i.MX8 NULL pointer dereference on interconnect instantiation

Thu Feb 2 23:49:16 PST 2023

Hi Luca,

On 2.02.23 18:55, Luca Ceresoli wrote:
> Hello,
> 
> I just met an oops on i.MX8MP that appears sporadically but quite often
> with my current config (~20%). It seems related to the concurrency of
> instantiaton between an interconnect and peripherals using it.
> 
> I haven't found any existing similar report.
> 
> Kernel: v6.2-rc5-20-g7bf70dbb1882 + the audio patches at
>          https://lore.kernel.org/all/20220625013235.710346-1-marex@denx.de/
> HW: Avnet MSC SM2-MB-EP1 Carrier Board
> 
> A log of the relevant section follows. Lines starting with ">>>" were
> added by me and show the relevant code lines being executed and some
> variable values.
> 
> ------------------------------8<------------------------------
> 
> [   15.170236] at24 0-0050: supply vcc not found, using dummy regulator
> [   15.181143] at24 0-0050: 8192 byte 24c64 EEPROM, writable, 32 bytes/write
> [   15.272681] >>> of_icc_get_from_provider:383 START, spec: np </soc at 0/interconnect at 32700000>
> [   15.281519] >>> of_icc_get_from_provider:405 RETURN -EPROBE_DEFER
> [   15.296345] >>> of_icc_get_from_provider:383 START, spec: np </soc at 0/interconnect at 32700000>
> [   15.305136] >>> of_icc_get_from_provider:405 RETURN -EPROBE_DEFER
> [   15.317576] >>> of_icc_get_from_provider:383 START, spec: np </soc at 0/interconnect at 32700000>
> [   15.326715] >>> of_icc_get_from_provider:405 RETURN -EPROBE_DEFER
> [   15.338297] input: 30370000.snvs:snvs-powerkey as /devices/platform/soc at 0/30000000.bus/30370000.snvs/30370000.snvs:snvs-powerkey/input/input0
> [   15.359831] >>> of_icc_get_from_provider:383 START, spec: np </soc at 0/interconnect at 32700000>
> [   15.368372] >>> of_icc_get_from_provider:405 RETURN -EPROBE_DEFER
> [   15.381942] >>> of_icc_get_from_provider:383 START, spec: np </soc at 0/interconnect at 32700000>
> [   15.383139] imx-bus-devfreq 32700000.interconnect: interconnect provider added to topology
> [   15.387956] snvs_rtc 30370000.snvs:snvs-rtc-lp: registered as rtc1
> [   15.390482] >>> of_icc_xlate_onecell:352 START
> [   15.401380] >>> of_icc_xlate_onecell:359 RETURN icc_data->nodes[37] = 0000000000000000
> [   15.409421] >>> of_icc_get_from_provider:416 RETURN data->node 0000000000000000
> [   15.416865] >>> of_icc_get_from_provider:383 START, spec: np </soc at 0/interconnect at 32700000>
> [   15.425391] >>> of_icc_xlate_onecell:352 START
> [   15.429996] >>> of_icc_xlate_onecell:359 RETURN icc_data->nodes[36] = ffff000005fe9e00
> [   15.434640] i.mx8mm_thermal 30260000.tmu: No OCOTP nvmem reference found, SoC-specific calibration not loaded. Please update your DT.
> [   15.438012] >>> of_icc_get_from_provider:416 RETURN data->node ffff000005fe9e00
> [   15.457502] >>> path_find:197 src 0000000000000000
> [   15.462430] Unable to handle kernel NULL pointer dereference at virtual address 0000000000000000
> [   15.471339] Mem abort info:
> [   15.473249] imx-cpufreq-dt imx-cpufreq-dt: cpu speed grade 7 mkt segment 2 supported-hw 0x80 0x4
> [   15.474253]   ESR = 0x0000000096000004
> [   15.486891]   EC = 0x25: DABT (current EL), IL = 32 bits
> [   15.492315]   SET = 0, FnV = 0
> [   15.495407]   EA = 0, S1PTW = 0
> [   15.498704]   FSC = 0x04: level 0 translation fault
> [   15.503725] Data abort info:
> [   15.506646]   ISV = 0, ISS = 0x00000004
> [   15.510728]   CM = 0, WnR = 0
> [   15.513796] user pgtable: 4k pages, 48-bit VAs, pgdp=000000004611a000
> [   15.520354] [0000000000000000] pgd=0000000000000000, p4d=0000000000000000
> [   15.527450] Internal error: Oops: 0000000096000004 [#1] PREEMPT SMP
> [   15.533737] Modules linked in: imx_cpufreq_dt imx8mm_thermal imx8mp_interconnect rtc_snvs imx_interconnect snvs_pwrkey governor_userspace imx_bus at24 fsl_imx8_ddr_perf caam error crct10dif_ce
> [   15.550925] CPU: 2 PID: 68 Comm: kworker/u8:4 Not tainted 6.2.0-rc5-00040-ged7bb521b8fe-dirty #70
> [   15.559809] Hardware name: MSC SM2-MB-EP1 Carrier Board with SM2S-IMX8PLUS-QC6-14N0600E SoM (DT)
> [   15.568602] Workqueue: events_unbound deferred_probe_work_func
> [   15.577666] pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
> [   15.584637] pc : path_find+0x94/0x374
> [   15.588314] lr : path_find+0x94/0x374
> [   15.591988] sp : ffff80000a78b730
> [   15.595305] x29: ffff80000a78b730 x28: 0000000000000000 x27: ffff80000a78b7c8
> [   15.602787] x26: ffff800009161988 x25: 0000000000000001 x24: 0000000000000000
> [   15.611498] x23: ffff800008e535c8 x22: ffff800008e53250 x21: ffff000005fe9e00
> [   15.618804] x20: ffff80000a78b7b8 x19: ffff80000a78b7a8 x18: 0000000000000030
> [   15.625956] x17: 3965663530303030 x16: 3066666666206564 x15: ffffffffffffffff
> [   15.633112] x14: 0000000000000000 x13: 3030303030303030 x12: 000000000004034f
> [   15.640265] x11: ffff8000095af930 x10: 000000000000011b x9 : 00000000ffffefff
> [   15.647418] x8 : ffff800009607930 x7 : 0000000000017fe8 x6 : 0000000000000000
> [   15.654571] x5 : 80000000fffff000 x4 : 0000000000000000 x3 : 0000000000000000
> [   15.661726] x2 : 0000000000000000 x1 : ffff000003516100 x0 : 0000000000000026
> [   15.668877] Call trace:
> [   15.671326]  path_find+0x94/0x374
> [   15.674653]  of_icc_get_by_index+0x1b0/0x290
> [   15.678932]  of_icc_get+0x70/0xa0
> [   15.682252]  of_icc_bulk_get+0x54/0xf0
> [   15.686007]  devm_of_icc_bulk_get+0x5c/0xc0
> [   15.690196]  imx8m_blk_ctrl_probe+0x22c/0x540
> [   15.694562]  platform_probe+0x68/0xe0
> [   15.698231]  really_probe+0xc0/0x3e0
> [   15.701820]  __driver_probe_device+0x7c/0x190
> [   15.706182]  driver_probe_device+0x3c/0x110
> [   15.710374]  __device_attach_driver+0xbc/0x160
> [   15.714827]  bus_for_each_drv+0x78/0xd0
> [   15.718670]  __device_attach+0xa8/0x1f0
> [   15.722513]  device_initial_probe+0x14/0x20
> [   15.726705]  bus_probe_device+0x9c/0xb0
> [   15.730549]  deferred_probe_work_func+0xa4/0x100
> [   15.735174]  process_one_work+0x288/0x6b0
> [   15.739193]  worker_thread+0x74/0x450
> [   15.742862]  kthread+0x10c/0x110
> [   15.746095]  ret_from_fork+0x10/0x20
> [   15.749683] Code: 90002480 91250000 f90053fb 97ffc398 (b8438783)
> [   15.755783] ---[ end trace 0000000000000000 ]---
> [   23.343608] random: crng init done
> 
> 
> ------------------------------8<------------------------------
> 
> The relevant line is line "B" in this snippet:
> 
>    A [   15.381942] >>> of_icc_get_from_provider:383 START, spec: np </soc at 0/interconnect at 32700000>
>    B [   15.383139] imx-bus-devfreq 32700000.interconnect: interconnect provider added to topology
>    C [   15.387956] snvs_rtc 30370000.snvs:snvs-rtc-lp: registered as rtc1
>    D [   15.390482] >>> of_icc_xlate_onecell:352 START
>    E [   15.401380] >>> of_icc_xlate_onecell:359 RETURN icc_data->nodes[37] = 0000000000000000
>    F [   15.409421] >>> of_icc_get_from_provider:416 RETURN data->node 0000000000000000
> 
> Here 32700000.interconnect is added during the execution of
> of_icc_get_from_provider(), which in turn calls of_icc_xlate_onecell()
> to find the interconnect node, failing and thus returning NULL. This
> NULL pointer is propagated up to of_icc_get_by_index() which passes it
> to path_find() where the pointer is dereferenced and the kernel oopses.
> 
> In successful runs, line B always appears outside of the execution of
> of_icc_get_from_provider(), i.e. either before line A or after line F, so
> it seems to me that the interconnect is being looked for while it is
> being added and the state is inconsistent.
> 
> That's all on my side at the moment. I haven't looked at how this
> could be fixed but I think the problem is pretty focused now.
> 
> I am of course available to provide more details.

Thanks for the report! Could you please try this patchset and see if it helps:
https://lore.kernel.org/all/20230201101559.15529-1-johan+linaro@kernel.org/

Thanks,
Georgi