getmail een beetje in de fout wanneer cron gebruikt wordt

[Verwijderd]

Gegroet Tweakers,

Ik ben bezig met het opzetten van een nieuw email systeem voor het plaatselijke streekmuseum. We zijn uitgekomen op Zarafa aangevuld met postfix en getmail. Alles draait op Ubuntu server 8.04 (voorlopig).

Ik heb iets raars met getmail waar ik geen verklaring/oplossing voor kan vinden. Als ik getmail in een shell start dan worden de POP mailboxen van de provider gelezen en worden de emails uitgesorteerd naar bestemming (dit laatste heeft te maken met het gebruik van aliassen in de betreffende POP mailboxen).

Als laatse gebruikt getmail het sendmail commando (van postfix) om de emails daar in de pickup queue te zetten. Alles werkt! Met andere woorden ik heb de getmailrc configuratie file helemaal spits (dacht ik).

Maar dan ga ik het aanroepen van getmail in crontab zetten. Ook dat werkt maar er komen wel extra emails uit getmail (en dus in postfix) met als inhoud dat er "iets" met de adressering niet deugt.

Het gaat hier eigenlijk om het verschil tussen het interactief uitvoeren van getmail versus het via crond uitvoeren. IMHO zou daar geen verschil in moeten zitten maar ik kan er natuurlijk geheel naast zitten...

Komt dit verschijnsel bekend voor of heb ik _echt_ iets niews voor elkaar weten te krijgen?

Hope to hear, Aad

[CyBeR]

De monumentale fout die je hier maakt is dat je noch je configuratie, noch die 'extra' emails post. Zo weten we dus helemaal niets.

[Verwijderd]

CyBeR schreef op zaterdag 22 mei 2010 @ 18:25:
De monumentale fout ...

Mea culpa. Hoe kan ik zo dom zijn... Mijn verhaal gaat dan hier verder.
Ik gebruik het userid vmail voor het 'runnen' van de getnail utility. De configuratie file van getmail staat dan ook in de directory /home/vmail/.getmail/getmailrc. De inhoud is:

code:

#
# /home/vmail/.getmail/getmailrc
#
# 20100502 initial version for testing.
#
[retriever]
type = SimplePOP3Retriever
server = pop.museum.nl
username = [e-mail]
password = **

[destination]
type = MultiGuesser
default = [admin]
locals = (
  ('palm2009@', '[palm2009]'),
  ('beuk2009@', '[beuk2009]'),
  ('berk2009@', '[berk2009]'),
  ('wilg2009@', '[wilg2009]'),
  ('eik2009@',  '[eik2009]')
  )

[admin]
type = MDA_external
path = /usr/sbin/sendmail
arguments = ("-i", "[e-mail]")

[palm2009]
type = MDA_external
path = /usr/sbin/sendmail
arguments = ("-i", "[e-mail]")

[beuk2009]
type = MDA_external
path = /usr/sbin/sendmail
arguments = ("-i", "[e-mail]")

[berk2009]
type = MDA_external
path = /usr/sbin/sendmail
arguments = ("-i", "[e-mail]")

[wilg2009]
type = MDA_external
path = /usr/sbin/sendmail
arguments = ("-i", "[e-mail]")

[eik2009]
type = MDA_external
path = /usr/sbin/sendmail
arguments = ("-i", "[e-mail]")

[options]
verbose = 2
delivered_to = false
received = false
message_log = /var/log/getmail/log
message_log_verbose = true
#
# Do not delete email from provider during testing.
# Change to true when production started.
#
delete = false

#
# EOF
#

Het was even prutsen maar het werkt. Vervolgens komt hier de log file van getmail. Slechts een paar regels.

code:

2010-05-22 17:01:01 Initializing SimplePOP3Retriever:[e-mail]@pop.museum.nl:110:
2010-05-22 17:01:02 msg 1/1 (2048 bytes) msgid D07BA9250CD94408B05B483DABD473C8 from <[e-mail]> delivered to MultiGuesser (default MDA_external command sendmail ())

Ook dit is als verwacht. Het maakt hier geen verschil of getmail interactief uitgevoerd wordt of met behulp van cron. Vervolgens kijk ik met het mailq commando naar de postfix queue (BTW postfix is op dit moment gestopt).

code:

-Queue ID- --Size-- ----Arrival Time---- -Sender/Recipient-------
982A0326FA      802 Sat May 22 15:01:01  vmail
                                         vmail

0486B326FB     2128 Sat May 22 15:01:02  vmail
                                         [e-mail]

-- 2 Kbytes in 2 Requests.

De tweede entry is de normale. De "vreemde eend" is de eerste. Deze komt niet voor als getmail interactief gebruikt wordt. Als ik nu postfix start dan komen er (vanwege de eerste email in de queue) een aantal foutmeldingen in de log die niet voorkomen bij interactief gebruik van getmail.

code:

May 22 19:15:30 bunto804 postfix/postfix-script[8652]: starting the Postfix mail system
May 22 19:15:30 bunto804 postfix/master[8653]: daemon started -- version 2.5.1, configuration /etc/postfix
May 22 19:15:30 bunto804 postfix/pickup[8654]: 96403326F8: uid=1001 from=<vmail>
May 22 19:15:30 bunto804 postfix/cleanup[8656]: 96403326F8: message-id=<[e-mail]>
May 22 19:15:30 bunto804 postfix/qmgr[8655]: 96403326F8: from=<[e-mail]>, size=987, nrcpt=1 (queue active)
May 22 19:15:30 bunto804 postfix/pickup[8654]: 9D137326F9: uid=1001 from=<vmail>
May 22 19:15:30 bunto804 postfix/cleanup[8656]: 9D137326F9: message-id=<[e-mail]>
May 22 19:15:30 bunto804 postfix/qmgr[8655]: 9D137326F9: from=<[e-mail]>, size=2120, nrcpt=1 (queue active)
May 22 19:15:30 bunto804 postfix/lmtp[8660]: 96403326F8: to=<[e-mail]>, orig_to=<vmail>, relay=127.0.0.1[127.0.0.1]:2003, delay=8069, delays=8069/0.03/0.05/0.05, dsn=5.1.1, status=bounced (host 127.0.0.1[127.0.0.1] said: 503 5.1.1 User does not exist (in reply to RCPT TO command))
May 22 19:15:30 bunto804 postfix/cleanup[8656]: BCFA2326FB: message-id=<[e-mail]>
May 22 19:15:30 bunto804 postfix/qmgr[8655]: BCFA2326FB: from=<>, size=2884, nrcpt=1 (queue active)
May 22 19:15:30 bunto804 postfix/bounce[8664]: 96403326F8: sender non-delivery notification: BCFA2326FB
May 22 19:15:30 bunto804 postfix/qmgr[8655]: 96403326F8: removed
May 22 19:15:30 bunto804 postfix/lmtp[8660]: BCFA2326FB: to=<[e-mail]>, relay=127.0.0.1[127.0.0.1]:2003, delay=0.11, delays=0.03/0/0.04/0.03, dsn=5.1.1, status=bounced (host 127.0.0.1[127.0.0.1] said: 503 5.1.1 User does not exist (in reply to RCPT TO command))
May 22 19:15:30 bunto804 postfix/qmgr[8655]: BCFA2326FB: removed
May 22 19:15:30 bunto804 postfix/lmtp[8661]: 9D137326F9: to=<[e-mail]>, relay=127.0.0.1[127.0.0.1]:2003, delay=8069, delays=8069/0.03/0.08/0.16, dsn=2.1.5, status=sent (250 2.1.5 [e-mail] Ok)
May 22 19:15:30 bunto804 postfix/qmgr[8655]: 9D137326F9: removed

Het goede nieuws is dat de email aan de geadresseerde uiteindelijk netjes afgeleverd word. Het is niet zo dat het hele systeem niet werkt. Ik vindt het echter nogal slordig om dit in produktie te nemen. En verder ben ik ook gewoon nieuwsgierig naar de oorzaak...

[CyBeR]

Als je getmail interactief draait, krijg je dan output? Zo ja, dan is dat waarschijnlijk het 'probleem'. Cron stuurt default alle output van een commando via email naar de gebruiker waar de job onder draait. Kijk dus even of je getmail kunt laten loggen naar een file ipv stdout.

[Verwijderd]

CyBeR schreef op zaterdag 22 mei 2010 @ 19:34:
Als je getmail interactief draait, krijg je dan output? Zo ja, dan is dat waarschijnlijk het 'probleem'. Cron stuurt default alle output van een commando via email naar de gebruiker waar de job onder draait. Kijk dus even of je getmail kunt laten loggen naar een file ipv stdout.

Je hebt helemaal gelijk. Ik was net weer een stukkie in "Postfix - The definitive guide" aan het lezen en zo kwam ik bij het postcat commando. Hier is de inhoud van het "vreemde" email bericht in de postfix queue

code:

*** ENVELOPE RECORDS maildrop/982A0326FA ***
message_arrival_time: Sat May 22 17:01:01 2010
named_attribute: rewrite_context=local
sender_fullname: CronDaemon
sender: vmail
recipient: vmail
*** MESSAGE CONTENTS maildrop/982A0326FA ***
From: root (Cron Daemon)
To: vmail
Subject: Cron <vmail@bunto804> getmail
Content-Type: text/plain; charset=ANSI_X3.4-1968
X-Cron-Env: <SHELL=/bin/sh>
X-Cron-Env: <HOME=/home/vmail>
X-Cron-Env: <PATH=/usr/bin:/bin>
X-Cron-Env: <LOGNAME=vmail>

getmail version 4.7.7
Copyright (C) 1998-2007 Charles Cazabon.  Licensed under the GNU GPL version 2.
SimplePOP3Retriever:[e-mail]@pop.museum.nl:110:
  msg 1/1 (2048 bytes) from <[e-mail]> delivered to MultiGuesser (default MDA_external command sendmail ())
  1 messages (2048 bytes) retrieved, 0 skipped
Summary:
Retrieved 1 messages (2048 bytes) from SimplePOP3Retriever:[e-mail]@pop.museum.nl:110
*** HEADER EXTRACTED maildrop/982A0326FA ***
*** MESSAGE FILE END maildrop/982A0326FA ***

In de crontab van de user vmail stond:

code:

01,16,31,46 * * * * getmail

Nu staat er:

code:

01,16,31,46 * * * * getmail > /dev/null 2>&1

Met dank voor het aanhoren van dit probleem