[{"id":3517,"web_url":"https://patchwork.libcamera.org/comment/3517/","msgid":"<20200118231948.GC1124294@oden.dyn.berto.se>","date":"2020-01-18T23:19:48","subject":"Re: [libcamera-devel] [PATCH 2/2] libcamera: log: Print the thread\n\tID in the log","submitter":{"id":5,"url":"https://patchwork.libcamera.org/api/people/5/","name":"Niklas Söderlund","email":"niklas.soderlund@ragnatech.se"},"content":"Hi Laurent,\n\nThanks for your work.\n\nOn 2020-01-18 23:33:48 +0200, Laurent Pinchart wrote:\n> The current thread ID is useful when debugging concurrency issues. Print\n> it in log messages. The syslog target is left out as the thread ID would\n> have little use there, and partly duplicates the process ID.\n> \n> Signed-off-by: Laurent Pinchart \n\nReviewed-by: Niklas Söderlund \n\n> ---\n> src/libcamera/log.cpp | 4 +++-\n> 1 file changed, 3 insertions(+), 1 deletion(-)\n> \n> diff --git a/src/libcamera/log.cpp b/src/libcamera/log.cpp\n> index f4eb8c11adc3..1dac4666b435 100644\n> --- a/src/libcamera/log.cpp\n> +++ b/src/libcamera/log.cpp\n> @@ -22,6 +22,7 @@\n> \n> #include \n> \n> +#include \"thread.h\"\n> #include \"utils.h\"\n> \n> /**\n> @@ -196,7 +197,8 @@ void LogOutput::write(const LogMessage &msg)\n> \t\tbreak;\n> \tcase LoggingTargetStream:\n> \tcase LoggingTargetFile:\n> -\t\tstr = \"[\" + utils::time_point_to_string(msg.timestamp()) + \"]\"\n> +\t\tstr = \"[\" + utils::time_point_to_string(msg.timestamp()) + \"] [\"\n> +\t\t + std::to_string(Thread::currentId()) + \"]\"\n> \t\t + log_severity_name(msg.severity()) + \" \"\n> \t\t + msg.category().name() + \" \" + msg.fileInfo() + \" \"\n> \t\t + msg.msg();\n> -- \n> Regards,\n> \n> Laurent Pinchart\n> \n> _______________________________________________\n> libcamera-devel mailing list\n> libcamera-devel@lists.libcamera.org\n> https://lists.libcamera.org/listinfo/libcamera-devel","headers":{"Return-Path":"","Received":["from mail-lj1-x243.google.com (mail-lj1-x243.google.com\n\t[IPv6:2a00:1450:4864:20::243])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id 659AB6079E\n\tfor ;\n\tSun, 19 Jan 2020 00:19:49 +0100 (CET)","by mail-lj1-x243.google.com with SMTP id y6so30217688lji.0\n\tfor ;\n\tSat, 18 Jan 2020 15:19:49 -0800 (PST)","from localhost (h-93-159.A463.priv.bahnhof.se. [46.59.93.159])\n\tby smtp.gmail.com with ESMTPSA id\n\tm16sm14547338ljb.47.2020.01.18.15.19.48\n\t(version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256);\n\tSat, 18 Jan 2020 15:19:48 -0800 (PST)"],"DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/relaxed;\n\td=ragnatech-se.20150623.gappssmtp.com; s=20150623;\n\th=date:from:to:cc:subject:message-id:references:mime-version\n\t:content-disposition:content-transfer-encoding:in-reply-to;\n\tbh=Y+4S1hBVatz0x5xMFRY6oqYSfhtCEwfkUfbNB+zkjpo=;\n\tb=d9SbXCFWTIu0876Z+o0c8va373hALql5OFpCKHozySDrwtMB7z9NDaQe5oUhkGQDIP\n\txWrWbKerkbyBtlel4stQmdfDoYO5BLmYy1BW4MrF4hB+gQDmL7CoUloHWuKuYpOI8IKx\n\taA59Oj5DFgW2yziE282bcKSS4uDTtU38nYYbwbNZC0wePy3Z4xjWU+mLl07avqTCKZ3z\n\t1RbILN4zzMkqZV7HtIDfKiufmdkOx+ts9SLOPjtfmZmvC75d4h8skoIoUycoD+y82ebn\n\tUrznS0uOvAKGKT9bjB1bWHhEoN01aZTJbWEeTuQGMxeqDbFoeZINgllLLx0bm4wTgi6M\n\tMkcw==","X-Google-DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/relaxed;\n\td=1e100.net; s=20161025;\n\th=x-gm-message-state:date:from:to:cc:subject:message-id:references\n\t:mime-version:content-disposition:content-transfer-encoding\n\t:in-reply-to;\n\tbh=Y+4S1hBVatz0x5xMFRY6oqYSfhtCEwfkUfbNB+zkjpo=;\n\tb=Pd9lOdIVJ4rbouyfzFWp1FdmXdecq5efbb3Payj2hqMlEfkmVGd7F/uXv5ffIfkNP7\n\twwUuF6JxQz/kkH9xNtxZnjNQKwaJRwd2gSQpNLqPCr0shIxvGGDa+K4e6b2fkoTKV55a\n\tMSmFYctNlZx5yuLAZWmUq4POS+zezLIlyMSsdQjMsIqz3x0iZur57/Nnc8Bn80hqVwMw\n\t67q2LqCngWztfm/pJ6+7Vm958/N36R1gGyLYMtoadPk+JCrsDG1gxDMTuuKpH6CBJH1J\n\tU9AxoY+geHHXGEv5PkgE5ShQ8yawKFLEZgVSN2wsoZIO+4nb/k5wawBgTJn3Uc2N0T3D\n\tWZMQ==","X-Gm-Message-State":"APjAAAXkpw0Jvxn+HS9xZz6xJ+Ov7vdEBJdIAPmMg5OZ39kkPVqn2K05\n\tuGZLtjjYarM5M2V+B7E44+oy+L+xr/A=","X-Google-Smtp-Source":"APXvYqxo1prb5jSlDHR6wxR/jFDAMzriqE5PSSPzGQyVKHbtHNV4AufOJ99UHHohSYaNvgRv2O7dsA==","X-Received":"by 2002:a2e:9cd8:: with SMTP id\n\tg24mr9390009ljj.243.1579389588814; \n\tSat, 18 Jan 2020 15:19:48 -0800 (PST)","Date":"Sun, 19 Jan 2020 00:19:48 +0100","From":"Niklas =?iso-8859-1?q?S=F6derlund?= ","To":"Laurent Pinchart ","Cc":"libcamera-devel@lists.libcamera.org","Message-ID":"<20200118231948.GC1124294@oden.dyn.berto.se>","References":"<20200118213348.16561-1-laurent.pinchart@ideasonboard.com>\n\t<20200118213348.16561-3-laurent.pinchart@ideasonboard.com>","MIME-Version":"1.0","Content-Type":"text/plain; charset=iso-8859-1","Content-Disposition":"inline","Content-Transfer-Encoding":"8bit","In-Reply-To":"<20200118213348.16561-3-laurent.pinchart@ideasonboard.com>","Subject":"Re: [libcamera-devel] [PATCH 2/2] libcamera: log: Print the thread\n\tID in the log","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","X-List-Received-Date":"Sat, 18 Jan 2020 23:19:49 -0000"}},{"id":3523,"web_url":"https://patchwork.libcamera.org/comment/3523/","msgid":"<781170c4-4288-1d19-19d0-3a6a1ac74fad@ideasonboard.com>","date":"2020-01-20T10:23:54","subject":"Re: [libcamera-devel] [PATCH 2/2] libcamera: log: Print the thread\n\tID in the log","submitter":{"id":4,"url":"https://patchwork.libcamera.org/api/people/4/","name":"Kieran Bingham","email":"kieran.bingham@ideasonboard.com"},"content":"Hi Laurent,\n\nOn 18/01/2020 23:19, Niklas Söderlund wrote:\n> Hi Laurent,\n> \n> Thanks for your work.\n> \n> On 2020-01-18 23:33:48 +0200, Laurent Pinchart wrote:\n>> The current thread ID is useful when debugging concurrency issues. Print\n>> it in log messages. The syslog target is left out as the thread ID would\n>> have little use there, and partly duplicates the process ID.\n>>\n\nAn example print here would be nice to make it easy to see the effect,\n\n>> Signed-off-by: Laurent Pinchart \n> \n> Reviewed-by: Niklas Söderlund \n> \n>> ---\n>> src/libcamera/log.cpp | 4 +++-\n>> 1 file changed, 3 insertions(+), 1 deletion(-)\n>>\n>> diff --git a/src/libcamera/log.cpp b/src/libcamera/log.cpp\n>> index f4eb8c11adc3..1dac4666b435 100644\n>> --- a/src/libcamera/log.cpp\n>> +++ b/src/libcamera/log.cpp\n>> @@ -22,6 +22,7 @@\n>> \n>> #include \n>> \n>> +#include \"thread.h\"\n>> #include \"utils.h\"\n>> \n>> /**\n>> @@ -196,7 +197,8 @@ void LogOutput::write(const LogMessage &msg)\n>> \t\tbreak;\n>> \tcase LoggingTargetStream:\n>> \tcase LoggingTargetFile:\n>> -\t\tstr = \"[\" + utils::time_point_to_string(msg.timestamp()) + \"]\"\n>> +\t\tstr = \"[\" + utils::time_point_to_string(msg.timestamp()) + \"] [\"\n\nAs we already have 2 characters to 'wrap' both the timestamp, and the\nthread ID, do we really need to add a third 'whitespace' separator?\n\nThe debug lines are already getting quite long... So we can argue both\nways, padding is expensive, or lines are already so long - that the\nlength doesn't matter...\n\nIt would be nice if we could keep our debug lines under 120 chars though\n(Purely arbitrary/selfish, That's my terminal width :-D)\n\nNoting of course that I have another patch which expands the debug log\nlevel to normalise spelling against their other usages which expands\nthis string by another character too ...\n\n>> +\t\t + std::to_string(Thread::currentId()) + \"]\"\n\nShould we print this with a fixed width?\n(Yes, I know that would cost extra characters of course)\n\nIn fact, I think I've argued myself out of this one.\nMy rationale was to stop something like this:\n\n> [80:48:31.722536024] DEBUG V4L2 v4l2_videodevice.cpp:1185 /dev/video0[cap]: Queueing buffer 0\n> [80:48:31.757739217] DEBUG V4L2 v4l2_videodevice.cpp:1254 /dev/video0[cap]: Dequeuing buffer 1\n\nlooking like this:\n\n> [80:48:31.722536024] [1234] DEBUG V4L2 v4l2_videodevice.cpp:1185 /dev/video0[cap]: Queueing buffer 0\n> [80:48:31.757739217] [123] DEBUG V4L2 v4l2_videodevice.cpp:1254 /dev/video0[cap]: Dequeuing buffer 1\n\nAs keeping the alignment on the actual message is nicer. But perhaps we\njust need a log parser like Gstreamer provides.\n\n\nDiscussion comments aside,\n\nReviewed-by: Kieran Bingham \n\n\n>> \t\t + log_severity_name(msg.severity()) + \" \"\n>> \t\t + msg.category().name() + \" \" + msg.fileInfo() + \" \"\n>> \t\t + msg.msg();\n>> -- \n>> Regards,\n>>\n>> Laurent Pinchart\n>>\n>> _______________________________________________\n>> libcamera-devel mailing list\n>> libcamera-devel@lists.libcamera.org\n>> https://lists.libcamera.org/listinfo/libcamera-devel\n>","headers":{"Return-Path":"","Received":["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 8314560454\n\tfor ;\n\tMon, 20 Jan 2020 11:23:57 +0100 (CET)","from [192.168.0.20]\n\t(cpc89242-aztw30-2-0-cust488.18-1.cable.virginm.net [86.31.129.233])\n\tby perceval.ideasonboard.com (Postfix) with ESMTPSA id CBB22A62;\n\tMon, 20 Jan 2020 11:23:56 +0100 (CET)"],"DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/simple; d=ideasonboard.com;\n\ts=mail; t=1579515837;\n\tbh=k7cn04OzpcIS8G6cwd8du1kjW+bet9o/No6GK8NcqIo=;\n\th=Reply-To:Subject:To:Cc:References:From:Date:In-Reply-To:From;\n\tb=Y/ZlVAB8DIpfskEnvZy0/Cc0PRvci1sw4pIObF0/bsNBINnLCM2UcIOTczy3fOr6C\n\tESdPNmxe38mWMwTmpAnYNxZfXPWhaRh2/hjTcF57M0I0IVy9v9B844xIUFVoXZXtqN\n\tQRKGG3S6acYoPFaNDgncQbDXL4AQJFux40HJUKaY=","Reply-To":"kieran.bingham@ideasonboard.com","To":"=?utf-8?q?Niklas_S=C3=B6derlund?= ,\n\tLaurent Pinchart ","Cc":"libcamera-devel@lists.libcamera.org","References":"<20200118213348.16561-1-laurent.pinchart@ideasonboard.com>\n\t<20200118213348.16561-3-laurent.pinchart@ideasonboard.com>\n\t<20200118231948.GC1124294@oden.dyn.berto.se>","From":"Kieran Bingham ","Openpgp":"preference=signencrypt","Autocrypt":"addr=kieran.bingham@ideasonboard.com; keydata=\n\tmQINBFYE/WYBEACs1PwjMD9rgCu1hlIiUA1AXR4rv2v+BCLUq//vrX5S5bjzxKAryRf0uHat\n\tV/zwz6hiDrZuHUACDB7X8OaQcwhLaVlq6byfoBr25+hbZG7G3+5EUl9cQ7dQEdvNj6V6y/SC\n\trRanWfelwQThCHckbobWiQJfK9n7rYNcPMq9B8e9F020LFH7Kj6YmO95ewJGgLm+idg1Kb3C\n\tpotzWkXc1xmPzcQ1fvQMOfMwdS+4SNw4rY9f07Xb2K99rjMwZVDgESKIzhsDB5GY465sCsiQ\n\tcSAZRxqE49RTBq2+EQsbrQpIc8XiffAB8qexh5/QPzCmR4kJgCGeHIXBtgRj+nIkCJPZvZtf\n\tKr2EAbc6tgg6DkAEHJb+1okosV09+0+TXywYvtEop/WUOWQ+zo+Y/OBd+8Ptgt1pDRyOBzL8\n\tRXa8ZqRf0Mwg75D+dKntZeJHzPRJyrlfQokngAAs4PaFt6UfS+ypMAF37T6CeDArQC41V3ko\n\tlPn1yMsVD0p+6i3DPvA/GPIksDC4owjnzVX9kM8Zc5Cx+XoAN0w5Eqo4t6qEVbuettxx55gq\n\t8K8FieAjgjMSxngo/HST8TpFeqI5nVeq0/lqtBRQKumuIqDg+Bkr4L1V/PSB6XgQcOdhtd36\n\tOe9X9dXB8YSNt7VjOcO7BTmFn/Z8r92mSAfHXpb07YJWJosQOQARAQABtDBLaWVyYW4gQmlu\n\tZ2hhbSA8a2llcmFuLmJpbmdoYW1AaWRlYXNvbmJvYXJkLmNvbT6JAlcEEwEKAEECGwMFCwkI\n\tBwIGFQgJCgsCBBYCAwECHgECF4ACGQEWIQSQLdeYP70o/eNy1HqhHkZyEKRh/QUCXWTtygUJ\n\tCyJXZAAKCRChHkZyEKRh/f8dEACTDsbLN2nioNZMwyLuQRUAFcXNolDX48xcUXsWS2QjxaPm\n\tVsJx8Uy8aYkS85mdPBh0C83OovQR/OVbr8AxhGvYqBs3nQvbWuTl/+4od7DfK2VZOoKBAu5S\n\tQK2FYuUcikDqYcFWJ8DQnubxfE8dvzojHEkXw0sA4igINHDDFX3HJGZtLio+WpEFQtCbfTAG\n\tYZslasz1YZRbwEdSsmO3/kqy5eMnczlm8a21A3fKUo3g8oAZEFM+f4DUNzqIltg31OAB/kZS\n\tenKZQ/SWC8PmLg/ZXBrReYakxXtkP6w3FwMlzOlhGxqhIRNiAJfXJBaRhuUWzPOpEDE9q5YJ\n\tBmqQL2WJm1VSNNVxbXJHpaWMH1sA2R00vmvRrPXGwyIO0IPYeUYQa3gsy6k+En/aMQJd27dp\n\taScf9am9PFICPY5T4ppneeJLif2lyLojo0mcHOV+uyrds9XkLpp14GfTkeKPdPMrLLTsHRfH\n\tfA4I4OBpRrEPiGIZB/0im98MkGY/Mu6qxeZmYLCcgD6qz4idOvfgVOrNh+aA8HzIVR+RMW8H\n\tQGBN9f0E3kfwxuhl3omo6V7lDw8XOdmuWZNC9zPq1UfryVHANYbLGz9KJ4Aw6M+OgBC2JpkD\n\thXMdHUkC+d20dwXrwHTlrJi1YNp6rBc+xald3wsUPOZ5z8moTHUX/uPA/qhGsbkCDQRWBP1m\n\tARAAzijkb+Sau4hAncr1JjOY+KyFEdUNxRy+hqTJdJfaYihxyaj0Ee0P0zEi35CbE6lgU0Uz\n\ttih9fiUbSV3wfsWqg1Ut3/5rTKu7kLFp15kF7eqvV4uezXRD3Qu4yjv/rMmEJbbD4cTvGCYI\n\td6MDC417f7vK3hCbCVIZSp3GXxyC1LU+UQr3fFcOyCwmP9vDUR9JV0BSqHHxRDdpUXE26Dk6\n\tmhf0V1YkspE5St814ETXpEus2urZE5yJIUROlWPIL+hm3NEWfAP06vsQUyLvr/GtbOT79vXl\n\tEn1aulcYyu20dRRxhkQ6iILaURcxIAVJJKPi8dsoMnS8pB0QW12AHWuirPF0g6DiuUfPmrA5\n\tPKe56IGlpkjc8cO51lIxHkWTpCMWigRdPDexKX+Sb+W9QWK/0JjIc4t3KBaiG8O4yRX8ml2R\n\t+rxfAVKM6V769P/hWoRGdgUMgYHFpHGSgEt80OKK5HeUPy2cngDUXzwrqiM5Sz6Od0qw5pCk\n\tNlXqI0W/who0iSVM+8+RmyY0OEkxEcci7rRLsGnM15B5PjLJjh1f2ULYkv8s4SnDwMZ/kE04\n\t/UqCMK/KnX8pwXEMCjz0h6qWNpGwJ0/tYIgQJZh6bqkvBrDogAvuhf60Sogw+mH8b+PBlx1L\n\toeTK396wc+4c3BfiC6pNtUS5GpsPMMjYMk7kVvEAEQEAAYkCPAQYAQoAJgIbDBYhBJAt15g/\n\tvSj943LUeqEeRnIQpGH9BQJdizzIBQkLSKZiAAoJEKEeRnIQpGH9eYgQAJpjaWNgqNOnMTmD\n\tMJggbwjIotypzIXfhHNCeTkG7+qCDlSaBPclcPGYrTwCt0YWPU2TgGgJrVhYT20ierN8LUvj\n\t6qOPTd+Uk7NFzL65qkh80ZKNBFddx1AabQpSVQKbdcLb8OFs85kuSvFdgqZwgxA1vl4TFhNz\n\tPZ79NAmXLackAx3sOVFhk4WQaKRshCB7cSl+RIng5S/ThOBlwNlcKG7j7W2MC06BlTbdEkUp\n\tECzuuRBv8wX4OQl+hbWbB/VKIx5HKlLu1eypen/5lNVzSqMMIYkkZcjV2SWQyUGxSwq0O/sx\n\tS0A8/atCHUXOboUsn54qdxrVDaK+6jIAuo8JiRWctP16KjzUM7MO0/+4zllM8EY57rXrj48j\n\tsbEYX0YQnzaj+jO6kJtoZsIaYR7rMMq9aUAjyiaEZpmP1qF/2sYenDx0Fg2BSlLvLvXM0vU8\n\tpQk3kgDu7kb/7PRYrZvBsr21EIQoIjXbZxDz/o7z95frkP71EaICttZ6k9q5oxxA5WC6sTXc\n\tMW8zs8avFNuA9VpXt0YupJd2ijtZy2mpZNG02fFVXhIn4G807G7+9mhuC4XG5rKlBBUXTvPU\n\tAfYnB4JBDLmLzBFavQfvonSfbitgXwCG3vS+9HEwAjU30Bar1PEOmIbiAoMzuKeRm2LVpmq4\n\tWZw01QYHU/GUV/zHJSFk","Organization":"Ideas on Board","Message-ID":"<781170c4-4288-1d19-19d0-3a6a1ac74fad@ideasonboard.com>","Date":"Mon, 20 Jan 2020 10:23:54 +0000","User-Agent":"Mozilla/5.0 (X11; Linux x86_64; rv:60.0) Gecko/20100101\n\tThunderbird/60.9.0","MIME-Version":"1.0","In-Reply-To":"<20200118231948.GC1124294@oden.dyn.berto.se>","Content-Type":"text/plain; charset=utf-8","Content-Language":"en-GB","Content-Transfer-Encoding":"8bit","Subject":"Re: [libcamera-devel] [PATCH 2/2] libcamera: log: Print the thread\n\tID in the log","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","X-List-Received-Date":"Mon, 20 Jan 2020 10:23:57 -0000"}},{"id":3526,"web_url":"https://patchwork.libcamera.org/comment/3526/","msgid":"<20200120112014.GB20122@pendragon.ideasonboard.com>","date":"2020-01-20T11:20:14","subject":"Re: [libcamera-devel] [PATCH 2/2] libcamera: log: Print the thread\n\tID in the log","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, Jan 20, 2020 at 10:23:54AM +0000, Kieran Bingham wrote:\n> On 18/01/2020 23:19, Niklas Söderlund wrote:\n> > On 2020-01-18 23:33:48 +0200, Laurent Pinchart wrote:\n> >> The current thread ID is useful when debugging concurrency issues. Print\n> >> it in log messages. The syslog target is left out as the thread ID would\n> >> have little use there, and partly duplicates the process ID.\n> \n> An example print here would be nice to make it easy to see the effect,\n\nI'll add\n\nThe log messages now look as follows.\n\n[19:10:33.206560546] [22096] INFO Camera camera_manager.cpp:274 libcamera v0.0.0+993-32696686\n\n> >> Signed-off-by: Laurent Pinchart \n> > \n> > Reviewed-by: Niklas Söderlund \n> > \n> >> ---\n> >> src/libcamera/log.cpp | 4 +++-\n> >> 1 file changed, 3 insertions(+), 1 deletion(-)\n> >>\n> >> diff --git a/src/libcamera/log.cpp b/src/libcamera/log.cpp\n> >> index f4eb8c11adc3..1dac4666b435 100644\n> >> --- a/src/libcamera/log.cpp\n> >> +++ b/src/libcamera/log.cpp\n> >> @@ -22,6 +22,7 @@\n> >> \n> >> #include \n> >> \n> >> +#include \"thread.h\"\n> >> #include \"utils.h\"\n> >> \n> >> /**\n> >> @@ -196,7 +197,8 @@ void LogOutput::write(const LogMessage &msg)\n> >> \t\tbreak;\n> >> \tcase LoggingTargetStream:\n> >> \tcase LoggingTargetFile:\n> >> -\t\tstr = \"[\" + utils::time_point_to_string(msg.timestamp()) + \"]\"\n> >> +\t\tstr = \"[\" + utils::time_point_to_string(msg.timestamp()) + \"] [\"\n> \n> As we already have 2 characters to 'wrap' both the timestamp, and the\n> thread ID, do we really need to add a third 'whitespace' separator?\n> \n> The debug lines are already getting quite long... So we can argue both\n> ways, padding is expensive, or lines are already so long - that the\n> length doesn't matter...\n> \n> It would be nice if we could keep our debug lines under 120 chars though\n> (Purely arbitrary/selfish, That's my terminal width :-D)\n> \n> Noting of course that I have another patch which expands the debug log\n> level to normalise spelling against their other usages which expands\n> this string by another character too ...\n> \n> >> +\t\t + std::to_string(Thread::currentId()) + \"]\"\n> \n> Should we print this with a fixed width?\n> (Yes, I know that would cost extra characters of course)\n> \n> In fact, I think I've argued myself out of this one.\n> My rationale was to stop something like this:\n> \n> > [80:48:31.722536024] DEBUG V4L2 v4l2_videodevice.cpp:1185 /dev/video0[cap]: Queueing buffer 0\n> > [80:48:31.757739217] DEBUG V4L2 v4l2_videodevice.cpp:1254 /dev/video0[cap]: Dequeuing buffer 1\n> \n> looking like this:\n> \n> > [80:48:31.722536024] [1234] DEBUG V4L2 v4l2_videodevice.cpp:1185 /dev/video0[cap]: Queueing buffer 0\n> > [80:48:31.757739217] [123] DEBUG V4L2 v4l2_videodevice.cpp:1254 /dev/video0[cap]: Dequeuing buffer 1\n> \n> As keeping the alignment on the actual message is nicer. But perhaps we\n> just need a log parser like Gstreamer provides.\n\nI agree there are arguments both ways, and one of my annoyances with the\ngstreamer log is indeed the line length. However, it's hard to be both\nverbose and terse at the same time :-)\n\nIn this specific case, what would you pad the TID with ? Note that it\nwould have to be padded to 5 characters unconditionally. I'm tempted to\nsolve this issue latter, possibly as part of your patch that expands the\nlog level, turning it into a log line normalization patch ? We could\nthen discuss the matter separately from this issue.\n\n> Discussion comments aside,\n> \n> Reviewed-by: Kieran Bingham \n> \n> >> \t\t + log_severity_name(msg.severity()) + \" \"\n> >> \t\t + msg.category().name() + \" \" + msg.fileInfo() + \" \"\n> >> \t\t + msg.msg();","headers":{"Return-Path":"","Received":["from perceval.ideasonboard.com (perceval.ideasonboard.com\n\t[213.167.242.64])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id 0D2CA600F5\n\tfor ;\n\tMon, 20 Jan 2020 12:20:15 +0100 (CET)","from pendragon.ideasonboard.com (81-175-216-236.bb.dnainternet.fi\n\t[81.175.216.236])\n\tby perceval.ideasonboard.com (Postfix) with ESMTPSA id 7AB30A62;\n\tMon, 20 Jan 2020 12:20:14 +0100 (CET)"],"DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/simple; d=ideasonboard.com;\n\ts=mail; t=1579519214;\n\tbh=2RNFeUtii5gtWyz+99etBVKhGEd2t2Bjx6fb6JgKYFY=;\n\th=Date:From:To:Cc:Subject:References:In-Reply-To:From;\n\tb=hAkVKJrR+GEVe6OPtDwV6yGG/tdaGxdXuWqf0bpehdy38bVUtYHXlU1kg99fgzWuM\n\tjSFpgBORZTnA9dHt730BTEwQ3tRRWDeABoFeRr8QIXPR3vO2CL7khJ/bcZn077Z7CT\n\t2RRaC+q0Emg8+wf5n5c30dwUy28xJg6ILodYDXIY=","Date":"Mon, 20 Jan 2020 13:20:14 +0200","From":"Laurent Pinchart ","To":"Kieran Bingham ","Cc":"Niklas =?utf-8?q?S=C3=B6derlund?= ,\n\tlibcamera-devel@lists.libcamera.org","Message-ID":"<20200120112014.GB20122@pendragon.ideasonboard.com>","References":"<20200118213348.16561-1-laurent.pinchart@ideasonboard.com>\n\t<20200118213348.16561-3-laurent.pinchart@ideasonboard.com>\n\t<20200118231948.GC1124294@oden.dyn.berto.se>\n\t<781170c4-4288-1d19-19d0-3a6a1ac74fad@ideasonboard.com>","MIME-Version":"1.0","Content-Type":"text/plain; charset=utf-8","Content-Disposition":"inline","Content-Transfer-Encoding":"8bit","In-Reply-To":"<781170c4-4288-1d19-19d0-3a6a1ac74fad@ideasonboard.com>","User-Agent":"Mutt/1.10.1 (2018-07-13)","Subject":"Re: [libcamera-devel] [PATCH 2/2] libcamera: log: Print the thread\n\tID in the log","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","X-List-Received-Date":"Mon, 20 Jan 2020 11:20:15 -0000"}},{"id":3535,"web_url":"https://patchwork.libcamera.org/comment/3535/","msgid":"<94acaee7-4679-56c5-0762-8641dcd959db@ideasonboard.com>","date":"2020-01-20T12:58:43","subject":"Re: [libcamera-devel] [PATCH 2/2] libcamera: log: Print the thread\n\tID in the log","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/01/2020 11:20, Laurent Pinchart wrote:\n> Hi Kieran,\n> \n> On Mon, Jan 20, 2020 at 10:23:54AM +0000, Kieran Bingham wrote:\n>> On 18/01/2020 23:19, Niklas Söderlund wrote:\n>>> On 2020-01-18 23:33:48 +0200, Laurent Pinchart wrote:\n>>>> The current thread ID is useful when debugging concurrency issues. Print\n>>>> it in log messages. The syslog target is left out as the thread ID would\n>>>> have little use there, and partly duplicates the process ID.\n>>\n>> An example print here would be nice to make it easy to see the effect,\n> \n> I'll add\n> \n> The log messages now look as follows.\n> \n> [19:10:33.206560546] [22096] INFO Camera camera_manager.cpp:274 libcamera v0.0.0+993-32696686\n> \n>>>> Signed-off-by: Laurent Pinchart \n>>>\n>>> Reviewed-by: Niklas Söderlund \n>>>\n>>>> ---\n>>>> src/libcamera/log.cpp | 4 +++-\n>>>> 1 file changed, 3 insertions(+), 1 deletion(-)\n>>>>\n>>>> diff --git a/src/libcamera/log.cpp b/src/libcamera/log.cpp\n>>>> index f4eb8c11adc3..1dac4666b435 100644\n>>>> --- a/src/libcamera/log.cpp\n>>>> +++ b/src/libcamera/log.cpp\n>>>> @@ -22,6 +22,7 @@\n>>>> \n>>>> #include \n>>>> \n>>>> +#include \"thread.h\"\n>>>> #include \"utils.h\"\n>>>> \n>>>> /**\n>>>> @@ -196,7 +197,8 @@ void LogOutput::write(const LogMessage &msg)\n>>>> \t\tbreak;\n>>>> \tcase LoggingTargetStream:\n>>>> \tcase LoggingTargetFile:\n>>>> -\t\tstr = \"[\" + utils::time_point_to_string(msg.timestamp()) + \"]\"\n>>>> +\t\tstr = \"[\" + utils::time_point_to_string(msg.timestamp()) + \"] [\"\n>>\n>> As we already have 2 characters to 'wrap' both the timestamp, and the\n>> thread ID, do we really need to add a third 'whitespace' separator?\n>>\n>> The debug lines are already getting quite long... So we can argue both\n>> ways, padding is expensive, or lines are already so long - that the\n>> length doesn't matter...\n>>\n>> It would be nice if we could keep our debug lines under 120 chars though\n>> (Purely arbitrary/selfish, That's my terminal width :-D)\n>>\n>> Noting of course that I have another patch which expands the debug log\n>> level to normalise spelling against their other usages which expands\n>> this string by another character too ...\n>>\n>>>> +\t\t + std::to_string(Thread::currentId()) + \"]\"\n>>\n>> Should we print this with a fixed width?\n>> (Yes, I know that would cost extra characters of course)\n>>\n>> In fact, I think I've argued myself out of this one.\n>> My rationale was to stop something like this:\n>>\n>>> [80:48:31.722536024] DEBUG V4L2 v4l2_videodevice.cpp:1185 /dev/video0[cap]: Queueing buffer 0\n>>> [80:48:31.757739217] DEBUG V4L2 v4l2_videodevice.cpp:1254 /dev/video0[cap]: Dequeuing buffer 1\n>>\n>> looking like this:\n>>\n>>> [80:48:31.722536024] [1234] DEBUG V4L2 v4l2_videodevice.cpp:1185 /dev/video0[cap]: Queueing buffer 0\n>>> [80:48:31.757739217] [123] DEBUG V4L2 v4l2_videodevice.cpp:1254 /dev/video0[cap]: Dequeuing buffer 1\n>>\n>> As keeping the alignment on the actual message is nicer. But perhaps we\n>> just need a log parser like Gstreamer provides.\n> \n> I agree there are arguments both ways, and one of my annoyances with the\n> gstreamer log is indeed the line length. However, it's hard to be both\n> verbose and terse at the same time :-)\n> \n> In this specific case, what would you pad the TID with ? Note that it\n> would have to be padded to 5 characters unconditionally. I'm tempted to\n> solve this issue latter, possibly as part of your patch that expands the\n> log level, turning it into a log line normalization patch ? We could\n> then discuss the matter separately from this issue.\n\nI think for a thread ID it would probably just be whitespace padding.\nLeading-Zero padding is an option, but not a friendly one.\n\nAgreed though, I don't think it's an issue for this patch - lets get\nthese integrated.\n\n> \n>> Discussion comments aside,\n>>\n>> Reviewed-by: Kieran Bingham \n>>\n>>>> \t\t + log_severity_name(msg.severity()) + \" \"\n>>>> \t\t + msg.category().name() + \" \" + msg.fileInfo() + \" \"\n>>>> \t\t + msg.msg();\n>","headers":{"Return-Path":"","Received":["from perceval.ideasonboard.com (perceval.ideasonboard.com\n\t[213.167.242.64])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id 5B8D560804\n\tfor ;\n\tMon, 20 Jan 2020 13:58:47 +0100 (CET)","from [192.168.0.20]\n\t(cpc89242-aztw30-2-0-cust488.18-1.cable.virginm.net [86.31.129.233])\n\tby perceval.ideasonboard.com (Postfix) with ESMTPSA id B840FA62;\n\tMon, 20 Jan 2020 13:58:46 +0100 (CET)"],"DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/simple; d=ideasonboard.com;\n\ts=mail; t=1579525126;\n\tbh=1eX5Hi4q8bElVrG6Oxc3mQT49Abq9UIvyABDg+RYCLU=;\n\th=Reply-To:Subject:To:Cc:References:From:Date:In-Reply-To:From;\n\tb=jNBCrcA4D+hOjCn28EXyPXjAGFBvqBpFzwJB5a2iNCsoazvonAOsQgRLDbBCrV3DR\n\tJ7ZrgtOob177I6O2G0LuSdGVQrUGrsz8Cun/V4Szk8XDa45JnA5m3L5WkRahbVmlRV\n\txmm/CPOPjmUKS4PtX/tB/EK2EVEH0/2PVY2FCTL8=","Reply-To":"kieran.bingham@ideasonboard.com","To":"Laurent Pinchart ","Cc":"=?utf-8?q?Niklas_S=C3=B6derlund?= ,\n\tlibcamera-devel@lists.libcamera.org","References":"<20200118213348.16561-1-laurent.pinchart@ideasonboard.com>\n\t<20200118213348.16561-3-laurent.pinchart@ideasonboard.com>\n\t<20200118231948.GC1124294@oden.dyn.berto.se>\n\t<781170c4-4288-1d19-19d0-3a6a1ac74fad@ideasonboard.com>\n\t<20200120112014.GB20122@pendragon.ideasonboard.com>","From":"Kieran Bingham ","Openpgp":"preference=signencrypt","Autocrypt":"addr=kieran.bingham@ideasonboard.com; keydata=\n\tmQINBFYE/WYBEACs1PwjMD9rgCu1hlIiUA1AXR4rv2v+BCLUq//vrX5S5bjzxKAryRf0uHat\n\tV/zwz6hiDrZuHUACDB7X8OaQcwhLaVlq6byfoBr25+hbZG7G3+5EUl9cQ7dQEdvNj6V6y/SC\n\trRanWfelwQThCHckbobWiQJfK9n7rYNcPMq9B8e9F020LFH7Kj6YmO95ewJGgLm+idg1Kb3C\n\tpotzWkXc1xmPzcQ1fvQMOfMwdS+4SNw4rY9f07Xb2K99rjMwZVDgESKIzhsDB5GY465sCsiQ\n\tcSAZRxqE49RTBq2+EQsbrQpIc8XiffAB8qexh5/QPzCmR4kJgCGeHIXBtgRj+nIkCJPZvZtf\n\tKr2EAbc6tgg6DkAEHJb+1okosV09+0+TXywYvtEop/WUOWQ+zo+Y/OBd+8Ptgt1pDRyOBzL8\n\tRXa8ZqRf0Mwg75D+dKntZeJHzPRJyrlfQokngAAs4PaFt6UfS+ypMAF37T6CeDArQC41V3ko\n\tlPn1yMsVD0p+6i3DPvA/GPIksDC4owjnzVX9kM8Zc5Cx+XoAN0w5Eqo4t6qEVbuettxx55gq\n\t8K8FieAjgjMSxngo/HST8TpFeqI5nVeq0/lqtBRQKumuIqDg+Bkr4L1V/PSB6XgQcOdhtd36\n\tOe9X9dXB8YSNt7VjOcO7BTmFn/Z8r92mSAfHXpb07YJWJosQOQARAQABtDBLaWVyYW4gQmlu\n\tZ2hhbSA8a2llcmFuLmJpbmdoYW1AaWRlYXNvbmJvYXJkLmNvbT6JAlcEEwEKAEECGwMFCwkI\n\tBwIGFQgJCgsCBBYCAwECHgECF4ACGQEWIQSQLdeYP70o/eNy1HqhHkZyEKRh/QUCXWTtygUJ\n\tCyJXZAAKCRChHkZyEKRh/f8dEACTDsbLN2nioNZMwyLuQRUAFcXNolDX48xcUXsWS2QjxaPm\n\tVsJx8Uy8aYkS85mdPBh0C83OovQR/OVbr8AxhGvYqBs3nQvbWuTl/+4od7DfK2VZOoKBAu5S\n\tQK2FYuUcikDqYcFWJ8DQnubxfE8dvzojHEkXw0sA4igINHDDFX3HJGZtLio+WpEFQtCbfTAG\n\tYZslasz1YZRbwEdSsmO3/kqy5eMnczlm8a21A3fKUo3g8oAZEFM+f4DUNzqIltg31OAB/kZS\n\tenKZQ/SWC8PmLg/ZXBrReYakxXtkP6w3FwMlzOlhGxqhIRNiAJfXJBaRhuUWzPOpEDE9q5YJ\n\tBmqQL2WJm1VSNNVxbXJHpaWMH1sA2R00vmvRrPXGwyIO0IPYeUYQa3gsy6k+En/aMQJd27dp\n\taScf9am9PFICPY5T4ppneeJLif2lyLojo0mcHOV+uyrds9XkLpp14GfTkeKPdPMrLLTsHRfH\n\tfA4I4OBpRrEPiGIZB/0im98MkGY/Mu6qxeZmYLCcgD6qz4idOvfgVOrNh+aA8HzIVR+RMW8H\n\tQGBN9f0E3kfwxuhl3omo6V7lDw8XOdmuWZNC9zPq1UfryVHANYbLGz9KJ4Aw6M+OgBC2JpkD\n\thXMdHUkC+d20dwXrwHTlrJi1YNp6rBc+xald3wsUPOZ5z8moTHUX/uPA/qhGsbkCDQRWBP1m\n\tARAAzijkb+Sau4hAncr1JjOY+KyFEdUNxRy+hqTJdJfaYihxyaj0Ee0P0zEi35CbE6lgU0Uz\n\ttih9fiUbSV3wfsWqg1Ut3/5rTKu7kLFp15kF7eqvV4uezXRD3Qu4yjv/rMmEJbbD4cTvGCYI\n\td6MDC417f7vK3hCbCVIZSp3GXxyC1LU+UQr3fFcOyCwmP9vDUR9JV0BSqHHxRDdpUXE26Dk6\n\tmhf0V1YkspE5St814ETXpEus2urZE5yJIUROlWPIL+hm3NEWfAP06vsQUyLvr/GtbOT79vXl\n\tEn1aulcYyu20dRRxhkQ6iILaURcxIAVJJKPi8dsoMnS8pB0QW12AHWuirPF0g6DiuUfPmrA5\n\tPKe56IGlpkjc8cO51lIxHkWTpCMWigRdPDexKX+Sb+W9QWK/0JjIc4t3KBaiG8O4yRX8ml2R\n\t+rxfAVKM6V769P/hWoRGdgUMgYHFpHGSgEt80OKK5HeUPy2cngDUXzwrqiM5Sz6Od0qw5pCk\n\tNlXqI0W/who0iSVM+8+RmyY0OEkxEcci7rRLsGnM15B5PjLJjh1f2ULYkv8s4SnDwMZ/kE04\n\t/UqCMK/KnX8pwXEMCjz0h6qWNpGwJ0/tYIgQJZh6bqkvBrDogAvuhf60Sogw+mH8b+PBlx1L\n\toeTK396wc+4c3BfiC6pNtUS5GpsPMMjYMk7kVvEAEQEAAYkCPAQYAQoAJgIbDBYhBJAt15g/\n\tvSj943LUeqEeRnIQpGH9BQJdizzIBQkLSKZiAAoJEKEeRnIQpGH9eYgQAJpjaWNgqNOnMTmD\n\tMJggbwjIotypzIXfhHNCeTkG7+qCDlSaBPclcPGYrTwCt0YWPU2TgGgJrVhYT20ierN8LUvj\n\t6qOPTd+Uk7NFzL65qkh80ZKNBFddx1AabQpSVQKbdcLb8OFs85kuSvFdgqZwgxA1vl4TFhNz\n\tPZ79NAmXLackAx3sOVFhk4WQaKRshCB7cSl+RIng5S/ThOBlwNlcKG7j7W2MC06BlTbdEkUp\n\tECzuuRBv8wX4OQl+hbWbB/VKIx5HKlLu1eypen/5lNVzSqMMIYkkZcjV2SWQyUGxSwq0O/sx\n\tS0A8/atCHUXOboUsn54qdxrVDaK+6jIAuo8JiRWctP16KjzUM7MO0/+4zllM8EY57rXrj48j\n\tsbEYX0YQnzaj+jO6kJtoZsIaYR7rMMq9aUAjyiaEZpmP1qF/2sYenDx0Fg2BSlLvLvXM0vU8\n\tpQk3kgDu7kb/7PRYrZvBsr21EIQoIjXbZxDz/o7z95frkP71EaICttZ6k9q5oxxA5WC6sTXc\n\tMW8zs8avFNuA9VpXt0YupJd2ijtZy2mpZNG02fFVXhIn4G807G7+9mhuC4XG5rKlBBUXTvPU\n\tAfYnB4JBDLmLzBFavQfvonSfbitgXwCG3vS+9HEwAjU30Bar1PEOmIbiAoMzuKeRm2LVpmq4\n\tWZw01QYHU/GUV/zHJSFk","Organization":"Ideas on Board","Message-ID":"<94acaee7-4679-56c5-0762-8641dcd959db@ideasonboard.com>","Date":"Mon, 20 Jan 2020 12:58:43 +0000","User-Agent":"Mozilla/5.0 (X11; Linux x86_64; rv:60.0) Gecko/20100101\n\tThunderbird/60.9.0","MIME-Version":"1.0","In-Reply-To":"<20200120112014.GB20122@pendragon.ideasonboard.com>","Content-Type":"text/plain; charset=utf-8","Content-Language":"en-GB","Content-Transfer-Encoding":"8bit","Subject":"Re: [libcamera-devel] [PATCH 2/2] libcamera: log: Print the thread\n\tID in the log","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","X-List-Received-Date":"Mon, 20 Jan 2020 12:58:47 -0000"}}]