Error message every minute

Use this forum if you have installed hMailServer and want to ask a question related to a production release of hMailServer. Before posting, please read the troubleshooting guide. A large part of all reported issues are already described in detail here.
Post Reply
LesD
Senior user
Senior user
Posts: 343
Joined: 2009-01-15 20:22
Location: London, UK.

Error message every minute

Post by LesD » 2015-05-17 22:23

I keep getting the same error message every minute and can't work out how to stop it.

It started a few hours ago.

The last few log lines:

Code: Select all

"TCPIP"	2332	"2015-05-17 20:49:26.034"	"TCP - 87.81.223.168 connected to 10.27.27.35:1439."
"TCPIP"	2332	"2015-05-17 20:49:26.034"	"TCP - 87.81.223.168 connected to 10.27.27.35:1439."
"ERROR"	1484	"2015-05-17 20:49:56.548"	"Severity: 2 (High), Code: HM5032, Source: DALConnection::Execute, Description: MySQL: Incorrect string value: '\xF3\xBE\xAC\x8D\xF3\xBE...' for column 'metadata_subject' at row 1 (Additional info: INSERT INTO hm_message_metadata (metadata_accountid, metadata_folderid, metadata_messageid, metadata_dateutc, metadata_from, metadata_subject, metadata_to, metadata_cc) VALUES (19, 33, 579768, '2015-05-17 09:18:01', '"Priv Msg" <kik1@lupive.com>', '[MessageLimit][testmode] [DNSBL][testmode] -"TCPIP"	2332	"2015-05-17 20:50:26.080"	"TCP - 87.81.223.168 connected to 10.27.27.35:1439."
"TCPIP"	2332	"2015-05-17 20:50:26.090"	"TCP - 87.81.223.168 connected to 10.27.27.35:1439."
"ERROR"	1484	"2015-05-17 20:50:56.554"	"Severity: 2 (High), Code: HM5032, Source: DALConnection::Execute, Description: MySQL: Incorrect string value: '\xF3\xBE\xAC\x8D\xF3\xBE...' for column 'metadata_subject' at row 1 (Additional info: INSERT INTO hm_message_metadata (metadata_accountid, metadata_folderid, metadata_messageid, metadata_dateutc, metadata_from, metadata_subject, metadata_to, metadata_cc) VALUES (19, 33, 579768, '2015-05-17 09:18:01', '"Priv Msg" <kik1@lupive.com>', '[MessageLimit][testmode] [DNSBL][testmode] -"TCPIP"	2332	"2015-05-17 20:51:26.077"	"TCP - 87.81.223.168 connected to 10.27.27.35:1439."
"TCPIP"	2332	"2015-05-17 20:51:26.097"	"TCP - 87.81.223.168 connected to 10.27.27.35:1439."
IP 87.81.223.168 is an authorised site which is allowed to connect to collect mail via IMAP. 1439 is my IMAP port.

The error line is very long and looks as if it might be a concentration of several log lines.

Below is just the error line.

Code: Select all

"ERROR"	1484	"2015-05-17 20:50:56.554"	"Severity: 2 (High), Code: HM5032, Source: DALConnection::Execute, Description: MySQL: Incorrect string value: '\xF3\xBE\xAC\x8D\xF3\xBE...' for column 'metadata_subject' at row 1 (Additional info: INSERT INTO hm_message_metadata (metadata_accountid, metadata_folderid, metadata_messageid, metadata_dateutc, metadata_from, metadata_subject, metadata_to, metadata_cc) VALUES (19, 33, 579768, '2015-05-17 09:18:01', '"Priv Msg" <kik1@lupive.com>', '[MessageLimit][testmode] [DNSBL][testmode] -"TCPIP"	2332	"2015-05-17 20:51:26.077"	"TCP - 87.81.223.168 connected to 10.27.27.35:1439."
It seems like hMS is trying at exactly 1 minute intervals to write a record to the MySQL database, and failing.

It looks like that the IMAP connections are just a coincidence as they do not always happen exactly with the error message, though they also seem to have a 1 minute cycle.

I can't see any undelivered incoming mail in the Data folder.

I recognise "[MessageLimit][testmode] [DNSBL][testmode]" as a typical addition by my ASSP front end to the subject line of suspect spam.

I have tried restarting MySQL and hMS services but it makes no difference.

One other thing is that the error messages are being logged in the hMS error log without any CR/LF between individual messages - but that seems to be an old bug. The error message in the main log also seems to suffer from that - The 'TCPIP' text at the end seems to be what should be an independent log line.

Running 5.5.2-B2129

Any ideas how to stop this?

LesD
Senior user
Senior user
Posts: 343
Joined: 2009-01-15 20:22
Location: London, UK.

Re: Error message every minute

Post by LesD » 2015-05-17 22:33

I have found the culprit email in my spam folder
Capture.PNG
The subject line contains some unprintable characters to which MySQL seems to be objecting.

Ho do I get hMS to give up retrying?

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

Re: Error message every minute

Post by jimimaseye » 2015-05-17 22:40

viewtopic.php?f=9&t=27884&p=172886

also if you search UTF on these forums you will see a lot talking about this problem.
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

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

Re: Error message every minute

Post by SorenR » 2015-05-17 23:01

A temporary fix that I use... It catches about 85% as it does not cover all character encodings...

Code: Select all

   Sub OnAcceptMessage(oClient, oMessage)
      Call FixEmojis(oMessage)
   End Sub

   Sub FixEmojis(oMessage)
      Dim strValue, strEmoji, ECFlag, SFlag : SFlag = False
      ECFlag = oMessage.EncodeFields
      oMessage.EncodeFields = False
      Do While (InStr(oMessage.Subject, "=F0=9F=") > 0)
         strEmoji = Mid(oMessage.Subject, InStr(oMessage.Subject, "=F0=9F="), 12)
         strValue = Replace(oMessage.Subject, strEmoji, "?")
         oMessage.Subject = strValue
         SFlag = True
      Loop
      If SFlag Then oMessage.Save
      oMessage.EncodeFields = ECFlag
   End Sub
SørenR.

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

LesD
Senior user
Senior user
Posts: 343
Joined: 2009-01-15 20:22
Location: London, UK.

Re: Error message every minute

Post by LesD » 2015-05-18 16:50

Thanks for the scripts, but they seem to relate to preventing future problems.

My current issue is finding out how to stop this pesky error every minute.

What is actually causing it?

hMS trying to update an index?

Can I delete a something from the MySQL database to stop this.

Also, the March post says:
When using hMailServer older than Version 5.5 AND enabling indexing, one may see occational SQL errors when storing "Subject:" strings.

One solution is to upgrade to latest hMailServer AND use MySQL version 5.5.3 or later.
I'm on hMS 5.5.2 and MySQL looks like it is version 5.6. So should I be suffering from this problem at all? :(

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

Re: Error message every minute

Post by jimimaseye » 2015-05-18 17:11

Did you read this one: viewtopic.php?f=7&t=26860 ? I think you will find an answer in there as to what to do now.
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

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

Re: Error message every minute

Post by SorenR » 2015-05-18 18:42

Info is starring you right in the face...

INSERT INTO hm_message_metadata (metadata_accountid, metadata_folderid, metadata_messageid, metadata_dateutc, metadata_from, metadata_subject, metadata_to, metadata_cc) VALUES (19, 33, 579768

AccountID = 19
FolderID = 33
MessageID = 579768

SELECT accountaddress FROM hm_accounts WHERE accountid = 19;
SELECT messagefilename FROM hm_messages WHERE messageid = 579768;

Now you know the user, the domain and the filename... Go edit the file and change the subject line.
SørenR.

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

LesD
Senior user
Senior user
Posts: 343
Joined: 2009-01-15 20:22
Location: London, UK.

Re: Error message every minute

Post by LesD » 2015-05-18 19:26

Thanks for all the guidance.

It took a while for the penny to drop that the table in question was the index table and hMS was trying to add a record for that purpose.

I stopped the indexing and the errors stopped.

I then realised, that I was actually causing my own problems by not deleting the spam message, which I then did. Still did not help until I realised that I had to actually close Thunderbird for the email to be purged. Did that, turned indexing back on and all is now quite. :)

Upgraded to the latest hMS in case that helps for the future.

I will review the suggested scripts a bit later.

Thanks again.

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

Re: Error message every minute

Post by SorenR » 2015-05-18 19:50

LesD wrote:Thanks for all the guidance.

It took a while for the penny to drop that the table in question was the index table and hMS was trying to add a record for that purpose.

I stopped the indexing and the errors stopped.

I then realised, that I was actually causing my own problems by not deleting the spam message, which I then did. Still did not help until I realised that I had to actually close Thunderbird for the email to be purged. Did that, turned indexing back on and all is now quite. :)

Upgraded to the latest hMS in case that helps for the future.

I will review the suggested scripts a bit later.

Thanks again.
If you change MySQL to use 4 byte UTF (utf8mb4) for the index table, then you don't need the script.
SørenR.

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

LesD
Senior user
Senior user
Posts: 343
Joined: 2009-01-15 20:22
Location: London, UK.

Re: Error message every minute

Post by LesD » 2015-05-18 20:00

-Fired up MySQL Workbench
-Stopped hMS indexing
-Changed collation from utf8-default to utf8mb4-default
- Apllied the change (took no time at all)
- Restarted hMS indexing.

Done!

Thank you again.

LesD
Senior user
Senior user
Posts: 343
Joined: 2009-01-15 20:22
Location: London, UK.

Re: Error message every minute

Post by LesD » 2015-05-18 20:17

I went back to the link provided by jimimaseye and read it and followed the link for the instructions on how to change the MySQL collation - a very clear article.

In answered my nagging doubt as to why the change took no time at all. I expected some form of conversion process. I now know that the change permits future 4-byte values but does not need to change any existing ones.

PS: After the change I went back to check the actual fields in the metadata table. While most were set to 'Table Default' there were 4 that were hard coded to utf8 and so needed changing.

Post Reply