Re: Querry regarding LTTng instrumentation and timing results on LTTV...

Mathieu Desnoyers <[email protected]> Tue, 4 Sep 2007 07:32:30 -0400
Newsgroups gmane.linux.kernel.tracing
Message-ID <20070904113230.GB14618@Krystal>
* satish ([email protected]) wrote:
> 
> Hi all ,
> Iam newbie to LTTng..
> 
> i am using genevent-0.31 for instrumenting 2.6.18 kernel to get my root filesystem's 
> 
> read performance. I am able to put Marker before the function i am interested to measure 
> 
> performance. After collection of data using lttctl, when i am using lttv for graphical display 
> 
> i am not able to get any timing information about this particular instrumented function.
> 
> i am getting this type of tree structure in LTTV:
> 
> in my Traceset :
> 
> Traceset statistics
> 
> |
> 
> -> mode types
> 
> |
> 
> ->MODE_UNKNOWN
> 
> ->IRQentry
> 
> ->SOFTIRQ
> 
> ->SYSCALL
> 
> |
> 
> ->submodes
> 
> |
> 
> ->NONE
> 
> ->ioctl
> 
> ->rt_sigaction
> 
> ->write
> 
> ->read(statistics for 'read' CPU timr: 0.000423449,elapsed time(
> 
> includes perprocess waiting time): 30.967086800, cumulative 
> 
> cpu time (includes nested routines and modes); 0.000423449
> 
> event count : 443
> 
> |
> 
> ->event_types
> 
> |
> 
> -> Statistics for 'event_types'
> 
> showing the number of events under read like 
> 
> syscall_entry: 122
> 
> read : 226
> 
> ....
> 
> ....
> 
> ....
> 
> myfs_read:1
> 
> ....
> 
> ....
> 
> 
> 
> 

Hi,

> 
> my question is why i am not getting the timing information of myfs_read?

What events do you have for myfs_read ? Is it a
myfs_read_start/myfs_read_end even pair ? If yes, we could count the
amount of time spend doing myfs_reads and then divide by the number of
myfs_read_start events encountered to know the average time... but
you'll have to extend lttv/lttv/stats.c. You could also just create your
own plugin and not touch stats.c, and do your computation within your
module. You may also just work on a text output, selecting only your
events, to compute such stats (that would be good for a quick proof of
concept...)

> 
> and what is the difference between read mentioned under event_types and read under 
> 
> submodes below SYSCALL??
> 

We have a syscall table enumeration which is used to known which system
call number is being executed. Therefore, we known the syscall number
(and therefore the syscall name, such as "read") of each system call
encountered. When we sum up statistics (lttv/lttv/stats.c), we use the
syscall ID as identifier in "current the system state tree paths".

Note that there is also a "read" event in the "fs" facility, but it is
not used for statistics.

Mathieu

> 
> REGARDS,
> 
> SATISH
> 

> _______________________________________________
> Ltt-dev mailing list
> [email protected]
> http://listserv.shafik.org/mailman/listinfo/ltt-dev


-- 
Mathieu Desnoyers
Computer Engineering Ph.D. Student, Ecole Polytechnique de Montreal
OpenPGP key fingerprint: 8CD5 52C3 8E3C 4140 715F  BA06 3F25 A8FE 3BAE 9A68