search

amoffat / sh

Python process launching
https://sh.readthedocs.io/en/latest/
MIT License
6.98k stars 506 forks source link

Is test_general_signal timing sensitive? #684

Closed SuperSandro2000 closed 1 year ago

SuperSandro2000 commented 1 year ago

I am building and running tests of sh on nixpkgs on a high load machine and was wondering if it is possible that the following test failure is caused by a timing issue:

Sourcing python-remove-tests-dir-hook
Sourcing python-catch-conflicts-hook.sh
Sourcing python-remove-bin-bytecode-hook.sh
Sourcing pip-build-hook
Using pipBuildPhase
Using pipShellHook
Sourcing pip-install-hook
Using pipInstallPhase
Sourcing python-imports-check-hook.sh
Using pythonImportsCheckPhase
Sourcing python-namespaces-hook
Sourcing python-catch-conflicts-hook.sh
Sourcing pytest-check-hook
Using pytestCheckPhase
unpacking sources
unpacking source archive /nix/store/v6hbjcc5ay3694bg19zjbhrn00f7k2rj-source
source root is source
setting SOURCE_DATE_EPOCH to timestamp 315619200 of file source/tox.ini
patching sources
configuring
no configure script, doing nothing
building
Executing pipBuildPhase
Creating a wheel...
WARNING: The directory '/homeless-shelter/.cache/pip' or its parent directory is not owned or is not writable by the current user. The cache has been disabled. Check the permissions and owner of that directory. If executing pip with sudo, you should use sudo's -H flag.
Processing /build/source
  Running command Preparing metadata (pyproject.toml)
  Preparing metadata (pyproject.toml) ... done
Building wheels for collected packages: sh
  Running command Building wheel for sh (pyproject.toml)
  Building wheel for sh (pyproject.toml) ... done
  Created wheel for sh: filename=sh-2.0.2-py3-none-any.whl size=38306 sha256=a8999ec9f4a529fcdabf23c8f1c1c3601214e1321ea6e315e1e5de16518f3b68
  Stored in directory: /build/pip-ephem-wheel-cache-dqfr9hiu/wheels/79/4b/9b/fc24941d75fdb959a71ee80195b2c89d6ae9389f9f0f80fb22
Successfully built sh
Finished creating a wheel...
Finished executing pipBuildPhase
installing
Executing pipInstallPhase
/build/source/dist /build/source
Processing ./sh-2.0.2-py3-none-any.whl
Installing collected packages: sh
Successfully installed sh-2.0.2
/build/source
Finished executing pipInstallPhase
pythonOutputDistPhase
Executing pythonOutputDistPhase
Finished executing pythonOutputDistPhase
post-installation fixup
shrinking RPATHs of ELF executables and libraries in /nix/store/dfqsl7x199hx8icr0q08fhkc9gwm4vb6-python3.10-sh-2.0.2
checking for references to /build/ in /nix/store/dfqsl7x199hx8icr0q08fhkc9gwm4vb6-python3.10-sh-2.0.2...
patching script interpreter paths in /nix/store/dfqsl7x199hx8icr0q08fhkc9gwm4vb6-python3.10-sh-2.0.2
stripping (with command strip and flags -S -p) in  /nix/store/dfqsl7x199hx8icr0q08fhkc9gwm4vb6-python3.10-sh-2.0.2/lib
shrinking RPATHs of ELF executables and libraries in /nix/store/zv50w2zg49nimk3mcpa9hs6bxdmcn867-python3.10-sh-2.0.2-dist
checking for references to /build/ in /nix/store/zv50w2zg49nimk3mcpa9hs6bxdmcn867-python3.10-sh-2.0.2-dist...
patching script interpreter paths in /nix/store/zv50w2zg49nimk3mcpa9hs6bxdmcn867-python3.10-sh-2.0.2-dist
Executing pythonRemoveTestsDir
Finished executing pythonRemoveTestsDir
running install tests
no Makefile or custom installCheckPhase, doing nothing
pythonCatchConflictsPhase
pythonRemoveBinBytecodePhase
pythonImportsCheckPhase
Executing pythonImportsCheckPhase
pytestCheckPhase
Executing pytestCheckPhase
============================= test session starts ==============================
platform linux -- Python 3.10.11, pytest-7.2.1, pluggy-1.0.0
rootdir: /build/source
collected 178 items / 4 deselected / 174 selected                              

tests/test.py ...F...................................................... [ 33%]
................................................s....................... [ 74%]
............................................                             [100%]

=================================== FAILURES ===================================
_____________________ FunctionalTests.test_general_signal ______________________

self = <tests.test.FunctionalTests testMethod=test_general_signal>

        def test_general_signal(self):
            from signal import SIGINT

            py = create_tmp_test(
                """
    import sys
    import os
    import time
    import signal

    i = 0
    def sig_handler(sig, frame):
        global i
        i = 42

    signal.signal(signal.SIGINT, sig_handler)

    for _ in range(6):
        print(i)
        i += 1
        sys.stdout.flush()
        time.sleep(1)
    """
            )

            stdout = []

            def agg(line, stdin, process):
                line = line.strip()
                stdout.append(line)
                if line == "3":
                    process.signal(SIGINT)
                    return True

            p = python(py.name, _out=agg, _tee=True)
            p.wait()

            self.assertEqual(p.process.exit_code, 0)
>           self.assertEqual(str(p), "0\n1\n2\n3\n42\n43\n")
E           AssertionError: '0\n1\n2\n3\n43\n44\n' != '0\n1\n2\n3\n42\n43\n'
E             0
E             1
E             2
E             3
E           + 42
E             43
E           - 44

tests/test.py:1672: AssertionError
=============================== warnings summary ===============================
tests/test.py::FunctionalTests::test_unchecked_pipeline_failure
  /nix/store/agawdr80hxrmhm2gcqvzs6z4s06qabby-python3.10-pytest-7.2.1/lib/python3.10/site-packages/_pytest/threadexception.py:73: PytestUnhandledThreadExceptionWarning: Exception in thread background thread for pid 290

  Traceback (most recent call last):
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
      self.run()
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 953, in run
      self._target(*self._args, **self._kwargs)
    File "/build/source/sh.py", line 1654, in wrap
      fn(*rgs, **kwargs)
    File "/build/source/sh.py", line 2656, in background_thread
      handle_exit_code(exit_code)
    File "/build/source/sh.py", line 2347, in fn
      return self.command.handle_command_exit_code(exit_code)
    File "/build/source/sh.py", line 838, in handle_command_exit_code
      raise exc
  sh.ErrorReturnCode_2: 

    RAN: /nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/bin/python3.10 /build/tmpp6a_vkid

    STDOUT:

    STDERR:

    warnings.warn(pytest.PytestUnhandledThreadExceptionWarning(msg))

tests/test.py::FunctionalTests::test_exit_code_with_hasattr
  /nix/store/agawdr80hxrmhm2gcqvzs6z4s06qabby-python3.10-pytest-7.2.1/lib/python3.10/site-packages/_pytest/threadexception.py:73: PytestUnhandledThreadExceptionWarning: Exception in thread background thread for pid 452

  Traceback (most recent call last):
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
      self.run()
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 953, in run
      self._target(*self._args, **self._kwargs)
    File "/build/source/sh.py", line 1654, in wrap
      fn(*rgs, **kwargs)
    File "/build/source/sh.py", line 2656, in background_thread
      handle_exit_code(exit_code)
    File "/build/source/sh.py", line 2347, in fn
      return self.command.handle_command_exit_code(exit_code)
    File "/build/source/sh.py", line 838, in handle_command_exit_code
      raise exc
  sh.ErrorReturnCode_3: 

    RAN: /nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/bin/python3.10 /build/tmpvaqcl0bf

    STDOUT:

    STDERR:

    warnings.warn(pytest.PytestUnhandledThreadExceptionWarning(msg))

tests/test.py::FunctionalTests::test_signal_exception
  /nix/store/agawdr80hxrmhm2gcqvzs6z4s06qabby-python3.10-pytest-7.2.1/lib/python3.10/site-packages/_pytest/threadexception.py:73: PytestUnhandledThreadExceptionWarning: Exception in thread background thread for pid 581

  Traceback (most recent call last):
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
      self.run()
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 953, in run
      self._target(*self._args, **self._kwargs)
    File "/build/source/sh.py", line 1654, in wrap
      fn(*rgs, **kwargs)
    File "/build/source/sh.py", line 2656, in background_thread
      handle_exit_code(exit_code)
    File "/build/source/sh.py", line 2347, in fn
      return self.command.handle_command_exit_code(exit_code)
    File "/build/source/sh.py", line 838, in handle_command_exit_code
      raise exc
  sh.SignalException_SIGTERM: 

    RAN: /nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/bin/python3.10 /build/tmp17rt4bv1

    STDOUT:

    STDERR:

    warnings.warn(pytest.PytestUnhandledThreadExceptionWarning(msg))

tests/test.py::FunctionalTests::test_stdout_callback_kill
  /nix/store/agawdr80hxrmhm2gcqvzs6z4s06qabby-python3.10-pytest-7.2.1/lib/python3.10/site-packages/_pytest/threadexception.py:73: PytestUnhandledThreadExceptionWarning: Exception in thread background thread for pid 661

  Traceback (most recent call last):
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
      self.run()
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 953, in run
      self._target(*self._args, **self._kwargs)
    File "/build/source/sh.py", line 1654, in wrap
      fn(*rgs, **kwargs)
    File "/build/source/sh.py", line 2656, in background_thread
      handle_exit_code(exit_code)
    File "/build/source/sh.py", line 2347, in fn
      return self.command.handle_command_exit_code(exit_code)
    File "/build/source/sh.py", line 838, in handle_command_exit_code
      raise exc
  sh.SignalException_SIGKILL: 

    RAN: /nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/bin/python3.10 -u /build/tmpeit9x7_h

    STDOUT:

    STDERR:

    warnings.warn(pytest.PytestUnhandledThreadExceptionWarning(msg))

tests/test.py::FunctionalTests::test_stdout_callback_terminate
  /nix/store/agawdr80hxrmhm2gcqvzs6z4s06qabby-python3.10-pytest-7.2.1/lib/python3.10/site-packages/_pytest/threadexception.py:73: PytestUnhandledThreadExceptionWarning: Exception in thread background thread for pid 701

  Traceback (most recent call last):
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
      self.run()
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 953, in run
      self._target(*self._args, **self._kwargs)
    File "/build/source/sh.py", line 1654, in wrap
      fn(*rgs, **kwargs)
    File "/build/source/sh.py", line 2656, in background_thread
      handle_exit_code(exit_code)
    File "/build/source/sh.py", line 2347, in fn
      return self.command.handle_command_exit_code(exit_code)
    File "/build/source/sh.py", line 838, in handle_command_exit_code
      raise exc
  sh.SignalException_SIGTERM: 

    RAN: /nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/bin/python3.10 -u /build/tmp_s9j1itv

    STDOUT:

    STDERR:

    warnings.warn(pytest.PytestUnhandledThreadExceptionWarning(msg))

tests/test.py::FunctionalTests::test_fg_alternative
  /nix/store/agawdr80hxrmhm2gcqvzs6z4s06qabby-python3.10-pytest-7.2.1/lib/python3.10/site-packages/_pytest/threadexception.py:73: PytestUnhandledThreadExceptionWarning: Exception in thread STDIN thread for pid 716

  Traceback (most recent call last):
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
      self.run()
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 953, in run
      self._target(*self._args, **self._kwargs)
    File "/build/source/sh.py", line 1654, in wrap
      fn(*rgs, **kwargs)
    File "/build/source/sh.py", line 2606, in input_thread
      done = stdin.write()
    File "/build/source/sh.py", line 2919, in write
      chunk = self.get_chunk()
    File "/build/source/sh.py", line 2860, in fn
      chunk = stdin.read(bufsize)
    File "/nix/store/agawdr80hxrmhm2gcqvzs6z4s06qabby-python3.10-pytest-7.2.1/lib/python3.10/site-packages/_pytest/capture.py", line 192, in read
      raise OSError(
  OSError: pytest: reading from stdin while output is captured!  Consider using `-s`.

    warnings.warn(pytest.PytestUnhandledThreadExceptionWarning(msg))

tests/test.py::FunctionalTests::test_signal_group
  /nix/store/agawdr80hxrmhm2gcqvzs6z4s06qabby-python3.10-pytest-7.2.1/lib/python3.10/site-packages/_pytest/threadexception.py:73: PytestUnhandledThreadExceptionWarning: Exception in thread background thread for pid 731

  Traceback (most recent call last):
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
      self.run()
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 953, in run
      self._target(*self._args, **self._kwargs)
    File "/build/source/sh.py", line 1654, in wrap
      fn(*rgs, **kwargs)
    File "/build/source/sh.py", line 2656, in background_thread
      handle_exit_code(exit_code)
    File "/build/source/sh.py", line 2347, in fn
      return self.command.handle_command_exit_code(exit_code)
    File "/build/source/sh.py", line 838, in handle_command_exit_code
      raise exc
  sh.SignalException_SIGKILL: 

    RAN: /nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/bin/python3.10 /build/tmpbfannjvz

    STDOUT:
  735
  731

    STDERR:

    warnings.warn(pytest.PytestUnhandledThreadExceptionWarning(msg))

tests/test.py::FunctionalTests::test_unchecked_producer_failure
  /nix/store/agawdr80hxrmhm2gcqvzs6z4s06qabby-python3.10-pytest-7.2.1/lib/python3.10/site-packages/_pytest/threadexception.py:73: PytestUnhandledThreadExceptionWarning: Exception in thread background thread for pid 757

  Traceback (most recent call last):
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
      self.run()
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 953, in run
      self._target(*self._args, **self._kwargs)
    File "/build/source/sh.py", line 1654, in wrap
      fn(*rgs, **kwargs)
    File "/build/source/sh.py", line 2656, in background_thread
      handle_exit_code(exit_code)
    File "/build/source/sh.py", line 2347, in fn
      return self.command.handle_command_exit_code(exit_code)
    File "/build/source/sh.py", line 838, in handle_command_exit_code
      raise exc
  sh.ErrorReturnCode_2: 

    RAN: /nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/bin/python3.10 /build/tmpssifhe90

    STDOUT:

    STDERR:

    warnings.warn(pytest.PytestUnhandledThreadExceptionWarning(msg))

tests/test.py::FunctionalTests::test_tty_tee
  /nix/store/agawdr80hxrmhm2gcqvzs6z4s06qabby-python3.10-pytest-7.2.1/lib/python3.10/site-packages/_pytest/threadexception.py:73: PytestUnhandledThreadExceptionWarning: Exception in thread background thread for pid 740

  Traceback (most recent call last):
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
      self.run()
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 953, in run
      self._target(*self._args, **self._kwargs)
    File "/build/source/sh.py", line 1654, in wrap
      fn(*rgs, **kwargs)
    File "/build/source/sh.py", line 2656, in background_thread
      handle_exit_code(exit_code)
    File "/build/source/sh.py", line 2347, in fn
      return self.command.handle_command_exit_code(exit_code)
    File "/build/source/sh.py", line 838, in handle_command_exit_code
      raise exc
  sh.SignalException_SIGKILL: 

    RAN: /nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/bin/python3.10 /build/tmpbfannjvz

    STDOUT:
  744
  740

    STDERR:

    warnings.warn(pytest.PytestUnhandledThreadExceptionWarning(msg))

tests/test.py::FunctionalTests::test_done_cb_exc
  /nix/store/agawdr80hxrmhm2gcqvzs6z4s06qabby-python3.10-pytest-7.2.1/lib/python3.10/site-packages/_pytest/threadexception.py:73: PytestUnhandledThreadExceptionWarning: Exception in thread background thread for pid 772

  Traceback (most recent call last):
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 1016, in _bootstrap_inner
      self.run()
    File "/nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/lib/python3.10/threading.py", line 953, in run
      self._target(*self._args, **self._kwargs)
    File "/build/source/sh.py", line 1654, in wrap
      fn(*rgs, **kwargs)
    File "/build/source/sh.py", line 2656, in background_thread
      handle_exit_code(exit_code)
    File "/build/source/sh.py", line 2347, in fn
      return self.command.handle_command_exit_code(exit_code)
    File "/build/source/sh.py", line 838, in handle_command_exit_code
      raise exc
  sh.ErrorReturnCode_1: 

    RAN: /nix/store/fhzv25qmq4jsfwddq2dslf4mcqpkk15w-python3-3.10.11/bin/python3.10 /build/tmpv6u2nrxi

    STDOUT:

    STDERR:

    warnings.warn(pytest.PytestUnhandledThreadExceptionWarning(msg))

-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
=========================== short test summary info ============================
FAILED tests/test.py::FunctionalTests::test_general_signal - AssertionError: '0\n1\n2\n3\n43\n44\n' != '0\n1\n2\n3\n42\n43\n'
= 1 failed, 172 passed, 1 skipped, 4 deselected, 10 warnings in 81.04s (0:01:21) =
/nix/store/4np3l3m41jjv0ig04v3f0gbilj6j38k0-stdenv-linux/setup: line 1596: pop_var_context: head of shell_variables not a function context
amoffat commented 1 year ago

There are a few tests that have timing issues inherent to process launching/flushing/exiting. Not sure if that one is, but it's possible.

l0b0 commented 1 year ago

Also ran into this in CI. Unfortunately the project is internal, but I got the exact same test result diff.