Multiple S30s in sibling mode cause messagePump unknown SenderId/SystemId

[ziz480]

First of all, thank you for all your work here!

I keep seeing the following error message in my HA logs - it's being emitted every second (sometimes 2x/sec).

2022-05-16 07:12:25 ERROR (MainThread) [lennoxs30api.s30api_async] messagePump unknown SenderId/SystemId [KL21xxxxxx]

The ID at the end has been redacted. I see two distinct ID's which I assume correspond to my thermostats/systems.

Browsing through your codebase I think this is coming from the cloud API component, but I'm not using the cloud connection so not understanding why I see the error. I have the integration connecting to my thermostats locally and everything seems to be stable (with the exception of this error).

Anyone else seeing this?

[PeteRager]

That's interesting, never seen that before.

What model thermostats do you have?

Let's capture the message logs. Go into configuration for each integration select the option to log messages to a file, give it a unique file name like "s30_message_connecition_1.log" (and a different one for the second), reload or restart the integration.

Upload those and/or search through them. I'd like to see both Good and Bad messages. If the redaction is hiding the sender Ids, there is an option to turn that off. But don't post the un-redacted log file as it does have personal info. If needed you can email to me.

[PeteRager]

And grab the software version running on the thermo. That should be in the lennox30.state objects.

softwareVersion: 3.81.207

[PeteRager]

I'm pretty sure you'll need to remove the redaction by enabling the "Personal Info in log file"

Here's an example from my logfile. The SenderID for local connections is always LCC - except in your case. Would be good to see if some message have LCC and other have the KL21xxxx and what the content of those KL21* messages are.

    "messages": [
        {
            "MessageId": 0,
            "SenderID": "LCC",
            "TargetID": "ha_prod",
            "MessageType": "PropertyChange",
            "Data": {
                "system": {
                    "status": {
                        "outdoorTemperatureStatus": "good",
                        "outdoorTemperature": 77,
                        "outdoorTemperatureC": 25
                    },
                    "publisher": {
                        "publisherName": "lcc"
                    }
                }
            }
        }
    ]
}

[ziz480]

I have two S30 thermostats with softwareVersion 3.70.212
The hubs have control software version 03.81.0777
Running v0.2.5 of this integration on HA 2022.5.3.

The log gets interesting right off the bat:

2022-05-16 19:48:58,899 [MainThread  ] [DEBUG]  {
    "messages": [
        {
            "MessageId": 0,
            "SenderID": "LCC",
            "TargetID": "homeassistant",
            "MessageType": "PropertyChange",
            "Data": {
                "siblings": [
                    {
                        "publisher": {
                            "publisherName": "lcc"
                        },
                        "id": 0,
                        "selfIdentifier": "KL21xxxxx1",
                        "sibling": {
                            "identifier": "KL21xxxxx2",
                            "systemName": "\"Bedrooms\"",
                            "nodePresent": true,
                            "portNumber": 443,
                            "groupCountTracker": true,
                            "ipAddress": "x.y.z.x"
                        }
                    }
                ]
            }
        }
    ]
}

I noticed the KL IDs actually correspond to my smart hub serial numbers and this message block suggests there's some type of group/sibling configuration between the thermostats. They are definitely aware of each other, and I can access both temperature settings on both tstats (I can swipe left/right on the main screen to flip between them). I don't think this was anything the installer set up for me explicitly but I can check.

Going further down, I seem to be receiving messages from both tstats through both integrations. E.g. Looking at the log for tstat1 I can see messages from tstat2 with SenderID equal to the serial number of tstat2's smart hub. They seem to correspond to messages in tstat2 log with SenderID == LCC. Even the diag level 2 messages seem to be coming through to the other device.

Happy to provide you with the full log for better analysis. Let me know where I should email it to.

[PeteRager]

That is very interesting. This a configuration I haven’t seen before. I know one person with 2 seperate hubs but they aren’t chained together like this. This may also explain the very high level of instability with diag level 2 as you have 2x the message volume.

I would like the logfiles. I have a simulator I can load them into.
Now, we need to figure out what to do. There are a couple of options.

A) Ignore/drop the messages. The simple solution is to have each connection ignore the messages not coming from LCC if it matches something in that siblings data structure. So instead of logging an error we would do nothing.

B) Connect to one hub (this would be the primary). In this solution we’d have a single connection to the one hub and get messages from primary and secondary hubs. This is the way the cloud connection works - a single connection and data may come from multiple hubs.

The benefits of A are its simple and if one hub is disconnected data will flow from the other hub. The disadvantage is we are doubling the network load and the load on the integration.

The benefits of B is we minimize the network load and integration load. The disadvantage is that the change is a little more involved. We’d also need to prove out that commands get routed correctly from the primary to the secondary hub.

Either way, we may want to also have an immediate fix to stop filling your log up with errors. I'll work on this in the AM, and will change that log message to DEBUG from ERROR.

[PeteRager]

Sent you a PM with questions on the Log Files. Once that is sorted out here's a test I'd like you to try:

Go into the integrations configuration and change the Application Id from the default "homeassistant" to a connection specific id - for example "ha_nnn" where nnn is the last three of the ip address. The name doesn't matter, we just want them different and to be able to identify which controller it is connected to.

After making the change, delete the message logs files and reload the integrations.

It is possible that the App_Id is a global identifier across the two controllers and hence all messages are getting routed to both integrations. By making them unique, it may change this behavior and remove the error. It's also possible this changes nothing. Either way it'd be good to know. I saw evidence of the same messages being sent back to back more that once; which is a behavior I haven't seen before either.

[PeteRager]

As I’m looking through the configuration for your system.

There appear to be two zones in your system. One on each S30. And hence there are 2 climate entities in HA

Are there two furnaces and two outdoor units or one furnace and one outdoor unit? Right now are there two working outdoor temperature sensors in HA?

[PeteRager]

For now, I've decided to take the simple approach and drop these messages. Option (A) above. Most of the changes for Option A are needed for Option B. So this gets us started and if we need to go further we can.

I should have a version available for you in a day or 2, after some more testing.

Changes included in the pull request:

• Fix for message logger S30 Message logs contain messages from all connections #156
• Process the sibling configuration information to capture the names, ip address of the sibling. This only processes data for a single sibling (our current use case), if it encounters multiple siblings (e.g. 3+ S30s) an error will be logged. Include the sibling name and ip address as new attributes in the diagnostic state object
• Drop messages from the sibling, log a debug message, and increment a new diagnostic state entity attribute "sibling_message_drop"
• If the message is not from a sibling, log an error message (current behavior), and increment a new diagnostic state entity attribute "sender_message_drop"

Bulk of changes are on the API side:
PeteRager/lennoxs30api#42

[PeteRager]

Updated state object with new diagnostic counters / info.

[ziz480]

Thank you!

As I’m looking through the configuration for your system.

There appear to be two zones in your system. One on each S30. And hence there are 2 climate entities in HA

Are there two furnaces and two outdoor units or one furnace and one outdoor unit? Right now are there two working outdoor temperature sensors in HA?

Yes, I have two climate entities & two outdoor temp entities in HA. Outdoor temperature seems to be reported correctly. The climate entities function and report correct temperature/target humidity as well. I basically have two complete systems (2x furnaces, 2x coils & 2x outdoor units).

[PeteRager]

Thanks for that explanation, that makes sense as an S30 can only control a single furnace, etc. So they chained them together.

New logs you sent are perfect.

I'm a day or two away from having the updated release.

[PeteRager]

I'm merging the pull request and creating a release, that will automatically close this issue. I will update when the release is finalized

[PeteRager]

https://github.com/PeteRager/lennoxs30/releases/tag/v0.2.7