Re: [RFC V2] printk: add warning while drop partial text in msg

[pierre kuo]

hi Sergey and Petr
> Hi,
> On (08/11/17 00:55), pierre kuo wrote:
> [..]
>> And people will be hard to find out some part of message is left behind.
>> (since the tail of original message is elegantly dropped by "\n")
>> That is the reason I try to add such warning in msg_print_text.
>
> have you ever seen it (the truncation) in real life?
The experimental steps are list as follows.
Feel free to give your comments.

Prerequisite:
a) kernel version:
    commit: a80099a152d0 ("Merge tag 'xfs-4.13-merge-6' of
git://git.kernel.org/pub/scm/fs/xfs/xfs-linux")

1. Add below patch in log_store to tell the content and length of log
that saved in log_text(msg) for below step #2 .
@@ -629,6 +629,11 @@ static int log_store(int facility, int level,
        msg->len = size;

        /* insert message */
+       if (msg->text_len > 512) {
+               trace_printk("%s\n", log_text(msg));
+               trace_printk("msg->text_len %d\n", msg->text_len);
+       }
+
        log_next_idx += msg->len;
        log_next_seq++;

2. Use below kernel thread sample for adding the string to msg.
int per_cpu_thread_fn(void* data)
{
    unsigned int index = 0;
    unsigned int len = 0;
    char* local_string = kzalloc(2048, GFP_KERNEL);

    do {
        len += sprintf((local_string + len), "this is the %d line\n", index++);
    }while(len < 576);
    printk_deferred("%s", local_string);
    return 0;
}

3. After running above #2, here is trace output from #1
(from the output, total "29 lines" of local_string has successfully
saved in log_buf)
# cat /sys/kernel/debug/tracing/trace;
# tracer: nop
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
  per_cpu_thread-81    [000] d..1    26.555745: log_store: this is the 0 line
this is the 1 line
this is the 2 line
this is the 3 line
this is the 4 line
this is the 5 line
this is the 6 line
this is the 7 line
this is the 8 line
this is the 9 line
this is the 10 line
this is the 11 line
this is the 12 line
this is the 13 line
this is the 14 line
this is the 15 line
this is the 16 line
this is the 17 line
this is the 18 line
this is the 19 line
this is the 20 line
this is the 21 line
this is the 22 line
this is the 23 line
this is the 24 line
this is the 25 line
this is the 26 line
this is the 27 line
this is the 28 line
this is the 29 line
  per_cpu_thread-81    [000] d..1    26.555753: log_store: msg->text_len 589

4. Write a user mode programs with buffer size 2MB, triple size bigger
than the text length in msg we saved in above #2, and repeatedly
calling SYSLOG_ACTION_READ for getting the log.
Then the log we got will _NOT_ show over than "this is the 26 line" as
below, that mean line#27 ~ line#29 are missing.
(the source is attached as "simple_log.tar.bz2")
<4>[   39.467710] this is the 0 line
<4>[   39.467710] this is the 1 line
<4>[   39.467710] this is the 2 line
<4>[   39.467710] this is the 3 line
<4>[   39.467710] this is the 4 line
<4>[   39.467710] this is the 5 line
<4>[   39.467710] this is the 6 line
<4>[   39.467710] this is the 7 line
<4>[   39.467710] this is the 8 line
<4>[   39.467710] this is the 9 line
<4>[   39.467710] this is the 10 line
<4>[   39.467710] this is the 11 line
<4>[   39.467710] this is the 12 line
<4>[   39.467710] this is the 13 line
<4>[   39.467710] this is the 14 line
<4>[   39.467710] this is the 15 line
<4>[   39.467710] this is the 16 line
<4>[   39.467710] this is the 17 line
<4>[   39.467710] this is the 18 line
<4>[   39.467710] this is the 19 line
<4>[   39.467710] this is the 20 line
<4>[   39.467710] this is the 21 line
<4>[   39.467710] this is the 22 line
<4>[   39.467710] this is the 23 line
<4>[   39.467710] this is the 24 line
<4>[   39.467710] this is the 25 line
<4>[   39.467710] this is the 26 line

Attachment: simple_log.tar.bz2
Description: BZip2 compressed data