Re: [PATCH 2/2 v6] printk: Add monotonic, boottime, and realtime timestamps

From: Mark Salyzyn
Date: Wed Aug 16 2017 - 11:43:50 EST


On 08/16/2017 08:17 AM, Prarit Bhargava wrote:
. . .
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fc47863f629c..f627a9bb97d1 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_set_timestamp(void);
+static u64 (*printk_get_ts)(void) = printk_set_timestamp;
+
/* 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;
. . .
+/**
+ * enum timestamp_sources - Timestamp sources for printk() messages.
+ * @PRINTK_TIME_UNDEFINED: Timestamp undefined. This option is not selectable
+ * from the configs, and is used as a reference in the code.
+ * @PRINTK_TIME_DISABLE: 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. On 32-bit
+ * systems selecting the real clock printk timestamp may lead to unlikely
+ * situations where a timestamp is wrong because the real time offset is read
+ * without the protection of a sequence lock when printk_get_ts() is set to
+ * printk_get_real_ns().
+ */
+enum timestamp_sources {
+ PRINTK_TIME_UNDEFINED = 0,
+ PRINTK_TIME_DISABLE = 1,
+ PRINTK_TIME_LOCAL = 2,
+ PRINTK_TIME_BOOT = 3,
+ PRINTK_TIME_MONO = 4,
+ PRINTK_TIME_REAL = 5,
+};
+. . .
+
+static u64 printk_set_timestamp(void)
+{
+ switch (printk_time) {
+ case PRINTK_TIME_LOCAL:
+ case PRINTK_TIME_DISABLE:
+ 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 = printk_get_real_ns;
+ break;
+ }
+ return printk_get_ts();
+}
I am really nervous about the default case, despite PRINTK_TIME_UNDEFINED being declared impossible. Either set printk_get_ts to local_clock for default: (which I prefer), or return (printk_get_ts != printk_set_timestamp) ? printk_get_ts() : 0; (which at least prevents the infinite loop).

+
+static int printk_time_set(const char *val, const struct kernel_param *kp)
+{
+ char *param = strstrip((char *)val);
+ int _printk_time = PRINTK_TIME_UNDEFINED;
+ int ts;
+
+ if (strlen(param) == 1) {
+ /* Preserve legacy boolean settings */
+ if ((param[0] == '0') || (param[0] == 'n') ||
+ (param[0] == 'N'))
+ _printk_time = PRINTK_TIME_DISABLE;
+ if ((param[0] == '1') || (param[0] == 'y') ||
+ (param[0] == 'Y'))
+ _printk_time = PRINTK_TIME_LOCAL;
+ }
+ if (_printk_time == PRINTK_TIME_UNDEFINED) {
+ for (ts = 0; ts < ARRAY_SIZE(timestamp_sources_str); ts++) {
+ if (!strncmp(timestamp_sources_str[ts], param,
+ strlen(param))) {
+ _printk_time = ts;
+ break;
+ }
+ }
+ }
+ if (_printk_time == PRINTK_TIME_UNDEFINED) {
+ pr_warn("printk: invalid timestamp option %s\n", param);
+ return -EINVAL;
+ }
+
+ /*
+ * Only allow enabling and disabling of the current printk_time
+ * setting. Changing it from one setting to another confuses
+ * userspace.
+ */
+ if (printk_time_source == PRINTK_TIME_UNDEFINED)
+ printk_time_source = _printk_time;
(I've asked this before) Could we add something like #ifndef PRINTK_TIME_DEBUG around the following to allow the option to chose for those that like to 'play' with the value?
+ else if ((printk_time_source != _printk_time) &&
+ (_printk_time != PRINTK_TIME_DISABLE)) {
+ pr_warn("printk: timestamp can only be set to 0, disabled, or %s\n",
+ timestamp_sources_str[printk_time_source]);
+ return -EINVAL;
+ }
+
-- Mark