loggfil-hacking med Ruby


tirsdag 20. september 2011 Ruby

loggfilhacking

Ruby er et perfekt språk til å lage små verktøy for å automatisere ting man som gode utviklere uansett bør være for late til å gjøre manuelt. Jeg bruker først og fremst Ruby til å lage små scripts som hjelper meg i bygging og/eller deployment av prosjekter, men jeg lager endel andre scripts også. Tenkte nå jeg skulle vise frem ett av dem.

I denne blogposten vil du se et enkelt script som leser loggfiler fra en webapplikasjon, og presenterer en rapport med oversikt over aggregerte data fra loggene. Målet er ikke å vise noe som helst revolusjonerende eller fantastisk – jeg vil bare dele litt kode, og kanskje inspirere flere til å automatisere slike ting.

Loggfilene

Filene jeg skal rapportere på er hentet fra en ASP.NET app som bruker log4net til logging. Her er en liten eksempelfil:


2011-09-06 00:33:43,821 [1] INFO  APPLICATION STARTED
2011-09-06 00:33:45,075 [5] DEBUG Default.aspx (loading..) | 4666/acme/PROD1
2011-09-06 00:33:50,043 [6] DEBUG Report.aspx (loading..) | 4666/acme/PROD1
2011-09-06 00:33:57,680 [5] DEBUG Report.aspx (loading..) | 4666/acme/PROD1
2011-09-06 00:33:57,726 [5] INFO  Loading report "Traffic report (monthly)" | 4666/acme/PROD1
2011-09-06 01:01:07,555 [5] DEBUG Default.aspx (loading..) | 1233/foobar/PROD1
2011-09-06 01:01:41,472 [6] DEBUG Report.aspx (loading..) | 1233/foobar/PROD1
2011-09-06 01:01:57,638 [9] DEBUG Report.aspx (loading..) | 1233/foobar/PROD1
2011-09-06 01:01:57,681 [9] INFO  Loading report "Incoming traffic report (weekly)" | 1233/foobar/PROD1
2011-09-06 01:02:18,194 [6] INFO  Loading report "Keyword period statistics" | 1233/foobar/PROD1

Her er det mye nyttig informasjon jeg gjerne vil rapportere på. Hver gang en side lastes logges det en debug-linje med sidens navn, og på slutten av linjen legges det på informasjon om brukeren. Og hver gang en bruker kjører en rapport logges det en info-linje med rapportens navn.

Webapplikasjonen genererer én ny logfil hver dag. De har et fast navn, med datoen lagt på som et suffix. Dagens logg heter MyWebApp.log, loggen for i går heter MyWebApp.log20110910, osv. Skriptet som analyserere filene må kunne slå sammen data fra et vilkårlig antall logfiler.

Resultatet

Jeg ønsker en tredelt rapport basert på disse logfilene. For det første ønsker jeg å vite hvor mange ganger de ulike sidene har blitt lastet. Deretter vil jeg vite hvilke brukere som er mest aktive, og til slutt vil jeg vite hvilke rapporter som kjøres flest ganger.

Scriptet mitt skal printe ut rapporten til konsollet. Ønsker jeg å lagre rapporten kan jeg da enkelt "pipe" output til en fil i stedet. Her er output basert på filen ovenfor:

Analysing file MyWebApp.log

Page                                                    Hits
------------------------------------------------------------
Report                                                     4
Default                                                    2

User                                                    Hits
------------------------------------------------------------
foobar              PROD1  ID:1233                         5
acme                PROD1  ID:4666                         4

Report                                                  Hits
------------------------------------------------------------
Keyword period statistics                                  1
Incoming traffic report (weekly)                           1
Traffic report (monthly)                                   1

Scriptet

Jeg skal ikke si så alt for mye om koden – håper den klarer å stå på egne ben. Men jeg har delt den opp litt for å forenkle lesingen. Her er første chunk, som i hovedsak består av en main-metode som først validerer parametrene, deretter parser log-filene (linje 35) og til slutt skriver ut rapporten (37).

10 unless ARGV.length == 2
11   raise <<EOF
12 
13 
14 Usage:   mywebapp_stats.rb folder filepattern
15 
16 Example: mywebapp_stats.rb . AccountWeb.log*
17 
18 EOF
19 end
20 
21 $user_hash = {}
22 $page_hash = {}
23 $report_hash = {}
24 
25 def main
26   log_dir = ARGV[0]
27   files_pattern = ARGV[1]
28 
29   if File.directory?(log_dir)
30     Dir.chdir log_dir
31   else
32     raise "#{log_dir} is not a directory"
33   end
34 
35   Dir.glob(files_pattern).each { |f| parse_file f }
36 
37   report
38 end

Og så følger koden som parser selve logfilene. Parsingen er basert på regulære uttrykk, så det kan se litt kryptisk ut. Magien ligger i reg_count, som inkrementerer en teller i en hashtabell hvis det regulære uttrykket matcher linjen. inc_hash! gjør selve teller-inkrementeringen.

40 ### ANALYSE FILE STUFF ###############################################
41 
42 def parse_file filepath
43   puts "Analysing file #{filepath}"
44   File.open(filepath, "r") do |f|
45     while (line = f.gets)
46       reg_count(/Loading report "(.*)"/, line, $report_hash)
47       reg_count(/\| (\d+)\/(.*)\/(PROD[123])/, line, $user_hash) do |m|
48         m[0][1].ljust(20) + m[0][2] + "  ID:" + m[0][0]
49       end
50       reg_count(/ ([A-Za-z]+)\.aspx \(loading\.\.\)/, line, $page_hash)
51     end
52   end
53 end
54 
55 def reg_count pattern, line, hash, &block
56   match = line.scan pattern
57   if match.length > 0
58     key = block.call(match) if block
59     inc_hash! key || match[0][0], hash
60   end
61 end
62 
63 def inc_hash! k, h
64   n = h[k] || 0
65   h[k] = n + 1
66 end

Det eneste som gjenstår da er å skrive ut rapporten.

68 ### REPORT OUTPUT STUFF ###############################################
69 
70 def report
71   report_hash "Page", "Hits", $page_hash
72   report_hash "User", "Hits", $user_hash
73   report_hash "Report", "Hits", $report_hash
74 end
75 
76 def report_hash col_a, col_b, h
77   report_header col_a, col_b
78   h.
79     sort{|a,b| a[1] <=> b[1]}.
80     reverse.
81     each { |key, value| report_line(key, value) }
82 end
83 
84 def report_header col_a, col_b
85   puts
86   report_line col_a, col_b
87   puts "-" * 60
88 end
89 
90 def report_line a, b
91   puts a.ljust(50) + b.to_s.rjust(10)
92 end
93 
94 main # run the program

Spørsmål? Uforståelig? Elementært?

Her er noen andre eksempler på hva jeg bruker Ruby til: Script IIS Manager med IronRuby | Litt ADO.NET i IronRuby | Slette/tømme MSMQ-køer med IronRuby | En minimal HTTP-server i Ruby


comments powered by Disqus