[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: [Xen-devel] [PATCH 2/2] [RFC] xen/console: Provide timestamps as an offset since boot.



On 02/27/14 09:03, Andrew Cooper wrote:
** This is RFC, and not intended to be applied in its current state **

There exists a "console_timestamps" command line option which causes full
date/time stamps to be printed, e.g.

     (XEN) ENABLING IO-APIC IRQs
     (XEN)  -> Using old ACK method
     (XEN) ..TIMER: vector=0xF0 apic1=0 pin1=2 apic2=-1 pin2=-1
     (XEN) TSC deadline timer enabled
     (XEN) [2014-02-27 12:29:27] Platform timer is 14.318MHz HPET
     (XEN) [2014-02-27 12:29:27] Allocated console ring of 64 KiB.
     (XEN) [2014-02-27 12:29:27] mwait-idle: MWAIT substates: 0x21120

However, this only has single-second granularity.  This patch replaces the
string printed with one which matches Linux kernel timestamps, in seconds and
milliseconds since boot.

The result looks like:

     (XEN) [    0.158968] VMX: Supported advanced features:
     (XEN) [    0.159369]  - APIC TPR shadow
     (XEN) [    0.159771] HVM: ASIDs disabled.
     (XEN) [    0.160203] HVM: VMX enabled
     (XEN) [    0.160599] HVM: Hardware Assisted Paging (HAP) not detected

Although it looks rather worse interleaved with kernel timestamps:

     [    0.300276] pci 0000:00:1c.0: System wakeup disabled by ACPI
     (XEN) [    3.286620] PCI add device 0000:00:1c.0
     [    0.301169] pci 0000:00:1c.4: System wakeup disabled by ACPI
     (XEN) [    3.287508] PCI add device 0000:00:1c.4
     [    0.302078] pci 0000:00:1c.5: System wakeup disabled by ACPI
     (XEN) [    3.288420] PCI add device 0000:00:1c.5
     [    0.302899] pci 0000:00:1d.0: System wakeup disabled by ACPI
     (XEN) [    3.289229] PCI add device 0000:00:1d.0

Some latent bugs are emphasised by these changes.  There are steps in time
when the TSC scale is calculated, and when the platform time is initialised ...

     (XEN) [    0.000000] Using scheduler: SMP Credit Scheduler (credit)
     (XEN) [   27.553075] Detected 2793.232 MHz processor.
     (XEN) [   27.558277] Initing memory sharing.
     (XEN) [   27.562502] Cannot set CPU feature mask on CPU#0
     (XEN) [   27.567852] mce_intel.c:717: MCA Capability: BCAST 0 SER 0 CMCI 0 
firstbank 0 extended MCE MSR 18
     (XEN) [   27.577687] Intel machine check reporting enabled
     (XEN) [   27.583147] PCI: MCFG configuration 0: base e0000000 segment 0000 
buses 00 - 3f
     (XEN) [   27.591407] PCI: MCFG area at e0000000 reserved in E820
     (XEN) [   27.597369] PCI: Using MCFG for segment 0000 bus 00-3f
     (XEN) [   27.603238] I/O virtualisation disabled
     (XEN) [   27.608093] ENABLING IO-APIC IRQs
     (XEN) [   27.612136]  -> Using new ACK method
     (XEN) [   27.616601] ..TIMER: vector=0xF0 apic1=0 pin1=2 apic2=-1 pin2=-1
     (XEN) [    0.153431] Platform timer is 14.318MHz HPET

... and the synchronisation across CPUs needs to be earlier during AP bringup.

     (XEN) [    0.161004] HVM: PVH mode not supported on this platform
     (XEN) [    0.000000] Cannot set CPU feature mask on CPU#1
     (XEN) [    0.182299] Brought up 2 CPUs

Is it likely that people would want to still have the option for the full
date/timestamps?  If so, that code will have to be kept.

I would like to be able to select the old way.

Comments/suggestions welcome, especially regarding the interleaving of Xen and
dom0 timestamps.

Another option would be to just add the milliseconds to the current output.  
This might help with the interleaving.

   -Don Slutz

~Andrew
---
  xen/drivers/char/console.c |   12 +++++-------
  1 file changed, 5 insertions(+), 7 deletions(-)

diff --git a/xen/drivers/char/console.c b/xen/drivers/char/console.c
index 532c426..e2d9521 100644
--- a/xen/drivers/char/console.c
+++ b/xen/drivers/char/console.c
@@ -548,21 +548,19 @@ static int printk_prefix_check(char *p, char **pp)
static void printk_start_of_line(const char *prefix)
  {
-    struct tm tm;
      char tstr[32];
+    uint64_t sec, nsec;
__putstr(prefix); if ( !opt_console_timestamps )
          return;
- tm = wallclock_time();
-    if ( tm.tm_mday == 0 )
-        return;
+    sec = NOW();
+    nsec = do_div(sec, 1000000000);
- snprintf(tstr, sizeof(tstr), "[%04u-%02u-%02u %02u:%02u:%02u] ",
-             1900 + tm.tm_year, tm.tm_mon + 1, tm.tm_mday,
-             tm.tm_hour, tm.tm_min, tm.tm_sec);
+    snprintf(tstr, sizeof(tstr), "[%5"PRIu64".%06"PRIu64"] ",
+             sec, nsec/1000);
      __putstr(tstr);
  }


_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxx
http://lists.xen.org/xen-devel


 


Rackspace

Lists.xenproject.org is hosted with RackSpace, monitoring our
servers 24x7x365 and backed by RackSpace's Fanatical Support®.