probot-home-assistant[bot]
commented
3 years ago itunes documentation itunes source (message by IssueLinks)
Closed deftdawg closed 3 years ago
probot-home-assistant[bot]
commented
3 years ago itunes documentation itunes source (message by IssueLinks)
deftdawg
commented
3 years ago I believe this to be an issue with supervisor rather than core -> https://github.com/home-assistant/supervisor/issues/3164
deftdawg
commented
3 years ago OK, seems I'm wrong... core is not starting up and apparently supervisor is chill about it...
Last message in the logs is iTunes everytime:
2021-09-28 21:45:21 WARNING (Thread-4) [homeassistant.util.executor] Thread[SyncWorker_6] is still running at shutdown: File "/usr/local/lib/python3.9/threading.py", line 930, in _bootstrap
self._bootstrap_inner()
File "/usr/local/lib/python3.9/threading.py", line 973, in _bootstrap_inner
self.run()
File "/usr/local/lib/python3.9/threading.py", line 910, in run
self._target(*self._args, **self._kwargs)
File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 77, in _worker
work_item.run()
File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 52, in run
result = self.fn(*self.args, **self.kwargs)
File "/usr/src/homeassistant/homeassistant/components/itunes/media_player.py", line 193, in setup_platform
ItunesDevice(
File "/usr/src/homeassistant/homeassistant/components/itunes/media_player.py", line 230, in __init__
self.update()
File "/usr/src/homeassistant/homeassistant/components/itunes/media_player.py", line 271, in update
now_playing = self.client.now_playing()
File "/usr/src/homeassistant/homeassistant/components/itunes/media_player.py", line 113, in now_playing
return self._request("GET", "/now_playing")
File "/usr/src/homeassistant/homeassistant/components/itunes/media_player.py", line 93, in _request
response = requests.get(url, timeout=DEFAULT_TIMEOUT)
File "/usr/local/lib/python3.9/site-packages/requests/api.py", line 76, in get
return request('get', url, params=params, **kwargs)
File "/usr/local/lib/python3.9/site-packages/requests/api.py", line 61, in request
return session.request(method=method, url=url, **kwargs)
File "/usr/local/lib/python3.9/site-packages/requests/sessions.py", line 542, in request
resp = self.send(prep, **send_kwargs)
File "/usr/local/lib/python3.9/site-packages/requests/sessions.py", line 655, in send
r = adapter.send(request, **kwargs)
File "/usr/local/lib/python3.9/site-packages/requests/adapters.py", line 439, in send
resp = conn.urlopen(
File "/usr/local/lib/python3.9/site-packages/urllib3/connectionpool.py", line 699, in urlopen
httplib_response = self._make_request(
File "/usr/local/lib/python3.9/site-packages/urllib3/connectionpool.py", line 394, in _make_request
conn.request(method, url, **httplib_request_kw)
File "/usr/local/lib/python3.9/site-packages/urllib3/connection.py", line 234, in request
super(HTTPConnection, self).request(method, url, body=body, headers=headers)
File "/usr/local/lib/python3.9/http/client.py", line 1279, in request
self._send_request(method, url, body, headers, encode_chunked)
File "/usr/local/lib/python3.9/http/client.py", line 1325, in _send_request
self.endheaders(body, encode_chunked=encode_chunked)
File "/usr/local/lib/python3.9/http/client.py", line 1274, in endheaders
self._send_output(message_body, encode_chunked=encode_chunked)
File "/usr/local/lib/python3.9/http/client.py", line 1034, in _send_output
self.send(msg)
File "/usr/local/lib/python3.9/http/client.py", line 974, in send
self.connect()
File "/usr/local/lib/python3.9/site-packages/urllib3/connection.py", line 200, in connect
conn = self._new_conn()
File "/usr/local/lib/python3.9/site-packages/urllib3/connection.py", line 169, in _new_conn
conn = connection.create_connection(
File "/usr/local/lib/python3.9/site-packages/urllib3/util/connection.py", line 73, in create_connection
for res in socket.getaddrinfo(host, port, family, socket.SOCK_STREAM):
File "/usr/local/lib/python3.9/socket.py", line 954, in getaddrinfo
for res in _socket.getaddrinfo(host, port, family, type, proto, flags):Next things to try is nuke iTunes from configuration via nano and ha host reboot
After that archive the ha db and reboot...
See if either of those works.
deftdawg
commented
3 years ago Ok, removing iTunes and it got stuck again at a different component...
2021-09-29 09:31:36 INFO (MainThread) [homeassistant.setup] Setup of domain tplink took 0.0 seconds
2021-09-29 09:31:36 INFO (MainThread) [homeassistant.setup] Setting up energy
2021-09-29 09:31:36 INFO (MainThread) [homeassistant.setup] Setup of domain energy took 0.0 seconds
2021-09-29 09:31:36 INFO (MainThread) [homeassistant.setup] Setting up network
2021-09-29 09:31:37 INFO (MainThread) [homeassistant.setup] Setting up hacs
2021-09-29 09:31:37 INFO (MainThread) [homeassistant.setup] Setup of domain hacs took 0.0 seconds
2021-09-29 09:31:37 INFO (MainThread) [homeassistant.components.light] Setting up light.decora_wifi
2021-09-29 09:31:37 INFO (MainThread) [homeassistant.setup] Setting up usb
2021-09-29 09:31:37 INFO (MainThread) [homeassistant.setup] Setup of domain usb took 0.0 seconds
2021-09-29 09:31:37 INFO (MainThread) [homeassistant.setup] Setup of domain system_health took 7.8 seconds
2021-09-29 09:31:38 INFO (MainThread) [homeassistant.setup] Setting up tesla
2021-09-29 09:31:38 INFO (MainThread) [homeassistant.setup] Setup of domain tesla took 0.0 seconds
2021-09-29 09:31:38 INFO (MainThread) [homeassistant.setup] Setting up switch
2021-09-29 09:31:38 INFO (MainThread) [homeassistant.setup] Setup of domain switch took 0.0 seconds
2021-09-29 09:31:39 INFO (MainThread) [homeassistant.setup] Setting up template
2021-09-29 09:31:39 INFO (MainThread) [homeassistant.setup] Setup of domain template took 0.0 seconds
2021-09-29 09:31:39 INFO (SyncWorker_5) [homeassistant.loader] Loaded dnsip from homeassistant.components.dnsip
2021-09-29 09:31:39 ERROR (MainThread) [custom_components.dyson_cloud] Cannot connect to Dyson cloud service.
2021-09-29 09:31:39 WARNING (MainThread) [homeassistant.config_entries] Config entry '***@gmail.com (CA)' for dyson_cloud integration not ready yet: None; Retrying in background
2021-09-29 09:31:39 INFO (MainThread) [homeassistant.components.notify] Setting up notify.lametric
2021-09-29 09:31:39 INFO (MainThread) [homeassistant.setup] Setup of domain light took 7.0 seconds
2021-09-29 09:31:39 INFO (MainThread) [homeassistant.setup] Setup of domain tag took 9.1 seconds
2021-09-29 09:31:39 INFO (MainThread) [homeassistant.components.switch] Setting up switch.command_line
2021-09-29 09:31:39 INFO (MainThread) [homeassistant.setup] Setting up binary_sensor
2021-09-29 09:31:39 INFO (MainThread) [homeassistant.setup] Setup of domain binary_sensor took 0.0 seconds
2021-09-29 09:31:39 DEBUG (SyncWorker_4) [nuheat.api] Creating NuHeat session
2021-09-29 09:31:39 INFO (MainThread) [custom_components.hacs] HACS is enabled
2021-09-29 09:31:39 INFO (MainThread) [custom_components.hacs]
-------------------------------------------------------------------
HACS (Home Assistant Community Store)
Version: 1.15.2
This is a custom integration
If you have any issues with this you need to open an issue here:
https://github.com/hacs/integration/issues
-------------------------------------------------------------------
2021-09-29 09:31:40 INFO (MainThread) [homeassistant.setup] Setup of domain group took 8.2 seconds
2021-09-29 09:31:40 INFO (SyncWorker_0) [homeassistant.loader] Loaded fan from homeassistant.components.fan
2021-09-29 09:31:40 INFO (MainThread) [homeassistant.components.lock] Setting up lock.template
2021-09-29 09:31:40 INFO (MainThread) [homeassistant.components.switch] Setting up switch.template
2021-09-29 09:31:40 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.template
2021-09-29 09:31:40 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.workday
2021-09-29 09:31:40 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.command_line
2021-09-29 09:31:40 INFO (SyncWorker_0) [homeassistant.loader] Loaded openhardwaremonitor from homeassistant.components.openhardwaremonitor
2021-09-29 09:31:40 WARNING (MainThread) [homeassistant.setup] Setup of zone is taking over 10 seconds.
2021-09-29 09:31:40 INFO (MainThread) [hangups.channel] Requesting new gsessionid and SID...
2021-09-29 09:31:40 INFO (SyncWorker_7) [homeassistant.loader] Loaded ffmpeg from homeassistant.components.ffmpeg
2021-09-29 09:31:40 INFO (MainThread) [homeassistant.setup] Setting up ping
2021-09-29 09:31:40 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.hassio
2021-09-29 09:31:40 INFO (MainThread) [homeassistant.setup] Setup of domain timer took 22.5 seconds
2021-09-29 09:31:40 INFO (MainThread) [homeassistant.setup] Setup of domain input_datetime took 22.2 seconds
2021-09-29 09:31:40 INFO (MainThread) [homeassistant.setup] Setup of domain input_text took 22.2 seconds
2021-09-29 09:31:41 INFO (MainThread) [homeassistant.setup] Setup of domain input_boolean took 22.1 seconds
2021-09-29 09:31:41 INFO (Thread-3) [homeassistant.components.mqtt] Connected to MQTT server core-mosquitto:1883 (0)
2021-09-29 09:31:41 INFO (MainThread) [homeassistant.setup] Setup of domain network took 4.4 seconds
2021-09-29 09:31:41 INFO (MainThread) [homeassistant.setup] Setup of domain counter took 22.0 seconds
2021-09-29 09:31:41 INFO (MainThread) [homeassistant.components.notify] Setting up notify.group
2021-09-29 09:31:41 INFO (MainThread) [homeassistant.setup] Setup of domain input_select took 10.7 seconds
2021-09-29 09:31:41 INFO (MainThread) [homeassistant.setup] Setup of domain input_number took 10.7 seconds
2021-09-29 09:31:41 INFO (MainThread) [homeassistant.components.notify] Setting up notify.hangouts
2021-09-29 09:31:41 INFO (MainThread) [homeassistant.setup] Setup of domain scene took 22.4 seconds
2021-09-29 09:31:41 INFO (SyncWorker_0) [homeassistant.loader] Loaded systemmonitor from homeassistant.components.systemmonitor
2021-09-29 09:31:41 INFO (MainThread) [homeassistant.setup] Setup of domain ping took 1.0 seconds
2021-09-29 09:31:41 INFO (SyncWorker_4) [homeassistant.loader] Loaded mjpeg from homeassistant.components.mjpeg
2021-09-29 09:31:41 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.updater
2021-09-29 09:31:42 INFO (MainThread) [homeassistant.setup] Setting up ipp
2021-09-29 09:31:42 INFO (MainThread) [homeassistant.setup] Setup of domain ipp took 0.0 seconds
2021-09-29 09:31:44 INFO (MainThread) [homeassistant.setup] Setting up brother
2021-09-29 09:31:44 INFO (MainThread) [homeassistant.setup] Setup of domain brother took 0.0 seconds
2021-09-29 09:31:45 INFO (SyncWorker_0) [homeassistant.loader] Loaded google_translate from homeassistant.components.google_translate
2021-09-29 09:31:46 INFO (MainThread) [homeassistant.setup] Setting up zwave_js
2021-09-29 09:31:46 INFO (MainThread) [homeassistant.setup] Setup of domain zwave_js took 0.0 seconds
2021-09-29 09:31:46 WARNING (MainThread) [homeassistant.components.media_player] Setup of media_player platform channels is taking over 10 seconds.
2021-09-29 09:31:46 INFO (SyncWorker_2) [homeassistant.loader] Loaded qnap from homeassistant.components.qnap
2021-09-29 09:31:46 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ping
2021-09-29 09:31:46 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.ping
2021-09-29 09:31:46 INFO (SyncWorker_7) [homeassistant.loader] Loaded climate from homeassistant.components.climate
2021-09-29 09:31:46 INFO (MainThread) [homeassistant.components.tplink.common] Discovered 1 TP-Link of expected 3 smart home device(s)
2021-09-29 09:31:46 INFO (SyncWorker_1) [homeassistant.loader] Loaded generic from homeassistant.components.generic
2021-09-29 09:31:51 WARNING (MainThread) [homeassistant.config_entries] Config entry 'HL-3170CDW U63478C4J354548' for brother integration not ready yet: Bad IPv4/UDP transport address HL-3170CDW@161: [Errno -3] Try againcaused by <class 'socket.gaierror'>: [Errno -3] Try again; Retrying in background
2021-09-29 09:31:51 INFO (MainThread) [homeassistant.setup] Setting up wemo
2021-09-29 09:31:51 INFO (MainThread) [homeassistant.setup] Setup of domain wemo took 0.0 seconds
2021-09-29 09:31:51 INFO (MainThread) [homeassistant.setup] Setting up zeroconf
2021-09-29 09:31:51 WARNING (MainThread) [homeassistant.config_entries] Config entry '192.168.1.2' for adguard integration not ready yet: Timeout occurred while connecting to AdGuard Home instance.; Retrying in background
2021-09-29 09:31:52 INFO (MainThread) [homeassistant.setup] Setting up tts
2021-09-29 09:31:52 INFO (MainThread) [homeassistant.setup] Setting up harmony
2021-09-29 09:31:52 INFO (MainThread) [homeassistant.setup] Setup of domain harmony took 0.0 seconds
2021-09-29 09:31:52 WARNING (MainThread) [homeassistant.components.switch] Setup of switch platform command_line is taking over 10 seconds.
2021-09-29 09:31:52 WARNING (MainThread) [homeassistant.components.switch] Setup of switch platform template is taking over 10 seconds.
2021-09-29 09:31:52 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform template is taking over 10 seconds.
2021-09-29 09:31:52 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform workday is taking over 10 seconds.
2021-09-29 09:31:52 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform command_line is taking over 10 seconds.
2021-09-29 09:31:52 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform hassio is taking over 10 seconds.
2021-09-29 09:31:52 INFO (MainThread) [homeassistant.setup] Setting up climate
2021-09-29 09:31:52 INFO (MainThread) [homeassistant.setup] Setup of domain climate took 0.0 seconds
2021-09-29 09:31:52 INFO (SyncWorker_2) [homeassistant.loader] Loaded nest from homeassistant.components.nest
2021-09-29 09:31:52 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform updater is taking over 10 seconds.
2021-09-29 09:31:52 INFO (MainThread) [hangups.client] Client.connect returning because Channel.listen returned
2021-09-29 09:32:02 WARNING (MainThread) [homeassistant.config_entries] Config entry '***@gmail.com' for tesla integration could not authenticateNext step is to login via ssh, set default logging to trace (nano config/ configuration.yaml) and do another ha host reboot
configuration.yaml:
logger:
# default: info
default: debugTime to remove Tesla and try again I guess:
2021-09-29 10:53:34 DEBUG (MainThread) [homeassistant.components.http.auth] Authenticated 172.30.32.2 for /api/config using bearer token
2021-09-29 10:53:34 DEBUG (MainThread) [homeassistant.components.http.view] Serving /api/config to 172.30.32.2 (auth: True)
2021-09-29 10:53:34 DEBUG (MainThread) [teslajsonpy.connection] Failed to authenticate
2021-09-29 10:53:34 WARNING (MainThread) [homeassistant.config_entries] Config entry '***@gmail.com' for tesla integration could not authenticate
2021-09-29 10:53:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=persistent_notification, service=create, service_data=title=Integration requires reconfiguration, message=At least one of your integrations requires reconfiguration to continue functioning. [Check it out](/config/integrations)., notification_id=config_entry_reconfigure>
2021-09-29 10:53:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=persistent_notification.config_entry_reconfigure, old_state=None, new_state=<state persistent_notification.config_entry_reconfigure=notifying; title=Integration requires reconfiguration, friendly_name=Integration requires reconfiguration, message=At least one of your integrations requires reconfiguration to continue functioning. [Check it out](/config/integrations). @ 2021-09-29T10:53:34.827264-04:00>>
2021-09-29 10:53:34 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event persistent_notifications_updated[L]>
2021-09-29 10:54:14 DEBUG (Thread-3) [paho.mqtt.client] Sending PINGREQ
2021-09-29 10:54:14 DEBUG (Thread-3) [paho.mqtt.client] Received PINGRESP
2021-09-29 10:55:14 DEBUG (Thread-3) [paho.mqtt.client] Sending PINGREQ
2021-09-29 10:55:14 DEBUG (Thread-3) [paho.mqtt.client] Received PINGRESP
2021-09-29 10:56:15 DEBUG (Thread-3) [paho.mqtt.client] Sending PINGREQ
2021-09-29 10:56:15 DEBUG (Thread-3) [paho.mqtt.client] Received PINGRESP
2021-09-29 10:57:15 DEBUG (Thread-3) [paho.mqtt.client] Sending PINGREQ
2021-09-29 10:57:15 DEBUG (Thread-3) [paho.mqtt.client] Received PINGRESP
2021-09-29 10:58:15 DEBUG (Thread-3) [paho.mqtt.client] Sending PINGREQ
2021-09-29 10:58:15 DEBUG (Thread-3) [paho.mqtt.client] Received PINGRESPRemoved by editing this file: nano /root/config/.storage/core.config_entries, doesn't help now stuck on TPlink:
2021-09-29 11:25:54 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=input_select>
2021-09-29 11:25:54 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=timer>
2021-09-29 11:25:54 INFO (SyncWorker_1) [homeassistant.loader] Loaded systemmonitor from homeassistant.components.systemmonitor
2021-09-29 11:25:55 INFO (MainThread) [homeassistant.setup] Setting up ipp
2021-09-29 11:25:55 INFO (MainThread) [homeassistant.setup] Setup of domain ipp took 0.0 seconds
2021-09-29 11:25:55 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=network>
2021-09-29 11:25:55 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=weather.toronto, old_state=None, new_state=<state weather.toronto=sunny; temperature=17.7, humidity=65, pressure=1019.0, wind_bearing=356.0, wind_speed=15.0, visibility=24.1, attribution=Data provided by Environment Canada, forecast=[{'datetime': '2021-09-29T11:25:55.112987-04:00', 'condition': 'sunny', 'precipitation_probability': 0, 'temperature': 19, 'templow': 9}, {'datetime': '2021-09-30T11:25:55.113075-04:00', 'temperature': 17, 'templow': 8, 'condition': 'partlycloudy', 'precipitation_probability': 0}, {'datetime': '2021-10-01T11:25:55.114271-04:00', 'temperature': 20, 'templow': 11, 'condition': 'partlycloudy', 'precipitation_probability': 0}, {'datetime': '2021-10-02T11:25:55.114416-04:00', 'temperature': 17, 'templow': 11, 'condition': 'cloudy', 'precipitation_probability': 0}, {'datetime': '2021-10-03T11:25:55.114505-04:00', 'temperature': 17, 'templow': 9, 'condition': 'rainy', 'precipitation_probability': 40}, {'datetime': '2021-10-04T11:25:55.114704-04:00', 'temperature': 17, 'templow': 7, 'condition': 'partlycloudy', 'precipitation_probability': 0}], friendly_name=Toronto @ 2021-09-29T11:25:55.115443-04:00>>
2021-09-29 11:25:55 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=command_line, service=reload>
2021-09-29 11:25:55 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=input_text>
2021-09-29 11:25:55 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=input_boolean>
2021-09-29 11:25:55 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=notify, service=lametric>
2021-09-29 11:25:55 DEBUG (MainThread) [homeassistant.components.http.view] Serving /auth/token to 172.30.32.2 (auth: False)
2021-09-29 11:25:55 WARNING (MainThread) [homeassistant.setup] Setup of zone is taking over 10 seconds.
2021-09-29 11:25:55 INFO (MainThread) [homeassistant.setup] Setting up ping
2021-09-29 11:25:55 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=ping, service=reload>
2021-09-29 11:25:55 DEBUG (SyncWorker_5) [homeassistant.components.ping] Using icmplib in privileged=True mode
2021-09-29 11:25:55 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.hassio
2021-09-29 11:25:55 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=media_player.living_room_channels, old_state=None, new_state=<state media_player.living_room_channels=unknown; is_volume_muted=False, media_content_type=channel, friendly_name=Living Room Channels, entity_picture=/api/media_player_proxy/media_player.living_room_channels?token=3bded084e6d65cb96f7695f5ac56cb1e15b2c9377e3bb6894f8e67d286587fb3&cache=b4b9cb10666a81dc, supported_features=23097 @ 2021-09-29T11:25:55.220814-04:00>>
2021-09-29 11:25:55 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=scene>
2021-09-29 11:25:55 DEBUG (MainThread) [homeassistant.components.updater] Finished fetching Home Assistant update data in 10.711 seconds (success: True)
2021-09-29 11:25:55 INFO (MainThread) [hangups.client] Client.connect returning because Channel.listen returned
2021-09-29 11:25:55 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=switch.lockitron, old_state=None, new_state=<state switch.lockitron=off; friendly_name=Lockitron @ 2021-09-29T11:25:55.298766-04:00>>
2021-09-29 11:25:55 WARNING (Thread-4) [homeassistant.util.executor] Thread[SyncWorker_0] is still running at shutdown: File "/usr/local/lib/python3.9/threading.py", line 930, in _bootstrap
self._bootstrap_inner()
File "/usr/local/lib/python3.9/threading.py", line 973, in _bootstrap_inner
self.run()
File "/usr/local/lib/python3.9/threading.py", line 910, in run
self._target(*self._args, **self._kwargs)
File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 77, in _worker
work_item.run()
File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 52, in run
result = self.fn(*self.args, **self.kwargs)
File "/usr/src/homeassistant/homeassistant/components/tplink/common.py", line 64, in discover
return Discover.discover()
File "/usr/local/lib/python3.9/site-packages/pyHS100/discover.py", line 51, in discover
data, addr = sock.recvfrom(4096)
2021-09-29 11:26:54 DEBUG (Thread-3) [paho.mqtt.client] Sending PINGREQ
2021-09-29 11:26:54 DEBUG (Thread-3) [paho.mqtt.client] Received PINGRESP
2021-09-29 11:27:54 DEBUG (Thread-3) [paho.mqtt.client] Sending PINGREQ
2021-09-29 11:27:54 DEBUG (Thread-3) [paho.mqtt.client] Received PINGRESP
2021-09-29 11:28:54 DEBUG (Thread-3) [paho.mqtt.client] Sending PINGREQ
2021-09-29 11:28:54 DEBUG (Thread-3) [paho.mqtt.client] Received PINGRESP
2021-09-29 11:29:54 DEBUG (Thread-3) [paho.mqtt.client] Sending PINGREQ
2021-09-29 11:29:54 DEBUG (Thread-3) [paho.mqtt.client] Received PINGRESPTime to try moving home-assistant_v2.db out of the way... it's at 3.1G and earlier I had seen log files indicating it was not cleanly closed.
deftdawg
commented
3 years ago Adding dmesg to the record. Next step is to mkdir disabled; mv *.yaml disabled; ha host reboot to see if it helps having no configuration...
[ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083]
[ 0.000000] Linux version 5.10.17-v8 (builder@b5f45778413c) (aarch64-buildroot-linux-gnu-gcc.br_real (Buildroot -gf0b9df90) 9.4.0, GNU ld (GNU Binutils) 2.35.2) #1 SMP PREEMPT Thu Sep 9 03:39:03 UTC 2021
[ 0.000000] Machine model: Raspberry Pi 4 Model B Rev 1.1
[ 0.000000] efi: UEFI not found.
[ 0.000000] Reserved memory: created CMA memory pool at 0x000000002ac00000, size 64 MiB
[ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[ 0.000000] Zone ranges:
[ 0.000000] DMA [mem 0x0000000000000000-0x000000003fffffff]
[ 0.000000] DMA32 [mem 0x0000000040000000-0x00000000fbffffff]
[ 0.000000] Normal empty
[ 0.000000] Movable zone start for each node
[ 0.000000] Early memory node ranges
[ 0.000000] node 0: [mem 0x0000000000000000-0x000000003b3fffff]
[ 0.000000] node 0: [mem 0x0000000040000000-0x00000000fbffffff]
[ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000000fbffffff]
[ 0.000000] On node 0 totalpages: 1012736
[ 0.000000] DMA zone: 3792 pages used for memmap
[ 0.000000] DMA zone: 0 pages reserved
[ 0.000000] DMA zone: 242688 pages, LIFO batch:63
[ 0.000000] DMA32 zone: 12032 pages used for memmap
[ 0.000000] DMA32 zone: 770048 pages, LIFO batch:63
[ 0.000000] percpu: Embedded 32 pages/cpu s91352 r8192 d31528 u131072
[ 0.000000] pcpu-alloc: s91352 r8192 d31528 u131072 alloc=32*4096
[ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[ 0.000000] Detected PIPT I-cache on CPU0
[ 0.000000] CPU features: detected: Spectre-v2
[ 0.000000] CPU features: detected: Spectre-v4
[ 0.000000] CPU features: detected: ARM errata 1165522, 1319367, or 1530923
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 996912
[ 0.000000] Kernel command line: zram.enabled=1 zram.num_devices=3 apparmor=1 security=apparmor rootwait systemd.machine_id=7bd751974f9c4975ba5af3e40ca39555 cgroup_enable=memory fsck.repair=yes coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=592 bcm2708_fb.fbheight=448 bcm2708_fb.fbswap=1 smsc95xx.macaddr=DC:A6:32:19:36:22 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 dwc_otg.lpm_enable=0 console=tty1 root=PARTUUID=a3ec664e-32ce-4665-95ea-7ae90ce9aa20 rootfstype=squashfs ro rauc.slot=B
[ 0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)
[ 0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.000000] software IO TLB: mapped [mem 0x0000000037400000-0x000000003b400000] (64MB)
[ 0.000000] Memory: 3815580K/4050944K available (12096K kernel code, 1962K rwdata, 4160K rodata, 3840K init, 1261K bss, 169828K reserved, 65536K cma-reserved)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[ 0.000000] ftrace: allocating 39239 entries in 154 pages
[ 0.000000] ftrace: allocated 154 pages with 4 groups
[ 0.000000] rcu: Preemptible hierarchical RCU implementation.
[ 0.000000] rcu: RCU event tracing is enabled.
[ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4.
[ 0.000000] Trampoline variant of Tasks RCU enabled.
[ 0.000000] Rude variant of Tasks RCU enabled.
[ 0.000000] Tracing variant of Tasks RCU enabled.
[ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4
[ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
[ 0.000000] GIC: Using split EOI/Deactivate mode
[ 0.000000] random: get_random_bytes called from start_kernel+0x3b8/0x57c with crng_init=0
[ 0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
[ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
[ 0.000006] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[ 0.000263] Console: colour dummy device 80x25
[ 0.000815] printk: console [tty1] enabled
[ 0.000874] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000)
[ 0.000916] pid_max: default: 32768 minimum: 301
[ 0.001067] LSM: Security Framework initializing
[ 0.001190] AppArmor: AppArmor initialized
[ 0.001408] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)
[ 0.001484] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)
[ 0.004608] rcu: Hierarchical SRCU implementation.
[ 0.005650] EFI services will not be available.
[ 0.006172] smp: Bringing up secondary CPUs ...
[ 0.007184] Detected PIPT I-cache on CPU1
[ 0.007255] CPU1: Booted secondary processor 0x0000000001 [0x410fd083]
[ 0.008429] Detected PIPT I-cache on CPU2
[ 0.008475] CPU2: Booted secondary processor 0x0000000002 [0x410fd083]
[ 0.009577] Detected PIPT I-cache on CPU3
[ 0.009622] CPU3: Booted secondary processor 0x0000000003 [0x410fd083]
[ 0.009772] smp: Brought up 1 node, 4 CPUs
[ 0.009861] SMP: Total of 4 processors activated.
[ 0.009886] CPU features: detected: 32-bit EL0 Support
[ 0.009909] CPU features: detected: CRC32 instructions
[ 0.009932] CPU features: detected: 32-bit EL1 Support
[ 0.047528] CPU: All CPU(s) started at EL2
[ 0.047611] alternatives: patching kernel code
[ 0.049151] devtmpfs: initialized
[ 0.059805] Enabled cp15_barrier support
[ 0.059871] Enabled setend support
[ 0.060122] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[ 0.060168] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[ 0.062148] pinctrl core: initialized pinctrl subsystem
[ 0.062942] DMI not present or invalid.
[ 0.063346] NET: Registered protocol family 16
[ 0.066685] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations
[ 0.066962] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
[ 0.067894] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
[ 0.067976] audit: initializing netlink subsys (disabled)
[ 0.068375] audit: type=2000 audit(0.068:1): state=initialized audit_enabled=0 res=1
[ 0.068843] thermal_sys: Registered thermal governor 'step_wise'
[ 0.069296] cpuidle: using governor menu
[ 0.069804] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[ 0.069992] ASID allocator initialised with 65536 entries
[ 0.070135] Serial: AMBA PL011 UART driver
[ 0.097901] bcm2835-mbox fe00b880.mailbox: mailbox enabled
[ 0.104314] raspberrypi-firmware soc:firmware: Attached to firmware from 2021-05-27T14:02:15, variant start
[ 0.108307] raspberrypi-firmware soc:firmware: Firmware hash is 7d9a298cda813f747b51fe17e1e417e7bf5ca94d
[ 0.142650] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
[ 0.146557] vgaarb: loaded
[ 0.146973] SCSI subsystem initialized
[ 0.147210] usbcore: registered new interface driver usbfs
[ 0.147278] usbcore: registered new interface driver hub
[ 0.147363] usbcore: registered new device driver usb
[ 0.147679] usb_phy_generic phy: supply vcc not found, using dummy regulator
[ 0.148054] mc: Linux media interface: v0.10
[ 0.149762] clocksource: Switched to clocksource arch_sys_counter
[ 1.168791] VFS: Disk quotas dquot_6.6.0
[ 1.168916] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 1.169087] FS-Cache: Loaded
[ 1.169340] CacheFiles: Loaded
[ 1.170148] AppArmor: AppArmor Filesystem Enabled
[ 1.180505] NET: Registered protocol family 2
[ 1.181690] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)
[ 1.181798] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)
[ 1.182015] TCP bind hash table entries: 32768 (order: 7, 524288 bytes, linear)
[ 1.182442] TCP: Hash tables configured (established 32768 bind 32768)
[ 1.182681] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear)
[ 1.182777] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear)
[ 1.183119] NET: Registered protocol family 1
[ 1.184003] RPC: Registered named UNIX socket transport module.
[ 1.184031] RPC: Registered udp transport module.
[ 1.184052] RPC: Registered tcp transport module.
[ 1.184072] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 1.184103] PCI: CLS 0 bytes, default 64
[ 1.186592] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available
[ 1.186893] kvm [1]: IPA Size Limit: 44 bits
[ 1.188088] kvm [1]: vgic interrupt IRQ9
[ 1.188385] kvm [1]: Hyp mode initialized successfully
[ 1.190511] Initialise system trusted keyrings
[ 1.190859] workingset: timestamp_bits=46 max_order=20 bucket_order=0
[ 1.197019] zbud: loaded
[ 1.198740] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 1.199006] FS-Cache: Netfs 'nfs' registered for caching
[ 1.199655] NFS: Registering the id_resolver key type
[ 1.199718] Key type id_resolver registered
[ 1.199741] Key type id_legacy registered
[ 1.199872] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 1.201050] Key type asymmetric registered
[ 1.201078] Asymmetric key parser 'x509' registered
[ 1.201136] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248)
[ 1.201401] io scheduler mq-deadline registered
[ 1.201427] io scheduler kyber registered
[ 1.205417] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
[ 1.205464] brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
[ 1.205551] brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000
[ 1.205654] brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x00bfffffff -> 0x0400000000
[ 1.255862] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC)
[ 1.256243] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
[ 1.256276] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 1.256306] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff])
[ 1.256406] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
[ 1.256657] pci 0000:00:00.0: PME# supported from D0 D3hot
[ 1.260788] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
[ 1.260925] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
[ 1.261356] pci 0000:01:00.0: PME# supported from D0 D3cold
[ 1.265258] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
[ 1.265295] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
[ 1.265347] pci 0000:00:00.0: PCI bridge to [bus 01]
[ 1.265381] pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff]
[ 1.266114] bcm2708_fb soc:fb: FB found 1 display(s)
[ 1.278733] Console: switching to colour frame buffer device 74x28
[ 1.280743] bcm2708_fb soc:fb: Registered framebuffer for display 0, size 592x448
[ 1.287786] iproc-rng200 fe104000.rng: hwrng registered
[ 1.289261] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[ 1.292472] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
[ 1.295159] cacheinfo: Unable to detect cache hierarchy for CPU 0
[ 1.307219] brd: module loaded
[ 1.320593] loop: module loaded
[ 1.322331] zram: Added device: zram0
[ 1.323914] zram: Added device: zram1
[ 1.325474] zram: Added device: zram2
[ 1.328058] Loading iSCSI transport class v2.0-870.
[ 1.332041] libphy: Fixed MDIO Bus: probed
[ 1.334058] tun: Universal TUN/TAP device driver, 1.6
[ 1.335912] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
[ 1.349787] libphy: bcmgenet MII bus: probed
[ 1.397907] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
[ 1.400036] usbcore: registered new interface driver r8152
[ 1.401165] usbcore: registered new interface driver lan78xx
[ 1.403805] pci 0000:00:00.0: enabling device (0000 -> 0002)
[ 1.404897] xhci_hcd 0000:01:00.0: enabling device (0000 -> 0002)
[ 1.406066] xhci_hcd 0000:01:00.0: xHCI Host Controller
[ 1.407133] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[ 1.409887] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000030000000890
[ 1.413232] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.10
[ 1.415346] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 1.417441] usb usb1: Product: xHCI Host Controller
[ 1.418509] usb usb1: Manufacturer: Linux 5.10.17-v8 xhci-hcd
[ 1.419553] usb usb1: SerialNumber: 0000:01:00.0
[ 1.421252] hub 1-0:1.0: USB hub found
[ 1.422373] hub 1-0:1.0: 1 port detected
[ 1.423993] xhci_hcd 0000:01:00.0: xHCI Host Controller
[ 1.425027] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[ 1.427139] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[ 1.428680] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.10
[ 1.430916] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 1.433167] usb usb2: Product: xHCI Host Controller
[ 1.434338] usb usb2: Manufacturer: Linux 5.10.17-v8 xhci-hcd
[ 1.435485] usb usb2: SerialNumber: 0000:01:00.0
[ 1.437287] hub 2-0:1.0: USB hub found
[ 1.438529] hub 2-0:1.0: 4 ports detected
[ 1.441182] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[ 1.442610] dwc_otg: FIQ enabled
[ 1.442622] dwc_otg: NAK holdoff enabled
[ 1.442633] dwc_otg: FIQ split-transaction FSM enabled
[ 1.442646] Module dwc_common_port init
[ 1.443160] usbcore: registered new interface driver uas
[ 1.444418] usbcore: registered new interface driver usb-storage
[ 1.445666] usbcore: registered new interface driver usbserial_generic
[ 1.446814] usbserial: USB Serial support registered for generic
[ 1.448104] mousedev: PS/2 mouse device common for all mice
[ 1.451010] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[ 1.455275] sdhci: Secure Digital Host Controller Interface driver
[ 1.456351] sdhci: Copyright(c) Pierre Ossman
[ 1.458220] mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe
[ 1.460766] sdhci-pltfm: SDHCI platform and OF driver helper
[ 1.463255] ledtrig-cpu: registered to indicate activity on CPUs
[ 1.463935] hid: raw HID events driver (C) Jiri Kosina
[ 1.464559] usbcore: registered new interface driver usbhid
[ 1.465099] usbhid: USB HID core driver
[ 1.468958] IPVS: Registered protocols (TCP, UDP, SCTP, AH, ESP)
[ 1.469569] IPVS: Connection hash table configured (size=4096, memory=64Kbytes)
[ 1.470869] IPVS: ipvs loaded.
[ 1.471459] IPVS: [rr] scheduler registered.
[ 1.472604] NET: Registered protocol family 10
[ 1.474085] Segment Routing with IPv6
[ 1.474833] NET: Registered protocol family 17
[ 1.475460] Bridge firewalling registered
[ 1.476088] Key type dns_resolver registered
[ 1.477029] registered taskstats version 1
[ 1.477573] Loading compiled-in X.509 certificates
[ 1.478371] Key type ._fscrypt registered
[ 1.478890] Key type .fscrypt registered
[ 1.479403] Key type fscrypt-provisioning registered
[ 1.479967] AppArmor: AppArmor sha1 policy hashing enabled
[ 1.486054] uart-pl011 fe201000.serial: there is not valid maps for state default
[ 1.487273] uart-pl011 fe201000.serial: cts_event_workaround enabled
[ 1.487872] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 21, base_baud = 0) is a PL011 rev2
[ 1.496795] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[ 1.498440] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0
[ 1.499011] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated
[ 1.531513] printk: console [netcon0] enabled
[ 1.532615] netconsole: network logging started
[ 1.533697] of_cfs_init
[ 1.534927] of_cfs_init: OK
[ 1.546710] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[ 1.548818] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 1.551141] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 1.554741] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[ 1.557129] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 1.566210] mmc0: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA
[ 1.567947] Waiting for root device PARTUUID=a3ec664e-32ce-4665-95ea-7ae90ce9aa20...
[ 1.586832] random: fast init done
[ 1.622549] mmc1: new high speed SDIO card at address 0001
[ 1.677885] mmc0: new ultra high speed DDR50 SDXC card at address 0001
[ 1.679835] mmcblk0: mmc0:0001 00000 232 GiB
[ 1.689698] mmcblk0: p1 p2 p3 p4 p5 p6 p7 p8
[ 1.699252] VFS: Mounted root (squashfs filesystem) readonly on device 179:5.
[ 1.702484] devtmpfs: mounted
[ 1.708554] Freeing unused kernel memory: 3840K
[ 1.717790] Run /sbin/init as init process
[ 1.718288] with arguments:
[ 1.718293] /sbin/init
[ 1.718298] with environment:
[ 1.718303] HOME=/
[ 1.718307] TERM=linux
[ 1.757794] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[ 1.908378] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
[ 1.909536] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[ 1.910860] usb 1-1: Product: USB2.0 Hub
[ 1.912982] hub 1-1:1.0: USB hub found
[ 1.914023] hub 1-1:1.0: 4 ports detected
[ 1.981806] systemd[1]: System time before build time, advancing clock.
[ 2.048277] systemd[1]: systemd 247 running in system mode. (+PAM -AUDIT -SELINUX -IMA +APPARMOR -SMACK -SYSVINIT -UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS -ACL -XZ -LZ4 -ZSTD -SECCOMP +BLKID -ELFUTILS +KMOD -IDN2 -IDN +PCRE2 default-hierarchy=hybrid)
[ 2.051894] systemd[1]: Detected architecture arm64.
[ 2.082511] systemd[1]: Set hostname to <homeassistant>.
[ 2.083621] systemd[1]: Installed transient /etc/machine-id file.
[ 2.217839] usb 1-1.4: new full-speed USB device number 3 using xhci_hcd
[ 2.336896] usb 1-1.4: New USB device found, idVendor=10c4, idProduct=8a2a, bcdDevice= 1.00
[ 2.339255] usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=5
[ 2.341509] usb 1-1.4: Product: HubZ Smart Home Controller
[ 2.342710] usb 1-1.4: Manufacturer: Silicon Labs
[ 2.343883] usb 1-1.4: SerialNumber: C13001DB
[ 2.766520] systemd[1]: Queued start job for default target Multi-User System.
[ 2.768730] random: systemd: uninitialized urandom read (16 bytes read)
[ 2.795917] systemd[1]: Created slice system-ha\x2dcli.slice.
[ 2.797500] random: systemd: uninitialized urandom read (16 bytes read)
[ 2.799887] systemd[1]: Created slice system-modprobe.slice.
[ 2.801368] random: systemd: uninitialized urandom read (16 bytes read)
[ 2.803551] systemd[1]: Created slice system-systemd\x2dfsck.slice.
[ 2.806821] systemd[1]: Created slice system-systemd\x2dgrowfs.slice.
[ 2.809917] systemd[1]: Created slice User and Session Slice.
[ 2.811648] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[ 2.813988] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[ 2.816297] systemd[1]: Reached target Local Encrypted Volumes.
[ 2.817858] systemd[1]: Reached target HassOS zram targets.
[ 2.819354] systemd[1]: Reached target Paths.
[ 2.820796] systemd[1]: Reached target Remote Encrypted Volumes.
[ 2.822280] systemd[1]: Reached target Remote File Systems.
[ 2.823712] systemd[1]: Reached target Slices.
[ 2.826835] systemd[1]: Listening on D-Bus System Message Bus Socket.
[ 2.831208] systemd[1]: Listening on Process Core Dump Socket.
[ 2.834445] systemd[1]: Listening on Journal Audit Socket.
[ 2.836254] systemd[1]: Listening on Journal Socket (/dev/log).
[ 2.838064] systemd[1]: Listening on Journal Socket.
[ 2.842219] systemd[1]: Listening on udev Control Socket.
[ 2.843983] systemd[1]: Listening on udev Kernel Socket.
[ 2.846000] systemd[1]: Condition check resulted in Huge Pages File System being skipped.
[ 2.850870] systemd[1]: Mounting POSIX Message Queue File System...
[ 2.857155] systemd[1]: Mounting Kernel Debug File System...
[ 2.862898] systemd[1]: Mounting Kernel Trace File System...
[ 2.868343] systemd[1]: Started D-Bus System Message Bus.
[ 2.878928] systemd[1]: Starting Home Assistant OS Agent...
[ 2.899060] systemd[1]: Starting Create list of static device nodes for the current kernel...
[ 2.911165] systemd[1]: Starting Load Kernel Module configfs...
[ 2.921820] systemd[1]: Starting Load Kernel Module drm...
[ 2.932580] systemd[1]: Starting Load Kernel Module fuse...
[ 2.948797] systemd[1]: Starting Journal Service...
[ 2.960762] systemd[1]: Starting Remount Root and Kernel File Systems...
[ 2.974348] systemd[1]: Starting Wait Until Kernel Time Synchronized...
[ 2.986182] systemd[1]: Starting Coldplug All udev Devices...
[ 2.999046] systemd[1]: Starting Disk Manager...
[ 3.011210] systemd[1]: Starting HassOS ZRAM swap...
[ 3.025977] systemd[1]: Starting HassOS ZRAM tmp...
[ 3.038679] systemd[1]: Starting HassOS ZRAM var...
[ 3.055191] systemd[1]: Mounted POSIX Message Queue File System.
[ 3.059286] systemd[1]: Mounted Kernel Debug File System.
[ 3.063209] systemd[1]: Mounted Kernel Trace File System.
[ 3.072429] systemd[1]: Finished Create list of static device nodes for the current kernel.
[ 3.078686] systemd[1]: modprobe@configfs.service: Succeeded.
[ 3.083503] systemd[1]: Finished Load Kernel Module configfs.
[ 3.092915] systemd[1]: Finished Remount Root and Kernel File Systems.
[ 3.106557] systemd[1]: Mounting Kernel Configuration File System...
[ 3.106969] fuse: init (API version 7.32)
[ 3.123691] systemd[1]: Starting Create Static Device Nodes in /dev...
[ 3.135162] systemd[1]: modprobe@fuse.service: Succeeded.
[ 3.140160] systemd[1]: Finished Load Kernel Module fuse.
[ 3.144922] systemd[1]: Mounted Kernel Configuration File System.
[ 3.157558] systemd[1]: Mounting FUSE Control File System...
[ 3.179926] systemd[1]: Mounted FUSE Control File System.
[ 3.264892] systemd[1]: Started Journal Service.
[ 3.536131] zram1: detected capacity change from 0 to 33554432
[ 3.540857] zram2: detected capacity change from 0 to 16777216
[ 3.540964] zram0: detected capacity change from 0 to 994549760
[ 3.641512] audit: type=1334 audit(1612279788.655:2): prog-id=5 op=LOAD
[ 3.645032] audit: type=1334 audit(1612279788.659:3): prog-id=6 op=LOAD
[ 4.284229] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000
[ 4.310594] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000
[ 4.330216] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[ 4.337137] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[ 4.339342] [vc_sm_connected_init]: start
[ 4.343101] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000
[ 4.346185] [vc_sm_connected_init]: installed successfully
[ 4.406460] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000
[ 4.469074] videodev: Linux video capture interface: v2.00
[ 4.502911] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
[ 4.515833] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[ 4.516858] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[ 4.536532] bcm2835_audio bcm2835_audio: card created with 4 channels
[ 4.544537] bcm2835_audio bcm2835_audio: card created with 4 channels
[ 4.563249] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[ 4.577135] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
[ 4.586666] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
[ 4.590437] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
[ 4.599094] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
[ 4.602456] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
[ 4.607989] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
[ 4.613024] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
[ 4.618081] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
[ 4.624651] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
[ 4.628895] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[ 4.635818] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
[ 4.639100] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
[ 4.642650] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
[ 4.649981] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
[ 4.652823] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
[ 4.738117] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
[ 4.794007] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
[ 4.811784] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[ 4.827975] usbcore: registered new interface driver cp210x
[ 4.828060] usbserial: USB Serial support registered for cp210x
[ 4.828213] cp210x 1-1.4:1.0: cp210x converter detected
[ 4.846580] usb 1-1.4: cp210x converter now attached to ttyUSB0
[ 4.848246] cp210x 1-1.4:1.1: cp210x converter detected
[ 4.871411] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[ 4.880032] usb 1-1.4: cp210x converter now attached to ttyUSB1
[ 4.958087] brcmfmac: F1 signature read @0x18000000=0x15264345
[ 4.967037] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[ 4.970005] usbcore: registered new interface driver brcmfmac
[ 5.002741] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,4-model-b.txt failed with error -2
[ 5.014250] Adding 971236k swap on /dev/zram0. Priority:-2 extents:1 across:971236k SSFS
[ 5.242914] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[ 5.249147] EXT4-fs (mmcblk0p7): mounted filesystem with ordered data mode. Opts: (null)
[ 5.251682] ext4 filesystem being mounted at /mnt/overlay supports timestamps until 2038 (0x7fffffff)
[ 5.265982] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Jan 4 2021 19:56:29 version 7.45.229 (617f1f5 CY) FWID 01-2dbd9d2e
[ 5.723382] EXT4-fs (zram2): mounted filesystem without journal. Opts: nobarrier
[ 5.723457] ext4 filesystem being mounted at /tmp supports timestamps until 2038 (0x7fffffff)
[ 5.774237] EXT4-fs (zram1): mounted filesystem without journal. Opts: nobarrier
[ 5.774301] ext4 filesystem being mounted at /var supports timestamps until 2038 (0x7fffffff)
[ 6.035948] EXT4-fs (mmcblk0p8): mounted filesystem with ordered data mode. Opts: (null)
[ 6.132662] EXT4-fs (mmcblk0p8): resizing filesystem from 60720891 to 60720891 blocks
[ 6.202234] systemd-journald[116]: Received client request to flush runtime journal.
[ 6.218810] systemd-journald[116]: File /var/log/journal/7bd751974f9c4975ba5af3e40ca39555/system.journal corrupted or uncleanly shut down, renaming and replacing.
[ 6.528063] Under-voltage detected! (0x00050005)
[ 7.485880] random: crng init done
[ 7.485903] random: 7 urandom warning(s) missed due to ratelimiting
[ 7.857475] audit: type=1334 audit(1633060813.179:4): prog-id=7 op=LOAD
[ 7.857719] audit: type=1334 audit(1633060813.179:5): prog-id=8 op=LOAD
[ 8.286145] audit: type=1400 audit(1633060813.591:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="hassio-supervisor" pid=390 comm="apparmor_parser"
[ 8.286190] audit: type=1400 audit(1633060813.591:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="hassio-supervisor///usr/bin/gdbus" pid=390 comm="apparmor_parser"
[ 8.286227] audit: type=1400 audit(1633060813.591:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="hassio-supervisor///usr/bin/git" pid=390 comm="apparmor_parser"
[ 8.372040] Bluetooth: Core ver 2.22
[ 8.372127] NET: Registered protocol family 31
[ 8.372133] Bluetooth: HCI device and connection manager initialized
[ 8.372149] Bluetooth: HCI socket layer initialized
[ 8.372158] Bluetooth: L2CAP socket layer initialized
[ 8.372173] Bluetooth: SCO socket layer initialized
[ 8.513084] uart-pl011 fe201000.serial: no DMA platform data
[ 8.847777] audit: type=1334 audit(1633060814.171:7): prog-id=9 op=LOAD
[ 8.847941] audit: type=1334 audit(1633060814.171:8): prog-id=10 op=LOAD
[ 9.144720] Bluetooth: HCI UART driver ver 2.3
[ 9.144746] Bluetooth: HCI UART protocol H4 registered
[ 9.144873] Bluetooth: HCI UART protocol Three-wire (H5) registered
[ 9.145195] Bluetooth: HCI UART protocol Broadcom registered
[ 9.398626] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)
[ 9.399057] bcmgenet fd580000.ethernet eth0: Link is Down
[ 9.471417] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
[ 9.476618] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[ 9.476640] Bluetooth: BNEP filters: protocol multicast
[ 9.476669] Bluetooth: BNEP socket layer initialized
[ 9.507526] NET: Registered protocol family 38
[ 9.545085] cryptd: max_cpu_qlen set to 1000
[ 13.502050] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[ 13.502118] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[ 22.307269] audit: type=1400 audit(1633060827.627:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="docker-default" pid=511 comm="apparmor_parser"
[ 24.713938] audit: type=1325 audit(1633060830.007:10): table=nat family=2 entries=5 op=xt_replace pid=537 subj==unconfined comm="iptables"
[ 24.745940] audit: type=1325 audit(1633060830.051:11): table=filter family=2 entries=4 op=xt_replace pid=539 subj==unconfined comm="iptables"
[ 24.789940] audit: type=1325 audit(1633060830.087:12): table=filter family=2 entries=6 op=xt_replace pid=541 subj==unconfined comm="iptables"
[ 24.830055] audit: type=1325 audit(1633060830.131:13): table=filter family=2 entries=8 op=xt_replace pid=543 subj==unconfined comm="iptables"
[ 24.869939] audit: type=1325 audit(1633060830.171:14): table=filter family=2 entries=10 op=xt_replace pid=545 subj==unconfined comm="iptables"
[ 24.909989] audit: type=1325 audit(1633060830.207:15): table=filter family=2 entries=11 op=xt_replace pid=547 subj==unconfined comm="iptables"
[ 24.949918] audit: type=1325 audit(1633060830.239:16): table=filter family=2 entries=12 op=xt_replace pid=548 subj==unconfined comm="iptables"
[ 24.981120] Initializing XFRM netlink socket
[ 25.078006] audit: type=1325 audit(1633060830.383:17): table=nat family=2 entries=7 op=xt_replace pid=556 subj==unconfined comm="iptables"
[ 25.129916] audit: type=1325 audit(1633060830.431:18): table=nat family=2 entries=8 op=xt_replace pid=558 subj==unconfined comm="iptables"
[ 26.962796] hassio: port 1(veth5ea0a08) entered blocking state
[ 26.962822] hassio: port 1(veth5ea0a08) entered disabled state
[ 26.963132] device veth5ea0a08 entered promiscuous mode
[ 26.963742] hassio: port 1(veth5ea0a08) entered blocking state
[ 26.963759] hassio: port 1(veth5ea0a08) entered forwarding state
[ 26.970043] hassio: port 1(veth5ea0a08) entered disabled state
[ 28.114859] cgroup: cgroup: disabling cgroup2 socket matching due to net_prio or net_cls activation
[ 29.553928] kauditd_printk_skb: 44 callbacks suppressed
[ 29.553939] audit: type=1325 audit(1633060834.855:63): table=nat family=2 entries=0 op=xt_register pid=731 subj==unconfined comm="iptables"
[ 29.601933] audit: type=1325 audit(1633060834.899:64): table=filter family=2 entries=0 op=xt_register pid=733 subj==unconfined comm="iptables"
[ 29.677917] audit: type=1325 audit(1633060834.971:65): table=nat family=2 entries=5 op=xt_replace pid=736 subj==unconfined comm="iptables"
[ 29.717932] audit: type=1325 audit(1633060835.015:66): table=nat family=2 entries=7 op=xt_replace pid=737 subj==unconfined comm="iptables"
[ 29.773946] audit: type=1325 audit(1633060835.063:67): table=nat family=2 entries=8 op=xt_replace pid=739 subj==unconfined comm="iptables"
[ 29.798000] audit: type=1325 audit(1633060835.103:68): table=nat family=2 entries=10 op=xt_replace pid=740 subj==unconfined comm="iptables"
[ 29.838016] audit: type=1325 audit(1633060835.139:69): table=nat family=2 entries=11 op=xt_replace pid=741 subj==unconfined comm="iptables"
[ 29.869929] audit: type=1325 audit(1633060835.179:70): table=nat family=2 entries=12 op=xt_replace pid=742 subj==unconfined comm="iptables"
[ 29.897973] audit: type=1325 audit(1633060835.203:71): table=nat family=2 entries=13 op=xt_replace pid=743 subj==unconfined comm="iptables"
[ 29.925980] audit: type=1325 audit(1633060835.231:72): table=nat family=2 entries=14 op=xt_replace pid=744 subj==unconfined comm="iptables"
[ 29.991894] eth0: renamed from veth8ec0603
[ 30.020722] IPv6: ADDRCONF(NETDEV_CHANGE): veth5ea0a08: link becomes ready
[ 30.020930] hassio: port 1(veth5ea0a08) entered blocking state
[ 30.020946] hassio: port 1(veth5ea0a08) entered forwarding state
[ 30.021195] IPv6: ADDRCONF(NETDEV_CHANGE): hassio: link becomes ready
[ 39.943649] docker0: port 1(veth29494c3) entered blocking state
[ 39.943680] docker0: port 1(veth29494c3) entered disabled state
[ 39.945587] device veth29494c3 entered promiscuous mode
[ 39.945659] audit: type=1700 audit(1633060867.206:73): dev=veth29494c3 prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[ 40.057461] hassio: port 2(veth7f82660) entered blocking state
[ 40.057488] hassio: port 2(veth7f82660) entered disabled state
[ 40.058442] device veth7f82660 entered promiscuous mode
[ 40.058555] audit: type=1700 audit(1633060867.318:74): dev=veth7f82660 prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[ 40.058999] hassio: port 2(veth7f82660) entered blocking state
[ 40.059015] hassio: port 2(veth7f82660) entered forwarding state
[ 40.086078] audit: type=1334 audit(1633060867.350:75): prog-id=10 op=UNLOAD
[ 40.086128] audit: type=1334 audit(1633060867.350:76): prog-id=9 op=UNLOAD
[ 40.976438] hassio: port 2(veth7f82660) entered disabled state
[ 40.978315] eth0: renamed from veth022b8c2
[ 41.007764] IPv6: ADDRCONF(NETDEV_CHANGE): veth29494c3: link becomes ready
[ 41.007966] docker0: port 1(veth29494c3) entered blocking state
[ 41.007981] docker0: port 1(veth29494c3) entered forwarding state
[ 41.008232] IPv6: ADDRCONF(NETDEV_CHANGE): docker0: link becomes ready
[ 41.269919] audit: type=1325 audit(1633060868.506:77): table=nat family=2 entries=0 op=xt_register pid=1096 subj==unconfined comm="iptables"
[ 41.317944] audit: type=1325 audit(1633060868.554:78): table=filter family=2 entries=0 op=xt_register pid=1097 subj==unconfined comm="iptables"
[ 41.365955] audit: type=1325 audit(1633060868.602:79): table=nat family=2 entries=5 op=xt_replace pid=1100 subj==unconfined comm="iptables"
[ 41.401984] audit: type=1325 audit(1633060868.634:80): table=nat family=2 entries=7 op=xt_replace pid=1101 subj==unconfined comm="iptables"
[ 41.433941] audit: type=1325 audit(1633060868.678:81): table=nat family=2 entries=8 op=xt_replace pid=1103 subj==unconfined comm="iptables"
[ 41.473947] audit: type=1325 audit(1633060868.702:82): table=nat family=2 entries=10 op=xt_replace pid=1104 subj==unconfined comm="iptables"
[ 41.635484] eth1: renamed from veth75a33cf
[ 41.655099] IPv6: ADDRCONF(NETDEV_CHANGE): veth7f82660: link becomes ready
[ 41.655240] hassio: port 2(veth7f82660) entered blocking state
[ 41.655248] hassio: port 2(veth7f82660) entered forwarding state
[ 49.761817] kauditd_printk_skb: 4 callbacks suppressed
[ 49.761827] audit: type=1334 audit(1633060877.022:87): prog-id=11 op=LOAD
[ 49.762954] audit: type=1334 audit(1633060877.026:88): prog-id=12 op=LOAD
[ 50.225640] audit: type=1334 audit(1633060877.486:89): prog-id=13 op=LOAD
[ 50.225701] audit: type=1334 audit(1633060877.486:90): prog-id=14 op=LOAD
[ 53.751915] audit: type=1400 audit(1633060881.006:91): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="hassio-supervisor" pid=1808 comm="apparmor_parser"
[ 53.753498] audit: type=1400 audit(1633060881.006:91): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="hassio-supervisor///usr/bin/gdbus" pid=1808 comm="apparmor_parser"
[ 53.753525] audit: type=1400 audit(1633060881.006:91): apparmor="STATUS" operation="profile_replace" info="same as current profile, skipping" profile="unconfined" name="hassio-supervisor///usr/bin/git" pid=1808 comm="apparmor_parser"
[ 54.889466] hassio: port 3(vethfb19834) entered blocking state
[ 54.889480] hassio: port 3(vethfb19834) entered disabled state
[ 54.889696] device vethfb19834 entered promiscuous mode
[ 54.889801] audit: type=1700 audit(1633060882.150:92): dev=vethfb19834 prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[ 56.009941] audit: type=1325 audit(1633060883.254:93): table=nat family=2 entries=0 op=xt_register pid=1884 subj==unconfined comm="iptables"
[ 56.070128] audit: type=1325 audit(1633060883.302:94): table=filter family=2 entries=0 op=xt_register pid=1886 subj==unconfined comm="iptables"
[ 56.121963] audit: type=1325 audit(1633060883.350:95): table=nat family=2 entries=5 op=xt_replace pid=1889 subj==unconfined comm="iptables"
[ 56.146118] audit: type=1325 audit(1633060883.390:96): table=nat family=2 entries=7 op=xt_replace pid=1890 subj==unconfined comm="iptables"
[ 56.182049] audit: type=1325 audit(1633060883.422:97): table=nat family=2 entries=8 op=xt_replace pid=1892 subj==unconfined comm="iptables"
[ 56.206113] audit: type=1325 audit(1633060883.450:98): table=nat family=2 entries=10 op=xt_replace pid=1893 subj==unconfined comm="iptables"
[ 56.234032] audit: type=1325 audit(1633060883.478:99): table=nat family=2 entries=11 op=xt_replace pid=1894 subj==unconfined comm="iptables"
[ 56.273962] audit: type=1325 audit(1633060883.506:100): table=nat family=2 entries=12 op=xt_replace pid=1895 subj==unconfined comm="iptables"
[ 56.297908] audit: type=1325 audit(1633060883.546:101): table=nat family=2 entries=13 op=xt_replace pid=1896 subj==unconfined comm="iptables"
[ 56.355725] eth0: renamed from vethe321cce
[ 56.379210] IPv6: ADDRCONF(NETDEV_CHANGE): vethfb19834: link becomes ready
[ 56.379364] hassio: port 3(vethfb19834) entered blocking state
[ 56.379375] hassio: port 3(vethfb19834) entered forwarding state
[ 57.780737] hassio: port 4(vethcee2fa6) entered blocking state
[ 57.780764] hassio: port 4(vethcee2fa6) entered disabled state
[ 57.782837] device vethcee2fa6 entered promiscuous mode
[ 59.225016] eth0: renamed from veth99cfe31
[ 59.251139] IPv6: ADDRCONF(NETDEV_CHANGE): vethcee2fa6: link becomes ready
[ 59.251309] hassio: port 4(vethcee2fa6) entered blocking state
[ 59.251319] hassio: port 4(vethcee2fa6) entered forwarding state
[ 60.419454] hassio: port 5(vethed3c7ea) entered blocking state
[ 60.419480] hassio: port 5(vethed3c7ea) entered disabled state
[ 60.420288] device vethed3c7ea entered promiscuous mode
[ 60.420401] kauditd_printk_skb: 12 callbacks suppressed
[ 60.420410] audit: type=1700 audit(1633060887.682:114): dev=vethed3c7ea prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[ 61.662011] audit: type=1325 audit(1633060888.902:115): table=nat family=2 entries=0 op=xt_register pid=2497 subj==unconfined comm="iptables"
[ 61.706007] audit: type=1325 audit(1633060888.942:116): table=filter family=2 entries=0 op=xt_register pid=2498 subj==unconfined comm="iptables"
[ 61.761986] audit: type=1325 audit(1633060888.994:117): table=nat family=2 entries=5 op=xt_replace pid=2501 subj==unconfined comm="iptables"
[ 61.785882] audit: type=1325 audit(1633060889.034:118): table=nat family=2 entries=7 op=xt_replace pid=2502 subj==unconfined comm="iptables"
[ 61.813927] audit: type=1325 audit(1633060889.054:119): table=nat family=2 entries=8 op=xt_replace pid=2504 subj==unconfined comm="iptables"
[ 61.845894] audit: type=1325 audit(1633060889.082:120): table=nat family=2 entries=10 op=xt_replace pid=2505 subj==unconfined comm="iptables"
[ 61.869932] audit: type=1325 audit(1633060889.114:121): table=nat family=2 entries=11 op=xt_replace pid=2506 subj==unconfined comm="iptables"
[ 61.894049] audit: type=1325 audit(1633060889.138:122): table=nat family=2 entries=12 op=xt_replace pid=2507 subj==unconfined comm="iptables"
[ 61.925977] audit: type=1325 audit(1633060889.166:123): table=nat family=2 entries=13 op=xt_replace pid=2508 subj==unconfined comm="iptables"
[ 61.995902] eth0: renamed from veth44b590e
[ 62.019791] IPv6: ADDRCONF(NETDEV_CHANGE): vethed3c7ea: link becomes ready
[ 62.019998] hassio: port 5(vethed3c7ea) entered blocking state
[ 62.020013] hassio: port 5(vethed3c7ea) entered forwarding state
[ 68.186178] Bluetooth: RFCOMM TTY layer initialized
[ 68.186226] Bluetooth: RFCOMM socket layer initialized
[ 68.186268] Bluetooth: RFCOMM ver 1.11
[ 75.848361] hassio: port 6(vethdc020f8) entered blocking state
[ 75.848376] hassio: port 6(vethdc020f8) entered disabled state
[ 75.848748] device vethdc020f8 entered promiscuous mode
[ 75.848841] kauditd_printk_skb: 1 callbacks suppressed
[ 75.848845] audit: type=1700 audit(1633060903.109:125): dev=vethdc020f8 prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[ 75.849387] hassio: port 6(vethdc020f8) entered blocking state
[ 75.849401] hassio: port 6(vethdc020f8) entered forwarding state
[ 75.851354] hassio: port 6(vethdc020f8) entered disabled state
[ 75.986248] audit: type=1325 audit(1633060903.229:126): table=nat family=2 entries=15 op=xt_replace pid=3415 subj==unconfined comm="iptables"
[ 76.034234] audit: type=1325 audit(1633060903.265:127): table=filter family=2 entries=30 op=xt_replace pid=3417 subj==unconfined comm="iptables"
[ 76.078259] audit: type=1325 audit(1633060903.313:128): table=nat family=2 entries=16 op=xt_replace pid=3419 subj==unconfined comm="iptables"
[ 76.142255] audit: type=1325 audit(1633060903.385:129): table=nat family=2 entries=17 op=xt_replace pid=3437 subj==unconfined comm="iptables"
[ 76.182202] audit: type=1325 audit(1633060903.421:130): table=filter family=2 entries=31 op=xt_replace pid=3439 subj==unconfined comm="iptables"
[ 76.214240] audit: type=1325 audit(1633060903.461:131): table=nat family=2 entries=18 op=xt_replace pid=3441 subj==unconfined comm="iptables"
[ 76.270241] audit: type=1325 audit(1633060903.505:132): table=nat family=2 entries=19 op=xt_replace pid=3457 subj==unconfined comm="iptables"
[ 76.302132] audit: type=1325 audit(1633060903.549:133): table=filter family=2 entries=32 op=xt_replace pid=3459 subj==unconfined comm="iptables"
[ 76.342305] audit: type=1325 audit(1633060903.577:134): table=nat family=2 entries=20 op=xt_replace pid=3461 subj==unconfined comm="iptables"
[ 77.884760] eth0: renamed from veth8a5196b
[ 77.899547] IPv6: ADDRCONF(NETDEV_CHANGE): vethdc020f8: link becomes ready
[ 77.899703] hassio: port 6(vethdc020f8) entered blocking state
[ 77.899714] hassio: port 6(vethdc020f8) entered forwarding state
[ 79.296323] hassio: port 7(veth48cbb76) entered blocking state
[ 79.296336] hassio: port 7(veth48cbb76) entered disabled state
[ 79.296647] device veth48cbb76 entered promiscuous mode
[ 80.854417] kauditd_printk_skb: 22 callbacks suppressed
[ 80.854429] audit: type=1325 audit(1633060908.093:157): table=nat family=2 entries=13 op=xt_replace pid=3856 subj==unconfined comm="iptables"
[ 80.886397] audit: type=1325 audit(1633060908.129:158): table=nat family=2 entries=14 op=xt_replace pid=3858 subj==unconfined comm="iptables"
[ 80.929727] eth0: renamed from vethca35fba
[ 80.970325] IPv6: ADDRCONF(NETDEV_CHANGE): veth48cbb76: link becomes ready
[ 80.970597] hassio: port 7(veth48cbb76) entered blocking state
[ 80.970612] hassio: port 7(veth48cbb76) entered forwarding state
[ 81.244878] audit: type=1334 audit(1633060908.505:159): prog-id=12 op=UNLOAD
[ 81.244932] audit: type=1334 audit(1633060908.505:160): prog-id=11 op=UNLOAD
[ 81.339267] audit: type=1334 audit(1633060908.601:161): prog-id=14 op=UNLOAD
[ 81.339324] audit: type=1334 audit(1633060908.601:162): prog-id=13 op=UNLOAD
[ 88.032487] hassio: port 8(veth8e2b54d) entered blocking state
[ 88.032505] hassio: port 8(veth8e2b54d) entered disabled state
[ 88.033429] device veth8e2b54d entered promiscuous mode
[ 88.033511] audit: type=1700 audit(1633060915.293:163): dev=veth8e2b54d prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[ 89.586615] audit: type=1325 audit(1633060916.817:164): table=nat family=2 entries=0 op=xt_register pid=4402 subj==unconfined comm="iptables"
[ 89.650613] audit: type=1325 audit(1633060916.881:165): table=filter family=2 entries=0 op=xt_register pid=4404 subj==unconfined comm="iptables"
[ 89.691084] audit: type=1325 audit(1633060916.933:166): table=nat family=2 entries=5 op=xt_replace pid=4410 subj==unconfined comm="iptables"
[ 89.724073] audit: type=1325 audit(1633060916.961:167): table=nat family=2 entries=7 op=xt_replace pid=4421 subj==unconfined comm="iptables"
[ 89.760435] audit: type=1325 audit(1633060917.001:168): table=nat family=2 entries=8 op=xt_replace pid=4441 subj==unconfined comm="iptables"
[ 89.783972] audit: type=1325 audit(1633060917.029:169): table=nat family=2 entries=10 op=xt_replace pid=4451 subj==unconfined comm="iptables"
[ 89.822727] audit: type=1325 audit(1633060917.057:170): table=nat family=2 entries=11 op=xt_replace pid=4456 subj==unconfined comm="iptables"
[ 89.850713] audit: type=1325 audit(1633060917.093:171): table=nat family=2 entries=12 op=xt_replace pid=4457 subj==unconfined comm="iptables"
[ 89.880246] audit: type=1325 audit(1633060917.121:172): table=nat family=2 entries=13 op=xt_replace pid=4458 subj==unconfined comm="iptables"
[ 89.971629] eth0: renamed from veth6fe2f54
[ 90.000760] IPv6: ADDRCONF(NETDEV_CHANGE): veth8e2b54d: link becomes ready
[ 90.001006] hassio: port 8(veth8e2b54d) entered blocking state
[ 90.001022] hassio: port 8(veth8e2b54d) entered forwarding state
[ 91.856785] hassio: port 9(veth6b7b3fa) entered blocking state
[ 91.856818] hassio: port 9(veth6b7b3fa) entered disabled state
[ 91.857211] device veth6b7b3fa entered promiscuous mode
[ 93.402631] kauditd_printk_skb: 5 callbacks suppressed
[ 93.402638] audit: type=1325 audit(1633060920.633:178): table=nat family=2 entries=0 op=xt_register pid=4804 subj==unconfined comm="iptables"
[ 93.430894] audit: type=1325 audit(1633060920.673:179): table=filter family=2 entries=0 op=xt_register pid=4805 subj==unconfined comm="iptables"
[ 93.490723] audit: type=1325 audit(1633060920.717:180): table=nat family=2 entries=5 op=xt_replace pid=4808 subj==unconfined comm="iptables"
[ 93.526704] audit: type=1325 audit(1633060920.761:181): table=nat family=2 entries=7 op=xt_replace pid=4810 subj==unconfined comm="iptables"
[ 93.570844] audit: type=1325 audit(1633060920.801:182): table=nat family=2 entries=8 op=xt_replace pid=4813 subj==unconfined comm="iptables"
[ 93.598783] audit: type=1325 audit(1633060920.837:183): table=nat family=2 entries=10 op=xt_replace pid=4816 subj==unconfined comm="iptables"
[ 93.634762] audit: type=1325 audit(1633060920.869:184): table=nat family=2 entries=11 op=xt_replace pid=4817 subj==unconfined comm="iptables"
[ 93.682800] audit: type=1325 audit(1633060920.905:185): table=nat family=2 entries=12 op=xt_replace pid=4818 subj==unconfined comm="iptables"
[ 93.712216] audit: type=1325 audit(1633060920.953:186): table=nat family=2 entries=13 op=xt_replace pid=4823 subj==unconfined comm="iptables"
[ 93.742705] audit: type=1325 audit(1633060920.981:187): table=nat family=2 entries=14 op=xt_replace pid=4827 subj==unconfined comm="iptables"
[ 93.780858] eth0: renamed from veth65ef610
[ 93.806242] IPv6: ADDRCONF(NETDEV_CHANGE): veth6b7b3fa: link becomes ready
[ 93.806631] hassio: port 9(veth6b7b3fa) entered blocking state
[ 93.806656] hassio: port 9(veth6b7b3fa) entered forwarding state
[ 95.832068] hassio: port 10(vethea6edb0) entered blocking state
[ 95.832095] hassio: port 10(vethea6edb0) entered disabled state
[ 95.835344] device vethea6edb0 entered promiscuous mode
[ 98.132966] eth0: renamed from vetha3cd3e8
[ 98.162557] IPv6: ADDRCONF(NETDEV_CHANGE): vethea6edb0: link becomes ready
[ 98.162821] hassio: port 10(vethea6edb0) entered blocking state
[ 98.162838] hassio: port 10(vethea6edb0) entered forwarding state
[ 100.314909] hassio: port 11(veth5fc3650) entered blocking state
[ 100.314934] hassio: port 11(veth5fc3650) entered disabled state
[ 100.315365] device veth5fc3650 entered promiscuous mode
[ 100.315499] kauditd_printk_skb: 14 callbacks suppressed
[ 100.315507] audit: type=1700 audit(1633060927.577:202): dev=veth5fc3650 prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
[ 102.175564] audit: type=1325 audit(1633060929.409:203): table=nat family=2 entries=0 op=xt_register pid=5986 subj==unconfined comm="iptables"
[ 102.219184] audit: type=1325 audit(1633060929.461:204): table=filter family=2 entries=0 op=xt_register pid=5988 subj==unconfined comm="iptables"
[ 102.270986] audit: type=1325 audit(1633060929.505:205): table=nat family=2 entries=5 op=xt_replace pid=5993 subj==unconfined comm="iptables"
[ 102.302795] audit: type=1325 audit(1633060929.541:206): table=nat family=2 entries=7 op=xt_replace pid=5994 subj==unconfined comm="iptables"
[ 102.352004] audit: type=1325 audit(1633060929.585:207): table=nat family=2 entries=8 op=xt_replace pid=5996 subj==unconfined comm="iptables"
[ 102.390745] audit: type=1325 audit(1633060929.625:208): table=nat family=2 entries=10 op=xt_replace pid=5998 subj==unconfined comm="iptables"
[ 102.434922] audit: type=1325 audit(1633060929.665:209): table=nat family=2 entries=11 op=xt_replace pid=5999 subj==unconfined comm="iptables"
[ 102.478784] audit: type=1325 audit(1633060929.717:210): table=nat family=2 entries=12 op=xt_replace pid=6000 subj==unconfined comm="iptables"
[ 102.520355] audit: type=1325 audit(1633060929.757:211): table=nat family=2 entries=13 op=xt_replace pid=6003 subj==unconfined comm="iptables"
[ 102.596769] eth0: renamed from veth4c6d36d
[ 102.618735] IPv6: ADDRCONF(NETDEV_CHANGE): veth5fc3650: link becomes ready
[ 102.619021] hassio: port 11(veth5fc3650) entered blocking state
[ 102.619037] hassio: port 11(veth5fc3650) entered forwarding stateInterestingly enough I'm able to get the startup wizard to come up after moving the config yamls out of the way...
21-10-01 00:18:30 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state CoreState.RUNNING
21-10-01 00:18:32 INFO (MainThread) [supervisor.resolution.fixup] Starting system autofix at state CoreState.RUNNING
I might try a restore in place from my last snapshot and doing a comparsion of files or something.
rjroch
commented
3 years ago I have this exact same issue as well in my ESXi install. My WARNING (Thread-4) [homeassistant.util.executor] lines are for things like BMW connected, Nest, Ring, and not always the same one at each restart.
I tried spinning up a fresh VM and restoring multiple snapshots, all have the same problem.
Everything was fine with my environment, all I did was restart the VM (from supervisor). I hadn't made any config changes in weeks.
Tam-Lin
commented
3 years ago I'm getting the same problem, also with TPLink, it appears:
2021-10-01 11:49:52 WARNING (Thread-12) [homeassistant.util.executor] Thread[SyncWorker_2] is still running at shutdown: File "/usr/local/lib/python3.9/threading.py", line 930, in _bootstrap
self._bootstrap_inner()
File "/usr/local/lib/python3.9/threading.py", line 973, in _bootstrap_inner
self.run()
File "/usr/local/lib/python3.9/threading.py", line 910, in run
self._target(*self._args, **self._kwargs)
File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 77, in _worker
work_item.run()
File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 52, in run
result = self.fn(*self.args, **self.kwargs)
File "/usr/src/homeassistant/homeassistant/components/tplink/common.py", line 64, in discover
return Discover.discover()
File "/usr/local/lib/python3.9/site-packages/pyHS100/discover.py", line 51, in discover
data, addr = sock.recvfrom(4096)
2021-10-01 11:49:53 WARNING (Thread-12) [homeassistant.util.executor] Thread[SyncWorker_2] is still running at shutdown: File "/usr/local/lib/python3.9/threading.py", line 930, in _bootstrap
self._bootstrap_inner()
File "/usr/local/lib/python3.9/threading.py", line 973, in _bootstrap_inner
self.run()
File "/usr/local/lib/python3.9/threading.py", line 910, in run
self._target(*self._args, **self._kwargs)
File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 77, in _worker
work_item.run()
File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 52, in run
result = self.fn(*self.args, **self.kwargs)
File "/usr/src/homeassistant/homeassistant/components/tplink/common.py", line 64, in discover
return Discover.discover()
File "/usr/local/lib/python3.9/site-packages/pyHS100/discover.py", line 51, in discover
data, addr = sock.recvfrom(4096)Full restore in-place didn't work...
@rjroch since you've already done a restore to a clean VM, I'll assume it won't help for me to reflash my raspberry pi (especially since I also know I can get HA to start by deleting my configuration.yaml)
My next step is probably to try a partial rollback to my Sept 12 backup of 2021.9.6 (seeing if I can only do HA core and not the configuration or other containers).
If that works then it's something about 2021.9.7...
Another path of troubleshooting might be to compare configuration integrations and eliminate common ones until we get back to a working HA core.
I'm not sure best way to figure out what integrations are installed, this might be a starting point (assuming you can SSH in via core-ssh)
grep platform /root/config/*.yaml | grep -v '#' | cut -d: -f3 | cut -b2- | sort -uFor me I have these:
channels
command_line
decora_wifi
dnsip
environment_canada
event
ffmpeg
generic
google_translate
group
hangouts
homeassistant
itunes
lametric
mjpeg
moon
mqtt
nest
neurio_energy
numeric_state
openhardwaremonitor
ping
qnap
rest
season
state
statistics
systemmonitor
template
time
time_pattern
uptime
workdayThat doesn't cover stuff in .storage/core.entity_registry or known_devices.yaml though... Though I'm pretty sure I nuked those in previous troubleshooting steps and it made no difference.
Tam-Lin
commented
3 years ago I seem to have fixed this. I changed two things (yes, should have just done 1):
1) I removed a TPLink device that ha couldn't reach from the list of TP Link devices core.config_entries 2) I removed the entry for Plum light pads that I had in core.config_entries, as they seem to be completely gone now
deftdawg
commented
3 years ago @Tam-Lin I also have plum_lightpad, I'll try removing that one and restarting!
deftdawg
commented
3 years ago I ended up nuking:
plum and tplink from /root/config/.storage/core.config_entriesitunes media player and plum from my configuration.yamlAnd now she starts!!! Thanks to @Tam-Lin for point us in the right direction!
All these devices were either no longer responding locally (tplink and itunes) or from the cloud (plum).
Tam-Lin
commented
3 years ago So the problem is sort of understood, but definitely needs to be debugged and fixed.
rjroch
commented
3 years ago I guess Plum finally killed their cloud service?
Tam-Lin
commented
3 years ago Maybe, that's what I'm wondering. My one remaining plum lightswitch has been cycling through rainbow colors, which is why I thought to remove it. I can't figure out what servers HA is relying on to check beyond that, though I didn't dig into it too deeply.
On Fri, Oct 1, 2021 at 4:03 PM rjroch @.***> wrote:
I guess Plum finally killed their cloud service?
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/56745#issuecomment-932515125, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAFACOXGBKOEBY3AA6TRS4DUEYH2BANCNFSM5E5WVOBA . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.
rjroch
commented
3 years ago Whatever they're using, the iOS app now no longer works for me. It says it cannot contact the cloud server. I have three of the switches that still work perfectly, but I guess I'll be finding replacements for them. Sad, it's some really nice hardware.
With Plum disabled, however, my HA instance still won't start. I bit the bullet and started from scratch. I guess it will let me set things up more correctly, perhaps, rather than the cobbled together config I had in place.
deftdawg
commented
3 years ago @rjroch I think just disabling plum from configuration.yaml is probably not enough, you need to nuke every mention from config/.storage/core.config_entries that requires core-SSH to fix though
rjroch
commented
3 years ago Yeah, removing the core.config_entries entry fixed the problem for me. There must not be a timeout in the initialization of the Plum addon or something.
I wonder if the Plum cloud service will ever come back. This happened once before a couple of years ago, the service was down for a week or so, and then mysteriously was available again.
rjroch
commented
3 years ago Also, simply changing "disabled_by": null to "disabled_by": "user" allows the system to come up fully, and leaves the config entry available in case we'd like to try the Plum service again occasionally.
Apparently this is the way to disable integrations which are not set up in configuration.yaml.
Update:
When either the hardware or the cloud service for an integration present within core.config_entries fails to respond to HA during startup, HA can die and HA OS gets stuck in
CoreState.STARTUPeffectively bricking the HA installation.configuration.yamlExample:Original:
The problem
Same as #53605.... Core does not shutdown because this thread won't quit.
Doesn't appear to be a way can force core to restart from ssh using "ha" command.
Restarting supervisor is possible, however supervisor doesn't kill core and fix the issue.
What is version of Home Assistant Core has the issue?
core-2021.9.7
What was the last working version of Home Assistant Core?
No response
What type of installation are you running?
Home Assistant OS
Integration causing the issue
plum
Link to integration documentation on our website
No response
Example YAML snippet
No response
Anything in the logs that might be useful for us?
Additional information
Supervisor logs