Filezilla: figuring out the cause of “Connection timed out after 20 seconds of inactivity”
Posted by jpluimers on 2021/07/21
On one of my Raspberry Pi boxes, somehow I could not access files over SFTP (SSH File Transfer Protocol) via FileZilla.
I would consistently get this error:
"Connection timed out after 20 seconds of inactivity"
Figuring the exact cause took a while.
TL;DR: SFTP uses an interactive non-login shell, then interprets the output from that shell. For that kind of shell, ensure few or none scripts run that output text.
These links finally got me to the cause
- [WayBack/Archive.is] filezilla “ssh” “Connection timed out after 20 seconds of inactivity” – Google Search
- [WayBack/Archive.is] “fzSftp started, protocol_version=8” “Connection timed out after 20 seconds of inactivity” – Google Search
- [WayBack/Archive.is] “fzSftp started, protocol_version=8” “Connection timed out after 20 seconds of inactivity” “Started a shell/command” – Google Search
- [WayBack] SFTP hangs after “Connected”, but not KiTTY – FileZilla Forums:
You have some faulty shell script installed on the server that displays welcome messages on non-login shells.
…
That was it! Here’s a little more details from here
- [WayBack] ssh login works but sftp doesn’t…
This error is because my shell startup file was outputting text to inform human reader! Why is this a problem?
The answer is below:
http://www.snailbook.com/faq/sftp-corruption.auto.html
- [WayBack] SSH Frequently Asked Questions
sftp and scp2 both actually work by running ssh in a subprocess, to connect to the remote host and run the file-transfer server (usually named sftp-server). For instance, the command sftp server might result in the following command being run (OpenSSH):
…
scp2/sftp and sftp-server use a special file-transfer protocol, which they speak over this SSH session. The protocol is in fact based on the same packet protocol used by SSH.
In order for this to work, the SSH session must be “clean” — that is, it must have on it only information transmitted by the programs at either end. What often happens, though, is that there are statements in either the system or per-user shell startup files on the server (.bashrc, .profile, /etc/csh.cshrc, .login, etc.) which output text messages on login, intended to be read by humans (like fortune, echo "Hi there!", etc.). Such code should only produce output on interactive logins, when there is a tty attached to standard input. If it does not make this test, it will insert these text messages where they don’t belong: in this case, polluting the protocol stream between scp2/sftp and sftp-server.
These helped me solve the cause
This solved my problem
This is what my /etc/bash.bashrc.local looked like:
# /etc/bash.bashrc.local for SUSE Linux
#
# PLEASE DO NOT CHANGE /etc/bash.bashrc There are chances that your changes
# will be lost during system upgrades. Instead use /etc/bash.bashrc.local
# for bash or /etc/ksh.kshrc.local for ksh or /etc/zsh.zshrc.local for the
# zsh or /etc/ash.ashrc.local for the plain ash bourne shell for your local
# settings, favourite global aliases, VISUAL and EDITOR variables, etc ...
. /etc/bash.aliases/_load-aliases.sh
#
# End of /etc/bash.bashrc.local
#
This is what it looks like now:
# /etc/bash.bashrc.local for SUSE Linux
#
# PLEASE DO NOT CHANGE /etc/bash.bashrc There are chances that your changes
# will be lost during system upgrades. Instead use /etc/bash.bashrc.local
# for bash or /etc/ksh.kshrc.local for ksh or /etc/zsh.zshrc.local for the
# zsh or /etc/ash.ashrc.local for the plain ash bourne shell for your local
# settings, favourite global aliases, VISUAL and EDITOR variables, etc ...
if [ "$SSH_TTY" ]
then
source /etc/bash.aliases/_load-aliases.sh
fi
#
# End of /etc/bash.bashrc.local
#
--jeroen
Status: Disconnected from server
Trace: CControlSocket::DoClose(66)
Trace: CControlSocket::ResetOperation(66)
Trace: CFileZillaEnginePrivate::ResetOperation(66)
Trace: CControlSocket::DoClose(66)
Trace: CControlSocket::DoClose(66)
Trace: CFileZillaEnginePrivate::ResetOperation(0)
Status: Connecting to 192.168.124.38...
Trace: CControlSocket::SendNextCommand()
Trace: CSftpDeleteOpData::Send() in state 0
Trace: Going to execute /Applications/FileZilla.app/Contents/MacOS/fzsftp
Response: fzSftp started, protocol_version=8
Trace: CSftpDeleteOpData::ParseResponse() in state 0
Trace: CControlSocket::SendNextCommand()
Trace: CSftpDeleteOpData::Send() in state 3
Command: open "jeroenp@192.168.124.38" 22
Trace: Connecting to 192.168.124.38 port 22
Trace: We claim version: SSH-2.0-FileZilla_3.39.0
Trace: Server version: SSH-2.0-OpenSSH_7.7
Trace: Using SSH protocol version 2
Trace: Doing ECDH key exchange with curve Curve25519 and hash SHA-256
Trace: Server also has ssh-rsa host key, but we don't know it
Trace: Host key fingerprint is:
Trace: ssh-ed25519 256 74:61:ab:6c:36:af:b6:5c:ee:7c:05:5e:a6:89:02:bb SbjJxfUHIU462/C/8lUoPrQORorrIh5senJFBeIIzMc=
Trace: Initialised AES-256 SDCTR client->server encryption
Trace: Initialised HMAC-SHA-256 client->server MAC algorithm
Trace: Initialised AES-256 SDCTR server->client encryption
Trace: Initialised HMAC-SHA-256 server->client MAC algorithm
Trace: Pageant is running. Requesting keys.
Trace: Pageant has 0 SSH-2 keys
Trace: Attempting keyboard-interactive authentication
Trace: Using keyboard-interactive authentication. inst_len: 0, num_prompts: 1
Command: Pass: *************
Trace: Access granted
Trace: Opening session as main channel
Trace: Opened main channel
Trace: Started a shell/command
Status: Connected to 192.168.124.38
Error: Connection timed out after 20 seconds of inactivity
Trace: CControlSocket::DoClose(2050)
Trace: CControlSocket::ResetOperation(2114)
Trace: CSftpDeleteOpData::Reset(2114) in state 3
Error: Could not connect to server
Trace: CFileZillaEnginePrivate::ResetOperation(2114)
Status: Waiting to retry...
Trace: CControlSocket::DoClose(66)
Trace: CControlSocket::DoClose(66)
Status: Connecting to 192.168.124.38...
Trace: CControlSocket::SendNextCommand()
Trace: CSftpDeleteOpData::Send() in state 0
Trace: Going to execute /Applications/FileZilla.app/Contents/MacOS/fzsftp
Response: fzSftp started, protocol_version=8
Trace: CSftpDeleteOpData::ParseResponse() in state 0
Trace: CControlSocket::SendNextCommand()
Trace: CSftpDeleteOpData::Send() in state 3
Command: open "jeroenp@192.168.124.38" 22
Trace: Connecting to 192.168.124.38 port 22
Trace: We claim version: SSH-2.0-FileZilla_3.39.0
Trace: Server version: SSH-2.0-OpenSSH_7.7
Trace: Using SSH protocol version 2
Trace: Doing ECDH key exchange with curve Curve25519 and hash SHA-256
Trace: Server also has ssh-rsa host key, but we don't know it
Trace: Host key fingerprint is:
Trace: ssh-ed25519 256 74:61:ab:6c:36:af:b6:5c:ee:7c:05:5e:a6:89:02:bb SbjJxfUHIU462/C/8lUoPrQORorrIh5senJFBeIIzMc=
Trace: Initialised AES-256 SDCTR client->server encryption
Trace: Initialised HMAC-SHA-256 client->server MAC algorithm
Trace: Initialised AES-256 SDCTR server->client encryption
Trace: Initialised HMAC-SHA-256 server->client MAC algorithm
Trace: Pageant is running. Requesting keys.
Trace: Pageant has 0 SSH-2 keys
Trace: Attempting keyboard-interactive authentication
Trace: Using keyboard-interactive authentication. inst_len: 0, num_prompts: 1
Command: Pass: *************
Trace: Access granted
Trace: Opening session as main channel
Trace: Opened main channel
Trace: Started a shell/command
Status: Connected to 192.168.124.38
Error: Connection timed out after 20 seconds of inactivity
Trace: CControlSocket::DoClose(2050)
Trace: CControlSocket::ResetOperation(2114)
Trace: CSftpDeleteOpData::Reset(2114) in state 3
Error: Could not connect to server
Trace: CFileZillaEnginePrivate::ResetOperation(2114)
Last login: Sun Aug 4 09:44:00 2019 from 192.168.171.24
/etc/bash.aliases ~
/etc/bash.aliases:
fatal: not a git repository: /etc/bash.aliases/../.git/modules/bash.aliases
~
/etc ~
/etc:
fatal: not a git repository (or any of the parent directories): .git
~
Started loading aliases from DIR=/etc/bash.aliases
Created alias tmux-attach-or-create-main-session=tmux new-session
More tmux and screen tips: http://www.dayid.org/comp/tm.html
detach from currently attached session tmux: ^b d OR ^b :detach screen: ^a ^d OR ^a :detach
list sessions tmux: ^b s OR tmux ls OR tmux list-sessions screen: screen -ls
Finished _various_aliases.sh apache-aliases.sh bind-named-aliases.sh certbot-aliases.sh filesystem-aliases.sh git-aliases.sh logrotate-a Finished _various_aliases.sh apache-aliases.sh bind-named-aliases.sh certbot-aliases.sh filesystem-aliases.sh git-aliases.sh logrotate-a Finished _various_aliases.sh apache-aliases.sh bind-named-aliases.sh certbot-aliases.sh filesystem-aliases.sh git-aliases.sh logrotate-a Finished _various_aliases.sh apache-aliases.sh bind-named-aliases.sh certbot-aliases.sh filesystem-aliases.sh git-aliases.sh logrotate-a Finished _various_aliases.sh apache-aliases.sh bind-named-aliases.sh certbot-aliases.sh filesystem-aliases.sh git-aliases.sh logrotate-a Finished _various_aliases.sh apache-aliases.sh bind-named-aliases.sh certbot-aliases.sh filesystem-aliases.sh git-aliases.sh logrotate-a Finished _various_aliases.sh apache-aliases.sh bind-named-aliases.sh certbot-aliases.sh filesystem-aliases.sh git-aliases.sh logrotate-a Finished _various_aliases.sh apache-aliases.sh bind-named-aliases.sh certbot-aliases.sh filesystem-aliases.sh git-aliases.sh logrotate-aliases.sh network-aliases.sh postfix-aliases.sh sendmail-aliases.sh ssh-aliases.sh ssl-aliases.sh whatismyip-hostname-aliases.sh zypper-aliases.sh
Finished loading aliases
Commented out anything in /etc/bash.bashrc.local
jeroenp@katrien
Password:
Last login: Sun Aug 4 10:06:25 2019 from 192.168.171.24
Status: Disconnected from server
Trace: CControlSocket::DoClose(66)
Trace: CControlSocket::DoClose(66)
Trace: CControlSocket::DoClose(66)
Trace: CFileZillaEnginePrivate::ResetOperation(0)
Status: Connecting to 192.168.124.38...
Trace: CControlSocket::SendNextCommand()
Trace: CSftpDeleteOpData::Send() in state 0
Trace: Going to execute /Applications/FileZilla.app/Contents/MacOS/fzsftp
Response: fzSftp started, protocol_version=8
Trace: CSftpDeleteOpData::ParseResponse() in state 0
Trace: CControlSocket::SendNextCommand()
Trace: CSftpDeleteOpData::Send() in state 3
Command: open "jeroenp@192.168.124.38" 22
Trace: Connecting to 192.168.124.38 port 22
Trace: We claim version: SSH-2.0-FileZilla_3.39.0
Trace: Server version: SSH-2.0-OpenSSH_7.7
Trace: Using SSH protocol version 2
Trace: Doing ECDH key exchange with curve Curve25519 and hash SHA-256
Trace: Server also has ssh-rsa host key, but we don't know it
Trace: Host key fingerprint is:
Trace: ssh-ed25519 256 74:61:ab:6c:36:af:b6:5c:ee:7c:05:5e:a6:89:02:bb SbjJxfUHIU462/C/8lUoPrQORorrIh5senJFBeIIzMc=
Trace: Initialised AES-256 SDCTR client->server encryption
Trace: Initialised HMAC-SHA-256 client->server MAC algorithm
Trace: Initialised AES-256 SDCTR server->client encryption
Trace: Initialised HMAC-SHA-256 server->client MAC algorithm
Trace: Pageant is running. Requesting keys.
Trace: Pageant has 0 SSH-2 keys
Trace: Attempting keyboard-interactive authentication
Trace: Using keyboard-interactive authentication. inst_len: 0, num_prompts: 1
Command: Pass: *************
Trace: Access granted
Trace: Opening session as main channel
Trace: Opened main channel
Trace: Started a shell/command
Status: Connected to 192.168.124.38
Trace: CSftpDeleteOpData::ParseResponse() in state 3
Trace: CControlSocket::ResetOperation(0)
Trace: CSftpDeleteOpData::Reset(0) in state 3
Trace: CFileZillaEnginePrivate::ResetOperation(0)
Status: Retrieving directory listing of "/home/jeroenp/Versioned/capture-192.168.124.38/fritzcap/captures"...
Trace: CControlSocket::SendNextCommand()
Trace: CSftpListOpData::Send() in state 0
Trace: CSftpChangeDirOpData::Send() in state 0
Trace: CSftpChangeDirOpData::Send() in state 2
Command: cd "/home/jeroenp/Versioned/capture-192.168.124.38/fritzcap/captures"
Response: New directory is: "/home/jeroenp/Versioned/capture-192.168.124.38/fritzcap/captures"
Trace: CSftpChangeDirOpData::ParseResponse() in state 2
Trace: CControlSocket::ResetOperation(0)
Trace: CSftpChangeDirOpData::Reset(0) in state 2
Trace: CSftpListOpData::SubcommandResult(0) in state 1
Trace: CControlSocket::SendNextCommand()
Trace: CSftpListOpData::Send() in state 2
Trace: CSftpListOpData::Send() in state 3
Command: ls
Status: Listing directory /home/jeroenp/Versioned/capture-192.168.124.38/fritzcap/captures
Listing: drwxr-xr-x 5 jeroenp users 4096 Aug 4 09:56 ..
Listing: drwxr-xr-x 2 jeroenp users 4096 Aug 4 09:27 .
Trace: CSftpListOpData::ParseResponse() in state 3
Trace: CControlSocket::ResetOperation(0)
Trace: CSftpListOpData::Reset(0) in state 3
Status: Directory listing of "/home/jeroenp/Versioned/capture-192.168.124.38/fritzcap/captures" successful
Trace: CFileZillaEnginePrivate::ResetOperation(0)
This entry was posted on 2021/07/21 at 12:00 and is filed under *nix, *nix-tools, bash, bash, Communications Development, Conference Topics, Conferences, Development, Event, Internet protocol suite, Power User, Scripting, SFTP, Software Development, SSH, TCP.
You can follow any responses to this entry through the RSS 2.0 feed.
You can leave a response, or trackback from your own site.
The Wiert Corner - irregular stream of stuff 
Leave a comment