Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753052AbYL3VDW (ORCPT ); Tue, 30 Dec 2008 16:03:22 -0500 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1752002AbYL3VDL (ORCPT ); Tue, 30 Dec 2008 16:03:11 -0500 Received: from mu-out-0910.google.com ([209.85.134.187]:1591 "EHLO mu-out-0910.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751530AbYL3VDK (ORCPT ); Tue, 30 Dec 2008 16:03:10 -0500 DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=date:from:to:cc:subject:message-id:references:mime-version :content-type:content-disposition:in-reply-to:user-agent; b=APAcLHtwGJ2HBudozBNffKDkGQHYAfDPL8JVK02GAXghUwFAGyoG4tHgB/T0Cyekn/ JZoAPXIsO9zDYhpQnw5V/cm6U6NaaJmIw2dkC1E6iT/ha/7p6zLK80SuMH/iPROJUmtR s2QhdZRl2LdLDfgkaNYeOokx1MyVbPb1/RLVA= Date: Tue, 30 Dec 2008 22:03:04 +0100 From: Frederic Weisbecker To: Vladislav Bolkhovitin Cc: Ingo Molnar , Steven Rostedt , Sam Ravnborg , linux-scsi@vger.kernel.org, James Bottomley , Andrew Morton , FUJITA Tomonori , Mike Christie , Jeff Garzik , Boaz Harrosh , Linus Torvalds , linux-kernel@vger.kernel.org, scst-devel@lists.sourceforge.net, Bart Van Assche , "Nicholas A. Bellinger" Subject: Re: [PATCH][RFC 2/23]: SCST core Message-ID: <20081230210303.GB6151@nowhere> References: <20081211210917.GB27010@uranus.ravnborg.org> <4942BA85.3070408@vlnb.net> <1229118607.24995.18.camel@localhost.localdomain> <4943CAAB.4050008@vlnb.net> <494A37E9.5000009@vlnb.net> <495137F4.9010404@vlnb.net> <20081227112055.GB18819@elte.hu> <495A56A8.1030208@vlnb.net> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <495A56A8.1030208@vlnb.net> User-Agent: Mutt/1.5.18 (2008-05-17) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 4196 Lines: 95 On Tue, Dec 30, 2008 at 08:13:12PM +0300, Vladislav Bolkhovitin wrote: > Ingo Molnar, on 12/27/2008 02:20 PM wrote: >> * Vladislav Bolkhovitin wrote: >> >>>> The word graph is actually here to explain here that we not only >>>> trace each function call but we can actually retrieve all of the >>>> call path of a function and then draw it as if it was C code: >>>> >>>> 0) ! 108.528 us | } >>>> 0) | irq_exit() { >>>> 0) | do_softirq() { >>>> 0) | __do_softirq() { >>>> 0) 0.895 us | __local_bh_disable(); >>>> 0) | run_timer_softirq() { >>>> 0) 0.827 us | hrtimer_run_pending(); >>>> 0) 1.226 us | _spin_lock_irq(); >>>> 0) | _spin_unlock_irq() { >>>> 0) 6.550 us | } >>>> 0) 0.924 us | _local_bh_enable(); >>>> 0) + 12.129 us | } >>>> 0) + 13.911 us | } >>>> 0) 0.707 us | idle_cpu(); >>>> 0) + 17.009 us | } >>>> 0) ! 137.419 us | } >>>> 0) <========== | >>>> 0) 1.045 us | } >>>> 0) ! 148.908 us | } >>>> 0) ! 151.022 us | } >>>> 0) ! 153.022 us | } >>>> 0) 0.963 us | journal_mark_dirty(); >>>> 0) 0.925 us | __brelse(); >>> Unfortunately, it lacks very useful "TASK-PID, CPU#, TIMESTAMP" >>> header fields.. >> >> those obscure readability in the typical usecases, but you can get them >> anytime via using this existing trace_options runtime switch: >> >> echo funcgraph-proc > /debug/tracing/trace_options >> >> resulting in traces like this: >> >> # CPU TASK/PID OVERHEAD/DURATION FUNCTION CALLS >> # | | | | | | | | >> ------------------------------------------ >> 0) distccd-28400 => cc1-30212 >> ------------------------------------------ >> >> 0) cc1-30212 | 0.270 us | } >> 0) cc1-30212 | | __do_fault() { >> 0) cc1-30212 | | filemap_fault() { >> 0) cc1-30212 | | find_lock_page() { >> 0) cc1-30212 | 0.453 us | find_get_page(); >> 0) cc1-30212 | 0.997 us | } >> 0) cc1-30212 | | PageUptodate() { >> 0) cc1-30212 | 0.266 us | constant_test_bit(); >> 0) cc1-30212 | 0.799 us | } >> 0) cc1-30212 | 0.379 us | mark_page_accessed(); >> 0) cc1-30212 | 3.275 us | } >> 0) cc1-30212 | 0.276 us | _spin_lock(); >> 0) cc1-30212 | 0.389 us | page_add_file_rmap(); >> 0) cc1-30212 | | unlock_page() { >> 0) cc1-30212 | 0.266 us | page_waitqueue(); >> 0) cc1-30212 | 0.381 us | __wake_up_bit(); >> 0) cc1-30212 | 1.442 us | } >> 0) cc1-30212 | 6.897 us | } >> 0) cc1-30212 |+ 11.663 us | } >> 0) cc1-30212 | | up_read() { >> 0) cc1-30212 | 0.280 us | _spin_lock_irqsave(); > > This view is OK for us, I can suggest only two things: > > 1. Add an option to disable "OVERHEAD/DURATION", it isn't needed in our > case of SCSI commands processing troubleshooting, hence would only hurt > readability and (I guess) add not needed overhead. You can disable the overhead but not yet the duration. But it's on my TODO list and should be available for 2.6.30 > 2. If possible, make the view more compact, i.e. with less spaces on > each line. Our tracing lines can be quite long. > > Thanks, > Vlad > I'm not sure... The spaces are mostly here to keep fixed width columns, in case we have huge durations, or long cmdlines... -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/