Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add newline to last pr_info to force dmesg to flush #235

Merged
merged 1 commit into from
Sep 28, 2023

Conversation

mechanicalamit
Copy link
Collaborator

dmesg only flushes when it encounter a newline. Without a newline, the line is held in memory pending another printk. In this particular example (example_atomic.c), the last pr_info in atomic_bitwise() prints when another printk happens (either by another module, or __exit for this module.

This can be confusing to new learner. This patch adds a newline to the last pr_info forcing dmesg to print to the screen when the module is loaded.

--------------- Alternate solution ---------------
Alternate solutions could be adding a newline to BYTE_TO_BINARY_PATTERN
#define BYTE_TO_BINARY_PATTERN "%c%c%c%c%c%c%c%c\n"

... or adding a newline to each pr_info() call.

dmesg only flushes when it encounter a newline. Without a newline, the line
is held in memory pending another printk. In this particular example
(example_atomic.c), the last pr_info in atomic_bitwise() prints when
another printk happens (either by another module, or __exit for this
module.

This can be confusing to new learner. This patch adds a newline to the last
pr_info forcing dmesg to print to the screen when the module is loaded.
@jserv jserv requested a review from linD026 September 28, 2023 15:41
@jserv
Copy link
Contributor

jserv commented Sep 28, 2023

I am not sure if adding a newline to each pr_info() call is better or not. I defer to @linD026 .

@linD026
Copy link
Collaborator

linD026 commented Sep 28, 2023

I ran the example_atomic.c on Ubuntu 5.15.0-84-generic, here is what I got:

[223073.466911] example_atomic started
[223073.466920] chris: 50, debbie: 52
[223073.466922] Bits 0: 00000000
[223073.466923] Bits 1: 00101000
[223073.466924] Bits 2: 00001000
[223073.466925] Bits 3: 00000000
[223073.466926] Bits 4: 00001000
[223073.466927] Bits 5: 11111111
[223092.000950] example_atomic exit

It's actually the same as this PR version.
I think you might misunderstand how the printk works, please check the mailing list and source code to provide a more strongly and closely relevant reason. Then, explain why we should add the newline even though the printk already did it by itself.

@mechanicalamit
Copy link
Collaborator Author

mechanicalamit commented Sep 28, 2023

On running insmod example_atomic.ko, the dmesg output is:

[81692.796873] example_atomic started
[81692.796880] chris: 50, debbie: 52
[81692.796882] Bits 0: 00000000
[81692.796883] Bits 1: 00101000
[81692.796884] Bits 2: 00001000
[81692.796885] Bits 3: 00000000
[81692.796886] Bits 4: 00001000

Note the missing Bits 5 line in the dmesg output, even though that Bits 5 printk() has been called.

Then further on running rmmod example_atomic.ko, the Bits 5 line and example_atomic exit line will show up in the dmesg output.

To be honest, its not actually a code problem as you said above. The code is correct from a module point of view. At some point some other printk will occur and flush out the Bits 5 line.

The problem is when a learner (like me) tries the code, runs the insmod and wonders why the Bits 5 line did not output in dmesg. That is exactly what happened to me and frankly made me learn a few more things.

Copy link
Collaborator

@linD026 linD026 left a comment

Choose a reason for hiding this comment

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

Thanks for the explanation.
Now, I know what is this PR targeting.
It makes sense to me.

@jserv jserv marked this pull request as ready for review September 28, 2023 18:23
@jserv jserv merged commit 866eba0 into sysprog21:master Sep 28, 2023
1 check passed
@mechanicalamit
Copy link
Collaborator Author

mechanicalamit commented Sep 28, 2023

Some amateur research (which might be incorrect).

In printk.c prb_final_commit() or prb_commit() is called depending on the presence of a newline.

prb_*_commit functions are defined in printk_ringbuffer.c

From comments above the prb_*_commit functions, here are the relevant quotes.

  • prb_commit()
  • Note that the data is not yet available to readers until it is finalized.
  • Finalizing happens automatically when space for the next record is
  • reserved
  • prb_final_commit()
  • By finalizing, the data is made immediately available to readers.

So it might seem, that it is a printk behavior, and not a dmesg behavior as my commit message says.

printk also seems to remove newlines, and then adds its own.
ref 1 ref 2

@mechanicalamit mechanicalamit deleted the atomic-patches branch September 28, 2023 18:51
@jserv
Copy link
Contributor

jserv commented Sep 28, 2023

So it might seem, that it is a printk behavior, and not a dmesg behavior as my commit message says.
printk also seems to remove newlines, and then adds its own. ref 1 ref 2

@mechanicalamit, Please create a new issue, so that we can track later.

@mechanicalamit
Copy link
Collaborator Author

@jserv, the above was an attempt to understand and explain why this behavior was occurring. I don't think its an issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants