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
|
|
|