You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2017/11/13 10:59:11 UTC
Build failed in Jenkins: Mesos-Buildbot » cmake,clang,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4447
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4447/display/redirect?page=changes>
Changes:
[alexr] Expanded description of the --recovery_timeout flag.
------------------------------------------
[...truncated 19.72 MB...]
3: I1113 10:59:00.050108 18287 slave.cpp:5120] Got exited event for executor(172)@172.17.0.2:37147
3: I1113 10:59:00.050158 18276 master.cpp:9626] Removing executor 'default' with resources [] of framework 273c248d-e734-4ab3-a67a-726dcb1fdf40-0000 on agent 273c248d-e734-4ab3-a67a-726dcb1fdf40-S0 at slave(498)@172.17.0.2:37147 (2451cb799b85)
3: I1113 10:59:00.050871 18277 hierarchical.cpp:355] Removed framework 273c248d-e734-4ab3-a67a-726dcb1fdf40-0000
3: I1113 10:59:00.050971 18285 slave.cpp:5520] Executor 'default' of framework 273c248d-e734-4ab3-a67a-726dcb1fdf40-0000 exited with status 0
3: I1113 10:59:00.051110 18285 slave.cpp:5624] Cleaning up executor 'default' of framework 273c248d-e734-4ab3-a67a-726dcb1fdf40-0000 at executor(172)@172.17.0.2:37147
3: W1113 10:59:00.051241 18267 master.cpp:7454] Ignoring unknown exited executor 'default' of framework 273c248d-e734-4ab3-a67a-726dcb1fdf40-0000 on agent 273c248d-e734-4ab3-a67a-726dcb1fdf40-S0 at slave(498)@172.17.0.2:37147 (2451cb799b85)
3: I1113 10:59:00.051357 18272 gc.cpp:90] Scheduling '/tmp/ReconciliationTest_UnacknowledgedTerminalTask_Xwp2TJ/slaves/273c248d-e734-4ab3-a67a-726dcb1fdf40-S0/frameworks/273c248d-e734-4ab3-a67a-726dcb1fdf40-0000/executors/default/runs/ff933ace-e54c-4460-b321-96906496a525' for gc 6.99999940659852days in the future
3: I1113 10:59:00.051620 18285 slave.cpp:5731] Cleaning up framework 273c248d-e734-4ab3-a67a-726dcb1fdf40-0000
3: I1113 10:59:00.051643 18290 gc.cpp:90] Scheduling '/tmp/ReconciliationTest_UnacknowledgedTerminalTask_Xwp2TJ/slaves/273c248d-e734-4ab3-a67a-726dcb1fdf40-S0/frameworks/273c248d-e734-4ab3-a67a-726dcb1fdf40-0000/executors/default' for gc 6.99999940371556days in the future
3: I1113 10:59:00.051757 18276 status_update_manager.cpp:285] Closing status update streams for framework 273c248d-e734-4ab3-a67a-726dcb1fdf40-0000
3: I1113 10:59:00.051828 18276 status_update_manager.cpp:531] Cleaning up status update stream for task 0 of framework 273c248d-e734-4ab3-a67a-726dcb1fdf40-0000
3: I1113 10:59:00.051856 18287 gc.cpp:90] Scheduling '/tmp/ReconciliationTest_UnacknowledgedTerminalTask_Xwp2TJ/slaves/273c248d-e734-4ab3-a67a-726dcb1fdf40-S0/frameworks/273c248d-e734-4ab3-a67a-726dcb1fdf40-0000' for gc 6.9999994009037days in the future
3: I1113 10:59:00.051882 18285 slave.cpp:883] Agent terminating
3: I1113 10:59:00.052098 18274 master.cpp:1309] Agent 273c248d-e734-4ab3-a67a-726dcb1fdf40-S0 at slave(498)@172.17.0.2:37147 (2451cb799b85) disconnected
3: I1113 10:59:00.052122 18274 master.cpp:3369] Disconnecting agent 273c248d-e734-4ab3-a67a-726dcb1fdf40-S0 at slave(498)@172.17.0.2:37147 (2451cb799b85)
3: I1113 10:59:00.052165 18274 master.cpp:3388] Deactivating agent 273c248d-e734-4ab3-a67a-726dcb1fdf40-S0 at slave(498)@172.17.0.2:37147 (2451cb799b85)
3: I1113 10:59:00.052300 18283 hierarchical.cpp:690] Agent 273c248d-e734-4ab3-a67a-726dcb1fdf40-S0 deactivated
3: I1113 10:59:00.056491 18266 master.cpp:1151] Master terminating
3: I1113 10:59:00.057328 18278 hierarchical.cpp:626] Removed agent 273c248d-e734-4ab3-a67a-726dcb1fdf40-S0
3: [ OK ] ReconciliationTest.UnacknowledgedTerminalTask (75 ms)
3: [ RUN ] ReconciliationTest.ReconcileStatusUpdateTaskState
3: I1113 10:59:00.065882 18266 cluster.cpp:162] Creating default 'local' authorizer
3: I1113 10:59:00.069669 18276 master.cpp:448] Master c146ba54-e343-4a23-be62-bd83939c1516 (2451cb799b85) started on 172.17.0.2:37147
3: I1113 10:59:00.069717 18276 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/1XkgfZ/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/1XkgfZ/master" --zk_session_timeout="10secs"
3: I1113 10:59:00.070085 18276 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1113 10:59:00.070094 18276 master.cpp:505] Master only allowing authenticated agents to register
3: I1113 10:59:00.070099 18276 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1113 10:59:00.070106 18276 credentials.hpp:37] Loading credentials for authentication from '/tmp/1XkgfZ/credentials'
3: I1113 10:59:00.070444 18276 master.cpp:555] Using default 'crammd5' authenticator
3: I1113 10:59:00.070618 18276 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1113 10:59:00.070798 18276 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1113 10:59:00.070962 18276 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1113 10:59:00.071112 18276 master.cpp:634] Authorization enabled
3: I1113 10:59:00.071283 18268 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1113 10:59:00.071300 18286 whitelist_watcher.cpp:77] No whitelist given
3: I1113 10:59:00.074681 18272 master.cpp:2213] Elected as the leading master!
3: I1113 10:59:00.074707 18272 master.cpp:1693] Recovering from registrar
3: I1113 10:59:00.074858 18282 registrar.cpp:347] Recovering registrar
3: I1113 10:59:00.075520 18282 registrar.cpp:391] Successfully fetched the registry (0B) in 619008ns
3: I1113 10:59:00.075654 18282 registrar.cpp:495] Applied 1 operations in 45276ns; attempting to update the registry
3: I1113 10:59:00.076292 18282 registrar.cpp:552] Successfully updated the registry in 572928ns
3: I1113 10:59:00.076442 18282 registrar.cpp:424] Successfully recovered registrar
3: I1113 10:59:00.076879 18273 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1113 10:59:00.076925 18283 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1113 10:59:00.082839 18266 process.cpp:3178] Attempted to spawn already running process files@172.17.0.2:37147
3: I1113 10:59:00.083189 18266 cluster.cpp:448] Creating default 'local' authorizer
3: I1113 10:59:00.085913 18290 slave.cpp:262] Mesos agent started on (499)@172.17.0.2:37147
3: I1113 10:59:00.085952 18290 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_Z5ssaC/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/ReconciliationTest_ReconcileStatusUpdateTaskState_Z5ssaC/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/ReconciliationTest_ReconcileStatusUpdateTaskState_Z5ssaC/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/ReconciliationTest_ReconcileStatusUpdateTaskState_Z5ssaC/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_Z5ssaC/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/ReconciliationTest_ReconcileStatusUpdateTaskState_Z5ssaC/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/ReconciliationTest_ReconcileStatusUpdateTaskState_Z5ssaC" --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/ReconciliationTest_ReconcileStatusUpdateTaskState_qAXQHN" --zk_session_timeout="10secs"
3: I1113 10:59:00.086406 18290 credentials.hpp:86] Loading credential for authentication from '/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_Z5ssaC/credential'
3: I1113 10:59:00.086575 18290 slave.cpp:295] Agent using credential for: test-principal
3: I1113 10:59:00.086596 18290 credentials.hpp:37] Loading credentials for authentication from '/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_Z5ssaC/http_credentials'
3: I1113 10:59:00.086923 18290 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1113 10:59:00.087061 18290 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: W1113 10:59:00.087296 18266 process.cpp:3178] Attempted to spawn already running process version@172.17.0.2:37147
3: I1113 10:59:00.087340 18290 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1113 10:59:00.087479 18290 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1113 10:59:00.087728 18290 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1113 10:59:00.087852 18290 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1113 10:59:00.088615 18266 sched.cpp:232] Version: 1.5.0
3: I1113 10:59:00.089399 18287 sched.cpp:336] New master detected at master@172.17.0.2:37147
3: I1113 10:59:00.089561 18287 sched.cpp:396] Authenticating with master master@172.17.0.2:37147
3: I1113 10:59:00.089586 18287 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1113 10:59:00.089627 18290 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: I1113 10:59:00.089889 18290 slave.cpp:601] Agent attributes: [ ]
3: I1113 10:59:00.089900 18290 slave.cpp:610] Agent hostname: 2451cb799b85
3: I1113 10:59:00.089984 18285 authenticatee.cpp:121] Creating new client SASL connection
3: I1113 10:59:00.090247 18287 status_update_manager.cpp:177] Pausing sending status updates
3: I1113 10:59:00.090366 18278 master.cpp:8286] Authenticating scheduler-64a9cba7-647b-44fa-9fb9-4acc8329a6ce@172.17.0.2:37147
3: I1113 10:59:00.090404 18281 hierarchical.cpp:1450] Performed allocation for 0 agents in 77518ns
3: I1113 10:59:00.090503 18282 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1021)@172.17.0.2:37147
3: I1113 10:59:00.090868 18283 authenticator.cpp:98] Creating new server SASL connection
3: I1113 10:59:00.091132 18273 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1113 10:59:00.091161 18273 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1113 10:59:00.091286 18268 authenticator.cpp:204] Received SASL authentication start
3: I1113 10:59:00.091356 18268 authenticator.cpp:326] Authentication requires more steps
3: I1113 10:59:00.091528 18269 authenticatee.cpp:259] Received SASL authentication step
3: I1113 10:59:00.091677 18269 authenticator.cpp:232] Received SASL authentication step
3: I1113 10:59:00.091712 18269 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2451cb799b85' server FQDN: '2451cb799b85' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1113 10:59:00.091733 18269 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1113 10:59:00.091770 18276 state.cpp:64] Recovering state from '/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_qAXQHN/meta'
3: I1113 10:59:00.091775 18269 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1113 10:59:00.091820 18269 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2451cb799b85' server FQDN: '2451cb799b85' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1113 10:59:00.091837 18269 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1113 10:59:00.091848 18269 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1113 10:59:00.091871 18269 authenticator.cpp:318] Authentication success
3: I1113 10:59:00.092066 18284 authenticatee.cpp:299] Authentication success
3: I1113 10:59:00.092154 18279 master.cpp:8316] Successfully authenticated principal 'test-principal' at scheduler-64a9cba7-647b-44fa-9fb9-4acc8329a6ce@172.17.0.2:37147
3: I1113 10:59:00.092183 18280 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1021)@172.17.0.2:37147
3: I1113 10:59:00.092211 18275 status_update_manager.cpp:203] Recovering status update manager
3: I1113 10:59:00.092581 18277 sched.cpp:502] Successfully authenticated with master master@172.17.0.2:37147
3: I1113 10:59:00.092620 18277 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:37147
3: I1113 10:59:00.092671 18270 slave.cpp:6422] Finished recovery
3: I1113 10:59:00.092790 18277 sched.cpp:857] Will retry registration in 951.52971ms if necessary
3: I1113 10:59:00.093017 18267 master.cpp:2962] Received SUBSCRIBE call for framework 'default' at scheduler-64a9cba7-647b-44fa-9fb9-4acc8329a6ce@172.17.0.2:37147
3: I1113 10:59:00.093053 18267 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1113 10:59:00.093407 18267 status_update_manager.cpp:177] Pausing sending status updates
3: I1113 10:59:00.093410 18289 slave.cpp:1007] New master detected at master@172.17.0.2:37147
3: I1113 10:59:00.093520 18289 slave.cpp:1042] Detecting new master
3: I1113 10:59:00.093693 18290 master.cpp:3042] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1113 10:59:00.093818 18289 slave.cpp:1069] Authenticating with master master@172.17.0.2:37147
3: I1113 10:59:00.093883 18289 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1113 10:59:00.094113 18276 authenticatee.cpp:121] Creating new client SASL connection
3: I1113 10:59:00.094331 18290 sched.cpp:751] Framework registered with c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.094378 18290 sched.cpp:765] Scheduler::registered took 27719ns
3: I1113 10:59:00.094420 18274 master.cpp:8286] Authenticating slave(499)@172.17.0.2:37147
3: I1113 10:59:00.094502 18288 hierarchical.cpp:303] Added framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.094558 18275 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1022)@172.17.0.2:37147
3: I1113 10:59:00.094759 18288 hierarchical.cpp:1450] Performed allocation for 0 agents in 100247ns
3: I1113 10:59:00.094825 18280 authenticator.cpp:98] Creating new server SASL connection
3: I1113 10:59:00.095044 18285 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1113 10:59:00.095077 18285 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1113 10:59:00.095197 18285 authenticator.cpp:204] Received SASL authentication start
3: I1113 10:59:00.095249 18285 authenticator.cpp:326] Authentication requires more steps
3: I1113 10:59:00.095363 18285 authenticatee.cpp:259] Received SASL authentication step
3: I1113 10:59:00.095492 18285 authenticator.cpp:232] Received SASL authentication step
3: I1113 10:59:00.095526 18285 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2451cb799b85' server FQDN: '2451cb799b85' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1113 10:59:00.095541 18285 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1113 10:59:00.095567 18285 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1113 10:59:00.095595 18285 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2451cb799b85' server FQDN: '2451cb799b85' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1113 10:59:00.095608 18285 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1113 10:59:00.095614 18285 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1113 10:59:00.095628 18285 authenticator.cpp:318] Authentication success
3: I1113 10:59:00.095767 18281 authenticatee.cpp:299] Authentication success
3: I1113 10:59:00.095813 18270 master.cpp:8316] Successfully authenticated principal 'test-principal' at slave(499)@172.17.0.2:37147
3: I1113 10:59:00.095881 18277 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1022)@172.17.0.2:37147
3: I1113 10:59:00.096081 18283 slave.cpp:1161] Successfully authenticated with master master@172.17.0.2:37147
3: I1113 10:59:00.096319 18283 slave.cpp:1682] Will retry registration in 9.638641ms if necessary
3: I1113 10:59:00.096501 18286 master.cpp:6033] Received register agent message from slave(499)@172.17.0.2:37147 (2451cb799b85)
3: I1113 10:59:00.096539 18286 master.cpp:3871] Authorizing agent with principal 'test-principal'
3: I1113 10:59:00.096949 18284 master.cpp:6093] Authorized registration of agent at slave(499)@172.17.0.2:37147 (2451cb799b85)
3: I1113 10:59:00.097057 18284 master.cpp:6186] Registering agent at slave(499)@172.17.0.2:37147 (2451cb799b85) with id c146ba54-e343-4a23-be62-bd83939c1516-S0
3: I1113 10:59:00.097451 18269 registrar.cpp:495] Applied 1 operations in 73469ns; attempting to update the registry
3: I1113 10:59:00.098023 18269 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1113 10:59:00.098233 18274 master.cpp:6233] Admitted agent c146ba54-e343-4a23-be62-bd83939c1516-S0 at slave(499)@172.17.0.2:37147 (2451cb799b85)
3: I1113 10:59:00.098999 18288 slave.cpp:1207] Registered with master master@172.17.0.2:37147; given agent ID c146ba54-e343-4a23-be62-bd83939c1516-S0
3: I1113 10:59:00.098845 18274 master.cpp:6264] Registered agent c146ba54-e343-4a23-be62-bd83939c1516-S0 at slave(499)@172.17.0.2:37147 (2451cb799b85) 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: I1113 10:59:00.099136 18282 status_update_manager.cpp:184] Resuming sending status updates
3: I1113 10:59:00.099427 18288 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_qAXQHN/meta/slaves/c146ba54-e343-4a23-be62-bd83939c1516-S0/slave.info'
3: I1113 10:59:00.099443 18280 hierarchical.cpp:593] Added agent c146ba54-e343-4a23-be62-bd83939c1516-S0 (2451cb799b85) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1113 10:59:00.099968 18288 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1113 10:59:00.100194 18278 master.cpp:7065] Received update of agent c146ba54-e343-4a23-be62-bd83939c1516-S0 at slave(499)@172.17.0.2:37147 (2451cb799b85) with total oversubscribed resources {}
3: I1113 10:59:00.100364 18278 master.cpp:7083] Ignoring update on agent c146ba54-e343-4a23-be62-bd83939c1516-S0 at slave(499)@172.17.0.2:37147 (2451cb799b85) as it reports no changes
3: I1113 10:59:00.100903 18280 hierarchical.cpp:1450] Performed allocation for 1 agents in 1.256613ms
3: I1113 10:59:00.101611 18285 master.cpp:8116] Sending 1 offers to framework c146ba54-e343-4a23-be62-bd83939c1516-0000 (default) at scheduler-64a9cba7-647b-44fa-9fb9-4acc8329a6ce@172.17.0.2:37147
3: I1113 10:59:00.103317 18281 sched.cpp:921] Scheduler::resourceOffers took 1.102796ms
3: I1113 10:59:00.104997 18270 master.cpp:10016] Removing offer c146ba54-e343-4a23-be62-bd83939c1516-O0
3: I1113 10:59:00.105253 18270 master.cpp:4229] Processing ACCEPT call for offers: [ c146ba54-e343-4a23-be62-bd83939c1516-O0 ] on agent c146ba54-e343-4a23-be62-bd83939c1516-S0 at slave(499)@172.17.0.2:37147 (2451cb799b85) for framework c146ba54-e343-4a23-be62-bd83939c1516-0000 (default) at scheduler-64a9cba7-647b-44fa-9fb9-4acc8329a6ce@172.17.0.2:37147
3: I1113 10:59:00.105376 18270 master.cpp:3598] Authorizing framework principal 'test-principal' to launch task 0
3: W1113 10:59:00.107633 18270 validation.cpp:1404] Executor 'default' for task '0' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
3: W1113 10:59:00.107674 18270 validation.cpp:1416] Executor 'default' for task '0' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
3: I1113 10:59:00.108166 18270 master.cpp:10762] Adding task 0 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}] on agent c146ba54-e343-4a23-be62-bd83939c1516-S0 at slave(499)@172.17.0.2:37147 (2451cb799b85)
3: I1113 10:59:00.108659 18270 master.cpp:4977] Launching task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000 (default) at scheduler-64a9cba7-647b-44fa-9fb9-4acc8329a6ce@172.17.0.2:37147 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}] on agent c146ba54-e343-4a23-be62-bd83939c1516-S0 at slave(499)@172.17.0.2:37147 (2451cb799b85)
3: I1113 10:59:00.109344 18268 slave.cpp:1803] Got assigned task '0' for framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.109700 18283 hierarchical.cpp:1125] Recovered ports(allocated: *):[31000-32000]; disk(allocated: *):1024 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: cpus(allocated: *):2; mem(allocated: *):1024) on agent c146ba54-e343-4a23-be62-bd83939c1516-S0 from framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.109763 18283 hierarchical.cpp:1171] Framework c146ba54-e343-4a23-be62-bd83939c1516-0000 filtered agent c146ba54-e343-4a23-be62-bd83939c1516-S0 for 5secs
3: I1113 10:59:00.110170 18268 slave.cpp:2071] Authorizing task '0' for framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.110255 18268 slave.cpp:7030] Authorizing framework principal 'test-principal' to launch task 0
3: I1113 10:59:00.111158 18279 slave.cpp:2239] Launching task '0' for framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.111675 18279 paths.cpp:605] Trying to chown '/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_qAXQHN/slaves/c146ba54-e343-4a23-be62-bd83939c1516-S0/frameworks/c146ba54-e343-4a23-be62-bd83939c1516-0000/executors/default/runs/03d2d585-9ed0-49d0-86b7-b2334893aff6' to user 'mesos'
3: I1113 10:59:00.111876 18279 slave.cpp:7504] Launching executor 'default' of framework c146ba54-e343-4a23-be62-bd83939c1516-0000 with resources [] in work directory '/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_qAXQHN/slaves/c146ba54-e343-4a23-be62-bd83939c1516-S0/frameworks/c146ba54-e343-4a23-be62-bd83939c1516-0000/executors/default/runs/03d2d585-9ed0-49d0-86b7-b2334893aff6'
3: I1113 10:59:00.112639 18279 slave.cpp:2467] Queued task '0' for executor 'default' of framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.112720 18279 slave.cpp:958] Successfully attached '/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_qAXQHN/slaves/c146ba54-e343-4a23-be62-bd83939c1516-S0/frameworks/c146ba54-e343-4a23-be62-bd83939c1516-0000/executors/default/runs/03d2d585-9ed0-49d0-86b7-b2334893aff6' to virtual path '/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_qAXQHN/slaves/c146ba54-e343-4a23-be62-bd83939c1516-S0/frameworks/c146ba54-e343-4a23-be62-bd83939c1516-0000/executors/default/runs/latest'
3: I1113 10:59:00.112757 18279 slave.cpp:958] Successfully attached '/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_qAXQHN/slaves/c146ba54-e343-4a23-be62-bd83939c1516-S0/frameworks/c146ba54-e343-4a23-be62-bd83939c1516-0000/executors/default/runs/03d2d585-9ed0-49d0-86b7-b2334893aff6' to virtual path '/frameworks/c146ba54-e343-4a23-be62-bd83939c1516-0000/executors/default/runs/latest'
3: I1113 10:59:00.112788 18279 slave.cpp:958] Successfully attached '/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_qAXQHN/slaves/c146ba54-e343-4a23-be62-bd83939c1516-S0/frameworks/c146ba54-e343-4a23-be62-bd83939c1516-0000/executors/default/runs/03d2d585-9ed0-49d0-86b7-b2334893aff6' to virtual path '/tmp/ReconciliationTest_ReconcileStatusUpdateTaskState_qAXQHN/slaves/c146ba54-e343-4a23-be62-bd83939c1516-S0/frameworks/c146ba54-e343-4a23-be62-bd83939c1516-0000/executors/default/runs/03d2d585-9ed0-49d0-86b7-b2334893aff6'
3: I1113 10:59:00.113003 18279 slave.cpp:2930] Launching container 03d2d585-9ed0-49d0-86b7-b2334893aff6 for executor 'default' of framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: W1113 10:59:00.115290 18287 process.cpp:3178] Attempted to spawn already running process version@172.17.0.2:37147
3: I1113 10:59:00.115458 18287 exec.cpp:162] Version: 1.5.0
3: I1113 10:59:00.115661 18275 exec.cpp:212] Executor started at: executor(173)@172.17.0.2:37147 with pid 18266
3: I1113 10:59:00.115845 18272 slave.cpp:4053] Got registration for executor 'default' of framework c146ba54-e343-4a23-be62-bd83939c1516-0000 from executor(173)@172.17.0.2:37147
3: I1113 10:59:00.116202 18274 exec.cpp:237] Executor registered on agent c146ba54-e343-4a23-be62-bd83939c1516-S0
3: I1113 10:59:00.116250 18274 exec.cpp:249] Executor::registered took 31292ns
3: I1113 10:59:00.116555 18272 slave.cpp:2669] Sending queued task '0' to executor 'default' of framework c146ba54-e343-4a23-be62-bd83939c1516-0000 at executor(173)@172.17.0.2:37147
3: I1113 10:59:00.116873 18288 exec.cpp:331] Executor asked to run task '0'
3: I1113 10:59:00.116955 18288 exec.cpp:340] Executor::launchTask took 70654ns
3: I1113 10:59:00.117063 18288 exec.cpp:571] Executor sending status update TASK_RUNNING (UUID: 5d131297-039d-4a3e-bf4e-1de85f6ec42a) for task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.117373 18278 slave.cpp:4507] Handling status update TASK_RUNNING (UUID: 5d131297-039d-4a3e-bf4e-1de85f6ec42a) for task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000 from executor(173)@172.17.0.2:37147
3: I1113 10:59:00.118001 18281 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: 5d131297-039d-4a3e-bf4e-1de85f6ec42a) for task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.118069 18281 status_update_manager.cpp:500] Creating StatusUpdate stream for task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.118639 18281 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 5d131297-039d-4a3e-bf4e-1de85f6ec42a) for task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000 to the agent
3: I1113 10:59:00.118990 18273 slave.cpp:4988] Forwarding the update TASK_RUNNING (UUID: 5d131297-039d-4a3e-bf4e-1de85f6ec42a) for task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000 to master@172.17.0.2:37147
3: I1113 10:59:00.119704 18273 slave.cpp:4882] Status update manager successfully handled status update TASK_RUNNING (UUID: 5d131297-039d-4a3e-bf4e-1de85f6ec42a) for task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.119779 18273 slave.cpp:4898] Sending acknowledgement for status update TASK_RUNNING (UUID: 5d131297-039d-4a3e-bf4e-1de85f6ec42a) for task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000 to executor(173)@172.17.0.2:37147
3: I1113 10:59:00.120005 18277 exec.cpp:388] Executor received status update acknowledgement 5d131297-039d-4a3e-bf4e-1de85f6ec42a for task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.120427 18271 exec.cpp:571] Executor sending status update TASK_FINISHED (UUID: d9798d03-c322-4199-9e85-0c08296ef99d) for task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.120744 18270 slave.cpp:4507] Handling status update TASK_FINISHED (UUID: d9798d03-c322-4199-9e85-0c08296ef99d) for task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000 from executor(173)@172.17.0.2:37147
3: I1113 10:59:00.121639 18268 status_update_manager.cpp:323] Received status update TASK_FINISHED (UUID: d9798d03-c322-4199-9e85-0c08296ef99d) for task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.121953 18286 slave.cpp:4882] Status update manager successfully handled status update TASK_FINISHED (UUID: d9798d03-c322-4199-9e85-0c08296ef99d) for task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.122016 18286 slave.cpp:4898] Sending acknowledgement for status update TASK_FINISHED (UUID: d9798d03-c322-4199-9e85-0c08296ef99d) for task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000 to executor(173)@172.17.0.2:37147
3: I1113 10:59:00.122196 18284 exec.cpp:388] Executor received status update acknowledgement d9798d03-c322-4199-9e85-0c08296ef99d for task 0 of framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.122423 18266 master.cpp:1151] Master terminating
3: W1113 10:59:00.122532 18266 master.cpp:9583] Removing task 0 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}] of framework c146ba54-e343-4a23-be62-bd83939c1516-0000 on agent c146ba54-e343-4a23-be62-bd83939c1516-S0 at slave(499)@172.17.0.2:37147 (2451cb799b85) in non-removable state TASK_STAGING
3: I1113 10:59:00.122984 18275 hierarchical.cpp:626] Removed agent c146ba54-e343-4a23-be62-bd83939c1516-S0
3: I1113 10:59:00.123246 18266 master.cpp:9626] Removing executor 'default' with resources [] of framework c146ba54-e343-4a23-be62-bd83939c1516-0000 on agent c146ba54-e343-4a23-be62-bd83939c1516-S0 at slave(499)@172.17.0.2:37147 (2451cb799b85)
3: I1113 10:59:00.124016 18288 hierarchical.cpp:355] Removed framework c146ba54-e343-4a23-be62-bd83939c1516-0000
3: I1113 10:59:00.124259 18277 slave.cpp:5120] Got exited event for master@172.17.0.2:37147
3: W1113 10:59:00.124289 18277 slave.cpp:5125] Master disconnected! Waiting for a new master to be elected
3: I1113 10:59:00.130571 18266 cluster.cpp:162] Creating default 'local' authorizer
3: I1113 10:59:00.134351 18268 master.cpp:448] Master 8028dffc-909f-465c-be42-2ad6e0a8f0fa (2451cb799b85) started on 172.17.0.2:37147
3: I1113 10:59:00.134398 18268 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/1XkgfZ/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/1XkgfZ/master" --zk_session_timeout="10secs"
3: I1113 10:59:00.134790 18268 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1113 10:59:00.134799 18268 master.cpp:505] Master only allowing authenticated agents to register
3: I1113 10:59:00.134804 18268 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1113 10:59:00.134809 18268 credentials.hpp:37] Loading credentials for authentication from '/tmp/1XkgfZ/credentials'
3: I1113 10:59:00.135083 18268 master.cpp:555] Using default 'crammd5' authenticator
3: I1113 10:59:00.135222 18268 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1113 10:59:00.135373 18268 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1113 10:59:00.135509 18268 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1113 10:59:00.135630 18268 master.cpp:634] Authorization enabled
3: I1113 10:59:00.135831 18287 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1113 10:59:00.135875 18275 whitelist_watcher.cpp:77] No whitelist given
3: I1113 10:59:00.138811 18267 master.cpp:2213] Elected as the leading master!
3: I1113 10:59:00.138829 18267 master.cpp:1693] Recovering from registrar
3: I1113 10:59:00.138964 18285 registrar.cpp:347] Recovering registrar
3: I1113 10:59:00.139426 18285 registrar.cpp:391] Successfully fetched the registry (0B) in 0ns
3: I1113 10:59:00.139510 18285 registrar.cpp:495] Applied 1 operations in 30037ns; attempting to update the registry
3: I1113 10:59:00.139943 18285 registrar.cpp:552] Successfully updated the registry in 0ns
3: I1113 10:59:00.140045 18285 registrar.cpp:424] Successfully recovered registrar
3: I1113 10:59:00.140350 18279 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1113 10:59:00.140378 18290 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: I1113 10:59:00.141041 18287 sched.cpp:330] Scheduler::disconnected took 25259ns
3: I1113 10:59:00.141062 18287 sched.cpp:336] New master detected at master@172.17.0.2:37147
3: I1113 10:59:00.141177 18287 sched.cpp:396] Authenticating with master master@172.17.0.2:37147
3: I1113 10:59:00.141194 18287 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1113 10:59:00.141505 18269 authenticatee.cpp:121] Creating new client SASL connection
3: I1113 10:59:00.141907 18283 master.cpp:8286] Authenticating scheduler-64a9cba7-647b-44fa-9fb9-4acc8329a6ce@172.17.0.2:37147
3: I1113 10:59:00.142065 18289 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1023)@172.17.0.2:37147
3: I1113 10:59:00.142279 18268 authenticator.cpp:98] Creating new server SASL connection
3: I1113 10:59:00.142488 18272 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1113 10:59:00.142510 18272 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1113 10:59:00.142594 18272 authenticator.cpp:204] Received SASL authentication start
3: I1113 10:59:00.142635 18272 authenticator.cpp:326] Authentication requires more steps
3: I1113 10:59:00.142730 18267 authenticatee.cpp:259] Received SASL authentication step
3: I1113 10:59:00.142853 18278 authenticator.cpp:232] Received SASL authentication step
3: I1113 10:59:00.142881 18278 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2451cb799b85' server FQDN: '2451cb799b85' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1113 10:59:00.142891 18278 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1113 10:59:00.142916 18278 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1113 10:59:00.142935 18278 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2451cb799b85' server FQDN: '2451cb799b85' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1113 10:59:00.142941 18278 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1113 10:59:00.142946 18278 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1113 10:59:00.142957 18278 authenticator.cpp:318] Authentication success
3: I1113 10:59:00.143044 18280 authenticatee.cpp:299] Authentication success
3: I1113 10:59:00.143085 18288 master.cpp:8316] Successfully authenticated principal 'test-principal' at scheduler-64a9cba7-647b-44fa-9fb9-4acc8329a6ce@172.17.0.2:37147
3: I1113 10:59:00.143121 18273 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1023)@172.17.0.2:37147
3: I1113 10:59:00.143271 18278 sched.cpp:502] Successfully authenticated with master master@172.17.0.2:37147
3: I1113 10:59:00.143287 18278 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:37147
3: I1113 10:59:00.143393 18278 sched.cpp:857] Will retry registration in 812.858576ms if necessary
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1510568570-22780
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos-Buildbot » cmake,clang,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4449
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4449/display/redirect?page=changes>
Build failed in Jenkins: Mesos-Buildbot » cmake,clang,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4448
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4448/display/redirect?page=changes>
Changes:
[yujie.jay] Provided handling for offer operation updates.
[yujie.jay] Added test helpers for storage operations.
[yujie.jay] Added a test for resource conversion using a resource provider.
------------------------------------------
[...truncated 13.37 MB...]
3: I1113 18:44:47.799698 18267 authenticator.cpp:232] Received SASL authentication step
3: I1113 18:44:47.799742 18267 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '07cc01e6260b' server FQDN: '07cc01e6260b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1113 18:44:47.799759 18267 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1113 18:44:47.799809 18267 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1113 18:44:47.799837 18267 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '07cc01e6260b' server FQDN: '07cc01e6260b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1113 18:44:47.799851 18267 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1113 18:44:47.799860 18267 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1113 18:44:47.799880 18267 authenticator.cpp:318] Authentication success
3: I1113 18:44:47.800048 18286 authenticatee.cpp:299] Authentication success
3: I1113 18:44:47.800103 18277 master.cpp:8316] Successfully authenticated principal 'test-principal' at slave(275)@172.17.0.4:38479
3: I1113 18:44:47.800204 18282 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(565)@172.17.0.4:38479
3: I1113 18:44:47.803978 18265 slave.cpp:1161] Successfully authenticated with master master@172.17.0.4:38479
3: I1113 18:44:47.804600 18265 slave.cpp:1682] Will retry registration in 282154ns if necessary
3: I1113 18:44:47.805194 18285 master.cpp:6033] Received register agent message from slave(275)@172.17.0.4:38479 (07cc01e6260b)
3: I1113 18:44:47.805290 18285 master.cpp:3871] Authorizing agent with principal 'test-principal'
3: I1113 18:44:47.805903 18269 master.cpp:6093] Authorized registration of agent at slave(275)@172.17.0.4:38479 (07cc01e6260b)
3: I1113 18:44:47.806049 18269 master.cpp:6186] Registering agent at slave(275)@172.17.0.4:38479 (07cc01e6260b) with id 38224e03-633a-4450-a1be-414985663bda-S0
3: I1113 18:44:47.806829 18266 registrar.cpp:495] Applied 1 operations in 229212ns; attempting to update the registry
3: I1113 18:44:47.808504 18266 registrar.cpp:552] Successfully updated the registry in 1.261056ms
3: I1113 18:44:47.808871 18278 slave.cpp:1682] Will retry registration in 9.047956ms if necessary
3: I1113 18:44:47.808895 18284 master.cpp:6233] Admitted agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b)
3: I1113 18:44:47.810271 18279 slave.cpp:1207] Registered with master master@172.17.0.4:38479; given agent ID 38224e03-633a-4450-a1be-414985663bda-S0
3: I1113 18:44:47.810070 18284 master.cpp:6264] Registered agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b) with [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":367489.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1113 18:44:47.810545 18271 status_update_manager.cpp:184] Resuming sending status updates
3: I1113 18:44:47.810557 18268 hierarchical.cpp:593] Added agent 38224e03-633a-4450-a1be-414985663bda-S0 (07cc01e6260b) with cpus:2; disk:367489; ports:[31000-32000] (allocated: {})
3: I1113 18:44:47.810871 18279 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/MasterAllocatorTest_0_CpusOnlyOfferedAndTaskLaunched_XRdGPw/meta/slaves/38224e03-633a-4450-a1be-414985663bda-S0/slave.info'
3: I1113 18:44:47.810902 18284 master.cpp:6033] Received register agent message from slave(275)@172.17.0.4:38479 (07cc01e6260b)
3: I1113 18:44:47.810961 18284 master.cpp:3871] Authorizing agent with principal 'test-principal'
3: I1113 18:44:47.811951 18284 master.cpp:6093] Authorized registration of agent at slave(275)@172.17.0.4:38479 (07cc01e6260b)
3: I1113 18:44:47.811982 18279 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1113 18:44:47.812137 18284 master.cpp:6164] Agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b) already registered, resending acknowledgement
3: W1113 18:44:47.812516 18277 slave.cpp:1262] Already registered with master master@172.17.0.4:38479
3: I1113 18:44:47.812572 18277 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1113 18:44:47.812682 18268 hierarchical.cpp:1450] Performed allocation for 1 agents in 1.844766ms
3: I1113 18:44:47.812947 18284 master.cpp:7065] Received update of agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b) with total oversubscribed resources {}
3: I1113 18:44:47.813191 18268 hierarchical.cpp:1450] Performed allocation for 1 agents in 243590ns
3: I1113 18:44:47.813226 18284 master.cpp:7083] Ignoring update on agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b) as it reports no changes
3: I1113 18:44:47.814190 18284 master.cpp:8116] Sending 1 offers to framework 38224e03-633a-4450-a1be-414985663bda-0000 (default) at scheduler-9e562cfd-21b4-454b-87bb-518251e567b1@172.17.0.4:38479
3: I1113 18:44:47.814713 18284 master.cpp:7065] Received update of agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b) with total oversubscribed resources {}
3: I1113 18:44:47.814934 18284 master.cpp:7083] Ignoring update on agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b) as it reports no changes
3: I1113 18:44:47.816565 18273 sched.cpp:921] Scheduler::resourceOffers took 1.258055ms
3: I1113 18:44:47.818969 18280 master.cpp:10016] Removing offer 38224e03-633a-4450-a1be-414985663bda-O0
3: I1113 18:44:47.819427 18280 master.cpp:4229] Processing ACCEPT call for offers: [ 38224e03-633a-4450-a1be-414985663bda-O0 ] on agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b) for framework 38224e03-633a-4450-a1be-414985663bda-0000 (default) at scheduler-9e562cfd-21b4-454b-87bb-518251e567b1@172.17.0.4:38479
3: I1113 18:44:47.819591 18280 master.cpp:3598] Authorizing framework principal 'test-principal' to launch task 0
3: W1113 18:44:47.822341 18276 validation.cpp:1404] Executor 'default' for task '0' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
3: W1113 18:44:47.822432 18276 validation.cpp:1416] Executor 'default' for task '0' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
3: I1113 18:44:47.822954 18276 master.cpp:10762] Adding task 0 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"}] on agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b)
3: I1113 18:44:47.823591 18276 master.cpp:4977] Launching task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000 (default) at scheduler-9e562cfd-21b4-454b-87bb-518251e567b1@172.17.0.4:38479 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"}] on agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b)
3: I1113 18:44:47.824652 18272 slave.cpp:1803] Got assigned task '0' for framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.825263 18269 hierarchical.cpp:1125] Recovered ports(allocated: *):[31000-32000]; disk(allocated: *):367489 (total: cpus:2; disk:367489; ports:[31000-32000], allocated: cpus(allocated: *):2) on agent 38224e03-633a-4450-a1be-414985663bda-S0 from framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.825356 18269 hierarchical.cpp:1171] Framework 38224e03-633a-4450-a1be-414985663bda-0000 filtered agent 38224e03-633a-4450-a1be-414985663bda-S0 for 5secs
3: I1113 18:44:47.825768 18272 slave.cpp:2071] Authorizing task '0' for framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.825901 18272 slave.cpp:7253] Authorizing framework principal 'test-principal' to launch task 0
3: I1113 18:44:47.827267 18266 slave.cpp:2239] Launching task '0' for framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.828157 18266 paths.cpp:605] Trying to chown '/tmp/MasterAllocatorTest_0_CpusOnlyOfferedAndTaskLaunched_XRdGPw/slaves/38224e03-633a-4450-a1be-414985663bda-S0/frameworks/38224e03-633a-4450-a1be-414985663bda-0000/executors/default/runs/cec71f27-34e1-4297-a895-03734d89e6fd' to user 'mesos'
3: I1113 18:44:47.828610 18266 slave.cpp:7727] Launching executor 'default' of framework 38224e03-633a-4450-a1be-414985663bda-0000 with resources [] in work directory '/tmp/MasterAllocatorTest_0_CpusOnlyOfferedAndTaskLaunched_XRdGPw/slaves/38224e03-633a-4450-a1be-414985663bda-S0/frameworks/38224e03-633a-4450-a1be-414985663bda-0000/executors/default/runs/cec71f27-34e1-4297-a895-03734d89e6fd'
3: I1113 18:44:47.830032 18266 slave.cpp:2467] Queued task '0' for executor 'default' of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.830237 18266 slave.cpp:958] Successfully attached '/tmp/MasterAllocatorTest_0_CpusOnlyOfferedAndTaskLaunched_XRdGPw/slaves/38224e03-633a-4450-a1be-414985663bda-S0/frameworks/38224e03-633a-4450-a1be-414985663bda-0000/executors/default/runs/cec71f27-34e1-4297-a895-03734d89e6fd' to virtual path '/tmp/MasterAllocatorTest_0_CpusOnlyOfferedAndTaskLaunched_XRdGPw/slaves/38224e03-633a-4450-a1be-414985663bda-S0/frameworks/38224e03-633a-4450-a1be-414985663bda-0000/executors/default/runs/latest'
3: I1113 18:44:47.830297 18266 slave.cpp:958] Successfully attached '/tmp/MasterAllocatorTest_0_CpusOnlyOfferedAndTaskLaunched_XRdGPw/slaves/38224e03-633a-4450-a1be-414985663bda-S0/frameworks/38224e03-633a-4450-a1be-414985663bda-0000/executors/default/runs/cec71f27-34e1-4297-a895-03734d89e6fd' to virtual path '/frameworks/38224e03-633a-4450-a1be-414985663bda-0000/executors/default/runs/latest'
3: I1113 18:44:47.830343 18266 slave.cpp:958] Successfully attached '/tmp/MasterAllocatorTest_0_CpusOnlyOfferedAndTaskLaunched_XRdGPw/slaves/38224e03-633a-4450-a1be-414985663bda-S0/frameworks/38224e03-633a-4450-a1be-414985663bda-0000/executors/default/runs/cec71f27-34e1-4297-a895-03734d89e6fd' to virtual path '/tmp/MasterAllocatorTest_0_CpusOnlyOfferedAndTaskLaunched_XRdGPw/slaves/38224e03-633a-4450-a1be-414985663bda-S0/frameworks/38224e03-633a-4450-a1be-414985663bda-0000/executors/default/runs/cec71f27-34e1-4297-a895-03734d89e6fd'
3: I1113 18:44:47.830821 18266 slave.cpp:2930] Launching container cec71f27-34e1-4297-a895-03734d89e6fd for executor 'default' of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: W1113 18:44:47.835561 18283 process.cpp:3178] Attempted to spawn already running process version@172.17.0.4:38479
3: I1113 18:44:47.835988 18283 exec.cpp:162] Version: 1.5.0
3: I1113 18:44:47.836356 18281 exec.cpp:212] Executor started at: executor(99)@172.17.0.4:38479 with pid 18263
3: I1113 18:44:47.836736 18281 slave.cpp:4063] Got registration for executor 'default' of framework 38224e03-633a-4450-a1be-414985663bda-0000 from executor(99)@172.17.0.4:38479
3: I1113 18:44:47.837568 18267 exec.cpp:237] Executor registered on agent 38224e03-633a-4450-a1be-414985663bda-S0
3: I1113 18:44:47.837646 18267 exec.cpp:249] Executor::registered took 35736ns
3: I1113 18:44:47.838093 18281 slave.cpp:2669] Sending queued task '0' to executor 'default' of framework 38224e03-633a-4450-a1be-414985663bda-0000 at executor(99)@172.17.0.4:38479
3: I1113 18:44:47.839010 18277 exec.cpp:331] Executor asked to run task '0'
3: I1113 18:44:47.839311 18277 exec.cpp:340] Executor::launchTask took 248149ns
3: I1113 18:44:47.839485 18277 exec.cpp:571] Executor sending status update TASK_RUNNING (UUID: 60446b2d-409c-4d4d-8845-fd96bc8d36a5) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.840116 18287 slave.cpp:4517] Handling status update TASK_RUNNING (UUID: 60446b2d-409c-4d4d-8845-fd96bc8d36a5) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000 from executor(99)@172.17.0.4:38479
3: I1113 18:44:47.840206 18280 exec.cpp:571] Executor sending status update TASK_FINISHED (UUID: 010bf365-47ff-44b6-bda9-f59ea53e6264) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.840921 18287 slave.cpp:4517] Handling status update TASK_FINISHED (UUID: 010bf365-47ff-44b6-bda9-f59ea53e6264) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000 from executor(99)@172.17.0.4:38479
3: I1113 18:44:47.841823 18287 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: 60446b2d-409c-4d4d-8845-fd96bc8d36a5) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.841918 18287 status_update_manager.cpp:500] Creating StatusUpdate stream for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.842919 18287 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 60446b2d-409c-4d4d-8845-fd96bc8d36a5) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000 to the agent
3: I1113 18:44:47.843387 18275 slave.cpp:4998] Forwarding the update TASK_RUNNING (UUID: 60446b2d-409c-4d4d-8845-fd96bc8d36a5) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000 to master@172.17.0.4:38479
3: I1113 18:44:47.843595 18287 status_update_manager.cpp:323] Received status update TASK_FINISHED (UUID: 010bf365-47ff-44b6-bda9-f59ea53e6264) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.843843 18275 slave.cpp:4892] Status update manager successfully handled status update TASK_RUNNING (UUID: 60446b2d-409c-4d4d-8845-fd96bc8d36a5) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.843924 18275 slave.cpp:4908] Sending acknowledgement for status update TASK_RUNNING (UUID: 60446b2d-409c-4d4d-8845-fd96bc8d36a5) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000 to executor(99)@172.17.0.4:38479
3: I1113 18:44:47.844218 18278 exec.cpp:388] Executor received status update acknowledgement 60446b2d-409c-4d4d-8845-fd96bc8d36a5 for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.844430 18287 master.cpp:7248] Status update TASK_RUNNING (UUID: 60446b2d-409c-4d4d-8845-fd96bc8d36a5) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000 from agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b)
3: I1113 18:44:47.844483 18275 slave.cpp:4892] Status update manager successfully handled status update TASK_FINISHED (UUID: 010bf365-47ff-44b6-bda9-f59ea53e6264) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.844532 18287 master.cpp:7310] Forwarding status update TASK_RUNNING (UUID: 60446b2d-409c-4d4d-8845-fd96bc8d36a5) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.844542 18275 slave.cpp:4908] Sending acknowledgement for status update TASK_FINISHED (UUID: 010bf365-47ff-44b6-bda9-f59ea53e6264) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000 to executor(99)@172.17.0.4:38479
3: I1113 18:44:47.844772 18266 exec.cpp:388] Executor received status update acknowledgement 010bf365-47ff-44b6-bda9-f59ea53e6264 for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.844986 18271 sched.cpp:1029] Scheduler::statusUpdate took 39187ns
3: I1113 18:44:47.845412 18287 master.cpp:9503] Updating the state of task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000 (latest state: TASK_FINISHED, status update state: TASK_RUNNING)
3: I1113 18:44:47.846143 18279 hierarchical.cpp:1125] Recovered cpus(allocated: *):2 (total: cpus:2; disk:367489; ports:[31000-32000], allocated: {}) on agent 38224e03-633a-4450-a1be-414985663bda-S0 from framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.846278 18287 master.cpp:5792] Processing ACKNOWLEDGE call 60446b2d-409c-4d4d-8845-fd96bc8d36a5 for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000 (default) at scheduler-9e562cfd-21b4-454b-87bb-518251e567b1@172.17.0.4:38479 on agent 38224e03-633a-4450-a1be-414985663bda-S0
3: I1113 18:44:47.846935 18286 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 60446b2d-409c-4d4d-8845-fd96bc8d36a5) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.847395 18286 status_update_manager.cpp:377] Forwarding update TASK_FINISHED (UUID: 010bf365-47ff-44b6-bda9-f59ea53e6264) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000 to the agent
3: I1113 18:44:47.847764 18267 slave.cpp:4998] Forwarding the update TASK_FINISHED (UUID: 010bf365-47ff-44b6-bda9-f59ea53e6264) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000 to master@172.17.0.4:38479
3: I1113 18:44:47.848177 18267 slave.cpp:3801] Status update manager successfully handled status update acknowledgement (UUID: 60446b2d-409c-4d4d-8845-fd96bc8d36a5) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.848624 18281 master.cpp:7248] Status update TASK_FINISHED (UUID: 010bf365-47ff-44b6-bda9-f59ea53e6264) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000 from agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b)
3: I1113 18:44:47.848722 18281 master.cpp:7310] Forwarding status update TASK_FINISHED (UUID: 010bf365-47ff-44b6-bda9-f59ea53e6264) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.849088 18281 master.cpp:9503] Updating the state of task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000 (latest state: TASK_FINISHED, status update state: TASK_FINISHED)
3: I1113 18:44:47.849339 18273 sched.cpp:1029] Scheduler::statusUpdate took 41067ns
3: I1113 18:44:47.849977 18277 master.cpp:5792] Processing ACKNOWLEDGE call 010bf365-47ff-44b6-bda9-f59ea53e6264 for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000 (default) at scheduler-9e562cfd-21b4-454b-87bb-518251e567b1@172.17.0.4:38479 on agent 38224e03-633a-4450-a1be-414985663bda-S0
3: I1113 18:44:47.850134 18277 master.cpp:9597] Removing task 0 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"}] of framework 38224e03-633a-4450-a1be-414985663bda-0000 on agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b)
3: I1113 18:44:47.851233 18268 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 010bf365-47ff-44b6-bda9-f59ea53e6264) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.851591 18268 status_update_manager.cpp:531] Cleaning up status update stream for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.852283 18282 slave.cpp:3801] Status update manager successfully handled status update acknowledgement (UUID: 010bf365-47ff-44b6-bda9-f59ea53e6264) for task 0 of framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.852393 18282 slave.cpp:8332] Completing task 0
3: I1113 18:44:47.865785 18265 hierarchical.cpp:1450] Performed allocation for 1 agents in 1.479185ms
3: I1113 18:44:47.866643 18285 master.cpp:8116] Sending 1 offers to framework 38224e03-633a-4450-a1be-414985663bda-0000 (default) at scheduler-9e562cfd-21b4-454b-87bb-518251e567b1@172.17.0.4:38479
3: I1113 18:44:47.867866 18285 sched.cpp:921] Scheduler::resourceOffers took 101611ns
3: I1113 18:44:47.868438 18263 sched.cpp:2009] Asked to stop the driver
3: I1113 18:44:47.868659 18264 sched.cpp:1191] Stopping framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.869418 18278 master.cpp:8793] Processing TEARDOWN call for framework 38224e03-633a-4450-a1be-414985663bda-0000 (default) at scheduler-9e562cfd-21b4-454b-87bb-518251e567b1@172.17.0.4:38479
3: I1113 18:44:47.869488 18278 master.cpp:8805] Removing framework 38224e03-633a-4450-a1be-414985663bda-0000 (default) at scheduler-9e562cfd-21b4-454b-87bb-518251e567b1@172.17.0.4:38479
3: I1113 18:44:47.869500 18278 master.cpp:3332] Deactivating framework 38224e03-633a-4450-a1be-414985663bda-0000 (default) at scheduler-9e562cfd-21b4-454b-87bb-518251e567b1@172.17.0.4:38479
3: I1113 18:44:47.869710 18269 hierarchical.cpp:412] Deactivated framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.870527 18278 master.cpp:10016] Removing offer 38224e03-633a-4450-a1be-414985663bda-O1
3: I1113 18:44:47.871387 18286 hierarchical.cpp:1125] Recovered cpus(allocated: *):2; disk(allocated: *):367489; ports(allocated: *):[31000-32000] (total: cpus:2; disk:367489; ports:[31000-32000], allocated: {}) on agent 38224e03-633a-4450-a1be-414985663bda-S0 from framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.871704 18270 slave.cpp:3267] Asked to shut down framework 38224e03-633a-4450-a1be-414985663bda-0000 by master@172.17.0.4:38479
3: I1113 18:44:47.871767 18270 slave.cpp:3292] Shutting down framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.871852 18270 slave.cpp:5865] Shutting down executor 'default' of framework 38224e03-633a-4450-a1be-414985663bda-0000 at executor(99)@172.17.0.4:38479
3: I1113 18:44:47.871868 18278 master.cpp:9626] Removing executor 'default' with resources [] of framework 38224e03-633a-4450-a1be-414985663bda-0000 on agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b)
3: I1113 18:44:47.872153 18270 exec.cpp:435] Executor asked to shutdown
3: I1113 18:44:47.872198 18270 exec.cpp:450] Executor::shutdown took 30079ns
3: I1113 18:44:47.872462 18265 slave.cpp:5130] Got exited event for executor(99)@172.17.0.4:38479
3: I1113 18:44:47.872982 18279 slave.cpp:5530] Executor 'default' of framework 38224e03-633a-4450-a1be-414985663bda-0000 exited with status 0
3: I1113 18:44:47.873095 18267 hierarchical.cpp:355] Removed framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.873162 18279 slave.cpp:5634] Cleaning up executor 'default' of framework 38224e03-633a-4450-a1be-414985663bda-0000 at executor(99)@172.17.0.4:38479
3: I1113 18:44:47.873556 18266 gc.cpp:90] Scheduling '/tmp/MasterAllocatorTest_0_CpusOnlyOfferedAndTaskLaunched_XRdGPw/slaves/38224e03-633a-4450-a1be-414985663bda-S0/frameworks/38224e03-633a-4450-a1be-414985663bda-0000/executors/default/runs/cec71f27-34e1-4297-a895-03734d89e6fd' for gc 6.99998989133037days in the future
3: W1113 18:44:47.873628 18278 master.cpp:7454] Ignoring unknown exited executor 'default' of framework 38224e03-633a-4450-a1be-414985663bda-0000 on agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b)
3: I1113 18:44:47.873702 18279 slave.cpp:5741] Cleaning up framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.873827 18266 gc.cpp:90] Scheduling '/tmp/MasterAllocatorTest_0_CpusOnlyOfferedAndTaskLaunched_XRdGPw/slaves/38224e03-633a-4450-a1be-414985663bda-S0/frameworks/38224e03-633a-4450-a1be-414985663bda-0000/executors/default' for gc 6.99998988866963days in the future
3: I1113 18:44:47.873883 18283 status_update_manager.cpp:285] Closing status update streams for framework 38224e03-633a-4450-a1be-414985663bda-0000
3: I1113 18:44:47.873963 18266 gc.cpp:90] Scheduling '/tmp/MasterAllocatorTest_0_CpusOnlyOfferedAndTaskLaunched_XRdGPw/slaves/38224e03-633a-4450-a1be-414985663bda-S0/frameworks/38224e03-633a-4450-a1be-414985663bda-0000' for gc 6.99998988648296days in the future
3: I1113 18:44:47.874372 18263 slave.cpp:883] Agent terminating
3: I1113 18:44:47.874661 18286 master.cpp:1309] Agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b) disconnected
3: I1113 18:44:47.874714 18286 master.cpp:3369] Disconnecting agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b)
3: I1113 18:44:47.874816 18286 master.cpp:3388] Deactivating agent 38224e03-633a-4450-a1be-414985663bda-S0 at slave(275)@172.17.0.4:38479 (07cc01e6260b)
3: I1113 18:44:47.875000 18275 hierarchical.cpp:690] Agent 38224e03-633a-4450-a1be-414985663bda-S0 deactivated
3: I1113 18:44:47.883882 18263 master.cpp:1151] Master terminating
3: I1113 18:44:47.884896 18269 hierarchical.cpp:626] Removed agent 38224e03-633a-4450-a1be-414985663bda-S0
3: [ OK ] MasterAllocatorTest/0.CpusOnlyOfferedAndTaskLaunched (141 ms)
3: [ RUN ] MasterAllocatorTest/0.MemoryOnlyOfferedAndTaskLaunched
3: I1113 18:44:47.899308 18263 cluster.cpp:162] Creating default 'local' authorizer
3: I1113 18:44:47.905166 18265 master.cpp:448] Master 39c718c7-b812-4ede-b1fa-bb6a43aff048 (07cc01e6260b) started on 172.17.0.4:38479
3: I1113 18:44:47.905236 18265 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="50ms" --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/dmLfTy/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/dmLfTy/master" --zk_session_timeout="10secs"
3: I1113 18:44:47.905818 18265 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1113 18:44:47.905835 18265 master.cpp:505] Master only allowing authenticated agents to register
3: I1113 18:44:47.905844 18265 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1113 18:44:47.905854 18265 credentials.hpp:37] Loading credentials for authentication from '/tmp/dmLfTy/credentials'
3: I1113 18:44:47.906461 18265 master.cpp:555] Using default 'crammd5' authenticator
3: I1113 18:44:47.906774 18265 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1113 18:44:47.907059 18265 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1113 18:44:47.907306 18265 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1113 18:44:47.907521 18265 master.cpp:634] Authorization enabled
3: I1113 18:44:47.907907 18268 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1113 18:44:47.907991 18271 whitelist_watcher.cpp:77] No whitelist given
3: I1113 18:44:47.911875 18279 master.cpp:2213] Elected as the leading master!
3: I1113 18:44:47.912052 18279 master.cpp:1693] Recovering from registrar
3: I1113 18:44:47.912276 18270 registrar.cpp:347] Recovering registrar
3: I1113 18:44:47.913161 18270 registrar.cpp:391] Successfully fetched the registry (0B) in 835072ns
3: I1113 18:44:47.913338 18270 registrar.cpp:495] Applied 1 operations in 75694ns; attempting to update the registry
3: I1113 18:44:47.914345 18270 registrar.cpp:552] Successfully updated the registry in 922112ns
3: I1113 18:44:47.914512 18270 registrar.cpp:424] Successfully recovered registrar
3: I1113 18:44:47.915463 18273 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1113 18:44:47.915984 18281 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1113 18:44:47.926513 18263 process.cpp:3178] Attempted to spawn already running process files@172.17.0.4:38479
3: I1113 18:44:47.927135 18263 cluster.cpp:448] Creating default 'local' authorizer
3: I1113 18:44:47.929927 18269 slave.cpp:262] Mesos agent started on (276)@172.17.0.4:38479
3: I1113 18:44:47.930133 18269 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/MasterAllocatorTest_0_MemoryOnlyOfferedAndTaskLaunched_nSRxqA/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/MasterAllocatorTest_0_MemoryOnlyOfferedAndTaskLaunched_nSRxqA/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/MasterAllocatorTest_0_MemoryOnlyOfferedAndTaskLaunched_nSRxqA/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/MasterAllocatorTest_0_MemoryOnlyOfferedAndTaskLaunched_nSRxqA/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/MasterAllocatorTest_0_MemoryOnlyOfferedAndTaskLaunched_nSRxqA/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/MasterAllocatorTest_0_MemoryOnlyOfferedAndTaskLaunched_nSRxqA/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:0;mem:200" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/MasterAllocatorTest_0_MemoryOnlyOfferedAndTaskLaunched_nSRxqA" --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/MasterAllocatorTest_0_MemoryOnlyOfferedAndTaskLaunched_ipGREz" --zk_session_timeout="10secs"
3: I1113 18:44:47.930944 18269 credentials.hpp:86] Loading credential for authentication from '/tmp/MasterAllocatorTest_0_MemoryOnlyOfferedAndTaskLaunched_nSRxqA/credential'
3: W1113 18:44:47.931128 18263 process.cpp:3178] Attempted to spawn already running process version@172.17.0.4:38479
3: I1113 18:44:47.931308 18269 slave.cpp:295] Agent using credential for: test-principal
3: I1113 18:44:47.931375 18269 credentials.hpp:37] Loading credentials for authentication from '/tmp/MasterAllocatorTest_0_MemoryOnlyOfferedAndTaskLaunched_nSRxqA/http_credentials'
3: I1113 18:44:47.931869 18269 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1113 18:44:47.932147 18269 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1113 18:44:47.932459 18269 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1113 18:44:47.932579 18269 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1113 18:44:47.932803 18269 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1113 18:44:47.932843 18263 sched.cpp:232] Version: 1.5.0
3: I1113 18:44:47.932942 18269 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1113 18:44:47.934264 18268 sched.cpp:336] New master detected at master@172.17.0.4:38479
3: I1113 18:44:47.934336 18269 slave.cpp:593] Agent resources: [{"name":"mem","scalar":{"value":200.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":367489.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I1113 18:44:47.934613 18269 slave.cpp:601] Agent attributes: [ ]
3: I1113 18:44:47.934624 18269 slave.cpp:610] Agent hostname: 07cc01e6260b
3: I1113 18:44:47.934742 18268 sched.cpp:396] Authenticating with master master@172.17.0.4:38479
3: I1113 18:44:47.934789 18268 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1113 18:44:47.934862 18272 status_update_manager.cpp:177] Pausing sending status updates
3: I1113 18:44:47.935279 18276 authenticatee.cpp:121] Creating new client SASL connection
3: I1113 18:44:47.935835 18270 master.cpp:8286] Authenticating scheduler-4d2a9ca8-b813-41c2-a47a-497f3b9868f5@172.17.0.4:38479
3: I1113 18:44:47.936152 18270 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(566)@172.17.0.4:38479
3: I1113 18:44:47.936709 18271 state.cpp:64] Recovering state from '/tmp/MasterAllocatorTest_0_MemoryOnlyOfferedAndTaskLaunched_ipGREz/meta'
3: I1113 18:44:47.936738 18270 authenticator.cpp:98] Creating new server SASL connection
3: I1113 18:44:47.937233 18285 status_update_manager.cpp:203] Recovering status update manager
3: I1113 18:44:47.937249 18270 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1113 18:44:47.937286 18270 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1113 18:44:47.937496 18285 authenticator.cpp:204] Received SASL authentication start
3: I1113 18:44:47.937656 18285 authenticator.cpp:326] Authentication requires more steps
3: I1113 18:44:47.937772 18281 slave.cpp:6432] Finished recovery
3: I1113 18:44:47.937999 18271 authenticatee.cpp:259] Received SASL authentication step
3: I1113 18:44:47.938243 18271 authenticator.cpp:232] Received SASL authentication step
3: I1113 18:44:47.938280 18271 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '07cc01e6260b' server FQDN: '07cc01e6260b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1113 18:44:47.938295 18271 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1113 18:44:47.938355 18271 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1113 18:44:47.938375 18271 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '07cc01e6260b' server FQDN: '07cc01e6260b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1113 18:44:47.938385 18271 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1113 18:44:47.938392 18271 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1113 18:44:47.938411 18271 authenticator.cpp:318] Authentication success
3: I1113 18:44:47.938534 18274 authenticatee.cpp:299] Authentication success
3: I1113 18:44:47.938716 18280 master.cpp:8316] Successfully authenticated principal 'test-principal' at scheduler-4d2a9ca8-b813-41c2-a47a-497f3b9868f5@172.17.0.4:38479
3: I1113 18:44:47.938794 18278 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(566)@172.17.0.4:38479
3: I1113 18:44:47.939366 18279 status_update_manager.cpp:177] Pausing sending status updates
3: I1113 18:44:47.939362 18276 slave.cpp:1007] New master detected at master@172.17.0.4:38479
3: I1113 18:44:47.939574 18276 slave.cpp:1042] Detecting new master
3: I1113 18:44:47.939615 18274 sched.cpp:502] Successfully authenticated with master master@172.17.0.4:38479
3: I1113 18:44:47.939653 18274 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.4:38479
3: I1113 18:44:47.939867 18274 sched.cpp:857] Will retry registration in 1.828541985secs if necessary
3: I1113 18:44:47.940188 18283 master.cpp:2962] Received SUBSCRIBE call for framework 'default' at scheduler-4d2a9ca8-b813-41c2-a47a-497f3b9868f5@172.17.0.4:38479
3: I1113 18:44:47.940217 18283 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1113 18:44:47.940912 18287 master.cpp:3042] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1113 18:44:47.942034 18265 sched.cpp:751] Framework registered with 39c718c7-b812-4ede-b1fa-bb6a43aff048-0000
3: I1113 18:44:47.942092 18273 hierarchical.cpp:303] Added framework 39c718c7-b812-4ede-b1fa-bb6a43aff048-0000
3: I1113 18:44:47.942123 18265 sched.cpp:765] Scheduler::registered took 37491ns
3: I1113 18:44:47.942365 18273 hierarchical.cpp:1450] Performed allocation for 0 agents in 111730ns
3: I1113 18:44:47.948292 18281 slave.cpp:1069] Authenticating with master master@172.17.0.4:38479
3: I1113 18:44:47.948484 18281 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1113 18:44:47.949057 18280 authenticatee.cpp:121] Creating new client SASL connection
3: I1113 18:44:47.949823 18284 master.cpp:8286] Authenticating slave(276)@172.17.0.4:38479
3: I1113 18:44:47.950470 18284 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(567)@172.17.0.4:38479
3: I1113 18:44:47.951939 18284 authenticator.cpp:98] Creating new server SASL connection
3: I1113 18:44:47.952868 18272 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1113 18:44:47.952960 18272 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1113 18:44:47.953284 18271 authenticator.cpp:204] Received SASL authentication start
3: I1113 18:44:47.953431 18271 authenticator.cpp:326] Authentication requires more steps
3: I1113 18:44:47.953696 18275 authenticatee.cpp:259] Received SASL authentication step
3: I1113 18:44:47.953899 18275 authenticator.cpp:232] Received SASL authentication step
3: I1113 18:44:47.953941 18275 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '07cc01e6260b' server FQDN: '07cc01e6260b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1113 18:44:47.953953 18275 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1113 18:44:47.953999 18275 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1113 18:44:47.954013 18275 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '07cc01e6260b' server FQDN: '07cc01e6260b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1113 18:44:47.954023 18275 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1113 18:44:47.954028 18275 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1113 18:44:47.954046 18275 authenticator.cpp:318] Authentication success
3: I1113 18:44:47.954175 18264 authenticatee.cpp:299] Authentication success
3: I1113 18:44:47.954448 18276 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(567)@172.17.0.4:38479
3: I1113 18:44:47.954718 18278 master.cpp:8316] Successfully authenticated principal 'test-principal' at slave(276)@172.17.0.4:38479
3: I1113 18:44:47.954916 18266 slave.cpp:1161] Successfully authenticated with master master@172.17.0.4:38479
+ docker rmi mesos-1510597150-14844
Error response from daemon: conflict: unable to remove repository reference "mesos-1510597150-14844" (must force) - container 07cc01e6260b is using its referenced image 80af0ce9f7f4
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user yujie.jay@gmail.com