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...
BR, Nikolaus