funcheck icon indicating copy to clipboard operation
funcheck copied to clipboard
verified publisher icon froz42

MLX support does not seem to work with NIX version

Open jukefr opened this issue 1 year ago • 6 comments

Describe the bug I was trying to test my so_long project (which uses MinilibX). If I run funcheck on for example get_next_line it works fine. If I run it on my so_long project, it seems to hang forever.

To Reproduce Steps to reproduce the behavior:

  1. Use a so_long project as base (or any project that uses Minilibx)
  2. Build it (I use this flake to build my so_long)
  3. Run funcheck ./<bin> <args>

Expected behavior It should not hang.

Screenshots image

Additional context For exact reproduction steps: as development shell

git clone https://codeberg.org/juke/so_long.git && cd so_long
nix develop "git+https://codeberg.org/juke/42-flakes.nix?dir=so_long" --refresh --no-write-lock-file
# inside development shell
make
funcheck ./so_long maps/map1.ber

or as direct build

git clone https://codeberg.org/juke/so_long.git && cd so_long
nix build "git+https://codeberg.org/juke/42-flakes.nix?dir=so_long" --refresh --no-write-lock-file --impure
funcheck ./result/bin/so_long maps/map1.ber

jukefr avatar Dec 11 '24 06:12 jukefr

seems to be any x11 stuff actually, not specifically mlx

i tried this simple gist https://gist.githubusercontent.com/m1nuz/8f8f10a7f8715b62fe79/raw/ac438bd5d757e82c1781d462bfa9be15d657ae31/simple-x11-window.c

and built it with -lX11 and funcheck also hangs on it

jukefr avatar Dec 11 '24 06:12 jukefr

heres the last lines of an strace with no fork following

pipe2([3, 6], 0)                        = 0
openat(AT_FDCWD, "/tmp", O_RDWR|O_EXCL|O_TMPFILE, 0600) = 7
fcntl(7, F_GETFL)                       = 0x418002 (flags O_RDWR|O_LARGEFILE|O_TMPFILE)
getpid()                                = 881499
openat(AT_FDCWD, "/dev/shm/funcheck_881499_1733907434_0", O_RDWR|O_CREAT|O_NOFOLLOW|O_CLOEXEC, 0666) = 8
ftruncate(8, 1176)                      = 0
mmap(NULL, 1176, PROT_READ|PROT_WRITE, MAP_SHARED, 8, 0) = 0x7ffff7dbc000
close(8)                                = 0
rt_sigaction(SIGRT_1, {sa_handler=0x7ffff7e4dcd0, sa_mask=[], sa_flags=SA_RESTORER|SA_ONSTACK|SA_RESTART|SA_SIGINFO, sa_restorer=0x7ffff7e00620}, NULL, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
mmap(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7ffff75bb000
mprotect(0x7ffff75bc000, 8388608, PROT_READ|PROT_WRITE) = 0
rt_sigprocmask(SIG_BLOCK, ~[], [], 8)   = 0
clone3({flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, child_tid=0x7ffff7dbb990, parent_tid=0x7ffff7dbb990, exit_signal=0, stack=0x7ffff75bb000, stack_size=0x7fff80, tls=0x7ffff7dbb6c0} => {parent_tid=[881502]}, 88) = 881502
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
dup(0)                                  = 8
mmap(NULL, 8392704, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7ffff6dba000
mprotect(0x7ffff6dbb000, 8388608, PROT_READ|PROT_WRITE) = 0
rt_sigprocmask(SIG_BLOCK, ~[], [], 8)   = 0
clone3({flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, child_tid=0x7ffff75ba990, parent_tid=0x7ffff75ba990, exit_signal=0, stack=0x7ffff6dba000, stack_size=0x7fff80, tls=0x7ffff75ba6c0} => {parent_tid=[881503]}, 88) = 881503
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7ffff7dbda10) = 881504
close(3)                                = 0
wait4(881504,

heres the last lines of an strace with fork following

[pid 882162] read(5,  <unfinished ...>
[pid 882161] write(1, "main\n??:0:0\n\n", 13 <unfinished ...>
[pid 882162] <... read resumed>"main\n??:0:0\n\n", 4096) = 13
[pid 882161] <... write resumed>)       = 13
[pid 882162] write(4, "0x5a0e\n", 7 <unfinished ...>
[pid 882161] read(0,  <unfinished ...>
[pid 882162] <... write resumed>)       = 7
[pid 882161] <... read resumed>"0x5a0e\n", 4096) = 7
[pid 882162] read(5,  <unfinished ...>
[pid 882161] write(1, "??\n??:0:0\n\n", 11 <unfinished ...>
[pid 882162] <... read resumed>"??\n??:0:0\n\n", 4096) = 11
[pid 882161] <... write resumed>)       = 11
[pid 882162] write(4, "0x2a27d\n", 8 <unfinished ...>
[pid 882161] read(0,  <unfinished ...>
[pid 882162] <... write resumed>)       = 8
[pid 882161] <... read resumed>"0x2a27d\n", 4096) = 8
[pid 882162] read(5,  <unfinished ...>
[pid 882161] write(1, "??\n??:0:0\n\n", 11 <unfinished ...>
[pid 882162] <... read resumed>"??\n??:0:0\n\n", 4096) = 11
[pid 882161] <... write resumed>)       = 11
[pid 882162] write(4, "0x2a338\n", 8 <unfinished ...>
[pid 882161] read(0,  <unfinished ...>
[pid 882162] <... write resumed>)       = 8
[pid 882161] <... read resumed>"0x2a338\n", 4096) = 8
[pid 882162] read(5,  <unfinished ...>
[pid 882161] write(1, "??\n??:0:0\n\n", 11 <unfinished ...>
[pid 882162] <... read resumed>"??\n??:0:0\n\n", 4096) = 11
[pid 882161] <... write resumed>)       = 11
[pid 882162] write(4, "0x4028d4\n", 9 <unfinished ...>
[pid 882161] read(0,  <unfinished ...>
[pid 882162] <... write resumed>)       = 9
[pid 882161] <... read resumed>"0x4028d4\n", 4096) = 9
[pid 882162] read(5,  <unfinished ...>
[pid 882161] write(1, "_start\n??:0:0\n\n", 15 <unfinished ...>
[pid 882162] <... read resumed>"_start\n??:0:0\n\n", 4096) = 15
[pid 882161] <... write resumed>)       = 15
[pid 882162] mprotect(0x7ffff02fd000, 49152, PROT_READ|PROT_WRITE <unfinished ...>
[pid 882161] read(0,  <unfinished ...>
[pid 882162] <... mprotect resumed>)    = 0
[pid 882162] futex(0x7ffff7dbc450, FUTEX_WAKE, 1) = 1
[pid 882162] futex(0x7ffff7dbc470, FUTEX_WAIT_BITSET|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY <unfinished ...>
[pid 882164] <... futex resumed>)       = 0
[pid 882164] futex(0x7ffff7aeb470, FUTEX_WAKE, 1) = 1
[pid 882162] <... futex resumed>)       = 0
[pid 882164] futex(0x7ffff7aeb450, FUTEX_WAIT_BITSET|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY <unfinished ...>
[pid 882162] futex(0x7ffff7dbc450, FUTEX_WAKE, 1 <unfinished ...>
[pid 882164] <... futex resumed>)       = -1 EAGAIN (Resource temporarily unavailable)
[pid 882162] <... futex resumed>)       = 0
[pid 882164] futex(0x7ffff7aeb450, FUTEX_WAIT_BITSET|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY <unfinished ...>
[pid 882162] futex(0x7ffff7dbc450, FUTEX_WAKE, 1 <unfinished ...>
[pid 882164] <... futex resumed>)       = -1 EAGAIN (Resource temporarily unavailable)
[pid 882162] <... futex resumed>)       = 0
[pid 882164] recvmsg(6,  <unfinished ...>
[pid 882162] futex(0x7ffff7dbc470, FUTEX_WAIT_BITSET|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY

jukefr avatar Dec 11 '24 09:12 jukefr

i added a bunch of logs until i found where it got stuck and it appears its here specifically https://github.com/froz42/funcheck/blob/main/host/srcs/run/runner.c#L178

jukefr avatar Dec 11 '24 09:12 jukefr

Hello, thank for your issue, did you tried the pre-compiled version of funcheck ? I do not think this is related to nix flake

froz42 avatar Dec 11 '24 09:12 froz42

I can't really run prebuilt dynamically linked executables "easily" :( https://nix.dev/guides/faq#how-to-run-non-nix-executables I have to patch the elf for it to work But at least the prebuilt version got further and actually "runs" (but very slow and the x11 window is just a black screen) I'm not really sure its working but compared to the nix build at least it doesn't hang and opens the X window... image

jukefr avatar Dec 11 '24 11:12 jukefr

ok so after alot of pain i am trying to find the issue...

i added some logs in the mlx hooks...

 INFO  Running program details:
 INFO    Program: ./result/bin/so_long
 INFO    Arguments:
 INFO      maps/map1.ber
 INFO  Forking process to run program
 INFO  Parent process continuing (child pid: 286059)
 INFO  Initial child process state: R (running)

 INFO  Child process started (pid: 286059)
 INFO  X11 Display: :0
 INFO  XAUTHORITY: not set
 INFO  Checking X11 socket: /tmp/.X11-unix/X0
 INFO  X11 socket exists
 INFO  X11 socket permissions: 755
 INFO  X11 socket exists and is owned by uid: 1000
 INFO  Executing program with execvpe
DEBUG: X11 hooks initialized
DEBUG: XSync hook at: 0x7f59096dcbd0
DEBUG: Library constructor called
DEBUG: setup() called
DEBUG: disabled hooks
DEBUG: initialized shared memory
DEBUG: Signals set up
DEBUG: Exit hook set up
DEBUG: setup hooks
DEBUG: setup() complete
DEBUG: XCreateGC hook called with display: 0x1a10b7b0
DEBUG: XCreateGC original function address: 0x7f590954e270
 INFO  Child process state after 100ms: S (sleeping)

 INFO  Child process state after 1s: S (sleeping)

i also have debug logs in xsync but for some reason they do not appear...

int EXPORT XSync(Display *a, Bool b)
{
    if (getenv("DEBUG"))
        fprintf(stderr, "DEBUG: XSync hook called\n");
    (void)a;
    (void)b;
    exit(0);
    return 0;
}

ltrace shows that the program does call Xsync....

ltrace -e 'X*' ./result/bin/so_long maps/map1.ber              [±master ●(✹)]
so_long->XOpenDisplay(0x4081a8, 0, 0, 0 <unfinished ...>
libX11.so.6->XSetErrorHandler(0, 0, 0, 0xffffff80) = 0x7f8a49160680
libX11.so.6->XSetIOErrorHandler(0, 0, 0, 0)       = 0x7f8a49160590
libxcb.so.1->XauGetBestAuthByAddr(256, 10, 0x7ffca9a500c0, 1 <unfinished ...>
libXau.so.6->XauFileName(256, 10, 0x7ffca9a500c0, 1) = 0x21e717c0
<... XauGetBestAuthByAddr resumed> )              = 0
libX11.so.6->XCreateGC(0x21e703c0, 892, 12, 0x7ffca9a503f0) = 0x21e819e0
libX11.so.6->XSynchronize(0x21e703c0, 0, 0, 0)    = 0
libX11.so.6->XkbUseExtension(0x21e703c0, 0, 0, 0 <unfinished ...>
libX11.so.6->XInitExtension(0x21e703c0, 0x7f8a491c76cf, 0, 68 <unfinished ...>
libX11.so.6->XQueryExtension(0x21e703c0, 0x7f8a491c76cf, 0x7ffca9a50304, 0x7ffca9a50308) = 1
<... XInitExtension resumed> )                    = 0x21e81b78
libX11.so.6->XESetWireToEvent(0x21e703c0, 85, 0x7f8a491b7450, 0) = 0x7f8a4915ff40
<... XkbUseExtension resumed> )                   = 1
<... XOpenDisplay resumed> )                      = 0x21e703c0
so_long->XInternAtom(0x21e703c0, 0x408207, 0, 0)  = 321
so_long->XInternAtom(0x21e703c0, 0x408218, 0, 0)  = 313
so_long->XShmQueryVersion(0x21e703c0, 0x7ffca9a5046c, 0x7ffca9a5046c, 0x7ffca9a50468 <unfinished ...>
libXext.so.6->XextFindDisplay(0x7f8a49115820, 0x21e703c0, 0x7ffca9a5046c, 0x7ffca9a50468) = 0
libXext.so.6->XextAddDisplay(0x7f8a49115820, 0x21e703c0, 0x7f8a491100ba, 0x7f8a491154a0 <unfinished ...>
libXext.so.6->XInitExtension(0x21e703c0, 0x7f8a491100ba, 0, 0 <unfinished ...>
libX11.so.6->XQueryExtension(0x21e703c0, 0x7f8a491100ba, 0x7ffca9a50364, 0x7ffca9a50368) = 1
<... XInitExtension resumed> )                    = 0x21e81e98
libXext.so.6->XESetWireToEvent(0x21e703c0, 65, 0x7f8a4910a5e0, 0) = 0x7f8a4915ff40
libXext.so.6->XESetEventToWire(0x21e703c0, 65, 0x7f8a4910a530, 0) = 0x7f8a4915ff70
libXext.so.6->XextCreateExtension(0, 130, 0x7f8a491154a0, 71) = 0x21e81a90
libXext.so.6->XextFindDisplay(0x21e81a90, 0x21e703c0, 0, 0) = 0
libXext.so.6->XextAddDisplay(0x21e81a90, 0x21e703c0, 0x7f8a49110200, 0x7f8a49115660 <unfinished ...>
libXext.so.6->XInitExtension(0x21e703c0, 0x7f8a49110200, 0, 0 <unfinished ...>
libX11.so.6->XQueryExtension(0x21e703c0, 0x7f8a49110200, 0x7ffca9a502b4, 0x7ffca9a502b8) = 1
<... XInitExtension resumed> )                    = 0x21e81f98
libXext.so.6->XESetCloseDisplay(0x21e703c0, 2, 0x7f8a4910f060, 0) = 0
<... XextAddDisplay resumed> )                    = 0x21e81e60
libXext.so.6->XESetWireToEvent(0x21e703c0, 35, 0x7f8a4910eff0, 0) = 0x7f8a4915ff80
libXext.so.6->XESetEventToWire(0x21e703c0, 35, 0x7f8a4910ef70, 0) = 0
libXext.so.6->XESetCloseDisplay(0x21e703c0, 1, 0x7f8a4910a480, 0) = 0
libXext.so.6->XESetErrorString(0x21e703c0, 1, 0x7f8a4910a6a0, 0) = 0
<... XextAddDisplay resumed> )                    = 0x21e81e30
<... XShmQueryVersion resumed> )                  = 1
so_long->XShmPixmapFormat(0x21e703c0, 0, 0xffffffff, 0 <unfinished ...>
libXext.so.6->XextFindDisplay(0x7f8a49115820, 0x21e703c0, 0xffffffff, 0) = 0x21e81e30
<... XShmPixmapFormat resumed> )                  = 2
so_long->XCreateWindow(0x21e703c0, 892, 0, 0)     = 0x1c00001
so_long->XGetWMNormalHints(0x21e703c0, 0x1c00001, 0x7ffca9a50320, 0x7ffca9a50318 <unfinished ...>
libX11.so.6->XGetWMSizeHints(0x21e703c0, 0x1c00001, 0x7ffca9a50320, 0x7ffca9a50318 <unfinished ...>
libX11.so.6->XGetWindowProperty(0x21e703c0, 0x1c00001, 40, 0) = 0
<... XGetWMSizeHints resumed> )                   = 0
<... XGetWMNormalHints resumed> )                 = 0
so_long->XSetWMNormalHints(0x21e703c0, 0x1c00001, 0x7ffca9a50320, 0 <unfinished ...>
libX11.so.6->XSetWMSizeHints(0x21e703c0, 0x1c00001, 0x7ffca9a50320, 40 <unfinished ...>
libX11.so.6->XChangeProperty(0x21e703c0, 0x1c00001, 40, 41) = 1
<... XSetWMSizeHints resumed> )                   = 0
<... XSetWMNormalHints resumed> )                 = 0
so_long->XStoreName(0x21e703c0, 0x1c00001, 0x4080d0, 0 <unfinished ...>
libX11.so.6->XChangeProperty(0x21e703c0, 0x1c00001, 39, 31) = 1
<... XStoreName resumed> )                        = 1
so_long->XSetWMProtocols(0x21e703c0, 0x1c00001, 0x21e703a0, 1 <unfinished ...>
libX11.so.6->XChangeProperty(0x21e703c0, 0x1c00001, 313, 4) = 1
<... XSetWMProtocols resumed> )                   = 1
so_long->XCreateGC(0x21e703c0, 0x1c00001, 7, 0x7ffca9a50410) = 0x21e82ba0
so_long->XMapRaised(0x21e703c0, 0x1c00001, 0x21e82838, 0) = 1
so_long->XWindowEvent(0x21e703c0, 0x1c00001, 0x8000, 0x7ffca9a502b0) = 0
so_long->XPutBackEvent(0x21e703c0, 0x7ffca9a502b0, 0, 0) = 0
^[so_long->XShmCreateImage(0x21e703c0, 0x21e7cf60, 24, 2) = 0x21e83250
so_long->XSetErrorHandler(0x4060a0, 0, 0, 0)      = 0x7f8a49160680
so_long->XShmAttach(0x21e703c0, 0x21e83228, 0, 0 <unfinished ...>
libXext.so.6->XextFindDisplay(0x7f8a49115820, 0x21e703c0, 0, 0) = 0x21e81e30
<... XShmAttach resumed> )                        = 1
so_long->XSync(0x21e703c0, 0, 0, 0)               = 1
[...]

but yeah the we seem to never get into the xsync hook...

edit: added a hook for xsyncrhonize which comes right after xcreategc

int (*EXPORT XSynchronize(Display *display, Bool onoff))()
{
	printf("DEBUG: XSynchronize called with display=%p, onoff=%d\n", (void*)display, onoff);
	disable_alloc_hooks();
	typeof(&XSynchronize) original_function = get_original_function();
	int (*result)() = original_function(display, onoff);
	enable_alloc_hooks();
	return result;
}

and i dont see the log when i run funcheck

will update this post as i keep trying stuff...

jukefr avatar Dec 13 '24 02:12 jukefr