disable_irq not effective

[jmi2]

Hello,

i'm new to python and micropython, playing with interrupts and have found surprissing situations.

I used following code, while quickly connecting/disconnecting that PIN to GND and got changesCountLocked > 0, which is suprising to me.
I suspect it could be some "code optimization" by reordering instructions or simillar, but cannot find anything like this in documentation of micropython.


Situation 1:
[code]
paste mode; Ctrl-C to cancel, Ctrl-D to finish
=== import micropython, machine, time, utime
=== from machine import Pin
===
=== micropython.alloc_emergency_exception_buf(100)
===
=== machine.WDT().deinit()
===
=== p14 = Pin(14, Pin.IN, Pin.PULL_UP)
===
=== changesCountUnlocked = 0
=== changesCountLocked = 0
=== locked = False
===
===
=== def callback(t):
=== global changesCountUnlocked
=== global changesCountLocked
=== global locked
===
=== if locked:
=== changesCountLocked = changesCountLocked + 1
=== else:
=== changesCountUnlocked = changesCountUnlocked + 1
===
===
=== p14.irq(trigger=Pin.IRQ_RISING | Pin.IRQ_FALLING, handler=callback)
===
=== for loop in range(50):
=== irq_state = machine.disable_irq() # Start of critical section
=== locked = True
===
=== # utime.sleep_ms(10)
=== a = 1;
=== for loop in range(100):
=== a = a + a;
===
=== locked = False
=== machine.enable_irq(irq_state) # End of critical section
=== time.sleep_ms(10)
===
===
=== print ('changes locked:', changesCountLocked)
=== print ('changes unlocked:', changesCountUnlocked)
<IRQ>
changes locked: 2
changes unlocked: 19
[/code]

thanks for help.
jmi

[pythoncoder]

I dont' know what platform you're using. I tested on a Pyboard with minimal modifications to enable it to run. I used a second timer and a wire link to toggle the pin at high speed. In this test disable_irq was 100% effective.

So the problem sounds as if it's platform-specific. So please describe your hardware and whether you're running official MicroPython or one of the other ports.

[jmi2]

Thanks, you are right, platform is imporant in this case.

MicroPython v1.9.4-272-g46091b8a on 2018-07-18; ESP module with ESP8266

(Wanted to edit post, but it disappered due to need for approval by moderator after submit and later also after first edit.)

[pythoncoder]

I can't replicate this on the reference board (Adafruit Feather Huzzah). I extended the test time to 5 seconds (loop count 500) and also tried repeatedly pinging the board while running the test. changesCountLocked was invariably 0.

[Roberthh]

I do not fully recall how it is implemented on the ESP8266, but as far as I recall, registering an event and calling the handler are two separate actions. When an IRQ occurs, a handler request is scheduled, and the handler is executed at a later time.
In that scenario, at the time of the IRQ 'locked' may have the value False, but when the handler actually runs, 'locked' has the value True.
Touching the wire manually to GND will, due to bouncing, produce many event asynchronous to the code, while using a timer to create test pulses makes synchronous pulses.

By using the test code with a loop count of 500 and attaching an external pulse generator at 1 kHz to create pulses, I get:

changes locked: 45
changes unlocked: 10560

b.t.w.: The statement "machine.WDT().deinit()" causes the WDT to start with default values. I had to remove it

[jmi2]

I believe, when interrupt occurs, its handler is called immediately (unless higher prio interrupt runs and unless interrupts are disabled).

Worst case scenario i can imagine is, that event occurts just when disabling interrupts. But even here, i see only two outcomes:
1) main program is interrupted and handler is called -> counted to changesCountUnlocked as locked flag is not set yet.
2) interrupt is already disabled and handler waits for re-enabling.

But as we see also changesCountLocked i'm thinking of bug in my code (or in micropython impl for esp8266).
Could it be, that python interpreter reordered statements in my code and as consequence locked flag was true, even if IRQs were not yet disabled (or were already enabled)?

thank you

[pythoncoder]

... attaching an external pulse generator at 1 kHz to create pulses, I get:

changes locked: 45
changes unlocked: 10560

b.t.w.: The statement "machine.WDT().deinit()" causes the WDT to start with default values. I had to remove it

You're generating interrupts at 500μs intervals which might be pushing the latency limit with an ESP8266. The locked mechanism should still work if reentrancy occurs; but it might be worth checking. I'd try repeating the test at 250Hz with a loop count of 2000.

btw I too removed the WDT code.

[Roberthh]

Actually i did not use a square wave, but a pulse of 10µs duration at a ferqency of 1 kHz. Changing that frequency affects the probability in which such a "error" condition occurs. A simple once-only series gives:

Code: Select all

Frequency Locked-count
2000        90
1000        42
 500        26
 250        12
 100         4

[Roberthh]

Adding a small sleep between urq_disable and setting of the "locked" flag brings the locked count to zero:

Code: Select all

    irq_state = machine.disable_irq() # Start of critical section
    time.sleep_us(50)
    locked = True

I faintly recall that call sleep allows other scheduled tasks to execute, at least for sleep_us larger than a certain limit.

[pythoncoder]

Actually i did not use a square wave, but a pulse of 10µs duration at a ferqency of 1 kHz....

The script triggers an interrupt on both edges. But I don't think this is the cause of the problem.

Evidently I used too few edges at too low a frequency to see a failure.

I think occasionally an interrupt occurs immediately before the disable_irq but the atrocious latency of the ESP8266 causes the ISR not to run until after after locked is set. Your delay ensures this can't happen.

This behaviour should either be fixed or documented.