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 [email protected]: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
[email protected]: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
[email protected]: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 [email protected]: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
[email protected]: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
[email protected]: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
[email protected]: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 [email protected]: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
[email protected]: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 [email protected]: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
[email protected]: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
[email protected]: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 [email protected]: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 [email protected]
Not sending mail to unregistered user [email protected]
