[libcamera-devel,11/11] Adds useful debug print statements.
diff mbox series

Message ID 20221024055543.116040-12-nicholas@rothemail.net
State Superseded
Headers show
Series
  • [libcamera-devel,01/11] Fixes Bug 156, which breaks libcamera on Android < 12.
Related show

Commit Message

Nicolas Dufresne via libcamera-devel Oct. 24, 2022, 5:55 a.m. UTC
From: Nicholas Roth <nicholas@rothemail.net>

---
 src/android/camera_capabilities.cpp           | 12 +++++++++---
 src/android/camera_hal_manager.cpp            |  3 ++-
 src/libcamera/base/log.cpp                    |  6 +++++-
 src/libcamera/pipeline/rkisp1/rkisp1_path.cpp |  2 ++
 src/libcamera/v4l2_subdevice.cpp              |  3 ++-
 5 files changed, 20 insertions(+), 6 deletions(-)

Comments

Laurent Pinchart Oct. 24, 2022, 11:59 p.m. UTC | #1
Hi Nicholas,

Thank you for the patch.

On Mon, Oct 24, 2022 at 12:55:43AM -0500, Nicholas Roth via libcamera-devel wrote:
> From: Nicholas Roth <nicholas@rothemail.net>
> 
> ---
>  src/android/camera_capabilities.cpp           | 12 +++++++++---
>  src/android/camera_hal_manager.cpp            |  3 ++-
>  src/libcamera/base/log.cpp                    |  6 +++++-
>  src/libcamera/pipeline/rkisp1/rkisp1_path.cpp |  2 ++
>  src/libcamera/v4l2_subdevice.cpp              |  3 ++-
>  5 files changed, 20 insertions(+), 6 deletions(-)
> 
> diff --git a/src/android/camera_capabilities.cpp b/src/android/camera_capabilities.cpp
> index 64bd8dde..ef0d10d0 100644
> --- a/src/android/camera_capabilities.cpp
> +++ b/src/android/camera_capabilities.cpp
> @@ -374,14 +374,20 @@ void CameraCapabilities::computeHwLevel(
>  	camera_metadata_enum_android_info_supported_hardware_level
>  		hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_FULL;
>  
> -	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_SENSOR))
> +	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_SENSOR)) {
> +		LOG(HAL, Info) << noFull << "missing manual sensor";
>  		hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
> +	}
>  
> -	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_POST_PROCESSING))
> +	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_POST_PROCESSING)) {
> +		LOG(HAL, Info) << noFull << "missing manual post processing";
>  		hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
> +	}
>  
> -	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_BURST_CAPTURE))
> +	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_BURST_CAPTURE)) {
> +		LOG(HAL, Info) << noFull << "missing burst capture";
>  		hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
> +	}

Paul, Jacopo, could you maybe review this part ?

>  
>  	found = staticMetadata_->getEntry(ANDROID_SYNC_MAX_LATENCY, &entry);
>  	if (!found || *entry.data.i32 != 0) {
> diff --git a/src/android/camera_hal_manager.cpp b/src/android/camera_hal_manager.cpp
> index 7512cc4e..7fac4e3f 100644
> --- a/src/android/camera_hal_manager.cpp
> +++ b/src/android/camera_hal_manager.cpp
> @@ -140,7 +140,8 @@ void CameraHalManager::cameraAdded(std::shared_ptr<Camera> cam)
>  	 */
>  	if (!isCameraExternal && !halConfig_.exists()) {
>  		LOG(HAL, Error)
> -			<< "HAL configuration file is mandatory for internal cameras";
> +			<< "HAL configuration file is mandatory for internal cameras."
> +			<< " Camera NOT loaded: \"" << cam->id() << "\"";
>  		return;
>  	}
>  
> diff --git a/src/libcamera/base/log.cpp b/src/libcamera/base/log.cpp
> index 55fbd7b0..b8c2c99f 100644
> --- a/src/libcamera/base/log.cpp
> +++ b/src/libcamera/base/log.cpp
> @@ -625,8 +625,12 @@ void Logger::parseLogFile()
>  void Logger::parseLogLevels()
>  {
>  	const char *debug = utils::secure_getenv("LIBCAMERA_LOG_LEVELS");
> -	if (!debug)
> +	if (!debug) {
> +		syslog(LOG_INFO, "Could not find LIBCAMERA_LOG_LEVELS in env");
>  		return;
> +	} else {
> +		syslog(LOG_INFO, "LIBCAMERA_LOG_LEVELS is %s", debug);
> +	}

I don't think we should log a message to syslog every time libcamera is
started to report the LIBCAMERA_LOG_LEVELS value. Is this a debugging
leftover ?

>  
>  	for (const char *pair = debug; *debug != '\0'; pair = debug) {
>  		const char *comma = strchrnul(debug, ',');
> diff --git a/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp b/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
> index 2d38f0fb..a2038704 100644
> --- a/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
> +++ b/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
> @@ -33,10 +33,12 @@ bool RkISP1Path::init(MediaDevice *media)
>  	std::string resizer = std::string("rkisp1_resizer_") + name_ + "path";
>  	std::string video = std::string("rkisp1_") + name_ + "path";
>  
> +	LOG(RkISP1, Debug) << "Creating " << resizer;
>  	resizer_ = V4L2Subdevice::fromEntityName(media, resizer);
>  	if (resizer_->open() < 0)
>  		return false;
>  
> +	LOG(RkISP1, Debug) << "Creating " << video;

Here too, is this something that you added to debug specific issues you
were facing, or do you expect this to be useful for users ? If the
latter, could you explain why ?

>  	video_ = V4L2VideoDevice::fromEntityName(media, video);
>  	if (video_->open() < 0)
>  		return false;
> diff --git a/src/libcamera/v4l2_subdevice.cpp b/src/libcamera/v4l2_subdevice.cpp
> index 15e8206a..8f86387b 100644
> --- a/src/libcamera/v4l2_subdevice.cpp
> +++ b/src/libcamera/v4l2_subdevice.cpp
> @@ -392,7 +392,8 @@ int V4L2Subdevice::getSelection(unsigned int pad, unsigned int target,
>  	if (ret < 0) {
>  		LOG(V4L2, Error)
>  			<< "Unable to get rectangle " << target << " on pad "
> -			<< pad << ": " << strerror(-ret);
> +			<< pad << ": " << strerror(-ret) << "."
> +			<< "device path: " << devicePath() << " device node: " << deviceNode();

If the device path and device node are useful in error messages, they
should be printed in all of them, not just this one. This should then be
done through the logPrefix() function. The code currently uses the
entity name as a log prefix, is that not enough ? The device path, in
particular, seems too verbose to me.

>  		return ret;
>  	}
>
Jacopo Mondi Oct. 25, 2022, 10:49 a.m. UTC | #2
Hello,

On Tue, Oct 25, 2022 at 02:59:07AM +0300, Laurent Pinchart via libcamera-devel wrote:
> Hi Nicholas,
>
> Thank you for the patch.
>
> On Mon, Oct 24, 2022 at 12:55:43AM -0500, Nicholas Roth via libcamera-devel wrote:
> > From: Nicholas Roth <nicholas@rothemail.net>
> >
> > ---
> >  src/android/camera_capabilities.cpp           | 12 +++++++++---
> >  src/android/camera_hal_manager.cpp            |  3 ++-
> >  src/libcamera/base/log.cpp                    |  6 +++++-
> >  src/libcamera/pipeline/rkisp1/rkisp1_path.cpp |  2 ++
> >  src/libcamera/v4l2_subdevice.cpp              |  3 ++-
> >  5 files changed, 20 insertions(+), 6 deletions(-)
> >
> > diff --git a/src/android/camera_capabilities.cpp b/src/android/camera_capabilities.cpp
> > index 64bd8dde..ef0d10d0 100644
> > --- a/src/android/camera_capabilities.cpp
> > +++ b/src/android/camera_capabilities.cpp
> > @@ -374,14 +374,20 @@ void CameraCapabilities::computeHwLevel(
> >  	camera_metadata_enum_android_info_supported_hardware_level
> >  		hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_FULL;
> >
> > -	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_SENSOR))
> > +	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_SENSOR)) {
> > +		LOG(HAL, Info) << noFull << "missing manual sensor";
> >  		hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
> > +	}
> >
> > -	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_POST_PROCESSING))
> > +	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_POST_PROCESSING)) {
> > +		LOG(HAL, Info) << noFull << "missing manual post processing";
> >  		hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
> > +	}
> >
> > -	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_BURST_CAPTURE))
> > +	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_BURST_CAPTURE)) {
> > +		LOG(HAL, Info) << noFull << "missing burst capture";
> >  		hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
> > +	}
>
> Paul, Jacopo, could you maybe review this part ?
>

Considering that we have below

	found = staticMetadata_->getEntry(ANDROID_SYNC_MAX_LATENCY, &entry);
	if (!found || *entry.data.i32 != 0) {
		LOG(HAL, Info) << noFull << "missing or invalid max sync latency";
		hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
	}

I guess it doesn't hurt.

However I guess there was no debug printout here because 'caps' gets
populated in 'computeCapabilities()' where each 'validate$Capability()'
call already prints out what it has enabled

In example:

bool CameraCapabilities::validateManualSensorCapability()
{
	const char *noMode = "Manual sensor capability unavailable: ";

	if (!staticMetadata_->entryContains<uint8_t>(ANDROID_CONTROL_AE_AVAILABLE_MODES,
						     ANDROID_CONTROL_AE_MODE_OFF)) {
		LOG(HAL, Info) << noMode << "missing AE mode off";
		return false;
	}

	if (!staticMetadata_->entryContains<uint8_t>(ANDROID_CONTROL_AE_LOCK_AVAILABLE,
						     ANDROID_CONTROL_AE_LOCK_AVAILABLE_TRUE)) {
		LOG(HAL, Info) << noMode << "missing AE lock";
		return false;
	}

        ..

}

All in all, I don't mind, but I can live without this, unless Nicholas
has found it particularly relevant for reasons I am missing.


> >
> >  	found = staticMetadata_->getEntry(ANDROID_SYNC_MAX_LATENCY, &entry);
> >  	if (!found || *entry.data.i32 != 0) {
> > diff --git a/src/android/camera_hal_manager.cpp b/src/android/camera_hal_manager.cpp
> > index 7512cc4e..7fac4e3f 100644
> > --- a/src/android/camera_hal_manager.cpp
> > +++ b/src/android/camera_hal_manager.cpp
> > @@ -140,7 +140,8 @@ void CameraHalManager::cameraAdded(std::shared_ptr<Camera> cam)
> >  	 */
> >  	if (!isCameraExternal && !halConfig_.exists()) {
> >  		LOG(HAL, Error)
> > -			<< "HAL configuration file is mandatory for internal cameras";
> > +			<< "HAL configuration file is mandatory for internal cameras."
> > +			<< " Camera NOT loaded: \"" << cam->id() << "\"";
> >  		return;
> >  	}
> >
> > diff --git a/src/libcamera/base/log.cpp b/src/libcamera/base/log.cpp
> > index 55fbd7b0..b8c2c99f 100644
> > --- a/src/libcamera/base/log.cpp
> > +++ b/src/libcamera/base/log.cpp
> > @@ -625,8 +625,12 @@ void Logger::parseLogFile()
> >  void Logger::parseLogLevels()
> >  {
> >  	const char *debug = utils::secure_getenv("LIBCAMERA_LOG_LEVELS");
> > -	if (!debug)
> > +	if (!debug) {
> > +		syslog(LOG_INFO, "Could not find LIBCAMERA_LOG_LEVELS in env");
> >  		return;
> > +	} else {
> > +		syslog(LOG_INFO, "LIBCAMERA_LOG_LEVELS is %s", debug);
> > +	}
>
> I don't think we should log a message to syslog every time libcamera is
> started to report the LIBCAMERA_LOG_LEVELS value. Is this a debugging
> leftover ?
>
> >
> >  	for (const char *pair = debug; *debug != '\0'; pair = debug) {
> >  		const char *comma = strchrnul(debug, ',');
> > diff --git a/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp b/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
> > index 2d38f0fb..a2038704 100644
> > --- a/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
> > +++ b/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
> > @@ -33,10 +33,12 @@ bool RkISP1Path::init(MediaDevice *media)
> >  	std::string resizer = std::string("rkisp1_resizer_") + name_ + "path";
> >  	std::string video = std::string("rkisp1_") + name_ + "path";
> >
> > +	LOG(RkISP1, Debug) << "Creating " << resizer;
> >  	resizer_ = V4L2Subdevice::fromEntityName(media, resizer);
> >  	if (resizer_->open() < 0)
> >  		return false;
> >
> > +	LOG(RkISP1, Debug) << "Creating " << video;
>
> Here too, is this something that you added to debug specific issues you
> were facing, or do you expect this to be useful for users ? If the
> latter, could you explain why ?
>
> >  	video_ = V4L2VideoDevice::fromEntityName(media, video);
> >  	if (video_->open() < 0)
> >  		return false;
> > diff --git a/src/libcamera/v4l2_subdevice.cpp b/src/libcamera/v4l2_subdevice.cpp
> > index 15e8206a..8f86387b 100644
> > --- a/src/libcamera/v4l2_subdevice.cpp
> > +++ b/src/libcamera/v4l2_subdevice.cpp
> > @@ -392,7 +392,8 @@ int V4L2Subdevice::getSelection(unsigned int pad, unsigned int target,
> >  	if (ret < 0) {
> >  		LOG(V4L2, Error)
> >  			<< "Unable to get rectangle " << target << " on pad "
> > -			<< pad << ": " << strerror(-ret);
> > +			<< pad << ": " << strerror(-ret) << "."
> > +			<< "device path: " << devicePath() << " device node: " << deviceNode();
>
> If the device path and device node are useful in error messages, they
> should be printed in all of them, not just this one. This should then be
> done through the logPrefix() function. The code currently uses the
> entity name as a log prefix, is that not enough ? The device path, in
> particular, seems too verbose to me.
>
> >  		return ret;
> >  	}
> >
>
> --
> Regards,
>
> Laurent Pinchart
Kieran Bingham Oct. 25, 2022, 11:13 a.m. UTC | #3
Hi Laurent,

Quoting Laurent Pinchart via libcamera-devel (2022-10-25 00:59:07)
> Hi Nicholas,
> 
> Thank you for the patch.
> 
> On Mon, Oct 24, 2022 at 12:55:43AM -0500, Nicholas Roth via libcamera-devel wrote:
> > From: Nicholas Roth <nicholas@rothemail.net>
> > 
> > ---
> >  src/android/camera_capabilities.cpp           | 12 +++++++++---
> >  src/android/camera_hal_manager.cpp            |  3 ++-
> >  src/libcamera/base/log.cpp                    |  6 +++++-
> >  src/libcamera/pipeline/rkisp1/rkisp1_path.cpp |  2 ++
> >  src/libcamera/v4l2_subdevice.cpp              |  3 ++-
> >  5 files changed, 20 insertions(+), 6 deletions(-)
> > 
> > diff --git a/src/android/camera_capabilities.cpp b/src/android/camera_capabilities.cpp
> > index 64bd8dde..ef0d10d0 100644

<snip android parts>

> > diff --git a/src/libcamera/v4l2_subdevice.cpp b/src/libcamera/v4l2_subdevice.cpp
> > index 15e8206a..8f86387b 100644
> > --- a/src/libcamera/v4l2_subdevice.cpp
> > +++ b/src/libcamera/v4l2_subdevice.cpp
> > @@ -392,7 +392,8 @@ int V4L2Subdevice::getSelection(unsigned int pad, unsigned int target,
> >       if (ret < 0) {
> >               LOG(V4L2, Error)
> >                       << "Unable to get rectangle " << target << " on pad "
> > -                     << pad << ": " << strerror(-ret);
> > +                     << pad << ": " << strerror(-ret) << "."
> > +                     << "device path: " << devicePath() << " device node: " << deviceNode();
> 
> If the device path and device node are useful in error messages, they
> should be printed in all of them, not just this one. This should then be
> done through the logPrefix() function. The code currently uses the
> entity name as a log prefix, is that not enough ? The device path, in
> particular, seems too verbose to me.

This makes me remember https://patchwork.libcamera.org/patch/12207/, and
wish it was something that could get more traction. It can help to see
what device nodes are being worked on when the logs are reported.

Your earlier comment of:
> I don't have a very strong opinion here, but I wonder if we could print
> the video node and entity name at open time, and only the entity name in
> other places ?

still stands, and is likely reasonable. I'll see if I can post a v2 with
that.

--
Kieran


> >               return ret;
> >       }
> >  
> 
> -- 
> Regards,
> 
> Laurent Pinchart
Nicholas Roth Oct. 26, 2022, 3:09 a.m. UTC | #4
> All in all, I don't mind, but I can live without this, unless Nicholas
> has found it particularly relevant for reasons I am missing.

This calls attention to the fact that the sensor is missing an important
piece of functionality required for a FULL instead of LIMITED camera to be
reported to Android.

On Tue, Oct 25, 2022 at 5:49 AM Jacopo Mondi <jacopo@jmondi.org> wrote:

> Hello,
>
> On Tue, Oct 25, 2022 at 02:59:07AM +0300, Laurent Pinchart via
> libcamera-devel wrote:
> > Hi Nicholas,
> >
> > Thank you for the patch.
> >
> > On Mon, Oct 24, 2022 at 12:55:43AM -0500, Nicholas Roth via
> libcamera-devel wrote:
> > > From: Nicholas Roth <nicholas@rothemail.net>
> > >
> > > ---
> > >  src/android/camera_capabilities.cpp           | 12 +++++++++---
> > >  src/android/camera_hal_manager.cpp            |  3 ++-
> > >  src/libcamera/base/log.cpp                    |  6 +++++-
> > >  src/libcamera/pipeline/rkisp1/rkisp1_path.cpp |  2 ++
> > >  src/libcamera/v4l2_subdevice.cpp              |  3 ++-
> > >  5 files changed, 20 insertions(+), 6 deletions(-)
> > >
> > > diff --git a/src/android/camera_capabilities.cpp
> b/src/android/camera_capabilities.cpp
> > > index 64bd8dde..ef0d10d0 100644
> > > --- a/src/android/camera_capabilities.cpp
> > > +++ b/src/android/camera_capabilities.cpp
> > > @@ -374,14 +374,20 @@ void CameraCapabilities::computeHwLevel(
> > >     camera_metadata_enum_android_info_supported_hardware_level
> > >             hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_FULL;
> > >
> > > -   if
> (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_SENSOR))
> > > +   if
> (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_SENSOR)) {
> > > +           LOG(HAL, Info) << noFull << "missing manual sensor";
> > >             hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
> > > +   }
> > >
> > > -   if
> (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_POST_PROCESSING))
> > > +   if
> (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_POST_PROCESSING))
> {
> > > +           LOG(HAL, Info) << noFull << "missing manual post
> processing";
> > >             hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
> > > +   }
> > >
> > > -   if
> (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_BURST_CAPTURE))
> > > +   if
> (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_BURST_CAPTURE)) {
> > > +           LOG(HAL, Info) << noFull << "missing burst capture";
> > >             hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
> > > +   }
> >
> > Paul, Jacopo, could you maybe review this part ?
> >
>
> Considering that we have below
>
>         found = staticMetadata_->getEntry(ANDROID_SYNC_MAX_LATENCY,
> &entry);
>         if (!found || *entry.data.i32 != 0) {
>                 LOG(HAL, Info) << noFull << "missing or invalid max sync
> latency";
>                 hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
>         }
>
> I guess it doesn't hurt.
>
> However I guess there was no debug printout here because 'caps' gets
> populated in 'computeCapabilities()' where each 'validate$Capability()'
> call already prints out what it has enabled
>
> In example:
>
> bool CameraCapabilities::validateManualSensorCapability()
> {
>         const char *noMode = "Manual sensor capability unavailable: ";
>
>         if
> (!staticMetadata_->entryContains<uint8_t>(ANDROID_CONTROL_AE_AVAILABLE_MODES,
>
>  ANDROID_CONTROL_AE_MODE_OFF)) {
>                 LOG(HAL, Info) << noMode << "missing AE mode off";
>                 return false;
>         }
>
>         if
> (!staticMetadata_->entryContains<uint8_t>(ANDROID_CONTROL_AE_LOCK_AVAILABLE,
>
>  ANDROID_CONTROL_AE_LOCK_AVAILABLE_TRUE)) {
>                 LOG(HAL, Info) << noMode << "missing AE lock";
>                 return false;
>         }
>
>         ..
>
> }
>
> All in all, I don't mind, but I can live without this, unless Nicholas
> has found it particularly relevant for reasons I am missing.
>
>
> > >
> > >     found = staticMetadata_->getEntry(ANDROID_SYNC_MAX_LATENCY,
> &entry);
> > >     if (!found || *entry.data.i32 != 0) {
> > > diff --git a/src/android/camera_hal_manager.cpp
> b/src/android/camera_hal_manager.cpp
> > > index 7512cc4e..7fac4e3f 100644
> > > --- a/src/android/camera_hal_manager.cpp
> > > +++ b/src/android/camera_hal_manager.cpp
> > > @@ -140,7 +140,8 @@ void
> CameraHalManager::cameraAdded(std::shared_ptr<Camera> cam)
> > >      */
> > >     if (!isCameraExternal && !halConfig_.exists()) {
> > >             LOG(HAL, Error)
> > > -                   << "HAL configuration file is mandatory for
> internal cameras";
> > > +                   << "HAL configuration file is mandatory for
> internal cameras."
> > > +                   << " Camera NOT loaded: \"" << cam->id() << "\"";
> > >             return;
> > >     }
> > >
> > > diff --git a/src/libcamera/base/log.cpp b/src/libcamera/base/log.cpp
> > > index 55fbd7b0..b8c2c99f 100644
> > > --- a/src/libcamera/base/log.cpp
> > > +++ b/src/libcamera/base/log.cpp
> > > @@ -625,8 +625,12 @@ void Logger::parseLogFile()
> > >  void Logger::parseLogLevels()
> > >  {
> > >     const char *debug = utils::secure_getenv("LIBCAMERA_LOG_LEVELS");
> > > -   if (!debug)
> > > +   if (!debug) {
> > > +           syslog(LOG_INFO, "Could not find LIBCAMERA_LOG_LEVELS in
> env");
> > >             return;
> > > +   } else {
> > > +           syslog(LOG_INFO, "LIBCAMERA_LOG_LEVELS is %s", debug);
> > > +   }
> >
> > I don't think we should log a message to syslog every time libcamera is
> > started to report the LIBCAMERA_LOG_LEVELS value. Is this a debugging
> > leftover ?
> >
> > >
> > >     for (const char *pair = debug; *debug != '\0'; pair = debug) {
> > >             const char *comma = strchrnul(debug, ',');
> > > diff --git a/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
> b/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
> > > index 2d38f0fb..a2038704 100644
> > > --- a/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
> > > +++ b/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
> > > @@ -33,10 +33,12 @@ bool RkISP1Path::init(MediaDevice *media)
> > >     std::string resizer = std::string("rkisp1_resizer_") + name_ +
> "path";
> > >     std::string video = std::string("rkisp1_") + name_ + "path";
> > >
> > > +   LOG(RkISP1, Debug) << "Creating " << resizer;
> > >     resizer_ = V4L2Subdevice::fromEntityName(media, resizer);
> > >     if (resizer_->open() < 0)
> > >             return false;
> > >
> > > +   LOG(RkISP1, Debug) << "Creating " << video;
> >
> > Here too, is this something that you added to debug specific issues you
> > were facing, or do you expect this to be useful for users ? If the
> > latter, could you explain why ?
> >
> > >     video_ = V4L2VideoDevice::fromEntityName(media, video);
> > >     if (video_->open() < 0)
> > >             return false;
> > > diff --git a/src/libcamera/v4l2_subdevice.cpp
> b/src/libcamera/v4l2_subdevice.cpp
> > > index 15e8206a..8f86387b 100644
> > > --- a/src/libcamera/v4l2_subdevice.cpp
> > > +++ b/src/libcamera/v4l2_subdevice.cpp
> > > @@ -392,7 +392,8 @@ int V4L2Subdevice::getSelection(unsigned int pad,
> unsigned int target,
> > >     if (ret < 0) {
> > >             LOG(V4L2, Error)
> > >                     << "Unable to get rectangle " << target << " on
> pad "
> > > -                   << pad << ": " << strerror(-ret);
> > > +                   << pad << ": " << strerror(-ret) << "."
> > > +                   << "device path: " << devicePath() << " device
> node: " << deviceNode();
> >
> > If the device path and device node are useful in error messages, they
> > should be printed in all of them, not just this one. This should then be
> > done through the logPrefix() function. The code currently uses the
> > entity name as a log prefix, is that not enough ? The device path, in
> > particular, seems too verbose to me.
> >
> > >             return ret;
> > >     }
> > >
> >
> > --
> > Regards,
> >
> > Laurent Pinchart
>
Nicholas Roth Oct. 26, 2022, 3:10 a.m. UTC | #5
Replied too fast! Specifically, this calls attention to _why_ that may be
the case. I had to hunt this down and debug in the code when I found that
my camera was marked as LIMITED. It will be helpful for other users to see
this in their logs right above the warning marking their cameras as LIMITED
so that they know why.


On Tue, Oct 25, 2022 at 5:49 AM Jacopo Mondi <jacopo@jmondi.org> wrote:

> Hello,
>
> On Tue, Oct 25, 2022 at 02:59:07AM +0300, Laurent Pinchart via
> libcamera-devel wrote:
> > Hi Nicholas,
> >
> > Thank you for the patch.
> >
> > On Mon, Oct 24, 2022 at 12:55:43AM -0500, Nicholas Roth via
> libcamera-devel wrote:
> > > From: Nicholas Roth <nicholas@rothemail.net>
> > >
> > > ---
> > >  src/android/camera_capabilities.cpp           | 12 +++++++++---
> > >  src/android/camera_hal_manager.cpp            |  3 ++-
> > >  src/libcamera/base/log.cpp                    |  6 +++++-
> > >  src/libcamera/pipeline/rkisp1/rkisp1_path.cpp |  2 ++
> > >  src/libcamera/v4l2_subdevice.cpp              |  3 ++-
> > >  5 files changed, 20 insertions(+), 6 deletions(-)
> > >
> > > diff --git a/src/android/camera_capabilities.cpp
> b/src/android/camera_capabilities.cpp
> > > index 64bd8dde..ef0d10d0 100644
> > > --- a/src/android/camera_capabilities.cpp
> > > +++ b/src/android/camera_capabilities.cpp
> > > @@ -374,14 +374,20 @@ void CameraCapabilities::computeHwLevel(
> > >     camera_metadata_enum_android_info_supported_hardware_level
> > >             hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_FULL;
> > >
> > > -   if
> (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_SENSOR))
> > > +   if
> (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_SENSOR)) {
> > > +           LOG(HAL, Info) << noFull << "missing manual sensor";
> > >             hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
> > > +   }
> > >
> > > -   if
> (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_POST_PROCESSING))
> > > +   if
> (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_POST_PROCESSING))
> {
> > > +           LOG(HAL, Info) << noFull << "missing manual post
> processing";
> > >             hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
> > > +   }
> > >
> > > -   if
> (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_BURST_CAPTURE))
> > > +   if
> (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_BURST_CAPTURE)) {
> > > +           LOG(HAL, Info) << noFull << "missing burst capture";
> > >             hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
> > > +   }
> >
> > Paul, Jacopo, could you maybe review this part ?
> >
>
> Considering that we have below
>
>         found = staticMetadata_->getEntry(ANDROID_SYNC_MAX_LATENCY,
> &entry);
>         if (!found || *entry.data.i32 != 0) {
>                 LOG(HAL, Info) << noFull << "missing or invalid max sync
> latency";
>                 hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
>         }
>
> I guess it doesn't hurt.
>
> However I guess there was no debug printout here because 'caps' gets
> populated in 'computeCapabilities()' where each 'validate$Capability()'
> call already prints out what it has enabled
>
> In example:
>
> bool CameraCapabilities::validateManualSensorCapability()
> {
>         const char *noMode = "Manual sensor capability unavailable: ";
>
>         if
> (!staticMetadata_->entryContains<uint8_t>(ANDROID_CONTROL_AE_AVAILABLE_MODES,
>
>  ANDROID_CONTROL_AE_MODE_OFF)) {
>                 LOG(HAL, Info) << noMode << "missing AE mode off";
>                 return false;
>         }
>
>         if
> (!staticMetadata_->entryContains<uint8_t>(ANDROID_CONTROL_AE_LOCK_AVAILABLE,
>
>  ANDROID_CONTROL_AE_LOCK_AVAILABLE_TRUE)) {
>                 LOG(HAL, Info) << noMode << "missing AE lock";
>                 return false;
>         }
>
>         ..
>
> }
>
> All in all, I don't mind, but I can live without this, unless Nicholas
> has found it particularly relevant for reasons I am missing.
>
>
> > >
> > >     found = staticMetadata_->getEntry(ANDROID_SYNC_MAX_LATENCY,
> &entry);
> > >     if (!found || *entry.data.i32 != 0) {
> > > diff --git a/src/android/camera_hal_manager.cpp
> b/src/android/camera_hal_manager.cpp
> > > index 7512cc4e..7fac4e3f 100644
> > > --- a/src/android/camera_hal_manager.cpp
> > > +++ b/src/android/camera_hal_manager.cpp
> > > @@ -140,7 +140,8 @@ void
> CameraHalManager::cameraAdded(std::shared_ptr<Camera> cam)
> > >      */
> > >     if (!isCameraExternal && !halConfig_.exists()) {
> > >             LOG(HAL, Error)
> > > -                   << "HAL configuration file is mandatory for
> internal cameras";
> > > +                   << "HAL configuration file is mandatory for
> internal cameras."
> > > +                   << " Camera NOT loaded: \"" << cam->id() << "\"";
> > >             return;
> > >     }
> > >
> > > diff --git a/src/libcamera/base/log.cpp b/src/libcamera/base/log.cpp
> > > index 55fbd7b0..b8c2c99f 100644
> > > --- a/src/libcamera/base/log.cpp
> > > +++ b/src/libcamera/base/log.cpp
> > > @@ -625,8 +625,12 @@ void Logger::parseLogFile()
> > >  void Logger::parseLogLevels()
> > >  {
> > >     const char *debug = utils::secure_getenv("LIBCAMERA_LOG_LEVELS");
> > > -   if (!debug)
> > > +   if (!debug) {
> > > +           syslog(LOG_INFO, "Could not find LIBCAMERA_LOG_LEVELS in
> env");
> > >             return;
> > > +   } else {
> > > +           syslog(LOG_INFO, "LIBCAMERA_LOG_LEVELS is %s", debug);
> > > +   }
> >
> > I don't think we should log a message to syslog every time libcamera is
> > started to report the LIBCAMERA_LOG_LEVELS value. Is this a debugging
> > leftover ?
> >
> > >
> > >     for (const char *pair = debug; *debug != '\0'; pair = debug) {
> > >             const char *comma = strchrnul(debug, ',');
> > > diff --git a/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
> b/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
> > > index 2d38f0fb..a2038704 100644
> > > --- a/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
> > > +++ b/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
> > > @@ -33,10 +33,12 @@ bool RkISP1Path::init(MediaDevice *media)
> > >     std::string resizer = std::string("rkisp1_resizer_") + name_ +
> "path";
> > >     std::string video = std::string("rkisp1_") + name_ + "path";
> > >
> > > +   LOG(RkISP1, Debug) << "Creating " << resizer;
> > >     resizer_ = V4L2Subdevice::fromEntityName(media, resizer);
> > >     if (resizer_->open() < 0)
> > >             return false;
> > >
> > > +   LOG(RkISP1, Debug) << "Creating " << video;
> >
> > Here too, is this something that you added to debug specific issues you
> > were facing, or do you expect this to be useful for users ? If the
> > latter, could you explain why ?
> >
> > >     video_ = V4L2VideoDevice::fromEntityName(media, video);
> > >     if (video_->open() < 0)
> > >             return false;
> > > diff --git a/src/libcamera/v4l2_subdevice.cpp
> b/src/libcamera/v4l2_subdevice.cpp
> > > index 15e8206a..8f86387b 100644
> > > --- a/src/libcamera/v4l2_subdevice.cpp
> > > +++ b/src/libcamera/v4l2_subdevice.cpp
> > > @@ -392,7 +392,8 @@ int V4L2Subdevice::getSelection(unsigned int pad,
> unsigned int target,
> > >     if (ret < 0) {
> > >             LOG(V4L2, Error)
> > >                     << "Unable to get rectangle " << target << " on
> pad "
> > > -                   << pad << ": " << strerror(-ret);
> > > +                   << pad << ": " << strerror(-ret) << "."
> > > +                   << "device path: " << devicePath() << " device
> node: " << deviceNode();
> >
> > If the device path and device node are useful in error messages, they
> > should be printed in all of them, not just this one. This should then be
> > done through the logPrefix() function. The code currently uses the
> > entity name as a log prefix, is that not enough ? The device path, in
> > particular, seems too verbose to me.
> >
> > >             return ret;
> > >     }
> > >
> >
> > --
> > Regards,
> >
> > Laurent Pinchart
>

Patch
diff mbox series

diff --git a/src/android/camera_capabilities.cpp b/src/android/camera_capabilities.cpp
index 64bd8dde..ef0d10d0 100644
--- a/src/android/camera_capabilities.cpp
+++ b/src/android/camera_capabilities.cpp
@@ -374,14 +374,20 @@  void CameraCapabilities::computeHwLevel(
 	camera_metadata_enum_android_info_supported_hardware_level
 		hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_FULL;
 
-	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_SENSOR))
+	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_SENSOR)) {
+		LOG(HAL, Info) << noFull << "missing manual sensor";
 		hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
+	}
 
-	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_POST_PROCESSING))
+	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_MANUAL_POST_PROCESSING)) {
+		LOG(HAL, Info) << noFull << "missing manual post processing";
 		hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
+	}
 
-	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_BURST_CAPTURE))
+	if (!caps.count(ANDROID_REQUEST_AVAILABLE_CAPABILITIES_BURST_CAPTURE)) {
+		LOG(HAL, Info) << noFull << "missing burst capture";
 		hwLevel = ANDROID_INFO_SUPPORTED_HARDWARE_LEVEL_LIMITED;
+	}
 
 	found = staticMetadata_->getEntry(ANDROID_SYNC_MAX_LATENCY, &entry);
 	if (!found || *entry.data.i32 != 0) {
diff --git a/src/android/camera_hal_manager.cpp b/src/android/camera_hal_manager.cpp
index 7512cc4e..7fac4e3f 100644
--- a/src/android/camera_hal_manager.cpp
+++ b/src/android/camera_hal_manager.cpp
@@ -140,7 +140,8 @@  void CameraHalManager::cameraAdded(std::shared_ptr<Camera> cam)
 	 */
 	if (!isCameraExternal && !halConfig_.exists()) {
 		LOG(HAL, Error)
-			<< "HAL configuration file is mandatory for internal cameras";
+			<< "HAL configuration file is mandatory for internal cameras."
+			<< " Camera NOT loaded: \"" << cam->id() << "\"";
 		return;
 	}
 
diff --git a/src/libcamera/base/log.cpp b/src/libcamera/base/log.cpp
index 55fbd7b0..b8c2c99f 100644
--- a/src/libcamera/base/log.cpp
+++ b/src/libcamera/base/log.cpp
@@ -625,8 +625,12 @@  void Logger::parseLogFile()
 void Logger::parseLogLevels()
 {
 	const char *debug = utils::secure_getenv("LIBCAMERA_LOG_LEVELS");
-	if (!debug)
+	if (!debug) {
+		syslog(LOG_INFO, "Could not find LIBCAMERA_LOG_LEVELS in env");
 		return;
+	} else {
+		syslog(LOG_INFO, "LIBCAMERA_LOG_LEVELS is %s", debug);
+	}
 
 	for (const char *pair = debug; *debug != '\0'; pair = debug) {
 		const char *comma = strchrnul(debug, ',');
diff --git a/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp b/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
index 2d38f0fb..a2038704 100644
--- a/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
+++ b/src/libcamera/pipeline/rkisp1/rkisp1_path.cpp
@@ -33,10 +33,12 @@  bool RkISP1Path::init(MediaDevice *media)
 	std::string resizer = std::string("rkisp1_resizer_") + name_ + "path";
 	std::string video = std::string("rkisp1_") + name_ + "path";
 
+	LOG(RkISP1, Debug) << "Creating " << resizer;
 	resizer_ = V4L2Subdevice::fromEntityName(media, resizer);
 	if (resizer_->open() < 0)
 		return false;
 
+	LOG(RkISP1, Debug) << "Creating " << video;
 	video_ = V4L2VideoDevice::fromEntityName(media, video);
 	if (video_->open() < 0)
 		return false;
diff --git a/src/libcamera/v4l2_subdevice.cpp b/src/libcamera/v4l2_subdevice.cpp
index 15e8206a..8f86387b 100644
--- a/src/libcamera/v4l2_subdevice.cpp
+++ b/src/libcamera/v4l2_subdevice.cpp
@@ -392,7 +392,8 @@  int V4L2Subdevice::getSelection(unsigned int pad, unsigned int target,
 	if (ret < 0) {
 		LOG(V4L2, Error)
 			<< "Unable to get rectangle " << target << " on pad "
-			<< pad << ": " << strerror(-ret);
+			<< pad << ": " << strerror(-ret) << "."
+			<< "device path: " << devicePath() << " device node: " << deviceNode();
 		return ret;
 	}