We'd love to hear about it! Click here to go to the product suggestion community
I am having some issues parsing the logs from the appliance i've got the majority off them sorted, its just the Message log I am having issues with.
Can anyone point me in the direction of a document or let me know what the fields are in log entries?
shows examples, but unlike the equivalent one for the Web appliance, (http://wsa.sophos.com/docs/wsa/webhelp/index.html#swa/concepts/InterpretingLogFiles.html)
it doesnt give you the key to the logs
I am trying to get them normalised so i can pass them into our SIEM, I can make educated guesses, but
"p=0.151 fur=184.108.40.206 r=220.127.116.11 tm=0.23 a=d/eom" means little to me
I guess I should really create a KB for that, good question.
In short there are 2 logs, the first is the MTA (postfix) log and the second is called the milter log (aka policy results)
When email is sent or received it flows through the appliance..
postfix accepts message into the front end mail queue
the queue process in turn delivers the message to the milter (127.0.0.1) 10025
the milter generates the maillog / policy hits
the message is delivered to the back end mail queue
back end queue to downstream relay.
When you search in the UI under mail logs, the appliance gatheres all of these parts and stuffs it into the UI.. In the actual logs there is no separation.
Postfix accepts message into the Front end queue, the first thing it does is assigns it a message ID:
2017-09-19 20:16:53 sea postfix/smtpd: 983E535C74_9C1DDA5F: client=unknown[192.168.5.8]2017-09-19 20:16:53 sea postfix/cleanup: 983E535C74_9C1DDA5F: message-id=<Odi01t29zW-FrYtzM_LUvKgBqiu13gezcxOO45G6eeg.EDqpQPe0B4DBGbfP-Uynf9adw653dqYeLB5Rjs7WTCg@toughhstjn.com>2017-09-19 20:16:53 sea postfix/qmgr: 983E535C74_9C1DDA5F: from=<firstname.lastname@example.org>, size=13247, nrcpt=1 (queue active)2017-09-19 20:18:34 sea postfix/smtp: 983E535C74_9C1DDA5F: to=<email@example.com>, relay=127.0.0.1[127.0.0.1]:10025, delay=101, delays=0.09/0.07/0.19/101, dsn=2.0.0, status=sent (250 OK, sent 59C1DDA5_2428_1_1 988DA38A83_9C1DE0AB)2017-09-19 20:18:34 sea postfix/qmgr: 983E535C74_9C1DDA5F: removed
the above says, message X arrived from the client 192.168.5.8 to: from: the relay is the loopback device. the removed part sais that the message cleared the milter process.
2017-09-19 20:18:34 sea postfix/backend/smtpd: 988DA38A83_9C1DE0AB: client=localhost.localdomain[127.0.0.1]
then the milter spits up the message to the back end mail queue, the id is changed from F as above to B .. indicating the frontend and backend mail queues.
2017-09-19 20:18:34 sea postfix/backend/cleanup: 988DA38A83_9C1DE0AB: message-id=<Odi01t29zW-FrYtzM_LUvKgBqiu13gezcxOO45G6eeg.EDqpQPe0B4DBGbfP-Uynf9adw653dqYeLB5Rjs7WTCg@toughhstjn.com>2017-09-19 20:18:34 sea postfix/backend/qmgr: 988DA38A83_9C1DE0AB: from=<firstname.lastname@example.org>, size=16205, nrcpt=1 (queue active)2017-09-19 20:18:35 sea postfix/backend/smtp: 988DA38A83_9C1DE0AB: to=<email@example.com>, relay=192.168.5.8[192.168.5.8]:25, delay=0.7, delays=0.23/0.1/0.31/0.06, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as C20A3E03D5)
this is the delivery receipt and SMTP code (250 2.0.0 aka delivered)
2017-09-19 20:18:35 sea postfix/backend/qmgr: 988DA38A83_9C1DE0AB: removed
message cleared the back end mail queue
Thats the mail log, every message will have at least 1 part.. if the milter deletes a message for spam, there would be a NO_FORWARD message instead of REMOVED
This is the log output of policy based on when postfix delivers the message to the milter. For the most part, most of this log will mean absolutely nothing to you. I have highlighted the good bits.
2017-09-20T03:19:14 q=59C1DE2D_2430_3_3 f=<firstname.lastname@example.org> t=<email@example.com> Rule=Deliver ME! type=rule b=ok DKIM-VERIFY=none action=deliver h=SXL_URI h=IMGSPAM_BODY h=DATE_IN_PAST_96_XX h=HTML_70_90 h=BODYTEXTH_SIZE_10000_LESS h=BODYTEXTH_SIZE_3000_MORE h=BODYTEXTP_SIZE_3000_LESS h=BODY_SIZE_6000_6999 h=BODY_SIZE_7000_LESS h=DATE_TZ_NA h=LINK_TO_IMAGE h=NO_URI_HTTPS h=URI_WITH_PATH_ONLY h=__ANY_URI h=__BAT_BOUNDARY h=__CP_URI_IN_BODY h=__CT h=__CTYPE_HAS_BOUNDARY h=__CTYPE_MULTIPART h=__CTYPE_MULTIPART_ALT h=__HAS_FROM h=__HAS_HTML h=__HAS_MSGID h=__HTML_AHREF_TAG h=__HTML_TAG_DIV h=__HTML_TAG_IMG_X2 h=__HTTP_IMAGE_TAG h=__IMGSPAM_BODY h=__MIME_HTML h=__MIME_TEXT_H h=__MIME_TEXT_H1 h=__MIME_TEXT_H2 h=__MIME_TEXT_P h=__MIME_TEXT_P1 h=__MIME_TEXT_P2 h=__MIME_VERSION h=__MULTIPLE_URI_HTML h=__MULTIPLE_URI_TEXT h=__RATWARE_SIGNATURE_3 h=__RATWARE_SIGNATURE_3_N1 h=__SANE_MSGID h=__SUBJ_ALPHA_END h=__TAG_EXISTS_HTML h=__TO_MALFORMED_2 h=__TO_NO_NAME h=__URI_IN_BODY h=__URI_NOT_IMG h=__URI_NO_MAILTO h=__URI_NO_WWW h=__URI_NS h=__URI_WITH_PATH inbound p=0.803 S=?q?Regrow_thicker_and_fuller_hair fur= r=192.168.5.8 tm=4.22 a=a/eom
q = message id from the front end queue
f = From
t = to
Rule = the highest prioirty rule hit with an action of either quarantine, discard or deliver
DKIM-VERIFY = results of dkim hashing
Action = Deliver (this could be quarantine or discard)
p = Spam score .. (0.803 = 80.3% spam)
s = subject
fur = first untrusted relay IP address (usually the envelope sender unless you have trusted relays configured)
tm = time the message took to scan (i keep debug on so it took 4.2 seconds)
Everything else in this log will translate into absolutely nothing, so don't even bother trying to "decode" it because In short .. it is the collection of spam / labs rules that were triggered, the exact formula is not meant to be analysed and changes all the time.
In reply to Red_Warrior:
cheers, more than i needed, but this will get the right stuff into our SIEM :)
hi sir your comment here really helped me. i wanted to know what is r= and b= here.
In reply to jenish r:
Glad to help.
Not sure about the b= .. I believe its a labs internal check that has something to do with AV results.
the r= is the ip of the last mta that relayed the message. In most cases it with also be the same as the FUR unless the ip is whitelisted.