[{"id":16745,"web_url":"https://patchwork.libcamera.org/comment/16745/","msgid":"<20210503144104.rjqq2b7fyvodrina@uno.localdomain>","date":"2021-05-03T14:41:04","subject":"Re: [libcamera-devel] [PATCH v3 2/3] android: CameraDevice: Prevent\n\trace due to concurrent HAL calls","submitter":{"id":3,"url":"https://patchwork.libcamera.org/api/people/3/","name":"Jacopo Mondi","email":"jacopo@jmondi.org"},"content":"Hi Hiro,\n\nOn Mon, Apr 26, 2021 at 05:38:29PM +0900, Hirokazu Honda wrote:\n> HAL API functions might be called by different threads in Android\n> Camera HAL3 API, while process_capture_request() must be called\n> by a single thread. Furthermore, close() and flush() can be\n> called any time. Therefore, races to variables can occur among\n> the HAL API functions.\n> This prevents the races by enclosing HAL calls by mutex. It\n> might not be the best in terms of the performance, but the\n> simplicity is good as a first step and also further development.\n>\n> Signed-off-by: Hirokazu Honda \n> ---\n> src/android/camera_device.cpp | 59 ++++++++++++++++++++---------------\n> src/android/camera_device.h | 7 +++--\n> 2 files changed, 39 insertions(+), 27 deletions(-)\n>\n> diff --git a/src/android/camera_device.cpp b/src/android/camera_device.cpp\n> index b3def04b..96c8d4a9 100644\n> --- a/src/android/camera_device.cpp\n> +++ b/src/android/camera_device.cpp\n> @@ -743,7 +743,7 @@ int CameraDevice::open(const hw_module_t *hardwareModule)\n>\n> void CameraDevice::close()\n> {\n> -\tstreams_.clear();\n> +\tstd::scoped_lock halLock(halMutex_);\n\nHave you considered locking the wrappers functions in camera_ops.cpp ?\nWouldn't it be simpler ? However locking with such a coarse-grained\ngranularity I feel contradicts a bit the Camera3 API flush()\ndocumentation, which implies that flush() and\nprocess_capture_request() can race\n\n * Due to\n * concurrency issues, it is possible that from the HAL's point of view, a\n * process_capture_request() call may be started after flush has been invoked but has not\n * returned yet. If such a call happens before flush() returns, the HAL should treat the new\n * capture request like other in-flight pending requests (see #4 below).\n\nLocking at function level rules out this use case: if we lock each\nfunction it's not possible for process_capture_request() to be started\nduring flush() execution as the lock hold by flush will be released\nonly at exit time.\n\nIf serializing operations with this granularity is fine (and I really\nwith it is, as it would really simplify life for use) the only racing\ncondition we have to protect from is between the request completion\nsignal emitted by libcamera, and the camera framework calling into the\nCamera HAL using the camera3 API as flush(), close() and\nprocess_capture_request() will always be serialized.\n\nAssuming the above is ok with the Camera3 API, isn't it enough to\n\n- flush() to call stop() and stop the Camera:\n - All queued requests at the time Camera::stop() is called\n will be returned one by one with an error state. There's no\n reason to cancel the descriptors at stop() time, those\n requests will be completed\n\n - A process_capture_request() called after flush() has stopped\n the camera will return immeditely as the camera is stopped\n and the capture request is returned with an error\n (we might want a flag to keep track of this, otherwise we'll\n hit a Camera state machine error, much like we do with\n running_)\n\n - A close() called after flush() will be a no op\n\n - Only open() will allow the CameraDevice to move back from\n stopped_ state\n\n- There's a tiny tiny window where a request can complete after flush\n has been called but the camera has not been stopped yet. In\n requestComplete() we'll have to inspect the stopped_ flag state and\n force the request to return with error even if it did not.\n\n- Once we move JPEG encoding to a worker thread, stop() will have to\n forcefully stop it. Requests interrupted during encoding will be\n returned with error.\n\nA simple lock around stopped_ should protect it from concurrent\naccesses between stop() and requestComplete().\n\nHave you considered this option and ruled it out for reasons I'm\nfailing to consider ? It feels simpler than decoupling requests and\ndescriptors, maybe you tried and found out it's not :)\n\nThanks\n j\n\n\n>\n> \tstop();\n>\n> @@ -758,12 +758,17 @@ void CameraDevice::stop()\n> \tworker_.stop();\n> \tcamera_->stop();\n>\n> -\tdescriptors_.clear();\n> +\t{\n> +\t\tstd::scoped_lock lock(mutex_);\n> +\t\tdescriptors_.clear();\n> +\t}\n> +\n> \trunning_ = false;\n> }\n>\n> void CameraDevice::setCallbacks(const camera3_callback_ops_t *callbacks)\n> {\n> +\tstd::scoped_lock halLock(halMutex_);\n> \tcallbacks_ = callbacks;\n> }\n>\n> @@ -1643,8 +1648,7 @@ PixelFormat CameraDevice::toPixelFormat(int format) const\n> */\n> int CameraDevice::configureStreams(camera3_stream_configuration_t *stream_list)\n> {\n> -\t/* Before any configuration attempt, stop the camera. */\n> -\tstop();\n> +\tstd::scoped_lock halLock(halMutex_);\n>\n> \tif (stream_list->num_streams == 0) {\n> \t\tLOG(HAL, Error) << \"No streams in configuration\";\n> @@ -1656,6 +1660,9 @@ int CameraDevice::configureStreams(camera3_stream_configuration_t *stream_list)\n> \t\treturn -EINVAL;\n> #endif\n>\n> +\t/* Before any configuration attempt, stop the camera. */\n> +\tstop();\n> +\n> \t/*\n> \t * Generate an empty configuration, and construct a StreamConfiguration\n> \t * for each camera3_stream to add to it.\n> @@ -1671,6 +1678,8 @@ int CameraDevice::configureStreams(camera3_stream_configuration_t *stream_list)\n> \t * ensure the required entries are available without further\n> \t * reallocation.\n> \t */\n> +\n> +\tstd::scoped_lock lock(mutex_);\n> \tstreams_.clear();\n> \tstreams_.reserve(stream_list->num_streams);\n>\n> @@ -1907,6 +1916,8 @@ int CameraDevice::processCaptureRequest(camera3_capture_request_t *camera3Reques\n> \tif (!isValidRequest(camera3Request))\n> \t\treturn -EINVAL;\n>\n> +\tstd::scoped_lock halLock(halMutex_);\n> +\n> \t/* Start the camera if that's the first request we handle. */\n> \tif (!running_) {\n> \t\tworker_.start();\n> @@ -2022,29 +2033,26 @@ int CameraDevice::processCaptureRequest(camera3_capture_request_t *camera3Reques\n>\n> void CameraDevice::requestComplete(Request *request)\n> {\n> +\tstd::scoped_lock lock(mutex_);\n> +\n> \tconst Request::BufferMap &buffers = request->buffers();\n> \tcamera3_buffer_status status = CAMERA3_BUFFER_STATUS_OK;\n> \tstd::unique_ptr resultMetadata;\n>\n> -\tdecltype(descriptors_)::node_type node;\n> -\tstd::unique_ptr captureRequest;\n> -\t{\n> -\t\tstd::scoped_lock lock(mutex_);\n> -\t\tauto requestIt = requests_.find(request->cookie());\n> -\t\tif (requestIt == requests_.end()) {\n> -\t\t\tLOG(HAL, Fatal)\n> -\t\t\t\t<< \"Unknown request: \" << request->cookie();\n> -\t\t\treturn;\n> -\t\t}\n> -\t\tcaptureRequest = std::move(requestIt->second);\n> -\t\trequests_.erase(requestIt);\n> +\tauto requestIt = requests_.find(request->cookie());\n> +\tif (requestIt == requests_.end()) {\n> +\t\tLOG(HAL, Fatal)\n> +\t\t\t<< \"Unknown request: \" << request->cookie();\n> +\t\treturn;\n> +\t}\n> +\tauto captureRequest = std::move(requestIt->second);\n> +\trequests_.erase(requestIt);\n>\n> -\t\tauto it = descriptors_.find(request->cookie());\n> -\t\tif (it == descriptors_.end())\n> -\t\t\treturn;\n> +\tauto it = descriptors_.find(request->cookie());\n> +\tif (it == descriptors_.end())\n> +\t\treturn;\n>\n> -\t\tnode = descriptors_.extract(it);\n> -\t}\n> +\tauto node = descriptors_.extract(it);\n> \tCamera3RequestDescriptor &descriptor = node.mapped();\n>\n> \tif (request->status() != Request::RequestComplete) {\n> @@ -2149,11 +2157,12 @@ void CameraDevice::notifyError(uint32_t frameNumber, camera3_stream_t *stream)\n> \tcamera3_notify_msg_t notify = {};\n>\n> \t/*\n> -\t * \\todo Report and identify the stream number or configuration to\n> -\t * clarify the stream that failed.\n> +\t * \\todo Report and identify the stream number or configuration\n> +\t * to clarify the stream that failed.\n> \t */\n> -\tLOG(HAL, Error) << \"Error occurred on frame \" << frameNumber << \" (\"\n> -\t\t\t<< toPixelFormat(stream->format).toString() << \")\";\n> +\tLOG(HAL, Error)\n> +\t\t<< \"Error occurred on frame \" << descriptor.frameNumber_ << \" (\"\n> +\t\t<< toPixelFormat(descriptor.buffers_[0].stream->format).toString() << \")\";\n>\n> \tnotify.type = CAMERA3_MSG_ERROR;\n> \tnotify.message.error.error_stream = stream;\n> diff --git a/src/android/camera_device.h b/src/android/camera_device.h\n> index 95d77890..325fb967 100644\n> --- a/src/android/camera_device.h\n> +++ b/src/android/camera_device.h\n> @@ -125,9 +125,12 @@ private:\n>\n> \tstd::vector streamConfigurations_;\n> \tstd::map formatsMap_;\n> -\tstd::vector streams_;\n>\n> -\tstd::mutex mutex_; /* Protect descriptors_ and requests_. */\n> +\t/* Avoid races by concurrent Camera HAL API calls. */\n> +\tstd::mutex halMutex_;\n> +\n> +\tstd::mutex mutex_; /* Protect streams_, descriptors_ and requests_. */\n> +\tstd::vector streams_;\n> \tstd::map descriptors_;\n> \tstd::map> requests_;\n>\n> --\n> 2.31.1.498.g6c1eba8ee3d-goog\n>\n> _______________________________________________\n> libcamera-devel mailing list\n> libcamera-devel@lists.libcamera.org\n> https://lists.libcamera.org/listinfo/libcamera-devel","headers":{"Return-Path":"","X-Original-To":"parsemail@patchwork.libcamera.org","Delivered-To":"parsemail@patchwork.libcamera.org","Received":["from lancelot.ideasonboard.com (lancelot.ideasonboard.com\n\t[92.243.16.209])\n\tby patchwork.libcamera.org (Postfix) with ESMTPS id 5BEACBDE78\n\tfor ;\n\tMon, 3 May 2021 14:40:22 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id 8E51B6890C;\n\tMon, 3 May 2021 16:40:21 +0200 (CEST)","from relay2-d.mail.gandi.net (relay2-d.mail.gandi.net\n\t[217.70.183.194])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id 41AF960511\n\tfor ;\n\tMon, 3 May 2021 16:40:20 +0200 (CEST)","from uno.localdomain (93-34-118-233.ip49.fastwebnet.it\n\t[93.34.118.233]) (Authenticated sender: jacopo@jmondi.org)\n\tby relay2-d.mail.gandi.net (Postfix) with ESMTPSA id AD09040016;\n\tMon, 3 May 2021 14:40:19 +0000 (UTC)"],"X-Originating-IP":"93.34.118.233","Date":"Mon, 3 May 2021 16:41:04 +0200","From":"Jacopo Mondi ","To":"Hirokazu Honda ","Message-ID":"<20210503144104.rjqq2b7fyvodrina@uno.localdomain>","References":"<20210426083830.2965095-1-hiroh@chromium.org>\n\t<20210426083830.2965095-3-hiroh@chromium.org>","MIME-Version":"1.0","Content-Disposition":"inline","In-Reply-To":"<20210426083830.2965095-3-hiroh@chromium.org>","Subject":"Re: [libcamera-devel] [PATCH v3 2/3] android: CameraDevice: Prevent\n\trace due to concurrent HAL calls","X-BeenThere":"libcamera-devel@lists.libcamera.org","X-Mailman-Version":"2.1.29","Precedence":"list","List-Id":"","List-Unsubscribe":",\n\t","List-Archive":"","List-Post":"","List-Help":"","List-Subscribe":",\n\t","Cc":"libcamera-devel@lists.libcamera.org","Content-Type":"text/plain; charset=\"us-ascii\"","Content-Transfer-Encoding":"7bit","Errors-To":"libcamera-devel-bounces@lists.libcamera.org","Sender":"\"libcamera-devel\" "}},{"id":16746,"web_url":"https://patchwork.libcamera.org/comment/16746/","msgid":"","date":"2021-05-03T14:55:38","subject":"Re: [libcamera-devel] [PATCH v3 2/3] android: CameraDevice: Prevent\n\trace due to concurrent HAL calls","submitter":{"id":2,"url":"https://patchwork.libcamera.org/api/people/2/","name":"Laurent Pinchart","email":"laurent.pinchart@ideasonboard.com"},"content":"Hello,\n\nOn Mon, May 03, 2021 at 04:41:04PM +0200, Jacopo Mondi wrote:\n> On Mon, Apr 26, 2021 at 05:38:29PM +0900, Hirokazu Honda wrote:\n> > HAL API functions might be called by different threads in Android\n> > Camera HAL3 API, while process_capture_request() must be called\n> > by a single thread. Furthermore, close() and flush() can be\n> > called any time. Therefore, races to variables can occur among\n> > the HAL API functions.\n> > This prevents the races by enclosing HAL calls by mutex. It\n> > might not be the best in terms of the performance, but the\n> > simplicity is good as a first step and also further development.\n> >\n> > Signed-off-by: Hirokazu Honda \n> > ---\n> > src/android/camera_device.cpp | 59 ++++++++++++++++++++---------------\n> > src/android/camera_device.h | 7 +++--\n> > 2 files changed, 39 insertions(+), 27 deletions(-)\n> >\n> > diff --git a/src/android/camera_device.cpp b/src/android/camera_device.cpp\n> > index b3def04b..96c8d4a9 100644\n> > --- a/src/android/camera_device.cpp\n> > +++ b/src/android/camera_device.cpp\n> > @@ -743,7 +743,7 @@ int CameraDevice::open(const hw_module_t *hardwareModule)\n> >\n> > void CameraDevice::close()\n> > {\n> > -\tstreams_.clear();\n> > +\tstd::scoped_lock halLock(halMutex_);\n> \n> Have you considered locking the wrappers functions in camera_ops.cpp ?\n> Wouldn't it be simpler ? However locking with such a coarse-grained\n> granularity I feel contradicts a bit the Camera3 API flush()\n> documentation, which implies that flush() and\n> process_capture_request() can race\n> \n> * Due to\n> * concurrency issues, it is possible that from the HAL's point of view, a\n> * process_capture_request() call may be started after flush has been invoked but has not\n> * returned yet. If such a call happens before flush() returns, the HAL should treat the new\n> * capture request like other in-flight pending requests (see #4 below).\n> \n> Locking at function level rules out this use case: if we lock each\n> function it's not possible for process_capture_request() to be started\n> during flush() execution as the lock hold by flush will be released\n> only at exit time.\n> \n> If serializing operations with this granularity is fine (and I really\n> with it is, as it would really simplify life for use)\n\nI think it is as an initial step, but likely not in the longer term. It\ndefeats the point of having the camera service issue\nprocess_capture_request() and stop()/flush() calls concurrently. If\nserializing operations was good enough in every case, it would be done\nin the camera service itself, and HAL implementations wouldn't need to\ndeal with this.\n\n> the only racing\n> condition we have to protect from is between the request completion\n> signal emitted by libcamera, and the camera framework calling into the\n> Camera HAL using the camera3 API as flush(), close() and\n> process_capture_request() will always be serialized.\n> \n> Assuming the above is ok with the Camera3 API, isn't it enough to\n> \n> - flush() to call stop() and stop the Camera:\n> - All queued requests at the time Camera::stop() is called\n> will be returned one by one with an error state. There's no\n> reason to cancel the descriptors at stop() time, those\n> requests will be completed\n> \n> - A process_capture_request() called after flush() has stopped\n> the camera will return immeditely as the camera is stopped\n> and the capture request is returned with an error\n> (we might want a flag to keep track of this, otherwise we'll\n> hit a Camera state machine error, much like we do with\n> running_)\n> \n> - A close() called after flush() will be a no op\n\nSo far it seems fine to me.\n\n> - Only open() will allow the CameraDevice to move back from\n> stopped_ state\n\nThat's correct for close(). For flush(), we can to make sure that a\nconfigureStreams() call will reopen the camera.\n\n> - There's a tiny tiny window where a request can complete after flush\n> has been called but the camera has not been stopped yet. In\n\nIt's not that tiny, it can certainly be hit in practice.\n\n> requestComplete() we'll have to inspect the stopped_ flag state and\n> force the request to return with error even if it did not.\n\nWhy can't we complete the request without any error in that case ?\n\n> - Once we move JPEG encoding to a worker thread, stop() will have to\n> forcefully stop it. Requests interrupted during encoding will be\n> returned with error.\n> \n> A simple lock around stopped_ should protect it from concurrent\n> accesses between stop() and requestComplete().\n\nThe issue is that the flush() function must wait for all requests to\ncomplete. This could be implemented with a condition variable, allowing\nto avoid serializing CameraDevice::requestComplete() with the API calls\nfrom the camera service. I think that would be better indeed.\n\n> Have you considered this option and ruled it out for reasons I'm\n> failing to consider ? It feels simpler than decoupling requests and\n> descriptors, maybe you tried and found out it's not :)\n> \n> > \tstop();\n> >\n> > @@ -758,12 +758,17 @@ void CameraDevice::stop()\n> > \tworker_.stop();\n> > \tcamera_->stop();\n> >\n> > -\tdescriptors_.clear();\n> > +\t{\n> > +\t\tstd::scoped_lock lock(mutex_);\n> > +\t\tdescriptors_.clear();\n> > +\t}\n> > +\n> > \trunning_ = false;\n> > }\n> >\n> > void CameraDevice::setCallbacks(const camera3_callback_ops_t *callbacks)\n> > {\n> > +\tstd::scoped_lock halLock(halMutex_);\n> > \tcallbacks_ = callbacks;\n> > }\n> >\n> > @@ -1643,8 +1648,7 @@ PixelFormat CameraDevice::toPixelFormat(int format) const\n> > */\n> > int CameraDevice::configureStreams(camera3_stream_configuration_t *stream_list)\n> > {\n> > -\t/* Before any configuration attempt, stop the camera. */\n> > -\tstop();\n> > +\tstd::scoped_lock halLock(halMutex_);\n> >\n> > \tif (stream_list->num_streams == 0) {\n> > \t\tLOG(HAL, Error) << \"No streams in configuration\";\n> > @@ -1656,6 +1660,9 @@ int CameraDevice::configureStreams(camera3_stream_configuration_t *stream_list)\n> > \t\treturn -EINVAL;\n> > #endif\n> >\n> > +\t/* Before any configuration attempt, stop the camera. */\n> > +\tstop();\n> > +\n> > \t/*\n> > \t * Generate an empty configuration, and construct a StreamConfiguration\n> > \t * for each camera3_stream to add to it.\n> > @@ -1671,6 +1678,8 @@ int CameraDevice::configureStreams(camera3_stream_configuration_t *stream_list)\n> > \t * ensure the required entries are available without further\n> > \t * reallocation.\n> > \t */\n> > +\n> > +\tstd::scoped_lock lock(mutex_);\n> > \tstreams_.clear();\n> > \tstreams_.reserve(stream_list->num_streams);\n> >\n> > @@ -1907,6 +1916,8 @@ int CameraDevice::processCaptureRequest(camera3_capture_request_t *camera3Reques\n> > \tif (!isValidRequest(camera3Request))\n> > \t\treturn -EINVAL;\n> >\n> > +\tstd::scoped_lock halLock(halMutex_);\n> > +\n> > \t/* Start the camera if that's the first request we handle. */\n> > \tif (!running_) {\n> > \t\tworker_.start();\n> > @@ -2022,29 +2033,26 @@ int CameraDevice::processCaptureRequest(camera3_capture_request_t *camera3Reques\n> >\n> > void CameraDevice::requestComplete(Request *request)\n> > {\n> > +\tstd::scoped_lock lock(mutex_);\n> > +\n> > \tconst Request::BufferMap &buffers = request->buffers();\n> > \tcamera3_buffer_status status = CAMERA3_BUFFER_STATUS_OK;\n> > \tstd::unique_ptr resultMetadata;\n> >\n> > -\tdecltype(descriptors_)::node_type node;\n> > -\tstd::unique_ptr captureRequest;\n> > -\t{\n> > -\t\tstd::scoped_lock lock(mutex_);\n> > -\t\tauto requestIt = requests_.find(request->cookie());\n> > -\t\tif (requestIt == requests_.end()) {\n> > -\t\t\tLOG(HAL, Fatal)\n> > -\t\t\t\t<< \"Unknown request: \" << request->cookie();\n> > -\t\t\treturn;\n> > -\t\t}\n> > -\t\tcaptureRequest = std::move(requestIt->second);\n> > -\t\trequests_.erase(requestIt);\n> > +\tauto requestIt = requests_.find(request->cookie());\n> > +\tif (requestIt == requests_.end()) {\n> > +\t\tLOG(HAL, Fatal)\n> > +\t\t\t<< \"Unknown request: \" << request->cookie();\n> > +\t\treturn;\n> > +\t}\n> > +\tauto captureRequest = std::move(requestIt->second);\n> > +\trequests_.erase(requestIt);\n> >\n> > -\t\tauto it = descriptors_.find(request->cookie());\n> > -\t\tif (it == descriptors_.end())\n> > -\t\t\treturn;\n> > +\tauto it = descriptors_.find(request->cookie());\n> > +\tif (it == descriptors_.end())\n> > +\t\treturn;\n> >\n> > -\t\tnode = descriptors_.extract(it);\n> > -\t}\n> > +\tauto node = descriptors_.extract(it);\n> > \tCamera3RequestDescriptor &descriptor = node.mapped();\n> >\n> > \tif (request->status() != Request::RequestComplete) {\n> > @@ -2149,11 +2157,12 @@ void CameraDevice::notifyError(uint32_t frameNumber, camera3_stream_t *stream)\n> > \tcamera3_notify_msg_t notify = {};\n> >\n> > \t/*\n> > -\t * \\todo Report and identify the stream number or configuration to\n> > -\t * clarify the stream that failed.\n> > +\t * \\todo Report and identify the stream number or configuration\n> > +\t * to clarify the stream that failed.\n> > \t */\n> > -\tLOG(HAL, Error) << \"Error occurred on frame \" << frameNumber << \" (\"\n> > -\t\t\t<< toPixelFormat(stream->format).toString() << \")\";\n> > +\tLOG(HAL, Error)\n> > +\t\t<< \"Error occurred on frame \" << descriptor.frameNumber_ << \" (\"\n> > +\t\t<< toPixelFormat(descriptor.buffers_[0].stream->format).toString() << \")\";\n> >\n> > \tnotify.type = CAMERA3_MSG_ERROR;\n> > \tnotify.message.error.error_stream = stream;\n> > diff --git a/src/android/camera_device.h b/src/android/camera_device.h\n> > index 95d77890..325fb967 100644\n> > --- a/src/android/camera_device.h\n> > +++ b/src/android/camera_device.h\n> > @@ -125,9 +125,12 @@ private:\n> >\n> > \tstd::vector streamConfigurations_;\n> > \tstd::map formatsMap_;\n> > -\tstd::vector streams_;\n> >\n> > -\tstd::mutex mutex_; /* Protect descriptors_ and requests_. */\n> > +\t/* Avoid races by concurrent Camera HAL API calls. */\n> > +\tstd::mutex halMutex_;\n> > +\n> > +\tstd::mutex mutex_; /* Protect streams_, descriptors_ and requests_. */\n> > +\tstd::vector streams_;\n> > \tstd::map descriptors_;\n> > \tstd::map> requests_;\n> >","headers":{"Return-Path":"","X-Original-To":"parsemail@patchwork.libcamera.org","Delivered-To":"parsemail@patchwork.libcamera.org","Received":["from lancelot.ideasonboard.com (lancelot.ideasonboard.com\n\t[92.243.16.209])\n\tby patchwork.libcamera.org (Postfix) with ESMTPS id 8BCF3BDE77\n\tfor ;\n\tMon, 3 May 2021 14:55:42 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id 0AB1168919;\n\tMon, 3 May 2021 16:55:42 +0200 (CEST)","from perceval.ideasonboard.com (perceval.ideasonboard.com\n\t[213.167.242.64])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id 9604B60511\n\tfor ;\n\tMon, 3 May 2021 16:55:40 +0200 (CEST)","from pendragon.ideasonboard.com (62-78-145-57.bb.dnainternet.fi\n\t[62.78.145.57])\n\tby perceval.ideasonboard.com (Postfix) with ESMTPSA id 1283356B;\n\tMon, 3 May 2021 16:55:40 +0200 (CEST)"],"Authentication-Results":"lancelot.ideasonboard.com;\n\tdkim=fail reason=\"signature verification failed\" (1024-bit key;\n\tunprotected) header.d=ideasonboard.com header.i=@ideasonboard.com\n\theader.b=\"Tuq5v0XW\"; dkim-atps=neutral","DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/simple; d=ideasonboard.com;\n\ts=mail; t=1620053740;\n\tbh=zlqsokHxFqemdT1WwRJmAugNRw/RVFT5MgiFKgn26wA=;\n\th=Date:From:To:Cc:Subject:References:In-Reply-To:From;\n\tb=Tuq5v0XWR9L4BaI9QjKRdKMOXakpTi+eXkeX2JrHebmFj0qSS2DH0RQaBAR11h4aM\n\tii367ywz8s8+iLXONYh+CxwzBXN4cGhNLB2MyOMkayPuKI3snqaMnvCkOzamUTsVfd\n\tAZqcT84OQYFd8QlME7NTZ3+YJ2h0+fHSnvM9XhIo=","Date":"Mon, 3 May 2021 17:55:38 +0300","From":"Laurent Pinchart ","To":"Jacopo Mondi ","Message-ID":"","References":"<20210426083830.2965095-1-hiroh@chromium.org>\n\t<20210426083830.2965095-3-hiroh@chromium.org>\n\t<20210503144104.rjqq2b7fyvodrina@uno.localdomain>","MIME-Version":"1.0","Content-Disposition":"inline","In-Reply-To":"<20210503144104.rjqq2b7fyvodrina@uno.localdomain>","Subject":"Re: [libcamera-devel] [PATCH v3 2/3] android: CameraDevice: Prevent\n\trace due to concurrent HAL calls","X-BeenThere":"libcamera-devel@lists.libcamera.org","X-Mailman-Version":"2.1.29","Precedence":"list","List-Id":"","List-Unsubscribe":",\n\t","List-Archive":"","List-Post":"","List-Help":"","List-Subscribe":",\n\t","Cc":"libcamera-devel@lists.libcamera.org","Content-Type":"text/plain; charset=\"us-ascii\"","Content-Transfer-Encoding":"7bit","Errors-To":"libcamera-devel-bounces@lists.libcamera.org","Sender":"\"libcamera-devel\" "}},{"id":16747,"web_url":"https://patchwork.libcamera.org/comment/16747/","msgid":"<20210503160251.6q5cqpoyfnjsciw4@uno.localdomain>","date":"2021-05-03T16:02:51","subject":"Re: [libcamera-devel] [PATCH v3 2/3] android: CameraDevice: Prevent\n\trace due to concurrent HAL calls","submitter":{"id":3,"url":"https://patchwork.libcamera.org/api/people/3/","name":"Jacopo Mondi","email":"jacopo@jmondi.org"},"content":"Hi Laurent,\n\nOn Mon, May 03, 2021 at 05:55:38PM +0300, Laurent Pinchart wrote:\n> Hello,\n>\n> On Mon, May 03, 2021 at 04:41:04PM +0200, Jacopo Mondi wrote:\n> > On Mon, Apr 26, 2021 at 05:38:29PM +0900, Hirokazu Honda wrote:\n> > > HAL API functions might be called by different threads in Android\n> > > Camera HAL3 API, while process_capture_request() must be called\n> > > by a single thread. Furthermore, close() and flush() can be\n> > > called any time. Therefore, races to variables can occur among\n> > > the HAL API functions.\n> > > This prevents the races by enclosing HAL calls by mutex. It\n> > > might not be the best in terms of the performance, but the\n> > > simplicity is good as a first step and also further development.\n> > >\n> > > Signed-off-by: Hirokazu Honda \n> > > ---\n> > > src/android/camera_device.cpp | 59 ++++++++++++++++++++---------------\n> > > src/android/camera_device.h | 7 +++--\n> > > 2 files changed, 39 insertions(+), 27 deletions(-)\n> > >\n> > > diff --git a/src/android/camera_device.cpp b/src/android/camera_device.cpp\n> > > index b3def04b..96c8d4a9 100644\n> > > --- a/src/android/camera_device.cpp\n> > > +++ b/src/android/camera_device.cpp\n> > > @@ -743,7 +743,7 @@ int CameraDevice::open(const hw_module_t *hardwareModule)\n> > >\n> > > void CameraDevice::close()\n> > > {\n> > > -\tstreams_.clear();\n> > > +\tstd::scoped_lock halLock(halMutex_);\n> >\n> > Have you considered locking the wrappers functions in camera_ops.cpp ?\n> > Wouldn't it be simpler ? However locking with such a coarse-grained\n> > granularity I feel contradicts a bit the Camera3 API flush()\n> > documentation, which implies that flush() and\n> > process_capture_request() can race\n> >\n> > * Due to\n> > * concurrency issues, it is possible that from the HAL's point of view, a\n> > * process_capture_request() call may be started after flush has been invoked but has not\n> > * returned yet. If such a call happens before flush() returns, the HAL should treat the new\n> > * capture request like other in-flight pending requests (see #4 below).\n> >\n> > Locking at function level rules out this use case: if we lock each\n> > function it's not possible for process_capture_request() to be started\n> > during flush() execution as the lock hold by flush will be released\n> > only at exit time.\n> >\n> > If serializing operations with this granularity is fine (and I really\n> > with it is, as it would really simplify life for use)\n>\n> I think it is as an initial step, but likely not in the longer term. It\n> defeats the point of having the camera service issue\n> process_capture_request() and stop()/flush() calls concurrently. If\n\nYes, that was my concern, although the documentation says it's enough\nto implement the full success/full fail behavior which I think it's\nwhat's happening here.\n\n> serializing operations was good enough in every case, it would be done\n> in the camera service itself, and HAL implementations wouldn't need to\n> deal with this.\n\nAlso true, indeed the framework allows to implement a finer granularity\nin locking the operations\n\n>\n> > the only racing\n> > condition we have to protect from is between the request completion\n> > signal emitted by libcamera, and the camera framework calling into the\n> > Camera HAL using the camera3 API as flush(), close() and\n> > process_capture_request() will always be serialized.\n> >\n> > Assuming the above is ok with the Camera3 API, isn't it enough to\n> >\n> > - flush() to call stop() and stop the Camera:\n> > - All queued requests at the time Camera::stop() is called\n> > will be returned one by one with an error state. There's no\n> > reason to cancel the descriptors at stop() time, those\n> > requests will be completed\n> >\n> > - A process_capture_request() called after flush() has stopped\n> > the camera will return immeditely as the camera is stopped\n> > and the capture request is returned with an error\n> > (we might want a flag to keep track of this, otherwise we'll\n> > hit a Camera state machine error, much like we do with\n> > running_)\n> >\n> > - A close() called after flush() will be a no op\n>\n> So far it seems fine to me.\n>\n> > - Only open() will allow the CameraDevice to move back from\n> > stopped_ state\n>\n> That's correct for close(). For flush(), we can to make sure that a\n> configureStreams() call will reopen the camera.\n\nRight, it's probably enough to just reset the state of the new flag in\nconfigureStreams() and return immediately from\nprocessCaptureRequest().\n\nMy main point should have been that processCaptureRequest() cannot be\ncalled after a flush() without going through configureStreams() ?\n\nMaybe not true however, considering:\n\n * flush() should only return when there are no more outstanding buffers or\n * requests left in the HAL. The framework may call configure_streams (as\n * the HAL state is now quiesced) or may issue new requests.\n\nWhich seems to suggest after a flush, processCaptureRequest() can be\ncalled again.\n\n>\n> > - There's a tiny tiny window where a request can complete after flush\n> > has been called but the camera has not been stopped yet. In\n>\n> It's not that tiny, it can certainly be hit in practice.\n>\n> > requestComplete() we'll have to inspect the stopped_ flag state and\n> > force the request to return with error even if it did not.\n>\n> Why can't we complete the request without any error in that case ?\n\nBecause flush() has been called already (but the camera has not\nstopped yet?)\n\nAlthough the documentation reports\n\n * 1. For captures that are too late for the HAL to cancel/stop, and will be\n * completed normally by the HAL; i.e. the HAL can send shutter/notify and\n * process_capture_result and buffers as normal.\n\nIt's then probably fine to let those requests just complete\nsuccessfully (even better, it's easier)\n\n>\n> > - Once we move JPEG encoding to a worker thread, stop() will have to\n> > forcefully stop it. Requests interrupted during encoding will be\n> > returned with error.\n> >\n> > A simple lock around stopped_ should protect it from concurrent\n> > accesses between stop() and requestComplete().\n>\n> The issue is that the flush() function must wait for all requests to\n> complete. This could be implemented with a condition variable, allowing\n> to avoid serializing CameraDevice::requestComplete() with the API calls\n> from the camera service. I think that would be better indeed.\n\nAh yes, I overlooked this part\n\n * flush() should only return when there are no more outstanding buffers or\n * requests left in the HAL.\n\nActually with a condition variable it might also get easier, as\n\n flush() {\n {\n /* mutex lock *\n flushing_ = true;\n }\n\n stop()\n\n flushed.wait()\n {\n /* mutex lock *\n flushing_ = false;\n }\n }\n\nWould allow to held the flushing_ state until all the pending requests\nhave been returned as a consequence of stop(). Once that's done we can\nreset the flushing_ flag, and the next processCaptureRequest() can\ncontinue as normal ?\n\nDo we have a list of CTS or cros_camera_test that exercizes flush() to\nbe used as validation ?\n\nI've tried with this series applied:\n\n# cros_camera_test --gtest_filter=\"Camera3FrameTest/Camera3FlushRequestsTest*\"\n[ PASSED ] 4 tests.\n[ FAILED ] 8 tests, listed below\n\nWhich is the same result I get on the most recent master..\n\nThanks\n j\n\n> > Have you considered this option and ruled it out for reasons I'm\n> > failing to consider ? It feels simpler than decoupling requests and\n> > descriptors, maybe you tried and found out it's not :)\n> >\n> > > \tstop();\n> > >\n> > > @@ -758,12 +758,17 @@ void CameraDevice::stop()\n> > > \tworker_.stop();\n> > > \tcamera_->stop();\n> > >\n> > > -\tdescriptors_.clear();\n> > > +\t{\n> > > +\t\tstd::scoped_lock lock(mutex_);\n> > > +\t\tdescriptors_.clear();\n> > > +\t}\n> > > +\n> > > \trunning_ = false;\n> > > }\n> > >\n> > > void CameraDevice::setCallbacks(const camera3_callback_ops_t *callbacks)\n> > > {\n> > > +\tstd::scoped_lock halLock(halMutex_);\n> > > \tcallbacks_ = callbacks;\n> > > }\n> > >\n> > > @@ -1643,8 +1648,7 @@ PixelFormat CameraDevice::toPixelFormat(int format) const\n> > > */\n> > > int CameraDevice::configureStreams(camera3_stream_configuration_t *stream_list)\n> > > {\n> > > -\t/* Before any configuration attempt, stop the camera. */\n> > > -\tstop();\n> > > +\tstd::scoped_lock halLock(halMutex_);\n> > >\n> > > \tif (stream_list->num_streams == 0) {\n> > > \t\tLOG(HAL, Error) << \"No streams in configuration\";\n> > > @@ -1656,6 +1660,9 @@ int CameraDevice::configureStreams(camera3_stream_configuration_t *stream_list)\n> > > \t\treturn -EINVAL;\n> > > #endif\n> > >\n> > > +\t/* Before any configuration attempt, stop the camera. */\n> > > +\tstop();\n> > > +\n> > > \t/*\n> > > \t * Generate an empty configuration, and construct a StreamConfiguration\n> > > \t * for each camera3_stream to add to it.\n> > > @@ -1671,6 +1678,8 @@ int CameraDevice::configureStreams(camera3_stream_configuration_t *stream_list)\n> > > \t * ensure the required entries are available without further\n> > > \t * reallocation.\n> > > \t */\n> > > +\n> > > +\tstd::scoped_lock lock(mutex_);\n> > > \tstreams_.clear();\n> > > \tstreams_.reserve(stream_list->num_streams);\n> > >\n> > > @@ -1907,6 +1916,8 @@ int CameraDevice::processCaptureRequest(camera3_capture_request_t *camera3Reques\n> > > \tif (!isValidRequest(camera3Request))\n> > > \t\treturn -EINVAL;\n> > >\n> > > +\tstd::scoped_lock halLock(halMutex_);\n> > > +\n> > > \t/* Start the camera if that's the first request we handle. */\n> > > \tif (!running_) {\n> > > \t\tworker_.start();\n> > > @@ -2022,29 +2033,26 @@ int CameraDevice::processCaptureRequest(camera3_capture_request_t *camera3Reques\n> > >\n> > > void CameraDevice::requestComplete(Request *request)\n> > > {\n> > > +\tstd::scoped_lock lock(mutex_);\n> > > +\n> > > \tconst Request::BufferMap &buffers = request->buffers();\n> > > \tcamera3_buffer_status status = CAMERA3_BUFFER_STATUS_OK;\n> > > \tstd::unique_ptr resultMetadata;\n> > >\n> > > -\tdecltype(descriptors_)::node_type node;\n> > > -\tstd::unique_ptr captureRequest;\n> > > -\t{\n> > > -\t\tstd::scoped_lock lock(mutex_);\n> > > -\t\tauto requestIt = requests_.find(request->cookie());\n> > > -\t\tif (requestIt == requests_.end()) {\n> > > -\t\t\tLOG(HAL, Fatal)\n> > > -\t\t\t\t<< \"Unknown request: \" << request->cookie();\n> > > -\t\t\treturn;\n> > > -\t\t}\n> > > -\t\tcaptureRequest = std::move(requestIt->second);\n> > > -\t\trequests_.erase(requestIt);\n> > > +\tauto requestIt = requests_.find(request->cookie());\n> > > +\tif (requestIt == requests_.end()) {\n> > > +\t\tLOG(HAL, Fatal)\n> > > +\t\t\t<< \"Unknown request: \" << request->cookie();\n> > > +\t\treturn;\n> > > +\t}\n> > > +\tauto captureRequest = std::move(requestIt->second);\n> > > +\trequests_.erase(requestIt);\n> > >\n> > > -\t\tauto it = descriptors_.find(request->cookie());\n> > > -\t\tif (it == descriptors_.end())\n> > > -\t\t\treturn;\n> > > +\tauto it = descriptors_.find(request->cookie());\n> > > +\tif (it == descriptors_.end())\n> > > +\t\treturn;\n> > >\n> > > -\t\tnode = descriptors_.extract(it);\n> > > -\t}\n> > > +\tauto node = descriptors_.extract(it);\n> > > \tCamera3RequestDescriptor &descriptor = node.mapped();\n> > >\n> > > \tif (request->status() != Request::RequestComplete) {\n> > > @@ -2149,11 +2157,12 @@ void CameraDevice::notifyError(uint32_t frameNumber, camera3_stream_t *stream)\n> > > \tcamera3_notify_msg_t notify = {};\n> > >\n> > > \t/*\n> > > -\t * \\todo Report and identify the stream number or configuration to\n> > > -\t * clarify the stream that failed.\n> > > +\t * \\todo Report and identify the stream number or configuration\n> > > +\t * to clarify the stream that failed.\n> > > \t */\n> > > -\tLOG(HAL, Error) << \"Error occurred on frame \" << frameNumber << \" (\"\n> > > -\t\t\t<< toPixelFormat(stream->format).toString() << \")\";\n> > > +\tLOG(HAL, Error)\n> > > +\t\t<< \"Error occurred on frame \" << descriptor.frameNumber_ << \" (\"\n> > > +\t\t<< toPixelFormat(descriptor.buffers_[0].stream->format).toString() << \")\";\n> > >\n> > > \tnotify.type = CAMERA3_MSG_ERROR;\n> > > \tnotify.message.error.error_stream = stream;\n> > > diff --git a/src/android/camera_device.h b/src/android/camera_device.h\n> > > index 95d77890..325fb967 100644\n> > > --- a/src/android/camera_device.h\n> > > +++ b/src/android/camera_device.h\n> > > @@ -125,9 +125,12 @@ private:\n> > >\n> > > \tstd::vector streamConfigurations_;\n> > > \tstd::map formatsMap_;\n> > > -\tstd::vector streams_;\n> > >\n> > > -\tstd::mutex mutex_; /* Protect descriptors_ and requests_. */\n> > > +\t/* Avoid races by concurrent Camera HAL API calls. */\n> > > +\tstd::mutex halMutex_;\n> > > +\n> > > +\tstd::mutex mutex_; /* Protect streams_, descriptors_ and requests_. */\n> > > +\tstd::vector streams_;\n> > > \tstd::map descriptors_;\n> > > \tstd::map> requests_;\n> > >\n>\n> --\n> Regards,\n>\n> Laurent Pinchart","headers":{"Return-Path":"","X-Original-To":"parsemail@patchwork.libcamera.org","Delivered-To":"parsemail@patchwork.libcamera.org","Received":["from lancelot.ideasonboard.com (lancelot.ideasonboard.com\n\t[92.243.16.209])\n\tby patchwork.libcamera.org (Postfix) with ESMTPS id 92BA5BDE78\n\tfor ;\n\tMon, 3 May 2021 16:02:10 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id E92326890E;\n\tMon, 3 May 2021 18:02:09 +0200 (CEST)","from relay4-d.mail.gandi.net (relay4-d.mail.gandi.net\n\t[217.70.183.196])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id 53B2E688AE\n\tfor ;\n\tMon, 3 May 2021 18:02:09 +0200 (CEST)","from uno.localdomain (93-34-118-233.ip49.fastwebnet.it\n\t[93.34.118.233]) (Authenticated sender: jacopo@jmondi.org)\n\tby relay4-d.mail.gandi.net (Postfix) with ESMTPSA id C42B7E001C;\n\tMon, 3 May 2021 16:02:07 +0000 (UTC)"],"X-Originating-IP":"93.34.118.233","Date":"Mon, 3 May 2021 18:02:51 +0200","From":"Jacopo Mondi ","To":"Laurent Pinchart ","Message-ID":"<20210503160251.6q5cqpoyfnjsciw4@uno.localdomain>","References":"<20210426083830.2965095-1-hiroh@chromium.org>\n\t<20210426083830.2965095-3-hiroh@chromium.org>\n\t<20210503144104.rjqq2b7fyvodrina@uno.localdomain>\n\t","MIME-Version":"1.0","Content-Disposition":"inline","In-Reply-To":"","Subject":"Re: [libcamera-devel] [PATCH v3 2/3] android: CameraDevice: Prevent\n\trace due to concurrent HAL calls","X-BeenThere":"libcamera-devel@lists.libcamera.org","X-Mailman-Version":"2.1.29","Precedence":"list","List-Id":"","List-Unsubscribe":",\n\t","List-Archive":"","List-Post":"","List-Help":"","List-Subscribe":",\n\t","Cc":"libcamera-devel@lists.libcamera.org","Content-Type":"text/plain; charset=\"us-ascii\"","Content-Transfer-Encoding":"7bit","Errors-To":"libcamera-devel-bounces@lists.libcamera.org","Sender":"\"libcamera-devel\" "}},{"id":16748,"web_url":"https://patchwork.libcamera.org/comment/16748/","msgid":"<20210503160414.bl5vk7vbrpwxuvae@uno.localdomain>","date":"2021-05-03T16:04:14","subject":"Re: [libcamera-devel] [PATCH v3 2/3] android: CameraDevice: Prevent\n\trace due to concurrent HAL calls","submitter":{"id":3,"url":"https://patchwork.libcamera.org/api/people/3/","name":"Jacopo Mondi","email":"jacopo@jmondi.org"},"content":"Hi Hiro,\n\nOn Mon, Apr 26, 2021 at 05:38:29PM +0900, Hirokazu Honda wrote:\n> HAL API functions might be called by different threads in Android\n> Camera HAL3 API, while process_capture_request() must be called\n> by a single thread. Furthermore, close() and flush() can be\n> called any time. Therefore, races to variables can occur among\n> the HAL API functions.\n> This prevents the races by enclosing HAL calls by mutex. It\n> might not be the best in terms of the performance, but the\n> simplicity is good as a first step and also further development.\n>\n> Signed-off-by: Hirokazu Honda \n> \t/*\n> -\t * \\todo Report and identify the stream number or configuration to\n> -\t * clarify the stream that failed.\n> +\t * \\todo Report and identify the stream number or configuration\n> +\t * to clarify the stream that failed.\n> \t */\n> -\tLOG(HAL, Error) << \"Error occurred on frame \" << frameNumber << \" (\"\n> -\t\t\t<< toPixelFormat(stream->format).toString() << \")\";\n> +\tLOG(HAL, Error)\n> +\t\t<< \"Error occurred on frame \" << descriptor.frameNumber_ << \" (\"\n> +\t\t<< toPixelFormat(descriptor.buffers_[0].stream->format).toString() << \")\";\n\nThat's probably a left-over as the patch does not compile with this\nhunk applied\n\nThanks\n j\n\n>\n> \tnotify.type = CAMERA3_MSG_ERROR;\n> \tnotify.message.error.error_stream = stream;\n> diff --git a/src/android/camera_device.h b/src/android/camera_device.h\n> index 95d77890..325fb967 100644\n> --- a/src/android/camera_device.h\n> +++ b/src/android/camera_device.h\n> @@ -125,9 +125,12 @@ private:\n>\n> \tstd::vector streamConfigurations_;\n> \tstd::map formatsMap_;\n> -\tstd::vector streams_;\n>\n> -\tstd::mutex mutex_; /* Protect descriptors_ and requests_. */\n> +\t/* Avoid races by concurrent Camera HAL API calls. */\n> +\tstd::mutex halMutex_;\n> +\n> +\tstd::mutex mutex_; /* Protect streams_, descriptors_ and requests_. */\n> +\tstd::vector streams_;\n> \tstd::map descriptors_;\n> \tstd::map> requests_;\n>\n> --\n> 2.31.1.498.g6c1eba8ee3d-goog\n>\n> _______________________________________________\n> libcamera-devel mailing list\n> libcamera-devel@lists.libcamera.org\n> https://lists.libcamera.org/listinfo/libcamera-devel","headers":{"Return-Path":"","X-Original-To":"parsemail@patchwork.libcamera.org","Delivered-To":"parsemail@patchwork.libcamera.org","Received":["from lancelot.ideasonboard.com (lancelot.ideasonboard.com\n\t[92.243.16.209])\n\tby patchwork.libcamera.org (Postfix) with ESMTPS id 84C3ABDE78\n\tfor ;\n\tMon, 3 May 2021 16:03:31 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id 536FA6890E;\n\tMon, 3 May 2021 18:03:31 +0200 (CEST)","from relay4-d.mail.gandi.net (relay4-d.mail.gandi.net\n\t[217.70.183.196])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id CE538688AE\n\tfor ;\n\tMon, 3 May 2021 18:03:29 +0200 (CEST)","from uno.localdomain (93-34-118-233.ip49.fastwebnet.it\n\t[93.34.118.233]) (Authenticated sender: jacopo@jmondi.org)\n\tby relay4-d.mail.gandi.net (Postfix) with ESMTPSA id 6527AE0009;\n\tMon, 3 May 2021 16:03:29 +0000 (UTC)"],"X-Originating-IP":"93.34.118.233","Date":"Mon, 3 May 2021 18:04:14 +0200","From":"Jacopo Mondi ","To":"Hirokazu Honda ","Message-ID":"<20210503160414.bl5vk7vbrpwxuvae@uno.localdomain>","References":"<20210426083830.2965095-1-hiroh@chromium.org>\n\t<20210426083830.2965095-3-hiroh@chromium.org>","MIME-Version":"1.0","Content-Disposition":"inline","In-Reply-To":"<20210426083830.2965095-3-hiroh@chromium.org>","Subject":"Re: [libcamera-devel] [PATCH v3 2/3] android: CameraDevice: Prevent\n\trace due to concurrent HAL calls","X-BeenThere":"libcamera-devel@lists.libcamera.org","X-Mailman-Version":"2.1.29","Precedence":"list","List-Id":"","List-Unsubscribe":",\n\t","List-Archive":"","List-Post":"","List-Help":"","List-Subscribe":",\n\t","Cc":"libcamera-devel@lists.libcamera.org","Content-Type":"text/plain; charset=\"us-ascii\"","Content-Transfer-Encoding":"7bit","Errors-To":"libcamera-devel-bounces@lists.libcamera.org","Sender":"\"libcamera-devel\" "}},{"id":16853,"web_url":"https://patchwork.libcamera.org/comment/16853/","msgid":"","date":"2021-05-10T06:48:41","subject":"Re: [libcamera-devel] [PATCH v3 2/3] android: CameraDevice: Prevent\n\trace due to concurrent HAL calls","submitter":{"id":63,"url":"https://patchwork.libcamera.org/api/people/63/","name":"Hirokazu Honda","email":"hiroh@chromium.org"},"content":"Hi Jacopo and Laurent, thank you for reviewing.\n\nOn Tue, May 4, 2021 at 1:02 AM Jacopo Mondi wrote:\n\n> Hi Laurent,\n>\n> On Mon, May 03, 2021 at 05:55:38PM +0300, Laurent Pinchart wrote:\n> > Hello,\n> >\n> > On Mon, May 03, 2021 at 04:41:04PM +0200, Jacopo Mondi wrote:\n> > > On Mon, Apr 26, 2021 at 05:38:29PM +0900, Hirokazu Honda wrote:\n> > > > HAL API functions might be called by different threads in Android\n> > > > Camera HAL3 API, while process_capture_request() must be called\n> > > > by a single thread. Furthermore, close() and flush() can be\n> > > > called any time. Therefore, races to variables can occur among\n> > > > the HAL API functions.\n> > > > This prevents the races by enclosing HAL calls by mutex. It\n> > > > might not be the best in terms of the performance, but the\n> > > > simplicity is good as a first step and also further development.\n> > > >\n> > > > Signed-off-by: Hirokazu Honda \n> > > > ---\n> > > > src/android/camera_device.cpp | 59\n> ++++++++++++++++++++---------------\n> > > > src/android/camera_device.h | 7 +++--\n> > > > 2 files changed, 39 insertions(+), 27 deletions(-)\n> > > >\n> > > > diff --git a/src/android/camera_device.cpp\n> b/src/android/camera_device.cpp\n> > > > index b3def04b..96c8d4a9 100644\n> > > > --- a/src/android/camera_device.cpp\n> > > > +++ b/src/android/camera_device.cpp\n> > > > @@ -743,7 +743,7 @@ int CameraDevice::open(const hw_module_t\n> *hardwareModule)\n> > > >\n> > > > void CameraDevice::close()\n> > > > {\n> > > > - streams_.clear();\n> > > > + std::scoped_lock halLock(halMutex_);\n> > >\n> > > Have you considered locking the wrappers functions in camera_ops.cpp ?\n> > > Wouldn't it be simpler ? However locking with such a coarse-grained\n> > > granularity I feel contradicts a bit the Camera3 API flush()\n> > > documentation, which implies that flush() and\n> > > process_capture_request() can race\n> > >\n> > > * Due to\n> > > * concurrency issues, it is possible that from the HAL's point of\n> view, a\n> > > * process_capture_request() call may be started after flush has\n> been invoked but has not\n> > > * returned yet. If such a call happens before flush() returns,\n> the HAL should treat the new\n> > > * capture request like other in-flight pending requests (see #4\n> below).\n> > >\n> > > Locking at function level rules out this use case: if we lock each\n> > > function it's not possible for process_capture_request() to be started\n> > > during flush() execution as the lock hold by flush will be released\n> > > only at exit time.\n> > >\n> > > If serializing operations with this granularity is fine (and I really\n> > > with it is, as it would really simplify life for use)\n> >\n> > I think it is as an initial step, but likely not in the longer term. It\n> > defeats the point of having the camera service issue\n> > process_capture_request() and stop()/flush() calls concurrently. If\n>\n> Yes, that was my concern, although the documentation says it's enough\n> to implement the full success/full fail behavior which I think it's\n> what's happening here.\n>\n> serializing operations was good enough in every case, it would be done\n> > in the camera service itself, and HAL implementations wouldn't need to\n> > deal with this.\n>\n> Also true, indeed the framework allows to implement a finer granularity\n> in locking the operations\n>\n>\nSince ChromeOS camera services sealizes the calls, ChromeOS doesn't\nrequire this serialization here.\nBut shall we assume that a HAL client serializes the call? Since this is a\nHAL implementation, I think we should align the HAL specification; no\nserialization is ensured.\n\n\n> >\n> > > the only racing\n> > > condition we have to protect from is between the request completion\n> > > signal emitted by libcamera, and the camera framework calling into the\n> > > Camera HAL using the camera3 API as flush(), close() and\n> > > process_capture_request() will always be serialized.\n> > >\n> > > Assuming the above is ok with the Camera3 API, isn't it enough to\n> > >\n> > > - flush() to call stop() and stop the Camera:\n> > > - All queued requests at the time Camera::stop() is called\n> > > will be returned one by one with an error state. There's no\n> > > reason to cancel the descriptors at stop() time, those\n> > > requests will be completed\n> > >\n>\n\nThat's correct. Well, I would do so just in case to ensure all requests are\nreturned before flush().\nBut it should be unnecessary.\n\n\n> > > - A process_capture_request() called after flush() has stopped\n> > > the camera will return immeditely as the camera is stopped\n> > > and the capture request is returned with an error\n> > > (we might want a flag to keep track of this, otherwise we'll\n> > > hit a Camera state machine error, much like we do with\n> > > running_)\n> > >\n>\n\nHmm, in my understanding, the process_capture_request() should re-start the\ncamera as it is a usual request.\nWhy do you think so?\n\n\n> > > - A close() called after flush() will be a no op\n> >\n> > So far it seems fine to me.\n>\n\nThe critical difference between close() and flush() is whether a camera is\nheld or not, isn't it?\nThat is, Camera::release() is called or not.\nI agree almost all is done by the preceding flush(), so close() called\nafter flush() will just call Camera::release().\nHow do you think?\n\n\n> >\n> > > - Only open() will allow the CameraDevice to move back from\n> > > stopped_ state\n> >\n> > That's correct for close(). For flush(), we can to make sure that a\n> > configureStreams() call will reopen the camera.\n>\n> Right, it's probably enough to just reset the state of the new flag in\n> configureStreams() and return immediately from\n> processCaptureRequest().\n>\n> My main point should have been that processCaptureRequest() cannot be\n> called after a flush() without going through configureStreams() ?\n>\n> Maybe not true however, considering:\n>\n> * flush() should only return when there are no more outstanding\n> buffers or\n> * requests left in the HAL. The framework may call configure_streams\n> (as\n> * the HAL state is now quiesced) or may issue new requests.\n>\n> Which seems to suggest after a flush, processCaptureRequest() can be\n> called again.\n>\n>\nYeah, from this, I think we should re-open camera in the first\nprocess_capture_request() after flush() has been called.\n\n\n> >\n> > > - There's a tiny tiny window where a request can complete after flush\n> > > has been called but the camera has not been stopped yet. In\n> >\n> > It's not that tiny, it can certainly be hit in practice.\n> >\n> > > requestComplete() we'll have to inspect the stopped_ flag state and\n> > > force the request to return with error even if it did not.\n> >\n> > Why can't we complete the request without any error in that case ?\n>\n> Because flush() has been called already (but the camera has not\n> stopped yet?)\n>\n> Although the documentation reports\n>\n> * 1. For captures that are too late for the HAL to cancel/stop, and\n> will be\n> * completed normally by the HAL; i.e. the HAL can send\n> shutter/notify and\n> * process_capture_result and buffers as normal.\n>\n> It's then probably fine to let those requests just complete\n> successfully (even better, it's easier)\n>\n>\nCamera::stop() is a blocking function and calls requestComplete() with all\nthe pending requests?\nIn that case, a return request is marked with CANCELLED or if the buffer is\nalready complete, marked with COMPLETE.\nWell, ideally, so that we should not execute a post-processing during flush\nand a thread should be separated for the post processing, we should\nintroduce a way of detecting that flush is being called in\nrequestComplete().\n\n\n> >\n> > > - Once we move JPEG encoding to a worker thread, stop() will have to\n> > > forcefully stop it. Requests interrupted during encoding will be\n> > > returned with error.\n> > >\n> > > A simple lock around stopped_ should protect it from concurrent\n> > > accesses between stop() and requestComplete().\n> >\n> > The issue is that the flush() function must wait for all requests to\n> > complete. This could be implemented with a condition variable, allowing\n> > to avoid serializing CameraDevice::requestComplete() with the API calls\n> > from the camera service. I think that would be better indeed.\n>\n> Ah yes, I overlooked this part\n>\n> * flush() should only return when there are no more outstanding\n> buffers or\n> * requests left in the HAL.\n>\n> Actually with a condition variable it might also get easier, as\n>\n> flush() {\n> {\n> /* mutex lock *\n> flushing_ = true;\n> }\n>\n> stop()\n>\n> flushed.wait()\n> {\n> /* mutex lock *\n> flushing_ = false;\n> }\n> }\n>\n>\nThe difficult point is with this other HAL calls (e.g.\nprocess_capture_request() and stop()) can be called during stop().\nWe can protect it with flushing_. But I think it should be simplified by\nguarding two mutexes as this patch does.\n\n\n> Would allow to held the flushing_ state until all the pending requests\n> have been returned as a consequence of stop(). Once that's done we can\n> reset the flushing_ flag, and the next processCaptureRequest() can\n> continue as normal ?\n>\n>\nYes, I did so in this patch series though without flushing_, but with a new\nmutex.\n\n\n> Do we have a list of CTS or cros_camera_test that exercizes flush() to\n> be used as validation ?\n>\n>\nI think CTS doesn't detect the issue.\n\n\n> I've tried with this series applied:\n>\n> # cros_camera_test\n> --gtest_filter=\"Camera3FrameTest/Camera3FlushRequestsTest*\"\n> [ PASSED ] 4 tests.\n> [ FAILED ] 8 tests, listed below\n>\n> Which is the same result I get on the most recent master..\n>\n>\nYou need 1954 and 1967 to pass the test.\n\nThanks,\n-Hiro\n\n\n> Thanks\n> j\n>\n> > > Have you considered this option and ruled it out for reasons I'm\n> > > failing to consider ? It feels simpler than decoupling requests and\n> > > descriptors, maybe you tried and found out it's not :)\n> > >\n> > > > stop();\n> > > >\n> > > > @@ -758,12 +758,17 @@ void CameraDevice::stop()\n> > > > worker_.stop();\n> > > > camera_->stop();\n> > > >\n> > > > - descriptors_.clear();\n> > > > + {\n> > > > + std::scoped_lock lock(mutex_);\n> > > > + descriptors_.clear();\n> > > > + }\n> > > > +\n> > > > running_ = false;\n> > > > }\n> > > >\n> > > > void CameraDevice::setCallbacks(const camera3_callback_ops_t\n> *callbacks)\n> > > > {\n> > > > + std::scoped_lock halLock(halMutex_);\n> > > > callbacks_ = callbacks;\n> > > > }\n> > > >\n> > > > @@ -1643,8 +1648,7 @@ PixelFormat CameraDevice::toPixelFormat(int\n> format) const\n> > > > */\n> > > > int CameraDevice::configureStreams(camera3_stream_configuration_t\n> *stream_list)\n> > > > {\n> > > > - /* Before any configuration attempt, stop the camera. */\n> > > > - stop();\n> > > > + std::scoped_lock halLock(halMutex_);\n> > > >\n> > > > if (stream_list->num_streams == 0) {\n> > > > LOG(HAL, Error) << \"No streams in configuration\";\n> > > > @@ -1656,6 +1660,9 @@ int\n> CameraDevice::configureStreams(camera3_stream_configuration_t *stream_list)\n> > > > return -EINVAL;\n> > > > #endif\n> > > >\n> > > > + /* Before any configuration attempt, stop the camera. */\n> > > > + stop();\n> > > > +\n> > > > /*\n> > > > * Generate an empty configuration, and construct a\n> StreamConfiguration\n> > > > * for each camera3_stream to add to it.\n> > > > @@ -1671,6 +1678,8 @@ int\n> CameraDevice::configureStreams(camera3_stream_configuration_t *stream_list)\n> > > > * ensure the required entries are available without further\n> > > > * reallocation.\n> > > > */\n> > > > +\n> > > > + std::scoped_lock lock(mutex_);\n> > > > streams_.clear();\n> > > > streams_.reserve(stream_list->num_streams);\n> > > >\n> > > > @@ -1907,6 +1916,8 @@ int\n> CameraDevice::processCaptureRequest(camera3_capture_request_t *camera3Reques\n> > > > if (!isValidRequest(camera3Request))\n> > > > return -EINVAL;\n> > > >\n> > > > + std::scoped_lock halLock(halMutex_);\n> > > > +\n> > > > /* Start the camera if that's the first request we handle. */\n> > > > if (!running_) {\n> > > > worker_.start();\n> > > > @@ -2022,29 +2033,26 @@ int\n> CameraDevice::processCaptureRequest(camera3_capture_request_t *camera3Reques\n> > > >\n> > > > void CameraDevice::requestComplete(Request *request)\n> > > > {\n> > > > + std::scoped_lock lock(mutex_);\n> > > > +\n> > > > const Request::BufferMap &buffers = request->buffers();\n> > > > camera3_buffer_status status = CAMERA3_BUFFER_STATUS_OK;\n> > > > std::unique_ptr resultMetadata;\n> > > >\n> > > > - decltype(descriptors_)::node_type node;\n> > > > - std::unique_ptr captureRequest;\n> > > > - {\n> > > > - std::scoped_lock lock(mutex_);\n> > > > - auto requestIt = requests_.find(request->cookie());\n> > > > - if (requestIt == requests_.end()) {\n> > > > - LOG(HAL, Fatal)\n> > > > - << \"Unknown request: \" <<\n> request->cookie();\n> > > > - return;\n> > > > - }\n> > > > - captureRequest = std::move(requestIt->second);\n> > > > - requests_.erase(requestIt);\n> > > > + auto requestIt = requests_.find(request->cookie());\n> > > > + if (requestIt == requests_.end()) {\n> > > > + LOG(HAL, Fatal)\n> > > > + << \"Unknown request: \" << request->cookie();\n> > > > + return;\n> > > > + }\n> > > > + auto captureRequest = std::move(requestIt->second);\n> > > > + requests_.erase(requestIt);\n> > > >\n> > > > - auto it = descriptors_.find(request->cookie());\n> > > > - if (it == descriptors_.end())\n> > > > - return;\n> > > > + auto it = descriptors_.find(request->cookie());\n> > > > + if (it == descriptors_.end())\n> > > > + return;\n> > > >\n> > > > - node = descriptors_.extract(it);\n> > > > - }\n> > > > + auto node = descriptors_.extract(it);\n> > > > Camera3RequestDescriptor &descriptor = node.mapped();\n> > > >\n> > > > if (request->status() != Request::RequestComplete) {\n> > > > @@ -2149,11 +2157,12 @@ void CameraDevice::notifyError(uint32_t\n> frameNumber, camera3_stream_t *stream)\n> > > > camera3_notify_msg_t notify = {};\n> > > >\n> > > > /*\n> > > > - * \\todo Report and identify the stream number or configuration to\n> > > > - * clarify the stream that failed.\n> > > > + * \\todo Report and identify the stream number or configuration\n> > > > + * to clarify the stream that failed.\n> > > > */\n> > > > - LOG(HAL, Error) << \"Error occurred on frame \" << frameNumber << \"\n> (\"\n> > > > - << toPixelFormat(stream->format).toString() << \")\";\n> > > > + LOG(HAL, Error)\n> > > > + << \"Error occurred on frame \" << descriptor.frameNumber_\n> << \" (\"\n> > > > + <<\n> toPixelFormat(descriptor.buffers_[0].stream->format).toString() << \")\";\n> > > >\n> > > > notify.type = CAMERA3_MSG_ERROR;\n> > > > notify.message.error.error_stream = stream;\n> > > > diff --git a/src/android/camera_device.h\n> b/src/android/camera_device.h\n> > > > index 95d77890..325fb967 100644\n> > > > --- a/src/android/camera_device.h\n> > > > +++ b/src/android/camera_device.h\n> > > > @@ -125,9 +125,12 @@ private:\n> > > >\n> > > > std::vector streamConfigurations_;\n> > > > std::map formatsMap_;\n> > > > - std::vector streams_;\n> > > >\n> > > > - std::mutex mutex_; /* Protect descriptors_ and requests_. */\n> > > > + /* Avoid races by concurrent Camera HAL API calls. */\n> > > > + std::mutex halMutex_;\n> > > > +\n> > > > + std::mutex mutex_; /* Protect streams_, descriptors_ and\n> requests_. */\n> > > > + std::vector streams_;\n> > > > std::map descriptors_;\n> > > > std::map> requests_;\n> > > >\n> >\n> > --\n> > Regards,\n> >\n> > Laurent Pinchart\n>","headers":{"Return-Path":"","X-Original-To":"parsemail@patchwork.libcamera.org","Delivered-To":"parsemail@patchwork.libcamera.org","Received":["from lancelot.ideasonboard.com (lancelot.ideasonboard.com\n\t[92.243.16.209])\n\tby patchwork.libcamera.org (Postfix) with ESMTPS id 3A07FBF831\n\tfor ;\n\tMon, 10 May 2021 06:48:54 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id 70F1C6891B;\n\tMon, 10 May 2021 08:48:53 +0200 (CEST)","from mail-ej1-x62b.google.com (mail-ej1-x62b.google.com\n\t[IPv6:2a00:1450:4864:20::62b])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id 578836153C\n\tfor ;\n\tMon, 10 May 2021 08:48:52 +0200 (CEST)","by mail-ej1-x62b.google.com with SMTP id b25so22795670eju.5\n\tfor ;\n\tSun, 09 May 2021 23:48:52 -0700 (PDT)"],"Authentication-Results":"lancelot.ideasonboard.com;\n\tdkim=fail reason=\"signature verification failed\" (1024-bit key;\n\tunprotected) header.d=chromium.org header.i=@chromium.org\n\theader.b=\"G1Kxo6U0\"; dkim-atps=neutral","DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/relaxed; d=chromium.org;\n\ts=google; \n\th=mime-version:references:in-reply-to:from:date:message-id:subject:to\n\t:cc; bh=HH/wNLz2kx+X4Rwom3KBTX+5sHfVuKL4F7C/FQGLRnM=;\n\tb=G1Kxo6U0qGlqb08RNW1GhYsPdBQBjNOJzJQKTjH2I8vn74aByajw4ELbowUwQRNwTx\n\toL8Ks733gi/HfTCI1Zc5bsY93paMkQHcia/fev2EfQFc455x9TCFJuZprW5b2Lgh021z\n\tInWnFz9Urjcgw5+iodpFbDiQoNZQechRyJR/M=","X-Google-DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/relaxed;\n\td=1e100.net; s=20161025;\n\th=x-gm-message-state:mime-version:references:in-reply-to:from:date\n\t:message-id:subject:to:cc;\n\tbh=HH/wNLz2kx+X4Rwom3KBTX+5sHfVuKL4F7C/FQGLRnM=;\n\tb=U2QIM8Gh46taQT36nemltK0d/OYElmi+uzYDZOAdV8qLgNRdwVGDSPqHXYGxFVv47a\n\tsnld7L9AHUa+7+a1VgBiiBnr7g6ik25I7RhcEFdB7fB4/bQN80IO4yJmRZ6tjlXQxMWU\n\t/CKcEnmLG+oJCoweGUPSM/tgeGhxuC6iE1UW5NrP4zknpKfyJjZSX89yM0DPTYwpeQdf\n\tfH9AqZG2551gZS7GVG6HqZtxEkDmJ+nApKQVhd65FXe77HVfL2r3U8e+61y394mkkkI6\n\tE6kdGm4B1F/t/+Uf1PbQBEdjmHO2R0dMfV7OgZG+/LqAHmx0Wa1kBxO92DbWB8jP+vgd\n\t5jYg==","X-Gm-Message-State":"AOAM530V/mbaCRMvL1WqM9PsZwUzMl0TkkdlI2B15m+yV/Cq+5xrdss/\n\tTwz47AsCHD/sTHTlh6Pkd5dCtsJ0qAGftBMHBntKdg==","X-Google-Smtp-Source":"ABdhPJyCstQcYa0Owec/68aVEF8sLLPdoppITHyj2IojCKHA0YhVpmTc2h/+s5rP5DPzhzppxRTUtf5DojICyya1Dvs=","X-Received":"by 2002:a17:907:a044:: with SMTP id\n\tgz4mr24336185ejc.55.1620629331963; \n\tSun, 09 May 2021 23:48:51 -0700 (PDT)","MIME-Version":"1.0","References":"<20210426083830.2965095-1-hiroh@chromium.org>\n\t<20210426083830.2965095-3-hiroh@chromium.org>\n\t<20210503144104.rjqq2b7fyvodrina@uno.localdomain>\n\t\n\t<20210503160251.6q5cqpoyfnjsciw4@uno.localdomain>","In-Reply-To":"<20210503160251.6q5cqpoyfnjsciw4@uno.localdomain>","From":"Hirokazu Honda ","Date":"Mon, 10 May 2021 15:48:41 +0900","Message-ID":"","To":"Jacopo Mondi ","Subject":"Re: [libcamera-devel] [PATCH v3 2/3] android: CameraDevice: Prevent\n\trace due to concurrent HAL calls","X-BeenThere":"libcamera-devel@lists.libcamera.org","X-Mailman-Version":"2.1.29","Precedence":"list","List-Id":"","List-Unsubscribe":",\n\t","List-Archive":"","List-Post":"","List-Help":"","List-Subscribe":",\n\t","Cc":"libcamera devel ","Content-Type":"multipart/mixed;\n\tboundary=\"===============4248931945597527141==\"","Errors-To":"libcamera-devel-bounces@lists.libcamera.org","Sender":"\"libcamera-devel\" "}}]