SFTP extremely poor performance on specific account

[janipewter]

Recently I have noticed that transferring files to a certain account on my server via SFTP is extremely slow. I have tested on other accounts including root on the same server and it is fine. FTP is fine for all users.

Instead of using all 10 threads, only 1 file gets uploaded per approximately every 3-5 seconds, with a big delay between each file. The client constantly disconnects and reconnects.

Here's a snippet from FileZilla log, I have it set to 10 concurrent connections (this has never been a problem in the past). I have changed username, hostname, filenames etc.

Status:    Connecting to myserver.net:225...
Status:    Connected to myserver.net
Status:    Retrieving directory listing...
Status:    Listing directory /home/main_website
Status:    Directory listing of "/home/main_website" successful
Status:    Retrieving directory listing of "/home/main_website/webfiles"...
Status:    Listing directory /home/main_website/webfiles
Status:    Directory listing of "/home/main_website/webfiles" successful
Status:    Connecting to myserver.net:225...
Status:    Connecting to myserver.net:225...
Status:    Connecting to myserver.net:225...
Status:    Connecting to myserver.net:225...
Status:    Connecting to myserver.net:225...
Status:    Connecting to myserver.net:225...
Status:    Connecting to myserver.net:225...
Status:    Connecting to myserver.net:225...
Status:    Connecting to myserver.net:225...
Status:    Connecting to myserver.net:225...
Status:    Connected to myserver.net
Status:    Connected to myserver.net
Status:    Connected to myserver.net
Status:    Connected to myserver.net
Status:    Starting upload of C:\stuff\large\file1.JPG
Status:    Connected to myserver.net
Status:    Connected to myserver.net
Status:    Connected to myserver.net
Status:    Connected to myserver.net
Status:    Connected to myserver.net
Status:    Connected to myserver.net
Command:    cd "/home/main_website/webfiles/unio/large"
Error:    Directory /home/main_website/webfiles/unio/large: no such file or directory
Command:    cd "/home/main_website/webfiles/unio"
Error:    Directory /home/main_website/webfiles/unio: no such file or directory
Command:    cd "/home/main_website/webfiles"
Response:    New directory is: "/home/main_website/webfiles"
Command:    mkdir "unio"
Response:    mkdir /home/main_website/webfiles/unio: OK
Command:    cd "/home/main_website/webfiles/unio"
Response:    New directory is: "/home/main_website/webfiles/unio"
Command:    mkdir "large"
Response:    mkdir /home/main_website/webfiles/unio/large: OK
Command:    cd "/home/main_website/webfiles/unio/large"
Response:    New directory is: "/home/main_website/webfiles/unio/large"
Status:    Retrieving directory listing of "/home/main_website/webfiles/unio/large"...
Command:    ls
Status:    Listing directory /home/main_website/webfiles/unio/large
Command:    put "C:\stuff\large\file1.JPG" "file1.JPG"
Command:    local:C:\stuff\large\file1.JPG => remote:/home/main_website/webfiles/unio/large/file1.JPG
Status:    File transfer successful, transferred 4,391,919 bytes in 2 seconds
Status:    Starting upload of C:\stuff\large\file2.JPG
Status:    File transfer successful, transferred 4,291,563 bytes in 1 second
Status:    Starting upload of C:\stuff\large\file3.JPG
Status:    File transfer successful, transferred 4,482,194 bytes in 1 second
Status:    Starting upload of C:\stuff\large\file4.JPG
Status:    File transfer successful, transferred 4,172,979 bytes in 1 second
Status:    Starting upload of C:\stuff\large\file5
Status:    File transfer successful, transferred 5,697,753 bytes in 2 seconds
Status:    Starting upload of C:\stuff\large\file6.JPG
Status:    File transfer successful, transferred 6,789,830 bytes in 2 seconds
Status:    Starting upload of C:\stuff\large\file8.JPG
Error:    Received unexpected end-of-file from SFTP server
Error:    Could not connect to server
Status:    Disconnected from server
Status:    Delaying connection for 5 seconds due to previously failed connection attempt...
Error:    Received unexpected end-of-file from SFTP server
Error:    Could not connect to server
Status:    Disconnected from server
Status:    Delaying connection for 5 seconds due to previously failed connection attempt...
Error:    Received unexpected end-of-file from SFTP server
Error:    Could not connect to server
Status:    Disconnected from server
Status:    Delaying connection for 5 seconds due to previously failed connection attempt...
Error:    Received unexpected end-of-file from SFTP server
Error:    Could not connect to server
Status:    Disconnected from server
Status:    Delaying connection for 5 seconds due to previously failed connection attempt...
Status:    File transfer successful, transferred 4,323,751 bytes in 1 second
Status:    Starting upload of C:\stuff\large\file7.JPG
Status:    File transfer successful, transferred 4,323,751 bytes in 2 seconds
Status:    Starting upload of C:\stuff\large\file9.JPG
Status:    Delaying connection for 1 second due to previously failed connection attempt...
Status:    Delaying connection for 1 second due to previously failed connection attempt...
Status:    Delaying connection for 1 second due to previously failed connection attempt...
Status:    Connecting to myserver.net:225...
Status:    Connecting to myserver.net:225...
Status:    Connecting to myserver.net:225...
Status:    Connecting to myserver.net:225...
Status:    File transfer successful, transferred 4,356,879 bytes in 2 seconds
Status:    Starting upload of C:\stuff\large\file10.JPG
Status:    Connected to myserver.net
Status:    Connected to myserver.net
Status:    Connected to myserver.net
Status:    Connected to myserver.net

And the log from /var/log/secure

Feb 22 22:03:20 srv01 sshd[21720]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:03:21 srv01 sshd[22551]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25259 ssh2
Feb 22 22:03:21 srv01 sshd[22551]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:21 srv01 sshd[22554]: subsystem request for sftp
Feb 22 22:03:27 srv01 sshd[22596]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25270 ssh2
Feb 22 22:03:27 srv01 sshd[22596]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:27 srv01 sshd[22593]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25262 ssh2
Feb 22 22:03:27 srv01 sshd[22593]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:27 srv01 sshd[22614]: subsystem request for sftp
Feb 22 22:03:27 srv01 sshd[22595]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25263 ssh2
Feb 22 22:03:27 srv01 sshd[22600]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25271 ssh2
Feb 22 22:03:27 srv01 sshd[22617]: subsystem request for sftp
Feb 22 22:03:27 srv01 sshd[22604]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25268 ssh2
Feb 22 22:03:27 srv01 sshd[22595]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:27 srv01 sshd[22600]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:27 srv01 sshd[22606]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25269 ssh2
Feb 22 22:03:27 srv01 sshd[22604]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:27 srv01 sshd[22605]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25264 ssh2
Feb 22 22:03:27 srv01 sshd[22606]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:27 srv01 sshd[22603]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25265 ssh2
Feb 22 22:03:27 srv01 sshd[22597]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25266 ssh2
Feb 22 22:03:27 srv01 sshd[22605]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:27 srv01 sshd[22603]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:27 srv01 sshd[22597]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:27 srv01 sshd[22602]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25267 ssh2
Feb 22 22:03:27 srv01 sshd[22632]: subsystem request for sftp
Feb 22 22:03:27 srv01 sshd[22635]: subsystem request for sftp
Feb 22 22:03:27 srv01 sshd[22651]: subsystem request for sftp
Feb 22 22:03:27 srv01 sshd[22660]: subsystem request for sftp
Feb 22 22:03:27 srv01 sshd[22602]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:27 srv01 sshd[22682]: subsystem request for sftp
Feb 22 22:03:27 srv01 sshd[22684]: subsystem request for sftp
Feb 22 22:03:27 srv01 sshd[22688]: subsystem request for sftp
Feb 22 22:03:27 srv01 sshd[22709]: subsystem request for sftp
Feb 22 22:03:42 srv01 sshd[22595]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:03:42 srv01 sshd[22606]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:03:42 srv01 sshd[22605]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:03:43 srv01 sshd[22600]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:03:43 srv01 sshd[22597]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:03:49 srv01 sshd[22913]: Accepted publickey for secretuser from 77.32.202.192 port 50836 ssh2
Feb 22 22:03:49 srv01 sshd[22913]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:49 srv01 sshd[22912]: Accepted publickey for secretuser from 77.32.202.192 port 63749 ssh2
Feb 22 22:03:49 srv01 sshd[22912]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:49 srv01 sshd[22923]: subsystem request for sftp
Feb 22 22:03:49 srv01 sshd[22926]: subsystem request for sftp
Feb 22 22:03:50 srv01 sshd[22917]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25276 ssh2
Feb 22 22:03:50 srv01 sshd[22917]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:50 srv01 sshd[22918]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25274 ssh2
Feb 22 22:03:50 srv01 sshd[22916]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25275 ssh2
Feb 22 22:03:50 srv01 sshd[22918]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:50 srv01 sshd[22916]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:03:50 srv01 sshd[22984]: subsystem request for sftp
Feb 22 22:03:50 srv01 sshd[22989]: subsystem request for sftp
Feb 22 22:03:50 srv01 sshd[22988]: subsystem request for sftp
Feb 22 22:04:05 srv01 sshd[22917]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:04:05 srv01 sshd[22916]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:04:11 srv01 sshd[23044]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25279 ssh2
Feb 22 22:04:11 srv01 sshd[23045]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25278 ssh2
Feb 22 22:04:11 srv01 sshd[23044]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:04:11 srv01 sshd[23045]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:04:11 srv01 sshd[23050]: subsystem request for sftp
Feb 22 22:04:11 srv01 sshd[23052]: subsystem request for sftp
Feb 22 22:04:20 srv01 sshd[22913]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:04:20 srv01 sshd[22912]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:04:25 srv01 sshd[23096]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25283 ssh2
Feb 22 22:04:25 srv01 sshd[23097]: Accepted publickey for secretuser from 2001:aaaa:3a7c:b37:70bc:bc40:9ae4:da57 port 25284 ssh2
Feb 22 22:04:25 srv01 sshd[23096]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:04:25 srv01 sshd[23097]: pam_unix(sshd:session): session opened for user secretuser by (uid=0)
Feb 22 22:04:25 srv01 sshd[23102]: subsystem request for sftp
Feb 22 22:04:25 srv01 sshd[23104]: subsystem request for sftp
Feb 22 22:04:26 srv01 sshd[23044]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:04:27 srv01 sshd[23045]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:04:40 srv01 sshd[23096]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:05:21 srv01 sshd[22596]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:05:22 srv01 sshd[22604]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:05:22 srv01 sshd[22603]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:05:30 srv01 sshd[22593]: pam_unix(sshd:session): session closed for user secretuser
Feb 22 22:05:43 srv01 sshd[22602]: pam_unix(sshd:session): session closed for user secretuser

Any ideas?

 

[cPanelLauren]

Hi @janipewter


This really looks like a network stability issue and not something specific to cPanel. Do you see anything of note in /var/log/messages when the latency is occurring?

 

[janipewter]

Nothing in /var/log/messages

This issue has only started recently and only affects one account.

 

[cPanelLauren]

Hi @janipewter

Is this account bigger than the others? This may be something that would be best investigated in a ticket.
If you'd like to do that please open one using the link in my signature. Once open please reply with the Ticket ID here so that we can update this thread with the resolution once the ticket is resolved.


Thanks!

 

[janipewter]

The account is fairly big, it's currently around 190GB. SFTP used to work fine on this account, it is only recently it has suddenly become extremely slow. We upload about 5000 thousand files of ~120kb per week and the business is reliant on this upload being finished promptly. Using Filezilla set to 10 threads would normally crunch through the process very fast, but now it is unusable. We have fallen back to FTP for the time being

 

[cPanelLauren]

Hi @janipewter


I'd really like for our analysts to be able to look into this further if you're able to please open a ticket with us so we can troubleshoot further.


Thanks!