log for 550 errors

Use this forum if you have problems with a hMailServer script, such as hMailServer WebAdmin or code in an event handler.
Post Reply
daniel.pirsu
New user
New user
Posts: 4
Joined: 2016-04-07 09:08

log for 550 errors

Post by daniel.pirsu » 2020-02-27 12:57

Hello,

I'm tryng to make a log for incoming messages with 550 errors. Only purpose is to find errors/attacks at a glance. Can anyone assist to choose between below events?

a) OnClientConnect - My opinion is that is too early (550 not yet triggered) and oMessage fields are not available. At this point From or To are unknown.

b) OnSMTPData (oClient, oMessage) - Sender and recipent are known but how to catch '550'? Guess oMessage.To field should be checked against all email address from server. Can be done, but I worry that might 'backfire' in case of SMTP attacks and put extra pressure on server. Have experienced attacks with 1000+ messages sent at once to random addresses to hosted domains on my server. (Hmail Team thanks for great product - as hmail didn't crashed at workload)

c) OnDeliveryStart / OnDeliverMessage - it is to late as message was already rejected, and can not see.

Many thanks,
best regards,
Daniel

User avatar
katip
Senior user
Senior user
Posts: 748
Joined: 2006-12-22 07:58
Location: Istanbul

Re: log for 550 errors

Post by katip » 2020-02-27 14:31

i'm parsing SMTP_log every 5 minutes and lookup 550,535,530,504 lines to feed my IP bans.
viewtopic.php?f=21&t=34145&hilit=autoban#p213305
if you need sender or recipient addresses too, it gets a little complicated. maintaining a seperate table might help.
Katip
--
HMS 5.7.0 x64, MariaDB 10.4.10 x64, SA 3.4.2, ClamAV 0.101.2 + SaneS

daniel.pirsu
New user
New user
Posts: 4
Joined: 2016-04-07 09:08

Re: log for 550 errors

Post by daniel.pirsu » 2020-02-27 15:02

Good day,

Many thanks, I will give it a try and see how it works. Only purpose was to 'manually' filter IP before giving it a ban.

because, if for example a clients just delete an email account without unsubscribing from a newsletter when news is receive it will trigger 550 and 'falsely' blocking sender and remaining user might still need that newsletter.

Thanks,
Daniel

palinka
Senior user
Senior user
Posts: 1923
Joined: 2017-09-12 17:57

Re: log for 550 errors

Post by palinka » 2020-02-29 16:24

katip wrote:
2020-02-27 14:31
i'm parsing SMTP_log every 5 minutes and lookup 550,535,530,504 lines to feed my IP bans.
viewtopic.php?f=21&t=34145&hilit=autoban#p213305
if you need sender or recipient addresses too, it gets a little complicated. maintaining a seperate table might help.
This sparked my interest and I made a powershell script to tail the log. I'm not really sure what to do with the results. I'm kind of hesitant to just ban it (which I would do via my firewall ban project). Can you help me out with the logic behind your bans?

Right now my script just sends an email when I get a hit on 550. I get very few hits thanks to a bunch of strict filters that reject/disconnect connections (plus firewall banning spammers so they can't return to spam another day :D ).

I also noticed that the log trails actual events by some amount of time. The transaction could be over before being logged and picked up by my script, so I'm not sure how useful tailing is compared to searching on an interval. Anyway, it filled up my hobby time for a few hours … :mrgreen:

The logic is instead of looking for "550" in the logs, it looks for "RCPT TO", parses out the email address, checks if not a domain with a catchall address (where 550 would be impossible), looks for possible plus addressing, then searches hmailserver database for the address. If the address is valid, it moves on. If not, it logs it and sends a notification. I could easily change that to ban the IP, or autoban it, or ???? What do you think is the appropriate action if found?

550.ps1 (run at 12:01 am by scheduled task)

Code: Select all

### SCRIPT VARIABLES ###########################################################
#                                                                              #
$CatchAllDomains = "mydomain.net"  #<-- For Multiple, Separate With Pipe "|"   #
$PlusAddressChar = "\+"            #<-- MUST Escape                            #
$LogDir = "C:\Program Files (x86)\hMailServer\Logs"                            #
#                                                                              #
###   MYSQL VARIABLES   ########################################################
#                                                                              #
$DatabaseType     = 'MYSQL'            #<-- Options: "MYSQL" or "MSSQL"        #
$SQLAdminUserName = 'hmailserver'                                              #
$SQLAdminPassword = 'supersecretpassword'                                      #
$SQLDatabase      = 'hmailserver'                                              #
$SQLHost          = '127.0.0.1'                                                #
$SQLPort          = 3306                                                       #
#                                                                              #
###   EMAIL VARIABLES   ########################################################
#                                                                              #
$FromAddress  = 'notifier.account@gmail.com'                                   #
$Recipient    = 'me@mydomain.com'                                              #
$SMTPServer   = 'smtp.gmail.com'                                               #
$SMTPAuthUser = 'notifier.account@gmail.com'                                   #
$SMTPAuthPass = 'supersecretpassword'                                          #
$SMTPPort     = 587                                                            #
$SSL          = 'True'                                                         #
#                                                                              #
################################################################################


#######################################
#                                     #
#             FUNTIONS                #
#                                     #
#######################################

Function EmailResults {
	$Subject = "hMS 550 Notification" 
	$Body = (Get-Content -Path $EmailBody | Out-String )
	$SMTPClient = New-Object Net.Mail.SmtpClient($SMTPServer, $SMTPPort) 
	$SMTPClient.EnableSsl = [System.Convert]::ToBoolean($SSL)
	$SMTPClient.Credentials = New-Object System.Net.NetworkCredential($SMTPAuthUser, $SMTPAuthPass); 
	$SMTPClient.Send($FromAddress, $Recipient, $Subject, $Body)
}

Function IsMSSQL(){
	return ($DatabaseType -eq "MSSQL")
}

Function IsMySQL(){
	return ($DatabaseType -eq "MYSQL")
}

Function RunSQLQuery($Query){
    If ($(IsMySQL)) {
        MySQLQuery($Query)
    } ElseIf ($(IsMSSQL)){
        MSSQLQuery($Query)
    } Else {
        Out-Null
    }
}

Function MySQLQuery($Query) {
	$Today = (Get-Date).ToString("yyyyMMdd")
	$DBErrorLog = "$PSScriptRoot\$Today-DBError.log"
	$ConnectionString = "server=" + $SQLHost + ";port=" + $SQLPort + ";uid=" + $SQLAdminUserName + ";pwd=" + $SQLAdminPassword + ";database=" + $SQLDatabase
	Try {
		[void][System.Reflection.Assembly]::LoadWithPartialName("MySql.Data")
		$Connection = New-Object MySql.Data.MySqlClient.MySqlConnection
		$Connection.ConnectionString = $ConnectionString
		$Connection.Open()
		$Command = New-Object MySql.Data.MySqlClient.MySqlCommand($Query, $Connection)
		$DataAdapter = New-Object MySql.Data.MySqlClient.MySqlDataAdapter($Command)
		$DataSet = New-Object System.Data.DataSet
		$RecordCount = $dataAdapter.Fill($dataSet, "data")
		$DataSet.Tables[0]
	}
	Catch {
		Write-Output "$((get-date).ToString(`"yy/MM/dd HH:mm:ss.ff`")) : ERROR : Unable to run query : $query `n$Error[0]" | out-file $DBErrorLog -append
	}
	Finally {
		$Connection.Close()
	}
}

Function MSSQLQuery($Query) {
	$Today = (Get-Date).ToString("yyyyMMdd")
	$DBErrorLog = "$PSScriptRoot\$Today-DBError.log"
    $ConnectionString = "Data Source=" + $SQLHost + "," + $SQLPort + ";uid=" + $SQLAdminUserName + ";password=" + $SQLAdminPassword + ";Initial Catalog=" + $SQLDatabase
	Try {
		[void][System.Reflection.Assembly]::LoadWithPartialName("MySql.Data")
		$Connection = New-Object System.Data.SqlClient.SQLConnection($connectionString)
		$Connection.Open()
		$Command = New-Object System.Data.SqlClient.SqlCommand($Query, $Connection)
		$DataAdapter = New-Object System.Data.SqlClient.SqlDataAdapter($Command)
		$DataSet = New-Object System.Data.DataSet
		$RecordCount = $dataAdapter.Fill($dataSet, "data")
		$DataSet.Tables[0]
	}
	Catch {
		Write-Output "$((get-date).ToString(`"yy/MM/dd HH:mm:ss.ff`")) : ERROR : Unable to run query : $query `n$Error[0]" | out-file $DBErrorLog -append
	}
	Finally {
		$Connection.Close()
	}
}

#######################################
#                                     #
#           START SCRIPT              #
#                                     #
#######################################

[regex]$RegexEmail = "[A-Za-z0-9!.#$%&'*+\/=?^_`{|}~-]+@([A-Za-z0-9-]{2,63}\.){1,10}[A-Za-z0-9-]{2,12}"

<#	Check to see if hMailServer is running. If not, quit. MySQL is a dependency of hMailServer service so you're actually checking both.   #>
<#	Prevents scheduled task failures at bootup.   #>
Do {
	If ((get-service hMailServer).Status -ne 'Running') { $Running = "NO" } Else { $Running = "YES" }
} Until ($Running = "YES")

<#	Tail log   #>
Get-ChildItem $LogDir | Where {$_.Name -match "^hmailserver_"+$((Get-Date).ToString("yyyy-MM-dd"))+".log$"} | ForEach {
	$LogName = $_
	
	<#	Convert log lines to objects   #>
	Get-Content "$LogDir\$LogName" -Wait -Tail 1 | ConvertFrom-String -Delimiter "`t" -PropertyNames Protocol, ThreadID, Session, DateTime, IPAddress, Message | ForEach {

		<#	Clear out variables in loop   #>
		$DateTime = $IP = $To = $LowerPart = $Domain = $Account = $AccountToTest = $Msg = $NULL

		<#	If SMTPD proceed, discard all others   #>
		If ($_.Protocol -match "SMTPD") {
			$DateTime = $_.DateTime
			$IP = $_.IPAddress

			<#	If RCPT TO proceed, discard other SMTPD   #>
			If ($_.Message -match "RCPT"){
				$To = ($RegexEmail.Matches($_.Message)).Value

				<#	Check for plus addressing, explode address and recombine without plus address   #>
				If ($To -match $PlusAddressChar) {
					$LowerPart = ($To).Split("@")[0]
					$Domain = ($To).Split("@")[1]
					$Account = ($LowerPart).Split($PlusAddressChar)[0]
					$ToPlus = "$Account@$Domain"
				}

				<#	Bypass domains with catchall addresses, then query address to see if it exists as hmailserver account   #>
				If ($To -notmatch $CatchAllDomains){
					$Query = "SELECT COUNT(*) AS result FROM hm_accounts WHERE accountaddress = '$To' OR accountaddress = '$ToPlus';"
					RunSQLQuery $Query | ForEach {
						$AccountExists = $_.result

						<#	If no address doesn't match accounts list, log and notify   #>
						If($AccountExists -eq "0"){
							$EmailBody = "$PSScriptRoot\550email.txt"
							$Msg = "$DateTime | Unknown User | Recipient: $To | $IP"
							Write-Output $Msg | Out-File "PSScriptRoot\550.log" -append
							Write-Output $Msg | Out-File $EmailBody -Encoding ASCII
							EmailResults $EmailBody
						}
					}
				}
			}
		}
		<#	Quit script at 23:59 in order to load next day's log (initiated by scheduled task at 00:01)  #>
		If ((Get-Date -format HH:mm) -gt "23:58") { Exit }
	}
}

palinka
Senior user
Senior user
Posts: 1923
Joined: 2017-09-12 17:57

Re: log for 550 errors

Post by palinka » 2020-02-29 18:34

Updated for automatic checking to see if plus addressing or catchall in use. Could be useful if different domains use different plus addressing character. :mrgreen:

Also don't need to check if hmailserver is running. Log is present or not whether hmailserver is running or not.

Code: Select all

###   SCRIPT VARIABLES   #######################################################
#                                                                              #
$LogDir = "C:\Program Files (x86)\hMailServer\Logs"                            #
#                                                                              #
###   MYSQL VARIABLES   ########################################################
#                                                                              #
$DatabaseType     = 'MYSQL'            #<-- Options: "MYSQL" or "MSSQL"        #
$SQLAdminUserName = 'hmailserver'                                              #
$SQLAdminPassword = 'supersecretpassword'                                      #
$SQLDatabase      = 'hmailserver'                                              #
$SQLHost          = '127.0.0.1'                                                #
$SQLPort          = 3306                                                       #
#                                                                              #
###   EMAIL VARIABLES   ########################################################
#                                                                              #
$FromAddress      = 'notifier.account@gmail.com'                               #
$Recipient        = 'me@mydomain.com'                                          #
$SMTPServer       = 'smtp.gmail.com'                                           #
$SMTPAuthUser     = 'notifier.account@gmail.com'                               #
$SMTPAuthPass     = 'supersecretpassword'                                      #
$SMTPPort         = 587                                                        #
$SSL              = 'True'                                                     #
#                                                                              #
################################################################################


#######################################
#                                     #
#             FUNTIONS                #
#                                     #
#######################################

Function EmailResults {
	$Subject = "hMS 550 Notification" 
	$Body = (Get-Content -Path $EmailBody | Out-String )
	$SMTPClient = New-Object Net.Mail.SmtpClient($SMTPServer, $SMTPPort) 
	$SMTPClient.EnableSsl = [System.Convert]::ToBoolean($SSL)
	$SMTPClient.Credentials = New-Object System.Net.NetworkCredential($SMTPAuthUser, $SMTPAuthPass); 
	$SMTPClient.Send($FromAddress, $Recipient, $Subject, $Body)
}

Function IsMSSQL(){
	return ($DatabaseType -eq "MSSQL")
}

Function IsMySQL(){
	return ($DatabaseType -eq "MYSQL")
}

Function RunSQLQuery($Query){
    If ($(IsMySQL)) {
        MySQLQuery($Query)
    } ElseIf ($(IsMSSQL)){
        MSSQLQuery($Query)
    } Else {
        Out-Null
    }
}

Function MySQLQuery($Query) {
	$Today = (Get-Date).ToString("yyyyMMdd")
	$DBErrorLog = "$PSScriptRoot\$Today-DBError.log"
	$ConnectionString = "server=" + $SQLHost + ";port=" + $SQLPort + ";uid=" + $SQLAdminUserName + ";pwd=" + $SQLAdminPassword + ";database=" + $SQLDatabase
	Try {
		[void][System.Reflection.Assembly]::LoadWithPartialName("MySql.Data")
		$Connection = New-Object MySql.Data.MySqlClient.MySqlConnection
		$Connection.ConnectionString = $ConnectionString
		$Connection.Open()
		$Command = New-Object MySql.Data.MySqlClient.MySqlCommand($Query, $Connection)
		$DataAdapter = New-Object MySql.Data.MySqlClient.MySqlDataAdapter($Command)
		$DataSet = New-Object System.Data.DataSet
		$RecordCount = $dataAdapter.Fill($dataSet, "data")
		$DataSet.Tables[0]
	}
	Catch {
		Write-Output "$((get-date).ToString(`"yy/MM/dd HH:mm:ss.ff`")) : ERROR : Unable to run query : $query `n$Error[0]" | out-file $DBErrorLog -append
	}
	Finally {
		$Connection.Close()
	}
}

Function MSSQLQuery($Query) {
	$Today = (Get-Date).ToString("yyyyMMdd")
	$DBErrorLog = "$PSScriptRoot\$Today-DBError.log"
    $ConnectionString = "Data Source=" + $SQLHost + "," + $SQLPort + ";uid=" + $SQLAdminUserName + ";password=" + $SQLAdminPassword + ";Initial Catalog=" + $SQLDatabase
	Try {
		[void][System.Reflection.Assembly]::LoadWithPartialName("MySql.Data")
		$Connection = New-Object System.Data.SqlClient.SQLConnection($connectionString)
		$Connection.Open()
		$Command = New-Object System.Data.SqlClient.SqlCommand($Query, $Connection)
		$DataAdapter = New-Object System.Data.SqlClient.SqlDataAdapter($Command)
		$DataSet = New-Object System.Data.DataSet
		$RecordCount = $dataAdapter.Fill($dataSet, "data")
		$DataSet.Tables[0]
	}
	Catch {
		Write-Output "$((get-date).ToString(`"yy/MM/dd HH:mm:ss.ff`")) : ERROR : Unable to run query : $query `n$Error[0]" | out-file $DBErrorLog -append
	}
	Finally {
		$Connection.Close()
	}
}

#######################################
#                                     #
#           START SCRIPT              #
#                                     #
#######################################

[regex]$RegexEmail = "[A-Za-z0-9!.#$%&'*+\/=?^_`{|}~-]+@([A-Za-z0-9-]{2,63}\.){1,10}[A-Za-z0-9-]{2,12}"

<#	Tail log   #>
Get-ChildItem $LogDir | Where {$_.Name -match "^hmailserver_"+$((Get-Date).ToString("yyyy-MM-dd"))+".log$"} | ForEach {
	$LogName = $_
	
	<#	Convert log lines to objects   #>
	Get-Content "$LogDir\$LogName" -Wait -Tail 1 | ConvertFrom-String -Delimiter "`t" -PropertyNames Protocol, ThreadID, Session, DateTime, IPAddress, Message | ForEach {

		<#	Clear out variables in loop   #>
		$DateTime = $IP = $To = $LowerPart = $Domain = $Account = $AccountToTest = $Msg = $PlusAddChar = $CatchAll = $NULL

		<#	If SMTPD proceed, discard all others   #>
		If ($_.Protocol -match "SMTPD") {
			$DateTime = $_.DateTime
			$IP = $_.IPAddress

			<#	If RCPT TO proceed, discard other SMTPD   #>
			If ($_.Message -match "RCPT"){
				$To = ($RegexEmail.Matches($_.Message)).Value

				<#	Check to see if plus addressing or catchall in use   #>
				$Domain = ($To).Split("@")[1]
				$PACSQL = "SELECT domainpostmaster, domainplusaddressingchar FROM hm_domains WHERE domainname = '$Domain';"
				RunSQLQuery $PACSQL | ForEach {
					If ($_.domainpostmaster -ne [DBNull]::Value) {$CatchAll = $_.domainpostmaster} Else {$CatchAll = $NULL}
					If ($_.domainplusaddressingchar -ne [DBNull]::Value) {$PlusAddChar = $_.domainplusaddressingchar} Else {$PlusAddChar = $NULL}
				}
				
				<#	Check for plus addressing, explode address and recombine without plus address   #>
				If ($PlusAddChar) {
					$LowerPart = ($To).Split("@")[0]
					$Account = ($LowerPart).Split($PlusAddChar)[0]
					$ToPlus = "$Account@$Domain"
				}

				<#	Bypass domains with catchall addresses, then query address to see if it exists as hmailserver account   #>
				If (-not($CatchAll)){
					$Query = "SELECT COUNT(*) AS result FROM hm_accounts WHERE accountaddress = '$To' OR accountaddress = '$ToPlus';"
					RunSQLQuery $Query | ForEach {
						$AccountExists = $_.result

						<#	If no address doesn't match accounts list, log and notify   #>
						If($AccountExists -eq "0"){
							$EmailBody = "C:\scripts\hmailserver\FWBan\550email.txt"
							$Msg = "$DateTime | Unknown User | Recipient: $To | $IP"
							Write-Output $Msg | Out-File "C:\scripts\hmailserver\FWBan\550.log" -append
							Write-Output $Msg | Out-File $EmailBody -Encoding ASCII
							EmailResults $EmailBody
						}
					}
				}
			}
		}
		<#	Quit script at 23:59 in order to load next day's log (initiated by scheduled task at 00:01)  #>
		If ((Get-Date -format HH:mm) -gt "23:58") { Exit }
	}
}

User avatar
katip
Senior user
Senior user
Posts: 748
Joined: 2006-12-22 07:58
Location: Istanbul

Re: log for 550 errors

Post by katip » 2020-02-29 19:02

palinka wrote:
2020-02-29 16:24
katip wrote:
2020-02-27 14:31
i'm parsing SMTP_log every 5 minutes and lookup 550,535,530,504 lines to feed my IP bans.
viewtopic.php?f=21&t=34145&hilit=autoban#p213305
if you need sender or recipient addresses too, it gets a little complicated. maintaining a seperate table might help.
Can you help me out with the logic behind your bans?
this is crucial in my script:

Code: Select all

trigger = 10 'this is a trigger to identify an IP as malicious, YMMV
you schedule the script to run every x minutes (my approach 5-10 min)
logic is simple:
it parses today's SMTP_log and finds IPs causing 550,535,530 or 504 more than "trigger" times, sends them to HMS autoban - if not already there.

caveat: i don't think it's very effective against bot attacks. usually bots do their job in <1 min and leave and rarely use the same IP for their next visit. banning /24 blocks might give slightly better (and a little risky) results, never tried though.
Katip
--
HMS 5.7.0 x64, MariaDB 10.4.10 x64, SA 3.4.2, ClamAV 0.101.2 + SaneS

palinka
Senior user
Senior user
Posts: 1923
Joined: 2017-09-12 17:57

Re: log for 550 errors

Post by palinka » 2020-02-29 19:54

katip wrote:
2020-02-29 19:02
it parses today's SMTP_log and finds IPs causing 550,535,530 or 504 more than "trigger" times, sends them to HMS autoban - if not already there.

caveat: i don't think it's very effective against bot attacks. usually bots do their job in <1 min and leave and rarely use the same IP for their next visit. banning /24 blocks might give slightly better (and a little risky) results, never tried though.
I see... Have you seen Soren's IDS? Its dead simple but brilliant. Achieves (I think) the same thing you're doing, but in a different way.

https://www.hmailserver.com/forum/viewt ... 45#p209545

And yeah, I know what you mean about the bots. I've learned a lot about them since I started my firewall ban project. I record a bunch of different information into the database and you start to see patterns after a while. About 60% of my bans never return (I know from scraping the firewall log and counting drops). About the only 550s I see are when a message gets deleted due to rules, or delivery to disabled account. Most spammers don't even get to the RCPT TO part of the transmission because my filters kill the connection, autoban then firewall ban it before it gets that far.

Oh well. I got to learn how to scrape the log. :D Maybe it will be useful in the future for another purpose.

Post Reply