home-assistant / supervisor

:house_with_garden: Home Assistant Supervisor
https://home-assistant.io/hassio/
Apache License 2.0
1.75k stars 639 forks source link

Bad File Descriptor on boot #1765

Closed sla89 closed 4 years ago

sla89 commented 4 years ago

Home Assistant release with the issue: Home Assistant 0.110.4

Operating environment (HassOS/Generic): Raspberry PI 3 with HassOS 4.8

Supervisor logs:

Traceback (most recent call last):
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 449, in send
    timeout=timeout
  File "/usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py", line 738, in urlopen
    conn = conn and conn.close()
  File "/usr/local/lib/python3.7/http/client.py", line 951, in close
    sock.close()   # close it manually... there may be other refs
  File "/usr/local/lib/python3.7/socket.py", line 420, in close
    self._real_close()
  File "/usr/local/lib/python3.7/socket.py", line 414, in _real_close
    _ss.close(self)
OSError: [Errno 9] Bad file descriptor
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/usr/src/supervisor/supervisor/plugins/multicast.py", line 94, in load
    await self.start()
  File "/usr/src/supervisor/supervisor/plugins/multicast.py", line 158, in start
    await self.instance.run()
  File "/usr/src/supervisor/supervisor/utils/__init__.py", line 31, in wrap_api
    return await method(api, *args, **kwargs)
  File "/usr/local/lib/python3.7/concurrent/futures/thread.py", line 57, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/supervisor/supervisor/docker/multicast.py", line 50, in _run
    environment={ENV_TIME: self.sys_timezone},
  File "/usr/src/supervisor/supervisor/docker/__init__.py", line 127, in run
    f"{image}:{version}", use_config_proxy=False, **kwargs
  File "/usr/local/lib/python3.7/site-packages/docker/models/containers.py", line 861, in create
    resp = self.client.api.create_container(**create_kwargs)
  File "/usr/local/lib/python3.7/site-packages/docker/api/container.py", line 430, in create_container
    return self.create_container_from_config(config, name)
  File "/usr/local/lib/python3.7/site-packages/docker/api/container.py", line 440, in create_container_from_config
    res = self._post_json(u, data=config, params=params)
  File "/usr/local/lib/python3.7/site-packages/docker/api/client.py", line 289, in _post_json
    return self._post(url, data=json.dumps(data2), **kwargs)
  File "/usr/local/lib/python3.7/site-packages/docker/utils/decorators.py", line 46, in inner
    return f(self, *args, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/docker/api/client.py", line 226, in _post
    return self.post(url, **self._set_request_timeout(kwargs))
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 578, in post
    return self.request('POST', url, data=data, json=json, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 530, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/sessions.py", line 643, in send
    r = adapter.send(request, **kwargs)
  File "/usr/local/lib/python3.7/site-packages/requests/adapters.py", line 498, in send
    raise ConnectionError(err, request=request)
requests.exceptions.ConnectionError: [Errno 9] Bad file descriptor
20-06-01 14:40:17 INFO (MainThread) [supervisor.updater] Fetch update data from https://version.home-assistant.io/stable.json
20-06-01 14:40:18 INFO (SyncWorker_15) [supervisor.docker.interface] Attach to homeassistant/raspberrypi3-homeassistant with version 0.110.4
20-06-01 14:40:18 INFO (MainThread) [supervisor.utils.gdbus] Call org.freedesktop.DBus.Properties.GetAll on /
20-06-01 14:40:18 INFO (MainThread) [supervisor.hassos] Detect HassOS 4.8 / BootSlot A
20-06-01 14:40:26 INFO (MainThread) [supervisor.store.git] Load add-on /data/addons/core repository
20-06-01 14:40:26 INFO (MainThread) [supervisor.store.git] Load add-on /data/addons/git/a0d7b954 repository
20-06-01 14:40:27 INFO (MainThread) [supervisor.store] Load add-ons from store: 65 all - 65 new - 0 remove
20-06-01 14:40:27 INFO (MainThread) [supervisor.addons] Found 5 installed add-ons
20-06-01 14:40:27 INFO (SyncWorker_8) [supervisor.docker.interface] Attach to homeassistant/armv7-addon-check_config with version 3.3.0
20-06-01 14:40:27 INFO (SyncWorker_19) [supervisor.docker.interface] Attach to hassioaddons/adguard-armv7 with version 2.3.3
20-06-01 14:40:27 INFO (SyncWorker_13) [supervisor.docker.interface] Attach to homeassistant/armv7-addon-ssh with version 8.5.4
20-06-01 14:40:27 INFO (SyncWorker_11) [supervisor.docker.interface] Attach to hassioaddons/node-red-armv7 with version 6.3.0
20-06-01 14:40:27 INFO (SyncWorker_18) [supervisor.docker.interface] Attach to hassioaddons/unifi-armv7 with version 0.16.0
20-06-01 14:40:27 INFO (MainThread) [supervisor.snapshots] Found 5 snapshot files
20-06-01 14:40:27 INFO (MainThread) [supervisor.discovery] Load 0 messages
20-06-01 14:40:27 INFO (MainThread) [supervisor.ingress] Load 0 ingress session
20-06-01 14:40:27 INFO (MainThread) [supervisor.misc.secrets] Load Home Assistant secrets: 1
20-06-01 14:40:27 INFO (MainThread) [__main__] Run Supervisor
20-06-01 14:40:27 INFO (MainThread) [supervisor.api] Start API on 172.30.32.2
20-06-01 14:40:27 INFO (MainThread) [supervisor.utils.gdbus] Call de.pengutronix.rauc.Installer.Mark on /
20-06-01 14:40:27 INFO (MainThread) [supervisor.hassos] Rauc: A - marked slot kernel.0 as good
20-06-01 14:40:27 INFO (MainThread) [supervisor.addons] Phase 'initialize' start 0 add-ons
20-06-01 14:40:27 INFO (MainThread) [supervisor.addons] Phase 'system' start 0 add-ons
20-06-01 14:40:27 INFO (MainThread) [supervisor.addons] Phase 'services' start 2 add-ons
20-06-01 14:40:33 INFO (SyncWorker_1) [supervisor.docker.addon] Start Docker add-on homeassistant/armv7-addon-ssh with version 8.5.4
20-06-01 14:40:34 INFO (SyncWorker_6) [supervisor.docker.addon] Start Docker add-on hassioaddons/unifi-armv7 with version 0.16.0
20-06-01 14:40:40 INFO (SyncWorker_0) [supervisor.docker.interface] Start homeassistant/raspberrypi3-homeassistant
20-06-01 14:40:43 INFO (MainThread) [supervisor.api.security] /host/info access from a0d7b954_unifi
20-06-01 14:42:38 INFO (MainThread) [supervisor.homeassistant] Detect a running Home Assistant instance
20-06-01 14:42:38 INFO (MainThread) [supervisor.addons] Phase 'application' start 1 add-ons
20-06-01 14:42:58 INFO (SyncWorker_12) [supervisor.docker.addon] Start Docker add-on hassioaddons/node-red-armv7 with version 6.3.0
20-06-01 14:43:05 INFO (MainThread) [supervisor.misc.tasks] All core tasks are scheduled
20-06-01 14:43:05 INFO (MainThread) [supervisor.misc.hwmon] Started Supervisor hardware monitor
20-06-01 14:43:05 INFO (MainThread) [supervisor.core] Supervisor is up and running
20-06-01 14:43:05 INFO (MainThread) [supervisor.host.info] Update local host information
20-06-01 14:43:05 INFO (MainThread) [supervisor.utils.gdbus] Call org.freedesktop.DBus.Properties.GetAll on /org/freedesktop/hostname1
20-06-01 14:43:05 INFO (MainThread) [supervisor.updater] Fetch update data from https://version.home-assistant.io/stable.json
20-06-01 14:43:06 INFO (MainThread) [supervisor.api.security] /host/info access from a0d7b954_nodered
20-06-01 14:43:07 INFO (MainThread) [supervisor.host.services] Update service information
20-06-01 14:43:07 INFO (MainThread) [supervisor.utils.gdbus] Call org.freedesktop.systemd1.Manager.ListUnits on /org/freedesktop/systemd1
20-06-01 14:43:07 INFO (MainThread) [supervisor.host.network] Update local network DNS information
20-06-01 14:43:07 INFO (MainThread) [supervisor.utils.gdbus] Call org.freedesktop.DBus.Properties.GetAll on /org/freedesktop/NetworkManager/DnsManager
20-06-01 14:43:07 INFO (MainThread) [supervisor.host.sound] Update PulseAudio information
20-06-01 14:43:19 INFO (MainThread) [supervisor.api.security] /dns/info access from a0d7b954_nodered
20-06-01 14:43:55 WARNING (MainThread) [supervisor.misc.tasks] Watchdog found a problem with Multicast plugin!
20-06-01 14:43:55 INFO (MainThread) [supervisor.plugins.multicast] Start Multicast plugin
20-06-01 14:44:24 INFO (SyncWorker_0) [supervisor.docker.multicast] Start Multicast homeassistant/armv7-hassio-multicast with version 2 - Host
20-06-01 14:45:30 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request initialize
20-06-01 14:45:30 INFO (MainThread) [supervisor.api.proxy] WebSocket access from a0d7b954_nodered
20-06-01 14:45:30 INFO (MainThread) [supervisor.homeassistant] Updated Home Assistant API token
20-06-01 14:45:30 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running

Multicast logs

data from=172.30.32.3 size=45
repeating data to eth0
data from=10.0.0.7 size=201
repeating data to hassio
data from=172.30.32.3 size=44
repeating data to eth0
data from=172.30.32.3 size=44
repeating data to eth0
data from=172.17.0.1 size=227
repeating data to eth0
repeating data to hassio
data from=127.0.0.1 size=227
repeating data to eth0
repeating data to hassio
data from=172.17.0.1 size=227
repeating data to eth0
repeating data to hassio
data from=127.0.0.1 size=227
repeating data to eth0
repeating data to hassio
data from=172.17.0.1 size=227
repeating data to eth0
repeating data to hassio
data from=127.0.0.1 size=227
repeating data to eth0
repeating data to hassio
data from=172.17.0.1 size=227
repeating data to eth0
repeating data to hassio
data from=127.0.0.1 size=227
repeating data to eth0
repeating data to hassio
data from=172.17.0.1 size=40
repeating data to eth0
repeating data to hassio
data from=127.0.0.1 size=40
repeating data to eth0
repeating data to hassio
data from=10.0.0.12 size=30
repeating data to hassio
data from=172.17.0.1 size=40
repeating data to eth0
repeating data to hassio
data from=127.0.0.1 size=40
repeating data to eth0
repeating data to hassio
data from=10.0.0.12 size=30
repeating data to hassio
data from=10.0.0.12 size=30
repeating data to hassio
data from=10.0.0.12 size=30
repeating data to hassio
data from=10.0.0.12 size=30
repeating data to hassio
data from=172.30.32.3 size=46
repeating data to eth0
data from=172.30.32.3 size=46
repeating data to eth0
data from=10.0.0.7 size=116
repeating data to hassio
data from=172.17.0.1 size=75
repeating data to eth0
repeating data to hassio
data from=127.0.0.1 size=75
repeating data to eth0
repeating data to hassio
data from=172.17.0.1 size=75
repeating data to eth0
repeating data to hassio
data from=127.0.0.1 size=75
repeating data to eth0
repeating data to hassio
data from=172.17.0.1 size=75
repeating data to eth0
repeating data to hassio
data from=127.0.0.1 size=75
repeating data to eth0
repeating data to hassio
data from=172.17.0.1 size=75
repeating data to eth0
repeating data to hassio
data from=127.0.0.1 size=75
repeating data to eth0
repeating data to hassio
data from=172.30.32.3 size=34
repeating data to eth0
data from=172.30.32.3 size=34
repeating data to eth0
data from=10.0.0.7 size=141
repeating data to hassio
data from=172.30.32.3 size=34
repeating data to eth0
data from=172.30.32.3 size=34
repeating data to eth0
data from=10.0.0.7 size=300
repeating data to hassio
data from=172.30.32.3 size=45
repeating data to eth0
data from=172.30.32.3 size=45
repeating data to eth0

Description of problem: Saw this logs after updating to the latest version.

stale[bot] commented 4 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.