Back to home page

OSCL-LXR
 
 

     

0001 # Display a process of packets and processed time.
0002 # SPDX-License-Identifier: GPL-2.0
0003 # It helps us to investigate networking or network device.
0004 #
0005 # options
0006 # tx: show only tx chart
0007 # rx: show only rx chart
0008 # dev=: show only thing related to specified device
0009 # debug: work with debug mode. It shows buffer status.
0010 
0011 from __future__ import print_function
0012 
0013 import os
0014 import sys
0015 
0016 sys.path.append(os.environ['PERF_EXEC_PATH'] + \
0017     '/scripts/python/Perf-Trace-Util/lib/Perf/Trace')
0018 
0019 from perf_trace_context import *
0020 from Core import *
0021 from Util import *
0022 from functools import cmp_to_key
0023 
0024 all_event_list = []; # insert all tracepoint event related with this script
0025 irq_dic = {}; # key is cpu and value is a list which stacks irqs
0026               # which raise NET_RX softirq
0027 net_rx_dic = {}; # key is cpu and value include time of NET_RX softirq-entry
0028          # and a list which stacks receive
0029 receive_hunk_list = []; # a list which include a sequence of receive events
0030 rx_skb_list = []; # received packet list for matching
0031                # skb_copy_datagram_iovec
0032 
0033 buffer_budget = 65536; # the budget of rx_skb_list, tx_queue_list and
0034                # tx_xmit_list
0035 of_count_rx_skb_list = 0; # overflow count
0036 
0037 tx_queue_list = []; # list of packets which pass through dev_queue_xmit
0038 of_count_tx_queue_list = 0; # overflow count
0039 
0040 tx_xmit_list = [];  # list of packets which pass through dev_hard_start_xmit
0041 of_count_tx_xmit_list = 0; # overflow count
0042 
0043 tx_free_list = [];  # list of packets which is freed
0044 
0045 # options
0046 show_tx = 0;
0047 show_rx = 0;
0048 dev = 0; # store a name of device specified by option "dev="
0049 debug = 0;
0050 
0051 # indices of event_info tuple
0052 EINFO_IDX_NAME=   0
0053 EINFO_IDX_CONTEXT=1
0054 EINFO_IDX_CPU=    2
0055 EINFO_IDX_TIME=   3
0056 EINFO_IDX_PID=    4
0057 EINFO_IDX_COMM=   5
0058 
0059 # Calculate a time interval(msec) from src(nsec) to dst(nsec)
0060 def diff_msec(src, dst):
0061     return (dst - src) / 1000000.0
0062 
0063 # Display a process of transmitting a packet
0064 def print_transmit(hunk):
0065     if dev != 0 and hunk['dev'].find(dev) < 0:
0066         return
0067     print("%7s %5d %6d.%06dsec %12.3fmsec      %12.3fmsec" %
0068         (hunk['dev'], hunk['len'],
0069         nsecs_secs(hunk['queue_t']),
0070         nsecs_nsecs(hunk['queue_t'])/1000,
0071         diff_msec(hunk['queue_t'], hunk['xmit_t']),
0072         diff_msec(hunk['xmit_t'], hunk['free_t'])))
0073 
0074 # Format for displaying rx packet processing
0075 PF_IRQ_ENTRY= "  irq_entry(+%.3fmsec irq=%d:%s)"
0076 PF_SOFT_ENTRY="  softirq_entry(+%.3fmsec)"
0077 PF_NAPI_POLL= "  napi_poll_exit(+%.3fmsec %s)"
0078 PF_JOINT=     "         |"
0079 PF_WJOINT=    "         |            |"
0080 PF_NET_RECV=  "         |---netif_receive_skb(+%.3fmsec skb=%x len=%d)"
0081 PF_NET_RX=    "         |---netif_rx(+%.3fmsec skb=%x)"
0082 PF_CPY_DGRAM= "         |      skb_copy_datagram_iovec(+%.3fmsec %d:%s)"
0083 PF_KFREE_SKB= "         |      kfree_skb(+%.3fmsec location=%x)"
0084 PF_CONS_SKB=  "         |      consume_skb(+%.3fmsec)"
0085 
0086 # Display a process of received packets and interrputs associated with
0087 # a NET_RX softirq
0088 def print_receive(hunk):
0089     show_hunk = 0
0090     irq_list = hunk['irq_list']
0091     cpu = irq_list[0]['cpu']
0092     base_t = irq_list[0]['irq_ent_t']
0093     # check if this hunk should be showed
0094     if dev != 0:
0095         for i in range(len(irq_list)):
0096             if irq_list[i]['name'].find(dev) >= 0:
0097                 show_hunk = 1
0098                 break
0099     else:
0100         show_hunk = 1
0101     if show_hunk == 0:
0102         return
0103 
0104     print("%d.%06dsec cpu=%d" %
0105         (nsecs_secs(base_t), nsecs_nsecs(base_t)/1000, cpu))
0106     for i in range(len(irq_list)):
0107         print(PF_IRQ_ENTRY %
0108             (diff_msec(base_t, irq_list[i]['irq_ent_t']),
0109             irq_list[i]['irq'], irq_list[i]['name']))
0110         print(PF_JOINT)
0111         irq_event_list = irq_list[i]['event_list']
0112         for j in range(len(irq_event_list)):
0113             irq_event = irq_event_list[j]
0114             if irq_event['event'] == 'netif_rx':
0115                 print(PF_NET_RX %
0116                     (diff_msec(base_t, irq_event['time']),
0117                     irq_event['skbaddr']))
0118                 print(PF_JOINT)
0119     print(PF_SOFT_ENTRY %
0120         diff_msec(base_t, hunk['sirq_ent_t']))
0121     print(PF_JOINT)
0122     event_list = hunk['event_list']
0123     for i in range(len(event_list)):
0124         event = event_list[i]
0125         if event['event_name'] == 'napi_poll':
0126             print(PF_NAPI_POLL %
0127                 (diff_msec(base_t, event['event_t']),
0128                 event['dev']))
0129             if i == len(event_list) - 1:
0130                 print("")
0131             else:
0132                 print(PF_JOINT)
0133         else:
0134             print(PF_NET_RECV %
0135                 (diff_msec(base_t, event['event_t']),
0136                 event['skbaddr'],
0137                 event['len']))
0138             if 'comm' in event.keys():
0139                 print(PF_WJOINT)
0140                 print(PF_CPY_DGRAM %
0141                     (diff_msec(base_t, event['comm_t']),
0142                     event['pid'], event['comm']))
0143             elif 'handle' in event.keys():
0144                 print(PF_WJOINT)
0145                 if event['handle'] == "kfree_skb":
0146                     print(PF_KFREE_SKB %
0147                         (diff_msec(base_t,
0148                         event['comm_t']),
0149                         event['location']))
0150                 elif event['handle'] == "consume_skb":
0151                     print(PF_CONS_SKB %
0152                         diff_msec(base_t,
0153                             event['comm_t']))
0154             print(PF_JOINT)
0155 
0156 def trace_begin():
0157     global show_tx
0158     global show_rx
0159     global dev
0160     global debug
0161 
0162     for i in range(len(sys.argv)):
0163         if i == 0:
0164             continue
0165         arg = sys.argv[i]
0166         if arg == 'tx':
0167             show_tx = 1
0168         elif arg =='rx':
0169             show_rx = 1
0170         elif arg.find('dev=',0, 4) >= 0:
0171             dev = arg[4:]
0172         elif arg == 'debug':
0173             debug = 1
0174     if show_tx == 0  and show_rx == 0:
0175         show_tx = 1
0176         show_rx = 1
0177 
0178 def trace_end():
0179     # order all events in time
0180     all_event_list.sort(key=cmp_to_key(lambda a,b :a[EINFO_IDX_TIME] < b[EINFO_IDX_TIME]))
0181     # process all events
0182     for i in range(len(all_event_list)):
0183         event_info = all_event_list[i]
0184         name = event_info[EINFO_IDX_NAME]
0185         if name == 'irq__softirq_exit':
0186             handle_irq_softirq_exit(event_info)
0187         elif name == 'irq__softirq_entry':
0188             handle_irq_softirq_entry(event_info)
0189         elif name == 'irq__softirq_raise':
0190             handle_irq_softirq_raise(event_info)
0191         elif name == 'irq__irq_handler_entry':
0192             handle_irq_handler_entry(event_info)
0193         elif name == 'irq__irq_handler_exit':
0194             handle_irq_handler_exit(event_info)
0195         elif name == 'napi__napi_poll':
0196             handle_napi_poll(event_info)
0197         elif name == 'net__netif_receive_skb':
0198             handle_netif_receive_skb(event_info)
0199         elif name == 'net__netif_rx':
0200             handle_netif_rx(event_info)
0201         elif name == 'skb__skb_copy_datagram_iovec':
0202             handle_skb_copy_datagram_iovec(event_info)
0203         elif name == 'net__net_dev_queue':
0204             handle_net_dev_queue(event_info)
0205         elif name == 'net__net_dev_xmit':
0206             handle_net_dev_xmit(event_info)
0207         elif name == 'skb__kfree_skb':
0208             handle_kfree_skb(event_info)
0209         elif name == 'skb__consume_skb':
0210             handle_consume_skb(event_info)
0211     # display receive hunks
0212     if show_rx:
0213         for i in range(len(receive_hunk_list)):
0214             print_receive(receive_hunk_list[i])
0215     # display transmit hunks
0216     if show_tx:
0217         print("   dev    len      Qdisc        "
0218             "       netdevice             free")
0219         for i in range(len(tx_free_list)):
0220             print_transmit(tx_free_list[i])
0221     if debug:
0222         print("debug buffer status")
0223         print("----------------------------")
0224         print("xmit Qdisc:remain:%d overflow:%d" %
0225             (len(tx_queue_list), of_count_tx_queue_list))
0226         print("xmit netdevice:remain:%d overflow:%d" %
0227             (len(tx_xmit_list), of_count_tx_xmit_list))
0228         print("receive:remain:%d overflow:%d" %
0229             (len(rx_skb_list), of_count_rx_skb_list))
0230 
0231 # called from perf, when it finds a correspoinding event
0232 def irq__softirq_entry(name, context, cpu, sec, nsec, pid, comm, callchain, vec):
0233     if symbol_str("irq__softirq_entry", "vec", vec) != "NET_RX":
0234         return
0235     event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, vec)
0236     all_event_list.append(event_info)
0237 
0238 def irq__softirq_exit(name, context, cpu, sec, nsec, pid, comm, callchain, vec):
0239     if symbol_str("irq__softirq_entry", "vec", vec) != "NET_RX":
0240         return
0241     event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, vec)
0242     all_event_list.append(event_info)
0243 
0244 def irq__softirq_raise(name, context, cpu, sec, nsec, pid, comm, callchain, vec):
0245     if symbol_str("irq__softirq_entry", "vec", vec) != "NET_RX":
0246         return
0247     event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, vec)
0248     all_event_list.append(event_info)
0249 
0250 def irq__irq_handler_entry(name, context, cpu, sec, nsec, pid, comm,
0251             callchain, irq, irq_name):
0252     event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
0253             irq, irq_name)
0254     all_event_list.append(event_info)
0255 
0256 def irq__irq_handler_exit(name, context, cpu, sec, nsec, pid, comm, callchain, irq, ret):
0257     event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, irq, ret)
0258     all_event_list.append(event_info)
0259 
0260 def napi__napi_poll(name, context, cpu, sec, nsec, pid, comm, callchain, napi,
0261         dev_name, work=None, budget=None):
0262     event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
0263             napi, dev_name, work, budget)
0264     all_event_list.append(event_info)
0265 
0266 def net__netif_receive_skb(name, context, cpu, sec, nsec, pid, comm, callchain, skbaddr,
0267             skblen, dev_name):
0268     event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
0269             skbaddr, skblen, dev_name)
0270     all_event_list.append(event_info)
0271 
0272 def net__netif_rx(name, context, cpu, sec, nsec, pid, comm, callchain, skbaddr,
0273             skblen, dev_name):
0274     event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
0275             skbaddr, skblen, dev_name)
0276     all_event_list.append(event_info)
0277 
0278 def net__net_dev_queue(name, context, cpu, sec, nsec, pid, comm, callchain,
0279             skbaddr, skblen, dev_name):
0280     event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
0281             skbaddr, skblen, dev_name)
0282     all_event_list.append(event_info)
0283 
0284 def net__net_dev_xmit(name, context, cpu, sec, nsec, pid, comm, callchain,
0285             skbaddr, skblen, rc, dev_name):
0286     event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
0287             skbaddr, skblen, rc ,dev_name)
0288     all_event_list.append(event_info)
0289 
0290 def skb__kfree_skb(name, context, cpu, sec, nsec, pid, comm, callchain,
0291             skbaddr, protocol, location):
0292     event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
0293             skbaddr, protocol, location)
0294     all_event_list.append(event_info)
0295 
0296 def skb__consume_skb(name, context, cpu, sec, nsec, pid, comm, callchain, skbaddr):
0297     event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
0298             skbaddr)
0299     all_event_list.append(event_info)
0300 
0301 def skb__skb_copy_datagram_iovec(name, context, cpu, sec, nsec, pid, comm, callchain,
0302     skbaddr, skblen):
0303     event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm,
0304             skbaddr, skblen)
0305     all_event_list.append(event_info)
0306 
0307 def handle_irq_handler_entry(event_info):
0308     (name, context, cpu, time, pid, comm, irq, irq_name) = event_info
0309     if cpu not in irq_dic.keys():
0310         irq_dic[cpu] = []
0311     irq_record = {'irq':irq, 'name':irq_name, 'cpu':cpu, 'irq_ent_t':time}
0312     irq_dic[cpu].append(irq_record)
0313 
0314 def handle_irq_handler_exit(event_info):
0315     (name, context, cpu, time, pid, comm, irq, ret) = event_info
0316     if cpu not in irq_dic.keys():
0317         return
0318     irq_record = irq_dic[cpu].pop()
0319     if irq != irq_record['irq']:
0320         return
0321     irq_record.update({'irq_ext_t':time})
0322     # if an irq doesn't include NET_RX softirq, drop.
0323     if 'event_list' in irq_record.keys():
0324         irq_dic[cpu].append(irq_record)
0325 
0326 def handle_irq_softirq_raise(event_info):
0327     (name, context, cpu, time, pid, comm, vec) = event_info
0328     if cpu not in irq_dic.keys() \
0329     or len(irq_dic[cpu]) == 0:
0330         return
0331     irq_record = irq_dic[cpu].pop()
0332     if 'event_list' in irq_record.keys():
0333         irq_event_list = irq_record['event_list']
0334     else:
0335         irq_event_list = []
0336     irq_event_list.append({'time':time, 'event':'sirq_raise'})
0337     irq_record.update({'event_list':irq_event_list})
0338     irq_dic[cpu].append(irq_record)
0339 
0340 def handle_irq_softirq_entry(event_info):
0341     (name, context, cpu, time, pid, comm, vec) = event_info
0342     net_rx_dic[cpu] = {'sirq_ent_t':time, 'event_list':[]}
0343 
0344 def handle_irq_softirq_exit(event_info):
0345     (name, context, cpu, time, pid, comm, vec) = event_info
0346     irq_list = []
0347     event_list = 0
0348     if cpu in irq_dic.keys():
0349         irq_list = irq_dic[cpu]
0350         del irq_dic[cpu]
0351     if cpu in net_rx_dic.keys():
0352         sirq_ent_t = net_rx_dic[cpu]['sirq_ent_t']
0353         event_list = net_rx_dic[cpu]['event_list']
0354         del net_rx_dic[cpu]
0355     if irq_list == [] or event_list == 0:
0356         return
0357     rec_data = {'sirq_ent_t':sirq_ent_t, 'sirq_ext_t':time,
0358             'irq_list':irq_list, 'event_list':event_list}
0359     # merge information related to a NET_RX softirq
0360     receive_hunk_list.append(rec_data)
0361 
0362 def handle_napi_poll(event_info):
0363     (name, context, cpu, time, pid, comm, napi, dev_name,
0364         work, budget) = event_info
0365     if cpu in net_rx_dic.keys():
0366         event_list = net_rx_dic[cpu]['event_list']
0367         rec_data = {'event_name':'napi_poll',
0368                 'dev':dev_name, 'event_t':time,
0369                 'work':work, 'budget':budget}
0370         event_list.append(rec_data)
0371 
0372 def handle_netif_rx(event_info):
0373     (name, context, cpu, time, pid, comm,
0374         skbaddr, skblen, dev_name) = event_info
0375     if cpu not in irq_dic.keys() \
0376     or len(irq_dic[cpu]) == 0:
0377         return
0378     irq_record = irq_dic[cpu].pop()
0379     if 'event_list' in irq_record.keys():
0380         irq_event_list = irq_record['event_list']
0381     else:
0382         irq_event_list = []
0383     irq_event_list.append({'time':time, 'event':'netif_rx',
0384         'skbaddr':skbaddr, 'skblen':skblen, 'dev_name':dev_name})
0385     irq_record.update({'event_list':irq_event_list})
0386     irq_dic[cpu].append(irq_record)
0387 
0388 def handle_netif_receive_skb(event_info):
0389     global of_count_rx_skb_list
0390 
0391     (name, context, cpu, time, pid, comm,
0392         skbaddr, skblen, dev_name) = event_info
0393     if cpu in net_rx_dic.keys():
0394         rec_data = {'event_name':'netif_receive_skb',
0395                 'event_t':time, 'skbaddr':skbaddr, 'len':skblen}
0396         event_list = net_rx_dic[cpu]['event_list']
0397         event_list.append(rec_data)
0398         rx_skb_list.insert(0, rec_data)
0399         if len(rx_skb_list) > buffer_budget:
0400             rx_skb_list.pop()
0401             of_count_rx_skb_list += 1
0402 
0403 def handle_net_dev_queue(event_info):
0404     global of_count_tx_queue_list
0405 
0406     (name, context, cpu, time, pid, comm,
0407         skbaddr, skblen, dev_name) = event_info
0408     skb = {'dev':dev_name, 'skbaddr':skbaddr, 'len':skblen, 'queue_t':time}
0409     tx_queue_list.insert(0, skb)
0410     if len(tx_queue_list) > buffer_budget:
0411         tx_queue_list.pop()
0412         of_count_tx_queue_list += 1
0413 
0414 def handle_net_dev_xmit(event_info):
0415     global of_count_tx_xmit_list
0416 
0417     (name, context, cpu, time, pid, comm,
0418         skbaddr, skblen, rc, dev_name) = event_info
0419     if rc == 0: # NETDEV_TX_OK
0420         for i in range(len(tx_queue_list)):
0421             skb = tx_queue_list[i]
0422             if skb['skbaddr'] == skbaddr:
0423                 skb['xmit_t'] = time
0424                 tx_xmit_list.insert(0, skb)
0425                 del tx_queue_list[i]
0426                 if len(tx_xmit_list) > buffer_budget:
0427                     tx_xmit_list.pop()
0428                     of_count_tx_xmit_list += 1
0429                 return
0430 
0431 def handle_kfree_skb(event_info):
0432     (name, context, cpu, time, pid, comm,
0433         skbaddr, protocol, location) = event_info
0434     for i in range(len(tx_queue_list)):
0435         skb = tx_queue_list[i]
0436         if skb['skbaddr'] == skbaddr:
0437             del tx_queue_list[i]
0438             return
0439     for i in range(len(tx_xmit_list)):
0440         skb = tx_xmit_list[i]
0441         if skb['skbaddr'] == skbaddr:
0442             skb['free_t'] = time
0443             tx_free_list.append(skb)
0444             del tx_xmit_list[i]
0445             return
0446     for i in range(len(rx_skb_list)):
0447         rec_data = rx_skb_list[i]
0448         if rec_data['skbaddr'] == skbaddr:
0449             rec_data.update({'handle':"kfree_skb",
0450                     'comm':comm, 'pid':pid, 'comm_t':time})
0451             del rx_skb_list[i]
0452             return
0453 
0454 def handle_consume_skb(event_info):
0455     (name, context, cpu, time, pid, comm, skbaddr) = event_info
0456     for i in range(len(tx_xmit_list)):
0457         skb = tx_xmit_list[i]
0458         if skb['skbaddr'] == skbaddr:
0459             skb['free_t'] = time
0460             tx_free_list.append(skb)
0461             del tx_xmit_list[i]
0462             return
0463 
0464 def handle_skb_copy_datagram_iovec(event_info):
0465     (name, context, cpu, time, pid, comm, skbaddr, skblen) = event_info
0466     for i in range(len(rx_skb_list)):
0467         rec_data = rx_skb_list[i]
0468         if skbaddr == rec_data['skbaddr']:
0469             rec_data.update({'handle':"skb_copy_datagram_iovec",
0470                     'comm':comm, 'pid':pid, 'comm_t':time})
0471             del rx_skb_list[i]
0472             return
[ Source navigation ] [ Diff markup ] [ Identifier search ] [ general search ]

This page was automatically generated by the 2.1.0 LXR engine.

The LXR team
Valid CSS 2.1! Valid HTML 4.01!