Phasor Burn

A bit of log file analysis 101

Say you want to get a rough idea of how many email messages are being sent per minute at peak periods, and you just have the raw log file to work with.

In /var/log/messages you might have lines that look like this for each message successfully sent.

Sep 30 12:21:15 localhost postfix/smtp[12519]: 2C46876021B: to=<april.smith@example.com>, relay=172.16.15.20[172.16.15.20]:25, delay=0.18, delays=0.04/0/0/0.13, dsn=2.6.0, status=sent (250 2.6.0 <924313460.6041.1317406875180.JavaMail.jira@jira-prod> Queued mail for delivery)

Let’s break it down. First grab just the status=sent lines, and run it thru head to limit the output for now.

$ sudo cat /var/log/maillog | grep status=sent | head

Examine the result, looks like the lines you want? Good.

Next, print just the date stamp for each of those lines. We only want Month, Day, Hour, and Minute.

Here I take advantage of using the colon as field separator.

$ sudo cat /var/log/maillog | grep status=sent | awk -F: '{print $1" "$2 }' | head
Sep 25 08 04
Sep 25 08 04
Sep 26 04 02
Sep 26 11 41
Sep 26 11 43
Sep 26 11 43
Sep 26 11 43
Sep 26 11 43
Sep 26 11 43
Sep 26 11 43

Result look like what you want? No? tweak until it does. I want a colon between the hour and minutes.

$ sudo cat /var/log/maillog | grep status=sent | awk -F: '{print $1":"$2 }' | head

Sep 25 08:04
Sep 25 08:04
Sep 26 04:02
Sep 26 11:41
Sep 26 11:43
Sep 26 11:43
Sep 26 11:43
Sep 26 11:43
Sep 26 11:43
Sep 26 11:43

Now, count how many of each date stamp.

$ sudo cat /var/log/maillog | grep status=sent | awk -F: '{print $1":"$2 }' | sort | uniq -c | head

2 Sep 25 08:04
1 Sep 26 04:02
1 Sep 26 11:41
240 Sep 26 11:43
828 Sep 26 11:44
962 Sep 26 11:45
26 Sep 26 11:47
9 Sep 26 11:48
18 Sep 26 11:50
10 Sep 26 11:51

Alright, we’re nearly there. I’m interested in the peaks, remember. So lets just say anything over 99 is a peak.
You probably don’t need the sort as the log file was already sorted.

$ sudo cat /var/log/maillog | grep status=sent | awk -F: '{print $1":"$2 }' | uniq -c | awk '$1 > 99 {print}'
240 Sep 26 11:43
828 Sep 26 11:44
962 Sep 26 11:45
447 Sep 26 11:55
2058 Sep 26 11:57
180 Sep 26 12:11
187 Sep 26 12:26
126 Sep 26 14:07
132 Sep 26 15:07
156 Sep 26 16:08
132 Sep 27 06:07
120 Sep 27 10:05
143 Sep 27 11:07
101 Sep 27 11:24
114 Sep 27 12:05
125 Sep 27 14:06
155 Sep 27 15:05
262 Sep 28 09:06
126 Sep 28 10:06
115 Sep 28 11:04
239 Sep 28 14:06
151 Sep 28 16:05
100 Sep 28 18:27
108 Sep 29 06:06
118 Sep 29 08:25
152 Sep 29 09:06
126 Sep 29 10:04
102 Sep 29 11:07
144 Sep 29 11:25
134 Sep 29 12:06
210 Sep 29 15:06
101 Sep 30 06:05
105 Sep 30 08:43
233 Sep 30 09:06

That’s all I was interested in this time.

Easy Peasy. Just build your command line pipe line one bit at a time until you’ve got what you’re looking for.

I feel like I’m wanting to move in the opposite direction of ‘the cloud’.

I actually have some interest in landing an opportunity to work with the Z mainframe stuff (which I think can run AIX and Linux inside of LPAR or something). It’s not very likely to happen, but still.

I don’t know exactly why I want to do this.

Perhaps leveraging existing os and platform stability vs designing/implementing for constant chaos-monkey action is part of it.

The older I get, the less risk for ‘exciting times’ I seem to want to take on. The less I care about actual geeky bits and the more I want to just leverage my income for enabling my photography hobby, taking time to do other things, etc.

Must be my mid life crisis creeping up on me again. Must also be why I’m working in financial services industry right now. Hmm.