[PATCH v3 0/5] linux-user: Trace sendto/recvfrom

[PATCH v3 0/5] linux-user: Trace sendto/recvfrom

[Philippe Mathieu-Daudé]

Since v2:
- Do not squash 2 first patches...

Since v1:
- Add/use print_buf_len (rth)

Strace format added while debugging
https://gitlab.com/qemu-project/qemu/-/issues/2485

Philippe Mathieu-Daudé (5):
  linux-user: Correct print_sockaddr() format
  linux-user: Display sockaddr buffer as pointer
  linux-user: Factor print_buf_len() out
  linux-user: Add strace for sendto()
  linux-user: Add strace for recvfrom()

 linux-user/strace.c    | 51 +++++++++++++++++++++++++++++++++++++-----
 linux-user/strace.list |  4 ++--
 2 files changed, 47 insertions(+), 8 deletions(-)

-- 
2.45.2

[PATCH v3 1/5] linux-user: Correct print_sockaddr() format

[Philippe Mathieu-Daudé]

When the %addr argument can not be accessed, a double comma
is logged (the final qemu_log call prepend a comma). Call
print_raw_param with last=1 to avoid the extra comma.
Remove spurious space.

Signed-off-by: Philippe Mathieu-Daudé <philmd@linaro.org>
---
 linux-user/strace.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/linux-user/strace.c b/linux-user/strace.c
index b4d1098170..73f81e66fc 100644
--- a/linux-user/strace.c
+++ b/linux-user/strace.c
@@ -434,9 +434,9 @@ print_sockaddr(abi_ulong addr, abi_long addrlen, int last)
         }
         unlock_user(sa, addr, 0);
     } else {
-        print_raw_param("0x"TARGET_ABI_FMT_lx, addr, 0);
+        print_raw_param("0x"TARGET_ABI_FMT_lx, addr, 1);
     }
-    qemu_log(", "TARGET_ABI_FMT_ld"%s", addrlen, get_comma(last));
+    qemu_log(","TARGET_ABI_FMT_ld"%s", addrlen, get_comma(last));
 }
 
 static void
-- 
2.45.2

Re: [PATCH v3 1/5] linux-user: Correct print_sockaddr() format

[Ilya Leoshkevich]

On Wed, 2024-08-07 at 14:43 +0200, Philippe Mathieu-Daudé wrote:
> When the %addr argument can not be accessed, a double comma
> is logged (the final qemu_log call prepend a comma). Call
> print_raw_param with last=1 to avoid the extra comma.
> Remove spurious space.
> 
> Signed-off-by: Philippe Mathieu-Daudé <philmd@linaro.org>
> ---
>  linux-user/strace.c | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/linux-user/strace.c b/linux-user/strace.c
> index b4d1098170..73f81e66fc 100644
> --- a/linux-user/strace.c
> +++ b/linux-user/strace.c
> @@ -434,9 +434,9 @@ print_sockaddr(abi_ulong addr, abi_long addrlen,
> int last)
>          }
>          unlock_user(sa, addr, 0);
>      } else {
> -        print_raw_param("0x"TARGET_ABI_FMT_lx, addr, 0);
> +        print_raw_param("0x"TARGET_ABI_FMT_lx, addr, 1);
>      }
> -    qemu_log(", "TARGET_ABI_FMT_ld"%s", addrlen, get_comma(last));
> +    qemu_log(","TARGET_ABI_FMT_ld"%s", addrlen, get_comma(last));
>  }
>  
>  static void

I see why this works, but it feels a bit wrong semantically: addr is
not the last argument.
Wouldn't it be better to add commas to the preceding switch's cases?

Anyhow:

Acked-by: Ilya Leoshkevich <iii@linux.ibm.com>

Re: [PATCH v3 1/5] linux-user: Correct print_sockaddr() format

[Richard Henderson]

On 10/2/24 00:54, Ilya Leoshkevich wrote:
> On Wed, 2024-08-07 at 14:43 +0200, Philippe Mathieu-Daudé wrote:
>> When the %addr argument can not be accessed, a double comma
>> is logged (the final qemu_log call prepend a comma). Call
>> print_raw_param with last=1 to avoid the extra comma.
>> Remove spurious space.
>>
>> Signed-off-by: Philippe Mathieu-Daudé <philmd@linaro.org>
>> ---
>>   linux-user/strace.c | 4 ++--
>>   1 file changed, 2 insertions(+), 2 deletions(-)
>>
>> diff --git a/linux-user/strace.c b/linux-user/strace.c
>> index b4d1098170..73f81e66fc 100644
>> --- a/linux-user/strace.c
>> +++ b/linux-user/strace.c
>> @@ -434,9 +434,9 @@ print_sockaddr(abi_ulong addr, abi_long addrlen,
>> int last)
>>           }
>>           unlock_user(sa, addr, 0);
>>       } else {
>> -        print_raw_param("0x"TARGET_ABI_FMT_lx, addr, 0);
>> +        print_raw_param("0x"TARGET_ABI_FMT_lx, addr, 1);
>>       }
>> -    qemu_log(", "TARGET_ABI_FMT_ld"%s", addrlen, get_comma(last));
>> +    qemu_log(","TARGET_ABI_FMT_ld"%s", addrlen, get_comma(last));
>>   }
>>   
>>   static void
> 
> I see why this works, but it feels a bit wrong semantically: addr is
> not the last argument.
> Wouldn't it be better to add commas to the preceding switch's cases?

It would indeed.
Adding the comma manually in the final log is odd.


r~

[PATCH v3 2/5] linux-user: Display sockaddr buffer as pointer

[Philippe Mathieu-Daudé]

Rather than 'raw param', display as pointer to get
"NULL" instead of "0x00000000".

Signed-off-by: Philippe Mathieu-Daudé <philmd@linaro.org>
Reviewed-by: Richard Henderson <richard.henderson@linaro.org>
---
 linux-user/strace.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/linux-user/strace.c b/linux-user/strace.c
index 73f81e66fc..80f64ff40c 100644
--- a/linux-user/strace.c
+++ b/linux-user/strace.c
@@ -434,7 +434,7 @@ print_sockaddr(abi_ulong addr, abi_long addrlen, int last)
         }
         unlock_user(sa, addr, 0);
     } else {
-        print_raw_param("0x"TARGET_ABI_FMT_lx, addr, 1);
+        print_pointer(addr, 1);
     }
     qemu_log(","TARGET_ABI_FMT_ld"%s", addrlen, get_comma(last));
 }
-- 
2.45.2

Re: [PATCH v3 2/5] linux-user: Display sockaddr buffer as pointer

[Ilya Leoshkevich]

On Wed, 2024-08-07 at 14:43 +0200, Philippe Mathieu-Daudé wrote:
> Rather than 'raw param', display as pointer to get
> "NULL" instead of "0x00000000".
> 
> Signed-off-by: Philippe Mathieu-Daudé <philmd@linaro.org>
> Reviewed-by: Richard Henderson <richard.henderson@linaro.org>

Reviewed-by: Ilya Leoshkevich <iii@linux.ibm.com>

[PATCH v3 3/5] linux-user: Factor print_buf_len() out

[Philippe Mathieu-Daudé]

Signed-off-by: Philippe Mathieu-Daudé <philmd@linaro.org>
---
 linux-user/strace.c | 13 +++++++++----
 1 file changed, 9 insertions(+), 4 deletions(-)

diff --git a/linux-user/strace.c b/linux-user/strace.c
index 80f64ff40c..210ff86afc 100644
--- a/linux-user/strace.c
+++ b/linux-user/strace.c
@@ -1655,6 +1655,13 @@ print_buf(abi_long addr, abi_long len, int last)
     }
 }
 
+static void
+print_buf_len(abi_long addr, abi_long len, int last)
+{
+    print_buf(addr, len, 0);
+    print_raw_param(TARGET_ABI_FMT_ld, len, last);
+}
+
 /*
  * Prints out raw parameter using given format.  Caller needs
  * to do byte swapping if needed.
@@ -2742,8 +2749,7 @@ static void do_print_sendrecv(const char *name, abi_long arg1)
 
     qemu_log("%s(", name);
     print_sockfd(sockfd, 0);
-    print_buf(msg, len, 0);
-    print_raw_param(TARGET_ABI_FMT_ld, len, 0);
+    print_buf_len(msg, len, 0);
     print_flags(msg_flags, flags, 1);
     qemu_log(")");
 }
@@ -2761,8 +2767,7 @@ static void do_print_msgaddr(const char *name, abi_long arg1)
 
     qemu_log("%s(", name);
     print_sockfd(sockfd, 0);
-    print_buf(msg, len, 0);
-    print_raw_param(TARGET_ABI_FMT_ld, len, 0);
+    print_buf_len(msg, len, 0);
     print_flags(msg_flags, flags, 0);
     print_sockaddr(addr, addrlen, 0);
     qemu_log(")");
-- 
2.45.2

Re: [PATCH v3 3/5] linux-user: Factor print_buf_len() out

[Ilya Leoshkevich]

On Wed, 2024-08-07 at 14:43 +0200, Philippe Mathieu-Daudé wrote:
> Signed-off-by: Philippe Mathieu-Daudé <philmd@linaro.org>
> ---
>  linux-user/strace.c | 13 +++++++++----
>  1 file changed, 9 insertions(+), 4 deletions(-)

Reviewed-by: Ilya Leoshkevich <iii@linux.ibm.com>

[PATCH v3 4/5] linux-user: Add strace for sendto()

[Philippe Mathieu-Daudé]

Signed-off-by: Philippe Mathieu-Daudé <philmd@linaro.org>
---
 linux-user/strace.c    | 15 +++++++++++++++
 linux-user/strace.list |  2 +-
 2 files changed, 16 insertions(+), 1 deletion(-)

diff --git a/linux-user/strace.c b/linux-user/strace.c
index 210ff86afc..98ef26b917 100644
--- a/linux-user/strace.c
+++ b/linux-user/strace.c
@@ -3127,6 +3127,21 @@ print_bind(CPUArchState *cpu_env, const struct syscallname *name,
 }
 #endif
 
+#ifdef TARGET_NR_sendto
+static void
+print_sendto(CPUArchState *cpu_env, const struct syscallname *name,
+             abi_long arg0, abi_long arg1, abi_long arg2,
+             abi_long arg3, abi_long arg4, abi_long arg5)
+{
+    print_syscall_prologue(name);
+    print_sockfd(arg0, 0);
+    print_buf_len(arg1, arg2, 0);
+    print_flags(msg_flags, arg3, 0);
+    print_sockaddr(arg4, arg5, 1);
+    print_syscall_epilogue(name);
+}
+#endif
+
 #if defined(TARGET_NR_stat) || defined(TARGET_NR_stat64) || \
     defined(TARGET_NR_lstat) || defined(TARGET_NR_lstat64)
 static void
diff --git a/linux-user/strace.list b/linux-user/strace.list
index dfd4237d14..5a86419e7d 100644
--- a/linux-user/strace.list
+++ b/linux-user/strace.list
@@ -1285,7 +1285,7 @@
 { TARGET_NR_sendmsg, "sendmsg" , NULL, NULL, NULL },
 #endif
 #ifdef TARGET_NR_sendto
-{ TARGET_NR_sendto, "sendto" , NULL, NULL, NULL },
+{ TARGET_NR_sendto, "sendto" , NULL, print_sendto, NULL },
 #endif
 #ifdef TARGET_NR_setdomainname
 { TARGET_NR_setdomainname, "setdomainname" , NULL, NULL, NULL },
-- 
2.45.2

Re: [PATCH v3 4/5] linux-user: Add strace for sendto()

[Ilya Leoshkevich]

On Wed, 2024-08-07 at 14:43 +0200, Philippe Mathieu-Daudé wrote:
> Signed-off-by: Philippe Mathieu-Daudé <philmd@linaro.org>
> ---
>  linux-user/strace.c    | 15 +++++++++++++++
>  linux-user/strace.list |  2 +-
>  2 files changed, 16 insertions(+), 1 deletion(-)
> 
> diff --git a/linux-user/strace.c b/linux-user/strace.c
> index 210ff86afc..98ef26b917 100644
> --- a/linux-user/strace.c
> +++ b/linux-user/strace.c
> @@ -3127,6 +3127,21 @@ print_bind(CPUArchState *cpu_env, const struct
> syscallname *name,
>  }
>  #endif
>  
> +#ifdef TARGET_NR_sendto
> +static void
> +print_sendto(CPUArchState *cpu_env, const struct syscallname *name,
> +             abi_long arg0, abi_long arg1, abi_long arg2,
> +             abi_long arg3, abi_long arg4, abi_long arg5)
> +{
> +    print_syscall_prologue(name);
> +    print_sockfd(arg0, 0);
> +    print_buf_len(arg1, arg2, 0);
> +    print_flags(msg_flags, arg3, 0);
> +    print_sockaddr(arg4, arg5, 1);
> +    print_syscall_epilogue(name);
> +}
> +#endif
> +
>  #if defined(TARGET_NR_stat) || defined(TARGET_NR_stat64) || \
>      defined(TARGET_NR_lstat) || defined(TARGET_NR_lstat64)
>  static void
> diff --git a/linux-user/strace.list b/linux-user/strace.list
> index dfd4237d14..5a86419e7d 100644
> --- a/linux-user/strace.list
> +++ b/linux-user/strace.list
> @@ -1285,7 +1285,7 @@
>  { TARGET_NR_sendmsg, "sendmsg" , NULL, NULL, NULL },
>  #endif
>  #ifdef TARGET_NR_sendto
> -{ TARGET_NR_sendto, "sendto" , NULL, NULL, NULL },
> +{ TARGET_NR_sendto, "sendto" , NULL, print_sendto, NULL },
>  #endif
>  #ifdef TARGET_NR_setdomainname
>  { TARGET_NR_setdomainname, "setdomainname" , NULL, NULL, NULL },

The output looks reasonable:

607813
sendto(9,"\24\0\0\0\26\0\1\3\242\370\374f\0\0\0\0\0\0\0\0",20,0,{nl_fam
ily=AF_NETLINK,nl_pid=0,nl_groups=0},12) = 20

Reviewed-by: Ilya Leoshkevich <iii@linux.ibm.com>

[PATCH v3 5/5] linux-user: Add strace for recvfrom()

[Philippe Mathieu-Daudé]

Signed-off-by: Philippe Mathieu-Daudé <philmd@linaro.org>
---
 linux-user/strace.c    | 19 +++++++++++++++++++
 linux-user/strace.list |  2 +-
 2 files changed, 20 insertions(+), 1 deletion(-)

diff --git a/linux-user/strace.c b/linux-user/strace.c
index 98ef26b917..d76907fdc9 100644
--- a/linux-user/strace.c
+++ b/linux-user/strace.c
@@ -3127,6 +3127,25 @@ print_bind(CPUArchState *cpu_env, const struct syscallname *name,
 }
 #endif
 
+#ifdef TARGET_NR_recvfrom
+static void
+print_recvfrom(CPUArchState *cpu_env, const struct syscallname *name,
+               abi_long arg0, abi_long arg1, abi_long arg2,
+               abi_long arg3, abi_long arg4, abi_long arg5)
+{
+    abi_ulong addrlen;
+
+    get_user_ualx(addrlen, arg5, 0);
+
+    print_syscall_prologue(name);
+    print_sockfd(arg0, 0);
+    print_buf_len(arg1, arg2, 0);
+    print_flags(msg_flags, arg3, 0);
+    print_sockaddr(arg4, addrlen, 1);
+    print_syscall_epilogue(name);
+}
+#endif
+
 #ifdef TARGET_NR_sendto
 static void
 print_sendto(CPUArchState *cpu_env, const struct syscallname *name,
diff --git a/linux-user/strace.list b/linux-user/strace.list
index 5a86419e7d..77ca824f9c 100644
--- a/linux-user/strace.list
+++ b/linux-user/strace.list
@@ -1135,7 +1135,7 @@
 { TARGET_NR_recv, "recv" , "%s(%d,%p,%u,%d)", NULL, NULL },
 #endif
 #ifdef TARGET_NR_recvfrom
-{ TARGET_NR_recvfrom, "recvfrom" , NULL, NULL, NULL },
+{ TARGET_NR_recvfrom, "recvfrom" , NULL, print_recvfrom, NULL },
 #endif
 #ifdef TARGET_NR_recvmmsg
 { TARGET_NR_recvmmsg, "recvmmsg" , NULL, NULL, NULL },
-- 
2.45.2

Re: [PATCH v3 5/5] linux-user: Add strace for recvfrom()

[Ilya Leoshkevich]

On Wed, 2024-08-07 at 14:43 +0200, Philippe Mathieu-Daudé wrote:
> Signed-off-by: Philippe Mathieu-Daudé <philmd@linaro.org>
> ---
>  linux-user/strace.c    | 19 +++++++++++++++++++
>  linux-user/strace.list |  2 +-
>  2 files changed, 20 insertions(+), 1 deletion(-)
> 
> diff --git a/linux-user/strace.c b/linux-user/strace.c
> index 98ef26b917..d76907fdc9 100644
> --- a/linux-user/strace.c
> +++ b/linux-user/strace.c
> @@ -3127,6 +3127,25 @@ print_bind(CPUArchState *cpu_env, const struct
> syscallname *name,
>  }
>  #endif
>  
> +#ifdef TARGET_NR_recvfrom
> +static void
> +print_recvfrom(CPUArchState *cpu_env, const struct syscallname
> *name,
> +               abi_long arg0, abi_long arg1, abi_long arg2,
> +               abi_long arg3, abi_long arg4, abi_long arg5)
> +{
> +    abi_ulong addrlen;
> +
> +    get_user_ualx(addrlen, arg5, 0);
> +
> +    print_syscall_prologue(name);
> +    print_sockfd(arg0, 0);
> +    print_buf_len(arg1, arg2, 0);
> +    print_flags(msg_flags, arg3, 0);
> +    print_sockaddr(arg4, addrlen, 1);
> +    print_syscall_epilogue(name);
> +}
> +#endif
> +
>  #ifdef TARGET_NR_sendto
>  static void
>  print_sendto(CPUArchState *cpu_env, const struct syscallname *name,
> diff --git a/linux-user/strace.list b/linux-user/strace.list
> index 5a86419e7d..77ca824f9c 100644
> --- a/linux-user/strace.list
> +++ b/linux-user/strace.list
> @@ -1135,7 +1135,7 @@
>  { TARGET_NR_recv, "recv" , "%s(%d,%p,%u,%d)", NULL, NULL },
>  #endif
>  #ifdef TARGET_NR_recvfrom
> -{ TARGET_NR_recvfrom, "recvfrom" , NULL, NULL, NULL },
> +{ TARGET_NR_recvfrom, "recvfrom" , NULL, print_recvfrom, NULL },
>  #endif
>  #ifdef TARGET_NR_recvmmsg
>  { TARGET_NR_recvmmsg, "recvmmsg" , NULL, NULL, NULL },

I needed to implement read()/write() tracing and stumbled upon this
series, which overall looks like a good thing to have. I spotted a few
issues though.


I get the following build error:

qemu/linux-user/strace.c:3138:5: error: implicit declaration of
function ‘get_user_ualx’; did you mean ‘get_user_ual’? [-Wimplicit-
function-declaration]
 3138 |     get_user_ualx(addrlen, arg5, 0);
      |     ^~~~~~~~~~~~~
      |     get_user_ual


The following helps:

--- a/linux-user/strace.c
+++ b/linux-user/strace.c
@@ -2666,11 +2666,15 @@ static void print_sockfd(abi_long sockfd, int
last)
 
 #endif
 
-#if defined(TARGET_NR_socketcall)
+#if defined(TARGET_NR_socketcall) || defined(TARGET_NR_recvfrom)
 
 #define get_user_ualx(x, gaddr, idx) \
         get_user_ual(x, (gaddr) + (idx) * sizeof(abi_long))
 
+#endif
+
+#if defined(TARGET_NR_socketcall)
+
 static void do_print_socket(const char *name, abi_long arg1)
 {
     abi_ulong domain, type, protocol;


With this I get the following output, which w.r.t. its shape looks
good:

598730 recvfrom(3,"HTTP/1.1 400 Bad request\15\12Connection:
Cl"...,8192,0,{sa_family=0, sa_data={00, 00, 00, 00, 00, 00, 00, 00,
00, 00, 00, 00, 00, 00}},128) = 0

However: aren't we printing the contents of the buffer before the
syscall returns? Same with sockaddr. This would make the output not
very useful.

Re: [PATCH v3 5/5] linux-user: Add strace for recvfrom()

[Richard Henderson]

On 10/1/24 23:55, Ilya Leoshkevich wrote:
> On Wed, 2024-08-07 at 14:43 +0200, Philippe Mathieu-Daudé wrote:
>> Signed-off-by: Philippe Mathieu-Daudé <philmd@linaro.org>
>> ---
>>   linux-user/strace.c    | 19 +++++++++++++++++++
>>   linux-user/strace.list |  2 +-
>>   2 files changed, 20 insertions(+), 1 deletion(-)
>>
>> diff --git a/linux-user/strace.c b/linux-user/strace.c
>> index 98ef26b917..d76907fdc9 100644
>> --- a/linux-user/strace.c
>> +++ b/linux-user/strace.c
>> @@ -3127,6 +3127,25 @@ print_bind(CPUArchState *cpu_env, const struct
>> syscallname *name,
>>   }
>>   #endif
>>   
>> +#ifdef TARGET_NR_recvfrom
>> +static void
>> +print_recvfrom(CPUArchState *cpu_env, const struct syscallname
>> *name,
>> +               abi_long arg0, abi_long arg1, abi_long arg2,
>> +               abi_long arg3, abi_long arg4, abi_long arg5)
>> +{
>> +    abi_ulong addrlen;
>> +
>> +    get_user_ualx(addrlen, arg5, 0);
>> +
>> +    print_syscall_prologue(name);
>> +    print_sockfd(arg0, 0);
>> +    print_buf_len(arg1, arg2, 0);
>> +    print_flags(msg_flags, arg3, 0);
>> +    print_sockaddr(arg4, addrlen, 1);
>> +    print_syscall_epilogue(name);
>> +}
>> +#endif
>> +
>>   #ifdef TARGET_NR_sendto
>>   static void
>>   print_sendto(CPUArchState *cpu_env, const struct syscallname *name,
>> diff --git a/linux-user/strace.list b/linux-user/strace.list
>> index 5a86419e7d..77ca824f9c 100644
>> --- a/linux-user/strace.list
>> +++ b/linux-user/strace.list
>> @@ -1135,7 +1135,7 @@
>>   { TARGET_NR_recv, "recv" , "%s(%d,%p,%u,%d)", NULL, NULL },
>>   #endif
>>   #ifdef TARGET_NR_recvfrom
>> -{ TARGET_NR_recvfrom, "recvfrom" , NULL, NULL, NULL },
>> +{ TARGET_NR_recvfrom, "recvfrom" , NULL, print_recvfrom, NULL },
>>   #endif
>>   #ifdef TARGET_NR_recvmmsg
>>   { TARGET_NR_recvmmsg, "recvmmsg" , NULL, NULL, NULL },
> 
> I needed to implement read()/write() tracing and stumbled upon this
> series, which overall looks like a good thing to have. I spotted a few
> issues though.
> 
> 
> I get the following build error:
> 
> qemu/linux-user/strace.c:3138:5: error: implicit declaration of
> function ‘get_user_ualx’; did you mean ‘get_user_ual’? [-Wimplicit-
> function-declaration]
>   3138 |     get_user_ualx(addrlen, arg5, 0);
>        |     ^~~~~~~~~~~~~
>        |     get_user_ual
> 
> 
> The following helps:
> 
> --- a/linux-user/strace.c
> +++ b/linux-user/strace.c
> @@ -2666,11 +2666,15 @@ static void print_sockfd(abi_long sockfd, int
> last)
>   
>   #endif
>   
> -#if defined(TARGET_NR_socketcall)
> +#if defined(TARGET_NR_socketcall) || defined(TARGET_NR_recvfrom)
>   
>   #define get_user_ualx(x, gaddr, idx) \
>           get_user_ual(x, (gaddr) + (idx) * sizeof(abi_long))
>   
> +#endif
> +
> +#if defined(TARGET_NR_socketcall)

Or just not use get_user_ualx.

> However: aren't we printing the contents of the buffer before the
> syscall returns? Same with sockaddr. This would make the output not
> very useful.

Yes indeed.  Two of the three pointers are output buffers; the last is in/out.


r~