Re: Array handling question

[Josh Stone <jistone@redhat.com>]

On 07/20/2015 11:14 AM, Zoltan Kiss wrote:
> Hi,
> 
> I have troubles to get what I want from linetimes.stp example, so I've 
> decided to create my own somewhat simplified version. I'm currently 
> interested in the average runtime of a function after a certain number 
> of runs, but apparently it gives me values like 74279383992077, which is 
> clearly wrong. And I have a feeling I'm misunderstanding something 
> obvious about the array handling, but I couldn't figure out what.
> Could anyone give me an advice about what am I missing?

I don't see where you are doing anything with arrays
-- do you mean stats?

> Regards,
> 
> Zoltan Kiss
> 
> And here is my example script:
> 
> global cnt = 0;
> global starttime = 0;

These two are scalar longs.

> global runtimes;

This is a statistic value, thanks to your '<<<' assignment.

> probe process(<procname>).function(<funcname>).call {
>          starttime = gettimeofday_ns();
> }

Since starttime is a scalar, this will behave badly if you ever have
multiple calls active at the same time.  These could be simultaneous
from separate threads or even just recursive calls in a single thread.

So this is usually where we'd recommend at least a tid()-indexed array,
and probably another nesting index to deal with recursion.  But you
don't need to write that manually; stap has @entry for this purpose.

> probe process(<procname>).function(<funcname>).return {
> 	runtime = gettimeofday_ns() - starttime;
> 	starttime = 0;

Consider this sequence with two threads, maybe from different processes:

1. Thread A reaches the .call and sets starttime.
2. Thread B reaches the .call and sets a later starttime.
3. Either thread reaches the .return, uses starttime, and sets it to 0.
4. The remaining thread reaches .return and uses gettimeofday_ns - 0.
This is nanoseconds since the Unix epoch, a large value that will skew
your @avg so much to be useless.

Recursion has a similar story, with call-A, call-B, return-B, return-A.

With @entry, you can remove your .call probe and just write:

  runtime = gettimeofday(ns) - @entry(gettimeofday_ns())

That will automatically take care of multiple threads and recursion.

> 	runtimes <<< runtime;
> 	if (cnt > 50000) {
> 		printf("Runtime avg: %u\n", @avg(runtimes));
> 		delete runtimes;
> 		cnt = 0;
> 	}
> 	cnt++;
> }