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.

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

Serialize amcrest snapshot commands and bump PyPI package to 1.2.4 #21664

Merged
merged 2 commits into from Mar 5, 2019

Conversation

Projects
None yet
5 participants
@pnbruckner
Copy link
Contributor

pnbruckner commented Mar 4, 2019

Description:

Attempting to send a snapshot command when a previous one hasn't finished will result in warnings and/or errors. This can happen when the camera picture is clicked on in the frontend, resulting in the thread that updates the thumbnail in the background every 10 seconds to sometimes collide with the thread that updates the large picture in the foreground quickly. An automation that calls the camera.snapshot service in yet another thread can make the situation worse. Fix by adding a thread lock to serialize snapshot commands. Also bump the amcrest package to 1.2.4 which fixes error handling in the command method and improves performance by reusing requests sessions.

Related issue (if applicable): None

Pull request in home-assistant.io with documentation (if applicable): None

Example entry for configuration.yaml (if applicable):

No change to configuration.

Checklist:

  • The code change is tested and works locally.
  • Local tests pass with tox. Your PR cannot be merged unless tests pass
  • There is no commented out code in this PR.

If the code communicates with devices, web services, or third-party tools:

  • New or updated dependencies have been added to requirements_all.txt by running script/gen_requirements_all.py.
Serialize snapshot commands and bump amcrest package to 1.2.4
Attempting to send a snapshot command when a previous one hasn't finished will result in warnings and/or errors. This can happen when the camera picture is clicked on in the frontend, resulting in the thread that updates the thumbnail in the background every 10 seconds to sometimes collide with the thread that updates the large picture in the foreground quickly. An automation that calls the camera.snapshot service in yet another thread can make the situation worse. Fix by adding a thread lock to serialize snapshot commands. Also bump the amcrest package to 1.2.4 which fixes error handling in the command method and improves performance by reusing requests sessions.
@amelchio

This comment has been minimized.

Copy link
Member

amelchio commented Mar 4, 2019

You deleted the part of the checklist that relates to the action that you forgot ...

Change looks good 👍

@pnbruckner

This comment has been minimized.

Copy link
Contributor Author

pnbruckner commented Mar 4, 2019

@amelchio

You deleted the part of the checklist that relates to the action that you forgot ...

What part/action was that? I deleted everything I though wasn't applicable.

@amelchio

This comment has been minimized.

Copy link
Member

amelchio commented Mar 5, 2019

There is (was) a whole section on new dependencies. You have to update requirements_all.txt as well for the Travis test to pass.

@pnbruckner

This comment has been minimized.

Copy link
Contributor Author

pnbruckner commented Mar 5, 2019

Ah, ok. Sorry, I missed that. Should be good now. Thx!

@amelchio
Copy link
Member

amelchio left a comment

Looks good 👍

try:
# Send the request to snap a picture and return raw jpg data
return self._camera.snapshot(channel=self._resolution).data
except (RequestException, ReadTimeoutError, ValueError) as error:

This comment has been minimized.

@amelchio

amelchio Mar 5, 2019

Member

It's a shame the library does not handle these exceptions and raises its own instead.

This comment has been minimized.

@pnbruckner

pnbruckner Mar 5, 2019

Author Contributor

Good idea. I'm working on the library, too, so I can look at doing that. Thanks!

@amelchio amelchio merged commit 16d79b5 into home-assistant:dev Mar 5, 2019

4 checks passed

Hound No violations found. Woof!
cla-bot Everyone involved has signed the CLA
continuous-integration/travis-ci/pr The Travis CI build passed
Details
coverage/coveralls First build on amcrest at 92.757%
Details

@wafflebot wafflebot bot removed the in progress label Mar 5, 2019

@pnbruckner pnbruckner deleted the pnbruckner:amcrest branch Mar 5, 2019

# Send the request to snap a picture and return raw jpg data
response = self._camera.snapshot(channel=self._resolution)
return response.data
with self._snapshot_lock:

This comment has been minimized.

@MartinHjelmare

MartinHjelmare Mar 5, 2019

Member

We should avoid waiting on locks in our thread pool. We can switch to the async api and use an asyncio.Lock instead.

This comment has been minimized.

@amelchio

amelchio Mar 5, 2019

Member

Oh. I agree that would be better but are you implying that we actually have a rule against locks?

This comment has been minimized.

@MartinHjelmare

MartinHjelmare Mar 5, 2019

Member

Yeah, it's basically the same rule as for sleeping in the thread pool.

This comment has been minimized.

@amelchio

amelchio Mar 5, 2019

Member

Hm. I think that dilutes the value of the thread pool. What if the lock was in the third party library? Maybe we should disallow I/O as well since it will sleep?

This comment has been minimized.

@amelchio

amelchio Mar 5, 2019

Member

@pnbruckner I think this is the rewrite that Martin suggests:

    async def async_camera_image(self):
        """Return a still image response from the camera."""
        with self._snapshot_lock:
            try:
                # Send the request to snap a picture and return raw jpg data
                response = await hass.async_add_executor_job(
                    self._camera.snapshot, self._resolution)
                return response.data
            except (RequestException, ReadTimeoutError, ValueError) as error:
                _LOGGER.error(
                    'Could not get camera image due to error %s', error)
                return None

(and then _snapshot_lock should be an asyncio.Lock())

This comment has been minimized.

@pnbruckner

pnbruckner Mar 5, 2019

Author Contributor

Ok. So how do I go about this? Do I restore my branch and check in more changes? Do I open a new PR? Something else?

This comment has been minimized.

@amelchio

amelchio Mar 5, 2019

Member

That should be a new PR.

This comment has been minimized.

@pnbruckner

pnbruckner Mar 6, 2019

Author Contributor

@amelchio @MartinHjelmare

I need some help on this. This is what I came up with based on the suggested code above:

        self._snapshot_lock = asyncio.Lock()

    async def async_camera_image(self):
        """Return a still image response from the camera."""
        with await self._snapshot_lock:
            try:
                # Send the request to snap a picture and return raw jpg data
                _LOGGER.critical('async_camera_image start')
                response = await self.hass.async_add_executor_job(
                    self._camera.snapshot, self._resolution)
                _LOGGER.critical('async_camera_image end: %i', len(response.data))
                return response.data
            except (RequestException, ReadTimeoutError, ValueError) as error:
                _LOGGER.error(
                    'Could not get camera image due to error %s', error)
                return None

But it doesn't seem to be working. I added the logging temporarily to try and see what's going on. I also added logging to the self._camera.snapshot method. Here is what I'm seeing:

2019-03-05 17:53:52 CRITICAL (MainThread) [homeassistant.components.amcrest.camera] async_camera_image start
2019-03-05 17:53:52 CRITICAL (SyncWorker_1) [amcrest.snapshot] snapshot start
2019-03-05 17:53:53 CRITICAL (SyncWorker_1) [amcrest.snapshot] snapshot end
2019-03-05 17:54:00 CRITICAL (MainThread) [homeassistant.components.amcrest.camera] async_camera_image end: 158840
2019-03-05 17:54:00 CRITICAL (MainThread) [homeassistant.components.amcrest.camera] async_camera_image start
2019-03-05 17:54:00 CRITICAL (SyncWorker_7) [amcrest.snapshot] snapshot start
2019-03-05 17:54:01 CRITICAL (SyncWorker_7) [amcrest.snapshot] snapshot end
2019-03-05 17:54:09 CRITICAL (MainThread) [homeassistant.components.amcrest.camera] async_camera_image end: 159495
2019-03-05 17:54:09 CRITICAL (MainThread) [homeassistant.components.amcrest.camera] async_camera_image start
2019-03-05 17:54:09 CRITICAL (SyncWorker_2) [amcrest.snapshot] snapshot start
2019-03-05 17:54:09 CRITICAL (MainThread) [homeassistant.components.amcrest.camera] async_camera_image start
2019-03-05 17:54:09 CRITICAL (SyncWorker_8) [amcrest.snapshot] snapshot start
2019-03-05 17:54:09 WARNING (SyncWorker_2) [urllib3.connectionpool] Retrying (Retry(total=2, connect=None, read=None, redirect=None, status=None)) after connection broken by 'ProtocolError('Connection aborted.', RemoteDisconnected('Remote end closed connection without response'))': /cgi-bin/snapshot.cgi?channel=0
2019-03-05 17:54:09 WARNING (SyncWorker_2) [amcrest.http] Trying again due to error 401 Client Error: Unauthorized for url: http://192.168.1.164:10007/cgi-bin/snapshot.cgi?channel=0

This shows two successful snapshots, but even so, there is a long delay from the snapshot method finishing to async_camera_image finishing. I don't understand that. Then you can see async_camera_image starts twice, which results in two calls to snapshot starting twice, which leads to the errors that the locking is supposed to be avoiding.

Why does the locking seem like it's not working?

This comment has been minimized.

@amelchio

amelchio Mar 6, 2019

Member

Why does the locking seem like it's not working?

Sorry, try this:

async with self._snapshot_lock:

... but please do open a new PR (you can tag me).

This comment has been minimized.

@pnbruckner

pnbruckner Mar 6, 2019

Author Contributor

Thank you. That fixed it! (And now I see why. Still learning asyncio!)

I'll be submitting a new PR with the change soon.

@SukramJ

This comment has been minimized.

Copy link
Contributor

SukramJ commented Mar 6, 2019

Hi,
there is no 1.2.4 in pypi. Just 1.2.3 and 1.2.5.

BR
Markus

@pnbruckner

This comment has been minimized.

Copy link
Contributor Author

pnbruckner commented Mar 6, 2019

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.