Skip to content

Conversation

@nordic-krch
Copy link
Contributor

Added log_panic() to fault handlers and replaced printk() with LOG_ERR() within fatal/fault module.

Ensure that only first log_panic() sends panic signal to backends

Signed-off-by: Krzysztof Chruscinski <[email protected]>
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This line should not be changed.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this neither

Copy link
Member

@aescolar aescolar Sep 18, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

  1. Question: Is the intention that only the new logger subsystem be used at all?
    So not only the old logger but also printk would be deprecated?

  2. The arm commit does not have a message body

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Imo, they overlaps since printk is actually error message in kernel. Some may argue that it is not error but info. Then why not to use logger directly. In fact there is an option to redirect printk to logger but this is rather for backward compatibility. Direct use of the console in printk is also a drawback. As long as it is simple polling there is no problem, but once console over uart uses interrupts then it cannot be used in fault handler. Logger handles that (panic mode).

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would it be reasonable to start by only enabling the logger panic in this PR, and let the user chose if he wants to use the old printk or route printk to the new logger with CONFIG_LOG_PRINTK?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe, but on the other hand replacing printk with LOG_.. adds value:

  • LOG_... can be redirected to multiple backends so adding flashlog backend will immediately add crashlog. Printk can be redirected to log but then it takes more resources and is less efficient.
  • standard severity level configuration can be used instead of custom one (CONFIG_FAULT_DUMP)
  • code is cleaner because #ifdef CONFIG_PRINTK can be removed.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not saying we should not do it eventually. My thinking was that this PR has 2 things:

  • Activate the logger panic -> It makes sense to take this change in right away.
  • Replacing calls from printk with logger. -> It's not urgent. Actually thanks to the CONFIG_LOG_PRINTK option, it could be done after the whole SYS_LOG => LOG transition. But starting to do the printk replacements today means losing them where the new logger does not yet work. So, if it were me, I would focus first on maturing the logger, getting in more backends for it, and doing the SYS_LOG=>LOG transition (that's already a lot of things to be done).

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Followed your suggestion and created #10098

Copy link
Member

@aescolar aescolar Sep 18, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

About removing the \n :
I guess that is because this logger adds on its own extra end of lines?
So, will all old calls to printk(), when routed to this new logger, have now 2 new lines instead of 1?
And it would not be possible to print to the same line in consecutive calls to this logger?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

yes, logger adds '\r\n' but there is an option to pass raw strings to it (log_printk() in log_core.h). Then when message is processed it is not formatted (no level prefix, no timestamp, no new line).

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why is it adding both a \r and a \n?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

when printf is used console is implicitly adding \r when \n is detected. So log is adding both. If you look at sys_log, it was also adding \n and then through console adding \r.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

console is implicitly adding \r when \n is detected

You mean the UART console "backend"? (while it would seem the ipm backend actively removes the \r it finds, and the sys_log_net strips the trailing '\n'). Would it makes sense to have the logger backends be the one adding extra \r if it needs them and have the core of the logger be a passthru?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It is like you said. Logger frontend/core doesn't do it. Log_output module is doing it. This helper module can be used by log backend to format string. We can extend log_ouput to optionally add \r.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah ok, I saw the logger output as a common component meant for mostly all backends.. I just missinterpreted the design.
I guess an option to both be able to disable the \r and dropping the timestamp'*1 when formatting the output would be nice (if it could be done easily '*2)
'*1 A backend which does in place processing may want to save that time, and let an external device do the timestamping.
'*2 If it cannot be done easily, I guess that logger_output code should just be "forked" for those weird backends

Added log_panic() to fault handlers. Replaced printk with log API

Signed-off-by: Krzysztof Chruscinski <[email protected]>
Added log_panic() to fault handlers. Replaced printk with log API

Signed-off-by: Krzysztof Chruscinski <[email protected]>
Added log_panic() to fault handlers. Replaced printk with log API

Signed-off-by: Krzysztof Chruscinski <[email protected]>
Added log_panic() to fault handlers. Replaced printk with log API

Signed-off-by: Krzysztof Chruscinski <[email protected]>
Added log_panic() to fault handlers. Replaced printk with log API

Signed-off-by: Krzysztof Chruscinski <[email protected]>
Added log_panic() to fault handlers. Replaced printk with log API

Signed-off-by: Krzysztof Chruscinski <[email protected]>
Copy link
Contributor

@pizi-nordic pizi-nordic left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think, that all these message should be logged using LOG_ERR(). Now, some of important information are printed on INFO level.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants