A tale of just another Linux kernel bug

As part of a bigger effort to get my Nokia N900 in good shape for development, I decided to track down an issue with the keyboard; I could type ‘a’, but not ‘A’ or any special characters, so no ‘shift’ or ‘ctrl’ or anything special. Trying to figure out what was going on took me through an unexpected journey, which is not remarkable, but I think it’s a good example of what many kernel developers (and low level developers) constantly go through, and as such, might be interesting for some people to read.

Keycodes

So, first things first. I recently had an issue with a PS/2 keyboard on my PC, so I had an idea how to debug this, and the first thing I did was to run keycode, which shows messages like these:

keycode  30 press
keycode  30 release
keycode  30 press
keycode  30 release
keycode  29 press

Then these keys are supposed to be converted to real characters somehow through a key map, and apparently X has a map of its own.

However, I saw keycodes being pressed when I clicked ‘shift’, so I concluded that neither hardware, nor input driver was the problem, could it be the mapping? The MeeGo project provided a mapping file that I have been using for some time, and it clearly shows “keycode 42 = Shift”, and I was getting keycode 42, so the mapping seemed correct, but was it being applied properly? I found out this can be checked by using dumpkeys, and indeed, the mapping was correct.

Everything was fine up to this level. Next.

Note: all these tools (showkey, loadkeys, and dumpkeys) are provided by the ‘kbd’ package.

Virtual terminal

Now I stumbled into a problem; I’ve no idea what it is that I am interacting with on the framebuffer console (I’m not using X). So, I try fill that gap in my knowledge by going to the ##linux IRC channel in freenode.net, and ask the question: what is it that converts they keycodes to characters in a framebuffer console? As it’s typical when I ask these sorts of tricky questions, I get useless responses, like, ‘what distribution are you using?’ I knew that didn’t matter, so I set out to investigate myself.

I thought, well, what is this thing that I have to add in my inittab to get the console working? 1:2345:respawn:/sbin/getty 9600 tty1. I tried to read documentation about getty and try different options, like try to specify vt100 as an argument, but to no avail.

Maybe it’s done in the kernel? I thought. So I quickly went through my kernel config, and I find this gem:

CONFIG_VT

If you say Y here, you will get support for terminal devices with
display and keyboard devices. These are called "virtual" because you
can run several virtual terminals (also called virtual consoles) on
one physical terminal. This is rather useful, for example one
virtual terminal can collect system messages and warnings, another
one can be used for a text-mode user session, and a third could run
an X session, all in parallel. Switching between virtual terminals
is done with certain key combinations, usually Alt-.

The setterm command ("man setterm") can be used to change the
properties (such as colors or beeping) of a virtual terminal. The
man page console_codes(4) ("man console_codes") contains the special
character sequences that can be used to change those properties
directly. The fonts used on virtual terminals can be changed with
the setfont ("man setfont") command and the key bindings are defined
with the loadkeys ("man loadkeys") command.

You need at least one virtual terminal device in order to make use
of your keyboard and monitor. Therefore, only people configuring an
embedded system would want to say N here in order to save some
memory; the only way to log into such a system is then via a serial
or network connection.

If unsure, say Y, or else you won't be able to do much with your new
shiny Linux system :-)

That makes sense, now we are getting somewhere. So, in the past, there was this notion of ‘terminals’, which are specialized pieces of hardware that send and receive ASCII (or some codes), so they are the ones that have all the needed stuff to control they keyboard, screen, and so on. I never had the need to use one of these terminals, therefore I never really knew what a “virtual” terminal was. So a virtual terminal does the job of a real terminal; it needs an input driver, and a display driver, and really puts them to do something useful.

Interesting theory, but is it true? I quickly looked at the code inside drivers/tty/vt, and I found code to control the keyboard, screen, and also that contains the keyboard mappings. Excellent! So we found the thing that uses these keyboard mappings. Now what?

Before moving on, the fact that this code resides in tty is also helpful, basically, serial console, virtual terminals (framebuffer console), and real terminals all operate through tty’s (teleprinter), which are means of communication between hosts and these “devices”. So, getty really gets a tty to be used by any of these.

All right, so now the knowledge gap seems to be filled, what next? Well, clearly there’s something wrong with this virtual terminal, but what? I immediately started looking at the code at drivers/tty/vt/keyboard.c, and I noticed something interesting: kbdmode can have different values, like RAW, and this mode, certain things are not handled, like ‘shift’. That looked promising, but how to change that mode?

I looked for tools to control the virtual terminal, I found an interesting one, setterm, which was not available in my minimal system, I couldn’t find how to get it, and anyway didn’t have any option that I wanted. terminfo and such looked interesting, but it didn’t seem like anything relevant to the issue at hand. Then I found kbd_mode, which obviously did what I wanted, and I already had it :). I couldn’t even type mbd_mode on my keyboard, so I had to write shortcuts on my PC (kbda, kbdb, etc.). Unfortunately, I found out that initially the mode was set to ‘unicode’, which seemed Ok, and changing to ‘ascii’ didn’t change anything.

So, it didn’t seem to be a user-space configuration of any sort. Next.

Getting our hands dirty

Time to actually type some code. I modified the code in ‘drivers/tty/vt/keyboard.c’, specially in kbd_keycode() to find out the true kbdmode, the keycodes coming down, and how they were being interpreted.

I quickly found out that they keycodes and mode were indeed correct, but each and every key press was immediately followed by a key release, so shift+a was interpreted as shift, a. Now we are getting somewhere; the problem has to be on the input driver.

Maybe I chose the wrong one, or maybe I’m missing some configurations. I see some CONFIG_KEYBOARD_GPIO, and CONFIG_KEYBOARD_TWL4030, and it looks like I should be using TWL4030, as that’s the chip the Nokia N900 has, but I’m not sure, so time to look at the N900 schematics. Well, it seemed like TWL4030 is indeed the right one, and there’s nothing to it; either you have it or not.

Maybe some recent change broke it… But there’s nothing recent that I can see that could do that. So it’s time to take a look at the actual code: drivers/input/keyboard/twl4030_keypad.c. After adding a few prints here and there I realize the problem starts with this code ret = twl4030_kpread(kp, &reg, KEYP_ISR1, 1) which returns 0 after a key press (that returns 1). So, time to read the TRM.

It took me some time to find the right document, and then understand what all the configuration options were actually doing (more or less), and then play around with them. After making a lot of more or less random changes I notice no difference in this particular problem of getting an extra ’0′. So I think to myself; maybe the problem is the interrupt.

So I abandon the configuration of the keyboard, and look at the code to request the interrupt:
request_threaded_irq(kp->irq, NULL, do_kp_irq, 0, pdev->name, kp);

I had some interrupt issues before (in fact on this very keyboard), so I knew a few hacks I could try, like specifying the IRQF_ONESHOT flag. That didn’t help, so I tried to do that in the parent interrupt on ‘drivers/mfd/twl4030-irq.c’, because I saw a patch from Neil Brown on the linux-omap mailing list that fixed another issue, but that didn’t help either. Then I realized I saw one patch that affected this interrupt request (see here). So I revert the patch, and voilà, no more 0′s afterwards, and the keyboard works properly.

However, there’s a nasty warning about interrupts being enabled, which is probably the reason why the original patch happened, so I try a few random things to get rid of it, but nothing helps. So then I wonder, maybe the reason the keyboard driver worked before that patch is just pure luck, and these extra interrupts were not being detected properly.

Enough fooling around

Since I really want to fix this issue properly, I push myself to really understand what’s going on in the driver. So I slowly read all the documentation, and all the registers, and try to set different values to see what’s going on. While doing that, I noticed one function was calculating the times wrongly, and was telling the driver to use values twice as big as originally intended. It took me some time to figure out why the author chose 31 << (x + 1) instead of 2 << (x + 1) * 31, which is what a direct function conversion would return, until I realized that a shift basically means multiplying by two, and x << 1 is basically the same as (2 << 0) * x, but the author missed that x = ptv + 1, and so it should be 31 << (ptv + 2). Anyway, after being confident of these timeout values, I could set big timeouts on the range of seconds without overflowing the registers and see exactly what they were doing in timescales I could notice.

So yeah, these registers were doing what I thought they should be doing. Nice try.

Time to go back to the interrupt handling. After reading the code of the twl4030-irq, which is supposed to fire the irqs that the keyboard driver eventually gets, and then reading some kernel core code as well, it was not really clear to me how these were all weaved together, so I added some printfs.

Before going forward I’ll briefly explain a bit what TWL4030 is. To my understanding it’s basically an integrated circuit that has many functions, one of them is having a keyboard controller. So there is no dedicated IRQ for the keyboard interrupt, but TWL4030 has a level interrupt, and then the right module IRQ is demultiplexed. OK.

I was hoping there was a chain of actions like pih -> sih (from twl-core) -> keyboard, but no, there was only one action in the chain. Fortunately when I reverted the patch I got a warning with a backtrace where I could see something like twl4030_irq_thread->generic_handle_irq->handle_simple_irq. It was really straight-forward, but I couldn’t see why. There was a lot of code in twl403o-irq for a “secondary interrupt handler” but it didn’t seem to be called at all, and I didn’t see how generic_handle_irq was calling handle_simple_irq.

Time to step back for a second. I remembered a patch from Neil Brown trying to fix something regarding how this sih stuff was called (here) because it was not called at all, but these patches are supposed to be fixes for other patches that are not applied at this point, so they really wouldn’t help.

At this point I’m pretty much stuck, as I’ve no idea how all this code is connected, you might think that all this is way over my head, and it might be, even if just a little, but that has never deterred me. I know that as long as I have the code, and I have a way to run it, I can figure out how it works, so I just keep trying.

After reading the code more carefully, I noticed that only some twl “modules” had a sih setup, and the keyboard was not one of them, so that explained the sih part. And then I noticed a part of the irq handling that dealt with “chips”, and one interesting function that setup the chip’s “handler”. Wait a second… So there’s a chip handler, and a client handler, a few keystrokes after and I find this gem irq_set_chip_and_handler(i, &twl4030_irq_chip, handle_simple_irq). Finally! So I can now see the whole chain of events, but alas, I still have no idea why things are failing.

I thought maybe some states where miscalculated, so I find a function that is used to print everything related to an irq, but it was hidden in some internal code, so I had to do a few tricks to use it in the keyboard driver. All the states seemed to be OK, except one… the irq count, which showed something like 0, 0, 0, 1, 2, 2, 3 where it should have shown 0, 0, 1, 1, 2, 2. I looked at all the places where this counter is modified, and I found an interesting function: handle_nested_irq, so I replaced handle_simple_irq just for fun, and…

BAM!

Everything worked perfectly.

Why, Why, Why

So, now I found a fix, but why does it work? If I want to fix this in a way that other people will not get bitten, I have to find the proper fix, so “This seems to make things work here” usually doesn’t convince many kernel hackers.

Using handle_nested_irq makes the compiler throw a warning right away, because the number of arguments is different, so I looked at how other people use this function, and it’s indeed very different, it looks like people are calling handle_nested_irq directly, instead of generic_handle_irq, which would eventually handle handle_simple_irq, because that’s the chip’s configured handler. It all boils down to the difference between handle_nested_irq and handle_simple_irq, and looking at them it’s clear that handle_nested_irq does much less, specifically, it calls directly the action->thread_fn() callback, which is the keyboard interrupt handler, rather than waking up the thread, which is the same function (but in a specialized thread).

And this finally shines some light; the reason why the interrupt counter is wrong, is that the thread is waked after the irq has been processed, so the code that is supposed to clear the interrupt hasn’t been called yet, and a second interrupt is generated which is spurious. The relevant code is supposed to read a register, and the hardware clear the interrupt on a read (or write) operation. The reason handle_nested_irq works is because it doesn’t bother with the interrupt thread at all, it calls the function right away on the same thread, and thus the interrupt is marked as handled at the right time (after it has been really handled).

And this also explains why other people call handle_nested_irq instead of generic_handle_irq; you are supposed to call it inside an interrupt thread (which is configured with request_threaded_irq), but there’s a thread lying around that nobody uses. Indeed, Neil Brown noticed the same (here), so irq_set_nested_thread() will make sure that no extra thread is created.

So both irq handlers must be threaded, the one for the twl-core, and the one for the keyboard, not just the one for the keyboard like right now. Fortunately Felipe Balbi already fixed that (see this patch series), but that broke things badly, and then Neil Brown fixed them (see this). Interestingly enough, I had already tested those patches for other reasons, but at this point I wasn’t sure if they would fix the keyboard problems, I just assumed the would anyway.

Good good, it looks like we finally have the whole picture, but the job’s not done yet.

Getting it “done”

Now the question is: how to fix this? One limitation of the ‘stable’ kernel trees (at least AFAIK), is that the patches should be in the latest Linus’s tree, so whatever solution is found, should be in the main tree.

Ideally, all the stack of irq’s should be reorganized to use the nested/threaded API, or none at all. So this patch, should have been applied only after this patch series, and not two years beforehand. I pondered for quite some time whether a middle-ground could be found, either by workarounds in the core irq handler, or in the keyboard one, eventually I came to the conclusion that since the core is supposed to set irq_set_nested_thread() anyway (just trust me), the keyboard one is the one that should check if it’s nested or not, and either set the thread handler, or a normal one, and this code should work before and after the patches applied for 3.2. Unfortunately, the ‘nested’ flag is supposed to be internal to the kernel’s thread handling code.

So there’s really no way around it, either the original patch is reverted (and other possible similar ones for other twl modules), or all the twl core irq handler gets the new code for 3.2 backported, and that code isn’t even fixed yet (as of v3.2-rc5) (and maybe it will not be the way things are progressing).

Then the question arises; is all that new code on v3.2 working properly? I went ahead and tried it, and lo and behold; the keyboard works as expected. I then backported all those patches to v3.1, and they all worked too.

But does it really make sense to apply all those patches to all the kernels after v2.6.33? Or does it make sense to revert a few of them? That’s not for me to decide, so I ask the community, after I did all that work on this mail.

Sometimes the result of a week’s work ends up being a one line patch, sometimes it’s just one character, and in this case, there was no patch (at least from me), but at least the issue is clearly identified, as well as the fixes. And that means nobody has to do this work again.

Well, the fun is not over… We still need to synchronize the maintainers, so the right patches land on Linus’ tree for v3.2, and they are back-ported to the relevant linux-stable trees.

Kernel development is hard, let’s go shopping

What are you talking about? This isn’t even kernel development, it’s just some legwork ;) I’m going to be Topper for a second and say “That’s nothing!”, there’s way more complicated and challenging issues kernel developers confront all the time. I thought this was interesting because of all the steps I had to do, and because it involved things I had no idea about.

Was this worth my time? Well, I learned what is actually a virtual terminal for real, and not some vague notion, like when common people say “My browser? Yeah, I use Google… No?”. I also learned a bit more about the IRQ handling API in the Linux kernel, and BTW, all this threaded interrupt API started because of real issues, and the removal of IRQF_DISABLED (nice LWN article about it here), and that thread was fun to read years ago, even when I didn’t understand most of it, maybe it’s time to read it again :)

For me, the best is the satisfaction of knowing that I really “got it”. I mean, I really understand what causes the problem, many of the possible solutions, including hacky and proper ones, and exactly what to do if I get bitten by a similar problem regarding threaded IRQ’s.

And now that the keyboard is fixed, on with the next problem on the N900 (which I stopped working on, because I though a functional keyboard would help to debug it, as opposed to shut down, remove the MMC, plug it into a PC, write a script with the commands I want to run, unmount, plug it back, and boot [I can't use USB networking for this issue to appear]).

About these ads

16 thoughts on “A tale of just another Linux kernel bug

  1. Felipe, of all people….
    I thought you’d be happily using/developing on a N9, alongside your N900.
    Interesting findings though, thanks for sharing!

  2. +Jed Yes, I’m using N9 as a personal device, but N900 for low-level development :)

    I might try some low-level stuff on an N950, but not yet.

  3. I see… RE N950 for development…

    qgil was going to try & arrange a CDP for the N9, as he did for the N950.
    But hopefully on a slightly larger scale than 300 devices…
    I’ve tried to chase-him-up a few times on it, but alas, no response yet.
    I think he may have gone to an entirely different department, sigh.

  4. +Jed I can probably ping him, but yeah, he seems to be working Raspberry PI and Qt stuff at the moment. So basically you just want me to ask him about what happened to the community device program for N9?

  5. Pingback: A tale of just another Linux kernel bug « Felipe Contreras » Tech Unleashed

  6. Hi, can you share your .config and which kernel sources+patches are you using? Also, which hardware components did you get working on your text-mode environment (wlan, usb storage/networking, cellular)? Thanks

  7. The complexity of the jargon and troubleshooting made me so confused.

    Man this is the reason a slightly casual power user like myself’s dreams of contributing anything program related will never be a reality past that of a couple of bash scripts.

    In either matter good on, great work and to say the least solving bugs like this really impresses a bunch of us out here. Nice!

    (Do you think it’s better to go to schooling to learn programming, perhaps self-teaching isnt the way to go?)

  8. Pingback: A tale of just another Linux kernel bug « Felipe Contreras | What is Linux

  9. I didn’t understand much of that, but I want to thank you for taking the time to write it up! If there were more stories like this lying around, we’d all waste a hell of a lot less time figuring stuff out from scratch.

  10. Hello Felipe? What came of this? (below) Thank-you!

    “+Jed I can probably ping him, but yeah, he seems to be working Raspberry PI and Qt stuff at the moment. So basically you just want me to ask him about what happened to the community device program for N9?”

  11. Hello Felipe? What came of this? (below) Thank-you!

    “+Jed I can probably ping him, but yeah, he seems to be working Raspberry PI and Qt stuff at the moment. So basically you just want me to ask him about what happened to the community device program for N9?”

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s