Oops removing thinkpad_acpi and video on git:linux-acpi-2.6

Hello!

I just got the following oops when removing thinkpad_acpi and then video. Kernel is the linux-acpi-2.6 git branch up to

commit 00a2b433557f10736e8a02de619b3e9052556c12
Merge: de85871... 2d571b3...
Author: Len Brown <[email protected]>
Date: Wed Oct 10 01:00:45 2007 -0400

Pull acpica into test branch

Just before the oops, dmesg shows the following, with the first being the event generated by brightness up/down with Fn keys and the second the ThinkFinger [1] device:
=====
thinkpad_acpi: unknown LID-related HKEY event: 0x5010
input: Virtual ThinkFinger Keyboard as /class/input/input99
=====

This is on a Lenovo ThinkPad X60 [2], ThinkPad BIOS 7BETD0WW (2.11)
[3] and EC 7BHT40WW-1.13, kernel compiled using the Debian kernel-package.

Thx, bye,
Gismo / Luca

Footnotes:
[1] http://thinkfinger.sourceforge.net
[2] http://luca.pca.it/projects/ibm/x60_1706-gmg/
[3] I'm aware there's a new version, but I'm waiting to understand if I can upgrade it using Free Software only (i.e. without the Lenovo bootable CD)

--8<---------------cut here---------------start------------->8---

Unable to handle kernel paging request at ffffffff880f7187 RIP:
 [<ffffffff880f7187>]
PGD 203067 PUD 207063 PMD 7cae4067 PTE 0
Oops: 0010 [1] SMP
CPU 1
Modules linked in: nls_iso8859_1 ncpfs nfs lockd nfs_acl sunrpc fuse
 usb_storage snd_usb_audio snd_usb_lib snd_seq_dummy snd_seq_oss
 snd_seq_midi snd_seq_midi_event snd_seq snd_rawmidi pwc
 snd_seq_device compat_ioctl32 videodev v4l2_common snd_hwdep
 v4l1_compat tcp_diag inet_diag battery arc4 ecb i915 drm rfcomm l2cap
 bluetooth dock container ipv6 acpi_cpufreq cpufreq_conservative
 cpufreq_ondemand cpufreq_powersave cpufreq_userspace cpufreq_stats
 freq_table uinput firewire_sbp2 loop pcmcia piix generic ide_core
 snd_hda_intel snd_pcm_oss snd_mixer_oss irtty_sir sir_dev
 firewire_ohci firewire_core snd_pcm iwl3945 yenta_socket
 rsrc_nonstatic pcmcia_core crc_itu_t ata_generic firmware_class sdhci
 ac power_supply iTCO_wdt snd_timer irda mmc_core mac80211 i2c_i801
 i2c_core button ehci_hcd e1000 snd uhci_hcd crc_ccitt cfg80211
 ata_piix soundcore snd_page_alloc serio_raw psmouse intel_agp tsdev
 evdev ext3 jbd mbcache sha256 aes cbc blkcipher dm_crypt dm_mirror
 dm_snapshot dm_mod sd_mod thermal processor fan ahci libata scsi_mod
Pid: 50, comm: kacpi_notify Not tainted 2.6.23-1-amd64 #1
RIP: 0010:[<ffffffff880f7187>]  [<ffffffff880f7187>]
RSP: 0018:ffff81007d881df0  EFLAGS: 00010286
RAX: 0000000000000000 RBX: ffff810020b7e140 RCX: 0000000000000001
RDX: 0000000000000052 RSI: ffff81007d881e10 RDI: 0000000000041678
RBP: 000000000000001e R08: ffff81003bb7f910 R09: ffff81001e98f268
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000087
R13: ffffffffffffffff R14: ffffffff8055dab0 R15: 0000000000000000
FS:  0000000000000000(0000) GS:ffff81000115cc40(0000) knlGS:0000000000000000
CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: ffffffff880f7187 CR3: 000000005559e000 CR4: 00000000000006a0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process kacpi_notify (pid: 50, threadinfo ffff81007d880000, task ffff8100011c6800)
Stack:  0000000000000001 000000000000001e 0000000000000000 ffff810020b7e140
 ffff810000000001 ffff81007d881df0 ffffffffffffffff ffff810020b7e140
 000000000000000a ffffffff880f75b2 0000000000000000 000000000000001e
Call Trace:
 [<ffffffff80325172>] acpi_os_execute_notify+0x0/0x2c
 [<ffffffff8032aae5>] acpi_ev_notify_dispatch+0x57/0x60
 [<ffffffff80325195>] acpi_os_execute_notify+0x23/0x2c
 [<ffffffff802449fc>] run_workqueue+0x7d/0x10c
 [<ffffffff80245439>] worker_thread+0xe1/0xf0
 [<ffffffff80248183>] autoremove_wake_function+0x0/0x2e
 [<ffffffff80245358>] worker_thread+0x0/0xf0
 [<ffffffff8024805d>] kthread+0x47/0x76
 [<ffffffff8020ccd8>] child_rip+0xa/0x12
 [<ffffffff8022f800>] default_wake_function+0x0/0xe
 [<ffffffff80248016>] kthread+0x0/0x76
 [<ffffffff8020ccce>] child_rip+0x0/0x12


Code:  Bad RIP value.

RIP [<ffffffff880f7187>]
RSP <ffff81007d881df0>
CR2: ffffffff880f7187
--8<---------------cut here---------------end--------------->8---

If you never load thinkpad_acpi in the first place, just video, and then remove video, does the oops happen? I can't help much with video, but thinkpad-acpi is my responsability.

Yeah, that 5010 event seems to mean "something in NVRAM changed". thinkpad-acpi just punts it to userspace. That event is gone in later BIOS revisions, I think.

You have a BIOS with bugs. Please consider updating.

No. You should use the CD if you can. Otherwise, you are risking your warranty, which is a very dumb thing to do.

Anyway, refer to http://thinkwiki.org/wiki/BIOS_Upgrade for upgrade experiences on the X60 using various methods.

Looks like either thinkpad-acpi or video forgot to remove a notify handler before unloading. Or maybe it is a race.

  "One disk to rule them all, One disk to find them. One disk to bring
  them all and in the darkness grind them. In the Land of Redmond
  where the shadows lie." -- The Silicon Valley Tarot
  Henrique Holschuh

Hi Henrique,

no need to Cc: me, I read the list ;-)

I tested with probably every kind of different combinations and it seemed I could not reproduce the oops anymore.

I also tried a situation very similar (except the software running) to the one when I experienced the oops:

1) booted the machine with thinkpad_acpi (no video)
2) modprobe video resulted in the following dmesg
=====
input: Video Bus as /class/input/input10
ACPI: Video Device [VID] (multi-head: yes rom: no post: no)
input: Video Bus as /class/input/input11
ACPI: Video Device [VID1] (multi-head: yes rom: no post: no)
thinkpad_acpi: unknown LID-related HKEY event: 0x5010
hald-addon-acpi[3654]: segfault at 0000000000000000 rip 00002b9373fd45eb rsp 00007fff371bacf0 error 4
=====
3) modprobe -r thinkpad_acpi succeeded
4) modprobe -r video succeeded as well, thus no oops

But read below :-)

Since I experienced the oops after having changed the LCD brightness, I pressed several times the brightness up/down Fn keys, then removed only the thinkpad_acpi module and voila, I got the oops again. So, the problem is a thinkpad_acpi one, confirmed by the fact that the same test with the video module only didn't generate the oops. However, if the video module is not present, thinkpad_acpi doesn't trigger the oops.

BTW, I forgot to say that I use the experimental option of the thinkpad_acpi module, but removing it doesn't change anything.

[...]

[...]

I usually upgrade the BIOS as soon as a new version is available and through the CD (I've the X6 dock, too, and I'm aware of ThinkWiki). But since the SD card reader on my X60 is broken (it generates an interrupt at card insertion, but nothing more, neither on Windows XP), I need to bring the laptop to an IBM center. So I decided to wait for the BIOS upgrade and to ask the IBM center about Free Software tools to deal with ThinkPad BIOSes.

Should I perform my tests again with the new BIOS? Or is this bug completely unrelated to the BIOS version?

Thx, bye,
Gismo / Luca

Hmm, I will see if I can reproduce it. Do you get that problem if you use 2.6.23 + thinkpad-acpi 0.18-20071013 available at:
http://sourceforge.net/project/showfiles.php?group_id=117042 ?

There is also a git tree, if you prefer:
http://repo.or.cz/w/linux-2.6/linux-acpi-2.6/ibm-acpi-2.6.git
for the gitweb interface, there is more data in that. Look at the release/ branches.

The bug might even be triggered by the BIOS, but it is a real bug in the driver. But the new BIOS will probably behave much better re. brightness functions.

  "One disk to rule them all, One disk to find them. One disk to bring
  them all and in the darkness grind them. In the Land of Redmond
  where the shadows lie." -- The Silicon Valley Tarot
  Henrique Holschuh

Hi Henrique!

[...]

Thank you.

I tested 2.6.23.1 + 0.18-20071013, oops still there. Should I test it with the latest linux-acpi-2.6 git tree, also? I don't think it's necessary, but I can do it in case (but please read below).

Sorry, I'm quite lost with the git tree: in release/ there's nothing about the latest linux-acpi-2.6 tree, what I can see is the different linux releases with spare patches. And if I correctly read the README, I should check what's in for-upstream, which I don't really know how to checkout with git (I performed a git clone $TREE).

Is it OK to wait to upgrade the BIOS until the bug has been fixed? Because if the bug won't be present anymore with the new BIOS, we don't have a way to be sure it's fixed.

Thx, bye,
Gismo / Luca

It is probably not liking something in 2.6.23. I will test that and get back to you as soon as I have an answer (might take a few days).

That tree is just for thinkpad-acpi, it usually has nothing related to other linux-acpi changes, unless they actually are required for something thinkpad-acpi needs to do.

Sure, it is OK to wait to upgrade the BIOS. As I said, I am certain there is a driver bug somewhere, regardless of any possible BIOS problems.

  "One disk to rule them all, One disk to find them. One disk to bring
  them all and in the darkness grind them. In the Land of Redmond
  where the shadows lie." -- The Silicon Valley Tarot
  Henrique Holschuh

Unfortunately, I can't reproduce it. Might be a 32/64 bit issue, since I can only test x86-32, or I could not duplicate exactly what is causing the problem, but...

Please compile thinkpad-acpi and ACPI with the debug modes enabled, and load thinkpad-acpi with the debug=0xffff parameter. Then reproduce the oops, and send me the entire kernel output since driver load until the oops.

You could also try turning on some of the ACPI debug bits, one of them (sorry, I don't know which) will tell you exactly which device's notify handler it is calling.

  "One disk to rule them all, One disk to find them. One disk to bring
  them all and in the darkness grind them. In the Land of Redmond
  where the shadows lie." -- The Silicon Valley Tarot
  Henrique Holschuh

Hi Henrique!

[...]

Done (and dmesg attached). Disabling CONFIG_THINKPAD_ACPI_HOTKEY_POLL doesn't change anything (and the dmesg attached is with that option enabled).

BTW, I needed to play a bit with module loading/unloading, since the first time I removed the thinkpad_acpi module the oops wasn't triggered.

Please let me know if you want my .config as well.

Well, I think I've all the ACPI debug options already on, since CONFIG_ACPI_DEBUG=y and CONFIG_ACPI_DEBUG_FUNC_TRACE=y, as well as CONFIG_PM_DEBUG=y (and CONFIG_THINKPAD_ACPI_DEBUG=y, obviously).

Thx, bye,
Gismo / Luca

Hmm, am I going crazy, or did the OOPS happen with an instance of thinkpad-acpi *not* loaded with debug=0xffff? Can you try that again making sure it always gets the debug=0xfffff parameter? Apparently, it was active only the first time you tried to load the module, and I wanted to see the exit path debug messages of the instance that gets an OOPS...

  "One disk to rule them all, One disk to find them. One disk to bring
  them all and in the darkness grind them. In the Land of Redmond
  where the shadows lie." -- The Silicon Valley Tarot
  Henrique Holschuh

Hi Henrique!

Sorry, my fault. It should be OK now.

Thx, bye,
Gismo / Luca

I was afraid of that, the OOPs happens entirely after the thinkpad-acpi module unloaded.

And we *did* unregister all notification functions in thinkpad-acpi, so it might well be a problem in the ACPI core, and not thinkpad-acpi.

Please try again, this time do this beforehand (warning: will generate a lot of debug output):

echo 0x4 > /proc/acpi/debug_layer
echo 0xfffffff > /proc/acpi/debug_level

Maybe we will be lucky and give us more info on what the ACPI layer is calling that causes the oops.

You could also try adding a sleep() call of a second or so in thinkpad-acpi's thinkpad_acpi_module_exit function, after the loop that calls ibm_exit. It is one of those ibm_exit calls that unregister the notify handler for hotkey (the only one active in your thinkpad-acpi install). If it is a race, that might eliminate it and give us further information.

  "One disk to rule them all, One disk to find them. One disk to bring
  them all and in the darkness grind them. In the Land of Redmond
  where the shadows lie." -- The Silicon Valley Tarot
  Henrique Holschuh

Hi Henrique!

Sorry for the delay, I was busy with real life...

It seems that the oops is no more thinkpad-acpi's fault, since yesterday and today I got the oops with ACPI's video only (read below).

The oops removing ACPI's video module occurred both in 2.6.23.1 (with thinkpad-acpi-0.18) or today's git pull for linux-acpi-2.6.

The machine booted with both video and thinkpad-acpi, then I removed them, enabled the ACPI debug and inserted video. To be sure that the oops wasn't video-related, I removed the video module and I got the oops (attached).

I think I don't need 2.6.23.1 anymore, right?

Now, since on Monday I'll bring my laptop to the IBM repairing center and since they told me that to repair the broken SD card reader they'll change the whole motherboard, I guess that they'll return me the laptop with the BIOS upgraded. So, if any urgent test is needed, I can perform it during the week-end.

Thx, bye,
Gismo / Luca

Yeah, it is as I feared. Something is broken in 2.6.23.1 and later (actually, LOTs of things are broken in 2.6.24-rc :p).

Don't worry about it.

  "One disk to rule them all, One disk to find them. One disk to bring
  them all and in the darkness grind them. In the Land of Redmond
  where the shadows lie." -- The Silicon Valley Tarot
  Henrique Holschuh