search

rmoesbergen / openwrt-ha-device-tracker

OpenWRT device tracker for Home Assistant that actually works
105 stars 18 forks source link

full_sync_polls not working #22

Closed walberjunior closed 1 year ago

walberjunior commented 1 year ago

I think the full_sync_polls option is not working properly. I use your device tracker and also UBUS integration. When restarting the HA, the connected devices do not sync again, I have to restart the wifi or walk around the house to change the router and be recognized again.

Do you need some log to check?

Here is a screenshot of the device trackers. Devices S20 and S20 SE are recognized by UBUS integration, but the same devices, S20 C2/C7 and S20 FE C2/C7 are not recognized.

tracker

rmoesbergen commented 1 year ago

Hi @walberjunior , can you explain your setup a bit more? Are the S20 and S20 SE the same devices as the S20 C2/C7, but with a different router/mac prefix? If you could post your configuration, that would help. Also logs are very helpful, especially if there are any errors or exceptions in them.

walberjunior commented 1 year ago

Yes, they are the same devices. S20, S20 FE and iPhone are tracked by UBUS. C7 is a tp-link Archer C7 and C2 is a TP-link Archer C2, both using your tracker.

Here the S20 is turned off and the problem also happens with the IPhone.

tracker2

The last log "away" on the router

Sun Feb 26 23:39:38 2023 daemon.info presence-detector[2547]: Device C7_xx:xx:xx:xx:xx is now away

The last log "home"on the router

Mon Feb 27 07:35:11 2023 daemon.info presence-detector[2547]: Device C7_xx:xx:xx:xx:xx is now at home

There is nothing in the logs:

Mon Feb 27 07:50:28 2023 daemon.err uhttpd[1977]: luci: accepted login on / for root from 192.168.0.11
Mon Feb 27 07:52:08 2023 daemon.notice hostapd: wlan1: AP-STA-DISCONNECTED xx:xx:xx:xx:xx
Mon Feb 27 07:52:08 2023 daemon.info hostapd: wlan1: STA xx:xx:xx:xx:xx IEEE 802.11: authenticated
Mon Feb 27 07:52:08 2023 daemon.info hostapd: wlan1: STA xx:xx:xx:xx:xx IEEE 802.11: associated (aid 2)
Mon Feb 27 07:52:08 2023 daemon.notice hostapd: wlan1: AP-STA-CONNECTED xx:xx:xx:xx:xx
Mon Feb 27 07:52:08 2023 daemon.info hostapd: wlan1: STA xx:xx:xx:xx:xx WPA: pairwise key handshake completed (RSN)
Mon Feb 27 07:52:08 2023 daemon.info dnsmasq-dhcp[10706]: DHCPDISCOVER(br-lan) xx:xx:xx:xx:xx
Mon Feb 27 07:52:08 2023 daemon.info dnsmasq-dhcp[10706]: DHCPOFFER(br-lan) 192.168.0.43 xx:xx:xx:xx:xx
Mon Feb 27 07:52:08 2023 daemon.info dnsmasq-dhcp[10706]: DHCPREQUEST(br-lan) 192.168.0.43 xx:xx:xx:xx:xx
Mon Feb 27 07:52:08 2023 daemon.info dnsmasq-dhcp[10706]: DHCPACK(br-lan) 192.168.0.43 xx:xx:xx:xx:xx nobreakrpi4
Mon Feb 27 07:54:14 2023 daemon.info dnsmasq-dhcp[10706]: DHCPREQUEST(br-lan) 192.168.0.51 xx:xx:xx:xx:xx
Mon Feb 27 07:54:14 2023 daemon.info dnsmasq-dhcp[10706]: DHCPACK(br-lan) 192.168.0.51 xx:xx:xx:xx:xx sala
Mon Feb 27 07:55:35 2023 daemon.info dnsmasq-dhcp[10706]: DHCPREQUEST(br-lan) 192.168.0.53 xx:xx:xx:xx:xx
Mon Feb 27 07:55:35 2023 daemon.info dnsmasq-dhcp[10706]: DHCPACK(br-lan) 192.168.0.53 xx:xx:xx:xx:xx corredor
Mon Feb 27 07:59:21 2023 daemon.notice netifd: wan (2197): udhcpc: sending renew to 100.122.2.42
Mon Feb 27 07:59:21 2023 daemon.notice netifd: wan (2197): udhcpc: lease of 177.179.32.189 obtained, lease time 3600
Mon Feb 27 08:06:23 2023 daemon.info dnsmasq[10706]: read /etc/hosts - 4 addresses
Mon Feb 27 08:06:23 2023 daemon.info dnsmasq[10706]: read /tmp/hosts/odhcpd - 4 addresses
Mon Feb 27 08:06:23 2023 daemon.info dnsmasq[10706]: read /tmp/hosts/dhcp.cfg01411c - 35 addresses
Mon Feb 27 08:06:23 2023 daemon.info dnsmasq-dhcp[10706]: read /etc/ethers - 0 addresses
Mon Feb 27 08:06:24 2023 daemon.info dnsmasq[10706]: read /etc/hosts - 4 addresses
Mon Feb 27 08:06:24 2023 daemon.info dnsmasq[10706]: read /tmp/hosts/odhcpd - 6 addresses
Mon Feb 27 08:06:24 2023 daemon.info dnsmasq[10706]: read /tmp/hosts/dhcp.cfg01411c - 35 addresses
Mon Feb 27 08:06:24 2023 daemon.info dnsmasq-dhcp[10706]: read /etc/ethers - 0 addresses
Mon Feb 27 08:14:33 2023 daemon.info dnsmasq-dhcp[10706]: DHCPREQUEST(br-lan) 192.168.0.52 xx:xx:xx:xx:xx
Mon Feb 27 08:14:33 2023 daemon.info dnsmasq-dhcp[10706]: DHCPACK(br-lan) 192.168.0.52 xx:xx:xx:xx:xx copa
2023-02-27 07:51:31.136 WARNING (SyncWorker_4) [homeassistant.loader] We found a custom integration webrtc which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-02-27 07:51:31.138 WARNING (SyncWorker_4) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-02-27 07:51:31.139 WARNING (SyncWorker_4) [homeassistant.loader] We found a custom integration next_holiday which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-02-27 07:51:31.140 WARNING (SyncWorker_4) [homeassistant.loader] We found a custom integration localtuya which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-02-27 07:51:31.141 WARNING (SyncWorker_4) [homeassistant.loader] We found a custom integration frigate which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-02-27 07:51:31.143 WARNING (SyncWorker_4) [homeassistant.loader] We found a custom integration duckdns_ipv4_ipv6 which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-02-27 07:51:31.146 WARNING (SyncWorker_4) [homeassistant.loader] We found a custom integration arpscan_tracker which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-02-27 07:51:31.148 WARNING (SyncWorker_4) [homeassistant.loader] We found a custom integration ssh which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-02-27 07:51:31.150 WARNING (SyncWorker_4) [homeassistant.loader] We found a custom integration nodered which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-02-27 07:51:31.153 WARNING (SyncWorker_4) [homeassistant.loader] We found a custom integration dht which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-02-27 07:51:31.157 WARNING (SyncWorker_4) [homeassistant.loader] We found a custom integration rpi_gpio which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-02-27 07:51:53.306 WARNING (MainThread) [homeassistant.components.sensor] Platform rest not ready yet: All connection attempts failed; Retrying in background in 30 seconds
2023-02-27 07:52:22.643 ERROR (MainThread) [homeassistant.config_entries] Error setting up entry petnobre for update
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/config_entries.py", line 382, in async_setup
    result = await component.async_setup_entry(hass, self)
  File "/usr/src/homeassistant/homeassistant/components/update/__init__.py", line 115, in async_setup_entry
    return await component.async_setup_entry(entry)
  File "/usr/src/homeassistant/homeassistant/helpers/entity_component.py", line 166, in async_setup_entry
    raise ValueError("Config entry has already been setup!")
ValueError: Config entry has already been setup!

  "offline_after": 2,
  "poll_interval": 10,
  "full_sync_polls": 2,
  "ap_name": "C7",
  "location": "home",
  "away": "not_home",
  "debug": false

But as I said, if I move from the range of C7 to C2, or vice versa, the device is detected

rmoesbergen commented 1 year ago

Are you using the latest version of the tracker script? There have been a number of fixes that impacted recovery after HA restart and full sync. If you are, please enable debug logging so we can get a better view of what's happening. The full-sync events are only logged with debug mode enabled.

walberjunior commented 1 year ago

I'm using the last version

Mon Feb 27 12:55:22 2023 daemon.err uhttpd[1977]: luci: accepted login on /admin/status/overview for root from 192.168.0.11
Mon Feb 27 12:55:31 2023 authpriv.info dropbear[23319]: Child connection from 192.168.0.11:28784
Mon Feb 27 12:55:33 2023 authpriv.notice dropbear[23319]: Password auth succeeded for 'root' from 192.168.0.11:28784
Mon Feb 27 12:55:43 2023 authpriv.info dropbear[23340]: Child connection from 192.168.0.11:28801
Mon Feb 27 12:55:44 2023 authpriv.notice dropbear[23340]: Password auth succeeded for 'root' from 192.168.0.11:28801
Mon Feb 27 12:55:56 2023 daemon.info presence-detector[2547]: Stopping...
Mon Feb 27 12:56:08 2023 daemon.info presence-detector[23821]: Device C7_xx:xx:xx:xx:xx:xx is now at home
########################
Reboot HA
########################
Mon Feb 27 12:56:09 2023 daemon.debug presence-detector[23821]: API Response: b'[]'
Mon Feb 27 12:56:19 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:56:29 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:56:39 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:56:49 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:56:59 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:57:09 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:57:19 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:57:29 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:57:39 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:57:49 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:57:59 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:58:10 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:58:20 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:58:30 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:58:40 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:58:50 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:59:00 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:59:10 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:59:20 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:59:22 2023 daemon.notice netifd: wan (2197): udhcpc: sending renew to 100.122.2.42
Mon Feb 27 12:59:22 2023 daemon.notice netifd: wan (2197): udhcpc: lease of xxx.xxx.xxx.xxx obtained, lease time 3600
Mon Feb 27 12:59:30 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:59:40 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 12:59:50 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 13:00:00 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 13:00:10 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 13:00:20 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 13:00:31 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 13:00:41 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 13:00:51 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 13:01:01 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}
Mon Feb 27 13:01:11 2023 daemon.debug presence-detector[23821]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 1}

Only S20 FE at home this time: tracker3

rmoesbergen commented 1 year ago

@walberjunior I found the issue and just pushed a fixed. Please try it out and let me know the results.

walberjunior commented 1 year ago

It's buggy. It works sometimes, but most of the times it times out and I have to restart presence-detector.

Tue Feb 28 17:52:55 2023 daemon.info presence-detector[4610]: Stopping...
Tue Feb 28 17:53:03 2023 daemon.info presence-detector[5392]: Device C7_xx:xx:xx:xx:xx:xx is now at home
Tue Feb 28 17:53:03 2023 daemon.debug presence-detector[5392]: API Response: b'[]'
Tue Feb 28 17:53:03 2023 daemon.info presence-detector[5392]: Device C7_xx:xx:xx:xx:xx:xx is now at home
Tue Feb 28 17:53:04 2023 daemon.debug presence-detector[5392]: API Response: b'[]'
Tue Feb 28 17:53:04 2023 daemon.info presence-detector[5392]: Device C7_xx:xx:xx:xx:xx:xx is now at home
Tue Feb 28 17:53:04 2023 daemon.debug presence-detector[5392]: API Response: b'[]'
Tue Feb 28 17:53:04 2023 daemon.info presence-detector[5392]: Device C7_xx:xx:xx:xx:xx:xx is now at home
Tue Feb 28 17:53:04 2023 daemon.debug presence-detector[5392]: API Response: b'[]'
Tue Feb 28 17:53:04 2023 daemon.info presence-detector[5392]: Device C7_xx:xx:xx:xx:xx:xx is now at home
Tue Feb 28 17:53:04 2023 daemon.debug presence-detector[5392]: API Response: b'[]'
Tue Feb 28 17:53:14 2023 daemon.debug presence-detector[5392]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2}
Tue Feb 28 17:53:14 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:14 2023 daemon.debug presence-detector[5392]: API Response: b'[]'
Tue Feb 28 17:53:14 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:14 2023 daemon.debug presence-detector[5392]: API Response: b'[]'
Tue Feb 28 17:53:14 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:14 2023 daemon.debug presence-detector[5392]: API Response: b'[]'
Tue Feb 28 17:53:14 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:14 2023 daemon.debug presence-detector[5392]: API Response: b'[]'
Tue Feb 28 17:53:14 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:14 2023 daemon.debug presence-detector[5392]: API Response: b'[]'
Tue Feb 28 17:53:24 2023 daemon.debug presence-detector[5392]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2}
Tue Feb 28 17:53:34 2023 daemon.debug presence-detector[5392]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2}
Tue Feb 28 17:53:34 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:34 2023 daemon.debug presence-detector[5392]: <urlopen error [Errno 146] Connection refused>
Tue Feb 28 17:53:34 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:34 2023 daemon.debug presence-detector[5392]: <urlopen error [Errno 146] Connection refused>
Tue Feb 28 17:53:34 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:34 2023 daemon.debug presence-detector[5392]: <urlopen error [Errno 146] Connection refused>
Tue Feb 28 17:53:34 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:34 2023 daemon.debug presence-detector[5392]: <urlopen error [Errno 146] Connection refused>
Tue Feb 28 17:53:34 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:34 2023 daemon.debug presence-detector[5392]: <urlopen error [Errno 146] Connection refused>
Tue Feb 28 17:53:44 2023 daemon.debug presence-detector[5392]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2}
Tue Feb 28 17:53:44 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:44 2023 daemon.debug presence-detector[5392]: HTTP Error 400: Bad Request
Tue Feb 28 17:53:44 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:44 2023 daemon.debug presence-detector[5392]: HTTP Error 400: Bad Request
Tue Feb 28 17:53:44 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:44 2023 daemon.debug presence-detector[5392]: HTTP Error 400: Bad Request
Tue Feb 28 17:53:44 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:44 2023 daemon.debug presence-detector[5392]: HTTP Error 400: Bad Request
Tue Feb 28 17:53:44 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:44 2023 daemon.debug presence-detector[5392]: HTTP Error 400: Bad Request
Tue Feb 28 17:53:54 2023 daemon.debug presence-detector[5392]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2}
Tue Feb 28 17:53:54 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:55 2023 daemon.debug presence-detector[5392]: HTTP Error 400: Bad Request
Tue Feb 28 17:53:55 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:53:56 2023 daemon.debug presence-detector[5392]: HTTP Error 400: Bad Request
Tue Feb 28 17:53:56 2023 daemon.debug presence-detector[5392]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]: Exception in thread Thread-1:
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]: Traceback (most recent call last):
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:   File "/usr/lib/python3.9/threading.py", line 980, in _bootstrap_inner
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:   File "/etc/config/presence-detector.py", line 216, in run
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:     self.full_sync()
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:   File "/etc/config/presence-detector.py", line 123, in full_sync
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:     sync_ok &= self._ha_seen(client)
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:   File "/etc/config/presence-detector.py", line 98, in _ha_seen
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:     response = self._post(
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:   File "/etc/config/presence-detector.py", line 81, in _post
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:     with request.urlopen(req, timeout=5) as response:
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:   File "/usr/lib/python3.9/urllib/request.py", line 214, in urlopen
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:   File "/usr/lib/python3.9/urllib/request.py", line 517, in open
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:   File "/usr/lib/python3.9/urllib/request.py", line 534, in _open
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:   File "/usr/lib/python3.9/urllib/request.py", line 494, in _call_chain
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:   File "/usr/lib/python3.9/urllib/request.py", line 1375, in http_open
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:   File "/usr/lib/python3.9/urllib/request.py", line 1350, in do_open
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:   File "/usr/lib/python3.9/http/client.py", line 1377, in getresponse
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:   File "/usr/lib/python3.9/http/client.py", line 320, in begin
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:   File "/usr/lib/python3.9/http/client.py", line 281, in _read_status
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]:   File "/usr/lib/python3.9/socket.py", line 704, in readinto
Tue Feb 28 17:54:01 2023 daemon.err presence-detector.py[5392]: socket.timeout: timed out
Tue Feb 28 17:54:18 2023 daemon.notice hostapd: wlan1: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
Tue Feb 28 17:54:18 2023 daemon.info hostapd: wlan1: STA xx:xx:xx:xx:xx:xx IEEE 802.11: authenticated
Tue Feb 28 17:54:18 2023 daemon.info hostapd: wlan1: STA xx:xx:xx:xx:xx:xx IEEE 802.11: associated (aid 2)
Tue Feb 28 17:54:18 2023 daemon.notice hostapd: wlan1: AP-STA-CONNECTED xx:xx:xx:xx:xx:xx
Tue Feb 28 17:54:18 2023 daemon.info hostapd: wlan1: STA xx:xx:xx:xx:xx:xx WPA: pairwise key handshake completed (RSN)
Tue Feb 28 17:54:18 2023 daemon.info dnsmasq-dhcp[3259]: DHCPDISCOVER(br-lan) xx:xx:xx:xx:xx:xx
Tue Feb 28 17:54:18 2023 daemon.info dnsmasq-dhcp[3259]: DHCPOFFER(br-lan) 192.168.0.43 xx:xx:xx:xx:xx:xx
Tue Feb 28 17:54:18 2023 daemon.info dnsmasq-dhcp[3259]: DHCPREQUEST(br-lan) 192.168.0.43 xx:xx:xx:xx:xx:xx
Tue Feb 28 17:54:18 2023 daemon.info dnsmasq-dhcp[3259]: DHCPACK(br-lan) 192.168.0.43 xx:xx:xx:xx:xx:xx nobreakrpi4
Tue Feb 28 17:56:53 2023 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED xx:xx:xx:xx:xx:xx
Tue Feb 28 17:57:00 2023 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: authenticated
Tue Feb 28 17:57:00 2023 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx IEEE 802.11: associated (aid 1)
Tue Feb 28 17:57:01 2023 daemon.notice hostapd: wlan0: AP-STA-CONNECTED xx:xx:xx:xx:xx:xx
Tue Feb 28 17:57:01 2023 daemon.info hostapd: wlan0: STA xx:xx:xx:xx:xx:xx WPA: pairwise key handshake completed (RSN)
Tue Feb 28 17:57:01 2023 daemon.info dnsmasq-dhcp[3259]: DHCPREQUEST(br-lan) 192.168.0.11 xx:xx:xx:xx:xx:xx
Tue Feb 28 17:57:01 2023 daemon.info dnsmasq-dhcp[3259]: DHCPACK(br-lan) 192.168.0.11 xx:xx:xx:xx:xx:xx NOTE
Tue Feb 28 17:58:04 2023 daemon.info presence-detector[5392]: Stopping...
Tue Feb 28 17:58:11 2023 daemon.info presence-detector[5917]: Device C7_xx:xx:xx:xx:xx:xx is now at home
Tue Feb 28 17:58:11 2023 daemon.debug presence-detector[5917]: API Response: b'[]'
Tue Feb 28 17:58:11 2023 daemon.info presence-detector[5917]: Device C7_xx:xx:xx:xx:xx:xx is now at home
Tue Feb 28 17:58:11 2023 daemon.debug presence-detector[5917]: API Response: b'[]'
Tue Feb 28 17:58:11 2023 daemon.info presence-detector[5917]: Device C7_xx:xx:xx:xx:xx:xx is now at home
Tue Feb 28 17:58:11 2023 daemon.debug presence-detector[5917]: API Response: b'[]'
Tue Feb 28 17:58:11 2023 daemon.info presence-detector[5917]: Device C7_xx:xx:xx:xx:xx:xx is now at home
Tue Feb 28 17:58:11 2023 daemon.debug presence-detector[5917]: API Response: b'[]'
Tue Feb 28 17:58:11 2023 daemon.info presence-detector[5917]: Device C7_xx:xx:xx:xx:xx:xx is now at home
Tue Feb 28 17:58:11 2023 daemon.debug presence-detector[5917]: API Response: b'[]'
Tue Feb 28 17:58:21 2023 daemon.debug presence-detector[5917]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2}
Tue Feb 28 17:58:21 2023 daemon.debug presence-detector[5917]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:58:22 2023 daemon.debug presence-detector[5917]: API Response: b'[]'
Tue Feb 28 17:58:22 2023 daemon.debug presence-detector[5917]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:58:22 2023 daemon.debug presence-detector[5917]: API Response: b'[]'
Tue Feb 28 17:58:22 2023 daemon.debug presence-detector[5917]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:58:22 2023 daemon.debug presence-detector[5917]: API Response: b'[]'
Tue Feb 28 17:58:22 2023 daemon.debug presence-detector[5917]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:58:22 2023 daemon.debug presence-detector[5917]: API Response: b'[]'
Tue Feb 28 17:58:22 2023 daemon.debug presence-detector[5917]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:58:22 2023 daemon.debug presence-detector[5917]: API Response: b'[]'
Tue Feb 28 17:58:32 2023 daemon.debug presence-detector[5917]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2}
Tue Feb 28 17:58:42 2023 daemon.debug presence-detector[5917]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2}
Tue Feb 28 17:58:42 2023 daemon.debug presence-detector[5917]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:58:42 2023 daemon.debug presence-detector[5917]: HTTP Error 400: Bad Request
Tue Feb 28 17:58:42 2023 daemon.debug presence-detector[5917]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:58:42 2023 daemon.debug presence-detector[5917]: HTTP Error 400: Bad Request
Tue Feb 28 17:58:42 2023 daemon.debug presence-detector[5917]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:58:42 2023 daemon.debug presence-detector[5917]: HTTP Error 400: Bad Request
Tue Feb 28 17:58:42 2023 daemon.debug presence-detector[5917]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:58:42 2023 daemon.debug presence-detector[5917]: HTTP Error 400: Bad Request
Tue Feb 28 17:58:42 2023 daemon.debug presence-detector[5917]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:58:42 2023 daemon.debug presence-detector[5917]: HTTP Error 400: Bad Request
Tue Feb 28 17:58:52 2023 daemon.debug presence-detector[5917]: Clients seen: {'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2, 'C7_xx:xx:xx:xx:xx:xx': 2}
Tue Feb 28 17:58:52 2023 daemon.debug presence-detector[5917]: full sync C7_xx:xx:xx:xx:xx:xx
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]: Exception in thread Thread-1:
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]: Traceback (most recent call last):
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:   File "/usr/lib/python3.9/threading.py", line 980, in _bootstrap_inner
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:   File "/etc/config/presence-detector.py", line 216, in run
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:     self.full_sync()
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:   File "/etc/config/presence-detector.py", line 123, in full_sync
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:     sync_ok &= self._ha_seen(client)
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:   File "/etc/config/presence-detector.py", line 98, in _ha_seen
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:     response = self._post(
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:   File "/etc/config/presence-detector.py", line 81, in _post
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:     with request.urlopen(req, timeout=5) as response:
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:   File "/usr/lib/python3.9/urllib/request.py", line 214, in urlopen
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:   File "/usr/lib/python3.9/urllib/request.py", line 517, in open
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:   File "/usr/lib/python3.9/urllib/request.py", line 534, in _open
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:   File "/usr/lib/python3.9/urllib/request.py", line 494, in _call_chain
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:   File "/usr/lib/python3.9/urllib/request.py", line 1375, in http_open
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:   File "/usr/lib/python3.9/urllib/request.py", line 1350, in do_open
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:   File "/usr/lib/python3.9/http/client.py", line 1377, in getresponse
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:   File "/usr/lib/python3.9/http/client.py", line 320, in begin
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:   File "/usr/lib/python3.9/http/client.py", line 281, in _read_status
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]:   File "/usr/lib/python3.9/socket.py", line 704, in readinto
Tue Feb 28 17:58:57 2023 daemon.err presence-detector.py[5917]: socket.timeout: timed out
rmoesbergen commented 1 year ago

@walberjunior Ok, the original issue is fixed, but now another exception thrown by urrlib is not caught. I just pushed a fix for that, please let me know if it works now.

walberjunior commented 1 year ago

Is working. Thanks.

I have a request/suggestion. What do you think about having a whitelist? Maybe a filter option, with option to toggle between white/black list?

{
  "hass_url": "http://hassio.local:8123",
  "hass_token" : "<Home Assistant REST API Bearer Token>",
  "interfaces": ["hostapd.wlan0", "hostapd.wlan1"],
  "white_list": true
  "filter": ["01:23:45:67:89:ab"], <<< only track this devices
  "params": {
    "00:00:00:00:00:00": {
      "mac": "ff:ff:ff:ff:ff:ff",
      "hostname": "Dave",
      "dev_id": "phonedave"
    }
  },
  "offline_after": 3,
  "poll_interval": 15,
  "full_sync_polls": 10,
  "ap_name": "",
  "location": "home",
  "away": "not_home",
  "debug": false
}
{
  "hass_url": "http://hassio.local:8123",
  "hass_token" : "<Home Assistant REST API Bearer Token>",
  "interfaces": ["hostapd.wlan0", "hostapd.wlan1"],
  "white_list": false
  "filter": ["01:23:45:67:89:ab"], <<< don´t track this devices
  "params": {
    "00:00:00:00:00:00": {
      "mac": "ff:ff:ff:ff:ff:ff",
      "hostname": "Dave",
      "dev_id": "phonedave"
    }
  },
  "offline_after": 3,
  "poll_interval": 15,
  "full_sync_polls": 10,
  "ap_name": "",
  "location": "home",
  "away": "not_home",
  "debug": false
}
rmoesbergen commented 1 year ago

That could be a useful feature, yes. Can you make a separate issue for that please?

rmoesbergen commented 1 year ago

@walberjunior I found some more issues when ap_name was set (ubus events would send the client mac without ap_name prefix). Please update to the latest version from the 'main' branch.