[{"id":13541,"web_url":"https://patchwork.libcamera.org/comment/13541/","msgid":"<20201028233723.GB10030@pendragon.ideasonboard.com>","date":"2020-10-28T23:37:23","subject":"Re: [libcamera-devel] [PATCH v2 2/6] libcamera: request: Add\n\ttracepoints","submitter":{"id":2,"url":"https://patchwork.libcamera.org/api/people/2/","name":"Laurent Pinchart","email":"laurent.pinchart@ideasonboard.com"},"content":"Hi Paul,\n\nThank you for the patch.\n\nOn Wed, Oct 28, 2020 at 07:31:47PM +0900, Paul Elder wrote:\n> Add and use tracepoints in Request.\n\nA rationale would be useful here. It can probably be as simple as\nexplaining that requests are core to libcamera operation, that detecting\ndelays in their processing is important, and that this thus serves as a\ngood usage example of tracepoints.\n\n> Signed-off-by: Paul Elder \n> \n> ---\n> Changes in v2:\n> - remove tracepoints from uvcvideo\n> - remove comment in changelog that this is only used for demonstration\n> - use Request pointers instead of feeding the fields manually to the\n> tracepoint\n> ---\n> .../internal/tracepoints/meson.build | 1 +\n> .../libcamera/internal/tracepoints/request.tp | 85 +++++++++++++++++++\n> src/libcamera/request.cpp | 15 ++++\n> 3 files changed, 101 insertions(+)\n> create mode 100644 include/libcamera/internal/tracepoints/request.tp\n> \n> diff --git a/include/libcamera/internal/tracepoints/meson.build b/include/libcamera/internal/tracepoints/meson.build\n> index 2dd6733e..8410c205 100644\n> --- a/include/libcamera/internal/tracepoints/meson.build\n> +++ b/include/libcamera/internal/tracepoints/meson.build\n> @@ -1,4 +1,5 @@\n> # SPDX-License-Identifier: CC0-1.0\n> \n> tracepoint_files = files([\n> + 'request.tp',\n> ])\n> diff --git a/include/libcamera/internal/tracepoints/request.tp b/include/libcamera/internal/tracepoints/request.tp\n> new file mode 100644\n> index 00000000..481a3670\n> --- /dev/null\n> +++ b/include/libcamera/internal/tracepoints/request.tp\n> @@ -0,0 +1,85 @@\n> +#include \n> +\n> +TRACEPOINT_EVENT_CLASS(\n> +\tlibcamera,\n> +\trequest,\n> +\tTP_ARGS(\n> +\t\tlibcamera::Request *, req,\n> +\t\tint, cancelled\n\nI suppose the reason why you can't use req->cancelled_ is because it's\nprivate ? I wonder if it's a useful field, given that it's only set in\nRequest::completeBuffer(), and after that it influences status_ in\nRequest::complete(), and status_ captured through req->status() below.\nI'd drop it, and instead create another event for\nRequest::completeBuffer() that takes the buffer status as an additional\nargument.\n\n> +\t),\n> +\tTP_FIELDS(\n> +\t\tctf_integer(uint64_t, cookie, req->cookie())\n> +\t\tctf_integer(int, status, req->status())\n\nOh, that's interesting.\n\nThis means that only the cookie and status (and cancelled below) are\nrecorded by the trace, right ?\n\n> +\t\tctf_integer(int, cancelled, cancelled)\n> +\t)\n> +)\n> +\n> +TRACEPOINT_EVENT_INSTANCE(\n> +\tlibcamera,\n> +\trequest,\n> +\trequest_construct,\n> +\tTP_ARGS(\n> +\t\tlibcamera::Request *, req,\n> +\t\tint, cancelled\n> +\t)\n> +)\n> +\n> +TRACEPOINT_EVENT_INSTANCE(\n> +\tlibcamera,\n> +\trequest,\n> +\trequest_deconstruct,\n\nI'd name this request_destroy as C++ has destructors.\n\n> +\tTP_ARGS(\n> +\t\tlibcamera::Request *, req,\n> +\t\tint, cancelled\n> +\t)\n> +)\n> +\n> +TRACEPOINT_EVENT_INSTANCE(\n> +\tlibcamera,\n> +\trequest,\n> +\trequest_reuse,\n> +\tTP_ARGS(\n> +\t\tlibcamera::Request *, req,\n> +\t\tint, cancelled\n> +\t)\n> +)\n> +\n> +TRACEPOINT_EVENT_INSTANCE(\n> +\tlibcamera,\n> +\trequest,\n> +\trequest_add_buffer,\n> +\tTP_ARGS(\n> +\t\tlibcamera::Request *, req,\n> +\t\tint, cancelled\n> +\t)\n> +)\n> +\n> +TRACEPOINT_EVENT_INSTANCE(\n> +\tlibcamera,\n> +\trequest,\n> +\trequest_find_buffer,\n> +\tTP_ARGS(\n> +\t\tconst libcamera::Request *, req,\n> +\t\tint, cancelled\n> +\t)\n> +)\n\nI'd drop those two for now, I don't think they're really useful to trace\nrequest timings.\n\n> +\n> +TRACEPOINT_EVENT_INSTANCE(\n> +\tlibcamera,\n> +\trequest,\n> +\trequest_complete,\n> +\tTP_ARGS(\n> +\t\tlibcamera::Request *, req,\n> +\t\tint, cancelled\n> +\t)\n> +)\n> +\n> +TRACEPOINT_EVENT_INSTANCE(\n> +\tlibcamera,\n> +\trequest,\n> +\trequest_complete_buffer,\n> +\tTP_ARGS(\n> +\t\tlibcamera::Request *, req,\n> +\t\tint, cancelled\n> +\t)\n> +)\n\nThis one I think is useful, but I wonder if we shouldn't add information\nabout the buffer being completed to make real use of it. The buffer\nstatus immediately come to mind, identifying the buffer would also be\nuseful I think. The second point can be addressed later.\n\n> diff --git a/src/libcamera/request.cpp b/src/libcamera/request.cpp\n> index ae8b1660..bec2cab5 100644\n> --- a/src/libcamera/request.cpp\n> +++ b/src/libcamera/request.cpp\n> @@ -16,6 +16,7 @@\n> \n> #include \"libcamera/internal/camera_controls.h\"\n> #include \"libcamera/internal/log.h\"\n> +#include \"libcamera/internal/tracepoints.h\"\n> \n> /**\n> * \\file request.h\n> @@ -85,10 +86,14 @@ Request::Request(Camera *camera, uint64_t cookie)\n> \t * \\todo: Add a validator for metadata controls.\n> \t */\n> \tmetadata_ = new ControlList(controls::controls);\n> +\n> +\tLIBCAMERA_TRACEPOINT(request_construct, this, cancelled_);\n> }\n> \n> Request::~Request()\n> {\n> +\tLIBCAMERA_TRACEPOINT(request_deconstruct, this, cancelled_);\n> +\n> \tdelete metadata_;\n> \tdelete controls_;\n> \tdelete validator_;\n> @@ -106,6 +111,8 @@ Request::~Request()\n> */\n> void Request::reuse(ReuseFlag flags)\n> {\n> +\tLIBCAMERA_TRACEPOINT(request_reuse, this, cancelled_);\n> +\n> \tpending_.clear();\n> \tif (flags & ReuseBuffers) {\n> \t\tfor (auto pair : bufferMap_) {\n> @@ -167,6 +174,8 @@ void Request::reuse(ReuseFlag flags)\n> */\n> int Request::addBuffer(const Stream *stream, FrameBuffer *buffer)\n> {\n> +\tLIBCAMERA_TRACEPOINT(request_add_buffer, this, cancelled_);\n> +\n> \tif (!stream) {\n> \t\tLOG(Request, Error) << \"Invalid stream reference\";\n> \t\treturn -EINVAL;\n> @@ -202,6 +211,8 @@ int Request::addBuffer(const Stream *stream, FrameBuffer *buffer)\n> */\n> FrameBuffer *Request::findBuffer(const Stream *stream) const\n> {\n> +\tLIBCAMERA_TRACEPOINT(request_find_buffer, this, cancelled_);\n> +\n> \tconst auto it = bufferMap_.find(stream);\n> \tif (it == bufferMap_.end())\n> \t\treturn nullptr;\n> @@ -253,6 +264,8 @@ FrameBuffer *Request::findBuffer(const Stream *stream) const\n> */\n> void Request::complete()\n> {\n> +\tLIBCAMERA_TRACEPOINT(request_complete, this, cancelled_);\n> +\n\nI'd move this after status_ to capture the correct status.\n\nReviewed-by: Laurent Pinchart \n\n> \tASSERT(!hasPendingBuffers());\n> \tstatus_ = cancelled_ ? RequestCancelled : RequestComplete;\n> \n> @@ -276,6 +289,8 @@ void Request::complete()\n> */\n> bool Request::completeBuffer(FrameBuffer *buffer)\n> {\n> +\tLIBCAMERA_TRACEPOINT(request_complete_buffer, this, cancelled_);\n> +\n> \tint ret = pending_.erase(buffer);\n> \tASSERT(ret == 1);\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 CA055C3B5C\n\tfor ;\n\tWed, 28 Oct 2020 23:38:14 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id 3010362825;\n\tThu, 29 Oct 2020 00:38:14 +0100 (CET)","from perceval.ideasonboard.com (perceval.ideasonboard.com\n\t[213.167.242.64])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id 5D178627A2\n\tfor ;\n\tThu, 29 Oct 2020 00:38:12 +0100 (CET)","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 C8070576;\n\tThu, 29 Oct 2020 00:38:11 +0100 (CET)"],"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=\"e7qHdn/M\"; dkim-atps=neutral","DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/simple; d=ideasonboard.com;\n\ts=mail; t=1603928292;\n\tbh=ixOspaWWypgGjMH4CAbHX69ueuDGvqDF6BRnLOyUuDY=;\n\th=Date:From:To:Cc:Subject:References:In-Reply-To:From;\n\tb=e7qHdn/MtmjX2Va4xO8NuJv0LzH93r9vuH++ea97qdcJogTQg4FofUE81cSHrppnu\n\tGFbw208TPBeS7DTLkr82+lWOY0ATfwTLGuOn2xnIcqJ0go5CSN9WFhRnlV0uPguJr/\n\tMxgfRTJNIobwsK7u91Ny03WEfRWzrvkqQXlA089E=","Date":"Thu, 29 Oct 2020 01:37:23 +0200","From":"Laurent Pinchart ","To":"Paul Elder ","Message-ID":"<20201028233723.GB10030@pendragon.ideasonboard.com>","References":"<20201028103151.34575-1-paul.elder@ideasonboard.com>\n\t<20201028103151.34575-2-paul.elder@ideasonboard.com>","MIME-Version":"1.0","Content-Disposition":"inline","In-Reply-To":"<20201028103151.34575-2-paul.elder@ideasonboard.com>","Subject":"Re: [libcamera-devel] [PATCH v2 2/6] libcamera: request: Add\n\ttracepoints","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\" "}}]