smtplogparser/internal/log.go

313 lines
9.1 KiB
Go

package internal
import (
"bufio"
"encoding/csv"
"io"
"log"
"regexp"
"strings"
"time"
)
const (
AnonymizedText = "**ANONYMIZED**"
)
// Syntax of a message:
// DD-MM-YYYY hh:mm:ss LogLevel Service [\[ID\]] LogMessage[ (MessageID)][.]
// Example failing mail:
// 19-03-2018 03:54:07 3 Fuzzy-Filter (40935FC192D) phase 1 (ex) 325ms result: Major=spam Minor=normal Fallback=spam Virus=
var (
// 05-03-2018 15:36:14 2 SMTPClient [E8F00BA5] (4DBAB2C02A3) Message delivered to: <person@kunde.de>
rxSuccessfulMessage = regexp.MustCompile(`^Message\s+delivered\s+to:\s+<(.+)>\s*$`)
rxMapMessageID = regexp.MustCompile(`^MessageID: .+\s*$`)
rxSubject = regexp.MustCompile(`^Testing: (.+)\s*$`)
rxSenderAddress = regexp.MustCompile(`(?i)^Recieve: MAIL\s+FROM:\s*<(.+)>\s*`)
rxRecipientAddress = regexp.MustCompile(`(?i)^Recieve: RCPT\s+TO:\s*<(.+)>\s*`)
/*
05-03-2018 15:36:13 3 SMTPClient [E8F00BA5] (4DBAB2C02A3) Receive on MAIL FROM: <MaxMustermann@daimler.com> = 250 2.1.0 Sender OK
05-03-2018 15:36:13 3 SMTPClient [E8F00BA5] (4DBAB2C02A3) Receive on RCPT TO: <person@kunde.de> = 250 2.1.5 Recipient OK
*/
rxSendMailFrom = regexp.MustCompile(`^Receive on MAIL\s+FROM:\s*<(.+)>\s+`)
rxSendRcptTo = regexp.MustCompile(`^Receive on RCPT\s+TO:\s*<(.+)>\s+`)
maxMessageAge = 30 * time.Second
)
type Log struct {
// Maps sessions by SMTP server session ID
smtpServerSessions map[string]*SMTPServerSession
CSVWriter *csv.Writer
AnonymizeSubject bool
}
func (this *Log) flushSingle(sessionId string) (err error) {
session := this.smtpServerSessions[sessionId]
delete(this.smtpServerSessions, sessionId)
if this.CSVWriter != nil {
if err := this.CSVWriter.Write(session.csv()); err != nil {
return err
}
}
return
}
func (this *Log) flush(timeout time.Duration, timestamp time.Time) (err error) {
outerLoop:
for {
for id, session := range this.smtpServerSessions {
if timestamp.Sub(session.Timestamp) >= timeout {
err = this.flushSingle(id)
if err != nil {
return
}
continue outerLoop
}
}
break
}
return
}
func (this *Log) Parse(r io.Reader) (err error) {
this.smtpServerSessions = map[string]*SMTPServerSession{}
textreader := bufio.NewScanner(r)
textreader.Scan()
thisLine := textreader.Text()
nextLine := ""
var session *SMTPServerSession
if this.CSVWriter != nil {
if err = this.CSVWriter.Write(sessionCSVHeader); err != nil {
return
}
}
for {
hasNextLineAvailable := textreader.Scan()
if hasNextLineAvailable {
nextLine = textreader.Text()
// Try parsing first two fields of the upcoming line. If it doesn't
// work, assume leakage of previous line content.
fields := strings.Fields(nextLine)
if len(fields) < 2 {
// this is a continuation (too few fields)
thisLine = strings.TrimSpace(thisLine) + nextLine
continue
}
_, err = time.Parse("02-01-2006 15:04:05", strings.Join(fields[0:2], " "))
if err != nil {
// this is a continuation (first two fields don't follow usual line syntax)
err = nil
thisLine = strings.TrimSpace(thisLine) + nextLine
continue
}
}
if len(strings.TrimSpace(thisLine)) > 0 {
fields := strings.Fields(thisLine)
if len(fields) < 2 {
log.Print("WARNING: Found a line with less than 2 fields to work with. Skipping:", thisLine)
} else {
timestamp, err := time.Parse("02-01-2006 15:04:05", strings.Join(fields[0:2], " "))
if err != nil {
// first two fields don't follow usual line syntax
return err
}
serviceName := fields[3]
sessionId := ""
messageId := ""
logMessage := ""
logMessageStartIndex := 4
logMessageEndIndex := len(fields)
// Is the session ID stored in the message?
// For this, fields[4] needs to start with [ and needs to contain an 8-char long ID.
if strings.HasPrefix(fields[4], "[") &&
strings.HasSuffix(fields[4], "]") &&
len(fields[4]) == 1+8+1 {
// Yup, there's an ID here!
sessionId = fields[4][1:9]
logMessageStartIndex = 5
}
// Check if there is a message ID at the end of the log message
messageIdPart := strings.TrimRight(fields[len(fields)-1], ".")
if strings.HasPrefix(messageIdPart, "(") &&
strings.HasSuffix(messageIdPart, ")") &&
len(messageIdPart) == 1+11+1 {
// Yup, there's a message ID!
messageId = messageIdPart[1:12]
logMessageEndIndex--
} else if strings.HasPrefix(fields[logMessageStartIndex], "(") &&
strings.HasSuffix(fields[logMessageStartIndex], ")") &&
len(fields[logMessageStartIndex]) == 1+11+1 {
// Message ID but in fields[logMessageStartIndex], so shift start of log message
messageId = fields[logMessageStartIndex][1:12]
logMessageStartIndex++
}
logMessage = strings.Join(fields[logMessageStartIndex:logMessageEndIndex], " ")
//log.Println(serviceName, "-", sessionId, "-", messageId, "-", logMessage)
switch serviceName {
case "SMTPClient":
// Could contain success message for delivery
//log.Println(">> parsing for delivery success")
if rxSuccessfulMessage.MatchString(logMessage) {
//log.Println(">> got delivery success!")
session = this.FindSMTPServerSessionByMessageId(messageId, timestamp)
if session == nil {
log.Println("WARNING: Found a delivery success message for a message we don't know:", logMessage)
break
}
session.IsSent = true
// immediately unregister
if err = this.flushSingle(session.SMTPServerSessionID); err != nil {
return err
}
}
// Could contain sender
subm := rxSendMailFrom.FindStringSubmatch(logMessage)
if subm != nil {
session = this.FindSMTPServerSessionByMessageId(messageId, timestamp)
if session == nil {
log.Println("WARNING: Found a log line about the sender for a passed message we don't know:", logMessage)
break
}
session.SenderAddress = subm[1]
break
}
// Could contain recipient
subm = rxSendRcptTo.FindStringSubmatch(logMessage)
if subm != nil {
session = this.FindSMTPServerSessionByMessageId(messageId, timestamp)
if session == nil {
log.Println("WARNING: Found a log line about the recipient for a passed message we don't know:", logMessage)
break
}
session.RecipientAddress = subm[1]
break
}
case "SMTPServer":
if len(sessionId) > 0 {
session = this.createOrFetchSMTPServerSession(sessionId, timestamp)
}
// Could contain recipient
subm := rxRecipientAddress.FindStringSubmatch(logMessage)
//log.Println(">> parsing for recipient")
if subm != nil {
//log.Println(">> got recipient")
// We got submatches, this has a recipient!
session.RecipientAddress = subm[1]
break
}
// Could contain sender
subm = rxSenderAddress.FindStringSubmatch(logMessage)
//log.Println(">> parsing for sender")
if subm != nil {
//log.Println(">> got sender")
// We got submatches, this has a sender!
session.SenderAddress = subm[1]
break
}
// Could have metadata about message ID
//log.Println(">> parsing for message ID map")
if len(messageId) > 0 {
//log.Println(">> got message ID map 1")
subm = rxMapMessageID.FindStringSubmatch(logMessage)
if subm != nil {
//log.Println(">> got message ID map 2")
// We got submatches, this lets us map session ID to message ID!
session.MessageID = messageId
//log.Println(messageId, "->", sessionId)
break
}
}
case "SBL-Filter", "SWL-Filter":
// Could contain the subject
//log.Println(">> parsing for subject")
subm := rxSubject.FindStringSubmatch(logMessage)
if subm != nil {
//log.Println(">> got subject")
// We got submatches, this has a subject!
subject := subm[1]
session = this.FindSMTPServerSessionByMessageId(messageId, timestamp)
if session == nil {
log.Println("WARNING: Found a subject line for a message we don't know:", logMessage)
break
}
if this.AnonymizeSubject {
session.Subject = AnonymizedText
} else {
session.Subject = subject
}
}
}
this.flush(maxMessageAge, timestamp)
}
}
if !hasNextLineAvailable {
break
}
thisLine = nextLine
}
this.flush(0, time.Now())
if this.CSVWriter != nil {
this.CSVWriter.Flush()
}
/*if err = textreader.Err(); err != nil {
return
}*/
err = textreader.Err()
return
}
func (this *Log) createOrFetchSMTPServerSession(sessionId string, timestamp time.Time) (session *SMTPServerSession) {
if len(sessionId) <= 0 {
panic("Empty session ID")
}
session, ok := this.smtpServerSessions[sessionId]
if !ok {
session = &SMTPServerSession{
SMTPServerSessionID: sessionId,
Timestamp: timestamp,
}
this.smtpServerSessions[sessionId] = session
}
return
}
func (this *Log) FindSMTPServerSessionByMessageId(messageId string, timestamp time.Time) (session *SMTPServerSession) {
for _, currentSession := range this.smtpServerSessions {
if currentSession.IsMatchByMessageId(messageId, timestamp) {
return currentSession
}
}
return nil
}