Kernel went nuts, dumping thousands of Emergency Thaw messages, malformed klog messages and stack traces into syslog

[Jeff Lane ]

This morning, the kernel went absolutely nuts on my Alienware M15x. It dumped literally millions of Emergency Thaw messages into syslog, many of which were malformed, like so:

bladernr@klaatu:~/Downloads$ grep "Emergency Thaw" /var/log/syslog |wc -l
16134519

Apr 17 11:40:05 klaatu kernel: [87482.066719] Emergency Thaw on sda6
Apr 17 11:40:05 klaatu kernel: [87482.066722] Emergency Thaw on sda6
Apr 17 11:40:05 klaatu kernel: [87482.066725] Emergency Thaw on sda6
Apr 17 11:40:05 klaatu kernel: [87482.066729] Emergenaw on sda6
Apr 17 11:40:05 klaatu kernel: aw on sda6
Apr 17 11:40:05 klaatu kernel: [8748aw on sda6
Apr 17 11:40:05 klaatu kernel: <aw on sda6
Apr 17 11:40:05 klaatu kernel: aw on sda6
Apr 17 11:40:05 klaatu kernel: [aw on sdaaw on sda6aw on sda6
Apr 17 11:40:05 klaatu kernel: <aw on sda6
Apr 17 11:40:05 klaatu kernel: <4aw on aw on sda6
Apr 17 11:40:05 klaatu kernel: <4aw on sda6
Apr 17 11:40:05 klaatu kernel: aw on sda6
Apr 17 11:40:05 klaatu kernel: [87482.aw on sda6
Apr 17 11:40:05 klaatu kernel: aw on sda6
Apr 17 11:40:05 klaatu kernel: aw on sda6
Apr 17 11:40:05 klaatu kernel: <aw on sda6
Apr 17 11:40:05 klaatu kernel: last message repeated 2 times
Apr 17 11:40:05 klaatu kernel: [87482.066793] Emergency Thaw on sda6
Apr 17 11:40:05 klaatu kernel: [87482.066796] Emergency Thaw on sda6
Apr 17 11:40:05 klaatu kernel: [87482.066800] Emergency Thaw on sda6

Also, there are a lot of malformed stack traces... it's as though the kernel was dumping things to syslog faster than syslog could keep up, causing essentially a system wide denial of service and the various syslog messages were all munged together. They're so bad I can't really paste them here, so check out lines 581150-581201 from the syslog I've attached...

I have no idea what kicked this off, but it made the system unusable, forcing a reboot to clear it up.
---
AlsaVersion: Advanced Linux Sound Architecture Driver Version 1.0.24.
ApportVersion: 2.0.1-0ubuntu5
Architecture: amd64
ArecordDevices:
 **** List of CAPTURE Hardware Devices ****
 card 0: Intel [HDA Intel], device 0: STAC92xx Analog [STAC92xx Analog]
   Subdevices: 1/1
   Subdevice #0: subdevice #0
AudioDevicesInUse:
 USER PID ACCESS COMMAND
 /dev/snd/controlC1: bladernr 2261 F.... pulseaudio
 /dev/snd/controlC0: bladernr 2261 F.... pulseaudio
Card0.Amixer.info:
 Card hw:0 'Intel'/'HDA Intel at 0xf0f20000 irq 48'
   Mixer name : 'IDT 92HD83C1X5'
   Components : 'HDA:111d7604,102802a2,00100104'
   Controls : 19
   Simple ctrls : 10
Card1.Amixer.info:
 Card hw:1 'NVidia'/'HDA NVidia at 0xcdefc000 irq 16'
   Mixer name : 'Nvidia GPU 0a HDMI/DP'
   Components : 'HDA:10de000a,10de0101,00100100'
   Controls : 24
   Simple ctrls : 4
CheckboxSubmission: b23ce36b87dcd99529399d76f1dc5b1d
CheckboxSystem: 5f30ac82cc48ed91bb5240b61cb4e295
DistroRelease: Ubuntu 12.04
HibernationDevice: RESUME=UUID=c2f4cbc3-a904-4dbf-acd4-0a28f482d683
InstallationMedia: Ubuntu 12.04 LTS "Precise Pangolin" - Alpha amd64 (20120307)
MachineType: Alienware M15x
NonfreeKernelModules: nvidia
Package: linux (not installed)
ProcEnviron:
 TERM=xterm
 PATH=(custom, user)
 LANG=en_US.UTF-8
 SHELL=/bin/bash
ProcFB: 0 VESA VGA
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-3.2.0-23-generic root=UUID=e7eedf5d-5aad-4230-b123-47162b1acea6 ro quiet splash vt.handoff=7
ProcVersionSignature: Ubuntu 3.2.0-23.36-generic 3.2.14
RelatedPackageVersions:
 linux-restricted-modules-3.2.0-23-generic N/A
 linux-backports-modules-3.2.0-23-generic N/A
 linux-firmware 1.79
SourcePackage: linux
Tags: precise precise
Uname: Linux 3.2.0-23-generic x86_64
UpgradeStatus: No upgrade log present (probably fresh install)
UserGroups: adm cdrom dip lpadmin plugdev sambashare sudo
WifiSyslog:
 Apr 18 07:47:23 klaatu dhclient: DHCPREQUEST of 192.168.1.11 on eth0 to 192.168.1.1 port 67
 Apr 18 07:47:23 klaatu dhclient: DHCPACK of 192.168.1.11 from 192.168.1.1
 Apr 18 07:47:23 klaatu dhclient: bound to 192.168.1.11 -- renewal in 35376 seconds.
 Apr 18 12:06:41 klaatu kernel: [86250.265846] chrome[29295]: segfault at 28 ip 00007f2c482ff820 sp 00007fffd32e8280 error 4 in chrome[7f2c46080000+4094000]
dmi.bios.date: 08/24/2010
dmi.bios.vendor: Alienware
dmi.bios.version: A08
dmi.board.vendor: Alienware
dmi.board.version: A08
dmi.chassis.type: 8
dmi.chassis.vendor: Alienware
dmi.chassis.version: A08
dmi.modalias: dmi:bvnAlienware:bvrA08:bd08/24/2010:svnAlienware:pnM15x:pvrA08:rvnAlienware:rn:rvrA08:cvnAlienware:ct8:cvrA08:
dmi.product.name: M15x
dmi.product.version: A08
dmi.sys.vendor: Alienware

[Jeff Lane  (bladernr)]

Also, there were a lot of what appeared to be SysRq help messages posted to the syslog file as well, like this:

Apr 17 11:40:02 klaatu kernel: [87478.935764] atkbd serio2: Use 'setkeycodes 08 <keycode>' to make it known.
Apr 17 11:40:02 klaatu kernel: [87478.936870] SysRq : HELP : loglevel(0-9) reBoot Crash terminate-all-tasks(E) memory-full-oom-kill(F) kill-all-tasks(I) thaw-filesystems(J) saK show-backtrace-all-active-cpus(L) show-memory-usage(M) nice-all-RT-tasks(N) powerOff show-registers(P) show-all-timers(Q) unRaw Sync show-task-states(T) Unmount show-blocked-tasks(W) dump-ftrace-buffer(Z)
Apr 17 11:40:02 klaatu kernel: [87478.938151] atkbd serio2: Unknown key pressed (raw set 2, code 0x0 on isa0060/serio2).

[Brad Figg (brad-figg)]

This bug is missing log files that will aid in diagnosing the problem. From a terminal window please run:

apport-collect 984273

and then change the status of the bug to 'Confirmed'.

If, due to the nature of the issue you have encountered, you are unable to run this command, please add a comment stating that fact and change the bug status to 'Confirmed'.

This change has been made by an automated script, maintained by the Ubuntu Kernel Team.

[Joseph Salisbury (jsalisbury)]

I wonder if this could be related to the other bug you opened, bug 984265 ? Maybe the keyboard is sending random keystrokes when it is expierencing the symptoms of the other bug.

I requested that you test the upstream kernel in the other bug. If possible, could you also test the latest oneiric kernel, to see if the issue is there or possible hardware related?

[Jeff Lane  (bladernr)]

On 04/17/2012 03:47 PM, Joseph Salisbury wrote:
> I wonder if this could be related to the other bug you opened, bug
> 984265 ? Maybe the keyboard is sending random keystrokes when it is
> expierencing the symptoms of the other bug.
>
> I requested that you test the upstream kernel in the other bug. If
> possible, could you also test the latest oneiric kernel, to see if the
> issue is there or possible hardware related?

Possible. I pulled the 3.3.0 kernel and got an email to try 3.4.0 :/ so
I installed THAT one... heh... We'll see.

beyond the latest upstream, are you asking me to run the latest Oneiric
kernel on Precise?

--
Jeff Lane - Hardware Certification Engineer and Test Tools Developer
Ubuntu Ham: W4KDH
Freenode IRC: bladernr or bladernr_
gpg: 1024D/3A14B2DD 8C88 B076 0DD7 B404 1417 C466 4ABD 3635 3A14 B2DD

[Joseph Salisbury (jsalisbury)]

Yes, it would be good to see if this issue exists with the Oneiric kernel. That can tell us if it is a regression if Oneiric does not have the bug. It could also indicate a hardware issue if the bug also exists in Oneiric.

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

apport information

[Jeff Lane  (bladernr)]

Well, I ran the mainline 3.4.0 overnight with no ill effects. I'm currently back on Precise current kernel. How do I install the Oneiric kernel? I can install mainline kernels all day long, but I've never tried installing a kernel from an older release onto a newer release... is there a wiki or something you can point me to so I can try that?

Also, the thing that triggered this was teh SysRq messages that hit klog/syslogd so hard that they were being written to the log files all munged together. I'm trying to get the actual syslog from this, but it's difficult as the file is 3.9GB in size, thanks to at least 19 million identical Emergency Thaw messages, malformed messages and stack traces. I'm culling out a lot of the duplicated cruft and trying to get the log down to a reasonable size to upload for you, but it's slow going as vi apparently wants to load the entire file into memory to edit it, and then deleting a million lines at a time takes a bit :)

Finally, I do NOT know what triggered this, and it's only happened the one time, so far. Just FYI.

[Joseph Salisbury (jsalisbury)]

Hmm, it might not be useful to install the Oneiric kernel if you don't have a reliable way to reproduce the bug.

To install the Oneiric kernel, you basically just need to download the pre-build .deb file and install it with dpkg -i, just like the mainline kernel.

The Oneiric kernel can be downloaded from:
https://launchpad.net/~canonical-kernel-team/+archive/ppa/+build/3385903

Also, in case your interested, all of the Ubuntu kernels can be found for download at:
https://launchpad.net/ubuntu/+source/linux

Just click the kernel version your interested in. On the resulting page, look for the "Builds" section, and select the arch you are interested in.

[Launchpad Janitor (janitor)]

[Expired for linux (Ubuntu) because there has been no activity for 60 days.]

[Jeff Lane  (bladernr)]

Ok... it happened again overnight.

 bladernr@klaatu:~$ uname -a
Linux klaatu 3.2.0-25-generic #40-Ubuntu SMP Wed May 23 20:30:51 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux

Fully updated Precise system :( at 0854 this morning, the first SysRq message appeared in the log:

Jun 20 08:54:04 klaatu kernel: [85700.545264] SysRq : HELP : loglevel(0-9) reBoot Crash terminate-all-tasks(E) memory-full-oom-kill(F) kill-all-tasks(I) thaw-filesystems(J) saK show-backtrace-all-active-cpus(L) show-memory-usage(M) nice-all-RT-tasks(N) powerOff show-registers(P) show-all-timers(Q) unRaw Sync show-task-states(T) Unmount show-blocked-tasks(W) dump-ftrace-buffer(Z)
Jun 20 08:54:04 klaatu kernel: [85700.548084] atkbd serio2: Unknown key pressed (raw set 2, code 0x0 on isa0060/serio2).
Jun 20 08:54:04 klaatu kernel: [85700.548093] atkbd serio2: Use 'setkeycodes 00 <keycode>' to make it known.
Jun 20 08:54:04 klaatu kernel: [85700.645263] atkbd serio2: Unknown key pressed (raw set 2, code 0x18 on isa0060/serio2).
Jun 20 08:54:04 klaatu kernel: [85700.645272] atkbd serio2: Use 'setkeycodes 18 <keycode>' to make it known.
Jun 20 08:54:04 klaatu kernel: [85700.647803] atkbd serio2: Unknown key pressed (raw set 2, code 0x174 on isa0060/serio2).

Then there was this next SysRq message:
Jun 20 08:54:06 klaatu kernel: [85702.601971] atkbd serio2: Use 'setkeycodes 00 <keycode>' to make it known.
Jun 20 08:54:06 klaatu kernel: [85702.678295] atkbd serio2: Unknown key pressed (raw set 2, code 0x8 on isa0060/serio2).
Jun 20 08:54:06 klaatu kernel: [85702.678303] atkbd serio2: Use 'setkeycodes 08 <keycode>' to make it known.
Jun 20 08:54:06 klaatu kernel: [85702.679470] SysRq : Changing Loglevel
Jun 20 08:54:06 klaatu kernel: [85702.679479] Loglevel set to 0
Jun 20 08:54:06 klaatu kernel: [85702.681515] atkbd serio2: Unknown key pressed (raw set 2, code 0x0 on isa0060/serio2).
Jun 20 08:54:06 klaatu kernel: [85702.681522] atkbd serio2: Use 'setkeycodes 00 <keycode>' to make it known.
Jun 20 08:54:06 klaatu kernel: [85702.826266] atkbd serio2: Unknown key pressed (raw set 2, code 0x8 on isa0060/serio2).
Jun 20 08:54:06 klaatu kernel: [85702.826274] atkbd serio2: Use 'setkeycodes 08 <keycode>' to make it known.

and more:
Jun 20 08:54:07 klaatu kernel: [85703.533880] atkbd serio2: Unknown key pressed (raw set 2, code 0x8 on isa0060/serio2).
Jun 20 08:54:07 klaatu kernel: [85703.533889] atkbd serio2: Use 'setkeycodes 08 <keycode>' to make it known.
Jun 20 08:54:07 klaatu kernel: [85703.535377] SysRq : Show Blocked State
Jun 20 08:54:07 klaatu kernel: [85703.535385] task PC stack pid father
Jun 20 08:54:07 klaatu kernel: [85703.535612] Sched Debug Version: v0.10, 3.2.0-25-generic #40-Ubuntu
Jun 20 08:54:07 klaatu kernel: [85703.535617] ktime : 85788353.151918
Jun 20 08:54:07 klaatu kernel: [85703.535622] sched_clk : 85703535.609556
Jun 20 08:54:07 klaatu kernel: [85703.535626] cpu_clk : 85703535.609650
Jun 20 08:54:07 klaatu kernel: [85703.535630] jiffies : 4316339384
Jun 20 08:54:07 klaatu kernel: [85703.535634] sched_clock_st...

[Jeff Lane  (bladernr)]

If you wish, please mark this as a duplicate of 984265 as it appears I have found the trigger for this issue... and it's directly caused by 984265.

[kenorb (kenorb)]

The same here.
https://bugzilla.kernel.org/show_bug.cgi?id=47741