linux-kernel - Re: [RFC PATCH] ftrace function-graph: print the function name on all } lines

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

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <20140502153249.1ee6aadd@gandalf.local.home>
Date:	Fri, 2 May 2014 15:32:49 -0400
From:	Steven Rostedt <rostedt@...dmis.org>
To:	"Elliott, Robert (Server Storage)" <Elliott@...com>
Cc:	"fweisbec@...il.com" <fweisbec@...il.com>,
	"mingo@...hat.com" <mingo@...hat.com>,
	"linux-kernel (linux-kernel@...r.kernel.org)" 
	<linux-kernel@...r.kernel.org>
Subject: Re: [RFC PATCH] ftrace function-graph: print the function name on
 all } lines

On Fri, 2 May 2014 19:11:11 +0000
"Elliott, Robert (Server Storage)" <Elliott@...com> wrote:

> Using ftrace function-graph to examine the times consumed by
> functions, the time shows up on the line where the call is made
> if no other traceable functions were called by that function:
>  11)   0.672 us    |    cmd_alloc [hpsa]();
> 
> but the time shows up down by the } if the were other traceable
> functions called by that function:
>  11)               |              cmd_alloc [hpsa]() {
>  11)   0.129 us    |                cmd_free [hpsa]();
>  11)   0.106 us    |                cmd_free [hpsa]();
>  11)   2.014 us    |              }
> 
> On its own, the } line doesn't indicate which function it is
> closing, so grep cannot be used to search for all the times
> for this function. You have to write a parser.
> 
> The function name does get printed on those lines when the
> start of the function is off the trace, so I modified 
> trace_functions_graph.c to do that in all cases.
> 
>  11)               |    hpsa_scsi_ioaccel_raid_map [hpsa]() {
>  11)               |      hpsa_scsi_ioaccel_queue_command [hpsa]() {
>  11)               |        hpsa_scsi_ioaccel2_queue_command [hpsa]() {
>  11)   0.067 us    |          fixup_ioaccel_cdb [hpsa]();
>  11)   0.053 us    |          set_encrypt_ioaccel2 [hpsa]();
>  11)   0.199 us    |          enqueue_cmd_and_start_io [hpsa]();
>  11)   1.952 us    |        } /* hpsa_scsi_ioaccel2_queue_command [hpsa] */
>  11)   2.501 us    |      } /* hpsa_scsi_ioaccel_queue_command [hpsa] */
>  11)   3.093 us    |    } /* hpsa_scsi_ioaccel_raid_map [hpsa] */
>  11)   4.667 us    |  } /* hpsa_scsi_queue_command [hpsa] */
> 
> rather than:
>  11)               |    hpsa_scsi_ioaccel_raid_map [hpsa]() {
>  11)               |      hpsa_scsi_ioaccel_queue_command [hpsa]() {
>  11)               |        hpsa_scsi_ioaccel2_queue_command [hpsa]() {
>  11)   0.067 us    |          fixup_ioaccel_cdb [hpsa]();
>  11)   0.053 us    |          set_encrypt_ioaccel2 [hpsa]();
>  11)   0.199 us    |          enqueue_cmd_and_start_io [hpsa]();
>  11)   1.952 us    |        }
>  11)   2.501 us    |      }
>  11)   3.093 us    |    }
>  11)   4.667 us    |  }
> 
> Is this a change you would be interested in taking, or
> do you think that makes the output too cluttered?

Yes it is too cluttered. Please make this a tracing option that is
default off.

Thanks,

-- Steve

> 
> A potential patch (based on kernel-3.14) is:
> 
--
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/