From mboxrd@z Thu Jan 1 00:00:00 1970 From: =?utf-8?Q?Bj=C3=B8rn_Mork?= Subject: Re: [PATCH 1/2] cpufreq: try to resume policies which failed on last resume Date: Mon, 06 Jan 2014 11:49:00 +0100 Message-ID: <87a9f92xnn.fsf@nemi.mork.no> References: <5562479.pVWRuDL0y6@vostro.rjw.lan> <87zjne7f75.fsf@nemi.mork.no> <2302938.b8tymqrMEz@vostro.rjw.lan> <878uuxquxu.fsf@nemi.mork.no> <871u0po0gx.fsf@nemi.mork.no> <87wqihmg9a.fsf@nemi.mork.no> <87iotx32mx.fsf@nemi.mork.no> Mime-Version: 1.0 Content-Transfer-Encoding: QUOTED-PRINTABLE Return-path: In-Reply-To: (Viresh Kumar's message of "Mon, 6 Jan 2014 15:27:51 +0530") Sender: cpufreq-owner@vger.kernel.org List-ID: Content-Type: text/plain; charset="utf-8" To: Viresh Kumar Cc: "Rafael J. Wysocki" , "cpufreq@vger.kernel.org" , "linux-pm@vger.kernel.org" , Linux Kernel Mailing List Viresh Kumar writes: > On 6 January 2014 14:31, Bj=C3=B8rn Mork wrote: >> That's correct. I have not observed this on suspend to RAM. But th= en >> again I haven't rigged any way to log that, so I don't think it's >> conclusive.. >> >> The point I tried to make is that it isn't related to any hibernatio= n >> *failures*. The warning appears even if the add_dev() is successful= , >> and it also appears if I touch only the *boot* cpu cpufreq attribute= s. > > Okay.. But your log below is for add_dev() failure case. Any suggestion on how to capure warnings issued between freeze and thaw is appreciated :-) Will a netconsole work? I can try that later. >> I.e., this seems to be unrelated to the hotplugging code. >> >> Here's another copy of the warning, captured by cancelling hibernati= on >> as I don't have any other way to log it at the moment. But I do see= the >> warning appear on the console *before* cancelling. And I also see t= his >> warning appear when trying the in-kernel hibernation instead of >> userspace. > > How do you cancel hibernation here? Sorry, what is in-kernel hibernat= ion? I don't know the proper terms here. I normally use s2disk from uswsusp to hibernate. By "in-kernel hibernation" I meant the process initiated by doing echo disk >/sys/power/state >> [ 267.893084] =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D >> [ 267.893085] [ INFO: possible circular locking dependency detected= ] >> [ 267.893087] 3.13.0-rc6+ #183 Tainted: G W >> [ 267.893089] -----------------------------------------------------= -- >> [ 267.893090] s2disk/5450 is trying to acquire lock: >> [ 267.893101] (s_active#164){++++.+}, at: [] sys= fs_addrm_finish+0x28/0x46 >> [ 267.893102] >> [ 267.893102] but task is already holding lock: >> [ 267.893111] (cpu_hotplug.lock){+.+.+.}, at: []= cpu_hotplug_begin+0x28/0x50 >> [ 267.893112] >> [ 267.893112] which lock already depends on the new lock. >> [ 267.893112] >> [ 267.893113] >> [ 267.893113] the existing dependency chain (in reverse order) is: >> [ 267.893117] >> [ 267.893117] -> #1 (cpu_hotplug.lock){+.+.+.}: >> [ 267.893123] [] lock_acquire+0xfb/0x144 >> [ 267.893128] [] mutex_lock_nested+0x6c/0x= 397 >> [ 267.893132] [] get_online_cpus+0x3c/0x50 >> [ 267.893137] [] store+0x20/0xad >> [ 267.893142] [] sysfs_write_file+0x138/0x= 18b >> [ 267.893147] [] vfs_write+0x9c/0x102 >> [ 267.893151] [] SyS_write+0x50/0x85 >> [ 267.893155] [] system_call_fastpath+0x16= /0x1b >> [ 267.893160] >> [ 267.893160] -> #0 (s_active#164){++++.+}: >> [ 267.893164] [] __lock_acquire+0xae3/0xe6= 8 >> [ 267.893168] [] lock_acquire+0xfb/0x144 >> [ 267.893172] [] sysfs_deactivate+0xa5/0x1= 08 >> [ 267.893175] [] sysfs_addrm_finish+0x28/0= x46 >> [ 267.893178] [] sysfs_remove+0x2a/0x31 >> [ 267.893182] [] sysfs_remove_dir+0x66/0x6= b >> [ 267.893186] [] kobject_del+0x18/0x42 >> [ 267.893190] [] kobject_cleanup+0xe1/0x14= f >> [ 267.893193] [] kobject_put+0x45/0x49 >> [ 267.893197] [] cpufreq_policy_put_kobj+0= x37/0x83 > > All above is for case where add dev was required to clear up earlier > allocated policy as something failed during add_dev() I see. I'll try capturing at least part of the warning with a camera, when it's not failing. >> [ 267.893201] [] __cpufreq_add_dev.isra.18= +0x75e/0x78c >> [ 267.893204] [] cpufreq_cpu_callback+0x53= /0x88 >> [ 267.893208] [] notifier_call_chain+0x67/= 0x92 >> [ 267.893213] [] __raw_notifier_call_chain= +0x9/0xb >> [ 267.893217] [] __cpu_notify+0x1b/0x32 >> [ 267.893221] [] cpu_notify+0xe/0x10 >> [ 267.893225] [] _cpu_up+0xf1/0x124 >> [ 267.893230] [] enable_nonboot_cpus+0x52/= 0xbf >> [ 267.893234] [] hibernation_snapshot+0x1b= e/0x2ed > > And this is again the same log as what you have sent last time. It ha= ppened > while saving image after disabling all non-boot CPUs. And so it happe= ned for > your case as your driver->init() was failing, so it may not get repro= duced at > my end. Haven't tried it though. > >> I don't think I do anything extra-ordinary to trigger this, so I wou= ld >> be surprised if you can't reproduce it by doing >> >> export x=3D`cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_gover= nor` >> echo $x >/sys/devices/system/cpu/cpu0/cpufreq/scaling_governor >> s2disk > > I don't see you cancelling hibernation here. Sorry got confused on ho= w > exactly you reproduced it. I cancelled by pressing backspace while the image was being written. Bj=C3=B8rn