You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2017/12/01 00:13:00 UTC
Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4521
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,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)/4521/display/redirect>
------------------------------------------
[...truncated 9.24 MB...]
3: I1201 00:12:46.572906 17400 slave.cpp:1298] Forwarding total oversubscribed resources {}
3: I1201 00:12:46.573397 17391 master.cpp:7036] Received update of agent a7e94bd0-9bc1-463c-a05c-ec5e01814b43-S0 at slave(244)@172.17.0.2:41214 (41703cc82666) with total resources cpus:2; mem:512; disk:512
3: I1201 00:12:46.573479 17391 master.cpp:7049] Received update of agent a7e94bd0-9bc1-463c-a05c-ec5e01814b43-S0 at slave(244)@172.17.0.2:41214 (41703cc82666) with total oversubscribed resources {}
3: I1201 00:12:46.574859 17404 hierarchical.cpp:620] Agent a7e94bd0-9bc1-463c-a05c-ec5e01814b43-S0 (41703cc82666) updated with total resources cpus:2; mem:512; disk:512
3: I1201 00:12:46.576598 17410 http_connection.hpp:221] New endpoint detected at http://172.17.0.2:41214/slave(244)/api/v1/resource_provider
3: I1201 00:12:46.580466 17403 http_connection.hpp:277] Connected with the remote endpoint at http://172.17.0.2:41214/slave(244)/api/v1/resource_provider
3: I1201 00:12:46.588892 17407 http_connection.hpp:129] Sending 1 call to http://172.17.0.2:41214/slave(244)/api/v1/resource_provider
3: I1201 00:12:46.590200 17393 process.cpp:3503] Handling HTTP event for process 'slave(244)' with path: '/slave(244)/api/v1/resource_provider'
3: I1201 00:12:46.592123 17391 http.cpp:1185] HTTP POST for /slave(244)/api/v1/resource_provider from 172.17.0.2:47298
3: I1201 00:12:46.592715 17404 manager.cpp:386] Subscribing resource provider {"name":"test","type":"org.apache.mesos.resource_provider.test"}
3: I1201 00:12:46.597216 17403 http_connection.hpp:129] Sending 3 call to http://172.17.0.2:41214/slave(244)/api/v1/resource_provider
3: I1201 00:12:46.598261 17398 process.cpp:3503] Handling HTTP event for process 'slave(244)' with path: '/slave(244)/api/v1/resource_provider'
3: I1201 00:12:46.599783 17393 http.cpp:1185] HTTP POST for /slave(244)/api/v1/resource_provider from 172.17.0.2:47296
3: I1201 00:12:46.600762 17408 slave.cpp:6800] Handling resource provider message 'UPDATE_STATE: 5af2cb60-7589-4d87-a977-8e315b0c6522 disk:8096'
3: I1201 00:12:46.601030 17408 slave.cpp:6939] Forwarding new total resources cpus:2; mem:512; disk:512; disk:8096
3: I1201 00:12:46.602061 17404 master.cpp:7036] Received update of agent a7e94bd0-9bc1-463c-a05c-ec5e01814b43-S0 at slave(244)@172.17.0.2:41214 (41703cc82666) with total resources cpus:2; mem:512; disk:512; disk:8096
3: I1201 00:12:46.604029 17395 hierarchical.cpp:644] Grew agent a7e94bd0-9bc1-463c-a05c-ec5e01814b43-S0 by disk:8096 (total), { } (used)
3: I1201 00:12:46.604298 17395 hierarchical.cpp:620] Agent a7e94bd0-9bc1-463c-a05c-ec5e01814b43-S0 (41703cc82666) updated with total resources disk:8096; cpus:2; mem:512; disk:512
3: I1201 00:12:46.605844 17386 slave.cpp:875] Agent terminating
3: I1201 00:12:46.606146 17406 master.cpp:1317] Agent a7e94bd0-9bc1-463c-a05c-ec5e01814b43-S0 at slave(244)@172.17.0.2:41214 (41703cc82666) disconnected
3: I1201 00:12:46.606184 17406 master.cpp:3376] Disconnecting agent a7e94bd0-9bc1-463c-a05c-ec5e01814b43-S0 at slave(244)@172.17.0.2:41214 (41703cc82666)
3: I1201 00:12:46.606257 17406 master.cpp:3395] Deactivating agent a7e94bd0-9bc1-463c-a05c-ec5e01814b43-S0 at slave(244)@172.17.0.2:41214 (41703cc82666)
3: I1201 00:12:46.606389 17399 hierarchical.cpp:671] Agent a7e94bd0-9bc1-463c-a05c-ec5e01814b43-S0 deactivated
3: I1201 00:12:46.616163 17386 master.cpp:1159] Master terminating
3: I1201 00:12:46.617024 17388 hierarchical.cpp:586] Removed agent a7e94bd0-9bc1-463c-a05c-ec5e01814b43-S0
3: [ OK ] SlaveTest.ResourceProviderSubscribe (104 ms)
3: [ RUN ] SlaveTest.ResourceVersions
3: I1201 00:12:46.626372 17386 cluster.cpp:170] Creating default 'local' authorizer
3: I1201 00:12:46.631909 17408 master.cpp:454] Master e83c202e-2386-479e-a54d-6f4ceecb57be (41703cc82666) started on 172.17.0.2:41214
3: I1201 00:12:46.631943 17408 master.cpp:456] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/3LK7H5/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/3LK7H5/master" --zk_session_timeout="10secs"
3: I1201 00:12:46.632436 17408 master.cpp:505] Master only allowing authenticated frameworks to register
3: I1201 00:12:46.632447 17408 master.cpp:511] Master only allowing authenticated agents to register
3: I1201 00:12:46.632453 17408 master.cpp:517] Master only allowing authenticated HTTP frameworks to register
3: I1201 00:12:46.632460 17408 credentials.hpp:37] Loading credentials for authentication from '/tmp/3LK7H5/credentials'
3: I1201 00:12:46.632872 17408 master.cpp:561] Using default 'crammd5' authenticator
3: I1201 00:12:46.633105 17408 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1201 00:12:46.633343 17408 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1201 00:12:46.633543 17408 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1201 00:12:46.633733 17408 master.cpp:640] Authorization enabled
3: I1201 00:12:46.633996 17392 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1201 00:12:46.634030 17389 whitelist_watcher.cpp:77] No whitelist given
3: I1201 00:12:46.638141 17407 master.cpp:2221] Elected as the leading master!
3: I1201 00:12:46.638187 17407 master.cpp:1701] Recovering from registrar
3: I1201 00:12:46.638442 17402 registrar.cpp:347] Recovering registrar
3: I1201 00:12:46.639298 17402 registrar.cpp:391] Successfully fetched the registry (0B) in 0ns
3: I1201 00:12:46.639443 17402 registrar.cpp:495] Applied 1 operations in 38076ns; attempting to update the registry
3: I1201 00:12:46.640298 17402 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1201 00:12:46.640489 17402 registrar.cpp:424] Successfully recovered registrar
3: I1201 00:12:46.641031 17391 master.cpp:1814] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1201 00:12:46.641094 17394 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: W1201 00:12:46.648457 17386 process.cpp:2756] Attempted to spawn already running process files@172.17.0.2:41214
3: I1201 00:12:46.649663 17386 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1201 00:12:46.650322 17386 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1201 00:12:46.650490 17386 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1201 00:12:46.650534 17386 provisioner.cpp:297] Using default backend 'copy'
3: I1201 00:12:46.653081 17386 cluster.cpp:458] Creating default 'local' authorizer
3: I1201 00:12:46.656462 17394 slave.cpp:253] Mesos agent started on (245)@172.17.0.2:41214
3: I1201 00:12:46.656489 17394 slave.cpp:254] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveTest_ResourceVersions_zm1FwA/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/SlaveTest_ResourceVersions_zm1FwA/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/SlaveTest_ResourceVersions_zm1FwA/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/SlaveTest_ResourceVersions_zm1FwA/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/SlaveTest_ResourceVersions_zm1FwA/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/SlaveTest_ResourceVersions_zm1FwA" --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/SlaveTest_ResourceVersions_tjao7k" --zk_session_timeout="10secs"
3: I1201 00:12:46.656946 17394 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveTest_ResourceVersions_zm1FwA/credential'
3: I1201 00:12:46.657137 17394 slave.cpp:286] Agent using credential for: test-principal
3: I1201 00:12:46.657160 17394 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveTest_ResourceVersions_zm1FwA/http_credentials'
3: I1201 00:12:46.657419 17394 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1201 00:12:46.657618 17394 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1201 00:12:46.659567 17394 slave.cpp:585] 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: I1201 00:12:46.659868 17394 slave.cpp:593] Agent attributes: [ ]
3: I1201 00:12:46.659881 17394 slave.cpp:602] Agent hostname: 41703cc82666
3: I1201 00:12:46.660051 17392 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1201 00:12:46.662168 17398 state.cpp:64] Recovering state from '/tmp/SlaveTest_ResourceVersions_tjao7k/meta'
3: I1201 00:12:46.662719 17409 task_status_update_manager.cpp:207] Recovering task status update manager
3: I1201 00:12:46.663025 17404 containerizer.cpp:668] Recovering containerizer
3: I1201 00:12:46.664937 17390 provisioner.cpp:493] Provisioner recovery complete
3: I1201 00:12:46.665334 17392 slave.cpp:6513] Finished recovery
3: I1201 00:12:46.666088 17403 slave.cpp:999] New master detected at master@172.17.0.2:41214
3: I1201 00:12:46.666097 17394 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1201 00:12:46.666157 17403 slave.cpp:1034] Detecting new master
3: I1201 00:12:46.667886 17387 slave.cpp:1061] Authenticating with master master@172.17.0.2:41214
3: I1201 00:12:46.667995 17387 slave.cpp:1070] Using default CRAM-MD5 authenticatee
3: I1201 00:12:46.668413 17406 authenticatee.cpp:121] Creating new client SASL connection
3: I1201 00:12:46.668896 17409 master.cpp:8593] Authenticating slave(245)@172.17.0.2:41214
3: I1201 00:12:46.669082 17399 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(472)@172.17.0.2:41214
3: I1201 00:12:46.669431 17400 authenticator.cpp:98] Creating new server SASL connection
3: I1201 00:12:46.669731 17396 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1201 00:12:46.669759 17396 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1201 00:12:46.669878 17396 authenticator.cpp:204] Received SASL authentication start
3: I1201 00:12:46.669940 17396 authenticator.cpp:326] Authentication requires more steps
3: I1201 00:12:46.670083 17388 authenticatee.cpp:259] Received SASL authentication step
3: I1201 00:12:46.670250 17393 authenticator.cpp:232] Received SASL authentication step
3: I1201 00:12:46.670284 17393 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '41703cc82666' server FQDN: '41703cc82666' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1201 00:12:46.670300 17393 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1201 00:12:46.670339 17393 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1201 00:12:46.670361 17393 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '41703cc82666' server FQDN: '41703cc82666' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1201 00:12:46.670368 17393 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1201 00:12:46.670374 17393 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1201 00:12:46.670387 17393 authenticator.cpp:318] Authentication success
3: I1201 00:12:46.670495 17395 authenticatee.cpp:299] Authentication success
3: I1201 00:12:46.670577 17404 master.cpp:8623] Successfully authenticated principal 'test-principal' at slave(245)@172.17.0.2:41214
3: I1201 00:12:46.670631 17391 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(472)@172.17.0.2:41214
3: I1201 00:12:46.670855 17410 slave.cpp:1153] Successfully authenticated with master master@172.17.0.2:41214
3: I1201 00:12:46.671097 17410 slave.cpp:1696] Will retry registration in 13.424135ms if necessary
3: I1201 00:12:46.671623 17397 master.cpp:6042] Received register agent message from slave(245)@172.17.0.2:41214 (41703cc82666)
3: I1201 00:12:46.671778 17397 master.cpp:3878] Authorizing agent with principal 'test-principal'
3: I1201 00:12:46.672296 17408 master.cpp:6104] Authorized registration of agent at slave(245)@172.17.0.2:41214 (41703cc82666)
3: I1201 00:12:46.672406 17408 master.cpp:6197] Registering agent at slave(245)@172.17.0.2:41214 (41703cc82666) with id e83c202e-2386-479e-a54d-6f4ceecb57be-S0
3: I1201 00:12:46.673014 17407 registrar.cpp:495] Applied 1 operations in 93798ns; attempting to update the registry
3: I1201 00:12:46.673889 17407 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1201 00:12:46.674221 17406 master.cpp:6246] Admitted agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0 at slave(245)@172.17.0.2:41214 (41703cc82666)
3: I1201 00:12:46.675377 17406 master.cpp:6282] Registered agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0 at slave(245)@172.17.0.2:41214 (41703cc82666) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
3: I1201 00:12:46.675511 17399 slave.cpp:1199] Registered with master master@172.17.0.2:41214; given agent ID e83c202e-2386-479e-a54d-6f4ceecb57be-S0
3: I1201 00:12:46.675679 17396 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1201 00:12:46.675873 17400 hierarchical.cpp:553] Added agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0 (41703cc82666) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1201 00:12:46.676012 17399 slave.cpp:1219] Checkpointing SlaveInfo to '/tmp/SlaveTest_ResourceVersions_tjao7k/meta/slaves/e83c202e-2386-479e-a54d-6f4ceecb57be-S0/slave.info'
3: I1201 00:12:46.676378 17400 hierarchical.cpp:1431] Performed allocation for 1 agents in 254059ns
3: I1201 00:12:46.676748 17399 slave.cpp:1298] Forwarding total oversubscribed resources {}
3: I1201 00:12:46.677048 17399 master.cpp:7049] Received update of agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0 at slave(245)@172.17.0.2:41214 (41703cc82666) with total oversubscribed resources {}
3: I1201 00:12:46.677343 17399 master.cpp:7092] Ignoring update on agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0 at slave(245)@172.17.0.2:41214 (41703cc82666) as it reports no changes
3: I1201 00:12:46.677944 17405 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1201 00:12:46.677943 17401 slave.cpp:999] New master detected at master@172.17.0.2:41214
3: I1201 00:12:46.678012 17401 slave.cpp:1034] Detecting new master
3: I1201 00:12:46.679561 17404 slave.cpp:1061] Authenticating with master master@172.17.0.2:41214
3: I1201 00:12:46.679638 17404 slave.cpp:1070] Using default CRAM-MD5 authenticatee
3: I1201 00:12:46.679939 17389 authenticatee.cpp:121] Creating new client SASL connection
3: I1201 00:12:46.680265 17391 master.cpp:8593] Authenticating slave(245)@172.17.0.2:41214
3: I1201 00:12:46.680373 17410 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(473)@172.17.0.2:41214
3: I1201 00:12:46.680599 17397 authenticator.cpp:98] Creating new server SASL connection
3: I1201 00:12:46.680809 17392 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1201 00:12:46.680829 17392 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1201 00:12:46.680945 17408 authenticator.cpp:204] Received SASL authentication start
3: I1201 00:12:46.681004 17408 authenticator.cpp:326] Authentication requires more steps
3: I1201 00:12:46.681123 17408 authenticatee.cpp:259] Received SASL authentication step
3: I1201 00:12:46.681249 17394 authenticator.cpp:232] Received SASL authentication step
3: I1201 00:12:46.681275 17394 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '41703cc82666' server FQDN: '41703cc82666' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1201 00:12:46.681285 17394 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1201 00:12:46.681308 17394 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1201 00:12:46.681325 17394 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '41703cc82666' server FQDN: '41703cc82666' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1201 00:12:46.681334 17394 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1201 00:12:46.681339 17394 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1201 00:12:46.681350 17394 authenticator.cpp:318] Authentication success
3: I1201 00:12:46.681520 17398 authenticatee.cpp:299] Authentication success
3: I1201 00:12:46.681550 17387 master.cpp:8623] Successfully authenticated principal 'test-principal' at slave(245)@172.17.0.2:41214
3: I1201 00:12:46.681581 17407 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(473)@172.17.0.2:41214
3: I1201 00:12:46.681967 17409 slave.cpp:1153] Successfully authenticated with master master@172.17.0.2:41214
3: I1201 00:12:46.682286 17409 slave.cpp:1696] Will retry registration in 5.0906ms if necessary
3: I1201 00:12:46.683037 17400 master.cpp:6371] Received re-register agent message from agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0 at slave(245)@172.17.0.2:41214 (41703cc82666)
3: I1201 00:12:46.683274 17400 master.cpp:3878] Authorizing agent with principal 'test-principal'
3: I1201 00:12:46.683774 17395 master.cpp:6442] Authorized re-registration of agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0 at slave(245)@172.17.0.2:41214 (41703cc82666)
3: I1201 00:12:46.683859 17395 master.cpp:6507] Re-registering agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0 at slave(245)@172.17.0.2:41214 (41703cc82666)
3: I1201 00:12:46.684110 17395 master.cpp:6614] Sending updated checkpointed resources {} to agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0 at slave(245)@172.17.0.2:41214 (41703cc82666)
3: I1201 00:12:46.684206 17393 slave.cpp:1343] Re-registered with master master@172.17.0.2:41214
3: I1201 00:12:46.684314 17405 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1201 00:12:46.684392 17393 slave.cpp:1411] Forwarding total oversubscribed resources {}
3: I1201 00:12:46.684547 17393 slave.cpp:3530] Ignoring new checkpointed resources identical to the current version: {}
3: I1201 00:12:46.684576 17390 master.cpp:7049] Received update of agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0 at slave(245)@172.17.0.2:41214 (41703cc82666) with total oversubscribed resources {}
3: I1201 00:12:46.684761 17390 master.cpp:7092] Ignoring update on agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0 at slave(245)@172.17.0.2:41214 (41703cc82666) as it reports no changes
3: I1201 00:12:46.685022 17389 slave.cpp:875] Agent terminating
3: I1201 00:12:46.685230 17397 master.cpp:1317] Agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0 at slave(245)@172.17.0.2:41214 (41703cc82666) disconnected
3: I1201 00:12:46.685250 17397 master.cpp:3376] Disconnecting agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0 at slave(245)@172.17.0.2:41214 (41703cc82666)
3: I1201 00:12:46.685303 17397 master.cpp:3395] Deactivating agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0 at slave(245)@172.17.0.2:41214 (41703cc82666)
3: I1201 00:12:46.685406 17408 hierarchical.cpp:671] Agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0 deactivated
3: I1201 00:12:46.694140 17386 master.cpp:1159] Master terminating
3: I1201 00:12:46.694995 17391 hierarchical.cpp:586] Removed agent e83c202e-2386-479e-a54d-6f4ceecb57be-S0
3: [ OK ] SlaveTest.ResourceVersions (75 ms)
3: [ RUN ] SlaveTest.ResourceProviderReconciliation
3: I1201 00:12:46.701867 17386 cluster.cpp:170] Creating default 'local' authorizer
3: I1201 00:12:46.705459 17391 master.cpp:454] Master 22ad261e-ee28-4f5a-a39f-480cc53768a1 (41703cc82666) started on 172.17.0.2:41214
3: I1201 00:12:46.705487 17391 master.cpp:456] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/o2GDZk/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/o2GDZk/master" --zk_session_timeout="10secs"
3: I1201 00:12:46.705865 17391 master.cpp:505] Master only allowing authenticated frameworks to register
3: I1201 00:12:46.705875 17391 master.cpp:511] Master only allowing authenticated agents to register
3: I1201 00:12:46.705881 17391 master.cpp:517] Master only allowing authenticated HTTP frameworks to register
3: I1201 00:12:46.705888 17391 credentials.hpp:37] Loading credentials for authentication from '/tmp/o2GDZk/credentials'
3: I1201 00:12:46.706239 17391 master.cpp:561] Using default 'crammd5' authenticator
3: I1201 00:12:46.706442 17391 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1201 00:12:46.706655 17391 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1201 00:12:46.706842 17391 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1201 00:12:46.707022 17391 master.cpp:640] Authorization enabled
3: I1201 00:12:46.707193 17395 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1201 00:12:46.707271 17394 whitelist_watcher.cpp:77] No whitelist given
3: I1201 00:12:46.711040 17390 master.cpp:2221] Elected as the leading master!
3: I1201 00:12:46.711074 17390 master.cpp:1701] Recovering from registrar
3: I1201 00:12:46.711206 17410 registrar.cpp:347] Recovering registrar
3: I1201 00:12:46.711855 17410 registrar.cpp:391] Successfully fetched the registry (0B) in 0ns
3: I1201 00:12:46.711974 17410 registrar.cpp:495] Applied 1 operations in 33075ns; attempting to update the registry
3: I1201 00:12:46.712579 17410 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1201 00:12:46.712702 17410 registrar.cpp:424] Successfully recovered registrar
3: I1201 00:12:46.713129 17409 master.cpp:1814] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1201 00:12:46.713191 17396 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: W1201 00:12:46.718289 17386 process.cpp:2756] Attempted to spawn already running process files@172.17.0.2:41214
3: I1201 00:12:46.719230 17386 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1201 00:12:46.719753 17386 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1201 00:12:46.719884 17386 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1201 00:12:46.719924 17386 provisioner.cpp:297] Using default backend 'copy'
3: I1201 00:12:46.722004 17386 cluster.cpp:458] Creating default 'local' authorizer
3: I1201 00:12:46.724503 17396 slave.cpp:253] Mesos agent started on (246)@172.17.0.2:41214
3: I1201 00:12:46.724527 17396 slave.cpp:254] Flags at startup: --acls="" --agent_features="capabilities {
3: type: MULTI_ROLE
3: }
3: capabilities {
3: type: HIERARCHICAL_ROLE
3: }
3: capabilities {
3: type: RESERVATION_REFINEMENT
3: }
3: capabilities {
3: type: RESOURCE_PROVIDER
3: }
3: " --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/SlaveTest_ResourceProviderReconciliation_E3Ee8P/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --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/SlaveTest_ResourceProviderReconciliation_E3Ee8P/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/SlaveTest_ResourceProviderReconciliation_E3Ee8P/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/SlaveTest_ResourceProviderReconciliation_E3Ee8P/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/SlaveTest_ResourceProviderReconciliation_E3Ee8P/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/SlaveTest_ResourceProviderReconciliation_E3Ee8P" --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/SlaveTest_ResourceProviderReconciliation_1wKVyA" --zk_session_timeout="10secs"
3: I1201 00:12:46.725123 17396 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveTest_ResourceProviderReconciliation_E3Ee8P/credential'
3: I1201 00:12:46.725311 17396 slave.cpp:286] Agent using credential for: test-principal
3: I1201 00:12:46.725333 17396 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveTest_ResourceProviderReconciliation_E3Ee8P/http_credentials'
3: I1201 00:12:46.725594 17396 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1201 00:12:46.727537 17396 slave.cpp:585] 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: I1201 00:12:46.727826 17396 slave.cpp:593] Agent attributes: [ ]
3: I1201 00:12:46.727843 17396 slave.cpp:602] Agent hostname: 41703cc82666
3: I1201 00:12:46.727984 17394 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1201 00:12:46.729948 17393 state.cpp:64] Recovering state from '/tmp/SlaveTest_ResourceProviderReconciliation_1wKVyA/meta'
3: I1201 00:12:46.730303 17393 task_status_update_manager.cpp:207] Recovering task status update manager
3: I1201 00:12:46.730576 17389 containerizer.cpp:668] Recovering containerizer
3: I1201 00:12:46.732403 17399 provisioner.cpp:493] Provisioner recovery complete
3: I1201 00:12:46.732769 17394 slave.cpp:6513] Finished recovery
3: I1201 00:12:46.733433 17396 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1201 00:12:46.733448 17401 slave.cpp:999] New master detected at master@172.17.0.2:41214
3: I1201 00:12:46.733505 17401 slave.cpp:1034] Detecting new master
3: I1201 00:12:46.735296 17405 slave.cpp:1061] Authenticating with master master@172.17.0.2:41214
3: I1201 00:12:46.735409 17405 slave.cpp:1070] Using default CRAM-MD5 authenticatee
3: I1201 00:12:46.735790 17393 authenticatee.cpp:121] Creating new client SASL connection
3: I1201 00:12:46.736280 17392 master.cpp:8593] Authenticating slave(246)@172.17.0.2:41214
3: I1201 00:12:46.736500 17408 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(474)@172.17.0.2:41214
3: I1201 00:12:46.736930 17398 authenticator.cpp:98] Creating new server SASL connection
3: I1201 00:12:46.737329 17397 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1201 00:12:46.737370 17397 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1201 00:12:46.737583 17402 authenticator.cpp:204] Received SASL authentication start
3: I1201 00:12:46.737699 17402 authenticator.cpp:326] Authentication requires more steps
3: I1201 00:12:46.737900 17402 authenticatee.cpp:259] Received SASL authentication step
3: I1201 00:12:46.738118 17409 authenticator.cpp:232] Received SASL authentication step
3: I1201 00:12:46.738170 17409 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '41703cc82666' server FQDN: '41703cc82666' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1201 00:12:46.738186 17409 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1201 00:12:46.738234 17409 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1201 00:12:46.738257 17409 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '41703cc82666' server FQDN: '41703cc82666' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1201 00:12:46.738273 17409 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1201 00:12:46.738282 17409 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1201 00:12:46.738306 17409 authenticator.cpp:318] Authentication success
3: I1201 00:12:46.738493 17389 authenticatee.cpp:299] Authentication success
3: I1201 00:12:46.738564 17407 master.cpp:8623] Successfully authenticated principal 'test-principal' at slave(246)@172.17.0.2:41214
3: I1201 00:12:46.738621 17410 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(474)@172.17.0.2:41214
3: I1201 00:12:46.739056 17389 slave.cpp:1153] Successfully authenticated with master master@172.17.0.2:41214
3: I1201 00:12:46.739359 17389 slave.cpp:1696] Will retry registration in 2.552955ms if necessary
write /dev/stdout: resource temporarily unavailable
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user yujie.jay@gmail.com
Not sending mail to unregistered user songzihao1990@gmail.com
Jenkins build is back to normal : Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4524
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,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)/4524/display/redirect?page=changes>
Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4523
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,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)/4523/display/redirect>
------------------------------------------
[...truncated 3.46 MB...]
3: I1201 02:45:44.576741 17333 master.cpp:8589] Authenticating slave(58)@172.17.0.4:43742
3: I1201 02:45:44.576880 17329 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(129)@172.17.0.4:43742
3: I1201 02:45:44.577122 17332 authenticator.cpp:98] Creating new server SASL connection
3: I1201 02:45:44.577337 17338 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1201 02:45:44.577360 17338 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1201 02:45:44.577512 17332 authenticator.cpp:204] Received SASL authentication start
3: I1201 02:45:44.577558 17332 authenticator.cpp:326] Authentication requires more steps
3: I1201 02:45:44.577651 17331 authenticatee.cpp:259] Received SASL authentication step
3: I1201 02:45:44.577759 17334 authenticator.cpp:232] Received SASL authentication step
3: I1201 02:45:44.577785 17334 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '5dc74a8b2fd6' server FQDN: '5dc74a8b2fd6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1201 02:45:44.577797 17334 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1201 02:45:44.577827 17334 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1201 02:45:44.577848 17334 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '5dc74a8b2fd6' server FQDN: '5dc74a8b2fd6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1201 02:45:44.577859 17334 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1201 02:45:44.577867 17334 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1201 02:45:44.577879 17334 authenticator.cpp:318] Authentication success
3: I1201 02:45:44.578050 17323 authenticatee.cpp:299] Authentication success
3: I1201 02:45:44.578069 17327 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(129)@172.17.0.4:43742
3: I1201 02:45:44.578110 17334 master.cpp:8619] Successfully authenticated principal 'test-principal' at slave(58)@172.17.0.4:43742
3: I1201 02:45:44.578508 17330 slave.cpp:1153] Successfully authenticated with master master@172.17.0.4:43742
3: I1201 02:45:44.578809 17330 slave.cpp:1696] Will retry registration in 9.870972ms if necessary
3: I1201 02:45:44.579300 17325 master.cpp:6042] Received register agent message from slave(58)@172.17.0.4:43742 (5dc74a8b2fd6)
3: I1201 02:45:44.579444 17325 master.cpp:3878] Authorizing agent with principal 'test-principal'
3: I1201 02:45:44.579919 17335 master.cpp:6104] Authorized registration of agent at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6)
3: I1201 02:45:44.580103 17335 master.cpp:6197] Registering agent at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6) with id 395db372-c241-4fe4-b74c-e70984dfe8a3-S0
3: I1201 02:45:44.580665 17329 registrar.cpp:495] Applied 1 operations in 78326ns; attempting to update the registry
3: I1201 02:45:44.581332 17329 registrar.cpp:552] Successfully updated the registry in 605952ns
3: I1201 02:45:44.581599 17329 master.cpp:6246] Admitted agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6)
3: I1201 02:45:44.582314 17329 master.cpp:6282] Registered agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
3: I1201 02:45:44.582362 17323 slave.cpp:1199] Registered with master master@172.17.0.4:43742; given agent ID 395db372-c241-4fe4-b74c-e70984dfe8a3-S0
3: I1201 02:45:44.582468 17327 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1201 02:45:44.582674 17337 hierarchical.cpp:553] Added agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 (5dc74a8b2fd6) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1201 02:45:44.582743 17323 slave.cpp:1219] Checkpointing SlaveInfo to '/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_DYbHnh/meta/slaves/395db372-c241-4fe4-b74c-e70984dfe8a3-S0/slave.info'
3: I1201 02:45:44.583225 17323 slave.cpp:1298] Forwarding total oversubscribed resources {}
3: I1201 02:45:44.583411 17330 master.cpp:7049] Received update of agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6) with total oversubscribed resources {}
3: I1201 02:45:44.583647 17330 master.cpp:7092] Ignoring update on agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6) as it reports no changes
3: I1201 02:45:44.584095 17337 hierarchical.cpp:1431] Performed allocation for 1 agents in 1.262029ms
3: I1201 02:45:44.584681 17336 master.cpp:8419] Sending 1 offers to framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 (default) at scheduler-50372b46-3a04-4dc9-9ee5-0b262e3a08e4@172.17.0.4:43742
3: I1201 02:45:44.586227 17336 sched.cpp:921] Scheduler::resourceOffers took 1.028674ms
3: I1201 02:45:44.587608 17336 master.cpp:10370] Removing offer 395db372-c241-4fe4-b74c-e70984dfe8a3-O0
3: I1201 02:45:44.587752 17336 master.cpp:4236] Processing ACCEPT call for offers: [ 395db372-c241-4fe4-b74c-e70984dfe8a3-O0 ] on agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6) for framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 (default) at scheduler-50372b46-3a04-4dc9-9ee5-0b262e3a08e4@172.17.0.4:43742
3: I1201 02:45:44.587854 17336 master.cpp:3605] Authorizing framework principal 'test-principal' to launch task 0
3: W1201 02:45:44.589829 17332 validation.cpp:1391] Executor 'default' for task '0' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
3: W1201 02:45:44.589941 17332 validation.cpp:1403] Executor 'default' for task '0' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
3: I1201 02:45:44.590425 17332 master.cpp:11130] Adding task 0 with resources cpus(allocated: *):1; mem(allocated: *):512 on agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6)
3: I1201 02:45:44.590749 17332 master.cpp:4984] Launching task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 (default) at scheduler-50372b46-3a04-4dc9-9ee5-0b262e3a08e4@172.17.0.4:43742 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] on agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6)
3: I1201 02:45:44.591437 17331 slave.cpp:1817] Got assigned task '0' for framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.592123 17331 slave.cpp:2085] Authorizing task '0' for framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.592180 17331 slave.cpp:7436] Authorizing framework principal 'test-principal' to launch task 0
3: I1201 02:45:44.593178 17325 slave.cpp:2253] Launching task '0' for framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.593863 17325 paths.cpp:692] Trying to chown '/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_DYbHnh/slaves/395db372-c241-4fe4-b74c-e70984dfe8a3-S0/frameworks/395db372-c241-4fe4-b74c-e70984dfe8a3-0000/executors/default/runs/d989f9d7-97fb-4ce7-a53c-0552d59da4d3' to user 'mesos'
3: I1201 02:45:44.594097 17323 hierarchical.cpp:1106] Recovered cpus(allocated: *):1; mem(allocated: *):512; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: cpus(allocated: *):1; mem(allocated: *):512) on agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 from framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.594158 17325 slave.cpp:7910] Launching executor 'default' of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 with resources [] in work directory '/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_DYbHnh/slaves/395db372-c241-4fe4-b74c-e70984dfe8a3-S0/frameworks/395db372-c241-4fe4-b74c-e70984dfe8a3-0000/executors/default/runs/d989f9d7-97fb-4ce7-a53c-0552d59da4d3'
3: I1201 02:45:44.594174 17323 hierarchical.cpp:1152] Framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 filtered agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 for 5secs
3: I1201 02:45:44.594691 17325 slave.cpp:2944] Launching container d989f9d7-97fb-4ce7-a53c-0552d59da4d3 for executor 'default' of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.595034 17325 slave.cpp:2481] Queued task '0' for executor 'default' of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.595126 17325 slave.cpp:950] Successfully attached '/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_DYbHnh/slaves/395db372-c241-4fe4-b74c-e70984dfe8a3-S0/frameworks/395db372-c241-4fe4-b74c-e70984dfe8a3-0000/executors/default/runs/d989f9d7-97fb-4ce7-a53c-0552d59da4d3' to virtual path '/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_DYbHnh/slaves/395db372-c241-4fe4-b74c-e70984dfe8a3-S0/frameworks/395db372-c241-4fe4-b74c-e70984dfe8a3-0000/executors/default/runs/latest'
3: I1201 02:45:44.595171 17325 slave.cpp:950] Successfully attached '/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_DYbHnh/slaves/395db372-c241-4fe4-b74c-e70984dfe8a3-S0/frameworks/395db372-c241-4fe4-b74c-e70984dfe8a3-0000/executors/default/runs/d989f9d7-97fb-4ce7-a53c-0552d59da4d3' to virtual path '/frameworks/395db372-c241-4fe4-b74c-e70984dfe8a3-0000/executors/default/runs/latest'
3: I1201 02:45:44.595232 17325 slave.cpp:950] Successfully attached '/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_DYbHnh/slaves/395db372-c241-4fe4-b74c-e70984dfe8a3-S0/frameworks/395db372-c241-4fe4-b74c-e70984dfe8a3-0000/executors/default/runs/d989f9d7-97fb-4ce7-a53c-0552d59da4d3' to virtual path '/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_DYbHnh/slaves/395db372-c241-4fe4-b74c-e70984dfe8a3-S0/frameworks/395db372-c241-4fe4-b74c-e70984dfe8a3-0000/executors/default/runs/d989f9d7-97fb-4ce7-a53c-0552d59da4d3'
3: W1201 02:45:44.597539 17337 process.cpp:2756] Attempted to spawn already running process version@172.17.0.4:43742
3: I1201 02:45:44.597718 17337 exec.cpp:162] Version: 1.5.0
3: I1201 02:45:44.598001 17328 exec.cpp:212] Executor started at: executor(10)@172.17.0.4:43742 with pid 17322
3: I1201 02:45:44.598206 17333 slave.cpp:4133] Got registration for executor 'default' of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 from executor(10)@172.17.0.4:43742
3: I1201 02:45:44.598695 17336 exec.cpp:237] Executor registered on agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0
3: I1201 02:45:44.598770 17336 exec.cpp:249] Executor::registered took 50216ns
3: I1201 02:45:44.599100 17333 slave.cpp:2683] Sending queued task '0' to executor 'default' of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 at executor(10)@172.17.0.4:43742
3: I1201 02:45:44.599445 17338 exec.cpp:331] Executor asked to run task '0'
3: I1201 02:45:44.599550 17338 exec.cpp:340] Executor::launchTask took 81620ns
3: I1201 02:45:44.599664 17338 exec.cpp:571] Executor sending status update TASK_FINISHED (UUID: 7d5e5399-d73c-40cb-bdef-51c913bc9d80) for task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.599993 17331 slave.cpp:4587] Handling status update TASK_FINISHED (UUID: 7d5e5399-d73c-40cb-bdef-51c913bc9d80) for task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 from executor(10)@172.17.0.4:43742
3: I1201 02:45:44.601047 17334 task_status_update_manager.cpp:328] Received task status update TASK_FINISHED (UUID: 7d5e5399-d73c-40cb-bdef-51c913bc9d80) for task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.601109 17334 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.601627 17334 task_status_update_manager.cpp:383] Forwarding task status update TASK_FINISHED (UUID: 7d5e5399-d73c-40cb-bdef-51c913bc9d80) for task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 to the agent
3: I1201 02:45:44.601954 17334 slave.cpp:5070] Forwarding the update TASK_FINISHED (UUID: 7d5e5399-d73c-40cb-bdef-51c913bc9d80) for task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 to master@172.17.0.4:43742
3: I1201 02:45:44.602130 17334 slave.cpp:4963] Task status update manager successfully handled status update TASK_FINISHED (UUID: 7d5e5399-d73c-40cb-bdef-51c913bc9d80) for task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.602177 17334 slave.cpp:4979] Sending acknowledgement for status update TASK_FINISHED (UUID: 7d5e5399-d73c-40cb-bdef-51c913bc9d80) for task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 to executor(10)@172.17.0.4:43742
3: I1201 02:45:44.602365 17334 exec.cpp:388] Executor received status update acknowledgement 7d5e5399-d73c-40cb-bdef-51c913bc9d80 for task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.602494 17325 master.cpp:7557] Status update TASK_FINISHED (UUID: 7d5e5399-d73c-40cb-bdef-51c913bc9d80) for task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 from agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6)
3: I1201 02:45:44.602565 17325 master.cpp:7613] Forwarding status update TASK_FINISHED (UUID: 7d5e5399-d73c-40cb-bdef-51c913bc9d80) for task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.602774 17325 master.cpp:9807] Updating the state of task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 (latest state: TASK_FINISHED, status update state: TASK_FINISHED)
3: I1201 02:45:44.603061 17326 sched.cpp:1029] Scheduler::statusUpdate took 88193ns
3: I1201 02:45:44.603459 17335 master.cpp:5799] Processing ACKNOWLEDGE call 7d5e5399-d73c-40cb-bdef-51c913bc9d80 for task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 (default) at scheduler-50372b46-3a04-4dc9-9ee5-0b262e3a08e4@172.17.0.4:43742 on agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0
3: I1201 02:45:44.603551 17335 master.cpp:9913] Removing task 0 with resources cpus(allocated: *):1; mem(allocated: *):512 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 on agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6)
3: I1201 02:45:44.603549 17328 hierarchical.cpp:1106] Recovered cpus(allocated: *):1; mem(allocated: *):512 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 from framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.603978 17327 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 7d5e5399-d73c-40cb-bdef-51c913bc9d80) for task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.604089 17327 task_status_update_manager.cpp:538] Cleaning up status update stream for task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.604457 17327 slave.cpp:3871] Task status update manager successfully handled status update acknowledgement (UUID: 7d5e5399-d73c-40cb-bdef-51c913bc9d80) for task 0 of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.604496 17327 slave.cpp:8515] Completing task 0
3: I1201 02:45:44.604910 17322 master.cpp:1159] Master terminating
3: I1201 02:45:44.605058 17322 master.cpp:9942] Removing executor 'default' with resources [] of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 on agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6)
3: I1201 02:45:44.605971 17337 hierarchical.cpp:586] Removed agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0
3: I1201 02:45:44.606082 17327 slave.cpp:5202] Got exited event for master@172.17.0.4:43742
3: W1201 02:45:44.606106 17327 slave.cpp:5207] Master disconnected! Waiting for a new master to be elected
3: I1201 02:45:44.606290 17337 hierarchical.cpp:345] Removed framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.616603 17322 cluster.cpp:170] Creating default 'local' authorizer
3: I1201 02:45:44.619850 17325 master.cpp:454] Master 34022412-d792-42a8-af9c-413e6b89011d (5dc74a8b2fd6) started on 172.17.0.4:43742
3: I1201 02:45:44.619910 17325 master.cpp:456] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/FeXBS7/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/FeXBS7/master" --zk_session_timeout="10secs"
3: I1201 02:45:44.620373 17325 master.cpp:505] Master only allowing authenticated frameworks to register
3: I1201 02:45:44.620411 17325 master.cpp:511] Master only allowing authenticated agents to register
3: I1201 02:45:44.620445 17325 master.cpp:517] Master only allowing authenticated HTTP frameworks to register
3: I1201 02:45:44.620477 17325 credentials.hpp:37] Loading credentials for authentication from '/tmp/FeXBS7/credentials'
3: I1201 02:45:44.620888 17325 master.cpp:561] Using default 'crammd5' authenticator
3: I1201 02:45:44.621155 17325 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1201 02:45:44.621368 17325 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1201 02:45:44.621526 17325 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1201 02:45:44.621680 17325 master.cpp:640] Authorization enabled
3: I1201 02:45:44.621969 17335 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1201 02:45:44.621984 17331 whitelist_watcher.cpp:77] No whitelist given
3: I1201 02:45:44.625002 17327 master.cpp:2221] Elected as the leading master!
3: I1201 02:45:44.625028 17327 master.cpp:1701] Recovering from registrar
3: I1201 02:45:44.625322 17324 registrar.cpp:347] Recovering registrar
3: I1201 02:45:44.625980 17324 registrar.cpp:391] Successfully fetched the registry (0B) in 568064ns
3: I1201 02:45:44.626129 17324 registrar.cpp:495] Applied 1 operations in 33618ns; attempting to update the registry
3: I1201 02:45:44.626734 17324 registrar.cpp:552] Successfully updated the registry in 518912ns
3: I1201 02:45:44.626883 17324 registrar.cpp:424] Successfully recovered registrar
3: I1201 02:45:44.627334 17337 master.cpp:1814] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1201 02:45:44.627398 17330 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: I1201 02:45:44.628278 17338 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1201 02:45:44.628288 17331 slave.cpp:999] New master detected at master@172.17.0.4:43742
3: I1201 02:45:44.628340 17331 slave.cpp:1034] Detecting new master
3: I1201 02:45:44.634207 17324 slave.cpp:1061] Authenticating with master master@172.17.0.4:43742
3: I1201 02:45:44.634300 17324 slave.cpp:1070] Using default CRAM-MD5 authenticatee
3: I1201 02:45:44.634651 17324 authenticatee.cpp:121] Creating new client SASL connection
3: I1201 02:45:44.634995 17324 master.cpp:8589] Authenticating slave(58)@172.17.0.4:43742
3: I1201 02:45:44.635185 17334 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(130)@172.17.0.4:43742
3: I1201 02:45:44.635512 17325 authenticator.cpp:98] Creating new server SASL connection
3: I1201 02:45:44.635920 17329 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1201 02:45:44.636008 17329 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1201 02:45:44.636232 17325 authenticator.cpp:204] Received SASL authentication start
3: I1201 02:45:44.636348 17325 authenticator.cpp:326] Authentication requires more steps
3: I1201 02:45:44.636512 17337 authenticatee.cpp:259] Received SASL authentication step
3: I1201 02:45:44.636628 17337 authenticator.cpp:232] Received SASL authentication step
3: I1201 02:45:44.636657 17337 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '5dc74a8b2fd6' server FQDN: '5dc74a8b2fd6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1201 02:45:44.636669 17337 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1201 02:45:44.636710 17337 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1201 02:45:44.636729 17337 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '5dc74a8b2fd6' server FQDN: '5dc74a8b2fd6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1201 02:45:44.636739 17337 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1201 02:45:44.636746 17337 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1201 02:45:44.636762 17337 authenticator.cpp:318] Authentication success
3: I1201 02:45:44.636909 17330 authenticatee.cpp:299] Authentication success
3: I1201 02:45:44.636977 17327 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(130)@172.17.0.4:43742
3: I1201 02:45:44.636945 17328 master.cpp:8619] Successfully authenticated principal 'test-principal' at slave(58)@172.17.0.4:43742
3: I1201 02:45:44.637331 17330 slave.cpp:1153] Successfully authenticated with master master@172.17.0.4:43742
3: I1201 02:45:44.637866 17330 slave.cpp:1696] Will retry registration in 12.465401ms if necessary
3: I1201 02:45:44.638366 17333 master.cpp:6371] Received re-register agent message from agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6)
3: I1201 02:45:44.638576 17333 master.cpp:3878] Authorizing agent with principal 'test-principal'
3: I1201 02:45:44.639155 17324 master.cpp:6442] Authorized re-registration of agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6)
3: I1201 02:45:44.639233 17324 master.cpp:6624] Re-registering agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6)
3: W1201 02:45:44.639813 17334 registry_operations.cpp:133] Allowing UNKNOWN agent to reregister: hostname: "5dc74a8b2fd6"
3: resources {
3: name: "cpus"
3: type: SCALAR
3: scalar {
3: value: 2
3: }
3: role: "*"
3: }
3: resources {
3: name: "mem"
3: type: SCALAR
3: scalar {
3: value: 1024
3: }
3: role: "*"
3: }
3: resources {
3: name: "disk"
3: type: SCALAR
3: scalar {
3: value: 1024
3: }
3: role: "*"
3: }
3: resources {
3: name: "ports"
3: type: RANGES
3: ranges {
3: range {
3: begin: 31000
3: end: 32000
3: }
3: }
3: role: "*"
3: }
3: id {
3: value: "395db372-c241-4fe4-b74c-e70984dfe8a3-S0"
3: }
3: checkpoint: true
3: port: 43742
3: I1201 02:45:44.640156 17334 registrar.cpp:495] Applied 1 operations in 382893ns; attempting to update the registry
3: I1201 02:45:44.640955 17334 registrar.cpp:552] Successfully updated the registry in 736us
3: I1201 02:45:44.641248 17328 master.cpp:6696] Re-admitted agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6)
3: I1201 02:45:44.642204 17328 master.cpp:6849] Re-registered agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
3: I1201 02:45:44.642343 17328 master.cpp:6912] Recovering framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 from re-registering agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6)
3: I1201 02:45:44.642421 17338 slave.cpp:1343] Re-registered with master master@172.17.0.4:43742
3: I1201 02:45:44.642546 17336 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1201 02:45:44.642562 17338 slave.cpp:1411] Forwarding total oversubscribed resources {}
3: I1201 02:45:44.642573 17331 hierarchical.cpp:553] Added agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 (5dc74a8b2fd6) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1201 02:45:44.642925 17331 hierarchical.cpp:1431] Performed allocation for 1 agents in 159029ns
3: I1201 02:45:44.643100 17328 master.cpp:7049] Received update of agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6) with total oversubscribed resources {}
3: I1201 02:45:44.643383 17328 master.cpp:7092] Ignoring update on agent 395db372-c241-4fe4-b74c-e70984dfe8a3-S0 at slave(58)@172.17.0.4:43742 (5dc74a8b2fd6) as it reports no changes
3: I1201 02:45:44.643474 17331 hierarchical.cpp:293] Added framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.643512 17331 hierarchical.cpp:406] Deactivated framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.643971 17327 sched.cpp:330] Scheduler::disconnected took 17877ns
3: I1201 02:45:44.643988 17327 sched.cpp:336] New master detected at master@172.17.0.4:43742
3: I1201 02:45:44.644076 17327 sched.cpp:396] Authenticating with master master@172.17.0.4:43742
3: I1201 02:45:44.644093 17327 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1201 02:45:44.644352 17330 authenticatee.cpp:121] Creating new client SASL connection
3: I1201 02:45:44.644731 17338 master.cpp:8589] Authenticating scheduler-50372b46-3a04-4dc9-9ee5-0b262e3a08e4@172.17.0.4:43742
3: I1201 02:45:44.644824 17336 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(131)@172.17.0.4:43742
3: I1201 02:45:44.645198 17336 authenticator.cpp:98] Creating new server SASL connection
3: I1201 02:45:44.645468 17336 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1201 02:45:44.645491 17336 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1201 02:45:44.645615 17323 authenticator.cpp:204] Received SASL authentication start
3: I1201 02:45:44.645675 17323 authenticator.cpp:326] Authentication requires more steps
3: I1201 02:45:44.645776 17323 authenticatee.cpp:259] Received SASL authentication step
3: I1201 02:45:44.645884 17323 authenticator.cpp:232] Received SASL authentication step
3: I1201 02:45:44.645912 17323 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '5dc74a8b2fd6' server FQDN: '5dc74a8b2fd6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1201 02:45:44.645923 17323 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1201 02:45:44.645962 17323 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1201 02:45:44.645982 17323 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '5dc74a8b2fd6' server FQDN: '5dc74a8b2fd6' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1201 02:45:44.645990 17323 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1201 02:45:44.645998 17323 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1201 02:45:44.646013 17323 authenticator.cpp:318] Authentication success
3: I1201 02:45:44.646085 17328 authenticatee.cpp:299] Authentication success
3: I1201 02:45:44.646149 17331 master.cpp:8619] Successfully authenticated principal 'test-principal' at scheduler-50372b46-3a04-4dc9-9ee5-0b262e3a08e4@172.17.0.4:43742
3: I1201 02:45:44.646221 17328 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(131)@172.17.0.4:43742
3: I1201 02:45:44.646502 17334 sched.cpp:502] Successfully authenticated with master master@172.17.0.4:43742
3: I1201 02:45:44.646522 17334 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.4:43742
3: I1201 02:45:44.646631 17334 sched.cpp:857] Will retry registration in 633.790614ms if necessary
3: I1201 02:45:44.646838 17330 master.cpp:2969] Received SUBSCRIBE call for framework 'default' at scheduler-50372b46-3a04-4dc9-9ee5-0b262e3a08e4@172.17.0.4:43742
3: I1201 02:45:44.647001 17330 master.cpp:2286] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1201 02:45:44.647575 17332 master.cpp:3049] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1201 02:45:44.647630 17332 master.cpp:6950] Updating info for framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.647882 17333 hierarchical.cpp:372] Activated framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.648028 17323 sched.cpp:751] Framework registered with 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
3: I1201 02:45:44.648094 17323 sched.cpp:765] Scheduler::registered took 44906ns
3: I1201 02:45:44.648123 17332 slave.cpp:3452] Updating info for framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 with pid updated to scheduler-50372b46-3a04-4dc9-9ee5-0b262e3a08e4@172.17.0.4:43742
3: I1201 02:45:44.648490 17331 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1201 02:45:44.648952 17330 slave.cpp:5202] Got exited event for executor(10)@172.17.0.4:43742
3: I1201 02:45:44.649173 17338 slave.cpp:5611] Executor 'default' of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 exited with status 0
3: I1201 02:45:44.649273 17338 slave.cpp:5715] Cleaning up executor 'default' of framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000 at executor(10)@172.17.0.4:43742
3: I1201 02:45:44.649456 17333 hierarchical.cpp:1431] Performed allocation for 1 agents in 1.434638ms
3: I1201 02:45:44.649621 17325 gc.cpp:90] Scheduling '/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_DYbHnh/slaves/395db372-c241-4fe4-b74c-e70984dfe8a3-S0/frameworks/395db372-c241-4fe4-b74c-e70984dfe8a3-0000/executors/default/runs/d989f9d7-97fb-4ce7-a53c-0552d59da4d3' for gc 6.99999248344889days in the future
3: I1201 02:45:44.649691 17338 slave.cpp:5822] Cleaning up framework 395db372-c241-4fe4-b74c-e70984dfe8a3-0000
write /dev/stdout: resource temporarily unavailable
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user yujie.jay@gmail.com
Not sending mail to unregistered user songzihao1990@gmail.com
Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4522
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,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)/4522/display/redirect?page=changes>
Changes:
[yujie.jay] Removed some dead code in the master.
[andrew] Windows: Added `os::set_job_cpu_limit` to stout.
[andrew] Windows: Added `os::set_job_mem_limit` to stout.
[andrew] Windows: Added `os::get_job_info` to stout.
[andrew] Windows: Added `os::get_job_processes` to stout.
[andrew] Windows: Added `os::get_job_mem` to stout.
[andrew] Windows: Abstracted out `os::name_job` in stout.
[andrew] Windows: Added `Cpu` and `Mem` isolators.
[andrew] Windows: Ported `Cpu` and `Mem` isolator tests.
[andrew] Windows: Documented the `cpu` and `mem` isolators.
[andrew] Windows: Fixed `SlaveReregisterTaskExecutorIds` test.
------------------------------------------
[...truncated 5.49 MB...]
3: I1201 01:27:46.862982 17334 hierarchical.cpp:586] Removed agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0
3: I1201 01:27:46.862987 17330 master.cpp:9913] Removing task 31c44447-55ba-4ba1-8aa5-537f78a872f7 with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] of framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000 on agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 at slave(109)@172.17.0.4:52315 (3e44a50127b8)
3: I1201 01:27:46.863281 17330 master.cpp:7608] Sending status update TASK_LOST for task 31c44447-55ba-4ba1-8aa5-537f78a872f7 of framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000 'health check timed out'
3: I1201 01:27:46.878130 17330 master.cpp:2138] Notifying framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000 (default) at scheduler-f4730b56-5f27-4e26-b45f-b0516deea246@172.17.0.4:52315 of lost agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 (3e44a50127b8)
3: I1201 01:27:46.878244 17334 sched.cpp:1029] Scheduler::statusUpdate took 97368ns
3: I1201 01:27:46.878530 17334 sched.cpp:1091] Lost agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0
3: I1201 01:27:46.878607 17334 sched.cpp:1102] Scheduler::slaveLost took 33363ns
3: I1201 01:27:46.883891 17338 process.cpp:3503] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot'
3: I1201 01:27:46.885184 17338 http.cpp:851] Authorizing principal 'ANY' to GET the endpoint '/metrics/snapshot'
3: I1201 01:27:46.961885 17337 process.cpp:3503] Handling HTTP event for process 'master' with path: '/master/state'
3: I1201 01:27:46.964293 17337 http.cpp:1185] HTTP GET for /master/state from 172.17.0.4:35427
3: I1201 01:27:46.999550 17334 slave.cpp:992] Lost leading master
3: I1201 01:27:46.999585 17334 slave.cpp:1034] Detecting new master
3: I1201 01:27:46.999717 17334 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1201 01:27:47.000094 17334 slave.cpp:999] New master detected at master@172.17.0.4:52315
3: I1201 01:27:47.000250 17334 slave.cpp:1034] Detecting new master
3: I1201 01:27:47.000382 17334 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1201 01:27:47.001621 17333 slave.cpp:1061] Authenticating with master master@172.17.0.4:52315
3: I1201 01:27:47.001716 17333 slave.cpp:1070] Using default CRAM-MD5 authenticatee
3: I1201 01:27:47.002135 17333 authenticatee.cpp:121] Creating new client SASL connection
3: I1201 01:27:47.002557 17333 master.cpp:8589] Authenticating slave(109)@172.17.0.4:52315
3: I1201 01:27:47.002760 17333 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(237)@172.17.0.4:52315
3: I1201 01:27:47.003180 17333 authenticator.cpp:98] Creating new server SASL connection
3: I1201 01:27:47.003453 17333 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1201 01:27:47.003476 17333 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1201 01:27:47.003588 17333 authenticator.cpp:204] Received SASL authentication start
3: I1201 01:27:47.003644 17333 authenticator.cpp:326] Authentication requires more steps
3: I1201 01:27:47.003752 17333 authenticatee.cpp:259] Received SASL authentication step
3: I1201 01:27:47.003868 17333 authenticator.cpp:232] Received SASL authentication step
3: I1201 01:27:47.003891 17333 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3e44a50127b8' server FQDN: '3e44a50127b8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1201 01:27:47.003902 17333 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1201 01:27:47.003947 17333 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1201 01:27:47.003964 17333 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3e44a50127b8' server FQDN: '3e44a50127b8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1201 01:27:47.003974 17333 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1201 01:27:47.003983 17333 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1201 01:27:47.003998 17333 authenticator.cpp:318] Authentication success
3: I1201 01:27:47.004215 17333 authenticatee.cpp:299] Authentication success
3: I1201 01:27:47.004313 17333 master.cpp:8619] Successfully authenticated principal 'test-principal' at slave(109)@172.17.0.4:52315
3: I1201 01:27:47.004401 17333 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(237)@172.17.0.4:52315
3: I1201 01:27:47.004765 17333 slave.cpp:1153] Successfully authenticated with master master@172.17.0.4:52315
3: I1201 01:27:47.006140 17325 master.cpp:6371] Received re-register agent message from agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 at slave(109)@172.17.0.4:52315 (3e44a50127b8)
3: I1201 01:27:47.006397 17325 master.cpp:3878] Authorizing agent with principal 'test-principal'
3: I1201 01:27:47.007091 17325 master.cpp:6442] Authorized re-registration of agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 at slave(109)@172.17.0.4:52315 (3e44a50127b8)
3: I1201 01:27:47.007182 17325 master.cpp:6624] Re-registering agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 at slave(109)@172.17.0.4:52315 (3e44a50127b8)
3: I1201 01:27:47.007851 17325 registrar.cpp:495] Applied 1 operations in 90367ns; attempting to update the registry
3: I1201 01:27:47.008803 17325 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1201 01:27:47.009212 17339 master.cpp:6696] Re-admitted agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 at slave(109)@172.17.0.4:52315 (3e44a50127b8)
3: I1201 01:27:47.009932 17339 master.cpp:11130] Adding task 31c44447-55ba-4ba1-8aa5-537f78a872f7 with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] on agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 at slave(109)@172.17.0.4:52315 (3e44a50127b8)
3: I1201 01:27:47.010664 17339 master.cpp:6849] Re-registered agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 at slave(109)@172.17.0.4:52315 (3e44a50127b8) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
3: I1201 01:27:47.011965 17339 hierarchical.cpp:553] Added agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 (3e44a50127b8) 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: I1201 01:27:47.012315 17339 hierarchical.cpp:1431] Performed allocation for 1 agents in 167115ns
3: I1201 01:27:47.012516 17333 slave.cpp:1696] Will retry registration in 17.239296ms if necessary
3: I1201 01:27:47.012816 17333 slave.cpp:1343] Re-registered with master master@172.17.0.4:52315
3: I1201 01:27:47.012985 17333 slave.cpp:1411] Forwarding total oversubscribed resources {}
3: I1201 01:27:47.013157 17332 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1201 01:27:47.013360 17332 master.cpp:7049] Received update of agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 at slave(109)@172.17.0.4:52315 (3e44a50127b8) with total oversubscribed resources {}
3: I1201 01:27:47.013572 17332 master.cpp:7092] Ignoring update on agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 at slave(109)@172.17.0.4:52315 (3e44a50127b8) as it reports no changes
3: I1201 01:27:47.013794 17333 slave.cpp:3452] Updating info for framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000 with pid updated to scheduler-f4730b56-5f27-4e26-b45f-b0516deea246@172.17.0.4:52315
3: I1201 01:27:47.013913 17328 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1201 01:27:47.014667 17331 master.cpp:8073] Performing explicit task state reconciliation for 1 tasks of framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000 (default) at scheduler-f4730b56-5f27-4e26-b45f-b0516deea246@172.17.0.4:52315
3: I1201 01:27:47.014806 17331 master.cpp:8221] Sending explicit reconciliation state TASK_RUNNING for task 31c44447-55ba-4ba1-8aa5-537f78a872f7 of framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000 (default) at scheduler-f4730b56-5f27-4e26-b45f-b0516deea246@172.17.0.4:52315
3: I1201 01:27:47.015224 17331 sched.cpp:1029] Scheduler::statusUpdate took 69468ns
3: I1201 01:27:47.018959 17337 process.cpp:3503] Handling HTTP event for process 'master' with path: '/master/state'
3: I1201 01:27:47.020814 17335 http.cpp:1185] HTTP GET for /master/state from 172.17.0.4:35428
3: I1201 01:27:47.051713 17333 process.cpp:3503] Handling HTTP event for process 'master' with path: '/master/state-summary'
3: I1201 01:27:47.053431 17337 http.cpp:1185] HTTP GET for /master/state-summary from 172.17.0.4:35429
3: I1201 01:27:47.085711 17325 process.cpp:3503] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot'
3: I1201 01:27:47.086828 17325 http.cpp:851] Authorizing principal 'ANY' to GET the endpoint '/metrics/snapshot'
3: I1201 01:27:47.112888 17323 sched.cpp:2009] Asked to stop the driver
3: I1201 01:27:47.117856 17330 sched.cpp:1191] Stopping framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000
3: I1201 01:27:47.118293 17339 master.cpp:9096] Processing TEARDOWN call for framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000 (default) at scheduler-f4730b56-5f27-4e26-b45f-b0516deea246@172.17.0.4:52315
3: I1201 01:27:47.118386 17339 master.cpp:9108] Removing framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000 (default) at scheduler-f4730b56-5f27-4e26-b45f-b0516deea246@172.17.0.4:52315
3: I1201 01:27:47.118435 17339 master.cpp:3339] Deactivating framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000 (default) at scheduler-f4730b56-5f27-4e26-b45f-b0516deea246@172.17.0.4:52315
3: I1201 01:27:47.118608 17328 hierarchical.cpp:406] Deactivated framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000
3: I1201 01:27:47.118831 17337 slave.cpp:3281] Asked to shut down framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000 by master@172.17.0.4:52315
3: I1201 01:27:47.118850 17339 master.cpp:9807] Updating the state of task 31c44447-55ba-4ba1-8aa5-537f78a872f7 of framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
3: I1201 01:27:47.119788 17339 master.cpp:9913] Removing task 31c44447-55ba-4ba1-8aa5-537f78a872f7 with resources cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] of framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000 on agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 at slave(109)@172.17.0.4:52315 (3e44a50127b8)
3: I1201 01:27:47.118930 17337 slave.cpp:3306] Shutting down framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000
3: I1201 01:27:47.121209 17337 slave.cpp:5946] Shutting down executor '31c44447-55ba-4ba1-8aa5-537f78a872f7' of framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000 at executor(1)@172.17.0.4:50306
3: I1201 01:27:47.121417 17339 hierarchical.cpp:1106] Recovered cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 from framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000
3: I1201 01:27:47.121717 17339 hierarchical.cpp:345] Removed framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000
3: I1201 01:27:47.126389 18859 exec.cpp:435] Executor asked to shutdown
3: I1201 01:27:47.127284 18859 executor.cpp:171] Received SHUTDOWN event
3: I1201 01:27:47.127307 18859 executor.cpp:747] Shutting down
3: I1201 01:27:47.127358 18859 executor.cpp:854] Sending SIGTERM to process tree at pid 18864
3: I1201 01:27:47.135218 18859 executor.cpp:867] Sent SIGTERM to the following process trees:
3: [
3: -+- 18864 sh -c sleep 60
3: \--- 18865 sleep 60
3: ]
3: I1201 01:27:47.135287 18859 executor.cpp:871] Scheduling escalation to SIGKILL in 3secs from now
3: I1201 01:27:47.136274 17338 slave.cpp:875] Agent terminating
3: I1201 01:27:47.136333 18859 executor.cpp:929] Command terminated with signal Terminated (pid: 18864)
3: I1201 01:27:47.136448 17338 slave.cpp:3281] Asked to shut down framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000 by @0.0.0.0:0
3: W1201 01:27:47.136485 17338 slave.cpp:3302] Ignoring shutdown framework 0578fa53-fea6-4e8c-9421-6f8075300357-0000 because it is terminating
3: I1201 01:27:47.153478 17338 master.cpp:1317] Agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 at slave(109)@172.17.0.4:52315 (3e44a50127b8) disconnected
3: I1201 01:27:47.153664 17338 master.cpp:3376] Disconnecting agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 at slave(109)@172.17.0.4:52315 (3e44a50127b8)
3: I1201 01:27:47.153794 17338 master.cpp:3395] Deactivating agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 at slave(109)@172.17.0.4:52315 (3e44a50127b8)
3: I1201 01:27:47.154152 17338 hierarchical.cpp:671] Agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0 deactivated
3: I1201 01:27:47.157483 17340 process.cpp:2578] Failed to deliver libprocess message to /slave(109)/mesos.internal.StatusUpdateMessage
3: I1201 01:27:47.158141 17328 containerizer.cpp:2326] Destroying container fbda24ea-9d50-4e1c-8bcc-4914eea91ec0 in RUNNING state
3: I1201 01:27:47.158170 17328 containerizer.cpp:2923] Transitioning the state of container fbda24ea-9d50-4e1c-8bcc-4914eea91ec0 from RUNNING to DESTROYING
3: I1201 01:27:47.158530 17328 launcher.cpp:156] Asked to destroy container fbda24ea-9d50-4e1c-8bcc-4914eea91ec0
3: I1201 01:27:47.165221 17331 hierarchical.cpp:1431] Performed allocation for 1 agents in 204409ns
3: I1201 01:27:47.173406 17340 process.cpp:774] Decode failure: Connection reset by peer
3: I1201 01:27:47.173559 17340 process.cpp:2139] Failed to shutdown socket with fd 7, address 172.17.0.4:52315: Transport endpoint is not connected
3: I1201 01:27:47.226439 17338 containerizer.cpp:2777] Container fbda24ea-9d50-4e1c-8bcc-4914eea91ec0 has exited
3: I1201 01:27:47.230406 17325 provisioner.cpp:595] Ignoring destroy request for unknown container fbda24ea-9d50-4e1c-8bcc-4914eea91ec0
3: I1201 01:27:47.345515 17323 master.cpp:1159] Master terminating
3: I1201 01:27:47.346994 17327 hierarchical.cpp:586] Removed agent 0578fa53-fea6-4e8c-9421-6f8075300357-S0
3: [ OK ] PartitionTest.ReregisterSlaveNotPartitionAware (1099 ms)
3: [ RUN ] PartitionTest.PartitionedSlaveReregistrationMasterFailover
3: I1201 01:27:47.364881 17323 cluster.cpp:170] Creating default 'local' authorizer
3: I1201 01:27:47.379663 17328 master.cpp:454] Master d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57 (3e44a50127b8) started on 172.17.0.4:52315
3: I1201 01:27:47.379698 17328 master.cpp:456] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/186RgC/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/186RgC/master" --zk_session_timeout="10secs"
3: I1201 01:27:47.380182 17328 master.cpp:505] Master only allowing authenticated frameworks to register
3: I1201 01:27:47.380190 17328 master.cpp:511] Master only allowing authenticated agents to register
3: I1201 01:27:47.380197 17328 master.cpp:517] Master only allowing authenticated HTTP frameworks to register
3: I1201 01:27:47.380203 17328 credentials.hpp:37] Loading credentials for authentication from '/tmp/186RgC/credentials'
3: I1201 01:27:47.380548 17328 master.cpp:561] Using default 'crammd5' authenticator
3: I1201 01:27:47.380774 17328 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1201 01:27:47.380992 17328 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1201 01:27:47.381736 17328 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1201 01:27:47.382218 17328 master.cpp:640] Authorization enabled
3: I1201 01:27:47.382413 17339 hierarchical.cpp:173] Initialized hierarchical allocator process
3: I1201 01:27:47.382784 17330 whitelist_watcher.cpp:77] No whitelist given
3: I1201 01:27:47.389456 17328 master.cpp:2221] Elected as the leading master!
3: I1201 01:27:47.389492 17328 master.cpp:1701] Recovering from registrar
3: I1201 01:27:47.389628 17327 registrar.cpp:347] Recovering registrar
3: I1201 01:27:47.390573 17327 registrar.cpp:391] Successfully fetched the registry (0B) in 0ns
3: I1201 01:27:47.390696 17327 registrar.cpp:495] Applied 1 operations in 43272ns; attempting to update the registry
3: I1201 01:27:47.391513 17327 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1201 01:27:47.391631 17327 registrar.cpp:424] Successfully recovered registrar
3: I1201 01:27:47.392223 17328 master.cpp:1814] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1201 01:27:47.392459 17328 hierarchical.cpp:211] Skipping recovery of hierarchical allocator: nothing to recover
3: W1201 01:27:47.421350 17323 process.cpp:2756] Attempted to spawn already running process files@172.17.0.4:52315
3: I1201 01:27:47.422744 17323 containerizer.cpp:304] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1201 01:27:47.423473 17323 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1201 01:27:47.423635 17323 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1201 01:27:47.423668 17323 provisioner.cpp:297] Using default backend 'copy'
3: I1201 01:27:47.426136 17323 cluster.cpp:458] Creating default 'local' authorizer
3: I1201 01:27:47.431802 17336 slave.cpp:253] Mesos agent started on (110)@172.17.0.4:52315
3: I1201 01:27:47.431843 17336 slave.cpp:254] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_p9X21E/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_PartitionedSlaveReregistrationMasterFailover_p9X21E/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_PartitionedSlaveReregistrationMasterFailover_p9X21E/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_PartitionedSlaveReregistrationMasterFailover_p9X21E/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_PartitionedSlaveReregistrationMasterFailover_p9X21E/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;mem:1024" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_p9X21E" --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_PartitionedSlaveReregistrationMasterFailover_bxc0C8" --zk_session_timeout="10secs"
3: I1201 01:27:47.432538 17336 credentials.hpp:86] Loading credential for authentication from '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_p9X21E/credential'
3: I1201 01:27:47.432835 17336 slave.cpp:286] Agent using credential for: test-principal
3: I1201 01:27:47.432853 17336 credentials.hpp:37] Loading credentials for authentication from '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_p9X21E/http_credentials'
3: I1201 01:27:47.433195 17336 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1201 01:27:47.433531 17336 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: W1201 01:27:47.433954 17323 process.cpp:2756] Attempted to spawn already running process version@172.17.0.4:52315
3: I1201 01:27:47.435137 17323 sched.cpp:232] Version: 1.5.0
3: I1201 01:27:47.435354 17336 slave.cpp:585] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":3701220.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1201 01:27:47.435708 17336 slave.cpp:593] Agent attributes: [ ]
3: I1201 01:27:47.435722 17336 slave.cpp:602] Agent hostname: 3e44a50127b8
3: I1201 01:27:47.435953 17339 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1201 01:27:47.436012 17339 sched.cpp:336] New master detected at master@172.17.0.4:52315
3: I1201 01:27:47.436154 17339 sched.cpp:396] Authenticating with master master@172.17.0.4:52315
3: I1201 01:27:47.436167 17339 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1201 01:27:47.436606 17339 authenticatee.cpp:121] Creating new client SASL connection
3: I1201 01:27:47.437340 17329 master.cpp:8589] Authenticating scheduler-ec82c481-2054-46bf-9150-deb1cf12a8d9@172.17.0.4:52315
3: I1201 01:27:47.437492 17334 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(238)@172.17.0.4:52315
3: I1201 01:27:47.437973 17334 authenticator.cpp:98] Creating new server SASL connection
3: I1201 01:27:47.438283 17334 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1201 01:27:47.438305 17334 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1201 01:27:47.438424 17334 authenticator.cpp:204] Received SASL authentication start
3: I1201 01:27:47.438479 17334 authenticator.cpp:326] Authentication requires more steps
3: I1201 01:27:47.438596 17334 authenticatee.cpp:259] Received SASL authentication step
3: I1201 01:27:47.438720 17334 authenticator.cpp:232] Received SASL authentication step
3: I1201 01:27:47.438748 17334 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3e44a50127b8' server FQDN: '3e44a50127b8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1201 01:27:47.438760 17334 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1201 01:27:47.438802 17334 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1201 01:27:47.438823 17334 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3e44a50127b8' server FQDN: '3e44a50127b8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1201 01:27:47.438833 17334 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1201 01:27:47.438841 17334 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1201 01:27:47.438858 17334 authenticator.cpp:318] Authentication success
3: I1201 01:27:47.439040 17334 authenticatee.cpp:299] Authentication success
3: I1201 01:27:47.439155 17334 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(238)@172.17.0.4:52315
3: I1201 01:27:47.439534 17334 sched.cpp:502] Successfully authenticated with master master@172.17.0.4:52315
3: I1201 01:27:47.439550 17334 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.4:52315
3: I1201 01:27:47.439666 17334 sched.cpp:857] Will retry registration in 1.624128516secs if necessary
3: I1201 01:27:47.440030 17329 master.cpp:2871] Queuing up SUBSCRIBE call for framework 'default' at scheduler-ec82c481-2054-46bf-9150-deb1cf12a8d9@172.17.0.4:52315 because authentication is still in progress
3: I1201 01:27:47.440214 17329 master.cpp:8619] Successfully authenticated principal 'test-principal' at scheduler-ec82c481-2054-46bf-9150-deb1cf12a8d9@172.17.0.4:52315
3: I1201 01:27:47.440433 17329 master.cpp:2969] Received SUBSCRIBE call for framework 'default' at scheduler-ec82c481-2054-46bf-9150-deb1cf12a8d9@172.17.0.4:52315
3: I1201 01:27:47.440552 17329 master.cpp:2286] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1201 01:27:47.441154 17334 master.cpp:3049] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1201 01:27:47.441812 17327 hierarchical.cpp:1431] Performed allocation for 0 agents in 64593ns
3: I1201 01:27:47.442653 17334 sched.cpp:751] Framework registered with d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-0000
3: I1201 01:27:47.442706 17334 sched.cpp:765] Scheduler::registered took 27128ns
3: I1201 01:27:47.442750 17337 hierarchical.cpp:293] Added framework d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-0000
3: I1201 01:27:47.442996 17337 hierarchical.cpp:1431] Performed allocation for 0 agents in 94395ns
3: I1201 01:27:47.446166 17338 state.cpp:64] Recovering state from '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_bxc0C8/meta'
3: I1201 01:27:47.493692 17336 task_status_update_manager.cpp:207] Recovering task status update manager
3: I1201 01:27:47.494524 17331 containerizer.cpp:672] Recovering containerizer
3: I1201 01:27:47.496757 17329 provisioner.cpp:493] Provisioner recovery complete
3: I1201 01:27:47.497386 17330 slave.cpp:6513] Finished recovery
3: I1201 01:27:47.498594 17330 slave.cpp:999] New master detected at master@172.17.0.4:52315
3: I1201 01:27:47.498742 17330 slave.cpp:1034] Detecting new master
3: I1201 01:27:47.498775 17335 task_status_update_manager.cpp:181] Pausing sending task status updates
3: I1201 01:27:47.500123 17339 slave.cpp:1061] Authenticating with master master@172.17.0.4:52315
3: I1201 01:27:47.500246 17339 slave.cpp:1070] Using default CRAM-MD5 authenticatee
3: I1201 01:27:47.500687 17339 authenticatee.cpp:121] Creating new client SASL connection
3: I1201 01:27:47.501157 17339 master.cpp:8589] Authenticating slave(110)@172.17.0.4:52315
3: I1201 01:27:47.501379 17339 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(239)@172.17.0.4:52315
3: I1201 01:27:47.501701 17330 authenticator.cpp:98] Creating new server SASL connection
3: I1201 01:27:47.502135 17330 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1201 01:27:47.502162 17330 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1201 01:27:47.502298 17330 authenticator.cpp:204] Received SASL authentication start
3: I1201 01:27:47.502360 17330 authenticator.cpp:326] Authentication requires more steps
3: I1201 01:27:47.502485 17330 authenticatee.cpp:259] Received SASL authentication step
3: I1201 01:27:47.502619 17330 authenticator.cpp:232] Received SASL authentication step
3: I1201 01:27:47.502651 17330 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3e44a50127b8' server FQDN: '3e44a50127b8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1201 01:27:47.502671 17330 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1201 01:27:47.502718 17330 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1201 01:27:47.502750 17330 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '3e44a50127b8' server FQDN: '3e44a50127b8' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1201 01:27:47.502765 17330 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1201 01:27:47.502773 17330 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1201 01:27:47.502786 17330 authenticator.cpp:318] Authentication success
3: I1201 01:27:47.503032 17327 authenticatee.cpp:299] Authentication success
3: I1201 01:27:47.503155 17327 master.cpp:8619] Successfully authenticated principal 'test-principal' at slave(110)@172.17.0.4:52315
3: I1201 01:27:47.503273 17327 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(239)@172.17.0.4:52315
3: I1201 01:27:47.503710 17324 slave.cpp:1153] Successfully authenticated with master master@172.17.0.4:52315
3: I1201 01:27:47.504006 17324 slave.cpp:1696] Will retry registration in 4.592972ms if necessary
3: I1201 01:27:47.504463 17324 master.cpp:6042] Received register agent message from slave(110)@172.17.0.4:52315 (3e44a50127b8)
3: I1201 01:27:47.504616 17324 master.cpp:3878] Authorizing agent with principal 'test-principal'
3: I1201 01:27:47.505347 17339 master.cpp:6104] Authorized registration of agent at slave(110)@172.17.0.4:52315 (3e44a50127b8)
3: I1201 01:27:47.505496 17339 master.cpp:6197] Registering agent at slave(110)@172.17.0.4:52315 (3e44a50127b8) with id d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-S0
3: I1201 01:27:47.506109 17339 registrar.cpp:495] Applied 1 operations in 87912ns; attempting to update the registry
3: I1201 01:27:47.507171 17327 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1201 01:27:47.507544 17327 master.cpp:6246] Admitted agent d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-S0 at slave(110)@172.17.0.4:52315 (3e44a50127b8)
3: I1201 01:27:47.508576 17327 master.cpp:6282] Registered agent d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-S0 at slave(110)@172.17.0.4:52315 (3e44a50127b8) with cpus:2; mem:1024; disk:3701220; ports:[31000-32000]
3: I1201 01:27:47.509222 17335 slave.cpp:1199] Registered with master master@172.17.0.4:52315; given agent ID d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-S0
3: I1201 01:27:47.509371 17328 task_status_update_manager.cpp:188] Resuming sending task status updates
3: I1201 01:27:47.509436 17327 hierarchical.cpp:553] Added agent d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-S0 (3e44a50127b8) with cpus:2; mem:1024; disk:3701220; ports:[31000-32000] (allocated: {})
3: I1201 01:27:47.509774 17335 slave.cpp:1219] Checkpointing SlaveInfo to '/tmp/PartitionTest_PartitionedSlaveReregistrationMasterFailover_bxc0C8/meta/slaves/d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-S0/slave.info'
3: I1201 01:27:47.510339 17335 slave.cpp:1298] Forwarding total oversubscribed resources {}
3: I1201 01:27:47.510799 17335 master.cpp:7049] Received update of agent d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-S0 at slave(110)@172.17.0.4:52315 (3e44a50127b8) with total oversubscribed resources {}
3: I1201 01:27:47.511121 17335 master.cpp:7092] Ignoring update on agent d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-S0 at slave(110)@172.17.0.4:52315 (3e44a50127b8) as it reports no changes
3: I1201 01:27:47.511225 17327 hierarchical.cpp:1431] Performed allocation for 1 agents in 1.601066ms
3: I1201 01:27:47.511827 17335 master.cpp:8419] Sending 1 offers to framework d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-0000 (default) at scheduler-ec82c481-2054-46bf-9150-deb1cf12a8d9@172.17.0.4:52315
3: I1201 01:27:47.512451 17335 sched.cpp:921] Scheduler::resourceOffers took 89626ns
3: I1201 01:27:47.515102 17339 master.cpp:10370] Removing offer d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-O0
3: I1201 01:27:47.515270 17339 master.cpp:4236] Processing ACCEPT call for offers: [ d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-O0 ] on agent d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-S0 at slave(110)@172.17.0.4:52315 (3e44a50127b8) for framework d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-0000 (default) at scheduler-ec82c481-2054-46bf-9150-deb1cf12a8d9@172.17.0.4:52315
3: I1201 01:27:47.515386 17339 master.cpp:3605] Authorizing framework principal 'test-principal' to launch task 5f515f79-1f3d-4281-b501-8cc32f180ce0
3: I1201 01:27:47.518388 17339 master.cpp:11130] Adding task 5f515f79-1f3d-4281-b501-8cc32f180ce0 with resources cpus(allocated: *):1; mem(allocated: *):512 on agent d7ac1d4c-38ff-4a0c-9c6c-44a867cdac57-S0 at slave(110)@172.17.0.4:52315 (3e44a50127b8)
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1512087808-25901
Error response from daemon: conflict: unable to remove repository reference "mesos-1512087808-25901" (must force) - container 3e44a50127b8 is using its referenced image 31cede56d1dc
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user yujie.jay@gmail.com
Not sending mail to unregistered user songzihao1990@gmail.com