| .. | .. |
|---|
| 44 | 44 | #include <linux/irq_work.h> |
|---|
| 45 | 45 | #include <linux/ctype.h> |
|---|
| 46 | 46 | #include <linux/uio.h> |
|---|
| 47 | | -#include <linux/kthread.h> |
|---|
| 48 | | -#include <linux/kdb.h> |
|---|
| 49 | | -#include <linux/clocksource.h> |
|---|
| 50 | 47 | #include <linux/sched/clock.h> |
|---|
| 51 | 48 | #include <linux/sched/debug.h> |
|---|
| 52 | 49 | #include <linux/sched/task_stack.h> |
|---|
| .. | .. |
|---|
| 64 | 61 | #include "printk_ringbuffer.h" |
|---|
| 65 | 62 | #include "console_cmdline.h" |
|---|
| 66 | 63 | #include "braille.h" |
|---|
| 64 | +#include "internal.h" |
|---|
| 65 | + |
|---|
| 66 | +#ifdef CONFIG_PRINTK_TIME_FROM_ARM_ARCH_TIMER |
|---|
| 67 | +#include <clocksource/arm_arch_timer.h> |
|---|
| 68 | +static u64 get_local_clock(void) |
|---|
| 69 | +{ |
|---|
| 70 | + u64 ns; |
|---|
| 71 | + |
|---|
| 72 | + ns = arch_timer_read_counter() * 1000; |
|---|
| 73 | + do_div(ns, 24); |
|---|
| 74 | + |
|---|
| 75 | + return ns; |
|---|
| 76 | +} |
|---|
| 77 | +#else |
|---|
| 78 | +static inline u64 get_local_clock(void) |
|---|
| 79 | +{ |
|---|
| 80 | + return local_clock(); |
|---|
| 81 | +} |
|---|
| 82 | +#endif |
|---|
| 67 | 83 | |
|---|
| 68 | 84 | int console_printk[4] = { |
|---|
| 69 | 85 | CONSOLE_LOGLEVEL_DEFAULT, /* console_loglevel */ |
|---|
| .. | .. |
|---|
| 232 | 248 | |
|---|
| 233 | 249 | static int __down_trylock_console_sem(unsigned long ip) |
|---|
| 234 | 250 | { |
|---|
| 235 | | - if (down_trylock(&console_sem)) |
|---|
| 251 | + int lock_failed; |
|---|
| 252 | + unsigned long flags; |
|---|
| 253 | + |
|---|
| 254 | + /* |
|---|
| 255 | + * Here and in __up_console_sem() we need to be in safe mode, |
|---|
| 256 | + * because spindump/WARN/etc from under console ->lock will |
|---|
| 257 | + * deadlock in printk()->down_trylock_console_sem() otherwise. |
|---|
| 258 | + */ |
|---|
| 259 | + printk_safe_enter_irqsave(flags); |
|---|
| 260 | + lock_failed = down_trylock(&console_sem); |
|---|
| 261 | + printk_safe_exit_irqrestore(flags); |
|---|
| 262 | + |
|---|
| 263 | + if (lock_failed) |
|---|
| 236 | 264 | return 1; |
|---|
| 237 | 265 | mutex_acquire(&console_lock_dep_map, 0, 1, ip); |
|---|
| 238 | 266 | return 0; |
|---|
| .. | .. |
|---|
| 241 | 269 | |
|---|
| 242 | 270 | static void __up_console_sem(unsigned long ip) |
|---|
| 243 | 271 | { |
|---|
| 272 | + unsigned long flags; |
|---|
| 273 | + |
|---|
| 244 | 274 | mutex_release(&console_lock_dep_map, ip); |
|---|
| 245 | 275 | |
|---|
| 276 | + printk_safe_enter_irqsave(flags); |
|---|
| 246 | 277 | up(&console_sem); |
|---|
| 278 | + printk_safe_exit_irqrestore(flags); |
|---|
| 247 | 279 | } |
|---|
| 248 | 280 | #define up_console_sem() __up_console_sem(_RET_IP_) |
|---|
| 249 | 281 | |
|---|
| .. | .. |
|---|
| 256 | 288 | * locked without the console sempahore held). |
|---|
| 257 | 289 | */ |
|---|
| 258 | 290 | static int console_locked, console_suspended; |
|---|
| 291 | + |
|---|
| 292 | +/* |
|---|
| 293 | + * If exclusive_console is non-NULL then only this console is to be printed to. |
|---|
| 294 | + */ |
|---|
| 295 | +static struct console *exclusive_console; |
|---|
| 259 | 296 | |
|---|
| 260 | 297 | /* |
|---|
| 261 | 298 | * Array of consoles built from command line options (console=) |
|---|
| .. | .. |
|---|
| 341 | 378 | LOG_CONT = 8, /* text is a fragment of a continuation line */ |
|---|
| 342 | 379 | }; |
|---|
| 343 | 380 | |
|---|
| 381 | +/* |
|---|
| 382 | + * The logbuf_lock protects kmsg buffer, indices, counters. This can be taken |
|---|
| 383 | + * within the scheduler's rq lock. It must be released before calling |
|---|
| 384 | + * console_unlock() or anything else that might wake up a process. |
|---|
| 385 | + */ |
|---|
| 386 | +DEFINE_RAW_SPINLOCK(logbuf_lock); |
|---|
| 387 | + |
|---|
| 388 | +/* |
|---|
| 389 | + * Helper macros to lock/unlock logbuf_lock and switch between |
|---|
| 390 | + * printk-safe/unsafe modes. |
|---|
| 391 | + */ |
|---|
| 392 | +#define logbuf_lock_irq() \ |
|---|
| 393 | + do { \ |
|---|
| 394 | + printk_safe_enter_irq(); \ |
|---|
| 395 | + raw_spin_lock(&logbuf_lock); \ |
|---|
| 396 | + } while (0) |
|---|
| 397 | + |
|---|
| 398 | +#define logbuf_unlock_irq() \ |
|---|
| 399 | + do { \ |
|---|
| 400 | + raw_spin_unlock(&logbuf_lock); \ |
|---|
| 401 | + printk_safe_exit_irq(); \ |
|---|
| 402 | + } while (0) |
|---|
| 403 | + |
|---|
| 404 | +#define logbuf_lock_irqsave(flags) \ |
|---|
| 405 | + do { \ |
|---|
| 406 | + printk_safe_enter_irqsave(flags); \ |
|---|
| 407 | + raw_spin_lock(&logbuf_lock); \ |
|---|
| 408 | + } while (0) |
|---|
| 409 | + |
|---|
| 410 | +#define logbuf_unlock_irqrestore(flags) \ |
|---|
| 411 | + do { \ |
|---|
| 412 | + raw_spin_unlock(&logbuf_lock); \ |
|---|
| 413 | + printk_safe_exit_irqrestore(flags); \ |
|---|
| 414 | + } while (0) |
|---|
| 415 | + |
|---|
| 344 | 416 | #ifdef CONFIG_PRINTK |
|---|
| 345 | | -/* syslog_lock protects syslog_* variables and write access to clear_seq. */ |
|---|
| 346 | | -static DEFINE_SPINLOCK(syslog_lock); |
|---|
| 347 | | - |
|---|
| 348 | | -/* Set to enable sync mode. Once set, it is never cleared. */ |
|---|
| 349 | | -static bool sync_mode; |
|---|
| 350 | | - |
|---|
| 351 | 417 | DECLARE_WAIT_QUEUE_HEAD(log_wait); |
|---|
| 352 | | -/* All 3 protected by @syslog_lock. */ |
|---|
| 353 | 418 | /* the next printk record to read by syslog(READ) or /proc/kmsg */ |
|---|
| 354 | 419 | static u64 syslog_seq; |
|---|
| 355 | 420 | static size_t syslog_partial; |
|---|
| 356 | 421 | static bool syslog_time; |
|---|
| 357 | 422 | |
|---|
| 358 | | -struct latched_seq { |
|---|
| 359 | | - seqcount_latch_t latch; |
|---|
| 360 | | - u64 val[2]; |
|---|
| 361 | | -}; |
|---|
| 423 | +/* the next printk record to write to the console */ |
|---|
| 424 | +static u64 console_seq; |
|---|
| 425 | +static u64 exclusive_console_stop_seq; |
|---|
| 426 | +static unsigned long console_dropped; |
|---|
| 362 | 427 | |
|---|
| 363 | | -/* |
|---|
| 364 | | - * The next printk record to read after the last 'clear' command. There are |
|---|
| 365 | | - * two copies (updated with seqcount_latch) so that reads can locklessly |
|---|
| 366 | | - * access a valid value. Writers are synchronized by @syslog_lock. |
|---|
| 367 | | - */ |
|---|
| 368 | | -static struct latched_seq clear_seq = { |
|---|
| 369 | | - .latch = SEQCNT_LATCH_ZERO(clear_seq.latch), |
|---|
| 370 | | - .val[0] = 0, |
|---|
| 371 | | - .val[1] = 0, |
|---|
| 372 | | -}; |
|---|
| 428 | +/* the next printk record to read after the last 'clear' command */ |
|---|
| 429 | +static u64 clear_seq; |
|---|
| 373 | 430 | |
|---|
| 374 | 431 | #ifdef CONFIG_PRINTK_CALLER |
|---|
| 375 | 432 | #define PREFIX_MAX 48 |
|---|
| 376 | 433 | #else |
|---|
| 377 | 434 | #define PREFIX_MAX 32 |
|---|
| 378 | 435 | #endif |
|---|
| 379 | | - |
|---|
| 380 | | -/* the maximum size allowed to be reserved for a record */ |
|---|
| 381 | 436 | #define LOG_LINE_MAX (1024 - PREFIX_MAX) |
|---|
| 382 | 437 | |
|---|
| 383 | 438 | #define LOG_LEVEL(v) ((v) & 0x07) |
|---|
| .. | .. |
|---|
| 415 | 470 | */ |
|---|
| 416 | 471 | static bool __printk_percpu_data_ready __read_mostly; |
|---|
| 417 | 472 | |
|---|
| 418 | | -static bool printk_percpu_data_ready(void) |
|---|
| 473 | +bool printk_percpu_data_ready(void) |
|---|
| 419 | 474 | { |
|---|
| 420 | 475 | return __printk_percpu_data_ready; |
|---|
| 421 | | -} |
|---|
| 422 | | - |
|---|
| 423 | | -/* Must be called under syslog_lock. */ |
|---|
| 424 | | -static void latched_seq_write(struct latched_seq *ls, u64 val) |
|---|
| 425 | | -{ |
|---|
| 426 | | - raw_write_seqcount_latch(&ls->latch); |
|---|
| 427 | | - ls->val[0] = val; |
|---|
| 428 | | - raw_write_seqcount_latch(&ls->latch); |
|---|
| 429 | | - ls->val[1] = val; |
|---|
| 430 | | -} |
|---|
| 431 | | - |
|---|
| 432 | | -/* Can be called from any context. */ |
|---|
| 433 | | -static u64 latched_seq_read_nolock(struct latched_seq *ls) |
|---|
| 434 | | -{ |
|---|
| 435 | | - unsigned int seq; |
|---|
| 436 | | - unsigned int idx; |
|---|
| 437 | | - u64 val; |
|---|
| 438 | | - |
|---|
| 439 | | - do { |
|---|
| 440 | | - seq = raw_read_seqcount_latch(&ls->latch); |
|---|
| 441 | | - idx = seq & 0x1; |
|---|
| 442 | | - val = ls->val[idx]; |
|---|
| 443 | | - } while (read_seqcount_latch_retry(&ls->latch, seq)); |
|---|
| 444 | | - |
|---|
| 445 | | - return val; |
|---|
| 446 | 476 | } |
|---|
| 447 | 477 | |
|---|
| 448 | 478 | /* Return log buffer address */ |
|---|
| .. | .. |
|---|
| 484 | 514 | *text_len -= *trunc_msg_len; |
|---|
| 485 | 515 | else |
|---|
| 486 | 516 | *trunc_msg_len = 0; |
|---|
| 517 | +} |
|---|
| 518 | + |
|---|
| 519 | +/* insert record into the buffer, discard old ones, update heads */ |
|---|
| 520 | +static int log_store(u32 caller_id, int facility, int level, |
|---|
| 521 | + enum log_flags flags, u64 ts_nsec, |
|---|
| 522 | + const struct dev_printk_info *dev_info, |
|---|
| 523 | + const char *text, u16 text_len) |
|---|
| 524 | +{ |
|---|
| 525 | + struct prb_reserved_entry e; |
|---|
| 526 | + struct printk_record r; |
|---|
| 527 | + u16 trunc_msg_len = 0; |
|---|
| 528 | + |
|---|
| 529 | + prb_rec_init_wr(&r, text_len); |
|---|
| 530 | + |
|---|
| 531 | + if (!prb_reserve(&e, prb, &r)) { |
|---|
| 532 | + /* truncate the message if it is too long for empty buffer */ |
|---|
| 533 | + truncate_msg(&text_len, &trunc_msg_len); |
|---|
| 534 | + prb_rec_init_wr(&r, text_len + trunc_msg_len); |
|---|
| 535 | + /* survive when the log buffer is too small for trunc_msg */ |
|---|
| 536 | + if (!prb_reserve(&e, prb, &r)) |
|---|
| 537 | + return 0; |
|---|
| 538 | + } |
|---|
| 539 | + |
|---|
| 540 | + /* fill message */ |
|---|
| 541 | + memcpy(&r.text_buf[0], text, text_len); |
|---|
| 542 | + if (trunc_msg_len) |
|---|
| 543 | + memcpy(&r.text_buf[text_len], trunc_msg, trunc_msg_len); |
|---|
| 544 | + r.info->text_len = text_len + trunc_msg_len; |
|---|
| 545 | + r.info->facility = facility; |
|---|
| 546 | + r.info->level = level & 7; |
|---|
| 547 | + r.info->flags = flags & 0x1f; |
|---|
| 548 | + if (ts_nsec > 0) |
|---|
| 549 | + r.info->ts_nsec = ts_nsec; |
|---|
| 550 | + else |
|---|
| 551 | + r.info->ts_nsec = get_local_clock(); |
|---|
| 552 | + r.info->caller_id = caller_id; |
|---|
| 553 | + if (dev_info) |
|---|
| 554 | + memcpy(&r.info->dev_info, dev_info, sizeof(r.info->dev_info)); |
|---|
| 555 | + |
|---|
| 556 | + /* A message without a trailing newline can be continued. */ |
|---|
| 557 | + if (!(flags & LOG_NEWLINE)) |
|---|
| 558 | + prb_commit(&e); |
|---|
| 559 | + else |
|---|
| 560 | + prb_final_commit(&e); |
|---|
| 561 | + |
|---|
| 562 | + trace_android_vh_logbuf(prb, &r); |
|---|
| 563 | + |
|---|
| 564 | + return (text_len + trunc_msg_len); |
|---|
| 487 | 565 | } |
|---|
| 488 | 566 | |
|---|
| 489 | 567 | int dmesg_restrict = IS_ENABLED(CONFIG_SECURITY_DMESG_RESTRICT); |
|---|
| .. | .. |
|---|
| 614 | 692 | |
|---|
| 615 | 693 | /* /dev/kmsg - userspace message inject/listen interface */ |
|---|
| 616 | 694 | struct devkmsg_user { |
|---|
| 617 | | - atomic64_t seq; |
|---|
| 695 | + u64 seq; |
|---|
| 618 | 696 | struct ratelimit_state rs; |
|---|
| 619 | 697 | struct mutex lock; |
|---|
| 620 | 698 | char buf[CONSOLE_EXT_LOG_MAX]; |
|---|
| .. | .. |
|---|
| 715 | 793 | if (ret) |
|---|
| 716 | 794 | return ret; |
|---|
| 717 | 795 | |
|---|
| 718 | | - if (!prb_read_valid(prb, atomic64_read(&user->seq), r)) { |
|---|
| 796 | + logbuf_lock_irq(); |
|---|
| 797 | + if (!prb_read_valid(prb, user->seq, r)) { |
|---|
| 719 | 798 | if (file->f_flags & O_NONBLOCK) { |
|---|
| 720 | 799 | ret = -EAGAIN; |
|---|
| 800 | + logbuf_unlock_irq(); |
|---|
| 721 | 801 | goto out; |
|---|
| 722 | 802 | } |
|---|
| 723 | 803 | |
|---|
| 804 | + logbuf_unlock_irq(); |
|---|
| 724 | 805 | ret = wait_event_interruptible(log_wait, |
|---|
| 725 | | - prb_read_valid(prb, atomic64_read(&user->seq), r)); |
|---|
| 806 | + prb_read_valid(prb, user->seq, r)); |
|---|
| 726 | 807 | if (ret) |
|---|
| 727 | 808 | goto out; |
|---|
| 809 | + logbuf_lock_irq(); |
|---|
| 728 | 810 | } |
|---|
| 729 | 811 | |
|---|
| 730 | | - if (r->info->seq != atomic64_read(&user->seq)) { |
|---|
| 812 | + if (r->info->seq != user->seq) { |
|---|
| 731 | 813 | /* our last seen message is gone, return error and reset */ |
|---|
| 732 | | - atomic64_set(&user->seq, r->info->seq); |
|---|
| 814 | + user->seq = r->info->seq; |
|---|
| 733 | 815 | ret = -EPIPE; |
|---|
| 816 | + logbuf_unlock_irq(); |
|---|
| 734 | 817 | goto out; |
|---|
| 735 | 818 | } |
|---|
| 736 | 819 | |
|---|
| .. | .. |
|---|
| 739 | 822 | &r->text_buf[0], r->info->text_len, |
|---|
| 740 | 823 | &r->info->dev_info); |
|---|
| 741 | 824 | |
|---|
| 742 | | - atomic64_set(&user->seq, r->info->seq + 1); |
|---|
| 825 | + user->seq = r->info->seq + 1; |
|---|
| 826 | + logbuf_unlock_irq(); |
|---|
| 743 | 827 | |
|---|
| 744 | 828 | if (len > count) { |
|---|
| 745 | 829 | ret = -EINVAL; |
|---|
| .. | .. |
|---|
| 774 | 858 | if (offset) |
|---|
| 775 | 859 | return -ESPIPE; |
|---|
| 776 | 860 | |
|---|
| 861 | + logbuf_lock_irq(); |
|---|
| 777 | 862 | switch (whence) { |
|---|
| 778 | 863 | case SEEK_SET: |
|---|
| 779 | 864 | /* the first record */ |
|---|
| 780 | | - atomic64_set(&user->seq, prb_first_valid_seq(prb)); |
|---|
| 865 | + user->seq = prb_first_valid_seq(prb); |
|---|
| 781 | 866 | break; |
|---|
| 782 | 867 | case SEEK_DATA: |
|---|
| 783 | 868 | /* |
|---|
| .. | .. |
|---|
| 785 | 870 | * like issued by 'dmesg -c'. Reading /dev/kmsg itself |
|---|
| 786 | 871 | * changes no global state, and does not clear anything. |
|---|
| 787 | 872 | */ |
|---|
| 788 | | - atomic64_set(&user->seq, latched_seq_read_nolock(&clear_seq)); |
|---|
| 873 | + user->seq = clear_seq; |
|---|
| 789 | 874 | break; |
|---|
| 790 | 875 | case SEEK_END: |
|---|
| 791 | 876 | /* after the last record */ |
|---|
| 792 | | - atomic64_set(&user->seq, prb_next_seq(prb)); |
|---|
| 877 | + user->seq = prb_next_seq(prb); |
|---|
| 793 | 878 | break; |
|---|
| 794 | 879 | default: |
|---|
| 795 | 880 | ret = -EINVAL; |
|---|
| 796 | 881 | } |
|---|
| 882 | + logbuf_unlock_irq(); |
|---|
| 797 | 883 | return ret; |
|---|
| 798 | 884 | } |
|---|
| 799 | 885 | |
|---|
| .. | .. |
|---|
| 808 | 894 | |
|---|
| 809 | 895 | poll_wait(file, &log_wait, wait); |
|---|
| 810 | 896 | |
|---|
| 811 | | - if (prb_read_valid_info(prb, atomic64_read(&user->seq), &info, NULL)) { |
|---|
| 897 | + logbuf_lock_irq(); |
|---|
| 898 | + if (prb_read_valid_info(prb, user->seq, &info, NULL)) { |
|---|
| 812 | 899 | /* return error when data has vanished underneath us */ |
|---|
| 813 | | - if (info.seq != atomic64_read(&user->seq)) |
|---|
| 900 | + if (info.seq != user->seq) |
|---|
| 814 | 901 | ret = EPOLLIN|EPOLLRDNORM|EPOLLERR|EPOLLPRI; |
|---|
| 815 | 902 | else |
|---|
| 816 | 903 | ret = EPOLLIN|EPOLLRDNORM; |
|---|
| 817 | 904 | } |
|---|
| 905 | + logbuf_unlock_irq(); |
|---|
| 818 | 906 | |
|---|
| 819 | 907 | return ret; |
|---|
| 820 | 908 | } |
|---|
| .. | .. |
|---|
| 847 | 935 | prb_rec_init_rd(&user->record, &user->info, |
|---|
| 848 | 936 | &user->text_buf[0], sizeof(user->text_buf)); |
|---|
| 849 | 937 | |
|---|
| 850 | | - atomic64_set(&user->seq, prb_first_valid_seq(prb)); |
|---|
| 938 | + logbuf_lock_irq(); |
|---|
| 939 | + user->seq = prb_first_valid_seq(prb); |
|---|
| 940 | + logbuf_unlock_irq(); |
|---|
| 851 | 941 | |
|---|
| 852 | 942 | file->private_data = user; |
|---|
| 853 | 943 | return 0; |
|---|
| .. | .. |
|---|
| 939 | 1029 | |
|---|
| 940 | 1030 | VMCOREINFO_SIZE(atomic_long_t); |
|---|
| 941 | 1031 | VMCOREINFO_TYPE_OFFSET(atomic_long_t, counter); |
|---|
| 942 | | - |
|---|
| 943 | | - VMCOREINFO_STRUCT_SIZE(latched_seq); |
|---|
| 944 | | - VMCOREINFO_OFFSET(latched_seq, val); |
|---|
| 945 | 1032 | } |
|---|
| 946 | 1033 | #endif |
|---|
| 947 | 1034 | |
|---|
| .. | .. |
|---|
| 1013 | 1100 | |
|---|
| 1014 | 1101 | static void __init set_percpu_data_ready(void) |
|---|
| 1015 | 1102 | { |
|---|
| 1103 | + printk_safe_init(); |
|---|
| 1104 | + /* Make sure we set this flag only after printk_safe() init is done */ |
|---|
| 1105 | + barrier(); |
|---|
| 1016 | 1106 | __printk_percpu_data_ready = true; |
|---|
| 1017 | 1107 | } |
|---|
| 1018 | 1108 | |
|---|
| .. | .. |
|---|
| 1052 | 1142 | struct printk_record r; |
|---|
| 1053 | 1143 | size_t new_descs_size; |
|---|
| 1054 | 1144 | size_t new_infos_size; |
|---|
| 1145 | + unsigned long flags; |
|---|
| 1055 | 1146 | char *new_log_buf; |
|---|
| 1056 | 1147 | unsigned int free; |
|---|
| 1057 | 1148 | u64 seq; |
|---|
| .. | .. |
|---|
| 1109 | 1200 | new_descs, ilog2(new_descs_count), |
|---|
| 1110 | 1201 | new_infos); |
|---|
| 1111 | 1202 | |
|---|
| 1203 | + logbuf_lock_irqsave(flags); |
|---|
| 1204 | + |
|---|
| 1112 | 1205 | log_buf_len = new_log_buf_len; |
|---|
| 1113 | 1206 | log_buf = new_log_buf; |
|---|
| 1114 | 1207 | new_log_buf_len = 0; |
|---|
| .. | .. |
|---|
| 1123 | 1216 | * appear during the transition to the dynamic buffer. |
|---|
| 1124 | 1217 | */ |
|---|
| 1125 | 1218 | prb = &printk_rb_dynamic; |
|---|
| 1219 | + |
|---|
| 1220 | + logbuf_unlock_irqrestore(flags); |
|---|
| 1126 | 1221 | |
|---|
| 1127 | 1222 | if (seq != prb_next_seq(&printk_rb_static)) { |
|---|
| 1128 | 1223 | pr_err("dropped %llu messages\n", |
|---|
| .. | .. |
|---|
| 1400 | 1495 | return ((prefix_len * line_count) + info->text_len + 1); |
|---|
| 1401 | 1496 | } |
|---|
| 1402 | 1497 | |
|---|
| 1403 | | -/* |
|---|
| 1404 | | - * Beginning with @start_seq, find the first record where it and all following |
|---|
| 1405 | | - * records up to (but not including) @max_seq fit into @size. |
|---|
| 1406 | | - * |
|---|
| 1407 | | - * @max_seq is simply an upper bound and does not need to exist. If the caller |
|---|
| 1408 | | - * does not require an upper bound, -1 can be used for @max_seq. |
|---|
| 1409 | | - */ |
|---|
| 1410 | | -static u64 find_first_fitting_seq(u64 start_seq, u64 max_seq, size_t size, |
|---|
| 1411 | | - bool syslog, bool time) |
|---|
| 1412 | | -{ |
|---|
| 1413 | | - struct printk_info info; |
|---|
| 1414 | | - unsigned int line_count; |
|---|
| 1415 | | - size_t len = 0; |
|---|
| 1416 | | - u64 seq; |
|---|
| 1417 | | - |
|---|
| 1418 | | - /* Determine the size of the records up to @max_seq. */ |
|---|
| 1419 | | - prb_for_each_info(start_seq, prb, seq, &info, &line_count) { |
|---|
| 1420 | | - if (info.seq >= max_seq) |
|---|
| 1421 | | - break; |
|---|
| 1422 | | - len += get_record_print_text_size(&info, line_count, syslog, time); |
|---|
| 1423 | | - } |
|---|
| 1424 | | - |
|---|
| 1425 | | - /* |
|---|
| 1426 | | - * Adjust the upper bound for the next loop to avoid subtracting |
|---|
| 1427 | | - * lengths that were never added. |
|---|
| 1428 | | - */ |
|---|
| 1429 | | - if (seq < max_seq) |
|---|
| 1430 | | - max_seq = seq; |
|---|
| 1431 | | - |
|---|
| 1432 | | - /* |
|---|
| 1433 | | - * Move first record forward until length fits into the buffer. Ignore |
|---|
| 1434 | | - * newest messages that were not counted in the above cycle. Messages |
|---|
| 1435 | | - * might appear and get lost in the meantime. This is a best effort |
|---|
| 1436 | | - * that prevents an infinite loop that could occur with a retry. |
|---|
| 1437 | | - */ |
|---|
| 1438 | | - prb_for_each_info(start_seq, prb, seq, &info, &line_count) { |
|---|
| 1439 | | - if (len <= size || info.seq >= max_seq) |
|---|
| 1440 | | - break; |
|---|
| 1441 | | - len -= get_record_print_text_size(&info, line_count, syslog, time); |
|---|
| 1442 | | - } |
|---|
| 1443 | | - |
|---|
| 1444 | | - return seq; |
|---|
| 1445 | | -} |
|---|
| 1446 | | - |
|---|
| 1447 | 1498 | static int syslog_print(char __user *buf, int size) |
|---|
| 1448 | 1499 | { |
|---|
| 1449 | 1500 | struct printk_info info; |
|---|
| .. | .. |
|---|
| 1451 | 1502 | char *text; |
|---|
| 1452 | 1503 | int len = 0; |
|---|
| 1453 | 1504 | |
|---|
| 1454 | | - text = kmalloc(CONSOLE_LOG_MAX, GFP_KERNEL); |
|---|
| 1505 | + text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL); |
|---|
| 1455 | 1506 | if (!text) |
|---|
| 1456 | 1507 | return -ENOMEM; |
|---|
| 1457 | 1508 | |
|---|
| 1458 | | - prb_rec_init_rd(&r, &info, text, CONSOLE_LOG_MAX); |
|---|
| 1509 | + prb_rec_init_rd(&r, &info, text, LOG_LINE_MAX + PREFIX_MAX); |
|---|
| 1459 | 1510 | |
|---|
| 1460 | 1511 | while (size > 0) { |
|---|
| 1461 | 1512 | size_t n; |
|---|
| 1462 | 1513 | size_t skip; |
|---|
| 1463 | 1514 | |
|---|
| 1464 | | - spin_lock_irq(&syslog_lock); |
|---|
| 1515 | + logbuf_lock_irq(); |
|---|
| 1465 | 1516 | if (!prb_read_valid(prb, syslog_seq, &r)) { |
|---|
| 1466 | | - spin_unlock_irq(&syslog_lock); |
|---|
| 1517 | + logbuf_unlock_irq(); |
|---|
| 1467 | 1518 | break; |
|---|
| 1468 | 1519 | } |
|---|
| 1469 | 1520 | if (r.info->seq != syslog_seq) { |
|---|
| .. | .. |
|---|
| 1492 | 1543 | syslog_partial += n; |
|---|
| 1493 | 1544 | } else |
|---|
| 1494 | 1545 | n = 0; |
|---|
| 1495 | | - spin_unlock_irq(&syslog_lock); |
|---|
| 1546 | + logbuf_unlock_irq(); |
|---|
| 1496 | 1547 | |
|---|
| 1497 | 1548 | if (!n) |
|---|
| 1498 | 1549 | break; |
|---|
| .. | .. |
|---|
| 1515 | 1566 | static int syslog_print_all(char __user *buf, int size, bool clear) |
|---|
| 1516 | 1567 | { |
|---|
| 1517 | 1568 | struct printk_info info; |
|---|
| 1569 | + unsigned int line_count; |
|---|
| 1518 | 1570 | struct printk_record r; |
|---|
| 1519 | 1571 | char *text; |
|---|
| 1520 | 1572 | int len = 0; |
|---|
| 1521 | 1573 | u64 seq; |
|---|
| 1522 | 1574 | bool time; |
|---|
| 1523 | 1575 | |
|---|
| 1524 | | - text = kmalloc(CONSOLE_LOG_MAX, GFP_KERNEL); |
|---|
| 1576 | + text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL); |
|---|
| 1525 | 1577 | if (!text) |
|---|
| 1526 | 1578 | return -ENOMEM; |
|---|
| 1527 | 1579 | |
|---|
| 1528 | 1580 | time = printk_time; |
|---|
| 1581 | + logbuf_lock_irq(); |
|---|
| 1529 | 1582 | /* |
|---|
| 1530 | 1583 | * Find first record that fits, including all following records, |
|---|
| 1531 | 1584 | * into the user-provided buffer for this dump. |
|---|
| 1532 | 1585 | */ |
|---|
| 1533 | | - seq = find_first_fitting_seq(latched_seq_read_nolock(&clear_seq), -1, |
|---|
| 1534 | | - size, true, time); |
|---|
| 1586 | + prb_for_each_info(clear_seq, prb, seq, &info, &line_count) |
|---|
| 1587 | + len += get_record_print_text_size(&info, line_count, true, time); |
|---|
| 1535 | 1588 | |
|---|
| 1536 | | - prb_rec_init_rd(&r, &info, text, CONSOLE_LOG_MAX); |
|---|
| 1589 | + /* move first record forward until length fits into the buffer */ |
|---|
| 1590 | + prb_for_each_info(clear_seq, prb, seq, &info, &line_count) { |
|---|
| 1591 | + if (len <= size) |
|---|
| 1592 | + break; |
|---|
| 1593 | + len -= get_record_print_text_size(&info, line_count, true, time); |
|---|
| 1594 | + } |
|---|
| 1595 | + |
|---|
| 1596 | + prb_rec_init_rd(&r, &info, text, LOG_LINE_MAX + PREFIX_MAX); |
|---|
| 1537 | 1597 | |
|---|
| 1538 | 1598 | len = 0; |
|---|
| 1539 | 1599 | prb_for_each_record(seq, prb, seq, &r) { |
|---|
| .. | .. |
|---|
| 1546 | 1606 | break; |
|---|
| 1547 | 1607 | } |
|---|
| 1548 | 1608 | |
|---|
| 1609 | + logbuf_unlock_irq(); |
|---|
| 1549 | 1610 | if (copy_to_user(buf + len, text, textlen)) |
|---|
| 1550 | 1611 | len = -EFAULT; |
|---|
| 1551 | 1612 | else |
|---|
| 1552 | 1613 | len += textlen; |
|---|
| 1614 | + logbuf_lock_irq(); |
|---|
| 1553 | 1615 | |
|---|
| 1554 | 1616 | if (len < 0) |
|---|
| 1555 | 1617 | break; |
|---|
| 1556 | 1618 | } |
|---|
| 1557 | 1619 | |
|---|
| 1558 | | - if (clear) { |
|---|
| 1559 | | - spin_lock_irq(&syslog_lock); |
|---|
| 1560 | | - latched_seq_write(&clear_seq, seq); |
|---|
| 1561 | | - spin_unlock_irq(&syslog_lock); |
|---|
| 1562 | | - } |
|---|
| 1620 | + if (clear) |
|---|
| 1621 | + clear_seq = seq; |
|---|
| 1622 | + logbuf_unlock_irq(); |
|---|
| 1563 | 1623 | |
|---|
| 1564 | 1624 | kfree(text); |
|---|
| 1565 | 1625 | return len; |
|---|
| .. | .. |
|---|
| 1567 | 1627 | |
|---|
| 1568 | 1628 | static void syslog_clear(void) |
|---|
| 1569 | 1629 | { |
|---|
| 1570 | | - spin_lock_irq(&syslog_lock); |
|---|
| 1571 | | - latched_seq_write(&clear_seq, prb_next_seq(prb)); |
|---|
| 1572 | | - spin_unlock_irq(&syslog_lock); |
|---|
| 1573 | | -} |
|---|
| 1574 | | - |
|---|
| 1575 | | -/* Return a consistent copy of @syslog_seq. */ |
|---|
| 1576 | | -static u64 read_syslog_seq_irq(void) |
|---|
| 1577 | | -{ |
|---|
| 1578 | | - u64 seq; |
|---|
| 1579 | | - |
|---|
| 1580 | | - spin_lock_irq(&syslog_lock); |
|---|
| 1581 | | - seq = syslog_seq; |
|---|
| 1582 | | - spin_unlock_irq(&syslog_lock); |
|---|
| 1583 | | - |
|---|
| 1584 | | - return seq; |
|---|
| 1630 | + logbuf_lock_irq(); |
|---|
| 1631 | + clear_seq = prb_next_seq(prb); |
|---|
| 1632 | + logbuf_unlock_irq(); |
|---|
| 1585 | 1633 | } |
|---|
| 1586 | 1634 | |
|---|
| 1587 | 1635 | int do_syslog(int type, char __user *buf, int len, int source) |
|---|
| .. | .. |
|---|
| 1607 | 1655 | return 0; |
|---|
| 1608 | 1656 | if (!access_ok(buf, len)) |
|---|
| 1609 | 1657 | return -EFAULT; |
|---|
| 1610 | | - |
|---|
| 1611 | 1658 | error = wait_event_interruptible(log_wait, |
|---|
| 1612 | | - prb_read_valid(prb, read_syslog_seq_irq(), NULL)); |
|---|
| 1659 | + prb_read_valid(prb, syslog_seq, NULL)); |
|---|
| 1613 | 1660 | if (error) |
|---|
| 1614 | 1661 | return error; |
|---|
| 1615 | 1662 | error = syslog_print(buf, len); |
|---|
| .. | .. |
|---|
| 1657 | 1704 | break; |
|---|
| 1658 | 1705 | /* Number of chars in the log buffer */ |
|---|
| 1659 | 1706 | case SYSLOG_ACTION_SIZE_UNREAD: |
|---|
| 1660 | | - spin_lock_irq(&syslog_lock); |
|---|
| 1707 | + logbuf_lock_irq(); |
|---|
| 1661 | 1708 | if (!prb_read_valid_info(prb, syslog_seq, &info, NULL)) { |
|---|
| 1662 | 1709 | /* No unread messages. */ |
|---|
| 1663 | | - spin_unlock_irq(&syslog_lock); |
|---|
| 1710 | + logbuf_unlock_irq(); |
|---|
| 1664 | 1711 | return 0; |
|---|
| 1665 | 1712 | } |
|---|
| 1666 | 1713 | if (info.seq != syslog_seq) { |
|---|
| .. | .. |
|---|
| 1688 | 1735 | } |
|---|
| 1689 | 1736 | error -= syslog_partial; |
|---|
| 1690 | 1737 | } |
|---|
| 1691 | | - spin_unlock_irq(&syslog_lock); |
|---|
| 1738 | + logbuf_unlock_irq(); |
|---|
| 1692 | 1739 | break; |
|---|
| 1693 | 1740 | /* Size of the log buffer */ |
|---|
| 1694 | 1741 | case SYSLOG_ACTION_SIZE_BUFFER: |
|---|
| .. | .. |
|---|
| 1707 | 1754 | return do_syslog(type, buf, len, SYSLOG_FROM_READER); |
|---|
| 1708 | 1755 | } |
|---|
| 1709 | 1756 | |
|---|
| 1757 | +/* |
|---|
| 1758 | + * Special console_lock variants that help to reduce the risk of soft-lockups. |
|---|
| 1759 | + * They allow to pass console_lock to another printk() call using a busy wait. |
|---|
| 1760 | + */ |
|---|
| 1761 | + |
|---|
| 1762 | +#ifdef CONFIG_LOCKDEP |
|---|
| 1763 | +static struct lockdep_map console_owner_dep_map = { |
|---|
| 1764 | + .name = "console_owner" |
|---|
| 1765 | +}; |
|---|
| 1766 | +#endif |
|---|
| 1767 | + |
|---|
| 1768 | +static DEFINE_RAW_SPINLOCK(console_owner_lock); |
|---|
| 1769 | +static struct task_struct *console_owner; |
|---|
| 1770 | +static bool console_waiter; |
|---|
| 1771 | + |
|---|
| 1772 | +/** |
|---|
| 1773 | + * console_lock_spinning_enable - mark beginning of code where another |
|---|
| 1774 | + * thread might safely busy wait |
|---|
| 1775 | + * |
|---|
| 1776 | + * This basically converts console_lock into a spinlock. This marks |
|---|
| 1777 | + * the section where the console_lock owner can not sleep, because |
|---|
| 1778 | + * there may be a waiter spinning (like a spinlock). Also it must be |
|---|
| 1779 | + * ready to hand over the lock at the end of the section. |
|---|
| 1780 | + */ |
|---|
| 1781 | +static void console_lock_spinning_enable(void) |
|---|
| 1782 | +{ |
|---|
| 1783 | + raw_spin_lock(&console_owner_lock); |
|---|
| 1784 | + console_owner = current; |
|---|
| 1785 | + raw_spin_unlock(&console_owner_lock); |
|---|
| 1786 | + |
|---|
| 1787 | + /* The waiter may spin on us after setting console_owner */ |
|---|
| 1788 | + spin_acquire(&console_owner_dep_map, 0, 0, _THIS_IP_); |
|---|
| 1789 | +} |
|---|
| 1790 | + |
|---|
| 1791 | +/** |
|---|
| 1792 | + * console_lock_spinning_disable_and_check - mark end of code where another |
|---|
| 1793 | + * thread was able to busy wait and check if there is a waiter |
|---|
| 1794 | + * |
|---|
| 1795 | + * This is called at the end of the section where spinning is allowed. |
|---|
| 1796 | + * It has two functions. First, it is a signal that it is no longer |
|---|
| 1797 | + * safe to start busy waiting for the lock. Second, it checks if |
|---|
| 1798 | + * there is a busy waiter and passes the lock rights to her. |
|---|
| 1799 | + * |
|---|
| 1800 | + * Important: Callers lose the lock if there was a busy waiter. |
|---|
| 1801 | + * They must not touch items synchronized by console_lock |
|---|
| 1802 | + * in this case. |
|---|
| 1803 | + * |
|---|
| 1804 | + * Return: 1 if the lock rights were passed, 0 otherwise. |
|---|
| 1805 | + */ |
|---|
| 1806 | +static int console_lock_spinning_disable_and_check(void) |
|---|
| 1807 | +{ |
|---|
| 1808 | + int waiter; |
|---|
| 1809 | + |
|---|
| 1810 | + raw_spin_lock(&console_owner_lock); |
|---|
| 1811 | + waiter = READ_ONCE(console_waiter); |
|---|
| 1812 | + console_owner = NULL; |
|---|
| 1813 | + raw_spin_unlock(&console_owner_lock); |
|---|
| 1814 | + |
|---|
| 1815 | + if (!waiter) { |
|---|
| 1816 | + spin_release(&console_owner_dep_map, _THIS_IP_); |
|---|
| 1817 | + return 0; |
|---|
| 1818 | + } |
|---|
| 1819 | + |
|---|
| 1820 | + /* The waiter is now free to continue */ |
|---|
| 1821 | + WRITE_ONCE(console_waiter, false); |
|---|
| 1822 | + |
|---|
| 1823 | + spin_release(&console_owner_dep_map, _THIS_IP_); |
|---|
| 1824 | + |
|---|
| 1825 | + /* |
|---|
| 1826 | + * Hand off console_lock to waiter. The waiter will perform |
|---|
| 1827 | + * the up(). After this, the waiter is the console_lock owner. |
|---|
| 1828 | + */ |
|---|
| 1829 | + mutex_release(&console_lock_dep_map, _THIS_IP_); |
|---|
| 1830 | + return 1; |
|---|
| 1831 | +} |
|---|
| 1832 | + |
|---|
| 1833 | +/** |
|---|
| 1834 | + * console_trylock_spinning - try to get console_lock by busy waiting |
|---|
| 1835 | + * |
|---|
| 1836 | + * This allows to busy wait for the console_lock when the current |
|---|
| 1837 | + * owner is running in specially marked sections. It means that |
|---|
| 1838 | + * the current owner is running and cannot reschedule until it |
|---|
| 1839 | + * is ready to lose the lock. |
|---|
| 1840 | + * |
|---|
| 1841 | + * Return: 1 if we got the lock, 0 othrewise |
|---|
| 1842 | + */ |
|---|
| 1843 | +static int console_trylock_spinning(void) |
|---|
| 1844 | +{ |
|---|
| 1845 | + struct task_struct *owner = NULL; |
|---|
| 1846 | + bool waiter; |
|---|
| 1847 | + bool spin = false; |
|---|
| 1848 | + unsigned long flags; |
|---|
| 1849 | + |
|---|
| 1850 | + if (console_trylock()) |
|---|
| 1851 | + return 1; |
|---|
| 1852 | + |
|---|
| 1853 | + printk_safe_enter_irqsave(flags); |
|---|
| 1854 | + |
|---|
| 1855 | + raw_spin_lock(&console_owner_lock); |
|---|
| 1856 | + owner = READ_ONCE(console_owner); |
|---|
| 1857 | + waiter = READ_ONCE(console_waiter); |
|---|
| 1858 | + if (!waiter && owner && owner != current) { |
|---|
| 1859 | + WRITE_ONCE(console_waiter, true); |
|---|
| 1860 | + spin = true; |
|---|
| 1861 | + } |
|---|
| 1862 | + raw_spin_unlock(&console_owner_lock); |
|---|
| 1863 | + |
|---|
| 1864 | + /* |
|---|
| 1865 | + * If there is an active printk() writing to the |
|---|
| 1866 | + * consoles, instead of having it write our data too, |
|---|
| 1867 | + * see if we can offload that load from the active |
|---|
| 1868 | + * printer, and do some printing ourselves. |
|---|
| 1869 | + * Go into a spin only if there isn't already a waiter |
|---|
| 1870 | + * spinning, and there is an active printer, and |
|---|
| 1871 | + * that active printer isn't us (recursive printk?). |
|---|
| 1872 | + */ |
|---|
| 1873 | + if (!spin) { |
|---|
| 1874 | + printk_safe_exit_irqrestore(flags); |
|---|
| 1875 | + return 0; |
|---|
| 1876 | + } |
|---|
| 1877 | + |
|---|
| 1878 | + /* We spin waiting for the owner to release us */ |
|---|
| 1879 | + spin_acquire(&console_owner_dep_map, 0, 0, _THIS_IP_); |
|---|
| 1880 | + /* Owner will clear console_waiter on hand off */ |
|---|
| 1881 | + while (READ_ONCE(console_waiter)) |
|---|
| 1882 | + cpu_relax(); |
|---|
| 1883 | + spin_release(&console_owner_dep_map, _THIS_IP_); |
|---|
| 1884 | + |
|---|
| 1885 | + printk_safe_exit_irqrestore(flags); |
|---|
| 1886 | + /* |
|---|
| 1887 | + * The owner passed the console lock to us. |
|---|
| 1888 | + * Since we did not spin on console lock, annotate |
|---|
| 1889 | + * this as a trylock. Otherwise lockdep will |
|---|
| 1890 | + * complain. |
|---|
| 1891 | + */ |
|---|
| 1892 | + mutex_acquire(&console_lock_dep_map, 0, 1, _THIS_IP_); |
|---|
| 1893 | + |
|---|
| 1894 | + return 1; |
|---|
| 1895 | +} |
|---|
| 1896 | + |
|---|
| 1897 | +/* |
|---|
| 1898 | + * Call the console drivers, asking them to write out |
|---|
| 1899 | + * log_buf[start] to log_buf[end - 1]. |
|---|
| 1900 | + * The console_lock must be held. |
|---|
| 1901 | + */ |
|---|
| 1902 | +static void call_console_drivers(const char *ext_text, size_t ext_len, |
|---|
| 1903 | + const char *text, size_t len) |
|---|
| 1904 | +{ |
|---|
| 1905 | + static char dropped_text[64]; |
|---|
| 1906 | + size_t dropped_len = 0; |
|---|
| 1907 | + struct console *con; |
|---|
| 1908 | + |
|---|
| 1909 | + trace_console_rcuidle(text, len); |
|---|
| 1910 | + |
|---|
| 1911 | + if (!console_drivers) |
|---|
| 1912 | + return; |
|---|
| 1913 | + |
|---|
| 1914 | + if (console_dropped) { |
|---|
| 1915 | + dropped_len = snprintf(dropped_text, sizeof(dropped_text), |
|---|
| 1916 | + "** %lu printk messages dropped **\n", |
|---|
| 1917 | + console_dropped); |
|---|
| 1918 | + console_dropped = 0; |
|---|
| 1919 | + } |
|---|
| 1920 | + |
|---|
| 1921 | + for_each_console(con) { |
|---|
| 1922 | + if (exclusive_console && con != exclusive_console) |
|---|
| 1923 | + continue; |
|---|
| 1924 | + if (!(con->flags & CON_ENABLED)) |
|---|
| 1925 | + continue; |
|---|
| 1926 | + if (!con->write) |
|---|
| 1927 | + continue; |
|---|
| 1928 | + if (!cpu_online(smp_processor_id()) && |
|---|
| 1929 | + !(con->flags & CON_ANYTIME)) |
|---|
| 1930 | + continue; |
|---|
| 1931 | + if (con->flags & CON_EXTENDED) |
|---|
| 1932 | + con->write(con, ext_text, ext_len); |
|---|
| 1933 | + else { |
|---|
| 1934 | + if (dropped_len) |
|---|
| 1935 | + con->write(con, dropped_text, dropped_len); |
|---|
| 1936 | + con->write(con, text, len); |
|---|
| 1937 | + } |
|---|
| 1938 | + } |
|---|
| 1939 | +} |
|---|
| 1940 | + |
|---|
| 1710 | 1941 | int printk_delay_msec __read_mostly; |
|---|
| 1711 | 1942 | |
|---|
| 1712 | | -static inline void printk_delay(int level) |
|---|
| 1943 | +static inline void printk_delay(void) |
|---|
| 1713 | 1944 | { |
|---|
| 1714 | | - boot_delay_msec(level); |
|---|
| 1715 | | - |
|---|
| 1716 | 1945 | if (unlikely(printk_delay_msec)) { |
|---|
| 1717 | 1946 | int m = printk_delay_msec; |
|---|
| 1718 | 1947 | |
|---|
| .. | .. |
|---|
| 1723 | 1952 | } |
|---|
| 1724 | 1953 | } |
|---|
| 1725 | 1954 | |
|---|
| 1726 | | -static bool kernel_sync_mode(void) |
|---|
| 1727 | | -{ |
|---|
| 1728 | | - return (oops_in_progress || sync_mode); |
|---|
| 1729 | | -} |
|---|
| 1730 | | - |
|---|
| 1731 | | -static bool console_can_sync(struct console *con) |
|---|
| 1732 | | -{ |
|---|
| 1733 | | - if (!(con->flags & CON_ENABLED)) |
|---|
| 1734 | | - return false; |
|---|
| 1735 | | - if (con->write_atomic && kernel_sync_mode()) |
|---|
| 1736 | | - return true; |
|---|
| 1737 | | - if (con->write_atomic && (con->flags & CON_HANDOVER) && !con->thread) |
|---|
| 1738 | | - return true; |
|---|
| 1739 | | - if (con->write && (con->flags & CON_BOOT) && !con->thread) |
|---|
| 1740 | | - return true; |
|---|
| 1741 | | - return false; |
|---|
| 1742 | | -} |
|---|
| 1743 | | - |
|---|
| 1744 | | -static bool call_sync_console_driver(struct console *con, const char *text, size_t text_len) |
|---|
| 1745 | | -{ |
|---|
| 1746 | | - if (!(con->flags & CON_ENABLED)) |
|---|
| 1747 | | - return false; |
|---|
| 1748 | | - if (con->write_atomic && kernel_sync_mode()) |
|---|
| 1749 | | - con->write_atomic(con, text, text_len); |
|---|
| 1750 | | - else if (con->write_atomic && (con->flags & CON_HANDOVER) && !con->thread) |
|---|
| 1751 | | - con->write_atomic(con, text, text_len); |
|---|
| 1752 | | - else if (con->write && (con->flags & CON_BOOT) && !con->thread) |
|---|
| 1753 | | - con->write(con, text, text_len); |
|---|
| 1754 | | - else |
|---|
| 1755 | | - return false; |
|---|
| 1756 | | - |
|---|
| 1757 | | - return true; |
|---|
| 1758 | | -} |
|---|
| 1759 | | - |
|---|
| 1760 | | -static bool have_atomic_console(void) |
|---|
| 1761 | | -{ |
|---|
| 1762 | | - struct console *con; |
|---|
| 1763 | | - |
|---|
| 1764 | | - for_each_console(con) { |
|---|
| 1765 | | - if (!(con->flags & CON_ENABLED)) |
|---|
| 1766 | | - continue; |
|---|
| 1767 | | - if (con->write_atomic) |
|---|
| 1768 | | - return true; |
|---|
| 1769 | | - } |
|---|
| 1770 | | - return false; |
|---|
| 1771 | | -} |
|---|
| 1772 | | - |
|---|
| 1773 | | -static bool print_sync(struct console *con, u64 *seq) |
|---|
| 1774 | | -{ |
|---|
| 1775 | | - struct printk_info info; |
|---|
| 1776 | | - struct printk_record r; |
|---|
| 1777 | | - size_t text_len; |
|---|
| 1778 | | - |
|---|
| 1779 | | - prb_rec_init_rd(&r, &info, &con->sync_buf[0], sizeof(con->sync_buf)); |
|---|
| 1780 | | - |
|---|
| 1781 | | - if (!prb_read_valid(prb, *seq, &r)) |
|---|
| 1782 | | - return false; |
|---|
| 1783 | | - |
|---|
| 1784 | | - text_len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time); |
|---|
| 1785 | | - |
|---|
| 1786 | | - if (!call_sync_console_driver(con, &con->sync_buf[0], text_len)) |
|---|
| 1787 | | - return false; |
|---|
| 1788 | | - |
|---|
| 1789 | | - *seq = r.info->seq; |
|---|
| 1790 | | - |
|---|
| 1791 | | - touch_softlockup_watchdog_sync(); |
|---|
| 1792 | | - clocksource_touch_watchdog(); |
|---|
| 1793 | | - rcu_cpu_stall_reset(); |
|---|
| 1794 | | - touch_nmi_watchdog(); |
|---|
| 1795 | | - |
|---|
| 1796 | | - if (text_len) |
|---|
| 1797 | | - printk_delay(r.info->level); |
|---|
| 1798 | | - |
|---|
| 1799 | | - return true; |
|---|
| 1800 | | -} |
|---|
| 1801 | | - |
|---|
| 1802 | | -static void print_sync_until(struct console *con, u64 seq) |
|---|
| 1803 | | -{ |
|---|
| 1804 | | - unsigned int flags; |
|---|
| 1805 | | - u64 printk_seq; |
|---|
| 1806 | | - |
|---|
| 1807 | | - console_atomic_lock(&flags); |
|---|
| 1808 | | - for (;;) { |
|---|
| 1809 | | - printk_seq = atomic64_read(&con->printk_seq); |
|---|
| 1810 | | - if (printk_seq >= seq) |
|---|
| 1811 | | - break; |
|---|
| 1812 | | - if (!print_sync(con, &printk_seq)) |
|---|
| 1813 | | - break; |
|---|
| 1814 | | - atomic64_set(&con->printk_seq, printk_seq + 1); |
|---|
| 1815 | | - } |
|---|
| 1816 | | - console_atomic_unlock(flags); |
|---|
| 1817 | | -} |
|---|
| 1818 | | - |
|---|
| 1819 | | -#ifdef CONFIG_PRINTK_NMI |
|---|
| 1820 | | -#define NUM_RECURSION_CTX 2 |
|---|
| 1821 | | -#else |
|---|
| 1822 | | -#define NUM_RECURSION_CTX 1 |
|---|
| 1823 | | -#endif |
|---|
| 1824 | | - |
|---|
| 1825 | | -struct printk_recursion { |
|---|
| 1826 | | - char count[NUM_RECURSION_CTX]; |
|---|
| 1827 | | -}; |
|---|
| 1828 | | - |
|---|
| 1829 | | -static DEFINE_PER_CPU(struct printk_recursion, percpu_printk_recursion); |
|---|
| 1830 | | -static char printk_recursion_count[NUM_RECURSION_CTX]; |
|---|
| 1831 | | - |
|---|
| 1832 | | -static char *printk_recursion_counter(void) |
|---|
| 1833 | | -{ |
|---|
| 1834 | | - struct printk_recursion *rec; |
|---|
| 1835 | | - char *count; |
|---|
| 1836 | | - |
|---|
| 1837 | | - if (!printk_percpu_data_ready()) { |
|---|
| 1838 | | - count = &printk_recursion_count[0]; |
|---|
| 1839 | | - } else { |
|---|
| 1840 | | - rec = this_cpu_ptr(&percpu_printk_recursion); |
|---|
| 1841 | | - |
|---|
| 1842 | | - count = &rec->count[0]; |
|---|
| 1843 | | - } |
|---|
| 1844 | | - |
|---|
| 1845 | | -#ifdef CONFIG_PRINTK_NMI |
|---|
| 1846 | | - if (in_nmi()) |
|---|
| 1847 | | - count++; |
|---|
| 1848 | | -#endif |
|---|
| 1849 | | - |
|---|
| 1850 | | - return count; |
|---|
| 1851 | | -} |
|---|
| 1852 | | - |
|---|
| 1853 | | -static bool printk_enter_irqsave(unsigned long *flags) |
|---|
| 1854 | | -{ |
|---|
| 1855 | | - char *count; |
|---|
| 1856 | | - |
|---|
| 1857 | | - local_irq_save(*flags); |
|---|
| 1858 | | - count = printk_recursion_counter(); |
|---|
| 1859 | | - /* Only 1 level of recursion allowed. */ |
|---|
| 1860 | | - if (*count > 1) { |
|---|
| 1861 | | - local_irq_restore(*flags); |
|---|
| 1862 | | - return false; |
|---|
| 1863 | | - } |
|---|
| 1864 | | - (*count)++; |
|---|
| 1865 | | - |
|---|
| 1866 | | - return true; |
|---|
| 1867 | | -} |
|---|
| 1868 | | - |
|---|
| 1869 | | -static void printk_exit_irqrestore(unsigned long flags) |
|---|
| 1870 | | -{ |
|---|
| 1871 | | - char *count; |
|---|
| 1872 | | - |
|---|
| 1873 | | - count = printk_recursion_counter(); |
|---|
| 1874 | | - (*count)--; |
|---|
| 1875 | | - local_irq_restore(flags); |
|---|
| 1876 | | -} |
|---|
| 1877 | | - |
|---|
| 1878 | 1955 | static inline u32 printk_caller_id(void) |
|---|
| 1879 | 1956 | { |
|---|
| 1880 | 1957 | return in_task() ? task_pid_nr(current) : |
|---|
| 1881 | 1958 | 0x80000000 + raw_smp_processor_id(); |
|---|
| 1882 | 1959 | } |
|---|
| 1883 | 1960 | |
|---|
| 1884 | | -/** |
|---|
| 1885 | | - * parse_prefix - Parse level and control flags. |
|---|
| 1886 | | - * |
|---|
| 1887 | | - * @text: The terminated text message. |
|---|
| 1888 | | - * @level: A pointer to the current level value, will be updated. |
|---|
| 1889 | | - * @lflags: A pointer to the current log flags, will be updated. |
|---|
| 1890 | | - * |
|---|
| 1891 | | - * @level may be NULL if the caller is not interested in the parsed value. |
|---|
| 1892 | | - * Otherwise the variable pointed to by @level must be set to |
|---|
| 1893 | | - * LOGLEVEL_DEFAULT in order to be updated with the parsed value. |
|---|
| 1894 | | - * |
|---|
| 1895 | | - * @lflags may be NULL if the caller is not interested in the parsed value. |
|---|
| 1896 | | - * Otherwise the variable pointed to by @lflags will be OR'd with the parsed |
|---|
| 1897 | | - * value. |
|---|
| 1898 | | - * |
|---|
| 1899 | | - * Return: The length of the parsed level and control flags. |
|---|
| 1900 | | - */ |
|---|
| 1901 | | -static u16 parse_prefix(char *text, int *level, enum log_flags *lflags) |
|---|
| 1902 | | -{ |
|---|
| 1903 | | - u16 prefix_len = 0; |
|---|
| 1904 | | - int kern_level; |
|---|
| 1905 | | - |
|---|
| 1906 | | - while (*text) { |
|---|
| 1907 | | - kern_level = printk_get_level(text); |
|---|
| 1908 | | - if (!kern_level) |
|---|
| 1909 | | - break; |
|---|
| 1910 | | - |
|---|
| 1911 | | - switch (kern_level) { |
|---|
| 1912 | | - case '0' ... '7': |
|---|
| 1913 | | - if (level && *level == LOGLEVEL_DEFAULT) |
|---|
| 1914 | | - *level = kern_level - '0'; |
|---|
| 1915 | | - break; |
|---|
| 1916 | | - case 'c': /* KERN_CONT */ |
|---|
| 1917 | | - if (lflags) |
|---|
| 1918 | | - *lflags |= LOG_CONT; |
|---|
| 1919 | | - } |
|---|
| 1920 | | - |
|---|
| 1921 | | - prefix_len += 2; |
|---|
| 1922 | | - text += 2; |
|---|
| 1923 | | - } |
|---|
| 1924 | | - |
|---|
| 1925 | | - return prefix_len; |
|---|
| 1926 | | -} |
|---|
| 1927 | | - |
|---|
| 1928 | | -static u16 printk_sprint(char *text, u16 size, int facility, enum log_flags *lflags, |
|---|
| 1929 | | - const char *fmt, va_list args) |
|---|
| 1930 | | -{ |
|---|
| 1931 | | - u16 text_len; |
|---|
| 1932 | | - |
|---|
| 1933 | | - text_len = vscnprintf(text, size, fmt, args); |
|---|
| 1934 | | - |
|---|
| 1935 | | - /* Mark and strip a trailing newline. */ |
|---|
| 1936 | | - if (text_len && text[text_len - 1] == '\n') { |
|---|
| 1937 | | - text_len--; |
|---|
| 1938 | | - *lflags |= LOG_NEWLINE; |
|---|
| 1939 | | - } |
|---|
| 1940 | | - |
|---|
| 1941 | | - /* Strip log level and control flags. */ |
|---|
| 1942 | | - if (facility == 0) { |
|---|
| 1943 | | - u16 prefix_len; |
|---|
| 1944 | | - |
|---|
| 1945 | | - prefix_len = parse_prefix(text, NULL, NULL); |
|---|
| 1946 | | - if (prefix_len) { |
|---|
| 1947 | | - text_len -= prefix_len; |
|---|
| 1948 | | - memmove(text, text + prefix_len, text_len); |
|---|
| 1949 | | - } |
|---|
| 1950 | | - } |
|---|
| 1951 | | - |
|---|
| 1952 | | - return text_len; |
|---|
| 1953 | | -} |
|---|
| 1954 | | - |
|---|
| 1955 | | -__printf(4, 0) |
|---|
| 1956 | | -static int vprintk_store(int facility, int level, |
|---|
| 1961 | +static size_t log_output(int facility, int level, enum log_flags lflags, |
|---|
| 1957 | 1962 | const struct dev_printk_info *dev_info, |
|---|
| 1958 | | - const char *fmt, va_list args) |
|---|
| 1963 | + char *text, size_t text_len) |
|---|
| 1959 | 1964 | { |
|---|
| 1960 | 1965 | const u32 caller_id = printk_caller_id(); |
|---|
| 1961 | | - struct prb_reserved_entry e; |
|---|
| 1966 | + |
|---|
| 1967 | + if (lflags & LOG_CONT) { |
|---|
| 1968 | + struct prb_reserved_entry e; |
|---|
| 1969 | + struct printk_record r; |
|---|
| 1970 | + |
|---|
| 1971 | + prb_rec_init_wr(&r, text_len); |
|---|
| 1972 | + if (prb_reserve_in_last(&e, prb, &r, caller_id, LOG_LINE_MAX)) { |
|---|
| 1973 | + memcpy(&r.text_buf[r.info->text_len], text, text_len); |
|---|
| 1974 | + r.info->text_len += text_len; |
|---|
| 1975 | + if (lflags & LOG_NEWLINE) { |
|---|
| 1976 | + r.info->flags |= LOG_NEWLINE; |
|---|
| 1977 | + prb_final_commit(&e); |
|---|
| 1978 | + } else { |
|---|
| 1979 | + prb_commit(&e); |
|---|
| 1980 | + } |
|---|
| 1981 | + |
|---|
| 1982 | + trace_android_vh_logbuf_pr_cont(&r, text_len); |
|---|
| 1983 | + return text_len; |
|---|
| 1984 | + } |
|---|
| 1985 | + } |
|---|
| 1986 | + |
|---|
| 1987 | + /* Store it in the record log */ |
|---|
| 1988 | + return log_store(caller_id, facility, level, lflags, 0, |
|---|
| 1989 | + dev_info, text, text_len); |
|---|
| 1990 | +} |
|---|
| 1991 | + |
|---|
| 1992 | +/* Must be called under logbuf_lock. */ |
|---|
| 1993 | +int vprintk_store(int facility, int level, |
|---|
| 1994 | + const struct dev_printk_info *dev_info, |
|---|
| 1995 | + const char *fmt, va_list args) |
|---|
| 1996 | +{ |
|---|
| 1997 | + static char textbuf[LOG_LINE_MAX]; |
|---|
| 1998 | + char *text = textbuf; |
|---|
| 1999 | + size_t text_len; |
|---|
| 1962 | 2000 | enum log_flags lflags = 0; |
|---|
| 1963 | | - bool final_commit = false; |
|---|
| 1964 | | - struct printk_record r; |
|---|
| 1965 | | - unsigned long irqflags; |
|---|
| 1966 | | - u16 trunc_msg_len = 0; |
|---|
| 1967 | | - char prefix_buf[8]; |
|---|
| 1968 | | - u16 reserve_size; |
|---|
| 1969 | | - va_list args2; |
|---|
| 1970 | | - u16 text_len; |
|---|
| 1971 | | - int ret = 0; |
|---|
| 1972 | | - u64 ts_nsec; |
|---|
| 1973 | | - u64 seq; |
|---|
| 1974 | 2001 | |
|---|
| 1975 | 2002 | /* |
|---|
| 1976 | | - * Since the duration of printk() can vary depending on the message |
|---|
| 1977 | | - * and state of the ringbuffer, grab the timestamp now so that it is |
|---|
| 1978 | | - * close to the call of printk(). This provides a more deterministic |
|---|
| 1979 | | - * timestamp with respect to the caller. |
|---|
| 2003 | + * The printf needs to come first; we need the syslog |
|---|
| 2004 | + * prefix which might be passed-in as a parameter. |
|---|
| 1980 | 2005 | */ |
|---|
| 1981 | | - ts_nsec = local_clock(); |
|---|
| 2006 | + text_len = vscnprintf(text, sizeof(textbuf), fmt, args); |
|---|
| 1982 | 2007 | |
|---|
| 1983 | | - if (!printk_enter_irqsave(&irqflags)) |
|---|
| 1984 | | - return 0; |
|---|
| 2008 | + /* mark and strip a trailing newline */ |
|---|
| 2009 | + if (text_len && text[text_len-1] == '\n') { |
|---|
| 2010 | + text_len--; |
|---|
| 2011 | + lflags |= LOG_NEWLINE; |
|---|
| 2012 | + } |
|---|
| 1985 | 2013 | |
|---|
| 1986 | | - /* |
|---|
| 1987 | | - * The sprintf needs to come first since the syslog prefix might be |
|---|
| 1988 | | - * passed in as a parameter. An extra byte must be reserved so that |
|---|
| 1989 | | - * later the vscnprintf() into the reserved buffer has room for the |
|---|
| 1990 | | - * terminating '\0', which is not counted by vsnprintf(). |
|---|
| 1991 | | - */ |
|---|
| 1992 | | - va_copy(args2, args); |
|---|
| 1993 | | - reserve_size = vsnprintf(&prefix_buf[0], sizeof(prefix_buf), fmt, args2) + 1; |
|---|
| 1994 | | - va_end(args2); |
|---|
| 2014 | + /* strip kernel syslog prefix and extract log level or control flags */ |
|---|
| 2015 | + if (facility == 0) { |
|---|
| 2016 | + int kern_level; |
|---|
| 1995 | 2017 | |
|---|
| 1996 | | - if (reserve_size > LOG_LINE_MAX) |
|---|
| 1997 | | - reserve_size = LOG_LINE_MAX; |
|---|
| 2018 | + while ((kern_level = printk_get_level(text)) != 0) { |
|---|
| 2019 | + switch (kern_level) { |
|---|
| 2020 | + case '0' ... '7': |
|---|
| 2021 | + if (level == LOGLEVEL_DEFAULT) |
|---|
| 2022 | + level = kern_level - '0'; |
|---|
| 2023 | + break; |
|---|
| 2024 | + case 'c': /* KERN_CONT */ |
|---|
| 2025 | + lflags |= LOG_CONT; |
|---|
| 2026 | + } |
|---|
| 1998 | 2027 | |
|---|
| 1999 | | - /* Extract log level or control flags. */ |
|---|
| 2000 | | - if (facility == 0) |
|---|
| 2001 | | - parse_prefix(&prefix_buf[0], &level, &lflags); |
|---|
| 2028 | + text_len -= 2; |
|---|
| 2029 | + text += 2; |
|---|
| 2030 | + } |
|---|
| 2031 | + } |
|---|
| 2002 | 2032 | |
|---|
| 2003 | 2033 | if (level == LOGLEVEL_DEFAULT) |
|---|
| 2004 | 2034 | level = default_message_loglevel; |
|---|
| .. | .. |
|---|
| 2006 | 2036 | if (dev_info) |
|---|
| 2007 | 2037 | lflags |= LOG_NEWLINE; |
|---|
| 2008 | 2038 | |
|---|
| 2009 | | - if (lflags & LOG_CONT) { |
|---|
| 2010 | | - prb_rec_init_wr(&r, reserve_size); |
|---|
| 2011 | | - if (prb_reserve_in_last(&e, prb, &r, caller_id, LOG_LINE_MAX)) { |
|---|
| 2012 | | - seq = r.info->seq; |
|---|
| 2013 | | - text_len = printk_sprint(&r.text_buf[r.info->text_len], reserve_size, |
|---|
| 2014 | | - facility, &lflags, fmt, args); |
|---|
| 2015 | | - r.info->text_len += text_len; |
|---|
| 2016 | | - |
|---|
| 2017 | | - if (lflags & LOG_NEWLINE) { |
|---|
| 2018 | | - r.info->flags |= LOG_NEWLINE; |
|---|
| 2019 | | - prb_final_commit(&e); |
|---|
| 2020 | | - final_commit = true; |
|---|
| 2021 | | - } else { |
|---|
| 2022 | | - prb_commit(&e); |
|---|
| 2023 | | - } |
|---|
| 2024 | | - |
|---|
| 2025 | | - ret = text_len; |
|---|
| 2026 | | - goto out; |
|---|
| 2027 | | - } |
|---|
| 2028 | | - } |
|---|
| 2029 | | - |
|---|
| 2030 | | - /* |
|---|
| 2031 | | - * Explicitly initialize the record before every prb_reserve() call. |
|---|
| 2032 | | - * prb_reserve_in_last() and prb_reserve() purposely invalidate the |
|---|
| 2033 | | - * structure when they fail. |
|---|
| 2034 | | - */ |
|---|
| 2035 | | - prb_rec_init_wr(&r, reserve_size); |
|---|
| 2036 | | - if (!prb_reserve(&e, prb, &r)) { |
|---|
| 2037 | | - /* truncate the message if it is too long for empty buffer */ |
|---|
| 2038 | | - truncate_msg(&reserve_size, &trunc_msg_len); |
|---|
| 2039 | | - |
|---|
| 2040 | | - prb_rec_init_wr(&r, reserve_size + trunc_msg_len); |
|---|
| 2041 | | - if (!prb_reserve(&e, prb, &r)) |
|---|
| 2042 | | - goto out; |
|---|
| 2043 | | - } |
|---|
| 2044 | | - |
|---|
| 2045 | | - seq = r.info->seq; |
|---|
| 2046 | | - |
|---|
| 2047 | | - /* fill message */ |
|---|
| 2048 | | - text_len = printk_sprint(&r.text_buf[0], reserve_size, facility, &lflags, fmt, args); |
|---|
| 2049 | | - if (trunc_msg_len) |
|---|
| 2050 | | - memcpy(&r.text_buf[text_len], trunc_msg, trunc_msg_len); |
|---|
| 2051 | | - r.info->text_len = text_len + trunc_msg_len; |
|---|
| 2052 | | - r.info->facility = facility; |
|---|
| 2053 | | - r.info->level = level & 7; |
|---|
| 2054 | | - r.info->flags = lflags & 0x1f; |
|---|
| 2055 | | - r.info->ts_nsec = ts_nsec; |
|---|
| 2056 | | - r.info->caller_id = caller_id; |
|---|
| 2057 | | - if (dev_info) |
|---|
| 2058 | | - memcpy(&r.info->dev_info, dev_info, sizeof(r.info->dev_info)); |
|---|
| 2059 | | - |
|---|
| 2060 | | - /* A message without a trailing newline can be continued. */ |
|---|
| 2061 | | - if (!(lflags & LOG_NEWLINE)) { |
|---|
| 2062 | | - prb_commit(&e); |
|---|
| 2063 | | - } else { |
|---|
| 2064 | | - prb_final_commit(&e); |
|---|
| 2065 | | - final_commit = true; |
|---|
| 2066 | | - } |
|---|
| 2067 | | - |
|---|
| 2068 | | - ret = text_len + trunc_msg_len; |
|---|
| 2069 | | -out: |
|---|
| 2070 | | - /* only the kernel may perform synchronous printing */ |
|---|
| 2071 | | - if (facility == 0 && final_commit) { |
|---|
| 2072 | | - struct console *con; |
|---|
| 2073 | | - |
|---|
| 2074 | | - for_each_console(con) { |
|---|
| 2075 | | - if (console_can_sync(con)) |
|---|
| 2076 | | - print_sync_until(con, seq + 1); |
|---|
| 2077 | | - } |
|---|
| 2078 | | - } |
|---|
| 2079 | | - |
|---|
| 2080 | | - printk_exit_irqrestore(irqflags); |
|---|
| 2081 | | - return ret; |
|---|
| 2039 | + return log_output(facility, level, lflags, dev_info, text, text_len); |
|---|
| 2082 | 2040 | } |
|---|
| 2083 | 2041 | |
|---|
| 2084 | 2042 | asmlinkage int vprintk_emit(int facility, int level, |
|---|
| .. | .. |
|---|
| 2086 | 2044 | const char *fmt, va_list args) |
|---|
| 2087 | 2045 | { |
|---|
| 2088 | 2046 | int printed_len; |
|---|
| 2047 | + bool in_sched = false; |
|---|
| 2048 | + unsigned long flags; |
|---|
| 2089 | 2049 | |
|---|
| 2090 | 2050 | /* Suppress unimportant messages after panic happens */ |
|---|
| 2091 | 2051 | if (unlikely(suppress_printk)) |
|---|
| 2092 | 2052 | return 0; |
|---|
| 2093 | 2053 | |
|---|
| 2094 | | - if (level == LOGLEVEL_SCHED) |
|---|
| 2054 | + if (level == LOGLEVEL_SCHED) { |
|---|
| 2095 | 2055 | level = LOGLEVEL_DEFAULT; |
|---|
| 2056 | + in_sched = true; |
|---|
| 2057 | + } |
|---|
| 2096 | 2058 | |
|---|
| 2059 | + boot_delay_msec(level); |
|---|
| 2060 | + printk_delay(); |
|---|
| 2061 | + |
|---|
| 2062 | + /* This stops the holder of console_sem just where we want him */ |
|---|
| 2063 | + logbuf_lock_irqsave(flags); |
|---|
| 2097 | 2064 | printed_len = vprintk_store(facility, level, dev_info, fmt, args); |
|---|
| 2065 | + logbuf_unlock_irqrestore(flags); |
|---|
| 2066 | + |
|---|
| 2067 | + /* If called from the scheduler, we can not call up(). */ |
|---|
| 2068 | + if (!in_sched) { |
|---|
| 2069 | + /* |
|---|
| 2070 | + * Disable preemption to avoid being preempted while holding |
|---|
| 2071 | + * console_sem which would prevent anyone from printing to |
|---|
| 2072 | + * console |
|---|
| 2073 | + */ |
|---|
| 2074 | + preempt_disable(); |
|---|
| 2075 | + /* |
|---|
| 2076 | + * Try to acquire and then immediately release the console |
|---|
| 2077 | + * semaphore. The release will print out buffers and wake up |
|---|
| 2078 | + * /dev/kmsg and syslog() users. |
|---|
| 2079 | + */ |
|---|
| 2080 | + if (console_trylock_spinning()) |
|---|
| 2081 | + console_unlock(); |
|---|
| 2082 | + preempt_enable(); |
|---|
| 2083 | + } |
|---|
| 2098 | 2084 | |
|---|
| 2099 | 2085 | wake_up_klogd(); |
|---|
| 2100 | 2086 | return printed_len; |
|---|
| 2101 | 2087 | } |
|---|
| 2102 | 2088 | EXPORT_SYMBOL(vprintk_emit); |
|---|
| 2103 | 2089 | |
|---|
| 2104 | | -__printf(1, 0) |
|---|
| 2105 | | -static int vprintk_default(const char *fmt, va_list args) |
|---|
| 2106 | | -{ |
|---|
| 2107 | | - return vprintk_emit(0, LOGLEVEL_DEFAULT, NULL, fmt, args); |
|---|
| 2108 | | -} |
|---|
| 2109 | | -__printf(1, 0) |
|---|
| 2110 | | -static int vprintk_func(const char *fmt, va_list args) |
|---|
| 2111 | | -{ |
|---|
| 2112 | | -#ifdef CONFIG_KGDB_KDB |
|---|
| 2113 | | - /* Allow to pass printk() to kdb but avoid a recursion. */ |
|---|
| 2114 | | - if (unlikely(kdb_trap_printk && kdb_printf_cpu < 0)) |
|---|
| 2115 | | - return vkdb_printf(KDB_MSGSRC_PRINTK, fmt, args); |
|---|
| 2116 | | -#endif |
|---|
| 2117 | | - return vprintk_default(fmt, args); |
|---|
| 2118 | | -} |
|---|
| 2119 | | - |
|---|
| 2120 | 2090 | asmlinkage int vprintk(const char *fmt, va_list args) |
|---|
| 2121 | 2091 | { |
|---|
| 2122 | 2092 | return vprintk_func(fmt, args); |
|---|
| 2123 | 2093 | } |
|---|
| 2124 | 2094 | EXPORT_SYMBOL(vprintk); |
|---|
| 2095 | + |
|---|
| 2096 | +int vprintk_default(const char *fmt, va_list args) |
|---|
| 2097 | +{ |
|---|
| 2098 | + return vprintk_emit(0, LOGLEVEL_DEFAULT, NULL, fmt, args); |
|---|
| 2099 | +} |
|---|
| 2100 | +EXPORT_SYMBOL_GPL(vprintk_default); |
|---|
| 2125 | 2101 | |
|---|
| 2126 | 2102 | /** |
|---|
| 2127 | 2103 | * printk - print a kernel message |
|---|
| .. | .. |
|---|
| 2157 | 2133 | } |
|---|
| 2158 | 2134 | EXPORT_SYMBOL(printk); |
|---|
| 2159 | 2135 | |
|---|
| 2160 | | -static int printk_kthread_func(void *data) |
|---|
| 2161 | | -{ |
|---|
| 2162 | | - struct console *con = data; |
|---|
| 2163 | | - unsigned long dropped = 0; |
|---|
| 2164 | | - char *dropped_text = NULL; |
|---|
| 2165 | | - struct printk_info info; |
|---|
| 2166 | | - struct printk_record r; |
|---|
| 2167 | | - char *ext_text = NULL; |
|---|
| 2168 | | - size_t dropped_len; |
|---|
| 2169 | | - int ret = -ENOMEM; |
|---|
| 2170 | | - char *text = NULL; |
|---|
| 2171 | | - char *write_text; |
|---|
| 2172 | | - u64 printk_seq; |
|---|
| 2173 | | - size_t len; |
|---|
| 2174 | | - int error; |
|---|
| 2175 | | - u64 seq; |
|---|
| 2176 | | - |
|---|
| 2177 | | - if (con->flags & CON_EXTENDED) { |
|---|
| 2178 | | - ext_text = kmalloc(CONSOLE_EXT_LOG_MAX, GFP_KERNEL); |
|---|
| 2179 | | - if (!ext_text) |
|---|
| 2180 | | - goto out; |
|---|
| 2181 | | - } |
|---|
| 2182 | | - text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL); |
|---|
| 2183 | | - dropped_text = kmalloc(64, GFP_KERNEL); |
|---|
| 2184 | | - if (!text || !dropped_text) |
|---|
| 2185 | | - goto out; |
|---|
| 2186 | | - |
|---|
| 2187 | | - if (con->flags & CON_EXTENDED) |
|---|
| 2188 | | - write_text = ext_text; |
|---|
| 2189 | | - else |
|---|
| 2190 | | - write_text = text; |
|---|
| 2191 | | - |
|---|
| 2192 | | - seq = atomic64_read(&con->printk_seq); |
|---|
| 2193 | | - |
|---|
| 2194 | | - prb_rec_init_rd(&r, &info, text, LOG_LINE_MAX + PREFIX_MAX); |
|---|
| 2195 | | - |
|---|
| 2196 | | - for (;;) { |
|---|
| 2197 | | - error = wait_event_interruptible(log_wait, |
|---|
| 2198 | | - prb_read_valid(prb, seq, &r) || kthread_should_stop()); |
|---|
| 2199 | | - |
|---|
| 2200 | | - if (kthread_should_stop()) |
|---|
| 2201 | | - break; |
|---|
| 2202 | | - |
|---|
| 2203 | | - if (error) |
|---|
| 2204 | | - continue; |
|---|
| 2205 | | - |
|---|
| 2206 | | - if (seq != r.info->seq) { |
|---|
| 2207 | | - dropped += r.info->seq - seq; |
|---|
| 2208 | | - seq = r.info->seq; |
|---|
| 2209 | | - } |
|---|
| 2210 | | - |
|---|
| 2211 | | - seq++; |
|---|
| 2212 | | - |
|---|
| 2213 | | - if (!(con->flags & CON_ENABLED)) |
|---|
| 2214 | | - continue; |
|---|
| 2215 | | - |
|---|
| 2216 | | - if (suppress_message_printing(r.info->level)) |
|---|
| 2217 | | - continue; |
|---|
| 2218 | | - |
|---|
| 2219 | | - if (con->flags & CON_EXTENDED) { |
|---|
| 2220 | | - len = info_print_ext_header(ext_text, |
|---|
| 2221 | | - CONSOLE_EXT_LOG_MAX, |
|---|
| 2222 | | - r.info); |
|---|
| 2223 | | - len += msg_print_ext_body(ext_text + len, |
|---|
| 2224 | | - CONSOLE_EXT_LOG_MAX - len, |
|---|
| 2225 | | - &r.text_buf[0], r.info->text_len, |
|---|
| 2226 | | - &r.info->dev_info); |
|---|
| 2227 | | - } else { |
|---|
| 2228 | | - len = record_print_text(&r, |
|---|
| 2229 | | - console_msg_format & MSG_FORMAT_SYSLOG, |
|---|
| 2230 | | - printk_time); |
|---|
| 2231 | | - } |
|---|
| 2232 | | - |
|---|
| 2233 | | - printk_seq = atomic64_read(&con->printk_seq); |
|---|
| 2234 | | - |
|---|
| 2235 | | - console_lock(); |
|---|
| 2236 | | - console_may_schedule = 0; |
|---|
| 2237 | | - |
|---|
| 2238 | | - if (kernel_sync_mode() && con->write_atomic) { |
|---|
| 2239 | | - console_unlock(); |
|---|
| 2240 | | - break; |
|---|
| 2241 | | - } |
|---|
| 2242 | | - |
|---|
| 2243 | | - if (!(con->flags & CON_EXTENDED) && dropped) { |
|---|
| 2244 | | - dropped_len = snprintf(dropped_text, 64, |
|---|
| 2245 | | - "** %lu printk messages dropped **\n", |
|---|
| 2246 | | - dropped); |
|---|
| 2247 | | - dropped = 0; |
|---|
| 2248 | | - |
|---|
| 2249 | | - con->write(con, dropped_text, dropped_len); |
|---|
| 2250 | | - printk_delay(r.info->level); |
|---|
| 2251 | | - } |
|---|
| 2252 | | - |
|---|
| 2253 | | - con->write(con, write_text, len); |
|---|
| 2254 | | - if (len) |
|---|
| 2255 | | - printk_delay(r.info->level); |
|---|
| 2256 | | - |
|---|
| 2257 | | - atomic64_cmpxchg_relaxed(&con->printk_seq, printk_seq, seq); |
|---|
| 2258 | | - |
|---|
| 2259 | | - console_unlock(); |
|---|
| 2260 | | - } |
|---|
| 2261 | | -out: |
|---|
| 2262 | | - kfree(dropped_text); |
|---|
| 2263 | | - kfree(text); |
|---|
| 2264 | | - kfree(ext_text); |
|---|
| 2265 | | - pr_info("%sconsole [%s%d]: printing thread stopped\n", |
|---|
| 2266 | | - (con->flags & CON_BOOT) ? "boot" : "", |
|---|
| 2267 | | - con->name, con->index); |
|---|
| 2268 | | - return ret; |
|---|
| 2269 | | -} |
|---|
| 2270 | | - |
|---|
| 2271 | | -/* Must be called within console_lock(). */ |
|---|
| 2272 | | -static void start_printk_kthread(struct console *con) |
|---|
| 2273 | | -{ |
|---|
| 2274 | | - /* No need to start a printing thread if the console cannot print. */ |
|---|
| 2275 | | - if (!con->write) |
|---|
| 2276 | | - return; |
|---|
| 2277 | | - |
|---|
| 2278 | | - con->thread = kthread_run(printk_kthread_func, con, |
|---|
| 2279 | | - "pr/%s%d", con->name, con->index); |
|---|
| 2280 | | - if (IS_ERR(con->thread)) { |
|---|
| 2281 | | - pr_err("%sconsole [%s%d]: unable to start printing thread\n", |
|---|
| 2282 | | - (con->flags & CON_BOOT) ? "boot" : "", |
|---|
| 2283 | | - con->name, con->index); |
|---|
| 2284 | | - return; |
|---|
| 2285 | | - } |
|---|
| 2286 | | - pr_info("%sconsole [%s%d]: printing thread started\n", |
|---|
| 2287 | | - (con->flags & CON_BOOT) ? "boot" : "", |
|---|
| 2288 | | - con->name, con->index); |
|---|
| 2289 | | -} |
|---|
| 2290 | | - |
|---|
| 2291 | | -/* protected by console_lock */ |
|---|
| 2292 | | -static bool kthreads_started; |
|---|
| 2293 | | - |
|---|
| 2294 | | -/* Must be called within console_lock(). */ |
|---|
| 2295 | | -static void console_try_thread(struct console *con) |
|---|
| 2296 | | -{ |
|---|
| 2297 | | - if (kthreads_started) { |
|---|
| 2298 | | - start_printk_kthread(con); |
|---|
| 2299 | | - return; |
|---|
| 2300 | | - } |
|---|
| 2301 | | - |
|---|
| 2302 | | - /* |
|---|
| 2303 | | - * The printing threads have not been started yet. If this console |
|---|
| 2304 | | - * can print synchronously, print all unprinted messages. |
|---|
| 2305 | | - */ |
|---|
| 2306 | | - if (console_can_sync(con)) |
|---|
| 2307 | | - print_sync_until(con, prb_next_seq(prb)); |
|---|
| 2308 | | -} |
|---|
| 2309 | | - |
|---|
| 2310 | 2136 | #else /* CONFIG_PRINTK */ |
|---|
| 2311 | 2137 | |
|---|
| 2312 | | -#define prb_first_valid_seq(rb) 0 |
|---|
| 2313 | | -#define prb_next_seq(rb) 0 |
|---|
| 2138 | +#define LOG_LINE_MAX 0 |
|---|
| 2139 | +#define PREFIX_MAX 0 |
|---|
| 2140 | +#define printk_time false |
|---|
| 2314 | 2141 | |
|---|
| 2315 | | -#define console_try_thread(con) |
|---|
| 2142 | +#define prb_read_valid(rb, seq, r) false |
|---|
| 2143 | +#define prb_first_valid_seq(rb) 0 |
|---|
| 2144 | + |
|---|
| 2145 | +static u64 syslog_seq; |
|---|
| 2146 | +static u64 console_seq; |
|---|
| 2147 | +static u64 exclusive_console_stop_seq; |
|---|
| 2148 | +static unsigned long console_dropped; |
|---|
| 2149 | + |
|---|
| 2150 | +static size_t record_print_text(const struct printk_record *r, |
|---|
| 2151 | + bool syslog, bool time) |
|---|
| 2152 | +{ |
|---|
| 2153 | + return 0; |
|---|
| 2154 | +} |
|---|
| 2155 | +static ssize_t info_print_ext_header(char *buf, size_t size, |
|---|
| 2156 | + struct printk_info *info) |
|---|
| 2157 | +{ |
|---|
| 2158 | + return 0; |
|---|
| 2159 | +} |
|---|
| 2160 | +static ssize_t msg_print_ext_body(char *buf, size_t size, |
|---|
| 2161 | + char *text, size_t text_len, |
|---|
| 2162 | + struct dev_printk_info *dev_info) { return 0; } |
|---|
| 2163 | +static void console_lock_spinning_enable(void) { } |
|---|
| 2164 | +static int console_lock_spinning_disable_and_check(void) { return 0; } |
|---|
| 2165 | +static void call_console_drivers(const char *ext_text, size_t ext_len, |
|---|
| 2166 | + const char *text, size_t len) {} |
|---|
| 2167 | +static bool suppress_message_printing(int level) { return false; } |
|---|
| 2316 | 2168 | |
|---|
| 2317 | 2169 | #endif /* CONFIG_PRINTK */ |
|---|
| 2318 | 2170 | |
|---|
| .. | .. |
|---|
| 2563 | 2415 | } |
|---|
| 2564 | 2416 | EXPORT_SYMBOL(is_console_locked); |
|---|
| 2565 | 2417 | |
|---|
| 2418 | +/* |
|---|
| 2419 | + * Check if we have any console that is capable of printing while cpu is |
|---|
| 2420 | + * booting or shutting down. Requires console_sem. |
|---|
| 2421 | + */ |
|---|
| 2422 | +static int have_callable_console(void) |
|---|
| 2423 | +{ |
|---|
| 2424 | + struct console *con; |
|---|
| 2425 | + |
|---|
| 2426 | + for_each_console(con) |
|---|
| 2427 | + if ((con->flags & CON_ENABLED) && |
|---|
| 2428 | + (con->flags & CON_ANYTIME)) |
|---|
| 2429 | + return 1; |
|---|
| 2430 | + |
|---|
| 2431 | + return 0; |
|---|
| 2432 | +} |
|---|
| 2433 | + |
|---|
| 2434 | +/* |
|---|
| 2435 | + * Can we actually use the console at this time on this cpu? |
|---|
| 2436 | + * |
|---|
| 2437 | + * Console drivers may assume that per-cpu resources have been allocated. So |
|---|
| 2438 | + * unless they're explicitly marked as being able to cope (CON_ANYTIME) don't |
|---|
| 2439 | + * call them until this CPU is officially up. |
|---|
| 2440 | + */ |
|---|
| 2441 | +static inline int can_use_console(void) |
|---|
| 2442 | +{ |
|---|
| 2443 | + return cpu_online(raw_smp_processor_id()) || have_callable_console(); |
|---|
| 2444 | +} |
|---|
| 2445 | + |
|---|
| 2566 | 2446 | /** |
|---|
| 2567 | 2447 | * console_unlock - unlock the console system |
|---|
| 2568 | 2448 | * |
|---|
| .. | .. |
|---|
| 2579 | 2459 | */ |
|---|
| 2580 | 2460 | void console_unlock(void) |
|---|
| 2581 | 2461 | { |
|---|
| 2462 | + static char ext_text[CONSOLE_EXT_LOG_MAX]; |
|---|
| 2463 | + static char text[LOG_LINE_MAX + PREFIX_MAX]; |
|---|
| 2464 | + unsigned long flags; |
|---|
| 2465 | + bool do_cond_resched, retry; |
|---|
| 2466 | + struct printk_info info; |
|---|
| 2467 | + struct printk_record r; |
|---|
| 2468 | + |
|---|
| 2582 | 2469 | if (console_suspended) { |
|---|
| 2583 | 2470 | up_console_sem(); |
|---|
| 2584 | 2471 | return; |
|---|
| 2585 | 2472 | } |
|---|
| 2586 | 2473 | |
|---|
| 2474 | + prb_rec_init_rd(&r, &info, text, sizeof(text)); |
|---|
| 2475 | + |
|---|
| 2476 | + /* |
|---|
| 2477 | + * Console drivers are called with interrupts disabled, so |
|---|
| 2478 | + * @console_may_schedule should be cleared before; however, we may |
|---|
| 2479 | + * end up dumping a lot of lines, for example, if called from |
|---|
| 2480 | + * console registration path, and should invoke cond_resched() |
|---|
| 2481 | + * between lines if allowable. Not doing so can cause a very long |
|---|
| 2482 | + * scheduling stall on a slow console leading to RCU stall and |
|---|
| 2483 | + * softlockup warnings which exacerbate the issue with more |
|---|
| 2484 | + * messages practically incapacitating the system. |
|---|
| 2485 | + * |
|---|
| 2486 | + * console_trylock() is not able to detect the preemptive |
|---|
| 2487 | + * context reliably. Therefore the value must be stored before |
|---|
| 2488 | + * and cleared after the "again" goto label. |
|---|
| 2489 | + */ |
|---|
| 2490 | + do_cond_resched = console_may_schedule; |
|---|
| 2491 | +again: |
|---|
| 2492 | + console_may_schedule = 0; |
|---|
| 2493 | + |
|---|
| 2494 | + /* |
|---|
| 2495 | + * We released the console_sem lock, so we need to recheck if |
|---|
| 2496 | + * cpu is online and (if not) is there at least one CON_ANYTIME |
|---|
| 2497 | + * console. |
|---|
| 2498 | + */ |
|---|
| 2499 | + if (!can_use_console()) { |
|---|
| 2500 | + console_locked = 0; |
|---|
| 2501 | + up_console_sem(); |
|---|
| 2502 | + return; |
|---|
| 2503 | + } |
|---|
| 2504 | + |
|---|
| 2505 | + for (;;) { |
|---|
| 2506 | + size_t ext_len = 0; |
|---|
| 2507 | + size_t len; |
|---|
| 2508 | + |
|---|
| 2509 | + printk_safe_enter_irqsave(flags); |
|---|
| 2510 | + raw_spin_lock(&logbuf_lock); |
|---|
| 2511 | +skip: |
|---|
| 2512 | + if (!prb_read_valid(prb, console_seq, &r)) |
|---|
| 2513 | + break; |
|---|
| 2514 | + |
|---|
| 2515 | + if (console_seq != r.info->seq) { |
|---|
| 2516 | + console_dropped += r.info->seq - console_seq; |
|---|
| 2517 | + console_seq = r.info->seq; |
|---|
| 2518 | + } |
|---|
| 2519 | + |
|---|
| 2520 | + if (suppress_message_printing(r.info->level)) { |
|---|
| 2521 | + /* |
|---|
| 2522 | + * Skip record we have buffered and already printed |
|---|
| 2523 | + * directly to the console when we received it, and |
|---|
| 2524 | + * record that has level above the console loglevel. |
|---|
| 2525 | + */ |
|---|
| 2526 | + console_seq++; |
|---|
| 2527 | + goto skip; |
|---|
| 2528 | + } |
|---|
| 2529 | + |
|---|
| 2530 | + /* Output to all consoles once old messages replayed. */ |
|---|
| 2531 | + if (unlikely(exclusive_console && |
|---|
| 2532 | + console_seq >= exclusive_console_stop_seq)) { |
|---|
| 2533 | + exclusive_console = NULL; |
|---|
| 2534 | + } |
|---|
| 2535 | + |
|---|
| 2536 | + /* |
|---|
| 2537 | + * Handle extended console text first because later |
|---|
| 2538 | + * record_print_text() will modify the record buffer in-place. |
|---|
| 2539 | + */ |
|---|
| 2540 | + if (nr_ext_console_drivers) { |
|---|
| 2541 | + ext_len = info_print_ext_header(ext_text, |
|---|
| 2542 | + sizeof(ext_text), |
|---|
| 2543 | + r.info); |
|---|
| 2544 | + ext_len += msg_print_ext_body(ext_text + ext_len, |
|---|
| 2545 | + sizeof(ext_text) - ext_len, |
|---|
| 2546 | + &r.text_buf[0], |
|---|
| 2547 | + r.info->text_len, |
|---|
| 2548 | + &r.info->dev_info); |
|---|
| 2549 | + } |
|---|
| 2550 | + len = record_print_text(&r, |
|---|
| 2551 | + console_msg_format & MSG_FORMAT_SYSLOG, |
|---|
| 2552 | + printk_time); |
|---|
| 2553 | + console_seq++; |
|---|
| 2554 | + raw_spin_unlock(&logbuf_lock); |
|---|
| 2555 | + |
|---|
| 2556 | + /* |
|---|
| 2557 | + * While actively printing out messages, if another printk() |
|---|
| 2558 | + * were to occur on another CPU, it may wait for this one to |
|---|
| 2559 | + * finish. This task can not be preempted if there is a |
|---|
| 2560 | + * waiter waiting to take over. |
|---|
| 2561 | + */ |
|---|
| 2562 | + console_lock_spinning_enable(); |
|---|
| 2563 | + |
|---|
| 2564 | + stop_critical_timings(); /* don't trace print latency */ |
|---|
| 2565 | + call_console_drivers(ext_text, ext_len, text, len); |
|---|
| 2566 | + start_critical_timings(); |
|---|
| 2567 | + |
|---|
| 2568 | + if (console_lock_spinning_disable_and_check()) { |
|---|
| 2569 | + printk_safe_exit_irqrestore(flags); |
|---|
| 2570 | + return; |
|---|
| 2571 | + } |
|---|
| 2572 | + |
|---|
| 2573 | + printk_safe_exit_irqrestore(flags); |
|---|
| 2574 | + |
|---|
| 2575 | + if (do_cond_resched) |
|---|
| 2576 | + cond_resched(); |
|---|
| 2577 | + } |
|---|
| 2578 | + |
|---|
| 2587 | 2579 | console_locked = 0; |
|---|
| 2588 | 2580 | |
|---|
| 2581 | + raw_spin_unlock(&logbuf_lock); |
|---|
| 2582 | + |
|---|
| 2589 | 2583 | up_console_sem(); |
|---|
| 2584 | + |
|---|
| 2585 | + /* |
|---|
| 2586 | + * Someone could have filled up the buffer again, so re-check if there's |
|---|
| 2587 | + * something to flush. In case we cannot trylock the console_sem again, |
|---|
| 2588 | + * there's a new owner and the console_unlock() from them will do the |
|---|
| 2589 | + * flush, no worries. |
|---|
| 2590 | + */ |
|---|
| 2591 | + raw_spin_lock(&logbuf_lock); |
|---|
| 2592 | + retry = prb_read_valid(prb, console_seq, NULL); |
|---|
| 2593 | + raw_spin_unlock(&logbuf_lock); |
|---|
| 2594 | + printk_safe_exit_irqrestore(flags); |
|---|
| 2595 | + |
|---|
| 2596 | + if (retry && console_trylock()) |
|---|
| 2597 | + goto again; |
|---|
| 2590 | 2598 | } |
|---|
| 2591 | 2599 | EXPORT_SYMBOL(console_unlock); |
|---|
| 2592 | 2600 | |
|---|
| .. | .. |
|---|
| 2636 | 2644 | */ |
|---|
| 2637 | 2645 | void console_flush_on_panic(enum con_flush_mode mode) |
|---|
| 2638 | 2646 | { |
|---|
| 2639 | | - struct console *c; |
|---|
| 2640 | | - u64 seq; |
|---|
| 2641 | | - |
|---|
| 2642 | | - if (!console_trylock()) |
|---|
| 2643 | | - return; |
|---|
| 2644 | | - |
|---|
| 2647 | + /* |
|---|
| 2648 | + * If someone else is holding the console lock, trylock will fail |
|---|
| 2649 | + * and may_schedule may be set. Ignore and proceed to unlock so |
|---|
| 2650 | + * that messages are flushed out. As this can be called from any |
|---|
| 2651 | + * context and we don't want to get preempted while flushing, |
|---|
| 2652 | + * ensure may_schedule is cleared. |
|---|
| 2653 | + */ |
|---|
| 2654 | + console_trylock(); |
|---|
| 2645 | 2655 | console_may_schedule = 0; |
|---|
| 2646 | 2656 | |
|---|
| 2647 | 2657 | if (mode == CONSOLE_REPLAY_ALL) { |
|---|
| 2648 | | - seq = prb_first_valid_seq(prb); |
|---|
| 2649 | | - for_each_console(c) |
|---|
| 2650 | | - atomic64_set(&c->printk_seq, seq); |
|---|
| 2651 | | - } |
|---|
| 2658 | + unsigned long flags; |
|---|
| 2652 | 2659 | |
|---|
| 2660 | + logbuf_lock_irqsave(flags); |
|---|
| 2661 | + console_seq = prb_first_valid_seq(prb); |
|---|
| 2662 | + logbuf_unlock_irqrestore(flags); |
|---|
| 2663 | + } |
|---|
| 2653 | 2664 | console_unlock(); |
|---|
| 2654 | 2665 | } |
|---|
| 2655 | 2666 | |
|---|
| .. | .. |
|---|
| 2784 | 2795 | */ |
|---|
| 2785 | 2796 | void register_console(struct console *newcon) |
|---|
| 2786 | 2797 | { |
|---|
| 2798 | + unsigned long flags; |
|---|
| 2787 | 2799 | struct console *bcon = NULL; |
|---|
| 2788 | 2800 | int err; |
|---|
| 2789 | 2801 | |
|---|
| .. | .. |
|---|
| 2806 | 2818 | } |
|---|
| 2807 | 2819 | } |
|---|
| 2808 | 2820 | } |
|---|
| 2809 | | - |
|---|
| 2810 | | - newcon->thread = NULL; |
|---|
| 2811 | 2821 | |
|---|
| 2812 | 2822 | if (console_drivers && console_drivers->flags & CON_BOOT) |
|---|
| 2813 | 2823 | bcon = console_drivers; |
|---|
| .. | .. |
|---|
| 2850 | 2860 | * the real console are the same physical device, it's annoying to |
|---|
| 2851 | 2861 | * see the beginning boot messages twice |
|---|
| 2852 | 2862 | */ |
|---|
| 2853 | | - if (bcon && ((newcon->flags & (CON_CONSDEV | CON_BOOT)) == CON_CONSDEV)) { |
|---|
| 2863 | + if (bcon && ((newcon->flags & (CON_CONSDEV | CON_BOOT)) == CON_CONSDEV)) |
|---|
| 2854 | 2864 | newcon->flags &= ~CON_PRINTBUFFER; |
|---|
| 2855 | | - newcon->flags |= CON_HANDOVER; |
|---|
| 2856 | | - } |
|---|
| 2857 | 2865 | |
|---|
| 2858 | 2866 | /* |
|---|
| 2859 | 2867 | * Put this console in the list - keep the |
|---|
| .. | .. |
|---|
| 2875 | 2883 | if (newcon->flags & CON_EXTENDED) |
|---|
| 2876 | 2884 | nr_ext_console_drivers++; |
|---|
| 2877 | 2885 | |
|---|
| 2878 | | - if (newcon->flags & CON_PRINTBUFFER) |
|---|
| 2879 | | - atomic64_set(&newcon->printk_seq, 0); |
|---|
| 2880 | | - else |
|---|
| 2881 | | - atomic64_set(&newcon->printk_seq, prb_next_seq(prb)); |
|---|
| 2882 | | - |
|---|
| 2883 | | - console_try_thread(newcon); |
|---|
| 2886 | + if (newcon->flags & CON_PRINTBUFFER) { |
|---|
| 2887 | + /* |
|---|
| 2888 | + * console_unlock(); will print out the buffered messages |
|---|
| 2889 | + * for us. |
|---|
| 2890 | + */ |
|---|
| 2891 | + logbuf_lock_irqsave(flags); |
|---|
| 2892 | + /* |
|---|
| 2893 | + * We're about to replay the log buffer. Only do this to the |
|---|
| 2894 | + * just-registered console to avoid excessive message spam to |
|---|
| 2895 | + * the already-registered consoles. |
|---|
| 2896 | + * |
|---|
| 2897 | + * Set exclusive_console with disabled interrupts to reduce |
|---|
| 2898 | + * race window with eventual console_flush_on_panic() that |
|---|
| 2899 | + * ignores console_lock. |
|---|
| 2900 | + */ |
|---|
| 2901 | + exclusive_console = newcon; |
|---|
| 2902 | + exclusive_console_stop_seq = console_seq; |
|---|
| 2903 | + console_seq = syslog_seq; |
|---|
| 2904 | + logbuf_unlock_irqrestore(flags); |
|---|
| 2905 | + } |
|---|
| 2884 | 2906 | console_unlock(); |
|---|
| 2885 | 2907 | console_sysfs_notify(); |
|---|
| 2886 | 2908 | |
|---|
| .. | .. |
|---|
| 2953 | 2975 | console->flags &= ~CON_ENABLED; |
|---|
| 2954 | 2976 | console_unlock(); |
|---|
| 2955 | 2977 | console_sysfs_notify(); |
|---|
| 2956 | | - |
|---|
| 2957 | | - if (console->thread && !IS_ERR(console->thread)) |
|---|
| 2958 | | - kthread_stop(console->thread); |
|---|
| 2959 | 2978 | |
|---|
| 2960 | 2979 | if (console->exit) |
|---|
| 2961 | 2980 | res = console->exit(console); |
|---|
| .. | .. |
|---|
| 3039 | 3058 | unregister_console(con); |
|---|
| 3040 | 3059 | } |
|---|
| 3041 | 3060 | } |
|---|
| 3042 | | - |
|---|
| 3043 | | -#ifdef CONFIG_PRINTK |
|---|
| 3044 | | - console_lock(); |
|---|
| 3045 | | - for_each_console(con) |
|---|
| 3046 | | - start_printk_kthread(con); |
|---|
| 3047 | | - kthreads_started = true; |
|---|
| 3048 | | - console_unlock(); |
|---|
| 3049 | | -#endif |
|---|
| 3050 | | - |
|---|
| 3051 | 3061 | ret = cpuhp_setup_state_nocalls(CPUHP_PRINTK_DEAD, "printk:dead", NULL, |
|---|
| 3052 | 3062 | console_cpu_notify); |
|---|
| 3053 | 3063 | WARN_ON(ret < 0); |
|---|
| .. | .. |
|---|
| 3063 | 3073 | * Delayed printk version, for scheduler-internal messages: |
|---|
| 3064 | 3074 | */ |
|---|
| 3065 | 3075 | #define PRINTK_PENDING_WAKEUP 0x01 |
|---|
| 3076 | +#define PRINTK_PENDING_OUTPUT 0x02 |
|---|
| 3066 | 3077 | |
|---|
| 3067 | 3078 | static DEFINE_PER_CPU(int, printk_pending); |
|---|
| 3068 | 3079 | |
|---|
| .. | .. |
|---|
| 3070 | 3081 | { |
|---|
| 3071 | 3082 | int pending = __this_cpu_xchg(printk_pending, 0); |
|---|
| 3072 | 3083 | |
|---|
| 3084 | + if (pending & PRINTK_PENDING_OUTPUT) { |
|---|
| 3085 | + /* If trylock fails, someone else is doing the printing */ |
|---|
| 3086 | + if (console_trylock()) |
|---|
| 3087 | + console_unlock(); |
|---|
| 3088 | + } |
|---|
| 3089 | + |
|---|
| 3073 | 3090 | if (pending & PRINTK_PENDING_WAKEUP) |
|---|
| 3074 | | - wake_up_interruptible_all(&log_wait); |
|---|
| 3091 | + wake_up_interruptible(&log_wait); |
|---|
| 3075 | 3092 | } |
|---|
| 3076 | 3093 | |
|---|
| 3077 | 3094 | static DEFINE_PER_CPU(struct irq_work, wake_up_klogd_work) = { |
|---|
| .. | .. |
|---|
| 3092 | 3109 | preempt_enable(); |
|---|
| 3093 | 3110 | } |
|---|
| 3094 | 3111 | |
|---|
| 3095 | | -__printf(1, 0) |
|---|
| 3096 | | -static int vprintk_deferred(const char *fmt, va_list args) |
|---|
| 3112 | +void defer_console_output(void) |
|---|
| 3097 | 3113 | { |
|---|
| 3098 | | - return vprintk_emit(0, LOGLEVEL_DEFAULT, NULL, fmt, args); |
|---|
| 3114 | + if (!printk_percpu_data_ready()) |
|---|
| 3115 | + return; |
|---|
| 3116 | + |
|---|
| 3117 | + preempt_disable(); |
|---|
| 3118 | + __this_cpu_or(printk_pending, PRINTK_PENDING_OUTPUT); |
|---|
| 3119 | + irq_work_queue(this_cpu_ptr(&wake_up_klogd_work)); |
|---|
| 3120 | + preempt_enable(); |
|---|
| 3121 | +} |
|---|
| 3122 | + |
|---|
| 3123 | +int vprintk_deferred(const char *fmt, va_list args) |
|---|
| 3124 | +{ |
|---|
| 3125 | + int r; |
|---|
| 3126 | + |
|---|
| 3127 | + r = vprintk_emit(0, LOGLEVEL_SCHED, NULL, fmt, args); |
|---|
| 3128 | + defer_console_output(); |
|---|
| 3129 | + |
|---|
| 3130 | + return r; |
|---|
| 3099 | 3131 | } |
|---|
| 3100 | 3132 | |
|---|
| 3101 | 3133 | int printk_deferred(const char *fmt, ...) |
|---|
| .. | .. |
|---|
| 3235 | 3267 | */ |
|---|
| 3236 | 3268 | void kmsg_dump(enum kmsg_dump_reason reason) |
|---|
| 3237 | 3269 | { |
|---|
| 3238 | | - struct kmsg_dumper_iter iter; |
|---|
| 3239 | 3270 | struct kmsg_dumper *dumper; |
|---|
| 3240 | | - |
|---|
| 3241 | | - if (!oops_in_progress) { |
|---|
| 3242 | | - /* |
|---|
| 3243 | | - * If atomic consoles are available, activate kernel sync mode |
|---|
| 3244 | | - * to make sure any final messages are visible. The trailing |
|---|
| 3245 | | - * printk message is important to flush any pending messages. |
|---|
| 3246 | | - */ |
|---|
| 3247 | | - if (have_atomic_console()) { |
|---|
| 3248 | | - sync_mode = true; |
|---|
| 3249 | | - pr_info("enabled sync mode\n"); |
|---|
| 3250 | | - } |
|---|
| 3251 | | - |
|---|
| 3252 | | - /* |
|---|
| 3253 | | - * Give the printing threads time to flush, allowing up to |
|---|
| 3254 | | - * 1s of no printing forward progress before giving up. |
|---|
| 3255 | | - */ |
|---|
| 3256 | | - pr_flush(1000, true); |
|---|
| 3257 | | - } |
|---|
| 3271 | + unsigned long flags; |
|---|
| 3258 | 3272 | |
|---|
| 3259 | 3273 | rcu_read_lock(); |
|---|
| 3260 | 3274 | list_for_each_entry_rcu(dumper, &dump_list, list) { |
|---|
| .. | .. |
|---|
| 3272 | 3286 | continue; |
|---|
| 3273 | 3287 | |
|---|
| 3274 | 3288 | /* initialize iterator with data about the stored records */ |
|---|
| 3275 | | - iter.active = true; |
|---|
| 3276 | | - kmsg_dump_rewind(&iter); |
|---|
| 3289 | + dumper->active = true; |
|---|
| 3290 | + |
|---|
| 3291 | + logbuf_lock_irqsave(flags); |
|---|
| 3292 | + dumper->cur_seq = clear_seq; |
|---|
| 3293 | + dumper->next_seq = prb_next_seq(prb); |
|---|
| 3294 | + logbuf_unlock_irqrestore(flags); |
|---|
| 3277 | 3295 | |
|---|
| 3278 | 3296 | /* invoke dumper which will iterate over records */ |
|---|
| 3279 | | - dumper->dump(dumper, reason, &iter); |
|---|
| 3297 | + dumper->dump(dumper, reason); |
|---|
| 3298 | + |
|---|
| 3299 | + /* reset iterator */ |
|---|
| 3300 | + dumper->active = false; |
|---|
| 3280 | 3301 | } |
|---|
| 3281 | 3302 | rcu_read_unlock(); |
|---|
| 3282 | 3303 | } |
|---|
| 3283 | 3304 | |
|---|
| 3284 | 3305 | /** |
|---|
| 3306 | + * kmsg_dump_get_line_nolock - retrieve one kmsg log line (unlocked version) |
|---|
| 3307 | + * @dumper: registered kmsg dumper |
|---|
| 3308 | + * @syslog: include the "<4>" prefixes |
|---|
| 3309 | + * @line: buffer to copy the line to |
|---|
| 3310 | + * @size: maximum size of the buffer |
|---|
| 3311 | + * @len: length of line placed into buffer |
|---|
| 3312 | + * |
|---|
| 3313 | + * Start at the beginning of the kmsg buffer, with the oldest kmsg |
|---|
| 3314 | + * record, and copy one record into the provided buffer. |
|---|
| 3315 | + * |
|---|
| 3316 | + * Consecutive calls will return the next available record moving |
|---|
| 3317 | + * towards the end of the buffer with the youngest messages. |
|---|
| 3318 | + * |
|---|
| 3319 | + * A return value of FALSE indicates that there are no more records to |
|---|
| 3320 | + * read. |
|---|
| 3321 | + * |
|---|
| 3322 | + * The function is similar to kmsg_dump_get_line(), but grabs no locks. |
|---|
| 3323 | + */ |
|---|
| 3324 | +bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog, |
|---|
| 3325 | + char *line, size_t size, size_t *len) |
|---|
| 3326 | +{ |
|---|
| 3327 | + struct printk_info info; |
|---|
| 3328 | + unsigned int line_count; |
|---|
| 3329 | + struct printk_record r; |
|---|
| 3330 | + size_t l = 0; |
|---|
| 3331 | + bool ret = false; |
|---|
| 3332 | + |
|---|
| 3333 | + prb_rec_init_rd(&r, &info, line, size); |
|---|
| 3334 | + |
|---|
| 3335 | + if (!dumper->active) |
|---|
| 3336 | + goto out; |
|---|
| 3337 | + |
|---|
| 3338 | + /* Read text or count text lines? */ |
|---|
| 3339 | + if (line) { |
|---|
| 3340 | + if (!prb_read_valid(prb, dumper->cur_seq, &r)) |
|---|
| 3341 | + goto out; |
|---|
| 3342 | + l = record_print_text(&r, syslog, printk_time); |
|---|
| 3343 | + } else { |
|---|
| 3344 | + if (!prb_read_valid_info(prb, dumper->cur_seq, |
|---|
| 3345 | + &info, &line_count)) { |
|---|
| 3346 | + goto out; |
|---|
| 3347 | + } |
|---|
| 3348 | + l = get_record_print_text_size(&info, line_count, syslog, |
|---|
| 3349 | + printk_time); |
|---|
| 3350 | + |
|---|
| 3351 | + } |
|---|
| 3352 | + |
|---|
| 3353 | + dumper->cur_seq = r.info->seq + 1; |
|---|
| 3354 | + ret = true; |
|---|
| 3355 | +out: |
|---|
| 3356 | + if (len) |
|---|
| 3357 | + *len = l; |
|---|
| 3358 | + return ret; |
|---|
| 3359 | +} |
|---|
| 3360 | + |
|---|
| 3361 | +/** |
|---|
| 3285 | 3362 | * kmsg_dump_get_line - retrieve one kmsg log line |
|---|
| 3286 | | - * @iter: kmsg dumper iterator |
|---|
| 3363 | + * @dumper: registered kmsg dumper |
|---|
| 3287 | 3364 | * @syslog: include the "<4>" prefixes |
|---|
| 3288 | 3365 | * @line: buffer to copy the line to |
|---|
| 3289 | 3366 | * @size: maximum size of the buffer |
|---|
| .. | .. |
|---|
| 3298 | 3375 | * A return value of FALSE indicates that there are no more records to |
|---|
| 3299 | 3376 | * read. |
|---|
| 3300 | 3377 | */ |
|---|
| 3301 | | -bool kmsg_dump_get_line(struct kmsg_dumper_iter *iter, bool syslog, |
|---|
| 3378 | +bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog, |
|---|
| 3302 | 3379 | char *line, size_t size, size_t *len) |
|---|
| 3303 | 3380 | { |
|---|
| 3304 | | - struct printk_info info; |
|---|
| 3305 | | - unsigned int line_count; |
|---|
| 3306 | | - struct printk_record r; |
|---|
| 3307 | | - size_t l = 0; |
|---|
| 3308 | | - bool ret = false; |
|---|
| 3381 | + unsigned long flags; |
|---|
| 3382 | + bool ret; |
|---|
| 3309 | 3383 | |
|---|
| 3310 | | - prb_rec_init_rd(&r, &info, line, size); |
|---|
| 3384 | + logbuf_lock_irqsave(flags); |
|---|
| 3385 | + ret = kmsg_dump_get_line_nolock(dumper, syslog, line, size, len); |
|---|
| 3386 | + logbuf_unlock_irqrestore(flags); |
|---|
| 3311 | 3387 | |
|---|
| 3312 | | - if (!iter->active) |
|---|
| 3313 | | - goto out; |
|---|
| 3314 | | - |
|---|
| 3315 | | - /* Read text or count text lines? */ |
|---|
| 3316 | | - if (line) { |
|---|
| 3317 | | - if (!prb_read_valid(prb, iter->cur_seq, &r)) |
|---|
| 3318 | | - goto out; |
|---|
| 3319 | | - l = record_print_text(&r, syslog, printk_time); |
|---|
| 3320 | | - } else { |
|---|
| 3321 | | - if (!prb_read_valid_info(prb, iter->cur_seq, |
|---|
| 3322 | | - &info, &line_count)) { |
|---|
| 3323 | | - goto out; |
|---|
| 3324 | | - } |
|---|
| 3325 | | - l = get_record_print_text_size(&info, line_count, syslog, |
|---|
| 3326 | | - printk_time); |
|---|
| 3327 | | - |
|---|
| 3328 | | - } |
|---|
| 3329 | | - |
|---|
| 3330 | | - iter->cur_seq = r.info->seq + 1; |
|---|
| 3331 | | - ret = true; |
|---|
| 3332 | | -out: |
|---|
| 3333 | | - if (len) |
|---|
| 3334 | | - *len = l; |
|---|
| 3335 | 3388 | return ret; |
|---|
| 3336 | 3389 | } |
|---|
| 3337 | 3390 | EXPORT_SYMBOL_GPL(kmsg_dump_get_line); |
|---|
| 3338 | 3391 | |
|---|
| 3339 | 3392 | /** |
|---|
| 3340 | 3393 | * kmsg_dump_get_buffer - copy kmsg log lines |
|---|
| 3341 | | - * @iter: kmsg dumper iterator |
|---|
| 3394 | + * @dumper: registered kmsg dumper |
|---|
| 3342 | 3395 | * @syslog: include the "<4>" prefixes |
|---|
| 3343 | 3396 | * @buf: buffer to copy the line to |
|---|
| 3344 | 3397 | * @size: maximum size of the buffer |
|---|
| .. | .. |
|---|
| 3355 | 3408 | * A return value of FALSE indicates that there are no more records to |
|---|
| 3356 | 3409 | * read. |
|---|
| 3357 | 3410 | */ |
|---|
| 3358 | | -bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool syslog, |
|---|
| 3359 | | - char *buf, size_t size, size_t *len_out) |
|---|
| 3411 | +bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog, |
|---|
| 3412 | + char *buf, size_t size, size_t *len) |
|---|
| 3360 | 3413 | { |
|---|
| 3361 | 3414 | struct printk_info info; |
|---|
| 3415 | + unsigned int line_count; |
|---|
| 3362 | 3416 | struct printk_record r; |
|---|
| 3417 | + unsigned long flags; |
|---|
| 3363 | 3418 | u64 seq; |
|---|
| 3364 | 3419 | u64 next_seq; |
|---|
| 3365 | | - size_t len = 0; |
|---|
| 3420 | + size_t l = 0; |
|---|
| 3366 | 3421 | bool ret = false; |
|---|
| 3367 | 3422 | bool time = printk_time; |
|---|
| 3368 | 3423 | |
|---|
| 3369 | | - if (!iter->active || !buf || !size) |
|---|
| 3424 | + prb_rec_init_rd(&r, &info, buf, size); |
|---|
| 3425 | + |
|---|
| 3426 | + if (!dumper->active || !buf || !size) |
|---|
| 3370 | 3427 | goto out; |
|---|
| 3371 | 3428 | |
|---|
| 3372 | | - if (prb_read_valid_info(prb, iter->cur_seq, &info, NULL)) { |
|---|
| 3373 | | - if (info.seq != iter->cur_seq) { |
|---|
| 3429 | + logbuf_lock_irqsave(flags); |
|---|
| 3430 | + if (prb_read_valid_info(prb, dumper->cur_seq, &info, NULL)) { |
|---|
| 3431 | + if (info.seq != dumper->cur_seq) { |
|---|
| 3374 | 3432 | /* messages are gone, move to first available one */ |
|---|
| 3375 | | - iter->cur_seq = info.seq; |
|---|
| 3433 | + dumper->cur_seq = info.seq; |
|---|
| 3376 | 3434 | } |
|---|
| 3377 | 3435 | } |
|---|
| 3378 | 3436 | |
|---|
| 3379 | 3437 | /* last entry */ |
|---|
| 3380 | | - if (iter->cur_seq >= iter->next_seq) |
|---|
| 3438 | + if (dumper->cur_seq >= dumper->next_seq) { |
|---|
| 3439 | + logbuf_unlock_irqrestore(flags); |
|---|
| 3381 | 3440 | goto out; |
|---|
| 3382 | | - |
|---|
| 3383 | | - /* |
|---|
| 3384 | | - * Find first record that fits, including all following records, |
|---|
| 3385 | | - * into the user-provided buffer for this dump. Pass in size-1 |
|---|
| 3386 | | - * because this function (by way of record_print_text()) will |
|---|
| 3387 | | - * not write more than size-1 bytes of text into @buf. |
|---|
| 3388 | | - */ |
|---|
| 3389 | | - seq = find_first_fitting_seq(iter->cur_seq, iter->next_seq, |
|---|
| 3390 | | - size - 1, syslog, time); |
|---|
| 3391 | | - |
|---|
| 3392 | | - /* |
|---|
| 3393 | | - * Next kmsg_dump_get_buffer() invocation will dump block of |
|---|
| 3394 | | - * older records stored right before this one. |
|---|
| 3395 | | - */ |
|---|
| 3396 | | - next_seq = seq; |
|---|
| 3397 | | - |
|---|
| 3398 | | - prb_rec_init_rd(&r, &info, buf, size); |
|---|
| 3399 | | - |
|---|
| 3400 | | - len = 0; |
|---|
| 3401 | | - prb_for_each_record(seq, prb, seq, &r) { |
|---|
| 3402 | | - if (r.info->seq >= iter->next_seq) |
|---|
| 3403 | | - break; |
|---|
| 3404 | | - |
|---|
| 3405 | | - len += record_print_text(&r, syslog, time); |
|---|
| 3406 | | - |
|---|
| 3407 | | - /* Adjust record to store to remaining buffer space. */ |
|---|
| 3408 | | - prb_rec_init_rd(&r, &info, buf + len, size - len); |
|---|
| 3409 | 3441 | } |
|---|
| 3410 | 3442 | |
|---|
| 3411 | | - iter->next_seq = next_seq; |
|---|
| 3443 | + /* calculate length of entire buffer */ |
|---|
| 3444 | + seq = dumper->cur_seq; |
|---|
| 3445 | + while (prb_read_valid_info(prb, seq, &info, &line_count)) { |
|---|
| 3446 | + if (r.info->seq >= dumper->next_seq) |
|---|
| 3447 | + break; |
|---|
| 3448 | + l += get_record_print_text_size(&info, line_count, syslog, time); |
|---|
| 3449 | + seq = r.info->seq + 1; |
|---|
| 3450 | + } |
|---|
| 3451 | + |
|---|
| 3452 | + /* move first record forward until length fits into the buffer */ |
|---|
| 3453 | + seq = dumper->cur_seq; |
|---|
| 3454 | + while (l >= size && prb_read_valid_info(prb, seq, |
|---|
| 3455 | + &info, &line_count)) { |
|---|
| 3456 | + if (r.info->seq >= dumper->next_seq) |
|---|
| 3457 | + break; |
|---|
| 3458 | + l -= get_record_print_text_size(&info, line_count, syslog, time); |
|---|
| 3459 | + seq = r.info->seq + 1; |
|---|
| 3460 | + } |
|---|
| 3461 | + |
|---|
| 3462 | + /* last message in next interation */ |
|---|
| 3463 | + next_seq = seq; |
|---|
| 3464 | + |
|---|
| 3465 | + /* actually read text into the buffer now */ |
|---|
| 3466 | + l = 0; |
|---|
| 3467 | + while (prb_read_valid(prb, seq, &r)) { |
|---|
| 3468 | + if (r.info->seq >= dumper->next_seq) |
|---|
| 3469 | + break; |
|---|
| 3470 | + |
|---|
| 3471 | + l += record_print_text(&r, syslog, time); |
|---|
| 3472 | + |
|---|
| 3473 | + /* adjust record to store to remaining buffer space */ |
|---|
| 3474 | + prb_rec_init_rd(&r, &info, buf + l, size - l); |
|---|
| 3475 | + |
|---|
| 3476 | + seq = r.info->seq + 1; |
|---|
| 3477 | + } |
|---|
| 3478 | + |
|---|
| 3479 | + dumper->next_seq = next_seq; |
|---|
| 3412 | 3480 | ret = true; |
|---|
| 3481 | + logbuf_unlock_irqrestore(flags); |
|---|
| 3413 | 3482 | out: |
|---|
| 3414 | | - if (len_out) |
|---|
| 3415 | | - *len_out = len; |
|---|
| 3483 | + if (len) |
|---|
| 3484 | + *len = l; |
|---|
| 3416 | 3485 | return ret; |
|---|
| 3417 | 3486 | } |
|---|
| 3418 | 3487 | EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer); |
|---|
| 3419 | 3488 | |
|---|
| 3420 | 3489 | /** |
|---|
| 3490 | + * kmsg_dump_rewind_nolock - reset the iterator (unlocked version) |
|---|
| 3491 | + * @dumper: registered kmsg dumper |
|---|
| 3492 | + * |
|---|
| 3493 | + * Reset the dumper's iterator so that kmsg_dump_get_line() and |
|---|
| 3494 | + * kmsg_dump_get_buffer() can be called again and used multiple |
|---|
| 3495 | + * times within the same dumper.dump() callback. |
|---|
| 3496 | + * |
|---|
| 3497 | + * The function is similar to kmsg_dump_rewind(), but grabs no locks. |
|---|
| 3498 | + */ |
|---|
| 3499 | +void kmsg_dump_rewind_nolock(struct kmsg_dumper *dumper) |
|---|
| 3500 | +{ |
|---|
| 3501 | + dumper->cur_seq = clear_seq; |
|---|
| 3502 | + dumper->next_seq = prb_next_seq(prb); |
|---|
| 3503 | +} |
|---|
| 3504 | + |
|---|
| 3505 | +/** |
|---|
| 3421 | 3506 | * kmsg_dump_rewind - reset the iterator |
|---|
| 3422 | | - * @iter: kmsg dumper iterator |
|---|
| 3507 | + * @dumper: registered kmsg dumper |
|---|
| 3423 | 3508 | * |
|---|
| 3424 | 3509 | * Reset the dumper's iterator so that kmsg_dump_get_line() and |
|---|
| 3425 | 3510 | * kmsg_dump_get_buffer() can be called again and used multiple |
|---|
| 3426 | 3511 | * times within the same dumper.dump() callback. |
|---|
| 3427 | 3512 | */ |
|---|
| 3428 | | -void kmsg_dump_rewind(struct kmsg_dumper_iter *iter) |
|---|
| 3513 | +void kmsg_dump_rewind(struct kmsg_dumper *dumper) |
|---|
| 3429 | 3514 | { |
|---|
| 3430 | | - iter->cur_seq = latched_seq_read_nolock(&clear_seq); |
|---|
| 3431 | | - iter->next_seq = prb_next_seq(prb); |
|---|
| 3515 | + unsigned long flags; |
|---|
| 3516 | + |
|---|
| 3517 | + logbuf_lock_irqsave(flags); |
|---|
| 3518 | + kmsg_dump_rewind_nolock(dumper); |
|---|
| 3519 | + logbuf_unlock_irqrestore(flags); |
|---|
| 3432 | 3520 | } |
|---|
| 3433 | 3521 | EXPORT_SYMBOL_GPL(kmsg_dump_rewind); |
|---|
| 3434 | 3522 | |
|---|
| 3435 | 3523 | #endif |
|---|
| 3436 | | - |
|---|
| 3437 | | -struct prb_cpulock { |
|---|
| 3438 | | - atomic_t owner; |
|---|
| 3439 | | - unsigned long __percpu *irqflags; |
|---|
| 3440 | | -}; |
|---|
| 3441 | | - |
|---|
| 3442 | | -#define DECLARE_STATIC_PRINTKRB_CPULOCK(name) \ |
|---|
| 3443 | | -static DEFINE_PER_CPU(unsigned long, _##name##_percpu_irqflags); \ |
|---|
| 3444 | | -static struct prb_cpulock name = { \ |
|---|
| 3445 | | - .owner = ATOMIC_INIT(-1), \ |
|---|
| 3446 | | - .irqflags = &_##name##_percpu_irqflags, \ |
|---|
| 3447 | | -} |
|---|
| 3448 | | - |
|---|
| 3449 | | -static bool __prb_trylock(struct prb_cpulock *cpu_lock, |
|---|
| 3450 | | - unsigned int *cpu_store) |
|---|
| 3451 | | -{ |
|---|
| 3452 | | - unsigned long *flags; |
|---|
| 3453 | | - unsigned int cpu; |
|---|
| 3454 | | - |
|---|
| 3455 | | - cpu = get_cpu(); |
|---|
| 3456 | | - |
|---|
| 3457 | | - *cpu_store = atomic_read(&cpu_lock->owner); |
|---|
| 3458 | | - /* memory barrier to ensure the current lock owner is visible */ |
|---|
| 3459 | | - smp_rmb(); |
|---|
| 3460 | | - if (*cpu_store == -1) { |
|---|
| 3461 | | - flags = per_cpu_ptr(cpu_lock->irqflags, cpu); |
|---|
| 3462 | | - local_irq_save(*flags); |
|---|
| 3463 | | - if (atomic_try_cmpxchg_acquire(&cpu_lock->owner, |
|---|
| 3464 | | - cpu_store, cpu)) { |
|---|
| 3465 | | - return true; |
|---|
| 3466 | | - } |
|---|
| 3467 | | - local_irq_restore(*flags); |
|---|
| 3468 | | - } else if (*cpu_store == cpu) { |
|---|
| 3469 | | - return true; |
|---|
| 3470 | | - } |
|---|
| 3471 | | - |
|---|
| 3472 | | - put_cpu(); |
|---|
| 3473 | | - return false; |
|---|
| 3474 | | -} |
|---|
| 3475 | | - |
|---|
| 3476 | | -/* |
|---|
| 3477 | | - * prb_lock: Perform a processor-reentrant spin lock. |
|---|
| 3478 | | - * @cpu_lock: A pointer to the lock object. |
|---|
| 3479 | | - * @cpu_store: A "flags" pointer to store lock status information. |
|---|
| 3480 | | - * |
|---|
| 3481 | | - * If no processor has the lock, the calling processor takes the lock and |
|---|
| 3482 | | - * becomes the owner. If the calling processor is already the owner of the |
|---|
| 3483 | | - * lock, this function succeeds immediately. If lock is locked by another |
|---|
| 3484 | | - * processor, this function spins until the calling processor becomes the |
|---|
| 3485 | | - * owner. |
|---|
| 3486 | | - * |
|---|
| 3487 | | - * It is safe to call this function from any context and state. |
|---|
| 3488 | | - */ |
|---|
| 3489 | | -static void prb_lock(struct prb_cpulock *cpu_lock, unsigned int *cpu_store) |
|---|
| 3490 | | -{ |
|---|
| 3491 | | - for (;;) { |
|---|
| 3492 | | - if (__prb_trylock(cpu_lock, cpu_store)) |
|---|
| 3493 | | - break; |
|---|
| 3494 | | - cpu_relax(); |
|---|
| 3495 | | - } |
|---|
| 3496 | | -} |
|---|
| 3497 | | - |
|---|
| 3498 | | -/* |
|---|
| 3499 | | - * prb_unlock: Perform a processor-reentrant spin unlock. |
|---|
| 3500 | | - * @cpu_lock: A pointer to the lock object. |
|---|
| 3501 | | - * @cpu_store: A "flags" object storing lock status information. |
|---|
| 3502 | | - * |
|---|
| 3503 | | - * Release the lock. The calling processor must be the owner of the lock. |
|---|
| 3504 | | - * |
|---|
| 3505 | | - * It is safe to call this function from any context and state. |
|---|
| 3506 | | - */ |
|---|
| 3507 | | -static void prb_unlock(struct prb_cpulock *cpu_lock, unsigned int cpu_store) |
|---|
| 3508 | | -{ |
|---|
| 3509 | | - unsigned long *flags; |
|---|
| 3510 | | - unsigned int cpu; |
|---|
| 3511 | | - |
|---|
| 3512 | | - cpu = atomic_read(&cpu_lock->owner); |
|---|
| 3513 | | - atomic_set_release(&cpu_lock->owner, cpu_store); |
|---|
| 3514 | | - |
|---|
| 3515 | | - if (cpu_store == -1) { |
|---|
| 3516 | | - flags = per_cpu_ptr(cpu_lock->irqflags, cpu); |
|---|
| 3517 | | - local_irq_restore(*flags); |
|---|
| 3518 | | - } |
|---|
| 3519 | | - |
|---|
| 3520 | | - put_cpu(); |
|---|
| 3521 | | -} |
|---|
| 3522 | | - |
|---|
| 3523 | | -DECLARE_STATIC_PRINTKRB_CPULOCK(printk_cpulock); |
|---|
| 3524 | | - |
|---|
| 3525 | | -void console_atomic_lock(unsigned int *flags) |
|---|
| 3526 | | -{ |
|---|
| 3527 | | - prb_lock(&printk_cpulock, flags); |
|---|
| 3528 | | -} |
|---|
| 3529 | | -EXPORT_SYMBOL(console_atomic_lock); |
|---|
| 3530 | | - |
|---|
| 3531 | | -void console_atomic_unlock(unsigned int flags) |
|---|
| 3532 | | -{ |
|---|
| 3533 | | - prb_unlock(&printk_cpulock, flags); |
|---|
| 3534 | | -} |
|---|
| 3535 | | -EXPORT_SYMBOL(console_atomic_unlock); |
|---|
| 3536 | | - |
|---|
| 3537 | | -static void pr_msleep(bool may_sleep, int ms) |
|---|
| 3538 | | -{ |
|---|
| 3539 | | - if (may_sleep) { |
|---|
| 3540 | | - msleep(ms); |
|---|
| 3541 | | - } else { |
|---|
| 3542 | | - while (ms--) |
|---|
| 3543 | | - udelay(1000); |
|---|
| 3544 | | - } |
|---|
| 3545 | | -} |
|---|
| 3546 | | - |
|---|
| 3547 | | -/** |
|---|
| 3548 | | - * pr_flush() - Wait for printing threads to catch up. |
|---|
| 3549 | | - * |
|---|
| 3550 | | - * @timeout_ms: The maximum time (in ms) to wait. |
|---|
| 3551 | | - * @reset_on_progress: Reset the timeout if forward progress is seen. |
|---|
| 3552 | | - * |
|---|
| 3553 | | - * A value of 0 for @timeout_ms means no waiting will occur. A value of -1 |
|---|
| 3554 | | - * represents infinite waiting. |
|---|
| 3555 | | - * |
|---|
| 3556 | | - * If @reset_on_progress is true, the timeout will be reset whenever any |
|---|
| 3557 | | - * printer has been seen to make some forward progress. |
|---|
| 3558 | | - * |
|---|
| 3559 | | - * Context: Any context. |
|---|
| 3560 | | - * Return: true if all enabled printers are caught up. |
|---|
| 3561 | | - */ |
|---|
| 3562 | | -bool pr_flush(int timeout_ms, bool reset_on_progress) |
|---|
| 3563 | | -{ |
|---|
| 3564 | | - int remaining = timeout_ms; |
|---|
| 3565 | | - struct console *con; |
|---|
| 3566 | | - u64 last_diff = 0; |
|---|
| 3567 | | - bool may_sleep; |
|---|
| 3568 | | - u64 printk_seq; |
|---|
| 3569 | | - u64 diff; |
|---|
| 3570 | | - u64 seq; |
|---|
| 3571 | | - |
|---|
| 3572 | | - may_sleep = (preemptible() && |
|---|
| 3573 | | - !in_softirq() && |
|---|
| 3574 | | - system_state >= SYSTEM_RUNNING); |
|---|
| 3575 | | - |
|---|
| 3576 | | - seq = prb_next_seq(prb); |
|---|
| 3577 | | - |
|---|
| 3578 | | - for (;;) { |
|---|
| 3579 | | - diff = 0; |
|---|
| 3580 | | - |
|---|
| 3581 | | - for_each_console(con) { |
|---|
| 3582 | | - if (!(con->flags & CON_ENABLED)) |
|---|
| 3583 | | - continue; |
|---|
| 3584 | | - if (!con->write && !con->write_atomic) |
|---|
| 3585 | | - continue; |
|---|
| 3586 | | - printk_seq = atomic64_read(&con->printk_seq); |
|---|
| 3587 | | - if (printk_seq < seq) |
|---|
| 3588 | | - diff += seq - printk_seq; |
|---|
| 3589 | | - } |
|---|
| 3590 | | - |
|---|
| 3591 | | - if (diff != last_diff && reset_on_progress) |
|---|
| 3592 | | - remaining = timeout_ms; |
|---|
| 3593 | | - |
|---|
| 3594 | | - if (!diff || remaining == 0) |
|---|
| 3595 | | - break; |
|---|
| 3596 | | - |
|---|
| 3597 | | - if (remaining < 0) { |
|---|
| 3598 | | - pr_msleep(may_sleep, 100); |
|---|
| 3599 | | - } else if (remaining < 100) { |
|---|
| 3600 | | - pr_msleep(may_sleep, remaining); |
|---|
| 3601 | | - remaining = 0; |
|---|
| 3602 | | - } else { |
|---|
| 3603 | | - pr_msleep(may_sleep, 100); |
|---|
| 3604 | | - remaining -= 100; |
|---|
| 3605 | | - } |
|---|
| 3606 | | - |
|---|
| 3607 | | - last_diff = diff; |
|---|
| 3608 | | - } |
|---|
| 3609 | | - |
|---|
| 3610 | | - return (diff == 0); |
|---|
| 3611 | | -} |
|---|
| 3612 | | -EXPORT_SYMBOL(pr_flush); |
|---|