WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Hi Palinka,
That seems a good idea, and I assume one would call disconnect.exe via the Sub OnHelo described, which would presumably be called from onClientConnect.
However, does that not mean that the IP or ehlo domain must be listed somewhere in the system? Either in the Sub or in a database, both requiring maintenance.
Since there are millions of potential Amazon (and other addresses) from which a connection could be made, how does this help?
I have temporarily blocked more than 500 Class B Amazon IPs.
We come back to trying to identify this asynch task.
2680 "smtpd" 900 13 "2019-12-24 09:39:57.366" "18.216.218.204" "sent: 354 ok, send."
task 2681 "debug" 900 "2019-12-24 09:39:57.507" "adding task asynchronoustask to work queue asynchronous task queue"
task 2682 "debug" 5764 "2019-12-24 09:39:57.507" "executing task asynchronoustask in work queue asynchronous task queue"
That seems a good idea, and I assume one would call disconnect.exe via the Sub OnHelo described, which would presumably be called from onClientConnect.
However, does that not mean that the IP or ehlo domain must be listed somewhere in the system? Either in the Sub or in a database, both requiring maintenance.
Since there are millions of potential Amazon (and other addresses) from which a connection could be made, how does this help?
I have temporarily blocked more than 500 Class B Amazon IPs.
We come back to trying to identify this asynch task.
2680 "smtpd" 900 13 "2019-12-24 09:39:57.366" "18.216.218.204" "sent: 354 ok, send."
task 2681 "debug" 900 "2019-12-24 09:39:57.507" "adding task asynchronoustask to work queue asynchronous task queue"
task 2682 "debug" 5764 "2019-12-24 09:39:57.507" "executing task asynchronoustask in work queue asynchronous task queue"
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Ok Dravion, I'll give that a try and Happy Holidays to all.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Sounds like you're on your way to a list already.

Everything needs maintenance. Even my cigarette lighter.
I block lots of things for lots of reasons. They're just filters in OnHELO and OnAcceptMessage. I focus mainly on rejecting the connection. For example, if an IP is listed in spamhaus, I reject with a message, call disconnect.exe, call autoban and firewall ban the IP. I do that for positive results on all my filters in OnHELO.
I generally don't block Amazonses because it's shared hosting with a mix of spam and ham. But UCE Protect is a good list for blocking Amazon since they focus on spam traps. Some legit mail may get blocked, but most/all abused Amazonses IPs get listed.
Do you know what was being sent from these Amazonses connections? Is it spam?
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
HI Dravion
So disabling the scripts ran without incident for 16 hours. I then checked the script, tested the syntax and enabled it. That ran for 12 hours without incident but then spiked to 100%. Unfortunately I did not have the perfmon running.
I restarted with script and perfmon and one of the original spam senders hit me within the hour.
Here is the log:
2712 "debug" 1292 "2019-12-26 12:47:31.382" "creating session 65"
2713 "tcpip" 1292 "2019-12-26 12:47:31.397" "tcp - 78.47.128.147 connected to 104.217.253.24:25."
2714 "debug" 1292 "2019-12-26 12:47:31.397" "tcp connection started for session 63"
2715 "smtpd" 1292 63 "2019-12-26 12:47:31.397" "78.47.128.147" "sent: 220 pci here"
2716 "smtpd" 3484 63 "2019-12-26 12:47:31.522" "78.47.128.147" "received: ehlo comparioquotes.co.uk"
2717 "smtpd" 3484 63 "2019-12-26 12:47:31.522" "78.47.128.147" "sent: 250-mail.propertyclubinternational.com[nl]250-size 20480000[nl]250-auth login[nl]250 help"
2718 "smtpd" 4460 63 "2019-12-26 12:47:31.647" "78.47.128.147" "received: mail from:|no-reply@comparioquotes.co.uk|"
match: 2719 "tcpip" 4460 "2019-12-26 12:47:31.663" "dns lookup: 147.128.47.78.zen.spamhaus.org, 0 addresses found: (none), match: false"
match: 2720 "tcpip" 4460 "2019-12-26 12:47:31.694" "dns lookup: 147.128.47.78.bl.spamcop.net, 0 addresses found: (none), match: false"
2721 "debug" 4460 "2019-12-26 12:47:31.694" "spam test: spamtestdnsblacklists, score: 0"
2722 "debug" 4460 "2019-12-26 12:47:31.772" "spam test: spamtesthelohost, score: 0"
2723 "debug" 4460 "2019-12-26 12:47:31.819" "spam test: spamtestmxrecords, score: 0"
2724 "debug" 4460 "2019-12-26 12:47:31.882" "spam test: spamtestspf, score: 0"
2725 "debug" 4460 "2019-12-26 12:47:31.882" "total spam score: 0"
2726 "smtpd" 4460 63 "2019-12-26 12:47:31.882" "78.47.128.147" "sent: 250 ok"
2727 "smtpd" 1292 63 "2019-12-26 12:47:32.007" "78.47.128.147" "received: rcpt to:|sales@slb.co.uk|"
2728 "debug" 1292 "2019-12-26 12:47:32.007" "spf passed, skipping greylisting."
2729 "smtpd" 1292 63 "2019-12-26 12:47:32.022" "78.47.128.147" "sent: 250 ok"
2730 "smtpd" 3484 63 "2019-12-26 12:47:32.147" "78.47.128.147" "received: data"
2731 "smtpd" 3484 63 "2019-12-26 12:47:32.147" "78.47.128.147" "sent: 354 ok, send."
task 2732 "debug" 4464 "2019-12-26 12:47:32.522" "adding task asynchronoustask to work queue asynchronous task queue"
task 2733 "debug" 2420 "2019-12-26 12:47:32.522" "executing task asynchronoustask in work queue asynchronous task queue"
2734 "debug" 2420 "2019-12-26 12:47:32.522" "total spam score: 0"
2735 "debug" 2420 "2019-12-26 12:47:32.522" "executing event onacceptmessage"
2736 "debug" 1292 "2019-12-26 12:47:56.903" "creating session 66"
2737 "tcpip" 1292 "2019-12-26 12:47:56.903" "tcp - 45.82.153.142 connected to 104.217.253.203:25."
blocked 2738 "debug" 1292 "2019-12-26 12:47:56.903" "client connection from 45.82.153.142 was not accepted. blocked either by ip range or by connection limit."
The actual msg was in {93B95D4B-2FDA-4251-BF65-45D0F52DBF41}.eml and is attached in the zip in .txt format and might contain something that my script is not handling properly. It is still in the data folder created at 12:47:32.
I can see that the script is causing problems, as a subsequent (also spam) was handled like this as is normal, completes the onacceptmessage and applys rules.
3157 "smtpd" 1292 84 "2019-12-26 12:58:45.090" "142.11.245.63" "sent: 220 pci here"
3158 "smtpd" 4464 84 "2019-12-26 12:58:45.215" "142.11.245.63" "received: ehlo 00482039.cbuniversity.bid"
3159 "smtpd" 4464 84 "2019-12-26 12:58:45.215" "142.11.245.63" "sent: 250-mail.propertyclubinternational.com[nl]250-size 20480000[nl]250-auth login[nl]250 help"
3160 "smtpd" 4464 84 "2019-12-26 12:58:45.325" "142.11.245.63" "received: mail from:|youragingprostate@cbuniversity.bid| size=5299"
match: 3161 "tcpip" 4464 "2019-12-26 12:58:45.356" "dns lookup: 63.245.11.142.zen.spamhaus.org, 0 addresses found: (none), match: false"
match: 3162 "tcpip" 4464 "2019-12-26 12:58:45.387" "dns lookup: 63.245.11.142.bl.spamcop.net, 0 addresses found: (none), match: false"
3163 "debug" 4464 "2019-12-26 12:58:45.387" "spam test: spamtestdnsblacklists, score: 0"
3164 "debug" 4464 "2019-12-26 12:58:45.418" "spam test: spamtesthelohost, score: 2"
3165 "debug" 4464 "2019-12-26 12:58:45.418" "spam test: spamtestmxrecords, score: 0"
3166 "debug" 4464 "2019-12-26 12:58:45.434" "spam test: spamtestspf, score: 0"
3167 "debug" 4464 "2019-12-26 12:58:45.434" "total spam score: 2"
3168 "smtpd" 4464 84 "2019-12-26 12:58:45.434" "142.11.245.63" "sent: 250 ok"
3169 "smtpd" 3484 84 "2019-12-26 12:58:45.559" "142.11.245.63" "received: rcpt to:|nigel@slb.co.uk|"
3170 "tcpip" 3484 "2019-12-26 12:58:45.575" "dns mx lookup: cbuniversity.bid"
were 3171 "tcpip" 3484 "2019-12-26 12:58:45.590" "dns - mx result: 1 ip addresses were found."
skipping 3172 "debug" 3484 "2019-12-26 12:58:45.590" "mail coming from a or mx record. skipping grey listing."
3173 "smtpd" 3484 84 "2019-12-26 12:58:45.590" "142.11.245.63" "sent: 250 ok"
3174 "smtpd" 1292 84 "2019-12-26 12:58:45.715" "142.11.245.63" "received: data"
3175 "smtpd" 1292 84 "2019-12-26 12:58:45.715" "142.11.245.63" "sent: 354 ok, send."
task 3176 "debug" 3484 "2019-12-26 12:58:45.840" "adding task asynchronoustask to work queue asynchronous task queue"
task 3177 "debug" 3344 "2019-12-26 12:58:45.840" "executing task asynchronoustask in work queue asynchronous task queue"
3178 "debug" 3344 "2019-12-26 12:58:45.840" "total spam score: 0"
3179 "debug" 3344 "2019-12-26 12:58:45.840" "executing event onacceptmessage"
3180 "debug" 3344 "2019-12-26 12:58:45.856" "event completed"
3181 "debug" 3344 "2019-12-26 12:58:45.856" "saving message: {f11b8289-42e3-4335-91dc-cc9eb7e6b55c}.eml"
3182 "debug" 3344 "2019-12-26 12:58:45.903" "requesting smtpdeliverymanager to start message delivery"
3183 "smtpd" 3344 84 "2019-12-26 12:58:45.903" "142.11.245.63" "sent: 250 queued (0.120 seconds)"
delivery 3184 "debug" 4272 "2019-12-26 12:58:45.919" "adding task deliverytask to work queue smtp delivery queue"
delivery 3185 "debug" 4264 "2019-12-26 12:58:45.919" "executing task deliverytask in work queue smtp delivery queue"
3186 "debug" 4264 "2019-12-26 12:58:45.919" "delivering message..."
youragingprostate@cbuniversity.bid 3187 "application" 4264 "2019-12-26 12:58:45.919" "smtpdeliverer - message 671999: delivering message from youragingprostate@cbuniversity.bid to nigel@slb.co.uk. file: c:\program files (x86)\hmailserver\data\{f11b8289-42e3-4335-91dc-cc9eb7e6b55c}.eml"
XXXYYY"application" 4264 "2019-12-26 12:58:45.919" "smtpdeliverer - message 671999: delivering message from youragingprostate@cbuniversity.bid to nigel@slb.co.uk. file: c:\program files (x86)\hmailserver\data\{f11b8289-42e3-4335-91dc-cc9eb7e6b55c}.eml"
3188 "debug" 4264 "2019-12-26 12:58:45.919" "applying rules"
XXXYYY"debug" 4264 "2019-12-26 12:58:45.919" "applying rules"
So here is my script and it clearly has a problem despite passing the syntax test. I'd really appreciate an opinion on it as all it should do is insert a database log record and that works with all but the offending spammers who are mainly from Amazon.
So disabling the scripts ran without incident for 16 hours. I then checked the script, tested the syntax and enabled it. That ran for 12 hours without incident but then spiked to 100%. Unfortunately I did not have the perfmon running.
I restarted with script and perfmon and one of the original spam senders hit me within the hour.
Here is the log:
2712 "debug" 1292 "2019-12-26 12:47:31.382" "creating session 65"
2713 "tcpip" 1292 "2019-12-26 12:47:31.397" "tcp - 78.47.128.147 connected to 104.217.253.24:25."
2714 "debug" 1292 "2019-12-26 12:47:31.397" "tcp connection started for session 63"
2715 "smtpd" 1292 63 "2019-12-26 12:47:31.397" "78.47.128.147" "sent: 220 pci here"
2716 "smtpd" 3484 63 "2019-12-26 12:47:31.522" "78.47.128.147" "received: ehlo comparioquotes.co.uk"
2717 "smtpd" 3484 63 "2019-12-26 12:47:31.522" "78.47.128.147" "sent: 250-mail.propertyclubinternational.com[nl]250-size 20480000[nl]250-auth login[nl]250 help"
2718 "smtpd" 4460 63 "2019-12-26 12:47:31.647" "78.47.128.147" "received: mail from:|no-reply@comparioquotes.co.uk|"
match: 2719 "tcpip" 4460 "2019-12-26 12:47:31.663" "dns lookup: 147.128.47.78.zen.spamhaus.org, 0 addresses found: (none), match: false"
match: 2720 "tcpip" 4460 "2019-12-26 12:47:31.694" "dns lookup: 147.128.47.78.bl.spamcop.net, 0 addresses found: (none), match: false"
2721 "debug" 4460 "2019-12-26 12:47:31.694" "spam test: spamtestdnsblacklists, score: 0"
2722 "debug" 4460 "2019-12-26 12:47:31.772" "spam test: spamtesthelohost, score: 0"
2723 "debug" 4460 "2019-12-26 12:47:31.819" "spam test: spamtestmxrecords, score: 0"
2724 "debug" 4460 "2019-12-26 12:47:31.882" "spam test: spamtestspf, score: 0"
2725 "debug" 4460 "2019-12-26 12:47:31.882" "total spam score: 0"
2726 "smtpd" 4460 63 "2019-12-26 12:47:31.882" "78.47.128.147" "sent: 250 ok"
2727 "smtpd" 1292 63 "2019-12-26 12:47:32.007" "78.47.128.147" "received: rcpt to:|sales@slb.co.uk|"
2728 "debug" 1292 "2019-12-26 12:47:32.007" "spf passed, skipping greylisting."
2729 "smtpd" 1292 63 "2019-12-26 12:47:32.022" "78.47.128.147" "sent: 250 ok"
2730 "smtpd" 3484 63 "2019-12-26 12:47:32.147" "78.47.128.147" "received: data"
2731 "smtpd" 3484 63 "2019-12-26 12:47:32.147" "78.47.128.147" "sent: 354 ok, send."
task 2732 "debug" 4464 "2019-12-26 12:47:32.522" "adding task asynchronoustask to work queue asynchronous task queue"
task 2733 "debug" 2420 "2019-12-26 12:47:32.522" "executing task asynchronoustask in work queue asynchronous task queue"
2734 "debug" 2420 "2019-12-26 12:47:32.522" "total spam score: 0"
2735 "debug" 2420 "2019-12-26 12:47:32.522" "executing event onacceptmessage"
2736 "debug" 1292 "2019-12-26 12:47:56.903" "creating session 66"
2737 "tcpip" 1292 "2019-12-26 12:47:56.903" "tcp - 45.82.153.142 connected to 104.217.253.203:25."
blocked 2738 "debug" 1292 "2019-12-26 12:47:56.903" "client connection from 45.82.153.142 was not accepted. blocked either by ip range or by connection limit."
The actual msg was in {93B95D4B-2FDA-4251-BF65-45D0F52DBF41}.eml and is attached in the zip in .txt format and might contain something that my script is not handling properly. It is still in the data folder created at 12:47:32.
I can see that the script is causing problems, as a subsequent (also spam) was handled like this as is normal, completes the onacceptmessage and applys rules.
3157 "smtpd" 1292 84 "2019-12-26 12:58:45.090" "142.11.245.63" "sent: 220 pci here"
3158 "smtpd" 4464 84 "2019-12-26 12:58:45.215" "142.11.245.63" "received: ehlo 00482039.cbuniversity.bid"
3159 "smtpd" 4464 84 "2019-12-26 12:58:45.215" "142.11.245.63" "sent: 250-mail.propertyclubinternational.com[nl]250-size 20480000[nl]250-auth login[nl]250 help"
3160 "smtpd" 4464 84 "2019-12-26 12:58:45.325" "142.11.245.63" "received: mail from:|youragingprostate@cbuniversity.bid| size=5299"
match: 3161 "tcpip" 4464 "2019-12-26 12:58:45.356" "dns lookup: 63.245.11.142.zen.spamhaus.org, 0 addresses found: (none), match: false"
match: 3162 "tcpip" 4464 "2019-12-26 12:58:45.387" "dns lookup: 63.245.11.142.bl.spamcop.net, 0 addresses found: (none), match: false"
3163 "debug" 4464 "2019-12-26 12:58:45.387" "spam test: spamtestdnsblacklists, score: 0"
3164 "debug" 4464 "2019-12-26 12:58:45.418" "spam test: spamtesthelohost, score: 2"
3165 "debug" 4464 "2019-12-26 12:58:45.418" "spam test: spamtestmxrecords, score: 0"
3166 "debug" 4464 "2019-12-26 12:58:45.434" "spam test: spamtestspf, score: 0"
3167 "debug" 4464 "2019-12-26 12:58:45.434" "total spam score: 2"
3168 "smtpd" 4464 84 "2019-12-26 12:58:45.434" "142.11.245.63" "sent: 250 ok"
3169 "smtpd" 3484 84 "2019-12-26 12:58:45.559" "142.11.245.63" "received: rcpt to:|nigel@slb.co.uk|"
3170 "tcpip" 3484 "2019-12-26 12:58:45.575" "dns mx lookup: cbuniversity.bid"
were 3171 "tcpip" 3484 "2019-12-26 12:58:45.590" "dns - mx result: 1 ip addresses were found."
skipping 3172 "debug" 3484 "2019-12-26 12:58:45.590" "mail coming from a or mx record. skipping grey listing."
3173 "smtpd" 3484 84 "2019-12-26 12:58:45.590" "142.11.245.63" "sent: 250 ok"
3174 "smtpd" 1292 84 "2019-12-26 12:58:45.715" "142.11.245.63" "received: data"
3175 "smtpd" 1292 84 "2019-12-26 12:58:45.715" "142.11.245.63" "sent: 354 ok, send."
task 3176 "debug" 3484 "2019-12-26 12:58:45.840" "adding task asynchronoustask to work queue asynchronous task queue"
task 3177 "debug" 3344 "2019-12-26 12:58:45.840" "executing task asynchronoustask in work queue asynchronous task queue"
3178 "debug" 3344 "2019-12-26 12:58:45.840" "total spam score: 0"
3179 "debug" 3344 "2019-12-26 12:58:45.840" "executing event onacceptmessage"
3180 "debug" 3344 "2019-12-26 12:58:45.856" "event completed"
3181 "debug" 3344 "2019-12-26 12:58:45.856" "saving message: {f11b8289-42e3-4335-91dc-cc9eb7e6b55c}.eml"
3182 "debug" 3344 "2019-12-26 12:58:45.903" "requesting smtpdeliverymanager to start message delivery"
3183 "smtpd" 3344 84 "2019-12-26 12:58:45.903" "142.11.245.63" "sent: 250 queued (0.120 seconds)"
delivery 3184 "debug" 4272 "2019-12-26 12:58:45.919" "adding task deliverytask to work queue smtp delivery queue"
delivery 3185 "debug" 4264 "2019-12-26 12:58:45.919" "executing task deliverytask in work queue smtp delivery queue"
3186 "debug" 4264 "2019-12-26 12:58:45.919" "delivering message..."
youragingprostate@cbuniversity.bid 3187 "application" 4264 "2019-12-26 12:58:45.919" "smtpdeliverer - message 671999: delivering message from youragingprostate@cbuniversity.bid to nigel@slb.co.uk. file: c:\program files (x86)\hmailserver\data\{f11b8289-42e3-4335-91dc-cc9eb7e6b55c}.eml"
XXXYYY"application" 4264 "2019-12-26 12:58:45.919" "smtpdeliverer - message 671999: delivering message from youragingprostate@cbuniversity.bid to nigel@slb.co.uk. file: c:\program files (x86)\hmailserver\data\{f11b8289-42e3-4335-91dc-cc9eb7e6b55c}.eml"
3188 "debug" 4264 "2019-12-26 12:58:45.919" "applying rules"
XXXYYY"debug" 4264 "2019-12-26 12:58:45.919" "applying rules"
So here is my script and it clearly has a problem despite passing the syntax test. I'd really appreciate an opinion on it as all it should do is insert a database log record and that works with all but the offending spammers who are mainly from Amazon.
Code: Select all
Sub OnAcceptMessage(oClient, oMessage)
If oMessage.FileName>"" Then CreateDeliveryLogEntry oMessage,oClient.IPAddress
End Sub
Function CreateDeliveryLogEntry(oMessage,sIP)
'On Error Resume Next
Dim sFrom, sSubject, sBody
sFrom = Escape(Mid(oMessage.From, 1, 255))
sSubject = Escape(Mid(oMessage.Subject, 1, 255))
sBody = Escape(Mid(oMessage.Body, 1, 250000))
Dim sMsgID
sMsgID = Trim(oMessage.FileName)
s = InStr(sMsgID,"{") + 1
e = InStr(sMsgID,"}") - s
sMsgID = Mid(sMsgID,s,e)
Dim obRecipients
Set obRecipients = oMessage.Recipients
Dim iRecipientCount
iRecipientCount = obRecipients.Count
Dim i
Dim sRecipients
For i = 0 to iRecipientCount -1
sRecipients = sRecipients &" " &obrecipients.Item(i).Address
Next
sRecipients = Escape(Mid(sRecipients,1,255))
Dim sSQL
sSQL = "INSERT INTO hm_deliverylog (Sender, Subject, Body, Recipients, MsgID, IP, Filename) " _
&" VALUES ('" &sFrom &"','" &sSubject &"','" &sBody &"','" &sRecipients &"','" &sMsgID &"','" &sIP &"','" &sMsgID & "')"
Set vMail = CreateObject("ADODB.Command")
With vMail
.ActiveConnection = "dsn=hMail"
.CommandText = sSQL
.CommandType = 1
.CommandTimeout = 0
.Prepared = true
.Execute()
End With
Set vMail = Nothing
End Function
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Its in general a bad idea to solve your spam Problem with VB-Scripts because of the spikes it produces. Fightibg spam
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Its in general a bad idea to solve your spam Problem with VB-Scripts because of the spikes it produces. Fighting spam is even on Linux with plenty of tools and a lot of experience a neverending story and on Windows its even harder. Some Windows Admins using a paid Cloud mitigation service, others are using Spam Hardware Appliances in front of it or specialized Software Firewall Product. Google with its GSuite for Business has a very good A.I based spam detection System which can redirect cleared mails to a local Emailserver.
Try to tweak Spamassasin as much as possible, maybe you can better filter and delete Spam at that stage instead inside hMail with VBScript.
Try to tweak Spamassasin as much as possible, maybe you can better filter and delete Spam at that stage instead inside hMail with VBScript.
- jimimaseye
- Moderator
- Posts: 8859
- Joined: 2011-09-08 17:48
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Back to the problem....
Silly question: have you tried just not running the logging function in your script (But leaving scripts enabled)? Ptr stated deciding to determine the cause: for example, remove the "sBody = Escape(Mid(oMessage.Body, 1, 250000))" line or changed the value of 'CommandTimeout = 0' and see if it makes a difference.
[Entered by mobile. Excuse my spelling.]
Silly question: have you tried just not running the logging function in your script (But leaving scripts enabled)? Ptr stated deciding to determine the cause: for example, remove the "sBody = Escape(Mid(oMessage.Body, 1, 250000))" line or changed the value of 'CommandTimeout = 0' and see if it makes a difference.
[Entered by mobile. Excuse my spelling.]
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
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Here is a way to do the delivery log without ADODB
viewtopic.php?f=20&t=13890
viewtopic.php?f=20&t=13890
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation
https://www.hmailserver.com/documentation
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Happy New Year. Latest report and to answer your posts.
jimimaseye: Yes, I have tried a number of script options. Interestingly, using an inline Replace instead of the Escape function worked better.
mattg: My deliverylog function is based on the one Martin posted years ago, and was running without problems until the Nov Update. I don 't have huge volumes and if I remember correctly, using the hMailServer.Application had some problems when I first used it. I am more familiar with ODBC anyway.
dravion: I was not using scripts for spam - only rules until this happened. I suspended SpamAssassin to try and resolve this and may reinstate.
My theory is that the 2 senders most causing the unknown asynch task to hang and spike have something in the Body that causes it. If that asynch task is my script, then it is surprising that a script error is not recorded. Inserting a deliverylog record without the Body for those senders appears to eliminate the spike.
I posted an example of the message in the zip on 26 Dec and repeat here.
In addition, since this only started on the Windows Update, I think there might have been something in there that changed the way that subs and functions are called in VBScript, specifically the use of parentheses when calling seems to have changed as I had to remove them to avoid an error.
My latest script is below and (fingers crossed) has not spiked yet after 48 hours. However, in this case, the script does differentiate for these 2 senders and that is not ideal, so if anyone can determine what in the Body might be causing the original problem, I would be very grateful.
I'd also like to make some suggestions for features.
1) Include the criteriaid in the sErrorMessage as well as the ruleid.
2) Identify the asynch task when it commences.
jimimaseye: Yes, I have tried a number of script options. Interestingly, using an inline Replace instead of the Escape function worked better.
mattg: My deliverylog function is based on the one Martin posted years ago, and was running without problems until the Nov Update. I don 't have huge volumes and if I remember correctly, using the hMailServer.Application had some problems when I first used it. I am more familiar with ODBC anyway.
dravion: I was not using scripts for spam - only rules until this happened. I suspended SpamAssassin to try and resolve this and may reinstate.
My theory is that the 2 senders most causing the unknown asynch task to hang and spike have something in the Body that causes it. If that asynch task is my script, then it is surprising that a script error is not recorded. Inserting a deliverylog record without the Body for those senders appears to eliminate the spike.
I posted an example of the message in the zip on 26 Dec and repeat here.
In addition, since this only started on the Windows Update, I think there might have been something in there that changed the way that subs and functions are called in VBScript, specifically the use of parentheses when calling seems to have changed as I had to remove them to avoid an error.
My latest script is below and (fingers crossed) has not spiked yet after 48 hours. However, in this case, the script does differentiate for these 2 senders and that is not ideal, so if anyone can determine what in the Body might be causing the original problem, I would be very grateful.
I'd also like to make some suggestions for features.
1) Include the criteriaid in the sErrorMessage as well as the ruleid.
2) Identify the asynch task when it commences.
Code: Select all
Sub OnAcceptMessage(oClient, oMessage)
CreateDeliveryLogEntry oMessage, oClient.IPAddress
End Sub
Function CreateDeliveryLogEntry(oMessage,sIP)
'On Error Resume Next
Dim sFrom, sSubject, sBody
sFrom = Mid(oMessage.From, 1, 255)
sSubject = Mid(oMessage.Subject, 1, 255)
sSubject = Replace(sSubject, "'", "''")
sSubject = Replace(sSubject, "\", "\\")
sBody = Mid(oMessage.Body, 1, 250000)
sBody = Replace(sBody, "'", "''")
sBody = Replace(sBody, "\", "\\")
Dim sMsgID
sMsgID = Trim(oMessage.FileName)
s = InStr(sMsgID,"{") + 1
e = InStr(sMsgID,"}") - s
sMsgID = Mid(sMsgID,s,e)
Dim obRecipients
Set obRecipients = oMessage.Recipients
Dim iRecipientCount
iRecipientCount = obRecipients.Count
Dim i
Dim sRecipients
For i = 0 to iRecipientCount -1
sRecipients = sRecipients &obrecipients.Item(i).Address &" "
Next
sRecipients = Trim(Mid(sRecipients,1,255))
Dim sSQL
sSQL = "INSERT INTO hm_deliverylog (Sender, Subject, Body, Recipients, MsgID, IP, Filename) " _
&" VALUES ('" &sFrom &"','" &sSubject &"','" &sBody &"','" &sRecipients &"','" &sMsgID &"','" &sIP &"','" &sMsgID & "')"
If InStr(oMessage.From,"compario")>0 Or InStr(oMessage.From,"millan.pgw.jp")>0 Then
sSQL = "INSERT INTO hm_deliverylog (Sender, Subject, Recipients, MsgID, IP, Filename) " _
&" VALUES ('"&sFrom&"','ERR'"&sSubject&"','"&sRecipients &"','"&sMsgID &"','" &sIP &"','" &sMsgID & "')"
End If
Set vMail = CreateObject("ADODB.Command")
With vMail
.ActiveConnection = "dsn=hMail"
.CommandText = sSQL
.CommandType = 1
.CommandTimeout = 0
.Prepared = true
.Execute()
End With
Set vMail = Nothing
End Function
- Attachments
-
- {93B95D4B-2FDA-4251-BF65-45D0F52DBF41}.zip
- (8.48 KiB) Downloaded 129 times
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Well, I spoke too soon.
Another sender spiked the cpu with a relatively simple body, then followed by "comparios" every 20 minutes also spiking.
In each case the .eml is created in the data folder, the OnAcceptMessage starts and does not complete. The .eml is left in the folder.
I am running again but with no call in the OnAcceptMessage for now, but cannot understand why the deliverylog script works for most msgs and not for others.
And again, why does hmail not log a script error?
Here is the first msg
Received: from mi-servidor-213-162-214-037.nodenet.net (mi-servidor-213-162-214-037.nodenet.net [213.162.214.37])
by mail.propertyclubinternational.com with ESMTP
; Fri, 3 Jan 2020 09:00:02 +0000
Received: from localhost (localhost [127.0.0.1])
by mi-servidor-213-162-214-037.nodenet.net (Postfix) with ESMTP id C4238349657
for <nigel@selnet.co.uk>; Fri, 3 Jan 2020 09:17:21 +0100 (CET)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=betsuites.com; h=
content-language:content-transfer-encoding:content-type
:content-type:mime-version:user-agent
date:message-id
:subject:subject:from:from; s=default; t=1578039441; x=
1579853842; bh=bOZl5VsftnU7wqnNCXC+EmzNSsdaGEGWXwluTQSZpEQ=; b=B
SLkWx//Fioff3ooIKJ2O0LwO5x0gJQLvnSODhE3t99LMDHq7kChOzPp93yTtzf0R
dKLUqhxc53F7j7KZKJy+KBAFTQlM392ztm25+P/IYn4DpuIqjVwDXknJ7MR+j1yV
O6z0/u/qaCtJ9UCUYyq2PzpRmtOuPeOFY4CG6yIL3WtXccES4aCoqRBX/VNmr59b
nt+SAsancrZp2PyKq6X2LcW4GchL1GMu+WKFLhTC9WB3rD2WOibqtlUozOleXoc5
+P4QU3uMxSjfou50Ub4wp1+1zN4xlASM1Ydo00J+50atrDlWPmR5zvpkCcXYq5Ch
9zJckU1SUVnqd8iN/rrnQ==
X-Virus-Scanned: Debian amavisd-new at mi-servidor-213-162-214-037.nodenet.net
Received: from mi-servidor-213-162-214-037.nodenet.net ([127.0.0.1])
by localhost (mi-servidor-213-162-214-037.nodenet.net [127.0.0.1]) (amavisd-new, port 10026)
with ESMTP id ma4utqc-dR7X for <nigel@selnet.co.uk>;
Fri, 3 Jan 2020 09:17:21 +0100 (CET)
Received: from betsuites.com (unknown [14.169.254.235])
(Authenticated sender: soporte@betsuites.com)
by mi-servidor-213-162-214-037.nodenet.net (Postfix) with ESMTPA id D2ADC162871
for <nigel@selnet.co.uk>; Fri, 3 Jan 2020 09:17:18 +0100 (CET)
To: "Nigel" <nigel@selnet.co.uk>
From: Vladimir Dejanovski <soporte@betsuites.com>
Subject: =?UTF-8?Q?Vladimir_Dejanovski_=F0=9F=93=88?=
Message-ID: <219741c1-e343-4f7f-b6da-a07634be5656@betsuites.com>
Date: Thu, 2 Jan 2020 22:21:35 -1000
User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:60.0) Gecko/20100101
Thunderbird/60.9.1
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8; format=flowed
Content-Transfer-Encoding: 7bit
Content-Language: en-US
Yo
https ://s peedribener1 971.blogs pot.s e/ [link obfuscated. Mod.]
Truly
Baby video messages 'amazing' for new parents
Victoria's triplets spent nine weeks in Southampton's neonatal unit and staff sent updates via a new app.
This is the best chart as we kick off 2020, technical analyst says
As the S&P 500 comes off one of its best years in decades, Miller Tabak's Matt Maley said this chart reveals the top pick to begin 2020.
Hu Jintao Fast Facts
Check out CNN's Hu Jintao Fast Facts for a look at the life of the former president of the People's Republic of China.
Passenger dies on board EasyJet flight to Newcastle
The airline said medical assistance was provided after someone was taken ill en route from Alicante.
Hospital execs say they are getting flooded with requests for your health data
Technology companies are building algorithms that are fueled by vast stores of patient health information.
Tennis landmark: $4.725 million prize
The 2019 WTA Finals in Shenzhen offers the largest purse in tennis history with $14 million up for grabs.
Another sender spiked the cpu with a relatively simple body, then followed by "comparios" every 20 minutes also spiking.
In each case the .eml is created in the data folder, the OnAcceptMessage starts and does not complete. The .eml is left in the folder.
I am running again but with no call in the OnAcceptMessage for now, but cannot understand why the deliverylog script works for most msgs and not for others.
And again, why does hmail not log a script error?
Here is the first msg
Received: from mi-servidor-213-162-214-037.nodenet.net (mi-servidor-213-162-214-037.nodenet.net [213.162.214.37])
by mail.propertyclubinternational.com with ESMTP
; Fri, 3 Jan 2020 09:00:02 +0000
Received: from localhost (localhost [127.0.0.1])
by mi-servidor-213-162-214-037.nodenet.net (Postfix) with ESMTP id C4238349657
for <nigel@selnet.co.uk>; Fri, 3 Jan 2020 09:17:21 +0100 (CET)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=betsuites.com; h=
content-language:content-transfer-encoding:content-type
:content-type:mime-version:user-agent

:subject:subject:from:from; s=default; t=1578039441; x=
1579853842; bh=bOZl5VsftnU7wqnNCXC+EmzNSsdaGEGWXwluTQSZpEQ=; b=B
SLkWx//Fioff3ooIKJ2O0LwO5x0gJQLvnSODhE3t99LMDHq7kChOzPp93yTtzf0R
dKLUqhxc53F7j7KZKJy+KBAFTQlM392ztm25+P/IYn4DpuIqjVwDXknJ7MR+j1yV
O6z0/u/qaCtJ9UCUYyq2PzpRmtOuPeOFY4CG6yIL3WtXccES4aCoqRBX/VNmr59b
nt+SAsancrZp2PyKq6X2LcW4GchL1GMu+WKFLhTC9WB3rD2WOibqtlUozOleXoc5
+P4QU3uMxSjfou50Ub4wp1+1zN4xlASM1Ydo00J+50atrDlWPmR5zvpkCcXYq5Ch
9zJckU1SUVnqd8iN/rrnQ==
X-Virus-Scanned: Debian amavisd-new at mi-servidor-213-162-214-037.nodenet.net
Received: from mi-servidor-213-162-214-037.nodenet.net ([127.0.0.1])
by localhost (mi-servidor-213-162-214-037.nodenet.net [127.0.0.1]) (amavisd-new, port 10026)
with ESMTP id ma4utqc-dR7X for <nigel@selnet.co.uk>;
Fri, 3 Jan 2020 09:17:21 +0100 (CET)
Received: from betsuites.com (unknown [14.169.254.235])
(Authenticated sender: soporte@betsuites.com)
by mi-servidor-213-162-214-037.nodenet.net (Postfix) with ESMTPA id D2ADC162871
for <nigel@selnet.co.uk>; Fri, 3 Jan 2020 09:17:18 +0100 (CET)
To: "Nigel" <nigel@selnet.co.uk>
From: Vladimir Dejanovski <soporte@betsuites.com>
Subject: =?UTF-8?Q?Vladimir_Dejanovski_=F0=9F=93=88?=
Message-ID: <219741c1-e343-4f7f-b6da-a07634be5656@betsuites.com>
Date: Thu, 2 Jan 2020 22:21:35 -1000
User-Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:60.0) Gecko/20100101
Thunderbird/60.9.1
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8; format=flowed
Content-Transfer-Encoding: 7bit
Content-Language: en-US
Yo
https ://s peedribener1 971.blogs pot.s e/ [link obfuscated. Mod.]
Truly
Baby video messages 'amazing' for new parents
Victoria's triplets spent nine weeks in Southampton's neonatal unit and staff sent updates via a new app.
This is the best chart as we kick off 2020, technical analyst says
As the S&P 500 comes off one of its best years in decades, Miller Tabak's Matt Maley said this chart reveals the top pick to begin 2020.
Hu Jintao Fast Facts
Check out CNN's Hu Jintao Fast Facts for a look at the life of the former president of the People's Republic of China.
Passenger dies on board EasyJet flight to Newcastle
The airline said medical assistance was provided after someone was taken ill en route from Alicante.
Hospital execs say they are getting flooded with requests for your health data
Technology companies are building algorithms that are fueled by vast stores of patient health information.
Tennis landmark: $4.725 million prize
The 2019 WTA Finals in Shenzhen offers the largest purse in tennis history with $14 million up for grabs.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
The message appears to be unprocessed by hmailserver. Is any "Received:" header by your hmailserver? Or is it left out as it appears to me?
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
On that msg it shows " Received: from betsuites.com (unknown [14.169.254.235]) " which is presumably added by hmailserver before it saves the .eml to the data folder.
But no further processing seems to take place and the .eml remains in the data folder, from where it would normally be deleted when either delivered or rejected.
That said, I revised my script a couple of days ago and so far all well, but there have been no further attempts from the several repetitive spammers like that one, that seem to cause the spikes, so I cannot tell if that has cured the problem yet.
But no further processing seems to take place and the .eml remains in the data folder, from where it would normally be deleted when either delivered or rejected.
That said, I revised my script a couple of days ago and so far all well, but there have been no further attempts from the several repetitive spammers like that one, that seem to cause the spikes, so I cannot tell if that has cured the problem yet.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
The full received by header:
Received: from betsuites.com (unknown [14.169.254.235])
(Authenticated sender: soporte@betsuites.com)
by mi-servidor-213-162-214-037.nodenet.net (Postfix) with ESMTPA id D2ADC162871
for <nigel@selnet.co.uk>; Fri, 3 Jan 2020 09:17:18 +0100 (CET)
That is not an hmailserver header.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
That doesn't surprise me, as this msg, like previous, was saved in data, and then spiked hmailserver, presumably before any further processing was done.
There are no X-hMailServer entries in it at this stage.
Not sure where you're going with this, Palinka.
There are no X-hMailServer entries in it at this stage.
Not sure where you're going with this, Palinka.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Me neither.

However, it may be helpful to know that hmail simply stopped processing the message at some point. The lack of hmail headers may indicate to someone more experienced than me at what point after receiving the message it fails. Then you can look for clues there.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
I still think is related to the ADODB connection
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation
https://www.hmailserver.com/documentation
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
I have changed the script that creates the delivery log not to use ADODB, although if the msg is rejected by a rule, my script updates the log record using ADODB and that part is working fine.
However, since doing that, none of the offending msgs have been attempted so there have been no spikes but I cannot say yet if this is permanent.
I do still suspect that those offending msgs had something in the body though.
Still would be great if the ruleid and criteriaid was included in the oMessage object when rejected.
However, since doing that, none of the offending msgs have been attempted so there have been no spikes but I cannot say yet if this is permanent.
I do still suspect that those offending msgs had something in the body though.
Still would be great if the ruleid and criteriaid was included in the oMessage object when rejected.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
It looks like the ADODB was causing the problem although I continue to use ADODB in a number of other subs in my scripts without problems.
There have been daily attempts since my last post by one of the offending senders, but they are now passing the asynch task to be deleted by a rule.
However, I don't understand why a script error was not logged if this was the case, so there is something hinky here.
Thanks to all for your input.
A last question - is there any way to report when " blocked either by ip range or by connection limit." without having debug on in the log and preferably with sender address?
There have been daily attempts since my last post by one of the offending senders, but they are now passing the asynch task to be deleted by a rule.
However, I don't understand why a script error was not logged if this was the case, so there is something hinky here.
Thanks to all for your input.
A last question - is there any way to report when " blocked either by ip range or by connection limit." without having debug on in the log and preferably with sender address?
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Have a look at this: https://www.hmailserver.com/forum/viewt ... =9&t=34179
I use it tog all kinds of things. I made it to basically replace the event log with something permanent and easier to retrieve data. It logs whatever you tell it to log. Anything you can add to the event log can go in here, effectively, subject to formatting for the tables, of course. I log details from every connection, every rejection, every message received and every logon attempt. The logons fill the log fast, so I expire successful ones after a couple weeks, but keep a record of failed logons. In fact, part of the inspiration for this project was to let me know when my mom failed logon (typed the wrong password into webmail) in order to prevent her from being auto banned.

If there's an event I want to be notified about (like my mom autobanning herself), I use my SMS gateway to send a short link created by YOURLS that opens up the connection log page to a search on that IP so I can see everything that was recorded. I can share all that if you're interested. You wouldn't need YOURLS or SMS. You could just send an email notification with the full link. I shorten it solely for SMS purposes.
Here's an example of a very, very specific search. Just to show how you can really dig deep into the data.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
That's interesting. I use a similar database (see post of 2 Jan) system, (originally from Martin's deliverylog script, now modified to use COM API again) and I prefer not to use a custom build.
What I was asking though was if it is possible to get the oMessage detail from a "client connection from 185.234.219.106 was not accepted. blocked either by ip range or by connection limit." and use this in a standard script to update the database log. This error message only appears in the standard log when debug mode is on.
Also would be very useful to get the specific rule criteria id when that is triggered, not just the rule id, which is all I can put in a custom header on rejection. Then my UpdateLog(oMessage) could report on the specific condition and update the delivery log record accordingly.
What I was asking though was if it is possible to get the oMessage detail from a "client connection from 185.234.219.106 was not accepted. blocked either by ip range or by connection limit." and use this in a standard script to update the database log. This error message only appears in the standard log when debug mode is on.
Also would be very useful to get the specific rule criteria id when that is triggered, not just the rule id, which is all I can put in a custom header on rejection. Then my UpdateLog(oMessage) could report on the specific condition and update the delivery log record accordingly.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
I block AUTH on port 25
I have a script that parses the log file every 5 minutes from a scheduled task, and finds the IP address in the log entries that show 'SENT: 504 Authentication not enabled.' and then I autoban them from the script.
You could do something similar if there is enough detail in the log entry
I have a script that parses the log file every 5 minutes from a scheduled task, and finds the IP address in the log entries that show 'SENT: 504 Authentication not enabled.' and then I autoban them from the script.
You could do something similar if there is enough detail in the log entry
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation
https://www.hmailserver.com/documentation
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Let's be honest here... its all custom when you're writing your own eventlog triggers...

There is no oMessage detail when connections are blocked becuase they get disconnected before they have the opportunity to transmit the message.What I was asking though was if it is possible to get the oMessage detail from a "client connection from 185.234.219.106 was not accepted. blocked either by ip range or by connection limit." and use this in a standard script to update the database log. This error message only appears in the standard log when debug mode is on.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
I have a trial version of Windows Server 2012 R2 (64bit) running RvdH's hMailServer 5.6.8-22 (32bit) as Backup-MX/Relay using "built-in database"... One week and not a foot wrong.
Actually it's set up to shield my current 5.4.2 (highly custom build) and to act as TLS-enabler for my current non-TLS capable 5.4.2...
I would love to see the eventhandlers.vbs as I feel the problem lies here. Too moch code in the main section and you are doomed.
Been there, Done that, Got the T-shirt!
Actually it's set up to shield my current 5.4.2 (highly custom build) and to act as TLS-enabler for my current non-TLS capable 5.4.2...
I would love to see the eventhandlers.vbs as I feel the problem lies here. Too moch code in the main section and you are doomed.
Been there, Done that, Got the T-shirt!
SørenR.
Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.
Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Thanks SorenR but I believe the original problem of spiking CPU has been solved by changing from ODBC to use the COM API.
Why this is the case is a mystery though. You can see the original Sub in my post of 2 Jan.
I'm quite happy with my version of the database log, apart from the lack of detail about which rule criteria is triggered.
Why this is the case is a mystery though. You can see the original Sub in my post of 2 Jan.
I'm quite happy with my version of the database log, apart from the lack of detail about which rule criteria is triggered.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Palinka, sorry if I misread, but didn't you say that onHelo could not provide rule criteria id because that had not yet been started?
If you hacve another method to obtain the criteria (not rule) id when triggered, could you please provide an example?
If you hacve another method to obtain the criteria (not rule) id when triggered, could you please provide an example?
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Maybe I'm the one that misunderstood. If you meant actual hmailserver rules, then no, I don't know of a way to identify that (yet

But anything triggered in eventhandlers.vbs can be recorded. And I *think* hmailserver rules may be accessible from OnDeliverMessage.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
What do you mean "accessible" ?? You can create/change/delete rules using the API at any time.
https://www.hmailserver.com/forum/viewtopic.php?t=2451
Execution wize "Global Rules" are executed after Sub OnDeliveryStart(oMessage) and before Sub OnDeliverMessage(oMessage).
"Account Rules" are executed after Sub OnDeliverMessage(oMessage)
SørenR.
Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.
Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Rule action "Run function" rulexyzfinished
Sub rulexyzfinished()
Call SMS(palinka,"I've done XYZ")
End Sub
Keine Hexerei nur Behändigkeit

SørenR.
Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.
Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Thanks both, but the issue is not creating a rule - that is simple with or without the API and I have my own web version to do so.
The issue is in identifying which rule criteria is triggered when the rule action is performed. eg,
XXXYYY"debug" 2864 "2020-01-21 04:33:25.492" "performing rule action"
265 "application" 2864 "2020-01-21 04:33:25.492" "smtpdeliverer - message 674065: message deleted. action was taken by a global rule (rule name: autoemail, id: 286). "
As you can see, only the ruleid and name are identified, and not even in the debug lines, let alone in the oMessage or oClient.
I use onAcceptMessage to create a record in my delivery log and in every rule action group, I set a header value of the ruleid and rulename. At this point the msg is still in the data folder and identified by its unique filename. If the ruleactions are triggered by the rulecriteria, I then call the UpdateLog Sub which updates the record accordingly before deleting the msg and stopping processing.
There is no need for a rulexyz sub.
As far as I know and as you guys have said, there is nowhere that traps the rulecriteriaid. That is what I would like to achieve.
My code is below and going back to the original issue of spiking, although I changed the createdeliverylogentry sub to a non-ODBC, I am still not convinced that it was not something in the body of the offenders.
The issue is in identifying which rule criteria is triggered when the rule action is performed. eg,
XXXYYY"debug" 2864 "2020-01-21 04:33:25.492" "performing rule action"
265 "application" 2864 "2020-01-21 04:33:25.492" "smtpdeliverer - message 674065: message deleted. action was taken by a global rule (rule name: autoemail, id: 286). "
As you can see, only the ruleid and name are identified, and not even in the debug lines, let alone in the oMessage or oClient.
I use onAcceptMessage to create a record in my delivery log and in every rule action group, I set a header value of the ruleid and rulename. At this point the msg is still in the data folder and identified by its unique filename. If the ruleactions are triggered by the rulecriteria, I then call the UpdateLog Sub which updates the record accordingly before deleting the msg and stopping processing.
There is no need for a rulexyz sub.
As far as I know and as you guys have said, there is nowhere that traps the rulecriteriaid. That is what I would like to achieve.
My code is below and going back to the original issue of spiking, although I changed the createdeliverylogentry sub to a non-ODBC, I am still not convinced that it was not something in the body of the offenders.
Code: Select all
Sub OnAcceptMessage(oClient, oMessage)
CreateDeliveryLogEntry oMessage,oClient.IPAddress
End Sub
Function CreateDeliveryLogEntry(oMessage,sIP)
Dim obApp, obDatabase
Set obApp = CreateObject("hMailServer.Application")
Call obApp.Authenticate(setting_username,setting_password)
Set obDatabase = obApp.Database
Dim sFrom, sFilename, sTime, sSubject, sBody
sFrom = Mid(oMessage.From, 1, 255)
sFrom = Replace(sFrom, "'", "''")
sFrom = Replace(sFrom, "\", "\\")
sSubject = Mid(oMessage.Subject, 1, 255)
sSubject = Replace(sSubject, "'", "''")
sSubject = Replace(sSubject, "\", "\\")
Dim s, e
sFileName = Trim(oMessage.FileName)
s = InStr(sFileName,"{") + 1
e = InStr(sFileName,"}") - s
sFileName = Mid(sFileName,s,e)
sFileName = Replace(sFileName, "'", "''")
sFileName = Replace(sFileName, "\", "\\")
sBody = Mid(oMessage.Body, 1, 250000)
sBody = Replace(sBody, "'", "''")
sBody = Replace(sBody, "\", "\\")
Dim obRecipients
Set obRecipients = oMessage.Recipients
Dim iRecipientCount
iRecipientCount = obRecipients.Count
Dim i
Dim sRecipients
For i = 0 to iRecipientCount -1
sRecipients = sRecipients &obrecipients.Item(i).Address &" "
Next
sRecipients = Trim(Mid(sRecipients,1,255))
Dim sSQL
sSQL = "INSERT INTO hm_deliverylog (Sender, Subject, Body, Recipients, IP, Filename) " _
&" VALUES ('"&sFrom &"','" &sSubject &"','" &sBody &"','" &sRecipients &"','" &sIP &"','" &sFileName & "')"
Dim iID
iID = obDatabase.ExecuteSQLWithReturn(sSQL)
Set obApp = Nothing
Set obDatabase = Nothing
End Function
Sub UpdateLog(oMessage)
'On Error Resume Next
sFileName = Trim(oMessage.FileName)
s = InStr(sFileName,"{") + 1
e = InStr(sFileName,"}") - s
sFileName = Mid(sFileName,s,e)
Dim oRule,oRuleID
oRule = oMessage.HeaderValue("N-Spam")
Set vMail = CreateObject("ADODB.Command")
With vMail
.ActiveConnection = "dsn=hMail"
.CommandText = "UPDATE hm_deliverylog SET status=9,rule='"&oRule&"' WHERE FileName='"&sFileName&"'"
.CommandType = 1
.CommandTimeout = 0
.Prepared = true
.Execute()
End With
Set vMail = Nothing
End Sub
- jimimaseye
- Moderator
- Posts: 8859
- Joined: 2011-09-08 17:48
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
(Nigel, use [ code] tags around code snippets to format and display it correctly]
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
SpamassassinForWindows 3.4.0 spamd service
AV: Clamwin + Clamd service + sanesecurity defs : https://www.hmailserver.com/forum/viewtopic.php?f=21&t=26829
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Exactly. Do as soren said.
Rule xyz:
If criteria
Then action 1
Then action 2
Then action "Run function" rulexyzfinished
Rule abc:
If criteria
Then action 1
Then action "Run function" ruleabcfinished
Set up as many subs as you have rules. Or just the ones you want to be notified about.
What I started working on for my log project is adding a unique ID for each connection. This way, everything I track can tie back to the unique ID. Then when the message is processed, if there's a trigger for a notification, the notification contains three ID with a link. Then i can see each of the steps it took as it traveled through my filters.
Now i have a way of determining if it triggered a rule criteria.
See, the big difference between your log and mine is that your log gets called once to add a pre- determined set of information. My log gets called at any step of the way that i want. When I get to my computer, I'll show you an example.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Example script. Leaving a lot out for simplicity.
There's a lot more than these items. I'm just displaying a bit to show how it works. I'd be happy to share if you want, but this snippet gets the point across, I think.
And just like how any piece of information can be added as in the example above, the same can be done via Soren's sub rulexyzfinished.
Actually, I'm not sure how those other variables could be passed (port, IP, HELO), but they could be spoofed or left blank. Or maybe I'll figure out a way to pass them. I haven't tried yet. 
Code: Select all
Sub OnAcceptMessage(oClient, oMessage)
REM - Grab PTR-Record
PTR_Record = PTRLookup(oClient.IPAddress)
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "Accepted", "Record-PTR", oClient.IPAddress, PTR_Record)
REM - Exclude local LAN & Backup from test after recording connection
If (Left(oClient.IPAddress, 8) = "192.168.") Then
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "Accepted", "Local", oClient.IPAddress, oClient.HELO)
Exit Sub
End If
If (Left(oClient.IPAddress, 9) = "127.0.0.1") Then
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "Accepted", "Local", oClient.IPAddress, oClient.HELO)
Exit Sub
End If
REM - Exclude authenticated users test
If (oClient.Username <> "") Then
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "Accepted", "MsgFrom", oClient.IPAddress, oMessage.FromAddress)
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "Accepted", "MsgTo", oClient.IPAddress, oMessage.Recipients(0).OriginalAddress)
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "Accepted", "MsgSubject", oClient.IPAddress, oMessage.Subject)
Exit Sub
End If
REM - Exclude servers with specific HELO/EHLO greetings (Whitelist)
strRegEx = GetXMLNode(XMLDATA, "//Whitelist/HELO")
Set Matches = oLookup(strRegEx, oClient.HELO, False)
For Each Match In Matches
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "Accepted", "WL-HELO", oClient.IPAddress, oClient.HELO)
Exit Sub
Next
REM - Check if TOR Exit Node
If IsTorExitNode(oClient.IPAddress) Then
Result.Value = 2
Result.Message = ". 17 Your access to this mail system has been rejected due to the sending MTA's poor reputation. If you believe that this failure is in error, please contact the intended recipient via alternate means."
Call Disconnect(oClient.IPAddress)
Call FWBan(oClient.IPAddress, "TorExitNode", oClient.HELO, PTR_Record)
Call AutoBan(oClient.IPAddress, "TorExitNode - " & oClient.IpAddress, 1, "h")
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "REJECTED", "TorExitNode", oClient.IPAddress, oClient.HELO)
Exit Sub
End If
REM - Reject on No-PTR
If (oClient.Port = 25) Then
If PTR_Record = "No.PTR.Record" Then
Result.Value = 2
Result.Message = ". 03 Your access to this mail system has been rejected due to the sending MTA's poor reputation. If you believe that this failure is in error, please contact the intended recipient via alternate means."
Call Disconnect(oClient.IPAddress)
Call FWBan(oClient.IPAddress, "No-PTR", oClient.HELO, PTR_Record)
Call AutoBan(oClient.IPAddress, "No-PTR - " & oClient.IpAddress, 1, "h")
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "REJECTED", "No-PTR", oClient.IPAddress, oClient.HELO)
Exit Sub
End If
End If
REM - Validate HELO/EHLO greeting
Const strFQDN = "^(?=^.{1,254}$)(^(?:(?!\.|-)([a-z0-9\-\*]{1,63}|([a-z0-9\-]{1,62}[a-z0-9]))\.)+(?:[a-z]{2,})$)$"
Const strIPv4 = "^\[(?:[0-9]{1,3}\.){3}[0-9]{1,3}\]$"
Const strIPv6 = "^\[(IPv6)((?:[0-9A-Fa-f]{0,4}:){1,7}(?:(?:(>25[0-5]|2[0-4][0-9]|[01]?[0-9][0-9]?)\.){3}(?:25[0-5]|2[0-4][0-9]|[01]?[0-9][0-9]?)|[0-9A-Fa-f]{1,4}))\]$"
strRegEx = strFQDN & "|" & strIPv4 & "|" & strIPv6
If (Lookup(strRegEx, oClient.HELO) = False) Then
Result.Value = 2
Result.Message = ". 04 Your access to this mail system has been rejected due to the sending MTA's poor reputation. If you believe that this failure is in error, please contact the intended recipient via alternate means."
Call Disconnect(oClient.IPAddress)
Call FWBan(oClient.IPAddress, "HELO-Inv", oClient.HELO, PTR_Record)
Call AutoBan(oClient.IPAddress, "Invalid HELO - " & oClient.HELO, 1, "h")
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "REJECTED", "HELO-Inv", oClient.IPAddress, oClient.HELO)
Exit Sub
End If
REM - Spamhaus Zen detection
If IsInSpamHausZEN(oClient.IPAddress) Then
Result.Value = 2
Result.Message = ". 02 This server does not accept connections blacklisted by Spamhaus.org. If you believe that this failure is in error, please contact the intended recipient via alternate means."
Call Disconnect(oClient.IPAddress)
Call FWBan(oClient.IPAddress, "Spamhaus", oClient.HELO, PTR_Record)
Call AutoBan(oClient.IPAddress, "Spamhaus - " & oClient.IpAddress, 1, "h")
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "REJECTED", "Spamhaus", oClient.IPAddress, oClient.HELO)
Exit Sub
End If
REM - Reject "From:"
strRegEx = GetXMLNode(XMLDATA, "//Reject/From")
Set Matches = oLookup(strRegEx, oMessage.From, False)
For Each Match In Matches
Result.Value = 2
Result.Message = ". 10 Your access to this mail system has been rejected due to the sending MTA's poor reputation. If you believe that this failure is in error, please contact the intended recipient via alternate means."
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "REJECTED", "FromAdd", oClient.IPAddress, oClient.HELO)
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "REJECTED", "MsgFrom", oClient.IPAddress, oMessage.FromAddress)
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "REJECTED", "MsgTo", oClient.IPAddress, oMessage.Recipients(0).OriginalAddress)
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "REJECTED", "MsgSubject", oClient.IPAddress, oMessage.Subject)
Exit Sub
Next
REM - Reject "Subject:"
strRegEx = GetXMLNode(XMLDATA, "//Reject/Subject")
If (oMessage.HeaderValue("X-Blacklist-RegEx") = "") Then
Set Matches = oLookup(strRegEx, oMessage.Subject, False)
For Each Match In Matches
Result.Value = 2
Result.Message = ". 11 Your access to this mail system has been rejected due to the sending MTA's poor reputation. If you believe that this failure is in error, please contact the intended recipient via alternate means."
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "REJECTED", "Subject", oClient.IPAddress, oClient.HELO)
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "REJECTED", "MsgFrom", oClient.IPAddress, oMessage.FromAddress)
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "REJECTED", "MsgTo", oClient.IPAddress, oMessage.Recipients(0).OriginalAddress)
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "REJECTED", "MsgSubject", oClient.IPAddress, oMessage.Subject)
Exit Sub
Next
End If
REM - Get spam reasons for AccRej Log
Dim Reason1, Reason2, Reason3, Reason4, Reason5, Reason6, Reason7
If (oMessage.HeaderValue("X-hMailServer-Spam") = "YES") Then
If (oMessage.HeaderValue("X-hMailServer-Reason-1") <> "") Then
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "Accepted", "Spam-Reason", oClient.IPAddress, oMessage.HeaderValue("X-hMailServer-Reason-1"))
End If
If (oMessage.HeaderValue("X-hMailServer-Reason-2") <> "") Then
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "Accepted", "Spam-Reason", oClient.IPAddress, oMessage.HeaderValue("X-hMailServer-Reason-2"))
End If
If (oMessage.HeaderValue("X-hMailServer-Reason-3") <> "") Then
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "Accepted", "Spam-Reason", oClient.IPAddress, oMessage.HeaderValue("X-hMailServer-Reason-3"))
End If
If (oMessage.HeaderValue("X-hMailServer-Reason-4") <> "") Then
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "Accepted", "Spam-Reason", oClient.IPAddress, oMessage.HeaderValue("X-hMailServer-Reason-4"))
End If
If (oMessage.HeaderValue("X-hMailServer-Reason-5") <> "") Then
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "Accepted", "Spam-Reason", oClient.IPAddress, oMessage.HeaderValue("X-hMailServer-Reason-5"))
End If
If (oMessage.HeaderValue("X-hMailServer-Reason-6") <> "") Then
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "Accepted", "Spam-Reason", oClient.IPAddress, oMessage.HeaderValue("X-hMailServer-Reason-6"))
End If
If (oMessage.HeaderValue("X-hMailServer-Reason-7") <> "") Then
Call AccRejDB(msgID, oClient.Port, "OnAcceptMessage", "Accepted", "Spam-Reason", oClient.IPAddress, oMessage.HeaderValue("X-hMailServer-Reason-7"))
End If
End If
End Sub
And just like how any piece of information can be added as in the example above, the same can be done via Soren's sub rulexyzfinished.
Code: Select all
Sub rulexyzfinished
Call AccRejDB(msgID, oClient.Port, "RuleTrigger", "REJECTED", "RuleCriteria", oClient.IPAddress, oClient.HELO)
End Sub

Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Thanks for the input.
However, I repeat, Soren's sub only seems to identify the rule NOT the criteria.
Palinka, your code is comprehensive but I already have most of that data in my version, and as far as I know, X-hMailServer-Reason-x is not standard and would not identify the criteria either. Plus I don't want a custom build on which yours is based.
Jimimaseye, thanks for the code pointer.
However, I repeat, Soren's sub only seems to identify the rule NOT the criteria.
Palinka, your code is comprehensive but I already have most of that data in my version, and as far as I know, X-hMailServer-Reason-x is not standard and would not identify the criteria either. Plus I don't want a custom build on which yours is based.
Jimimaseye, thanks for the code pointer.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
The sub was never intended to identify the criteria. Having said that ... IF the criteria is met then the rule is performed so that should indicate some form of knowledge about the criteria.
It's the difference between Deductive Reasoning and Inductive Reasoning that makes the small miracles

SørenR.
Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.
Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
Of course it will:
Code: Select all
20/01/26 10:56.52 173.214.188.35 25 OnAcceptMessage Accepted Spam-Reason United States Tagged as Spam by SpamAssassin - (Score: 24)
20/01/26 10:56.52 173.214.188.35 25 OnAcceptMessage Accepted Spam-Reason United States Rejected by SpamCop. - (Score: 2)
20/01/26 10:56.52 173.214.188.35 25 OnAcceptMessage Accepted Spam-Reason United States Blocked by SPF () - (Score: 3)
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
The criteria is the IF statement in the rule, not the subject matter examined. So yes, the criteria was indeed identified by identifying the rule that was triggered.

cri·te·ri·on (krī-tîr′ē-ən)
n. pl. cri·te·ri·a (-tîr′ē-ə) or cri·te·ri·ons
A standard, rule, or test on which a judgment or decision can be based.
Re: WIn Server 2012 R2 Updates causing hMailServer to go 100% CPU
The rule could have multiple criteriapalinka wrote: ↑2020-01-28 16:56The criteria is the IF statement in the rule, not the subject matter examined. So yes, the criteria was indeed identified by identifying the rule that was triggered.![]()
cri·te·ri·on (krī-tîr′ē-ən)
n. pl. cri·te·ri·a (-tîr′ē-ə) or cri·te·ri·ons
A standard, rule, or test on which a judgment or decision can be based.

Like
IF "teenager = true" AND "arrive home = late" AND "drunk = true" THEN "grounded" = 1 month
Do we really care about the detail? Well, some people do and that's why the get an ulser or die from a stroke.
SørenR.
Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.
Algorithm (noun.)
Word used by programmers when they do not want to explain what they did.