See
<https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4560/display/redirect>
------------------------------------------
[...truncated 3.67 MB...]
3: I1208 02:42:12.748484 18412 master.cpp:9051] Adding framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000 (default) with roles { } suppressed
3: I1208 02:42:12.748535 18400 hierarchical.cpp:572] Added agent
41953f09-fcd4-42a5-b268-f18492a3b224-S0 (b69706d34c34) with cpus:2; mem:1024;
disk:1024; ports:[31000-32000] (allocated: {})
3: I1208 02:42:12.748652 18411 slave.cpp:1463] Forwarding total oversubscribed
resources {}
3: I1208 02:42:12.748677 18391 task_status_update_manager.cpp:188] Resuming
sending task status updates
3: I1208 02:42:12.749006 18412 master.cpp:7245] Received update of agent
41953f09-fcd4-42a5-b268-f18492a3b224-S0 at slave(59)@172.17.0.4:38494
(b69706d34c34) with total oversubscribed resources {}
3: I1208 02:42:12.749148 18400 hierarchical.cpp:297] Added framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000
3: I1208 02:42:12.749184 18412 master.cpp:7288] Ignoring update on agent
41953f09-fcd4-42a5-b268-f18492a3b224-S0 at slave(59)@172.17.0.4:38494
(b69706d34c34) as it reports no changes
3: I1208 02:42:12.749194 18400 hierarchical.cpp:405] Deactivated framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000
3: I1208 02:42:12.749480 18400 hierarchical.cpp:1513] Performed allocation for
1 agents in 204934ns
3: I1208 02:42:12.749683 18414 sched.cpp:330] Scheduler::disconnected took
54156ns
3: I1208 02:42:12.749727 18414 sched.cpp:336] New master detected at
[email protected]:38494
3: I1208 02:42:12.749891 18414 sched.cpp:396] Authenticating with master
[email protected]:38494
3: I1208 02:42:12.749925 18414 sched.cpp:403] Using default CRAM-MD5
authenticatee
3: I1208 02:42:12.750289 18406 authenticatee.cpp:121] Creating new client SASL
connection
3: I1208 02:42:12.750619 18401 master.cpp:8830] Authenticating
[email protected]:38494
3: I1208 02:42:12.750746 18403 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(130)@172.17.0.4:38494
3: I1208 02:42:12.751108 18409 authenticator.cpp:98] Creating new server SASL
connection
3: I1208 02:42:12.751435 18395 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I1208 02:42:12.751467 18395 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I1208 02:42:12.751603 18395 authenticator.cpp:204] Received SASL
authentication start
3: I1208 02:42:12.751688 18395 authenticator.cpp:326] Authentication requires
more steps
3: I1208 02:42:12.751847 18408 authenticatee.cpp:259] Received SASL
authentication step
3: I1208 02:42:12.751966 18408 authenticator.cpp:232] Received SASL
authentication step
3: I1208 02:42:12.751996 18408 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'b69706d34c34' server FQDN: 'b69706d34c34'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I1208 02:42:12.752018 18408 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I1208 02:42:12.752054 18408 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I1208 02:42:12.752073 18408 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'b69706d34c34' server FQDN: 'b69706d34c34'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I1208 02:42:12.752082 18408 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1208 02:42:12.752087 18408 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1208 02:42:12.752100 18408 authenticator.cpp:318] Authentication success
3: I1208 02:42:12.752220 18402 authenticatee.cpp:299] Authentication success
3: I1208 02:42:12.752275 18405 master.cpp:8860] Successfully authenticated
principal 'test-principal' at
[email protected]:38494
3: I1208 02:42:12.752308 18391 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(130)@172.17.0.4:38494
3: I1208 02:42:12.752559 18411 sched.cpp:502] Successfully authenticated with
master [email protected]:38494
3: I1208 02:42:12.752581 18411 sched.cpp:824] Sending SUBSCRIBE call to
[email protected]:38494
3: I1208 02:42:12.752691 18411 sched.cpp:857] Will retry registration in
38.436949ms if necessary
3: I1208 02:42:12.752868 18398 master.cpp:2962] Received SUBSCRIBE call for
framework 'default' at
[email protected]:38494
3: I1208 02:42:12.752892 18398 master.cpp:2279] Authorizing framework principal
'test-principal' to receive offers for roles '{ * }'
3: I1208 02:42:12.753329 18412 master.cpp:3042] Subscribing framework default
with checkpointing disabled and capabilities [ MULTI_ROLE,
RESERVATION_REFINEMENT ]
3: I1208 02:42:12.753379 18412 master.cpp:7145] Updating framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000 (default) with roles { } suppressed
3: I1208 02:42:12.753633 18413 hierarchical.cpp:371] Activated framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000
3: I1208 02:42:12.753777 18397 sched.cpp:751] Framework registered with
41953f09-fcd4-42a5-b268-f18492a3b224-0000
3: I1208 02:42:12.753842 18397 sched.cpp:765] Scheduler::registered took 52796ns
3: I1208 02:42:12.753867 18400 slave.cpp:3515] Updating info for framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000 with pid updated to
[email protected]:38494
3: I1208 02:42:12.753998 18407 task_status_update_manager.cpp:188] Resuming
sending task status updates
3: I1208 02:42:12.754588 18402 slave.cpp:5316] Got exited event for
executor(10)@172.17.0.4:38494
3: I1208 02:42:12.754818 18410 slave.cpp:5725] Executor 'default' of framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000 exited with status 0
3: I1208 02:42:12.754918 18410 slave.cpp:5829] Cleaning up executor 'default'
of framework 41953f09-fcd4-42a5-b268-f18492a3b224-0000 at
executor(10)@172.17.0.4:38494
3: I1208 02:42:12.754915 18413 hierarchical.cpp:1513] Performed allocation for
1 agents in 1.144871ms
3: I1208 02:42:12.755146 18399 gc.cpp:90] Scheduling
'/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_DuoHkR/slaves/41953f09-fcd4-42a5-b268-f18492a3b224-S0/frameworks/41953f09-fcd4-42a5-b268-f18492a3b224-0000/executors/default/runs/7f18c1d8-e787-4294-b515-6a53a95fee37'
for gc 6.9999912610637days in the future
3: I1208 02:42:12.755313 18410 slave.cpp:5936] Cleaning up framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000
3: I1208 02:42:12.755316 18399 gc.cpp:90] Scheduling
'/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_DuoHkR/slaves/41953f09-fcd4-42a5-b268-f18492a3b224-S0/frameworks/41953f09-fcd4-42a5-b268-f18492a3b224-0000/executors/default'
for gc 6.99999125882074days in the future
3: I1208 02:42:12.755445 18411 task_status_update_manager.cpp:289] Closing task
status update streams for framework 41953f09-fcd4-42a5-b268-f18492a3b224-0000
3: I1208 02:42:12.755439 18409 master.cpp:8660] Sending 1 offers to framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000 (default) at
[email protected]:38494
3: I1208 02:42:12.755502 18398 gc.cpp:90] Scheduling
'/tmp/FaultToleranceTest_FrameworkReregisterEmptyExecutor_DuoHkR/slaves/41953f09-fcd4-42a5-b268-f18492a3b224-S0/frameworks/41953f09-fcd4-42a5-b268-f18492a3b224-0000'
for gc 6.99999125678222days in the future
3: I1208 02:42:12.755947 18409 master.cpp:7987] Executor 'default' of framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000 on agent
41953f09-fcd4-42a5-b268-f18492a3b224-S0 at slave(59)@172.17.0.4:38494
(b69706d34c34): exited with status 0
3: I1208 02:42:12.756012 18393 sched.cpp:921] Scheduler::resourceOffers took
30907ns
3: I1208 02:42:12.756011 18409 master.cpp:10191] Removing executor 'default'
with resources [] of framework 41953f09-fcd4-42a5-b268-f18492a3b224-0000 on
agent 41953f09-fcd4-42a5-b268-f18492a3b224-S0 at slave(59)@172.17.0.4:38494
(b69706d34c34)
3: I1208 02:42:12.756332 18403 sched.cpp:1131] Executor default on agent
41953f09-fcd4-42a5-b268-f18492a3b224-S0 exited with status 0
3: I1208 02:42:12.756399 18403 sched.cpp:1142] Scheduler::executorLost took
56041ns
3: I1208 02:42:12.756708 18390 sched.cpp:2009] Asked to stop the driver
3: I1208 02:42:12.756800 18392 sched.cpp:1191] Stopping framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000
3: I1208 02:42:12.757020 18402 master.cpp:9340] Processing TEARDOWN call for
framework 41953f09-fcd4-42a5-b268-f18492a3b224-0000 (default) at
[email protected]:38494
3: I1208 02:42:12.757053 18402 master.cpp:9352] Removing framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000 (default) at
[email protected]:38494
3: I1208 02:42:12.757067 18402 master.cpp:3332] Deactivating framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000 (default) at
[email protected]:38494
3: I1208 02:42:12.757166 18391 hierarchical.cpp:405] Deactivated framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000
3: I1208 02:42:12.757582 18402 master.cpp:10580] Removing offer
da467127-0b92-4fec-981e-aa0357b4fae7-O0
3: I1208 02:42:12.757625 18390 slave.cpp:907] Agent terminating
3: I1208 02:42:12.758066 18402 master.cpp:1310] Agent
41953f09-fcd4-42a5-b268-f18492a3b224-S0 at slave(59)@172.17.0.4:38494
(b69706d34c34) disconnected
3: I1208 02:42:12.758090 18402 master.cpp:3369] Disconnecting agent
41953f09-fcd4-42a5-b268-f18492a3b224-S0 at slave(59)@172.17.0.4:38494
(b69706d34c34)
3: I1208 02:42:12.758144 18402 master.cpp:3388] Deactivating agent
41953f09-fcd4-42a5-b268-f18492a3b224-S0 at slave(59)@172.17.0.4:38494
(b69706d34c34)
3: I1208 02:42:12.758164 18413 hierarchical.cpp:1188] 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 41953f09-fcd4-42a5-b268-f18492a3b224-S0 from framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000
3: I1208 02:42:12.758553 18413 hierarchical.cpp:344] Removed framework
41953f09-fcd4-42a5-b268-f18492a3b224-0000
3: I1208 02:42:12.758648 18413 hierarchical.cpp:762] Agent
41953f09-fcd4-42a5-b268-f18492a3b224-S0 deactivated
3: I1208 02:42:12.763165 18399 master.cpp:1152] Master terminating
3: I1208 02:42:12.763700 18402 hierarchical.cpp:605] Removed agent
41953f09-fcd4-42a5-b268-f18492a3b224-S0
3: [ OK ] FaultToleranceTest.FrameworkReregisterEmptyExecutor (111 ms)
3: [ RUN ] FaultToleranceTest.SplitBrainMasters
3: I1208 02:42:12.770050 18390 cluster.cpp:172] Creating default 'local'
authorizer
3: I1208 02:42:12.772774 18402 master.cpp:456] Master
8f24f2f7-0b18-4d72-94e1-bd3bcd313857 (b69706d34c34) started on 172.17.0.4:38494
3: I1208 02:42:12.772809 18402 master.cpp:458] 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/XaWQqt/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/XaWQqt/master"
--zk_session_timeout="10secs"
3: I1208 02:42:12.773082 18402 master.cpp:507] Master only allowing
authenticated frameworks to register
3: I1208 02:42:12.773088 18402 master.cpp:513] Master only allowing
authenticated agents to register
3: I1208 02:42:12.773092 18402 master.cpp:519] Master only allowing
authenticated HTTP frameworks to register
3: I1208 02:42:12.773097 18402 credentials.hpp:37] Loading credentials for
authentication from '/tmp/XaWQqt/credentials'
3: I1208 02:42:12.773366 18402 master.cpp:563] Using default 'crammd5'
authenticator
3: I1208 02:42:12.773499 18402 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
3: I1208 02:42:12.773638 18402 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
3: I1208 02:42:12.773756 18402 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
3: I1208 02:42:12.773869 18402 master.cpp:642] Authorization enabled
3: I1208 02:42:12.774024 18405 hierarchical.cpp:175] Initialized hierarchical
allocator process
3: I1208 02:42:12.774027 18395 whitelist_watcher.cpp:77] No whitelist given
3: I1208 02:42:12.776762 18401 master.cpp:2214] Elected as the leading master!
3: I1208 02:42:12.776806 18401 master.cpp:1694] Recovering from registrar
3: I1208 02:42:12.776973 18393 registrar.cpp:347] Recovering registrar
3: I1208 02:42:12.777463 18393 registrar.cpp:391] Successfully fetched the
registry (0B) in 453120ns
3: I1208 02:42:12.777565 18393 registrar.cpp:495] Applied 1 operations in
40109ns; attempting to update the registry
3: I1208 02:42:12.778060 18393 registrar.cpp:552] Successfully updated the
registry in 450048ns
3: I1208 02:42:12.778182 18393 registrar.cpp:424] Successfully recovered
registrar
3: I1208 02:42:12.778684 18414 master.cpp:1807] Recovered 0 agents from the
registry (135B); allowing 10mins for agents to re-register
3: I1208 02:42:12.778719 18411 hierarchical.cpp:213] Skipping recovery of
hierarchical allocator: nothing to recover
3: W1208 02:42:12.783314 18390 process.cpp:2756] Attempted to spawn already
running process [email protected]:38494
3: I1208 02:42:12.783627 18390 cluster.cpp:460] Creating default 'local'
authorizer
3: I1208 02:42:12.786115 18400 slave.cpp:258] Mesos agent started on
(60)@172.17.0.4:38494
3: I1208 02:42:12.786151 18400 slave.cpp:259] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/FaultToleranceTest_SplitBrainMasters_PI8LQh/store/appc"
--authenticate_http_executors="true" --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/FaultToleranceTest_SplitBrainMasters_PI8LQh/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/FaultToleranceTest_SplitBrainMasters_PI8LQh/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/FaultToleranceTest_SplitBrainMasters_PI8LQh/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/FaultToleranceTest_SplitBrainMasters_PI8LQh/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem"
--jwt_secret_key="/tmp/FaultToleranceTest_SplitBrainMasters_PI8LQh/jwt_secret_key"
--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" --reconfiguration_policy="equal" --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/FaultToleranceTest_SplitBrainMasters_PI8LQh"
--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/FaultToleranceTest_SplitBrainMasters_vw2NDn"
--zk_session_timeout="10secs"
3: I1208 02:42:12.786569 18400 credentials.hpp:86] Loading credential for
authentication from
'/tmp/FaultToleranceTest_SplitBrainMasters_PI8LQh/credential'
3: W1208 02:42:12.786572 18390 process.cpp:2756] Attempted to spawn already
running process [email protected]:38494
3: I1208 02:42:12.786720 18400 slave.cpp:291] Agent using credential for:
test-principal
3: I1208 02:42:12.786736 18400 credentials.hpp:37] Loading credentials for
authentication from
'/tmp/FaultToleranceTest_SplitBrainMasters_PI8LQh/http_credentials'
3: I1208 02:42:12.786991 18400 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-executor'
3: I1208 02:42:12.787097 18400 http.cpp:1066] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-executor'
3: I1208 02:42:12.787348 18400 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
3: I1208 02:42:12.787441 18400 http.cpp:1066] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readonly'
3: I1208 02:42:12.787668 18400 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readwrite'
3: I1208 02:42:12.787797 18400 http.cpp:1066] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readwrite'
3: I1208 02:42:12.787871 18390 sched.cpp:232] Version: 1.5.0
3: I1208 02:42:12.788501 18401 sched.cpp:336] New master detected at
[email protected]:38494
3: I1208 02:42:12.788602 18401 sched.cpp:396] Authenticating with master
[email protected]:38494
3: I1208 02:42:12.788620 18401 sched.cpp:403] Using default CRAM-MD5
authenticatee
3: I1208 02:42:12.788887 18406 authenticatee.cpp:121] Creating new client SASL
connection
3: I1208 02:42:12.789155 18412 master.cpp:8830] Authenticating
[email protected]:38494
3: I1208 02:42:12.789275 18409 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(131)@172.17.0.4:38494
3: I1208 02:42:12.789561 18397 authenticator.cpp:98] Creating new server SASL
connection
3: I1208 02:42:12.789383 18400 slave.cpp:590] 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: I1208 02:42:12.789595 18400 slave.cpp:598] Agent attributes: [ ]
3: I1208 02:42:12.789608 18400 slave.cpp:607] Agent hostname: b69706d34c34
3: I1208 02:42:12.789836 18393 task_status_update_manager.cpp:181] Pausing
sending task status updates
3: I1208 02:42:12.789858 18407 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I1208 02:42:12.789880 18407 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I1208 02:42:12.789988 18407 authenticator.cpp:204] Received SASL
authentication start
3: I1208 02:42:12.790051 18407 authenticator.cpp:326] Authentication requires
more steps
3: I1208 02:42:12.790156 18392 authenticatee.cpp:259] Received SASL
authentication step
3: I1208 02:42:12.790340 18413 authenticator.cpp:232] Received SASL
authentication step
3: I1208 02:42:12.790383 18413 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'b69706d34c34' server FQDN: 'b69706d34c34'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I1208 02:42:12.790393 18413 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I1208 02:42:12.790428 18413 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I1208 02:42:12.790447 18413 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'b69706d34c34' server FQDN: 'b69706d34c34'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I1208 02:42:12.790457 18413 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1208 02:42:12.790462 18413 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1208 02:42:12.790477 18413 authenticator.cpp:318] Authentication success
3: I1208 02:42:12.790572 18414 authenticatee.cpp:299] Authentication success
3: I1208 02:42:12.790686 18395 master.cpp:8860] Successfully authenticated
principal 'test-principal' at
[email protected]:38494
3: I1208 02:42:12.790721 18404 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(131)@172.17.0.4:38494
3: I1208 02:42:12.790962 18402 sched.cpp:502] Successfully authenticated with
master [email protected]:38494
3: I1208 02:42:12.790982 18402 sched.cpp:824] Sending SUBSCRIBE call to
[email protected]:38494
3: I1208 02:42:12.791092 18402 sched.cpp:857] Will retry registration in
1.995674049secs if necessary
3: I1208 02:42:12.791306 18391 master.cpp:2962] Received SUBSCRIBE call for
framework 'default' at
[email protected]:38494
3: I1208 02:42:12.791329 18391 master.cpp:2279] Authorizing framework principal
'test-principal' to receive offers for roles '{ * }'
3: I1208 02:42:12.791438 18403 state.cpp:66] Recovering state from
'/tmp/FaultToleranceTest_SplitBrainMasters_vw2NDn/meta'
3: I1208 02:42:12.791826 18412 task_status_update_manager.cpp:207] Recovering
task status update manager
3: I1208 02:42:12.791889 18409 master.cpp:3042] Subscribing framework default
with checkpointing disabled and capabilities [ MULTI_ROLE,
RESERVATION_REFINEMENT ]
3: I1208 02:42:12.792050 18409 master.cpp:9051] Adding framework
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000 (default) at
[email protected]:38494 with roles { }
suppressed
3: I1208 02:42:12.792273 18394 slave.cpp:6696] Finished recovery
3: I1208 02:42:12.792569 18411 sched.cpp:751] Framework registered with
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000
3: I1208 02:42:12.792634 18411 sched.cpp:765] Scheduler::registered took 40651ns
3: I1208 02:42:12.792659 18407 hierarchical.cpp:297] Added framework
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000
3: I1208 02:42:12.792871 18407 hierarchical.cpp:1513] Performed allocation for
0 agents in 71278ns
3: I1208 02:42:12.792922 18402 task_status_update_manager.cpp:181] Pausing
sending task status updates
3: I1208 02:42:12.792949 18391 slave.cpp:1031] New master detected at
[email protected]:38494
3: I1208 02:42:12.793035 18391 slave.cpp:1086] Detecting new master
3: I1208 02:42:12.803346 18396 slave.cpp:1113] Authenticating with master
[email protected]:38494
3: I1208 02:42:12.803432 18396 slave.cpp:1122] Using default CRAM-MD5
authenticatee
3: I1208 02:42:12.803700 18401 authenticatee.cpp:121] Creating new client SASL
connection
3: I1208 02:42:12.803957 18412 master.cpp:8830] Authenticating
slave(60)@172.17.0.4:38494
3: I1208 02:42:12.804061 18397 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(132)@172.17.0.4:38494
3: I1208 02:42:12.804275 18393 authenticator.cpp:98] Creating new server SASL
connection
3: I1208 02:42:12.804492 18409 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I1208 02:42:12.804519 18409 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I1208 02:42:12.804607 18409 authenticator.cpp:204] Received SASL
authentication start
3: I1208 02:42:12.804658 18409 authenticator.cpp:326] Authentication requires
more steps
3: I1208 02:42:12.804740 18409 authenticatee.cpp:259] Received SASL
authentication step
3: I1208 02:42:12.804893 18413 authenticator.cpp:232] Received SASL
authentication step
3: I1208 02:42:12.804946 18413 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'b69706d34c34' server FQDN: 'b69706d34c34'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I1208 02:42:12.804955 18413 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I1208 02:42:12.804986 18413 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I1208 02:42:12.805012 18413 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'b69706d34c34' server FQDN: 'b69706d34c34'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I1208 02:42:12.805019 18413 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1208 02:42:12.805024 18413 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1208 02:42:12.805037 18413 authenticator.cpp:318] Authentication success
3: I1208 02:42:12.805162 18411 authenticatee.cpp:299] Authentication success
3: I1208 02:42:12.805243 18392 master.cpp:8860] Successfully authenticated
principal 'test-principal' at slave(60)@172.17.0.4:38494
3: I1208 02:42:12.805308 18410 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(132)@172.17.0.4:38494
3: I1208 02:42:12.805490 18413 slave.cpp:1205] Successfully authenticated with
master [email protected]:38494
3: I1208 02:42:12.805704 18413 slave.cpp:1748] Will retry registration in
10.051492ms if necessary
3: I1208 02:42:12.805953 18400 master.cpp:6084] Received register agent message
from slave(60)@172.17.0.4:38494 (b69706d34c34)
3: I1208 02:42:12.806035 18400 master.cpp:3871] Authorizing agent with
principal 'test-principal'
3: I1208 02:42:12.806423 18407 master.cpp:6160] Authorized registration of
agent at slave(60)@172.17.0.4:38494 (b69706d34c34)
3: I1208 02:42:12.806509 18407 master.cpp:6253] Registering agent at
slave(60)@172.17.0.4:38494 (b69706d34c34) with id
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0
3: I1208 02:42:12.806896 18403 registrar.cpp:495] Applied 1 operations in
90422ns; attempting to update the registry
3: I1208 02:42:12.807461 18403 registrar.cpp:552] Successfully updated the
registry in 510976ns
3: I1208 02:42:12.807723 18396 master.cpp:6302] Admitted agent
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0 at slave(60)@172.17.0.4:38494
(b69706d34c34)
3: I1208 02:42:12.808475 18396 master.cpp:6338] Registered agent
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0 at slave(60)@172.17.0.4:38494
(b69706d34c34) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
3: I1208 02:42:12.808678 18412 slave.cpp:1251] Registered with master
[email protected]:38494; given agent ID 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0
3: I1208 02:42:12.808818 18405 task_status_update_manager.cpp:188] Resuming
sending task status updates
3: I1208 02:42:12.808817 18401 hierarchical.cpp:572] Added agent
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0 (b69706d34c34) with cpus:2; mem:1024;
disk:1024; ports:[31000-32000] (allocated: {})
3: I1208 02:42:12.809054 18412 slave.cpp:1271] Checkpointing SlaveInfo to
'/tmp/FaultToleranceTest_SplitBrainMasters_vw2NDn/meta/slaves/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0/slave.info'
3: I1208 02:42:12.809540 18412 slave.cpp:1350] Forwarding total oversubscribed
resources {}
3: I1208 02:42:12.809768 18414 master.cpp:7245] Received update of agent
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0 at slave(60)@172.17.0.4:38494
(b69706d34c34) with total oversubscribed resources {}
3: I1208 02:42:12.810041 18414 master.cpp:7288] Ignoring update on agent
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0 at slave(60)@172.17.0.4:38494
(b69706d34c34) as it reports no changes
3: I1208 02:42:12.810115 18401 hierarchical.cpp:1513] Performed allocation for
1 agents in 1.135714ms
3: I1208 02:42:12.810880 18414 master.cpp:8660] Sending 1 offers to framework
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000 (default) at
[email protected]:38494
3: I1208 02:42:12.812853 18414 sched.cpp:921] Scheduler::resourceOffers took
1.299506ms
3: I1208 02:42:12.814270 18399 master.cpp:10580] Removing offer
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-O0
3: I1208 02:42:12.814414 18399 master.cpp:4278] Processing ACCEPT call for
offers: [ 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-O0 ] on agent
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0 at slave(60)@172.17.0.4:38494
(b69706d34c34) for framework 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000
(default) at [email protected]:38494
3: I1208 02:42:12.814517 18399 master.cpp:3598] Authorizing framework principal
'test-principal' to launch task 0
3: W1208 02:42:12.816222 18404 validation.cpp:1388] 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: W1208 02:42:12.816256 18404 validation.cpp:1400] 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: I1208 02:42:12.816656 18404 master.cpp:11332] Adding task 0 with resources
cpus(allocated: *):1; mem(allocated: *):512 on agent
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0 at slave(60)@172.17.0.4:38494
(b69706d34c34)
3: I1208 02:42:12.816877 18404 master.cpp:5026] Launching task 0 of framework
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000 (default) at
[email protected]:38494 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 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0 at slave(60)@172.17.0.4:38494
(b69706d34c34)
3: I1208 02:42:12.817440 18413 slave.cpp:1869] Got assigned task '0' for
framework 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000
3: I1208 02:42:12.818056 18413 slave.cpp:2137] Authorizing task '0' for
framework 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000
3: I1208 02:42:12.818114 18413 slave.cpp:7617] Authorizing framework principal
'test-principal' to launch task 0
3: I1208 02:42:12.818143 18400 hierarchical.cpp:1188] 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
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0 from framework
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000
3: I1208 02:42:12.818214 18400 hierarchical.cpp:1234] Framework
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000 filtered agent
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0 for 5secs
3: I1208 02:42:12.818917 18402 slave.cpp:2305] Launching task '0' for framework
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000
3: I1208 02:42:12.819605 18402 paths.cpp:702] Trying to chown
'/tmp/FaultToleranceTest_SplitBrainMasters_vw2NDn/slaves/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0/frameworks/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000/executors/default/runs/bfc4a517-ad88-4f96-a41d-8c81a324493a'
to user 'mesos'
3: I1208 02:42:12.819977 18402 slave.cpp:8091] Launching executor 'default' of
framework 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000 with resources [] in work
directory
'/tmp/FaultToleranceTest_SplitBrainMasters_vw2NDn/slaves/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0/frameworks/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000/executors/default/runs/bfc4a517-ad88-4f96-a41d-8c81a324493a'
3: I1208 02:42:12.820793 18402 slave.cpp:2533] Queued task '0' for executor
'default' of framework 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000
3: I1208 02:42:12.820883 18402 slave.cpp:982] Successfully attached
'/tmp/FaultToleranceTest_SplitBrainMasters_vw2NDn/slaves/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0/frameworks/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000/executors/default/runs/bfc4a517-ad88-4f96-a41d-8c81a324493a'
to virtual path
'/tmp/FaultToleranceTest_SplitBrainMasters_vw2NDn/slaves/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0/frameworks/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000/executors/default/runs/latest'
3: I1208 02:42:12.820921 18402 slave.cpp:982] Successfully attached
'/tmp/FaultToleranceTest_SplitBrainMasters_vw2NDn/slaves/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0/frameworks/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000/executors/default/runs/bfc4a517-ad88-4f96-a41d-8c81a324493a'
to virtual path
'/frameworks/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000/executors/default/runs/latest'
3: I1208 02:42:12.820955 18402 slave.cpp:982] Successfully attached
'/tmp/FaultToleranceTest_SplitBrainMasters_vw2NDn/slaves/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0/frameworks/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000/executors/default/runs/bfc4a517-ad88-4f96-a41d-8c81a324493a'
to virtual path
'/tmp/FaultToleranceTest_SplitBrainMasters_vw2NDn/slaves/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0/frameworks/8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000/executors/default/runs/bfc4a517-ad88-4f96-a41d-8c81a324493a'
3: I1208 02:42:12.821240 18402 slave.cpp:2999] Launching container
bfc4a517-ad88-4f96-a41d-8c81a324493a for executor 'default' of framework
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000
3: W1208 02:42:12.824086 18397 process.cpp:2756] Attempted to spawn already
running process [email protected]:38494
3: I1208 02:42:12.824246 18397 exec.cpp:162] Version: 1.5.0
3: I1208 02:42:12.824558 18393 exec.cpp:212] Executor started at:
executor(11)@172.17.0.4:38494 with pid 18390
3: I1208 02:42:12.824782 18405 slave.cpp:4244] Got registration for executor
'default' of framework 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000 from
executor(11)@172.17.0.4:38494
3: I1208 02:42:12.825197 18409 exec.cpp:237] Executor registered on agent
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0
3: I1208 02:42:12.825239 18409 exec.cpp:249] Executor::registered took 26189ns
3: I1208 02:42:12.825928 18411 slave.cpp:2738] Sending queued task '0' to
executor 'default' of framework 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000 at
executor(11)@172.17.0.4:38494
3: I1208 02:42:12.826288 18411 exec.cpp:331] Executor asked to run task '0'
3: I1208 02:42:12.826366 18411 exec.cpp:340] Executor::launchTask took 67251ns
3: I1208 02:42:12.826457 18411 exec.cpp:571] Executor sending status update
TASK_RUNNING (UUID: 945ac9fe-6375-4534-a4df-13763214c248) for task 0 of
framework 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000
3: I1208 02:42:12.826731 18411 slave.cpp:4701] Handling status update
TASK_RUNNING (UUID: 945ac9fe-6375-4534-a4df-13763214c248) for task 0 of
framework 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000 from
executor(11)@172.17.0.4:38494
3: I1208 02:42:12.827345 18410 task_status_update_manager.cpp:328] Received
task status update TASK_RUNNING (UUID: 945ac9fe-6375-4534-a4df-13763214c248)
for task 0 of framework 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000
3: I1208 02:42:12.827405 18410 task_status_update_manager.cpp:507] Creating
StatusUpdate stream for task 0 of framework
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000
3: I1208 02:42:12.827848 18410 task_status_update_manager.cpp:383] Forwarding
task status update TASK_RUNNING (UUID: 945ac9fe-6375-4534-a4df-13763214c248)
for task 0 of framework 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000 to the agent
3: I1208 02:42:12.828060 18404 slave.cpp:5184] Forwarding the update
TASK_RUNNING (UUID: 945ac9fe-6375-4534-a4df-13763214c248) for task 0 of
framework 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000 to [email protected]:38494
3: I1208 02:42:12.828315 18404 slave.cpp:5077] Task status update manager
successfully handled status update TASK_RUNNING (UUID:
945ac9fe-6375-4534-a4df-13763214c248) for task 0 of framework
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000
3: I1208 02:42:12.828373 18404 slave.cpp:5093] Sending acknowledgement for
status update TASK_RUNNING (UUID: 945ac9fe-6375-4534-a4df-13763214c248) for
task 0 of framework 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000 to
executor(11)@172.17.0.4:38494
3: I1208 02:42:12.828522 18400 master.cpp:7753] Status update TASK_RUNNING
(UUID: 945ac9fe-6375-4534-a4df-13763214c248) for task 0 of framework
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000 from agent
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0 at slave(60)@172.17.0.4:38494
(b69706d34c34)
3: I1208 02:42:12.828553 18413 exec.cpp:388] Executor received status update
acknowledgement 945ac9fe-6375-4534-a4df-13763214c248 for task 0 of framework
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000
3: I1208 02:42:12.828582 18400 master.cpp:7809] Forwarding status update
TASK_RUNNING (UUID: 945ac9fe-6375-4534-a4df-13763214c248) for task 0 of
framework 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000
3: I1208 02:42:12.828766 18400 master.cpp:10056] Updating the state of task 0
of framework 8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000 (latest state:
TASK_RUNNING, status update state: TASK_RUNNING)
3: I1208 02:42:12.829047 18407 sched.cpp:1029] Scheduler::statusUpdate took
99163ns
3: I1208 02:42:12.829401 18391 master.cpp:5841] Processing ACKNOWLEDGE call
945ac9fe-6375-4534-a4df-13763214c248 for task 0 of framework
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-0000 (default) at
[email protected]:38494 on agent
8f24f2f7-0b18-4d72-94e1-bd3bcd313857-S0
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1512699327-1537
Error response from daemon: conflict: unable to remove repository reference
"mesos-1512699327-1537" (must force) - container b69706d34c34 is using its
referenced image 1eeee6221881
Build step 'Execute shell' marked build as failure
