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/09/01 20:30:27 UTC

Build failed in Jenkins: Mesos-Buildbot » cmake,clang,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2) #4184

See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)/4184/display/redirect?page=changes>

Changes:

[songzihao1990] Added unit test for killing the default executor process.

[alexr] Ensured JAVA HTTP adapter propagates a subscription error.

[alexr] Extracted JNI code into a protected function for clarity.

[alexr] Added several logs to the C++ part of the v1-v0 adapter.

[alexr] Added MESOS-7872 to 1.4.1 CHANGELOG.

[alexr] Added MESOS-7872 to 1.3.2 CHANGELOG.

[alexr] Added MESOS-7872 to 1.2.3 CHANGELOG.

------------------------------------------
[...truncated 2.82 MB...]
I0901 16:36:37.262676 30819 master.cpp:1163] Master terminating
I0901 16:36:37.263746 30823 hierarchical.cpp:626] Removed agent b56547b4-9999-4f23-9a69-ed6664e44736-S0
W0901 16:36:37.265396 30819 master.hpp:2761] Failed to close HTTP pipe for b56547b4-9999-4f23-9a69-ed6664e44736-0000 (default)
[       OK ] DefaultExecutorCheckTest.CommandCheckTimeout (3294 ms)
[ RUN      ] DefaultExecutorCheckTest.CommandCheckAndHealthCheckNoShadowing
I0901 16:36:37.273700 30819 cluster.cpp:162] Creating default 'local' authorizer
I0901 16:36:37.278300 30825 master.cpp:445] Master 4479157b-8091-4d7a-8add-b8bd8cf96ad1 (ad57000f913b) started on 172.17.0.4:43745
I0901 16:36:37.278380 30825 master.cpp:447] 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/nkxgQt/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/nkxgQt/master" --zk_session_timeout="10secs"
I0901 16:36:37.278874 30825 master.cpp:497] Master only allowing authenticated frameworks to register
I0901 16:36:37.278890 30825 master.cpp:511] Master only allowing authenticated agents to register
I0901 16:36:37.278899 30825 master.cpp:524] Master only allowing authenticated HTTP frameworks to register
I0901 16:36:37.278910 30825 credentials.hpp:37] Loading credentials for authentication from '/tmp/nkxgQt/credentials'
I0901 16:36:37.279314 30825 master.cpp:569] Using default 'crammd5' authenticator
I0901 16:36:37.279661 30825 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0901 16:36:37.279881 30825 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0901 16:36:37.280050 30825 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0901 16:36:37.280189 30825 master.cpp:649] Authorization enabled
I0901 16:36:37.280463 30822 hierarchical.cpp:171] Initialized hierarchical allocator process
I0901 16:36:37.280491 30821 whitelist_watcher.cpp:77] No whitelist given
I0901 16:36:37.284351 30821 master.cpp:2166] Elected as the leading master!
I0901 16:36:37.284387 30821 master.cpp:1705] Recovering from registrar
I0901 16:36:37.284593 30822 registrar.cpp:347] Recovering registrar
I0901 16:36:37.285432 30822 registrar.cpp:391] Successfully fetched the registry (0B) in 781056ns
I0901 16:36:37.285734 30822 registrar.cpp:495] Applied 1 operations in 59139ns; attempting to update the registry
I0901 16:36:37.286664 30822 registrar.cpp:552] Successfully updated the registry in 828928ns
I0901 16:36:37.286869 30822 registrar.cpp:424] Successfully recovered registrar
I0901 16:36:37.287458 30821 master.cpp:1804] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
I0901 16:36:37.287609 30827 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
I0901 16:36:37.292625 30819 containerizer.cpp:290] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
W0901 16:36:37.293354 30819 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend requires root privileges
W0901 16:36:37.293552 30819 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
I0901 16:36:37.293593 30819 provisioner.cpp:255] Using default backend 'copy'
W0901 16:36:37.299856 30819 process.cpp:3240] Attempted to spawn already running process files@172.17.0.4:43745
I0901 16:36:37.300416 30819 cluster.cpp:448] Creating default 'local' authorizer
I0901 16:36:37.303463 30825 slave.cpp:252] Mesos agent started on (25)@172.17.0.4:43745
I0901 16:36:37.303532 30825 slave.cpp:253] Flags at startup: --acls="permissive: true
" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_Z8EEWe/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_Z8EEWe/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/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_Z8EEWe/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/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_Z8EEWe/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/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_Z8EEWe/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/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_Z8EEWe" --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/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_mcQroR" --zk_session_timeout="10secs"
I0901 16:36:37.304461 30825 credentials.hpp:86] Loading credential for authentication from '/tmp/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_Z8EEWe/credential'
I0901 16:36:37.304963 30825 slave.cpp:285] Agent using credential for: test-principal
I0901 16:36:37.304998 30825 credentials.hpp:37] Loading credentials for authentication from '/tmp/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_Z8EEWe/http_credentials'
I0901 16:36:37.305366 30819 scheduler.cpp:184] Version: 1.5.0
I0901 16:36:37.305513 30825 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
I0901 16:36:37.306418 30821 scheduler.cpp:470] New master detected at master@172.17.0.4:43745
I0901 16:36:37.306463 30821 scheduler.cpp:479] Waiting for 0ns before initiating a re-(connection) attempt with the master
I0901 16:36:37.308233 30825 slave.cpp:581] 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"}]
I0901 16:36:37.308584 30825 slave.cpp:589] Agent attributes: [  ]
I0901 16:36:37.308604 30825 slave.cpp:598] Agent hostname: ad57000f913b
I0901 16:36:37.309170 30822 status_update_manager.cpp:177] Pausing sending status updates
I0901 16:36:37.311147 30826 state.cpp:64] Recovering state from '/tmp/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_mcQroR/meta'
I0901 16:36:37.311559 30825 status_update_manager.cpp:203] Recovering status update manager
I0901 16:36:37.311827 30821 containerizer.cpp:646] Recovering containerizer
I0901 16:36:37.312592 30827 scheduler.cpp:361] Connected with the master at http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:37.314497 30825 scheduler.cpp:243] Sending SUBSCRIBE call to http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:37.316789 30824 process.cpp:3956] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0901 16:36:37.318800 30825 provisioner.cpp:416] Provisioner recovery complete
I0901 16:36:37.319212 30827 slave.cpp:6296] Finished recovery
I0901 16:36:37.319468 30821 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:42696
I0901 16:36:37.319865 30821 master.cpp:2548] Received subscription request for HTTP framework 'default'
I0901 16:36:37.319914 30821 master.cpp:2231] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
I0901 16:36:37.320413 30827 slave.cpp:6478] Querying resource estimator for oversubscribable resources
I0901 16:36:37.320591 30821 master.cpp:2684] Subscribing framework 'default' with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
I0901 16:36:37.320791 30824 slave.cpp:987] New master detected at master@172.17.0.4:43745
I0901 16:36:37.320829 30827 status_update_manager.cpp:177] Pausing sending status updates
I0901 16:36:37.320972 30824 slave.cpp:1022] Detecting new master
I0901 16:36:37.321127 30824 slave.cpp:6492] Received oversubscribable resources {} from the resource estimator
I0901 16:36:37.321576 30824 master.hpp:349] Sending heartbeat to framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.321640 30826 hierarchical.cpp:303] Added framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.321965 30826 hierarchical.cpp:1943] No allocations performed
I0901 16:36:37.322005 30826 hierarchical.cpp:2033] No inverse offers to send out!
I0901 16:36:37.322046 30826 hierarchical.cpp:1486] Performed allocation for 0 agents in 143522ns
I0901 16:36:37.323348 30820 scheduler.cpp:676] Enqueuing event SUBSCRIBED received from http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:37.325708 30823 scheduler.cpp:676] Enqueuing event HEARTBEAT received from http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:37.327111 30825 slave.cpp:1049] Authenticating with master master@172.17.0.4:43745
I0901 16:36:37.327424 30825 slave.cpp:1060] Using default CRAM-MD5 authenticatee
I0901 16:36:37.327893 30821 authenticatee.cpp:121] Creating new client SASL connection
I0901 16:36:37.328471 30820 master.cpp:7834] Authenticating slave(25)@172.17.0.4:43745
I0901 16:36:37.328727 30826 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(47)@172.17.0.4:43745
I0901 16:36:37.329211 30823 authenticator.cpp:98] Creating new server SASL connection
I0901 16:36:37.329663 30823 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0901 16:36:37.329695 30823 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0901 16:36:37.329984 30824 authenticator.cpp:204] Received SASL authentication start
I0901 16:36:37.330085 30824 authenticator.cpp:326] Authentication requires more steps
I0901 16:36:37.330338 30825 authenticatee.cpp:259] Received SASL authentication step
I0901 16:36:37.330670 30821 authenticator.cpp:232] Received SASL authentication step
I0901 16:36:37.330718 30821 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ad57000f913b' server FQDN: 'ad57000f913b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0901 16:36:37.330736 30821 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0901 16:36:37.330790 30821 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0901 16:36:37.330819 30821 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ad57000f913b' server FQDN: 'ad57000f913b' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0901 16:36:37.330837 30821 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0901 16:36:37.330849 30821 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0901 16:36:37.330874 30821 authenticator.cpp:318] Authentication success
I0901 16:36:37.331061 30820 authenticatee.cpp:299] Authentication success
I0901 16:36:37.331089 30826 master.cpp:7864] Successfully authenticated principal 'test-principal' at slave(25)@172.17.0.4:43745
I0901 16:36:37.331166 30821 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(47)@172.17.0.4:43745
I0901 16:36:37.331598 30820 slave.cpp:1144] Successfully authenticated with master master@172.17.0.4:43745
I0901 16:36:37.331915 30820 slave.cpp:1623] Will retry registration in 16.661975ms if necessary
I0901 16:36:37.332350 30825 master.cpp:5717] Received register agent message from slave(25)@172.17.0.4:43745 (ad57000f913b)
I0901 16:36:37.332417 30825 master.cpp:3806] Authorizing agent with principal 'test-principal'
I0901 16:36:37.333101 30826 master.cpp:5777] Authorized registration of agent at slave(25)@172.17.0.4:43745 (ad57000f913b)
I0901 16:36:37.333374 30826 master.cpp:5870] Registering agent at slave(25)@172.17.0.4:43745 (ad57000f913b) with id 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0
I0901 16:36:37.333950 30821 registrar.cpp:495] Applied 1 operations in 123170ns; attempting to update the registry
I0901 16:36:37.334820 30821 registrar.cpp:552] Successfully updated the registry in 769024ns
I0901 16:36:37.335139 30827 master.cpp:5917] Admitted agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 at slave(25)@172.17.0.4:43745 (ad57000f913b)
I0901 16:36:37.336928 30820 slave.cpp:1190] Registered with master master@172.17.0.4:43745; given agent ID 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0
I0901 16:36:37.337302 30825 status_update_manager.cpp:184] Resuming sending status updates
I0901 16:36:37.337352 30824 hierarchical.cpp:593] Added agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 (ad57000f913b) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
I0901 16:36:37.337505 30820 slave.cpp:1210] Checkpointing SlaveInfo to '/tmp/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_mcQroR/meta/slaves/4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0/slave.info'
I0901 16:36:37.336685 30827 master.cpp:5948] Registered agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 at slave(25)@172.17.0.4:43745 (ad57000f913b) 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"}]
I0901 16:36:37.338105 30820 slave.cpp:1259] Forwarding total oversubscribed resources {}
I0901 16:36:37.338306 30820 slave.cpp:4963] Received ping from slave-observer(22)@172.17.0.4:43745
I0901 16:36:37.338651 30827 master.cpp:6685] Received update of agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 at slave(25)@172.17.0.4:43745 (ad57000f913b) with total oversubscribed resources {}
I0901 16:36:37.339474 30824 hierarchical.cpp:2033] No inverse offers to send out!
I0901 16:36:37.339644 30824 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.974769ms
I0901 16:36:37.339964 30824 hierarchical.cpp:660] Agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 (ad57000f913b) updated with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000]
I0901 16:36:37.340296 30821 master.cpp:7664] Sending 1 offers to framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 (default)
I0901 16:36:37.343560 30827 scheduler.cpp:676] Enqueuing event OFFERS received from http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:37.346117 30827 scheduler.cpp:243] Sending ACCEPT call to http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:37.348984 30824 process.cpp:3956] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0901 16:36:37.351739 30824 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:42698
I0901 16:36:37.353302 30824 master.cpp:9162] Removing offer 4479157b-8091-4d7a-8add-b8bd8cf96ad1-O0
I0901 16:36:37.353566 30824 master.cpp:4156] Processing ACCEPT call for offers: [ 4479157b-8091-4d7a-8add-b8bd8cf96ad1-O0 ] on agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 at slave(25)@172.17.0.4:43745 (ad57000f913b) for framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 (default)
I0901 16:36:37.353720 30824 master.cpp:3533] Authorizing framework principal 'test-principal' to launch task 8348ced9-f32a-4f9e-a78f-5857bddcba27
I0901 16:36:37.357100 30824 master.cpp:9908] Adding task 8348ced9-f32a-4f9e-a78f-5857bddcba27 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":32.0},"type":"SCALAR"}] on agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 at slave(25)@172.17.0.4:43745 (ad57000f913b)
I0901 16:36:37.357877 30824 master.cpp:4819] Launching task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 (default) with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":32.0},"type":"SCALAR"}] on agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 at slave(25)@172.17.0.4:43745 (ad57000f913b)
I0901 16:36:37.359458 30820 slave.cpp:1744] Got assigned task '8348ced9-f32a-4f9e-a78f-5857bddcba27' for framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.360930 30820 slave.cpp:2012] Authorizing task '8348ced9-f32a-4f9e-a78f-5857bddcba27' for framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.361125 30820 slave.cpp:6795] Authorizing framework principal 'test-principal' to launch task 8348ced9-f32a-4f9e-a78f-5857bddcba27
I0901 16:36:37.361341 30826 hierarchical.cpp:887] Updated allocation of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 on agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 from cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000] to cpus(allocated: *):2; mem(allocated: *):1024; disk(allocated: *):1024; ports(allocated: *):[31000-32000]
I0901 16:36:37.362469 30824 slave.cpp:2180] Launching task '8348ced9-f32a-4f9e-a78f-5857bddcba27' for framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.362769 30826 hierarchical.cpp:1161] Recovered cpus(allocated: *):1.9; mem(allocated: *):992; disk(allocated: *):992; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: cpus(allocated: *):0.1; mem(allocated: *):32; disk(allocated: *):32) on agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 from framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.362933 30826 hierarchical.cpp:1207] Framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 filtered agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 for 5secs
I0901 16:36:37.363467 30824 paths.cpp:578] Trying to chown '/tmp/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_mcQroR/slaves/4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0/frameworks/4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000/executors/8348ced9-f32a-4f9e-a78f-5857bddcba27/runs/943443b5-2f40-42b5-bb95-163c5c55da60' to user 'mesos'
I0901 16:36:37.363986 30824 slave.cpp:7257] Launching executor '8348ced9-f32a-4f9e-a78f-5857bddcba27' of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}] in work directory '/tmp/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_mcQroR/slaves/4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0/frameworks/4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000/executors/8348ced9-f32a-4f9e-a78f-5857bddcba27/runs/943443b5-2f40-42b5-bb95-163c5c55da60'
I0901 16:36:37.365036 30824 slave.cpp:2871] Launching container 943443b5-2f40-42b5-bb95-163c5c55da60 for executor '8348ced9-f32a-4f9e-a78f-5857bddcba27' of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.365581 30825 containerizer.cpp:1120] Starting container 943443b5-2f40-42b5-bb95-163c5c55da60
I0901 16:36:37.365603 30824 slave.cpp:2408] Queued task '8348ced9-f32a-4f9e-a78f-5857bddcba27' for executor '8348ced9-f32a-4f9e-a78f-5857bddcba27' of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.365824 30824 slave.cpp:940] Successfully attached file '/tmp/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_mcQroR/slaves/4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0/frameworks/4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000/executors/8348ced9-f32a-4f9e-a78f-5857bddcba27/runs/943443b5-2f40-42b5-bb95-163c5c55da60'
I0901 16:36:37.365897 30824 slave.cpp:940] Successfully attached file '/tmp/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_mcQroR/slaves/4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0/frameworks/4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000/executors/8348ced9-f32a-4f9e-a78f-5857bddcba27/runs/943443b5-2f40-42b5-bb95-163c5c55da60'
I0901 16:36:37.366456 30825 containerizer.cpp:2749] Transitioning the state of container 943443b5-2f40-42b5-bb95-163c5c55da60 from PROVISIONING to PREPARING
I0901 16:36:37.373553 30821 containerizer.cpp:1718] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/mesos\/build\/src"],"shell":false,"value":"\/mesos\/build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.4:43745"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_mcQroR\/slaves\/4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0\/frameworks\/4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000\/executors\/8348ced9-f32a-4f9e-a78f-5857bddcba27\/runs\/943443b5-2f40-42b5-bb95-163c5c55da60"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"8348ced9-f32a-4f9e-a78f-5857bddcba27"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(25)@172.17.0.4:43745"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_mcQroR\/slaves\/4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0\/frameworks\/4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000\/executors\/8348ced9-f32a-4f9e-a78f-5857bddcba27\/runs\/943443b5-2f40-42b5-bb95-163c5c55da60"}]},"task_environment":{},"user":"mesos","working_directory":"\/tmp\/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_mcQroR\/slaves\/4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0\/frameworks\/4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000\/executors\/8348ced9-f32a-4f9e-a78f-5857bddcba27\/runs\/943443b5-2f40-42b5-bb95-163c5c55da60"}" --pipe_read="12" --pipe_write="13" --runtime_directory="/tmp/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_Z8EEWe/containers/943443b5-2f40-42b5-bb95-163c5c55da60" --unshare_namespace_mnt="false"'
I0901 16:36:37.376618 30821 launcher.cpp:140] Forked child with pid '31258' for container '943443b5-2f40-42b5-bb95-163c5c55da60'
I0901 16:36:37.377436 30821 containerizer.cpp:2749] Transitioning the state of container 943443b5-2f40-42b5-bb95-163c5c55da60 from PREPARING to ISOLATING
I0901 16:36:37.384222 30821 containerizer.cpp:2749] Transitioning the state of container 943443b5-2f40-42b5-bb95-163c5c55da60 from ISOLATING to FETCHING
I0901 16:36:37.384428 30821 fetcher.cpp:377] Starting to fetch URIs for container: 943443b5-2f40-42b5-bb95-163c5c55da60, directory: /tmp/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_mcQroR/slaves/4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0/frameworks/4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000/executors/8348ced9-f32a-4f9e-a78f-5857bddcba27/runs/943443b5-2f40-42b5-bb95-163c5c55da60
I0901 16:36:37.385408 30826 containerizer.cpp:2749] Transitioning the state of container 943443b5-2f40-42b5-bb95-163c5c55da60 from FETCHING to RUNNING
I0901 16:36:37.614356 30826 slave.cpp:3938] Got registration for executor '8348ced9-f32a-4f9e-a78f-5857bddcba27' of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 from executor(1)@172.17.0.4:40677
I0901 16:36:37.620623 30825 slave.cpp:2610] Sending queued task '8348ced9-f32a-4f9e-a78f-5857bddcba27' to executor '8348ced9-f32a-4f9e-a78f-5857bddcba27' of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 at executor(1)@172.17.0.4:40677
I0901 16:36:37.656997 30821 slave.cpp:4392] Handling status update TASK_RUNNING (UUID: 0878027e-9e0a-41fe-a312-247a9e2bdfbd) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 from executor(1)@172.17.0.4:40677
I0901 16:36:37.659351 30826 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: 0878027e-9e0a-41fe-a312-247a9e2bdfbd) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.659479 30826 status_update_manager.cpp:500] Creating StatusUpdate stream for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.660300 30826 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 0878027e-9e0a-41fe-a312-247a9e2bdfbd) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 to the agent
I0901 16:36:37.660835 30820 slave.cpp:4873] Forwarding the update TASK_RUNNING (UUID: 0878027e-9e0a-41fe-a312-247a9e2bdfbd) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 to master@172.17.0.4:43745
I0901 16:36:37.661253 30820 slave.cpp:4767] Status update manager successfully handled status update TASK_RUNNING (UUID: 0878027e-9e0a-41fe-a312-247a9e2bdfbd) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.661342 30820 slave.cpp:4783] Sending acknowledgement for status update TASK_RUNNING (UUID: 0878027e-9e0a-41fe-a312-247a9e2bdfbd) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 to executor(1)@172.17.0.4:40677
I0901 16:36:37.661640 30821 master.cpp:6843] Status update TASK_RUNNING (UUID: 0878027e-9e0a-41fe-a312-247a9e2bdfbd) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 from agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 at slave(25)@172.17.0.4:43745 (ad57000f913b)
I0901 16:36:37.661734 30821 master.cpp:6905] Forwarding status update TASK_RUNNING (UUID: 0878027e-9e0a-41fe-a312-247a9e2bdfbd) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.662405 30821 master.cpp:8930] Updating the state of task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I0901 16:36:37.664108 30823 scheduler.cpp:676] Enqueuing event UPDATE received from http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:37.666062 30826 scheduler.cpp:243] Sending ACKNOWLEDGE call to http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:37.669059 30827 process.cpp:3956] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0901 16:36:37.710971 30824 slave.cpp:4392] Handling status update TASK_RUNNING (UUID: 463a78f9-a933-40be-925f-09ff41332c5e) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 from executor(1)@172.17.0.4:40677
I0901 16:36:37.713572 30823 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: 463a78f9-a933-40be-925f-09ff41332c5e) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.713994 30821 slave.cpp:4767] Status update manager successfully handled status update TASK_RUNNING (UUID: 463a78f9-a933-40be-925f-09ff41332c5e) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.714110 30821 slave.cpp:4783] Sending acknowledgement for status update TASK_RUNNING (UUID: 463a78f9-a933-40be-925f-09ff41332c5e) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 to executor(1)@172.17.0.4:40677
I0901 16:36:37.716020 30821 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:42698
I0901 16:36:37.716382 30821 master.cpp:5482] Processing ACKNOWLEDGE call 0878027e-9e0a-41fe-a312-247a9e2bdfbd for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 (default) on agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0
I0901 16:36:37.716938 30824 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 0878027e-9e0a-41fe-a312-247a9e2bdfbd) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.717392 30824 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 463a78f9-a933-40be-925f-09ff41332c5e) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 to the agent
I0901 16:36:37.717821 30826 slave.cpp:4873] Forwarding the update TASK_RUNNING (UUID: 463a78f9-a933-40be-925f-09ff41332c5e) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 to master@172.17.0.4:43745
I0901 16:36:37.718423 30820 master.cpp:6843] Status update TASK_RUNNING (UUID: 463a78f9-a933-40be-925f-09ff41332c5e) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 from agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 at slave(25)@172.17.0.4:43745 (ad57000f913b)
I0901 16:36:37.718526 30820 master.cpp:6905] Forwarding status update TASK_RUNNING (UUID: 463a78f9-a933-40be-925f-09ff41332c5e) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.718757 30826 slave.cpp:3676] Status update manager successfully handled status update acknowledgement (UUID: 0878027e-9e0a-41fe-a312-247a9e2bdfbd) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.719429 30820 master.cpp:8930] Updating the state of task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I0901 16:36:37.721509 30826 scheduler.cpp:676] Enqueuing event UPDATE received from http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:37.723250 30823 scheduler.cpp:243] Sending ACKNOWLEDGE call to http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:37.725720 30826 process.cpp:3956] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0901 16:36:37.775789 30820 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:42698
I0901 16:36:37.776278 30820 master.cpp:5482] Processing ACKNOWLEDGE call 463a78f9-a933-40be-925f-09ff41332c5e for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 (default) on agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0
I0901 16:36:37.776872 30820 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 463a78f9-a933-40be-925f-09ff41332c5e) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:37.777456 30821 slave.cpp:3676] Status update manager successfully handled status update acknowledgement (UUID: 463a78f9-a933-40be-925f-09ff41332c5e) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:38.281807 30826 hierarchical.cpp:2192] Filtered offer with cpus:1.9; mem:992; disk:992; ports:[31000-32000] on agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 for role * of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:38.281888 30826 hierarchical.cpp:1943] No allocations performed
I0901 16:36:38.281944 30826 hierarchical.cpp:2033] No inverse offers to send out!
I0901 16:36:38.282007 30826 hierarchical.cpp:1486] Performed allocation for 1 agents in 872249ns
I0901 16:36:38.715114 30827 slave.cpp:4392] Handling status update TASK_RUNNING (UUID: 6eb935e1-f6e7-4c4d-a385-98fa6abb2165) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 in health state healthy of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 from executor(1)@172.17.0.4:40677
I0901 16:36:38.717308 30824 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: 6eb935e1-f6e7-4c4d-a385-98fa6abb2165) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 in health state healthy of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:38.717607 30824 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 6eb935e1-f6e7-4c4d-a385-98fa6abb2165) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 in health state healthy of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 to the agent
I0901 16:36:38.718036 30823 slave.cpp:4873] Forwarding the update TASK_RUNNING (UUID: 6eb935e1-f6e7-4c4d-a385-98fa6abb2165) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 in health state healthy of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 to master@172.17.0.4:43745
I0901 16:36:38.718437 30823 slave.cpp:4767] Status update manager successfully handled status update TASK_RUNNING (UUID: 6eb935e1-f6e7-4c4d-a385-98fa6abb2165) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 in health state healthy of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:38.718510 30823 slave.cpp:4783] Sending acknowledgement for status update TASK_RUNNING (UUID: 6eb935e1-f6e7-4c4d-a385-98fa6abb2165) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 in health state healthy of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 to executor(1)@172.17.0.4:40677
I0901 16:36:38.718717 30826 master.cpp:6843] Status update TASK_RUNNING (UUID: 6eb935e1-f6e7-4c4d-a385-98fa6abb2165) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 in health state healthy of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 from agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 at slave(25)@172.17.0.4:43745 (ad57000f913b)
I0901 16:36:38.718813 30826 master.cpp:6905] Forwarding status update TASK_RUNNING (UUID: 6eb935e1-f6e7-4c4d-a385-98fa6abb2165) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 in health state healthy of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:38.719503 30826 master.cpp:8930] Updating the state of task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
I0901 16:36:38.721565 30821 scheduler.cpp:676] Enqueuing event UPDATE received from http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:38.723479 30825 scheduler.cpp:243] Sending ACKNOWLEDGE call to http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:38.724254 30825 scheduler.cpp:243] Sending RECONCILE call to http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:38.726137 30824 process.cpp:3956] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0901 16:36:38.775346 30821 process.cpp:3956] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0901 16:36:38.776461 30821 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:42698
I0901 16:36:38.776854 30821 master.cpp:5482] Processing ACKNOWLEDGE call 6eb935e1-f6e7-4c4d-a385-98fa6abb2165 for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 (default) on agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0
I0901 16:36:38.777671 30823 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 6eb935e1-f6e7-4c4d-a385-98fa6abb2165) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:38.777808 30827 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:42698
I0901 16:36:38.778049 30827 master.cpp:7277] Performing implicit task state reconciliation for framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 (default)
I0901 16:36:38.778235 30821 slave.cpp:3676] Status update manager successfully handled status update acknowledgement (UUID: 6eb935e1-f6e7-4c4d-a385-98fa6abb2165) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:38.778308 30827 master.cpp:7327] Sending implicit reconciliation state TASK_RUNNING for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 (default)
I0901 16:36:38.780807 30824 scheduler.cpp:676] Enqueuing event UPDATE received from http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:38.782570 30825 scheduler.cpp:243] Sending TEARDOWN call to http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:38.785470 30827 process.cpp:3956] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
I0901 16:36:38.835988 30827 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:42698
I0901 16:36:38.836207 30827 master.cpp:8357] Removing framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 (default)
I0901 16:36:38.836236 30827 master.cpp:3267] Deactivating framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 (default)
I0901 16:36:38.836482 30821 hierarchical.cpp:412] Deactivated framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:38.836558 30826 slave.cpp:3208] Asked to shut down framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 by master@172.17.0.4:43745
I0901 16:36:38.836621 30826 slave.cpp:3233] Shutting down framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:38.836661 30827 master.cpp:8930] Updating the state of task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
I0901 16:36:38.836695 30826 slave.cpp:5729] Shutting down executor '8348ced9-f32a-4f9e-a78f-5857bddcba27' of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 at executor(1)@172.17.0.4:40677
I0901 16:36:38.837829 30827 master.cpp:9024] Removing task 8348ced9-f32a-4f9e-a78f-5857bddcba27 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":32.0},"type":"SCALAR"}] of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 on agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 at slave(25)@172.17.0.4:43745 (ad57000f913b)
I0901 16:36:38.838186 30820 hierarchical.cpp:1161] Recovered cpus(allocated: *):0.1; mem(allocated: *):32; disk(allocated: *):32 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent 4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0 from framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
E0901 16:36:38.840797 30823 scheduler.cpp:649] End-Of-File received from master. The master closed the event stream
I0901 16:36:38.841464 30826 scheduler.cpp:444] Re-detecting master
I0901 16:36:38.842234 30826 scheduler.cpp:395] Ignoring disconnection attempt from stale connection
I0901 16:36:38.842615 30826 scheduler.cpp:470] New master detected at master@172.17.0.4:43745
I0901 16:36:38.842653 30826 scheduler.cpp:479] Waiting for 0ns before initiating a re-(connection) attempt with the master
I0901 16:36:38.842996 30826 scheduler.cpp:395] Ignoring disconnection attempt from stale connection
I0901 16:36:38.839468 30824 hierarchical.cpp:355] Removed framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:38.848305 30826 scheduler.cpp:361] Connected with the master at http://172.17.0.4:43745/master/api/v1/scheduler
I0901 16:36:38.917690 30826 slave.cpp:4392] Handling status update TASK_KILLED (UUID: c613e2ec-502d-4562-85fa-a6b3021aac8e) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 from executor(1)@172.17.0.4:40677
W0901 16:36:38.917805 30826 slave.cpp:4461] Ignoring status update TASK_KILLED (UUID: c613e2ec-502d-4562-85fa-a6b3021aac8e) for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 for terminating framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:39.283192 30826 hierarchical.cpp:1943] No allocations performed
I0901 16:36:39.283278 30826 hierarchical.cpp:1486] Performed allocation for 1 agents in 297611ns
I0901 16:36:39.945389 30827 slave.cpp:5005] Got exited event for executor(1)@172.17.0.4:40677
I0901 16:36:39.964630 30824 containerizer.cpp:2649] Container 943443b5-2f40-42b5-bb95-163c5c55da60 has exited
I0901 16:36:39.964679 30824 containerizer.cpp:2203] Destroying container 943443b5-2f40-42b5-bb95-163c5c55da60 in RUNNING state
I0901 16:36:39.964701 30824 containerizer.cpp:2749] Transitioning the state of container 943443b5-2f40-42b5-bb95-163c5c55da60 from RUNNING to DESTROYING
I0901 16:36:39.964982 30824 launcher.cpp:156] Asked to destroy container 943443b5-2f40-42b5-bb95-163c5c55da60
I0901 16:36:39.970878 30823 provisioner.cpp:490] Ignoring destroy request for unknown container 943443b5-2f40-42b5-bb95-163c5c55da60
I0901 16:36:39.971793 30824 slave.cpp:5405] Executor '8348ced9-f32a-4f9e-a78f-5857bddcba27' of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 exited with status 0
I0901 16:36:39.971876 30824 slave.cpp:5509] Cleaning up executor '8348ced9-f32a-4f9e-a78f-5857bddcba27' of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000 at executor(1)@172.17.0.4:40677
I0901 16:36:39.972170 30827 gc.cpp:91] Scheduling '/tmp/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_mcQroR/slaves/4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0/frameworks/4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000/executors/8348ced9-f32a-4f9e-a78f-5857bddcba27/runs/943443b5-2f40-42b5-bb95-163c5c55da60' for gc 6.99998874952593days in the future
I0901 16:36:39.972376 30824 slave.cpp:5605] Cleaning up framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:39.972455 30827 gc.cpp:91] Scheduling '/tmp/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_mcQroR/slaves/4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0/frameworks/4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000/executors/8348ced9-f32a-4f9e-a78f-5857bddcba27' for gc 6.99998874677037days in the future
I0901 16:36:39.972630 30826 status_update_manager.cpp:285] Closing status update streams for framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:39.972683 30826 status_update_manager.cpp:531] Cleaning up status update stream for task 8348ced9-f32a-4f9e-a78f-5857bddcba27 of framework 4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000
I0901 16:36:39.972731 30824 gc.cpp:91] Scheduling '/tmp/DefaultExecutorCheckTest_CommandCheckAndHealthCheckNoShadowing_mcQroR/slaves/4479157b-8091-4d7a-8add-b8bd8cf96ad1-S0/frameworks/4479157b-8091-4d7a-8add-b8bd8cf96ad1-0000' for gc 6.99998874337778days in the future
Build timed out (after 300 minutes). Marking the build as failed.
Build was aborted
++ docker rmi mesos-1504280195-20433
Error response from daemon: conflict: unable to remove repository reference "mesos-1504280195-20433" (must force) - container ad57000f913b is using its referenced image 8343ce330462
Not sending mail to unregistered user songzihao1990@gmail.com

Jenkins build is back to normal : Mesos-Buildbot » cmake,clang,--verbose,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2) #4185

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)/4185/display/redirect?page=changes>