search

espressif / esp-apple-homekit-adk

This is a port for Apple's Open Source HomeKit ADK
624 stars 64 forks source link

ESP32-WROOM-32 "Fault assertion failed" message and reboots #5

Open AramVartanyan opened 4 years ago

AramVartanyan commented 4 years ago

I have tried unchanged version of the Lightbulb example, following the building instructions. It works fine, however I have noticed that it keeps rebooting around 10 minutes after closing the session with the "iOS" device. I really don't understand what is causing the issue, but I want to help and mention it. This is a part of the screen log (I hope it is enough):

1970-01-01'T'00:10:41'Z'    Info    [com.apple.mfi.HomeKit.Core:PairingPairVerify] Pair Verify procedure completed (pairing ID 0).
1970-01-01'T'00:10:41'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb9cd0:<
    0000  48545450 2f312e31 20323030 204f4b0d 0a436f6e 74656e74 2d547970 653a2061    HTTP/1.1 200 OK..Content-Type: a
    0020  70706c69 63617469 6f6e2f70 61697269 6e672b74 6c76380d 0a436f6e 74656e74    pplication/pairing+tlv8..Content
    0040  2d4c656e 6774683a 20330d0a 0d0a0601 04                                     -Length: 3.......
1970-01-01'T'00:10:41'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb9cd0:input closed
1970-01-01'T'00:10:41'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb9cd0:closing
1970-01-01'T'00:10:41'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb9cd0:closing security context
1970-01-01'T'00:10:41'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] Closing HAP session.
1970-01-01'T'00:10:41'Z'    Debug   [com.apple.mfi.HomeKit.Core:Session] HAPSessionRelease
1970-01-01'T'00:10:41'Z'    Debug   [com.apple.mfi.HomeKit.Core:Session] HAPSessionInvalidate
1970-01-01'T'00:10:41'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb9cd0:closing TCP stream
1970-01-01'T'00:10:41'Z'    Debug   [com.apple.mfi.HomeKit.Platform:TCPStreamManager] shutdown(51, SHUT_RDWR);
1970-01-01'T'00:10:41'Z'    Fault   assertion failed - HAPPlatformLogPOSIXError @ /Users/Logic/esp32_test/esp-apple-homekit-adk/port/src/HAPPlatformLog.c:65

abort() was called at PC 0x400d5fa3 on core 0
0x400d5fa3: syscall_not_implemented_aborts at /Users/Logic/esp32_test/esp-idf/components/newlib/syscalls.c:39

Backtrace:0x4008760f:0x3ffc9540 0x40087cad:0x3ffc9560 0x4008e8fe:0x3ffc9580 0x400d5fa3:0x3ffc95f0 0x40163db2:0x3ffc9610 0x400e9a65:0x3ffc9630 0x400d8b74:0x3ffc9650 0x400e9ca6:0x3ffc9670 0x400d87a2:0x3ffc97a0 0x400e320a:0x3ffc97c0 0x400e32bf:0x3ffc9800 0x400e4ba5:0x3ffc9820 0x400e5aa9:0x3ffc9850 0x400d7e51:0x3ffc9870 0x400d721d:0x3ffc9890 0x400d7a20:0x3ffc98b0 0x400d6487:0x3ffc98f0 0x40087cb5:0x3ffc9910
0x4008760f: panic_abort at /Users/Logic/esp32_test/esp-idf/components/esp_system/panic.c:330

0x40087cad: esp_system_abort at /Users/Logic/esp32_test/esp-idf/components/esp_system/system_api.c:100

0x4008e8fe: abort at /Users/Logic/esp32_test/esp-idf/components/newlib/abort.c:46

0x400d5fa3: syscall_not_implemented_aborts at /Users/Logic/esp32_test/esp-idf/components/newlib/syscalls.c:39

0x40163db2: exit at /builds/idf/crosstool-NG/.build/HOST-x86_64-apple-darwin12/xtensa-esp32-elf/src/newlib/newlib/libc/stdlib/exit.c:64

0x400e9a65: HAPPlatformAbort at /Users/Logic/esp32_test/esp-apple-homekit-adk/port/src/HAPPlatformAbort.c:27

0x400d8b74: HAPAssertInternal at /Users/Logic/esp32_test/esp-apple-homekit-adk/homekit_adk/PAL/HAPAssert.c:20

0x400e9ca6: HAPPlatformLogPOSIXError at /Users/Logic/esp32_test/esp-apple-homekit-adk/port/src/HAPPlatformLog.c:65 (discriminator 2)

0x400d87a2: HAPPlatformTCPStreamClose at /Users/Logic/esp32_test/esp-apple-homekit-adk/port/src/HAPPlatformTCPStreamManager.c:516

0x400e320a: CloseSession at /Users/Logic/esp32_test/esp-apple-homekit-adk/homekit_adk/HAP/HAPIPAccessoryServer.c:513 (discriminator 1)

0x400e32bf: handle_input_closed at /Users/Logic/esp32_test/esp-apple-homekit-adk/homekit_adk/HAP/HAPIPAccessoryServer.c:3553

0x400e4ba5: ReadInboundData at /Users/Logic/esp32_test/esp-apple-homekit-adk/homekit_adk/HAP/HAPIPAccessoryServer.c:3595

0x400e5aa9: HandleTCPStreamEvent at /Users/Logic/esp32_test/esp-apple-homekit-adk/homekit_adk/HAP/HAPIPAccessoryServer.c:3622

0x400d7e51: HandleTCPStreamFileHandleCallback at /Users/Logic/esp32_test/esp-apple-homekit-adk/port/src/HAPPlatformTCPStreamManager.c:731

0x400d721d: ProcessSelectedFileHandles at /Users/Logic/esp32_test/esp-apple-homekit-adk/port/src/HAPPlatformRunLoop.c:303

0x400d7a20: HAPPlatformRunLoopRun at /Users/Logic/esp32_test/esp-apple-homekit-adk/port/src/HAPPlatformRunLoop.c:640

0x400d6487: main_task at /Users/Logic/esp32_test/esp-apple-homekit-adk/examples/Lightbulb/build/../main/app_main.c:336

0x40087cb5: vPortTaskWrapper at /Users/Logic/esp32_test/esp-idf/components/freertos/xtensa/port.c:143
shahpiyushv commented 4 years ago

@AramVartanyan , can you see what happens if you comment out these shutdown calls and the error check code around them? https://github.com/espressif/esp-apple-homekit-adk/blob/master/port/src/HAPPlatformTCPStreamManager.c#L512, https://github.com/espressif/esp-apple-homekit-adk/blob/master/port/src/HAPPlatformTCPStreamManager.c#L328

AramVartanyan commented 4 years ago

Thank you for your fast respond. I have commented the two "Shutdowns" you suggested. It doesn't restart anymore. Which is very nice! :)

The output is as follows:

1970-01-01'T'00:34:37'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] <private> Pair Verify M3: iOSDeviceInfo.
1970-01-01'T'00:34:37'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] <private> Pair Verify M3: kTLVType_Signature.
1970-01-01'T'00:34:37'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] Pair Verify M4: Verify Finish Response.
1970-01-01'T'00:34:37'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] <private> Pair Verify Start Session: AccessoryToControllerKey
1970-01-01'T'00:34:37'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] <private> Pair Verify Start Session: ControllerToAccessoryKey
1970-01-01'T'00:34:37'Z'    Info    [com.apple.mfi.HomeKit.Core:PairingPairVerify] Pair Verify procedure completed (pairing ID 0).
D (2079079) nvs: nvs_open_from_partition hap.A0 1
D (2079079) nvs: nvs_get_str_or_blob 00
D (2079119) nvs: nvs_close 167
D (2079119) nvs: nvs_open_from_partition hap.A0 1
D (2079119) nvs: nvs_get_str_or_blob 00
D (2079189) nvs: nvs_close 168
D (2079189) nvs: nvs_open_from_partition hap.A0 1
D (2079189) nvs: nvs_get_str_or_blob 00
D (2079249) nvs: nvs_close 169
D (2079259) nvs: nvs_open_from_partition hap.A0 1
D (2079259) nvs: nvs_get_str_or_blob 01
D (2079319) nvs: nvs_close 170
1970-01-01'T'00:34:38'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb99d8:<
    0000  48545450 2f312e31 20323030 204f4b0d 0a436f6e 74656e74 2d547970 653a2061    HTTP/1.1 200 OK..Content-Type: a
    0020  70706c69 63617469 6f6e2f70 61697269 6e672b74 6c76380d 0a436f6e 74656e74    pplication/pairing+tlv8..Content
    0040  2d4c656e 6774683a 20330d0a 0d0a0601 04                                     -Length: 3.......
1970-01-01'T'00:34:38'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb99d8:input closed
1970-01-01'T'00:34:38'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb99d8:closing
1970-01-01'T'00:34:38'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb99d8:closing security context
1970-01-01'T'00:34:38'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] Closing HAP session.
1970-01-01'T'00:34:38'Z'    Debug   [com.apple.mfi.HomeKit.Core:Session] HAPSessionRelease
1970-01-01'T'00:34:38'Z'    Debug   [com.apple.mfi.HomeKit.Core:Session] HAPSessionInvalidate
1970-01-01'T'00:34:38'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb99d8:closing TCP stream
1970-01-01'T'00:34:38'Z'    Debug   [com.apple.mfi.HomeKit.Platform:TCPStreamManager] close(50);
1970-01-01'T'00:34:38'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb99d8:closed
1970-01-01'T'00:34:38'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb99d8:releasing session
D (2079449) esp_netif_lwip: esp_netif_get_ip_info esp_netif:0x3ffcb0dc
1970-01-01'T'00:34:39'Z'    Debug   [com.apple.mfi.HomeKit.Platform:TCPStreamManager] accept(49, NULL, NULL);
1970-01-01'T'00:34:39'Z'    Debug   [com.apple.mfi.HomeKit.Platform:TCPStreamManager] setsockopt(50, 6, 1, <buffer>);
    0000  01000000                                                                   ....
1970-01-01'T'00:34:39'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] Opening HAP session.
1970-01-01'T'00:34:39'Z'    Debug   [com.apple.mfi.HomeKit.Core:Session] HAPSessionCreate
1970-01-01'T'00:34:39'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb99d8:accepted
1970-01-01'T'00:34:39'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb99d8:>
    0000  504f5354 202f7061 69722d76 65726966 79204854 54502f31 2e310d0a 486f7374    POST /pair-verify HTTP/1.1..Host
    0020  3a204163 6d655c30 33324c69 6768745c 30333242 756c622e 5f686170 2e5f7463    : Acme\032Light\032Bulb._hap._tc
    0040  702e6c6f 63616c0d 0a436f6e 74656e74 2d4c656e 6774683a 2033370d 0a436f6e    p.local..Content-Length: 37..Con
    0060  74656e74 2d547970 653a2061 70706c69 63617469 6f6e2f70 61697269 6e672b74    tent-Type: application/pairing+t
    0080  6c76380d 0a0d0a06 01010320 33409853 f12e0166 32c0d695 2094aed7 8532bcbc    lv8........ 3@.S...f2... ....2..
    00a0  1b43c561 be00d130 1fb00f74                                                 .C.a...0...t
1970-01-01'T'00:34:39'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] Pair Verify M1: Verify Start Request.
1970-01-01'T'00:34:39'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] Pair Verify M1: kTLVType_Method = 2.
1970-01-01'T'00:34:39'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] Pair Verify M1: Controller_cv_PK.
    0000  33409853 f12e0166 32c0d695 2094aed7 8532bcbc 1b43c561 be00d130 1fb00f74    3@.S...f2... ....2...C.a...0...t
1970-01-01'T'00:34:39'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] Pair Verify M2: Verify Start Response.
1970-01-01'T'00:34:39'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] <private> Pair Verify M2: cv_SK.
1970-01-01'T'00:34:39'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] Pair Verify M2: cv_PK.
    0000  6766dbe0 e376eef1 b2e052c7 734eb569 b0038f2b ab5a2a0a 5836eb5b 06d73421    gf...v....R.sN.i...+.Z*.X6.[..4!
1970-01-01'T'00:34:40'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] <private> Pair Verify M2: cv_KEY.
D (2081019) nvs: nvs_open_from_partition hap.90 1
D (2081019) nvs: nvs_get_str_or_blob 00
D (2081059) nvs: nvs_close 171
1970-01-01'T'00:34:40'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] <private> Pair Verify M2: AccessoryInfo
1970-01-01'T'00:34:40'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] <private> Pair Verify M2: kTLVType_Signature
1970-01-01'T'00:34:40'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] <private> Pair Verify M2: SessionKey
1970-01-01'T'00:34:40'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] Pair Verify M2: kTLVType_EncryptedData.
    0000  0c2d8b35 95ca12a9 3f7fd489 0b9316b6 66391c92 4488bc30 c8affa5f 8914d90e    .-.5....?.......f9..D..0..._....
    0020  5cf62b00 f0ee564c 6ac407b6 e73f2242 8c0d9d63 3d20fa99 2a9fecdc e1cac28d    \.+...VLj....?"B...c= ..*.......
    0040  001757c7 e577e4a7 7e65b9e8 b1b1d62d cbf0f5d9 310c03e7 f6d53492 8dc5f357    ..W..w..~e.....-....1.....4....W
    0060  9cc16bfa 9d                                                                ..k..
D (2081149) esp_netif_lwip: esp_netif_get_ip_info esp_netif:0x3ffcb0dc
D (2081489) nvs: nvs_open_from_partition hap.A0 1
D (2081489) nvs: nvs_get_str_or_blob 00
D (2081589) nvs: nvs_close 172
D (2081589) nvs: nvs_open_from_partition hap.A0 1
D (2081589) nvs: nvs_get_str_or_blob 00
D (2081659) nvs: nvs_close 173
D (2081659) nvs: nvs_open_from_partition hap.A0 1
D (2081659) nvs: nvs_get_str_or_blob 00
D (2081679) nvs: nvs_close 174
D (2081679) nvs: nvs_open_from_partition hap.A0 1
D (2081679) nvs: nvs_get_str_or_blob 01
D (2081739) nvs: nvs_close 175
1970-01-01'T'00:34:40'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb99d8:<
    0000  48545450 2f312e31 20323030 204f4b0d 0a436f6e 74656e74 2d547970 653a2061    HTTP/1.1 200 OK..Content-Type: a
    0020  70706c69 63617469 6f6e2f70 61697269 6e672b74 6c76380d 0a436f6e 74656e74    pplication/pairing+tlv8..Content
    0040  2d4c656e 6774683a 20313430 0d0a0d0a 06010203 206766db e0e376ee f1b2e052    -Length: 140........ gf...v....R
    0060  c7734eb5 69b0038f 2bab5a2a 0a5836eb 5b06d734 2105650c 2d8b3595 ca12a93f    .sN.i...+.Z*.X6.[..4!.e.-.5....?
    0080  7fd4890b 9316b666 391c9244 88bc30c8 affa5f89 14d90e5c f62b00f0 ee564c6a    .......f9..D..0..._....\.+...VLj
    00a0  c407b6e7 3f22428c 0d9d633d 20fa992a 9fecdce1 cac28d00 1757c7e5 77e4a77e    ....?"B...c= ..*.........W..w..~
    00c0  65b9e8b1 b1d62dcb f0f5d931 0c03e7f6 d534928d c5f3579c c16bfa9d             e.....-....1.....4....W..k..
D (2081809) esp_netif_lwip: esp_netif_get_ip_info esp_netif:0x3ffcb0dc
1970-01-01'T'00:34:41'Z'    Debug   [com.apple.mfi.HomeKit.Core:IPAccessoryServer] session:0x3ffb99d8:>
    0000  504f5354 202f7061 69722d76 65726966 79204854 54502f31 2e310d0a 486f7374    POST /pair-verify HTTP/1.1..Host
    0020  3a204163 6d655c30 33324c69 6768745c 30333242 756c622e 5f686170 2e5f7463    : Acme\032Light\032Bulb._hap._tc
    0040  702e6c6f 63616c0d 0a436f6e 74656e74 2d4c656e 6774683a 20313235 0d0a436f    p.local..Content-Length: 125..Co
    0060  6e74656e 742d5479 70653a20 6170706c 69636174 696f6e2f 70616972 696e672b    ntent-Type: application/pairing+
    0080  746c7638 0d0a0d0a 05782c04 ae041037 8b2a3aed 7c0ea5be 9fc5352f 0b0b816c    tlv8.....x,....7.*:.|.....5/...l
    00a0  8c4a62dc 80664a30 52c85b65 de7bc1c1 8c5c8a0b 2ba2274e b5476e03 f9351778    .Jb..fJ0R.[e.{...\..+.'N.Gn..5.x
    00c0  305e235e 14177b6a 86e4cd8f 5e684ba8 661505d3 a2ffefae bdbd0840 017c3a68    0^#^..{j....^hK.f..........@.|:h
    00e0  eab43716 955a56e9 cabbcc4f b399828d 4409cfa8 f0f4147d 285748cc ac59bbde    ..7..ZV....O....D......}(WH..Y..
    0100  cd950601 03                                                                .....
    0000  2c04ae04 10378b2a 3aed7c0e a5be9fc5 352f0b0b 816c8c4a 62dc8066 4a3052c8    ,....7.*:.|.....5/...l.Jb..fJ0R.ptedData.
    0020  5b65de7b c1c18c5c 8a0b2ba2 274eb547 6e03f935 1778305e 235e1417 7b6a86e4    [e.{...\..+.'N.Gn..5.x0^#^..{j..
    0040  cd8f5e68 4ba86615 05d3a2ff efaebdbd 0840017c 3a68eab4 3716955a 56e9cabb    ..^hK.f..........@.|:h..7..ZV...
    0060  cc4fb399 828d4409 cfa8f0f4 147d2857 48ccac59 bbdecd95                      .O....D......}(WH..Y....
D (2083309) nvs: nvs_open_from_partition hap.A0 1
D (2083309) nvs: nvs_get_str_or_blob 00
D (2083389) nvs: nvs_close 176
1970-01-01'T'00:34:42'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] <private> Pair Verify M3: iOSDeviceInfo.
1970-01-01'T'00:34:42'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] <private> Pair Verify M3: kTLVType_Signature.
1970-01-01'T'00:34:42'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] Pair Verify M4: Verify Finish Response.
1970-01-01'T'00:34:42'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] <private> Pair Verify Start Session: AccessoryToControllerKey
1970-01-01'T'00:34:42'Z'    Debug   [com.apple.mfi.HomeKit.Core:PairingPairVerify] <private> Pair Verify Start Session: ControllerToAccessoryKey
1970-01-01'T'00:34:42'Z'    Info    [com.apple.mfi.HomeKit.Core:PairingPairVerify] Pair Verify procedure completed (pairing ID 0).
D (2083919) nvs: nvs_open_from_partition hap.A0 1
D (2083919) nvs: nvs_get_str_or_blob 00
D (2084009) nvs: nvs_close 177

I didn't stated before, but there was a strange error during compilation. If it is related:

[1017/1034] Building C object esp-idf/port/CMakeFiles/__idf_port.dir/src/HAPPlatformLog.c.obj
/Users/Logic/esp32_test/esp-apple-homekit-adk/port/src/HAPPlatformLog.c: In function 'HAPPlatformLogPOSIXError':
/Users/Logic/esp32_test/esp-apple-homekit-adk/port/src/HAPPlatformLog.c:60:13: warning: initialization of 'int' from 'char *' makes integer from pointer without a cast [-Wint-conversion]
     int e = strerror_r(errorNumber, errorString, sizeof errorString);
             ^~~~~~~~~~
skanico commented 4 years ago

https://github.com/espressif/esp-apple-homekit-adk/pull/13/commits/3b10ee65e26f0dba635c06947cbb30a437f7f1b2 seems to solve the problem. No more crashes for me.