On 09/26/2017 04:42 AM, tip-bot for Prarit Bhargava wrote:
> Commit-ID: 310b454a8653ea60d3eb21ce5ab03a282a32fbe1
> Gitweb: http://git.kernel.org/tip/310b454a8653ea60d3eb21ce5ab03a282a32fbe1
> Author: Prarit Bhargava <prarit@xxxxxxxxxx>
> AuthorDate: Mon, 18 Sep 2017 13:51:00 -0400
> Committer: Thomas Gleixner <tglx@xxxxxxxxxxxxx>
> CommitDate: Tue, 26 Sep 2017 10:38:07 +0200
>
> printk: Add monotonic, boottime, and realtime timestamps
>
> printk.time=1/CONFIG_PRINTK_TIME=1 adds a unmodified local hardware clock
> timestamp to printk messages. The local hardware clock loses time each
> day making it difficult to determine exactly when an issue has occurred in
> the kernel log, and making it difficult to determine how kernel and
> hardware issues relate to each other.
>
> Make printk output different timestamps by adding options for no timestamp,
> the local hardware clock, monotonic clock, boottime clock, and clock
> realtime. The default clock can be selected via:
>
> - Kconfig
> - Kernel command line parameter
> - Sysfs file
>
> Note, that existing user space tools might be confused by selecting clock
> realtime, so handle with care.
pmladek found a compile warning due to printk_time being unused. I will post a
v14 on LKML shortly.
P.
>
> [jstultz: Reworked Kconfig settings to avoid defconfig noise]
>
> Signed-off-by: Prarit Bhargava <prarit@xxxxxxxxxx>
> Signed-off-by: Thomas Gleixner <tglx@xxxxxxxxxxxxx>
> Cc: Joel Fernandes <joelaf@xxxxxxxxxx>
> Cc: Geert Uytterhoeven <geert+renesas@xxxxxxxxx>
> Cc: linux-doc@xxxxxxxxxxxxxxx
> Cc: Peter Zijlstra <peterz@xxxxxxxxxxxxx>
> Cc: Deepa Dinamani <deepa.kernel@xxxxxxxxx>
> Cc: Christoffer Dall <cdall@xxxxxxxxxx>
> Cc: "Jason A. Donenfeld" <Jason@xxxxxxxxx>
> Cc: Jonathan Corbet <corbet@xxxxxxx>
> Cc: "Paul E. McKenney" <paulmck@xxxxxxxxxxxxxxxxxx>
> Cc: Petr Mladek <pmladek@xxxxxxxx>
> Cc: Kees Cook <keescook@xxxxxxxxxxxx>
> Cc: Steven Rostedt <rostedt@xxxxxxxxxxx>
> Cc: Nicholas Piggin <npiggin@xxxxxxxxx>
> Cc: Josh Poimboeuf <jpoimboe@xxxxxxxxxx>
> Cc: Greg Kroah-Hartman <gregkh@xxxxxxxxxxxxxxxxxxx>
> Cc: Stephen Boyd <sboyd@xxxxxxxxxxxxxx>
> Cc: Mark Salyzyn <salyzyn@xxxxxxxxxxx>
> Cc: Sergey Senozhatsky <sergey.senozhatsky@xxxxxxxxx>
> Cc: "Luis R. Rodriguez" <mcgrof@xxxxxxxxxx>
> Cc: Olof Johansson <olof@xxxxxxxxx>
> Cc: Andrew Morton <akpm@xxxxxxxxxxxxxxxxxxxx>
> Link: https://lkml.kernel.org/r/1505757060-2004-4-git-send-email-prarit@xxxxxxxxxx
>
> ---
> Documentation/admin-guide/kernel-parameters.txt | 6 +-
> kernel/printk/printk.c | 130 +++++++++++++++++++++++-
> lib/Kconfig.debug | 48 ++++++++-
> 3 files changed, 176 insertions(+), 8 deletions(-)
>
> diff --git a/Documentation/admin-guide/kernel-parameters.txt b/Documentation/admin-guide/kernel-parameters.txt
> index 0549662..9a84483 100644
> --- a/Documentation/admin-guide/kernel-parameters.txt
> +++ b/Documentation/admin-guide/kernel-parameters.txt
> @@ -3211,8 +3211,10 @@
> ratelimit - ratelimit the logging
> Default: ratelimit
>
> - printk.time= Show timing data prefixed to each printk message line
> - Format: <bool> (1/Y/y=enable, 0/N/n=disable)
> + printk.time= Show timestamp prefixed to each printk message line
> + Format: <string>
> + (0/N/n/disable, 1/Y/y/local,
> + b/boot, m/monotonic, r/realtime (in UTC))
>
> processor.max_cstate= [HW,ACPI]
> Limit processor to maximum C-state
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 512f7c2..5e0bf2e 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -576,6 +576,9 @@ static u32 truncate_msg(u16 *text_len, u16 *trunc_msg_len,
> return msg_used_size(*text_len + *trunc_msg_len, 0, pad_len);
> }
>
> +static u64 printk_get_first_ts(void);
> +static u64 (*printk_get_ts)(void) = printk_get_first_ts;
> +
> /* insert record into the buffer, discard old ones, update heads */
> static int log_store(int facility, int level,
> enum log_flags flags, u64 ts_nsec,
> @@ -624,7 +627,7 @@ static int log_store(int facility, int level,
> if (ts_nsec > 0)
> msg->ts_nsec = ts_nsec;
> else
> - msg->ts_nsec = local_clock();
> + msg->ts_nsec = printk_get_ts();
> memset(log_dict(msg) + dict_len, 0, pad_len);
> msg->len = size;
>
> @@ -1201,14 +1204,130 @@ static inline void boot_delay_msec(int level)
> }
> #endif
>
> -static bool printk_time = IS_ENABLED(CONFIG_PRINTK_TIME);
> -module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
> +/**
> + * enum timestamp_sources - Timestamp sources for printk() messages.
> + * @PRINTK_TIME_DISABLED: No time stamp.
> + * @PRINTK_TIME_LOCAL: Local hardware clock timestamp.
> + * @PRINTK_TIME_BOOT: Boottime clock timestamp.
> + * @PRINTK_TIME_MONO: Monotonic clock timestamp.
> + * @PRINTK_TIME_REAL: Realtime clock timestamp.
> + */
> +enum timestamp_sources {
> + PRINTK_TIME_DISABLED = 0,
> + PRINTK_TIME_LOCAL = 1,
> + PRINTK_TIME_BOOT = 2,
> + PRINTK_TIME_MONO = 3,
> + PRINTK_TIME_REAL = 4,
> +};
> +
> +static const char * const timestamp_sources_str[5] = {
> + "disabled",
> + "local",
> + "boottime",
> + "monotonic",
> + "realtime",
> +};
> +
> +static int printk_time = CONFIG_PRINTK_TIME_TYPE;
> +
> +static int printk_set_ts_source(enum timestamp_sources ts_source)
> +{
> + int err = 0;
> +
> + switch (ts_source) {
> + case PRINTK_TIME_LOCAL:
> + printk_get_ts = local_clock;
> + break;
> + case PRINTK_TIME_BOOT:
> + printk_get_ts = ktime_get_boot_fast_ns;
> + break;
> + case PRINTK_TIME_MONO:
> + printk_get_ts = ktime_get_mono_fast_ns;
> + break;
> + case PRINTK_TIME_REAL:
> + printk_get_ts = ktime_get_real_fast_ns;
> + break;
> + case PRINTK_TIME_DISABLED:
> + /*
> + * The timestamp is always stored into the log buffer.
> + * Keep the current one.
> + */
> + break;
> + default:
> + err = -EINVAL;
> + break;
> + }
> +
> + if (!err)
> + printk_time = ts_source;
> + return err;
> +}
> +
> +static u64 printk_get_first_ts(void)
> +{
> + printk_set_ts_source(printk_time);
> +
> + /* Fallback for invalid or disabled timestamp source */
> + if (printk_get_ts == printk_get_first_ts)
> + printk_get_ts = local_clock;
> +
> + return printk_get_ts();
> +}
> +
> +static int param_set_time(const char *val, const struct kernel_param *kp)
> +{
> + char *param = strstrip((char *)val);
> + int time_source = -1;
> + int ts;
> + int err;
> +
> + if (strlen(param) == 1) {
> + /* Preserve legacy boolean settings */
> + if ((param[0] == '0') || (param[0] == 'n') ||
> + (param[0] == 'N'))
> + time_source = PRINTK_TIME_DISABLED;
> + if ((param[0] == '1') || (param[0] == 'y') ||
> + (param[0] == 'Y'))
> + time_source = PRINTK_TIME_LOCAL;
> + }
> + if (time_source == -1) {
> + for (ts = 0; ts < ARRAY_SIZE(timestamp_sources_str); ts++) {
> + if (!strncmp(timestamp_sources_str[ts], param,
> + strlen(param))) {
> + time_source = ts;
> + break;
> + }
> + }
> + }
> +
> + err = printk_set_ts_source(time_source);
> + if (err) {
> + pr_warn("printk: invalid timestamp option %s\n", param);
> + return err;
> + }
> +
> + pr_info("printk: timestamp set to %s\n",
> + timestamp_sources_str[printk_time]);
> + return 0;
> +}
> +
> +static int param_get_time(char *buffer, const struct kernel_param *kp)
> +{
> + return scnprintf(buffer, PAGE_SIZE, "%s",
> + timestamp_sources_str[printk_time]);
> +}
> +
> +static struct kernel_param_ops printk_time_ops = {
> + .set = param_set_time,
> + .get = param_get_time,
> +};
> +module_param_cb(time, &printk_time_ops, NULL, 0644);
>
> static size_t print_time(u64 ts, char *buf)
> {
> unsigned long rem_nsec;
>
> - if (!printk_time)
> + if (printk_time == PRINTK_TIME_DISABLED)
> return 0;
>
> rem_nsec = do_div(ts, 1000000000);
> @@ -1631,7 +1750,7 @@ static bool cont_add(int facility, int level, enum log_flags flags, const char *
> cont.facility = facility;
> cont.level = level;
> cont.owner = current;
> - cont.ts_nsec = local_clock();
> + cont.ts_nsec = printk_get_ts();
> cont.flags = flags;
> }
>
> @@ -1861,6 +1980,7 @@ static size_t msg_print_text(const struct printk_log *msg,
> bool syslog, char *buf, size_t size) { return 0; }
> static bool suppress_message_printing(int level) { return false; }
>
> +static int printk_time;
> #endif /* CONFIG_PRINTK */
>
> #ifdef CONFIG_EARLY_PRINTK
> diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
> index 2689b7c..c6401d3 100644
> --- a/lib/Kconfig.debug
> +++ b/lib/Kconfig.debug
> @@ -8,12 +8,58 @@ config PRINTK_TIME
> messages to be added to the output of the syslog() system
> call and at the console.
>
> +choice
> + prompt "printk default clock timestamp" if PRINTK_TIME
> + default PRINTK_TIME_LOCAL if PRINTK_TIME
> + help
> + This option is selected by setting one of
> + PRINTK_TIME_[DISABLE|LOCAL|BOOT|MONO|REAL] and causes time stamps of
> + the printk() messages to be added to the output of the syslog()
> + system call and at the console.
> +
> The timestamp is always recorded internally, and exported
> to /dev/kmsg. This flag just specifies if the timestamp should
> be included, not that the timestamp is recorded.
>
> The behavior is also controlled by the kernel command line
> - parameter printk.time=1. See Documentation/admin-guide/kernel-parameters.rst
> + parameter printk.time. See
> + Documentation/admin-guide/kernel-parameters.rst
> +
> +config PRINTK_TIME_LOCAL
> + bool "Local Clock"
> + help
> + Selecting this option causes the time stamps of printk() to be
> + stamped with the unadjusted hardware clock.
> +
> +config PRINTK_TIME_BOOT
> + bool "Boot Time Clock"
> + help
> + Selecting this option causes the time stamps of printk() to be
> + stamped with the adjusted boottime clock.
> +
> +config PRINTK_TIME_MONO
> + bool "Monotonic Clock"
> + help
> + Selecting this option causes the time stamps of printk() to be
> + stamped with the adjusted monotonic clock.
> +
> +config PRINTK_TIME_REAL
> + bool "Real Time Clock"
> + help
> + Selecting this option causes the time stamps of printk() to be
> + stamped with the adjusted realtime clock (UTC).
> +endchoice
> +
> +config PRINTK_TIME_TYPE
> + int
> + depends on PRINTK
> + range 0 4
> + default 0 if !PRINTK_TIME
> + default 1 if PRINTK_TIME_LOCAL
> + default 2 if PRINTK_TIME_BOOT
> + default 3 if PRINTK_TIME_MONO
> + default 4 if PRINTK_TIME_REAL
> +
>
> config CONSOLE_LOGLEVEL_DEFAULT
> int "Default console loglevel (1-15)"
>
--
To unsubscribe from this list: send the line "unsubscribe linux-tip-commits" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
|