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

2017-08-16 Thread John Stultz 
> diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
> index 98fe715522e8..c303b235a0b1 100644
> --- a/lib/Kconfig.debug
> +++ b/lib/Kconfig.debug
> @@ -1,19 +1,61 @@
>  menu "printk and dmesg options"
>
> +choice
> +   prompt "printk default clock timestamp"
> +
> +config PRINTK_TIME_DISABLE
> +   bool "Disabled"
> +   help
> +Selecting this option disables the time stamps of printk().
> +
> +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 "CLOCK_BOOTTIME"
> +   help
> + Selecting this option causes the time stamps of printk() to be
> + stamped with the adjusted boottime clock.
> +
> +config PRINTK_TIME_MONO
> +   bool "CLOCK_MONOTONIC"
> +   help
> + Selecting this option causes the time stamps of printk() to be
> + stamped with the adjusted monotonic clock.
> +
> +config PRINTK_TIME_REAL
> +   bool "CLOCK_REALTIME"
> +   help
> + Selecting this option causes the time stamps of printk() to be
> + stamped with the adjusted realtime clock.
> +
> +endchoice
> +
>  config PRINTK_TIME
> -   bool "Show timing information on printks"
> +   int "Show timestamp information on printks"

You need to drop the prompt on this, as it ends up with this insane
setup where you chose from the choice list, but then you can go and
set the PRINTK_TIME manually to something else?

So PRINTK_TIME_REAL can be y, but PRINTK_TIME can be 2...  Yuck.

I'm still annoyed enough with this Kconfig/defconfig noise in the
patch that I'm going to take my own shot at it ( hopefully there's a
better way, but likely it will help me understand why it was done this
way :).

thanks
-john
--
To unsubscribe from this list: send the line "unsubscribe linux-doc" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

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

2017-08-16 Thread Mark Salyzyn 

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
--
To unsubscribe from this list: send the line "unsubscribe linux-doc" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

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

2017-08-16 Thread Prarit Bhargava 
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 in real time.

Make printk output different timestamps by adding options for no
timestamp, the local hardware clock, the monotonic clock, the boottime
clock, and the real clock.  Allow a user to pick one of the clocks by
using the printk.time kernel parameter.  Output the type of clock in
/sys/module/printk/parameters/time so userspace programs can interpret the
timestamp.

Real clock & 32-bit systems:  Selecting the real clock printk timestamp may
lead to unlikely situations where a timestamp is wrong because the real time
without the protection of a sequence lock when printk_get_ts() is set
printk_get_real_ns().

v2: Use peterz's suggested Kconfig options.  Merge patchset together.
Fix i386 !CONFIG_PRINTK builds.

v3: Fixed x86_64_defconfig. Added printk_time_type enum and
printk_time_str for better output. Added BOOTTIME clock functionality.

v4: Fix messages, add additional printk.time options, and fix configs.

v5: Renaming of structures, and allow printk_time_set() to
evaluate substrings of entries (eg: allow 'r', 'real', 'realtime').  From
peterz, make fast functions return 0 until timekeeping is initialized
(removes timekeeping_active & ktime_get_boot|real_log_ts() suggested by
 tglx and adds ktime_get_real_offset()).  Switch to a function pointer
for printk_get_ts() and reference fast functions.  Make timestamp_sources enum
match choice options for CONFIG_PRINTK_TIME (adds PRINTK_TIME_UNDEFINED).

v6: Define PRINTK_TIME_UNDEFINED for !CONFIG_PRINTK builds.  Separate
timekeeping changes into separate patch.  Minor include file cleanup.

Signed-off-by: Prarit Bhargava 
Cc: Mark Salyzyn 
Cc: Jonathan Corbet 
Cc: Petr Mladek 
Cc: Sergey Senozhatsky 
Cc: Steven Rostedt 
Cc: John Stultz 
Cc: Thomas Gleixner 
Cc: Stephen Boyd 
Cc: Andrew Morton 
Cc: Greg Kroah-Hartman 
Cc: "Paul E. McKenney" 
Cc: Christoffer Dall 
Cc: Deepa Dinamani 
Cc: Ingo Molnar 
Cc: Joel Fernandes 
Cc: Prarit Bhargava 
Cc: Kees Cook 
Cc: Peter Zijlstra 
Cc: Geert Uytterhoeven 
Cc: "Luis R. Rodriguez" 
Cc: Nicholas Piggin 
Cc: "Jason A. Donenfeld" 
Cc: Olof Johansson 
Cc: Josh Poimboeuf 
Cc: linux-doc@vger.kernel.org
---
 Documentation/admin-guide/kernel-parameters.txt|   6 +-
 arch/arm/configs/aspeed_g4_defconfig   |   2 +-
 arch/arm/configs/aspeed_g5_defconfig   |   2 +-
 arch/arm/configs/axm55xx_defconfig |   2 +-
 arch/arm/configs/bcm2835_defconfig |   2 +-
 arch/arm/configs/colibri_pxa270_defconfig  |   2 +-
 arch/arm/configs/colibri_pxa300_defconfig  |   2 +-
 arch/arm/configs/dove_defconfig|   2 +-
 arch/arm/configs/efm32_defconfig   |   2 +-
 arch/arm/configs/exynos_defconfig  |   2 +-
 arch/arm/configs/ezx_defconfig |   2 +-
 arch/arm/configs/h5000_defconfig   |   2 +-
 arch/arm/configs/hisi_defconfig|   2 +-
 arch/arm/configs/imote2_defconfig  |   2 +-
 arch/arm/configs/imx_v6_v7_defconfig   |   2 +-
 arch/arm/configs/keystone_defconfig|   2 +-
 arch/arm/configs/lpc18xx_defconfig |   2 +-
 arch/arm/configs/magician_defconfig|   2 +-
 arch/arm/configs/mmp2_defconfig|   2 +-
 arch/arm/configs/moxart_defconfig  |   2 +-
 arch/arm/configs/mps2_defconfig|   2 +-
 arch/arm/configs/multi_v7_defconfig|   2 +-
 arch/arm/configs/mvebu_v7_defconfig|   2 +-
 arch/arm/configs/mxs_defconfig |   2 +-
 arch/arm/configs/omap2plus_defconfig   |   2 +-
 arch/arm/configs/pxa168_defconfig  |   2 +-
 arch/arm/configs/pxa3xx_defconfig  |   2 +-
 arch/arm/configs/pxa910_defconfig  |   2 +-
 arch/arm/configs/pxa_defconfig |   2 +-
 arch/arm/configs/qcom_defconfig|   2 +-
 arch/arm/configs/raumfeld_defconfig|   2 +-
 arch/arm/configs/shmobile_defconfig|   2 +-
 arch/arm/configs/socfpga_defconfig |