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.

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

Connection failed: MDNS lookup failed: SMLight #136864

Closed
Anto79-ops opened this issue Jan 29, 2025 · 45 comments · Fixed by #136942
Closed

Connection failed: MDNS lookup failed: SMLight #136864

Anto79-ops opened this issue Jan 29, 2025 · 45 comments · Fixed by #136942
Labels
integration: smlight problem in device Issue lies within the device, such firmware, software, or user customization/config
Milestone

Comments

@Anto79-ops
Copy link

Anto79-ops commented Jan 29, 2025

The problem

hello!

Upon updating to 2025.2.0b0, i noticed thes logs and my SMLite integration entities are unavailable.

Z2M and directly connecting to the adapter are working normally, just the integration is failing. Rebooting the adapter, restores the entities, but after a few minutes, they go back to being unavailable.

might be related to this.

thanks

SLZB-06 by SMLIGHT
Firmware: core: v2.7.1 / zigbee: 20240710

Logger: homeassistant.components.smlight
Source: helpers/update_coordinator.py:405
integration: SMLIGHT SLZB (documentation, issues)
First occurred: 11:10:47 AM (2 occurrences)
Last logged: 11:24:53 AM

Error fetching smlight_SLZB-06.local data: Connection failed
Logger: homeassistant.components.smlight
Source: helpers/update_coordinator.py:312
integration: SMLIGHT SLZB (documentation, issues)
First occurred: 11:15:30 AM (6 occurrences)
Last logged: 11:18:32 AM

Unexpected error fetching smlight_SLZB-06.local data
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 1351, in _create_direct_connection
    hosts = await self._resolve_host(host, port, traces=traces)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 995, in _resolve_host
    return await asyncio.shield(resolved_host_task)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 1026, in _resolve_host_with_throttle
    addrs = await self._resolver.resolve(host, port, family=self._family)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp_asyncmdnsresolver/_impl.py", line 94, in resolve
    return await self._resolve_mdns(host, port, family)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp_asyncmdnsresolver/_impl.py", line 116, in _resolve_mdns
    raise OSError(None, "MDNS lookup failed")
OSError: [Errno None] MDNS lookup failed

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/pysmlight/web.py", line 55, in check_auth_needed
    async with self.session.get(self.url, auth=auth, params=params) as response:
               ~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/client.py", line 1425, in __aenter__
    self._resp: _RetType = await self._coro
                           ^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/client.py", line 703, in _request
    conn = await self._connector.connect(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
        req, traces=traces, timeout=real_timeout
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 548, in connect
    proto = await self._create_connection(req, traces, timeout)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 1056, in _create_connection
    _, proto = await self._create_direct_connection(req, traces, timeout)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 1357, in _create_direct_connection
    raise ClientConnectorDNSError(req.connection_key, exc) from exc
aiohttp.client_exceptions.ClientConnectorDNSError: Cannot connect to host slzb-06.local:80 ssl:default [MDNS lookup failed]

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 312, in __wrap_async_setup
    await self._async_setup()
  File "/usr/src/homeassistant/homeassistant/components/smlight/coordinator.py", line 65, in _async_setup
    if await self.client.check_auth_needed():
       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/pysmlight/web.py", line 62, in check_auth_needed
    raise SmlightConnectionError("Connection failed")
pysmlight.exceptions.SmlightConnectionError: Connection failed

What version of Home Assistant Core has the issue?

2025.2.0b0

What was the last working version of Home Assistant Core?

2025.1.x

What type of installation are you running?

Home Assistant OS

Integration causing the issue

SMLight

Link to integration documentation on our website

https://www.home-assistant.io/integrations/smlight/

Diagnostics information

No response

Example YAML snippet

Anything in the logs that might be useful for us?

Additional information

No response

@home-assistant
Copy link

Hey there @tl-sl, mind taking a look at this issue as it has been labeled with an integration (smlight) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of smlight can trigger bot actions by commenting:

  • @home-assistant close Closes the issue.
  • @home-assistant rename Awesome new title Renames the issue.
  • @home-assistant reopen Reopen the issue.
  • @home-assistant unassign smlight Removes the current integration label and assignees on the issue, add the integration domain after the command.
  • @home-assistant add-label needs-more-information Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue.
  • @home-assistant remove-label needs-more-information Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

(message by CodeOwnersMention)


smlight documentation
smlight source
(message by IssueLinks)

@gratiachristi95

This comment has been minimized.

@Anto79-ops
Copy link
Author

thanks, ok. Here's what I have for you:

Step 1: all good here, I can acess the adapter via local LAN to slzb-06.local and it loads up no problem
Step 2: It set to static
Step 3: All up to date
Step 4: No changes to firewall, just HA core updated to 2025.2.0b0 from 2025.1.4
Step 5: Using Z2M

Will get you logs on Step 6 on my next post. But here is another log I missed in the HA Core logs (Different from above):

Logger: homeassistant.helpers.entity
Source: helpers/entity.py:960
First occurred: 11:34:54 AM (2 occurrences)
Last logged: 11:49:54 AM

Update for binary_sensor.slzb_06_internet fails
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 1351, in _create_direct_connection
    hosts = await self._resolve_host(host, port, traces=traces)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 995, in _resolve_host
    return await asyncio.shield(resolved_host_task)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 1026, in _resolve_host_with_throttle
    addrs = await self._resolver.resolve(host, port, family=self._family)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp_asyncmdnsresolver/_impl.py", line 94, in resolve
    return await self._resolve_mdns(host, port, family)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp_asyncmdnsresolver/_impl.py", line 116, in _resolve_mdns
    raise OSError(None, "MDNS lookup failed")
OSError: [Errno None] MDNS lookup failed

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/pysmlight/web.py", line 73, in get
    async with self.session.get(
               ~~~~~~~~~~~~~~~~^
        url, headers=self.headers, params=params, auth=self.auth
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    ) as response:
    ^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/client.py", line 1425, in __aenter__
    self._resp: _RetType = await self._coro
                           ^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/client.py", line 703, in _request
    conn = await self._connector.connect(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
        req, traces=traces, timeout=real_timeout
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 548, in connect
    proto = await self._create_connection(req, traces, timeout)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 1056, in _create_connection
    _, proto = await self._create_direct_connection(req, traces, timeout)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 1357, in _create_direct_connection
    raise ClientConnectorDNSError(req.connection_key, exc) from exc
aiohttp.client_exceptions.ClientConnectorDNSError: Cannot connect to host slzb-06.local:80 ssl:default [MDNS lookup failed]

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 960, in async_update_ha_state
    await self.async_device_update()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1318, in async_device_update
    await self.async_update()
  File "/usr/src/homeassistant/homeassistant/components/smlight/binary_sensor.py", line 141, in async_update
    await self.coordinator.client.get_param("inetState")
  File "/usr/local/lib/python3.13/site-packages/pysmlight/web.py", line 228, in get_param
    return await self.get(params)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/pysmlight/web.py", line 89, in get
    raise SmlightConnectionError("Connection failed") from err
pysmlight.exceptions.SmlightConnectionError: Connection failed

@joostlek joostlek added this to the 2025.2.0 milestone Jan 29, 2025
@Anto79-ops
Copy link
Author

Regarding Step 6, after adding this to my configuration.yaml

logger:
  default: warning
  logs:
    homeassistant.components.smlight: debug
    pysmlight.web: debug

and rebooting Home Assistant, the adapter and integration are working well, but after a few minutes, it fails and goes unavaiable. The are the logs associated with SMLite during this time.

2025-01-29 12:13:23.074 DEBUG (MainThread) [homeassistant.components.smlight] Finished fetching smlight_SLZB-06.local data in 0.246 seconds (success: True)
2025-01-29 12:13:24.586 DEBUG (MainThread) [homeassistant.components.smlight] Finished fetching smlight_SLZB-06.local data in 1.417 seconds (success: True)
2025-01-29 12:18:31.713 ERROR (MainThread) [homeassistant.components.smlight] Error fetching smlight_SLZB-06.local data: Connection failed
2025-01-29 12:18:31.713 DEBUG (MainThread) [homeassistant.components.smlight] Finished fetching smlight_SLZB-06.local data in 5.001 seconds (success: False)
2025-01-29 12:23:36.713 DEBUG (MainThread) [homeassistant.components.smlight] Finished fetching smlight_SLZB-06.local data in 5.000 seconds (success: False)
2025-01-29 12:28:31.807 ERROR (MainThread) [homeassistant.helpers.entity] Update for binary_sensor.slzb_06_internet fails
Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 1351, in _create_direct_connection
    hosts = await self._resolve_host(host, port, traces=traces)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 995, in _resolve_host
    return await asyncio.shield(resolved_host_task)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 1026, in _resolve_host_with_throttle
    addrs = await self._resolver.resolve(host, port, family=self._family)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp_asyncmdnsresolver/_impl.py", line 94, in resolve
    return await self._resolve_mdns(host, port, family)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp_asyncmdnsresolver/_impl.py", line 116, in _resolve_mdns
    raise OSError(None, "MDNS lookup failed")
OSError: [Errno None] MDNS lookup failed

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/lib/python3.13/site-packages/pysmlight/web.py", line 73, in get
    async with self.session.get(
               ~~~~~~~~~~~~~~~~^
        url, headers=self.headers, params=params, auth=self.auth
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    ) as response:
    ^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/client.py", line 1425, in __aenter__
    self._resp: _RetType = await self._coro
                           ^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/client.py", line 703, in _request
    conn = await self._connector.connect(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
        req, traces=traces, timeout=real_timeout
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 548, in connect
    proto = await self._create_connection(req, traces, timeout)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 1056, in _create_connection
    _, proto = await self._create_direct_connection(req, traces, timeout)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/aiohttp/connector.py", line 1357, in _create_direct_connection
    raise ClientConnectorDNSError(req.connection_key, exc) from exc
aiohttp.client_exceptions.ClientConnectorDNSError: Cannot connect to host slzb-06.local:80 ssl:default [MDNS lookup failed]

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 960, in async_update_ha_state
    await self.async_device_update()
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 1318, in async_device_update
    await self.async_update()
  File "/usr/src/homeassistant/homeassistant/components/smlight/binary_sensor.py", line 141, in async_update
    await self.coordinator.client.get_param("inetState")
  File "/usr/local/lib/python3.13/site-packages/pysmlight/web.py", line 228, in get_param
    return await self.get(params)
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.13/site-packages/pysmlight/web.py", line 89, in get
    raise SmlightConnectionError("Connection failed") from err
pysmlight.exceptions.SmlightConnectionError: Connection failed
2025-01-29 12:28:41.714 DEBUG (MainThread) [homeassistant.components.smlight] Finished fetching smlight_SLZB-06.local data in 5.001 seconds (success: False)

During this time, i can easily login to the adapter via chrome broswer to slzb-06.local

Also, it does work for the first minutes from rebooting HA.
thanks

@jpbede
Copy link
Member

jpbede commented Jan 29, 2025

Can confirm this. When removing and re-adding the config entry it works for some time. @bdraco can this relate to the changes made to mDNS caching?

@bdraco
Copy link
Member

bdraco commented Jan 29, 2025

It does look like it.

Going to need debug logs for zeroconf to see why it can't lookup the name.

@bdraco
Copy link
Member

bdraco commented Jan 29, 2025

Also strange in the log its smlight_SLZB-06.local but above slzb-06.local:80

Which one is the correct name, and which one is it actually trying to connect to ?

@bdraco
Copy link
Member

bdraco commented Jan 29, 2025

Service call to turn on zeroconf logging

action: logger.set_level
data:
  zeroconf: debug

@jpbede
Copy link
Member

jpbede commented Jan 29, 2025

The smlight_ comes from the coordinator name:

super().__init__(
hass,
LOGGER,
name=f"{DOMAIN}_{host}",
update_interval=SCAN_INTERVAL,

Will turn on zeroconf debug log

@jpbede
Copy link
Member

jpbede commented Jan 29, 2025

After seeing the Ignoring duplicate message with no unicast questions received from for slzb-06.local the integration stopped working.

home-assistant.zeroconf.log

@bdraco bdraco changed the title Connection failed: SMLight Connection failed: MDNS lookup failed: SMLight Jan 29, 2025
@bdraco
Copy link
Member

bdraco commented Jan 29, 2025

2025-01-29 22:20:20.018 DEBUG (MainThread) [zeroconf] Sending to (224.0.0.251, 5353) via [socket 15 (('10.12.0.8', 5353))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:20.019 DEBUG (MainThread) [zeroconf] Sending to (224.0.0.251, 5353) via [socket 17 (('10.12.2.3', 5353))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:20.020 DEBUG (MainThread) [zeroconf] Sending to (ff02::fb, 5353) via [socket 19 (('fd64:5c16:1a1a:0:a699:a615:972:6e24', 5353, 0, 0))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:20.021 DEBUG (MainThread) [zeroconf] Sending to (ff02::fb, 5353) via [socket 20 (('fd64:5c16:1a1a:2:afd6:ee5f:30cb:1e13', 5353, 0, 0))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:20.021 DEBUG (MainThread) [zeroconf] IPv6 scope_id 0 associated to the receiving interface
2025-01-29 22:20:20.021 DEBUG (MainThread) [zeroconf] Received from '::ffff:10.12.0.8':5353 [socket 12 (('::', 5353, 0, 0))]: <DNSIncoming:id=0, flags=0, truncated=False, n_q=4, n_ans=0, n_auth=0, n_add=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[]> (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:20.021 DEBUG (MainThread) [zeroconf] Ignoring duplicate message with no unicast questions received from ('::ffff:10.12.2.3', 5353, 0, 0) [socket 12 (('::', 5353, 0, 0))] (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:20.021 DEBUG (MainThread) [zeroconf] Ignoring duplicate message with no unicast questions received from ('fd64:5c16:1a1a:0:a699:a615:972:6e24', 5353, 0, 0) [socket 12 (('::', 5353, 0, 0))] (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:20.022 DEBUG (MainThread) [zeroconf] Ignoring duplicate message with no unicast questions received from ('fd64:5c16:1a1a:2:afd6:ee5f:30cb:1e13', 5353, 0, 0) [socket 12 (('::', 5353, 0, 0))] (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:20.637 DEBUG (MainThread) [zeroconf] IPv6 scope_id 0 associated to the receiving interface

The ignoring is fine as its the question it just asked being reflected back to itself. However it seems like its never getting an answer.

% python3
Python 3.13.0 (main, Oct  7 2024, 05:02:14) [Clang 16.0.0 (clang-1600.0.26.4)] on darwin
Type "help", "copyright", "credits" or "license" for more information.
>>> import dns.message
>>> str(dns.message.from_wire(b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'))
'id 0\nopcode QUERY\nrcode NOERROR\nflags \n;QUESTION\nslzb-06.local. IN SRV\nslzb-06.local. IN TXT\nslzb-06.local. IN A\nslzb-06.local. IN AAAA\n;ANSWER\n;AUTHORITY\n;ADDITIONAL'
>>> 

@bdraco
Copy link
Member

bdraco commented Jan 29, 2025

It sure looks like we ask the right question, but the device never responds back to us

>>> str(dns.message.from_wire(b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'))
'id 0\nopcode QUERY\nrcode NOERROR\nflags \n;QUESTION\nslzb-06.local. IN SRV\nslzb-06.local. IN TXT\nslzb-06.local. IN A\nslzb-06.local. IN AAAA\n;ANSWER\n;AUTHORITY\n;ADDITIONAL'
>>> print(str(dns.message.from_wire(b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01')))
id 0
opcode QUERY
rcode NOERROR
flags 
;QUESTION
slzb-06.local. IN SRV
slzb-06.local. IN TXT
slzb-06.local. IN A
slzb-06.local. IN AAAA
;ANSWER
;AUTHORITY
;ADDITIONAL

@bdraco
Copy link
Member

bdraco commented Jan 29, 2025

When discovery happens earlier, the A record gets populated as an when it asks for SLZB-06._slzb-06._tcp.local..... it should have be in the additionals because its not the question that was asked (we ask a[question,QU,in,SLZB-06._slzb-06._tcp.local.] but we get back in answers record[a,in-unique,SLZB-06.local.]=120.0/119,10.12.2.8

2025-01-29 22:15:12.302 DEBUG (MainThread) [zeroconf] Sending to (224.0.0.251, 5353) via [socket 15 (('10.12.0.8', 5353))] (57 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QU,in,SLZB-06._slzb-06._tcp.local.], a[question,QU,in,SLZB-06._slzb-06._tcp.local.], quada[question,QU,in,SLZB-06._slzb-06._tcp.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x07SLZB-06\x08_slzb-06\x04_tcp\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01'...
2025-01-29 22:15:12.303 DEBUG (MainThread) [zeroconf] Sending to (224.0.0.251, 5353) via [socket 17 (('10.12.2.3', 5353))] (57 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QU,in,SLZB-06._slzb-06._tcp.local.], a[question,QU,in,SLZB-06._slzb-06._tcp.local.], quada[question,QU,in,SLZB-06._slzb-06._tcp.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x07SLZB-06\x08_slzb-06\x04_tcp\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01'...
2025-01-29 22:15:12.304 DEBUG (MainThread) [zeroconf] Sending to (ff02::fb, 5353) via [socket 19 (('fd64:5c16:1a1a:0:a699:a615:972:6e24', 5353, 0, 0))] (57 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QU,in,SLZB-06._slzb-06._tcp.local.], a[question,QU,in,SLZB-06._slzb-06._tcp.local.], quada[question,QU,in,SLZB-06._slzb-06._tcp.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x07SLZB-06\x08_slzb-06\x04_tcp\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01'...
2025-01-29 22:15:12.305 DEBUG (MainThread) [zeroconf] Sending to (ff02::fb, 5353) via [socket 20 (('fd64:5c16:1a1a:2:afd6:ee5f:30cb:1e13', 5353, 0, 0))] (57 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QU,in,SLZB-06._slzb-06._tcp.local.], a[question,QU,in,SLZB-06._slzb-06._tcp.local.], quada[question,QU,in,SLZB-06._slzb-06._tcp.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x07SLZB-06\x08_slzb-06\x04_tcp\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01'...
2025-01-29 22:15:12.351 DEBUG (MainThread) [zeroconf] IPv6 scope_id 0 associated to the receiving interface
2025-01-29 22:15:12.351 DEBUG (MainThread) [zeroconf] Received from '::ffff:10.12.0.8':5353 [socket 12 (('::', 5353, 0, 0))]: <DNSIncoming:id=0, flags=0, truncated=False, n_q=3, n_ans=0, n_auth=0, n_add=0, questions=[srv[question,QU,in,SLZB-06._slzb-06._tcp.local.], a[question,QU,in,SLZB-06._slzb-06._tcp.local.], quada[question,QU,in,SLZB-06._slzb-06._tcp.local.]], answers=[]> (57 bytes) as [b'\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x07SLZB-06\x08_slzb-06\x04_tcp\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01']
2025-01-29 22:15:12.352 DEBUG (MainThread) [zeroconf] IPv6 scope_id 0 associated to the receiving interface
2025-01-29 22:15:12.352 DEBUG (MainThread) [zeroconf] Received from '::ffff:10.12.2.3':5353 [socket 12 (('::', 5353, 0, 0))]: <DNSIncoming:id=0, flags=0, truncated=False, n_q=3, n_ans=0, n_auth=0, n_add=0, questions=[srv[question,QU,in,SLZB-06._slzb-06._tcp.local.], a[question,QU,in,SLZB-06._slzb-06._tcp.local.], quada[question,QU,in,SLZB-06._slzb-06._tcp.local.]], answers=[]> (57 bytes) as [b'\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x07SLZB-06\x08_slzb-06\x04_tcp\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01']
2025-01-29 22:15:12.352 DEBUG (MainThread) [zeroconf] IPv6 scope_id 0 associated to the receiving interface
2025-01-29 22:15:12.352 DEBUG (MainThread) [zeroconf] Received from 'fd64:5c16:1a1a:0:a699:a615:972:6e24':5353 [socket 12 (('::', 5353, 0, 0))]: <DNSIncoming:id=0, flags=0, truncated=False, n_q=3, n_ans=0, n_auth=0, n_add=0, questions=[srv[question,QU,in,SLZB-06._slzb-06._tcp.local.], a[question,QU,in,SLZB-06._slzb-06._tcp.local.], quada[question,QU,in,SLZB-06._slzb-06._tcp.local.]], answers=[]> (57 bytes) as [b'\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x07SLZB-06\x08_slzb-06\x04_tcp\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01']
2025-01-29 22:15:12.352 DEBUG (MainThread) [zeroconf] IPv6 scope_id 0 associated to the receiving interface
2025-01-29 22:15:12.352 DEBUG (MainThread) [zeroconf] Received from 'fd64:5c16:1a1a:2:afd6:ee5f:30cb:1e13':5353 [socket 12 (('::', 5353, 0, 0))]: <DNSIncoming:id=0, flags=0, truncated=False, n_q=3, n_ans=0, n_auth=0, n_add=0, questions=[srv[question,QU,in,SLZB-06._slzb-06._tcp.local.], a[question,QU,in,SLZB-06._slzb-06._tcp.local.], quada[question,QU,in,SLZB-06._slzb-06._tcp.local.]], answers=[]> (57 bytes) as [b'\x00\x00\x00\x00\x00\x03\x00\x00\x00\x00\x00\x00\x07SLZB-06\x08_slzb-06\x04_tcp\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01']
2025-01-29 22:15:12.408 DEBUG (MainThread) [zeroconf] IPv6 scope_id 0 associated to the receiving interface
2025-01-29 22:15:12.408 DEBUG (MainThread) [zeroconf] Received from 'fd64:5c16:1a1a:2:fee8:c0ff:fef8:60e7':5353 [socket 20 (('fd64:5c16:1a1a:2:afd6:ee5f:30cb:1e13', 5353, 0, 0))]: <DNSIncoming:id=0, flags=33792, truncated=False, n_q=0, n_ans=1, n_auth=0, n_add=4, questions=[], answers=[record[srv,in-unique,SLZB-06._slzb-06._tcp.local.]=120.0/119,SLZB-06.local.:6638, record[a,in-unique,SLZB-06.local.]=120.0/119,10.12.2.8, record[quada,in-unique,SLZB-06.local.]=120.0/119,fe80::fee8:c0ff:fef8:60e7, record[quada,in-unique,SLZB-06.local.]=120.0/119,fd64:5c16:1a1a:2:fee8:c0ff:fef8:60e7, record[quada,in-unique,SLZB-06.local.]=120.0/119,2a00:6020:4e00:202:fee8:c0ff:fef8:60e7]> (167 bytes) as [b'\x00\x00\x84\x00\x00\x00\x00\x01\x00\x00\x00\x04\x07SLZB-06\x08_slzb-06\x04_tcp\x05local\x00\x00!\x80\x01\x00\x00\x00x\x00\x10\x00\x00\x00\x00\x19\xee\x07SLZB-06\xc0"\xc09\x00\x01\x80\x01\x00\x00\x00x\x00\x04\n\x0c\x02\x08\xc09\x00\x1c\x80\x01\x00\x00\x00x\x00\x10\xfe\x80\x00\x00\x00\x00\x00\x00\xfe\xe8\xc0\xff\xfe\xf8`\xe7\xc09\x00\x1c\x80\x01\x00\x00\x00x\x00\x10\xfdd\\\x16\x1a\x1a\x00\x02\xfe\xe8\xc0\xff\xfe\xf8`\xe7\xc09\x00\x1c\x80\x01\x00\x00\x00x\x00\x10*\x00` N\x00\x02\x02\xfe\xe8\xc0\xff\xfe\xf8`\xe7']

@Anto79-ops
Copy link
Author

Also strange in the log its smlight_SLZB-06.local but above slzb-06.local:80

Which one is the correct name, and which one is it actually trying to connect to ?

when on my home network, i use http://slzb-06.local/ on my Chrome broswer, and brings me to the UI of the device.

@bdraco
Copy link
Member

bdraco commented Jan 29, 2025

So its likely that the mDNS stack on the device is not very compliant, and whatever Chrome is using to do the query is sending it in an order that it happens to work, and when zeroconf sends it, its never responding to it.

It could be any of the following:

  • The device only responds to PTR queries
  • The device requires a case sensitive A query ie SLZB-06.local
  • The device wants an ANY query and zeroconf is asking for specific records.
  • The device's mDNS stack might not implement name compression (which is required) and it is relying on the A record query happening first in the question
  • Some other spec violation

It sure looks like a bug in the mDNS stack of the device.

@bdraco
Copy link
Member

bdraco commented Jan 29, 2025

Its pretty clear from the logs that the device isn't responding to the A record query, and zeroconf is trying a QU query first, and than falling back to a QM one... and it just never responds

2025-01-29 22:20:15.184 DEBUG (MainThread) [zeroconf] now offsets = questions=4, answers=0, authorities=0, additionals=0
2025-01-29 22:20:15.185 DEBUG (MainThread) [zeroconf] Sending to (224.0.0.251, 5353) via [socket 15 (('10.12.0.8', 5353))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QU,in,slzb-06.local.], txt[question,QU,in,slzb-06.local.], a[question,QU,in,slzb-06.local.], quada[question,QU,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x10\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01'...
2025-01-29 22:20:15.185 DEBUG (MainThread) [zeroconf] Sending to (224.0.0.251, 5353) via [socket 17 (('10.12.2.3', 5353))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QU,in,slzb-06.local.], txt[question,QU,in,slzb-06.local.], a[question,QU,in,slzb-06.local.], quada[question,QU,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x10\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01'...
2025-01-29 22:20:15.185 DEBUG (MainThread) [zeroconf] Sending to (ff02::fb, 5353) via [socket 19 (('fd64:5c16:1a1a:0:a699:a615:972:6e24', 5353, 0, 0))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QU,in,slzb-06.local.], txt[question,QU,in,slzb-06.local.], a[question,QU,in,slzb-06.local.], quada[question,QU,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x10\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01'...
2025-01-29 22:20:15.186 DEBUG (MainThread) [zeroconf] Sending to (ff02::fb, 5353) via [socket 20 (('fd64:5c16:1a1a:2:afd6:ee5f:30cb:1e13', 5353, 0, 0))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QU,in,slzb-06.local.], txt[question,QU,in,slzb-06.local.], a[question,QU,in,slzb-06.local.], quada[question,QU,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x10\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01'...
2025-01-29 22:20:15.187 DEBUG (MainThread) [zeroconf] IPv6 scope_id 0 associated to the receiving interface
2025-01-29 22:20:15.187 DEBUG (MainThread) [zeroconf] Received from '::ffff:10.12.0.8':5353 [socket 12 (('::', 5353, 0, 0))]: <DNSIncoming:id=0, flags=0, truncated=False, n_q=4, n_ans=0, n_auth=0, n_add=0, questions=[srv[question,QU,in,slzb-06.local.], txt[question,QU,in,slzb-06.local.], a[question,QU,in,slzb-06.local.], quada[question,QU,in,slzb-06.local.]], answers=[]> (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x10\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01']
2025-01-29 22:20:15.187 DEBUG (MainThread) [zeroconf] IPv6 scope_id 0 associated to the receiving interface
2025-01-29 22:20:15.187 DEBUG (MainThread) [zeroconf] Received from '::ffff:10.12.2.3':5353 [socket 12 (('::', 5353, 0, 0))]: <DNSIncoming:id=0, flags=0, truncated=False, n_q=4, n_ans=0, n_auth=0, n_add=0, questions=[srv[question,QU,in,slzb-06.local.], txt[question,QU,in,slzb-06.local.], a[question,QU,in,slzb-06.local.], quada[question,QU,in,slzb-06.local.]], answers=[]> (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x10\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01']
2025-01-29 22:20:15.187 DEBUG (MainThread) [zeroconf] IPv6 scope_id 0 associated to the receiving interface
2025-01-29 22:20:15.187 DEBUG (MainThread) [zeroconf] Received from 'fd64:5c16:1a1a:0:a699:a615:972:6e24':5353 [socket 12 (('::', 5353, 0, 0))]: <DNSIncoming:id=0, flags=0, truncated=False, n_q=4, n_ans=0, n_auth=0, n_add=0, questions=[srv[question,QU,in,slzb-06.local.], txt[question,QU,in,slzb-06.local.], a[question,QU,in,slzb-06.local.], quada[question,QU,in,slzb-06.local.]], answers=[]> (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x10\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01']
2025-01-29 22:20:15.188 DEBUG (MainThread) [zeroconf] IPv6 scope_id 0 associated to the receiving interface
2025-01-29 22:20:15.188 DEBUG (MainThread) [zeroconf] Received from 'fd64:5c16:1a1a:2:afd6:ee5f:30cb:1e13':5353 [socket 12 (('::', 5353, 0, 0))]: <DNSIncoming:id=0, flags=0, truncated=False, n_q=4, n_ans=0, n_auth=0, n_add=0, questions=[srv[question,QU,in,slzb-06.local.], txt[question,QU,in,slzb-06.local.], a[question,QU,in,slzb-06.local.], quada[question,QU,in,slzb-06.local.]], answers=[]> (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x80\x01\xc0\x0c\x00\x10\x80\x01\xc0\x0c\x00\x01\x80\x01\xc0\x0c\x00\x1c\x80\x01']
2025-01-29 22:20:15.477 DEBUG (MainThread) [zeroconf] offsets = questions=0, answers=0, authorities=0, additionals=0
2025-01-29 22:20:15.477 DEBUG (MainThread) [zeroconf] lengths = questions=4, answers=0, authorities=0, additionals=0
2025-01-29 22:20:15.477 DEBUG (MainThread) [zeroconf] now offsets = questions=4, answers=0, authorities=0, additionals=0
2025-01-29 22:20:15.477 DEBUG (MainThread) [zeroconf] Sending to (224.0.0.251, 5353) via [socket 15 (('10.12.0.8', 5353))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:15.478 DEBUG (MainThread) [zeroconf] Sending to (224.0.0.251, 5353) via [socket 17 (('10.12.2.3', 5353))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:15.478 DEBUG (MainThread) [zeroconf] Sending to (ff02::fb, 5353) via [socket 19 (('fd64:5c16:1a1a:0:a699:a615:972:6e24', 5353, 0, 0))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:15.478 DEBUG (MainThread) [zeroconf] Sending to (ff02::fb, 5353) via [socket 20 (('fd64:5c16:1a1a:2:afd6:ee5f:30cb:1e13', 5353, 0, 0))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:15.479 DEBUG (MainThread) [zeroconf] IPv6 scope_id 0 associated to the receiving interface
2025-01-29 22:20:15.479 DEBUG (MainThread) [zeroconf] Received from '::ffff:10.12.0.8':5353 [socket 12 (('::', 5353, 0, 0))]: <DNSIncoming:id=0, flags=0, truncated=False, n_q=4, n_ans=0, n_auth=0, n_add=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[]> (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:15.479 DEBUG (MainThread) [zeroconf] Ignoring duplicate message with no unicast questions received from ('::ffff:10.12.2.3', 5353, 0, 0) [socket 12 (('::', 5353, 0, 0))] (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:15.479 DEBUG (MainThread) [zeroconf] Ignoring duplicate message with no unicast questions received from ('fd64:5c16:1a1a:0:a699:a615:972:6e24', 5353, 0, 0) [socket 12 (('::', 5353, 0, 0))] (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:15.479 DEBUG (MainThread) [zeroconf] Ignoring duplicate message with no unicast questions received from ('fd64:5c16:1a1a:2:afd6:ee5f:30cb:1e13', 5353, 0, 0) [socket 12 (('::', 5353, 0, 0))] (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:16.747 DEBUG (MainThread) [zeroconf] offsets = questions=0, answers=0, authorities=0, additionals=0
2025-01-29 22:20:16.747 DEBUG (MainThread) [zeroconf] lengths = questions=4, answers=0, authorities=0, additionals=0
2025-01-29 22:20:16.747 DEBUG (MainThread) [zeroconf] now offsets = questions=4, answers=0, authorities=0, additionals=0
2025-01-29 22:20:16.748 DEBUG (MainThread) [zeroconf] Sending to (224.0.0.251, 5353) via [socket 15 (('10.12.0.8', 5353))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:16.748 DEBUG (MainThread) [zeroconf] Sending to (224.0.0.251, 5353) via [socket 17 (('10.12.2.3', 5353))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:16.748 DEBUG (MainThread) [zeroconf] Sending to (ff02::fb, 5353) via [socket 19 (('fd64:5c16:1a1a:0:a699:a615:972:6e24', 5353, 0, 0))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:16.748 DEBUG (MainThread) [zeroconf] Sending to (ff02::fb, 5353) via [socket 20 (('fd64:5c16:1a1a:2:afd6:ee5f:30cb:1e13', 5353, 0, 0))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:16.748 DEBUG (MainThread) [zeroconf] IPv6 scope_id 0 associated to the receiving interface
2025-01-29 22:20:16.749 DEBUG (MainThread) [zeroconf] Received from '::ffff:10.12.0.8':5353 [socket 12 (('::', 5353, 0, 0))]: <DNSIncoming:id=0, flags=0, truncated=False, n_q=4, n_ans=0, n_auth=0, n_add=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[]> (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:16.749 DEBUG (MainThread) [zeroconf] Ignoring duplicate message with no unicast questions received from ('::ffff:10.12.2.3', 5353, 0, 0) [socket 12 (('::', 5353, 0, 0))] (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:16.749 DEBUG (MainThread) [zeroconf] Ignoring duplicate message with no unicast questions received from ('fd64:5c16:1a1a:0:a699:a615:972:6e24', 5353, 0, 0) [socket 12 (('::', 5353, 0, 0))] (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:16.750 DEBUG (MainThread) [zeroconf] Ignoring duplicate message with no unicast questions received from ('fd64:5c16:1a1a:2:afd6:ee5f:30cb:1e13', 5353, 0, 0) [socket 12 (('::', 5353, 0, 0))] (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:17.849 DEBUG (MainThread) [zeroconf] offsets = questions=0, answers=0, authorities=0, additionals=0
2025-01-29 22:20:17.849 DEBUG (MainThread) [zeroconf] lengths = questions=4, answers=0, authorities=0, additionals=0
2025-01-29 22:20:17.849 DEBUG (MainThread) [zeroconf] now offsets = questions=4, answers=0, authorities=0, additionals=0
2025-01-29 22:20:17.849 DEBUG (MainThread) [zeroconf] Sending to (224.0.0.251, 5353) via [socket 15 (('10.12.0.8', 5353))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:17.850 DEBUG (MainThread) [zeroconf] Sending to (224.0.0.251, 5353) via [socket 17 (('10.12.2.3', 5353))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:17.850 DEBUG (MainThread) [zeroconf] Sending to (ff02::fb, 5353) via [socket 19 (('fd64:5c16:1a1a:0:a699:a615:972:6e24', 5353, 0, 0))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:17.850 DEBUG (MainThread) [zeroconf] Sending to (ff02::fb, 5353) via [socket 20 (('fd64:5c16:1a1a:2:afd6:ee5f:30cb:1e13', 5353, 0, 0))] (49 bytes #1) <DNSOutgoing:multicast=True, flags=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[], authorities=[], additionals=[]> as b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01'...
2025-01-29 22:20:17.850 DEBUG (MainThread) [zeroconf] IPv6 scope_id 0 associated to the receiving interface
2025-01-29 22:20:17.850 DEBUG (MainThread) [zeroconf] Received from '::ffff:10.12.0.8':5353 [socket 12 (('::', 5353, 0, 0))]: <DNSIncoming:id=0, flags=0, truncated=False, n_q=4, n_ans=0, n_auth=0, n_add=0, questions=[srv[question,QM,in,slzb-06.local.], txt[question,QM,in,slzb-06.local.], a[question,QM,in,slzb-06.local.], quada[question,QM,in,slzb-06.local.]], answers=[]> (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:17.851 DEBUG (MainThread) [zeroconf] Ignoring duplicate message with no unicast questions received from ('::ffff:10.12.2.3', 5353, 0, 0) [socket 12 (('::', 5353, 0, 0))] (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:17.851 DEBUG (MainThread) [zeroconf] Ignoring duplicate message with no unicast questions received from ('fd64:5c16:1a1a:0:a699:a615:972:6e24', 5353, 0, 0) [socket 12 (('::', 5353, 0, 0))] (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:17.851 DEBUG (MainThread) [zeroconf] Ignoring duplicate message with no unicast questions received from ('fd64:5c16:1a1a:2:afd6:ee5f:30cb:1e13', 5353, 0, 0) [socket 12 (('::', 5353, 0, 0))] (49 bytes) as [b'\x00\x00\x00\x00\x00\x04\x00\x00\x00\x00\x00\x00\x07slzb-06\x05local\x00\x00!\x00\x01\xc0\x0c\x00\x10\x00\x01\xc0\x0c\x00\x01\x00\x01\xc0\x0c\x00\x1c\x00\x01']
2025-01-29 22:20:18.163 DEBUG (MainThread) [zeroconf] IPv6 scope_id 5 associated to the receiving interface
2025-01-29 22:20:18.164 DEBUG (MainThread) [zeroconf] Received from 'fe80::42:d8ff:fe35:8443':5353 [socket 12 (('::', 5353, 0, 0))]: <DNSIncoming:id=0, flags=0, truncated=False, n_q=2, n_ans=0, n_auth=0, n_add=0, questions=[quada[question,QM,in,homeassistant.local.], a[question,QM,in,homeassistant.local.]], answers=[]> (43 bytes) as [b'\x00\x00\x00\x00\x00\x02\x00\x00\x00\x00\x00\x00\rhomeassistant\x05local\x00\x00\x1c\x00\x01\xc0\x0c\x00\x01\x00\x01']

It does respond to the PTR query from discovery which is what allows it to work for a bit right away since it sends the unsolicited A record (in the wrong field) as a result of the PTR query which sticks around for 120 seconds.... and than it never responds to a the A queries again and we end up in the failure state.

@bdraco bdraco added the problem in device Issue lies within the device, such firmware, software, or user customization/config label Jan 29, 2025
@bdraco
Copy link
Member

bdraco commented Jan 29, 2025

I ordered one to see if I can come up with a workaround, but the vendor should fix the device so it responds to A queries.

@bdraco
Copy link
Member

bdraco commented Jan 29, 2025

Maybe could make a new class with _generate_request_query that does the A record query first and the AAAA record query second so if its is a problem with the device not understanding name compression the uncompressed name would be used for the first record.

To make that work we would need to reimplement https://github.com/aio-libs/aiohttp-asyncmdnsresolver/blob/7bce43593a21050d46a9cdd5f39be6d36ef67fa3/src/aiohttp_asyncmdnsresolver/_impl.py#L13 https://github.com/aio-libs/aiohttp-asyncmdnsresolver/blob/7bce43593a21050d46a9cdd5f39be6d36ef67fa3/src/aiohttp_asyncmdnsresolver/_impl.py#L22 https://github.com/aio-libs/aiohttp-asyncmdnsresolver/blob/7bce43593a21050d46a9cdd5f39be6d36ef67fa3/src/aiohttp_asyncmdnsresolver/_impl.py#L31 in zeroconf itself.

... thats assuming its not a UPPERcase lowercase bug in the device's stack.... really hard to guess what magic is needed to make the device happy without it in hand.

@jpbede
Copy link
Member

jpbede commented Jan 29, 2025

Wow thanks a lot @bdraco for your extensive debugging. Is there a way how I can verify (mostly the first 3 cases) this:

It could be any of the following:

  • The device only responds to PTR queries
  • The device requires a case sensitive A query ie SLZB-06.local
  • The device wants an ANY query and zeroconf is asking for specific records.
  • The device's mDNS stack might not implement name compression (which is required) and it is relying on the A record query happening first in the question
  • Some other spec violation

@bdraco
Copy link
Member

bdraco commented Jan 29, 2025

The best way would be to manually construct and send some DNSOutgoing objects based on the 3 cases and see what the device replies with

@bdraco
Copy link
Member

bdraco commented Jan 29, 2025

I'll see if I can come up with some sample test scripts

@jpbede
Copy link
Member

jpbede commented Jan 29, 2025

I'll see if I can come up with some sample test scripts

That would be awesome. Otherwise, I would have a look for myself tomorrow.
And thanks again for your work ❤

@bdraco
Copy link
Member

bdraco commented Jan 29, 2025

import asyncio
import logging

from zeroconf import (
    DNSOutgoing,
    DNSQuestion,
)
from zeroconf.asyncio import AsyncZeroconf
from zeroconf.const import _CLASS_IN, _FLAGS_QR_QUERY, _TYPE_A, _TYPE_AAAA, _TYPE_ANY

logging.basicConfig(level=logging.DEBUG)
logging.getLogger("zeroconf").setLevel(logging.DEBUG)
name = "SLZB-06.local."
lower_name = name.lower()


async def test_send_a_query_lowercase_a():
    """Send a query with the A record type with the lowercase name."""
    aiozc = AsyncZeroconf()
    await aiozc.zeroconf.async_wait_for_start()
    question = DNSQuestion(lower_name, _TYPE_A, _CLASS_IN)
    outgoing = DNSOutgoing(_FLAGS_QR_QUERY)
    outgoing.add_question(question)
    aiozc.zeroconf.async_send(outgoing)
    await asyncio.sleep(3)


async def test_send_a_query_lowercase_aaaa_and_a():
    """Send a query with the AAAA and A record types first.

    The A record will have name compression because
    it is the same as the AAAA record.
    """
    aiozc = AsyncZeroconf()
    await aiozc.zeroconf.async_wait_for_start()
    question_a = DNSQuestion(lower_name, _TYPE_A, _CLASS_IN)
    question_aaaa = DNSQuestion(lower_name, _TYPE_AAAA, _CLASS_IN)
    outgoing = DNSOutgoing(_FLAGS_QR_QUERY)
    outgoing.add_question(question_aaaa)
    outgoing.add_question(question_a)
    aiozc.zeroconf.async_send(outgoing)
    await asyncio.sleep(3)


async def test_send_a_query_lowercase_any():
    """Send a query with the ANY record type with the lowercase name."""
    aiozc = AsyncZeroconf()
    await aiozc.zeroconf.async_wait_for_start()
    question = DNSQuestion(lower_name, _TYPE_ANY, _CLASS_IN)
    outgoing = DNSOutgoing(_FLAGS_QR_QUERY)
    outgoing.add_question(question)
    aiozc.zeroconf.async_send(outgoing)
    await asyncio.sleep(3)


async def test_send_a_query_uppercase_a():
    """Send a query with the A record type with the uppercase name."""
    aiozc = AsyncZeroconf()
    await aiozc.zeroconf.async_wait_for_start()
    question = DNSQuestion(name, _TYPE_A, _CLASS_IN)
    outgoing = DNSOutgoing(_FLAGS_QR_QUERY)
    outgoing.add_question(question)
    aiozc.zeroconf.async_send(outgoing)
    await asyncio.sleep(3)


print("Running tests")
print("==============")
print("test_send_a_query_lowercase_a")
print("==============")
asyncio.run(test_send_a_query_lowercase_a())
print("==============")
print ("\n" * 10)

print("test_send_a_query_lowercase_aaaa_and_a")
print("==============")
asyncio.run(test_send_a_query_lowercase_aaaa_and_a())
print("==============")
print ("\n" * 10)

print("test_send_a_query_lowercase_any")
print("==============")
asyncio.run(test_send_a_query_lowercase_any())
print("==============")
print ("\n" * 10)

print("test_send_a_query_uppercase_a")
print("==============")
asyncio.run(test_send_a_query_uppercase_a())
print("==============")
print ("\n" * 10)

print("Done")

You'll need to capture the stdout and stderr

ie

python3 debug_136864.py > debug_136864.log 2>&1

@bdraco
Copy link
Member

bdraco commented Jan 29, 2025

@Anto79-ops just sent me his logs. Confirms the device is ignoring the questions for slzb-06.local as well in the same way

@tl-sl
Copy link
Contributor

tl-sl commented Jan 30, 2025

might be related to this.

this issue should be fixed in 2025.02.0b0

vendor should fix the device so it responds to A queries.

I will look into this, but seemingly can't reproduce here yet.

@Anto79-ops
Copy link
Author

might be related to this.

this issue should be fixed in 2025.02.0b0

@tl-sl thanks! Please ignore my comment about #135870. I don't see that issue anymore.

The mdns is the new issue. You may wish to wait maybe 5 minutes after HA startup, then the integration goes offline but the adapter itself works perfectly well.

@bdraco
Copy link
Member

bdraco commented Jan 30, 2025

Another random thought is everyone with the issue using unifi with multicast enhancement turned on?

@tl-sl
Copy link
Contributor

tl-sl commented Jan 30, 2025

You may wish to wait maybe 5 minutes after HA startup

Still waiting, its been about 2hrs without errors...

@Anto79-ops
Copy link
Author

Anto79-ops commented Jan 30, 2025

Another random thought is everyone with the issue using unifi with multicast enhancement turned on?>

just checked my settings:

Image

@Anto79-ops
Copy link
Author

Here's something you may want to see it seems to come back briefly and then go offline. For example, the history of one of the buttons:

Screenshot_20250129_201232_Home Assistant.jpg

@jpbede
Copy link
Member

jpbede commented Jan 30, 2025

Another random thought is everyone with the issue using unifi with multicast enhancement turned on?

No Unifi at all here.

See the attached debug log from the script. As @Anto79-ops already said, from time to time the device comes accessible but I can't figure out why.

debug_136864.log

@bdraco
Copy link
Member

bdraco commented Jan 30, 2025

See the attached debug log from the script. As @Anto79-ops already said, from time to time the device comes accessible but I can't figure out why.

debug_136864.log

In your debug log you get answers right away, and everything responds as expected.

I'm starting to think the device doesn't like PTR and SRV records queries in the same request

@bdraco
Copy link
Member

bdraco commented Jan 30, 2025

@jpbede Can you try this version with the other record types?

import asyncio
import logging

from zeroconf import (
    DNSOutgoing,
    DNSQuestion,
)
from zeroconf.asyncio import AsyncZeroconf
from zeroconf.const import (
    _CLASS_IN,
    _FLAGS_QR_QUERY,
    _TYPE_A,
    _TYPE_AAAA,
    _TYPE_ANY,
    _TYPE_TXT,
    _TYPE_SRV,
)

logging.basicConfig(level=logging.DEBUG)
logging.getLogger("zeroconf").setLevel(logging.DEBUG)
name = "SLZB-06.local."
lower_name = name.lower()


async def test_send_a_aaaa_query_lowercase_a_with_srv_txt():
    """Send a query with the A record type with the lowercase name."""
    aiozc = AsyncZeroconf()
    await aiozc.zeroconf.async_wait_for_start()
    outgoing = DNSOutgoing(_FLAGS_QR_QUERY)
    outgoing.add_question(DNSQuestion(lower_name, _TYPE_SRV, _CLASS_IN))
    outgoing.add_question(DNSQuestion(lower_name, _TYPE_TXT, _CLASS_IN))
    outgoing.add_question(DNSQuestion(lower_name, _TYPE_A, _CLASS_IN))
    outgoing.add_question(DNSQuestion(lower_name, _TYPE_AAAA, _CLASS_IN))
    aiozc.zeroconf.async_send(outgoing)
    await asyncio.sleep(3)


print("Running tests")
print("==============")
print("test_send_a_aaaa_query_lowercase_a_with_srv_txt")
print("==============")
asyncio.run(test_send_a_aaaa_query_lowercase_a_with_srv_txt())
print("==============")
print("\n" * 10)


print("Done")

@bdraco bdraco mentioned this issue Jan 30, 2025
19 tasks
@jpbede
Copy link
Member

jpbede commented Jan 30, 2025

@jpbede Can you try this version with the other record types?

Sure, here you go. From my pov, the device has not answered this question.

debug_136864 (1).log

@bdraco
Copy link
Member

bdraco commented Jan 30, 2025

So it seems that by asking for the TXT and SRV records in addition to the A and AAAA records it causes the query to fail

@bdraco
Copy link
Member

bdraco commented Jan 30, 2025

We don't actually need the SRV and TXT record requests so I've added a new class in zeroconf 0.142.0 to be able to make the request without them

#136940

@bdraco
Copy link
Member

bdraco commented Jan 30, 2025

Once thats in we can bump the aiohttp-asyncmdnsresolver to 0.0.2 which uses the new built-in zeroconf resolver classes https://github.com/aio-libs/aiohttp-asyncmdnsresolver/releases/tag/v0.0.2

@bdraco
Copy link
Member

bdraco commented Jan 30, 2025

#136942 to bump to 0.0.2 which will not send the SRV and TXT record queries

@jpbede
Copy link
Member

jpbede commented Jan 30, 2025

Nice, thanks a lot!

@bdraco
Copy link
Member

bdraco commented Jan 30, 2025

Please do reopen if it doesn't solve the issue. The test unit arrives tomorrow so I'll able to do more exhaustive testing when it does.

@jpbede
Copy link
Member

jpbede commented Jan 30, 2025

For the records, I run the v2.7.1 on the SLZB-06, which is the newest firmware.

Image

@Anto79-ops
Copy link
Author

same here, same device and FW. thanks all!

@jpbede
Copy link
Member

jpbede commented Jan 30, 2025

I'm going to close this as fixed for now. Thanks @bdraco for your help!

@jpbede jpbede closed this as completed Jan 30, 2025
@bdraco
Copy link
Member

bdraco commented Feb 1, 2025

Confirmed that the device never responds when the query includes the SRV and TXT record queries. As soon as I take it out an it only asks for AAAA and A it works just fine DEBUG:zeroconf:Received from '192.168.212.84':5353 [socket 6 (('0.0.0.0', 5353))]: <DNSIncoming:id=0, flags=33792, truncated=False, n_q=0, n_ans=3, n_auth=0, n_add=0, questions=[], answers=[record[a,in-unique,SLZB-06P7.local.]=120.0/119,192.168.212.84, record[quada,in-unique,SLZB-06P7.local.]=120.0/119,fe80::162b:2fff:fed7:2d57, record[quada,in-unique,SLZB-06P7.local.]=120.0/119,fdc8:d776:7cca:d246:162b:2fff:fed7:2d57]> (99 bytes) as [b'\x00\x00\x84\x00\x00\x00\x00\x03\x00\x00\x00\x00\tSLZB-06P7\x05local\x00\x00\x01\x80\x01\x00\x00\x00x\x00\x04\xc0\xa8\xd4T\xc0\x0c\x00\x1c\x80\x01\x00\x00\x00x\x00\x10\xfe\x80\x00\x00\x00\x00\x00\x00\x16+/\xff\xfe\xd7-W\xc0\x0c\x00\x1c\x80\x01\x00\x00\x00x\x00\x10\xfd\xc8\xd7v|\xca\xd2F\x16+/\xff\xfe\xd7-W']

@Anto79-ops
Copy link
Author

Anto79-ops commented Feb 1, 2025

Also wanted to add, since updating to b2 (8 hrs ago) with the above fix, all is back to normal now. Thanks again, all.

Screenshot_20250131_201909_Home Assistant.jpg

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
integration: smlight problem in device Issue lies within the device, such firmware, software, or user customization/config
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants