1*0076d546SFeng Tang# process_event.py: general event handler in python
2*0076d546SFeng Tang#
3*0076d546SFeng Tang# Current perf report is alreay very powerful with the anotation integrated,
4*0076d546SFeng Tang# and this script is not trying to be as powerful as perf report, but
5*0076d546SFeng Tang# providing end user/developer a flexible way to analyze the events other
6*0076d546SFeng Tang# than trace points.
7*0076d546SFeng Tang#
8*0076d546SFeng Tang# The 2 database related functions in this script just show how to gather
9*0076d546SFeng Tang# the basic information, and users can modify and write their own functions
10*0076d546SFeng Tang# according to their specific requirment.
11*0076d546SFeng Tang#
12*0076d546SFeng Tang# The first sample "show_general_events" just does a baisc grouping for all
13*0076d546SFeng Tang# generic events with the help of sqlite, and the 2nd one "show_pebs_ll" is
14*0076d546SFeng Tang# for a x86 HW PMU event: PEBS with load latency data.
15*0076d546SFeng Tang#
16*0076d546SFeng Tang
17*0076d546SFeng Tangimport os
18*0076d546SFeng Tangimport sys
19*0076d546SFeng Tangimport math
20*0076d546SFeng Tangimport struct
21*0076d546SFeng Tangimport sqlite3
22*0076d546SFeng Tang
23*0076d546SFeng Tangsys.path.append(os.environ['PERF_EXEC_PATH'] + \
24*0076d546SFeng Tang        '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
25*0076d546SFeng Tang
26*0076d546SFeng Tangfrom perf_trace_context import *
27*0076d546SFeng Tangfrom EventClass import *
28*0076d546SFeng Tang
29*0076d546SFeng Tang#
30*0076d546SFeng Tang# If the perf.data has a big number of samples, then the insert operation
31*0076d546SFeng Tang# will be very time consuming (about 10+ minutes for 10000 samples) if the
32*0076d546SFeng Tang# .db database is on disk. Move the .db file to RAM based FS to speedup
33*0076d546SFeng Tang# the handling, which will cut the time down to several seconds.
34*0076d546SFeng Tang#
35*0076d546SFeng Tangcon = sqlite3.connect("/dev/shm/perf.db")
36*0076d546SFeng Tangcon.isolation_level = None
37*0076d546SFeng Tang
38*0076d546SFeng Tangdef trace_begin():
39*0076d546SFeng Tang	print "In trace_begin:\n"
40*0076d546SFeng Tang
41*0076d546SFeng Tang        #
42*0076d546SFeng Tang        # Will create several tables at the start, pebs_ll is for PEBS data with
43*0076d546SFeng Tang        # load latency info, while gen_events is for general event.
44*0076d546SFeng Tang        #
45*0076d546SFeng Tang        con.execute("""
46*0076d546SFeng Tang                create table if not exists gen_events (
47*0076d546SFeng Tang                        name text,
48*0076d546SFeng Tang                        symbol text,
49*0076d546SFeng Tang                        comm text,
50*0076d546SFeng Tang                        dso text
51*0076d546SFeng Tang                );""")
52*0076d546SFeng Tang        con.execute("""
53*0076d546SFeng Tang                create table if not exists pebs_ll (
54*0076d546SFeng Tang                        name text,
55*0076d546SFeng Tang                        symbol text,
56*0076d546SFeng Tang                        comm text,
57*0076d546SFeng Tang                        dso text,
58*0076d546SFeng Tang                        flags integer,
59*0076d546SFeng Tang                        ip integer,
60*0076d546SFeng Tang                        status integer,
61*0076d546SFeng Tang                        dse integer,
62*0076d546SFeng Tang                        dla integer,
63*0076d546SFeng Tang                        lat integer
64*0076d546SFeng Tang                );""")
65*0076d546SFeng Tang
66*0076d546SFeng Tang#
67*0076d546SFeng Tang# Create and insert event object to a database so that user could
68*0076d546SFeng Tang# do more analysis with simple database commands.
69*0076d546SFeng Tang#
70*0076d546SFeng Tangdef process_event(param_dict):
71*0076d546SFeng Tang        event_attr = param_dict["attr"]
72*0076d546SFeng Tang        sample     = param_dict["sample"]
73*0076d546SFeng Tang        raw_buf    = param_dict["raw_buf"]
74*0076d546SFeng Tang        comm       = param_dict["comm"]
75*0076d546SFeng Tang        name       = param_dict["ev_name"]
76*0076d546SFeng Tang
77*0076d546SFeng Tang        # Symbol and dso info are not always resolved
78*0076d546SFeng Tang        if (param_dict.has_key("dso")):
79*0076d546SFeng Tang                dso = param_dict["dso"]
80*0076d546SFeng Tang        else:
81*0076d546SFeng Tang                dso = "Unknown_dso"
82*0076d546SFeng Tang
83*0076d546SFeng Tang        if (param_dict.has_key("symbol")):
84*0076d546SFeng Tang                symbol = param_dict["symbol"]
85*0076d546SFeng Tang        else:
86*0076d546SFeng Tang                symbol = "Unknown_symbol"
87*0076d546SFeng Tang
88*0076d546SFeng Tang        # Creat the event object and insert it to the right table in database
89*0076d546SFeng Tang        event = create_event(name, comm, dso, symbol, raw_buf)
90*0076d546SFeng Tang        insert_db(event)
91*0076d546SFeng Tang
92*0076d546SFeng Tangdef insert_db(event):
93*0076d546SFeng Tang        if event.ev_type == EVTYPE_GENERIC:
94*0076d546SFeng Tang                con.execute("insert into gen_events values(?, ?, ?, ?)",
95*0076d546SFeng Tang                                (event.name, event.symbol, event.comm, event.dso))
96*0076d546SFeng Tang        elif event.ev_type == EVTYPE_PEBS_LL:
97*0076d546SFeng Tang                event.ip &= 0x7fffffffffffffff
98*0076d546SFeng Tang                event.dla &= 0x7fffffffffffffff
99*0076d546SFeng Tang                con.execute("insert into pebs_ll values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)",
100*0076d546SFeng Tang                        (event.name, event.symbol, event.comm, event.dso, event.flags,
101*0076d546SFeng Tang                                event.ip, event.status, event.dse, event.dla, event.lat))
102*0076d546SFeng Tang
103*0076d546SFeng Tangdef trace_end():
104*0076d546SFeng Tang	print "In trace_end:\n"
105*0076d546SFeng Tang        # We show the basic info for the 2 type of event classes
106*0076d546SFeng Tang        show_general_events()
107*0076d546SFeng Tang        show_pebs_ll()
108*0076d546SFeng Tang        con.close()
109*0076d546SFeng Tang
110*0076d546SFeng Tang#
111*0076d546SFeng Tang# As the event number may be very big, so we can't use linear way
112*0076d546SFeng Tang# to show the histgram in real number, but use a log2 algorithm.
113*0076d546SFeng Tang#
114*0076d546SFeng Tang
115*0076d546SFeng Tangdef num2sym(num):
116*0076d546SFeng Tang        # Each number will have at least one '#'
117*0076d546SFeng Tang        snum = '#' * (int)(math.log(num, 2) + 1)
118*0076d546SFeng Tang        return snum
119*0076d546SFeng Tang
120*0076d546SFeng Tangdef show_general_events():
121*0076d546SFeng Tang
122*0076d546SFeng Tang        # Check the total record number in the table
123*0076d546SFeng Tang        count = con.execute("select count(*) from gen_events")
124*0076d546SFeng Tang        for t in count:
125*0076d546SFeng Tang                print "There is %d records in gen_events table" % t[0]
126*0076d546SFeng Tang                if t[0] == 0:
127*0076d546SFeng Tang                        return
128*0076d546SFeng Tang
129*0076d546SFeng Tang        print "Statistics about the general events grouped by thread/symbol/dso: \n"
130*0076d546SFeng Tang
131*0076d546SFeng Tang         # Group by thread
132*0076d546SFeng Tang        commq = con.execute("select comm, count(comm) from gen_events group by comm order by -count(comm)")
133*0076d546SFeng Tang        print "\n%16s %8s %16s\n%s" % ("comm", "number", "histgram", "="*42)
134*0076d546SFeng Tang        for row in commq:
135*0076d546SFeng Tang             print "%16s %8d     %s" % (row[0], row[1], num2sym(row[1]))
136*0076d546SFeng Tang
137*0076d546SFeng Tang        # Group by symbol
138*0076d546SFeng Tang        print "\n%32s %8s %16s\n%s" % ("symbol", "number", "histgram", "="*58)
139*0076d546SFeng Tang        symbolq = con.execute("select symbol, count(symbol) from gen_events group by symbol order by -count(symbol)")
140*0076d546SFeng Tang        for row in symbolq:
141*0076d546SFeng Tang             print "%32s %8d     %s" % (row[0], row[1], num2sym(row[1]))
142*0076d546SFeng Tang
143*0076d546SFeng Tang        # Group by dso
144*0076d546SFeng Tang        print "\n%40s %8s %16s\n%s" % ("dso", "number", "histgram", "="*74)
145*0076d546SFeng Tang        dsoq = con.execute("select dso, count(dso) from gen_events group by dso order by -count(dso)")
146*0076d546SFeng Tang        for row in dsoq:
147*0076d546SFeng Tang             print "%40s %8d     %s" % (row[0], row[1], num2sym(row[1]))
148*0076d546SFeng Tang
149*0076d546SFeng Tang#
150*0076d546SFeng Tang# This function just shows the basic info, and we could do more with the
151*0076d546SFeng Tang# data in the tables, like checking the function parameters when some
152*0076d546SFeng Tang# big latency events happen.
153*0076d546SFeng Tang#
154*0076d546SFeng Tangdef show_pebs_ll():
155*0076d546SFeng Tang
156*0076d546SFeng Tang        count = con.execute("select count(*) from pebs_ll")
157*0076d546SFeng Tang        for t in count:
158*0076d546SFeng Tang                print "There is %d records in pebs_ll table" % t[0]
159*0076d546SFeng Tang                if t[0] == 0:
160*0076d546SFeng Tang                        return
161*0076d546SFeng Tang
162*0076d546SFeng Tang        print "Statistics about the PEBS Load Latency events grouped by thread/symbol/dse/latency: \n"
163*0076d546SFeng Tang
164*0076d546SFeng Tang        # Group by thread
165*0076d546SFeng Tang        commq = con.execute("select comm, count(comm) from pebs_ll group by comm order by -count(comm)")
166*0076d546SFeng Tang        print "\n%16s %8s %16s\n%s" % ("comm", "number", "histgram", "="*42)
167*0076d546SFeng Tang        for row in commq:
168*0076d546SFeng Tang             print "%16s %8d     %s" % (row[0], row[1], num2sym(row[1]))
169*0076d546SFeng Tang
170*0076d546SFeng Tang        # Group by symbol
171*0076d546SFeng Tang        print "\n%32s %8s %16s\n%s" % ("symbol", "number", "histgram", "="*58)
172*0076d546SFeng Tang        symbolq = con.execute("select symbol, count(symbol) from pebs_ll group by symbol order by -count(symbol)")
173*0076d546SFeng Tang        for row in symbolq:
174*0076d546SFeng Tang             print "%32s %8d     %s" % (row[0], row[1], num2sym(row[1]))
175*0076d546SFeng Tang
176*0076d546SFeng Tang        # Group by dse
177*0076d546SFeng Tang        dseq = con.execute("select dse, count(dse) from pebs_ll group by dse order by -count(dse)")
178*0076d546SFeng Tang        print "\n%32s %8s %16s\n%s" % ("dse", "number", "histgram", "="*58)
179*0076d546SFeng Tang        for row in dseq:
180*0076d546SFeng Tang             print "%32s %8d     %s" % (row[0], row[1], num2sym(row[1]))
181*0076d546SFeng Tang
182*0076d546SFeng Tang        # Group by latency
183*0076d546SFeng Tang        latq = con.execute("select lat, count(lat) from pebs_ll group by lat order by lat")
184*0076d546SFeng Tang        print "\n%32s %8s %16s\n%s" % ("latency", "number", "histgram", "="*58)
185*0076d546SFeng Tang        for row in latq:
186*0076d546SFeng Tang             print "%32s %8d     %s" % (row[0], row[1], num2sym(row[1]))
187*0076d546SFeng Tang
188*0076d546SFeng Tangdef trace_unhandled(event_name, context, event_fields_dict):
189*0076d546SFeng Tang		print ' '.join(['%s=%s'%(k,str(v))for k,v in sorted(event_fields_dict.items())])
190*0076d546SFeng Tang
191*0076d546SFeng Tangdef print_header(event_name, cpu, secs, nsecs, pid, comm):
192*0076d546SFeng Tang	print "%-20s %5u %05u.%09u %8u %-20s " % \
193*0076d546SFeng Tang	(event_name, cpu, secs, nsecs, pid, comm),
194