From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1751987AbdHDArS (ORCPT ); Thu, 3 Aug 2017 20:47:18 -0400 Received: from mail.linuxfoundation.org ([140.211.169.12]:33818 "EHLO mail.linuxfoundation.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751866AbdHDArQ (ORCPT ); Thu, 3 Aug 2017 20:47:16 -0400 Date: Thu, 3 Aug 2017 17:47:12 -0700 From: Greg Kroah-Hartman To: Todd Poynor Cc: LKML , android-kernel , Todd E Brandt , "Rafael J. Wysocki" Subject: Re: [PATCH] initcall_debug: add deferred probe times Message-ID: <20170804004712.GA26520@kroah.com> References: <20170725233159.89543-1-toddpoynor@google.com> <20170725234042.GA3256@kroah.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: User-Agent: Mutt/1.8.3 (2017-05-23) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Tue, Jul 25, 2017 at 08:01:49PM -0700, Todd Poynor wrote: > On Tue, Jul 25, 2017 at 4:40 PM, Greg Kroah-Hartman > wrote: > > On Tue, Jul 25, 2017 at 04:31:59PM -0700, Todd Poynor wrote: > >> initcall_debug attributes all deferred device probe retries for the > >> late_initcall level to function deferred_probe_initcall. Add logs of > >> the individual device probe routines called, to identify which drivers > >> are executing for how long during the initcall path. Deferred probes > >> that occur after initcall processing are not shown. > >> > >> Example log messages added: > >> > >> [ 0.505119] deferred probe my-sound-device @ 6 > >> [ 0.517656] deferred probe my-sound-device returned after 1227 usecs > > > > Can't you subtract the timestamp number right there? > > This patch extends the existing initcall_debug functionality; I've > copied the methods used by do_one_initcall_debug() to compute and > report timing info in a compatible format. If it's better to change > the way this is reported, I can also suggest changes to the existing > initcall_debug code. cc'ed the maintainers (I should have in the > first place). Ah, ok, I missed that, I was looking at the driver probe debug path, this makes a lot more sense then. > > And doesn't the tools/power/pm-graph/ scripts do this type of thing > > automatically for you to give you pretty graphs you can use to drill > > down on what is taking how long and such? > > analyze_boot.py parses the dmesg output printed by initcall_debug to > produce those graphs (and can also produce ftrace-based function > callgraphs). The initcall_debug output printed (and graphed) for > deferred probe calls are lumped into a single entry > "deferred_probe_initcall". This patch logs the times of the > individual deferred probe calls by device name, to better help > developers understand where the time is spent. If this feature finds > favor, it may also be deemed useful to update analyze_boot.py to graph > this information. I think updating it would be good, but for now this should be fine. Thanks for the information. greg k-h