openssh unix dev - Nov 2012 - sftp authentication failure only as cronjob

Hi all,

I have a problem using sftp which I cannot get solved even after
searching all over the web, so maybe one of you has a useful hint:

I want to run a simple script that puts a file on a server using sftp.
Keys are setup correctly, everything works fine if I run the script from
within a terminal. When I run the same script from the crontab (my
personal crontab as user) the script runs fine on one installation
(running OpenSSH_5.4 on an older fedora 13 machine) but fails on another
machine (running OpenSSH_5.3 on a recent centos 6.3).

I assume that the failure is not caused by the older version of OpenSSH
but rather due to some difference in setup but simply cannot get to the
root of the problem. The ssh_config files are identical on both
machines.

The debug trace (using -v) when run interactively on the centos system
is a follows:


OpenSSH_5.3p1, OpenSSL 1.0.0-fips 29 Mar 2010
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Applying options for *
debug1: Connecting to www.lars-schade.de [82.165.88.246] port 22.
debug1: Connection established.
debug1: identity file /home/lars/.ssh/id_rsa type 1
debug1: Remote protocol version 2.0, remote software version OpenSSH
debug1: match: OpenSSH pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.3
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: server->client aes128-ctr hmac-md5 none
debug1: kex: client->server aes128-ctr hmac-md5 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug1: Host 'www.lars-schade.de' is known and matches the DSA host key.
debug1: Found key in /home/lars/.ssh/known_hosts:2
debug1: ssh_dss_verify: signature correct
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: publickey,password
debug1: Next authentication method: publickey
debug1: Offering public key: /home/lars/.ssh/id_rsa
debug1: Server accepts key: pkalg ssh-rsa blen 277
debug1: Authentication succeeded (publickey).
...

When the same script is run from the crontab the trace is identical
except that the authentication fails:

OpenSSH_5.3p1, OpenSSL 1.0.0-fips 29 Mar 2010
debug1: Reading configuration data /etc/ssh/ssh_config
debug1: Applying options for *
debug1: Connecting to www.lars-schade.de [82.165.88.246] port 22.
debug1: Connection established.
debug1: identity file /home/lars/.ssh/id_rsa type 1
debug1: Remote protocol version 2.0, remote software version OpenSSH
debug1: match: OpenSSH pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.3
debug1: SSH2_MSG_KEXINIT sent
debug1: SSH2_MSG_KEXINIT received
debug1: kex: server->client aes128-ctr hmac-md5 none
debug1: kex: client->server aes128-ctr hmac-md5 none
debug1: SSH2_MSG_KEX_DH_GEX_REQUEST(1024<1024<8192) sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_GROUP
debug1: SSH2_MSG_KEX_DH_GEX_INIT sent
debug1: expecting SSH2_MSG_KEX_DH_GEX_REPLY
debug1: Host 'www.lars-schade.de' is known and matches the DSA host key.
debug1: Found key in /home/lars/.ssh/known_hosts:2
debug1: ssh_dss_verify: signature correct
debug1: SSH2_MSG_NEWKEYS sent
debug1: expecting SSH2_MSG_NEWKEYS
debug1: SSH2_MSG_NEWKEYS received
debug1: SSH2_MSG_SERVICE_REQUEST sent
debug1: SSH2_MSG_SERVICE_ACCEPT received
debug1: Authentications that can continue: publickey,password
debug1: Next authentication method: publickey
debug1: Offering public key: /home/lars/.ssh/id_rsa
debug1: Server accepts key: pkalg ssh-rsa blen 277
debug1: PEM_read_PrivateKey failed
debug1: read PEM private key done: type <unknown>
debug1: No more authentication methods to try.
Permission denied (publickey,password).
Couldn't read packet: Connection reset by peer

Again the script runs fine from the crontab on the fedora 13 machine but
fails on the centos 6.3 machine (even though it works there
interactively).

Anyone any ideas or hints what the cause of the authentication failure
could be or where to look at?

Thanks, Lars

On Thu, 1 Nov 2012, Lars Schade wrote:
> Hi all,
> 
> I have a problem using sftp which I cannot get solved even after
> searching all over the web, so maybe one of you has a useful hint:
> 
> I want to run a simple script that puts a file on a server using sftp.
> Keys are setup correctly, everything works fine if I run the script from
> within a terminal. When I run the same script from the crontab (my
> personal crontab as user) the script runs fine on one installation
> (running OpenSSH_5.4 on an older fedora 13 machine) but fails on another
> machine (running OpenSSH_5.3 on a recent centos 6.3).
> 
> I assume that the failure is not caused by the older version of OpenSSH
> but rather due to some difference in setup but simply cannot get to the
> root of the problem. The ssh_config files are identical on both
> machines.
> 
> The debug trace (using -v) when run interactively on the centos system
> is a follows:
...
> debug1: Offering public key: /home/lars/.ssh/id_rsa
> debug1: Server accepts key: pkalg ssh-rsa blen 277
> debug1: PEM_read_PrivateKey failed
The only thing that appears different is that the private key is failing
to load. You aren't using ssh-agent are you? (it doesn't look like you
are)

Is SELinux enabled? It might be preventing jobs launched by cron from
accessing your private keys. You could test this by trying to run something
like "md5sum /home/lars/.ssh/id_rsa" from cron and seeing if it
succeeds
(or by finding errors in the logs)

-d

Hi all,

my problem with the sftp connection run as cron job is finally solved.
As in most cases the problem sits in front of the computer.

My script ran fine from the command line in my gnome session because the
ssh-agent provided the password for the private key in the background.
When run by the cron daemon the ssh-agent is not started and the prompt
for the password is for some reason not explicitly visible even in the
verbose log. So I simply removed the password from the key and now the
script runs fine even as cron job.

PS: On the other machine things worked fine right away because there the
keys were not password protected to begin with.

Sorry to have bothered you, this was just a bit tricky to diagnose.

Regards,
Lars