Bug 4052

Created attachment 1119 [details]
message

Created attachment 1120 [details]
message with kernel error

Sometimes the kernel printed some error messages:
############
Mar 19 06:48:05 qemumips user.warn kernel: Reserved instruction in kernel code[#1]:
Mar 19 06:48:05 qemumips user.warn kernel: Cpu 0
Mar 19 06:48:05 qemumips user.warn kernel: $ 0   : 00000000 c0029eb8 00000008 c0028000
Mar 19 06:48:05 qemumips user.warn kernel: $ 4   : 86cb54f0 a08bb480 ffffffff 00000000
Mar 19 06:48:05 qemumips user.warn kernel: $ 8   : 008ba270 804c8a70 00001000 00000001
Mar 19 06:48:05 qemumips user.warn kernel: $12   : 00000000 ffffffff 00000001 6e706172
Mar 19 06:48:05 qemumips user.warn kernel: $16   : 00000006 86d68780 3000a401 86cb5400
Mar 19 06:48:05 qemumips user.warn kernel: $20   : 8515bc00 00000001 a08bb480 00000003
Mar 19 06:48:05 qemumips user.warn kernel: $24   : 00000002 804805a8    
Mar 19 06:48:05 qemumips user.warn kernel: $28   : 86c14000 86c15bd8 86cb54f0 c002e08c
Mar 19 06:48:05 qemumips user.warn kernel: Hi    : 00000423
Mar 19 06:48:05 qemumips user.warn kernel: Lo    : 020c4d59
Mar 19 06:48:05 qemumips user.warn kernel: epc   : c0028000 uhci_check_bandwidth+0x0/0x160 [uhci_hcd]
Mar 19 06:48:05 qemumips user.warn kernel:     Not tainted
Mar 19 06:48:05 qemumips user.warn kernel: ra    : c002e08c uhci_urb_enqueue+0xba4/0xc48 [uhci_hcd]
Mar 19 06:48:05 qemumips user.warn kernel: Status: 3000a402    KERNEL EXL 
Mar 19 06:48:05 qemumips user.warn kernel: Cause : 90800028
Mar 19 06:48:05 qemumips user.warn kernel: PrId  : 00019300 (MIPS 24Kc)
Mar 19 06:48:05 qemumips user.warn kernel: Modules linked in: i2c_piix4 uhci_hcd i2c_core
Mar 19 06:48:05 qemumips user.warn kernel: Process Xorg (pid: 172, threadinfo=86c14000, task=87dd49b0, tls=77206490)
Mar 19 06:48:05 qemumips user.warn kernel: Stack : 000200da 00000000 00000000 802223a4 86cb54f0 00000041 00000001 00000002
Mar 19 06:48:05 qemumips user.warn kernel:         81081e60 81143798 87c04c00 80226204 1000a401 80224c18 808b7530 00000020
Mar 19 06:48:05 qemumips user.warn kernel:         86d68780 86cb5400 00000000 86d68788 000000d0 86d5ce3c 80233110 86c15e78
Mar 19 06:48:05 qemumips user.warn kernel:         00000000 8058092c 86c0f000 000000d0 00000000 81081e60 87fcdbc4 00000002
Mar 19 06:48:05 qemumips user.warn kernel:         00000000 00000002 00000000 87fcdbc4 00000000 86d5e400 86d5e4d8 86d5ce04
Mar 19 06:48:05 qemumips user.warn kernel:         ...
Mar 19 06:48:05 qemumips user.warn kernel: Call Trace:
Mar 19 06:48:05 qemumips user.warn kernel: [<c0028000>] uhci_check_bandwidth+0x0/0x160 [uhci_hcd]
Mar 19 06:48:05 qemumips user.warn kernel: [<c002e08c>] uhci_urb_enqueue+0xba4/0xc48 [uhci_hcd]
Mar 19 06:48:05 qemumips user.warn kernel: [<8058092c>] usb_hcd_submit_urb+0xdc/0x848
Mar 19 06:48:05 qemumips user.warn kernel: [<805b8fbc>] wacom_open+0x44/0x8c
Mar 19 06:48:05 qemumips user.warn kernel: [<805a1990>] input_open_device+0xac/0xec
Mar 19 06:48:05 qemumips user.warn kernel: [<805a8cec>] evdev_open+0x188/0x1bc
Mar 19 06:48:05 qemumips user.warn kernel: [<802331d8>] chrdev_open+0xc8/0x1c4
Mar 19 06:48:05 qemumips user.warn kernel: [<8022b338>] do_dentry_open+0x248/0x2e4
Mar 19 06:48:05 qemumips user.warn kernel: [<8022b418>] finish_open+0x44/0x68
Mar 19 06:48:05 qemumips user.warn kernel: [<8023e51c>] do_last.isra.29+0x2c0/0xcbc
Mar 19 06:48:05 qemumips user.warn kernel: [<8023efd8>] path_openat+0xc0/0x52c
Mar 19 06:48:05 qemumips user.warn kernel: [<8023f840>] do_filp_open+0x4c/0xbc
Mar 19 06:48:05 qemumips user.warn kernel: [<8022cc3c>] do_sys_open+0x128/0x20c
Mar 19 06:48:05 qemumips user.warn kernel: [<8010c07c>] stack_done+0x20/0x44
Mar 19 06:48:05 qemumips user.warn kernel: Code: (Bad address in epc)
Mar 19 06:48:05 qemumips user.warn kernel: ---[ end trace 8a48c6046870f8c2 ]---
Mar 19 06:48:05 qemumips user.info kernel: note: Xorg[172] exited with preempt_count 1
#############

This issue is present on qemux86-64 master:bdca49274173153b1b0a72887de6321b4756b684

(In reply to comment #3)
> This issue is present on qemux86-64
> master:bdca49274173153b1b0a72887de6321b4756b684

FYI, the issue you're referring to was already fixed on master [1] and is not related to this one.

[1] http://git.yoctoproject.org/cgit.cgi/poky/commit/?id=9915f945c904fd7664d073421b803fd1c672c324

The root cause is ftrace inserting invalid instructions.

The workaround is disabling CONFIG_DYNAMIC_FTRACE, which is the easy one.

The proper fix would be fixing mips32 tracing, which seems difficult enough that experienced mips guys can't make it right. See arch/mips/kernel/ftrace.c

Bruce, can you please take a look and see what suits you ?

I've just fixed (and queued) a similar issue for mips64.

------------------
commit eb6cb79808d7dc6535a71e5386f26c0abdaa1fb4
Author: Bruce Ashfield <bruce.ashfield@windriver.com>
Date:   Thu Apr 4 23:39:57 2013 -0400

    Revert "MIPS: Function tracer: Fix broken function tracing"
    
    This reverts commit 58b69401c797e470c8f638c598dddc44a4ce8a96.

:100644 100644 83fa146... 6a2d758... M  arch/mips/kernel/ftrace.c
:100644 100644 1658676... 4c968e7... M  arch/mips/kernel/mcount.S
------------------

Can you try reverting that same commit on your local kernel and see if it helps ?
I'm investigating two other bugs at the moment and it would really help if you can
try this on my behalf.

I'll take care of getting it into the linux-yocto tree if it fixes. the problem.

tested with 58b69401c797e470c8f638c598dddc44a4ce8a96 reverted, does not start at all.

I added the patch below to test, it works ok, I suggest using it.

diff --git a/arch/mips/kernel/ftrace.c b/arch/mips/kernel/ftrace.c
index 83fa146..2a988d9 100644
--- a/arch/mips/kernel/ftrace.c
+++ b/arch/mips/kernel/ftrace.c
@@ -100,6 +100,7 @@ static int ftrace_modify_code_2(unsigned long ip, unsigned int new_code1,
                                unsigned int new_code2)
 {
        int faulted;
+       return 0;
 
        safe_store_code(new_code1, ip, faulted);
        if (unlikely(faulted))

Heh. No, we won't insert a return 0 into the code as a fix. 

I'll have to try my own boot tests today, since the revert really should fix the problem, as I've
been booting qemumips with X enabled for a while with my staged / pending kernel tree.

If the revert isn't working, then I'll simply disable the config.

I'm testing now just the config disable, I'll let you know how it goes.

(In reply to comment #9)
> I'm testing now just the config disable, I'll let you know how it goes.

Sounds good. I'm doing a sato build, and will try the revert myself, and attempt to bisect the failure if
it doesn't fix the problem. But disabling the config is our fallback position, and your confirmation will
be very helpful.

Disabling CONFIG_DYNAMIC_FTRACE leads to building problems - ifdefs are not correctly defined.

I'd look into either fixing these, or the horrible return 0 hack.

I'm seeing wildly different behaviour with qemu mips as I jump through revisions
since v3.4. Everything from silent boot death to graphics issues. In fact, 3.8 with
my pending config tweaks is better than anything since 3.4.

Has this really just started happening ? I tested the initial uprev, and it worked, and
3.8 has been the default for quit some time.

I'm trying to figure out what else may have changed that could trigger this.

And finally, if someone can try and fix the build failure with ftrace disabled, that
will be useful, since I'm busy bisecting the kernel build and need some help tasking
it in.

The breakage for this seems to have happened some time ago, in fact, it looks
like the 3.5 timeframe. 

I've built and booted sato about 15 times with the following revert:

commit 0ec615c31233b8cce72242329a2e008e1101524e
Author: Bruce Ashfield <bruce.ashfield@windriver.com>
Date:   Mon Apr 8 12:57:18 2013 -0700

    Revert "ftrace/x86: Have x86 ftrace use the ftrace_modify_all_code()"
    
    This reverts commit e4f5d5440bb860a3e8942ca8f7277a7f31798965.

-----------------------

on standard/mti-malta32

It would be good to hear what it does for other people's boards.

did anyone else try a boot with the last revert I posted ? It works for me here, but
we want more confirmation than just my single test.

I still verify the crash with patch e4f5d5440bb860a3e8942ca8f7277a7f31798965 reverted.

Can you please push your kernel head to a contrib branch ?

Everything was pushed last night, see zedd/kernel-aufs off contrib. Take all the commits.

Bruce

I still reproduce the crash with the zedd/kernel-aufs branch.

I recommend the "return 0;"  patch, however ugly it is.

We aren't going with return 0, we have to have some pride in our work.
Work on the compile failure with the config item turned off, we don't
stub out code.

This has booted 50 or 60 times here, so continuing to point the finger at
the kernel only .. isn't constructive. There is something else going on here,
we need the root cause of why my runs are different than yours.

Per Richard's suggestion, the right way to test this bug is to boot qemu with serial console, and watch the log/dmesg out for a Reserved instruction crash.


The image will boot to graphical display, but no interaction is possible due to the kernel crash. Please follow the dumps above.

Do you really think that I haven't booted to the prompt as many times as the graphical shell ? :)
That works just as well, and is something that I do constantly.

Just logging my build from this morning, sato image, nographic boot to prompt:

root@qemumips:~# uname -a
Linux qemumips 3.8.4-yocto-standard #1 PREEMPT Wed Apr 10 08:00:31 PDT 2013 mips GNU/Linux
root@qemumips:~# dmesg | grep Reserv
root@qemumips:~# 

The summary is that I'm not seeing the Reserved instructions during boot. I'll move to graphical boot now.

Update: we've worked around the problem by building ECHI into the kernel for now. X is
up, mouse works, but no keyboard.

As my bisects were showing, and Alexandru's investigation, this does come back to ftrace
patching module code incorrectly. There's an interaction between the prologue, the module
loader and ftrace. We can completely disable FTRACE as another option, but that only
masks the problem, and has the same result as building the module in (X boots, no
keyboard). 

We do need to fix FTRACE, but that's going to be in a point release. 

The keyboard is a separate issue, and I'd suggest that it isn't related to the same symptom
and a new bug be opened to track it.

Everything appears fixed by http://git.yoctoproject.org/cgit.cgi/poky/commit/?id=4c02dd5f6432c6e683a57d47b610f56433e9ca0d (there were several issues, the ftrace issue breaking kernel modules, the superio being missing breaking the keyboard and likely configu issues breaking the graphics). All of these seem resolved as of the above commit.