diff mbox

[1/3] log: improve performance of qemu_log and qemu_log_mask if disabled

Message ID 1444894224-9542-2-git-send-email-den@openvz.org
State New
Headers show

Commit Message

Denis V. Lunev Oct. 15, 2015, 7:30 a.m. UTC
The patch is intended to avoid to perform any operation including
calculation of log function arguments when the log is not enabled due to
various reasons.

Functions qemu_log and qemu_log_mask are replaced with variadic macros.
Unfortunately the code is not C99 compatible and we can not use
portable __VA_ARGS__ way. There are a lot of warnings in the other
places with --std=c99. Thus the only way to achive the result is to use
args.. GCC extension.

Format checking performed by compiler will not suffer by this patch. It
will be done inside in fprintf arguments checking.

Signed-off-by: Denis V. Lunev <den@openvz.org>
Signed-off-by: Pavel Butsykin <pbutsykin@virtuozzo.com>
CC: Markus Armbruster <armbru@redhat.com>
CC: Luiz Capitulino <lcapitulino@redhat.com>
CC: Eric Blake <eblake@redhat.com>
CC: Peter Maydell <peter.maydell@linaro.org>
---
 include/qemu/log.h | 17 ++++++++++++++---
 qemu-log.c         | 21 ---------------------
 2 files changed, 14 insertions(+), 24 deletions(-)

Comments

Alex Bennée Oct. 15, 2015, 5:23 p.m. UTC | #1
Denis V. Lunev <den@openvz.org> writes:

> The patch is intended to avoid to perform any operation including
> calculation of log function arguments when the log is not enabled due to
> various reasons.
>
> Functions qemu_log and qemu_log_mask are replaced with variadic macros.
> Unfortunately the code is not C99 compatible and we can not use
> portable __VA_ARGS__ way. There are a lot of warnings in the other
> places with --std=c99. Thus the only way to achive the result is to use
> args.. GCC extension.
>
> Format checking performed by compiler will not suffer by this patch. It
> will be done inside in fprintf arguments checking.
>
> Signed-off-by: Denis V. Lunev <den@openvz.org>
> Signed-off-by: Pavel Butsykin <pbutsykin@virtuozzo.com>
> CC: Markus Armbruster <armbru@redhat.com>
> CC: Luiz Capitulino <lcapitulino@redhat.com>
> CC: Eric Blake <eblake@redhat.com>
> CC: Peter Maydell <peter.maydell@linaro.org>
> ---
>  include/qemu/log.h | 17 ++++++++++++++---
>  qemu-log.c         | 21 ---------------------
>  2 files changed, 14 insertions(+), 24 deletions(-)
>
> diff --git a/include/qemu/log.h b/include/qemu/log.h
> index f880e66..57b8c96 100644
> --- a/include/qemu/log.h
> +++ b/include/qemu/log.h
> @@ -53,7 +53,13 @@ static inline bool qemu_loglevel_mask(int mask)
>  
>  /* main logging function
>   */
> -void GCC_FMT_ATTR(1, 2) qemu_log(const char *fmt, ...);
> +#define qemu_log(args...)                   \
> +    do {                                    \
> +        if (!qemu_log_enabled()) {          \
> +            break;                          \
> +        }                                   \
> +        fprintf(qemu_logfile, args);        \
> +    } while (0)
>

I've had one of Peter's patches in my logging improvements queue for a
while although it uses a slightly different form which I prefer:

-/* 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__);              \
+        }                                               \

See the message:

qemu-log: Avoid function call for disabled qemu_log_mask logging

>  /* vfprintf-like logging function
>   */
> @@ -67,8 +73,13 @@ qemu_log_vprintf(const char *fmt, va_list va)
>  
>  /* log only if a bit is set on the current loglevel mask
>   */
> -void GCC_FMT_ATTR(2, 3) qemu_log_mask(int mask, const char *fmt, ...);
> -
> +#define qemu_log_mask(mask, args...)        \
> +    do {                                    \
> +        if (!qemu_loglevel_mask(mask)) {    \
> +            break;                          \
> +        }                                   \
> +        qemu_log(args);                     \
> +    } while (0)
>  
>  /* Special cases: */
>  
> diff --git a/qemu-log.c b/qemu-log.c
> index 13f3813..e6d2b3f 100644
> --- a/qemu-log.c
> +++ b/qemu-log.c
> @@ -25,27 +25,6 @@ FILE *qemu_logfile;
>  int qemu_loglevel;
>  static int log_append = 0;
>  
> -void qemu_log(const char *fmt, ...)
> -{
> -    va_list ap;
> -
> -    va_start(ap, fmt);
> -    if (qemu_logfile) {
> -        vfprintf(qemu_logfile, fmt, ap);
> -    }
> -    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)
Denis V. Lunev Oct. 15, 2015, 5:40 p.m. UTC | #2
On 10/15/2015 08:23 PM, Alex Bennée wrote:
> Denis V. Lunev <den@openvz.org> writes:
>
>> The patch is intended to avoid to perform any operation including
>> calculation of log function arguments when the log is not enabled due to
>> various reasons.
>>
>> Functions qemu_log and qemu_log_mask are replaced with variadic macros.
>> Unfortunately the code is not C99 compatible and we can not use
>> portable __VA_ARGS__ way. There are a lot of warnings in the other
>> places with --std=c99. Thus the only way to achive the result is to use
>> args.. GCC extension.
>>
>> Format checking performed by compiler will not suffer by this patch. It
>> will be done inside in fprintf arguments checking.
>>
>> Signed-off-by: Denis V. Lunev <den@openvz.org>
>> Signed-off-by: Pavel Butsykin <pbutsykin@virtuozzo.com>
>> CC: Markus Armbruster <armbru@redhat.com>
>> CC: Luiz Capitulino <lcapitulino@redhat.com>
>> CC: Eric Blake <eblake@redhat.com>
>> CC: Peter Maydell <peter.maydell@linaro.org>
>> ---
>>   include/qemu/log.h | 17 ++++++++++++++---
>>   qemu-log.c         | 21 ---------------------
>>   2 files changed, 14 insertions(+), 24 deletions(-)
>>
>> diff --git a/include/qemu/log.h b/include/qemu/log.h
>> index f880e66..57b8c96 100644
>> --- a/include/qemu/log.h
>> +++ b/include/qemu/log.h
>> @@ -53,7 +53,13 @@ static inline bool qemu_loglevel_mask(int mask)
>>   
>>   /* main logging function
>>    */
>> -void GCC_FMT_ATTR(1, 2) qemu_log(const char *fmt, ...);
>> +#define qemu_log(args...)                   \
>> +    do {                                    \
>> +        if (!qemu_log_enabled()) {          \
>> +            break;                          \
>> +        }                                   \
>> +        fprintf(qemu_logfile, args);        \
>> +    } while (0)
>>
> I've had one of Peter's patches in my logging improvements queue for a
> while although it uses a slightly different form which I prefer:
>
> -/* 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__);              \
> +        }                                               \
>
> See the message:
>
> qemu-log: Avoid function call for disabled qemu_log_mask logging

as far as I can see that patch is one year old at least
and my version is slightly better, it does the same for
qemu_log.

The difference is that old patch has unlikely() hint and does not
contain break.

I can revert the condition and add the hint in a couple
of minutes if this will increase the chance to get
both things merged. We should have both functions
as macros.

Will you accept that?

Den
Alex Bennée Oct. 15, 2015, 6:36 p.m. UTC | #3
Denis V. Lunev <den@openvz.org> writes:

> On 10/15/2015 08:23 PM, Alex Bennée wrote:
>> Denis V. Lunev <den@openvz.org> writes:
>>
>>> The patch is intended to avoid to perform any operation including
>>> calculation of log function arguments when the log is not enabled due to
>>> various reasons.
>>>
>>> Functions qemu_log and qemu_log_mask are replaced with variadic macros.
>>> Unfortunately the code is not C99 compatible and we can not use
>>> portable __VA_ARGS__ way. There are a lot of warnings in the other
>>> places with --std=c99. Thus the only way to achive the result is to use
>>> args.. GCC extension.
>>>
>>> Format checking performed by compiler will not suffer by this patch. It
>>> will be done inside in fprintf arguments checking.
>>>
>>> Signed-off-by: Denis V. Lunev <den@openvz.org>
>>> Signed-off-by: Pavel Butsykin <pbutsykin@virtuozzo.com>
>>> CC: Markus Armbruster <armbru@redhat.com>
>>> CC: Luiz Capitulino <lcapitulino@redhat.com>
>>> CC: Eric Blake <eblake@redhat.com>
>>> CC: Peter Maydell <peter.maydell@linaro.org>
>>> ---
>>>   include/qemu/log.h | 17 ++++++++++++++---
>>>   qemu-log.c         | 21 ---------------------
>>>   2 files changed, 14 insertions(+), 24 deletions(-)
>>>
>>> diff --git a/include/qemu/log.h b/include/qemu/log.h
>>> index f880e66..57b8c96 100644
>>> --- a/include/qemu/log.h
>>> +++ b/include/qemu/log.h
>>> @@ -53,7 +53,13 @@ static inline bool qemu_loglevel_mask(int mask)
>>>   
>>>   /* main logging function
>>>    */
>>> -void GCC_FMT_ATTR(1, 2) qemu_log(const char *fmt, ...);
>>> +#define qemu_log(args...)                   \
>>> +    do {                                    \
>>> +        if (!qemu_log_enabled()) {          \
>>> +            break;                          \
>>> +        }                                   \
>>> +        fprintf(qemu_logfile, args);        \
>>> +    } while (0)
>>>
>> I've had one of Peter's patches in my logging improvements queue for a
>> while although it uses a slightly different form which I prefer:
>>
>> -/* 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__);              \
>> +        }                                               \
>>
>> See the message:
>>
>> qemu-log: Avoid function call for disabled qemu_log_mask logging
>
> as far as I can see that patch is one year old at least
> and my version is slightly better, it does the same for
> qemu_log.

Yeah it has been sitting in my queue for a while as part of a larger
series. I haven't been pushing it because the demand for the other
changes isn't super high.

Yes it would be better to do both qemu_log and qemu_log_mask.

> The difference is that old patch has unlikely() hint and does not
> contain break.

I'm not sure what the break form brings. It's personal preference I
guess but to me it is more natural to wrap things inside the condition
then use break to skip out of a block.

> I can revert the condition and add the hint in a couple
> of minutes if this will increase the chance to get
> both things merged. We should have both functions
> as macros.
>
> Will you accept that?

I'll certainly review the next submission. I also suggest you CC
qemu-trivial once you have collected all your r-b and a-b/s-o-b tags.

>
> Den
Markus Armbruster Oct. 16, 2015, 7:17 a.m. UTC | #4
"Denis V. Lunev" <den@openvz.org> writes:

> The patch is intended to avoid to perform any operation including
> calculation of log function arguments when the log is not enabled due to
> various reasons.
>
> Functions qemu_log and qemu_log_mask are replaced with variadic macros.
> Unfortunately the code is not C99 compatible and we can not use
> portable __VA_ARGS__ way. There are a lot of warnings in the other
> places with --std=c99. Thus the only way to achive the result is to use
> args.. GCC extension.

Really?  We use __VA_ARGS__ all over the place, why won't it work here?

> Format checking performed by compiler will not suffer by this patch. It
> will be done inside in fprintf arguments checking.
>
> Signed-off-by: Denis V. Lunev <den@openvz.org>
> Signed-off-by: Pavel Butsykin <pbutsykin@virtuozzo.com>
> CC: Markus Armbruster <armbru@redhat.com>
> CC: Luiz Capitulino <lcapitulino@redhat.com>
> CC: Eric Blake <eblake@redhat.com>
> CC: Peter Maydell <peter.maydell@linaro.org>
> ---
>  include/qemu/log.h | 17 ++++++++++++++---
>  qemu-log.c         | 21 ---------------------
>  2 files changed, 14 insertions(+), 24 deletions(-)
>
> diff --git a/include/qemu/log.h b/include/qemu/log.h
> index f880e66..57b8c96 100644
> --- a/include/qemu/log.h
> +++ b/include/qemu/log.h
> @@ -53,7 +53,13 @@ static inline bool qemu_loglevel_mask(int mask)
>  
>  /* main logging function
>   */
> -void GCC_FMT_ATTR(1, 2) qemu_log(const char *fmt, ...);
> +#define qemu_log(args...)                   \
> +    do {                                    \
> +        if (!qemu_log_enabled()) {          \
> +            break;                          \
> +        }                                   \
> +        fprintf(qemu_logfile, args);        \
> +    } while (0)

Feels stilted.  Like Alex's, I'd prefer something like

    #define qemu_log(fmt, ...)				\
        do {                                                \
            if (unlikely(qemu_log_enabled())) {		\
                fprintf(qemu_logfile, fmt, ## __VA_ARGS__);	\
            }						\
        } while (0)

I'm no fan of hiding qemu_logfile in qemu_log_enabled(), then using it
directly to print to it, but that's a different conversation.

However, we already have

    static inline void GCC_FMT_ATTR(1, 0)
    qemu_log_vprintf(const char *fmt, va_list va)
    {
        if (qemu_logfile) {
            vfprintf(qemu_logfile, fmt, va);
        }
    }

Wouldn't static inline work for qemu_log(), too?

>  /* vfprintf-like logging function
>   */
> @@ -67,8 +73,13 @@ qemu_log_vprintf(const char *fmt, va_list va)
>  
>  /* log only if a bit is set on the current loglevel mask
>   */
> -void GCC_FMT_ATTR(2, 3) qemu_log_mask(int mask, const char *fmt, ...);
> -
> +#define qemu_log_mask(mask, args...)        \
> +    do {                                    \
> +        if (!qemu_loglevel_mask(mask)) {    \
> +            break;                          \
> +        }                                   \
> +        qemu_log(args);                     \
> +    } while (0)
>  
>  /* Special cases: */
>  
> diff --git a/qemu-log.c b/qemu-log.c
> index 13f3813..e6d2b3f 100644
> --- a/qemu-log.c
> +++ b/qemu-log.c
> @@ -25,27 +25,6 @@ FILE *qemu_logfile;
>  int qemu_loglevel;
>  static int log_append = 0;
>  
> -void qemu_log(const char *fmt, ...)
> -{
> -    va_list ap;
> -
> -    va_start(ap, fmt);
> -    if (qemu_logfile) {
> -        vfprintf(qemu_logfile, fmt, ap);
> -    }
> -    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)

I support the general approach to inline the "is logging on" test
somehow.
Denis V. Lunev Oct. 16, 2015, 7:45 a.m. UTC | #5
On 10/16/2015 10:17 AM, Markus Armbruster wrote:
> "Denis V. Lunev" <den@openvz.org> writes:
>
>> The patch is intended to avoid to perform any operation including
>> calculation of log function arguments when the log is not enabled due to
>> various reasons.
>>
>> Functions qemu_log and qemu_log_mask are replaced with variadic macros.
>> Unfortunately the code is not C99 compatible and we can not use
>> portable __VA_ARGS__ way. There are a lot of warnings in the other
>> places with --std=c99. Thus the only way to achive the result is to use
>> args.. GCC extension.
> Really?  We use __VA_ARGS__ all over the place, why won't it work here?

I have received warning like this
   "__VA_ARGS__ can only appear in the expansion of a C99 variadic macro"
with intermediate version of the patch.

At the moment (with the current version) the replacement to __VA_ARGS__
works. Something strange has been happen. This syntax is definitely
better for me.

Will change.

>> Format checking performed by compiler will not suffer by this patch. It
>> will be done inside in fprintf arguments checking.
>>
>> Signed-off-by: Denis V. Lunev <den@openvz.org>
>> Signed-off-by: Pavel Butsykin <pbutsykin@virtuozzo.com>
>> CC: Markus Armbruster <armbru@redhat.com>
>> CC: Luiz Capitulino <lcapitulino@redhat.com>
>> CC: Eric Blake <eblake@redhat.com>
>> CC: Peter Maydell <peter.maydell@linaro.org>
>> ---
>>   include/qemu/log.h | 17 ++++++++++++++---
>>   qemu-log.c         | 21 ---------------------
>>   2 files changed, 14 insertions(+), 24 deletions(-)
>>
>> diff --git a/include/qemu/log.h b/include/qemu/log.h
>> index f880e66..57b8c96 100644
>> --- a/include/qemu/log.h
>> +++ b/include/qemu/log.h
>> @@ -53,7 +53,13 @@ static inline bool qemu_loglevel_mask(int mask)
>>   
>>   /* main logging function
>>    */
>> -void GCC_FMT_ATTR(1, 2) qemu_log(const char *fmt, ...);
>> +#define qemu_log(args...)                   \
>> +    do {                                    \
>> +        if (!qemu_log_enabled()) {          \
>> +            break;                          \
>> +        }                                   \
>> +        fprintf(qemu_logfile, args);        \
>> +    } while (0)
> Feels stilted.  Like Alex's, I'd prefer something like
>
>      #define qemu_log(fmt, ...)				\
>          do {                                                \
>              if (unlikely(qemu_log_enabled())) {		\
>                  fprintf(qemu_logfile, fmt, ## __VA_ARGS__);	\
>              }						\
>          } while (0)
>
> I'm no fan of hiding qemu_logfile in qemu_log_enabled(), then using it
> directly to print to it, but that's a different conversation.
actually I am fine with any approach :) as there is no difference to me.
In general, this was taken from another project where I have
had more code below if. This is just an option to reduce indentation
to a meaningful piece of the code.

> However, we already have
>
>      static inline void GCC_FMT_ATTR(1, 0)
>      qemu_log_vprintf(const char *fmt, va_list va)
>      {
>          if (qemu_logfile) {
>              vfprintf(qemu_logfile, fmt, va);
>          }
>      }
>
> Wouldn't static inline work for qemu_log(), too?

AFAIK no and the problem is that this could be compiler
specific.

irbis ~ $ cat 1.c
#include <stdio.h>

int f()
{
     return 1;
}

static inline int test(int a, int b)
{
     if (a == 1) {
         printf("%d\n", b);
     }
}

int main()
{
     test(2, f());
     return 0;
}
irbis ~ $

000000000040056b <main>:
   40056b:    55                       push   %rbp
   40056c:    48 89 e5                 mov    %rsp,%rbp
   40056f:    b8 00 00 00 00           mov    $0x0,%eax
   400574:    e8 bd ff ff ff           callq  400536 <f>
   400579:    89 c6                    mov    %eax,%esi
   40057b:    bf 02 00 00 00           mov    $0x2,%edi
   400580:    e8 bc ff ff ff           callq  400541 <test>
   400585:    b8 00 00 00 00           mov    $0x0,%eax
   40058a:    5d                       pop    %rbp
   40058b:    c3                       retq
   40058c:    0f 1f 40 00              nopl   0x0(%rax)


as you can see here f() is called before calling to test()

Thus I feel that this inline should be replaced too ;)

>>   /* vfprintf-like logging function
>>    */
>> @@ -67,8 +73,13 @@ qemu_log_vprintf(const char *fmt, va_list va)
>>   
>>   /* log only if a bit is set on the current loglevel mask
>>    */
>> -void GCC_FMT_ATTR(2, 3) qemu_log_mask(int mask, const char *fmt, ...);
>> -
>> +#define qemu_log_mask(mask, args...)        \
>> +    do {                                    \
>> +        if (!qemu_loglevel_mask(mask)) {    \
>> +            break;                          \
>> +        }                                   \
>> +        qemu_log(args);                     \
>> +    } while (0)
>>   
>>   /* Special cases: */
>>   
>> diff --git a/qemu-log.c b/qemu-log.c
>> index 13f3813..e6d2b3f 100644
>> --- a/qemu-log.c
>> +++ b/qemu-log.c
>> @@ -25,27 +25,6 @@ FILE *qemu_logfile;
>>   int qemu_loglevel;
>>   static int log_append = 0;
>>   
>> -void qemu_log(const char *fmt, ...)
>> -{
>> -    va_list ap;
>> -
>> -    va_start(ap, fmt);
>> -    if (qemu_logfile) {
>> -        vfprintf(qemu_logfile, fmt, ap);
>> -    }
>> -    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)
> I support the general approach to inline the "is logging on" test
> somehow.
Markus Armbruster Oct. 16, 2015, 11:02 a.m. UTC | #6
"Denis V. Lunev" <den@openvz.org> writes:

> On 10/16/2015 10:17 AM, Markus Armbruster wrote:
>> "Denis V. Lunev" <den@openvz.org> writes:
>>
>>> The patch is intended to avoid to perform any operation including
>>> calculation of log function arguments when the log is not enabled due to
>>> various reasons.
>>>
>>> Functions qemu_log and qemu_log_mask are replaced with variadic macros.
>>> Unfortunately the code is not C99 compatible and we can not use
>>> portable __VA_ARGS__ way. There are a lot of warnings in the other
>>> places with --std=c99. Thus the only way to achive the result is to use
>>> args.. GCC extension.
>> Really?  We use __VA_ARGS__ all over the place, why won't it work here?
>
> I have received warning like this
>   "__VA_ARGS__ can only appear in the expansion of a C99 variadic macro"
> with intermediate version of the patch.
>
> At the moment (with the current version) the replacement to __VA_ARGS__
> works. Something strange has been happen. This syntax is definitely
> better for me.
>
> Will change.
>
>>> Format checking performed by compiler will not suffer by this patch. It
>>> will be done inside in fprintf arguments checking.
>>>
>>> Signed-off-by: Denis V. Lunev <den@openvz.org>
>>> Signed-off-by: Pavel Butsykin <pbutsykin@virtuozzo.com>
>>> CC: Markus Armbruster <armbru@redhat.com>
>>> CC: Luiz Capitulino <lcapitulino@redhat.com>
>>> CC: Eric Blake <eblake@redhat.com>
>>> CC: Peter Maydell <peter.maydell@linaro.org>
>>> ---
>>>   include/qemu/log.h | 17 ++++++++++++++---
>>>   qemu-log.c         | 21 ---------------------
>>>   2 files changed, 14 insertions(+), 24 deletions(-)
>>>
>>> diff --git a/include/qemu/log.h b/include/qemu/log.h
>>> index f880e66..57b8c96 100644
>>> --- a/include/qemu/log.h
>>> +++ b/include/qemu/log.h
>>> @@ -53,7 +53,13 @@ static inline bool qemu_loglevel_mask(int mask)
>>>     /* main logging function
>>>    */
>>> -void GCC_FMT_ATTR(1, 2) qemu_log(const char *fmt, ...);
>>> +#define qemu_log(args...)                   \
>>> +    do {                                    \
>>> +        if (!qemu_log_enabled()) {          \
>>> +            break;                          \
>>> +        }                                   \
>>> +        fprintf(qemu_logfile, args);        \
>>> +    } while (0)
>> Feels stilted.  Like Alex's, I'd prefer something like
>>
>>      #define qemu_log(fmt, ...)				\
>>          do {                                                \
>>              if (unlikely(qemu_log_enabled())) {		\
>>                  fprintf(qemu_logfile, fmt, ## __VA_ARGS__);	\
>>              }						\
>>          } while (0)
>>
>> I'm no fan of hiding qemu_logfile in qemu_log_enabled(), then using it
>> directly to print to it, but that's a different conversation.
> actually I am fine with any approach :) as there is no difference to me.
> In general, this was taken from another project where I have
> had more code below if. This is just an option to reduce indentation
> to a meaningful piece of the code.
>
>> However, we already have
>>
>>      static inline void GCC_FMT_ATTR(1, 0)
>>      qemu_log_vprintf(const char *fmt, va_list va)
>>      {
>>          if (qemu_logfile) {
>>              vfprintf(qemu_logfile, fmt, va);
>>          }
>>      }
>>
>> Wouldn't static inline work for qemu_log(), too?
>
> AFAIK no and the problem is that this could be compiler
> specific.
>
> irbis ~ $ cat 1.c
> #include <stdio.h>
>
> int f()
> {
>     return 1;
> }
>
> static inline int test(int a, int b)
> {
>     if (a == 1) {
>         printf("%d\n", b);
>     }
> }
>
> int main()
> {
>     test(2, f());
>     return 0;
> }
> irbis ~ $
>
> 000000000040056b <main>:
>   40056b:    55                       push   %rbp
>   40056c:    48 89 e5                 mov    %rsp,%rbp
>   40056f:    b8 00 00 00 00           mov    $0x0,%eax
>   400574:    e8 bd ff ff ff           callq  400536 <f>
>   400579:    89 c6                    mov    %eax,%esi
>   40057b:    bf 02 00 00 00           mov    $0x2,%edi
>   400580:    e8 bc ff ff ff           callq  400541 <test>
>   400585:    b8 00 00 00 00           mov    $0x0,%eax
>   40058a:    5d                       pop    %rbp
>   40058b:    c3                       retq
>   40058c:    0f 1f 40 00              nopl   0x0(%rax)
>
>
> as you can see here f() is called before calling to test()
>
> Thus I feel that this inline should be replaced too ;)

Well, what did you expect?  You asked the compiler to inline test(), and
it inlined test().  You didn't ask it to inline f(), and it didn't
inline f().

[...]
Denis V. Lunev Oct. 16, 2015, 11:08 a.m. UTC | #7
On 10/16/2015 02:02 PM, Markus Armbruster wrote:
> "Denis V. Lunev" <den@openvz.org> writes:
>
>> On 10/16/2015 10:17 AM, Markus Armbruster wrote:
>>> "Denis V. Lunev" <den@openvz.org> writes:
>>>
>>>> The patch is intended to avoid to perform any operation including
>>>> calculation of log function arguments when the log is not enabled due to
>>>> various reasons.
>>>>
>>>> Functions qemu_log and qemu_log_mask are replaced with variadic macros.
>>>> Unfortunately the code is not C99 compatible and we can not use
>>>> portable __VA_ARGS__ way. There are a lot of warnings in the other
>>>> places with --std=c99. Thus the only way to achive the result is to use
>>>> args.. GCC extension.
>>> Really?  We use __VA_ARGS__ all over the place, why won't it work here?
>> I have received warning like this
>>    "__VA_ARGS__ can only appear in the expansion of a C99 variadic macro"
>> with intermediate version of the patch.
>>
>> At the moment (with the current version) the replacement to __VA_ARGS__
>> works. Something strange has been happen. This syntax is definitely
>> better for me.
>>
>> Will change.
>>
>>>> Format checking performed by compiler will not suffer by this patch. It
>>>> will be done inside in fprintf arguments checking.
>>>>
>>>> Signed-off-by: Denis V. Lunev <den@openvz.org>
>>>> Signed-off-by: Pavel Butsykin <pbutsykin@virtuozzo.com>
>>>> CC: Markus Armbruster <armbru@redhat.com>
>>>> CC: Luiz Capitulino <lcapitulino@redhat.com>
>>>> CC: Eric Blake <eblake@redhat.com>
>>>> CC: Peter Maydell <peter.maydell@linaro.org>
>>>> ---
>>>>    include/qemu/log.h | 17 ++++++++++++++---
>>>>    qemu-log.c         | 21 ---------------------
>>>>    2 files changed, 14 insertions(+), 24 deletions(-)
>>>>
>>>> diff --git a/include/qemu/log.h b/include/qemu/log.h
>>>> index f880e66..57b8c96 100644
>>>> --- a/include/qemu/log.h
>>>> +++ b/include/qemu/log.h
>>>> @@ -53,7 +53,13 @@ static inline bool qemu_loglevel_mask(int mask)
>>>>      /* main logging function
>>>>     */
>>>> -void GCC_FMT_ATTR(1, 2) qemu_log(const char *fmt, ...);
>>>> +#define qemu_log(args...)                   \
>>>> +    do {                                    \
>>>> +        if (!qemu_log_enabled()) {          \
>>>> +            break;                          \
>>>> +        }                                   \
>>>> +        fprintf(qemu_logfile, args);        \
>>>> +    } while (0)
>>> Feels stilted.  Like Alex's, I'd prefer something like
>>>
>>>       #define qemu_log(fmt, ...)				\
>>>           do {                                                \
>>>               if (unlikely(qemu_log_enabled())) {		\
>>>                   fprintf(qemu_logfile, fmt, ## __VA_ARGS__);	\
>>>               }						\
>>>           } while (0)
>>>
>>> I'm no fan of hiding qemu_logfile in qemu_log_enabled(), then using it
>>> directly to print to it, but that's a different conversation.
>> actually I am fine with any approach :) as there is no difference to me.
>> In general, this was taken from another project where I have
>> had more code below if. This is just an option to reduce indentation
>> to a meaningful piece of the code.
>>
>>> However, we already have
>>>
>>>       static inline void GCC_FMT_ATTR(1, 0)
>>>       qemu_log_vprintf(const char *fmt, va_list va)
>>>       {
>>>           if (qemu_logfile) {
>>>               vfprintf(qemu_logfile, fmt, va);
>>>           }
>>>       }
>>>
>>> Wouldn't static inline work for qemu_log(), too?
>> AFAIK no and the problem is that this could be compiler
>> specific.
>>
>> irbis ~ $ cat 1.c
>> #include <stdio.h>
>>
>> int f()
>> {
>>      return 1;
>> }
>>
>> static inline int test(int a, int b)
>> {
>>      if (a == 1) {
>>          printf("%d\n", b);
>>      }
>> }
>>
>> int main()
>> {
>>      test(2, f());
>>      return 0;
>> }
>> irbis ~ $
>>
>> 000000000040056b <main>:
>>    40056b:    55                       push   %rbp
>>    40056c:    48 89 e5                 mov    %rsp,%rbp
>>    40056f:    b8 00 00 00 00           mov    $0x0,%eax
>>    400574:    e8 bd ff ff ff           callq  400536 <f>
>>    400579:    89 c6                    mov    %eax,%esi
>>    40057b:    bf 02 00 00 00           mov    $0x2,%edi
>>    400580:    e8 bc ff ff ff           callq  400541 <test>
>>    400585:    b8 00 00 00 00           mov    $0x0,%eax
>>    40058a:    5d                       pop    %rbp
>>    40058b:    c3                       retq
>>    40058c:    0f 1f 40 00              nopl   0x0(%rax)
>>
>>
>> as you can see here f() is called before calling to test()
>>
>> Thus I feel that this inline should be replaced too ;)
> Well, what did you expect?  You asked the compiler to inline test(), and
> it inlined test().  You didn't ask it to inline f(), and it didn't
> inline f().
>
> [...]
you have asked whether 'static inline' will help
to avoid arguments evaluation. This does not happen,
compiler has not inlined inline function, (call test)
is here and arguments have been calculated.

For me this means that macros are better than
inline functions for logging functions. I do not
want to bother about interesting side-effects.

No log - no parameter evaluation under all
conditions.

Den
diff mbox

Patch

diff --git a/include/qemu/log.h b/include/qemu/log.h
index f880e66..57b8c96 100644
--- a/include/qemu/log.h
+++ b/include/qemu/log.h
@@ -53,7 +53,13 @@  static inline bool qemu_loglevel_mask(int mask)
 
 /* main logging function
  */
-void GCC_FMT_ATTR(1, 2) qemu_log(const char *fmt, ...);
+#define qemu_log(args...)                   \
+    do {                                    \
+        if (!qemu_log_enabled()) {          \
+            break;                          \
+        }                                   \
+        fprintf(qemu_logfile, args);        \
+    } while (0)
 
 /* vfprintf-like logging function
  */
@@ -67,8 +73,13 @@  qemu_log_vprintf(const char *fmt, va_list va)
 
 /* log only if a bit is set on the current loglevel mask
  */
-void GCC_FMT_ATTR(2, 3) qemu_log_mask(int mask, const char *fmt, ...);
-
+#define qemu_log_mask(mask, args...)        \
+    do {                                    \
+        if (!qemu_loglevel_mask(mask)) {    \
+            break;                          \
+        }                                   \
+        qemu_log(args);                     \
+    } while (0)
 
 /* Special cases: */
 
diff --git a/qemu-log.c b/qemu-log.c
index 13f3813..e6d2b3f 100644
--- a/qemu-log.c
+++ b/qemu-log.c
@@ -25,27 +25,6 @@  FILE *qemu_logfile;
 int qemu_loglevel;
 static int log_append = 0;
 
-void qemu_log(const char *fmt, ...)
-{
-    va_list ap;
-
-    va_start(ap, fmt);
-    if (qemu_logfile) {
-        vfprintf(qemu_logfile, fmt, ap);
-    }
-    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)