{"action":"created","issue":{"url":"https://api.github.com/repos/home-assistant/home-assistant/issues/17511","repository_url":"https://api.github.com/repos/home-assistant/home-assistant","labels_url":"https://api.github.com/repos/home-assistant/home-assistant/issues/17511/labels{/name}","comments_url":"https://api.github.com/repos/home-assistant/home-assistant/issues/17511/comments","events_url":"https://api.github.com/repos/home-assistant/home-assistant/issues/17511/events","html_url":"https://github.com/home-assistant/home-assistant/issues/17511","id":370511195,"node_id":"MDU6SXNzdWUzNzA1MTExOTU=","number":17511,"title":"Sensors stop working with `bad file descriptor`, process dumps core or hangs","user":{"login":"lbschenkel","id":1428661,"node_id":"MDQ6VXNlcjE0Mjg2NjE=","avatar_url":"https://avatars1.githubusercontent.com/u/1428661?v=4","gravatar_id":"","url":"https://api.github.com/users/lbschenkel","html_url":"https://github.com/lbschenkel","followers_url":"https://api.github.com/users/lbschenkel/followers","following_url":"https://api.github.com/users/lbschenkel/following{/other_user}","gists_url":"https://api.github.com/users/lbschenkel/gists{/gist_id}","starred_url":"https://api.github.com/users/lbschenkel/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/lbschenkel/subscriptions","organizations_url":"https://api.github.com/users/lbschenkel/orgs","repos_url":"https://api.github.com/users/lbschenkel/repos","events_url":"https://api.github.com/users/lbschenkel/events{/privacy}","received_events_url":"https://api.github.com/users/lbschenkel/received_events","type":"User","site_admin":false},"labels":[],"state":"open","locked":false,"assignee":null,"assignees":[],"milestone":null,"comments":1,"created_at":"2018-10-16T09:07:48Z","updated_at":"2018-10-16T12:19:54Z","closed_at":null,"author_association":"CONTRIBUTOR","body":"<!-- READ THIS FIRST:\r\n- If you need additional help with this template please refer to https://www.home-assistant.io/help/reporting_issues/\r\n- Make sure you are running the latest version of Home Assistant before reporting an issue: https://github.com/home-assistant/home-assistant/releases\r\n- Do not report issues for components if you are using custom components: files in <config-dir>/custom_components\r\n- This is for bugs only. Feature and enhancement requests should go in our community forum: https://community.home-assistant.io/c/feature-requests\r\n- Provide as many details as possible. Paste logs, configuration sample and code into the backticks. Do not delete any text from this template!\r\n-->\r\n\r\n**Home Assistant release with the issue:**\r\n<!--\r\n- Frontend -> Developer tools -> Info\r\n- Or use this command: hass --version\r\n-->\r\n0.80.1 \r\n\r\n**Last working Home Assistant release (if known):**\r\n\r\n0.79.x, but not completely sure (see below)\r\n\r\n**Operating environment (Hass.io/Docker/Windows/etc.):**\r\n<!--\r\nPlease provide details about your environment.\r\n-->\r\nHass.io containers running on Docker 18.06.1-ce on Debian 9.5/Proxmox kernel:\r\n```\r\nLinux pve 4.15.18-7-pve #1 SMP PVE 4.15.18-26 (Thu, 04 Oct 2018 11:03:06 +0200) x86_64 GNU/Linux\r\n```\r\nMachine is a Core i5 with 16 GB of RAM, lightly loaded (~0.2 load), with < 50% memory usage.\r\n\r\n**Component/platform:**\r\n<!--\r\nPlease add the link to the documentation at https://www.home-assistant.io/components/ of the component/platform in question.\r\n-->\r\nThese start failing:\r\n- https://www.home-assistant.io/components/binary_sensor.ping/\r\n- https://www.home-assistant.io/components/device_tracker.nmap_tracker/\r\n\r\nThen sometimes others follow.\r\n\r\n**Description of problem:**\r\n\r\n*Problem 1*\r\n\r\nSensors stop working after a while, from minutes to hours. When this happens I start seeing `Bad file descriptor` errors (tracebacks below). Then I start seeing periodic logging of `took longer than the scheduled update interval` for the sensor, and no further sensor updates. Sometimes the `bad file descriptor` error gets logged again, and sometimes only `took longer than` keeps being logged.\r\n\r\nMaybe it's a coincidence, but what all these sensors have in common is that they periodically invoke external processes.\r\n\r\n*Problem 2*\r\n\r\nOnce problem 1 start occurring, if I keep the server running for many hours I have seen two different outcomes:\r\n1. the Python process dumps core (core file is written to config directory) and the container gets automatically restarted by the Hass.io supervisor -- this is the most common\r\n2. other I/O eventually starts failing, some other sensors that hit the network start failing, at some point even the HTTP server stops serving requests (requests hang until they timeout), I need to manually restart the container -- It looks like more and more threads get 'stuck' until there's none left\r\n\r\nHASS usually does not survive for 24h before either of the above happens.\r\n\r\n*Problem 3*\r\n\r\nSometimes Home Assistant hangs when starting. It logs `Updating ping sensor took longer than the scheduled update interval` and does not proceed, nor it responds to HTTP requests. I need to manually restart the container in order to have a successful startup. (The `bad file descriptor` error is not logged in this scenario.)\r\n\r\n**Problem-relevant `configuration.yaml` entries and (fill out even if it seems unimportant):**\r\n```yaml\r\n\r\ndevice_tracker:\r\n  # tried to change to a ping tracker, same symptoms:\r\n  - platform: nmap_tracker\r\n    scan_options: '-sn'\r\n    hosts:\r\n      - host1\r\n      - host2\r\n      - host3\r\n    home_interval: 1\r\n    interval_seconds: 10\r\n    consider_home: 120\r\n\r\nbinary_sensor:\r\n  # about 20 of these:\r\n  - platform: ping\r\n    host: host\r\n```\r\n\r\n**Traceback (if applicable):**\r\n\r\nWhen `ping` sensor starts failing:\r\n```\r\n2018-10-16 09:01:23 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport ReadUnixTransport (error status in uv_stream_t.read callback)\r\nOSError: [Errno 9] Bad file descriptor\r\n2018-10-16 09:01:23 ERROR (MainThread) [homeassistant.helpers.entity] Update for binary_sensor.nas fails\r\nTraceback (most recent call last):\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/helpers/entity.py\", line 221, in async_update_ha_state\r\n    await self.async_device_update()\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/helpers/entity.py\", line 347, in async_device_update\r\n    await self.async_update()\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/components/binary_sensor/ping.py\", line 98, in async_update\r\n    await self.ping.update()\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/components/binary_sensor/ping.py\", line 158, in update\r\n    self.data = await self.ping()\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/components/binary_sensor/ping.py\", line 125, in ping\r\n    out = await pinger.communicate()\r\n  File \"/usr/local/lib/python3.6/asyncio/subprocess.py\", line 195, in communicate\r\n    loop=self._loop)\r\n  File \"/usr/local/lib/python3.6/asyncio/subprocess.py\", line 173, in _read_stream\r\n    output = yield from stream.read()\r\n  File \"/usr/local/lib/python3.6/asyncio/streams.py\", line 627, in read\r\n    block = yield from self.read(self._limit)\r\n  File \"/usr/local/lib/python3.6/asyncio/streams.py\", line 634, in read\r\n    yield from self._wait_for_data('read')\r\n  File \"/usr/local/lib/python3.6/asyncio/streams.py\", line 464, in _wait_for_data\r\n    yield from self._waiter\r\nOSError: [Errno 9] Bad file descriptor\r\n```\r\nWhen `nmap` tracker starts failing:\r\n```\r\n018-10-16 09:10:31 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved\r\nTraceback (most recent call last):\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/__init__.py\", line 692, in async_device_tracker_scan\r\n    found_devices = await scanner.async_scan_devices()\r\n  File \"/usr/local/lib/python3.6/concurrent/futures/thread.py\", line 56, in run\r\n    result = self.fn(*self.args, **self.kwargs)\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/nmap_tracker.py\", line 81, in scan_devices\r\n    self._update_info()\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/components/device_tracker/nmap_tracker.py\", line 132, in _update_info\r\n    arguments=options)\r\n  File \"/usr/local/lib/python3.6/site-packages/nmap/nmap.py\", line 235, in scan\r\n    (self._nmap_last_output, nmap_err) = p.communicate()\r\n  File \"/usr/local/lib/python3.6/subprocess.py\", line 843, in communicate\r\n    stdout, stderr = self._communicate(input, endtime, timeout)\r\n  File \"/usr/local/lib/python3.6/subprocess.py\", line 1534, in _communicate\r\n    data = os.read(key.fd, 32768)\r\nOSError: [Errno 9] Bad file descriptor\r\n```\r\n\r\nWhen eventually other sensors start failing (always after ping and nmap start misbehaving):\r\n```\r\n2018-10-16 09:11:50 ERROR (SyncWorker_4) [homeassistant.components.media_player.plex] Could not connect to plex server at http://redacted:32400 ([Errno 9] Bad file descriptor)\r\n2018-10-16 09:12:03 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved\r\nTraceback (most recent call last):\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/components/discovery.py\", line 169, in scan_devices\r\n    results = await hass.async_add_job(_discover, netdisco)\r\n  File \"/usr/local/lib/python3.6/concurrent/futures/thread.py\", line 56, in run\r\n    result = self.fn(*self.args, **self.kwargs)\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/components/discovery.py\", line 195, in _discover\r\n    netdisco.scan()\r\n  File \"/usr/local/lib/python3.6/site-packages/netdisco/discovery.py\", line 54, in scan\r\n    self.mdns.start()\r\n  File \"/usr/local/lib/python3.6/site-packages/netdisco/mdns.py\", line 21, in start\r\n    self.zeroconf = zeroconf.Zeroconf()\r\n  File \"/usr/local/lib/python3.6/site-packages/zeroconf.py\", line 1734, in __init__\r\n    socket.IPPROTO_IP, socket.IP_ADD_MEMBERSHIP, _value)\r\nOSError: [Errno 9] Bad file descriptor\r\n```\r\nAlthough they don't fail with the same errors, it's suspicious that those start failing always after the `bad file descriptor` errors start occurring. I never saw them failing during \"normal\" operation:\r\n```\r\n2018-10-16 10:28:12 ERROR (SyncWorker_4) [homeassistant.components.sensor.rest] Error fetching data: <PreparedRequest [GET]> from https://redacted failed with HTTPSConnectionPool(host='redacted', port=443): Max retries exceeded with url: /redacted (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x7f63e3892828>: Failed to establish a new connection: [Errno -3] Try again',))\r\n2018-10-16 10:28:12 ERROR (MainThread) [homeassistant.helpers.entity] Update for sensor.redacted fails\r\nTraceback (most recent call last):\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/helpers/entity.py\", line 221, in async_update_ha_state\r\n    await self.async_device_update()\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/helpers/entity.py\", line 349, in async_device_update\r\n    await self.hass.async_add_job(self.update)\r\n  File \"/usr/local/lib/python3.6/concurrent/futures/thread.py\", line 56, in run\r\n    result = self.fn(*self.args, **self.kwargs)\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/components/sensor/scrape.py\", line 117, in update\r\n    raw_data = BeautifulSoup(self.rest.data, 'html.parser')\r\n  File \"/usr/local/lib/python3.6/site-packages/bs4/__init__.py\", line 246, in __init__\r\n    elif len(markup) <= 256 and (\r\nTypeError: object of type 'NoneType' has no len()\r\n```\r\n\r\n**Additional information:**\r\n\r\nI have been running HASS in this same machine with this same config for months without any problem. I started experiencing these issues after I recently added a lot of new ping sensors *and* at the same time 0.80.0 was released, so it's unclear if the same problems would have occurred or be as serious with 0.79.x. It's not impossible that this was happening on a lesser degree before but I have never noticed -- unfortunately the logs have been rolled over and I cannot check.\r\n\r\nThis instability is happening only on the HASS container. No other process or container running in this same machine is affected. To make sure I'm not running out of file descriptors, I have set them to `unlimited` in `/etc/security/limits.conf` and confirmed both in the machine and inside the container that both the soft and hard limits are set to `1048576`.\r\n\r\nI have tried to generate a backtrace of the HASS Python process inside the container to get more insight, however the `gdb` shipped with Alpine Linux does not have Python support and I can only generate native backtraces, which are not very helpful.\r\n\r\nI also have the core dump files, but I'm not willing to share it since the memory dump will contain secrets. But if somebody can direct me to which commands I should run to further diagnose it, I can copy and paste the output here.\r\n\r\nI'm a technical person and a developer (not a Python expert, though), so I'm willing to do anything at my disposal to get to the bottom of this. These issues caused my HASS setup to became unusable. Please let me know what are the possible next steps that I can take to shed more light into this and help getting it fixed.\r\n\r\nSimilar issues that could be related:\r\n- https://github.com/home-assistant/home-assistant/issues/16986\r\n- https://github.com/home-assistant/home-assistant/issues/16930"},"comment":{"url":"https://api.github.com/repos/home-assistant/home-assistant/issues/comments/430215573","html_url":"https://github.com/home-assistant/home-assistant/issues/17511#issuecomment-430215573","issue_url":"https://api.github.com/repos/home-assistant/home-assistant/issues/17511","id":430215573,"node_id":"MDEyOklzc3VlQ29tbWVudDQzMDIxNTU3Mw==","user":{"login":"Mariusthvdb","id":33354141,"node_id":"MDQ6VXNlcjMzMzU0MTQx","avatar_url":"https://avatars1.githubusercontent.com/u/33354141?v=4","gravatar_id":"","url":"https://api.github.com/users/Mariusthvdb","html_url":"https://github.com/Mariusthvdb","followers_url":"https://api.github.com/users/Mariusthvdb/followers","following_url":"https://api.github.com/users/Mariusthvdb/following{/other_user}","gists_url":"https://api.github.com/users/Mariusthvdb/gists{/gist_id}","starred_url":"https://api.github.com/users/Mariusthvdb/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/Mariusthvdb/subscriptions","organizations_url":"https://api.github.com/users/Mariusthvdb/orgs","repos_url":"https://api.github.com/users/Mariusthvdb/repos","events_url":"https://api.github.com/users/Mariusthvdb/events{/privacy}","received_events_url":"https://api.github.com/users/Mariusthvdb/received_events","type":"User","site_admin":false},"created_at":"2018-10-16T12:19:54Z","updated_at":"2018-10-16T12:19:54Z","author_association":"NONE","body":"and spotify on 0.80.0:\r\n\r\nsee:https://community.home-assistant.io/t/spotify-bad-file-descriptor-ssl-issue-since-ha-0-80-0/72688\r\n\r\nhave specific ssl errors, though spotify isn't playing at all, an I can connect to the spotify developers api page without issue.\r\n\r\n`requests.exceptions.SSLError: HTTPSConnectionPool(host='api.spotify.com', port=443): Max retries exceeded with url: /v1/me/player/devices (Caused by SSLError(OSError(9, 'Bad file descriptor'),))`\r\n\r\n```\r\n2018-10-15 17:50:00 ERROR (MainThread) [homeassistant.helpers.entity] Update for media_player.spotify fails\r\nTraceback (most recent call last):\r\n  File \"/usr/local/lib/python3.6/site-packages/urllib3/connectionpool.py\", line 600, in urlopen\r\n    chunked=chunked)\r\n  File \"/usr/local/lib/python3.6/site-packages/urllib3/connectionpool.py\", line 343, in _make_request\r\n    self._validate_conn(conn)\r\n  File \"/usr/local/lib/python3.6/site-packages/urllib3/connectionpool.py\", line 849, in _validate_conn\r\n    conn.connect()\r\n  File \"/usr/local/lib/python3.6/site-packages/urllib3/connection.py\", line 356, in connect\r\n    ssl_context=context)\r\n  File \"/usr/local/lib/python3.6/site-packages/urllib3/util/ssl_.py\", line 359, in ssl_wrap_socket\r\n    return context.wrap_socket(sock, server_hostname=server_hostname)\r\n  File \"/usr/local/lib/python3.6/ssl.py\", line 407, in wrap_socket\r\n    _context=self, _session=session)\r\n  File \"/usr/local/lib/python3.6/ssl.py\", line 814, in __init__\r\n    self.do_handshake()\r\n  File \"/usr/local/lib/python3.6/ssl.py\", line 1068, in do_handshake\r\n    self._sslobj.do_handshake()\r\n  File \"/usr/local/lib/python3.6/ssl.py\", line 689, in do_handshake\r\n    self._sslobj.do_handshake()\r\nssl.SSLError: [SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed (_ssl.c:841)\r\n\r\nDuring handling of the above exception, another exception occurred:\r\n\r\nTraceback (most recent call last):\r\n  File \"/usr/local/lib/python3.6/site-packages/requests/adapters.py\", line 445, in send\r\n    timeout=timeout\r\n  File \"/usr/local/lib/python3.6/site-packages/urllib3/connectionpool.py\", line 638, in urlopen\r\n    _stacktrace=sys.exc_info()[2])\r\n  File \"/usr/local/lib/python3.6/site-packages/urllib3/util/retry.py\", line 398, in increment\r\n    raise MaxRetryError(_pool, url, error or ResponseError(cause))\r\nurllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='api.spotify.com', port=443): Max retries exceeded with url: /v1/me/player/devices (Caused by SSLError(SSLError(1, '[SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed (_ssl.c:841)'),))\r\n\r\nDuring handling of the above exception, another exception occurred:\r\n\r\nTraceback (most recent call last):\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/helpers/entity.py\", line 221, in async_update_ha_state\r\n    await self.async_device_update()\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/helpers/entity.py\", line 349, in async_device_update\r\n    await self.hass.async_add_job(self.update)\r\n  File \"/usr/local/lib/python3.6/concurrent/futures/thread.py\", line 56, in run\r\n    result = self.fn(*self.args, **self.kwargs)\r\n  File \"/usr/local/lib/python3.6/site-packages/homeassistant/components/media_player/spotify.py\", line 176, in update\r\n    player_devices = self._player.devices()\r\n  File \"/usr/local/lib/python3.6/site-packages/spotipy/client.py\", line 848, in devices\r\n    return self._get(\"me/player/devices\")\r\n  File \"/usr/local/lib/python3.6/site-packages/spotipy/client.py\", line 148, in _get\r\n    return self._internal_call('GET', url, payload, kwargs)\r\n  File \"/usr/local/lib/python3.6/site-packages/spotipy/client.py\", line 110, in _internal_call\r\n    r = self._session.request(method, url, headers=headers, proxies=self.proxies, **args)\r\n  File \"/usr/local/lib/python3.6/site-packages/requests/sessions.py\", line 512, in request\r\n    resp = self.send(prep, **send_kwargs)\r\n  File \"/usr/local/lib/python3.6/site-packages/requests/sessions.py\", line 622, in send\r\n    r = adapter.send(request, **kwargs)\r\n  File \"/usr/local/lib/python3.6/site-packages/requests/adapters.py\", line 511, in send\r\n    raise SSLError(e, request=request)\r\nrequests.exceptions.SSLError: HTTPSConnectionPool(host='api.spotify.com', port=443): Max retries exceeded with url: /v1/me/player/devices (Caused by SSLError(SSLError(1, '[SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed (_ssl.c:841)'),))\r\n```\r\n\r\nproblems 1 to 3  described are all recognized and experienced in this setup."}}
{"actor":{"display_login":"Mariusthvdb"}}