Ssh works as always, but sftp and scp don't

General
#1

I have always used ssh to connect to my trusty XA2, now updated several times up to 4.3.0.15.
And why stop at ssh command line - sftp and scp used to work just as well, no need to use MTP.
And I could do it all over WIFI.

Now only ssh works anymore. I suspect this happened after the latest update but can’t be 100% sure. It has been going on for many many days now, and I have spent countless hours debugging…

The only customization I made in /etc/ssh/sshd_config was to disable password login and enforce keys.

Short version:

It looks like any sftp or scp connection is succesful, but gets immediately closed by the phones’ system again, for no apparent reason, and afaics without any sort of error code either. Both sides then terminate the connection thinking that’s as it should be.

Long version:

verbose output for
scp -v xa2:/home/nemo/Pictures/Camera/* .
followed by output of
journalctl -b -f | grep -v 'kernel:':

Executing: program /usr/bin/ssh host xa2, user (unspecified), command scp -v -f /home/nemo/Pictures/Camera/*
OpenSSH_8.9p1, OpenSSL 1.1.1n  15 Mar 2022
debug1: Reading configuration data /home/ohnonot/.ssh/config
debug1: /home/ohnonot/.ssh/config line 44: Applying options for xa2
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Connecting to 192.168.0.16 [192.168.0.16] port 22.
debug1: Connection established.
debug1: identity file /home/ohnonot/.ssh/key-id-ed25519 type 3
debug1: identity file /home/ohnonot/.ssh/key-id-ed25519-cert type -1
debug1: Local version string SSH-2.0-OpenSSH_8.9
debug1: Remote protocol version 2.0, remote software version OpenSSH_8.0
debug1: compat_banner: match: OpenSSH_8.0 pat OpenSSH* compat 0x04000000
debug1: Authenticating to 192.168.0.16:22 as 'nemo'
debug1: load_hostkeys: fopen /home/ohnonot/.ssh/known_hosts2: No such file or directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts: No such file or directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts2: No such file or directory
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: algorithm: curve25519-sha256
debug1: kex: host key algorithm: ssh-ed25519
debug1: kex: server->client cipher: aes128-ctr MAC: umac-64-etm@openssh.com compression: zlib@openssh.com
debug1: kex: client->server cipher: aes128-ctr MAC: umac-64-etm@openssh.com compression: zlib@openssh.com
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: SSH2_MSG_KEX_ECDH_REPLY received
debug1: Server host key: ssh-ed25519 SHA256:XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
debug1: load_hostkeys: fopen /home/ohnonot/.ssh/known_hosts2: No such file or directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts: No such file or directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts2: No such file or directory
debug1: Host '192.168.0.16' is known and matches the ED25519 host key.
debug1: Found key in /home/ohnonot/.ssh/known_hosts:20
debug1: rekey out after 4294967296 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug1: rekey in after 4294967296 blocks
debug1: get_agent_identities: bound agent to hostkey
debug1: get_agent_identities: agent returned 3 keys
debug1: Will attempt key: /home/ohnonot/.ssh/key-id-ed25519 ED25519 SHA256:XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX explicit agent
debug1: SSH2_MSG_EXT_INFO received
debug1: kex_input_ext_info: server-sig-algs=<ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521>
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: publickey
debug1: Next authentication method: publickey
debug1: Offering public key: /home/ohnonot/.ssh/key-id-ed25519 ED25519 SHA256:XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX explicit agent
debug1: Server accepts key: /home/ohnonot/.ssh/key-id-ed25519 ED25519 SHA256:XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX explicit agent
debug1: Enabling compression at level 6.
Authenticated to 192.168.0.16 ([192.168.0.16]:22) using "publickey".
debug1: channel 0: new [client-session]
debug1: Requesting no-more-sessions@openssh.com
debug1: Entering interactive session.
debug1: pledge: filesystem
debug1: client_input_global_request: rtype hostkeys-00@openssh.com want_reply 0
debug1: client_input_hostkeys: searching /home/ohnonot/.ssh/known_hosts for 192.168.0.16 / (none)
debug1: client_input_hostkeys: searching /home/ohnonot/.ssh/known_hosts2 for 192.168.0.16 / (none)
debug1: client_input_hostkeys: hostkeys file /home/ohnonot/.ssh/known_hosts2 does not exist
debug1: client_input_hostkeys: no new or deprecated keys from server
debug1: Remote: /home/nemo/.ssh/authorized_keys:3: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
debug1: Remote: /home/nemo/.ssh/authorized_keys:3: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
debug1: Sending command: scp -v -f /home/nemo/Pictures/Camera/*
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug1: client_input_channel_req: channel 0 rtype eow@openssh.com reply 0
debug1: channel 0: free: client-session, nchannels 1
Transferred: sent 2248, received 2356 bytes, in 0.1 seconds
Bytes per second: sent 21187.1, received 22205.0
debug1: Exit status 0
debug1: compress outgoing: raw data 162, compressed 149, factor 0.92
debug1: compress incoming: raw data 820, compressed 663, factor 0.81

Mar 19 20:38:39 XperiaXA2-DualSIM sshd[23254]: Accepted publickey for nemo from 192.168.0.10 port 35504 ssh2: ED25519 SHA256:XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
Mar 19 20:38:39 XperiaXA2-DualSIM sshd[23254]: pam_systemd(sshd:session): Using 600s D-Bus method call timeout
Mar 19 20:38:39 XperiaXA2-DualSIM systemd[1]: Started Session c17 of user nemo.
Mar 19 20:38:39 XperiaXA2-DualSIM systemd-logind[2900]: New session c17 of user nemo.
Mar 19 20:38:39 XperiaXA2-DualSIM sshd[23254]: pam_unix(sshd:session): session opened for user nemo by (uid=0)
Mar 19 20:38:39 XperiaXA2-DualSIM sshd[23259]: Received disconnect from 192.168.0.10 port 35504:11: disconnected by user
Mar 19 20:38:39 XperiaXA2-DualSIM sshd[23259]: Disconnected from user nemo 192.168.0.10 port 35504
Mar 19 20:38:39 XperiaXA2-DualSIM sshd[23254]: pam_unix(sshd:session): session closed for user nemo
Mar 19 20:38:39 XperiaXA2-DualSIM systemd-logind[2900]: Removed session c17.

###########################################

verbose output for
sshfs -d -C -o "follow_symlinks,ServerAliveInterval=15,reconnect,IdentitiesOnly=yes,IdentityFile=/home/mus/.ssh/key-id-ed25519,LogLevel=DEBUG" nemo@192.168.0.16:/home/nemo .
followed by output of
journalctl -b -f | grep -v 'kernel:':

FUSE library version: 2.9.9
nullpath_ok: 0
nopath: 0
utime_omit_ok: 0
debug1: Reading configuration data /home/ohnonot/.ssh/config
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: /etc/ssh/ssh_config line 19: Applying options for *
debug1: Connecting to 192.168.0.16 [192.168.0.16] port 22.
debug1: Connection established.
debug1: identity file /home/ohnonot/.ssh/key-id-ed25519 type -1
debug1: identity file /home/ohnonot/.ssh/key-id-ed25519-cert type -1
debug1: Local version string SSH-2.0-OpenSSH_7.9p1 Debian-10+deb10u2
debug1: Remote protocol version 2.0, remote software version OpenSSH_8.0
debug1: match: OpenSSH_8.0 pat OpenSSH* compat 0x04000000
debug1: Authenticating to 192.168.0.16:22 as 'nemo'
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: algorithm: curve25519-sha256
debug1: kex: host key algorithm: ssh-ed25519
debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: zlib@openssh.com
debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: zlib@openssh.com
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: Server host key: ssh-ed25519 SHA256:XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
debug1: Host '192.168.0.16' is known and matches the ED25519 host key.
debug1: Found key in /home/ohnonot/.ssh/known_hosts:5
debug1: rekey after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug1: rekey after 134217728 blocks
debug1: Will attempt key: /home/ohnonot/.ssh/key-id-ed25519  explicit
debug1: SSH2_MSG_EXT_INFO received
debug1: kex_input_ext_info: server-sig-algs=<ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521>
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: publickey
debug1: Next authentication method: publickey
debug1: Trying private key: /home/ohnonot/.ssh/key-id-ed25519
Enter passphrase for key '/home/ohnonot/.ssh/key-id-ed25519':
debug1: Enabling compression at level 6.
debug1: Authentication succeeded (publickey).
Authenticated to 192.168.0.16 ([192.168.0.16]:22).
debug1: channel 0: new [client-session]
debug1: Requesting no-more-sessions@openssh.com
debug1: Entering interactive session.
debug1: pledge: network
debug1: client_input_global_request: rtype hostkeys-00@openssh.com want_reply 0
debug1: Remote: /home/nemo/.ssh/authorized_keys:3: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
debug1: Sending environment.
debug1: Sending env LANG = en_IE.UTF-8
debug1: Sending subsystem: sftp
debug1: client_input_channel_req: channel 0 rtype exit-status reply 0
debug1: client_input_channel_req: channel 0 rtype eow@openssh.com reply 0
debug1: channel 0: free: client-session, nchannels 1
debug1: fd 0 clearing O_NONBLOCK
Transferred: sent 1984, received 2268 bytes, in 0.3 seconds
Bytes per second: sent 7573.7, received 8657.9
debug1: Exit status 0
debug1: compress outgoing: raw data 177, compressed 151, factor 0.85
debug1: compress incoming: raw data 703, compressed 658, factor 0.94
remote host has disconnected

Mar 19 20:46:37 XperiaXA2-DualSIM sshd[26002]: Accepted publickey for nemo from 192.168.0.11 port 43752 ssh2: ED25519 SHA256:XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
Mar 19 20:46:37 XperiaXA2-DualSIM sshd[26002]: pam_systemd(sshd:session): Using 600s D-Bus method call timeout
Mar 19 20:46:37 XperiaXA2-DualSIM systemd-logind[2900]: New session c19 of user nemo.
Mar 19 20:46:37 XperiaXA2-DualSIM systemd[1]: Started Session c19 of user nemo.
Mar 19 20:46:37 XperiaXA2-DualSIM sshd[26002]: pam_unix(sshd:session): session opened for user nemo by (uid=0)
Mar 19 20:46:37 XperiaXA2-DualSIM sshd[26041]: Received disconnect from 192.168.0.11 port 43752:11: disconnected by user
Mar 19 20:46:37 XperiaXA2-DualSIM sshd[26041]: Disconnected from user nemo 192.168.0.11 port 43752
Mar 19 20:46:37 XperiaXA2-DualSIM sshd[26002]: pam_unix(sshd:session): session closed for user nemo
Mar 19 20:46:37 XperiaXA2-DualSIM systemd-logind[2900]: Removed session c19.

Comparison: a healthy ssh connection

ssh -v xa2
OpenSSH_8.9p1, OpenSSL 1.1.1n  15 Mar 2022
debug1: Reading configuration data /home/ohnonot/.ssh/config
debug1: /home/ohnonot/.ssh/config line 44: Applying options for xa2
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Connecting to 192.168.0.16 [192.168.0.16] port 22.
debug1: Connection established.
debug1: identity file /home/ohnonot/.ssh/key-id-ed25519 type 3
debug1: identity file /home/ohnonot/.ssh/key-id-ed25519-cert type -1
debug1: Local version string SSH-2.0-OpenSSH_8.9
debug1: Remote protocol version 2.0, remote software version OpenSSH_8.0
debug1: compat_banner: match: OpenSSH_8.0 pat OpenSSH* compat 0x04000000
debug1: Authenticating to 192.168.0.16:22 as 'nemo'
debug1: load_hostkeys: fopen /home/ohnonot/.ssh/known_hosts2: No such file or directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts: No such file or directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts2: No such file or directory
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: algorithm: curve25519-sha256
debug1: kex: host key algorithm: ssh-ed25519
debug1: kex: server->client cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: zlib@openssh.com
debug1: kex: client->server cipher: chacha20-poly1305@openssh.com MAC: <implicit> compression: zlib@openssh.com
debug1: expecting SSH2_MSG_KEX_ECDH_REPLY
debug1: SSH2_MSG_KEX_ECDH_REPLY received
debug1: Server host key: ssh-ed25519 SHA256:XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
debug1: load_hostkeys: fopen /home/ohnonot/.ssh/known_hosts2: No such file or directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts: No such file or directory
debug1: load_hostkeys: fopen /etc/ssh/ssh_known_hosts2: No such file or directory
debug1: Host '192.168.0.16' is known and matches the ED25519 host key.
debug1: Found key in /home/ohnonot/.ssh/known_hosts:20
debug1: rekey out after 134217728 blocks
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug1: rekey in after 134217728 blocks
debug1: get_agent_identities: bound agent to hostkey
debug1: get_agent_identities: agent returned 3 keys
debug1: Will attempt key: /home/ohnonot/.ssh/key-id-ed25519 ED25519 SHA256:XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX explicit agent
debug1: SSH2_MSG_EXT_INFO received
debug1: kex_input_ext_info: server-sig-algs=<ssh-ed25519,ssh-rsa,rsa-sha2-256,rsa-sha2-512,ssh-dss,ecdsa-sha2-nistp256,ecdsa-sha2-nistp384,ecdsa-sha2-nistp521>
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: publickey
debug1: Next authentication method: publickey
debug1: Offering public key: /home/ohnonot/.ssh/key-id-ed25519 ED25519 SHA256:XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX explicit agent
debug1: Server accepts key: /home/ohnonot/.ssh/key-id-ed25519 ED25519 SHA256:XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX explicit agent
debug1: Enabling compression at level 6.
Authenticated to 192.168.0.16 ([192.168.0.16]:22) using "publickey".
debug1: channel 0: new [client-session]
debug1: Requesting no-more-sessions@openssh.com
debug1: Entering interactive session.
debug1: pledge: filesystem
debug1: client_input_global_request: rtype hostkeys-00@openssh.com want_reply 0
debug1: client_input_hostkeys: searching /home/ohnonot/.ssh/known_hosts for 192.168.0.16 / (none)
debug1: client_input_hostkeys: searching /home/ohnonot/.ssh/known_hosts2 for 192.168.0.16 / (none)
debug1: client_input_hostkeys: hostkeys file /home/ohnonot/.ssh/known_hosts2 does not exist
debug1: client_input_hostkeys: no new or deprecated keys from server
debug1: Remote: /home/nemo/.ssh/authorized_keys:3: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
debug1: Remote: /home/nemo/.ssh/authorized_keys:3: key options: agent-forwarding port-forwarding pty user-rc x11-forwarding
Last login: Sat Mar 19 20:14:02 2022 from 192.168.0.11
,---
| Sailfish OS 4.3.0.15 (Suomenlinna)
'---
XperiaXA2  nemo ~

According journalctl output on phone:

Mar 19 20:52:22 XperiaXA2-DualSIM sshd[27629]: Accepted publickey for nemo from 192.168.0.10 port 35506 ssh2: ED25519 SHA256:XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
Mar 19 20:52:22 XperiaXA2-DualSIM sshd[27629]: pam_systemd(sshd:session): Using 600s D-Bus method call timeout
Mar 19 20:52:22 XperiaXA2-DualSIM systemd[1]: Started Session c20 of user nemo.
Mar 19 20:52:22 XperiaXA2-DualSIM systemd-logind[2900]: New session c20 of user nemo.
Mar 19 20:52:22 XperiaXA2-DualSIM sshd[27629]: pam_unix(sshd:session): session opened for user nemo by (uid=0)
1 Like
#2

scp phone desktop works for me (so, fetching from phone sitting on a desktop, login to defaultuser). XA2 H4113, 4.4.0.58

1 Like
#3

What is the symptom that is telling you that the sftp or scp connection doesn’t work? The logs look like it transfered data, finished and then closed the connection.

#4

On my devices (Tablet, Gemini PDA, …), all with version 4.3, scp works. I use it with rsync and ssh-keys (not with password) …

#5

Good point.
sftp: sshfs should fuse-mount the XA2 home folder locally - it doesn’t. There’s no error code, it just isn’t mounted.
scp: I know there are files in the folder I am trying to transfer files from, but nothing is transferred.

These both used to work flawlessly for years.

The behaviour is identical on another machine with a very different OS (Debian oldstable vs. ArchLinux).

I have a vague suspicion that I messed up my /etc/ssh/sshd_config in a very specific way, resulting in some sort of firewall/watchdog/authentication thingy blocking these things on the phone side so that it allows incoming ssh connections, but not scp or sftp - or both.
I would like to get hold of the original /etc/ssh/sshd_config, I fear I might not have it anymore.

#6

I also tried rsync. It doesn’t copy anything either, but so far it’s the only one that sees something is wrong:

$> rsync -e ssh -vvv -r nemo@192.168.0.16:/home/nemo/Pictures/Camera .
opening connection using: ssh -l nemo 192.168.0.16 rsync --server --sender -vvvre.iLsfxCIvu . /home/nemo/Pictures/Camera  (10 args)
rsync: connection unexpectedly closed (0 bytes received so far) [Receiver]
rsync error: error in rsync protocol data stream (code 12) at io.c(228) [Receiver=v3.2.3]
[Receiver] _exit_cleanup(code=12, file=io.c, line=228): about to call exit(12)
#7

Got it!
It had nothing to do with sshd settings.
My /home/nemo/.bashrc was missing the following at its top:

# if not running interactively, do nothing
[[ $- == *i* ]] || return

Both these articles mention this for both scp and sftp:

1 Like