External POP3 Fetcher - DELE without RETR - crashing frequently

Use this forum if you want to discuss a problem or ask a question related to a hMailServer beta release.
Post Reply
derelvis
New user
New user
Posts: 18
Joined: 2018-11-19 19:15

External POP3 Fetcher - DELE without RETR - crashing frequently

Post by derelvis » 2019-04-29 19:31

Since version HMS 5.6.7-B2427 (x64) I have massive problems with refetching of old - already delivered emails - when fetcher tries to delete them during POP3fetch without getting new mails at the same time (like described here: https://www.hmailserver.com/forum/viewt ... 10&t=32493). And it continues with HMS 5.7.0-B2428 (x64), hoped that it will fix it for me. On some days there are 20-30 emails reappearing at some accounts and users get stressed abut that.
Not sure to which version I could switch safely or how to find a version in which it has already been fixed as it seems that a solution is already available (refering to the mentioned thread above).
Any advice?
Thank you very much in advance!
Any more info needed?

hmailserver_2019-04-29.log:

Code: Select all

"DEBUG"	64544	"2019-04-29 12:06:19.603"	"Adding task ExternalFetchTask to work queue External fetch queue"
"DEBUG"	54760	"2019-04-29 12:06:19.603"	"Executing task ExternalFetchTask in work queue External fetch queue"
"DEBUG"	54760	"2019-04-29 12:06:19.603"	"Retrieving messages from external account info@XXXXXX.de"
"DEBUG"	54760	"2019-04-29 12:06:19.603"	"Pre-creating session 9294"
"DEBUG"	60648	"2019-04-29 12:06:19.634"	"TCP connection started for session 9294"
"DEBUG"	60648	"2019-04-29 12:06:19.634"	"Performing SSL/TLS handshake for session 9294. Verify certificate: True, Expected remote host name: pop.XXXXXX.de"
"DEBUG"	45628	"2019-04-29 12:06:19.806"	"Certificate verification succeeded for session 9294."
"POP3C"	45628	9294	"2019-04-29 12:06:19.915"	"XX.XXX.XX.X"	"RECEIVED: +OK Hello there."
"POP3C"	45628	9294	"2019-04-29 12:06:19.915"	"XX.XXX.XX.X"	"SENT: USER info@XXXXXXX.de"
"POP3C"	52092	9294	"2019-04-29 12:06:19.931"	"XX.XXX.XX.X"	"RECEIVED: +OK Password required."
"POP3C"	52092	9294	"2019-04-29 12:06:19.931"	"XX.XXX.XX.X"	"SENT: ***"
"POP3C"	52092	9294	"2019-04-29 12:06:20.009"	"XX.XXX.XX.X"	"RECEIVED: +OK logged in."
"DEBUG"	24076	"2019-04-29 12:06:20.009"	"Completed retrieval of messages from external account."
"POP3C"	52092	9294	"2019-04-29 12:06:20.009"	"XX.XXX.XX.X"	"SENT: UIDL"
"DEBUG"	6444	"2019-04-29 12:06:20.024"	"Completed retrieval of messages from external account."
"POP3C"	9724	9294	"2019-04-29 12:06:20.149"	"XX.XXX.XX.X"	"SENT: DELE 159"
"POP3C"	50260	9294	"2019-04-29 12:06:20.181"	"XX.XXX.XX.X"	"RECEIVED: +OK Deleted."
"ERROR"	50260	"2019-04-29 12:06:20.181"	"Severity: 3 (Medium), Code: HM5136, Source: TCPConnection::AsyncReadCompleted, Description: An error occured while parsing data. Data size: 0 Remote IP: XX.XXX.XX.X"
"DEBUG"	50260	"2019-04-29 12:06:20.181"	"Ending session 9294"
"DEBUG"	54760	"2019-04-29 12:06:20.181"	"Completed retrieval of messages from external account."
"ERROR"	50260	"2019-04-29 12:06:20.181"	"Severity: 2 (High), Code: HM4208, Source: ExceptionHandler::Run, Description: An error occured while executing 'IOCPQueueWorkerTask'"
"DEBUG"	50260	"2019-04-29 12:06:20.181"	"Logging exception.."
"ERROR"	50260	"2019-04-29 12:06:20.633"	"Severity: 1 (Critical), Code: HM5519, Source: StackLogger::Log, Description: An error has been detected. A mini dump has been written to C:\Program Files (x86)\hMailServer\Logs\minidump_2019-04-29 120620_{072557AB-7A3F-44FB-899A-0EAB902857DE}.dmp"
"DEBUG"	50260	"2019-04-29 12:06:20.633"	"Completed logging of exception..."
ERROR_hmailserver_2019-04-29.log:

Code: Select all

"ERROR"	50260	"2019-04-29 12:06:20.181"	"Severity: 3 (Medium), Code: HM5136, Source: TCPConnection::AsyncReadCompleted, Description: An error occured while parsing data. Data size: 0 Remote IP: XX.XXX.XX.X"
"ERROR"	50260	"2019-04-29 12:06:20.181"	"Severity: 2 (High), Code: HM4208, Source: ExceptionHandler::Run, Description: An error occured while executing 'IOCPQueueWorkerTask'"
"ERROR"	50260	"2019-04-29 12:06:20.633"	"Severity: 1 (Critical), Code: HM5519, Source: StackLogger::Log, Description: An error has been detected. A mini dump has been written to C:\Program Files (x86)\hMailServer\Logs\minidump_2019-04-29 120620_{072557AB-7A3F-44FB-899A-0EAB902857DE}.dmp"
Attachments
minidump_2019-04-29 120620_{072557AB-7A3F-44FB-899A-0EAB902857DE}.dmp.zip
(33.27 KiB) Downloaded 12 times
HMS 5.7.0-B2428 (x64) - MySQL 8.0.15 (DB version 5700)
ClamWin0.99.4 + Clamd service - SpamAssassin 3.4.1.38
Windows Server 2012 - 64Bit

derelvis
New user
New user
Posts: 18
Joined: 2018-11-19 19:15

Re: External POP3 Fetcher - DELE without RETR - crashing frequently

Post by derelvis » 2019-05-25 13:30

@Dravion:
It seems that there even already exists a fix for this issue:
https://github.com/Dravion/hMailServer/issues/1
https://github.com/hmailserver/hmailser ... n:DELE_fix

Any chance to get this solved in your version? I was not able to create a pull request from sprintman repo.

For us it is even getting worse: we have a forward configured in hms to an external address and when the error happens and old emails reappear and get back to delivery they also are forwarded again. And this leads to an error replay to the initial sender. So some customers now get failure emails on very old emails about message already exists.

I would extremly happy for any help on this :-)
Thank you so much in advance!
HMS 5.7.0-B2428 (x64) - MySQL 8.0.15 (DB version 5700)
ClamWin0.99.4 + Clamd service - SpamAssassin 3.4.1.38
Windows Server 2012 - 64Bit

User avatar
Dravion
Senior user
Senior user
Posts: 1327
Joined: 2015-09-26 11:50
Location: Germany
Contact:

Re: External POP3 Fetcher - DELE without RETR - crashing frequently

Post by Dravion » 2019-05-25 17:31

Hi,
Can you first try this version

https://github.com/Dravion/hMailServer/ ... SL-x64.exe

In some cases the LibreSSL version works more robust on the 64-Bit version.
64-Bit builds of hMailserver

hMailServer-5.6.+ (HCD) https://github.com/hMailServer-ComDevs/hmailserver
hMailServer-5.6.+ (LTS) https://github.com/Dravion/hMailServer/releases

derelvis
New user
New user
Posts: 18
Joined: 2018-11-19 19:15

Re: External POP3 Fetcher - DELE without RETR - crashing frequently

Post by derelvis » 2019-05-25 18:28

Hi Dravion,

thank you for your reply and the hint. I downloaded and installed the LibreSSL x64 version and installed it (btw. it shows 5.7.0-B2429 in Status dialogue ;-) ).
I will check for errors and let you know.

Thanks again and best regards
HMS 5.7.0-B2428 (x64) - MySQL 8.0.15 (DB version 5700)
ClamWin0.99.4 + Clamd service - SpamAssassin 3.4.1.38
Windows Server 2012 - 64Bit

derelvis
New user
New user
Posts: 18
Joined: 2018-11-19 19:15

Re: External POP3 Fetcher - DELE without RETR - crashing frequently

Post by derelvis » 2019-05-25 18:52

Sorry, no luck :(
Set external pop3 fetcher to "delete after 30 days" (before it was "delete after 31 days") to get a result immediately and it just crashed again on the next try without new mails to fetch from pop3 server:

Code: Select all

"TCPIP"	85412	"2019-05-25 18:36:44.579"	"TCPConnection - TLS/SSL handshake completed. Session Id: 172, Remote IP: xx.xxx.xx.x, Version: TLSv1.2, Cipher: AES128-GCM-SHA256, Bits: 128"
"POP3C"	85412	172	"2019-05-25 18:36:44.635"	"xx.xxx.xx.x"	"RECEIVED: +OK Hello there."
"POP3C"	85412	172	"2019-05-25 18:36:44.636"	"xx.xxx.xx.x"	"SENT: USER xxx@xxx.de"
"POP3C"	85452	172	"2019-05-25 18:36:44.643"	"xx.xxx.xx.x"	"RECEIVED: +OK Password required."
"POP3C"	85452	172	"2019-05-25 18:36:44.645"	"xx.xxx.xx.x"	"SENT: ***"
"POP3C"	85412	172	"2019-05-25 18:36:44.689"	"xx.xxx.xx.x"	"RECEIVED: +OK logged in."
"POP3C"	85412	172	"2019-05-25 18:36:44.690"	"xx.xxx.xx.x"	"SENT: UIDL"
"POP3C"	72656	172	"2019-05-25 18:36:44.776"	"xx.xxx.xx.x"	"SENT: DELE 839"
"POP3C"	85456	172	"2019-05-25 18:36:44.787"	"xx.xxx.xx.x"	"RECEIVED: +OK Deleted."
"ERROR"	85456	"2019-05-25 18:36:44.789"	"Severity: 3 (Medium), Code: HM5136, Source: TCPConnection::AsyncReadCompleted, Description: An error occured while parsing data. Data size: 0 Remote IP: xx.xxx.xx.x"
"DEBUG"	85456	"2019-05-25 18:36:44.795"	"Ending session 172"
"DEBUG"	85564	"2019-05-25 18:36:44.795"	"Completed retrieval of messages from external account."
"ERROR"	85456	"2019-05-25 18:36:44.796"	"Severity: 2 (High), Code: HM4208, Source: ExceptionHandler::Run, Description: An error occured while executing 'IOCPQueueWorkerTask'"
"DEBUG"	85456	"2019-05-25 18:36:44.798"	"Logging exception.."
"ERROR"	85456	"2019-05-25 18:36:45.505"	"Severity: 1 (Critical), Code: HM5519, Source: StackLogger::Log, Description: An error has been detected. A mini dump has been written to C:\Program Files (x86)\hMailServer\Logs\minidump_2019-05-25 183644_{DBD6DC5D-F9F4-4077-A01F-2C232211FC2E}.dmp"
"DEBUG"	85456	"2019-05-25 18:36:45.507"	"Completed logging of exception..."
Any other ideas?
Once I delete these old messages (here it says a total number of 839) from the pop3 server directly in webmail the error does not happen!
But as this server has no option to do an automatic deletion after a period of time within webmail it is no solution. I am only able to use the option in HMS.
HMS 5.7.0-B2428 (x64) - MySQL 8.0.15 (DB version 5700)
ClamWin0.99.4 + Clamd service - SpamAssassin 3.4.1.38
Windows Server 2012 - 64Bit

Post Reply