[PATCH v1 0/5] linux-user mmap debug cleanup

[PATCH v1 0/5] linux-user mmap debug cleanup

[Alex Bennée]

Hi,

While debugging some wierd ELF loading bugs I realised our mmap debug
code could do with a little clean-up so I removed the DEBUG_MMAP in
favour of some tracepoints and extending the information that -d page
gives you.

Alex Bennée (5):
  linux-user: convert target_mprotect debug to tracepoint
  linux-user: convert target_mmap debug to tracepoint
  linux-user: add target_mmap_complete tracepoint
  linux-user: log page table changes under -d page
  linux-user: convert target_munmap debug to a tracepoint

 linux-user/mmap.c       | 82 ++++++++++++++++++++++-------------------
 linux-user/trace-events |  6 +++
 2 files changed, 50 insertions(+), 38 deletions(-)

-- 
2.20.1

[PATCH v1 1/5] linux-user: convert target_mprotect debug to tracepoint

[Alex Bennée]

It is a pain to re-compile when you need to debug and tracepoints are
a fairly low impact way to instrument QEMU.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
---
 linux-user/mmap.c       | 17 +++++++++--------
 linux-user/trace-events |  3 +++
 2 files changed, 12 insertions(+), 8 deletions(-)

diff --git a/linux-user/mmap.c b/linux-user/mmap.c
index 46a6e3a761a..66868762519 100644
--- a/linux-user/mmap.c
+++ b/linux-user/mmap.c
@@ -17,7 +17,7 @@
  *  along with this program; if not, see <http://www.gnu.org/licenses/>.
  */
 #include "qemu/osdep.h"
-
+#include "trace.h"
 #include "qemu.h"
 
 //#define DEBUG_MMAP
@@ -66,13 +66,14 @@ int target_mprotect(abi_ulong start, abi_ulong len, int prot)
     abi_ulong end, host_start, host_end, addr;
     int prot1, ret;
 
-#ifdef DEBUG_MMAP
-    printf("mprotect: start=0x" TARGET_ABI_FMT_lx
-           "len=0x" TARGET_ABI_FMT_lx " prot=%c%c%c\n", start, len,
-           prot & PROT_READ ? 'r' : '-',
-           prot & PROT_WRITE ? 'w' : '-',
-           prot & PROT_EXEC ? 'x' : '-');
-#endif
+    if (TRACE_TARGET_MPROTECT_ENABLED) {
+        char prot_str[4];
+        prot_str[0] = prot & PROT_READ ? 'r' : '-';
+        prot_str[1] = prot & PROT_WRITE ? 'w' : '-';
+        prot_str[2] = prot & PROT_EXEC ? 'x' : '-';
+        prot_str[3] = 0;
+        trace_target_mprotect(start, len, prot_str);
+    }
 
     if ((start & ~TARGET_PAGE_MASK) != 0)
         return -TARGET_EINVAL;
diff --git a/linux-user/trace-events b/linux-user/trace-events
index 6df234bbb67..41d72e61abb 100644
--- a/linux-user/trace-events
+++ b/linux-user/trace-events
@@ -11,3 +11,6 @@ user_handle_signal(void *env, int target_sig) "env=%p signal %d"
 user_host_signal(void *env, int host_sig, int target_sig) "env=%p signal %d (target %d("
 user_queue_signal(void *env, int target_sig) "env=%p signal %d"
 user_s390x_restore_sigregs(void *env, uint64_t sc_psw_addr, uint64_t env_psw_addr) "env=%p frame psw.addr 0x%"PRIx64 " current psw.addr 0x%"PRIx64
+
+# mmap.c
+target_mprotect(uint64_t start, uint64_t len, char *flags) "start=0x%"PRIx64 " len=0x%"PRIx64 " prot=%s"
-- 
2.20.1

Re: [PATCH v1 1/5] linux-user: convert target_mprotect debug to tracepoint

[Richard Henderson]

On 11/28/19 7:45 PM, Alex Bennée wrote:
> -#ifdef DEBUG_MMAP
> -    printf("mprotect: start=0x" TARGET_ABI_FMT_lx
> -           "len=0x" TARGET_ABI_FMT_lx " prot=%c%c%c\n", start, len,
> -           prot & PROT_READ ? 'r' : '-',
> -           prot & PROT_WRITE ? 'w' : '-',
> -           prot & PROT_EXEC ? 'x' : '-');
> -#endif
> +    if (TRACE_TARGET_MPROTECT_ENABLED) {
> +        char prot_str[4];
> +        prot_str[0] = prot & PROT_READ ? 'r' : '-';
> +        prot_str[1] = prot & PROT_WRITE ? 'w' : '-';
> +        prot_str[2] = prot & PROT_EXEC ? 'x' : '-';
> +        prot_str[3] = 0;
> +        trace_target_mprotect(start, len, prot_str);
> +    }

There are other bits in prot other than these 3.
See especially my linux-user BTI patch set, and
know that the same sort of thing will be in the
as-yet undecided abi for the MTE extension.

Unless you have a good reason otherwise, I think
we should just print the numeric value in hex.


r~

[PATCH v1 2/5] linux-user: convert target_mmap debug to tracepoint

[Alex Bennée]

It is a pain to re-compile when you need to debug and tracepoints are
a fairly low impact way to instrument QEMU.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
---
 linux-user/mmap.c       | 51 +++++++++++++++++++++++------------------
 linux-user/trace-events |  1 +
 2 files changed, 30 insertions(+), 22 deletions(-)

diff --git a/linux-user/mmap.c b/linux-user/mmap.c
index 66868762519..c81fd85fbd2 100644
--- a/linux-user/mmap.c
+++ b/linux-user/mmap.c
@@ -60,6 +60,15 @@ void mmap_fork_end(int child)
         pthread_mutex_unlock(&mmap_mutex);
 }
 
+/* mmap prot pretty printer */
+static void pp_prot(char (*str)[4], int prot)
+{
+    (*str)[0] = prot & PROT_READ ? 'r' : '-';
+    (*str)[1] = prot & PROT_WRITE ? 'w' : '-';
+    (*str)[2] = prot & PROT_EXEC ? 'x' : '-';
+    (*str)[3] = 0;
+}
+
 /* NOTE: all the constants are the HOST ones, but addresses are target. */
 int target_mprotect(abi_ulong start, abi_ulong len, int prot)
 {
@@ -68,10 +77,7 @@ int target_mprotect(abi_ulong start, abi_ulong len, int prot)
 
     if (TRACE_TARGET_MPROTECT_ENABLED) {
         char prot_str[4];
-        prot_str[0] = prot & PROT_READ ? 'r' : '-';
-        prot_str[1] = prot & PROT_WRITE ? 'w' : '-';
-        prot_str[2] = prot & PROT_EXEC ? 'x' : '-';
-        prot_str[3] = 0;
+        pp_prot(&prot_str, prot);
         trace_target_mprotect(start, len, prot_str);
     }
 
@@ -370,32 +376,33 @@ abi_long target_mmap(abi_ulong start, abi_ulong len, int prot,
     abi_ulong ret, end, real_start, real_end, retaddr, host_offset, host_len;
 
     mmap_lock();
-#ifdef DEBUG_MMAP
-    {
-        printf("mmap: start=0x" TARGET_ABI_FMT_lx
-               " len=0x" TARGET_ABI_FMT_lx " prot=%c%c%c flags=",
-               start, len,
-               prot & PROT_READ ? 'r' : '-',
-               prot & PROT_WRITE ? 'w' : '-',
-               prot & PROT_EXEC ? 'x' : '-');
-        if (flags & MAP_FIXED)
-            printf("MAP_FIXED ");
-        if (flags & MAP_ANONYMOUS)
-            printf("MAP_ANON ");
-        switch(flags & MAP_TYPE) {
+    if (TRACE_TARGET_MMAP_ENABLED) {
+        char prot_str[4];
+        g_autoptr(GString) flag_str = g_string_new(NULL);
+
+        pp_prot(&prot_str, prot);
+
+        if (flags & MAP_FIXED) {
+            g_string_append(flag_str, "MAP_FIXED ");
+        }
+        if (flags & MAP_ANONYMOUS) {
+            g_string_append(flag_str, "MAP_ANON ");
+        }
+
+        switch (flags & MAP_TYPE) {
         case MAP_PRIVATE:
-            printf("MAP_PRIVATE ");
+            g_string_append(flag_str, "MAP_PRIVATE ");
             break;
         case MAP_SHARED:
-            printf("MAP_SHARED ");
+            g_string_append(flag_str, "MAP_SHARED ");
             break;
         default:
-            printf("[MAP_TYPE=0x%x] ", flags & MAP_TYPE);
+            g_string_append_printf(flag_str, "[MAP_TYPE=0x%x] ",
+                                   flags & MAP_TYPE);
             break;
         }
-        printf("fd=%d offset=" TARGET_ABI_FMT_lx "\n", fd, offset);
+        trace_target_mmap(start, len, prot_str, flag_str->str, fd, offset);
     }
-#endif
 
     if (!len) {
         errno = EINVAL;
diff --git a/linux-user/trace-events b/linux-user/trace-events
index 41d72e61abb..9411ab357c9 100644
--- a/linux-user/trace-events
+++ b/linux-user/trace-events
@@ -14,3 +14,4 @@ user_s390x_restore_sigregs(void *env, uint64_t sc_psw_addr, uint64_t env_psw_add
 
 # mmap.c
 target_mprotect(uint64_t start, uint64_t len, char *flags) "start=0x%"PRIx64 " len=0x%"PRIx64 " prot=%s"
+target_mmap(uint64_t start, uint64_t len, char *pflags, char *mflags, int fd, uint64_t offset) "start=0x%"PRIx64 " len=0x%"PRIx64 " prot=%s flags=%s fd=%d offset=0x%"PRIx64
-- 
2.20.1

Re: [PATCH v1 2/5] linux-user: convert target_mmap debug to tracepoint

[Richard Henderson]

On 11/28/19 7:46 PM, Alex Bennée wrote:
> +    if (TRACE_TARGET_MMAP_ENABLED) {
> +        char prot_str[4];
> +        g_autoptr(GString) flag_str = g_string_new(NULL);
> +
> +        pp_prot(&prot_str, prot);
> +
> +        if (flags & MAP_FIXED) {
> +            g_string_append(flag_str, "MAP_FIXED ");
> +        }
> +        if (flags & MAP_ANONYMOUS) {
> +            g_string_append(flag_str, "MAP_ANON ");
> +        }
> +
> +        switch (flags & MAP_TYPE) {
>          case MAP_PRIVATE:
> -            printf("MAP_PRIVATE ");
> +            g_string_append(flag_str, "MAP_PRIVATE ");
>              break;
>          case MAP_SHARED:
> -            printf("MAP_SHARED ");
> +            g_string_append(flag_str, "MAP_SHARED ");
>              break;
>          default:
> -            printf("[MAP_TYPE=0x%x] ", flags & MAP_TYPE);
> +            g_string_append_printf(flag_str, "[MAP_TYPE=0x%x] ",
> +                                   flags & MAP_TYPE);
>              break;
>          }
> -        printf("fd=%d offset=" TARGET_ABI_FMT_lx "\n", fd, offset);
> +        trace_target_mmap(start, len, prot_str, flag_str->str, fd, offset);
>      }

I don't think that you need to re-create -strace output.
There are also quite a lot of MAP_* flags that are not
being printed, without any indication that they are left out.

Again, I think we should just print the hex value.


r~

[PATCH v1 3/5] linux-user: add target_mmap_complete tracepoint

[Alex Bennée]

For full details we also want to see where the mmaps end up.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
---
 linux-user/mmap.c       | 2 +-
 linux-user/trace-events | 1 +
 2 files changed, 2 insertions(+), 1 deletion(-)

diff --git a/linux-user/mmap.c b/linux-user/mmap.c
index c81fd85fbd2..a2c7037f1b6 100644
--- a/linux-user/mmap.c
+++ b/linux-user/mmap.c
@@ -577,8 +577,8 @@ abi_long target_mmap(abi_ulong start, abi_ulong len, int prot,
  the_end1:
     page_set_flags(start, start + len, prot | PAGE_VALID);
  the_end:
+    trace_target_mmap_complete(start);
 #ifdef DEBUG_MMAP
-    printf("ret=0x" TARGET_ABI_FMT_lx "\n", start);
     page_dump(stdout);
     printf("\n");
 #endif
diff --git a/linux-user/trace-events b/linux-user/trace-events
index 9411ab357c9..774280cefbd 100644
--- a/linux-user/trace-events
+++ b/linux-user/trace-events
@@ -15,3 +15,4 @@ user_s390x_restore_sigregs(void *env, uint64_t sc_psw_addr, uint64_t env_psw_add
 # mmap.c
 target_mprotect(uint64_t start, uint64_t len, char *flags) "start=0x%"PRIx64 " len=0x%"PRIx64 " prot=%s"
 target_mmap(uint64_t start, uint64_t len, char *pflags, char *mflags, int fd, uint64_t offset) "start=0x%"PRIx64 " len=0x%"PRIx64 " prot=%s flags=%s fd=%d offset=0x%"PRIx64
+target_mmap_complete(uint64_t retaddr) "retaddr=0x%"PRIx64
-- 
2.20.1

Re: [PATCH v1 3/5] linux-user: add target_mmap_complete tracepoint

[Richard Henderson]

On 11/28/19 7:46 PM, Alex Bennée wrote:
> For full details we also want to see where the mmaps end up.
> 
> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
> ---
>  linux-user/mmap.c       | 2 +-
>  linux-user/trace-events | 1 +
>  2 files changed, 2 insertions(+), 1 deletion(-)

Reviewed-by: Richard Henderson <richard.henderson@linaro.org>


r~

[PATCH v1 4/5] linux-user: log page table changes under -d page

[Alex Bennée]

The CPU_LOG_PAGE flag is woefully underused and could stand to do
extra duty tracking page changes. If the user doesn't want to see the
details as things change they still have the tracepoints available.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
---
 linux-user/mmap.c | 11 +++++++----
 1 file changed, 7 insertions(+), 4 deletions(-)

diff --git a/linux-user/mmap.c b/linux-user/mmap.c
index a2c7037f1b6..c2755fcba1f 100644
--- a/linux-user/mmap.c
+++ b/linux-user/mmap.c
@@ -18,6 +18,7 @@
  */
 #include "qemu/osdep.h"
 #include "trace.h"
+#include "exec/log.h"
 #include "qemu.h"
 
 //#define DEBUG_MMAP
@@ -578,10 +579,12 @@ abi_long target_mmap(abi_ulong start, abi_ulong len, int prot,
     page_set_flags(start, start + len, prot | PAGE_VALID);
  the_end:
     trace_target_mmap_complete(start);
-#ifdef DEBUG_MMAP
-    page_dump(stdout);
-    printf("\n");
-#endif
+    if (qemu_loglevel_mask(CPU_LOG_PAGE)) {
+        qemu_log_lock();
+        qemu_log("new page @ 0x"TARGET_ABI_FMT_lx" updates page map:\n", start);
+        log_page_dump();
+        qemu_log_unlock();
+    }
     tb_invalidate_phys_range(start, start + len);
     mmap_unlock();
     return start;
-- 
2.20.1

Re: [PATCH v1 4/5] linux-user: log page table changes under -d page

[Richard Henderson]

On 11/28/19 7:46 PM, Alex Bennée wrote:
> +    if (qemu_loglevel_mask(CPU_LOG_PAGE)) {
> +        qemu_log_lock();
> +        qemu_log("new page @ 0x"TARGET_ABI_FMT_lx" updates page map:\n", start);
> +        log_page_dump();
> +        qemu_log_unlock();
> +    }

Hmm.  The language used here asserts a change, when we don't actually know that
for a fact.  It *probably* adds a new page, but it could be overwriting an old
page.  Can you find a better wording here?


r~

Re: [PATCH v1 4/5] linux-user: log page table changes under -d page

[Richard Henderson]

On 12/1/19 1:26 AM, Richard Henderson wrote:
> On 11/28/19 7:46 PM, Alex Bennée wrote:
>> +    if (qemu_loglevel_mask(CPU_LOG_PAGE)) {
>> +        qemu_log_lock();
>> +        qemu_log("new page @ 0x"TARGET_ABI_FMT_lx" updates page map:\n", start);
>> +        log_page_dump();
>> +        qemu_log_unlock();
>> +    }
> 
> Hmm.  The language used here asserts a change, when we don't actually know that
> for a fact.  It *probably* adds a new page, but it could be overwriting an old
> page.  Can you find a better wording here?

Also, if you're going to do this, you might as well instrument munmap and
mremap as well.  Otherwise we're missing transitions.


r~

[PATCH v1 5/5] linux-user: convert target_munmap debug to a tracepoint

[Alex Bennée]

Convert the final bit of DEBUG_MMAP to a tracepoint and remove the
last remanents of the #ifdef hackery.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
---
 linux-user/mmap.c       | 9 ++-------
 linux-user/trace-events | 1 +
 2 files changed, 3 insertions(+), 7 deletions(-)

diff --git a/linux-user/mmap.c b/linux-user/mmap.c
index c2755fcba1f..137aa3eb95f 100644
--- a/linux-user/mmap.c
+++ b/linux-user/mmap.c
@@ -21,8 +21,6 @@
 #include "exec/log.h"
 #include "qemu.h"
 
-//#define DEBUG_MMAP
-
 static pthread_mutex_t mmap_mutex = PTHREAD_MUTEX_INITIALIZER;
 static __thread int mmap_lock_count;
 
@@ -639,11 +637,8 @@ int target_munmap(abi_ulong start, abi_ulong len)
     abi_ulong end, real_start, real_end, addr;
     int prot, ret;
 
-#ifdef DEBUG_MMAP
-    printf("munmap: start=0x" TARGET_ABI_FMT_lx " len=0x"
-           TARGET_ABI_FMT_lx "\n",
-           start, len);
-#endif
+    trace_target_munmap(start, len);
+
     if (start & ~TARGET_PAGE_MASK)
         return -TARGET_EINVAL;
     len = TARGET_PAGE_ALIGN(len);
diff --git a/linux-user/trace-events b/linux-user/trace-events
index 774280cefbd..bd897add252 100644
--- a/linux-user/trace-events
+++ b/linux-user/trace-events
@@ -16,3 +16,4 @@ user_s390x_restore_sigregs(void *env, uint64_t sc_psw_addr, uint64_t env_psw_add
 target_mprotect(uint64_t start, uint64_t len, char *flags) "start=0x%"PRIx64 " len=0x%"PRIx64 " prot=%s"
 target_mmap(uint64_t start, uint64_t len, char *pflags, char *mflags, int fd, uint64_t offset) "start=0x%"PRIx64 " len=0x%"PRIx64 " prot=%s flags=%s fd=%d offset=0x%"PRIx64
 target_mmap_complete(uint64_t retaddr) "retaddr=0x%"PRIx64
+target_munmap(uint64_t start, uint64_t len) "start=0x%"PRIx64" len=0x%"PRIx64
-- 
2.20.1

Re: [PATCH v1 5/5] linux-user: convert target_munmap debug to a tracepoint

[Richard Henderson]

On 11/28/19 7:46 PM, Alex Bennée wrote:
> Convert the final bit of DEBUG_MMAP to a tracepoint and remove the
> last remanents of the #ifdef hackery.
> 
> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
> ---
>  linux-user/mmap.c       | 9 ++-------
>  linux-user/trace-events | 1 +
>  2 files changed, 3 insertions(+), 7 deletions(-)

Reviewed-by: Richard Henderson <richard.henderson@linaro.org>


r~