[Letux-kernel] New LetuxOS Kernels - strcmp(NULL)

[H. Nikolaus Schaller]

> Am 22.06.2018 um 09:16 schrieb Tony Lindgren <tony at atomide.com>:
> 
> * H. Nikolaus Schaller <hns at 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 at 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 at 48:bci: Retrying from deferred list
[    6.066497] platform 48070000.i2c:twl at 48:bci: Retrying from deferred list
[    6.080902] platform 48070000.i2c:twl at 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 at 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...

BR,
Nikolaus