No title [ ]

Posted on Mon 29 March 2004 by alex in general

Today I was hacking about with the Linux Trace Toolkit in an attempt to measure some latencies in my code. Although the toolkit comes with a nice graphical utility that allows you to look through events and see what is going it isn't very good for finding particular instances occur. I previously did this instrumenting my code with a unusual
sys-call when something took too long. However its a bit of a hack because you have to modify the code each time you want to measure a new period. So today I wrote href=http://www.bennee.com/cgi-bin/viewcvs.cgi/src/perl/pdump.pl?annotate=1.2>this
perl script to make my life easier.

To use it you need dump the LTT trace files into text form. You can either do this from the GUI or using tracedump

[alex@cambridge alex]$ tracedump ll_long

Now you need to identify the events you want to trace. You currently pipe the data into pdump.pl with or without the event option (without the event option it will show all System calls it can measure).

[alex@cambridge alex]$ cat ll_long.data | pdump.pl -e readv
PID: 161 has events
Event: SYSCALL : readv; PC : 0x00405C70
PID: 160 has events
Event: SYSCALL : readv; PC : 0x00405C70
PID: 145 has events
Event: SYSCALL : readv; PC : 0x004051F4

Now you can parse the data again with a pid and time (in case the default 30ms is not what you want).

[alex@cambridge alex]$ cat ll_long.data | pdump.pl -e readv -p 161 -t 30000
30683 delay, previous TS: 1080574392047396
prev: Syscall entry          1,080,574,392,047,396      161     12      SYSCALL : readv; PC : 0x00405C70
curr: Syscall entry          1,080,574,392,078,079      161     12      SYSCALL : readv; PC : 0x00405C70
598 events, total = 9953145,  average time 16644.0551839465

To be exact you can just set the --event flag to the PC you are interested.