mesos-builds mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject Build failed in Jenkins: Mesos-Buildbot » cmake,gcc,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4644
Date Thu, 21 Dec 2017 15:48:46 GMT
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)/4644/display/redirect?page=changes>

Changes:

[toenshoff] Updated support/mesos-style.py to build the virtualenv less often.

------------------------------------------
[...truncated 35.29 MB...]
3: I1221 15:48:42.051256 24241 master.cpp:9438] Processing TEARDOWN call for framework 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-0000
(default) at scheduler-1555f316-0940-4a29-ad4d-e5a13e980937@172.17.0.3:42493
3: I1221 15:48:42.051290 24241 master.cpp:9450] Removing framework 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-0000
(default) at scheduler-1555f316-0940-4a29-ad4d-e5a13e980937@172.17.0.3:42493
3: I1221 15:48:42.051306 24241 master.cpp:3328] Deactivating framework 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-0000
(default) at scheduler-1555f316-0940-4a29-ad4d-e5a13e980937@172.17.0.3:42493
3: I1221 15:48:42.051509 24242 hierarchical.cpp:405] Deactivated framework 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-0000
3: I1221 15:48:42.052232 17609 slave.cpp:931] Agent terminating
3: I1221 15:48:42.052295 17609 slave.cpp:3398] Asked to shut down framework 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-0000
by @0.0.0.0:0
3: I1221 15:48:42.052340 17609 slave.cpp:3423] Shutting down framework 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-0000
3: I1221 15:48:42.052384 24241 master.cpp:10671] Removing offer 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-O3
3: I1221 15:48:42.052397 17609 slave.cpp:6129] Shutting down executor 'default' of framework
1b83ae21-41f5-4b58-9bb4-be7c014b24c5-0000 at executor(222)@172.17.0.3:42493
3: I1221 15:48:42.052531 24238 exec.cpp:435] Executor asked to shutdown
3: I1221 15:48:42.052604 24238 exec.cpp:450] Executor::shutdown took 49027ns
3: I1221 15:48:42.052665 24241 master.cpp:10288] Removing executor 'default' with resources
[] of framework 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-0000 on agent 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-S0
at slave(1008)@172.17.0.3:42493 (67c59b4a59f4)
3: I1221 15:48:42.053270 24233 hierarchical.cpp:1192] Recovered cpus(allocated: role):0.5;
mem(allocated: role):256; disk(allocated: role):3701220; ports(allocated: role):[31000-32000];
cpus(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):1.5; mem(allocated: role)(reservations:
[(DYNAMIC,role,test-principal)]):768 (total: cpus:0.5; mem:256; disk:3701220; ports:[31000-32000];
cpus(reservations: [(DYNAMIC,role,test-principal)]):1.5; mem(reservations: [(DYNAMIC,role,test-principal)]):768,
allocated: {}) on agent 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-S0 from framework 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-0000
3: I1221 15:48:42.053365 24241 master.cpp:1305] Agent 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-S0
at slave(1008)@172.17.0.3:42493 (67c59b4a59f4) disconnected
3: I1221 15:48:42.053391 24241 master.cpp:3365] Disconnecting agent 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-S0
at slave(1008)@172.17.0.3:42493 (67c59b4a59f4)
3: I1221 15:48:42.053453 24241 master.cpp:3384] Deactivating agent 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-S0
at slave(1008)@172.17.0.3:42493 (67c59b4a59f4)
3: I1221 15:48:42.053716 24233 hierarchical.cpp:344] Removed framework 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-0000
3: I1221 15:48:42.053809 24233 hierarchical.cpp:766] Agent 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-S0
deactivated
3: I1221 15:48:42.059499 17609 master.cpp:1147] Master terminating
3: I1221 15:48:42.060803 24240 hierarchical.cpp:609] Removed agent 1b83ae21-41f5-4b58-9bb4-be7c014b24c5-S0
3: [       OK ] ResourceProviderCapability/ReservationTest.ACLMultipleOperations/0 (122 ms)
3: [ RUN      ] ResourceProviderCapability/ReservationTest.ACLMultipleOperations/1
3: I1221 15:48:42.068058 17609 cluster.cpp:172] Creating default 'local' authorizer
3: I1221 15:48:42.071524 24246 master.cpp:456] Master a38af167-ca31-4de2-9ae7-be6a90bebfd8
(67c59b4a59f4) started on 172.17.0.3:42493
3: I1221 15:48:42.071550 24246 master.cpp:458] Flags at startup: --acls="reserve_resources
{
3:   principals {
3:     values: "test-principal"
3:   }
3:   roles {
3:     type: ANY
3:   }
3: }
3: unreserve_resources {
3:   principals {
3:     values: "test-principal"
3:   }
3:   reserver_principals {
3:     type: NONE
3:   }
3: }
3: " --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="5ms"
--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/1l4a98/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" --roles="role" --root_submissions="true"
--user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/1l4a98/master"
--zk_session_timeout="10secs"
3: I1221 15:48:42.071976 24246 master.cpp:507] Master only allowing authenticated frameworks
to register
3: I1221 15:48:42.071990 24246 master.cpp:513] Master only allowing authenticated agents to
register
3: I1221 15:48:42.071998 24246 master.cpp:519] Master only allowing authenticated HTTP frameworks
to register
3: I1221 15:48:42.072007 24246 credentials.hpp:37] Loading credentials for authentication
from '/tmp/1l4a98/credentials'
3: I1221 15:48:42.072329 24246 master.cpp:563] Using default 'crammd5' authenticator
3: I1221 15:48:42.072506 24246 http.cpp:1045] Creating default 'basic' HTTP authenticator
for realm 'mesos-master-readonly'
3: I1221 15:48:42.072707 24246 http.cpp:1045] Creating default 'basic' HTTP authenticator
for realm 'mesos-master-readwrite'
3: I1221 15:48:42.072882 24246 http.cpp:1045] Creating default 'basic' HTTP authenticator
for realm 'mesos-master-scheduler'
3: I1221 15:48:42.073047 24246 master.cpp:642] Authorization enabled
3: W1221 15:48:42.073065 24246 master.cpp:705] The '--roles' flag is deprecated. This flag
will be removed in the future. See the Mesos 0.27 upgrade notes for more information
3: I1221 15:48:42.073258 24238 hierarchical.cpp:175] Initialized hierarchical allocator process
3: I1221 15:48:42.073308 24245 whitelist_watcher.cpp:77] No whitelist given
3: I1221 15:48:42.076217 24235 master.cpp:2210] Elected as the leading master!
3: I1221 15:48:42.076249 24235 master.cpp:1689] Recovering from registrar
3: I1221 15:48:42.076473 24244 registrar.cpp:347] Recovering registrar
3: I1221 15:48:42.077172 24244 registrar.cpp:391] Successfully fetched the registry (0B) in
0ns
3: I1221 15:48:42.077280 24244 registrar.cpp:495] Applied 1 operations in 30601ns; attempting
to update the registry
3: I1221 15:48:42.077841 24244 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1221 15:48:42.077957 24244 registrar.cpp:424] Successfully recovered registrar
3: I1221 15:48:42.078408 24238 master.cpp:1803] Recovered 0 agents from the registry (135B);
allowing 10mins for agents to re-register
3: I1221 15:48:42.078459 24242 hierarchical.cpp:213] Skipping recovery of hierarchical allocator:
nothing to recover
3: W1221 15:48:42.083135 17609 process.cpp:2756] Attempted to spawn already running process
files@172.17.0.3:42493
3: I1221 15:48:42.083397 17609 cluster.cpp:460] Creating default 'local' authorizer
3: I1221 15:48:42.085649 24239 slave.cpp:262] Mesos agent started on (1009)@172.17.0.3:42493
3: I1221 15:48:42.085664 24239 slave.cpp:263] 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/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_Fvp6ZU/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/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_Fvp6ZU/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/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_Fvp6ZU/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/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_Fvp6ZU/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/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_Fvp6ZU/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem"
--jwt_secret_key="/tmp/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_Fvp6ZU/jwt_secret_key"
--launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO"
--max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs"
--perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns"
--quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins"
--registration_backoff_factor="10ms" --resources="cpus:2;mem:1024" --revocable_cpu_low_priority="true"
--runtime_dir="/tmp/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_Fvp6ZU"
--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/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_WigD41"
--zk_session_timeout="10secs"
3: I1221 15:48:42.086105 24239 credentials.hpp:86] Loading credential for authentication from
'/tmp/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_Fvp6ZU/credential'
3: I1221 15:48:42.086203 24234 hierarchical.cpp:1517] Performed allocation for 0 agents in
58140ns
3: I1221 15:48:42.086294 24239 slave.cpp:295] Agent using credential for: test-principal
3: I1221 15:48:42.086311 24239 credentials.hpp:37] Loading credentials for authentication
from '/tmp/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_Fvp6ZU/http_credentials'
3: I1221 15:48:42.086614 24239 http.cpp:1045] Creating default 'basic' HTTP authenticator
for realm 'mesos-agent-executor'
3: I1221 15:48:42.086751 24239 http.cpp:1066] Creating default 'jwt' HTTP authenticator for
realm 'mesos-agent-executor'
3: I1221 15:48:42.086990 24239 http.cpp:1045] Creating default 'basic' HTTP authenticator
for realm 'mesos-agent-readonly'
3: I1221 15:48:42.087103 24239 http.cpp:1066] Creating default 'jwt' HTTP authenticator for
realm 'mesos-agent-readonly'
3: I1221 15:48:42.087321 24239 http.cpp:1045] Creating default 'basic' HTTP authenticator
for realm 'mesos-agent-readwrite'
3: I1221 15:48:42.087432 24239 http.cpp:1066] Creating default 'jwt' HTTP authenticator for
realm 'mesos-agent-readwrite'
3: I1221 15:48:42.088639 24239 slave.cpp:612] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":3701220.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1221 15:48:42.088846 24239 slave.cpp:620] Agent attributes: [  ]
3: I1221 15:48:42.088860 24239 slave.cpp:629] Agent hostname: 67c59b4a59f4
3: I1221 15:48:42.089085 24245 task_status_update_manager.cpp:181] Pausing sending task status
updates
3: I1221 15:48:42.090716 24237 state.cpp:66] Recovering state from '/tmp/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_WigD41/meta'
3: I1221 15:48:42.091087 24243 task_status_update_manager.cpp:207] Recovering task status
update manager
3: I1221 15:48:42.091575 24241 slave.cpp:6775] Finished recovery
3: I1221 15:48:42.092360 24232 slave.cpp:1055] New master detected at master@172.17.0.3:42493
3: I1221 15:48:42.092406 24233 task_status_update_manager.cpp:181] Pausing sending task status
updates
3: I1221 15:48:42.092425 24232 slave.cpp:1110] Detecting new master
3: I1221 15:48:42.092654 24232 slave.cpp:1137] Authenticating with master master@172.17.0.3:42493
3: I1221 15:48:42.092730 24232 slave.cpp:1146] Using default CRAM-MD5 authenticatee
3: I1221 15:48:42.092968 24238 authenticatee.cpp:121] Creating new client SASL connection
3: I1221 15:48:42.093272 24246 master.cpp:8928] Authenticating slave(1009)@172.17.0.3:42493
3: I1221 15:48:42.093397 24242 authenticator.cpp:414] Starting authentication session for
crammd5-authenticatee(1726)@172.17.0.3:42493
3: I1221 15:48:42.093678 24239 authenticator.cpp:98] Creating new server SASL connection
3: I1221 15:48:42.093879 24237 authenticatee.cpp:213] Received SASL authentication mechanisms:
CRAM-MD5
3: I1221 15:48:42.093901 24237 authenticatee.cpp:239] Attempting to authenticate with mechanism
'CRAM-MD5'
3: I1221 15:48:42.094034 24240 authenticator.cpp:204] Received SASL authentication start
3: I1221 15:48:42.094100 24240 authenticator.cpp:326] Authentication requires more steps
3: I1221 15:48:42.094225 24240 authenticatee.cpp:259] Received SASL authentication step
3: I1221 15:48:42.094374 24243 authenticator.cpp:232] Received SASL authentication step
3: I1221 15:48:42.094408 24243 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '67c59b4a59f4' server FQDN: '67c59b4a59f4' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1221 15:48:42.094420 24243 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1221 15:48:42.094454 24243 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1221 15:48:42.094478 24243 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '67c59b4a59f4' server FQDN: '67c59b4a59f4' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1221 15:48:42.094487 24243 auxprop.cpp:131] Skipping auxiliary property '*userPassword'
since SASL_AUXPROP_AUTHZID == true
3: I1221 15:48:42.094496 24243 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
3: I1221 15:48:42.094516 24243 authenticator.cpp:318] Authentication success
3: I1221 15:48:42.094617 24235 authenticatee.cpp:299] Authentication success
3: I1221 15:48:42.094760 24235 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1726)@172.17.0.3:42493
3: I1221 15:48:42.094777 24247 master.cpp:8958] Successfully authenticated principal 'test-principal'
at slave(1009)@172.17.0.3:42493
3: I1221 15:48:42.094991 24241 slave.cpp:1229] Successfully authenticated with master master@172.17.0.3:42493
3: I1221 15:48:42.095222 24241 slave.cpp:1708] Will retry registration in 3.224371ms if necessary
3: I1221 15:48:42.095369 24238 master.cpp:6078] Received register agent message from slave(1009)@172.17.0.3:42493
(67c59b4a59f4)
3: I1221 15:48:42.095445 24238 master.cpp:3867] Authorizing agent with principal 'test-principal'
3: I1221 15:48:42.095844 24238 master.cpp:6148] Authorized registration of agent at slave(1009)@172.17.0.3:42493
(67c59b4a59f4)
3: I1221 15:48:42.095985 24238 master.cpp:6241] Registering agent at slave(1009)@172.17.0.3:42493
(67c59b4a59f4) with id a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0
3: I1221 15:48:42.096520 24239 registrar.cpp:495] Applied 1 operations in 79210ns; attempting
to update the registry
3: I1221 15:48:42.097054 24239 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1221 15:48:42.097219 24243 master.cpp:6289] Admitted agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0
at slave(1009)@172.17.0.3:42493 (67c59b4a59f4)
3: I1221 15:48:42.097985 24243 master.cpp:6338] Registered agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0
at slave(1009)@172.17.0.3:42493 (67c59b4a59f4) with cpus:2; mem:1024; disk:3701220; ports:[31000-32000]
3: I1221 15:48:42.098052 24247 slave.cpp:1275] Registered with master master@172.17.0.3:42493;
given agent ID a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0
3: I1221 15:48:42.098161 24233 task_status_update_manager.cpp:188] Resuming sending task status
updates
3: I1221 15:48:42.098363 24247 slave.cpp:1295] Checkpointing SlaveInfo to '/tmp/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_WigD41/meta/slaves/a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0/slave.info'
3: I1221 15:48:42.098389 24245 hierarchical.cpp:574] Added agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0
(67c59b4a59f4) with cpus:2; mem:1024; disk:3701220; ports:[31000-32000] (allocated: {})
3: I1221 15:48:42.098780 24245 hierarchical.cpp:1517] Performed allocation for 1 agents in
202375ns
3: I1221 15:48:42.098817 24247 slave.cpp:1352] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"Deg+mQOqSU2mT3GGYvBxQw=="},"slave_id":{"value":"a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0"},"update_oversubscribed_resources":true}
3: I1221 15:48:42.099160 24247 master.cpp:7268] Received update of agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0
at slave(1009)@172.17.0.3:42493 (67c59b4a59f4) with total oversubscribed resources {}
3: I1221 15:48:42.099426 24247 master.cpp:7362] Ignoring update on agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0
at slave(1009)@172.17.0.3:42493 (67c59b4a59f4) as it reports no changes
3: W1221 15:48:42.099820 17609 process.cpp:2756] Attempted to spawn already running process
version@172.17.0.3:42493
3: I1221 15:48:42.101052 17609 sched.cpp:232] Version: 1.5.0
3: I1221 15:48:42.101701 24234 sched.cpp:336] New master detected at master@172.17.0.3:42493
3: I1221 15:48:42.101779 24234 sched.cpp:396] Authenticating with master master@172.17.0.3:42493
3: I1221 15:48:42.101792 24234 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1221 15:48:42.102023 24237 authenticatee.cpp:121] Creating new client SASL connection
3: I1221 15:48:42.102263 24244 master.cpp:8928] Authenticating scheduler-64251fa2-b046-4ba2-90b2-c6484580e7ea@172.17.0.3:42493
3: I1221 15:48:42.102365 24232 authenticator.cpp:414] Starting authentication session for
crammd5-authenticatee(1727)@172.17.0.3:42493
3: I1221 15:48:42.102627 24243 authenticator.cpp:98] Creating new server SASL connection
3: I1221 15:48:42.102880 24233 authenticatee.cpp:213] Received SASL authentication mechanisms:
CRAM-MD5
3: I1221 15:48:42.102912 24233 authenticatee.cpp:239] Attempting to authenticate with mechanism
'CRAM-MD5'
3: I1221 15:48:42.103051 24235 authenticator.cpp:204] Received SASL authentication start
3: I1221 15:48:42.103118 24235 authenticator.cpp:326] Authentication requires more steps
3: I1221 15:48:42.103257 24245 authenticatee.cpp:259] Received SASL authentication step
3: I1221 15:48:42.103391 24245 authenticator.cpp:232] Received SASL authentication step
3: I1221 15:48:42.103420 24245 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '67c59b4a59f4' server FQDN: '67c59b4a59f4' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
3: I1221 15:48:42.103430 24245 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1221 15:48:42.103458 24245 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1221 15:48:42.103480 24245 auxprop.cpp:109] Request to lookup properties for user: 'test-principal'
realm: '67c59b4a59f4' server FQDN: '67c59b4a59f4' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
3: I1221 15:48:42.103495 24245 auxprop.cpp:131] Skipping auxiliary property '*userPassword'
since SASL_AUXPROP_AUTHZID == true
3: I1221 15:48:42.103502 24245 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
3: I1221 15:48:42.103516 24245 authenticator.cpp:318] Authentication success
3: I1221 15:48:42.103639 24247 authenticatee.cpp:299] Authentication success
3: I1221 15:48:42.103679 24246 master.cpp:8958] Successfully authenticated principal 'test-principal'
at scheduler-64251fa2-b046-4ba2-90b2-c6484580e7ea@172.17.0.3:42493
3: I1221 15:48:42.103735 24242 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1727)@172.17.0.3:42493
3: I1221 15:48:42.104007 24245 sched.cpp:502] Successfully authenticated with master master@172.17.0.3:42493
3: I1221 15:48:42.104030 24245 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.3:42493
3: I1221 15:48:42.104153 24245 sched.cpp:857] Will retry registration in 1.415382093secs if
necessary
3: I1221 15:48:42.104326 24237 master.cpp:2958] Received SUBSCRIBE call for framework 'default'
at scheduler-64251fa2-b046-4ba2-90b2-c6484580e7ea@172.17.0.3:42493
3: I1221 15:48:42.104400 24237 master.cpp:2275] Authorizing framework principal 'test-principal'
to receive offers for roles '{ role }'
3: I1221 15:48:42.104884 24244 master.cpp:3038] Subscribing framework default with checkpointing
disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
3: I1221 15:48:42.105062 24244 master.cpp:9149] Adding framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
(default) at scheduler-64251fa2-b046-4ba2-90b2-c6484580e7ea@172.17.0.3:42493 with roles {
 } suppressed
3: I1221 15:48:42.105540 24233 sched.cpp:751] Framework registered with a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.105572 24232 hierarchical.cpp:297] Added framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.105603 24233 sched.cpp:765] Scheduler::registered took 29040ns
3: I1221 15:48:42.106817 24232 hierarchical.cpp:1517] Performed allocation for 1 agents in
1.125252ms
3: I1221 15:48:42.107403 24235 master.cpp:8758] Sending 1 offers to framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
(default) at scheduler-64251fa2-b046-4ba2-90b2-c6484580e7ea@172.17.0.3:42493
3: I1221 15:48:42.107982 24235 sched.cpp:921] Scheduler::resourceOffers took 116422ns
3: I1221 15:48:42.108671 24247 hierarchical.cpp:1517] Performed allocation for 1 agents in
345553ns
3: I1221 15:48:42.110100 24246 master.cpp:10671] Removing offer a38af167-ca31-4de2-9ae7-be6a90bebfd8-O0
3: I1221 15:48:42.110209 24246 master.cpp:4274] Processing ACCEPT call for offers: [ a38af167-ca31-4de2-9ae7-be6a90bebfd8-O0
] on agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0 at slave(1009)@172.17.0.3:42493 (67c59b4a59f4)
for framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 (default) at scheduler-64251fa2-b046-4ba2-90b2-c6484580e7ea@172.17.0.3:42493
3: I1221 15:48:42.110330 24246 master.cpp:3652] Authorizing principal 'test-principal' to
reserve resources '[{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":512.0},"type":"SCALAR"}]'
3: I1221 15:48:42.112277 24245 master.cpp:4607] Applying RESERVE operation for resources [{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":512.0},"type":"SCALAR"}]
from framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 (default) at scheduler-64251fa2-b046-4ba2-90b2-c6484580e7ea@172.17.0.3:42493
to agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0 at slave(1009)@172.17.0.3:42493 (67c59b4a59f4)
3: I1221 15:48:42.113270 24245 master.cpp:10569] Sending operation '' (uuid: 19fcb234-ad3d-4275-875b-1d34f6fee9ba)
to agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0 at slave(1009)@172.17.0.3:42493 (67c59b4a59f4)
3: I1221 15:48:42.114517 24234 slave.cpp:3721] Updated checkpointed resources from {} to cpus(reservations:
[(DYNAMIC,role,test-principal)]):1; mem(reservations: [(DYNAMIC,role,test-principal)]):512
3: I1221 15:48:42.114619 24234 slave.cpp:7454] Updating the state of operation '' (uuid: 19fcb234-ad3d-4275-875b-1d34f6fee9ba)
of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 (latest state: OPERATION_FINISHED,
status update state: OPERATION_FINISHED)
3: I1221 15:48:42.114861 24234 master.cpp:10358] Updating the state of operation '' (uuid:
19fcb234-ad3d-4275-875b-1d34f6fee9ba) of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
(latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
3: I1221 15:48:42.116401 24244 hierarchical.cpp:925] Updated allocation of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
on agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0 from cpus(allocated: role):2; mem(allocated:
role):1024; disk(allocated: role):3701220; ports(allocated: role):[31000-32000] to cpus(allocated:
role):1; mem(allocated: role):512; disk(allocated: role):3701220; ports(allocated: role):[31000-32000];
cpus(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):1; mem(allocated: role)(reservations:
[(DYNAMIC,role,test-principal)]):512
3: I1221 15:48:42.117733 24244 hierarchical.cpp:1192] Recovered cpus(allocated: role):1; mem(allocated:
role):512; disk(allocated: role):3701220; 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:3701220; ports:[31000-32000];
cpus(reservations: [(DYNAMIC,role,test-principal)]):1; mem(reservations: [(DYNAMIC,role,test-principal)]):512,
allocated: {}) on agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0 from framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.119601 24243 hierarchical.cpp:1517] Performed allocation for 1 agents in
1.478237ms
3: I1221 15:48:42.120296 24232 master.cpp:8758] Sending 1 offers to framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
(default) at scheduler-64251fa2-b046-4ba2-90b2-c6484580e7ea@172.17.0.3:42493
3: I1221 15:48:42.120798 24232 sched.cpp:921] Scheduler::resourceOffers took 78180ns
3: I1221 15:48:42.122733 24247 master.cpp:10671] Removing offer a38af167-ca31-4de2-9ae7-be6a90bebfd8-O1
3: I1221 15:48:42.122959 24247 master.cpp:4274] Processing ACCEPT call for offers: [ a38af167-ca31-4de2-9ae7-be6a90bebfd8-O1
] on agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0 at slave(1009)@172.17.0.3:42493 (67c59b4a59f4)
for framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 (default) at scheduler-64251fa2-b046-4ba2-90b2-c6484580e7ea@172.17.0.3:42493
3: I1221 15:48:42.123139 24247 master.cpp:3720] Authorizing principal 'test-principal' to
unreserve resources '[{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":512.0},"type":"SCALAR"}]'
3: I1221 15:48:42.123679 24247 master.cpp:3652] Authorizing principal 'test-principal' to
reserve resources '[{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":0.5},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":256.0},"type":"SCALAR"}]'
3: I1221 15:48:42.124101 24247 master.cpp:3594] Authorizing framework principal 'test-principal'
to launch task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44
3: W1221 15:48:42.125164 24233 master.cpp:2360] Dropping UNRESERVE operation from framework
a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 (default) at scheduler-64251fa2-b046-4ba2-90b2-c6484580e7ea@172.17.0.3:42493:
Not authorized to unreserve resources as 'test-principal'
3: I1221 15:48:42.125931 24233 master.cpp:4607] Applying RESERVE operation for resources [{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":0.5},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":256.0},"type":"SCALAR"}]
from framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 (default) at scheduler-64251fa2-b046-4ba2-90b2-c6484580e7ea@172.17.0.3:42493
to agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0 at slave(1009)@172.17.0.3:42493 (67c59b4a59f4)
3: I1221 15:48:42.126884 24233 master.cpp:10569] Sending operation '' (uuid: acddcd3a-277c-4e91-9ddb-f6f8fa4a3336)
to agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0 at slave(1009)@172.17.0.3:42493 (67c59b4a59f4)
3: I1221 15:48:42.128067 24244 slave.cpp:3721] Updated checkpointed resources from cpus(reservations:
[(DYNAMIC,role,test-principal)]):1; mem(reservations: [(DYNAMIC,role,test-principal)]):512
to cpus(reservations: [(DYNAMIC,role,test-principal)]):1.5; mem(reservations: [(DYNAMIC,role,test-principal)]):768
3: I1221 15:48:42.128157 24244 slave.cpp:7454] Updating the state of operation '' (uuid: acddcd3a-277c-4e91-9ddb-f6f8fa4a3336)
of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 (latest state: OPERATION_FINISHED,
status update state: OPERATION_FINISHED)
3: W1221 15:48:42.128319 24233 validation.cpp:1386] Executor 'default' for task '850f0f11-3247-4bd0-96d7-0c2be9dfbc44'
uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this
will be mandatory in future releases.
3: W1221 15:48:42.128353 24233 validation.cpp:1398] Executor 'default' for task '850f0f11-3247-4bd0-96d7-0c2be9dfbc44'
uses less memory (None) than the minimum required (32MB). Please update your executor, as
this will be mandatory in future releases.
3: I1221 15:48:42.128979 24233 master.cpp:11426] Adding task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44
with resources cpus(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):0.5; mem(allocated:
role)(reservations: [(DYNAMIC,role,test-principal)]):256 on agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0
at slave(1009)@172.17.0.3:42493 (67c59b4a59f4)
3: I1221 15:48:42.129329 24233 master.cpp:5025] Launching task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44
of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 (default) at scheduler-64251fa2-b046-4ba2-90b2-c6484580e7ea@172.17.0.3:42493
with resources [{"allocation_info":{"role":"role"},"name":"cpus","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":0.5},"type":"SCALAR"},{"allocation_info":{"role":"role"},"name":"mem","reservations":[{"principal":"test-principal","role":"role","type":"DYNAMIC"}],"scalar":{"value":256.0},"type":"SCALAR"}]
on agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0 at slave(1009)@172.17.0.3:42493 (67c59b4a59f4)
3: I1221 15:48:42.129992 24243 slave.cpp:1831] Got assigned task '850f0f11-3247-4bd0-96d7-0c2be9dfbc44'
for framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.130226 24233 master.cpp:10358] Updating the state of operation '' (uuid:
acddcd3a-277c-4e91-9ddb-f6f8fa4a3336) of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
(latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
3: I1221 15:48:42.130599 24243 slave.cpp:2101] Authorizing task '850f0f11-3247-4bd0-96d7-0c2be9dfbc44'
for framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.130655 24243 slave.cpp:7892] Authorizing framework principal 'test-principal'
to launch task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44
3: I1221 15:48:42.131583 24246 slave.cpp:2494] Launching task '850f0f11-3247-4bd0-96d7-0c2be9dfbc44'
for framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.132102 24246 paths.cpp:756] Trying to chown '/tmp/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_WigD41/slaves/a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0/frameworks/a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000/executors/default/runs/420998f0-a83c-4ee4-aaa7-070e28d9ae9a'
to user 'mesos'
3: I1221 15:48:42.132321 24246 slave.cpp:8366] Launching executor 'default' of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
with resources [] in work directory '/tmp/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_WigD41/slaves/a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0/frameworks/a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000/executors/default/runs/420998f0-a83c-4ee4-aaa7-070e28d9ae9a'
3: I1221 15:48:42.133194 24246 slave.cpp:2580] Queued task '850f0f11-3247-4bd0-96d7-0c2be9dfbc44'
for executor 'default' of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.133285 24246 slave.cpp:1006] Successfully attached '/tmp/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_WigD41/slaves/a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0/frameworks/a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000/executors/default/runs/420998f0-a83c-4ee4-aaa7-070e28d9ae9a'
to virtual path '/tmp/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_WigD41/slaves/a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0/frameworks/a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000/executors/default/runs/latest'
3: I1221 15:48:42.133337 24246 slave.cpp:1006] Successfully attached '/tmp/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_WigD41/slaves/a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0/frameworks/a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000/executors/default/runs/420998f0-a83c-4ee4-aaa7-070e28d9ae9a'
to virtual path '/frameworks/a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000/executors/default/runs/latest'
3: I1221 15:48:42.133641 24246 slave.cpp:3046] Launching container 420998f0-a83c-4ee4-aaa7-070e28d9ae9a
for executor 'default' of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.134160 24246 slave.cpp:1006] Successfully attached '/tmp/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_WigD41/slaves/a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0/frameworks/a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000/executors/default/runs/420998f0-a83c-4ee4-aaa7-070e28d9ae9a'
to virtual path '/tmp/ResourceProviderCapability_ReservationTest_ACLMultipleOperations_1_WigD41/slaves/a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0/frameworks/a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000/executors/default/runs/420998f0-a83c-4ee4-aaa7-070e28d9ae9a'
3: I1221 15:48:42.134999 24241 hierarchical.cpp:925] Updated allocation of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
on agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0 from cpus(allocated: role):1; mem(allocated:
role):512; disk(allocated: role):3701220; ports(allocated: role):[31000-32000]; cpus(allocated:
role)(reservations: [(DYNAMIC,role,test-principal)]):1; mem(allocated: role)(reservations:
[(DYNAMIC,role,test-principal)]):512 to cpus(allocated: role):0.5; mem(allocated: role):256;
disk(allocated: role):3701220; ports(allocated: role):[31000-32000]; cpus(allocated: role)(reservations:
[(DYNAMIC,role,test-principal)]):1.5; mem(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):768
3: W1221 15:48:42.136476 24237 process.cpp:2756] Attempted to spawn already running process
version@172.17.0.3:42493
3: I1221 15:48:42.136639 24237 exec.cpp:162] Version: 1.5.0
3: I1221 15:48:42.136905 24241 hierarchical.cpp:1192] Recovered cpus(allocated: role):0.5;
mem(allocated: role):256; disk(allocated: role):3701220; 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:0.5; mem:256; disk:3701220; ports:[31000-32000];
cpus(reservations: [(DYNAMIC,role,test-principal)]):1.5; mem(reservations: [(DYNAMIC,role,test-principal)]):768,
allocated: mem(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):256; cpus(allocated:
role)(reservations: [(DYNAMIC,role,test-principal)]):0.5) on agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0
from framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.136971 24245 exec.cpp:212] Executor started at: executor(223)@172.17.0.3:42493
with pid 17609
3: I1221 15:48:42.137411 24245 slave.cpp:4313] Got registration for executor 'default' of
framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 from executor(223)@172.17.0.3:42493
3: I1221 15:48:42.137845 24233 exec.cpp:237] Executor registered on agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0
3: I1221 15:48:42.137894 24233 exec.cpp:249] Executor::registered took 24690ns
3: I1221 15:48:42.138813 24238 slave.cpp:2785] Sending queued task '850f0f11-3247-4bd0-96d7-0c2be9dfbc44'
to executor 'default' of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 at executor(223)@172.17.0.3:42493
3: I1221 15:48:42.139165 24238 exec.cpp:331] Executor asked to run task '850f0f11-3247-4bd0-96d7-0c2be9dfbc44'
3: I1221 15:48:42.139245 24238 exec.cpp:340] Executor::launchTask took 62614ns
3: I1221 15:48:42.139333 24238 exec.cpp:571] Executor sending status update TASK_FINISHED
(Status UUID: 9bd92609-0d4a-49fd-b399-556e7dffafe2) for task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44
of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.139581 24238 slave.cpp:4770] Handling status update TASK_FINISHED (Status
UUID: 9bd92609-0d4a-49fd-b399-556e7dffafe2) for task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44
of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 from executor(223)@172.17.0.3:42493
3: I1221 15:48:42.140755 24247 task_status_update_manager.cpp:328] Received task status update
TASK_FINISHED (Status UUID: 9bd92609-0d4a-49fd-b399-556e7dffafe2) for task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44
of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.140792 24247 task_status_update_manager.cpp:507] Creating StatusUpdate stream
for task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44 of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.141168 24247 task_status_update_manager.cpp:383] Forwarding task status
update TASK_FINISHED (Status UUID: 9bd92609-0d4a-49fd-b399-556e7dffafe2) for task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44
of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 to the agent
3: I1221 15:48:42.141350 24234 slave.cpp:5253] Forwarding the update TASK_FINISHED (Status
UUID: 9bd92609-0d4a-49fd-b399-556e7dffafe2) for task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44
of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 to master@172.17.0.3:42493
3: I1221 15:48:42.141571 24234 slave.cpp:5146] Task status update manager successfully handled
status update TASK_FINISHED (Status UUID: 9bd92609-0d4a-49fd-b399-556e7dffafe2) for task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44
of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.141620 24234 slave.cpp:5162] Sending acknowledgement for status update TASK_FINISHED
(Status UUID: 9bd92609-0d4a-49fd-b399-556e7dffafe2) for task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44
of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 to executor(223)@172.17.0.3:42493
3: I1221 15:48:42.141726 24237 master.cpp:7850] Status update TASK_FINISHED (Status UUID:
9bd92609-0d4a-49fd-b399-556e7dffafe2) for task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44 of framework
a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 from agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0
at slave(1009)@172.17.0.3:42493 (67c59b4a59f4)
3: I1221 15:48:42.141786 24244 exec.cpp:388] Executor received status update acknowledgement
9bd92609-0d4a-49fd-b399-556e7dffafe2 for task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44 of framework
a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.141783 24237 master.cpp:7906] Forwarding status update TASK_FINISHED (Status
UUID: 9bd92609-0d4a-49fd-b399-556e7dffafe2) for task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44
of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.141968 24237 master.cpp:10153] Updating the state of task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44
of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000 (latest state: TASK_FINISHED, status
update state: TASK_FINISHED)
3: I1221 15:48:42.142282 24233 sched.cpp:1029] Scheduler::statusUpdate took 70749ns
3: I1221 15:48:42.142649 24235 master.cpp:5843] Processing ACKNOWLEDGE call 9bd92609-0d4a-49fd-b399-556e7dffafe2
for task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44 of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
(default) at scheduler-64251fa2-b046-4ba2-90b2-c6484580e7ea@172.17.0.3:42493 on agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0
3: I1221 15:48:42.142839 24235 master.cpp:10259] Removing task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44
with resources cpus(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):0.5; mem(allocated:
role)(reservations: [(DYNAMIC,role,test-principal)]):256 of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
on agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0 at slave(1009)@172.17.0.3:42493 (67c59b4a59f4)
3: I1221 15:48:42.143298 24245 hierarchical.cpp:1192] Recovered cpus(allocated: role)(reservations:
[(DYNAMIC,role,test-principal)]):0.5; mem(allocated: role)(reservations: [(DYNAMIC,role,test-principal)]):256
(total: cpus:0.5; mem:256; disk:3701220; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,role,test-principal)]):1.5;
mem(reservations: [(DYNAMIC,role,test-principal)]):768, allocated: {}) on agent a38af167-ca31-4de2-9ae7-be6a90bebfd8-S0
from framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.143373 24236 task_status_update_manager.cpp:401] Received task status update
acknowledgement (UUID: 9bd92609-0d4a-49fd-b399-556e7dffafe2) for task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44
of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
3: I1221 15:48:42.143465 24236 task_status_update_manager.cpp:538] Cleaning up status update
stream for task 850f0f11-3247-4bd0-96d7-0c2be9dfbc44 of framework a38af167-ca31-4de2-9ae7-be6a90bebfd8-0000
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1513868588-8876
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user toenshoff@me.com


Mime
View raw message