SpamAssassin not detecting spams in hmailserver

Use this forum for discussions about SpamAssassin and anti-spam in general.
Post Reply
lslabiga
New user
New user
Posts: 7
Joined: 2017-08-25 18:36

SpamAssassin not detecting spams in hmailserver

Post by lslabiga » 2017-08-25 18:42

Good day to all of you! :)

I have finished setting up hmailserver with 2 domains and 1 account each domain. Configured them in Thunderbird as well. I also installed Spamassassin for windows with nssm and testing it in the hmailserver administrator panel it gives out a result. The problem is whenever I try the GTUBE test through Thunderbird by sending an email from one domain to another it doesn't detect it as spam and it also says in the status window in hmailserver the processed messages but no spam messages. Am I doing this wrong? It's my first time on all these things and I'm still testing things out.

Thank you in advanced!

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

Re: SpamAssassin not detecting spams in hmailserver

Post by jimimaseye » 2017-08-25 20:15

Please run this and post the results: viewtopic.php?f=20&t=30914

Also, enable DEBUG logging, then press the Spam TEST button. Do you get entries appearing like:
"DEBUG" 24008 "2017-08-25 19:16:24.569" "Creating session 15"
"DEBUG" 20532 "2017-08-25 19:16:24.625" "TCP connection started for session 15"
"DEBUG" 20532 "2017-08-25 19:16:24.626" "Sending message to SpamAssassin. Session 15, File: C:\Program Files (x86)\hMailServer\Temp\{4C36A5C5-C624-4F7A-A1CF-C07CF3141037}.tmp"
"DEBUG" 13928 "2017-08-25 19:16:25.995" "Parsing response from SpamAssassin. Session 15"
"DEBUG" 15988 "2017-08-25 19:16:26.524" "SA - Copy+Delete used"
"DEBUG" 15988 "2017-08-25 19:16:26.526" "Ending session 15"
?
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

lslabiga
New user
New user
Posts: 7
Joined: 2017-08-25 18:36

Re: SpamAssassin not detecting spams in hmailserver

Post by lslabiga » 2017-08-25 20:31

After enabling debug logging, I did saw some similar entries appearing just as what you said but with just a different session number (in my case 144).

Here are the results:

[code]2017-08-25 Hmailserver: 5.6.6-B2383

DOMAINS

"Domain1.com" - ez.com Enabled: True

SIGNATURE LIMITS DKIM ADVANCED
Enabled: False Max size: 0 Enabled: False
Max message size: 0 Plus addressing: False
Max size of accounts: 0
Greylisting: False

"Domain2.com" - ezx.com Enabled: True

SIGNATURE LIMITS DKIM ADVANCED
Enabled: False Max size: 0 Enabled: False
Max message size: 0 Plus addressing: False
Max size of accounts: 0
Greylisting: False
-----------------------------------------------------------------------------------------------

IP RANGES

IP: 127.0.0.1 - 127.0.0.1 Priority: 15 Name: My computer

Allow connections Other
SMTP: True Antispam : True
POP3: True !! Protocol DISABLED !! Antivirus: True !! ANTIVIRUS NOT CONFIGURED !!
IMAP: True SSL/TLS: False

Allow Deliveries from Require Authentication from
Local To Local - True Local To Local - False
Local To External - True Local To External - False
External To Local - True External To Local - False
External To External - True External To External - True


IP: 0.0.0.0 - 255.255.255.255 Priority: 10 Name: Internet

Allow connections Other
SMTP: True Antispam : True
POP3: True !! Protocol DISABLED !! Antivirus: True !! ANTIVIRUS NOT CONFIGURED !!
IMAP: True SSL/TLS: False

Allow Deliveries from Require Authentication from
Local To Local - True Local To Local - False
Local To External - True Local To External - False
External To Local - True External To Local - False
External To External - True External To External - True


------------------------------------------------------
AUTOBANNED Local Addresses:
No entries

-----------------------------------------------------------------------------------------------

AUTOBAN
Autoban Enabled: False

No problems were found in the IP range configuration.
-----------------------------------------------------------------------------------------------

INCOMING RELAYS
No entries
-----------------------------------------------------------------------------------------------

PROTOCOLS

SMTP
GENERAL DELIVERY RFC COMPLIANCE ADVANCED
No. Connections: 0 No Retries: 4 Mins: 60 Plain Text: False Bind:
Host: EXTERNAL.TLD Empty sender: True Batch recipients: 100
Max Msg Size: 20480 Relay:- Incorrect endings: True Use STARTTLS: True
(none entered) Disc. on invalid: False Delivered-To hdr: False
Req Auth: False Loop limit: 5
Recipient hosts: 15
Con. Sec.: None
POP3
!! Service Not Enabled !!

IMAP
GENERAL PUBLIC FOLDERS ADVANCED
No. Connections: 0 Public folder name: #Public IMAP sort: True
IMAP Quota: True
IMAP Idle: True
IMAP ACL: True
Delim: "."
-----------------------------------------------------------------------------------------------

ANTISPAM

GENERAL SPAM TESTS Score SPAMASSASSIN
Spam Mark: 6 Use SPF: True - 3 Use Spamassassin: True
Add X-HmailServer-Spam: True Check HELO host: True - 2 Hostname: 127.0.0.1
Add X-HmailServer-Reason: True Check MX records: True - 3 Port: 783
Add X-HmailServer-Subject: True Verify DKIM: False - 5 Use SA score: False - 5
Subject Text: "[SPAM]"
Spam delete threshold: 8 Maximum message size: 1024

GREYLISTING:
Greylisting: False

DNSBL ENTRIES:
No entries

SURBL ENTRIES:
No entries
-----------------------------------------------------------------------------------------------

WHITELISTING
No entries
-----------------------------------------------------------------------------------------------

ANTIVIRUS: No application configured.

Block Attachments: False
-----------------------------------------------------------------------------------------------

SSL/TLS
SSL 3.0 : False
TLS 1.0 : True
TLS 1.1 : True
TLS 1.2 : True Verify Remote SSL/TLS Certs: True
SslCipherList :

ECDHE-RSA-AES128-GCM-SHA256 - ECDHE-ECDSA-AES128-GCM-SHA256 - ECDHE-RSA-AES256-GCM-SHA384
ECDHE-ECDSA-AES256-GCM-SHA384 - DHE-RSA-AES128-GCM-SHA256 - DHE-DSS-AES128-GCM-SHA256
kEDH+AESGCM - ECDHE-RSA-AES128-SHA256 - ECDHE-ECDSA-AES128-SHA256
ECDHE-RSA-AES128-SHA - ECDHE-ECDSA-AES128-SHA - ECDHE-RSA-AES256-SHA384
ECDHE-ECDSA-AES256-SHA384 - ECDHE-RSA-AES256-SHA - ECDHE-ECDSA-AES256-SHA
DHE-RSA-AES128-SHA256 - DHE-RSA-AES128-SHA - DHE-DSS-AES128-SHA256
DHE-RSA-AES256-SHA256 - DHE-DSS-AES256-SHA - DHE-RSA-AES256-SHA
AES128-GCM-SHA256 - AES256-GCM-SHA384 - ECDHE-RSA-RC4-SHA
ECDHE-ECDSA-RC4-SHA - AES128 - AES256
RC4-SHA - HIGH - !aNULL
!eNULL - !EXPORT - !DES
!3DES - !MD5 - !PSK;
-----------------------------------------------------------------------------------------------

TCPIP PORTS Connection Sec
0.0.0.0 / 25 / SMTP - None
0.0.0.0 / 110 / POP3 - None
0.0.0.0 / 143 / IMAP - None
0.0.0.0 / 587 / SMTP - None
-----------------------------------------------------------------------------------------------

LOGGING Logging Enabled: False

Paths:-
Error: C:\Program Files (x86)\hMailServer\Logs\ERROR_hmailserver_2017-08-25.log - !! ERRORS PRESENT !!
Event: C:\Program Files (x86)\hMailServer\Logs\hmailserver_events.log - Not present
Awstats: C:\Program Files (x86)\hMailServer\Logs\hmailserver_awstats.log
-----------------------------------------------------------------------------------------------

SYSTEM TESTS

Database type: MSSQL Compact

IPv6 support is available in operating system.

ERROR: Backup directory has not been specified.

Relative message paths are stored in the database for all messages.

-----------------------------------------------------------------------------------------------

HMAILSERVER.INI

[Directories]
Program folder: C:\Program Files (x86)\hMailServer\
Database folder: C:\Program Files (x86)\hMailServer\Database
Data folder: C:\Program Files (x86)\hMailServer\Data
Log folder: C:\Program Files (x86)\hMailServer\Logs
Temp folder: C:\Program Files (x86)\hMailServer\Temp
Event folder: C:\Program Files (x86)\hMailServer\Events

[Database]
Type= MSSQLCE
Username=
PasswordEncryption=1
Port= 0
Server=
Internal= 1
-----------------------------------------------------------------------------------------------

[/code]
Generated by HMSSettingsDiagnostics v1.73, Hmailserver Forum.

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

Re: SpamAssassin not detecting spams in hmailserver

Post by mattg » 2017-08-25 22:17

Can you please show your normal log with the these debug entries....

ALSO, can you please show the C:\Program Files (x86)\hMailServer\Logs\ERROR_hmailserver_2017-08-25.log
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
jimimaseye
Moderator
Moderator
Posts: 8116
Joined: 2011-09-08 17:48

Re: SpamAssassin not detecting spams in hmailserver

Post by jimimaseye » 2017-08-25 22:39

Logging is disabled.

(Also the Internet range has this box open to sending spam).
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

lslabiga
New user
New user
Posts: 7
Joined: 2017-08-25 18:36

Re: SpamAssassin not detecting spams in hmailserver

Post by lslabiga » 2017-08-26 01:41

Debug logs:

Code: Select all

"DEBUG"	740	"2017-08-25 11:28:01.846"	"Creating session 142"
"DEBUG"	1972	"2017-08-25 11:28:01.846"	"TCP connection started for session 142"
"DEBUG"	1972	"2017-08-25 11:28:01.846"	"Sending message to SpamAssassin. Session 142, File: C:\Program Files (x86)\hMailServer\Temp\{DC14494A-DFF6-4314-BF0A-A2E7A9DD2300}.tmp"
"DEBUG"	1972	"2017-08-25 11:28:02.872"	"Parsing response from SpamAssassin. Session 142"
"ERROR"	1964	"2017-08-25 11:28:02.872"	"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."
"DEBUG"	1964	"2017-08-25 11:28:02.872"	"The read operation failed. Bytes transferred: 0 Remote IP: 127.0.0.1, Session: 142, Code: 2, Message: End of file"
"DEBUG"	1964	"2017-08-25 11:28:02.872"	"Ending session 142"
"DEBUG"	740	"2017-08-25 11:28:19.650"	"Creating session 143"
"DEBUG"	1956	"2017-08-25 11:28:19.650"	"TCP connection started for session 143"
"DEBUG"	1956	"2017-08-25 11:28:19.650"	"Sending message to SpamAssassin. Session 143, File: C:\Program Files (x86)\hMailServer\Temp\{D283DD04-6569-478D-88CA-FF108BEFC1CB}.tmp"
"DEBUG"	1956	"2017-08-25 11:28:21.061"	"Parsing response from SpamAssassin. Session 143"
"ERROR"	1980	"2017-08-25 11:28:21.122"	"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."
"DEBUG"	1980	"2017-08-25 11:28:21.122"	"The read operation failed. Bytes transferred: 0 Remote IP: 127.0.0.1, Session: 143, Code: 2, Message: End of file"
"DEBUG"	1980	"2017-08-25 11:28:21.122"	"Ending session 143"
"DEBUG"	1992	"2017-08-25 11:28:30.339"	"Ending session 137"
"DEBUG"	1976	"2017-08-25 11:28:30.341"	"Ending session 138"
"DEBUG"	1964	"2017-08-25 11:28:30.342"	"Ending session 136"
"DEBUG"	1956	"2017-08-25 11:28:30.342"	"Ending session 139"
"DEBUG"	1976	"2017-08-25 11:28:30.344"	"Ending session 140"
"DEBUG"	2100	"2017-08-25 11:29:14.015"	"Creating session 144"
"DEBUG"	1980	"2017-08-25 11:29:14.015"	"TCP connection started for session 144"
"DEBUG"	1980	"2017-08-25 11:29:14.015"	"Sending message to SpamAssassin. Session 144, File: C:\Program Files (x86)\hMailServer\Temp\{D7E6F882-B533-49DA-A672-75952ECAB3C5}.tmp"
"DEBUG"	1976	"2017-08-25 11:29:15.461"	"Parsing response from SpamAssassin. Session 144"
"DEBUG"	1988	"2017-08-25 11:29:15.461"	"SA - Copy+Delete used"
"DEBUG"	1988	"2017-08-25 11:29:15.461"	"Ending session 144"
"DEBUG"	1484	"2017-08-25 11:57:03.813"	"Creating session 145"
"DEBUG"	1960	"2017-08-25 11:57:03.813"	"TCP connection started for session 145"
"DEBUG"	1960	"2017-08-25 11:57:03.813"	"Sending message to SpamAssassin. Session 145, File: C:\Program Files (x86)\hMailServer\Temp\{37FABA59-39C3-4458-8F89-8365C0840DDB}.tmp"
"DEBUG"	1960	"2017-08-25 11:57:05.318"	"Parsing response from SpamAssassin. Session 145"
"DEBUG"	1960	"2017-08-25 11:57:05.318"	"SA - Copy+Delete used"
"DEBUG"	1960	"2017-08-25 11:57:05.318"	"Ending session 145"
"DEBUG"	1992	"2017-08-25 11:57:12.151"	"Creating session 146"
"DEBUG"	1960	"2017-08-25 11:57:12.151"	"Creating session 147"
"DEBUG"	1960	"2017-08-25 11:57:12.151"	"TCP connection started for session 146"
"DEBUG"	1992	"2017-08-25 11:57:12.151"	"TCP connection started for session 141"
"DEBUG"	1976	"2017-08-25 11:57:12.167"	"Creating session 148"
"DEBUG"	1976	"2017-08-25 11:57:12.167"	"TCP connection started for session 147"
"DEBUG"	1988	"2017-08-25 11:57:23.072"	"Creating session 149"
"DEBUG"	1988	"2017-08-25 11:57:23.089"	"TCP connection started for session 148"
"DEBUG"	1996	"2017-08-25 11:57:31.978"	"Creating session 150"
"DEBUG"	1996	"2017-08-25 11:57:31.978"	"TCP connection started for session 133"
"DEBUG"	1996	"2017-08-25 11:57:32.040"	"Adding task AsynchronousTask to work queue Asynchronous task queue"
"DEBUG"	1792	"2017-08-25 11:57:32.040"	"Executing task AsynchronousTask in work queue Asynchronous task queue"
"DEBUG"	1792	"2017-08-25 11:57:32.040"	"Saving message: {193966A5-936B-4180-939F-222A21E7B582}.eml"
"DEBUG"	1792	"2017-08-25 11:57:32.040"	"Requesting SMTPDeliveryManager to start message delivery"
"DEBUG"	1980	"2017-08-25 11:57:32.040"	"Ending session 133"
"DEBUG"	1828	"2017-08-25 11:57:32.040"	"Adding task DeliveryTask to work queue SMTP delivery queue"
"DEBUG"	1868	"2017-08-25 11:57:32.040"	"Executing task DeliveryTask in work queue SMTP delivery queue"
"DEBUG"	1868	"2017-08-25 11:57:32.040"	"Delivering message..."
"DEBUG"	1868	"2017-08-25 11:57:32.056"	"Applying rules"
"DEBUG"	1868	"2017-08-25 11:57:32.056"	"Applying rule ExternalScore7"
"DEBUG"	1868	"2017-08-25 11:57:32.056"	"Performing local delivery"
"DEBUG"	1868	"2017-08-25 11:57:32.056"	"Applying rules"
"DEBUG"	1868	"2017-08-25 11:57:32.056"	"Saving message: {193966A5-936B-4180-939F-222A21E7B582}.eml"
"DEBUG"	1868	"2017-08-25 11:57:32.056"	"Reading messages from database."
"DEBUG"	1868	"2017-08-25 11:57:32.056"	"Local delivery completed"
"DEBUG"	1964	"2017-08-25 11:57:32.056"	"Saving message: {50247A52-39FB-4F5F-A862-CA1A6FFC211A}.eml"
"DEBUG"	1972	"2017-08-25 11:57:32.150"	"Ending session 148"
"DEBUG"	1980	"2017-08-25 11:57:44.843"	"Creating session 151"
"DEBUG"	1980	"2017-08-25 11:57:44.843"	"TCP connection started for session 149"
"DEBUG"	1964	"2017-08-25 11:57:44.843"	"Reading messages from database."
"DEBUG"	1996	"2017-08-25 12:02:11.021"	"Ending session 147"
"DEBUG"	1956	"2017-08-25 12:02:11.021"	"Ending session 141"
"DEBUG"	1972	"2017-08-25 12:02:11.036"	"Ending session 149"
"DEBUG"	1968	"2017-08-25 12:02:11.036"	"Ending session 146"
"DEBUG"	1132	"2017-08-25 12:17:37.926"	"Received shutdown-request from Windows."
"DEBUG"	1132	"2017-08-25 12:17:37.926"	"Application::StopServers() - Removing server work queue"
"DEBUG"	1132	"2017-08-25 12:17:37.926"	"WorkQueueManager::RemoveQueue - Server queue"
"DEBUG"	1132	"2017-08-25 12:17:37.926"	"Stopping working queue Server queue."
"DEBUG"	1132	"2017-08-25 12:17:37.926"	"Interupt and join threads in working queue Server queue"
"DEBUG"	1132	"2017-08-25 12:17:37.988"	"Still 4 remaining threads in queue Server queue. First task: SMTPDeliveryManager"
"DEBUG"	1824	"2017-08-25 12:17:38.160"	"IOService::Stop()"
"DEBUG"	1996	"2017-08-25 12:17:38.160"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	1996	"2017-08-25 12:17:38.160"	"Ending session 32"
"DEBUG"	1952	"2017-08-25 12:17:38.176"	"TCP - AcceptEx failed. Error code: 995, Message: The I/O operation has been aborted because of either a thread exit or an application request"
"DEBUG"	1952	"2017-08-25 12:17:38.176"	"Ending session 151"
"DEBUG"	1824	"2017-08-25 12:17:38.191"	"IOService::DoWork() - removing Queue IOCP Queue"
"DEBUG"	1824	"2017-08-25 12:17:38.191"	"WorkQueueManager::RemoveQueue - IOCPQueue"
"DEBUG"	1824	"2017-08-25 12:17:38.207"	"Stopping working queue IOCPQueue."
"DEBUG"	1824	"2017-08-25 12:17:38.207"	"Interupt and join threads in working queue IOCPQueue"
"DEBUG"	1952	"2017-08-25 12:17:38.207"	"Worker exited in work queue IOCPQueue"
"DEBUG"	1948	"2017-08-25 12:17:38.207"	"Worker exited in work queue IOCPQueue"
"DEBUG"	1984	"2017-08-25 12:17:38.207"	"Worker exited in work queue IOCPQueue"
"DEBUG"	2000	"2017-08-25 12:17:38.207"	"Worker exited in work queue IOCPQueue"
"DEBUG"	1988	"2017-08-25 12:17:38.207"	"Worker exited in work queue IOCPQueue"
"DEBUG"	1960	"2017-08-25 12:17:38.207"	"Worker exited in work queue IOCPQueue"
"DEBUG"	1980	"2017-08-25 12:17:38.207"	"Worker exited in work queue IOCPQueue"
"DEBUG"	1964	"2017-08-25 12:17:38.207"	"Worker exited in work queue IOCPQueue"
"DEBUG"	1972	"2017-08-25 12:17:38.207"	"Worker exited in work queue IOCPQueue"
"DEBUG"	1996	"2017-08-25 12:17:38.207"	"Worker exited in work queue IOCPQueue"
"DEBUG"	1956	"2017-08-25 12:17:38.207"	"Worker exited in work queue IOCPQueue"
"DEBUG"	1976	"2017-08-25 12:17:38.207"	"Worker exited in work queue IOCPQueue"
"DEBUG"	1968	"2017-08-25 12:17:38.207"	"Worker exited in work queue IOCPQueue"
"DEBUG"	1992	"2017-08-25 12:17:38.207"	"Worker exited in work queue IOCPQueue"
"DEBUG"	1944	"2017-08-25 12:17:38.207"	"Worker exited in work queue IOCPQueue"
"DEBUG"	1824	"2017-08-25 12:17:38.207"	"All threads are joined in queue IOCPQueue."
"DEBUG"	1824	"2017-08-25 12:17:38.207"	"WorkQueueManager::RemoveQueue - Stopped IOCPQueue"
"DEBUG"	1824	"2017-08-25 12:17:38.207"	"WorkQueueManager::RemoveQueue - Erased IOCPQueue"
"DEBUG"	1824	"2017-08-25 12:17:38.207"	"IOService::Stop() - Complete"
"DEBUG"	1824	"2017-08-25 12:17:38.207"	"Destructing work queue IOCPQueue"
"DEBUG"	1816	"2017-08-25 12:17:38.238"	"Worker exited in work queue Server queue"
"DEBUG"	1820	"2017-08-25 12:17:38.238"	"Worker exited in work queue Server queue"
"DEBUG"	1828	"2017-08-25 12:17:38.238"	"Worker exited in work queue Server queue"
"DEBUG"	1824	"2017-08-25 12:17:38.238"	"Worker exited in work queue Server queue"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"All threads are joined in queue Server queue."
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"WorkQueueManager::RemoveQueue - Stopped Server queue"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"WorkQueueManager::RemoveQueue - Erased Server queue"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"Destructing work queue Server queue"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"Application::StopServers() - Clearing caches"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"Application::StopServers() - Destructing IOCP"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"IOService::~IOService - Destructing"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"TCPServer::~TCPServer"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"TCPServer::~TCPServer"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"TCPServer::~TCPServer"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"Ending session 150"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"Application::StopServers() - Destructing DeliveryManager"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"WorkQueueManager::RemoveQueue - SMTP delivery queue"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"Stopping working queue SMTP delivery queue."
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"Interupt and join threads in working queue SMTP delivery queue"
"DEBUG"	1868	"2017-08-25 12:17:38.238"	"Worker exited in work queue SMTP delivery queue"
"DEBUG"	1860	"2017-08-25 12:17:38.238"	"Worker exited in work queue SMTP delivery queue"
"DEBUG"	1852	"2017-08-25 12:17:38.238"	"Worker exited in work queue SMTP delivery queue"
"DEBUG"	1844	"2017-08-25 12:17:38.238"	"Worker exited in work queue SMTP delivery queue"
"DEBUG"	1836	"2017-08-25 12:17:38.238"	"Worker exited in work queue SMTP delivery queue"
"DEBUG"	1864	"2017-08-25 12:17:38.238"	"Worker exited in work queue SMTP delivery queue"
"DEBUG"	1856	"2017-08-25 12:17:38.238"	"Worker exited in work queue SMTP delivery queue"
"DEBUG"	1848	"2017-08-25 12:17:38.238"	"Worker exited in work queue SMTP delivery queue"
"DEBUG"	1840	"2017-08-25 12:17:38.238"	"Worker exited in work queue SMTP delivery queue"
"DEBUG"	1832	"2017-08-25 12:17:38.238"	"Worker exited in work queue SMTP delivery queue"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"All threads are joined in queue SMTP delivery queue."
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"WorkQueueManager::RemoveQueue - Stopped SMTP delivery queue"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"WorkQueueManager::RemoveQueue - Erased SMTP delivery queue"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"Destructing work queue SMTP delivery queue"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"Application::StopServers() - Destructing FetchManager"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"ExternalFetchManager::~ExternalFetchManager"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"WorkQueueManager::RemoveQueue - External fetch queue"
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"Stopping working queue External fetch queue."
"DEBUG"	1132	"2017-08-25 12:17:38.238"	"Interupt and join threads in working queue External fetch queue"
"DEBUG"	1916	"2017-08-25 12:17:38.238"	"Worker exited in work queue External fetch queue"
"DEBUG"	1908	"2017-08-25 12:17:38.254"	"Worker exited in work queue External fetch queue"
"DEBUG"	1924	"2017-08-25 12:17:38.254"	"Worker exited in work queue External fetch queue"
"DEBUG"	1900	"2017-08-25 12:17:38.254"	"Worker exited in work queue External fetch queue"
"DEBUG"	1892	"2017-08-25 12:17:38.254"	"Worker exited in work queue External fetch queue"
"DEBUG"	1884	"2017-08-25 12:17:38.254"	"Worker exited in work queue External fetch queue"
"DEBUG"	1876	"2017-08-25 12:17:38.254"	"Worker exited in work queue External fetch queue"
"DEBUG"	1928	"2017-08-25 12:17:38.254"	"Worker exited in work queue External fetch queue"
"DEBUG"	1920	"2017-08-25 12:17:38.254"	"Worker exited in work queue External fetch queue"
"DEBUG"	1912	"2017-08-25 12:17:38.254"	"Worker exited in work queue External fetch queue"
"DEBUG"	1904	"2017-08-25 12:17:38.254"	"Worker exited in work queue External fetch queue"
"DEBUG"	1896	"2017-08-25 12:17:38.254"	"Worker exited in work queue External fetch queue"
"DEBUG"	1888	"2017-08-25 12:17:38.254"	"Worker exited in work queue External fetch queue"
"DEBUG"	1880	"2017-08-25 12:17:38.254"	"Worker exited in work queue External fetch queue"
"DEBUG"	1132	"2017-08-25 12:17:38.254"	"Still 1 remaining threads in queue External fetch queue. First task: <Unknown>"
"DEBUG"	1872	"2017-08-25 12:17:38.254"	"Worker exited in work queue External fetch queue"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"All threads are joined in queue External fetch queue."
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"WorkQueueManager::RemoveQueue - Stopped External fetch queue"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"WorkQueueManager::RemoveQueue - Erased External fetch queue"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"Destructing work queue External fetch queue"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"ExternalFetchManager::~ExternalFetchManager - Removed queue"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"Application::StopServers() - Destructing Scheduler"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"Application::StopServers() - Destructing Rest"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"WorkQueueManager::RemoveQueue - Maintenance queue"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"Stopping working queue Maintenance queue."
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"Interupt and join threads in working queue Maintenance queue"
"DEBUG"	1348	"2017-08-25 12:17:38.504"	"Worker exited in work queue Maintenance queue"
"DEBUG"	1344	"2017-08-25 12:17:38.504"	"Worker exited in work queue Maintenance queue"
"DEBUG"	1340	"2017-08-25 12:17:38.504"	"Worker exited in work queue Maintenance queue"
"DEBUG"	1336	"2017-08-25 12:17:38.504"	"Worker exited in work queue Maintenance queue"
"DEBUG"	1332	"2017-08-25 12:17:38.504"	"Worker exited in work queue Maintenance queue"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"All threads are joined in queue Maintenance queue."
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"WorkQueueManager::RemoveQueue - Stopped Maintenance queue"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"WorkQueueManager::RemoveQueue - Erased Maintenance queue"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"Destructing work queue Maintenance queue"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"WorkQueueManager::RemoveQueue - Asynchronous task queue"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"Stopping working queue Asynchronous task queue."
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"Interupt and join threads in working queue Asynchronous task queue"
"DEBUG"	1792	"2017-08-25 12:17:38.504"	"Worker exited in work queue Asynchronous task queue"
"DEBUG"	1788	"2017-08-25 12:17:38.504"	"Worker exited in work queue Asynchronous task queue"
"DEBUG"	1784	"2017-08-25 12:17:38.504"	"Worker exited in work queue Asynchronous task queue"
"DEBUG"	1780	"2017-08-25 12:17:38.504"	"Worker exited in work queue Asynchronous task queue"
"DEBUG"	1776	"2017-08-25 12:17:38.504"	"Worker exited in work queue Asynchronous task queue"
"DEBUG"	1772	"2017-08-25 12:17:38.504"	"Worker exited in work queue Asynchronous task queue"
"DEBUG"	1768	"2017-08-25 12:17:38.504"	"Worker exited in work queue Asynchronous task queue"
"DEBUG"	1764	"2017-08-25 12:17:38.504"	"Worker exited in work queue Asynchronous task queue"
"DEBUG"	1760	"2017-08-25 12:17:38.504"	"Worker exited in work queue Asynchronous task queue"
"DEBUG"	1756	"2017-08-25 12:17:38.504"	"Worker exited in work queue Asynchronous task queue"
"DEBUG"	1752	"2017-08-25 12:17:38.504"	"Worker exited in work queue Asynchronous task queue"
"DEBUG"	1748	"2017-08-25 12:17:38.504"	"Worker exited in work queue Asynchronous task queue"
"DEBUG"	1744	"2017-08-25 12:17:38.504"	"Worker exited in work queue Asynchronous task queue"
"DEBUG"	1740	"2017-08-25 12:17:38.504"	"Worker exited in work queue Asynchronous task queue"
"DEBUG"	1736	"2017-08-25 12:17:38.504"	"Worker exited in work queue Asynchronous task queue"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"All threads are joined in queue Asynchronous task queue."
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"WorkQueueManager::RemoveQueue - Stopped Asynchronous task queue"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"WorkQueueManager::RemoveQueue - Erased Asynchronous task queue"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"Destructing work queue Asynchronous task queue"
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"Application::ExitInstance - Closing database connection..."
"DEBUG"	1132	"2017-08-25 12:17:38.504"	"Application::ExitInstance - Deleting caches..."
"DEBUG"	1308	"2017-08-25 16:29:05.397"	"Application::InitInstance - Configuration loaded."
"DEBUG"	1308	"2017-08-25 16:29:05.600"	"Creating work queue Asynchronous task queue"
"DEBUG"	1308	"2017-08-25 16:29:05.600"	"Starting work queue Asynchronous task queue"
"DEBUG"	1308	"2017-08-25 16:29:05.600"	"Started work queue Asynchronous task queue"
"DEBUG"	1700	"2017-08-25 16:29:05.600"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	1704	"2017-08-25 16:29:05.600"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	1708	"2017-08-25 16:29:05.600"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	1712	"2017-08-25 16:29:05.600"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	1716	"2017-08-25 16:29:05.600"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	1720	"2017-08-25 16:29:05.600"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	1724	"2017-08-25 16:29:05.600"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	1728	"2017-08-25 16:29:05.600"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	1732	"2017-08-25 16:29:05.600"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	1736	"2017-08-25 16:29:05.600"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	1740	"2017-08-25 16:29:05.600"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	1744	"2017-08-25 16:29:05.600"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	1748	"2017-08-25 16:29:05.600"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	1752	"2017-08-25 16:29:05.600"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	1756	"2017-08-25 16:29:05.600"	"Running worker in work queue Asynchronous task queue"
"DEBUG"	1308	"2017-08-25 16:29:06.537"	"Creating work queue Server queue"
"DEBUG"	1308	"2017-08-25 16:29:06.537"	"Starting work queue Server queue"
"DEBUG"	1788	"2017-08-25 16:29:06.537"	"Running worker in work queue Server queue"
"DEBUG"	1796	"2017-08-25 16:29:06.537"	"Running worker in work queue Server queue"
"DEBUG"	1308	"2017-08-25 16:29:06.537"	"Started work queue Server queue"
"DEBUG"	1308	"2017-08-25 16:29:06.537"	"Adding task Scheduler to work queue Server queue"
"DEBUG"	1792	"2017-08-25 16:29:06.537"	"Running worker in work queue Server queue"
"DEBUG"	1800	"2017-08-25 16:29:06.537"	"Running worker in work queue Server queue"
"DEBUG"	1308	"2017-08-25 16:29:06.537"	"Adding task IOService to work queue Server queue"
"DEBUG"	1796	"2017-08-25 16:29:06.537"	"Executing task Scheduler in work queue Server queue"
"DEBUG"	1800	"2017-08-25 16:29:06.537"	"Executing task IOService in work queue Server queue"
"DEBUG"	1800	"2017-08-25 16:29:06.537"	"IOService::Start()"
"DEBUG"	1308	"2017-08-25 16:29:06.616"	"Creating work queue SMTP delivery queue"
"DEBUG"	1308	"2017-08-25 16:29:06.616"	"Starting work queue SMTP delivery queue"
"DEBUG"	1308	"2017-08-25 16:29:06.616"	"Started work queue SMTP delivery queue"
"DEBUG"	1308	"2017-08-25 16:29:06.616"	"Adding task SMTPDeliveryManager to work queue Server queue"
"DEBUG"	1308	"2017-08-25 16:29:06.616"	"Creating work queue External fetch queue"
"DEBUG"	1308	"2017-08-25 16:29:06.616"	"Starting work queue External fetch queue"
"DEBUG"	1308	"2017-08-25 16:29:06.616"	"Started work queue External fetch queue"
"DEBUG"	1308	"2017-08-25 16:29:06.616"	"Adding task ExternalFetchManager to work queue Server queue"
"DEBUG"	1804	"2017-08-25 16:29:06.616"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	1808	"2017-08-25 16:29:06.616"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	1812	"2017-08-25 16:29:06.616"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	1816	"2017-08-25 16:29:06.616"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	1820	"2017-08-25 16:29:06.616"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	1824	"2017-08-25 16:29:06.616"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	1828	"2017-08-25 16:29:06.616"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	1832	"2017-08-25 16:29:06.616"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	1836	"2017-08-25 16:29:06.616"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	1840	"2017-08-25 16:29:06.616"	"Running worker in work queue SMTP delivery queue"
"DEBUG"	1792	"2017-08-25 16:29:06.616"	"Executing task SMTPDeliveryManager in work queue Server queue"
"DEBUG"	1792	"2017-08-25 16:29:06.616"	"SMTPDeliveryManager::Start()"
"DEBUG"	1844	"2017-08-25 16:29:06.616"	"Running worker in work queue External fetch queue"
"DEBUG"	1848	"2017-08-25 16:29:06.616"	"Running worker in work queue External fetch queue"
"DEBUG"	1852	"2017-08-25 16:29:06.616"	"Running worker in work queue External fetch queue"
"DEBUG"	1856	"2017-08-25 16:29:06.616"	"Running worker in work queue External fetch queue"
"DEBUG"	1860	"2017-08-25 16:29:06.616"	"Running worker in work queue External fetch queue"
"DEBUG"	1864	"2017-08-25 16:29:06.616"	"Running worker in work queue External fetch queue"
"DEBUG"	1868	"2017-08-25 16:29:06.616"	"Running worker in work queue External fetch queue"
"DEBUG"	1872	"2017-08-25 16:29:06.616"	"Running worker in work queue External fetch queue"
"DEBUG"	1876	"2017-08-25 16:29:06.616"	"Running worker in work queue External fetch queue"
"DEBUG"	1880	"2017-08-25 16:29:06.616"	"Running worker in work queue External fetch queue"
"DEBUG"	1884	"2017-08-25 16:29:06.616"	"Running worker in work queue External fetch queue"
"DEBUG"	1888	"2017-08-25 16:29:06.616"	"Running worker in work queue External fetch queue"
"DEBUG"	1892	"2017-08-25 16:29:06.616"	"Running worker in work queue External fetch queue"
"DEBUG"	1896	"2017-08-25 16:29:06.616"	"Running worker in work queue External fetch queue"
"DEBUG"	1900	"2017-08-25 16:29:06.616"	"Running worker in work queue External fetch queue"
"DEBUG"	1788	"2017-08-25 16:29:06.616"	"Executing task ExternalFetchManager in work queue Server queue"
"DEBUG"	1788	"2017-08-25 16:29:06.616"	"ExternalFetchManager::Start()"
"DEBUG"	1800	"2017-08-25 16:29:06.991"	"Creating session 1"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Creating session 2"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Creating session 3"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Creating work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Starting work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Started work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	1800	"2017-08-25 16:29:07.053"	"Adding task IOCPQueueWorkerTask to work queue IOCPQueue"
"DEBUG"	1920	"2017-08-25 16:29:07.053"	"Running worker in work queue IOCPQueue"
"DEBUG"	1920	"2017-08-25 16:29:07.053"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	1924	"2017-08-25 16:29:07.053"	"Running worker in work queue IOCPQueue"
"DEBUG"	1924	"2017-08-25 16:29:07.053"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	1928	"2017-08-25 16:29:07.053"	"Running worker in work queue IOCPQueue"
"DEBUG"	1928	"2017-08-25 16:29:07.053"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	1932	"2017-08-25 16:29:07.053"	"Running worker in work queue IOCPQueue"
"DEBUG"	1932	"2017-08-25 16:29:07.053"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	1936	"2017-08-25 16:29:07.069"	"Running worker in work queue IOCPQueue"
"DEBUG"	1936	"2017-08-25 16:29:07.069"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	1940	"2017-08-25 16:29:07.069"	"Running worker in work queue IOCPQueue"
"DEBUG"	1940	"2017-08-25 16:29:07.069"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	1944	"2017-08-25 16:29:07.069"	"Running worker in work queue IOCPQueue"
"DEBUG"	1944	"2017-08-25 16:29:07.069"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	1948	"2017-08-25 16:29:07.069"	"Running worker in work queue IOCPQueue"
"DEBUG"	1948	"2017-08-25 16:29:07.069"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	1952	"2017-08-25 16:29:07.069"	"Running worker in work queue IOCPQueue"
"DEBUG"	1952	"2017-08-25 16:29:07.069"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	1956	"2017-08-25 16:29:07.069"	"Running worker in work queue IOCPQueue"
"DEBUG"	1956	"2017-08-25 16:29:07.069"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	1960	"2017-08-25 16:29:07.069"	"Running worker in work queue IOCPQueue"
"DEBUG"	1960	"2017-08-25 16:29:07.069"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	1964	"2017-08-25 16:29:07.069"	"Running worker in work queue IOCPQueue"
"DEBUG"	1964	"2017-08-25 16:29:07.069"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	1968	"2017-08-25 16:29:07.069"	"Running worker in work queue IOCPQueue"
"DEBUG"	1968	"2017-08-25 16:29:07.069"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	1972	"2017-08-25 16:29:07.069"	"Running worker in work queue IOCPQueue"
"DEBUG"	1972	"2017-08-25 16:29:07.069"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	1976	"2017-08-25 16:29:07.069"	"Running worker in work queue IOCPQueue"
"DEBUG"	1976	"2017-08-25 16:29:07.069"	"Executing task IOCPQueueWorkerTask in work queue IOCPQueue"
"DEBUG"	1976	"2017-08-25 16:31:41.743"	"Creating session 4"
"DEBUG"	1976	"2017-08-25 16:31:41.745"	"TCP connection started for session 2"
"DEBUG"	1968	"2017-08-25 16:31:41.888"	"Creating session 5"
"DEBUG"	1968	"2017-08-25 16:31:41.888"	"TCP connection started for session 4"
"DEBUG"	1968	"2017-08-25 16:31:41.919"	"Creating session 6"
"DEBUG"	1968	"2017-08-25 16:31:41.921"	"TCP connection started for session 5"
"DEBUG"	1944	"2017-08-25 16:31:42.093"	"Reading messages from database."
"DEBUG"	1956	"2017-08-25 16:31:42.109"	"Reading messages from database."
"DEBUG"	1968	"2017-08-25 16:32:43.806"	"Creating session 7"
"DEBUG"	1968	"2017-08-25 16:32:43.806"	"TCP connection started for session 6"
"DEBUG"	1928	"2017-08-25 16:32:44.693"	"Reading messages from database."
"DEBUG"	1976	"2017-08-25 16:32:44.693"	"Creating session 8"
"DEBUG"	1976	"2017-08-25 16:32:44.693"	"TCP connection started for session 7"
"DEBUG"	1960	"2017-08-25 16:32:45.881"	"Creating session 9"
"DEBUG"	1960	"2017-08-25 16:32:45.881"	"TCP connection started for session 3"
"DEBUG"	1928	"2017-08-25 16:32:45.982"	"Adding task AsynchronousTask to work queue Asynchronous task queue"
"DEBUG"	1756	"2017-08-25 16:32:45.982"	"Executing task AsynchronousTask in work queue Asynchronous task queue"
"DEBUG"	1756	"2017-08-25 16:32:45.999"	"Saving message: {83AB53EA-49D8-4B54-B6EE-8914992DF8AA}.eml"
"DEBUG"	1756	"2017-08-25 16:32:46.032"	"Requesting SMTPDeliveryManager to start message delivery"
"DEBUG"	1792	"2017-08-25 16:32:46.049"	"Adding task DeliveryTask to work queue SMTP delivery queue"
"DEBUG"	1840	"2017-08-25 16:32:46.066"	"Executing task DeliveryTask in work queue SMTP delivery queue"
"DEBUG"	1840	"2017-08-25 16:32:46.066"	"Delivering message..."
"DEBUG"	1840	"2017-08-25 16:32:46.066"	"Applying rules"
"DEBUG"	1960	"2017-08-25 16:32:46.082"	"Ending session 3"
"DEBUG"	1840	"2017-08-25 16:32:46.099"	"Applying rule ExternalScore7"
"DEBUG"	1840	"2017-08-25 16:32:46.117"	"Performing local delivery"
"DEBUG"	1976	"2017-08-25 16:32:46.150"	"Saving message: {CC3B18A1-6854-4588-9DE5-B2226D470B72}.eml"
"DEBUG"	1976	"2017-08-25 16:32:46.150"	"Reading messages from database."
"DEBUG"	1840	"2017-08-25 16:32:46.167"	"Applying rules"
"DEBUG"	1840	"2017-08-25 16:32:46.184"	"Saving message: {83AB53EA-49D8-4B54-B6EE-8914992DF8AA}.eml"
"DEBUG"	1840	"2017-08-25 16:32:46.200"	"Reading messages from database."
"DEBUG"	1840	"2017-08-25 16:32:46.200"	"Local delivery completed"
"DEBUG"	1960	"2017-08-25 16:32:46.386"	"The read operation failed. Bytes transferred: 0 Remote IP: 127.0.0.1, Session: 7, Code: 2, Message: End of file"
"DEBUG"	1960	"2017-08-25 16:32:46.386"	"Ending session 7"
"DEBUG"	1976	"2017-08-25 16:32:46.553"	"Creating session 10"
"DEBUG"	1976	"2017-08-25 16:32:46.553"	"TCP connection started for session 8"
"DEBUG"	1936	"2017-08-25 16:33:00.962"	"Creating session 11"
"DEBUG"	1936	"2017-08-25 16:33:00.962"	"TCP connection started for session 9"
"DEBUG"	1952	"2017-08-25 16:33:01.009"	"Adding task AsynchronousTask to work queue Asynchronous task queue"
"DEBUG"	1756	"2017-08-25 16:33:01.009"	"Executing task AsynchronousTask in work queue Asynchronous task queue"
"DEBUG"	1756	"2017-08-25 16:33:01.009"	"Saving message: {2FA9AFDB-E51A-4128-B22B-4113376F3DD3}.eml"
"DEBUG"	1756	"2017-08-25 16:33:01.009"	"Requesting SMTPDeliveryManager to start message delivery"
"DEBUG"	1792	"2017-08-25 16:33:01.009"	"Adding task DeliveryTask to work queue SMTP delivery queue"
"DEBUG"	1840	"2017-08-25 16:33:01.009"	"Executing task DeliveryTask in work queue SMTP delivery queue"
"DEBUG"	1840	"2017-08-25 16:33:01.009"	"Delivering message..."
"DEBUG"	1840	"2017-08-25 16:33:01.009"	"Applying rules"
"DEBUG"	1840	"2017-08-25 16:33:01.009"	"Applying rule ExternalScore7"
"DEBUG"	1840	"2017-08-25 16:33:01.009"	"Performing local delivery"
"DEBUG"	1936	"2017-08-25 16:33:01.025"	"Ending session 9"
"DEBUG"	1928	"2017-08-25 16:33:01.025"	"Saving message: {0A98C284-34E0-4FE2-A08C-71B0B6A465DF}.eml"
"DEBUG"	1928	"2017-08-25 16:33:01.025"	"Reading messages from database."
"DEBUG"	1840	"2017-08-25 16:33:01.040"	"Applying rules"
"DEBUG"	1840	"2017-08-25 16:33:01.040"	"Saving message: {2FA9AFDB-E51A-4128-B22B-4113376F3DD3}.eml"
"DEBUG"	1840	"2017-08-25 16:33:01.040"	"Reading messages from database."
"DEBUG"	1840	"2017-08-25 16:33:01.040"	"Local delivery completed"
"DEBUG"	1944	"2017-08-25 16:33:01.181"	"The read operation failed. Bytes transferred: 0 Remote IP: 127.0.0.1, Session: 8, Code: 2, Message: End of file"
"DEBUG"	1944	"2017-08-25 16:33:01.181"	"Ending session 8"
"DEBUG"	1976	"2017-08-25 16:33:10.654"	"Ending session 6"
"DEBUG"	1960	"2017-08-25 16:33:10.654"	"Ending session 4"
"DEBUG"	1928	"2017-08-25 16:33:10.654"	"Ending session 5"
"DEBUG"	1944	"2017-08-25 16:33:10.654"	"Ending session 2"
"DEBUG"	3016	"2017-08-25 16:33:57.171"	"Creating session 12"
"DEBUG"	1960	"2017-08-25 16:33:57.171"	"TCP connection started for session 12"
"DEBUG"	1960	"2017-08-25 16:33:57.171"	"Sending message to SpamAssassin. Session 12, File: C:\Program Files (x86)\hMailServer\Temp\{3E5DEDB6-1057-4453-8C17-20A53A4DEB03}.tmp"
"DEBUG"	1960	"2017-08-25 16:33:58.485"	"Parsing response from SpamAssassin. Session 12"
"DEBUG"	1960	"2017-08-25 16:33:58.485"	"SA - Copy+Delete used"
"DEBUG"	1960	"2017-08-25 16:33:58.485"	"Ending session 12"
ERROR log:

Code: Select all

"ERROR"	1952	"2017-08-25 10:19:35.040"	"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"	1984	"2017-08-25 10:20:00.693"	"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"	1964	"2017-08-25 11:28:02.872"	"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"	1980	"2017-08-25 11:28:21.122"	"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."
jimimaseye wrote:Logging is disabled.

(Also the Internet range has this box open to sending spam).
Sorry, logging was disabled when I did the diagnostic report stuff, enabled it right after that. Also, what did you mean with the internet range?

Thank you!

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

Re: SpamAssassin not detecting spams in hmailserver

Post by mattg » 2017-08-26 02:42

lslabiga wrote:Sorry, logging was disabled when I did the diagnostic report stuff, enabled it right after that. Also, what did you mean with the internet range?
clearly the SpamAssassin isn't working - that's why it times out....

The internet range issue is that you allow local to external without authentication.
That means that anyone can log onto you server, pretend to be sending mail from yourdomain.com and send mail to the world
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation

lslabiga
New user
New user
Posts: 7
Joined: 2017-08-25 18:36

Re: SpamAssassin not detecting spams in hmailserver

Post by lslabiga » 2017-08-26 03:41

mattg wrote: clearly the SpamAssassin isn't working - that's why it times out....

The internet range issue is that you allow local to external without authentication.
That means that anyone can log onto you server, pretend to be sending mail from yourdomain.com and send mail to the world
How is it not working? Test gives out some results that I dont understand... The whole anti-spam also seems to be not working as the hmailserver isn't detecting spams (0 in spam messages in the status tab) even though the mail sent was the GTUBE message test. I assume that anti-spam works even if I sent with different domains on the same host? I am currently only doing local emails through localhost and no external mails or from the internet since I'm only testing things out.

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

Re: SpamAssassin not detecting spams in hmailserver

Post by mattg » 2017-08-26 06:12

lslabiga wrote:How is it not working?
"ERROR" 1964 "2017-08-25 11:28:02.872" "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."
lslabiga wrote:The whole anti-spam also seems to be not working as the hmailserver isn't detecting spams (0 in spam messages in the status tab) even though the mail sent was the GTUBE message test.
GTUBE is a spam assassin test, not a general Spam detection test.
lslabiga wrote:I am currently only doing local emails through localhost and no external mails or from the internet since I'm only testing things out.
You may well only be doing local emails, but a spammer can use your server to send mass mail from your server/domain without your knowledge - that's what they do
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
jimimaseye
Moderator
Moderator
Posts: 8116
Joined: 2011-09-08 17:48

Re: SpamAssassin not detecting spams in hmailserver

Post by jimimaseye » 2017-08-26 09:32

Check the SpamAssassin service is up and running (look at its spamd log) and that port 783 is free and open.
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

lslabiga
New user
New user
Posts: 7
Joined: 2017-08-25 18:36

Re: SpamAssassin not detecting spams in hmailserver

Post by lslabiga » 2017-08-26 11:07

jimimaseye wrote:Check the SpamAssassin service is up and running (look at its spamd log) and that port 783 is free and open.
The service is running and port 783 is open but SpamAssassin still isn't working. Is there some settings I need to setup in Thunderbird?

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

Re: SpamAssassin not detecting spams in hmailserver

Post by jimimaseye » 2017-08-26 11:13

This has nothing to do with email clients.

Review and re-apply the SpamAssassin installation instructions.
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

tunis
Normal user
Normal user
Posts: 222
Joined: 2015-01-05 20:22
Location: Sweden

Re: SpamAssassin not detecting spams in hmailserver

Post by tunis » 2017-08-26 15:53

I saw in the diagnostics your spam score for SpamAssassin was 5 and mark as spam 6.
If only SpamAssassin detect spam, mail are not marked as spam.
HMS 5.6.8 B2437.17 on Windows Server 2019 Core VM.
HMS 5.6.8 B2451.21 on Windows Server 2016 Core VM.
HMS 5.6.7 B2425.16 on Windows Server 2012 R2 Core VM.

lslabiga
New user
New user
Posts: 7
Joined: 2017-08-25 18:36

Re: SpamAssassin not detecting spams in hmailserver

Post by lslabiga » 2017-09-01 14:00

tunis wrote:I saw in the diagnostics your spam score for SpamAssassin was 5 and mark as spam 6.
If only SpamAssassin detect spam, mail are not marked as spam.
Does that mean that if SA detects a mail as spam, it wont show up in hmailserver's status?

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

Re: SpamAssassin not detecting spams in hmailserver

Post by jimimaseye » 2017-09-01 14:13

lslabiga wrote:
tunis wrote:I saw in the diagnostics your spam score for SpamAssassin was 5 and mark as spam 6.
If only SpamAssassin detect spam, mail are not marked as spam.
Does that mean that if SA detects a mail as spam, it wont show up in hmailserver's status?
Yes. Its because you have "Use SA score: False - 5"

Effectively saying that you dont use SA actual score (because you have "FALSE") but just the advice from SA that it is spam - and on this advice you give it a score of 5. As you have it as 5, but your mark threshold is 6, you are not acheiving the mark threshold.

Conclusion (and advice): lower your mark threshold from 6 to 5.
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

tunis
Normal user
Normal user
Posts: 222
Joined: 2015-01-05 20:22
Location: Sweden

Re: SpamAssassin not detecting spams in hmailserver

Post by tunis » 2017-09-01 14:14

lslabiga wrote:
tunis wrote:I saw in the diagnostics your spam score for SpamAssassin was 5 and mark as spam 6.
If only SpamAssassin detect spam, mail are not marked as spam.
Does that mean that if SA detects a mail as spam, it wont show up in hmailserver's status?
If only SA and no other spam score added, then it's not Spam.

Set SA score to 6 or mark as spam to 5, then if SA detect it as spam it's also marked as spam.
HMS 5.6.8 B2437.17 on Windows Server 2019 Core VM.
HMS 5.6.8 B2451.21 on Windows Server 2016 Core VM.
HMS 5.6.7 B2425.16 on Windows Server 2012 R2 Core VM.

lslabiga
New user
New user
Posts: 7
Joined: 2017-08-25 18:36

Re: SpamAssassin not detecting spams in hmailserver

Post by lslabiga » 2017-09-01 16:15

Does SpamAssassin work on local emails? I'm thinking that it is the problem rn. I'm using Thunderbird and have 2 accounts with different domains and I'm sending messages from one to another through Thunderbird. I doubt it is the problem but I still don't understand SA right now lol

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

Re: SpamAssassin not detecting spams in hmailserver

Post by jimimaseye » 2017-09-01 18:33

Antispam checks are not run emails that come in via an authenticated connection.
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

Post Reply