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