Ev3dev: Motors don't stop when using run-to-rel-pos command in ev3dev-stretch-ev3-generic-2018-07-26 image

[ndward]

It seems to me the 27 July EV3 Stretch image is broken! Even a simple script like this fails to run correctly, even though it runs fine on the preceding Stretch image.

#!/usr/bin/env python3
from ev3dev.ev3 import *
mB = LargeMotor('outB')
mB.stop_action = 'hold'
mB.run_to_rel_pos(position_sp=360, speed_sp=100)
mB.wait_while('running')

I expected the motor to stop after turning 360° but it never stopped. I could not stop it from VS Code nor did it stop when I pressed the Back button on the EV3. I had to reboot the brick to make the motor stop.

I'm using VS Code 1.25.1 on a Win10 machine.

Image file:         ev3dev-stretch-ev3-generic-2018-07-26
Kernel version:     4.14.58-ev3dev-2.2.1-ev3
Brickman:           0.10.0
BogoMIPS:           148.88
Board:              board0
BOARD_INFO_HW_REV=7
BOARD_INFO_MODEL=LEGO MINDSTORMS EV3
BOARD_INFO_ROM_REV=6
BOARD_INFO_SERIAL_NUM=00165340377E
BOARD_INFO_TYPE=main

I've exchanged emails with @WasabiFan and he confirms the problem. He adds 'my guess is that something about positional readings was broken with the new position implementation. It looks to me like the driver is partially frozen once it starts moving the motor.' He also wrote to me 'The port names changed a few Stretch releases ago, so the port name is actually “ev3-ports:outB” now. In general you should use the “OUTPUT_B” constants rather than the string “outB” so that library updates can change those names internally. In this case we haven’t released an accordingly updated library version anyway so it wouldn’t fix it in this case. Honestly, I’m not sure why it works for you at all – I would expect it to throw an error about the port name'.

I modified the script to use OUTPUT_B and experienced the same problem.

I encourage all users of my site ev3python.com (which targets beginners) to always use the latest Stretch version and VS Code, so this will be a problem for them. I hope a fixed image can be released ASAP!

[dlech]

Are there any error messages in the kernel log (output of dmesg)?

Do the motors work as expected in the previous SD card image (2018-07-15)?

[WasabiFan]

Are there any error messages in the kernel log (output of dmesg)?

There aren't. The only even vaguely related/new message I see is about registering the PRU channel.

Do the motors work as expected in the previous SD card image (2018-07-15)?

Yes, they do. This is the image I'm using for my ev3dev-lang-python testing.

---

Here's a repro:

robot@ev3dev:~$ cd /sys/class/tacho-motor/motor0
robot@ev3dev:/sys/class/tacho-motor/motor0$ echo 200 > speed_sp
robot@ev3dev:/sys/class/tacho-motor/motor0$ echo 100 > position_sp
robot@ev3dev:/sys/class/tacho-motor/motor0$ echo run-to-rel-pos > command

Other notes:

Once you're in this state, the driver no longer registers plug/unplug events. Additionally (and perhaps more useful), running cat position or cat speed after the motor starts just hangs the terminal -- presumably cat is waiting for output or for some syscall to return and it isn't. Reading from state does the same. However, reading from commands or max_speed is fine. The brick otherwise still runs -- accepts SSH connections, lets you run other code, etc.

[dlech]

Sounds like a deadlock caused by the changes in https://github.com/ev3dev/lego-linux-drivers/commit/b122a8fedd264668151e733dc1aea17976c5d848

There is probably a function that calls another function while the lock is held.

[dlech]

Whoop there it is:

[  290.938697] ============================================
[  290.942740] WARNING: possible recursive locking detected
[  290.946792] 4.14.58-ev3dev-2.2.1-ev3 #437 Not tainted
[  290.950572] --------------------------------------------
[  290.954627] irq/255-ev3-tac/227 is trying to acquire lock:
[  290.958844]  (&ev3_tm->lock){++++}, at: [<c022e704>] legoev3_motor_stop+0x34/0xe8
[  290.965169] 
               but task is already holding lock:
[  290.968422]  (&ev3_tm->lock){++++}, at: [<c022ea74>] legoev3_motor_tacho_cb+0x24/0x26c
[  290.975154] 
               other info that might help us debug this:
[  290.979107]  Possible unsafe locking scenario:

[  290.982445]        CPU0
[  290.983600]        ----
[  290.984755]   lock(&ev3_tm->lock);
[  290.986895]   lock(&ev3_tm->lock);
[  290.989034] 
                *** DEADLOCK ***

[  290.991063]  May be due to missing lock nesting notation

[  290.995286] 1 lock held by irq/255-ev3-tac/227:
[  290.998540]  #0:  (&ev3_tm->lock){++++}, at: [<c022ea74>] legoev3_motor_tacho_cb+0x24/0x26c
[  291.005713] 
               stack backtrace:
[  291.007504] CPU: 0 PID: 227 Comm: irq/255-ev3-tac Not tainted 4.14.58-ev3dev-2.2.1-ev3 #437
[  291.014607] Hardware name: LEGO MINDSTORMS EV3
[  291.017776] Backtrace: 
[  291.019008] [<c000dd84>] (dump_backtrace) from [<c000e034>] (show_stack+0x18/0x1c)
[  291.025346]  r7:c0eacec4 r6:c0bfe2d8 r5:00000000 r4:c0bfe2d8
[  291.029796] [<c000e01c>] (show_stack) from [<c052c978>] (dump_stack+0x20/0x28)
[  291.035819] [<c052c958>] (dump_stack) from [<c004c1ec>] (__lock_acquire+0x3a0/0x16c4)
[  291.042436] [<c004be4c>] (__lock_acquire) from [<c004dc68>] (lock_acquire+0x78/0x98)
[  291.048951]  r10:c3156b88 r9:00000001 r8:c0762ab0 r7:00000001 r6:60000013 r5:00000000
[  291.055531]  r4:ffffe000
[  291.056825] [<c004dbf0>] (lock_acquire) from [<c0542c3c>] (down_write+0x48/0x8c)
[  291.062988]  r7:c3bfc010 r6:c3156b88 r5:c022e704 r4:c3156b88
[  291.067417] [<c0542bf4>] (down_write) from [<c022e704>] (legoev3_motor_stop+0x34/0xe8)
[  291.074094]  r5:00000000 r4:c3156810
[  291.076425] [<c022e6d0>] (legoev3_motor_stop) from [<c022ec28>] (legoev3_motor_tacho_cb+0x1d8/0x26c)
[  291.084335]  r9:00000000 r8:c317df10 r7:00000064 r6:00000064 r5:00000064 r4:c3156810
[  291.090873] [<c022ea50>] (legoev3_motor_tacho_cb) from [<c03ad000>] (iio_buffer_cb_store_to+0x20/0x24)
[  291.098966]  r10:c0f78bb8 r9:c1a67f38 r8:c317df10 r7:c1a67ed0 r6:c32a1a20 r5:c317df04
[  291.105551]  r4:c317df00 r3:c317df00
[  291.107883] [<c03acfe0>] (iio_buffer_cb_store_to) from [<c03aa8fc>] (iio_push_to_buffers+0x8c/0xb8)
[  291.115759] [<c03aa870>] (iio_push_to_buffers) from [<bf0c62f8>] (ev3_pru_tacho_trigger_handler+0x158/0x16c [ev3_pru])
[  291.125249]  r9:c1a67f38 r8:00000002 r7:c32a1800 r6:c4b5c000 r5:000000f0 r4:c1a67efc
[  291.131797] [<bf0c61a0>] (ev3_pru_tacho_trigger_handler [ev3_pru]) from [<c0056dd4>] (irq_thread_fn+0x24/0x3c)
[  291.140584]  r8:c1a66000 r7:c0056db0 r6:c075218c r5:c33f75c0 r4:c33f75c0
[  291.146054] [<c0056db0>] (irq_thread_fn) from [<c00570a8>] (irq_thread+0x158/0x1f0)
[  291.152477]  r7:c0056db0 r6:ffffe000 r5:c33f75c0 r4:c075218c
[  291.156903] [<c0056f50>] (irq_thread) from [<c00382ec>] (kthread+0x138/0x154)
[  291.162813]  r10:c0f78bb8 r9:c389fbe4 r8:c0056f50 r7:c33f75c0 r6:c1a66000 r5:c0f1c1e0
[  291.169393]  r4:c0f78b80
[  291.170674] [<c00381b4>] (kthread) from [<c000a570>] (ret_from_fork+0x14/0x24)
[  291.176664]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c00381b4
[  291.183243]  r4:c0f1c1e0

[dlech]

Fix has been released in kernel ev3dev-2.2.2.