LinuxQuestions.org
Review your favorite Linux distribution.
Home Forums Tutorials Articles Register
Go Back   LinuxQuestions.org > Forums > Linux Forums > Linux - Server
User Name
Password
Linux - Server This forum is for the discussion of Linux Software used in a server related context.

Notices


Reply
  Search this Thread
Old 04-01-2013, 04:40 PM   #1
adayforgotten
LQ Newbie
 
Registered: Apr 2013
Location: USA
Distribution: Ubuntu
Posts: 9

Rep: Reputation: Disabled
working script fails when run by cron


I created a script to do some rsync work between locations. When I run the script as root on the cli, everything works as expected.

When the script is run by cron, it fails every time (usually mid command). Lines at the bottom of the script don't even execute (which I verified by putting mkdir statements around the code and checking if they got created after the cron job ran).

I have found plenty of people having cron issues with working scripts and the only thing I see is a whole lot of people suggesting it has to do with the environment. That is not the issue. I created a cron job to dump the env to a file and compared it with the cli environment. The cron env is more than enough (the PATH in particular was identical). And the major difference between this and the multitude of other posts I've found is that it stops mid command (the logs show rsync taking place, then EOF).

I am at a loss for what to try next. An ideas for what could cause this?

Here are the contents of the script with private info removed. Feel free to use it in your projects if it helps. What it does is run a dry run rsync with --delete to get a list of files that don't exist at the source end. It then checks the 'change' date on all those files at the destination and moves them to the trash if they were created before the last sync (keep in mind this means before the last sync run on the source since we are basing the move decision on whether or not it was ever sync'd to the far end in the first place). Once this is complete, it runs rsync with the -u for update only to pull new and change data. It marks it's completion time when it is done (so the source can use that timestamp for part one when it runs the script next). I know this is not the best explaination but I tried to comment almost everything so let me know if anything doesn't make sense...

Code:
#!/bin/bash

###########################################################
# This should be run as root
#
# Any file with a 'change' time more than $LASTSYNC will be preserved
# Others are assumed to be existing files which were deleted from the far end
# Files deleted from the far end are moved to the TRASHBIN for manual deletion (safety feature)
###########################################################

LOGFILE="/home/user/rsync.log/cron/host2--host1_$(date +%Y-%m-%d-%H:%M:%S).log"
# This is the username used for remote ssh (rsync)
USERNAME="user"
# This is the ssh key used to authenticate to remote source
SSHKEY="/root/.ssh/host1-rsync"
# List of items which are not sync'd
EXCLUDES="/home/user/excludes-rsync.txt"
# Can be hostnameif DNS is configured correctly
SOURCEIP="xx.xx.xx.xx"
# These are only for feedback output (and logs)
SOURCENAME="host2"
DESTNAME="host1"
# These are the directories which will be sync'd
SOURCEDIR="/mnt/dir/"
DESTDIR="/mnt/dir/"
# Deleted Files will be moved here rather than deleted (must have trailing slash)
TRASHBIN="/mnt/TrashBin/"
# Location of the file used to store the last sync time
# Destination file must be writable
DEST_LASTSYNC="/home/user/rsync.log/.lastsync-host2--host1"
# Source file must be readable by USERNAME on the remote machine
SOURCE_LASTSYNC="/home/user/rsync.log/.lastsync-host1--host2"

logged ()
{
    # Get the timestamp of the last completed sync on the source
    # This represents the last time the remote system ran the sync
    remoteLastSync="$(ssh -i ${SSHKEY} ${USERNAME}@${SOURCEIP} "${SOURCE_LASTSYNC}")" # SEE CODE BELOW TO UNDERSTAND WHAT THE REMOTE SYSTEM DOES HERE
    case $remoteLastSync in
        DNE)
            remoteLastSync=0 # All files will be considered new files and are replicated
        ;;
        R)
            printf "%s\n" "SOURCE_LASTSYNC time file \"${SOURCE_LASTSYNC}\" not readable by user \"${USERNAME}@${SOURCENAME}\""
            exit
        ;;
        Rejected)
            printf "%s\n" "SSH key ${SSHKEY} was rejected for this command"
            exit
        ;;
        *)
            remoteLastSync=$remoteLastSync
        ;;
    esac

    # If DEST_LASTSYNC doesn't exist, make sure we can create it
    if [ ! -e "${DEST_LASTSYNC}" ]; then
        # If the touch fails, exit
        touch "${DEST_LASTSYNC}" || ( printf "%s\n" "DEST_LASTSYNC time file \"${DEST_LASTSYNC}\" not writable by user \"$(id -un)\"" && exit )
        # remove the test create to avoid a false positive for a completed sync
        rm "${DEST_LASTSYNC}"
    else # If it does exist, make sure we can update it
        [ ! -w ${DEST_LASTSYNC} ] && \
            printf "%s\n" "DEST_LASTSYNC time file \"${DEST_LASTSYNC}\" not writable by user \"$(id -un)\"" && exit
    fi

    # Assign timeCompare to the curent time
    timeCompare="$(date +%s)"
    # Mark the time of the last completed sync on this machine in log
    ([ -e "${DEST_LASTSYNC}" ] && printf "%s\n" "  Last: $(stat "${DEST_LASTSYNC}" -c %y)") || \
        printf "%s\n" "  Last: Never"
    # Mark timeCompare in log
    printf "%s\n" " Start: $(date -d @${timeCompare} +%Y-%m-%d\ %H:%M:%S.%N\ %z)"
    # Mark remoteLastSync in log
    printf "%s\n" "Remote: $(date -d @${remoteLastSync} +%Y-%m-%d\ %H:%M:%S.%N\ %z)"

    # Delete items on DEST that were deleted on SOURCE
    printf "%s\n" "Finding items on ${DESTNAME} that were deleted on ${SOURCENAME}"
    old_IFS=$IFS # Split output on newlines
    IFS=$'\n'
    # Dry Run rsync to get a list of files that don't exist on the remote end
    # The outer parenthesis make an array split on $IFS
    deletedFiles=($(rsync -nrve "ssh -i ${SSHKEY}" --delete --exclude-from="${EXCLUDES}" "${USERNAME}@${SOURCEIP}:${SOURCEDIR}" "${DESTDIR}" | grep deleting | sed "s;^deleting\ ;${DESTDIR};"))
    IFS=$old_IFS # Restore default (spaces usually)

    for i in "${deletedFiles[@]}"
    do
        # If the file was not 'changed' since the remoteLastSync
        #   (if 'change' time of $i is less than remoteLastSync)
        if [ $(stat "$i" -c %Z) -lt $remoteLastSync ]; then
            # Files
            [ -f "$i" ] && filename="$(printf "%s\n" "$i" | sed 's/.*\///')"
            # Directories (Above broken by trailing slash)
            [ -d "$i" ] && filename="$(printf "%s\n" "$i" | sed 's/\/$//' | sed 's/.*\///')"
            # If filename already exists in the Trash dir
            if [ -e "${TRASHBIN}${filename}" ]; then
                counter=0
                while [ -e "${TRASHBIN}${filename}(${counter})" ]
                do
                    counter=$((${counter}+1))
                done
                filename="${filename}(${counter})"
            fi
            timeChg="$(stat "$i" -c %z)"
            ( mv "$i" "${TRASHBIN}${filename}" && \
            (    printf "%s\n%s\n" "Moved \"${DESTNAME}:$i\" (Changed: ${timeChg})" \
                "   to \"${DESTNAME}:${TRASHBIN}${filename}\"" ) || \
                ( printf "%s\n" "FAILURE: \"${DESTNAME}:$i\" (Changed: ${timeChg})" && exit )
        else
            printf "%s\n" "New Item: $i" # output list of new files to log
        fi
    done

    # Update new & existing files
    # host1 <-- host2
    printf "%s\n" "rsync ${DESTNAME} <-- ${SOURCENAME}"
    rsync -nirlptgoDuvPe "ssh -i ${SSHKEY}" --exclude-from="${EXCLUDES}" "${USERNAME}@${SOURCEIP}:${SOURCEDIR}" "${DESTDIR}"
    if [ $? -eq 0 ]; then # Update DEST_LASTSYNC time file with timeCompare date/time if no errors
        touch -t $(date -d @${timeCompare} +%Y%m%d%H%M.%S) -m "${DEST_LASTSYNC}"
    else
        printf "%s\n%s\n" "rsync returned \"$?\"" \
            "An error occured, \"${DEST_LASTSYNC}\" will not be updated"
    fi
    # Mark completion time in log
    printf "%s\n" "Done:  $(date +%Y-%m-%d\ %H:%M:%S.%N\ %z)"
}

# Run the script
# The function allows output from stout and sterr to be sent to
#   both a log file, and the screen simultaneously
# `touch` ensures that we can write the log file
(touch ${LOGFILE} && logged 2>&1 | tee ${LOGFILE}) || \
    printf "%s\n" "Can't write to log file \"${LOGFILE}\""
In order for the SSH connections to the remote system to work, the SSH key is set in the authorized_keys file to execute this script:
Code:
#!/bin/sh

# This controls access to run commands via ssh

case "$SSH_ORIGINAL_COMMAND" in
    *\&*)
        echo "Rejected"
    ;;
    *\(*)
        echo "Rejected"
    ;;
    *\{*)
        echo "Rejected"
    ;;
    *\;*)
        echo "Rejected"
    ;;
    *\<*)
        echo "Rejected"
    ;;
    *\`*)
        echo "Rejected"
    ;;
    *\|*)
        echo "Rejected"
    ;;
    rsync\ --server\ --sender\ -vnre.iLsf\ .\ /mnt/dir/)
        # Allow check for deleted files
        rsync --server --sender -vnre.iLsf . /mnt/dir/
    ;;
    rsync\ --server\ --sender\ -vunlogDtpre.iLsf\ .\ /mnt/dir/)
        # Allow Dry Run for rsync update
        rsync --server --sender -vunlogDtpre.iLsf . /mnt/dir/
    ;;
    rsync\ --server\ --sender\ -vulogDtpre.iLsf\ .\ /mnt/dir/)
        # Allow Run for rsync
        rsync --server --sender -vulogDtpre.iLsf . /mnt/dir/
    ;;
    /home/user/rsync.log/*)
        if [ ! -e "${SSH_ORIGINAL_COMMAND}" ]; then
            printf "%s\n" "DNE"
        elif [ ! -r "${SSH_ORIGINAL_COMMAND}" ]; then
            printf "%s\n" "R"
        else
            stat "${SSH_ORIGINAL_COMMAND}" -c %Y
        fi
    ;;
    *)
        echo "Rejected"
    ;;
esac
And lastly, this is a pretty good example of the output I get from the cron run:
Code:
  Last: 2013-04-01 15:28:41.000000000 -0400
 Start: 2013-04-01 15:32:03.000000000 -0400
Remote: 2013-03-01 00:00:00.000000000 -0500
Finding items on host2 that were deleted on host1
New Item: /mnt/dir/testfile
New Item: /mnt/dir/x/xxxxxxxxx.gif
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx.jpg
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx.mkv
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.sfv
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.rar
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r15
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r14
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r13
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r12
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r11
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r10
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r09
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r08
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r07
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r06
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r05
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r04
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r03
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r02
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r01
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r00
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.nfo
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx/
rsync host2 <-- host1
receiving incremental file list
.d..t...... ./
>f.stp..... newdoc1.txt
>f+++++++++ testfileee
.d..t...... xxxx/xxx/xxxxxx/
.d..t...... xxxxxxxxxxx/
In the log above, some files that should have been updated weren't and the output at the end of the rsync as well as the "done" timestamp are not executed. (Essentially the process literally dies midway - or so it seems)

Thanks in advance LQ. First original post despite finding thousands of answers here.

Last edited by adayforgotten; 04-03-2013 at 12:54 PM. Reason: # Update new & existing files - Expanded if statement /// changed quoted section to code for log output
 
Old 04-01-2013, 11:27 PM   #2
chrism01
LQ Guru
 
Registered: Aug 2004
Location: Sydney
Distribution: Rocky 9.2
Posts: 18,356

Rep: Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751
You could start by adding debug cmd to bash script
Code:
#!/bin/bash

# this line shows exactly what the parser is doing;
# ensure you capture both stdout & stderr in a log file
set -xv
then the cronjob
Code:
min hr day mth dow script >script.log 2>&1
HTH
 
Old 04-02-2013, 12:33 PM   #3
adayforgotten
LQ Newbie
 
Registered: Apr 2013
Location: USA
Distribution: Ubuntu
Posts: 9

Original Poster
Rep: Reputation: Disabled
Lightbulb Progress!!

Quote:
Originally Posted by chrism01 View Post
then the cronjob
Code:
min hr day mth dow script >script.log 2>&1
HTH
So something interesting happened... I had already tried the 'set -xv' but it gave me no answers (it still seemed to just stop executing mid rsync). When I add redirection in the crontab file, it works completely as expected.

I have confirmed that the script as it is posted above works in cron when I have it like this:
Code:
## ## ## ## ##   root    /home/user/syncStorage.sh >/home/user/rsync.log/cron/output.log 2>&1
But goes back to the previously described behavior as soon as I take out the redirection like so:
Code:
## ## ## ## ##   root    /home/user/syncStorage.sh
I did a little more digging and found this in my syslog:
Code:
Apr  2 12:56:01 host2 cron[1373]: (*system*) RELOAD (/etc/crontab)
Apr  2 12:56:01 host2 CRON[19748]: (root) CMD (   /home/user/syncStorage.sh)
Apr  2 12:56:03 host2 postfix/sendmail[19759]: fatal: open /etc/postfix/main.cf: No such file or directory
Apr  2 13:02:01 host2 cron[1373]: (*system*) RELOAD (/etc/crontab)
Apr  2 13:02:01 host2 CRON[19922]: (root) CMD (   /home/user/syncStorage.sh >/home/user/rsync.log/cron/HELP.log 2>&1)
It looks like cron is trying to email some more info about the failure. Anyone have any other thoughts? How can I fix my cron so that it puts errors somewhere else rather than trying to email them?

On host1, there is no postfix message in the syslog despite exhibiting the exact same behavior.

Last edited by adayforgotten; 04-02-2013 at 12:34 PM. Reason: minor
 
Old 04-02-2013, 03:15 PM   #4
sag47
Senior Member
 
Registered: Sep 2009
Location: Raleigh, NC
Distribution: Ubuntu, PopOS, Raspbian
Posts: 1,899
Blog Entries: 36

Rep: Reputation: 477Reputation: 477Reputation: 477Reputation: 477Reputation: 477
It's likely mailed it to root (based on /etc/aliases). If you log into root you can run the 'mail' command to view messages mailed to root.

In general here are the commands you can use with the mail client.
h - headers (show a list of messages)
n - where n is an integer for the number message to display.
d n - delete message number n
q - quit mail
 
Old 04-02-2013, 08:12 PM   #5
chrism01
LQ Guru
 
Registered: Aug 2004
Location: Sydney
Distribution: Rocky 9.2
Posts: 18,356

Rep: Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751
1. what did you find in /home/user/rsync.log/cron/output.log or /home/user/rsync.log/cron/HELP.log ?

2. its possible you didn't install a mail server/MTA like sendmail or postfix.
Even if you didn't think you wanted one, the system needs one to talk to itself. eg if cron has an issue, it attempts to email the job owner or root.

You can use the mailx cli client to check those emails.
http://linux.die.net/man/1/mailx

You should get the MTA from the Ubuntu repos; its looking for postfix according to that error.
http://www.postfix.org/
 
Old 04-02-2013, 09:04 PM   #6
adayforgotten
LQ Newbie
 
Registered: Apr 2013
Location: USA
Distribution: Ubuntu
Posts: 9

Original Poster
Rep: Reputation: Disabled
Question Still a little confused about why the script fails when there's no redirection in the crontab entry

Quote:
Originally Posted by chrism01 View Post
1. what did you find in /home/user/rsync.log/cron/output.log or /home/user/rsync.log/cron/HELP.log ?
The output is identical to the log file generated by the tee command (runs successfully to completion as expected):
Code:
  Last: 2013-04-02 15:00:02.000000000 -0400
 Start: 2013-04-02 16:40:03.000000000 -0400
Remote: 2013-03-01 00:00:00.000000000 -0500
Finding items on host2 that were deleted on host1
New Item: /mnt/dir/testfile
New Item: /mnt/dir/x/xxxxxxxxx.gif
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx.jpg
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx.mkv
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.sfv
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.rar
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r15
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r14
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r13
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r12
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r11
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r10
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r09
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r08
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r07
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r06
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r05
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r04
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r03
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r02
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r01
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.r00
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx.nfo
New Item: /mnt/dir/Media/Completed/xxxxxxxxxxxx/xxxxxxxxxxxx/
rsync host2 <-- host1
receiving incremental file list
.d..t...... ./
>f.stp..... newdoc1.txt
>f+++++++++ testfileee
.d..t...... xxxx/xxx/xxxxxx/
.d..t...... xxxxxxxxxxx/
>f+++++++++ xxxxxxxxxxx/xxxxx
>f+++++++++ xxxxxxxxxxx/xxxxx

sent 46526 bytes  received 15268280 bytes  397787.17 bytes/sec
total size is 52588236548  speedup is 274413.42 (DRY RUN)
Done:  2013-04-02 16:41:21.994053061 -0400
But as soon as I remove the redirection from the crontab (as shown in my last post), the output from the 'tee' command in the script is the same as my original post (missing the last two transfers and everything after).

Quote:
Originally Posted by chrism01 View Post
2. its possible you didn't install a mail server/MTA like sendmail or postfix.
Even if you didn't think you wanted one, the system needs one to talk to itself. eg if cron has an issue, it attempts to email the job owner or root.
I don't have one installed. I will need to do that to see the messages on host2. host1 didn't have that error and probably because there is a mail program installed. host1 is a much older install with many more packages as I've used it for other projects.

Quote:
Originally Posted by sag47 View Post
It's likely mailed it to root (based on /etc/aliases). If you log into root you can run the 'mail' command to view messages mailed to root.
My system seems to be set up a little differently (Ubuntu 10.04.4 x64). The 'mail' command/program doesn't exist on my installation. I am unsure of where mail ends up currently (if anywhere at all on host2 based on the syslog).

Quote:
Originally Posted by chrism01 View Post
You should get the MTA from the Ubuntu repos; its looking for postfix according to that error.
I'll give this a try and post back what I find in root's mailbox.
 
Old 04-02-2013, 10:35 PM   #7
chrism01
LQ Guru
 
Registered: Aug 2004
Location: Sydney
Distribution: Rocky 9.2
Posts: 18,356

Rep: Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751Reputation: 2751
1. if you had 'set -xv' in the prog, you'd see all the cmds and their translated/parsed form as well. You need to 'set -vx' AND re-direct all output (stdout+stderr) to a logfile.

2. the local mail client may be called mail or mailx or even nail (or others..); there's more than one available and some distros have more than one in their repos.
 
Old 04-03-2013, 08:41 AM   #8
sag47
Senior Member
 
Registered: Sep 2009
Location: Raleigh, NC
Distribution: Ubuntu, PopOS, Raspbian
Posts: 1,899
Blog Entries: 36

Rep: Reputation: 477Reputation: 477Reputation: 477Reputation: 477Reputation: 477
Quote:
Originally Posted by adayforgotten View Post
My system seems to be set up a little differently (Ubuntu 10.04.4 x64). The 'mail' command/program doesn't exist on my installation. I am unsure of where mail ends up currently (if anywhere at all on host2 based on the syslog).
It is likely being mailed to root. Look at your /etc/aliases file. It will tell you where stuff is being mailed (whether it's local or remote mailing). If you haven't modified any mail settings then it will default to sending mail to the user who the cron job is owned by.

You don't need to use a mail client to view your user mail (it makes it easier). You can view mail for your user located at:
Code:
/var/spool/mail/$USER
Just use a plain text editor as it will just be a regular file.
 
Old 04-03-2013, 12:50 PM   #9
adayforgotten
LQ Newbie
 
Registered: Apr 2013
Location: USA
Distribution: Ubuntu
Posts: 9

Original Poster
Rep: Reputation: Disabled
Red face

Quote:
Originally Posted by chrism01 View Post
1. if you had 'set -xv' in the prog, you'd see all the cmds and their translated/parsed form as well. You need to 'set -vx' AND re-direct all output (stdout+stderr) to a logfile.
I didn't do this because when there is redirection in the crontab, the script works 100%. So if I add the redirection in the crontab to see what the problem is, the script runs to completion and the huge amount of output it generates is exactly what I'd expect to see. I will do it and post it just for completionist's sake.

I made some additions to the script to prevent both ends from trying to run the sync at the same time. Here is a repost of the updated scripts from my original post. As stated in previous posts, the script runs as expected with no errors or unwanted behavior as long as the output is redirected in /etc/crontab. The added code checks to see if there exists "${SOURCE_LASTSYNC}.run" on the source system and loops at a set interval until it no longer exists or a timer expires.

The main script (syncStorage.sh):
Code:
#!/bin/bash

#set -vx # Enable bash debugging

###########################################################
# This should be run as root
#
# Any file with a 'change' time more than $LASTSYNC will be preserved
# Others are assumed to be existing files which were deleted from the far end
# Files deleted from the far end are moved to the TRASHBIN for manual deletion (safety feature)
###########################################################

LOGFILE="/home/user/rsync.log/prod/host2--host1_$(date +%Y-%m-%d-%H:%M:%S).log"
# This is the username used for remote ssh (rsync)
USERNAME="user"
# This is the ssh key used to authenticate to remote source
SSHKEY="/root/.ssh/host1-rsync"
# List of items which are not sync'd
EXCLUDES="/home/user/excludes-rsync.txt"
# Can be hostnameif DNS is configured correctly
SOURCEIP="xx.xx.xx.xx"
# These are only for feedback output (and logs)
SOURCENAME="host2"
DESTNAME="host1"
# These are the directories which will be sync'd
SOURCEDIR="/mnt/dir/"
DESTDIR="/mnt/dir/"
# Deleted Files will be moved here rather than deleted (must have trailing slash)
TRASHBIN="/mnt/TrashBin/"
# Location of the file used to store the last sync time
# Destination file must be writable
DEST_LASTSYNC="/home/user/rsync.log/prod/.lastsync-host2--host1"
# Source file must be readable by USERNAME on the remote machine
SOURCE_LASTSYNC="/home/user/rsync.log/prod/.lastsync-host1--host2"
# Delay in minutes the process should wait when the sync is already running on the source
RUNNING_DELAY=1
# Number of times to wait
# RUNNING_DELAY * RUNNING_TERM = Total time in minutes this process will wait before terminating
RUNNING_TERM=2

logged ()
{
    # Create a temporary file to signify that this sync process is running
    touch "${DEST_LASTSYNC}.run" || ( printf "%s\n" "Failure creating ${DEST_LASTSYNC}.run file" && exit )
    # Get the timestamp of the last completed sync on the source
    # This represents the last time the remote system ran the sync
    remoteLastSync="$(ssh -i ${SSHKEY} ${USERNAME}@${SOURCEIP} "${SOURCE_LASTSYNC}")"
    # If the script is already running on the remote end,
    #   wait a little and try again
    counter=0
    while [ "${remoteLastSync}" = "RUN" ]; do
        if [ ${counter} -eq ${RUNNING_TERM} ]; then # Terminate after 5 minutes waiting
            printf "%s\n" "Sync process running too long on source, giving up"
            rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file"
            exit
        fi
        counter=$((${counter}+1))
        printf "%s\n" "Sync process running on source, sleeping... ; waited $((${counter}*${RUNNING_DELAY})) minutes"
        rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file"
        sleep $(((${RUNNING_DELAY}*60)-1)) # 5 minutes
        touch "${DEST_LASTSYNC}.run" || ( printf "%s\n" "Failure creating ${DEST_LASTSYNC}.run file" && exit )
        sleep 1
        remoteLastSync="$(ssh -i ${SSHKEY} ${USERNAME}@${SOURCEIP} "${SOURCE_LASTSYNC}")"
    done
    case $remoteLastSync in
        DNE)
            remoteLastSync=0 # All files will be considered new files and are replicated
        ;;
        R)
            printf "%s\n" "SOURCE_LASTSYNC time file \"${SOURCE_LASTSYNC}\" not readable by user \"${USERNAME}@${SOURCENAME}\""
            rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file"
            exit
        ;;
        Rejected)
            printf "%s\n" "SSH key ${SSHKEY} was rejected for this command"
            rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file"
            exit
        ;;
        *)
            remoteLastSync=$remoteLastSync
        ;;
    esac

    # If DEST_LASTSYNC doesn't exist, make sure we can create it
    if [ ! -e "${DEST_LASTSYNC}" ]; then
        # If the touch fails, exit
        touch "${DEST_LASTSYNC}" || \
            ( printf "%s\n" "DEST_LASTSYNC time file \"${DEST_LASTSYNC}\" not writable by user \"$(id -un)\"" && \
              ( rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file" ) && exit )
        # remove the test create to avoid a false positive for a completed sync
        rm "${DEST_LASTSYNC}"
    else # If it does exist, make sure we can update it
        [ ! -w "${DEST_LASTSYNC}" ] && \
            printf "%s\n" "DEST_LASTSYNC time file \"${DEST_LASTSYNC}\" not writable by user \"$(id -un)\"" && \
              ( rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file" ) && exit
    fi

    # Assign timeCompare to the curent time
    timeCompare="$(date +%s)"
    # Mark the time of the last completed sync on this machine in log
    ([ -e "${DEST_LASTSYNC}" ] && printf "%s\n" "  Last: $(stat "${DEST_LASTSYNC}" -c %y)") || \
        printf "%s\n" "  Last: Never"
    # Mark timeCompare in log
    printf "%s\n" " Start: $(date -d @${timeCompare} +%Y-%m-%d\ %H:%M:%S.%N\ %z)"
    # Mark remoteLastSync in log
    printf "%s\n" "Remote: $(date -d @${remoteLastSync} +%Y-%m-%d\ %H:%M:%S.%N\ %z)"

    # Delete items on host1 that were deleted on host2
    printf "%s\n" "Finding items on ${DESTNAME} that were deleted on ${SOURCENAME}"
    old_IFS=$IFS # Split output on newlines
    IFS=$'\n'
    # Dry Run rsync to get a list of files that don't exist on the remote end
    # The outer parenthesis make an array split on $IFS
    deletedFiles=($(rsync -nrve "ssh -i ${SSHKEY}" --delete --exclude-from="${EXCLUDES}" "${USERNAME}@${SOURCEIP}:${SOURCEDIR}" "${DESTDIR}" | grep deleting | sed "s;^deleting\ ;${DESTDIR};"))
    IFS=$old_IFS # Restore default (spaces usually)

    for i in "${deletedFiles[@]}"
    do
        # If the file was not 'changed' since the remoteLastSync
        #   (if 'change' time of $i is less than remoteLastSync)
        if [ $(stat "$i" -c %Z) -lt $remoteLastSync ]; then
            # Files
            [ -f "$i" ] && filename="$(printf "%s\n" "$i" | sed 's/.*\///')"
            # Directories (Above broken by trailing slash)
            [ -d "$i" ] && filename="$(printf "%s\n" "$i" | sed 's/\/$//' | sed 's/.*\///')"
            # If filename already exists in the Trash dir
            if [ -e "${TRASHBIN}${filename}" ]; then
                counter=0
                while [ -e "${TRASHBIN}${filename}(${counter})" ]
                do
                    counter=$((${counter}+1))
                done
                filename="${filename}(${counter})"
            fi
            timeChg="$(stat "$i" -c %z)"
           # ( mv "$i" "${TRASHBIN}${filename}" && \
                ( printf "%s\n%s\n" "Moved \"${DESTNAME}:$i\" (Changed: ${timeChg})" \
                "   to \"${DESTNAME}:${TRASHBIN}${filename}\"" ) || \
                ( printf "%s\n" "FAILURE: \"${DESTNAME}:$i\" (Changed: ${timeChg})" && \
                    ( rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file" ) && exit )
        else
            printf "%s\n" "New Item: $i" # output list of new files to log
        fi
    done

    # Update new & existing files
    # host1 <-- host2
    printf "%s\n" "rsync ${DESTNAME} <-- ${SOURCENAME}"
    rsync -nirlptgoDuvPe "ssh -i ${SSHKEY}" --exclude-from="${EXCLUDES}" "${USERNAME}@${SOURCEIP}:${SOURCEDIR}" "${DESTDIR}"
    if [ $? -eq 0 ]; then # Update DEST_LASTSYNC time file with timeCompare date/time if no errors
        touch -t $(date -d @${timeCompare} +%Y%m%d%H%M.%S) -m "${DEST_LASTSYNC}"
    else
        printf "%s\n%s\n" "rsync returned \"$?\"" \
            "An error occured, \"${DEST_LASTSYNC}\" will not be updated"
    fi
    # Mark completion time in log
    printf "%s\n\n" "  Done: $(date +%Y-%m-%d\ %H:%M:%S.%N\ %z)"
    # Remove the temporary file to signify that this sync process is complete
    rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file"
}

# Run the script
# The function allows output from stout and sterr to be sent to
#   both a log file, and the screen simultaneously
# `touch` ensures that we can write the log file
(touch "${LOGFILE}" && logged 2>&1 | tee "${LOGFILE}") || \
    printf "%s\n" "Can't write to log file \"${LOGFILE}\""
The SSH key script (executed in response to connections made by the SSH key I created for this process):
Code:
#!/bin/sh

# This controls access to run commands via ssh

case "$SSH_ORIGINAL_COMMAND" in
    *\&*)
        echo "Rejected"
    ;;
    *\(*)
        echo "Rejected"
    ;;
    *\{*)
        echo "Rejected"
    ;;
    *\;*)
        echo "Rejected"
    ;;
    *\<*)
        echo "Rejected"
    ;;
    *\`*)
        echo "Rejected"
    ;;
    *\|*)
        echo "Rejected"
    ;;
    rsync\ --server\ --sender\ -vnre.iLsf\ .\ /mnt/dir/)
        # Allow check for deleted files
        rsync --server --sender -vnre.iLsf . /mnt/dir/
    ;;
    rsync\ --server\ --sender\ -vunlogDtpre.iLsf\ .\ /mnt/dir/)
        # Allow Dry Run for rsync update
        rsync --server --sender -vunlogDtpre.iLsf . /mnt/dir/
    ;;
    rsync\ --server\ --sender\ -vulogDtpre.iLsf\ .\ /mnt/dir/)
        # Allow Run for rsync
        rsync --server --sender -vulogDtpre.iLsf . /mnt/dir/
    ;;
    /home/user/rsync.log/*)
        if [ -e "${SSH_ORIGINAL_COMMAND}.run" ]; then
            printf "%s\n" "RUN"
        elif [ ! -e "${SSH_ORIGINAL_COMMAND}" ]; then
            printf "%s\n" "DNE"
        elif [ ! -r "${SSH_ORIGINAL_COMMAND}" ]; then
            printf "%s\n" "R"
        else
            stat "${SSH_ORIGINAL_COMMAND}" -c %Y
        fi
    ;;
    *)
        echo "Rejected"
    ;;
esac
Here is the output with the 'set -vx' line AND redirection in /etc/crontab (the redirected output file and the log file generated by the script with the 'tee' command are identical for the logged() function portion):
Code:
###########################################################
# This should be run as root
#
# Any file with a 'change' time more than $LASTSYNC will be preserved
# Others are assumed to be existing files which were deleted from the far end
# Files deleted from the far end are moved to the TRASHBIN for manual deletion (safety feature)
###########################################################

LOGFILE="/home/user/rsync.log/prod/host2--host1_$(date +%Y-%m-%d-%H:%M:%S).log"
date +%Y-%m-%d-%H:%M:%S).log"
date +%Y-%m-%d-%H:%M:%S).log
date +%Y-%m-%d-%H:%M:%S
++ date +%Y-%m-%d-%H:%M:%S
+ LOGFILE=/home/user/rsync.log/prod/host2--host1_2013-04-03-11:15:02.log
# This is the username used for remote ssh (rsync)
USERNAME="user"
+ USERNAME=user
# This is the ssh key used to authenticate to remote source
SSHKEY="/root/.ssh/host1-rsync"
+ SSHKEY=/root/.ssh/host1-rsync
# List of items which are not sync'd
EXCLUDES="/home/user/excludes-rsync.txt"
+ EXCLUDES=/home/user/excludes-rsync.txt
# Can be hostnameif DNS is configured correctly
SOURCEIP="xx.xx.xx.xx"
+ SOURCEIP=xx.xx.xx.xx
# These are only for feedback output (and logs)
SOURCENAME="host2"
+ SOURCENAME=host2
DESTNAME="host1"
+ DESTNAME=host1
# These are the directories which will be sync'd
SOURCEDIR="/mnt/dir/"
+ SOURCEDIR=/mnt/dir/
DESTDIR="/mnt/dir/"
+ DESTDIR=/mnt/dir/
# Deleted Files will be moved here rather than deleted (must have trailing slash)
TRASHBIN="/mnt/TrashBin/"
+ TRASHBIN='/mnt/TrashBin/'
# Location of the file used to store the last sync time
# Destination file must be writable
DEST_LASTSYNC="/home/user/rsync.log/prod/.lastsync-host2--host1"
+ DEST_LASTSYNC=/home/user/rsync.log/prod/.lastsync-host2--host1
# Source file must be readable by USERNAME on the remote machine
SOURCE_LASTSYNC="/home/user/rsync.log/prod/.lastsync-host1--host2"
+ SOURCE_LASTSYNC=/home/user/rsync.log/prod/.lastsync-host1--host2
# Delay in minutes the process should wait when the sync is already running on the source
RUNNING_DELAY=1
+ RUNNING_DELAY=1
# Number of times to wait
# RUNNING_DELAY * RUNNING_TERM = Total time in minutes this process will wait before terminating
RUNNING_TERM=2
+ RUNNING_TERM=2

logged ()
{
    # Create a temporary file to signify that this sync process is running
    touch "${DEST_LASTSYNC}.run" || ( printf "%s\n" "Failure creating ${DEST_LASTSYNC}.run file" && exit )
    # Get the timestamp of the last completed sync on the source
    # This represents the last time the remote system ran the sync
    remoteLastSync="$(ssh -i ${SSHKEY} ${USERNAME}@${SOURCEIP} "${SOURCE_LASTSYNC}")"
    # If the script is already running on the remote end,
    #   wait a little and try again
    counter=0
    while [ "${remoteLastSync}" = "RUN" ]; do
        if [ ${counter} -eq ${RUNNING_TERM} ]; then # Terminate after 5 minutes waiting
            printf "%s\n" "Sync process running too long on source, giving up"
            rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file"
            exit
        fi
        counter=$((${counter}+1))
        printf "%s\n" "Sync process running on source, sleeping... ; waited $((${counter}*${RUNNING_DELAY})) minutes"
        rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file"
        sleep $(((${RUNNING_DELAY}*60)-1)) # 5 minutes
        touch "${DEST_LASTSYNC}.run" || ( printf "%s\n" "Failure creating ${DEST_LASTSYNC}.run file" && exit )
        sleep 1
        remoteLastSync="$(ssh -i ${SSHKEY} ${USERNAME}@${SOURCEIP} "${SOURCE_LASTSYNC}")"
    done
    case $remoteLastSync in
        DNE)
            remoteLastSync=0 # All files will be considered new files and are replicated
        ;;
        R)
            printf "%s\n" "SOURCE_LASTSYNC time file \"${SOURCE_LASTSYNC}\" not readable by user \"${USERNAME}@${SOURCENAME}\""
            rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file"
            exit
        ;;
        Rejected)
            printf "%s\n" "SSH key ${SSHKEY} was rejected for this command"
            rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file"
            exit
        ;;
        *)
            remoteLastSync=$remoteLastSync
        ;;
    esac

    # If DEST_LASTSYNC doesn't exist, make sure we can create it
    if [ ! -e "${DEST_LASTSYNC}" ]; then
        # If the touch fails, exit
        touch "${DEST_LASTSYNC}" || \
            ( printf "%s\n" "DEST_LASTSYNC time file \"${DEST_LASTSYNC}\" not writable by user \"$(id -un)\"" && \
              ( rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file" ) && exit )
        # remove the test create to avoid a false positive for a completed sync
        rm "${DEST_LASTSYNC}"
    else # If it does exist, make sure we can update it
        [ ! -w "${DEST_LASTSYNC}" ] && \
            printf "%s\n" "DEST_LASTSYNC time file \"${DEST_LASTSYNC}\" not writable by user \"$(id -un)\"" && \
              ( rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file" ) && exit
    fi

    # Assign timeCompare to the curent time
    timeCompare="$(date +%s)"
    # Mark the time of the last completed sync on this machine in log
    ([ -e "${DEST_LASTSYNC}" ] && printf "%s\n" "  Last: $(stat "${DEST_LASTSYNC}" -c %y)") || \
        printf "%s\n" "  Last: Never"
    # Mark timeCompare in log
    printf "%s\n" " Start: $(date -d @${timeCompare} +%Y-%m-%d\ %H:%M:%S.%N\ %z)"
    # Mark remoteLastSync in log
    printf "%s\n" "Remote: $(date -d @${remoteLastSync} +%Y-%m-%d\ %H:%M:%S.%N\ %z)"

    # Delete items on host1 that were deleted on host2
    printf "%s\n" "Finding items on ${DESTNAME} that were deleted on ${SOURCENAME}"
    old_IFS=$IFS # Split output on newlines
    IFS=$'\n'
    # Dry Run rsync to get a list of files that don't exist on the remote end
    # The outer parenthesis make an array split on $IFS
    deletedFiles=($(rsync -nrve "ssh -i ${SSHKEY}" --delete --exclude-from="${EXCLUDES}" "${USERNAME}@${SOURCEIP}:${SOURCEDIR}" "${DESTDIR}" | grep deleting | sed "s;^deleting\ ;${DESTDIR};"))
    IFS=$old_IFS # Restore default (spaces usually)

    for i in "${deletedFiles[@]}"
    do
        # If the file was not 'changed' since the remoteLastSync
        #   (if 'change' time of $i is less than remoteLastSync)
        if [ $(stat "$i" -c %Z) -lt $remoteLastSync ]; then
            # Files
            [ -f "$i" ] && filename="$(printf "%s\n" "$i" | sed 's/.*\///')"
            # Directories (Above broken by trailing slash)
            [ -d "$i" ] && filename="$(printf "%s\n" "$i" | sed 's/\/$//' | sed 's/.*\///')"
            # If filename already exists in the Trash dir
            if [ -e "${TRASHBIN}${filename}" ]; then
                counter=0
                while [ -e "${TRASHBIN}${filename}(${counter})" ]
                do
                    counter=$((${counter}+1))
                done
                filename="${filename}(${counter})"
            fi
            timeChg="$(stat "$i" -c %z)"
           # ( mv "$i" "${TRASHBIN}${filename}" && \
                ( printf "%s\n%s\n" "Moved \"${DESTNAME}:$i\" (Changed: ${timeChg})" \
                "   to \"${DESTNAME}:${TRASHBIN}${filename}\"" ) || \
                ( printf "%s\n" "FAILURE: \"${DESTNAME}:$i\" (Changed: ${timeChg})" && \
                    ( rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file" ) && exit )
        else
            printf "%s\n" "New Item: $i" # output list of new files to log
        fi
    done

    # Update new & existing files
    # host1 <-- host2
    printf "%s\n" "rsync ${DESTNAME} <-- ${SOURCENAME}"
    rsync -nirlptgoDuvPe "ssh -i ${SSHKEY}" --exclude-from="${EXCLUDES}" "${USERNAME}@${SOURCEIP}:${SOURCEDIR}" "${DESTDIR}"
    if [ $? -eq 0 ]; then # Update DEST_LASTSYNC time file with timeCompare date/time if no errors
        touch -t $(date -d @${timeCompare} +%Y%m%d%H%M.%S) -m "${DEST_LASTSYNC}"
    else
        printf "%s\n%s\n" "rsync returned \"$?\"" \
            "An error occured, \"${DEST_LASTSYNC}\" will not be updated"
    fi
    # Mark completion time in log
    printf "%s\n\n" "  Done: $(date +%Y-%m-%d\ %H:%M:%S.%N\ %z)"
    # Remove the temporary file to signify that this sync process is complete
    rm "${DEST_LASTSYNC}.run" || printf "%s\n" "Failure removing ${DEST_LASTSYNC}.run file"
}

# Run the script
# The function allows output from stout and sterr to be sent to
#   both a log file, and the screen simultaneously
# `touch` ensures that we can write the log file
(touch "${LOGFILE}" && logged 2>&1 | tee "${LOGFILE}") || \
    printf "%s\n" "Can't write to log file \"${LOGFILE}\""
+ touch /home/user/rsync.log/prod/host2--host1_2013-04-03-11:15:02.log
+ logged
+ tee /home/user/rsync.log/prod/host2--host1_2013-04-03-11:15:02.log
+ touch /home/user/rsync.log/prod/.lastsync-host2--host1.run
ssh -i ${SSHKEY} ${USERNAME}@${SOURCEIP} "${SOURCE_LASTSYNC}")"
ssh -i ${SSHKEY} ${USERNAME}@${SOURCEIP} "${SOURCE_LASTSYNC}")
ssh -i ${SSHKEY} ${USERNAME}@${SOURCEIP} "${SOURCE_LASTSYNC}"
++ ssh -i /root/.ssh/host1-rsync user@xx.xx.xx.xx /home/user/rsync.log/prod/.lastsync-host1--host2
+ remoteLastSync=1365001865
+ counter=0
+ '[' 1365001865 = RUN ']'
+ case $remoteLastSync in
+ remoteLastSync=1365001865
+ '[' '!' -e /home/user/rsync.log/prod/.lastsync-host2--host1 ']'
+ '[' '!' -w /home/user/rsync.log/prod/.lastsync-host2--host1 ']'
date +%s)"
date +%s)
date +%s
++ date +%s
+ timeCompare=1365002103
+ '[' -e /home/user/rsync.log/prod/.lastsync-host2--host1 ']'
stat "${DEST_LASTSYNC}" -c %y)"
stat "${DEST_LASTSYNC}" -c %y)
stat "${DEST_LASTSYNC}" -c %y
++ stat /home/user/rsync.log/prod/.lastsync-host2--host1 -c %y
+ printf '%s\n' '  Last: 2013-04-03 11:09:03.000000000 -0400'
  Last: 2013-04-03 11:09:03.000000000 -0400
date -d @${timeCompare} +%Y-%m-%d\ %H:%M:%S.%N\ %z)"
date -d @${timeCompare} +%Y-%m-%d\ %H:%M:%S.%N\ %z)
date -d @${timeCompare} +%Y-%m-%d\ %H:%M:%S.%N\ %z
++ date -d @1365002103 '+%Y-%m-%d %H:%M:%S.%N %z'
+ printf '%s\n' ' Start: 2013-04-03 11:15:03.000000000 -0400'
 Start: 2013-04-03 11:15:03.000000000 -0400
date -d @${remoteLastSync} +%Y-%m-%d\ %H:%M:%S.%N\ %z)"
date -d @${remoteLastSync} +%Y-%m-%d\ %H:%M:%S.%N\ %z)
date -d @${remoteLastSync} +%Y-%m-%d\ %H:%M:%S.%N\ %z
++ date -d @1365001865 '+%Y-%m-%d %H:%M:%S.%N %z'
+ printf '%s\n' 'Remote: 2013-04-03 11:11:05.000000000 -0400'
Remote: 2013-04-03 11:11:05.000000000 -0400
+ printf '%s\n' 'Finding items on host1 that were deleted on host2'
Finding items on host1 that were deleted on host2
+ old_IFS='
'
+ IFS='
'
+ deletedFiles=($(rsync -nrve "ssh -i ${SSHKEY}" --delete --exclude-from="${EXCLUDES}" "${USERNAME}@${SOURCEIP}:${SOURCEDIR}" "${DESTDIR}" | grep deleting | sed "s;^deleting\ ;${DESTDIR};"))
rsync -nrve "ssh -i ${SSHKEY}" --delete --exclude-from="${EXCLUDES}" "${USERNAME}@${SOURCEIP}:${SOURCEDIR}" "${DESTDIR}" | grep deleting | sed "s;^deleting\ ;${DESTDIR};")
rsync -nrve "ssh -i ${SSHKEY}" --delete --exclude-from="${EXCLUDES}" "${USERNAME}@${SOURCEIP}:${SOURCEDIR}" "${DESTDIR}" | grep deleting | sed "s;^deleting\ ;${DESTDIR};")
rsync -nrve "ssh -i ${SSHKEY}" --delete --exclude-from="${EXCLUDES}" "${USERNAME}@${SOURCEIP}:${SOURCEDIR}" "${DESTDIR}" | grep deleting | sed "s;^deleting\ ;${DESTDIR};"
++ rsync -nrve 'ssh -i /root/.ssh/host1-rsync' --delete --exclude-from=/home/user/excludes-rsync.txt user@xx.xx.xx.xx:/mnt/dir/ /mnt/dir/
++ grep deleting
++ sed 's;^deleting\ ;/mnt/dir/;'
+ IFS='
'
+ for i in '"${deletedFiles[@]}"'
stat "$i" -c %Z)
stat "$i" -c %Z
++ stat /mnt/dir/testdir/ -c %Z
+ '[' 1364419084 -lt 1365001865 ']'
+ '[' -f /mnt/dir/testdir/ ']'
+ '[' -d /mnt/dir/testdir/ ']'
printf "%s\n" "$i" | sed 's/\/$//' | sed 's/.*\///')"
printf "%s\n" "$i" | sed 's/\/$//' | sed 's/.*\///')
printf "%s\n" "$i" | sed 's/\/$//' | sed 's/.*\///'
++ printf '%s\n' /mnt/dir/testdir/
++ sed 's/\/$//'
++ sed 's/.*\///'
+ filename=testdir
+ '[' -e '/mnt/TrashBin/testdir' ']'
stat "$i" -c %z)"
stat "$i" -c %z)
stat "$i" -c %z
++ stat /mnt/dir/testdir/ -c %z
+ timeChg='2013-03-27 17:18:04.442474478 -0400'
+ printf '%s\n%s\n' 'Moved "host1:/mnt/dir/testdir/" (Changed: 2013-03-27 17:18:04.442474478 -0400)' '   to "host1:/mnt/TrashBin/testdir"'
Moved "host1:/mnt/dir/testdir/" (Changed: 2013-03-27 17:18:04.442474478 -0400)
   to "host1:/mnt/TrashBin/testdir"
+ for i in '"${deletedFiles[@]}"'
stat "$i" -c %Z)
stat "$i" -c %Z
++ stat /mnt/dir/testfile -c %Z
+ '[' 1364419084 -lt 1365001865 ']'
+ '[' -f /mnt/dir/testfile ']'
printf "%s\n" "$i" | sed 's/.*\///')"
printf "%s\n" "$i" | sed 's/.*\///')
printf "%s\n" "$i" | sed 's/.*\///'
++ printf '%s\n' /mnt/dir/testfile
++ sed 's/.*\///'
+ filename=testfile
+ '[' -d /mnt/dir/testfile ']'
+ '[' -e '/mnt/TrashBin/testfile' ']'
stat "$i" -c %z)"
stat "$i" -c %z)
stat "$i" -c %z
++ stat /mnt/dir/testfile -c %z
+ timeChg='2013-03-27 17:18:04.442474478 -0400'
+ printf '%s\n%s\n' 'Moved "host1:/mnt/dir/testfile" (Changed: 2013-03-27 17:18:04.442474478 -0400)' '   to "host1:/mnt/TrashBin/testfile"'
Moved "host1:/mnt/dir/testfile" (Changed: 2013-03-27 17:18:04.442474478 -0400)
   to "host1:/mnt/TrashBin/testfile"
+ printf '%s\n' 'rsync host1 <-- host2'
rsync host1 <-- host2
+ rsync -nirlptgoDuvPe 'ssh -i /root/.ssh/host1-rsync' --exclude-from=/home/user/excludes-rsync.txt user@xx.xx.xx.xx:/mnt/dir/ /mnt/dir/
receiving incremental file list
.d..t...... ./
>f.stp..... newdoc1.txt
>f+++++++++ testfileee
.d..t...... xxxx/xxx/xxxxxx/
.d..t...... xxxxxxxxxxx/
>f+++++++++ xxxxxxxxxxx/xxxxx
>f+++++++++ xxxxxxxxxxx/xxxxx

sent 46526 bytes  received 15268280 bytes  397787.17 bytes/sec
total size is 52588236548  speedup is 274413.42 (DRY RUN)
+ '[' 0 -eq 0 ']'
date -d @${timeCompare} +%Y%m%d%H%M.%S)
date -d @${timeCompare} +%Y%m%d%H%M.%S)
date -d @${timeCompare} +%Y%m%d%H%M.%S
++ date -d @1365002103 +%Y%m%d%H%M.%S
+ touch -t 201304031115.03 -m /home/user/rsync.log/prod/.lastsync-host2--host1
date +%Y-%m-%d\ %H:%M:%S.%N\ %z)"
date +%Y-%m-%d\ %H:%M:%S.%N\ %z)
date +%Y-%m-%d\ %H:%M:%S.%N\ %z
++ date '+%Y-%m-%d %H:%M:%S.%N %z'
+ printf '%s\n\n' '  Done: 2013-04-03 11:16:21.824773350 -0400'
  Done: 2013-04-03 11:16:21.824773350 -0400

+ rm /home/user/rsync.log/prod/.lastsync-host2--host1.run
If I schedule it again (same exact script) with the 'set -vx' line WITHOUT redirection in /etc/crontab (from the log file generated by the script), the script starts and creates the .run file but then dies. The log file is completely empty, and the .run file never gets removed since the script stops executing. This is actually worse than without the 'set -vx' line. If I comment that one line and schedule it, the output file generated by the script yields:
Code:
  Last: 2013-04-03 12:55:03.000000000 -0400
 Start: 2013-04-03 13:13:02.000000000 -0400
Remote: 2013-04-03 11:11:05.000000000 -0400
Finding items on nas1 that were deleted on nas2
Moved "nas1:/mnt/storage/testdir/" (Changed: 2013-03-27 17:18:04.442474478 -0400)
   to "nas1:/mnt/storage/Consolidated Backup/TrashBin/testdir"
Moved "nas1:/mnt/storage/testfileee" (Changed: 2013-03-27 17:18:04.442474478 -0400)
   to "nas1:/mnt/storage/Consolidated Backup/TrashBin/testfileee"
rsync nas1 <-- nas2
receiving incremental file list
.d..t...... ./
>f.stp..... newdoc1.txt
>f+++++++++ testfileee
.d..t...... xxxx/xxx/xxxxxx/
.d..t...... xxxxxxxxxxx/
The .run file is also never removed in this case. And again, if I put the redirection back into the /etc/crontab and reschedule, everything works as expected.

Quote:
Originally Posted by sag47 View Post
Look at your /etc/aliases file.
This file does not exist on my system.
Quote:
Originally Posted by sag47 View Post
You can view mail for your user located at: /var/spool/mail/$USER
/var/spool/mail is a link to /var/mail and it is empty:
Code:
user@host1:~$ ls -la /var/spool/mail
lrwxrwxrwx 1 root root 7 2012-03-27 01:10 /var/spool/mail -> ../mail
user@host1:~$ ls -la /var/mail/
total 8
drwxrwsr-x  2 root mail 4096 2012-02-14 05:44 .
drwxr-xr-x 15 root root 4096 2012-02-14 05:47 ..
user@host1:~$
 
  


Reply



Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

BB code is On
Smilies are On
[IMG] code is Off
HTML code is Off



Similar Threads
Thread Thread Starter Forum Replies Last Post
[SOLVED] ffmpeg fails to run in cron but ok from command line Liquid_Squelch Linux - Software 7 02-11-2013 04:29 PM
[SOLVED] Cron run fails at random points, throws: Attempting to re-run cron while.... Nighteyes Linux - Newbie 2 06-22-2012 05:08 AM
script run fine from ./ but when put in cron does not run j-me Linux - Server 6 06-16-2012 10:02 AM
Script runs Manually but not in Cron, yet other parts of the script run mccartjd Linux - Newbie 5 01-08-2012 06:54 PM
cron backup job fails to run bluethundr Linux - Newbie 5 01-06-2011 05:50 AM

LinuxQuestions.org > Forums > Linux Forums > Linux - Server

All times are GMT -5. The time now is 11:25 AM.

Main Menu
Advertisement
My LQ
Write for LQ
LinuxQuestions.org is looking for people interested in writing Editorials, Articles, Reviews, and more. If you'd like to contribute content, let us know.
Main Menu
Syndicate
RSS1  Latest Threads
RSS1  LQ News
Twitter: @linuxquestions
Open Source Consulting | Domain Registration