Copyright © https://mongoose-os.com

Mongoose OS Forum

frame

Core 0 Panic'ed

So I'm seeing this:

set_spiffs_errno     read: res = 18, e = -10002
set_spiffs_errno   Guru Meditation Error: Core  0 panic'ed (Interrupt wdt timeout on CPU0)
Register dump:
PC      : 0x4011c9bf  PS      : 0x00060534  A0      : 0x80110eb7  A1      : 0x3ffcb7e0
A2      : 0x00694861  A3      : 0x3ffc5618  A4      : 0x3ff4908c  A5      : 0x00000000
A6      : 0x3ffc4bf0  A7      : 0x0000865f  A8      : 0x00694862  A9      : 0xcccccccd
A10     : 0xb8c2bfb4  A11     : 0x00000000  A12     : 0x3ff4908c  A13     : 0x00000017
A14     : 0x00000000  A15     : 0x0000003f  SAR     : 0x00000009  EXCCAUSE: 0x00000005
EXCVADDR: 0x00000000  LBEG    : 0x4000c349  LEND    : 0x4000c36b  LCOUNT  : 0x00000000

Backtrace: 0x4011c9bf:0x3ffcb7e0 0x40110eb7:0x3ffcb800 0x4010ca58:0x3ffcb820 0x4010caaa:0x3ffcb840 0x4010cd42:0x3ffcb860 0x4010705d:0x3ffcb880 0x40145e32:0x3ffcb8a0 0x40126256:0x3ffcb8c0 0x40126a28:0x3ffcb970 0x40130bec:0x3ffcb990 0x401292a8:0x3ffcba10 0x4013bbd4:0x3ffcba40 0x40135726:0x3ffcbb00 0x40135769:0x3ffcbb20 0x40115560:0x3ffcbb40 0x40116b77:0x3ffcbb60 0x40117639:0x3ffcbba0 0x401179f2:0x3ffcbc10 0x40114ca2:0x3ffcbc70 0x4010f887:0x3ffcbc90 0x40111111:0x3ffcbcb0

--- BEGIN CORE DUMP ---
{"arch": "ESP32", "cause": 5Guru Meditation Error: Core  0 panic'ed (Interrupt wdt timeout on CPU0)
Register dump:
PC      : 0x4011c9bf  PS      : 0x00060034  A0      : 0x80083d2a  A1      : 0x3ffcb440
A2      : 0x00000002  A3      : 0x3ffcb800  A4      : 0x8010ca58  A5      : 0x3ffcb800
A6      : 0x00000000  A7      : 0xb8dc594e  A8      : 0x00000000  A9      : 0x00000000
A10     : 0x00060027  A11     : 0x3ffbd1bc  A12     : 0x00040027  A13     : 0x3ffcb720
A14     : 0x3ffcb790  A15     : 0x00000000  SAR     : 0x0000001f  EXCCAUSE: 0x00000005
EXCVADDR: 0x00000000  LBEG    : 0x400d1918  LEND    : 0x400d191f  LCOUNT  : 0x00000000

Backtrace: 0x4011c9bf:0x3ffcb440 0x40083d2a:0x3ffcb460 0x400f45cb:0x3ffcb480 0x400855cd:0x3ffcb540 0x40085708:0x3ffcb5b0 0x40085415:0x3ffcb660 0x40085526:0x3ffcb6e0 0x40081318:0x3ffcb720

Two parts here, the first panic is in:

(gdb) disas 0x4011c9bf
Dump of assembler code for function gpio_set_direction:
   0x4011c9bc <+0>: entry   a1, 48
   0x4011c9bf <+3>: movi    a8, 39
   0x4011c9c2 <+6>: bltu    a8, a2, 0x4011c9d0 <gpio_set_direction+20>
   0x4011c9c5 <+9>: l32r    a8, 0x4010af3c
   0x4011c9c8 <+12>:    addx4   a8, a2, a8
   0x4011c9cb <+15>:    l32i    a8, a8, 0
   0x4011c9ce <+18>:    bnez.n  a8, 0x4011c9fa <gpio_set_direction+62>

Partial backtrace:

0x4011c9bf gpio_set_direction
0x40110eb7 mgos_usleep
0x4010ca58 mgos_i2c_half_delay
0x4010caaa mgos_i2c_send_byte
0x4010cd42 mgos_i2c_write
0x4010705d mgos_atca_hal_i2c_send
0x40145e32 atsend
0x40126256 atcab_challenge
0x40126a28 atcab_sign
0x40130bec eckey_atca_sign_wrap
0x401292a8 mbedtls_pk_sign
...
0x40117639 mg_mgr_handle_conn
...

The second part repeats 41 times before the whole thing goes off the rails. It's obviously just the debug code for core dumping, but interesting that it fails in the same place.

0x4011c9bf gpio_set_direction
0x40083d2a __getreent
0x400f45cb snprintf
0x400855cd emit_core_dump_section
0x40085708 esp_core_dump_to_uart
0x40085415 commonErrorHandler
0x40085526 ??
0x40081318 _xt_panic

I've kind of got a lot going on in this little app. A timer is running at a reasonably high frequency to send serial data to a NeoPixel chain ("rainbowing"), there are also RPC calls being made, TLS set up for MQTT/AWS and HTTPS using the ATECC508A (same slot for each, three ECDH slots allocated as well).

But I do wonder if I need to do more to protect shared resources, like the GPIO pins, from getting hit from multiple tasks. Or is this something that mgos should be taking care of?

Thanks!

«1

Comments

  • I'm also seeing this frequently:

    Guru Meditation Error: Core  0 panic'ed (Interrupt wdt timeout on CPU0)
    Register dump:
    PC      : 0x4010d5c0  PS      : 0x00060f34  A0      : 0x80111767  A1      : 0x3ffcb780
    A2      : 0x00696898  A3      : 0x00000001  A4      : 0x3ff4908c  A5      : 0x3ffcb970
    A6      : 0x00000068  A7      : 0x74756120  A8      : 0x000484ae  A9      : 0xcccccccd
    A10     : 0x0ff2f819  A11     : 0x00000000  A12     : 0x3ff4908c  A13     : 0x76c4835e
    A14     : 0x3f401638  A15     : 0x00000000  SAR     : 0x00000009  EXCCAUSE: 0x00000005
    EXCVADDR: 0x00000000  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0x00000000
    
    Backtrace: 0x4010d5c0:0x3ffcb780 0x40111767:0x3ffcb7a0 0x4010d308:0x3ffcb7c0 0x4010d4f8:0x3ffcb7e0 0x401070dc:0x3ffcb810 0x4010713b:0x3ffcb830 0x40146aea:0x3ffcb860 0x40126c4c:0x3ffcb880 0x40126e27:0x3ffcb8a0 0x401277b6:0x3ffcb950 0x40131a83:0x3ffcb970 0x40144e42:0x3ffcb9f0 0x40144f50:0x3ffcba20 0x4013c6fe:0x3ffcba50 0x401363c2:0x3ffcbb10 0x40136405:0x3ffcbb30 0x40115e74:0x3ffcbb50 0x4011748b:0x3ffcbb70 0x40117f4d:0x3ffcbbb0 0x40118306:0x3ffcbc20 0x401155b6:0x3ffcbc80 0x40110137:0x3ffcbca0 0x401119c1:0x3ffcbcc0
    

    in mgos_i2c_read, also during mbedtls connection arbitration, as it talks to the ATECC508A.

  • rojerrojer Dublin, Ireland

    hm. this is really strange. i will take a look next week.

  • Any insights on this?

  • rojerrojer Dublin, Ireland

    not yet, sorry. super busy with other stuff.

  • I got something similar updating MOS and pressing the Flash button too quickly on my development ESP32 board executing the example button_mqtt.js example file.

    It would first dump a lot of text like below:

    f2B
     3u56eV0HDAQMQ8by/ygGAARAICCRIkUAi0QbVQszVrP+S2ZLd4eWDx3wACgRcqZgYd/8gaT/enJdBwwEDEPG8v8AAAA2QQAhLu+CAgAioV4AiBEgKCAd8Acd/D/X3/7/
    l1+s/xQRQT8gEUE/LBFBPzZBAFH5/5Hn9IIFAMAgAJgJQEB0/Njlyf+tAiWo/yIFAPwCDIghDO

    If I interrupted the device and then plugged it back in. I would get this

    mgos_mqtt_ev         Subscribing to 'esp32_00C918/rpc'
    mgos_mqtt_ev         Subscribing to 'esp32_00C918/rpc/#'
    Guru Meditation Error of type IllegalInstruction occurred on core  0. Exception was unhandled.
    Register dump:
    PC      : 0x4011fcda  PS      : 0x00060b30  A0      : 0x80120c1c  A1      : 0x3ffcb760  
    A2      : 0x3ffd335c  A3      : 0x00000002  A4      : 0x000003ae  A5      : 0xfff80000  
    A6      : 0x3ffd338c  A7      : 0x00000000  A8      : 0x8011b8be  A9      : 0x3ffcb750  
    A10     : 0x3ffd5b3c  A11     : 0x00000007  A12     : 0x00000000  A13     : 0x3ffd36c0  
    A14     : 0x00000000  A15     : 0x3ffd3864  SAR     : 0x00000010  EXCCAUSE: 0x00000000  
    EXCVADDR: 0x00000000  LBEG    : 0x4000c349  LEND    : 0x4000c36b  LCOUNT  : 0xffffffff
  • rojerrojer Dublin, Ireland

    ok, thanks for the report. i have another reproducible crash. i will take a look tomorrow or early next week.

  • I found the cause for the issue above. If you use the button example given and hold the flash button, it causes my guru meditation error above. However just loading the load('api_rpc.js'); file seems to make this break on some normal + long clicks. Hope this helps.

  • rojerrojer Dublin, Ireland

    gents, this may or may not be related, but please try with https://github.com/cesanta/mongoose-os/commit/f9867df1c42565b83711eaa26e728ab9f63f1faa and let me know if the issue persists.

  • carlcarl US

    Sorry, still seeing the same thing

  • rojerrojer Dublin, Ireland

    yeah, there's something rotten there. however, i don't have anything reproducible that i could work with. still monitoring our CI.

  • carlcarl US
    edited May 3

    So just because I'm lazy and don't want to look for it, is there a semaphore or something that guards access to the i2c bus and/or each atca chip? I assume that we would need both, actually.

  • rojerrojer Dublin, Ireland

    mos does not do locking in most of its apis, because it currently assumes event-driven approach - i.e. all work performed on the "main task". locking is only performed where it's known to interface with other tasks, such as invocations from betwork callbacks etc.
    if you follow the model - keep everything in timer or gpio int callbacks and thus on the main task - you don't need extra locking. otherwise, you need to introduce your own serialization.

  • carlcarl US

    I'm not sure if this is related, but I'm also seeing a lot of ATCA_RX_TIMEOUT errors, trying to do RPC over HTTPS. This is while little else is going on, other than the normal AWS shadow pings.

    That error is actually a PHY issue. Not sure exactly what might cause that tho.

  • carlcarl US

    In looking at some recent crashes, there does seem to a fair number of overlapping requests being handled, but they are mostly ok, until they aren't. I also figured out an easier way to get stack traces, thankfully:

    % xtensa-esp32-elf-addr2line -a -f -p -e build/objs/fw.elf 0x4010821d:0x3ffcb870 0x40119357:0x3ffcb890 0x40114bf8:0x3ffcb8b0 0x40114e11:0x3ffcb8d0 0x4010ffb0:0x3ffcb900 0x4014f1c2:0x3ffcb920 0x4012fb80:0x3ffcb940 0x4012fbe0:0x3ffcb9f0 0x40139c78:0x3ffcba10 0x40132344:0x3ffcba90 0x40144c98:0x3ffcbac0 0x4013e7c6:0x3ffcbb80 0x4013e809:0x3ffcbba0 0x4011dba4:0x3ffcbbc0 0x4011f59f:0x3ffcbbe0 0x40120074:0x3ffcbc20 0x40120432:0x3ffcbc90 0x4011d2de:0x3ffcbcf0 0x40117baf:0x3ffcbd10 0x4011957d:0x3ffcbd30
    0x4010821d: get_time_since_boot at /opt/Espressif/esp-idf/components/newlib/./time.c:157
    0x40119357: mgos_usleep at /mongoose-os/fw/platforms/esp32/src/esp32_hal.c:77
    0x40114bf8: mgos_i2c_half_delay at /mongoose-os/fw/src/mgos_i2c_gpio.c:49
    0x40114e11: mgos_i2c_read_byte at /mongoose-os/fw/src/mgos_i2c_gpio.c:169
    0x4010ffb0: mgos_atca_hal_i2c_receive at /mongoose-os/fw/src/mgos_atca.c:85
    0x4014f1c2: atreceive at /mongoose-os/third_party/cryptoauthlib/lib/atca_iface.c:141
    0x4012fb80: atcab_sign_base at /mongoose-os/third_party/cryptoauthlib/lib/basic/atca_basic.c:1856
    0x4012fbe0: atcab_sign at /mongoose-os/third_party/cryptoauthlib/lib/basic/atca_basic.c:1856
    0x40139c78: eckey_atca_sign_wrap at /opt/cs_mbedtls/library/ecp_atca.c:78
    0x40132344: mbedtls_pk_sign at /opt/cs_mbedtls/library/pk.c:324
    0x40144c98: ssl_write_server_key_exchange at /opt/cs_mbedtls/library/ssl_srv.c:3128
    0x4013e7c6: mbedtls_ssl_handshake_step at /opt/cs_mbedtls/library/ssl_tls.c:6193
    0x4013e809: mbedtls_ssl_handshake at /opt/cs_mbedtls/library/ssl_tls.c:6193
    0x4011dba4: mg_ssl_if_handshake at /mongoose-os/mongoose/mongoose.c:2944
    0x4011f59f: mg_ssl_begin at /mongoose-os/mongoose/mongoose.c:2944
    0x40120074: mg_handle_tcp_read at /mongoose-os/mongoose/mongoose.c:2944
    0x40120432: mg_socket_if_poll at /mongoose-os/mongoose/mongoose.c:2944
    0x4011d2de: mg_mgr_poll at /mongoose-os/mongoose/mongoose.c:2944
    0x40117baf: mongoose_poll at /mongoose-os/fw/src/mgos_mongoose.c:229
    0x4011957d: mgos_task at /mongoose-os/fw/platforms/esp32/src/esp32_main.c:160
    
    mgos_http_ev         0x3ffd484c HTTP connection from 192.168.1.151:50182
    ssl_socket_send      0x3ffb461c 465 -> 465
    ssl_socket_send      0x3ffb461c 31 -> 31
    ssl_socket_recv      0x3ffd4dc0 5 <- 5
    ssl_socket_recv      0x3ffd4dc0 206 <- 206
    ssl_socket_send      0x3ffd4dc0 96 -> 96
    ssl_socket_send      0x3ffd4dc0 666 -> 666
    ATCA:7 ECDH get pubkey ok
    ATCA:4 ECDSA sign ok
    ssl_socket_send      0x3ffd4dc0 152 -> 152
    ssl_socket_send      0x3ffd4dc0 9 -> 9
    ssl_socket_recv      0x3ffd4dc0 5 <- 5
    ssl_socket_recv      0x3ffd4dc0 70 <- 70
    ATCA:7 ECDH ok
    ssl_socket_recv      0x3ffd4dc0 5 <- 5
    ssl_socket_recv      0x3ffd4dc0 1 <- 1
    ssl_socket_recv      0x3ffd4dc0 5 <- 5
    ssl_socket_recv      0x3ffd4dc0 40 <- 40
    ssl_socket_send      0x3ffd4dc0 6 -> 6
    ssl_socket_send      0x3ffd4dc0 45 -> 45
    mgos_http_ev         0x3ffd4dc0 HTTP connection from 192.168.1.151:50184
    ssl_socket_recv      0x3ffb49a4 5 <- 5
    ssl_socket_recv      0x3ffb49a4 424 <- 424
    mg_http_is_authorize /state  1 1
    ssl_socket_recv      0x3ffb49a4 5 <- -1
    ssl_socket_recv      0x3ffd484c 5 <- 5
    ssl_socket_recv      0x3ffd484c 424 <- 424
    mg_http_is_authorize /state  1 1
    ssl_socket_recv      0x3ffd484c 5 <- -1
    ssl_socket_recv      0x3ffd4338 5 <- 5
    ssl_socket_recv      0x3ffd4338 206 <- 206
    ssl_socket_send      0x3ffd4338 96 -> 96
    ssl_socket_send      0x3ffd4338 666 -> 666
    ATCA:6 ECDH get pubkey ok
    ATCA:4 ECDSA sign ok
    ssl_socket_send      0x3ffd4338 153 -> 153
    ssl_socket_send      0x3ffd4338 9 -> 9
    ssl_socket_recv      0x3ffd4338 5 <- 5
    ssl_socket_recv      0x3ffd4338 70 <- 70
    ATCA:6 ECDH ok
    ssl_socket_recv      0x3ffd4338 5 <- 5
    ssl_socket_recv      0x3ffd4338 1 <- 1
    ssl_socket_recv      0x3ffd4338 5 <- 5
    ssl_socket_recv      0x3ffd4338 40 <- 40
    ssl_socket_send      0x3ffd4338 6 -> 6
    ssl_socket_send      0x3ffd4338 45 -> 45
    mgos_http_ev         0x3ffd4338 HTTP connection from 192.168.1.151:50189
    ssl_socket_recv      0x3ffd4dc0 5 <- 5
    ssl_socket_recv      0x3ffd4dc0 424 <- 424
    mg_http_is_authorize /state  1 1
    ssl_socket_recv      0x3ffd4dc0 5 <- -1
    ssl_socket_send      0x3ffb49a4 465 -> 465
    ssl_socket_send      0x3ffd484c 465 -> 465
    ssl_socket_send      0x3ffb49a4 31 -> 31
    ssl_socket_send      0x3ffd484c 31 -> 31
    ssl_socket_recv      0x3ffd5ae8 5 <- 5
    ssl_socket_recv      0x3ffd5ae8 206 <- 206
    ssl_socket_send      0x3ffd5ae8 96 -> 96
    ssl_socket_send      0x3ffd5ae8 666 -> 666
    ATCA:6 ECDH get pubkey ok
    ATCA:4 ECDSA sign ok
    ssl_socket_send      0x3ffd5ae8 154 -> 154
    ssl_socket_send      0x3ffd5ae8 9 -> 9
    ssl_socket_recv      0x3ffd5ae8 5 <- 5
    ssl_socket_recv      0x3ffd5ae8 70 <- 70
    ATCA:6 ECDH ok
    ssl_socket_recv      0x3ffd5ae8 5 <- 5
    ssl_socket_recv      0x3ffd5ae8 1 <- 1
    ssl_socket_recv      0x3ffd5ae8 5 <- 5
    ssl_socket_recv      0x3ffd5ae8 40 <- 40
    ssl_socket_send      0x3ffd5ae8 6 -> 6
    ssl_socket_send      0x3ffd5ae8 45 -> 45
    mgos_http_ev         0x3ffd5ae8 HTTP connection from 192.168.1.151:50194
    ssl_socket_recv      0x3ffd4338 5 <- 5
    ssl_socket_recv      0x3ffd4338 424 <- 424
    mg_http_is_authorize /state  1 1
    ssl_socket_recv      0x3ffd4338 5 <- -1
    ssl_socket_send      0x3ffd4dc0 465 -> 465
    ssl_socket_send      0x3ffd4dc0 31 -> 31
    ssl_socket_recv      0x3ffd44b8 5 <- 5
    ssl_socket_recv      0x3ffd44b8 206 <- 206
    ssl_socket_send      0x3ffd44b8 96 -> 96
    ssl_socket_send      0x3ffd44b8 666 -> 666
    ATCA:5 ECDH get pubkey ok
    Guru Meditation Error: Core  0 panic'ed (Interrupt wdt timeout on CPU0)
    Register dump:
    PC      : 0x4010821d  PS      : 0x00060934  A0      : 0x80119357  A1      : 0x3ffcb870
    A2      : 0x3ff47004  A3      : 0x3ffc55a8  A4      : 0x3ff4908c  A5      : 0x3ffd1510
    A6      : 0x3ffc4b1c  A7      : 0x00000000  A8      : 0x0004855c  A9      : 0xcccccccd
    A10     : 0x07a36c69  A11     : 0x00000000  A12     : 0x3ff4908c  A13     : 0x3ffbd314
    A14     : 0x00000000  A15     : 0x00000000  SAR     : 0x00000009  EXCCAUSE: 0x00000005
    EXCVADDR: 0x00000000  LBEG    : 0x4000c349  LEND    : 0x4000c36b  LCOUNT  : 0x00000000
    
    Backtrace: 0x4010821d:0x3ffcb870 0x40119357:0x3ffcb890 0x40114bf8:0x3ffcb8b0 0x40114e11:0x3ffcb8d0 0x4010ffb0:0x3ffcb900 0x4014f1c2:0x3ffcb920 0x4012fb80:0x3ffcb940 0x4012fbe0:0x3ffcb9f0 0x40139c78:0x3ffcba10 0x40132344:0x3ffcba90 0x40144c98:0x3ffcbac0 0x4013e7c6:0x3ffcbb80 0x4013e809:0x3ffcbba0 0x4011dba4:0x3ffcbbc0 0x4011f59f:0x3ffcbbe0 0x40120074:0x3ffcbc20 0x40120432:0x3ffcbc90 0x4011d2de:0x3ffcbcf0 0x40117baf:0x3ffcbd10 0x4011957d:0x3ffcbd30
    
    --- BEGIN CORE DUMP ---
    {"arch": "ESP32", "cause": 5Guru Meditation Error: Core  0 panic'ed (Interrupt wdt timeout on CPU0)
    Register dump:
    PC      : 0x4008472a  PS      : 0x00060034  A0      : 0x8008474a  A1      : 0x3ffcb4d0
    A2      : 0x00000002  A3      : 0x3ffcb890  A4      : 0x80114bf8  A5      : 0x3ffcb890
    A6      : 0x00000000  A7      : 0x07bd0603  A8      : 0x00000000  A9      : 0x00000000
    A10     : 0x00060025  A11     : 0x00000000  A12     : 0x00040025  A13     : 0x3ffcb7b0
    A14     : 0x3ffcb820  A15     : 0x00000000  SAR     : 0x00000011  EXCCAUSE: 0x00000005
    EXCVADDR: 0x00000000  LBEG    : 0x400d10f8  LEND    : 0x400d10ff  LCOUNT  : 0x00000000
    
    Backtrace: 0x4008472a:0x3ffcb4d0 0x4008474a:0x3ffcb4f0 0x400fb162:0x3ffcb510 0x40086051:0x3ffcb5d0 0x4008618c:0x3ffcb640 0x40085e3f:0x3ffcb6f0 0x40085fa9:0x3ffcb770 0x40081d81:0x3ffcb7b0
    
    --- BEGIN CORE DUMP ---
    (repeats prior lines...)
    
  • rojerrojer Dublin, Ireland

    why would that cause an interrupt WDT timeout? we're clearly not in an interrupt. a mystery.
    in any case, looks like you have pretty heavy traffic on I2C, talking to the crypto chip. this is where hardware I2C might help - i have support for it almost finished, but not quite yet.

  • carlcarl US

    Cool. That will help a lot.

  • I get the same error.. when a vTaskDelay(.) is called.
  • rojerrojer Dublin, Ireland
    edited May 16

    @carl @william.frasson gentlemen, please try again. this change seems to have got rid of the crashes i was seeing periodically. @carl, specifically for you - i also implemented hardware I2C support on ESP32 and raised default clock frequency to 400 khz, so talking to ECC508 should be much faster now.
    let me know if you still experience crashes / watchdog timeouts.

  • rojerrojer Dublin, Ireland
    edited May 16

    for your amusement - bugs found while working on this: one, two, three.

  • Awesome! It definitely is a lot faster, but I'm having trouble with signature verification. Possibly a timing issue?

    mgos_i2c_write       write 1 to 0, start? 1 stop? 1
    mgos_i2c_write        0 sent 0x00
    esp32_i2c_exec         193 loops, ok? 0, ints 0x00001a43 -> 0x00001e43, tx_fifo 1/0 rx_fifo 0/-1, status 0x66040020
    esp32_i2c_exec           80000000 0
    esp32_i2c_exec           80000901 1
    esp32_i2c_exec           00000901 1
    esp32_i2c_exec           00002000 4
    mgos_i2c_stop        stop
    esp32_i2c_exec         10000 loops, ok? 0, ints 0x00001a43 -> 0x00001a43, tx_fifo 0/-1 rx_fifo 0/-1, status 0x66000020
    esp32_i2c_exec           80001800 3
    mgos_i2c_read        read 1 from 96, start? 1, stop? 0 3ffc5c64
    esp32_i2c_exec         112 loops, ok? 1, ints 0x00001a43 -> 0x00001a4b, tx_fifo 0/-1 rx_fifo 1/1, status 0x35000100
    mgos_i2c_read         0 recd 0x04
    mgos_i2c_read        read 3 from 65535, start? 0, stop? 1 3ffc5c64
    esp32_i2c_exec         188 loops, ok? 1, ints 0x00001a43 -> 0x00001a4b, tx_fifo 0/-1 rx_fifo 3/3, status 0x35000300
    mgos_i2c_read         0 recd 0x11
    mgos_i2c_stop        stop
    esp32_i2c_exec         14 loops, ok? 1, ints 0x00001a43 -> 0x00001ac3, tx_fifo 0/-1 rx_fifo 0/-1, status 0x65000000
    mgos_i2c_write       write 40 to 96, start? 1 stop? 1
    mgos_i2c_write        0 sent 0x03
    esp32_i2c_exec         1991 loops, ok? 1, ints 0x00001a43 -> 0x00001a4b, tx_fifo 0/0 rx_fifo 0/-1, status 0x36000000
    mgos_i2c_write        31 sent 0xd1
    esp32_i2c_exec         544 loops, ok? 1, ints 0x00001a43 -> 0x00001a4b, tx_fifo 0/0 rx_fifo 0/-1, status 0x36000000
    mgos_i2c_stop        stop
    esp32_i2c_exec         14 loops, ok? 1, ints 0x00001a43 -> 0x00001ac3, tx_fifo 0/-1 rx_fifo 0/-1, status 0x66000000
    mgos_i2c_read        read 1 from 96, start? 1, stop? 0 3ffc9c20
    esp32_i2c_exec         121 loops, ok? 1, ints 0x00001a43 -> 0x00001a4b, tx_fifo 0/-1 rx_fifo 1/1, status 0x35000100
    mgos_i2c_read         0 recd 0x04
    mgos_i2c_read        read 3 from 65535, start? 0, stop? 1 3ffc5c64
    esp32_i2c_exec         188 loops, ok? 1, ints 0x00001a43 -> 0x00001a4b, tx_fifo 0/-1 rx_fifo 3/3, status 0x35000300
    mgos_i2c_read         0 recd 0x00
    mgos_i2c_stop        stop
    esp32_i2c_exec         14 loops, ok? 1, ints 0x00001a43 -> 0x00001ac3, tx_fifo 0/-1 rx_fifo 0/-1, status 0x65000000
    mgos_i2c_write       write 1 to 96, start? 1 stop? 1
    mgos_i2c_write        0 sent 0x02
    esp32_i2c_exec         103 loops, ok? 1, ints 0x00001a43 -> 0x00001a4b, tx_fifo 0/0 rx_fifo 0/-1, status 0x36000000
    mgos_i2c_stop        stop
    esp32_i2c_exec         14 loops, ok? 1, ints 0x00001a43 -> 0x00001ac3, tx_fifo 0/-1 rx_fifo 0/-1, status 0x66000000
    mgos_i2c_write       write 1 to 0, start? 1 stop? 1
    mgos_i2c_write        0 sent 0x00
    esp32_i2c_exec         211 loops, ok? 0, ints 0x00001a43 -> 0x00001e43, tx_fifo 1/0 rx_fifo 0/-1, status 0x66040020
    esp32_i2c_exec           80000000 0
    esp32_i2c_exec           80000901 1
    esp32_i2c_exec           00000901 1
    esp32_i2c_exec           00002000 4
    mgos_i2c_stop        stop
    esp32_i2c_exec         10000 loops, ok? 0, ints 0x00001a43 -> 0x00001a43, tx_fifo 0/-1 rx_fifo 0/-1, status 0x66000020
    esp32_i2c_exec           80001800 3
    mgos_i2c_read        read 1 from 96, start? 1, stop? 0 3ffc5c64
    esp32_i2c_exec         103 loops, ok? 1, ints 0x00001a43 -> 0x00001a4b, tx_fifo 0/-1 rx_fifo 1/1, status 0x35000100
    mgos_i2c_read         0 recd 0x04
    mgos_i2c_read        read 3 from 65535, start? 0, stop? 1 3ffc5c64
    esp32_i2c_exec         188 loops, ok? 1, ints 0x00001a43 -> 0x00001a4b, tx_fifo 0/-1 rx_fifo 3/3, status 0x35000300
    mgos_i2c_read         0 recd 0x11
    mgos_i2c_stop        stop
    esp32_i2c_exec         14 loops, ok? 1, ints 0x00001a43 -> 0x00001ac3, tx_fifo 0/-1 rx_fifo 0/-1, status 0x65000000
    mgos_i2c_write       write 136 to 96, start? 1 stop? 1
    mgos_i2c_write        0 sent 0x03
    esp32_i2c_exec         1980 loops, ok? 1, ints 0x00001a43 -> 0x00001a4b, tx_fifo 0/0 rx_fifo 0/-1, status 0x36000000
    mgos_i2c_write        31 sent 0xb7
    esp32_i2c_exec         1997 loops, ok? 1, ints 0x00001a43 -> 0x00001a4b, tx_fifo 0/0 rx_fifo 0/-1, status 0x36000000
    mgos_i2c_write        63 sent 0xf3
    esp32_i2c_exec         1977 loops, ok? 1, ints 0x00001a43 -> 0x00001a4b, tx_fifo 0/0 rx_fifo 0/-1, status 0x36000000
    mgos_i2c_write        95 sent 0x40
    esp32_i2c_exec         1995 loops, ok? 1, ints 0x00001a43 -> 0x00001a4b, tx_fifo 0/0 rx_fifo 0/-1, status 0x36000000
    mgos_i2c_write        127 sent 0x46
    esp32_i2c_exec         562 loops, ok? 1, ints 0x00001a43 -> 0x00001a4b, tx_fifo 0/0 rx_fifo 0/-1, status 0x36000000
    mgos_i2c_stop        stop
    esp32_i2c_exec         6 loops, ok? 1, ints 0x00001a43 -> 0x00001acb, tx_fifo 0/-1 rx_fifo 0/-1, status 0x56000000
    mgos_i2c_read        read 1 from 96, start? 1, stop? 0 3ffc9c20
    esp32_i2c_exec         48 loops, ok? 0, ints 0x00001a43 -> 0x00001e43, tx_fifo 0/-1 rx_fifo 0/1, status 0x66000000
    esp32_i2c_exec           80000000 0
    esp32_i2c_exec           80000901 1
    esp32_i2c_exec           00001001 2
    esp32_i2c_exec           00002000 4
    mgos_i2c_read        read 1 from 96, start? 1, stop? 0 3ffc5c64
    esp32_i2c_exec         63 loops, ok? 0, ints 0x00001a43 -> 0x00001e43, tx_fifo 0/-1 rx_fifo 0/1, status 0x66000000
    esp32_i2c_exec           80000000 0
    esp32_i2c_exec           80000901 1
    esp32_i2c_exec           00001001 2
    esp32_i2c_exec           00002000 4
    mgos_i2c_read        read 1 from 96, start? 1, stop? 0 3ffc5c64
    esp32_i2c_exec         63 loops, ok? 0, ints 0x00001a43 -> 0x00001e43, tx_fifo 0/-1 rx_fifo 0/1, status 0x66000000
    esp32_i2c_exec           80000000 0
    esp32_i2c_exec           80000901 1
    esp32_i2c_exec           00001001 2
    esp32_i2c_exec           00002000 4
    mgos_i2c_read        read 1 from 96, start? 1, stop? 0 3ffc5c64
    esp32_i2c_exec         45 loops, ok? 0, ints 0x00001a43 -> 0x00001e43, tx_fifo 0/-1 rx_fifo 0/1, status 0x66000000
    esp32_i2c_exec           80000000 0
    esp32_i2c_exec           80000901 1
    esp32_i2c_exec           00001001 2
    esp32_i2c_exec           00002000 4
    

    (repeats 45 or 63 loops several times)

    mgos_i2c_write       write 1 to 96, start? 1 stop? 1
    mgos_i2c_write        0 sent 0x02
    esp32_i2c_exec         63 loops, ok? 0, ints 0x00001a43 -> 0x00001e43, tx_fifo 1/0 rx_fifo 0/-1, status 0x66040000
    esp32_i2c_exec           80000000 0
    esp32_i2c_exec           80000901 1
    esp32_i2c_exec           00000901 1
    esp32_i2c_exec           00002000 4
    mgos_i2c_stop        stop
    esp32_i2c_exec         10000 loops, ok? 0, ints 0x00001a43 -> 0x00001a43, tx_fifo 0/-1 rx_fifo 0/-1, status 0x66000000
    esp32_i2c_exec           80001800 3
    mgos_i2c_write       write 1 to 96, start? 1 stop? 1
    mgos_i2c_write        0 sent 0x02
    esp32_i2c_exec         45 loops, ok? 0, ints 0x00001a43 -> 0x00001e43, tx_fifo 1/0 rx_fifo 0/-1, status 0x66040000
    esp32_i2c_exec           80000000 0
    esp32_i2c_exec           80000901 1
    esp32_i2c_exec           00000901 1
    esp32_i2c_exec           00002000 4
    mgos_i2c_stop        stop
    esp32_i2c_exec         10000 loops, ok? 0, ints 0x00001a43 -> 0x00001a43, tx_fifo 0/-1 rx_fifo 0/-1, status 0x66000000
    esp32_i2c_exec           80001800 3
    ATCA ECDSA verify failed: 0xeb
    
  • rojerrojer Dublin, Ireland

    ugh. yes. turns out, mgos_usleep is not accurate enough, and with blazing fast i2c it actually matters now. working on a fix.

  • rojerrojer Dublin, Ireland

    @carl while testing the original change, i never tested signing and verify and ecdh worked fine. what could go wrong, right? wrong!... well, here's the fix.

  • Hrm. Looks like more loops, but same effect:

    ...
    mgos_i2c_read        read 1 from 96, start? 1, stop? 0 3ffc5c64
    esp32_i2c_exec         170 loops, ok? 0, ints 0x00001a43 -> 0x00001b43, tx_fifo 1/-1 rx_fifo 0/1, status 0x34040010
    esp32_i2c_exec           00000000 0
    esp32_i2c_exec           00000901 1
    esp32_i2c_exec           00001001 2
    esp32_i2c_exec           00002000 4
    mgos_i2c_read        read 1 from 96, start? 1, stop? 0 3ffc5c64
    esp32_i2c_exec         27 loops, ok? 0, ints 0x00001a43 -> 0x00001b43, tx_fifo 1/-1 rx_fifo 0/1, status 0x34040010
    esp32_i2c_exec           00000000 0
    esp32_i2c_exec           00000901 1
    esp32_i2c_exec           00001001 2
    esp32_i2c_exec           00002000 4
    mgos_i2c_write       write 1 to 96, start? 1 stop? 1
    mgos_i2c_write        0 sent 0x02
    esp32_i2c_exec         151 loops, ok? 0, ints 0x00001a43 -> 0x00001b43, tx_fifo 2/0 rx_fifo 0/-1, status 0x34080010
    esp32_i2c_exec           00000000 0
    esp32_i2c_exec           00000901 1
    esp32_i2c_exec           00000901 1
    esp32_i2c_exec           00002000 4
    mgos_i2c_stop        stop
    esp32_i2c_exec         133 loops, ok? 0, ints 0x00001a43 -> 0x00001b43, tx_fifo 0/-1 rx_fifo 0/-1, status 0x34000010
    esp32_i2c_exec           00001800 3
    mgos_i2c_write       write 1 to 96, start? 1 stop? 1
    mgos_i2c_write        0 sent 0x02
    esp32_i2c_exec         142 loops, ok? 0, ints 0x00001a43 -> 0x00001b43, tx_fifo 2/0 rx_fifo 0/-1, status 0x34080010
    esp32_i2c_exec           00000000 0
    esp32_i2c_exec           00000901 1
    esp32_i2c_exec           00000901 1
    esp32_i2c_exec           00002000 4
    mgos_i2c_stop        stop
    esp32_i2c_exec         43 loops, ok? 0, ints 0x00001a43 -> 0x00001b43, tx_fifo 0/-1 rx_fifo 0/-1, status 0x34000010
    esp32_i2c_exec           00001800 3
    ATCA ECDSA verify failed: 0xeb
    
  • rojerrojer Dublin, Ireland

    hm. did not work for me, but now definitely does. can you show full log.

  • rojerrojer Dublin, Ireland

    also, try i2c.freq=100000, see if that works

  • I created gists with logs with/without debug and 100/400k freq: https://gist.github.com/carldunham

  • rojerrojer Dublin, Ireland

    hm. to me this looks like what i saw before i fixed the delays - everything works fine, except we try to read result of the operation too quickly.
    so, after having verified that you have my latest fix in your tree (things happen), can you please double delays here - https://github.com/cesanta/mongoose-os/blob/master/fw/src/mgos_atca.c#L262
    just * 2 the arguments to mgos_usleep, this workaround worked for me too before i went and fixed mgos_usleep properly.

  • Sorry, @rojer, no luck. Fully clean builds, from master, increased timeouts *3, *10, *100 with no change, other than it taking longer to fail.

  • Oddly, I'm getting a lot of clock skew warnings from make. Is there a cleaner clean than removing ./build and using the --clean flag?

Sign In or Register to comment.