Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

TestPantsDaemonIntegration.test_pantsd_sigint is flaky #7547

Closed
jsirois opened this issue Apr 13, 2019 · 2 comments · Fixed by #11223
Closed

TestPantsDaemonIntegration.test_pantsd_sigint is flaky #7547

jsirois opened this issue Apr 13, 2019 · 2 comments · Fixed by #11223

Comments

@jsirois
Copy link
Contributor

jsirois commented Apr 13, 2019

Presumably closely related to #7425.

Looks like the following in CI:

02:56:55 35:51       [run]
                     Only executing 2 of 27 total tests in shard 0 of 20
                     .F                                         [100%]
                     ==================== FAILURES ====================
                     _ TestPantsDaemonIntegration.test_pantsd_sigint __
                     
                     self = <pants_test.pantsd.test_pantsd_integration.TestPantsDaemonIntegration testMethod=test_pantsd_sigint>
                     
                         def test_pantsd_sigint(self):
                           self._assert_pantsd_keyboardinterrupt_signal(
                             signal.SIGINT,
                             regexps=["""\
                         \\[INFO\\] Sending SIGINT to pantsd-runner with pid [0-9]+, waiting up to 5\\.0 seconds before sending SIGKILL\\.\\.\\.
                         Interrupted by user.
                         Interrupted by user:
                         Interrupted by user over pailgun client!
                     >   $"""])
                     
                     .pants.d/pyprep/sources/dc0796b750bd3448755396bf4a0a649caf8917d5/pants_test/pantsd/test_pantsd_integration.py:527: 
                     _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
                     .pants.d/pyprep/sources/dc0796b750bd3448755396bf4a0a649caf8917d5/pants_test/pantsd/test_pantsd_integration.py:485: in _assert_pantsd_keyboardinterrupt_signal
                         assertRegex(self, waiter_run.stderr_data, regexp)
                     .pants.d/pyprep/sources/dc0796b750bd3448755396bf4a0a649caf8917d5/pants_test/testutils/py2_compat.py:17: in assertRegex
                         self.assertRegex(text, expected_regex, msg)
                     E   AssertionError: Regex didn't match: '\\[INFO\\] Sending SIGINT to pantsd-runner with pid [0-9]+, waiting up to 5\\.0 seconds before sending SIGKILL\\.\\.\\.\nInterrupted by user.\nInterrupted by user:\nInterrupted by user over pailgun client!\n$' not found in '02:57:32 [INFO] Sending SIGINT to pantsd-runner with pid 9756, waiting up to 5.0 seconds before sending SIGKILL...\nInterrupted by user:\nInterrupted by user over pailgun client!\n'
                     -------------- Captured stdout call --------------
                     
                     pantsd log is /home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/pantsd/pantsd.log
                     >>> config: 
                     {'GLOBAL': {'enable_pantsd': True, 'watchman_socket_path': '/tmp/watchman.7421.sock', 'level': 'info', 'pants_subprocessdir': '/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.pids'}}
                     
                     
                     running: ./pants kill-pantsd (config={'GLOBAL': {'enable_pantsd': True, 'watchman_socket_path': '/tmp/watchman.7421.sock', 'level': 'info', 'pants_subprocessdir': '/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.pids'}}) (extra_env={})
                     
                     completed in 7.311360597610474 seconds
                     PantsDaemonMonitor: pid is 9555 is_alive=True
                     logs/exceptions.9343.log +++ 
                     logs/exceptions.9343.log --- 
                     logs/exceptions.9121.log +++ 
                     logs/exceptions.9121.log >>> timestamp: 2019-04-13T02:57:25.209001
                     logs/exceptions.9121.log >>> process title: pantsd [/home/travis/build/pantsbuild/pants]
                     logs/exceptions.9121.log >>> sys.argv: ['/home/travis/build/pantsbuild/pants/pants.pex', '--no-pantsrc', '--pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d', '--kill-nailguns', '--print-exception-stacktrace=True', '--pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/pants.ini', 'kill-pantsd']
                     logs/exceptions.9121.log >>> pid: 9121
                     logs/exceptions.9121.log >>> Signal 15 (SIGTERM) was raised. Exiting with failure.
                     logs/exceptions.9121.log >>>   File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 193, in _run_module_as_main
                     logs/exceptions.9121.log >>>     "__main__", mod_spec)
                     logs/exceptions.9121.log >>>   File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 85, in _run_code
                     logs/exceptions.9121.log >>>     exec(code, run_globals)
                     logs/exceptions.9121.log >>>   File "__main__.py", line 32, in <module>
                     logs/exceptions.9121.log >>>     bootstrap_pex(__entry_point__)
                     logs/exceptions.9121.log >>>   File ".bootstrap/pex/pex_bootstrapper.py", line 155, in bootstrap_pex
                     logs/exceptions.9121.log >>>     pex.PEX(entry_point).execute()
                     logs/exceptions.9121.log >>>   File ".bootstrap/pex/pex.py", line 352, in execute
                     logs/exceptions.9121.log >>>     exit_code = self._wrap_coverage(self._wrap_profiling, self._execute)
                     logs/exceptions.9121.log >>>   File ".bootstrap/pex/pex.py", line 284, in _wrap_coverage
                     logs/exceptions.9121.log >>>     return runner(*args)
                     logs/exceptions.9121.log >>>   File ".bootstrap/pex/pex.py", line 315, in _wrap_profiling
                     logs/exceptions.9121.log >>>     return runner(*args)
                     logs/exceptions.9121.log >>>   File ".bootstrap/pex/pex.py", line 397, in _execute
                     logs/exceptions.9121.log >>>     return self.execute_entry(self._pex_info.entry_point)
                     logs/exceptions.9121.log >>>   File ".bootstrap/pex/pex.py", line 495, in execute_entry
                     logs/exceptions.9121.log >>>     return runner(entry_point)
                     logs/exceptions.9121.log >>>   File ".bootstrap/pex/pex.py", line 510, in execute_pkg_resources
                     logs/exceptions.9121.log >>>     return runner()
                     logs/exceptions.9121.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/bin/pants_loader.py", line 85, in main
                     logs/exceptions.9121.log >>>     PantsLoader.run()
                     logs/exceptions.9121.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/bin/pants_loader.py", line 81, in run
                     logs/exceptions.9121.log >>>     cls.load_and_execute(entrypoint)
                     logs/exceptions.9121.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/bin/pants_loader.py", line 74, in load_and_execute
                     logs/exceptions.9121.log >>>     entrypoint_main()
                     logs/exceptions.9121.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/pantsd/pants_daemon.py", line 474, in launch
                     logs/exceptions.9121.log >>>     PantsDaemon.Factory.create(OptionsBootstrapper.create()).run_sync()
                     logs/exceptions.9121.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/pantsd/pants_daemon.py", line 407, in run_sync
                     logs/exceptions.9121.log >>>     self._run_services(self._services)
                     logs/exceptions.9121.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/pantsd/pants_daemon.py", line 362, in _run_services
                     logs/exceptions.9121.log >>>     service_thread.join(self.JOIN_TIMEOUT_SECONDS)
                     logs/exceptions.9121.log >>>   File "/opt/pyenv/versions/3.6.7/lib/python3.6/threading.py", line 1060, in join
                     logs/exceptions.9121.log >>>     self._wait_for_tstate_lock(timeout=max(timeout, 0))
                     logs/exceptions.9121.log >>>   File "/opt/pyenv/versions/3.6.7/lib/python3.6/threading.py", line 1072, in _wait_for_tstate_lock
                     logs/exceptions.9121.log >>>     elif lock.acquire(block, timeout):
                     logs/exceptions.9121.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/base/exception_sink.py", line 74, in handle_sigterm
                     logs/exceptions.9121.log >>>     raise self.SignalHandledNonLocalExit(signum, 'SIGTERM')
                     logs/exceptions.9121.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/base/exception_sink.py", line 67, in __init__
                     logs/exceptions.9121.log >>>     self.traceback_lines = traceback.format_stack()
                     logs/exceptions.9121.log >>> 
                     logs/exceptions.9121.log >>> 
                     logs/exceptions.9121.log >>> timestamp: 2019-04-13T02:57:25.209941
                     logs/exceptions.9121.log >>> process title: pantsd [/home/travis/build/pantsbuild/pants]
                     logs/exceptions.9121.log >>> sys.argv: ['/home/travis/build/pantsbuild/pants/pants.pex', '--no-pantsrc', '--pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d', '--kill-nailguns', '--print-exception-stacktrace=True', '--pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/pants.ini', 'kill-pantsd']
                     logs/exceptions.9121.log >>> pid: 9121
                     logs/exceptions.9121.log >>> Exception caught: (builtins.ValueError)
                     logs/exceptions.9121.log >>>   File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 193, in _run_module_as_main
                     logs/exceptions.9121.log >>>     "__main__", mod_spec)
                     logs/exceptions.9121.log >>>   File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 85, in _run_code
                     logs/exceptions.9121.log >>>     exec(code, run_globals)
                     logs/exceptions.9121.log >>>   File "__main__.py", line 32, in <module>
                     logs/exceptions.9121.log >>>     bootstrap_pex(__entry_point__)
                     logs/exceptions.9121.log >>>   File ".bootstrap/pex/pex_bootstrapper.py", line 155, in bootstrap_pex
                     logs/exceptions.9121.log >>>     pex.PEX(entry_point).execute()
                     logs/exceptions.9121.log >>>   File ".bootstrap/pex/pex.py", line 371, in execute
                     logs/exceptions.9121.log >>>     sys.stderr.flush()
                     logs/exceptions.9121.log >>> 
                     logs/exceptions.9121.log >>> Exception message: I/O operation on closed file.
                     logs/exceptions.9121.log >>> 
                     logs/exceptions.9121.log --- 
                     logs/exceptions.8909.log +++ 
                     logs/exceptions.8909.log --- 
                     logs/exceptions.log +++ 
                     logs/exceptions.log >>> timestamp: 2019-04-13T02:57:25.209001
                     logs/exceptions.log >>> process title: pantsd [/home/travis/build/pantsbuild/pants]
                     logs/exceptions.log >>> sys.argv: ['/home/travis/build/pantsbuild/pants/pants.pex', '--no-pantsrc', '--pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d', '--kill-nailguns', '--print-exception-stacktrace=True', '--pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/pants.ini', 'kill-pantsd']
                     logs/exceptions.log >>> pid: 9121
                     logs/exceptions.log >>> Signal 15 (SIGTERM) was raised. Exiting with failure.
                     logs/exceptions.log >>>   File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 193, in _run_module_as_main
                     logs/exceptions.log >>>     "__main__", mod_spec)
                     logs/exceptions.log >>>   File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 85, in _run_code
                     logs/exceptions.log >>>     exec(code, run_globals)
                     logs/exceptions.log >>>   File "__main__.py", line 32, in <module>
                     logs/exceptions.log >>>     bootstrap_pex(__entry_point__)
                     logs/exceptions.log >>>   File ".bootstrap/pex/pex_bootstrapper.py", line 155, in bootstrap_pex
                     logs/exceptions.log >>>     pex.PEX(entry_point).execute()
                     logs/exceptions.log >>>   File ".bootstrap/pex/pex.py", line 352, in execute
                     logs/exceptions.log >>>     exit_code = self._wrap_coverage(self._wrap_profiling, self._execute)
                     logs/exceptions.log >>>   File ".bootstrap/pex/pex.py", line 284, in _wrap_coverage
                     logs/exceptions.log >>>     return runner(*args)
                     logs/exceptions.log >>>   File ".bootstrap/pex/pex.py", line 315, in _wrap_profiling
                     logs/exceptions.log >>>     return runner(*args)
                     logs/exceptions.log >>>   File ".bootstrap/pex/pex.py", line 397, in _execute
                     logs/exceptions.log >>>     return self.execute_entry(self._pex_info.entry_point)
                     logs/exceptions.log >>>   File ".bootstrap/pex/pex.py", line 495, in execute_entry
                     logs/exceptions.log >>>     return runner(entry_point)
                     logs/exceptions.log >>>   File ".bootstrap/pex/pex.py", line 510, in execute_pkg_resources
                     logs/exceptions.log >>>     return runner()
                     logs/exceptions.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/bin/pants_loader.py", line 85, in main
                     logs/exceptions.log >>>     PantsLoader.run()
                     logs/exceptions.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/bin/pants_loader.py", line 81, in run
                     logs/exceptions.log >>>     cls.load_and_execute(entrypoint)
                     logs/exceptions.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/bin/pants_loader.py", line 74, in load_and_execute
                     logs/exceptions.log >>>     entrypoint_main()
                     logs/exceptions.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/pantsd/pants_daemon.py", line 474, in launch
                     logs/exceptions.log >>>     PantsDaemon.Factory.create(OptionsBootstrapper.create()).run_sync()
                     logs/exceptions.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/pantsd/pants_daemon.py", line 407, in run_sync
                     logs/exceptions.log >>>     self._run_services(self._services)
                     logs/exceptions.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/pantsd/pants_daemon.py", line 362, in _run_services
                     logs/exceptions.log >>>     service_thread.join(self.JOIN_TIMEOUT_SECONDS)
                     logs/exceptions.log >>>   File "/opt/pyenv/versions/3.6.7/lib/python3.6/threading.py", line 1060, in join
                     logs/exceptions.log >>>     self._wait_for_tstate_lock(timeout=max(timeout, 0))
                     logs/exceptions.log >>>   File "/opt/pyenv/versions/3.6.7/lib/python3.6/threading.py", line 1072, in _wait_for_tstate_lock
                     logs/exceptions.log >>>     elif lock.acquire(block, timeout):
                     logs/exceptions.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/base/exception_sink.py", line 74, in handle_sigterm
                     logs/exceptions.log >>>     raise self.SignalHandledNonLocalExit(signum, 'SIGTERM')
                     logs/exceptions.log >>>   File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/base/exception_sink.py", line 67, in __init__
                     logs/exceptions.log >>>     self.traceback_lines = traceback.format_stack()
                     logs/exceptions.log >>> 
                     logs/exceptions.log >>> 
                     logs/exceptions.log >>> timestamp: 2019-04-13T02:57:25.209941
                     logs/exceptions.log >>> process title: pantsd [/home/travis/build/pantsbuild/pants]
                     logs/exceptions.log >>> sys.argv: ['/home/travis/build/pantsbuild/pants/pants.pex', '--no-pantsrc', '--pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d', '--kill-nailguns', '--print-exception-stacktrace=True', '--pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/pants.ini', 'kill-pantsd']
                     logs/exceptions.log >>> pid: 9121
                     logs/exceptions.log >>> Exception caught: (builtins.ValueError)
                     logs/exceptions.log >>>   File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 193, in _run_module_as_main
                     logs/exceptions.log >>>     "__main__", mod_spec)
                     logs/exceptions.log >>>   File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 85, in _run_code
                     logs/exceptions.log >>>     exec(code, run_globals)
                     logs/exceptions.log >>>   File "__main__.py", line 32, in <module>
                     logs/exceptions.log >>>     bootstrap_pex(__entry_point__)
                     logs/exceptions.log >>>   File ".bootstrap/pex/pex_bootstrapper.py", line 155, in bootstrap_pex
                     logs/exceptions.log >>>     pex.PEX(entry_point).execute()
                     logs/exceptions.log >>>   File ".bootstrap/pex/pex.py", line 371, in execute
                     logs/exceptions.log >>>     sys.stderr.flush()
                     logs/exceptions.log >>> 
                     logs/exceptions.log >>> Exception message: I/O operation on closed file.
                     logs/exceptions.log >>> 
                     logs/exceptions.log --- 
                     logs/exceptions.9555.log +++ 
                     logs/exceptions.9555.log --- 
                     pantsd/pantsd.log +++ 
                     pantsd/pantsd.log >>> 02:57:24 [INFO] setting up service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7f45c813a6a0>
                     pantsd/pantsd.log >>> 02:57:24 [INFO] setting up service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f45c813a780>
                     pantsd/pantsd.log >>> 02:57:24 [INFO] watching invalidating files: set()
                     pantsd/pantsd.log >>> 02:57:24 [INFO] setting up service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7f45c80caac8>
                     pantsd/pantsd.log >>> 02:57:24 [INFO] setting up service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7f45c80caa20>
                     pantsd/pantsd.log >>> 02:57:24 [INFO] starting service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7f45c813a6a0>
                     pantsd/pantsd.log >>> 02:57:24 [INFO] starting service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f45c813a780>
                     pantsd/pantsd.log >>> 02:57:24 [INFO] starting service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7f45c80caac8>
                     pantsd/pantsd.log >>> 02:57:24 [INFO] starting pailgun server on port 44707
                     pantsd/pantsd.log >>> 02:57:24 [INFO] starting service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7f45c80caa20>
                     pantsd/pantsd.log >>> 02:57:24 [INFO] handling pailgun request: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/pants.ini kill-pantsd`
                     pantsd/pantsd.log >>> 02:57:24 [INFO] confirmed watchman subscription: {'clock': 'c:1555124241:9102:1:3', 'subscribe': 'all_files', 'version': '4.9.1'}
                     pantsd/pantsd.log >>> 02:57:24 [INFO] enqueuing 5052 changes for subscription all_files
                     pantsd/pantsd.log >>> 02:57:24 [INFO] confirmed watchman subscription: {'clock': 'c:1555124241:9102:1:4', 'subscribe': 'pantsd_pid', 'version': '4.9.1'}
                     pantsd/pantsd.log >>> 02:57:24 [INFO] enqueuing 1 changes for subscription pantsd_pid
                     pantsd/pantsd.log >>> 02:57:24 [INFO] pailgun request completed: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/pants.ini kill-pantsd`
                     pantsd/pantsd.log >>> 02:57:25 [WARN] Encountered error when trying to log this message: b'timestamp: 2019-04-13T02:57:25.209167\nSignal 15 (SIGTERM) was raised. Exiting with failure.\n  File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 193, in _run_module_as_main\n    "__main__", mod_spec)\n  File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 85, in _run_code\n    exec(code, run_globals)\n  File "__main__.py", line 32, in <module>\n    bootstrap_pex(__entry_point__)\n  File ".bootstrap/pex/pex_bootstrapper.py", line 155, in bootstrap_pex\n    pex.PEX(entry_point).execute()\n  File ".bootstrap/pex/pex.py", line 352, in execute\n    exit_code = self._wrap_coverage(self._wrap_profiling, self._execute)\n  File ".bootstrap/pex/pex.py", line 284, in _wrap_coverage\n    return runner(*args)\n  File ".bootstrap/pex/pex.py", line 315, in _wrap_profiling\n    return runner(*args)\n  File ".bootstrap/pex/pex.py", line 397, in _execute\n    return self.execute_entry(self._pex_info.entry_point)\n  File ".bootstrap/pex/pex.py", line 495, in execute_entry\n    return runner(entry_point)\n  File ".bootstrap/pex/pex.py", line 510, in execute_pkg_resources\n    return runner()\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/bin/pants_loader.py", line 85, in main\n    PantsLoader.run()\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/bin/pants_loader.py", line 81, in run\n    cls.load_and_execute(entrypoint)\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/bin/pants_loader.py", line 74, in load_and_execute\n    entrypoint_main()\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/pantsd/pants_daemon.py", line 474, in launch\n    PantsDaemon.Factory.create(OptionsBootstrapper.create()).run_sync()\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/pantsd/pants_daemon.py", line 407, in run_sync\n    self._run_services(self._services)\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/pantsd/pants_daemon.py", line 362, in _run_services\n    service_thread.join(self.JOIN_TIMEOUT_SECONDS)\n  File "/opt/pyenv/versions/3.6.7/lib/python3.6/threading.py", line 1060, in join\n    self._wait_for_tstate_lock(timeout=max(timeout, 0))\n  File "/opt/pyenv/versions/3.6.7/lib/python3.6/threading.py", line 1072, in _wait_for_tstate_lock\n    elif lock.acquire(block, timeout):\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/base/exception_sink.py", line 74, in handle_sigterm\n    raise self.SignalHandledNonLocalExit(signum, \'SIGTERM\')\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/base/exception_sink.py", line 67, in __init__\n    self.traceback_lines = traceback.format_stack()\n\n\n'
                     pantsd/pantsd.log >>> 02:57:25 [WARN] Encountered error when trying to log this message: b'timestamp: 2019-04-13T02:57:25.210117\nException caught: (builtins.ValueError)\n  File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 193, in _run_module_as_main\n    "__main__", mod_spec)\n  File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 85, in _run_code\n    exec(code, run_globals)\n  File "__main__.py", line 32, in <module>\n    bootstrap_pex(__entry_point__)\n  File ".bootstrap/pex/pex_bootstrapper.py", line 155, in bootstrap_pex\n    pex.PEX(entry_point).execute()\n  File ".bootstrap/pex/pex.py", line 371, in execute\n    sys.stderr.flush()\n\nException message: I/O operation on closed file.\n\n'
                     pantsd/pantsd.log >>> 02:57:31 [INFO] setting up service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7f225b8ac6a0>
                     pantsd/pantsd.log >>> 02:57:31 [INFO] setting up service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f225b8ac780>
                     pantsd/pantsd.log >>> 02:57:31 [INFO] watching invalidating files: set()
                     pantsd/pantsd.log >>> 02:57:31 [INFO] setting up service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7f225b83cac8>
                     pantsd/pantsd.log >>> 02:57:31 [INFO] setting up service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7f225b83ca20>
                     pantsd/pantsd.log >>> 02:57:31 [INFO] starting service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7f225b8ac6a0>
                     pantsd/pantsd.log >>> 02:57:31 [INFO] starting service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f225b8ac780>
                     pantsd/pantsd.log >>> 02:57:31 [INFO] starting service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7f225b83cac8>
                     pantsd/pantsd.log >>> 02:57:31 [INFO] starting pailgun server on port 43419
                     pantsd/pantsd.log >>> 02:57:31 [INFO] starting service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7f225b83ca20>
                     pantsd/pantsd.log >>> 02:57:31 [INFO] handling pailgun request: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/pants.ini run testprojects/src/python/coordinated_runs:waiter -- /home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/some_magic_file`
                     pantsd/pantsd.log >>> 02:57:32 [INFO] confirmed watchman subscription: {'clock': 'c:1555124248:9536:1:3', 'subscribe': 'all_files', 'version': '4.9.1'}
                     pantsd/pantsd.log >>> 02:57:32 [INFO] enqueuing 5052 changes for subscription all_files
                     pantsd/pantsd.log >>> 02:57:32 [INFO] confirmed watchman subscription: {'clock': 'c:1555124248:9536:1:4', 'subscribe': 'pantsd_pid', 'version': '4.9.1'}
                     pantsd/pantsd.log >>> 02:57:32 [INFO] enqueuing 1 changes for subscription pantsd_pid
                     pantsd/pantsd.log >>> 02:57:32 [INFO] pailgun request completed: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/pants.ini run testprojects/src/python/coordinated_runs:waiter -- /home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/some_magic_file`
                     pantsd/pantsd.log --- 
                     ===============================================================
                     - BEGIN pantsd.log --------------------------------------------
                     ===============================================================
                     02:57:24 [INFO] setting up service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7f45c813a6a0>
                     02:57:24 [INFO] setting up service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f45c813a780>
                     02:57:24 [INFO] watching invalidating files: set()
                     02:57:24 [INFO] setting up service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7f45c80caac8>
                     02:57:24 [INFO] setting up service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7f45c80caa20>
                     02:57:24 [INFO] starting service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7f45c813a6a0>
                     02:57:24 [INFO] starting service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f45c813a780>
                     02:57:24 [INFO] starting service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7f45c80caac8>
                     02:57:24 [INFO] starting pailgun server on port 44707
                     02:57:24 [INFO] starting service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7f45c80caa20>
                     02:57:24 [INFO] handling pailgun request: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/pants.ini kill-pantsd`
                     02:57:24 [INFO] confirmed watchman subscription: {'clock': 'c:1555124241:9102:1:3', 'subscribe': 'all_files', 'version': '4.9.1'}
                     02:57:24 [INFO] enqueuing 5052 changes for subscription all_files
                     02:57:24 [INFO] confirmed watchman subscription: {'clock': 'c:1555124241:9102:1:4', 'subscribe': 'pantsd_pid', 'version': '4.9.1'}
                     02:57:24 [INFO] enqueuing 1 changes for subscription pantsd_pid
                     02:57:24 [INFO] pailgun request completed: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/pants.ini kill-pantsd`
                     02:57:25 [WARN] Encountered error when trying to log this message: b'timestamp: 2019-04-13T02:57:25.209167\nSignal 15 (SIGTERM) was raised. Exiting with failure.\n  File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 193, in _run_module_as_main\n    "__main__", mod_spec)\n  File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 85, in _run_code\n    exec(code, run_globals)\n  File "__main__.py", line 32, in <module>\n    bootstrap_pex(__entry_point__)\n  File ".bootstrap/pex/pex_bootstrapper.py", line 155, in bootstrap_pex\n    pex.PEX(entry_point).execute()\n  File ".bootstrap/pex/pex.py", line 352, in execute\n    exit_code = self._wrap_coverage(self._wrap_profiling, self._execute)\n  File ".bootstrap/pex/pex.py", line 284, in _wrap_coverage\n    return runner(*args)\n  File ".bootstrap/pex/pex.py", line 315, in _wrap_profiling\n    return runner(*args)\n  File ".bootstrap/pex/pex.py", line 397, in _execute\n    return self.execute_entry(self._pex_info.entry_point)\n  File ".bootstrap/pex/pex.py", line 495, in execute_entry\n    return runner(entry_point)\n  File ".bootstrap/pex/pex.py", line 510, in execute_pkg_resources\n    return runner()\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/bin/pants_loader.py", line 85, in main\n    PantsLoader.run()\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/bin/pants_loader.py", line 81, in run\n    cls.load_and_execute(entrypoint)\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/bin/pants_loader.py", line 74, in load_and_execute\n    entrypoint_main()\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/pantsd/pants_daemon.py", line 474, in launch\n    PantsDaemon.Factory.create(OptionsBootstrapper.create()).run_sync()\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/pantsd/pants_daemon.py", line 407, in run_sync\n    self._run_services(self._services)\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/pantsd/pants_daemon.py", line 362, in _run_services\n    service_thread.join(self.JOIN_TIMEOUT_SECONDS)\n  File "/opt/pyenv/versions/3.6.7/lib/python3.6/threading.py", line 1060, in join\n    self._wait_for_tstate_lock(timeout=max(timeout, 0))\n  File "/opt/pyenv/versions/3.6.7/lib/python3.6/threading.py", line 1072, in _wait_for_tstate_lock\n    elif lock.acquire(block, timeout):\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/base/exception_sink.py", line 74, in handle_sigterm\n    raise self.SignalHandledNonLocalExit(signum, \'SIGTERM\')\n  File "/home/travis/.pex/code/2a9ffea5b11631c9f895593ac2902e0815280e15/pants/base/exception_sink.py", line 67, in __init__\n    self.traceback_lines = traceback.format_stack()\n\n\n'
                     02:57:25 [WARN] Encountered error when trying to log this message: b'timestamp: 2019-04-13T02:57:25.210117\nException caught: (builtins.ValueError)\n  File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 193, in _run_module_as_main\n    "__main__", mod_spec)\n  File "/opt/pyenv/versions/3.6.7/lib/python3.6/runpy.py", line 85, in _run_code\n    exec(code, run_globals)\n  File "__main__.py", line 32, in <module>\n    bootstrap_pex(__entry_point__)\n  File ".bootstrap/pex/pex_bootstrapper.py", line 155, in bootstrap_pex\n    pex.PEX(entry_point).execute()\n  File ".bootstrap/pex/pex.py", line 371, in execute\n    sys.stderr.flush()\n\nException message: I/O operation on closed file.\n\n'
                     02:57:31 [INFO] setting up service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7f225b8ac6a0>
                     02:57:31 [INFO] setting up service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f225b8ac780>
                     02:57:31 [INFO] watching invalidating files: set()
                     02:57:31 [INFO] setting up service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7f225b83cac8>
                     02:57:31 [INFO] setting up service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7f225b83ca20>
                     02:57:31 [INFO] starting service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7f225b8ac6a0>
                     02:57:31 [INFO] starting service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f225b8ac780>
                     02:57:31 [INFO] starting service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7f225b83cac8>
                     02:57:31 [INFO] starting pailgun server on port 43419
                     02:57:31 [INFO] starting service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7f225b83ca20>
                     02:57:31 [INFO] handling pailgun request: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/pants.ini run testprojects/src/python/coordinated_runs:waiter -- /home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/some_magic_file`
                     02:57:32 [INFO] confirmed watchman subscription: {'clock': 'c:1555124248:9536:1:3', 'subscribe': 'all_files', 'version': '4.9.1'}
                     02:57:32 [INFO] enqueuing 5052 changes for subscription all_files
                     02:57:32 [INFO] confirmed watchman subscription: {'clock': 'c:1555124248:9536:1:4', 'subscribe': 'pantsd_pid', 'version': '4.9.1'}
                     02:57:32 [INFO] enqueuing 1 changes for subscription pantsd_pid
                     02:57:32 [INFO] pailgun request completed: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/pants.ini run testprojects/src/python/coordinated_runs:waiter -- /home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.workdir.pants.d/some_magic_file`
                     ===============================================================
                     - END pantsd.log ----------------------------------------------
                     ===============================================================
                     
                     running: ./pants kill-pantsd (config={'GLOBAL': {'enable_pantsd': True, 'watchman_socket_path': '/tmp/watchman.7421.sock', 'level': 'info', 'pants_subprocessdir': '/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpu0yclxig.pants.d/.pids'}}) (extra_env={})
                     
                     completed in 3.868635892868042 seconds
                     PantsDaemonMonitor: pid is 9555 is_alive=False
                     - generated xml file: /home/travis/build/pantsbuild/pants/.pants.d/test/pytest/tests.python.pants_test.pantsd.pantsd_integration/junitxml/TEST-tests.python.pants_test.pantsd.pantsd_integration.xml -
                     ============ short test summary info =============
                     FAIL tests/python/pants_test/pantsd/test_pantsd_integration.py::TestPantsDaemonIntegration::test_pantsd_sigint
                     1 failed, 1 passed in 39.75 seconds
@jsirois
Copy link
Contributor Author

jsirois commented Apr 14, 2019

Seen several hours later in the CI cron job.

@jsirois
Copy link
Contributor Author

jsirois commented Apr 14, 2019

And again in #7548 ... x2. I'm going to add some skips in TestPantsDaemonIntegration for the current crop of unresolved flakes it has.

jsirois added a commit to jsirois/pants that referenced this issue Apr 14, 2019
@jsirois jsirois added the pantsd label Apr 14, 2019
jsirois added a commit to jsirois/pants that referenced this issue Apr 14, 2019
jsirois added a commit that referenced this issue Apr 15, 2019
@jsirois jsirois self-assigned this Mar 24, 2020
jsirois added a commit to jsirois/pants that referenced this issue Mar 25, 2020
This brings our skip count up from 7 python and 2 rust to 25 python and
4 rust, hopefully in the name of stability as outlined in pantsbuild#9386.

Also updates the How to Contribute docs with a pointer to pantsbuild#9386 for
the latest procedure.

Includes flaky tests from:
 pantsbuild#9313 pantsbuild#9312 pantsbuild#8679 pantsbuild#8678 pantsbuild#8520 pantsbuild#8520 pantsbuild#8520 pantsbuild#8405 pantsbuild#8193 pantsbuild#8171 pantsbuild#7836 pantsbuild#7622
 pantsbuild#7573 pantsbuild#7572 pantsbuild#7554 pantsbuild#7547 pantsbuild#7457 pantsbuild#7168 pantsbuild#7149 pantsbuild#6838 pantsbuild#6829 pantsbuild#6787 pantsbuild#6114

[ci skip-jvm-tests]  # No JVM changes made.
jsirois added a commit that referenced this issue Mar 25, 2020
This brings our skip count up from 7 python and 2 rust to 25 python and
4 rust, hopefully in the name of stability as outlined in #9386.

Also updates the How to Contribute docs with a pointer to #9386 for
the latest procedure.

Includes flaky tests from:
 #9313 #9312 #8679 #8678 #8520 #8520 #8520 #8405 #8193 #8171 #7836 #7622
 #7573 #7572 #7554 #7547 #7457 #7168 #7149 #6838 #6829 #6787 #6114
@jsirois jsirois removed their assignment Mar 25, 2020
stuhood added a commit that referenced this issue Nov 24, 2020
### Problem

In order to re-enable concurrent runs in #7654, we can no longer kill the server in order to cancel an ongoing run when the client exits (as that would kill all runs rather than just the run associated with the single cancelled client). Instead, we need to gracefully terminate ongoing runs when a `pantsd` client goes away.

### Solution

Using [new facilities](https://github.com/stuhood/nails/commits/9e805a20948a04aea6c082efbe5a9d95b7b71e31) in `nails` `0.8.0`, we detect that a client has `shutdown` the write half of the connection (or otherwise gone away, via heartbeats), and set a cancellation signal on the `Session` for the associated run. When a `Session` has been marked cancelled, the server will cleanly exit the UI loop, and interrupt any `InteractiveProcess` instances.

The client now uses Rust signal handling to intercept Ctrl+C to decide to cancel the run, and will exit the client entirely on the second signal. Because of this, the `ExceptionSink` is now manually installed, and only in locations that are running a `Scheduler` in-process: the `pantsd` server, or a no-`pantsd` local run.

### Result

In general, the server should stay up much longer, because the client no longer kills it in order to handle Ctrl+C. Fixes and unskips some tests related to Ctrl+C handling, and deletes some others. Should cause interactive processes to be consistently interruptible without killing the server.

In another PR we will use this same signal to gracefully cancel any work that was happening in the `Graph`, but since only `InteractiveProcess` or `Console` instances can interact with the UI, that change does not block landing this.

Fixes #7554, fixes #7572, fixes #7547, fixes #7457, fixes #7514.

[ci skip-build-wheels]
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant