Hi, [I changed the name of this thread, as I realized that I more or less hijacked this thread from [EMAIL PROTECTED] and two threads with the same subject proceeded in parallel, my sincere apologies to [EMAIL PROTECTED] and to the list]
Mark Sapiro wrote: > Rolf E. Sonneveld wrote: > >> Mark Sapiro wrote: >> >>> One minor point here. The post log entry is not written until the >>> message is delivered by SMTPDirect. >>> >>> >> OK, thus only after the message has been delivered to at least one >> subscriber (or the first MTA in the chain of delivery to at least one >> subscriber). >> > > > Yes, the first MTA, namely the one on localhost, port 25 unless > overridden by SMTPHOST/SMTPPORT in mm_cfg.py. There is no guarantee > this MTA has sent the message further. You need to refer the the MTA's > logs for that. > OK, there was no message submission to the MTA, and this corresponds to the fact that there are no entries in smtp and smtp-failure logfiles. >> In my case there were no entries in smtp nor in smtp-failure. >> > > > So the message didn't get that far. > > > >>> 1) The MTA pipes the message to the wrapper which passes it to the >>> scripts/post script which in turn places it in the qfiles/in queue. >>> Nothing is logged in Mailman, but the MTA normally logs the delivery. >>> >>> >> Now here's the problem, I think. The MTA logs the message as being >> delivered to Mailman (via the wrapper script >> $MAILMANDIR/mailman/bin/mailman), so from the MTA's point of view it's >> done. Now, as the sent message cannot be found under qfiles, and as none >> of the $MAILMANDIR/logs/* files is modified, it seems as if the message >> disappeared in a black hole. Is there no way to enable debugging in the >> wrapper script? It would show the first action of Mailman, I assume. >> > > > There are at least two possibilities here. > > 1) The post was rejected (not held or discarded). A reject is not > logged, but there should be an associated entry in Mailman's smtp log > with a mailman generated message-id and 1 recipient for the reject > message sent to the poster. > There is none. > 2) The wrapper is for a different Mailman installation with a different > qfiles directory and probably no qrunners running and probably > different log files too. > I see no other installation; I have only one in /usr/local/mailman. > The wrapper itself (I would expect it to be located at > $MAILMANDIR/mail/mailman, not $MAILMANDIR/mailman/bin/mailman) correct, I made a wrong assumption when I was typing. I doublechecked and the mailman wrapper is at $MAILMANDIR/mail/mailman. > has the > path to the scripts/ directory compiled in and doesn't have any debug > switches. It will invoke the scripts/post script and presumably this > happens OK or it will return a failure status to the MTA which would > be logged by the MTA. > The logfile within the MTA shows: 11:26:48.08: middleman version 0.2 starting, pid 25427 11:26:48.16: channel: mailman 11:26:48.17: option file: IMTA_TABLE:mailman_option 11:26:48.17: Opening the channel option file 11:26:48.17: mtaOptionStart: succeeded 11:26:48.17: WRAPPER=/usr/local/mailman/mail/mailman 11:26:48.17: MAX_THREADS=5 11:26:48.17: mtaDequeueStart() 11:26:48.17: #1: process_message() callback 11:26:48.17: #1: build_operations() starting 11:26:48.17: #1: first address: [EMAIL PROTECTED] 11:26:48.17: #1: localpart: allloc5estatic-owner 11:26:48.17: #1: listname: allloc5estatic 11:26:48.17: #1: command: owner 11:26:48.17: #1: build_operations() returning 11:26:48.17: #1: get_messagefile() starting 11:26:48.17: #1: opening tmpfile 11:26:48.19: #1: wrote tmpfile successfully 11:26:48.19: #1: get_messagefile() returning 11:26:48.19: #1: running wrapper for every recipient 11:26:48.19: #1: seeking back to the beginning of the message 11:26:48.19: #1: about to fork() 11:26:48.19: #1: command completed successfully 11:26:48.19: #1: cleaning up 11:26:48.19: #1: mm_opers_free() starting 11:26:48.19: #1: mm_opers_free() returning 11:26:48.19: #1: waiting child 25428 11:26:48.20: #1: dequeue finished 11:26:48.21: #1: command completed successfully 11:26:48.21: #1: cleaning up 11:26:48.21: #1: mm_opers_free() starting 11:26:48.21: #1: mm_opers_free() returning 11:26:48.21: #1: dequeue finished 11:29:48.00: mtaDequeueStart() returned > You can add debugging to the scripts/post script. If you look at this > script, you will see that it already detects a missing or invalid list > name from the wrapper and writes to stderr which is logged to both the > post and error logs. > > You could add some more output, say by adding the last two lines of > > inq = get_switchboard(mm_cfg.INQUEUE_DIR) > inq.enqueue(sys.stdin.read(), > listname=listname, > tolist=1, _plaintext=1) > print >> sys.stderr, 'Post for %s queued in %s' \ > % (listname, mm_cfg.INQUEUE_DIR) > I have added the last two lines, but nothing is written to the post logfile. > If you don't see this in the post and error logs, you are not looking > at the right installation or (third possibility) the right log files. > Look in mm_cfg.py/Defaults.py for the definition of LOG_DIR and > anything else used in its definition. > The mm_cfg.py does not define LOG_DIR. In /usr/local/mailman/Mailman/Defaults.py it is defined as: LOG_DIR = os.path.join(VAR_PREFIX, 'logs') where VAR_PREFIX is defined in the same file as: VAR_PREFIX = '/usr/local/mailman' > This can be tricky. LOG_DIR is defined in Defaults.py in terms of > VAR_PREFIX. If VAR_PREFIX is redefined in mm_cfg.py, this will not > redefine LOG_DIR as LOG_DIR was already defined in Defaults.py in > terms of the Defaults.py definition of VAR_PREFIX. > I see; however in my case this seems to be not the problem, as mm_cfg.py does not define LOG_DIR nor VAR_PREFIX. Now, I tested the following: I became user mailman mailman> cd /usr/local/mailman/scripts mailman> ./post <listname> <message input> <ctrl-D> and indeed something showed up in the locks logfile, as well as in the post logfile and in the bounce logfile (as the sender address was not defined, mailman could not authorize the message submissions, which ended in a bounce). So it seems that the calling program within the MTA gets a positive success status from mailman, but something is wrong during message submission. To repeat part of he logfile: [...] 11:26:48.19: #1: running wrapper for every recipient 11:26:48.19: #1: seeking back to the beginning of the message 11:26:48.19: #1: about to fork() 11:26:48.19: #1: command completed successfully 11:26:48.19: #1: cleaning up 11:26:48.19: #1: mm_opers_free() starting 11:26:48.19: #1: mm_opers_free() returning 11:26:48.19: #1: waiting child 25428 11:26:48.20: #1: dequeue finished 11:26:48.21: #1: command completed successfully 11:26:48.21: #1: cleaning up [...] /rolf ------------------------------------------------------ Mailman-Users mailing list Mailman-Users@python.org http://mail.python.org/mailman/listinfo/mailman-users Mailman FAQ: http://www.python.org/cgi-bin/faqw-mm.py Searchable Archives: http://www.mail-archive.com/mailman-users%40python.org/ Unsubscribe: http://mail.python.org/mailman/options/mailman-users/archive%40jab.org Security Policy: http://www.python.org/cgi-bin/faqw-mm.py?req=show&file=faq01.027.htp
