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)/4504/display/redirect>
------------------------------------------
[...truncated 18.00 MB...]
3: I1128 01:25:02.690534 18297 hierarchical.cpp:1132] 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 ecce28b9-9468-4b96-805a-33838f5db6f1-S0 from framework
ecce28b9-9468-4b96-805a-33838f5db6f1-0000
3: I1128 01:25:02.690634 18297 hierarchical.cpp:1178] Framework
ecce28b9-9468-4b96-805a-33838f5db6f1-0000 filtered agent
ecce28b9-9468-4b96-805a-33838f5db6f1-S0 for 5secs
3: I1128 01:25:02.690958 18297 hierarchical.cpp:419] Deactivated framework
ecce28b9-9468-4b96-805a-33838f5db6f1-0000
3: I1128 01:25:02.691314 18297 hierarchical.cpp:358] Removed framework
ecce28b9-9468-4b96-805a-33838f5db6f1-0000
3: I1128 01:25:02.692312 18308 slave.cpp:883] Agent terminating
3: I1128 01:25:02.692591 18298 master.cpp:1311] Agent
ecce28b9-9468-4b96-805a-33838f5db6f1-S0 at slave(440)@172.17.0.4:35865
(aba42f2867a8) disconnected
3: I1128 01:25:02.692625 18298 master.cpp:3370] Disconnecting agent
ecce28b9-9468-4b96-805a-33838f5db6f1-S0 at slave(440)@172.17.0.4:35865
(aba42f2867a8)
3: I1128 01:25:02.692689 18298 master.cpp:3389] Deactivating agent
ecce28b9-9468-4b96-805a-33838f5db6f1-S0 at slave(440)@172.17.0.4:35865
(aba42f2867a8)
3: I1128 01:25:02.692837 18299 hierarchical.cpp:697] Agent
ecce28b9-9468-4b96-805a-33838f5db6f1-S0 deactivated
3: I1128 01:25:02.701156 18295 master.cpp:1153] Master terminating
3: I1128 01:25:02.701942 18308 hierarchical.cpp:633] Removed agent
ecce28b9-9468-4b96-805a-33838f5db6f1-S0
3: [ OK ] TaskGroupValidationTest.TaskUsesNetworkInfo (71 ms)
3: [ RUN ] TaskGroupValidationTest.TaskUsesDifferentExecutor
3: I1128 01:25:02.709612 18295 cluster.cpp:162] Creating default 'local'
authorizer
3: I1128 01:25:02.713783 18299 master.cpp:448] Master
6c280ee5-6a83-4360-9b40-925d5c59111f (aba42f2867a8) started on 172.17.0.4:35865
3: I1128 01:25:02.713812 18299 master.cpp:450] 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/l3J3FY/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/l3J3FY/master"
--zk_session_timeout="10secs"
3: I1128 01:25:02.714220 18299 master.cpp:499] Master only allowing
authenticated frameworks to register
3: I1128 01:25:02.714231 18299 master.cpp:505] Master only allowing
authenticated agents to register
3: I1128 01:25:02.714236 18299 master.cpp:511] Master only allowing
authenticated HTTP frameworks to register
3: I1128 01:25:02.714243 18299 credentials.hpp:37] Loading credentials for
authentication from '/tmp/l3J3FY/credentials'
3: I1128 01:25:02.714625 18299 master.cpp:555] Using default 'crammd5'
authenticator
3: I1128 01:25:02.714824 18299 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
3: I1128 01:25:02.715045 18299 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
3: I1128 01:25:02.715250 18299 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
3: I1128 01:25:02.715415 18299 master.cpp:634] Authorization enabled
3: I1128 01:25:02.715589 18308 hierarchical.cpp:173] Initialized hierarchical
allocator process
3: I1128 01:25:02.715667 18317 whitelist_watcher.cpp:77] No whitelist given
3: I1128 01:25:02.718986 18307 master.cpp:2215] Elected as the leading master!
3: I1128 01:25:02.719017 18307 master.cpp:1695] Recovering from registrar
3: I1128 01:25:02.719163 18303 registrar.cpp:347] Recovering registrar
3: I1128 01:25:02.719794 18303 registrar.cpp:391] Successfully fetched the
registry (0B) in 591104ns
3: I1128 01:25:02.719899 18303 registrar.cpp:495] Applied 1 operations in
28789ns; attempting to update the registry
3: I1128 01:25:02.720471 18303 registrar.cpp:552] Successfully updated the
registry in 516096ns
3: I1128 01:25:02.720603 18303 registrar.cpp:424] Successfully recovered
registrar
3: I1128 01:25:02.721076 18312 master.cpp:1808] Recovered 0 agents from the
registry (129B); allowing 10mins for agents to re-register
3: I1128 01:25:02.721114 18316 hierarchical.cpp:211] Skipping recovery of
hierarchical allocator: nothing to recover
3: W1128 01:25:02.727591 18295 process.cpp:2756] Attempted to spawn already
running process [email protected]:35865
3: I1128 01:25:02.728720 18295 containerizer.cpp:301] Using isolation {
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1128 01:25:02.729449 18295 backend.cpp:76] Failed to create 'aufs' backend:
AufsBackend requires root privileges
3: W1128 01:25:02.729605 18295 backend.cpp:76] Failed to create 'bind' backend:
BindBackend requires root privileges
3: I1128 01:25:02.729648 18295 provisioner.cpp:259] Using default backend 'copy'
3: I1128 01:25:02.732195 18295 cluster.cpp:448] Creating default 'local'
authorizer
3: I1128 01:25:02.735178 18316 slave.cpp:262] Mesos agent started on
(441)@172.17.0.4:35865
3: I1128 01:25:02.735209 18316 slave.cpp:263] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/TaskGroupValidationTest_TaskUsesDifferentExecutor_SJxj5R/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/TaskGroupValidationTest_TaskUsesDifferentExecutor_SJxj5R/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/TaskGroupValidationTest_TaskUsesDifferentExecutor_SJxj5R/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/TaskGroupValidationTest_TaskUsesDifferentExecutor_SJxj5R/executor_secret_key"
--executor_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/TaskGroupValidationTest_TaskUsesDifferentExecutor_SJxj5R/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/TaskGroupValidationTest_TaskUsesDifferentExecutor_SJxj5R/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/TaskGroupValidationTest_TaskUsesDifferentExecutor_SJxj5R"
--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/TaskGroupValidationTest_TaskUsesDifferentExecutor_hMSFnV"
--zk_session_timeout="10secs"
3: I1128 01:25:02.736090 18316 credentials.hpp:86] Loading credential for
authentication from
'/tmp/TaskGroupValidationTest_TaskUsesDifferentExecutor_SJxj5R/credential'
3: W1128 01:25:02.736215 18295 process.cpp:2756] Attempted to spawn already
running process [email protected]:35865
3: I1128 01:25:02.736349 18316 slave.cpp:295] Agent using credential for:
test-principal
3: I1128 01:25:02.736385 18316 credentials.hpp:37] Loading credentials for
authentication from
'/tmp/TaskGroupValidationTest_TaskUsesDifferentExecutor_SJxj5R/http_credentials'
3: I1128 01:25:02.737013 18316 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-executor'
3: I1128 01:25:02.737238 18316 http.cpp:1066] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-executor'
3: I1128 01:25:02.737677 18316 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
3: I1128 01:25:02.737892 18316 http.cpp:1066] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readonly'
3: I1128 01:25:02.738108 18295 sched.cpp:232] Version: 1.5.0
3: I1128 01:25:02.738306 18316 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readwrite'
3: I1128 01:25:02.738555 18316 http.cpp:1066] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readwrite'
3: I1128 01:25:02.738900 18303 sched.cpp:336] New master detected at
[email protected]:35865
3: I1128 01:25:02.739070 18303 sched.cpp:396] Authenticating with master
[email protected]:35865
3: I1128 01:25:02.739096 18303 sched.cpp:403] Using default CRAM-MD5
authenticatee
3: I1128 01:25:02.739475 18304 authenticatee.cpp:121] Creating new client SASL
connection
3: I1128 01:25:02.739897 18317 master.cpp:8312] Authenticating
[email protected]:35865
3: I1128 01:25:02.740065 18308 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(910)@172.17.0.4:35865
3: I1128 01:25:02.740423 18306 authenticator.cpp:98] Creating new server SASL
connection
3: I1128 01:25:02.740773 18299 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I1128 01:25:02.740820 18299 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I1128 01:25:02.741052 18314 authenticator.cpp:204] Received SASL
authentication start
3: I1128 01:25:02.741138 18314 authenticator.cpp:326] Authentication requires
more steps
3: I1128 01:25:02.741304 18315 authenticatee.cpp:259] Received SASL
authentication step
3: I1128 01:25:02.741492 18307 authenticator.cpp:232] Received SASL
authentication step
3: I1128 01:25:02.741184 18316 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: I1128 01:25:02.741541 18316 slave.cpp:601] Agent attributes: [ ]
3: I1128 01:25:02.741546 18307 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'aba42f2867a8' server FQDN: 'aba42f2867a8'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I1128 01:25:02.741557 18316 slave.cpp:610] Agent hostname: aba42f2867a8
3: I1128 01:25:02.741565 18307 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I1128 01:25:02.741611 18307 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I1128 01:25:02.741641 18307 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'aba42f2867a8' server FQDN: 'aba42f2867a8'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I1128 01:25:02.741667 18307 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1128 01:25:02.741678 18307 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1128 01:25:02.741698 18307 authenticator.cpp:318] Authentication success
3: I1128 01:25:02.741785 18302 task_status_update_manager.cpp:181] Pausing
sending task status updates
3: I1128 01:25:02.741830 18309 authenticatee.cpp:299] Authentication success
3: I1128 01:25:02.741951 18313 master.cpp:8342] Successfully authenticated
principal 'test-principal' at
[email protected]:35865
3: I1128 01:25:02.742053 18296 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(910)@172.17.0.4:35865
3: I1128 01:25:02.742265 18301 sched.cpp:502] Successfully authenticated with
master [email protected]:35865
3: I1128 01:25:02.742295 18301 sched.cpp:824] Sending SUBSCRIBE call to
[email protected]:35865
3: I1128 01:25:02.742496 18301 sched.cpp:857] Will retry registration in
1.480253014secs if necessary
3: I1128 01:25:02.742760 18319 master.cpp:2963] Received SUBSCRIBE call for
framework 'default' at
[email protected]:35865
3: I1128 01:25:02.742892 18319 master.cpp:2280] Authorizing framework principal
'test-principal' to receive offers for roles '{ * }'
3: I1128 01:25:02.743552 18303 master.cpp:3043] Subscribing framework default
with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1128 01:25:02.743983 18317 state.cpp:64] Recovering state from
'/tmp/TaskGroupValidationTest_TaskUsesDifferentExecutor_hMSFnV/meta'
3: I1128 01:25:02.744027 18303 master.cpp:6994] Updating info for framework
Test_Framework
3: I1128 01:25:02.744385 18299 task_status_update_manager.cpp:207] Recovering
task status update manager
3: I1128 01:25:02.744532 18305 hierarchical.cpp:306] Added framework
Test_Framework
3: I1128 01:25:02.744606 18305 hierarchical.cpp:419] Deactivated framework
Test_Framework
3: I1128 01:25:02.744623 18306 sched.cpp:751] Framework registered with
Test_Framework
3: I1128 01:25:02.744657 18307 containerizer.cpp:668] Recovering containerizer
3: I1128 01:25:02.744685 18306 sched.cpp:765] Scheduler::registered took 36363ns
3: I1128 01:25:02.744819 18305 hierarchical.cpp:385] Activated framework
Test_Framework
3: I1128 01:25:02.745141 18305 hierarchical.cpp:1457] Performed allocation for
0 agents in 107445ns
3: I1128 01:25:02.746680 18310 provisioner.cpp:455] Provisioner recovery
complete
3: I1128 01:25:02.747164 18308 slave.cpp:6493] Finished recovery
3: I1128 01:25:02.748195 18302 task_status_update_manager.cpp:181] Pausing
sending task status updates
3: I1128 01:25:02.748200 18303 slave.cpp:1007] New master detected at
[email protected]:35865
3: I1128 01:25:02.748332 18303 slave.cpp:1042] Detecting new master
3: I1128 01:25:02.755240 18309 slave.cpp:1069] Authenticating with master
[email protected]:35865
3: I1128 01:25:02.755342 18309 slave.cpp:1078] Using default CRAM-MD5
authenticatee
3: I1128 01:25:02.755658 18306 authenticatee.cpp:121] Creating new client SASL
connection
3: I1128 01:25:02.756053 18305 master.cpp:8312] Authenticating
slave(441)@172.17.0.4:35865
3: I1128 01:25:02.756247 18297 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(911)@172.17.0.4:35865
3: I1128 01:25:02.756620 18300 authenticator.cpp:98] Creating new server SASL
connection
3: I1128 01:25:02.756992 18318 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I1128 01:25:02.757042 18318 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I1128 01:25:02.757241 18318 authenticator.cpp:204] Received SASL
authentication start
3: I1128 01:25:02.757328 18318 authenticator.cpp:326] Authentication requires
more steps
3: I1128 01:25:02.757513 18301 authenticatee.cpp:259] Received SASL
authentication step
3: I1128 01:25:02.757721 18296 authenticator.cpp:232] Received SASL
authentication step
3: I1128 01:25:02.757767 18296 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'aba42f2867a8' server FQDN: 'aba42f2867a8'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I1128 01:25:02.757789 18296 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I1128 01:25:02.757829 18296 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I1128 01:25:02.757855 18296 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'aba42f2867a8' server FQDN: 'aba42f2867a8'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I1128 01:25:02.757872 18296 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1128 01:25:02.757881 18296 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1128 01:25:02.757900 18296 authenticator.cpp:318] Authentication success
3: I1128 01:25:02.758039 18307 authenticatee.cpp:299] Authentication success
3: I1128 01:25:02.758095 18311 master.cpp:8342] Successfully authenticated
principal 'test-principal' at slave(441)@172.17.0.4:35865
3: I1128 01:25:02.758167 18298 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(911)@172.17.0.4:35865
3: I1128 01:25:02.758412 18296 slave.cpp:1161] Successfully authenticated with
master [email protected]:35865
3: I1128 01:25:02.758724 18296 slave.cpp:1685] Will retry registration in
19.538797ms if necessary
3: I1128 01:25:02.759021 18317 master.cpp:6036] Received register agent message
from slave(441)@172.17.0.4:35865 (aba42f2867a8)
3: I1128 01:25:02.759210 18317 master.cpp:3872] Authorizing agent with
principal 'test-principal'
3: I1128 01:25:02.759794 18314 master.cpp:6098] Authorized registration of
agent at slave(441)@172.17.0.4:35865 (aba42f2867a8)
3: I1128 01:25:02.759953 18314 master.cpp:6191] Registering agent at
slave(441)@172.17.0.4:35865 (aba42f2867a8) with id
6c280ee5-6a83-4360-9b40-925d5c59111f-S0
3: I1128 01:25:02.760576 18315 registrar.cpp:495] Applied 1 operations in
90274ns; attempting to update the registry
3: I1128 01:25:02.761467 18315 registrar.cpp:552] Successfully updated the
registry in 806912ns
3: I1128 01:25:02.761807 18306 master.cpp:6240] Admitted agent
6c280ee5-6a83-4360-9b40-925d5c59111f-S0 at slave(441)@172.17.0.4:35865
(aba42f2867a8)
3: I1128 01:25:02.762794 18306 master.cpp:6276] Registered agent
6c280ee5-6a83-4360-9b40-925d5c59111f-S0 at slave(441)@172.17.0.4:35865
(aba42f2867a8) with cpus:2; mem:1024; disk:1024; ports:[31000-32000]
3: I1128 01:25:02.762924 18297 slave.cpp:1207] Registered with master
[email protected]:35865; given agent ID 6c280ee5-6a83-4360-9b40-925d5c59111f-S0
3: I1128 01:25:02.763100 18318 task_status_update_manager.cpp:188] Resuming
sending task status updates
3: I1128 01:25:02.763309 18300 hierarchical.cpp:600] Added agent
6c280ee5-6a83-4360-9b40-925d5c59111f-S0 (aba42f2867a8) with cpus:2; mem:1024;
disk:1024; ports:[31000-32000] (allocated: {})
3: I1128 01:25:02.763406 18297 slave.cpp:1227] Checkpointing SlaveInfo to
'/tmp/TaskGroupValidationTest_TaskUsesDifferentExecutor_hMSFnV/meta/slaves/6c280ee5-6a83-4360-9b40-925d5c59111f-S0/slave.info'
3: I1128 01:25:02.764084 18297 slave.cpp:1298] Forwarding total oversubscribed
resources {}
3: I1128 01:25:02.764400 18319 master.cpp:7091] Received update of agent
6c280ee5-6a83-4360-9b40-925d5c59111f-S0 at slave(441)@172.17.0.4:35865
(aba42f2867a8) with total oversubscribed resources {}
3: I1128 01:25:02.764705 18319 master.cpp:7109] Ignoring update on agent
6c280ee5-6a83-4360-9b40-925d5c59111f-S0 at slave(441)@172.17.0.4:35865
(aba42f2867a8) as it reports no changes
3: I1128 01:25:02.765179 18300 hierarchical.cpp:1457] Performed allocation for
1 agents in 1.617977ms
3: I1128 01:25:02.765846 18307 master.cpp:8142] Sending 1 offers to framework
Test_Framework (default) at
[email protected]:35865
3: I1128 01:25:02.766645 18311 sched.cpp:921] Scheduler::resourceOffers took
166103ns
3: I1128 01:25:02.769856 18308 master.cpp:10063] Removing offer
6c280ee5-6a83-4360-9b40-925d5c59111f-O0
3: I1128 01:25:02.770223 18308 master.cpp:4230] Processing ACCEPT call for
offers: [ 6c280ee5-6a83-4360-9b40-925d5c59111f-O0 ] on agent
6c280ee5-6a83-4360-9b40-925d5c59111f-S0 at slave(441)@172.17.0.4:35865
(aba42f2867a8) for framework Test_Framework (default) at
[email protected]:35865
3: I1128 01:25:02.770437 18308 master.cpp:3599] Authorizing framework principal
'test-principal' to launch task 1
3: I1128 01:25:02.770830 18308 master.cpp:3599] Authorizing framework principal
'test-principal' to launch task 2
3: I1128 01:25:02.774569 18302 master.cpp:7331] Sending status update
TASK_ERROR for task 1 of framework Test_Framework 'The `ExecutorInfo` of task
'1' is different from executor 'default''
3: I1128 01:25:02.774842 18302 master.cpp:7331] Sending status update
TASK_ERROR for task 2 of framework Test_Framework 'The `ExecutorInfo` of task
'1' is different from executor 'default''
3: I1128 01:25:02.775087 18315 sched.cpp:1029] Scheduler::statusUpdate took
96799ns
3: I1128 01:25:02.775382 18315 sched.cpp:1029] Scheduler::statusUpdate took
50375ns
3: I1128 01:25:02.775599 18295 sched.cpp:2009] Asked to stop the driver
3: I1128 01:25:02.775714 18297 sched.cpp:1191] Stopping framework Test_Framework
3: I1128 01:25:02.776029 18307 master.cpp:8819] Processing TEARDOWN call for
framework Test_Framework (default) at
[email protected]:35865
3: I1128 01:25:02.776072 18307 master.cpp:8831] Removing framework
Test_Framework (default) at
[email protected]:35865
3: I1128 01:25:02.776089 18307 master.cpp:3333] Deactivating framework
Test_Framework (default) at
[email protected]:35865
3: I1128 01:25:02.776322 18311 slave.cpp:3270] Asked to shut down framework
Test_Framework by [email protected]:35865
3: I1128 01:25:02.776365 18311 slave.cpp:3285] Cannot shut down unknown
framework Test_Framework
3: I1128 01:25:02.776623 18313 hierarchical.cpp:1132] 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 6c280ee5-6a83-4360-9b40-925d5c59111f-S0 from framework
Test_Framework
3: I1128 01:25:02.776724 18313 hierarchical.cpp:1178] Framework Test_Framework
filtered agent 6c280ee5-6a83-4360-9b40-925d5c59111f-S0 for 5secs
3: I1128 01:25:02.777135 18313 hierarchical.cpp:419] Deactivated framework
Test_Framework
3: I1128 01:25:02.777685 18313 hierarchical.cpp:358] Removed framework
Test_Framework
3: I1128 01:25:02.777757 18297 slave.cpp:883] Agent terminating
3: I1128 01:25:02.778014 18307 master.cpp:1311] Agent
6c280ee5-6a83-4360-9b40-925d5c59111f-S0 at slave(441)@172.17.0.4:35865
(aba42f2867a8) disconnected
3: I1128 01:25:02.778048 18307 master.cpp:3370] Disconnecting agent
6c280ee5-6a83-4360-9b40-925d5c59111f-S0 at slave(441)@172.17.0.4:35865
(aba42f2867a8)
3: I1128 01:25:02.778129 18307 master.cpp:3389] Deactivating agent
6c280ee5-6a83-4360-9b40-925d5c59111f-S0 at slave(441)@172.17.0.4:35865
(aba42f2867a8)
3: I1128 01:25:02.778277 18306 hierarchical.cpp:697] Agent
6c280ee5-6a83-4360-9b40-925d5c59111f-S0 deactivated
3: I1128 01:25:02.787585 18295 master.cpp:1153] Master terminating
3: I1128 01:25:02.788548 18309 hierarchical.cpp:633] Removed agent
6c280ee5-6a83-4360-9b40-925d5c59111f-S0
3: [ OK ] TaskGroupValidationTest.TaskUsesDifferentExecutor (87 ms)
3: [ RUN ] TaskGroupValidationTest.ExecutorEnvironmentInvalid
3: I1128 01:25:02.797271 18295 cluster.cpp:162] Creating default 'local'
authorizer
3: I1128 01:25:02.801652 18314 master.cpp:448] Master
34927a5e-d806-4133-ab7a-18bda369b6b7 (aba42f2867a8) started on 172.17.0.4:35865
3: I1128 01:25:02.801687 18314 master.cpp:450] 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/R1HNuI/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/R1HNuI/master"
--zk_session_timeout="10secs"
3: I1128 01:25:02.802098 18314 master.cpp:499] Master only allowing
authenticated frameworks to register
3: I1128 01:25:02.802109 18314 master.cpp:505] Master only allowing
authenticated agents to register
3: I1128 01:25:02.802116 18314 master.cpp:511] Master only allowing
authenticated HTTP frameworks to register
3: I1128 01:25:02.802124 18314 credentials.hpp:37] Loading credentials for
authentication from '/tmp/R1HNuI/credentials'
3: I1128 01:25:02.802511 18314 master.cpp:555] Using default 'crammd5'
authenticator
3: I1128 01:25:02.802731 18314 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
3: I1128 01:25:02.802945 18314 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
3: I1128 01:25:02.803136 18314 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
3: I1128 01:25:02.803319 18314 master.cpp:634] Authorization enabled
3: I1128 01:25:02.803503 18313 hierarchical.cpp:173] Initialized hierarchical
allocator process
3: I1128 01:25:02.803534 18310 whitelist_watcher.cpp:77] No whitelist given
3: I1128 01:25:02.807478 18303 master.cpp:2215] Elected as the leading master!
3: I1128 01:25:02.807521 18303 master.cpp:1695] Recovering from registrar
3: I1128 01:25:02.807674 18311 registrar.cpp:347] Recovering registrar
3: I1128 01:25:02.808423 18311 registrar.cpp:391] Successfully fetched the
registry (0B) in 699904ns
3: I1128 01:25:02.808550 18311 registrar.cpp:495] Applied 1 operations in
33295ns; attempting to update the registry
3: I1128 01:25:02.809257 18311 registrar.cpp:552] Successfully updated the
registry in 641024ns
3: I1128 01:25:02.809417 18311 registrar.cpp:424] Successfully recovered
registrar
3: I1128 01:25:02.809880 18305 master.cpp:1808] Recovered 0 agents from the
registry (129B); allowing 10mins for agents to re-register
3: I1128 01:25:02.809924 18311 hierarchical.cpp:211] Skipping recovery of
hierarchical allocator: nothing to recover
3: W1128 01:25:02.816287 18295 process.cpp:2756] Attempted to spawn already
running process [email protected]:35865
3: I1128 01:25:02.817593 18295 containerizer.cpp:301] Using isolation {
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1128 01:25:02.818265 18295 backend.cpp:76] Failed to create 'aufs' backend:
AufsBackend requires root privileges
3: W1128 01:25:02.818416 18295 backend.cpp:76] Failed to create 'bind' backend:
BindBackend requires root privileges
3: I1128 01:25:02.818457 18295 provisioner.cpp:259] Using default backend 'copy'
3: I1128 01:25:02.820842 18295 cluster.cpp:448] Creating default 'local'
authorizer
3: I1128 01:25:02.823631 18308 slave.cpp:262] Mesos agent started on
(442)@172.17.0.4:35865
3: I1128 01:25:02.823657 18308 slave.cpp:263] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/TaskGroupValidationTest_ExecutorEnvironmentInvalid_LATbjC/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/TaskGroupValidationTest_ExecutorEnvironmentInvalid_LATbjC/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/TaskGroupValidationTest_ExecutorEnvironmentInvalid_LATbjC/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/TaskGroupValidationTest_ExecutorEnvironmentInvalid_LATbjC/executor_secret_key"
--executor_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/TaskGroupValidationTest_ExecutorEnvironmentInvalid_LATbjC/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/TaskGroupValidationTest_ExecutorEnvironmentInvalid_LATbjC/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/TaskGroupValidationTest_ExecutorEnvironmentInvalid_LATbjC"
--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/TaskGroupValidationTest_ExecutorEnvironmentInvalid_dJ7YoF"
--zk_session_timeout="10secs"
3: I1128 01:25:02.824226 18308 credentials.hpp:86] Loading credential for
authentication from
'/tmp/TaskGroupValidationTest_ExecutorEnvironmentInvalid_LATbjC/credential'
3: W1128 01:25:02.824314 18295 process.cpp:2756] Attempted to spawn already
running process [email protected]:35865
3: I1128 01:25:02.824430 18308 slave.cpp:295] Agent using credential for:
test-principal
3: I1128 01:25:02.824455 18308 credentials.hpp:37] Loading credentials for
authentication from
'/tmp/TaskGroupValidationTest_ExecutorEnvironmentInvalid_LATbjC/http_credentials'
3: I1128 01:25:02.824841 18308 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-executor'
3: I1128 01:25:02.825007 18308 http.cpp:1066] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-executor'
3: I1128 01:25:02.825253 18308 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
3: I1128 01:25:02.825378 18308 http.cpp:1066] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readonly'
3: I1128 01:25:02.825564 18295 sched.cpp:232] Version: 1.5.0
3: I1128 01:25:02.825611 18308 http.cpp:1045] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readwrite'
3: I1128 01:25:02.825750 18308 http.cpp:1066] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readwrite'
3: I1128 01:25:02.826148 18315 sched.cpp:336] New master detected at
[email protected]:35865
3: I1128 01:25:02.826285 18315 sched.cpp:396] Authenticating with master
[email protected]:35865
3: I1128 01:25:02.826309 18315 sched.cpp:403] Using default CRAM-MD5
authenticatee
3: I1128 01:25:02.826591 18311 authenticatee.cpp:121] Creating new client SASL
connection
3: I1128 01:25:02.826884 18296 master.cpp:8312] Authenticating
[email protected]:35865
3: I1128 01:25:02.827045 18313 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(912)@172.17.0.4:35865
3: I1128 01:25:02.827363 18317 authenticator.cpp:98] Creating new server SASL
connection
3: I1128 01:25:02.827677 18314 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I1128 01:25:02.827710 18314 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I1128 01:25:02.827833 18314 authenticator.cpp:204] Received SASL
authentication start
3: I1128 01:25:02.827898 18314 authenticator.cpp:326] Authentication requires
more steps
3: I1128 01:25:02.827642 18308 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: I1128 01:25:02.827927 18308 slave.cpp:601] Agent attributes: [ ]
3: I1128 01:25:02.827944 18308 slave.cpp:610] Agent hostname: aba42f2867a8
3: I1128 01:25:02.828012 18314 authenticatee.cpp:259] Received SASL
authentication step
3: I1128 01:25:02.828089 18318 task_status_update_manager.cpp:181] Pausing
sending task status updates
3: I1128 01:25:02.828155 18307 authenticator.cpp:232] Received SASL
authentication step
3: I1128 01:25:02.828197 18307 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'aba42f2867a8' server FQDN: 'aba42f2867a8'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I1128 01:25:02.828209 18307 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I1128 01:25:02.828245 18307 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I1128 01:25:02.828265 18307 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: 'aba42f2867a8' server FQDN: 'aba42f2867a8'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I1128 01:25:02.828279 18307 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1128 01:25:02.828285 18307 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1128 01:25:02.828301 18307 authenticator.cpp:318] Authentication success
3: I1128 01:25:02.828418 18297 authenticatee.cpp:299] Authentication success
3: I1128 01:25:02.828491 18299 master.cpp:8342] Successfully authenticated
principal 'test-principal' at
[email protected]:35865
3: I1128 01:25:02.828550 18309 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(912)@172.17.0.4:35865
3: I1128 01:25:02.828774 18302 sched.cpp:502] Successfully authenticated with
master [email protected]:35865
3: I1128 01:25:02.828802 18302 sched.cpp:824] Sending SUBSCRIBE call to
[email protected]:35865
3: I1128 01:25:02.828974 18302 sched.cpp:857] Will retry registration in
238.422336ms if necessary
3: I1128 01:25:02.829277 18301 master.cpp:2963] Received SUBSCRIBE call for
framework 'default' at
[email protected]:35865
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1511829608-4784
Build step 'Execute shell' marked build as failure
