[{"id":16392,"web_url":"https://patchwork.libcamera.org/comment/16392/","msgid":"","date":"2021-04-20T17:26:47","subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","submitter":{"id":75,"url":"https://patchwork.libcamera.org/api/people/75/","name":"Jean-Michel Hautbois","email":"jeanmichel.hautbois@ideasonboard.com"},"content":"Hi Kieran,\n\nThanks for the patch !\n\nOn 20/04/2021 15:07, Kieran Bingham wrote:\n> Report the function which fails an assertion as well as the actual\n> assertion.\n> \n> This now reports as:\n> \n> [30:08:53.218816270] [226567] FATAL default request.cpp:150 assertion \"d\" failed in reuse()\n> rather than:\n> [30:11:05.271888926] [228531] FATAL default request.cpp:150 assertion \"d\" failed\n> \n> Signed-off-by: Kieran Bingham \n> \nReviewed-by: Jean-Michel Hautbois \n> ---\n> We could use __PRETTY_FUNCTION__ instead to get:\n> [30:17:16.736265045] [232054] FATAL default request.cpp:150 assertion \"d\" failed in void libcamera::Request::reuse(libcamera::Request::ReuseFlag)\n> \n> include/libcamera/internal/log.h | 7 ++++---\n> 1 file changed, 4 insertions(+), 3 deletions(-)\n> \n> diff --git a/include/libcamera/internal/log.h b/include/libcamera/internal/log.h\n> index be0bab3c1272..b66bf55bc57d 100644\n> --- a/include/libcamera/internal/log.h\n> +++ b/include/libcamera/internal/log.h\n> @@ -117,9 +117,10 @@ LogMessage _log(const LogCategory *category, LogSeverity severity,\n> #endif /* __DOXYGEN__ */\n> \n> #ifndef NDEBUG\n> -#define ASSERT(condition) static_cast(({\t\t\t\t\\\n> -\tif (!(condition))\t\t\t\t\t\t\\\n> -\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed\";\t\\\n> +#define ASSERT(condition) static_cast(({ \\\n> +\tif (!(condition)) \\\n> +\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed in \" \\\n> +\t\t\t << __func__ << \"()\"; \\\n> }))\n> #else\n> #define ASSERT(condition) static_cast(false && (condition))\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 D1417BDB15\n\tfor ;\n\tTue, 20 Apr 2021 17:26:48 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id 8AA5268845;\n\tTue, 20 Apr 2021 19:26:48 +0200 (CEST)","from perceval.ideasonboard.com (perceval.ideasonboard.com\n\t[IPv6:2001:4b98:dc2:55:216:3eff:fef7:d647])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id BB6DE60516\n\tfor ;\n\tTue, 20 Apr 2021 19:26:47 +0200 (CEST)","from [IPv6:2a01:e0a:169:7140:6781:d49:79ac:cf13] (unknown\n\t[IPv6:2a01:e0a:169:7140:6781:d49:79ac:cf13])\n\tby perceval.ideasonboard.com (Postfix) with ESMTPSA id 688A8411;\n\tTue, 20 Apr 2021 19:26:47 +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=\"GwKWubVz\"; dkim-atps=neutral","DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/simple; d=ideasonboard.com;\n\ts=mail; t=1618939607;\n\tbh=sHTw/REyTvzj+rbt/zUBb913iGwvdjsGfJJz5QQuqgY=;\n\th=Subject:To:References:From:Date:In-Reply-To:From;\n\tb=GwKWubVz9xA48bdj6gXiiasb06aADbMiMCHVevtwnXKUTxKUWTcf3hkXEvT1eGiq/\n\tqxi0kVgYQOy+DPI7KbuWqLwo4RvwFAC3+afkthzltFE85mKEoxlLEfW8o2HwTZCZGK\n\tJYDwP6xs2uYJ7kdY0nLbNcTdwiCTHMJxYcWT5yUI=","To":"Kieran Bingham ,\n\tlibcamera devel ","References":"<20210420130741.236848-1-kieran.bingham@ideasonboard.com>\n\t<20210420130741.236848-6-kieran.bingham@ideasonboard.com>","From":"Jean-Michel Hautbois ","Message-ID":"","Date":"Tue, 20 Apr 2021 19:26:47 +0200","User-Agent":"Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101\n\tThunderbird/78.7.1","MIME-Version":"1.0","In-Reply-To":"<20210420130741.236848-6-kieran.bingham@ideasonboard.com>","Content-Language":"en-US","Subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","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","Content-Type":"text/plain; charset=\"us-ascii\"","Content-Transfer-Encoding":"7bit","Errors-To":"libcamera-devel-bounces@lists.libcamera.org","Sender":"\"libcamera-devel\" "}},{"id":16413,"web_url":"https://patchwork.libcamera.org/comment/16413/","msgid":"","date":"2021-04-20T22:05:44","subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","submitter":{"id":2,"url":"https://patchwork.libcamera.org/api/people/2/","name":"Laurent Pinchart","email":"laurent.pinchart@ideasonboard.com"},"content":"Hi Kieran,\n\nThank you for the patch.\n\nOn Tue, Apr 20, 2021 at 02:07:40PM +0100, Kieran Bingham wrote:\n> Report the function which fails an assertion as well as the actual\n> assertion.\n> \n> This now reports as:\n> \n> [30:08:53.218816270] [226567] FATAL default request.cpp:150 assertion \"d\" failed in reuse()\n> rather than:\n> [30:11:05.271888926] [228531] FATAL default request.cpp:150 assertion \"d\" failed\n> \n> Signed-off-by: Kieran Bingham \n> \n> ---\n> We could use __PRETTY_FUNCTION__ instead to get:\n> [30:17:16.736265045] [232054] FATAL default request.cpp:150 assertion \"d\" failed in void libcamera::Request::reuse(libcamera::Request::ReuseFlag)\n\nIs this feature useful for an ASSERT() only, or should we print the\nfunction name in all log messages ? The short function name has limited\nvalue, while the pretty function name is likely too long :-S\n\nGiven that debugging an assertion failure involves open the source\nanyway, I wonder if there's an actual value in printing the function\nname as we have the file name and line number.\n\n> include/libcamera/internal/log.h | 7 ++++---\n> 1 file changed, 4 insertions(+), 3 deletions(-)\n> \n> diff --git a/include/libcamera/internal/log.h b/include/libcamera/internal/log.h\n> index be0bab3c1272..b66bf55bc57d 100644\n> --- a/include/libcamera/internal/log.h\n> +++ b/include/libcamera/internal/log.h\n> @@ -117,9 +117,10 @@ LogMessage _log(const LogCategory *category, LogSeverity severity,\n> #endif /* __DOXYGEN__ */\n> \n> #ifndef NDEBUG\n> -#define ASSERT(condition) static_cast(({\t\t\t\t\\\n> -\tif (!(condition))\t\t\t\t\t\t\\\n> -\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed\";\t\\\n> +#define ASSERT(condition) static_cast(({ \\\n> +\tif (!(condition)) \\\n> +\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed in \" \\\n> +\t\t\t << __func__ << \"()\"; \\\n> }))\n> #else\n> #define ASSERT(condition) static_cast(false && (condition))","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 98081BDB16\n\tfor ;\n\tTue, 20 Apr 2021 22:05:50 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id 0AE8C68840;\n\tWed, 21 Apr 2021 00:05:50 +0200 (CEST)","from perceval.ideasonboard.com (perceval.ideasonboard.com\n\t[IPv6:2001:4b98:dc2:55:216:3eff:fef7:d647])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id 2DD5F602C8\n\tfor ;\n\tWed, 21 Apr 2021 00:05:49 +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 1D36645E;\n\tWed, 21 Apr 2021 00:05:48 +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=\"q5jh1a+C\"; dkim-atps=neutral","DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/simple; d=ideasonboard.com;\n\ts=mail; t=1618956348;\n\tbh=dR9DEygfxdC4T0zx0CUZZfSh6RROtu0I0CGA4qMy85I=;\n\th=Date:From:To:Cc:Subject:References:In-Reply-To:From;\n\tb=q5jh1a+CUqnV038u4WVWyOzRnQE+8k53zR5woEOKDYpCpweCBf73crbD5qYXaWKXa\n\tnaMWbn71ahHFKrlLQCwTLNpSgZlsy2Ph/k5Ui0V22FHBScWuBcul4zqq72UyT2QYLd\n\tUAQk/UxH6QUCi4PwD9WA5JweuIPLPZG+r3nHpmRk=","Date":"Wed, 21 Apr 2021 01:05:44 +0300","From":"Laurent Pinchart ","To":"Kieran Bingham ","Message-ID":"","References":"<20210420130741.236848-1-kieran.bingham@ideasonboard.com>\n\t<20210420130741.236848-6-kieran.bingham@ideasonboard.com>","MIME-Version":"1.0","Content-Disposition":"inline","In-Reply-To":"<20210420130741.236848-6-kieran.bingham@ideasonboard.com>","Subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","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":"text/plain; charset=\"us-ascii\"","Content-Transfer-Encoding":"7bit","Errors-To":"libcamera-devel-bounces@lists.libcamera.org","Sender":"\"libcamera-devel\" "}},{"id":16511,"web_url":"https://patchwork.libcamera.org/comment/16511/","msgid":"","date":"2021-04-22T10:17:39","subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","submitter":{"id":4,"url":"https://patchwork.libcamera.org/api/people/4/","name":"Kieran Bingham","email":"kieran.bingham@ideasonboard.com"},"content":"Hi Laurent,\n\nOn 20/04/2021 23:05, Laurent Pinchart wrote:\n> Hi Kieran,\n> \n> Thank you for the patch.\n> \n> On Tue, Apr 20, 2021 at 02:07:40PM +0100, Kieran Bingham wrote:\n>> Report the function which fails an assertion as well as the actual\n>> assertion.\n>>\n>> This now reports as:\n>>\n>> [30:08:53.218816270] [226567] FATAL default request.cpp:150 assertion \"d\" failed in reuse()\n>> rather than:\n>> [30:11:05.271888926] [228531] FATAL default request.cpp:150 assertion \"d\" failed\n>>\n>> Signed-off-by: Kieran Bingham \n>>\n>> ---\n>> We could use __PRETTY_FUNCTION__ instead to get:\n>> [30:17:16.736265045] [232054] FATAL default request.cpp:150 assertion \"d\" failed in void libcamera::Request::reuse(libcamera::Request::ReuseFlag)\n> \n> Is this feature useful for an ASSERT() only, or should we print the\n> function name in all log messages ?\n\nAt the moment, I didn't want to change for all, as it makes everything\nlonger.\n\nWhat I liked about having the ASSERT say the function name is it helps\nquickly identify the assertion failure.\n\nFor instance, there may be multiple identical /equivalent assertions in\nlots of functions through a module.\n\nWhen it happens, I want to know quickly which one it was.\n\nFor example, the Assertions added into request, as demonstrated above\nwould give the same print for 6 ASSERTs with only the line number as a\ndifference.\n\nThat's much easier to parse if it states /which/ instance of the assert\nfailed, without relying on a further lookup to get the initial feel for\nwhat went wrong.\n\n\n> The short function name has limited\n> value, while the pretty function name is likely too long :-S\n\nThe 'too long' is why I have chosen the short version...\n\n\n> Given that debugging an assertion failure involves open the source\n> anyway, I wonder if there's an actual value in printing the function\n> name as we have the file name and line number.\n\nSure - but not always if you're already deep into debugging something.\n\nImagine you throw a handful of extra assertions in, across a set of\nfunctions and what you are trying to do is rapidly narrow down the\ncause... function names help there to save a manual lookup process.\n\n\n\n>> include/libcamera/internal/log.h | 7 ++++---\n>> 1 file changed, 4 insertions(+), 3 deletions(-)\n>>\n>> diff --git a/include/libcamera/internal/log.h b/include/libcamera/internal/log.h\n>> index be0bab3c1272..b66bf55bc57d 100644\n>> --- a/include/libcamera/internal/log.h\n>> +++ b/include/libcamera/internal/log.h\n>> @@ -117,9 +117,10 @@ LogMessage _log(const LogCategory *category, LogSeverity severity,\n>> #endif /* __DOXYGEN__ */\n>> \n>> #ifndef NDEBUG\n>> -#define ASSERT(condition) static_cast(({\t\t\t\t\\\n>> -\tif (!(condition))\t\t\t\t\t\t\\\n>> -\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed\";\t\\\n>> +#define ASSERT(condition) static_cast(({ \\\n>> +\tif (!(condition)) \\\n>> +\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed in \" \\\n>> +\t\t\t << __func__ << \"()\"; \\\n>> }))\n>> #else\n>> #define ASSERT(condition) static_cast(false && (condition))\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 81794BDB17\n\tfor ;\n\tThu, 22 Apr 2021 10:17:43 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id D854A68844;\n\tThu, 22 Apr 2021 12:17: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 0A0DB60514\n\tfor ;\n\tThu, 22 Apr 2021 12:17:42 +0200 (CEST)","from [192.168.0.20]\n\t(cpc89244-aztw30-2-0-cust3082.18-1.cable.virginm.net [86.31.172.11])\n\tby perceval.ideasonboard.com (Postfix) with ESMTPSA id 7BB9A3EE;\n\tThu, 22 Apr 2021 12:17:41 +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=\"i1AC0SgB\"; dkim-atps=neutral","DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/simple; d=ideasonboard.com;\n\ts=mail; t=1619086661;\n\tbh=D+gH97xOXd65qZFIxp9f19bfN7fUT7s6igt5MvCinZk=;\n\th=Reply-To:Subject:To:Cc:References:From:Date:In-Reply-To:From;\n\tb=i1AC0SgBkgl6iplvuC+DsiAr9PdST0Y8Y3xOfuYP60hovWYnqUD2wJszET8a6srPj\n\tP/si5Q1yf8o4hEH4ki5LvL8cuy0r0+UfHPTa+rfmCzQ7IZitupKBYWA8+iuAdPmSSK\n\tA4qRi6iGG6FTPJU1Dv9ziRqldeIbKWEW83Mpvajg=","To":"Laurent Pinchart ","References":"<20210420130741.236848-1-kieran.bingham@ideasonboard.com>\n\t<20210420130741.236848-6-kieran.bingham@ideasonboard.com>\n\t","From":"Kieran Bingham ","Organization":"Ideas on Board","Message-ID":"","Date":"Thu, 22 Apr 2021 11:17:39 +0100","User-Agent":"Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101\n\tThunderbird/78.7.1","MIME-Version":"1.0","In-Reply-To":"","Content-Language":"en-GB","Subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","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","Reply-To":"kieran.bingham@ideasonboard.com","Cc":"libcamera devel ","Content-Type":"text/plain; charset=\"us-ascii\"","Content-Transfer-Encoding":"7bit","Errors-To":"libcamera-devel-bounces@lists.libcamera.org","Sender":"\"libcamera-devel\" "}},{"id":16519,"web_url":"https://patchwork.libcamera.org/comment/16519/","msgid":"","date":"2021-04-23T02:36:13","subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","submitter":{"id":2,"url":"https://patchwork.libcamera.org/api/people/2/","name":"Laurent Pinchart","email":"laurent.pinchart@ideasonboard.com"},"content":"Hi Kieran,\n\nOn Thu, Apr 22, 2021 at 11:17:39AM +0100, Kieran Bingham wrote:\n> On 20/04/2021 23:05, Laurent Pinchart wrote:\n> > On Tue, Apr 20, 2021 at 02:07:40PM +0100, Kieran Bingham wrote:\n> >> Report the function which fails an assertion as well as the actual\n> >> assertion.\n> >>\n> >> This now reports as:\n> >>\n> >> [30:08:53.218816270] [226567] FATAL default request.cpp:150 assertion \"d\" failed in reuse()\n> >> rather than:\n> >> [30:11:05.271888926] [228531] FATAL default request.cpp:150 assertion \"d\" failed\n> >>\n> >> Signed-off-by: Kieran Bingham \n> >>\n> >> ---\n> >> We could use __PRETTY_FUNCTION__ instead to get:\n> >> [30:17:16.736265045] [232054] FATAL default request.cpp:150 assertion \"d\" failed in void libcamera::Request::reuse(libcamera::Request::ReuseFlag)\n> > \n> > Is this feature useful for an ASSERT() only, or should we print the\n> > function name in all log messages ?\n> \n> At the moment, I didn't want to change for all, as it makes everything\n> longer.\n> \n> What I liked about having the ASSERT say the function name is it helps\n> quickly identify the assertion failure.\n> \n> For instance, there may be multiple identical /equivalent assertions in\n> lots of functions through a module.\n> \n> When it happens, I want to know quickly which one it was.\n> \n> For example, the Assertions added into request, as demonstrated above\n> would give the same print for 6 ASSERTs with only the line number as a\n> difference.\n> \n> That's much easier to parse if it states /which/ instance of the assert\n> failed, without relying on a further lookup to get the initial feel for\n> what went wrong.\n\nMy workflow would be to then immediately jump to that function to dig\ndeeper, which the line number would allow me to do as easily. Printing\nthe function name will tell me what function has thrown the assert a few\nseconds earlier, which seems a short amount of time (time is relative\nthough :-)). Your mileage may vary though, and if this really makes it \neasier for you, I'm sure it could also help other developers, so I'm not\nopposed to the change. As it doesn't match my personal experience, I'd \njust like to avoid merging it with an illusion that it will help, to \nonly realize later that it doesn't. I trust your judgement and your \nconfidence, so you can decide if you want to carry the change locally \nfor a bit to test it, or merge it now. We can also consider merging it \nto see if it helps other developers and revert it later if everybody \nends up not using this feature. Up to you.\n\n> > The short function name has limited\n> > value, while the pretty function name is likely too long :-S\n> \n> The 'too long' is why I have chosen the short version...\n\nWould be nice to have a __SHORT_PRETTY_FUNCTION__ that would print\n\"Request::reuse()\". The compiler should magically understand that we\ndon't need the namespace to be printed if it's just \"libcamera\" :-)\n\n> > Given that debugging an assertion failure involves open the source\n> > anyway, I wonder if there's an actual value in printing the function\n> > name as we have the file name and line number.\n> \n> Sure - but not always if you're already deep into debugging something.\n> \n> Imagine you throw a handful of extra assertions in, across a set of\n> functions and what you are trying to do is rapidly narrow down the\n> cause... function names help there to save a manual lookup process.\n\nMy personal experience is that line numbers are more important, as I\nusually end up throwing log messages in different places in the same\nfunction. Again, your mileage may very well vary, my data point is just\nthat, a single data point.\n\n> >> include/libcamera/internal/log.h | 7 ++++---\n> >> 1 file changed, 4 insertions(+), 3 deletions(-)\n> >>\n> >> diff --git a/include/libcamera/internal/log.h b/include/libcamera/internal/log.h\n> >> index be0bab3c1272..b66bf55bc57d 100644\n> >> --- a/include/libcamera/internal/log.h\n> >> +++ b/include/libcamera/internal/log.h\n> >> @@ -117,9 +117,10 @@ LogMessage _log(const LogCategory *category, LogSeverity severity,\n> >> #endif /* __DOXYGEN__ */\n> >> \n> >> #ifndef NDEBUG\n> >> -#define ASSERT(condition) static_cast(({\t\t\t\t\\\n> >> -\tif (!(condition))\t\t\t\t\t\t\\\n> >> -\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed\";\t\\\n> >> +#define ASSERT(condition) static_cast(({ \\\n> >> +\tif (!(condition)) \\\n> >> +\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed in \" \\\n> >> +\t\t\t << __func__ << \"()\"; \\\n> >> }))\n> >> #else\n> >> #define ASSERT(condition) static_cast(false && (condition))","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 407F6BDB15\n\tfor ;\n\tFri, 23 Apr 2021 02:36:21 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id 5CBD368870;\n\tFri, 23 Apr 2021 04:36:20 +0200 (CEST)","from perceval.ideasonboard.com (perceval.ideasonboard.com\n\t[213.167.242.64])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id 857B16885B\n\tfor ;\n\tFri, 23 Apr 2021 04:36:18 +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 F09C945F;\n\tFri, 23 Apr 2021 04:36:17 +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=\"TiZVQ8cM\"; dkim-atps=neutral","DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/simple; d=ideasonboard.com;\n\ts=mail; t=1619145378;\n\tbh=z7nw9eI2rGwTe/NFCsREmwI8sBu+M3+cKyI76f6yrBs=;\n\th=Date:From:To:Cc:Subject:References:In-Reply-To:From;\n\tb=TiZVQ8cMbrJn97CuUhzXIGNRpeVWpCmQjK6BkRlgO8rz6DYHORqoDmL7JezLFllpn\n\tn0BZoKZ1BJYbpiyPqz59BOs3ZPzZU2VJUH03jzicZmuTK1epjPJdL20NmFvGQWub6u\n\tV9PjlL001DWQTd6Pveq1Jbcau6TbAeJNRcICN0B0=","Date":"Fri, 23 Apr 2021 05:36:13 +0300","From":"Laurent Pinchart ","To":"Kieran Bingham ","Message-ID":"","References":"<20210420130741.236848-1-kieran.bingham@ideasonboard.com>\n\t<20210420130741.236848-6-kieran.bingham@ideasonboard.com>\n\t\n\t","MIME-Version":"1.0","Content-Disposition":"inline","In-Reply-To":"","Subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","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":"text/plain; charset=\"us-ascii\"","Content-Transfer-Encoding":"7bit","Errors-To":"libcamera-devel-bounces@lists.libcamera.org","Sender":"\"libcamera-devel\" "}},{"id":16575,"web_url":"https://patchwork.libcamera.org/comment/16575/","msgid":"<69a60fb0-3c0c-2b1f-c164-1770c0f88942@ideasonboard.com>","date":"2021-04-26T08:44:59","subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","submitter":{"id":4,"url":"https://patchwork.libcamera.org/api/people/4/","name":"Kieran Bingham","email":"kieran.bingham@ideasonboard.com"},"content":"Hi Laurent,\n\nOn 23/04/2021 03:36, Laurent Pinchart wrote:\n> Hi Kieran,\n> \n> On Thu, Apr 22, 2021 at 11:17:39AM +0100, Kieran Bingham wrote:\n>> On 20/04/2021 23:05, Laurent Pinchart wrote:\n>>> On Tue, Apr 20, 2021 at 02:07:40PM +0100, Kieran Bingham wrote:\n>>>> Report the function which fails an assertion as well as the actual\n>>>> assertion.\n>>>>\n>>>> This now reports as:\n>>>>\n>>>> [30:08:53.218816270] [226567] FATAL default request.cpp:150 assertion \"d\" failed in reuse()\n>>>> rather than:\n>>>> [30:11:05.271888926] [228531] FATAL default request.cpp:150 assertion \"d\" failed\n>>>>\n>>>> Signed-off-by: Kieran Bingham \n>>>>\n>>>> ---\n>>>> We could use __PRETTY_FUNCTION__ instead to get:\n>>>> [30:17:16.736265045] [232054] FATAL default request.cpp:150 assertion \"d\" failed in void libcamera::Request::reuse(libcamera::Request::ReuseFlag)\n>>>\n>>> Is this feature useful for an ASSERT() only, or should we print the\n>>> function name in all log messages ?\n>>\n>> At the moment, I didn't want to change for all, as it makes everything\n>> longer.\n>>\n>> What I liked about having the ASSERT say the function name is it helps\n>> quickly identify the assertion failure.\n>>\n>> For instance, there may be multiple identical /equivalent assertions in\n>> lots of functions through a module.\n>>\n>> When it happens, I want to know quickly which one it was.\n>>\n>> For example, the Assertions added into request, as demonstrated above\n>> would give the same print for 6 ASSERTs with only the line number as a\n>> difference.\n>>\n>> That's much easier to parse if it states /which/ instance of the assert\n>> failed, without relying on a further lookup to get the initial feel for\n>> what went wrong.\n> \n> My workflow would be to then immediately jump to that function to dig\n> deeper, which the line number would allow me to do as easily. Printing\n> the function name will tell me what function has thrown the assert a few\n> seconds earlier, which seems a short amount of time (time is relative\n> though :-)). Your mileage may vary though, and if this really makes it \n> easier for you, I'm sure it could also help other developers, so I'm not\n> opposed to the change. As it doesn't match my personal experience, I'd \n> just like to avoid merging it with an illusion that it will help, to \n> only realize later that it doesn't. I trust your judgement and your \n> confidence, so you can decide if you want to carry the change locally \n> for a bit to test it, or merge it now. We can also consider merging it \n> to see if it helps other developers and revert it later if everybody \n> ends up not using this feature. Up to you.\n> \n>>> The short function name has limited\n>>> value, while the pretty function name is likely too long :-S\n>>\n>> The 'too long' is why I have chosen the short version...\n> \n> Would be nice to have a __SHORT_PRETTY_FUNCTION__ that would print\n> \"Request::reuse()\". The compiler should magically understand that we\n> don't need the namespace to be printed if it's just \"libcamera\" :-)\n> \n>>> Given that debugging an assertion failure involves open the source\n>>> anyway, I wonder if there's an actual value in printing the function\n>>> name as we have the file name and line number.\n>>\n>> Sure - but not always if you're already deep into debugging something.\n>>\n>> Imagine you throw a handful of extra assertions in, across a set of\n>> functions and what you are trying to do is rapidly narrow down the\n>> cause... function names help there to save a manual lookup process.\n> \n> My personal experience is that line numbers are more important, as I\n> usually end up throwing log messages in different places in the same\n> function. Again, your mileage may very well vary, my data point is just\n> that, a single data point.\n\nYes, but please remember lots of people are different. Some people\nrecognise numbers better than words, and some people follow words better\nthan numbers ... All we're doing here is adding an extra word to a\nhopefully rare debug print.\n\nI'm in the later camp. A word will help me prepare my brain for where to\nsearch.\n\nI might tell you that I live in , Filton, Bristol, which is a\nclose approximation to where I live, and not quite as detailed as\n\n 51.50080108642578, -2.5474119186401367 (not my actual address)\n\nAnd for commencing the journey in either case the reader will likely\nhave to look up the exact destination, but a lot more information is\nconveyed with the words than the numbers pre-lookup ...\n\nOf course you might then say but my house has a numerical address, which\nindeed it does, lets call it 100 stop()street, v4l2_device()town....\n\nThe line number helps provide the final destination address, but to me,\nthe function name is the street name. Perhaps not always essential, but\na very useful reference point.\n\nAnd certainly if you have lots of debug prints in the same function,\nthen the line number matters. But we already have the line number, so\nI'm not going to argue over the value of that ;-)\n\n\n\n>>>> include/libcamera/internal/log.h | 7 ++++---\n>>>> 1 file changed, 4 insertions(+), 3 deletions(-)\n>>>>\n>>>> diff --git a/include/libcamera/internal/log.h b/include/libcamera/internal/log.h\n>>>> index be0bab3c1272..b66bf55bc57d 100644\n>>>> --- a/include/libcamera/internal/log.h\n>>>> +++ b/include/libcamera/internal/log.h\n>>>> @@ -117,9 +117,10 @@ LogMessage _log(const LogCategory *category, LogSeverity severity,\n>>>> #endif /* __DOXYGEN__ */\n>>>> \n>>>> #ifndef NDEBUG\n>>>> -#define ASSERT(condition) static_cast(({\t\t\t\t\\\n>>>> -\tif (!(condition))\t\t\t\t\t\t\\\n>>>> -\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed\";\t\\\n>>>> +#define ASSERT(condition) static_cast(({ \\\n>>>> +\tif (!(condition)) \\\n>>>> +\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed in \" \\\n>>>> +\t\t\t << __func__ << \"()\"; \\\n>>>> }))\n>>>> #else\n>>>> #define ASSERT(condition) static_cast(false && (condition))\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 51D62BDC9A\n\tfor ;\n\tMon, 26 Apr 2021 08:45:04 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id 9A147688B7;\n\tMon, 26 Apr 2021 10:45:03 +0200 (CEST)","from perceval.ideasonboard.com (perceval.ideasonboard.com\n\t[213.167.242.64])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id 9391F68880\n\tfor ;\n\tMon, 26 Apr 2021 10:45:02 +0200 (CEST)","from [192.168.0.20]\n\t(cpc89244-aztw30-2-0-cust3082.18-1.cable.virginm.net [86.31.172.11])\n\tby perceval.ideasonboard.com (Postfix) with ESMTPSA id 13731D8B;\n\tMon, 26 Apr 2021 10:45:02 +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=\"EFFdwKTD\"; dkim-atps=neutral","DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/simple; d=ideasonboard.com;\n\ts=mail; t=1619426702;\n\tbh=kEwN7XuO2zpDGMXI83cz4V+ELpgB925UQ+dkKWzyBNs=;\n\th=Reply-To:Subject:To:Cc:References:From:Date:In-Reply-To:From;\n\tb=EFFdwKTDWz1KArZRz9qJFke6GHCmsqkNekWxuIYHKS5atfAIOvsqQaC7VKpgpOR0b\n\tktLAWKaXTTMv4WMlR3q+Wo7Q2AYMayf4/Ug3sEZ75bnxLF9zb9mrFoPqaTONhe4664\n\t92fw25PRnN8LbAi99I77XvZgbndgczyNg98PVlV8=","To":"Laurent Pinchart ","References":"<20210420130741.236848-1-kieran.bingham@ideasonboard.com>\n\t<20210420130741.236848-6-kieran.bingham@ideasonboard.com>\n\t\n\t\n\t","From":"Kieran Bingham ","Organization":"Ideas on Board","Message-ID":"<69a60fb0-3c0c-2b1f-c164-1770c0f88942@ideasonboard.com>","Date":"Mon, 26 Apr 2021 09:44:59 +0100","User-Agent":"Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101\n\tThunderbird/78.7.1","MIME-Version":"1.0","In-Reply-To":"","Content-Language":"en-GB","Subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","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","Reply-To":"kieran.bingham@ideasonboard.com","Cc":"libcamera devel ","Content-Type":"text/plain; charset=\"us-ascii\"","Content-Transfer-Encoding":"7bit","Errors-To":"libcamera-devel-bounces@lists.libcamera.org","Sender":"\"libcamera-devel\" "}},{"id":16629,"web_url":"https://patchwork.libcamera.org/comment/16629/","msgid":"","date":"2021-04-27T06:58:30","subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","submitter":{"id":2,"url":"https://patchwork.libcamera.org/api/people/2/","name":"Laurent Pinchart","email":"laurent.pinchart@ideasonboard.com"},"content":"Hi Kieran,\n\nOn Mon, Apr 26, 2021 at 09:44:59AM +0100, Kieran Bingham wrote:\n> On 23/04/2021 03:36, Laurent Pinchart wrote:\n> > On Thu, Apr 22, 2021 at 11:17:39AM +0100, Kieran Bingham wrote:\n> >> On 20/04/2021 23:05, Laurent Pinchart wrote:\n> >>> On Tue, Apr 20, 2021 at 02:07:40PM +0100, Kieran Bingham wrote:\n> >>>> Report the function which fails an assertion as well as the actual\n> >>>> assertion.\n> >>>>\n> >>>> This now reports as:\n> >>>>\n> >>>> [30:08:53.218816270] [226567] FATAL default request.cpp:150 assertion \"d\" failed in reuse()\n> >>>> rather than:\n> >>>> [30:11:05.271888926] [228531] FATAL default request.cpp:150 assertion \"d\" failed\n> >>>>\n> >>>> Signed-off-by: Kieran Bingham \n> >>>>\n> >>>> ---\n> >>>> We could use __PRETTY_FUNCTION__ instead to get:\n> >>>> [30:17:16.736265045] [232054] FATAL default request.cpp:150 assertion \"d\" failed in void libcamera::Request::reuse(libcamera::Request::ReuseFlag)\n> >>>\n> >>> Is this feature useful for an ASSERT() only, or should we print the\n> >>> function name in all log messages ?\n> >>\n> >> At the moment, I didn't want to change for all, as it makes everything\n> >> longer.\n> >>\n> >> What I liked about having the ASSERT say the function name is it helps\n> >> quickly identify the assertion failure.\n> >>\n> >> For instance, there may be multiple identical /equivalent assertions in\n> >> lots of functions through a module.\n> >>\n> >> When it happens, I want to know quickly which one it was.\n> >>\n> >> For example, the Assertions added into request, as demonstrated above\n> >> would give the same print for 6 ASSERTs with only the line number as a\n> >> difference.\n> >>\n> >> That's much easier to parse if it states /which/ instance of the assert\n> >> failed, without relying on a further lookup to get the initial feel for\n> >> what went wrong.\n> > \n> > My workflow would be to then immediately jump to that function to dig\n> > deeper, which the line number would allow me to do as easily. Printing\n> > the function name will tell me what function has thrown the assert a few\n> > seconds earlier, which seems a short amount of time (time is relative\n> > though :-)). Your mileage may vary though, and if this really makes it \n> > easier for you, I'm sure it could also help other developers, so I'm not\n> > opposed to the change. As it doesn't match my personal experience, I'd \n> > just like to avoid merging it with an illusion that it will help, to \n> > only realize later that it doesn't. I trust your judgement and your \n> > confidence, so you can decide if you want to carry the change locally \n> > for a bit to test it, or merge it now. We can also consider merging it \n> > to see if it helps other developers and revert it later if everybody \n> > ends up not using this feature. Up to you.\n> > \n> >>> The short function name has limited\n> >>> value, while the pretty function name is likely too long :-S\n> >>\n> >> The 'too long' is why I have chosen the short version...\n> > \n> > Would be nice to have a __SHORT_PRETTY_FUNCTION__ that would print\n> > \"Request::reuse()\". The compiler should magically understand that we\n> > don't need the namespace to be printed if it's just \"libcamera\" :-)\n> > \n> >>> Given that debugging an assertion failure involves open the source\n> >>> anyway, I wonder if there's an actual value in printing the function\n> >>> name as we have the file name and line number.\n> >>\n> >> Sure - but not always if you're already deep into debugging something.\n> >>\n> >> Imagine you throw a handful of extra assertions in, across a set of\n> >> functions and what you are trying to do is rapidly narrow down the\n> >> cause... function names help there to save a manual lookup process.\n> > \n> > My personal experience is that line numbers are more important, as I\n> > usually end up throwing log messages in different places in the same\n> > function. Again, your mileage may very well vary, my data point is just\n> > that, a single data point.\n> \n> Yes, but please remember lots of people are different. Some people\n> recognise numbers better than words, and some people follow words better\n> than numbers ... All we're doing here is adding an extra word to a\n> hopefully rare debug print.\n\nThere's no need to convince me :-) As I've said, I wanted to make sure\nthat you had really tested this as helping your debugging experience, as\nopposed to only thinking it could improve it without actually testing\nit. As you say you have, that's enough for me, I trust you, and I'm fine\nwith the change.\n\n> I'm in the later camp. A word will help me prepare my brain for where to\n> search.\n> \n> I might tell you that I live in , Filton, Bristol, which is a\n> close approximation to where I live, and not quite as detailed as\n> \n> 51.50080108642578, -2.5474119186401367 (not my actual address)\n> \n> And for commencing the journey in either case the reader will likely\n> have to look up the exact destination, but a lot more information is\n> conveyed with the words than the numbers pre-lookup ...\n> \n> Of course you might then say but my house has a numerical address, which\n> indeed it does, lets call it 100 stop()street, v4l2_device()town....\n> \n> The line number helps provide the final destination address, but to me,\n> the function name is the street name. Perhaps not always essential, but\n> a very useful reference point.\n> \n> And certainly if you have lots of debug prints in the same function,\n> then the line number matters. But we already have the line number, so\n> I'm not going to argue over the value of that ;-)\n> \n> >>>> include/libcamera/internal/log.h | 7 ++++---\n> >>>> 1 file changed, 4 insertions(+), 3 deletions(-)\n> >>>>\n> >>>> diff --git a/include/libcamera/internal/log.h b/include/libcamera/internal/log.h\n> >>>> index be0bab3c1272..b66bf55bc57d 100644\n> >>>> --- a/include/libcamera/internal/log.h\n> >>>> +++ b/include/libcamera/internal/log.h\n> >>>> @@ -117,9 +117,10 @@ LogMessage _log(const LogCategory *category, LogSeverity severity,\n> >>>> #endif /* __DOXYGEN__ */\n> >>>> \n> >>>> #ifndef NDEBUG\n> >>>> -#define ASSERT(condition) static_cast(({\t\t\t\t\\\n> >>>> -\tif (!(condition))\t\t\t\t\t\t\\\n> >>>> -\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed\";\t\\\n> >>>> +#define ASSERT(condition) static_cast(({ \\\n> >>>> +\tif (!(condition)) \\\n> >>>> +\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed in \" \\\n> >>>> +\t\t\t << __func__ << \"()\"; \\\n> >>>> }))\n> >>>> #else\n> >>>> #define ASSERT(condition) static_cast(false && (condition))","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 5FDE6BDCC3\n\tfor ;\n\tTue, 27 Apr 2021 06:58:38 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id C5E76688AF;\n\tTue, 27 Apr 2021 08:58:37 +0200 (CEST)","from perceval.ideasonboard.com (perceval.ideasonboard.com\n\t[213.167.242.64])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id 9351860512\n\tfor ;\n\tTue, 27 Apr 2021 08:58:36 +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 04D8FE9;\n\tTue, 27 Apr 2021 08:58:35 +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=\"V4DBtmnG\"; dkim-atps=neutral","DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/simple; d=ideasonboard.com;\n\ts=mail; t=1619506716;\n\tbh=fnVZ5RvqkuzreUwDiUq+Fq/nr3BYSYpx0tWb9yG9O94=;\n\th=Date:From:To:Cc:Subject:References:In-Reply-To:From;\n\tb=V4DBtmnGGzSyHmFpMt9uKtXQCtn/2VEtCqnIof+oP/CXGrlOaGLvlbG98uqW21mMX\n\tBbbon+E4vDS1IczpwiHyL/b2/8ow/rNEK6vTJtx0QnaEwDQz6cNoWxG2dq2qSA0Lbc\n\tfCjkrAj1NCCEJNRRxobqznRuqQ8itzXQ/zTz7hX4=","Date":"Tue, 27 Apr 2021 09:58:30 +0300","From":"Laurent Pinchart ","To":"Kieran Bingham ","Message-ID":"","References":"<20210420130741.236848-1-kieran.bingham@ideasonboard.com>\n\t<20210420130741.236848-6-kieran.bingham@ideasonboard.com>\n\t\n\t\n\t\n\t<69a60fb0-3c0c-2b1f-c164-1770c0f88942@ideasonboard.com>","MIME-Version":"1.0","Content-Disposition":"inline","In-Reply-To":"<69a60fb0-3c0c-2b1f-c164-1770c0f88942@ideasonboard.com>","Subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","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":"text/plain; charset=\"us-ascii\"","Content-Transfer-Encoding":"7bit","Errors-To":"libcamera-devel-bounces@lists.libcamera.org","Sender":"\"libcamera-devel\" "}},{"id":16645,"web_url":"https://patchwork.libcamera.org/comment/16645/","msgid":"","date":"2021-04-27T07:58:53","subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","submitter":{"id":4,"url":"https://patchwork.libcamera.org/api/people/4/","name":"Kieran Bingham","email":"kieran.bingham@ideasonboard.com"},"content":"Hi Laurent,\n\nOn 27/04/2021 07:58, Laurent Pinchart wrote:\n> Hi Kieran,\n> \n> On Mon, Apr 26, 2021 at 09:44:59AM +0100, Kieran Bingham wrote:\n>> On 23/04/2021 03:36, Laurent Pinchart wrote:\n>>> On Thu, Apr 22, 2021 at 11:17:39AM +0100, Kieran Bingham wrote:\n>>>> On 20/04/2021 23:05, Laurent Pinchart wrote:\n>>>>> On Tue, Apr 20, 2021 at 02:07:40PM +0100, Kieran Bingham wrote:\n>>>>>> Report the function which fails an assertion as well as the actual\n>>>>>> assertion.\n>>>>>>\n>>>>>> This now reports as:\n>>>>>>\n>>>>>> [30:08:53.218816270] [226567] FATAL default request.cpp:150 assertion \"d\" failed in reuse()\n>>>>>> rather than:\n>>>>>> [30:11:05.271888926] [228531] FATAL default request.cpp:150 assertion \"d\" failed\n>>>>>>\n>>>>>> Signed-off-by: Kieran Bingham \n>>>>>>\n>>>>>> ---\n>>>>>> We could use __PRETTY_FUNCTION__ instead to get:\n>>>>>> [30:17:16.736265045] [232054] FATAL default request.cpp:150 assertion \"d\" failed in void libcamera::Request::reuse(libcamera::Request::ReuseFlag)\n>>>>>\n>>>>> Is this feature useful for an ASSERT() only, or should we print the\n>>>>> function name in all log messages ?\n>>>>\n>>>> At the moment, I didn't want to change for all, as it makes everything\n>>>> longer.\n>>>>\n>>>> What I liked about having the ASSERT say the function name is it helps\n>>>> quickly identify the assertion failure.\n>>>>\n>>>> For instance, there may be multiple identical /equivalent assertions in\n>>>> lots of functions through a module.\n>>>>\n>>>> When it happens, I want to know quickly which one it was.\n>>>>\n>>>> For example, the Assertions added into request, as demonstrated above\n>>>> would give the same print for 6 ASSERTs with only the line number as a\n>>>> difference.\n>>>>\n>>>> That's much easier to parse if it states /which/ instance of the assert\n>>>> failed, without relying on a further lookup to get the initial feel for\n>>>> what went wrong.\n>>>\n>>> My workflow would be to then immediately jump to that function to dig\n>>> deeper, which the line number would allow me to do as easily. Printing\n>>> the function name will tell me what function has thrown the assert a few\n>>> seconds earlier, which seems a short amount of time (time is relative\n>>> though :-)). Your mileage may vary though, and if this really makes it \n>>> easier for you, I'm sure it could also help other developers, so I'm not\n>>> opposed to the change. As it doesn't match my personal experience, I'd \n>>> just like to avoid merging it with an illusion that it will help, to \n>>> only realize later that it doesn't. I trust your judgement and your \n>>> confidence, so you can decide if you want to carry the change locally \n>>> for a bit to test it, or merge it now. We can also consider merging it \n>>> to see if it helps other developers and revert it later if everybody \n>>> ends up not using this feature. Up to you.\n>>>\n>>>>> The short function name has limited\n>>>>> value, while the pretty function name is likely too long :-S\n>>>>\n>>>> The 'too long' is why I have chosen the short version...\n>>>\n>>> Would be nice to have a __SHORT_PRETTY_FUNCTION__ that would print\n>>> \"Request::reuse()\". The compiler should magically understand that we\n>>> don't need the namespace to be printed if it's just \"libcamera\" :-)\n>>>\n>>>>> Given that debugging an assertion failure involves open the source\n>>>>> anyway, I wonder if there's an actual value in printing the function\n>>>>> name as we have the file name and line number.\n>>>>\n>>>> Sure - but not always if you're already deep into debugging something.\n>>>>\n>>>> Imagine you throw a handful of extra assertions in, across a set of\n>>>> functions and what you are trying to do is rapidly narrow down the\n>>>> cause... function names help there to save a manual lookup process.\n>>>\n>>> My personal experience is that line numbers are more important, as I\n>>> usually end up throwing log messages in different places in the same\n>>> function. Again, your mileage may very well vary, my data point is just\n>>> that, a single data point.\n>>\n>> Yes, but please remember lots of people are different. Some people\n>> recognise numbers better than words, and some people follow words better\n>> than numbers ... All we're doing here is adding an extra word to a\n>> hopefully rare debug print.\n> \n> There's no need to convince me :-) As I've said, I wanted to make sure\n> that you had really tested this as helping your debugging experience, as\n> opposed to only thinking it could improve it without actually testing\n> it. As you say you have, that's enough for me, I trust you, and I'm fine\n> with the change.\n\n\nA tag of some form would convince me of that ;-)\n\n--\nKieran\n\n\n\n> \n>> I'm in the later camp. A word will help me prepare my brain for where to\n>> search.\n>>\n>> I might tell you that I live in , Filton, Bristol, which is a\n>> close approximation to where I live, and not quite as detailed as\n>>\n>> 51.50080108642578, -2.5474119186401367 (not my actual address)\n>>\n>> And for commencing the journey in either case the reader will likely\n>> have to look up the exact destination, but a lot more information is\n>> conveyed with the words than the numbers pre-lookup ...\n>>\n>> Of course you might then say but my house has a numerical address, which\n>> indeed it does, lets call it 100 stop()street, v4l2_device()town....\n>>\n>> The line number helps provide the final destination address, but to me,\n>> the function name is the street name. Perhaps not always essential, but\n>> a very useful reference point.\n>>\n>> And certainly if you have lots of debug prints in the same function,\n>> then the line number matters. But we already have the line number, so\n>> I'm not going to argue over the value of that ;-)\n>>\n>>>>>> include/libcamera/internal/log.h | 7 ++++---\n>>>>>> 1 file changed, 4 insertions(+), 3 deletions(-)\n>>>>>>\n>>>>>> diff --git a/include/libcamera/internal/log.h b/include/libcamera/internal/log.h\n>>>>>> index be0bab3c1272..b66bf55bc57d 100644\n>>>>>> --- a/include/libcamera/internal/log.h\n>>>>>> +++ b/include/libcamera/internal/log.h\n>>>>>> @@ -117,9 +117,10 @@ LogMessage _log(const LogCategory *category, LogSeverity severity,\n>>>>>> #endif /* __DOXYGEN__ */\n>>>>>> \n>>>>>> #ifndef NDEBUG\n>>>>>> -#define ASSERT(condition) static_cast(({\t\t\t\t\\\n>>>>>> -\tif (!(condition))\t\t\t\t\t\t\\\n>>>>>> -\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed\";\t\\\n>>>>>> +#define ASSERT(condition) static_cast(({ \\\n>>>>>> +\tif (!(condition)) \\\n>>>>>> +\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed in \" \\\n>>>>>> +\t\t\t << __func__ << \"()\"; \\\n>>>>>> }))\n>>>>>> #else\n>>>>>> #define ASSERT(condition) static_cast(false && (condition))\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 AFAADBDCC3\n\tfor ;\n\tTue, 27 Apr 2021 07:58:59 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id 161A2688C1;\n\tTue, 27 Apr 2021 09:58:59 +0200 (CEST)","from perceval.ideasonboard.com (perceval.ideasonboard.com\n\t[IPv6:2001:4b98:dc2:55:216:3eff:fef7:d647])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id 203D7688B5\n\tfor ;\n\tTue, 27 Apr 2021 09:58:58 +0200 (CEST)","from [192.168.0.20]\n\t(cpc89244-aztw30-2-0-cust3082.18-1.cable.virginm.net [86.31.172.11])\n\tby perceval.ideasonboard.com (Postfix) with ESMTPSA id 775D8E9;\n\tTue, 27 Apr 2021 09:58:57 +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=\"kuRBrYOm\"; dkim-atps=neutral","DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/simple; d=ideasonboard.com;\n\ts=mail; t=1619510337;\n\tbh=l3RsB+PY4+NUNT8jwlBPBsRE1ABnwiGM6KfzldaEYFU=;\n\th=Reply-To:Subject:To:Cc:References:From:Date:In-Reply-To:From;\n\tb=kuRBrYOm5eH50RqfxwCO0l89g42LzX5c+8MYd6G05Tj3Fw+z6sWHt/YGqquQ/fxzy\n\tgHY4X0kJV79PZTgjur+iphTrM75NH2DDX0QWBHHrLZBrYXWxItalo6lRerw+e44h2D\n\tBfm9DjeM8KHoH3h3yOed8FXwZSK3QqJgDYdVNjcY=","To":"Laurent Pinchart ","References":"<20210420130741.236848-1-kieran.bingham@ideasonboard.com>\n\t<20210420130741.236848-6-kieran.bingham@ideasonboard.com>\n\t\n\t\n\t\n\t<69a60fb0-3c0c-2b1f-c164-1770c0f88942@ideasonboard.com>\n\t","From":"Kieran Bingham ","Organization":"Ideas on Board","Message-ID":"","Date":"Tue, 27 Apr 2021 08:58:53 +0100","User-Agent":"Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101\n\tThunderbird/78.7.1","MIME-Version":"1.0","In-Reply-To":"","Content-Language":"en-GB","Subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","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","Reply-To":"kieran.bingham@ideasonboard.com","Cc":"libcamera devel ","Content-Type":"text/plain; charset=\"us-ascii\"","Content-Transfer-Encoding":"7bit","Errors-To":"libcamera-devel-bounces@lists.libcamera.org","Sender":"\"libcamera-devel\" "}},{"id":16646,"web_url":"https://patchwork.libcamera.org/comment/16646/","msgid":"","date":"2021-04-27T08:12:15","subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","submitter":{"id":2,"url":"https://patchwork.libcamera.org/api/people/2/","name":"Laurent Pinchart","email":"laurent.pinchart@ideasonboard.com"},"content":"On Tue, Apr 27, 2021 at 08:58:53AM +0100, Kieran Bingham wrote:\n> On 27/04/2021 07:58, Laurent Pinchart wrote:\n> > On Mon, Apr 26, 2021 at 09:44:59AM +0100, Kieran Bingham wrote:\n> >> On 23/04/2021 03:36, Laurent Pinchart wrote:\n> >>> On Thu, Apr 22, 2021 at 11:17:39AM +0100, Kieran Bingham wrote:\n> >>>> On 20/04/2021 23:05, Laurent Pinchart wrote:\n> >>>>> On Tue, Apr 20, 2021 at 02:07:40PM +0100, Kieran Bingham wrote:\n> >>>>>> Report the function which fails an assertion as well as the actual\n> >>>>>> assertion.\n> >>>>>>\n> >>>>>> This now reports as:\n> >>>>>>\n> >>>>>> [30:08:53.218816270] [226567] FATAL default request.cpp:150 assertion \"d\" failed in reuse()\n> >>>>>> rather than:\n> >>>>>> [30:11:05.271888926] [228531] FATAL default request.cpp:150 assertion \"d\" failed\n> >>>>>>\n> >>>>>> Signed-off-by: Kieran Bingham \n> >>>>>>\n> >>>>>> ---\n> >>>>>> We could use __PRETTY_FUNCTION__ instead to get:\n> >>>>>> [30:17:16.736265045] [232054] FATAL default request.cpp:150 assertion \"d\" failed in void libcamera::Request::reuse(libcamera::Request::ReuseFlag)\n> >>>>>\n> >>>>> Is this feature useful for an ASSERT() only, or should we print the\n> >>>>> function name in all log messages ?\n> >>>>\n> >>>> At the moment, I didn't want to change for all, as it makes everything\n> >>>> longer.\n> >>>>\n> >>>> What I liked about having the ASSERT say the function name is it helps\n> >>>> quickly identify the assertion failure.\n> >>>>\n> >>>> For instance, there may be multiple identical /equivalent assertions in\n> >>>> lots of functions through a module.\n> >>>>\n> >>>> When it happens, I want to know quickly which one it was.\n> >>>>\n> >>>> For example, the Assertions added into request, as demonstrated above\n> >>>> would give the same print for 6 ASSERTs with only the line number as a\n> >>>> difference.\n> >>>>\n> >>>> That's much easier to parse if it states /which/ instance of the assert\n> >>>> failed, without relying on a further lookup to get the initial feel for\n> >>>> what went wrong.\n> >>>\n> >>> My workflow would be to then immediately jump to that function to dig\n> >>> deeper, which the line number would allow me to do as easily. Printing\n> >>> the function name will tell me what function has thrown the assert a few\n> >>> seconds earlier, which seems a short amount of time (time is relative\n> >>> though :-)). Your mileage may vary though, and if this really makes it \n> >>> easier for you, I'm sure it could also help other developers, so I'm not\n> >>> opposed to the change. As it doesn't match my personal experience, I'd \n> >>> just like to avoid merging it with an illusion that it will help, to \n> >>> only realize later that it doesn't. I trust your judgement and your \n> >>> confidence, so you can decide if you want to carry the change locally \n> >>> for a bit to test it, or merge it now. We can also consider merging it \n> >>> to see if it helps other developers and revert it later if everybody \n> >>> ends up not using this feature. Up to you.\n> >>>\n> >>>>> The short function name has limited\n> >>>>> value, while the pretty function name is likely too long :-S\n> >>>>\n> >>>> The 'too long' is why I have chosen the short version...\n> >>>\n> >>> Would be nice to have a __SHORT_PRETTY_FUNCTION__ that would print\n> >>> \"Request::reuse()\". The compiler should magically understand that we\n> >>> don't need the namespace to be printed if it's just \"libcamera\" :-)\n> >>>\n> >>>>> Given that debugging an assertion failure involves open the source\n> >>>>> anyway, I wonder if there's an actual value in printing the function\n> >>>>> name as we have the file name and line number.\n> >>>>\n> >>>> Sure - but not always if you're already deep into debugging something.\n> >>>>\n> >>>> Imagine you throw a handful of extra assertions in, across a set of\n> >>>> functions and what you are trying to do is rapidly narrow down the\n> >>>> cause... function names help there to save a manual lookup process.\n> >>>\n> >>> My personal experience is that line numbers are more important, as I\n> >>> usually end up throwing log messages in different places in the same\n> >>> function. Again, your mileage may very well vary, my data point is just\n> >>> that, a single data point.\n> >>\n> >> Yes, but please remember lots of people are different. Some people\n> >> recognise numbers better than words, and some people follow words better\n> >> than numbers ... All we're doing here is adding an extra word to a\n> >> hopefully rare debug print.\n> > \n> > There's no need to convince me :-) As I've said, I wanted to make sure\n> > that you had really tested this as helping your debugging experience, as\n> > opposed to only thinking it could improve it without actually testing\n> > it. As you say you have, that's enough for me, I trust you, and I'm fine\n> > with the change.\n> \n> A tag of some form would convince me of that ;-)\n\nReviewed-by: Laurent Pinchart \n\n> >> I'm in the later camp. A word will help me prepare my brain for where to\n> >> search.\n> >>\n> >> I might tell you that I live in , Filton, Bristol, which is a\n> >> close approximation to where I live, and not quite as detailed as\n> >>\n> >> 51.50080108642578, -2.5474119186401367 (not my actual address)\n> >>\n> >> And for commencing the journey in either case the reader will likely\n> >> have to look up the exact destination, but a lot more information is\n> >> conveyed with the words than the numbers pre-lookup ...\n> >>\n> >> Of course you might then say but my house has a numerical address, which\n> >> indeed it does, lets call it 100 stop()street, v4l2_device()town....\n> >>\n> >> The line number helps provide the final destination address, but to me,\n> >> the function name is the street name. Perhaps not always essential, but\n> >> a very useful reference point.\n> >>\n> >> And certainly if you have lots of debug prints in the same function,\n> >> then the line number matters. But we already have the line number, so\n> >> I'm not going to argue over the value of that ;-)\n> >>\n> >>>>>> include/libcamera/internal/log.h | 7 ++++---\n> >>>>>> 1 file changed, 4 insertions(+), 3 deletions(-)\n> >>>>>>\n> >>>>>> diff --git a/include/libcamera/internal/log.h b/include/libcamera/internal/log.h\n> >>>>>> index be0bab3c1272..b66bf55bc57d 100644\n> >>>>>> --- a/include/libcamera/internal/log.h\n> >>>>>> +++ b/include/libcamera/internal/log.h\n> >>>>>> @@ -117,9 +117,10 @@ LogMessage _log(const LogCategory *category, LogSeverity severity,\n> >>>>>> #endif /* __DOXYGEN__ */\n> >>>>>> \n> >>>>>> #ifndef NDEBUG\n> >>>>>> -#define ASSERT(condition) static_cast(({\t\t\t\t\\\n> >>>>>> -\tif (!(condition))\t\t\t\t\t\t\\\n> >>>>>> -\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed\";\t\\\n> >>>>>> +#define ASSERT(condition) static_cast(({ \\\n> >>>>>> +\tif (!(condition)) \\\n> >>>>>> +\t\tLOG(Fatal) << \"assertion \\\"\" #condition \"\\\" failed in \" \\\n> >>>>>> +\t\t\t << __func__ << \"()\"; \\\n> >>>>>> }))\n> >>>>>> #else\n> >>>>>> #define ASSERT(condition) static_cast(false && (condition))","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 C9606BDE19\n\tfor ;\n\tTue, 27 Apr 2021 08:12:23 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id 1D935688C3;\n\tTue, 27 Apr 2021 10:12:23 +0200 (CEST)","from perceval.ideasonboard.com (perceval.ideasonboard.com\n\t[IPv6:2001:4b98:dc2:55:216:3eff:fef7:d647])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id 44A5F688B5\n\tfor ;\n\tTue, 27 Apr 2021 10:12:22 +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 9CBB8E9;\n\tTue, 27 Apr 2021 10:12:21 +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=\"o/dvMXHR\"; dkim-atps=neutral","DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/simple; d=ideasonboard.com;\n\ts=mail; t=1619511141;\n\tbh=TrxkZZnU3IftY7/sALhtbmwvWA94Yj6if+/59xecgD8=;\n\th=Date:From:To:Cc:Subject:References:In-Reply-To:From;\n\tb=o/dvMXHR8s/BxE/aYQPS2E/Y7xkNeobB35Ap3vZQ4mPE2Tpj0C9zxfbCQx3q4Jif7\n\tStADomoc35Ue61AWzaQh3HogIXzcZ/ixCm5F5qHCvgswtPQjK2Fy8TZQ8WLtKmEeOY\n\t/2i9G3pAhtJTEdE/hpSRzJNoajwdNDNxEwOphdhs=","Date":"Tue, 27 Apr 2021 11:12:15 +0300","From":"Laurent Pinchart ","To":"Kieran Bingham ","Message-ID":"","References":"<20210420130741.236848-1-kieran.bingham@ideasonboard.com>\n\t<20210420130741.236848-6-kieran.bingham@ideasonboard.com>\n\t\n\t\n\t\n\t<69a60fb0-3c0c-2b1f-c164-1770c0f88942@ideasonboard.com>\n\t\n\t","MIME-Version":"1.0","Content-Disposition":"inline","In-Reply-To":"","Subject":"Re: [libcamera-devel] [PATCH v4 5/6] libcamera: internal: log:\n\tReport function on asserts","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":"text/plain; charset=\"us-ascii\"","Content-Transfer-Encoding":"7bit","Errors-To":"libcamera-devel-bounces@lists.libcamera.org","Sender":"\"libcamera-devel\" "}}]