net: l2: ethernet: arp: improve debug output

[JordanYates]

Improve the ARP debug output by printing:

• Sending ARP query
• Queuing packets due to pending ARP query
• Receiving ARP query response

[jukkar]

No objections to adding more prints, but imho these are more like debug messages instead of infos. If all is well and one is not debugging things, there should be no need to print anything. And with debugging one needs to usually enable the debug level which then prints these.

[JordanYates]

No objections to adding more prints, but imho these are more like debug messages instead of infos. If all is well and one is not debugging things, there should be no need to print anything. And with debugging one needs to usually enable the debug level which then prints these.

Is DBG the only valid log level in the networking stack? It seems I can turn on CONFIG_NET_LOG when I am having a problem and get 0% more idea of where my problem is until I turn on _LOG_LEVEL_DBG in the module that I don't yet know contains the problem.

If I change it to debug, there is no differentiation between "Here is the ARP request and response" which is 2 prints per IP and "Here is ARP translation for every single packet I ever send", which can immediately consume the entire log buffer.

If INFO is too verbose, my opinion is that either you should be turning off NET_LOG or the default level should be changed to WRN in Kconfig.

I won't die on this hill though :)

[jukkar]

Yeah, you can turn off all network logging with CONFIG_NET_LOG and your workflow (setting CONFIG_NET_LOG=y) is one possibility to see output. Perhaps I am too close to this and usually never use NET_INFO as it has not been very useful for me because it can lead excessive printing. I usually always have set CONFIG_NET_LOG=y in my development and then set the log level to DBG to see in detail what is going on in the system.
Anyway, not sure what other people think about this, @rlubos WDYT?

[JordanYates]

Yeah, you can turn off all network logging with CONFIG_NET_LOG and your workflow (setting CONFIG_NET_LOG=y) is one possibility to see output. Perhaps I am too close to this and usually never use NET_INFO as it has not been very useful for me because it can lead excessive printing. I usually always have set CONFIG_NET_LOG=y in my development and then set the log level to DBG to see in detail what is going on in the system. Anyway, not sure what other people think about this, @rlubos WDYT?

Ignoring the networking part for now, my opinion is that if a piece of code is doing real work then there should be some level of logging at INFO. INFO should be for high level actions that let you know the thing is working normally, DBG is for the details that would otherwise spam the console. My 2c.

[jukkar]

It is interesting to see other people workflow, the way you are using CONFIG_NET_LOG is kind of handy to see information about the normal state of the system. For me it probably means excessive logging but I can certainly cope this if we want to go to this direction. I checked subsys/net and there are quite many LOG_INF used, those should be converted to NET_INFO so that the CONFIG_NET_LOG would work as expected, I will send a PR for this at some point.

[rlubos]

I kind of like the idea of introducing more granularity to the networking logs, currently in most cases it just DBG or ERR. And debug logs can really get bloated in some cases.
But IMO we should indeed consider changing the default log level in the networking subsystem to WARN, as suggested. If more components follow this pattern, the amount of logs enabled by default with INFO level could be too much.

[JordanYates]

Changed NET_INFO to NET_DBG, changes to default log levels are outside the scope of the PR