Re: Human readable output for function return tracer

[Arnaldo Carvalho de Melo <acme@redhat.com>]

Em Mon, Nov 24, 2008 at 08:10:47PM +0100, Frédéric Weisbecker escreveu:
> 2008/11/24 Arnaldo Carvalho de Melo <acme@redhat.com>:
> > I do something like that in my ctracer tool[1], take a look at one of
> > the callgraphs:
> >
> > http://oops.ghostprotocols.net:81/ostra/dccp/tx/
> 
> 
> Oh yes, that's what I would see as an end result. Except that it would be more
> easy for me to have the time of execution on the left (I don't need the time
> they are called since it's just a cost measure).
> 
> 
> > I.e. the leaf functions doesn't use {}
> 
> I guess I could avoid it too..
> 
> 
> > On ctracer I didn't had this problem as I don't trace all functions,
> > just the ones that receive as one of its parameters a pointer to the
> > desired struct, and this pointer is present in all the trace buffer
> > entries,
> 
> How do you do this tracing by only passing a structure?

[acme@doppio linux-2.6-x86]$ pfunct --verbose --class=inode fs/ext4/ext4.ko | head
ext4_fsblk_t ext4_new_blocks(handle_t * handle, struct inode * inode, ext4_lblk_t iblock, ext4_fsblk_t goal, long unsigned int * count, int * errp);
ext4_fsblk_t ext4_new_meta_blocks(handle_t * handle, struct inode * inode, ext4_fsblk_t goal, long unsigned int * count, int * errp);
ext4_fsblk_t ext4_new_meta_block(handle_t * handle, struct inode * inode, ext4_fsblk_t goal, int * errp);
void ext4_free_blocks(handle_t * handle, struct inode * inode, ext4_fsblk_t block, long unsigned int count, int metadata);
int ext4_check_dir_entry(const char  * function, struct inode * dir, struct ext4_dir_entry_2 * de, struct buffer_head * bh, long unsigned int offset);
int ext4_release_dir(struct inode * inode, struct file * filp);
int ext4_release_file(struct inode * inode, struct file * filp);
void vfs_dq_init(struct inode * inode);
struct inode * ext4_new_inode(handle_t * handle, struct inode * dir, int mode);
void ext4_free_inode(handle_t * handle, struct inode * inode);
[acme@doppio linux-2.6-x86]$ 

My first attempt at this kind of tracing used a sparse (the kernel
checker tool uses it too), preprocessing and inserting the calls if,
looking that the tokens, I found I was at the start of a function source
code, and, for return tracing I just looke for return calls, inserting
at each return point, in the source code, the call, that way I could
even know which one of the returns were taken, and how many times.

Looking at Steven's redefinition of "if", I think we could do the same
for returns 8)

Then I used the DWARF debug info to find out which functions in the
objects of interest have as one of its args a pointer to the struct of
interest, i.e. I find its methods, then write a kernel module
registering jprobes and kretprobes for the functions I was interested
in.

Then I moved this to generate a systemtap script.

Then came the mcount approach, but it lacked return hooks.

Thanks to you I guess now I should rewrite this thing again :-)

> > so as part of postprocessing it separates the callgraphs per
> > object.
> 
> I would like to separate the callgraph per thread. I'm not sure how. Perhaps
> by only drawing a simple
> 
> ------8<----- switch to task nr x -----------8<-------------------

Well, you can record, for each entry, the thread id, but then you will
not know to what file, say, a close operation relates to.

- Arnaldo