Improving the performance of netdev-times.py script

[William Cohen <wcohen@redhat.com>]

[-- Attachment #1: Type: text/plain, Size: 2258 bytes --]

Hi All,

I was experimenting with the perf utils scripts and  I noticed that the netdev-times.py was really slow.  I modified the python script to run Python profiling and found that a lot of time was spent in the handle_skb_copy_datagram_iovec because there can be many many possible entries in rx_skb_list and the code did a linear search through the possible matches.  Python dictionaries use hashing and could be much faster.  I modified rx_skb_list to be a dictionary and the runtime for my example went from 5 minutes down to 11 seconds.

The attached patch shows the changes.  I compared the output between the original perf script and the patched on; there were 8 lines that differed (as shown below), so there is still something not quite correct in the patch.  The output should be identical.  Comments and feedback would be appreciated on this patch.

-Will

[wcohen@santana profiling]$ diff -u /tmp/original /tmp/improved |more
--- /tmp/original	2014-06-12 21:49:51.475501535 -0400
+++ /tmp/improved	2014-06-12 21:44:35.942703446 -0400
@@ -985,8 +985,6 @@
   softirq_entry(+0.010msec)
          |
          |---netif_receive_skb(+0.021msec skb=ffff8803d7d79500 len=50)
-         |            |
-         |      skb_copy_datagram_iovec(+138.745msec 4574:gnome-shell)
          |
          |---netif_receive_skb(+0.044msec skb=ffff8803d7d79500 len=72)
          |            |
@@ -1011,8 +1009,6 @@
   softirq_entry(+0.010msec)
          |
          |---netif_receive_skb(+0.021msec skb=ffff8803b0c25e00 len=50)
-         |            |
-         |      skb_copy_datagram_iovec(+37.385msec 6044:gnome-terminal-)
          |
   napi_poll_exit(+0.047msec em1)
 
@@ -1676,8 +1672,6 @@
   softirq_entry(+0.007msec)
          |
          |---netif_receive_skb(+0.017msec skb=ffff8803d704ff00 len=52)
-         |            |
-         |      skb_copy_datagram_iovec(+556.930msec 1301:Xorg)
          |
   napi_poll_exit(+0.067msec em1)
 
@@ -2475,8 +2469,6 @@
          |---netif_receive_skb(+0.026msec skb=ffff8803b104a800 len=52)
          |
          |---netif_receive_skb(+0.108msec skb=ffff8803b104a800 len=52)
-         |            |
-         |      skb_copy_datagram_iovec(+64.266msec 1301:Xorg)
          |
   napi_poll_exit(+0.125msec em1)
 

[-- Attachment #2: netdev-times-optim.patch --]
[-- Type: text/x-patch, Size: 2294 bytes --]

--- /usr/libexec/perf-core/scripts/python/netdev-times.py	2014-06-07 21:33:33.000000000 -0400
+++ /home/wcohen/libexec/perf-core/scripts/python/netdev-times.py	2014-06-13 09:46:03.809403435 -0400
@@ -23,7 +23,7 @@
 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
+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
@@ -387,9 +387,9 @@
 			    '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()
+		if len(rx_skb_list) < buffer_budget:
+                        rx_skb_list[skbaddr] = rec_data
+                else:
 			of_count_rx_skb_list += 1
 
 def handle_net_dev_queue(event_info):
@@ -435,13 +435,11 @@
 			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
+	if skbaddr in rx_skb_list.keys():
+                rx_skb_list[skbaddr].update({'handle':"kfree_skb",
+                                 'comm':comm, 'pid':pid, 'comm_t':time})
+                del rx_skb_list[skbaddr]
+                return
 
 def handle_consume_skb(event_info):
 	(name, context, cpu, time, pid, comm, skbaddr) = event_info
@@ -455,10 +453,8 @@
 
 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
+	if skbaddr in rx_skb_list.keys():
+		rx_skb_list[skbaddr].update({'handle':"skb_copy_datagram_iovec",
+				'comm':comm, 'pid':pid, 'comm_t':time})
+		del rx_skb_list[skbaddr]
+		return