hi, I am trying to find out the avg cpu time spent in each of my user methods (exclusive of other methods invoked by a method). Hence the following snippet failed miserably: ----------------------- pid$target:a.out::entry { time[probefunc] = timestamp;} pid$target:a.out::return { @spent[probefunc] = avg(timestamp - time[probefunc]);} END { printa(@spent);} --------------------------------- Sample process int g(){} int f2(){g();} int f(){f2();g();} int main() { f(); } ------------------ sample output: g 13296 __fsr 32679(what really is this __fsr, i wonder sometimes?) f2 37930(<--------want to exclude time of g here) f 85044(<--------want to exclude times of f2 and g here) main 111241(<--------want to exclude time of f here) --------------------------- I know this may be quite easy but its not just clicking to me. I am on solaris 10. Kindly let me know of anyone''s experience with a similar problem or a possible solution. cheers, pankaj
Hi Pankaj,> I am trying to find out the avg cpu time spent in each of my user > methods (exclusive of other methods invoked by a method).Hmmm, getting the exclusive time across all functions is a bit tricky. I think it might be better to use a different tool here - the profiler in Sun Studio can be used on a running process (via the collect command), is very low overhead, and will give you exactly what you''re after (and it''s free now). In fact, the overhead of running collect on your process is likely to be less than probing every function call with DTrace. A way of getting close is to use the stackdepth variable to track timestamps when calling and returning from functions (and thus excluding time from the ancestor''s figure). I''ve had a few attempts at this and can''t seem to get it absolutely right (and this approach doesn''t really work if you''re limiting the modules to probe - you need to be counting every function call, even to functions outside the current module). IMHO, DTrace is more about iterating through questions you can ask quickly. So I''d imagine you''d be looking to spot problems rapidly using the inclusive time, and then focus in on interesting functions by limiting probe scope or using predicates. Or, alternatively you could do something like a flowindent showing the inclusive times, which would make it clear which functions are the expensive ones and which of their callees is expensive. Of course, the real power of DTrace is that you don''t just have to make do with averages - you can quantize the time spent in a function into buckets, which gives you visibility of a function which is normally cheap, but expensive on a few rare occasions. Then, you can use speculative tracing to work out what''s actually going on in those rare, expensive cases. You can''t easily do this with a traditional profiler, unless you know up front what the expensive cases are and can simulate them. Finally, when doing this sort of thing, you''ll want to use vtimestamp rather than timestamp. The latter is a measure of wall clock time, and as a result might make you think a particular function is expensive when actually it''s just a point at which you were pre-empted by another process. HTH, -- Philip Beevers Fidessa Infrastructure Development mailto:philip.beevers at fidessa.com phone: +44 1483 206571 ****************************************************************** This message is intended only for the stated addressee(s) and may be confidential. Access to this email by anyone else is unauthorised. Any opinions expressed in this email do not necessarily reflect the opinions of royalblue. Any unauthorised disclosure, use or dissemination, either whole or in part is prohibited. If you are not the intended recipient of this message, please notify the sender immediately. ******************************************************************
On 2/16/06, Pankaj Maurya <pankaj at iitk.ac.in> wrote:> hi, > I am trying to find out the avg cpu time spent in each of my user > methods (exclusive of other methods invoked by a method). > Hence the following snippet failed miserably: > ----------------------- > pid$target:a.out::entry > { time[probefunc] = timestamp;} > pid$target:a.out::return > { @spent[probefunc] = avg(timestamp - time[probefunc]);} > END > { printa(@spent);}I was thinking about this problem the other day, too. I had a thought for something that might work, but I haven''t tried it yet. It essentially involves replicating the call stack to some extent. The following is just an outline of what I''m thinking. It needs a way to get the calling function in a form that exactly matches what probefunc would give you, or it could use something other than probefunc that would yield the current function name. It also assumes a singly-threaded program, but that could be fixed by also including tid as a key to self->ts. And ''level'' might need to be a thread-local variable. pid$1:::entry { ts = vtimestamp; caller_time = ts - self->ts[level,<calling func, as a string that matches probefunc>]; @func_time[<calling func, as above>] = sum(caller_time); level++; self->ts[level,probefunc] = ts; } pid$1:::exit { ts = vtimestamp; func_time = ts - self->ts[level,probefunc]; @func_time[probefunc] = sum(func_time); level--; self->ts[level,<calling func, as above>] = ts; } END { printa(@func_time); } I haven''t tried this yet, so I don''t know if it''s at all feasible. Can anyone else comment on whether this should work and do what I think it should do? Chad Mynhier
Hi Chad,> > I haven''t tried this yet, so I don''t know if it''s at all feasible. > Can anyone else comment on whether this should work and do > what I think it should do?Yep, this is what I ended up doing earlier; I just use an associative array to store the function names alongside the stack depth. My script is trying to keep hold of both the inclusive averages and exclusive totals, which makes it too messy to share :-) I''m testing this on Solaris 10, but it looks like if you''re running Nevada build 20 or later, there''s a built-in variable called "ustackdepth" which means you don''t have to count the depth yourself. Also in Nevada, the ucaller variable and ufunc() action which Jonathan mentioned in another thread today would remove the need to remember all those function names. -- Philip Beevers Fidessa Infrastructure Development mailto:philip.beevers at fidessa.com phone: +44 1483 206571 ****************************************************************** This message is intended only for the stated addressee(s) and may be confidential. Access to this email by anyone else is unauthorised. Any opinions expressed in this email do not necessarily reflect the opinions of royalblue. Any unauthorised disclosure, use or dissemination, either whole or in part is prohibited. If you are not the intended recipient of this message, please notify the sender immediately. ******************************************************************