libcamera: Improve Request life cycle tracking

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 <niklas.soderlund@ragnatech.se>
Reviewed-by: Paul Elder <paul.elder@ideasonboard.com>
Signed-off-by: Jacopo Mondi <jacopo@jmondi.org>
This commit is contained in:
Jacopo Mondi 2021-01-28 09:58:06 +01:00
parent 3e952cfb0f
commit bc6440792b
3 changed files with 8 additions and 2 deletions

View file

@ -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.