From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1751391AbdFEWK4 (ORCPT ); Mon, 5 Jun 2017 18:10:56 -0400 Received: from mail-pg0-f51.google.com ([74.125.83.51]:35266 "EHLO mail-pg0-f51.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751180AbdFEWKy (ORCPT ); Mon, 5 Jun 2017 18:10:54 -0400 Subject: Re: PM / Suspend: Print wall time at suspend entry and exit To: Pavel Machek , "Rafael J. Wysocki" References: <20170605193157.59875-1-salyzyn@android.com> <20170605211835.GB9035@amd> <5931f9cb-016f-4163-4908-6825cf84b9d3@android.com> Cc: Linux Kernel Mailing List , Linux PM , Todd Poynor , "Rafael J. Wysocki" , Len Brown From: Mark Salyzyn Message-ID: Date: Mon, 5 Jun 2017 15:10:52 -0700 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:45.0) Gecko/20100101 Thunderbird/45.8.0 MIME-Version: 1.0 In-Reply-To: <5931f9cb-016f-4163-4908-6825cf84b9d3@android.com> Content-Type: text/plain; charset=windows-1252; format=flowed Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On 06/05/2017 02:47 PM, Mark Salyzyn wrote: > On 06/05/2017 02:18 PM, Pavel Machek wrote: >> Hi! >> >>> On Mon, Jun 5, 2017 at 9:31 PM, Mark Salyzyn >>> wrote: >>>> Permits power state and battery life diagnosis. >>> Which is possible even without this patch and we have tools for that >>> (analyze_suspend.py, anyone?). >>> >>> Honestly, I don't see why this change is necessary or even useful. >> I ran dmesg after resume and now I... >> >> [1019729.486249] ACPI : EC: EC stopped >> [1019729.486255] PM: Saving platform NVS memory >> [1019729.486276] Disabling non-boot CPUs ... >> [1019729.490423] smpboot: CPU 1 is now offline >> [1019729.531015] smpboot: CPU 2 is now offline >> [1019729.577742] Broke affinity for irq 16 >> [1019729.577747] Broke affinity for irq 17 >> [1019729.577751] Broke affinity for irq 19 >> [1019729.577756] Broke affinity for irq 23 >> [1019729.578771] smpboot: CPU 3 is now offline >> [1019729.604987] ACPI: Low-level resume complete >> [1019729.605052] ACPI : EC: EC started >> [1019729.605054] PM: Restoring platform NVS memory >> [1019729.605352] Suspended for 3196.166 seconds >> [1019729.605376] Enabling non-boot CPUs ... >> [1019729.631246] x86: Booting SMP configuration: >> [1019729.631249] smpboot: Booting Node 0 Processor 1 APIC 0x1 >> [1019729.631496] Initializing CPU#1 >> [1019729.631514] Disabled fast string operations >> [1019729.636643] cache: parent cpu1 should not be sleeping >> [1019729.637286] CPU1 is up >> >> Aha. I missed the "suspended for 3196" message before. So I believe >> you are right; there's already enough information in the kernel logs. >> >> Pavel > > We do not get the Suspended for messages on failure to suspend > (interrupt wakeup), but that is a weak argument ;-/ since it is > discoverable from context and we can count the aborted suspends > switching the tools. The Suspended for messages are in ms which is not > accurate enough for Android user space logs (in ns) long term > continuous tracking of monotonic vs realtime and makes no accounting > for ntp adjustments. Currently, post mortem data only on Android, we > have no other way to align monotonic kernel logs with user space logs > without this. > > Sincerely -- Mark Salyzyn > Also, not all devices have a persistent time that can be collected at Suspend at that level, so they have to turn off CONFIG_SUSPEND_TIME because 'Suspended for' is meaningless on those platforms, but alas these prints turn into a backup mechanism for those platforms as they are printed befopre and after the hardware is up and running. -- Mark