QUERY · ISSUE

wiznet5k driver can call scheduler from hard IRQ context

openby tpwrulesopened 2025-08-09updated 2025-08-10

bug

Port, board and/or hardware

W5500-EVB-Pico

MicroPython version

MicroPython v1.25.0 on 2025-04-15; W5500-EVB-Pico with RP2040 (official downloaded .uf2)

Reproduction

Put code below into a file
Disconnect Ethernet from board and hard reset it and ensure it doesn't have any files that run on boot
Run the code with mpremote run

import network
from machine import Timer
import micropython
micropython.alloc_emergency_exception_buf(100)

print("starting...")
l = [[] for _ in range(5000)] # make GC take longer

nic = network.WIZNET5K()
nic.active(True)

def timer_cb(x):
    data = bytearray(1024) # stress GC from scheduler
timer = Timer(freq=100, callback=timer_cb) # soft IRQ only on rp2

print("running...")
while True:
    data = bytearray(1024) # stress GC from main loop

Expected behaviour

The code runs indefinitely.

Observed behaviour

After several seconds, the following exception appears:

Traceback (most recent call last):
  File "<stdin>", line 13, in timer_cb
MemoryError: memory allocation failed, heap is locked

Sometimes conditions are wrong and it will not appear and a fresh reset is needed.

Additional Information

Also reproduces on 1.26.0.

It appears that the WIZNET5K Ethernet driver will call the MicroPython scheduler through here if blocking sends or receives are performed, but those can occur from PendSV timer callbacks, which can run while the GC is locked. Not sure of an appropriate resolution.

Backtrace from SWD (issue reproduces on a standard build but the custom build is what I have symbols for):
<details>

Breakpoint 1, m_malloc_fail (num_bytes=num_bytes@entry=16) at /build/source/py/runtime.c:1656
1656	        mp_raise_msg(&mp_type_MemoryError, MP_ERROR_TEXT("memory allocation failed, heap is locked"));
(gdb) bt
#0  m_malloc_fail (num_bytes=num_bytes@entry=16) at /build/source/py/runtime.c:1656
#1  0x1000e3cc in m_malloc (num_bytes=16) at /build/source/py/malloc.c:88
#2  m_malloc (num_bytes=num_bytes@entry=16) at /build/source/py/malloc.c:85
#3  0x10013240 in array_new (typecode=typecode@entry=1 '\001', n=n@entry=1024) at /build/source/py/objarray.c:99
#4  0x10013790 in bytearray_make_new (type_in=<optimized out>, n_args=1, n_kw=<optimized out>, args=<optimized out>) at /build/source/py/objarray.c:191
#5  0x1001b2fc in type_call (self_in=<optimized out>, n_args=<optimized out>, n_kw=<optimized out>, args=<optimized out>) at /build/source/py/objtype.c:1017
#6  0x1001ded4 in mp_call_function_n_kw (fun_in=0x10070c9c <mp_type_bytearray>, n_args=1, n_kw=0, args=args@entry=0x20041ac8) at /build/source/py/runtime.c:726
#7  0x10020120 in mp_execute_bytecode (code_state=code_state@entry=0x20041ab0, inject_exc=inject_exc@entry=0x0) at /build/source/py/vm.c:957
#8  0x10015784 in fun_bc_call (self_in=0x2000c2a0, n_args=1, n_kw=0, args=0x20041b2c) at /build/source/py/objfun.c:295
#9  0x1001ded4 in mp_call_function_n_kw (fun_in=0x2000c2a0, n_args=1, n_kw=0, args=0x20041b2c) at /build/source/py/runtime.c:726
#10 0x1001df6a in mp_call_function_1 (fun=fun@entry=0x2000c2a0, arg=<optimized out>, arg@entry=0x2003c190) at /build/source/py/runtime.c:704
#11 0x1001ed6e in mp_call_function_1_protected (fun=fun@entry=0x2000c2a0, arg=arg@entry=0x2003c190) at /build/source/py/runtime_utils.c:33
#12 0x1001ef5a in mp_sched_run_pending () at /build/source/py/scheduler.c:111
#13 mp_handle_pending (raise_exc=raise_exc@entry=true) at /build/source/py/scheduler.c:246
#14 0x1002b314 in mpy_wiznet_yield () at /build/source/extmod/network_wiznet5k.c:146
#15 0x100351fe in wizchip_sendto (sn=sn@entry=0 '\000', buf=buf@entry=0x20003425 <wiznet5k_obj+29> "\377\377\377\377\377\377\002\300\v\214c\232\b", len=len@entry=350, 
    addr=addr@entry=0x20041bcc "\001\001\001\001\b4", port=port@entry=11) at /build/source/lib/wiznet5k/Ethernet/socket.c:619
#16 0x1002ae18 in wiznet5k_send_ethernet (self=self@entry=0x20003408 <wiznet5k_obj>, len=350, buf=buf@entry=0x20003425 <wiznet5k_obj+29> "\377\377\377\377\377\377\002\300\v\214c\232\b")
    at /build/source/extmod/network_wiznet5k.c:255
#17 0x1002b044 in wiznet5k_netif_output (netif=<optimized out>, p=0x20008858 <ram_heap+345>) at /build/source/extmod/network_wiznet5k.c:292
#18 0x10048fd0 in ethernet_output (netif=netif@entry=0x20003a14 <wiznet5k_obj+1548>, p=p@entry=0x20008858 <ram_heap+345>, src=src@entry=0x20003afe <wiznet5k_obj+1782>, dst=0x1007e556 <ethbroadcast>, 
    eth_type=eth_type@entry=2048) at /build/source/lib/lwip/src/netif/ethernet.c:320
#19 0x1003dd2c in etharp_output (netif=0x20003a14 <wiznet5k_obj+1548>, q=0x20008858 <ram_heap+345>, ipaddr=0x1007e3bc <ip_addr_broadcast>) at /build/source/lib/lwip/src/core/ipv4/etharp.c:897
#20 0x1003e99a in ip4_output_if_opt_src (p=p@entry=0x20008858 <ram_heap+345>, src=src@entry=0x1007e3d4 <ip_addr_any>, dest=dest@entry=0x1007e3bc <ip_addr_broadcast>, ttl=255 '\377', 
    tos=tos@entry=0 '\000', proto=proto@entry=17 '\021', netif=netif@entry=0x20003a14 <wiznet5k_obj+1548>, ip_options=ip_options@entry=0x0, optlen=optlen@entry=0)
    at /build/source/lib/lwip/src/core/ipv4/ip4.c:1041
#21 0x1003ea20 in ip4_output_if_src (p=p@entry=0x20008858 <ram_heap+345>, src=src@entry=0x1007e3d4 <ip_addr_any>, dest=dest@entry=0x1007e3bc <ip_addr_broadcast>, ttl=<optimized out>, tos=0 '\000', 
    proto=proto@entry=17 '\021', netif=netif@entry=0x20003a14 <wiznet5k_obj+1548>) at /build/source/lib/lwip/src/core/ipv4/ip4.c:866
#22 0x10048af6 in udp_sendto_if_src (pcb=0x20008638 <memp_memory_UDP_PCB_base+243>, p=p@entry=0x20008858 <ram_heap+345>, dst_ip=0x1007e3bc <ip_addr_broadcast>, dst_port=dst_port@entry=67, 
    netif=netif@entry=0x20003a14 <wiznet5k_obj+1548>, src_ip=0x1007e3d4 <ip_addr_any>) at /build/source/lib/lwip/src/core/udp.c:893
#23 0x1003ccc0 in dhcp_discover (netif=0x20003a14 <wiznet5k_obj+1548>) at /build/source/lib/lwip/src/core/ipv4/dhcp.c:1059
#24 0x1003d776 in dhcp_timeout (netif=0x20003a14 <wiznet5k_obj+1548>) at /build/source/lib/lwip/src/core/ipv4/dhcp.c:602
#25 dhcp_fine_tmr () at /build/source/lib/lwip/src/core/ipv4/dhcp.c:564
#26 0x100482f0 in lwip_cyclic_timer (arg=0x1007e518 <lwip_cyclic_timers+32>) at /build/source/lib/lwip/src/core/timeouts.c:241
#27 0x10048440 in sys_check_timeouts () at /build/source/lib/lwip/src/core/timeouts.c:390
#28 0x100370bc in mp_network_soft_timer_callback (self=<optimized out>) at /build/source/ports/rp2/mpnetworkport.c:135
#29 0x10033f3c in soft_timer_handler () at /build/source/shared/runtime/softtimer.c:93
#30 0x1003736a in PendSV_Handler () at /build/source/ports/rp2/pendsv.c:177
#31 <signal handler called>
#32 0x1000d2aa in gc_deal_with_stack_overflow () at /build/source/py/gc.c:558
#33 gc_collect_end () at /build/source/py/gc.c:536
#34 0x10036dba in gc_collect () at /build/source/ports/rp2/main.c:288
#35 0x1000d50c in gc_alloc (n_bytes=n_bytes@entry=1024, alloc_flags=alloc_flags@entry=0) at /build/source/py/gc.c:840
#36 0x1000e3be in m_malloc (num_bytes=num_bytes@entry=1024) at /build/source/py/malloc.c:86
#37 0x1001325e in array_new (typecode=typecode@entry=1 '\001', n=n@entry=1024) at /build/source/py/objarray.c:110
#38 0x10013790 in bytearray_make_new (type_in=<optimized out>, n_args=1, n_kw=<optimized out>, args=<optimized out>) at /build/source/py/objarray.c:191
#39 0x1001b2fc in type_call (self_in=<optimized out>, n_args=<optimized out>, n_kw=<optimized out>, args=<optimized out>) at /build/source/py/objtype.c:1017
#40 0x1001ded4 in mp_call_function_n_kw (fun_in=0x10070c9c <mp_type_bytearray>, n_args=1, n_kw=0, args=args@entry=0x20041ec0) at /build/source/py/runtime.c:726
#41 0x10020120 in mp_execute_bytecode (code_state=code_state@entry=0x20041ea8, inject_exc=inject_exc@entry=0x0) at /build/source/py/vm.c:957
#42 0x10015784 in fun_bc_call (self_in=0x2000ccd0, n_args=0, n_kw=0, args=0x0) at /build/source/py/objfun.c:295
#43 0x1001ded4 in mp_call_function_n_kw (fun_in=0x2000ccd0, n_args=0, n_kw=0, args=0x0) at /build/source/py/runtime.c:726
#44 0x1001deec in mp_call_function_0 (fun=fun@entry=0x2000ccd0) at /build/source/py/runtime.c:700
#45 0x10033aa2 in parse_compile_execute (source=source@entry=0x20041f94, input_kind=input_kind@entry=MP_PARSE_FILE_INPUT, exec_flags=exec_flags@entry=65) at /build/source/shared/runtime/pyexec.c:119
#46 0x10033c02 in do_reader_stdin (c=65) at /build/source/shared/runtime/pyexec.c:276
#47 pyexec_raw_repl () at /build/source/shared/runtime/pyexec.c:509
#48 0x10036d58 in main (argc=<optimized out>, argv=<optimized out>) at /build/source/ports/rp2/main.c:232

</details>

Code of Conduct

Yes, I agree

CANDIDATE · PULL REQUEST

Allow real memory errors (from locked gc) to be reported with traceback.

mergedby dhylandsopened 2014-10-07updated 2015-11-08

This is related to: http://forum.micropython.org/viewtopic.php?f=3&t=328

I was able to reproduce the problem in the unix microptyhon with the following code:

import gc

class Foo(object):
    def __init__(self):
        pass

    def bar(self):
        pass

x = Foo()

def Func():
    print("Func called")
    x.bar
    print("After x")

gc.disable()
Func()
gc.enable()

If I run under unix micropython then I get the following reported:

>>> import x
Func called
MemoryError:

with no traceback information.

I've tracked down the memory allocation failure to this line:
https://github.com/micropython/micropython/blob/master/py/runtime.c#L813

It should fail here since we're trying to do a memory allocation while the heap is locked. But the issue is, why is there no traceback?

The issue is that the code for using the special exception buffer exists in the mp_obj_new_exception_msg_varg function, and m_malloc_fail calls:

nlr_raise((mp_obj_t)&mp_const_MemoryError_obj);

If I change m_malloc_fail to use:

    nlr_raise(mp_obj_new_exception_msg_varg(&mp_type_MemoryError,
                                            "memory allocation failed, allocating " UINT_FMT " bytes", num_bytes));

instead, and increase the size of the exception buffer to 256 bytes, then I now get this failure:

Func called
Traceback (most recent call last):
  File "x.py", line 18, in <module>
  File "x.py", line 14, in Func
MemoryError: memory allocation failed, allocating 24 bytes

With this patch, the original pyboard code:

import pyb
import micropython
micropython.alloc_emergency_exception_buf(200)

sw = pyb.Switch()

def BTN_callback():
    pyb.LED(1).toggle

sw.callback(BTN_callback)

Now produces this error:

>>> import switch
>>> Uncaught exception in ExtInt interrupt handler line 3
Traceback (most recent call last):
  File "switch.py", line 8, in BTN_callback
MemoryError: memory allocation failed, allocating 12 bytes