See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4473/display/redirect?page=changes>
Changes: [bmahler] Added a Future constructor for Try<Future<T>>. ------------------------------------------ [...truncated 5.44 MB...] 3: I1120 01:04:23.486485 15994 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/PartitionTest_ReregisterSlavePartitionAware_e4U3Ew/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/PartitionTest_ReregisterSlavePartitionAware_e4U3Ew/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io"; --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/PartitionTest_ReregisterSlavePartitionAware_e4U3Ew/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/PartitionTest_ReregisterSlavePartitionAware_e4U3Ew/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/PartitionTest_ReregisterSlavePartitionAware_e4U3Ew/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/PartitionTest_ReregisterSlavePartitionAware_e4U3Ew" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/PartitionTest_ReregisterSlavePartitionAware_4RPYC0" --zk_session_timeout="10secs" 3: I1120 01:04:23.487121 15994 credentials.hpp:86] Loading credential for authentication from '/tmp/PartitionTest_ReregisterSlavePartitionAware_e4U3Ew/credential' 3: W1120 01:04:23.487191 15988 process.cpp:3185] Attempted to spawn already running process version@172.17.0.4:38372 3: I1120 01:04:23.487351 15994 slave.cpp:295] Agent using credential for: test-principal 3: I1120 01:04:23.487392 15994 credentials.hpp:37] Loading credentials for authentication from '/tmp/PartitionTest_ReregisterSlavePartitionAware_e4U3Ew/http_credentials' 3: I1120 01:04:23.487749 15994 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1120 01:04:23.487987 15994 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1120 01:04:23.488459 15988 sched.cpp:232] Version: 1.5.0 3: I1120 01:04:23.489190 16005 sched.cpp:336] New master detected at master@172.17.0.4:38372 3: I1120 01:04:23.489311 16005 sched.cpp:396] Authenticating with master master@172.17.0.4:38372 3: I1120 01:04:23.489331 16005 sched.cpp:403] Using default CRAM-MD5 authenticatee 3: I1120 01:04:23.489595 15993 authenticatee.cpp:121] Creating new client SASL connection 3: I1120 01:04:23.489980 16010 master.cpp:8285] Authenticating scheduler-e69f0f84-4514-49b6-8d1f-038de3090d9b@172.17.0.4:38372 3: I1120 01:04:23.490180 15990 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(229)@172.17.0.4:38372 3: I1120 01:04:23.490367 15991 hierarchical.cpp:1457] Performed allocation for 0 agents in 106765ns 3: I1120 01:04:23.490144 15994 slave.cpp:593] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] 3: I1120 01:04:23.490412 15994 slave.cpp:601] Agent attributes: [ ] 3: I1120 01:04:23.490425 15994 slave.cpp:610] Agent hostname: d0cd093edba7 3: I1120 01:04:23.490473 16007 authenticator.cpp:98] Creating new server SASL connection 3: I1120 01:04:23.490600 15991 status_update_manager.cpp:177] Pausing sending status updates 3: I1120 01:04:23.490778 16004 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1120 01:04:23.490818 16004 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1120 01:04:23.490952 16004 authenticator.cpp:204] Received SASL authentication start 3: I1120 01:04:23.491022 16004 authenticator.cpp:326] Authentication requires more steps 3: I1120 01:04:23.491159 16003 authenticatee.cpp:259] Received SASL authentication step 3: I1120 01:04:23.491340 15997 authenticator.cpp:232] Received SASL authentication step 3: I1120 01:04:23.491379 15997 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd0cd093edba7' server FQDN: 'd0cd093edba7' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1120 01:04:23.491399 15997 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1120 01:04:23.491443 15997 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1120 01:04:23.491472 15997 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd0cd093edba7' server FQDN: 'd0cd093edba7' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1120 01:04:23.491487 15997 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1120 01:04:23.491500 15997 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1120 01:04:23.491521 15997 authenticator.cpp:318] Authentication success 3: I1120 01:04:23.491636 16011 authenticatee.cpp:299] Authentication success 3: I1120 01:04:23.491719 15992 master.cpp:8315] Successfully authenticated principal 'test-principal' at scheduler-e69f0f84-4514-49b6-8d1f-038de3090d9b@172.17.0.4:38372 3: I1120 01:04:23.491896 16006 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(229)@172.17.0.4:38372 3: I1120 01:04:23.492121 16009 sched.cpp:502] Successfully authenticated with master master@172.17.0.4:38372 3: I1120 01:04:23.492149 16009 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.4:38372 3: I1120 01:04:23.492310 16009 sched.cpp:857] Will retry registration in 34.94461ms if necessary 3: I1120 01:04:23.492527 15995 master.cpp:2961] Received SUBSCRIBE call for framework 'default' at scheduler-e69f0f84-4514-49b6-8d1f-038de3090d9b@172.17.0.4:38372 3: I1120 01:04:23.492549 15995 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 3: I1120 01:04:23.492894 16005 state.cpp:64] Recovering state from '/tmp/PartitionTest_ReregisterSlavePartitionAware_4RPYC0/meta' 3: I1120 01:04:23.493233 15990 status_update_manager.cpp:203] Recovering status update manager 3: I1120 01:04:23.493225 16012 master.cpp:3041] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT, PARTITION_AWARE ] 3: I1120 01:04:23.493474 15991 containerizer.cpp:662] Recovering containerizer 3: I1120 01:04:23.493716 16007 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.4:38372 3: I1120 01:04:23.493865 16007 sched.cpp:857] Will retry registration in 2.147915999secs if necessary 3: I1120 01:04:23.494129 16007 sched.cpp:751] Framework registered with d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.494158 16012 master.cpp:2961] Received SUBSCRIBE call for framework 'default' at scheduler-e69f0f84-4514-49b6-8d1f-038de3090d9b@172.17.0.4:38372 3: I1120 01:04:23.494179 16007 sched.cpp:765] Scheduler::registered took 26867ns 3: I1120 01:04:23.494182 16012 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 3: I1120 01:04:23.494206 16000 hierarchical.cpp:306] Added framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.494441 16000 hierarchical.cpp:1457] Performed allocation for 0 agents in 100365ns 3: I1120 01:04:23.494732 16001 master.cpp:3041] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT, PARTITION_AWARE ] 3: I1120 01:04:23.494765 16001 master.cpp:3051] Framework d496844b-697e-4d51-8e21-607a63cdedce-0000 (default) at scheduler-e69f0f84-4514-49b6-8d1f-038de3090d9b@172.17.0.4:38372 already subscribed, resending acknowledgement 3: I1120 01:04:23.495038 15995 sched.cpp:738] Ignoring framework registered message because the driver is already connected! 3: I1120 01:04:23.495795 15993 provisioner.cpp:416] Provisioner recovery complete 3: I1120 01:04:23.496220 15990 slave.cpp:6441] Finished recovery 3: I1120 01:04:23.497314 15999 slave.cpp:1007] New master detected at master@172.17.0.4:38372 3: I1120 01:04:23.497330 16007 status_update_manager.cpp:177] Pausing sending status updates 3: I1120 01:04:23.497436 15999 slave.cpp:1042] Detecting new master 3: I1120 01:04:23.498755 15992 slave.cpp:1069] Authenticating with master master@172.17.0.4:38372 3: I1120 01:04:23.498821 15992 slave.cpp:1078] Using default CRAM-MD5 authenticatee 3: I1120 01:04:23.499193 16002 authenticatee.cpp:121] Creating new client SASL connection 3: I1120 01:04:23.499719 15998 master.cpp:8285] Authenticating slave(106)@172.17.0.4:38372 3: I1120 01:04:23.499889 16000 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(230)@172.17.0.4:38372 3: I1120 01:04:23.500252 16008 authenticator.cpp:98] Creating new server SASL connection 3: I1120 01:04:23.500537 16012 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1120 01:04:23.500569 16012 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1120 01:04:23.500771 16012 authenticator.cpp:204] Received SASL authentication start 3: I1120 01:04:23.500850 16012 authenticator.cpp:326] Authentication requires more steps 3: I1120 01:04:23.500984 16012 authenticatee.cpp:259] Received SASL authentication step 3: I1120 01:04:23.501148 16012 authenticator.cpp:232] Received SASL authentication step 3: I1120 01:04:23.501178 16012 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd0cd093edba7' server FQDN: 'd0cd093edba7' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1120 01:04:23.501188 16012 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1120 01:04:23.501222 16012 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1120 01:04:23.501245 16012 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd0cd093edba7' server FQDN: 'd0cd093edba7' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1120 01:04:23.501252 16012 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1120 01:04:23.501260 16012 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1120 01:04:23.501273 16012 authenticator.cpp:318] Authentication success 3: I1120 01:04:23.501376 16001 authenticatee.cpp:299] Authentication success 3: I1120 01:04:23.501448 16006 master.cpp:8315] Successfully authenticated principal 'test-principal' at slave(106)@172.17.0.4:38372 3: I1120 01:04:23.501504 15994 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(230)@172.17.0.4:38372 3: I1120 01:04:23.501710 16001 slave.cpp:1161] Successfully authenticated with master master@172.17.0.4:38372 3: I1120 01:04:23.501931 16001 slave.cpp:1682] Will retry registration in 13.41708ms if necessary 3: I1120 01:04:23.502177 15989 master.cpp:6032] Received register agent message from slave(106)@172.17.0.4:38372 (d0cd093edba7) 3: I1120 01:04:23.502225 15989 master.cpp:3870] Authorizing agent with principal 'test-principal' 3: I1120 01:04:23.502635 16004 master.cpp:6092] Authorized registration of agent at slave(106)@172.17.0.4:38372 (d0cd093edba7) 3: I1120 01:04:23.502755 16004 master.cpp:6185] Registering agent at slave(106)@172.17.0.4:38372 (d0cd093edba7) with id d496844b-697e-4d51-8e21-607a63cdedce-S0 3: I1120 01:04:23.503155 16003 registrar.cpp:495] Applied 1 operations in 80550ns; attempting to update the registry 3: I1120 01:04:23.503767 16003 registrar.cpp:552] Successfully updated the registry in 0ns 3: I1120 01:04:23.503976 16002 master.cpp:6232] Admitted agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) 3: I1120 01:04:23.504868 16000 slave.cpp:1207] Registered with master master@172.17.0.4:38372; given agent ID d496844b-697e-4d51-8e21-607a63cdedce-S0 3: I1120 01:04:23.504626 16002 master.cpp:6263] Registered agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] 3: I1120 01:04:23.504979 16002 status_update_manager.cpp:184] Resuming sending status updates 3: I1120 01:04:23.504998 16008 hierarchical.cpp:600] Added agent d496844b-697e-4d51-8e21-607a63cdedce-S0 (d0cd093edba7) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {}) 3: I1120 01:04:23.505198 16000 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/PartitionTest_ReregisterSlavePartitionAware_4RPYC0/meta/slaves/d496844b-697e-4d51-8e21-607a63cdedce-S0/slave.info' 3: I1120 01:04:23.505610 16000 slave.cpp:1295] Forwarding total oversubscribed resources {} 3: I1120 01:04:23.505844 15991 master.cpp:7064] Received update of agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) with total oversubscribed resources {} 3: I1120 01:04:23.506021 15991 master.cpp:7082] Ignoring update on agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) as it reports no changes 3: I1120 01:04:23.506491 16008 hierarchical.cpp:1457] Performed allocation for 1 agents in 1.358678ms 3: I1120 01:04:23.507027 16012 master.cpp:8115] Sending 1 offers to framework d496844b-697e-4d51-8e21-607a63cdedce-0000 (default) at scheduler-e69f0f84-4514-49b6-8d1f-038de3090d9b@172.17.0.4:38372 3: I1120 01:04:23.507596 16010 sched.cpp:921] Scheduler::resourceOffers took 106788ns 3: I1120 01:04:23.509553 16005 master.cpp:10024] Removing offer d496844b-697e-4d51-8e21-607a63cdedce-O0 3: I1120 01:04:23.509747 16005 master.cpp:4228] Processing ACCEPT call for offers: [ d496844b-697e-4d51-8e21-607a63cdedce-O0 ] on agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) for framework d496844b-697e-4d51-8e21-607a63cdedce-0000 (default) at scheduler-e69f0f84-4514-49b6-8d1f-038de3090d9b@172.17.0.4:38372 3: I1120 01:04:23.509830 16005 master.cpp:3597] Authorizing framework principal 'test-principal' to launch task ade26628-0fc6-4e8f-9004-e50fcd87daa2 3: I1120 01:04:23.512009 15994 master.cpp:10770] Adding task ade26628-0fc6-4e8f-9004-e50fcd87daa2 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] on agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) 3: I1120 01:04:23.512711 15994 master.cpp:4976] Launching task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 (default) at scheduler-e69f0f84-4514-49b6-8d1f-038de3090d9b@172.17.0.4:38372 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] on agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) 3: I1120 01:04:23.513689 15989 slave.cpp:1803] Got assigned task 'ade26628-0fc6-4e8f-9004-e50fcd87daa2' for framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.514356 15989 slave.cpp:2071] Authorizing task 'ade26628-0fc6-4e8f-9004-e50fcd87daa2' for framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.514427 15989 slave.cpp:7262] Authorizing framework principal 'test-principal' to launch task ade26628-0fc6-4e8f-9004-e50fcd87daa2 3: I1120 01:04:23.515317 16007 slave.cpp:2239] Launching task 'ade26628-0fc6-4e8f-9004-e50fcd87daa2' for framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.515921 16007 paths.cpp:621] Trying to chown '/tmp/PartitionTest_ReregisterSlavePartitionAware_4RPYC0/slaves/d496844b-697e-4d51-8e21-607a63cdedce-S0/frameworks/d496844b-697e-4d51-8e21-607a63cdedce-0000/executors/ade26628-0fc6-4e8f-9004-e50fcd87daa2/runs/1fc3757a-a888-4d92-9d81-b4049c8587b2' to user 'mesos' 3: I1120 01:04:23.516170 16007 slave.cpp:7736] Launching executor 'ade26628-0fc6-4e8f-9004-e50fcd87daa2' of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}] in work directory '/tmp/PartitionTest_ReregisterSlavePartitionAware_4RPYC0/slaves/d496844b-697e-4d51-8e21-607a63cdedce-S0/frameworks/d496844b-697e-4d51-8e21-607a63cdedce-0000/executors/ade26628-0fc6-4e8f-9004-e50fcd87daa2/runs/1fc3757a-a888-4d92-9d81-b4049c8587b2' 3: I1120 01:04:23.516875 16007 slave.cpp:2930] Launching container 1fc3757a-a888-4d92-9d81-b4049c8587b2 for executor 'ade26628-0fc6-4e8f-9004-e50fcd87daa2' of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.517143 16003 containerizer.cpp:1149] Starting container 1fc3757a-a888-4d92-9d81-b4049c8587b2 3: I1120 01:04:23.517223 16007 slave.cpp:2467] Queued task 'ade26628-0fc6-4e8f-9004-e50fcd87daa2' for executor 'ade26628-0fc6-4e8f-9004-e50fcd87daa2' of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.517321 16007 slave.cpp:958] Successfully attached '/tmp/PartitionTest_ReregisterSlavePartitionAware_4RPYC0/slaves/d496844b-697e-4d51-8e21-607a63cdedce-S0/frameworks/d496844b-697e-4d51-8e21-607a63cdedce-0000/executors/ade26628-0fc6-4e8f-9004-e50fcd87daa2/runs/1fc3757a-a888-4d92-9d81-b4049c8587b2' to virtual path '/tmp/PartitionTest_ReregisterSlavePartitionAware_4RPYC0/slaves/d496844b-697e-4d51-8e21-607a63cdedce-S0/frameworks/d496844b-697e-4d51-8e21-607a63cdedce-0000/executors/ade26628-0fc6-4e8f-9004-e50fcd87daa2/runs/latest' 3: I1120 01:04:23.517377 16007 slave.cpp:958] Successfully attached '/tmp/PartitionTest_ReregisterSlavePartitionAware_4RPYC0/slaves/d496844b-697e-4d51-8e21-607a63cdedce-S0/frameworks/d496844b-697e-4d51-8e21-607a63cdedce-0000/executors/ade26628-0fc6-4e8f-9004-e50fcd87daa2/runs/1fc3757a-a888-4d92-9d81-b4049c8587b2' to virtual path '/frameworks/d496844b-697e-4d51-8e21-607a63cdedce-0000/executors/ade26628-0fc6-4e8f-9004-e50fcd87daa2/runs/latest' 3: I1120 01:04:23.517421 16007 slave.cpp:958] Successfully attached '/tmp/PartitionTest_ReregisterSlavePartitionAware_4RPYC0/slaves/d496844b-697e-4d51-8e21-607a63cdedce-S0/frameworks/d496844b-697e-4d51-8e21-607a63cdedce-0000/executors/ade26628-0fc6-4e8f-9004-e50fcd87daa2/runs/1fc3757a-a888-4d92-9d81-b4049c8587b2' to virtual path '/tmp/PartitionTest_ReregisterSlavePartitionAware_4RPYC0/slaves/d496844b-697e-4d51-8e21-607a63cdedce-S0/frameworks/d496844b-697e-4d51-8e21-607a63cdedce-0000/executors/ade26628-0fc6-4e8f-9004-e50fcd87daa2/runs/1fc3757a-a888-4d92-9d81-b4049c8587b2' 3: I1120 01:04:23.517598 16003 containerizer.cpp:2818] Transitioning the state of container 1fc3757a-a888-4d92-9d81-b4049c8587b2 from PROVISIONING to PREPARING 3: I1120 01:04:23.521800 16010 containerizer.cpp:1768] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/mesos\/build\/src"],"shell":false,"value":"\/mesos\/build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.4:38372"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/PartitionTest_ReregisterSlavePartitionAware_4RPYC0\/slaves\/d496844b-697e-4d51-8e21-607a63cdedce-S0\/frameworks\/d496844b-697e-4d51-8e21-607a63cdedce-0000\/executors\/ade26628-0fc6-4e8f-9004-e50fcd87daa2\/runs\/1fc3757a-a888-4d92-9d81-b4049c8587b2"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"ade26628-0fc6-4e8f-9004-e50fcd87daa2"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"d496844b-697e-4d51-8e21-607a63cdedce-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"d496844b-697e-4d51-8e21-607a63cdedce-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(106)@172.17.0.4:38372"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/PartitionTest_ReregisterSlavePartitionAware_4RPYC0\/slaves\/d496844b-697e-4d51-8e21-607a63cdedce-S0\/frameworks\/d496844b-697e-4d51-8e21-607a63cdedce-0000\/executors\/ade26628-0fc6-4e8f-9004-e50fcd87daa2\/runs\/1fc3757a-a888-4d92-9d81-b4049c8587b2"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/PartitionTest_ReregisterSlavePartitionAware_4RPYC0\/slaves\/d496844b-697e-4d51-8e21-607a63cdedce-S0\/frameworks\/d496844b-697e-4d51-8e21-607a63cdedce-0000\/executors\/ade26628-0fc6-4e8f-9004-e50fcd87daa2\/runs\/1fc3757a-a888-4d92-9d81-b4049c8587b2"}" --pipe_read="7" --pipe_write="8" --runtime_directory="/tmp/PartitionTest_ReregisterSlavePartitionAware_e4U3Ew/containers/1fc3757a-a888-4d92-9d81-b4049c8587b2" --unshare_namespace_mnt="false"' 3: I1120 01:04:23.524359 16010 launcher.cpp:140] Forked child with pid '17893' for container '1fc3757a-a888-4d92-9d81-b4049c8587b2' 3: I1120 01:04:23.524966 16010 containerizer.cpp:2818] Transitioning the state of container 1fc3757a-a888-4d92-9d81-b4049c8587b2 from PREPARING to ISOLATING 3: I1120 01:04:23.526468 16009 containerizer.cpp:2818] Transitioning the state of container 1fc3757a-a888-4d92-9d81-b4049c8587b2 from ISOLATING to FETCHING 3: I1120 01:04:23.526664 16011 fetcher.cpp:379] Starting to fetch URIs for container: 1fc3757a-a888-4d92-9d81-b4049c8587b2, directory: /tmp/PartitionTest_ReregisterSlavePartitionAware_4RPYC0/slaves/d496844b-697e-4d51-8e21-607a63cdedce-S0/frameworks/d496844b-697e-4d51-8e21-607a63cdedce-0000/executors/ade26628-0fc6-4e8f-9004-e50fcd87daa2/runs/1fc3757a-a888-4d92-9d81-b4049c8587b2 3: I1120 01:04:23.527485 16002 containerizer.cpp:2818] Transitioning the state of container 1fc3757a-a888-4d92-9d81-b4049c8587b2 from FETCHING to RUNNING 3: I1120 01:04:23.783962 17894 exec.cpp:162] Version: 1.5.0 3: I1120 01:04:23.798209 16012 slave.cpp:4063] Got registration for executor 'ade26628-0fc6-4e8f-9004-e50fcd87daa2' of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 from executor(1)@172.17.0.4:36009 3: I1120 01:04:23.802170 16007 slave.cpp:2669] Sending queued task 'ade26628-0fc6-4e8f-9004-e50fcd87daa2' to executor 'ade26628-0fc6-4e8f-9004-e50fcd87daa2' of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 at executor(1)@172.17.0.4:36009 3: I1120 01:04:23.803575 17914 exec.cpp:237] Executor registered on agent d496844b-697e-4d51-8e21-607a63cdedce-S0 3: I1120 01:04:23.807934 17896 executor.cpp:171] Received SUBSCRIBED event 3: I1120 01:04:23.809551 17896 executor.cpp:175] Subscribed executor on d0cd093edba7 3: I1120 01:04:23.809893 17896 executor.cpp:171] Received LAUNCH event 3: I1120 01:04:23.812547 17896 executor.cpp:637] Starting task ade26628-0fc6-4e8f-9004-e50fcd87daa2 3: I1120 01:04:23.815300 15999 slave.cpp:4517] Handling status update TASK_STARTING (UUID: 807945aa-a804-4a10-aa04-b9468081465b) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 from executor(1)@172.17.0.4:36009 3: I1120 01:04:23.817618 16012 status_update_manager.cpp:323] Received status update TASK_STARTING (UUID: 807945aa-a804-4a10-aa04-b9468081465b) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.817673 16012 status_update_manager.cpp:500] Creating StatusUpdate stream for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.818574 16012 status_update_manager.cpp:377] Forwarding update TASK_STARTING (UUID: 807945aa-a804-4a10-aa04-b9468081465b) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 to the agent 3: I1120 01:04:23.819025 15996 slave.cpp:4998] Forwarding the update TASK_STARTING (UUID: 807945aa-a804-4a10-aa04-b9468081465b) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 to master@172.17.0.4:38372 3: I1120 01:04:23.819617 15996 slave.cpp:4892] Status update manager successfully handled status update TASK_STARTING (UUID: 807945aa-a804-4a10-aa04-b9468081465b) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.819696 15996 slave.cpp:4908] Sending acknowledgement for status update TASK_STARTING (UUID: 807945aa-a804-4a10-aa04-b9468081465b) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 to executor(1)@172.17.0.4:36009 3: I1120 01:04:23.819926 15995 master.cpp:7247] Status update TASK_STARTING (UUID: 807945aa-a804-4a10-aa04-b9468081465b) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 from agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) 3: I1120 01:04:23.820040 15995 master.cpp:7309] Forwarding status update TASK_STARTING (UUID: 807945aa-a804-4a10-aa04-b9468081465b) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.820367 15995 master.cpp:9502] Updating the state of task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING) 3: I1120 01:04:23.820843 16004 sched.cpp:1029] Scheduler::statusUpdate took 171994ns 3: I1120 01:04:23.821317 15993 master.cpp:5791] Processing ACKNOWLEDGE call 807945aa-a804-4a10-aa04-b9468081465b for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 (default) at scheduler-e69f0f84-4514-49b6-8d1f-038de3090d9b@172.17.0.4:38372 on agent d496844b-697e-4d51-8e21-607a63cdedce-S0 3: I1120 01:04:23.821774 15992 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 807945aa-a804-4a10-aa04-b9468081465b) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.822144 16005 slave.cpp:3801] Status update manager successfully handled status update acknowledgement (UUID: 807945aa-a804-4a10-aa04-b9468081465b) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.828914 17896 executor.cpp:477] Running '/mesos/build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>' 3: I1120 01:04:23.832309 17896 executor.cpp:650] Forked command at 17920 3: I1120 01:04:23.835908 15989 slave.cpp:4517] Handling status update TASK_RUNNING (UUID: ae29d973-9e78-44cd-9012-03911c2af1cb) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 from executor(1)@172.17.0.4:36009 3: I1120 01:04:23.838531 15991 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: ae29d973-9e78-44cd-9012-03911c2af1cb) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.838753 15991 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: ae29d973-9e78-44cd-9012-03911c2af1cb) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 to the agent 3: I1120 01:04:23.839020 16006 slave.cpp:4998] Forwarding the update TASK_RUNNING (UUID: ae29d973-9e78-44cd-9012-03911c2af1cb) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 to master@172.17.0.4:38372 3: I1120 01:04:23.839226 16006 slave.cpp:4892] Status update manager successfully handled status update TASK_RUNNING (UUID: ae29d973-9e78-44cd-9012-03911c2af1cb) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.839269 16006 slave.cpp:4908] Sending acknowledgement for status update TASK_RUNNING (UUID: ae29d973-9e78-44cd-9012-03911c2af1cb) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 to executor(1)@172.17.0.4:36009 3: I1120 01:04:23.839471 16008 master.cpp:7247] Status update TASK_RUNNING (UUID: ae29d973-9e78-44cd-9012-03911c2af1cb) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 from agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) 3: I1120 01:04:23.839579 16008 master.cpp:7309] Forwarding status update TASK_RUNNING (UUID: ae29d973-9e78-44cd-9012-03911c2af1cb) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.839854 16008 master.cpp:9502] Updating the state of task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING) 3: I1120 01:04:23.840180 16012 sched.cpp:1029] Scheduler::statusUpdate took 117638ns 3: I1120 01:04:23.840564 16012 master.cpp:5791] Processing ACKNOWLEDGE call ae29d973-9e78-44cd-9012-03911c2af1cb for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 (default) at scheduler-e69f0f84-4514-49b6-8d1f-038de3090d9b@172.17.0.4:38372 on agent d496844b-697e-4d51-8e21-607a63cdedce-S0 3: I1120 01:04:23.840982 16004 status_update_manager.cpp:395] Received status update acknowledgement (UUID: ae29d973-9e78-44cd-9012-03911c2af1cb) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.841485 15997 slave.cpp:3801] Status update manager successfully handled status update acknowledgement (UUID: ae29d973-9e78-44cd-9012-03911c2af1cb) for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 3: I1120 01:04:23.853103 15992 hierarchical.cpp:1457] Performed allocation for 1 agents in 284278ns 3: I1120 01:04:23.855417 16001 hierarchical.cpp:1457] Performed allocation for 1 agents in 260862ns 3: I1120 01:04:23.858234 16008 hierarchical.cpp:1457] Performed allocation for 1 agents in 325712ns 3: I1120 01:04:23.860306 16003 hierarchical.cpp:1457] Performed allocation for 1 agents in 242811ns 3: I1120 01:04:23.860592 16005 slave.cpp:6058] Current disk usage 64.57%. Max allowed age: 1.780375662920394days 3: I1120 01:04:23.862751 15992 hierarchical.cpp:1457] Performed allocation for 1 agents in 122814ns 3: I1120 01:04:23.862962 16001 master.cpp:7571] Marking agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) unreachable: health check timed out 3: I1120 01:04:23.863533 16000 registrar.cpp:495] Applied 1 operations in 143254ns; attempting to update the registry 3: I1120 01:04:23.864426 16000 registrar.cpp:552] Successfully updated the registry in 0ns 3: I1120 01:04:23.864825 16004 master.cpp:7619] Marked agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) unreachable: health check timed out 3: I1120 01:04:23.865216 16004 master.cpp:9502] Updating the state of task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 (latest state: TASK_UNREACHABLE, status update state: TASK_UNREACHABLE) 3: I1120 01:04:23.865639 15997 hierarchical.cpp:633] Removed agent d496844b-697e-4d51-8e21-607a63cdedce-S0 3: I1120 01:04:23.866423 16004 master.cpp:9596] Removing task ade26628-0fc6-4e8f-9004-e50fcd87daa2 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 on agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) 3: I1120 01:04:23.867442 16004 master.cpp:7304] Sending status update TASK_UNREACHABLE for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 'health check timed out' 3: I1120 01:04:23.867954 16008 sched.cpp:1029] Scheduler::statusUpdate took 78006ns 3: I1120 01:04:23.868002 16004 master.cpp:2130] Notifying framework d496844b-697e-4d51-8e21-607a63cdedce-0000 (default) at scheduler-e69f0f84-4514-49b6-8d1f-038de3090d9b@172.17.0.4:38372 of lost agent d496844b-697e-4d51-8e21-607a63cdedce-S0 (d0cd093edba7) 3: I1120 01:04:23.868309 16003 sched.cpp:1091] Lost agent d496844b-697e-4d51-8e21-607a63cdedce-S0 3: I1120 01:04:23.868376 16003 sched.cpp:1102] Scheduler::slaveLost took 32509ns 3: I1120 01:04:23.870725 16009 process.cpp:3932] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot' 3: I1120 01:04:23.871564 16002 http.cpp:851] Authorizing principal 'ANY' to GET the endpoint '/metrics/snapshot' 3: I1120 01:04:23.893038 16011 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/state' 3: I1120 01:04:23.894764 15993 http.cpp:1185] HTTP GET for /master/state from 172.17.0.4:56076 3: I1120 01:04:23.904803 16010 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/tasks' 3: I1120 01:04:23.906205 15996 http.cpp:1185] HTTP GET for /master/tasks from 172.17.0.4:56078 3: I1120 01:04:23.916470 15994 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/state-summary' 3: I1120 01:04:23.917738 16007 http.cpp:1185] HTTP GET for /master/state-summary from 172.17.0.4:56080 3: I1120 01:04:23.925426 16003 slave.cpp:1000] Lost leading master 3: I1120 01:04:23.925451 16003 slave.cpp:1042] Detecting new master 3: I1120 01:04:23.925467 15993 status_update_manager.cpp:177] Pausing sending status updates 3: I1120 01:04:23.925866 15998 status_update_manager.cpp:177] Pausing sending status updates 3: I1120 01:04:23.925902 15992 slave.cpp:1007] New master detected at master@172.17.0.4:38372 3: I1120 01:04:23.926012 15992 slave.cpp:1042] Detecting new master 3: I1120 01:04:23.927335 15994 slave.cpp:1069] Authenticating with master master@172.17.0.4:38372 3: I1120 01:04:23.927400 15994 slave.cpp:1078] Using default CRAM-MD5 authenticatee 3: I1120 01:04:23.927686 16009 authenticatee.cpp:121] Creating new client SASL connection 3: I1120 01:04:23.928046 16005 master.cpp:8285] Authenticating slave(106)@172.17.0.4:38372 3: I1120 01:04:23.928191 16002 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(231)@172.17.0.4:38372 3: I1120 01:04:23.928495 16008 authenticator.cpp:98] Creating new server SASL connection 3: I1120 01:04:23.928762 15999 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1120 01:04:23.928792 15999 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1120 01:04:23.928921 15999 authenticator.cpp:204] Received SASL authentication start 3: I1120 01:04:23.928987 15999 authenticator.cpp:326] Authentication requires more steps 3: I1120 01:04:23.929136 16010 authenticatee.cpp:259] Received SASL authentication step 3: I1120 01:04:23.929288 16007 authenticator.cpp:232] Received SASL authentication step 3: I1120 01:04:23.929322 16007 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd0cd093edba7' server FQDN: 'd0cd093edba7' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1120 01:04:23.929337 16007 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1120 01:04:23.929392 16007 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1120 01:04:23.929419 16007 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'd0cd093edba7' server FQDN: 'd0cd093edba7' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1120 01:04:23.929427 16007 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1120 01:04:23.929436 16007 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1120 01:04:23.929456 16007 authenticator.cpp:318] Authentication success 3: I1120 01:04:23.929661 16006 authenticatee.cpp:299] Authentication success 3: I1120 01:04:23.929721 15991 master.cpp:8315] Successfully authenticated principal 'test-principal' at slave(106)@172.17.0.4:38372 3: I1120 01:04:23.929790 16007 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(231)@172.17.0.4:38372 3: I1120 01:04:23.930038 16006 slave.cpp:1161] Successfully authenticated with master master@172.17.0.4:38372 3: I1120 01:04:23.930701 16006 slave.cpp:1682] Will retry registration in 2.426207ms if necessary 3: I1120 01:04:23.931382 15990 master.cpp:6350] Received re-register agent message from agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) 3: I1120 01:04:23.931428 15990 master.cpp:3870] Authorizing agent with principal 'test-principal' 3: I1120 01:04:23.932096 15990 master.cpp:6419] Authorized re-registration of agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) 3: I1120 01:04:23.932184 15990 master.cpp:6599] Re-registering agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) 3: I1120 01:04:23.932761 16003 registrar.cpp:495] Applied 1 operations in 200905ns; attempting to update the registry 3: I1120 01:04:23.933434 16003 registrar.cpp:552] Successfully updated the registry in 0ns 3: I1120 01:04:23.933851 15994 master.cpp:6668] Re-admitted agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) 3: I1120 01:04:23.934602 15994 master.cpp:10770] Adding task ade26628-0fc6-4e8f-9004-e50fcd87daa2 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] on agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) 3: I1120 01:04:23.935804 16001 slave.cpp:1340] Re-registered with master master@172.17.0.4:38372 3: I1120 01:04:23.935566 15994 master.cpp:6846] Re-registered agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] 3: I1120 01:04:23.935905 15999 status_update_manager.cpp:184] Resuming sending status updates 3: I1120 01:04:23.935945 16001 slave.cpp:1397] Forwarding total oversubscribed resources {} 3: I1120 01:04:23.936206 15994 master.cpp:7064] Received update of agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) with total oversubscribed resources {} 3: I1120 01:04:23.936213 16001 slave.cpp:3438] Updating info for framework d496844b-697e-4d51-8e21-607a63cdedce-0000 with pid updated to scheduler-e69f0f84-4514-49b6-8d1f-038de3090d9b@172.17.0.4:38372 3: I1120 01:04:23.936324 16010 status_update_manager.cpp:184] Resuming sending status updates 3: I1120 01:04:23.936309 16008 hierarchical.cpp:600] Added agent d496844b-697e-4d51-8e21-607a63cdedce-S0 (d0cd093edba7) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000]) 3: I1120 01:04:23.936405 15994 master.cpp:7082] Ignoring update on agent d496844b-697e-4d51-8e21-607a63cdedce-S0 at slave(106)@172.17.0.4:38372 (d0cd093edba7) as it reports no changes 3: I1120 01:04:23.936657 16008 hierarchical.cpp:1457] Performed allocation for 1 agents in 195915ns 3: I1120 01:04:23.937454 15995 master.cpp:7769] Performing explicit task state reconciliation for 1 tasks of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 (default) at scheduler-e69f0f84-4514-49b6-8d1f-038de3090d9b@172.17.0.4:38372 3: I1120 01:04:23.937646 15995 master.cpp:7917] Sending explicit reconciliation state TASK_RUNNING for task ade26628-0fc6-4e8f-9004-e50fcd87daa2 of framework d496844b-697e-4d51-8e21-607a63cdedce-0000 (default) at scheduler-e69f0f84-4514-49b6-8d1f-038de3090d9b@172.17.0.4:38372 3: I1120 01:04:23.938207 15991 sched.cpp:1029] Scheduler::statusUpdate took 123800ns 3: I1120 01:04:23.940891 15993 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/state' 3: I1120 01:04:23.941937 16009 http.cpp:1185] HTTP GET for /master/state from 172.17.0.4:56082 3: I1120 01:04:23.950738 16004 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/tasks' 3: I1120 01:04:23.951742 16005 http.cpp:1185] HTTP GET for /master/tasks from 172.17.0.4:56084 3: I1120 01:04:23.957264 16003 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/state-summary' 3: I1120 01:04:23.958204 16005 http.cpp:1185] HTTP GET for /master/state-summary from 172.17.0.4:56086 3: I1120 01:04:23.964193 16001 process.cpp:3932] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot' Build step 'Execute shell' marked build as failure
