Hi Petr et al,
CC linux-embedded
On Tue, Oct 1, 2024 at 5:55 PM Petr Mladek <pmladek@xxxxxxxx> wrote:
> On 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
Thanks, this is very useful information!
Isn't this kernel log message bookkeeping becoming a bit too excessive?
E.g. on a small system:
printk: log buffer data + meta data: 65536 + 204800 = 270336 bytes
Why is the meta data that big (> 3*log buffer)?
#define PRB_AVGBITS 5 /* 32 character average length */
unsigned int descs_count = log_buf_len >> PRB_AVGBITS;
meta_data_size = descs_count * (sizeof(struct prb_desc) +
sizeof(struct printk_info));
struct prb_data_blk_lpos {
unsigned long begin;
unsigned long next;
};
struct prb_desc {
atomic_long_t state_var;
struct prb_data_blk_lpos text_blk_lpos;
};
i.e. 12 bytes on 32-bit, 24 bytes on 64-bit.
#define PRINTK_INFO_SUBSYSTEM_LEN 16
#define PRINTK_INFO_DEVICE_LEN 48
struct dev_printk_info {
char subsystem[PRINTK_INFO_SUBSYSTEM_LEN];
char device[PRINTK_INFO_DEVICE_LEN];
};
struct printk_info {
u64 seq; /* sequence number */
u64 ts_nsec; /* timestamp in nanoseconds */
u16 text_len; /* length of text message */
u8 facility; /* syslog facility */
u8 flags:5; /* internal record flags */
u8 level:3; /* syslog level */
u32 caller_id; /* thread id or processor id */
struct dev_printk_info dev_info;
};
for a whopping 88 bytes. So that totals to 100 bytes per entry
on 32-bit, and 112 on 64-bit, for an average of 32 characters per
printed message...
Gr{oetje,eeting}s,
Geert
--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@xxxxxxxxxxxxxx
In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
-- Linus Torvalds
