kernel/printk/printk.c | 30 ++++++++++++++++++++++++++---- 1 file changed, 26 insertions(+), 4 deletions(-)
When the initial printk ring buffer size is updated, setup_log_buf()
allocates a new ring buffer, as well as a set of meta-data structures
for the new ring buffer. The function also emits the new size of the
ring buffer, but not the size of the meta-data structures.
This makes it difficult to assess how changing the log buffer size
impacts memory usage during boot.
For instance, increasing the ring buffer size from 512 KB to 1 MB
through the command line yields an increase of 2304 KB in reserved
memory at boot, while the only obvious change is the 512 KB
difference in the ring buffer sizes:
log_buf_len=512K:
printk: log_buf_len: 524288 bytes
Memory: ... (... 733252K reserved ...)
log_buf_len=1M:
printk: log_buf_len: 1048576 bytes
Memory: ... (... 735556K reserved ...)
This is because of how the size of the meta-data structures scale with
the size of the ring buffer.
Even when there aren't changes to the printk ring buffer size (i.e. the
initial size == 1 << CONFIG_LOG_BUF_SHIFT), it is impossible to tell
how much memory is consumed by the printk ring buffer during boot.
Therefore, unconditionally log the sizes of the printk ring buffer
and its meta-data structures, so that it's easier to understand
how changing the log buffer size (either through the command line or
by changing CONFIG_LOG_BUF_SHIFT) affects boot time memory usage.
With the new logs, it is much easier to see exactly why the memory
increased by 2304 KB:
log_buf_len=512K:
printk: log_buf_len: 524288 bytes
printk: prb_descs size: 393216 bytes
printk: printk_infos size: 1441792 bytes
Memory: ... (... 733252K reserved ...)
log_buf_len=1M:
printk: log_buf_len: 1048576 bytes
printk: prb_descs size: 786432 bytes
printk: printk_infos size: 2883584 bytes
Memory: ... (... 735556K reserved ...)
Signed-off-by: Isaac J. Manjarres <isaacmanjarres@google.com>
---
kernel/printk/printk.c | 30 ++++++++++++++++++++++++++----
1 file changed, 26 insertions(+), 4 deletions(-)
v1 -> v2:
- Consolidated the printk memory usage stats into a single line, and
summed the printk_info and prb_desc structure sizes into a single
stat to make the output more user-friendly.
- Fixed an error that caused the memory usage stats to be emitted twice
when using the default printk buffer.
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index beb808f4c367..9ba7dd8f352f 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1156,6 +1156,17 @@ static unsigned int __init add_to_rb(struct printk_ringbuffer *rb,
static char setup_text_buf[PRINTKRB_RECORD_MAX] __initdata;
+static void print_log_buf_usage_stats(void)
+{
+ unsigned int descs_count = log_buf_len >> PRB_AVGBITS;
+ size_t meta_data_size;
+
+ meta_data_size = descs_count * (sizeof(struct prb_desc) + sizeof(struct printk_info));
+
+ pr_info("log buffer data + meta data: %u + %zu = %zu bytes\n",
+ log_buf_len, meta_data_size, log_buf_len + meta_data_size);
+}
+
void __init setup_log_buf(int early)
{
struct printk_info *new_infos;
@@ -1185,20 +1196,29 @@ void __init setup_log_buf(int early)
if (!early && !new_log_buf_len)
log_buf_add_cpu();
- if (!new_log_buf_len)
+ if (!new_log_buf_len) {
+ /*
+ * If early == 0 here, then we're using the default buffer,
+ * but the memory usage stats haven't been printed yet,
+ * so do that now.
+ */
+ if (!early)
+ goto out;
+
return;
+ }
new_descs_count = new_log_buf_len >> PRB_AVGBITS;
if (new_descs_count == 0) {
pr_err("new_log_buf_len: %lu too small\n", new_log_buf_len);
- return;
+ goto out;
}
new_log_buf = memblock_alloc(new_log_buf_len, LOG_ALIGN);
if (unlikely(!new_log_buf)) {
pr_err("log_buf_len: %lu text bytes not available\n",
new_log_buf_len);
- return;
+ goto out;
}
new_descs_size = new_descs_count * sizeof(struct prb_desc);
@@ -1261,7 +1281,7 @@ void __init setup_log_buf(int early)
prb_next_seq(&printk_rb_static) - seq);
}
- pr_info("log_buf_len: %u bytes\n", log_buf_len);
+ print_log_buf_usage_stats();
pr_info("early log buf free: %u(%u%%)\n",
free, (free * 100) / __LOG_BUF_LEN);
return;
@@ -1270,6 +1290,8 @@ void __init setup_log_buf(int early)
memblock_free(new_descs, new_descs_size);
err_free_log_buf:
memblock_free(new_log_buf, new_log_buf_len);
+out:
+ print_log_buf_usage_stats();
}
static bool __read_mostly ignore_loglevel;
--
2.46.1.824.gd892dcdcdd-googOn Mon 2024-09-30 11:48:24, Isaac J. Manjarres wrote: > When the initial printk ring buffer size is updated, setup_log_buf() > allocates a new ring buffer, as well as a set of meta-data structures > for the new ring buffer. The function also emits the new size of the > ring buffer, but not the size of the meta-data structures. > > This makes it difficult to assess how changing the log buffer size > impacts memory usage during boot. > > For instance, increasing the ring buffer size from 512 KB to 1 MB > through the command line yields an increase of 2304 KB in reserved > memory at boot, while the only obvious change is the 512 KB > difference in the ring buffer sizes: > > log_buf_len=512K: > > printk: log_buf_len: 524288 bytes > Memory: ... (... 733252K reserved ...) > > log_buf_len=1M: > > printk: log_buf_len: 1048576 bytes > Memory: ... (... 735556K reserved ...) > > This is because of how the size of the meta-data structures scale with > the size of the ring buffer. > > Even when there aren't changes to the printk ring buffer size (i.e. the > initial size == 1 << CONFIG_LOG_BUF_SHIFT), it is impossible to tell > how much memory is consumed by the printk ring buffer during boot. > > Therefore, unconditionally log the sizes of the printk ring buffer > and its meta-data structures, so that it's easier to understand > how changing the log buffer size (either through the command line or > by changing CONFIG_LOG_BUF_SHIFT) affects boot time memory usage. > > With the new logs, it is much easier to see exactly why the memory > increased by 2304 KB: > > log_buf_len=512K: > > printk: log_buf_len: 524288 bytes > printk: prb_descs size: 393216 bytes > printk: printk_infos size: 1441792 bytes This should get updated to the new format. If I count correctly then it should be: printk: log buffer data + meta data: 524288 + 1835008 = 2359296 bytes > Memory: ... (... 733252K reserved ...) > > log_buf_len=1M: > > printk: log_buf_len: 1048576 bytes > printk: prb_descs size: 786432 bytes > printk: printk_infos size: 2883584 bytes and here: printk: log buffer data + meta data: 1048576 + 3670016 = 4718592 bytes > Memory: ... (... 735556K reserved ...) > > Signed-off-by: Isaac J. Manjarres <isaacmanjarres@google.com> Otherwise, it looks good. With the updated commit message: Reviewed-by: Petr Mladek <pmladek@suse.com> Tested-by: Petr Mladek <pmladek@suse.com> Note need to send v3. I could update the commit message when committing the patch. I am going to wait few days for a potential another review before pushing. Best Regards, Petr
On Tue, Oct 01, 2024 at 05:46:31PM +0200, Petr Mladek wrote: > On Mon 2024-09-30 11:48:24, Isaac J. Manjarres wrote: > > With the new logs, it is much easier to see exactly why the memory > > increased by 2304 KB: > > > > log_buf_len=512K: > > > > printk: log_buf_len: 524288 bytes > > printk: prb_descs size: 393216 bytes > > printk: printk_infos size: 1441792 bytes > > This should get updated to the new format. > If I count correctly then it should be: > > printk: log buffer data + meta data: 524288 + 1835008 = 2359296 bytes Sorry, I forgot to do that; thanks for catching it. Yes, the calculation is correct. > > Memory: ... (... 733252K reserved ...) > > > > log_buf_len=1M: > > > > printk: log_buf_len: 1048576 bytes > > printk: prb_descs size: 786432 bytes > > printk: printk_infos size: 2883584 bytes > > and here: > > printk: log buffer data + meta data: 1048576 + 3670016 = 4718592 bytes This is also correct. > > Memory: ... (... 735556K reserved ...) > > > > Signed-off-by: Isaac J. Manjarres <isaacmanjarres@google.com> > > Otherwise, it looks good. With the updated commit message: > > Reviewed-by: Petr Mladek <pmladek@suse.com> > Tested-by: Petr Mladek <pmladek@suse.com> > > > Note need to send v3. I could update the commit message when committing > the patch. > > I am going to wait few days for a potential another review > before pushing. Thank you Petr for your review and for picking this up! I really appreciate it. Thanks, Isaac
On Wed, Oct 02, 2024 at 11:04:48AM -0700, Isaac Manjarres wrote: > On Tue, Oct 01, 2024 at 05:46:31PM +0200, Petr Mladek wrote: > > On Mon 2024-09-30 11:48:24, Isaac J. Manjarres wrote: > > > With the new logs, it is much easier to see exactly why the memory > > > increased by 2304 KB: > > > > > > log_buf_len=512K: > > > > > > printk: log_buf_len: 524288 bytes > > > printk: prb_descs size: 393216 bytes > > > printk: printk_infos size: 1441792 bytes > > > > This should get updated to the new format. > > If I count correctly then it should be: > > > > printk: log buffer data + meta data: 524288 + 1835008 = 2359296 bytes > Sorry, I forgot to do that; thanks for catching it. Yes, the > calculation is correct. > > > > Memory: ... (... 733252K reserved ...) > > > > > > log_buf_len=1M: > > > > > > printk: log_buf_len: 1048576 bytes > > > printk: prb_descs size: 786432 bytes > > > printk: printk_infos size: 2883584 bytes > > > > and here: > > > > printk: log buffer data + meta data: 1048576 + 3670016 = 4718592 bytes > This is also correct. > > > > Memory: ... (... 735556K reserved ...) > > > > > > Signed-off-by: Isaac J. Manjarres <isaacmanjarres@google.com> > > > > Otherwise, it looks good. With the updated commit message: > > > > Reviewed-by: Petr Mladek <pmladek@suse.com> > > Tested-by: Petr Mladek <pmladek@suse.com> > > > > > > Note need to send v3. I could update the commit message when committing > > the patch. > > > > I am going to wait few days for a potential another review > > before pushing. > Thank you Petr for your review and for picking this up! I really > appreciate it. > > Thanks, > Isaac Hi Petr, I just wanted to follow up to see if there was anything else left for this patch? Otherwise, would it be possible to please merge this? Thank you, Isaac
On Tue 2024-10-15 05:47:55, Isaac Manjarres wrote:
> On Wed, Oct 02, 2024 at 11:04:48AM -0700, Isaac Manjarres wrote:
> > On Tue, Oct 01, 2024 at 05:46:31PM +0200, Petr Mladek wrote:
> > > On Mon 2024-09-30 11:48:24, Isaac J. Manjarres wrote:
> > > > With the new logs, it is much easier to see exactly why the memory
> > > > increased by 2304 KB:
> > > >
> > > Note need to send v3. I could update the commit message when committing
> > > the patch.
>
> I just wanted to follow up to see if there was anything else left
> for this patch? Otherwise, would it be possible to please merge this?
I am sorry for the delay and thanks for the reminder. Last weeks were
a bit hectic...
Anyway, I have just comitted the patch into printk/linux.git,
branch for-6.13.
Note:
I have updated the sample messages in the commit message as suggested
earlier.
Also I double checked the patch and simplified the comment
in the following hunk. The original one was a bit cryptic.
@@ -1185,20 +1196,25 @@ void __init setup_log_buf(int early)
if (!early && !new_log_buf_len)
log_buf_add_cpu();
- if (!new_log_buf_len)
+ if (!new_log_buf_len) {
+ /* Show the memory stats only once. */
+ if (!early)
+ goto out;
+
return;
+ }
, see also
https://git.kernel.org/pub/scm/linux/kernel/git/printk/linux.git/commit/?h=for-6.13&id=a961ec4e2860af4933e8c1763fe4f038c2d6ac80
Best Regards,
Petr
On Wed, Oct 16, 2024 at 12:24:35PM +0200, Petr Mladek wrote:
> I am sorry for the delay and thanks for the reminder. Last weeks were
> a bit hectic...
>
> Anyway, I have just comitted the patch into printk/linux.git,
> branch for-6.13.
>
> Note:
>
> I have updated the sample messages in the commit message as suggested
> earlier.
>
> Also I double checked the patch and simplified the comment
> in the following hunk. The original one was a bit cryptic.
>
> @@ -1185,20 +1196,25 @@ void __init setup_log_buf(int early)
> if (!early && !new_log_buf_len)
> log_buf_add_cpu();
>
> - if (!new_log_buf_len)
> + if (!new_log_buf_len) {
> + /* Show the memory stats only once. */
> + if (!early)
> + goto out;
> +
> return;
> + }
>
> , see also
> https://git.kernel.org/pub/scm/linux/kernel/git/printk/linux.git/commit/?h=for-6.13&id=a961ec4e2860af4933e8c1763fe4f038c2d6ac80
>
> Best Regards,
> Petr
No worries! I completely understand. Thank you for merging the patch
into your tree, and for cleaning up the commit message/comment.
Thanks,
Isaac
© 2016 - 2024 Red Hat, Inc.