[Xen-devel] [PATCH v6 0/5] xen: debugtrace cleanup and per-cpu buffer support

[Xen-devel] [PATCH v6 0/5] xen: debugtrace cleanup and per-cpu buffer support

[Juergen Gross]

Another debugtrace enhancement I needed for core scheduling debugging,
plus some cleanup.

Changes in V6:
- some comments by Jan addressed
- added patch 5

Changes in V5:
- several comments by Jan addressed (code: patches 1 and 4, commit
  message of patch 3)

Changes in V4:
- replaced patch 1 (original one was committed, new one requested by
  Jan Beulich)
- several comments by Jan addressed

Changes in V3:
- rebase to current staging

Changes in V2:
- added new patch 1 (preparing the move of debugtrace coding)
- patch 4 (v1 patch 3): avoid leaking buffer

Juergen Gross (5):
  xen: fix debugtrace clearing
  xen: move debugtrace coding to common/debugtrace.c
  xen: refactor debugtrace data
  xen: add per-cpu buffer option to debugtrace
  xen: add debugtrace entry when entry count is wrapping

 docs/misc/xen-command-line.pandoc |   7 +-
 xen/common/Makefile               |   1 +
 xen/common/debugtrace.c           | 303 ++++++++++++++++++++++++++++++++++++++
 xen/drivers/char/console.c        | 178 +---------------------
 4 files changed, 309 insertions(+), 180 deletions(-)
 create mode 100644 xen/common/debugtrace.c

-- 
2.16.4


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

[Xen-devel] [PATCH v6 1/5] xen: fix debugtrace clearing

[Juergen Gross]

After dumping the debugtrace buffer it is cleared. This results in some
entries not being printed in case the buffer is dumped again before
having wrapped.

While at it remove the trailing zero byte in the buffer as it is no
longer needed. Commit b5e6e1ee8da59f introduced passing the number of
chars to be printed in the related interfaces, so the trailing 0 byte
is no longer required.

Signed-off-by: Juergen Gross <jgross@suse.com>
Reviewed-by: Jan Beulich <jbeulich@suse.com>
---
V5:
- invalidate last_buf instead of last_prd after printing the buffer
  (Jan Beulich)
V6:
- instead of moving last_buf to file scope use a boolean for buffer
  invalidation (Jan Beulich)
---
 xen/drivers/char/console.c | 14 +++++++-------
 1 file changed, 7 insertions(+), 7 deletions(-)

diff --git a/xen/drivers/char/console.c b/xen/drivers/char/console.c
index f49c6f29a8..11e1db5684 100644
--- a/xen/drivers/char/console.c
+++ b/xen/drivers/char/console.c
@@ -1173,6 +1173,7 @@ static char        *debugtrace_buf; /* Debug-trace buffer */
 static unsigned int debugtrace_prd; /* Producer index     */
 static unsigned int debugtrace_kilobytes = 128, debugtrace_bytes;
 static unsigned int debugtrace_used;
+static bool debugtrace_buf_empty;
 static DEFINE_SPINLOCK(debugtrace_lock);
 integer_param("debugtrace", debugtrace_kilobytes);
 
@@ -1184,16 +1185,17 @@ static void debugtrace_dump_worker(void)
     printk("debugtrace_dump() starting\n");
 
     /* Print oldest portion of the ring. */
-    ASSERT(debugtrace_buf[debugtrace_bytes - 1] == 0);
     if ( debugtrace_buf[debugtrace_prd] != '\0' )
         console_serial_puts(&debugtrace_buf[debugtrace_prd],
-                            debugtrace_bytes - debugtrace_prd - 1);
+                            debugtrace_bytes - debugtrace_prd);
 
     /* Print youngest portion of the ring. */
     debugtrace_buf[debugtrace_prd] = '\0';
     console_serial_puts(&debugtrace_buf[0], debugtrace_prd);
 
     memset(debugtrace_buf, '\0', debugtrace_bytes);
+    debugtrace_prd = 0;
+    debugtrace_buf_empty = true;
 
     printk("debugtrace_dump() finished\n");
 }
@@ -1241,8 +1243,7 @@ static void debugtrace_add_to_buf(char *buf)
     for ( p = buf; *p != '\0'; p++ )
     {
         debugtrace_buf[debugtrace_prd++] = *p;
-        /* Always leave a nul byte at the end of the buffer. */
-        if ( debugtrace_prd == (debugtrace_bytes - 1) )
+        if ( debugtrace_prd == debugtrace_bytes )
             debugtrace_prd = 0;
     }
 }
@@ -1264,8 +1265,6 @@ void debugtrace_printk(const char *fmt, ...)
 
     spin_lock_irqsave(&debugtrace_lock, flags);
 
-    ASSERT(debugtrace_buf[debugtrace_bytes - 1] == 0);
-
     va_start(args, fmt);
     nr = vscnprintf(buf, sizeof(buf), fmt, args);
     va_end(args);
@@ -1279,8 +1278,9 @@ void debugtrace_printk(const char *fmt, ...)
     }
     else
     {
-        if ( strcmp(buf, last_buf) )
+        if ( debugtrace_buf_empty || strcmp(buf, last_buf) )
         {
+            debugtrace_buf_empty = false;
             last_prd = debugtrace_prd;
             last_count = ++count;
             safe_strcpy(last_buf, buf);
-- 
2.16.4


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

Re: [Xen-devel] [PATCH v6 1/5] xen: fix debugtrace clearing

[Jan Beulich]

On 09.09.2019 09:35, Juergen Gross wrote:
> --- a/xen/drivers/char/console.c
> +++ b/xen/drivers/char/console.c
> @@ -1173,6 +1173,7 @@ static char        *debugtrace_buf; /* Debug-trace buffer */
>  static unsigned int debugtrace_prd; /* Producer index     */
>  static unsigned int debugtrace_kilobytes = 128, debugtrace_bytes;
>  static unsigned int debugtrace_used;
> +static bool debugtrace_buf_empty;

Wouldn't it be more logical for this to start out as "true"?
And I'm debating with myself whether it might want to be
__read_mostly. Both could be adjusted (if agreement can be
reached) while committing.

Jan

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

Re: [Xen-devel] [PATCH v6 1/5] xen: fix debugtrace clearing

[Jan Beulich]

On 09.09.2019 09:53, Jan Beulich wrote:
> On 09.09.2019 09:35, Juergen Gross wrote:
>> --- a/xen/drivers/char/console.c
>> +++ b/xen/drivers/char/console.c
>> @@ -1173,6 +1173,7 @@ static char        *debugtrace_buf; /* Debug-trace buffer */
>>  static unsigned int debugtrace_prd; /* Producer index     */
>>  static unsigned int debugtrace_kilobytes = 128, debugtrace_bytes;
>>  static unsigned int debugtrace_used;
>> +static bool debugtrace_buf_empty;
> 
> Wouldn't it be more logical for this to start out as "true"?
> And I'm debating with myself whether it might want to be
> __read_mostly.

Hmm, no, the latter rather not.

Jan

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

Re: [Xen-devel] [PATCH v6 1/5] xen: fix debugtrace clearing

[Juergen Gross]

On 09.09.19 09:53, Jan Beulich wrote:
> On 09.09.2019 09:35, Juergen Gross wrote:
>> --- a/xen/drivers/char/console.c
>> +++ b/xen/drivers/char/console.c
>> @@ -1173,6 +1173,7 @@ static char        *debugtrace_buf; /* Debug-trace buffer */
>>   static unsigned int debugtrace_prd; /* Producer index     */
>>   static unsigned int debugtrace_kilobytes = 128, debugtrace_bytes;
>>   static unsigned int debugtrace_used;
>> +static bool debugtrace_buf_empty;
> 
> Wouldn't it be more logical for this to start out as "true"?

In the end it doesn't matter, as last_buf[] will be empty initially.
But I can change it to let its semantics match the reality.


Juergen

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

[Xen-devel] [PATCH v6 2/5] xen: move debugtrace coding to common/debugtrace.c

[Juergen Gross]

Instead of living in drivers/char/console.c move the debugtrace
related coding to a new file common/debugtrace.c

No functional change, code movement only.

Signed-off-by: Juergen Gross <jgross@suse.com>
Acked-by: Jan Beulich <jbeulich@suse.com>
---
 xen/common/Makefile        |   1 +
 xen/common/debugtrace.c    | 180 +++++++++++++++++++++++++++++++++++++++++++++
 xen/drivers/char/console.c | 178 +-------------------------------------------
 3 files changed, 182 insertions(+), 177 deletions(-)
 create mode 100644 xen/common/debugtrace.c

diff --git a/xen/common/Makefile b/xen/common/Makefile
index eddda5daa6..62b34e69e9 100644
--- a/xen/common/Makefile
+++ b/xen/common/Makefile
@@ -4,6 +4,7 @@ obj-y += bsearch.o
 obj-$(CONFIG_CORE_PARKING) += core_parking.o
 obj-y += cpu.o
 obj-y += cpupool.o
+obj-$(CONFIG_DEBUG_TRACE) += debugtrace.o
 obj-$(CONFIG_HAS_DEVICE_TREE) += device_tree.o
 obj-y += domctl.o
 obj-y += domain.o
diff --git a/xen/common/debugtrace.c b/xen/common/debugtrace.c
new file mode 100644
index 0000000000..07e2746846
--- /dev/null
+++ b/xen/common/debugtrace.c
@@ -0,0 +1,180 @@
+/******************************************************************************
+ * debugtrace.c
+ *
+ * Debugtrace for Xen
+ */
+
+
+#include <xen/console.h>
+#include <xen/init.h>
+#include <xen/keyhandler.h>
+#include <xen/lib.h>
+#include <xen/mm.h>
+#include <xen/serial.h>
+#include <xen/spinlock.h>
+#include <xen/watchdog.h>
+
+/* Send output direct to console, or buffer it? */
+static volatile int debugtrace_send_to_console;
+
+static char        *debugtrace_buf; /* Debug-trace buffer */
+static unsigned int debugtrace_prd; /* Producer index     */
+static unsigned int debugtrace_kilobytes = 128, debugtrace_bytes;
+static unsigned int debugtrace_used;
+static bool debugtrace_buf_empty;
+static DEFINE_SPINLOCK(debugtrace_lock);
+integer_param("debugtrace", debugtrace_kilobytes);
+
+static void debugtrace_dump_worker(void)
+{
+    if ( (debugtrace_bytes == 0) || !debugtrace_used )
+        return;
+
+    printk("debugtrace_dump() starting\n");
+
+    /* Print oldest portion of the ring. */
+    if ( debugtrace_buf[debugtrace_prd] != '\0' )
+        console_serial_puts(&debugtrace_buf[debugtrace_prd],
+                            debugtrace_bytes - debugtrace_prd);
+
+    /* Print youngest portion of the ring. */
+    debugtrace_buf[debugtrace_prd] = '\0';
+    console_serial_puts(&debugtrace_buf[0], debugtrace_prd);
+
+    memset(debugtrace_buf, '\0', debugtrace_bytes);
+    debugtrace_prd = 0;
+    debugtrace_buf_empty = true;
+
+    printk("debugtrace_dump() finished\n");
+}
+
+static void debugtrace_toggle(void)
+{
+    unsigned long flags;
+
+    watchdog_disable();
+    spin_lock_irqsave(&debugtrace_lock, flags);
+
+    /*
+     * Dump the buffer *before* toggling, in case the act of dumping the
+     * buffer itself causes more printk() invocations.
+     */
+    printk("debugtrace_printk now writing to %s.\n",
+           !debugtrace_send_to_console ? "console": "buffer");
+    if ( !debugtrace_send_to_console )
+        debugtrace_dump_worker();
+
+    debugtrace_send_to_console = !debugtrace_send_to_console;
+
+    spin_unlock_irqrestore(&debugtrace_lock, flags);
+    watchdog_enable();
+
+}
+
+void debugtrace_dump(void)
+{
+    unsigned long flags;
+
+    watchdog_disable();
+    spin_lock_irqsave(&debugtrace_lock, flags);
+
+    debugtrace_dump_worker();
+
+    spin_unlock_irqrestore(&debugtrace_lock, flags);
+    watchdog_enable();
+}
+
+static void debugtrace_add_to_buf(char *buf)
+{
+    char *p;
+
+    for ( p = buf; *p != '\0'; p++ )
+    {
+        debugtrace_buf[debugtrace_prd++] = *p;
+        if ( debugtrace_prd == debugtrace_bytes )
+            debugtrace_prd = 0;
+    }
+}
+
+void debugtrace_printk(const char *fmt, ...)
+{
+    static char buf[1024], last_buf[1024];
+    static unsigned int count, last_count, last_prd;
+
+    char          cntbuf[24];
+    va_list       args;
+    unsigned long flags;
+    unsigned int nr;
+
+    if ( debugtrace_bytes == 0 )
+        return;
+
+    debugtrace_used = 1;
+
+    spin_lock_irqsave(&debugtrace_lock, flags);
+
+    va_start(args, fmt);
+    nr = vsnprintf(buf, sizeof(buf), fmt, args);
+    va_end(args);
+
+    if ( debugtrace_send_to_console )
+    {
+        unsigned int n = scnprintf(cntbuf, sizeof(cntbuf), "%u ", ++count);
+
+        console_serial_puts(cntbuf, n);
+        console_serial_puts(buf, nr);
+    }
+    else
+    {
+        if ( debugtrace_buf_empty || strcmp(buf, last_buf) )
+        {
+            debugtrace_buf_empty = false;
+            last_prd = debugtrace_prd;
+            last_count = ++count;
+            safe_strcpy(last_buf, buf);
+            snprintf(cntbuf, sizeof(cntbuf), "%u ", count);
+        }
+        else
+        {
+            debugtrace_prd = last_prd;
+            snprintf(cntbuf, sizeof(cntbuf), "%u-%u ", last_count, ++count);
+        }
+        debugtrace_add_to_buf(cntbuf);
+        debugtrace_add_to_buf(buf);
+    }
+
+    spin_unlock_irqrestore(&debugtrace_lock, flags);
+}
+
+static void debugtrace_key(unsigned char key)
+{
+    debugtrace_toggle();
+}
+
+static int __init debugtrace_init(void)
+{
+    int order;
+    unsigned int kbytes, bytes;
+
+    /* Round size down to next power of two. */
+    while ( (kbytes = (debugtrace_kilobytes & (debugtrace_kilobytes-1))) != 0 )
+        debugtrace_kilobytes = kbytes;
+
+    bytes = debugtrace_kilobytes << 10;
+    if ( bytes == 0 )
+        return 0;
+
+    order = get_order_from_bytes(bytes);
+    debugtrace_buf = alloc_xenheap_pages(order, 0);
+    ASSERT(debugtrace_buf != NULL);
+
+    memset(debugtrace_buf, '\0', bytes);
+
+    debugtrace_bytes = bytes;
+
+    register_keyhandler('T', debugtrace_key,
+                        "toggle debugtrace to console/buffer", 0);
+
+    return 0;
+}
+__initcall(debugtrace_init);
diff --git a/xen/drivers/char/console.c b/xen/drivers/char/console.c
index 11e1db5684..7f29190eaf 100644
--- a/xen/drivers/char/console.c
+++ b/xen/drivers/char/console.c
@@ -1160,183 +1160,7 @@ int printk_ratelimit(void)
 
 /*
  * **************************************************************
- * *************** Serial console ring buffer *******************
- * **************************************************************
- */
-
-#ifdef CONFIG_DEBUG_TRACE
-
-/* Send output direct to console, or buffer it? */
-static volatile int debugtrace_send_to_console;
-
-static char        *debugtrace_buf; /* Debug-trace buffer */
-static unsigned int debugtrace_prd; /* Producer index     */
-static unsigned int debugtrace_kilobytes = 128, debugtrace_bytes;
-static unsigned int debugtrace_used;
-static bool debugtrace_buf_empty;
-static DEFINE_SPINLOCK(debugtrace_lock);
-integer_param("debugtrace", debugtrace_kilobytes);
-
-static void debugtrace_dump_worker(void)
-{
-    if ( (debugtrace_bytes == 0) || !debugtrace_used )
-        return;
-
-    printk("debugtrace_dump() starting\n");
-
-    /* Print oldest portion of the ring. */
-    if ( debugtrace_buf[debugtrace_prd] != '\0' )
-        console_serial_puts(&debugtrace_buf[debugtrace_prd],
-                            debugtrace_bytes - debugtrace_prd);
-
-    /* Print youngest portion of the ring. */
-    debugtrace_buf[debugtrace_prd] = '\0';
-    console_serial_puts(&debugtrace_buf[0], debugtrace_prd);
-
-    memset(debugtrace_buf, '\0', debugtrace_bytes);
-    debugtrace_prd = 0;
-    debugtrace_buf_empty = true;
-
-    printk("debugtrace_dump() finished\n");
-}
-
-static void debugtrace_toggle(void)
-{
-    unsigned long flags;
-
-    watchdog_disable();
-    spin_lock_irqsave(&debugtrace_lock, flags);
-
-    /*
-     * Dump the buffer *before* toggling, in case the act of dumping the
-     * buffer itself causes more printk() invocations.
-     */
-    printk("debugtrace_printk now writing to %s.\n",
-           !debugtrace_send_to_console ? "console": "buffer");
-    if ( !debugtrace_send_to_console )
-        debugtrace_dump_worker();
-
-    debugtrace_send_to_console = !debugtrace_send_to_console;
-
-    spin_unlock_irqrestore(&debugtrace_lock, flags);
-    watchdog_enable();
-
-}
-
-void debugtrace_dump(void)
-{
-    unsigned long flags;
-
-    watchdog_disable();
-    spin_lock_irqsave(&debugtrace_lock, flags);
-
-    debugtrace_dump_worker();
-
-    spin_unlock_irqrestore(&debugtrace_lock, flags);
-    watchdog_enable();
-}
-
-static void debugtrace_add_to_buf(char *buf)
-{
-    char *p;
-
-    for ( p = buf; *p != '\0'; p++ )
-    {
-        debugtrace_buf[debugtrace_prd++] = *p;
-        if ( debugtrace_prd == debugtrace_bytes )
-            debugtrace_prd = 0;
-    }
-}
-
-void debugtrace_printk(const char *fmt, ...)
-{
-    static char buf[1024], last_buf[1024];
-    static unsigned int count, last_count, last_prd;
-
-    char          cntbuf[24];
-    va_list       args;
-    unsigned long flags;
-    unsigned int nr;
-
-    if ( debugtrace_bytes == 0 )
-        return;
-
-    debugtrace_used = 1;
-
-    spin_lock_irqsave(&debugtrace_lock, flags);
-
-    va_start(args, fmt);
-    nr = vscnprintf(buf, sizeof(buf), fmt, args);
-    va_end(args);
-
-    if ( debugtrace_send_to_console )
-    {
-        unsigned int n = scnprintf(cntbuf, sizeof(cntbuf), "%u ", ++count);
-
-        console_serial_puts(cntbuf, n);
-        console_serial_puts(buf, nr);
-    }
-    else
-    {
-        if ( debugtrace_buf_empty || strcmp(buf, last_buf) )
-        {
-            debugtrace_buf_empty = false;
-            last_prd = debugtrace_prd;
-            last_count = ++count;
-            safe_strcpy(last_buf, buf);
-            snprintf(cntbuf, sizeof(cntbuf), "%u ", count);
-        }
-        else
-        {
-            debugtrace_prd = last_prd;
-            snprintf(cntbuf, sizeof(cntbuf), "%u-%u ", last_count, ++count);
-        }
-        debugtrace_add_to_buf(cntbuf);
-        debugtrace_add_to_buf(buf);
-    }
-
-    spin_unlock_irqrestore(&debugtrace_lock, flags);
-}
-
-static void debugtrace_key(unsigned char key)
-{
-    debugtrace_toggle();
-}
-
-static int __init debugtrace_init(void)
-{
-    int order;
-    unsigned int kbytes, bytes;
-
-    /* Round size down to next power of two. */
-    while ( (kbytes = (debugtrace_kilobytes & (debugtrace_kilobytes-1))) != 0 )
-        debugtrace_kilobytes = kbytes;
-
-    bytes = debugtrace_kilobytes << 10;
-    if ( bytes == 0 )
-        return 0;
-
-    order = get_order_from_bytes(bytes);
-    debugtrace_buf = alloc_xenheap_pages(order, 0);
-    ASSERT(debugtrace_buf != NULL);
-
-    memset(debugtrace_buf, '\0', bytes);
-
-    debugtrace_bytes = bytes;
-
-    register_keyhandler('T', debugtrace_key,
-                        "toggle debugtrace to console/buffer", 0);
-
-    return 0;
-}
-__initcall(debugtrace_init);
-
-#endif /* !CONFIG_DEBUG_TRACE */
-
-
-/*
- * **************************************************************
- * *************** Debugging/tracing/error-report ***************
+ * ********************** Error-report **************************
  * **************************************************************
  */
 
-- 
2.16.4


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

[Xen-devel] [PATCH v6 3/5] xen: refactor debugtrace data

[Juergen Gross]

As a preparation for per-cpu buffers do a little refactoring of the
debugtrace data: put the needed buffer admin data into the buffer as
it will be needed for each buffer. In order not to limit buffer size
switch the related fields from unsigned int to unsigned long, as on
huge machines with RAM in the TB range it might be interesting to
support buffers >4GB.

While at it switch debugtrace_send_to_console and debugtrace_used to
bool and delete an empty line.

Signed-off-by: Juergen Gross <jgross@suse.com>
Reviewed-by: Jan Beulich <jbeulich@suse.com>
---
V4:
- renamed struct debugtrace_data_s (Jan Beulich)
- renamed debtr_data (Jan Beulich)
- remove unneeded condition (Jan Beulich)
- recalc debugtrace_bytes (Jan Beulich)
V6:
- undo putting bytes into struct debugtrace_data (Jan Beulich)
---
 xen/common/debugtrace.c | 70 ++++++++++++++++++++++++++++---------------------
 1 file changed, 40 insertions(+), 30 deletions(-)

diff --git a/xen/common/debugtrace.c b/xen/common/debugtrace.c
index 07e2746846..51ab41f7a7 100644
--- a/xen/common/debugtrace.c
+++ b/xen/common/debugtrace.c
@@ -15,34 +15,40 @@
 #include <xen/watchdog.h>
 
 /* Send output direct to console, or buffer it? */
-static volatile int debugtrace_send_to_console;
+static volatile bool debugtrace_send_to_console;
 
-static char        *debugtrace_buf; /* Debug-trace buffer */
-static unsigned int debugtrace_prd; /* Producer index     */
-static unsigned int debugtrace_kilobytes = 128, debugtrace_bytes;
-static unsigned int debugtrace_used;
+struct debugtrace_data {
+    unsigned long prd;   /* Producer index. */
+    char          buf[];
+};
+
+static struct debugtrace_data *dt_data;
+
+static unsigned int debugtrace_kilobytes = 128;
+static unsigned long debugtrace_bytes;
 static bool debugtrace_buf_empty;
+static bool debugtrace_used;
 static DEFINE_SPINLOCK(debugtrace_lock);
 integer_param("debugtrace", debugtrace_kilobytes);
 
 static void debugtrace_dump_worker(void)
 {
-    if ( (debugtrace_bytes == 0) || !debugtrace_used )
+    if ( !debugtrace_used )
         return;
 
     printk("debugtrace_dump() starting\n");
 
     /* Print oldest portion of the ring. */
-    if ( debugtrace_buf[debugtrace_prd] != '\0' )
-        console_serial_puts(&debugtrace_buf[debugtrace_prd],
-                            debugtrace_bytes - debugtrace_prd);
+    if ( dt_data->buf[dt_data->prd] != '\0' )
+        console_serial_puts(&dt_data->buf[dt_data->prd],
+                            debugtrace_bytes - dt_data->prd);
 
     /* Print youngest portion of the ring. */
-    debugtrace_buf[debugtrace_prd] = '\0';
-    console_serial_puts(&debugtrace_buf[0], debugtrace_prd);
+    dt_data->buf[dt_data->prd] = '\0';
+    console_serial_puts(&dt_data->buf[0], dt_data->prd);
 
-    memset(debugtrace_buf, '\0', debugtrace_bytes);
-    debugtrace_prd = 0;
+    memset(dt_data->buf, '\0', debugtrace_bytes);
+    dt_data->prd = 0;
     debugtrace_buf_empty = true;
 
     printk("debugtrace_dump() finished\n");
@@ -68,7 +74,6 @@ static void debugtrace_toggle(void)
 
     spin_unlock_irqrestore(&debugtrace_lock, flags);
     watchdog_enable();
-
 }
 
 void debugtrace_dump(void)
@@ -90,26 +95,27 @@ static void debugtrace_add_to_buf(char *buf)
 
     for ( p = buf; *p != '\0'; p++ )
     {
-        debugtrace_buf[debugtrace_prd++] = *p;
-        if ( debugtrace_prd == debugtrace_bytes )
-            debugtrace_prd = 0;
+        dt_data->buf[dt_data->prd++] = *p;
+        if ( dt_data->prd == debugtrace_bytes )
+            dt_data->prd = 0;
     }
 }
 
 void debugtrace_printk(const char *fmt, ...)
 {
     static char buf[1024], last_buf[1024];
-    static unsigned int count, last_count, last_prd;
+    static unsigned int count, last_count;
+    static unsigned long last_prd;
 
     char          cntbuf[24];
     va_list       args;
     unsigned long flags;
     unsigned int nr;
 
-    if ( debugtrace_bytes == 0 )
+    if ( !dt_data )
         return;
 
-    debugtrace_used = 1;
+    debugtrace_used = true;
 
     spin_lock_irqsave(&debugtrace_lock, flags);
 
@@ -129,14 +135,14 @@ void debugtrace_printk(const char *fmt, ...)
         if ( debugtrace_buf_empty || strcmp(buf, last_buf) )
         {
             debugtrace_buf_empty = false;
-            last_prd = debugtrace_prd;
+            last_prd = dt_data->prd;
             last_count = ++count;
             safe_strcpy(last_buf, buf);
             snprintf(cntbuf, sizeof(cntbuf), "%u ", count);
         }
         else
         {
-            debugtrace_prd = last_prd;
+            dt_data->prd = last_prd;
             snprintf(cntbuf, sizeof(cntbuf), "%u-%u ", last_count, ++count);
         }
         debugtrace_add_to_buf(cntbuf);
@@ -154,23 +160,27 @@ static void debugtrace_key(unsigned char key)
 static int __init debugtrace_init(void)
 {
     int order;
-    unsigned int kbytes, bytes;
+    unsigned long kbytes;
+    struct debugtrace_data *data;
 
     /* Round size down to next power of two. */
     while ( (kbytes = (debugtrace_kilobytes & (debugtrace_kilobytes-1))) != 0 )
         debugtrace_kilobytes = kbytes;
 
-    bytes = debugtrace_kilobytes << 10;
-    if ( bytes == 0 )
+    debugtrace_bytes = debugtrace_kilobytes << 10;
+    if ( debugtrace_bytes == 0 )
         return 0;
 
-    order = get_order_from_bytes(bytes);
-    debugtrace_buf = alloc_xenheap_pages(order, 0);
-    ASSERT(debugtrace_buf != NULL);
+    order = get_order_from_bytes(debugtrace_bytes);
+    data = alloc_xenheap_pages(order, 0);
+    if ( !data )
+        return -ENOMEM;
 
-    memset(debugtrace_buf, '\0', bytes);
+    debugtrace_bytes = PAGE_SIZE << order;
+    memset(data, '\0', debugtrace_bytes);
+    debugtrace_bytes -= sizeof(*data);
 
-    debugtrace_bytes = bytes;
+    dt_data = data;
 
     register_keyhandler('T', debugtrace_key,
                         "toggle debugtrace to console/buffer", 0);
-- 
2.16.4


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

[Xen-devel] [PATCH v6 4/5] xen: add per-cpu buffer option to debugtrace

[Juergen Gross]

debugtrace is normally writing trace entries into a single trace
buffer. There are cases where this is not optimal, e.g. when hunting
a bug which requires writing lots of trace entries and one cpu is
stuck. This will result in other cpus filling the trace buffer and
finally overwriting the interesting trace entries of the hanging cpu.

In order to be able to debug such situations add the capability to use
per-cpu trace buffers. This can be selected by specifying the
debugtrace boot parameter with the modifier "cpu:", like:

  debugtrace=cpu:16

At the same time switch the parsing function to accept size modifiers
(e.g. 4M or 1G).

Printing out the trace entries is done for each buffer in order to
minimize the effort needed during printing. As each entry is prefixed
with its sequence number sorting the entries can easily be done when
analyzing them.

Signed-off-by: Juergen Gross <jgross@suse.com>
---
V2:
- only allocate buffer if not already done so
V4:
- unsigned int -> unsigned long (Jan Beulich)
- replace check for bytes < PAGE_SIZE by !bytes (Jan Beulich)
- print info which buffer allocation failed (Jan Beulich)
- replace switch by if in cpu notifier handler (Jan Beulich)
V5:
- don't silently ignore trailing characters when parsing buffer size
  (Jan Beulich)
- limit scope of some variables (Jan Beulich)
- adjust error message format (Jan Beulich)
V6:
- move calculation of final debugtrace_bytes value to parameter parsing
---
 docs/misc/xen-command-line.pandoc |   7 +-
 xen/common/debugtrace.c           | 158 +++++++++++++++++++++++++++++---------
 2 files changed, 127 insertions(+), 38 deletions(-)

diff --git a/docs/misc/xen-command-line.pandoc b/docs/misc/xen-command-line.pandoc
index 7c72e31032..832797e2e2 100644
--- a/docs/misc/xen-command-line.pandoc
+++ b/docs/misc/xen-command-line.pandoc
@@ -644,12 +644,13 @@ over the PCI busses sequentially) or by PCI device (must be on segment 0).
 Limits the number lines printed in Xen stack traces.
 
 ### debugtrace
-> `= <integer>`
+> `= [cpu:]<size>`
 
 > Default: `128`
 
-Specify the size of the console debug trace buffer in KiB. The debug
-trace feature is only enabled in debugging builds of Xen.
+Specify the size of the console debug trace buffer. By specifying `cpu:`
+additionally a trace buffer of the specified size is allocated per cpu.
+The debug trace feature is only enabled in debugging builds of Xen.
 
 ### dma_bits
 > `= <integer>`
diff --git a/xen/common/debugtrace.c b/xen/common/debugtrace.c
index 51ab41f7a7..669b2102ab 100644
--- a/xen/common/debugtrace.c
+++ b/xen/common/debugtrace.c
@@ -6,6 +6,7 @@
 
 
 #include <xen/console.h>
+#include <xen/cpu.h>
 #include <xen/init.h>
 #include <xen/keyhandler.h>
 #include <xen/lib.h>
@@ -23,35 +24,79 @@ struct debugtrace_data {
 };
 
 static struct debugtrace_data *dt_data;
+static DEFINE_PER_CPU(struct debugtrace_data *, dt_cpu_data);
 
-static unsigned int debugtrace_kilobytes = 128;
-static unsigned long debugtrace_bytes;
+static unsigned long debugtrace_bytes = 128 << 10;
+static bool debugtrace_per_cpu;
 static bool debugtrace_buf_empty;
 static bool debugtrace_used;
 static DEFINE_SPINLOCK(debugtrace_lock);
-integer_param("debugtrace", debugtrace_kilobytes);
 
-static void debugtrace_dump_worker(void)
+static int __init debugtrace_parse_param(const char *s)
 {
-    if ( !debugtrace_used )
+    unsigned long bytes;
+
+    if ( !strncmp(s, "cpu:", 4) )
+    {
+        debugtrace_per_cpu = true;
+        s += 4;
+    }
+    bytes = parse_size_and_unit(s, &s);
+
+    if ( *s )
+        return -EINVAL;
+
+    debugtrace_bytes = MAX(bytes, PAGE_SIZE);
+
+    /* Round size down to next power of two. */
+    while ( (bytes = (debugtrace_bytes & (debugtrace_bytes - 1))) != 0 )
+        debugtrace_bytes = bytes;
+
+    return 0;
+}
+custom_param("debugtrace", debugtrace_parse_param);
+
+static void debugtrace_dump_buffer(struct debugtrace_data *data,
+                                   const char *which)
+{
+    if ( !data )
         return;
 
-    printk("debugtrace_dump() starting\n");
+    printk("debugtrace_dump() %s buffer starting\n", which);
 
     /* Print oldest portion of the ring. */
-    if ( dt_data->buf[dt_data->prd] != '\0' )
-        console_serial_puts(&dt_data->buf[dt_data->prd],
-                            debugtrace_bytes - dt_data->prd);
+    if ( data->buf[data->prd] != '\0' )
+        console_serial_puts(&data->buf[data->prd],
+                            debugtrace_bytes - data->prd);
 
     /* Print youngest portion of the ring. */
-    dt_data->buf[dt_data->prd] = '\0';
-    console_serial_puts(&dt_data->buf[0], dt_data->prd);
+    data->buf[data->prd] = '\0';
+    console_serial_puts(&data->buf[0], data->prd);
 
-    memset(dt_data->buf, '\0', debugtrace_bytes);
-    dt_data->prd = 0;
-    debugtrace_buf_empty = true;
+    memset(data->buf, '\0', debugtrace_bytes);
+    data->prd = 0;
 
-    printk("debugtrace_dump() finished\n");
+    printk("debugtrace_dump() %s buffer finished\n", which);
+}
+
+static void debugtrace_dump_worker(void)
+{
+    unsigned int cpu;
+
+    if ( !debugtrace_used )
+        return;
+
+    debugtrace_dump_buffer(dt_data, "global");
+
+    for ( cpu = 0; cpu < nr_cpu_ids; cpu++ )
+    {
+        char buf[16];
+
+        snprintf(buf, sizeof(buf), "cpu %u", cpu);
+        debugtrace_dump_buffer(per_cpu(dt_cpu_data, cpu), buf);
+    }
+
+    debugtrace_buf_empty = true;
 }
 
 static void debugtrace_toggle(void)
@@ -91,28 +136,33 @@ void debugtrace_dump(void)
 
 static void debugtrace_add_to_buf(char *buf)
 {
+    struct debugtrace_data *data;
     char *p;
 
+    data = debugtrace_per_cpu ? this_cpu(dt_cpu_data) : dt_data;
+
     for ( p = buf; *p != '\0'; p++ )
     {
-        dt_data->buf[dt_data->prd++] = *p;
-        if ( dt_data->prd == debugtrace_bytes )
-            dt_data->prd = 0;
+        data->buf[data->prd++] = *p;
+        if ( data->prd == debugtrace_bytes )
+            data->prd = 0;
     }
 }
 
 void debugtrace_printk(const char *fmt, ...)
 {
     static char buf[1024], last_buf[1024];
-    static unsigned int count, last_count;
+    static unsigned int count, last_count, last_cpu;
     static unsigned long last_prd;
 
     char          cntbuf[24];
     va_list       args;
     unsigned long flags;
     unsigned int nr;
+    struct debugtrace_data *data;
 
-    if ( !dt_data )
+    data = debugtrace_per_cpu ? this_cpu(dt_cpu_data) : dt_data;
+    if ( !data )
         return;
 
     debugtrace_used = true;
@@ -132,17 +182,20 @@ void debugtrace_printk(const char *fmt, ...)
     }
     else
     {
+        unsigned int cpu = debugtrace_per_cpu ? smp_processor_id() : 0;
+
         if ( debugtrace_buf_empty || strcmp(buf, last_buf) )
         {
             debugtrace_buf_empty = false;
-            last_prd = dt_data->prd;
+            last_prd = data->prd;
             last_count = ++count;
+            last_cpu = cpu;
             safe_strcpy(last_buf, buf);
             snprintf(cntbuf, sizeof(cntbuf), "%u ", count);
         }
         else
         {
-            dt_data->prd = last_prd;
+            data->prd = last_prd;
             snprintf(cntbuf, sizeof(cntbuf), "%u-%u ", last_count, ++count);
         }
         debugtrace_add_to_buf(cntbuf);
@@ -157,34 +210,69 @@ static void debugtrace_key(unsigned char key)
     debugtrace_toggle();
 }
 
-static int __init debugtrace_init(void)
+static void debugtrace_alloc_buffer(struct debugtrace_data **ptr,
+                                    unsigned int cpu)
 {
     int order;
-    unsigned long kbytes;
     struct debugtrace_data *data;
 
-    /* Round size down to next power of two. */
-    while ( (kbytes = (debugtrace_kilobytes & (debugtrace_kilobytes-1))) != 0 )
-        debugtrace_kilobytes = kbytes;
-
-    debugtrace_bytes = debugtrace_kilobytes << 10;
-    if ( debugtrace_bytes == 0 )
-        return 0;
+    if ( *ptr )
+        return;
 
     order = get_order_from_bytes(debugtrace_bytes);
     data = alloc_xenheap_pages(order, 0);
     if ( !data )
-        return -ENOMEM;
+    {
+        if ( debugtrace_per_cpu )
+            printk("CPU%u: failed to allocate debugtrace buffer\n", cpu);
+        else
+            printk("failed to allocate debugtrace buffer\n");
+        return;
+    }
 
-    debugtrace_bytes = PAGE_SIZE << order;
-    memset(data, '\0', debugtrace_bytes);
-    debugtrace_bytes -= sizeof(*data);
+    memset(data, '\0', debugtrace_bytes + sizeof(*data));
 
     dt_data = data;
+    *ptr = data;
+}
+
+static int debugtrace_cpu_callback(struct notifier_block *nfb,
+                                   unsigned long action, void *hcpu)
+{
+    unsigned int cpu = (unsigned long)hcpu;
+
+    /* Buffers are only ever allocated, never freed. */
+    if ( action == CPU_UP_PREPARE )
+        debugtrace_alloc_buffer(&per_cpu(dt_cpu_data, cpu), cpu);
+
+    return 0;
+}
+
+static struct notifier_block debugtrace_nfb = {
+    .notifier_call = debugtrace_cpu_callback
+};
+
+static int __init debugtrace_init(void)
+{
+    unsigned int cpu;
+
+    if ( !debugtrace_bytes )
+        return 0;
 
     register_keyhandler('T', debugtrace_key,
                         "toggle debugtrace to console/buffer", 0);
 
+    debugtrace_bytes -= sizeof(struct debugtrace_data);
+
+    if ( debugtrace_per_cpu )
+    {
+        for_each_online_cpu ( cpu )
+            debugtrace_alloc_buffer(&per_cpu(dt_cpu_data, cpu), cpu);
+        register_cpu_notifier(&debugtrace_nfb);
+    }
+    else
+        debugtrace_alloc_buffer(&dt_data, 0);
+
     return 0;
 }
 __initcall(debugtrace_init);
-- 
2.16.4


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

Re: [Xen-devel] [PATCH v6 4/5] xen: add per-cpu buffer option to debugtrace

[Jan Beulich]

On 09.09.2019 09:35, Juergen Gross wrote:
> debugtrace is normally writing trace entries into a single trace
> buffer. There are cases where this is not optimal, e.g. when hunting
> a bug which requires writing lots of trace entries and one cpu is
> stuck. This will result in other cpus filling the trace buffer and
> finally overwriting the interesting trace entries of the hanging cpu.
> 
> In order to be able to debug such situations add the capability to use
> per-cpu trace buffers. This can be selected by specifying the
> debugtrace boot parameter with the modifier "cpu:", like:
> 
>   debugtrace=cpu:16
> 
> At the same time switch the parsing function to accept size modifiers
> (e.g. 4M or 1G).
> 
> Printing out the trace entries is done for each buffer in order to
> minimize the effort needed during printing. As each entry is prefixed
> with its sequence number sorting the entries can easily be done when
> analyzing them.
> 
> Signed-off-by: Juergen Gross <jgross@suse.com>

Reviewed-by: Jan Beulich <jbeulich@suse.com>
perhaps with ...

> @@ -23,35 +24,79 @@ struct debugtrace_data {
>  };
>  
>  static struct debugtrace_data *dt_data;
> +static DEFINE_PER_CPU(struct debugtrace_data *, dt_cpu_data);
>  
> -static unsigned int debugtrace_kilobytes = 128;
> -static unsigned long debugtrace_bytes;
> +static unsigned long debugtrace_bytes = 128 << 10;
> +static bool debugtrace_per_cpu;

... two more __read_mostly used here (which could again be done
while committing if you agree).

Jan

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

Re: [Xen-devel] [PATCH v6 4/5] xen: add per-cpu buffer option to debugtrace

[Jan Beulich]

On 09.09.2019 09:59, Jan Beulich wrote:
> On 09.09.2019 09:35, Juergen Gross wrote:
>> debugtrace is normally writing trace entries into a single trace
>> buffer. There are cases where this is not optimal, e.g. when hunting
>> a bug which requires writing lots of trace entries and one cpu is
>> stuck. This will result in other cpus filling the trace buffer and
>> finally overwriting the interesting trace entries of the hanging cpu.
>>
>> In order to be able to debug such situations add the capability to use
>> per-cpu trace buffers. This can be selected by specifying the
>> debugtrace boot parameter with the modifier "cpu:", like:
>>
>>   debugtrace=cpu:16
>>
>> At the same time switch the parsing function to accept size modifiers
>> (e.g. 4M or 1G).
>>
>> Printing out the trace entries is done for each buffer in order to
>> minimize the effort needed during printing. As each entry is prefixed
>> with its sequence number sorting the entries can easily be done when
>> analyzing them.
>>
>> Signed-off-by: Juergen Gross <jgross@suse.com>
> 
> Reviewed-by: Jan Beulich <jbeulich@suse.com>

Oh, no - I have to take this back. Looking at patch 5 I notice
that you now only ever write last_cpu; you must have lost its
consumer.

Jan

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

Re: [Xen-devel] [PATCH v6 4/5] xen: add per-cpu buffer option to debugtrace

[Juergen Gross]

On 09.09.19 10:04, Jan Beulich wrote:
> On 09.09.2019 09:59, Jan Beulich wrote:
>> On 09.09.2019 09:35, Juergen Gross wrote:
>>> debugtrace is normally writing trace entries into a single trace
>>> buffer. There are cases where this is not optimal, e.g. when hunting
>>> a bug which requires writing lots of trace entries and one cpu is
>>> stuck. This will result in other cpus filling the trace buffer and
>>> finally overwriting the interesting trace entries of the hanging cpu.
>>>
>>> In order to be able to debug such situations add the capability to use
>>> per-cpu trace buffers. This can be selected by specifying the
>>> debugtrace boot parameter with the modifier "cpu:", like:
>>>
>>>    debugtrace=cpu:16
>>>
>>> At the same time switch the parsing function to accept size modifiers
>>> (e.g. 4M or 1G).
>>>
>>> Printing out the trace entries is done for each buffer in order to
>>> minimize the effort needed during printing. As each entry is prefixed
>>> with its sequence number sorting the entries can easily be done when
>>> analyzing them.
>>>
>>> Signed-off-by: Juergen Gross <jgross@suse.com>
>>
>> Reviewed-by: Jan Beulich <jbeulich@suse.com>
> 
> Oh, no - I have to take this back. Looking at patch 5 I notice
> that you now only ever write last_cpu; you must have lost its
> consumer.

Oh, indeed. Thanks for spotting that. Will send out a corrected patch
soon.


Juergen

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

[Xen-devel] [PATCH v6 5/5] xen: add debugtrace entry when entry count is wrapping

[Juergen Gross]

The debugtrace entry count is a 32 bit variable, so it can wrap when
lots of trace entries are being produced. Making it wider would result
in a waste of buffer space as the printed count value would consume
more bytes when not wrapping.

So instead of letting the count value grow to huge values let it wrap
and add a wrap counter printed in this situation. This will keep the
needed buffer space at today's value while avoiding to loose a way to
sort all entries in case multiple trace buffers are involved.

Signed-off-by: Juergen Gross <jgross@suse.com>
---
 xen/common/debugtrace.c | 33 +++++++++++++++++++++++++++++----
 1 file changed, 29 insertions(+), 4 deletions(-)

diff --git a/xen/common/debugtrace.c b/xen/common/debugtrace.c
index 669b2102ab..f779ad36ed 100644
--- a/xen/common/debugtrace.c
+++ b/xen/common/debugtrace.c
@@ -15,11 +15,14 @@
 #include <xen/spinlock.h>
 #include <xen/watchdog.h>
 
+#define DEBUGTRACE_COUNT_WRAP 99999999
+
 /* Send output direct to console, or buffer it? */
 static volatile bool debugtrace_send_to_console;
 
 struct debugtrace_data {
     unsigned long prd;   /* Producer index. */
+    unsigned long wrap_cnt;
     char          buf[];
 };
 
@@ -72,6 +75,7 @@ static void debugtrace_dump_buffer(struct debugtrace_data *data,
     /* Print youngest portion of the ring. */
     data->buf[data->prd] = '\0';
     console_serial_puts(&data->buf[0], data->prd);
+    printk("wrap: %lu\n", data->wrap_cnt);
 
     memset(data->buf, '\0', debugtrace_bytes);
     data->prd = 0;
@@ -153,9 +157,9 @@ void debugtrace_printk(const char *fmt, ...)
 {
     static char buf[1024], last_buf[1024];
     static unsigned int count, last_count, last_cpu;
-    static unsigned long last_prd;
+    static unsigned long last_prd, wrap_cnt;
 
-    char          cntbuf[24];
+    char          cntbuf[50];
     va_list       args;
     unsigned long flags;
     unsigned int nr;
@@ -173,10 +177,23 @@ void debugtrace_printk(const char *fmt, ...)
     nr = vsnprintf(buf, sizeof(buf), fmt, args);
     va_end(args);
 
+    if ( count == DEBUGTRACE_COUNT_WRAP )
+    {
+        count = 0;
+        wrap_cnt++;
+    }
+
     if ( debugtrace_send_to_console )
     {
-        unsigned int n = scnprintf(cntbuf, sizeof(cntbuf), "%u ", ++count);
+        unsigned int n;
+
+        if ( count == 0 )
+        {
+            n = scnprintf(cntbuf, sizeof(cntbuf), "wrap: %lu\n", wrap_cnt);
+            console_serial_puts(cntbuf, n);
+        }
 
+        n = scnprintf(cntbuf, sizeof(cntbuf), "%u ", ++count);
         console_serial_puts(cntbuf, n);
         console_serial_puts(buf, nr);
     }
@@ -184,8 +201,16 @@ void debugtrace_printk(const char *fmt, ...)
     {
         unsigned int cpu = debugtrace_per_cpu ? smp_processor_id() : 0;
 
-        if ( debugtrace_buf_empty || strcmp(buf, last_buf) )
+        if ( debugtrace_buf_empty || wrap_cnt != data->wrap_cnt ||
+             strcmp(buf, last_buf) )
         {
+            if ( wrap_cnt != data->wrap_cnt )
+            {
+                snprintf(cntbuf, sizeof(cntbuf), "wrap: %lu->%lu\n",
+                         data->wrap_cnt, wrap_cnt);
+                debugtrace_add_to_buf(cntbuf);
+                data->wrap_cnt = wrap_cnt;
+            }
             debugtrace_buf_empty = false;
             last_prd = data->prd;
             last_count = ++count;
-- 
2.16.4


_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

Re: [Xen-devel] [PATCH v6 5/5] xen: add debugtrace entry when entry count is wrapping

[Jan Beulich]

On 09.09.2019 09:35, Juergen Gross wrote:
> @@ -173,10 +177,23 @@ void debugtrace_printk(const char *fmt, ...)
>      nr = vsnprintf(buf, sizeof(buf), fmt, args);
>      va_end(args);
>  
> +    if ( count == DEBUGTRACE_COUNT_WRAP )
> +    {
> +        count = 0;
> +        wrap_cnt++;
> +    }
> +
>      if ( debugtrace_send_to_console )
>      {
> -        unsigned int n = scnprintf(cntbuf, sizeof(cntbuf), "%u ", ++count);
> +        unsigned int n;
> +
> +        if ( count == 0 )
> +        {
> +            n = scnprintf(cntbuf, sizeof(cntbuf), "wrap: %lu\n", wrap_cnt);
> +            console_serial_puts(cntbuf, n);
> +        }
>  
> +        n = scnprintf(cntbuf, sizeof(cntbuf), "%u ", ++count);
>          console_serial_puts(cntbuf, n);
>          console_serial_puts(buf, nr);
>      }

Just one minor remark: In this case you issue a "wrap" message at
start of day, ...

> @@ -184,8 +201,16 @@ void debugtrace_printk(const char *fmt, ...)
>      {
>          unsigned int cpu = debugtrace_per_cpu ? smp_processor_id() : 0;
>  
> -        if ( debugtrace_buf_empty || strcmp(buf, last_buf) )
> +        if ( debugtrace_buf_empty || wrap_cnt != data->wrap_cnt ||
> +             strcmp(buf, last_buf) )
>          {
> +            if ( wrap_cnt != data->wrap_cnt )
> +            {
> +                snprintf(cntbuf, sizeof(cntbuf), "wrap: %lu->%lu\n",
> +                         data->wrap_cnt, wrap_cnt);
> +                debugtrace_add_to_buf(cntbuf);
> +                data->wrap_cnt = wrap_cnt;
> +            }
>              debugtrace_buf_empty = false;
>              last_prd = data->prd;
>              last_count = ++count;

... whereas here one gets issued (as I'd expect it) only after the
first wrapping of "count".

Jan

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel

Re: [Xen-devel] [PATCH v6 5/5] xen: add debugtrace entry when entry count is wrapping

[Juergen Gross]

On 09.09.19 10:19, Jan Beulich wrote:
> On 09.09.2019 09:35, Juergen Gross wrote:
>> @@ -173,10 +177,23 @@ void debugtrace_printk(const char *fmt, ...)
>>       nr = vsnprintf(buf, sizeof(buf), fmt, args);
>>       va_end(args);
>>   
>> +    if ( count == DEBUGTRACE_COUNT_WRAP )
>> +    {
>> +        count = 0;
>> +        wrap_cnt++;
>> +    }
>> +
>>       if ( debugtrace_send_to_console )
>>       {
>> -        unsigned int n = scnprintf(cntbuf, sizeof(cntbuf), "%u ", ++count);
>> +        unsigned int n;
>> +
>> +        if ( count == 0 )
>> +        {
>> +            n = scnprintf(cntbuf, sizeof(cntbuf), "wrap: %lu\n", wrap_cnt);
>> +            console_serial_puts(cntbuf, n);
>> +        }
>>   
>> +        n = scnprintf(cntbuf, sizeof(cntbuf), "%u ", ++count);
>>           console_serial_puts(cntbuf, n);
>>           console_serial_puts(buf, nr);
>>       }
> 
> Just one minor remark: In this case you issue a "wrap" message at
> start of day, ...
> 
>> @@ -184,8 +201,16 @@ void debugtrace_printk(const char *fmt, ...)
>>       {
>>           unsigned int cpu = debugtrace_per_cpu ? smp_processor_id() : 0;
>>   
>> -        if ( debugtrace_buf_empty || strcmp(buf, last_buf) )
>> +        if ( debugtrace_buf_empty || wrap_cnt != data->wrap_cnt ||
>> +             strcmp(buf, last_buf) )
>>           {
>> +            if ( wrap_cnt != data->wrap_cnt )
>> +            {
>> +                snprintf(cntbuf, sizeof(cntbuf), "wrap: %lu->%lu\n",
>> +                         data->wrap_cnt, wrap_cnt);
>> +                debugtrace_add_to_buf(cntbuf);
>> +                data->wrap_cnt = wrap_cnt;
>> +            }
>>               debugtrace_buf_empty = false;
>>               last_prd = data->prd;
>>               last_count = ++count;
> 
> ... whereas here one gets issued (as I'd expect it) only after the
> first wrapping of "count".

Yes, I know. The reason I have done it this way was the possibility to
support debugtrace via console even in case of a zero-sized buffer in
future. I can point that out in the commit message.


Juergen

_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xenproject.org
https://lists.xenproject.org/mailman/listinfo/xen-devel