Re: RFC: Stopping Zephyr networking from being painful by enabling error logging by default


Paul Sokolovsky
 

On Thu, 14 Sep 2017 09:33:22 +0300
Jukka Rissanen <jukka.rissanen@linux.intel.com> wrote:

Hi Paul,

On Wed, 2017-09-13 at 23:02 +0300, Paul Sokolovsky wrote:
Hello,

I more the once mentioned the issue that Zephyr IP networking is
very hard to configure. It almost impossible to configure
a slightly-above-trivial app from scratch: something won't work with
it,
usually silently.
I am probably biased here and looking the code too close but what
exactly is hard when configuring the IP stack? Is it difficult to
figure out the suitable config options, are the help texts in Kconfig
options too short or what? Please elaborate this more.
It's that there're too many options, and need for a particular option
or an effect of some option is hard to anticipate, and if one didn't,
an application usually silently doesn't do anything/something useful or
just crashes.

A usual response would be "enable debug logging", but here it goes
in the vicious cycle, because it's hard to enable network debug
logging in
Zephyr. It requires setting CONFIG_NET_LOG, then if you're lucky,
you discover CONFIG_NET_LOG_GLOBAL, then you also need to figure
out that you need to set CONFIG_SYS_LOG_NET_LEVEL to a cryptic
numeric value.
I never use the CONFIG_NET_LOG_GLOBAL because it just prints out too
much data which slows down everything in the device and makes
debugging even harder. I would actually propose that we remove that
option but if someone sees it useful to have, then we can keep it.
That's why I propose to enable it only with "warning" logging level.
That will be useful for users to spot misconfigurations/understand
misbehavior. But as I mentioned in the previous reply on the thread
(to Andrew), this leads to a problem that if a user adjusts just
the logging level to "debug", they get flooded with spam-logging.

We should anticipate this problem and give instructions for users how to
deal with it (as in: Kconfig help for CONFIG_NET_LOG_GLOBAL should warn
against it's usage with DEBUG, and instead suggest to disable itself
and enabled individual module logging).



If you think that's enough, then nah, because CONFIG_NET_LOG_GLOBAL
doesn't really enable logging globally. Then maybe you trace another
config option, after which you will likely either get a flood of
DEBUG
level logging, or find out that an important condition is not logged
at
all.
As the name implies, the CONFIG_NET_LOG_GLOBAL is only for networking.
It might also miss some new net debug options.
ARP is also networking, BSD Sockets is also networking, SLIP is also
networking. I'm, a Random J User, expect to see errors/warnings in all
of them by default (and ready to be taught how to deal with debug-level
logging enabled).



Debugging the configuration and debug logging itself is quite
painful,
after a year on Zephyr, I still didn't master it, what to say about
newcomers?

So, I'd like to propose to make following changes:

1. Enable CONFIG_NET_LOG=y, CONFIG_NET_LOG_GLOBAL=y,
CONFIG_SYS_LOG_NET_LEVEL=2 (WARN) by default.
We could set the log level to 2 (warn) as you suggest, there was not
many warns in the net stack anyway.

I disagree with enabling logging by default, it bloats the binary and
also increases ram / stack usage.
Above you write that there're not so many warnings in the stack. So,
bloating a binary shouldn't be that big a problem. If it is, we need to
optimize the logging and its ram/stack usage. (But we definitely need
to add more warns/errors, that's the whole point.)

Normally you do not need to have
debugging enabled anyway,
My experience with Zephyr shows the contrary.

and if you need it, then it is easy to set
CONFIG_NET_LOG=y,
So, the talk is about making it uber-easy: users get the errors by
default, and making it easy to *disable* it (by setting
CONFIG_NET_LOG=n).

enable individual component logging
Enable individual component logging is easy? But you need to know that
you need to enable it individually, know how to do that, know which
individual components exist. That's already *very* hard for a novice.

or global
logging, and then increase the log level.
You lost me (a random novice user) here.

Perhaps we could have better documentation about this, could you
perhaps send a patch describing how to do it?
So, the talk is about making it work with least user surprise
for novice and casual users - by enabling the err/warn logging by
default. Then, for users who go as far as using Zephyr in production
(where logging should be disabled), there should be an easy way to
disable it (1 config option). Yes, it should be well documented, and
I'll be happy to contribute to such documentation. (Sorry, expecting
that people start on a new project with thoroughly reading docs is,
well, ungrounded.)


Cheers,
Jukka
Thanks,

--
Best Regards,
Paul

Linaro.org | Open source software for ARM SoCs
Follow Linaro: http://www.facebook.com/pages/Linaro
http://twitter.com/#!/linaroorg - http://www.linaro.org/linaro-blog

Join devel@lists.zephyrproject.org to automatically receive all group messages.