rsync and shell scripting

Alright, so I'm using rsync to backup my CRM system's database automatically to two places: my web hosting account (which is a CentOS linux box) and a 10.4 Server computer that I have on my LAN. I'm running a Macbook Pro with 10.6 and rsync is running on the Macbook Pro.

I use Daylite for CRM, and it automatically make a daily backup of its database on my hard drive. So I wrote the following shell script:

#! /bin/sh

rsync -a /Users/saw500/Library/"Application Support"/Daylite/Backup/ 192.168.1.99:/Users/saw500/Documents/Daylite
rsync -a /Users/saw500/Library/"Application Support"/Daylite/Backup/ design1@waltonstreetwebdesign.com:/home/design1/daylite

I used CronniX to add this script to cron. So here's the weird thing: it backs up to my linux hosting account, but not to my 10.4 box on the LAN! When I manually run the rsync command for the LAN it works, and when I manually run the script it works. Now, I know the script is running on cron because it automatically gets backed up to the remote linux box when cron triggers the script. But the weird thing is, and I've confirmed this 2 nights in a row, when cron triggers the script it doesn't back up to my LAN machine!!! Why?

Macbook Pro 17 Inch, Mac OS X (10.6.1)

Posted on Nov 4, 2009 1:04 AM

Reply
9 replies

Nov 4, 2009 4:18 PM in response to BobHarris

Actually I do have mail! It's mail for user saw500.

From saw500@Sawtooth500s-Macbook-Pro-2.local Wed Nov 4 00:10:49 2009
X-Original-To: saw500
Delivered-To: saw500@Sawtooth500s-Macbook-Pro-2.local
From: saw500@Sawtooth500s-Macbook-Pro-2.local (Cron Daemon)
To: saw500@Sawtooth500s-Macbook-Pro-2.local
Subject: Cron <saw500@Sawtooth500s-Macbook-Pro-2> /Users/saw500/daylite.sh
X-Cron-Env: <SHELL=/bin/sh>
X-Cron-Env: <PATH=/usr/bin:/bin>
X-Cron-Env: <LOGNAME=saw500>
X-Cron-Env: <USER=saw500>
X-Cron-Env: <HOME=/Users/saw500>
Date: Wed, 4 Nov 2009 00:10:03 -0600 (CST)

Permission denied, please try again.
Received disconnect from 192.168.1.99: 2: Too many authentication failures for saw500
rsync: connection unexpectedly closed (0 bytes received so far) [sender]
rsync error: error in rsync protocol data stream (code 12) at /SourceCache/rsync/rsync-37.3/rsync/io.c(452) [sender=2.6.9]

I think I'm running this as saw500, not root.

But here's what I really don't get: The line:
rsync -a /Users/saw500/Library/"Application Support"/Daylite/Backup/ 192.168.1.99:/Users/saw500/Documents/Daylite

Is taken directly out of the script. If I run this line by itself in the shell, it works like it's supposed to. It only fails in the script!

Actually I'm going to try adding saw500@192.168.1.99 to the line in the script, if it's running as root then it's trying to authenticate with the wrong user. How do I find out what it's running as, I just used CronniX and it's running however CronniX sets it.

Regarding authentication I have public/private keypairs set up, it's never given me a problem with that before.

Message was edited by: Sawtooth501

Nov 4, 2009 6:49 PM in response to Sawtooth501

On the other system, you can look at the /var/log/system.log and /var/log/secure.log, which might tell you how the other side was seeing the rsync connection request.
How do I find out what it's running as

You could add the following to your script

id >/tmp/my.cron.job.id.info

Then the next time your run, you will see your current ID.

However, I suspect you are running as saw500 because the mail message includes your LOGNAME environment variable:
X-Cron-Env: <LOGNAME=saw500>

About your public/private keys:
Regarding authentication I have public/private keypairs set up, it's never given me a problem with that before.

I assume you mean you have ssh-keygen created keys. Are these keys without a passphrase? Or do you use ssh-add to store your passphrase in the ssh-agent backgroup process. If you do have a passphrase, cron would not have access to it.

Nov 4, 2009 10:55 PM in response to BobHarris

Alright, I added that id line in my script, but we'll have to wait till tomorrow night for that to run.

Also, I'm using the following line in my script:
rsync -a /Users/saw500/Library/"Application Support"/Daylite/Backup/ saw500@192.168.1.99:/Users/saw500/Documents/Daylite

The difference is here that I specify saw500@192.168.1.99, where previously it was just 192.168.1.99. saw500 is my short name on both my sending system (10.6) and receiving system (10.4). Just as before, if I manually put that line in the terminal it works just fine, but it doesn't work in the script.

Also I'm using private/public key auth with no password, if I just ssh via the shell it doesn't ask me for a password, nor does it ask me for password when I type that rsync line directly into the shell.

The cron job is set to run 10 minutes past midnight. On the receiving 10.4 machine, this was the var/log/secure.log output:

Nov 5 00:10:01 c-24-1-191-236 com.apple.SecurityServer: authinternal failed to authenticate user saw500.
Nov 5 00:10:01 c-24-1-191-236 com.apple.SecurityServer: Failed to authorize right system.login.tty by process /usr/sbin/sshd for authorization created by /usr/sbin/sshd.
Nov 5 00:10:02 c-24-1-191-236 sshd[17036]: error: PAM: Authentication failure for saw500 from 192.168.1.100
Nov 5 00:10:02 c-24-1-191-236 com.apple.SecurityServer: authinternal failed to authenticate user saw500.
Nov 5 00:10:02 c-24-1-191-236 com.apple.SecurityServer: Failed to authorize right system.login.tty by process /usr/sbin/sshd for authorization created by /usr/sbin/sshd.
Nov 5 00:10:02 c-24-1-191-236 sshd[17036]: error: PAM: Authentication failure for saw500 from 192.168.1.100
Nov 5 00:10:02 c-24-1-191-236 com.apple.SecurityServer: authinternal failed to authenticate user saw500.
Nov 5 00:10:02 c-24-1-191-236 com.apple.SecurityServer: Failed to authorize right system.login.tty by process /usr/sbin/sshd for authorization created by /usr/sbin/sshd.
Nov 5 00:10:02 c-24-1-191-236 sshd[17036]: error: PAM: Authentication failure for saw500 from 192.168.1.100
Nov 5 00:10:02 c-24-1-191-236 sshd[17036]: Failed keyboard-interactive/pam for saw500 from 192.168.1.100 port 49514 ssh2
Nov 5 00:10:02 c-24-1-191-236 sshd[17036]: Failed password for saw500 from 192.168.1.100 port 49514 ssh2
Nov 5 00:10:02 c-24-1-191-236 sshd[17036]: Failed password for saw500 from 192.168.1.100 port 49514 ssh2

Also, here is the mail output for the message mailed to me on my 10.6 sending machine tonight:
From saw500@Sawtooth500s-Macbook-Pro-2.local Thu Nov 5 00:12:38 2009
X-Original-To: saw500
Delivered-To: saw500@Sawtooth500s-Macbook-Pro-2.local
From: saw500@Sawtooth500s-Macbook-Pro-2.local (Cron Daemon)
To: saw500@Sawtooth500s-Macbook-Pro-2.local
Subject: Cron <saw500@Sawtooth500s-Macbook-Pro-2> /Users/saw500/daylite.sh
X-Cron-Env: <SHELL=/bin/sh>
X-Cron-Env: <PATH=/usr/bin:/bin>
X-Cron-Env: <LOGNAME=saw500>
X-Cron-Env: <USER=saw500>
X-Cron-Env: <HOME=/Users/saw500>
Date: Thu, 5 Nov 2009 00:10:02 -0600 (CST)

Permission denied, please try again.
Received disconnect from 192.168.1.99: 2: Too many authentication failures for saw500
rsync: connection unexpectedly closed (0 bytes received so far) [sender]
rsync error: unexplained error (code 255) at /SourceCache/rsync/rsync-37.3/rsync/io.c(452) [sender=2.6.9]

I'm not quite sure what all that means... but Bob thank you so much for helping me out with all this!

Nov 5, 2009 9:40 AM in response to Sawtooth501

Try the following:

rsync -a -e "ssh -v -v -v"
/Users/saw500/Library/"Application Support"/Daylite/Backup/
saw500@192.168.1.99:/Users/saw500/Documents/Daylite

This is your command, with the addition of *-e 'ssh -v -v -v'* which give you a ton of ssh debugging information in your next cron mail message.

And then use the same command from the Terminal (you said that worked).

Now compare the debugging output from both runs. Where the output differs will hopefully narrow down just what is upsetting the cron job.

Nov 6, 2009 12:01 AM in response to BobHarris

Alright, so here's tonight's breakdown:

First off, this is the output from cron, the one that doesn't work:

From saw500@Sawtooth500s-Macbook-Pro-2.local Fri Nov 6 00:10:47 2009
X-Original-To: saw500
Delivered-To: saw500@Sawtooth500s-Macbook-Pro-2.local
From: saw500@Sawtooth500s-Macbook-Pro-2.local (Cron Daemon)
To: saw500@Sawtooth500s-Macbook-Pro-2.local
Subject: Cron <saw500@Sawtooth500s-Macbook-Pro-2> /Users/saw500/daylite.sh
X-Cron-Env: <SHELL=/bin/sh>
X-Cron-Env: <PATH=/usr/bin:/bin>
X-Cron-Env: <LOGNAME=saw500>
X-Cron-Env: <USER=saw500>
X-Cron-Env: <HOME=/Users/saw500>
Date: Fri, 6 Nov 2009 00:10:01 -0600 (CST)

OpenSSH_5.2p1, OpenSSL 0.9.8k 25 Mar 2009
debug1: Reading configuration data /etc/ssh_config
debug2: ssh_connect: needpriv 0
debug1: Connecting to 192.168.1.99 [192.168.1.99] port 22.
debug1: Connection established.
debug1: identity file /Users/saw500/.ssh/identity type -1
debug3: Not a RSA1 key file /Users/saw500/.ssh/id_rsa.
debug2: key type_fromname: unknown key type '-----BEGIN'
debug3: key_read: missing keytype
debug2: key type_fromname: unknown key type 'Proc-Type:'
debug3: key_read: missing keytype
debug2: key type_fromname: unknown key type 'DEK-Info:'
debug3: key_read: missing keytype
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug2: key type_fromname: unknown key type '-----END'
debug3: key_read: missing keytype




Now this is the output when I put that command directly in the command line, this works:

OpenSSH_5.2p1, OpenSSL 0.9.8k 25 Mar 2009
debug1: Reading configuration data /etc/ssh_config
debug2: ssh_connect: needpriv 0
debug1: Connecting to 192.168.1.99 [192.168.1.99] port 22.
debug1: Connection established.
debug1: identity file /Users/saw500/.ssh/identity type -1
debug3: Not a RSA1 key file /Users/saw500/.ssh/id_rsa.
debug2: key type_fromname: unknown key type '-----BEGIN'
debug3: key_read: missing keytype
debug2: key type_fromname: unknown key type 'Proc-Type:'
debug3: key_read: missing keytype
debug2: key type_fromname: unknown key type 'DEK-Info:'
debug3: key_read: missing keytype
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug2: key type_fromname: unknown key type '-----END'
debug3: key_read: missing keytype
debug1: identity file /Users/saw500/.ssh/id_rsa type 1
debug3: Not a RSA1 key file /Users/saw500/.ssh/id_dsa.
debug2: key type_fromname: unknown key type '-----BEGIN'
debug3: key_read: missing keytype
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug3: key_read: missing whitespace
debug2: key type_fromname: unknown key type '-----END'
debug3: key_read: missing keytype
debug1: identity file /Users/saw500/.ssh/id_dsa type 2
debug1: Remote protocol version 2.0, remote software version OpenSSH_5.1
debug1: match: OpenSSH_5.1 pat OpenSSH*
debug1: Enabling compatibility mode for protocol 2.0
debug1: Local version string SSH-2.0-OpenSSH_5.2
debug2: fd 3 setting O_NONBLOCK
debug1: SSH2 MSGKEXINIT sent
debug1: SSH2 MSGKEXINIT received
debug2: kex parsekexinit: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie- hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex parsekexinit: ssh-rsa,ssh-dss
debug2: kex parsekexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blow fish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex parsekexinit: aes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blow fish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se
debug2: kex parsekexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.co m,hmac-sha1-96,hmac-md5-96
debug2: kex parsekexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.co m,hmac-sha1-96,hmac-md5-96
debug2: kex parsekexinit: none,zlib@openssh.com,zlib
debug2: kex parsekexinit: none,zlib@openssh.com,zlib
debug2: kex parsekexinit:
debug2: kex parsekexinit:
debug2: kex parsekexinit: first kexfollows 0
debug2: kex parsekexinit: reserved 0
debug2: kex parsekexinit: diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie- hellman-group14-sha1,diffie-hellman-group1-sha1
debug2: kex parsekexinit: ssh-rsa,ssh-dss
debug2: kex parsekexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes1 92-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex parsekexinit: aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,arcfour128,arcfour256,arcfour,aes1 92-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,aes128-ctr,aes192-ctr,aes256-ctr
debug2: kex parsekexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.co m,hmac-sha1-96,hmac-md5-96
debug2: kex parsekexinit: hmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.co m,hmac-sha1-96,hmac-md5-96
debug2: kex parsekexinit: none,zlib@openssh.com
debug2: kex parsekexinit: none,zlib@openssh.com
debug2: kex parsekexinit:
debug2: kex parsekexinit:
debug2: kex parsekexinit: first kexfollows 0
debug2: kex parsekexinit: reserved 0
debug2: mac_setup: found hmac-md5
debug1: kex: server->client aes128-ctr hmac-md5 none
debug2: mac_setup: found hmac-md5
debug1: kex: client->server aes128-ctr hmac-md5 none
debug1: SSH2 MSG_KEX_DH_GEXREQUEST(1024<1024<8192) sent
debug1: expecting SSH2 MSG_KEX_DH_GEXGROUP
debug2: dh genkey: priv key bits set: 135/256
debug2: bits set: 526/1024
debug1: SSH2 MSG_KEX_DH_GEXINIT sent
debug1: expecting SSH2 MSG_KEX_DH_GEXREPLY
debug3: check host_inhostfile: filename /Users/saw500/.ssh/known_hosts
debug3: check host_inhostfile: match line 7
debug1: Host '192.168.1.99' is known and matches the RSA host key.
debug1: Found key in /Users/saw500/.ssh/known_hosts:7
debug2: bits set: 544/1024
debug1: ssh rsaverify: signature correct
debug2: kex derivekeys
debug2: set_newkeys: mode 1
debug1: SSH2 MSGNEWKEYS sent
debug1: expecting SSH2 MSGNEWKEYS
debug2: set_newkeys: mode 0
debug1: SSH2 MSGNEWKEYS received
debug1: SSH2 MSG_SERVICEREQUEST sent
debug2: service_accept: ssh-userauth
debug1: SSH2 MSG_SERVICEACCEPT received
debug2: key: /Users/saw500/.ssh/id_rsa (0x100117920)
debug2: key: /Users/saw500/.ssh/identity (0x0)
debug2: key: /Users/saw500/.ssh/id_dsa (0x100123d40)
debug1: Authentications that can continue: publickey,gssapi-keyex,gssapi-with-mic,password,keyboard-interactive
debug3: start over, passed a different list publickey,gssapi-keyex,gssapi-with-mic,password,keyboard-interactive
debug3: preferred publickey,keyboard-interactive,password
debug3: authmethod_lookup publickey
debug3: remaining preferred: keyboard-interactive,password
debug3: authmethod isenabled publickey
debug1: Next authentication method: publickey
debug1: Offering public key: /Users/saw500/.ssh/id_rsa
debug3: send pubkeytest
debug2: we sent a publickey packet, wait for reply
debug1: Server accepts key: pkalg ssh-rsa blen 277
debug2: input userauth_pkok: fp dc:17:16:d7:b2:01:c3:c3:ec:34:db:c2:77:b4:91:ab
debug3: sign and_sendpubkey
debug1: Authentication succeeded (publickey).
debug2: fd 4 setting O_NONBLOCK
debug3: fd 5 is O_NONBLOCK
debug1: channel 0: new [client-session]
debug3: ssh session2open: channel_new: 0
debug2: channel 0: send open
debug1: Requesting no-more-sessions@openssh.com
debug1: Entering interactive session.
debug2: callback start
debug2: client session2setup: id 0
debug1: Sending command: rsync --server -logDtpr . /Users/saw500/Documents/Daylite
debug2: channel 0: request exec confirm 1
debug2: fd 3 setting TCP_NODELAY
debug2: callback done
debug2: channel 0: open confirm rwindow 0 rmax 32768
debug2: channel 0: rcvd adjust 2097152
debug2: channel input_statusconfirm: type 99 id 0
debug2: exec request accepted on channel 0
debug2: channel 0: rcvd adjust 16548
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug2: channel 0: rcvd adjust 8192
debug1: client input_channelreq: channel 0 rtype exit-status reply 0
debug1: client input_channelreq: channel 0 rtype eow@openssh.com reply 0
debug2: channel 0: rcvd eow
debug2: channel 0: close_read
debug2: channel 0: input open -> closed
debug2: channel 0: rcvd eof
debug2: channel 0: output open -> drain
debug2: channel 0: obuf empty
debug2: channel 0: close_write
debug2: channel 0: output drain -> closed
debug2: channel 0: rcvd close
debug3: channel 0: will not send data after close
debug2: channel 0: almost dead
debug2: channel 0: gc: notify user
debug2: channel 0: gc: user detached
debug2: channel 0: send close
debug2: channel 0: is dead
debug2: channel 0: garbage collecting
debug1: channel 0: free: client-session, nchannels 1
debug3: channel 0: status: The following connections are open:
#0 client-session (t4 r0 i3/0 o3/0 fd -1/-1 cfd -1)

debug3: channel 0: close_fds r -1 w -1 e 6 c -1
debug1: fd 0 clearing O_NONBLOCK
debug1: fd 1 clearing O_NONBLOCK
Transferred: sent 16060944, received 64600 bytes, in 4.6 seconds
Bytes per second: sent 3459579.8, received 13915.1
debug1: Exit status 0

FYI I truncated a bunch of "debug2: channel 0: rcvd adjust 8192" lines from this output, it seemed like there were a few thousand of them probably too much to fit into this post. Also that http stuff you see in the output isn't really there, it's this forum translating brackets around an IP address into HTTP for some reason.



My best analysis from this is it's some sort of public/private key problem? But I'm still not exactly sure what it is... or how to fix it!

Nov 6, 2009 10:06 AM in response to Sawtooth501

I'm sorry, but I'm out of ideas.

I've looked at my own ssh -v -v -v output and it is similar to yours.

The only thing I can think to do at this point is, create new ssh-keygen keys, copy the .pub to the remote system and put the .pub key in the .ssh/authorized_keys file.

I would also go through the "man ssh" man page and search for "permission", then make sure that all the file permissions on both the local and remote systems are in line with what ssh desires (I'm not saying this is a permission problem, as that is generally an explicit error in the ssh debugging output, but I'm beyond reasonable debugging suggestions 🙂 ).

Side note: If you wan to post information without the forum thinking it has formatting characters, you can enclose your text in


... your stuff here ...

This thread has been closed by the system or the community team. You may vote for any posts you find helpful, or search the Community for additional answers.

rsync and shell scripting

Welcome to Apple Support Community
A forum where Apple customers help each other with their products. Get started with your Apple Account.