[BUG?] false positive in soft lockup detector while unlzma initramfs on slow cpu

[BUG?] false positive in soft lockup detector while unlzma initramfs on slow cpu

[Mike Lykov]

Hi all!

I have "embedded" computer, based on  DM&P Vortex86DX (like 
i486/FPU/600Mhz/256Mb RAM).

I boot it with own builded kernel & own compressed initramfs based on 
ALTLinux. When I used initramfs compressed with gzip -9 it worked good. 
But now I need downsize initramfs, and try to change gzip -9 to lzma -9, 
and encounter a kernel BUG. Maybe it a false positive soft lockup detecting.

I compile kernel with this options:

CONFIG_LOCKUP_DETECTOR=y
CONFIG_HARDLOCKUP_DETECTOR=y
CONFIG_BOOTPARAM_HARDLOCKUP_PANIC=y
CONFIG_BOOTPARAM_HARDLOCKUP_PANIC_VALUE=1
CONFIG_BOOTPARAM_SOFTLOCKUP_PANIC=y
CONFIG_BOOTPARAM_SOFTLOCKUP_PANIC_VALUE=1
CONFIG_DETECT_HUNG_TASK=y
CONFIG_DEFAULT_HUNG_TASK_TIMEOUT=120
CONFIG_BOOTPARAM_HUNG_TASK_PANIC=y
CONFIG_BOOTPARAM_HUNG_TASK_PANIC_VALUE=1

gzip-compressed initramfs boot (~9 sec):

[ 0.344173] pci 0000:00:09.0: Firmware left e100 interrupts enabled; 
disabling
[ 0.435551] Unpacking initramfs...
[ 8.927297] Freeing initrd memory: 22900k freed
[ 9.059939] platform rtc_cmos: registered platform RTC device (no PNP 
device found)

lzma -3 initramfs compressed boot (~ 44 sec)

[ 0.344612] pci 0000:00:09.0: Firmware left e100 interrupts enabled; 
disabling
[ 0.437119] Unpacking initramfs...
[ 5.030218] sched: RT throttling activated
[ 44.175427] Freeing initrd memory: 17580k freed
[ 44.278414] platform rtc_cmos: registered platform RTC device (no PNP 
device found)

lzma -9 initramfs compressed boot (not finished)

[ 0.437111] Unpacking initramfs...
[ 28.056740] BUG: soft lockup - CPU#0 stuck for 23s! [swapper:1]
[ 28.056740]
[ 28.056740] Pid: 1, comm: swapper Not tainted 3.2.32VEP-01ML5-initramfs 
0000017
[ 28.056740] EIP: 0060:[<c03abcbf>] EFLAGS: 00000202 CPU: 0
[ 28.056740] EIP is at unlzma+0x346/0xac0
[ 28.056740] EAX: 0000012f EBX: 00000007 ECX: d481ce6c EDX: 00f70012
[ 28.056740] ESI: 02796020 EDI: 00000100 EBP: ce827f80 ESP: ce827ee8
[ 28.056740] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
[ 28.056740] Process swapper (pid: 1, ti=ce802000 task=ce80b410 
task.ti=ce826000)
[ 28.056740] Stack:
[ 28.056740] 1144f698 d481c0a2 00000000 00000003 cf0eb000 000000e8 
00000028 cf0eb000
[ 28.056740] 00000003 00000000 0adcda49 00004038 d481ce6c d481c000 
d080a000 00000070
[ 28.056740] 00001f00 00000024 ffffffff c03ab896 cfbb37a4 cf0eb000 
cffefa0b 00f04a0b
[ 28.056740] Call Trace:
[ 28.056740] [<c03ab896>] ? gunzip+0x25b/0x25b
[ 28.056740] [<c039ed46>] ? initrd_load+0x3b/0x3b
[ 28.056740] [<c03ab979>] ? rc_get_bit+0x7c/0x7c
[ 28.056740] [<c039f211>] unpack_to_rootfs+0x139/0x237
[ 28.056740] [<c039ef53>] ? write_buffer+0x2c/0x2c
[ 28.056740] [<c039ed46>] ? initrd_load+0x3b/0x3b
[ 28.056740] [<c039e791>] ? do_one_initcall+0x112/0x112
[ 28.056740] [<c039f9b4>] populate_rootfs+0x42/0x85
[ 28.056740] [<c039e6ef>] do_one_initcall+0x70/0x112
[ 28.056740] [<c039f972>] ? do_header+0x1d4/0x1d4
[ 28.056740] [<c039e791>] ? do_one_initcall+0x112/0x112
[ 28.056740] [<c039e810>] kernel_init+0x7f/0xf8
[ 28.056740] [<c02eb2b6>] kernel_thread_helper+0x6/0xd
[ 28.056740] Code: 2b 55 ac eb 02 01 c2 39 c2 73 fa 8b 7d a0 8a 04 17 0f 
b6 c0 89 45 a8 d1 65 a8 8b 7d a8 8b 45 f0 8b 4d 98 81 e7 00 01 00 00 01 
f8 <8d> 94 41 00 02 00 00 8d 4d f0 8d 45 b4 e8 2c fc ff ff 85 c0 74

I cannot find a method to change "watchdog_thresh" parameter 
("compile-time initialized to 10 and configurable through sysctl of the
same name") at boot time ( commandline 
initrd=initram-alt-p6rel2-9.cpio.lzma console=uart,io,0x240,115200n8 
kernel.watchdog_thresh=20 NOT work) and I patch kernel/watchdog.c 
directly (by idea of kirill@shutemov.name)

--- watchdog.c-orig 2012-10-17 06:50:15.000000000 +0400
+++ watchdog.c 2013-01-29 16:41:51.695990261 +0400
@@ -28,7 +28,7 @@
  #include <linux/perf_event.h>

  int watchdog_enabled = 1;

-int __read_mostly watchdog_thresh = 10;
+int __read_mostly watchdog_thresh = 30;

And it DID BOOT (lzma -9 initramfs on kernel with watchdog_thresh = 30):

[ 0.344345] pci 0000:00:09.0: Firmware left e100 interrupts enabled; 
disabling
[ 0.436961] Unpacking initramfs...
[ 38.907093] sched: RT throttling activated
[ 41.206994] Freeing initrd memory: 15380k freed
[ 41.298015] platform rtc_cmos: registered platform RTC device (no PNP 
device found)

So my questions:

1. Are there a BUG in soft lockup detection mechanizm? Changing 
watchdog_thresh to 30 have a side effect in production - D-state 
userspace processes will be detected slowly. Are there a need to 
detecting soft lockups at boot time? Maybe it need after initramfs boot 
only when userspace processes begin to work?

2. How to change watchdog_thresh parameter at boot without patching 
sources? If it necessary (with it side effects) maybe implement it as 
commandline parameter or config compile time parameter?


With best regards
--
Mike

Re: [BUG?] false positive in soft lockup detector while unlzma initramfs on slow cpu

[Don Zickus]

Hi Mike,

On Tue, Jan 29, 2013 at 05:42:43PM +0400, Mike Lykov wrote:
> 
> So my questions:
> 
> 1. Are there a BUG in soft lockup detection mechanizm? Changing
> watchdog_thresh to 30 have a side effect in production - D-state
> userspace processes will be detected slowly. Are there a need to
> detecting soft lockups at boot time? Maybe it need after initramfs
> boot only when userspace processes begin to work?

The softlockup mechanism works scheduling a high priority task that kicks
the softlockups.  If the unzip thread is taking too long, it could
accidentally trip the detection.

Seeing that you are running on a 600 MHz machine, it could be possible.
Though I am not entirely sure how the scheduling works for decompressing
the initramfs.  I wouldn't think it is that high of a priority.

> 
> 2. How to change watchdog_thresh parameter at boot without patching
> sources? If it necessary (with it side effects) maybe implement it
> as commandline parameter or config compile time parameter?

I attached a patch below that allows you to set it a boot time.  Let me
know if this works for you, then I can clean it up and post it properly.

Cheers,
Don


diff --git a/kernel/watchdog.c b/kernel/watchdog.c
index 75a2ab3..e448d63 100644
--- a/kernel/watchdog.c
+++ b/kernel/watchdog.c
@@ -79,6 +79,14 @@ static int __init softlockup_panic_setup(char *str)
 }
 __setup("softlockup_panic=", softlockup_panic_setup);
 
+static int __init watchdog_thresh_setup(char *str)
+{
+	watchdog_thresh = simple_strtoul(str, NULL, 0);
+
+	return 1;
+}
+__setup("watchdog_thresh=", watchdog_thresh_setup);
+
 static int __init nowatchdog_setup(char *str)
 {
 	watchdog_enabled = 0;

Re: [BUG?] false positive in soft lockup detector while unlzma initramfs on slow cpu

[anish kumar]

On Tue, 2013-01-29 at 10:33 -0500, Don Zickus wrote:
> Hi Mike,
> 
> On Tue, Jan 29, 2013 at 05:42:43PM +0400, Mike Lykov wrote:
> > 
> > So my questions:
> > 
> > 1. Are there a BUG in soft lockup detection mechanizm? Changing
> > watchdog_thresh to 30 have a side effect in production - D-state
> > userspace processes will be detected slowly. Are there a need to
> > detecting soft lockups at boot time? Maybe it need after initramfs
you want to disable it then you can do that with nosoftlockup parameter
in kernel-parameters.
> > boot only when userspace processes begin to work?
If my understanding is correct you can do this as well by enabling
watchdog using sysctl.
> 
> The softlockup mechanism works scheduling a high priority task that kicks
> the softlockups.  If the unzip thread is taking too long, it could
> accidentally trip the detection.
> 
> Seeing that you are running on a 600 MHz machine, it could be possible.
> Though I am not entirely sure how the scheduling works for decompressing
> the initramfs.  I wouldn't think it is that high of a priority.
> 
> > 
> > 2. How to change watchdog_thresh parameter at boot without patching
> > sources? If it necessary (with it side effects) maybe implement it
> > as commandline parameter or config compile time parameter?
> 
> I attached a patch below that allows you to set it a boot time.  Let me
> know if this works for you, then I can clean it up and post it properly.
> 
> Cheers,
> Don
> 
> 
> diff --git a/kernel/watchdog.c b/kernel/watchdog.c
> index 75a2ab3..e448d63 100644
> --- a/kernel/watchdog.c
> +++ b/kernel/watchdog.c
> @@ -79,6 +79,14 @@ static int __init softlockup_panic_setup(char *str)
>  }
>  __setup("softlockup_panic=", softlockup_panic_setup);
>  
> +static int __init watchdog_thresh_setup(char *str)
> +{
> +	watchdog_thresh = simple_strtoul(str, NULL, 0);
> +
> +	return 1;
> +}
> +__setup("watchdog_thresh=", watchdog_thresh_setup);
> +
>  static int __init nowatchdog_setup(char *str)
>  {
>  	watchdog_enabled = 0;
Sorry for digressing from the topic but I think there is something wrong
with my understanding or something wrong with the code.So I guess Don
can clarify this.
If I pass this below parameter during boot i.e. setting watchdog_enabled
to zero.
__setup("nowatchdog", nowatchdog_setup);

Now I use sysctl to enable the watchdog then wouldn't the below code
will hinder enabling the watchdog?

static void watchdog_enable_all_cpus(void)
{//snip
        if (watchdog_disabled) {  /* this is zero ?? */
                watchdog_disabled = 0;
//snip
}

Should watchdog_disabled be set to 1?Or is it that we always disable the
watchdog and then enable it?

This code is used from long time and that is the reason I am puzzled as
to how it can be wrong?I think there is some missing piece which I am
not understanding.
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/

Re: [BUG?] false positive in soft lockup detector while unlzma initramfs on slow cpu

[Andrew Morton]

On Tue, 29 Jan 2013 10:33:48 -0500
Don Zickus <dzickus@redhat.com> wrote:

> --- a/kernel/watchdog.c
> +++ b/kernel/watchdog.c
> @@ -79,6 +79,14 @@ static int __init softlockup_panic_setup(char *str)
>  }
>  __setup("softlockup_panic=", softlockup_panic_setup);
>  
> +static int __init watchdog_thresh_setup(char *str)
> +{
> +	watchdog_thresh = simple_strtoul(str, NULL, 0);
> +
> +	return 1;
> +}
> +__setup("watchdog_thresh=", watchdog_thresh_setup);

I wonder if there's some magical way in which we can set any sysctl
from the kernel command line.  Add sys.vm.min_free_kbytes=42 to the
command line, walk the hierarchy late in boot...

To address Mike's bug I suggest we poke a touch_softlockup_watchdog()
into the appropriate place.  Presumably the loop in
lib/decompress_unlzma.c:unlzma().  The decompress code makes me cry.

Re: [BUG?] false positive in soft lockup detector while unlzma initramfs on slow cpu

[Mike Lykov]

29.01.2013 19:33, Don Zickus пишет:

> The softlockup mechanism works scheduling a high priority task that kicks
> the softlockups.  If the unzip thread is taking too long, it could
> accidentally trip the detection.

Inyerestingly, that a decompress of lzma -4 takes longer time than 
decompress lzma -9, and it stated in man lzma(1):
"  On  the  same hardware, the decompression speed is approximately a 
constant number of bytes of compressed data per second.  In other words, 
the better the compression, the faster the  decompression
will  usually  be. "

I tested it on target computer by hand:

lzma -4 compressed: time unlzma initram-alt-p6rel3-4.cpio.lzma
20.94user 1.47system 0:22:45elapsed 99%CPU (...19424maxresidents)k

lzma -9 compressed: time unlzma initram-alt-p6rel3-9.cpio.lzma
19.49user 1.92system 0:21:44elapsed 99%CPU (...241488maxresidents)k

So, it cannot "take too long" because not-working faster than working.
Apparently time not matter, but algorithm complexity?

>> 2. How to change watchdog_thresh parameter at boot without patching
>> sources? If it necessary (with it side effects) maybe implement it
>> as commandline parameter or config compile time parameter?
>
> I attached a patch below that allows you to set it a boot time.  Let me
> know if this works for you, then I can clean it up and post it properly.

It not works for me. I apply this patch, build, use ("int __read_mostly 
watchdog_thresh = 10;"  as in original)
command line:

[    0.000000] Kernel command line: 
initrd=initram-alt-p6rel3-9.cpio.lzma console=uart,io,0x240,115200n8 
kernel.watchdog_thresh=30 BOOT_IMAGE=bzImage-3232-ml5-fwinkrn-wtdg10cmd

Full list of panic:

[   28.057086] BUG: soft lockup - CPU#0 stuck for 23s! [swapper:1]
[   28.057086]
[   28.057086] Pid: 1, comm: swapper Not tainted 
3.2.32VEP-01ML5-initramfs #19
[   28.057086] EIP: 0060:[<c03ab92f>] EFLAGS: 00000212 CPU: 0
[   28.057086] EIP is at rc_get_bit+0x1a/0x7c
[   28.057086] EAX: ce827f34 EBX: ce827f34 ECX: ce827f70 EDX: d481f926
[   28.057086] ESI: d481f926 EDI: ce827f70 EBP: ce827ee0 ESP: ce827ed4
[   28.057086]  DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
[   28.057086] Process swapper (pid: 1, ti=ce802000 task=ce80b410 
task.ti=ce826000)
[   28.057086] Stack:
[   28.057086]  00000001 02857802 d481f86c ce827f80 c03abd13 0b60a3e6 
d481c666 00000000
[   28.057086]  00000003 cf0ea000 00000183 004f1e0a cf0ea000 00000003 
00000000 00e584dd
[   28.057086]  009c2509 d481f86c d481c000 d080a000 00000012 00000002 
000003dd ffffffff
[   28.057086] Call Trace:
[   28.057086]  [<c03abd13>] unlzma+0x382/0xac0
[   28.057086]  [<c03ab8ae>] ? gunzip+0x25b/0x25b
[   28.057086]  [<c039ed46>] ? initrd_load+0x3b/0x3b
[   28.057086]  [<c03ab991>] ? rc_get_bit+0x7c/0x7c
[   28.057086]  [<c039f211>] unpack_to_rootfs+0x139/0x237
[   28.057086]  [<c039ef53>] ? write_buffer+0x2c/0x2c
[   28.057086]  [<c039ed46>] ? initrd_load+0x3b/0x3b
[   28.057086]  [<c039e791>] ? do_one_initcall+0x112/0x112
[   28.057086]  [<c039f9b4>] populate_rootfs+0x42/0x85
[   28.057086]  [<c039e6ef>] do_one_initcall+0x70/0x112
[   28.057086]  [<c039f972>] ? do_header+0x1d4/0x1d4
[   28.057086]  [<c039e791>] ? do_one_initcall+0x112/0x112
[   28.057086]  [<c039e810>] kernel_init+0x7f/0xf8
[   28.057086]  [<c02eb2b6>] kernel_thread_helper+0x6/0xd
[   28.057086] Code: b6 01 41 c1 e2 08 89 4b 04 09 d0 89 43 14 5b 5d c3 
55 89 e5 57 89 cf 56 89 d6 53 89 c3 81 78 18 ff ff ff 00 77 05 e8 b5 ff 
ff ff <8b> 4b 18 0f b7 06 89 ca c1 ea 0b 0f af c2 8b 53 14 39 c2 89 43
[   28.057086] Call Trace:
[   28.057086]  [<c03abd13>] unlzma+0x382/0xac0
[   28.057086]  [<c03ab8ae>] ? gunzip+0x25b/0x25b
[   28.057086]  [<c039ed46>] ? initrd_load+0x3b/0x3b
[   28.057086]  [<c03ab991>] ? rc_get_bit+0x7c/0x7c
[   28.057086]  [<c039f211>] unpack_to_rootfs+0x139/0x237
[   28.057086]  [<c039ef53>] ? write_buffer+0x2c/0x2c
[   28.057086]  [<c039ed46>] ? initrd_load+0x3b/0x3b
[   28.057086]  [<c039e791>] ? do_one_initcall+0x112/0x112
[   28.057086]  [<c039f9b4>] populate_rootfs+0x42/0x85
[   28.057086]  [<c039e6ef>] do_one_initcall+0x70/0x112
[   28.057086]  [<c039f972>] ? do_header+0x1d4/0x1d4
[   28.057086]  [<c039e791>] ? do_one_initcall+0x112/0x112
[   28.057086]  [<c039e810>] kernel_init+0x7f/0xf8
[   28.057086]  [<c02eb2b6>] kernel_thread_helper+0x6/0xd
[   28.057086] Kernel panic - not syncing: softlockup: hung tasks
[   28.057086] Pid: 1, comm: swapper Not tainted 
3.2.32VEP-01ML5-initramfs #19
[   28.057086] Call Trace:
[   28.057086]  [<c02e91c4>] ? printk+0xf/0x11
[   28.057086]  [<c02e90c0>] panic+0x50/0x145
[   28.057086]  [<c012fa9b>] watchdog_timer_fn+0xf2/0x10f
[   28.057086]  [<c0124ae0>] hrtimer_run_queues+0x13d/0x1bc
[   28.057086]  [<c01193cf>] run_local_timers+0x8/0x14
[   28.057086]  [<c01193f6>] update_process_times+0x1b/0x4e
[   28.057086]  [<c012b6d2>] tick_periodic.clone.20+0x52/0x54
[   28.057086]  [<c012b6e1>] tick_handle_periodic+0xd/0x5b
[   28.057086]  [<c010339f>] timer_interrupt+0x13/0x1a
[   28.057086]  [<c013032b>] handle_irq_event_percpu+0x24/0xfb
[   28.057086]  [<c0131a80>] ? handle_simple_irq+0x3f/0x3f
[   28.057086]  [<c013041e>] handle_irq_event+0x1c/0x26
[   28.057086]  [<c0131aeb>] handle_level_irq+0x6b/0x75
[   28.057086]  <IRQ>  [<c0102f62>] ? do_IRQ+0x34/0x74
[   28.057086]  [<c02eb2a9>] ? common_interrupt+0x29/0x30
[   28.057086]  [<c03ab92f>] ? rc_get_bit+0x1a/0x7c
[   28.057086]  [<c03abd13>] ? unlzma+0x382/0xac0
[   28.057086]  [<c03ab8ae>] ? gunzip+0x25b/0x25b
[   28.057086]  [<c039ed46>] ? initrd_load+0x3b/0x3b
[   28.057086]  [<c03ab991>] ? rc_get_bit+0x7c/0x7c
[   28.057086]  [<c039f211>] ? unpack_to_rootfs+0x139/0x237
[   28.057086]  [<c039ef53>] ? write_buffer+0x2c/0x2c
[   28.057086]  [<c039ed46>] ? initrd_load+0x3b/0x3b
[   28.057086]  [<c039e791>] ? do_one_initcall+0x112/0x112
[   28.057086]  [<c039f9b4>] ? populate_rootfs+0x42/0x85
[   28.057086]  [<c039e6ef>] ? do_one_initcall+0x70/0x112
[   28.057086]  [<c039f972>] ? do_header+0x1d4/0x1d4
[   28.057086]  [<c039e791>] ? do_one_initcall+0x112/0x112
[   28.057086]  [<c039e810>] ? kernel_init+0x7f/0xf8
[   28.057086]  [<c02eb2b6>] ? kernel_thread_helper+0x6/0xd


> diff --git a/kernel/watchdog.c b/kernel/watchdog.c
> index 75a2ab3..e448d63 100644
> --- a/kernel/watchdog.c
> +++ b/kernel/watchdog.c
> @@ -79,6 +79,14 @@ static int __init softlockup_panic_setup(char *str)
>   }
>   __setup("softlockup_panic=", softlockup_panic_setup);
>
> +static int __init watchdog_thresh_setup(char *str)
> +{
> +	watchdog_thresh = simple_strtoul(str, NULL, 0);
> +
> +	return 1;
> +}
> +__setup("watchdog_thresh=", watchdog_thresh_setup);
> +
>   static int __init nowatchdog_setup(char *str)
>   {
>   	watchdog_enabled = 0;

--
Mike

Re: [BUG?] false positive in soft lockup detector while unlzma initramfs on slow cpu

[Don Zickus]

On Wed, Jan 30, 2013 at 01:39:23PM +0400, Mike Lykov wrote:
> 29.01.2013 19:33, Don Zickus пишет:
> 
> >The softlockup mechanism works scheduling a high priority task that kicks
> >the softlockups.  If the unzip thread is taking too long, it could
> >accidentally trip the detection.
> 
> Inyerestingly, that a decompress of lzma -4 takes longer time than
> decompress lzma -9, and it stated in man lzma(1):
> "  On  the  same hardware, the decompression speed is approximately
> a constant number of bytes of compressed data per second.  In other
> words, the better the compression, the faster the  decompression
> will  usually  be. "
> 
> I tested it on target computer by hand:
> 
> lzma -4 compressed: time unlzma initram-alt-p6rel3-4.cpio.lzma
> 20.94user 1.47system 0:22:45elapsed 99%CPU (...19424maxresidents)k
> 
> lzma -9 compressed: time unlzma initram-alt-p6rel3-9.cpio.lzma
> 19.49user 1.92system 0:21:44elapsed 99%CPU (...241488maxresidents)k
> 
> So, it cannot "take too long" because not-working faster than working.
> Apparently time not matter, but algorithm complexity?
> 
> >>2. How to change watchdog_thresh parameter at boot without patching
> >>sources? If it necessary (with it side effects) maybe implement it
> >>as commandline parameter or config compile time parameter?
> >
> >I attached a patch below that allows you to set it a boot time.  Let me
> >know if this works for you, then I can clean it up and post it properly.
> 
> It not works for me. I apply this patch, build, use ("int
> __read_mostly watchdog_thresh = 10;"  as in original)
> command line:
> 
> [    0.000000] Kernel command line:
> initrd=initram-alt-p6rel3-9.cpio.lzma console=uart,io,0x240,115200n8
> kernel.watchdog_thresh=30

I have never seen usage like 'kernel.watchdog_thresh=30'.  Could you try
'watchdog_thresh=30' instead?

I also attached another patch as suggested by Andrew to add a
touch_softlockup_watchdog in the unlzma routine.  Probably makes things
run a little slower.  Compiled tested only.

Cheers,
Don

diff --git a/lib/decompress_unlzma.c b/lib/decompress_unlzma.c
index 32adb73..313f4fa 100644
--- a/lib/decompress_unlzma.c
+++ b/lib/decompress_unlzma.c
@@ -36,6 +36,7 @@
 #endif /* STATIC */
 
 #include <linux/decompress/mm.h>
+#include <linux/nmi.h>
 
 #define	MIN(a, b) (((a) < (b)) ? (a) : (b))
 
@@ -648,6 +649,7 @@ STATIC inline int INIT unlzma(unsigned char *buf, int in_len,
 		}
 		if (rc.buffer_size <= 0)
 			goto exit_3;
+		touch_softlockup_watchdog();
 	}
 
 	if (posp)

Re: [BUG?] false positive in soft lockup detector while unlzma initramfs on slow cpu

[Don Zickus]

On Tue, Jan 29, 2013 at 10:48:27PM +0530, anish kumar wrote:
> Sorry for digressing from the topic but I think there is something wrong
> with my understanding or something wrong with the code.So I guess Don
> can clarify this.
> If I pass this below parameter during boot i.e. setting watchdog_enabled
> to zero.
> __setup("nowatchdog", nowatchdog_setup);
> 
> Now I use sysctl to enable the watchdog then wouldn't the below code
> will hinder enabling the watchdog?
> 
> static void watchdog_enable_all_cpus(void)
> {//snip
>         if (watchdog_disabled) {  /* this is zero ?? */
>                 watchdog_disabled = 0;
> //snip
> }
> 
> Should watchdog_disabled be set to 1?Or is it that we always disable the
> watchdog and then enable it?

It seems like a bug, so does something like this fix it?  There is
probably a better way to handle the internal representation of the
watchdog state (watchdog_disable) and the procfs version
(watchdog_enable), but I just can't think of something right now. :-(

Cheers,
Don


diff --git a/kernel/watchdog.c b/kernel/watchdog.c
index 75a2ab3..d287726 100644
--- a/kernel/watchdog.c
+++ b/kernel/watchdog.c
@@ -82,6 +82,7 @@ __setup("softlockup_panic=", softlockup_panic_setup);
 static int __init nowatchdog_setup(char *str)
 {
 	watchdog_enabled = 0;
+	watchdog_disabled =1;
 	return 1;
 }
 __setup("nowatchdog", nowatchdog_setup);

Re: [BUG?] false positive in soft lockup detector while unlzma initramfs on slow cpu

[anish kumar]

On Wed, 2013-01-30 at 10:51 -0500, Don Zickus wrote:
> On Tue, Jan 29, 2013 at 10:48:27PM +0530, anish kumar wrote:
> > Sorry for digressing from the topic but I think there is something wrong
> > with my understanding or something wrong with the code.So I guess Don
> > can clarify this.
> > If I pass this below parameter during boot i.e. setting watchdog_enabled
> > to zero.
> > __setup("nowatchdog", nowatchdog_setup);
> > 
> > Now I use sysctl to enable the watchdog then wouldn't the below code
> > will hinder enabling the watchdog?
> > 
> > static void watchdog_enable_all_cpus(void)
> > {//snip
> >         if (watchdog_disabled) {  /* this is zero ?? */
> >                 watchdog_disabled = 0;
> > //snip
> > }
> > 
> > Should watchdog_disabled be set to 1?Or is it that we always disable the
> > watchdog and then enable it?
> 
> It seems like a bug, so does something like this fix it?  There is
> probably a better way to handle the internal representation of the
> watchdog state (watchdog_disable) and the procfs version
> (watchdog_enable), but I just can't think of something right now. :-(
> 
> Cheers,
> Don
> 
> 
> diff --git a/kernel/watchdog.c b/kernel/watchdog.c
> index 75a2ab3..d287726 100644
> --- a/kernel/watchdog.c
> +++ b/kernel/watchdog.c
> @@ -82,6 +82,7 @@ __setup("softlockup_panic=", softlockup_panic_setup);
>  static int __init nowatchdog_setup(char *str)
>  {
>  	watchdog_enabled = 0;
> +	watchdog_disabled =1;
I don't know if this will work or not but while going through the code I
spotted this.I will think of something better if I couldn't think of
anything better than anyway we have this patch.
>  	return 1;
>  }
>  __setup("nowatchdog", nowatchdog_setup);

Re: [BUG?] false positive in soft lockup detector while unlzma initramfs on slow cpu

[Ingo Molnar]

* Andrew Morton <akpm@linux-foundation.org> wrote:

> On Tue, 29 Jan 2013 10:33:48 -0500
> Don Zickus <dzickus@redhat.com> wrote:
> 
> > --- a/kernel/watchdog.c
> > +++ b/kernel/watchdog.c
> > @@ -79,6 +79,14 @@ static int __init softlockup_panic_setup(char *str)
> >  }
> >  __setup("softlockup_panic=", softlockup_panic_setup);
> >  
> > +static int __init watchdog_thresh_setup(char *str)
> > +{
> > +	watchdog_thresh = simple_strtoul(str, NULL, 0);
> > +
> > +	return 1;
> > +}
> > +__setup("watchdog_thresh=", watchdog_thresh_setup);
> 
> I wonder if there's some magical way in which we can set any 
> sysctl from the kernel command line.  Add 
> sys.vm.min_free_kbytes=42 to the command line, walk the 
> hierarchy late in boot...

A facility like that would be totally awesome - we could remove 
a lot of duplicated and outright inconsistent (often missing) 
__setup() hackery that way.

Single source of information and all that.

Thanks,

	Ingo

Re: [BUG?] false positive in soft lockup detector while unlzma initramfs on slow cpu

[Mike Lykov]

30.01.2013 19:40, Don Zickus пишет:
 > I have never seen usage like 'kernel.watchdog_thresh=30'.  Could you try
 > 'watchdog_thresh=30' instead?

Ok. "kernel.watchdog_thresh=30" is a sysctl presentation, i mixed them 
wrongly.

Your patch about cmd support for 'watchdog_thresh=30' working. I tested 
it: parameter applies and lzma -9 initramfs loading successfully.
If I delete parameter from cmdline - same kernel not boot.

 > I also attached another patch as suggested by Andrew to add a
 > touch_softlockup_watchdog in the unlzma routine.  Probably makes things
 > run a little slower.  Compiled tested only.

In my case (3.2.32) it cannot compile:

   LD      arch/x86/boot/compressed/vmlinux
arch/x86/boot/compressed/misc.o: In function `decompress_kernel':
misc.c:(.text+0x993): undefined reference to `touch_softlockup_watchdog'

---
Mike



 >
 > Cheers,
 > Don
 >
 > diff --git a/lib/decompress_unlzma.c b/lib/decompress_unlzma.c
 > index 32adb73..313f4fa 100644
 > --- a/lib/decompress_unlzma.c
 > +++ b/lib/decompress_unlzma.c
 > @@ -36,6 +36,7 @@
 >   #endif /* STATIC */
 >
 >   #include<linux/decompress/mm.h>
 > +#include<linux/nmi.h>
 >
 >   #define	MIN(a, b) (((a)<  (b)) ? (a) : (b))
 >
 > @@ -648,6 +649,7 @@ STATIC inline int INIT unlzma(unsigned char *buf, 
int in_len,
 >   		}
 >   		if (rc.buffer_size<= 0)
 >   			goto exit_3;
 > +		touch_softlockup_watchdog();
 >   	}
 >
 >   	if (posp)

Re: [BUG?] false positive in soft lockup detector while unlzma initramfs on slow cpu

[Don Zickus]

On Thu, Jan 31, 2013 at 03:21:02PM +0400, Mike Lykov wrote:
> 
> 30.01.2013 19:40, Don Zickus пишет:
> > I have never seen usage like 'kernel.watchdog_thresh=30'.  Could you try
> > 'watchdog_thresh=30' instead?
> 
> Ok. "kernel.watchdog_thresh=30" is a sysctl presentation, i mixed
> them wrongly.
> 
> Your patch about cmd support for 'watchdog_thresh=30' working. I
> tested it: parameter applies and lzma -9 initramfs loading
> successfully.
> If I delete parameter from cmdline - same kernel not boot.

Good to know.

> 
> > I also attached another patch as suggested by Andrew to add a
> > touch_softlockup_watchdog in the unlzma routine.  Probably makes things
> > run a little slower.  Compiled tested only.
> 
> In my case (3.2.32) it cannot compile:
> 
>   LD      arch/x86/boot/compressed/vmlinux
> arch/x86/boot/compressed/misc.o: In function `decompress_kernel':
> misc.c:(.text+0x993): undefined reference to `touch_softlockup_watchdog'

I think Andrew's suggestion is a better approach which is add the
touch_softlockup_watchdog.  So I would have to see you .config file to
understand the compile warning.

Cheers,
Don

Re: [BUG?] false positive in soft lockup detector while unlzma initramfs on slow cpu

[Mike Lykov]

[-- Attachment #1: Type: text/plain, Size: 4105 bytes --]

31.01.2013 18:46, Don Zickus пишет:

>>> I also attached another patch as suggested by Andrew to add a
>>> touch_softlockup_watchdog in the unlzma routine.  Probably makes things
>>> run a little slower.  Compiled tested only.
>>
>> In my case (3.2.32) it cannot compile:
>>
>>    LD      arch/x86/boot/compressed/vmlinux
>> arch/x86/boot/compressed/misc.o: In function `decompress_kernel':
>> misc.c:(.text+0x993): undefined reference to `touch_softlockup_watchdog'
>
> I think Andrew's suggestion is a better approach which is add the
> touch_softlockup_watchdog.  So I would have to see you .config file to
> understand the compile warning.

Attached lzma-compressed .config with this letter.

Kirill@ advices me to insert some stub to success compile:

--- arch/x86/boot/compressed/misc.c-orig 2013-01-30 15:23:41.639993355 +0400
+++ arch/x86/boot/compressed/misc.c 2013-01-30 15:09:24.647993671 +0400
@@ -147,6 +147,10 @@
  #include "../../../../lib/decompress_unlzo.c"
  #endif

+void touch_softlockup_watchdog()
+{
+}
+
  static void scroll(void)
{
         int i;

And then really compile and boot. But... another problem arises.
On that motherboard 
(http://www.fastwel.com/products/433089/433197/433198/433223.html), by 
accident, soldered NAND-flash module and kernel pata driver don't 
recognize it (and it not needed now).
(pata_rdc, needed to built-in IDE interface, and it works with IDE).

But it try to request it, wait for ~30sec, request again, fail, and go 
on further booting.
Looks like:
Apr 11 18:18:49 vep01 kernel: [ 9.515104] ata1.01: CFA: 1024MB ATA Flash 
Disk, ADBA408J, max MWDMA2
...
Apr 11 18:18:50 vep01 kernel: [ 9.673242] sd 0:0:1:0: [sdb] 2001888 
512-byte logical blocks: (1.02 GB/977 MiB)
...
Apr 11 18:18:50 vep01 kernel: [ 40.058092] ata1: lost interrupt (Status 
0x58)
Apr 11 18:18:50 vep01 kernel: [ 40.113062] ata1.01: exception Emask 0x0 
SAct 0x0 SErr 0x0 action 0x6 frozen
Apr 11 18:18:50 vep01 kernel: [ 40.120401] ata1.01: failed command: READ DMA
Apr 11 18:18:50 vep01 kernel: [ 40.372722] ata1.01: device reported 
invalid CHS sector 0

And so.. if i not patch touch_softlockup_watchdog as above - it boot on 
this stage. If i patch it  (your patch + as above to compile) - it catch 
softlockup at requesting that flash and waiting (request flash going 
after usb hid load usually)

[ 42.591095] input: HID 04f3:0103 as 
/devices/pci0000:00/0000:00:0a.0/usb3/3-2/3-2:1.1/input/input2
[ 42.601428] generic-usb 0003:04F3:0103.0002: input: USB HID v1.10 
Device [HID 04f3:0103] on usb-0000:00:0a.0-2/input1
[ 68.064357] BUG: soft lockup - CPU#0 stuck for 22s! [swapper:0]
[ 68.064357]
[ 68.064357] Pid: 0, comm: swapper Not tainted 3.2.32VEP-01ML5-initramfs 
0000020
[ 68.064357] EIP: 0060:[<c0106009>] EFLAGS: 00000246 CPU: 0
[ 68.064357] EIP is at default_idle+0x29/0x3e
[ 68.064357] EAX: 00000000 EBX: c03b9118 ECX: 00000000 EDX: c0380300
[ 68.064357] ESI: 0003e800 EDI: c037c000 EBP: c037bfc0 ESP: c037bfc0
[ 68.064357] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
[ 68.064357] Process swapper (pid: 0, ti=ce802000 task=c0380300 
task.ti=c037a000)
[ 68.064357] Stack:
[ 68.064357] c037bfc8 c0101413 c037bfd0 c02e385e c037bfe0 c039e67a 
c03b9118 0fff0000
[ 68.064357] c037bff8 c039e0b0 0f0ee000 00000000 00000000 0003e800 
00605003 00000000
[ 68.064357] Call Trace:
[ 68.064357] [<c0101413>] cpu_idle+0x21/0x36
[ 68.064357] [<c02e385e>] rest_init+0x52/0x54
[ 68.064357] [<c039e67a>] start_kernel+0x26b/0x270
[ 68.064357] [<c039e0b0>] i386_start_kernel+0xb0/0xb7
[ 68.064357] Code: 5d c3 83 3d 98 b6 3c c0 00 55 89 e5 75 2d 80 3d c5 b3 
39 c0 00 74 24 89 e0 25 00 e0 ff ff 83 60 0c fb 8b 40 08 a8 08 75 04 fb 
f4 <eb> 01 fb 89 e0 25 00 e0 ff ff 83 48 0c 04 eb 03 fb f3 90 5d c3
[ 68.064357] Call Trace:
[ 68.064357] [<c0101413>] cpu_idle+0x21/0x36
[ 68.064357] [<c02e385e>] rest_init+0x52/0x54
[ 68.064357] [<c039e67a>] start_kernel+0x26b/0x270
[ 68.064357] [<c039e0b0>] i386_start_kernel+0xb0/0xb7
[ 68.064357] Kernel panic - not syncing: softlockup: hung tasks


So I do not know to do with it, someone else will pay attention to it.



---
Mike




[-- Attachment #2: config.lzma --]
[-- Type: application/x-lzma, Size: 9636 bytes --]

Re: [BUG?] false positive in soft lockup detector while unlzma initramfs on slow cpu

[Don Zickus]

On Fri, Feb 01, 2013 at 02:44:43PM +0400, Mike Lykov wrote:
> 31.01.2013 18:46, Don Zickus пишет:
> 
> >>>I also attached another patch as suggested by Andrew to add a
> >>>touch_softlockup_watchdog in the unlzma routine.  Probably makes things
> >>>run a little slower.  Compiled tested only.
> >>
> >>In my case (3.2.32) it cannot compile:
> >>
> >>   LD      arch/x86/boot/compressed/vmlinux
> >>arch/x86/boot/compressed/misc.o: In function `decompress_kernel':
> >>misc.c:(.text+0x993): undefined reference to `touch_softlockup_watchdog'
> >
> >I think Andrew's suggestion is a better approach which is add the
> >touch_softlockup_watchdog.  So I would have to see you .config file to
> >understand the compile warning.
> 
> Attached lzma-compressed .config with this letter.
> 
> Kirill@ advices me to insert some stub to success compile:
> 
> --- arch/x86/boot/compressed/misc.c-orig 2013-01-30 15:23:41.639993355 +0400
> +++ arch/x86/boot/compressed/misc.c 2013-01-30 15:09:24.647993671 +0400
> @@ -147,6 +147,10 @@
>  #include "../../../../lib/decompress_unlzo.c"
>  #endif
> 
> +void touch_softlockup_watchdog()
> +{
> +}
> +
>  static void scroll(void)
> {
>         int i;

Hmm, that seems to make sense.  I was expecting that problem to pop up on
my end but didn't see.  I just asusmed the boot code didn't use that
decompressor.

Though I am not sure why that is leading to your other PATA problems
below.  Did you have similar problems when you used other decompression
levels?  I am not sure how to explain the differences.

Cheers,
Don
> 
> And then really compile and boot. But... another problem arises.
> On that motherboard
> (http://www.fastwel.com/products/433089/433197/433198/433223.html),
> by accident, soldered NAND-flash module and kernel pata driver don't
> recognize it (and it not needed now).
> (pata_rdc, needed to built-in IDE interface, and it works with IDE).
> 
> But it try to request it, wait for ~30sec, request again, fail, and
> go on further booting.
> Looks like:
> Apr 11 18:18:49 vep01 kernel: [ 9.515104] ata1.01: CFA: 1024MB ATA
> Flash Disk, ADBA408J, max MWDMA2
> ...
> Apr 11 18:18:50 vep01 kernel: [ 9.673242] sd 0:0:1:0: [sdb] 2001888
> 512-byte logical blocks: (1.02 GB/977 MiB)
> ...
> Apr 11 18:18:50 vep01 kernel: [ 40.058092] ata1: lost interrupt
> (Status 0x58)
> Apr 11 18:18:50 vep01 kernel: [ 40.113062] ata1.01: exception Emask
> 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
> Apr 11 18:18:50 vep01 kernel: [ 40.120401] ata1.01: failed command: READ DMA
> Apr 11 18:18:50 vep01 kernel: [ 40.372722] ata1.01: device reported
> invalid CHS sector 0
> 
> And so.. if i not patch touch_softlockup_watchdog as above - it boot
> on this stage. If i patch it  (your patch + as above to compile) -
> it catch softlockup at requesting that flash and waiting (request
> flash going after usb hid load usually)
> 
> [ 42.591095] input: HID 04f3:0103 as
> /devices/pci0000:00/0000:00:0a.0/usb3/3-2/3-2:1.1/input/input2
> [ 42.601428] generic-usb 0003:04F3:0103.0002: input: USB HID v1.10
> Device [HID 04f3:0103] on usb-0000:00:0a.0-2/input1
> [ 68.064357] BUG: soft lockup - CPU#0 stuck for 22s! [swapper:0]
> [ 68.064357]
> [ 68.064357] Pid: 0, comm: swapper Not tainted
> 3.2.32VEP-01ML5-initramfs 0000020
> [ 68.064357] EIP: 0060:[<c0106009>] EFLAGS: 00000246 CPU: 0
> [ 68.064357] EIP is at default_idle+0x29/0x3e
> [ 68.064357] EAX: 00000000 EBX: c03b9118 ECX: 00000000 EDX: c0380300
> [ 68.064357] ESI: 0003e800 EDI: c037c000 EBP: c037bfc0 ESP: c037bfc0
> [ 68.064357] DS: 007b ES: 007b FS: 0000 GS: 0000 SS: 0068
> [ 68.064357] Process swapper (pid: 0, ti=ce802000 task=c0380300
> task.ti=c037a000)
> [ 68.064357] Stack:
> [ 68.064357] c037bfc8 c0101413 c037bfd0 c02e385e c037bfe0 c039e67a
> c03b9118 0fff0000
> [ 68.064357] c037bff8 c039e0b0 0f0ee000 00000000 00000000 0003e800
> 00605003 00000000
> [ 68.064357] Call Trace:
> [ 68.064357] [<c0101413>] cpu_idle+0x21/0x36
> [ 68.064357] [<c02e385e>] rest_init+0x52/0x54
> [ 68.064357] [<c039e67a>] start_kernel+0x26b/0x270
> [ 68.064357] [<c039e0b0>] i386_start_kernel+0xb0/0xb7
> [ 68.064357] Code: 5d c3 83 3d 98 b6 3c c0 00 55 89 e5 75 2d 80 3d
> c5 b3 39 c0 00 74 24 89 e0 25 00 e0 ff ff 83 60 0c fb 8b 40 08 a8 08
> 75 04 fb f4 <eb> 01 fb 89 e0 25 00 e0 ff ff 83 48 0c 04 eb 03 fb f3
> 90 5d c3
> [ 68.064357] Call Trace:
> [ 68.064357] [<c0101413>] cpu_idle+0x21/0x36
> [ 68.064357] [<c02e385e>] rest_init+0x52/0x54
> [ 68.064357] [<c039e67a>] start_kernel+0x26b/0x270
> [ 68.064357] [<c039e0b0>] i386_start_kernel+0xb0/0xb7
> [ 68.064357] Kernel panic - not syncing: softlockup: hung tasks
> 
> 
> So I do not know to do with it, someone else will pay attention to it.
> 
> 
> 
> ---
> Mike
> 
> 
> 

Re: [BUG?] false positive in soft lockup detector while unlzma initramfs on slow cpu

[Mike Lykov]

01.02.2013 19:59, Don Zickus пишет:
 > Hmm, that seems to make sense.  I was expecting that problem to pop up on
 > my end but didn't see.  I just asusmed the boot code didn't use that
 > decompressor.

Can you accumulate all our discussion and create one right-coded, 
kernelcode-styled patch?

 > Though I am not sure why that is leading to your other PATA problems
 > below.  Did you have similar problems when you used other decompression
 > levels?

In past - no. But I not test this last  kernel variant with other level.

 > I am not sure how to explain the differences.

I think this is similar as decompress:
Kernel stop and wait next try in "default_idle()" for 20-30 sec, and in 
this moment softlockup detector panics ;)

But without patch for touch_softlockup_watchdog in 
decompress_unlzma+misc.c it works (try, fail, pause, try, fail, go on).

-- 
Mike
Sapienti sat.