maximkulkin / esp-homekit

Apple HomeKit accessory server library for ESP-OPEN-RTOS
MIT License
1.12k stars 170 forks source link

Fatal exception (29) caused when the second client is connected. #83

Closed emrahduruer closed 5 years ago

emrahduruer commented 5 years ago

Hello,

I experience this problem; As soon as the second client connected, I get cpu reset Fatal Exception(29) at 0x402410c2: uxListRemove at /tools/esp-open-rtos/FreeRTOS/Source/list.c:176.

So, I have read issue #13 and issue #10. I followed all the suggestions in there. No luck so far. I have the latest esp-homekit code including your March 14 update.

I tried to explain what I see so far. Please advise.

  1. In one scenerio, the second client connects and it works fine for a while. `>>> HomeKit: Got new client connection: 5 [hermes-beryllium] [] on_homekit_event: HOMEKIT_EVENT_CLIENT_CONNECTED

    homekit_client_process: [Client 5] Got 165 incomming data homekit_server_on_pair_verify: HomeKit Pair Verify homekit_server_on_pair_verify: Free heap: 30504 tlv_debug: Got following TLV values: tlv_debug: Type 6 value (1 bytes): \x01 tlv_debug: Type 3 value (32 bytes): s\xD4\xE8\xE4-\x9E\xED5xQ\x9Fxj\x1B\xD9\x8F7\x8A\xB8?\xC5\xBAq\xE8jHi\x93\x97\x8C\xBDB HomeKit: [Client 5] Pair Verify Step 1/2 homekit_server_on_pair_verify: [Client 5] Importing device Curve25519 public key homekit_server_on_pair_verify: [Client 5] Generating accessory Curve25519 key homekit_server_on_pair_verify: [Client 5] Exporting accessory Curve25519 public key homekit_server_on_pair_verify: [Client 5] Generating Curve25519 shared secret homekit_server_on_pair_verify: [Client 5] Generating signature homekit_server_on_pair_verify: [Client 5] Generating proof homekit_server_on_pair_verify: [Client 5] Encrypting response send_tlv_response: [Client 5] Sending TLV response tlv_debug: Got following TLV values: tlv_debug: Type 6 value (1 bytes): \x02 tlv_debug: Type 3 value (32 bytes): \xBA\x16UY\x93J\xC3\xB8/\x05\xE9\x01\xEF\x97\x0F\x09\xBFM\xF2S\xBE\x8D\xBB\x1E59\xE4\xCCW\x9Cg tlv_debug: Type 5 value (101 bytes): \x108\xD3\xE4\xDE\xB2\x1D20\x10\x1BA\xEA\xE4}\xE5DI\x0F\x0D\xF7\xFA\xEB2`\x9A'\x16\x80\xAD\x08\x14\x9E\xCD\xEF{\x915\xA1t#\xD4}EA\xAF\xFA\xF0\xFCb\xBCo\xE26\xA1\x8Ei\x10\x08\xC9\xB7~C\xBA\xFEY8\xB0\xB4\xF8\xE5^\x96\x128\x8F\xF1]\xD8X\x02\xBA-\xB2\xD6\xEFU3\x0F\x0C\x9DK)\xEEr\xD9\x9D \x8A\x0A\xFD client_send: [Client 5] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 140\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x06\x01\x02\x03 \xBA\x16UY\x93J\xC3\xB8/\x05\xE9\x01\xEF\x97\x0F\x09\xBFM\xF2S\xBE\x8D\xBB\x1E59\xE4\xCCW\x9Cg\x05e\x108\xD3\xE4\xDE\xB2\x1D20\x10\x1BA\xEA\xE4}\xE5DI\x0F\x0D\xF7\xFA\xEB2\x9A'\x16\x80\xAD\x08\x14\x9E\xCD\xEF{\x915\xA1t#\xD4}EA\xAF\xFA\xF0\xFCb\xBCo\xE26\xA1\x8Ei\x10\x08\xC9\xB7~C\xBA\xFEY8\xB0\xB4\xF8\xE5^\x96\x128\x8F\xF1]\xD8X\x02\xBA-\xB2\xD6\xEFU3\x0F\x0C\x9DK)\xEEr\xD9\x9D \x8A\x0A\xFD homekit_client_process: [Client 5] Finished processing homekit_client_process: [Client 5] Got 254 incomming data homekit_server_on_pair_verify: HomeKit Pair Verify homekit_server_on_pair_verify: Free heap: 30220 tlv_debug: Got following TLV values: tlv_debug: Type 5 value (120 bytes): \x1B\xDD\xA5\xA3\xD4+\x09\x15j\xC0\x08\x87,Q1\x1B\xBF.\xCD\x9E\x8B\x8A\xA1\xC1b\x88\x00\xE4kiLx\xD9\x1B\x8B\xA4M\x18\xB0\xE4\x8C\x86\xBE$\xE8\x06\x95\xB8\xA3\xB8\xD5\xBF\xD7\x14\xB1\x8E\x04\x04\xB1k\xE1$\xAF\xA7\x044w\x1AfYVP\xBD\x0C'b\xD8\x80D@}\xEF\xAA\x8D/\xE03\x83\x8F\x90)3\x1F\x14\x8A/L\\\xBA\x10\xD3\xF5\xCC\x16\xF2\xD6\xE2'\xBC\x12\xDB\xDD\xE9\xE8\xDC:\xFB\xFD)7 tlv_debug: Type 6 value (1 bytes): \x03 HomeKit: [Client 5] Pair Verify Step 2/2 homekit_server_on_pair_verify: [Client 5] Decrypting payload homekit_server_on_pair_verify: [Client 5] Searching pairing with F19D5199-BF7C-4BF7-B083-1C96550395FD HomeKit: [Client 5] Found pairing with F19D5199-BF7C-4BF7-B083-1C96550395FD homekit_server_on_pair_verify: [Client 5] Verifying device signature send_tlv_response: [Client 5] Sending TLV response tlv_debug: Got following TLV values: tlv_debug: Type 6 value (1 bytes): \x04 client_send: [Client 5] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 3\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x06\x01\x04 [hermes-beryllium] [] on_homekit_event: HOMEKIT_EVENT_CLIENT_VERIFIED HomeKit: [Client 5] Verification successful, secure session established homekit_client_process: [Client 5] Finished processing homekit_client_process: [Client 5] Got 85 incomming data homekit_client_process: [Client 5] Decrypting data homekit_client_process: [Client 5] Decrypted 67 bytes, available 0 Decrypted data (67 bytes): "GET /accessories HTTP/1.1\x0D\x0AHost: beryllium-5C6A._hap._tcp.local\x0D\x0A\x0D\x0A" HomeKit: [Client 5] Get Accessories homekit_server_on_get_accessories: Free heap: 30400 client_send: [Client 5] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A client_send: [Client 5] Sending payload: 3fe\x0D\x0A{"accessories":[{"aid":1,"services":[{"iid":1,"type":"3E","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":2,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"beryllium"},{"aid":1,"iid":3,"type":"20","perms":["pr"],"description":"Manufacturer","format":"string","value":"hermes-iot"},{"aid":1,"iid":4,"type":"30","perms":["pr"],"description":"Serial Number","format":"string","value":"037A2BABF19D"},{"aid":1,"iid":5,"type":"21","perms":["pr"],"description":"Model","format":"string","value":"hermes-beryllium"},{"aid":1,"iid":6,"type":"52","perms":["pr"],"description":"Firmware Revision","format":"string","value":"hermes-beryllium"},{"aid":1,"iid":7,"type":"14","perms":["pw"],"description":"Identify","format":"bool"}]},{"iid":8,"type":"49","hidden":false,"primary":true,"characteristics":[{"aid":1,"iid":9,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Relay 1"},{"aid":1,"iid":10,"type":"25","perms":["pr","pw","ev"],"ev":false,"description":"On",\x0D\x0A client_send: [Client 5] Sending payload: 3fd\x0D\x0A"format":"bool","value":false}]},{"iid":11,"type":"49","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":12,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Relay 2"},{"aid":1,"iid":13,"type":"25","perms":["pr","pw","ev"],"ev":false,"description":"On","format":"bool","value":true}]},{"iid":14,"type":"8A","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":15,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Temperature Sensor"},{"aid":1,"iid":16,"type":"11","perms":["pr","ev"],"ev":false,"description":"Current Temperature","format":"float","unit":"celsius","minValue":0,"maxValue":100,"minStep":0.100000001490116,"value":23.8999996185303}]},{"iid":17,"type":"82","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":18,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Humidity Sensor"},{"aid":1,"iid":19,"type":"10","perms":["pr","ev"],"ev":false,"description":"Current Relative Humidity","format":\x0D\x0A client_send: [Client 5] Sending payload: 196\x0D\x0A"float","unit":"percentage","minValue":0,"maxValue":100,"minStep":1,"value":31.7999992370605}]},{"iid":20,"type":"85","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":21,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Motion Sensor"},{"aid":1,"iid":22,"type":"22","perms":["pr","ev"],"ev":false,"description":"Motion Detected","format":"bool","value":false}]}]}]}\x0D\x0A client_send: [Client 5] Sending payload: 0\x0D\x0A\x0D\x0A homekit_client_process: [Client 5] Finished processing [hermes-beryllium] [] homekit_gpi_callback: gpi_event_activated client_notify_characteristic: Got characteristic 1.22 change event client_notify_characteristic: Sending event to client 4 send_client_events: [Client 4] Sending EVENT send_client_events: Free heap: 30452 client_send: [Client 4] Sending payload: EVENT/1.0 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0A\x0D\x0A client_send: [Client 4] Sending payload: 35\x0D\x0A{"characteristics":[{"aid":1,"iid":22,"value":true}]}\x0D\x0A client_send: [Client 4] Sending payload: 0\x0D\x0A\x0D\x0A [hermes-beryllium] [] homekit_gpi_callback: gpi_event_deactivated client_notify_characteristic: Got characteristic 1.22 change event client_notify_characteristic: Sending event to client 4 send_client_events: [Client 4] Sending EVENT send_client_events: Free heap: 30452 client_send: [Client 4] Sending payload: EVENT/1.0 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0A\x0D\x0A client_send: [Client 4] Sending payload: 36\x0D\x0A{"characteristics":[{"aid":1,"iid":22,"value":false}]}\x0D\x0A client_send: [Client 4] Sending payload: 0\x0D\x0A\x0D\x0A homekit_client_process: [Client 5] Got 312 incomming data homekit_client_process: [Client 5] Decrypting data homekit_client_process: [Client 5] Decrypted 294 bytes, available 0 Decrypted data (294 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: beryllium-5C6A._hap._tcp.local\x0D\x0AContent-Length: 166\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":16,"ev":true},{"aid":1,"iid":10,"ev":true},{"aid":1,"iid":22,"ev":true},{"aid":1,"iid":13,"ev":true},{"aid":1,"iid":19,"ev":true}]}" HomeKit: [Client 5] Update Characteristics homekit_server_on_update_characteristics: Free heap: 29996 homekit_server_on_update_characteristics: [Client 5] Processing element { "aid": 1, "iid": 16, "ev": true } homekit_server_on_update_characteristics: [Client 5] Processing element { "aid": 1, "iid": 10, "ev": true } homekit_server_on_update_characteristics: [Client 5] Processing element { "aid": 1, "iid": 22, "ev": true } homekit_server_on_update_characteristics: [Client 5] Processing element { "aid": 1, "iid": 13, "ev": true } homekit_server_on_update_characteristics: [Client 5] Processing element { "aid": 1, "iid": 19, "ev": true } homekit_server_on_update_characteristics: [Client 5] There were no processing errors, sending No Content response client_send: [Client 5] Sending payload: HTTP/1.1 204 No Content\x0D\x0A\x0D\x0A homekit_client_process: [Client 5] Finished processing homekit_client_process: [Client 5] Got 312 incomming data homekit_client_process: [Client 5] Decrypting data homekit_client_process: [Client 5] Decrypted 294 bytes, available 0 Decrypted data (294 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: beryllium-5C6A._hap._tcp.local\x0D\x0AContent-Length: 166\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":16,"ev":true},{"aid":1,"iid":10,"ev":true},{"aid":1,"iid":22,"ev":true},{"aid":1,"iid":13,"ev":true},{"aid":1,"iid":19,"ev":true}]}" HomeKit: [Client 5] Update Characteristics homekit_server_on_update_characteristics: Free heap: 29896 homekit_server_on_update_characteristics: [Client 5] Processing element { "aid": 1, "iid": 16, "ev": true } homekit_server_on_update_characteristics: [Client 5] Processing element { "aid": 1, "iid": 10, "ev": true } homekit_server_on_update_characteristics: [Client 5] Processing element { "aid": 1, "iid": 22, "ev": true } homekit_server_on_update_characteristics: [Client 5] Processing element { "aid": 1, "iid": 13, "ev": true } homekit_server_on_update_characteristics: [Client 5] Processing element { "aid": 1, "iid": 19, "ev": true } homekit_server_on_update_characteristics: [Client 5] There were no processing errors, sending No Content response client_send: [Client 5] Sending payload: HTTP/1.1 204 No Content\x0D\x0A\x0D\x0A homekit_client_process: [Client 5] Finished processing homekit_client_process: [Client 5] Got 117 incomming data homekit_client_process: [Client 5] Decrypting data homekit_client_process: [Client 5] Decrypted 99 bytes, available 0 Decrypted data (99 bytes): "GET /characteristics?id=1.19,1.10,1.22,1.13,1.16 HTTP/1.1\x0D\x0AHost: beryllium-5C6A._hap._tcp.local\x0D\x0A\x0D\x0A" HomeKit: [Client 5] Get Characteristics homekit_server_on_get_characteristics: Free heap: 30192 homekit_server_on_get_characteristics: [Client 5] Query paramter id = 1.19,1.10,1.22,1.13,1.16 homekit_server_on_get_characteristics: [Client 5] Requested characteristic info for 1.19 homekit_server_on_get_characteristics: [Client 5] Requested characteristic info for 1.10 homekit_server_on_get_characteristics: [Client 5] Requested characteristic info for 1.22 homekit_server_on_get_characteristics: [Client 5] Requested characteristic info for 1.13 homekit_server_on_get_characteristics: [Client 5] Requested characteristic info for 1.16 client_send: [Client 5] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A homekit_server_on_get_characteristics: [Client 5] Requested characteristic info for 1.19 homekit_server_on_get_characteristics: [Client 5] Requested characteristic info for 1.10 homekit_server_on_get_characteristics: [Client 5] Requested characteristic info for 1.22 homekit_server_on_get_characteristics: [Client 5] Requested characteristic info for 1.13 homekit_server_on_get_characteristics: [Client 5] Requested characteristic info for 1.16 client_send: [Client 5] Sending payload: cf\x0D\x0A{"characteristics":[{"aid":1,"iid":19,"value":31.7999992370605},{"aid":1,"iid":10,"value":false},{"aid":1,"iid":22,"value":false},{"aid":1,"iid":13,"value":true},{"aid":1,"iid":16,"value":23.8999996185303}]}\x0D\x0A client_send: [Client 5] Sending payload: 0\x0D\x0A\x0D\x0A homekit_client_process: [Client 5] Finished processing [hermes-beryllium] [] homekit_gpi_callback: gpi_event_activated client_notify_characteristic: Got characteristic 1.22 change event client_notify_characteristic: Sending event to client 4 client_notify_characteristic: Got characteristic 1.22 change event client_notify_characteristic: Sending event to client 5 send_client_events: [Client 5] Sending EVENT send_client_events: Free heap: 30332 client_send: [Client 5] Sending payload: EVENT/1.0 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0A\x0D\x0A client_send: [Client 5] Sending payload: 35\x0D\x0A{"characteristics":[{"aid":1,"iid":22,"value":true}]}\x0D\x0A client_send: [Client 5] Sending payload: 0\x0D\x0A\x0D\x0A send_client_events: [Client 4] Sending EVENT send_client_events: Free heap: 27144 client_send: [Client 4] Sending payload: EVENT/1.0 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0A\x0D\x0A client_send: [Client 4] Sending payload: 35\x0D\x0A{"characteristics":[{"aid":1,"iid":22,"value":true}]}\x0D\x0A client_send: [Client 4] Sending payload: 0\x0D\x0A\x0D\x0A [hermes-beryllium] [] homekit__dht_data: homekit__dht_data: 23.9, 31.2 [hermes-beryllium] [] homekit__dht_data: Free heap: 30296 client_notify_characteristic: Got characteristic 1.16 change event client_notify_characteristic: Sending event to client 4 client_notify_characteristic: Got characteristic 1.16 change event client_notify_characteristic: Sending event to client 5 client_notify_characteristic: Got characteristic 1.19 change event client_notify_characteristic: Sending event to client 4 client_notify_characteristic: Got characteristic 1.19 change event client_notify_characteristic: Sending event to client 5 send_client_events: [Client 5] Sending EVENT send_client_events: Free heap: 30284 client_send: [Client 5] Sending payload: EVENT/1.0 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0A\x0D\x0A client_send: [Client 5] Sending payload: 6d\x0D\x0A{"characteristics":[{"aid":1,"iid":16,"value":23.8999996185303},{"aid":1,"iid":19,"value":31.2000007629395}]}\x0D\x0A client_send: [Client 5] Sending payload: 0\x0D\x0A\x0D\x0A send_client_events: [Client 4] Sending EVENT send_client_events: Free heap: 27120 client_send: [Client 4] Sending payload: EVENT/1.0 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0A\x0D\x0A client_send: [Client 4] Sending payload: 6d\x0D\x0A{"characteristics":[{"aid":1,"iid":16,"value":23.8999996185303},{"aid":1,"iid":19,"value":31.2000007629395}]}\x0D\x0A client_send: [Client 4] Sending payload: 0\x0D\x0A\x0D\x0A [hermes-beryllium] [] homekit_gpi_callback: gpi_event_deactivated client_notify_characteristic: Got characteristic 1.22 change event client_notify_characteristic: Sending event to client 4 client_notify_characteristic: Got characteristic 1.22 change event client_notify_characteristic: Sending event to client 5 send_client_events: [Client 5] Sending EVENT send_client_events: Free heap: 27124 client_send: [Client 5] Sending payload: EVENT/1.0 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0A\x0D\x0A client_send: [Client 5] Sending payload: 36\x0D\x0A{"characteristics":[{"aid":1,"iid":22,"value":false}]}\x0D\x0A client_send: [Client 5] Sending payload: 0\x0D\x0A\x0D\x0A send_client_events: [Client 4] Sending EVENT send_client_events: Free heap: 27144 client_send: [Client 4] Sending payload: EVENT/1.0 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0A\x0D\x0A client_send: [Client 4] Sending payload: 36\x0D\x0A{"characteristics":[{"aid":1,"iid":22,"value":false}]}\x0D\x0A client_send: [Client 4] Sending payload: 0\x0D\x0A\x0D\x0A [hermes-beryllium] [] homekit_gpi_callback: gpi_event_activated client_notify_characteristic: Got characteristic 1.22 change event client_notify_characteristic: Sending event to client 4 client_notify_characteristic: Got characteristic 1.22 change event client_notify_characteristic: Sending event to client 5 send_client_events: [Client 5] Sending EVENT send_client_events: Free heap: 30332 client_send: [Client 5] Sending payload: EVENT/1.0 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0A\x0D\x0A client_send: [Client 5] Sending payload: 35\x0D\x0A{"characteristics":[{"aid":1,"iid":22,"value":true}]}\x0D\x0A client_send: [Client 5] Sending payload: 0\x0D\x0A\x0D\x0A send_client_events: [Client 4] Sending EVENT send_client_events: Free heap: 27144 client_send: [Client 4] Sending payload: EVENT/1.0 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0A\x0D\x0A client_send: [Client 4] Sending payload: 35\x0D\x0A{"characteristics":[{"aid":1,"iid":22,"value":true}]}\x0D\x0A client_send: [Client 4] Sending payload: 0\x0D\x0A\x0D\x0A [hermes-beryllium] [] homekit_gpi_callback: gpi_event_deactivated client_notify_characteristic: Got characteristic 1.22 change event client_notify_characteristic: Sending event to client 4 client_notify_characteristic: Got characteristic 1.22 change event client_notify_characteristic: Sending event to client 5 send_client_events: [Client 5] Sending EVENT send_client_events: Free heap: 30332 client_send: [Client 5] Sending payload: EVENT/1.0 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0A\x0D\x0A client_send: [Client 5] Sending payload: 36\x0D\x0A{"characteristics":[{"aid":1,"iid":22,"value":false}]}\x0D\x0A client_send: [Client 5] Sending payload: 0\x0D\x0A\x0D\x0A send_client_events: [Client 4] Sending EVENT send_client_events: Free heap: 27144 client_send: [Client 4] Sending payload: EVENT/1.0 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0A\x0D\x0A client_send: [Client 4] Sending payload: 36\x0D\x0A{"characteristics":[{"aid":1,"iid":22,"value":false}]}\x0D\x0A client_send: [Client 4] Sending payload: 0\x0D\x0A\x0D\x0A Fatal exception (29): epc1=0x402410c2 epc2=0x00000000 epc3=0x4020281a excvaddr=0x092de6bc depc=0x00000000 excsave1=0x4021059a Registers: a0 4021059a a1 3fff3df0 a2 3fff6064 a3 00ffffff a4 092de6b4 a5 ffc2d439 a6 3fff6060 a7 00000000 a8 00000003 a9 00000009 a10 fffff000 a11 4023feb0 a12 3fff1af0 a13 3fff1ae8 SAR 0000001f

  2. Other one, if the client connected automatically, I notice that GET /accessories command does not come from the client. After that, in the first attemp to send EVENT command, the code crashes. Not that it happens even there is one client connected.

`>>> HomeKit: Got new client connection: 4 [hermes-beryllium] [] on_homekit_event: HOMEKIT_EVENT_CLIENT_CONNECTED

homekit_client_process: [Client 4] Got 165 incomming data homekit_server_on_pair_verify: HomeKit Pair Verify homekit_server_on_pair_verify: Free heap: 27044 tlv_debug: Got following TLV values: tlv_debug: Type 6 value (1 bytes): \x01 tlv_debug: Type 3 value (32 bytes): \xB4\x98\xD73\x8E5NRcr/.\xAD\xDD\xF8/\x12\xA6\x8B\xF9\xE7\x01\x96D\xB0\x89\xDAQ!q9& HomeKit: [Client 4] Pair Verify Step 1/2 homekit_server_on_pair_verify: [Client 4] Importing device Curve25519 public key homekit_server_on_pair_verify: [Client 4] Generating accessory Curve25519 key homekit_server_on_pair_verify: [Client 4] Exporting accessory Curve25519 public key homekit_server_on_pair_verify: [Client 4] Generating Curve25519 shared secret homekit_server_on_pair_verify: [Client 4] Generating signature homekit_server_on_pair_verify: [Client 4] Generating proof homekit_server_on_pair_verify: [Client 4] Encrypting response send_tlv_response: [Client 4] Sending TLV response tlv_debug: Got following TLV values: tlv_debug: Type 6 value (1 bytes): \x02 tlv_debug: Type 3 value (32 bytes): \xF2\x81\xB8\xFC\xD3\xE9\x13&\x9E\x8C.z\xF4\x90\x83}&␡S\xA2\x82}!%\xDB\xCB1\xF1\x08\xB5sx tlv_debug: Type 5 value (101 bytes): \xBE$\xE5\x93\xCC\x89\xF6C/\x0C>\x89&\xE5\xB2\xCB\x8BK\x19\xDF0I\x17=\x8F?\xF3\x9Co\x0F\xA6B\xDC\xDC\xDD\x9CU\x02\xA0\xE7\xF06\xAA6k\xC7\xC9"\xF7\x84e\x89~U\x00Z\xE1\x90\x91\x97%D\xD9\xC7\xFE\xC3J\x8F\x06\x13g78lc\x94\xE6\xE7k|\xFBD{\x80\x14\xCD+v\xEBH\x1C\xB8\xA6c"\xC5\xA7\xE3xJ client_send: [Client 4] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 140\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x06\x01\x02\x03 \xF2\x81\xB8\xFC\xD3\xE9\x13&\x9E\x8C.z\xF4\x90\x83}&␡S\xA2\x82}!%\xDB\xCB1\xF1\x08\xB5sx\x05e\xBE$\xE5\x93\xCC\x89\xF6C/\x0C>\x89&\xE5\xB2\xCB\x8BK\x19\xDF0I\x17=\x8F?\xF3\x9Co\x0F\xA6B\xDC\xDC\xDD\x9CU\x02\xA0\xE7\xF06\xAA6k\xC7\xC9"\xF7\x84e\x89~U\x00Z\xE1\x90\x91\x97%D\xD9\xC7\xFE\xC3J\x8F\x06\x13g78lc\x94\xE6\xE7k|\xFBD{\x80\x14\xCD+v\xEBH\x1C\xB8\xA6c"\xC5\xA7\xE3xJ homekit_client_process: [Client 4] Finished processing [hermes-beryllium] [] homekit_gpi_callback: gpi_event_deactivated homekit_client_process: [Client 4] Got 254 incomming data homekit_server_on_pair_verify: HomeKit Pair Verify homekit_server_on_pair_verify: Free heap: 26756 tlv_debug: Got following TLV values: tlv_debug: Type 5 value (120 bytes): \xB84x\xEF\xAF\x1Co\x13mW\x17\xCD\xD5R\xA5|\xC3\xEBP\xCB\x96N\x03\xA4:\xA3\x8D'\x98\xDC\xB7\x0F\x9F\\xC5\xD9\x8Cg\xBCf\xE02\xF2\xB2\x9E2\xD0\xCB\xBFd\x83\xCAR\xB1R\x98h\x92\xDDom\x0Bz`@(*\x91y\xAC\xBB\x01\xA6\x16(\xC3\xDC\xFE\x8A\xE3\xD5\x10P\x97\xFE\xA5MH\x1B\xB3J\x12\xD4\xA9\x8D\xE8c\xFA\x10'\x0A\x94'\xBC?\xC9usB\x9C\x04j\xEEa\x06\xCF\x09\xA2 tlv_debug: Type 6 value (1 bytes): \x03 HomeKit: [Client 4] Pair Verify Step 2/2 homekit_server_on_pair_verify: [Client 4] Decrypting payload homekit_server_on_pair_verify: [Client 4] Searching pairing with B1D801BA-998D-43A3-B4D2-00D4FCD76000 HomeKit: [Client 4] Found pairing with B1D801BA-998D-43A3-B4D2-00D4FCD76000 homekit_server_on_pair_verify: [Client 4] Verifying device signature send_tlv_response: [Client 4] Sending TLV response tlv_debug: Got following TLV values: tlv_debug: Type 6 value (1 bytes): \x04 client_send: [Client 4] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/pairing+tlv8\x0D\x0AContent-Length: 3\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A\x06\x01\x04 [hermes-beryllium] [] on_homekit_event: HOMEKIT_EVENT_CLIENT_VERIFIED HomeKit: [Client 4] Verification successful, secure session established homekit_client_process: [Client 4] Finished processing homekit_client_process: [Client 4] Got 85 incomming data homekit_client_process: [Client 4] Decrypting data homekit_client_process: [Client 4] Decrypted 67 bytes, available 0 Decrypted data (67 bytes): "GET /accessories HTTP/1.1\x0D\x0AHost: beryllium-5C6A._hap._tcp.local\x0D\x0A\x0D\x0A" HomeKit: [Client 4] Get Accessories homekit_server_on_get_accessories: Free heap: 26932 client_send: [Client 4] Sending payload: HTTP/1.1 200 OK\x0D\x0AContent-Type: application/hap+json\x0D\x0ATransfer-Encoding: chunked\x0D\x0AConnection: keep-alive\x0D\x0A\x0D\x0A client_send: [Client 4] Sending payload: 3fe\x0D\x0A{"accessories":[{"aid":1,"services":[{"iid":1,"type":"3E","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":2,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"beryllium"},{"aid":1,"iid":3,"type":"20","perms":["pr"],"description":"Manufacturer","format":"string","value":"hermes-iot"},{"aid":1,"iid":4,"type":"30","perms":["pr"],"description":"Serial Number","format":"string","value":"037A2BABF19D"},{"aid":1,"iid":5,"type":"21","perms":["pr"],"description":"Model","format":"string","value":"hermes-beryllium"},{"aid":1,"iid":6,"type":"52","perms":["pr"],"description":"Firmware Revision","format":"string","value":"hermes-beryllium"},{"aid":1,"iid":7,"type":"14","perms":["pw"],"description":"Identify","format":"bool"}]},{"iid":8,"type":"49","hidden":false,"primary":true,"characteristics":[{"aid":1,"iid":9,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Relay 1"},{"aid":1,"iid":10,"type":"25","perms":["pr","pw","ev"],"ev":false,"description":"On",\x0D\x0A client_send: [Client 4] Sending payload: 3fe\x0D\x0A"format":"bool","value":false}]},{"iid":11,"type":"49","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":12,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Relay 2"},{"aid":1,"iid":13,"type":"25","perms":["pr","pw","ev"],"ev":false,"description":"On","format":"bool","value":false}]},{"iid":14,"type":"8A","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":15,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Temperature Sensor"},{"aid":1,"iid":16,"type":"11","perms":["pr","ev"],"ev":false,"description":"Current Temperature","format":"float","unit":"celsius","minValue":0,"maxValue":100,"minStep":0.100000001490116,"value":22.8999996185303}]},{"iid":17,"type":"82","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":18,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Humidity Sensor"},{"aid":1,"iid":19,"type":"10","perms":["pr","ev"],"ev":false,"description":"Current Relative Humidity","format":\x0D\x0A client_send: [Client 4] Sending payload: 196\x0D\x0A"float","unit":"percentage","minValue":0,"maxValue":100,"minStep":1,"value":33.5999984741211}]},{"iid":20,"type":"85","hidden":false,"primary":false,"characteristics":[{"aid":1,"iid":21,"type":"23","perms":["pr"],"description":"Name","format":"string","value":"Motion Sensor"},{"aid":1,"iid":22,"type":"22","perms":["pr","ev"],"ev":false,"description":"Motion Detected","format":"bool","value":false}]}]}]}\x0D\x0A client_send: [Client 4] Sending payload: 0\x0D\x0A\x0D\x0A homekit_client_process: [Client 4] Finished processing homekit_client_process: [Client 4] Got 312 incomming data homekit_client_process: [Client 4] Decrypting data homekit_client_process: [Client 4] Decrypted 294 bytes, available 0 Decrypted data (294 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: beryllium-5C6A._hap._tcp.local\x0D\x0AContent-Length: 166\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"ev":true},{"aid":1,"iid":13,"ev":true},{"aid":1,"iid":16,"ev":true},{"aid":1,"iid":19,"ev":true},{"aid":1,"iid":22,"ev":true}]}" HomeKit: [Client 4] Update Characteristics homekit_server_on_update_characteristics: Free heap: 26220 homekit_server_on_update_characteristics: [Client 4] Processing element { "aid": 1, "iid": 10, "ev": true } homekit_server_on_update_characteristics: [Client 4] Processing element { "aid": 1, "iid": 13, "ev": true } homekit_server_on_update_characteristics: [Client 4] Processing element { "aid": 1, "iid": 16, "ev": true } homekit_server_on_update_characteristics: [Client 4] Processing element { "aid": 1, "iid": 19, "ev": true } homekit_server_on_update_characteristics: [Client 4] Processing element { "aid": 1, "iid": 22, "ev": true } homekit_server_on_update_characteristics: [Client 4] There were no processing errors, sending No Content response client_send: [Client 4] Sending payload: HTTP/1.1 204 No Content\x0D\x0A\x0D\x0A homekit_client_process: [Client 4] Finished processing homekit_client_process: [Client 4] Got 312 incomming data homekit_client_process: [Client 4] Decrypting data homekit_client_process: [Client 4] Decrypted 294 bytes, available 0 Decrypted data (294 bytes): "PUT /characteristics HTTP/1.1\x0D\x0AHost: beryllium-5C6A._hap._tcp.local\x0D\x0AContent-Length: 166\x0D\x0AContent-Type: application/hap+json\x0D\x0A\x0D\x0A{"characteristics":[{"aid":1,"iid":10,"ev":true},{"aid":1,"iid":13,"ev":true},{"aid":1,"iid":16,"ev":true},{"aid":1,"iid":19,"ev":true},{"aid":1,"iid":22,"ev":true}]}" HomeKit: [Client 4] Update Characteristics homekit_server_on_update_characteristics: Free heap: 26120 homekit_server_on_update_characteristics: [Client 4] Processing element { "aid": 1, "iid": 10, "ev": true } homekit_server_on_update_characteristics: [Client 4] Processing element { "aid": 1, "iid": 13, "ev": true } homekit_server_on_update_characteristics: [Client 4] Processing element { "aid": 1, "iid": 16, "ev": true } homekit_server_on_update_characteristics: [Client 4] Processing element { "aid": 1, "iid": 19, "ev": true } homekit_server_on_update_characteristics: [Client 4] Processing element { "aid": 1, "iid": 22, "ev": true } homekit_server_on_update_characteristics: [Client 4] There were no processing errors, sending No Content response client_send: [Client 4] Sending payload: HTTP/1.1 204 No Content\x0D\x0A\x0D\x0A homekit_client_process: [Client 4] Finished processing [hermes-beryllium] [] homekitdht_data: homekit__dht_data: 23.0, 33.4 [hermes-beryllium] [] homekitdht_data: Free heap: 26524 client_notify_characteristic: Got characteri ets Jan 8 2013,rst cause:4, boot mode:(3,7)

wdt reset load 0x40100000, len 2292, room 16 tail 4 chksum 0x57 load 0x3ffe8000, len 772, room 4 tail 0 chksum 0x0b csum 0x0b `

maximkulkin commented 5 years ago

Can you show code of your motion detector?

emrahduruer commented 5 years ago

Sure. Not that I was having the problem without the motion detector as well.

homekit_value_t motion_get() {
    return HOMEKIT_BOOL(motion_detected);
}

homekit_characteristic_t motion = HOMEKIT_CHARACTERISTIC_(
    MOTION_DETECTED, false,
    .getter = motion_get);

...

HOMEKIT_SERVICE(MOTION_SENSOR,
                    .characteristics = (homekit_characteristic_t*[]) {
        HOMEKIT_CHARACTERISTIC(NAME, "Motion Sensor"),
        &motion,
        NULL
    }),

...

void homekit_gpi_callback(uint8_t gpio_num, gpi_event event, void* cprm) {

        if (event == gpi_event_activated) {
            DEBUG_PRINT("gpi_event_activated");
            motion_detected = true;
            homekit_characteristic_notify(&motion, HOMEKIT_BOOL(motion_detected));
        } else if (event == gpi_event_deactivated) {
            DEBUG_PRINT("gpi_event_deactivated");
            motion_detected = false;
            homekit_characteristic_notify(&motion, HOMEKIT_BOOL(motion_detected));
        }
    }

    register_digital_sensor(MOTION_SENSOR_PIN, HIGH, &homekit_gpi_callback, NULL);
maximkulkin commented 5 years ago

Ok, I do not see anything criminal here, but last reset that you showed was caused by watchdog, so maybe you're doing too much in an interrupt or something. It would help if you'd show the whole code.

emrahduruer commented 5 years ago

ok. here is the code where I control all my interrupts. This code is calling the callback funtion in the homekit code to notify the clients. DHT data changes is running in different task and calling another callback method in homekit code to notify.

#include <common.h>

#include <stdio.h>
#include <FreeRTOS.h>
#include <task.h>
#include <esp/gpio.h>
#include <gpi.h>
#include <timers.h>

digital_gpi *gpis = NULL;

static void gpi_intr_callback_tick(digital_gpi *gpi) {
    gpi->prev_on_state_time = 0;
    gpi->callback(gpi->gpio_num,
                  gpi_event_single_press, gpi->callback_param);
}

/* The callback function that will execute in the context of the daemon task.
Note callback functions must all use this same prototype. */
void vProcessInterface( void *pvParameter1, uint32_t ulParameter2 ) {

    uint8_t gpio = *((uint8_t*) pvParameter1);
    /* ...Perform the processing here... */
    digital_gpi *gpi = find_gpi_by_gpio_num(gpio);
    if (gpi == NULL) {
        return;
    }

    uint32_t now = xTaskGetTickCountFromISR();
    if ((now - gpi->last_event_time) * portTICK_PERIOD_MS <
        gpi->debounce_time) {
        // debounce time, ignore events
        return;
    }
    gpi->last_event_time = now;

    // Wait until the input changes...
    if (gpi->type == gpi_toggle_switch) {
        while(gpio_read(gpi->gpio_num) == gpi->last_state_value) {
        }
        gpi->last_state_value = gpio_read(gpi->gpio_num);
    }

    if (gpio_read(gpi->gpio_num) == gpi->on_state_value) {
        if (gpi->type == gpi_button) {
            gpi->prev_on_state_time = gpi->last_on_state_time;
        }
        gpi->last_on_state_time = now;

        if (gpi->type == gpi_digital_sensor) {
            // This is a sensor or any input...
            gpi->callback(gpi->gpio_num,
                          gpi_event_activated, gpi->callback_param);
        } else if (gpi->type == gpi_toggle_switch) {
            // This is a toggle switch...
            gpi->callback(gpi->gpio_num,
                          gpi_event_toggled_on, gpi->callback_param);
        }
    } else {
        if (gpi->type == gpi_button) {
            // This is a button...
            if (gpi->prev_on_state_time > 0 &&
                (gpi->last_on_state_time
                    - gpi->prev_on_state_time) * portTICK_PERIOD_MS <=
                DOUBLE_CLICK_TIME) {
                // Double click is detected.
                gpi->prev_on_state_time = 0;
                sdk_os_timer_disarm(&gpi->timer);
                gpi->callback(gpi->gpio_num,
                              gpi_event_double_press, gpi->callback_param);
            } else if (gpi->long_press_time > 0 && // If the long press time is set.
                    (now - gpi->last_on_state_time) * portTICK_PERIOD_MS >
                           gpi->long_press_time) {
                // Long press is detected.
                gpi->callback(gpi->gpio_num,
                              gpi_event_long_press, gpi->callback_param);
            } else {
                sdk_os_timer_arm(&gpi->timer, DOUBLE_CLICK_TIME + 50, 0);
            }
        } else if (gpi->type == gpi_toggle_switch) {
            // This is a toggle switch...
            gpi->callback(gpi->gpio_num,
                          gpi_event_toggled_off, gpi->callback_param);
        } else {
            // This is a sensor or any input...
            gpi->callback(gpi->gpio_num,
                          gpi_event_deactivated, gpi->callback_param);
        }
    }
}

void gpi_intr_callback(uint8_t gpio) {
    BaseType_t xHigherPriorityTaskWoken;

    xHigherPriorityTaskWoken = pdFALSE;
    xTimerPendFunctionCallFromISR(vProcessInterface,
                               &gpio,
                               NULL,
                               &xHigherPriorityTaskWoken);
    if (xHigherPriorityTaskWoken) {
        portYIELD();
    }
}

digital_gpi* register_gpi(uint8_t gpio_num,
                          gpi_type type,
                          int on_state_value,
                          gpi_callback cb, void* cb_param) {
    // If it is already registered, we just returned the register one.
    digital_gpi *gpi = find_gpi_by_gpio_num(gpio_num);
    if (gpi) {
        return gpi;
    }

    gpi = malloc(sizeof(digital_gpi));
    memset(gpi, 0, sizeof(*gpi));
    gpi->gpio_num = gpio_num;
    gpi->type = type;
    gpi->callback = cb;
    gpi->callback_param = cb_param;
    gpi->on_state_value = on_state_value;
    gpi->debounce_time = DEBOUNCE_TIME;

    gpi->last_state_value = gpio_read(gpi->gpio_num);
    uint32_t now = xTaskGetTickCountFromISR();
    gpi->last_event_time = now;
    gpi->last_on_state_time = now;

    if (type == gpi_button) {
        sdk_os_timer_setfn(&gpi->timer, (void (*)(void *))gpi_intr_callback_tick,
               gpi);
    }

    gpi->next = gpis;
    gpis = gpi;

    if (type == gpi_toggle_switch || type == gpi_digital_sensor) {
        gpio_enable(gpi->gpio_num, GPIO_INPUT);
    } else {
        gpio_set_pullup(gpi->gpio_num, true, true);
    }
    gpio_set_interrupt(gpi->gpio_num, GPIO_INTTYPE_EDGE_ANY,
               gpi_intr_callback);

    return gpi;
}

digital_gpi* register_button(uint8_t gpio_num,
                             int on_state_value,
                             uint16_t long_press_time,
                             gpi_callback cb, void* cb_param) {

    digital_gpi* gpi = register_gpi(gpio_num,
                                    gpi_button,
                                    on_state_value,
                                    cb, cb_param);
    if (gpi != NULL) {
        gpi->long_press_time = long_press_time;
    }
    return gpi;
}

digital_gpi* register_switch(uint8_t gpio_num,
                             int on_state_value,
                             gpi_callback cb, void* cb_param) {

    return register_gpi(gpio_num,
                        gpi_toggle_switch,
                        on_state_value,
                        cb, cb_param);
}

digital_gpi* register_digital_sensor(uint8_t gpio_num,
                                     int on_state_value,
                                     gpi_callback cb, void* cb_param) {

    return register_gpi(gpio_num,
                        gpi_digital_sensor,
                        on_state_value,
                        cb, cb_param);
}

digital_gpi* find_gpi_by_gpio_num(uint8_t gpio_num) {
    digital_gpi *gpi = gpis;
    while (gpi && gpi->gpio_num != gpio_num) {
        gpi = gpi->next;
    }
    return gpi;
}
emrahduruer commented 5 years ago

After you told me about the interrupt, while I am checking my code, I realized that in fact, the problem was the DHT data notifications.

Thank you for your quick responses.

maximkulkin commented 5 years ago

Consider it closed? Would you mind sharing your findings so that other can benefit?