topic Re: i.MX28 - Possible recursive locking detected in i.MX Processors

i.MX28 - Possible recursive locking detected

rabryn — Fri, 27 Sep 2013 15:18:11 GMT

I'm integrating a TI WL1271 WLAN module into an i.MX28 design. The WL1271 is connected to the i.MX28 via SSP1 (4 bit wide) SDIO and an IRQ pin (driven by the WL1271 and connected to a GPIO on the i.MX28). I have the i.MX28 communicating to the WL1271 but I see the following informational. The issue doesn't prevent the WL1271 driver from working, but I don't believe this is correct.

[ 13.910817] mmc1: card claims to support voltages below the defined range. These will be ignored.

[ 13.938941] mmc1: queuing unknown CIS tuple 0x91 (3 bytes)

[ 13.950533] mmc1: new SDIO card at address 0001

[ 14.046390]

[ 14.047931] =============================================

[ 14.053345] [ INFO: possible recursive locking detected ]

[ 14.058762] 3.10.12 #9 Not tainted

[ 14.062176] ---------------------------------------------

[ 14.067587] kworker/0:0/4 is trying to acquire lock:

[ 14.072562] (&irq_desc_lock_class){-.-...}, at: [<c0067c3c>] __irq_get_desc_lock+0x48/0x88

[ 14.081021]

[ 14.081021] but task is already holding lock:

[ 14.086876] (&irq_desc_lock_class){-.-...}, at: [<c0067c3c>] __irq_get_desc_lock+0x48/0x88

[ 14.095308]

[ 14.095308] other info that might help us debug this:

[ 14.101854] Possible unsafe locking scenario:

[ 14.101854]

[ 14.107789] CPU0

[ 14.110243] ----

[ 14.112697] lock(&irq_desc_lock_class);

[ 14.116739] lock(&irq_desc_lock_class);

[ 14.120780]

[ 14.120780] *** DEADLOCK ***

[ 14.120780]

[ 14.126720] May be due to missing lock nesting notation

[ 14.126720]

[ 14.133528] 3 locks held by kworker/0:0/4:

[ 14.137634] #0: (events){.+.+.+}, at: [<c0035db0>] process_one_work+0x134/0x4a4

[ 14.145214] #1: ((&fw_work->work)){+.+.+.}, at: [<c0035db0>] process_one_work+0x134/0x4a4

[ 14.153659] #2: (&irq_desc_lock_class){-.-...}, at: [<c0067c3c>] __irq_get_desc_lock+0x48/0x88

[ 14.162536]

[ 14.162536] stack backtrace:

[ 14.166926] CPU: 0 PID: 4 Comm: kworker/0:0 Not tainted 3.10.12 #9

[ 14.173153] Workqueue: events request_firmware_work_func

[ 14.178538] [<c0013e54>] (unwind_backtrace+0x0/0xf0) from [<c0011c10>] (show_stack+0x10/0x14)

[ 14.187122] [<c0011c10>] (show_stack+0x10/0x14) from [<c005b228>] (__lock_acquire+0x140c/0x1a64)

[ 14.195959] [<c005b228>] (__lock_acquire+0x140c/0x1a64) from [<c005bdc8>] (lock_acquire+0x9c/0x104)

[ 14.205054] [<c005bdc8>] (lock_acquire+0x9c/0x104) from [<c04da944>] (_raw_spin_lock_irqsave+0x44/0x58)

[ 14.214496] [<c04da944>] (_raw_spin_lock_irqsave+0x44/0x58) from [<c0067c3c>] (__irq_get_desc_lock+0x48/0x88)

[ 14.224458] [<c0067c3c>] (__irq_get_desc_lock+0x48/0x88) from [<c00684c4>] (irq_set_irq_wake+0x20/0xf4)

[ 14.233904] [<c00684c4>] (irq_set_irq_wake+0x20/0xf4) from [<c026e3b8>] (mxs_gpio_set_wake_irq+0x1c/0x24)

[ 14.243520] [<c026e3b8>] (mxs_gpio_set_wake_irq+0x1c/0x24) from [<c0068340>] (set_irq_wake_real+0x30/0x44)

[ 14.253220] [<c0068340>] (set_irq_wake_real+0x30/0x44) from [<c0068530>] (irq_set_irq_wake+0x8c/0xf4)

[ 14.262504] [<c0068530>] (irq_set_irq_wake+0x8c/0xf4) from [<c030bf4c>] (wlcore_nvs_cb+0x10c/0x980)

[ 14.271608] [<c030bf4c>] (wlcore_nvs_cb+0x10c/0x980) from [<c02ba0b8>] (request_firmware_work_func+0x38/0x58)

[ 14.281574] [<c02ba0b8>] (request_firmware_work_func+0x38/0x58) from [<c0035e3c>] (process_one_work+0x1c0/0x4a4)

[ 14.291796] [<c0035e3c>] (process_one_work+0x1c0/0x4a4) from [<c00364f4>] (worker_thread+0x138/0x394)

[ 14.301060] [<c00364f4>] (worker_thread+0x138/0x394) from [<c003c5bc>] (kthread+0xa4/0xb0)

[ 14.309383] [<c003c5bc>] (kthread+0xa4/0xb0) from [<c000ee00>] (ret_from_fork+0x14/0x34)

[ 14.695611] wlcore: mem_start 00040000 mem_size 00014FC0

[ 14.700975] wlcore: reg_start 00300000 reg_size 00008800

[ 14.706429] wlcore: mem2_start 00000000 mem2_size 00000000

[ 14.711951] wlcore: mem3_start 00000000 mem3_size 00000000

[ 14.720154] wlcore: PG Ver major = 3 minor = 0, MAC is not present

[ 14.730585] wlcore: chip id 0x4030111 (1271 PG20)

[ 14.735361] wlcore: base address: oui deadbe nic ef0000

[ 14.800781] wlcore: loaded

I've investigated the issue and found how the double locking occurs although I'm not sure how to fix it. In addition to the SDIO interface, the module provides an IRQ line that I've connected to a GPIO pin of the i.MX28. The WL1271 driver sets up an IRQ handler for rising edges on the GPIO pin. During the setup of this IRQ handler the double locking occurs. In short, as far as I can see, a call to 'enable_irq_wake' may cause the double lock. Here's the call stack (from mainline kernel version 3.10.12, same issue was also seen in 3.8.3)...

wlcore_nvs_cb (drivers/net/wireless/ti/wlcore/main.c)

enable_irq_wake (include/linux/interrupt.h)

irq_set_irq_wake (kernel/irq/manage.c)

irq_get_desc_buslock (kernel/irq/manage.c - locking occurs here)

set_irq_wake_real (kernel/irq/manage.c)

desc->irq_data.chip->irq_set_wake (kernel/irq/manage.c, irq_set_wake is a function pointer that points to mxs_gpio_set_wake_irq)

irq_set_wake -> mxs_gpio_set_wake_irq (drivers/gpio/gpio-mxs.c)

enable_irq_wake (include/linux/interrupt.h)

irq_set_irq_wake (kernel/irq/manage.c)

irq_get_desc_buslock (kernel/irq/manage.c - locking occurs here, again)

Any advice or help would be appreciated.

Re: i.MX28 - Possible recursive locking detected

fabio_estevam — Sat, 28 Sep 2013 04:05:34 GMT

Hi Ryan,

Thanks for reporting it. This is something that needs to be fixed. Could you please also try 3.12-rc2?

If the problem is still there, then I would suggest you to report it via linux-arm-kernel mailing list.

Please also share your dts file in the report.

Regards,

Fabio Estevam

Re: i.MX28 - Possible recursive locking detected

rabryn — Fri, 04 Oct 2013 18:28:19 GMT

Hi Fabio,

Same situation with 3.12.0-rc3:

[ 37.873503] =============================================

[ 37.878922] [ INFO: possible recursive locking detected ]

[ 37.884341] 3.12.0-rc3 #3 Not tainted

[ 37.888017] ---------------------------------------------

[ 37.893431] kworker/0:0/4 is trying to acquire lock:

[ 37.898408] (&irq_desc_lock_class){-.-...}, at: [<c004f594>] __irq_get_desc_lock+0x48/0x88

[ 37.906873]

[ 37.906873] but task is already holding lock:

[ 37.912730] (&irq_desc_lock_class){-.-...}, at: [<c004f594>] __irq_get_desc_lock+0x48/0x88

[ 37.921163]

[ 37.921163] other info that might help us debug this:

[ 37.927713] Possible unsafe locking scenario:

[ 37.927713]

[ 37.933648] CPU0

[ 37.936103] ----

[ 37.938556] lock(&irq_desc_lock_class);

[ 37.942597] lock(&irq_desc_lock_class);

[ 37.946637]

[ 37.946637] *** DEADLOCK ***

[ 37.946637]

[ 37.952581] May be due to missing lock nesting notation

[ 37.952581]

[ 37.959391] 3 locks held by kworker/0:0/4:

[ 37.963497] #0: (events){.+.+.+}, at: [<c0032f0c>] process_one_work+0x134/0x4a4

[ 37.971074] #1: ((&fw_work->work)){+.+.+.}, at: [<c0032f0c>] process_one_work+0x134/0x4a4

[ 37.979513] #2: (&irq_desc_lock_class){-.-...}, at: [<c004f594>] __irq_get_desc_lock+0x48/0x88

[ 37.988390]

[ 37.988390] stack backtrace:

[ 37.992781] CPU: 0 PID: 4 Comm: kworker/0:0 Not tainted 3.12.0-rc3 #3

[ 37.999261] Workqueue: events request_firmware_work_func

[ 38.004662] [<c00144c8>] (unwind_backtrace+0x0/0xf0) from [<c0011ce4>] (show_stack+0x10/0x14)

[ 38.013243] [<c0011ce4>] (show_stack+0x10/0x14) from [<c0062034>] (__lock_acquire+0x140c/0x1a64)

[ 38.022070] [<c0062034>] (__lock_acquire+0x140c/0x1a64) from [<c0062bd4>] (lock_acquire+0x9c/0x104)

[ 38.031170] [<c0062bd4>] (lock_acquire+0x9c/0x104) from [<c05331d4>] (_raw_spin_lock_irqsave+0x44/0x58)

[ 38.040608] [<c05331d4>] (_raw_spin_lock_irqsave+0x44/0x58) from [<c004f594>] (__irq_get_desc_lock+0x48/0x88)

[ 38.050569] [<c004f594>] (__irq_get_desc_lock+0x48/0x88) from [<c004fe20>] (irq_set_irq_wake+0x20/0xf4)

[ 38.060022] [<c004fe20>] (irq_set_irq_wake+0x20/0xf4) from [<c0283490>] (mxs_gpio_set_wake_irq+0x1c/0x24)

[ 38.069636] [<c0283490>] (mxs_gpio_set_wake_irq+0x1c/0x24) from [<c004fc98>] (set_irq_wake_real+0x30/0x44)

[ 38.079333] [<c004fc98>] (set_irq_wake_real+0x30/0x44) from [<c004fe8c>] (irq_set_irq_wake+0x8c/0xf4)

[ 38.088616] [<c004fe8c>] (irq_set_irq_wake+0x8c/0xf4) from [<c03260bc>] (wlcore_nvs_cb+0x10c/0x8dc)

[ 38.097717] [<c03260bc>] (wlcore_nvs_cb+0x10c/0x8dc) from [<c02d03b0>] (request_firmware_work_func+0x38/0x58)

[ 38.107672] [<c02d03b0>] (request_firmware_work_func+0x38/0x58) from [<c0032f98>] (process_one_work+0x1c0/0x4a4)

[ 38.117886] [<c0032f98>] (process_one_work+0x1c0/0x4a4) from [<c0033654>] (worker_thread+0x13c/0x384)

[ 38.127158] [<c0033654>] (worker_thread+0x13c/0x384) from [<c0039744>] (kthread+0xa4/0xb0)

[ 38.135471] [<c0039744>] (kthread+0xa4/0xb0) from [<c000efa0>] (ret_from_fork+0x14/0x34)

I'll post to the arm KML.

Thanks,

Ryan

Re: i.MX28 - Possible recursive locking detected

fabio_estevam — Fri, 04 Oct 2013 18:37:12 GMT

Thanks, Ryan.

How do you pass the IRQ GPIO pin in the device tree?

Regards,

Fabio Estevam

Re: i.MX28 - Possible recursive locking detected

rabryn — Thu, 10 Oct 2013 17:58:25 GMT

I'm not defining the IRQ in the device tree. I defined it using 'wl12xx_platform_data' in mach-mxs.c.

Re: i.MX28 - Possible recursive locking detected

alexgal — Thu, 10 Oct 2013 18:24:19 GMT

Hey there.

I had the same issue (TX28 board with TIWI-BLE).

In my case, I disabled power management since I did not need it and made the issue go away (you might need a small patch to make it compile without CONFIG_PM).

Cheers,

Alex

Re: i.MX28 - Possible recursive locking detected

rabryn — Thu, 10 Oct 2013 18:37:15 GMT

Alex,

I saw the #ifdef for CONFIG_PM when I was digging around in the code.

On another note, did you use the bluetooth side of the wl1271? I'm playing with that now... in bluez + pulseaudio hell trying to get audio to stream over bluetooth from a phone to the mx28 via wl1271. I can get pulseaudio to recognize the bluetooth card, but it won't create a bluez_source.

Ryan

Re: i.MX28 - Possible recursive locking detected

alexgal — Thu, 10 Oct 2013 19:07:16 GMT

I only did a basic test with bluez i.e. scanning and pairing with my phone.

I did notice however that if I shutdown the TIWI, I am not able to do hciattach if I bring the TIWI back. ):

Re: i.MX28 - Possible recursive locking detected

rabryn — Thu, 10 Oct 2013 19:12:53 GMT

I'm not exactly sure what you mean by "shutdown the TIWI", but I have to drive the 'bluetooth enable' pin low, pause, then back high before I can call hciattach, every time.

Re: i.MX28 - Possible recursive locking detected

MarekVasut — Mon, 24 Mar 2014 02:46:36 GMT

"[PATCH] gpio: mxs: Allow for recursive enable_irq_wake() call" should be fixing this problem and is landing in linux-arm-kernel now.

Re: i.MX28 - Possible recursive locking detected

MarekVasut — Mon, 24 Mar 2014 02:47:27 GMT

[PATCH] gpio: mxs: Allow for recursive enable_irq_wake() call