From bc6440792bbae533a4f9a5837dbed628ec664cc4 Mon Sep 17 00:00:00 2001 From: Jacopo Mondi Date: Thu, 28 Jan 2021 09:58:06 +0100 Subject: libcamera: Improve Request life cycle tracking MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The current logging to track the status of a Request when running the Android camera HAL provide the following information: When a Request is queued to libcamera: HAL camera_device.cpp:1776 '\_SB_.PCI0.I2C2.CAM0': Queueing Request to libcamera with 1 HAL streams When a Request completes: Request request.cpp:268 Request has completed - cookie: 138508601719648 The queueing of a Request reports the number of streams it contains while the completion of a Request reports the address of the associated cookie. This makes very hard to keep track of what Requests have completed, as the logging associated with a queue/complete event does not allow to identify a Request easily. Add two more printouts to make it easier to track a Request life cycle. To make it possible to print the Request cookie in the CameraDevice class add a method to access it from the CameraRequest class. The result looks like the following trace: Request request.cpp:92 Created request - cookie: 140701719392768 HAL camera_device.cpp:1710 '\_SB_.PCI0.I2C2.CAM0': Queueing request 140701719392768 with 1 streams HAL camera_device.cpp:1747 '\_SB_.PCI0.I2C2.CAM0': 0 - (4160x3104)[0x00000023] -> (4160x3104)[NV12] (direct) ... Request request.cpp:268 Request has completed - cookie: 140701719392768 HAL camera_device.cpp:1800 '\_SB_.PCI0.I2C2.CAM0': Request 140701719392768 completed with 1 streams.. Reviewed-by: Niklas Söderlund Reviewed-by: Paul Elder Signed-off-by: Jacopo Mondi --- src/android/camera_device.cpp | 7 +++++-- src/android/camera_worker.h | 1 + src/libcamera/request.cpp | 2 ++ 3 files changed, 8 insertions(+), 2 deletions(-) diff --git a/src/android/camera_device.cpp b/src/android/camera_device.cpp index 14e4853e..a50b0ebf 100644 --- a/src/android/camera_device.cpp +++ b/src/android/camera_device.cpp @@ -1716,8 +1716,8 @@ int CameraDevice::processCaptureRequest(camera3_capture_request_t *camera3Reques else descriptor->settings_ = lastSettings_; - LOG(HAL, Debug) << "Queueing Request to libcamera with " - << descriptor->numBuffers_ << " HAL streams"; + LOG(HAL, Debug) << "Queueing request " << descriptor->request_->cookie() + << " with " << descriptor->numBuffers_ << " streams"; for (unsigned int i = 0; i < descriptor->numBuffers_; ++i) { const camera3_stream_buffer_t *camera3Buffer = &descriptor->buffers_[i]; camera3_stream *camera3Stream = camera3Buffer->stream; @@ -1806,6 +1806,9 @@ void CameraDevice::requestComplete(Request *request) status = CAMERA3_BUFFER_STATUS_ERROR; } + LOG(HAL, Debug) << "Request " << request->cookie() << " completed with " + << descriptor->numBuffers_ << " streams"; + /* * \todo The timestamp used for the metadata is currently always taken * from the first buffer (which may be the first stream) in the Request. diff --git a/src/android/camera_worker.h b/src/android/camera_worker.h index 6522f1d6..d7060576 100644 --- a/src/android/camera_worker.h +++ b/src/android/camera_worker.h @@ -30,6 +30,7 @@ public: { return request_->metadata(); } + unsigned long cookie() const { return request_->cookie(); } void addBuffer(libcamera::Stream *stream, libcamera::FrameBuffer *buffer, int fence); diff --git a/src/libcamera/request.cpp b/src/libcamera/request.cpp index a68684ef..e561ce1d 100644 --- a/src/libcamera/request.cpp +++ b/src/libcamera/request.cpp @@ -88,6 +88,8 @@ Request::Request(Camera *camera, uint64_t cookie) metadata_ = new ControlList(controls::controls); LIBCAMERA_TRACEPOINT(request_construct, this); + + LOG(Request, Debug) << "Created request - cookie: " << cookie_; } Request::~Request() -- cgit v1.2.1