[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <02b4ce85-c1e5-6601-e3a7-cecfbd5298dc@i-love.sakura.ne.jp>
Date: Fri, 30 Nov 2018 23:33:39 +0900
From: Tetsuo Handa <penguin-kernel@...ove.sakura.ne.jp>
To: Petr Mladek <pmladek@...e.com>
Cc: Sergey Senozhatsky <sergey.senozhatsky@...il.com>,
Steven Rostedt <rostedt@...dmis.org>,
linux-kernel@...r.kernel.org
Subject: Re: [PATCH] printk: don't unconditionally shortcut print_time()
On 2018/11/30 21:30, Petr Mladek wrote:
> I am not fully happy with the solution passing time parameter.
> It is less secure. But it would not break compatibility.
> This particular race might be solved the following way:
>
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 1b2a029360b7..5b489988e9b7 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -1294,6 +1294,7 @@ static size_t msg_print_text(const struct printk_log *msg, bool syslog, char *bu
>
> static int syslog_print(char __user *buf, int size)
> {
> + static bool time;
> char *text;
> struct printk_log *msg;
> int len = 0;
> @@ -1318,9 +1319,13 @@ static int syslog_print(char __user *buf, int size)
> break;
> }
>
> + /* Keep partial line consistent */
> + if (!syslog_partial)
> + time = printk_time;
> +
> skip = syslog_partial;
> msg = log_from_idx(syslog_idx);
> - n = msg_print_text(msg, true, text, LOG_LINE_MAX + PREFIX_MAX);
> + n = msg_print_text(msg, true, time, text, LOG_LINE_MAX + PREFIX_MAX);
> if (n - syslog_partial <= size) {
OK. This should avoid making "n < syslog_partial" true.
Running below test code on current linux.git reads garbage bytes
----------------------------------------
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <unistd.h>
#include <sys/klog.h>
#define SYSLOG_ACTION_READ 2
#define SYSLOG_ACTION_SIZE_UNREAD 9
int main(int argc, char *argv[])
{
static char buffer[1024];
int fd1 = open("/sys/module/printk/parameters/time", O_WRONLY);
int fd2 = open("/proc/sysrq-trigger", O_WRONLY);
int size;
write(fd1, "1\n", 2);
write(fd2, "h\n", 2);
while ((size = klogctl(SYSLOG_ACTION_SIZE_UNREAD, NULL, 0)) > 2)
klogctl(SYSLOG_ACTION_READ, buffer, (size > sizeof(buffer) ? sizeof(buffer) : size) - 1);
write(fd1, "0\n", 2);
klogctl(SYSLOG_ACTION_READ, buffer, sizeof(buffer));
return 0;
}
----------------------------------------
and (I can't find the reproducer but) sometimes crashes like
[ 451.988242] BUG: pagefault on kernel address 0xffff8881337fa000 in non-whitelisted uaccess
[ 451.990465] BUG: unable to handle kernel paging request at ffff8881337fa000
[ 451.992254] PGD 3602067 P4D 3602067 PUD 3605067 PMD 13ff65067 PTE 800ffffecc805060
[ 451.994066] Oops: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[ 451.995284] CPU: 0 PID: 8147 Comm: a.out Kdump: loaded Not tainted 4.20.0-rc4+ #537
[ 451.997268] Hardware name: VMware, Inc. VMware Virtual Platform/440BX Desktop Reference Platform, BIOS 6.00 05/19/2017
[ 451.999857] RIP: 0010:copy_user_generic_unrolled+0x54/0xc0
[ 452.001312] Code: 83 e2 3f c1 e9 06 74 4a 4c 8b 06 4c 8b 4e 08 4c 8b 56 10 4c 8b 5e 18 4c 89 07 4c 89 4f 08 4c 89 57 10 4c 89 5f 18 4c 8b 46 20 <4c> 8b 4e 28 4c 8b 56 30 4c 8b 5e 38 4c 89 47 20 4c 89 4f 28 4c 89
[ 452.006119] RSP: 0018:ffffc90002573e90 EFLAGS: 00010202
[ 452.007230] RAX: 0000000000701060 RBX: 0000000000100000 RCX: 0000000000002f02
[ 452.008792] RDX: 0000000000000000 RSI: ffff8881337f9fd4 RDI: 0000000000644fe0
[ 452.010399] RBP: 0000000000601060 R08: 8b494e7401000000 R09: 00000b88858b4900
[ 452.011916] R10: 0f02000000c980f6 R11: b4bb830000025d85 R12: ffff8881337b6054
[ 452.013351] R13: 0000000000601060 R14: ffff8881337b5fa8 R15: 00000000000000ac
[ 452.014807] FS: 00007fb3c9eec740(0000) GS:ffff88813b200000(0000) knlGS:0000000000000000
[ 452.016931] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 452.018234] CR2: ffff8881337fa000 CR3: 0000000139153002 CR4: 00000000001606f0
[ 452.020038] Call Trace:
[ 452.020708] _copy_to_user+0x56/0x70
[ 452.021580] do_syslog+0x47d/0x7b0
[ 452.022359] ? syscall_trace_enter+0x1c3/0x360
[ 452.023395] ? trace_hardirqs_on_thunk+0x1a/0x1c
[ 452.024438] ? lockdep_hardirqs_off+0x73/0xe0
[ 452.025433] __x64_sys_syslog+0x13/0x20
[ 452.026363] do_syscall_64+0x4f/0x1f0
[ 452.027235] entry_SYSCALL_64_after_hwframe+0x49/0xbe
> /* message fits into buffer, move forward */
> syslog_idx = log_next(syslog_idx);
But we need to make this "static bool time;" accessible from SYSLOG_ACTION_SIZE_UNREAD case
because syslog_partial subtraction assumes that msg_print_text() used printk_time value
as of syslog_print() updated syslog_partial.
while (seq < log_next_seq) {
struct printk_log *msg = log_from_idx(idx);
error += msg_print_text(msg, true, NULL, 0);
idx = log_next(idx);
seq++;
}
error -= syslog_partial;
So, we would use a global variable like below?
/*
* To keep partial line consistent, pass this value to msg_print_text()
* when accessing syslog_partial.
*/
static bool syslog_partial_printk_time;
Powered by blists - more mailing lists