[SOLVED] cron in debian is not executing a script at the scheduled time

educated__fool · 09-20-2012, 12:33 AM

Hi there,

I'm new to the boards so I didn't know what is the appropriate place to post this in... if the place is wrong the mods can move the thread to its place...

anyhow, I purged arch linux from one of my vps'es and installed debian6. restored my configs and data and was up and running in no time, but...

I noticed that my cron is 'not' working as expected. what I mean by this is that it is working and executing my bash scripts but is not executing them at the time set... for example, this is what I have in my 'crontab -l':

Code:

┌─[06:37:49]-[root@gordon]-[/etc/nginx]
└─› crontab -l
@reboot echo "$(hostname)" | /usr/bin/mail -s "Server up" my@email.net

*/5  *   *   *   *  /root/bin/update_vnstat_db
# daily backup
#*/5  *   *   *   *  /usr/bin/strace /root/bin/bkpTool > /tmp/strace.cron.out
59   7   *   *   *  /usr/bin/bkpTool 2>&1 | mail -s "GORDON: Backup report => $(date)" my@email.net

#|   |   |   |   |  user command
#|   |   |   |  weekday (0-6) (Sunday=0)
#|   |   |   month (1-12)
#|   |   day (0-31)
#|   hour (0-23)
#minute (0-59)

Code:

┌─[07:25:40]-[root@gordon]-[/etc/nginx]
└─› ls -la /usr/bin/bkpTool
-rwxr-xr-x 1 root root 7333 Sep  4 07:54 /usr/bin/bkpTool

Code:

┌─[07:26:39]-[root@gordon]-[/etc/nginx]
└─› ps aux | grep -v grep | grep cron
root      1006  0.0  0.1   3816   552 ?        Ss   Sep19   0:00 /usr/sbin/cron

Code:

┌─[07:26:48]-[root@gordon]-[/etc/nginx]
└─› grep bkpTool /var/log/cron.log
Sep 16 13:59:01 gordon /USR/SBIN/CRON[3375]: (root) CMD (/usr/bin/bkpTool 2>&1 | mail -s "GORDON: Backup report => $(date)"   my@email.net)
Sep 17 13:59:01 gordon /USR/SBIN/CRON[6841]: (root) CMD (/usr/bin/bkpTool 2>&1 | mail -s "GORDON: Backup report => $(date)"   my@email.net)
Sep 18 13:59:01 gordon /USR/SBIN/CRON[20892]: (root) CMD (/usr/bin/bkpTool 2>&1 | mail -s "GORDON: Backup report => $(date)" my@email.net)
Sep 19 13:59:01 gordon /USR/SBIN/CRON[30375]: (root) CMD (/usr/bin/bkpTool 2>&1 | mail -s "GORDON: Backup report => $(date)" my@email.net)

Code:

┌─[07:26:48]-[root@gordon]-[/etc/nginx]
└─› grep bkpTool /var/log/cron.log
Sep 16 13:59:01 gordon /USR/SBIN/CRON[3375]: (root) CMD (/usr/bin/bkpTool 2>&1 | mail -s "GORDON: Backup report => $(date)"   my@email.net)
Sep 17 13:59:01 gordon /USR/SBIN/CRON[6841]: (root) CMD (/usr/bin/bkpTool 2>&1 | mail -s "GORDON: Backup report => $(date)"   my@email.net)
Sep 18 13:59:01 gordon /USR/SBIN/CRON[20892]: (root) CMD (/usr/bin/bkpTool 2>&1 | mail -s "GORDON: Backup report => $(date)" my@email.net)
Sep 19 13:59:01 gordon /USR/SBIN/CRON[30375]: (root) CMD (/usr/bin/bkpTool 2>&1 | mail -s "GORDON: Backup report => $(date)" my@email.net)

how can this be? am I missing something? the cron executes the script at 01:59 PM instead of 7:59 AM...

if someone can just sched some light to me it would be great as I'm in a `while true` loop for more than an hour trying to figure this out with no success

thanks,

- d

pan64 · 09-20-2012, 12:56 AM

What can be found int the subject of the mail sent by the cronjob? "GORDON: Backup report => $(date)"
I can only imagine some tricky timezone settings.

educated__fool · 09-20-2012, 12:59 AM

Hey, pan64 thanks for your prompt reply. Here's what the subject looks like:

Code:

GORDON: Backup report => Tue Sep 18 13:59:01 CEST 2012

I checked the time zone too but anyhow:

Code:

┌─[07:58:52]-[root@gordon]-[/etc/nginx]
└─› ls -la /etc/localtime 
lrwxrwxrwx 1 root root 33 Aug 27 08:43 /etc/localtime -> /usr/share/zoneinfo/Europe/Skopje

┌─[07:58:53]-[root@gordon]-[/etc/nginx]
└─› date
Thu Sep 20 07:58:55 CEST 2012

have really no idea what's going on...

Satyaveer Arya · 09-20-2012, 01:03 AM

Hi educated,

You said that your script is executing but at different time. So, sure the problem is of time or time zone on your system.

pan64 · 09-20-2012, 01:04 AM

I would try to compare the environment (that means you execute set in a cronjob, save the output and compare it with set executed in a normal shell)

educated__fool · 09-20-2012, 01:20 AM

i've put this to run with set -x

Code:

*/5  *   *   *   * /usr/bin/bkpTool 2>&1 | mail -s "GORDON: Backup report => $(date)" e@mail.com

and am waiting to complete and then to compare them. anyhow, here's what the env used by the cron looks like:

Code:

*/1  *   *   *   *  env > /tmp/env.cron

┌─[08:15:50]-[root@gordon]-[~]
└─› cat /tmp/env.cron 
HOME=/root
LOGNAME=root
PATH=/usr/bin:/bin
LANG=en_US.UTF-8
SHELL=/bin/sh
PWD=/root

pan64 · 09-20-2012, 01:23 AM

and what is the env of a normal shell?

educated__fool · 09-20-2012, 01:26 AM

here's the difference between them:

Code:

┌─[08:23:35]-[root@gordon]-[~]
└─› diff -u /tmp/env.cron /tmp/env.shell 
--- /tmp/env.cron	2012-09-20 08:12:01.000000000 +0200
+++ /tmp/env.shell	2012-09-20 08:12:47.000000000 +0200
@@ -1,6 +1,55 @@
+LESS_TERMCAP_mb=
+LESS_TERMCAP_md=
+LESS_TERMCAP_me=
+MAILTO=m@email.net
+SHELL=/bin/bash
+TERM=screen
+HISTSIZE=20000
+SSH_CLIENT=XXX.XXX.XXX.XXX 43378 PORT
+LESS_TERMCAP_ue=
+SSH_TTY=/dev/pts/0
+USER=root
+TERMCAP=SC|screen|VT 100/ANSI X3.64 virtual terminal:\
+	:DO=\E[%dB:LE=\E[%dD:RI=\E[%dC:UP=\E[%dA:bs:bt=\E[Z:\
+	:cd=\E[J:ce=\E[K:cl=\E[H\E[J:cm=\E[%i%d;%dH:ct=\E[3g:\
+	:do=^J:nd=\E[C:pt:rc=\E8:rs=\Ec:sc=\E7:st=\EH:up=\EM:\
+	:le=^H:bl=^G:cr=^M:it#8:ho=\E[H:nw=\EE:ta=^I:is=\E)0:\
+	:li#56:co#183:am:xn:xv:LP:sr=\EM:al=\E[L:AL=\E[%dL:\
+	:cs=\E[%i%d;%dr:dl=\E[M:DL=\E[%dM:dc=\E[P:DC=\E[%dP:\
+	:im=\E[4h:ei=\E[4l:mi:IC=\E[%d@:ks=\E[?1h\E=:\
+	:ke=\E[?1l\E>:vi=\E[?25l:ve=\E[34h\E[?25h:vs=\E[34l:\
+	:ti=\E[?1049h:te=\E[?1049l:us=\E[4m:ue=\E[24m:so=\E[3m:\
+	:se=\E[23m:mb=\E[5m:md=\E[1m:mr=\E[7m:me=\E[m:ms:\
+	:Co#8:pa#64:AF=\E[3%dm:AB=\E[4%dm:op=\E[39;49m:AX:\
+	:vb=\Eg:G0:as=\E(0:ae=\E(B:\
+	:ac=\140\140aaffggjjkkllmmnnooppqqrrssttuuvvwwxxyyzz{{||}}~~..--++,,hhII00:\
+	:po=\E[5i:pf=\E[4i:k0=\E[10~:k1=\EOP:k2=\EOQ:k3=\EOR:\
+	:k4=\EOS:k5=\E[15~:k6=\E[17~:k7=\E[18~:k8=\E[19~:\
+	:k9=\E[20~:k;=\E[21~:F1=\E[23~:F2=\E[24~:F3=\E[1;2P:\
+	:F4=\E[1;2Q:F5=\E[1;2R:F6=\E[1;2S:F7=\E[15;2~:\
+	:F8=\E[17;2~:F9=\E[18;2~:FA=\E[19;2~:kb=:K2=\EOE:\
+	:kB=\E[Z:kF=\E[1;2B:kR=\E[1;2A:*4=\E[3;2~:*7=\E[1;2F:\
+	:#2=\E[1;2H:#3=\E[2;2~:#4=\E[1;2D:%c=\E[6;2~:%e=\E[5;2~:\
+	:%i=\E[1;2C:kh=\E[1~:@1=\E[1~:kH=\E[4~:@7=\E[4~:\
+	:kN=\E[6~:kP=\E[5~:kI=\E[2~:kD=\E[3~:ku=\EOA:kd=\EOB:\
+	:kr=\EOC:kl=\EOD:km:
+LESS_TERMCAP_us=
+PATH=/root/bin:/root/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
+MAIL=/var/mail/root
+STY=2018.ViruSzZ
+PWD=/etc/nginx
+EDITOR=vim
+LANG=en_US.UTF-8
+HISTCONTROL=ignoredups:ignorespace
 HOME=/root
+SHLVL=2
+SCREEN_CONF_DIR=/root/.screen/configs
 LOGNAME=root
-PATH=/usr/bin:/bin
-LANG=en_US.UTF-8
-SHELL=/bin/sh
-PWD=/root
+VISUAL=vim
+WINDOW=0
+SSH_CONNECTION=XXX.XXX.XXX.XXX 43378 XXX.XXX.XXX.XXX PORT
+LESS_TERMCAP_so=
+SCREEN_CONF=main
+LESS_TERMCAP_se=
+_=/usr/bin/env
+OLDPWD=/root

thanks,

educated__fool · 09-20-2012, 01:37 AM

ok, this is solved by running:

Code:

┌─[08:33:16]-[root@gordon]-[~]
└─› dpkg-reconfigure tzdata

don't know why as I just re-set the same settings I set before .... Europe/Skopje and to test it set the cron to run at 08:35 and it executed just fine....

marking this as [SOLVED] ... what a waste of time ... but still interesting ....

thank you all for your inputs.

take care,

- d

EDIT: Sorry, but how would I go editing the subject and appending [SOLVED] to it?
EDIT2: Ok, found it at the top-right ..... I'm kinda tired was working 3rd shift all night long ...