Skip to content
New issue

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

Sign up for GitHub

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

Already on GitHub? Sign in to your account

Jump to bottom

OS 12.2 and 12.3 show bad status on ThinkCentre M93p #3376

Open
coc opened this issue May 16, 2024 · 0 comments
Open

OS 12.2 and 12.3 show bad status on ThinkCentre M93p #3376

coc opened this issue May 16, 2024 · 0 comments
Labels
bug

Comments

@coc
Copy link

coc commented May 16, 2024

Describe the issue you are experiencing

When flashing x86-64 generic version 12.2 or 12.3 on a SATA SSD on a ThinkCentre M93p Thin Client, a new reboot is not possible. Status = bad is reported

BadStatus

If I downgrade from 12.3 to 12.2 on ha console and upgrade back to 12.3 from UI, the status is good for both slots.

The next issue: After restoring a full backup in 12.3, File Editor and Advanced SSH & WEB Terminal will not start. The only way to get it start is to reboot the OS again.

What operating system image do you use?

generic-x86-64 (Generic UEFI capable x86-64 systems)

What version of Home Assistant Operating System is installed?

6.6.29-haos

Did you upgrade the Operating System.

Yes

Steps to reproduce the issue

  1. Flash SSD image from USB Stick on a ThinkCebtre M93p
  2. shutdown and remove USB stick
  3. reboot
    ...

Anything in the Supervisor logs that might be useful for us?

2024-05-16 05:50:37.088 WARNING (SyncWorker_0) [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
2024-05-16 05:50:38.121 WARNING (Recorder) [homeassistant.components.recorder.util] The system could not validate that the sqlite3 database at //config/home-assistant_v2.db was shutdown cleanly
2024-05-16 05:50:38.134 WARNING (Recorder) [homeassistant.components.recorder.util] Ended unfinished session (id=34 from 2024-05-15 17:20:56.396504)
2024-05-16 05:50:39.784 WARNING (MainThread) [homeassistant.helpers.frame] Detected that custom integration 'hacs' accesses hass.components.frontend. This is deprecated and will stop working in Home Assistant 2024.9, it should be updated to import functions used from frontend directly at custom_components/hacs/frontend.py, line 68: hass.components.frontend.async_register_built_in_panel(, please create a bug report at https://github.com/hacs/integration/issues
2024-05-16 05:50:40.667 WARNING (MainThread) [homeassistant.components.http.ban] Login attempt or request with invalid authentication from supervisor (172.30.32.2). Requested URL: '/api/core/state'. (HomeAssistantSupervisor/2024.05.1 aiohttp/3.9.5 Python/3.12)
2024-05-16 05:50:42.623 WARNING (ImportExecutor_0) [py.warnings] /usr/local/lib/python3.12/site-packages/vobject/base.py:736: SyntaxWarning: invalid escape sequence '\-'
  patterns['name'] = '[a-zA-Z0-9\-_]+'

2024-05-16 05:50:42.626 WARNING (ImportExecutor_0) [py.warnings] /usr/local/lib/python3.12/site-packages/vobject/base.py:1219: SyntaxWarning: invalid escape sequence '\;'
  s = s.replace("\\", "\\\\").replace(";", "\;").replace(",", "\,")

2024-05-16 05:50:42.626 WARNING (ImportExecutor_0) [py.warnings] /usr/local/lib/python3.12/site-packages/vobject/base.py:1219: SyntaxWarning: invalid escape sequence '\,'
  s = s.replace("\\", "\\\\").replace(";", "\;").replace(",", "\,")

2024-05-16 05:50:45.101 ERROR (bellows.thread_0) [bellows.uart] CRC error in frame b'0dd20a7e' (b'd20a' != b'305d')
2024-05-16 05:50:52.210 WARNING (MainThread) [homeassistant.helpers.frame] Detected that custom integration 'hacs' accesses hass.helpers.event. This is deprecated and will stop working in Home Assistant 2024.11, it should be updated to import functions used from event directly at custom_components/hacs/base.py, line 642: self.hass.helpers.event.async_track_time_interval(, please create a bug report at https://github.com/hacs/integration/issues
2024-05-16 05:50:57.685 WARNING (Recorder) [homeassistant.components.sensor.recorder] Entity sensor.tibber_pulse_fasanenweg_27_produktion_auf_der_letzten_meile from integration tibber has state class total_increasing, but its state is negative. Triggered by state -1 with last_updated set to 2024-05-16T03:19:59.999999+00:00. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+tibber%22

--------------

s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
cont-init: info: running /etc/cont-init.d/udev.sh
[04:14:04] INFO: Using udev information from host
cont-init: info: /etc/cont-init.d/udev.sh exited 0
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
services-up: info: copying legacy longrun supervisor (no readiness notification)
services-up: info: copying legacy longrun watchdog (no readiness notification)
[04:14:04] INFO: Starting local supervisor watchdog...
s6-rc: info: service legacy-services successfully started
2024-05-16 04:14:05.753 INFO (MainThread) [__main__] Initializing Supervisor setup
2024-05-16 04:14:05.763 INFO (MainThread) [supervisor.docker.network] Can't find Supervisor network, creating a new network
2024-05-16 04:14:05.898 INFO (MainThread) [supervisor.bootstrap] Setting up coresys for machine: generic-x86-64
2024-05-16 04:14:05.901 INFO (MainThread) [supervisor.docker.supervisor] Attaching to Supervisor ghcr.io/home-assistant/amd64-hassio-supervisor with version 2024.05.1
2024-05-16 04:14:05.901 INFO (MainThread) [supervisor.docker.supervisor] Connecting Supervisor to hassio-network
2024-05-16 04:14:06.004 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state initialize
2024-05-16 04:14:06.007 INFO (MainThread) [supervisor.resolution.evaluate] System evaluation complete
2024-05-16 04:14:06.008 INFO (MainThread) [__main__] Setting up Supervisor
2024-05-16 04:14:06.111 INFO (MainThread) [supervisor.api] Starting API on 172.30.32.2
2024-05-16 04:14:06.172 INFO (MainThread) [supervisor.hardware.monitor] Started Supervisor hardware monitor
2024-05-16 04:14:06.173 INFO (MainThread) [supervisor.dbus.manager] Connected to system D-Bus.
2024-05-16 04:14:06.173 INFO (MainThread) [supervisor.dbus.agent] Load dbus interface io.hass.os
2024-05-16 04:14:06.174 INFO (MainThread) [supervisor.dbus.hostname] Load dbus interface org.freedesktop.hostname1
2024-05-16 04:14:06.174 INFO (MainThread) [supervisor.dbus.logind] Load dbus interface org.freedesktop.login1
2024-05-16 04:14:06.174 INFO (MainThread) [supervisor.dbus.network] Load dbus interface org.freedesktop.NetworkManager
2024-05-16 04:14:06.175 INFO (MainThread) [supervisor.dbus.rauc] Load dbus interface de.pengutronix.rauc
2024-05-16 04:14:06.175 INFO (MainThread) [supervisor.dbus.resolved] Load dbus interface org.freedesktop.resolve1
2024-05-16 04:14:06.175 INFO (MainThread) [supervisor.dbus.systemd] Load dbus interface org.freedesktop.systemd1
2024-05-16 04:14:06.175 INFO (MainThread) [supervisor.dbus.timedate] Load dbus interface org.freedesktop.timedate1
2024-05-16 04:14:06.256 INFO (MainThread) [supervisor.host.services] Updating service information
2024-05-16 04:14:06.260 INFO (MainThread) [supervisor.host.sound] Updating PulseAudio information
2024-05-16 04:14:06.262 WARNING (SyncWorker_0) [supervisor.host.sound] Can't update PulseAudio data: Failed to connect to pulseaudio server
2024-05-16 04:14:06.327 INFO (MainThread) [supervisor.host.network] Updating local network information
2024-05-16 04:14:06.348 INFO (MainThread) [supervisor.host.apparmor] Loading AppArmor Profiles: {'hassio-supervisor'}
2024-05-16 06:14:06.432 INFO (MainThread) [supervisor.docker.monitor] Started docker events monitor
2024-05-16 06:14:06.432 INFO (MainThread) [supervisor.updater] Fetching update data from https://version.home-assistant.io/stable.json
2024-05-16 06:14:06.509 INFO (MainThread) [supervisor.docker.interface] Found ghcr.io/home-assistant/amd64-hassio-cli versions: [<AwesomeVersion CalVer '2024.05.0'>]
2024-05-16 06:14:06.513 INFO (MainThread) [supervisor.docker.interface] Attaching to ghcr.io/home-assistant/amd64-hassio-cli with version 2024.05.0
2024-05-16 06:14:06.530 INFO (MainThread) [supervisor.plugins.cli] Starting CLI plugin
2024-05-16 06:14:06.811 INFO (MainThread) [supervisor.docker.cli] Starting CLI ghcr.io/home-assistant/amd64-hassio-cli with version 2024.05.0 - 172.30.32.5
2024-05-16 06:14:06.831 INFO (MainThread) [supervisor.docker.interface] Found ghcr.io/home-assistant/amd64-hassio-dns versions: [<AwesomeVersion CalVer '2024.04.0'>]
2024-05-16 06:14:06.836 INFO (MainThread) [supervisor.docker.interface] Attaching to ghcr.io/home-assistant/amd64-hassio-dns with version 2024.04.0
2024-05-16 06:14:06.865 INFO (MainThread) [supervisor.plugins.dns] Starting CoreDNS plugin
2024-05-16 06:14:07.150 INFO (MainThread) [supervisor.docker.dns] Starting DNS ghcr.io/home-assistant/amd64-hassio-dns with version 2024.04.0 - 172.30.32.3
2024-05-16 06:14:07.151 INFO (MainThread) [supervisor.plugins.dns] Updated /etc/resolv.conf
2024-05-16 06:14:07.167 INFO (MainThread) [supervisor.docker.interface] Found ghcr.io/home-assistant/amd64-hassio-audio versions: [<AwesomeVersion CalVer '2023.12.0'>]
2024-05-16 06:14:07.172 INFO (MainThread) [supervisor.docker.interface] Attaching to ghcr.io/home-assistant/amd64-hassio-audio with version 2023.12.0
2024-05-16 06:14:07.193 INFO (MainThread) [supervisor.plugins.audio] Starting Audio plugin
2024-05-16 06:14:07.534 INFO (MainThread) [supervisor.docker.audio] Starting Audio ghcr.io/home-assistant/amd64-hassio-audio with version 2023.12.0 - 172.30.32.4
2024-05-16 06:14:07.541 INFO (MainThread) [supervisor.docker.interface] Found ghcr.io/home-assistant/amd64-hassio-observer versions: [<AwesomeVersion CalVer '2023.06.0'>]
2024-05-16 06:14:07.545 INFO (MainThread) [supervisor.docker.interface] Attaching to ghcr.io/home-assistant/amd64-hassio-observer with version 2023.06.0
2024-05-16 06:14:07.573 INFO (MainThread) [supervisor.plugins.observer] Starting observer plugin
2024-05-16 06:14:07.916 INFO (MainThread) [supervisor.docker.observer] Starting Observer ghcr.io/home-assistant/amd64-hassio-observer with version 2023.06.0 - 172.30.32.6
2024-05-16 06:14:07.926 INFO (MainThread) [supervisor.docker.interface] Found ghcr.io/home-assistant/amd64-hassio-multicast versions: [<AwesomeVersion CalVer '2024.03.0'>]
2024-05-16 06:14:07.930 INFO (MainThread) [supervisor.docker.interface] Attaching to ghcr.io/home-assistant/amd64-hassio-multicast with version 2024.03.0
2024-05-16 06:14:07.942 INFO (MainThread) [supervisor.plugins.multicast] Starting Multicast plugin
2024-05-16 06:14:08.108 INFO (MainThread) [supervisor.docker.multicast] Starting Multicast ghcr.io/home-assistant/amd64-hassio-multicast with version 2024.03.0 - Host
2024-05-16 06:14:08.108 INFO (MainThread) [supervisor.homeassistant.secrets] Loaded 0 Home Assistant secrets
2024-05-16 06:14:08.116 INFO (MainThread) [supervisor.docker.interface] No version found for ghcr.io/home-assistant/generic-x86-64-homeassistant
2024-05-16 06:14:08.116 INFO (MainThread) [supervisor.homeassistant.core] No Home Assistant Docker image ghcr.io/home-assistant/generic-x86-64-homeassistant found.
2024-05-16 06:14:08.120 INFO (MainThread) [supervisor.docker.interface] Attaching to ghcr.io/home-assistant/generic-x86-64-homeassistant with version landingpage
2024-05-16 06:14:08.121 INFO (MainThread) [supervisor.homeassistant.core] Using preinstalled landingpage
2024-05-16 06:14:08.131 INFO (MainThread) [supervisor.homeassistant.core] Starting HomeAssistant landingpage
2024-05-16 06:14:08.148 INFO (MainThread) [supervisor.homeassistant.module] Update pulse/client.config: /data/tmp/homeassistant_pulse
2024-05-16 06:14:08.343 INFO (MainThread) [supervisor.docker.homeassistant] Starting Home Assistant ghcr.io/home-assistant/generic-x86-64-homeassistant with version landingpage
2024-05-16 06:14:08.362 INFO (MainThread) [supervisor.os.manager] Detect Home Assistant Operating System 12.3 / BootSlot A
2024-05-16 06:14:08.364 INFO (MainThread) [supervisor.store.git] Cloning add-on https://github.com/esphome/home-assistant-addon repository
2024-05-16 06:14:08.364 INFO (MainThread) [supervisor.store.git] Cloning add-on https://github.com/home-assistant/addons repository
2024-05-16 06:14:08.365 INFO (MainThread) [supervisor.store.git] Cloning add-on https://github.com/hassio-addons/repository repository
2024-05-16 06:14:09.578 INFO (MainThread) [supervisor.store] Loading add-ons from store: 77 all - 77 new - 0 remove
2024-05-16 06:14:09.598 INFO (MainThread) [supervisor.addons.manager] Found 0 installed add-ons
2024-05-16 06:14:09.612 INFO (MainThread) [supervisor.backups.manager] Found 0 backup files
2024-05-16 06:14:09.612 INFO (MainThread) [supervisor.discovery] Loaded 0 messages
2024-05-16 06:14:09.612 INFO (MainThread) [supervisor.ingress] Loaded 0 ingress sessions
2024-05-16 06:14:09.613 INFO (MainThread) [supervisor.resolution.check] Starting system checks with state setup
2024-05-16 06:14:09.613 INFO (MainThread) [supervisor.resolution.checks.base] Run check for disabled_data_disk/system
2024-05-16 06:14:09.613 INFO (MainThread) [supervisor.resolution.checks.base] Run check for multiple_data_disks/system
2024-05-16 06:14:09.613 INFO (MainThread) [supervisor.resolution.check] System checks complete
2024-05-16 06:14:09.613 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state setup
2024-05-16 06:14:09.613 INFO (MainThread) [supervisor.resolution.evaluate] System evaluation complete
2024-05-16 06:14:09.613 INFO (MainThread) [supervisor.jobs] 'ResolutionFixup.run_autofix' blocked from execution, system is not running - setup
2024-05-16 06:14:09.613 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state setup
2024-05-16 06:14:09.614 INFO (MainThread) [supervisor.resolution.evaluate] System evaluation complete
2024-05-16 06:14:09.614 INFO (MainThread) [__main__] Running Supervisor
2024-05-16 06:14:09.622 INFO (MainThread) [supervisor.os.manager] Rauc: A - marked slot kernel.0 as good
2024-05-16 06:14:09.626 INFO (MainThread) [supervisor.addons.manager] Phase 'initialize' starting 0 add-ons
2024-05-16 06:14:09.639 INFO (MainThread) [supervisor.addons.manager] Phase 'system' starting 0 add-ons
2024-05-16 06:14:09.639 INFO (MainThread) [supervisor.addons.manager] Phase 'services' starting 0 add-ons
2024-05-16 06:14:09.642 INFO (MainThread) [supervisor.core] Skipping start of Home Assistant
2024-05-16 06:14:09.642 INFO (MainThread) [supervisor.addons.manager] Phase 'application' starting 0 add-ons
2024-05-16 06:14:09.651 INFO (MainThread) [supervisor.misc.tasks] All core tasks are scheduled
2024-05-16 06:14:09.651 INFO (MainThread) [supervisor.core] Supervisor is up and running
2024-05-16 06:14:09.651 INFO (MainThread) [supervisor.homeassistant.core] Home Assistant setup
2024-05-16 06:14:09.651 INFO (MainThread) [supervisor.docker.interface] Updating image ghcr.io/home-assistant/generic-x86-64-homeassistant:landingpage to ghcr.io/home-assistant/generic-x86-64-homeassistant:2024.5.3
2024-05-16 06:14:09.652 INFO (MainThread) [supervisor.docker.interface] Downloading docker image ghcr.io/home-assistant/generic-x86-64-homeassistant with tag 2024.5.3.
2024-05-16 06:14:09.652 INFO (MainThread) [supervisor.host.info] Updating local host information
2024-05-16 06:14:09.652 INFO (MainThread) [supervisor.resolution.check] Starting system checks with state running
2024-05-16 06:14:09.652 INFO (MainThread) [supervisor.resolution.checks.base] Run check for dns_server_failed/dns_server
2024-05-16 06:14:09.667 INFO (MainThread) [supervisor.host.services] Updating service information
2024-05-16 06:14:09.668 INFO (MainThread) [supervisor.resolution.checks.base] Run check for disabled_data_disk/system
2024-05-16 06:14:09.668 INFO (MainThread) [supervisor.resolution.checks.base] Run check for multiple_data_disks/system
2024-05-16 06:14:09.669 INFO (MainThread) [supervisor.resolution.checks.base] Run check for trust/supervisor
2024-05-16 06:14:09.672 INFO (MainThread) [supervisor.host.network] Updating local network information
2024-05-16 06:14:09.674 INFO (MainThread) [supervisor.resolution.checks.base] Run check for pwned/addon
2024-05-16 06:14:09.674 INFO (MainThread) [supervisor.resolution.checks.base] Run check for free_space/system
2024-05-16 06:14:09.674 INFO (MainThread) [supervisor.resolution.checks.base] Run check for dns_server_ipv6_error/dns_server
2024-05-16 06:14:09.688 INFO (MainThread) [supervisor.resolution.checks.base] Run check for no_current_backup/system
2024-05-16 06:14:09.688 INFO (MainThread) [supervisor.resolution.module] Create new suggestion create_full_backup - system / None
2024-05-16 06:14:09.689 INFO (MainThread) [supervisor.resolution.module] Create new issue no_current_backup - system / None
2024-05-16 06:14:09.689 INFO (MainThread) [supervisor.resolution.checks.base] Run check for ipv4_connection_problem/system
2024-05-16 06:14:09.689 INFO (MainThread) [supervisor.resolution.checks.base] Run check for security/core
2024-05-16 06:14:09.689 INFO (MainThread) [supervisor.resolution.checks.base] Run check for docker_config/system
2024-05-16 06:14:09.689 INFO (MainThread) [supervisor.resolution.check] System checks complete
2024-05-16 06:14:09.689 INFO (MainThread) [supervisor.resolution.evaluate] Starting system evaluation with state running
2024-05-16 06:14:09.736 INFO (MainThread) [supervisor.host.sound] Updating PulseAudio information
2024-05-16 06:14:09.742 INFO (MainThread) [supervisor.host.manager] Host information reload completed
2024-05-16 06:14:09.810 INFO (MainThread) [supervisor.resolution.evaluate] System evaluation complete
2024-05-16 06:14:09.810 INFO (MainThread) [supervisor.resolution.fixup] Starting system autofix at state running
2024-05-16 06:14:09.810 INFO (MainThread) [supervisor.resolution.fixup] System autofix complete
2024-05-16 06:14:32.196 ERROR (MainThread) [supervisor.os.manager] Don't have an URL for OTA updates!

Anything in the Host logs that might be useful for us?

2024-05-16 07:05:29.325 WARNING (SyncWorker_0) [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
2024-05-16 07:05:31.948 WARNING (MainThread) [homeassistant.helpers.frame] Detected that custom integration 'hacs' accesses hass.components.frontend. This is deprecated and will stop working in Home Assistant 2024.9, it should be updated to import functions used from frontend directly at custom_components/hacs/frontend.py, line 68: hass.components.frontend.async_register_built_in_panel(, please create a bug report at https://github.com/hacs/integration/issues
2024-05-16 07:05:44.423 WARNING (MainThread) [zigpy.application] Zigbee channel 20 utilization is 93.76%!
2024-05-16 07:05:44.424 WARNING (MainThread) [zigpy.application] If you are having problems joining new devices, are missing sensor updates, or have issues keeping devices joined, ensure your coordinator is away from interference sources such as USB 3.0 devices, SSDs, WiFi routers, etc.
2024-05-16 07:05:44.532 WARNING (MainThread) [homeassistant.helpers.frame] Detected that custom integration 'hacs' accesses hass.helpers.event. This is deprecated and will stop working in Home Assistant 2024.11, it should be updated to import functions used from event directly at custom_components/hacs/base.py, line 642: self.hass.helpers.event.async_track_time_interval(, please create a bug report at https://github.com/hacs/integration/issues
2024-05-16 07:05:50.030 WARNING (Recorder) [homeassistant.components.sensor.recorder] Entity sensor.tibber_pulse_fasanenweg_27_produktion_auf_der_letzten_meile from integration tibber has state class total_increasing, but its state is negative. Triggered by state -1 with last_updated set to 2024-05-16T04:59:59.999999+00:00. Please create a bug report at https://github.com/home-assistant/core/issues?q=is%3Aopen+is%3Aissue+label%3A%22integration%3A+tibber%22
2024-05-16 09:20:35.133 ERROR (MainThread) [tibber.home] Error in rt_subscribe
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/protocol.py", line 963, in transfer_data
    message = await self.read_message()
              ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/protocol.py", line 1033, in read_message
    frame = await self.read_data_frame(max_size=self.max_size)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/protocol.py", line 1108, in read_data_frame
    frame = await self.read_frame(max_size)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/protocol.py", line 1165, in read_frame
    frame = await Frame.read(
            ^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/framing.py", line 68, in read
    data = await reader(2)
           ^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/asyncio/streams.py", line 750, in readexactly
    raise exceptions.IncompleteReadError(incomplete, n)
asyncio.exceptions.IncompleteReadError: 0 bytes read on a total of 2 expected bytes

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

Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/tibber/home.py", line 439, in _start
    async for data in self._tibber_control.realtime.sub_manager.session.subscribe(
  File "/usr/local/lib/python3.12/site-packages/gql/client.py", line 1475, in subscribe
    async for result in inner_generator:
  File "/usr/local/lib/python3.12/site-packages/gql/client.py", line 1372, in _subscribe
    async for result in inner_generator:
  File "/usr/local/lib/python3.12/site-packages/gql/transport/websockets_base.py", line 388, in subscribe
    answer_type, execution_result = await listener.get()
                                    ^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/gql/transport/websockets_base.py", line 56, in get
    raise item
  File "/usr/local/lib/python3.12/site-packages/gql/transport/websockets_base.py", line 301, in _receive_data_loop
    answer = await self._receive()
             ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/tibber/websocker_transport.py", line 37, in _receive
    msg = await asyncio.wait_for(super()._receive(), timeout=self._timeout)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/asyncio/tasks.py", line 520, in wait_for
    return await fut
           ^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/gql/transport/websockets_base.py", line 231, in _receive
    data: Data = await self.websocket.recv()
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/protocol.py", line 568, in recv
    await self.ensure_open()
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/protocol.py", line 934, in ensure_open
    raise self.connection_closed_exc()
websockets.exceptions.ConnectionClosedError: no close frame received or sent
2024-05-16 09:20:37.466 ERROR (MainThread) [tibber.realtime] Watchdog: Connection is down, 2024-05-16 09:20:47.466842
2024-05-16 09:20:47.707 ERROR (MainThread) [tibber.realtime] Error in watchdog connect, retrying in 43 seconds, 1
2024-05-16 09:21:35.709 ERROR (MainThread) [tibber.realtime] Watchdog: Connection is down, 2024-05-16 09:21:45.709006
2024-05-16 09:23:42.335 ERROR (MainThread) [tibber.realtime] Watchdog: Connection is down, 2024-05-16 09:23:52.335800
2024-05-16 09:23:52.631 ERROR (MainThread) [tibber.realtime] Error in watchdog connect, retrying in 6 seconds, 1
2024-05-16 09:24:03.633 ERROR (MainThread) [tibber.realtime] Watchdog: Connection is down, 2024-05-16 09:24:13.633702
2024-05-16 11:08:01.370 ERROR (MainThread) [tibber.home] Error in rt_subscribe
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/protocol.py", line 963, in transfer_data
    message = await self.read_message()
              ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/protocol.py", line 1033, in read_message
    frame = await self.read_data_frame(max_size=self.max_size)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/protocol.py", line 1108, in read_data_frame
    frame = await self.read_frame(max_size)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/protocol.py", line 1165, in read_frame
    frame = await Frame.read(
            ^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/framing.py", line 68, in read
    data = await reader(2)
           ^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/asyncio/streams.py", line 750, in readexactly
    raise exceptions.IncompleteReadError(incomplete, n)
asyncio.exceptions.IncompleteReadError: 0 bytes read on a total of 2 expected bytes

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

Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/tibber/home.py", line 439, in _start
    async for data in self._tibber_control.realtime.sub_manager.session.subscribe(
  File "/usr/local/lib/python3.12/site-packages/gql/client.py", line 1475, in subscribe
    async for result in inner_generator:
  File "/usr/local/lib/python3.12/site-packages/gql/client.py", line 1372, in _subscribe
    async for result in inner_generator:
  File "/usr/local/lib/python3.12/site-packages/gql/transport/websockets_base.py", line 388, in subscribe
    answer_type, execution_result = await listener.get()
                                    ^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/gql/transport/websockets_base.py", line 56, in get
    raise item
  File "/usr/local/lib/python3.12/site-packages/gql/transport/websockets_base.py", line 301, in _receive_data_loop
    answer = await self._receive()
             ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/tibber/websocker_transport.py", line 37, in _receive
    msg = await asyncio.wait_for(super()._receive(), timeout=self._timeout)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/asyncio/tasks.py", line 520, in wait_for
    return await fut
           ^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/gql/transport/websockets_base.py", line 231, in _receive
    data: Data = await self.websocket.recv()
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/protocol.py", line 568, in recv
    await self.ensure_open()
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/protocol.py", line 934, in ensure_open
    raise self.connection_closed_exc()
websockets.exceptions.ConnectionClosedError: no close frame received or sent
2024-05-16 11:08:05.567 ERROR (MainThread) [tibber.realtime] Watchdog: Connection is down, 2024-05-16 11:08:15.567167
2024-05-16 11:08:15.797 ERROR (MainThread) [tibber.realtime] Error in watchdog connect, retrying in 31 seconds, 1
2024-05-16 11:08:51.799 ERROR (MainThread) [tibber.realtime] Watchdog: Connection is down, 2024-05-16 11:09:01.799388
2024-05-16 11:10:12.021 ERROR (MainThread) [tibber.realtime] Watchdog: Connection is down, 2024-05-16 11:10:22.020997
2024-05-16 11:10:32.238 ERROR (MainThread) [tibber.realtime] Error in watchdog connect, retrying in 6 seconds, 1
2024-05-16 11:10:43.241 ERROR (MainThread) [tibber.realtime] Watchdog: Connection is down, 2024-05-16 11:10:53.241126
2024-05-16 11:10:53.485 ERROR (MainThread) [tibber.realtime] Error in watchdog connect, retrying in 54 seconds, 2
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/asyncio/tasks.py", line 520, in wait_for
    return await fut
           ^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/client.py", line 647, in __await_impl_timeout__
    return await self.__await_impl__()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/client.py", line 654, in __await_impl__
    await protocol.handshake(
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/client.py", line 319, in handshake
    status_code, response_headers = await self.read_http_response()
                                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/client.py", line 139, in read_http_response
    status_code, reason, headers = await read_response(self.reader)
                                   ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/http.py", line 120, in read_response
    status_line = await read_line(stream)
                  ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/websockets/legacy/http.py", line 194, in read_line
    line = await stream.readline()
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/asyncio/streams.py", line 568, in readline
    line = await self.readuntil(sep)
           ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/asyncio/streams.py", line 660, in readuntil
    await self._wait_for_data('readuntil')
  File "/usr/local/lib/python3.12/asyncio/streams.py", line 545, in _wait_for_data
    await self._waiter
asyncio.exceptions.CancelledError

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

Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/tibber/realtime.py", line 156, in _watchdog
    await self.sub_manager.connect_async()  # type: ignore
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/site-packages/gql/client.py", line 789, in connect_async
    await self.transport.connect()
  File "/usr/local/lib/python3.12/site-packages/gql/transport/websockets_base.py", line 490, in connect
    self.websocket = await asyncio.wait_for(
                     ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.12/asyncio/tasks.py", line 519, in wait_for
    async with timeouts.timeout(timeout):
  File "/usr/local/lib/python3.12/asyncio/timeouts.py", line 115, in __aexit__
    raise TimeoutError from exc_val
TimeoutError
2024-05-16 11:11:52.492 ERROR (MainThread) [tibber.realtime] Watchdog: Connection is down, 2024-05-16 11:12:02.492509
2024-05-16 12:36:12.293 WARNING (MainThread) [homeassistant.components.websocket_api.http.connection] [139814717679808] from 10.10.10.104 (Home Assistant/2024.4 (io.robbie.HomeAssistant; build:2024.624; iOS 17.4.1)): Disconnected: Did not receive auth message within 10 seconds

System information

No response

Additional information

No response
@coc coc added the bug label May 16, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@coc