"Connection to Spamassassin was lost" errors

Use this forum for discussions about SpamAssassin and anti-spam in general.
Post Reply
User avatar
katip
Senior user
Senior user
Posts: 683
Joined: 2006-12-22 07:58
Location: Istanbul

"Connection to Spamassassin was lost" errors

Post by katip » 2017-05-03 21:24

I come across to unscanned messages (spams), not frequently but 1-3 times a day. otherwise SA is working perfectly.
recent occurrence:

HMS tells:

Code: Select all

"ERROR"	1800	"2017-05-03 15:26:41.494"	"Severity: 3 (Medium), Code: HM5157, Source: SpamAssassinClient::OnReadError, Description: There was a communication error with SpamAssassin. hMailServer tried to retrieve data from SpamAssassin but the connection to SpamAssassin was lost. The WinSock error code is 2. Enable debug logging to retrieve more information regarding this problem. The problem could be that SpamAssassin is malfunctioning."
"ERROR"	2692	"2017-05-03 15:26:41.494"	"Severity: 2 (High), Code: HM5508, Source: SpamAssassinTestConnect::TestConnect, Description: The SpamAssassin tests did not complete. Please confirm that the configuration (host name and port) is valid and that SpamAssassin is running."
and spamd tells (HMS is ~1 sec behind, so this should be the concurrent moment and some suspicious entries 10 secs before) :

Code: Select all

Wed May  3 15:26:31 2017 [3832] info: prefork: child states: III
Wed May  3 15:26:31 2017 [3832] info: prefork: adjust: 3 idle children more than 2 maximum idle children. Decreasing spamd children: -1496 killed.
Wed May  3 15:26:31 2017 [-1496] info: spamd: child got SIGINT, exiting
Wed May  3 15:26:33 2017 [3832] info: spamd: handled cleanup of child pid [-1496]: exit 0
(...some usual connection and processing entries..)
Wed May  3 15:26:42 2017 [3832] info: prefork: child states: BB
Wed May  3 15:26:42 2017 [3832] info: spamd: server successfully spawned child process, pid -3304
Wed May  3 15:26:42 2017 [3832] info: prefork: adjust: 0 idle children less than 1 minimum idle children. Increasing spamd children: -3304 started.
Wed May  3 15:26:42 2017 [3832] info: prefork: child states: BBI
(...goes on with usual connection and processing entries..)
HMS and SA/ClamAV are on seperate VMs in same Hyper-V box. so, any physical connection failure is out of possibility.
debugging is a pain. this is a busy production server.

thanks for any advise (tweak suggestions?) without debugging option first - if possible.
Katip
--
HMS 5.7.0-B2428-LTS-64-bit, MySQL 5.7.24, SA 3.4.2, ClamAV 0.101.2 + SaneS

User avatar
jimimaseye
Moderator
Moderator
Posts: 8116
Joined: 2011-09-08 17:48

Re: "Connection to Spamassassin was lost" errors

Post by jimimaseye » 2017-05-03 21:41

Known problem. Reported and discussed many times. No answer or solution yet. Even Jam (of SA For Windows) have been involved and concluded its HMS. Hopefully there are attempts to address it in 5.7. Detailed info: viewtopic.php?t=28227 ("Binkle" is from Jam).

Youll just have to ignore it.
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

User avatar
SorenR
Senior user
Senior user
Posts: 3183
Joined: 2006-08-21 15:38
Location: Denmark

Re: "Connection to Spamassassin was lost" errors

Post by SorenR » 2017-05-03 22:00

katip wrote:

Code: Select all

Wed May  3 15:26:31 2017 [3832] info: prefork: child states: III
Wed May  3 15:26:31 2017 [3832] info: prefork: adjust: 3 idle children more than 2 maximum idle children. Decreasing spamd children: -1496 killed.
Wed May  3 15:26:31 2017 [-1496] info: spamd: child got SIGINT, exiting
Wed May  3 15:26:33 2017 [3832] info: spamd: handled cleanup of child pid [-1496]: exit 0
(...some usual connection and processing entries..)
Wed May  3 15:26:42 2017 [3832] info: prefork: child states: BB
Wed May  3 15:26:42 2017 [3832] info: spamd: server successfully spawned child process, pid -3304
Wed May  3 15:26:42 2017 [3832] info: prefork: adjust: 0 idle children less than 1 minimum idle children. Increasing spamd children: -3304 started.
Wed May  3 15:26:42 2017 [3832] info: prefork: child states: BBI
(...goes on with usual connection and processing entries..)
You removed the interesting bits... There are no errors in the above log, only housekeeping.

Any of them lines looking anything like...

Code: Select all

Tue Feb  7 06:31:41 2017 [-3992] info: spamd: connection from datacenter.acme.inc [127.0.0.1]:3059 to port 783, fd 6
Tue Feb  7 06:31:41 2017 [-3992] info: spamd: processing message <OF3D9D98A7.C308F75C-ONC12580C0.001E5564@cfp.dk> for (unknown):0
Tue Feb  7 06:39:32 2017 [-3992] info: spamd: clean message (-2.6/3.0) for (unknown):0 in 470.6 seconds, 712208 bytes.
Tue Feb  7 06:39:32 2017 [-3992] info: spamd: result: . -2 - BAYES_00,RCVD_IN_DNSWL_LOW,RCVD_IN_MSPIKE_H3,TIME_LIMIT_EXCEEDED,T_OBFU_PDF_ATTACH scantime=470.6,size=712208,user=(unknown),uid=0,required_score=3.0,rhost=datacenter.acme.inc,raddr=127.0.0.1,rport=3059,mid=<OF3D9D98A7.C308F75C-ONC12580C0.001E5564@cfp.dk>,bayes=0.000000,autolearn=unavailable
I get the error if it takes too long to process... For some unknown reason my timeout limits are giving me the finger :roll:
SørenR.

“With age comes wisdom, but sometimes age comes alone.”
- Oscar Wilde

User avatar
jimimaseye
Moderator
Moderator
Posts: 8116
Joined: 2011-09-08 17:48

Re: "Connection to Spamassassin was lost" errors

Post by jimimaseye » 2017-05-03 22:16

SorenR wrote: Any of them lines looking anything like...

Code: Select all

Tue Feb  7 06:31:41 2017 [-3992] info: spamd: connection from datacenter.acme.inc [127.0.0.1]:3059 to port 783, fd 6
Tue Feb  7 06:31:41 2017 [-3992] info: spamd: processing message <OF3D9D98A7.C308F75C-ONC12580C0.001E5564@cfp.dk> for (unknown):0
Tue Feb  7 06:39:32 2017 [-3992] info: spamd: clean message (-2.6/3.0) for (unknown):0 in 470.6 seconds, 712208 bytes.
Tue Feb  7 06:39:32 2017 [-3992] info: spamd: result: . -2 - BAYES_00,RCVD_IN_DNSWL_LOW,RCVD_IN_MSPIKE_H3,TIME_LIMIT_EXCEEDED,T_OBFU_PDF_ATTACH scantime=470.6,size=712208,user=(unknown),uid=0,required_score=3.0,rhost=datacenter.acme.inc,raddr=127.0.0.1,rport=3059,mid=<OF3D9D98A7.C308F75C-ONC12580C0.001E5564@cfp.dk>,bayes=0.000000,autolearn=unavailable
I get the error if it takes too long to process... For some unknown reason my timeout limits are giving me the finger :roll:

This doesnt apply to me. Most recent example:

Error:
"ERROR" 2800 "2017-04-27 12:11:18.721" "Severity: 3 (Medium), Code: HM5157, Source: SpamAssassinClient::OnReadError, Description: There was a communication error with SpamAssassin. hMailServer tried to retrieve data from SpamAssassin but the connection to SpamAssassin was lost. The WinSock error code is 2. Enable debug logging to retrieve more information regarding this problem. The problem could be that SpamAssassin is malfunctioning."
"ERROR" 1856 "2017-04-27 12:11:18.909" "Severity: 2 (High), Code: HM5508, Source: SpamAssassinTestConnect::TestConnect, Description: The SpamAssassin tests did not complete. Please confirm that the configuration (host name and port) is valid and that SpamAssassin is running."
SPAMD:
[quote]Thu Apr 27 12:11:16 2017 [-3192] info: spamd: connection from mailserver [127.0.0.1]:64411 to port 783, fd 6
Thu Apr 27 12:11:16 2017 [-3192] info: spamd: processing message <F639F648-BB65-4099-8454-3E8A741B4206@reflekt-events.net> for (unknown):0
Thu Apr 27 12:11:18 2017 [-3192] info: spamd: clean message (-2.1/3.0) for (unknown):0 in 1.9 seconds, 27358 bytes.
Thu Apr 27 12:11:18 2017 [-3192] info: spamd: result: . -2 - BAYES_00,DKIM_SIGNED,DKIM_VALID,HTML_MESSAGE,RCVD_IN_DNSWL_NONE,RCVD_IN_HOSTKARMA_YE,RCVD_IN_MSPIKE_H2,RCVD_IN_SORBS_SPAM,SUBJ_ALL_CAPS,URG_BIZ scantime=1.9,size=27358,user=(unknown),uid=0,required_score=3.0,rhost=mailserver,raddr=127.0.0.1,rport=64411,mid=<F639F648-BB65-4099-8454-3E8A741B4206@reflekt-events.net>,bayes=0.000000,autolearn=no autolearn_force=no,shortcircuit=no
Thu Apr 27 12:11:20 2017 [-3700] info: spamd: connection from mailserver [127.0.0.1]:64415 to port 783, fd 6
Thu Apr 27 12:11:20 2017 [-3700] info: spamd: processing message <84d0db4eb3f84b3c96075694a5f74efe@DH1MX001.beaulieu.local> for (unknown):0
Thu Apr 27 12:11:21 2017 [-3700] info: spamd: clean message (-3.0/3.0) for (unknown):0 in 0.9 seconds, 141275 bytes.
Thu Apr 27 12:11:21 2017 [-3700] info: spamd: result: . -2 - BAYES_00,FROM_WORDY_SHORT,HTML_MESSAGE,MIME_HTML_ONLY,RCVD_IN_DNSWL_NONE,RCVD_IN_HOSTKARMA_YE,RCVD_IN_MSPIKE_H2,SPF_PASS,T_OBFU_PDF_ATTACH scantime=0.9,size=141275,user=(unknown),uid=0,required_score=3.0,rhost=mailserver,raddr=127.0.0.1,rport=64415,mid=<84d0db4eb3f84b3c96075694a5f74efe@DH1MX001.beaulieu.local>,bayes=0.000000,autolearn=ham autolearn_force=no,shortcircuit=no[/quote]


Scan times completed in less than 2 seconds. (Similar to other random quick checks of other previous errors Ive just done to be sure)
HMS 5.6.6 B2383 on Win Server 2008 R2 Foundation, + 5.6.7-B2415 on test.
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829

User avatar
mattg
Moderator
Moderator
Posts: 20103
Joined: 2007-06-14 05:12
Location: 'The Outback' Australia

Re: "Connection to Spamassassin was lost" errors

Post by mattg » 2017-05-04 01:05

Just checked my logs

Since 1 April, I've had 10 single occurrences of this, none so far this month, only ever one per day at most.
( I use SpamAssassin on a virtual Ubuntu on my network).

Interestingly most are just a few minutes after midnight, or a few minutes after midday. Don't know the relevance of that, I have no scripts that particularly ran at these times.

I have these settings in my hMailserver.ini

Code: Select all

SAMinTimeout=180
; 30 seconds is default

SAMaxTimeout=280
; 90 seconds is default
I've just updated them to 240 /360
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation

User avatar
katip
Senior user
Senior user
Posts: 683
Joined: 2006-12-22 07:58
Location: Istanbul

Re: "Connection to Spamassassin was lost" errors

Post by katip » 2017-05-04 06:08

SorenR wrote: I get the error if it takes too long to process... For some unknown reason my timeout limits are giving me the finger :roll:
hmm, i checked all log of yesterday. average time is 4,1 secs, max. 21,7 secs, anyways below than default min. (30 secs).

viewtopic.php?t=28227 , yes, interesting reading. let's keep waiting for HMS 5.7.
thanks.
Katip
--
HMS 5.7.0-B2428-LTS-64-bit, MySQL 5.7.24, SA 3.4.2, ClamAV 0.101.2 + SaneS

Post Reply