[PATCH] Do not use %m in common code to print error messages

[PATCH] Do not use %m in common code to print error messages

[Thomas Huth]

The %m format specifier is an extension from glibc - and when compiling
QEMU for NetBSD, the compiler correctly complains, e.g.:

/home/qemu/qemu-test.ELjfrQ/src/util/main-loop.c: In function 'sigfd_handler':
/home/qemu/qemu-test.ELjfrQ/src/util/main-loop.c:64:13: warning: %m is only
 allowed in syslog(3) like functions [-Wformat=]
             printf("read from sigfd returned %zd: %m\n", len);
             ^
Let's use g_strerror() here instead, which is an easy-to-use wrapper
around the thread-safe strerror_r() function.

While we're at it, also convert the "printf()" in main-loop.c into
the preferred "error_report()".

Signed-off-by: Thomas Huth <thuth@redhat.com>
---
 hw/misc/tmp421.c | 8 ++++++--
 util/main-loop.c | 4 +++-
 util/systemd.c   | 5 +++--
 3 files changed, 12 insertions(+), 5 deletions(-)

diff --git a/hw/misc/tmp421.c b/hw/misc/tmp421.c
index 9f044705fa..f23c46a40a 100644
--- a/hw/misc/tmp421.c
+++ b/hw/misc/tmp421.c
@@ -120,7 +120,9 @@ static void tmp421_get_temperature(Object *obj, Visitor *v, const char *name,
     int tempid;
 
     if (sscanf(name, "temperature%d", &tempid) != 1) {
-        error_setg(errp, "error reading %s: %m", name);
+        const char *errmsg = g_strerror(errno);
+        error_setg(errp, "error reading %s: %s", name, errmsg);
+        g_free((gpointer)errmsg);
         return;
     }
 
@@ -160,7 +162,9 @@ static void tmp421_set_temperature(Object *obj, Visitor *v, const char *name,
     }
 
     if (sscanf(name, "temperature%d", &tempid) != 1) {
-        error_setg(errp, "error reading %s: %m", name);
+        const char *errmsg = g_strerror(errno);
+        error_setg(errp, "error reading %s: %s", errmsg);
+        g_free((gpointer)errmsg);
         return;
     }
 
diff --git a/util/main-loop.c b/util/main-loop.c
index e3eaa55866..e95d93fef3 100644
--- a/util/main-loop.c
+++ b/util/main-loop.c
@@ -61,7 +61,9 @@ static void sigfd_handler(void *opaque)
         }
 
         if (len != sizeof(info)) {
-            printf("read from sigfd returned %zd: %m\n", len);
+            const char *errmsg = g_strerror(errno);
+            error_report("read from sigfd returned %zd: %s", len, errmsg);
+            g_free((gpointer)errmsg);
             return;
         }
 
diff --git a/util/systemd.c b/util/systemd.c
index d22e86c707..17862c704f 100644
--- a/util/systemd.c
+++ b/util/systemd.c
@@ -59,9 +59,10 @@ unsigned int check_socket_activation(void)
              * descriptor is invalid, so socket activation has gone wrong
              * and we should exit.
              */
+            const char *errmsg = g_strerror(errno);
             error_report("Socket activation failed: "
-                         "invalid file descriptor fd = %d: %m",
-                         fd);
+                         "invalid file descriptor fd = %d: %s", fd, errmsg);
+            g_free((gpointer)errmsg);
             exit(EXIT_FAILURE);
         }
     }
-- 
2.18.1

Re: [PATCH] Do not use %m in common code to print error messages

[Daniel P. Berrangé]

On Fri, Oct 18, 2019 at 12:44:38PM +0200, Thomas Huth wrote:
> The %m format specifier is an extension from glibc - and when compiling
> QEMU for NetBSD, the compiler correctly complains, e.g.:
> 
> /home/qemu/qemu-test.ELjfrQ/src/util/main-loop.c: In function 'sigfd_handler':
> /home/qemu/qemu-test.ELjfrQ/src/util/main-loop.c:64:13: warning: %m is only
>  allowed in syslog(3) like functions [-Wformat=]
>              printf("read from sigfd returned %zd: %m\n", len);
>              ^
> Let's use g_strerror() here instead, which is an easy-to-use wrapper
> around the thread-safe strerror_r() function.
> 
> While we're at it, also convert the "printf()" in main-loop.c into
> the preferred "error_report()".
> 
> Signed-off-by: Thomas Huth <thuth@redhat.com>
> ---
>  hw/misc/tmp421.c | 8 ++++++--
>  util/main-loop.c | 4 +++-
>  util/systemd.c   | 5 +++--
>  3 files changed, 12 insertions(+), 5 deletions(-)
> 
> diff --git a/hw/misc/tmp421.c b/hw/misc/tmp421.c
> index 9f044705fa..f23c46a40a 100644
> --- a/hw/misc/tmp421.c
> +++ b/hw/misc/tmp421.c
> @@ -120,7 +120,9 @@ static void tmp421_get_temperature(Object *obj, Visitor *v, const char *name,
>      int tempid;
>  
>      if (sscanf(name, "temperature%d", &tempid) != 1) {
> -        error_setg(errp, "error reading %s: %m", name);
> +        const char *errmsg = g_strerror(errno);
> +        error_setg(errp, "error reading %s: %s", name, errmsg);
> +        g_free((gpointer)errmsg);

Kaboom crash. This is trying to free a const string that is the caller
doesn't own. It remains under ownership of g_strerror forever.

Regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|

Re: [PATCH] Do not use %m in common code to print error messages

[Thomas Huth]

On 18/10/2019 12.57, Daniel P. Berrangé wrote:
> On Fri, Oct 18, 2019 at 12:44:38PM +0200, Thomas Huth wrote:
>> The %m format specifier is an extension from glibc - and when compiling
>> QEMU for NetBSD, the compiler correctly complains, e.g.:
>>
>> /home/qemu/qemu-test.ELjfrQ/src/util/main-loop.c: In function 'sigfd_handler':
>> /home/qemu/qemu-test.ELjfrQ/src/util/main-loop.c:64:13: warning: %m is only
>>  allowed in syslog(3) like functions [-Wformat=]
>>              printf("read from sigfd returned %zd: %m\n", len);
>>              ^
>> Let's use g_strerror() here instead, which is an easy-to-use wrapper
>> around the thread-safe strerror_r() function.
>>
>> While we're at it, also convert the "printf()" in main-loop.c into
>> the preferred "error_report()".
>>
>> Signed-off-by: Thomas Huth <thuth@redhat.com>
>> ---
>>  hw/misc/tmp421.c | 8 ++++++--
>>  util/main-loop.c | 4 +++-
>>  util/systemd.c   | 5 +++--
>>  3 files changed, 12 insertions(+), 5 deletions(-)
>>
>> diff --git a/hw/misc/tmp421.c b/hw/misc/tmp421.c
>> index 9f044705fa..f23c46a40a 100644
>> --- a/hw/misc/tmp421.c
>> +++ b/hw/misc/tmp421.c
>> @@ -120,7 +120,9 @@ static void tmp421_get_temperature(Object *obj, Visitor *v, const char *name,
>>      int tempid;
>>  
>>      if (sscanf(name, "temperature%d", &tempid) != 1) {
>> -        error_setg(errp, "error reading %s: %m", name);
>> +        const char *errmsg = g_strerror(errno);
>> +        error_setg(errp, "error reading %s: %s", name, errmsg);
>> +        g_free((gpointer)errmsg);
> 
> Kaboom crash. This is trying to free a const string that is the caller
> doesn't own. It remains under ownership of g_strerror forever.

Well, if you look at the implementation of g_strerror(), you can see
that glib returns allocated memory here (with g_strdup() for example).
So if we don't free, this will leak memory over time.

But you're right, the "const" and documentation of the function indicate
that the caller should rather not free the memory. What a bummer, sounds
like g_strerror() is pretty much useless unless you immediately exit()
afterwards (and you care about not leaking memory).

I guess we have to implement our own wrapper, qemu_strerror() instead?

 Thomas

Re: [PATCH] Do not use %m in common code to print error messages

[Daniel P. Berrangé]

On Fri, Oct 18, 2019 at 01:31:34PM +0200, Thomas Huth wrote:
> On 18/10/2019 12.57, Daniel P. Berrangé wrote:
> > On Fri, Oct 18, 2019 at 12:44:38PM +0200, Thomas Huth wrote:
> >> The %m format specifier is an extension from glibc - and when compiling
> >> QEMU for NetBSD, the compiler correctly complains, e.g.:
> >>
> >> /home/qemu/qemu-test.ELjfrQ/src/util/main-loop.c: In function 'sigfd_handler':
> >> /home/qemu/qemu-test.ELjfrQ/src/util/main-loop.c:64:13: warning: %m is only
> >>  allowed in syslog(3) like functions [-Wformat=]
> >>              printf("read from sigfd returned %zd: %m\n", len);
> >>              ^
> >> Let's use g_strerror() here instead, which is an easy-to-use wrapper
> >> around the thread-safe strerror_r() function.
> >>
> >> While we're at it, also convert the "printf()" in main-loop.c into
> >> the preferred "error_report()".
> >>
> >> Signed-off-by: Thomas Huth <thuth@redhat.com>
> >> ---
> >>  hw/misc/tmp421.c | 8 ++++++--
> >>  util/main-loop.c | 4 +++-
> >>  util/systemd.c   | 5 +++--
> >>  3 files changed, 12 insertions(+), 5 deletions(-)
> >>
> >> diff --git a/hw/misc/tmp421.c b/hw/misc/tmp421.c
> >> index 9f044705fa..f23c46a40a 100644
> >> --- a/hw/misc/tmp421.c
> >> +++ b/hw/misc/tmp421.c
> >> @@ -120,7 +120,9 @@ static void tmp421_get_temperature(Object *obj, Visitor *v, const char *name,
> >>      int tempid;
> >>  
> >>      if (sscanf(name, "temperature%d", &tempid) != 1) {
> >> -        error_setg(errp, "error reading %s: %m", name);
> >> +        const char *errmsg = g_strerror(errno);
> >> +        error_setg(errp, "error reading %s: %s", name, errmsg);
> >> +        g_free((gpointer)errmsg);
> > 
> > Kaboom crash. This is trying to free a const string that is the caller
> > doesn't own. It remains under ownership of g_strerror forever.
> 
> Well, if you look at the implementation of g_strerror(), you can see
> that glib returns allocated memory here (with g_strdup() for example).
> So if we don't free, this will leak memory over time.

This is *not* a leak, it is a cache.

It is maintaining a static hash table that caches the mapping from
errno -> string. So many calls all with the same errno value will
return the same cached string. So by free'ing the string you're
causing a use-after-free flaw the next time the same errno is
passed to g_strerror. The memory usage here is finite, bounded
by the number of possible errnos that we see.

> But you're right, the "const" and documentation of the function indicate
> that the caller should rather not free the memory. What a bummer, sounds
> like g_strerror() is pretty much useless unless you immediately exit()
> afterwards (and you care about not leaking memory).
> 
> I guess we have to implement our own wrapper, qemu_strerror() instead?

No, g_strerror is working fine without free'ing the result.

Regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|

Re: [PATCH] Do not use %m in common code to print error messages

[Thomas Huth]

On 18/10/2019 13.37, Daniel P. Berrangé wrote:
> On Fri, Oct 18, 2019 at 01:31:34PM +0200, Thomas Huth wrote:
>> On 18/10/2019 12.57, Daniel P. Berrangé wrote:
>>> On Fri, Oct 18, 2019 at 12:44:38PM +0200, Thomas Huth wrote:
>>>> The %m format specifier is an extension from glibc - and when compiling
>>>> QEMU for NetBSD, the compiler correctly complains, e.g.:
>>>>
>>>> /home/qemu/qemu-test.ELjfrQ/src/util/main-loop.c: In function 'sigfd_handler':
>>>> /home/qemu/qemu-test.ELjfrQ/src/util/main-loop.c:64:13: warning: %m is only
>>>>  allowed in syslog(3) like functions [-Wformat=]
>>>>              printf("read from sigfd returned %zd: %m\n", len);
>>>>              ^
>>>> Let's use g_strerror() here instead, which is an easy-to-use wrapper
>>>> around the thread-safe strerror_r() function.
>>>>
>>>> While we're at it, also convert the "printf()" in main-loop.c into
>>>> the preferred "error_report()".
>>>>
>>>> Signed-off-by: Thomas Huth <thuth@redhat.com>
>>>> ---
>>>>  hw/misc/tmp421.c | 8 ++++++--
>>>>  util/main-loop.c | 4 +++-
>>>>  util/systemd.c   | 5 +++--
>>>>  3 files changed, 12 insertions(+), 5 deletions(-)
>>>>
>>>> diff --git a/hw/misc/tmp421.c b/hw/misc/tmp421.c
>>>> index 9f044705fa..f23c46a40a 100644
>>>> --- a/hw/misc/tmp421.c
>>>> +++ b/hw/misc/tmp421.c
>>>> @@ -120,7 +120,9 @@ static void tmp421_get_temperature(Object *obj, Visitor *v, const char *name,
>>>>      int tempid;
>>>>  
>>>>      if (sscanf(name, "temperature%d", &tempid) != 1) {
>>>> -        error_setg(errp, "error reading %s: %m", name);
>>>> +        const char *errmsg = g_strerror(errno);
>>>> +        error_setg(errp, "error reading %s: %s", name, errmsg);
>>>> +        g_free((gpointer)errmsg);
>>>
>>> Kaboom crash. This is trying to free a const string that is the caller
>>> doesn't own. It remains under ownership of g_strerror forever.
>>
>> Well, if you look at the implementation of g_strerror(), you can see
>> that glib returns allocated memory here (with g_strdup() for example).
>> So if we don't free, this will leak memory over time.
> 
> This is *not* a leak, it is a cache.
> 
> It is maintaining a static hash table that caches the mapping from
> errno -> string. So many calls all with the same errno value will
> return the same cached string. So by free'ing the string you're
> causing a use-after-free flaw the next time the same errno is
> passed to g_strerror. The memory usage here is finite, bounded
> by the number of possible errnos that we see.
> 
>> But you're right, the "const" and documentation of the function indicate
>> that the caller should rather not free the memory. What a bummer, sounds
>> like g_strerror() is pretty much useless unless you immediately exit()
>> afterwards (and you care about not leaking memory).
>>
>> I guess we have to implement our own wrapper, qemu_strerror() instead?
> 
> No, g_strerror is working fine without free'ing the result.

Ah, well, thanks for the explanation, not sure how I could have missed
that when looking at the source code :-/ Time for weekend, I guess...

So g_strerror should be fine, and I'll respin the patch without g_free.

 Thomas

Re: [PATCH] Do not use %m in common code to print error messages

[no-reply]

Patchew URL: https://patchew.org/QEMU/20191018104438.6158-1-thuth@redhat.com/



Hi,

This series failed the docker-quick@centos7 build test. Please find the testing commands and
their output below. If you have Docker installed, you can probably reproduce it
locally.

=== TEST SCRIPT BEGIN ===
#!/bin/bash
make docker-image-centos7 V=1 NETWORK=1
time make docker-test-quick@centos7 SHOW_ENV=1 J=14 NETWORK=1
=== TEST SCRIPT END ===

  CC      hw/misc/imx6_ccm.o
  CC      hw/misc/imx6ul_ccm.o
/tmp/qemu-test/src/hw/misc/tmp421.c: In function 'tmp421_set_temperature':
/tmp/qemu-test/src/hw/misc/tmp421.c:166:9: error: format '%s' expects a matching 'char *' argument [-Werror=format=]
         error_setg(errp, "error reading %s: %s", errmsg);
         ^
cc1: all warnings being treated as errors
  CC      hw/misc/imx7_ccm.o
  CC      hw/misc/imx2_wdt.o
make: *** [hw/misc/tmp421.o] Error 1
make: *** Waiting for unfinished jobs....
Traceback (most recent call last):
  File "./tests/docker/docker.py", line 662, in <module>
---
    raise CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command '['sudo', '-n', 'docker', 'run', '--label', 'com.qemu.instance.uuid=eae0544322904584b30d3ce7bcb77a82', '-u', '1001', '--security-opt', 'seccomp=unconfined', '--rm', '-e', 'TARGET_LIST=', '-e', 'EXTRA_CONFIGURE_OPTS=', '-e', 'V=', '-e', 'J=14', '-e', 'DEBUG=', '-e', 'SHOW_ENV=1', '-e', 'CCACHE_DIR=/var/tmp/ccache', '-v', '/home/patchew/.cache/qemu-docker-ccache:/var/tmp/ccache:z', '-v', '/var/tmp/patchew-tester-tmp-786nsriq/src/docker-src.2019-10-18-19.26.59.10681:/var/tmp/qemu:z,ro', 'qemu:centos7', '/var/tmp/qemu/run', 'test-quick']' returned non-zero exit status 2.
filter=--filter=label=com.qemu.instance.uuid=eae0544322904584b30d3ce7bcb77a82
make[1]: *** [docker-run] Error 1
make[1]: Leaving directory `/var/tmp/patchew-tester-tmp-786nsriq/src'
make: *** [docker-run-test-quick@centos7] Error 2

real    2m5.578s
user    0m7.522s


The full log is available at
http://patchew.org/logs/20191018104438.6158-1-thuth@redhat.com/testing.docker-quick@centos7/?type=message.
---
Email generated automatically by Patchew [https://patchew.org/].
Please send your feedback to patchew-devel@redhat.com

Re: [PATCH] Do not use %m in common code to print error messages

[no-reply]

Patchew URL: https://patchew.org/QEMU/20191018104438.6158-1-thuth@redhat.com/



Hi,

This series failed the docker-mingw@fedora build test. Please find the testing commands and
their output below. If you have Docker installed, you can probably reproduce it
locally.

=== TEST SCRIPT BEGIN ===
#! /bin/bash
export ARCH=x86_64
make docker-image-fedora V=1 NETWORK=1
time make docker-test-mingw@fedora J=14 NETWORK=1
=== TEST SCRIPT END ===

  CC      hw/ssi/pl022.o
In file included from /tmp/qemu-test/src/hw/misc/tmp421.c:30:
/tmp/qemu-test/src/hw/misc/tmp421.c: In function 'tmp421_set_temperature':
/tmp/qemu-test/src/include/qapi/error.h:166:25: error: format '%s' expects a matching 'char *' argument [-Werror=format=]
                         (fmt), ## __VA_ARGS__)
                         ^~~~~
/tmp/qemu-test/src/hw/misc/tmp421.c:166:9: note: in expansion of macro 'error_setg'
         error_setg(errp, "error reading %s: %s", errmsg);
         ^~~~~~~~~~
cc1: all warnings being treated as errors
make: *** [/tmp/qemu-test/src/rules.mak:69: hw/misc/tmp421.o] Error 1
make: *** Waiting for unfinished jobs....
Traceback (most recent call last):
  File "./tests/docker/docker.py", line 662, in <module>
---
    raise CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command '['sudo', '-n', 'docker', 'run', '--label', 'com.qemu.instance.uuid=aeeffa7799634227ba70e98b4d08d799', '-u', '1003', '--security-opt', 'seccomp=unconfined', '--rm', '-e', 'TARGET_LIST=', '-e', 'EXTRA_CONFIGURE_OPTS=', '-e', 'V=', '-e', 'J=14', '-e', 'DEBUG=', '-e', 'SHOW_ENV=', '-e', 'CCACHE_DIR=/var/tmp/ccache', '-v', '/home/patchew2/.cache/qemu-docker-ccache:/var/tmp/ccache:z', '-v', '/var/tmp/patchew-tester-tmp-4zudpx4q/src/docker-src.2019-10-18-19.29.53.18800:/var/tmp/qemu:z,ro', 'qemu:fedora', '/var/tmp/qemu/run', 'test-mingw']' returned non-zero exit status 2.
filter=--filter=label=com.qemu.instance.uuid=aeeffa7799634227ba70e98b4d08d799
make[1]: *** [docker-run] Error 1
make[1]: Leaving directory `/var/tmp/patchew-tester-tmp-4zudpx4q/src'
make: *** [docker-run-test-mingw@fedora] Error 2

real    2m1.697s
user    0m7.284s


The full log is available at
http://patchew.org/logs/20191018104438.6158-1-thuth@redhat.com/testing.docker-mingw@fedora/?type=message.
---
Email generated automatically by Patchew [https://patchew.org/].
Please send your feedback to patchew-devel@redhat.com