RE: audio lost from speaker after reboot from windows on the device ALC295
Hi, Kailiang: Thanks for your tools, here are the two enclosed alsa-info with and without sound. -Original Message- From: Kailang Sent: Friday, July 5, 2019 10:42 AM To: He, Bo ; alsa-de...@alsa-project.org; linux-kernel@vger.kernel.org Cc: pe...@perex.cz; ti...@suse.com; jian-h...@endlessm.com; dr...@endlessm.com; c...@endlessm.com; hui.w...@canonical.com Subject: RE: audio lost from speaker after reboot from windows on the device ALC295 Sorry!! Forgot attach file. > -Original Message- > From: Kailang > Sent: Friday, July 5, 2019 10:41 AM > To: 'He, Bo' ; alsa-de...@alsa-project.org; > linux-kernel@vger.kernel.org > Cc: pe...@perex.cz; ti...@suse.com; jian-h...@endlessm.com; > dr...@endlessm.com; c...@endlessm.com; hui.w...@canonical.com > Subject: RE: audio lost from speaker after reboot from windows on the > device > ALC295 > > Hi Bo He, > > Could you help to dump info for us? > Please use attach file to get results. > > ./alsa-info.sh --no-upload > > You will find dump file in folder /tmp/alsa-info.txt-. > > Please run one time in normal state and one time in fail state. > Please send two result files to me. > > BR, > Kailang > > > -Original Message- > > From: He, Bo > > Sent: Thursday, July 4, 2019 8:02 PM > > To: Kailang ; alsa-de...@alsa-project.org; > > linux-kernel@vger.kernel.org > > Cc: pe...@perex.cz; ti...@suse.com; jian-h...@endlessm.com; > > dr...@endlessm.com; c...@endlessm.com; hui.w...@canonical.com > > Subject: audio lost from speaker after reboot from windows on the > > device > > ALC295 > > > > Hi, patch_realtek.c maintainer: > > I see one issue that reboot from windows and boot to ubuntu, the > > audio lost from speaker, I suspect there are some bugs in > > patch_realtek.c drivers, the device is ALC295 and the device id is > 0x10ec0295. > > > > I have done the below experiments: > > 1. reboot from windows to windows, the audio is persist . > > 2. reboot from windows to ubuntu, the audio lost from speaker, but > > can hear if I hotplug one earphone. > > 3. if the issue reproduce after reboot from windows, reboot the > > ubuntu can't restore the audio, I suspect it's warm reset. > > 4. if I write the port 0xcf9 with 0xe to do cold reset, the audio can > > restore. > > 5. if I do suspend/resume, the audio can restore, I suspect do cold > > boot and suspend will trigger the platform reset to reset the ALC295. > > 6. if I do double function reset (write the verb 0x7ff in alc_init), > > the audio is still can't restore. > > snd_hda_codec_write(codec, 0x01, 0, AC_VERB_SET_CODEC_RESET, 0); /* > > Function reset */ snd_hda_codec_write(codec, 0x01, 0, > > AC_VERB_SET_CODEC_RESET, 0); /* double Function reset */ 7. the > > issue is first found on kernel 4.19.50, I still see the issue with > > the latest kernel 5.2-rc2, is it possible windows change some > > default registers, but ALC295 don't initialize the register? > > > > --Please consider the environment before printing this e-mail. upload=true=true= !! !!ALSA Information Script v 0.4.63 !! !!Script ran on: Fri Jul 5 11:36:08 UTC 2019 !!Linux Distribution !!-- Ubuntu 19.04 \n \l DISTRIB_ID=Ubuntu DISTRIB_DESCRIPTION="Ubuntu 19.04" NAME="Ubuntu" ID=ubuntu ID_LIKE=debian PRETTY_NAME="Ubuntu 19.04" HOME_URL="https://www.ubuntu.com/; SUPPORT_URL="https://help.ubuntu.com/; BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/; PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy; UBUNTU_CODENAME=disco !!DMI Information !!--- Manufacturer: HP Product Name: HP Pavilion x360 Convertible 14-dh0xxx Product Version: Type1ProductConfigId Firmware Version: F.02 !!Kernel Information !!-- Kernel release:5.0.0-13-generic Operating System: GNU/Linux Architecture: x86_64 Processor: x86_64 SMP Enabled: Yes !!ALSA Version !! Driver version: k5.0.0-13-generic Library version:1.1.8 Utilities version: 1.1.8 !!Loaded ALSA modules !!--- snd_hda_intel !!Sound Servers on this system !! Pulseaudio: Installed - Yes (/usr/bin/pulseaudio) Running - Yes !!Soundcards recognised by ALSA !!- 0 [PCH]: HDA-Intel - HDA Intel PCH HDA Intel PCH at 0xa1318000 irq 157 !!PCI Soundcards installed in the system !!-- 00:1f.3 Audio device: Intel Corporation Device 9dc8 (rev 30) !!Advanced
audio lost from speaker after reboot from windows on the device ALC295
Hi, patch_realtek.c maintainer: I see one issue that reboot from windows and boot to ubuntu, the audio lost from speaker, I suspect there are some bugs in patch_realtek.c drivers, the device is ALC295 and the device id is 0x10ec0295. I have done the below experiments: 1. reboot from windows to windows, the audio is persist . 2. reboot from windows to ubuntu, the audio lost from speaker, but can hear if I hotplug one earphone. 3. if the issue reproduce after reboot from windows, reboot the ubuntu can't restore the audio, I suspect it's warm reset. 4. if I write the port 0xcf9 with 0xe to do cold reset, the audio can restore. 5. if I do suspend/resume, the audio can restore, I suspect do cold boot and suspend will trigger the platform reset to reset the ALC295. 6. if I do double function reset (write the verb 0x7ff in alc_init), the audio is still can't restore. snd_hda_codec_write(codec, 0x01, 0, AC_VERB_SET_CODEC_RESET, 0); /* Function reset */ snd_hda_codec_write(codec, 0x01, 0, AC_VERB_SET_CODEC_RESET, 0); /* double Function reset */ 7. the issue is first found on kernel 4.19.50, I still see the issue with the latest kernel 5.2-rc2, is it possible windows change some default registers, but ALC295 don't initialize the register?
RE: [PATCH 3.18 132/134] rcu: Do RCU GP kthread self-wakeup from softirq and interrupt
Hi, Paul: I have tried on my PC and not hit any hang issue with RCU torture test for one hour, the configurations are like: OS: ubuntu 16.04 kenrel: 3.18.136 + 3.18 rcu patch CPU: Intel(R) Xeon(R) CPU E3-1225 V2 @ 3.20GHz -Original Message- From: Paul E. McKenney Sent: Tuesday, March 26, 2019 12:00 AM To: Greg Kroah-Hartman Cc: He, Bo ; linux-kernel@vger.kernel.org; sta...@vger.kernel.org; Zhang, Jun ; Xiao, Jin ; Bai, Jie A Subject: Re: [PATCH 3.18 132/134] rcu: Do RCU GP kthread self-wakeup from softirq and interrupt On Sat, Mar 23, 2019 at 07:33:15AM +0100, Greg Kroah-Hartman wrote: > On Fri, Mar 22, 2019 at 04:00:17PM +0000, He, Bo wrote: > > Hi, Greg: > > Can you hold on the 3.18-stable branch, it seems there are some issue, > > please see the comments from Paul: > > > > Comments from Paul: > > I subjected all of the others to light rcutorture testing, which > > they passed. This v3.18 patch hung, however. Trying it again with > > stock > > v3.18 got the same hang, so I believe we can exonerate the patch and give > > it a good firm "maybe" on 3.18. > > > > Worth paying special attention to further test results from 3.18.x, though! > > Ok, I've dropped this from the 3.18.y queue now, thanks. Bo, if you know of a "y" for 3.18.y that would likely pass rcutorture testing, please let me know. Thanx, Paul
RE: [PATCH 3.18 132/134] rcu: Do RCU GP kthread self-wakeup from softirq and interrupt
Hi, Greg:
Can you hold on the 3.18-stable branch, it seems there are some issue,
please see the comments from Paul:
Comments from Paul:
I subjected all of the others to light rcutorture testing, which they passed.
This v3.18 patch hung, however. Trying it again with stock
v3.18 got the same hang, so I believe we can exonerate the patch and give it a
good firm "maybe" on 3.18.
Worth paying special attention to further test results from 3.18.x, though!
-Original Message-
From: Greg Kroah-Hartman
Sent: Friday, March 22, 2019 7:16 PM
To: linux-kernel@vger.kernel.org
Cc: Greg Kroah-Hartman ; sta...@vger.kernel.org;
He, Bo ; Zhang, Jun ; Paul E. McKenney
; Xiao, Jin ; Bai, Jie A
Subject: [PATCH 3.18 132/134] rcu: Do RCU GP kthread self-wakeup from softirq
and interrupt
3.18-stable review patch. If anyone has any objections, please let me know.
--
From: Zhang, Jun
commit 1d1f898df6586c5ea9aeaf349f13089c6fa37903 upstream.
The rcu_gp_kthread_wake() function is invoked when it might be necessary to
wake the RCU grace-period kthread. Because self-wakeups are normally a useless
waste of CPU cycles, if rcu_gp_kthread_wake() is invoked from this kthread, it
naturally refuses to do the wakeup.
Unfortunately, natural though it might be, this heuristic fails when
rcu_gp_kthread_wake() is invoked from an interrupt or softirq handler that
interrupted the grace-period kthread just after the final check of the
wait-event condition but just before the schedule() call. In this case, a
wakeup is required, even though the call to rcu_gp_kthread_wake() is within the
RCU grace-period kthread's context. Failing to provide this wakeup can result
in grace periods failing to start, which in turn results in out-of-memory
conditions.
This race window is quite narrow, but it actually did happen during real
testing. It would of course need to be fixed even if it was strictly
theoretical in nature.
This patch does not Cc stable because it does not apply cleanly to earlier
kernel versions.
Fixes: 48a7639ce80c ("rcu: Make callers awaken grace-period kthread")
Reported-by: "He, Bo"
Co-developed-by: "Zhang, Jun"
Co-developed-by: "He, Bo"
Co-developed-by: "xiao, jin"
Co-developed-by: Bai, Jie A
Signed-off: "Zhang, Jun"
Signed-off: "He, Bo"
Signed-off: "xiao, jin"
Signed-off: Bai, Jie A
Signed-off-by: "Zhang, Jun" [ paulmck: Switch from
!in_softirq() to "!in_interrupt() &&
!in_serving_softirq() to avoid redundant wakeups and to also handle the
interrupt-handler scenario as well as the softirq-handler scenario that
actually occurred in testing. ]
Signed-off-by: Paul E. McKenney
Link:
https://lkml.kernel.org/r/cd6925e8781efd4d8e11882d20fc406d52a11...@shsmsx104.ccr.corp.intel.com
Signed-off-by: Greg Kroah-Hartman
---
kernel/rcu/tree.c | 20 ++--
1 file changed, 14 insertions(+), 6 deletions(-)
--- a/kernel/rcu/tree.c
+++ b/kernel/rcu/tree.c
@@ -1399,15 +1399,23 @@ static int rcu_future_gp_cleanup(struct }
/*
- * Awaken the grace-period kthread for the specified flavor of RCU.
- * Don't do a self-awaken, and don't bother awakening when there is
- * nothing for the grace-period kthread to do (as in several CPUs
- * raced to awaken, and we lost), and finally don't try to awaken
- * a kthread that has not yet been created.
+ * Awaken the grace-period kthread. Don't do a self-awaken (unless in
+ * an interrupt or softirq handler), and don't bother awakening when
+ there
+ * is nothing for the grace-period kthread to do (as in several CPUs
+ raced
+ * to awaken, and we lost), and finally don't try to awaken a kthread
+ that
+ * has not yet been created. If all those checks are passed, track
+ some
+ * debug information and awaken.
+ *
+ * So why do the self-wakeup when in an interrupt or softirq handler
+ * in the grace-period kthread's context? Because the kthread might
+ have
+ * been interrupted just as it was going to sleep, and just after the
+ final
+ * pre-sleep check of the awaken condition. In this case, a wakeup
+ really
+ * is required, and is therefore supplied.
*/
static void rcu_gp_kthread_wake(struct rcu_state *rsp) {
- if (current == rsp->gp_kthread ||
+ if ((current == rsp->gp_kthread &&
+!in_interrupt() && !in_serving_softirq()) ||
!ACCESS_ONCE(rsp->gp_flags) ||
!rsp->gp_kthread)
return;
RE: must hold the driver_input_lock in hid_debug_rdesc_show
thanks, without the patch we can reproduce with the way in 10 hours Suspend/Resume test, with the test, we can't reproduce for 30 hours. -Original Message- From: Jiri Kosina Sent: Tuesday, March 19, 2019 10:42 PM To: He, Bo Cc: benjamin.tissoi...@redhat.com; linux-in...@vger.kernel.org; linux-kernel@vger.kernel.org; Zhang, Jun ; Zhang, Yanmin Subject: Re: must hold the driver_input_lock in hid_debug_rdesc_show On Thu, 14 Mar 2019, He, Bo wrote: > we see the below kernel panic logs when run suspend resume test with > usb mouse and usb keyboard connected. > > the scenario is the userspace call the hid_debug_rdesc_show to dump > the input device while the device is removed. the patch hold the > driver_input_lock to avoid the race. > > [ 5381.757295] selinux: SELinux: Could not stat > /sys/devices/pci:00/:00:15.0/usb1/1-2/1-2:1.0/0003:03F0:0325.0320/input/input960/input960::scrolllock: > No such file or directory. > [ 5382.636498] BUG: unable to handle kernel paging request at 000783316040 > [ 5382.651950] CPU: 1 PID: 1512 Comm: getevent Tainted: G U O > 4.19.20-quilt-2e5dc0ac-00029-gc455a447dd55 #1 > [ 5382.663797] RIP: 0010:hid_dump_device+0x9b/0x160 [ 5382.758853] > Call Trace: > [ 5382.761581] hid_debug_rdesc_show+0x72/0x1d0 [ 5382.766343] > seq_read+0xe0/0x410 [ 5382.769941] full_proxy_read+0x5f/0x90 [ > 5382.774121] __vfs_read+0x3a/0x170 [ 5382.788392] > vfs_read+0xa0/0x150 [ 5382.791984] ksys_read+0x58/0xc0 [ 5382.801404] > __x64_sys_read+0x1a/0x20 [ 5382.805483] do_syscall_64+0x55/0x110 [ > 5382.809559] entry_SYSCALL_64_after_hwframe+0x49/0xbe > > Signed-off-by: he, bo > Signed-off-by: "Zhang, Jun" I rewrote the changelog to explain the situation a bit more clearly, and applied. Thanks, -- Jiri Kosina SUSE Labs
must hold the driver_input_lock in hid_debug_rdesc_show
we see the below kernel panic logs when run suspend resume test with usb mouse and usb keyboard connected. the scenario is the userspace call the hid_debug_rdesc_show to dump the input device while the device is removed. the patch hold the driver_input_lock to avoid the race. [ 5381.757295] selinux: SELinux: Could not stat /sys/devices/pci:00/:00:15.0/usb1/1-2/1-2:1.0/0003:03F0:0325.0320/input/input960/input960::scrolllock: No such file or directory. [ 5382.636498] BUG: unable to handle kernel paging request at 000783316040 [ 5382.651950] CPU: 1 PID: 1512 Comm: getevent Tainted: G U O 4.19.20-quilt-2e5dc0ac-00029-gc455a447dd55 #1 [ 5382.663797] RIP: 0010:hid_dump_device+0x9b/0x160 [ 5382.758853] Call Trace: [ 5382.761581] hid_debug_rdesc_show+0x72/0x1d0 [ 5382.766343] seq_read+0xe0/0x410 [ 5382.769941] full_proxy_read+0x5f/0x90 [ 5382.774121] __vfs_read+0x3a/0x170 [ 5382.788392] vfs_read+0xa0/0x150 [ 5382.791984] ksys_read+0x58/0xc0 [ 5382.801404] __x64_sys_read+0x1a/0x20 [ 5382.805483] do_syscall_64+0x55/0x110 [ 5382.809559] entry_SYSCALL_64_after_hwframe+0x49/0xbe Signed-off-by: he, bo Signed-off-by: "Zhang, Jun" --- drivers/hid/hid-debug.c | 5 + 1 file changed, 5 insertions(+) diff --git a/drivers/hid/hid-debug.c b/drivers/hid/hid-debug.c index ebc9ffde41e9..a353a011fbdf 100644 --- a/drivers/hid/hid-debug.c +++ b/drivers/hid/hid-debug.c @@ -1060,10 +1060,15 @@ static int hid_debug_rdesc_show(struct seq_file *f, void *p) seq_printf(f, "\n\n"); /* dump parsed data and input mappings */ + if (down_interruptible(>driver_input_lock)) + return 0; + hid_dump_device(hdev, f); seq_printf(f, "\n"); hid_dump_input_mapping(hdev, f); + up(>driver_input_lock); + return 0; } -- 2.20.1
RE: [PATCH 4.20 12/88] usb: dwc3: gadget: synchronize_irq dwc irq in suspend
Hi, Greg:
Marek Szyprowski report the patch has issue that calling
synchronize_irq() under dwc->lock spinlock, he has upload the below patch for
the issue:
dwc3_gadget_suspend() is called under dwc->lock spinlock. In such context
calling synchronize_irq() is not allowed. Move the problematic call out of the
protected block to fix the following kernel BUG during system
suspend:
BUG: sleeping function called from invalid context at kernel/irq/manage.c:112
in_atomic(): 1, irqs_disabled(): 128, pid: 1601, name: rtcwake
6 locks held by rtcwake/1601:
#0: f70ac2a2 (sb_writers#7){.+.+}, at: vfs_write+0x130/0x16c
#1: b5fe1270 (>mutex){+.+.}, at: kernfs_fop_write+0xc0/0x1e4
#2: 7e597705 (kn->count#60){.+.+}, at: kernfs_fop_write+0xc8/0x1e4
#3: 8b3527d0 (system_transition_mutex){+.+.}, at: pm_suspend+0xc4/0xc04
#4: fc7f1c42 (>mutex){}, at: __device_suspend+0xd8/0x74c
#5: 4b36507e (&(>lock)->rlock){}, at: dwc3_gadget_suspend+0x24/0x3c
irq event stamp: 11252 hardirqs last enabled at (11251): []
_raw_spin_unlock_irqrestore+0x6c/0x74
hardirqs last disabled at (11252): []
_raw_spin_lock_irqsave+0x1c/0x5c softirqs last enabled at (9744): []
__do_softirq+0x3a4/0x66c softirqs last disabled at (9737): []
irq_exit+0x140/0x168 Preemption disabled at:
[<>] (null)
CPU: 7 PID: 1601 Comm: rtcwake Not tainted
5.0.0-rc3-next-20190122-00039-ga3f4ee4f8a52 #5252 Hardware name: SAMSUNG EXYNOS
(Flattened Device Tree) [] (unwind_backtrace) from []
(show_stack+0x10/0x14) [] (show_stack) from []
(dump_stack+0x90/0xc8) [] (dump_stack) from []
(___might_sleep+0x22c/0x2c8) [] (___might_sleep) from []
(synchronize_irq+0x28/0x84) [] (synchronize_irq) from []
(dwc3_gadget_suspend+0x34/0x3c) [] (dwc3_gadget_suspend) from
[] (dwc3_suspend_common+0x154/0x410) []
(dwc3_suspend_common) from [] (dwc3_suspend+0x14/0x2c) []
(dwc3_suspend) from [] (platform_pm_suspend+0x2c/0x54) []
(platform_pm_suspend) from [] (dpm_run_callback+0xa4/0x3dc)
[] (dpm_run_callback) from []
(__device_suspend+0x134/0x74c) [] (__device_suspend) from
[] (dpm_suspend+0x174/0x588) [] (dpm_suspend) from
[] (suspend_devices_and_enter+0xc0/0xe74)
[] (suspend_devices_and_enter) from []
(pm_suspend+0x770/0xc04) [] (pm_suspend) from []
(state_store+0x6c/0xcc) [] (state_store) from []
(kobj_attr_store+0x14/0x20) [] (kobj_attr_store) from []
(sysfs_kf_write+0x4c/0x50) [] (sysfs_kf_write) from []
(kernfs_fop_write+0xfc/0x1e4) [] (kernfs_fop_write) from []
(__vfs_write+0x2c/0x160) [] (__vfs_write) from []
(vfs_write+0xa4/0x16c) [] (vfs_write) from []
(ksys_write+0x40/0x8c) [] (ksys_write) from []
(ret_fast_syscall+0x0/0x28) Exception stack(0xed55ffa8 to 0xed55fff0) ...
Signed-off-by: Marek Szyprowski
---
drivers/usb/dwc3/core.c | 2 ++
drivers/usb/dwc3/gadget.c | 2 --
2 files changed, 2 insertions(+), 2 deletions(-)
diff --git a/drivers/usb/dwc3/core.c b/drivers/usb/dwc3/core.c index
a1b126f90261..206d7e5d6d71 100644
--- a/drivers/usb/dwc3/core.c
+++ b/drivers/usb/dwc3/core.c
@@ -1600,6 +1600,7 @@ static int dwc3_suspend_common(struct dwc3 *dwc,
pm_message_t msg)
spin_lock_irqsave(>lock, flags);
dwc3_gadget_suspend(dwc);
spin_unlock_irqrestore(>lock, flags);
+ synchronize_irq(dwc->irq_gadget);
dwc3_core_exit(dwc);
break;
case DWC3_GCTL_PRTCAP_HOST:
@@ -1632,6 +1633,7 @@ static int dwc3_suspend_common(struct dwc3 *dwc,
pm_message_t msg)
spin_lock_irqsave(>lock, flags);
dwc3_gadget_suspend(dwc);
spin_unlock_irqrestore(>lock, flags);
+ synchronize_irq(dwc->irq_gadget);
}
dwc3_otg_exit(dwc);
diff --git a/drivers/usb/dwc3/gadget.c b/drivers/usb/dwc3/gadget.c index
e293400cc6e9..2bb0ff9608d3 100644
--- a/drivers/usb/dwc3/gadget.c
+++ b/drivers/usb/dwc3/gadget.c
@@ -3384,8 +3384,6 @@ int dwc3_gadget_suspend(struct dwc3 *dwc)
dwc3_disconnect_gadget(dwc);
__dwc3_gadget_stop(dwc);
- synchronize_irq(dwc->irq_gadget);
-
return 0;
}
--
2.17.1
-Original Message-
From: Greg Kroah-Hartman
Sent: Monday, March 4, 2019 4:22 PM
To: linux-kernel@vger.kernel.org
Cc: Greg Kroah-Hartman ; sta...@vger.kernel.org;
He, Bo ; Wang, Yu Y ; Felipe Balbi
; Sasha Levin
Subject: [PATCH 4.20 12/88] usb: dwc3: gadget: synchronize_irq dwc irq in
suspend
4.20-stable review patch. If anyone has any objections, please let me know.
--
[ Upstream commit 01c10880d24291a96a4ab0da773e3c5ce4d12da8 ]
We see dwc3 endpoint stopped by unwanted irq during suspend resume test, which
is caused dwc3 ep can't be started with error "No Resource".
Here, add synchronize_irq before suspend to sync the pending IRQ handlers
complete.
Signed-off-by: Bo He
Signed-off-by: Yu Wang
Signed-off-by: Felipe Balbi
[PATCH] io: accel: kxcjk1013: restore the range after resume.
restore the range register in case kxcjk1013 power is off after suspend we see the issue on some laptops, after system suspend and resume, the CTRL_REG1 register changed from 0xc8 to 0x80, so acceleration range is changed, the patch is to restore the acceleration range after resume. Signed-off-by: he, bo Signed-off-by: Chen, Hu --- drivers/iio/accel/kxcjk-1013.c | 1 + 1 file changed, 1 insertion(+) diff --git a/drivers/iio/accel/kxcjk-1013.c b/drivers/iio/accel/kxcjk-1013.c index 7506bd9..c6bb3be 100644 --- a/drivers/iio/accel/kxcjk-1013.c +++ b/drivers/iio/accel/kxcjk-1013.c @@ -1340,6 +1340,7 @@ static int kxcjk1013_resume(struct device *dev) mutex_lock(>mutex); ret = kxcjk1013_set_mode(data, OPERATION); + ret += kxcjk1013_set_range(data, data->range); mutex_unlock(>mutex); return ret; -- 2.7.4
RE: rcu_preempt caused oom
check with jun:
the scenario is more like:
@@@rcu_start_this_gp@@@ start after ___swait_event before
schedule
rcu_gp_kthread--> swait_event_idle_exclusive--> __swait_event_idle-->
___swait_event->schedule
@@@ rcu_gp_kthread_wake skip wakeup in rcu_gp_kthread
then rcu_gp_kthread will sleep and can't wake up.
Jun's patch can workaround it, what's your ideas?
-Original Message-
From: Zhang, Jun
Sent: Tuesday, December 18, 2018 10:47 AM
To: He, Bo ; paul...@linux.ibm.com
Cc: Steven Rostedt ; linux-kernel@vger.kernel.org;
j...@joshtriplett.org; mathieu.desnoy...@efficios.com; jiangshan...@gmail.com;
Xiao, Jin ; Zhang, Yanmin ; Bai,
Jie A ; Sun, Yi J ; Chang, Junxiao
; Mei, Paul
Subject: RE: rcu_preempt caused oom
Hello, paul
In softirq context, and current is rcu_preempt-10, rcu_gp_kthread_wake don't
wakeup rcu_preempt.
Maybe next patch could fix it. Please help review.
diff --git a/kernel/rcu/tree.c b/kernel/rcu/tree.c index 0b760c1..98f5b40 100644
--- a/kernel/rcu/tree.c
+++ b/kernel/rcu/tree.c
@@ -1697,7 +1697,7 @@ static bool rcu_future_gp_cleanup(struct rcu_state *rsp,
struct rcu_node *rnp)
*/
static void rcu_gp_kthread_wake(struct rcu_state *rsp) {
- if (current == rsp->gp_kthread ||
+ if (((current == rsp->gp_kthread) && !in_softirq()) ||
!READ_ONCE(rsp->gp_flags) ||
!rsp->gp_kthread)
return;
[44932.311439, 0][ rcu_preempt] rcu_preempt-10[001] .n..
44929.401037: rcu_grace_period: rcu_preempt 19063548 reqwait
..
[44932.311517, 0][ rcu_preempt] rcu_preempt-10[001] d.s2
44929.402234: rcu_future_grace_period: rcu_preempt 19063548 19063552 0 0 3
Startleaf
[44932.311536, 0][ rcu_preempt] rcu_preempt-10[001] d.s2
44929.402237: rcu_future_grace_period: rcu_preempt 19063548 19063552 0 0 3
Startedroot
-----Original Message-
From: He, Bo
Sent: Tuesday, December 18, 2018 07:16
To: paul...@linux.ibm.com
Cc: Zhang, Jun ; Steven Rostedt ;
linux-kernel@vger.kernel.org; j...@joshtriplett.org;
mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Xiao, Jin
; Zhang, Yanmin ; Bai, Jie A
; Sun, Yi J ; Chang, Junxiao
; Mei, Paul
Subject: RE: rcu_preempt caused oom
Thanks for your comments, the issue could be panic with the change if (ret ==
1). Here enclosed are the logs.
-Original Message-
From: Paul E. McKenney
Sent: Monday, December 17, 2018 12:26 PM
To: He, Bo
Cc: Zhang, Jun ; Steven Rostedt ;
linux-kernel@vger.kernel.org; j...@joshtriplett.org;
mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Xiao, Jin
; Zhang, Yanmin ; Bai, Jie A
; Sun, Yi J ; Chang, Junxiao
; Mei, Paul
Subject: Re: rcu_preempt caused oom
On Mon, Dec 17, 2018 at 03:15:42AM +, He, Bo wrote:
> for double confirm the issue is not reproduce after 90 hours, we tried only
> add the enclosed patch on the easy reproduced build, the issue is not
> reproduced after 63 hours in the whole weekend on 16 boards.
> so current conclusion is the debug patch has extreme effect on the rcu issue.
This is not a surprise. (Please see the end of this email for a replacement
patch that won't suppress the bug.)
To see why this is not a surprise, let's take a closer look at your patch, in
light of the comment header for wait_event_idle_timeout_exclusive():
* Returns:
* 0 if the @condition evaluated to %false after the @timeout elapsed,
* 1 if the @condition evaluated to %true after the @timeout elapsed,
* or the remaining jiffies (at least 1) if the @condition evaluated
* to %true before the @timeout elapsed.
The situation we are seeing is that the RCU_GP_FLAG_INIT is set, but the
rcu_preempt task does not wake up. This would correspond to the second case
above, that is, a return value of 1. Looking now at your patch, with comments
interspersed below:
>From e8b583aa685b3b4f304f72398a80461bba09389c Mon Sep 17 00:00:00 2001
From: "he, bo"
Date: Sun, 9 Dec 2018 18:11:33 +0800
Subject: [PATCH] rcu: detect the preempt_rcu hang for triage jing's board
Change-Id: I2ffceec2ae4847867753609e45c99afc66956003
Tracked-On:
Signed-off-by: he, bo
---
kernel/rcu/tree.c | 20 ++--
1 file changed, 18 insertions(+), 2 deletions(-)
diff --git a/kernel/rcu/tree.c b/kernel/rcu/tree.c index 78c0cf2..d6de363 100644
--- a/kernel/rcu/tree.c
+++ b/kernel/rcu/tree.c
@@ -2192,8 +2192,13 @@ static int __noreturn rcu_gp_kthread(void *arg)
int ret;
struct rcu_state *rsp = arg;
struct rcu_node *rnp = rcu_get_root(rsp);
+ pid_t rcu_preempt_pid;
rcu_bind_gp_kthread();
+ if(!strcmp(rsp->name, "rcu_pr
RE: rcu_preempt caused oom
for double confirm the issue is not reproduce after 90 hours, we tried only add
the enclosed patch on the easy reproduced build, the issue is not reproduced
after 63 hours in the whole weekend on 16 boards.
so current conclusion is the debug patch has extreme effect on the rcu issue.
Compared with the swait_event_idle_timeout_exclusive will do 3 times to check
the condition, while swait_event_idle_ exclusive will do 2 times check the
condition.
so today I will do another experiment, only change as below:
- swait_event_idle_exclusive(rsp->gp_wq,
READ_ONCE(rsp->gp_flags) &
-RCU_GP_FLAG_INIT);
+ ret = swait_event_idle_timeout_exclusive(rsp->gp_wq,
READ_ONCE(rsp->gp_flags) &
+ RCU_GP_FLAG_INIT, MAX_SCHEDULE_TIMEOUT);
+
Can you get some clues from the experiment?
-Original Message-
From: Paul E. McKenney
Sent: Friday, December 14, 2018 1:39 PM
To: He, Bo
Cc: Zhang, Jun ; Steven Rostedt ;
linux-kernel@vger.kernel.org; j...@joshtriplett.org;
mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Xiao, Jin
; Zhang, Yanmin ; Bai, Jie A
; Sun, Yi J
Subject: Re: rcu_preempt caused oom
On Thu, Dec 13, 2018 at 09:10:12PM -0800, Paul E. McKenney wrote:
> On Fri, Dec 14, 2018 at 02:40:50AM +, He, Bo wrote:
> > another experiment we have done with the enclosed debug patch, and also
> > have more rcu trace event enable but without CONFIG_RCU_BOOST config, we
> > don't reproduce the issue after 90 Hours until now on 10 boards(the issue
> > should reproduce on one night per previous experience).
>
> That certainly supports the hypothesis that a wakeup is either not
> being sent or is being lost. Your patch is great for debugging (thank
> you!), but the real solution of course needs to avoid the extra
> wakeups, especially on battery-powered systems.
>
> One suggested change below, to get rid of potential false positives.
>
> > the purposes are to capture the more rcu event trace close to the issue
> > happen, because I check the __wait_rcu_gp is not always in running, so we
> > think even it trigger the panic for 3s timeout, the issue is already
> > happened before 3s.
>
> Agreed, it would be really good to have trace information from the cause.
> In the case you sent yesterday, it would be good to have trace
> information from 308.256 seconds prior to the sysrq-v, for example, by
> collecting the same event traces you did a few days ago. It would
> also be good to know whether the scheduler tick is providing
> interrupts, and if so, why
> rcu_check_gp_start_stall() isn't being invoked. ;-)
>
> If collecting this information with your setup is not feasible (for
> example, you might need a large trace buffer to capture five minutes
> of traces), please let me know and I can provide additional debug
> code. Or you could add "rcu_ftrace_dump(DUMP_ALL);" just before the
> "show_rcu_gp_kthreads();" in your patch below.
>
> > And Actually the rsp->gp_flags = 1, but RCU_GP_WAIT_GPS(1) ->state: 0x402,
> > it means the kthread is not schedule for 300s but the RCU_GP_FLAG_INIT is
> > set. What's your ideas?
>
> The most likely possibility is that my analysis below is confused and
> there really is some way that the code can set the RCU_GP_FLAG_INIT
> bit without later doing a wakeup. The trace data above could help
> unconfuse me.
>
> Thanx, Paul
>
> > -
> > - swait_event_idle_exclusive(rsp->gp_wq,
> > READ_ONCE(rsp->gp_flags) &
> > -RCU_GP_FLAG_INIT);
> > + if (current->pid != rcu_preempt_pid) {
> > + swait_event_idle_exclusive(rsp->gp_wq,
> > READ_ONCE(rsp->gp_flags) &
> > + RCU_GP_FLAG_INIT);
> > + } else {
>
> wait_again:
>
> > + ret =
> > swait_event_idle_timeout_exclusive(rsp->gp_wq, READ_ONCE(rsp->gp_flags) &
> > + RCU_GP_FLAG_INIT, 2*HZ);
> > +
> > + if(!ret) {
>
> This would avoid complaining if RCU was legitimately idle for a long time:
Let's try this again. Unless I am confused (quite possible) your original
would panic if RCU was idle for more than two seconds. What we instead want is
to
RE: rcu_preempt caused oom
another experiment we have done with the enclosed debug patch, and also have
more rcu trace event enable but without CONFIG_RCU_BOOST config, we don't
reproduce the issue after 90 Hours until now on 10 boards(the issue should
reproduce on one night per previous experience).
the purposes are to capture the more rcu event trace close to the issue happen,
because I check the __wait_rcu_gp is not always in running, so we think even it
trigger the panic for 3s timeout, the issue is already happened before 3s.
And Actually the rsp->gp_flags = 1, but RCU_GP_WAIT_GPS(1) ->state: 0x402, it
means the kthread is not schedule for 300s but the RCU_GP_FLAG_INIT is set.
What's your ideas?
-
- swait_event_idle_exclusive(rsp->gp_wq,
READ_ONCE(rsp->gp_flags) &
-RCU_GP_FLAG_INIT);
+ if (current->pid != rcu_preempt_pid) {
+ swait_event_idle_exclusive(rsp->gp_wq,
READ_ONCE(rsp->gp_flags) &
+ RCU_GP_FLAG_INIT);
+ } else {
+ ret =
swait_event_idle_timeout_exclusive(rsp->gp_wq, READ_ONCE(rsp->gp_flags) &
+ RCU_GP_FLAG_INIT, 2*HZ);
+
+ if(!ret) {
+ show_rcu_gp_kthreads();
+ panic("hung_task: blocked in
rcu_gp_kthread init");
+ }
+ }
--
-Original Message-
From: Paul E. McKenney
Sent: Friday, December 14, 2018 10:15 AM
To: He, Bo
Cc: Zhang, Jun ; Steven Rostedt ;
linux-kernel@vger.kernel.org; j...@joshtriplett.org;
mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Xiao, Jin
; Zhang, Yanmin ; Bai, Jie A
; Sun, Yi J
Subject: Re: rcu_preempt caused oom
On Fri, Dec 14, 2018 at 01:30:04AM +, He, Bo wrote:
> as you mentioned CONFIG_FAST_NO_HZ, do you mean CONFIG_RCU_FAST_NO_HZ? I
> double checked there is no FAST_NO_HZ in .config:
Yes, you are correct, CONFIG_RCU_FAST_NO_HZ. OK, you do not have it set, which
means several code paths can be ignored. Also CONFIG_HZ=1000, so
300 second delay.
Thanx, Paul
> Here is the grep from .config:
> egrep "HZ|RCU" .config
> CONFIG_NO_HZ_COMMON=y
> # CONFIG_HZ_PERIODIC is not set
> CONFIG_NO_HZ_IDLE=y
> # CONFIG_NO_HZ_FULL is not set
> CONFIG_NO_HZ=y
> # RCU Subsystem
> CONFIG_PREEMPT_RCU=y
> # CONFIG_RCU_EXPERT is not set
> CONFIG_SRCU=y
> CONFIG_TREE_SRCU=y
> CONFIG_TASKS_RCU=y
> CONFIG_RCU_STALL_COMMON=y
> CONFIG_RCU_NEED_SEGCBLIST=y
> # CONFIG_HZ_100 is not set
> # CONFIG_HZ_250 is not set
> # CONFIG_HZ_300 is not set
> CONFIG_HZ_1000=y
> CONFIG_HZ=1000
> # CONFIG_MACHZ_WDT is not set
> # RCU Debugging
> CONFIG_PROVE_RCU=y
> CONFIG_RCU_PERF_TEST=m
> CONFIG_RCU_TORTURE_TEST=m
> CONFIG_RCU_CPU_STALL_TIMEOUT=7
> CONFIG_RCU_TRACE=y
> CONFIG_RCU_EQS_DEBUG=y
>
> -Original Message-
> From: Paul E. McKenney
> Sent: Friday, December 14, 2018 2:12 AM
> To: He, Bo
> Cc: Zhang, Jun ; Steven Rostedt
> ; linux-kernel@vger.kernel.org;
> j...@joshtriplett.org; mathieu.desnoy...@efficios.com;
> jiangshan...@gmail.com; Xiao, Jin ; Zhang, Yanmin
> ; Bai, Jie A ; Sun, Yi J
>
> Subject: Re: rcu_preempt caused oom
>
> On Thu, Dec 13, 2018 at 03:26:08PM +, He, Bo wrote:
> > one of the board reproduce the issue with the show_rcu_gp_kthreads(), I
> > also enclosed the logs as attachment.
> >
> > [17818.936032] rcu: rcu_preempt: wait state: RCU_GP_WAIT_GPS(1) ->state:
> > 0x402 delta ->gp_activity 308257 ->gp_req_activity 308256 ->gp_wake_time
> > 308258 ->gp_wake_seq 21808189 ->gp_seq 21808192 ->gp_seq_needed
> > 21808196 ->gp_flags 0x1
>
> This is quite helpful, thank you!
>
> The "RCU lockdep checking is enabled" says that CONFIG_PROVE_RCU=y, which is
> good. The "RCU_GP_WAIT_GPS(1)" means that the rcu_preempt task is waiting
> for a new grace-period request. The "->state: 0x402" means that it is
> sleeping, neither running nor in the process of waking up.
> The "delta ->gp_activity 308257 ->gp_req_activity 308256 ->gp_wake_time
> 308258" means that it has been more than 300,000 jiffies since the
> rcu_preempt task did anything or was requested to do anything.
>
> The "->gp_wake_seq 21808189 -&g
RE: rcu_preempt caused oom
as you mentioned CONFIG_FAST_NO_HZ, do you mean CONFIG_RCU_FAST_NO_HZ? I double checked there is no FAST_NO_HZ in .config: Here is the grep from .config: egrep "HZ|RCU" .config CONFIG_NO_HZ_COMMON=y # CONFIG_HZ_PERIODIC is not set CONFIG_NO_HZ_IDLE=y # CONFIG_NO_HZ_FULL is not set CONFIG_NO_HZ=y # RCU Subsystem CONFIG_PREEMPT_RCU=y # CONFIG_RCU_EXPERT is not set CONFIG_SRCU=y CONFIG_TREE_SRCU=y CONFIG_TASKS_RCU=y CONFIG_RCU_STALL_COMMON=y CONFIG_RCU_NEED_SEGCBLIST=y # CONFIG_HZ_100 is not set # CONFIG_HZ_250 is not set # CONFIG_HZ_300 is not set CONFIG_HZ_1000=y CONFIG_HZ=1000 # CONFIG_MACHZ_WDT is not set # RCU Debugging CONFIG_PROVE_RCU=y CONFIG_RCU_PERF_TEST=m CONFIG_RCU_TORTURE_TEST=m CONFIG_RCU_CPU_STALL_TIMEOUT=7 CONFIG_RCU_TRACE=y CONFIG_RCU_EQS_DEBUG=y -Original Message- From: Paul E. McKenney Sent: Friday, December 14, 2018 2:12 AM To: He, Bo Cc: Zhang, Jun ; Steven Rostedt ; linux-kernel@vger.kernel.org; j...@joshtriplett.org; mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Xiao, Jin ; Zhang, Yanmin ; Bai, Jie A ; Sun, Yi J Subject: Re: rcu_preempt caused oom On Thu, Dec 13, 2018 at 03:26:08PM +0000, He, Bo wrote: > one of the board reproduce the issue with the show_rcu_gp_kthreads(), I also > enclosed the logs as attachment. > > [17818.936032] rcu: rcu_preempt: wait state: RCU_GP_WAIT_GPS(1) ->state: > 0x402 delta ->gp_activity 308257 ->gp_req_activity 308256 ->gp_wake_time > 308258 ->gp_wake_seq 21808189 ->gp_seq 21808192 ->gp_seq_needed > 21808196 ->gp_flags 0x1 This is quite helpful, thank you! The "RCU lockdep checking is enabled" says that CONFIG_PROVE_RCU=y, which is good. The "RCU_GP_WAIT_GPS(1)" means that the rcu_preempt task is waiting for a new grace-period request. The "->state: 0x402" means that it is sleeping, neither running nor in the process of waking up. The "delta ->gp_activity 308257 ->gp_req_activity 308256 ->gp_wake_time 308258" means that it has been more than 300,000 jiffies since the rcu_preempt task did anything or was requested to do anything. The "->gp_wake_seq 21808189 ->gp_seq 21808192" says that the last attempt to awaken the rcu_preempt task happened during the last grace period. The "->gp_seq_needed 21808196 ->gp_flags 0x1" nevertheless says that someone requested a new grace period. So if the rcu_preempt task were to wake up, it would process the new grace period. Note again also the ->gp_req_activity 308256, which indicates that ->gp_flags was set more than 300,000 jiffies ago, just after the last recorded activity of the rcu_preempt task. But this is exactly the situation that rcu_check_gp_start_stall() is designed to warn about (and does warn about for me when I comment out the wakeup code). So why is rcu_check_gp_start_stall() not being called? Here are a couple of possibilities: 1. Because rcu_check_gp_start_stall() is only ever invoked from RCU_SOFTIRQ, it is possible that softirqs are stalled for whatever reason. 2. Because RCU_SOFTIRQ is invoked primarily from the scheduler-clock interrupt handler, it is possible that the scheduler tick has somehow been disabled. Traces from earlier runs showed a great deal of RCU callbacks queued, which would have caused RCU to refuse to allow the scheduler tick to be disabled, even if the corresponding CPU was idle. 3. You have CONFIG_FAST_NO_HZ=y (which you probably do, given that you are building for a battery-powered device) and all of the CPU's callbacks are lazy. Except that your earlier traces showed lots of non-lazy callbacks. Besides, even if all callbacks were lazy, there would still be a scheduling-clock interrupt every six seconds, and there are quite a few six-second intervals in a two-minute watchdog timeout. But if we cannot find the problem quickly, I will likely ask you to try reproducing with CONFIG_FAST_NO_HZ=n. This could be thought of as bisecting the RCU code looking for the bug. The first two of these seem unlikely given that the watchdog timer was still firing. Still, I don't see how 300,000 jiffies elapsed with a grace period requested and not started otherwise. Could you please check? One way to do so would be to enable ftrace on rcu_check_callbacks(), __rcu_process_callbacks(), and rcu_check_gp_start_stall(). It might be necessary to no-inline rcu_check_gp_start_stall(). You might have better ways to collect this information. Without this information, the only workaround patch I can give you will degrade battery lifetime, which might not be what you want. You do have a lockdep complaint early at boot. Although I don't immediately see how this self-deadlock would affect RCU, please do get it fixed. Sometimes the consequen
RE: rcu_preempt caused oom
I don't see the rcutree.sysrq_rcu parameter in v4.19 kernel, I also checked the
latest kernel and the latest tag v4.20-rc6, not see the sysrq_rcu.
Please correct me if I have something wrong.
-Original Message-
From: Paul E. McKenney
Sent: Thursday, December 13, 2018 5:03 AM
To: He, Bo
Cc: Steven Rostedt ; linux-kernel@vger.kernel.org;
j...@joshtriplett.org; mathieu.desnoy...@efficios.com; jiangshan...@gmail.com;
Zhang, Jun ; Xiao, Jin ; Zhang, Yanmin
; Bai, Jie A
Subject: Re: rcu_preempt caused oom
On Wed, Dec 12, 2018 at 07:42:24AM -0800, Paul E. McKenney wrote:
> On Wed, Dec 12, 2018 at 01:21:33PM +0000, He, Bo wrote:
> > we reproduce on two boards, but I still not see the show_rcu_gp_kthreads()
> > dump logs, it seems the patch can't catch the scenario.
> > I double confirmed the CONFIG_PROVE_RCU=y is enabled in the config as it's
> > extracted from the /proc/config.gz.
>
> Strange.
>
> Are the systems responsive to sysrq keys once failure occurs? If so,
> I will provide you a sysrq-R or some such to dump out the RCU state.
Or, as it turns out, sysrq-y if booting with rcutree.sysrq_rcu=1 using the
patch below. Only lightly tested.
Thanx, Paul
commit adfc7dff659495a3433d5084256be59eee0ac6df
Author: Paul E. McKenney
Date: Mon Dec 10 16:33:59 2018 -0800
rcu: Improve diagnostics for failed RCU grace-period start
Backported from v4.21/v5.0
If a grace period fails to start (for example, because you commented
out the last two lines of rcu_accelerate_cbs_unlocked()), rcu_core()
will invoke rcu_check_gp_start_stall(), which will notice and complain.
However, this complaint is lacking crucial debugging information such
as when the last wakeup executed and what the value of ->gp_seq was at
that time. This commit therefore removes the current pr_alert() from
rcu_check_gp_start_stall(), instead invoking show_rcu_gp_kthreads(),
which has been updated to print the needed information, which is collected
by rcu_gp_kthread_wake().
Signed-off-by: Paul E. McKenney
diff --git a/kernel/rcu/tree.c b/kernel/rcu/tree.c index
0b760c1369f7..4bcd8753e293 100644
--- a/kernel/rcu/tree.c
+++ b/kernel/rcu/tree.c
@@ -626,25 +626,57 @@ void rcu_sched_force_quiescent_state(void)
}
EXPORT_SYMBOL_GPL(rcu_sched_force_quiescent_state);
+/*
+ * Convert a ->gp_state value to a character string.
+ */
+static const char *gp_state_getname(short gs) {
+ if (gs < 0 || gs >= ARRAY_SIZE(gp_state_names))
+ return "???";
+ return gp_state_names[gs];
+}
+
+/*
+ * Return the root node of the specified rcu_state structure.
+ */
+static struct rcu_node *rcu_get_root(struct rcu_state *rsp) {
+ return >node[0];
+}
+
/*
* Show the state of the grace-period kthreads.
*/
void show_rcu_gp_kthreads(void)
{
int cpu;
+ unsigned long j;
+ unsigned long ja;
+ unsigned long jr;
+ unsigned long jw;
struct rcu_data *rdp;
struct rcu_node *rnp;
struct rcu_state *rsp;
+ j = jiffies;
for_each_rcu_flavor(rsp) {
- pr_info("%s: wait state: %d ->state: %#lx\n",
- rsp->name, rsp->gp_state, rsp->gp_kthread->state);
+ ja = j - READ_ONCE(rsp->gp_activity);
+ jr = j - READ_ONCE(rsp->gp_req_activity);
+ jw = j - READ_ONCE(rsp->gp_wake_time);
+ pr_info("%s: wait state: %s(%d) ->state: %#lx delta
->gp_activity %lu ->gp_req_activity %lu ->gp_wake_time %lu ->gp_wake_seq %ld
->gp_seq %ld ->gp_seq_needed %ld ->gp_flags %#x\n",
+ rsp->name, gp_state_getname(rsp->gp_state),
+ rsp->gp_state,
+ rsp->gp_kthread ? rsp->gp_kthread->state : 0x1L,
+ ja, jr, jw, (long)READ_ONCE(rsp->gp_wake_seq),
+ (long)READ_ONCE(rsp->gp_seq),
+ (long)READ_ONCE(rcu_get_root(rsp)->gp_seq_needed),
+ READ_ONCE(rsp->gp_flags));
rcu_for_each_node_breadth_first(rsp, rnp) {
if (ULONG_CMP_GE(rsp->gp_seq, rnp->gp_seq_needed))
continue;
- pr_info("\trcu_node %d:%d ->gp_seq %lu ->gp_seq_needed
%lu\n",
- rnp->grplo, rnp->grphi, rnp->gp_seq,
- rnp->gp_seq_needed);
+ pr_info("\trcu_node %d:%d ->gp_seq %ld ->gp_seq_needed
%ld\n",
+ rnp->grplo, rnp->grphi, (long)rnp->gp_seq,
+ (long)rnp-&
RE: rcu_preempt caused oom
sure, we will update the new patch to run the test.
-Original Message-
From: Paul E. McKenney
Sent: Tuesday, December 11, 2018 12:47 PM
To: He, Bo
Cc: Steven Rostedt ; linux-kernel@vger.kernel.org;
j...@joshtriplett.org; mathieu.desnoy...@efficios.com; jiangshan...@gmail.com;
Zhang, Jun ; Xiao, Jin ; Zhang, Yanmin
; Bai, Jie A
Subject: Re: rcu_preempt caused oom
On Mon, Dec 10, 2018 at 04:38:38PM -0800, Paul E. McKenney wrote:
> On Mon, Dec 10, 2018 at 06:56:18AM +0000, He, Bo wrote:
> > Hi,
> >We have start the test with the CONFIG_PROVE_RCU=y, and also add one 2s
> > to detect the preempt rcu hang, hope we can get more useful logs tomorrow.
> >I also enclosed the config and the debug patches for you review.
>
> I instead suggest the (lightly tested) debug patch shown below, which
> tracks wakeups of RCU's grace-period kthreads and dumps them out if a
> given requested grace period fails to start. Again, it is necessary
> to build with CONFIG_PROVE_RCU=y, that is, with CONFIG_PROVE_LOCKING=y.
Right. This time without commenting out the wakeup as a test of the
diagnostic. :-/
Please use the patch below instead of the one that I sent in my previous email.
Thanx, Paul
commit adfc7dff659495a3433d5084256be59eee0ac6df
Author: Paul E. McKenney
Date: Mon Dec 10 16:33:59 2018 -0800
rcu: Improve diagnostics for failed RCU grace-period start
Backported from v4.21/v5.0
If a grace period fails to start (for example, because you commented
out the last two lines of rcu_accelerate_cbs_unlocked()), rcu_core()
will invoke rcu_check_gp_start_stall(), which will notice and complain.
However, this complaint is lacking crucial debugging information such
as when the last wakeup executed and what the value of ->gp_seq was at
that time. This commit therefore removes the current pr_alert() from
rcu_check_gp_start_stall(), instead invoking show_rcu_gp_kthreads(),
which has been updated to print the needed information, which is collected
by rcu_gp_kthread_wake().
Signed-off-by: Paul E. McKenney
diff --git a/kernel/rcu/tree.c b/kernel/rcu/tree.c index
0b760c1369f7..4bcd8753e293 100644
--- a/kernel/rcu/tree.c
+++ b/kernel/rcu/tree.c
@@ -626,25 +626,57 @@ void rcu_sched_force_quiescent_state(void)
}
EXPORT_SYMBOL_GPL(rcu_sched_force_quiescent_state);
+/*
+ * Convert a ->gp_state value to a character string.
+ */
+static const char *gp_state_getname(short gs) {
+ if (gs < 0 || gs >= ARRAY_SIZE(gp_state_names))
+ return "???";
+ return gp_state_names[gs];
+}
+
+/*
+ * Return the root node of the specified rcu_state structure.
+ */
+static struct rcu_node *rcu_get_root(struct rcu_state *rsp) {
+ return >node[0];
+}
+
/*
* Show the state of the grace-period kthreads.
*/
void show_rcu_gp_kthreads(void)
{
int cpu;
+ unsigned long j;
+ unsigned long ja;
+ unsigned long jr;
+ unsigned long jw;
struct rcu_data *rdp;
struct rcu_node *rnp;
struct rcu_state *rsp;
+ j = jiffies;
for_each_rcu_flavor(rsp) {
- pr_info("%s: wait state: %d ->state: %#lx\n",
- rsp->name, rsp->gp_state, rsp->gp_kthread->state);
+ ja = j - READ_ONCE(rsp->gp_activity);
+ jr = j - READ_ONCE(rsp->gp_req_activity);
+ jw = j - READ_ONCE(rsp->gp_wake_time);
+ pr_info("%s: wait state: %s(%d) ->state: %#lx delta
->gp_activity %lu ->gp_req_activity %lu ->gp_wake_time %lu ->gp_wake_seq %ld
->gp_seq %ld ->gp_seq_needed %ld ->gp_flags %#x\n",
+ rsp->name, gp_state_getname(rsp->gp_state),
+ rsp->gp_state,
+ rsp->gp_kthread ? rsp->gp_kthread->state : 0x1L,
+ ja, jr, jw, (long)READ_ONCE(rsp->gp_wake_seq),
+ (long)READ_ONCE(rsp->gp_seq),
+ (long)READ_ONCE(rcu_get_root(rsp)->gp_seq_needed),
+ READ_ONCE(rsp->gp_flags));
rcu_for_each_node_breadth_first(rsp, rnp) {
if (ULONG_CMP_GE(rsp->gp_seq, rnp->gp_seq_needed))
continue;
- pr_info("\trcu_node %d:%d ->gp_seq %lu ->gp_seq_needed
%lu\n",
- rnp->grplo, rnp->grphi, rnp->gp_seq,
- rnp->gp_seq_needed);
+ pr_info("\trcu_node %d:%d ->gp_seq %ld ->gp_seq_needed
%ld\n",
+ rnp->grplo, rnp->grphi, (long)rnp->gp_seq,
+
RE: rcu_preempt caused oom
Hi,
We have start the test with the CONFIG_PROVE_RCU=y, and also add one 2s to
detect the preempt rcu hang, hope we can get more useful logs tomorrow.
I also enclosed the config and the debug patches for you review.
-Original Message-
From: Paul E. McKenney
Sent: Monday, December 10, 2018 3:56 AM
To: He, Bo
Cc: Steven Rostedt ; linux-kernel@vger.kernel.org;
j...@joshtriplett.org; mathieu.desnoy...@efficios.com; jiangshan...@gmail.com;
Zhang, Jun ; Xiao, Jin ; Zhang, Yanmin
; Bai, Jie A
Subject: Re: rcu_preempt caused oom
On Fri, Dec 07, 2018 at 06:11:31AM -0800, Paul E. McKenney wrote:
> On Fri, Dec 07, 2018 at 08:25:09AM +0000, He, Bo wrote:
> > Bad news, the issue is still reproduced after 61 Hours monkey test on 1/6
> > boards with the CONFIG_RCU_BOOST=y, and the issue is not seen on kernel
> > 4.14, the CONFIG_RCU_BOOST is also not enabled in our kernel 4.14 config.
> > Here enclosed is the logs.
> >
> > > So the question becomes "Why is the grace-period kthread being awakened
> > > so many times, but not actually waking up?"
> > maybe it's not schedule issue, I have two suspects:
> > we can see tons of grace_period with 117392312:
> > [219346.919405, 0] showmap-31232 [000] d..1 219346.136035:
> > rcu_future_grace_period: rcu_preempt 117392312 117392316 0 0 3
> > Startleaf [219346.919417, 0] showmap-31232 [000] d..1
> > 219346.136036: rcu_future_grace_period: rcu_preempt 117392312
> > 117392316 0 0 3 Prestarted [219346.919429, 0] showmap-31232 [000]
> > d..1 219346.136036: rcu_grace_period: rcu_preempt 117392312
> > AccWaitCB
> >
> > "Startleaf" means start the grace period, "Prestarted" means the grace
> > period is already started or other conditions blocked, RCU_GP_FLAG_INIT
> > should follow the "Startedroot", then the kthread can be wakeup.
>
> Yes, when "Startleaf" is followed by "Prestarted", that means that we
> reached an rcu_node structure that is already aware that the requested
> grace period is needed. Breaking down the relevant "if" statement in
> rcu_start_this_gp():
>
> if (ULONG_CMP_GE(rnp->gp_seq_needed, gp_seq_req) ||
> // A. GP already requested at this rcu_node
> rcu_seq_started(>gp_seq, gp_seq_req) ||
> // B. The requested grace period already started
> (rnp != rnp_start &&
>rcu_seq_state(rcu_seq_current(>gp_seq {
> // C. Leaf rcu_node recorded request, and
> // some grace period is in progress
>
> A:In this case, the "Startedroot" should be taken care of by some
> other thread, or one of B or C held earlier.
>
> B:This cannot be the case, because your earlier trace showed that
> the requested grace period had not started.
>
> C:This cannot be the case because both traces above are on the
> leaf rcu_node structure. If it were the case, the currently
> running grace period would notice the need for the requested
> grace period when it ended, and would start the grace period
> at that time.
>
> So you are saying that your trace goes back far enough to capture the
> very first "Startleaf" for this new grace period, and you don't ever
> see a "Startedroot"? This would be OK if the later "Startedleaf"
> showed up at that point. If you do have such a trace, could you
> please send it to me (or post it somewhere and send me the URL)?
>
> In any case, this code has bee reworked recently, so I will take a
> closer look, which will take some time. Please feel free to continue
> to do so as well, of course!
Hmmm... Could you please build with CONFIG_PROVE_RCU=y and run the original
(for example, CONFIG_RCU_BOOST=n)? I would expect this to trigger the warning
in rcu_check_gp_start_stall(). Of course, if it does not trigger, that would
be valuable information as well.
Thanx, Paul
> > I do experiment to dump the backtrace, the rcu_quiescent_state_report is
> > called in softirq context:
> > -0 [000] dNs2 24471.669280: rcu_quiescent_state_report:
> > rcu_preempt 3562401 1>0 0 0 3 0
> > -0 [000] dNs2 24471.669293:
> > => rcu_report_qs_rnp+0x1e2/0x2a0
> > => rcu_process_callbacks+0x2f1/0x3c0 => __do_softirq+0x12a/0x386
> > => irq_exit+0xb1/0xc0 => smp_apic_timer_interrupt+0xd4/0x1e0
> > => apic_timer_interrupt+0xf/0x20
> > => cpuidle_enter_state+0xb1/0x340
> > => cpui
RE: rcu_preempt caused oom
I double checked the .config, we don't enable CONFIG_NO_HZ_FULL . Our previous logs can dump all the task backtrace, and kthread (the rcu_preempt, rcu_sched, and rcu_bh tasks) are all in "I" state not in "R" state, my understandings are if it's the side-effect of causing RCU's kthreads to be run at SCHED_FIFO priority 1, the kthreads should be in R state. I will do more experiments and keep you update once we have more findings: 1. set the kthread priority to SCHED_FIFO without CONFIG_RCU_BOOST and see if the issue can reproduce. 2. check more ftrace to double confirm why there is no trace_rcu_quiescent_state_report and most of the trace_rcu_grace_period are in "AccWaitCB". -Original Message- From: Paul E. McKenney Sent: Wednesday, December 5, 2018 3:50 AM To: He, Bo Cc: Steven Rostedt ; linux-kernel@vger.kernel.org; j...@joshtriplett.org; mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Zhang, Jun ; Xiao, Jin ; Zhang, Yanmin ; Bai, Jie A Subject: Re: rcu_preempt caused oom On Tue, Dec 04, 2018 at 07:50:04AM +, He, Bo wrote: > Hi, Paul: > the enclosed is the log trigger the 120s hung_task_panic without other debug > patches, the hung task is blocked at __wait_rcu_gp, it means the > rcu_cpu_stall can't detect the scenario: > echo 1 > /proc/sys/kernel/panic_on_rcu_stall > echo 7 > /sys/module/rcupdate/parameters/rcu_cpu_stall_timeout Not necessarily. If there is an RCU CPU stall warning, blocking within __wait_rcu_gp() is expected behavior. It is possible that the problem is that although the grace period is completing as required, the callbacks are not being invoked in a timely fashion. And that could happen if you had CONFIG_NO_HZ_FULL and a bunch of nohz_full CPUs, or, alternatively, callback offloading enabled. But I don't see these in your previous emails. Another possible cause is that the grace-period kthread is being delayed, so that the grace period never starts. This seems unlikely, but it is the only thing thus far that matches the symptoms. CONFIG_RCU_BOOST=y has the side-effect of causing RCU's kthreads to be run at SCHED_FIFO priority 1, and that would help in the case where RCU's grace-period kthread (the rcu_preempt, rcu_sched, and rcu_bh tasks, all of which execute in the rcu_gp_kthread() function) was being starved of CPU time. Does that sound likely? Thanx, Paul > -Original Message- > From: Paul E. McKenney > Sent: Monday, December 3, 2018 9:57 PM > To: He, Bo > Cc: Steven Rostedt ; > linux-kernel@vger.kernel.org; j...@joshtriplett.org; > mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Zhang, Jun > ; Xiao, Jin ; Zhang, Yanmin > > Subject: Re: rcu_preempt caused oom > > On Mon, Dec 03, 2018 at 07:44:03AM +, He, Bo wrote: > > Thanks, we have run the test for the whole weekend and not reproduce the > > issue, so we confirm the CONFIG_RCU_BOOST can fix the issue. > > Very good, that is encouraging. Perhaps I should think about making > CONFIG_RCU_BOOST=y the default for CONFIG_PREEMPT in mainline, at least for > architectures for which rt_mutexes are implemented. > > > We have enabled the rcupdate.rcu_cpu_stall_timeout=7 and also set panic on > > rcu stall and will see if we can see the panic, will keep you posed with > > the test results. > > echo 1 > /proc/sys/kernel/panic_on_rcu_stall > > Looking forward to seeing what is going on! Of course, to reproduce, you > will need to again build with CONFIG_RCU_BOOST=n. > > Thanx, Paul > > > -Original Message- > > From: Paul E. McKenney > > Sent: Saturday, December 1, 2018 12:49 AM > > To: He, Bo > > Cc: Steven Rostedt ; > > linux-kernel@vger.kernel.org; j...@joshtriplett.org; > > mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Zhang, Jun > > ; Xiao, Jin ; Zhang, Yanmin > > > > Subject: Re: rcu_preempt caused oom > > > > On Fri, Nov 30, 2018 at 03:18:58PM +, He, Bo wrote: > > > Here is the kernel cmdline: > > > > Thank you! > > > > > Kernel command line: androidboot.acpio_idx=0 > > > androidboot.bootloader=efiwrapper-02_03-userdebug_kernelflinger-06 > > > _0 > > > 3- userdebug androidboot.diskbus=00.0 > > > androidboot.verifiedbootstate=green > > > androidboot.bootreason=power-on > > > androidboot.serialno=R1J56L6006a7bb > > > g_ffs.iSerialNumber=R1J56L6006a7bb no_timer_check noxsaves > > > reboot_panic=p,w i915.hpd_sense_invert=0x7 mem=2G nokaslr nopti > > > ftrace_dump_on_oops trace_buf_size=1024K intel_iommu=off gpt > > > loglevel=4 andr
RE: rcu_preempt caused oom
I double checked the .config, we don't enable CONFIG_NO_HZ_FULL . Our previous logs can dump all the task backtrace, and kthread (the rcu_preempt, rcu_sched, and rcu_bh tasks) are all in "I" state not in "R" state, my understandings are if it's the side-effect of causing RCU's kthreads to be run at SCHED_FIFO priority 1, the kthreads should be in R state. I will do more experiments and keep you update once we have more findings: 1. set the kthread priority to SCHED_FIFO without CONFIG_RCU_BOOST and see if the issue can reproduce. 2. check more ftrace to double confirm why there is no trace_rcu_quiescent_state_report and most of the trace_rcu_grace_period are in "AccWaitCB". -Original Message- From: Paul E. McKenney Sent: Wednesday, December 5, 2018 3:50 AM To: He, Bo Cc: Steven Rostedt ; linux-kernel@vger.kernel.org; j...@joshtriplett.org; mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Zhang, Jun ; Xiao, Jin ; Zhang, Yanmin ; Bai, Jie A Subject: Re: rcu_preempt caused oom On Tue, Dec 04, 2018 at 07:50:04AM +, He, Bo wrote: > Hi, Paul: > the enclosed is the log trigger the 120s hung_task_panic without other debug > patches, the hung task is blocked at __wait_rcu_gp, it means the > rcu_cpu_stall can't detect the scenario: > echo 1 > /proc/sys/kernel/panic_on_rcu_stall > echo 7 > /sys/module/rcupdate/parameters/rcu_cpu_stall_timeout Not necessarily. If there is an RCU CPU stall warning, blocking within __wait_rcu_gp() is expected behavior. It is possible that the problem is that although the grace period is completing as required, the callbacks are not being invoked in a timely fashion. And that could happen if you had CONFIG_NO_HZ_FULL and a bunch of nohz_full CPUs, or, alternatively, callback offloading enabled. But I don't see these in your previous emails. Another possible cause is that the grace-period kthread is being delayed, so that the grace period never starts. This seems unlikely, but it is the only thing thus far that matches the symptoms. CONFIG_RCU_BOOST=y has the side-effect of causing RCU's kthreads to be run at SCHED_FIFO priority 1, and that would help in the case where RCU's grace-period kthread (the rcu_preempt, rcu_sched, and rcu_bh tasks, all of which execute in the rcu_gp_kthread() function) was being starved of CPU time. Does that sound likely? Thanx, Paul > -Original Message- > From: Paul E. McKenney > Sent: Monday, December 3, 2018 9:57 PM > To: He, Bo > Cc: Steven Rostedt ; > linux-kernel@vger.kernel.org; j...@joshtriplett.org; > mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Zhang, Jun > ; Xiao, Jin ; Zhang, Yanmin > > Subject: Re: rcu_preempt caused oom > > On Mon, Dec 03, 2018 at 07:44:03AM +, He, Bo wrote: > > Thanks, we have run the test for the whole weekend and not reproduce the > > issue, so we confirm the CONFIG_RCU_BOOST can fix the issue. > > Very good, that is encouraging. Perhaps I should think about making > CONFIG_RCU_BOOST=y the default for CONFIG_PREEMPT in mainline, at least for > architectures for which rt_mutexes are implemented. > > > We have enabled the rcupdate.rcu_cpu_stall_timeout=7 and also set panic on > > rcu stall and will see if we can see the panic, will keep you posed with > > the test results. > > echo 1 > /proc/sys/kernel/panic_on_rcu_stall > > Looking forward to seeing what is going on! Of course, to reproduce, you > will need to again build with CONFIG_RCU_BOOST=n. > > Thanx, Paul > > > -Original Message- > > From: Paul E. McKenney > > Sent: Saturday, December 1, 2018 12:49 AM > > To: He, Bo > > Cc: Steven Rostedt ; > > linux-kernel@vger.kernel.org; j...@joshtriplett.org; > > mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Zhang, Jun > > ; Xiao, Jin ; Zhang, Yanmin > > > > Subject: Re: rcu_preempt caused oom > > > > On Fri, Nov 30, 2018 at 03:18:58PM +, He, Bo wrote: > > > Here is the kernel cmdline: > > > > Thank you! > > > > > Kernel command line: androidboot.acpio_idx=0 > > > androidboot.bootloader=efiwrapper-02_03-userdebug_kernelflinger-06 > > > _0 > > > 3- userdebug androidboot.diskbus=00.0 > > > androidboot.verifiedbootstate=green > > > androidboot.bootreason=power-on > > > androidboot.serialno=R1J56L6006a7bb > > > g_ffs.iSerialNumber=R1J56L6006a7bb no_timer_check noxsaves > > > reboot_panic=p,w i915.hpd_sense_invert=0x7 mem=2G nokaslr nopti > > > ftrace_dump_on_oops trace_buf_size=1024K intel_iommu=off gpt > > > loglevel=4 andr
RE: rcu_preempt caused oom
Hi, Paul: the enclosed is the log trigger the 120s hung_task_panic without other debug patches, the hung task is blocked at __wait_rcu_gp, it means the rcu_cpu_stall can't detect the scenario: echo 1 > /proc/sys/kernel/panic_on_rcu_stall echo 7 > /sys/module/rcupdate/parameters/rcu_cpu_stall_timeout -Original Message- From: Paul E. McKenney Sent: Monday, December 3, 2018 9:57 PM To: He, Bo Cc: Steven Rostedt ; linux-kernel@vger.kernel.org; j...@joshtriplett.org; mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Zhang, Jun ; Xiao, Jin ; Zhang, Yanmin Subject: Re: rcu_preempt caused oom On Mon, Dec 03, 2018 at 07:44:03AM +0000, He, Bo wrote: > Thanks, we have run the test for the whole weekend and not reproduce the > issue, so we confirm the CONFIG_RCU_BOOST can fix the issue. Very good, that is encouraging. Perhaps I should think about making CONFIG_RCU_BOOST=y the default for CONFIG_PREEMPT in mainline, at least for architectures for which rt_mutexes are implemented. > We have enabled the rcupdate.rcu_cpu_stall_timeout=7 and also set panic on > rcu stall and will see if we can see the panic, will keep you posed with the > test results. > echo 1 > /proc/sys/kernel/panic_on_rcu_stall Looking forward to seeing what is going on! Of course, to reproduce, you will need to again build with CONFIG_RCU_BOOST=n. Thanx, Paul > -Original Message- > From: Paul E. McKenney > Sent: Saturday, December 1, 2018 12:49 AM > To: He, Bo > Cc: Steven Rostedt ; > linux-kernel@vger.kernel.org; j...@joshtriplett.org; > mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Zhang, Jun > ; Xiao, Jin ; Zhang, Yanmin > > Subject: Re: rcu_preempt caused oom > > On Fri, Nov 30, 2018 at 03:18:58PM +, He, Bo wrote: > > Here is the kernel cmdline: > > Thank you! > > > Kernel command line: androidboot.acpio_idx=0 > > androidboot.bootloader=efiwrapper-02_03-userdebug_kernelflinger-06_0 > > 3- userdebug androidboot.diskbus=00.0 > > androidboot.verifiedbootstate=green > > androidboot.bootreason=power-on androidboot.serialno=R1J56L6006a7bb > > g_ffs.iSerialNumber=R1J56L6006a7bb no_timer_check noxsaves > > reboot_panic=p,w i915.hpd_sense_invert=0x7 mem=2G nokaslr nopti > > ftrace_dump_on_oops trace_buf_size=1024K intel_iommu=off gpt > > loglevel=4 androidboot.hardware=gordon_peak > > firmware_class.path=/vendor/firmware relative_sleep_states=1 > > enforcing=0 androidboot.selinux=permissive cpu_init_udelay=10 > > androidboot.android_dt_dir=/sys/bus/platform/devices/ANDR0001:00/pro > > pe rties/android/ pstore.backend=ramoops memmap=0x140$0x5000 > > ramoops.mem_address=0x5000 ramoops.mem_size=0x140 > > ramoops.record_size=0x4000 ramoops.console_size=0x100 > > ramoops.ftrace_size=0x1 ramoops.dump_oops=1 vga=current > > i915.modeset=1 drm.atomic=1 i915.nuclear_pageflip=1 > > drm.vblankoffdelay= > > And no sign of any suppression of RCU CPU stall warnings. Hmmm... > It does take more than 21 seconds to OOM? Or do things happen faster than > that? If they do happen faster than that, then on approach would be to add > something like this to the kernel command line: > > rcupdate.rcu_cpu_stall_timeout=7 > > This would set the stall timeout to seven seconds. Note that timeouts less > than three seconds are silently interpreted as three seconds. > > Thanx, Paul > > > -Original Message- > > From: Steven Rostedt > > Sent: Friday, November 30, 2018 11:17 PM > > To: Paul E. McKenney > > Cc: He, Bo ; linux-kernel@vger.kernel.org; > > j...@joshtriplett.org; mathieu.desnoy...@efficios.com; > > jiangshan...@gmail.com; Zhang, Jun ; Xiao, Jin > > ; Zhang, Yanmin > > Subject: Re: rcu_preempt caused oom > > > > On Fri, 30 Nov 2018 06:43:17 -0800 > > "Paul E. McKenney" wrote: > > > > > Could you please send me your list of kernel boot parameters? > > > They usually appear near the start of your console output. > > > > Or just: cat /proc/cmdline > > > > -- Steve > > > apanic_console Description: apanic_console
RE: rcu_preempt caused oom
Hi, Paul: the enclosed is the log trigger the 120s hung_task_panic without other debug patches, the hung task is blocked at __wait_rcu_gp, it means the rcu_cpu_stall can't detect the scenario: echo 1 > /proc/sys/kernel/panic_on_rcu_stall echo 7 > /sys/module/rcupdate/parameters/rcu_cpu_stall_timeout -Original Message- From: Paul E. McKenney Sent: Monday, December 3, 2018 9:57 PM To: He, Bo Cc: Steven Rostedt ; linux-kernel@vger.kernel.org; j...@joshtriplett.org; mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Zhang, Jun ; Xiao, Jin ; Zhang, Yanmin Subject: Re: rcu_preempt caused oom On Mon, Dec 03, 2018 at 07:44:03AM +0000, He, Bo wrote: > Thanks, we have run the test for the whole weekend and not reproduce the > issue, so we confirm the CONFIG_RCU_BOOST can fix the issue. Very good, that is encouraging. Perhaps I should think about making CONFIG_RCU_BOOST=y the default for CONFIG_PREEMPT in mainline, at least for architectures for which rt_mutexes are implemented. > We have enabled the rcupdate.rcu_cpu_stall_timeout=7 and also set panic on > rcu stall and will see if we can see the panic, will keep you posed with the > test results. > echo 1 > /proc/sys/kernel/panic_on_rcu_stall Looking forward to seeing what is going on! Of course, to reproduce, you will need to again build with CONFIG_RCU_BOOST=n. Thanx, Paul > -Original Message- > From: Paul E. McKenney > Sent: Saturday, December 1, 2018 12:49 AM > To: He, Bo > Cc: Steven Rostedt ; > linux-kernel@vger.kernel.org; j...@joshtriplett.org; > mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Zhang, Jun > ; Xiao, Jin ; Zhang, Yanmin > > Subject: Re: rcu_preempt caused oom > > On Fri, Nov 30, 2018 at 03:18:58PM +, He, Bo wrote: > > Here is the kernel cmdline: > > Thank you! > > > Kernel command line: androidboot.acpio_idx=0 > > androidboot.bootloader=efiwrapper-02_03-userdebug_kernelflinger-06_0 > > 3- userdebug androidboot.diskbus=00.0 > > androidboot.verifiedbootstate=green > > androidboot.bootreason=power-on androidboot.serialno=R1J56L6006a7bb > > g_ffs.iSerialNumber=R1J56L6006a7bb no_timer_check noxsaves > > reboot_panic=p,w i915.hpd_sense_invert=0x7 mem=2G nokaslr nopti > > ftrace_dump_on_oops trace_buf_size=1024K intel_iommu=off gpt > > loglevel=4 androidboot.hardware=gordon_peak > > firmware_class.path=/vendor/firmware relative_sleep_states=1 > > enforcing=0 androidboot.selinux=permissive cpu_init_udelay=10 > > androidboot.android_dt_dir=/sys/bus/platform/devices/ANDR0001:00/pro > > pe rties/android/ pstore.backend=ramoops memmap=0x140$0x5000 > > ramoops.mem_address=0x5000 ramoops.mem_size=0x140 > > ramoops.record_size=0x4000 ramoops.console_size=0x100 > > ramoops.ftrace_size=0x1 ramoops.dump_oops=1 vga=current > > i915.modeset=1 drm.atomic=1 i915.nuclear_pageflip=1 > > drm.vblankoffdelay= > > And no sign of any suppression of RCU CPU stall warnings. Hmmm... > It does take more than 21 seconds to OOM? Or do things happen faster than > that? If they do happen faster than that, then on approach would be to add > something like this to the kernel command line: > > rcupdate.rcu_cpu_stall_timeout=7 > > This would set the stall timeout to seven seconds. Note that timeouts less > than three seconds are silently interpreted as three seconds. > > Thanx, Paul > > > -Original Message- > > From: Steven Rostedt > > Sent: Friday, November 30, 2018 11:17 PM > > To: Paul E. McKenney > > Cc: He, Bo ; linux-kernel@vger.kernel.org; > > j...@joshtriplett.org; mathieu.desnoy...@efficios.com; > > jiangshan...@gmail.com; Zhang, Jun ; Xiao, Jin > > ; Zhang, Yanmin > > Subject: Re: rcu_preempt caused oom > > > > On Fri, 30 Nov 2018 06:43:17 -0800 > > "Paul E. McKenney" wrote: > > > > > Could you please send me your list of kernel boot parameters? > > > They usually appear near the start of your console output. > > > > Or just: cat /proc/cmdline > > > > -- Steve > > > apanic_console Description: apanic_console
RE: rcu_preempt caused oom
Thanks, we have run the test for the whole weekend and not reproduce the issue, so we confirm the CONFIG_RCU_BOOST can fix the issue. We have enabled the rcupdate.rcu_cpu_stall_timeout=7 and also set panic on rcu stall and will see if we can see the panic, will keep you posed with the test results. echo 1 > /proc/sys/kernel/panic_on_rcu_stall -Original Message- From: Paul E. McKenney Sent: Saturday, December 1, 2018 12:49 AM To: He, Bo Cc: Steven Rostedt ; linux-kernel@vger.kernel.org; j...@joshtriplett.org; mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Zhang, Jun ; Xiao, Jin ; Zhang, Yanmin Subject: Re: rcu_preempt caused oom On Fri, Nov 30, 2018 at 03:18:58PM +0000, He, Bo wrote: > Here is the kernel cmdline: Thank you! > Kernel command line: androidboot.acpio_idx=0 > androidboot.bootloader=efiwrapper-02_03-userdebug_kernelflinger-06_03- > userdebug androidboot.diskbus=00.0 androidboot.verifiedbootstate=green > androidboot.bootreason=power-on androidboot.serialno=R1J56L6006a7bb > g_ffs.iSerialNumber=R1J56L6006a7bb no_timer_check noxsaves > reboot_panic=p,w i915.hpd_sense_invert=0x7 mem=2G nokaslr nopti > ftrace_dump_on_oops trace_buf_size=1024K intel_iommu=off gpt > loglevel=4 androidboot.hardware=gordon_peak > firmware_class.path=/vendor/firmware relative_sleep_states=1 > enforcing=0 androidboot.selinux=permissive cpu_init_udelay=10 > androidboot.android_dt_dir=/sys/bus/platform/devices/ANDR0001:00/prope > rties/android/ pstore.backend=ramoops memmap=0x140$0x5000 > ramoops.mem_address=0x5000 ramoops.mem_size=0x140 > ramoops.record_size=0x4000 ramoops.console_size=0x100 > ramoops.ftrace_size=0x1 ramoops.dump_oops=1 vga=current > i915.modeset=1 drm.atomic=1 i915.nuclear_pageflip=1 > drm.vblankoffdelay= And no sign of any suppression of RCU CPU stall warnings. Hmmm... It does take more than 21 seconds to OOM? Or do things happen faster than that? If they do happen faster than that, then on approach would be to add something like this to the kernel command line: rcupdate.rcu_cpu_stall_timeout=7 This would set the stall timeout to seven seconds. Note that timeouts less than three seconds are silently interpreted as three seconds. Thanx, Paul > -Original Message- > From: Steven Rostedt > Sent: Friday, November 30, 2018 11:17 PM > To: Paul E. McKenney > Cc: He, Bo ; linux-kernel@vger.kernel.org; > j...@joshtriplett.org; mathieu.desnoy...@efficios.com; > jiangshan...@gmail.com; Zhang, Jun ; Xiao, Jin > ; Zhang, Yanmin > Subject: Re: rcu_preempt caused oom > > On Fri, 30 Nov 2018 06:43:17 -0800 > "Paul E. McKenney" wrote: > > > Could you please send me your list of kernel boot parameters? They > > usually appear near the start of your console output. > > Or just: cat /proc/cmdline > > -- Steve >
RE: rcu_preempt caused oom
Thanks, we have run the test for the whole weekend and not reproduce the issue, so we confirm the CONFIG_RCU_BOOST can fix the issue. We have enabled the rcupdate.rcu_cpu_stall_timeout=7 and also set panic on rcu stall and will see if we can see the panic, will keep you posed with the test results. echo 1 > /proc/sys/kernel/panic_on_rcu_stall -Original Message- From: Paul E. McKenney Sent: Saturday, December 1, 2018 12:49 AM To: He, Bo Cc: Steven Rostedt ; linux-kernel@vger.kernel.org; j...@joshtriplett.org; mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Zhang, Jun ; Xiao, Jin ; Zhang, Yanmin Subject: Re: rcu_preempt caused oom On Fri, Nov 30, 2018 at 03:18:58PM +0000, He, Bo wrote: > Here is the kernel cmdline: Thank you! > Kernel command line: androidboot.acpio_idx=0 > androidboot.bootloader=efiwrapper-02_03-userdebug_kernelflinger-06_03- > userdebug androidboot.diskbus=00.0 androidboot.verifiedbootstate=green > androidboot.bootreason=power-on androidboot.serialno=R1J56L6006a7bb > g_ffs.iSerialNumber=R1J56L6006a7bb no_timer_check noxsaves > reboot_panic=p,w i915.hpd_sense_invert=0x7 mem=2G nokaslr nopti > ftrace_dump_on_oops trace_buf_size=1024K intel_iommu=off gpt > loglevel=4 androidboot.hardware=gordon_peak > firmware_class.path=/vendor/firmware relative_sleep_states=1 > enforcing=0 androidboot.selinux=permissive cpu_init_udelay=10 > androidboot.android_dt_dir=/sys/bus/platform/devices/ANDR0001:00/prope > rties/android/ pstore.backend=ramoops memmap=0x140$0x5000 > ramoops.mem_address=0x5000 ramoops.mem_size=0x140 > ramoops.record_size=0x4000 ramoops.console_size=0x100 > ramoops.ftrace_size=0x1 ramoops.dump_oops=1 vga=current > i915.modeset=1 drm.atomic=1 i915.nuclear_pageflip=1 > drm.vblankoffdelay= And no sign of any suppression of RCU CPU stall warnings. Hmmm... It does take more than 21 seconds to OOM? Or do things happen faster than that? If they do happen faster than that, then on approach would be to add something like this to the kernel command line: rcupdate.rcu_cpu_stall_timeout=7 This would set the stall timeout to seven seconds. Note that timeouts less than three seconds are silently interpreted as three seconds. Thanx, Paul > -Original Message- > From: Steven Rostedt > Sent: Friday, November 30, 2018 11:17 PM > To: Paul E. McKenney > Cc: He, Bo ; linux-kernel@vger.kernel.org; > j...@joshtriplett.org; mathieu.desnoy...@efficios.com; > jiangshan...@gmail.com; Zhang, Jun ; Xiao, Jin > ; Zhang, Yanmin > Subject: Re: rcu_preempt caused oom > > On Fri, 30 Nov 2018 06:43:17 -0800 > "Paul E. McKenney" wrote: > > > Could you please send me your list of kernel boot parameters? They > > usually appear near the start of your console output. > > Or just: cat /proc/cmdline > > -- Steve >
RE: rcu_preempt caused oom
Here is the kernel cmdline: Kernel command line: androidboot.acpio_idx=0 androidboot.bootloader=efiwrapper-02_03-userdebug_kernelflinger-06_03-userdebug androidboot.diskbus=00.0 androidboot.verifiedbootstate=green androidboot.bootreason=power-on androidboot.serialno=R1J56L6006a7bb g_ffs.iSerialNumber=R1J56L6006a7bb no_timer_check noxsaves reboot_panic=p,w i915.hpd_sense_invert=0x7 mem=2G nokaslr nopti ftrace_dump_on_oops trace_buf_size=1024K intel_iommu=off gpt loglevel=4 androidboot.hardware=gordon_peak firmware_class.path=/vendor/firmware relative_sleep_states=1 enforcing=0 androidboot.selinux=permissive cpu_init_udelay=10 androidboot.android_dt_dir=/sys/bus/platform/devices/ANDR0001:00/properties/android/ pstore.backend=ramoops memmap=0x140$0x5000 ramoops.mem_address=0x5000 ramoops.mem_size=0x140 ramoops.record_size=0x4000 ramoops.console_size=0x100 ramoops.ftrace_size=0x1 ramoops.dump_oops=1 vga=current i915.modeset=1 drm.atomic=1 i915.nuclear_pageflip=1 drm.vblankoffdelay= -Original Message- From: Steven Rostedt Sent: Friday, November 30, 2018 11:17 PM To: Paul E. McKenney Cc: He, Bo ; linux-kernel@vger.kernel.org; j...@joshtriplett.org; mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Zhang, Jun ; Xiao, Jin ; Zhang, Yanmin Subject: Re: rcu_preempt caused oom On Fri, 30 Nov 2018 06:43:17 -0800 "Paul E. McKenney" wrote: > Could you please send me your list of kernel boot parameters? They > usually appear near the start of your console output. Or just: cat /proc/cmdline -- Steve
RE: rcu_preempt caused oom
Here is the kernel cmdline: Kernel command line: androidboot.acpio_idx=0 androidboot.bootloader=efiwrapper-02_03-userdebug_kernelflinger-06_03-userdebug androidboot.diskbus=00.0 androidboot.verifiedbootstate=green androidboot.bootreason=power-on androidboot.serialno=R1J56L6006a7bb g_ffs.iSerialNumber=R1J56L6006a7bb no_timer_check noxsaves reboot_panic=p,w i915.hpd_sense_invert=0x7 mem=2G nokaslr nopti ftrace_dump_on_oops trace_buf_size=1024K intel_iommu=off gpt loglevel=4 androidboot.hardware=gordon_peak firmware_class.path=/vendor/firmware relative_sleep_states=1 enforcing=0 androidboot.selinux=permissive cpu_init_udelay=10 androidboot.android_dt_dir=/sys/bus/platform/devices/ANDR0001:00/properties/android/ pstore.backend=ramoops memmap=0x140$0x5000 ramoops.mem_address=0x5000 ramoops.mem_size=0x140 ramoops.record_size=0x4000 ramoops.console_size=0x100 ramoops.ftrace_size=0x1 ramoops.dump_oops=1 vga=current i915.modeset=1 drm.atomic=1 i915.nuclear_pageflip=1 drm.vblankoffdelay= -Original Message- From: Steven Rostedt Sent: Friday, November 30, 2018 11:17 PM To: Paul E. McKenney Cc: He, Bo ; linux-kernel@vger.kernel.org; j...@joshtriplett.org; mathieu.desnoy...@efficios.com; jiangshan...@gmail.com; Zhang, Jun ; Xiao, Jin ; Zhang, Yanmin Subject: Re: rcu_preempt caused oom On Fri, 30 Nov 2018 06:43:17 -0800 "Paul E. McKenney" wrote: > Could you please send me your list of kernel boot parameters? They > usually appear near the start of your console output. Or just: cat /proc/cmdline -- Steve
rcu_preempt caused oom
Hi, we test on kernel 4.19.0 on android, after run more than 24 Hours monkey stress test, we see OOM on 1/10 2G memory board, the issue is not seen on the 4.14 kernel. we have done some debugs: 1. OOM is due to the filp consume too many memory: 300M vs 2G board. 2. with the 120s hung task detect, most of the tasks will block at __wait_rcu_gp: wait_for_completion(_array[i].completion); [47571.863839] Kernel panic - not syncing: hung_task: blocked tasks [47571.875446] CPU: 1 PID: 13626 Comm: FinalizerDaemon Tainted: G U O 4.19.0-quilt-2e5dc0ac-gf3f313245eb6 #1 [47571.887603] Call Trace: [47571.890547] dump_stack+0x70/0xa5 [47571.894456] panic+0xe3/0x241 [47571.897977] ? wait_for_completion_timeout+0x72/0x1b0 [47571.903830] __wait_rcu_gp+0x17b/0x180 [47571.908226] synchronize_rcu.part.76+0x38/0x50 [47571.913393] ? __call_rcu.constprop.79+0x3a0/0x3a0 [47571.918948] ? __bpf_trace_rcu_invoke_callback+0x10/0x10 [47571.925094] synchronize_rcu+0x43/0x50 [47571.929487] evdev_detach_client+0x59/0x60 [47571.934264] evdev_release+0x4e/0xd0 [47571.938464] __fput+0xfa/0x1f0 [47571.942072] fput+0xe/0x10 [47571.945683] task_work_run+0x90/0xc0 [47571.949884] exit_to_usermode_loop+0x9f/0xb0 [47571.954855] do_syscall_64+0xfa/0x110 [47571.959151] entry_SYSCALL_64_after_hwframe+0x49/0xbe 3. after enable the rcu trace, we don't see rcu_quiescent_state_report trace in a long time, we see rcu_callback: rcu_preempt will never response with the rcu_invoke_callback. [47572.040668] ps-12388 1d..1 47566097572us : rcu_grace_period: rcu_preempt 23716088 AccWaitCB [47572.040707] ps-12388 1d... 47566097621us : rcu_callback: rcu_preempt rhp=783a728b func=file_free_rcu 4354/82824 [47572.040734] ps-12388 1d..1 47566097622us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Startleaf [47572.040756] ps-12388 1d..1 47566097623us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Prestarted [47572.040778] ps-12388 1d..1 47566097623us : rcu_grace_period: rcu_preempt 23716088 AccWaitCB [47572.040802] ps-12388 1d... 47566097674us : rcu_callback: rcu_preempt rhp=42c76521 func=file_free_rcu 4354/82825 [47572.040824] ps-12388 1d..1 47566097676us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Startleaf [47572.040847] ps-12388 1d..1 47566097676us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Prestarted [47572.040868] ps-12388 1d..1 47566097676us : rcu_grace_period: rcu_preempt 23716088 AccWaitCB [47572.040895] ps-12388 1d..1 47566097716us : rcu_callback: rcu_preempt rhp=5e40fde2 func=avc_node_free 4354/82826 [47572.040919] ps-12388 1d..1 47566097735us : rcu_callback: rcu_preempt rhp=f80fe353 func=avc_node_free 4354/82827 [47572.040943] ps-12388 1d..1 47566097758us : rcu_callback: rcu_preempt rhp=7486f400 func=avc_node_free 4354/82828 [47572.040967] ps-12388 1d..1 47566097760us : rcu_callback: rcu_preempt rhp=b87872a8 func=avc_node_free 4354/82829 [47572.040990] ps-12388 1d... 47566097789us : rcu_callback: rcu_preempt rhp=8c656343 func=file_free_rcu 4354/82830 [47572.041013] ps-12388 1d..1 47566097790us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Startleaf [47572.041036] ps-12388 1d..1 47566097790us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Prestarted [47572.041057] ps-12388 1d..1 47566097791us : rcu_grace_period: rcu_preempt 23716088 AccWaitCB [47572.041081] ps-12388 1d... 47566097871us : rcu_callback: rcu_preempt rhp=7e6c898c func=file_free_rcu 4354/82831 [47572.041103] ps-12388 1d..1 47566097872us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Startleaf [47572.041126] ps-12388 1d..1 47566097872us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Prestarted [47572.041147] ps-12388 1d..1 47566097873us : rcu_grace_period: rcu_preempt 23716088 AccWaitCB [47572.041170] ps-12388 1d... 47566097945us : rcu_callback: rcu_preempt rhp=32f4f174 func=file_free_rcu 4354/82832 [47572.041193] ps-12388 1d..1 47566097946us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Startleaf Do you have any suggestions to debug the issue?
rcu_preempt caused oom
Hi, we test on kernel 4.19.0 on android, after run more than 24 Hours monkey stress test, we see OOM on 1/10 2G memory board, the issue is not seen on the 4.14 kernel. we have done some debugs: 1. OOM is due to the filp consume too many memory: 300M vs 2G board. 2. with the 120s hung task detect, most of the tasks will block at __wait_rcu_gp: wait_for_completion(_array[i].completion); [47571.863839] Kernel panic - not syncing: hung_task: blocked tasks [47571.875446] CPU: 1 PID: 13626 Comm: FinalizerDaemon Tainted: G U O 4.19.0-quilt-2e5dc0ac-gf3f313245eb6 #1 [47571.887603] Call Trace: [47571.890547] dump_stack+0x70/0xa5 [47571.894456] panic+0xe3/0x241 [47571.897977] ? wait_for_completion_timeout+0x72/0x1b0 [47571.903830] __wait_rcu_gp+0x17b/0x180 [47571.908226] synchronize_rcu.part.76+0x38/0x50 [47571.913393] ? __call_rcu.constprop.79+0x3a0/0x3a0 [47571.918948] ? __bpf_trace_rcu_invoke_callback+0x10/0x10 [47571.925094] synchronize_rcu+0x43/0x50 [47571.929487] evdev_detach_client+0x59/0x60 [47571.934264] evdev_release+0x4e/0xd0 [47571.938464] __fput+0xfa/0x1f0 [47571.942072] fput+0xe/0x10 [47571.945683] task_work_run+0x90/0xc0 [47571.949884] exit_to_usermode_loop+0x9f/0xb0 [47571.954855] do_syscall_64+0xfa/0x110 [47571.959151] entry_SYSCALL_64_after_hwframe+0x49/0xbe 3. after enable the rcu trace, we don't see rcu_quiescent_state_report trace in a long time, we see rcu_callback: rcu_preempt will never response with the rcu_invoke_callback. [47572.040668] ps-12388 1d..1 47566097572us : rcu_grace_period: rcu_preempt 23716088 AccWaitCB [47572.040707] ps-12388 1d... 47566097621us : rcu_callback: rcu_preempt rhp=783a728b func=file_free_rcu 4354/82824 [47572.040734] ps-12388 1d..1 47566097622us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Startleaf [47572.040756] ps-12388 1d..1 47566097623us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Prestarted [47572.040778] ps-12388 1d..1 47566097623us : rcu_grace_period: rcu_preempt 23716088 AccWaitCB [47572.040802] ps-12388 1d... 47566097674us : rcu_callback: rcu_preempt rhp=42c76521 func=file_free_rcu 4354/82825 [47572.040824] ps-12388 1d..1 47566097676us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Startleaf [47572.040847] ps-12388 1d..1 47566097676us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Prestarted [47572.040868] ps-12388 1d..1 47566097676us : rcu_grace_period: rcu_preempt 23716088 AccWaitCB [47572.040895] ps-12388 1d..1 47566097716us : rcu_callback: rcu_preempt rhp=5e40fde2 func=avc_node_free 4354/82826 [47572.040919] ps-12388 1d..1 47566097735us : rcu_callback: rcu_preempt rhp=f80fe353 func=avc_node_free 4354/82827 [47572.040943] ps-12388 1d..1 47566097758us : rcu_callback: rcu_preempt rhp=7486f400 func=avc_node_free 4354/82828 [47572.040967] ps-12388 1d..1 47566097760us : rcu_callback: rcu_preempt rhp=b87872a8 func=avc_node_free 4354/82829 [47572.040990] ps-12388 1d... 47566097789us : rcu_callback: rcu_preempt rhp=8c656343 func=file_free_rcu 4354/82830 [47572.041013] ps-12388 1d..1 47566097790us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Startleaf [47572.041036] ps-12388 1d..1 47566097790us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Prestarted [47572.041057] ps-12388 1d..1 47566097791us : rcu_grace_period: rcu_preempt 23716088 AccWaitCB [47572.041081] ps-12388 1d... 47566097871us : rcu_callback: rcu_preempt rhp=7e6c898c func=file_free_rcu 4354/82831 [47572.041103] ps-12388 1d..1 47566097872us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Startleaf [47572.041126] ps-12388 1d..1 47566097872us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Prestarted [47572.041147] ps-12388 1d..1 47566097873us : rcu_grace_period: rcu_preempt 23716088 AccWaitCB [47572.041170] ps-12388 1d... 47566097945us : rcu_callback: rcu_preempt rhp=32f4f174 func=file_free_rcu 4354/82832 [47572.041193] ps-12388 1d..1 47566097946us : rcu_future_grace_period: rcu_preempt 23716088 23716092 0 0 3 Startleaf Do you have any suggestions to debug the issue?
RE: [alsa-devel] [PATCH] fix the kernel panic due to wrong use the dev memory API
Hi,
I submit the patch based on tag v4.19.
-Original Message-
From: Pierre-Louis Bossart
Sent: Tuesday, November 6, 2018 1:02 AM
To: He, Bo ; alsa-de...@alsa-project.org;
linux-kernel@vger.kernel.org
Cc: liam.r.girdw...@linux.intel.com; pe...@perex.cz; ti...@suse.com; Singh,
Guneshwor O ; Periyasamy, SriramX
; Kale, Sanyog R ;
Kesapragada, Pardha Saradhi ;
kuninori.morimoto...@renesas.com; guruprasadx.pa...@intel.com; Ughreja, Rakesh
A ; Prakash, Divya1 ;
Diwakar, Praveen ; Zhang, Yanmin
Subject: Re: [alsa-devel] [PATCH] fix the kernel panic due to wrong use the dev
memory API
On 11/5/18 2:29 AM, He, Bo wrote:
> skl->dais is allocated with devm_kcalloc, can't free with
> the krealloc. Memory allocated with devm API is automatically freed on
> driver detach, Like all other devres resources.
>
> Refer to drivers/base/devres.c devm_kmalloc for more details.
What code are you looking at?
I see this in the Mark's tree
int skl_platform_register(struct device *dev) {
int ret;
struct snd_soc_dai_driver *dais;
int num_dais = ARRAY_SIZE(skl_platform_dai);
struct hdac_bus *bus = dev_get_drvdata(dev);
struct skl *skl = bus_to_skl(bus);
INIT_LIST_HEAD(>ppl_list);
INIT_LIST_HEAD(>bind_list);
skl->dais = kmemdup(skl_platform_dai, sizeof(skl_platform_dai),
GFP_KERNEL);
if (!skl->dais) {
ret = -ENOMEM;
goto err;
}
if (!skl->use_tplg_pcm) {
dais = krealloc(skl->dais, sizeof(skl_fe_dai) +
sizeof(skl_platform_dai), GFP_KERNEL);
No trace of devm as you mention it? I checked the Chrome tree as well and it's
not there.
What am I missing?
>
> Signed-off-by: he, bo
> ---
> sound/soc/intel/skylake/skl-pcm.c | 5 ++---
> 1 file changed, 2 insertions(+), 3 deletions(-)
>
> diff --git a/sound/soc/intel/skylake/skl-pcm.c
> b/sound/soc/intel/skylake/skl-pcm.c
> index 823e391..928d314 100644
> --- a/sound/soc/intel/skylake/skl-pcm.c
> +++ b/sound/soc/intel/skylake/skl-pcm.c
> @@ -1438,7 +1438,8 @@ int skl_platform_register(struct device *dev)
> }
>
> if (!skl->use_tplg_pcm) {
> - dais = krealloc(skl->dais, sizeof(skl_fe_dai) +
> + devm_kfree(dev, skl->dais);
> + dais = devm_kcalloc(dev, skl->dais, sizeof(skl_fe_dai) +
> sizeof(skl_platform_dai), GFP_KERNEL);
> if (!dais) {
> ret = -ENOMEM;
> @@ -1472,7 +1473,5 @@ int skl_platform_unregister(struct device *dev)
> }
> }
>
> - kfree(skl->dais);
> -
> return 0;
> }
RE: [alsa-devel] [PATCH] fix the kernel panic due to wrong use the dev memory API
Hi,
I submit the patch based on tag v4.19.
-Original Message-
From: Pierre-Louis Bossart
Sent: Tuesday, November 6, 2018 1:02 AM
To: He, Bo ; alsa-de...@alsa-project.org;
linux-kernel@vger.kernel.org
Cc: liam.r.girdw...@linux.intel.com; pe...@perex.cz; ti...@suse.com; Singh,
Guneshwor O ; Periyasamy, SriramX
; Kale, Sanyog R ;
Kesapragada, Pardha Saradhi ;
kuninori.morimoto...@renesas.com; guruprasadx.pa...@intel.com; Ughreja, Rakesh
A ; Prakash, Divya1 ;
Diwakar, Praveen ; Zhang, Yanmin
Subject: Re: [alsa-devel] [PATCH] fix the kernel panic due to wrong use the dev
memory API
On 11/5/18 2:29 AM, He, Bo wrote:
> skl->dais is allocated with devm_kcalloc, can't free with
> the krealloc. Memory allocated with devm API is automatically freed on
> driver detach, Like all other devres resources.
>
> Refer to drivers/base/devres.c devm_kmalloc for more details.
What code are you looking at?
I see this in the Mark's tree
int skl_platform_register(struct device *dev) {
int ret;
struct snd_soc_dai_driver *dais;
int num_dais = ARRAY_SIZE(skl_platform_dai);
struct hdac_bus *bus = dev_get_drvdata(dev);
struct skl *skl = bus_to_skl(bus);
INIT_LIST_HEAD(>ppl_list);
INIT_LIST_HEAD(>bind_list);
skl->dais = kmemdup(skl_platform_dai, sizeof(skl_platform_dai),
GFP_KERNEL);
if (!skl->dais) {
ret = -ENOMEM;
goto err;
}
if (!skl->use_tplg_pcm) {
dais = krealloc(skl->dais, sizeof(skl_fe_dai) +
sizeof(skl_platform_dai), GFP_KERNEL);
No trace of devm as you mention it? I checked the Chrome tree as well and it's
not there.
What am I missing?
>
> Signed-off-by: he, bo
> ---
> sound/soc/intel/skylake/skl-pcm.c | 5 ++---
> 1 file changed, 2 insertions(+), 3 deletions(-)
>
> diff --git a/sound/soc/intel/skylake/skl-pcm.c
> b/sound/soc/intel/skylake/skl-pcm.c
> index 823e391..928d314 100644
> --- a/sound/soc/intel/skylake/skl-pcm.c
> +++ b/sound/soc/intel/skylake/skl-pcm.c
> @@ -1438,7 +1438,8 @@ int skl_platform_register(struct device *dev)
> }
>
> if (!skl->use_tplg_pcm) {
> - dais = krealloc(skl->dais, sizeof(skl_fe_dai) +
> + devm_kfree(dev, skl->dais);
> + dais = devm_kcalloc(dev, skl->dais, sizeof(skl_fe_dai) +
> sizeof(skl_platform_dai), GFP_KERNEL);
> if (!dais) {
> ret = -ENOMEM;
> @@ -1472,7 +1473,5 @@ int skl_platform_unregister(struct device *dev)
> }
> }
>
> - kfree(skl->dais);
> -
> return 0;
> }
[PATCH] fix the kernel panic due to wrong use the dev memory API
skl->dais is allocated with devm_kcalloc, can't free with
the krealloc. Memory allocated with devm API is automatically freed
on driver detach, Like all other devres resources.
Refer to drivers/base/devres.c devm_kmalloc for more details.
Signed-off-by: he, bo
---
sound/soc/intel/skylake/skl-pcm.c | 5 ++---
1 file changed, 2 insertions(+), 3 deletions(-)
diff --git a/sound/soc/intel/skylake/skl-pcm.c
b/sound/soc/intel/skylake/skl-pcm.c
index 823e391..928d314 100644
--- a/sound/soc/intel/skylake/skl-pcm.c
+++ b/sound/soc/intel/skylake/skl-pcm.c
@@ -1438,7 +1438,8 @@ int skl_platform_register(struct device *dev)
}
if (!skl->use_tplg_pcm) {
- dais = krealloc(skl->dais, sizeof(skl_fe_dai) +
+ devm_kfree(dev, skl->dais);
+ dais = devm_kcalloc(dev, skl->dais, sizeof(skl_fe_dai) +
sizeof(skl_platform_dai), GFP_KERNEL);
if (!dais) {
ret = -ENOMEM;
@@ -1472,7 +1473,5 @@ int skl_platform_unregister(struct device *dev)
}
}
- kfree(skl->dais);
-
return 0;
}
--
2.7.4
[PATCH] fix the kernel panic due to wrong use the dev memory API
skl->dais is allocated with devm_kcalloc, can't free with
the krealloc. Memory allocated with devm API is automatically freed
on driver detach, Like all other devres resources.
Refer to drivers/base/devres.c devm_kmalloc for more details.
Signed-off-by: he, bo
---
sound/soc/intel/skylake/skl-pcm.c | 5 ++---
1 file changed, 2 insertions(+), 3 deletions(-)
diff --git a/sound/soc/intel/skylake/skl-pcm.c
b/sound/soc/intel/skylake/skl-pcm.c
index 823e391..928d314 100644
--- a/sound/soc/intel/skylake/skl-pcm.c
+++ b/sound/soc/intel/skylake/skl-pcm.c
@@ -1438,7 +1438,8 @@ int skl_platform_register(struct device *dev)
}
if (!skl->use_tplg_pcm) {
- dais = krealloc(skl->dais, sizeof(skl_fe_dai) +
+ devm_kfree(dev, skl->dais);
+ dais = devm_kcalloc(dev, skl->dais, sizeof(skl_fe_dai) +
sizeof(skl_platform_dai), GFP_KERNEL);
if (!dais) {
ret = -ENOMEM;
@@ -1472,7 +1473,5 @@ int skl_platform_unregister(struct device *dev)
}
}
- kfree(skl->dais);
-
return 0;
}
--
2.7.4
RE: [PATCH] ALSA: core: fix unsigned int pages overflow when comapred
Hi, Takashi:
we tested for the whole weekend, your patch works, no panic issue seen.
You can safe merge you patch.
-Original Message-
From: Takashi Iwai
Sent: Thursday, July 19, 2018 5:11 PM
To: Zhang, Jun
Cc: He, Bo ; alsa-de...@alsa-project.org; pe...@perex.cz;
linux-kernel@vger.kernel.org; Zhang, Yanmin
Subject: Re: [PATCH] ALSA: core: fix unsigned int pages overflow when comapred
On Thu, 19 Jul 2018 08:42:14 +0200,
Takashi Iwai wrote:
>
> On Thu, 19 Jul 2018 08:08:06 +0200,
> Zhang, Jun wrote:
> >
> > Hello, Takashi
> >
> > I think use our patch, it's NOT possible that the returned size is over
> > sgbuf->tblsize.
> >
> > In function snd_malloc_sgbuf_pages,
> >
> > Pages is align page,
> > sgbuf->tblsize is align 32*page,
> > chunk is align 2^n*page,
> >
> > in our panic case, pages = 123, tlbsize = 128, 1st loop trunk = 32
> > 2nd loop trunk = 32 3rd loop trunk = 32 4th loop trunk = 16 5th loop
> > trunk = 16 So in 5th loop pages-trunk = -5, which make dead loop.
>
> Looking at the code again, yeah, you are right, that won't happen.
>
> And now it becomes clear: the fundamental problem is that
> snd_dma_alloc_pages_fallback() returns a larger size than requested.
> It would be acceptable if the internal allocator aligns a larger size,
> but it shouldn't appear in the returned size outside. I believe this
> was just a misunderstanding of get_order() usage there.
> (BTW, it's interesting that the allocation with a larger block worked
> while allocation with a smaller chunk failed; it must be a rare case
> and that's one of reasons this bug didn't hit frequently.)
>
> That being said, what we should fix is rather the function
> snd_dma_alloc_pages_fallback() to behave as expected, and it'll be
> like the patch below.
And we can reduce even more lines. A proper patch is below.
thanks,
Takashi
-- 8< --
From: Takashi Iwai
Subject: [PATCH] ALSA: memalloc: Don't exceed over the requested size
snd_dma_alloc_pages_fallback() tries to allocate pages again when the
allocation fails with reduced size. But the first try actually
*increases* the size to power-of-two, which may give back a larger chunk than
the requested size. This confuses the callers, e.g. sgbuf assumes that the
size is equal or less, and it may result in a bad loop due to the underflow and
eventually lead to Oops.
The code of this function seems incorrectly assuming the usage of get_order().
We need to decrease at first, then align to power-of-two.
Reported-by: he, bo
Reported-by: zhang jun
Cc:
Signed-off-by: Takashi Iwai
---
sound/core/memalloc.c | 8 ++--
1 file changed, 2 insertions(+), 6 deletions(-)
diff --git a/sound/core/memalloc.c b/sound/core/memalloc.c index
7f89d3c79a4b..753d5fc4b284 100644
--- a/sound/core/memalloc.c
+++ b/sound/core/memalloc.c
@@ -242,16 +242,12 @@ int snd_dma_alloc_pages_fallback(int type, struct device
*device, size_t size,
int err;
while ((err = snd_dma_alloc_pages(type, device, size, dmab)) < 0) {
- size_t aligned_size;
if (err != -ENOMEM)
return err;
if (size <= PAGE_SIZE)
return -ENOMEM;
- aligned_size = PAGE_SIZE << get_order(size);
- if (size != aligned_size)
- size = aligned_size;
- else
- size >>= 1;
+ size >>= 1;
+ size = PAGE_SIZE << get_order(size);
}
if (! dmab->area)
return -ENOMEM;
--
2.18.0
RE: [PATCH] ALSA: core: fix unsigned int pages overflow when comapred
Hi, Takashi:
we tested for the whole weekend, your patch works, no panic issue seen.
You can safe merge you patch.
-Original Message-
From: Takashi Iwai
Sent: Thursday, July 19, 2018 5:11 PM
To: Zhang, Jun
Cc: He, Bo ; alsa-de...@alsa-project.org; pe...@perex.cz;
linux-kernel@vger.kernel.org; Zhang, Yanmin
Subject: Re: [PATCH] ALSA: core: fix unsigned int pages overflow when comapred
On Thu, 19 Jul 2018 08:42:14 +0200,
Takashi Iwai wrote:
>
> On Thu, 19 Jul 2018 08:08:06 +0200,
> Zhang, Jun wrote:
> >
> > Hello, Takashi
> >
> > I think use our patch, it's NOT possible that the returned size is over
> > sgbuf->tblsize.
> >
> > In function snd_malloc_sgbuf_pages,
> >
> > Pages is align page,
> > sgbuf->tblsize is align 32*page,
> > chunk is align 2^n*page,
> >
> > in our panic case, pages = 123, tlbsize = 128, 1st loop trunk = 32
> > 2nd loop trunk = 32 3rd loop trunk = 32 4th loop trunk = 16 5th loop
> > trunk = 16 So in 5th loop pages-trunk = -5, which make dead loop.
>
> Looking at the code again, yeah, you are right, that won't happen.
>
> And now it becomes clear: the fundamental problem is that
> snd_dma_alloc_pages_fallback() returns a larger size than requested.
> It would be acceptable if the internal allocator aligns a larger size,
> but it shouldn't appear in the returned size outside. I believe this
> was just a misunderstanding of get_order() usage there.
> (BTW, it's interesting that the allocation with a larger block worked
> while allocation with a smaller chunk failed; it must be a rare case
> and that's one of reasons this bug didn't hit frequently.)
>
> That being said, what we should fix is rather the function
> snd_dma_alloc_pages_fallback() to behave as expected, and it'll be
> like the patch below.
And we can reduce even more lines. A proper patch is below.
thanks,
Takashi
-- 8< --
From: Takashi Iwai
Subject: [PATCH] ALSA: memalloc: Don't exceed over the requested size
snd_dma_alloc_pages_fallback() tries to allocate pages again when the
allocation fails with reduced size. But the first try actually
*increases* the size to power-of-two, which may give back a larger chunk than
the requested size. This confuses the callers, e.g. sgbuf assumes that the
size is equal or less, and it may result in a bad loop due to the underflow and
eventually lead to Oops.
The code of this function seems incorrectly assuming the usage of get_order().
We need to decrease at first, then align to power-of-two.
Reported-by: he, bo
Reported-by: zhang jun
Cc:
Signed-off-by: Takashi Iwai
---
sound/core/memalloc.c | 8 ++--
1 file changed, 2 insertions(+), 6 deletions(-)
diff --git a/sound/core/memalloc.c b/sound/core/memalloc.c index
7f89d3c79a4b..753d5fc4b284 100644
--- a/sound/core/memalloc.c
+++ b/sound/core/memalloc.c
@@ -242,16 +242,12 @@ int snd_dma_alloc_pages_fallback(int type, struct device
*device, size_t size,
int err;
while ((err = snd_dma_alloc_pages(type, device, size, dmab)) < 0) {
- size_t aligned_size;
if (err != -ENOMEM)
return err;
if (size <= PAGE_SIZE)
return -ENOMEM;
- aligned_size = PAGE_SIZE << get_order(size);
- if (size != aligned_size)
- size = aligned_size;
- else
- size >>= 1;
+ size >>= 1;
+ size = PAGE_SIZE << get_order(size);
}
if (! dmab->area)
return -ENOMEM;
--
2.18.0
RE: [PATCH] ALSA: core: fix unsigned int pages overflow when comapred
Thanks, we will run the test with your patch, will update the test results in
24 Hours.
Current status is:
We can reproduce the issue in 3000 cycles stress S/R test, we can't reproduce
the kernel panic with our patch in 6000 cycles.
-Original Message-
From: Takashi Iwai
Sent: Wednesday, July 18, 2018 8:34 PM
To: He, Bo
Cc: alsa-de...@alsa-project.org; pe...@perex.cz; linux-kernel@vger.kernel.org;
Zhang, Jun ; Zhang, Yanmin
Subject: Re: [PATCH] ALSA: core: fix unsigned int pages overflow when comapred
On Wed, 18 Jul 2018 13:52:45 +0200,
He, Bo wrote:
>
> we see the below kernel panic on stress suspend resume test in
> snd_malloc_sgbuf_pages(), snd_dma_alloc_pages_fallback() alloc chunk
> maybe larger than the left pages due to the pages alignment, which
> will cause the pages overflow.
>
> while (pages > 0) {
> ...
> pages -= chunk;
> }
>
> the patch is change the pages from unsigned int to int to fix the issue.
Thanks for the patch.
Although the analysis is correct, the fix doesn't look ideal. It's also
possible that the returned size may over sgbuf->tblsize if we are more unlucky.
A change like below should work instead. Could you give it a try?
Takashi
-- 8< --
--- a/sound/core/sgbuf.c
+++ b/sound/core/sgbuf.c
@@ -108,7 +108,7 @@ void *snd_malloc_sgbuf_pages(struct device *device,
break;
}
chunk = tmpb.bytes >> PAGE_SHIFT;
- for (i = 0; i < chunk; i++) {
+ for (i = 0; i < chunk && pages > 0; i++) {
table->buf = tmpb.area;
table->addr = tmpb.addr;
if (!i)
@@ -117,9 +117,9 @@ void *snd_malloc_sgbuf_pages(struct device *device,
*pgtable++ = virt_to_page(tmpb.area);
tmpb.area += PAGE_SIZE;
tmpb.addr += PAGE_SIZE;
+ sgbuf->pages++;
+ pages--;
}
- sgbuf->pages += chunk;
- pages -= chunk;
if (chunk < maxpages)
maxpages = chunk;
}
RE: [PATCH] ALSA: core: fix unsigned int pages overflow when comapred
Thanks, we will run the test with your patch, will update the test results in
24 Hours.
Current status is:
We can reproduce the issue in 3000 cycles stress S/R test, we can't reproduce
the kernel panic with our patch in 6000 cycles.
-Original Message-
From: Takashi Iwai
Sent: Wednesday, July 18, 2018 8:34 PM
To: He, Bo
Cc: alsa-de...@alsa-project.org; pe...@perex.cz; linux-kernel@vger.kernel.org;
Zhang, Jun ; Zhang, Yanmin
Subject: Re: [PATCH] ALSA: core: fix unsigned int pages overflow when comapred
On Wed, 18 Jul 2018 13:52:45 +0200,
He, Bo wrote:
>
> we see the below kernel panic on stress suspend resume test in
> snd_malloc_sgbuf_pages(), snd_dma_alloc_pages_fallback() alloc chunk
> maybe larger than the left pages due to the pages alignment, which
> will cause the pages overflow.
>
> while (pages > 0) {
> ...
> pages -= chunk;
> }
>
> the patch is change the pages from unsigned int to int to fix the issue.
Thanks for the patch.
Although the analysis is correct, the fix doesn't look ideal. It's also
possible that the returned size may over sgbuf->tblsize if we are more unlucky.
A change like below should work instead. Could you give it a try?
Takashi
-- 8< --
--- a/sound/core/sgbuf.c
+++ b/sound/core/sgbuf.c
@@ -108,7 +108,7 @@ void *snd_malloc_sgbuf_pages(struct device *device,
break;
}
chunk = tmpb.bytes >> PAGE_SHIFT;
- for (i = 0; i < chunk; i++) {
+ for (i = 0; i < chunk && pages > 0; i++) {
table->buf = tmpb.area;
table->addr = tmpb.addr;
if (!i)
@@ -117,9 +117,9 @@ void *snd_malloc_sgbuf_pages(struct device *device,
*pgtable++ = virt_to_page(tmpb.area);
tmpb.area += PAGE_SIZE;
tmpb.addr += PAGE_SIZE;
+ sgbuf->pages++;
+ pages--;
}
- sgbuf->pages += chunk;
- pages -= chunk;
if (chunk < maxpages)
maxpages = chunk;
}
[PATCH] ALSA: core: fix unsigned int pages overflow when comapred
we see the below kernel panic on stress suspend resume test in
snd_malloc_sgbuf_pages(), snd_dma_alloc_pages_fallback() alloc
chunk maybe larger than the left pages due to the pages alignment,
which will cause the pages overflow.
while (pages > 0) {
...
pages -= chunk;
}
the patch is change the pages from unsigned int to int to fix the issue.
BUG: unable to handle kernel paging request at 88000deb4000
IP: [] memset_erms+0x9/0x10
Call Trace:
[] snd_dma_alloc_pages+0xff/0x210
[] snd_dma_alloc_pages_fallback+0x6f/0x90
[] snd_malloc_sgbuf_pages+0x145/0x370
[] snd_dma_alloc_pages+0x16e/0x210
[] hdac_ext_dma_alloc_pages+0x1d/0x40 [snd_hda_ext_core]
[] snd_hdac_dsp_prepare+0xca/0x1c0 [snd_hda_core]
[] skl_dsp_prepare+0x99/0xf0 [snd_soc_skl]
[] bxt_load_base_firmware+0x9e/0x5c0 [snd_soc_skl_ipc]
[] bxt_set_dsp_D0+0x14c/0x300 [snd_soc_skl_ipc]
[] skl_dsp_get_core+0x43/0xd0 [snd_soc_skl_ipc]
[] skl_dsp_wake+0x10/0x20 [snd_soc_skl_ipc]
[] skl_resume_dsp+0x7e/0x140 [snd_soc_skl]
[] skl_resume+0xda/0x170 [snd_soc_skl]
[] pci_pm_resume+0x76/0xe0
[] dpm_run_callback+0x5a/0x180
[] device_resume+0xdc/0x2c0
[] dpm_resume+0x118/0x310
[] dpm_resume_end+0x11/0x20
[] suspend_devices_and_enter+0x11c/0x2b0
[] pm_suspend+0x35d/0x3d0
[] state_store+0x66/0x90
[] kobj_attr_store+0x12/0x20
[] sysfs_kf_write+0x3c/0x50
[] kernfs_fop_write+0x11d/0x1a0
[] __vfs_write+0x3a/0x150
[] vfs_write+0xb1/0x1a0
[] SyS_write+0x58/0xc0
[] do_syscall_64+0x6a/0xe0
[] entry_SYSCALL_64_after_swapgs+0x5d/0xd7
Signed-off-by: he, bo
Signed-off-by: zhang jun
---
sound/core/sgbuf.c | 3 ++-
1 file changed, 2 insertions(+), 1 deletion(-)
diff --git a/sound/core/sgbuf.c b/sound/core/sgbuf.c
index 84fffab..33449ee 100644
--- a/sound/core/sgbuf.c
+++ b/sound/core/sgbuf.c
@@ -68,7 +68,8 @@ void *snd_malloc_sgbuf_pages(struct device *device,
size_t *res_size)
{
struct snd_sg_buf *sgbuf;
- unsigned int i, pages, chunk, maxpages;
+ unsigned int i, chunk, maxpages;
+ int pages;
struct snd_dma_buffer tmpb;
struct snd_sg_page *table;
struct page **pgtable;
--
2.7.4
[PATCH] ALSA: core: fix unsigned int pages overflow when comapred
we see the below kernel panic on stress suspend resume test in
snd_malloc_sgbuf_pages(), snd_dma_alloc_pages_fallback() alloc
chunk maybe larger than the left pages due to the pages alignment,
which will cause the pages overflow.
while (pages > 0) {
...
pages -= chunk;
}
the patch is change the pages from unsigned int to int to fix the issue.
BUG: unable to handle kernel paging request at 88000deb4000
IP: [] memset_erms+0x9/0x10
Call Trace:
[] snd_dma_alloc_pages+0xff/0x210
[] snd_dma_alloc_pages_fallback+0x6f/0x90
[] snd_malloc_sgbuf_pages+0x145/0x370
[] snd_dma_alloc_pages+0x16e/0x210
[] hdac_ext_dma_alloc_pages+0x1d/0x40 [snd_hda_ext_core]
[] snd_hdac_dsp_prepare+0xca/0x1c0 [snd_hda_core]
[] skl_dsp_prepare+0x99/0xf0 [snd_soc_skl]
[] bxt_load_base_firmware+0x9e/0x5c0 [snd_soc_skl_ipc]
[] bxt_set_dsp_D0+0x14c/0x300 [snd_soc_skl_ipc]
[] skl_dsp_get_core+0x43/0xd0 [snd_soc_skl_ipc]
[] skl_dsp_wake+0x10/0x20 [snd_soc_skl_ipc]
[] skl_resume_dsp+0x7e/0x140 [snd_soc_skl]
[] skl_resume+0xda/0x170 [snd_soc_skl]
[] pci_pm_resume+0x76/0xe0
[] dpm_run_callback+0x5a/0x180
[] device_resume+0xdc/0x2c0
[] dpm_resume+0x118/0x310
[] dpm_resume_end+0x11/0x20
[] suspend_devices_and_enter+0x11c/0x2b0
[] pm_suspend+0x35d/0x3d0
[] state_store+0x66/0x90
[] kobj_attr_store+0x12/0x20
[] sysfs_kf_write+0x3c/0x50
[] kernfs_fop_write+0x11d/0x1a0
[] __vfs_write+0x3a/0x150
[] vfs_write+0xb1/0x1a0
[] SyS_write+0x58/0xc0
[] do_syscall_64+0x6a/0xe0
[] entry_SYSCALL_64_after_swapgs+0x5d/0xd7
Signed-off-by: he, bo
Signed-off-by: zhang jun
---
sound/core/sgbuf.c | 3 ++-
1 file changed, 2 insertions(+), 1 deletion(-)
diff --git a/sound/core/sgbuf.c b/sound/core/sgbuf.c
index 84fffab..33449ee 100644
--- a/sound/core/sgbuf.c
+++ b/sound/core/sgbuf.c
@@ -68,7 +68,8 @@ void *snd_malloc_sgbuf_pages(struct device *device,
size_t *res_size)
{
struct snd_sg_buf *sgbuf;
- unsigned int i, pages, chunk, maxpages;
+ unsigned int i, chunk, maxpages;
+ int pages;
struct snd_dma_buffer tmpb;
struct snd_sg_page *table;
struct page **pgtable;
--
2.7.4
RE: [PATCH] usb: gadget: udc: fix the kernel NULL pointer in composite_setup
The patch I submitted is based on the latest kernel,
I checked the latest kernel has the same logic,
so I send the patch to LKML.
Thanks for your comments.
-Original Message-
From: Felipe Balbi [mailto:ba...@kernel.org]
Sent: Wednesday, July 19, 2017 3:51 PM
To: He, Bo <bo...@intel.com>; linux-kernel@vger.kernel.org;
linux-...@vger.kernel.org
Cc: gre...@linuxfoundation.org; peter.c...@nxp.com; k.opas...@samsung.com;
ste...@agner.ch; felixhaedi...@web.de; colin.k...@canonical.com; rog...@ti.com;
f.faine...@gmail.com; Zhang, Yanmin <yanmin.zh...@intel.com>
Subject: RE: [PATCH] usb: gadget: udc: fix the kernel NULL pointer in
composite_setup
Hi,
(please don't top-post and also break your lines at 80-columns ;-)
"He, Bo" <bo...@intel.com> writes:
> 1. the issue reproduced very rarely, we run reboot test
> reproduce the issue, it reproduced two times on two board after
> more than 1500 cycles reboot.
That's fine, we, somehow, got a use-after-free on the tracepoints. I'm
interested in fixing that without touching udc-core since that's a dwc3-only
bug.
> 2. the kernel version is 4.4, the test case is cold reboot, I think
> it's not android patches cause it, it's the interrupt thread run after the
> udc->driver->unbind.
Yeah, I need you to try v4.13-rc1. v4.4 is *really* old. I can't accept your
patch unless I'm certain the bug still exists.
> 3. I check more drivers, like amd5536_udc_stop, at91_stop,
> atmel_usba_stop, bcm63xx_udc_stop, s3c_hsudc_stop, all the
> interrupt disable will be in the udc_stop(), so we need
> guarantee to stop the interrupt then release the resource.
Right, we also disable the interrupt on ->udc_stop(). See below:
static void __dwc3_gadget_stop(struct dwc3 *dwc) {
dwc3_gadget_disable_irq(dwc);
__dwc3_gadget_ep_disable(dwc->eps[0]);
__dwc3_gadget_ep_disable(dwc->eps[1]);
}
static int dwc3_gadget_stop(struct usb_gadget *g) {
struct dwc3 *dwc = gadget_to_dwc(g);
unsigned long flags;
int epnum;
spin_lock_irqsave(>lock, flags);
if (pm_runtime_suspended(dwc->dev))
goto out;
__dwc3_gadget_stop(dwc);
for (epnum = 2; epnum < DWC3_ENDPOINTS_NUM; epnum++) {
struct dwc3_ep *dep = dwc->eps[epnum];
if (!dep)
continue;
if (!(dep->flags & DWC3_EP_END_TRANSFER_PENDING))
continue;
wait_event_lock_irq(dep->wait_end_transfer,
!(dep->flags &
DWC3_EP_END_TRANSFER_PENDING),
dwc->lock);
}
out:
dwc->gadget_driver = NULL;
spin_unlock_irqrestore(>lock, flags);
free_irq(dwc->irq_gadget, dwc->ev_buf);
return 0;
}
--
balbi
RE: [PATCH] usb: gadget: udc: fix the kernel NULL pointer in composite_setup
The patch I submitted is based on the latest kernel,
I checked the latest kernel has the same logic,
so I send the patch to LKML.
Thanks for your comments.
-Original Message-
From: Felipe Balbi [mailto:ba...@kernel.org]
Sent: Wednesday, July 19, 2017 3:51 PM
To: He, Bo ; linux-kernel@vger.kernel.org;
linux-...@vger.kernel.org
Cc: gre...@linuxfoundation.org; peter.c...@nxp.com; k.opas...@samsung.com;
ste...@agner.ch; felixhaedi...@web.de; colin.k...@canonical.com; rog...@ti.com;
f.faine...@gmail.com; Zhang, Yanmin
Subject: RE: [PATCH] usb: gadget: udc: fix the kernel NULL pointer in
composite_setup
Hi,
(please don't top-post and also break your lines at 80-columns ;-)
"He, Bo" writes:
> 1. the issue reproduced very rarely, we run reboot test
> reproduce the issue, it reproduced two times on two board after
> more than 1500 cycles reboot.
That's fine, we, somehow, got a use-after-free on the tracepoints. I'm
interested in fixing that without touching udc-core since that's a dwc3-only
bug.
> 2. the kernel version is 4.4, the test case is cold reboot, I think
> it's not android patches cause it, it's the interrupt thread run after the
> udc->driver->unbind.
Yeah, I need you to try v4.13-rc1. v4.4 is *really* old. I can't accept your
patch unless I'm certain the bug still exists.
> 3. I check more drivers, like amd5536_udc_stop, at91_stop,
> atmel_usba_stop, bcm63xx_udc_stop, s3c_hsudc_stop, all the
> interrupt disable will be in the udc_stop(), so we need
> guarantee to stop the interrupt then release the resource.
Right, we also disable the interrupt on ->udc_stop(). See below:
static void __dwc3_gadget_stop(struct dwc3 *dwc) {
dwc3_gadget_disable_irq(dwc);
__dwc3_gadget_ep_disable(dwc->eps[0]);
__dwc3_gadget_ep_disable(dwc->eps[1]);
}
static int dwc3_gadget_stop(struct usb_gadget *g) {
struct dwc3 *dwc = gadget_to_dwc(g);
unsigned long flags;
int epnum;
spin_lock_irqsave(>lock, flags);
if (pm_runtime_suspended(dwc->dev))
goto out;
__dwc3_gadget_stop(dwc);
for (epnum = 2; epnum < DWC3_ENDPOINTS_NUM; epnum++) {
struct dwc3_ep *dep = dwc->eps[epnum];
if (!dep)
continue;
if (!(dep->flags & DWC3_EP_END_TRANSFER_PENDING))
continue;
wait_event_lock_irq(dep->wait_end_transfer,
!(dep->flags &
DWC3_EP_END_TRANSFER_PENDING),
dwc->lock);
}
out:
dwc->gadget_driver = NULL;
spin_unlock_irqrestore(>lock, flags);
free_irq(dwc->irq_gadget, dwc->ev_buf);
return 0;
}
--
balbi
RE: [PATCH] usb: gadget: udc: fix the kernel NULL pointer in composite_setup
Hi, Balbi: 1. the issue reproduced very rarely, we run reboot test reproduce the issue, it reproduced two times on two board after more than 1500 cycles reboot. 2. the kernel version is 4.4, the test case is cold reboot, I think it's not android patches cause it, it's the interrupt thread run after the udc->driver->unbind. 3. I check more drivers, like amd5536_udc_stop, at91_stop, atmel_usba_stop, bcm63xx_udc_stop, s3c_hsudc_stop, all the interrupt disable will be in the udc_stop(), so we need guarantee to stop the interrupt then release the resource. -Original Message- From: Felipe Balbi [mailto:ba...@kernel.org] Sent: Tuesday, July 18, 2017 6:44 PM To: He, Bo <bo...@intel.com>; linux-kernel@vger.kernel.org; linux-...@vger.kernel.org Cc: gre...@linuxfoundation.org; peter.c...@nxp.com; k.opas...@samsung.com; ste...@agner.ch; felixhaedi...@web.de; colin.k...@canonical.com; rog...@ti.com; f.faine...@gmail.com; He, Bo <bo...@intel.com>; Zhang, Yanmin <yanmin.zh...@intel.com> Subject: Re: [PATCH] usb: gadget: udc: fix the kernel NULL pointer in composite_setup Hi, "He, Bo" <bo...@intel.com> writes: > the patch is for fix the below kernel panic: > BUG: unable to handle kernel NULL pointer dereference at > 002a > IP: [] composite_setup+0x3d/0x1830 PGD 27525b067 PUD > 27525a067 PMD 0 > Oops: 0002 [#1] PREEMPT SMP > Call Trace: > [] ? dwc3_trace+0x52/0x60 [] ? > get_parent_ip+0xd/0x50 [] android_setup+0xbc/0x140 > [] ? irq_finalize_oneshot+0xe0/0xe0 > [] dwc3_ep0_delegate_req+0x37/0x50 > [] dwc3_ep0_interrupt+0xaf9/0xc10 > [] ? get_parent_ip+0xd/0x50 [] ? > irq_finalize_oneshot+0xe0/0xe0 [] > dwc3_thread_interrupt+0x931/0xbf0 [] ? > irq_finalize_oneshot+0xe0/0xe0 [] > irq_thread_fn+0x1e/0x40 [] irq_thread+0x134/0x1b0 > [] ? wake_threads_waitq+0x30/0x30 > [] kthread+0xed/0x110 [] > ret_from_fork+0x3f/0x70 RIP [] > composite_setup+0x3d/0x1830 > > the root cause is dwc interrupt comes after usb_gadget_remove_driver. > the fix is stop udc to have the dwc3 disable the interrupt, then > release the resource in udc->driver->unbind. > usb_gadget_udc_stop--> > udc->gadget->ops->udc_stop(udc->gadget)--> > dwc3_gadget_stop > > Signed-off-by: he, bo <bo...@intel.com> > --- > drivers/usb/gadget/udc/core.c | 2 +- > 1 file changed, 1 insertion(+), 1 deletion(-) > > diff --git a/drivers/usb/gadget/udc/core.c > b/drivers/usb/gadget/udc/core.c index e6f04ee..67e9aa5 100644 > --- a/drivers/usb/gadget/udc/core.c > +++ b/drivers/usb/gadget/udc/core.c > @@ -1258,8 +1258,8 @@ static void usb_gadget_remove_driver(struct > usb_udc *udc) > > usb_gadget_disconnect(udc->gadget); > udc->driver->disconnect(udc->gadget); > - udc->driver->unbind(udc->gadget); > usb_gadget_udc_stop(udc); > + udc->driver->unbind(udc->gadget); unbind must be called before udc_stop. This seems to be a bug *only* in dwc3. I can't see how this would happen, actually. On dwc3_gadget_stop() we mask dwc3's interrupts, so the handler should be executed anymore. Can you tell me how to reproduce this? I could try this out tomorrow. Which kernel are you using? I wonder if this is something caused by the Android patches. -- balbi
RE: [PATCH] usb: gadget: udc: fix the kernel NULL pointer in composite_setup
Hi, Balbi: 1. the issue reproduced very rarely, we run reboot test reproduce the issue, it reproduced two times on two board after more than 1500 cycles reboot. 2. the kernel version is 4.4, the test case is cold reboot, I think it's not android patches cause it, it's the interrupt thread run after the udc->driver->unbind. 3. I check more drivers, like amd5536_udc_stop, at91_stop, atmel_usba_stop, bcm63xx_udc_stop, s3c_hsudc_stop, all the interrupt disable will be in the udc_stop(), so we need guarantee to stop the interrupt then release the resource. -Original Message- From: Felipe Balbi [mailto:ba...@kernel.org] Sent: Tuesday, July 18, 2017 6:44 PM To: He, Bo ; linux-kernel@vger.kernel.org; linux-...@vger.kernel.org Cc: gre...@linuxfoundation.org; peter.c...@nxp.com; k.opas...@samsung.com; ste...@agner.ch; felixhaedi...@web.de; colin.k...@canonical.com; rog...@ti.com; f.faine...@gmail.com; He, Bo ; Zhang, Yanmin Subject: Re: [PATCH] usb: gadget: udc: fix the kernel NULL pointer in composite_setup Hi, "He, Bo" writes: > the patch is for fix the below kernel panic: > BUG: unable to handle kernel NULL pointer dereference at > 002a > IP: [] composite_setup+0x3d/0x1830 PGD 27525b067 PUD > 27525a067 PMD 0 > Oops: 0002 [#1] PREEMPT SMP > Call Trace: > [] ? dwc3_trace+0x52/0x60 [] ? > get_parent_ip+0xd/0x50 [] android_setup+0xbc/0x140 > [] ? irq_finalize_oneshot+0xe0/0xe0 > [] dwc3_ep0_delegate_req+0x37/0x50 > [] dwc3_ep0_interrupt+0xaf9/0xc10 > [] ? get_parent_ip+0xd/0x50 [] ? > irq_finalize_oneshot+0xe0/0xe0 [] > dwc3_thread_interrupt+0x931/0xbf0 [] ? > irq_finalize_oneshot+0xe0/0xe0 [] > irq_thread_fn+0x1e/0x40 [] irq_thread+0x134/0x1b0 > [] ? wake_threads_waitq+0x30/0x30 > [] kthread+0xed/0x110 [] > ret_from_fork+0x3f/0x70 RIP [] > composite_setup+0x3d/0x1830 > > the root cause is dwc interrupt comes after usb_gadget_remove_driver. > the fix is stop udc to have the dwc3 disable the interrupt, then > release the resource in udc->driver->unbind. > usb_gadget_udc_stop--> > udc->gadget->ops->udc_stop(udc->gadget)--> > dwc3_gadget_stop > > Signed-off-by: he, bo > --- > drivers/usb/gadget/udc/core.c | 2 +- > 1 file changed, 1 insertion(+), 1 deletion(-) > > diff --git a/drivers/usb/gadget/udc/core.c > b/drivers/usb/gadget/udc/core.c index e6f04ee..67e9aa5 100644 > --- a/drivers/usb/gadget/udc/core.c > +++ b/drivers/usb/gadget/udc/core.c > @@ -1258,8 +1258,8 @@ static void usb_gadget_remove_driver(struct > usb_udc *udc) > > usb_gadget_disconnect(udc->gadget); > udc->driver->disconnect(udc->gadget); > - udc->driver->unbind(udc->gadget); > usb_gadget_udc_stop(udc); > + udc->driver->unbind(udc->gadget); unbind must be called before udc_stop. This seems to be a bug *only* in dwc3. I can't see how this would happen, actually. On dwc3_gadget_stop() we mask dwc3's interrupts, so the handler should be executed anymore. Can you tell me how to reproduce this? I could try this out tomorrow. Which kernel are you using? I wonder if this is something caused by the Android patches. -- balbi
[PATCH] usb: gadget: udc: fix the kernel NULL pointer in composite_setup
the patch is for fix the below kernel panic: BUG: unable to handle kernel NULL pointer dereference at 002a IP: [] composite_setup+0x3d/0x1830 PGD 27525b067 PUD 27525a067 PMD 0 Oops: 0002 [#1] PREEMPT SMP Call Trace: [] ? dwc3_trace+0x52/0x60 [] ? get_parent_ip+0xd/0x50 [] android_setup+0xbc/0x140 [] ? irq_finalize_oneshot+0xe0/0xe0 [] dwc3_ep0_delegate_req+0x37/0x50 [] dwc3_ep0_interrupt+0xaf9/0xc10 [] ? get_parent_ip+0xd/0x50 [] ? irq_finalize_oneshot+0xe0/0xe0 [] dwc3_thread_interrupt+0x931/0xbf0 [] ? irq_finalize_oneshot+0xe0/0xe0 [] irq_thread_fn+0x1e/0x40 [] irq_thread+0x134/0x1b0 [] ? wake_threads_waitq+0x30/0x30 [] kthread+0xed/0x110 [] ret_from_fork+0x3f/0x70 RIP [] composite_setup+0x3d/0x1830 the root cause is dwc interrupt comes after usb_gadget_remove_driver. the fix is stop udc to have the dwc3 disable the interrupt, then release the resource in udc->driver->unbind. usb_gadget_udc_stop--> udc->gadget->ops->udc_stop(udc->gadget)--> dwc3_gadget_stop Signed-off-by: he, bo <bo...@intel.com> --- drivers/usb/gadget/udc/core.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/drivers/usb/gadget/udc/core.c b/drivers/usb/gadget/udc/core.c index e6f04ee..67e9aa5 100644 --- a/drivers/usb/gadget/udc/core.c +++ b/drivers/usb/gadget/udc/core.c @@ -1258,8 +1258,8 @@ static void usb_gadget_remove_driver(struct usb_udc *udc) usb_gadget_disconnect(udc->gadget); udc->driver->disconnect(udc->gadget); - udc->driver->unbind(udc->gadget); usb_gadget_udc_stop(udc); + udc->driver->unbind(udc->gadget); udc->driver = NULL; udc->dev.driver = NULL; -- 2.7.4
[PATCH] usb: gadget: udc: fix the kernel NULL pointer in composite_setup
the patch is for fix the below kernel panic: BUG: unable to handle kernel NULL pointer dereference at 002a IP: [] composite_setup+0x3d/0x1830 PGD 27525b067 PUD 27525a067 PMD 0 Oops: 0002 [#1] PREEMPT SMP Call Trace: [] ? dwc3_trace+0x52/0x60 [] ? get_parent_ip+0xd/0x50 [] android_setup+0xbc/0x140 [] ? irq_finalize_oneshot+0xe0/0xe0 [] dwc3_ep0_delegate_req+0x37/0x50 [] dwc3_ep0_interrupt+0xaf9/0xc10 [] ? get_parent_ip+0xd/0x50 [] ? irq_finalize_oneshot+0xe0/0xe0 [] dwc3_thread_interrupt+0x931/0xbf0 [] ? irq_finalize_oneshot+0xe0/0xe0 [] irq_thread_fn+0x1e/0x40 [] irq_thread+0x134/0x1b0 [] ? wake_threads_waitq+0x30/0x30 [] kthread+0xed/0x110 [] ret_from_fork+0x3f/0x70 RIP [] composite_setup+0x3d/0x1830 the root cause is dwc interrupt comes after usb_gadget_remove_driver. the fix is stop udc to have the dwc3 disable the interrupt, then release the resource in udc->driver->unbind. usb_gadget_udc_stop--> udc->gadget->ops->udc_stop(udc->gadget)--> dwc3_gadget_stop Signed-off-by: he, bo --- drivers/usb/gadget/udc/core.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/drivers/usb/gadget/udc/core.c b/drivers/usb/gadget/udc/core.c index e6f04ee..67e9aa5 100644 --- a/drivers/usb/gadget/udc/core.c +++ b/drivers/usb/gadget/udc/core.c @@ -1258,8 +1258,8 @@ static void usb_gadget_remove_driver(struct usb_udc *udc) usb_gadget_disconnect(udc->gadget); udc->driver->disconnect(udc->gadget); - udc->driver->unbind(udc->gadget); usb_gadget_udc_stop(udc); + udc->driver->unbind(udc->gadget); udc->driver = NULL; udc->dev.driver = NULL; -- 2.7.4
RE: [PATCH] mm, oom: normalize the adj to ensure oom_badness return a positive number
Sorry, the title is confusing. Change it to: mm, oom: normalize the adj to ensure oom_badness returns a positive number We are enabling android mobiles. When running stress memory test, there is a bad issue. Some critical processes such as Healthd and watchdogd are killed, while some other processes are still alive. OOM should kill the tasks whose oom_score are biggest. Many processes use a minus oom_score_adj. oom_badness returns 1 for all of them and their oom_score are all 0. The patch tries to convert the minus oom_score_adj to a positive number when calculating oom_score. oom_score can keep right process priority sequence. Without the patch, almost all the processes' oom_score are equal to 0. (cat /proc/XXX/oom_*) Healthd-15 0 -941 Servicemanager -15 0 -941 Vold -15 0 -941 ia_watchdogd -15 0 -941 surfaceflinger -15 0 -941 zygote-15 0 -941 system_server -15 0 -941 ndroid.systemui-11 0 -705 With the patch, we can get different oom_score: Healthd-15 59 -941 Servicemanager -15 89 -941 Vold -15 60 -941 ia_watchdogd -15 89 -941 surfaceflinger -15 145 -941 zygote-15 122 -941 system_server -15 166 -941 ndroid.systemui-11 419 -705 -Original Message- From: David Rientjes [mailto:rient...@google.com] Sent: Tuesday, March 04, 2014 1:05 PM To: He, Bo Cc: linux-kernel@vger.kernel.org; Ingo Molnar; han...@cmpxchg.org; o...@redhat.com; kirill.shute...@linux.intel.com; Zhang, Yanmin; yanmin_zh...@intel.linux.com; Wang, Biao Subject: Re: [PATCH] mm, oom: normalize the adj to ensure oom_badness return one On Mon, 3 Mar 2014, He, Bo wrote: > if oom_score_adj is a big negative number, such as -941, adj *= > totalpages / 1000 will be a big negative number, finally the > oom_badness will get 0 points, here normalize the oom_score_adj to > ensure oom_badness return the positive number. > Sorry, I have no clue what you're talking about or trying to fix. A /proc/pid/oom_score_adj of -941 would mean discounting 94.1% of system memory from pid's resident memory usage for a system oom condition. This is the effect of adj *= totalpages / 1000 and is working as intended per Documentation/filesystems/proc.txt. oom_badness() will then return the smallest integer possible, 1 (not 0), that still allows the process to be killed, that's the effect of "return points > 0 ? points : 1". It never returns 0 as you state, you're either not reading the code correctly or not working on any recent kernel. > Change-Id: I1c56a948ce48b65a1bb63b56ffef07d5d76d7ec8 > Signed-off-by: he, bo > Signed-off-by: wang, biao > Reviewed-by: Yanmin Zhang > --- > mm/oom_kill.c |3 +++ > 1 files changed, 3 insertions(+), 0 deletions(-) > > diff --git a/mm/oom_kill.c b/mm/oom_kill.c > index 3291e82..5a93986 100644 > --- a/mm/oom_kill.c > +++ b/mm/oom_kill.c > @@ -181,6 +181,9 @@ unsigned long oom_badness(struct task_struct *p, struct > mem_cgroup *memcg, > points -= (points * 3) / 100; > > /* Normalize to oom_score_adj units */ > + if(OOM_SCORE_ADJ_MIN < 0) > + adj -= OOM_SCORE_ADJ_MIN; > + > adj *= totalpages / 1000; > points += adj; > -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
[PATCH] mm, oom: normalize the adj to ensure oom_badness return one
if oom_score_adj is a big negative number, such as -941, adj *= totalpages / 1000 will be a big negative number, finally the oom_badness will get 0 points, here normalize the oom_score_adj to ensure oom_badness return the positive number. Change-Id: I1c56a948ce48b65a1bb63b56ffef07d5d76d7ec8 Signed-off-by: he, bo Signed-off-by: wang, biao Reviewed-by: Yanmin Zhang --- mm/oom_kill.c |3 +++ 1 files changed, 3 insertions(+), 0 deletions(-) diff --git a/mm/oom_kill.c b/mm/oom_kill.c index 3291e82..5a93986 100644 --- a/mm/oom_kill.c +++ b/mm/oom_kill.c @@ -181,6 +181,9 @@ unsigned long oom_badness(struct task_struct *p, struct mem_cgroup *memcg, points -= (points * 3) / 100; /* Normalize to oom_score_adj units */ + if(OOM_SCORE_ADJ_MIN < 0) + adj -= OOM_SCORE_ADJ_MIN; + adj *= totalpages / 1000; points += adj; -- 1.7.6 -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
[PATCH] mm, oom: normalize the adj to ensure oom_badness return one
if oom_score_adj is a big negative number, such as -941, adj *= totalpages / 1000 will be a big negative number, finally the oom_badness will get 0 points, here normalize the oom_score_adj to ensure oom_badness return the positive number. Change-Id: I1c56a948ce48b65a1bb63b56ffef07d5d76d7ec8 Signed-off-by: he, bo bo...@intel.com Signed-off-by: wang, biao biao.w...@intel.com Reviewed-by: Yanmin Zhang yanmin_zh...@intel.com --- mm/oom_kill.c |3 +++ 1 files changed, 3 insertions(+), 0 deletions(-) diff --git a/mm/oom_kill.c b/mm/oom_kill.c index 3291e82..5a93986 100644 --- a/mm/oom_kill.c +++ b/mm/oom_kill.c @@ -181,6 +181,9 @@ unsigned long oom_badness(struct task_struct *p, struct mem_cgroup *memcg, points -= (points * 3) / 100; /* Normalize to oom_score_adj units */ + if(OOM_SCORE_ADJ_MIN 0) + adj -= OOM_SCORE_ADJ_MIN; + adj *= totalpages / 1000; points += adj; -- 1.7.6 -- To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
RE: [PATCH] mm, oom: normalize the adj to ensure oom_badness return a positive number
Sorry, the title is confusing. Change it to: mm, oom: normalize the adj to ensure oom_badness returns a positive number We are enabling android mobiles. When running stress memory test, there is a bad issue. Some critical processes such as Healthd and watchdogd are killed, while some other processes are still alive. OOM should kill the tasks whose oom_score are biggest. Many processes use a minus oom_score_adj. oom_badness returns 1 for all of them and their oom_score are all 0. The patch tries to convert the minus oom_score_adj to a positive number when calculating oom_score. oom_score can keep right process priority sequence. Without the patch, almost all the processes' oom_score are equal to 0. (cat /proc/XXX/oom_*) Healthd-15 0 -941 Servicemanager -15 0 -941 Vold -15 0 -941 ia_watchdogd -15 0 -941 surfaceflinger -15 0 -941 zygote-15 0 -941 system_server -15 0 -941 ndroid.systemui-11 0 -705 With the patch, we can get different oom_score: Healthd-15 59 -941 Servicemanager -15 89 -941 Vold -15 60 -941 ia_watchdogd -15 89 -941 surfaceflinger -15 145 -941 zygote-15 122 -941 system_server -15 166 -941 ndroid.systemui-11 419 -705 -Original Message- From: David Rientjes [mailto:rient...@google.com] Sent: Tuesday, March 04, 2014 1:05 PM To: He, Bo Cc: linux-kernel@vger.kernel.org; Ingo Molnar; han...@cmpxchg.org; o...@redhat.com; kirill.shute...@linux.intel.com; Zhang, Yanmin; yanmin_zh...@intel.linux.com; Wang, Biao Subject: Re: [PATCH] mm, oom: normalize the adj to ensure oom_badness return one On Mon, 3 Mar 2014, He, Bo wrote: if oom_score_adj is a big negative number, such as -941, adj *= totalpages / 1000 will be a big negative number, finally the oom_badness will get 0 points, here normalize the oom_score_adj to ensure oom_badness return the positive number. Sorry, I have no clue what you're talking about or trying to fix. A /proc/pid/oom_score_adj of -941 would mean discounting 94.1% of system memory from pid's resident memory usage for a system oom condition. This is the effect of adj *= totalpages / 1000 and is working as intended per Documentation/filesystems/proc.txt. oom_badness() will then return the smallest integer possible, 1 (not 0), that still allows the process to be killed, that's the effect of return points 0 ? points : 1. It never returns 0 as you state, you're either not reading the code correctly or not working on any recent kernel. Change-Id: I1c56a948ce48b65a1bb63b56ffef07d5d76d7ec8 Signed-off-by: he, bo bo...@intel.com Signed-off-by: wang, biao biao.w...@intel.com Reviewed-by: Yanmin Zhang yanmin_zh...@intel.com --- mm/oom_kill.c |3 +++ 1 files changed, 3 insertions(+), 0 deletions(-) diff --git a/mm/oom_kill.c b/mm/oom_kill.c index 3291e82..5a93986 100644 --- a/mm/oom_kill.c +++ b/mm/oom_kill.c @@ -181,6 +181,9 @@ unsigned long oom_badness(struct task_struct *p, struct mem_cgroup *memcg, points -= (points * 3) / 100; /* Normalize to oom_score_adj units */ + if(OOM_SCORE_ADJ_MIN 0) + adj -= OOM_SCORE_ADJ_MIN; + adj *= totalpages / 1000; points += adj; -- To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
RE: [PATCH V2] output the cpu number when printking.
Thanks, Greg. I did use this patch to fix many races on SMP. But to respect maintainer, I stop pushing the patch to upstream. -Original Message- From: Greg KH [mailto:gre...@linuxfoundation.org] Sent: Thursday, December 27, 2012 1:50 AM To: Yanmin Zhang Cc: He, Bo; Randy Dunlap; a...@linux-foundation.org; mi...@elte.hu; linux-kernel@vger.kernel.org; a.p.zijls...@chello.nl Subject: Re: [PATCH V2] output the cpu number when printking. On Tue, Dec 25, 2012 at 09:09:05AM +0800, Yanmin Zhang wrote: > On Mon, 2012-12-24 at 09:55 -0800, Greg KH wrote: > > On Mon, Dec 24, 2012 at 01:01:55PM +0800, he, bo wrote: > > > From: "he, bo" > > > > > > We often hit kernel panic issues on SMP machines because processes > > > race on multiple cpu. By adding a new parameter printk.cpu, kernel > > > prints cpu number at printk information line. It’s useful to debug > > > what cpus are racing. > > > > How useful is this really for normal developers? > It's very useful to debug race conditions under SMP environment. > We applied the patch to our Android build image on our smartphones. That's fine for your application, and seemed to be useful to others with their first interactions with SMP systems. However, once you start to get to "real" numbers of CPUs, this information turns pretty pointless, which is why the patch was originally rejected. sorry, greg k-h
RE: [PATCH V2] output the cpu number when printking.
Thanks, Greg. I did use this patch to fix many races on SMP. But to respect maintainer, I stop pushing the patch to upstream. -Original Message- From: Greg KH [mailto:gre...@linuxfoundation.org] Sent: Thursday, December 27, 2012 1:50 AM To: Yanmin Zhang Cc: He, Bo; Randy Dunlap; a...@linux-foundation.org; mi...@elte.hu; linux-kernel@vger.kernel.org; a.p.zijls...@chello.nl Subject: Re: [PATCH V2] output the cpu number when printking. On Tue, Dec 25, 2012 at 09:09:05AM +0800, Yanmin Zhang wrote: On Mon, 2012-12-24 at 09:55 -0800, Greg KH wrote: On Mon, Dec 24, 2012 at 01:01:55PM +0800, he, bo wrote: From: he, bo bo...@intel.com We often hit kernel panic issues on SMP machines because processes race on multiple cpu. By adding a new parameter printk.cpu, kernel prints cpu number at printk information line. It’s useful to debug what cpus are racing. How useful is this really for normal developers? It's very useful to debug race conditions under SMP environment. We applied the patch to our Android build image on our smartphones. That's fine for your application, and seemed to be useful to others with their first interactions with SMP systems. However, once you start to get to real numbers of CPUs, this information turns pretty pointless, which is why the patch was originally rejected. sorry, greg k-h
[PATCH V2] output the cpu number when printking.
From: "he, bo"
We often hit kernel panic issues on SMP machines because processes race
on multiple cpu. By adding a new parameter printk.cpu, kernel prints
cpu number at printk information line. It’s useful to debug what cpus
are racing.
Signed-off-by: he, bo
---
Documentation/kernel-parameters.txt |4
kernel/printk.c | 18 --
2 files changed, 20 insertions(+), 2 deletions(-)
diff --git a/Documentation/kernel-parameters.txt
b/Documentation/kernel-parameters.txt
index ddd84d6..3387a7f 100644
--- a/Documentation/kernel-parameters.txt
+++ b/Documentation/kernel-parameters.txt
@@ -2378,6 +2378,10 @@ bytes respectively. Such letter suffixes can also be
entirely omitted.
printk.time=Show timing data prefixed to each printk message line
Format: (1/Y/y=enable, 0/N/n=disable)
+ printk.cpu= Show cpu data prefixed to each printk message line
+ Format: (1/Y/y=enable, 0/N/n=disable)
+ printk.cpu takes effect only when printk.time=y.
+
processor.max_cstate= [HW,ACPI]
Limit processor to maximum C-state
max_cstate=9 overrides any DMI blacklist limit.
diff --git a/kernel/printk.c b/kernel/printk.c
index 19c0d7b..873a226 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -863,9 +863,14 @@ static bool printk_time;
#endif
module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
+static bool printk_cpu = 1;
+module_param_named(cpu, printk_cpu, bool, S_IRUGO | S_IWUSR);
+
static size_t print_time(u64 ts, char *buf)
{
unsigned long rem_nsec;
+ size_t len = 0;
+ int this_cpu;
if (!printk_time)
return 0;
@@ -874,8 +879,17 @@ static size_t print_time(u64 ts, char *buf)
return 15;
rem_nsec = do_div(ts, 10);
- return sprintf(buf, "[%5lu.%06lu] ",
- (unsigned long)ts, rem_nsec / 1000);
+
+ if (printk_cpu) {
+ this_cpu = raw_smp_processor_id();
+ len = sprintf(buf, "[%5lu.%06lu,%u] ",
+ (unsigned long)ts, rem_nsec / 1000, this_cpu);
+ } else {
+ len = sprintf(buf, "[%5lu.%06lu] ",
+ (unsigned long)ts, rem_nsec / 1000);
+ }
+
+ return len;
}
static size_t print_prefix(const struct log *msg, bool syslog, char *buf)
--
1.7.6
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH] output the cpu number when printking.
Thanks randy's comments, I will modifiy it.
On Sun, 2012-12-23 at 19:37 -0800, Randy Dunlap wrote:
> On 12/23/12 18:31, he, bo wrote:
> > From: "he, bo"
> >
> > We often hit kernel panic issues on SMP machines because processes race
> > on multiple cpu. By adding a new parameter printk.cpu, kernel prints
> > cpu number at printk information line. It’s useful to debug what cpus
> > are racing.
> >
> > Signed-off-by: he, bo
> > ---
> > Documentation/kernel-parameters.txt |4
> > kernel/printk.c | 18 --
> > 2 files changed, 20 insertions(+), 2 deletions(-)
> >
> > diff --git a/Documentation/kernel-parameters.txt
> > b/Documentation/kernel-parameters.txt
> > index ddd84d6..ccd5266 100644
> > --- a/Documentation/kernel-parameters.txt
> > +++ b/Documentation/kernel-parameters.txt
> > @@ -2378,6 +2378,10 @@ bytes respectively. Such letter suffixes can also be
> > entirely omitted.
> > printk.time=Show timing data prefixed to each printk message line
> > Format: (1/Y/y=enable, 0/N/n=disable)
> >
> > + printk.cpu= Show cpu data prefixed to each printk message line
> > + Format: (1/Y/y=enable, 0/N/n=disable)
> > + printk.cpu takes effect only when printk.time=y.
>
> Above line needs to be indented more (beginning under "Format:").
>
> > +
> > processor.max_cstate= [HW,ACPI]
> > Limit processor to maximum C-state
> > max_cstate=9 overrides any DMI blacklist limit.
> > diff --git a/kernel/printk.c b/kernel/printk.c
> > index 19c0d7b..873a226 100644
> > --- a/kernel/printk.c
> > +++ b/kernel/printk.c
> > @@ -863,9 +863,14 @@ static bool printk_time;
> > #endif
> > module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
> >
> > +static bool printk_cpu = 1;
> > +module_param_named(cpu, printk_cpu, bool, S_IRUGO | S_IWUSR);
> > +
> > static size_t print_time(u64 ts, char *buf)
> > {
> > unsigned long rem_nsec;
> > + size_t len = 0;
> > + int this_cpu;
> >
> > if (!printk_time)
> > return 0;
> > @@ -874,8 +879,17 @@ static size_t print_time(u64 ts, char *buf)
> > return 15;
> >
> > rem_nsec = do_div(ts, 10);
> > - return sprintf(buf, "[%5lu.%06lu] ",
> > - (unsigned long)ts, rem_nsec / 1000);
> > +
> > + if (printk_cpu) {
> > + this_cpu = raw_smp_processor_id();
> > + len = sprintf(buf, "[%5lu.%06lu,%u] ",
> > + (unsigned long)ts, rem_nsec / 1000, this_cpu);
> > + } else {
> > + len = sprintf(buf, "[%5lu.%06lu] ",
> > + (unsigned long)ts, rem_nsec / 1000);
> > + }
> > +
> > + return len;
> > }
> >
> > static size_t print_prefix(const struct log *msg, bool syslog, char *buf)
> >
>
>
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
[PATCH] output the cpu number when printking.
From: "he, bo"
We often hit kernel panic issues on SMP machines because processes race
on multiple cpu. By adding a new parameter printk.cpu, kernel prints
cpu number at printk information line. It’s useful to debug what cpus
are racing.
Signed-off-by: he, bo
---
Documentation/kernel-parameters.txt |4
kernel/printk.c | 18 --
2 files changed, 20 insertions(+), 2 deletions(-)
diff --git a/Documentation/kernel-parameters.txt
b/Documentation/kernel-parameters.txt
index ddd84d6..ccd5266 100644
--- a/Documentation/kernel-parameters.txt
+++ b/Documentation/kernel-parameters.txt
@@ -2378,6 +2378,10 @@ bytes respectively. Such letter suffixes can also be
entirely omitted.
printk.time=Show timing data prefixed to each printk message line
Format: (1/Y/y=enable, 0/N/n=disable)
+ printk.cpu= Show cpu data prefixed to each printk message line
+ Format: (1/Y/y=enable, 0/N/n=disable)
+ printk.cpu takes effect only when printk.time=y.
+
processor.max_cstate= [HW,ACPI]
Limit processor to maximum C-state
max_cstate=9 overrides any DMI blacklist limit.
diff --git a/kernel/printk.c b/kernel/printk.c
index 19c0d7b..873a226 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -863,9 +863,14 @@ static bool printk_time;
#endif
module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
+static bool printk_cpu = 1;
+module_param_named(cpu, printk_cpu, bool, S_IRUGO | S_IWUSR);
+
static size_t print_time(u64 ts, char *buf)
{
unsigned long rem_nsec;
+ size_t len = 0;
+ int this_cpu;
if (!printk_time)
return 0;
@@ -874,8 +879,17 @@ static size_t print_time(u64 ts, char *buf)
return 15;
rem_nsec = do_div(ts, 10);
- return sprintf(buf, "[%5lu.%06lu] ",
- (unsigned long)ts, rem_nsec / 1000);
+
+ if (printk_cpu) {
+ this_cpu = raw_smp_processor_id();
+ len = sprintf(buf, "[%5lu.%06lu,%u] ",
+ (unsigned long)ts, rem_nsec / 1000, this_cpu);
+ } else {
+ len = sprintf(buf, "[%5lu.%06lu] ",
+ (unsigned long)ts, rem_nsec / 1000);
+ }
+
+ return len;
}
static size_t print_prefix(const struct log *msg, bool syslog, char *buf)
--
1.7.6
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
[PATCH] output the cpu number when printking.
From: he, bo bo...@intel.com
We often hit kernel panic issues on SMP machines because processes race
on multiple cpu. By adding a new parameter printk.cpu, kernel prints
cpu number at printk information line. It’s useful to debug what cpus
are racing.
Signed-off-by: he, bo bo...@intel.com
---
Documentation/kernel-parameters.txt |4
kernel/printk.c | 18 --
2 files changed, 20 insertions(+), 2 deletions(-)
diff --git a/Documentation/kernel-parameters.txt
b/Documentation/kernel-parameters.txt
index ddd84d6..ccd5266 100644
--- a/Documentation/kernel-parameters.txt
+++ b/Documentation/kernel-parameters.txt
@@ -2378,6 +2378,10 @@ bytes respectively. Such letter suffixes can also be
entirely omitted.
printk.time=Show timing data prefixed to each printk message line
Format: bool (1/Y/y=enable, 0/N/n=disable)
+ printk.cpu= Show cpu data prefixed to each printk message line
+ Format: bool (1/Y/y=enable, 0/N/n=disable)
+ printk.cpu takes effect only when printk.time=y.
+
processor.max_cstate= [HW,ACPI]
Limit processor to maximum C-state
max_cstate=9 overrides any DMI blacklist limit.
diff --git a/kernel/printk.c b/kernel/printk.c
index 19c0d7b..873a226 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -863,9 +863,14 @@ static bool printk_time;
#endif
module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
+static bool printk_cpu = 1;
+module_param_named(cpu, printk_cpu, bool, S_IRUGO | S_IWUSR);
+
static size_t print_time(u64 ts, char *buf)
{
unsigned long rem_nsec;
+ size_t len = 0;
+ int this_cpu;
if (!printk_time)
return 0;
@@ -874,8 +879,17 @@ static size_t print_time(u64 ts, char *buf)
return 15;
rem_nsec = do_div(ts, 10);
- return sprintf(buf, [%5lu.%06lu] ,
- (unsigned long)ts, rem_nsec / 1000);
+
+ if (printk_cpu) {
+ this_cpu = raw_smp_processor_id();
+ len = sprintf(buf, [%5lu.%06lu,%u] ,
+ (unsigned long)ts, rem_nsec / 1000, this_cpu);
+ } else {
+ len = sprintf(buf, [%5lu.%06lu] ,
+ (unsigned long)ts, rem_nsec / 1000);
+ }
+
+ return len;
}
static size_t print_prefix(const struct log *msg, bool syslog, char *buf)
--
1.7.6
--
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [PATCH] output the cpu number when printking.
Thanks randy's comments, I will modifiy it.
On Sun, 2012-12-23 at 19:37 -0800, Randy Dunlap wrote:
On 12/23/12 18:31, he, bo wrote:
From: he, bo bo...@intel.com
We often hit kernel panic issues on SMP machines because processes race
on multiple cpu. By adding a new parameter printk.cpu, kernel prints
cpu number at printk information line. It’s useful to debug what cpus
are racing.
Signed-off-by: he, bo bo...@intel.com
---
Documentation/kernel-parameters.txt |4
kernel/printk.c | 18 --
2 files changed, 20 insertions(+), 2 deletions(-)
diff --git a/Documentation/kernel-parameters.txt
b/Documentation/kernel-parameters.txt
index ddd84d6..ccd5266 100644
--- a/Documentation/kernel-parameters.txt
+++ b/Documentation/kernel-parameters.txt
@@ -2378,6 +2378,10 @@ bytes respectively. Such letter suffixes can also be
entirely omitted.
printk.time=Show timing data prefixed to each printk message line
Format: bool (1/Y/y=enable, 0/N/n=disable)
+ printk.cpu= Show cpu data prefixed to each printk message line
+ Format: bool (1/Y/y=enable, 0/N/n=disable)
+ printk.cpu takes effect only when printk.time=y.
Above line needs to be indented more (beginning under Format:).
+
processor.max_cstate= [HW,ACPI]
Limit processor to maximum C-state
max_cstate=9 overrides any DMI blacklist limit.
diff --git a/kernel/printk.c b/kernel/printk.c
index 19c0d7b..873a226 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -863,9 +863,14 @@ static bool printk_time;
#endif
module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
+static bool printk_cpu = 1;
+module_param_named(cpu, printk_cpu, bool, S_IRUGO | S_IWUSR);
+
static size_t print_time(u64 ts, char *buf)
{
unsigned long rem_nsec;
+ size_t len = 0;
+ int this_cpu;
if (!printk_time)
return 0;
@@ -874,8 +879,17 @@ static size_t print_time(u64 ts, char *buf)
return 15;
rem_nsec = do_div(ts, 10);
- return sprintf(buf, [%5lu.%06lu] ,
- (unsigned long)ts, rem_nsec / 1000);
+
+ if (printk_cpu) {
+ this_cpu = raw_smp_processor_id();
+ len = sprintf(buf, [%5lu.%06lu,%u] ,
+ (unsigned long)ts, rem_nsec / 1000, this_cpu);
+ } else {
+ len = sprintf(buf, [%5lu.%06lu] ,
+ (unsigned long)ts, rem_nsec / 1000);
+ }
+
+ return len;
}
static size_t print_prefix(const struct log *msg, bool syslog, char *buf)
--
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
[PATCH V2] output the cpu number when printking.
From: he, bo bo...@intel.com
We often hit kernel panic issues on SMP machines because processes race
on multiple cpu. By adding a new parameter printk.cpu, kernel prints
cpu number at printk information line. It’s useful to debug what cpus
are racing.
Signed-off-by: he, bo bo...@intel.com
---
Documentation/kernel-parameters.txt |4
kernel/printk.c | 18 --
2 files changed, 20 insertions(+), 2 deletions(-)
diff --git a/Documentation/kernel-parameters.txt
b/Documentation/kernel-parameters.txt
index ddd84d6..3387a7f 100644
--- a/Documentation/kernel-parameters.txt
+++ b/Documentation/kernel-parameters.txt
@@ -2378,6 +2378,10 @@ bytes respectively. Such letter suffixes can also be
entirely omitted.
printk.time=Show timing data prefixed to each printk message line
Format: bool (1/Y/y=enable, 0/N/n=disable)
+ printk.cpu= Show cpu data prefixed to each printk message line
+ Format: bool (1/Y/y=enable, 0/N/n=disable)
+ printk.cpu takes effect only when printk.time=y.
+
processor.max_cstate= [HW,ACPI]
Limit processor to maximum C-state
max_cstate=9 overrides any DMI blacklist limit.
diff --git a/kernel/printk.c b/kernel/printk.c
index 19c0d7b..873a226 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -863,9 +863,14 @@ static bool printk_time;
#endif
module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
+static bool printk_cpu = 1;
+module_param_named(cpu, printk_cpu, bool, S_IRUGO | S_IWUSR);
+
static size_t print_time(u64 ts, char *buf)
{
unsigned long rem_nsec;
+ size_t len = 0;
+ int this_cpu;
if (!printk_time)
return 0;
@@ -874,8 +879,17 @@ static size_t print_time(u64 ts, char *buf)
return 15;
rem_nsec = do_div(ts, 10);
- return sprintf(buf, [%5lu.%06lu] ,
- (unsigned long)ts, rem_nsec / 1000);
+
+ if (printk_cpu) {
+ this_cpu = raw_smp_processor_id();
+ len = sprintf(buf, [%5lu.%06lu,%u] ,
+ (unsigned long)ts, rem_nsec / 1000, this_cpu);
+ } else {
+ len = sprintf(buf, [%5lu.%06lu] ,
+ (unsigned long)ts, rem_nsec / 1000);
+ }
+
+ return len;
}
static size_t print_prefix(const struct log *msg, bool syslog, char *buf)
--
1.7.6
--
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
[PATCH] hrtimer:__run_hrtimer races with enqueue_hrtimer
From: Yanmin Zhang
We hit a kernel panic at __run_hrtimer=>BUG_ON(timer->state !=
HRTIMER_STATE_CALLBACK).
<2>[ 10.226053, 3] kernel BUG at
/home/android/xiaobing/ymz/r4/hardware/intel/linux-2.6/kernel/hrtimer.c:1228!
<0>[ 10.235682, 3] invalid opcode: [#1] PREEMPT SMP
<4>[ 10.240716, 3] Modules linked in: wl12xx_sdio wl12xx mac80211 cfg80211
compat btwilink rmi4(C) fmdrv_chr st_drv matrix(C)
<4>[ 10.251651, 3]
<4>[ 10.253391, 3] Pid: 68, comm: kworker/3:4 Tainted: GWC
3.0.34-140430-g2af538d #45 Intel Corporation CloverTrail/FFRD
<4>[ 10.264674, 3] EIP: 0060:[] EFLAGS: 00010002 CPU: 3
<4>[ 10.270411, 3] EIP is at __run_hrtimer+0xbd/0x240
<4>[ 10.275091, 3] EAX: 0001 EBX: f67fb6b8 ECX: f57b4000 EDX: 7301
<4>[ 10.281602, 3] ESI: c1d614c0 EDI: f67fb680 EBP: f57b5dd8 ESP: f57b5da8
<4>[ 10.288113, 3] DS: 007b ES: 007b FS: 00d8 GS: SS: 0068
<0>[ 10.293754, 3] Process kworker/3:4 (pid: 68, ti=f57b4000 task=f57aa730
task.ti=f57b4000)
<0>[ 10.301827, 3] Stack:
<4>[ 10.304083, 3] c1afef40 f57b5dd8 c167a6e0 f67fb680 20b366e3
f67fb6b8 f57b5e14
<4>[ 10.312069, 3] 0001 f67fb6b8 0001 f67fb680 f57b5e28 c126d1e5
f57b5e08 c126f325
<4>[ 10.320055, 3] 86b9868d 0001 86b9868d 0001 0003
7fff
<0>[ 10.328041, 3] Call Trace:
<4>[ 10.330742, 3] [] ? gburst_thread_stop.isra.25+0x40/0x40
<4>[ 10.336988, 3] [] hrtimer_interrupt+0xd5/0x250
<4>[ 10.342368, 3] [] ? sched_clock_cpu+0xe5/0x150
<4>[ 10.347753, 3] [] smp_apic_timer_interrupt+0x54/0x88
<4>[ 10.353654, 3] [] ? trace_hardirqs_off_thunk+0xc/0x14
<4>[ 10.359643, 3] [] apic_timer_interrupt+0x2f/0x34
<4>[ 10.365199, 3] [] ? sub_preempt_count+0x1f/0x50
<4>[ 10.370669, 3] [] delay_tsc+0x3a/0xc0
<6>[ 10.371589, 0] android_work: did not send uevent (0 0 (null))
<4>[ 10.381171, 3] [] __const_udelay+0x23/0x30
<4>[ 10.386207, 3] [] mdfld_dsi_send_dcs+0x12a/0x5d0
<4>[ 10.391760, 3] [] ? _raw_spin_unlock_irqrestore+0x26/0x50
<4>[ 10.398101, 3] [] ? ospm_power_using_hw_begin+0xa1/0x350
<4>[ 10.399053, 3] [] ? __mutex_lock_slowpath+0x1ff/0x2f0
<4>[ 10.399069, 3] [] mdfld_dbi_update_panel+0x21e/0x2d0
<4>[ 10.399085, 3] [] mdfld_te_handler_work+0x71/0x80
<4>[ 10.399099, 3] [] process_one_work+0xfe/0x3f0
<4>[ 10.399114, 3] [] ? mdfld_async_flip_te_handler+0xf0/0xf0
Basically, __run_hrtimer has a race with enqueue_hrtimer. When __run_hrtimer
calls
the timer callback fn, another thread might call enqueue_hrtimer or
hrtimer_start
to requeue it, and the timer->state is equal to
HRTIMER_STATE_CALLBACK|HRTIMER_STATE_ENQUEUED,
which causes the BUG_ON(timer->state != HRTIMER_STATE_CALLBACK) checking fails.
The patch fixes it by checking only bit HRTIMER_STATE_CALLBACK.
Signed-off-by: Yanmin Zhang
Reviewed-by: He, Bo
---
kernel/hrtimer.c |2 +-
1 files changed, 1 insertions(+), 1 deletions(-)
diff --git a/kernel/hrtimer.c b/kernel/hrtimer.c
index 6db7a5e..6280184 100644
--- a/kernel/hrtimer.c
+++ b/kernel/hrtimer.c
@@ -1235,7 +1235,7 @@ static void __run_hrtimer(struct hrtimer *timer, ktime_t
*now)
* hrtimer_start_range_ns() or in hrtimer_interrupt()
*/
if (restart != HRTIMER_NORESTART) {
- BUG_ON(timer->state != HRTIMER_STATE_CALLBACK);
+ BUG_ON(!(timer->state & HRTIMER_STATE_CALLBACK));
enqueue_hrtimer(timer, base);
}
--
1.7.6
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
[PATCH] hrtimer:__run_hrtimer races with enqueue_hrtimer
From: Yanmin Zhang yanmin.zh...@intel.com
We hit a kernel panic at __run_hrtimer=BUG_ON(timer-state !=
HRTIMER_STATE_CALLBACK).
2[ 10.226053, 3] kernel BUG at
/home/android/xiaobing/ymz/r4/hardware/intel/linux-2.6/kernel/hrtimer.c:1228!
0[ 10.235682, 3] invalid opcode: [#1] PREEMPT SMP
4[ 10.240716, 3] Modules linked in: wl12xx_sdio wl12xx mac80211 cfg80211
compat btwilink rmi4(C) fmdrv_chr st_drv matrix(C)
4[ 10.251651, 3]
4[ 10.253391, 3] Pid: 68, comm: kworker/3:4 Tainted: GWC
3.0.34-140430-g2af538d #45 Intel Corporation CloverTrail/FFRD
4[ 10.264674, 3] EIP: 0060:[c126c7ed] EFLAGS: 00010002 CPU: 3
4[ 10.270411, 3] EIP is at __run_hrtimer+0xbd/0x240
4[ 10.275091, 3] EAX: 0001 EBX: f67fb6b8 ECX: f57b4000 EDX: 7301
4[ 10.281602, 3] ESI: c1d614c0 EDI: f67fb680 EBP: f57b5dd8 ESP: f57b5da8
4[ 10.288113, 3] DS: 007b ES: 007b FS: 00d8 GS: SS: 0068
0[ 10.293754, 3] Process kworker/3:4 (pid: 68, ti=f57b4000 task=f57aa730
task.ti=f57b4000)
0[ 10.301827, 3] Stack:
4[ 10.304083, 3] c1afef40 f57b5dd8 c167a6e0 f67fb680 20b366e3
f67fb6b8 f57b5e14
4[ 10.312069, 3] 0001 f67fb6b8 0001 f67fb680 f57b5e28 c126d1e5
f57b5e08 c126f325
4[ 10.320055, 3] 86b9868d 0001 86b9868d 0001 0003
7fff
0[ 10.328041, 3] Call Trace:
4[ 10.330742, 3] [c167a6e0] ? gburst_thread_stop.isra.25+0x40/0x40
4[ 10.336988, 3] [c126d1e5] hrtimer_interrupt+0xd5/0x250
4[ 10.342368, 3] [c126f325] ? sched_clock_cpu+0xe5/0x150
4[ 10.347753, 3] [c1871d44] smp_apic_timer_interrupt+0x54/0x88
4[ 10.353654, 3] [c1496558] ? trace_hardirqs_off_thunk+0xc/0x14
4[ 10.359643, 3] [c186be9f] apic_timer_interrupt+0x2f/0x34
4[ 10.365199, 3] [c186e60f] ? sub_preempt_count+0x1f/0x50
4[ 10.370669, 3] [c149558a] delay_tsc+0x3a/0xc0
6[ 10.371589, 0] android_work: did not send uevent (0 0 (null))
4[ 10.381171, 3] [c14954e3] __const_udelay+0x23/0x30
4[ 10.386207, 3] [c16d043a] mdfld_dsi_send_dcs+0x12a/0x5d0
4[ 10.391760, 3] [c186b6c6] ? _raw_spin_unlock_irqrestore+0x26/0x50
4[ 10.398101, 3] [c16af431] ? ospm_power_using_hw_begin+0xa1/0x350
4[ 10.399053, 3] [c186a49f] ? __mutex_lock_slowpath+0x1ff/0x2f0
4[ 10.399069, 3] [c16bd59e] mdfld_dbi_update_panel+0x21e/0x2d0
4[ 10.399085, 3] [c16b1ae1] mdfld_te_handler_work+0x71/0x80
4[ 10.399099, 3] [c12642be] process_one_work+0xfe/0x3f0
4[ 10.399114, 3] [c16b1a70] ? mdfld_async_flip_te_handler+0xf0/0xf0
Basically, __run_hrtimer has a race with enqueue_hrtimer. When __run_hrtimer
calls
the timer callback fn, another thread might call enqueue_hrtimer or
hrtimer_start
to requeue it, and the timer-state is equal to
HRTIMER_STATE_CALLBACK|HRTIMER_STATE_ENQUEUED,
which causes the BUG_ON(timer-state != HRTIMER_STATE_CALLBACK) checking fails.
The patch fixes it by checking only bit HRTIMER_STATE_CALLBACK.
Signed-off-by: Yanmin Zhang yanmin.zh...@intel.com
Reviewed-by: He, Bo bo...@intel.com
---
kernel/hrtimer.c |2 +-
1 files changed, 1 insertions(+), 1 deletions(-)
diff --git a/kernel/hrtimer.c b/kernel/hrtimer.c
index 6db7a5e..6280184 100644
--- a/kernel/hrtimer.c
+++ b/kernel/hrtimer.c
@@ -1235,7 +1235,7 @@ static void __run_hrtimer(struct hrtimer *timer, ktime_t
*now)
* hrtimer_start_range_ns() or in hrtimer_interrupt()
*/
if (restart != HRTIMER_NORESTART) {
- BUG_ON(timer-state != HRTIMER_STATE_CALLBACK);
+ BUG_ON(!(timer-state HRTIMER_STATE_CALLBACK));
enqueue_hrtimer(timer, base);
}
--
1.7.6
--
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
