Core: 0.92.0 - BOM Camera component causing errors

[jurgenweber]

Home Assistant release with the issue:
0.92.0

Last working Home Assistant release (if known):
new feature.

Operating environment (Hass.io/Docker/Windows/etc.):
Hass.io, python 3.5.

Component/platform:
BOM Camera; https://www.home-assistant.io/components/bom/#camera

Description of problem:
I found lots of errors in my homeassistant.log. I was not sure what it was but I disabled the bom cameras and restarted and the errors have disappeared. There are 100's of lines of these errors going through a lot of different components.

2019-04-25 14:12:10 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.1099204368] Error handling message: Unknown error
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/websocket_api/decorators.py", line 17, in _handle_async_response
    await func(hass, connection, msg)
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/camera/__init__.py", line 524, in websocket_camera_thumbnail
    image = await async_get_image(hass, msg['entity_id'])
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/camera/__init__.py", line 125, in async_get_image
    image = await camera.async_camera_image()
  File "/usr/lib/python3.5/asyncio/futures.py", line 380, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.5/asyncio/tasks.py", line 304, in _wakeup
    future.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/lib/python3.5/concurrent/futures/thread.py", line 55, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/bom/camera.py", line 73, in camera_image
    return self._cam.current
  File "/srv/homeassistant/lib/python3.5/site-packages/bomradarloop/__init__.py", line 118, in current
    self._current = self._get_loop()
  File "/srv/homeassistant/lib/python3.5/site-packages/bomradarloop/__init__.py", line 202, in _get_loop
    frames = self._get_frames()
  File "/srv/homeassistant/lib/python3.5/site-packages/bomradarloop/__init__.py", line 158, in _get_frames
    pool0 = multiprocessing.dummy.Pool(self._frames)
  File "/usr/lib/python3.5/multiprocessing/dummy/__init__.py", line 117, in Pool
    return ThreadPool(processes, initializer, initargs)
  File "/usr/lib/python3.5/multiprocessing/pool.py", line 749, in __init__
    Pool.__init__(self, processes, initializer, initargs)
  File "/usr/lib/python3.5/multiprocessing/pool.py", line 194, in __init__
    self._result_handler.start()
  File "/usr/lib/python3.5/threading.py", line 844, in start
    _start_new_thread(self._bootstrap, ())
RuntimeError: can't start new thread
2019-04-25 14:12:10 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.1099204368] Error handling message: Unknown error
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/websocket_api/decorators.py", line 17, in _handle_async_response
    await func(hass, connection, msg)
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/camera/__init__.py", line 524, in websocket_camera_thumbnail
    image = await async_get_image(hass, msg['entity_id'])
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/camera/__init__.py", line 125, in async_get_image
    image = await camera.async_camera_image()
  File "/usr/lib/python3.5/asyncio/futures.py", line 380, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.5/asyncio/tasks.py", line 304, in _wakeup
    future.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/lib/python3.5/concurrent/futures/thread.py", line 55, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/bom/camera.py", line 73, in camera_image
    return self._cam.current
  File "/srv/homeassistant/lib/python3.5/site-packages/bomradarloop/__init__.py", line 118, in current
    self._current = self._get_loop()
  File "/srv/homeassistant/lib/python3.5/site-packages/bomradarloop/__init__.py", line 202, in _get_loop
    frames = self._get_frames()
  File "/srv/homeassistant/lib/python3.5/site-packages/bomradarloop/__init__.py", line 163, in _get_frames
    pool1 = multiprocessing.dummy.Pool(len(wximages))
  File "/usr/lib/python3.5/multiprocessing/dummy/__init__.py", line 117, in Pool
    return ThreadPool(processes, initializer, initargs)
  File "/usr/lib/python3.5/multiprocessing/pool.py", line 749, in __init__
    Pool.__init__(self, processes, initializer, initargs)
  File "/usr/lib/python3.5/multiprocessing/pool.py", line 168, in __init__
    self._repopulate_pool()
  File "/usr/lib/python3.5/multiprocessing/pool.py", line 233, in _repopulate_pool
    w.start()
  File "/usr/lib/python3.5/multiprocessing/dummy/__init__.py", line 48, in start
    threading.Thread.start(self)
  File "/usr/lib/python3.5/threading.py", line 844, in start
    _start_new_thread(self._bootstrap, ())
RuntimeError: can't start new thread

I could see no outward symptom from these, the cameras still seemed to work but I restarted and removed the BOM Camera config and the errors are gone.

Problem-relevant configuration.yaml entries and (fill out even if it seems unimportant):

  - name: Newcastle
    platform: bom
    location: Newcastle
  - name: Sydney
    platform: bom
    location: Sydney

Traceback (if applicable):
You can find my full log file here; https://warvm-mail01.space-marine.org/hass.log.tar.gz

Additional information:

[awarecan]

cc @maddenp

[maddenp]

@jurgenweber, in your full log I see many instances of MemoryError, so I suspect that you may be running out of memory -- the other errors are probably side effects of that root cause.

Are you in a position to do any monitoring of your system's memory to see how much is available? Can you run without issues with just a single camera defined instead of two?

Also, is there any chance that you are running a 32-bit Python? I'm testing on Linux and can check this like so:

% python -c 'import platform ; print(platform.architecture())'
('64bit', 'ELF')

IIRC A 32-bit Python would only be able to access 4GB or memory, regardless of how much physical RAM you have.

[jurgenweber]

yeah, I hear you.

# source /srv/homeassistant/bin/activate
 # which python
/srv/homeassistant/bin/python
 # python -c 'import platform ; print(platform.architecture())'
('32bit', 'ELF')

Well that is annoying, I would of thought hassbian would handle this.

Right now

# free -m
              total        used        free      shared  buff/cache   available
Mem:            927         238         246          46         442         577
Swap:            99           8          91

Should recompile python for this venv.

[maddenp]

A friend was testing an earlier version of the BOM camera code that did more caching for performance, and he ran into similar MemoryError issues. I removed the caching to use less memory and the errors went away. There may be other changes that could further favor memory over time, but an image-processing component probably has some baseline memory requirement that's going to be bigger than many other components.

I don't suppose that a 64-bit Python is going to help if you've only got a gig of RAM to begin with. I'm pretty sure that my friend was lately running several cameras at once without issues. I think he's also using a Raspberry Pi, though I'm not sure which model or how much memory it has. Are you using any other components that might also be vying for a lot of memory?

I will be curious to see if this is a problem for others and whether I'll need to look at trying to squeeze the memory footprint further.

[jurgenweber]

so! I turned one of the BOM Cameras back on for now.

cat /sys/firmware/devicetree/base/model
Raspberry Pi 3 Model B Rev 1.2

I added some stuff from https://www.home-assistant.io/components/systemmonitor/ and we can see how it goes. I seems to be hanging out at the half a gig free mark; https://take.ms/syD5b

My HASS is pretty huge, to give you an idea:

# grep ^\\w /home/homeassistant/.homeassistant/configuration.yaml
homeassistant:
alert:
arlo:
automation: !include_dir_merge_list automation/
binary_sensor: !include binary_sensor.yaml
camera:
config:
cloud: !include cloud.yaml
cloudflare:
conversation:
cover:
daikin:
device_tracker:
fastdotcom:
ffmpeg:
frontend:
geo_location:
googlehome:
group: !include groups.yaml
history:
http:
input_boolean:
input_number:
light: !include light.yaml
lovelace:
logbook:
logger:
media_player:
mqtt:
notify:
owntracks:
person:
recorder:
rest_command:
script: !include scripts.yaml
sensor: !include sensor.yaml
shell_command:
speedtestdotnet:
sun:
system_health:
system_log:
timer:
transmission:
tts:
updater:
vacuum:
weather:
zone:
zwave: !include zwave.yaml

I also have two hikvision security cameras that I stream, etc. Not sure what else would consume a lot of mem, maybe all the zwave nodes? I have about 30.

I did have the jupyter data science stuff running on this as well, which I turned off for now. I am not using it.

Yes, you are correct with only a GB of RAM 64bit Python does seem pointless. I didn't even notice until you mentioned it.

[jurgenweber]

ok, it has started again:

2019-04-26 14:06:05 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection.1271915184] Error handling message: Unknown error
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/websocket_api/decorators.py", line 17, in _handle_async_response
    await func(hass, connection, msg)
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/camera/__init__.py", line 524, in websocket_camera_thumbnail
    image = await async_get_image(hass, msg['entity_id'])
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/camera/__init__.py", line 125, in async_get_image
    image = await camera.async_camera_image()
  File "/usr/lib/python3.5/asyncio/futures.py", line 380, in __iter__
    yield self  # This tells Task to wait for completion.
  File "/usr/lib/python3.5/asyncio/tasks.py", line 304, in _wakeup
    future.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/lib/python3.5/concurrent/futures/thread.py", line 55, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/bom/camera.py", line 73, in camera_image
    return self._cam.current
  File "/srv/homeassistant/lib/python3.5/site-packages/bomradarloop/__init__.py", line 118, in current
    self._current = self._get_loop()
  File "/srv/homeassistant/lib/python3.5/site-packages/bomradarloop/__init__.py", line 202, in _get_loop
    frames = self._get_frames()
  File "/srv/homeassistant/lib/python3.5/site-packages/bomradarloop/__init__.py", line 163, in _get_frames
    pool1 = multiprocessing.dummy.Pool(len(wximages))
  File "/usr/lib/python3.5/multiprocessing/dummy/__init__.py", line 117, in Pool
    return ThreadPool(processes, initializer, initargs)
  File "/usr/lib/python3.5/multiprocessing/pool.py", line 749, in __init__
    Pool.__init__(self, processes, initializer, initargs)
  File "/usr/lib/python3.5/multiprocessing/pool.py", line 194, in __init__
    self._result_handler.start()
  File "/usr/lib/python3.5/threading.py", line 844, in start
    _start_new_thread(self._bootstrap, ())
RuntimeError: can't start new thread
2019-04-26 14:06:15 WARNING (MainThread) [pydaikin.appliance] ServerDisconnectedError 3
2019-04-26 14:08:15 ERROR (Thread-20) [homeassistant.core] Error doing job: Future exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.5/concurrent/futures/thread.py", line 55, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/transmission/__init__.py", line 81, in refresh
    tm_data.update()
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/transmission/__init__.py", line 117, in update
    self.torrents = self._api.get_torrents()
  File "/srv/homeassistant/lib/python3.5/site-packages/transmissionrpc/client.py", line 583, in get_torrents
    return list(self._request('torrent-get', {'fields': arguments}, ids, timeout=timeout).values())
  File "/srv/homeassistant/lib/python3.5/site-packages/transmissionrpc/client.py", line 247, in _request
    http_data = self._http_query(query, timeout)
  File "/srv/homeassistant/lib/python3.5/site-packages/transmissionrpc/client.py", line 205, in _http_query
    result = self.http_handler.request(self.url, query, headers, timeout)
  File "/srv/homeassistant/lib/python3.5/site-packages/transmissionrpc/httphandler.py", line 82, in request
    return response.read().decode('utf-8')
MemoryError
2019-04-26 14:10:01 ERROR (MainThread) [homeassistant.core] Error doing job: Future exception was never retrieved
Traceback (most recent call last):
  File "/usr/lib/python3.5/concurrent/futures/thread.py", line 55, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/transmission/__init__.py", line 81, in refresh
    tm_data.update()
  File "/srv/homeassistant/lib/python3.5/site-packages/homeassistant/components/transmission/__init__.py", line 117, in update
    self.torrents = self._api.get_torrents()
  File "/srv/homeassistant/lib/python3.5/site-packages/transmissionrpc/client.py", line 583, in get_torrents
    return list(self._request('torrent-get', {'fields': arguments}, ids, timeout=timeout).values())
  File "/srv/homeassistant/lib/python3.5/site-packages/transmissionrpc/client.py", line 247, in _request
    http_data = self._http_query(query, timeout)
  File "/srv/homeassistant/lib/python3.5/site-packages/transmissionrpc/client.py", line 205, in _http_query
    result = self.http_handler.request(self.url, query, headers, timeout)
  File "/srv/homeassistant/lib/python3.5/site-packages/transmissionrpc/httphandler.py", line 82, in request
    return response.read().decode('utf-8')
MemoryError

but Free Mem never went under 400mb; https://take.ms/cM0MI

Also nothing in dmesg suggesting it is killing things for OOM.

[maddenp]

As a test, I ran HA with 8 BOM cameras (and no other components) for 2 hours, and saw a slow decrease in available memory, from ~2.2GB to ~1.9GB, over that period. I was also running one web browser (this is all on my laptop), though, so I will test again with no applications at all running, and for longer -- probably overnight. Maybe there's a memory leak in the component, which might be more pronounced on a system with less memory. I'll see if I can find anything.

[jurgenweber]

yeah, sorry. I had a busy weekend. If you like you can ping me on discord.

I am thinking the same sort of thing, with it off you can see my usual mem usage; https://take.ms/EbQNP

[maddenp]

I did another test and had similar results, so I'm feeling fairly confident that there's a memory leak. I want to test the underlying bomradarloop PyPI package that provides most of the functionality, independent of HA, and see if I can reproduce there, too. To my dismay, I see that there have been multiple reports of memory leaks in the Pillow package, which I'm using for image manipulation, so the problem could be there. But I will assume it's my bug to fix until I know more.

[maddenp]

I think I found (and fixed) the problem, and made some other small changes to try to be less demanding on memory. PR #23599 should fix this. At least, I ran HA with my browser open with 10 cameras for 13 hours and saw (unlike before) no creep-up in memory use.

[jurgenweber]

Yeah, just confirming This is working great now for me also.