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.
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.
14 sys.path.append(os.environ['PERF_EXEC_PATH'] + \
15 '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
17 from perf_trace_context import *
21 all_event_list = []; # insert all tracepoint event related with this script
22 irq_dic = {}; # key is cpu and value is a list which stacks irqs
23 # which raise NET_RX softirq
24 net_rx_dic = {}; # key is cpu and value include time of NET_RX softirq-entry
25 # and a list which stacks receive
26 receive_hunk_list = []; # a list which include a sequence of receive events
27 rx_skb_list = []; # received packet list for matching
28 # skb_copy_datagram_iovec
30 buffer_budget = 65536; # the budget of rx_skb_list, tx_queue_list and
32 of_count_rx_skb_list = 0; # overflow count
34 tx_queue_list = []; # list of packets which pass through dev_queue_xmit
35 of_count_tx_queue_list = 0; # overflow count
37 tx_xmit_list = []; # list of packets which pass through dev_hard_start_xmit
38 of_count_tx_xmit_list = 0; # overflow count
40 tx_free_list = []; # list of packets which is freed
45 dev = 0; # store a name of device specified by option "dev="
48 # indices of event_info tuple
56 # Calculate a time interval(msec) from src(nsec) to dst(nsec)
57 def diff_msec(src, dst):
58 return (dst - src) / 1000000.0
60 # Display a process of transmitting a packet
61 def print_transmit(hunk):
62 if dev != 0 and hunk['dev'].find(dev) < 0:
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']))
71 # Format for displaying rx packet processing
72 PF_IRQ_ENTRY= " irq_entry(+%.3fmsec irq=%d:%s)"
73 PF_SOFT_ENTRY=" softirq_entry(+%.3fmsec)"
74 PF_NAPI_POLL= " napi_poll_exit(+%.3fmsec %s)"
77 PF_NET_RECV= " |---netif_receive_skb(+%.3fmsec skb=%x len=%d)"
78 PF_NET_RX= " |---netif_rx(+%.3fmsec skb=%x)"
79 PF_CPY_DGRAM= " | skb_copy_datagram_iovec(+%.3fmsec %d:%s)"
80 PF_KFREE_SKB= " | kfree_skb(+%.3fmsec location=%x)"
81 PF_CONS_SKB= " | consume_skb(+%.3fmsec)"
83 # Display a process of received packets and interrputs associated with
85 def print_receive(hunk):
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
92 for i in range(len(irq_list)):
93 if irq_list[i]['name'].find(dev) >= 0:
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'])
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':
113 (diff_msec(base_t, irq_event['time']),
114 irq_event['skbaddr'])
116 print PF_SOFT_ENTRY % \
117 diff_msec(base_t, hunk['sirq_ent_t'])
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:
130 print PF_NET_RECV % \
131 (diff_msec(base_t, event['event_t']), event['skbaddr'],
133 if 'comm' in event.keys():
135 print PF_CPY_DGRAM % \
136 (diff_msec(base_t, event['comm_t']),
137 event['pid'], event['comm'])
138 elif 'handle' in event.keys():
140 if event['handle'] == "kfree_skb":
141 print PF_KFREE_SKB % \
145 elif event['handle'] == "consume_skb":
146 print PF_CONS_SKB % \
157 for i in range(len(sys.argv)):
165 elif arg.find('dev=',0, 4) >= 0:
169 if show_tx == 0 and show_rx == 0:
174 # order all events in time
175 all_event_list.sort(lambda a,b :cmp(a[EINFO_IDX_TIME],
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
209 for i in range(len(receive_hunk_list)):
210 print_receive(receive_hunk_list[i])
211 # display transmit hunks
213 print " dev len Qdisc " \
215 for i in range(len(tx_free_list)):
216 print_transmit(tx_free_list[i])
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)
227 # called from perf, when it finds a correspoinding event
228 def irq__softirq_entry(name, context, cpu, sec, nsec, pid, comm, callchain, vec):
229 if symbol_str("irq__softirq_entry", "vec", vec) != "NET_RX":
231 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, vec)
232 all_event_list.append(event_info)
234 def irq__softirq_exit(name, context, cpu, sec, nsec, pid, comm, callchain, vec):
235 if symbol_str("irq__softirq_entry", "vec", vec) != "NET_RX":
237 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, vec)
238 all_event_list.append(event_info)
240 def irq__softirq_raise(name, context, cpu, sec, nsec, pid, comm, callchain, vec):
241 if symbol_str("irq__softirq_entry", "vec", vec) != "NET_RX":
243 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, vec)
244 all_event_list.append(event_info)
246 def 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,
250 all_event_list.append(event_info)
252 def 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)
256 def 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)
262 def net__netif_receive_skb(name, context, cpu, sec, nsec, pid, comm, callchain, skbaddr,
264 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
265 skbaddr, skblen, dev_name)
266 all_event_list.append(event_info)
268 def net__netif_rx(name, context, cpu, sec, nsec, pid, comm, callchain, skbaddr,
270 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
271 skbaddr, skblen, dev_name)
272 all_event_list.append(event_info)
274 def 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)
280 def 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)
286 def 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)
292 def skb__consume_skb(name, context, cpu, sec, nsec, pid, comm, callchain, skbaddr):
293 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
295 all_event_list.append(event_info)
297 def skb__skb_copy_datagram_iovec(name, context, cpu, sec, nsec, pid, comm, callchain,
299 event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
301 all_event_list.append(event_info)
303 def 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():
307 irq_record = {'irq':irq, 'name':irq_name, 'cpu':cpu, 'irq_ent_t':time}
308 irq_dic[cpu].append(irq_record)
310 def 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():
314 irq_record = irq_dic[cpu].pop()
315 if irq != irq_record['irq']:
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)
322 def 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:
327 irq_record = irq_dic[cpu].pop()
328 if 'event_list' in irq_record.keys():
329 irq_event_list = irq_record['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)
336 def 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':[]}
340 def handle_irq_softirq_exit(event_info):
341 (name, context, cpu, time, pid, comm, vec) = event_info
344 if cpu in irq_dic.keys():
345 irq_list = 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']
351 if irq_list == [] or event_list == 0:
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)
358 def 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)
368 def 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:
374 irq_record = irq_dic[cpu].pop()
375 if 'event_list' in irq_record.keys():
376 irq_event_list = irq_record['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)
384 def handle_netif_receive_skb(event_info):
385 global of_count_rx_skb_list
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:
397 of_count_rx_skb_list += 1
399 def handle_net_dev_queue(event_info):
400 global of_count_tx_queue_list
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:
408 of_count_tx_queue_list += 1
410 def handle_net_dev_xmit(event_info):
411 global of_count_tx_xmit_list
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:
420 tx_xmit_list.insert(0, skb)
422 if len(tx_xmit_list) > buffer_budget:
424 of_count_tx_xmit_list += 1
427 def 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:
435 for i in range(len(tx_xmit_list)):
436 skb = tx_xmit_list[i]
437 if skb['skbaddr'] == skbaddr:
439 tx_free_list.append(skb)
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})
450 def 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:
456 tx_free_list.append(skb)
460 def 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})