Return-Path: <linux-kernel-owner@vger.kernel.org>
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S1751857AbdHACmw (ORCPT <rfc822;w@1wt.eu>);
        Mon, 31 Jul 2017 22:42:52 -0400
Received: from mail-pg0-f67.google.com ([74.125.83.67]:35271 "EHLO
        mail-pg0-f67.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
        with ESMTP id S1751809AbdHACmu (ORCPT
        <rfc822;linux-kernel@vger.kernel.org>);
        Mon, 31 Jul 2017 22:42:50 -0400
Date: Tue, 1 Aug 2017 11:43:03 +0900
From: Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>
To: pierre Kuo <vichy.kuo@gmail.com>
Cc: pmladek@suse.com, sergey.senozhatsky@gmail.com, rostedt@goodmis.org,
        linux-kernel@vger.kernel.org
Subject: Re: [RFC V2] printk: add warning while drop partial text in msg
Message-ID: <20170801024303.GA469@jagdpanzerIV.localdomain>
References: <1501421870-12042-1-git-send-email-vichy.kuo@gmail.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <1501421870-12042-1-git-send-email-vichy.kuo@gmail.com>
User-Agent: Mutt/1.8.3 (2017-05-23)
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org
Content-Length: 2590
Lines: 77

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