#! /usr/bin/env stap ############################################################ # linux_xmit_latency.stp # Author: William Cohen # Porivdes information through procfs about the amount of time # spent in the various steps for sending data via network interfaces ############################################################ global sys_t, t0, device_name global tx_device, tx_queue_t, tx_netdevice_t, tx_free_t probe kernel.trace("sys_enter") { sys_t[tid()] = gettimeofday_us() } probe kernel.trace("sys_exit") { delete sys_t[tid()] } probe kernel.trace("net_dev_queue") { t = gettimeofday_us() s0 = sys_t[tid()] if (s0) { t0[$skb] = s0 dev = kernel_string($skb->dev->name) tx_device[$skb] = dev tx_queue_t[dev] <<< t - s0 device_name[dev] <<< 1 } } probe kernel.trace("net_dev_xmit") { t = gettimeofday_us() s0 = t0[$skb] if (s0) { tx_netdevice_t[tx_device[$skb]] <<< t - s0 } } probe kernel.trace("kfree_skb"), kernel.trace("consume_skb") { t = gettimeofday_us() s0 = t0[$skb] if (s0) { tx_free_t[tx_device[$skb]] <<< t - s0 delete tx_device[$skb] delete t0[$skb] } } probe procfs("net_latency").read { /* print header */ output = sprintf("#dev: tx_queue_n tx_queue_avg tx_queue_sum tx_xmit_n tx_xmit_avg tx_xmit_sum tx_free_n tx tx_free_avg tx_free_sum\n") /* write out info for each device */ foreach(d+ in device_name){ output = sprintf("%s%s: %d %d %d %d %d %d %d %d %d\n", output, d, @count(tx_queue_t[d]), @count(tx_queue_t[d]) ? @avg(tx_queue_t[d]) : 0, @count(tx_queue_t[d]) ? @sum(tx_queue_t[d]) : 0, @count(tx_netdevice_t[d]), @count(tx_netdevice_t[d]) ? @avg(tx_netdevice_t[d]) : 0, @count(tx_netdevice_t[d]) ? @sum(tx_netdevice_t[d]) : 0, @count(tx_free_t[d]), @count(tx_free_t[d]) ? @avg(tx_free_t[d]) : 0, @count(tx_free_t[d])? @sum(tx_free_t[d]) : 0 ) } $value = output } /* Following is for development purposes to show distributions in times */ probe end { printf("histogram of tx times\n") foreach ([devname+] in device_name) { if (@count(tx_queue_t[devname])) { printf("Device:%s tx_queued:%d avg:%d max:%d (microseconds)\n", devname, @count(tx_queue_t[devname]), @avg(tx_queue_t[devname]), @max(tx_queue_t[devname])) println(@hist_log(tx_queue_t[devname])) } if (@count(tx_netdevice_t[devname])) { printf("Device:%s tx_xmit:%d avg:%d max:%d (microseconds)\n", devname, @count(tx_netdevice_t[devname]), @avg(tx_netdevice_t[devname]), @max(tx_netdevice_t[devname])) println(@hist_log(tx_netdevice_t[devname])) } if (@count(tx_free_t[devname])) { printf("Device:%s tx_freed:%d avg:%d max:%d (microseconds)\n", devname, @count(tx_free_t[devname]), @avg(tx_free_t[devname]), @max(tx_free_t[devname])) println(@hist_log(tx_free_t[devname])) } } }