TypeError: argument of type 'NoneType' is not iterable

[mweinelt]

Bisect stopped two steps in with an exception.

❯ extra-bisect start HEAD e398b1b319c4ec436e7264c09961a3ba19a0e238
Bisecting: 129 revisions left to test after this (roughly 7 steps)
[6ed25880d2d8209a6f11bac1336e40380d1d4165] python3Packages.sphinx-jinja: 1.4.0 -> 2.0.1
❯ extra-bisect run nix-build-status --failure-line "FAILED tests/generic/test_finalize.py::test_binops" python3.pkgs.pandas
$ bisect-env nix-build-status --failure-line 'FAILED tests/generic/test_finalize.py::test_binops' python3.pkgs.pandas
Querying status of /nix/store/l0yan2cpa1bxrblkchnshzw9knryq7hw-python3.9-pandas-1.4.1.drv.
Build status: success
bisect: good
Previous HEAD position was 6ed25880d2d python3Packages.sphinx-jinja: 1.4.0 -> 2.0.1
HEAD is now at 7de7b57c6a3 lookatme: fix tests
$ bisect-env nix-build-status --failure-line 'FAILED tests/generic/test_finalize.py::test_binops' python3.pkgs.pandas
Querying status of /nix/store/v4pj7g2an6zhj0hj5bd3j3dis13icqrd-python3.9-pandas-1.4.1.drv.
error: build of '/nix/store/v4pj7g2an6zhj0hj5bd3j3dis13icqrd-python3.9-pandas-1.4.1.drv' on 'ssh://root@meduna' failed: builder for '/nix/store/v4pj7g2an6zhj0hj5bd3j3dis13icqrd-python3.9-pandas-1.4.1.drv' failed with exit code 1
error: error: builder for '/nix/store/v4pj7g2an6zhj0hj5bd3j3dis13icqrd-python3.9-pandas-1.4.1.drv' failed with exit code 1;
              last 10 log lines:
              > FAILED tests/generic/test_finalize.py::test_binops[mod-args0-right]
              > FAILED tests/generic/test_finalize.py::test_binops[mod-args4-right]
              > FAILED tests/generic/test_finalize.py::test_binops[rmod-args0-right]
              > FAILED tests/generic/test_finalize.py::test_binops[rmod-args4-right]
              > FAILED tests/generic/test_finalize.py::test_binops[pow-args0-right]
              > FAILED tests/generic/test_finalize.py::test_binops[pow-args4-right]
              > FAILED tests/generic/test_finalize.py::test_binops[rpow-args0-right]
              > FAILED tests/generic/test_finalize.py::test_binops[rpow-args4-right]
              > = 28 failed, 98861 passed, 7632 skipped, 49944 deselected, 693 xfailed, 2 xpassed, 164 warnings in 8253.66s (2:17:33) =
              > builder for '/nix/store/v4pj7g2an6zhj0hj5bd3j3dis13icqrd-python3.9-pandas-1.4.1.drv' failed with exit code 1
              For full logs, run 'nix log /nix/store/v4pj7g2an6zhj0hj5bd3j3dis13icqrd-python3.9-pandas-1.4.1.drv'.
error: build of '/nix/store/v4pj7g2an6zhj0hj5bd3j3dis13icqrd-python3.9-pandas-1.4.1.drv' on 'ssh://root@meduna' failed: builder for '/nix/store/v4pj7g2an6zhj0hj5bd3j3dis13icqrd-python3.9-pandas-1.4.1.drv' failed with exit code 1
error: error: builder for '/nix/store/v4pj7g2an6zhj0hj5bd3j3dis13icqrd-python3.9-pandas-1.4.1.drv' failed with exit code 1;
              last 10 log lines:
              > FAILED tests/generic/test_finalize.py::test_binops[mod-args0-right]
              > FAILED tests/generic/test_finalize.py::test_binops[mod-args4-right]
              > FAILED tests/generic/test_finalize.py::test_binops[rmod-args0-right]
              > FAILED tests/generic/test_finalize.py::test_binops[rmod-args4-right]
              > FAILED tests/generic/test_finalize.py::test_binops[pow-args0-right]
              > FAILED tests/generic/test_finalize.py::test_binops[pow-args4-right]
              > FAILED tests/generic/test_finalize.py::test_binops[rpow-args0-right]
              > FAILED tests/generic/test_finalize.py::test_binops[rpow-args4-right]
              > = 28 failed, 98862 passed, 7632 skipped, 49944 deselected, 692 xfailed, 2 xpassed, 164 warnings in 4955.67s (1:22:35) =
              > builder for '/nix/store/v4pj7g2an6zhj0hj5bd3j3dis13icqrd-python3.9-pandas-1.4.1.drv' failed with exit code 1
              For full logs, run 'nix log /nix/store/v4pj7g2an6zhj0hj5bd3j3dis13icqrd-python3.9-pandas-1.4.1.drv'.
Traceback (most recent call last):
  File "/nix/store/dn3xmqdmrp42sbhfvrcyzs0rc2m180lr-nix-bisect-0.4.1/bin/.nix-build-status-wrapped", line 9, in <module>
    sys.exit(_main())
  File "/nix/store/dn3xmqdmrp42sbhfvrcyzs0rc2m180lr-nix-bisect-0.4.1/lib/python3.9/site-packages/nix_bisect/build_status.py", line 184, in _main
    status = build_status(
  File "/nix/store/dn3xmqdmrp42sbhfvrcyzs0rc2m180lr-nix-bisect-0.4.1/lib/python3.9/site-packages/nix_bisect/build_status.py", line 57, in build_status
    if failure_line is None or drv.log_contains(failure_line):
  File "/nix/store/dn3xmqdmrp42sbhfvrcyzs0rc2m180lr-nix-bisect-0.4.1/lib/python3.9/site-packages/nix_bisect/derivation.py", line 79, in log_contains
    return nix.log_contains(self.drv, line) == "yes"
  File "/nix/store/dn3xmqdmrp42sbhfvrcyzs0rc2m180lr-nix-bisect-0.4.1/lib/python3.9/site-packages/nix_bisect/nix.py", line 258, in log_contains
    if phrase in log_content:
TypeError: argument of type 'NoneType' is not iterable

[andersk]

There are at least three problems here:

1. Because we use pexpect rather than subprocess to run nix in a TTY, nix prints terminal color escape sequences, which we then assume are part of the derivation name; we end up calling something like nix.log('\x1b[35;1m/nix/store/6sc0gb9lbw10kwzm3dk6qw3jj868cpgy-yaru-22.04.3.1.drv\x1b[0m').

2. Even after suppressing the colors with export NO_COLOR=1, nix.log('/nix/store/6sc0gb9lbw10kwzm3dk6qw3jj868cpgy-yaru-22.04.3.1.drv') still invokes an invalid nix command.

   $ nix log -f. /nix/store/6sc0gb9lbw10kwzm3dk6qw3jj868cpgy-yaru-22.04.3.1.drv
   error: attribute '/nix/store/6sc0gb9lbw10kwzm3dk6qw3jj868cpgy-yaru-22' in selection path '/nix/store/6sc0gb9lbw10kwzm3dk6qw3jj868cpgy-yaru-22.04.3.1.drv' not found

3. nix.log() swallows errors from the child process and converts them to None, but its callers aren’t prepared to handle None.

[timokau]

Hi,

I wrote about the current status of nix-bisect here. Thanks @mweinelt fort the bug report and @andersk for the analysis. At this point I'm not sure when/if I will work on this, but pull requests are welcome.