Loading...
1# Display a process of packets and processed time.
2# It helps us to investigate networking or network device.
3#
4# options
5# tx: show only tx chart
6# rx: show only rx chart
7# dev=: show only thing related to specified device
8# debug: work with debug mode. It shows buffer status.
9
10import os
11import sys
12
13sys.path.append(os.environ['PERF_EXEC_PATH'] + \
14 '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
15
16from perf_trace_context import *
17from Core import *
18from Util import *
19
20all_event_list = []; # insert all tracepoint event related with this script
21irq_dic = {}; # key is cpu and value is a list which stacks irqs
22 # which raise NET_RX softirq
23net_rx_dic = {}; # key is cpu and value include time of NET_RX softirq-entry
24 # and a list which stacks receive
25receive_hunk_list = []; # a list which include a sequence of receive events
26rx_skb_list = []; # received packet list for matching
27 # skb_copy_datagram_iovec
28
29buffer_budget = 65536; # the budget of rx_skb_list, tx_queue_list and
30 # tx_xmit_list
31of_count_rx_skb_list = 0; # overflow count
32
33tx_queue_list = []; # list of packets which pass through dev_queue_xmit
34of_count_tx_queue_list = 0; # overflow count
35
36tx_xmit_list = []; # list of packets which pass through dev_hard_start_xmit
37of_count_tx_xmit_list = 0; # overflow count
38
39tx_free_list = []; # list of packets which is freed
40
41# options
42show_tx = 0;
43show_rx = 0;
44dev = 0; # store a name of device specified by option "dev="
45debug = 0;
46
47# indices of event_info tuple
48EINFO_IDX_NAME= 0
49EINFO_IDX_CONTEXT=1
50EINFO_IDX_CPU= 2
51EINFO_IDX_TIME= 3
52EINFO_IDX_PID= 4
53EINFO_IDX_COMM= 5
54
55# Calculate a time interval(msec) from src(nsec) to dst(nsec)
56def diff_msec(src, dst):
57 return (dst - src) / 1000000.0
58
59# Display a process of transmitting a packet
60def print_transmit(hunk):
61 if dev != 0 and hunk['dev'].find(dev) < 0:
62 return
63 print "%7s %5d %6d.%06dsec %12.3fmsec %12.3fmsec" % \
64 (hunk['dev'], hunk['len'],
65 nsecs_secs(hunk['queue_t']),
66 nsecs_nsecs(hunk['queue_t'])/1000,
67 diff_msec(hunk['queue_t'], hunk['xmit_t']),
68 diff_msec(hunk['xmit_t'], hunk['free_t']))
69
70# Format for displaying rx packet processing
71PF_IRQ_ENTRY= " irq_entry(+%.3fmsec irq=%d:%s)"
72PF_SOFT_ENTRY=" softirq_entry(+%.3fmsec)"
73PF_NAPI_POLL= " napi_poll_exit(+%.3fmsec %s)"
74PF_JOINT= " |"
75PF_WJOINT= " | |"
76PF_NET_RECV= " |---netif_receive_skb(+%.3fmsec skb=%x len=%d)"
77PF_NET_RX= " |---netif_rx(+%.3fmsec skb=%x)"
78PF_CPY_DGRAM= " | skb_copy_datagram_iovec(+%.3fmsec %d:%s)"
79PF_KFREE_SKB= " | kfree_skb(+%.3fmsec location=%x)"
80PF_CONS_SKB= " | consume_skb(+%.3fmsec)"
81
82# Display a process of received packets and interrputs associated with
83# a NET_RX softirq
84def print_receive(hunk):
85 show_hunk = 0
86 irq_list = hunk['irq_list']
87 cpu = irq_list[0]['cpu']
88 base_t = irq_list[0]['irq_ent_t']
89 # check if this hunk should be showed
90 if dev != 0:
91 for i in range(len(irq_list)):
92 if irq_list[i]['name'].find(dev) >= 0:
93 show_hunk = 1
94 break
95 else:
96 show_hunk = 1
97 if show_hunk == 0:
98 return
99
100 print "%d.%06dsec cpu=%d" % \
101 (nsecs_secs(base_t), nsecs_nsecs(base_t)/1000, cpu)
102 for i in range(len(irq_list)):
103 print PF_IRQ_ENTRY % \
104 (diff_msec(base_t, irq_list[i]['irq_ent_t']),
105 irq_list[i]['irq'], irq_list[i]['name'])
106 print PF_JOINT
107 irq_event_list = irq_list[i]['event_list']
108 for j in range(len(irq_event_list)):
109 irq_event = irq_event_list[j]
110 if irq_event['event'] == 'netif_rx':
111 print PF_NET_RX % \
112 (diff_msec(base_t, irq_event['time']),
113 irq_event['skbaddr'])
114 print PF_JOINT
115 print PF_SOFT_ENTRY % \
116 diff_msec(base_t, hunk['sirq_ent_t'])
117 print PF_JOINT
118 event_list = hunk['event_list']
119 for i in range(len(event_list)):
120 event = event_list[i]
121 if event['event_name'] == 'napi_poll':
122 print PF_NAPI_POLL % \
123 (diff_msec(base_t, event['event_t']), event['dev'])
124 if i == len(event_list) - 1:
125 print ""
126 else:
127 print PF_JOINT
128 else:
129 print PF_NET_RECV % \
130 (diff_msec(base_t, event['event_t']), event['skbaddr'],
131 event['len'])
132 if 'comm' in event.keys():
133 print PF_WJOINT
134 print PF_CPY_DGRAM % \
135 (diff_msec(base_t, event['comm_t']),
136 event['pid'], event['comm'])
137 elif 'handle' in event.keys():
138 print PF_WJOINT
139 if event['handle'] == "kfree_skb":
140 print PF_KFREE_SKB % \
141 (diff_msec(base_t,
142 event['comm_t']),
143 event['location'])
144 elif event['handle'] == "consume_skb":
145 print PF_CONS_SKB % \
146 diff_msec(base_t,
147 event['comm_t'])
148 print PF_JOINT
149
150def trace_begin():
151 global show_tx
152 global show_rx
153 global dev
154 global debug
155
156 for i in range(len(sys.argv)):
157 if i == 0:
158 continue
159 arg = sys.argv[i]
160 if arg == 'tx':
161 show_tx = 1
162 elif arg =='rx':
163 show_rx = 1
164 elif arg.find('dev=',0, 4) >= 0:
165 dev = arg[4:]
166 elif arg == 'debug':
167 debug = 1
168 if show_tx == 0 and show_rx == 0:
169 show_tx = 1
170 show_rx = 1
171
172def trace_end():
173 # order all events in time
174 all_event_list.sort(lambda a,b :cmp(a[EINFO_IDX_TIME],
175 b[EINFO_IDX_TIME]))
176 # process all events
177 for i in range(len(all_event_list)):
178 event_info = all_event_list[i]
179 name = event_info[EINFO_IDX_NAME]
180 if name == 'irq__softirq_exit':
181 handle_irq_softirq_exit(event_info)
182 elif name == 'irq__softirq_entry':
183 handle_irq_softirq_entry(event_info)
184 elif name == 'irq__softirq_raise':
185 handle_irq_softirq_raise(event_info)
186 elif name == 'irq__irq_handler_entry':
187 handle_irq_handler_entry(event_info)
188 elif name == 'irq__irq_handler_exit':
189 handle_irq_handler_exit(event_info)
190 elif name == 'napi__napi_poll':
191 handle_napi_poll(event_info)
192 elif name == 'net__netif_receive_skb':
193 handle_netif_receive_skb(event_info)
194 elif name == 'net__netif_rx':
195 handle_netif_rx(event_info)
196 elif name == 'skb__skb_copy_datagram_iovec':
197 handle_skb_copy_datagram_iovec(event_info)
198 elif name == 'net__net_dev_queue':
199 handle_net_dev_queue(event_info)
200 elif name == 'net__net_dev_xmit':
201 handle_net_dev_xmit(event_info)
202 elif name == 'skb__kfree_skb':
203 handle_kfree_skb(event_info)
204 elif name == 'skb__consume_skb':
205 handle_consume_skb(event_info)
206 # display receive hunks
207 if show_rx:
208 for i in range(len(receive_hunk_list)):
209 print_receive(receive_hunk_list[i])
210 # display transmit hunks
211 if show_tx:
212 print " dev len Qdisc " \
213 " netdevice free"
214 for i in range(len(tx_free_list)):
215 print_transmit(tx_free_list[i])
216 if debug:
217 print "debug buffer status"
218 print "----------------------------"
219 print "xmit Qdisc:remain:%d overflow:%d" % \
220 (len(tx_queue_list), of_count_tx_queue_list)
221 print "xmit netdevice:remain:%d overflow:%d" % \
222 (len(tx_xmit_list), of_count_tx_xmit_list)
223 print "receive:remain:%d overflow:%d" % \
224 (len(rx_skb_list), of_count_rx_skb_list)
225
226# called from perf, when it finds a correspoinding event
227def irq__softirq_entry(name, context, cpu, sec, nsec, pid, comm, callchain, vec):
228 if symbol_str("irq__softirq_entry", "vec", vec) != "NET_RX":
229 return
230 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, vec)
231 all_event_list.append(event_info)
232
233def irq__softirq_exit(name, context, cpu, sec, nsec, pid, comm, callchain, vec):
234 if symbol_str("irq__softirq_entry", "vec", vec) != "NET_RX":
235 return
236 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, vec)
237 all_event_list.append(event_info)
238
239def irq__softirq_raise(name, context, cpu, sec, nsec, pid, comm, callchain, vec):
240 if symbol_str("irq__softirq_entry", "vec", vec) != "NET_RX":
241 return
242 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, vec)
243 all_event_list.append(event_info)
244
245def irq__irq_handler_entry(name, context, cpu, sec, nsec, pid, comm,
246 callchain, irq, irq_name):
247 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
248 irq, irq_name)
249 all_event_list.append(event_info)
250
251def irq__irq_handler_exit(name, context, cpu, sec, nsec, pid, comm, callchain, irq, ret):
252 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, irq, ret)
253 all_event_list.append(event_info)
254
255def napi__napi_poll(name, context, cpu, sec, nsec, pid, comm, callchain, napi,
256 dev_name, work=None, budget=None):
257 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
258 napi, dev_name, work, budget)
259 all_event_list.append(event_info)
260
261def net__netif_receive_skb(name, context, cpu, sec, nsec, pid, comm, callchain, skbaddr,
262 skblen, dev_name):
263 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
264 skbaddr, skblen, dev_name)
265 all_event_list.append(event_info)
266
267def net__netif_rx(name, context, cpu, sec, nsec, pid, comm, callchain, skbaddr,
268 skblen, dev_name):
269 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
270 skbaddr, skblen, dev_name)
271 all_event_list.append(event_info)
272
273def net__net_dev_queue(name, context, cpu, sec, nsec, pid, comm, callchain,
274 skbaddr, skblen, dev_name):
275 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
276 skbaddr, skblen, dev_name)
277 all_event_list.append(event_info)
278
279def net__net_dev_xmit(name, context, cpu, sec, nsec, pid, comm, callchain,
280 skbaddr, skblen, rc, dev_name):
281 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
282 skbaddr, skblen, rc ,dev_name)
283 all_event_list.append(event_info)
284
285def skb__kfree_skb(name, context, cpu, sec, nsec, pid, comm, callchain,
286 skbaddr, protocol, location):
287 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
288 skbaddr, protocol, location)
289 all_event_list.append(event_info)
290
291def skb__consume_skb(name, context, cpu, sec, nsec, pid, comm, callchain, skbaddr):
292 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
293 skbaddr)
294 all_event_list.append(event_info)
295
296def skb__skb_copy_datagram_iovec(name, context, cpu, sec, nsec, pid, comm, callchain,
297 skbaddr, skblen):
298 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
299 skbaddr, skblen)
300 all_event_list.append(event_info)
301
302def handle_irq_handler_entry(event_info):
303 (name, context, cpu, time, pid, comm, irq, irq_name) = event_info
304 if cpu not in irq_dic.keys():
305 irq_dic[cpu] = []
306 irq_record = {'irq':irq, 'name':irq_name, 'cpu':cpu, 'irq_ent_t':time}
307 irq_dic[cpu].append(irq_record)
308
309def handle_irq_handler_exit(event_info):
310 (name, context, cpu, time, pid, comm, irq, ret) = event_info
311 if cpu not in irq_dic.keys():
312 return
313 irq_record = irq_dic[cpu].pop()
314 if irq != irq_record['irq']:
315 return
316 irq_record.update({'irq_ext_t':time})
317 # if an irq doesn't include NET_RX softirq, drop.
318 if 'event_list' in irq_record.keys():
319 irq_dic[cpu].append(irq_record)
320
321def handle_irq_softirq_raise(event_info):
322 (name, context, cpu, time, pid, comm, vec) = event_info
323 if cpu not in irq_dic.keys() \
324 or len(irq_dic[cpu]) == 0:
325 return
326 irq_record = irq_dic[cpu].pop()
327 if 'event_list' in irq_record.keys():
328 irq_event_list = irq_record['event_list']
329 else:
330 irq_event_list = []
331 irq_event_list.append({'time':time, 'event':'sirq_raise'})
332 irq_record.update({'event_list':irq_event_list})
333 irq_dic[cpu].append(irq_record)
334
335def handle_irq_softirq_entry(event_info):
336 (name, context, cpu, time, pid, comm, vec) = event_info
337 net_rx_dic[cpu] = {'sirq_ent_t':time, 'event_list':[]}
338
339def handle_irq_softirq_exit(event_info):
340 (name, context, cpu, time, pid, comm, vec) = event_info
341 irq_list = []
342 event_list = 0
343 if cpu in irq_dic.keys():
344 irq_list = irq_dic[cpu]
345 del irq_dic[cpu]
346 if cpu in net_rx_dic.keys():
347 sirq_ent_t = net_rx_dic[cpu]['sirq_ent_t']
348 event_list = net_rx_dic[cpu]['event_list']
349 del net_rx_dic[cpu]
350 if irq_list == [] or event_list == 0:
351 return
352 rec_data = {'sirq_ent_t':sirq_ent_t, 'sirq_ext_t':time,
353 'irq_list':irq_list, 'event_list':event_list}
354 # merge information realted to a NET_RX softirq
355 receive_hunk_list.append(rec_data)
356
357def handle_napi_poll(event_info):
358 (name, context, cpu, time, pid, comm, napi, dev_name,
359 work, budget) = event_info
360 if cpu in net_rx_dic.keys():
361 event_list = net_rx_dic[cpu]['event_list']
362 rec_data = {'event_name':'napi_poll',
363 'dev':dev_name, 'event_t':time,
364 'work':work, 'budget':budget}
365 event_list.append(rec_data)
366
367def handle_netif_rx(event_info):
368 (name, context, cpu, time, pid, comm,
369 skbaddr, skblen, dev_name) = event_info
370 if cpu not in irq_dic.keys() \
371 or len(irq_dic[cpu]) == 0:
372 return
373 irq_record = irq_dic[cpu].pop()
374 if 'event_list' in irq_record.keys():
375 irq_event_list = irq_record['event_list']
376 else:
377 irq_event_list = []
378 irq_event_list.append({'time':time, 'event':'netif_rx',
379 'skbaddr':skbaddr, 'skblen':skblen, 'dev_name':dev_name})
380 irq_record.update({'event_list':irq_event_list})
381 irq_dic[cpu].append(irq_record)
382
383def handle_netif_receive_skb(event_info):
384 global of_count_rx_skb_list
385
386 (name, context, cpu, time, pid, comm,
387 skbaddr, skblen, dev_name) = event_info
388 if cpu in net_rx_dic.keys():
389 rec_data = {'event_name':'netif_receive_skb',
390 'event_t':time, 'skbaddr':skbaddr, 'len':skblen}
391 event_list = net_rx_dic[cpu]['event_list']
392 event_list.append(rec_data)
393 rx_skb_list.insert(0, rec_data)
394 if len(rx_skb_list) > buffer_budget:
395 rx_skb_list.pop()
396 of_count_rx_skb_list += 1
397
398def handle_net_dev_queue(event_info):
399 global of_count_tx_queue_list
400
401 (name, context, cpu, time, pid, comm,
402 skbaddr, skblen, dev_name) = event_info
403 skb = {'dev':dev_name, 'skbaddr':skbaddr, 'len':skblen, 'queue_t':time}
404 tx_queue_list.insert(0, skb)
405 if len(tx_queue_list) > buffer_budget:
406 tx_queue_list.pop()
407 of_count_tx_queue_list += 1
408
409def handle_net_dev_xmit(event_info):
410 global of_count_tx_xmit_list
411
412 (name, context, cpu, time, pid, comm,
413 skbaddr, skblen, rc, dev_name) = event_info
414 if rc == 0: # NETDEV_TX_OK
415 for i in range(len(tx_queue_list)):
416 skb = tx_queue_list[i]
417 if skb['skbaddr'] == skbaddr:
418 skb['xmit_t'] = time
419 tx_xmit_list.insert(0, skb)
420 del tx_queue_list[i]
421 if len(tx_xmit_list) > buffer_budget:
422 tx_xmit_list.pop()
423 of_count_tx_xmit_list += 1
424 return
425
426def handle_kfree_skb(event_info):
427 (name, context, cpu, time, pid, comm,
428 skbaddr, protocol, location) = event_info
429 for i in range(len(tx_queue_list)):
430 skb = tx_queue_list[i]
431 if skb['skbaddr'] == skbaddr:
432 del tx_queue_list[i]
433 return
434 for i in range(len(tx_xmit_list)):
435 skb = tx_xmit_list[i]
436 if skb['skbaddr'] == skbaddr:
437 skb['free_t'] = time
438 tx_free_list.append(skb)
439 del tx_xmit_list[i]
440 return
441 for i in range(len(rx_skb_list)):
442 rec_data = rx_skb_list[i]
443 if rec_data['skbaddr'] == skbaddr:
444 rec_data.update({'handle':"kfree_skb",
445 'comm':comm, 'pid':pid, 'comm_t':time})
446 del rx_skb_list[i]
447 return
448
449def handle_consume_skb(event_info):
450 (name, context, cpu, time, pid, comm, skbaddr) = event_info
451 for i in range(len(tx_xmit_list)):
452 skb = tx_xmit_list[i]
453 if skb['skbaddr'] == skbaddr:
454 skb['free_t'] = time
455 tx_free_list.append(skb)
456 del tx_xmit_list[i]
457 return
458
459def handle_skb_copy_datagram_iovec(event_info):
460 (name, context, cpu, time, pid, comm, skbaddr, skblen) = event_info
461 for i in range(len(rx_skb_list)):
462 rec_data = rx_skb_list[i]
463 if skbaddr == rec_data['skbaddr']:
464 rec_data.update({'handle':"skb_copy_datagram_iovec",
465 'comm':comm, 'pid':pid, 'comm_t':time})
466 del rx_skb_list[i]
467 return
1# Display a process of packets and processed time.
2# SPDX-License-Identifier: GPL-2.0
3# It helps us to investigate networking or network device.
4#
5# options
6# tx: show only tx chart
7# rx: show only rx chart
8# dev=: show only thing related to specified device
9# debug: work with debug mode. It shows buffer status.
10
11import os
12import sys
13
14sys.path.append(os.environ['PERF_EXEC_PATH'] + \
15 '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
16
17from perf_trace_context import *
18from Core import *
19from Util import *
20
21all_event_list = []; # insert all tracepoint event related with this script
22irq_dic = {}; # key is cpu and value is a list which stacks irqs
23 # which raise NET_RX softirq
24net_rx_dic = {}; # key is cpu and value include time of NET_RX softirq-entry
25 # and a list which stacks receive
26receive_hunk_list = []; # a list which include a sequence of receive events
27rx_skb_list = []; # received packet list for matching
28 # skb_copy_datagram_iovec
29
30buffer_budget = 65536; # the budget of rx_skb_list, tx_queue_list and
31 # tx_xmit_list
32of_count_rx_skb_list = 0; # overflow count
33
34tx_queue_list = []; # list of packets which pass through dev_queue_xmit
35of_count_tx_queue_list = 0; # overflow count
36
37tx_xmit_list = []; # list of packets which pass through dev_hard_start_xmit
38of_count_tx_xmit_list = 0; # overflow count
39
40tx_free_list = []; # list of packets which is freed
41
42# options
43show_tx = 0;
44show_rx = 0;
45dev = 0; # store a name of device specified by option "dev="
46debug = 0;
47
48# indices of event_info tuple
49EINFO_IDX_NAME= 0
50EINFO_IDX_CONTEXT=1
51EINFO_IDX_CPU= 2
52EINFO_IDX_TIME= 3
53EINFO_IDX_PID= 4
54EINFO_IDX_COMM= 5
55
56# Calculate a time interval(msec) from src(nsec) to dst(nsec)
57def diff_msec(src, dst):
58 return (dst - src) / 1000000.0
59
60# Display a process of transmitting a packet
61def print_transmit(hunk):
62 if dev != 0 and hunk['dev'].find(dev) < 0:
63 return
64 print "%7s %5d %6d.%06dsec %12.3fmsec %12.3fmsec" % \
65 (hunk['dev'], hunk['len'],
66 nsecs_secs(hunk['queue_t']),
67 nsecs_nsecs(hunk['queue_t'])/1000,
68 diff_msec(hunk['queue_t'], hunk['xmit_t']),
69 diff_msec(hunk['xmit_t'], hunk['free_t']))
70
71# Format for displaying rx packet processing
72PF_IRQ_ENTRY= " irq_entry(+%.3fmsec irq=%d:%s)"
73PF_SOFT_ENTRY=" softirq_entry(+%.3fmsec)"
74PF_NAPI_POLL= " napi_poll_exit(+%.3fmsec %s)"
75PF_JOINT= " |"
76PF_WJOINT= " | |"
77PF_NET_RECV= " |---netif_receive_skb(+%.3fmsec skb=%x len=%d)"
78PF_NET_RX= " |---netif_rx(+%.3fmsec skb=%x)"
79PF_CPY_DGRAM= " | skb_copy_datagram_iovec(+%.3fmsec %d:%s)"
80PF_KFREE_SKB= " | kfree_skb(+%.3fmsec location=%x)"
81PF_CONS_SKB= " | consume_skb(+%.3fmsec)"
82
83# Display a process of received packets and interrputs associated with
84# a NET_RX softirq
85def print_receive(hunk):
86 show_hunk = 0
87 irq_list = hunk['irq_list']
88 cpu = irq_list[0]['cpu']
89 base_t = irq_list[0]['irq_ent_t']
90 # check if this hunk should be showed
91 if dev != 0:
92 for i in range(len(irq_list)):
93 if irq_list[i]['name'].find(dev) >= 0:
94 show_hunk = 1
95 break
96 else:
97 show_hunk = 1
98 if show_hunk == 0:
99 return
100
101 print "%d.%06dsec cpu=%d" % \
102 (nsecs_secs(base_t), nsecs_nsecs(base_t)/1000, cpu)
103 for i in range(len(irq_list)):
104 print PF_IRQ_ENTRY % \
105 (diff_msec(base_t, irq_list[i]['irq_ent_t']),
106 irq_list[i]['irq'], irq_list[i]['name'])
107 print PF_JOINT
108 irq_event_list = irq_list[i]['event_list']
109 for j in range(len(irq_event_list)):
110 irq_event = irq_event_list[j]
111 if irq_event['event'] == 'netif_rx':
112 print PF_NET_RX % \
113 (diff_msec(base_t, irq_event['time']),
114 irq_event['skbaddr'])
115 print PF_JOINT
116 print PF_SOFT_ENTRY % \
117 diff_msec(base_t, hunk['sirq_ent_t'])
118 print PF_JOINT
119 event_list = hunk['event_list']
120 for i in range(len(event_list)):
121 event = event_list[i]
122 if event['event_name'] == 'napi_poll':
123 print PF_NAPI_POLL % \
124 (diff_msec(base_t, event['event_t']), event['dev'])
125 if i == len(event_list) - 1:
126 print ""
127 else:
128 print PF_JOINT
129 else:
130 print PF_NET_RECV % \
131 (diff_msec(base_t, event['event_t']), event['skbaddr'],
132 event['len'])
133 if 'comm' in event.keys():
134 print PF_WJOINT
135 print PF_CPY_DGRAM % \
136 (diff_msec(base_t, event['comm_t']),
137 event['pid'], event['comm'])
138 elif 'handle' in event.keys():
139 print PF_WJOINT
140 if event['handle'] == "kfree_skb":
141 print PF_KFREE_SKB % \
142 (diff_msec(base_t,
143 event['comm_t']),
144 event['location'])
145 elif event['handle'] == "consume_skb":
146 print PF_CONS_SKB % \
147 diff_msec(base_t,
148 event['comm_t'])
149 print PF_JOINT
150
151def trace_begin():
152 global show_tx
153 global show_rx
154 global dev
155 global debug
156
157 for i in range(len(sys.argv)):
158 if i == 0:
159 continue
160 arg = sys.argv[i]
161 if arg == 'tx':
162 show_tx = 1
163 elif arg =='rx':
164 show_rx = 1
165 elif arg.find('dev=',0, 4) >= 0:
166 dev = arg[4:]
167 elif arg == 'debug':
168 debug = 1
169 if show_tx == 0 and show_rx == 0:
170 show_tx = 1
171 show_rx = 1
172
173def trace_end():
174 # order all events in time
175 all_event_list.sort(lambda a,b :cmp(a[EINFO_IDX_TIME],
176 b[EINFO_IDX_TIME]))
177 # process all events
178 for i in range(len(all_event_list)):
179 event_info = all_event_list[i]
180 name = event_info[EINFO_IDX_NAME]
181 if name == 'irq__softirq_exit':
182 handle_irq_softirq_exit(event_info)
183 elif name == 'irq__softirq_entry':
184 handle_irq_softirq_entry(event_info)
185 elif name == 'irq__softirq_raise':
186 handle_irq_softirq_raise(event_info)
187 elif name == 'irq__irq_handler_entry':
188 handle_irq_handler_entry(event_info)
189 elif name == 'irq__irq_handler_exit':
190 handle_irq_handler_exit(event_info)
191 elif name == 'napi__napi_poll':
192 handle_napi_poll(event_info)
193 elif name == 'net__netif_receive_skb':
194 handle_netif_receive_skb(event_info)
195 elif name == 'net__netif_rx':
196 handle_netif_rx(event_info)
197 elif name == 'skb__skb_copy_datagram_iovec':
198 handle_skb_copy_datagram_iovec(event_info)
199 elif name == 'net__net_dev_queue':
200 handle_net_dev_queue(event_info)
201 elif name == 'net__net_dev_xmit':
202 handle_net_dev_xmit(event_info)
203 elif name == 'skb__kfree_skb':
204 handle_kfree_skb(event_info)
205 elif name == 'skb__consume_skb':
206 handle_consume_skb(event_info)
207 # display receive hunks
208 if show_rx:
209 for i in range(len(receive_hunk_list)):
210 print_receive(receive_hunk_list[i])
211 # display transmit hunks
212 if show_tx:
213 print " dev len Qdisc " \
214 " netdevice free"
215 for i in range(len(tx_free_list)):
216 print_transmit(tx_free_list[i])
217 if debug:
218 print "debug buffer status"
219 print "----------------------------"
220 print "xmit Qdisc:remain:%d overflow:%d" % \
221 (len(tx_queue_list), of_count_tx_queue_list)
222 print "xmit netdevice:remain:%d overflow:%d" % \
223 (len(tx_xmit_list), of_count_tx_xmit_list)
224 print "receive:remain:%d overflow:%d" % \
225 (len(rx_skb_list), of_count_rx_skb_list)
226
227# called from perf, when it finds a correspoinding event
228def irq__softirq_entry(name, context, cpu, sec, nsec, pid, comm, callchain, vec):
229 if symbol_str("irq__softirq_entry", "vec", vec) != "NET_RX":
230 return
231 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, vec)
232 all_event_list.append(event_info)
233
234def irq__softirq_exit(name, context, cpu, sec, nsec, pid, comm, callchain, vec):
235 if symbol_str("irq__softirq_entry", "vec", vec) != "NET_RX":
236 return
237 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, vec)
238 all_event_list.append(event_info)
239
240def irq__softirq_raise(name, context, cpu, sec, nsec, pid, comm, callchain, vec):
241 if symbol_str("irq__softirq_entry", "vec", vec) != "NET_RX":
242 return
243 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, vec)
244 all_event_list.append(event_info)
245
246def irq__irq_handler_entry(name, context, cpu, sec, nsec, pid, comm,
247 callchain, irq, irq_name):
248 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
249 irq, irq_name)
250 all_event_list.append(event_info)
251
252def irq__irq_handler_exit(name, context, cpu, sec, nsec, pid, comm, callchain, irq, ret):
253 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, irq, ret)
254 all_event_list.append(event_info)
255
256def napi__napi_poll(name, context, cpu, sec, nsec, pid, comm, callchain, napi,
257 dev_name, work=None, budget=None):
258 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
259 napi, dev_name, work, budget)
260 all_event_list.append(event_info)
261
262def net__netif_receive_skb(name, context, cpu, sec, nsec, pid, comm, callchain, skbaddr,
263 skblen, dev_name):
264 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
265 skbaddr, skblen, dev_name)
266 all_event_list.append(event_info)
267
268def net__netif_rx(name, context, cpu, sec, nsec, pid, comm, callchain, skbaddr,
269 skblen, dev_name):
270 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
271 skbaddr, skblen, dev_name)
272 all_event_list.append(event_info)
273
274def net__net_dev_queue(name, context, cpu, sec, nsec, pid, comm, callchain,
275 skbaddr, skblen, dev_name):
276 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
277 skbaddr, skblen, dev_name)
278 all_event_list.append(event_info)
279
280def net__net_dev_xmit(name, context, cpu, sec, nsec, pid, comm, callchain,
281 skbaddr, skblen, rc, dev_name):
282 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
283 skbaddr, skblen, rc ,dev_name)
284 all_event_list.append(event_info)
285
286def skb__kfree_skb(name, context, cpu, sec, nsec, pid, comm, callchain,
287 skbaddr, protocol, location):
288 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
289 skbaddr, protocol, location)
290 all_event_list.append(event_info)
291
292def skb__consume_skb(name, context, cpu, sec, nsec, pid, comm, callchain, skbaddr):
293 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
294 skbaddr)
295 all_event_list.append(event_info)
296
297def skb__skb_copy_datagram_iovec(name, context, cpu, sec, nsec, pid, comm, callchain,
298 skbaddr, skblen):
299 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
300 skbaddr, skblen)
301 all_event_list.append(event_info)
302
303def handle_irq_handler_entry(event_info):
304 (name, context, cpu, time, pid, comm, irq, irq_name) = event_info
305 if cpu not in irq_dic.keys():
306 irq_dic[cpu] = []
307 irq_record = {'irq':irq, 'name':irq_name, 'cpu':cpu, 'irq_ent_t':time}
308 irq_dic[cpu].append(irq_record)
309
310def handle_irq_handler_exit(event_info):
311 (name, context, cpu, time, pid, comm, irq, ret) = event_info
312 if cpu not in irq_dic.keys():
313 return
314 irq_record = irq_dic[cpu].pop()
315 if irq != irq_record['irq']:
316 return
317 irq_record.update({'irq_ext_t':time})
318 # if an irq doesn't include NET_RX softirq, drop.
319 if 'event_list' in irq_record.keys():
320 irq_dic[cpu].append(irq_record)
321
322def handle_irq_softirq_raise(event_info):
323 (name, context, cpu, time, pid, comm, vec) = event_info
324 if cpu not in irq_dic.keys() \
325 or len(irq_dic[cpu]) == 0:
326 return
327 irq_record = irq_dic[cpu].pop()
328 if 'event_list' in irq_record.keys():
329 irq_event_list = irq_record['event_list']
330 else:
331 irq_event_list = []
332 irq_event_list.append({'time':time, 'event':'sirq_raise'})
333 irq_record.update({'event_list':irq_event_list})
334 irq_dic[cpu].append(irq_record)
335
336def handle_irq_softirq_entry(event_info):
337 (name, context, cpu, time, pid, comm, vec) = event_info
338 net_rx_dic[cpu] = {'sirq_ent_t':time, 'event_list':[]}
339
340def handle_irq_softirq_exit(event_info):
341 (name, context, cpu, time, pid, comm, vec) = event_info
342 irq_list = []
343 event_list = 0
344 if cpu in irq_dic.keys():
345 irq_list = irq_dic[cpu]
346 del irq_dic[cpu]
347 if cpu in net_rx_dic.keys():
348 sirq_ent_t = net_rx_dic[cpu]['sirq_ent_t']
349 event_list = net_rx_dic[cpu]['event_list']
350 del net_rx_dic[cpu]
351 if irq_list == [] or event_list == 0:
352 return
353 rec_data = {'sirq_ent_t':sirq_ent_t, 'sirq_ext_t':time,
354 'irq_list':irq_list, 'event_list':event_list}
355 # merge information realted to a NET_RX softirq
356 receive_hunk_list.append(rec_data)
357
358def handle_napi_poll(event_info):
359 (name, context, cpu, time, pid, comm, napi, dev_name,
360 work, budget) = event_info
361 if cpu in net_rx_dic.keys():
362 event_list = net_rx_dic[cpu]['event_list']
363 rec_data = {'event_name':'napi_poll',
364 'dev':dev_name, 'event_t':time,
365 'work':work, 'budget':budget}
366 event_list.append(rec_data)
367
368def handle_netif_rx(event_info):
369 (name, context, cpu, time, pid, comm,
370 skbaddr, skblen, dev_name) = event_info
371 if cpu not in irq_dic.keys() \
372 or len(irq_dic[cpu]) == 0:
373 return
374 irq_record = irq_dic[cpu].pop()
375 if 'event_list' in irq_record.keys():
376 irq_event_list = irq_record['event_list']
377 else:
378 irq_event_list = []
379 irq_event_list.append({'time':time, 'event':'netif_rx',
380 'skbaddr':skbaddr, 'skblen':skblen, 'dev_name':dev_name})
381 irq_record.update({'event_list':irq_event_list})
382 irq_dic[cpu].append(irq_record)
383
384def handle_netif_receive_skb(event_info):
385 global of_count_rx_skb_list
386
387 (name, context, cpu, time, pid, comm,
388 skbaddr, skblen, dev_name) = event_info
389 if cpu in net_rx_dic.keys():
390 rec_data = {'event_name':'netif_receive_skb',
391 'event_t':time, 'skbaddr':skbaddr, 'len':skblen}
392 event_list = net_rx_dic[cpu]['event_list']
393 event_list.append(rec_data)
394 rx_skb_list.insert(0, rec_data)
395 if len(rx_skb_list) > buffer_budget:
396 rx_skb_list.pop()
397 of_count_rx_skb_list += 1
398
399def handle_net_dev_queue(event_info):
400 global of_count_tx_queue_list
401
402 (name, context, cpu, time, pid, comm,
403 skbaddr, skblen, dev_name) = event_info
404 skb = {'dev':dev_name, 'skbaddr':skbaddr, 'len':skblen, 'queue_t':time}
405 tx_queue_list.insert(0, skb)
406 if len(tx_queue_list) > buffer_budget:
407 tx_queue_list.pop()
408 of_count_tx_queue_list += 1
409
410def handle_net_dev_xmit(event_info):
411 global of_count_tx_xmit_list
412
413 (name, context, cpu, time, pid, comm,
414 skbaddr, skblen, rc, dev_name) = event_info
415 if rc == 0: # NETDEV_TX_OK
416 for i in range(len(tx_queue_list)):
417 skb = tx_queue_list[i]
418 if skb['skbaddr'] == skbaddr:
419 skb['xmit_t'] = time
420 tx_xmit_list.insert(0, skb)
421 del tx_queue_list[i]
422 if len(tx_xmit_list) > buffer_budget:
423 tx_xmit_list.pop()
424 of_count_tx_xmit_list += 1
425 return
426
427def handle_kfree_skb(event_info):
428 (name, context, cpu, time, pid, comm,
429 skbaddr, protocol, location) = event_info
430 for i in range(len(tx_queue_list)):
431 skb = tx_queue_list[i]
432 if skb['skbaddr'] == skbaddr:
433 del tx_queue_list[i]
434 return
435 for i in range(len(tx_xmit_list)):
436 skb = tx_xmit_list[i]
437 if skb['skbaddr'] == skbaddr:
438 skb['free_t'] = time
439 tx_free_list.append(skb)
440 del tx_xmit_list[i]
441 return
442 for i in range(len(rx_skb_list)):
443 rec_data = rx_skb_list[i]
444 if rec_data['skbaddr'] == skbaddr:
445 rec_data.update({'handle':"kfree_skb",
446 'comm':comm, 'pid':pid, 'comm_t':time})
447 del rx_skb_list[i]
448 return
449
450def handle_consume_skb(event_info):
451 (name, context, cpu, time, pid, comm, skbaddr) = event_info
452 for i in range(len(tx_xmit_list)):
453 skb = tx_xmit_list[i]
454 if skb['skbaddr'] == skbaddr:
455 skb['free_t'] = time
456 tx_free_list.append(skb)
457 del tx_xmit_list[i]
458 return
459
460def handle_skb_copy_datagram_iovec(event_info):
461 (name, context, cpu, time, pid, comm, skbaddr, skblen) = event_info
462 for i in range(len(rx_skb_list)):
463 rec_data = rx_skb_list[i]
464 if skbaddr == rec_data['skbaddr']:
465 rec_data.update({'handle':"skb_copy_datagram_iovec",
466 'comm':comm, 'pid':pid, 'comm_t':time})
467 del rx_skb_list[i]
468 return