Bug#1020321: Acknowledgement (glib2.0: FTBFS on hppa - test simple-construction1 fails)

John David Anglin dave.anglin at bell.net
Tue Aug 15 13:45:36 BST 2023


The issue is with the test.

136/366 glib:gobject+performance+no-valgrind / performance                     RUNNING
 >>> MALLOC_CHECK_=2 MALLOC_PERTURB_=153 G_TEST_SRCDIR=/<<PKGBUILDDIR>>/gobject/tests/performance G_ENABLE_DIAGNOSTIC=1 G_DEBUG=gc-friendly 
G_TEST_BUILDDIR=/<<PKGBUILDDIR>>/debian/build/deb/gobject/tests/performance 
LD_LIBRARY_PATH=/<<PKGBUILDDIR>>/debian/build/deb/glib:/<<PKGBUILDDIR>>/debian/build/deb/gobject 
/<<PKGBUILDDIR>>/debian/build/deb/gobject/tests/performance/performance --seconds 0
――――――――――――――――――――――――――――――――――――― ✀ ―――――――――――――――――――――――――――――――――――――
Running test simple-construction
Millions of constructed objects per second: 0.312
Running test simple-construction1

(performance:4588): GLib-ERROR **: 15:54:55.415: ../../../glib/gmem.c:470: overflow allocating 2147483647*4 bytes
――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――――
136/366 glib:gobject+performance+no-valgrind / performance                     FAIL              7.49s   killed by signal 5 SIGTRAP

Debugging this, I see this is caused by a timer issue:

   /* Estimate time for one run by doing a few test rounds */
   min_elapsed = 0;
   for (i = 0; i < ESTIMATE_ROUND_TIME_N_RUNS; i++)
     {
       test->init (test, data, 1.0);
       g_timer_start (timer);
       test->run (test, data);
       g_timer_stop (timer);
       test->finish (test, data);

       elapsed = g_timer_elapsed (timer, NULL);
       if (i == 0)
         min_elapsed = elapsed;
       else
         min_elapsed = MIN (min_elapsed, elapsed);
     }

   factor = TARGET_ROUND_TIME / min_elapsed;

g_timer_elapsed() uses g_get_monotonic_time():

gint64
g_get_monotonic_time (void)
{
   struct timespec ts;
   gint result;

   result = clock_gettime (CLOCK_MONOTONIC, &ts);

   if G_UNLIKELY (result != 0)
     g_error ("GLib requires working CLOCK_MONOTONIC");

   return (((gint64) ts.tv_sec) * 1000000) + (ts.tv_nsec / 1000);
}

The tick resolution of CLOCK_MONOTONIC is poor on SMP machines and it is determined by CONFIG_HZ.
CONFIG_HZ= 100 on the machines where this occurs. The error does not occur on UP machines where
CLOCK_MONOTONIC has the full accuracy of the CPU hardware timer.

The problem is g_timer_elapsed() returns zero in the first call in simple-construction1. The test does not check
for zero returns. min_elapsed is set to zero and factor to inf. This factor value causes the allocation overflow.

Here is strace output for test:
write(1, "Running test simple-construction"..., 34Running test simple-construction1
) = 34
clock_gettime64(CLOCK_MONOTONIC, {tv_sec=431547, tv_nsec=711943581}) = 0
clock_gettime64(CLOCK_MONOTONIC, {tv_sec=431547, tv_nsec=711943581}) = 0
brk(0x68000)                            = 0x68000
clock_gettime64(CLOCK_MONOTONIC, {tv_sec=431547, tv_nsec=941941637}) = 0
clock_gettime64(CLOCK_MONOTONIC, {tv_sec=431547, tv_nsec=941941637}) = 0
clock_gettime64(CLOCK_MONOTONIC, {tv_sec=431547, tv_nsec=941941637}) = 0
clock_gettime64(CLOCK_MONOTONIC, {tv_sec=431547, tv_nsec=951941553}) = 0
clock_gettime64(CLOCK_MONOTONIC, {tv_sec=431547, tv_nsec=951941553}) = 0
clock_gettime64(CLOCK_MONOTONIC, {tv_sec=431547, tv_nsec=951941553}) = 0
clock_gettime64(CLOCK_MONOTONIC, {tv_sec=431547, tv_nsec=951941553}) = 0
clock_gettime64(CLOCK_MONOTONIC, {tv_sec=431547, tv_nsec=961941468}) = 0
clock_gettime64(CLOCK_MONOTONIC, {tv_sec=431547, tv_nsec=961941468}) = 0
clock_gettime64(CLOCK_MONOTONIC, {tv_sec=431547, tv_nsec=961941468}) = 0
clock_gettime64(CLOCK_MONOTONIC, {tv_sec=431547, tv_nsec=961941468}) = 0
getpeername(2, 0xf91ac888, [128])       = -1 ENOTSOCK (Socket operation on non-socket)
futex_time64(0xf773de68, FUTEX_WAKE_PRIVATE, 2147483647) = 0
ioctl(2, TCGETS, {c_iflag=ICRNL|IXON|IMAXBEL, c_oflag=NL0|CR0|TAB0|BS0|VT0|FF0|OPOST|ONLCR, c_cflag=B38400|CS8|CREAD, 
c_lflag=ISIG|ICANON|ECHO|ECHOE|ECHOK|IEXTEN|ECHOCTL|ECHOKE, ...}) = 0
getpid()                                = 17069
clock_gettime64(CLOCK_REALTIME, {tv_sec=1692049088, tv_nsec=309288398}) = 0
openat(AT_FDCWD, "/etc/localtime", O_RDONLY|O_CLOEXEC) = 3
statx(3, "", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT|AT_EMPTY_PATH, STATX_BASIC_STATS, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0, 
stx_mode=S_IFREG|0644, stx_size=114, ...}) = 0
statx(3, "", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT|AT_EMPTY_PATH, STATX_BASIC_STATS, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0, 
stx_mode=S_IFREG|0644, stx_size=114, ...}) = 0
read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 114
_llseek(3, -60, [54], SEEK_CUR)         = 0
read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 60
close(3)                                = 0
brk(0x51000)                            = 0x51000
write(2, "\n(performance:17069): GLib-\33[1;3"..., 128
(performance:17069): GLib-ERROR **: 21:38:08.309: ../../../glib/gmem.c:470: overflow allocating 2147483647*) = 128
write(2, "4 bytes\n", 84 bytes
)                = 8
gettid()                                = 17069
getpid()                                = 17069
tgkill(17069, 17069, SIGTRAP)           = 0
--- SIGTRAP {si_signo=SIGTRAP, si_code=SI_TKILL, si_pid=17069, si_uid=1000} ---
+++ killed by SIGTRAP (core dumped) +++
Trace/breakpoint trap

You can see that multiple calls to clock_gettime64() return the same result.

The attached change will fix the test but probably isn't ideal.

Regards,
Dave Anglin

-- 
John David Anglin  dave.anglin at bell.net
-------------- next part --------------
--- ./gobject/tests/performance/performance.c.save	2023-08-14 21:59:41.728405583 +0000
+++ ./gobject/tests/performance/performance.c	2023-08-14 22:02:53.026806919 +0000
@@ -114,7 +114,10 @@
 	min_elapsed = MIN (min_elapsed, elapsed);
     }
 
-  factor = TARGET_ROUND_TIME / min_elapsed;
+  if (min_elapsed != 0.0)
+    factor = TARGET_ROUND_TIME / min_elapsed;
+  else
+    factor = 1.0;
 
   if (verbose)
     g_print ("Uncorrected round time: %.4f msecs, correction factor %.2f\n", 1000*min_elapsed, factor);


More information about the pkg-gnome-maintainers mailing list