queue lifetime

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
15 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

queue lifetime

Sascha Hüdepohl-3
Hi!

On my server i have two mails in queue which can't be delivered because
there seems to be no smtp-server reachable for the domain (mainz.de).
This all doenst bother me.

Which i can't understand is that they are in queue since May  8 11:20
and i have:

/usr/sbin/postconf | grep lifetime
bounce_queue_lifetime = 2d
maximal_queue_lifetime = 2d

When will these mails be bounced? What did i miss?

Regards
sascha
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: queue lifetime

Ralf Hildebrandt
* Sascha Hüdepohl <[hidden email]>:

> Hi!
>
> On my server i have two mails in queue which can't be delivered because
> there seems to be no smtp-server reachable for the domain (mainz.de).
> This all doenst bother me.
>
> Which i can't understand is that they are in queue since May  8 11:20
> and i have:
>
> /usr/sbin/postconf | grep lifetime
> bounce_queue_lifetime = 2d
> maximal_queue_lifetime = 2d
>
> When will these mails be bounced? What did i miss?

Maybe they were requeued?

--
Ralf Hildebrandt ([hidden email])          [hidden email]
Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
http://www.arschkrebs.de
DISCLAIMER:
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: queue lifetime

Sascha Hüdepohl-3
* Ralf Hildebrandt ([hidden email]) wrote:
> * Sascha Hüdepohl <[hidden email]>:
> >
> > When will these mails be bounced? What did i miss?
>
> Maybe they were requeued?

When they are requeued they get a new queue-id right?

some log-entries:
mail.info: May 10 01:32:08 postfix/qmgr[10614]: 415503C2BF62:
from=<[hidden email]>, size=2015, nrcpt=1 (queue active)
mail.info: May 10 01:32:38 postfix/smtp[15814]: connect to
mainz.de[213.139.155.226]: Connection timed out (port 25)
mail.info: May 10 01:32:38 postfix/smtp[15814]: 415503C2BF62:
to=<[hidden email]>, relay=none, delay=137585,
delays=137555/0.15/30/0, dsn=4.4.1, status=deferred (connect to
 mainz.de[213.139.155.226]: Connection timed out)

Is there something wrong?

When undelivereable Mail becomes requeued after every delivery attempt
when will the queue_lifetime settings match?

I fear i missunderstood something. (aber so richtig)
Where do i need to start reading?

Regards
sascha
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: queue lifetime

Ralf Hildebrandt
* Sascha Hüdepohl <[hidden email]>:
> * Ralf Hildebrandt ([hidden email]) wrote:
> > * Sascha Hüdepohl <[hidden email]>:
> > >
> > > When will these mails be bounced? What did i miss?
> >
> > Maybe they were requeued?
>
> When they are requeued they get a new queue-id right?

Yes.

> mail.info: May 10 01:32:08 postfix/qmgr[10614]: 415503C2BF62: from=<[hidden email]>, size=2015, nrcpt=1 (queue active)
> mail.info: May 10 01:32:38 postfix/smtp[15814]: connect to mainz.de[213.139.155.226]: Connection timed out (port 25)
> mail.info: May 10 01:32:38 postfix/smtp[15814]: 415503C2BF62: to=<[hidden email]>, relay=none, delay=137585,
> delays=137555/0.15/30/0, dsn=4.4.1, status=deferred (connect to  mainz.de[213.139.155.226]: Connection timed out)

delay=137585s = 38.2h < 2d

--
Ralf Hildebrandt ([hidden email])          [hidden email]
Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
http://www.arschkrebs.de
Ralf always swears like a trooper. Just look at his picture on his web
site, you can imagine him doing it. Probably in German.
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: queue lifetime

Sascha Hüdepohl-3
* Ralf Hildebrandt ([hidden email]) wrote:

> * Sascha Hüdepohl <[hidden email]>:
> > * Ralf Hildebrandt ([hidden email]) wrote:
> > > * Sascha Hüdepohl <[hidden email]>:
> > > >
> > > > When will these mails be bounced? What did i miss?
> > >
> > > Maybe they were requeued?
> >
> > When they are requeued they get a new queue-id right?
>
> Yes.
>
> > mail.info: May 10 01:32:08 postfix/qmgr[10614]: 415503C2BF62: from=<[hidden email]>, size=2015, nrcpt=1 (queue active)
> > mail.info: May 10 01:32:38 postfix/smtp[15814]: connect to mainz.de[213.139.155.226]: Connection timed out (port 25)
> > mail.info: May 10 01:32:38 postfix/smtp[15814]: 415503C2BF62: to=<[hidden email]>, relay=none, delay=137585,
> > delays=137555/0.15/30/0, dsn=4.4.1, status=deferred (connect to  mainz.de[213.139.155.226]: Connection timed out)
>
> delay=137585s = 38.2h < 2d

Ok, but this was yesterday. Sorry i randomly chose some logentries.
The current delay is:

mail.info: May 11 13:32:39 postfix/smtp[19802]: B017B3C2BF78:
to=<[hidden email]>, relay=none, delay=267185,
delays=267155/0.1/30/0, dsn=4.4.1, status=deferred (conne
ct to mainz.de[213.139.155.226]: Connection timed out)

What does 267155/0.1/30/0 mean?

sascha

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: queue lifetime

Ralf Hildebrandt
* Sascha Hüdepohl <[hidden email]>:

> Ok, but this was yesterday. Sorry i randomly chose some logentries.
> The current delay is:
>
> mail.info: May 11 13:32:39 postfix/smtp[19802]: B017B3C2BF78: to=<[hidden email]>, relay=none, delay=267185,
> delays=267155/0.1/30/0, dsn=4.4.1, status=deferred (connect to mainz.de[213.139.155.226]: Connection timed out)

74 hours, that's a lot

Show
postconf | grep life
output.

> What does 267155/0.1/30/0 mean?

See my book :)
or slide 35 from
http://www.arschkrebs.de/slides/postfix-changes-slides.pdf

--
Ralf Hildebrandt ([hidden email])          [hidden email]
Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
http://www.arschkrebs.de
A good rule of thumb to keep in mind is that any field of study which
has "science" in its name is not a science.
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: queue lifetime

Sascha Hüdepohl-3
* Ralf Hildebrandt ([hidden email]) wrote:

> * Sascha Hüdepohl <[hidden email]>:
>
> > Ok, but this was yesterday. Sorry i randomly chose some logentries.
> > The current delay is:
> >
> > mail.info: May 11 13:32:39 postfix/smtp[19802]: B017B3C2BF78: to=<[hidden email]>, relay=none, delay=267185,
> > delays=267155/0.1/30/0, dsn=4.4.1, status=deferred (connect to mainz.de[213.139.155.226]: Connection timed out)
>
> 74 hours, that's a lot
>
> Show
> postconf | grep life
> output.

# postconf | grep life
bounce_queue_lifetime = 2d
maximal_queue_lifetime = 2d

> > What does 267155/0.1/30/0 mean?
>
> See my book :)

It's on my Desk at work.
But i think i allready found the meaning.

> or slide 35 from
> http://www.arschkrebs.de/slides/postfix-changes-slides.pdf
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: queue lifetime

Ralf Hildebrandt
* Sascha Hüdepohl <[hidden email]>:

> > > mail.info: May 11 13:32:39 postfix/smtp[19802]: B017B3C2BF78: to=<[hidden email]>, relay=none, delay=267185,
> > > delays=267155/0.1/30/0, dsn=4.4.1, status=deferred (connect to mainz.de[213.139.155.226]: Connection timed out)
> >
> > 74 hours, that's a lot
> >
> > Show
> > postconf | grep life
> > output.
>
> # postconf | grep life
> bounce_queue_lifetime = 2d
> maximal_queue_lifetime = 2d

Very odd.

--
Ralf Hildebrandt ([hidden email])          [hidden email]
Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
http://www.arschkrebs.de
I Pledge Allegiance
To the Flag
That Appears on my Desktop Startup Screen.
And to the Monopoly
For Which it Stands;
One Operating System
Over All,
Inescapable,
With Freedom and Privacy for none.
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: queue lifetime

Sascha Hüdepohl-3
* Ralf Hildebrandt ([hidden email]) wrote:

> * Sascha Hüdepohl <[hidden email]>:
>
> > > > mail.info: May 11 13:32:39 postfix/smtp[19802]: B017B3C2BF78: to=<[hidden email]>, relay=none, delay=267185,
> > > > delays=267155/0.1/30/0, dsn=4.4.1, status=deferred (connect to mainz.de[213.139.155.226]: Connection timed out)
> > >
> > > 74 hours, that's a lot
> > >
> > > Show
> > > postconf | grep life
> > > output.
> >
> > # postconf | grep life
> > bounce_queue_lifetime = 2d
> > maximal_queue_lifetime = 2d
>
> Very odd.

Hm...
I will inform the sender of the Mail and wait some more days to see what
happens.

Thanks!
sascha
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: queue lifetime

Ralf Hildebrandt
* Sascha Hüdepohl <[hidden email]>:

> > > > > mail.info: May 11 13:32:39 postfix/smtp[19802]: B017B3C2BF78: to=<[hidden email]>, relay=none, delay=267185,
> > > > > delays=267155/0.1/30/0, dsn=4.4.1, status=deferred (connect to mainz.de[213.139.155.226]: Connection timed out)
>
> Hm...
> I will inform the sender of the Mail and wait some more days to see what
> happens.

What for? You could use:
mainz.de  error:mainz.de does not accept mail
to have it bounce immediately.

First and last log entries for that queeuid B017B3C2BF78 are?

--
Ralf Hildebrandt ([hidden email])          [hidden email]
Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
http://www.arschkrebs.de
Of course it doesn't work, but look how fast it is!
                                            -- fefe
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: queue lifetime

Sascha Hüdepohl-3
* Ralf Hildebrandt ([hidden email]) wrote:

> * Sascha Hüdepohl <[hidden email]>:
>
> > > > > > mail.info: May 11 13:32:39 postfix/smtp[19802]: B017B3C2BF78: to=<[hidden email]>, relay=none, delay=267185,
> > > > > > delays=267155/0.1/30/0, dsn=4.4.1, status=deferred (connect to mainz.de[213.139.155.226]: Connection timed out)
> >
> > Hm...
> > I will inform the sender of the Mail and wait some more days to see what
> > happens.
>
> What for? You could use:
> mainz.de  error:mainz.de does not accept mail
> to have it bounce immediately.
>
> First and last log entries for that queeuid B017B3C2BF78 are?

first:
mail.info: May 10 11:46:09 postfix/pickup[16745]: B017B3C2BF78: uid=101
from=<[hidden email]> orig_id=415503C2BF62
mail.info: May 10 11:46:09 postfix/cleanup[16886]: B017B3C2BF78:
message-id=<[hidden email]>
mail.info: May 10 11:46:09 postfix/qmgr[10614]: B017B3C2BF78:
from=<[hidden email]>, size=2132, nrcpt=1 (queue active)
mail.info: May 10 11:46:40 postfix/smtp[16889]: B017B3C2BF78:
to=<[hidden email]>, relay=none, delay=174426,
delays=174396/0.1/30/0, dsn=4.4.1, s
tatus=deferred (connect to mainz.de[213.139.155.226]: Connection timed
out)

last:
mail.info: May 11 14:41:54 postfix/qmgr[19918]: B017B3C2BF78:
from=<[hidden email]>, size=2132, nrcpt=1 (queue active)
mail.info: May 11 14:42:24 postfix/smtp[20117]: connect to
mainz.de[213.139.155.226]: Connection timed out (port 25)
mail.info: May 11 14:42:24 postfix/smtp[20117]: B017B3C2BF78:
to=<[hidden email]>, relay=none, delay=271371,
delays=271341/0.11/30/0, dsn=4.4.1, status=deferred
(connect to mainz.de[213.139.155.226]: Connection timed out)
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: queue lifetime

Ralf Hildebrandt
* Sascha Hüdepohl <[hidden email]>:

> May 10 11:46:09 postfix/pickup[16745]: B017B3C2BF78: uid=101 from=<[hidden email]> orig_id=415503C2BF62
> May 10 11:46:09 postfix/cleanup[16886]: B017B3C2BF78: message-id=<[hidden email]>
> May 10 11:46:09 postfix/qmgr[10614]: B017B3C2BF78: from=<[hidden email]>, size=2132, nrcpt=1 (queue active)
> May 10 11:46:40 postfix/smtp[16889]: B017B3C2BF78: to=<[hidden email]>, relay=none, delay=174426,
> delays=174396/0.1/30/0, dsn=4.4.1, status=deferred (connect to mainz.de[213.139.155.226]: Connection timed out)

The FIRST entry has a delay of 174426??? Why? The mail was just picked up!

> May 11 14:41:54 postfix/qmgr[19918]: B017B3C2BF78: from=<[hidden email]>, size=2132, nrcpt=1 (queue active)
> May 11 14:42:24 postfix/smtp[20117]: connect to mainz.de[213.139.155.226]: Connection timed out (port 25)
> May 11 14:42:24 postfix/smtp[20117]: B017B3C2BF78: to=<[hidden email]>, relay=none, delay=271371,
> delays=271341/0.11/30/0, dsn=4.4.1, status=deferred (connect to mainz.de[213.139.155.226]: Connection timed out)

The last entry is 1d:3h later (which is < 2d!) and it has a delay of
delay=271371

Something is terribly fubared.  Clock jumping back and forth? I have
no idea.

--
Ralf Hildebrandt ([hidden email])          [hidden email]
Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
http://www.arschkrebs.de
Vegetarier ist altindianisch für "zu doof zum Jagen".
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: queue lifetime

Sascha Hüdepohl-3
* Ralf Hildebrandt ([hidden email]) wrote:
> * Sascha Hüdepohl <[hidden email]>:
>
> > May 10 11:46:09 postfix/pickup[16745]: B017B3C2BF78: uid=101 from=<[hidden email]> orig_id=415503C2BF62
> > May 10 11:46:09 postfix/cleanup[16886]: B017B3C2BF78: message-id=<[hidden email]>
> > May 10 11:46:09 postfix/qmgr[10614]: B017B3C2BF78: from=<[hidden email]>, size=2132, nrcpt=1 (queue active)
> > May 10 11:46:40 postfix/smtp[16889]: B017B3C2BF78: to=<[hidden email]>, relay=none, delay=174426,
> > delays=174396/0.1/30/0, dsn=4.4.1, status=deferred (connect to mainz.de[213.139.155.226]: Connection timed out)
>
> The FIRST entry has a delay of 174426??? Why? The mail was just picked up!

maybe because it allready was for that time in the queue under an other id?

> > May 11 14:41:54 postfix/qmgr[19918]: B017B3C2BF78: from=<[hidden email]>, size=2132, nrcpt=1 (queue active)
> > May 11 14:42:24 postfix/smtp[20117]: connect to mainz.de[213.139.155.226]: Connection timed out (port 25)
> > May 11 14:42:24 postfix/smtp[20117]: B017B3C2BF78: to=<[hidden email]>, relay=none, delay=271371,
> > delays=271341/0.11/30/0, dsn=4.4.1, status=deferred (connect to mainz.de[213.139.155.226]: Connection timed out)
>
> The last entry is 1d:3h later (which is < 2d!) and it has a delay of
> delay=271371
>
> Something is terribly fubared.  Clock jumping back and forth?

I would exclude this possibility by 99%. I never saw a sign for such
behaviour.
The clock is fairly accurate. Whithout any timedaemon runnning.

> I have no idea.
>
> --
> Ralf Hildebrandt ([hidden email])          [hidden email]
> Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
> http://www.arschkrebs.de
> Vegetarier ist altindianisch für "zu doof zum Jagen".
>
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: queue lifetime

Ralf Hildebrandt
* Sascha Hüdepohl <[hidden email]>:

> * Ralf Hildebrandt ([hidden email]) wrote:
> > * Sascha Hüdepohl <[hidden email]>:
> >
> > > May 10 11:46:09 postfix/pickup[16745]: B017B3C2BF78: uid=101 from=<[hidden email]> orig_id=415503C2BF62
> > > May 10 11:46:09 postfix/cleanup[16886]: B017B3C2BF78: message-id=<[hidden email]>
> > > May 10 11:46:09 postfix/qmgr[10614]: B017B3C2BF78: from=<[hidden email]>, size=2132, nrcpt=1 (queue active)
> > > May 10 11:46:40 postfix/smtp[16889]: B017B3C2BF78: to=<[hidden email]>, relay=none, delay=174426,
> > > delays=174396/0.1/30/0, dsn=4.4.1, status=deferred (connect to mainz.de[213.139.155.226]: Connection timed out)
> >
> > The FIRST entry has a delay of 174426??? Why? The mail was just picked up!
>
> maybe because it allready was for that time in the queue under an other id?

Usually postfix would log that fact:

# postsuper -r 0DA9D1C3630
postsuper: 0DA9D1C3630: requeued
postsuper: Requeued: 1 message

May 11 15:21:56 mail postfix/postsuper[9719]: 0DA9D1C3630: requeued
(unfortunately it doesn't say the new queueid)

And yes, this keeps the delay settings intact! (I just noticed).

So, simple solution: Don't requeue :)

--
Ralf Hildebrandt ([hidden email])          [hidden email]
Postfix - Einrichtung, Betrieb und Wartung       Tel. +49 (0)30-450 570-155
http://www.arschkrebs.de
I have never left my schooling interfere with my education. - Mark Twain
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: queue lifetime

Victor Duchovni
On Sun, May 11, 2008 at 03:24:01PM +0200, Ralf Hildebrandt wrote:

> May 11 15:21:56 mail postfix/postsuper[9719]: 0DA9D1C3630: requeued
> (unfortunately it doesn't say the new queueid)

Actually, it will log the new/old queue-id pair once pickup runs.

--
        Viktor.

Disclaimer: off-list followups get on-list replies or get ignored.
Please do not ignore the "Reply-To" header.

To unsubscribe from the postfix-users list, visit
http://www.postfix.org/lists.html or click the link below:
<mailto:[hidden email]?body=unsubscribe%20postfix-users>

If my response solves your problem, the best way to thank me is to not
send an "it worked, thanks" follow-up. If you must respond, please put
"It worked, thanks" in the "Subject" so I can delete these quickly.
Loading...