Question to Xen log level in the case of PT

Question to Xen log level in the case of PT

[Chen, Tiejun]

All guys,

Sorry to raise a question to you since I'm not very sure how to deal 
with this.

When I passthrough a device like IGD, I can see so many messages:

"memory_map:add:...." and "memory_map:remove:"

since we have to add/remove all pages map residing PCI bar. Especially 
as a graphic device, oftentimes this range would occupy dozens of MB, 
even hundreds of MB. These print messages consume a lot of time to boot 
a VM. For instance, it takes about 5 minutes to boot a Windows guest on 
my BDW. But if I remove these output simply like this,

diff --git a/xen/common/domctl.c b/xen/common/domctl.c
index 7f959f3..82da9d1 100644
--- a/xen/common/domctl.c
+++ b/xen/common/domctl.c
@@ -1049,10 +1049,6 @@ long 
do_domctl(XEN_GUEST_HANDLE_PARAM(xen_domctl_t) u_domctl)

          if ( add )
          {
-            printk(XENLOG_G_INFO
-                   "memory_map:add: dom%d gfn=%lx mfn=%lx nr=%lx\n",
-                   d->domain_id, gfn, mfn, nr_mfns);
-
              ret = map_mmio_regions(d, gfn, nr_mfns, mfn);
              if ( ret )
                  printk(XENLOG_G_WARNING
@@ -1061,10 +1057,6 @@ long 
do_domctl(XEN_GUEST_HANDLE_PARAM(xen_domctl_t) u_domctl)
          }
          else
          {
-            printk(XENLOG_G_INFO
-                   "memory_map:remove: dom%d gfn=%lx mfn=%lx nr=%lx\n",
-                   d->domain_id, gfn, mfn, nr_mfns);
-
              ret = unmap_mmio_regions(d, gfn, nr_mfns, mfn);
              if ( ret && is_hardware_domain(current->domain) )
                  printk(XENLOG_ERR

its down to a half, about 2.5 minutes.

I know I can't delete this directly. But currently there are four log 
level on Xen side,

  *   XENLOG_ERR: Fatal errors, either Xen, Guest or Dom0
  *               is about to crash.
  *
  *   XENLOG_WARNING: Something bad happened, but we can recover.
  *
  *   XENLOG_INFO: Interesting stuff, but not too noisy.
  *
  *   XENLOG_DEBUG: Use where ever you like. Lots of noise.

looks I have to change XENLOG_G_INFO to XENLOG_G_WARNING but its not 
appropriate here.

So can Xen change log level dynamically like Linux? If yes, we might 
change this level temporarily while passing through IGD. If not, any 
suggestion?

Thanks
Tiejun

Re: Question to Xen log level in the case of PT

[Jan Beulich]

[-- Attachment #1: Type: text/plain, Size: 3288 bytes --]

>>> On 08.09.15 at 08:53, <tiejun.chen@intel.com> wrote:
> When I passthrough a device like IGD, I can see so many messages:
> 
> "memory_map:add:...." and "memory_map:remove:"
> 
> since we have to add/remove all pages map residing PCI bar. Especially 
> as a graphic device, oftentimes this range would occupy dozens of MB, 
> even hundreds of MB. These print messages consume a lot of time to boot 
> a VM. For instance, it takes about 5 minutes to boot a Windows guest on 
> my BDW. But if I remove these output simply like this,
> 
> diff --git a/xen/common/domctl.c b/xen/common/domctl.c
> index 7f959f3..82da9d1 100644
> --- a/xen/common/domctl.c
> +++ b/xen/common/domctl.c
> @@ -1049,10 +1049,6 @@ long do_domctl(XEN_GUEST_HANDLE_PARAM(xen_domctl_t) u_domctl)
> 
>           if ( add )
>           {
> -            printk(XENLOG_G_INFO
> -                   "memory_map:add: dom%d gfn=%lx mfn=%lx nr=%lx\n",
> -                   d->domain_id, gfn, mfn, nr_mfns);
> -
>               ret = map_mmio_regions(d, gfn, nr_mfns, mfn);
>               if ( ret )
>                   printk(XENLOG_G_WARNING
> @@ -1061,10 +1057,6 @@ long do_domctl(XEN_GUEST_HANDLE_PARAM(xen_domctl_t) u_domctl)
>           }
>           else
>           {
> -            printk(XENLOG_G_INFO
> -                   "memory_map:remove: dom%d gfn=%lx mfn=%lx nr=%lx\n",
> -                   d->domain_id, gfn, mfn, nr_mfns);
> -
>               ret = unmap_mmio_regions(d, gfn, nr_mfns, mfn);
>               if ( ret && is_hardware_domain(current->domain) )
>                   printk(XENLOG_ERR
> 
> its down to a half, about 2.5 minutes.
> 
> I know I can't delete this directly. But currently there are four log 
> level on Xen side,
> 
>   *   XENLOG_ERR: Fatal errors, either Xen, Guest or Dom0
>   *               is about to crash.
>   *
>   *   XENLOG_WARNING: Something bad happened, but we can recover.
>   *
>   *   XENLOG_INFO: Interesting stuff, but not too noisy.
>   *
>   *   XENLOG_DEBUG: Use where ever you like. Lots of noise.
> 
> looks I have to change XENLOG_G_INFO to XENLOG_G_WARNING but its not 
> appropriate here.

???

> So can Xen change log level dynamically like Linux? If yes, we might 
> change this level temporarily while passing through IGD. If not, any 
> suggestion?

First of all you could boot without lowering the log level (non-debug
builds) or raising the log level ("loglvl=warning"; debug builds). But
that would change the log level for the entire session, which may
not be what you're after. I too realized that having a way to
dynamically adjust the log level would be useful occasionally. For
post-4.6 I have a patch (attached) ready allowing to do so in a
limited way from the serial console (and hence also via "xl debug-key").
As you'll see in there I also took note of it probably being desirable
to have a sysctl (and then a wrapping xl command) to full control the
log level. I didn't get around to implement that yet.

Otoh the specific messages you cite are of quite questionable use
in the first place. I certainly would welcome a patch lowering their
priority to XENLOG_G_DEBUG (which however would still not
change behavior in the default debug build case).

Jan


[-- Attachment #2: loglvl-adjust.patch --]
[-- Type: text/plain, Size: 3222 bytes --]


Note that upper thresholds are sticky, i.e. while they get adjusted
upwards when the lower threshold would otherwise end up above the upper
one, they don't get adjusted when reducing the lower one.

---
TBD: Should we also add a (more flexible) sysctl?

--- unstable.orig/xen/drivers/char/console.c	2015-08-13 12:13:27.000000000 +0200
+++ unstable/xen/drivers/char/console.c	2015-08-13 14:24:46.000000000 +0200
@@ -168,7 +168,7 @@ static void __init parse_guest_loglvl(ch
     _parse_loglvl(s, &xenlog_guest_lower_thresh, &xenlog_guest_upper_thresh);
 }
 
-static char * __init loglvl_str(int lvl)
+static char *loglvl_str(int lvl)
 {
     switch ( lvl )
     {
@@ -181,6 +181,66 @@ static char * __init loglvl_str(int lvl)
     return "???";
 }
 
+static int *__read_mostly upper_thresh_adj = &xenlog_upper_thresh;
+static int *__read_mostly lower_thresh_adj = &xenlog_lower_thresh;
+static const char *__read_mostly thresh_adj = "standard";
+
+static void do_toggle_guest(unsigned char key, struct cpu_user_regs *regs)
+{
+    if ( upper_thresh_adj == &xenlog_upper_thresh )
+    {
+        upper_thresh_adj = &xenlog_guest_upper_thresh;
+        lower_thresh_adj = &xenlog_guest_lower_thresh;
+        thresh_adj = "guest";
+    }
+    else
+    {
+        upper_thresh_adj = &xenlog_upper_thresh;
+        lower_thresh_adj = &xenlog_lower_thresh;
+        thresh_adj = "standard";
+    }
+    printk("'%c' pressed -> %s log level adjustments enabled\n",
+           key, thresh_adj);
+}
+
+static void do_adj_thresh(unsigned char key)
+{
+    if ( *upper_thresh_adj < *lower_thresh_adj )
+        *upper_thresh_adj = *lower_thresh_adj;
+    printk("'%c' pressed -> %s log level: %s (rate limited %s)\n",
+           key, thresh_adj, loglvl_str(*lower_thresh_adj),
+           loglvl_str(*upper_thresh_adj));
+}
+
+static void do_inc_thresh(unsigned char key, struct cpu_user_regs *regs)
+{
+    ++*lower_thresh_adj;
+    do_adj_thresh(key);
+}
+
+static void do_dec_thresh(unsigned char key, struct cpu_user_regs *regs)
+{
+    if ( *lower_thresh_adj )
+        --*lower_thresh_adj;
+    do_adj_thresh(key);
+}
+
+static struct keyhandler inc_thresh_keyhandler = {
+    .irq_callback = 1,
+    .u.irq_fn = do_inc_thresh,
+    .desc = "increase log level threshold"
+};
+static struct keyhandler dec_thresh_keyhandler = {
+    .irq_callback = 1,
+    .u.irq_fn = do_dec_thresh,
+    .desc = "decrease log level threshold"
+};
+static struct keyhandler toggle_guest_keyhandler = {
+    .irq_callback = 1,
+    .u.irq_fn = do_toggle_guest,
+    .desc = "toggle host/guest log level adjustment"
+};
+
 /*
  * ********************************************************
  * *************** ACCESS TO CONSOLE RING *****************
@@ -834,6 +894,9 @@ void __init console_endboot(void)
         xen_rx = !xen_rx;
 
     register_keyhandler('w', &dump_console_ring_keyhandler);
+    register_keyhandler('+', &inc_thresh_keyhandler);
+    register_keyhandler('-', &dec_thresh_keyhandler);
+    register_keyhandler('G', &toggle_guest_keyhandler);
 
     /* Serial input is directed to DOM0 by default. */
     switch_serial_input();

[-- Attachment #3: Type: text/plain, Size: 126 bytes --]

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

Re: Question to Xen log level in the case of PT

[Chen, Tiejun]

>> So can Xen change log level dynamically like Linux? If yes, we might
>> change this level temporarily while passing through IGD. If not, any
>> suggestion?
>
> First of all you could boot without lowering the log level (non-debug
> builds) or raising the log level ("loglvl=warning"; debug builds). But

Sorry I don't know how to build "non-debug" here. Could you give me this 
detail? Or where I can get this info?

> that would change the log level for the entire session, which may
> not be what you're after. I too realized that having a way to
> dynamically adjust the log level would be useful occasionally. For
> post-4.6 I have a patch (attached) ready allowing to do so in a
> limited way from the serial console (and hence also via "xl debug-key").
> As you'll see in there I also took note of it probably being desirable
> to have a sysctl (and then a wrapping xl command) to full control the
> log level. I didn't get around to implement that yet.

Good to know this.

>
> Otoh the specific messages you cite are of quite questionable use
> in the first place. I certainly would welcome a patch lowering their
> priority to XENLOG_G_DEBUG (which however would still not

Done.

Thanks
Tiejun

Re: Question to Xen log level in the case of PT

[Jan Beulich]

>>> On 09.09.15 at 08:53, <tiejun.chen@intel.com> wrote:
>> > So can Xen change log level dynamically like Linux? If yes, we might
>>> change this level temporarily while passing through IGD. If not, any
>>> suggestion?
>>
>> First of all you could boot without lowering the log level (non-debug
>> builds) or raising the log level ("loglvl=warning"; debug builds). But
> 
> Sorry I don't know how to build "non-debug" here. Could you give me this 
> detail? Or where I can get this info?

Config.mk has

# A debug build of Xen and tools?
debug ?= y
debug_symbols ?= $(debug)

which you can alter or override on the make command line or in
.config. But for development purposes you really want to build
debug mode binaries, and rather adjust the log level on the
command line.

Jan