[{"id":14770,"web_url":"https://patchwork.libcamera.org/comment/14770/","msgid":"","date":"2021-01-26T08:17:51","subject":"Re: [libcamera-devel] [PATCH v2 2/5] ipa: raspberrypi: alsc:\n\tReplace Raspberry Pi debug with libcamera debug","submitter":{"id":2,"url":"https://patchwork.libcamera.org/api/people/2/","name":"Laurent Pinchart","email":"laurent.pinchart@ideasonboard.com"},"content":"Hi David,\n\nThank you for the patch.\n\nOn Mon, Jan 25, 2021 at 06:48:55PM +0000, David Plowman wrote:\n> Some unhelpful debug messages have been removed.\n> \n> Signed-off-by: David Plowman \n> Reviewed-by: Kieran Bingham \n\nReviewed-by: Laurent Pinchart \n\n> ---\n> src/ipa/raspberrypi/controller/rpi/alsc.cpp | 66 +++++++++++----------\n> 1 file changed, 35 insertions(+), 31 deletions(-)\n> \n> diff --git a/src/ipa/raspberrypi/controller/rpi/alsc.cpp b/src/ipa/raspberrypi/controller/rpi/alsc.cpp\n> index c354c985..5262bcab 100644\n> --- a/src/ipa/raspberrypi/controller/rpi/alsc.cpp\n> +++ b/src/ipa/raspberrypi/controller/rpi/alsc.cpp\n> @@ -6,12 +6,17 @@\n> */\n> #include \n> \n> +#include \"libcamera/internal/log.h\"\n> +\n> #include \"../awb_status.h\"\n> #include \"alsc.hpp\"\n> \n> // Raspberry Pi ALSC (Auto Lens Shading Correction) algorithm.\n> \n> using namespace RPiController;\n> +using namespace libcamera;\n> +\n> +LOG_DEFINE_CATEGORY(RPiAlsc)\n> \n> #define NAME \"rpi.alsc\"\n> \n> @@ -110,15 +115,14 @@ static void read_calibrations(std::vector &calibrations,\n> \t\t\t\t\t\"Alsc: too few values for ct \" +\n> \t\t\t\t\tstd::to_string(ct) + \" in \" + name);\n> \t\t\tcalibrations.push_back(calibration);\n> -\t\t\tRPI_LOG(\"Read \" << name << \" calibration for ct \"\n> -\t\t\t\t\t<< ct);\n> +\t\t\tLOG(RPiAlsc, Debug)\n> +\t\t\t\t<< \"Read \" << name << \" calibration for ct \" << ct;\n> \t\t}\n> \t}\n> }\n> \n> void Alsc::Read(boost::property_tree::ptree const ¶ms)\n> {\n> -\tRPI_LOG(\"Alsc\");\n> \tconfig_.frame_period = params.get(\"frame_period\", 12);\n> \tconfig_.startup_frames = params.get(\"startup_frames\", 10);\n> \tconfig_.speed = params.get(\"speed\", 0.05);\n> @@ -139,7 +143,8 @@ void Alsc::Read(boost::property_tree::ptree const ¶ms)\n> \t\tread_lut(config_.luminance_lut,\n> \t\t\t params.get_child(\"luminance_lut\"));\n> \telse\n> -\t\tRPI_WARN(\"Alsc: no luminance table - assume unity everywhere\");\n> +\t\tLOG(RPiAlsc, Warning)\n> +\t\t\t<< \"no luminance table - assume unity everywhere\";\n> \tread_calibrations(config_.calibrations_Cr, params, \"calibrations_Cr\");\n> \tread_calibrations(config_.calibrations_Cb, params, \"calibrations_Cb\");\n> \tconfig_.default_ct = params.get(\"default_ct\", 4500.0);\n> @@ -164,7 +169,6 @@ static void add_luminance_to_tables(double results[3][Y][X],\n> \n> void Alsc::Initialise()\n> {\n> -\tRPI_LOG(\"Alsc\");\n> \tframe_count2_ = frame_count_ = frame_phase_ = 0;\n> \tfirst_time_ = true;\n> \tct_ = config_.default_ct;\n> @@ -252,7 +256,7 @@ void Alsc::SwitchMode(CameraMode const &camera_mode,\n> \n> void Alsc::fetchAsyncResults()\n> {\n> -\tRPI_LOG(\"Fetch ALSC results\");\n> +\tLOG(RPiAlsc, Debug) << \"Fetch ALSC results\";\n> \tasync_finished_ = false;\n> \tasync_started_ = false;\n> \tmemcpy(sync_results_, async_results_, sizeof(sync_results_));\n> @@ -263,11 +267,11 @@ double get_ct(Metadata *metadata, double default_ct)\n> \tAwbStatus awb_status;\n> \tawb_status.temperature_K = default_ct; // in case nothing found\n> \tif (metadata->Get(\"awb.status\", awb_status) != 0)\n> -\t\tRPI_WARN(\"Alsc: no AWB results found, using \"\n> -\t\t\t << awb_status.temperature_K);\n> +\t\tLOG(RPiAlsc, Warning) << \"no AWB results found, using \"\n> +\t\t\t\t << awb_status.temperature_K;\n> \telse\n> -\t\tRPI_LOG(\"Alsc: AWB results found, using \"\n> -\t\t\t<< awb_status.temperature_K);\n> +\t\tLOG(RPiAlsc, Debug) << \"AWB results found, using \"\n> +\t\t\t\t << awb_status.temperature_K;\n> \treturn awb_status.temperature_K;\n> }\n> \n> @@ -289,7 +293,7 @@ static void copy_stats(bcm2835_isp_stats_region regions[XY], StatisticsPtr &stat\n> \n> void Alsc::restartAsync(StatisticsPtr &stats, Metadata *image_metadata)\n> {\n> -\tRPI_LOG(\"Starting ALSC thread\");\n> +\tLOG(RPiAlsc, Debug) << \"Starting ALSC calculation\";\n> \t// Get the current colour temperature. It's all we need from the\n> \t// metadata. Default to the last CT value (which could be the default).\n> \tct_ = get_ct(image_metadata, ct_);\n> @@ -297,7 +301,8 @@ void Alsc::restartAsync(StatisticsPtr &stats, Metadata *image_metadata)\n> \t// the LSC table that the pipeline applied to them.\n> \tAlscStatus alsc_status;\n> \tif (image_metadata->Get(\"alsc.status\", alsc_status) != 0) {\n> -\t\tRPI_WARN(\"No ALSC status found for applied gains!\");\n> +\t\tLOG(RPiAlsc, Warning)\n> +\t\t\t<< \"No ALSC status found for applied gains!\";\n> \t\tfor (int y = 0; y < Y; y++)\n> \t\t\tfor (int x = 0; x < X; x++) {\n> \t\t\t\talsc_status.r[y][x] = 1.0;\n> @@ -324,13 +329,12 @@ void Alsc::Prepare(Metadata *image_metadata)\n> \tdouble speed = frame_count_ < (int)config_.startup_frames\n> \t\t\t ? 1.0\n> \t\t\t : config_.speed;\n> -\tRPI_LOG(\"Alsc: frame_count \" << frame_count_ << \" speed \" << speed);\n> +\tLOG(RPiAlsc, Debug)\n> +\t\t<< \"frame_count \" << frame_count_ << \" speed \" << speed;\n> \t{\n> \t\tstd::unique_lock lock(mutex_);\n> -\t\tif (async_started_ && async_finished_) {\n> -\t\t\tRPI_LOG(\"ALSC thread finished\");\n> +\t\tif (async_started_ && async_finished_)\n> \t\t\tfetchAsyncResults();\n> -\t\t}\n> \t}\n> \t// Apply IIR filter to results and program into the pipeline.\n> \tdouble *ptr = (double *)sync_results_,\n> @@ -354,13 +358,11 @@ void Alsc::Process(StatisticsPtr &stats, Metadata *image_metadata)\n> \t\tframe_phase_++;\n> \tif (frame_count2_ < (int)config_.startup_frames)\n> \t\tframe_count2_++;\n> -\tRPI_LOG(\"Alsc: frame_phase \" << frame_phase_);\n> +\tLOG(RPiAlsc, Debug) << \"frame_phase \" << frame_phase_;\n> \tif (frame_phase_ >= (int)config_.frame_period ||\n> \t frame_count2_ < (int)config_.startup_frames) {\n> -\t\tif (async_started_ == false) {\n> -\t\t\tRPI_LOG(\"ALSC thread starting\");\n> +\t\tif (async_started_ == false)\n> \t\t\trestartAsync(stats, image_metadata);\n> -\t\t}\n> \t}\n> }\n> \n> @@ -391,25 +393,26 @@ void get_cal_table(double ct, std::vector const &calibrations,\n> \tif (calibrations.empty()) {\n> \t\tfor (int i = 0; i < XY; i++)\n> \t\t\tcal_table[i] = 1.0;\n> -\t\tRPI_LOG(\"Alsc: no calibrations found\");\n> +\t\tLOG(RPiAlsc, Debug) << \"no calibrations found\";\n> \t} else if (ct <= calibrations.front().ct) {\n> \t\tmemcpy(cal_table, calibrations.front().table,\n> \t\t XY * sizeof(double));\n> -\t\tRPI_LOG(\"Alsc: using calibration for \"\n> -\t\t\t<< calibrations.front().ct);\n> +\t\tLOG(RPiAlsc, Debug) << \"using calibration for \"\n> +\t\t\t\t << calibrations.front().ct;\n> \t} else if (ct >= calibrations.back().ct) {\n> \t\tmemcpy(cal_table, calibrations.back().table,\n> \t\t XY * sizeof(double));\n> -\t\tRPI_LOG(\"Alsc: using calibration for \"\n> -\t\t\t<< calibrations.front().ct);\n> +\t\tLOG(RPiAlsc, Debug) << \"using calibration for \"\n> +\t\t\t\t << calibrations.front().ct;\n> \t} else {\n> \t\tint idx = 0;\n> \t\twhile (ct > calibrations[idx + 1].ct)\n> \t\t\tidx++;\n> \t\tdouble ct0 = calibrations[idx].ct,\n> \t\t ct1 = calibrations[idx + 1].ct;\n> -\t\tRPI_LOG(\"Alsc: ct is \" << ct << \", interpolating between \"\n> -\t\t\t\t << ct0 << \" and \" << ct1);\n> +\t\tLOG(RPiAlsc, Debug)\n> +\t\t\t<< \"ct is \" << ct << \", interpolating between \"\n> +\t\t\t<< ct0 << \" and \" << ct1;\n> \t\tfor (int i = 0; i < XY; i++)\n> \t\t\tcal_table[i] =\n> \t\t\t\t(calibrations[idx].table[i] * (ct1 - ct) +\n> @@ -660,15 +663,16 @@ static void run_matrix_iterations(double const C[XY], double lambda[XY],\n> \tfor (int i = 0; i < n_iter; i++) {\n> \t\tdouble max_diff = fabs(gauss_seidel2_SOR(M, omega, lambda));\n> \t\tif (max_diff < threshold) {\n> -\t\t\tRPI_LOG(\"Stop after \" << i + 1 << \" iterations\");\n> +\t\t\tLOG(RPiAlsc, Debug)\n> +\t\t\t\t<< \"Stop after \" << i + 1 << \" iterations\";\n> \t\t\tbreak;\n> \t\t}\n> \t\t// this happens very occasionally (so make a note), though\n> \t\t// doesn't seem to matter\n> \t\tif (max_diff > last_max_diff)\n> -\t\t\tRPI_LOG(\"Iteration \" << i << \": max_diff gone up \"\n> -\t\t\t\t\t << last_max_diff << \" to \"\n> -\t\t\t\t\t << max_diff);\n> +\t\t\tLOG(RPiAlsc, Debug)\n> +\t\t\t\t<< \"Iteration \" << i << \": max_diff gone up \"\n> +\t\t\t\t<< last_max_diff << \" to \" << max_diff;\n> \t\tlast_max_diff = max_diff;\n> \t}\n> \t// We're going to normalise the lambdas so the smallest is 1. Not sure","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 867ECBD808\n\tfor ;\n\tTue, 26 Jan 2021 08:18:12 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id 13C09682E1;\n\tTue, 26 Jan 2021 09:18:12 +0100 (CET)","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 079BD6030D\n\tfor ;\n\tTue, 26 Jan 2021 09:18:11 +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 68E282C1;\n\tTue, 26 Jan 2021 09:18:10 +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=\"H1QOstaY\"; dkim-atps=neutral","DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/simple; d=ideasonboard.com;\n\ts=mail; t=1611649090;\n\tbh=G76akDGBmYyiLcGOtnJUEInnv9dtMK33N/g4EA28ueE=;\n\th=Date:From:To:Cc:Subject:References:In-Reply-To:From;\n\tb=H1QOstaYpRRFiwL7Joh3Sk/MZGzHmCx0ZU4ulmr6UIZU3MFETdGIqapAmrVTg6YMw\n\teyAUZz5dQtSibPuA21lN63NHLmwdX7T/S+nqpKarmt/DtfprTtHw1iTgmtM4B67jTX\n\tV1Q0Ugc4ZmiZAKTvdt69oHLrOaxj5OOzcnNIjrbU=","Date":"Tue, 26 Jan 2021 10:17:51 +0200","From":"Laurent Pinchart ","To":"David Plowman ","Message-ID":"","References":"<20210125184858.16339-1-david.plowman@raspberrypi.com>\n\t<20210125184858.16339-3-david.plowman@raspberrypi.com>","MIME-Version":"1.0","Content-Disposition":"inline","In-Reply-To":"<20210125184858.16339-3-david.plowman@raspberrypi.com>","Subject":"Re: [libcamera-devel] [PATCH v2 2/5] ipa: raspberrypi: alsc:\n\tReplace Raspberry Pi debug with libcamera debug","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\" "}}]