Still seeing sporatic LFTP timeouts that seem to lock up the thread

[quadcom]

I am seeing LFTP timeouts that seem to lock the thread so that it cannot be used again unless the service is restarted.

After a while, I have noticed that the DL speeds would cap out at a very low level.

The speeds would not resume to normal until after I restart the service.

Nothing jumps out in the logs -aside from the timeout that is.

2022/03/29 10:49:28 - ERROR - seedsync.Controller.Lftp - Lftp timeout exception Traceback (most recent call last): File "lftp/lftp.py", line 128, in run_command File "pexpect/spawnbase.py", line 343, in expect File "pexpect/spawnbase.py", line 372, in expect_list File "pexpect/expect.py", line 181, in expect_loop File "pexpect/expect.py", line 144, in timeout pexpect.exceptions.TIMEOUT: Timeout exceeded. <pexpect.pty_spawn.spawn object at 0x7f6f01dfd4c0> command: /usr/bin/lftp args: ['/usr/bin/lftp', '-p', '22', '-u', 'XXXXXXXXX,XXXXXXXXXXXXXX', 'sftp://XXXX.XXXXXXXX.XX'] buffer (last 100 chars): b' ' before (last 100 chars): b' ' after: <class 'pexpect.exceptions.TIMEOUT'> match: None match_index: None exitstatus: None flag_eof: False pid: 21081 child_fd: 28 closed: False timeout: 30 delimiter: <class 'pexpect.exceptions.EOF'> logfile: None logfile_read: None logfile_send: None maxread: 2000 ignorecase: False searchwindowsize: None delaybeforesend: 0.05 delayafterclose: 0.1 delayafterterminate: 0.1 searcher: searcher_re: 0: re.compile(b'lftp XXXX@XXXXXXXX.XX:.*>') 2022/03/29 10:49:32 - ERROR - seedsync.Controller.Lftp - Lftp timeout exception Traceback (most recent call last): File "lftp/lftp.py", line 128, in run_command File "pexpect/spawnbase.py", line 343, in expect File "pexpect/spawnbase.py", line 372, in expect_list File "pexpect/expect.py", line 181, in expect_loop File "pexpect/expect.py", line 144, in timeout pexpect.exceptions.TIMEOUT: Timeout exceeded. <pexpect.pty_spawn.spawn object at 0x7f6f01dfd4c0> command: /usr/bin/lftp args: ['/usr/bin/lftp', '-p', '22', '-u', 'XXXXXXXXX,XXXXXXXXXXXXXX', 'sftp://XXXX.XXXXXXXX.XX'] buffer (last 100 chars): b' ' before (last 100 chars): b' ' after: <class 'pexpect.exceptions.TIMEOUT'> match: None match_index: None exitstatus: None flag_eof: False pid: 21081 child_fd: 28 closed: False timeout: 30 delimiter: <class 'pexpect.exceptions.EOF'> logfile: None logfile_read: None logfile_send: None maxread: 2000 ignorecase: False searchwindowsize: None delaybeforesend: 0.05 delayafterclose: 0.1 delayafterterminate: 0.1 searcher: searcher_re: 0: re.compile(b'lftp XXXX@XXXXXXXX.XX:.>') 2022/03/29 10:50:10 - ERROR - seedsync.Controller.Lftp - Lftp timeout exception Traceback (most recent call last): File "lftp/lftp.py", line 128, in __run_command File "pexpect/spawnbase.py", line 343, in expect File "pexpect/spawnbase.py", line 372, in expect_list File "pexpect/expect.py", line 181, in expect_loop File "pexpect/expect.py", line 144, in timeout pexpect.exceptions.TIMEOUT: Timeout exceeded. <pexpect.pty_spawn.spawn object at 0x7f6f01dfd4c0> command: /usr/bin/lftp args: ['/usr/bin/lftp', '-p', '22', '-u', 'XXXXXXXXX,XXXXXXXXXXXXXX', 'sftp://XXXX.XXXXXXXX.XX'] buffer (last 100 chars): b' ' before (last 100 chars): b' ' after: <class 'pexpect.exceptions.TIMEOUT'> match: None match_index: None exitstatus: None flag_eof: False pid: 21081 child_fd: 28 closed: False timeout: 30 delimiter: <class 'pexpect.exceptions.EOF'> logfile: None logfile_read: None logfile_send: None maxread: 2000 ignorecase: False searchwindowsize: None delaybeforesend: 0.05 delayafterclose: 0.1 delayafterterminate: 0.1 searcher: searcher_re: 0: re.compile(b'lftp XXXX@XXXXXXXX.XX:.>') 2022/03/29 10:50:14 - ERROR - seedsync.Controller.Lftp - Lftp timeout exception Traceback (most recent call last): File "lftp/lftp.py", line 128, in run_command File "pexpect/spawnbase.py", line 343, in expect File "pexpect/spawnbase.py", line 372, in expect_list File "pexpect/expect.py", line 181, in expect_loop File "pexpect/expect.py", line 144, in timeout pexpect.exceptions.TIMEOUT: Timeout exceeded. <pexpect.pty_spawn.spawn object at 0x7f6f01dfd4c0> command: /usr/bin/lftp args: ['/usr/bin/lftp', '-p', '22', '-u', 'XXXXXXXXX,XXXXXXXXXXXXXX', 'sftp://XXXX.XXXXXXXX.XX'] buffer (last 100 chars): b' ' before (last 100 chars): b' ' after: <class 'pexpect.exceptions.TIMEOUT'> match: None match_index: None exitstatus: None flag_eof: False pid: 21081 child_fd: 28 closed: False timeout: 30 delimiter: <class 'pexpect.exceptions.EOF'> logfile: None logfile_read: None logfile_send: None maxread: 2000 ignorecase: False searchwindowsize: None delaybeforesend: 0.05 delayafterclose: 0.1 delayafterterminate: 0.1 searcher: searcher_re: 0: re.compile(b'lftp XXXX@XXXXXXXX.XX:.*>') 2022/03/29 10:50:17 - ERROR - seedsync.Controller.Lftp - Lftp timeout exception Traceback (most recent call last): File "lftp/lftp.py", line 128, in run_command File "pexpect/spawnbase.py", line 343, in expect File "pexpect/spawnbase.py", line 372, in expect_list File "pexpect/expect.py", line 181, in expect_loop File "pexpect/expect.py", line 144, in timeout pexpect.exceptions.TIMEOUT: Timeout exceeded. <pexpect.pty_spawn.spawn object at 0x7f6f01dfd4c0> command: /usr/bin/lftp args: ['/usr/bin/lftp', '-p', '22', '-u', 'XXXXXXXXX,XXXXXXXXXXXXXX', 'sftp://XXXX.XXXXXXXX.XX'] buffer (last 100 chars): b' ' before (last 100 chars): b' ' after: <class 'pexpect.exceptions.TIMEOUT'> match: None match_index: None exitstatus: None flag_eof: False pid: 21081 child_fd: 28 closed: False timeout: 30 delimiter: <class 'pexpect.exceptions.EOF'> logfile: None logfile_read: None logfile_send: None maxread: 2000 ignorecase: False searchwindowsize: None delaybeforesend: 0.05 delayafterclose: 0.1 delayafterterminate: 0.1 searcher: searcher_re: 0: re.compile(b'lftp XXXX@XXXXXXXX.XX:.>') 2022/03/29 10:50:56 - ERROR - seedsync.Controller.Lftp - Lftp timeout exception Traceback (most recent call last): File "lftp/lftp.py", line 128, in __run_command File "pexpect/spawnbase.py", line 343, in expect File "pexpect/spawnbase.py", line 372, in expect_list File "pexpect/expect.py", line 181, in expect_loop File "pexpect/expect.py", line 144, in timeout pexpect.exceptions.TIMEOUT: Timeout exceeded. <pexpect.pty_spawn.spawn object at 0x7f6f01dfd4c0> command: /usr/bin/lftp args: ['/usr/bin/lftp', '-p', '22', '-u', 'XXXXXXXXX,XXXXXXXXXXXXXX', 'sftp://XXXX.XXXXXXXX.XX'] buffer (last 100 chars): b' ' before (last 100 chars): b' ' after: <class 'pexpect.exceptions.TIMEOUT'> match: None match_index: None exitstatus: None flag_eof: False pid: 21081 child_fd: 28 closed: False timeout: 30 delimiter: <class 'pexpect.exceptions.EOF'> logfile: None logfile_read: None logfile_send: None maxread: 2000 ignorecase: False searchwindowsize: None delaybeforesend: 0.05 delayafterclose: 0.1 delayafterterminate: 0.1 searcher: searcher_re: 0: re.compile(b'lftp XXXX@XXXXXXXX.XX:.>') 2022/03/29 10:50:59 - ERROR - seedsync.Controller.Lftp - Lftp timeout exception Traceback (most recent call last): File "lftp/lftp.py", line 128, in run_command File "pexpect/spawnbase.py", line 343, in expect File "pexpect/spawnbase.py", line 372, in expect_list File "pexpect/expect.py", line 181, in expect_loop File "pexpect/expect.py", line 144, in timeout pexpect.exceptions.TIMEOUT: Timeout exceeded. <pexpect.pty_spawn.spawn object at 0x7f6f01dfd4c0> command: /usr/bin/lftp args: ['/usr/bin/lftp', '-p', '22', '-u', 'XXXXXXXXX,XXXXXXXXXXXXXX', 'sftp://XXXX.XXXXXXXX.XX'] buffer (last 100 chars): b' ' before (last 100 chars): b' ' after: <class 'pexpect.exceptions.TIMEOUT'> match: None match_index: None exitstatus: None flag_eof: False pid: 21081 child_fd: 28 closed: False timeout: 30 delimiter: <class 'pexpect.exceptions.EOF'> logfile: None logfile_read: None logfile_send: None maxread: 2000 ignorecase: False searchwindowsize: None delaybeforesend: 0.05 delayafterclose: 0.1 delayafterterminate: 0.1 searcher: searcher_re: 0: re.compile(b'lftp XXXX@XXXXXXXX.XX:.*>') 2022/03/29 10:51:03 - ERROR - seedsync.Controller.Lftp - Lftp timeout exception Traceback (most recent call last): File "lftp/lftp.py", line 128, in run_command File "pexpect/spawnbase.py", line 343, in expect File "pexpect/spawnbase.py", line 372, in expect_list File "pexpect/expect.py", line 181, in expect_loop File "pexpect/expect.py", line 144, in timeout pexpect.exceptions.TIMEOUT: Timeout exceeded. <pexpect.pty_spawn.spawn object at 0x7f6f01dfd4c0> command: /usr/bin/lftp args: ['/usr/bin/lftp', '-p', '22', '-u', 'XXXXXXXXX,XXXXXXXXXXXXXX', 'sftp://XXXX.XXXXXXXX.XX'] buffer (last 100 chars): b' jobs -v\r\n' before (last 100 chars): b' jobs -v\r\n' after: <class 'pexpect.exceptions.TIMEOUT'> match: None match_index: None exitstatus: None flag_eof: False pid: 21081 child_fd: 28 closed: False timeout: 30 delimiter: <class 'pexpect.exceptions.EOF'> logfile: None logfile_read: None logfile_send: None maxread: 2000 ignorecase: False searchwindowsize: None delaybeforesend: 0.05 delayafterclose: 0.1 delayafterterminate: 0.1 searcher: searcher_re: 0: re.compile(b'lftp XXXX@XXXXXXXX.XX:.*>')

[ndmartin2015]

I'm having these issues. It takes like 4-5 attempts to start a download and half of the time I need to restart the service.

[quadcom]

I happened across an article that referred to LFTP default settings. In there are timeouts and retries settings.

It would be great to have access to those settings. I tried editing the etc/lftp.conf file but there is no nano or vim installed and I am unable to install those on the Docker container. I also am unable to so anything sudo as sudo does not exist.

There was an article that apparently explained how to add sudo to a docker container but my brain broke trying to figure it out.

But, adding vars to account for the LFTP settings or, exposing the conf file in the containers persistent settings would be an awesome addition to help tweak LFTP.

https://askubuntu.com/questions/1012006/lftp-default-timeout-and-retry

[quadcom]

Here is the complete list of default LFTP settings in the system

lftp :~> set -d set bmk:auto-sync yes set bmk:save-passwords no set cache:cache-empty-listings no set cache:enable yes set cache:expire 60m set cache:expire-negative 1m set cache:size 16M set cmd:at-background "" set cmd:at-exit "" set cmd:at-exit-bg "" set cmd:at-exit-fg "" set cmd:at-finish "" set cmd:at-queue-finish "" set cmd:at-terminate "" set cmd:cls-completion-default -FBa set cmd:cls-default -F set cmd:cls-exact-time yes set cmd:csh-history off set cmd:default-protocol ftp set cmd:default-title "lftp \h:\w" set cmd:fail-exit no set cmd:interactive auto set cmd:long-running 30 set cmd:ls-default "" set cmd:move-background yes set cmd:move-background-detach yes set cmd:nullglob yes set cmd:parallel 1 set cmd:prompt "lftp \S\? \u\@\h:\w> " set cmd:queue-parallel 1 set cmd:remote-completion on set cmd:save-cwd-history yes set cmd:save-rl-history yes set cmd:set-term-status no set cmd:show-status yes set cmd:status-interval 0.8s set cmd:stifle-rl-history 500 set cmd:term-status "" set cmd:time-style "%b %e %Y|%b %e %H:%M" set cmd:trace no set cmd:verbose no set cmd:verify-host yes set cmd:verify-path yes set cmd:verify-path-cached no set color:dir-colors "" set color:use-color auto set dns:SRV-query no set dns:cache-enable yes set dns:cache-expire 1h set dns:cache-size 256 set dns:fatal-timeout 7d set dns:max-retries 1000 set dns:name "" set dns:order "inet6 inet" set dns:use-fork yes set file:charset "" set file:use-fallocate yes set file:use-lock no set fish:auto-confirm no set fish:charset "" set fish:connect-program "ssh -a -x" set fish:shell /bin/sh set ftp:abor-max-wait 15s set ftp:acct "" set ftp:anon-pass lftp@ set ftp:anon-user anonymous set ftp:auto-passive-mode yes set ftp:auto-sync-mode "" set ftp:bind-data-socket yes set ftp:catch-size yes set ftp:charset "" set ftp:client lftp/4.8.4 set ftp:compressed-re "\.(bz2|[glrsx7]z|lzma|lz[hox]|[ai]ce|apk|ar[cj]|cab|cfs|dar|[je]ar|lha|isz|pak|rar|sitx?|t(gz|bz2|lz)|tar\.(gz|xz|bz2|lzma)|war|zipx?|zoo|[arz0][0-9][0-9])$" set ftp:device-prefix no set ftp:fix-pasv-address yes set ftp:fxp-force no set ftp:fxp-passive-source no set ftp:fxp-passive-sscn yes set ftp:home "" set ftp:ignore-pasv-address no set ftp:lang "" set ftp:list-empty-ok no set ftp:list-options "" set ftp:mode-z-level 6 set ftp:netkey-allow yes set ftp:nop-interval 120 set ftp:passive-mode on set ftp:port-ipv4 "" set ftp:port-range full set ftp:prefer-epsv no set ftp:proxy "" set ftp:proxy-auth-type user set ftp:rest-list no set ftp:rest-stor yes set ftp:retry-530 "too many|overloaded|try (again |back )?later|is restricted to|maximum number|number of connect|only.session.allowed|more connection|already connected|simultaneous login" set ftp:retry-530-anonymous "Login incorrect" set ftp:site (nil) set ftp:site-group "" set ftp:skey-allow yes set ftp:skey-force no set ftp:ssl-allow yes set ftp:ssl-allow-anonymous no set ftp:ssl-auth TLS set ftp:ssl-copy-sid yes set ftp:ssl-data-use-keys yes set ftp:ssl-force no set ftp:ssl-protect-data no set ftp:ssl-protect-fxp no set ftp:ssl-protect-list yes set ftp:ssl-shutdown-timeout 5 set ftp:ssl-use-ccc no set ftp:stat-interval 1 set ftp:strict-multiline off set ftp:sync-mode on set ftp:timezone GMT set ftp:too-many-re "(Too many|No more) connections" set ftp:trust-feat no set ftp:use-abor yes set ftp:use-allo yes set ftp:use-feat yes set ftp:use-fxp yes set ftp:use-hftp yes set ftp:use-ip-tos no set ftp:use-mdtm yes set ftp:use-mdtm-overloaded no set ftp:use-mlsd yes set ftp:use-mode-z yes set ftp:use-pret yes set ftp:use-quit yes set ftp:use-site-chmod yes set ftp:use-site-idle no set ftp:use-site-utime yes set ftp:use-site-utime2 yes set ftp:use-size yes set ftp:use-stat yes set ftp:use-stat-for-list no set ftp:use-telnet-iac yes set ftp:use-tvfs auto set ftp:use-utf8 yes set ftp:verify-address no set ftp:verify-port no set ftp:waiting-150-timeout 5 set ftp:web-mode off set ftps:initial-prot "" set hftp:cache yes set hftp:cache-control "" set hftp:decode no set hftp:proxy "" set hftp:use-allprop no set hftp:use-authorization yes set hftp:use-head yes set hftp:use-mkcol no set hftp:use-propfind no set hftp:use-range yes set hftp:use-type yes set http:accept / set http:accept-charset "" set http:accept-encoding "" set http:accept-language "" set http:authorization "" set http:cache yes set http:cache-control "" set http:cookie "" set http:decode yes set http:post-content-type application/x-www-form-urlencoded set http:proxy "" set http:put-content-type "" set http:put-method PUT set http:referer "" set http:set-cookies no set http:use-allprop no set http:use-mkcol yes set http:use-propfind no set http:use-range yes set http:user-agent lftp/4.8.4 set https:proxy "" set log:enabled no set log:file "" set log:level 9 set log:max-size 1M set log:prefix-error "*** " set log:prefix-note "---- " set log:prefix-recv "<--- " set log:prefix-send "---> " set log:show-ctx no set log:show-pid no set log:show-time no set mirror:dereference no set mirror:exclude-regex "(^|/)(\.in\.|\.nfs)" set mirror:include-regex "" set mirror:no-empty-dirs no set mirror:order ".sfv .sig .md5 .sum /" set mirror:overwrite no set mirror:parallel-directories yes set mirror:parallel-transfer-count 0 set mirror:require-source no set mirror:set-permissions yes set mirror:skip-noaccess no set mirror:sort-by name set mirror:use-pget-n 0 set module:path /usr/lib/lftp/4.8.4:/usr/lib/lftp set net:connection-limit 0 set net:connection-limit-timer 5m set net:connection-takeover yes set net:idle 3m set net:limit-max 0 set net:limit-rate 0:0 set net:limit-total-max 0 set net:limit-total-rate 0:0 set net:max-retries 1000 set net:no-proxy "" set net:persist-retries 0 set net:reconnect-interval-base 30 set net:reconnect-interval-max 600 set net:reconnect-interval-multiplier 1.5 set net:socket-bind-ipv4 "" set net:socket-bind-ipv6 "" set net:socket-buffer 0 set net:socket-maxseg 0 set net:timeout 5m set pget:default-n 5 set pget:min-chunk-size 1M set pget:save-status 10s set sftp:auto-confirm no set sftp:charset "" set sftp:connect-program "ssh -a -x" set sftp:max-packets-in-flight 16 set sftp:protocol-version 6 set sftp:server-program sftp set sftp:size-read 32k set sftp:size-write 32k set sftp:use-full-path yes set ssl:ca-file "" set ssl:cert-file "" set ssl:check-hostname yes set ssl:crl-file "" set ssl:key-file "" set ssl:priority "" set ssl:use-sni yes set ssl:verify-certificate yes set torrent:ip "" set torrent:ipv6 "" set torrent:max-peers 60 set torrent:port-range 6881-6889 set torrent:retracker "" set torrent:save-metadata yes set torrent:seed-max-time 30d set torrent:seed-min-peers 3 set torrent:stop-min-ppr 1.4 set torrent:stop-on-ratio 2.0 set torrent:timeout 7d set torrent:use-dht yes set xfer:auto-rename no set xfer:backup-suffix ~%Y%m%d%H%M%S~ set xfer:buffer-size 0x10000 set xfer:clobber no set xfer:destination-directory "" set xfer:disk-full-fatal no set xfer:eta-period 120 set xfer:eta-terse yes set xfer:keep-backup no set xfer:make-backup yes set xfer:max-redirections 5 set xfer:parallel 1 set xfer:rate-period 15 set xfer:temp-file-name .in.* set xfer:timeout 1d set xfer:use-temp-file no set xfer:verify no set xfer:verify-command ""

[quadcom]

Some things that stuck out to me

set net:idle 3m -

This will time out a connection with no traffic after 3 minutes. That might be a bit long.

set net:max-retries 1000 -

This will cap how many times it will retry a transfer. While 1000 seems like it would be sufficient, I wonder if this limit gets hit and if the LFTP service is still running, that count might be getting stuck. That's why a restart of the service seems to open things back up again.

set net:reconnect-interval-base 30 set net:reconnect-interval-max 600 set net:reconnect-interval-multiplier 1.5

These values are in seconds (aside from the multiplier). The service will wait to reconnect after 30 seconds. After each subsequent failure to connect it will apply the multiplier to the current interval value, assign the result to the current reconnect time period and try again. If it fails again, the multiplier is used to calculate the next new reconnect time period. Up to the maximum reconnect time period which is set to 600 seconds. This to me seems a bit too long across the board. For a server to take 30 seconds to respond means there are other problems. Connections should be measured in milliseconds, not seconds.

set net:timeout 5m

Sets the network protocol timeout, in this case SFTP. 5 minutes is an eternity for a server to wait for a command, especially so for an automated system like Seedsync. This should be much much shorter.

The thought I had with most of these settings is if these statistics are persisted when the service is started up. If that's the case, then hitting the max on timeouts and retries would mean the server never recovers lost threads and dropped connections.

Perhaps the Seedsync UI, the scanner and LFTP need to be separate services. When the scanner detects changes on the server it starts up LFTP and starts transfers. Each queued item in the list, once completed, would shut down and restart the LFTP service for the next queued item so that the stats are cleared each time a new download starts. I know that this would kill simultaneous file downloads, but, each file downloaded would get all of the threads meaning each file would download faster. We are, after all, limited to the bandwidth our ISPs provide us. Whether you are downloading 1 file or 5 files at once, the bandwidth is spread across all downloads. Why not just get each individual file faster? That is actually how my config is set up. I always had corruption issues when I had it set to download multiple files at once.

Just a thought (and a hope).