Unhandled exception in interrupt handler

[daniel]

I have been trying to reproduce the issue with the latest firmware without success. @paulS can you provide another example that shows the issue?

[danielm]

@daniel
Did you generate enough pulses to increment all three counters? As you can see, in my experiments 22-24k pulses were needed in total to encounter those issues.

[robert-hh]

@danielm Maybe the problem is somewhere else. The LoPy (and WiPy) use a soft interrupt handler. That means this handler can be interrupted by another event. This event can come from the same source, when the signal, which you count has a slow slope, and slow means rise/fall time >2-3 µs. I had seen this phenomenon without following it in my tests of irq latency, where I had unexpected responses first when using a 'slow' source. Now I made a test, and triggered the lopy with triangle pulses. The code is simple. The ISR just responds with a pulse when triggered. If the slope is slow, is see several pulses.
Pulse width 3.3 µs, rise/fall time 1.65 µs: Single pulse

Pulse width 10 µs, rise/fall time 5 µs: Two pulses

Pulse width 400µs, rise/fall time 200 µs: Four pulses

Maybe that's a reason for the effect here. I recall an observation, that interrupt handler may be called recursively, if the next event happens, before handling of the first has finished. And with your three timers that may stack up even more, if by chance the event coincide. In another application I used therefore a flag to avoid recursive calls.
And yes, here is my test code:

from machine import Pin, idle

resp_pin = Pin("G11", mode=Pin.OUT)
resp_pin(1)
def resp(p, pout = resp_pin):
    pout(0)
    pout(1)

irq_pin = Pin("G7", mode=Pin.IN, pull=Pin.PULL_UP)
irq_pin.callback(trigger = Pin.IRQ_FALLING, handler = resp, arg=None)

try:
    while True:
        idle()
except:
    pass

irq_pin.callback(handler = None)

[robert-hh]

@danielm said in Unhandled exception in interrupt handler:

def counter3irq(self, obj):
self.temporary2 = self.counter3
self.counter3 = self.temporary2 + 1

Not that I think it's the reason, but should'nt that piece of code be:

	def counter3irq(self, obj):
		self.temporary3 = self.counter3
		self.counter3 = self.temporary3 + 1

[danielm]

@robert-hh
Yes, of course it should. I was just too quick with copy-paste :)
Thank you for your previous reply as well. I am not sure how fast are my opto-isolators. I will check with oscilloscope in the beginning of next week.

[daniel]

@robert-hh thanks. I'll investigate around your findings today.

[robert-hh]

@daniel I could not find evidence that the simple IRS I used is called recursively. To catch that event, I had set up a global flag, which is set and clear upon entry, and i set upon entry, would increase a global counter, like this:

resp_pin = Pin("G11", mode=Pin.OUT)
resp_pin(1)
flag = False
counter = 0
def resp(p, pout = resp_pin):
    global flag, counter
    if flag:
        counter += 1
    else:
        flag = True
        pout(0)
        pout(1)
        flag = False

That counter stayed 0, even if I extended the time between the two pout() calls.
Hy hypothesis is, that the input stage of the esp32 has not Schmitt-Trigger characteristics, and noise in a slow transition causes the input stage to toggle fast. At a slope time of 1ms for instance, I had the ISR called 12 times in a row.

[danielm]

@robert-hh
If your hypothesis is right and there are no recursively called ISRs could it somehow cause memory issues anyway?
Btw, my opto-isolators are quite slow, as one could expect from opto-isolators... Rise time is around 23us.

[robert-hh]

@danielm I'm not saying, that this does not happen, only my test did not reveal it. What is even more likely, that with your three ISR functions you have the chance of stacked calls. Daniel wanted to look into it. I have just one signal generator, but I could set up another micro to generate pulses.

But in any case you have to deal with multiple calls form that single source. Didn't you see increments of your counter faster than excepted? In order to shape the signal, you could add a Schmitt-Trigger gate, like the 74HC14. You could also try the falling edge of your opto-isolator, which should be faster.

[robert-hh]

@robert-hh I managed to make the test with at least two signals (the signal generator has two channels!). SO I could test all variants of slow vs. fast pulses, pulses at the same time and pulses properly apart. I've set the pulse frequency to 100Hz. Setting the delays I could fine shift the two pulses in relation to each other, so that they happened either at the same time or with some µs distance. And I modified my test code to register two signals and to detect, when the ISR for one signal is interrupted by the one for the other signal. That never happened, the code never crashed. Only when I pushed Ctrl-C to end the test, I got sometimes a core dump, and the probability of that seems to depend on the chance, that the test program is interrupted in a critical state, so the increasing probability was.

• single source fast pulse (lowest)
• single source slow pulse or double source fast pulse
• double source slow pulse (highest)

Test code:

from machine import Pin, idle

resp_pin1 = Pin("G11", mode=Pin.OUT)
resp_pin1(1)

resp_pin2 = Pin("G13", mode=Pin.OUT)
resp_pin2(1)

flag1 = False
flag2 = False
count1 = 0
count2 = 0

def resp1(p, pout = resp_pin1):
    global flag2, flag1, count1
    flag1 = True
    if flag2:
        count1 += 1
    pout(0)
    pout(1)
    flag1 = False

def resp2(p, pout = resp_pin2):
    global flag2, flag1, count2
    flag2 = True
    if flag1:
        count2 += 1
    pout(0)
    pout(1)
    flag2 = False

def run(flag = True):
    irq_pin1 = Pin("G7", mode=Pin.IN, pull=Pin.PULL_UP)
    irq_pin2 = Pin("G9", mode=Pin.IN, pull=Pin.PULL_UP)
    irq_pin1.callback(trigger = Pin.IRQ_RISING, handler = resp1, arg=None)
    if flag:
        irq_pin2.callback(trigger = Pin.IRQ_RISING, handler = resp2, arg=None)
    try:
        while True:
            idle()
    except:
        print("%5d %5d" % (count1, count2))
        irq_pin1.callback(handler = None)
        irq_pin2.callback(handler = None)

[livius]

@robert-hh
can you show how that signals looks like
maybe characteristic of raising and falling edge matters (how fast raise and how fast falling
)
or maybe @danielm have some noise in real signal?

[robert-hh]

@livius If you scroll down and read in this post, you'll see the answers to your questions, and also has @daniel already expressed interest in this topic. For the last test I used the rise time seen bye @danielm.
Using the pulse mode of my signal generator with transition times of about 7 ns the multiple interupts do not occur. B.T.W.: I had a similar effect on the ESP8266 with slow pulses. Very nasty!

[daniel]

@robert-hh thanks for the super detailed analysis! Can you share how did you solve this issue on the ESP8266?

[robert-hh]

@danielm @livius Until now I was testing with a symmetric triangle pulse of 50 µs duration. I switched now to a exp-rise pulse, with a rise time of ~25 µs. Funny enough, the double pulse disappeared, until I changed to trigger on the falling edge. I had made the same observation with other asymmetric pulses. The red trace is the input pulse for the green response. I cannot extend the pulse independently form the rise time without creating my own pulse shapes, which somehow fails with the vendors software (Windows only, with missing NI libs).

[robert-hh]

@daniel Actually it were two different cases:
a) Timer interrupt. If the handler took longer than about 500 µs, the handler seemed to be raised a second time. Solved by a flag in the handler, which checked whether it was already busy.
b) External interrupt, which was called twice in a row. Solved by using a different drive with faster slopes..

[daniel]

@robert-hh thanks. Could the solution here be to disable GPIO interrupts while the C handler is executing (this is fast)?

[livius]

@daniel
Then we can miss interrupt on different pin?
Or you mean interrupt on exact pin?

[daniel]

@livius I mean to disable the interrupt on that same pin.

[livius]

@daniel
it looks like good concept - not overlapped events

[danielm]

I just want to remind that this issue remains unsolved on 1.6.13.b1

Counter 1: 10009 Counter 2: 6449 Counter 3: 12757
Counter 1: 10024 Counter 2: 6459 Counter 3: 12778
Counter 1: 10040 Counter 2: 6470 Counter 3: 12798
Counter 1: 10055 Counter 2: 6480 Counter 3: 12818
Counter 1: 10070 Counter 2: 6490 Counter 3: 12838
Counter 1: 10086 Counter 2: 6501 Counter 3: 12858
Counter 1: 10101 Counter 2: 6511 Counter 3: 12878
Counter 1: 10116 Counter 2: 6521 Counter 3: 12899
Counter 1: 10132 Counter 2: 6531 Counter 3: 12919
Counter 1: 10147 Counter 2: 6541 Counter 3: 12939
Guru Meditation Error of type InstrFetchProhibited occurred on core  0. Exception was unhandled.
Register dump:
PC      : 0xffffffff  PS      : 0x00060a30  A0      : 0x800eb2f0  A1      : 0x3ffe1f50
A2      : 0x3ffe28d0  A3      : 0x00000001  A4      : 0x00000000  A5      : 0x3ffe1f70
A6      : 0x00050823  A7      : 0x00000000  A8      : 0x800eb2ac  A9      : 0x3ffe1f30
A10     : 0x3ffe28d0  A11     : 0x00000001  A12     : 0x00000000  A13     : 0x3ffe1f70
A14     : 0x00000003  A15     : 0x00060823  SAR     : 0x00000012  EXCCAUSE: 0x00000014
EXCVADDR: 0xfffffffc  LBEG    : 0x400f753a  LEND    : 0x400f7543  LCOUNT  : 0x00000000

Backtrace: 0x7fffffff:0x3ffe1f50 0x400eb2f0:0x3ffe1f70 0x400dccb8:0x3ffe1fa0 0x400e1672:0x3ffe1fc0 0x400d8244:0x3ffe2050

================= CORE DUMP START =================

...