printk.c 76.5 KB
Newer Older
Linus Torvalds's avatar
Linus Torvalds committed
1
2
3
4
5
6
7
8
9
10
11
12
/*
 *  linux/kernel/printk.c
 *
 *  Copyright (C) 1991, 1992  Linus Torvalds
 *
 * Modified to make sys_syslog() more flexible: added commands to
 * return the last 4k of kernel messages, regardless of whether
 * they've been read or not.  Added option to suppress kernel printk's
 * to the console.  Added hook for sending the console messages
 * elsewhere, in preparation for a serial line console (someday).
 * Ted Ts'o, 2/11/93.
 * Modified for sysctl support, 1/8/97, Chris Horn.
13
 * Fixed SMP synchronization, 08/08/99, Manfred Spraul
14
 *     manfred@colorfullife.com
Linus Torvalds's avatar
Linus Torvalds committed
15
 * Rewrote bits to get rid of console_lock
16
 *	01Mar01 Andrew Morton
Linus Torvalds's avatar
Linus Torvalds committed
17
18
19
20
21
22
23
24
 */

#include <linux/kernel.h>
#include <linux/mm.h>
#include <linux/tty.h>
#include <linux/tty_driver.h>
#include <linux/console.h>
#include <linux/init.h>
Randy Dunlap's avatar
Randy Dunlap committed
25
26
#include <linux/jiffies.h>
#include <linux/nmi.h>
Linus Torvalds's avatar
Linus Torvalds committed
27
#include <linux/module.h>
Jan Engelhardt's avatar
Jan Engelhardt committed
28
#include <linux/moduleparam.h>
Linus Torvalds's avatar
Linus Torvalds committed
29
30
31
32
33
#include <linux/interrupt.h>			/* For in_interrupt() */
#include <linux/delay.h>
#include <linux/smp.h>
#include <linux/security.h>
#include <linux/bootmem.h>
34
#include <linux/memblock.h>
Linus Torvalds's avatar
Linus Torvalds committed
35
#include <linux/syscalls.h>
36
#include <linux/kexec.h>
37
#include <linux/kdb.h>
38
#include <linux/ratelimit.h>
39
#include <linux/kmsg_dump.h>
40
#include <linux/syslog.h>
41
42
#include <linux/cpu.h>
#include <linux/notifier.h>
43
#include <linux/rculist.h>
44
#include <linux/poll.h>
45
#include <linux/irq_work.h>
46
#include <linux/utsname.h>
Alex Elder's avatar
Alex Elder committed
47
#include <linux/ctype.h>
48
#include <linux/uio.h>
Linus Torvalds's avatar
Linus Torvalds committed
49
50
51

#include <asm/uaccess.h>

52
53
54
#define CREATE_TRACE_POINTS
#include <trace/events/printk.h>

Joe Perches's avatar
Joe Perches committed
55
#include "console_cmdline.h"
56
#include "braille.h"
Joe Perches's avatar
Joe Perches committed
57

Linus Torvalds's avatar
Linus Torvalds committed
58
int console_printk[4] = {
59
	CONSOLE_LOGLEVEL_DEFAULT,	/* console_loglevel */
60
	MESSAGE_LOGLEVEL_DEFAULT,	/* default_message_loglevel */
61
62
	CONSOLE_LOGLEVEL_MIN,		/* minimum_console_loglevel */
	CONSOLE_LOGLEVEL_DEFAULT,	/* default_console_loglevel */
Linus Torvalds's avatar
Linus Torvalds committed
63
64
65
};

/*
66
 * Low level drivers may need that to know if they can schedule in
Linus Torvalds's avatar
Linus Torvalds committed
67
68
69
70
71
72
73
74
75
76
 * their unblank() callback or not. So let's export it.
 */
int oops_in_progress;
EXPORT_SYMBOL(oops_in_progress);

/*
 * console_sem protects the console_drivers list, and also
 * provides serialisation for access to the entire console
 * driver system.
 */
77
static DEFINE_SEMAPHORE(console_sem);
Linus Torvalds's avatar
Linus Torvalds committed
78
struct console *console_drivers;
Ingo Molnar's avatar
Ingo Molnar committed
79
80
EXPORT_SYMBOL_GPL(console_drivers);

81
82
83
84
85
86
#ifdef CONFIG_LOCKDEP
static struct lockdep_map console_lock_dep_map = {
	.name = "console_lock"
};
#endif

87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
/*
 * Helper macros to handle lockdep when locking/unlocking console_sem. We use
 * macros instead of functions so that _RET_IP_ contains useful information.
 */
#define down_console_sem() do { \
	down(&console_sem);\
	mutex_acquire(&console_lock_dep_map, 0, 0, _RET_IP_);\
} while (0)

static int __down_trylock_console_sem(unsigned long ip)
{
	if (down_trylock(&console_sem))
		return 1;
	mutex_acquire(&console_lock_dep_map, 0, 1, ip);
	return 0;
}
#define down_trylock_console_sem() __down_trylock_console_sem(_RET_IP_)

#define up_console_sem() do { \
	mutex_release(&console_lock_dep_map, 1, _RET_IP_);\
	up(&console_sem);\
} while (0)

Linus Torvalds's avatar
Linus Torvalds committed
110
111
112
113
/*
 * This is used for debugging the mess that is the VT code by
 * keeping track if we have the console semaphore held. It's
 * definitely not the perfect debug tool (we don't know if _WE_
Alex Elder's avatar
Alex Elder committed
114
115
116
 * hold it and are racing, but it helps tracking those weird code
 * paths in the console code where we end up in places I want
 * locked without the console sempahore held).
Linus Torvalds's avatar
Linus Torvalds committed
117
 */
118
static int console_locked, console_suspended;
Linus Torvalds's avatar
Linus Torvalds committed
119

120
121
122
123
124
/*
 * If exclusive_console is non-NULL then only this console is to be printed to.
 */
static struct console *exclusive_console;

Linus Torvalds's avatar
Linus Torvalds committed
125
126
127
128
129
130
131
/*
 *	Array of consoles built from command line options (console=)
 */

#define MAX_CMDLINECONSOLES 8

static struct console_cmdline console_cmdline[MAX_CMDLINECONSOLES];
Joe Perches's avatar
Joe Perches committed
132

Linus Torvalds's avatar
Linus Torvalds committed
133
134
static int selected_console = -1;
static int preferred_console = -1;
135
136
int console_set_on_cmdline;
EXPORT_SYMBOL(console_set_on_cmdline);
Linus Torvalds's avatar
Linus Torvalds committed
137
138
139
140

/* Flag: console code may call schedule() */
static int console_may_schedule;

141
142
143
144
145
146
/*
 * The printk log buffer consists of a chain of concatenated variable
 * length records. Every record starts with a record header, containing
 * the overall length of the record.
 *
 * The heads to the first and last entry in the buffer, as well as the
Alex Elder's avatar
Alex Elder committed
147
148
 * sequence numbers of these entries are maintained when messages are
 * stored.
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
 *
 * If the heads indicate available messages, the length in the header
 * tells the start next message. A length == 0 for the next message
 * indicates a wrap-around to the beginning of the buffer.
 *
 * Every record carries the monotonic timestamp in microseconds, as well as
 * the standard userspace syslog level and syslog facility. The usual
 * kernel messages use LOG_KERN; userspace-injected messages always carry
 * a matching syslog facility, by default LOG_USER. The origin of every
 * message can be reliably determined that way.
 *
 * The human readable log message directly follows the message header. The
 * length of the message text is stored in the header, the stored message
 * is not terminated.
 *
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
 * Optionally, a message can carry a dictionary of properties (key/value pairs),
 * to provide userspace with a machine-readable message context.
 *
 * Examples for well-defined, commonly used property names are:
 *   DEVICE=b12:8               device identifier
 *                                b12:8         block dev_t
 *                                c127:3        char dev_t
 *                                n8            netdev ifindex
 *                                +sound:card0  subsystem:devname
 *   SUBSYSTEM=pci              driver-core subsystem name
 *
 * Valid characters in property names are [a-zA-Z0-9.-_]. The plain text value
 * follows directly after a '=' character. Every property is terminated by
 * a '\0' character. The last property is not terminated.
 *
 * Example of a message structure:
 *   0000  ff 8f 00 00 00 00 00 00      monotonic time in nsec
 *   0008  34 00                        record is 52 bytes long
 *   000a        0b 00                  text is 11 bytes long
 *   000c              1f 00            dictionary is 23 bytes long
 *   000e                    03 00      LOG_KERN (facility) LOG_ERR (level)
 *   0010  69 74 27 73 20 61 20 6c      "it's a l"
 *         69 6e 65                     "ine"
 *   001b           44 45 56 49 43      "DEVIC"
 *         45 3d 62 38 3a 32 00 44      "E=b8:2\0D"
 *         52 49 56 45 52 3d 62 75      "RIVER=bu"
 *         67                           "g"
 *   0032     00 00 00                  padding to next message header
 *
193
 * The 'struct printk_log' buffer header must never be directly exported to
194
195
196
197
198
199
200
201
202
203
204
205
 * userspace, it is a kernel-private implementation detail that might
 * need to be changed in the future, when the requirements change.
 *
 * /dev/kmsg exports the structured data in the following line format:
 *   "level,sequnum,timestamp;<message text>\n"
 *
 * The optional key/value pairs are attached as continuation lines starting
 * with a space character and terminated by a newline. All possible
 * non-prinatable characters are escaped in the "\xff" notation.
 *
 * Users of the export format should ignore possible additional values
 * separated by ',', and find the message after the ';' character.
206
207
 */

208
enum log_flags {
209
210
211
212
	LOG_NOCONS	= 1,	/* already flushed, do not print to console */
	LOG_NEWLINE	= 2,	/* text ended with a newline */
	LOG_PREFIX	= 4,	/* text started with a prefix */
	LOG_CONT	= 8,	/* text is a fragment of a continuation line */
213
214
};

215
struct printk_log {
216
217
218
219
	u64 ts_nsec;		/* timestamp in nanoseconds */
	u16 len;		/* length of entire record */
	u16 text_len;		/* length of text buffer */
	u16 dict_len;		/* length of dictionary buffer */
220
221
222
	u8 facility;		/* syslog facility */
	u8 flags:5;		/* internal record flags */
	u8 level:3;		/* syslog level */
223
224
225
};

/*
226
227
228
 * The logbuf_lock protects kmsg buffer, indices, counters.  This can be taken
 * within the scheduler's rq lock. It must be released before calling
 * console_unlock() or anything else that might wake up a process.
229
230
 */
static DEFINE_RAW_SPINLOCK(logbuf_lock);
231

232
#ifdef CONFIG_PRINTK
233
DECLARE_WAIT_QUEUE_HEAD(log_wait);
234
235
236
/* the next printk record to read by syslog(READ) or /proc/kmsg */
static u64 syslog_seq;
static u32 syslog_idx;
237
static enum log_flags syslog_prev;
238
static size_t syslog_partial;
239
240
241
242
243
244
245
246
247

/* index and sequence number of the first record stored in the buffer */
static u64 log_first_seq;
static u32 log_first_idx;

/* index and sequence number of the next record to store in the buffer */
static u64 log_next_seq;
static u32 log_next_idx;

248
249
250
251
252
/* the next printk record to write to the console */
static u64 console_seq;
static u32 console_idx;
static enum log_flags console_prev;

253
254
255
256
/* the next printk record to read after the last 'clear' command */
static u64 clear_seq;
static u32 clear_idx;

257
#define PREFIX_MAX		32
Alex Elder's avatar
Alex Elder committed
258
#define LOG_LINE_MAX		(1024 - PREFIX_MAX)
259
260

/* record buffer */
261
#if defined(CONFIG_HAVE_EFFICIENT_UNALIGNED_ACCESS)
262
263
#define LOG_ALIGN 4
#else
264
#define LOG_ALIGN __alignof__(struct printk_log)
265
#endif
266
#define __LOG_BUF_LEN (1 << CONFIG_LOG_BUF_SHIFT)
267
static char __log_buf[__LOG_BUF_LEN] __aligned(LOG_ALIGN);
268
269
270
static char *log_buf = __log_buf;
static u32 log_buf_len = __LOG_BUF_LEN;

271
272
273
274
275
276
277
278
279
280
281
282
/* Return log buffer address */
char *log_buf_addr_get(void)
{
	return log_buf;
}

/* Return log buffer size */
u32 log_buf_len_get(void)
{
	return log_buf_len;
}

283
/* human readable text of the record */
284
static char *log_text(const struct printk_log *msg)
285
{
286
	return (char *)msg + sizeof(struct printk_log);
287
288
289
}

/* optional key/value pair dictionary attached to the record */
290
static char *log_dict(const struct printk_log *msg)
291
{
292
	return (char *)msg + sizeof(struct printk_log) + msg->text_len;
293
294
295
}

/* get record by index; idx must point to valid msg */
296
static struct printk_log *log_from_idx(u32 idx)
297
{
298
	struct printk_log *msg = (struct printk_log *)(log_buf + idx);
299
300
301
302
303
304

	/*
	 * A length == 0 record is the end of buffer marker. Wrap around and
	 * read the message at the start of the buffer.
	 */
	if (!msg->len)
305
		return (struct printk_log *)log_buf;
306
307
308
309
310
311
	return msg;
}

/* get next record; idx must point to valid msg */
static u32 log_next(u32 idx)
{
312
	struct printk_log *msg = (struct printk_log *)(log_buf + idx);
313
314
315
316
317
318
319
320

	/* length == 0 indicates the end of the buffer; wrap */
	/*
	 * A length == 0 record is the end of buffer marker. Wrap around and
	 * read the message at the start of the buffer as *this* one, and
	 * return the one after that.
	 */
	if (!msg->len) {
321
		msg = (struct printk_log *)log_buf;
322
323
324
325
326
		return msg->len;
	}
	return idx + msg->len;
}

Petr Mladek's avatar
Petr Mladek committed
327
328
329
330
331
332
333
334
335
336
/*
 * Check whether there is enough free space for the given message.
 *
 * The same values of first_idx and next_idx mean that the buffer
 * is either empty or full.
 *
 * If the buffer is empty, we must respect the position of the indexes.
 * They cannot be reset to the beginning of the buffer.
 */
static int logbuf_has_space(u32 msg_size, bool empty)
337
338
339
{
	u32 free;

Petr Mladek's avatar
Petr Mladek committed
340
	if (log_next_idx > log_first_idx || empty)
341
342
343
344
345
346
347
348
349
350
351
		free = max(log_buf_len - log_next_idx, log_first_idx);
	else
		free = log_first_idx - log_next_idx;

	/*
	 * We need space also for an empty header that signalizes wrapping
	 * of the buffer.
	 */
	return free >= msg_size + sizeof(struct printk_log);
}

Petr Mladek's avatar
Petr Mladek committed
352
static int log_make_free_space(u32 msg_size)
353
354
{
	while (log_first_seq < log_next_seq) {
Petr Mladek's avatar
Petr Mladek committed
355
356
		if (logbuf_has_space(msg_size, false))
			return 0;
Alex Elder's avatar
Alex Elder committed
357
		/* drop old messages until we have enough contiguous space */
358
359
360
		log_first_idx = log_next(log_first_idx);
		log_first_seq++;
	}
Petr Mladek's avatar
Petr Mladek committed
361
362
363
364
365
366

	/* sequence numbers are equal, so the log buffer is empty */
	if (logbuf_has_space(msg_size, true))
		return 0;

	return -ENOMEM;
367
368
}

369
370
371
372
373
374
375
376
377
378
379
380
/* compute the message size including the padding bytes */
static u32 msg_used_size(u16 text_len, u16 dict_len, u32 *pad_len)
{
	u32 size;

	size = sizeof(struct printk_log) + text_len + dict_len;
	*pad_len = (-size) & (LOG_ALIGN - 1);
	size += *pad_len;

	return size;
}

Petr Mladek's avatar
Petr Mladek committed
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
/*
 * Define how much of the log buffer we could take at maximum. The value
 * must be greater than two. Note that only half of the buffer is available
 * when the index points to the middle.
 */
#define MAX_LOG_TAKE_PART 4
static const char trunc_msg[] = "<truncated>";

static u32 truncate_msg(u16 *text_len, u16 *trunc_msg_len,
			u16 *dict_len, u32 *pad_len)
{
	/*
	 * The message should not take the whole buffer. Otherwise, it might
	 * get removed too soon.
	 */
	u32 max_text_len = log_buf_len / MAX_LOG_TAKE_PART;
	if (*text_len > max_text_len)
		*text_len = max_text_len;
	/* enable the warning message */
	*trunc_msg_len = strlen(trunc_msg);
	/* disable the "dict" completely */
	*dict_len = 0;
	/* compute the size again, count also the warning message */
	return msg_used_size(*text_len + *trunc_msg_len, 0, pad_len);
}

407
/* insert record into the buffer, discard old ones, update heads */
408
409
410
411
static int log_store(int facility, int level,
		     enum log_flags flags, u64 ts_nsec,
		     const char *dict, u16 dict_len,
		     const char *text, u16 text_len)
412
{
413
	struct printk_log *msg;
414
	u32 size, pad_len;
Petr Mladek's avatar
Petr Mladek committed
415
	u16 trunc_msg_len = 0;
416
417

	/* number of '\0' padding bytes to next message */
418
	size = msg_used_size(text_len, dict_len, &pad_len);
419

Petr Mladek's avatar
Petr Mladek committed
420
421
422
423
424
425
	if (log_make_free_space(size)) {
		/* truncate the message if it is too long for empty buffer */
		size = truncate_msg(&text_len, &trunc_msg_len,
				    &dict_len, &pad_len);
		/* survive when the log buffer is too small for trunc_msg */
		if (log_make_free_space(size))
426
			return 0;
Petr Mladek's avatar
Petr Mladek committed
427
	}
428

429
	if (log_next_idx + size + sizeof(struct printk_log) > log_buf_len) {
430
431
432
433
434
		/*
		 * This message + an additional empty header does not fit
		 * at the end of the buffer. Add an empty header with len == 0
		 * to signify a wrap around.
		 */
435
		memset(log_buf + log_next_idx, 0, sizeof(struct printk_log));
436
437
438
439
		log_next_idx = 0;
	}

	/* fill message */
440
	msg = (struct printk_log *)(log_buf + log_next_idx);
441
442
	memcpy(log_text(msg), text, text_len);
	msg->text_len = text_len;
Petr Mladek's avatar
Petr Mladek committed
443
444
445
446
	if (trunc_msg_len) {
		memcpy(log_text(msg) + text_len, trunc_msg, trunc_msg_len);
		msg->text_len += trunc_msg_len;
	}
447
448
	memcpy(log_dict(msg), dict, dict_len);
	msg->dict_len = dict_len;
449
450
451
452
453
454
455
	msg->facility = facility;
	msg->level = level & 7;
	msg->flags = flags & 0x1f;
	if (ts_nsec > 0)
		msg->ts_nsec = ts_nsec;
	else
		msg->ts_nsec = local_clock();
456
	memset(log_dict(msg) + dict_len, 0, pad_len);
457
	msg->len = size;
458
459
460
461

	/* insert message */
	log_next_idx += msg->len;
	log_next_seq++;
462
463

	return msg->text_len;
464
}
465

Alex Elder's avatar
Alex Elder committed
466
int dmesg_restrict = IS_ENABLED(CONFIG_SECURITY_DMESG_RESTRICT);
467
468
469
470
471
472
473
474
475
476
477
478
479

static int syslog_action_restricted(int type)
{
	if (dmesg_restrict)
		return 1;
	/*
	 * Unless restricted, we allow "read all" and "get buffer size"
	 * for everybody.
	 */
	return type != SYSLOG_ACTION_READ_ALL &&
	       type != SYSLOG_ACTION_SIZE_BUFFER;
}

480
int check_syslog_permissions(int type, bool from_file)
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
502
503
504
505
506
507
{
	/*
	 * If this is from /proc/kmsg and we've already opened it, then we've
	 * already done the capabilities checks at open time.
	 */
	if (from_file && type != SYSLOG_ACTION_OPEN)
		return 0;

	if (syslog_action_restricted(type)) {
		if (capable(CAP_SYSLOG))
			return 0;
		/*
		 * For historical reasons, accept CAP_SYS_ADMIN too, with
		 * a warning.
		 */
		if (capable(CAP_SYS_ADMIN)) {
			pr_warn_once("%s (%d): Attempt to access syslog with "
				     "CAP_SYS_ADMIN but no CAP_SYSLOG "
				     "(deprecated).\n",
				 current->comm, task_pid_nr(current));
			return 0;
		}
		return -EPERM;
	}
	return security_syslog(type);
}

508
509
510
511
512
static void append_char(char **pp, char *e, char c)
{
	if (*pp < e)
		*(*pp)++ = c;
}
513

514
515
516
517
/* /dev/kmsg - userspace message inject/listen interface */
struct devkmsg_user {
	u64 seq;
	u32 idx;
518
	enum log_flags prev;
519
	struct mutex lock;
520
	char buf[CONSOLE_EXT_LOG_MAX];
521
522
};

Al Viro's avatar
Al Viro committed
523
static ssize_t devkmsg_write(struct kiocb *iocb, struct iov_iter *from)
524
525
526
527
528
{
	char *buf, *line;
	int i;
	int level = default_message_loglevel;
	int facility = 1;	/* LOG_USER */
Christoph Hellwig's avatar
Christoph Hellwig committed
529
	size_t len = iov_iter_count(from);
530
531
532
533
534
535
536
537
	ssize_t ret = len;

	if (len > LOG_LINE_MAX)
		return -EINVAL;
	buf = kmalloc(len+1, GFP_KERNEL);
	if (buf == NULL)
		return -ENOMEM;

Al Viro's avatar
Al Viro committed
538
539
540
541
	buf[len] = '\0';
	if (copy_from_iter(buf, len, from) != len) {
		kfree(buf);
		return -EFAULT;
542
543
544
545
546
547
548
549
550
551
552
553
554
555
556
557
558
559
560
561
562
563
564
565
566
567
568
569
570
571
572
573
574
575
576
	}

	/*
	 * Extract and skip the syslog prefix <[0-9]*>. Coming from userspace
	 * the decimal value represents 32bit, the lower 3 bit are the log
	 * level, the rest are the log facility.
	 *
	 * If no prefix or no userspace facility is specified, we
	 * enforce LOG_USER, to be able to reliably distinguish
	 * kernel-generated messages from userspace-injected ones.
	 */
	line = buf;
	if (line[0] == '<') {
		char *endp = NULL;

		i = simple_strtoul(line+1, &endp, 10);
		if (endp && endp[0] == '>') {
			level = i & 7;
			if (i >> 3)
				facility = i >> 3;
			endp++;
			len -= endp - line;
			line = endp;
		}
	}

	printk_emit(facility, level, NULL, 0, "%s", line);
	kfree(buf);
	return ret;
}

static ssize_t devkmsg_read(struct file *file, char __user *buf,
			    size_t count, loff_t *ppos)
{
	struct devkmsg_user *user = file->private_data;
577
	struct printk_log *msg;
578
	char *p, *e;
579
	u64 ts_usec;
580
	size_t i;
581
	char cont = '-';
582
583
584
585
586
587
	size_t len;
	ssize_t ret;

	if (!user)
		return -EBADF;

588
589
590
	p = user->buf;
	e = user->buf + sizeof(user->buf);

591
592
593
	ret = mutex_lock_interruptible(&user->lock);
	if (ret)
		return ret;
594
	raw_spin_lock_irq(&logbuf_lock);
595
596
597
	while (user->seq == log_next_seq) {
		if (file->f_flags & O_NONBLOCK) {
			ret = -EAGAIN;
598
			raw_spin_unlock_irq(&logbuf_lock);
599
600
601
			goto out;
		}

602
		raw_spin_unlock_irq(&logbuf_lock);
603
604
605
606
		ret = wait_event_interruptible(log_wait,
					       user->seq != log_next_seq);
		if (ret)
			goto out;
607
		raw_spin_lock_irq(&logbuf_lock);
608
609
610
611
612
613
614
	}

	if (user->seq < log_first_seq) {
		/* our last seen message is gone, return error and reset */
		user->idx = log_first_idx;
		user->seq = log_first_seq;
		ret = -EPIPE;
615
		raw_spin_unlock_irq(&logbuf_lock);
616
617
618
619
		goto out;
	}

	msg = log_from_idx(user->idx);
620
621
	ts_usec = msg->ts_nsec;
	do_div(ts_usec, 1000);
622
623
624
625
626
627
628
629
630
631
632
633
634
635
636

	/*
	 * If we couldn't merge continuation line fragments during the print,
	 * export the stored flags to allow an optional external merge of the
	 * records. Merging the records isn't always neccessarily correct, like
	 * when we hit a race during printing. In most cases though, it produces
	 * better readable output. 'c' in the record flags mark the first
	 * fragment of a line, '+' the following.
	 */
	if (msg->flags & LOG_CONT && !(user->prev & LOG_CONT))
		cont = 'c';
	else if ((msg->flags & LOG_CONT) ||
		 ((user->prev & LOG_CONT) && !(msg->flags & LOG_PREFIX)))
		cont = '+';

637
638
639
	p += scnprintf(p, e - p, "%u,%llu,%llu,%c;",
		       (msg->facility << 3) | msg->level,
		       user->seq, ts_usec, cont);
640
	user->prev = msg->flags;
641
642
643

	/* escape non-printable characters */
	for (i = 0; i < msg->text_len; i++) {
644
		unsigned char c = log_text(msg)[i];
645

646
		if (c < ' ' || c >= 127 || c == '\\')
647
			p += scnprintf(p, e - p, "\\x%02x", c);
648
		else
649
			append_char(&p, e, c);
650
	}
651
	append_char(&p, e, '\n');
652
653
654
655
656

	if (msg->dict_len) {
		bool line = true;

		for (i = 0; i < msg->dict_len; i++) {
657
			unsigned char c = log_dict(msg)[i];
658
659

			if (line) {
660
				append_char(&p, e, ' ');
661
662
663
664
				line = false;
			}

			if (c == '\0') {
665
				append_char(&p, e, '\n');
666
667
668
669
				line = true;
				continue;
			}

670
			if (c < ' ' || c >= 127 || c == '\\') {
671
				p += scnprintf(p, e - p, "\\x%02x", c);
672
673
674
				continue;
			}

675
			append_char(&p, e, c);
676
		}
677
		append_char(&p, e, '\n');
678
679
680
681
	}

	user->idx = log_next(user->idx);
	user->seq++;
682
	raw_spin_unlock_irq(&logbuf_lock);
683

684
	len = p - user->buf;
685
686
687
688
689
690
691
692
693
694
695
696
697
698
699
700
701
702
703
704
705
706
707
708
709
	if (len > count) {
		ret = -EINVAL;
		goto out;
	}

	if (copy_to_user(buf, user->buf, len)) {
		ret = -EFAULT;
		goto out;
	}
	ret = len;
out:
	mutex_unlock(&user->lock);
	return ret;
}

static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence)
{
	struct devkmsg_user *user = file->private_data;
	loff_t ret = 0;

	if (!user)
		return -EBADF;
	if (offset)
		return -ESPIPE;

710
	raw_spin_lock_irq(&logbuf_lock);
711
712
713
714
715
716
717
718
719
720
721
722
723
724
725
726
727
728
729
730
731
732
733
	switch (whence) {
	case SEEK_SET:
		/* the first record */
		user->idx = log_first_idx;
		user->seq = log_first_seq;
		break;
	case SEEK_DATA:
		/*
		 * The first record after the last SYSLOG_ACTION_CLEAR,
		 * like issued by 'dmesg -c'. Reading /dev/kmsg itself
		 * changes no global state, and does not clear anything.
		 */
		user->idx = clear_idx;
		user->seq = clear_seq;
		break;
	case SEEK_END:
		/* after the last record */
		user->idx = log_next_idx;
		user->seq = log_next_seq;
		break;
	default:
		ret = -EINVAL;
	}
734
	raw_spin_unlock_irq(&logbuf_lock);
735
736
737
738
739
740
741
742
743
744
745
746
747
	return ret;
}

static unsigned int devkmsg_poll(struct file *file, poll_table *wait)
{
	struct devkmsg_user *user = file->private_data;
	int ret = 0;

	if (!user)
		return POLLERR|POLLNVAL;

	poll_wait(file, &log_wait, wait);

748
	raw_spin_lock_irq(&logbuf_lock);
749
750
751
752
	if (user->seq < log_next_seq) {
		/* return error when data has vanished underneath us */
		if (user->seq < log_first_seq)
			ret = POLLIN|POLLRDNORM|POLLERR|POLLPRI;
753
754
		else
			ret = POLLIN|POLLRDNORM;
755
	}
756
	raw_spin_unlock_irq(&logbuf_lock);
757
758
759
760
761
762
763
764
765
766
767
768
769

	return ret;
}

static int devkmsg_open(struct inode *inode, struct file *file)
{
	struct devkmsg_user *user;
	int err;

	/* write-only does not need any file context */
	if ((file->f_flags & O_ACCMODE) == O_WRONLY)
		return 0;

770
771
	err = check_syslog_permissions(SYSLOG_ACTION_READ_ALL,
				       SYSLOG_FROM_READER);
772
773
774
775
776
777
778
779
780
	if (err)
		return err;

	user = kmalloc(sizeof(struct devkmsg_user), GFP_KERNEL);
	if (!user)
		return -ENOMEM;

	mutex_init(&user->lock);

781
	raw_spin_lock_irq(&logbuf_lock);
782
783
	user->idx = log_first_idx;
	user->seq = log_first_seq;
784
	raw_spin_unlock_irq(&logbuf_lock);
785
786
787
788
789
790
791
792
793
794
795
796
797
798
799
800
801
802
803
804

	file->private_data = user;
	return 0;
}

static int devkmsg_release(struct inode *inode, struct file *file)
{
	struct devkmsg_user *user = file->private_data;

	if (!user)
		return 0;

	mutex_destroy(&user->lock);
	kfree(user);
	return 0;
}

const struct file_operations kmsg_fops = {
	.open = devkmsg_open,
	.read = devkmsg_read,
Al Viro's avatar
Al Viro committed
805
	.write_iter = devkmsg_write,
806
807
808
809
810
	.llseek = devkmsg_llseek,
	.poll = devkmsg_poll,
	.release = devkmsg_release,
};

811
812
#ifdef CONFIG_KEXEC
/*
813
 * This appends the listed symbols to /proc/vmcore
814
 *
815
 * /proc/vmcore is used by various utilities, like crash and makedumpfile to
816
817
818
819
820
821
822
823
 * obtain access to symbols that are otherwise very difficult to locate.  These
 * symbols are specifically used so that utilities can access and extract the
 * dmesg log from a vmcore file after a crash.
 */
void log_buf_kexec_setup(void)
{
	VMCOREINFO_SYMBOL(log_buf);
	VMCOREINFO_SYMBOL(log_buf_len);
824
825
	VMCOREINFO_SYMBOL(log_first_idx);
	VMCOREINFO_SYMBOL(log_next_idx);
826
	/*
827
	 * Export struct printk_log size and field offsets. User space tools can
828
829
	 * parse it and detect any changes to structure down the line.
	 */
830
831
832
833
834
	VMCOREINFO_STRUCT_SIZE(printk_log);
	VMCOREINFO_OFFSET(printk_log, ts_nsec);
	VMCOREINFO_OFFSET(printk_log, len);
	VMCOREINFO_OFFSET(printk_log, text_len);
	VMCOREINFO_OFFSET(printk_log, dict_len);
835
836
837
}
#endif

838
839
840
/* requested log_buf_len from kernel cmdline */
static unsigned long __initdata new_log_buf_len;

841
842
/* we practice scaling the ring buffer by powers of 2 */
static void __init log_buf_len_update(unsigned size)
Linus Torvalds's avatar
Linus Torvalds committed
843
844
845
{
	if (size)
		size = roundup_pow_of_two(size);
846
847
	if (size > log_buf_len)
		new_log_buf_len = size;
848
849
850
851
852
853
854
855
}

/* save requested log_buf_len since it's too early to process it */
static int __init log_buf_len_setup(char *str)
{
	unsigned size = memparse(str, &str);

	log_buf_len_update(size);
856
857

	return 0;
Linus Torvalds's avatar
Linus Torvalds committed
858
}
859
860
early_param("log_buf_len", log_buf_len_setup);

861
862
863
#ifdef CONFIG_SMP
#define __LOG_CPU_MAX_BUF_LEN (1 << CONFIG_LOG_CPU_MAX_BUF_SHIFT)

864
865
866
867
868
869
870
871
872
873
874
875
876
877
878
879
880
881
882
883
884
885
886
887
888
889
static void __init log_buf_add_cpu(void)
{
	unsigned int cpu_extra;

	/*
	 * archs should set up cpu_possible_bits properly with
	 * set_cpu_possible() after setup_arch() but just in
	 * case lets ensure this is valid.
	 */
	if (num_possible_cpus() == 1)
		return;

	cpu_extra = (num_possible_cpus() - 1) * __LOG_CPU_MAX_BUF_LEN;

	/* by default this will only continue through for large > 64 CPUs */
	if (cpu_extra <= __LOG_BUF_LEN / 2)
		return;

	pr_info("log_buf_len individual max cpu contribution: %d bytes\n",
		__LOG_CPU_MAX_BUF_LEN);
	pr_info("log_buf_len total cpu_extra contributions: %d bytes\n",
		cpu_extra);
	pr_info("log_buf_len min size: %d bytes\n", __LOG_BUF_LEN);

	log_buf_len_update(cpu_extra + __LOG_BUF_LEN);
}
890
891
892
#else /* !CONFIG_SMP */
static inline void log_buf_add_cpu(void) {}
#endif /* CONFIG_SMP */
893

894
895
896
897
898
899
void __init setup_log_buf(int early)
{
	unsigned long flags;
	char *new_log_buf;
	int free;

900
901
902
903
904
905
	if (log_buf != __log_buf)
		return;

	if (!early && !new_log_buf_len)
		log_buf_add_cpu();

906
907
	if (!new_log_buf_len)
		return;
Linus Torvalds's avatar
Linus Torvalds committed
908

909
	if (early) {
910
		new_log_buf =
911
			memblock_virt_alloc(new_log_buf_len, LOG_ALIGN);
912
	} else {
913
914
		new_log_buf = memblock_virt_alloc_nopanic(new_log_buf_len,
							  LOG_ALIGN);
915
916
917
918
919
920
921
922
	}

	if (unlikely(!new_log_buf)) {
		pr_err("log_buf_len: %ld bytes not available\n",
			new_log_buf_len);
		return;
	}

923
	raw_spin_lock_irqsave(&logbuf_lock, flags);
924
925
926
	log_buf_len = new_log_buf_len;
	log_buf = new_log_buf;
	new_log_buf_len = 0;
927
928
	free = __LOG_BUF_LEN - log_next_idx;
	memcpy(log_buf, __log_buf, __LOG_BUF_LEN);
929
	raw_spin_unlock_irqrestore(&logbuf_lock, flags);
930

931
	pr_info("log_buf_len: %d bytes\n", log_buf_len);
932
933
934
	pr_info("early log buf free: %d(%d%%)\n",
		free, (free * 100) / __LOG_BUF_LEN);
}
Linus Torvalds's avatar
Linus Torvalds committed
935

936
937
938
939
static bool __read_mostly ignore_loglevel;

static int __init ignore_loglevel_setup(char *str)
{
940
	ignore_loglevel = true;
941
	pr_info("debug: ignoring loglevel setting.\n");
942
943
944
945
946
947

	return 0;
}

early_param("ignore_loglevel", ignore_loglevel_setup);
module_param(ignore_loglevel, bool, S_IRUGO | S_IWUSR);
948
949
MODULE_PARM_DESC(ignore_loglevel,
		 "ignore loglevel setting (prints all kernel messages to the console)");
950

Randy Dunlap's avatar
Randy Dunlap committed
951
952
#ifdef CONFIG_BOOT_PRINTK_DELAY

953
static int boot_delay; /* msecs delay after each printk during bootup */
954
static unsigned long long loops_per_msec;	/* based on boot_delay */
Randy Dunlap's avatar
Randy Dunlap committed
955
956
957
958
959
960
961
962
963
964
965
966

static int __init boot_delay_setup(char *str)
{
	unsigned long lpj;

	lpj = preset_lpj ? preset_lpj : 1000000;	/* some guess */
	loops_per_msec = (unsigned long long)lpj / 1000 * HZ;

	get_option(&str, &boot_delay);
	if (boot_delay > 10 * 1000)
		boot_delay = 0;

967
968
969
	pr_debug("boot_delay: %u, preset_lpj: %ld, lpj: %lu, "
		"HZ: %d, loops_per_msec: %llu\n",
		boot_delay, preset_lpj, lpj, HZ, loops_per_msec);
970
	return 0;
Randy Dunlap's avatar
Randy Dunlap committed
971
}
972
early_param("boot_delay", boot_delay_setup);
Randy Dunlap's avatar
Randy Dunlap committed
973

974
static void boot_delay_msec(int level)
Randy Dunlap's avatar
Randy Dunlap committed
975
976
977
978
{
	unsigned long long k;
	unsigned long timeout;

979
980
	if ((boot_delay == 0 || system_state != SYSTEM_BOOTING)
		|| (level >= console_loglevel && !ignore_loglevel)) {
Randy Dunlap's avatar
Randy Dunlap committed
981
		return;
982
	}
Randy Dunlap's avatar
Randy Dunlap committed
983

984
	k = (unsigned long long)loops_per_msec * boot_delay;
Randy Dunlap's avatar
Randy Dunlap committed
985
986
987
988
989
990
991
992
993
994
995
996
997
998
999
1000

	timeout = jiffies + msecs_to_jiffies(boot_delay);
	while (k) {
		k--;
		cpu_relax();
		/*
		 * use (volatile) jiffies to prevent
		 * compiler reduction; loop termination via jiffies
		 * is secondary and may or may not happen.
		 */
		if (time_after(jiffies, timeout))
			break;
		touch_nmi_watchdog();
	}
}
#else
1001
static inline void boot_delay_msec(int level)
Randy Dunlap's avatar
Randy Dunlap committed
1002
1003
1004
1005
{
}
#endif

Alex Elder's avatar
Alex Elder committed
1006
static bool printk_time = IS_ENABLED(CONFIG_PRINTK_TIME);
1007
1008
module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);

1009
1010
1011
1012
1013
1014
1015
static size_t print_time(u64 ts, char *buf)
{
	unsigned long rem_nsec;

	if (!printk_time)
		return 0;

1016
1017
	rem_nsec = do_div(ts, 1000000000);

1018
	if (!buf)
1019
		return snprintf(NULL, 0, "[%5lu.000000] ", (unsigned long)ts);
1020
1021
1022
1023
1024

	return sprintf(buf, "[%5lu.%06lu] ",
		       (unsigned long)ts, rem_nsec / 1000);
}

1025
static size_t print_prefix(const struct printk_log *msg, bool syslog, char *buf)
1026
{
1027
	size_t len = 0;
1028
	unsigned int prefix = (msg->facility << 3) | msg->level;
1029

1030
1031
	if (syslog) {
		if (buf) {
1032
			len += sprintf(buf, "<%u>", prefix);
1033
1034
		} else {
			len += 3;
1035
1036
1037
1038
1039
			if (prefix > 999)
				len += 3;
			else if (prefix > 99)
				len += 2;
			else if (prefix > 9)
1040
1041
1042
				len++;
		}
	}
1043

1044
	len += print_time(msg->ts_nsec, buf ? buf + len : NULL);
1045
	return len;
1046
1047
}

1048
static size_t msg_print_text(const struct printk_log *msg, enum log_flags prev,
1049
			     bool syslog, char *buf, size_t size)
1050
{
1051
1052
	const char *text = log_text(msg);
	size_t text_size = msg->text_len;
1053
1054
	bool prefix = true;
	bool newline = true;
1055
1056
	size_t len = 0;

1057
1058
1059
1060
1061
1062
1063
1064
1065
1066
1067
	if ((prev & LOG_CONT) && !(msg->flags & LOG_PREFIX))
		prefix = false;

	if (msg->flags & LOG_CONT) {
		if ((prev & LOG_CONT) && !(prev & LOG_NEWLINE))
			prefix = false;

		if (!(msg->flags & LOG_NEWLINE))
			newline = false;
	}

1068
1069
1070
1071
1072
1073
1074
1075
1076
1077
1078
	do {
		const char *next = memchr(text, '\n', text_size);
		size_t text_len;

		if (next) {
			text_len = next - text;
			next++;
			text_size -= next - text;
		} else {
			text_len = text_size;
		}
1079

1080
1081
		if (buf) {
			if (print_prefix(msg, syslog, NULL) +
1082
			    text_len + 1 >= size - len)
1083
				break;
1084

1085
1086
			if (prefix)
				len += print_prefix(msg, syslog, buf + len);
1087
1088
			memcpy(buf + len, text, text_len);
			len += text_len;
1089
1090
			if (next || newline)
				buf[len++] = '\n';
1091
1092
		} else {
			/* SYSLOG_ACTION_* buffer size only calculation */
1093
1094
1095
1096
1097
			if (prefix)
				len += print_prefix(msg, syslog, NULL);
			len += text_len;
			if (next || newline)
				len++;
1098
		}
1099

1100
		prefix = true;
1101
1102
		text = next;
	} while (text);
1103
1104
1105
1106
1107
1108
1109

	return len;
}

static int syslog_print(char __user *buf, int size)
{
	char *text;
1110
	struct printk_log *msg;
1111
	int len = 0;
1112

1113
	text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
1114
1115
1116
	if (!text)
		return -ENOMEM;

1117
1118
	while (size > 0) {
		size_t n;
1119
		size_t skip;
1120
1121
1122
1123
1124
1125

		raw_spin_lock_irq(&logbuf_lock);
		if (syslog_seq < log_first_seq) {
			/* messages are gone, move to first one */
			syslog_seq = log_first_seq;
			syslog_idx = log_first_idx;
1126
			syslog_prev = 0;
1127
			syslog_partial = 0;
1128
1129
1130
1131
1132
		}
		if (syslog_seq == log_next_seq) {
			raw_spin_unlock_irq(&logbuf_lock);
			break;
		}
1133
1134

		skip = syslog_partial;
1135
		msg = log_from_idx(syslog_idx);
1136
1137
		n = msg_print_text(msg, syslog_prev, true, text,
				   LOG_LINE_MAX + PREFIX_MAX);
1138
1139
		if (n - syslog_partial <= size) {
			/* message fits into buffer, move forward */
1140
1141
			syslog_idx = log_next(syslog_idx);
			syslog_seq++;
1142
			syslog_prev = msg->flags;
1143
1144
1145
1146
1147
1148
			n -= syslog_partial;
			syslog_partial = 0;
		} else if (!len){
			/* partial read(), remember position */
			n = size;
			syslog_partial += n;
1149
1150
1151
1152
1153
1154
1155
		} else
			n = 0;
		raw_spin_unlock_irq(&logbuf_lock);

		if (!n)
			break;

1156
		if (copy_to_user(buf, text + skip, n)) {
1157
1158
1159
1160
			if (!len)
				len = -EFAULT;
			break;
		}
1161
1162
1163
1164

		len += n;
		size -= n;
		buf += n;
1165
1166
1167
1168
1169
1170
1171
1172
1173
1174
1175
	}

	kfree(text);
	return len;
}

static int syslog_print_all(char __user *buf, int size, bool clear)
{
	char *text;
	int len = 0;

1176
	text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
1177
1178
1179
1180
1181
1182
1183
1184
	if (!text)
		return -ENOMEM;

	raw_spin_lock_irq(&logbuf_lock);
	if (buf) {
		u64 next_seq;
		u64 seq;
		u32 idx;
1185
		enum log_flags prev;
1186
1187
1188
1189
1190
1191
1192
1193
1194
1195

		if (clear_seq < log_first_seq) {
			/* messages are gone, move to first available one */
			clear_seq = log_first_seq;
			clear_idx = log_first_idx;
		}

		/*
		 * Find first record that fits, including all following records,
		 * into the user-provided buffer for this dump.
1196
		 */
1197
1198
		seq = clear_seq;
		idx = clear_idx;
1199
		prev = 0;
1200
		while (seq < log_next_seq) {
1201
			struct printk_log *msg = log_from_idx(idx);
1202

1203
			len += msg_print_text(msg, prev, true, NULL, 0);
1204
			prev = msg->flags;
1205
1206
1207
			idx = log_next(idx);
			seq++;
		}
1208
1209

		/* move first record forward until length fits into the buffer */
1210
1211
		seq = clear_seq;
		idx = clear_idx;
1212
		prev = 0;
1213
		while (len > size && seq < log_next_seq) {
1214
			struct printk_log *msg = log_from_idx(idx);
1215

1216
			len -= msg_print_text(msg, prev, true, NULL, 0);
1217
			prev = msg->flags;
1218
1219
1220
1221
			idx = log_next(idx);
			seq++;
		}

1222
		/* last message fitting into this dump */
1223
1224
1225
1226
		next_seq = log_next_seq;

		len = 0;
		while (len >= 0 && seq < next_seq) {
1227
			struct printk_log *msg = log_from_idx(idx);
1228
1229
			int textlen;

1230
1231
			textlen = msg_print_text(msg, prev, true, text,
						 LOG_LINE_MAX + PREFIX_MAX);
1232
1233
1234
1235
1236
1237
			if (textlen < 0) {
				len = textlen;
				break;
			}
			idx = log_next(idx);
			seq++;
1238
			prev = msg->flags;
1239
1240
1241
1242
1243
1244
1245
1246
1247
1248
1249
1250

			raw_spin_unlock_irq(&logbuf_lock);
			if (copy_to_user(buf + len, text, textlen))
				len = -EFAULT;
			else
				len += textlen;
			raw_spin_lock_irq(&logbuf_lock);

			if (seq < log_first_seq) {
				/* messages are gone, move to next one */
				seq = log_first_seq;
				idx = log_first_idx;
1251
				prev = 0;
1252
1253
1254
1255
1256
1257
1258
1259
1260
1261
1262
1263
1264
1265
			}
		}
	}

	if (clear) {
		clear_seq = log_next_seq;
		clear_idx = log_next_idx;
	}
	raw_spin_unlock_irq(&logbuf_lock);

	kfree(text);
	return len;
}

1266
int do_syslog(int type, char __user *buf, int len, bool from_file)
Linus Torvalds's avatar
Linus Torvalds committed
1267
{
1268
	bool clear = false;
1269
	static int saved_console_loglevel = LOGLEVEL_DEFAULT;
1270
	int error;
Linus Torvalds's avatar
Linus Torvalds committed
1271

1272
1273
1274
	error = check_syslog_permissions(type, from_file);
	if (error)
		goto out;
1275
1276

	error = security_syslog(type);
Linus Torvalds's avatar
Linus Torvalds committed
1277
1278
1279
1280
	if (error)
		return error;

	switch (type) {
1281
	case SYSLOG_ACTION_CLOSE:	/* Close log */
Linus Torvalds's avatar
Linus Torvalds committed
1282
		break;
1283
	case SYSLOG_ACTION_OPEN:	/* Open log */
Linus Torvalds's avatar
Linus Torvalds committed
1284
		break;
1285
	case SYSLOG_ACTION_READ:	/* Read from log */
Linus Torvalds's avatar
Linus Torvalds committed
1286
1287
1288
1289
1290
1291
1292
1293
1294
1295
		error = -EINVAL;
		if (!buf || len < 0)
			goto out;
		error = 0;
		if (!len)
			goto out;
		if (!access_ok(VERIFY_WRITE, buf, len)) {
			error = -EFAULT;
			goto out;
		}
Jesper Juhl's avatar