Use this forum if you want to discuss a problem or ask a question related to a hMailServer beta release.
-
sprint
- Normal user
- Posts: 31
- Joined: 2018-01-31 01:36
Post
by sprint » 2018-03-09 02:05
I have recently started testing 5.7.0-B2429 and been getting errors when the external fetch tries to delete old messages. This only, and always, happens when there is no new messages to fetch but there is an old message to be deleted . After the error, the old message remains on the external server and hMailServer seems to ignore it in future sessions, neither fetching nor deleting it. I never saw this issue with 5.6.7-B2425 or earlier.
Code: Select all
"DEBUG" 6816 "2018-03-07 18:11:08.793" "Adding task ExternalFetchTask to work queue External fetch queue"
"DEBUG" 4260 "2018-03-07 18:11:08.793" "Executing task ExternalFetchTask in work queue External fetch queue"
"DEBUG" 4260 "2018-03-07 18:11:08.793" "Retrieving messages from external account mail"
"DEBUG" 4260 "2018-03-07 18:11:08.794" "Pre-creating session 1629"
"TCPIP" 4260 "2018-03-07 18:11:08.794" "Connecting to xxx.xxx.xxx.xxx:995..."
"DEBUG" 6664 "2018-03-07 18:11:08.800" "TCP connection started for session 1629"
"DEBUG" 6664 "2018-03-07 18:11:08.800" "Performing SSL/TLS handshake for session 1629. Verify certificate: True, Expected remote host name: mail.domain.com"
"DEBUG" 6656 "2018-03-07 18:11:08.816" "Certificate verification succeeded for session 1629."
"TCPIP" 6664 "2018-03-07 18:11:08.829" "TCPConnection - TLS/SSL handshake completed. Session Id: 1629, Remote IP: xxx.xxx.xxx.xxx, Version: TLSv1.2, Cipher: ECDHE-RSA-AES128-GCM-SHA256, Bits: 128"
"POP3C" 6664 1629 "2018-03-07 18:11:09.029" "xxx.xxx.xxx.xxx" "RECEIVED: +OK Dovecot ready."
"POP3C" 6664 1629 "2018-03-07 18:11:09.030" "xxx.xxx.xxx.xxx" "SENT: USER mail@domain.com"
"POP3C" 6656 1629 "2018-03-07 18:11:09.035" "xxx.xxx.xxx.xxx" "RECEIVED: +OK"
"POP3C" 6656 1629 "2018-03-07 18:11:09.035" "xxx.xxx.xxx.xxx" "SENT: ***"
"POP3C" 6664 1629 "2018-03-07 18:11:09.142" "xxx.xxx.xxx.xxx" "RECEIVED: +OK Logged in."
"POP3C" 6664 1629 "2018-03-07 18:11:09.142" "xxx.xxx.xxx.xxx" "SENT: UIDL"
"POP3C" 6656 1629 "2018-03-07 18:11:09.158" "xxx.xxx.xxx.xxx" "SENT: DELE 51"
"POP3C" 6656 1629 "2018-03-07 18:11:09.164" "xxx.xxx.xxx.xxx" "RECEIVED: +OK Marked to be deleted."
"ERROR" 6656 "2018-03-07 18:11:09.164" "Severity: 3 (Medium), Code: HM5136, Source: TCPConnection::AsyncReadCompleted, Description: An error occured while parsing data. Data size: 0 Remote IP: xxx.xxx.xxx.xxx"
"DEBUG" 6656 "2018-03-07 18:11:09.165" "Ending session 1629"
"DEBUG" 4260 "2018-03-07 18:11:09.165" "Completed retrieval of messages from external account."
"ERROR" 6656 "2018-03-07 18:11:09.165" "Severity: 2 (High), Code: HM4208, Source: ExceptionHandler::Run, Description: An error occured while executing 'IOCPQueueWorkerTask'"
"DEBUG" 6656 "2018-03-07 18:11:09.165" "Logging exception.."
"ERROR" 6656 "2018-03-07 18:11:09.278" "Severity: 1 (Critical), Code: HM5519, Source: StackLogger::Log, Description: An error has been detected. A mini dump has been written to C:\hMailServer\Logs\minidump_2018-03-07 181109_{0F93C8D0-6197-4E1E-A4B1-78EBB49D585F}.dmp"
"DEBUG" 6656 "2018-03-07 18:11:09.278" "Completed logging of exception..."
-
mattg
- Moderator
- Posts: 22435
- Joined: 2007-06-14 05:12
- Location: 'The Outback' Australia
Post
by mattg » 2018-03-09 02:36
Have you posted this to Github?
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation
-
sprint
- Normal user
- Posts: 31
- Joined: 2018-01-31 01:36
Post
by sprint » 2018-03-09 03:02
Not yet. I have only just figured out exactly when it was happening.
I have recently been testing an external script that watches the external account with IMAP idle and calls FetchAccount.DownloadNow when a new message comes in. I left hMailServer set to download every 15mins as a backup while I confirmed the script was reliable. This was all working well with 5.6.7 .
When I upgraded to 5.7 the errors started, but seemingly at random. But I noticed it only happened on the fetches that hMailServer had triggered, not the ones triggered by my script. And it seemed to happen mostly in the early hours of the morning, and only occasionally during business hours.
When I realised that it happened only when there was no new messages this made sense, since the script only triggers when there is a message, and also there is a lot more mail that comes in during business hours.
For now I have set hMailServer to fetch every 360mins which seems to avoid the issue since we never go that long between messages (and the scripted call to DownloadNow resets the timer) so the fetch account never gets checked unless there is new mail waiting.
-
jimimaseye
- Moderator
- Posts: 10053
- Joined: 2011-09-08 17:48
Post
by jimimaseye » 2018-03-15 09:03
Can you report this all on github?
5.7 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
-
sprint
- Normal user
- Posts: 31
- Joined: 2018-01-31 01:36
Post
by sprint » 2018-03-16 08:26
I had already done so.
I think I've just tracked down the problem, but I won't have time to compile and test til next week
-
RvdH
- Senior user
- Posts: 3231
- Joined: 2008-06-27 14:42
- Location: The Netherlands
Post
by RvdH » 2018-03-19 17:56
Is this something that should/could be fixed in 5.6.x as well? I reviewed the code in 5.6.x and it is very similar to 5.7 code except for a few int to size conversions (64-bit migrations)
CIDR to RegEx: d-fault.nl/cidrtoregex
DNS Lookup: d-fault.nl/dnstools
DKIM Generator: d-fault.nl/dkimgenerator
DNSBL Lookup: d-fault.nl/dnsbllookup
GEOIP Lookup: d-fault.nl/geoiplookup
-
RvdH
- Senior user
- Posts: 3231
- Joined: 2008-06-27 14:42
- Location: The Netherlands
Post
by RvdH » 2018-03-20 10:23
OK, I guess i need to fix this in my experimental build than as it has #93 implemented
CIDR to RegEx: d-fault.nl/cidrtoregex
DNS Lookup: d-fault.nl/dnstools
DKIM Generator: d-fault.nl/dkimgenerator
DNSBL Lookup: d-fault.nl/dnsbllookup
GEOIP Lookup: d-fault.nl/geoiplookup