Help with Interpreting Log File(s)

Use this forum if you have installed hMailServer and want to ask a question related to a production release of hMailServer. Before posting, please read the troubleshooting guide. A large part of all reported issues are already described in detail here.
Post Reply
RangerRik1
Normal user
Normal user
Posts: 62
Joined: 2007-01-11 22:26
Location: Florida

Help with Interpreting Log File(s)

Post by RangerRik1 » 2014-07-20 03:06

Hello all,
I need some help (or at least verification). I've been asked to perform an "email audit" for one of my commercial accounts. It appears there is going to be a legal hearing and I have been asked to review email records to help with the case.

In particular, my client is asking for any evidence relating to an employee {we'll say "Target User" for the anonymous examples I have prepared below}, in regards to tracking the date and time(s) the user can be identified as sending -and/or- receiving/checking email.

That is, my client wants to know WHEN the user ran their email software, which was outlook 2010, to either send a new email message (SMTP) -or- check for new email (POP).

It is my understanding the hmail log files can be used for this purpose. Correct?

My email server log files are HUGE. In fact, we are talking about over 100GB for the time frame being investigated.

To help narrow the scope, I wrote a quick script which scans the original hmail log files and outputs any lines containing the target user's email address to a much more manageable small "log".

Here is an example for two days scan results:

Analyzing: mailserver_2013-09-03.log
"POP3D" 2200 203359 "2013-09-03 10:30:27.003" "{protected ip address}" "RECEIVED: USER targetuser@thetargetdomain.com"
"SMTPD" 2204 203576 "2013-09-03 10:36:24.972" "{protected ip address}" "RECEIVED: MAIL FROM: [targetuser@thetargetdomain.com]"
"SMTPD" 2216 203576 "2013-09-03 10:36:31.237" "{protected ip address}" "RECEIVED: MAIL FROM: [targetuser@thetargetdomain.com]"
"SMTPC" 2212 203583 "2013-09-03 10:36:50.003" "{protected ip address2}" "SENT: MAIL FROM:[targetuser@thetargetdomain.com]"
"POP3D" 2200 204491 "2013-09-03 11:00:44.956" "{protected ip address}" "RECEIVED: USER targetuser@thetargetdomain.com"
"SMTPD" 2212 205091 "2013-09-03 11:17:44.065" "{protected ip address3}" "RECEIVED: RCPT TO: [targetuser@thetargetdomain.com]"
"POP3D" 2200 205614 "2013-09-03 11:30:55.519" "{protected ip address}" "RECEIVED: USER targetuser@thetargetdomain.com"
"POP3D" 2224 206785 "2013-09-03 12:01:08.487" "{protected ip address}" "RECEIVED: USER targetuser@thetargetdomain.com"
"POP3D" 2232 219589 "2013-09-03 18:31:51.717" "{protected ip address}" "RECEIVED: USER targetuser@thetargetdomain.com"
"POP3D" 2196 219680 "2013-09-03 18:36:47.326" "{protected ip address}" "RECEIVED: USER targetuser@thetargetdomain.com"
Total Hits Found: 10

Analyzing: mailserver_2013-09-04.log
"SMTPD" 2196 236152 "2013-09-04 09:09:20.774" "{protected ip address}" "RECEIVED: RCPT TO: [targetuser@thetargetdomain.com]"
"SMTPD" 2224 236152 "2013-09-04 09:09:24.524" "{protected ip address}" "RECEIVED: RCPT TO: [targetuser@thetargetdomain.com]"
"SMTPD" 2204 236178 "2013-09-04 09:10:04.290" "{protected ip address}" "RECEIVED: RCPT TO: [targetuser@thetargetdomain.com]"
"SMTPD" 2196 236178 "2013-09-04 09:10:07.040" "{protected ip address}" "RECEIVED: RCPT TO: [targetuser@thetargetdomain.com]"
"SMTPD" 2208 236221 "2013-09-04 09:11:27.462" "{protected ip address}" "RECEIVED: RCPT TO: [targetuser@thetargetdomain.com]"
"SMTPD" 2228 236221 "2013-09-04 09:11:31.243" "{protected ip address}" "RECEIVED: RCPT TO: [targetuser@thetargetdomain.com]"
"SMTPD" 2200 236283 "2013-09-04 09:12:42.978" "{protected ip address}" "RECEIVED: RCPT TO: [targetuser@thetargetdomain.com]"
"SMTPD" 2208 236283 "2013-09-04 09:12:46.228" "{protected ip address}" "RECEIVED: RCPT TO: [targetuser@thetargetdomain.com]"
"SMTPD" 2204 236299 "2013-09-04 09:12:59.040" "{protected ip address}" "RECEIVED: RCPT TO: [targetuser@thetargetdomain.com]"
"SMTPD" 2212 236299 "2013-09-04 09:13:01.790" "{protected ip address}" "RECEIVED: RCPT TO: [targetuser@thetargetdomain.com]"
"SMTPD" 2216 237983 "2013-09-04 09:58:48.821" "{protected ip address4}" "RECEIVED: RCPT TO:[targetuser@thetargetdomain.com]"
"POP3D" 2212 238026 "2013-09-04 10:00:27.540" "{protected ip address5}" "SENT: Target Username [targetuser@thetargetdomain.com], "
"POP3D" 2224 238398 "2013-09-04 10:10:35.634" "{protected ip address6}" "SENT: Target Username [targetuser@thetargetdomain.com], "
"POP3D" 2208 246363 "2013-09-04 13:55:47.135" "{protected ip address}" "RECEIVED: USER targetuser@thetargetdomain.com"
"POP3D" 2212 246433 "2013-09-04 13:57:39.010" "{protected ip address}" "RECEIVED: USER targetuser@thetargetdomain.com"
Total Hits Found: 15

My question(s) relate to properly interpreting the log file lines as shown above.

ANY HELP YOU ALL CAN PROVIDE ME ANSWERING THESE QUESTIONS IS GREATLY APPRECIATED. I want to make sure I am delivering accurate information to the courts.

#1 - Is it true that any lines beginning with "POP3D" prove that the user is running the email client and is checking (send and receive in outlook) their email? (checking for new email)

#2 - Is it true that any SMTPD lines stating "Received: Mail From: Targetuser@thetargetdomain.com" is hmail receiving an outbound message from the target user's email client to send out? (Ie: the user is sending a new message?)

#3 - Is it true that any SMTPD lines stating "Received: Rcpt to: Targetuser@thetargetdomain.com" is hmail receiving an inbound messsage for the target user from any source? (ie: inbound message from a foreign mail server or device - and hmail will save the inbound message in the user's mailbox?)

#4 - Is it true the any SMTPC lines stating "SENT: MAIL FROM:targetuser@thetargetdomain.com" is hmail DELIVERING an outbound message from the target user to the recipient's mail server?

Thanks again for any help or tips...

--Rick

User avatar
mattg
Moderator
Moderator
Posts: 20111
Joined: 2007-06-14 05:12
Location: 'The Outback' Australia

Re: Help with Interpreting Log File(s)

Post by mattg » 2014-07-20 10:54

Yes to all, with some caveats

#1 & #2 could be someone PRETENDING to be said user, you would need to check the IP address in that line
That line alone doesn't mean mail was accepted, just that someone tried to send from that address

#3 Again, these lines may not actually result in mail being delivered. This suggests that someone is trying to send to that user. The message may get dumped for Anti-SPAM or AV reasons

#4 Again, this is an attempt to send, but may well be rejected.

You will need to search for the entire conversation in the mail logs.

This may help clarify >> http://log.damnation.org.uk/
But you can't upload 100 Mb of data in one hit. You will need to feed smaller chuncks
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation

^DooM^
Site Admin
Posts: 13861
Joined: 2005-07-29 16:18
Location: UK

Re: Help with Interpreting Log File(s)

Post by ^DooM^ » 2014-07-20 11:00

He said 100GB which is in an insane amount of log space. how many domains/users roughly do you have RangerRik?
If at first you don't succeed, bomb disposal probably isn't for you! ヅ

User avatar
mattg
Moderator
Moderator
Posts: 20111
Joined: 2007-06-14 05:12
Location: 'The Outback' Australia

Re: Help with Interpreting Log File(s)

Post by mattg » 2014-07-20 11:06

Oh, you are correct.

100 MB is large in my books. 100 Gb is mind numbing.
You'd need a dedicated drive just for the log file...
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation

RangerRik1
Normal user
Normal user
Posts: 62
Joined: 2007-01-11 22:26
Location: Florida

Re: Help with Interpreting Log File(s)

Post by RangerRik1 » 2014-07-20 17:02

I currently have 40 domains. Most are 20 users or less, however, one has 180 users and another has 80 users. Last time we checked was about 6 months ago and we had approximately 350 users.

I periodically ZIP up the log files, which compress well. A typical day's log file is 150Mb to 200Mb.

Also I'm looking at a 9-12 month time frame. Thus I needed a script to do the heavy searching...

Thanks for the information--much appreciated.

RangerRik1
Normal user
Normal user
Posts: 62
Joined: 2007-01-11 22:26
Location: Florida

Re: Help with Interpreting Log File(s)

Post by RangerRik1 » 2014-07-21 22:46

Can someone explain the difference between these two lines?

"POP3D" 2200 203359 "2013-09-03 10:30:27.003" "{Protected IP1}" "RECEIVED: USER targetuser@thetargetdomain.com"

"POP3D" 2212 238026 "2013-09-04 10:00:27.540" "{Protected IP2}" "SENT: User Name [targetuser@thetargetdomain.com], "

What is going on, in the POP "conversation" that leads to "Received: User..." and "Send" User..."?

Again, thanks for any assistance.

--Rick

percepts
Senior user
Senior user
Posts: 5282
Joined: 2009-10-20 16:33
Location: Sceptred Isle

Re: Help with Interpreting Log File(s)

Post by percepts » 2014-07-22 00:07

RECEIVED: USER is part of POP3 handshake with client (identification/authentication of who the user is)
SENT: is hmail saying its sent something to email client.

i.e. the conversation that takes place between client and hmail to establish a connection to a specific user. Client sending USER and hmail sending back user for client to be sure its talking to same user on hmail. Maybe accompanied with authentication.

User avatar
mattg
Moderator
Moderator
Posts: 20111
Joined: 2007-06-14 05:12
Location: 'The Outback' Australia

Re: Help with Interpreting Log File(s)

Post by mattg » 2014-07-22 01:06

RangerRik1 wrote:Can someone explain the difference between these two lines?

"POP3D" 2200 203359 "2013-09-03 10:30:27.003" "{Protected IP1}" "RECEIVED: USER targetuser@thetargetdomain.com"

"POP3D" 2212 238026 "2013-09-04 10:00:27.540" "{Protected IP2}" "SENT: User Name [targetuser@thetargetdomain.com], "

What is going on, in the POP "conversation" that leads to "Received: User..." and "Send" User..."?

Again, thanks for any assistance.

--Rick
Can you show the dozen or two lines prior to the bottom one?
Are you sure that it is POP3D and not POP3C?
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation

RangerRik1
Normal user
Normal user
Posts: 62
Joined: 2007-01-11 22:26
Location: Florida

Re: Help with Interpreting Log File(s)

Post by RangerRik1 » 2014-07-26 16:26

Sorry--I haven't had time to review the big log files but I will and post the full "conversation" soon.

In the meantime, could you explain (in general) the difference between POPD and POPC?

(I'm assuming it is "POP-delivery" and "POP-client") ... Would POPC only occur if hmail is configured to retrieve emails from a third party server? -- correct?

User avatar
mattg
Moderator
Moderator
Posts: 20111
Joined: 2007-06-14 05:12
Location: 'The Outback' Australia

Re: Help with Interpreting Log File(s)

Post by mattg » 2014-07-27 00:58

Yep, you're correct
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation

^DooM^
Site Admin
Posts: 13861
Joined: 2005-07-29 16:18
Location: UK

Re: Help with Interpreting Log File(s)

Post by ^DooM^ » 2014-07-27 01:16

Always thought the D stood for Deamon myself, learn something new every day :D
If at first you don't succeed, bomb disposal probably isn't for you! ヅ

User avatar
mattg
Moderator
Moderator
Posts: 20111
Joined: 2007-06-14 05:12
Location: 'The Outback' Australia

Re: Help with Interpreting Log File(s)

Post by mattg » 2014-07-27 02:10

OK, you are more correct

I always see D as receive, C as fetch
RangerRik1 wrote:Would POPC only occur if hmail is configured to retrieve emails from a third party server? -- correct?
mattg wrote:Yep, you're correct
Just 'cause I link to a page and say little else doesn't mean I am not being nice.
https://www.hmailserver.com/documentation

Post Reply