| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <20081127135155.GA23076@elte.hu>
Date: Thu, 27 Nov 2008 14:51:55 +0100
From: Ingo Molnar <mingo@...e.hu>
To: Frédéric Weisbecker <fweisbec@...il.com>
Cc: Steven Rostedt <rostedt@...dmis.org>,
Tim Bird <tim.bird@...sony.com>,
Linux Kernel <linux-kernel@...r.kernel.org>,
Peter Zijlstra <a.p.zijlstra@...llo.nl>
Subject: Re: [PATCH] tracing/function-branch-tracer: enhancements for the
trace output
* Frédéric Weisbecker <fweisbec@...il.com> wrote:
> 2008/11/27 Ingo Molnar <mingo@...e.hu>:
> > But in fact, it might be even better to display the costs like this,
> > on the left side [mockup]:
> >
> > ---------------------------------------------------------
> > CPU) cost | function
> > ---------------------------------------------------------
> >
> > 0) | sys_read() {
> > 0) 0.331 us | fget_light();
> > 0) | vfs_read() {
> > 0) | rw_verify_area() {
> > 0) | security_file_permission() {
> > 0) 0.306 us | cap_file_permission();
> > 0) 0.300 us | cap_file_permission();
> > 0) 8.909 us | }
> > 0) 0.993 us | }
> > 0) 11.649 us | }
> > 0) | do_sync_read() {
> > 0) | sock_aio_read() {
> > 0) | __sock_recvmsg() {
> > 0) | security_socket_recvmsg() {
> > 0) 100.319 us | cap_socket_recvmsg();
> > ---------------------------------------------------------
> >
> > note the 8 small tweaks i did to optimize the visual real estate of
> > the tracer output:
> >
> > 1) we done need reminders on the left side that this is about CPU
> > numbers. It will be obvious anyway if it's "all mixed up".
> > (microseconds is different - that is a unit that will be quoted and
> > it's also a number that actually matters more in the daily use of
> > such traces )
> >
> > 2) no need for [] on the left side - a single separator is enough. I
> > picked ')' as it looks pretty natural and unintrusive.
> >
> > 3) we should use the CPU number width on the left side that
> > log10(cpus_weight_nr(cpu_online_map)) tells us. So if a system has
> > just two cores, we should print single-width. If it has 16 CPUs, we
> > should print 00..01....15.
> >
> > 4) I left 4 decimal points for the cost. That's up to 9999.999
> > microseconds, after that point we should lose precision and print:
> > 99999.99, then should print up to 999999.9, and then print up to
> > 99999999 microseconds. Always keep the length of the number at 8
> > characters. Above that, just let the rest shift to the right a bit.
> > (but that will be about delays of more than 100 seconds - that does
> > not really matter in practice)
> >
> > 5) Note, by printing the cost at fixed width, we can leave out the '+'
> > and '!' visual alerts (sorry! :-). The visible width of the numbers
> > will be enough of an attention grabber - as you can see it in the
> > mockup above already.
> >
> > 6) Note the vertical '|' separator. I tried it with and without, and i
> > think the code on the right side looks more structured that way. It
> > looks like a sheet of paper, and it looks tidier - so please add
> > it.
> >
> > 7) Note how unobscured the right side code portion looks like this
> > way. Since this is the only piece of information that is heavily
> > variable-width, we keep it at the end and dont worry about length
> > problems.
>
>
> Yeah, I will miss a bit the overhead signs, they were really useful
> to find in one quick sight a costly function call. I know that the
> decimal. The visible width of the duration replaces it but not as
> much efficiently. Moreover, put these times on the full left will be
> perhaps harder for the eyes to retrieve the concerned function
> return (thinking of a deep calls).
We can still add the overhead signs.
We still have a single space in the first column before the CPU number
(that looks better when these traces are pasted into email, which is
one of the most common uses of them), and we can add the sign there.
I.e. something like this:
> > ---------------------------------------------------------
> > CPU) cost | function
> > ---------------------------------------------------------
> >
> > 0) | sys_read() {
> > 0) 0.331 us | fget_light();
> > 0) | vfs_read() {
> > 0) | rw_verify_area() {
> > 0) | security_file_permission() {
> > 0) 0.306 us | cap_file_permission();
> > 0) 0.300 us | cap_file_permission();
> > 0) 8.909 us | }
> > 0) 0.993 us | }
> > +0) 11.649 us | }
> > 0) | do_sync_read() {
> > 0) | sock_aio_read() {
> > 0) | __sock_recvmsg() {
> > 0) | security_socket_recvmsg() {
> > !0) 100.319 us | cap_socket_recvmsg();
> > ---------------------------------------------------------
Or we could add them to the function name bit - there we have two free
space characters anyway:
Something like this:
> > ---------------------------------------------------------
> > CPU) cost | function
> > ---------------------------------------------------------
> >
> > 0) | sys_read() {
> > 0) 0.331 us | fget_light();
> > 0) | vfs_read() {
> > 0) | rw_verify_area() {
> > 0) | security_file_permission() {
> > 0) 0.306 us | cap_file_permission();
> > 0) 0.300 us | cap_file_permission();
> > 0) 8.909 us | }
> > 0) 0.993 us | }
> > 0) 11.649 us |+ }
> > 0) | do_sync_read() {
> > 0) | sock_aio_read() {
> > 0) | __sock_recvmsg() {
> > 0) | security_socket_recvmsg() {
> > 0) 100.319 us |! cap_socket_recvmsg();
> > ---------------------------------------------------------
Hm?
> I don't know, perhaps that will actually be better in practice...
i think it will be better. I'm biased, so i gave the output to two
people with good visual taste (one of them female), [note, i gave them
the mockup from the previous mail] and the first question of both of
them was: "why arent the times on the left?".
I think we could make the time column a trace_option as well -
default-enabled.
Ingo
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists