[Qemu-devel] [PATCH] glib-compat: work around g_test_message bug with subprocess tests

[Qemu-devel] [PATCH] glib-compat: work around g_test_message bug with subprocess tests

[Paolo Bonzini]

Subprocesses are created by glib without leaving the file descriptors
open.  Therefore, g_test_message (and assertion failures, but those
trigger when things are going bad anyway) will think that it is writing
to the log file descriptor, but while actually stomping on the QMP
file descriptor or similar.  This causes spurious failures, which are
as nice to debug as the reader can imagine.  While I have opened a
pull request on GLib, this will probably take a while to propagate
to distros.

I found this while working on qgraph, but the fix is generic.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
---
 include/glib-compat.h | 6 ++++++
 1 file changed, 6 insertions(+)

diff --git a/include/glib-compat.h b/include/glib-compat.h
index fdf95a2..989b9ef 100644
--- a/include/glib-compat.h
+++ b/include/glib-compat.h
@@ -113,4 +113,10 @@ gint g_poll_fixed(GPollFD *fds, guint nfds, gint timeout);
 
 #pragma GCC diagnostic pop
 
+/* See https://gitlab.gnome.org/GNOME/glib/merge_requests/501 */
+#define g_test_message(...)							\
+	do {									\
+		if (!g_test_subprocess()) g_test_message(__VA_ARGS__);		\
+	} while (0)
+
 #endif
-- 
1.8.3.1

Re: [Qemu-devel] [PATCH] glib-compat: work around g_test_message bug with subprocess tests

[Eric Blake]

On 11/27/18 12:35 PM, Paolo Bonzini wrote:
> Subprocesses are created by glib without leaving the file descriptors
> open.  Therefore, g_test_message (and assertion failures, but those
> trigger when things are going bad anyway) will think that it is writing
> to the log file descriptor, but while actually stomping on the QMP
> file descriptor or similar.  This causes spurious failures, which are
> as nice to debug as the reader can imagine.  While I have opened a
> pull request on GLib, this will probably take a while to propagate
> to distros.
> 
> I found this while working on qgraph, but the fix is generic.
> 
> Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
> ---
>   include/glib-compat.h | 6 ++++++
>   1 file changed, 6 insertions(+)

Wow. I don't envy the debug session that you went through to finally 
realize this problem.

Reviewed-by: Eric Blake <eblake@redhat.com>

I think this is safe for 3.1-rc3 if you want it there, as minimizing 
spurious test failures is a good thing.

> diff --git a/include/glib-compat.h b/include/glib-compat.h
> index fdf95a2..989b9ef 100644
> --- a/include/glib-compat.h
> +++ b/include/glib-compat.h
> @@ -113,4 +113,10 @@ gint g_poll_fixed(GPollFD *fds, guint nfds, gint timeout);
>   
>   #pragma GCC diagnostic pop
>   
> +/* See https://gitlab.gnome.org/GNOME/glib/merge_requests/501 */
> +#define g_test_message(...)							\
> +	do {									\
> +		if (!g_test_subprocess()) g_test_message(__VA_ARGS__);		\

I'm surprised checkpatch.pl doesn't complain about missing {} in this 
macro expansion, but doing it right would mean 2 more lines, so I'm fine 
overlooking the style.

-- 
Eric Blake, Principal Software Engineer
Red Hat, Inc.           +1-919-301-3266
Virtualization:  qemu.org | libvirt.org

Re: [Qemu-devel] [PATCH] glib-compat: work around g_test_message bug with subprocess tests

[Marc-André Lureau]

On Tue, Nov 27, 2018 at 10:35 PM Paolo Bonzini <pbonzini@redhat.com> wrote:
>
> Subprocesses are created by glib without leaving the file descriptors
> open.  Therefore, g_test_message (and assertion failures, but those
> trigger when things are going bad anyway) will think that it is writing
> to the log file descriptor, but while actually stomping on the QMP
> file descriptor or similar.  This causes spurious failures, which are
> as nice to debug as the reader can imagine.  While I have opened a
> pull request on GLib, this will probably take a while to propagate
> to distros.
>
> I found this while working on qgraph, but the fix is generic.
>
> Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>

good catch! makes me wonder if g_test_message() is supposed to be
usable in a subprocess.. Let see the review comments on upstream bug.
At least, documentation should be updated.

Reviewed-by: Marc-André Lureau <marcandre.lureau@redhat.com>

> ---
>  include/glib-compat.h | 6 ++++++
>  1 file changed, 6 insertions(+)
>
> diff --git a/include/glib-compat.h b/include/glib-compat.h
> index fdf95a2..989b9ef 100644
> --- a/include/glib-compat.h
> +++ b/include/glib-compat.h
> @@ -113,4 +113,10 @@ gint g_poll_fixed(GPollFD *fds, guint nfds, gint timeout);
>
>  #pragma GCC diagnostic pop
>
> +/* See https://gitlab.gnome.org/GNOME/glib/merge_requests/501 */
> +#define g_test_message(...)                                                    \
> +       do {                                                                    \
> +               if (!g_test_subprocess()) g_test_message(__VA_ARGS__);          \
> +       } while (0)
> +
>  #endif
> --
> 1.8.3.1
>

Re: [Qemu-devel] [PATCH] glib-compat: work around g_test_message bug with subprocess tests

[Paolo Bonzini]

On 27/11/18 19:49, Marc-André Lureau wrote:
> good catch! makes me wonder if g_test_message() is supposed to be
> usable in a subprocess.. Let see the review comments on upstream bug.
> At least, documentation should be updated.
> 
> Reviewed-by: Marc-André Lureau <marcandre.lureau@redhat.com>

Considering that GLib goes to great lengths to pass the test log fd as
--GTestFD, it definitely should.  So the alternative is not that that
documentation should be updated, the test log file descriptor should not
be passed.

Paolo

Re: [Qemu-devel] [PATCH] glib-compat: work around g_test_message bug with subprocess tests

[Paolo Bonzini]

On 27/11/18 19:44, Eric Blake wrote:
> On 11/27/18 12:35 PM, Paolo Bonzini wrote:
>> Subprocesses are created by glib without leaving the file descriptors
>> open.  Therefore, g_test_message (and assertion failures, but those
>> trigger when things are going bad anyway) will think that it is writing
>> to the log file descriptor, but while actually stomping on the QMP
>> file descriptor or similar.  This causes spurious failures, which are
>> as nice to debug as the reader can imagine.  While I have opened a
>> pull request on GLib, this will probably take a while to propagate
>> to distros.
>>
>> I found this while working on qgraph, but the fix is generic.
>>
>> Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
>> ---
>>   include/glib-compat.h | 6 ++++++
>>   1 file changed, 6 insertions(+)
> 
> Wow. I don't envy the debug session that you went through to finally
> realize this problem.

It only took me 4 hours actually, but not really the fun kind of
debugging. :(  Lots of cursing when I found the culprit...

> Reviewed-by: Eric Blake <eblake@redhat.com>
> 
> I think this is safe for 3.1-rc3 if you want it there, as minimizing
> spurious test failures is a good thing.

I suspect it is the cause of QTEST_VHOST_USER_FIXME but I am not sure it
is.  In any case, I was not planning to merge it in 3.1-rc3 since we do
not have any case where it breaks CI or maintainers' tests.

Paolo

Re: [Qemu-devel] [PATCH] glib-compat: work around g_test_message bug with subprocess tests

[no-reply]

Hi,

This series seems to have some coding style problems. See output below for
more information:

Type: series
Subject: [Qemu-devel] [PATCH] glib-compat: work around g_test_message bug with subprocess tests
Message-id: 1543343726-53531-1-git-send-email-pbonzini@redhat.com

=== TEST SCRIPT BEGIN ===
#!/bin/bash

BASE=base
n=1
total=$(git log --oneline $BASE.. | wc -l)
failed=0

git config --local diff.renamelimit 0
git config --local diff.renames True
git config --local diff.algorithm histogram

commits="$(git log --format=%H --reverse $BASE..)"
for c in $commits; do
    echo "Checking PATCH $n/$total: $(git log -n 1 --format=%s $c)..."
    if ! git show $c --format=email | ./scripts/checkpatch.pl --mailback -; then
        failed=1
        echo
    fi
    n=$((n+1))
done

exit $failed
=== TEST SCRIPT END ===

Updating 3c8cf5a9c21ff8782164d1def7f44bd888713384
Switched to a new branch 'test'
062e659 glib-compat: work around g_test_message bug with subprocess tests

=== OUTPUT BEGIN ===
Checking PATCH 1/1: glib-compat: work around g_test_message bug with subprocess tests...
WARNING: line over 80 characters
#30: FILE: include/glib-compat.h:117:
+#define g_test_message(...)							\

ERROR: code indent should never use tabs
#30: FILE: include/glib-compat.h:117:
+#define g_test_message(...)^I^I^I^I^I^I^I\$

WARNING: line over 80 characters
#31: FILE: include/glib-compat.h:118:
+	do {									\

ERROR: code indent should never use tabs
#31: FILE: include/glib-compat.h:118:
+^Ido {^I^I^I^I^I^I^I^I^I\$

WARNING: line over 80 characters
#32: FILE: include/glib-compat.h:119:
+		if (!g_test_subprocess()) g_test_message(__VA_ARGS__);		\

ERROR: code indent should never use tabs
#32: FILE: include/glib-compat.h:119:
+^I^Iif (!g_test_subprocess()) g_test_message(__VA_ARGS__);^I^I\$

ERROR: trailing statements should be on next line
#32: FILE: include/glib-compat.h:119:
+		if (!g_test_subprocess()) g_test_message(__VA_ARGS__);		\

ERROR: braces {} are necessary for all arms of this statement
#32: FILE: include/glib-compat.h:119:
+		if (!g_test_subprocess()) g_test_message(__VA_ARGS__);		\
[...]

ERROR: code indent should never use tabs
#33: FILE: include/glib-compat.h:120:
+^I} while (0)$

total: 6 errors, 3 warnings, 10 lines checked

Your patch has style problems, please review.  If any of these errors
are false positives report them to the maintainer, see
CHECKPATCH in MAINTAINERS.

=== OUTPUT END ===

Test command exited with code: 1


---
Email generated automatically by Patchew [http://patchew.org/].
Please send your feedback to patchew-devel@redhat.com

Re: [Qemu-devel] [Qemu-devel for-3.1?] [PATCH] glib-compat: work around g_test_message bug with subprocess tests

[Eric Blake]

On 11/27/18 12:44 PM, Eric Blake wrote:
> On 11/27/18 12:35 PM, Paolo Bonzini wrote:
>> Subprocesses are created by glib without leaving the file descriptors
>> open.  Therefore, g_test_message (and assertion failures, but those
>> trigger when things are going bad anyway) will think that it is writing
>> to the log file descriptor, but while actually stomping on the QMP
>> file descriptor or similar.  This causes spurious failures, which are
>> as nice to debug as the reader can imagine.  While I have opened a
>> pull request on GLib, this will probably take a while to propagate
>> to distros.
>>
>> I found this while working on qgraph, but the fix is generic.
>>
>> Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
>> ---
>>   include/glib-compat.h | 6 ++++++
>>   1 file changed, 6 insertions(+)
> 
> Wow. I don't envy the debug session that you went through to finally 
> realize this problem.
> 
> Reviewed-by: Eric Blake <eblake@redhat.com>
> 
> I think this is safe for 3.1-rc3 if you want it there, as minimizing 
> spurious test failures is a good thing.

Whoops - we missed -rc3. By itself, this is not worth -rc4, but is still 
a possible candidate if more serious stuff requires a release delay.	

> 
>> diff --git a/include/glib-compat.h b/include/glib-compat.h
>> index fdf95a2..989b9ef 100644
>> --- a/include/glib-compat.h
>> +++ b/include/glib-compat.h
>> @@ -113,4 +113,10 @@ gint g_poll_fixed(GPollFD *fds, guint nfds, gint 
>> timeout);
>>   #pragma GCC diagnostic pop
>> +/* See https://gitlab.gnome.org/GNOME/glib/merge_requests/501 */
>> +#define g_test_message(...)                            \
>> +    do {                                    \
>> +        if (!g_test_subprocess()) g_test_message(__VA_ARGS__);        \
> 
> I'm surprised checkpatch.pl doesn't complain about missing {} in this 
> macro expansion, but doing it right would mean 2 more lines, so I'm fine 
> overlooking the style.

Aha - checkpatch eventually DID flag it, as well as your use of TAB 
characters, but patchew has enough lag that it took a few hours.

-- 
Eric Blake, Principal Software Engineer
Red Hat, Inc.           +1-919-301-3266
Virtualization:  qemu.org | libvirt.org