Am 23.06.2018 um 12:13 schrieb H. Nikolaus Schaller hns@goldelico.com:
Hi all,
Am 22.06.2018 um 13:34 schrieb H. Nikolaus Schaller hns@goldelico.com:
Am 22.06.2018 um 09:16 schrieb Tony Lindgren tony@atomide.com:
- H. Nikolaus Schaller hns@goldelico.com [180621 17:48]:
selector = pinctrl_generic_group_name_to_selector(pctldev, name); if (selector >= 0) { printk("%s: pctldev=%px name=%s found selector=%d\n", __func__, pctldev, name, pctldev->num_groups);
well, my printk isn't correct! I'll check if the result is just an effect of the wrong printk.
Oh OK :)
Yes, they were wrong. Now here a log with correct printk. Looks sane on first impression:
root@letux:~# dmesg|grep "dt_free|generic_add|deferred" [ 0.759490] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_hsusb2_pins new selector=0 [ 0.761657] pinctrl_generic_add_group: pctldev=ee35ff80 name=pinmux_hsusb2_2_pins new selector=0 [ 0.762420] pinctrl_generic_add_group: pctldev=ee35fe00 name=pinmux_mcbsp1_devconf0_pins new selector=0 [ 0.763092] pinctrl_generic_add_group: pctldev=ee35fd00 name=pinmux_tv_acbias_devconf1_pins new selector=0 [ 0.780242] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_uart1_pins new selector=1 [ 0.781921] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_uart2_pins new selector=2 [ 0.783050] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_uart3_pins new selector=3 [ 1.812499] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_twl4030_pins new selector=4 [ 1.822235] pinctrl_generic_add_group: pctldev=ee445000 name=pinmux_twl4030_vpins new selector=0 [ 1.989715] pinctrl_generic_add_group: pctldev=ee35ff80 name=spi_gpio_pinmux new selector=1 [ 2.184509] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_mmc1_pins new selector=5 [ 2.221252] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_wlan_irq_pin new selector=6 [ 2.241210] pcs_dt_free_map: pctldev=ee445180 [ 2.394989] platform 6e000000.gpmc: Retrying from deferred list [ 2.401672] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_gpmc_pins new selector=7 [ 2.789489] platform wlan_en_regulator: Retrying from deferred list [ 2.796203] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_wlan_pins new selector=8 [ 2.806518] platform bt_en_regulator: Retrying from deferred list [ 2.813354] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_bt_pins new selector=9 [ 2.822723] platform 480b4000.mmc: Retrying from deferred list [ 2.829711] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_wlan_irq_pin found selector=6 [ 5.385803] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_dss_dpi_pins new selector=10 [ 6.019317] platform 48070000.i2c:twl@48:bci: Retrying from deferred list [ 6.066497] platform 48070000.i2c:twl@48:bci: Retrying from deferred list [ 6.080902] platform 48070000.i2c:twl@48:bci: Retrying from deferred list [ 6.143432] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_penirq_pins new selector=11 [ 6.218383] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_mcbsp1_pins new selector=12 [ 6.282104] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_mcbsp2_pins new selector=13 [ 6.424468] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins new selector=14 [ 6.473358] pcs_dt_free_map: pctldev=ee445180 [ 6.713745] i2c 1-0030: Retrying from deferred list [ 6.724761] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins found selector=14 [ 6.742156] pcs_dt_free_map: pctldev=ee445180 [ 6.748229] pinctrl_generic_add_group: pctldev=ee445180 name=hdq_pins new selector=15 [ 6.756622] i2c 1-0030: Retrying from deferred list [ 6.762542] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins found selector=14 [ 6.782073] pcs_dt_free_map: pctldev=ee445180 [ 6.795288] i2c 1-0030: Retrying from deferred list [ 6.804748] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins found selector=14 [ 6.822540] pcs_dt_free_map: pctldev=ee445180 [ 6.890319] i2c 1-0030: Retrying from deferred list [ 6.895629] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins found selector=14 [ 6.935729] pcs_dt_free_map: pctldev=ee445180 [ 6.951324] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_mcbsp3_pins new selector=16 [ 6.960571] i2c 1-0030: Retrying from deferred list [ 7.028198] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins found selector=14 [ 7.037719] pcs_dt_free_map: pctldev=ee445180 [ 7.057189] i2c 1-0030: Retrying from deferred list [ 7.062652] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_mcbsp4_pins new selector=17 [ 7.136230] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins found selector=14 [ 7.153869] pcs_dt_free_map: pctldev=ee445180 [ 7.164825] i2c 1-0030: Retrying from deferred list [ 7.174407] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins found selector=14 [ 7.196655] pcs_dt_free_map: pctldev=ee445180 [ 7.216339] pinctrl_generic_add_group: pctldev=ee445180 name=backlight_pins_pinmux new selector=18 [ 7.405364] pcs_dt_free_map: pctldev=ee445180 [ 7.460327] i2c 1-0030: Retrying from deferred list [ 7.470367] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins found selector=14 [ 7.491027] pcs_dt_free_map: pctldev=ee445180 [ 7.501129] platform backlight: Retrying from deferred list [ 7.513153] pinctrl_generic_add_group: pctldev=ee445180 name=backlight_pins_pinmux found selector=18 [ 7.563171] i2c 1-0030: Retrying from deferred list [ 7.574401] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins found selector=14 [ 7.606201] pcs_dt_free_map: pctldev=ee445180 [ 7.729339] i2c 1-0030: Retrying from deferred list [ 7.734680] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins found selector=14 [ 7.758361] pcs_dt_free_map: pctldev=ee445180 [ 7.763092] pinctrl_generic_add_group: pctldev=ee445180 name=modem_pins new selector=19 [ 8.287200] i2c 1-0030: Retrying from deferred list [ 8.301971] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins found selector=14 [ 8.314514] pcs_dt_free_map: pctldev=ee445180 [ 8.392425] i2c 1-0030: Retrying from deferred list [ 8.397766] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins found selector=14 [ 8.421295] pcs_dt_free_map: pctldev=ee445180 [ 8.425994] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_pps_pins new selector=20 [ 8.518798] i2c 1-0030: Retrying from deferred list [ 8.524169] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins found selector=14 [ 8.548370] pcs_dt_free_map: pctldev=ee445180 [ 9.366851] platform sound_bluetooth: Retrying from deferred list [ 9.381958] platform sound_fmradio: Retrying from deferred list [ 9.396972] i2c 1-0030: Retrying from deferred list [ 9.407379] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins found selector=14 [ 9.427551] pcs_dt_free_map: pctldev=ee445180 [ 9.583404] platform sound_bluetooth: Retrying from deferred list [ 9.616180] platform sound_fmradio: Retrying from deferred list [ 9.637329] i2c 1-0030: Retrying from deferred list [ 9.644073] pinctrl_generic_add_group: pctldev=ee445180 name=pinmux_camera_pins found selector=14 [ 9.654144] pcs_dt_free_map: pctldev=ee445180 root@letux:~#
And I didn't see the strcmp(NULL) any more. I already was suspecting that it is a Heisenbug: the more you study it, the less likely it appears.
Maybe the printk have some (positive) side-effect (internal locking)?
To test that I have reverted all patches with printk which produce the log from above. Only after removing the printk in pcs_dt_free_map(), the strcmp(NULL) came back.
Next I'll try to find out if I can add the other patches to see something...
I think I now have a scenario with additional information. I removed the printk in pcs_dt_free_map() and I get the strcmp(NULL) again.
So far there are several workarounds to get rid of the problem: a) add printk to pcs_dt_free_map() b) add printk to pinctrl_generic_add_group() c) blacklist some drivers which are loaded around the critical point
So I had to keep them all, but still get useful debugging information. Therefore I added a test for gname == NULL to print a stack dump and the whole list of selectors in that case:
static int pinctrl_generic_group_name_to_selector(struct pinctrl_dev *pctldev, const char *function) { const struct pinctrl_ops *ops = pctldev->desc->pctlops; unsigned ngroups = ops->get_groups_count(pctldev); unsigned selector = 0;
/* See if this pctldev has this group */ while (selector < ngroups) { const char *gname = ops->get_group_name(pctldev, selector);
if (!gname || !function) { printk("%s: pctldev = %px function = %s\n", __func__, pctldev, function); printk(" strcmp(%s, %s)\n", function, gname); printk(" get_group_name() = %pF\n", ops->get_group_name); printk(" ngroups = %u\n", ngroups); printk(" selector = %u\n", selector); dump_stack(); selector = 0; while (selector < ngroups) { const char *gname = ops->get_group_name(pctldev, selector); printk(" gname[%u] = %s\n", selector, gname); selector++; } return -EINVAL; }
if (!strcmp(function, gname)) return selector; selector++;}
return -EINVAL; }
and
int pinctrl_get_group_selector(struct pinctrl_dev *pctldev, const char *pin_group) { const struct pinctrl_ops *pctlops = pctldev->desc->pctlops; unsigned ngroups = pctlops->get_groups_count(pctldev); unsigned group_selector = 0;
while (group_selector < ngroups) { const char *gname = pctlops->get_group_name(pctldev, group_selector); if (!gname || !pin_group) { printk("%s: strcmp: %s %s\n", __func__, gname, pin_group); printk(" group_selector = %u\n", group_selector); printk(" get_group_name = %pF\n", pctlops->get_group_name); printk(" pctldev = %pF\n", pctldev); } if (!strcmp(gname, pin_group)) { dev_dbg(pctldev->dev, "found group selector %u for %s\n", group_selector, pin_group); return group_selector; }
group_selector++;}
dev_err(pctldev->dev, "does not have pin group %s\n", pin_group);
return -EINVAL; }
This time it is quite reproducible and here is the log:
## Booting kernel from Legacy Image at 82000000 ... Image Name: Linux-4.17.0-letux+ Image Type: ARM Linux Kernel Image (uncompressed) Data Size: 4760144 Bytes = 4.5 MiB Load Address: 80008000 Entry Point: 80008000 Verifying Checksum ... OK ## Flattened Device Tree blob at 81c00000 Booting using the fdt blob at 0x81c00000 Loading Kernel Image ... OK Using Device Tree in place at 81c00000, end 81c14a70
Starting kernel ...
[ 0.000000] Booting Linux on physical CPU 0x0 [ 0.000000] Linux version 4.17.0-letux+ (hns@iMac.fritz.box) (gcc version 4.9.2 (GCC)) #2494 SMP PREEMPT Sat Jun 23 09:48:15 CEST 2018 [ 0.000000] CPU: ARMv7 Processor [413fc082] revision 2 (ARMv7), cr=10c5387d [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache [ 0.000000] OF: fdt: Machine model: Goldelico GTA04A5/Letux 2804 [ 0.000000] debug: ignoring loglevel setting. [ 0.000000] Memory policy: Data cache writeback [ 0.000000] cma: Reserved 16 MiB at 0xbe800000 [ 0.000000] On node 0 totalpages: 261632 [ 0.000000] Normal zone: 1536 pages used for memmap [ 0.000000] Normal zone: 0 pages reserved [ 0.000000] Normal zone: 196608 pages, LIFO batch:31 [ 0.000000] HighMem zone: 65024 pages, LIFO batch:15 [ 0.000000] CPU: All CPU(s) started in SVC mode. [ 0.000000] OMAP3630/DM3730 ES1.2 (l2cache iva sgx neon isp 192mhz_clk) [ 0.000000] percpu: Embedded 17 pages/cpu @(ptrval) s40000 r8192 d21440 u69632 [ 0.000000] pcpu-alloc: s40000 r8192 d21440 u69632 alloc=17*4096 [ 0.000000] pcpu-alloc: [0] 0 [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 260096 [ 0.000000] Kernel command line: console=ttyO2,115200n8 mtdoops.mtddev=omap2.nand ubi.mtd=4 root=/dev/mmcblk0p1 rw rootfstype=ext4,ext3 rootwait 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 log_buf_len=8M ignore_loglevel earlyprintk [ 0.000000] log_buf_len: 8388608 bytes [ 0.000000] early log buf free: 63960(97%) [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes) [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes) [ 0.000000] Memory: 1001476K/1046528K available (6547K kernel code, 650K rwdata, 1820K rodata, 1024K init, 220K bss, 28668K reserved, 16384K cma-reserved, 243712K highmem) [ 0.000000] Virtual kernel memory layout: [ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB) [ 0.000000] fixmap : 0xffc00000 - 0xfff00000 (3072 kB) [ 0.000000] vmalloc : 0xf0800000 - 0xff800000 ( 240 MB) [ 0.000000] lowmem : 0xc0000000 - 0xf0000000 ( 768 MB) [ 0.000000] pkmap : 0xbfe00000 - 0xc0000000 ( 2 MB) [ 0.000000] modules : 0xbf000000 - 0xbfe00000 ( 14 MB) [ 0.000000] .text : 0x(ptrval) - 0x(ptrval) (7540 kB) [ 0.000000] .init : 0x(ptrval) - 0x(ptrval) (1024 kB) [ 0.000000] .data : 0x(ptrval) - 0x(ptrval) ( 651 kB) [ 0.000000] .bss : 0x(ptrval) - 0x(ptrval) ( 221 kB) [ 0.000000] Preemptible hierarchical RCU implementation. [ 0.000000] RCU restricting CPUs from NR_CPUS=4 to nr_cpu_ids=1. [ 0.000000] Tasks RCU enabled. [ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1 [ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 [ 0.000000] IRQ: Found an INTC at 0x(ptrval) (revision 4.0) with 96 interrupts [ 0.000000] Clocking rate (Crystal/Core/MPU): 26.0/400/600 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.000000] sched_clock: 32 bits at 32kHz, resolution 30517ns, wraps every 65535999984741ns [ 0.000030] OMAP clocksource: 32k_counter at 32768 Hz [ 0.002136] Console: colour dummy device 80x30 [ 0.002197] Calibrating delay loop... 597.60 BogoMIPS (lpj=2988032) [ 0.115203] pid_max: default: 32768 minimum: 301 [ 0.115386] Security Framework initialized [ 0.115509] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes) [ 0.115539] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes) [ 0.116455] CPU: Testing write buffer coherency: ok [ 0.116943] CPU0: thread -1, cpu 0, socket -1, mpidr 0 [ 0.165161] Setting up static identity map for 0x80100000 - 0x80100060 [ 0.175079] Hierarchical SRCU implementation. [ 0.195098] smp: Bringing up secondary CPUs ... [ 0.195129] smp: Brought up 1 node, 1 CPU [ 0.195129] SMP: Total of 1 processors activated (597.60 BogoMIPS). [ 0.195159] CPU: All CPU(s) started in SVC mode. [ 0.197204] devtmpfs: initialized [ 0.225524] random: get_random_u32 called from bucket_table_alloc+0x15c/0x1ac with crng_init=0 [ 0.235504] VFP support v0.3: implementor 41 architecture 3 part 30 variant c rev 3 [ 0.236236] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns [ 0.236267] futex hash table entries: 256 (order: 2, 16384 bytes) [ 0.237731] pinctrl core: initialized pinctrl subsystem [ 0.239074] NET: Registered protocol family 16 [ 0.242218] DMA: preallocated 256 KiB pool for atomic coherent allocations [ 0.273742] omap_hwmod: mcbsp2_sidetone using broken dt data from mcbsp [ 0.274566] omap_hwmod: mcbsp3_sidetone using broken dt data from mcbsp [ 0.357635] audit: initializing netlink subsys (disabled) [ 0.363189] audit: type=2000 audit(0.360:1): state=initialized audit_enabled=0 res=1 [ 0.364807] cpuidle: using governor menu [ 0.366088] Reprogramming SDRC clock to 400000000 Hz [ 0.377929] OMAP GPIO hardware version 2.5 [ 0.386535] GPIO line 143 (irda_en) hogged as output/high [ 0.414459] omap-gpmc 6e000000.gpmc: could not find pctldev for node /ocp@68000000/l4@48000000/scm@2000/pinmux@30/pinmux_gpmc_pins, deferring probe [ 0.434875] No ATAGs? [ 0.434906] hw-breakpoint: debug architecture 0x4 unsupported. [ 0.436126] omap4_sram_init:Unable to allocate sram needed to handle errata I688 [ 0.436157] omap4_sram_init:Unable to get sram pool needed to handle errata I688 [ 0.436523] OMAP DMA hardware revision 5.0 [ 0.543273] omap-dma-engine 48056000.dma-controller: OMAP DMA engine driver (LinkedList1/2/3 supported) [ 0.548492] reg-fixed-voltage wlan_en_regulator: could not find pctldev for node /ocp@68000000/l4@48000000/scm@2000/pinmux@30/pinmux_wlan_pins, deferring probe [ 0.548553] reg-fixed-voltage bt_en_regulator: could not find pctldev for node /ocp@68000000/l4@48000000/scm@2000/pinmux@30/pinmux_bt_pins, deferring probe [ 0.558776] omap-iommu 480bd400.mmu: 480bd400.mmu registered [ 0.559783] iommu: Adding device 480bc000.isp to group 0 [ 0.562622] vgaarb: loaded [ 0.563812] SCSI subsystem initialized [ 0.565612] libata version 3.00 loaded. [ 0.566589] usbcore: registered new interface driver usbfs [ 0.566802] usbcore: registered new interface driver hub [ 0.567016] usbcore: registered new device driver usb [ 0.567718] usb_phy_generic hsusb2_phy: hsusb2_phy supply vcc not found, using dummy regulator [ 0.573394] omap_i2c 48070000.i2c: bus 0 rev4.4 at 2600 kHz [ 0.578063] omap_i2c 48072000.i2c: bus 1 rev4.4 at 400 kHz [ 0.580566] omap_i2c 48060000.i2c: bus 2 rev4.4 at 100 kHz [ 0.582733] Advanced Linux Sound Architecture Driver Initialized. [ 0.587829] clocksource: Switched to clocksource 32k_counter [ 0.684509] VFS: Disk quotas dquot_6.6.0 [ 0.684631] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) [ 0.719573] NET: Registered protocol family 2 [ 0.720947] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes) [ 0.721008] TCP established hash table entries: 8192 (order: 3, 32768 bytes) [ 0.721130] TCP bind hash table entries: 8192 (order: 4, 65536 bytes) [ 0.721282] TCP: Hash tables configured (established 8192 bind 8192) [ 0.721435] UDP hash table entries: 512 (order: 2, 16384 bytes) [ 0.721496] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes) [ 0.722381] NET: Registered protocol family 1 [ 0.722442] PCI: CLS 0 bytes, default 64 [ 0.726928] hw perfevents: enabled with armv7_cortex_a8 PMU driver, 5 counters available [ 0.732513] Initialise system trusted keyrings [ 0.734283] workingset: timestamp_bits=30 max_order=18 bucket_order=0 [ 0.734924] squashfs: version 4.0 (2009/01/31) Phillip Lougher [ 0.739746] Key type asymmetric registered [ 0.739776] Asymmetric key parser 'x509' registered [ 0.739898] bounce: pool size: 64 pages [ 0.740020] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251) [ 0.740051] io scheduler noop registered [ 0.740051] io scheduler deadline registered [ 0.740142] io scheduler cfq registered (default) [ 0.740173] io scheduler mq-deadline registered [ 0.740173] io scheduler kyber registered [ 0.749450] pinctrl-single 48002030.pinmux: 284 pins, size 568 [ 0.750427] pinctrl-single 48002a00.pinmux: 46 pins, size 92 [ 0.751434] pinctrl-single 480025a0.pinmux: 46 pins, size 92 [ 0.752319] pinctrl-single 48002274.pinmux_mcbsp1: initialized with no interrupts [ 0.752319] pinctrl-single 48002274.pinmux_mcbsp1: 10 pins, size 4 [ 0.753082] pinctrl-single 480022d8.pinmux_tv_out: initialized with no interrupts [ 0.753082] pinctrl-single 480022d8.pinmux_tv_out: 4 pins, size 4 [ 0.770263] omap_uart 4806a000.serial: no wakeirq for uart0 [ 0.770782] 4806a000.serial: ttyO0 at MMIO 0x4806a000 (irq = 88, base_baud = 3000000) is a OMAP UART0 [ 0.771514] serial serial0: tty port ttyO0 registered [ 0.772064] omap_uart 4806c000.serial: no wakeirq for uart1 [ 0.772277] 4806c000.serial: ttyO1 at MMIO 0x4806c000 (irq = 89, base_baud = 3000000) is a OMAP UART1 [ 0.772796] serial serial1: tty port ttyO1 registered [ 0.773315] omap_uart 49020000.serial: no wakeirq for uart2 [ 0.773742] 49020000.serial: ttyO2 at MMIO 0x49020000 (irq = 90, base_baud = 3000000) is a OMAP UART2 [ 1.669250] console [ttyO2] enabled [ 1.674468] omap_uart 49042000.serial: no wakeirq for uart3 [ 1.681060] 49042000.serial: ttyO3 at MMIO 0x49042000 (irq = 96, base_baud = 3000000) is a OMAP UART3 [ 1.715942] brd: module loaded [ 1.732696] loop: module loaded [ 1.771636] twl 0-0048: PIH (irq 23) chaining IRQs 144..152 [ 1.777618] twl 0-0048: power (irq 149) chaining IRQs 152..159 [ 1.789855] random: fast init done [ 1.796966] VAUX3: Bringing 2800000uV into 2500000-2500000uV [ 1.822326] VMMC2: Bringing 2600000uV into 1800000-1800000uV [ 1.829650] VMMC2: failed to apply 1800000-1800000uV constraint(-22) [ 1.836334] twl4030_reg 48070000.i2c:twl@48:regulator-vmmc2: can't register VMMC2, -22 [ 1.844879] twl4030_reg: probe of 48070000.i2c:twl@48:regulator-vmmc2 failed with error -22 [ 1.863830] VSIM: Bringing 1800000uV into 2800000-2800000uV [ 1.909942] libphy: Fixed MDIO Bus: probed [ 1.924407] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver [ 1.932098] ehci-pci: EHCI PCI platform driver [ 1.937194] usbcore: registered new interface driver usb-storage [ 1.944854] mousedev: PS/2 mouse device common for all mice [ 1.953552] twl_rtc 48070000.i2c:twl@48:rtc: Power up reset detected. [ 1.961181] twl_rtc 48070000.i2c:twl@48:rtc: Enabling TWL-RTC [ 1.969757] twl_rtc 48070000.i2c:twl@48:rtc: rtc core: registered 48070000.i2c:twl@48:rtc as rtc0 [ 1.980316] i2c /dev entries driver [ 1.985534] IR NEC protocol handler initialized [ 1.990753] IR RC5(x/sz) protocol handler initialized [ 1.996063] IR RC6 protocol handler initialized [ 2.000915] IR JVC protocol handler initialized [ 2.005645] IR Sony protocol handler initialized [ 2.010681] IR SANYO protocol handler initialized [ 2.015624] IR Sharp protocol handler initialized [ 2.020629] IR MCE Keyboard/mouse protocol handler initialized [ 2.026733] IR XMP protocol handler initialized [ 2.031524] Driver for 1-wire Dallas network protocol. [ 2.039276] ti-soc-thermal 48002524.bandgap: This OMAP thermal sensor is unreliable. You've been warned [ 2.049774] ti-soc-thermal 48002524.bandgap: Non-trimmed BGAP, Temp not accurate [ 2.060546] omap_wdt: OMAP Watchdog Timer Rev 0x31: initial timeout 60 sec [ 2.079956] sdhci: Secure Digital Host Controller Interface driver [ 2.086395] sdhci: Copyright(c) Pierre Ossman [ 2.119934] sdhci-pltfm: SDHCI platform and OF driver helper [ 2.127655] ledtrig-cpu: registered to indicate activity on CPUs [ 2.142974] usbcore: registered new interface driver usbhid [ 2.150115] usbhid: USB HID core driver [ 2.154602] ashmem: initialized [ 2.164764] oprofile: using arm/armv7 [ 2.168762] mmc0: host does not support reading read-only switch, assuming write-enable [ 2.178344] Initializing XFRM netlink socket [ 2.182983] mmc0: new high speed SDHC card at address b368 [ 2.188934] NET: Registered protocol family 17 [ 2.193634] NET: Registered protocol family 15 [ 2.199462] mmcblk0: mmc0:b368 USD 7.47 GiB [ 2.205291] Key type dns_resolver registered [ 2.211181] omap2_set_init_voltage: unable to find boot up OPP for vdd_core [ 2.218627] omap2_set_init_voltage: unable to set vdd_core [ 2.224731] omap3_pm_off_mode_enable(1) [ 2.229064] mmcblk0: p1 [ 2.232788] ThumbEE CPU extension supported. [ 2.237274] Registering SWP/SWPB emulation handler [ 2.243316] SmartReflex Class3 initialized [ 2.248870] Loading compiled-in X.509 certificates [ 2.272949] platform 6e000000.gpmc: Retrying from deferred list [ 2.279907] omap-gpmc 6e000000.gpmc: GPMC revision 5.0 [ 2.285308] gpmc_mem_init: disabling cs 0 mapped at 0x0-0x1000000 [ 2.293548] omap2-onenand 4000000.onenand: initializing on CS0 (0x04000000), va (ptrval), DMA mode [ 2.303405] OneNAND Manufacturer: Samsung (0xec) [ 2.308349] Muxed OneNAND 512MB 1.8V 16-bit (0x50) [ 2.313323] OneNAND version = 0x0232 [ 2.317077] Chip support all block unlock [ 2.321319] Chip has 4KiB pagesize [ 2.324859] Chip has cache program feature [ 2.330688] Scanning device for bad blocks [ 2.438171] onenand_bbt_wait: ecc 0xaaaa ctrl 0x0400 intr 0x8080 addr1 0x34b addr8 0x0 [ 2.446441] OneNAND eraseblock 843 is an initial bad block [ 2.599395] omap2-onenand 4000000.onenand: optimized timings for 83 MHz [ 2.606353] 5 fixed-partitions partitions found on MTD device 4000000.onenand [ 2.613861] Creating 5 MTD partitions on "4000000.onenand": [ 2.619720] 0x000000000000-0x000000080000 : "X-Loader" [ 2.626708] 0x000000080000-0x000000240000 : "U-Boot" [ 2.633850] 0x000000240000-0x000000280000 : "U-Boot Env" [ 2.641326] 0x000000280000-0x000000880000 : "Kernel" [ 2.648498] 0x000000880000-0x000020000000 : "File System" [ 2.658264] platform wlan_en_regulator: Retrying from deferred list [ 2.666290] platform bt_en_regulator: Retrying from deferred list [ 2.673919] platform 480b4000.mmc: Retrying from deferred list [ 2.795898] ubi0: default fastmap pool size: 100 [ 2.802978] ubi0: default fastmap WL pool size: 50 [ 2.808135] ubi0: attaching mtd4 [ 2.815002] omap_hsmmc 480b4000.mmc: card claims to support voltages below defined range [ 2.834747] onenand_wait: correctable ECC error = 0x5555 [ 2.841308] ubi0: fixable bit-flip detected at PEB 187 [ 2.858123] mmc1: new high speed SDIO card at address 0001 [ 2.876342] onenand_wait: correctable ECC error = 0x5555 [ 2.882049] ubi0: fixable bit-flip detected at PEB 465 [ 2.948211] onenand_wait: correctable ECC error = 0x5555 [ 2.953765] ubi0: fixable bit-flip detected at PEB 1326 [ 2.975341] onenand_wait: correctable ECC error = 0x5555 [ 2.980987] ubi0: fixable bit-flip detected at PEB 1554 [ 3.015136] onenand_wait: correctable ECC error = 0x5555 [ 3.020751] ubi0: fixable bit-flip detected at PEB 1960 [ 3.029998] ubi0: scanning is finished [ 3.040924] ubi0: attached mtd4 (name "File System", size 503 MiB) [ 3.047393] ubi0: PEB size: 262144 bytes (256 KiB), LEB size: 258048 bytes [ 3.054962] ubi0: min./max. I/O unit sizes: 4096/4096, sub-page size 1024 [ 3.062164] ubi0: VID header offset: 1024 (aligned 1024), data offset: 4096 [ 3.069519] ubi0: good PEBs: 2013, bad PEBs: 1, corrupted PEBs: 0 [ 3.075897] ubi0: user volume: 1, internal volumes: 1, max. volumes count: 128 [ 3.083587] ubi0: max/mean erase counter: 59/35, WL threshold: 4096, image sequence number: 163025748 [ 3.093353] ubi0: available PEBs: 0, total reserved PEBs: 2013, PEBs reserved for bad PEB handling: 39 [ 3.103149] ubi0: background thread "ubi_bgt0d" started, PID 1039 [ 3.110595] input: gpio-keys as /devices/platform/gpio-keys/input/input0 [ 3.119354] input: gpio-keys-wwan-wakeup as /devices/platform/gpio-keys-wwan-wakeup/input/input1 [ 3.129791] omap_gpio 49056000.gpio: Could not set line 16 debounce to 10000 microseconds (-22) [ 3.139648] input: antenna-detect as /devices/platform/antenna-detect/input/input2 [ 3.149291] twl_rtc 48070000.i2c:twl@48:rtc: setting system clock to 2000-01-01 00:00:01 UTC (946684801) [ 3.159606] sr_init: No PMIC hook to init smartreflex [ 3.165618] smartreflex 480cb000.smartreflex: omap_sr_probe: SmartReflex driver initialized [ 3.175109] smartreflex 480c9000.smartreflex: omap_sr_probe: SmartReflex driver initialized [ 3.186187] VAUX3: disabling [ 3.190185] VDAC: disabling [ 3.193664] VUSB1V5: disabling [ 3.197296] VUSB1V8: disabling [ 3.201049] VUSB3V1: disabling [ 3.204681] wlan-en-regulator: disabling [ 3.208923] bt-en-regulator: disabling [ 3.212860] ALSA device list: [ 3.215942] No soundcards found. [ 3.250671] EXT4-fs (mmcblk0p1): mounted filesystem with ordered data mode. Opts: (null) [ 3.259613] VFS: Mounted root (ext4 filesystem) on device 179:1. [ 3.280364] devtmpfs: mounted [ 3.285339] Freeing unused kernel memory: 1024K Mount failed for selinuxfs on /sys/fs/selinux: No such file or directory INIT: version 2.88 booting [info] Using makefile-style concurrent boot in runlevel S. [....] Starting the hotplug events dispatcher: udevd[ 4.705017] systemd-udevd[1172]: starting version 215 [ 4.800628] random: udevd: uninitialized urandom read (16 bytes read) [ 4.821441] random: udevd: uninitialized urandom read (16 bytes read) . [ ok ] Synthesizing the initial hotplug events...^[[c[ 5.236297] omapdss: unknown parameter 'def_disp' ignored done. [....] Waiting for /dev to be fully populated...[ 5.303161] omapdss_dss 48050000.dss: 48050000.dss supply vdda_video not found, using dummy regulator ^[[c[ 5.342681] DSS: OMAP DSS rev 2.0 [ 5.365570] omapdss_dss 48050000.dss: bound 48050400.dispc (ops dispc_component_ops [omapdss]) [ 5.425079] omapdss_dss 48050000.dss: bound 48050c00.encoder (ops venc_component_ops [omapdss]) [ 5.469055] gnss: GNSS driver registered with major 243 [ 5.517791] ehci-omap: OMAP-EHCI Host Controller driver [ 5.550659] input: twl4030_pwrbutton as /devices/platform/68000000.ocp/48070000.i2c/i2c-0/0-0048/48070000.i2c:twl@48:pwrbutton/input/input3 [ 5.583160] input: twl4030:vibrator as /devices/platform/68000000.ocp/48070000.i2c/i2c-0/0-0048/48070000.i2c:twl@48:audio/twl4030-vibra/input/input4 [ 5.658874] twl4030_madc 48070000.i2c:twl@48:madc: 48070000.i2c:twl@48:madc supply vusb3v1 not found, using dummy regulator [ 5.670684] ehci-omap 48064800.ehci: EHCI Host Controller [ 5.699920] ehci-omap 48064800.ehci: new USB bus registered, assigned bus number 1 [ 5.779174] ehci-omap 48064800.ehci: irq 93, io mem 0x48064800 [ 5.791900] twl4030_gpio twl4030-gpio: can't dispatch IRQs from modules [ 5.836730] ehci-omap 48064800.ehci: USB 2.0 started, EHCI 1.00 [ 5.882385] platform 48070000.i2c:twl@48:bci: Retrying from deferred list [ 5.893646] media: Linux media interface: v0.10 [ 5.932739] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.17 [ 5.948638] platform 48070000.i2c:twl@48:bci: Retrying from deferred list [ 6.018402] input: accelerometer-iio-input-bridge as /devices/virtual/input/input5 [ 6.028686] twl4030_usb 48070000.i2c:twl@48:twl4030-usb: Initialized TWL4030 USB module [ 6.044372] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 6.062072] Linux video capture interface: v2.00 [ 6.072601] input: TSC2007 Touchscreen as /devices/platform/68000000.ocp/48072000.i2c/i2c-1/1-0048/input/input6 [ 6.108154] usb usb1: Product: EHCI Host Controller [ 6.113250] usb usb1: Manufacturer: Linux 4.17.0-letux+ ehci_hcd [ 6.125518] musb-hdrc musb-hdrc.0.auto: MUSB HDRC host driver [ 6.172119] usb usb1: SerialNumber: 48064800.ehci [ 6.180450] bmp280 1-0076: 1-0076 supply vddd not found, using dummy regulator [ 6.207427] hub 1-0:1.0: USB hub found [ 6.212493] bmp280 1-0076: 1-0076 supply vdda not found, using dummy regulator [ 6.220794] hub 1-0:1.0: 3 ports detected [ 6.245635] musb-hdrc musb-hdrc.0.auto: new USB bus registered, assigned bus number 2 [ 6.298309] usb usb2: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.17 [ 6.363555] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 6.394958] usb usb2: Product: MUSB HDRC host driver [ 6.442871] usb usb2: Manufacturer: Linux 4.17.0-letux+ musb-hcd [ 6.505920] usb usb2: SerialNumber: musb-hdrc.0.auto [ 6.535705] hub 2-0:1.0: USB hub found [ 6.550048] i2c 1-0030: Retrying from deferred list [ 6.576538] hub 2-0:1.0: 1 port detected [ 6.612670] i2c 1-0030: Retrying from deferred list [ 6.626068] i2c 1-0030: Retrying from deferred list [ 6.648223] omap_hdq 480b2000.1w: OMAP HDQ Hardware Rev 0.5. Driver in Interrupt mode [ 6.728515] i2c 1-0030: Retrying from deferred list [ 6.738250] w1_master_driver w1_bus_master1: Attaching one wire slave 01.000000000000 crc 3d [ 6.747406] i2c 1-0030: Retrying from deferred list [ 6.790191] bq27xxx_battery_setup [ 6.793701] bq27xxx_battery_setup: dm_regs= (null) [ 6.798980] i2c 1-0030: Retrying from deferred list [ 6.812499] (NULL device *): hwmon: 'bq27000-battery' is not a valid name attribute, please fix [ 6.835296] bq27xxx_battery_settings [ 6.840545] bq27xxx_battery_settings: power_supply_get_battery_info failed ret=-1088380908 [ 6.882781] pwm-backlight backlight: backlight supply power not found, using dummy regulator [ 6.966156] (NULL device *): hwmon: 'gta04-battery' is not a valid name attribute, please fix [ 6.994628] wwan_on_off_init: wwan_on_off_init [ 7.014556] pps_core: LinuxPPS API ver. 1 registered [ 7.037109] i2c 1-0030: Retrying from deferred list [ 7.042602] iio_charge:-747 [ 7.048522] platform backlight: Retrying from deferred list [ 7.054901] pinctrl_generic_get_group_name: group>name is NULL [ 7.077026] pinctrl_generic_group_name_to_selector: pctldev = ee33b180 function = backlight_pins_pinmux [ 7.096343] strcmp(backlight_pins_pinmux, (null)) [ 7.108062] get_group_name() = pinctrl_generic_get_group_name+0x0/0x5c [ 7.115081] ngroups = 19 [ 7.119476] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti giometti@linux.it [ 7.129150] selector = 18 [ 7.132080] CPU: 0 PID: 952 Comm: kworker/0:2 Not tainted 4.17.0-letux+ #2494 [ 7.139526] Hardware name: Generic OMAP36xx (Flattened Device Tree) [ 7.146087] Workqueue: events deferred_probe_work_func [ 7.151489] [<c01106ec>] (unwind_backtrace) from [<c010c058>] (show_stack+0x10/0x14) [ 7.159606] [<c010c058>] (show_stack) from [<c074bd08>] (dump_stack+0x7c/0x9c) [ 7.167144] [<c074bd08>] (dump_stack) from [<c042ce78>] (pinctrl_generic_add_group+0xa4/0x174) [ 7.176147] [<c042ce78>] (pinctrl_generic_add_group) from [<c0432128>] (pcs_dt_node_to_map+0x4b0/0x81c) [ 7.185943] [<c0432128>] (pcs_dt_node_to_map) from [<c04300c0>] (pinctrl_dt_to_map+0x1ec/0x2b8) [ 7.195037] [<c04300c0>] (pinctrl_dt_to_map) from [<c042d10c>] (create_pinctrl+0x58/0x2f8) [ 7.203674] [<c042d10c>] (create_pinctrl) from [<c042d46c>] (devm_pinctrl_get+0x2c/0x6c) [ 7.212127] [<c042d46c>] (devm_pinctrl_get) from [<c04f2f88>] (pinctrl_bind_pins+0x3c/0x138) [ 7.220947] [<c04f2f88>] (pinctrl_bind_pins) from [<c04d3fa4>] (driver_probe_device+0xe8/0x318) [ 7.230041] [<c04d3fa4>] (driver_probe_device) from [<c04d27f4>] (bus_for_each_drv+0x84/0x94) [ 7.238952] [<c04d27f4>] (bus_for_each_drv) from [<c04d3e24>] (__device_attach+0x88/0xfc) [ 7.247497] [<c04d3e24>] (__device_attach) from [<c04d33d0>] (bus_probe_device+0x28/0x80) [ 7.256011] [<c04d33d0>] (bus_probe_device) from [<c04d38ec>] (deferred_probe_work_func+0xf8/0x130) [ 7.265472] [<c04d38ec>] (deferred_probe_work_func) from [<c014874c>] (process_one_work+0x244/0x464) [ 7.275054] [<c014874c>] (process_one_work) from [<c0148f20>] (worker_thread+0x2c0/0x3ec) [ 7.283599] [<c0148f20>] (worker_thread) from [<c014cef4>] (kthread+0x134/0x150) [ 7.291320] [<c014cef4>] (kthread) from [<c01010e8>] (ret_from_fork+0x14/0x2c) [ 7.298858] Exception stack(0xee69dfb0 to 0xee69dff8) [ 7.304138] dfa0: 00000000 00000000 00000000 00000000 [ 7.312683] dfc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 [ 7.321197] dfe0: 00000000 00000000 00000000 00000000 00000013 00000000 [ 7.528137] gname[0] = pinmux_hsusb2_pins [ 7.532531] gname[1] = pinmux_uart1_pins [ 7.536804] gname[2] = pinmux_uart2_pins [ 7.558166] gname[3] = pinmux_uart3_pins [ 7.562469] gname[4] = pinmux_twl4030_pins [ 7.566925] gname[5] = pinmux_mmc1_pins [ 7.588165] gname[6] = pinmux_wlan_irq_pin [ 7.592651] gname[7] = pinmux_gpmc_pins [ 7.596832] gname[8] = pinmux_wlan_pins [ 7.608184] gname[9] = pinmux_bt_pins [ 7.612213] gname[10] = pinmux_dss_dpi_pins [ 7.616760] gname[11] = pinmux_mcbsp1_pins [ 7.636383] gname[12] = pinmux_mcbsp2_pins [ 7.648162] gname[13] = pinmux_mcbsp3_pins [ 7.652648] gname[14] = pinmux_mcbsp4_pins [ 7.657104] gname[15] = pinmux_penirq_pins [ 7.671142] gname[16] = pinmux_camera_pins [ 7.675598] gname[17] = hdq_pins [ 7.688140] pinctrl_generic_get_group_name: group>name is NULL [ 7.694244] gname[18] = (null)
^^^ this is interesting!
The printk code behind pinctrl_generic_get_group_name is:
const char *pinctrl_generic_get_group_name(struct pinctrl_dev *pctldev, unsigned int selector) { struct group_desc *group;
group = radix_tree_lookup(&pctldev->pin_group_tree, selector); if (!group) { printk("%s: selector %d not found\n", __func__, selector); } if (!group) return NULL;
if (!group->name) { printk("%s: group>name is NULL\n", __func__); } return group->name; }
Which means that the struct group_desc exists but the group->name is NULL. So there is no NULL magically added to the radix tree, but the group->name pointer becomes NULL. Which means that the memory region was overwritten.
Next I tried to printk all entries of the struct group_desc
if (!group->name) { printk("%s: group =%px\n", __func__, group); printk(" group>name = %s\n", group->name); printk(" group>pins = %px\n", group->pins); printk(" group>num_pins = %d\n", group->num_pins); printk(" group>data = %px\n", group->data); }
Result (first lines where something goes wrong):
[ 6.798248] i2c 1-0030: Retrying from deferred list [ 6.813171] platform backlight: Retrying from deferred list [ 6.823303] pinctrl_generic_get_group_name: group =ed1eec90 [ 6.836791] group>name = (null) [ 6.846557] group>pins = ed1eed50 [ 6.852874] group>num_pins = 1 [ 6.856262] group>data = ee441c10
Here another run:
[ 6.923797] i2c 1-0030: Retrying from deferred list [ 6.935577] platform backlight: Retrying from deferred list [ 6.948547] pinctrl_generic_get_group_name: group =ed213b50 [ 6.962036] group>name = (null) [ 6.965515] group>pins = ed213c10 [ 6.978088] group>num_pins = 1 [ 6.983520] group>data = ee444c10
Hm.
Looks sane, especially group->pins (allocated in pcs_parse_one_pinctrl_entry just before pinctrl_generic_add_group is called), and group->num_pins.
group>name must have been != NULL in pinctrl_generic_add_group() or we would have seen an error before the first one.
So only group->name became NULL, most likely AFTER calling pinctrl_generic_add_group - since otherwise we could not even find the entry in the radix tree.
But how can that happen?
The interesting thing is that it is repeatable even with randomly changing base addresses. So it must be someone who knows the address of the (struct) group_desc. But there aren't many places:
https://elixir.bootlin.com/linux/v4.18-rc1/ident/group_desc
Some of these just use a group_desc variable and in most cases the struct group_desc pointer is hidden local to the function.
The only exception is pinctrl_generic_get_group(). But it seems not to be used explicitly on OMAP systems except for iodelay but there it is also a local variable and not shared with anyone else.
So it remains a miracle where the code sits that does the group->name = NULL; and only for the "backlight" driver.
BR, Nikolaus
[ 7.697692] pinctrl_generic_get_group_name: group>name is NULL [ 7.708221] pinctrl_generic_get_group_name: group>name is NULL [ 7.714324] pinctrl_get_group_selector: strcmp: (null) backlight_pins_pinmux [ 7.733917] group_selector = 18 [ 7.737426] get_group_name = pinctrl_generic_get_group_name+0x0/0x5c [ 7.758148] pctldev = 0xee33b180 [ 7.761749] Unable to handle kernel NULL pointer dereference at virtual address 00000000 [ 7.786560] pgd = (ptrval) [ 7.789642] [00000000] *pgd=00000000 [ 7.793395] Internal error: Oops: 17 [#1] PREEMPT SMP ARM [ 7.799041] Modules linked in: pps_gpio(+) panel_tpo_td028ttec1 snd_soc_simple_card(+) snd_soc_simple_card_utils snd_soc_omap_twl4030(+) encoder_opa362 pps_core wwan_on_off(+) snd_soc_gtm601 connector_analog_tv pwm_omap_dmtimer generic_adc_battery pwm_bl bq27xxx_battery_hdq bq27xxx_battery bmp280_spi wlcore_sdio ov9655 v4l2_fwnode v4l2_common omap_hdq omap2430 bmp280_i2c bmp280 videodev at24 bmc150_accel_i2c bmc150_magn_i2c tsc2007 bmc150_magn leds_tca6507 bmc150_accel_core industrialio_triggered_buffer phy_twl4030_usb kfifo_buf media snd_soc_omap_mcbsp snd_soc_omap snd_pcm_dmaengine musb_hdrc gpio_twl4030 snd_soc_twl4030 twl4030_charger twl4030_vibra gnss_w2sg0004 twl4030_madc twl4030_pwrbutton industrialio ehci_omap gnss w2cbw003_bluetooth omapdss omapdss_base cec [ 7.870178] CPU: 0 PID: 952 Comm: kworker/0:2 Not tainted 4.17.0-letux+ #2494 [ 7.877655] Hardware name: Generic OMAP36xx (Flattened Device Tree) [ 7.884216] Workqueue: events deferred_probe_work_func [ 7.889617] PC is at strcmp+0x0/0x34 [ 7.893341] LR is at pinctrl_get_group_selector+0x90/0xd8 [ 7.898986] pc : [<c0758fc0>] lr : [<c042dac8>] psr: 60000113 [ 7.905548] sp : ee69de20 ip : 00000000 fp : 00000000 [ 7.911010] r10: ed22f6c0 r9 : 00000014 r8 : 00000000 [ 7.916442] r7 : c0799fd4 r6 : ee33b180 r5 : ef7c4958 r4 : 00000012 [ 7.923248] r3 : 00000000 r2 : 00000000 r1 : ef7c4958 r0 : 00000000 [ 7.930053] Flags: nZCv IRQs on FIQs on Mode SVC_32 ISA ARM Segment none [ 7.937499] Control: 10c5387d Table: ad3a8019 DAC: 00000051 [ 7.943511] Process kworker/0:2 (pid: 952, stack limit = 0x(ptrval)) [ 7.950134] Stack: (0xee69de20 to 0xee69e000) [ 7.954681] de20: ee69de44 00000000 ee33b180 ed12c210 ef7c4958 ed22f6c0 00000000 c042eaac [ 7.963226] de40: ed20b910 00000001 ed2267c0 ed22f700 ed22f740 ed12c210 00000000 c042d2a4 [ 7.971771] de60: 00000014 ee28f780 c0b59e30 c08e9fec ee230010 00000000 ed226890 ee230010 [ 7.980316] de80: c0bd1df0 fffffdfb bf212014 0000002e c0b98f70 c042d46c 00000000 ee230010 [ 7.988830] dea0: ed2265d0 c04f2f88 ee230010 00000000 c0bd1df4 c04d3fa4 00000000 ee69def0 [ 7.997375] dec0: c04d42b0 ee230044 c0b664c4 c0b02d00 00000000 c04d27f4 ee01be6c ed204b38 [ 8.005889] dee0: ee230010 c0b666c8 00000001 c04d3e24 ee230010 00000001 00000000 ee230010 [ 8.014434] df00: c0b666c8 ee230010 00000000 c04d33d0 ee230010 c0b664a8 ef7b7c80 c04d38ec [ 8.022979] df20: ee4eef00 c0b664dc ef7b7c80 00000000 ef7baf00 c014874c ee4eef00 c0b664dc [ 8.031524] df40: ffff8d8f ee4eef00 ef7b7c80 ef7b7c80 ee69c000 ef7b7c98 c0b02d00 ee4eef18 [ 8.040039] df60: 00000008 c0148f20 00000000 ee680b00 ee4ebdc0 00000000 ee4eef00 c0148c60 [ 8.048583] df80: ee0b5ef0 ee680b1c 00000000 c014cef4 ee4ebdc0 c014cdc0 00000000 00000000 [ 8.057128] dfa0: 00000000 00000000 00000000 c01010e8 00000000 00000000 00000000 00000000 [ 8.065673] dfc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 [ 8.074218] dfe0: 00000000 00000000 00000000 00000000 00000013 00000000 00000000 00000000 [ 8.082763] [<c0758fc0>] (strcmp) from [<c042dac8>] (pinctrl_get_group_selector+0x90/0xd8) [ 8.091400] [<c042dac8>] (pinctrl_get_group_selector) from [<c042eaac>] (pinmux_map_to_setting+0xf0/0x134) [ 8.101501] [<c042eaac>] (pinmux_map_to_setting) from [<c042d2a4>] (create_pinctrl+0x1f0/0x2f8) [ 8.110565] [<c042d2a4>] (create_pinctrl) from [<c042d46c>] (devm_pinctrl_get+0x2c/0x6c) [ 8.119018] [<c042d46c>] (devm_pinctrl_get) from [<c04f2f88>] (pinctrl_bind_pins+0x3c/0x138) [ 8.127838] [<c04f2f88>] (pinctrl_bind_pins) from [<c04d3fa4>] (driver_probe_device+0xe8/0x318) [ 8.136962] [<c04d3fa4>] (driver_probe_device) from [<c04d27f4>] (bus_for_each_drv+0x84/0x94) [ 8.145843] [<c04d27f4>] (bus_for_each_drv) from [<c04d3e24>] (__device_attach+0x88/0xfc) [ 8.154418] [<c04d3e24>] (__device_attach) from [<c04d33d0>] (bus_probe_device+0x28/0x80) [ 8.162963] [<c04d33d0>] (bus_probe_device) from [<c04d38ec>] (deferred_probe_work_func+0xf8/0x130) [ 8.172424] [<c04d38ec>] (deferred_probe_work_func) from [<c014874c>] (process_one_work+0x244/0x464) [ 8.181976] [<c014874c>] (process_one_work) from [<c0148f20>] (worker_thread+0x2c0/0x3ec) [ 8.190551] [<c0148f20>] (worker_thread) from [<c014cef4>] (kthread+0x134/0x150) [ 8.198272] [<c014cef4>] (kthread) from [<c01010e8>] (ret_from_fork+0x14/0x2c) [ 8.205841] Exception stack(0xee69dfb0 to 0xee69dff8) [ 8.211120] dfa0: 00000000 00000000 00000000 00000000 [ 8.219665] dfc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 [ 8.228210] dfe0: 00000000 00000000 00000000 00000000 00000013 00000000 [ 8.235137] Code: e3520000 e5e32001 1afffffb e12fff1e (e4d03001) [ 8.248138] pinctrl_generic_group_name_to_selector: pctldev = ee33b180 function = modem_pins [ 8.256988] strcmp(modem_pins, (null)) [ 8.345520] get_group_name() = pinctrl_generic_get_group_name+0x0/0x5c [ 8.376617] ngroups = 20 [ 8.379638] selector = 18 [ 8.382568] CPU: 0 PID: 1207 Comm: udevd Tainted: G D 4.17.0-letux+ #2494 [ 8.391021] Hardware name: Generic OMAP36xx (Flattened Device Tree) [ 8.397613] [<c01106ec>] (unwind_backtrace) from [<c010c058>] (show_stack+0x10/0x14) [ 8.405700] [<c010c058>] (show_stack) from [<c074bd08>] (dump_stack+0x7c/0x9c) [ 8.413269] [<c074bd08>] (dump_stack) from [<c042ce78>] (pinctrl_generic_add_group+0xa4/0x174) [ 8.422271] [<c042ce78>] (pinctrl_generic_add_group) from [<c0432128>] (pcs_dt_node_to_map+0x4b0/0x81c) [ 8.432128] [<c0432128>] (pcs_dt_node_to_map) from [<c04300c0>] (pinctrl_dt_to_map+0x1ec/0x2b8) [ 8.441223] [<c04300c0>] (pinctrl_dt_to_map) from [<c042d10c>] (create_pinctrl+0x58/0x2f8) [ 8.449890] [<c042d10c>] (create_pinctrl) from [<c042d46c>] (devm_pinctrl_get+0x2c/0x6c) [ 8.458343] [<c042d46c>] (devm_pinctrl_get) from [<c04f2f88>] (pinctrl_bind_pins+0x3c/0x138) [ 8.467193] [<c04f2f88>] (pinctrl_bind_pins) from [<c04d3fa4>] (driver_probe_device+0xe8/0x318) [ 8.476287] [<c04d3fa4>] (driver_probe_device) from [<c04d4254>] (__driver_attach+0x80/0xa4) [ 8.485107] [<c04d4254>] (__driver_attach) from [<c04d2738>] (bus_for_each_dev+0x58/0x7c) [ 8.493682] [<c04d2738>] (bus_for_each_dev) from [<c04d35d0>] (bus_add_driver+0xcc/0x1e0) [ 8.502227] [<c04d35d0>] (bus_add_driver) from [<c04d4df8>] (driver_register+0x9c/0xe0) [ 8.510620] [<c04d4df8>] (driver_register) from [<c0102d74>] (do_one_initcall+0xb4/0x248) [ 8.519165] [<c0102d74>] (do_one_initcall) from [<c01a7174>] (do_init_module+0x58/0x1d0) [ 8.527648] [<c01a7174>] (do_init_module) from [<c01a5fa4>] (load_module+0xe04/0xfb0) [ 8.535858] [<c01a5fa4>] (load_module) from [<c01a6328>] (sys_finit_module+0x88/0x90) [ 8.544036] [<c01a6328>] (sys_finit_module) from [<c0101000>] (ret_fast_syscall+0x0/0x54) [ 8.552612] Exception stack(0xed09bfa8 to 0xed09bff0) [ 8.557891] bfa0: b6d6a7d4 00051f70 00000006 b6d699f8 00000000 b6d6a31c [ 8.566436] bfc0: b6d6a7d4 00051f70 d5a16800 0000017b 00020000 00037f78 00050048 000593e8 [ 8.575012] bfe0: bede5ee0 bede5ed0 b6d63c4b b6e6ea42 [ 8.694702] ---[ end trace e23961e39ad1e53b ]--- [ 9.145721] gname[0] = pinmux_hsusb2_pins [ 9.152832] gname[1] = pinmux_uart1_pins [ 9.157623] gname[2] = pinmux_uart2_pins [ 9.162536] gname[3] = pinmux_uart3_pins [ 9.167541] gname[4] = pinmux_twl4030_pins [ 9.188140] gname[5] = pinmux_mmc1_pins [ 9.192352] gname[6] = pinmux_wlan_irq_pin [ 9.196807] gname[7] = pinmux_gpmc_pins [ 9.238220] gname[8] = pinmux_wlan_pins [ 9.255950] gname[9] = pinmux_bt_pins [ 9.268737] gname[10] = pinmux_dss_dpi_pins [ 9.300689] gname[11] = pinmux_mcbsp1_pins [ 9.324005] gname[12] = pinmux_mcbsp2_pins [ 9.343505] gname[13] = pinmux_mcbsp3_pins [ 9.365600] gname[14] = pinmux_mcbsp4_pins [ 9.389404] gname[15] = pinmux_penirq_pins [ 9.393859] gname[16] = pinmux_camera_pins [ 9.438110] gname[17] = hdq_pins [ 9.455657] pinctrl_generic_get_group_name: group>name is NULL [ 9.492248] gname[18] = (null) [ 9.495666] gname[19] = backlight_pins_pinmux [ 9.571685] cfg80211: Loading compiled-in X.509 certificates for regulatory database [ 9.626831] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' [ 9.665374] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2 [ 9.682403] cfg80211: failed to load regulatory.db [ 24.218994] random: crng init done
So the issue is that "backlight_pins_pinmux" are searched for a NULL record before they are properly stored. Or someone punches a NULL into the radix_tree.
Hope this sheds some new light on the problem.
BR and thanks, Nikolaus
Kernel mailing list Kernel@pyra-handheld.com http://pyra-handheld.com/cgi-bin/mailman/listinfo/kernel