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 [email protected]:.>')
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 [email protected]:.>')
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 [email protected]:.>')
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 [email protected]:.>')
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 [email protected]:.>')
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 [email protected]:.>')
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 [email protected]:.>')
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 [email protected]:.>')

[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).