logs del cron y mail no coinciden

Victor Hugo dos Santos listas.vhs en gmail.com
Lun Ene 26 10:03:02 CLST 2009


Hola a todos,

Tengo las siguientes linea en el archivo /etc/cron.d/dbnet

=============
$ sudo cat /etc/cron.d/dbnet
# Detencion de los servicios de DBNET
0 3 * * * root /etc/init.d/dbnet stop
0 3 * * * root echo "hola 3:0" | mail root
0 5 * * * root /etc/init.d/dbnet start
0 5 * * * root echo "hola 5:0" | mail root
=============

Los comandos "echos" lo puse, para poder depurar el problema y
funciona correctamente a la hora estipulada
pero "algo" raro, pasa con los comandos start/stop.. bueno, el start
especificamente, pues este es lo que tengo en los logs (/var/log/cron)

=============
$ sudo cat cron cron.1 | egrep '(init|hola)'
Jan 25 03:00:01 dbnetbd crond[25594]: (root) CMD (echo "hola 3:0" | mail root )
Jan 25 03:00:01 dbnetbd crond[25596]: (root) CMD (/etc/init.d/dbnet stop)
Jan 25 05:00:01 dbnetbd crond[19285]: (root) CMD (echo "hola 5:0" | mail root )
Jan 25 05:00:01 dbnetbd crond[19287]: (root) CMD (/etc/init.d/dbnet start )

Jan 26 03:00:02 dbnetbd crond[19454]: (root) CMD (echo "hola 3:0" | mail root )
Jan 26 03:00:02 dbnetbd crond[19457]: (root) CMD (/etc/init.d/dbnet stop)
Jan 26 05:00:02 dbnetbd crond[23854]: (root) CMD (echo "hola 5:0" | mail root )
Jan 26 05:00:02 dbnetbd crond[23866]: (root) CMD (/etc/init.d/dbnet start )
=============

Teoricamente "correcto", pero estos son los correos que recibo a
diario con la salida de los comandos de mas arriba (observen que
ambos correos, son enviados a las 03:00:02):

===================
Recibido: from dbnetbd by  (MDaemon PRO v9.6.5)
 with ESMTP id md50007430798.msg
 for <linux_admin>; Mon, 26 Jan 2009 02:56:50 -0300
X-Spam-Processed: , Mon, 26 Jan 2009 02:56:50 -0300
 (not processed: message from trusted or authenticated source)
X-Rcpt-To: linux_admin
X-MDRcpt-To: linux_admin
X-Envelope-From: root en dbnetbd
Recibido: by dbnetbd (Postfix)
 id D59D734437; Mon, 26 Jan 2009 03:00:03 -0300 (CLST)
Distribuido-A: root en dbnetbd
Recibido: by dbnetbd (Postfix, from userid 0)
 id CCE1933CF8; Mon, 26 Jan 2009 03:00:02 -0300 (CLST)
Desde: root en dbnetbd (Cron Daemon)
Para: root en dbnetbd
Asunto: Cron <root en dbnetbd> /etc/init.d/dbnet stop
X-Cron-Env: <SHELL=/bin/sh>
X-Cron-Env: <HOME=/root>
X-Cron-Env: <PATH=/usr/bin:/bin>
X-Cron-Env: <LOGNAME=root>
X-Cron-Env: <USER=root>
Message-Id: <20090126060003.CCE1933CF8 en dbnetbd>
Fecha: Mon, 26 Jan 2009 03:00:02 -0300 (CLST)
Responder a: root en dbnetbd
X-MDAV-Processed: , Mon, 26 Jan 2009 02:56:50 -0300
X-MDRedirect: 1
X-Return-Path: linux_admin

-----------------------

Recibido: from dbnetbd by  (MDaemon PRO v9.6.5)
 with ESMTP id md50007430799.msg
 for <linux_admin>; Mon, 26 Jan 2009 02:56:50 -0300
X-Spam-Processed: , Mon, 26 Jan 2009 02:56:50 -0300
 (not processed: message from trusted or authenticated source)
X-Rcpt-To: linux_admin
X-MDRcpt-To: linux_admin
X-Envelope-From: root en dbnetbd
Recibido: by dbnetbd (Postfix)
 id 1E03033CF8; Mon, 26 Jan 2009 03:00:05 -0300 (CLST)
Distribuido-A: root en dbnetbd
Recibido: by dbnetbd (Postfix, from userid 0)
 id D1C7634433; Mon, 26 Jan 2009 03:00:02 -0300 (CLST)
Desde: root en dbnetbd (Cron Daemon)
Para: root en dbnetbd
Asunto: Cron <root en dbnetbd> /etc/init.d/dbnet start
X-Cron-Env: <SHELL=/bin/sh>
X-Cron-Env: <HOME=/root>
X-Cron-Env: <PATH=/usr/bin:/bin>
X-Cron-Env: <LOGNAME=root>
X-Cron-Env: <USER=root>
Message-Id: <20090126060003.D1C7634433 en dbnetbd>
Fecha: Mon, 26 Jan 2009 03:00:02 -0300 (CLST)
Responder a: root en dbnetbd
X-MDAV-Processed: , Mon, 26 Jan 2009 02:56:50 -0300
X-MDRedirect: 1
X-Return-Path: linux_admin
===================


Y en los logs del servidor de correo (local), me confirma que los
correos fueron enviado a las 03:00:00

==================
Jan 26 03:00:03 dbnetbd postfix/pickup[17603]: CCE1933CF8: uid=0 from=<root>
Jan 26 03:00:03 dbnetbd postfix/cleanup[19520]: CCE1933CF8:
message-id=<20090126060003.CCE1933CF8 en dbnetbd>
Jan 26 03:00:03 dbnetbd postfix/qmgr[1331]: CCE1933CF8:
from=<root en dbnetbd>, size=758, nrcpt=1 (queue active)
Jan 26 03:00:03 dbnetbd postfix/pickup[17603]: D1C7634433: uid=0 from=<root>
Jan 26 03:00:03 dbnetbd postfix/cleanup[19522]: D1C7634433:
message-id=<20090126060003.D1C7634433 en dbnetbd>
Jan 26 03:00:03 dbnetbd postfix/cleanup[19525]: D59D734437:
message-id=<20090126060003.CCE1933CF8 en dbnetbd>
Jan 26 03:00:05 dbnetbd postfix/qmgr[1331]: D1C7634433:
from=<root en dbnetbd>, size=924, nrcpt=1 (queue active)
Jan 26 03:00:05 dbnetbd postfix/local[19524]: CCE1933CF8:
to=<root en dbnetbd>, orig_to=<root>, relay=local, delay=3, status=sent
(forwarded as D59D734437)
Jan 26 03:00:05 dbnetbd postfix/qmgr[1331]: CCE1933CF8: removed
Jan 26 03:00:05 dbnetbd postfix/cleanup[19520]: 1E03033CF8:
message-id=<20090126060003.D1C7634433 en dbnetbd>
Jan 26 03:00:05 dbnetbd postfix/local[19523]: D1C7634433:
to=<root en dbnetbd>, orig_to=<root>, relay=local, delay=3, status=sent
(forwarded as 1E03033CF8)
Jan 26 03:00:05 dbnetbd postfix/qmgr[1331]: D1C7634433: removed
Jan 26 03:00:05 dbnetbd postfix/smtp[19526]: D59D734437:
to=<linux_admin>, orig_to=<root>, relay=mail[192.168.1.28], delay=2,
status=sent (250 Ok, message saved <Message-ID:
20090126060003.CCE1933CF8 en dbnetbd>)
Jan 26 03:00:05 dbnetbd postfix/smtp[19528]: 1E03033CF8:
to=<linux_admin>, orig_to=<root>, relay=mail[192.168.1.28], delay=0,
status=sent (250 Ok, message saved <Message-ID:
20090126060003.D1C7634433 en dbnetbd>)
==================


Nuevamente digo que los correos de prueba (echo hola), funcionan en la
hora correcta:

==================
Para: root en dbnetbd
Message-Id: <20090126060003.C6BC534434 en dbnetbd>
Fecha: Mon, 26 Jan 2009 03:00:02 -0300 (CLST)
Desde: root en dbnetbd (root)
Responder a: root en dbnetbd
X-MDAV-Processed: , Mon, 26 Jan 2009 02:56:50 -0300

hola 3:0
------------------------------------
Para: root en dbnetbd
Message-Id: <20090126080002.A92DD34434 en dbnetbd>
Fecha: Mon, 26 Jan 2009 05:00:02 -0300 (CLST)
Desde: root en dbnetbd (root)
Responder a: root en dbnetbd
X-MDAV-Processed: , Mon, 26 Jan 2009 04:56:48 -0300

hola 5:0
==================

Asi, que tengo la duda de si realmente se esta ejecutando a las 05:00:00 !!! :-(
y en caso positivo, por que demonios sera que envía los correos a las
03:00AM  ???

alguna idea/sugerencia de donde buscar el problema ???

salu2

-- 
-- 
Victor Hugo dos Santos
Linux Counter #224399



Más información sobre la lista de distribución Linux