search

martinpitt / umockdev

Mock hardware devices for creating unit tests and bug reporting
https://launchpad.net/umockdev
GNU Lesser General Public License v2.1
314 stars 58 forks source link

testsuite fails with libusb 1.0.24 #115

Closed flokli closed 3 years ago

flokli commented 3 years ago

While doing a nixpkgs bump, I tried compiling umockdev, and realized tests in umockdev suddenly broke:

# Start of umockdev-testbed-usb tests
# GLib-DEBUG: setenv()/putenv() are not thread-safe and should not be used after threads are created
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.BBR4V0
# DEBUG: umockdev.vala:700: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:704: umockdev_testbed_uevent: sending uevent add for device /sys/devices/usb1
**
ERROR:tests/test-umockdev.c:1137:t_testbed_usb_lsusb: assertion failed: (g_str_has_prefix(out, "\nBus 001 Device 001: ID 04a9:31c0"))
Bail out! ERROR:tests/test-umockdev.c:1137:t_testbed_usb_lsusb: assertion failed: (g_str_has_prefix(out, "\nBus 001 Device 001: ID 04a9:31c0"))
/nix/store/4l7wsi6h6283194r6fqy1731qxlagq62-bash-4.4-p23/bin/bash: line 1:  3282 Aborted                 (core dumped) TOP_BUILDDIR=. TOP_SRCDIR=. LD_LIBRARY_PATH=./.libs:$LD_LIBRARY_PATH GI_TYPELIB_PATH=. PATH=./src:$PATH G_SLICE=debug-blocks MALLOC_PERTURB_=85 MALLOC_CHECK_=3 ./src/umockdev-wrapper $f
make[3]: *** [Makefile:2208: check-local] Error 134
make[3]: Leaving directory '/build/umockdev-0.13.1'
make[2]: *** [Makefile:1970: check-am] Error 2
make[2]: Leaving directory '/build/umockdev-0.13.1'
make[1]: *** [Makefile:1680: check-recursive] Error 1
make[1]: Leaving directory '/build/umockdev-0.13.1'
make: *** [Makefile:1972: check] Error 2
builder for '/nix/store/nn626wdbgvinwrm3c4a755qc9ykzz7xp-umockdev-0.13.1.drv' failed with exit code 2

I bisected this to the "libusb 1.0.23 -> 1.0.24" bump in nixpkgs (commit id 24342209d4011e4ca2d68c1507403d7f3cdd5607 there)

git bisect start
# good: [9232d4168e27cf0f35d2d1e0b1e54ef8c0a1b39a] Merge pull request #106535 from sternenseemann/ufonormalizer-0.5.2
git bisect good 9232d4168e27cf0f35d2d1e0b1e54ef8c0a1b39a
# bad: [3aac2c14a8db029546d33aa8c458c99e6bbe32b2] Merge master into staging-next
git bisect bad 3aac2c14a8db029546d33aa8c458c99e6bbe32b2
# good: [74971a10d53174d81f4573ada22535f593d0a584] gitlab-runner: 13.6.0 -> 13.7.0 (#107378)
git bisect good 74971a10d53174d81f4573ada22535f593d0a584
# good: [59f649840c4ad3f687ce84dea89899b275008b1d] kpurpose: remove patch applied upstream
git bisect good 59f649840c4ad3f687ce84dea89899b275008b1d
# bad: [6e0acbf2ec38835bf65ff7b628ecf9c4ed50802e] Merge staging-next into staging
git bisect bad 6e0acbf2ec38835bf65ff7b628ecf9c4ed50802e
# good: [de4b7d5b81ab4d47e451891dfde52ee9a300064f] Merge staging-next into staging
git bisect good de4b7d5b81ab4d47e451891dfde52ee9a300064f
# bad: [7a06f5dd59a0c05568621be3afb0f57df2f696f1] Merge pull request #106908 from Mic92/fix-static-pie
git bisect bad 7a06f5dd59a0c05568621be3afb0f57df2f696f1
# bad: [da0398db780133e06dca14c5285f4d57c460eb09] Merge pull request #106738 from r-ryantm/auto-update/libusb
git bisect bad da0398db780133e06dca14c5285f4d57c460eb09
# good: [c2842e5ad427876e2f023ef41ea3500dce630e04] Merge staging-next into staging
git bisect good c2842e5ad427876e2f023ef41ea3500dce630e04
# good: [fa28c1544db7ddda1939a8eb40c50271bfcf22c7] Merge pull request #106549 from primeos/cryptography
git bisect good fa28c1544db7ddda1939a8eb40c50271bfcf22c7

Can you reproduce this on your systems, with libusb 1.0.24?

flokli commented 3 years ago

While nixpkgs currently is on umockdev 0.13.1, I was able to also reproduce the failure with umockdev 0.15.2 - and moving libusb back to 1.0.23 did get the tests to succeed.

martinpitt commented 3 years ago

I noticed something like this yesterday in a debian testing run. It also fails in an lsusb test now. Indeed Debian did the same version bump. So I need to re-do the recorded traces to also match this version.

martinpitt commented 3 years ago

Unfortunately the test failure with Debian is slightly different -- lsusb just exits with 1 without printing a single error message, whereas in your case it did succeed (exit code 0) but did not print the expected device. But I'll start with investigating this on Debian (which is much easier for me), and with some luck it is the same root cause.

I bisected this to https://github.com/libusb/libusb/commit/c3864c822b190dfbef48b0459222a08467f94cfb which is unfortunately very big. To be continued later..

martinpitt commented 3 years ago

@flokli : I fixed this in commit 1b58d24 now. It most probably works for nix as well, please let me know if it doesn't. I'll do a new upstream release with this fix in a few days.

flokli commented 3 years ago

Hmm, this doesn't seem to do the trick for me:

When just applying that patch on top of 0.15.2, I get the following output:

[0/1] Running all tests.
1/7 umockdev / umockdev                       FAIL           0.07s (killed by signal 6 SIGABRT)
2/7 umockdev:fails-valgrind / umockdev-vala   OK             0.32s
3/7 umockdev / ioctl-tree                     OK             0.01s
4/7 umockdev / umockdev-run                   OK             1.07s
5/7 umockdev:fails-valgrind / umockdev-record OK             1.37s
6/7 umockdev / static-code                    OK             0.07s
7/7 umockdev:fails-valgrind / umockdev.py     OK             0.07s

The output from the failed tests:

1/7 umockdev / umockdev                       FAIL           0.07s (killed by signal 6 SIGABRT)

--- command ---
23:54:49 LD_LIBRARY_PATH='/build/umockdev-0.15.2/build' GI_TYPELIB_PATH='/build/umockdev-0.15.2/build:/nix/store/dbh2lc6y43z3c4bhz18q31krrvppc89h-gobject-introspection-1.66.1/lib/girepository-1.0:/nix/store/pv0k8pg3znmid1nmwx72w76clxxb9nxh-libgudev-234/lib/girepository-1.0:/nix/store/dbh2lc6y43z3c4bhz18q31krrvppc89h-gobject-introspection-1.66.1/lib/girepository-1.0:/nix/store/pv0k8pg3znmid1nmwx72w76clxxb9nxh-libgudev-234/lib/girepository-1.0:/nix/store/dbh2lc6y43z3c4bhz18q31krrvppc89h-gobject-introspection-1.66.1/lib/girepository-1.0:/nix/store/pv0k8pg3znmid1nmwx72w76clxxb9nxh-libgudev-234/lib/girepository-1.0' MALLOC_CHECK_='3' G_DEBUG='fatal-warnings,fatal-criticals,gc-friendly' TOP_SRCDIR='/build/umockdev-0.15.2' PATH='/build/umockdev-0.15.2/build:/nix/store/4sb75wbkiky9945kwqzjb2xw09dm3ar4-gobject-introspection-1.66.1-dev/bin:/nix/store/y8cr0sc3mmq40m44flq4k7blklj8nq9v-glib-2.66.3-dev/bin:/nix/store/40aa067kyqc67dff1lzfcslivqx3ymkg-gettext-0.21/bin:/nix/store/q0jkx3lpfaszmlymcl5ds7gjigcqa3lr-glib-2.66.3-bin/bin:/nix/store/8xvfzz1cdyavdcvzc1fz2sn16p94cprb-gtk-doc-1.33.0/bin:/nix/store/n9vj7i7armczjs1x7qzyqhfhzfidrv62-meson-0.56.0/bin:/nix/store/ycc7cpg9jvfsdcih23ih6ypcqhvpn96b-ninja-1.10.2/bin:/nix/store/d2bnc0h350yz0wlqbizhzb58lhmy1k6j-pkg-config-wrapper-0.29.2/bin:/nix/store/2lshxhimppd8z2xx4l8pb57pmvwcfjxk-vala-0.48.9/bin:/nix/store/jdp800qwb3v330ggl6iq722ww96q2444-python3-3.8.6/bin:/nix/store/20jz8krnn4g4iilf9fryzadjifs8pg17-which-2.21/bin:/nix/store/xhc40pbi6fhdfzxqjzxykyyccmpkriak-usbutils-012/bin:/nix/store/kg1ck8dgi10yqwmm20gi7gx5m3sr5jdq-patchelf-0.12/bin:/nix/store/b96dqbx6pri2xp2xxlq6i269virrdaw6-gcc-wrapper-9.3.0/bin:/nix/store/wmzmnnrj780268ybilmcfyd3grn5qzi6-gcc-9.3.0/bin:/nix/store/7niy0yd0ygv0wa05kl5l46x6fdflpwf1-glibc-2.32-10-bin/bin:/nix/store/8gsdifv2q3hnq42v7ddk38nmiagmjd6c-coreutils-8.32/bin:/nix/store/ip7xkk70anay3k7bp2cr6aqdg0mcdja2-binutils-wrapper-2.31.1/bin:/nix/store/kcp0y7g1ir4dxq2gqz687i4vb7gqy8s0-binutils-2.31.1/bin:/nix/store/7niy0yd0ygv0wa05kl5l46x6fdflpwf1-glibc-2.32-10-bin/bin:/nix/store/8gsdifv2q3hnq42v7ddk38nmiagmjd6c-coreutils-8.32/bin:/nix/store/y8cr0sc3mmq40m44flq4k7blklj8nq9v-glib-2.66.3-dev/bin:/nix/store/40aa067kyqc67dff1lzfcslivqx3ymkg-gettext-0.21/bin:/nix/store/q0jkx3lpfaszmlymcl5ds7gjigcqa3lr-glib-2.66.3-bin/bin:/nix/store/19b2j9a2k9plk17rqb92cvr5bkjsb011-systemd-247/bin:/nix/store/8gsdifv2q3hnq42v7ddk38nmiagmjd6c-coreutils-8.32/bin:/nix/store/khvalqldk47cx8d54gik9jrqsinzmwng-findutils-4.7.0/bin:/nix/store/6wzkn6gdpj3psqjgbfx858wd3dhanj12-diffutils-3.7/bin:/nix/store/q3ppqi1npx3vnsdlk8hk9s4p3adc4ygp-gnused-4.8/bin:/nix/store/134fdr0yrl4wgrrasxn9d3s8vzcm5lxq-gnugrep-3.6/bin:/nix/store/y9rbfriadb1gq5l8hjm8476cvjjq38ww-gawk-5.1.0/bin:/nix/store/gm4gjb3pkyxyj54kb4fizldvr60cpb2l-gnutar-1.32/bin:/nix/store/svhnwsc7rbzrfcfn0y1hsry1m8yi0y88-gzip-1.10/bin:/nix/store/pj616ldh4sbmqj7ad6dhmfcawfzgqpqf-bzip2-1.0.6.0.1-bin/bin:/nix/store/6mic0pcmp4va0ghx7hn5wl3jl4ll4h2q-gnumake-4.3/bin:/nix/store/4l7wsi6h6283194r6fqy1731qxlagq62-bash-4.4-p23/bin:/nix/store/wav2vx6iaxvkmzcwzwa127p6jri4rqdz-patch-2.7.6/bin:/nix/store/hzvfm203h5argiylhqprnpwznxxbdmj3-xz-5.2.5-bin/bin' /build/umockdev-0.15.2/src/umockdev-wrapper /build/umockdev-0.15.2/build/test-umockdev
--- Listing only the last 100 lines from a long log. ---
# Start of umockdev-testbed tests
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.TVL5V0
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.TVL5V0
ok 1 /umockdev-testbed/empty
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.42M5V0
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/extkeyboard1
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.42M5V0
ok 2 /umockdev-testbed/add_devicev
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.Z7J5V0
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/extkeyboard1
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.Z7J5V0
ok 3 /umockdev-testbed/add_device
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.OBP5V0
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/scribble
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.OBP5V0
ok 4 /umockdev-testbed/add_block_device
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.WDP5V0
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/usb1
# DEBUG: umockdev.vala:1116: parsing device description for /devices/target
# DEBUG: umockdev.vala:1185: creating device /devices/target (subsystem foo)
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/target
# DEBUG: umockdev.vala:1246: create_node_for_device: creating pty device /build/umockdev.WDP5V0/dev/target: got pty /dev/pts/0
# DEBUG: umockdev.vala:1267: create_node_for_device: creating ptymap symlink /build/umockdev.WDP5V0/dev/.ptymap/_dev_pts_0
# DEBUG: umockdev.vala:1116: parsing device description for /devices/other
# DEBUG: umockdev.vala:1185: creating device /devices/other (subsystem foo)
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/other
# DEBUG: umockdev.vala:1246: create_node_for_device: creating pty device /build/umockdev.WDP5V0/dev/other: got pty /dev/pts/1
# DEBUG: umockdev.vala:1267: create_node_for_device: creating ptymap symlink /build/umockdev.WDP5V0/dev/.ptymap/_dev_pts_1
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.WDP5V0
ok 5 /umockdev-testbed/add_device_errors
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.F5P5V0
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/usb1
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/usb1/1-1
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/usb1/1-1/kb1
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.F5P5V0
ok 6 /umockdev-testbed/child_device
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.IVN5V0
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/extkeyboard1
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.IVN5V0
ok 7 /umockdev-testbed/set_attribute
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.TJO5V0
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/extkeyboard1
# GLib-GIO-DEBUG: _g_io_module_get_default: Found default implementation local (GLocalVfs) for ?gio-vfs?
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.TJO5V0
ok 8 /umockdev-testbed/set_property
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.9DF5V0
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:1185: creating device /devices/dev1 (subsystem pci)
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/dev1
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev2/subdev1
# DEBUG: umockdev.vala:1185: creating device /devices/dev2/subdev1 (subsystem input)
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/dev2/subdev1
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev2
# DEBUG: umockdev.vala:1185: creating device /devices/dev2 (subsystem hid)
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/dev2
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.9DF5V0
ok 9 /umockdev-testbed/add_from_string
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.MZE5V0
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:1309: record_parse_line: >E: SIMPLE_PROP
< does not match anything, failing
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:1309: record_parse_line: >X: SIMPLE_PROP=1
< does not match anything, failing
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:1185: creating device /devices/dev1 (subsystem usb)
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/dev1
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.MZE5V0
ok 10 /umockdev-testbed/add_from_string_errors
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.V6E5V0
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:1309: record_parse_line: >X: Whatever
< does not match anything, failing
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:1185: creating device /devices/dev1 (subsystem pci)
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/dev1
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.V6E5V0
ok 11 /umockdev-testbed/add_from_file
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.AME5V0
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:1185: creating device /devices/dev1 (subsystem pci)
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/dev1
Bail out! ERROR:../tests/test-umockdev.c:1090:t_testbed_libc: assertion failed (errno == ENOENT): (9 == 2)
--- stderr ---
**
ERROR:../tests/test-umockdev.c:1090:t_testbed_libc: assertion failed (errno == ENOENT): (9 == 2)
-------

Summary of Failures:

1/7 umockdev / umockdev                       FAIL           0.07s (killed by signal 6 SIGABRT)
1/7 umockdev / umockdev                       FAIL           0.07s (killed by signal 6 SIGABRT)

Ok:                 6
Expected Fail:      0
Fail:               1
Unexpected Pass:    0
Skipped:            0
Timeout:            0

Full log written to /build/umockdev-0.15.2/build/meson-logs/testlog.txt
FAILED: meson-test
/nix/store/n9vj7i7armczjs1x7qzyqhfhzfidrv62-meson-0.56.0/bin/meson test --no-rebuild --print-errorlogs
ninja: build stopped: subcommand failed.
builder for '/nix/store/wnp1rmhiazb2a47nv5q9kksrx659g0mh-umockdev-0.15.2.drv' failed with exit code 1
error: build of '/nix/store/wnp1rmhiazb2a47nv5q9kksrx659g0mh-umockdev-0.15.2.drv' failed

When building umockdev from 1b58d24 directly, this:

[0/1] Running all tests.
1/7 umockdev / umockdev                       FAIL           0.07s (killed by signal 6 SIGABRT)
2/7 umockdev:fails-valgrind / umockdev-vala   OK             0.33s
3/7 umockdev / ioctl-tree                     OK             0.01s
4/7 umockdev / umockdev-run                   OK             1.07s
5/7 umockdev:fails-valgrind / umockdev-record OK             1.37s
6/7 umockdev / static-code                    OK             0.07s
7/7 umockdev:fails-valgrind / umockdev.py     OK             0.07s

The output from the failed tests:

1/7 umockdev / umockdev                       FAIL           0.07s (killed by signal 6 SIGABRT)

--- command ---
23:57:05 MALLOC_CHECK_='3' G_DEBUG='fatal-warnings,fatal-criticals,gc-friendly' LD_LIBRARY_PATH='/build/source/build' GI_TYPELIB_PATH='/build/source/build:/nix/store/dbh2lc6y43z3c4bhz18q31krrvppc89h-gobject-introspection-1.66.1/lib/girepository-1.0:/nix/store/pv0k8pg3znmid1nmwx72w76clxxb9nxh-libgudev-234/lib/girepository-1.0:/nix/store/dbh2lc6y43z3c4bhz18q31krrvppc89h-gobject-introspection-1.66.1/lib/girepository-1.0:/nix/store/pv0k8pg3znmid1nmwx72w76clxxb9nxh-libgudev-234/lib/girepository-1.0:/nix/store/dbh2lc6y43z3c4bhz18q31krrvppc89h-gobject-introspection-1.66.1/lib/girepository-1.0:/nix/store/pv0k8pg3znmid1nmwx72w76clxxb9nxh-libgudev-234/lib/girepository-1.0' TOP_SRCDIR='/build/source' PATH='/build/source/build:/nix/store/4sb75wbkiky9945kwqzjb2xw09dm3ar4-gobject-introspection-1.66.1-dev/bin:/nix/store/y8cr0sc3mmq40m44flq4k7blklj8nq9v-glib-2.66.3-dev/bin:/nix/store/40aa067kyqc67dff1lzfcslivqx3ymkg-gettext-0.21/bin:/nix/store/q0jkx3lpfaszmlymcl5ds7gjigcqa3lr-glib-2.66.3-bin/bin:/nix/store/8xvfzz1cdyavdcvzc1fz2sn16p94cprb-gtk-doc-1.33.0/bin:/nix/store/n9vj7i7armczjs1x7qzyqhfhzfidrv62-meson-0.56.0/bin:/nix/store/ycc7cpg9jvfsdcih23ih6ypcqhvpn96b-ninja-1.10.2/bin:/nix/store/d2bnc0h350yz0wlqbizhzb58lhmy1k6j-pkg-config-wrapper-0.29.2/bin:/nix/store/2lshxhimppd8z2xx4l8pb57pmvwcfjxk-vala-0.48.9/bin:/nix/store/jdp800qwb3v330ggl6iq722ww96q2444-python3-3.8.6/bin:/nix/store/20jz8krnn4g4iilf9fryzadjifs8pg17-which-2.21/bin:/nix/store/xhc40pbi6fhdfzxqjzxykyyccmpkriak-usbutils-012/bin:/nix/store/kg1ck8dgi10yqwmm20gi7gx5m3sr5jdq-patchelf-0.12/bin:/nix/store/b96dqbx6pri2xp2xxlq6i269virrdaw6-gcc-wrapper-9.3.0/bin:/nix/store/wmzmnnrj780268ybilmcfyd3grn5qzi6-gcc-9.3.0/bin:/nix/store/7niy0yd0ygv0wa05kl5l46x6fdflpwf1-glibc-2.32-10-bin/bin:/nix/store/8gsdifv2q3hnq42v7ddk38nmiagmjd6c-coreutils-8.32/bin:/nix/store/ip7xkk70anay3k7bp2cr6aqdg0mcdja2-binutils-wrapper-2.31.1/bin:/nix/store/kcp0y7g1ir4dxq2gqz687i4vb7gqy8s0-binutils-2.31.1/bin:/nix/store/7niy0yd0ygv0wa05kl5l46x6fdflpwf1-glibc-2.32-10-bin/bin:/nix/store/8gsdifv2q3hnq42v7ddk38nmiagmjd6c-coreutils-8.32/bin:/nix/store/y8cr0sc3mmq40m44flq4k7blklj8nq9v-glib-2.66.3-dev/bin:/nix/store/40aa067kyqc67dff1lzfcslivqx3ymkg-gettext-0.21/bin:/nix/store/q0jkx3lpfaszmlymcl5ds7gjigcqa3lr-glib-2.66.3-bin/bin:/nix/store/19b2j9a2k9plk17rqb92cvr5bkjsb011-systemd-247/bin:/nix/store/8gsdifv2q3hnq42v7ddk38nmiagmjd6c-coreutils-8.32/bin:/nix/store/khvalqldk47cx8d54gik9jrqsinzmwng-findutils-4.7.0/bin:/nix/store/6wzkn6gdpj3psqjgbfx858wd3dhanj12-diffutils-3.7/bin:/nix/store/q3ppqi1npx3vnsdlk8hk9s4p3adc4ygp-gnused-4.8/bin:/nix/store/134fdr0yrl4wgrrasxn9d3s8vzcm5lxq-gnugrep-3.6/bin:/nix/store/y9rbfriadb1gq5l8hjm8476cvjjq38ww-gawk-5.1.0/bin:/nix/store/gm4gjb3pkyxyj54kb4fizldvr60cpb2l-gnutar-1.32/bin:/nix/store/svhnwsc7rbzrfcfn0y1hsry1m8yi0y88-gzip-1.10/bin:/nix/store/pj616ldh4sbmqj7ad6dhmfcawfzgqpqf-bzip2-1.0.6.0.1-bin/bin:/nix/store/6mic0pcmp4va0ghx7hn5wl3jl4ll4h2q-gnumake-4.3/bin:/nix/store/4l7wsi6h6283194r6fqy1731qxlagq62-bash-4.4-p23/bin:/nix/store/wav2vx6iaxvkmzcwzwa127p6jri4rqdz-patch-2.7.6/bin:/nix/store/hzvfm203h5argiylhqprnpwznxxbdmj3-xz-5.2.5-bin/bin' /build/source/src/umockdev-wrapper /build/source/build/test-umockdev
--- Listing only the last 100 lines from a long log. ---
# Start of umockdev-testbed tests
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.KTF4V0
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.KTF4V0
ok 1 /umockdev-testbed/empty
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.RPW4V0
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/extkeyboard1
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.RPW4V0
ok 2 /umockdev-testbed/add_devicev
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.W6W4V0
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/extkeyboard1
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.W6W4V0
ok 3 /umockdev-testbed/add_device
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.2XU4V0
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/scribble
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.2XU4V0
ok 4 /umockdev-testbed/add_block_device
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.QXV4V0
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/usb1
# DEBUG: umockdev.vala:1116: parsing device description for /devices/target
# DEBUG: umockdev.vala:1185: creating device /devices/target (subsystem foo)
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/target
# DEBUG: umockdev.vala:1246: create_node_for_device: creating pty device /build/umockdev.QXV4V0/dev/target: got pty /dev/pts/0
# DEBUG: umockdev.vala:1267: create_node_for_device: creating ptymap symlink /build/umockdev.QXV4V0/dev/.ptymap/_dev_pts_0
# DEBUG: umockdev.vala:1116: parsing device description for /devices/other
# DEBUG: umockdev.vala:1185: creating device /devices/other (subsystem foo)
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/other
# DEBUG: umockdev.vala:1246: create_node_for_device: creating pty device /build/umockdev.QXV4V0/dev/other: got pty /dev/pts/1
# DEBUG: umockdev.vala:1267: create_node_for_device: creating ptymap symlink /build/umockdev.QXV4V0/dev/.ptymap/_dev_pts_1
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.QXV4V0
ok 5 /umockdev-testbed/add_device_errors
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.90Z4V0
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/usb1
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/usb1/1-1
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/usb1/1-1/kb1
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.90Z4V0
ok 6 /umockdev-testbed/child_device
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.JQ04V0
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/extkeyboard1
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.JQ04V0
ok 7 /umockdev-testbed/set_attribute
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.KI04V0
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/extkeyboard1
# GLib-GIO-DEBUG: _g_io_module_get_default: Found default implementation local (GLocalVfs) for ?gio-vfs?
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.KI04V0
ok 8 /umockdev-testbed/set_property
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.ODZ4V0
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:1185: creating device /devices/dev1 (subsystem pci)
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/dev1
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev2/subdev1
# DEBUG: umockdev.vala:1185: creating device /devices/dev2/subdev1 (subsystem input)
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/dev2/subdev1
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev2
# DEBUG: umockdev.vala:1185: creating device /devices/dev2 (subsystem hid)
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/dev2
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.ODZ4V0
ok 9 /umockdev-testbed/add_from_string
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.T2Q4V0
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:1309: record_parse_line: >E: SIMPLE_PROP
< does not match anything, failing
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:1309: record_parse_line: >X: SIMPLE_PROP=1
< does not match anything, failing
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:1185: creating device /devices/dev1 (subsystem usb)
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/dev1
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.T2Q4V0
ok 10 /umockdev-testbed/add_from_string_errors
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.LXO4V0
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:1309: record_parse_line: >X: Whatever
< does not match anything, failing
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:1185: creating device /devices/dev1 (subsystem pci)
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/dev1
# DEBUG: umockdev.vala:101: Removing test bed /build/umockdev.LXO4V0
ok 11 /umockdev-testbed/add_from_file
# DEBUG: umockdev.vala:79: Created udev test bed /build/umockdev.01O4V0
# DEBUG: umockdev.vala:1116: parsing device description for /devices/dev1
# DEBUG: umockdev.vala:1185: creating device /devices/dev1 (subsystem pci)
# DEBUG: umockdev.vala:701: umockdev_testbed_uevent: lazily initializing uevent_sender
# DEBUG: umockdev.vala:705: umockdev_testbed_uevent: sending uevent add for device /sys/devices/dev1
Bail out! ERROR:../tests/test-umockdev.c:1090:t_testbed_libc: assertion failed (errno == ENOENT): (9 == 2)
--- stderr ---
**
ERROR:../tests/test-umockdev.c:1090:t_testbed_libc: assertion failed (errno == ENOENT): (9 == 2)
-------

Summary of Failures:

1/7 umockdev / umockdev                       FAIL           0.07s (killed by signal 6 SIGABRT)
1/7 umockdev / umockdev                       FAIL           0.07s (killed by signal 6 SIGABRT)

Ok:                 6
Expected Fail:      0
Fail:               1
Unexpected Pass:    0
Skipped:            0
Timeout:            0

Full log written to /build/source/build/meson-logs/testlog.txt
FAILED: meson-test
/nix/store/n9vj7i7armczjs1x7qzyqhfhzfidrv62-meson-0.56.0/bin/meson test --no-rebuild --print-errorlogs
ninja: build stopped: subcommand failed.
martinpitt commented 3 years ago

@flokli : Interesting, that /umockdev-testbed/libc failure is unrelated to the libusb changes, but some fallout from a recent glibc or possibly kernel upgrade. At this point it'd be best to include NixOS in CI, to make sure that umockdev keeps working there. It's been in NixOS for some time, after all. I'll try to come up with a tests/run-nix script using the official https://hub.docker.com/r/nixos/nix container.

martinpitt commented 3 years ago

@flokli : Hm, I have tried for an hour how, stumbling around nix-env, building a default.nix that uses a local source checkout, etc., and I'm not really getting anywhere. Could you show me the commands to run in a

podman run -it --rm --volume `pwd`:/source:ro docker.io/nixos/nix

container (docker works as well, of course) that will install the build deps and build/test umockdev? I'm happy to massage them into CI, but I need some help with grasping how to do things in nix. Thanks!

jtojnar commented 3 years ago

You can build the package in one of the following ways:

  1. Clone nixpkgs and edit pkgs/development/libraries/umockdev/default.nix (change src and patches keys and add doCheck = true) and then run nix-build -E '(import /nixpkgs-source-path {}).umockdev'.
  2. Download just the default.nix file, edit is as in 1. and run it with latest Nixpkgs using nix-build -E '(import (builtins.fetchTarball { url = "https://github.com/NixOS/nixpkgs/archive/master.tar.gz"; }) {}).callPackage /source/default.nix {}'
  3. Override the attributes on command-line, fetching both the expression and the rest of Nixpkgs, using nix-build -E '(import (builtins.fetchTarball { url = "https://github.com/NixOS/nixpkgs/archive/master.tar.gz"; }) {}).umockdev.overrideAttrs (attrs: { src = /source; patches = []; doCheck = true; })'
martinpitt commented 3 years ago

Thanks @jtojnar! This looks workable, especially solution 3. Note for myself: Add --keep-failed to retain the build dir.

I get a different failure, though:

6/7 umockdev / static-code                    FAIL           0.93s (exit status 127)

Error relocating /tmp/nix-build-umockdev-0.15.2.drv-0/source/build/libumockdev-preload.so.0: __snprintf_chk: symbol not found
Error relocating /tmp/nix-build-umockdev-0.15.2.drv-0/source/build/libumockdev-preload.so.0: __memcpy_chk: symbol not found
Error relocating /tmp/nix-build-umockdev-0.15.2.drv-0/source/build/libumockdev-preload.so.0: __fprintf_chk: symbol not found

This seems related to commit 3cc547f4af7:

# tests/test-static-code 
grep: unrecognized option: text

I attempted to fix that, but it's apparently not working just yet. I'll keep looking into this.

@flokli : FYI, the preCheck patchShebangs hack should be obsolete with commit 701921664a1. I took it out by overriding preCheck = "".

martinpitt commented 3 years ago

The test-static-code failure is weird.. It gets called (unnecessarily, for technical reasons) through umockdev-wrapper, and it seems from the build tree the linker gets upset:

# LD_LIBRARY_PATH='/tmp/nix-build-umockdev-0.15.2.drv-0/source/build' /tmp/nix-build-umockdev-0.15.2.drv-0/source/src/umockdev-wra
pper true
Error relocating /tmp/nix-build-umockdev-0.15.2.drv-0/source/build/libumockdev-preload.so.0: __snprintf_chk: symbol not found
Error relocating /tmp/nix-build-umockdev-0.15.2.drv-0/source/build/libumockdev-preload.so.0: __memcpy_chk: symbol not found
Error relocating /tmp/nix-build-umockdev-0.15.2.drv-0/source/build/libumockdev-preload.so.0: __fprintf_chk: symbol not found

It does seem to link against the right libc:

# /nix/store/7niy0yd0ygv0wa05kl5l46x6fdflpwf1-glibc-2.32-10-bin/bin/ldd /tmp/nix-build-umockdev-0.15.2.drv-0/source/build/libumock
dev-preload.so.0
    linux-vdso.so.1 (0x00007ffcbd253000)
    libdl.so.2 => /nix/store/1yvpgm763b3hvg8q4fzpzmflr5674x4j-glibc-2.32-10/lib/libdl.so.2 (0x00007f89a0e8b000)
    libc.so.6 => /nix/store/1yvpgm763b3hvg8q4fzpzmflr5674x4j-glibc-2.32-10/lib/libc.so.6 (0x00007f89a0ccb000)
    /nix/store/1yvpgm763b3hvg8q4fzpzmflr5674x4j-glibc-2.32-10/lib64/ld-linux-x86-64.so.2 (0x00007f89a0eb1000)

# /nix/store/kcp0y7g1ir4dxq2gqz687i4vb7gqy8s0-binutils-2.31.1/bin/nm -D /nix/store/1yvpgm763b3hvg8q4fzpzmflr5674x4j-glibc-2.32-10/
lib/libc.so.6 | grep memcpy_chk
00000000001043a0 i __memcpy_chk
0000000000105610 T __wmemcpy_chk

I am at loss with this. The nix build env is rather hard to debug, as pretty much nothing is "in the system", which breaks drilling down to invididual build/test steps.

martinpitt commented 3 years ago

Commit 0e60ddbff6f05345f adds a nix test, which succeeds. This hacks around the test-static-code failure by dropping the test from meson.build. Help with fixing this properly would be very much appreciated! But at least that will now keep the general build working, so 0.15.3 should be by and large ok for you?

Thanks @flokli for the report and @jtojnar for your build recipe!

jtojnar commented 3 years ago

Hmm, I am also getting the 9 == 2 error in Nix on Ubuntu but can reproduce the symbols not found in Docker. Not sure if there is any difference other than possibly different sandboxing level. Will try to look into it.

For CI, it might be better to use nixos-unstable branch since it tracks the latest commit from master branch that was built by our CI, where tests pass and binary substitutes for packages are generally available. Unfortunately, it does not yet contain the switch to meson based builds yet. That is also why including the default.nix in the repository might be useful.

jtojnar commented 3 years ago

I could reproduce it in Docker by running the environment in /tmp/nix-build-umockdev-0.15.2.drv-0/source/build/meson-logs/testlog.txt:

$ docker exec -ti zen_gagarin env GI_TYPELIB_PATH='/tmp/nix-build-umockdev-0.15.2.drv-0/source/build:/nix/store/6j415gpqni7cj91xkk52dri9rg40gf21-gobject-introspection-1.66.1/lib/girepository-1.0:/nix/store/qh9f1728pb9ybp677vqbz39pv12z3cx4-libgudev-234/lib/girepository-1.0:/nix/store/6j415gpqni7cj91xkk52dri9rg40gf21-gobject-introspection-1.66.1/lib/girepository-1.0:/nix/store/qh9f1728pb9ybp677vqbz39pv12z3cx4-libgudev-234/lib/girepository-1.0:/nix/store/6j415gpqni7cj91xkk52dri9rg40gf21-gobject-introspection-1.66.1/lib/girepository-1.0:/nix/store/qh9f1728pb9ybp677vqbz39pv12z3cx4-libgudev-234/lib/girepository-1.0' PATH='/tmp/nix-build-umockdev-0.15.2.drv-0/source/build:/nix/store/9zmnxxd2lrfcvzyncsc8c9d0znkxd0wk-gobject-introspection-1.66.1-dev/bin:/nix/store/biv1ds2x8d5ji0yj7qxv44b40xid312g-glib-2.66.3-dev/bin:/nix/store/40aa067kyqc67dff1lzfcslivqx3ymkg-gettext-0.21/bin:/nix/store/lljddzamy684ah9pxzkr80x2qbc0fbg7-glib-2.66.3-bin/bin:/nix/store/w1xyc9wr5lvcakzz1n4q8mhs0v9xp7x5-gtk-doc-1.33.0/bin:/nix/store/crakvb0jk50ap9nczzvdlijds7rddhrk-meson-0.56.0/bin:/nix/store/09mmkj13p52yqlbsn77549qnr4hfjqbp-ninja-1.10.2/bin:/nix/store/d2bnc0h350yz0wlqbizhzb58lhmy1k6j-pkg-config-wrapper-0.29.2/bin:/nix/store/92gqx3fqkmzshikyp1mqx4ds23bz729s-vala-0.48.9/bin:/nix/store/m7080pw0ryjk0jhljp55rq1hd2qy8gki-python3-3.8.6/bin:/nix/store/20jz8krnn4g4iilf9fryzadjifs8pg17-which-2.21/bin:/nix/store/nx19q4zadh0m7j3jw4qq94spv197prfa-usbutils-012/bin:/nix/store/kg1ck8dgi10yqwmm20gi7gx5m3sr5jdq-patchelf-0.12/bin:/nix/store/b96dqbx6pri2xp2xxlq6i269virrdaw6-gcc-wrapper-9.3.0/bin:/nix/store/wmzmnnrj780268ybilmcfyd3grn5qzi6-gcc-9.3.0/bin:/nix/store/7niy0yd0ygv0wa05kl5l46x6fdflpwf1-glibc-2.32-10-bin/bin:/nix/store/8gsdifv2q3hnq42v7ddk38nmiagmjd6c-coreutils-8.32/bin:/nix/store/ip7xkk70anay3k7bp2cr6aqdg0mcdja2-binutils-wrapper-2.31.1/bin:/nix/store/kcp0y7g1ir4dxq2gqz687i4vb7gqy8s0-binutils-2.31.1/bin:/nix/store/7niy0yd0ygv0wa05kl5l46x6fdflpwf1-glibc-2.32-10-bin/bin:/nix/store/8gsdifv2q3hnq42v7ddk38nmiagmjd6c-coreutils-8.32/bin:/nix/store/biv1ds2x8d5ji0yj7qxv44b40xid312g-glib-2.66.3-dev/bin:/nix/store/40aa067kyqc67dff1lzfcslivqx3ymkg-gettext-0.21/bin:/nix/store/lljddzamy684ah9pxzkr80x2qbc0fbg7-glib-2.66.3-bin/bin:/nix/store/n572k0545dyc18vbzczqbrhh7h7rn4x1-systemd-247.2/bin:/nix/store/8gsdifv2q3hnq42v7ddk38nmiagmjd6c-coreutils-8.32/bin:/nix/store/khvalqldk47cx8d54gik9jrqsinzmwng-findutils-4.7.0/bin:/nix/store/6wzkn6gdpj3psqjgbfx858wd3dhanj12-diffutils-3.7/bin:/nix/store/q3ppqi1npx3vnsdlk8hk9s4p3adc4ygp-gnused-4.8/bin:/nix/store/134fdr0yrl4wgrrasxn9d3s8vzcm5lxq-gnugrep-3.6/bin:/nix/store/y9rbfriadb1gq5l8hjm8476cvjjq38ww-gawk-5.1.0/bin:/nix/store/gm4gjb3pkyxyj54kb4fizldvr60cpb2l-gnutar-1.32/bin:/nix/store/svhnwsc7rbzrfcfn0y1hsry1m8yi0y88-gzip-1.10/bin:/nix/store/pj616ldh4sbmqj7ad6dhmfcawfzgqpqf-bzip2-1.0.6.0.1-bin/bin:/nix/store/6mic0pcmp4va0ghx7hn5wl3jl4ll4h2q-gnumake-4.3/bin:/nix/store/4l7wsi6h6283194r6fqy1731qxlagq62-bash-4.4-p23/bin:/nix/store/wav2vx6iaxvkmzcwzwa127p6jri4rqdz-patch-2.7.6/bin:/nix/store/hzvfm203h5argiylhqprnpwznxxbdmj3-xz-5.2.5-bin/bin' MALLOC_CHECK_='3' G_DEBUG='fatal-warnings,fatal-criticals,gc-friendly' LD_LIBRARY_PATH='/tmp/nix-build-umockdev-0.15.2.drv-0/source/build' TOP_SRCDIR='/tmp/nix-build-umockdev-0.15.2.drv-0/source' /tmp/nix-build-umockdev-0.15.2.drv-0/source/src/umockdev-wrapper /tmp/nix-build-umockdev-0.15.2.drv-0/source/tests/test-static-code
Error relocating /tmp/nix-build-umockdev-0.15.2.drv-0/source/build/libumockdev-preload.so.0: __snprintf_chk: symbol not found
Error relocating /tmp/nix-build-umockdev-0.15.2.drv-0/source/build/libumockdev-preload.so.0: __memcpy_chk: symbol not found
Error relocating /tmp/nix-build-umockdev-0.15.2.drv-0/source/build/libumockdev-preload.so.0: __fprintf_chk: symbol not found

It looks like it does not actually seem to be using the correct ld.so:

$ docker exec -ti zen_gagarin ldd /tmp/nix-build-umockdev-0.15.2.drv-0/source/build/libumockdev-preload.so.0
    /lib/ld-musl-x86_64.so.1 (0x7fad1b57c000)
    libdl.so.2 => /lib/ld-musl-x86_64.so.1 (0x7fad1b57c000)
    libc.so.6 => /lib/ld-musl-x86_64.so.1 (0x7fad1b57c000)
$ docker exec -ti zen_gagarin nix-shell -I nixpkgs=channel:nixos-unstable -p elfutils --run "readelf -d /tmp/nix-build-umockdev-0.15.2.drv-0/source/build/libumockdev-preload.so.0"

Dynamic section at offset 0x10b30 contains 30 entries:
  Tag        Type                         Name/Value
 0x0000000000000001 (NEEDED)             Shared library: [libdl.so.2]
 0x0000000000000001 (NEEDED)             Shared library: [libc.so.6]
 0x000000000000000e (SONAME)             Library soname: [libumockdev-preload.so.0]
 0x000000000000001d (RUNPATH)            Library runpath: [/nix/store/9k8il9x354dx6mvqrj0s7ndi7pz5pc8z-umockdev-0.15.2/lib64:/nix/store/9k8il9x354dx6mvqrj0s7ndi7pz5pc8z-umockdev-0.15.2/lib:/nix/store/1yvpgm763b3hvg8q4fzpzmflr5674x4j-glibc-2.32-10/lib:/nix/store/isy60my0ijjzh49rscgdb1i2457nf7lp-gcc-9.3.0-lib/lib]
 0x000000000000000c (INIT)               0x4000
 0x000000000000000d (FINI)               0xbef4
 0x0000000000000019 (INIT_ARRAY)         0x11b18
 0x000000000000001b (INIT_ARRAYSZ)       16 (bytes)
 0x000000000000001a (FINI_ARRAY)         0x11b28
 0x000000000000001c (FINI_ARRAYSZ)       8 (bytes)
 0x0000000000000004 (HASH)               0x200
 0x000000006ffffef5 (GNU_HASH)           0x590
 0x0000000000000005 (STRTAB)             0x1408
 0x0000000000000006 (SYMTAB)             0x808
 0x000000000000000a (STRSZ)              1684 (bytes)
 0x000000000000000b (SYMENT)             24 (bytes)
 0x0000000000000003 (PLTGOT)             0x11d50
 0x0000000000000002 (PLTRELSZ)           1632 (bytes)
 0x0000000000000014 (PLTREL)             RELA
 0x0000000000000017 (JMPREL)             0x2c80
 0x0000000000000007 (RELA)               0x1c30
 0x0000000000000008 (RELASZ)             4176 (bytes)
 0x0000000000000009 (RELAENT)            24 (bytes)
 0x000000000000001e (FLAGS)              BIND_NOW
 0x000000006ffffffb (FLAGS_1)            Flags: NOW
 0x000000006ffffffe (VERNEED)            0x1ba0
 0x000000006fffffff (VERNEEDNUM)         2
 0x000000006ffffff0 (VERSYM)             0x1a9c
 0x000000006ffffff9 (RELACOUNT)          158
 0x0000000000000000 (NULL)               0x0
flokli commented 3 years ago

The nixos/nix docker image isn't super pure, IIRC the Nix sandbox is disabled, as the seccomp stuff it does doesn't work inside docker. musl leaking in seems to suggest that.

If this targets github actions, it's probably easier to use https://github.com/marketplace/actions/install-nix (which should have the sandbox enabled).

martinpitt commented 3 years ago

"musl leaking in" does sound like a good hint.. It would explain both the *_chk symbol not found errors and probably also the 9 == 2 test failure; the latter effectively checks that openat( open("/run", O_RDONLY | O_DIRECTORY), "sys", O_RDONLY) returns ENOENT (2), whereas in your environment it returns EBADF (9), which means that the first O_DIRECTORY.

umockdev does work with musl in general, I fixed it up not too long ago for Alpine (which also runs in CI). But apparently it somehow gets linked to glibc and musl at the same time?

@flokli: I do run the tests in GitHub actions right now, but I don't want to use that install-nix actions -- it would (1) mean that it's not possible to run and investigate the test locally, and (2) make it hard to move CI someplace else (I just moved it from Travis). In other words, I only support OSes that can be run in a container. That can be a privileged podman or docker container, so if there is any way to enable the sandboxing with these, I'm all ears.

martinpitt commented 3 years ago

@jtojnar : I tried to move to url = "https://github.com/NixOS/nixpkgs/archive/nixos-unstable.tar.gz", but that fails to build early:

configuring
no configure script, doing nothing
building
no Makefile, doing nothing
running tests
no Makefile or custom checkPhase, doing nothing
glibPreInstallPhase
glibPreInstallPhase
installing
install flags: SHELL=/nix/store/4l7wsi6h6283194r6fqy1731qxlagq62-bash-4.4-p23/bin/bash gsettingsschemadir=/nix/store/f6rl4byksifrpvgzi7lrar9ng3qpz6n5-umockdev-0.13.1/share/gsettings-schemas/umockdev-0.13.1/glib-2.0/schemas/ gsettingsschemadir=/nix/store/f6rl4byksifrpvgzi7lrar9ng3qpz6n5-umockdev-0.13.1/share/gsettings-schemas/umockdev-0.13.1/glib-2.0/schemas/ pkgconfigdir=/nix/store/4m4k9hz79k9sy6cd0a3zc0idsqc99q72-umockdev-0.13.1-dev/lib/pkgconfig m4datadir=/nix/store/4m4k9hz79k9sy6cd0a3zc0idsqc99q72-umockdev-0.13.1-dev/share/aclocal aclocaldir=/nix/store/4m4k9hz79k9sy6cd0a3zc0idsqc99q72-umockdev-0.13.1-dev/share/aclocal install
make: *** No rule to make target 'install'.  Stop.

in other words, this is still the old autotools build system, and https://github.com/NixOS/nixpkgs/blob/nixos-unstable/pkgs/development/libraries/umockdev/default.nix is indeed much older than https://github.com/NixOS/nixpkgs/blob/master/pkgs/development/libraries/umockdev/default.nix . So it seems the other way around, master is newer than unstable, and thus a better CI target?

jtojnar commented 3 years ago

"musl leaking in" does sound like a good hint.. It would explain both the *_chk symbol not found errors and probably also the 9 == 2 test failure

Well, the Nix builds outside of Docker are sandboxed so the musl cannot be an issue there.

in other words, this is still the old autotools build system, and NixOS/nixpkgs@nixos-unstable/pkgs/development/libraries/umockdev/default.nix is indeed much older than NixOS/nixpkgs@master/pkgs/development/libraries/umockdev/default.nix . So it seems the other way around, master is newer than unstable, and thus a better CI target?

Yeah, that's what I meant by it "does not yet contain the switch to meson based builds". The issue with using master is that it might not have prebuilt binaries available yet, depending on how busy our infrastructure is. nixos-unstable will be already built and tested (but sometimes is several days behind). Including the umockdev package as mentioned in 2., and only using Nixpkgs for dependencies might be more stable.

I only support OSes that can be run in a container. That can be a privileged podman or docker container, so if there is any way to enable the sandboxing with these, I'm all ears.

See https://github.com/NixOS/docker#limitations for the necessary configuration.

flokli commented 3 years ago

@flokli: I do run the tests in GitHub actions right now, but I don't want to use that install-nix actions -- it would (1) mean that it's not possible to run and investigate the test locally, and (2) make it hard to move CI someplace else (I just moved it from Travis). In other words, I only support OSes that can be run in a container. That can be a privileged podman or docker container, so if there is any way to enable the sandboxing with these, I'm all ears.

Yes, the sandbox can be enabled, if you can start a privileged containers: https://github.com/NixOS/docker#limitations

I proposed using the install nix action because then Nix is installed on the runner directly (for that run) and you don't need to mess with wrapping it in docker/podman in CI at all. Locally reproducing can be done on systems with Nix installed, or doing the privileged container dance there.

martinpitt commented 3 years ago

A-ha! I enabled sandboxing; locally for a developer, running an user podman container with --privileged is no big deal, and it totally doesn't matter on CI either. This indeed fixes the test-static-code failure, and locally I now get these two failures:

1/7 umockdev / umockdev                       FAIL           1.13s (killed by signal 6 SIGABRT)
Bail out! ERROR:../tests/test-umockdev.c:1090:t_testbed_libc: assertion failed (errno == ENOENT): (9 == 2)

2/7 umockdev:fails-valgrind / umockdev-vala   FAIL           0.24s (killed by signal 5 SIGTRAP)
Bail out! FATAL-CRITICAL: file test-umockdev-vala.p/tests/test-umockdev-vala.c: line 515: uncaught error: Error opening directory ?sys?: No such file or directory (g-file-error-quark, 4)

The exact same errors happen in GitHub CI. Does that faithfully reproduce what you are seeing?

Note, I kept this change in a "nixos" branch for now, as I don't want to land changes in master which break the tests.

martinpitt commented 3 years ago

How do you debug failures like this? I. e. after a failing nix-build --keep-failed with sandboxing, how can I "enter" the built sandbox? A naïve

cd /tmp/nix-build-umockdev-0.15.2.drv-0/source/build/
# meson test
/bin/sh: meson: not found

obviously does not work, and LD_LIBRARY_PATH=. ./test-umockdev immediately fails as well (unsurprisingly).

https://github.com/NixOS/nix/issues/1147 and nix-shell sound promising, but I can't put it together..

jtojnar commented 3 years ago

The /tmp/nix-build-umockdev-0.15.2.drv-0/ should contain env-vars file with the environment. Replacing the nix-build program for nix-shell in the commands above should also put you into the environment (but note that unlike nix-build it only sandboxes the environment, it does not put you into a chroot).

Also, I am experiencing just the 9 == 2 error, umockdev-vala passes for me in Nix sandbox outside of Docker (I can reproduce it in Docker) so that might be something else (perhaps sandboxing works differently in container, it mentions sys in the message).

flokli commented 3 years ago

How do you debug failures like this? I. e. after a failing nix-build --keep-failed with sandboxing, how can I "enter" the built sandbox?

You might be able to use breakpointHook (which will "pause" the build on a failure, and allow you to enter the build environment via cntr) - see https://discourse.nixos.org/t/debug-a-failed-derivation-with-breakpointhook-and-cntr/8669.

I never tried this through podman, but it might work :-)

martinpitt commented 3 years ago

Thanks! breakpointHook sounds like what I really want, but it doesn't work:

# nix-build --keep-failed -E '(import (builtins.fetchTarball { url = "https://gith
ub.com/NixOS/nixpkgs/archive/master.tar.gz"; }) {}).umockdev.overrideAttrs (attrs: { src = /sour
ce; patches = []; preCheck = ""; doCheck = true; nativeBuildInputs = attrs.nativeBuildInputs ++ 
[ breakpointHook ]; })'
error: undefined variable 'breakpointHook' at (string):1:247

I tried to replace nix-buid with nix-shell, and that downloads/installs the build dependencies and such. I can do the usual cd /source; meson setup /tmp/dbg --buildtype debug, and build/test, but that again falls into the __memcpy_chk failures, and does not reproduce the sandboxed failures. So it seems I somehow need the breakpointHook thing.

flokli commented 3 years ago

@martinpitt breakpointHook is accessible in pkgs.

This probably has exceeded the amount of characters I'd feel comfortable with having inline, but if you create a default.nix:

let
  pkgs = (import (builtins.fetchTarball { url = "https://github.com/NixOS/nixpkgs/archive/master.tar.gz"; }) {});
in pkgs.umockdev.overrideAttrs (attrs: {
  src = /source;
  patches = [];
  preCheck = "";
  doCheck = true;
  nativeBuildInputs = attrs.nativeBuildInputs ++ [ pkgs.breakpointHook ];
})

and run nix-build default.nix, that should get you what you want.

Running nix-shell on the above expression will drop you in an environment with the build dependencies available (and setup hooks installed to set various environment variables), but won't bring you inside a sandbox.

jtojnar commented 3 years ago

umockdev should be pkgs.umockdev in the above expression – in the original expression, we are accessing umockdev directly from the imported Nixpkgs but here we want to use pkgs multiple times so we factored it out into a variable.

martinpitt commented 3 years ago

I welcome having a default.nix file, it's much clearer than cramming it into a single command indeed. The version above fails with

error: undefined variable 'umockdev' at /source/tests/default.nix:3:4

I'm googling around for similar recipes (it's hard to find one), as to me the syntax is not quite intuitive. But as this introduces a pkgs namespace, I tried with in pkgs.umockdev.overrideAttrs ..., and that seems to work. Without the breakpoint I get the same failures, and with the breakpoint I can run the cntr attach command.

It lands in the wrong directory, though, so that all values in env-vars and the actual environment are wrong:

localhost:/var/lib/cntr$ pwd
/var/lib/cntr
localhost:/var/lib/cntr$ ls -l
total 32
drwxr-xr-x    2 nobody   nogroup       4096 Dec 28 15:29 bin
drwx------    6 nixbld   nixbld        4096 Dec 28 15:30 build
drwxr-xr-x    4 nobody   nogroup       4096 Dec 28 15:29 dev
drwxr-xr-x    2 nobody   nogroup       4096 Dec 28 15:29 etc
drwxr-xr-x    3 nobody   nogroup       4096 Dec 28 15:29 nix
dr-xr-xr-x  272 nobody   nogroup          0 Dec 28 15:29 proc
drwxrwxrwt    6 nobody   nogroup       4096 Dec 28 15:32 tmp
drwxr-xr-x    3 nobody   nogroup       4096 Dec 28 15:30 var
localhost:/var/lib/cntr$ echo $TEMPDIR
/build
localhost:/var/lib/cntr$ ls -l /build
ls: /build: No such file or directory
localhost:/var/lib/cntr$

I.e. it seems it should really chroot into the /var/lib/cntr/ subdirectory (there is even a bin/sh), but I don't see an option for this. Nor does cntr attach -t command --effective-user root work (I'm still nixbld in the container and thus can't chroot again).

flokli commented 3 years ago

IIRC, cntr won't bring you the exact same sandbox - the idea is mostly be able to poke around with the build outputs and have some of the environment variables set, but you "bring your own, more powerful userland" with you. Or @Mic92, did I miss something?

martinpitt commented 3 years ago

Hm, I still don't understand this -- there must be some easy way to get a shell in the very build environment that nix-build uses to invoke the build. Anything else would make debugging insanely difficult. I'm sure that works somehow, I just don't know it yet.

If cntr somehow doesn't work properly in a docker environment, and that works in a plain VM, I can also look at that. These are much less comfortable, as it is much more difficult to create them, share files with your host, deploy them in CI etc., but maybe the sandboxing just breaks in containers. Is there some kind of "nix developer" VM akin to docker.io/nixos/nix which is known to work?

martinpitt commented 3 years ago

poke around with the build outputs

I did try that, but it is rather difficult with all the $PATH, $LD_LIBRARY_PATH, $TMPDIR etc. being wrong. You can't even do . env-vars, as nix' default shell does not understand the syntax of this (declare -x) (otherwise I could vi the file, prepend the /var/lib/cntr prefix, and source it again). There seems to be a lot of impedance mismatches in all these parts :cry:

flokli commented 3 years ago

Sorry for this being so frustrating. Probably the easiest way is to either use the Nix installer on most other distributions, or one of the NixOS images shipped on the website: https://nixos.org/download.html

martinpitt commented 3 years ago

I started a fedora 33 VM, and ran (as user):

curl -L https://nixos.org/nix/install | sh
. ~/.nix-profile/etc/profile.d/nix.sh

nix-env -i git
nix-env -i cntr
git clone -b nixos https://github.com/martinpitt/umockdev.git
cat <<EOG > ~/default.nix
let pkgs = (import (builtins.fetchTarball { url = "https://github.com/NixOS/nixpkgs/archive/master.tar.gz"; }) {});

in pkgs.umockdev.overrideAttrs (attrs: {
  src = /home/admin/umockdev;
  patches = [];
  preCheck = "";
  doCheck = true;
  nativeBuildInputs = attrs.nativeBuildInputs ++ [ ];
})
EOG
nix-build  ~/default.nix

This reproduces exactly the failures that I see in the container.

When I add pkgs.breakpointHook to the nativeBuildInputs, I get a similar cntr command, but trying to run that fails:

$ cntr attach -t command cntr-/nix/store/5x9qjnnyzlc6ra99hgggv1swcnqyf6kz-umockdev-0.15.2
failed to setup /.cntr: failed to create setcap executable: Failed set file capability CAP_SYS_CHROOT on /tmp/cntr.XSt8UM/cntr-exec: setxattr failed: EPERM: Operation not permitted

I can't run it through sudo either, as all of these commands are specific to my admin user.

I also tried to run the whole nix setup as user root, but that fails also:

# curl -L https://nixos.org/nix/install | sh
[...]
copying Nix to /nix/store......................................
warning: the group 'nixbld' specified in 'build-users-group' does not exist
warning: the group 'nixbld' specified in 'build-users-group' does not exist
installing 'nix-2.3.10'
error: the group 'nixbld' specified in 'build-users-group' does not exist
/tmp/nix-binary-tarball-unpack.mExr62GETn/unpack/nix-2.3.10-x86_64-linux/install: unable to install Nix into your default profile

So I'm afraid I'm still none the wiser -- I really need some way to drill down into the test, in an interactive shell, with iterating meson, strace, gdb, etc. It seems that the behaviour in a VM is not any different to a container.

martinpitt commented 3 years ago

I prodded around a bit by hacking the source (system("ls -l") style) and iterating nix-build ~/default.nix. I figured out the reason for the 9 != 2 error code, and fixed it in commit 7719fefcf72ad898cb6ca26a1c4c71fb25358af8 . That was quite shallow.

test-umockdev still has one subsequent failure, though, in the lsusb test. With some debugging:

------ out: -------

Bus 000 Device 000: ID 04a9:31c0  
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               2.00
  bDeviceClass            0 
  bDeviceSubClass         0 
  bDeviceProtocol         0 
  bMaxPacketSize0        64
  idVendor           0x04a9 
[...]
------ err: ------
Couldn't open device, some information will be missing

-----
Bail out! ERROR:../tests/test-umockdev.c:1139:t_testbed_usb_lsusb: assertion failed: (g_str_has_prefix(out, "\nBus 001 Device 001: ID 04a9:31c0"))

Debugging this "blindly" is just too cumbersome, so I hacked the test to be a bit more lenient on NixOS for the time being. At least all the other tests can run then, and we prevent further regressions.

That leaves the test-umockdev-vala failure. That fails exactly here, i.e. relative paths into the trapped /sys are not working. Everything before (absolute paths to trapped /sys) works fine. This is relatively new, from commit 946f3dd144365. The reason is again that the NixOS sandbox does not actually have /sys, so that the realpath() call fails. I fixed that in commit 5b97ebdc4ec861d6493a909b0dba85cd502bac2d.

With these changes, the nix tests succeed, so I landed that branch on master.

@flokli, can you please check if current master now works alright for you? If so, I'm happy to publish a new release, and then you can clean up the patchShebangs and re-enable tests.

I'd still like to figure out what is going wrong in t_testbed_usb_lsusb, but for that I really need an interactive shell.

flokli commented 3 years ago

@martinpitt wow, thanks for being so persistent despite the bad debuggability. I'll try to build it on that commit and will report back.

lsusb not being able to reach "real" usb devices should be expected in a sandbox environment, shouldn't it?

There's probably not much documentation about it, but Nix does set up some seccomp filters here and the rest of the sandbox environment setup, including filesystem mounts happens here.

flokli commented 3 years ago

I confirmed I'm able to build and run tests in 71014c2b6de49cc90c246cb0709b1126aec073b8 without any patches on top, in the sandbox, see https://github.com/NixOS/nixpkgs/pull/108317 for the PR.

martinpitt commented 3 years ago

@flokli: That lsusb test case tests simulated devices. It could still be some weird side effect of the machine not having a real /sys , but that's a bit hard to debug. That nixpkgs PR looks pleasantly green, so that seems good enough? I'll make a 0.15.4 then. Thanks for your help!