Message stay at "queued/accepted" state more than 2 min

[Kot Degt]

Hello!

I have PMG 7.2-4 (lxc container) it's work very well, but today i got problem with it.

The message(all normal messages) stay at "queued/accepted" state little more than 2 min, after that it becomes "accepted/delivered" state.
Now my user can't accept 3D secure by mail (Code lives only 2 min). How i can reduce queued time?
Mar 3 18:43:36 mailgw postfix/smtpd[18131]: connect from mail-lj1-f179.google.com[209.85.208.179] Mar 3 18:43:37 mailgw postfix/smtpd[18131]: 890EF1912D: client=mail-lj1-f179.google.com[209.85.208.179] Mar 3 18:43:37 mailgw postfix/cleanup[18134]: 890EF1912D: message-id=<d805a956-f725-818c-7272-4badac68c94f@gmail.com> Mar 3 18:43:37 mailgw postfix/qmgr[420]: 890EF1912D: from=<src@gmail.com>, size=3406, nrcpt=1 (queue active) Mar 3 18:43:37 mailgw pmg-smtp-filter[18001]: 191B96401B339AC24F: new mail message-id=<d805a956-f725-818c-7272-4badac68c94f@gmail.com>#012 Mar 3 18:43:38 mailgw pmg-smtp-filter[18001]: 191B96401B339AC24F: SA score=0/5 time=0.270 bayes=0.00 autolearn=no autolearn_force=no hits=AWL(0.056),BAYES_00(-1.5),FREEMAIL_FROM(0.001),KAM_NUMSUBJECT(0.5) Mar 3 18:43:38 mailgw postfix/smtpd[18139]: connect from localhost[127.0.0.1] Mar 3 18:43:38 mailgw postfix/smtpd[18139]: 0AAB019133: client=localhost[127.0.0.1], orig_client=mail-lj1-f179.google.com[209.85.208.179] Mar 3 18:43:38 mailgw postfix/cleanup[18134]: 0AAB019133: message-id=<d805a956-f725-818c-7272-4badac68c94f@gmail.com> Mar 3 18:43:38 mailgw postfix/qmgr[420]: 0AAB019133: from=<src@gmail.com>, size=3946, nrcpt=1 (queue active) Mar 3 18:43:38 mailgw pmg-smtp-filter[18001]: 191B96401B339AC24F: accept mail to <admin@example.org> (0AAB019133) (rule: default-accept) Mar 3 18:43:38 mailgw postfix/smtpd[18139]: disconnect from localhost[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=1 data=1 commands=5 Mar 3 18:43:38 mailgw pmg-smtp-filter[18001]: 191B96401B339AC24F: processing time: 0.439 seconds (0.27, 0.034, 0) Mar 3 18:43:38 mailgw postfix/lmtp[18135]: 890EF1912D: to=<admin@example.org>, relay=127.0.0.1[127.0.0.1]:10024, delay=1.3, delays=0.57/0.03/0/0.69, dsn=2.5.0, status=sent (250 2.5.0 OK (191B96401B339AC24F)) Mar 3 18:43:38 mailgw postfix/qmgr[420]: 890EF1912D: removed Mar 3 18:44:10 mailgw postfix/smtpd[18131]: disconnect from mail-lj1-f179.google.com[209.85.208.179] ehlo=2 starttls=1 mail=1 rcpt=1 bdat=1 quit=1 commands=7 Mar 3 18:45:48 mailgw postfix/smtp[18140]: 0AAB019133: to=<admin@example.org>, relay=192.168.111.230[192.168.111.230]:25, delay=130, delays=0.1/0.03/0.1/130, dsn=2.0.0, status=sent (250 OK id=1pY10s-0007n8-8z) Mar 3 18:45:48 mailgw postfix/qmgr[420]: 0AAB019133: removed

Thanx for your hardwork!

 

[Stoiko Ivanov]

The logs don't seem complete (the initial connection from the smtp client (postfix/smtp) to your downstream server 192.168.111.230 is missing)...

postfix/smtp[18140]: 0AAB019133: to=<admin@example.org>, relay=192.168.111.230[192.168.111.230]:25, delay=130, delays=0.1/0.03/0.1/130, dsn=2.0.0, status=sent (250 OK id=1pY10s-0007n8-8z)

this line (especially delay=130) says that sending the mail from your PMG to 192.168.111.230 (your downstream server) took 2 minutes.

This can have many reasons - quite common ones are:
* broken DNS setup on either system (reverse DNS-lookups take too long)
* duplicate IPs/MACs in your network
* routing issues

I hope this helps!

 

[Kot Degt]

Thanks... I'll check again. May be it is DNS reverse, i will check it.
But... from another sender delay are never happens... I can't understand why...
Mar 3 20:43:44 mailgw postfix/smtpd[20392]: connect from mail.example2.org[94.229.247.46] Mar 3 20:43:44 mailgw postfix/smtpd[20392]: A8DAC1B79F: client=mail.example2.org[94.229.247.46] Mar 3 20:43:44 mailgw postfix/cleanup[20561]: A8DAC1B79F: message-id=<54203bbc-933d-930c-70db-e3860c574239@example2.org> Mar 3 20:43:44 mailgw postfix/qmgr[420]: A8DAC1B79F: from=<admin@example2.org>, size=1326, nrcpt=1 (queue active) Mar 3 20:43:44 mailgw postfix/smtpd[20392]: disconnect from mail.example2.org[94.229.247.46] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7 Mar 3 20:43:44 mailgw pmg-smtp-filter[20374]: 1B7466401CF60B4837: new mail message-id=<54203bbc-933d-930c-70db-e3860c574239@example2.org>#012 Mar 3 20:43:44 mailgw pmg-smtp-filter[20374]: 1B7466401CF60B4837: SA score=0/5 time=0.151 bayes=0.00 autolearn=no autolearn_force=no hits=AWL(-0.067),BAYES_00(-1.5),KAM_NUMSUBJECT(0.5) Mar 3 20:43:44 mailgw postfix/smtpd[20566]: connect from localhost[127.0.0.1] Mar 3 20:43:44 mailgw postfix/smtpd[20566]: EA5E61B74F: client=localhost[127.0.0.1], orig_client=mail.example2.org[94.229.247.46] Mar 3 20:43:44 mailgw postfix/cleanup[20561]: EA5E61B74F: message-id=<54203bbc-933d-930c-70db-e3860c574239@example2.org> Mar 3 20:43:44 mailgw postfix/qmgr[420]: EA5E61B74F: from=<admin@example2.org>, size=1780, nrcpt=1 (queue active) Mar 3 20:43:44 mailgw pmg-smtp-filter[20374]: 1B7466401CF60B4837: accept mail to <admin@example.org> (EA5E61B74F) (rule: default-accept) Mar 3 20:43:44 mailgw postfix/smtpd[20566]: disconnect from localhost[127.0.0.1] ehlo=1 xforward=1 mail=1 rcpt=1 data=1 commands=5 Mar 3 20:43:44 mailgw pmg-smtp-filter[20374]: 1B7466401CF60B4837: processing time: 0.224 seconds (0.151, 0.039, 0) Mar 3 20:43:44 mailgw postfix/lmtp[20562]: A8DAC1B79F: to=<admin@example.org>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.29, delays=0.03/0.03/0/0.23, dsn=2.5.0, status=sent (250 2.5.0 OK (1B7466401CF60B4837)) Mar 3 20:43:44 mailgw postfix/qmgr[420]: A8DAC1B79F: removed Mar 3 20:43:45 mailgw postfix/smtp[20450]: EA5E61B74F: to=<admin@example.org>, relay=192.168.111.230[192.168.111.230]:25, delay=0.22, delays=0/0/0.09/0.12, dsn=2.0.0, status=sent (250 OK id=1pY2t7-0008VP-28) Mar 3 20:43:45 mailgw postfix/qmgr[420]: EA5E61B74F: removed