Re: [patch 34/37] LTTng instrumentation ipc

From: Alexey Dobriyan
Date: Thu Apr 24 2008 - 18:07:30 EST


On Thu, Apr 24, 2008 at 11:03:58AM -0400, Mathieu Desnoyers wrote:
> Interprocess communication, core events.
>
> Added markers :
>
> ipc_msg_create
> ipc_sem_create
> ipc_shm_create

> --- linux-2.6-lttng.orig/ipc/shm.c
> +++ linux-2.6-lttng/ipc/shm.c
> @@ -39,6 +39,7 @@
> #include <linux/nsproxy.h>
> #include <linux/mount.h>
> #include <linux/ipc_namespace.h>
> +#include <linux/marker.h>
>
> #include <asm/uaccess.h>
>
> @@ -482,6 +483,7 @@ asmlinkage long sys_shmget (key_t key, s
> struct ipc_namespace *ns;
> struct ipc_ops shm_ops;
> struct ipc_params shm_params;
> + long err;
>
> ns = current->nsproxy->ipc_ns;
>
> @@ -493,7 +495,9 @@ asmlinkage long sys_shmget (key_t key, s
> shm_params.flg = shmflg;
> shm_params.u.size = size;
>
> - return ipcget(ns, &shm_ids(ns), &shm_ops, &shm_params);
> + err = ipcget(ns, &shm_ids(ns), &shm_ops, &shm_params);
> + trace_mark(ipc_shm_create, "id %ld flags %d", err, shmflg);
> + return err;
> }

OK, finally the meat of markers facility was posted and we can actually
see the end result. And the end result is unwieldy and limited.

Today I was debugging some SysV shmem stuff and only 0.5 of marker
above would be useful. I ended up with the following:

rv = ipcget(...);
if (rv < 0)
printk("%s: rv = %d\n", __func__, rv);
return rv;

because I knew app was doing a lot of shmget/IPC_RMID and only -E events
were interesting. The rest was inserted deeply in mm/shmem.c internals
which these patches avoid for some reason :^)

Can I write

if (rv < 0)
trace_mark(foo, "rv %d", rv);

?

Looks like i could. But people want also want to see success, so what?
Two markers per exit?

rv = ipc_get(...);
if (rv < 0)
trace_marker(foo_err, ...);
trace_marker(foo_all, ...);


Also everything inserted so far is static. Sometimes only one bit in
mask is interesting and to save time to parse nibbles people do:

printk("foo = %d\n", !!(mask & foo));

And interesting bits vary.

Again, all events aren't interesting:

if (file && file->f_op == &shm_file_operations)
printk("%s: file = %p: START\n", __func__, file);

Can I write this with markers?

And finally, if we are talking by debugging by printks (which to me, markers
essentially are), they come in generations: you insert some initial
stuff, get information, narrow search area, insert some more in places
that are dependent from what you've seen in step 1, and whoila, bug is
understood.

So what is proposed? Insert markers at places that look strategic? Feed
me with data I DO NOT care and DO NOT want to see?

mm/ patch is full if "file %p". Do you realize that pointers are
only sometimes interesting and sometimes you want dentry (not pointer,
but name!):

printk("file = '%s'\n", file->f_dentry->d_name.name);

You seem to place _one_ marker at the very end of error path, but,
c'mon, information _which_ "goto" exactly came to the error path is
also interesting!

Should I preventively insert marker when writing new code?



So, let me say even more explicitly. Looking at proposed places elite
enough to be blessed with marker...

Those which are close enough to system call boundary are essentially
strace(1).

Markers are very visible and distract attention from real code.
Markers steal critical vertical space (80 x only _25_ ).

Markers fmt strings are unconditional and can't take prior information
about the problem into account.

Markers points won't be removed, only accumulated -- somebody _might_ be
interested in this information.

Developers want to see wildly different information. Marker is one for
everyone.

Said that, markers are lame and should be fully removed until too late.


P.S.: I probably miss some obvious things and look only from specific
debugging perspective. Let someone speak up from another angle. It's very
good moment now because ipc/ kernel/ mm/ net/ patches show CRYSTALLY CLEAR
the end result. (and futex patch earlier).

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/