Piler not accepting mail fast enough

[Dale Storrie]

I have an issue with Piler where it doesn't seem to collect email fast enough which is causing Outbound message queues to build up from Exchange.

I have tried to increase the connection limit and the worker_process limit, none which have helped.

Any advice would be most appreciated.

[Janos SUTO]

Let’s start with the piler version (piler -v) and the current throughput piler-smtp is receiving messages.

[Dale Storrie]

root:/home/dale # piler -v
1.3.9 build 998

Using service piler status i can see there is messages coming in.

Jan 26 13:21:02 mailarchive piler[2415]: 12/L4ACXW5I76NOT8VQ: 400000006010174824f39e1c00416571691c, size=132791/24216, attachments=0, reference=, message-id=<removed for security>, retention=2557, folder=0, de$
Jan 26 13:21:02 mailarchive piler[2412]: 9/I4S3MXDBPO2M57UG: 4000000060101748292b11f400fe38183617, size=128714/23640, attachments=0, reference=, message-id=<removed for security>, retention=2557, folder=0, del$
Jan 26 13:21:02 mailarchive piler-smtp[2388]: received: NO6WA6BIAOOXGO5M, from=, size=132227, client=10.48.11.15, fd=6, fsync=16520
Jan 26 13:21:02 mailarchive piler-smtp[2388]: received: UZKGH7DRY4Z53KZB, from=, size=6910, client=10.48.11.15, fd=6, fsync=32754
Jan 26 13:21:02 mailarchive piler[2426]: 23/WPXR2YBEBOB1NN9B: 40000000601017482fe0a14400416edbbc35, size=11103/4976, attachments=0, reference=, message-id=<removed for security>, retention=2557, folder=0, dela$
Jan 26 13:21:02 mailarchive piler[2422]: 19/32K0KY28V1ZDY9W0: 40000000601017482ff56994000d3aea4daf, size=128703/23312, attachments=0, reference=, message-id=<removed for security>, retention=2557, folder=0, de$
Jan 26 13:21:03 mailarchive piler[2420]: 17/QOPI2WLQZE9MNIQM: 400000006010174901f968c400b492bbac89, size=128750/23728, attachments=0, reference=, message-id=<removed for security>, retention=2557, folder=0, de$
Jan 26 13:21:03 mailarchive piler[2424]: 21/UZKGH7DRY4Z53KZB: 4000000060101749103306ac004657db6635, size=6910/2248, attachments=0, reference=<removed for security>, message-id=<dccb6426f7b64466bcf5$
Jan 26 13:21:03 mailarchive piler[2419]: 16/PGU4624V0A63KLQM: 40000000601017491e0e773400ec2dfc0125, size=128180/23512, attachments=0, reference=, message-id=<removed for security>, retention=2557, folder=0, de$
Jan 26 13:21:03 mailarchive piler[2417]: 14/NO6WA6BIAOOXGO5M: 400000006010174924f76ac4000a771cba33, size=132227/24128, attachments=0, reference=, message-id=<removed for security>, retention=2557, folder=0, de$

[Janos SUTO]

OK. Can you estimate the message receiving rate of piler-smtp? Eg. messages per minute or similar. Also please elaborate your conclusion why you think piler-smtp can’t keep up with the pace of Exchange. And how many messages would it be per minute to satisfy Exchange?

[Dale Storrie]

We have monitoring setup on our Exchange server which we have used to monitor an older version of mailpiler for some years. It states if the exchange like the following:

68 (Messages Queued For Delivery) is above the error limit of 50 in Messages Queued For Delivery

This queue was always 0 before we updated to the latest piler version.

We also seem to be having quite a few SMTP timeouts.

‌

[Janos SUTO]

How many smtp connections would Exchange open to piler? Also can it use a single connection to send more emails?

I’d like you to run ngrep -X port 25 on piler, then try to flush all emails from Exchange, and check if there’s really a problem at piler’s side. You may set verbosity=5 in piler.conf (and reload piler-smtp) to have a detailed logging.

[Dale Storrie]

Ok, cleared the queue down in exchange and did as asked but the queue just builds up so fast again.

Getting a lot of output like below:

.}o..J."AZ2....o.y....%j0...P.le...^.a...q..JB..%Ly.3:....tW.I..w....N;<Y....4'Q...F.....p~E..bmn.J.+P..0.d.\. w$S.'...iD..2$........F........a.Q..z.~.4..8.TP...KT].......k...T.....".Wo.{.%%..........W...&S..:zC..K.T..;..J
...t.i...~R.O.(;>..Ig...m...pG."5:U....@..~......j@....|..VI.+g.b..........G...c.T.:...fb......O.Nb.. ...../..g.
....?...t..?....-..tc......8..L........Ja^}..;...b.5y...F...S'.........C.P..u..'.b.w.#....']...\......T...._U.. ,$.[93.......p.C?2S.@=.K.+z.....5.wW.............._>nL.<......r..bHp...o.)....=..1...._.....{.e........QV....o.. ...L.......G.<...I..1}........e.aTFra.q>...0:./S.M.p.:......V..>..$...g&..QH;L.D...>...t...a.^.....M.^=.....A.<
...y~..)E%~..a45...A....M..8y.T..4./...7*..{.b5P.E....2=..5d............ugP....................p..hmQN...d..c-
..3....ne.J.O.......%^..,.....B.b.^..r..r.V..W...... ...g.....~...l..ks.a.uW.&4so.}...:..[..Ai........H...5..
......UM............Yl.c.X.f^a.K.y.>.D..cH;.....N.....=;....?...9..........d.!.!a3..f._..[W...^....

‌

T 10.48.11.18:25 -> 10.48.11.15:37292 [AP] #756
421 All server ports are busy..

‌

T 10.48.11.15:37292 -> 10.48.11.18:25 [AP] #759
QUIT..

‌

T 10.48.11.18:25 -> 10.48.11.15:37315 [AP] #764
421 All server ports are busy..

‌

T 10.48.11.15:37315 -> 10.48.11.18:25 [AP] #767
QUIT..
#######
T 10.48.11.18:25 -> 10.48.11.15:37341 [AP] #774
421 All server ports are busy..

‌

T 10.48.11.15:37341 -> 10.48.11.18:25 [AP] #777
QUIT..

‌

T 10.48.11.18:25 -> 10.48.11.15:37357 [AP] #783
421 All server ports are busy..

‌

T 10.48.11.15:37357 -> 10.48.11.18:25 [AP] #786
QUIT..

‌

‌

[Dale Storrie]

Just to add to the above it seems to be a single generated email that causes the queue to start growing:

‌

Identity: EXCHANGE\3\237215338725477
Subject: CS Abandoned Calls Hourly - CS Abanboned Calls
Internet Message ID: [e-mail]
From Address: <>
Status: Active
Size (KB): 5
Message Source Name: Journaling
Source IP: 255.255.255.255
SCL: 0
Date Received: 26/01/2021 16:02:09
Expiration Time:
Last Error:
Queue ID: EXCHANGE\3
Recipients: mailto:[e-mail];2;2;[{LRT=};{LED=421 4.4.2 Connection dropped due to SocketError};{FQDN=};{IP=}];0;CN=Mail Archiving,CN=Connections,CN=Exchange Routing Group (DWBGZMFD01QNBJR),CN=Routing Groups,CN=Exchange Administrative Group (FYDIBOHF23SPDLT),CN=Administrative Groups,CN=removed,CN=Microsoft Exchange,CN=Services,CN=Configuration,DC=removed,DC=com;0

[Janos SUTO]

Can you defer or withhold this single email, and then release the queue on exchange?

I’d also like to see the mail log on the piler side. It’s odd to me that a single email could disrupt piler even if it just can’t process it.

So piler syslogs all smtp connections including the number of active connections. It returns an all ports busy if all (by default) 64 smtp slots are busy. Is exchange really sending that many at the same time?

[Dale Storrie]

Janos, is there somewhere private/secure I could upload you my mail.log file? Or do you have an email I can forward it too?

[Janos SUTO]

How about skype? My id is janos.suto

[Janos SUTO]

Any update on the issue?

[Janos SUTO]

No news is good news.