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_lifecycle_invalidation CI failure #6114

Closed
jsirois opened this issue Jul 13, 2018 · 2 comments · Fixed by #10035
Closed

TestPantsDaemonIntegration.test_pantsd_lifecycle_invalidation CI failure #6114

jsirois opened this issue Jul 13, 2018 · 2 comments · Fixed by #10035

Comments

@jsirois
Copy link
Contributor

jsirois commented Jul 13, 2018

This would appear to be rare, but as seen in the wild:

                     ==================== FAILURES ====================
                      TestPantsDaemonIntegration.test_pantsd_lifecycle_invalidation 
                     
                     self = <pants_test.pantsd.test_pantsd_integration.TestPantsDaemonIntegration testMethod=test_pantsd_lifecycle_invalidation>
                     
                         def test_pantsd_lifecycle_invalidation(self):
                           """Runs pants commands with pantsd enabled, in a loop, alternating between options that
                             should invalidate pantsd and incur a restart and then asserts for pid consistency.
                             """
                           with self.pantsd_successful_run_context() as (pantsd_run, checker, _, _):
                             variants = (
                               ['debug', 'help'],
                               ['info', 'help']
                             )
                             last_pid = None
                             for cmd in itertools.chain(*itertools.repeat(variants, 3)):
                               # Run with a CLI flag.
                     >         pantsd_run(['-l{}'.format(cmd[0]), cmd[1]])
                     
                     .pants.d/pyprep/sources/fb7306e3a97ef92b3cc5872e1eb3041fcf84d2b4/pants_test/pantsd/test_pantsd_integration.py:266: 
                     _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 
                     .pants.d/pyprep/sources/fb7306e3a97ef92b3cc5872e1eb3041fcf84d2b4/pants_test/pantsd/test_pantsd_integration.py:173: in assert_success_runner
                         runs_created,
                     E   AssertionError: Expected 1 RunTracker run to be created per pantsd run: was 0
                     -------------- Captured stdout call --------------
                     
                     pantsd log is /home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pantsd/pantsd.log
                     >>> config: 
                     {u'GLOBAL': {u'watchman_socket_path': u'/tmp/watchman.10384.sock', u'pants_subprocessdir': u'/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids', u'level': u'info', u'enable_pantsd': True}}
                     
                     
                     running: ./pants kill-pantsd (config={u'GLOBAL': {u'watchman_socket_path': u'/tmp/watchman.10384.sock', u'pants_subprocessdir': u'/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids', u'level': u'info', u'enable_pantsd': True}}) (extra_env={})
                     
                     completed in 3.103058815 seconds
                     
                     running: ./pants -ldebug help (config={u'GLOBAL': {u'watchman_socket_path': u'/tmp/watchman.10384.sock', u'pants_subprocessdir': u'/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids', u'level': u'info', u'enable_pantsd': True}}) (extra_env=None)
                     
                     completed in 2.9121260643 seconds
                     PantsDaemonMonitor: pid is 11083 is_alive=True
                     
                     running: ./pants help (config={u'GLOBAL': {u'watchman_socket_path': u'/tmp/watchman.10384.sock', u'pants_subprocessdir': u'/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids', u'level': u'debug', u'enable_pantsd': True}}) (extra_env=None)
                     
                     completed in 1.26216602325 seconds
                     PantsDaemonMonitor: pid is 11083 is_alive=True
                     
                     running: ./pants -linfo help (config={u'GLOBAL': {u'watchman_socket_path': u'/tmp/watchman.10384.sock', u'pants_subprocessdir': u'/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids', u'level': u'debug', u'enable_pantsd': True}}) (extra_env=None)
                     
                     completed in 2.80230903625 seconds
                     PantsDaemonMonitor: pid is 11241 is_alive=True
                     
                     running: ./pants help (config={u'GLOBAL': {u'watchman_socket_path': u'/tmp/watchman.10384.sock', u'pants_subprocessdir': u'/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids', u'level': u'info', u'enable_pantsd': True}}) (extra_env=None)
                     
                     completed in 1.24617195129 seconds
                     PantsDaemonMonitor: pid is 11241 is_alive=True
                     
                     running: ./pants -ldebug help (config={u'GLOBAL': {u'watchman_socket_path': u'/tmp/watchman.10384.sock', u'pants_subprocessdir': u'/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids', u'level': u'info', u'enable_pantsd': True}}) (extra_env=None)
                     
                     completed in 2.71507883072 seconds
                     PantsDaemonMonitor: pid is 11396 is_alive=True
                     
                     running: ./pants help (config={u'GLOBAL': {u'watchman_socket_path': u'/tmp/watchman.10384.sock', u'pants_subprocessdir': u'/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids', u'level': u'debug', u'enable_pantsd': True}}) (extra_env=None)
                     
                     completed in 1.2286400795 seconds
                     PantsDaemonMonitor: pid is 11396 is_alive=True
                     
                     running: ./pants -linfo help (config={u'GLOBAL': {u'watchman_socket_path': u'/tmp/watchman.10384.sock', u'pants_subprocessdir': u'/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids', u'level': u'debug', u'enable_pantsd': True}}) (extra_env=None)
                     
                     completed in 2.66272878647 seconds
                     PantsDaemonMonitor: pid is 11551 is_alive=True
                     
                     running: ./pants help (config={u'GLOBAL': {u'watchman_socket_path': u'/tmp/watchman.10384.sock', u'pants_subprocessdir': u'/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids', u'level': u'info', u'enable_pantsd': True}}) (extra_env=None)
                     
                     completed in 1.20683908463 seconds
                     PantsDaemonMonitor: pid is 11551 is_alive=True
                     
                     running: ./pants -ldebug help (config={u'GLOBAL': {u'watchman_socket_path': u'/tmp/watchman.10384.sock', u'pants_subprocessdir': u'/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids', u'level': u'info', u'enable_pantsd': True}}) (extra_env=None)
                     
                     completed in 1.06143808365 seconds
                     ===============================================================
                     - BEGIN pantsd.log --------------------------------------------
                     ===============================================================
                     I0713 17:01:07.157752 10967 pants_daemon.py:360] pantsd starting, log level is INFO
                     I0713 17:01:07.158081 10967 pants_daemon.py:309] setting up service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7f09787fbb10>
                     I0713 17:01:07.158202 10967 pants_daemon.py:309] setting up service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f097c26a450>
                     I0713 17:01:07.158286 10967 scheduler_service.py:74] watching invalidating files: set([])
                     I0713 17:01:07.158359 10967 pants_daemon.py:309] setting up service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7f09787a6d10>
                     I0713 17:01:07.158416 10967 pants_daemon.py:309] setting up service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7f09787a6f90>
                     I0713 17:01:07.158575 10967 pants_daemon.py:328] starting service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7f09787fbb10>
                     I0713 17:01:07.158945 10967 pants_daemon.py:328] starting service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7f09787a6f90>
                     I0713 17:01:07.159451 10967 pants_daemon.py:328] starting service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f097c26a450>
                     I0713 17:01:07.161123 10967 pants_daemon.py:328] starting service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7f09787a6d10>
                     I0713 17:01:07.161972 10967 pailgun_service.py:102] starting pailgun server on port 46870
                     I0713 17:01:07.211781 10967 pailgun_server.py:72] handling pailgun request: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini kill-pantsd`
                     I0713 17:01:07.425451 10967 pailgun_server.py:81] pailgun request completed: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini kill-pantsd`
                     I0713 17:01:07.829041 10967 watchman.py:184] confirmed watchman subscription: {u'subscribe': 'all_files', u'version': u'4.9.1', u'clock': u'c:1531501266:10948:1:3'}
                     I0713 17:01:07.835637 10967 scheduler_service.py:82] enqueuing 10596 changes for subscription all_files
                     I0713 17:01:07.877067 10967 watchman.py:184] confirmed watchman subscription: {u'subscribe': 'pantsd_pid', u'version': u'4.9.1', u'clock': u'c:1531501266:10948:1:8'}
                     I0713 17:01:07.878284 10967 scheduler_service.py:82] enqueuing 1 changes for subscription pantsd_pid
                     D0713 17:01:10.226243 11083 pants_daemon.py:302] logging initialized
                     I0713 17:01:10.226421 11083 pants_daemon.py:360] pantsd starting, log level is DEBUG
                     I0713 17:01:10.226687 11083 pants_daemon.py:309] setting up service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7efc7d704b10>
                     I0713 17:01:10.226804 11083 pants_daemon.py:309] setting up service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7efc81172450>
                     I0713 17:01:10.226883 11083 scheduler_service.py:74] watching invalidating files: set([])
                     I0713 17:01:10.226955 11083 pants_daemon.py:309] setting up service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7efc7d693750>
                     I0713 17:01:10.227013 11083 pants_daemon.py:309] setting up service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7efc7d6aec90>
                     I0713 17:01:10.227164 11083 pants_daemon.py:328] starting service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7efc7d704b10>
                     I0713 17:01:10.227474 11083 pants_daemon.py:328] starting service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7efc7d6aec90>
                     I0713 17:01:10.228490 11083 pants_daemon.py:328] starting service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7efc81172450>
                     I0713 17:01:10.228949 11083 pants_daemon.py:328] starting service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7efc7d693750>
                     I0713 17:01:10.229293 11083 pailgun_service.py:102] starting pailgun server on port 38800
                     D0713 17:01:10.229176 11083 store_gc_service.py:40] Extending leases
                     D0713 17:01:10.230290 11083 store_gc_service.py:42] Done extending leases
                     D0713 17:01:10.230699 11083 watchman.py:68] setting initial watchman timeout to 30.0
                     I0713 17:01:10.296534 11083 pailgun_server.py:72] handling pailgun request: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini -ldebug help`
                     D0713 17:01:10.296696 11083 pailgun_server.py:73] pailgun request environment: {u'NAILGUN_PATHSEPARATOR': u':', u'TRAVIS_PULL_REQUEST_BRANCH': u'python/resolve/fix-current-platform-handling', u'rvm_version': u'1.29.3 (latest)', u'LC_CTYPE': u'en_US.UTF-8', u'TRAVIS': u'true', u'NAILGUN_TTY_2': u'0', u'NAILGUN_TTY_0': u'0', u'NAILGUN_TTY_1': u'0', u'TRAVIS_REPO_SLUG': u'pantsbuild/pants', u'PANTSD_RUNTRACKER_CLIENT_START_TIME': u'1531501268.91', u'TRAVIS_STACK_LANGUAGES': u'__garnet__ c c++ clojure cplusplus cpp default go groovy java node_js php pure_java python ruby scala', u'JRUBY_OPTS': u' --client -J-XX:+TieredCompilation -J-XX:TieredStopAtLevel=1 -J-Xss2m -Xcompile.invokedynamic=false', u'VIRTUAL_ENV': u'/home/travis/build/pantsbuild/pants/build-support/pants_dev_deps.venv', u'SHELL': u'/bin/bash', u'TRAVIS_UID': u'2000', u'PYENV_SHELL': u'bash', u'TRAVIS_BRANCH': u'master', u'TRAVIS_PULL_REQUEST_SLUG': u'jsirois/pants', u'HISTSIZE': u'1000', u'NVM_BIN': u'/home/travis/.nvm/versions/node/v8.9.1/bin', u'RBENV_SHELL': u'bash', u'MANPATH': u'/home/travis/.nvm/versions/node/v8.9.1/share/man:/home/travis/.kiex/elixirs/elixir-1.4.5/man:/home/travis/.rvm/rubies/ruby-2.4.1/share/man:/usr/local/man:/usr/local/cmake-3.9.2/man:/usr/local/clang-5.0.0/share/man:/usr/local/share/man:/usr/share/man:/home/travis/.rvm/man', u'JAVA_HOME': u'/usr/lib/jvm/java-8-oracle', u'XDG_RUNTIME_DIR': u'/run/user/2000', u'PYTHONPATH': u'/home/travis/build/pantsbuild/pants/src/python:', u'_system_type': u'Linux', u'TRAVIS_SECURE_ENV_VARS': u'false', u'MY_RUBY_HOME': u'/home/travis/.rvm/rubies/ruby-2.4.1', u'XDG_SESSION_ID': u'2', u'TRAVIS_DIST': u'trusty', u'RUBY_VERSION': u'ruby-2.4.1', u'CXX': u'g++', u'PIP_DISABLE_PIP_VERSION_CHECK': u'1', u'_system_version': u'14.04', u'TRAVIS_COMMIT_RANGE': u'2e171f73d1cc32256cf93d5b04246fda2ccb58f3...fe2907e76d98458a78ee066377965df4ca16ee9e', u'MAIL': u'/var/mail/travis', u'SSH_CONNECTION': u'10.10.4.33 36036 10.20.0.218 22', u'GOPATH': u'/home/travis/gopath', u'CONTINUOUS_INTEGRATION': u'true', u'GOROOT': u'/home/travis/.gimme/versions/go1.7.4.linux.amd64', u'TRAVIS_STACK_TIMESTAMP': u'2017-12-05 19:33:09 UTC', u'RACK_ENV': u'test', u'USER': u'travis', u'PYTHONUNBUFFERED': u'1', u'PS1': u'(pants_dev_deps.venv) ', u'PS4': u'+', u'SHLVL': u'3', u'TRAVIS_PULL_REQUEST_SHA': u'fe2907e76d98458a78ee066377965df4ca16ee9e', u'SHARD': u'Python integration tests for pants - shard 3', u'MERB_ENV': u'test', u'JDK_SWITCHER_DEFAULT': u'oraclejdk8', u'GIT_ASKPASS': u'echo', u'GEM_PATH': u'/home/travis/.rvm/gems/ruby-2.4.1:/home/travis/.rvm/gems/ruby-2.4.1@global', u'HAS_ANTARES_THREE_LITTLE_FRONZIES_BADGE': u'true', u'TRAVIS_EVENT_TYPE': u'pull_request', u'TRAVIS_TAG': u'', u'NAILGUN_FILESEPARATOR': u'/', u'TRAVIS_BUILD_NUMBER': u'18440', u'PYENV_ROOT': u'/opt/pyenv', u'TRAVIS_STACK_FEATURES': u'basic cassandra chromium couchdb disabled-ipv6 docker docker-compose elasticsearch firefox go-toolchain google-chrome jdk memcached mongodb mysql neo4j nodejs_interpreter perl_interpreter perlbrew phantomjs postgresql python_interpreter rabbitmq redis riak ruby_interpreter sqlite xserver', u'_system_name': u'Ubuntu', u'PAGER': u'cat', u'PYTEST_PASSTHRU_ARGS': u'-v --duration=3', u'TRAVIS_SUDO': u'true', u'MIX_ARCHIVES': u'/home/travis/.kiex/mix/elixir-1.4.5', u'TRAVIS_BUILD_ID': u'403626566', u'PANTS_CONFIG_FILES': u'/home/travis/build/pantsbuild/pants/pants.travis-ci.ini', u'NVM_DIR': u'/home/travis/.nvm', u'TRAVIS_STACK_NAME': u'garnet', u'HOME': u'/home/travis', u'TRAVIS_PULL_REQUEST': u'6104', u'LANG': u'en_US.UTF-8', u'TRAVIS_COMMIT': u'a6f28670c5c10199bd4a2bd1f34d8181f721326e', u'TRAVIS_STACK_JOB_BOARD_REGISTER': u'/.job-board-register.yml', u'_system_arch': u'x86_64', u'MYSQL_UNIX_PORT': u'/var/run/mysqld/mysqld.sock', u'CI': u'true', u'rvm_prefix': u'/home/travis', u'DEBIAN_FRONTEND': u'noninteractive', u'TRAVIS_PRE_CHEF_BOOTSTRAP_TIME': u'2017-12-05T19:32:55', u'TRAVIS_COMMIT_MESSAGE': u'Merge fe2907e76d98458a78ee066377965df4ca16ee9e into 2e171f73d1cc32256cf93d5b04246fda2ccb58f3', u'IRBRC': u'/home/travis/.rvm/rubies/ruby-2.4.1/.irbrc', u'rvm_path': u'/home/travis/.rvm', u'CASHER_DIR': u'/home/travis/.casher', u'COLUMNS': u'50', u'TRAVIS_STACK_NODE_ATTRIBUTES': u'/.node-attributes.yml', u'SSH_TTY': u'/dev/pts/0', u'PERLBREW_HOME': u'/home/travis/.perlbrew', u'GEM_HOME': u'/home/travis/.rvm/gems/ruby-2.4.1', u'HAS_JOSH_K_SEAL_OF_APPROVAL': u'true', u'PYTHON_CFLAGS': u'-g -fstack-protector --param=ssp-buffer-size=4 -Wformat -Werror=format-security', u'COMPOSER_NO_INTERACTION': u'1', u'NVM_CD_FLAGS': u'', u'TRAVIS_BUILD_STAGE_NAME': u'Test pants', u'SSH_CLIENT': u'10.10.4.33 36036 22', u'PERLBREW_BASHRC_VERSION': u'0.80', u'LOGNAME': u'travis', u'TRAVIS_INIT': u'upstart', u'PATH': u'/home/travis/build/pantsbuild/pants/build-support/pants_dev_deps.venv/bin:/home/travis/.rvm/gems/ruby-2.4.1/bin:/home/travis/.rvm/gems/ruby-2.4.1@global/bin:/home/travis/.rvm/rubies/ruby-2.4.1/bin:/home/travis/.rvm/bin:/home/travis/virtualenv/python2.7.13/bin:/home/travis/bin:/home/travis/.local/bin:/opt/pyenv/shims:/home/travis/.phpenv/shims:/home/travis/perl5/perlbrew/bin:/home/travis/.nvm/versions/node/v8.9.1/bin:/home/travis/.kiex/elixirs/elixir-1.4.5/bin:/home/travis/.kiex/bin:/home/travis/gopath/bin:/home/travis/.gimme/versions/go1.7.4.linux.amd64/bin:/usr/local/phantomjs/bin:/usr/local/phantomjs:/usr/local/neo4j-3.2.7/bin:/usr/local/maven-3.5.2/bin:/usr/local/cmake-3.9.2/bin:/usr/local/clang-5.0.0/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/home/travis/.phpenv/bin:/opt/pyenv/bin:/home/travis/.yarn/bin', u'TRAVIS_ALLOW_FAILURE': u'false', u'elapsed_start_time': u'1531498647', u'TERM': u'xterm', u'TZ': u'UTC', u'HISTFILESIZE': u'2000', u'TRAVIS_OSX_IMAGE': u'', u'rvm_bin_path': u'/home/travis/.rvm/bin', u'RAILS_ENV': u'test', u'PERLBREW_ROOT': u'/home/travis/perl5/perlbrew', u'TRAVIS_JOB_NUMBER': u'18440.10', u'PYTHON_CONFIGURE_OPTS': u'--enable-unicode=ucs4 --with-wide-unicode --enable-shared --enable-ipv6 --enable-loadable-sqlite-extensions --with-computed-gotos', u'LC_ALL': u'en_US.UTF-8', u'TRAVIS_JOB_ID': u'403626576', u'PYTEST_CURRENT_TEST': u'../tests/python/pants_test/pantsd/test_pantsd_integration.py::TestPantsDaemonIntegration::test_pantsd_lifecycle_invalidation (call)', u'TRAVIS_PYTHON_VERSION': u'2.7.13', u'TRAVIS_LANGUAGE': u'python', u'TRAVIS_BUILD_DIR': u'/home/travis/build/pantsbuild/pants', u'HISTCONTROL': u'ignoredups:ignorespace', u'PWD': u'/home/travis/build/pantsbuild/pants', u'TRAVIS_OS_NAME': u'linux', u'ELIXIR_VERSION': u'1.4.5', u'rvm_pretty_print_flag': u'auto'}
                     D0713 17:01:10.297046 11083 pailgun_service.py:60] execution commandline: [u'./pants', u'--no-pantsrc', u'--pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d', u'--kill-nailguns', u'--print-exception-stacktrace=True', u'--pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini', u'-ldebug', u'help']
                     D0713 17:01:10.478298 11083 pailgun_service.py:67] warming the product graph via <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7efc81172450>
                     D0713 17:01:10.491489 11083 target_roots_calculator.py:145] spec_roots are: None
                     D0713 17:01:10.491966 11083 target_roots_calculator.py:146] changed_request is: ChangedRequest(changes_since=None, diffspec=None, include_dependees=none, fast=False)
                     D0713 17:01:10.492297 11083 target_roots_calculator.py:147] owned_files are: []
                     D0713 17:01:10.500983 11083 git.py:294] Executing: git --git-dir=/home/travis/build/pantsbuild/pants/.git --work-tree=/home/travis/build/pantsbuild/pants rev-parse --abbrev-ref HEAD
                     D0713 17:01:10.506392 11083 build_environment.py:83] Detected git repository at /home/travis/build/pantsbuild/pants on branch None
                     D0713 17:01:10.506901 11083 engine_initializer.py:155] warming target_roots for: TargetRoots(specs=None)
                     D0713 17:01:10.507821 11083 scheduler.py:496] computed 0 nodes in 0.000370 seconds. there are 0 total nodes.
                     D0713 17:01:10.509743 11083 process_manager.py:213] purging metadata directory: /home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids/pantsd-run-2018-07-13t17_01_10_508043
                     D0713 17:01:10.510088 11083 process_manager.py:460] forking <pants.bin.daemon_pants_runner.DaemonPantsRunner object at 0x7efc82464210>
                     I0713 17:01:10.517646 11083 pailgun_server.py:81] pailgun request completed: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini -ldebug help`
                     D0713 17:01:10.842865 11083 watchman.py:152] set post-startup watchman timeout to 5.0
                     D0713 17:01:10.843183 11083 watchman.py:177] watchman command_list is: [[u'subscribe', '/home/travis/build/pantsbuild/pants', u'all_files', {'fields': [u'name'], 'expression': [u'allof', [u'not', [u'dirname', u'dist', [u'depth', u'eq', 0]]], [u'not', [u'pcre', u'^\\..*', u'wholename']], [u'not', [u'match', u'*.pyc']]]}], [u'subscribe', '/home/travis/build/pantsbuild/pants', u'pantsd_pid', {'fields': [u'name'], 'expression': [u'allof', [u'dirname', u'.pants.d/tmp/tmpsYhrVh.pants.d/.pids/pantsd'], [u'name', u'pid']]}]]
                     I0713 17:01:10.893743 11083 watchman.py:184] confirmed watchman subscription: {u'subscribe': 'all_files', u'version': u'4.9.1', u'clock': u'c:1531501269:11064:1:6'}
                     I0713 17:01:10.902504 11083 scheduler_service.py:82] enqueuing 10596 changes for subscription all_files
                     I0713 17:01:10.934089 11083 watchman.py:184] confirmed watchman subscription: {u'subscribe': 'pantsd_pid', u'version': u'4.9.1', u'clock': u'c:1531501269:11064:1:8'}
                     D0713 17:01:10.934344 11083 fs_event_service.py:161] callback ID 1 for all_files succeeded
                     I0713 17:01:10.935307 11083 scheduler_service.py:82] enqueuing 1 changes for subscription pantsd_pid
                     D0713 17:01:10.935621 11083 fs_event_service.py:161] callback ID 2 for pantsd_pid succeeded
                     D0713 17:01:10.959840 11083 scheduler_service.py:138] processing 10596 files for subscription all_files (first_event=True)
                     D0713 17:01:10.961242 11083 scheduler_service.py:138] processing 1 files for subscription pantsd_pid (first_event=True)
                     I0713 17:01:11.853085 11083 pailgun_server.py:72] handling pailgun request: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini help`
                     D0713 17:01:11.853262 11083 pailgun_server.py:73] pailgun request environment: {u'NAILGUN_PATHSEPARATOR': u':', u'TRAVIS_PULL_REQUEST_BRANCH': u'python/resolve/fix-current-platform-handling', u'rvm_version': u'1.29.3 (latest)', u'LC_CTYPE': u'en_US.UTF-8', u'TRAVIS': u'true', u'NAILGUN_TTY_2': u'0', u'NAILGUN_TTY_0': u'0', u'NAILGUN_TTY_1': u'0', u'TRAVIS_REPO_SLUG': u'pantsbuild/pants', u'PANTSD_RUNTRACKER_CLIENT_START_TIME': u'1531501271.84', u'TRAVIS_STACK_LANGUAGES': u'__garnet__ c c++ clojure cplusplus cpp default go groovy java node_js php pure_java python ruby scala', u'JRUBY_OPTS': u' --client -J-XX:+TieredCompilation -J-XX:TieredStopAtLevel=1 -J-Xss2m -Xcompile.invokedynamic=false', u'VIRTUAL_ENV': u'/home/travis/build/pantsbuild/pants/build-support/pants_dev_deps.venv', u'SHELL': u'/bin/bash', u'TRAVIS_UID': u'2000', u'PYENV_SHELL': u'bash', u'TRAVIS_BRANCH': u'master', u'TRAVIS_PULL_REQUEST_SLUG': u'jsirois/pants', u'HISTSIZE': u'1000', u'NVM_BIN': u'/home/travis/.nvm/versions/node/v8.9.1/bin', u'RBENV_SHELL': u'bash', u'MANPATH': u'/home/travis/.nvm/versions/node/v8.9.1/share/man:/home/travis/.kiex/elixirs/elixir-1.4.5/man:/home/travis/.rvm/rubies/ruby-2.4.1/share/man:/usr/local/man:/usr/local/cmake-3.9.2/man:/usr/local/clang-5.0.0/share/man:/usr/local/share/man:/usr/share/man:/home/travis/.rvm/man', u'JAVA_HOME': u'/usr/lib/jvm/java-8-oracle', u'XDG_RUNTIME_DIR': u'/run/user/2000', u'PYTHONPATH': u'/home/travis/build/pantsbuild/pants/src/python:', u'_system_type': u'Linux', u'TRAVIS_SECURE_ENV_VARS': u'false', u'MY_RUBY_HOME': u'/home/travis/.rvm/rubies/ruby-2.4.1', u'XDG_SESSION_ID': u'2', u'TRAVIS_DIST': u'trusty', u'RUBY_VERSION': u'ruby-2.4.1', u'CXX': u'g++', u'PIP_DISABLE_PIP_VERSION_CHECK': u'1', u'_system_version': u'14.04', u'TRAVIS_COMMIT_RANGE': u'2e171f73d1cc32256cf93d5b04246fda2ccb58f3...fe2907e76d98458a78ee066377965df4ca16ee9e', u'MAIL': u'/var/mail/travis', u'SSH_CONNECTION': u'10.10.4.33 36036 10.20.0.218 22', u'GOPATH': u'/home/travis/gopath', u'CONTINUOUS_INTEGRATION': u'true', u'GOROOT': u'/home/travis/.gimme/versions/go1.7.4.linux.amd64', u'TRAVIS_STACK_TIMESTAMP': u'2017-12-05 19:33:09 UTC', u'RACK_ENV': u'test', u'USER': u'travis', u'PYTHONUNBUFFERED': u'1', u'PS1': u'(pants_dev_deps.venv) ', u'PS4': u'+', u'SHLVL': u'3', u'TRAVIS_PULL_REQUEST_SHA': u'fe2907e76d98458a78ee066377965df4ca16ee9e', u'SHARD': u'Python integration tests for pants - shard 3', u'MERB_ENV': u'test', u'JDK_SWITCHER_DEFAULT': u'oraclejdk8', u'GIT_ASKPASS': u'echo', u'GEM_PATH': u'/home/travis/.rvm/gems/ruby-2.4.1:/home/travis/.rvm/gems/ruby-2.4.1@global', u'HAS_ANTARES_THREE_LITTLE_FRONZIES_BADGE': u'true', u'TRAVIS_EVENT_TYPE': u'pull_request', u'TRAVIS_TAG': u'', u'NAILGUN_FILESEPARATOR': u'/', u'TRAVIS_BUILD_NUMBER': u'18440', u'PYENV_ROOT': u'/opt/pyenv', u'TRAVIS_STACK_FEATURES': u'basic cassandra chromium couchdb disabled-ipv6 docker docker-compose elasticsearch firefox go-toolchain google-chrome jdk memcached mongodb mysql neo4j nodejs_interpreter perl_interpreter perlbrew phantomjs postgresql python_interpreter rabbitmq redis riak ruby_interpreter sqlite xserver', u'_system_name': u'Ubuntu', u'PAGER': u'cat', u'PYTEST_PASSTHRU_ARGS': u'-v --duration=3', u'TRAVIS_SUDO': u'true', u'MIX_ARCHIVES': u'/home/travis/.kiex/mix/elixir-1.4.5', u'TRAVIS_BUILD_ID': u'403626566', u'PANTS_CONFIG_FILES': u'/home/travis/build/pantsbuild/pants/pants.travis-ci.ini', u'NVM_DIR': u'/home/travis/.nvm', u'TRAVIS_STACK_NAME': u'garnet', u'HOME': u'/home/travis', u'TRAVIS_PULL_REQUEST': u'6104', u'LANG': u'en_US.UTF-8', u'TRAVIS_COMMIT': u'a6f28670c5c10199bd4a2bd1f34d8181f721326e', u'TRAVIS_STACK_JOB_BOARD_REGISTER': u'/.job-board-register.yml', u'_system_arch': u'x86_64', u'MYSQL_UNIX_PORT': u'/var/run/mysqld/mysqld.sock', u'CI': u'true', u'rvm_prefix': u'/home/travis', u'DEBIAN_FRONTEND': u'noninteractive', u'TRAVIS_PRE_CHEF_BOOTSTRAP_TIME': u'2017-12-05T19:32:55', u'TRAVIS_COMMIT_MESSAGE': u'Merge fe2907e76d98458a78ee066377965df4ca16ee9e into 2e171f73d1cc32256cf93d5b04246fda2ccb58f3', u'IRBRC': u'/home/travis/.rvm/rubies/ruby-2.4.1/.irbrc', u'rvm_path': u'/home/travis/.rvm', u'CASHER_DIR': u'/home/travis/.casher', u'COLUMNS': u'50', u'TRAVIS_STACK_NODE_ATTRIBUTES': u'/.node-attributes.yml', u'SSH_TTY': u'/dev/pts/0', u'PERLBREW_HOME': u'/home/travis/.perlbrew', u'GEM_HOME': u'/home/travis/.rvm/gems/ruby-2.4.1', u'HAS_JOSH_K_SEAL_OF_APPROVAL': u'true', u'PYTHON_CFLAGS': u'-g -fstack-protector --param=ssp-buffer-size=4 -Wformat -Werror=format-security', u'COMPOSER_NO_INTERACTION': u'1', u'NVM_CD_FLAGS': u'', u'TRAVIS_BUILD_STAGE_NAME': u'Test pants', u'SSH_CLIENT': u'10.10.4.33 36036 22', u'PERLBREW_BASHRC_VERSION': u'0.80', u'LOGNAME': u'travis', u'TRAVIS_INIT': u'upstart', u'PATH': u'/home/travis/build/pantsbuild/pants/build-support/pants_dev_deps.venv/bin:/home/travis/.rvm/gems/ruby-2.4.1/bin:/home/travis/.rvm/gems/ruby-2.4.1@global/bin:/home/travis/.rvm/rubies/ruby-2.4.1/bin:/home/travis/.rvm/bin:/home/travis/virtualenv/python2.7.13/bin:/home/travis/bin:/home/travis/.local/bin:/opt/pyenv/shims:/home/travis/.phpenv/shims:/home/travis/perl5/perlbrew/bin:/home/travis/.nvm/versions/node/v8.9.1/bin:/home/travis/.kiex/elixirs/elixir-1.4.5/bin:/home/travis/.kiex/bin:/home/travis/gopath/bin:/home/travis/.gimme/versions/go1.7.4.linux.amd64/bin:/usr/local/phantomjs/bin:/usr/local/phantomjs:/usr/local/neo4j-3.2.7/bin:/usr/local/maven-3.5.2/bin:/usr/local/cmake-3.9.2/bin:/usr/local/clang-5.0.0/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/home/travis/.phpenv/bin:/opt/pyenv/bin:/home/travis/.yarn/bin', u'TRAVIS_ALLOW_FAILURE': u'false', u'elapsed_start_time': u'1531498647', u'TERM': u'xterm', u'TZ': u'UTC', u'HISTFILESIZE': u'2000', u'TRAVIS_OSX_IMAGE': u'', u'rvm_bin_path': u'/home/travis/.rvm/bin', u'RAILS_ENV': u'test', u'PERLBREW_ROOT': u'/home/travis/perl5/perlbrew', u'TRAVIS_JOB_NUMBER': u'18440.10', u'PYTHON_CONFIGURE_OPTS': u'--enable-unicode=ucs4 --with-wide-unicode --enable-shared --enable-ipv6 --enable-loadable-sqlite-extensions --with-computed-gotos', u'LC_ALL': u'en_US.UTF-8', u'TRAVIS_JOB_ID': u'403626576', u'PYTEST_CURRENT_TEST': u'../tests/python/pants_test/pantsd/test_pantsd_integration.py::TestPantsDaemonIntegration::test_pantsd_lifecycle_invalidation (call)', u'TRAVIS_PYTHON_VERSION': u'2.7.13', u'TRAVIS_LANGUAGE': u'python', u'TRAVIS_BUILD_DIR': u'/home/travis/build/pantsbuild/pants', u'HISTCONTROL': u'ignoredups:ignorespace', u'PWD': u'/home/travis/build/pantsbuild/pants', u'TRAVIS_OS_NAME': u'linux', u'ELIXIR_VERSION': u'1.4.5', u'rvm_pretty_print_flag': u'auto'}
                     D0713 17:01:11.853672 11083 pailgun_service.py:60] execution commandline: [u'./pants', u'--no-pantsrc', u'--pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d', u'--kill-nailguns', u'--print-exception-stacktrace=True', u'--pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini', u'help']
                     D0713 17:01:11.991677 11083 pailgun_service.py:67] warming the product graph via <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7efc81172450>
                     D0713 17:01:11.998593 11083 target_roots_calculator.py:145] spec_roots are: None
                     D0713 17:01:11.998742 11083 target_roots_calculator.py:146] changed_request is: ChangedRequest(changes_since=None, diffspec=None, include_dependees=none, fast=False)
                     D0713 17:01:11.998908 11083 target_roots_calculator.py:147] owned_files are: []
                     D0713 17:01:11.999090 11083 engine_initializer.py:155] warming target_roots for: TargetRoots(specs=None)
                     D0713 17:01:11.999563 11083 scheduler.py:496] computed 0 nodes in 0.000279 seconds. there are 0 total nodes.
                     D0713 17:01:11.999991 11083 process_manager.py:213] purging metadata directory: /home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids/pantsd-run-2018-07-13t17_01_11_999732
                     D0713 17:01:12.000281 11083 process_manager.py:460] forking <pants.bin.daemon_pants_runner.DaemonPantsRunner object at 0x7efc7d6bdb10>
                     I0713 17:01:12.008246 11083 pailgun_server.py:81] pailgun request completed: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini help`
                     I0713 17:01:14.511209 11241 pants_daemon.py:360] pantsd starting, log level is INFO
                     I0713 17:01:14.511677 11241 pants_daemon.py:309] setting up service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7f8083eb1b10>
                     I0713 17:01:14.511878 11241 pants_daemon.py:309] setting up service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f8087920450>
                     I0713 17:01:14.512000 11241 scheduler_service.py:74] watching invalidating files: set([])
                     I0713 17:01:14.512159 11241 pants_daemon.py:309] setting up service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7f8083e5dfd0>
                     I0713 17:01:14.512275 11241 pants_daemon.py:309] setting up service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7f8083e5ddd0>
                     I0713 17:01:14.512548 11241 pants_daemon.py:328] starting service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7f8083eb1b10>
                     I0713 17:01:14.513623 11241 pants_daemon.py:328] starting service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7f8083e5ddd0>
                     I0713 17:01:14.514419 11241 pants_daemon.py:328] starting service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f8087920450>
                     I0713 17:01:14.514931 11241 pants_daemon.py:328] starting service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7f8083e5dfd0>
                     I0713 17:01:14.515222 11241 pailgun_service.py:102] starting pailgun server on port 38478
                     I0713 17:01:14.564955 11241 watchman.py:184] confirmed watchman subscription: {u'subscribe': 'all_files', u'version': u'4.9.1', u'clock': u'c:1531501269:11064:1:105'}
                     I0713 17:01:14.566349 11241 pailgun_server.py:72] handling pailgun request: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini -linfo help`
                     I0713 17:01:14.568869 11241 scheduler_service.py:82] enqueuing 10596 changes for subscription all_files
                     I0713 17:01:14.600944 11241 watchman.py:184] confirmed watchman subscription: {u'subscribe': 'pantsd_pid', u'version': u'4.9.1', u'clock': u'c:1531501269:11064:1:108'}
                     I0713 17:01:14.602884 11241 scheduler_service.py:82] enqueuing 1 changes for subscription pantsd_pid
                     I0713 17:01:14.747867 11241 pailgun_server.py:81] pailgun request completed: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini -linfo help`
                     I0713 17:01:15.908832 11241 pailgun_server.py:72] handling pailgun request: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini help`
                     I0713 17:01:16.073143 11241 pailgun_server.py:81] pailgun request completed: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini help`
                     D0713 17:01:18.465053 11396 pants_daemon.py:302] logging initialized
                     I0713 17:01:18.465276 11396 pants_daemon.py:360] pantsd starting, log level is DEBUG
                     I0713 17:01:18.465723 11396 pants_daemon.py:309] setting up service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7fd2427cab10>
                     I0713 17:01:18.465912 11396 pants_daemon.py:309] setting up service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7fd246238450>
                     I0713 17:01:18.466047 11396 scheduler_service.py:74] watching invalidating files: set([])
                     I0713 17:01:18.466186 11396 pants_daemon.py:309] setting up service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7fd242774d10>
                     I0713 17:01:18.466299 11396 pants_daemon.py:309] setting up service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7fd242774f50>
                     I0713 17:01:18.466587 11396 pants_daemon.py:328] starting service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7fd2427cab10>
                     I0713 17:01:18.467003 11396 pants_daemon.py:328] starting service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7fd242774f50>
                     I0713 17:01:18.467569 11396 pants_daemon.py:328] starting service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7fd246238450>
                     D0713 17:01:18.467767 11396 store_gc_service.py:40] Extending leases
                     D0713 17:01:18.468694 11396 store_gc_service.py:42] Done extending leases
                     I0713 17:01:18.469058 11396 pants_daemon.py:328] starting service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7fd242774d10>
                     I0713 17:01:18.469566 11396 pailgun_service.py:102] starting pailgun server on port 33411
                     D0713 17:01:18.470180 11396 watchman.py:68] setting initial watchman timeout to 30.0
                     D0713 17:01:18.486447 11396 watchman.py:152] set post-startup watchman timeout to 5.0
                     D0713 17:01:18.486927 11396 watchman.py:177] watchman command_list is: [[u'subscribe', '/home/travis/build/pantsbuild/pants', u'all_files', {'fields': [u'name'], 'expression': [u'allof', [u'not', [u'dirname', u'dist', [u'depth', u'eq', 0]]], [u'not', [u'pcre', u'^\\..*', u'wholename']], [u'not', [u'match', u'*.pyc']]]}], [u'subscribe', '/home/travis/build/pantsbuild/pants', u'pantsd_pid', {'fields': [u'name'], 'expression': [u'allof', [u'dirname', u'.pants.d/tmp/tmpsYhrVh.pants.d/.pids/pantsd'], [u'name', u'pid']]}]]
                     I0713 17:01:18.517385 11396 watchman.py:184] confirmed watchman subscription: {u'subscribe': 'all_files', u'version': u'4.9.1', u'clock': u'c:1531501269:11064:1:209'}
                     I0713 17:01:18.521579 11396 scheduler_service.py:82] enqueuing 10596 changes for subscription all_files
                     D0713 17:01:18.561434 11396 scheduler_service.py:138] processing 10596 files for subscription all_files (first_event=True)
                     I0713 17:01:18.561686 11396 watchman.py:184] confirmed watchman subscription: {u'subscribe': 'pantsd_pid', u'version': u'4.9.1', u'clock': u'c:1531501269:11064:1:210'}
                     D0713 17:01:18.563321 11396 fs_event_service.py:161] callback ID 1 for all_files succeeded
                     I0713 17:01:18.563710 11396 scheduler_service.py:82] enqueuing 1 changes for subscription pantsd_pid
                     D0713 17:01:18.564069 11396 scheduler_service.py:138] processing 1 files for subscription pantsd_pid (first_event=True)
                     D0713 17:01:18.564371 11396 fs_event_service.py:161] callback ID 2 for pantsd_pid succeeded
                     I0713 17:01:18.565150 11396 pailgun_server.py:72] handling pailgun request: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini -ldebug help`
                     D0713 17:01:18.565243 11396 pailgun_server.py:73] pailgun request environment: {u'NAILGUN_PATHSEPARATOR': u':', u'TRAVIS_PULL_REQUEST_BRANCH': u'python/resolve/fix-current-platform-handling', u'rvm_version': u'1.29.3 (latest)', u'LC_CTYPE': u'en_US.UTF-8', u'TRAVIS': u'true', u'NAILGUN_TTY_2': u'0', u'NAILGUN_TTY_0': u'0', u'NAILGUN_TTY_1': u'0', u'TRAVIS_REPO_SLUG': u'pantsbuild/pants', u'PANTSD_RUNTRACKER_CLIENT_START_TIME': u'1531501277.17', u'TRAVIS_STACK_LANGUAGES': u'__garnet__ c c++ clojure cplusplus cpp default go groovy java node_js php pure_java python ruby scala', u'JRUBY_OPTS': u' --client -J-XX:+TieredCompilation -J-XX:TieredStopAtLevel=1 -J-Xss2m -Xcompile.invokedynamic=false', u'VIRTUAL_ENV': u'/home/travis/build/pantsbuild/pants/build-support/pants_dev_deps.venv', u'SHELL': u'/bin/bash', u'TRAVIS_UID': u'2000', u'PYENV_SHELL': u'bash', u'TRAVIS_BRANCH': u'master', u'TRAVIS_PULL_REQUEST_SLUG': u'jsirois/pants', u'HISTSIZE': u'1000', u'NVM_BIN': u'/home/travis/.nvm/versions/node/v8.9.1/bin', u'RBENV_SHELL': u'bash', u'MANPATH': u'/home/travis/.nvm/versions/node/v8.9.1/share/man:/home/travis/.kiex/elixirs/elixir-1.4.5/man:/home/travis/.rvm/rubies/ruby-2.4.1/share/man:/usr/local/man:/usr/local/cmake-3.9.2/man:/usr/local/clang-5.0.0/share/man:/usr/local/share/man:/usr/share/man:/home/travis/.rvm/man', u'JAVA_HOME': u'/usr/lib/jvm/java-8-oracle', u'XDG_RUNTIME_DIR': u'/run/user/2000', u'PYTHONPATH': u'/home/travis/build/pantsbuild/pants/src/python:', u'_system_type': u'Linux', u'TRAVIS_SECURE_ENV_VARS': u'false', u'MY_RUBY_HOME': u'/home/travis/.rvm/rubies/ruby-2.4.1', u'XDG_SESSION_ID': u'2', u'TRAVIS_DIST': u'trusty', u'RUBY_VERSION': u'ruby-2.4.1', u'CXX': u'g++', u'PIP_DISABLE_PIP_VERSION_CHECK': u'1', u'_system_version': u'14.04', u'TRAVIS_COMMIT_RANGE': u'2e171f73d1cc32256cf93d5b04246fda2ccb58f3...fe2907e76d98458a78ee066377965df4ca16ee9e', u'MAIL': u'/var/mail/travis', u'SSH_CONNECTION': u'10.10.4.33 36036 10.20.0.218 22', u'GOPATH': u'/home/travis/gopath', u'CONTINUOUS_INTEGRATION': u'true', u'GOROOT': u'/home/travis/.gimme/versions/go1.7.4.linux.amd64', u'TRAVIS_STACK_TIMESTAMP': u'2017-12-05 19:33:09 UTC', u'RACK_ENV': u'test', u'USER': u'travis', u'PYTHONUNBUFFERED': u'1', u'PS1': u'(pants_dev_deps.venv) ', u'PS4': u'+', u'SHLVL': u'3', u'TRAVIS_PULL_REQUEST_SHA': u'fe2907e76d98458a78ee066377965df4ca16ee9e', u'SHARD': u'Python integration tests for pants - shard 3', u'MERB_ENV': u'test', u'JDK_SWITCHER_DEFAULT': u'oraclejdk8', u'GIT_ASKPASS': u'echo', u'GEM_PATH': u'/home/travis/.rvm/gems/ruby-2.4.1:/home/travis/.rvm/gems/ruby-2.4.1@global', u'HAS_ANTARES_THREE_LITTLE_FRONZIES_BADGE': u'true', u'TRAVIS_EVENT_TYPE': u'pull_request', u'TRAVIS_TAG': u'', u'NAILGUN_FILESEPARATOR': u'/', u'TRAVIS_BUILD_NUMBER': u'18440', u'PYENV_ROOT': u'/opt/pyenv', u'TRAVIS_STACK_FEATURES': u'basic cassandra chromium couchdb disabled-ipv6 docker docker-compose elasticsearch firefox go-toolchain google-chrome jdk memcached mongodb mysql neo4j nodejs_interpreter perl_interpreter perlbrew phantomjs postgresql python_interpreter rabbitmq redis riak ruby_interpreter sqlite xserver', u'_system_name': u'Ubuntu', u'PAGER': u'cat', u'PYTEST_PASSTHRU_ARGS': u'-v --duration=3', u'TRAVIS_SUDO': u'true', u'MIX_ARCHIVES': u'/home/travis/.kiex/mix/elixir-1.4.5', u'TRAVIS_BUILD_ID': u'403626566', u'PANTS_CONFIG_FILES': u'/home/travis/build/pantsbuild/pants/pants.travis-ci.ini', u'NVM_DIR': u'/home/travis/.nvm', u'TRAVIS_STACK_NAME': u'garnet', u'HOME': u'/home/travis', u'TRAVIS_PULL_REQUEST': u'6104', u'LANG': u'en_US.UTF-8', u'TRAVIS_COMMIT': u'a6f28670c5c10199bd4a2bd1f34d8181f721326e', u'TRAVIS_STACK_JOB_BOARD_REGISTER': u'/.job-board-register.yml', u'_system_arch': u'x86_64', u'MYSQL_UNIX_PORT': u'/var/run/mysqld/mysqld.sock', u'CI': u'true', u'rvm_prefix': u'/home/travis', u'DEBIAN_FRONTEND': u'noninteractive', u'TRAVIS_PRE_CHEF_BOOTSTRAP_TIME': u'2017-12-05T19:32:55', u'TRAVIS_COMMIT_MESSAGE': u'Merge fe2907e76d98458a78ee066377965df4ca16ee9e into 2e171f73d1cc32256cf93d5b04246fda2ccb58f3', u'IRBRC': u'/home/travis/.rvm/rubies/ruby-2.4.1/.irbrc', u'rvm_path': u'/home/travis/.rvm', u'CASHER_DIR': u'/home/travis/.casher', u'COLUMNS': u'50', u'TRAVIS_STACK_NODE_ATTRIBUTES': u'/.node-attributes.yml', u'SSH_TTY': u'/dev/pts/0', u'PERLBREW_HOME': u'/home/travis/.perlbrew', u'GEM_HOME': u'/home/travis/.rvm/gems/ruby-2.4.1', u'HAS_JOSH_K_SEAL_OF_APPROVAL': u'true', u'PYTHON_CFLAGS': u'-g -fstack-protector --param=ssp-buffer-size=4 -Wformat -Werror=format-security', u'COMPOSER_NO_INTERACTION': u'1', u'NVM_CD_FLAGS': u'', u'TRAVIS_BUILD_STAGE_NAME': u'Test pants', u'SSH_CLIENT': u'10.10.4.33 36036 22', u'PERLBREW_BASHRC_VERSION': u'0.80', u'LOGNAME': u'travis', u'TRAVIS_INIT': u'upstart', u'PATH': u'/home/travis/build/pantsbuild/pants/build-support/pants_dev_deps.venv/bin:/home/travis/.rvm/gems/ruby-2.4.1/bin:/home/travis/.rvm/gems/ruby-2.4.1@global/bin:/home/travis/.rvm/rubies/ruby-2.4.1/bin:/home/travis/.rvm/bin:/home/travis/virtualenv/python2.7.13/bin:/home/travis/bin:/home/travis/.local/bin:/opt/pyenv/shims:/home/travis/.phpenv/shims:/home/travis/perl5/perlbrew/bin:/home/travis/.nvm/versions/node/v8.9.1/bin:/home/travis/.kiex/elixirs/elixir-1.4.5/bin:/home/travis/.kiex/bin:/home/travis/gopath/bin:/home/travis/.gimme/versions/go1.7.4.linux.amd64/bin:/usr/local/phantomjs/bin:/usr/local/phantomjs:/usr/local/neo4j-3.2.7/bin:/usr/local/maven-3.5.2/bin:/usr/local/cmake-3.9.2/bin:/usr/local/clang-5.0.0/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/home/travis/.phpenv/bin:/opt/pyenv/bin:/home/travis/.yarn/bin', u'TRAVIS_ALLOW_FAILURE': u'false', u'elapsed_start_time': u'1531498647', u'TERM': u'xterm', u'TZ': u'UTC', u'HISTFILESIZE': u'2000', u'TRAVIS_OSX_IMAGE': u'', u'rvm_bin_path': u'/home/travis/.rvm/bin', u'RAILS_ENV': u'test', u'PERLBREW_ROOT': u'/home/travis/perl5/perlbrew', u'TRAVIS_JOB_NUMBER': u'18440.10', u'PYTHON_CONFIGURE_OPTS': u'--enable-unicode=ucs4 --with-wide-unicode --enable-shared --enable-ipv6 --enable-loadable-sqlite-extensions --with-computed-gotos', u'LC_ALL': u'en_US.UTF-8', u'TRAVIS_JOB_ID': u'403626576', u'PYTEST_CURRENT_TEST': u'../tests/python/pants_test/pantsd/test_pantsd_integration.py::TestPantsDaemonIntegration::test_pantsd_lifecycle_invalidation (call)', u'TRAVIS_PYTHON_VERSION': u'2.7.13', u'TRAVIS_LANGUAGE': u'python', u'TRAVIS_BUILD_DIR': u'/home/travis/build/pantsbuild/pants', u'HISTCONTROL': u'ignoredups:ignorespace', u'PWD': u'/home/travis/build/pantsbuild/pants', u'TRAVIS_OS_NAME': u'linux', u'ELIXIR_VERSION': u'1.4.5', u'rvm_pretty_print_flag': u'auto'}
                     D0713 17:01:18.565757 11396 pailgun_service.py:60] execution commandline: [u'./pants', u'--no-pantsrc', u'--pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d', u'--kill-nailguns', u'--print-exception-stacktrace=True', u'--pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini', u'-ldebug', u'help']
                     D0713 17:01:18.687866 11396 pailgun_service.py:67] warming the product graph via <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7fd246238450>
                     D0713 17:01:18.694708 11396 target_roots_calculator.py:145] spec_roots are: None
                     D0713 17:01:18.694891 11396 target_roots_calculator.py:146] changed_request is: ChangedRequest(changes_since=None, diffspec=None, include_dependees=none, fast=False)
                     D0713 17:01:18.695102 11396 target_roots_calculator.py:147] owned_files are: []
                     D0713 17:01:18.699723 11396 git.py:294] Executing: git --git-dir=/home/travis/build/pantsbuild/pants/.git --work-tree=/home/travis/build/pantsbuild/pants rev-parse --abbrev-ref HEAD
                     D0713 17:01:18.703603 11396 build_environment.py:83] Detected git repository at /home/travis/build/pantsbuild/pants on branch None
                     D0713 17:01:18.703967 11396 engine_initializer.py:155] warming target_roots for: TargetRoots(specs=None)
                     D0713 17:01:18.704945 11396 scheduler.py:496] computed 0 nodes in 0.000494 seconds. there are 0 total nodes.
                     D0713 17:01:18.706116 11396 process_manager.py:213] purging metadata directory: /home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids/pantsd-run-2018-07-13t17_01_18_705112
                     D0713 17:01:18.706414 11396 process_manager.py:460] forking <pants.bin.daemon_pants_runner.DaemonPantsRunner object at 0x7fd24752a210>
                     I0713 17:01:18.711800 11396 pailgun_server.py:81] pailgun request completed: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini -ldebug help`
                     I0713 17:01:19.862438 11396 pailgun_server.py:72] handling pailgun request: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini help`
                     D0713 17:01:19.862610 11396 pailgun_server.py:73] pailgun request environment: {u'NAILGUN_PATHSEPARATOR': u':', u'TRAVIS_PULL_REQUEST_BRANCH': u'python/resolve/fix-current-platform-handling', u'rvm_version': u'1.29.3 (latest)', u'LC_CTYPE': u'en_US.UTF-8', u'TRAVIS': u'true', u'NAILGUN_TTY_2': u'0', u'NAILGUN_TTY_0': u'0', u'NAILGUN_TTY_1': u'0', u'TRAVIS_REPO_SLUG': u'pantsbuild/pants', u'PANTSD_RUNTRACKER_CLIENT_START_TIME': u'1531501279.85', u'TRAVIS_STACK_LANGUAGES': u'__garnet__ c c++ clojure cplusplus cpp default go groovy java node_js php pure_java python ruby scala', u'JRUBY_OPTS': u' --client -J-XX:+TieredCompilation -J-XX:TieredStopAtLevel=1 -J-Xss2m -Xcompile.invokedynamic=false', u'VIRTUAL_ENV': u'/home/travis/build/pantsbuild/pants/build-support/pants_dev_deps.venv', u'SHELL': u'/bin/bash', u'TRAVIS_UID': u'2000', u'PYENV_SHELL': u'bash', u'TRAVIS_BRANCH': u'master', u'TRAVIS_PULL_REQUEST_SLUG': u'jsirois/pants', u'HISTSIZE': u'1000', u'NVM_BIN': u'/home/travis/.nvm/versions/node/v8.9.1/bin', u'RBENV_SHELL': u'bash', u'MANPATH': u'/home/travis/.nvm/versions/node/v8.9.1/share/man:/home/travis/.kiex/elixirs/elixir-1.4.5/man:/home/travis/.rvm/rubies/ruby-2.4.1/share/man:/usr/local/man:/usr/local/cmake-3.9.2/man:/usr/local/clang-5.0.0/share/man:/usr/local/share/man:/usr/share/man:/home/travis/.rvm/man', u'JAVA_HOME': u'/usr/lib/jvm/java-8-oracle', u'XDG_RUNTIME_DIR': u'/run/user/2000', u'PYTHONPATH': u'/home/travis/build/pantsbuild/pants/src/python:', u'_system_type': u'Linux', u'TRAVIS_SECURE_ENV_VARS': u'false', u'MY_RUBY_HOME': u'/home/travis/.rvm/rubies/ruby-2.4.1', u'XDG_SESSION_ID': u'2', u'TRAVIS_DIST': u'trusty', u'RUBY_VERSION': u'ruby-2.4.1', u'CXX': u'g++', u'PIP_DISABLE_PIP_VERSION_CHECK': u'1', u'_system_version': u'14.04', u'TRAVIS_COMMIT_RANGE': u'2e171f73d1cc32256cf93d5b04246fda2ccb58f3...fe2907e76d98458a78ee066377965df4ca16ee9e', u'MAIL': u'/var/mail/travis', u'SSH_CONNECTION': u'10.10.4.33 36036 10.20.0.218 22', u'GOPATH': u'/home/travis/gopath', u'CONTINUOUS_INTEGRATION': u'true', u'GOROOT': u'/home/travis/.gimme/versions/go1.7.4.linux.amd64', u'TRAVIS_STACK_TIMESTAMP': u'2017-12-05 19:33:09 UTC', u'RACK_ENV': u'test', u'USER': u'travis', u'PYTHONUNBUFFERED': u'1', u'PS1': u'(pants_dev_deps.venv) ', u'PS4': u'+', u'SHLVL': u'3', u'TRAVIS_PULL_REQUEST_SHA': u'fe2907e76d98458a78ee066377965df4ca16ee9e', u'SHARD': u'Python integration tests for pants - shard 3', u'MERB_ENV': u'test', u'JDK_SWITCHER_DEFAULT': u'oraclejdk8', u'GIT_ASKPASS': u'echo', u'GEM_PATH': u'/home/travis/.rvm/gems/ruby-2.4.1:/home/travis/.rvm/gems/ruby-2.4.1@global', u'HAS_ANTARES_THREE_LITTLE_FRONZIES_BADGE': u'true', u'TRAVIS_EVENT_TYPE': u'pull_request', u'TRAVIS_TAG': u'', u'NAILGUN_FILESEPARATOR': u'/', u'TRAVIS_BUILD_NUMBER': u'18440', u'PYENV_ROOT': u'/opt/pyenv', u'TRAVIS_STACK_FEATURES': u'basic cassandra chromium couchdb disabled-ipv6 docker docker-compose elasticsearch firefox go-toolchain google-chrome jdk memcached mongodb mysql neo4j nodejs_interpreter perl_interpreter perlbrew phantomjs postgresql python_interpreter rabbitmq redis riak ruby_interpreter sqlite xserver', u'_system_name': u'Ubuntu', u'PAGER': u'cat', u'PYTEST_PASSTHRU_ARGS': u'-v --duration=3', u'TRAVIS_SUDO': u'true', u'MIX_ARCHIVES': u'/home/travis/.kiex/mix/elixir-1.4.5', u'TRAVIS_BUILD_ID': u'403626566', u'PANTS_CONFIG_FILES': u'/home/travis/build/pantsbuild/pants/pants.travis-ci.ini', u'NVM_DIR': u'/home/travis/.nvm', u'TRAVIS_STACK_NAME': u'garnet', u'HOME': u'/home/travis', u'TRAVIS_PULL_REQUEST': u'6104', u'LANG': u'en_US.UTF-8', u'TRAVIS_COMMIT': u'a6f28670c5c10199bd4a2bd1f34d8181f721326e', u'TRAVIS_STACK_JOB_BOARD_REGISTER': u'/.job-board-register.yml', u'_system_arch': u'x86_64', u'MYSQL_UNIX_PORT': u'/var/run/mysqld/mysqld.sock', u'CI': u'true', u'rvm_prefix': u'/home/travis', u'DEBIAN_FRONTEND': u'noninteractive', u'TRAVIS_PRE_CHEF_BOOTSTRAP_TIME': u'2017-12-05T19:32:55', u'TRAVIS_COMMIT_MESSAGE': u'Merge fe2907e76d98458a78ee066377965df4ca16ee9e into 2e171f73d1cc32256cf93d5b04246fda2ccb58f3', u'IRBRC': u'/home/travis/.rvm/rubies/ruby-2.4.1/.irbrc', u'rvm_path': u'/home/travis/.rvm', u'CASHER_DIR': u'/home/travis/.casher', u'COLUMNS': u'50', u'TRAVIS_STACK_NODE_ATTRIBUTES': u'/.node-attributes.yml', u'SSH_TTY': u'/dev/pts/0', u'PERLBREW_HOME': u'/home/travis/.perlbrew', u'GEM_HOME': u'/home/travis/.rvm/gems/ruby-2.4.1', u'HAS_JOSH_K_SEAL_OF_APPROVAL': u'true', u'PYTHON_CFLAGS': u'-g -fstack-protector --param=ssp-buffer-size=4 -Wformat -Werror=format-security', u'COMPOSER_NO_INTERACTION': u'1', u'NVM_CD_FLAGS': u'', u'TRAVIS_BUILD_STAGE_NAME': u'Test pants', u'SSH_CLIENT': u'10.10.4.33 36036 22', u'PERLBREW_BASHRC_VERSION': u'0.80', u'LOGNAME': u'travis', u'TRAVIS_INIT': u'upstart', u'PATH': u'/home/travis/build/pantsbuild/pants/build-support/pants_dev_deps.venv/bin:/home/travis/.rvm/gems/ruby-2.4.1/bin:/home/travis/.rvm/gems/ruby-2.4.1@global/bin:/home/travis/.rvm/rubies/ruby-2.4.1/bin:/home/travis/.rvm/bin:/home/travis/virtualenv/python2.7.13/bin:/home/travis/bin:/home/travis/.local/bin:/opt/pyenv/shims:/home/travis/.phpenv/shims:/home/travis/perl5/perlbrew/bin:/home/travis/.nvm/versions/node/v8.9.1/bin:/home/travis/.kiex/elixirs/elixir-1.4.5/bin:/home/travis/.kiex/bin:/home/travis/gopath/bin:/home/travis/.gimme/versions/go1.7.4.linux.amd64/bin:/usr/local/phantomjs/bin:/usr/local/phantomjs:/usr/local/neo4j-3.2.7/bin:/usr/local/maven-3.5.2/bin:/usr/local/cmake-3.9.2/bin:/usr/local/clang-5.0.0/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/home/travis/.phpenv/bin:/opt/pyenv/bin:/home/travis/.yarn/bin', u'TRAVIS_ALLOW_FAILURE': u'false', u'elapsed_start_time': u'1531498647', u'TERM': u'xterm', u'TZ': u'UTC', u'HISTFILESIZE': u'2000', u'TRAVIS_OSX_IMAGE': u'', u'rvm_bin_path': u'/home/travis/.rvm/bin', u'RAILS_ENV': u'test', u'PERLBREW_ROOT': u'/home/travis/perl5/perlbrew', u'TRAVIS_JOB_NUMBER': u'18440.10', u'PYTHON_CONFIGURE_OPTS': u'--enable-unicode=ucs4 --with-wide-unicode --enable-shared --enable-ipv6 --enable-loadable-sqlite-extensions --with-computed-gotos', u'LC_ALL': u'en_US.UTF-8', u'TRAVIS_JOB_ID': u'403626576', u'PYTEST_CURRENT_TEST': u'../tests/python/pants_test/pantsd/test_pantsd_integration.py::TestPantsDaemonIntegration::test_pantsd_lifecycle_invalidation (call)', u'TRAVIS_PYTHON_VERSION': u'2.7.13', u'TRAVIS_LANGUAGE': u'python', u'TRAVIS_BUILD_DIR': u'/home/travis/build/pantsbuild/pants', u'HISTCONTROL': u'ignoredups:ignorespace', u'PWD': u'/home/travis/build/pantsbuild/pants', u'TRAVIS_OS_NAME': u'linux', u'ELIXIR_VERSION': u'1.4.5', u'rvm_pretty_print_flag': u'auto'}
                     D0713 17:01:19.862945 11396 pailgun_service.py:60] execution commandline: [u'./pants', u'--no-pantsrc', u'--pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d', u'--kill-nailguns', u'--print-exception-stacktrace=True', u'--pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini', u'help']
                     D0713 17:01:19.993228 11396 pailgun_service.py:67] warming the product graph via <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7fd246238450>
                     D0713 17:01:20.000976 11396 target_roots_calculator.py:145] spec_roots are: None
                     D0713 17:01:20.001117 11396 target_roots_calculator.py:146] changed_request is: ChangedRequest(changes_since=None, diffspec=None, include_dependees=none, fast=False)
                     D0713 17:01:20.001271 11396 target_roots_calculator.py:147] owned_files are: []
                     D0713 17:01:20.001456 11396 engine_initializer.py:155] warming target_roots for: TargetRoots(specs=None)
                     D0713 17:01:20.001965 11396 scheduler.py:496] computed 0 nodes in 0.000332 seconds. there are 0 total nodes.
                     D0713 17:01:20.002372 11396 process_manager.py:213] purging metadata directory: /home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids/pantsd-run-2018-07-13t17_01_20_002125
                     D0713 17:01:20.002584 11396 process_manager.py:460] forking <pants.bin.daemon_pants_runner.DaemonPantsRunner object at 0x7fd242721bd0>
                     I0713 17:01:20.008790 11396 pailgun_server.py:81] pailgun request completed: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini help`
                     I0713 17:01:22.379790 11551 pants_daemon.py:360] pantsd starting, log level is INFO
                     I0713 17:01:22.380280 11551 pants_daemon.py:309] setting up service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7fd473fbfb10>
                     I0713 17:01:22.380458 11551 pants_daemon.py:309] setting up service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7fd477a2e450>
                     I0713 17:01:22.380594 11551 scheduler_service.py:74] watching invalidating files: set([])
                     I0713 17:01:22.380728 11551 pants_daemon.py:309] setting up service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7fd473f4fed0>
                     I0713 17:01:22.380857 11551 pants_daemon.py:309] setting up service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7fd473f6bc50>
                     I0713 17:01:22.381115 11551 pants_daemon.py:328] starting service <pants.pantsd.service.fs_event_service.FSEventService object at 0x7fd473fbfb10>
                     I0713 17:01:22.381432 11551 pants_daemon.py:328] starting service <pants.pantsd.service.store_gc_service.StoreGCService object at 0x7fd473f6bc50>
                     I0713 17:01:22.382055 11551 pants_daemon.py:328] starting service <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7fd477a2e450>
                     I0713 17:01:22.382555 11551 pants_daemon.py:328] starting service <pants.pantsd.service.pailgun_service.PailgunService object at 0x7fd473f4fed0>
                     I0713 17:01:22.382962 11551 pailgun_service.py:102] starting pailgun server on port 45248
                     I0713 17:01:22.418956 11551 watchman.py:184] confirmed watchman subscription: {u'subscribe': 'all_files', u'version': u'4.9.1', u'clock': u'c:1531501269:11064:1:334'}
                     I0713 17:01:22.423099 11551 scheduler_service.py:82] enqueuing 10596 changes for subscription all_files
                     I0713 17:01:22.450211 11551 watchman.py:184] confirmed watchman subscription: {u'subscribe': 'pantsd_pid', u'version': u'4.9.1', u'clock': u'c:1531501269:11064:1:337'}
                     I0713 17:01:22.451726 11551 scheduler_service.py:82] enqueuing 1 changes for subscription pantsd_pid
                     I0713 17:01:22.452696 11551 pailgun_server.py:72] handling pailgun request: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini -linfo help`
                     I0713 17:01:22.611726 11551 pailgun_server.py:81] pailgun request completed: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini -linfo help`
                     I0713 17:01:23.761673 11551 pailgun_server.py:72] handling pailgun request: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini help`
                     I0713 17:01:23.907471 11551 pailgun_server.py:81] pailgun request completed: `./pants --no-pantsrc --pants-workdir=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d --kill-nailguns --print-exception-stacktrace=True --pants-config-files=/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.workdir.pants.d/pants.ini help`
                     ===============================================================
                     - END pantsd.log ----------------------------------------------
                     ===============================================================
                     
                     running: ./pants kill-pantsd (config={u'GLOBAL': {u'watchman_socket_path': u'/tmp/watchman.10384.sock', u'pants_subprocessdir': u'/home/travis/build/pantsbuild/pants/.pants.d/tmp/tmpsYhrVh.pants.d/.pids', u'level': u'info', u'enable_pantsd': True}}) (extra_env={})
                     
                     completed in 2.86789488792 seconds
                     PantsDaemonMonitor: pid is 11551 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 
                     ============ slowest 3 test durations ============
                     23.09s call     ../tests/python/pants_test/pantsd/test_pantsd_integration.py::TestPantsDaemonIntegration::test_pantsd_lifecycle_invalidation
                     21.48s call     ../tests/python/pants_test/pantsd/test_pantsd_integration.py::TestPantsDaemonIntegration::test_pantsd_run
                     12.54s call     ../tests/python/pants_test/pantsd/test_pantsd_integration.py::TestPantsDaemonIntegration::test_pantsd_client_env_var_is_inherited_by_pantsd_runner_children
                     ====== 1 failed, 2 passed in 57.27 seconds =======

Maybe a resurrection of #5056?

@jsirois jsirois added the pantsd label Jul 13, 2018
@jsirois
Copy link
Contributor Author

jsirois commented Jul 13, 2018

@kwlzn you already had a peek I think, but here in case you need reference to the details.

@Eric-Arellano
Copy link
Contributor

Likely related test that timed out:

tests/python/pants_test/pantsd/test_pantsd_integration.py::TestPantsDaemonIntegration::test_pantsd_client_env_var_is_inherited_by_pantsd_runner_children <- pyprep/sources/687f782195d1805e96992ecb028ae0cc6c8a31f1/pants_test/pantsd/test_pantsd_integration.py 
No output has been received in the last 10m0s, this potentially indicates a stalled build or something wrong with the build itself.
Check the details on how to adjust your build configuration on: https://docs.travis-ci.com/user/common-build-problems/#Build-times-out-because-no-output-was-received
The build has been terminated

@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 Jun 15, 2020
### Problem

Currently we restart pantsd for most configuration changes, and exclude a small set of bootstrap options (by marking them `daemon=False`) that should not trigger a restart. But in most cases, restarting is heavy-handed. We'd like to be able to keep more and more of our state alive over time as we continue to remove global mutable state (in order to allow us to tackle #7654, among other things).

Additionally, the pantsd client currently implements the fingerprinting that decides when the server should restart, which blocks moving the pantsd client to rust. We'd like the client to only need to interact with a small set of options to simplify its implementation.

### Solution

Move the nailgun server out of the `PantsService` model and directly into the `PantsDaemon` class. Share a `PantsDaemonCore` between the daemon and `DaemonPantsRunner` that encapsulates the current `Scheduler` and all live services. Finally, have the `PantsDaemonCore` implement fingerprinting to decide when to reinitialize/recreate the `Scheduler` (without restarting) and trim down the options that trigger a restart (`daemon=True`) to only those that are used to start the daemon itself (rather than to create the `Scheduler`).

### Result

`pantsd` will stay up through the vast majority of options changes (with the exception of a handful of "micro-bootstrap" options), and will instead reinitialize the `Scheduler` for bootstrap options changes with some useful output when it does so.

Example:
```
$ ./pants help
23:26:22 [INFO] initializing pantsd...
23:26:24 [INFO] pantsd initialized.
Pants 1.30.0.dev0 https://pypi.org/pypi/pantsbuild.pants/1.30.0.dev0

Usage:
<snip>

$ ./pants --no-v1 help
23:26:31 [INFO] initialization options changed: reinitializing pantsd...
23:26:32 [INFO] pantsd initialized.
Pants 1.30.0.dev0 https://pypi.org/pypi/pantsbuild.pants/1.30.0.dev0

Usage:
<snip>
```

This prepares to port the client to rust, and unblocks a fix for #8200, by having the `PantsDaemon` class tear down the nailgun server cleanly in the foreground if any services exit. Fixes #6114, fixes #7573, and fixes #10041.
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.

2 participants