If you change run-assert-msg-test.sh to print "$OUT" in the fail message on line 45, what gets printed?

(In reply to Philip Withnall from comment #1)
> If you change run-assert-msg-test.sh to print "$OUT" in the fail message on
> line 45, what gets printed?

I've made the change you told me to make, but the output in test-suite.log is exactly the same as before. If it helps, below is the terminal output (which I didn't save from last time, but I don't think it's very different, either).

FAIL: run-assert-msg-test.sh
============================================================================
Testsuite summary for glib 2.52.1
============================================================================
# TOTAL: 28
# PASS:  27
# SKIP:  0
# XFAIL: 0
# FAIL:  1
# XPASS: 0
# ERROR: 0
============================================================================
See tests/test-suite.log
Please report to http://bugzilla.gnome.org/enter_bug.cgi?product=glib
============================================================================
make[6]: *** [Makefile:1752: test-suite.log] Error 1
make[6]: Leaving directory '/home/tirifto/Downloads/glib2/src/glib/tests'
make[5]: *** [Makefile:1860: check-TESTS] Error 2
make[5]: Leaving directory '/home/tirifto/Downloads/glib2/src/glib/tests'
make[4]: *** [Makefile:2176: check-am] Error 2
make[4]: Leaving directory '/home/tirifto/Downloads/glib2/src/glib/tests'
make[3]: *** [Makefile:1644: check-recursive] Error 1
make[3]: Leaving directory '/home/tirifto/Downloads/glib2/src/glib/tests'
make[2]: *** [Makefile:2179: check] Error 2
make[2]: Leaving directory '/home/tirifto/Downloads/glib2/src/glib/tests'
make[1]: *** [Makefile:1239: check-recursive] Error 1
make[1]: Leaving directory '/home/tirifto/Downloads/glib2/src/glib'
make: *** [Makefile:1696: check] Error 2
==> ERROR: A failure occurred in check().
    Aborting...

(In reply to tirifto from comment #2)
> (In reply to Philip Withnall from comment #1)
> > If you change run-assert-msg-test.sh to print "$OUT" in the fail message on
> > line 45, what gets printed?
> 
> I've made the change you told me to make, but the output in test-suite.log
> is exactly the same as before.

That doesn’t make any sense. Are you sure the test which you modified is being executed, and the Arch build process isn’t running a copy from somewhere else?

I'm trying to make a debug build of glib for this bug: https://bugzilla.gnome.org/show_bug.cgi?id=784771#c7, but I'm encountering this issue. First of all, the reason why the reporter's output wasn't changing is that, when running makepkg again after making the change, the shell script is just overwritten by the original, so you have to apply the changes while it's building. Here's what I got for $OUT (It seems to be a stack trace so I'm just going to paste it directly instead of attatching the log file.):

[Thread debugging using libthread_db enabled]
Using host libthread_db library "/usr/lib/libthread_db.so.1".

Program received signal SIGABRT, Aborted.
0x00007fc0fd5d88c0 in raise () from /usr/lib/libc.so.6
$1 = 0x202e60 <error: Cannot access memory at address 0x202e60>
A debugging session is active.

	Inferior 1 [process 27449] will be killed.

Quit anyway? (y or n) [answered Y; input not from terminal]

What compilation options are being used on Arch? For example, is G_DISABLE_ASSERT defined?

It looks like __glib_assert_msg is not being set correctly by g_assert(), or is being overwritten somehow.

Could you change tests/assert-msg-test.gdb to the following and reproduce please? Print $OUT again and paste it here, as the output from the modified .gdb file will be there:

set pagination off
watch __glib_assert_msg
commands
print (char*) __glib_assert_msg
bt
cont
end
run
set print elements 0
print (char*) __glib_assert_msg
quit

>What compilation options are being used on Arch? For example, is G_DISABLE_ASSERT defined?

G_DISABLE_ASSERT doesn't seem to be defined. The full list of options used to configure it should be here: https://git.archlinux.org/svntogit/packages.git/tree/trunk/PKGBUILD?h=packages/glib2#n41.

>Could you change tests/assert-msg-test.gdb to the following and reproduce please? Print $OUT again and paste it here, as the output from the modified .gdb file will be there:

I've edited the script and GDB file, but $OUT seems to be empty:
=======================================
   glib 2.52.3: tests/test-suite.log
=======================================

# TOTAL: 28
# PASS:  27
# SKIP:  0
# XFAIL: 0
# FAIL:  1
# XPASS: 0
# ERROR: 0

.. contents:: :depth: 2

FAIL: run-assert-msg-test.sh
============================

OUT: 
Test failed: __glib_assert_msg does not have assertion message
FAIL run-assert-msg-test.sh (exit status: 1)

And here's the relevant part of run-assert-msg-test.sh:

if ! echo "$OUT" | grep -q '^$1.*"GLib:ERROR:.*assert-msg-test.c:.*:.*main.*: assertion failed: (42 < 0)"'; then
  echo "OUT: " $OUT
  fail "__glib_assert_msg does not have assertion message"
fi

I also tried printing the output before the if like so:

OUT=$($LIBTOOL --mode=execute gdb --batch -x ${srcdir:-.}/assert-msg-test.gdb ./assert-msg-test 2> $error_out) || fail "failed to run gdb"
echo "OUT: " $OUT

This produced the same results.

This bug continues to make very little sense. As well as printing $OUT, could you print ensure $error_out is set to /dev/stderr by hard-coding it (and verbose=1) in run-assert-msg-test.sh?

I think I see what's going on. By default, $error_out is set to /dev/null: https://git.gnome.org/browse/glib/tree/tests/run-assert-msg-test.sh#n16. Unless $verbose is set to 1 (And, in my test, by default it's not.), it stays that way, so when the GDB command is expanded (https://git.gnome.org/browse/glib/tree/tests/run-assert-msg-test.sh#n41), the errors are redirected to /dev/null.

I adjusted the script to simulate verbose conditions (The echo_v function and $LIBTOOL if statement are just included for context, they're not changed.):
echo_v ()
{
  if [ "$verbose" = "1" ]; then
    echo "$*"
  fi
}

verbose=1
error_out=/dev/stderr

if [ -z "$LIBTOOL" ]; then

So, here's the log file with the following changed:
 - The script being changed to default (Without manually printing $OUT.)
 - The modified GDB file.
=======================================
   glib 2.52.3: tests/test-suite.log
=======================================

# TOTAL: 28
# PASS:  27
# SKIP:  0
# XFAIL: 0
# FAIL:  1
# XPASS: 0
# ERROR: 0

.. contents:: :depth: 2

FAIL: run-assert-msg-test.sh
============================

./assert-msg-test.gdb:2: Error in sourced command file:Checking if assert message is in __glib_assert_msg
Test failed: __glib_assert_msg does not have assertion message
FAIL run-assert-msg-test.sh (exit status: 1)

Repeating the process with the normal GDB file yeilds the same results.

Ah, interesting. So if you use the original GDB file, but remove the `set print elements 0` line, what happens?

If you run `set print elements 0` in a standalone GDB session, what happens?

>Ah, interesting. So if you use the original GDB file, but remove the `set print elements 0` line, what happens?

Here's the log:

=======================================
   glib 2.52.3: tests/test-suite.log
=======================================

# TOTAL: 28
# PASS:  27
# SKIP:  0
# XFAIL: 0
# FAIL:  1
# XPASS: 0
# ERROR: 0

.. contents:: :depth: 2

FAIL: run-assert-msg-test.sh
============================

**
GLib:ERROR:assert-msg-test.c:5:main: assertion faileChecking if assert message is in __glib_assert_msg
Test failed: __glib_assert_msg does not have assertion message
FAIL run-assert-msg-test.sh (exit status: 1)


Really weird how the error message is seemingly being corrupted/overwritten.

>If you run `set print elements 0` in a standalone GDB session, what happens?

Unless there are commands I'm supposed to run before/after this, it doesn't seem like anything happens:

(gdb) set print elements 0
(gdb)

(In reply to thekoopakingdom from comment #10)
> >Ah, interesting. So if you use the original GDB file, but remove the `set print elements 0` line, what happens?
> 
> Here's the log:
> 
> =======================================
>    glib 2.52.3: tests/test-suite.log
> =======================================
> 
> # TOTAL: 28
> # PASS:  27
> # SKIP:  0
> # XFAIL: 0
> # FAIL:  1
> # XPASS: 0
> # ERROR: 0
> 
> .. contents:: :depth: 2
> 
> FAIL: run-assert-msg-test.sh
> ============================
> 
> **
> GLib:ERROR:assert-msg-test.c:5:main: assertion faileChecking if assert
> message is in __glib_assert_msg
> Test failed: __glib_assert_msg does not have assertion message
> FAIL run-assert-msg-test.sh (exit status: 1)
> 
> 
> Really weird how the error message is seemingly being corrupted/overwritten.

A bit weird, although that’s the error message which is printed to the terminal by g_assert(), rather than the one stored to __glib_assert_msg which is the one we care about for this test. So that’s a bit of a red herring.

> >If you run `set print elements 0` in a standalone GDB session, what happens?
> 
> Unless there are commands I'm supposed to run before/after this, it doesn't
> seem like anything happens:
> 
> (gdb) set print elements 0
> (gdb)

That’s fine. I was wondering if gdb was erroring on that command.

---

Have you tried this with GLib 2.54.0? There have been a few changes to the logging code since 2.52.3 which might be affecting this. In particular, I wonder if commit 15faf0ef fixes a crash which you might be silently getting.

As well as trying with the latest GLib version, you could also try adding `t a a bt full` to the .gdb file (after `run`) to see if that produces any output in $OuT.

>Have you tried this with GLib 2.54.0? There have been a few changes to the logging code since 2.52.3 which might be affecting this. In particular, I wonder if commit 15faf0ef fixes a crash which you might be silently getting.

Yep, GLib compiles fine on 15faf0ef and passes all of the unit tests.

(In reply to thekoopakingdom from comment #12)
> >Have you tried this with GLib 2.54.0? There have been a few changes to the logging code since 2.52.3 which might be affecting this. In particular, I wonder if commit 15faf0ef fixes a crash which you might be silently getting.
> 
> Yep, GLib compiles fine on 15faf0ef and passes all of the unit tests.

RESOLVED OBSOLETE then. Thanks for your help.

Actually, I just managed to reproduce on an Endless OS system. The problem (for me) seems to be caused by compiling without CFLAGS=-g. When compiled without debug symbols on a 64-bit system, gdb thinks sizeof(__glib_assert_msg)==4, and chops off the most-significant 4 bytes, which obviously means it can’t print out the assertion message.

I think this is a bug in gdb (since the symbol size for __glib_assert_msg is available in the symbol table for GLib even when compiling without -g), but in the meantime, I guess we should skip this part of the test if debug symbols aren’t available.

I’ve filed https://sourceware.org/bugzilla/show_bug.cgi?id=22501 about the gdb bug. It seems we can work around the problem here by referencing and dereferencing __glib_assert_msg in the gdb script. Patch coming.

Created attachment 364492 [details] [review]
tests: Work around a gdb bug in assert-msg-test

It seems that when GLib is compiled without CFLAGS=-g, gdb can’t work
out the size of __glib_assert_msg, so assumes it’s 4 bytes — even on
64-bit systems. This causes it to not read the most significant 4 bytes
of the assertion message pointer, and hence it can’t print the stored
assertion message. This causes assert-msg-test to fail.

The upstream gdb bug is
https://sourceware.org/bugzilla/show_bug.cgi?id=22501.

Work around that by referencing and dereferencing __glib_assert_msg so
that gdb treats it as a pointer of sizeof(char*) rather than of the size
it incorrectly calculated from the library’s symbol table (or through
some other mystical process).

Signed-off-by: Philip Withnall <withnall@endlessm.com>

Review of attachment 364492 [details] [review]:

:thumbsup:

Attachment 364492 [details] pushed as 82adf7b - tests: Work around a gdb bug in assert-msg-test