I recently upgraded one servers (running RHEL AS 5) from OpenSSH 4 server to OpenSSH 5.2 server.
Since the upgrade a customer is unable to scp files from the machine anymore. They use an ssh client from http://ssh.com/.
I can scp files from and to the machine using openssh without problems.
We use "Public key authentication" and they are still able to ssh to the machine but not scp files.
Is there any known -obvious- cause for such incompatibilities? If not how can I dig deeper into this issue?
Here is a log from the client side:
user@srv/home/user> /usr/local/bin/scp -v cdr@xxx.xxx.xxx.51:/home/cdr/test .
scp:SshAppCommon/sshappcommon.c:133: Allocating global SshRegex context.
scp:Scp2/scp2.c:499: Received error "SSH_FC_OK"., msg: Globbing successful.
scp:Scp2/scp2.c:564: Starting transfer...
scp:/home/cdr/test
scp:SshFCTransfer/sshfc_transfer.c:3018: File list has 2 files.
scp:SshFCTransfer/sshfc_transfer.c:2567: Not yet connected, or connection down, waiting...
scp:SshFileCopy/sshfilecopy.c:940: Connecting to remote host. (host = xxx.xxx.xxx.51, user = cdr, port = NULL)
scp:Scp2/scp2.c:1679: argv[0] = /usr/local/bin/ssh2
scp:Scp2/scp2.c:1679: argv[1] = -l
scp:Scp2/scp2.c:1679: argv[2] = cdr
scp:Scp2/scp2.c:1679: argv[3] = -v
scp:Scp2/scp2.c:1679: argv[4] = -x
scp:Scp2/scp2.c:1679: argv[5] = -a
scp:Scp2/scp2.c:1679: argv[6] = -o
scp:Scp2/scp2.c:1679: argv[7] = clearallforwardings yes
scp:Scp2/scp2.c:1679: argv[8] = -o
scp:Scp2/scp2.c:1679: argv[9] = passwordprompt %U@%H's password:
scp:Scp2/scp2.c:1679: argv[10] = -o
scp:Scp2/scp2.c:1679: argv[11] = nodelay yes
scp:Scp2/scp2.c:1679: argv[12] = -o
scp:Scp2/scp2.c:1679: argv[13] = authenticationnotify yes
scp:Scp2/scp2.c:1679: argv[14] = xxx.xxx.xxx.51
scp:Scp2/scp2.c:1679: argv[15] = -s
scp:Scp2/scp2.c:1679: argv[16] = sftp
debug: Connecting to xxx.xxx.xxx.51, port 22... (SOCKS not used)
debug: Ssh2/ssh2.c:2121: Entering event loop.
debug: Ssh2Client/sshclient.c:1403: Creating transport protocol.
debug: SshAuthMethodClient/sshauthmethodc.c:83: Added "publickey" to usable methods.
debug: SshAuthMethodClient/sshauthmethodc.c:83: Added "password" to usable methods.
debug: Ssh2Client/sshclient.c:1444: Creating userauth protocol.
debug: client supports 2 auth methods: 'publickey,password'
debug: Ssh2Common/sshcommon.c:559: local ip = xxx.xxx.xxx.35, local port = 56985
debug: Ssh2Common/sshcommon.c:561: remote ip = xxx.xxx.xxx.51, remote port = 22
debug: SshConnection/sshconn.c:1930: Wrapping...
debug: Ssh2/ssh2.c:899: Opening /dev/tty for queries.
debug: Remote version: SSH-2.0-OpenSSH_5.2
debug: Ssh2Transport/trcommon.c:1306: Remote version has rekey incompatibility bug.
debug: Ssh2Transport/trcommon.c:1308: Remote version is OpenSSH, KEX guesses disabled.
debug: Ssh2Transport/trcommon.c:1647: lang s to c: `', lang c to s: `'
debug: Ssh2Transport/trcommon.c:1712: c_to_s: cipher aes128-cbc, mac hmac-sha1, compression none
debug: Ssh2Transport/trcommon.c:1715: s_to_c: cipher aes128-cbc, mac hmac-sha1, compression none
debug: Remote host key found from database.
debug: Ssh2Common/sshcommon.c:317: Received SSH_CROSS_STARTUP packet from connection protocol.
debug: Ssh2Common/sshcommon.c:367: Received SSH_CROSS_ALGORITHMS packet from connection protocol.
debug: server offers auth methods 'publickey,password,keyboard-interactive'.
debug: Ssh2AuthPubKeyClient/authc-pubkey.c:1535: adding keyfile "/devapp_users/nsdtest/.ssh2/nsdau187" to candidates
debug: Ssh2AuthPubKeyClient/authc-pubkey.c:1535: adding keyfile "/devapp_users/nsdtest/.ssh2/id_dsa_1024_a" to candidates
debug: Ssh2AuthPubKeyClient/authc-pubkey.c:1535: adding keyfile "/devapp_users/nsdtest/.ssh2/id_dsa_1024_b" to candidates
debug: Constructing and sending signature in publickey authentication.
debug: Ssh2AuthPubKeyClient/authc-pubkey.c:772: ssh_client_auth_pubkey_send_signature: reading /devapp_users/nsdtest/.ssh2/nsdau187
debug: Ssh2AuthPubKeyClient/authc-pubkey.c:1751: Public key authentication was successful.
debug: Ssh2Common/sshcommon.c:285: Received SSH_CROSS_AUTHENTICATED packet from connection protocol.
debug: Ssh2/ssh2.c:650: Returning user input stream to original values.
debug: Ssh2Common/sshcommon.c:829: num_channels now 1
scp:SshFCTransfer/sshfc_transfer.c:130: Source file is "raw", and it needs to be parsed.
debug: SshTtyFlags/sshttyflags.c:354: Not a tty. (fd = 0)
scp:SshFCTransfer/sshfc_transfer.c:1319: No connection yet. Waiting...
scp:SshFileXferClient/sshfilexferc.c:981: ssh_file_client_receive_proc: bad VERSION
scp:SshFCTransfer/sshfc_transfer.c:1319: No connection yet. Waiting...
scp:SshFCTransfer/sshfc_transfer.c:1319: No connection yet. Waiting...
scp:SshFCTransfer/sshfc_transfer.c:1319: No connection yet. Waiting...
scp:SshFCTransfer/sshfc_transfer.c:1319: No connection yet. Waiting...
scp:SshFCTransfer/sshfc_transfer.c:1319: No connection yet. Waiting...
[...] same until the user presses Ctrl+C
user@srv/home/user> debug: SshConnection/sshconn.c:405: EOF from channel stream
debug: Ssh2ChannelSession/sshchsession.c:1721: received exit status : 0
debug: Ssh2Common/sshcommon.c:803: num_channels now 0
debug: Got session close with exit_status=0
debug: destroying client struct...
debug: Ssh2Client/sshclient.c:1478: Destroying client.
debug: SshConfig/sshconfig.c:555: Freeing pki. (host_pki != NULL, user_pki = NULL)
debug: SshConnection/sshconn.c:1982: Destroying SshConn object.
debug: Ssh2Client/sshclient.c:1540: Destroying client completed.
debug: SshAuthMethodClient/sshauthmethodc.c:88: Destroying authentication method array.
debug: SshAppCommon/sshappcommon.c:146: Freeing global SshRegex context.
debug: SshConfig/sshconfig.c:555: Freeing pki. (host_pki = NULL, user_pki = NULL)
And here are the entries form the server log
Jun 3 07:22:36 localhost sshd[19898]: Accepted publickey for cdr from xxx.xxx.xx.x port 53119 ssh2
Jun 3 07:22:36 localhost sshd[19900]: subsystem request for sftp
Jun 3 07:22:58 localhost snmpd[8500]: netsnmp_assert index == tmp failed if-mib/data_access/interface.c:467 _access_interface_entry_save_name()
Jun 3 07:23:58 localhost last message repeated 4 times
Edit: "Subsystem sftp internal-sftp" is already enabled in the conf file, and I can sftp files form the server without problems.
Edit: Trying without the keys by specifying a username/password does not work either.
Reverting back to the older version works, so that's what we are doing for now.
Btw we suspected this line
debug: SshTtyFlags/sshttyflags.c:354: Not a tty. (fd = 0)
might mean the shell is sending something which is showing on the ssh console but messing up the scp, but nothing seems to be sent on ssh (and .bashrc seems clean) and I cannot view the decrypted scp traffic to see if something is being sent wrongly.
Best Answer
What does "unable to scp files" any more mean? What is the error message they get?
Check your logs (/var/log/syslog, /var/log/messages, /var/log/daemon.log) to see if the SSH server is throwing any errors. They should be pretty descriptive. With the logs and the customer's error, we should be able to narrow down what the problem is.
Edit
The logs you posted indicate the most likely problem:
Looks like this thing is trying to use the sftp protocol rather than scp directly. OpenSSH, by default, disables the sftp subsystem. I don't know when this change was made, but it sounds likely. Add this to your sshd_config and see if it changes things: