{"id":11103,"url":"https://patchwork.libcamera.org/api/1.1/patches/11103/?format=json","web_url":"https://patchwork.libcamera.org/patch/11103/","project":{"id":1,"url":"https://patchwork.libcamera.org/api/1.1/projects/1/?format=json","name":"libcamera","link_name":"libcamera","list_id":"libcamera_core","list_email":"libcamera-devel@lists.libcamera.org","web_url":"","scm_url":"","webscm_url":""},"msgid":"<20210202115530.40145-1-jacopo@jmondi.org>","date":"2021-02-02T11:55:30","name":"[libcamera-devel,v2] libcamera: Improve Request life cycle tracking","commit_ref":null,"pull_url":null,"state":"accepted","archived":false,"hash":"a74143a179f6a85478f48aae380569adcd8e6ff2","submitter":{"id":3,"url":"https://patchwork.libcamera.org/api/1.1/people/3/?format=json","name":"Jacopo Mondi","email":"jacopo@jmondi.org"},"delegate":null,"mbox":"https://patchwork.libcamera.org/patch/11103/mbox/","series":[{"id":1636,"url":"https://patchwork.libcamera.org/api/1.1/series/1636/?format=json","web_url":"https://patchwork.libcamera.org/project/libcamera/list/?series=1636","date":"2021-02-02T11:55:30","name":"[libcamera-devel,v2] libcamera: Improve Request life cycle tracking","version":2,"mbox":"https://patchwork.libcamera.org/series/1636/mbox/"}],"comments":"https://patchwork.libcamera.org/api/patches/11103/comments/","check":"pending","checks":"https://patchwork.libcamera.org/api/patches/11103/checks/","tags":{},"headers":{"Return-Path":"<libcamera-devel-bounces@lists.libcamera.org>","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 56AFFBD160\n\tfor <parsemail@patchwork.libcamera.org>;\n\tTue,  2 Feb 2021 11:55:15 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id DE76168424;\n\tTue,  2 Feb 2021 12:55:14 +0100 (CET)","from relay10.mail.gandi.net (relay10.mail.gandi.net\n\t[217.70.178.230])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id 65C7060307\n\tfor <libcamera-devel@lists.libcamera.org>;\n\tTue,  2 Feb 2021 12:55:13 +0100 (CET)","from uno.LocalDomain (93-61-96-190.ip145.fastwebnet.it\n\t[93.61.96.190]) (Authenticated sender: jacopo@jmondi.org)\n\tby relay10.mail.gandi.net (Postfix) with ESMTPSA id 9610D240006;\n\tTue,  2 Feb 2021 11:55:12 +0000 (UTC)"],"From":"Jacopo Mondi <jacopo@jmondi.org>","To":"libcamera-devel@lists.libcamera.org","Date":"Tue,  2 Feb 2021 12:55:30 +0100","Message-Id":"<20210202115530.40145-1-jacopo@jmondi.org>","X-Mailer":"git-send-email 2.30.0","MIME-Version":"1.0","Subject":"[libcamera-devel] [PATCH v2] libcamera: Improve Request life cycle\n\ttracking","X-BeenThere":"libcamera-devel@lists.libcamera.org","X-Mailman-Version":"2.1.29","Precedence":"list","List-Id":"<libcamera-devel.lists.libcamera.org>","List-Unsubscribe":"<https://lists.libcamera.org/options/libcamera-devel>,\n\t<mailto:libcamera-devel-request@lists.libcamera.org?subject=unsubscribe>","List-Archive":"<https://lists.libcamera.org/pipermail/libcamera-devel/>","List-Post":"<mailto:libcamera-devel@lists.libcamera.org>","List-Help":"<mailto:libcamera-devel-request@lists.libcamera.org?subject=help>","List-Subscribe":"<https://lists.libcamera.org/listinfo/libcamera-devel>,\n\t<mailto:libcamera-devel-request@lists.libcamera.org?subject=subscribe>","Content-Type":"text/plain; charset=\"utf-8\"","Content-Transfer-Encoding":"base64","Errors-To":"libcamera-devel-bounces@lists.libcamera.org","Sender":"\"libcamera-devel\" <libcamera-devel-bounces@lists.libcamera.org>"},"content":"The current logging to track the status of a Request when running the\nAndroid camera HAL provide the following information:\n\nWhen a Request is queued to libcamera:\nHAL camera_device.cpp:1776 '\\_SB_.PCI0.I2C2.CAM0': Queueing Request to libcamera with 1 HAL streams\n\nWhen a Request completes:\nRequest request.cpp:268 Request has completed - cookie: 138508601719648\n\nThe queueing of a Request reports the number of streams it contains\nwhile the completion of a Request reports the address of the associated\ncookie.\n\nThis makes very hard to keep track of what Requests have completed, as\nthe logging associated with a queue/complete event does not allow to identify\na Request easily.\n\nAdd two more printouts to make it easier to track a Request life cycle.\nTo make it possible to print the Request cookie in the CameraDevice\nclass add a method to access it from the CameraRequest class.\n\nThe result looks like the following trace:\n\nRequest request.cpp:92 Created request - cookie: 140701719392768\nHAL camera_device.cpp:1710 '\\_SB_.PCI0.I2C2.CAM0': Queueing request 140701719392768 with 1 streams\nHAL camera_device.cpp:1747 '\\_SB_.PCI0.I2C2.CAM0': 0 - (4160x3104)[0x00000023] -> (4160x3104)[NV12] (direct)\n...\nRequest request.cpp:268 Request has completed - cookie: 140701719392768\nHAL camera_device.cpp:1800 '\\_SB_.PCI0.I2C2.CAM0': Request 140701719392768 completed with 1 streams..\n\nReviewed-by: Niklas Söderlund <niklas.soderlund@ragnatech.se>\nReviewed-by: Paul Elder <paul.elder@ideasonboard.com>\nSigned-off-by: Jacopo Mondi <jacopo@jmondi.org>\n---\n src/android/camera_device.cpp | 7 +++++--\n src/android/camera_worker.h   | 1 +\n src/libcamera/request.cpp     | 2 ++\n 3 files changed, 8 insertions(+), 2 deletions(-)\n\n--\n2.30.0","diff":"diff --git a/src/android/camera_device.cpp b/src/android/camera_device.cpp\nindex c1025e812e5e..82479ad88f91 100644\n--- a/src/android/camera_device.cpp\n+++ b/src/android/camera_device.cpp\n@@ -1707,8 +1707,8 @@ int CameraDevice::processCaptureRequest(camera3_capture_request_t *camera3Reques\n \telse\n \t\tdescriptor->settings_ = lastSettings_;\n\n-\tLOG(HAL, Debug) << \"Queueing Request to libcamera with \"\n-\t\t\t<< descriptor->numBuffers_ << \" HAL streams\";\n+\tLOG(HAL, Debug) << \"Queueing request \" << descriptor->request_->cookie()\n+\t\t\t<< \" with \" << descriptor->numBuffers_ << \" streams\";\n \tfor (unsigned int i = 0; i < descriptor->numBuffers_; ++i) {\n \t\tconst camera3_stream_buffer_t *camera3Buffer = &descriptor->buffers_[i];\n \t\tcamera3_stream *camera3Stream = camera3Buffer->stream;\n@@ -1797,6 +1797,9 @@ void CameraDevice::requestComplete(Request *request)\n \t\tstatus = CAMERA3_BUFFER_STATUS_ERROR;\n \t}\n\n+\tLOG(HAL, Debug) << \"Request \" << request->cookie() << \" completed with \"\n+\t\t\t<< descriptor->numBuffers_ << \" streams\";\n+\n \t/*\n \t * \\todo The timestamp used for the metadata is currently always taken\n \t * from the first buffer (which may be the first stream) in the Request.\ndiff --git a/src/android/camera_worker.h b/src/android/camera_worker.h\nindex 6522f1d68a20..d70605761509 100644\n--- a/src/android/camera_worker.h\n+++ b/src/android/camera_worker.h\n@@ -30,6 +30,7 @@ public:\n \t{\n \t\treturn request_->metadata();\n \t}\n+\tunsigned long cookie() const { return request_->cookie(); }\n\n \tvoid addBuffer(libcamera::Stream *stream,\n \t\t       libcamera::FrameBuffer *buffer, int fence);\ndiff --git a/src/libcamera/request.cpp b/src/libcamera/request.cpp\nindex a68684ef9fd3..e561ce1d5d0e 100644\n--- a/src/libcamera/request.cpp\n+++ b/src/libcamera/request.cpp\n@@ -88,6 +88,8 @@ Request::Request(Camera *camera, uint64_t cookie)\n \tmetadata_ = new ControlList(controls::controls);\n\n \tLIBCAMERA_TRACEPOINT(request_construct, this);\n+\n+\tLOG(Request, Debug) << \"Created request - cookie: \" << cookie_;\n }\n\n Request::~Request()\n","prefixes":["libcamera-devel","v2"]}