Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]
Groups > linux.kernel > #1700596 > unrolled thread
| Started by | Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> |
|---|---|
| First post | 2017-08-01 04:50 +0200 |
| Last post | 2017-08-10 19:00 +0200 |
| Articles | 3 — 2 participants |
Back to article view | Back to linux.kernel
This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by
below is the oldest one visible, not the original post.
Re: [RFC V2] printk: add warning while drop partial text in msg Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> - 2017-08-01 04:50 +0200
Re: [RFC V2] printk: add warning while drop partial text in msg pierre kuo <vichy.kuo@gmail.com> - 2017-08-10 18:30 +0200
Re: [RFC V2] printk: add warning while drop partial text in msg pierre kuo <vichy.kuo@gmail.com> - 2017-08-10 19:00 +0200
| From | Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com> |
|---|---|
| Date | 2017-08-01 04:50 +0200 |
| Subject | Re: [RFC V2] printk: add warning while drop partial text in msg |
| Message-ID | <u9vpU-5XY-5@gated-at.bofh.it> |
On (07/30/17 21:37), pierre Kuo wrote:
> If the buffer pass to msg_print_text is not big enough to put both all
> prefixes and log_text(msg), kernel will quietly break.
> That means the user may not have the chance to know whether the
> log_text(msg) is fully printed into buffer or not.
>
> In this patch, once above case happened, we try to calculate how many
> characters of log_text(msg) are dropped and add warning for debugging
> purpose.
[..]
Hello,
this is not the only place that can truncate the message.
vprintk_emit() can do so as well /* vscnprintf() */. but
I think we don't care that much. a user likely will notice
truncated messages. we report lost messages, because this
is a completely different sort of problem.
[..]
> @@ -1264,8 +1270,23 @@ static size_t msg_print_text(const struct printk_log *msg, bool syslog, char *bu
>
> if (buf) {
> if (print_prefix(msg, syslog, NULL) +
> - text_len + 1 >= size - len)
> + text_len + 1 >= size - len) {
> + /* below stores dropped characters
> + * related information in next msg
> + */
> + size_t drop_len;
> +
> + drop_len = scnprintf(drop_msg,
> + MAX_DROP_MSG_LENGTH,
> + "<%u characters dropped>",
> + (next) ?
> + (unsigned int)(text_size + next - text) :
> + (unsigned int)text_size);
> + drop_msg[drop_len] = 0;
> + log_store(msg->facility, msg->level, msg->flags,
> + 0, NULL, 0, drop_msg, strlen(drop_msg));
> break;
> + }
this change, most likely, will confuse people. because msg_print_text() is
called on a message that is being currently processed, which is not
necessarily the last message in the logbuf. for example, see console_unlock().
we do something like this:
while (console_seq != log_next_seq) {
msg = log_from_idx(console_idx);
msg_print_text(msg);
console_idx = log_next(console_idx);
console_seq++;
}
your log_store(), invoked from msg_print_text(), will append the error
message to the logbuf (tail), possibly far-far-far away from console_idx.
so your "characters dropped" warning will appear much later.
> len += print_prefix(msg, syslog, buf + len);
> memcpy(buf + len, text, text_len);
but more importantly, msg_print_text() is called from several places. and
can even be called from a user space, potentially triggering the same
"<characters dropped>" error log_store() over and over again, wiping out
the actually important kernel messages. which is
a) not nice
and
b) can be used to deliberately "hide" something really important.
so, no. sorry, I don't like this change.
-ss
[toc] | [next] | [standalone]
| From | pierre kuo <vichy.kuo@gmail.com> |
|---|---|
| Date | 2017-08-10 18:30 +0200 |
| Message-ID | <ucYvn-83r-9@gated-at.bofh.it> |
| In reply to | #1700596 |
hi Sergey
> this is not the only place that can truncate the message.
> vprintk_emit() can do so as well /* vscnprintf() */. but
> I think we don't care that much. a user likely will notice
> truncated messages. we report lost messages, because this
> is a completely different sort of problem.
Usually people will more easily find message truncated from semantics
by vscnprintf,
since it brute force truncate input message by the upper limit of output buffer.
In msg_print_text, it use memchr to find "\n" as copying unit while
memcping msg->text to output buffer.
People will more difficultly to find out some part of message is left behind.
That is the reason I try to add such warning in msg_print_text.
>
>
> [..]
>> @@ -1264,8 +1270,23 @@ static size_t msg_print_text(const struct printk_log *msg, bool syslog, char *bu
>>
>> if (buf) {
>> if (print_prefix(msg, syslog, NULL) +
>> - text_len + 1 >= size - len)
>> + text_len + 1 >= size - len) {
>> + /* below stores dropped characters
>> + * related information in next msg
>> + */
>> + size_t drop_len;
>> +
>> + drop_len = scnprintf(drop_msg,
>> + MAX_DROP_MSG_LENGTH,
>> + "<%u characters dropped>",
>> + (next) ?
>> + (unsigned int)(text_size + next - text) :
>> + (unsigned int)text_size);
>> + drop_msg[drop_len] = 0;
>> + log_store(msg->facility, msg->level, msg->flags,
>> + 0, NULL, 0, drop_msg, strlen(drop_msg));
>> break;
>> + }
>
> this change, most likely, will confuse people. because msg_print_text() is
> called on a message that is being currently processed, which is not
> necessarily the last message in the logbuf. for example, see console_unlock().
> we do something like this:
>
> while (console_seq != log_next_seq) {
> msg = log_from_idx(console_idx);
> msg_print_text(msg);
> console_idx = log_next(console_idx);
> console_seq++;
> }
>
> your log_store(), invoked from msg_print_text(), will append the error
> message to the logbuf (tail), possibly far-far-far away from console_idx.
> so your "characters dropped" warning will appear much later.
>
>
>> len += print_prefix(msg, syslog, buf + len);
>> memcpy(buf + len, text, text_len);
>
>
> but more importantly, msg_print_text() is called from several places. and
> can even be called from a user space, potentially triggering the same
> "<characters dropped>" error log_store() over and over again, wiping out
> the actually important kernel messages. which is
> a) not nice
> and
> b) can be used to deliberately "hide" something really important.
>
>
> so, no. sorry, I don't like this change.
>
> -ss
[toc] | [prev] | [next] | [standalone]
| From | pierre kuo <vichy.kuo@gmail.com> |
|---|---|
| Date | 2017-08-10 19:00 +0200 |
| Message-ID | <ucYYq-8ev-3@gated-at.bofh.it> |
| In reply to | #1708810 |
hi Sergey:
(Please ignore previous mail, I apologize for pressing send button too early :)
>> this is not the only place that can truncate the message.
>> vprintk_emit() can do so as well /* vscnprintf() */. but
>> I think we don't care that much. a user likely will notice
>> truncated messages. we report lost messages, because this
>> is a completely different sort of problem.
Usually people will more easily find message truncated from semantics
by vscnprintf, since it brute force truncate input message by the
upper limit of output buffer.
In msg_print_text, it use memchr to find "\n" as copying unit while
memcping msg->text to output buffer.
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.
> your log_store(), invoked from msg_print_text(), will append the error
> message to the logbuf (tail), possibly far-far-far away from console_idx.
> so your "characters dropped" warning will appear much later.
Got ur point and thanks for your advising.
>> len += print_prefix(msg, syslog, buf + len);
>> memcpy(buf + len, text, text_len);
>
>
> but more importantly, msg_print_text() is called from several places. and
> can even be called from a user space, potentially triggering the same
> "<characters dropped>" error log_store() over and over again, wiping out
> the actually important kernel messages. which is
> a) not nice
> and
> b) can be used to deliberately "hide" something really important.
>
how about we directly adding warning message in buffer instead of
log_store like below?
Appreciate your review and advising.
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fc47863..fcd1dd4 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -557,6 +557,7 @@ static u32 msg_used_size(u16 text_len, u16
dict_len, u32 *pad_len)
*/
#define MAX_LOG_TAKE_PART 4
static const char trunc_msg[] = "<truncated>";
+static const char drop_msg[] = "<dropped>";
static u32 truncate_msg(u16 *text_len, u16 *trunc_msg_len,
u16 *dict_len, u32 *pad_len)
@@ -1264,8 +1265,14 @@ static size_t msg_print_text(const struct
printk_log *msg, bool syslog, char *bu
if (buf) {
if (print_prefix(msg, syslog, NULL) +
- text_len + 1 >= size - len)
+ text_len + 1 >= size - len) {
+ /* below adding warning message
+ * related information into output buffer
+ */
+ if ((size - len) > strlen(drop_msg))
+ memcpy(buf + len, drop_msg,
strlen(drop_msg));
break;
+ }
len += print_prefix(msg, syslog, buf + len);
memcpy(buf + len, text, text_len);
[toc] | [prev] | [standalone]
Back to top | Article view | linux.kernel
csiph-web