Re: skipped, still being delivered !!!!????

From: Lutz Jaenicke (no email)
Date: Mon Oct 22 2001 - 07:02:24 EDT


On Fri, Oct 19, 2001 at 11:14:34PM +0200, Manuel Hendel wrote:
> Where does this message come from, and why does it come so often.
> More than 5000 times a day. I didn't flushed postfix and just reloaded
> once. For some reason the queue is flushed every minute, I don't know
> why.
> I already use "smtpd_etrn_restrictions = reject". I don't know what to
> do anymore. I already tried to fix this problem with the help of Ralf
> Hildebrand (Thank you very much!), but we couldn't get it.

Hmm. I step in on this message (I read the entire thread, though).
If there was an earlier thread on that topic, I have missed it, so please
excuse if some of my statements were already discussed.

The message is generated by qmgr (or nqmgr), when it tries to open a queue
file for processing and finds, that the file is locked using the
operating system dependant file system locking mechanism (flock(), fcntl(),
hidden inside Postfix's myflock() call). As the file is locked, [n]qmgr
concludes that the file is actually being processed (delivered).
* This can and will happen, if a queue file is still being delivered,
  when [n]qmgr starts another queue run for whatever reason. The options
  have already been discussed in this thread.
  Please check out the PID of the [n]qmgr process. If [n]qmgr is restarted
  due to a table change, actually a new process is spawned and a new PID
  should be seen. If this does not happen, you can already rule out this
  option.
* If a queue file is under processing (delivery), another postfix process
  should be handling it. Thus, if the queue file 3FC9A2219 is being processed
  and the message occurs, you see another process (e.g. smtp) handling it.
  If you grep in the syslog file for 3FC9A2219, you should find
  Oct 18 17:41:13 ws01 postfix/nqmgr[24139]: 3FC9A2219: from=<>, size=2394, nrcpt=1 (queue active)
  ...
  Oct 18 17:41:16 ws01 postfix/smtp[6324]: 3FC9A2219: to=<>, relay=serv01.aet.tu-cottbus.de[141.43.132.161], delay=4, status=sent (250Ok: queued as B85C0299E)

  The "skipped, ..." message should only occur between these two messages
  and would indicate, that another queue run was started in between.
  From the log entries you should also see, whether delivery was abnormally
  slow (here you see approx. 3 seconds between start and delivery, needed
  because the TLS handshake took place, I have omitted the log entries).
  With the log entries you can also see the PID of the (smtp) process
  called by [n]qmgr (in the example it is 6324), so that you can check out
  the other corresponding entries related to this process.
* Long delivery exceeding the queue manager time constant can happen with
  slow connections and large mails. You should however be able to identify
  these problems from the logfiles and they should not occur that often.
  You may also identify them with the "mailq" command, as "active" messages
  are indicated by an asterisk "*". Only those message may lead to the
  "skipped, ..." log file entry.
* Some information missing in your post is, whether these messages occur
  for the same queue file (same queue ID) or for "random" queue entries.
  This might lead to some systematic effect (or not).
* It is also possible that your operating system has a buggy lockf()/flock()
  implementation that returns false values and thus causes [n]qmgr to
  issue false warnings (and unnecessarily delay delivery). Please post your
  operating system (and file system) information.

Best regards,
        Lutz

-- 
Lutz Jaenicke                             
BTU Cottbus               http://www.aet.TU-Cottbus.DE/personen/jaenicke/
Lehrstuhl Allgemeine Elektrotechnik                  Tel. +49 355 69-4129
Universitaetsplatz 3-4, D-03044 Cottbus              Fax. +49 355 69-4153
-
To unsubscribe, send mail to  with content
(not subject): unsubscribe postfix-users







Hosted Email Solutions

Invaluement Anti-Spam DNSBLs



Powered By FreeBSD   Powered By FreeBSD