[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