[Letux-kernel] Letux-kernel on OpenPandora

H. Nikolaus Schaller hns at goldelico.com
Sun Jun 18 13:07:18 CEST 2017


Hi Marek,

> Am 15.06.2017 um 22:38 schrieb H. Nikolaus Schaller <hns at goldelico.com>:
> 
> Hi Marek,
> I have cc'ed the letux kernel mailing list. Maybe someone else has an idea as well.
> 
>> Am 15.06.2017 um 20:49 schrieb Belisko Marek <marek.belisko at gmail.com>:
>> 
>> Hi Nikolaus,
>> 
>> On Wed, Jun 14, 2017 at 11:14 PM, H. Nikolaus Schaller
>> <hns at goldelico.com> wrote:
>>> Hi Marek,
>>> 
>>>> Am 14.06.2017 um 23:11 schrieb Belisko Marek <marek.belisko at gmail.com>:
>>>> 
>>>> Hi Nikolaus,
>>>> 
>>>> same here. I see only Starting kernel message and then it hangs.
>>> 
>>> Thanks for confirming!
>>> 
>>>> Probably we need to enable earlyprintk and check why kernel hangs
>>>> before console is available. I can check tomorrow. Thanks.
>>> 
>>> Yes, that would be a great help to find this issue. Most likely it is small
>>> since we don't have many differences to GTA04.
>> After enabling earlyprintk:
> 
>> 
>> Starting kernel ...
>> 
>> [    0.000000] Booting Linux on physical CPU 0x0
>> [    0.000000] Linux version 4.12.0-rc5-letux+ (marek at mbuntu) (gcc
>> version 5.4.0 20160609 (Ubuntu/Linaro 5.4.0-6ubuntu1~16.04.4) ) #5 SMP
>> PREEMPT Thu Jun 15 19:06:45 CEST 2017
>> [    0.000000] CPU: ARMv7 Processor [411fc083] revision 3 (ARMv7), cr=10c5387d
>> [    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT
>> nonaliasing instruction cache
>> [    0.000000] OF: fdt: Machine model: Pandora Handheld Console
>> [    0.000000] bootconsole [earlycon0] enabled
>> [    0.000000] debug: ignoring loglevel setting.
>> [    0.000000] ------------[ cut here ]------------
>> [    0.000000] WARNING: CPU: 0 PID: 0 at kernel/printk/printk.c:2422
>> register_console+0x3c/0x3c4
>> [    0.000000] console 'earlycon0' already registered
>> [    0.000000] Modules linked in:
>> [    0.000000] CPU: 0 PID: 0 Comm: swapper Not tainted 4.12.0-rc5-letux+ #5
>> [    0.000000] Hardware name: Generic OMAP3 (Flattened Device Tree)
>> [    0.000000] [<c010f2e0>] (unwind_backtrace) from [<c010b868>]
>> (show_stack+0x10/0x14)
>> [    0.000000] [<c010b868>] (show_stack) from [<c043e1c8>]
>> (dump_stack+0x90/0xc4)
>> [    0.000000] [<c043e1c8>] (dump_stack) from [<c012f24c>] (__warn+0xc8/0xfc)
>> [    0.000000] [<c012f24c>] (__warn) from [<c012f2b4>]
>> (warn_slowpath_fmt+0x34/0x44)
>> [    0.000000] [<c012f2b4>] (warn_slowpath_fmt) from [<c018ea1c>]
>> (register_console+0x3c/0x3c4)
>> [    0.000000] [<c018ea1c>] (register_console) from [<c0b05a90>]
>> (setup_early_printk+0x14/0x24)
>> [    0.000000] [<c0b05a90>] (setup_early_printk) from [<c0b00478>]
>> (do_early_param+0x6c/0xbc)
>> [    0.000000] [<c0b00478>] (do_early_param) from [<c0151e6c>]
>> (parse_args+0x194/0x284)
>> [    0.000000] [<c0151e6c>] (parse_args) from [<c0b00878>]
>> (parse_early_options+0x2c/0x3c)
>> [    0.000000] [<c0b00878>] (parse_early_options) from [<c0b008b4>]
>> (parse_early_param+0x2c/0x3c)
>> [    0.000000] [<c0b008b4>] (parse_early_param) from [<c0b03e84>]
>> (setup_arch+0x508/0xb54)
>> [    0.000000] [<c0b03e84>] (setup_arch) from [<c0b00924>]
>> (start_kernel+0x54/0x398)
>> [    0.000000] [<c0b00924>] (start_kernel) from [<8000807c>] (0x8000807c)
>> [    0.000000] ---[ end trace 0000000000000000 ]---
> 
> that can indeed be ignored
> 
>> [    0.000000] Memory policy: Data cache writeback
>> [    0.000000] cma: Reserved 16 MiB at 0x9e800000
>> [    0.000000] On node 0 totalpages: 130560
>> [    0.000000] free_area_init_node: node 0, pgdat c0ca42c0,
>> node_mem_map df9f1000
>> [    0.000000]   Normal zone: 1020 pages used for memmap
>> [    0.000000]   Normal zone: 0 pages reserved
>> [    0.000000]   Normal zone: 130560 pages, LIFO batch:31
>> [    0.000000] CPU: All CPU(s) started in SVC mode.
>> [    0.000000] OMAP3430/3530 ES3.1 (l2cache iva sgx neon isp)
>> [    0.000000] percpu: Embedded 17 pages/cpu @df99a000 s40296 r8192
>> d21144 u69632
>> [    0.000000] pcpu-alloc: s40296 r8192 d21144 u69632 alloc=17*4096
>> [    0.000000] pcpu-alloc: [0] 0
>> [    0.000000] Built 1 zonelists in Zone order, mobility grouping on.
>> Total pages: 129540
>> [    0.000000] Kernel command line: console=ttyO2,115200n8 ubi.mtd=
>> root=/dev/mmcblk0p1 rw rootfstype=ext4,ext3 rootwait earlyprintk
>> console=ttyO2,115200n8 vram=12M omapfb.vram=0:8M,1:4M
>> omapfb.rotate_type=0 omapdss.def_disp=lcd rootwait k
>> [    0.000000] UBI warning: empty 'mtd=' parameter - ignored
>> [    0.000000] log_buf_len: 8388608 bytes
>> [    0.000000] early log buf free: 62172(94%)
>> [    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: 472732K/522240K available (7168K kernel code,
>> 681K rwdata, 2268K rodata, 1024K init, 8002K bss, 33124K reserved,
>> 16384K cma-reserved, 0K highmem)
> 
> looks ok so far
> 
>> [    0.000000] Virtual kernel memory layout:
>> [    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
>> [    0.000000]     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
>> [    0.000000]     vmalloc : 0xe0000000 - 0xff800000   ( 504 MB)
>> [    0.000000]     lowmem  : 0xc0000000 - 0xdfe00000   ( 510 MB)
>> [    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
>> [    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
>> [    0.000000]       .text : 0xc0008000 - 0xc0800000   (8160 kB)
>> [    0.000000]       .init : 0xc0b00000 - 0xc0c00000   (1024 kB)
>> [    0.000000]       .data : 0xc0c00000 - 0xc0caa468   ( 682 kB)
>> [    0.000000]        .bss : 0xc0caa468 - 0xc147ae64   (8003 kB)
>> [    0.000000] Running RCU self tests
>> [    0.000000] Preemptible hierarchical RCU implementation.
>> [    0.000000]  RCU lockdep checking is enabled.
>> [    0.000000]  RCU restricting CPUs from NR_CPUS=2 to nr_cpu_ids=1.
>> [    0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
>> [    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] Clocking rate (Crystal/Core/MPU): 26.0/332/500 MHz
>> [    0.000000] OMAP clockevent source: timer1 at 32768 Hz
>> [    0.000000] clocksource: 32k_counter: mask: 0xffffffff max_cycles:
>> 0xffffffff, max_idle_ns: 58327039986419 ns
>> [    0.000030] sched_clock: 32 bits at 32kHz, resolution 30517ns,
>> wraps every 65535999984741ns
>> [    0.008728] OMAP clocksource: 32k_counter at 32768 Hz
>> [    0.017333] Console: colour dummy device 80x30
>> [    0.022186] Lock dependency validator: Copyright (c) 2006 Red Hat,
>> Inc., Ingo Molnar
>> [    0.030364] ... MAX_LOCKDEP_SUBCLASSES:  8
>> [    0.034698] ... MAX_LOCK_DEPTH:          48
>> [    0.039184] ... MAX_LOCKDEP_KEYS:        8191
>> [    0.043792] ... CLASSHASH_SIZE:          4096
>> [    0.048370] ... MAX_LOCKDEP_ENTRIES:     32768
>> [    0.053131] ... MAX_LOCKDEP_CHAINS:      65536
>> [    0.057830] ... CHAINHASH_SIZE:          32768
>> [    0.062591]  memory used by lock dependency info: 5167 kB
>> [    0.068237]  per task-struct memory footprint: 1536 bytes
>> [    0.074035] Calibrating delay loop... 493.97 BogoMIPS (lpj=2469888)
>> [    0.135040] pid_max: default: 32768 minimum: 301
>> [    0.140716] Security Framework initialized
>> [    0.145294] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
>> [    0.152313] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
>> [    0.165649] CPU: Testing write buffer coherency: ok
>> [    0.174713] CPU0: thread -1, cpu 0, socket -1, mpidr 0
>> [    0.218749] Setting up static identity map for 0x80100000 - 0x80100060
>> [    0.268402] smp: Bringing up secondary CPUs ...
>> [    0.273193] smp: Brought up 1 node, 1 CPU
>> [    0.277435] SMP: Total of 1 processors activated (493.97 BogoMIPS).
>> [    0.284271] CPU: All CPU(s) started in SVC mode.
> 
> all fine so far
> 
>> [    0.297027] devtmpfs: initialized
>> [    0.459106] VFP support v0.3: implementor 41 architecture 3 part 30
>> variant c rev 1
>> [    0.480407] clocksource: jiffies: mask: 0xffffffff max_cycles:
>> 0xffffffff, max_idle_ns: 19112604462750000 ns
>> [    0.492645] futex hash table entries: 256 (order: 2, 16384 bytes)
>> [    0.504180] pinctrl core: initialized pinctrl subsystem
>> [    0.526672] NET: Registered protocol family 16
>> [    0.552429] DMA: preallocated 256 KiB pool for atomic coherent allocations
>> [    0.703948] omap_hwmod: mcbsp2_sidetone using broken dt data from mcbsp
>> [    0.715087] omap_hwmod: mcbsp3_sidetone using broken dt data from mcbsp
>> [    0.924774] Reprogramming SDRC clock to 332000000 Hz
>> [    0.992492] OMAP GPIO hardware version 2.5
>> [    1.089721] irq: no irq domain found for
>> /ocp at 68000000/l4 at 48000000/scm at 2000/pinmux at 30 !
> 
> ^^^ ok or not ok?
> 
>> [    1.185394] omap-gpmc 6e000000.gpmc: GPMC revision 5.0
>> [    1.192749] gpmc_mem_init: disabling cs 0 mapped at 0x0-0x1000000
>> [    1.253387] No ATAGs?
> 
> that is a standard error
> 
>> [    1.253417] hw-breakpoint: debug architecture 0x4 unsupported.
>> [    1.267364] omap4_sram_init:Unable to allocate sram needed to
>> handle errata I688
>> [    1.275115] omap4_sram_init:Unable to get sram pool needed to
>> handle errata I688
> 
> as well
> 
>> [    1.287445] OMAP DMA hardware revision 4.0
>> [    1.699005] omap-dma-engine 48056000.dma-controller: OMAP DMA engine driver
>> [    1.742309] omap-iommu 480bd400.mmu: 480bd400.mmu registered
>> [    1.751770] iommu: Adding device 480bc000.isp to group 0
>> [    1.769531] SCSI subsystem initialized
>> [    1.787109] libata version 3.00 loaded.
>> [    1.793090] usbcore: registered new interface driver usbfs
>> [    1.807312] usbcore: registered new interface driver hub
>> [    1.814361] usbcore: registered new device driver usb
>> [    1.837402] omap_i2c 48070000.i2c: bus 0 rev3.3 at 2600 kHz
>> [    1.848327] omap_i2c 48072000.i2c: bus 1 rev3.3 at 100 kHz
>> [    1.860504] omap_i2c 48060000.i2c: bus 2 rev3.3 at 100 kHz
> 
> even i2c is up and running
> 
>> [    1.873992] Advanced Linux Sound Architecture Driver Initialized.
>> [    1.908325] clocksource: Switched to clocksource 32k_counter
>>                                +-----------------------------+
>> [    2.260925] VFS: Disk quotas dquot_6.6.0
>>                                |                             |
>> [    2.265380] VFS: Dquot-cache hash table entries: 1024 (order 0,
>> 4096 bytes)                          |  Cannot open /dev/ttyUSB0!  |
>> [    2.436401] NET: Registered protocol family 2
>>                                |                             |
>> [    2.449798] TCP established hash table entries: 4096 (order: 2,
>> 16384 bytes)                         +-----------------------------+
>> [    2.457366] TCP bind hash table entries: 4096 (order: 5, 147456
>> bytes)
>> [    2.467712] TCP: Hash tables configured (established 4096 bind
>> 4096)
>> [    2.475616] UDP hash table entries: 256 (order: 2, 20480 bytes)
>> [    2.482604] UDP-Lite hash table entries: 256 (order: 2, 20480
>> bytes)
>> [    2.491180] NET: Registered protocol family 1
>> [    2.510742] hw perfevents: no interrupt-affinity property for
>> /pmu at 54000000, guessing.
>> [    2.520751] hw perfevents: enabled with armv7_cortex_a8 PMU driver,
>> 5 counters available
>> [    2.548858] random: fast init done
>> [    2.558898] audit: initializing netlink subsys (disabled)
>> [    2.567810] audit: type=2000 audit(2.569:1): state=initialized
>> audit_enabled=0 res=1
>> [    2.587554] workingset: timestamp_bits=30 max_order=17 bucket_order=0
>> [    2.610839] squashfs: version 4.0 (2009/01/31) Phillip Lougher
>> [    2.642425] Block layer SCSI generic (bsg) driver version 0.4
>> loaded (major 251)
>> [    2.652343] io scheduler noop registered
>> [    2.656524] io scheduler deadline registered
>> [    2.662261] io scheduler cfq registered (default)
>> [    2.667205] io scheduler mq-deadline registered
>> [    2.672760] io scheduler kyber registered
> 
> fine up to here
> 
>> [    2.689941] pinctrl-single 48002030.pinmux: 284 pins at pa fa002030 size 568
> 
> does it hang after this line?

I now found a little time to try earlyprink as well and I have the same.

My Pandora hangs here as well.

> 
> Then I would think that we have a bug in pinmux DT which disables something which
> is essential for further operation.
> 
> A simple bug could be that we disable UART pinmux... And the kernel hangs later
> with something else. But we simply are not informed about.

Next I have added some printk to pinctrl_select_state() and pinmux_enable_setting()
to see what is ging on:

[    2.704895] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[    2.714721] io scheduler noop registered
[    2.720123] io scheduler deadline registered
[    2.724700] io scheduler cfq registered (default)
[    2.730438] io scheduler mq-deadline registered
[    2.735229] io scheduler kyber registered
[    2.751708] pinctrl-single 48002030.pinmux: 284 pins at pa fa002030 size 568
[    2.760925] pinctrl_select_state: 48002030.pinmux 2
[    2.766082] pinmux_enable_setting: 
[    2.770782] pinmux_enable_setting: alloc 0
[    2.775115] pinmux_enable_setting: alloc 1
[    2.779815] pinmux_enable_setting: alloc 2
[    2.784179] pinmux_enable_setting: alloc 3
[    2.788818] pinmux_enable_setting: alloc 4
[    2.793151] pinmux_enable_setting: alloc 5
[    2.797485] pinmux_enable_setting: alloc 6
[    2.801971] pinmux_enable_setting: alloc 7
[    2.806304] pinmux_enable_setting: set 0 PIN210
[    2.811218] pinmux_enable_setting: set 1 PIN211
[    2.815979] pinmux_enable_setting: set 2 PIN212
[    2.820892] pinmux_enable_setting: set 3 PIN213
[    2.825683] pinmux_enable_setting: set 4 PIN214
[    2.830596] pinmux_enable_setting: set 5 PIN215
[    2.835357] pinmux_enable_setting: set 6 PIN181
[    2.840270] pinmux_enable_setting: set 7 PIN182
[    2.845062] pinmux_enable_setting: now set mux
[    2.850158] pinmux_enable_setting: done (0)
[    2.854583] pinctrl_select_state: 48002030.pinmux 2
[    2.859863] pinmux_enable_setting: 
[    2.863586] pinmux_enable_setting: alloc 0
[    2.867919] pinmux_enable_setting: alloc 1
[    2.872375] pinmux_enable_setting: alloc 2
[    2.876708] pinmux_enable_setting: alloc 3
[    2.881225] pinmux_enable_setting: alloc 4
[    2.885559] pinmux_enable_setting: alloc 5
[    2.890014] pinmux_enable_setting: set 0 PIN2
[    2.894622] pinmux_enable_setting: set 1 PIN3
[    2.899353] pinmux_enable_setting: set 2 PIN4
[    2.903961] pinmux_enable_setting: set 3 PIN9
[    2.908691] pinmux_enable_setting: set 4 PIN10
[    2.913360] pinmux_enable_setting: set 5 PIN11
[    2.918182] pinmux_enable_setting: now set mux
[    2.922912] pinmux_enable_setting: done (0)

So this means that 2 banks of pinmuxes are set - and setting succeeds!
Then, everything hangs.

Maybe I should also dump_stack() to see who calls pinctrl_select_state().

BR,
Nikolaus


> 
>> 
>> I don't see anything obvious. Maybe it's issue with mounting sdcard
>> (as I cannot see any info in kernel bootlog).
> 
> That usually comes later. And we would see a message.
> The first would be about initializing the mmc interfaces and potentially finding
> an SD card.
> The second about mounting rootfs - or failure.
> 
>> Any other ideas?
> 
> Ah one more idea. If I remember correctly there had been some Pandora specific
> hwmods and platform data like patches/tricks. Maybe someone did remove them
> without testing/providing a good enough replacement.
> 
>> Do you know that some 4.10, 4.11 works on Pandora? Thanks.
> 
> I think it did work 6 months ago...
> 
> If you have a little time, you could try to install older uImages (for boot tests it is not even required to install kernel modules):
> 
> http://download.goldelico.com/letux-kernel/letux-4.10.5/
> http://download.goldelico.com/letux-kernel/letux-4.9.4/
> http://download.goldelico.com/letux-kernel/letux-4.8.11/
> http://download.goldelico.com/letux-kernel/letux-4.7/
> 
> BR,
> Nikolaus
> 
> _______________________________________________
> http://projects.goldelico.com/p/gta04-kernel/
> Letux-kernel mailing list
> Letux-kernel at openphoenux.org
> http://lists.goldelico.com/mailman/listinfo.cgi/letux-kernel



More information about the Letux-kernel mailing list