[PATCH 1/2] mem_event: Return previous value of CR0/CR3/CR4 on change.

[PATCH 1/2] mem_event: Return previous value of CR0/CR3/CR4 on change.

[Andrew Cooper]

From: Tamas K Lengyel <tamas.lengyel@zentific.com>

This patch extends the information returned for CR0/CR3/CR4 register
write events with the previous value of the register. The old value
was already passed to the trap processing function, just never placed
into the returned request. By returning this value, applications
subscribing the CR events obtain additional context about the event.

Signed-off-by: Tamas K Lengyel <tamas.lengyel@zentific.com>
Acked-by: Tim Deegan <tim@xen.org>
---
 xen/arch/x86/hvm/hvm.c         |    4 ++++
 xen/include/public/mem_event.h |    6 +++---
 2 files changed, 7 insertions(+), 3 deletions(-)

diff --git a/xen/arch/x86/hvm/hvm.c b/xen/arch/x86/hvm/hvm.c
index 08fec34..9e85c13 100644
--- a/xen/arch/x86/hvm/hvm.c
+++ b/xen/arch/x86/hvm/hvm.c
@@ -4808,6 +4808,10 @@ static int hvm_memory_event_traps(long p, uint32_t reason,
         req.gla = gla;
         req.gla_valid = 1;
     }
+    else
+    {
+        req.gla = old;
+    }
     
     mem_event_put_request(d, &d->mem_event->access, &req);
     
diff --git a/xen/include/public/mem_event.h b/xen/include/public/mem_event.h
index c9ed546..3831b41 100644
--- a/xen/include/public/mem_event.h
+++ b/xen/include/public/mem_event.h
@@ -40,9 +40,9 @@
 /* Reasons for the memory event request */
 #define MEM_EVENT_REASON_UNKNOWN     0    /* typical reason */
 #define MEM_EVENT_REASON_VIOLATION   1    /* access violation, GFN is address */
-#define MEM_EVENT_REASON_CR0         2    /* CR0 was hit: gfn is CR0 value */
-#define MEM_EVENT_REASON_CR3         3    /* CR3 was hit: gfn is CR3 value */
-#define MEM_EVENT_REASON_CR4         4    /* CR4 was hit: gfn is CR4 value */
+#define MEM_EVENT_REASON_CR0         2    /* CR0 was hit: gfn is new CR0 value, gla is previous */
+#define MEM_EVENT_REASON_CR3         3    /* CR3 was hit: gfn is new CR3 value, gla is previous */
+#define MEM_EVENT_REASON_CR4         4    /* CR4 was hit: gfn is new CR4 value, gla is previous */
 #define MEM_EVENT_REASON_INT3        5    /* int3 was hit: gla/gfn are RIP */
 #define MEM_EVENT_REASON_SINGLESTEP  6    /* single step was invoked: gla/gfn are RIP */
 #define MEM_EVENT_REASON_MSR         7    /* MSR was hit: gfn is MSR value, gla is MSR address;
-- 
1.7.10.4

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

[Andrew Cooper]

** 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.

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

~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);
 }
 
-- 
1.7.10.4

Re: [PATCH 1/2] mem_event: Return previous value of CR0/CR3/CR4 on change.

[Andrew Cooper]

Apologies - Please ignore.

I am being particuarly dim with git send-email today.

~Andrew

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

[Tim Deegan]

At 14:03 +0000 on 27 Feb (1393506187), Andrew Cooper wrote:
> 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

The patch below fixes the first step for me.  I haven't been able to
understand the exact mechanism of the second one yet.  With this patch
applied, of course, the second step is not visible -- which doesn't
mean it's gone away.

Cheers,

Tim.

commit d986516ce297bbcf3181225105dbc67edfa7c37e
Author: Tim Deegan <tim@xen.org>
Date:   Thu Feb 27 16:17:02 2014 +0000

    x86/time: Always count s_time from Xen boot.
    
    In the early-boot clock, before the calibration routines kick in,
    count time from Xen boot rather than from when the BSP's TSC was 0.
    
    Signed-off-by: Tim Deegan <tim@xen.org>

diff --git a/xen/arch/x86/time.c b/xen/arch/x86/time.c
index 82492c1..2bc2b2d 100644
--- a/xen/arch/x86/time.c
+++ b/xen/arch/x86/time.c
@@ -1456,6 +1456,7 @@ void __init early_time_init(void)
     u64 tmp = init_pit_and_calibrate_tsc();
 
     set_time_scale(&this_cpu(cpu_time).tsc_scale, tmp);
+    rdtscll(this_cpu(cpu_time).local_tsc_stamp);
 
     do_div(tmp, 1000);
     cpu_khz = (unsigned long)tmp;

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

[Andrew Cooper]

On 27/02/14 16:21, Tim Deegan wrote:
> At 14:03 +0000 on 27 Feb (1393506187), Andrew Cooper wrote:
>> 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
> The patch below fixes the first step for me.  I haven't been able to
> understand the exact mechanism of the second one yet.  With this patch
> applied, of course, the second step is not visible -- which doesn't
> mean it's gone away.
>
> Cheers,
>
> Tim.
>
> commit d986516ce297bbcf3181225105dbc67edfa7c37e
> Author: Tim Deegan <tim@xen.org>
> Date:   Thu Feb 27 16:17:02 2014 +0000
>
>     x86/time: Always count s_time from Xen boot.
>     
>     In the early-boot clock, before the calibration routines kick in,
>     count time from Xen boot rather than from when the BSP's TSC was 0.
>     
>     Signed-off-by: Tim Deegan <tim@xen.org>

This does indeed fix the first step, although I will continue debugging
the second without this present.

However, as a time from boot, it would make more sense for the beginning
of __start_xen() (or even in the early asm code) to stash the TSC value
sideways.  I will see how easy this is to do.

~Andrew

>
> diff --git a/xen/arch/x86/time.c b/xen/arch/x86/time.c
> index 82492c1..2bc2b2d 100644
> --- a/xen/arch/x86/time.c
> +++ b/xen/arch/x86/time.c
> @@ -1456,6 +1456,7 @@ void __init early_time_init(void)
>      u64 tmp = init_pit_and_calibrate_tsc();
>  
>      set_time_scale(&this_cpu(cpu_time).tsc_scale, tmp);
> +    rdtscll(this_cpu(cpu_time).local_tsc_stamp);
>  
>      do_div(tmp, 1000);
>      cpu_khz = (unsigned long)tmp;
>

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

[Andrew Cooper]

On 27/02/14 17:50, Andrew Cooper wrote:
> On 27/02/14 16:21, Tim Deegan wrote:
>> At 14:03 +0000 on 27 Feb (1393506187), Andrew Cooper wrote:
>>> 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
>> The patch below fixes the first step for me.  I haven't been able to
>> understand the exact mechanism of the second one yet.  With this patch
>> applied, of course, the second step is not visible -- which doesn't
>> mean it's gone away.
>>
>> Cheers,
>>
>> Tim.
>>
>> commit d986516ce297bbcf3181225105dbc67edfa7c37e
>> Author: Tim Deegan <tim@xen.org>
>> Date:   Thu Feb 27 16:17:02 2014 +0000
>>
>>     x86/time: Always count s_time from Xen boot.
>>     
>>     In the early-boot clock, before the calibration routines kick in,
>>     count time from Xen boot rather than from when the BSP's TSC was 0.
>>     
>>     Signed-off-by: Tim Deegan <tim@xen.org>
> This does indeed fix the first step, although I will continue debugging
> the second without this present.
>
> However, as a time from boot, it would make more sense for the beginning
> of __start_xen() (or even in the early asm code) to stash the TSC value
> sideways.  I will see how easy this is to do.
>
> ~Andrew

And indeed, stashing the TSC in head.S result in:

(XEN) [    0.000000] IRQ limits: 24 GSI, 376 MSI/MSI-X
(XEN) [    0.000000] Using scheduler: SMP Credit Scheduler (credit)
(XEN) [    1.013174] Detected 2793.250 MHz processor.
(XEN) [    1.018377] Initing memory sharing.
(XEN) [    1.022601] Cannot set CPU feature mask on CPU#0
(XEN) [    1.027950] mce_intel.c:717: MCA Capability: BCAST 0 SER 0 CMCI
0 firstbank 0 extended MCE MSR 18
(XEN) [    1.037785] Intel machine check reporting enabled
(XEN) [    1.043245] PCI: MCFG configuration 0: base e0000000 segment
0000 buses 00 - 3f
(XEN) [    1.051509] PCI: MCFG area at e0000000 reserved in E820
(XEN) [    1.057471] PCI: Using MCFG for segment 0000 bus 00-3f
(XEN) [    1.063340] I/O virtualisation disabled
(XEN) [    1.068198] ENABLING IO-APIC IRQs
(XEN) [    1.072241]  -> Using new ACK method
(XEN) [    1.076706] ..TIMER: vector=0xF0 apic1=0 pin1=2 apic2=-1 pin2=-1
(XEN) [    0.470790] Platform timer is 14.318MHz HPET
(XEN) [    0.475474] Allocated console ring of 16 KiB.

Which is a rather more accurate time-since-boot, until the the platform
timer starts up and steps time backwards.

~Andrew

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

[Don Slutz]

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);
>   }
>