SOLVED CPANEL-36050 - Backblaze B2: Backup transport errors

[MindServer]

Hi,

We have a serious problem: when cPanel do backups sometimes block the server and we need reboot him.

Where can I check the logs for send you?.

Thank you.

 

[cPRex]

Can you let me know what you mean when you say "block the server" ? Are you unable to access the cPanel machine at all? If so, the best place to look would be the error logs at /usr/local/cpanel/logs/error_log and the backup log at /usr/local/cpanel/logs/cpbackup/ for the most recent backup run.

This doesn't sound like it is related to the Backblaze issue, so it might be best if this was in a separate thread.

 

[MindServer]

Hi,

When I says "block the server" I mean that not works any tool: WHM, cPanel, SSH, FTP, websites, emails, etc. The server are doing ping, but not works any tool.

The datacenter checked this and told us that not is a hardware problem. This happens 2 times and in the both times WHM/cPanel are doing backups, in the logs the server have normal Load Averages: 1.00 - 2.00.

Before appear this problem, every week we receive email that says cPanel not complete all the backups: only complete 110 - 115 accounts (this server have 121 cPanel accounts).

Now we disabled cPanel backups (we are doing backups with JetBackup) and the problem not happens again.

In the file "/usr/local/cpanel/logs/error_log" before the server are down appear this:

[2021-07-03 06:16:03 +0200] warn [cpsrvd] lookup_mail_user() failed: You do not have a user named *****. at /usr/local/cpanel/Cpanel/Server.pm line 2385, <GEN19351> line 2.
Cpanel::Server::__ANON__(__CPANEL_HIDDEN__...) called at /usr/local/cpanel/Cpanel/Server/Dovecot.pm line 203
Cpanel::Server::Dovecot::_handle_dovecot_userdb(Cpanel::Server::Dovecot=HASH(0x31f22d0), "shared", "dovecot_userdb", "quota-status", "*****") called at /usr/local/cpanel/Cpanel/Server/Dovecot.pm line 150
Cpanel::Server::Dovecot::_dovecot_request_handler(Cpanel::Server::Dovecot=HASH(0x31f22d0), "Lshared/dovecot_userdb-quota-status/*****") called at /usr/local/cpanel/Cpanel/Server/Dovecot.pm line 90
eval {...} called at /usr/local/cpanel/Cpanel/Server/Dovecot.pm line 75
Cpanel::Server::Dovecot::handle_cpdoveauthd_request(Cpanel::Server::Dovecot=HASH(0x31f22d0)) called at /usr/local/cpanel/Cpanel/Server.pm line 2392
Cpanel::Server::handle_cpdoveauthd_connection(Cpanel::Server=HASH(0x326c208)) called at cpsrvd.pl line 1855
cpanel::cpsrvd::_handle_unix_socket_connection("handle_cpdoveauthd_connection") called at cpsrvd.pl line 1110
cpanel::cpsrvd::script() called at cpsrvd.pl line 432
[2021-07-03 06:16:07 +0200] info [autorepair] Successfully verified signature for cpanel (key types: release).
[2021-07-03 06:42:05 +0200] warn [cpsrvd] lookup_mail_user() failed: You do not have a user named *****. at /usr/local/cpanel/Cpanel/Server.pm line 2385, <GEN19532> line 2.
Cpanel::Server::__ANON__(__CPANEL_HIDDEN__...) called at /usr/local/cpanel/Cpanel/Server/Dovecot.pm line 203
Cpanel::Server::Dovecot::_handle_dovecot_userdb(Cpanel::Server::Dovecot=HASH(0x31f22b8), "shared", "dovecot_userdb", "quota-status", "*****") called at /usr/local/cpanel/Cpanel/Server/Dovecot.pm line 150
Cpanel::Server::Dovecot::_dovecot_request_handler(Cpanel::Server::Dovecot=HASH(0x31f22b8), "Lshared/dovecot_userdb-quota-status/*****") called at /usr/local/cpanel/Cpanel/Server/Dovecot.pm line 90
eval {...} called at /usr/local/cpanel/Cpanel/Server/Dovecot.pm line 75
Cpanel::Server::Dovecot::handle_cpdoveauthd_request(Cpanel::Server::Dovecot=HASH(0x31f22b8)) called at /usr/local/cpanel/Cpanel/Server.pm line 2392
Cpanel::Server::handle_cpdoveauthd_connection(Cpanel::Server=HASH(0x326c208)) called at cpsrvd.pl line 1855
cpanel::cpsrvd::_handle_unix_socket_connection("handle_cpdoveauthd_connection") called at cpsrvd.pl line 1110
cpanel::cpsrvd::script() called at cpsrvd.pl line 432
[2021-07-03 06:47:25 +0200] info [whostmgrd] Successfully verified signature for cpanel (key types: release).
-- RESTART MARKER (PID 1499 at Sat Jul 3 07:44:38 2021 - 1625291078)--
==> cpsrvd 11.94.0.12 started
==> cpsrvd: loading security policy....Done
==> cpsrvd: Setting up SSL support ... Done
==> cpsrvd: transferred port bindings: 3,4,5,6,7,8,9,10,11,12
==> cpsrvd: bound to ports

In the file " /usr/local/cpanel/logs/cpbackup/..." before the server are down appear this:

[2021-07-03 07:00:14 +0200] Completed “Integration” component.
[2021-07-03 07:00:14 +0200] Performing “AuthnLinks” component....
[2021-07-03 07:00:14 +0200] Completed “AuthnLinks” component.
[2021-07-03 07:00:14 +0200] Performing “APITokens” component....
[2021-07-03 07:00:14 +0200] Completed “APITokens” component.
[2021-07-03 07:00:14 +0200] Performing “DNSSEC” component....
[2021-07-03 07:00:14 +0200] Completed “DNSSEC” component.
[2021-07-03 07:00:14 +0200] Performing “Custom” component....
[2021-07-03 07:00:14 +0200] No custom components to perform.
[2021-07-03 07:00:14 +0200] Completed “Custom” component.
[2021-07-03 07:00:14 +0200] Performing “AutoSSL” component....
[2021-07-03 07:00:14 +0200] Completed “AutoSSL” component.
[2021-07-03 07:00:14 +0200] Storing Subdomains....
[2021-07-03 07:00:14 +0200] Done
[2021-07-03 07:00:14 +0200] Storing Parked Domains....
[2021-07-03 07:00:14 +0200] Done
[2021-07-03 07:00:14 +0200] Storing Addon Domains....
[2021-07-03 07:00:14 +0200] Performing “Password” component....
[2021-07-03 07:00:14 +0200] Completed “Password” component.
[2021-07-03 07:00:14 +0200] Performing “DigestShadow” component....
[2021-07-03 07:00:14 +0200] Completed “DigestShadow” component.
[2021-07-03 07:00:14 +0200] Copying shell.......[2021-07-03 07:00:14 +0200] Done
[2021-07-03 07:00:14 +0200] Performing “WebCalls” component....
[2021-07-03 07:00:14 +0200] Completed “WebCalls” component.
[2021-07-03 07:00:14 +0200] Performing “PublicContact” component....
[2021-07-03 07:00:14 +0200] Completed “PublicContact” component.
[2021-07-03 07:00:14 +0200] Performing “MailLimits” component....
[2021-07-03 07:00:14 +0200] Completed “MailLimits” component.
[2021-07-03 07:00:14 +0200] Performing “LinkedNodes” component....
[2021-07-03 07:00:14 +0200] Completed “LinkedNodes” component.
[2021-07-03 07:00:14 +0200] Creating Archive ........................
[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] pkgacctfile is: /backup/2021-07-03/accounts/*****.tar.gz
[2021-07-03 07:00:19 +0200]
[2021-07-03 07:00:19 +0200] size is: 68444600
[2021-07-03 07:00:19 +0200]
[2021-07-03 07:00:19 +0200] homesize is: 163880960
[2021-07-03 07:00:19 +0200]
[2021-07-03 07:00:19 +0200] homefiles is: 5755
[2021-07-03 07:00:19 +0200]
[2021-07-03 07:00:19 +0200] mysqlsize is: 2214709
[2021-07-03 07:00:19 +0200] pkgacct completed
[2021-07-03 07:00:19 +0200] info [backup] Successfully backed up account “*****” to “/backup/2021-07-03/accounts”
[2021-07-03 07:00:19 +0200] info [backup] Adding metadata information for ***** to backup at /backup/2021-07-03
[2021-07-03 07:00:19 +0200] info [backup] Queuing daily backup copy of “*****” for transport of “/backup/2021-07-03/accounts/*****.tar.gz” to “2021-07-03/accounts/*****.tar.gz”
[2021-07-03 07:00:19 +0200] info [backup] This particular transport will be queued with keep_local = 0 , based on the need to copy weekly () and/or monthly () copies as well.
[2021-07-03 07:00:19 +0200] info [backup] Queuing transport of file: /backup/2021-07-03/accounts/*****.tar.gz
[2021-07-03 07:00:19 +0200] info [backup] no_transport = 0 .. and queueid = TQ:TaskQueue:16000
[2021-07-03 07:00:19 +0200] info [backup] leaving queue_backup_transport_item
[2021-07-03 07:00:19 +0200] info [backup] checking backup for *****
[2021-07-03 07:00:19 +0200] info [backup] Backups ARE enabled for *****
[2021-07-03 07:00:19 +0200] info [backup] Calling pkgacct under cpuwatch to backup user “*****”
[2021-07-03 07:00:19 +0200] pkgacct started.
[2021-07-03 07:00:19 +0200] pkgacct version 10 - user : ***** - tarball: 1 - target mysql : default - split: 0 - incremental: 0 - homedir: 1 - mailman: 1 - backup: 1 - archive version: 4 - running with uid 0
[2021-07-03 07:00:19 +0200] pkgacct using '/usr/local/cpanel/3rdparty/bin/pigz -6 --processes 1 --blocksize 4096 --rsyncable' to compress archives
[2021-07-03 07:00:19 +0200] pkgacct working dir : /backup/2021-07-03/accounts/*****
[2021-07-03 07:00:19 +0200] Copying Reseller Config...[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Copying Suspension Info (if needed)...[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Copying installed SSL certificates and keys...[2021-07-03 07:00:19 +0200] Performing “ApacheTLS” component....
[2021-07-03 07:00:19 +0200] Completed “ApacheTLS” component.
[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Copying DKIM keys....[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Copying Bandwidth Data....[2021-07-03 07:00:19 +0200] Performing “Bandwidth” component....
Summary databases … done!
[2021-07-03 07:00:19 +0200] Completed “Bandwidth” component.
[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Copying Dns Zones.......*****.com...[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Copying Mail files....[2021-07-03 07:00:19 +0200] Performing “MailConfig” component....
[2021-07-03 07:00:19 +0200] Completed “MailConfig” component.
[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Copying proftpd file....[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Copy userdata...[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Copy custom virtualhost templates...[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Copying mailman lists and archives....Done copying mailman lists and archives.
[2021-07-03 07:00:19 +0200] Copying homedir.............
[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Fixing up EA4 .htaccess blocks: /home/*****/public_html/.htaccess Done.
[2021-07-03 07:00:19 +0200] Performing “Mysql” component....
Load watching suspended due to SIGUSR1
[2021-07-03 07:00:19 +0200] Determining mysql dbs...[2021-07-03 07:00:19 +0200] ...mysqldump version: 10.3.30...[2021-07-03 07:00:19 +0200] ...mysql version: 10.3...[2021-07-03 07:00:19 +0200] Saving mysql privs...[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Saving mysql authentication information...[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Storing MySQL databases...[2021-07-03 07:00:19 +0200] Storing database *****
[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] ...Done
[2021-07-03 07:00:19 +0200] ...Done
[2021-07-03 07:00:19 +0200] Completed “Mysql” component.
Load watching resumed due to SIGUSR2
[2021-07-03 07:00:19 +0200] Performing “MysqlRemoteNotes” component....
[2021-07-03 07:00:19 +0200] Completed “MysqlRemoteNotes” component.
[2021-07-03 07:00:19 +0200] Performing “CpUserFile” component....
[2021-07-03 07:00:19 +0200] Completed “CpUserFile” component.
[2021-07-03 07:00:19 +0200] Performing “Cron” component....
[2021-07-03 07:00:19 +0200] No readable crontab file found.
[2021-07-03 07:00:19 +0200] Completed “Cron” component.
[2021-07-03 07:00:19 +0200] Performing “Quota” component....
[2021-07-03 07:00:19 +0200] Completed “Quota” component.
[2021-07-03 07:00:19 +0200] Performing “Integration” component....

[2021-07-03 07:00:19 +0200] Completed “Integration” component.
[2021-07-03 07:00:19 +0200] Performing “AuthnLinks” component....
[2021-07-03 07:00:19 +0200] Completed “AuthnLinks” component.
[2021-07-03 07:00:19 +0200] Performing “APITokens” component....
[2021-07-03 07:00:19 +0200] Completed “APITokens” component.
[2021-07-03 07:00:19 +0200] Performing “DNSSEC” component....
[2021-07-03 07:00:19 +0200] Completed “DNSSEC” component.
[2021-07-03 07:00:19 +0200] Performing “Custom” component....
[2021-07-03 07:00:19 +0200] No custom components to perform.
[2021-07-03 07:00:19 +0200] Completed “Custom” component.
[2021-07-03 07:00:19 +0200] Performing “AutoSSL” component....
[2021-07-03 07:00:19 +0200] Completed “AutoSSL” component.
[2021-07-03 07:00:19 +0200] Storing Subdomains....
[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Storing Parked Domains....
[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Storing Addon Domains....
[2021-07-03 07:00:19 +0200] Performing “Password” component....
[2021-07-03 07:00:19 +0200] Completed “Password” component.
[2021-07-03 07:00:19 +0200] Performing “DigestShadow” component....
[2021-07-03 07:00:19 +0200] Completed “DigestShadow” component.
[2021-07-03 07:00:19 +0200] Copying shell.......[2021-07-03 07:00:19 +0200] Done
[2021-07-03 07:00:19 +0200] Performing “WebCalls” component....
[2021-07-03 07:00:19 +0200] Completed “WebCalls” component.
[2021-07-03 07:00:19 +0200] Performing “PublicContact” component....
[2021-07-03 07:00:19 +0200] Completed “PublicContact” component.
[2021-07-03 07:00:19 +0200] Performing “MailLimits” component....
[2021-07-03 07:00:19 +0200] Completed “MailLimits” component.
[2021-07-03 07:00:19 +0200] Performing “LinkedNodes” component....
[2021-07-03 07:00:19 +0200] Completed “LinkedNodes” component.
[2021-07-03 07:00:19 +0200] Creating Archive ....................................................................................
........................................

You can see in the last line that not complete the backup.

Thank you very much. Have a nice day.

Note: sorry my bad english.

 

[cPRex]

You've posted many times and I've always thought your English is just fine!

This is the type of issue we might just need a ticket to examine. If possible we could run the backup at a specific time and watch the server to see how it behaves and if the problem happens again, as those logs do not show anything that would be a problem, except the backup just stopping.

It's possible there could be useful data in /var/log/messages on the system, as that file could report problems with the server itself.

 

[MindServer]

You've posted many times and I've always thought your English is just fine!

This is the type of issue we might just need a ticket to examine. If possible we could run the backup at a specific time and watch the server to see how it behaves and if the problem happens again, as those logs do not show anything that would be a problem, except the backup just stopping.

It's possible there could be useful data in /var/log/messages on the system, as that file could report problems with the server itself.

Thank you very much.

The sysadmin checked various file logs but not found relevant data, only have normal logs. I will copy you some logs here:

Jul 3 07:05:54 ***** kernel: Firewall: *TCP6IN Blocked* IN=eth0 OUT= MAC=***** SRC=***** DST=***** LEN=60 TC=0 HOPLIMIT=55 FLOWLBL=0 PROTO=TCP SPT=443 DPT=17668 WINDOW=0 RES=0x00 RST URGP=0
Jul 3 07:05:55 ***** kernel: Firewall: *TCP_IN Blocked* IN=eth0 OUT= MAC=***** SRC=***** LEN=40 TOS=0x00 PREC=0x00 TTL=51 ID=0 DF PROTO=TCP SPT=52222 DPT=443 WINDOW=0 RES=0x00 RST URGP=0
Jul 3 07:06:01 ***** systemd: Started Session c129074 of user root.
Jul 3 07:06:01 ***** systemd: Started Session c129075 of user root.
Jul 3 07:06:01 ***** systemd: Started Session c129076 of user root.
Jul 3 07:06:01 ***** systemd: Started Session c129077 of user root.
Jul 3 07:06:01 ***** systemd: Started Session c129078 of user root.
Jul 3 07:06:01 ***** systemd: Started Session c129079 of user root.
Jul 3 07:06:01 ***** systemd: Started Session c129080 of user root.

Jun 27 03:48:48 ***** kernel: lsphp invoked oom-killer: gfp_mask=0xd0, order=0, oom_score_adj=0
Jun 27 03:48:48 ***** kernel: lsphp cpuset=/ mems_allowed=0
Jun 27 03:48:48 ***** kernel: CPU: 1 PID: 2767758 Comm: lsphp ve: 0 Kdump: loaded Tainted: G O ------------ 3.10.0-962.3.2.lve1.5.56.el7.x86_64 #1 61.16
Jun 27 03:48:48 ***** kernel: Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./E3C246D4U2-2T, BIOS L2.02K 12/18/2019
Jun 27 03:48:48 ***** kernel: Call Trace:
Jun 27 03:48:48 ***** kernel: [<ffffffffa4329add>] dump_stack+0x19/0x1b
Jun 27 03:48:48 ***** kernel: [<ffffffffa4325a7f>] dump_header+0x90/0x229
Jun 27 03:48:48 ***** kernel: [<ffffffffa3daf178>] oom_kill_process+0x5e8/0x640
Jun 27 03:48:48 ***** kernel: [<ffffffffa3dd81fe>] ? get_task_oom_score_adj+0xee/0x100
Jun 27 03:48:48 ***** kernel: [<ffffffffa3e2e4f9>] mem_cgroup_oom_synchronize+0x4a9/0x500
Jun 27 03:48:48 ***** kernel: [<ffffffffa3daf723>] pagefault_out_of_memory+0x13/0x50
Jun 27 03:48:48 ***** kernel: [<ffffffffa4323b47>] mm_fault_error+0x6a/0x157
Jun 27 03:48:48 ***** kernel: [<ffffffffa4336906>] __do_page_fault+0x496/0x4f0
Jun 27 03:48:48 ***** kernel: [<ffffffffa4336995>] do_page_fault+0x35/0x90
Jun 27 03:48:48 ***** kernel: [<ffffffffa4332778>] page_fault+0x28/0x30
Jun 27 03:48:48 ***** kernel: Task in /lve1171 killed as a result of limit of /lve1171
Jun 27 03:48:48 ***** kernel: memory: usage 1048576kB, limit 1048576kB, failcnt 1200687
Jun 27 03:48:48 ***** kernel: memory+swap: usage 1048576kB, limit 9007199254740988kB, failcnt 0
Jun 27 03:48:48 ***** kernel: kmem: usage 0kB, limit 9007199254740988kB, failcnt 0
Jun 27 03:48:48 ***** kernel: Memory cgroup stats for /lve1171: rss_huge:0KB mapped_file:4KB shmem:4KB slab_unreclaimable:0KB swap:0KB cache:200KB rss:1048376KB slab_reclaimable:0KB inactive_anon:225924KB active_anon:822348KB inactive_file:56KB active_file:48KB unevictable:0KB
Jun 27 03:48:48 ***** kernel: Memory cgroup out of memory: Kill process 2767264 (lsphp) score 170 or sacrifice child
Jun 27 03:48:48 ***** kernel: Killed process 2767264 (lsphp) in VE "0" total-vm:551316kB, anon-rss:169860kB, file-rss:8464kB, shmem-rss:4kB

Jun 27 04:00:09 ***** lfd[1344043]: SYSLOG check [YgKwh8bOQ9Cwv5qOIiks]
Jun 27 04:00:18 ***** pure-ftpd: ([email protected]) [INFO] New connection from 127.0.0.1
Jun 27 04:00:18 ***** pure-ftpd: ([email protected]) [INFO] __cpanel__service__auth__ftpd__ReORUel6uXoEzg56 is now logged in
Jun 27 04:00:18 ***** pure-ftpd: ([email protected]) [INFO] Logout.

Jun 29 08:11:27 ***** kernel: Mem-Info:
Jun 29 08:11:27 ***** kernel: active_anon:1218718 inactive_anon:225813 isolated_anon:0#012 active_file:15512559 inactive_file:14285582 isolated_file:0#012 unevictable:0 dirty:92148 writeback:32750 wbtmp:0 unstable:0#012 slab_reclaimable:1218529 slab_unreclaimable:38508#012 mapped:41772 shmem:108654 pagetables:10863 bounce:0#012 free:158855 free_pcp:4117 free_cma:0
Jun 29 08:11:27 ***** kernel: Node 0 DMA free:15816kB min:4kB low:4kB high:4kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15992kB managed:15900kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:84kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
Jun 29 08:11:27 ***** kernel: lowmem_reserve[]: 0 1541 128492 128492
Jun 29 08:11:27 ***** kernel: Node 0 DMA32 free:507932kB min:784kB low:980kB high:1176kB active_anon:24136kB inactive_anon:42612kB active_file:316948kB inactive_file:302936kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1816760kB managed:1578576kB mlocked:0kB dirty:2116kB writeback:1520kB mapped:2028kB shmem:3656kB slab_reclaimable:364972kB slab_unreclaimable:4372kB kernel_stack:176kB pagetables:876kB unstable:0kB bounce:0kB free_pcp:8376kB local_pcp:224kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Jun 29 08:11:27 ***** kernel: lowmem_reserve[]: 0 0 126950 126950
Jun 29 08:11:27 ***** kernel: Node 0 Normal free:111672kB min:64740kB low:80924kB high:97108kB active_anon:4850736kB inactive_anon:860640kB active_file:61733288kB inactive_file:56839392kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:132112384kB managed:129997652kB mlocked:0kB dirty:366476kB writeback:129480kB mapped:165060kB shmem:430960kB slab_reclaimable:4509144kB slab_unreclaimable:149576kB kernel_stack:10896kB pagetables:42576kB unstable:0kB bounce:0kB free_pcp:8084kB local_pcp:292kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Jun 29 08:11:27 ***** kernel: lowmem_reserve[]: 0 0 0 0
Jun 29 08:11:27 ***** kernel: Node 0 DMA: 0*4kB 1*8kB (U) 0*16kB 0*32kB 3*64kB (U) 2*128kB (U) 0*256kB 0*512kB 1*1024kB (U) 1*2048kB (M) 3*4096kB (M) = 15816kB
Jun 29 08:11:27 ***** kernel: Node 0 DMA32: 668*4kB (UEM) 8919*8kB (UEM) 3930*16kB (UEM) 2462*32kB (UEM) 1107*64kB (EM) 116*128kB (UEM) 18*256kB (UEM) 63*512kB (UE) 38*1024kB (UEM) 16*2048kB (UE) 24*4096kB (UEM) = 508232kB
Jun 29 08:11:27 ***** kernel: Node 0 Normal: 19040*4kB (UEM) 4400*8kB (UEM) 1*16kB (U) 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 111376kB
Jun 29 08:11:27 ***** kernel: Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
Jun 29 08:11:27 ***** kernel: Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
Jun 29 08:11:27 ***** kernel: 29906802 total pagecache pages
Jun 29 08:11:27 ***** kernel: 4 pages in swap cache
Jun 29 08:11:27 ***** kernel: Swap cache stats: add 402, delete 398, find 8699/8767
Jun 29 08:11:27 ***** kernel: Free swap = 1043192kB
Jun 29 08:11:27 ***** kernel: Total swap = 1046520kB
Jun 29 08:11:27 ***** kernel: kworker/u32:0: page allocation failure: order:2, mode:0x4020
Jun 29 08:11:27 ***** kernel: CPU: 5 PID: 916186 Comm: kworker/u32:0 ve: 0 Kdump: loaded Tainted: G OE ------------ 3.10.0-962.3.2.lve1.5.56.el7.x86_64 #1 61.16
Jun 29 08:11:27 ***** kernel: Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./E3C246D4U2-2T, BIOS L2.02K 12/18/2019
Jun 29 08:11:27 ***** kernel: Workqueue: writeback bdi_writeback_workfn (flush-9:2)
Jun 29 08:11:27 ***** kernel: Call Trace:
Jun 29 08:11:27 ***** kernel: [<ffffffffa4329add>] dump_stack+0x19/0x1b
Jun 29 08:11:27 ***** kernel: [<ffffffffa3db1620>] warn_alloc_failed+0x110/0x180
Jun 29 08:11:27 ***** kernel: [<ffffffffa3ce1757>] ? update_curr+0x137/0x1f0
Jun 29 08:11:27 ***** kernel: [<ffffffffa4326634>] __alloc_pages_slowpath+0x677/0x78c
Jun 29 08:11:27 ***** kernel: [<ffffffffa3cd2fa9>] ? ttwu_do_wakeup+0x19/0xe0
Jun 29 08:11:27 ***** kernel: [<ffffffffa3db5db5>] __alloc_pages_nodemask+0x5d5/0x600
Jun 29 08:11:27 ***** kernel: [<ffffffffa3e05648>] alloc_pages_current+0x98/0x110
Jun 29 08:11:27 ***** kernel: [<ffffffffa3dd2288>] kmalloc_order+0x18/0x40
Jun 29 08:11:27 ***** kernel: [<ffffffffa3dd22d6>] kmalloc_order_trace+0x26/0xa0
Jun 29 08:11:27 ***** kernel: [<ffffffffa3e148c1>] __kmalloc+0x281/0x2a0
Jun 29 08:11:27 ***** kernel: [<ffffffffc03a0834>] nvme_queue_rq+0xb4/0x8d0 [nvme]
Jun 29 08:11:27 ***** kernel: [<ffffffffa3f8dfad>] ? sbitmap_get+0x5d/0xb0
Jun 29 08:11:27 ***** kernel: [<ffffffffa3f8e22b>] ? __sbitmap_queue_get+0x2b/0xb0
Jun 29 08:11:27 ***** kernel: [<ffffffffa3f35ff1>] ? __blk_mq_get_tag+0x21/0x90
Jun 29 08:11:27 ***** kernel: [<ffffffffa3f36443>] ? blk_mq_get_tag+0xc3/0x2a0
Jun 29 08:11:27 ***** kernel: [<ffffffffa3cc1950>] ? wake_up_atomic_t+0x30/0x30
Jun 29 08:11:27 ***** kernel: [<ffffffffa3f33166>] __blk_mq_try_issue_directly+0x196/0x1e0
Jun 29 08:11:27 ***** kernel: [<ffffffffa3f33217>] blk_mq_try_issue_directly+0x67/0x80
Jun 29 08:11:27 ***** kernel: [<ffffffffa3f33d54>] blk_mq_make_request+0x434/0x5d0
Jun 29 08:11:27 ***** kernel: [<ffffffffa3f27a2b>] generic_make_request+0x10b/0x320
Jun 29 08:11:27 ***** kernel: [<ffffffffc047c9ee>] raid1_unplug+0x11e/0x160 [raid1]
Jun 29 08:11:27 ***** kernel: [<ffffffffa3f29607>] blk_flush_plug_list+0xa7/0x230
Jun 29 08:11:27 ***** kernel: [<ffffffffa432d240>] ? bit_wait+0x50/0x50
Jun 29 08:11:27 ***** kernel: [<ffffffffa432e848>] io_schedule_timeout+0x128/0x130
Jun 29 08:11:27 ***** kernel: [<ffffffffa432e868>] io_schedule+0x18/0x20
Jun 29 08:11:27 ***** kernel: [<ffffffffa432d251>] bit_wait_io+0x11/0x50
Jun 29 08:11:27 ***** kernel: [<ffffffffa432cd77>] __wait_on_bit+0x67/0x90
Jun 29 08:11:27 ***** kernel: [<ffffffffa432d240>] ? bit_wait+0x50/0x50
Jun 29 08:11:27 ***** kernel: [<ffffffffa432cee1>] out_of_line_wait_on_bit+0x81/0xb0
Jun 29 08:11:27 ***** kernel: [<ffffffffa3cc1a10>] ? wake_bit_function+0x40/0x40
Jun 29 08:11:27 ***** kernel: [<ffffffffa3e7835a>] __wait_on_buffer+0x2a/0x30
Jun 29 08:11:27 ***** kernel: [<ffffffffc0621830>] ext4_wait_block_bitmap+0xd0/0xe0 [ext4]
Jun 29 08:11:27 ***** kernel: [<ffffffffc0661bd6>] ext4_mb_init_cache+0x226/0x6e0 [ext4]
Jun 29 08:11:27 ***** kernel: [<ffffffffa3dbaabe>] ? lru_cache_add+0xe/0x10
Jun 29 08:11:27 ***** kernel: [<ffffffffc0662731>] ext4_mb_load_buddy_gfp+0x2b1/0x340 [ext4]
Jun 29 08:11:27 ***** kernel: [<ffffffffc0664087>] ext4_mb_find_by_goal+0xb7/0x340 [ext4]
Jun 29 08:11:27 ***** kernel: [<ffffffffc047d5be>] ? raid1_write_request+0x5de/0xa10 [raid1]
Jun 29 08:11:27 ***** kernel: [<ffffffffc0664b33>] ext4_mb_regular_allocator+0x73/0x480 [ext4]
Jun 29 08:11:27 ***** kernel: [<ffffffffa3e785ec>] ? __find_get_block+0xbc/0x120
Jun 29 08:11:27 ***** kernel: [<ffffffffc0666bc3>] ext4_mb_new_blocks+0x6b3/0xaf0 [ext4]
Jun 29 08:11:27 ***** kernel: [<ffffffffa3e1488d>] ? __kmalloc+0x24d/0x2a0
Jun 29 08:11:27 ***** kernel: [<ffffffffc0657fec>] ? ext4_ext_find_extent+0x12c/0x2e0 [ext4]
Jun 29 08:11:27 ***** kernel: [<ffffffffc065bb76>] ext4_ext_map_blocks+0x4a6/0xfc0 [ext4]
Jun 29 08:11:27 ***** kernel: [<ffffffffc062a3c6>] ext4_map_blocks+0x136/0x6a0 [ext4]
Jun 29 08:11:27 ***** kernel: [<ffffffffc062e23a>] ext4_writepages+0x6ca/0xd40 [ext4]
Jun 29 08:11:27 ***** kernel: [<ffffffffa3db83c1>] do_writepages+0x21/0x50
Jun 29 08:11:27 ***** kernel: [<ffffffffa3e6de4f>] __writeback_single_inode+0x7f/0x430
Jun 29 08:11:27 ***** kernel: [<ffffffffa3e6ebe1>] writeback_sb_inodes+0x231/0x590
Jun 29 08:11:27 ***** kernel: [<ffffffffa3e6efdf>] __writeback_inodes_wb+0x9f/0xd0
Jun 29 08:11:27 ***** kernel: [<ffffffffa3e6f273>] wb_writeback+0x263/0x320
Jun 29 08:11:27 ***** kernel: [<ffffffffa3e5a9dc>] ? get_nr_inodes+0x4c/0x70
Jun 29 08:11:27 ***** kernel: [<ffffffffa3e6fcd2>] bdi_writeback_workfn+0x2e2/0x430
Jun 29 08:11:27 ***** kernel: [<ffffffffa3cb8622>] process_one_work+0x182/0x440
Jun 29 08:11:27 ***** kernel: [<ffffffffa3cb97d6>] worker_thread+0x126/0x3c0
Jun 29 08:11:27 ***** kernel: [<ffffffffa3cb96b0>] ? manage_workers.isra.24+0x2a0/0x2a0
Jun 29 08:11:27 ***** kernel: [<ffffffffa3cc0771>] kthread+0xd1/0xe0
Jun 29 08:11:27 ***** kernel: [<ffffffffa3cc06a0>] ? create_kthread+0x60/0x60
Jun 29 08:11:27 ***** kernel: [<ffffffffa433b69d>] ret_from_fork_nospec_begin+0x7/0x21
Jun 29 08:11:27 ***** kernel: [<ffffffffa3cc06a0>] ? create_kthread+0x60/0x60

Note: this logs not are created while the problem happens, this logs appear in other days/hours but we not found nothing more.

Note: the server have 128GB RAM, and normally we use 10%-20%, have many free RAM always.

Thank you again. Have a nice day.

 

[cPRex]

The memory issues in the second paste are related to the CloudLinux LVE tools killing off a process using too much RAM, so that isn't an overall issue with the server.

I don't see anything in there that would indicate an obvious issue. It might be best to have someone watch the machine while the backups run to see if there are any issues that can be seen during that time.