buytenh/ivykis

0.43 make check fails on i686

Closed this issue · 18 comments

czanik commented

While trying to update the ivykis package on Fedora from 0.42.4 to 0.43 I ran into a problem. make check runs fine on all Fedora platforms for ivykis 0.42.4. However, for 0.43 it fails on i686:

+ make check
Making check in src
make[1]: Entering directory '/builddir/build/BUILD/ivykis-0.43/src'
make[1]: Nothing to be done for 'check'.
make[1]: Leaving directory '/builddir/build/BUILD/ivykis-0.43/src'
Making check in test
make[1]: Entering directory '/builddir/build/BUILD/ivykis-0.43/test'
make  check-TESTS
make[2]: Entering directory '/builddir/build/BUILD/ivykis-0.43/test'
make[3]: Entering directory '/builddir/build/BUILD/ivykis-0.43/test'
PASS: avl
PASS: event_unregister_bug
../test-driver: line 112:  8580 Aborted                 (core dumped) "$@" >> "$log_file" 2>&1
FAIL: iv_event_raw_test
PASS: struct_sizes
FAIL: timer
../test-driver: line 112:  8616 Aborted                 (core dumped) "$@" >> "$log_file" 2>&1
../test-driver: line 112:  8634 Aborted                 (core dumped) "$@" >> "$log_file" 2>&1
FAIL: timer_fairness
PASS: timer_fairness_bug
../test-driver: line 112:  8670 Aborted                 (core dumped) "$@" >> "$log_file" 2>&1
FAIL: timer_order
../test-driver: line 112:  8688 Aborted                 (core dumped) "$@" >> "$log_file" 2>&1
FAIL: timer_past
../test-driver: line 112:  8706 Aborted                 (core dumped) "$@" >> "$log_file" 2>&1
FAIL: timer_zero
PASS: iv_signal_test
============================================================================
Testsuite summary for ivykis 0.43
============================================================================
# TOTAL: 11
# PASS:  5
# SKIP:  0
# XFAIL: 0
# FAIL:  6
# XPASS: 0
# ERROR: 0
============================================================================
See test/test-suite.log
Please report to libivykis-discuss@lists.sourceforge.net
============================================================================
make[3]: Leaving directory '/builddir/build/BUILD/ivykis-0.43/test'
make[3]: *** [Makefile:1001: test-suite.log] Error 1
make[2]: *** [Makefile:1109: check-TESTS] Error 2
make[2]: Leaving directory '/builddir/build/BUILD/ivykis-0.43/test'
make[1]: Leaving directory '/builddir/build/BUILD/ivykis-0.43/test'
make[1]: *** [Makefile:1251: check-am] Error 2
make: *** [Makefile:400: check-recursive] Error 1

You can find the full log at: https://kojipkgs.fedoraproject.org//work/tasks/1834/112651834/build.log

Is there a real bug behind these failures, or I should just disable make check on i686?

czanik commented

Also did a local build, so I have ```test/test-suite.log:

======================================
   ivykis 0.43: test/test-suite.log
======================================

# TOTAL: 11
# PASS:  5
# SKIP:  0
# XFAIL: 0
# FAIL:  6
# XPASS: 0
# ERROR: 0

.. contents:: :depth: 2

FAIL: iv_event_raw_test
=======================

FAIL iv_event_raw_test (exit status: 134)

FAIL: timer
===========

FAIL timer (exit status: 134)

FAIL: timer_fairness
====================

FAIL timer_fairness (exit status: 134)

FAIL: timer_order
=================

FAIL timer_order (exit status: 134)

FAIL: timer_past
================

FAIL timer_past (exit status: 134)

FAIL: timer_zero
================

FAIL timer_zero (exit status: 134)

can you run those commands manually? they should print the reason for the abort on stderr but don't seem to be captured by either of those logs.

All I see is:

bash-5.2# ./iv_event_raw_test 
Aborted (core dumped)

And I cannot see a core file.

I added strace to the spec file, here is the output:

bash-5.2# strace ./iv_event_raw_test
execve("./iv_event_raw_test", ["./iv_event_raw_test"], 0xffc682f0 /* 28 vars */) = 0
brk(NULL)                               = 0x5841e000
mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xf7f6b000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_LARGEFILE|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=6761, ...}) = 0
mmap2(NULL, 6761, PROT_READ, MAP_PRIVATE, 3, 0) = 0xf7f69000
close(3)                                = 0
openat(AT_FDCWD, "/lib/libtinfo.so.6", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\0\0\0\0004\0\0\0"..., 512) = 512
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|0755, stx_size=174024, ...}) = 0
mmap2(NULL, 173756, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xf7f3e000
mmap2(0xf7f42000, 77824, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x4000) = 0xf7f42000
mmap2(0xf7f55000, 69632, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x17000) = 0xf7f55000
mmap2(0xf7f66000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x27000) = 0xf7f66000
close(3)                                = 0
openat(AT_FDCWD, "/lib/libc.so.6", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\3\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\0N\2\0004\0\0\0"..., 512) = 512
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|0755, stx_size=2489200, ...}) = 0
mmap2(NULL, 2066236, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xf7d45000
mmap2(0xf7d68000, 1421312, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x23000) = 0xf7d68000
mmap2(0xf7ec3000, 471040, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x17e000) = 0xf7ec3000
mmap2(0xf7f36000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1f1000) = 0xf7f36000
mmap2(0xf7f39000, 18236, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xf7f39000
close(3)                                = 0
set_thread_area({entry_number=-1, base_addr=0xf7f6c900, limit=0x0fffff, seg_32bit=1, contents=0, read_exec_only=0, limit_in_pages=1, seg_not_present=0, useable=1}) = 0 (entry_number=12)
set_tid_address(0xf7f6c968)             = 38280
set_robust_list(0xf7f6c96c, 12)         = 0
rseq(0xf7f6cda0, 0x20, 0, 0x53053053)   = 0
mprotect(0xf7f36000, 8192, PROT_READ)   = 0
mprotect(0xf7f66000, 8192, PROT_READ)   = 0
mprotect(0x566e4000, 8192, PROT_READ)   = 0
mprotect(0xf7fa5000, 8192, PROT_READ)   = 0
ugetrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM_INFINITY}) = 0
munmap(0xf7f69000, 6761)                = 0
openat(AT_FDCWD, "/dev/tty", O_RDWR|O_NONBLOCK|O_LARGEFILE) = 3
close(3)                                = 0
getrandom("\xc9\x97\xd1\x09", 4, GRND_NONBLOCK) = 4
brk(NULL)                               = 0x5841e000
brk(0x5843f000)                         = 0x5843f000
brk(0x58440000)                         = 0x58440000
openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/locale.alias", 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=2998, ...}) = 0
read(3, "# Locale name alias data base.\n#"..., 4096) = 2998
read(3, "", 4096)                       = 0
close(3)                                = 0
openat(AT_FDCWD, "/usr/lib/locale/en_US.UTF-8/LC_IDENTIFICATION", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/en_US.utf8/LC_IDENTIFICATION", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/en_US/LC_IDENTIFICATION", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/en.UTF-8/LC_IDENTIFICATION", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/en.utf8/LC_IDENTIFICATION", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/locale/en/LC_IDENTIFICATION", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
getuid32()                              = 0
getgid32()                              = 0
geteuid32()                             = 0
getegid32()                             = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
rt_sigaction(SIGCHLD, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTART}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGCHLD, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTART}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTART}, 8) = 0
rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGQUIT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGQUIT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTSTP, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTSTP, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTTIN, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTTIN, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTTOU, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTTOU, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
rt_sigaction(SIGQUIT, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
uname({sysname="Linux", nodename="fedora39.localdomain", ...}) = 0
statx(AT_FDCWD, "/builddir/build/BUILD/ivykis-0.43/test", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_BASIC_STATS, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFDIR|0755, stx_size=4096, ...}) = 0
statx(AT_FDCWD, ".", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_BASIC_STATS, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFDIR|0755, stx_size=4096, ...}) = 0
statx(AT_FDCWD, "/builddir", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_BASIC_STATS, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFDIR|0775, stx_size=37, ...}) = 0
statx(AT_FDCWD, "/builddir/build", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_BASIC_STATS, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFDIR|0775, stx_size=106, ...}) = 0
statx(AT_FDCWD, "/builddir/build/BUILD", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_BASIC_STATS, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFDIR|0775, stx_size=54, ...}) = 0
statx(AT_FDCWD, "/builddir/build/BUILD/ivykis-0.43", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_BASIC_STATS, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFDIR|0755, stx_size=4096, ...}) = 0
statx(AT_FDCWD, "/builddir/build/BUILD/ivykis-0.43/test", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_BASIC_STATS, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFDIR|0755, stx_size=4096, ...}) = 0
statx(AT_FDCWD, "/builddir/build/BUILD/ivykis-0.43", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_BASIC_STATS, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFDIR|0755, stx_size=4096, ...}) = 0
getpid()                                = 38280
getppid()                               = 38277
getpid()                                = 38280
getppid()                               = 38277
getpid()                                = 38280
getppid()                               = 38277
getpgrp()                               = 38277
ioctl(2, TIOCGPGRP, [38277])            = 0
rt_sigaction(SIGCHLD, {sa_handler=0x565c69c0, sa_mask=[], sa_flags=SA_RESTART}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTART}, 8) = 0
ugetrlimit(RLIMIT_NPROC, {rlim_cur=11558, rlim_max=11558}) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
openat(AT_FDCWD, "./iv_event_raw_test", O_RDONLY|O_LARGEFILE) = 3
statx(AT_FDCWD, "./iv_event_raw_test", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_BASIC_STATS, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFREG|0755, stx_size=6368, ...}) = 0
ioctl(3, TCGETS, 0xff962de0)            = -1 ENOTTY (Inappropriate ioctl for device)
_llseek(3, 0, [0], SEEK_CUR)            = 0
read(3, "#! /bin/sh\n\n# iv_event_raw_test "..., 80) = 80
_llseek(3, 0, [0], SEEK_SET)            = 0
ugetrlimit(RLIMIT_NOFILE, {rlim_cur=1024, rlim_max=512*1024}) = 0
fcntl64(255, F_GETFD)                   = -1 EBADF (Bad file descriptor)
dup2(3, 255)                            = 255
close(3)                                = 0
fcntl64(255, F_SETFD, FD_CLOEXEC)       = 0
fcntl64(255, F_GETFL)                   = 0x8000 (flags O_RDONLY|O_LARGEFILE)
statx(255, "", 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|0755, stx_size=6368, ...}) = 0
_llseek(255, 0, [0], SEEK_CUR)          = 0
read(255, "#! /bin/sh\n\n# iv_event_raw_test "..., 6368) = 6368
pipe2([3, 4], 0)                        = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
rt_sigprocmask(SIG_BLOCK, [INT TERM CHLD], [], 8) = 0
_llseek(255, -5452, [916], SEEK_CUR)    = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7f6c968) = 38281
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGCHLD, {sa_handler=0x565c69c0, sa_mask=[], sa_flags=SA_RESTART}, {sa_handler=0x565c69c0, sa_mask=[], sa_flags=SA_RESTART}, 8) = 0
close(4)                                = 0
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
read(3, "allexport      \toff\nbraceexpand "..., 4096) = 481
read(3, "verbose        \toff\nvi          "..., 4096) = 60
read(3, "", 4096)                       = 0
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=38281, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG, NULL) = 38281
wait4(-1, 0xff960ab4, WNOHANG, NULL)    = -1 ECHILD (No child processes)
sigreturn({mask=[INT]})                 = 0
close(3)                                = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGINT, {sa_handler=0x565c9e00, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=0x565c9e00, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
read(255, "BIN_SH=xpg4; export BIN_SH # for"..., 6368) = 5452
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
rt_sigprocmask(SIG_BLOCK, [INT TERM CHLD], [], 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [INT TERM CHLD], 8) = 0
rt_sigprocmask(SIG_SETMASK, [INT TERM CHLD], NULL, 8) = 0
_llseek(255, -5235, [1133], SEEK_CUR)   = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7f6c968) = 38283
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=38283, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG, NULL) = 38283
wait4(-1, 0xff9619f4, WNOHANG, NULL)    = -1 ECHILD (No child processes)
sigreturn({mask=[]})                    = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGINT, {sa_handler=0x565c9e00, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=0x565c9e00, sa_mask=[], sa_flags=0}, 8) = 0
ioctl(2, TIOCGWINSZ, {ws_row=60, ws_col=118, ws_xpixel=0, ws_ypixel=0}) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
read(255, "\nrelink_command=\"\"\n\n# This envir"..., 6368) = 5235
pipe2([3, 4], 0)                        = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
rt_sigprocmask(SIG_BLOCK, [INT TERM CHLD], [], 8) = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7f6c968) = 38284
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGCHLD, {sa_handler=0x565c69c0, sa_mask=[], sa_flags=SA_RESTART}, {sa_handler=0x565c69c0, sa_mask=[], sa_flags=SA_RESTART}, 8) = 0
close(4)                                = 0
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=38284, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG, NULL) = 38284
wait4(-1, 0xff960bb4, WNOHANG, NULL)    = -1 ECHILD (No child processes)
sigreturn({mask=[]})                    = 0
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
read(3, ".\n", 4096)                    = 2
read(3, "", 4096)                       = 0
close(3)                                = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGINT, {sa_handler=0x565c9e00, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=0x565c9e00, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
pipe2([3, 4], 0)                        = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
rt_sigprocmask(SIG_BLOCK, [INT TERM CHLD], [], 8) = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7f6c968) = 38287
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGCHLD, {sa_handler=0x565c69c0, sa_mask=[], sa_flags=SA_RESTART}, {sa_handler=0x565c69c0, sa_mask=[], sa_flags=SA_RESTART}, 8) = 0
close(4)                                = 0
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
read(3, "", 4096)                       = 0
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=38287, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG, NULL) = 38287
wait4(-1, 0xff95fd74, WNOHANG, NULL)    = -1 ECHILD (No child processes)
sigreturn({mask=[INT]})                 = 0
close(3)                                = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGINT, {sa_handler=0x565c9e00, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=0x565c9e00, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
pipe2([3, 4], 0)                        = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
rt_sigprocmask(SIG_BLOCK, [INT TERM CHLD], [], 8) = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7f6c968) = 38290
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=38290, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG, NULL) = 38290
wait4(-1, 0xff960f74, WNOHANG, NULL)    = -1 ECHILD (No child processes)
sigreturn({mask=[]})                    = 0
rt_sigaction(SIGCHLD, {sa_handler=0x565c69c0, sa_mask=[], sa_flags=SA_RESTART}, {sa_handler=0x565c69c0, sa_mask=[], sa_flags=SA_RESTART}, 8) = 0
close(4)                                = 0
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
read(3, "/builddir/build/BUILD/ivykis-0.4"..., 4096) = 39
read(3, "", 4096)                       = 0
close(3)                                = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGINT, {sa_handler=0x565c9e00, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=0x565c9e00, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
statx(AT_FDCWD, "/builddir/build/BUILD/ivykis-0.43/test/.libs/iv_event_raw_test", AT_STATX_SYNC_AS_STAT|AT_NO_AUTOMOUNT, STATX_BASIC_STATS, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFREG|0755, stx_size=20304, ...}) = 0
pipe2([3, 4], 0)                        = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
rt_sigprocmask(SIG_BLOCK, [INT TERM CHLD], [], 8) = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xf7f6c968) = 38291
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGCHLD, {sa_handler=0x565c69c0, sa_mask=[], sa_flags=SA_RESTART}, {sa_handler=0x565c69c0, sa_mask=[], sa_flags=SA_RESTART}, 8) = 0
close(4)                                = 0
rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0
read(3, "/builddir/build/BUILD/ivykis-0.4"..., 4096) = 44
read(3, "", 4096)                       = 0
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=38291, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WNOHANG, NULL) = 38291
wait4(-1, 0xff960274, WNOHANG, NULL)    = -1 ECHILD (No child processes)
sigreturn({mask=[INT]})                 = 0
close(3)                                = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGINT, {sa_handler=0x565c9e00, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=0x565c9e00, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigaction(SIGINT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGQUIT, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGCHLD, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=SA_RESTART}, {sa_handler=0x565c69c0, sa_mask=[], sa_flags=SA_RESTART}, 8) = 0
execve("/builddir/build/BUILD/ivykis-0.43/test/.libs/iv_event_raw_test", ["/builddir/build/BUILD/ivykis-0.4"...], 0x58436020 /* 30 vars */) = 0
brk(NULL)                               = 0x56adf000
mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xf7f73000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/builddir/build/BUILD/ivykis-0.43/src/.libs/libivykis.so.0", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\0\0\0\0004\0\0\0"..., 512) = 512
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|0755, stx_size=269016, ...}) = 0
mmap2(NULL, 70400, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xf7f61000
mmap2(0xf7f63000, 36864, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0xf7f63000
mmap2(0xf7f6c000, 20480, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xb000) = 0xf7f6c000
mmap2(0xf7f71000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xf000) = 0xf7f71000
close(3)                                = 0
openat(AT_FDCWD, "/builddir/build/BUILD/ivykis-0.43/src/.libs/libc.so.6", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_LARGEFILE|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=6761, ...}) = 0
mmap2(NULL, 6761, PROT_READ, MAP_PRIVATE, 3, 0) = 0xf7f5f000
close(3)                                = 0
openat(AT_FDCWD, "/lib/libc.so.6", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\3\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\0N\2\0004\0\0\0"..., 512) = 512
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|0755, stx_size=2489200, ...}) = 0
mmap2(NULL, 2066236, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xf7d66000
mmap2(0xf7d89000, 1421312, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x23000) = 0xf7d89000
mmap2(0xf7ee4000, 471040, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x17e000) = 0xf7ee4000
mmap2(0xf7f57000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1f1000) = 0xf7f57000
mmap2(0xf7f5a000, 18236, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xf7f5a000
close(3)                                = 0
set_thread_area({entry_number=-1, base_addr=0xf7f749c0, limit=0x0fffff, seg_32bit=1, contents=0, read_exec_only=0, limit_in_pages=1, seg_not_present=0, useable=1}) = 0 (entry_number=12)
set_tid_address(0xf7f74a28)             = 38280
set_robust_list(0xf7f74a2c, 12)         = 0
rseq(0xf7f74e60, 0x20, 0, 0x53053053)   = 0
mprotect(0xf7f57000, 8192, PROT_READ)   = 0
mprotect(0xf7f71000, 4096, PROT_READ)   = 0
mprotect(0x5659f000, 4096, PROT_READ)   = 0
mprotect(0xf7fad000, 8192, PROT_READ)   = 0
ugetrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM_INFINITY}) = 0
munmap(0xf7f5f000, 6761)                = 0
alarm(5)                                = 0
getrandom("\xa0\x64\x6e\x89", 4, GRND_NONBLOCK) = 4
brk(NULL)                               = 0x56adf000
brk(0x56b00000)                         = 0x56b00000
brk(0x56b01000)                         = 0x56b01000
geteuid32()                             = 0
rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTART}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGURG, {sa_handler=SIG_IGN, sa_mask=[URG], sa_flags=SA_RESTART}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
ugetrlimit(RLIMIT_NOFILE, {rlim_cur=1024, rlim_max=512*1024}) = 0
prlimit64(0, RLIMIT_NOFILE, {rlim_cur=128*1024, rlim_max=128*1024}, NULL) = 0
epoll_create1(EPOLL_CLOEXEC)            = 3
eventfd2(0, EFD_CLOEXEC|EFD_NONBLOCK)   = 4
fcntl64(4, F_GETFD)                     = 0x1 (flags FD_CLOEXEC)
fcntl64(4, F_GETFL)                     = 0x802 (flags O_RDWR|O_NONBLOCK)
setsockopt(4, SOL_SOCKET, SO_OOBINLINE, [1], 4) = -1 ENOTSOCK (Socket operation on non-socket)
write(4, "\1\0\0\0\0\0\0\0", 8)         = 8
epoll_ctl(3, EPOLL_CTL_ADD, 4, {events=EPOLLIN, data={u32=1448738920, u64=14333640808}}) = 0
epoll_pwait2(3, [{events=EPOLLIN, data={u32=1448738920, u64=14333640808}}], 2, NULL, NULL, 1448738920) = 1
read(4, "\1\0\0\0\0\0\0\0", 8)          = 8
epoll_ctl(3, EPOLL_CTL_DEL, 4, 0xffe95e30) = 0
close(4)                                = 0
epoll_pwait2(3, 0xffe962c0, 1, 0xffe96280, NULL, 4293485232) = -1 EINVAL (Invalid argument)
openat(AT_FDCWD, "/etc/localtime", O_RDONLY|O_CLOEXEC) = 4
statx(4, "", 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=0, ...}) = 0
statx(4, "", 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=0, ...}) = 0
read(4, "", 4096)                       = 0
close(4)                                = 0
brk(0x56b00000)                         = 0x56b00000
socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 4
connect(4, {sa_family=AF_UNIX, sun_path="/dev/log"}, 110) = -1 ENOENT (No such file or directory)
close(4)                                = 0
rt_sigprocmask(SIG_UNBLOCK, [ABRT], NULL, 8) = 0
gettid()                                = 38280
getpid()                                = 38280
tgkill(38280, 38280, SIGABRT)           = 0
--- SIGABRT {si_signo=SIGABRT, si_code=SI_TKILL, si_pid=38280, si_uid=0} ---
+++ killed by SIGABRT (core dumped) +++
Aborted (core dumped)
bash-5.2# 

This happens on Debian as well. The commit which broke it is 491daf4 noted as ' iv_fd_epoll: Add support for epoll_pwait2()'.

It seems that epoll_pwait2() is returning EINVAL:

    epoll_pwait2(3, 0xffe962c0, 1, 0xffe96280, NULL, 4293485232) = -1 EINVAL (Invalid argument)

The man page for epoll_pwait2() says under ERRORS:

       EINVAL epfd is not an epoll file descriptor, or maxevents is less  than
              or equal to zero.

But neither of those are the case, so this doesn't tell us much.

I suspect that the layout of struct timespec in 32-bit compatibility mode is the issue. If this is the case, then we should hit the same problem with ppoll(2), as that also uses a struct timespec for the timeout. Can you try excluding the epoll poll methods (by setting the IV_EXCLUDE_POLL_METHOD="epoll-timerfd epoll" environment variable) and then checking that 1. ivykis then uses ppoll(2) 2. ppoll(2) also fails with -EINVAL?

Can you test whether c4f4e9f makes the issue go away for you?

The patch itself looks good, but I did not test it. I'd need a 64bit kernel + 32 bit userland, let me think.

I reproduced this issue with export CFLAGS="-m32", FWIW.

I've just tested this using docker using i386 images. First I reproduced the issue on the master branch (e.g. without the patch), failed nicely:

PASS: avl
PASS: event_unregister_bug
../../test-driver: line 112: 14762 Aborted                 (core dumped) "$@" >> "$log_file" 2>&1
FAIL: iv_event_raw_test
PASS: struct_sizes
../../test-driver: line 112: 14798 Aborted                 (core dumped) "$@" >> "$log_file" 2>&1
FAIL: timer
../../test-driver: line 112: 14816 Aborted                 (core dumped) "$@" >> "$log_file" 2>&1
FAIL: timer_fairness
PASS: timer_fairness_bug
../../test-driver: line 112: 14852 Aborted                 (core dumped) "$@" >> "$log_file" 2>&1
FAIL: timer_order
../../test-driver: line 112: 14870 Aborted                 (core dumped) "$@" >> "$log_file" 2>&1
FAIL: timer_past
../../test-driver: line 112: 14888 Aborted                 (core dumped) "$@" >> "$log_file" 2>&1
FAIL: timer_zero
PASS: iv_signal_test

confirmed that it's indeed the EINVAL issue:

epoll_pwait2(3, 0xffa54070, 1, 0xffa54038, NULL, 3) = -1 EINVAL (Invalid argument)

Then reset my tree to your change, recompiled and the aborts are gone:

PASS: avl
PASS: event_unregister_bug
PASS: iv_event_raw_test
PASS: struct_sizes
PASS: timer
PASS: timer_fairness
PASS: timer_fairness_bug
PASS: timer_order
PASS: timer_past
PASS: timer_zero
PASS: iv_signal_test

Thanks! I added your Tested-by: and merged the fix into master. I'll try to release this as 0.43.1 this weekend.

Thanks! I added your Tested-by: and merged the fix into master. I'll try to release this as 0.43.1 this weekend.

Bit slower feedback. Tested on Debian/i386 and now it compiles here as well. Did an amd64 test as well, still working fine.

Fix merged to master: cc777b2

Thanks! Started to work on updating the ivykis package in Fedora Rawhide / openSUSE Tumbleweed / FreeBSD. My current ETA is next week, depending on my health and the speed of the various approval processes.

@buytenh @bazsi I did a few tests using 0.43.1 and syslog-ng. FreeBSD seems to be all right. However, on Fedora Linux syslog-ng behaves strangely since the new ivykis was installed: it works when started from a terminal, but not when started from systemd. No test on openSUSE, as that uses the ivykis version embedded into syslog-ng sources.

@buytenh @bazsi I did a few tests using 0.43.1 and syslog-ng. FreeBSD seems to be all right. However, on Fedora Linux syslog-ng behaves strangely since the new ivykis was installed: it works when started from a terminal, but not when started from systemd. No test on openSUSE, as that uses the ivykis version embedded into syslog-ng sources.

@bazsi Can you take this one?

Update: yesterday, when it failed, I tested it on Fedora 39. This morning I tested it on Rocky Linux 9, and experienced no problems. Next I tested it on Fedora Rawhide, and it also failed the same way.

@buytenh @bazsi I did a few tests using 0.43.1 and syslog-ng. FreeBSD seems to be all right. However, on Fedora Linux syslog-ng behaves strangely since the new ivykis was installed: it works when started from a terminal, but not when started from systemd. No test on openSUSE, as that uses the ivykis version embedded into syslog-ng sources.

@bazsi Can you take this one?

Sorry, I was out on a conference, just returned. I don't have a fedora environment handy, but I'll try to reproduce this.

I've checked and it did start up for me properly. I've noticed two issues, but neither are ivykis related:

Screenshot from 2024-06-16 12-51-11

  1. the SYSLOGNG_OPTS environment variable is unset, in that case a warning is displayed
  2. syslog-ng does not seem to have permissions to register an inotify watch

The first seems to be a systemd unit issue, the 2nd is a missing selinux permission. Here's the list of audit failure events for syslog-ng:

image

Versions of the packages (pulled them from your githead repo):

image