Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Müller Licht bulbs constantly request OTAs #16371

Closed
RubenKelevra opened this issue Jan 26, 2023 · 7 comments
Closed

Müller Licht bulbs constantly request OTAs #16371

RubenKelevra opened this issue Jan 26, 2023 · 7 comments
Labels
problem Something isn't working stale Stale issues

Comments

@RubenKelevra
Copy link
Contributor

RubenKelevra commented Jan 26, 2023 •
edited
Loading

What happened?

I noticed that my Müller-Licht bulbs request an OTA update very often and Zigbee2MQTT seems to not react to it at all.

What did you expect to happen?

Maybe Z2M can tell devices that there's no OTA available, if they are not yet supported with firmware updates, to give them a response to that and back off with their requests?

How to reproduce it (minimal and precise)

Use Müller Licht bulbs in a Zigbee Network with Z2M/zStack as coordinator

Zigbee2MQTT version

1.29.2

Adapter firmware version

20221102

Adapter

Slaesh's CC2652RB stick

Debug log

ota_log.txt

See also

#16278
@RubenKelevra RubenKelevra added the problem Something isn't working label Jan 26, 2023
@Koenkk
Copy link
Owner

Koenkk commented Jan 26, 2023

Normally Zigbee2MQTT should respond to these requests:

zigbee2mqtt/lib/extension/otaUpdate.ts

Line 124 in 1402139

await endpoint.commandResponse('genOta', 'queryNextImageResponse', {status: 0x98});
. However as this is not always done, can you provide me the herdsman debug log so I can double check this?

See https://www.zigbee2mqtt.io/guide/usage/debug.html on how to enable the herdsman debug logging. Note that this is only logged to STDOUT and not to log files.

@Styx85
Copy link

Styx85 commented Jan 27, 2023

putty.log

Well, while I wasn't able to transfer it to the internal log file, I did a grab with putty.
So the Muller Lights are:

  • Vorgarten Tür
  • Vorgarten Treppe
  • Garten Wohnzimmer
  • Wohnzimmer Stehlampe 2

I hope this helps.

Koenkk added a commit that referenced this issue Jan 29, 2023
@Koenkk
Log device OTA request response. #16371
a3f1399
@Koenkk
Copy link
Owner

Koenkk commented Jan 29, 2023 •
edited
Loading

It is a bit hard to see in this log, I've improved the logging, the herdsman debug logging is not needed anymore, just the normal z2m debug logging is enough. After each Device 'xx' requested OTA you will now see either Responded to OTA request of 'xx' with 'NO_IMAGE_AVAILABLE' or Did not respond to OTA request of 'xx' (no OTA endpoint).

Changes will be available in the dev branch in a few hours from now. (https://www.zigbee2mqtt.io/advanced/more/switch-to-dev-branch.html)

@Styx85
Copy link

Styx85 commented Jan 29, 2023

Yep now it is easier:

Debug 2023-01-29 18:31:50Received Zigbee message from 'Vorgarten Treppe', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 18:31:50Device 'Vorgarten Treppe' requested OTA
Debug 2023-01-29 18:31:50Did not respond to OTA request of 'Vorgarten Treppe' (no OTA endpoint)
Debug 2023-01-29 18:32:08Received Zigbee message from 'Vorgarten Treppe', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 18:32:08Device 'Vorgarten Treppe' requested OTA
Debug 2023-01-29 18:32:08Did not respond to OTA request of 'Vorgarten Treppe' (no OTA endpoint)
Debug 2023-01-29 18:32:26Received Zigbee message from 'Vorgarten Treppe', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 18:32:26Device 'Vorgarten Treppe' requested OTA
Debug 2023-01-29 18:32:26Did not respond to OTA request of 'Vorgarten Treppe' (no OTA endpoint)

Debug 2023-01-29 18:31:13Received Zigbee message from 'Vorgarten Tür', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 18:31:13Device 'Vorgarten Tür' requested OTA
Debug 2023-01-29 18:31:14Did not respond to OTA request of 'Vorgarten Tür' (no OTA endpoint)
Debug 2023-01-29 18:31:32Received Zigbee message from 'Vorgarten Tür', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 18:31:32Device 'Vorgarten Tür' requested OTA
Debug 2023-01-29 18:31:32Did not respond to OTA request of 'Vorgarten Tür' (no OTA endpoint)
Debug 2023-01-29 18:31:50Received Zigbee message from 'Vorgarten Tür', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 18:31:50Device 'Vorgarten Tür' requested OTA
Debug 2023-01-29 18:31:50Did not respond to OTA request of 'Vorgarten Tür' (no OTA endpoint)

Debug 2023-01-29 18:31:43Received Zigbee message from 'Wohnzimmer Stehlampe 2', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 18:31:43Device 'Wohnzimmer Stehlampe 2' requested OTA
Debug 2023-01-29 18:31:43Did not respond to OTA request of 'Wohnzimmer Stehlampe 2' (no OTA endpoint)
Debug 2023-01-29 18:32:01Received Zigbee message from 'Wohnzimmer Stehlampe 2', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 18:32:01Device 'Wohnzimmer Stehlampe 2' requested OTA
Debug 2023-01-29 18:32:01Did not respond to OTA request of 'Wohnzimmer Stehlampe 2' (no OTA endpoint)
Debug 2023-01-29 18:32:19Received Zigbee message from 'Wohnzimmer Stehlampe 2', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 18:32:19Device 'Wohnzimmer Stehlampe 2' requested OTA
Debug 2023-01-29 18:32:19Did not respond to OTA request of 'Wohnzimmer Stehlampe 2' (no OTA endpoint)

Koenkk added a commit that referenced this issue Jan 29, 2023
@Koenkk
Always respond to OTA request. #16371
f943619
@Koenkk
Copy link
Owner

Koenkk commented Jan 29, 2023

Did not respond to OTA request of 'Wohnzimmer Stehlampe 2' (no OTA endpoint) -> I've changed the code to now always respond, in case non has an OTA endpoint it will respond to the one it was requested with.

Changes will be available in the dev branch in a few hours from now. (https://www.zigbee2mqtt.io/advanced/more/switch-to-dev-branch.html)

@Styx85
Copy link

Styx85 commented Jan 29, 2023

I can confirm this changes and reduces the spamming with OTA requests. The bulbs now fire the OTA request roughly every minute (one minute + at least one second). Before it was every 15 plus x seconds. That takes some pressure from the network, but is still not nice. It has already been suspected before that the firmware in these kinds of lamps are incorrectly in a developer mode. So I think that is kind of the best we can get (maybe I get in touch with the company to ask for an updated firmware).

I will now dig deeper into #16278, @ASNNetworks there already suggested that the bulbs react with flickering when pairing mode "all" is activated (so far confirmed from my side). So it seems to be kind of developer mode, too. Maybe you can give some hints in the other thread what to look for in the logs.

Debug 2023-01-29 21:03:00Received Zigbee message from 'Wohnzimmer Stehlampe 2', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 21:03:00Device 'Wohnzimmer Stehlampe 2' requested OTA
Debug 2023-01-29 21:03:00Responded to OTA request of 'Wohnzimmer Stehlampe 2' with 'NO_IMAGE_AVAILABLE'
Debug 2023-01-29 21:04:01Received Zigbee message from 'Wohnzimmer Stehlampe 2', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 21:04:01Device 'Wohnzimmer Stehlampe 2' requested OTA
Debug 2023-01-29 21:04:01Responded to OTA request of 'Wohnzimmer Stehlampe 2' with 'NO_IMAGE_AVAILABLE'
Debug 2023-01-29 21:05:02Received Zigbee message from 'Wohnzimmer Stehlampe 2', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 21:05:02Device 'Wohnzimmer Stehlampe 2' requested OTA
Debug 2023-01-29 21:05:02Responded to OTA request of 'Wohnzimmer Stehlampe 2' with 'NO_IMAGE_AVAILABLE'
Debug 2023-01-29 21:06:04Received Zigbee message from 'Wohnzimmer Stehlampe 2', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 21:06:04Device 'Wohnzimmer Stehlampe 2' requested OTA
Debug 2023-01-29 21:06:04Responded to OTA request of 'Wohnzimmer Stehlampe 2' with 'NO_IMAGE_AVAILABLE'
Debug 2023-01-29 21:07:05Received Zigbee message from 'Wohnzimmer Stehlampe 2', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 21:07:05Device 'Wohnzimmer Stehlampe 2' requested OTA
Debug 2023-01-29 21:07:05Responded to OTA request of 'Wohnzimmer Stehlampe 2' with 'NO_IMAGE_AVAILABLE'
Debug 2023-01-29 21:08:06Received Zigbee message from 'Wohnzimmer Stehlampe 2', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 21:08:06Device 'Wohnzimmer Stehlampe 2' requested OTA
Debug 2023-01-29 21:08:06Responded to OTA request of 'Wohnzimmer Stehlampe 2' with 'NO_IMAGE_AVAILABLE'

Debug 2023-01-29 21:08:17Received Zigbee message from 'Vorgarten Tür', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 21:08:17Device 'Vorgarten Tür' requested OTA
Debug 2023-01-29 21:08:17Responded to OTA request of 'Vorgarten Tür' with 'NO_IMAGE_AVAILABLE'
Debug 2023-01-29 21:09:18Received Zigbee message from 'Vorgarten Tür', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 21:09:18Device 'Vorgarten Tür' requested OTA
Debug 2023-01-29 21:09:18Responded to OTA request of 'Vorgarten Tür' with 'NO_IMAGE_AVAILABLE'
Debug 2023-01-29 21:10:19Received Zigbee message from 'Vorgarten Tür', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":537462801,"imageType":268,"manufacturerCode":4137}' from endpoint 1 with groupID 0
Debug 2023-01-29 21:10:19Device 'Vorgarten Tür' requested OTA
Debug 2023-01-29 21:10:19Responded to OTA request of 'Vorgarten Tür' with 'NO_IMAGE_AVAILABLE'

@Styx85 Styx85 mentioned this issue Jan 29, 2023
Closed
@chojnicki chojnicki mentioned this issue Feb 3, 2023
Closed
@github-actions
Copy link
Contributor

github-actions bot commented Mar 1, 2023

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days

@github-actions github-actions bot added the stale Stale issues label Mar 1, 2023
@github-actions github-actions bot closed this as not planned Won't fix, can't repro, duplicate, stale Mar 8, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
problem Something isn't working stale Stale issues
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@RubenKelevra @Koenkk @Styx85