Crash on soft reset on CLUE

[jepler]

CircuitPython version

Adafruit CircuitPython 7.0.0-alpha.3-437-g394087869 on 2021-07-19; Adafruit CLUE nRF52840 Express with nRF52840

Code/REPL

print("hello")

Behavior

Auto-reload is on. Simply save files over USB to run them or enter REPL to disable.
code.py output:
hello

[tio 10:31:37] Disconnected
[tio 10:31:41] Connected
Auto-reload is off.
Running in safe mode! Not running saved code.

You are in safe mode because:
CircuitPython core code crashed hard. Whoops!
Attempted heap allocation when VM not running.
Please file an issue with the contents of your CIRCUITPY drive at 
https://github.com/adafruit/circuitpython/issues

Press any key to enter the REPL. Use CTRL-D to reload.

Description

Load the above code.py. Open the REPL. Hit ctrl-d repeatedly. After a few iterations (almost always fewer than 10) the board will hard-fault.

Additional information

I determined that the problem seems to have been introduced when #4957 was merged.

[jepler]

@DavePutz noticed:

Re-tested this on 7.0.0-alpha.4 and got a different stack:

#0  reset_into_safe_mode (reason=reason@entry=GC_ALLOC_OUTSIDE_VM) at ../../supervisor/shared/safe_mode.c:123
#1  0x000287ce in gc_alloc (n_bytes=n_bytes@entry=16, alloc_flags=alloc_flags@entry=0, long_lived=<optimized out>)
    at ../../py/gc.c:508
#2  0x00027dc8 in m_malloc_maybe (num_bytes=num_bytes@entry=16, long_lived=long_lived@entry=false)
    at ../../py/malloc.c:103
#3  0x00037636 in mp_obj_new_exception_msg_vlist (exc_type=0x98458 <mp_type_ValueError>, fmt=0xa20bc <v>,
    fmt@entry=0x0, ap=..., ap@entry=...) at ../../py/objexcept.c:425
#4  0x00037726 in mp_obj_new_exception_msg_varg (exc_type=<optimized out>, fmt=0xa20bc <v>)
    at ../../py/objexcept.c:413
#5  0x00037736 in mp_obj_new_exception_msg (exc_type=<optimized out>, msg=<optimized out>) at ../../py/objexcept.c:372
#6  0x00032c76 in mp_raise_msg (exc_type=<optimized out>, msg=<optimized out>) at ../../py/runtime.c:1601
#7  0x00032dce in mp_raise_ValueError (msg=<optimized out>) at ../../py/runtime.c:1649
#8  0x0005947a in check_nrf_error (err_code=7) at common-hal/_bleio/__init__.c:56
#9  0x00059288 in common_hal_bleio_service_add_characteristic (self=0x20012254 <supervisor_ble_serial_service>,
    characteristic=characteristic@entry=0x20012224 <supervisor_ble_rx_characteristic>,
    initial_value_bufinfo=initial_value_bufinfo@entry=0x0,
    user_description=user_description@entry=0xa3190 "CircuitPython Serial") at common-hal/_bleio/Service.c:176
#10 0x00057798 in common_hal_bleio_characteristic_construct (
    self=self@entry=0x20012224 <supervisor_ble_rx_characteristic>,
    service=service@entry=0x20012254 <supervisor_ble_serial_service>, handle=handle@entry=0,
    uuid=uuid@entry=0x2001224c <supervisor_ble_rx_uuid>, props=props@entry=48 '0',
    read_perm=read_perm@entry=SECURITY_MODE_NO_ACCESS, write_perm=write_perm@entry=SECURITY_MODE_ENC_NO_MITM,
    max_length=max_length@entry=512, fixed_length=fixed_length@entry=false,
    initial_value_bufinfo=initial_value_bufinfo@entry=0x0,
    user_description=user_description@entry=0xa3190 "CircuitPython Serial") at common-hal/_bleio/Characteristic.c:129
#11 0x0004bb28 in supervisor_start_bluetooth_serial () at ../../supervisor/shared/bluetooth/serial.c:83
#12 0x0004b1d2 in supervisor_start_bluetooth () at ../../supervisor/shared/bluetooth/bluetooth.c:233
#13 0x00045698 in main () at ../../main.c:811

[tannewt]

This is the bug I got frustrated chasing. The err_code 7 is invalid parameter from the softdevice but when I break on the add_characteristic call the parameters look ok. I thought this might have been an initialization issue of what we're passing in but I'm not certain it is.

I've seen it happen sporadically on start up as well.

[tannewt]

Does this still happen with the latest main?

[DavePutz]

I Just re-tested with the current main (commit e9369d5) built with DEBUG=1. I had to reset a couple of times, but my Feather nRF52840 Express did mount as CIRCUITPY and get into the REPL. However; it was in safe mode with the following message: CircuitPython core code crashed hard. Whoops! Attempted heap allocation when VM not running. A subsequent reset then brought the board into normal operation. I will do some more testing to see if more info can be gathered.

…

On Wed, Jul 28, 2021 at 7:19 PM Scott Shawcroft ***@***.***> wrote: Does this still happen with the latest main? — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#5018 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AFNJKEQOVWRTE6RSFSVEMF3T2CNB3ANCNFSM5AT6LA5A> .

[tannewt]

I can't reproduce this. Jeff, do you want to try it again?

[ThomasAtBBTF]

I checked this again on my ItysBitsy nRF52840 after installing:
Adafruit CircuitPython 7.0.0-alpha.5-105-gf0e489f51 on 2021-08-05; Adafruit ItsyBitsy nRF52840 Express with nRF52840
and I can not reproduce the problem anymore.

But note: I am calling now supervisor.disable_ble_workflow() in boot.py