new error, only for single email? "sa-milter.sock: can't read SMFIC_BODY reply packet header: Connection timed out" #5

New issue

Closed

opened 2020-11-06 15:54:16 +00:00 by pgnd · 2 comments

pgnd commented

2020-11-06 15:54:16 +00:00

(Migrated from gitlab.com)

SA-milter's been running fine in a postfix milter chain for quite awhile now.

A few days ago, I started seeing these errors in my log summary reports:

milter unix:/run/sa-milter/sa-milter.sock: can't read SMFIC_BODY reply packet header: Connection timed out

Currently, there's several hundred.

It's a reject/error for one, and ONLY one sender; a legit email from a friend @gmail.com, that apparently contains an attachment.

Gmail keeps attempting the resend of the same email from its queue.

I've grep'd the SA-milter src ... no trace of "SMFIC_BODY" that i can see.

I'm just starting to troubleshoot this now, and dig around various 'timeout' settings.

1st, though -- is this a recognized/known error 'in' SA-milter?
Or, any likely suggestions where to start looking? E.g., which timeout, etc?

SA-milter's been running fine in a postfix milter chain for quite awhile now. A few days ago, I started seeing these errors in my log summary reports: milter unix:/run/sa-milter/sa-milter.sock: can't read SMFIC_BODY reply packet header: Connection timed out Currently, there's several hundred. It's a reject/error for one, and ONLY one sender; a legit email from a friend @gmail.com, that apparently contains an attachment. Gmail keeps attempting the resend of the same email from its queue. I've grep'd the SA-milter src ... no trace of "SMFIC_BODY" that i can see. I'm just starting to troubleshoot this now, and dig around various 'timeout' settings. 1st, though -- is this a recognized/known error 'in' SA-milter? Or, any likely suggestions where to start looking? E.g., _which_ timeout, etc?

glts commented

2020-11-07 08:47:06 +00:00

(Migrated from gitlab.com)

The error message is from Postfix.

The error message means that Postfix did not get a timely response while it was executing the milter callback for the body stage. All this callback does is send message content to spamc.

Postfix has several milter_*_timeout parameters. The one that it ran into here is milter_content_timeout (default 5 minutes).

It is a bit worrying, but I’m not sure SpamAssassin Milter’s the culprit. Perhaps something about that particular message that causes spamc/SpamAssassin to become very busy …?

The error message is from Postfix. The error message means that Postfix did not get a timely response while it was executing the [milter callback for the body stage](https://gitlab.com/glts/spamassassin-milter/-/blob/0.1.4/src/callbacks.rs#L187-203). All this callback does is send message content to `spamc`. Postfix has several `milter_*_timeout` parameters. The one that it ran into here is `milter_content_timeout` (default 5 minutes). It is a bit worrying, but I’m not sure SpamAssassin Milter’s the culprit. Perhaps something about that particular message that causes `spamc`/SpamAssassin to become very busy …?

glts commented

2020-12-19 11:02:51 +00:00

(Migrated from gitlab.com)

This is actually quite easy to reproduce, just let spamc sleep for a few
minutes when it is invoked. Postfix simply stops waiting for a milter when it
doesn’t receive a response in time, and logs the above message. I believe all of
this is working as intended.

Possible solutions:

Increase the Postfix timeout milter_content_timeout to give the
SpamAssassin components more time to process the message.
Decrease the spamc timeout (-t option), to make the SpamAssassin
components return a response more quickly (before Postfix runs into the
timeout).
Of course the best option is to look into why the SpamAssassin
components take so long to respond, and find out if it can be avoided.

This is actually quite easy to reproduce, just let `spamc` sleep for a few minutes when it is invoked. Postfix simply stops waiting for a milter when it doesn’t receive a response in time, and logs the above message. I believe all of this is working as intended. Possible solutions: * Increase the Postfix timeout `milter_content_timeout` to give the SpamAssassin components more time to process the message. * Decrease the `spamc` timeout (`-t` option), to make the SpamAssassin components return a response more quickly (before Postfix runs into the timeout). * Of course the best option is to look into why the SpamAssassin components take so long to respond, and find out if it can be avoided.