Skip to main content

Backup error - Connection stalled

Comments

7 comments

  • cPanelMichael
    New The error: Upload attempt failed: Connection to remote server stalled at /usr/local/cpanel/Cpanel/LoggerAdapter.pm line 27

    Hello :) Do you notice any error messages in the SFTP logs (/var/log/secure) on the remote destination? Also, are there any additional entries in the transport logs (/usr/local/cpanel/logs/cpbackup_transporter/) on the cPanel server? Thank you.
    0
  • Bill Hicks the third
    There are no errrors in /var/log/secure on the destination relating to the sender. During the backup the following is recorded in secure
    Dec 1 02:00:51 live2 sshd[11483]: Accepted password for root from 62.121.13.124 port 33157 ssh2 Dec 1 02:00:51 live2 sshd[11483]: pam_unix(sshd:session): session opened for user root by (uid=0) Dec 1 02:00:51 live2 sshd[11483]: subsystem request for sftp Dec 1 02:02:02 live2 sshd[11483]: Received disconnect from 62.121.13.124: 11: disconnected by user Dec 1 02:02:02 live2 sshd[11483]: pam_unix(sshd:session): session closed for user root Dec 1 02:02:02 live2 sshd[11534]: Accepted password for root from 62.121.13.124 port 4125 ssh2 Dec 1 02:02:03 live2 sshd[11534]: pam_unix(sshd:session): session opened for user root by (uid=0) Dec 1 02:02:03 live2 sshd[11534]: subsystem request for sftp Dec 1 02:03:08 live2 sshd[11534]: Received disconnect from 62.121.13.124: 11: disconnected by user Dec 1 02:03:08 live2 sshd[11534]: pam_unix(sshd:session): session closed for user root Dec 1 02:03:09 live2 sshd[11561]: Accepted password for root from 62.121.13.124 port 35991 ssh2 Dec 1 02:03:09 live2 sshd[11561]: pam_unix(sshd:session): session opened for user root by (uid=0) Dec 1 02:03:09 live2 sshd[11561]: subsystem request for sftp Dec 1 02:03:09 live2 sshd[11561]: Received disconnect from 62.121.13.124: 11: disconnected by user Dec 1 02:03:09 live2 sshd[11561]: pam_unix(sshd:session): session closed for user root Dec 1 02:03:09 live2 sshd[11575]: Accepted password for root from 62.121.13.124 port 45698 ssh2 Dec 1 02:03:10 live2 sshd[11575]: pam_unix(sshd:session): session opened for user root by (uid=0) Dec 1 02:03:10 live2 sshd[11575]: subsystem request for sftp Dec 1 02:03:10 live2 sshd[11575]: Received disconnect from 62.121.13.124: 11: disconnected by user Dec 1 02:03:10 live2 sshd[11575]: pam_unix(sshd:session): session closed for user root Dec 1 02:03:10 live2 sshd[11589]: Accepted password for root from 62.121.13.124 port 55329 ssh2 Dec 1 02:03:10 live2 sshd[11589]: pam_unix(sshd:session): session opened for user root by (uid=0) Dec 1 02:03:10 live2 sshd[11589]: subsystem request for sftp Dec 1 02:03:28 live2 sshd[11589]: Received disconnect from 62.121.13.124: 11: disconnected by user Dec 1 02:03:28 live2 sshd[11589]: pam_unix(sshd:session): session closed for user root Dec 1 02:03:28 live2 sshd[11603]: Accepted password for root from 62.121.13.124 port 37857 ssh2 Dec 1 02:03:29 live2 sshd[11603]: pam_unix(sshd:session): session opened for user root by (uid=0) Dec 1 02:03:29 live2 sshd[11603]: subsystem request for sftp Dec 1 02:05:07 live2 sshd[11603]: Received disconnect from 62.121.13.124: 11: disconnected by user Dec 1 02:05:07 live2 sshd[11603]: pam_unix(sshd:session): session closed for user root Dec 1 02:05:08 live2 sshd[11643]: Accepted password for root from 62.121.13.124 port 42062 ssh2 Dec 1 02:05:08 live2 sshd[11643]: pam_unix(sshd:session): session opened for user root by (uid=0) Dec 1 02:05:08 live2 sshd[11643]: subsystem request for sftp Dec 1 02:06:51 live2 sshd[11643]: Received disconnect from 62.121.13.124: 11: disconnected by user Dec 1 02:06:51 live2 sshd[11643]: pam_unix(sshd:session): session closed for user root Dec 1 02:06:52 live2 sshd[11710]: Accepted password for root from 62.121.13.124 port 22856 ssh2 Dec 1 02:06:52 live2 sshd[11710]: pam_unix(sshd:session): session opened for user root by (uid=0) Dec 1 02:06:52 live2 sshd[11710]: subsystem request for sftp Dec 1 02:08:27 live2 sshd[11710]: Received disconnect from 62.121.13.124: 11: disconnected by user Dec 1 02:08:27 live2 sshd[11710]: pam_unix(sshd:session): session closed for user root Dec 1 02:08:27 live2 sshd[11734]: Accepted password for root from 62.121.13.124 port 32903 ssh2 Dec 1 02:08:28 live2 sshd[11734]: pam_unix(sshd:session): session opened for user root by (uid=0) Dec 1 02:08:28 live2 sshd[11734]: subsystem request for sftp Dec 1 02:08:28 live2 sshd[11734]: Received disconnect from 62.121.13.124: 11: disconnected by user Dec 1 02:08:28 live2 sshd[11734]: pam_unix(sshd:session): session closed for user root Dec 1 02:08:28 live2 sshd[11748]: Accepted password for root from 62.121.13.124 port 16290 ssh2 Dec 1 02:08:28 live2 sshd[11748]: pam_unix(sshd:session): session opened for user root by (uid=0) Dec 1 02:08:28 live2 sshd[11748]: subsystem request for sftp Dec 1 02:08:29 live2 sshd[11748]: Received disconnect from 62.121.13.124: 11: disconnected by user Dec 1 02:08:29 live2 sshd[11748]: pam_unix(sshd:session): session closed for user root
    The transport logs /usr/local/cpanel/logs/cpbackup_transporter/ for the same night contains:
    [2015-12-01 02:00:50 +0000] info [cpbackup_transporter] Initializing log file [2015-12-01 02:00:50 +0000] info [cpbackup_transporter] cPanel Backup Transporter Queue Daemon started. [2015-12-01 02:00:50 +0000] info [cpbackup_transporter] cpbackup_transporter - started [2015-12-01 02:00:50 +0000] info [cpbackup_transporter] cpbackup_transporter - Checking queue for tasks [2015-12-01 02:00:50 +0000] info [cpbackup_transporter] cpbackup_transporter - Processing next task [2015-12-01 02:00:51 +0000] info [cpbackup_transporter] Starting a "copy_system_backup" operation on the "Live2" destination ID "wgauWR_o7f7tThVuVPTgU2lp". [2015-12-01 02:00:51 +0000] info [cpbackup_transporter] Base path for destination is /DXLIVE3_backup [2015-12-01 02:00:51 +0000] info [cpbackup_transporter] Uploading system backup file /backup/2015-12-01/system_files.tar to Live2 [2015-12-01 02:00:51 +0000] info [cpbackup_transporter] Upload attempt #1 starting for /backup/2015-12-01/system_files.tar to /DXLIVE3_backup/2015-12-01/system_files.tar for destination: Live2 [2015-12-01 02:02:01 +0000] info [cpbackup_transporter] cpbackup_transporter - Checking queue for tasks [2015-12-01 02:02:01 +0000] info [cpbackup_transporter] cpbackup_transporter - Processing next task [2015-12-01 02:02:02 +0000] info [cpbackup_transporter] Starting a "copy_system_backup" operation on the "Live2" destination ID "wgauWR_o7f7tThVuVPTgU2lp". [2015-12-01 02:02:02 +0000] info [cpbackup_transporter] Base path for destination is /DXLIVE3_backup [2015-12-01 02:02:02 +0000] info [cpbackup_transporter] Uploading system backup file /backup/2015-12-01/system_files.tar to Live2 [2015-12-01 02:02:02 +0000] info [cpbackup_transporter] Upload attempt #1 starting for /backup/2015-12-01/system_files.tar to /DXLIVE3_backup/monthly/2015-12-01/system_files.tar for destination: Live2 [2015-12-01 02:03:07 +0000] info [cpbackup_transporter] cpbackup_transporter - Checking queue for tasks [2015-12-01 02:03:07 +0000] info [cpbackup_transporter] cpbackup_transporter - Processing next task [2015-12-01 02:03:07 +0000] info [cpbackup_transporter] Deleting system backup tar file: /backup/2015-12-01/system_files.tar [2015-12-01 02:03:07 +0000] info [cpbackup_transporter] cpbackup_transporter - Checking queue for tasks [2015-12-01 02:03:07 +0000] info [cpbackup_transporter] cpbackup_transporter - Processing next task [2015-12-01 02:03:08 +0000] info [cpbackup_transporter] Starting a "copy" operation on the "Live2" destination ID "wgauWR_o7f7tThVuVPTgU2lp". [2015-12-01 02:03:08 +0000] info [cpbackup_transporter] Base path for destination is /DXLIVE3_backup [2015-12-01 02:03:08 +0000] info [cpbackup_transporter] Upload attempt #1 starting for /backup/2015-12-01/accounts/dxlive3.tar.gz to /DXLIVE3_backup/2015-12-01/dxlive3.tar.gz for destination: Live2 [2015-12-01 02:03:08 +0000] info [cpbackup_transporter] cpbackup_transporter - Checking queue for tasks [2015-12-01 02:03:08 +0000] info [cpbackup_transporter] cpbackup_transporter - Processing next task [2015-12-01 02:03:09 +0000] info [cpbackup_transporter] Starting a "copy" operation on the "Live2" destination ID "wgauWR_o7f7tThVuVPTgU2lp". [2015-12-01 02:03:09 +0000] info [cpbackup_transporter] Base path for destination is /DXLIVE3_backup [2015-12-01 02:03:09 +0000] info [cpbackup_transporter] Upload attempt #1 starting for /backup/2015-12-01/accounts/dxlive3.tar.gz to /DXLIVE3_backup/monthly/2015-12-01/dxlive3.tar.gz for destination: Live2 [2015-12-01 02:03:09 +0000] info [cpbackup_transporter] cpbackup_transporter - Checking queue for tasks [2015-12-01 02:03:09 +0000] info [cpbackup_transporter] cpbackup_transporter - Processing next task [2015-12-01 02:03:10 +0000] info [cpbackup_transporter] Starting a "copy" operation on the "Live2" destination ID "wgauWR_o7f7tThVuVPTgU2lp". [2015-12-01 02:03:10 +0000] info [cpbackup_transporter] Base path for destination is /DXLIVE3_backup [2015-12-01 02:03:10 +0000] info [cpbackup_transporter] Upload attempt #1 starting for /backup/2015-12-01/accounts/creative62.tar.gz to /DXLIVE3_backup/2015-12-01/creative62.tar.gz for destination: Live2 [2015-12-01 02:03:27 +0000] info [cpbackup_transporter] cpbackup_transporter - Checking queue for tasks [2015-12-01 02:03:27 +0000] info [cpbackup_transporter] cpbackup_transporter - Processing next task [2015-12-01 02:03:28 +0000] info [cpbackup_transporter] Starting a "copy" operation on the "Live2" destination ID "wgauWR_o7f7tThVuVPTgU2lp". [2015-12-01 02:03:28 +0000] info [cpbackup_transporter] Base path for destination is /DXLIVE3_backup [2015-12-01 02:03:28 +0000] info [cpbackup_transporter] Upload attempt #1 starting for /backup/2015-12-01/accounts/creative62.tar.gz to /DXLIVE3_backup/monthly/2015-12-01/creative62.tar.gz for destination: Live2 [2015-12-01 02:04:58 +0000] warn [cpbackup_transporter] Upload attempt failed: Connection to remote server stalled at /usr/local/cpanel/Cpanel/LoggerAdapter.pm line 27. Cpanel::LoggerAdapter::warn(Cpanel::LoggerAdapter=HASH(0x18d7c50), "Upload attempt failed: Connection to remote server stalled") called at /usr/local/cpanel/Cpanel/Backup/Queue.pm line 497 Cpanel::Backup::Queue::transport_backup::attempt_to_upload_file(Cpanel::Backup::Queue::transport_backup=HASH(0x2034be8), Cpanel::Transport::Files::SFTP=HASH(0x21104a0), "/backup/2015-12-01/accounts/creative62.tar.gz", "/DXLIVE3_backup/monthly/2015-12-01/creative62.tar.gz", Cpanel::LoggerAdapter=HASH(0x18d7c50)) called at /usr/local/cpanel/Cpanel/Backup/Queue.pm line 259 Cpanel::Backup::Queue::transport_backup::process_task(Cpanel::Backup::Queue::transport_backup=HASH(0x2034be8), cPanel::TaskQueue::Task=HASH(0x236efe8), Cpanel::LoggerAdapter=HASH(0x18d7c50)) called at /usr/local/cpanel/3rdparty/perl/514/lib64/perl5/cpanel_lib/cPanel/TaskQueue.pm line 582 eval {...} called at /usr/local/cpanel/3rdparty/perl/514/lib64/perl5/cpanel_lib/cPanel/TaskQueue.pm line 585 cPanel::TaskQueue::__ANON__() called at /usr/local/cpanel/3rdparty/perl/514/lib64/perl5/cpanel_lib/cPanel/StateFile.pm line 238 eval {...} called at /usr/local/cpanel/3rdparty/perl/514/lib64/perl5/cpanel_lib/cPanel/StateFile.pm line 238 cPanel::StateFile::Guard::call_unlocked(cPanel::StateFile::Guard=HASH(0x2643430), CODE(0x22dcd10)) called at /usr/local/cpanel/3rdparty/perl/514/lib64/perl5/cpanel_lib/cPanel/TaskQueue.pm line 590 cPanel::TaskQueue::process_next_task(cPanel::TaskQueue=HASH(0x2110440)) called at /usr/local/cpanel/bin/cpbackup_transporter line 151 eval {...} called at /usr/local/cpanel/bin/cpbackup_transporter line 149 [2015-12-01 02:04:58 +0000] info [cpbackup_transporter] Upload attempt #2 starting for /backup/2015-12-01/accounts/creative62.tar.gz to /DXLIVE3_backup/monthly/2015-12-01/creative62.tar.gz for destination: Live2 [2015-12-01 02:04:58 +0000] warn [cpbackup_transporter] Upload attempt failed: Connection to remote server stalled at /usr/local/cpanel/Cpanel/LoggerAdapter.pm line 27. Cpanel::LoggerAdapter::warn(Cpanel::LoggerAdapter=HASH(0x18d7c50), "Upload attempt failed: Connection to remote server stalled") called at /usr/local/cpanel/Cpanel/Backup/Queue.pm line 497 Cpanel::Backup::Queue::transport_backup::attempt_to_upload_file(Cpanel::Backup::Queue::transport_backup=HASH(0x2034be8), Cpanel::Transport::Files::SFTP=HASH(0x21104a0), "/backup/2015-12-01/accounts/creative62.tar.gz", "/DXLIVE3_backup/monthly/2015-12-01/creative62.tar.gz", Cpanel::LoggerAdapter=HASH(0x18d7c50)) called at /usr/local/cpanel/Cpanel/Backup/Queue.pm line 259 Cpanel::Backup::Queue::transport_backup::process_task(Cpanel::Backup::Queue::transport_backup=HASH(0x2034be8), cPanel::TaskQueue::Task=HASH(0x236efe8), Cpanel::LoggerAdapter=HASH(0x18d7c50)) called at /usr/local/cpanel/3rdparty/perl/514/lib64/perl5/cpanel_lib/cPanel/TaskQueue.pm line 582 eval {...} called at /usr/local/cpanel/3rdparty/perl/514/lib64/perl5/cpanel_lib/cPanel/TaskQueue.pm line 585 cPanel::TaskQueue::__ANON__() called at /usr/local/cpanel/3rdparty/perl/514/lib64/perl5/cpanel_lib/cPanel/StateFile.pm line 238 eval {...} called at /usr/local/cpanel/3rdparty/perl/514/lib64/perl5/cpanel_lib/cPanel/StateFile.pm line 238 cPanel::StateFile::Guard::call_unlocked(cPanel::StateFile::Guard=HASH(0x2643430), CODE(0x22dcd10)) called at /usr/local/cpanel/3rdparty/perl/514/lib64/perl5/cpanel_lib/cPanel/TaskQueue.pm line 590 cPanel::TaskQueue::process_next_task(cPanel::TaskQueue=HASH(0x2110440)) called at /usr/local/cpanel/bin/cpbackup_transporter line 151 eval {...} called at /usr/local/cpanel/bin/cpbackup_transporter line 149 [2015-12-01 02:04:58 +0000] info [cpbackup_transporter] Upload attempt #3 starting for /backup/2015-12-01/accounts/creative62.tar.gz to /DXLIVE3_backup/monthly/2015-12-01/creative62.tar.gz for destination: Live2 [2015-12-01 02:04:58 +0000] warn [cpbackup_transporter] Upload attempt failed: Connection to remote server stalled at /usr/local/cpanel/Cpanel/LoggerAdapter.pm line 27. Cpanel::LoggerAdapter::warn(Cpanel::LoggerAdapter=HASH(0x18d7c50), "Upload attempt failed: Connection to remote server stalled") called at /usr/local/cpanel/Cpanel/Backup/Queue.pm line 497 Cpanel::Backup::Queue::transport_backup::attempt_to_upload_file(Cpanel::Backup::Queue::transport_backup=HASH(0x2034be8), Cpanel::Transport::Files::SFTP=HASH(0x21104a0), "/backup/2015-12-01/accounts/creative62.tar.gz", "/DXLIVE3_backup/monthly/2015-12-01/creative62.tar.gz", Cpanel::LoggerAdapter=HASH(0x18d7c50)) called at /usr/local/cpanel/Cpanel/Backup/Queue.pm line 259 Cpanel::Backup::Queue::transport_backup::process_task(Cpanel::Backup::Queue::transport_backup=HASH(0x2034be8), cPanel::TaskQueue::Task=HASH(0x236efe8), Cpanel::LoggerAdapter=HASH(0x18d7c50)) called at /usr/local/cpanel/3rdparty/perl/514/lib64/perl5/cpanel_lib/cPanel/TaskQueue.pm line 582 eval {...} called at /usr/local/cpanel/3rdparty/perl/514/lib64/perl5/cpanel_lib/cPanel/TaskQueue.pm line 585 cPanel::TaskQueue::__ANON__() called at /usr/local/cpanel/3rdparty/perl/514/lib64/perl5/cpanel_lib/cPanel/StateFile.pm line 238 eval {...} called at /usr/local/cpanel/3rdparty/perl/514/lib64/perl5/cpanel_lib/cPanel/StateFile.pm line 238 cPanel::StateFile::Guard::call_unlocked(cPanel::StateFile::Guard=HASH(0x2643430), CODE(0x22dcd10)) called at /usr/local/cpanel/3rdparty/perl/514/lib64/perl5/cpanel_lib/cPanel/TaskQueue.pm line 590 cPanel::TaskQueue::process_next_task(cPanel::TaskQueue=HASH(0x2110440)) called at /usr/local/cpanel/bin/cpbackup_transporter line 151 eval {...} called at /usr/local/cpanel/bin/cpbackup_transporter line 149 [2015-12-01 02:05:06 +0000] info [cpbackup_transporter] cpbackup_transporter - Checking queue for tasks [2015-12-01 02:05:06 +0000] info [cpbackup_transporter] cpbackup_transporter - Processing next task [2015-12-01 02:05:07 +0000] info [cpbackup_transporter] Starting a "copy" operation on the "Live2" destination ID "wgauWR_o7f7tThVuVPTgU2lp". [2015-12-01 02:05:07 +0000] info [cpbackup_transporter] Base path for destination is /DXLIVE3_backup [2015-12-01 02:05:07 +0000] info [cpbackup_transporter] Upload attempt #1 starting for /backup/2015-12-01/accounts/abima.tar.gz to /DXLIVE3_backup/2015-12-01/abima.tar.gz for destination: Live2 [2015-12-01 02:06:50 +0000] info [cpbackup_transporter] cpbackup_transporter - Checking queue for tasks [2015-12-01 02:06:50 +0000] info [cpbackup_transporter] cpbackup_transporter - Processing next task [2015-12-01 02:06:51 +0000] info [cpbackup_transporter] Starting a "copy" operation on the "Live2" destination ID "wgauWR_o7f7tThVuVPTgU2lp". [2015-12-01 02:06:51 +0000] info [cpbackup_transporter] Base path for destination is /DXLIVE3_backup [2015-12-01 02:06:51 +0000] info [cpbackup_transporter] Upload attempt #1 starting for /backup/2015-12-01/accounts/abima.tar.gz to /DXLIVE3_backup/monthly/2015-12-01/abima.tar.gz for destination: Live2 [2015-12-01 02:08:26 +0000] info [cpbackup_transporter] cpbackup_transporter - Checking queue for tasks [2015-12-01 02:08:26 +0000] info [cpbackup_transporter] cpbackup_transporter - Processing next task [2015-12-01 02:08:27 +0000] info [cpbackup_transporter] Starting a "prune" operation on the "Live2" destination ID "wgauWR_o7f7tThVuVPTgU2lp". [2015-12-01 02:08:27 +0000] info [cpbackup_transporter] Base path for destination is /DXLIVE3_backup [2015-12-01 02:08:27 +0000] info [cpbackup_transporter] cpbackup_transporter - Checking queue for tasks [2015-12-01 02:08:27 +0000] info [cpbackup_transporter] cpbackup_transporter - Processing next task [2015-12-01 02:08:28 +0000] info [cpbackup_transporter] Starting a "prune" operation on the "Live2" destination ID "wgauWR_o7f7tThVuVPTgU2lp". [2015-12-01 02:08:28 +0000] info [cpbackup_transporter] Base path for destination is /DXLIVE3_backup [2015-12-01 02:08:28 +0000] info [cpbackup_transporter] cpbackup_transporter - Checking queue for tasks [2015-12-01 02:08:28 +0000] info [cpbackup_transporter] cpbackup_transporter - Processing next task [2015-12-01 02:08:28 +0000] info [cpbackup_transporter] cpbackup_transporter - Checking queue for tasks [2015-12-01 02:08:28 +0000] info [cpbackup_transporter] cpbackup_transporter - Exiting - the queue has been emptied; no more work to do [2015-12-01 02:08:28 +0000] info [cpbackup_transporter] cPanel Backup Transporter Queue Daemon is being stopped.
    0
  • cPanelMichael
    Do the failed accounts in the transport logs utilize a high amount of disk space? It looks like the connection to the remote server is timing out, indicating an issue with the firewall on one of the servers. Also, increase the timeout values in "WHM >> Backup >> Backup Configuration" for the individual destination and with the "Maximum destination timeout" value. Thank you.
    0
  • Bill Hicks the third
    The 3 accounts take up 800MB, 80MB and 1Mb, which I wouldn't say is particularily large. 'Maximum destination timeout' was already set to 10,000 seconds, which seems high enough for our site-to-site connection. I've increased STFP 'Timeout' from 90 seconds to 240 seconds to see if that makes a difference. I'll report back.
    0
  • Infopro
    How were you able to make it accept 10,000 secs? The system only permits up to 300 secs.
    0
  • Bill Hicks the third
    The SFTP 'timout' setting is set to 240 and that has a limit of 300 seconds. I was talking about the 'Maximum destination timeout [] in seconds' value in Backup Configuration -> Global Settings, which needs to be between 300 and 50,000. That is the value that is set to 10,000
    0
  • Bill Hicks the third
    I have done some ping testing between servers and haven't noticed any drops during the night even during the failed ones. More importantly, we had a national campaign going on over the last few weeks which were causing massive load on the server around 9pm every night. Since this finished last week, and I changed the timeout settings; the backup has failed once which is a lot less than usual. I'm not sure why a load at 9pm would cause backups to fail when they start 5 hours later. Lets just hope the backups continue to succeed.
    0

Please sign in to leave a comment.