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

Zha - bellows - Errors in the logs #10993

Closed
sumitrajancse opened this issue Dec 6, 2017 · 5 comments
Closed

Zha - bellows - Errors in the logs #10993

sumitrajancse opened this issue Dec 6, 2017 · 5 comments

Comments

@sumitrajancse
Copy link

sumitrajancse commented Dec 6, 2017 •
edited by MartinHjelmare
Loading

I have following zigbee devices:

Nortek USB stick with Zwave and zigbee protocol.
1 Osram lightify RBGW buld
2 sengled tunable white light bulbs.
3 cree connected bulbs

List of errors in the logs and after sometimes not able to control zigbee devices until home assistant is restarted. The light stop to respond to the home assistant and when i verify the logs found following error.
It is full of error.

2017-11-08 05:04:16 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 05:04:55 WARNING (MainThread) [homeassistant.components.light] Setup of platform flux_led is taking over 10 seconds.
2017-11-08 05:05:04 WARNING (SyncWorker_0) [homeassistant.components.light.flux_led] Failed to connect to bulb 192.168.1.25, Cooking Light
2017-11-08 05:05:07 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 05:05:07 WARNING (MainThread) [bellows.zigbee.application] Unexpected response TSN=11 command=1 args=[[]]
2017-11-08 05:05:23 WARNING (SyncWorker_10) [netdisco.ssdp] Error fetching description at http://192.168.0.254:49152/wps_device.xml
2017-11-08 05:06:24 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 05:13:12 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 05:14:18 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 05:23:14 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 05:24:20 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 05:26:44 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 05:29:37 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 05:33:17 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 05:34:23 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 05:40:21 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 05:43:20 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 05:44:25 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 05:53:22 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 05:54:28 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:03:25 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:04:30 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:06:11 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:13:27 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:14:33 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:23:30 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:24:35 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:26:45 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:29:23 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:33:33 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:34:38 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:40:14 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:43:35 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:44:40 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:53:39 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:54:43 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 06:54:48 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/aiohttp/web_protocol.py", line 278, in data_received
    messages, upgraded, tail = self._request_parser.feed_data(data)
  File "aiohttp/_http_parser.pyx", line 274, in aiohttp._http_parser.HttpParser.feed_data
aiohttp.http_exceptions.BadStatusLine: invalid HTTP method
2017-11-08 06:55:18 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/aiohttp/web_protocol.py", line 278, in data_received
    messages, upgraded, tail = self._request_parser.feed_data(data)
  File "aiohttp/_http_parser.pyx", line 274, in aiohttp._http_parser.HttpParser.feed_data
aiohttp.http_exceptions.BadStatusLine: invalid HTTP method
2017-11-08 07:00:42 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2017-11-08 07:03:43 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 07:04:45 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 07:05:51 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 07:13:49 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 07:14:48 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 07:23:56 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 07:24:51 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 07:26:45 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 07:28:58 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 07:32:10 ERROR (MainThread) [aiohttp.access] Error in logging
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/aiohttp/helpers.py", line 500, in log
    for key, value in fmt_info:
  File "/usr/lib/python3.6/site-packages/aiohttp/helpers.py", line 483, in return
    ((key, method(args)) for key, method in self._methods)
  File "/usr/lib/python3.6/site-packages/aiohttp/helpers.py", line 436, in _format_a
    peername = args[3].get_extra_info('peername')
  File "/usr/lib/python3.6/asyncio/sslproto.py", line 306, in get_extra_info
    return self._ssl_protocol._get_extra_info(name, default)
  File "/usr/lib/python3.6/asyncio/sslproto.py", line 547, in _get_extra_info
    return self._transport.get_extra_info(name, default)
AttributeError: 'NoneType' object has no attribute 'get_extra_info'
2017-11-08 07:34:01 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 07:34:54 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 07:39:47 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 07:40:08 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 07:44:06 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 07:44:57 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 07:54:10 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 07:55:00 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:04:14 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:05:03 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:05:15 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:14:17 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:15:06 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:24:21 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:25:08 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:26:46 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:28:29 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:34:24 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:35:11 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:40:00 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:44:27 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:45:13 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:54:30 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:55:16 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 08:56:43 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 08:56:43 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 08:56:43 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 08:56:43 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 08:56:43 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 08:57:48 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 08:59:34 WARNING (MainThread) [bellows.zigbee.application] Unexpected response TSN=88 command=11 args=[0, <Status.SUCCESS: 0>]
2017-11-08 09:00:55 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2017-11-08 09:04:33 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 09:04:39 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 09:05:18 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 09:14:35 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 09:15:21 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 09:16:23 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 09:16:33 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 09:16:58 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 09:17:01 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 09:17:32 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 09:17:34 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 09:17:58 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 09:24:38 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 09:25:24 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 09:26:46 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 09:28:03 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 09:28:15 ERROR (MainThread) [aiohttp.access] Error in logging
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/aiohttp/helpers.py", line 500, in log
    for key, value in fmt_info:
  File "/usr/lib/python3.6/site-packages/aiohttp/helpers.py", line 483, in return
    ((key, method(args)) for key, method in self._methods)
  File "/usr/lib/python3.6/site-packages/aiohttp/helpers.py", line 436, in _format_a
    peername = args[3].get_extra_info('peername')
  File "/usr/lib/python3.6/asyncio/sslproto.py", line 306, in get_extra_info
    return self._ssl_protocol._get_extra_info(name, default)
  File "/usr/lib/python3.6/asyncio/sslproto.py", line 547, in _get_extra_info
  return self._transport.get_extra_info(name, default)
AttributeError: 'NoneType' object has no attribute 'get_extra_info'
2017-11-08 09:28:24 ERROR (MainThread) [aiohttp.access] Error in logging
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/aiohttp/helpers.py", line 500, in log
    for key, value in fmt_info:
  File "/usr/lib/python3.6/site-packages/aiohttp/helpers.py", line 483, in return
    ((key, method(args)) for key, method in self._methods)
  File "/usr/lib/python3.6/site-packages/aiohttp/helpers.py", line 436, in _format_a
    peername = args[3].get_extra_info('peername')
  File "/usr/lib/python3.6/asyncio/sslproto.py", line 306, in get_extra_info
    return self._ssl_protocol._get_extra_info(name, default)
  File "/usr/lib/python3.6/asyncio/sslproto.py", line 547, in _get_extra_info
    return self._transport.get_extra_info(name, default)
AttributeError: 'NoneType' object has no attribute 'get_extra_info'
2017-11-08 09:34:41 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 09:35:26 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 09:39:53 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 09:44:44 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 09:45:28 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 09:47:55 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 09:47:55 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 09:47:55 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 09:48:41 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 09:48:54 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 09:48:54 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 09:48:57 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 09:52:48 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 09:54:46 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 09:55:31 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:00:26 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2017-11-08 10:00:43 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2017-11-08 10:00:43 WARNING (MainThread) [homeassistant.helpers.entity] Update of light.cooking_light is taking over 10 seconds
2017-11-08 10:04:24 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:04:49 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:05:34 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:14:52 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:15:36 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:24:54 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:25:39 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:26:08 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 10:26:47 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:27:40 ERROR (MainThread) [aiohttp.access] Error in logging
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/aiohttp/helpers.py", line 500, in log
    for key, value in fmt_info:
  File "/usr/lib/python3.6/site-packages/aiohttp/helpers.py", line 483, in return
    ((key, method(args)) for key, method in self._methods)
  File "/usr/lib/python3.6/site-packages/aiohttp/helpers.py", line 436, in _format_a
    peername = args[3].get_extra_info('peername')
  File "/usr/lib/python3.6/asyncio/sslproto.py", line 306, in get_extra_info
    return self._ssl_protocol._get_extra_info(name, default)
  File "/usr/lib/python3.6/asyncio/sslproto.py", line 547, in _get_extra_info
    return self._transport.get_extra_info(name, default)
AttributeError: 'NoneType' object has no attribute 'get_extra_info'
2017-11-08 10:27:49 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:34:57 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:35:28 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 10:35:41 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:39:46 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:42:31 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 10:43:19 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 10:45:00 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:45:44 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:55:03 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 10:55:46 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:04:11 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:05:05 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:05:49 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:05:50 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 11:05:55 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 11:05:58 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 11:15:08 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:15:51 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:25:10 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:25:54 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:26:47 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:27:35 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:35:13 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:35:56 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:39:40 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:39:52 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 11:39:52 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 11:39:52 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 11:39:52 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 11:40:48 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 11:40:48 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 11:40:52 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 11:45:16 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:45:59 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:55:18 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 11:56:01 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:00:24 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 12:00:56 ERROR (MainThread) [homeassistant.core] Timer got out of sync. Resetting
2017-11-08 12:03:52 ERROR (MainThread) [aiohttp.access] Error in logging
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/aiohttp/helpers.py", line 500, in log
    for key, value in fmt_info:
  File "/usr/lib/python3.6/site-packages/aiohttp/helpers.py", line 483, in return
    ((key, method(args)) for key, method in self._methods)
  File "/usr/lib/python3.6/site-packages/aiohttp/helpers.py", line 436, in _format_a
    peername = args[3].get_extra_info('peername')
  File "/usr/lib/python3.6/asyncio/sslproto.py", line 306, in get_extra_info
    return self._ssl_protocol._get_extra_info(name, default)
  File "/usr/lib/python3.6/asyncio/sslproto.py", line 547, in _get_extra_info
    return self._transport.get_extra_info(name, default)
AttributeError: 'NoneType' object has no attribute 'get_extra_info'
2017-11-08 12:03:57 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:05:21 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:06:04 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:15:24 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:16:06 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:20:28 ERROR (MainThread) [homeassistant.core] Error doing job: Fatal error on transport TCPTransport (error status in uv_stream_t.read callback)
TimeoutError: [Errno 110] Operation timed out
2017-11-08 12:25:26 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:26:09 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:26:48 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:27:21 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:35:29 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:36:11 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:39:33 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:41:51 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.6/asyncio/tasks.py", line 179, in _step
    result = coro.send(None)
  File "/usr/lib/python3.6/site-packages/homeassistant/core.py", line 1038, in _event_to_service_call
    yield from service_handler.func(service_call)
  File "/usr/lib/python3.6/site-packages/homeassistant/components/light/init.py", line 282, in async_handle_light_service
    yield from light.async_turn_off(**params)
  File "/usr/lib/python3.6/site-packages/homeassistant/components/light/zha.py", line 118, in async_turn_off
    yield from self._endpoint.on_off.off()
  File "/usr/lib/python3.6/site-packages/bellows/zigbee/application.py", line 286, in request
    v = yield from asyncio.wait_for(reply_fut, timeout)
  File "/usr/lib/python3.6/asyncio/tasks.py", line 356, in wait_for
    raise futures.TimeoutError()
concurrent.futures._base.TimeoutError
2017-11-08 12:42:21 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.6/asyncio/tasks.py", line 181, in _step
    result = coro.throw(exc)
  File "/usr/lib/python3.6/site-packages/homeassistant/core.py", line 1038, in _event_to_service_call
    yield from service_handler.func(service_call)
  File "/usr/lib/python3.6/site-packages/homeassistant/components/light/init.py", line 282, in async_handle_light_service
    yield from light.async_turn_off(**params)
  File "/usr/lib/python3.6/site-packages/homeassistant/components/light/zha.py", line 118, in async_turn_off
    yield from self._endpoint.on_off.off()
  File "/usr/lib/python3.6/site-packages/bellows/zigbee/application.py", line 284, in request
    v = yield from send_fut
  File "/usr/lib/python3.6/asyncio/futures.py", line 331, in iter
    yield self # This tells Task to wait for completion.
  File "/usr/lib/python3.6/asyncio/tasks.py", line 244, in _wakeup
    future.result()
  File "/usr/lib/python3.6/asyncio/futures.py", line 244, in result
    raise self._exception
bellows.zigbee.exceptions.DeliveryError: Message send failure: EmberStatus.DELIVERY_FAILED
2017-11-08 12:45:32 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:46:14 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:48:41 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:55:34 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
2017-11-08 12:55:52 WARNING (SyncWorker_15) [netdisco.ssdp] Found malformed XML at http://192.168.1.19:9080: status=ok
2017-11-08 12:56:16 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification
@MartinHjelmare MartinHjelmare changed the title bellows.zigbee.application . List of errors in the logs and after sometimes not able to control zigbee devices until home assistant is restarted. Zha - bellows - Errors in the logs Dec 6, 2017
@MartinHjelmare
Copy link
Member

MartinHjelmare commented Dec 6, 2017 •
edited
Loading

Please update the issue and fill out the issue template that was present when you opened the issue. You can read it again here:
https://github.com/home-assistant/home-assistant/blob/dev/.github/ISSUE_TEMPLATE.md

And please keep the format of your log next time.

@dshokouhi
Copy link
Member

this is identical to #10973 can we maybe merge that information over and use that bug?

@dshokouhi
Copy link
Member

@MartinHjelmare I would add the logs that @sumitrajancse has provided here to my bug however in my case the logs just stop generating. The logs in this ticket are very similar to the logs I have seen however once this issue occurs they just stop. I don't even get an error when I try to control the device, almost as if the component just stops working. Turning on debugging also does not provide anything in addition.

2017-11-08 12:56:16 WARNING (MainThread) [bellows.zigbee.application] Unexpected message send notification

This is always the last log I see, usually in the middle of the night while I am sleeping when this issue occurs.

@sumitrajancse
Copy link
Author

sumitrajancse commented Feb 2, 2018 •
edited by MartinHjelmare
Loading

Now some of the bulbs stop working, try to add again by resetting but not working.
All_Lights

Log Details (ERROR)

Fri Feb 02 2018 13:06:04 GMT-0400 (SA Western Standard Time)

Error executing service <ServiceCall light.turn_on: entity_id=['light.cree_connected_a19_60w_equivalent_fe03e82d_10']>
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/homeassistant/core.py", line 1010, in _event_to_service_call
    yield from service_handler.func(service_call)
  File "/usr/lib/python3.6/site-packages/homeassistant/components/light/__init__.py", line 270, in async_handle_light_service
    yield from light.async_turn_on(**params)
  File "/usr/lib/python3.6/site-packages/homeassistant/components/light/zha.py", line 118, in async_turn_on
    duration
  File "/usr/lib/python3.6/site-packages/bellows/zigbee/application.py", line 284, in request
    v = yield from send_fut
  File "/usr/lib/python3.6/asyncio/futures.py", line 332, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.6/asyncio/tasks.py", line 250, in _wakeup
    future.result()
  File "/usr/lib/python3.6/asyncio/futures.py", line 245, in result
    raise self._exception
bellows.zigbee.exceptions.DeliveryError: Message send failure: EmberStatus.DELIVERY_FAILED

@rcloran
Copy link
Contributor

rcloran commented Feb 19, 2018

The NCP expects prompt responses, and is not getting them. What you're seeing can be caused by other components blocking the event loop for too long. "Timer got out of sync ..." is a usual tell-tale of this, afaict. This is kinda a dup of zigpy/bellows#37 -- bellows should probably run the time-critical sections on a different thread. That said, Home Assistant components should not block the event loop.

Closing this out to track in zigpy/bellows#37 .

@rcloran rcloran closed this as completed Feb 19, 2018
@home-assistant home-assistant locked and limited conversation to collaborators May 29, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@rcloran @dshokouhi @MartinHjelmare @sumitrajancse