Re: Example looking at the periodic timers

[William Cohen <wcohen at redhat dot com>]

On 12/14/2011 06:23 AM, Mark Wielaard wrote:
> On Tue, 2011-12-13 at 16:57 -0500, William Cohen wrote:
>> One case that people would like to use SystemTap for is finding out
>> why some latency sensitive application is slowed down every x seconds.
>> They know that something keeps running on the machine and slowing
>> things down, but they don't know what it is.
>>
>> I have been playing around with the timer tracepoints and came up with
>> the attached script, periodic.stp.  When the script exits it prints
>> out a list of the periodic timers, sorted from most frequently to
>> least frequently fired timer. It also include the average period for
>> the timer.  The functions that have [dg] are things put into the
>> delayed_work_queues.

Hi Mark,

Thanks for the feedback. I made some revisions and attached the new peroidic.stp.

> 
> Looks nice. I would add a begin probe to announce the script started and
> that the user must press control-C to get results and/or make the end
> probe a end,timer.s(10) probe so that you get output every 10 seconds
> (then you can also clean up the tables).

The begin probe would be easy enough to add. Loading in thing with the "--all-modules" can slow things down, so that would give people some useful feedback.  The timer.s(10) might not be so useful when people are looking for things that have a period longer than 10 seconds.  There are things in the kernel that run every 600 seconds or so, and timer.s(10) would miss those. Maybe make an optional argument for periodic output/cleanup.

> 
> Are the timer addresses really useful? I just don't know how to
> interpret them, does it matter on which timer some event fired?

The timer addresses are probably not that useful in the output and I was debating whether to remove them before posting the script on the mailing list. It was more for when I was creating things and I could see that the same functions were attached to different timers. Now that the script appears to be working I removed that from the output.

> Printing the comms on process_timeout is a nice touch. Maybe explicitly
> prefix it with process: or some other string making that more clear?
> 
> You could also add modname() to the output, then people can more easily
> see whether it is a kernel or module function being triggered.

The output for the function could use some tweaks. The modname() sounds like a good addition.  Maybe replace the #timer columnn with type: "module", "process", "delayed_work" as in the revised script.

> I also got some functions that don't immediately make sense, they don't
> seem to fall inside either the kernel nor a module. Did you figure out
> where they point at? From seeing the high address I assume they are
> actually dynamically allocated structures, not direct functions.

Which functions are you referring to? I think that the raw addresses in the output are might the timers related to the systemtap instrumentation module.

-Will

Attachment: periodic.stp
Description: Text document