[Qemu-devel] [PATCH v9 0/9] qemu-log, -dfilter and other logging tweaks

[Qemu-devel] [PATCH v9 0/9] qemu-log, -dfilter and other logging tweaks

[Alex Bennée]

The only change since v8 is fixing the off-by-one in the dfilter -
parsing case (the + case was fixed in v8).

Ready for merge now?

Alex Bennée (7):
  tcg: pass down TranslationBlock to tcg_code_gen
  qemu-log: correct help text for -d cpu
  qemu-log: new option -dfilter to limit output
  qemu-log: dfilter-ise exec, out_asm, op and opt_op
  target-arm: dfilter support for in_asm
  qemu-log: support simple pid substitution for logs
  cputlb: modernise the debug support

Peter Maydell (2):
  qemu-log: Avoid function call for disabled qemu_log_mask logging
  qemu-log: Improve the "exec" TB execution logging

 cpu-exec.c                 |  21 ++++---
 cputlb.c                   |  88 ++++++++++++++--------------
 include/exec/exec-all.h    |   5 ++
 include/qemu/log.h         |  28 ++++++++-
 qemu-options.hx            |  18 ++++++
 target-arm/translate-a64.c |   3 +-
 target-arm/translate.c     |   3 +-
 tcg/tcg.c                  |  12 ++--
 tcg/tcg.h                  |   2 +-
 tests/Makefile             |   4 ++
 tests/test-logging.c       | 141 +++++++++++++++++++++++++++++++++++++++++++++
 translate-all.c            |   5 +-
 util/log.c                 | 120 +++++++++++++++++++++++++++++++++-----
 vl.c                       |   3 +
 14 files changed, 374 insertions(+), 79 deletions(-)
 create mode 100644 tests/test-logging.c

-- 
2.7.2

[Qemu-devel] [PATCH v9] cputlb: modernise the debug support

[Alex Bennée]

To avoid cluttering the code with #ifdef legs we wrap up the print
statements into a tlb_debug() macro. As access to the virtual TLB can
get quite heavy defining DEBUG_TLB_LOG will ensure all the logs go to
the qemu_log target of CPU_LOG_MMU instead of stderr. This remains
compile time optional as these debug statements haven't been considered
for usefulness for user visible logging.

I've also removed DEBUG_TLB_CHECK which wasn't used.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Richard Henderson <rth@twiddle.net>

---
v2
  - ensure compiler checks format strings even if debug is optimised out
v5
  - reword commit to justify not just using qemu_log at this time
v6
  - add r-b tag
v8
  - clean-up new flush_by_mmuidx functions
  - make message simpler
---
 cputlb.c | 88 ++++++++++++++++++++++++++++++++--------------------------------
 1 file changed, 44 insertions(+), 44 deletions(-)

diff --git a/cputlb.c b/cputlb.c
index 2f7a166..466663b 100644
--- a/cputlb.c
+++ b/cputlb.c
@@ -30,8 +30,30 @@
 #include "exec/ram_addr.h"
 #include "tcg/tcg.h"
 
-//#define DEBUG_TLB
-//#define DEBUG_TLB_CHECK
+/* DEBUG defines, enable DEBUG_TLB_LOG to log to the CPU_LOG_MMU target */
+/* #define DEBUG_TLB */
+/* #define DEBUG_TLB_LOG */
+
+#ifdef DEBUG_TLB
+# define DEBUG_TLB_GATE 1
+# ifdef DEBUG_TLB_LOG
+#  define DEBUG_TLB_LOG_GATE 1
+# else
+#  define DEBUG_TLB_LOG_GATE 0
+# endif
+#else
+# define DEBUG_TLB_GATE 0
+# define DEBUG_TLB_LOG_GATE 0
+#endif
+
+#define tlb_debug(fmt, ...) do { \
+    if (DEBUG_TLB_LOG_GATE) { \
+        qemu_log_mask(CPU_LOG_MMU, "%s: " fmt, __func__, \
+                      ## __VA_ARGS__); \
+    } else if (DEBUG_TLB_GATE) { \
+        fprintf(stderr, "%s: " fmt, __func__, ## __VA_ARGS__); \
+    } \
+} while (0)
 
 /* statistics */
 int tlb_flush_count;
@@ -52,9 +74,8 @@ void tlb_flush(CPUState *cpu, int flush_global)
 {
     CPUArchState *env = cpu->env_ptr;
 
-#if defined(DEBUG_TLB)
-    printf("tlb_flush:\n");
-#endif
+    tlb_debug("(%d)\n", flush_global);
+
     /* must reset current TB so that interrupts cannot modify the
        links while we are modifying them */
     cpu->current_tb = NULL;
@@ -73,9 +94,7 @@ static inline void v_tlb_flush_by_mmuidx(CPUState *cpu, va_list argp)
 {
     CPUArchState *env = cpu->env_ptr;
 
-#if defined(DEBUG_TLB)
-    printf("tlb_flush_by_mmuidx:");
-#endif
+    tlb_debug("start\n");
     /* must reset current TB so that interrupts cannot modify the
        links while we are modifying them */
     cpu->current_tb = NULL;
@@ -87,18 +106,12 @@ static inline void v_tlb_flush_by_mmuidx(CPUState *cpu, va_list argp)
             break;
         }
 
-#if defined(DEBUG_TLB)
-        printf(" %d", mmu_idx);
-#endif
+        tlb_debug("%d\n", mmu_idx);
 
         memset(env->tlb_table[mmu_idx], -1, sizeof(env->tlb_table[0]));
         memset(env->tlb_v_table[mmu_idx], -1, sizeof(env->tlb_v_table[0]));
     }
 
-#if defined(DEBUG_TLB)
-    printf("\n");
-#endif
-
     memset(cpu->tb_jmp_cache, 0, sizeof(cpu->tb_jmp_cache));
 }
 
@@ -128,16 +141,14 @@ void tlb_flush_page(CPUState *cpu, target_ulong addr)
     int i;
     int mmu_idx;
 
-#if defined(DEBUG_TLB)
-    printf("tlb_flush_page: " TARGET_FMT_lx "\n", addr);
-#endif
+    tlb_debug("page :" TARGET_FMT_lx "\n", addr);
+
     /* Check if we need to flush due to large pages.  */
     if ((addr & env->tlb_flush_mask) == env->tlb_flush_addr) {
-#if defined(DEBUG_TLB)
-        printf("tlb_flush_page: forced full flush ("
-               TARGET_FMT_lx "/" TARGET_FMT_lx ")\n",
-               env->tlb_flush_addr, env->tlb_flush_mask);
-#endif
+        tlb_debug("forcing full flush ("
+                  TARGET_FMT_lx "/" TARGET_FMT_lx ")\n",
+                  env->tlb_flush_addr, env->tlb_flush_mask);
+
         tlb_flush(cpu, 1);
         return;
     }
@@ -170,16 +181,14 @@ void tlb_flush_page_by_mmuidx(CPUState *cpu, target_ulong addr, ...)
 
     va_start(argp, addr);
 
-#if defined(DEBUG_TLB)
-    printf("tlb_flush_page_by_mmu_idx: " TARGET_FMT_lx, addr);
-#endif
+    tlb_debug("addr "TARGET_FMT_lx"\n", addr);
+
     /* Check if we need to flush due to large pages.  */
     if ((addr & env->tlb_flush_mask) == env->tlb_flush_addr) {
-#if defined(DEBUG_TLB)
-        printf(" forced full flush ("
-               TARGET_FMT_lx "/" TARGET_FMT_lx ")\n",
-               env->tlb_flush_addr, env->tlb_flush_mask);
-#endif
+        tlb_debug("forced full flush ("
+                  TARGET_FMT_lx "/" TARGET_FMT_lx ")\n",
+                  env->tlb_flush_addr, env->tlb_flush_mask);
+
         v_tlb_flush_by_mmuidx(cpu, argp);
         va_end(argp);
         return;
@@ -198,9 +207,7 @@ void tlb_flush_page_by_mmuidx(CPUState *cpu, target_ulong addr, ...)
             break;
         }
 
-#if defined(DEBUG_TLB)
-        printf(" %d", mmu_idx);
-#endif
+        tlb_debug("idx %d\n", mmu_idx);
 
         tlb_flush_entry(&env->tlb_table[mmu_idx][i], addr);
 
@@ -211,10 +218,6 @@ void tlb_flush_page_by_mmuidx(CPUState *cpu, target_ulong addr, ...)
     }
     va_end(argp);
 
-#if defined(DEBUG_TLB)
-    printf("\n");
-#endif
-
     tb_flush_jmp_cache(cpu, addr);
 }
 
@@ -367,12 +370,9 @@ void tlb_set_page_with_attrs(CPUState *cpu, target_ulong vaddr,
     section = address_space_translate_for_iotlb(cpu, asidx, paddr, &xlat, &sz);
     assert(sz >= TARGET_PAGE_SIZE);
 
-#if defined(DEBUG_TLB)
-    qemu_log_mask(CPU_LOG_MMU,
-           "tlb_set_page: vaddr=" TARGET_FMT_lx " paddr=0x" TARGET_FMT_plx
-           " prot=%x idx=%d\n",
-           vaddr, paddr, prot, mmu_idx);
-#endif
+    tlb_debug("vaddr=" TARGET_FMT_lx " paddr=0x" TARGET_FMT_plx
+              " prot=%x idx=%d\n",
+              vaddr, paddr, prot, mmu_idx);
 
     address = vaddr;
     if (!memory_region_is_ram(section->mr) && !memory_region_is_romd(section->mr)) {
-- 
2.7.2

[Qemu-devel] [PATCH v9 1/9] tcg: pass down TranslationBlock to tcg_code_gen

[Alex Bennée]

My later debugging patches need access to the origin PC which is held in
the TranslationBlock structure. Pass down the whole structure as it also
holds the information about the code start point.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Richard Henderson  <rth@twiddle.net>

---
v1
 - checkpatch fixes
v5
 - much simplified due to changes since last posting
v6
 - remove needless tweaking of gen_code_buf in tb_gen_code
v8
 - Add r-b tag
---
 tcg/tcg.c       | 6 +++---
 tcg/tcg.h       | 2 +-
 translate-all.c | 2 +-
 3 files changed, 5 insertions(+), 5 deletions(-)

diff --git a/tcg/tcg.c b/tcg/tcg.c
index 550671b..bbe3835 100644
--- a/tcg/tcg.c
+++ b/tcg/tcg.c
@@ -2328,7 +2328,7 @@ void tcg_dump_op_count(FILE *f, fprintf_function cpu_fprintf)
 #endif
 
 
-int tcg_gen_code(TCGContext *s, tcg_insn_unit *gen_code_buf)
+int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
 {
     int i, oi, oi_next, num_insns;
 
@@ -2387,8 +2387,8 @@ int tcg_gen_code(TCGContext *s, tcg_insn_unit *gen_code_buf)
 
     tcg_reg_alloc_start(s);
 
-    s->code_buf = gen_code_buf;
-    s->code_ptr = gen_code_buf;
+    s->code_buf = tb->tc_ptr;
+    s->code_ptr = tb->tc_ptr;
 
     tcg_out_tb_init(s);
 
diff --git a/tcg/tcg.h b/tcg/tcg.h
index b83f763..40c8fbe 100644
--- a/tcg/tcg.h
+++ b/tcg/tcg.h
@@ -636,7 +636,7 @@ void tcg_context_init(TCGContext *s);
 void tcg_prologue_init(TCGContext *s);
 void tcg_func_start(TCGContext *s);
 
-int tcg_gen_code(TCGContext *s, tcg_insn_unit *gen_code_buf);
+int tcg_gen_code(TCGContext *s, TranslationBlock *tb);
 
 void tcg_set_frame(TCGContext *s, TCGReg reg, intptr_t start, intptr_t size);
 
diff --git a/translate-all.c b/translate-all.c
index e9f409b..b3207fe 100644
--- a/translate-all.c
+++ b/translate-all.c
@@ -1120,7 +1120,7 @@ TranslationBlock *tb_gen_code(CPUState *cpu,
        the tcg optimization currently hidden inside tcg_gen_code.  All
        that should be required is to flush the TBs, allocate a new TB,
        re-initialize it per above, and re-do the actual code generation.  */
-    gen_code_size = tcg_gen_code(&tcg_ctx, gen_code_buf);
+    gen_code_size = tcg_gen_code(&tcg_ctx, tb);
     if (unlikely(gen_code_size < 0)) {
         goto buffer_overflow;
     }
-- 
2.7.2

[Qemu-devel] [PATCH v9 2/9] qemu-log: correct help text for -d cpu

[Alex Bennée]

This doesn't just dump CPU state on translation but on every block
entrance.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Andreas Färber <afaerber@suse.de>
Reviewed-by: Richard Henderson <rth@twiddle.net>

---
v4
  - add r-b tag
v5
  - slightly tweak the wording now nochain exists
v6
  - add rth r-b tag
---
 util/log.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/util/log.c b/util/log.c
index 8b921de..a14d480 100644
--- a/util/log.c
+++ b/util/log.c
@@ -120,7 +120,7 @@ const QEMULogItem qemu_log_items[] = {
     { CPU_LOG_EXEC, "exec",
       "show trace before each executed TB (lots of logs)" },
     { CPU_LOG_TB_CPU, "cpu",
-      "show CPU state before block translation" },
+      "show CPU registers before entering a TB (lots of logs)" },
     { CPU_LOG_MMU, "mmu",
       "log MMU-related activities" },
     { CPU_LOG_PCALL, "pcall",
-- 
2.7.2

[Qemu-devel] [PATCH v9 3/9] qemu-log: Avoid function call for disabled qemu_log_mask logging

[Alex Bennée]

From: Peter Maydell <peter.maydell@linaro.org>

Make qemu_log_mask() a macro which only calls the function to
do the actual work if the logging is enabled. This avoids making
a function call in possible fast paths where logging is disabled.

Signed-off-by: Peter Maydell <peter.maydell@linaro.org>
Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Andreas Färber <afaerber@suse.de>

---
v4
  - fix s-o-b tags, add r-b tag
---
 include/qemu/log.h | 13 ++++++++++---
 util/log.c         | 11 -----------
 2 files changed, 10 insertions(+), 14 deletions(-)

diff --git a/include/qemu/log.h b/include/qemu/log.h
index 40c24fd..523c886 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -66,10 +66,17 @@ qemu_log_vprintf(const char *fmt, va_list va)
     }
 }
 
-/* log only if a bit is set on the current loglevel mask
+/* log only if a bit is set on the current loglevel mask:
+ * @mask: bit to check in the mask
+ * @fmt: printf-style format string
+ * @args: optional arguments for format string
  */
-void GCC_FMT_ATTR(2, 3) qemu_log_mask(int mask, const char *fmt, ...);
-
+#define qemu_log_mask(MASK, FMT, ...)                   \
+    do {                                                \
+        if (unlikely(qemu_loglevel_mask(MASK))) {       \
+            qemu_log(FMT, ## __VA_ARGS__);              \
+        }                                               \
+    } while (0)
 
 /* Maintenance: */
 
diff --git a/util/log.c b/util/log.c
index a14d480..4e69586 100644
--- a/util/log.c
+++ b/util/log.c
@@ -38,17 +38,6 @@ void qemu_log(const char *fmt, ...)
     va_end(ap);
 }
 
-void qemu_log_mask(int mask, const char *fmt, ...)
-{
-    va_list ap;
-
-    va_start(ap, fmt);
-    if ((qemu_loglevel & mask) && qemu_logfile) {
-        vfprintf(qemu_logfile, fmt, ap);
-    }
-    va_end(ap);
-}
-
 /* enable or disable low levels log */
 void do_qemu_set_log(int log_flags, bool use_own_buffers)
 {
-- 
2.7.2

[Qemu-devel] [PATCH v9 4/9] qemu-log: Improve the "exec" TB execution logging

[Alex Bennée]

From: Peter Maydell <peter.maydell@linaro.org>

Improve the TB execution logging so that it is easier to identify
what is happening from trace logs:
 * move the "Trace" logging of executed TBs into cpu_tb_exec()
   so that it is emitted if and only if we actually execute a TB,
   and for consistency for the CPU state logging
 * log when we link two TBs together via tb_add_jump()
 * log when cpu_tb_exec() returns early from a chain of TBs

The new style logging looks like this:

Trace 0x7fb7cc822ca0 [ffffffc0000dce00]
Linking TBs 0x7fb7cc822ca0 [ffffffc0000dce00] index 0 -> 0x7fb7cc823110 [ffffffc0000dce10]
Trace 0x7fb7cc823110 [ffffffc0000dce10]
Trace 0x7fb7cc823420 [ffffffc000302688]
Trace 0x7fb7cc8234a0 [ffffffc000302698]
Trace 0x7fb7cc823520 [ffffffc0003026a4]
Trace 0x7fb7cc823560 [ffffffc0000dce44]
Linking TBs 0x7fb7cc823560 [ffffffc0000dce44] index 1 -> 0x7fb7cc8235d0 [ffffffc0000dce70]
Trace 0x7fb7cc8235d0 [ffffffc0000dce70]
Stopped execution of TB chain before 0x7fb7cc8235d0 [ffffffc0000dce70]
Trace 0x7fb7cc8235d0 [ffffffc0000dce70]
Trace 0x7fb7cc822fd0 [ffffffc0000dd52c]

Signed-off-by: Peter Maydell <peter.maydell@linaro.org>
Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
[AJB: reword patch title, Abandoned->Stopped]
Reviewed-by: Aurelien Jarno <aurelien@aurel32.net>
Reviewed-by: Richard Henderson <rth@twiddle.net>

---
v6
  - Abandoned -> Stopped
  - Added r-b tag
---
 cpu-exec.c              | 20 +++++++++++---------
 include/exec/exec-all.h |  3 +++
 2 files changed, 14 insertions(+), 9 deletions(-)

diff --git a/cpu-exec.c b/cpu-exec.c
index fd92452..6206cdf 100644
--- a/cpu-exec.c
+++ b/cpu-exec.c
@@ -133,10 +133,14 @@ static void init_delay_params(SyncClocks *sc, const CPUState *cpu)
 #endif /* CONFIG USER ONLY */
 
 /* Execute a TB, and fix up the CPU state afterwards if necessary */
-static inline tcg_target_ulong cpu_tb_exec(CPUState *cpu, uint8_t *tb_ptr)
+static inline tcg_target_ulong cpu_tb_exec(CPUState *cpu, TranslationBlock *itb)
 {
     CPUArchState *env = cpu->env_ptr;
     uintptr_t next_tb;
+    uint8_t *tb_ptr = itb->tc_ptr;
+
+    qemu_log_mask(CPU_LOG_EXEC, "Trace %p [" TARGET_FMT_lx "] %s\n",
+                  itb->tc_ptr, itb->pc, lookup_symbol(itb->pc));
 
 #if defined(DEBUG_DISAS)
     if (qemu_loglevel_mask(CPU_LOG_TB_CPU)) {
@@ -167,6 +171,10 @@ static inline tcg_target_ulong cpu_tb_exec(CPUState *cpu, uint8_t *tb_ptr)
          */
         CPUClass *cc = CPU_GET_CLASS(cpu);
         TranslationBlock *tb = (TranslationBlock *)(next_tb & ~TB_EXIT_MASK);
+        qemu_log_mask(CPU_LOG_EXEC,
+                      "Stopped execution of TB chain before %p ["
+                      TARGET_FMT_lx "] %s\n",
+                      itb->tc_ptr, itb->pc, lookup_symbol(itb->pc));
         if (cc->synchronize_from_tb) {
             cc->synchronize_from_tb(cpu, tb);
         } else {
@@ -202,7 +210,7 @@ static void cpu_exec_nocache(CPUState *cpu, int max_cycles,
     cpu->current_tb = tb;
     /* execute the generated code */
     trace_exec_tb_nocache(tb, tb->pc);
-    cpu_tb_exec(cpu, tb->tc_ptr);
+    cpu_tb_exec(cpu, tb);
     cpu->current_tb = NULL;
     tb_phys_invalidate(tb, -1);
     tb_free(tb);
@@ -344,7 +352,6 @@ int cpu_exec(CPUState *cpu)
 #endif
     int ret, interrupt_request;
     TranslationBlock *tb;
-    uint8_t *tc_ptr;
     uintptr_t next_tb;
     SyncClocks sc;
 
@@ -500,10 +507,6 @@ int cpu_exec(CPUState *cpu)
                     next_tb = 0;
                     tcg_ctx.tb_ctx.tb_invalidated_flag = 0;
                 }
-                if (qemu_loglevel_mask(CPU_LOG_EXEC)) {
-                    qemu_log("Trace %p [" TARGET_FMT_lx "] %s\n",
-                             tb->tc_ptr, tb->pc, lookup_symbol(tb->pc));
-                }
                 /* see if we can patch the calling TB. When the TB
                    spans two pages, we cannot safely do a direct
                    jump. */
@@ -515,10 +518,9 @@ int cpu_exec(CPUState *cpu)
                 tb_unlock();
                 if (likely(!cpu->exit_request)) {
                     trace_exec_tb(tb, tb->pc);
-                    tc_ptr = tb->tc_ptr;
                     /* execute the generated code */
                     cpu->current_tb = tb;
-                    next_tb = cpu_tb_exec(cpu, tc_ptr);
+                    next_tb = cpu_tb_exec(cpu, tb);
                     cpu->current_tb = NULL;
                     switch (next_tb & TB_EXIT_MASK) {
                     case TB_EXIT_REQUESTED:
diff --git a/include/exec/exec-all.h b/include/exec/exec-all.h
index 05a151d..1823ee3 100644
--- a/include/exec/exec-all.h
+++ b/include/exec/exec-all.h
@@ -379,6 +379,9 @@ static inline void tb_add_jump(TranslationBlock *tb, int n,
 {
     /* NOTE: this test is only needed for thread safety */
     if (!tb->jmp_next[n]) {
+        qemu_log_mask(CPU_LOG_EXEC, "Linking TBs %p [" TARGET_FMT_lx
+                      "] index %d -> %p [" TARGET_FMT_lx "]\n",
+                      tb->tc_ptr, tb->pc, n, tb_next->tc_ptr, tb_next->pc);
         /* patch the native jump address */
         tb_set_jmp_target(tb, n, (uintptr_t)tb_next->tc_ptr);
 
-- 
2.7.2

[Qemu-devel] [PATCH v9 5/9] qemu-log: new option -dfilter to limit output

[Alex Bennée]

When debugging big programs or system emulation sometimes you want both
the verbosity of cpu,exec et all but don't want to generate lots of logs
for unneeded stuff. This patch adds a new option -dfilter which allows
you to specify interesting address ranges in the form:

  -dfilter 0x8000..0x8fff,0xffffffc000080000+0x200,...

Then logging code can use the new qemu_log_in_addr_range() function to
decide if it will output logging information for the given range.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>

---

v2
  - More clean-ups to the documentation
v3
  - re-base
  - use GArray instead of GList to avoid cache bouncing
  - checkpatch fixes
v5
  - minor re-base conflicts
  - *did not* convert to -d dfilter=x fmt as easier to document
  - strtoul -> qemu_strtoul
  - fix a few checkpatch spacing warnings
  - made range operator .., - now intuitively subtracts from start
  - no added r-b tag as changes a bit
v6
  - make parsing suck less (stroull, strstr, err)
  - add some basic unit tests
v8
 - handle +0 and off-by-one length
 - add more parse fail tests
 - fix osdep.h include
 - corrected option help text
v9
 - also fix - off-by-one case
 - minor re-factoring to avoid too much repetition
---
 include/qemu/log.h   |   2 +
 qemu-options.hx      |  18 +++++++++
 tests/Makefile       |   4 ++
 tests/test-logging.c | 107 +++++++++++++++++++++++++++++++++++++++++++++++++++
 util/log.c           |  85 ++++++++++++++++++++++++++++++++++++++++
 vl.c                 |   3 ++
 6 files changed, 219 insertions(+)
 create mode 100644 tests/test-logging.c

diff --git a/include/qemu/log.h b/include/qemu/log.h
index 523c886..1d0222d 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -122,6 +122,8 @@ static inline void qemu_set_log(int log_flags)
 }
 
 void qemu_set_log_filename(const char *filename);
+void qemu_set_dfilter_ranges(const char *ranges);
+bool qemu_log_in_addr_range(uint64_t addr);
 int qemu_str_to_log_mask(const char *str);
 
 /* Print a usage message listing all the valid logging categories
diff --git a/qemu-options.hx b/qemu-options.hx
index 0cf7bb9..2b91ef8 100644
--- a/qemu-options.hx
+++ b/qemu-options.hx
@@ -3149,6 +3149,24 @@ STEXI
 Output log in @var{logfile} instead of to stderr
 ETEXI
 
+DEF("dfilter", HAS_ARG, QEMU_OPTION_DFILTER, \
+    "-dfilter range,..  filter debug output to range of addresses (useful for -d cpu,exec,etc..)\n",
+    QEMU_ARCH_ALL)
+STEXI
+@item -dfilter @var{range1}[,...]
+@findex -dfilter
+Filter debug output to that relevant to a range of target addresses. The filter
+spec can be either @var{start}+@var{size}, @var{start}-@var{size} or
+@var{start}..@var{end} where @var{start} @var{end} and @var{size} are the
+addresses and sizes required. For example:
+@example
+    -dfilter 0x8000..0x8fff,0xffffffc000080000+0x200,0xffffffc000060000-0x1000
+@end example
+Will dump output for any code in the 0x1000 sized block starting at 0x8000 and
+the 0x200 sized block starting at 0xffffffc000080000 and another 0x1000 sized
+block starting at 0xffffffc00005f000.
+ETEXI
+
 DEF("L", HAS_ARG, QEMU_OPTION_L, \
     "-L path         set the directory for the BIOS, VGA BIOS and keymaps\n",
     QEMU_ARCH_ALL)
diff --git a/tests/Makefile b/tests/Makefile
index cd4bbd4..721a174 100644
--- a/tests/Makefile
+++ b/tests/Makefile
@@ -92,6 +92,8 @@ check-unit-$(CONFIG_GNUTLS) += tests/test-io-channel-tls$(EXESUF)
 check-unit-y += tests/test-io-channel-command$(EXESUF)
 check-unit-y += tests/test-io-channel-buffer$(EXESUF)
 check-unit-y += tests/test-base64$(EXESUF)
+gcov-files-test-logging-y = tests/test-logging.c
+check-unit-y += tests/test-logging$(EXESUF)
 
 check-block-$(CONFIG_POSIX) += tests/qemu-iotests-quick.sh
 
@@ -431,6 +433,8 @@ tests/test-timed-average$(EXESUF): tests/test-timed-average.o qemu-timer.o \
 tests/test-base64$(EXESUF): tests/test-base64.o \
 	libqemuutil.a libqemustub.a
 
+tests/test-logging$(EXESUF): tests/test-logging.o $(test-util-obj-y)
+
 tests/test-qapi-types.c tests/test-qapi-types.h :\
 $(SRC_PATH)/tests/qapi-schema/qapi-schema-test.json $(SRC_PATH)/scripts/qapi-types.py $(qapi-py)
 	$(call quiet-command,$(PYTHON) $(SRC_PATH)/scripts/qapi-types.py \
diff --git a/tests/test-logging.c b/tests/test-logging.c
new file mode 100644
index 0000000..193fa92
--- /dev/null
+++ b/tests/test-logging.c
@@ -0,0 +1,107 @@
+/*
+ * logging unit-tests
+ *
+ * Copyright (C) 2016 Linaro Ltd.
+ *
+ *  Author: Alex Bennée <alex.bennee@linaro.org>
+ *
+ * Permission is hereby granted, free of charge, to any person obtaining a copy
+ * of this software and associated documentation files (the "Software"), to deal
+ * in the Software without restriction, including without limitation the rights
+ * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+ * copies of the Software, and to permit persons to whom the Software is
+ * furnished to do so, subject to the following conditions:
+ *
+ * The above copyright notice and this permission notice shall be included in
+ * all copies or substantial portions of the Software.
+ *
+ * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+ * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+ * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL
+ * THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+ * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+ * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
+ * THE SOFTWARE.
+ */
+
+#include "qemu/osdep.h"
+#include <glib.h>
+
+#include "qemu-common.h"
+#include "include/qemu/log.h"
+
+static void test_parse_range(void)
+{
+    qemu_set_dfilter_ranges("0x1000+0x100");
+
+    g_assert_false(qemu_log_in_addr_range(0xfff));
+    g_assert(qemu_log_in_addr_range(0x1000));
+    g_assert(qemu_log_in_addr_range(0x1001));
+    g_assert(qemu_log_in_addr_range(0x10ff));
+    g_assert_false(qemu_log_in_addr_range(0x1100));
+
+    qemu_set_dfilter_ranges("0x1000-0x100");
+
+    g_assert_false(qemu_log_in_addr_range(0x1001));
+    g_assert(qemu_log_in_addr_range(0x1000));
+    g_assert(qemu_log_in_addr_range(0x0f01));
+    g_assert_false(qemu_log_in_addr_range(0x0f00));
+
+    qemu_set_dfilter_ranges("0x1000..0x1100");
+
+    g_assert_false(qemu_log_in_addr_range(0xfff));
+    g_assert(qemu_log_in_addr_range(0x1000));
+    g_assert(qemu_log_in_addr_range(0x1100));
+    g_assert_false(qemu_log_in_addr_range(0x1101));
+
+    qemu_set_dfilter_ranges("0x1000..0x1000");
+
+    g_assert_false(qemu_log_in_addr_range(0xfff));
+    g_assert(qemu_log_in_addr_range(0x1000));
+    g_assert_false(qemu_log_in_addr_range(0x1001));
+
+    qemu_set_dfilter_ranges("0x1000+0x100,0x2100-0x100,0x3000..0x3100");
+    g_assert(qemu_log_in_addr_range(0x1050));
+    g_assert(qemu_log_in_addr_range(0x2050));
+    g_assert(qemu_log_in_addr_range(0x3050));
+}
+
+#ifdef CONFIG_HAS_GLIB_SUBPROCESS_TESTS
+static void test_parse_invalid_range_subprocess(void)
+{
+    qemu_set_dfilter_ranges("0x1000+onehundred");
+}
+static void test_parse_invalid_range(void)
+{
+    g_test_trap_subprocess("/logging/parse_invalid_range/subprocess", 0, 0);
+    g_test_trap_assert_failed();
+    g_test_trap_assert_stdout("");
+    g_test_trap_assert_stderr("*Failed to parse range in: 0x1000+onehundred\n");
+}
+static void test_parse_zero_range_subprocess(void)
+{
+    qemu_set_dfilter_ranges("0x1000+0");
+}
+static void test_parse_zero_range(void)
+{
+    g_test_trap_subprocess("/logging/parse_zero_range/subprocess", 0, 0);
+    g_test_trap_assert_failed();
+    g_test_trap_assert_stdout("");
+    g_test_trap_assert_stderr("*Failed to parse range in: 0x1000+0\n");
+}
+#endif
+
+int main(int argc, char **argv)
+{
+    g_test_init(&argc, &argv, NULL);
+
+    g_test_add_func("/logging/parse_range", test_parse_range);
+#ifdef CONFIG_HAS_GLIB_SUBPROCESS_TESTS
+    g_test_add_func("/logging/parse_invalid_range/subprocess", test_parse_invalid_range_subprocess);
+    g_test_add_func("/logging/parse_invalid_range", test_parse_invalid_range);
+    g_test_add_func("/logging/parse_zero_range/subprocess", test_parse_zero_range_subprocess);
+    g_test_add_func("/logging/parse_zero_range", test_parse_zero_range);
+#endif
+
+    return g_test_run();
+}
diff --git a/util/log.c b/util/log.c
index 4e69586..10a917b 100644
--- a/util/log.c
+++ b/util/log.c
@@ -20,12 +20,14 @@
 #include "qemu/osdep.h"
 #include "qemu-common.h"
 #include "qemu/log.h"
+#include "qemu/range.h"
 #include "trace/control.h"
 
 static char *logfilename;
 FILE *qemu_logfile;
 int qemu_loglevel;
 static int log_append = 0;
+static GArray *debug_regions;
 
 void qemu_log(const char *fmt, ...)
 {
@@ -94,6 +96,89 @@ void qemu_set_log_filename(const char *filename)
     qemu_set_log(qemu_loglevel);
 }
 
+/* Returns true if addr is in our debug filter or no filter defined
+ */
+bool qemu_log_in_addr_range(uint64_t addr)
+{
+    if (debug_regions) {
+        int i = 0;
+        for (i = 0; i < debug_regions->len; i++) {
+            struct Range *range = &g_array_index(debug_regions, Range, i);
+            if (addr >= range->begin && addr <= range->end) {
+                return true;
+            }
+        }
+        return false;
+    } else {
+        return true;
+    }
+}
+
+
+void qemu_set_dfilter_ranges(const char *filter_spec)
+{
+    gchar **ranges = g_strsplit(filter_spec, ",", 0);
+    if (ranges) {
+        gchar **next = ranges;
+        gchar *r = *next++;
+        debug_regions = g_array_sized_new(FALSE, FALSE,
+                                          sizeof(Range), g_strv_length(ranges));
+        while (r) {
+            char *range_op = strstr(r, "-");
+            char *r2 = range_op ? range_op + 1 : NULL;
+            if (!range_op) {
+                range_op = strstr(r, "+");
+                r2 = range_op ? range_op + 1 : NULL;
+            }
+            if (!range_op) {
+                range_op = strstr(r, "..");
+                r2 = range_op ? range_op + 2 : NULL;
+            }
+            if (range_op) {
+                const char *e = NULL;
+                unsigned long r1val, r2val;
+
+                if ((qemu_strtoull(r, &e, 0, &r1val) == 0) &&
+                    (qemu_strtoull(r2, NULL, 0, &r2val) == 0) &&
+                    r2val > 0) {
+                    struct Range range;
+
+                    g_assert(e == range_op);
+
+                    switch (*range_op) {
+                    case '+':
+                    {
+                        range.begin = r1val;
+                        range.end = r1val + (r2val - 1);
+                        break;
+                    }
+                    case '-':
+                    {
+                        range.end = r1val;
+                        range.begin = r1val - (r2val - 1);
+                        break;
+                    }
+                    case '.':
+                        range.begin = r1val;
+                        range.end = r2val;
+                        break;
+                    default:
+                        g_assert_not_reached();
+                    }
+                    g_array_append_val(debug_regions, range);
+
+                } else {
+                    g_error("Failed to parse range in: %s", r);
+                }
+            } else {
+                g_error("Bad range specifier in: %s", r);
+            }
+            r = *next++;
+        }
+        g_strfreev(ranges);
+    }
+}
+
 const QEMULogItem qemu_log_items[] = {
     { CPU_LOG_TB_OUT_ASM, "out_asm",
       "show generated host assembly code for each compiled TB" },
diff --git a/vl.c b/vl.c
index 7a28982..b8ada4e 100644
--- a/vl.c
+++ b/vl.c
@@ -3354,6 +3354,9 @@ int main(int argc, char **argv, char **envp)
             case QEMU_OPTION_D:
                 log_file = optarg;
                 break;
+            case QEMU_OPTION_DFILTER:
+                qemu_set_dfilter_ranges(optarg);
+                break;
             case QEMU_OPTION_s:
                 add_device_config(DEV_GDB, "tcp::" DEFAULT_GDBSTUB_PORT);
                 break;
-- 
2.7.2

[Qemu-devel] [PATCH v9 6/9] qemu-log: dfilter-ise exec, out_asm, op and opt_op

[Alex Bennée]

This ensures the code generation debug code will honour -dfilter if set.
For the "exec" tracing I've added a new inline macro for efficiency's
sake.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Aurelien Jarno <aurelien@aureL32.net>
Reviewed-by: Richard Henderson <rth@twiddle.net>

----
v2
   - checkpatch updates
   - add qemu_log_mask_and_addr macro for inline dump for traces
   - re-base on re-factored tcg layout
   - include new Trace & Link lines
v5
   - add r-b tag
   - slight reword to commit now LOG_OP is common
v6
   - minor merge conflict with earlier patch
   - add r-b tag
---
 cpu-exec.c              | 13 +++++++------
 include/exec/exec-all.h |  8 +++++---
 include/qemu/log.h      | 15 +++++++++++++++
 tcg/tcg.c               |  6 ++++--
 translate-all.c         |  3 ++-
 5 files changed, 33 insertions(+), 12 deletions(-)

diff --git a/cpu-exec.c b/cpu-exec.c
index 6206cdf..bbfcbfb 100644
--- a/cpu-exec.c
+++ b/cpu-exec.c
@@ -139,8 +139,9 @@ static inline tcg_target_ulong cpu_tb_exec(CPUState *cpu, TranslationBlock *itb)
     uintptr_t next_tb;
     uint8_t *tb_ptr = itb->tc_ptr;
 
-    qemu_log_mask(CPU_LOG_EXEC, "Trace %p [" TARGET_FMT_lx "] %s\n",
-                  itb->tc_ptr, itb->pc, lookup_symbol(itb->pc));
+    qemu_log_mask_and_addr(CPU_LOG_EXEC, itb->pc,
+                           "Trace %p [" TARGET_FMT_lx "] %s\n",
+                           itb->tc_ptr, itb->pc, lookup_symbol(itb->pc));
 
 #if defined(DEBUG_DISAS)
     if (qemu_loglevel_mask(CPU_LOG_TB_CPU)) {
@@ -171,10 +172,10 @@ static inline tcg_target_ulong cpu_tb_exec(CPUState *cpu, TranslationBlock *itb)
          */
         CPUClass *cc = CPU_GET_CLASS(cpu);
         TranslationBlock *tb = (TranslationBlock *)(next_tb & ~TB_EXIT_MASK);
-        qemu_log_mask(CPU_LOG_EXEC,
-                      "Stopped execution of TB chain before %p ["
-                      TARGET_FMT_lx "] %s\n",
-                      itb->tc_ptr, itb->pc, lookup_symbol(itb->pc));
+        qemu_log_mask_and_addr(CPU_LOG_EXEC, itb->pc,
+                               "Stopped execution of TB chain before %p ["
+                               TARGET_FMT_lx "] %s\n",
+                               itb->tc_ptr, itb->pc, lookup_symbol(itb->pc));
         if (cc->synchronize_from_tb) {
             cc->synchronize_from_tb(cpu, tb);
         } else {
diff --git a/include/exec/exec-all.h b/include/exec/exec-all.h
index 1823ee3..7362095 100644
--- a/include/exec/exec-all.h
+++ b/include/exec/exec-all.h
@@ -379,9 +379,11 @@ static inline void tb_add_jump(TranslationBlock *tb, int n,
 {
     /* NOTE: this test is only needed for thread safety */
     if (!tb->jmp_next[n]) {
-        qemu_log_mask(CPU_LOG_EXEC, "Linking TBs %p [" TARGET_FMT_lx
-                      "] index %d -> %p [" TARGET_FMT_lx "]\n",
-                      tb->tc_ptr, tb->pc, n, tb_next->tc_ptr, tb_next->pc);
+        qemu_log_mask_and_addr(CPU_LOG_EXEC, tb->pc,
+                               "Linking TBs %p [" TARGET_FMT_lx
+                               "] index %d -> %p [" TARGET_FMT_lx "]\n",
+                               tb->tc_ptr, tb->pc, n,
+                               tb_next->tc_ptr, tb_next->pc);
         /* patch the native jump address */
         tb_set_jmp_target(tb, n, (uintptr_t)tb_next->tc_ptr);
 
diff --git a/include/qemu/log.h b/include/qemu/log.h
index 1d0222d..cf38adb 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -78,6 +78,21 @@ qemu_log_vprintf(const char *fmt, va_list va)
         }                                               \
     } while (0)
 
+/* log only if a bit is set on the current loglevel mask
+ * and we are in the address range we care about:
+ * @mask: bit to check in the mask
+ * @addr: address to check in dfilter
+ * @fmt: printf-style format string
+ * @args: optional arguments for format string
+ */
+#define qemu_log_mask_and_addr(MASK, ADDR, FMT, ...)    \
+    do {                                                \
+        if (unlikely(qemu_loglevel_mask(MASK)) &&       \
+                     qemu_log_in_addr_range(ADDR)) {    \
+            qemu_log(FMT, ## __VA_ARGS__);              \
+        }                                               \
+    } while (0)
+
 /* Maintenance: */
 
 /* fflush() the log file */
diff --git a/tcg/tcg.c b/tcg/tcg.c
index bbe3835..83fecb6 100644
--- a/tcg/tcg.c
+++ b/tcg/tcg.c
@@ -2351,7 +2351,8 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
 #endif
 
 #ifdef DEBUG_DISAS
-    if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP))) {
+    if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP)
+                 && qemu_log_in_addr_range(tb->pc))) {
         qemu_log("OP:\n");
         tcg_dump_ops(s);
         qemu_log("\n");
@@ -2378,7 +2379,8 @@ int tcg_gen_code(TCGContext *s, TranslationBlock *tb)
 #endif
 
 #ifdef DEBUG_DISAS
-    if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP_OPT))) {
+    if (unlikely(qemu_loglevel_mask(CPU_LOG_TB_OP_OPT)
+                 && qemu_log_in_addr_range(tb->pc))) {
         qemu_log("OP after optimization and liveness analysis:\n");
         tcg_dump_ops(s);
         qemu_log("\n");
diff --git a/translate-all.c b/translate-all.c
index b3207fe..b4df1ec 100644
--- a/translate-all.c
+++ b/translate-all.c
@@ -1137,7 +1137,8 @@ TranslationBlock *tb_gen_code(CPUState *cpu,
 #endif
 
 #ifdef DEBUG_DISAS
-    if (qemu_loglevel_mask(CPU_LOG_TB_OUT_ASM)) {
+    if (qemu_loglevel_mask(CPU_LOG_TB_OUT_ASM) &&
+        qemu_log_in_addr_range(tb->pc)) {
         qemu_log("OUT: [size=%d]\n", gen_code_size);
         log_disas(tb->tc_ptr, gen_code_size);
         qemu_log("\n");
-- 
2.7.2

[Qemu-devel] [PATCH v9 7/9] target-arm: dfilter support for in_asm

[Alex Bennée]

Each individual architecture needs to use the qemu_log_in_addr_range()
feature for enabling in_asm output as it is part of the frontend.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Aurelien Jarno <aurelien@aurel32.net>
Reviewed-by: Richard Henderson  <rth@twiddle.net>

---
v5
  - no longer wrapping tcg_gen_insn_start (was tcg_gen_debug)
  - reword to handle only in_asm
  - added r-b tag
v8
  - added r-b tag
---
 target-arm/translate-a64.c | 3 ++-
 target-arm/translate.c     | 3 ++-
 2 files changed, 4 insertions(+), 2 deletions(-)

diff --git a/target-arm/translate-a64.c b/target-arm/translate-a64.c
index f0c73df..b13cff7 100644
--- a/target-arm/translate-a64.c
+++ b/target-arm/translate-a64.c
@@ -11225,7 +11225,8 @@ done_generating:
     gen_tb_end(tb, num_insns);
 
 #ifdef DEBUG_DISAS
-    if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM)) {
+    if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) &&
+        qemu_log_in_addr_range(pc_start)) {
         qemu_log("----------------\n");
         qemu_log("IN: %s\n", lookup_symbol(pc_start));
         log_target_disas(cs, pc_start, dc->pc - pc_start,
diff --git a/target-arm/translate.c b/target-arm/translate.c
index 025c7a5..78df0b6 100644
--- a/target-arm/translate.c
+++ b/target-arm/translate.c
@@ -11718,7 +11718,8 @@ done_generating:
     gen_tb_end(tb, num_insns);
 
 #ifdef DEBUG_DISAS
-    if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM)) {
+    if (qemu_loglevel_mask(CPU_LOG_TB_IN_ASM) &&
+        qemu_log_in_addr_range(pc_start)) {
         qemu_log("----------------\n");
         qemu_log("IN: %s\n", lookup_symbol(pc_start));
         log_target_disas(cs, pc_start, dc->pc - pc_start,
-- 
2.7.2

[Qemu-devel] [PATCH v9 8/9] qemu-log: support simple pid substitution for logs

[Alex Bennée]

When debugging stuff that occurs over several forks it would be useful
not to keep overwriting the one logfile you've set-up. This allows a
simple %d to be included once in the logfile parameter which is
substituted with getpid().

As the test cases involve checking user output they need
g_test_trap_subprocess() support. As a result they are currently skipped
on Travis builds due to the older glib involved.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Leandro Dorileo <l@dorileo.org>
Reviewed-by: Aurelien Jarno <aurelien@aurel32.net>
Reviewed-by: Richard Henderson  <rth@twiddle.net>

---
v5
  - add another r-b
v7
  - simpler error check as suggested by Eric Blake
  - don't g_error, just error_report (so we don't crash from monitor)
  - add some unit tests
v8
  - added rth's r-b tag
  - tweak subprocess tests
---
 tests/test-logging.c | 36 +++++++++++++++++++++++++++++++++++-
 util/log.c           | 22 ++++++++++++++++++++--
 2 files changed, 55 insertions(+), 3 deletions(-)

diff --git a/tests/test-logging.c b/tests/test-logging.c
index 193fa92..ac8deed 100644
--- a/tests/test-logging.c
+++ b/tests/test-logging.c
@@ -89,7 +89,37 @@ static void test_parse_zero_range(void)
     g_test_trap_assert_stdout("");
     g_test_trap_assert_stderr("*Failed to parse range in: 0x1000+0\n");
 }
-#endif
+
+/* As the only real failure from a bad log filename path spec is
+ * reporting to the user we have to use the g_test_trap_subprocess
+ * mechanism and check no errors reported on stderr.
+ */
+static void test_parse_path_subprocess(void)
+{
+    /* All these should work without issue */
+    qemu_set_log_filename("/tmp/qemu.log");
+    qemu_set_log_filename("/tmp/qemu-%d.log");
+    qemu_set_log_filename("/tmp/qemu.log.%d");
+}
+static void test_parse_path(void)
+{
+    g_test_trap_subprocess ("/logging/parse_path/subprocess", 0, 0);
+    g_test_trap_assert_passed();
+    g_test_trap_assert_stdout("");
+    g_test_trap_assert_stderr("");
+}
+static void test_parse_invalid_path_subprocess(void)
+{
+    qemu_set_log_filename("/tmp/qemu-%d%d.log");
+}
+static void test_parse_invalid_path(void)
+{
+    g_test_trap_subprocess ("/logging/parse_invalid_path/subprocess", 0, 0);
+    g_test_trap_assert_passed();
+    g_test_trap_assert_stdout("");
+    g_test_trap_assert_stderr("Bad logfile format: /tmp/qemu-%d%d.log\n");
+}
+#endif /* CONFIG_HAS_GLIB_SUBPROCESS_TESTS */
 
 int main(int argc, char **argv)
 {
@@ -101,6 +131,10 @@ int main(int argc, char **argv)
     g_test_add_func("/logging/parse_invalid_range", test_parse_invalid_range);
     g_test_add_func("/logging/parse_zero_range/subprocess", test_parse_zero_range_subprocess);
     g_test_add_func("/logging/parse_zero_range", test_parse_zero_range);
+    g_test_add_func("/logging/parse_path", test_parse_path);
+    g_test_add_func("/logging/parse_path/subprocess", test_parse_path_subprocess);
+    g_test_add_func("/logging/parse_invalid_path", test_parse_invalid_path);
+    g_test_add_func("/logging/parse_invalid_path/subprocess", test_parse_invalid_path_subprocess);
 #endif
 
     return g_test_run();
diff --git a/util/log.c b/util/log.c
index 10a917b..66370d2 100644
--- a/util/log.c
+++ b/util/log.c
@@ -21,6 +21,7 @@
 #include "qemu-common.h"
 #include "qemu/log.h"
 #include "qemu/range.h"
+#include "qemu/error-report.h"
 #include "trace/control.h"
 
 static char *logfilename;
@@ -87,11 +88,28 @@ void do_qemu_set_log(int log_flags, bool use_own_buffers)
         qemu_log_close();
     }
 }
-
+/*
+ * Allow the user to include %d in their logfile which will be
+ * substituted with the current PID. This is useful for debugging many
+ * nested linux-user tasks but will result in lots of logs.
+ */
 void qemu_set_log_filename(const char *filename)
 {
+    char *pidstr;
     g_free(logfilename);
-    logfilename = g_strdup(filename);
+
+    pidstr = strstr(filename, "%");
+    if (pidstr) {
+        /* We only accept one %d, no other format strings */
+        if (pidstr[1] != 'd' || strchr(pidstr + 2, '%')) {
+            error_report("Bad logfile format: %s", filename);
+            logfilename = NULL;
+        } else {
+            logfilename = g_strdup_printf(filename, getpid());
+        }
+    } else {
+        logfilename = g_strdup(filename);
+    }
     qemu_log_close();
     qemu_set_log(qemu_loglevel);
 }
-- 
2.7.2

[Qemu-devel] [PATCH v9 9/9] cputlb: modernise the debug support

[Alex Bennée]

To avoid cluttering the code with #ifdef legs we wrap up the print
statements into a tlb_debug() macro. As access to the virtual TLB can
get quite heavy defining DEBUG_TLB_LOG will ensure all the logs go to
the qemu_log target of CPU_LOG_MMU instead of stderr. This remains
compile time optional as these debug statements haven't been considered
for usefulness for user visible logging.

I've also removed DEBUG_TLB_CHECK which wasn't used.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
Reviewed-by: Richard Henderson <rth@twiddle.net>

---
v2
  - ensure compiler checks format strings even if debug is optimised out
v5
  - reword commit to justify not just using qemu_log at this time
v6
  - add r-b tag
v8
  - clean-up new flush_by_mmuidx functions
  - make message simpler
---
 cputlb.c | 88 ++++++++++++++++++++++++++++++++--------------------------------
 1 file changed, 44 insertions(+), 44 deletions(-)

diff --git a/cputlb.c b/cputlb.c
index 2f7a166..466663b 100644
--- a/cputlb.c
+++ b/cputlb.c
@@ -30,8 +30,30 @@
 #include "exec/ram_addr.h"
 #include "tcg/tcg.h"
 
-//#define DEBUG_TLB
-//#define DEBUG_TLB_CHECK
+/* DEBUG defines, enable DEBUG_TLB_LOG to log to the CPU_LOG_MMU target */
+/* #define DEBUG_TLB */
+/* #define DEBUG_TLB_LOG */
+
+#ifdef DEBUG_TLB
+# define DEBUG_TLB_GATE 1
+# ifdef DEBUG_TLB_LOG
+#  define DEBUG_TLB_LOG_GATE 1
+# else
+#  define DEBUG_TLB_LOG_GATE 0
+# endif
+#else
+# define DEBUG_TLB_GATE 0
+# define DEBUG_TLB_LOG_GATE 0
+#endif
+
+#define tlb_debug(fmt, ...) do { \
+    if (DEBUG_TLB_LOG_GATE) { \
+        qemu_log_mask(CPU_LOG_MMU, "%s: " fmt, __func__, \
+                      ## __VA_ARGS__); \
+    } else if (DEBUG_TLB_GATE) { \
+        fprintf(stderr, "%s: " fmt, __func__, ## __VA_ARGS__); \
+    } \
+} while (0)
 
 /* statistics */
 int tlb_flush_count;
@@ -52,9 +74,8 @@ void tlb_flush(CPUState *cpu, int flush_global)
 {
     CPUArchState *env = cpu->env_ptr;
 
-#if defined(DEBUG_TLB)
-    printf("tlb_flush:\n");
-#endif
+    tlb_debug("(%d)\n", flush_global);
+
     /* must reset current TB so that interrupts cannot modify the
        links while we are modifying them */
     cpu->current_tb = NULL;
@@ -73,9 +94,7 @@ static inline void v_tlb_flush_by_mmuidx(CPUState *cpu, va_list argp)
 {
     CPUArchState *env = cpu->env_ptr;
 
-#if defined(DEBUG_TLB)
-    printf("tlb_flush_by_mmuidx:");
-#endif
+    tlb_debug("start\n");
     /* must reset current TB so that interrupts cannot modify the
        links while we are modifying them */
     cpu->current_tb = NULL;
@@ -87,18 +106,12 @@ static inline void v_tlb_flush_by_mmuidx(CPUState *cpu, va_list argp)
             break;
         }
 
-#if defined(DEBUG_TLB)
-        printf(" %d", mmu_idx);
-#endif
+        tlb_debug("%d\n", mmu_idx);
 
         memset(env->tlb_table[mmu_idx], -1, sizeof(env->tlb_table[0]));
         memset(env->tlb_v_table[mmu_idx], -1, sizeof(env->tlb_v_table[0]));
     }
 
-#if defined(DEBUG_TLB)
-    printf("\n");
-#endif
-
     memset(cpu->tb_jmp_cache, 0, sizeof(cpu->tb_jmp_cache));
 }
 
@@ -128,16 +141,14 @@ void tlb_flush_page(CPUState *cpu, target_ulong addr)
     int i;
     int mmu_idx;
 
-#if defined(DEBUG_TLB)
-    printf("tlb_flush_page: " TARGET_FMT_lx "\n", addr);
-#endif
+    tlb_debug("page :" TARGET_FMT_lx "\n", addr);
+
     /* Check if we need to flush due to large pages.  */
     if ((addr & env->tlb_flush_mask) == env->tlb_flush_addr) {
-#if defined(DEBUG_TLB)
-        printf("tlb_flush_page: forced full flush ("
-               TARGET_FMT_lx "/" TARGET_FMT_lx ")\n",
-               env->tlb_flush_addr, env->tlb_flush_mask);
-#endif
+        tlb_debug("forcing full flush ("
+                  TARGET_FMT_lx "/" TARGET_FMT_lx ")\n",
+                  env->tlb_flush_addr, env->tlb_flush_mask);
+
         tlb_flush(cpu, 1);
         return;
     }
@@ -170,16 +181,14 @@ void tlb_flush_page_by_mmuidx(CPUState *cpu, target_ulong addr, ...)
 
     va_start(argp, addr);
 
-#if defined(DEBUG_TLB)
-    printf("tlb_flush_page_by_mmu_idx: " TARGET_FMT_lx, addr);
-#endif
+    tlb_debug("addr "TARGET_FMT_lx"\n", addr);
+
     /* Check if we need to flush due to large pages.  */
     if ((addr & env->tlb_flush_mask) == env->tlb_flush_addr) {
-#if defined(DEBUG_TLB)
-        printf(" forced full flush ("
-               TARGET_FMT_lx "/" TARGET_FMT_lx ")\n",
-               env->tlb_flush_addr, env->tlb_flush_mask);
-#endif
+        tlb_debug("forced full flush ("
+                  TARGET_FMT_lx "/" TARGET_FMT_lx ")\n",
+                  env->tlb_flush_addr, env->tlb_flush_mask);
+
         v_tlb_flush_by_mmuidx(cpu, argp);
         va_end(argp);
         return;
@@ -198,9 +207,7 @@ void tlb_flush_page_by_mmuidx(CPUState *cpu, target_ulong addr, ...)
             break;
         }
 
-#if defined(DEBUG_TLB)
-        printf(" %d", mmu_idx);
-#endif
+        tlb_debug("idx %d\n", mmu_idx);
 
         tlb_flush_entry(&env->tlb_table[mmu_idx][i], addr);
 
@@ -211,10 +218,6 @@ void tlb_flush_page_by_mmuidx(CPUState *cpu, target_ulong addr, ...)
     }
     va_end(argp);
 
-#if defined(DEBUG_TLB)
-    printf("\n");
-#endif
-
     tb_flush_jmp_cache(cpu, addr);
 }
 
@@ -367,12 +370,9 @@ void tlb_set_page_with_attrs(CPUState *cpu, target_ulong vaddr,
     section = address_space_translate_for_iotlb(cpu, asidx, paddr, &xlat, &sz);
     assert(sz >= TARGET_PAGE_SIZE);
 
-#if defined(DEBUG_TLB)
-    qemu_log_mask(CPU_LOG_MMU,
-           "tlb_set_page: vaddr=" TARGET_FMT_lx " paddr=0x" TARGET_FMT_plx
-           " prot=%x idx=%d\n",
-           vaddr, paddr, prot, mmu_idx);
-#endif
+    tlb_debug("vaddr=" TARGET_FMT_lx " paddr=0x" TARGET_FMT_plx
+              " prot=%x idx=%d\n",
+              vaddr, paddr, prot, mmu_idx);
 
     address = vaddr;
     if (!memory_region_is_ram(section->mr) && !memory_region_is_romd(section->mr)) {
-- 
2.7.2

Re: [Qemu-devel] [PATCH v9 0/9] qemu-log, -dfilter and other logging tweaks

[Richard Henderson]

On 03/15/2016 07:30 AM, Alex Bennée wrote:
> The only change since v8 is fixing the off-by-one in the dfilter -
> parsing case (the + case was fixed in v8).
>
> Ready for merge now?

Yep.

>
> Alex Bennée (7):
>    tcg: pass down TranslationBlock to tcg_code_gen
>    qemu-log: correct help text for -d cpu
>    qemu-log: new option -dfilter to limit output
>    qemu-log: dfilter-ise exec, out_asm, op and opt_op
>    target-arm: dfilter support for in_asm
>    qemu-log: support simple pid substitution for logs
>    cputlb: modernise the debug support
>
> Peter Maydell (2):
>    qemu-log: Avoid function call for disabled qemu_log_mask logging
>    qemu-log: Improve the "exec" TB execution logging

Reviewed-by: Richard Henderson <rth@twiddle.net>


r~

Re: [Qemu-devel] [PATCH v9 0/9] qemu-log, -dfilter and other logging tweaks

[Alex Bennée]

Richard Henderson <rth@twiddle.net> writes:

> On 03/15/2016 07:30 AM, Alex Bennée wrote:
>> The only change since v8 is fixing the off-by-one in the dfilter -
>> parsing case (the + case was fixed in v8).
>>
>> Ready for merge now?
>
> Yep.

Are you going to pull it in via your tree?

>>
>> Alex Bennée (7):
>>    tcg: pass down TranslationBlock to tcg_code_gen
>>    qemu-log: correct help text for -d cpu
>>    qemu-log: new option -dfilter to limit output
>>    qemu-log: dfilter-ise exec, out_asm, op and opt_op
>>    target-arm: dfilter support for in_asm
>>    qemu-log: support simple pid substitution for logs
>>    cputlb: modernise the debug support
>>
>> Peter Maydell (2):
>>    qemu-log: Avoid function call for disabled qemu_log_mask logging
>>    qemu-log: Improve the "exec" TB execution logging
>
> Reviewed-by: Richard Henderson <rth@twiddle.net>

Unless you want me to issue v10 with your tags?

--
Alex Bennée

Re: [Qemu-devel] [PATCH v9 0/9] qemu-log, -dfilter and other logging tweaks

[Richard Henderson]

On 03/15/2016 09:05 AM, Alex Bennée wrote:
>
> Richard Henderson <rth@twiddle.net> writes:
>
>> On 03/15/2016 07:30 AM, Alex Bennée wrote:
>>> The only change since v8 is fixing the off-by-one in the dfilter -
>>> parsing case (the + case was fixed in v8).
>>>
>>> Ready for merge now?
>>
>> Yep.
>
> Are you going to pull it in via your tree?

I'm happy for you to issue the pull.

> Unless you want me to issue v10 with your tags?

No, quite all right.


r~

Re: [Qemu-devel] [PATCH v9 0/9] qemu-log, -dfilter and other logging tweaks

[Alex Bennée]

Richard Henderson <rth@twiddle.net> writes:

> On 03/15/2016 09:05 AM, Alex Bennée wrote:
>>
>> Richard Henderson <rth@twiddle.net> writes:
>>
>>> On 03/15/2016 07:30 AM, Alex Bennée wrote:
>>>> The only change since v8 is fixing the off-by-one in the dfilter -
>>>> parsing case (the + case was fixed in v8).
>>>>
>>>> Ready for merge now?
>>>
>>> Yep.
>>
>> Are you going to pull it in via your tree?
>
> I'm happy for you to issue the pull.

Erm surely it needs to go via one of the maintainer trees? Peter won't
pull directly from me for TCG releated stuff.

>> Unless you want me to issue v10 with your tags?
>
> No, quite all right.
>
>
> r~


--
Alex Bennée

Re: [Qemu-devel] [PATCH v9 0/9] qemu-log, -dfilter and other logging tweaks

[Paolo Bonzini]

On 15/03/2016 19:09, Alex Bennée wrote:
> > > Are you going to pull it in via your tree?
> >
> > I'm happy for you to issue the pull.
> 
> Erm surely it needs to go via one of the maintainer trees? Peter won't
> pull directly from me for TCG releated stuff.

I can pull this then.

Paolo

Re: [Qemu-devel] [PATCH v9 0/9] qemu-log, -dfilter and other logging tweaks

[Alex Bennée]

Paolo Bonzini <pbonzini@redhat.com> writes:

> On 15/03/2016 19:09, Alex Bennée wrote:
>> > > Are you going to pull it in via your tree?
>> >
>> > I'm happy for you to issue the pull.
>>
>> Erm surely it needs to go via one of the maintainer trees? Peter won't
>> pull directly from me for TCG releated stuff.
>
> I can pull this then.

Thanks. Do you want a tree with Richard's reviewed-by tags?
>
> Paolo


--
Alex Bennée

Re: [Qemu-devel] [PATCH v9 0/9] qemu-log, -dfilter and other logging tweaks

[Paolo Bonzini]

On 16/03/2016 10:06, Alex Bennée wrote:
> > I can pull this then.
>
> Thanks. Do you want a tree with Richard's reviewed-by tags?

It's easier to add them myself, thanks though!

Paolo