search

Yurik72 / ESPHap

ESP32/ESP8266 Arduino library for native Apple Homekit Accessory Protocol (HAP)
MIT License
265 stars 60 forks source link

ESP01s (esp8266) & IOS14.4 - Device not responding after restart #51

Closed Ceda closed 3 years ago

Ceda commented 3 years ago

Hi, just trying new release 1.7, and pairing work better then in older release, but not every try.. Now I'm experimenting with RGB motion example.. After success pairing device work, but after restart i can't reconnect and device not responding.

Looks like problem in older release, after Pair Verify Step is disconnected.

Thx for help and great project! I use on few devices original Maxim project and looking for alternative which offers more and simpler use third party libs and it is your project.. ;)

Log after restart... 

>>> HomeKit: find pairings
>>> HomeKit: Preinit pairing context
>>> HomeKit: Using user-specified password: 111-11-111
>>> HomeKit: Free heap: 30320
>>> HomeKit: Calculating public key len=384
>>> HomeKit: Calculating public key result 0
>>> HomeKit: arduino_homekit_preinit success
>>> HomeKit: Configuring mDNS
>>> HomeKit: MDNS.begin: ES-AFC4, IP: 192.168.0.115
>>> HomeKit: Init server over
Web server is NOT SET, waiting for pairing
>>> HomeKit: WiFiServer receives a new client (current 0, max 4)
>>> HomeKit: Got new client connection: local 192.168.0.115:5556, remote 192.168.0.106:51444
>>> HomeKit: [Client 1073692772] Got 158 incomming data, encrypted is 
>>> HomeKit: [Client 1073692772] Pair Verify Step 1/2
>>> HomeKit: Free heap: 25760
>>> HomeKit: [Client 1073692772] Disconnected!
>>> HomeKit: Free heap: 26064
>>> HomeKit: [Client 1073692772] Closing client connection

Full log

IP address: 
192.168.0.115
>>> Home Integration: homekit_is_paired 0
>>> HomeKit: Update the CPU to run at 160MHz
>>> HomeKit: Free heap: 32944
>>> HomeKit: Starting server
>>> HomeKit: Formatting flash at 0x200000
Failed to open pair.dat
>>> HomeKit: storage init 1
>>> HomeKit: if r
>>> HomeKit: generating id
>>> HomeKit: Generated new accessory ID: 72:21:DB:65:BD:82
>>> HomeKit: Generated new accessory ID: 1073686756
>>> HomeKit:  key generated
Failed to open pair.dat
>>> HomeKit:  key saved
>>> HomeKit: Generated new accessory key
Failed to open pair.dat
>>> HomeKit: find pairings
>>> HomeKit: Preinit pairing context
>>> HomeKit: Using user-specified password: 111-11-111
>>> HomeKit: Free heap: 30320
>>> HomeKit: Calculating public key len=384
>>> HomeKit: Calculating public key result 0
>>> HomeKit: arduino_homekit_preinit success
>>> HomeKit: Configuring mDNS
>>> HomeKit: MDNS.begin: ES-3AAF, IP: 192.168.0.115
>>> HomeKit: Init server over
Web server is NOT SET, waiting for pairing
>>> HomeKit: WiFiServer receives a new client (current 0, max 4)
>>> HomeKit: Got new client connection: local 192.168.0.115:5556, remote 192.168.0.193:50082
>>> HomeKit: [Client 1073694964] Got 125 incomming data, encrypted is 
>>> HomeKit: [Client 1073694964] Pair Setup Step 1/3
>>> HomeKit: [Client 1073694964] Got 536 incomming data, encrypted is 
>>> HomeKit: [Client 1073694964] Got 42 incomming data, encrypted is 
>>> HomeKit: [Client 1073694964] Pair Setup Step 2/3
>>> HomeKit: [Client 1073694964] Computing SRP shared secret
>>> HomeKit: [Client 1073694964] Verifying peer's proof
>>> HomeKit: [Client 1073694964] Generating own proof
>>> HomeKit: [Client 1073694964] Got 280 incomming data, encrypted is 
>>> HomeKit: [Client 1073694964] Pair Setup Step 3/3
Failed to open pair.dat
>>> HomeKit: Added pairing with E5D14223-5021-47D6-BE9A-A9F83244461E
>>> HomeKit: Free saved_preinit_pairing_context
>>> HomeKit: Configuring mDNS
>>> HomeKit: MDNS.restart: ES-3AAF, IP: 192.168.0.115
>>> HomeKit: MDNS.begin: ES-3AAF, IP: 192.168.0.115
>>> HomeKit: [Client 1073694964] Successfully paired
>>> HomeKit: [Client 1073694964] Disconnected!
>>> HomeKit: Free heap: 29448
>>> HomeKit: [Client 1073694964] Closing client connection
>>> HomeKit: WiFiServer receives a new client (current 0, max 4)
>>> HomeKit: Got new client connection: local 192.168.0.115:5556, remote 192.168.0.193:50083
>>> HomeKit: [Client 1073696828] Got 158 incomming data, encrypted is 
>>> HomeKit: [Client 1073696828] Pair Verify Step 1/2
>>> HomeKit: Free heap: 28448
>>> HomeKit: [Client 1073696828] Got 247 incomming data, encrypted is 
>>> HomeKit: [Client 1073696828] Pair Verify Step 2/2
>>> HomeKit: [Client 1073696828] Found pairing with E5D14223-5021-47D6-BE9A-A9F83244461E
>>> HomeKit: [Client 1073696828] Verification successful, secure session established
>>> HomeKit: Free heap: 27936
>>> HomeKit: [Client 1073696828] Got 78 incomming data, encrypted is 
>>> HomeKit: [Client 1073696828] Get Accessories
>>> HomeKit: [Client 1073696828] Got 276 incomming data, encrypted is 
>>> HomeKit: [Client 1073696828] Update Characteristics
>>> HomeKit: [Client 1073696828] Got 276 incomming data, encrypted is 
>>> HomeKit: [Client 1073696828] Update Characteristics
>>> HomeKit: [Client 1073696828] Got 276 incomming data, encrypted is 
>>> HomeKit: [Client 1073696828] Update Characteristics
>>> HomeKit: [Client 1073696828] Got 217 incomming data, encrypted is 
>>> HomeKit: [Client 1073696828] Add Pairing
Failed to open pair.dat
>>> HomeKit: Added pairing with 77EEB1B3-18E7-4D24-B316-DA56AA8627A6
>>> HomeKit: [Client 1073696828] Got 217 incomming data, encrypted is 
>>> HomeKit: [Client 1073696828] Add Pairing
Failed to open pair.dat
>>> HomeKit: Added pairing with F1C852ED-F707-4363-89A4-C05CBBEA1A6C
>>> HomeKit: WiFiServer receives a new client (current 1, max 4)
>>> HomeKit: Got new client connection: local 192.168.0.115:5556, remote 192.168.0.138:54779
>>> HomeKit: [Client 1073695316] Got 158 incomming data, encrypted is 
>>> HomeKit: [Client 1073695316] Pair Verify Step 1/2
>>> HomeKit: Free heap: 25760
>>> HomeKit: [Client 1073695316] Got 247 incomming data, encrypted is 
>>> HomeKit: [Client 1073695316] Pair Verify Step 2/2
>>> HomeKit: [Client 1073695316] Found pairing with E5D14223-5021-47D6-BE9A-A9F83244461E
>>> HomeKit: [Client 1073695316] Verification successful, secure session established
>>> HomeKit: Free heap: 25696
>>> HomeKit: [Client 1073695316] Got 78 incomming data, encrypted is 
>>> HomeKit: [Client 1073695316] Get Accessories
>>> HomeKit: [Client 1073695316] Got 276 incomming data, encrypted is 
>>> HomeKit: [Client 1073695316] Update Characteristics
>>> HomeKit: [Client 1073695316] Got 89 incomming data, encrypted is 
>>> HomeKit: [Client 1073695316] Get Characteristics
>>> HomeKit: [Client 1073695316] Got 105 incomming data, encrypted is 
>>> HomeKit: [Client 1073695316] Get Characteristics
>>> HomeKit: [Client 1073696828] Got 90 incomming data, encrypted is 
>>> HomeKit: [Client 1073696828] Get Characteristics
>>> HomeKit: [Client 1073696828] Got 100 incomming data, encrypted is 
>>> HomeKit: [Client 1073696828] Get Characteristics
rll⸮⸮|⸮l⸮|⸮l⸮b|⸮⸮⸮⸮r⸮b⸮b⸮⸮nn⸮lnn⸮⸮⸮bp⸮lrlrlp⸮n⸮⸮l⸮⸮bn⸮|⸮l⸮⸮b⸮⸮nn⸮l⸮⸮l`⸮nnl`nr⸮⸮⸮nbl`r⸮⸮nbl`⸮b⸮⸮lr⸮`⸮⸮n⸮SPIFFS Mount failedFree heap: 35832
init_hap_storageFailed to read pair.dat
>>> HomeKit: init_storage_ex size 0x1c1
>>> Home Integration: hap_services added chararacteristic  0: 23 
>>> Home Integration: hap_services added chararacteristic  1: 25 
>>> Home Integration: hap_services added chararacteristic  2: 8 
>>> Home Integration: hap_services added chararacteristic  3: 13 
>>> Home Integration: hap_services added chararacteristic  4: 2F 
..............WiFi connected
IP address: 
192.168.0.115
>>> Home Integration: homekit_is_paired 0
>>> HomeKit: Update the CPU to run at 160MHz
>>> HomeKit: Free heap: 32944
>>> HomeKit: Starting server
>>> HomeKit: Formatting flash at 0x200000
Failed to open pair.dat
>>> HomeKit: storage init 1
>>> HomeKit: if r
>>> HomeKit: generating id
>>> HomeKit: Generated new accessory ID: 1F:9B:24:5F:76:89
>>> HomeKit: Generated new accessory ID: 1073692052
>>> HomeKit:  key generated
Failed to open pair.dat
>>> HomeKit:  key saved
>>> HomeKit: Generated new accessory key
Failed to open pair.dat
>>> HomeKit: find pairings
>>> HomeKit: Preinit pairing context
>>> HomeKit: Using user-specified password: 111-11-111
>>> HomeKit: Free heap: 30320
>>> HomeKit: Calculating public key len=384
>>> HomeKit: Calculating public key result 0
>>> HomeKit: arduino_homekit_preinit success
>>> HomeKit: Configuring mDNS
>>> HomeKit: MDNS.begin: ES-AFC4, IP: 192.168.0.115
>>> HomeKit: Init server over
Web server is NOT SET, waiting for pairing
>>> HomeKit: WiFiServer receives a new client (current 0, max 4)
>>> HomeKit: Got new client connection: local 192.168.0.115:5556, remote 192.168.0.106:51444
>>> HomeKit: [Client 1073692772] Got 158 incomming data, encrypted is 
>>> HomeKit: [Client 1073692772] Pair Verify Step 1/2
>>> HomeKit: Free heap: 25760
>>> HomeKit: [Client 1073692772] Disconnected!
>>> HomeKit: Free heap: 26064
>>> HomeKit: [Client 1073692772] Closing client connection
JohnWickham commented 3 years ago

Seeing the same thing; pairing is much improved, but doesn't persist after reboot. I think this may be a regression in 1.0.7

Yurik72 commented 3 years ago

Ok, Firts will answer for the original issue from Ceda. In the provided logs I'm clearly see that problem is related to store pairing information into the pair.dat

Failed to open pair.dat
>>> HomeKit:  key saved
>>> HomeKit: Generated new accessory key
Failed to open pair.dat

Means that ESP can't write file and defintelly that reason is problem to keep pairing information So my suggestion is check compilation setting. For instance correct are:

ESP8266 v2.7.4 (in Boards Manager) Board: NodeMCU 1.0 (ESP-12E Module) - Note, this is a NodeMCU v1.0 Rev2.0 (192.168.1.155) CPU Freq: 120MHz Flash Size: 4MB (FS:2MB oTA:~1019KB) Debug port: Disabled Debug level: None IwIP Variant: v2 Higher Bandwidth VTables: Flash Exceptions: Legacy (new can return nullptr) Erase Flash: Only Sketch

Than check why you can't write/read from the SPIFFS. This are basic things and not exactly related to the library ASs well you can provide me a full sketch which you are trying to use

Yurik72 commented 3 years ago

Seeing the same thing; pairing is much improved, but doesn't persist after reboot. I think this may be a regression in 1.0.7

Hello , could you provide me a sketch which are reproduciong that. v1.0.7 doesn't contain any changes to keepm pairing. But definetelly i will check

Ceda commented 3 years ago

Ok, Firts will answer for the original issue from Ceda. In the provided logs I'm clearly see that problem is related to store pairing information into the pair.dat

Failed to open pair.dat
>>> HomeKit:  key saved
>>> HomeKit: Generated new accessory key
Failed to open pair.dat

Means that ESP can't write file and defintelly that reason is problem to keep pairing information So my suggestion is check compilation setting. For instance correct are:

ESP8266 v2.7.4 (in Boards Manager) Board: NodeMCU 1.0 (ESP-12E Module) - Note, this is a NodeMCU v1.0 Rev2.0 (192.168.1.155) CPU Freq: 120MHz Flash Size: 4MB (FS:2MB oTA:~1019KB) Debug port: Disabled Debug level: None IwIP Variant: v2 Higher Bandwidth VTables: Flash Exceptions: Legacy (new can return nullptr) Erase Flash: Only Sketch

Than check why you can't write/read from the SPIFFS. This are basic things and not exactly related to the library ASs well you can provide me a full sketch which you are trying to use

Hi, thanks for reply... Trying change board settings and didn't help :/ Still can't write/open pair.dat

Board settings:

Screenshot 2021-02-14 at 15 25 52

Sketch: EspHap_RGB_Motion.ino.zip

Yurik72 commented 3 years ago

Ok, Let's try one of the following

  1. After lines 
    
if (!SPIFFS.begin()) {
#endif
   Serial.print("SPIFFS Mount failed");
}

Insert 
```c
if (SPIFFS.format())
{
Serial.print("SPIFFS FORMATTED");
}

Than try to execute sketch one time and see a result, in case of sucess formating you need remove those lines and use ESP

  1. Try to upload any small file within ESP8266 Sketch Data Upload, it should as well make a format
Ceda commented 3 years ago

Ok, Let's try one of the following

  1. After lines
if (!SPIFFS.begin()) {
#endif
       Serial.print("SPIFFS Mount failed");
  }

Insert

if (SPIFFS.format())
{
Serial.print("SPIFFS FORMATTED");
}

Than try to execute sketch one time and see a result, in case of sucess formating you need remove those lines and use ESP

  1. Try to upload any small file within ESP8266 Sketch Data Upload, it should as well make a format

Just trying ESP8266 Sketch data upload and find pairing is successful. Thanks for help 👍 

>>> HomeKit: Using existing accessory ID: 8B:32:F6:A8:2C:59
>>> HomeKit: find pairings
>>> HomeKit: Found admin pairing with E5D14223-5021-47D6-BE9A-A9F83244461E, disabling pair setup
Ceda commented 3 years ago

But pairing on esp8266 still not work ideally :/ After delete pairing file trought filebrowse, next pairing is ok..

>>> HomeKit: Got new client connection: local 192.168.0.115:5556, remote 192.168.0.193:50842
>>> HomeKit: [Client 1073694852] Got 129 incomming data, encrypted is 
>>> HomeKit: [Client 1073694852] Pair Setup Step 1/3
>>> HomeKit: [Client 1073694852] Got 582 incomming data, encrypted is 
>>> HomeKit: [Client 1073694852] Pair Setup Step 2/3
>>> HomeKit: [Client 1073694852] Computing SRP shared secret
>>> HomeKit: [Client 1073694852] Verifying peer's proof
>>> HomeKit: [Client 1073694852] Generating own proof
>>> HomeKit: [Client 1073694852] Got 284 incomming data, encrypted is 
>>> HomeKit: [Client 1073694852] Pair Setup Step 3/3
>>> HomeKit: Added pairing with E5D14223-5021-47D6-BE9A-A9F83244461E
>>> HomeKit: Free saved_preinit_pairing_context
>>> HomeKit: Configuring mDNS
>>> HomeKit: MDNS.restart: EspLed-E64C, IP: 192.168.0.115
>>> HomeKit: MDNS.begin: EspLed-E64C, IP: 192.168.0.115
>>> HomeKit: [Client 1073694852] Successfully paired
>>> HomeKit: [Client 1073694852] Disconnected!
>>> HomeKit: Free heap: 29392
>>> HomeKit: [Client 1073694852] Closing client connection
>>> HomeKit: WiFiServer receives a new client (current 0, max 4)
>>> HomeKit: Got new client connection: local 192.168.0.115:5556, remote 192.168.0.193:50843
>>> HomeKit: [Client 1073694884] Got 162 incomming data, encrypted is 
>>> HomeKit: [Client 1073694884] Pair Verify Step 1/2
>>> HomeKit: Free heap: 27888
>>> HomeKit: [Client 1073694884] Got 251 incomming data, encrypted is 
>>> HomeKit: [Client 1073694884] Pair Verify Step 2/2
>>> HomeKit: [Client 1073694884] Found pairing with E5D14223-5021-47D6-BE9A-A9F83244461E
>>> HomeKit: [Client 1073694884] Verification successful, secure session established
>>> HomeKit: Free heap: 27824
>>> HomeKit: [Client 1073694884] Disconnected!
>>> HomeKit: Free heap: 29752
>>> HomeKit: [Client 1073694884] Closing client connection
Yurik72 commented 3 years ago

But pairing on esp8266 still not work ideally :/ After delete pairing file trought filebrowse, next pairing is ok..

Looks you are using wrong version . Pairing bug is fixed in #37 , commit But pairing on esp8266 still not work ideally :/ After delete pairing file trought filebrowse, next pairing is ok..

check commit https://github.com/Yurik72/ESPHap/commit/8d7a33d2a30e701cc5f7e0329db8abde7ca6bd3e In your logs i do not see those changes Due to

HomeKit: Configuring mDNS HomeKit: MDNS.restart: EspLed-E64C, IP: 192.168.0.115 HomeKit: MDNS.begin: EspLed-E64C, IP: 192.168.0.115 HomeKit: [Client 1073694852] Successfully paired

Mdn is trying init again... Please make sure that you have right version

Ceda commented 3 years ago

But pairing on esp8266 still not work ideally :/ After delete pairing file trought filebrowse, next pairing is ok..

Looks you are using wrong version . Pairing bug is fixed in #37 , commit But pairing on esp8266 still not work ideally :/ After delete pairing file trought filebrowse, next pairing is ok..

check commit 8d7a33d In your logs i do not see those changes Due to

HomeKit: Configuring mDNS HomeKit: MDNS.restart: EspLed-E64C, IP: 192.168.0.115 HomeKit: MDNS.begin: EspLed-E64C, IP: 192.168.0.115 HomeKit: [Client 1073694852] Successfully paired

Mdn is trying init again... Please make sure that you have right version

It is strange. I am on master.

commit e59cab2e84cce987d8167679e513e016edee3689 (HEAD -> master, upstream/master, origin/master)
Author: yurik972 <yurik.kovalenko@gmail.com>
Date:   Fri Feb 12 15:04:56 2021 +0200

    small fixes

commit 3d69c496c111ae782291e1fcf5de2ac0d6407237
Author: yurik972 <yurik.kovalenko@gmail.com>
Date:   Thu Feb 11 19:03:32 2021 +0200

    typo
Yurik72 commented 3 years ago

Very strange, just checked twice and paired without any problem Latest commit is https://github.com/Yurik72/ESPHap/commit/148660a97d0128aa96dfd76c4849d7af0b9fc9f1

Send me a log pls

Ceda commented 3 years ago

I apologize for the confusion, i just update repo, but not library in arduino folder... Now pairing work great... Many thanks and closing issue...

JohnWickham commented 3 years ago

Seeing the same thing; pairing is much improved, but doesn't persist after reboot. I think this may be a regression in 1.0.7

Hello , could you provide me a sketch which are reproduciong that. v1.0.7 doesn't contain any changes to keepm pairing. But definetelly i will check

Follow up: I re-installed the library, I'm no longer having this issue! Not sure if I was mistakenly using an outdated version or something.