Re: [PATCH v2 2/4] linux-user: Use `qemu_log' for strace

2020-02-04 Thread Laurent Vivier
Le 04/02/2020 à 03:55, Josh Kunz a écrit :
> On Tue, Jan 28, 2020 at 7:07 AM Laurent Vivier  wrote:
>>
>> Le 17/01/2020 à 20:28, Josh Kunz a écrit :
>>> This change switches linux-user strace logging to use the newer `qemu_log`
>>> logging subsystem rather than the older `gemu_log` (notice the "g")
>>> logger. `qemu_log` has several advantages, namely that it allows logging
>>> to a file, and provides a more unified interface for configuration
>>> of logging (via the QEMU_LOG environment variable or options).
>>>
>>> This change introduces a new log mask: `LOG_STRACE` which is used for
>>> logging of user-mode strace messages.
>>>
>>> Signed-off-by: Josh Kunz 
>>> ---
>>>  include/qemu/log.h   |   2 +
>>>  linux-user/main.c|  30 ++-
>>>  linux-user/qemu.h|   1 -
>>>  linux-user/signal.c  |   2 +-
>>>  linux-user/strace.c  | 479 ++-
>>>  linux-user/syscall.c |  13 +-
>>>  util/log.c   |   2 +
>>>  7 files changed, 278 insertions(+), 251 deletions(-)
>>>
>> ...
>>> diff --git a/linux-user/syscall.c b/linux-user/syscall.c
>>> index 629f3a21b5..54e60f3807 100644
>>> --- a/linux-user/syscall.c
>>> +++ b/linux-user/syscall.c
>>> @@ -12098,14 +12098,15 @@ abi_long do_syscall(void *cpu_env, int num, 
>>> abi_long arg1,
>>>  record_syscall_start(cpu, num, arg1,
>>>   arg2, arg3, arg4, arg5, arg6, arg7, arg8);
>>>
>>> -if (unlikely(do_strace)) {
>>> +if (unlikely(qemu_loglevel_mask(LOG_STRACE))) {
>>>  print_syscall(num, arg1, arg2, arg3, arg4, arg5, arg6);
>>> -ret = do_syscall1(cpu_env, num, arg1, arg2, arg3, arg4,
>>> -  arg5, arg6, arg7, arg8);
>>> +}
>>> +
>>> +ret = do_syscall1(cpu_env, num, arg1, arg2, arg3, arg4,
>>> +  arg5, arg6, arg7, arg8);
>>> +
>>> +if (unlikely(qemu_loglevel_mask(LOG_STRACE))) {
>>>  print_syscall_ret(num, ret);
>>> -} else {
>>> -ret = do_syscall1(cpu_env, num, arg1, arg2, arg3, arg4,
>>> -  arg5, arg6, arg7, arg8);
>>>  }
>>>
>>>  record_syscall_return(cpu, num, ret);
>>
>> In term of performance perhaps it sould be better to only test once for
>> the mask as it is done before?
> 
> Modern compilers will generate functionally identical sequences for
> test once or testing twice (which is to say, they recognize they are
> the same compare: https://godbolt.org/z/VyrMHf IMO testing twice is
> nicer to read, so I'm leaving it that way for now unless you object.
> 

If generated code is the same, I have no objection.

Thanks,
Laurent



Re: [PATCH v2 2/4] linux-user: Use `qemu_log' for strace

2020-02-03 Thread Josh Kunz
On Tue, Jan 28, 2020 at 7:07 AM Laurent Vivier  wrote:
>
> Le 17/01/2020 à 20:28, Josh Kunz a écrit :
> > This change switches linux-user strace logging to use the newer `qemu_log`
> > logging subsystem rather than the older `gemu_log` (notice the "g")
> > logger. `qemu_log` has several advantages, namely that it allows logging
> > to a file, and provides a more unified interface for configuration
> > of logging (via the QEMU_LOG environment variable or options).
> >
> > This change introduces a new log mask: `LOG_STRACE` which is used for
> > logging of user-mode strace messages.
> >
> > Signed-off-by: Josh Kunz 
> > ---
> >  include/qemu/log.h   |   2 +
> >  linux-user/main.c|  30 ++-
> >  linux-user/qemu.h|   1 -
> >  linux-user/signal.c  |   2 +-
> >  linux-user/strace.c  | 479 ++-
> >  linux-user/syscall.c |  13 +-
> >  util/log.c   |   2 +
> >  7 files changed, 278 insertions(+), 251 deletions(-)
> >
> ...
> > diff --git a/linux-user/syscall.c b/linux-user/syscall.c
> > index 629f3a21b5..54e60f3807 100644
> > --- a/linux-user/syscall.c
> > +++ b/linux-user/syscall.c
> > @@ -12098,14 +12098,15 @@ abi_long do_syscall(void *cpu_env, int num, 
> > abi_long arg1,
> >  record_syscall_start(cpu, num, arg1,
> >   arg2, arg3, arg4, arg5, arg6, arg7, arg8);
> >
> > -if (unlikely(do_strace)) {
> > +if (unlikely(qemu_loglevel_mask(LOG_STRACE))) {
> >  print_syscall(num, arg1, arg2, arg3, arg4, arg5, arg6);
> > -ret = do_syscall1(cpu_env, num, arg1, arg2, arg3, arg4,
> > -  arg5, arg6, arg7, arg8);
> > +}
> > +
> > +ret = do_syscall1(cpu_env, num, arg1, arg2, arg3, arg4,
> > +  arg5, arg6, arg7, arg8);
> > +
> > +if (unlikely(qemu_loglevel_mask(LOG_STRACE))) {
> >  print_syscall_ret(num, ret);
> > -} else {
> > -ret = do_syscall1(cpu_env, num, arg1, arg2, arg3, arg4,
> > -  arg5, arg6, arg7, arg8);
> >  }
> >
> >  record_syscall_return(cpu, num, ret);
>
> In term of performance perhaps it sould be better to only test once for
> the mask as it is done before?

Modern compilers will generate functionally identical sequences for
test once or testing twice (which is to say, they recognize they are
the same compare: https://godbolt.org/z/VyrMHf IMO testing twice is
nicer to read, so I'm leaving it that way for now unless you object.



Re: [PATCH v2 2/4] linux-user: Use `qemu_log' for strace

2020-01-28 Thread Laurent Vivier
Le 17/01/2020 à 20:28, Josh Kunz a écrit :
> This change switches linux-user strace logging to use the newer `qemu_log`
> logging subsystem rather than the older `gemu_log` (notice the "g")
> logger. `qemu_log` has several advantages, namely that it allows logging
> to a file, and provides a more unified interface for configuration
> of logging (via the QEMU_LOG environment variable or options).
> 
> This change introduces a new log mask: `LOG_STRACE` which is used for
> logging of user-mode strace messages.
> 
> Signed-off-by: Josh Kunz 
> ---
>  include/qemu/log.h   |   2 +
>  linux-user/main.c|  30 ++-
>  linux-user/qemu.h|   1 -
>  linux-user/signal.c  |   2 +-
>  linux-user/strace.c  | 479 ++-
>  linux-user/syscall.c |  13 +-
>  util/log.c   |   2 +
>  7 files changed, 278 insertions(+), 251 deletions(-)
> 
...
> diff --git a/linux-user/syscall.c b/linux-user/syscall.c
> index 629f3a21b5..54e60f3807 100644
> --- a/linux-user/syscall.c
> +++ b/linux-user/syscall.c
> @@ -12098,14 +12098,15 @@ abi_long do_syscall(void *cpu_env, int num, 
> abi_long arg1,
>  record_syscall_start(cpu, num, arg1,
>   arg2, arg3, arg4, arg5, arg6, arg7, arg8);
>  
> -if (unlikely(do_strace)) {
> +if (unlikely(qemu_loglevel_mask(LOG_STRACE))) {
>  print_syscall(num, arg1, arg2, arg3, arg4, arg5, arg6);
> -ret = do_syscall1(cpu_env, num, arg1, arg2, arg3, arg4,
> -  arg5, arg6, arg7, arg8);
> +}
> +
> +ret = do_syscall1(cpu_env, num, arg1, arg2, arg3, arg4,
> +  arg5, arg6, arg7, arg8);
> +
> +if (unlikely(qemu_loglevel_mask(LOG_STRACE))) {
>  print_syscall_ret(num, ret);
> -} else {
> -ret = do_syscall1(cpu_env, num, arg1, arg2, arg3, arg4,
> -  arg5, arg6, arg7, arg8);
>  }
>  
>  record_syscall_return(cpu, num, ret);

In term of performance perhaps it sould be better to only test once for
the mask as it is done before?

For the other parts:

Reviewed-by: Laurent Vivier 

Thanks,
Laurent



[PATCH v2 2/4] linux-user: Use `qemu_log' for strace

2020-01-17 Thread Josh Kunz
This change switches linux-user strace logging to use the newer `qemu_log`
logging subsystem rather than the older `gemu_log` (notice the "g")
logger. `qemu_log` has several advantages, namely that it allows logging
to a file, and provides a more unified interface for configuration
of logging (via the QEMU_LOG environment variable or options).

This change introduces a new log mask: `LOG_STRACE` which is used for
logging of user-mode strace messages.

Signed-off-by: Josh Kunz 
---
 include/qemu/log.h   |   2 +
 linux-user/main.c|  30 ++-
 linux-user/qemu.h|   1 -
 linux-user/signal.c  |   2 +-
 linux-user/strace.c  | 479 ++-
 linux-user/syscall.c |  13 +-
 util/log.c   |   2 +
 7 files changed, 278 insertions(+), 251 deletions(-)

diff --git a/include/qemu/log.h b/include/qemu/log.h
index e0f4e40628..f4724f7330 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -62,6 +62,8 @@ static inline bool qemu_log_separate(void)
 #define CPU_LOG_TB_OP_IND  (1 << 16)
 #define CPU_LOG_TB_FPU (1 << 17)
 #define CPU_LOG_PLUGIN (1 << 18)
+/* LOG_STRACE is used for user-mode strace logging. */
+#define LOG_STRACE (1 << 19)
 
 /* Lock output for a series of related logs.  Since this is not needed
  * for a single qemu_log / qemu_log_mask / qemu_log_mask_and_addr, we
diff --git a/linux-user/main.c b/linux-user/main.c
index fba833aac9..8f1d07cdd6 100644
--- a/linux-user/main.c
+++ b/linux-user/main.c
@@ -60,6 +60,19 @@ unsigned long mmap_min_addr;
 unsigned long guest_base;
 int have_guest_base;
 
+/*
+ * Used to implement backwards-compatibility for the `-strace`, and
+ * QEMU_STRACE options. Without this, the QEMU_LOG can be overwritten by
+ * -strace, or vice versa.
+ */
+static bool enable_strace;
+
+/*
+ * The last log mask given by the user in an environment variable or argument.
+ * Used to support command line arguments overriding environment variables.
+ */
+static int last_log_mask;
+
 /*
  * When running 32-on-64 we should make sure we can fit all of the possible
  * guest address space into a contiguous chunk of virtual host memory.
@@ -223,15 +236,11 @@ static void handle_arg_help(const char *arg)
 
 static void handle_arg_log(const char *arg)
 {
-int mask;
-
-mask = qemu_str_to_log_mask(arg);
-if (!mask) {
+last_log_mask = qemu_str_to_log_mask(arg);
+if (!last_log_mask) {
 qemu_print_log_usage(stdout);
 exit(EXIT_FAILURE);
 }
-qemu_log_needs_buffers();
-qemu_set_log(mask);
 }
 
 static void handle_arg_dfilter(const char *arg)
@@ -375,7 +384,7 @@ static void handle_arg_singlestep(const char *arg)
 
 static void handle_arg_strace(const char *arg)
 {
-do_strace = 1;
+enable_strace = true;
 }
 
 static void handle_arg_version(const char *arg)
@@ -629,6 +638,7 @@ int main(int argc, char **argv, char **envp)
 int i;
 int ret;
 int execfd;
+int log_mask;
 unsigned long max_reserved_va;
 
 error_init(argv[0]);
@@ -661,6 +671,12 @@ int main(int argc, char **argv, char **envp)
 
 optind = parse_args(argc, argv);
 
+log_mask = last_log_mask | (enable_strace ? LOG_STRACE : 0);
+if (log_mask) {
+qemu_log_needs_buffers();
+qemu_set_log(log_mask);
+}
+
 if (!trace_init_backends()) {
 exit(1);
 }
diff --git a/linux-user/qemu.h b/linux-user/qemu.h
index f6f5fe5fbb..02c6890c8a 100644
--- a/linux-user/qemu.h
+++ b/linux-user/qemu.h
@@ -385,7 +385,6 @@ void print_syscall_ret(int num, abi_long arg1);
  * --- SIGSEGV {si_signo=SIGSEGV, si_code=SI_KERNEL, si_addr=0} ---
  */
 void print_taken_signal(int target_signum, const target_siginfo_t *tinfo);
-extern int do_strace;
 
 /* signal.c */
 void process_pending_signals(CPUArchState *cpu_env);
diff --git a/linux-user/signal.c b/linux-user/signal.c
index 5ca6d62b15..818d867b7b 100644
--- a/linux-user/signal.c
+++ b/linux-user/signal.c
@@ -864,7 +864,7 @@ static void handle_pending_signal(CPUArchState *cpu_env, 
int sig,
 handler = sa->_sa_handler;
 }
 
-if (do_strace) {
+if (unlikely(qemu_loglevel_mask(LOG_STRACE))) {
 print_taken_signal(sig, >info);
 }
 
diff --git a/linux-user/strace.c b/linux-user/strace.c
index 3d4d684450..4f7130b2ff 100644
--- a/linux-user/strace.c
+++ b/linux-user/strace.c
@@ -12,8 +12,6 @@
 #include 
 #include "qemu.h"
 
-int do_strace=0;
-
 struct syscallname {
 int nr;
 const char *name;
@@ -80,7 +78,7 @@ print_ipc_cmd(int cmd)
 {
 #define output_cmd(val) \
 if( cmd == val ) { \
-gemu_log(#val); \
+qemu_log(#val); \
 return; \
 }
 
@@ -120,7 +118,7 @@ if( cmd == val ) { \
 output_cmd( IPC_RMID );
 
 /* Some value we don't recognize */
-gemu_log("%d",cmd);
+qemu_log("%d", cmd);
 }
 
 static void
@@ -151,7 +149,7 @@ print_signal(abi_ulong arg, int last)
 print_raw_param("%ld", arg, last);
 return;
 }
-gemu_log("%s%s", signal_name, get_comma(last));
+