[libcamera-devel,v2,2/5] ipa: raspberrypi: alsc: Replace Raspberry Pi debug with libcamera debug
diff mbox series

Message ID 20210125184858.16339-3-david.plowman@raspberrypi.com
State Accepted
Commit b2186c2b89d762475e45935c835dc900ff5a7149
Headers show
Series
  • Remove Raspberry Pi logging
Related show

Commit Message

David Plowman Jan. 25, 2021, 6:48 p.m. UTC
Some unhelpful debug messages have been removed.

Signed-off-by: David Plowman <david.plowman@raspberrypi.com>
Reviewed-by: Kieran Bingham <kieran.bingham@ideasonboard.com>
---
 src/ipa/raspberrypi/controller/rpi/alsc.cpp | 66 +++++++++++----------
 1 file changed, 35 insertions(+), 31 deletions(-)

Comments

Laurent Pinchart Jan. 26, 2021, 8:17 a.m. UTC | #1
Hi David,

Thank you for the patch.

On Mon, Jan 25, 2021 at 06:48:55PM +0000, David Plowman wrote:
> Some unhelpful debug messages have been removed.
> 
> Signed-off-by: David Plowman <david.plowman@raspberrypi.com>
> Reviewed-by: Kieran Bingham <kieran.bingham@ideasonboard.com>

Reviewed-by: Laurent Pinchart <laurent.pinchart@ideasonboard.com>

> ---
>  src/ipa/raspberrypi/controller/rpi/alsc.cpp | 66 +++++++++++----------
>  1 file changed, 35 insertions(+), 31 deletions(-)
> 
> diff --git a/src/ipa/raspberrypi/controller/rpi/alsc.cpp b/src/ipa/raspberrypi/controller/rpi/alsc.cpp
> index c354c985..5262bcab 100644
> --- a/src/ipa/raspberrypi/controller/rpi/alsc.cpp
> +++ b/src/ipa/raspberrypi/controller/rpi/alsc.cpp
> @@ -6,12 +6,17 @@
>   */
>  #include <math.h>
>  
> +#include "libcamera/internal/log.h"
> +
>  #include "../awb_status.h"
>  #include "alsc.hpp"
>  
>  // Raspberry Pi ALSC (Auto Lens Shading Correction) algorithm.
>  
>  using namespace RPiController;
> +using namespace libcamera;
> +
> +LOG_DEFINE_CATEGORY(RPiAlsc)
>  
>  #define NAME "rpi.alsc"
>  
> @@ -110,15 +115,14 @@ static void read_calibrations(std::vector<AlscCalibration> &calibrations,
>  					"Alsc: too few values for ct " +
>  					std::to_string(ct) + " in " + name);
>  			calibrations.push_back(calibration);
> -			RPI_LOG("Read " << name << " calibration for ct "
> -					<< ct);
> +			LOG(RPiAlsc, Debug)
> +				<< "Read " << name << " calibration for ct " << ct;
>  		}
>  	}
>  }
>  
>  void Alsc::Read(boost::property_tree::ptree const &params)
>  {
> -	RPI_LOG("Alsc");
>  	config_.frame_period = params.get<uint16_t>("frame_period", 12);
>  	config_.startup_frames = params.get<uint16_t>("startup_frames", 10);
>  	config_.speed = params.get<double>("speed", 0.05);
> @@ -139,7 +143,8 @@ void Alsc::Read(boost::property_tree::ptree const &params)
>  		read_lut(config_.luminance_lut,
>  			 params.get_child("luminance_lut"));
>  	else
> -		RPI_WARN("Alsc: no luminance table - assume unity everywhere");
> +		LOG(RPiAlsc, Warning)
> +			<< "no luminance table - assume unity everywhere";
>  	read_calibrations(config_.calibrations_Cr, params, "calibrations_Cr");
>  	read_calibrations(config_.calibrations_Cb, params, "calibrations_Cb");
>  	config_.default_ct = params.get<double>("default_ct", 4500.0);
> @@ -164,7 +169,6 @@ static void add_luminance_to_tables(double results[3][Y][X],
>  
>  void Alsc::Initialise()
>  {
> -	RPI_LOG("Alsc");
>  	frame_count2_ = frame_count_ = frame_phase_ = 0;
>  	first_time_ = true;
>  	ct_ = config_.default_ct;
> @@ -252,7 +256,7 @@ void Alsc::SwitchMode(CameraMode const &camera_mode,
>  
>  void Alsc::fetchAsyncResults()
>  {
> -	RPI_LOG("Fetch ALSC results");
> +	LOG(RPiAlsc, Debug) << "Fetch ALSC results";
>  	async_finished_ = false;
>  	async_started_ = false;
>  	memcpy(sync_results_, async_results_, sizeof(sync_results_));
> @@ -263,11 +267,11 @@ double get_ct(Metadata *metadata, double default_ct)
>  	AwbStatus awb_status;
>  	awb_status.temperature_K = default_ct; // in case nothing found
>  	if (metadata->Get("awb.status", awb_status) != 0)
> -		RPI_WARN("Alsc: no AWB results found, using "
> -			 << awb_status.temperature_K);
> +		LOG(RPiAlsc, Warning) << "no AWB results found, using "
> +				      << awb_status.temperature_K;
>  	else
> -		RPI_LOG("Alsc: AWB results found, using "
> -			<< awb_status.temperature_K);
> +		LOG(RPiAlsc, Debug) << "AWB results found, using "
> +				    << awb_status.temperature_K;
>  	return awb_status.temperature_K;
>  }
>  
> @@ -289,7 +293,7 @@ static void copy_stats(bcm2835_isp_stats_region regions[XY], StatisticsPtr &stat
>  
>  void Alsc::restartAsync(StatisticsPtr &stats, Metadata *image_metadata)
>  {
> -	RPI_LOG("Starting ALSC thread");
> +	LOG(RPiAlsc, Debug) << "Starting ALSC calculation";
>  	// Get the current colour temperature. It's all we need from the
>  	// metadata. Default to the last CT value (which could be the default).
>  	ct_ = get_ct(image_metadata, ct_);
> @@ -297,7 +301,8 @@ void Alsc::restartAsync(StatisticsPtr &stats, Metadata *image_metadata)
>  	// the LSC table that the pipeline applied to them.
>  	AlscStatus alsc_status;
>  	if (image_metadata->Get("alsc.status", alsc_status) != 0) {
> -		RPI_WARN("No ALSC status found for applied gains!");
> +		LOG(RPiAlsc, Warning)
> +			<< "No ALSC status found for applied gains!";
>  		for (int y = 0; y < Y; y++)
>  			for (int x = 0; x < X; x++) {
>  				alsc_status.r[y][x] = 1.0;
> @@ -324,13 +329,12 @@ void Alsc::Prepare(Metadata *image_metadata)
>  	double speed = frame_count_ < (int)config_.startup_frames
>  			       ? 1.0
>  			       : config_.speed;
> -	RPI_LOG("Alsc: frame_count " << frame_count_ << " speed " << speed);
> +	LOG(RPiAlsc, Debug)
> +		<< "frame_count " << frame_count_ << " speed " << speed;
>  	{
>  		std::unique_lock<std::mutex> lock(mutex_);
> -		if (async_started_ && async_finished_) {
> -			RPI_LOG("ALSC thread finished");
> +		if (async_started_ && async_finished_)
>  			fetchAsyncResults();
> -		}
>  	}
>  	// Apply IIR filter to results and program into the pipeline.
>  	double *ptr = (double *)sync_results_,
> @@ -354,13 +358,11 @@ void Alsc::Process(StatisticsPtr &stats, Metadata *image_metadata)
>  		frame_phase_++;
>  	if (frame_count2_ < (int)config_.startup_frames)
>  		frame_count2_++;
> -	RPI_LOG("Alsc: frame_phase " << frame_phase_);
> +	LOG(RPiAlsc, Debug) << "frame_phase " << frame_phase_;
>  	if (frame_phase_ >= (int)config_.frame_period ||
>  	    frame_count2_ < (int)config_.startup_frames) {
> -		if (async_started_ == false) {
> -			RPI_LOG("ALSC thread starting");
> +		if (async_started_ == false)
>  			restartAsync(stats, image_metadata);
> -		}
>  	}
>  }
>  
> @@ -391,25 +393,26 @@ void get_cal_table(double ct, std::vector<AlscCalibration> const &calibrations,
>  	if (calibrations.empty()) {
>  		for (int i = 0; i < XY; i++)
>  			cal_table[i] = 1.0;
> -		RPI_LOG("Alsc: no calibrations found");
> +		LOG(RPiAlsc, Debug) << "no calibrations found";
>  	} else if (ct <= calibrations.front().ct) {
>  		memcpy(cal_table, calibrations.front().table,
>  		       XY * sizeof(double));
> -		RPI_LOG("Alsc: using calibration for "
> -			<< calibrations.front().ct);
> +		LOG(RPiAlsc, Debug) << "using calibration for "
> +				    << calibrations.front().ct;
>  	} else if (ct >= calibrations.back().ct) {
>  		memcpy(cal_table, calibrations.back().table,
>  		       XY * sizeof(double));
> -		RPI_LOG("Alsc: using calibration for "
> -			<< calibrations.front().ct);
> +		LOG(RPiAlsc, Debug) << "using calibration for "
> +				    << calibrations.front().ct;
>  	} else {
>  		int idx = 0;
>  		while (ct > calibrations[idx + 1].ct)
>  			idx++;
>  		double ct0 = calibrations[idx].ct,
>  		       ct1 = calibrations[idx + 1].ct;
> -		RPI_LOG("Alsc: ct is " << ct << ", interpolating between "
> -				       << ct0 << " and " << ct1);
> +		LOG(RPiAlsc, Debug)
> +			<< "ct is " << ct << ", interpolating between "
> +			<< ct0 << " and " << ct1;
>  		for (int i = 0; i < XY; i++)
>  			cal_table[i] =
>  				(calibrations[idx].table[i] * (ct1 - ct) +
> @@ -660,15 +663,16 @@ static void run_matrix_iterations(double const C[XY], double lambda[XY],
>  	for (int i = 0; i < n_iter; i++) {
>  		double max_diff = fabs(gauss_seidel2_SOR(M, omega, lambda));
>  		if (max_diff < threshold) {
> -			RPI_LOG("Stop after " << i + 1 << " iterations");
> +			LOG(RPiAlsc, Debug)
> +				<< "Stop after " << i + 1 << " iterations";
>  			break;
>  		}
>  		// this happens very occasionally (so make a note), though
>  		// doesn't seem to matter
>  		if (max_diff > last_max_diff)
> -			RPI_LOG("Iteration " << i << ": max_diff gone up "
> -					     << last_max_diff << " to "
> -					     << max_diff);
> +			LOG(RPiAlsc, Debug)
> +				<< "Iteration " << i << ": max_diff gone up "
> +				<< last_max_diff << " to " << max_diff;
>  		last_max_diff = max_diff;
>  	}
>  	// We're going to normalise the lambdas so the smallest is 1. Not sure

Patch
diff mbox series

diff --git a/src/ipa/raspberrypi/controller/rpi/alsc.cpp b/src/ipa/raspberrypi/controller/rpi/alsc.cpp
index c354c985..5262bcab 100644
--- a/src/ipa/raspberrypi/controller/rpi/alsc.cpp
+++ b/src/ipa/raspberrypi/controller/rpi/alsc.cpp
@@ -6,12 +6,17 @@ 
  */
 #include <math.h>
 
+#include "libcamera/internal/log.h"
+
 #include "../awb_status.h"
 #include "alsc.hpp"
 
 // Raspberry Pi ALSC (Auto Lens Shading Correction) algorithm.
 
 using namespace RPiController;
+using namespace libcamera;
+
+LOG_DEFINE_CATEGORY(RPiAlsc)
 
 #define NAME "rpi.alsc"
 
@@ -110,15 +115,14 @@  static void read_calibrations(std::vector<AlscCalibration> &calibrations,
 					"Alsc: too few values for ct " +
 					std::to_string(ct) + " in " + name);
 			calibrations.push_back(calibration);
-			RPI_LOG("Read " << name << " calibration for ct "
-					<< ct);
+			LOG(RPiAlsc, Debug)
+				<< "Read " << name << " calibration for ct " << ct;
 		}
 	}
 }
 
 void Alsc::Read(boost::property_tree::ptree const &params)
 {
-	RPI_LOG("Alsc");
 	config_.frame_period = params.get<uint16_t>("frame_period", 12);
 	config_.startup_frames = params.get<uint16_t>("startup_frames", 10);
 	config_.speed = params.get<double>("speed", 0.05);
@@ -139,7 +143,8 @@  void Alsc::Read(boost::property_tree::ptree const &params)
 		read_lut(config_.luminance_lut,
 			 params.get_child("luminance_lut"));
 	else
-		RPI_WARN("Alsc: no luminance table - assume unity everywhere");
+		LOG(RPiAlsc, Warning)
+			<< "no luminance table - assume unity everywhere";
 	read_calibrations(config_.calibrations_Cr, params, "calibrations_Cr");
 	read_calibrations(config_.calibrations_Cb, params, "calibrations_Cb");
 	config_.default_ct = params.get<double>("default_ct", 4500.0);
@@ -164,7 +169,6 @@  static void add_luminance_to_tables(double results[3][Y][X],
 
 void Alsc::Initialise()
 {
-	RPI_LOG("Alsc");
 	frame_count2_ = frame_count_ = frame_phase_ = 0;
 	first_time_ = true;
 	ct_ = config_.default_ct;
@@ -252,7 +256,7 @@  void Alsc::SwitchMode(CameraMode const &camera_mode,
 
 void Alsc::fetchAsyncResults()
 {
-	RPI_LOG("Fetch ALSC results");
+	LOG(RPiAlsc, Debug) << "Fetch ALSC results";
 	async_finished_ = false;
 	async_started_ = false;
 	memcpy(sync_results_, async_results_, sizeof(sync_results_));
@@ -263,11 +267,11 @@  double get_ct(Metadata *metadata, double default_ct)
 	AwbStatus awb_status;
 	awb_status.temperature_K = default_ct; // in case nothing found
 	if (metadata->Get("awb.status", awb_status) != 0)
-		RPI_WARN("Alsc: no AWB results found, using "
-			 << awb_status.temperature_K);
+		LOG(RPiAlsc, Warning) << "no AWB results found, using "
+				      << awb_status.temperature_K;
 	else
-		RPI_LOG("Alsc: AWB results found, using "
-			<< awb_status.temperature_K);
+		LOG(RPiAlsc, Debug) << "AWB results found, using "
+				    << awb_status.temperature_K;
 	return awb_status.temperature_K;
 }
 
@@ -289,7 +293,7 @@  static void copy_stats(bcm2835_isp_stats_region regions[XY], StatisticsPtr &stat
 
 void Alsc::restartAsync(StatisticsPtr &stats, Metadata *image_metadata)
 {
-	RPI_LOG("Starting ALSC thread");
+	LOG(RPiAlsc, Debug) << "Starting ALSC calculation";
 	// Get the current colour temperature. It's all we need from the
 	// metadata. Default to the last CT value (which could be the default).
 	ct_ = get_ct(image_metadata, ct_);
@@ -297,7 +301,8 @@  void Alsc::restartAsync(StatisticsPtr &stats, Metadata *image_metadata)
 	// the LSC table that the pipeline applied to them.
 	AlscStatus alsc_status;
 	if (image_metadata->Get("alsc.status", alsc_status) != 0) {
-		RPI_WARN("No ALSC status found for applied gains!");
+		LOG(RPiAlsc, Warning)
+			<< "No ALSC status found for applied gains!";
 		for (int y = 0; y < Y; y++)
 			for (int x = 0; x < X; x++) {
 				alsc_status.r[y][x] = 1.0;
@@ -324,13 +329,12 @@  void Alsc::Prepare(Metadata *image_metadata)
 	double speed = frame_count_ < (int)config_.startup_frames
 			       ? 1.0
 			       : config_.speed;
-	RPI_LOG("Alsc: frame_count " << frame_count_ << " speed " << speed);
+	LOG(RPiAlsc, Debug)
+		<< "frame_count " << frame_count_ << " speed " << speed;
 	{
 		std::unique_lock<std::mutex> lock(mutex_);
-		if (async_started_ && async_finished_) {
-			RPI_LOG("ALSC thread finished");
+		if (async_started_ && async_finished_)
 			fetchAsyncResults();
-		}
 	}
 	// Apply IIR filter to results and program into the pipeline.
 	double *ptr = (double *)sync_results_,
@@ -354,13 +358,11 @@  void Alsc::Process(StatisticsPtr &stats, Metadata *image_metadata)
 		frame_phase_++;
 	if (frame_count2_ < (int)config_.startup_frames)
 		frame_count2_++;
-	RPI_LOG("Alsc: frame_phase " << frame_phase_);
+	LOG(RPiAlsc, Debug) << "frame_phase " << frame_phase_;
 	if (frame_phase_ >= (int)config_.frame_period ||
 	    frame_count2_ < (int)config_.startup_frames) {
-		if (async_started_ == false) {
-			RPI_LOG("ALSC thread starting");
+		if (async_started_ == false)
 			restartAsync(stats, image_metadata);
-		}
 	}
 }
 
@@ -391,25 +393,26 @@  void get_cal_table(double ct, std::vector<AlscCalibration> const &calibrations,
 	if (calibrations.empty()) {
 		for (int i = 0; i < XY; i++)
 			cal_table[i] = 1.0;
-		RPI_LOG("Alsc: no calibrations found");
+		LOG(RPiAlsc, Debug) << "no calibrations found";
 	} else if (ct <= calibrations.front().ct) {
 		memcpy(cal_table, calibrations.front().table,
 		       XY * sizeof(double));
-		RPI_LOG("Alsc: using calibration for "
-			<< calibrations.front().ct);
+		LOG(RPiAlsc, Debug) << "using calibration for "
+				    << calibrations.front().ct;
 	} else if (ct >= calibrations.back().ct) {
 		memcpy(cal_table, calibrations.back().table,
 		       XY * sizeof(double));
-		RPI_LOG("Alsc: using calibration for "
-			<< calibrations.front().ct);
+		LOG(RPiAlsc, Debug) << "using calibration for "
+				    << calibrations.front().ct;
 	} else {
 		int idx = 0;
 		while (ct > calibrations[idx + 1].ct)
 			idx++;
 		double ct0 = calibrations[idx].ct,
 		       ct1 = calibrations[idx + 1].ct;
-		RPI_LOG("Alsc: ct is " << ct << ", interpolating between "
-				       << ct0 << " and " << ct1);
+		LOG(RPiAlsc, Debug)
+			<< "ct is " << ct << ", interpolating between "
+			<< ct0 << " and " << ct1;
 		for (int i = 0; i < XY; i++)
 			cal_table[i] =
 				(calibrations[idx].table[i] * (ct1 - ct) +
@@ -660,15 +663,16 @@  static void run_matrix_iterations(double const C[XY], double lambda[XY],
 	for (int i = 0; i < n_iter; i++) {
 		double max_diff = fabs(gauss_seidel2_SOR(M, omega, lambda));
 		if (max_diff < threshold) {
-			RPI_LOG("Stop after " << i + 1 << " iterations");
+			LOG(RPiAlsc, Debug)
+				<< "Stop after " << i + 1 << " iterations";
 			break;
 		}
 		// this happens very occasionally (so make a note), though
 		// doesn't seem to matter
 		if (max_diff > last_max_diff)
-			RPI_LOG("Iteration " << i << ": max_diff gone up "
-					     << last_max_diff << " to "
-					     << max_diff);
+			LOG(RPiAlsc, Debug)
+				<< "Iteration " << i << ": max_diff gone up "
+				<< last_max_diff << " to " << max_diff;
 		last_max_diff = max_diff;
 	}
 	// We're going to normalise the lambdas so the smallest is 1. Not sure