Mike Giacomelli | 6 Jul 2012 00:30
Picon
Favicon

New rockbox logging system

Hi Everyone.

I've implemented a new logging system for rockbox to eventually
replace DEBUGF and LOGF.  The new system is very similar to the old,
but with 2 significant improvements:

1)  It uses the register_storage_idle_func to write log files to disk
during spin up.  This is similar to how config files and battery bench
logs are handled.  Thus, there is no loss of battery life from
logging.

2)  There is a priority system for logging, such that the amount of
data logged is configurable.  In addition, each entry to the log is
prepended with the function name that called it (and hopefully the
source file name once we have the makefile issues worked out).  By
default, the preprocessor eliminates all non-error messages.

With these improvements, I plan to change the logging system to record
critical errors by default on both dev and release builds.  This will
greatly simplify trouble shooting, particularly for users who often
have no way to figure out why Rockbox refuses to read a file, crashes
when building a database, etc.  It will hopefully aid us in tracking
down rare crashes, particularly in places like codecs, bufflib, and
theme parsing by allowing users provide debug information directly.

I would appreciate it if people would take a look and provide feedback:

http://gerrit.rockbox.org/r/#/c/288/

Once this is committed, I will probably redefine all DEBUGF and LOGF
(Continue reading)

Jonas Wielicki | 6 Jul 2012 09:43
Gravatar

Re: New rockbox logging system

On 06.07.2012 00:30, Mike Giacomelli wrote:
> 1)  It uses the register_storage_idle_func to write log files to disk
> during spin up.  This is similar to how config files and battery bench
> logs are handled.  Thus, there is no loss of battery life from
> logging.
Can this be turned off? I am hunting issues which relate to disk access,
and I get freezes upon writing / reading in some cases.

> Once this is committed, I will probably redefine all DEBUGF and LOGF
> statements to the new system with a 'warning' priority so that they do
> not get logged by default.  It will then be up to developers going
> forward to decide which conditions are critical enough to warrant
> logging to disk.
Have you made some testing on the performance and the executable size if
you really compile in all DEBUGF and LOGF calls?

Related to your gerrit, can one see the whole diff of all patchsets
together in gerrit somehow?

cheers,
Jonas

Jonas Wielicki | 6 Jul 2012 11:03
Gravatar

Re: New rockbox logging system

On 06.07.2012 09:43, Jonas Wielicki wrote:
> 
Okay, my mail might've been to critic, I like the work, a good logging
system might be really helpful. Just asking some questions back cause
I'm curious :)

cheers

Frank Gevaerts | 6 Jul 2012 11:12
Picon

Re: New rockbox logging system

On Fri, Jul 06, 2012 at 09:43:24AM +0200, Jonas Wielicki wrote:
> Related to your gerrit, can one see the whole diff of all patchsets
> together in gerrit somehow?

Yes, indirectly. In the list of patch sets, next to each patch set
there's a gitweb link. If you click on that, you get to the gitweb page
about that commit, which has a diff link that shows one single diff.

Frank

--

-- 
"Debugging is twice as hard as writing the code in the first place.
Therefore, if you write the code as cleverly as possible, you are,
by definition, not smart enough to debug it." - Brian W. Kernighan

Mike Giacomelli | 6 Jul 2012 20:35
Picon
Favicon

Re: New rockbox logging system

>Can this be turned off? I am hunting issues which relate to disk access,
>and I get freezes upon writing / reading in some cases.

Turning this off would result in the system we currently have.  If you
want that system, just use LOGF directly and ignore my patch.

Thomas Martitz | 6 Jul 2012 23:19
Favicon
Gravatar

Re: New rockbox logging system



Mike Giacomelli <giac2000 <at> hotmail.com> schrieb:
>Can this be turned off? I am hunting issues which relate to disk access,
>and I get freezes upon writing / reading in some cases.

Turning this off would result in the system we currently have. If you
want that system, just use LOGF directly and ignore my patch.

What if this lands in mainline?

Best regards.
Mike Giacomelli | 6 Jul 2012 23:53
Picon
Favicon

Re: New rockbox logging system

We can leave the actual logf code in git, and just convert the stuff
that makes sense over to the new system.

Thomas Martitz | 8 Jul 2012 19:08
Favicon
Gravatar

Re: New rockbox logging system

Am 06.07.2012 23:53, schrieb Mike Giacomelli:
> We can leave the actual logf code in git, and just convert the stuff
> that makes sense over to the new system.

Any log to disk would trigger Jonas' storage-related problems. I guess 
he asks if a read-only build would be possible.

Best regards.

Jonas Wielicki | 8 Jul 2012 19:16
Gravatar

Re: New rockbox logging system

On 08.07.2012 19:08, Thomas Martitz wrote:
> Am 06.07.2012 23:53, schrieb Mike Giacomelli:
>> We can leave the actual logf code in git, and just convert the stuff
>> that makes sense over to the new system.
> 
> Any log to disk would trigger Jonas' storage-related problems. I guess
> he asks if a read-only build would be possible.
Right, thats what I meant.

To add some clarification: As posted on the list before, I am struggling
with debugging issues related somehow to writing to or reading from the
SSD i built into my iriver.

Obviously, it would be nice to have a proper logger (especially since
the current logging system makes my player freeze after boot, posted
that on this list too), but if that logging system would perform disk
access, it would not only trigger an infinite recursion (I have log
calls in ata_* functions, which are used to write the log files -> log
calls -> writing -> ...).

The latter problem is intrinsic to have a logger which writes to disk or
actually uses any subsystem which uses logging. That is why one has to
take great care when implementing a sophisticated logging system.

cheers,
Jonas

Mike Giacomelli | 9 Jul 2012 01:01
Picon
Favicon

RE: New rockbox logging system


> Am 06.07.2012 23:53, schrieb Mike Giacomelli:
> > We can leave the actual logf code in git, and just convert the stuff
> > that makes sense over to the new system.
>
> Any log to disk would trigger Jonas' storage-related problems. I guess
> he asks if a read-only build would be possible.
>
> Best regards.
>



The logf system logs to DRAM.  Thats part of why its not so useful, everything is lost after reboot or crash.  You have to read out the stuff on the screen (unless you have a player that can do rs232 over USB).  We can certainly leave it in for situations where the disk can't be used.  



Mike
Bertrik Sikken | 8 Jul 2012 01:08
Picon
Favicon

Re: New rockbox logging system

Hi Mike,

On 6-7-2012 12:30, Mike Giacomelli wrote:
> Hi Everyone.
> 
> I've implemented a new logging system for rockbox to eventually
> replace DEBUGF and LOGF.  The new system is very similar to the old,
> but with 2 significant improvements:
> 
> 1)  It uses the register_storage_idle_func to write log files to disk
> during spin up.  This is similar to how config files and battery bench
> logs are handled.  Thus, there is no loss of battery life from
> logging.
> 
> 2)  There is a priority system for logging, such that the amount of
> data logged is configurable.  In addition, each entry to the log is
> prepended with the function name that called it (and hopefully the
> source file name once we have the makefile issues worked out).  By
> default, the preprocessor eliminates all non-error messages.
> 
> With these improvements, I plan to change the logging system to record
> critical errors by default on both dev and release builds.  This will
> greatly simplify trouble shooting, particularly for users who often
> have no way to figure out why Rockbox refuses to read a file, crashes
> when building a database, etc.  It will hopefully aid us in tracking
> down rare crashes, particularly in places like codecs, bufflib, and
> theme parsing by allowing users provide debug information directly.
> 
> I would appreciate it if people would take a look and provide feedback:

I haven't checked out the patch yet, but I just want to say I think this
is a great idea and I appreciate you taking the initiative for this.

With kind regards,
Bertrik


Gmane