qemu-devel.nongnu.org archive mirror
 help / color / mirror / Atom feed
* [Qemu-devel] [PATCH v2] qemu-log: add log category for MMU info
@ 2014-10-10 10:59 Antony Pavlov
  2014-10-10 14:47 ` Peter Maydell
  0 siblings, 1 reply; 3+ messages in thread
From: Antony Pavlov @ 2014-10-10 10:59 UTC (permalink / raw)
  To: qemu-devel
  Cc: Peter Maydell, Alexander Graf, Blue Swirl, Antony Pavlov,
	Edgar E. Iglesias, Guan Xuetao, Aurelien Jarno, Richard Henderson

Running barebox on qemu-system-mips* with '-d unimp' overloads
stderr by very very many mips_cpu_handle_mmu_fault() messages:

  mips_cpu_handle_mmu_fault address=b80003fd ret 0 physical 00000000180003fd prot 3
  mips_cpu_handle_mmu_fault address=a0800884 ret 0 physical 0000000000800884 prot 3
  mips_cpu_handle_mmu_fault pc a080cd80 ad b80003fd rw 0 mmu_idx 0

So it's very difficult to find LOG_UNIMP message.

The mips_cpu_handle_mmu_fault() messages appears on enabling ANY
logging! It's not very handy.

Adding separate log category for *_cpu_handle_mmu_fault()
logging fixes the problem.

Signed-off-by: Antony Pavlov <antonynpavlov@gmail.com>
---

Changes since v1:

 * add cris, i386, microblaze, ppc, s390x, sparc and unicore32 support.

---

 cputlb.c                   |  3 ++-
 include/qemu/log.h         |  1 +
 qemu-log.c                 |  2 ++
 target-cris/helper.c       | 12 +++++++-----
 target-i386/helper.c       | 18 +++++++++---------
 target-microblaze/helper.c | 15 +++++++++++----
 target-mips/helper.c       |  6 ++++--
 target-ppc/mmu-hash32.c    |  2 +-
 target-s390x/helper.c      |  4 ++--
 target-sparc/mmu_helper.c  | 14 ++++++++++----
 target-unicore32/softmmu.c |  3 ++-
 11 files changed, 51 insertions(+), 29 deletions(-)

diff --git a/cputlb.c b/cputlb.c
index a55518a..3b271d4 100644
--- a/cputlb.c
+++ b/cputlb.c
@@ -270,7 +270,8 @@ void tlb_set_page(CPUState *cpu, target_ulong vaddr,
     assert(sz >= TARGET_PAGE_SIZE);
 
 #if defined(DEBUG_TLB)
-    printf("tlb_set_page: vaddr=" TARGET_FMT_lx " paddr=0x" TARGET_FMT_plx
+    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
diff --git a/include/qemu/log.h b/include/qemu/log.h
index d515424..195f665 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -40,6 +40,7 @@ static inline bool qemu_log_enabled(void)
 #define CPU_LOG_RESET      (1 << 9)
 #define LOG_UNIMP          (1 << 10)
 #define LOG_GUEST_ERROR    (1 << 11)
+#define CPU_LOG_MMU        (1 << 12)
 
 /* Returns true if a bit is set in the current loglevel mask
  */
diff --git a/qemu-log.c b/qemu-log.c
index 797f2af..05b5493 100644
--- a/qemu-log.c
+++ b/qemu-log.c
@@ -106,6 +106,8 @@ const QEMULogItem qemu_log_items[] = {
       "show trace before each executed TB (lots of logs)" },
     { CPU_LOG_TB_CPU, "cpu",
       "show CPU state before block translation" },
+    { CPU_LOG_MMU, "mmu",
+      "log MMU-related activities" },
     { CPU_LOG_PCALL, "pcall",
       "x86 only: show protected mode far calls/returns/exceptions" },
     { CPU_LOG_RESET, "cpu_reset",
diff --git a/target-cris/helper.c b/target-cris/helper.c
index e901c3a..e368e23 100644
--- a/target-cris/helper.c
+++ b/target-cris/helper.c
@@ -30,9 +30,11 @@
 #ifdef CRIS_HELPER_DEBUG
 #define D(x) x
 #define D_LOG(...) qemu_log(__VA_ARGS__)
+#define LOG_MMU(...) qemu_log_mask(CPU_LOG_MMU, __VA_ARGS__)
 #else
 #define D(x)
 #define D_LOG(...) do { } while (0)
+#define LOG_MMU(...) do { } while (0)
 #endif
 
 #if defined(CONFIG_USER_ONLY)
@@ -84,8 +86,8 @@ int cris_cpu_handle_mmu_fault(CPUState *cs, vaddr address, int rw,
     int r = -1;
     target_ulong phy;
 
-    D(printf("%s addr=%" VADDR_PRIx " pc=%x rw=%x\n",
-             __func__, address, env->pc, rw));
+    LOG_MMU("%s addr=%" VADDR_PRIx " pc=%x rw=%x\n",
+            __func__, address, env->pc, rw);
     miss = cris_mmu_translate(&res, env, address & TARGET_PAGE_MASK,
                               rw, mmu_idx, 0);
     if (miss) {
@@ -112,9 +114,9 @@ int cris_cpu_handle_mmu_fault(CPUState *cs, vaddr address, int rw,
         r = 0;
     }
     if (r > 0) {
-        D_LOG("%s returns %d irqreq=%x addr=%" VADDR_PRIx " phy=%x vec=%x"
-              " pc=%x\n", __func__, r, cs->interrupt_request, address, res.phy,
-              res.bf_vec, env->pc);
+        LOG_MMU("%s returns %d irqreq=%x addr=%" VADDR_PRIx " phy=%x vec=%x"
+                " pc=%x\n", __func__, r, cs->interrupt_request, address,
+                res.phy, res.bf_vec, env->pc);
     }
     return r;
 }
diff --git a/target-i386/helper.c b/target-i386/helper.c
index 345bda1..ae159a3 100644
--- a/target-i386/helper.c
+++ b/target-i386/helper.c
@@ -27,6 +27,12 @@
 
 //#define DEBUG_MMU
 
+#ifdef DEBUG_MMU
+#  define LOG_MMU(...) qemu_log_mask(CPU_LOG_MMU, __VA_ARGS__)
+#else
+#  define LOG_MMU(...) do { } while (0)
+#endif
+
 static void cpu_x86_version(CPUX86State *env, int *family, int *model)
 {
     int cpuver = env->cpuid_version;
@@ -388,9 +394,7 @@ void x86_cpu_set_a20(X86CPU *cpu, int a20_state)
     if (a20_state != ((env->a20_mask >> 20) & 1)) {
         CPUState *cs = CPU(cpu);
 
-#if defined(DEBUG_MMU)
-        printf("A20 update: a20=%d\n", a20_state);
-#endif
+        LOG_MMU("A20 update: a20=%d\n", a20_state);
         /* if the cpu is currently executing code, we must unlink it and
            all the potentially executing TB */
         cpu_interrupt(cs, CPU_INTERRUPT_EXITTB);
@@ -407,9 +411,7 @@ void cpu_x86_update_cr0(CPUX86State *env, uint32_t new_cr0)
     X86CPU *cpu = x86_env_get_cpu(env);
     int pe_state;
 
-#if defined(DEBUG_MMU)
-    printf("CR0 update: CR0=0x%08x\n", new_cr0);
-#endif
+    LOG_MMU("CR0 update: CR0=0x%08x\n", new_cr0);
     if ((new_cr0 & (CR0_PG_MASK | CR0_WP_MASK | CR0_PE_MASK)) !=
         (env->cr[0] & (CR0_PG_MASK | CR0_WP_MASK | CR0_PE_MASK))) {
         tlb_flush(CPU(cpu), 1);
@@ -452,9 +454,7 @@ void cpu_x86_update_cr3(CPUX86State *env, target_ulong new_cr3)
 
     env->cr[3] = new_cr3;
     if (env->cr[0] & CR0_PG_MASK) {
-#if defined(DEBUG_MMU)
-        printf("CR3 update: CR3=" TARGET_FMT_lx "\n", new_cr3);
-#endif
+        LOG_MMU("CR3 update: CR3=" TARGET_FMT_lx "\n", new_cr3);
         tlb_flush(CPU(cpu), 0);
     }
 }
diff --git a/target-microblaze/helper.c b/target-microblaze/helper.c
index 59466c9..7b48d17 100644
--- a/target-microblaze/helper.c
+++ b/target-microblaze/helper.c
@@ -22,7 +22,14 @@
 #include "qemu/host-utils.h"
 
 #define D(x)
-#define DMMU(x)
+
+#undef DEBUG_MMU
+
+#ifdef DEBUG_MMU
+#  define LOG_MMU(...) qemu_log_mask(CPU_LOG_MMU, __VA_ARGS__)
+#else
+#  define LOG_MMU(...) do { } while (0)
+#endif
 
 #if defined(CONFIG_USER_ONLY)
 
@@ -75,13 +82,13 @@ int mb_cpu_handle_mmu_fault(CPUState *cs, vaddr address, int rw,
             vaddr = address & TARGET_PAGE_MASK;
             paddr = lu.paddr + vaddr - lu.vaddr;
 
-            DMMU(qemu_log("MMU map mmu=%d v=%x p=%x prot=%x\n",
-                     mmu_idx, vaddr, paddr, lu.prot));
+            LOG_MMU("MMU map mmu=%d v=%x p=%x prot=%x\n",
+                    mmu_idx, vaddr, paddr, lu.prot);
             tlb_set_page(cs, vaddr, paddr, lu.prot, mmu_idx, TARGET_PAGE_SIZE);
             r = 0;
         } else {
             env->sregs[SR_EAR] = address;
-            DMMU(qemu_log("mmu=%d miss v=%x\n", mmu_idx, address));
+            LOG_MMU("mmu=%d miss v=%x\n", mmu_idx, address);
 
             switch (lu.err) {
                 case ERR_PROT:
diff --git a/target-mips/helper.c b/target-mips/helper.c
index fe16820..127f52a 100644
--- a/target-mips/helper.c
+++ b/target-mips/helper.c
@@ -309,7 +309,8 @@ int mips_cpu_handle_mmu_fault(CPUState *cs, vaddr address, int rw,
 #if 0
     log_cpu_state(cs, 0);
 #endif
-    qemu_log("%s pc " TARGET_FMT_lx " ad %" VADDR_PRIx " rw %d mmu_idx %d\n",
+    qemu_log_mask(CPU_LOG_MMU,
+              "%s pc " TARGET_FMT_lx " ad %" VADDR_PRIx " rw %d mmu_idx %d\n",
               __func__, env->active_tc.PC, address, rw, mmu_idx);
 
     rw &= 1;
@@ -321,7 +322,8 @@ int mips_cpu_handle_mmu_fault(CPUState *cs, vaddr address, int rw,
     access_type = ACCESS_INT;
     ret = get_physical_address(env, &physical, &prot,
                                address, rw, access_type);
-    qemu_log("%s address=%" VADDR_PRIx " ret %d physical " TARGET_FMT_plx
+    qemu_log_mask(CPU_LOG_MMU,
+             "%s address=%" VADDR_PRIx " ret %d physical " TARGET_FMT_plx
              " prot %d\n",
              __func__, address, ret, physical, prot);
     if (ret == TLBRET_MATCH) {
diff --git a/target-ppc/mmu-hash32.c b/target-ppc/mmu-hash32.c
index 0a13a81..0737d72 100644
--- a/target-ppc/mmu-hash32.c
+++ b/target-ppc/mmu-hash32.c
@@ -28,7 +28,7 @@
 //#define DEBUG_BAT
 
 #ifdef DEBUG_MMU
-#  define LOG_MMU(...) qemu_log(__VA_ARGS__)
+#  define LOG_MMU(...) qemu_log_mask(CPU_LOG_MMU, __VA_ARGS__)
 #  define LOG_MMU_STATE(cpu) log_cpu_state((cpu), 0)
 #else
 #  define LOG_MMU(...) do { } while (0)
diff --git a/target-s390x/helper.c b/target-s390x/helper.c
index e21afe6..96c7590 100644
--- a/target-s390x/helper.c
+++ b/target-s390x/helper.c
@@ -461,8 +461,8 @@ int s390_cpu_handle_mmu_fault(CPUState *cs, vaddr orig_vaddr,
         return 1;
     }
 
-    DPRINTF("%s: set tlb %" PRIx64 " -> %" PRIx64 " (%x)\n", __func__,
-            (uint64_t)vaddr, (uint64_t)raddr, prot);
+    qemu_log_mask(CPU_LOG_MMU, "%s: set tlb %" PRIx64 " -> %" PRIx64 " (%x)\n",
+            __func__, (uint64_t)vaddr, (uint64_t)raddr, prot);
 
     tlb_set_page(cs, orig_vaddr, raddr, prot,
                  mmu_idx, TARGET_PAGE_SIZE);
diff --git a/target-sparc/mmu_helper.c b/target-sparc/mmu_helper.c
index 61afbcf..cfd9a4e 100644
--- a/target-sparc/mmu_helper.c
+++ b/target-sparc/mmu_helper.c
@@ -23,6 +23,14 @@
 
 /* Sparc MMU emulation */
 
+#undef DEBUG_MMU
+
+#ifdef DEBUG_MMU
+#  define LOG_MMU(...) qemu_log_mask(CPU_LOG_MMU, __VA_ARGS__)
+#else
+#  define LOG_MMU(...) do { } while (0)
+#endif
+
 #if defined(CONFIG_USER_ONLY)
 
 int sparc_cpu_handle_mmu_fault(CPUState *cs, vaddr address, int rw,
@@ -213,10 +221,8 @@ int sparc_cpu_handle_mmu_fault(CPUState *cs, vaddr address, int rw,
                                       address, rw, mmu_idx, &page_size);
     vaddr = address;
     if (error_code == 0) {
-#ifdef DEBUG_MMU
-        printf("Translate at %" VADDR_PRIx " -> " TARGET_FMT_plx ", vaddr "
-               TARGET_FMT_lx "\n", address, paddr, vaddr);
-#endif
+        LOG_MMU("Translate at %" VADDR_PRIx " -> " TARGET_FMT_plx ", vaddr "
+                TARGET_FMT_lx "\n", address, paddr, vaddr);
         tlb_set_page(cs, vaddr, paddr, prot, mmu_idx, page_size);
         return 0;
     }
diff --git a/target-unicore32/softmmu.c b/target-unicore32/softmmu.c
index 9a3786d..42be555 100644
--- a/target-unicore32/softmmu.c
+++ b/target-unicore32/softmmu.c
@@ -236,7 +236,8 @@ int uc32_cpu_handle_mmu_fault(CPUState *cs, vaddr address,
             ret = get_phys_addr_ucv2(env, address, access_type, is_user,
                                     &phys_addr, &prot, &page_size);
             if (is_user) {
-                DPRINTF("user space access: ret %x, address %" VADDR_PRIx ", "
+                qemu_log_mask(CPU_LOG_MMU,
+                        "user space access: ret %x, address %" VADDR_PRIx ", "
                         "access_type %x, phys_addr %x, prot %x\n",
                         ret, address, access_type, phys_addr, prot);
             }
-- 
2.1.1

^ permalink raw reply related	[flat|nested] 3+ messages in thread

* Re: [Qemu-devel] [PATCH v2] qemu-log: add log category for MMU info
  2014-10-10 10:59 [Qemu-devel] [PATCH v2] qemu-log: add log category for MMU info Antony Pavlov
@ 2014-10-10 14:47 ` Peter Maydell
  2014-10-13 14:50   ` Alexander Graf
  0 siblings, 1 reply; 3+ messages in thread
From: Peter Maydell @ 2014-10-10 14:47 UTC (permalink / raw)
  To: Antony Pavlov
  Cc: QEMU Developers, Alexander Graf, Blue Swirl, Edgar E. Iglesias,
	Guan Xuetao, Aurelien Jarno, Richard Henderson

On 10 October 2014 11:59, Antony Pavlov <antonynpavlov@gmail.com> wrote:
> Running barebox on qemu-system-mips* with '-d unimp' overloads
> stderr by very very many mips_cpu_handle_mmu_fault() messages:
>
>   mips_cpu_handle_mmu_fault address=b80003fd ret 0 physical 00000000180003fd prot 3
>   mips_cpu_handle_mmu_fault address=a0800884 ret 0 physical 0000000000800884 prot 3
>   mips_cpu_handle_mmu_fault pc a080cd80 ad b80003fd rw 0 mmu_idx 0
>
> So it's very difficult to find LOG_UNIMP message.
>
> The mips_cpu_handle_mmu_fault() messages appears on enabling ANY
> logging! It's not very handy.
>
> Adding separate log category for *_cpu_handle_mmu_fault()
> logging fixes the problem.
>
> Signed-off-by: Antony Pavlov <antonynpavlov@gmail.com>

This mostly looks good, thanks!

I should also note that I'm happy for us to just implement
the common-code (ie the log flag) and fix those targets
which are particularly obnoxious about logging and/or
easy to fix. We can always leave the other targets to
update their code later (or you could update other targets
in separate patches once the main one has gone in).

A minor tweak:

> --- a/target-cris/helper.c
> +++ b/target-cris/helper.c
> @@ -30,9 +30,11 @@
>  #ifdef CRIS_HELPER_DEBUG
>  #define D(x) x
>  #define D_LOG(...) qemu_log(__VA_ARGS__)
> +#define LOG_MMU(...) qemu_log_mask(CPU_LOG_MMU, __VA_ARGS__)
>  #else
>  #define D(x)
>  #define D_LOG(...) do { } while (0)
> +#define LOG_MMU(...) do { } while (0)
>  #endif

Now this logging is configurably enablable at runtime,
we should just call qemu_log_mask() directly, rather
than wrapping it in a LOG_MMU macro which might be compiled
out.

> --- a/target-i386/helper.c
> +++ b/target-i386/helper.c
> @@ -27,6 +27,12 @@
>
>  //#define DEBUG_MMU
>
> +#ifdef DEBUG_MMU
> +#  define LOG_MMU(...) qemu_log_mask(CPU_LOG_MMU, __VA_ARGS__)
> +#else
> +#  define LOG_MMU(...) do { } while (0)
> +#endif

Similarly here.

> --- a/target-microblaze/helper.c
> +++ b/target-microblaze/helper.c
> @@ -22,7 +22,14 @@
>  #include "qemu/host-utils.h"
>
>  #define D(x)
> -#define DMMU(x)
> +
> +#undef DEBUG_MMU
> +
> +#ifdef DEBUG_MMU
> +#  define LOG_MMU(...) qemu_log_mask(CPU_LOG_MMU, __VA_ARGS__)
> +#else
> +#  define LOG_MMU(...) do { } while (0)
> +#endif

and here.

> --- a/target-ppc/mmu-hash32.c
> +++ b/target-ppc/mmu-hash32.c

There are other PPC files which also do MMU logging;
we should either fix them all or none of them.

thanks
-- PMM

^ permalink raw reply	[flat|nested] 3+ messages in thread

* Re: [Qemu-devel] [PATCH v2] qemu-log: add log category for MMU info
  2014-10-10 14:47 ` Peter Maydell
@ 2014-10-13 14:50   ` Alexander Graf
  0 siblings, 0 replies; 3+ messages in thread
From: Alexander Graf @ 2014-10-13 14:50 UTC (permalink / raw)
  To: Peter Maydell, Antony Pavlov
  Cc: QEMU Developers, Blue Swirl, Edgar E. Iglesias, Guan Xuetao,
	Aurelien Jarno, Richard Henderson



On 10.10.14 16:47, Peter Maydell wrote:
> On 10 October 2014 11:59, Antony Pavlov <antonynpavlov@gmail.com> wrote:
>> Running barebox on qemu-system-mips* with '-d unimp' overloads
>> stderr by very very many mips_cpu_handle_mmu_fault() messages:
>>
>>   mips_cpu_handle_mmu_fault address=b80003fd ret 0 physical 00000000180003fd prot 3
>>   mips_cpu_handle_mmu_fault address=a0800884 ret 0 physical 0000000000800884 prot 3
>>   mips_cpu_handle_mmu_fault pc a080cd80 ad b80003fd rw 0 mmu_idx 0
>>
>> So it's very difficult to find LOG_UNIMP message.
>>
>> The mips_cpu_handle_mmu_fault() messages appears on enabling ANY
>> logging! It's not very handy.
>>
>> Adding separate log category for *_cpu_handle_mmu_fault()
>> logging fixes the problem.
>>
>> Signed-off-by: Antony Pavlov <antonynpavlov@gmail.com>
> 
> This mostly looks good, thanks!
> 
> I should also note that I'm happy for us to just implement
> the common-code (ie the log flag) and fix those targets
> which are particularly obnoxious about logging and/or
> easy to fix. We can always leave the other targets to
> update their code later (or you could update other targets
> in separate patches once the main one has gone in).
> 
> A minor tweak:
> 
>> --- a/target-cris/helper.c
>> +++ b/target-cris/helper.c
>> @@ -30,9 +30,11 @@
>>  #ifdef CRIS_HELPER_DEBUG
>>  #define D(x) x
>>  #define D_LOG(...) qemu_log(__VA_ARGS__)
>> +#define LOG_MMU(...) qemu_log_mask(CPU_LOG_MMU, __VA_ARGS__)
>>  #else
>>  #define D(x)
>>  #define D_LOG(...) do { } while (0)
>> +#define LOG_MMU(...) do { } while (0)
>>  #endif
> 
> Now this logging is configurably enablable at runtime,
> we should just call qemu_log_mask() directly, rather
> than wrapping it in a LOG_MMU macro which might be compiled
> out.

The MMU lookups are in a pretty hot path. Are you sure we always want to
have the log enabled checks and register pollution in there?


Alex

^ permalink raw reply	[flat|nested] 3+ messages in thread

end of thread, other threads:[~2014-10-13 14:52 UTC | newest]

Thread overview: 3+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2014-10-10 10:59 [Qemu-devel] [PATCH v2] qemu-log: add log category for MMU info Antony Pavlov
2014-10-10 14:47 ` Peter Maydell
2014-10-13 14:50   ` Alexander Graf

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).