Still getting 'rsync error: error in rsync protocol data stream (code 12)' w/ OpenBSD 3.8 and rsync 2.6.6
I’m still getting a meaningless rsync error, even with OpenBSD 3.8 and rsync 2.6.6. I’d hoped upgrading to the latest everything would at least give me a more meaningful error message, if not solve the problem.
Alas, such is not the case. When I run qdb.pl as root from an interactive shell on ender, all is well; qdb.pl rsyncs to jane, uploads a small Perl file to prepare the backup target, and proceeds with the backup. However, running the exact same script as a root cron job yields:
rsync: connection unexpectedly closed (0 bytes received so far) [sender]
rsync error: error in rsync protocol data stream (code 12) at /usr/ports/net/rsync/w-rsync-2.6.6/rsync-2.6.6/io.c(434)
In the rsync current issues list, mention is made of the ‘code 12′ error, and provides this invaluable guidance:
This error tells you that the local rsync was trying to talk to the remote rsync, but the connection to that rsync is now gone. The thing you must figure out is why, and that can involve some investigative work.
Hmm, figure out why, you say? Brilliant.
…
After much consternation, I believe I’ve identified the problem. qdb.pl needs to determine the home directory in order to locate the SSH key file which will be used to authenticate. If this fails, it will not attempt to use the key file. However, this apparently causes unexpected behavior with rsync.
When I wrote that logic, I assumed that, absent a key file, SSH would prompt the user for credentials, which rsync is obviously capable of handling under normal circumstances. However, for some reason it seems to cause a problem under cron. I’ll tweak the code a bit to confirm.
Ok, so I made a modified qdb.pl which will never use a key file with SSH, and ran it from an interactive shell:
[root@ender] /usr/local/backup (520) $ ./qdb2.pl --server jane --username ender_backup --rsync_cmd /usr/local/bin/rsync
ender_backup@jane's password:
Clearly, it prompts, as I expected. Now I’ll try it under cron.
Sure enough:
rsync: connection unexpectedly closed (0 bytes received so far) [sender]
rsync error: error in rsync protocol data stream (code 12) at
So, I guess because rsync and ssh are running without a TTY in cron, the prompt for credentials doesn’t appear? Seems rather odd. But, in any case, since rsync’s pipe up to jane is the ssh session, that it can’t be established clearly breaks rsync is a generic way, as rsync has no real insight into what is wrong.
What, then, is the fix? If I disable interactive password authentication, qdb.pl becomes slightly less useful, though the most realistic use case is running it from cron. So, I’ll modify qdb.pl so it will fail if it can’t locate an identity file; I may add a switch later to turn this off, if I ever need it.
Alright, I’ve incorporated that change; now I get:
Error preparing server jane for backup:
An SSH identity file doesn't exist at /var/log/.qdb/qdb_key; run 'qdb.pl --setup' first
Now I knew that HOME was being set to /var/log; it never dawned on me the dire implications thereof. I’m rather reluctant to change the HOME env var for root’s cron jobs, so I think another qdb.pl switch is in order, to manually specify the path of the SSH identity file.
Alright, I’ve added --identity_file_path, and modified backup.sh accordingly. It seems to be running now. What an ordeal.