[{"id":14771,"web_url":"https://patchwork.libcamera.org/comment/14771/","msgid":"<YA/RaxeixtPJImj0@pendragon.ideasonboard.com>","date":"2021-01-26T08:23:07","subject":"Re: [libcamera-devel] [PATCH v2 3/5] ipa: raspberrypi: awb: Replace\n\tRaspberry 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:56PM +0000, David Plowman wrote:\n> Signed-off-by: David Plowman <david.plowman@raspberrypi.com>\n> Reviewed-by: Kieran Bingham <kieran.bingham@ideasonboard.com>\n\nReviewed-by: Laurent Pinchart <laurent.pinchart@ideasonboard.com>\n\n> ---\n>  src/ipa/raspberrypi/controller/rpi/awb.cpp | 97 ++++++++++++----------\n>  1 file changed, 53 insertions(+), 44 deletions(-)\n> \n> diff --git a/src/ipa/raspberrypi/controller/rpi/awb.cpp b/src/ipa/raspberrypi/controller/rpi/awb.cpp\n> index f66c2b29..62337b13 100644\n> --- a/src/ipa/raspberrypi/controller/rpi/awb.cpp\n> +++ b/src/ipa/raspberrypi/controller/rpi/awb.cpp\n> @@ -5,12 +5,16 @@\n>   * awb.cpp - AWB control algorithm\n>   */\n>  \n> -#include \"../logging.hpp\"\n> +#include \"libcamera/internal/log.h\"\n> +\n>  #include \"../lux_status.h\"\n>  \n>  #include \"awb.hpp\"\n>  \n>  using namespace RPiController;\n> +using namespace libcamera;\n> +\n> +LOG_DEFINE_CATEGORY(RPiAwb)\n>  \n>  #define NAME \"rpi.awb\"\n>  \n> @@ -58,7 +62,6 @@ static void read_ct_curve(Pwl &ct_r, Pwl &ct_b,\n>  \n>  void AwbConfig::Read(boost::property_tree::ptree const &params)\n>  {\n> -\tRPI_LOG(\"AwbConfig\");\n>  \tbayes = params.get<int>(\"bayes\", 1);\n>  \tframe_period = params.get<uint16_t>(\"frame_period\", 10);\n>  \tstartup_frames = params.get<uint16_t>(\"startup_frames\", 10);\n> @@ -104,8 +107,8 @@ void AwbConfig::Read(boost::property_tree::ptree const &params)\n>  \tif (bayes) {\n>  \t\tif (ct_r.Empty() || ct_b.Empty() || priors.empty() ||\n>  \t\t    default_mode == nullptr) {\n> -\t\t\tRPI_WARN(\n> -\t\t\t\t\"Bayesian AWB mis-configured - switch to Grey method\");\n> +\t\t\tLOG(RPiAwb, Warning)\n> +\t\t\t\t<< \"Bayesian AWB mis-configured - switch to Grey method\";\n>  \t\t\tbayes = false;\n>  \t\t}\n>  \t}\n> @@ -220,7 +223,7 @@ void Awb::SwitchMode([[maybe_unused]] CameraMode const &camera_mode,\n>  \n>  void Awb::fetchAsyncResults()\n>  {\n> -\tRPI_LOG(\"Fetch AWB results\");\n> +\tLOG(RPiAwb, Debug) << \"Fetch AWB results\";\n>  \tasync_finished_ = false;\n>  \tasync_started_ = false;\n>  \tsync_results_ = async_results_;\n> @@ -229,7 +232,7 @@ void Awb::fetchAsyncResults()\n>  void Awb::restartAsync(StatisticsPtr &stats, std::string const &mode_name,\n>  \t\t       double lux)\n>  {\n> -\tRPI_LOG(\"Starting AWB thread\");\n> +\tLOG(RPiAwb, Debug) << \"Starting AWB calculation\";\n>  \t// this makes a new reference which belongs to the asynchronous thread\n>  \tstatistics_ = stats;\n>  \t// store the mode as it could technically change\n> @@ -254,13 +257,12 @@ void Awb::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(\"Awb: frame_count \" << frame_count_ << \" speed \" << speed);\n> +\tLOG(RPiAwb, Debug)\n> +\t\t<< \"frame_count \" << frame_count_ << \" speed \" << speed;\n>  \t{\n>  \t\tstd::unique_lock<std::mutex> lock(mutex_);\n> -\t\tif (async_started_ && async_finished_) {\n> -\t\t\tRPI_LOG(\"AWB thread finished\");\n> +\t\tif (async_started_ && async_finished_)\n>  \t\t\tfetchAsyncResults();\n> -\t\t}\n>  \t}\n>  \t// Finally apply IIR filter to results and put into metadata.\n>  \tmemcpy(prev_sync_results_.mode, sync_results_.mode,\n> @@ -275,9 +277,10 @@ void Awb::Prepare(Metadata *image_metadata)\n>  \tprev_sync_results_.gain_b = speed * sync_results_.gain_b +\n>  \t\t\t\t    (1.0 - speed) * prev_sync_results_.gain_b;\n>  \timage_metadata->Set(\"awb.status\", prev_sync_results_);\n> -\tRPI_LOG(\"Using AWB gains r \" << prev_sync_results_.gain_r << \" g \"\n> -\t\t\t\t     << prev_sync_results_.gain_g << \" b \"\n> -\t\t\t\t     << prev_sync_results_.gain_b);\n> +\tLOG(RPiAwb, Debug)\n> +\t\t<< \"Using AWB gains r \" << prev_sync_results_.gain_r << \" g \"\n> +\t\t<< prev_sync_results_.gain_g << \" b \"\n> +\t\t<< prev_sync_results_.gain_b;\n>  }\n>  \n>  void Awb::Process(StatisticsPtr &stats, Metadata *image_metadata)\n> @@ -287,7 +290,7 @@ void Awb::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(\"Awb: frame_phase \" << frame_phase_);\n> +\tLOG(RPiAwb, Debug) << \"frame_phase \" << frame_phase_;\n>  \tif (frame_phase_ >= (int)config_.frame_period ||\n>  \t    frame_count2_ < (int)config_.startup_frames) {\n>  \t\t// Update any settings and any image metadata that we need.\n> @@ -299,14 +302,12 @@ void Awb::Process(StatisticsPtr &stats, Metadata *image_metadata)\n>  \t\tstruct LuxStatus lux_status = {};\n>  \t\tlux_status.lux = 400; // in case no metadata\n>  \t\tif (image_metadata->Get(\"lux.status\", lux_status) != 0)\n> -\t\t\tRPI_LOG(\"No lux metadata found\");\n> -\t\tRPI_LOG(\"Awb lux value is \" << lux_status.lux);\n> +\t\t\tLOG(RPiAwb, Debug) << \"No lux metadata found\";\n> +\t\tLOG(RPiAwb, Debug) << \"Awb lux value is \" << lux_status.lux;\n>  \n>  \t\tstd::unique_lock<std::mutex> lock(mutex_);\n> -\t\tif (async_started_ == false) {\n> -\t\t\tRPI_LOG(\"AWB thread starting\");\n> +\t\tif (async_started_ == false)\n>  \t\t\trestartAsync(stats, mode_name, lux_status.lux);\n> -\t\t}\n>  \t}\n>  }\n>  \n> @@ -375,7 +376,7 @@ double Awb::computeDelta2Sum(double gain_r, double gain_b)\n>  \t\tdouble delta_r = gain_r * z.R - 1 - config_.whitepoint_r;\n>  \t\tdouble delta_b = gain_b * z.B - 1 - config_.whitepoint_b;\n>  \t\tdouble delta2 = delta_r * delta_r + delta_b * delta_b;\n> -\t\t//RPI_LOG(\"delta_r \" << delta_r << \" delta_b \" << delta_b << \" delta2 \" << delta2);\n> +\t\t//LOG(RPiAwb, Debug) << \"delta_r \" << delta_r << \" delta_b \" << delta_b << \" delta2 \" << delta2;\n>  \t\tdelta2 = std::min(delta2, config_.delta_limit);\n>  \t\tdelta2_sum += delta2;\n>  \t}\n> @@ -438,10 +439,11 @@ double Awb::coarseSearch(Pwl const &prior)\n>  \t\tdouble prior_log_likelihood =\n>  \t\t\tprior.Eval(prior.Domain().Clip(t));\n>  \t\tdouble final_log_likelihood = delta2_sum - prior_log_likelihood;\n> -\t\tRPI_LOG(\"t: \" << t << \" gain_r \" << gain_r << \" gain_b \"\n> -\t\t\t      << gain_b << \" delta2_sum \" << delta2_sum\n> -\t\t\t      << \" prior \" << prior_log_likelihood << \" final \"\n> -\t\t\t      << final_log_likelihood);\n> +\t\tLOG(RPiAwb, Debug)\n> +\t\t\t<< \"t: \" << t << \" gain_r \" << gain_r << \" gain_b \"\n> +\t\t\t<< gain_b << \" delta2_sum \" << delta2_sum\n> +\t\t\t<< \" prior \" << prior_log_likelihood << \" final \"\n> +\t\t\t<< final_log_likelihood;\n>  \t\tpoints_.push_back(Pwl::Point(t, final_log_likelihood));\n>  \t\tif (points_.back().y < points_[best_point].y)\n>  \t\t\tbest_point = points_.size() - 1;\n> @@ -452,7 +454,7 @@ double Awb::coarseSearch(Pwl const &prior)\n>  \t\t\t     mode_->ct_hi);\n>  \t}\n>  \tt = points_[best_point].x;\n> -\tRPI_LOG(\"Coarse search found CT \" << t);\n> +\tLOG(RPiAwb, Debug) << \"Coarse search found CT \" << t;\n>  \t// We have the best point of the search, but refine it with a quadratic\n>  \t// interpolation around its neighbours.\n>  \tif (points_.size() > 2) {\n> @@ -461,8 +463,9 @@ double Awb::coarseSearch(Pwl const &prior)\n>  \t\tt = interpolate_quadatric(points_[best_point - 1],\n>  \t\t\t\t\t  points_[best_point],\n>  \t\t\t\t\t  points_[best_point + 1]);\n> -\t\tRPI_LOG(\"After quadratic refinement, coarse search has CT \"\n> -\t\t\t<< t);\n> +\t\tLOG(RPiAwb, Debug)\n> +\t\t\t<< \"After quadratic refinement, coarse search has CT \"\n> +\t\t\t<< t;\n>  \t}\n>  \treturn t;\n>  }\n> @@ -514,8 +517,9 @@ void Awb::fineSearch(double &t, double &r, double &b, Pwl const &prior)\n>  \t\t\tdouble gain_r = 1 / r_test, gain_b = 1 / b_test;\n>  \t\t\tdouble delta2_sum = computeDelta2Sum(gain_r, gain_b);\n>  \t\t\tpoints[j].y = delta2_sum - prior_log_likelihood;\n> -\t\t\tRPI_LOG(\"At t \" << t_test << \" r \" << r_test << \" b \"\n> -\t\t\t\t\t<< b_test << \": \" << points[j].y);\n> +\t\t\tLOG(RPiAwb, Debug)\n> +\t\t\t\t<< \"At t \" << t_test << \" r \" << r_test << \" b \"\n> +\t\t\t\t<< b_test << \": \" << points[j].y;\n>  \t\t\tif (points[j].y < points[best_point].y)\n>  \t\t\t\tbest_point = j;\n>  \t\t}\n> @@ -532,17 +536,18 @@ void Awb::fineSearch(double &t, double &r, double &b, Pwl const &prior)\n>  \t\tdouble gain_r = 1 / r_test, gain_b = 1 / b_test;\n>  \t\tdouble delta2_sum = computeDelta2Sum(gain_r, gain_b);\n>  \t\tdouble final_log_likelihood = delta2_sum - prior_log_likelihood;\n> -\t\tRPI_LOG(\"Finally \"\n> +\t\tLOG(RPiAwb, Debug)\n> +\t\t\t<< \"Finally \"\n>  \t\t\t<< t_test << \" r \" << r_test << \" b \" << b_test << \": \"\n>  \t\t\t<< final_log_likelihood\n> -\t\t\t<< (final_log_likelihood < best_log_likelihood ? \" BEST\"\n> -\t\t\t\t\t\t\t\t       : \"\"));\n> +\t\t\t<< (final_log_likelihood < best_log_likelihood ? \" BEST\" : \"\");\n>  \t\tif (best_t == 0 || final_log_likelihood < best_log_likelihood)\n>  \t\t\tbest_log_likelihood = final_log_likelihood,\n>  \t\t\tbest_t = t_test, best_r = r_test, best_b = b_test;\n>  \t}\n>  \tt = best_t, r = best_r, b = best_b;\n> -\tRPI_LOG(\"Fine search found t \" << t << \" r \" << r << \" b \" << b);\n> +\tLOG(RPiAwb, Debug)\n> +\t\t<< \"Fine search found t \" << t << \" r \" << r << \" b \" << b;\n>  }\n>  \n>  void Awb::awbBayes()\n> @@ -556,13 +561,14 @@ void Awb::awbBayes()\n>  \tPwl prior = interpolatePrior();\n>  \tprior *= zones_.size() / (double)(AWB_STATS_SIZE_X * AWB_STATS_SIZE_Y);\n>  \tprior.Map([](double x, double y) {\n> -\t\tRPI_LOG(\"(\" << x << \",\" << y << \")\");\n> +\t\tLOG(RPiAwb, Debug) << \"(\" << x << \",\" << y << \")\";\n>  \t});\n>  \tdouble t = coarseSearch(prior);\n>  \tdouble r = config_.ct_r.Eval(t);\n>  \tdouble b = config_.ct_b.Eval(t);\n> -\tRPI_LOG(\"After coarse search: r \" << r << \" b \" << b << \" (gains r \"\n> -\t\t\t\t\t  << 1 / r << \" b \" << 1 / b << \")\");\n> +\tLOG(RPiAwb, Debug)\n> +\t\t<< \"After coarse search: r \" << r << \" b \" << b << \" (gains r \"\n> +\t\t<< 1 / r << \" b \" << 1 / b << \")\";\n>  \t// Not entirely sure how to handle the fine search yet. Mostly the\n>  \t// estimated CT is already good enough, but the fine search allows us to\n>  \t// wander transverely off the CT curve. Under some illuminants, where\n> @@ -570,8 +576,9 @@ void Awb::awbBayes()\n>  \t// though I probably need more real datasets before deciding exactly how\n>  \t// this should be controlled and tuned.\n>  \tfineSearch(t, r, b, prior);\n> -\tRPI_LOG(\"After fine search: r \" << r << \" b \" << b << \" (gains r \"\n> -\t\t\t\t\t<< 1 / r << \" b \" << 1 / b << \")\");\n> +\tLOG(RPiAwb, Debug)\n> +\t\t<< \"After fine search: r \" << r << \" b \" << b << \" (gains r \"\n> +\t\t<< 1 / r << \" b \" << 1 / b << \")\";\n>  \t// Write results out for the main thread to pick up. Remember to adjust\n>  \t// the gains from the ones that the \"canonical sensor\" would require to\n>  \t// the ones needed by *this* sensor.\n> @@ -583,7 +590,7 @@ void Awb::awbBayes()\n>  \n>  void Awb::awbGrey()\n>  {\n> -\tRPI_LOG(\"Grey world AWB\");\n> +\tLOG(RPiAwb, Debug) << \"Grey world AWB\";\n>  \t// Make a separate list of the derivatives for each of red and blue, so\n>  \t// that we can sort them to exclude the extreme gains.  We could\n>  \t// consider some variations, such as normalising all the zones first, or\n> @@ -620,21 +627,23 @@ void Awb::doAwb()\n>  \t\tasync_results_.gain_r = manual_r_;\n>  \t\tasync_results_.gain_g = 1.0;\n>  \t\tasync_results_.gain_b = manual_b_;\n> -\t\tRPI_LOG(\"Using manual white balance: gain_r \"\n> +\t\tLOG(RPiAwb, Debug)\n> +\t\t\t<< \"Using manual white balance: gain_r \"\n>  \t\t\t<< async_results_.gain_r << \" gain_b \"\n> -\t\t\t<< async_results_.gain_b);\n> +\t\t\t<< async_results_.gain_b;\n>  \t} else {\n>  \t\tprepareStats();\n> -\t\tRPI_LOG(\"Valid zones: \" << zones_.size());\n> +\t\tLOG(RPiAwb, Debug) << \"Valid zones: \" << zones_.size();\n>  \t\tif (zones_.size() > config_.min_regions) {\n>  \t\t\tif (config_.bayes)\n>  \t\t\t\tawbBayes();\n>  \t\t\telse\n>  \t\t\t\tawbGrey();\n> -\t\t\tRPI_LOG(\"CT found is \"\n> +\t\t\tLOG(RPiAwb, Debug)\n> +\t\t\t\t<< \"CT found is \"\n>  \t\t\t\t<< async_results_.temperature_K\n>  \t\t\t\t<< \" with gains r \" << async_results_.gain_r\n> -\t\t\t\t<< \" and b \" << async_results_.gain_b);\n> +\t\t\t\t<< \" and b \" << async_results_.gain_b;\n>  \t\t}\n>  \t}\n>  }","headers":{"Return-Path":"<libcamera-devel-bounces@lists.libcamera.org>","X-Original-To":"parsemail@patchwork.libcamera.org","Delivered-To":"parsemail@patchwork.libcamera.org","Received":["from lancelot.ideasonboard.com (lancelot.ideasonboard.com\n\t[92.243.16.209])\n\tby patchwork.libcamera.org (Postfix) with ESMTPS id 8A22CC0F2B\n\tfor <parsemail@patchwork.libcamera.org>;\n\tTue, 26 Jan 2021 08:23:28 +0000 (UTC)","from lancelot.ideasonboard.com (localhost [IPv6:::1])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTP id EC1B1682DF;\n\tTue, 26 Jan 2021 09:23:27 +0100 (CET)","from perceval.ideasonboard.com (perceval.ideasonboard.com\n\t[213.167.242.64])\n\tby lancelot.ideasonboard.com (Postfix) with ESMTPS id B655C6030D\n\tfor <libcamera-devel@lists.libcamera.org>;\n\tTue, 26 Jan 2021 09:23:26 +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 31DAE2C1;\n\tTue, 26 Jan 2021 09:23:26 +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=\"Cl5oxq+w\"; dkim-atps=neutral","DKIM-Signature":"v=1; a=rsa-sha256; c=relaxed/simple; d=ideasonboard.com;\n\ts=mail; t=1611649406;\n\tbh=U3dnsU7oWFUeSYeXxRUFDAz5LmpEHT05PqtcmyEaNac=;\n\th=Date:From:To:Cc:Subject:References:In-Reply-To:From;\n\tb=Cl5oxq+wvnUcIuqSWFokTJhxiSP/oRqEcgRUkGhCaRip/tvGnQLG+Jld+AYb51LsX\n\tCS4+9s7Jf00nbqSgFlgwqELF/DZDoeUdmtOyCg/xPgNHbfodxadEWZ2FxOSLTbc48K\n\tUzDQ2JE7lMAQsf2o6K7BPc1ucvTrbyZWhQxLB8/Q=","Date":"Tue, 26 Jan 2021 10:23:07 +0200","From":"Laurent Pinchart <laurent.pinchart@ideasonboard.com>","To":"David Plowman <david.plowman@raspberrypi.com>","Message-ID":"<YA/RaxeixtPJImj0@pendragon.ideasonboard.com>","References":"<20210125184858.16339-1-david.plowman@raspberrypi.com>\n\t<20210125184858.16339-4-david.plowman@raspberrypi.com>","MIME-Version":"1.0","Content-Disposition":"inline","In-Reply-To":"<20210125184858.16339-4-david.plowman@raspberrypi.com>","Subject":"Re: [libcamera-devel] [PATCH v2 3/5] ipa: raspberrypi: awb: Replace\n\tRaspberry Pi debug with libcamera debug","X-BeenThere":"libcamera-devel@lists.libcamera.org","X-Mailman-Version":"2.1.29","Precedence":"list","List-Id":"<libcamera-devel.lists.libcamera.org>","List-Unsubscribe":"<https://lists.libcamera.org/options/libcamera-devel>,\n\t<mailto:libcamera-devel-request@lists.libcamera.org?subject=unsubscribe>","List-Archive":"<https://lists.libcamera.org/pipermail/libcamera-devel/>","List-Post":"<mailto:libcamera-devel@lists.libcamera.org>","List-Help":"<mailto:libcamera-devel-request@lists.libcamera.org?subject=help>","List-Subscribe":"<https://lists.libcamera.org/listinfo/libcamera-devel>,\n\t<mailto:libcamera-devel-request@lists.libcamera.org?subject=subscribe>","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\" <libcamera-devel-bounces@lists.libcamera.org>"}}]