8 accessories initialized force the 1st one to be considered as a Hub/HomeBridge

simkard69 commented 9 months ago

Hello,

I had to do some tweaks to the library in order to be able to initialize more than 7 accessories at the same time. While initializing 8, HomeKit UI considers the 1st one (the main accessory) as a Hub/HomeBridge and avoids using its services. Moreover, client gets disconnected and updating whatever value on whatever accessory fails the 1st time and needs to be updated again. Here is an output of what is happening (notice the timestamps) :

19:19:14.750 -> >>> HomeKit: [Client 49] Closing client connection          // This is not happening when using 7 accessories
19:19:18.257 -> >>> HomeKit: Got new client connection: 49
19:19:18.257 -> >>> HomeKit: [Client 49] Pair Verify Step 1/2
19:19:18.289 -> >>> HomeKit: [Client 49] Pair Verify Step 2/2
19:19:18.332 -> >>> HomeKit: [Client 49] Found pairing with 808FF924-3E08-4301-9626-58130226B6E1
19:19:18.332 -> >>> HomeKit: [Client 49] Verification successful, secure session established
19:19:18.379 -> >>> HomeKit: [Client 49] Get Accessories
19:19:18.443 -> >>> HomeKit: [Client 49] Get Characteristics
19:19:18.443 -> >>> HomeKit: [Client 49] Update Characteristics
19:19:18.443 -> >>> HomeKit: [Client 49] Update Characteristics
19:19:18.443 -> >>> HomeKit: [Client 49] Update Characteristics
19:19:18.475 -> >>> HomeKit: [Client 49] Update Characteristics
19:19:18.475 -> >>> HomeKit: [Client 49] Update Characteristics
19:19:18.475 -> >>> HomeKit: [Client 49] Update Characteristics
19:19:18.475 -> >>> HomeKit: [Client 49] Update Characteristics
19:19:23.539 -> >>> HomeKit: [Client 49] Closing client connection          // This is not happening when using 7 accessories

Can anyone please help me out on that one ? @Yurik72 ? Thanks !

simkard69 commented 9 months ago

Tried modding values from "arduino_homekit_server.cpp" file : FROM

#define HOMEKIT_MAX_CLIENTS  8
#define CLIENT_CONTEXT_CACHE_SIZE 8

TO

#define HOMEKIT_MAX_CLIENTS  12
#define CLIENT_CONTEXT_CACHE_SIZE 12

Didn't helped so far, am I using too many accessories ?

Yurik72 commented 9 months ago

Hello usually this happens if compilation setting lwIP is not valid According to doc ! Note for ESP8266 boards select lwIP Variant :v2 High bandwidth. Device behaviours is more stable especially in pairing process

simkard69 commented 9 months ago

Hello @Yurik72 and thanks for your answer. I'm using an ESP32, not an ESP8266. So I really don't know what is happening here. Trying to compile with DEBUG MODE enabled to see if I can gather additionnal reasons of why this is happening.

Yurik72 commented 9 months ago

This happens if tcp stack overfull. usually not happening on ESP32, therefore i thinking about ESP8266. I meet couple of times when debugging. and didn't catch how to improve. after reboot esp. usually disappears

simkard69 commented 9 months ago

With Core debug level set to DEBUG at compilation time, I just get nothing more in the console's output :

14:10:47.482 -> [ 18043][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 12 - AP_STACONNECTED
14:10:47.652 -> [ 18212][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 14 - AP_STAIPASSIGNED
14:10:58.731 -> >>> HomeKit: Got new client connection: 49
14:10:58.731 -> >>> HomeKit: [Client 49] Pair Setup 
14:10:58.731 -> >>> HomeKit: [Client 49] Pair Setup Step 1/3
14:10:58.731 -> >>> HomeKit: [Client 49] new pairing content
14:10:58.731 -> >>> HomeKit: started crypto
14:10:58.731 -> >>> HomeKit: Free heap: 106488
14:11:00.361 -> >>> HomeKit: Calculating public key len=384
14:11:01.203 -> >>> HomeKit: Calculating public key result 0
14:11:01.203 -> >>> HomeKit: [Client 49] send_tlv_response
14:11:01.203 -> >>> HomeKit: [Client 49] send_tlv_response done
14:11:07.590 -> >>> HomeKit: [Client 49] Pair Setup 
14:11:07.590 -> >>> HomeKit: [Client 49] Pair Setup Step 2/3
14:11:10.577 -> >>> HomeKit: [Client 49] Pair Setup 
14:11:10.577 -> >>> HomeKit: [Client 49] Pair Setup Step 3/3
14:11:10.577 -> [HAP]   Storage changed ... Success (File created) + (File written)
14:11:10.851 -> >>> HomeKit: Added pairing with 808FF924-3E08-4301-9626-58130226B6E1
14:11:10.892 -> >>> HomeKit: Configuring mDNS
14:11:10.892 -> >>> HomeKit: [Client 49] Successfully paired
14:11:10.970 -> >>> HomeKit: [Client 49] Closing client connection
14:11:11.015 -> >>> HomeKit: Got new client connection: 49
14:11:11.015 -> >>> HomeKit: [Client 49] Pair Verify Step 1/2
14:11:11.092 -> >>> HomeKit: [Client 49] Pair Verify Step 2/2
14:11:11.093 -> >>> HomeKit: [Client 49] Found pairing with 808FF924-3E08-4301-9626-58130226B6E1
14:11:11.093 -> >>> HomeKit: [Client 49] Verification successful, secure session established
14:11:11.125 -> >>> HomeKit: [Client 49] Get Accessories
14:11:11.388 -> >>> HomeKit: [Client 49] Update Characteristics
14:11:11.422 -> >>> HomeKit: [Client 49] Update Characteristics
14:11:11.422 -> >>> HomeKit: [Client 49] Update Characteristics
14:11:11.465 -> >>> HomeKit: [Client 49] Update Characteristics
14:11:11.465 -> >>> HomeKit: [Client 49] Update Characteristics
14:11:11.465 -> >>> HomeKit: [Client 49] Update Characteristics
14:11:11.465 -> >>> HomeKit: [Client 49] Update Characteristics
14:11:11.497 -> >>> HomeKit: [Client 49] Update Characteristics
14:11:11.497 -> >>> HomeKit: [Client 49] Update Characteristics
14:11:11.497 -> >>> HomeKit: [Client 49] Update Characteristics
14:11:11.497 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.531 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.531 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.564 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.564 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.564 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.564 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.651 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.651 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.651 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.688 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.688 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.688 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.725 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.725 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.759 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.759 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.759 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.830 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.830 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.830 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.867 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.867 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.899 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.944 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.944 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.944 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:11.978 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:12.020 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:12.020 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:12.020 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:12.067 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:12.202 -> >>> HomeKit: [Client 49] Get Characteristics
14:11:17.428 -> >>> HomeKit: [Client 49] Closing client connection

What is supposed to engage a "Closing client connection" ? Is this one of the functions contained in "arduino_homekit_server.cpp" file ?

simkard69 commented 9 months ago

Tried with Core debug level set to VERBOSE : Nothing new :( What I've tried :

Paired the device and all its accessories (with Base/Main accessory considered as a Bridge)
Once pairing ends, 5 seconds after last communication from iOS device to the ESP32, I get the infamous line : ">>> HomeKit: [Client 49] Closing client connection"
Rebooted the ESP32 and tried to send a command which did not worked at first, then I sent another and it worked.
Tried to send multiple commands subsequently without waiting until the 5 seconds : worked fine without any problem
Waited 5 seconds and got the message again : ">>> HomeKit: [Client 49] Closing client connection"

I just don't understand what is happening here ...

Yurik72 commented 9 months ago

Regarding 5. In my memory this is OK, Apple can close connection after paired. Than it should opened again. If it brings any trouble ?

simkard69 commented 9 months ago

The infamous ">>> HomeKit: [Client 49] Closing client connection" absolutely doesn't happen when having only 3-5 accessories. But as soon as we have 6/7 devices : it starts to show.

Having 8 or more accessories initialized makes the UI on HomeKit recognizes the first one as a Hub/Bridge.

At some point, I may try the HomeSpan library just to see if it acts the same.

simkard69 commented 9 months ago

@Yurik72 : Just te be sure of something, I tried to initialize as this :

1 main/Base accessory with 6 services
5 additional accessories

Everything working fine and got absolutely no closing connection message at some point ... even waiting for some minutes. Instead, I get the "Get Characteristics" message showing up approximatively every minute :

14:36:54.761 -> >>> HomeKit: [Client 49] Get Characteristics
14:37:55.660 -> >>> HomeKit: [Client 49] Get Characteristics
14:38:56.683 -> >>> HomeKit: [Client 49] Get Characteristics
14:39:57.700 -> >>> HomeKit: [Client 49] Get Characteristics

This is definitely driving me crazy.

simkard69 commented 9 months ago

Pretty sure it is this damn "bridge" thing that is enabling itself automatically at some point when using 8 accessories or more on the same device. Any chance there is a parameter/function that avoids the device of being considered as a bridge ?

simkard69 commented 9 months ago

@Yurik72 : Just te be sure of something, I tried to initialize as this :

1 main/Base accessory with 6 services

5 additional accessories

Everything working fine and got absolutely no closing connection message at some point ... even waiting for some minutes. Instead, I get the "Get Characteristics" message showing up approximatively every minute :

14:36:54.761 -> >>> HomeKit: [Client 49] Get Characteristics

14:37:55.660 -> >>> HomeKit: [Client 49] Get Characteristics

14:38:56.683 -> >>> HomeKit: [Client 49] Get Characteristics

14:39:57.700 -> >>> HomeKit: [Client 49] Get Characteristics

This is definitely driving me crazy.

FYI @Yurik72 : I've just tried with these settings and got it 100% working :

1 main/Base accessory with 2 services (strangely 1st one is not shown ... but I don't have the BRIDGE thing showing up this time on HomeKit UI on iOS device // pretty sure my initial problem root cause was the BRIDGE thing here being autodetected for an unknown reason)
9 additional accessories

STATUS >>> 100% working ... this is driving me nuts but I'll use it like that as ... so far it is the only working solution I have

simkard69 commented 9 months ago

Interesting informations around the BRIDGE thing that might be helpful at some point : isBridged | Apple Developer Documentation

simkard69 commented 9 months ago

Well I can't understand some things here.

Did a lot of tests and here are some results :

With 2 SERVICES on BASE ACCESSORY + 4 additionnal ACCESSORIES >>> IOS UI shows 2 ACCESSORIES on MAIN + 4 ACC >>> OK except first two are necessarily in the same room
With 2 SERVICES on BASE ACCESSORY + 6 additionnal ACCESSORIES >>> IOS UI shows 2 ACCESSORIES on MAIN + 6 ACC >>> OK except first two are necessarily in the same room
With 1 SERVICE on BASE ACCESSORY + 7 additionnal ACCESSORIES >>> IOS UI considers BRIDGE MODE, only 7 additionnal ACCESSORIES are available and can be separated into multiple rooms BUT the infamous "Closing client connection" happens
With 0 SERVICE on BASE ACCESSORY + 7 additionnal ACCESSORIES >>> IOS UI does not show any HomeKit device at time of detection (before pairing)
With 2 SERVICES on BASE ACCESSORY + 10 additionnal ACCESSORIES >>> IOS UI shows 2nd SERVICE on MAIN + 10 additionnal ACCESSORIES + no infamous "Closing client connection" after some seconds of idling + 1st SERVICE from BASE ACCESSORY is not shown at all
With 2 SERVICES on BASE ACCESSORY + 14 additionnal ACCESSORIES >>> IOS UI considers BRIDGE MODE, no SERVICES from MAIN + 14 additionnal ACCESSORIES + Infamous "Closing client connection" happens after some seconds of idling

I'm considering modifying the library in order to be able to declare MAIN ACCESSORY unique SERVICE as a BRIDGE and then, initializing every single service as additionnal accessories.

@Yurik72 : What would be your advice here ? do you have any input on this situation ? Thanks

At time of initialization, I'm using :

hap_setbase_accessorytype(homekit_accessory_category_window_covering);
hap_initbase_accessory_service("HOSTNAME", "MANUFACTURER", "SERIALNUMBER", "MODEL", "FIRMWAREVERSION");
HomeKit_Svc_SVC0   = hap_add_windowcovering_service("SVC0",   HAP_SVC0_update,   0);
HomeKit_Svc_ACC2  = hap_add_windowcovering_as_accessory(homekit_accessory_category_window_covering, "ACC2",  HAP_ACC2_update,   0);

Yurik72 / ESPHap

8 accessories initialized force the 1st one to be considered as a Hub/HomeBridge #141