See
<https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4473/display/redirect?page=changes>
Changes:
[bmahler] Added a Future constructor for Try<Future<T>>.
------------------------------------------
[...truncated 26.27 MB...]
3: I1120 01:14:38.734169 17518 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I1120 01:14:38.734199 17518 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I1120 01:14:38.734334 17517 authenticator.cpp:204] Received SASL
authentication start
3: I1120 01:14:38.734395 17517 authenticator.cpp:326] Authentication requires
more steps
3: I1120 01:14:38.734515 17523 authenticatee.cpp:259] Received SASL
authentication step
3: I1120 01:14:38.734669 17512 authenticator.cpp:232] Received SASL
authentication step
3: I1120 01:14:38.734714 17512 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '6c3408add39c' server FQDN: '6c3408add39c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I1120 01:14:38.734733 17512 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I1120 01:14:38.734771 17512 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I1120 01:14:38.734800 17512 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '6c3408add39c' server FQDN: '6c3408add39c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I1120 01:14:38.734817 17512 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1120 01:14:38.734828 17512 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1120 01:14:38.734849 17512 authenticator.cpp:318] Authentication success
3: I1120 01:14:38.734941 17519 authenticatee.cpp:299] Authentication success
3: I1120 01:14:38.735072 17511 master.cpp:8315] Successfully authenticated
principal 'test-principal' at slave(688)@172.17.0.2:45437
3: I1120 01:14:38.735162 17519 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1336)@172.17.0.2:45437
3: I1120 01:14:38.735285 17514 slave.cpp:1161] Successfully authenticated with
master master@172.17.0.2:45437
3: I1120 01:14:38.735484 17514 slave.cpp:1682] Will retry registration in
5.026273ms if necessary
3: I1120 01:14:38.735685 17516 master.cpp:6032] Received register agent message
from slave(688)@172.17.0.2:45437 (6c3408add39c)
3: I1120 01:14:38.735807 17516 master.cpp:3870] Authorizing agent with
principal 'test-principal'
3: I1120 01:14:38.736238 17515 master.cpp:6092] Authorized registration of
agent at slave(688)@172.17.0.2:45437 (6c3408add39c)
3: I1120 01:14:38.736351 17515 master.cpp:6185] Registering agent at
slave(688)@172.17.0.2:45437 (6c3408add39c) with id
4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0
3: I1120 01:14:38.736855 17522 registrar.cpp:495] Applied 1 operations in
62541ns; attempting to update the registry
3: I1120 01:14:38.737457 17522 registrar.cpp:552] Successfully updated the
registry in 537856ns
3: I1120 01:14:38.737697 17513 master.cpp:6232] Admitted agent
4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0 at slave(688)@172.17.0.2:45437
(6c3408add39c)
3: I1120 01:14:38.738541 17508 slave.cpp:1207] Registered with master
master@172.17.0.2:45437; given agent ID 4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0
3: I1120 01:14:38.738651 17519 status_update_manager.cpp:184] Resuming sending
status updates
3: I1120 01:14:38.738389 17513 master.cpp:6263] Registered agent
4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0 at slave(688)@172.17.0.2:45437
(6c3408add39c) with
[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1120 01:14:38.738818 17511 hierarchical.cpp:600] Added agent
4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0 (6c3408add39c) with cpus:2; mem:1024;
disk:1024; ports:[31000-32000] (allocated: {})
3: I1120 01:14:38.738898 17508 slave.cpp:1227] Checkpointing SlaveInfo to
'/tmp/ContentType_MasterAPITest_ReserveResources_1_IfoQje/meta/slaves/4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0/slave.info'
3: I1120 01:14:38.739346 17508 slave.cpp:1295] Forwarding total oversubscribed
resources {}
3: I1120 01:14:38.739555 17508 master.cpp:7064] Received update of agent
4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0 at slave(688)@172.17.0.2:45437
(6c3408add39c) with total oversubscribed resources {}
3: I1120 01:14:38.739742 17508 master.cpp:7082] Ignoring update on agent
4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0 at slave(688)@172.17.0.2:45437
(6c3408add39c) as it reports no changes
3: I1120 01:14:38.740419 17511 hierarchical.cpp:1457] Performed allocation for
1 agents in 1.393359ms
3: I1120 01:14:38.740973 17516 master.cpp:8115] Sending 1 offers to framework
4d448e15-f8cf-4e33-98b2-12bef7d28b78-0000 (default) at
scheduler-210762e9-9890-48bf-b101-62c506898e73@172.17.0.2:45437
3: I1120 01:14:38.741552 17521 sched.cpp:921] Scheduler::resourceOffers took
118359ns
3: I1120 01:14:38.744834 17519 process.cpp:3932] Handling HTTP event for
process 'master' with path: '/master/api/v1'
3: I1120 01:14:38.746502 17518 http.cpp:1185] HTTP POST for /master/api/v1 from
172.17.0.2:34785
3: I1120 01:14:38.747292 17518 http.cpp:673] Processing call RESERVE_RESOURCES
3: I1120 01:14:38.747627 17518 master.cpp:3655] Authorizing principal
'test-principal' to reserve resources
'[{"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":512.0},"type":"SCALAR"}]'
3: I1120 01:14:38.749274 17523 master.cpp:10024] Removing offer
4d448e15-f8cf-4e33-98b2-12bef7d28b78-O0
3: I1120 01:14:38.749454 17510 sched.cpp:947] Rescinded offer
4d448e15-f8cf-4e33-98b2-12bef7d28b78-O0
3: I1120 01:14:38.749539 17510 sched.cpp:958] Scheduler::offerRescinded took
30927ns
3: I1120 01:14:38.749868 17512 hierarchical.cpp:1132] Recovered cpus(allocated:
role):2; mem(allocated: role):1024; disk(allocated: role):1024;
ports(allocated: role):[31000-32000] (total: cpus:2; mem:1024; disk:1024;
ports:[31000-32000], allocated: {}) on agent
4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0 from framework
4d448e15-f8cf-4e33-98b2-12bef7d28b78-0000
3: I1120 01:14:38.749943 17512 hierarchical.cpp:1178] Framework
4d448e15-f8cf-4e33-98b2-12bef7d28b78-0000 filtered agent
4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0 for 5secs
3: I1120 01:14:38.753548 17520 master.cpp:9969] Sending updated checkpointed
resources cpus(reservations: [(DYNAMIC,role,test-principal)]):1;
mem(reservations: [(DYNAMIC,role,test-principal)]):512 to agent
4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0 at slave(688)@172.17.0.2:45437
(6c3408add39c)
3: I1120 01:14:38.754621 17520 slave.cpp:3587] Updated checkpointed resources
from {} to cpus(reservations: [(DYNAMIC,role,test-principal)]):1;
mem(reservations: [(DYNAMIC,role,test-principal)]):512
3: I1120 01:14:38.754686 17518 master.cpp:5537] Processing REVIVE call for
framework 4d448e15-f8cf-4e33-98b2-12bef7d28b78-0000 (default) at
scheduler-210762e9-9890-48bf-b101-62c506898e73@172.17.0.2:45437
3: I1120 01:14:38.754870 17523 hierarchical.cpp:1279] Revived offers for roles
{ role } of framework 4d448e15-f8cf-4e33-98b2-12bef7d28b78-0000
3: I1120 01:14:38.756960 17523 hierarchical.cpp:1457] Performed allocation for
1 agents in 1.943462ms
3: I1120 01:14:38.757791 17512 master.cpp:8115] Sending 1 offers to framework
4d448e15-f8cf-4e33-98b2-12bef7d28b78-0000 (default) at
scheduler-210762e9-9890-48bf-b101-62c506898e73@172.17.0.2:45437
3: I1120 01:14:38.758448 17512 sched.cpp:921] Scheduler::resourceOffers took
140635ns
3: I1120 01:14:38.759022 17507 sched.cpp:2009] Asked to stop the driver
3: I1120 01:14:38.759184 17516 sched.cpp:1191] Stopping framework
4d448e15-f8cf-4e33-98b2-12bef7d28b78-0000
3: I1120 01:14:38.759482 17508 master.cpp:8792] Processing TEARDOWN call for
framework 4d448e15-f8cf-4e33-98b2-12bef7d28b78-0000 (default) at
scheduler-210762e9-9890-48bf-b101-62c506898e73@172.17.0.2:45437
3: I1120 01:14:38.759518 17508 master.cpp:8804] Removing framework
4d448e15-f8cf-4e33-98b2-12bef7d28b78-0000 (default) at
scheduler-210762e9-9890-48bf-b101-62c506898e73@172.17.0.2:45437
3: I1120 01:14:38.759533 17508 master.cpp:3331] Deactivating framework
4d448e15-f8cf-4e33-98b2-12bef7d28b78-0000 (default) at
scheduler-210762e9-9890-48bf-b101-62c506898e73@172.17.0.2:45437
3: I1120 01:14:38.759676 17521 hierarchical.cpp:419] Deactivated framework
4d448e15-f8cf-4e33-98b2-12bef7d28b78-0000
3: I1120 01:14:38.760525 17521 slave.cpp:883] Agent terminating
3: I1120 01:14:38.760818 17508 master.cpp:10024] Removing offer
4d448e15-f8cf-4e33-98b2-12bef7d28b78-O1
3: I1120 01:14:38.761391 17508 master.cpp:1309] Agent
4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0 at slave(688)@172.17.0.2:45437
(6c3408add39c) disconnected
3: I1120 01:14:38.761423 17508 master.cpp:3368] Disconnecting agent
4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0 at slave(688)@172.17.0.2:45437
(6c3408add39c)
3: I1120 01:14:38.761493 17508 master.cpp:3387] Deactivating agent
4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0 at slave(688)@172.17.0.2:45437
(6c3408add39c)
3: I1120 01:14:38.761914 17510 hierarchical.cpp:1132] Recovered cpus(allocated:
role):1; mem(allocated: role):512; disk(allocated: role):1024; ports(allocated:
role):[31000-32000]; cpus(allocated: role)(reservations:
[(DYNAMIC,role,test-principal)]):1; mem(allocated: role)(reservations:
[(DYNAMIC,role,test-principal)]):512 (total: cpus:1; mem:512; disk:1024;
ports:[31000-32000]; cpus(reservations: [(DYNAMIC,role,test-principal)]):1;
mem(reservations: [(DYNAMIC,role,test-principal)]):512, allocated: {}) on agent
4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0 from framework
4d448e15-f8cf-4e33-98b2-12bef7d28b78-0000
3: I1120 01:14:38.762382 17510 hierarchical.cpp:358] Removed framework
4d448e15-f8cf-4e33-98b2-12bef7d28b78-0000
3: I1120 01:14:38.762476 17510 hierarchical.cpp:697] Agent
4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0 deactivated
3: I1120 01:14:38.768106 17507 master.cpp:1151] Master terminating
3: I1120 01:14:38.769188 17508 hierarchical.cpp:633] Removed agent
4d448e15-f8cf-4e33-98b2-12bef7d28b78-S0
3: [ OK ] ContentType/MasterAPITest.ReserveResources/1 (81 ms)
3: [ RUN ] ContentType/MasterAPITest.UnreserveResources/0
3: I1120 01:14:38.775504 17507 cluster.cpp:162] Creating default 'local'
authorizer
3: I1120 01:14:38.777947 17513 master.cpp:448] Master
67fc8282-ffa5-4180-9795-334b974e8fea (6c3408add39c) started on 172.17.0.2:45437
3: I1120 01:14:38.777966 17513 master.cpp:450] Flags at startup: --acls=""
--agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
--allocation_interval="1000secs" --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/pXsy5M/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/pXsy5M/master"
--zk_session_timeout="10secs"
3: I1120 01:14:38.778199 17513 master.cpp:499] Master only allowing
authenticated frameworks to register
3: I1120 01:14:38.778206 17513 master.cpp:505] Master only allowing
authenticated agents to register
3: I1120 01:14:38.778210 17513 master.cpp:511] Master only allowing
authenticated HTTP frameworks to register
3: I1120 01:14:38.778214 17513 credentials.hpp:37] Loading credentials for
authentication from '/tmp/pXsy5M/credentials'
3: I1120 01:14:38.778440 17513 master.cpp:555] Using default 'crammd5'
authenticator
3: I1120 01:14:38.778565 17513 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
3: I1120 01:14:38.778693 17513 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
3: I1120 01:14:38.778808 17513 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
3: I1120 01:14:38.778916 17513 master.cpp:634] Authorization enabled
3: I1120 01:14:38.779124 17511 whitelist_watcher.cpp:77] No whitelist given
3: I1120 01:14:38.779153 17509 hierarchical.cpp:173] Initialized hierarchical
allocator process
3: I1120 01:14:38.782359 17521 master.cpp:2213] Elected as the leading master!
3: I1120 01:14:38.782390 17521 master.cpp:1693] Recovering from registrar
3: I1120 01:14:38.782635 17520 registrar.cpp:347] Recovering registrar
3: I1120 01:14:38.783246 17520 registrar.cpp:391] Successfully fetched the
registry (0B) in 564992ns
3: I1120 01:14:38.783349 17520 registrar.cpp:495] Applied 1 operations in
29496ns; attempting to update the registry
3: I1120 01:14:38.783983 17523 registrar.cpp:552] Successfully updated the
registry in 569088ns
3: I1120 01:14:38.784121 17523 registrar.cpp:424] Successfully recovered
registrar
3: I1120 01:14:38.784560 17509 master.cpp:1806] Recovered 0 agents from the
registry (129B); allowing 10mins for agents to re-register
3: I1120 01:14:38.784631 17521 hierarchical.cpp:211] Skipping recovery of
hierarchical allocator: nothing to recover
3: W1120 01:14:38.788868 17507 process.cpp:3185] Attempted to spawn already
running process files@172.17.0.2:45437
3: I1120 01:14:38.789934 17507 containerizer.cpp:301] Using isolation {
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1120 01:14:38.790544 17507 backend.cpp:76] Failed to create 'aufs' backend:
AufsBackend requires root privileges
3: W1120 01:14:38.790670 17507 backend.cpp:76] Failed to create 'bind' backend:
BindBackend requires root privileges
3: I1120 01:14:38.790705 17507 provisioner.cpp:255] Using default backend 'copy'
3: I1120 01:14:38.792853 17507 cluster.cpp:448] Creating default 'local'
authorizer
3: I1120 01:14:38.795382 17511 slave.cpp:262] Mesos agent started on
(689)@172.17.0.2:45437
3: I1120 01:14:38.795405 17511 slave.cpp:263] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/ContentType_MasterAPITest_UnreserveResources_0_pS2xrC/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/ContentType_MasterAPITest_UnreserveResources_0_pS2xrC/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/ContentType_MasterAPITest_UnreserveResources_0_pS2xrC/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_secret_key="/tmp/ContentType_MasterAPITest_UnreserveResources_0_pS2xrC/executor_secret_key"
--executor_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/ContentType_MasterAPITest_UnreserveResources_0_pS2xrC/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/ContentType_MasterAPITest_UnreserveResources_0_pS2xrC/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/ContentType_MasterAPITest_UnreserveResources_0_pS2xrC"
--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/ContentType_MasterAPITest_UnreserveResources_0_Y1JxLH"
--zk_session_timeout="10secs"
3: I1120 01:14:38.795938 17511 credentials.hpp:86] Loading credential for
authentication from
'/tmp/ContentType_MasterAPITest_UnreserveResources_0_pS2xrC/credential'
3: I1120 01:14:38.796108 17511 slave.cpp:295] Agent using credential for:
test-principal
3: I1120 01:14:38.796128 17511 credentials.hpp:37] Loading credentials for
authentication from
'/tmp/ContentType_MasterAPITest_UnreserveResources_0_pS2xrC/http_credentials'
3: I1120 01:14:38.796535 17511 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-executor'
3: I1120 01:14:38.796679 17511 http.cpp:1066] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-executor'
3: I1120 01:14:38.796955 17511 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
3: I1120 01:14:38.797085 17511 http.cpp:1066] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readonly'
3: I1120 01:14:38.797351 17511 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readwrite'
3: I1120 01:14:38.797477 17511 http.cpp:1066] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readwrite'
3: I1120 01:14:38.799273 17511 slave.cpp:593] Agent resources:
[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1120 01:14:38.799571 17511 slave.cpp:601] Agent attributes: [ ]
3: I1120 01:14:38.799582 17511 slave.cpp:610] Agent hostname: 6c3408add39c
3: I1120 01:14:38.799716 17523 status_update_manager.cpp:177] Pausing sending
status updates
3: I1120 01:14:38.801371 17509 state.cpp:64] Recovering state from
'/tmp/ContentType_MasterAPITest_UnreserveResources_0_Y1JxLH/meta'
3: I1120 01:14:38.801769 17512 status_update_manager.cpp:203] Recovering status
update manager
3: I1120 01:14:38.801981 17512 containerizer.cpp:662] Recovering containerizer
3: I1120 01:14:38.803582 17514 provisioner.cpp:416] Provisioner recovery
complete
3: I1120 01:14:38.804004 17514 slave.cpp:6441] Finished recovery
3: I1120 01:14:38.804764 17508 status_update_manager.cpp:177] Pausing sending
status updates
3: I1120 01:14:38.804783 17517 slave.cpp:1007] New master detected at
master@172.17.0.2:45437
3: I1120 01:14:38.804854 17517 slave.cpp:1042] Detecting new master
3: I1120 01:14:38.805984 17523 slave.cpp:1069] Authenticating with master
master@172.17.0.2:45437
3: I1120 01:14:38.806063 17523 slave.cpp:1078] Using default CRAM-MD5
authenticatee
3: I1120 01:14:38.806365 17512 authenticatee.cpp:121] Creating new client SASL
connection
3: I1120 01:14:38.806676 17512 master.cpp:8285] Authenticating
slave(689)@172.17.0.2:45437
3: I1120 01:14:38.806825 17522 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1337)@172.17.0.2:45437
3: I1120 01:14:38.807149 17513 authenticator.cpp:98] Creating new server SASL
connection
3: I1120 01:14:38.807411 17511 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I1120 01:14:38.807440 17511 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I1120 01:14:38.807552 17511 authenticator.cpp:204] Received SASL
authentication start
3: I1120 01:14:38.807610 17511 authenticator.cpp:326] Authentication requires
more steps
3: I1120 01:14:38.807772 17509 authenticatee.cpp:259] Received SASL
authentication step
3: I1120 01:14:38.807976 17509 authenticator.cpp:232] Received SASL
authentication step
3: I1120 01:14:38.808027 17509 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '6c3408add39c' server FQDN: '6c3408add39c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I1120 01:14:38.808043 17509 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I1120 01:14:38.808076 17509 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I1120 01:14:38.808095 17509 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '6c3408add39c' server FQDN: '6c3408add39c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I1120 01:14:38.808105 17509 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1120 01:14:38.808111 17509 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1120 01:14:38.808126 17509 authenticator.cpp:318] Authentication success
3: I1120 01:14:38.808224 17514 authenticatee.cpp:299] Authentication success
3: I1120 01:14:38.808323 17515 master.cpp:8315] Successfully authenticated
principal 'test-principal' at slave(689)@172.17.0.2:45437
3: I1120 01:14:38.808356 17509 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1337)@172.17.0.2:45437
3: I1120 01:14:38.808750 17514 slave.cpp:1161] Successfully authenticated with
master master@172.17.0.2:45437
3: I1120 01:14:38.808995 17514 slave.cpp:1682] Will retry registration in
4.519116ms if necessary
3: I1120 01:14:38.809265 17523 master.cpp:6032] Received register agent message
from slave(689)@172.17.0.2:45437 (6c3408add39c)
3: I1120 01:14:38.809389 17523 master.cpp:3870] Authorizing agent with
principal 'test-principal'
3: I1120 01:14:38.809844 17516 master.cpp:6092] Authorized registration of
agent at slave(689)@172.17.0.2:45437 (6c3408add39c)
3: I1120 01:14:38.809973 17516 master.cpp:6185] Registering agent at
slave(689)@172.17.0.2:45437 (6c3408add39c) with id
67fc8282-ffa5-4180-9795-334b974e8fea-S0
3: I1120 01:14:38.810431 17522 registrar.cpp:495] Applied 1 operations in
58559ns; attempting to update the registry
3: I1120 01:14:38.811103 17518 registrar.cpp:552] Successfully updated the
registry in 600832ns
3: I1120 01:14:38.811384 17510 master.cpp:6232] Admitted agent
67fc8282-ffa5-4180-9795-334b974e8fea-S0 at slave(689)@172.17.0.2:45437
(6c3408add39c)
3: I1120 01:14:38.812263 17519 slave.cpp:1207] Registered with master
master@172.17.0.2:45437; given agent ID 67fc8282-ffa5-4180-9795-334b974e8fea-S0
3: I1120 01:14:38.812423 17512 status_update_manager.cpp:184] Resuming sending
status updates
3: I1120 01:14:38.812163 17510 master.cpp:6263] Registered agent
67fc8282-ffa5-4180-9795-334b974e8fea-S0 at slave(689)@172.17.0.2:45437
(6c3408add39c) with
[{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1120 01:14:38.812561 17519 slave.cpp:1227] Checkpointing SlaveInfo to
'/tmp/ContentType_MasterAPITest_UnreserveResources_0_Y1JxLH/meta/slaves/67fc8282-ffa5-4180-9795-334b974e8fea-S0/slave.info'
3: I1120 01:14:38.812659 17517 hierarchical.cpp:600] Added agent
67fc8282-ffa5-4180-9795-334b974e8fea-S0 (6c3408add39c) with cpus:2; mem:1024;
disk:1024; ports:[31000-32000] (allocated: {})
3: I1120 01:14:38.812911 17519 slave.cpp:1295] Forwarding total oversubscribed
resources {}
3: I1120 01:14:38.812916 17517 hierarchical.cpp:1457] Performed allocation for
1 agents in 120054ns
3: I1120 01:14:38.813078 17519 master.cpp:7064] Received update of agent
67fc8282-ffa5-4180-9795-334b974e8fea-S0 at slave(689)@172.17.0.2:45437
(6c3408add39c) with total oversubscribed resources {}
3: I1120 01:14:38.813215 17519 master.cpp:7082] Ignoring update on agent
67fc8282-ffa5-4180-9795-334b974e8fea-S0 at slave(689)@172.17.0.2:45437
(6c3408add39c) as it reports no changes
3: I1120 01:14:38.814867 17518 process.cpp:3932] Handling HTTP event for
process 'master' with path: '/master/api/v1'
3: I1120 01:14:38.816550 17517 http.cpp:1185] HTTP POST for /master/api/v1 from
172.17.0.2:34786
3: I1120 01:14:38.816774 17517 http.cpp:673] Processing call RESERVE_RESOURCES
3: I1120 01:14:38.817134 17517 master.cpp:3655] Authorizing principal
'test-principal' to reserve resources
'[{"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":512.0},"type":"SCALAR"}]'
3: I1120 01:14:38.821315 17513 master.cpp:9969] Sending updated checkpointed
resources cpus(reservations: [(DYNAMIC,role,test-principal)]):1;
mem(reservations: [(DYNAMIC,role,test-principal)]):512 to agent
67fc8282-ffa5-4180-9795-334b974e8fea-S0 at slave(689)@172.17.0.2:45437
(6c3408add39c)
3: I1120 01:14:38.822337 17513 slave.cpp:3587] Updated checkpointed resources
from {} to cpus(reservations: [(DYNAMIC,role,test-principal)]):1;
mem(reservations: [(DYNAMIC,role,test-principal)]):512
3: W1120 01:14:38.822381 17507 process.cpp:3185] Attempted to spawn already
running process version@172.17.0.2:45437
3: I1120 01:14:38.823140 17507 sched.cpp:232] Version: 1.5.0
3: I1120 01:14:38.823773 17508 sched.cpp:336] New master detected at
master@172.17.0.2:45437
3: I1120 01:14:38.823880 17508 sched.cpp:396] Authenticating with master
master@172.17.0.2:45437
3: I1120 01:14:38.823920 17508 sched.cpp:403] Using default CRAM-MD5
authenticatee
3: I1120 01:14:38.824178 17511 authenticatee.cpp:121] Creating new client SASL
connection
3: I1120 01:14:38.824501 17511 master.cpp:8285] Authenticating
scheduler-6487611d-8844-44fc-bae7-d38006226e70@172.17.0.2:45437
3: I1120 01:14:38.824637 17523 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1338)@172.17.0.2:45437
3: I1120 01:14:38.824951 17520 authenticator.cpp:98] Creating new server SASL
connection
3: I1120 01:14:38.825206 17520 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I1120 01:14:38.825232 17520 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I1120 01:14:38.825350 17509 authenticator.cpp:204] Received SASL
authentication start
3: I1120 01:14:38.825410 17509 authenticator.cpp:326] Authentication requires
more steps
3: I1120 01:14:38.825546 17513 authenticatee.cpp:259] Received SASL
authentication step
3: I1120 01:14:38.825686 17512 authenticator.cpp:232] Received SASL
authentication step
3: I1120 01:14:38.825716 17512 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '6c3408add39c' server FQDN: '6c3408add39c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I1120 01:14:38.825727 17512 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I1120 01:14:38.825757 17512 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I1120 01:14:38.825774 17512 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '6c3408add39c' server FQDN: '6c3408add39c'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I1120 01:14:38.825789 17512 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1120 01:14:38.825796 17512 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1120 01:14:38.825810 17512 authenticator.cpp:318] Authentication success
3: I1120 01:14:38.825911 17515 authenticatee.cpp:299] Authentication success
3: I1120 01:14:38.825956 17516 master.cpp:8315] Successfully authenticated
principal 'test-principal' at
scheduler-6487611d-8844-44fc-bae7-d38006226e70@172.17.0.2:45437
3: I1120 01:14:38.826004 17512 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1338)@172.17.0.2:45437
3: I1120 01:14:38.826258 17521 sched.cpp:502] Successfully authenticated with
master master@172.17.0.2:45437
3: I1120 01:14:38.826283 17521 sched.cpp:824] Sending SUBSCRIBE call to
master@172.17.0.2:45437
3: I1120 01:14:38.826411 17521 sched.cpp:857] Will retry registration in
1.044062431secs if necessary
3: I1120 01:14:38.826620 17508 master.cpp:2961] Received SUBSCRIBE call for
framework 'default' at
scheduler-6487611d-8844-44fc-bae7-d38006226e70@172.17.0.2:45437
3: I1120 01:14:38.826709 17508 master.cpp:2278] Authorizing framework principal
'test-principal' to receive offers for roles '{ role }'
3: I1120 01:14:38.827239 17511 master.cpp:3041] Subscribing framework default
with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1120 01:14:38.827903 17520 sched.cpp:751] Framework registered with
67fc8282-ffa5-4180-9795-334b974e8fea-0000
3: I1120 01:14:38.827950 17520 sched.cpp:765] Scheduler::registered took 21192ns
3: I1120 01:14:38.828055 17523 hierarchical.cpp:306] Added framework
67fc8282-ffa5-4180-9795-334b974e8fea-0000
3: I1120 01:14:38.830143 17523 hierarchical.cpp:1457] Performed allocation for
1 agents in 1.931921ms
3: I1120 01:14:38.831073 17513 master.cpp:8115] Sending 1 offers to framework
67fc8282-ffa5-4180-9795-334b974e8fea-0000 (default) at
scheduler-6487611d-8844-44fc-bae7-d38006226e70@172.17.0.2:45437
3: I1120 01:14:38.831794 17519 sched.cpp:921] Scheduler::resourceOffers took
140141ns
3: I1120 01:14:38.834790 17514 process.cpp:3932] Handling HTTP event for
process 'master' with path: '/master/api/v1'
3: I1120 01:14:38.836408 17519 http.cpp:1185] HTTP POST for /master/api/v1 from
172.17.0.2:34787
3: I1120 01:14:38.836694 17519 http.cpp:673] Processing call UNRESERVE_RESOURCES
3: I1120 01:14:38.837083 17519 master.cpp:3723] Authorizing principal
'test-principal' to unreserve resources
'[{"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":512.0},"type":"SCALAR"}]'
3: I1120 01:14:38.839236 17522 master.cpp:10024] Removing offer
67fc8282-ffa5-4180-9795-334b974e8fea-O0
3: I1120 01:14:38.839396 17512 sched.cpp:947] Rescinded offer
67fc8282-ffa5-4180-9795-334b974e8fea-O0
3: I1120 01:14:38.839468 17512 sched.cpp:958] Scheduler::offerRescinded took
23054ns
3: I1120 01:14:38.840306 17518 hierarchical.cpp:1132] Recovered cpus(allocated:
role):1; mem(allocated: role):512; disk(allocated: role):1024; ports(allocated:
role):[31000-32000]; cpus(allocated: role)(reservations:
[(DYNAMIC,role,test-principal)]):1; mem(allocated: role)(reservations:
[(DYNAMIC,role,test-principal)]):512 (total: cpus:1; mem:512; disk:1024;
ports:[31000-32000]; cpus(reservations: [(DYNAMIC,role,test-principal)]):1;
mem(reservations: [(DYNAMIC,role,test-principal)]):512, allocated: {}) on agent
67fc8282-ffa5-4180-9795-334b974e8fea-S0 from framework
67fc8282-ffa5-4180-9795-334b974e8fea-0000
3: I1120 01:14:38.840414 17518 hierarchical.cpp:1178] Framework
67fc8282-ffa5-4180-9795-334b974e8fea-0000 filtered agent
67fc8282-ffa5-4180-9795-334b974e8fea-S0 for 5secs
3: I1120 01:14:38.843775 17521 master.cpp:9969] Sending updated checkpointed
resources {} to agent 67fc8282-ffa5-4180-9795-334b974e8fea-S0 at
slave(689)@172.17.0.2:45437 (6c3408add39c)
3: I1120 01:14:38.844386 17521 slave.cpp:3587] Updated checkpointed resources
from cpus(reservations: [(DYNAMIC,role,test-principal)]):1; mem(reservations:
[(DYNAMIC,role,test-principal)]):512 to {}
3: I1120 01:14:38.844939 17519 master.cpp:5537] Processing REVIVE call for
framework 67fc8282-ffa5-4180-9795-334b974e8fea-0000 (default) at
scheduler-6487611d-8844-44fc-bae7-d38006226e70@172.17.0.2:45437
3: I1120 01:14:38.845130 17519 hierarchical.cpp:1279] Revived offers for roles
{ role } of framework 67fc8282-ffa5-4180-9795-334b974e8fea-0000
3: I1120 01:14:38.846447 17519 hierarchical.cpp:1457] Performed allocation for
1 agents in 1.174587ms
3: I1120 01:14:38.847090 17518 master.cpp:8115] Sending 1 offers to framework
67fc8282-ffa5-4180-9795-334b974e8fea-0000 (default) at
scheduler-6487611d-8844-44fc-bae7-d38006226e70@172.17.0.2:45437
3: I1120 01:14:38.847626 17518 sched.cpp:921] Scheduler::resourceOffers took
108767ns
3: I1120 01:14:38.848134 17507 sched.cpp:2009] Asked to stop the driver
3: I1120 01:14:38.848278 17513 sched.cpp:1191] Stopping framework
67fc8282-ffa5-4180-9795-334b974e8fea-0000
3: I1120 01:14:38.848567 17521 master.cpp:8792] Processing TEARDOWN call for
framework 67fc8282-ffa5-4180-9795-334b974e8fea-0000 (default) at
scheduler-6487611d-8844-44fc-bae7-d38006226e70@172.17.0.2:45437
3: I1120 01:14:38.848605 17521 master.cpp:8804] Removing framework
67fc8282-ffa5-4180-9795-334b974e8fea-0000 (default) at
scheduler-6487611d-8844-44fc-bae7-d38006226e70@172.17.0.2:45437
3: I1120 01:14:38.848629 17521 master.cpp:3331] Deactivating framework
67fc8282-ffa5-4180-9795-334b974e8fea-0000 (default) at
scheduler-6487611d-8844-44fc-bae7-d38006226e70@172.17.0.2:45437
3: I1120 01:14:38.848896 17517 hierarchical.cpp:419] Deactivated framework
67fc8282-ffa5-4180-9795-334b974e8fea-0000
3: I1120 01:14:38.849371 17521 master.cpp:10024] Removing offer
67fc8282-ffa5-4180-9795-334b974e8fea-O1
3: I1120 01:14:38.849617 17508 slave.cpp:3267] Asked to shut down framework
67fc8282-ffa5-4180-9795-334b974e8fea-0000 by master@172.17.0.2:45437
3: I1120 01:14:38.849658 17508 slave.cpp:3282] Cannot shut down unknown
framework 67fc8282-ffa5-4180-9795-334b974e8fea-0000
3: I1120 01:14:38.849982 17517 hierarchical.cpp:1132] Recovered cpus(allocated:
role):2; mem(allocated: role):1024; disk(allocated: role):1024;
ports(allocated: role):[31000-32000] (total: cpus:2; mem:1024; disk:1024;
ports:[31000-32000], allocated: {}) on agent
67fc8282-ffa5-4180-9795-334b974e8fea-S0 from framework
67fc8282-ffa5-4180-9795-334b974e8fea-0000
3: I1120 01:14:38.850340 17517 hierarchical.cpp:358] Removed framework
67fc8282-ffa5-4180-9795-334b974e8fea-0000
3: I1120 01:14:38.850481 17521 slave.cpp:883] Agent terminating
3: I1120 01:14:38.850711 17521 master.cpp:1309] Agent
67fc8282-ffa5-4180-9795-334b974e8fea-S0 at slave(689)@172.17.0.2:45437
(6c3408add39c) disconnected
3: I1120 01:14:38.850736 17521 master.cpp:3368] Disconnecting agent
67fc8282-ffa5-4180-9795-334b974e8fea-S0 at slave(689)@172.17.0.2:45437
(6c3408add39c)
3: I1120 01:14:38.850788 17521 master.cpp:3387] Deactivating agent
67fc8282-ffa5-4180-9795-334b974e8fea-S0 at slave(689)@172.17.0.2:45437
(6c3408add39c)
3: I1120 01:14:38.851004 17509 hierarchical.cpp:697] Agent
67fc8282-ffa5-4180-9795-334b974e8fea-S0 deactivated
3: I1120 01:14:38.857700 17507 master.cpp:1151] Master terminating
3: I1120 01:14:38.858497 17523 hierarchical.cpp:633] Removed agent
67fc8282-ffa5-4180-9795-334b974e8fea-S0
3: [ OK ] ContentType/MasterAPITest.UnreserveResources/0 (89 ms)
3: [ RUN ] ContentType/MasterAPITest.UnreserveResources/1
3: I1120 01:14:38.866351 17507 cluster.cpp:162] Creating default 'local'
authorizer
3: I1120 01:14:38.869380 17510 master.cpp:448] Master
d5dc85ef-7eb8-44ec-9473-f62d2b34204b (6c3408add39c) started on 172.17.0.2:45437
3: I1120 01:14:38.869405 17510 master.cpp:450] Flags at startup: --acls=""
--agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
--allocation_interval="1000secs" --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/ZEL4nc/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/ZEL4nc/master"
--zk_session_timeout="10secs"
3: I1120 01:14:38.869796 17510 master.cpp:499] Master only allowing
authenticated frameworks to register
3: I1120 01:14:38.869807 17510 master.cpp:505] Master only allowing
authenticated agents to register
3: I1120 01:14:38.869813 17510 master.cpp:511] Master only allowing
authenticated HTTP frameworks to register
3: I1120 01:14:38.869820 17510 credentials.hpp:37] Loading credentials for
authentication from '/tmp/ZEL4nc/credentials'
Build step 'Execute shell' marked build as failure
