topic Re: i.mx6sx linux-fslc sema4 bug in i.MX Processors

i.mx6sx linux-fslc sema4 bug

kubiznak_petr — Wed, 04 Oct 2017 16:48:09 GMT

How to reproduce

I hit on a problem in linux-fslc 4.1.38, available at GitHub - Freescale/linux-fslc: Linux kernel source tree . It is related to the sema4 mutex locking mechanism (drivers/char/imx_amp/imx_sema4.c). The problem only arises when the M4 core is running and its RDC domain is set. I'm running a trivial FreeRTOS program based on the hello_world demo from the NXP's official distribution (https://www.nxp.com/webapp/Download?colCode=FreeRTOS_MX6SX_1.0.1_WIN&appType=license&Parent_nodeId=142289606182472763482… ). The program simply sets the RDC domain and loops forever:

RDC_SetDomainID(RDC, rdcMdaM4, BOARD_DOMAIN_ID, false);
while (1) ;

With Yocto (Morty), I built the qt4e-demo-image (fslc-framebuffer distro). When I boot the image, qtdemoE demo starts. The problem can be reproduced with an intensive I2C communication. In my case, I touch on the screen wildly, generating the touch events. My interrupt-driven touchscreen driver calls i2c_smbus_read_byte_data() to read the data.

What it does

After a while, the following message starts printing in the terminal infinitely:

drivers/char/imx_amp/imx_sema4.c -> _imx_sema4_mutex_lock 137 already locked, wait! num 6 val 1

The FreeRTOS on the M4 core continues without problem. If I stop the debugger and check the SEMA4_Gate06 register, its value is set to 1, indicating it is locked by the A9 core.

Workaround

After spending hours on this problem, I formed a testing patch (see attached). In the _imx_sema4_mutex_lock() function, it disables the error log for the first 5 occurences. As a result, instead of being imprisoned in the infinite error message loop, I just get a single message and everything seems to work fine:

286 Trying to unlock an unlock mutex.

When this repeats 5-times (which might take a while), the system enters the infinite message loop. Including my added prints, the output looks as follows:

286 Trying to unlock an unlock mutex.
286 Trying to unlock an unlock mutex.
286 Trying to unlock an unlock mutex.
286 Trying to unlock an unlock mutex.
286 Trying to unlock an unlock mutex.
drivers/char/imx_amp/imx_sema4.c -> _imx_sema4_mutex_lock 145 already locked, wait! num 6 val 1. 6
CPU: 0 PID: 66 Comm: irq/203-crtouch Tainted: G           O    4.1.38-fslc-01914-gb3f76d9ae87e-dirty #12
Hardware name: Freescale i.MX6 SoloX (Device Tree)
[<800184e0>] (unwind_backtrace) from [<80013cfc>] (show_stack+0x20/0x24)
[<80013cfc>] (show_stack) from [<8091b2ec>] (dump_stack+0x80/0x94)
[<8091b2ec>] (dump_stack) from [<80406be8>] (_imx_sema4_mutex_lock+0x11c/0x1c4)
[<80406be8>] (_imx_sema4_mutex_lock) from [<80406d58>] (imx_sema4_mutex_lock+0xa4/0x128)
[<80406d58>] (imx_sema4_mutex_lock) from [<80025738>] (clk_gate2_do_shared_clks+0x78/0xe4)
[<80025738>] (clk_gate2_do_shared_clks) from [<800258b8>] (clk_gate2_disable+0x58/0x7c)
[<800258b8>] (clk_gate2_disable) from [<806b6838>] (clk_core_disable+0x64/0x1e4)
[<806b6838>] (clk_core_disable) from [<806b7630>] (clk_disable+0x34/0x40)
[<806b7630>] (clk_disable) from [<805d2eec>] (i2c_imx_xfer+0x194/0xe28)
[<805d2eec>] (i2c_imx_xfer) from [<805ce5a0>] (__i2c_transfer+0x160/0x678)
[<805ce5a0>] (__i2c_transfer) from [<805ceb2c>] (i2c_transfer+0x74/0xa0)
[<805ceb2c>] (i2c_transfer) from [<805cf1a4>] (i2c_smbus_xfer+0x590/0x9d8)
[<805cf1a4>] (i2c_smbus_xfer) from [<805cf7ec>] (i2c_smbus_read_byte_data+0x3c/0x4c)
[<805cf7ec>] (i2c_smbus_read_byte_data) from [<805c07d0>] (crtouch_ts_interrupt+0x90/0x14c)
[<805c07d0>] (crtouch_ts_interrupt) from [<8007e824>] (irq_thread_fn+0x2c/0x50)
[<8007e824>] (irq_thread_fn) from [<8007eb80>] (irq_thread+0x13c/0x188)
[<8007eb80>] (irq_thread) from [<800576b4>] (kthread+0xec/0x104)
[<800576b4>] (kthread) from [<8000fca8>] (ret_from_fork+0x14/0x2c)
l : 97284, 8852a240, clk_gate2_do_shared_clks+0x78/0xe4
lo: 97284, 8852a240, clk_pllv3_do_shared_clks+0x78/0xe4
k : 97284, 8852a240, clk_gate2_do_shared_clks+0x78/0xe4
ko: 97284, 8852a240, clk_pllv3_do_shared_clks+0x78/0xe4
u : 97282, 8852a240, clk_gate2_do_shared_clks+0xa4/0xe4
uo: 97180, 8852a240, clk_pllv3_do_shared_clks+0xa4/0xe4
drivers/char/imx_amp/imx_sema4.c -> _imx_sema4_mutex_lock 145 already locked, wait! num 6 val 1. 7
CPU: 0 PID: 66 Comm: irq/203-crtouch Tainted: G           O    4.1.38-fslc-01914-gb3f76d9ae87e-dirty #12
Hardware name: Freescale i.MX6 SoloX (Device Tree)
[<800184e0>] (unwind_backtrace) from [<80013cfc>] (show_stack+0x20/0x24)
[<80013cfc>] (show_stack) from [<8091b2ec>] (dump_stack+0x80/0x94)
[<8091b2ec>] (dump_stack) from [<80406be8>] (_imx_sema4_mutex_lock+0x11c/0x1c4)
[<80406be8>] (_imx_sema4_mutex_lock) from [<80406d88>] (imx_sema4_mutex_lock+0xd4/0x128)
[<80406d88>] (imx_sema4_mutex_lock) from [<80025738>] (clk_gate2_do_shared_clks+0x78/0xe4)
[<80025738>] (clk_gate2_do_shared_clks) from [<800258b8>] (clk_gate2_disable+0x58/0x7c)
[<800258b8>] (clk_gate2_disable) from [<806b6838>] (clk_core_disable+0x64/0x1e4)
[<806b6838>] (clk_core_disable) from [<806b7630>] (clk_disable+0x34/0x40)
[<806b7630>] (clk_disable) from [<805d2eec>] (i2c_imx_xfer+0x194/0xe28)
[<805d2eec>] (i2c_imx_xfer) from [<805ce5a0>] (__i2c_transfer+0x160/0x678)
[<805ce5a0>] (__i2c_transfer) from [<805ceb2c>] (i2c_transfer+0x74/0xa0)
[<805ceb2c>] (i2c_transfer) from [<805cf1a4>] (i2c_smbus_xfer+0x590/0x9d8)
[<805cf1a4>] (i2c_smbus_xfer) from [<805cf7ec>] (i2c_smbus_read_byte_data+0x3c/0x4c)
[<805cf7ec>] (i2c_smbus_read_byte_data) from [<805c07d0>] (crtouch_ts_interrupt+0x90/0x14c)
[<805c07d0>] (crtouch_ts_interrupt) from [<8007e824>] (irq_thread_fn+0x2c/0x50)
[<8007e824>] (irq_thread_fn) from [<8007eb80>] (irq_thread+0x13c/0x188)
[<8007eb80>] (irq_thread) from [<800576b4>] (kthread+0xec/0x104)
[<800576b4>] (kthread) from [<8000fca8>] (ret_from_fork+0x14/0x2c)
l : 97284, 8852a240, clk_gate2_do_shared_clks+0x78/0xe4
lo: 97284, 8852a240, clk_pllv3_do_shared_clks+0x78/0xe4
k : 97284, 8852a240, clk_gate2_do_shared_clks+0x78/0xe4
ko: 97284, 8852a240, clk_pllv3_do_shared_clks+0x78/0xe4
u : 97282, 8852a240, clk_gate2_do_shared_clks+0xa4/0xe4
uo: 97180, 8852a240, clk_pllv3_do_shared_clks+0xa4/0xe4
... (repeats infinitely) ...

The problem

The output shows the problem is in calling the imx_sema4_mutex_lock() function from two places at once (clk_gate2_do_shared_clks() and clk_pllv3_do_shared_clks()). One comes from the touchscreen interrupt handler, second comes from some worker thread, but I don't know more details about it.

It is obvious that printing anything to the console from an interrupt handler is not okay. So I suggest to disable all debug/error prints in the imx_sema4.c file. Then the infinite message loop would be avoided.

The question is, what is the root cause. Is the debug print really the problem (i.e. it is a valid situation that mutex_ptr->gate_val == SEMA4_A9_LOCK), or does it just expose a problem hidden somewhere else (i.e. the debug print should actually never appear).

As the aforementioned output shows, the condition (mutex_ptr->gate_val != SEMA4_A9_LOCK) in imx_sema4_mutex_unlock() holds true when the problematic situation arises. I guess it is because the gate_val is already 0, as the unlock function has been called twice, which corresponds to the two locking calls. That suggests the locking mechanism does not work correctly.

Is my reasoning correct? How to properly fix the problem? I guess this question might be interesting for OtavioSalvador or Daiane Angolini .

Original Attachment has been moved to: imx_sema4.patch.zip

Re: i.mx6sx linux-fslc sema4 bug

daiane_angolini — Mon, 09 Oct 2017 17:58:21 GMT

Hi Petr, sorry for my late reply, it was a very busy week.

Have you tried to follow the mutex lifetime? I mean, which other components deal with the same?

Another point, have you tried to reproduce the same using the 4.1.5_2.0.0_GA kernel?

Re: i.mx6sx linux-fslc sema4 bug

daiane_angolini — Mon, 09 Oct 2017 18:21:02 GMT

Another point. Have you tried to use the real time kernel?

Re: i.mx6sx linux-fslc sema4 bug

kubiznak_petr — Tue, 10 Oct 2017 13:02:31 GMT

Hi Daiane, thank you for your reply.

I have not tested with those kernels since I don't have them. Can you please provide such zImages?

I didn't follow the mutex lifetime, as I don't know how to efficiently do it. I never had a chance to learn something more efficient than kernel logs. How would you do that?

Just by luck, I found that the evbug kernel module might be incident with the issue. When I rmmod evbug, I never see the issue appear. When I insmod evbug again, the issue reappears. I don't think it's the root cause, though.

Re: i.mx6sx linux-fslc sema4 bug

daiane_angolini — Wed, 11 Oct 2017 12:40:09 GMT

For the kernel RT, I would take the one from kernel mainline. Another option is to follow the recipe in meta-freescale-3rd to take a branch with imx6 support.

ultimately, please send the bug to the meta-freescale mailing list so we can enter a bug on bugzila.

Re: i.mx6sx linux-fslc sema4 bug

OtavioSalvador — Tue, 17 Oct 2017 12:34:11 GMT

If you can, check our current linux-fslc-imx release as it has several fixes. The rocko branch has it up to date.

Re: i.mx6sx linux-fslc sema4 bug

kubiznak_petr — Tue, 09 Jan 2018 17:26:49 GMT

Hi Daiane, I've reported the bug 3 months ago, including the mailing list post ([meta-freescale] i.mx6sx linux-fslc sema4 bug ). There was absolutely no reply in the mailing list and I didn't find any recent update in the imx_sema4.c file in the linux-fslc kernel.

I don't consider blind trying of more and more kernel versions to be the right strategy. I would expect someone competent to look at the issue, try to reproduce it and give some solution. Or to say that it was already fixed by those and those patches, so I am able to either switch to the proven kernel version, or backport the fix to my version. Some analytical approach would be appreciated.

Re: i.mx6sx linux-fslc sema4 bug

daiane_angolini — Wed, 10 Jan 2018 17:22:34 GMT

We recommended you to test in different kernel versions and providers only because you are reporting the bug in a kernel that is out of the support boundaries for both nxp and the community.

I don't know how to fix the bug, and I can only escalate it internally if it's reproducible on the reference board using the latest NXP IMX kernel for that soc.

Re: i.mx6sx linux-fslc sema4 bug

davidpatton — Wed, 13 Jun 2018 21:48:02 GMT

Was this ever resolved? I'm having the same issue; my kernel is older than the original posters (4.1.15) so it makes sense that I'd have it, but I need a fix. Thanks...

Re: i.mx6sx linux-fslc sema4 bug

davidpatton — Tue, 19 Jun 2018 15:27:12 GMT

I see a problem in the sema4 driver. An A9 thread is never put to sleep if it cannot obtain the sema4. A wait_q is created, and the ISR will wake up any thread on the wait_q, but the driver never puts a thread on the wait_q. In imx_sema4_mutex_lock() it just continuously tries to get the sema4, thus locking out the thread that holds the sema4 and we have a deadlock, in my case it is constantly spitting out the trace:

drivers/char/imx_amp/imx_sema4.c -> _imx_sema4_mutex_lock 137 already locked, wait! num 6 val 1.

If the M4 actually has the sema4, the A9 will be stuck with 1 thread in a tight loop, waiting for it. I'm fairly certain this is not correct behavior. If the A9 cannot obtain the semaphore, it should be put to sleep.

Re: i.mx6sx linux-fslc sema4 bug

kubiznak_petr — Mon, 25 Jun 2018 06:50:59 GMT

Hi David, thank you for your investigation! I really appreciate it. It doesn't seem that anyone from NXP is ever going to dig into the issue. Do you think you would be able to patch the driver? I would be willing to do it, regrettably I don't know kernel programming that well. I could at least test the patch on version 4.1.38.

Re: i.mx6sx linux-fslc sema4 bug

BiyongSUN — Wed, 27 Jun 2018 05:39:04 GMT

Have you ever tried NXP official BSP release?

NXP didn't do any release on 4.1.38

Please git the source code from the NXP git site.

Re: i.mx6sx linux-fslc sema4 bug

kubiznak_petr — Fri, 29 Jun 2018 09:08:55 GMT

Hi Biyong, thanks for your reply. 4.1.15 was an official release, yet it contains exactly the same driver: linux-imx.git - i.MX Linux Kernel (yes, I did compare the files).

And as David recently posted, he's experiencing the same issue.

Re: i.mx6sx linux-fslc sema4 bug

BiyongSUN — Mon, 02 Jul 2018 04:44:30 GMT

If you want to use the i2c with the "protocol", you need virtualization.

The hardware semaphore sema4 is just "hardware" mutex to let the hardware ready for use.

Here should be the i2c.

Re: i.mx6sx linux-fslc sema4 bug

kubiznak_petr — Mon, 02 Jul 2018 06:42:56 GMT

I'm sorry, I don't really understand what you are suggesting. I have checked the drivers/i2c/i2c-core.c and drivers/i2c/busses/i2c-imx.c files for changes, and they are the same in 4.1.15 and 4.1.38.

Anyway, I am not sure that the bug relates to the I2C operation only. davidpatton‌, may you please describe your use case in more details?

Re: i.mx6sx linux-fslc sema4 bug

BiyongSUN — Tue, 03 Jul 2018 02:36:29 GMT

The hardware sema4 is for set flag for like writing the register here is the i2c register.

But it could not handle the i2c protocol sequence.

Re: i.mx6sx linux-fslc sema4 bug

kubiznak_petr — Tue, 03 Jul 2018 08:01:25 GMT

Hi Otavio, thank you for your reply. I've made the test with recent linux-fslc-imx (4.1-2.0.x+gitAUTOINC+6c1ad49339-r0) in rocko, with the same result. The imx_sema4.c file equals the one from version 4.1.38.

Can now the issue be escalated? Or is there an option to switch to another kernel with full i.MX6SoloX support?

Re: i.mx6sx linux-fslc sema4 bug

BiyongSUN — Wed, 04 Jul 2018 02:54:29 GMT

Below is your descript of "the problem"

It is like a protocol sequence.

It needs virtualization to do so.

Or need lock a complete i2c communication of A9 side. then release to M4. Then M4 finish a complete i2c communication then release to A9.

It could not be lock at anytime or middle of i2c communication. That is why need virtualization.

The hardware semaphore is not to handle a sequence. that is why the log shows lots of try to lock.

It is not a GPIO, it is i2c bus.

If it is just a GPIO, it can just use a hardware semaphore to do so. you can try a GPIO to see what is happening.

That is the last reply from me.

The problem

Is my reasoning correct? How to properly fix the problem? I guess this question might be interesting for OtavioSalvador or Daiane Angolini .

Original Attachment has been moved to:

Re: i.mx6sx linux-fslc sema4 bug

kubiznak_petr — Wed, 04 Jul 2018 13:41:05 GMT

I finally had some time to at least do this blind trying. I used the linux-fslc-imx-rt_4.1-2.0 from the meta-freescale layer of the community rocko branch. I wasn't able to reproduce the bug with this realtime kernel, which is promising. It would be great to get this confirmed from someone else experiencing the same issue, e.g. davidpatton‌.

---

Just a note regarding the kernel version. linux-fslc-imx-rt_4.1-2.0 is the name of the recipe, anyway it corresponds to the kernel version 4.1.38 (4.1.38-rt45-fslc+gee67fc7e072d in particular) at both morty and rocko branches. That is the same kernel version I originally reported, as it was the version corresponding to the linux-fslc-imx_4.1-2.0 recipe at morty. And according to the FSL Community BSP Release Notes 2.4 (Draft document) documentation , the 4.1-2.0.x+git kernel "version" is still the default kernel for imx6sxsabresd. That's why I believe this bug report should be interesting for the community.

Re: i.mx6sx linux-fslc sema4 bug

daiane_angolini — Thu, 05 Jul 2018 16:22:11 GMT

thanks for mentioning me. I don't know the answer.