diff options
| author | Takashi Iwai <tiwai@suse.de> | 2010-11-03 17:51:26 +0300 | 
|---|---|---|
| committer | Takashi Iwai <tiwai@suse.de> | 2010-11-03 17:51:26 +0300 | 
| commit | 69dbdd819599e2f3b77c172e83af512845bca5ad (patch) | |
| tree | 49939d8b80ec2115a801eae2aebc21f23867c876 /tools/perf/scripts/python/netdev-times.py | |
| parent | 87232dd49aeb6b7d1af291edca8bd129a82ef4b5 (diff) | |
| parent | 75e3f3137cb570661c2ad3035a139dda671fbb63 (diff) | |
| download | linux-69dbdd819599e2f3b77c172e83af512845bca5ad.tar.xz | |
Merge branch 'fix/asoc' into for-linus
Diffstat (limited to 'tools/perf/scripts/python/netdev-times.py')
| -rw-r--r-- | tools/perf/scripts/python/netdev-times.py | 464 | 
1 files changed, 464 insertions, 0 deletions
| diff --git a/tools/perf/scripts/python/netdev-times.py b/tools/perf/scripts/python/netdev-times.py new file mode 100644 index 000000000000..9aa0a32972e8 --- /dev/null +++ b/tools/perf/scripts/python/netdev-times.py @@ -0,0 +1,464 @@ +# Display a process of packets and processed time. +# It helps us to investigate networking or network device. +# +# options +# tx: show only tx chart +# rx: show only rx chart +# dev=: show only thing related to specified device +# debug: work with debug mode. It shows buffer status. + +import os +import sys + +sys.path.append(os.environ['PERF_EXEC_PATH'] + \ +	'/scripts/python/Perf-Trace-Util/lib/Perf/Trace') + +from perf_trace_context import * +from Core import * +from Util import * + +all_event_list = []; # insert all tracepoint event related with this script +irq_dic = {}; # key is cpu and value is a list which stacks irqs +              # which raise NET_RX softirq +net_rx_dic = {}; # key is cpu and value include time of NET_RX softirq-entry +		 # and a list which stacks receive +receive_hunk_list = []; # a list which include a sequence of receive events +rx_skb_list = []; # received packet list for matching +		       # skb_copy_datagram_iovec + +buffer_budget = 65536; # the budget of rx_skb_list, tx_queue_list and +		       # tx_xmit_list +of_count_rx_skb_list = 0; # overflow count + +tx_queue_list = []; # list of packets which pass through dev_queue_xmit +of_count_tx_queue_list = 0; # overflow count + +tx_xmit_list = [];  # list of packets which pass through dev_hard_start_xmit +of_count_tx_xmit_list = 0; # overflow count + +tx_free_list = [];  # list of packets which is freed + +# options +show_tx = 0; +show_rx = 0; +dev = 0; # store a name of device specified by option "dev=" +debug = 0; + +# indices of event_info tuple +EINFO_IDX_NAME=   0 +EINFO_IDX_CONTEXT=1 +EINFO_IDX_CPU=    2 +EINFO_IDX_TIME=   3 +EINFO_IDX_PID=    4 +EINFO_IDX_COMM=   5 + +# Calculate a time interval(msec) from src(nsec) to dst(nsec) +def diff_msec(src, dst): +	return (dst - src) / 1000000.0 + +# Display a process of transmitting a packet +def print_transmit(hunk): +	if dev != 0 and hunk['dev'].find(dev) < 0: +		return +	print "%7s %5d %6d.%06dsec %12.3fmsec      %12.3fmsec" % \ +		(hunk['dev'], hunk['len'], +		nsecs_secs(hunk['queue_t']), +		nsecs_nsecs(hunk['queue_t'])/1000, +		diff_msec(hunk['queue_t'], hunk['xmit_t']), +		diff_msec(hunk['xmit_t'], hunk['free_t'])) + +# Format for displaying rx packet processing +PF_IRQ_ENTRY= "  irq_entry(+%.3fmsec irq=%d:%s)" +PF_SOFT_ENTRY="  softirq_entry(+%.3fmsec)" +PF_NAPI_POLL= "  napi_poll_exit(+%.3fmsec %s)" +PF_JOINT=     "         |" +PF_WJOINT=    "         |            |" +PF_NET_RECV=  "         |---netif_receive_skb(+%.3fmsec skb=%x len=%d)" +PF_NET_RX=    "         |---netif_rx(+%.3fmsec skb=%x)" +PF_CPY_DGRAM= "         |      skb_copy_datagram_iovec(+%.3fmsec %d:%s)" +PF_KFREE_SKB= "         |      kfree_skb(+%.3fmsec location=%x)" +PF_CONS_SKB=  "         |      consume_skb(+%.3fmsec)" + +# Display a process of received packets and interrputs associated with +# a NET_RX softirq +def print_receive(hunk): +	show_hunk = 0 +	irq_list = hunk['irq_list'] +	cpu = irq_list[0]['cpu'] +	base_t = irq_list[0]['irq_ent_t'] +	# check if this hunk should be showed +	if dev != 0: +		for i in range(len(irq_list)): +			if irq_list[i]['name'].find(dev) >= 0: +				show_hunk = 1 +				break +	else: +		show_hunk = 1 +	if show_hunk == 0: +		return + +	print "%d.%06dsec cpu=%d" % \ +		(nsecs_secs(base_t), nsecs_nsecs(base_t)/1000, cpu) +	for i in range(len(irq_list)): +		print PF_IRQ_ENTRY % \ +			(diff_msec(base_t, irq_list[i]['irq_ent_t']), +			irq_list[i]['irq'], irq_list[i]['name']) +		print PF_JOINT +		irq_event_list = irq_list[i]['event_list'] +		for j in range(len(irq_event_list)): +			irq_event = irq_event_list[j] +			if irq_event['event'] == 'netif_rx': +				print PF_NET_RX % \ +					(diff_msec(base_t, irq_event['time']), +					irq_event['skbaddr']) +				print PF_JOINT +	print PF_SOFT_ENTRY % \ +		diff_msec(base_t, hunk['sirq_ent_t']) +	print PF_JOINT +	event_list = hunk['event_list'] +	for i in range(len(event_list)): +		event = event_list[i] +		if event['event_name'] == 'napi_poll': +			print PF_NAPI_POLL % \ +			    (diff_msec(base_t, event['event_t']), event['dev']) +			if i == len(event_list) - 1: +				print "" +			else: +				print PF_JOINT +		else: +			print PF_NET_RECV % \ +			    (diff_msec(base_t, event['event_t']), event['skbaddr'], +				event['len']) +			if 'comm' in event.keys(): +				print PF_WJOINT +				print PF_CPY_DGRAM % \ +					(diff_msec(base_t, event['comm_t']), +					event['pid'], event['comm']) +			elif 'handle' in event.keys(): +				print PF_WJOINT +				if event['handle'] == "kfree_skb": +					print PF_KFREE_SKB % \ +						(diff_msec(base_t, +						event['comm_t']), +						event['location']) +				elif event['handle'] == "consume_skb": +					print PF_CONS_SKB % \ +						diff_msec(base_t, +							event['comm_t']) +			print PF_JOINT + +def trace_begin(): +	global show_tx +	global show_rx +	global dev +	global debug + +	for i in range(len(sys.argv)): +		if i == 0: +			continue +		arg = sys.argv[i] +		if arg == 'tx': +			show_tx = 1 +		elif arg =='rx': +			show_rx = 1 +		elif arg.find('dev=',0, 4) >= 0: +			dev = arg[4:] +		elif arg == 'debug': +			debug = 1 +	if show_tx == 0  and show_rx == 0: +		show_tx = 1 +		show_rx = 1 + +def trace_end(): +	# order all events in time +	all_event_list.sort(lambda a,b :cmp(a[EINFO_IDX_TIME], +					    b[EINFO_IDX_TIME])) +	# process all events +	for i in range(len(all_event_list)): +		event_info = all_event_list[i] +		name = event_info[EINFO_IDX_NAME] +		if name == 'irq__softirq_exit': +			handle_irq_softirq_exit(event_info) +		elif name == 'irq__softirq_entry': +			handle_irq_softirq_entry(event_info) +		elif name == 'irq__softirq_raise': +			handle_irq_softirq_raise(event_info) +		elif name == 'irq__irq_handler_entry': +			handle_irq_handler_entry(event_info) +		elif name == 'irq__irq_handler_exit': +			handle_irq_handler_exit(event_info) +		elif name == 'napi__napi_poll': +			handle_napi_poll(event_info) +		elif name == 'net__netif_receive_skb': +			handle_netif_receive_skb(event_info) +		elif name == 'net__netif_rx': +			handle_netif_rx(event_info) +		elif name == 'skb__skb_copy_datagram_iovec': +			handle_skb_copy_datagram_iovec(event_info) +		elif name == 'net__net_dev_queue': +			handle_net_dev_queue(event_info) +		elif name == 'net__net_dev_xmit': +			handle_net_dev_xmit(event_info) +		elif name == 'skb__kfree_skb': +			handle_kfree_skb(event_info) +		elif name == 'skb__consume_skb': +			handle_consume_skb(event_info) +	# display receive hunks +	if show_rx: +		for i in range(len(receive_hunk_list)): +			print_receive(receive_hunk_list[i]) +	# display transmit hunks +	if show_tx: +		print "   dev    len      Qdisc        " \ +			"       netdevice             free" +		for i in range(len(tx_free_list)): +			print_transmit(tx_free_list[i]) +	if debug: +		print "debug buffer status" +		print "----------------------------" +		print "xmit Qdisc:remain:%d overflow:%d" % \ +			(len(tx_queue_list), of_count_tx_queue_list) +		print "xmit netdevice:remain:%d overflow:%d" % \ +			(len(tx_xmit_list), of_count_tx_xmit_list) +		print "receive:remain:%d overflow:%d" % \ +			(len(rx_skb_list), of_count_rx_skb_list) + +# called from perf, when it finds a correspoinding event +def irq__softirq_entry(name, context, cpu, sec, nsec, pid, comm, vec): +	if symbol_str("irq__softirq_entry", "vec", vec) != "NET_RX": +		return +	event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, vec) +	all_event_list.append(event_info) + +def irq__softirq_exit(name, context, cpu, sec, nsec, pid, comm, vec): +	if symbol_str("irq__softirq_entry", "vec", vec) != "NET_RX": +		return +	event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, vec) +	all_event_list.append(event_info) + +def irq__softirq_raise(name, context, cpu, sec, nsec, pid, comm, vec): +	if symbol_str("irq__softirq_entry", "vec", vec) != "NET_RX": +		return +	event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, vec) +	all_event_list.append(event_info) + +def irq__irq_handler_entry(name, context, cpu, sec, nsec, pid, comm, +			irq, irq_name): +	event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, +			irq, irq_name) +	all_event_list.append(event_info) + +def irq__irq_handler_exit(name, context, cpu, sec, nsec, pid, comm, irq, ret): +	event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, irq, ret) +	all_event_list.append(event_info) + +def napi__napi_poll(name, context, cpu, sec, nsec, pid, comm, napi, dev_name): +	event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, +			napi, dev_name) +	all_event_list.append(event_info) + +def net__netif_receive_skb(name, context, cpu, sec, nsec, pid, comm, skbaddr, +			skblen, dev_name): +	event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, +			skbaddr, skblen, dev_name) +	all_event_list.append(event_info) + +def net__netif_rx(name, context, cpu, sec, nsec, pid, comm, skbaddr, +			skblen, dev_name): +	event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, +			skbaddr, skblen, dev_name) +	all_event_list.append(event_info) + +def net__net_dev_queue(name, context, cpu, sec, nsec, pid, comm, +			skbaddr, skblen, dev_name): +	event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, +			skbaddr, skblen, dev_name) +	all_event_list.append(event_info) + +def net__net_dev_xmit(name, context, cpu, sec, nsec, pid, comm, +			skbaddr, skblen, rc, dev_name): +	event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, +			skbaddr, skblen, rc ,dev_name) +	all_event_list.append(event_info) + +def skb__kfree_skb(name, context, cpu, sec, nsec, pid, comm, +			skbaddr, protocol, location): +	event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, +			skbaddr, protocol, location) +	all_event_list.append(event_info) + +def skb__consume_skb(name, context, cpu, sec, nsec, pid, comm, skbaddr): +	event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, +			skbaddr) +	all_event_list.append(event_info) + +def skb__skb_copy_datagram_iovec(name, context, cpu, sec, nsec, pid, comm, +	skbaddr, skblen): +	event_info = (name, context, cpu, nsecs(sec, nsec), pid, comm, +			skbaddr, skblen) +	all_event_list.append(event_info) + +def handle_irq_handler_entry(event_info): +	(name, context, cpu, time, pid, comm, irq, irq_name) = event_info +	if cpu not in irq_dic.keys(): +		irq_dic[cpu] = [] +	irq_record = {'irq':irq, 'name':irq_name, 'cpu':cpu, 'irq_ent_t':time} +	irq_dic[cpu].append(irq_record) + +def handle_irq_handler_exit(event_info): +	(name, context, cpu, time, pid, comm, irq, ret) = event_info +	if cpu not in irq_dic.keys(): +		return +	irq_record = irq_dic[cpu].pop() +	if irq != irq_record['irq']: +		return +	irq_record.update({'irq_ext_t':time}) +	# if an irq doesn't include NET_RX softirq, drop. +	if 'event_list' in irq_record.keys(): +		irq_dic[cpu].append(irq_record) + +def handle_irq_softirq_raise(event_info): +	(name, context, cpu, time, pid, comm, vec) = event_info +	if cpu not in irq_dic.keys() \ +	or len(irq_dic[cpu]) == 0: +		return +	irq_record = irq_dic[cpu].pop() +	if 'event_list' in irq_record.keys(): +		irq_event_list = irq_record['event_list'] +	else: +		irq_event_list = [] +	irq_event_list.append({'time':time, 'event':'sirq_raise'}) +	irq_record.update({'event_list':irq_event_list}) +	irq_dic[cpu].append(irq_record) + +def handle_irq_softirq_entry(event_info): +	(name, context, cpu, time, pid, comm, vec) = event_info +	net_rx_dic[cpu] = {'sirq_ent_t':time, 'event_list':[]} + +def handle_irq_softirq_exit(event_info): +	(name, context, cpu, time, pid, comm, vec) = event_info +	irq_list = [] +	event_list = 0 +	if cpu in irq_dic.keys(): +		irq_list = irq_dic[cpu] +		del irq_dic[cpu] +	if cpu in net_rx_dic.keys(): +		sirq_ent_t = net_rx_dic[cpu]['sirq_ent_t'] +		event_list = net_rx_dic[cpu]['event_list'] +		del net_rx_dic[cpu] +	if irq_list == [] or event_list == 0: +		return +	rec_data = {'sirq_ent_t':sirq_ent_t, 'sirq_ext_t':time, +		    'irq_list':irq_list, 'event_list':event_list} +	# merge information realted to a NET_RX softirq +	receive_hunk_list.append(rec_data) + +def handle_napi_poll(event_info): +	(name, context, cpu, time, pid, comm, napi, dev_name) = event_info +	if cpu in net_rx_dic.keys(): +		event_list = net_rx_dic[cpu]['event_list'] +		rec_data = {'event_name':'napi_poll', +				'dev':dev_name, 'event_t':time} +		event_list.append(rec_data) + +def handle_netif_rx(event_info): +	(name, context, cpu, time, pid, comm, +		skbaddr, skblen, dev_name) = event_info +	if cpu not in irq_dic.keys() \ +	or len(irq_dic[cpu]) == 0: +		return +	irq_record = irq_dic[cpu].pop() +	if 'event_list' in irq_record.keys(): +		irq_event_list = irq_record['event_list'] +	else: +		irq_event_list = [] +	irq_event_list.append({'time':time, 'event':'netif_rx', +		'skbaddr':skbaddr, 'skblen':skblen, 'dev_name':dev_name}) +	irq_record.update({'event_list':irq_event_list}) +	irq_dic[cpu].append(irq_record) + +def handle_netif_receive_skb(event_info): +	global of_count_rx_skb_list + +	(name, context, cpu, time, pid, comm, +		skbaddr, skblen, dev_name) = event_info +	if cpu in net_rx_dic.keys(): +		rec_data = {'event_name':'netif_receive_skb', +			    'event_t':time, 'skbaddr':skbaddr, 'len':skblen} +		event_list = net_rx_dic[cpu]['event_list'] +		event_list.append(rec_data) +		rx_skb_list.insert(0, rec_data) +		if len(rx_skb_list) > buffer_budget: +			rx_skb_list.pop() +			of_count_rx_skb_list += 1 + +def handle_net_dev_queue(event_info): +	global of_count_tx_queue_list + +	(name, context, cpu, time, pid, comm, +		skbaddr, skblen, dev_name) = event_info +	skb = {'dev':dev_name, 'skbaddr':skbaddr, 'len':skblen, 'queue_t':time} +	tx_queue_list.insert(0, skb) +	if len(tx_queue_list) > buffer_budget: +		tx_queue_list.pop() +		of_count_tx_queue_list += 1 + +def handle_net_dev_xmit(event_info): +	global of_count_tx_xmit_list + +	(name, context, cpu, time, pid, comm, +		skbaddr, skblen, rc, dev_name) = event_info +	if rc == 0: # NETDEV_TX_OK +		for i in range(len(tx_queue_list)): +			skb = tx_queue_list[i] +			if skb['skbaddr'] == skbaddr: +				skb['xmit_t'] = time +				tx_xmit_list.insert(0, skb) +				del tx_queue_list[i] +				if len(tx_xmit_list) > buffer_budget: +					tx_xmit_list.pop() +					of_count_tx_xmit_list += 1 +				return + +def handle_kfree_skb(event_info): +	(name, context, cpu, time, pid, comm, +		skbaddr, protocol, location) = event_info +	for i in range(len(tx_queue_list)): +		skb = tx_queue_list[i] +		if skb['skbaddr'] == skbaddr: +			del tx_queue_list[i] +			return +	for i in range(len(tx_xmit_list)): +		skb = tx_xmit_list[i] +		if skb['skbaddr'] == skbaddr: +			skb['free_t'] = time +			tx_free_list.append(skb) +			del tx_xmit_list[i] +			return +	for i in range(len(rx_skb_list)): +		rec_data = rx_skb_list[i] +		if rec_data['skbaddr'] == skbaddr: +			rec_data.update({'handle':"kfree_skb", +					'comm':comm, 'pid':pid, 'comm_t':time}) +			del rx_skb_list[i] +			return + +def handle_consume_skb(event_info): +	(name, context, cpu, time, pid, comm, skbaddr) = event_info +	for i in range(len(tx_xmit_list)): +		skb = tx_xmit_list[i] +		if skb['skbaddr'] == skbaddr: +			skb['free_t'] = time +			tx_free_list.append(skb) +			del tx_xmit_list[i] +			return + +def handle_skb_copy_datagram_iovec(event_info): +	(name, context, cpu, time, pid, comm, skbaddr, skblen) = event_info +	for i in range(len(rx_skb_list)): +		rec_data = rx_skb_list[i] +		if skbaddr == rec_data['skbaddr']: +			rec_data.update({'handle':"skb_copy_datagram_iovec", +					'comm':comm, 'pid':pid, 'comm_t':time}) +			del rx_skb_list[i] +			return | 
