Python 3.6 error in Logging

pbavinck · August 22, 2017, 7:30pm

I started seeing these errors in my logs (not frequently, but still). Running latest version of hass (0.51.2) and hass.io Supervisor (0.57). Is this a bug?

2017-08-22 21:18:57 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 <genexpr>
    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'

Jeroen · August 28, 2017, 7:32am

I have the exact same issue on 0.51.2 and 0.52. The frequency seems to be quite random. My first impression is that is seems less frequent after the update.

sendorm · August 31, 2017, 8:12am

I am also getting this error from time to time. I don’t know if they are related but usually it’s not possible to connect to home assistant front end from iphone. It’s ok as usual from the pc though. Version 0.51.2. I am not using Hass. io, just the normal rasppi setup.

2017-08-30 23:35:15 ERROR (MainThread) [aiohttp.access] Error in logging
Traceback (most recent call last):
  File "/home/pi/.homeassistant/deps/lib/python3.5/site-packages/aiohttp/helpers.py", line 500, in log
    for key, value in fmt_info:
  File "/home/pi/.homeassistant/deps/lib/python3.5/site-packages/aiohttp/helpers.py", line 483, in <genexpr>
    return ((key, method(args)) for key, method in self._methods)
  File "/home/pi/.homeassistant/deps/lib/python3.5/site-packages/aiohttp/helpers.py", line 436, in _format_a
    peername = args[3].get_extra_info('peername')
  File "/usr/lib/python3.5/asyncio/sslproto.py", line 306, in get_extra_info
    return self._ssl_protocol._get_extra_info(name, default)
  File "/usr/lib/python3.5/asyncio/sslproto.py", line 546, in _get_extra_info
    return self._transport.get_extra_info(name, default)
AttributeError: 'NoneType' object has no attribute 'get_extra_info'

JSCSJSCS · September 4, 2017, 12:56am

Add me to the list. Hass.io 0.52.1

Times:
15:54:09
16:28:45
17:09:24

2017-09-03 15:54:09 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 <genexpr>
    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'

quad1661 · September 7, 2017, 2:46am

Add me to the list as well…

Hass.io version 0.52.1

2017-09-06 19:24:06 ERROR
2017-09-06 19:26:01 ERROR
2017-09-06 19:32:11 ERROR
2017-09-06 19:34:29 ERROR
2017-09-06 19:37:05 ERROR

2017-09-06 19:37:05 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 <genexpr>
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'

plonka2000 · September 9, 2017, 6:29pm

Get the same, or similar errors:

2017-09-09 16:50:43 ERROR (MainThread) [aiohttp.server] Error handling request
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/homeassistant/components/websocket_api.py", line 326, in handle
    msg = yield from wsock.receive_json()
  File "/usr/lib/python3.6/site-packages/aiohttp/web_ws.py", line 328, in receive_json
    data = yield from self.receive_str(timeout=timeout)
  File "/usr/lib/python3.6/site-packages/aiohttp/web_ws.py", line 310, in receive_str
    msg = yield from self.receive(timeout)
  File "/usr/lib/python3.6/site-packages/aiohttp/web_ws.py", line 273, in receive
    msg = yield from self._reader.read()
  File "/usr/lib/python3.6/site-packages/aiohttp/streams.py", line 627, in read
    return (yield from super().read())
  File "/usr/lib/python3.6/site-packages/aiohttp/streams.py", line 509, in read
    yield from self._waiter
  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 236, in result
    raise CancelledError
concurrent.futures._base.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/aiohttp/web_protocol.py", line 422, in start
    resp = yield from self._request_handler(request)
  File "/usr/lib/python3.6/site-packages/aiohttp/web.py", line 306, in _handle
    resp = yield from handler(request)
  File "/usr/lib/python3.6/asyncio/coroutines.py", line 213, in coro
    res = yield from res
  File "/usr/lib/python3.6/asyncio/coroutines.py", line 213, in coro
    res = yield from res
  File "/usr/lib/python3.6/site-packages/homeassistant/components/http/ban.py", line 58, in ban_middleware_handler
    return (yield from handler(request))
  File "/usr/lib/python3.6/site-packages/homeassistant/components/http/__init__.py", line 424, in handle
    result = yield from result
  File "/usr/lib/python3.6/asyncio/coroutines.py", line 213, in coro
    res = yield from res
  File "/usr/lib/python3.6/site-packages/homeassistant/components/websocket_api.py", line 388, in handle
    yield from self._writer_task
  File "/usr/lib/python3.6/asyncio/futures.py", line 333, in __iter__
    return self.result()  # May raise too.
  File "/usr/lib/python3.6/asyncio/futures.py", line 244, in result
    raise self._exception
  File "/usr/lib/python3.6/asyncio/tasks.py", line 181, in _step
    result = coro.throw(exc)
  File "/usr/lib/python3.6/site-packages/homeassistant/components/websocket_api.py", line 238, in _writer
    yield from self.wsock.send_json(message, dumps=JSON_DUMP)
  File "/usr/lib/python3.6/site-packages/aiohttp/http_writer.py", line 128, in drain
    yield from self._protocol._drain_helper()
  File "/usr/lib/python3.6/asyncio/streams.py", line 211, in _drain_helper
    yield from waiter
  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
ConnectionResetError: [Errno 104] Connection reset by peer

Schneider · September 21, 2017, 12:44pm

Hello guys! I am also receiving this error:

2017-09-21 09:37:05 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 <genexpr>
    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'

I am facing some problems with Homebridge when trying to set the Host to local IP or docker. It only works using DDNS and lags a lot… Not sure if is related to this.

Thanks!

andrejLt · September 22, 2017, 7:57pm

Same here. This can be related to NAT looping

lauindustries · September 23, 2017, 3:19am

I am having the same error. But everything seems to be running fine…

Dennis87 · October 4, 2017, 1:16pm

Same issue in latest hass.io

My router have NAT loopback turned on. Looks like its stops when I turn it off but then im not able to access from local network using duckdns.

Nitee · October 5, 2017, 9:06am

I am also having this error however I’m running HASSbian 1.3 with the latest 0.54 update.

stokesy · October 5, 2017, 9:51am

Yes it is a bug, that was filed back in July. HA throws this error when you refresh the web GUI (hit F5) in Chrome, but the page refreshes OK for me.

cjsimmons · October 20, 2017, 10:29pm

I’m getting this error pop up as well, but I’m using Python 3.5. The error is exactly the same.

I just went and tried this and sure enough, after hitting F5, I had a new error pop up.

At least I now know it’s nothing too worry about, and just seems to be a bug that will hopefully be fixed in time.

Dennis87 · October 25, 2017, 8:35am

Is it a error bug report created for this issue? Its starting to get very annoying to see all the errors in the logs

shred · October 27, 2017, 4:03am

I’m getting a similar error in Hassio 0.56.2. It doesn’t appear to be tied to refreshing the browser.

2017-10-26 19:17:57 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

Seeing many of these in my log.

Romi · October 31, 2017, 6:02pm

Getting the same type of errors but all related to z wave devices on my Wink hub 2.

2017-10-31 13:46:44 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/helpers/entity_component.py”, line 398, in async_process_entity
new_entity, self, update_before_add=update_before_add
File “/usr/lib/python3.6/site-packages/homeassistant/helpers/entity_component.py”, line 246, in async_add_entity
yield from entity.async_update_ha_state()
File “/usr/lib/python3.6/site-packages/homeassistant/helpers/entity.py”, line 222, in async_update_ha_state
attr = self.state_attributes or {}
File “/usr/lib/python3.6/site-packages/homeassistant/components/cover/init.py”, line 236, in state_attributes
current = self.current_cover_position
File “/usr/lib/python3.6/site-packages/homeassistant/components/cover/wink.py”, line 52, in current_cover_position
return int(self.wink.state()*100)
TypeError: unsupported operand type(s) for *: ‘NoneType’ and ‘int’

GrahamS · December 10, 2017, 7:18am

Not the same error message in Romi post. Look elsewhere.

GrahamS · December 10, 2017, 7:30am

Now at 0.59.2 and getting the same errors.
About 6 per day at random times. This is more times than previous Home Assistant versions.
I don’t know if this is a python package bug or how this package is being used.
Is anyone working on this?

PS.
I am using dnsmasq add-on to access duckdns.org on my internal network. My router does not have NAT.
I have 3 Z-Wave devices and a 3 WI-FI devices. Nothing too sophisticated.

Romi · December 10, 2017, 2:55pm

Yes sir…

GrahamS · December 16, 2017, 12:40am

Looks to be a Python Bug reported here: