Lots of warnings in HA logs, serious or not?

[mvdwetering]

My Home Assistant log is filled with warning log lines from plugwise_usb.
The integration does seem to work as far as I can tell. I get energy readings for all plugs in the energy dashboard and they seem reasonable.

Even Home Assistant complains about the amount with a warning

Logger: homeassistant.util.logging
Bron: util/logging.py:74
Eerst voorgekomen: 13 juli 2025 om 23:07:03 (1 gebeurtenis)
Laatst gelogd: 13 juli 2025 om 23:07:03

Module plugwise_usb.connection.queue is logging too frequently. 200 messages since last count

The most logged line seems to be:

logger: plugwise_usb.connection.queue
Bron: runner.py:154
Eerst voorgekomen: 13 juli 2025 om 22:12:33 (137710 gebeurtenissen)
Laatst gelogd: 21:03:56

Awaiting plugwise responses 1012
Awaiting plugwise responses 1011
Awaiting plugwise responses 1010
Awaiting plugwise responses 1009
Awaiting plugwise responses 1008

These logs seem to start happening from the moment the integration starts and over time the number at the end increases.

Runner up is:

Logger: plugwise_usb.connection.sender
Bron: runner.py:154
Eerst voorgekomen: 13 juli 2025 om 22:12:31 (1907 gebeurtenissen)
Laatst gelogd: 20:24:51

No open request for StickResponse (seq_id=b'4123', retries=0, ack=TIMEOUT)
No open request for StickResponse (seq_id=b'413E', retries=0, ack=TIMEOUT)
No open request for StickResponse (seq_id=b'4158', retries=0, ack=TIMEOUT)
No open request for StickResponse (seq_id=b'4172', retries=0, ack=TIMEOUT)
No open request for StickResponse (seq_id=b'4E1F', retries=0, ack=TIMEOUT)

I am a bit confused about how serious these are and what to do with them.

[dirixmjm]

I've seen these sometimes, typically a second restart helps.

I think @ArnoutD introduced these, maybe he can comment?

[bouwew]

@mvdwetering Your zigbee network is seriously overloaded or the radio-channel is seriously disturbed, I sometimes see this happen when I use my microwave-oven to heat some food.
This also means that the connections between the Circle + and the other devices are completely blocked.
This should resolve itself over time, might take a while though.

@ArnoutD given this result I still think we should do something to lessen the effect of such a disturbance.

[mvdwetering]

What would be a reasonable time for it to resolve itself? Hours, days, weeks?

Can I see and/or change the channel the network is on?
I could check against Wifi networks to find the best channel, or just try a few differnt ones to see which one is best.

I have the roudtriptime enabled (and RSSI sensors).
Can I assume those spikes are an indication of overloaded network?

[bouwew]

Should be in the order of hours.

On the channel used, the plugwise-usb software does not provide this information as far as I know. Also changing the channel is not possible I think.

On the graph, I'm seeing similar spikes in my network (10 Circles) but maybe 10% of what you see.

I have an idea on how to avoid the send-queue from filling up completely.
The idea is simple: allow the queue to fill up to a maximum then start dropping older messages.
Would you be willing to test such an update?

[mvdwetering]

Just as an FYI. I learned that my Plugwise network is on channel 15. My network is 12 Circles.

I used a Zigbeesniffer and just tried channels until I found one where I could see the mac addresses of the plugs in Wireshark. The data is encrypted, but apparently the addressing not.
My Matter Thread network was also at 15 so I changed that to 20, so should be less interference from that.

[bouwew]

I'm now testing with an implementation of my idea, it looks like the counter is not correct:

2025-07-18 08:56:53.609 WARNING (MainThread) [plugwise_usb.connection.queue] Awaiting responses 4
2025-07-18 08:56:53.609 WARNING (MainThread) [plugwise_usb.connection.queue] Queue contents: SortedList([CircleEnergyLogsRequest (mac=000D6F0003562003, seq_id=UNKNOWN, attempt=0, log_address=5225), CircleEnergyLogsRequest (mac=000D6F00029C32C7, seq_id=UNKNOWN, attempt=0, log_address=1469)])
2025-07-18 08:56:53.609 WARNING (MainThread) [plugwise_usb.connection.queue] Requests dropped: 0

And

2025-07-18 09:19:40.778 WARNING (MainThread) [plugwise_usb.connection.queue] Awaiting responses 17
2025-07-18 09:19:40.778 WARNING (MainThread) [plugwise_usb.connection.queue] Queue contents: SortedList([])
2025-07-18 09:19:40.778 WARNING (MainThread) [plugwise_usb.connection.queue] Requests dropped: 0
2025-07-18 09:19:41.389 WARNING (MainThread) [plugwise_usb.connection.queue] Awaiting responses 16
2025-07-18 09:19:41.390 WARNING (MainThread) [plugwise_usb.connection.queue] Queue contents: SortedList([])

[bouwew]

@mvdwetering Would you mind testing a library-update for me?

[mvdwetering]

Sure, I can test.

However it seems my plugwise network now indeed having more severe issues.
Since yesterday not getting any more energy readings (or they are very low) from any plugs else except the Circle+. Strangely enough I still have power readings. I also see holes in the graphs now, so plugs became unreachable it seems.

That being said, the logs still seem similar, so maybe not an issue for testing stuff.

[bouwew]

I'm seeing some strange behavior in the hourly and daily energy graphs, need to find out first if that is caused by my recent update or that it comes from a previous update.

[bouwew]

I found the reason, a fix will be available in a coming update release.

[bouwew]

@mvdwetering Can you make a change to the manifest.json file of the plugwise_usb-beta integration?

If yes, change the line "requirements": ["plugwise-usb==0.44.7"], to:

"requirements": [
  "https://test-files.pythonhosted.org/packages/c0/75/47ebb587dced57ce1fffc2c8a843bd64938578e8b7efb2d21280d096d0d3/plugwise_usb-0.44.8a8.tar.gz#plugwise-usb==0.44.8a8"
],

Save the change and restart HA.

After the restart the number in the Awaiting plugwise responses ... messages will show the correct number of responses waiting in the send-queue. Please let me know what the maximum number is you are seeing after this update.

[mvdwetering]

It has been running for about a day now, so I took a look at the HA log.
The number was mostly 4, 5, 6,l 7 and one time it was a 10.

However these lines stopped after ~1 hour after HA restart.
There are some exceptions around that time. Not sure if those are related.

I added the full log. I see that there are some other errors that I need to fix, but I expect them to be not a problem for plugwise (old phone notification, error in automation, error in epson_projector and some IP network hiccups).

home-assistant_2025-07-21T19-02-55.731Z.zip

[bouwew]

Yes I've seen a similar behaviour in the numbers displayed, and the messages stopped appearing after all the energy-logs were collected after the restart.

Please note: this queue-size update is now release in v0.55.5. Also, the strange steps showing up at regular intervals in the Energy-graphs have been fixed.

[bouwew]

About your ZigBee networks, I found this https://www.zigbee2mqtt.io/advanced/zigbee/02_improve_network_range_and_stability.html#try-different-orientations-of-the-adapter interesting reading material. Especially this part: https://www.metageek.com/training/resources/zigbee-wifi-coexistence/

[mvdwetering]

Thanks for the research. I work with Zigbee devices so was already aware of the channel overlap. Never knew that Plugwise was Zigbee under the hood.

Unfortunately channel 15 is a bad one for me. I used to have reachability issues with my Hue setup when it was at channel 15 which was gone after moving to 25. Probably because someone in the neighbourhood has a 40 MHz wide band on Wifi channel 3 even though the signal is not super strong.

Changing the orientation is an easy thing to try, so will do that