Letux Kernel

Issue 464: "Reboot" fails

Reported by Nikolaus Schaller, Jul 26, 2013

it appears as if a "reboot" command with USB connected 
fails. The devices goes through the U-Boot sequence, but the kernel 
simply hangs after "Starting kernel ...".

Maybe this is related to a bug recently mentioned for the BB-XM 
3.11-rx2 kernel, where it is said that there is a problem if the 
MUSB is already initialized (which is when doing a 
"reboot").

Comment 1 by Nikolaus Schaller, Jul 28, 2013

Labels: Milestone:3.10

Comment 2 by Nikolaus Schaller, Jul 29, 2013

Further analysis shows that it is NOT dependent on using the USB 
cable.

The situation is:
* removing battery + reinsert -> boots
* 'powerdown' + pressing power button -> boots
* long-press power button + power button -> boots
* 'reboot' -> hangs after "Starting kernel..."

So this indicates that (most likely) the TWL4030 stores some state 
between the reboot and starting the kernel that prevents the kernel 
to properly initialize. It could be some driver that is not prepared 
to find it's device already initialized and therefore hangs in an 
endless loop.

Unfortunately we don't see any kernel messages (after "Starting 
kernel..."). A debugging tool could be to enable low-level 
debugging (AFAIK it does not buffer the console going to the UART 
but writes immediately).

Comment 3 by Nikolaus Schaller, Jul 29, 2013

This is what I see with low-level OMAP/UART3 debugging enabled:


lcm state set to deep-standby
display power off
## Booting kernel from Legacy Image at 82000000 ...
   Image Name:   Linux-3.11.0-rc2-gta04
   Image Type:   ARM Linux Kernel Image (uncompressed)
   Data Size:    3271784 Bytes = 3.1 MiB
   Load Address: 80008000
   Entry Point:  80008000
   Verifying Checksum ... OK
   Loading Kernel Image ... OK
OK

Starting kernel ...

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 3.11.0-rc2-gta04 (hns@iMac.local) (gcc 
version 4.6.3 (GCC) ) #2 PREEMPT Mon Jul 29 16:25:27 CEST 2013
[    0.000000] CPU: ARMv7 Processor [413fc082] revision 2 (ARMv7), 
cr=10c53c7d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT 
aliasing instruction cache
[    0.000000] Machine: GTA04
[    0.000000] debug: ignoring loglevel setting.
[    0.000000] bootconsole [earlycon0] enabled
[    0.000000] Memory policy: ECC disabled, Data cache writeback
[    0.000000] On node 0 totalpages: 130816
[    0.000000] free_area_init_node: node 0, pgdat c06748b4, 
node_mem_map c089c000
[    0.000000]   Normal zone: 1024 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 130816 pages, LIFO batch:31
[    0.000000] CPU: All CPU(s) started in SVC mode.
[    0.000000] OMAP3630 ES1.2 (l2cache iva sgx neon isp 192mhz_clk )
[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[    0.000000] pcpu-alloc: [0] 0 
[    0.000000] Built 1 zonelists in Zone order, mobility grouping 
on.  Total pages: 129792
[    0.000000] Kernel command line: console=ttyO2,115200n8 vram=12M 
omapfb.vram=0:8M,1:4M omapfb.rotate_type=0 omapdss.def_disp=lcd 
rootwait twl4030_charger.allow_usb=1 musb_hdrc.preserve_vbus=1 
log_buf_len=8M ignore_loglevel eat
[    0.000000] log_buf_len: 8388608
[    0.000000] early log buf free: 2095488(99%)
[    0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
[    0.000000] Dentry cache hash table entries: 65536 (order: 6, 
262144 bytes)
[    0.000000] Inode-cache hash table entries: 32768 (order: 5, 
131072 bytes)
[    0.000000] Memory: 501716K/523264K available (4484K kernel code, 
292K rwdata, 1588K rodata, 208K init, 2199K bss, 21548K reserved, 0K 
highmem)
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xfff00000 - 0xfffe0000   ( 896 kB)
[    0.000000]     vmalloc : 0xe0800000 - 0xff000000   ( 488 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xe0000000   ( 512 MB)
[    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
[    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
[    0.000000]       .text : 0xc0008000 - 0xc05f65bc   (6074 kB)
[    0.000000]       .init : 0xc05f7000 - 0xc062b138   ( 209 kB)
[    0.000000]       .data : 0xc062c000 - 0xc06752c0   ( 293 kB)
[    0.000000]        .bss : 0xc06752c0 - 0xc089b170   (2200 kB)
[    0.000000] Preemptible hierarchical RCU implementation.
[    0.000000] NR_IRQS:16 nr_irqs:16 16
[    0.000000] IRQ: Found an INTC at 0xfa200000 (revision 4.0) with 
96 interrupts
[    0.000000] Total of 96 interrupts on 1 active controller
[    0.000000] Clocking rate (Crystal/Core/MPU): 26.0/332/600 MHz
[    0.000000] OMAP clockevent source: timer12 at 32768 Hz
[    0.000000] sched_clock: 32 bits at 32kHz, resolution 30517ns, 
wraps every 131071999ms
[    0.000000] OMAP clocksource: 32k_counter at 32768 Hz
[    0.000000] Console: colour dummy device 80x30
[    0.010284] Calibrating delay loop... 334.23 BogoMIPS 
(lpj=1671168)
[    0.065002] pid_max: default: 32768 minimum: 301
[    0.069946] Mount-cache hash table entries: 512
[    0.075408] CPU: Testing write buffer coherency: ok
[    0.080871] Setting up static identity map for 0xc0439838 - 
0xc0439890
[    0.088958] devtmpfs: initialized
[    0.149841] pinctrl core: initialized pinctrl subsystem
[    0.155761] regulator-dummy: no parameters
[    0.160369] NET: Registered protocol family 16
[    0.166046] DMA: preallocated 256 KiB pool for atomic coherent 
allocations
[    0.173522] omap-gpmc omap-gpmc: GPMC revision 5.0
[    0.180297] OMAP GPIO hardware version 2.5
[    0.188598] running gta04_init()
[    0.192199] omap_mux_init: Add partition: #1: core, flags: 4
[    0.206268] Reprogramming SDRC clock to 332000000 Hz
[    0.214477] Revision GTA04A3
[    0.219512] gta04_init done...
[    0.222778] hw-breakpoint: debug architecture 0x4 unsupported.

Comment 4 by Nikolaus Schaller, Jul 29, 2013

And this is after forcing power down and rebooting:


Environment size: 3132/131068 bytes
lcm state set to deep-standby
display power off
## Booting kernel from Legacy Image at 82000000 ...
   Image Name:   Linux-3.11.0-rc2-gta04
   Image Type:   ARM Linux Kernel Image (uncompressed)
   Data Size:    3271784 Bytes = 3.1 MiB
   Load Address: 80008000
   Entry Point:  80008000
   Verifying Checksum ... OK
   Loading Kernel Image ... OK
OK

Starting kernel ...

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 3.11.0-rc2-gta04 (hns@iMac.local) (gcc 
version 4.6.3 (GCC) ) #2 PREEMPT Mon Jul 29 16:25:27 CEST 2013
[    0.000000] CPU: ARMv7 Processor [413fc082] revision 2 (ARMv7), 
cr=10c53c7d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT 
aliasing instruction cache
[    0.000000] Machine: GTA04
[    0.000000] debug: ignoring loglevel setting.
[    0.000000] bootconsole [earlycon0] enabled
[    0.000000] Memory policy: ECC disabled, Data cache writeback
[    0.000000] On node 0 totalpages: 130816
[    0.000000] free_area_init_node: node 0, pgdat c06748b4, 
node_mem_map c089c000
[    0.000000]   Normal zone: 1024 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 130816 pages, LIFO batch:31
[    0.000000] CPU: All CPU(s) started in SVC mode.
[    0.000000] OMAP3630 ES1.2 (l2cache iva sgx neon isp 192mhz_clk )
[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[    0.000000] pcpu-alloc: [0] 0 
[    0.000000] Built 1 zonelists in Zone order, mobility grouping 
on.  Total pages: 129792
[    0.000000] Kernel command line: console=ttyO2,115200n8 vram=12M 
omapfb.vram=0:8M,1:4M omapfb.rotate_type=0 omapdss.def_disp=lcd 
rootwait twl4030_charger.allow_usb=1 musb_hdrc.preserve_vbus=1 
log_buf_len=8M ignore_loglevel eat
[    0.000000] log_buf_len: 8388608
[    0.000000] early log buf free: 2095488(99%)
[    0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
[    0.000000] Dentry cache hash table entries: 65536 (order: 6, 
262144 bytes)
[    0.000000] Inode-cache hash table entries: 32768 (order: 5, 
131072 bytes)
[    0.000000] Memory: 501716K/523264K available (4484K kernel code, 
292K rwdata, 1588K rodata, 208K init, 2199K bss, 21548K reserved, 0K 
highmem)
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xfff00000 - 0xfffe0000   ( 896 kB)
[    0.000000]     vmalloc : 0xe0800000 - 0xff000000   ( 488 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xe0000000   ( 512 MB)
[    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
[    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
[    0.000000]       .text : 0xc0008000 - 0xc05f65bc   (6074 kB)
[    0.000000]       .init : 0xc05f7000 - 0xc062b138   ( 209 kB)
[    0.000000]       .data : 0xc062c000 - 0xc06752c0   ( 293 kB)
[    0.000000]        .bss : 0xc06752c0 - 0xc089b170   (2200 kB)
[    0.000000] Preemptible hierarchical RCU implementation.
[    0.000000] NR_IRQS:16 nr_irqs:16 16
[    0.000000] IRQ: Found an INTC at 0xfa200000 (revision 4.0) with 
96 interrupts
[    0.000000] Total of 96 interrupts on 1 active controller
[    0.000000] Clocking rate (Crystal/Core/MPU): 26.0/332/600 MHz
[    0.000000] OMAP clockevent source: timer12 at 32768 Hz
[    0.000000] sched_clock: 32 bits at 32kHz, resolution 30517ns, 
wraps every 131071999ms
[    0.000000] OMAP clocksource: 32k_counter at 32768 Hz
[    0.000000] Console: colour dummy device 80x30
[    0.010284] Calibrating delay loop... 336.69 BogoMIPS 
(lpj=1683456)
[    0.065185] pid_max: default: 32768 minimum: 301
[    0.070159] Mount-cache hash table entries: 512
[    0.075592] CPU: Testing write buffer coherency: ok
[    0.081054] Setting up static identity map for 0xc0439838 - 
0xc0439890
[    0.089141] devtmpfs: initialized
[    0.142791] pinctrl core: initialized pinctrl subsystem
[    0.148712] regulator-dummy: no parameters
[    0.153289] NET: Registered protocol family 16
[    0.158966] DMA: preallocated 256 KiB pool for atomic coherent 
allocations
[    0.166473] omap-gpmc omap-gpmc: GPMC revision 5.0
[    0.173309] OMAP GPIO hardware version 2.5
[    0.181579] running gta04_init()
[    0.185150] omap_mux_init: Add partition: #1: core, flags: 4
[    0.199279] Reprogramming SDRC clock to 332000000 Hz
[    0.207489] Revision GTA04A3
[    0.212463] gta04_init done...
[    0.215728] hw-breakpoint: debug architecture 0x4 unsupported.
[    0.226165] Switched to new clocking rate (Crystal/Core/MPU): 
26.0/332/800 MHz
[    0.233917] OMAP DMA hardware revision 5.0
[    0.243530] bio: create slab <bio-0> at 0
[    0.258117] omap-dma-engine omap-dma-engine: OMAP DMA engine 
driver


So this indicates that clock switching does not work after a 
"reboot":

[    0.226165] Switched to new clocking rate (Crystal/Core/MPU): 
26.0/332/800 MHz

Comment 5 by Nikolaus Schaller, Jul 29, 2013

Further inserted printk commands appear to show that it hangs in

	r = clk_set_rate(mpurate_ck, mpurate);

on line 613 in function omap2_clk_switch_mpurate_at_boot() of 
arch/arm/mach-omap2/clock.c

mpurate=800000000l (in both cases).

Comment 6 by Nikolaus Schaller, Jul 29, 2013

title fixed since it does not have to do anything with USB
Summary: "Reboot" fails

Comment 7 by Nikolaus Schaller, Jul 29, 2013

Fixed by

http://git.goldelico.com/?p=gta04-kernel.git;a=commit;h=dc3089217005c
99d1450c9f5da0499786d2c120d
Status: Fixed

Created: 8 years 5 months ago by Nikolaus Schaller

Updated: 8 years 5 months ago

Status: Fixed

Labels:
Type:Defect
Priority:Critical
Milestone:3.10