[libcamera-devel,v3,01/11] libcamera: Print Timer identifier

14915 diff mbox series

The Timer debug output does not report to which timer a condition refers
to. Fix that by printing the Timer address.

Signed-off-by: Jacopo Mondi <jacopo@jmondi.org>
---
 src/libcamera/base/event_dispatcher_poll.cpp | 3 ++-
 src/libcamera/base/timer.cpp                 | 4 ++--
 2 files changed, 4 insertions(+), 3 deletions(-)

Hi Jacopo,

Thank you for the patch.

On Wed, Dec 01, 2021 at 12:36:24AM +0100, Jacopo Mondi wrote:
> The Timer debug output does not report to which timer a condition refers
> to. Fix that by printing the Timer address.

Do I assume correctly that this comes from an issue you were trying to
debug ? If so, could you share some information (for my own information,
doesn't have to be recorded in the commit message) ?

> Signed-off-by: Jacopo Mondi <jacopo@jmondi.org>
> ---
>  src/libcamera/base/event_dispatcher_poll.cpp | 3 ++-
>  src/libcamera/base/timer.cpp                 | 4 ++--
>  2 files changed, 4 insertions(+), 3 deletions(-)
> 
> diff --git a/src/libcamera/base/event_dispatcher_poll.cpp b/src/libcamera/base/event_dispatcher_poll.cpp
> index 8ee22d5adcc4..20cc6e617189 100644
> --- a/src/libcamera/base/event_dispatcher_poll.cpp
> +++ b/src/libcamera/base/event_dispatcher_poll.cpp
> @@ -214,7 +214,8 @@ int EventDispatcherPoll::poll(std::vector<struct pollfd> *pollfds)
>  			timeout = { 0, 0 };
>  
>  		LOG(Event, Debug)
> -			<< "timeout " << timeout.tv_sec << "."
> +			<< "timeout " << nextTimer << " "
> +			<< timeout.tv_sec << "."

"timeout <pointer> <value>" could be a bit hard to read, how about

		LOG(Event, Debug)
			<< "next timer " << nextTimer << " expires in "
			<< timeout.tv_sec << "."
			<< std::setfill('0') << std::setw(9)
			<< timeout.tv_nsec;

If you think that's overkill you can ignore it.

>  			<< std::setfill('0') << std::setw(9)
>  			<< timeout.tv_nsec;
>  	}
> diff --git a/src/libcamera/base/timer.cpp b/src/libcamera/base/timer.cpp
> index 9c54352d46bd..187336e3a1a4 100644
> --- a/src/libcamera/base/timer.cpp
> +++ b/src/libcamera/base/timer.cpp
> @@ -96,7 +96,7 @@ void Timer::start(std::chrono::milliseconds duration)
>  void Timer::start(std::chrono::steady_clock::time_point deadline)
>  {
>  	if (Thread::current() != thread()) {
> -		LOG(Timer, Error) << "Timer can't be started from another thread";
> +		LOG(Timer, Error) << "Timer " << this << " << can't be started from another thread";

Maybe a timer ID would be useful to have in the future for debugging
purpose. Then we could inherit from Loggable. For now this will do.

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

>  		return;
>  	}
>  
> @@ -128,7 +128,7 @@ void Timer::stop()
>  		return;
>  
>  	if (Thread::current() != thread()) {
> -		LOG(Timer, Error) << "Timer can't be stopped from another thread";
> +		LOG(Timer, Error) << "Timer " << this << " can't be stopped from another thread";
>  		return;
>  	}
>

Hi Laurent

On Wed, Dec 01, 2021 at 02:32:37AM +0200, Laurent Pinchart wrote:
> Hi Jacopo,
>
> Thank you for the patch.
>
> On Wed, Dec 01, 2021 at 12:36:24AM +0100, Jacopo Mondi wrote:
> > The Timer debug output does not report to which timer a condition refers
> > to. Fix that by printing the Timer address.
>
> Do I assume correctly that this comes from an issue you were trying to
> debug ? If so, could you share some information (for my own information,
> doesn't have to be recorded in the commit message) ?

I didn't have any specific issue, I wanted to be sure the 'right'
timer was started at the right time, but just that displying such
information without saying to what timer they belong is not that useful

>
> > Signed-off-by: Jacopo Mondi <jacopo@jmondi.org>
> > ---
> >  src/libcamera/base/event_dispatcher_poll.cpp | 3 ++-
> >  src/libcamera/base/timer.cpp                 | 4 ++--
> >  2 files changed, 4 insertions(+), 3 deletions(-)
> >
> > diff --git a/src/libcamera/base/event_dispatcher_poll.cpp b/src/libcamera/base/event_dispatcher_poll.cpp
> > index 8ee22d5adcc4..20cc6e617189 100644
> > --- a/src/libcamera/base/event_dispatcher_poll.cpp
> > +++ b/src/libcamera/base/event_dispatcher_poll.cpp
> > @@ -214,7 +214,8 @@ int EventDispatcherPoll::poll(std::vector<struct pollfd> *pollfds)
> >  			timeout = { 0, 0 };
> >
> >  		LOG(Event, Debug)
> > -			<< "timeout " << timeout.tv_sec << "."
> > +			<< "timeout " << nextTimer << " "
> > +			<< timeout.tv_sec << "."
>
> "timeout <pointer> <value>" could be a bit hard to read, how about
>
> 		LOG(Event, Debug)
> 			<< "next timer " << nextTimer << " expires in "
> 			<< timeout.tv_sec << "."
> 			<< std::setfill('0') << std::setw(9)
> 			<< timeout.tv_nsec;
>
> If you think that's overkill you can ignore it.
>

It's good! I'll test how it looks like and I'll eventually take it in

> >  			<< std::setfill('0') << std::setw(9)
> >  			<< timeout.tv_nsec;
> >  	}
> > diff --git a/src/libcamera/base/timer.cpp b/src/libcamera/base/timer.cpp
> > index 9c54352d46bd..187336e3a1a4 100644
> > --- a/src/libcamera/base/timer.cpp
> > +++ b/src/libcamera/base/timer.cpp
> > @@ -96,7 +96,7 @@ void Timer::start(std::chrono::milliseconds duration)
> >  void Timer::start(std::chrono::steady_clock::time_point deadline)
> >  {
> >  	if (Thread::current() != thread()) {
> > -		LOG(Timer, Error) << "Timer can't be started from another thread";
> > +		LOG(Timer, Error) << "Timer " << this << " << can't be started from another thread";
>
> Maybe a timer ID would be useful to have in the future for debugging
> purpose. Then we could inherit from Loggable. For now this will do.
>
> Reviewed-by: Laurent Pinchart <laurent.pinchart@ideasonboard.com>

Thanks
  j

>
> >  		return;
> >  	}
> >
> > @@ -128,7 +128,7 @@ void Timer::stop()
> >  		return;
> >
> >  	if (Thread::current() != thread()) {
> > -		LOG(Timer, Error) << "Timer can't be stopped from another thread";
> > +		LOG(Timer, Error) << "Timer " << this << " can't be stopped from another thread";
> >  		return;
> >  	}
> >
>
> --
> Regards,
>
> Laurent Pinchart