See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=autotools,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)/4328/display/redirect?page=changes>
Changes: [bmahler] Added protobuf install handler benchmark. ------------------------------------------ [...truncated 23.49 MB...] I1017 00:07:49.693032 6796 slave.cpp:254] Mesos agent started on (528)@172.17.0.2:43465 I1017 00:07:49.693140 6796 slave.cpp:255] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/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/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/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/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/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/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/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/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.5.0/_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/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST" --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/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn" --zk_session_timeout="10secs" I1017 00:07:49.693688 6796 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/credential' I1017 00:07:49.693958 6796 slave.cpp:287] Agent using credential for: test-principal I1017 00:07:49.694064 6796 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/http_credentials' I1017 00:07:49.694550 6796 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor' I1017 00:07:49.694809 6796 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor' I1017 00:07:49.695083 6796 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' I1017 00:07:49.695241 6796 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly' I1017 00:07:49.695541 6796 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' I1017 00:07:49.695768 6796 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite' W1017 00:07:49.696123 6788 process.cpp:3194] Attempted to spawn already running process [email protected]:43465 I1017 00:07:49.697326 6788 sched.cpp:232] Version: 1.5.0 I1017 00:07:49.697634 6796 slave.cpp:585] 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"}] I1017 00:07:49.697928 6796 slave.cpp:593] Agent attributes: [ ] I1017 00:07:49.697944 6796 slave.cpp:602] Agent hostname: 9c0b222740d3 I1017 00:07:49.697981 6795 sched.cpp:336] New master detected at [email protected]:43465 I1017 00:07:49.698087 6795 sched.cpp:396] Authenticating with master [email protected]:43465 I1017 00:07:49.698104 6795 sched.cpp:403] Using default CRAM-MD5 authenticatee I1017 00:07:49.698170 6802 status_update_manager.cpp:177] Pausing sending status updates I1017 00:07:49.698329 6802 authenticatee.cpp:121] Creating new client SASL connection I1017 00:07:49.698613 6807 master.cpp:7936] Authenticating [email protected]:43465 I1017 00:07:49.698797 6807 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1073)@172.17.0.2:43465 I1017 00:07:49.699154 6807 authenticator.cpp:98] Creating new server SASL connection I1017 00:07:49.699571 6802 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I1017 00:07:49.699676 6802 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I1017 00:07:49.699926 6802 authenticator.cpp:204] Received SASL authentication start I1017 00:07:49.699966 6809 state.cpp:64] Recovering state from '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/meta' I1017 00:07:49.700119 6802 authenticator.cpp:326] Authentication requires more steps I1017 00:07:49.700265 6809 status_update_manager.cpp:203] Recovering status update manager I1017 00:07:49.700387 6802 authenticatee.cpp:259] Received SASL authentication step I1017 00:07:49.700646 6801 slave.cpp:6310] Finished recovery I1017 00:07:49.700660 6791 authenticator.cpp:232] Received SASL authentication step I1017 00:07:49.700855 6791 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9c0b222740d3' server FQDN: '9c0b222740d3' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1017 00:07:49.700873 6791 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I1017 00:07:49.700917 6791 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1017 00:07:49.700938 6791 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9c0b222740d3' server FQDN: '9c0b222740d3' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1017 00:07:49.700950 6791 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1017 00:07:49.700960 6791 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1017 00:07:49.700980 6791 authenticator.cpp:318] Authentication success I1017 00:07:49.701100 6803 authenticatee.cpp:299] Authentication success I1017 00:07:49.701361 6801 slave.cpp:6492] Querying resource estimator for oversubscribable resources I1017 00:07:49.701568 6801 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1073)@172.17.0.2:43465 I1017 00:07:49.701378 6797 master.cpp:7966] Successfully authenticated principal 'test-principal' at [email protected]:43465 I1017 00:07:49.701743 6798 status_update_manager.cpp:177] Pausing sending status updates I1017 00:07:49.701967 6803 sched.cpp:502] Successfully authenticated with master [email protected]:43465 I1017 00:07:49.702054 6803 sched.cpp:820] Sending SUBSCRIBE call to [email protected]:43465 I1017 00:07:49.702055 6791 slave.cpp:993] New master detected at [email protected]:43465 I1017 00:07:49.702215 6803 sched.cpp:853] Will retry registration in 1.150332041secs if necessary I1017 00:07:49.702222 6791 slave.cpp:1028] Detecting new master I1017 00:07:49.702477 6789 master.cpp:2929] Received SUBSCRIBE call for framework 'default' at [email protected]:43465 I1017 00:07:49.702621 6789 master.cpp:2263] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' *** Aborted at 1508198869 (unix time) try "date -d @1508198869" if you are using GNU date *** I1017 00:07:49.703171 6792 master.cpp:3009] Subscribing framework default with checkpointing enabled and capabilities [ RESERVATION_REFINEMENT ] I1017 00:07:49.702661 6791 slave.cpp:6506] Received oversubscribable resources {} from the resource estimator I1017 00:07:49.703991 6812 hierarchical.cpp:303] Added framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.704010 6792 sched.cpp:747] Framework registered with 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.704057 6792 sched.cpp:761] Scheduler::registered took 31491ns I1017 00:07:49.704165 6812 hierarchical.cpp:1943] No allocations performed I1017 00:07:49.704210 6812 hierarchical.cpp:2033] No inverse offers to send out! I1017 00:07:49.704244 6812 hierarchical.cpp:1486] Performed allocation for 0 agents in 129925ns I1017 00:07:49.705420 6811 slave.cpp:1055] Authenticating with master [email protected]:43465 I1017 00:07:49.705548 6811 slave.cpp:1064] Using default CRAM-MD5 authenticatee I1017 00:07:49.705816 6811 authenticatee.cpp:121] Creating new client SASL connection I1017 00:07:49.706097 6811 master.cpp:7936] Authenticating slave(528)@172.17.0.2:43465 I1017 00:07:49.706305 6811 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1074)@172.17.0.2:43465 I1017 00:07:49.706740 6811 authenticator.cpp:98] Creating new server SASL connection I1017 00:07:49.707093 6811 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I1017 00:07:49.707193 6811 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I1017 00:07:49.707432 6811 authenticator.cpp:204] Received SASL authentication start I1017 00:07:49.707597 6811 authenticator.cpp:326] Authentication requires more steps I1017 00:07:49.707855 6808 authenticatee.cpp:259] Received SASL authentication step I1017 00:07:49.708015 6795 authenticator.cpp:232] Received SASL authentication step I1017 00:07:49.708104 6795 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9c0b222740d3' server FQDN: '9c0b222740d3' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1017 00:07:49.708169 6795 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I1017 00:07:49.708251 6795 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1017 00:07:49.708314 6795 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '9c0b222740d3' server FQDN: '9c0b222740d3' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1017 00:07:49.708369 6795 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1017 00:07:49.708416 6795 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1017 00:07:49.708467 6795 authenticator.cpp:318] Authentication success I1017 00:07:49.708580 6803 authenticatee.cpp:299] Authentication success I1017 00:07:49.708691 6804 master.cpp:7966] Successfully authenticated principal 'test-principal' at slave(528)@172.17.0.2:43465 I1017 00:07:49.708714 6795 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1074)@172.17.0.2:43465 I1017 00:07:49.708859 6803 slave.cpp:1147] Successfully authenticated with master [email protected]:43465 I1017 00:07:49.709178 6803 slave.cpp:1626] Will retry registration in 19.294825ms if necessary I1017 00:07:49.709463 6797 master.cpp:5801] Received register agent message from slave(528)@172.17.0.2:43465 (9c0b222740d3) I1017 00:07:49.709512 6797 master.cpp:3838] Authorizing agent with principal 'test-principal' I1017 00:07:49.710013 6796 master.cpp:5861] Authorized registration of agent at slave(528)@172.17.0.2:43465 (9c0b222740d3) I1017 00:07:49.710136 6796 master.cpp:5954] Registering agent at slave(528)@172.17.0.2:43465 (9c0b222740d3) with id 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 I1017 00:07:49.710551 6800 registrar.cpp:495] Applied 1 operations in 116031ns; attempting to update the registry I1017 00:07:49.711277 6800 registrar.cpp:552] Successfully updated the registry in 645888ns I1017 00:07:49.711472 6810 master.cpp:6001] Admitted agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 at slave(528)@172.17.0.2:43465 (9c0b222740d3) I1017 00:07:49.712348 6798 slave.cpp:1193] Registered with master [email protected]:43465; given agent ID 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 I1017 00:07:49.712100 6810 master.cpp:6032] Registered agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 at slave(528)@172.17.0.2:43465 (9c0b222740d3) 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"}] I1017 00:07:49.712466 6811 status_update_manager.cpp:184] Resuming sending status updates I1017 00:07:49.712546 6801 hierarchical.cpp:593] Added agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 (9c0b222740d3) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {}) I1017 00:07:49.712831 6798 slave.cpp:1213] Checkpointing SlaveInfo to '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/meta/slaves/06e1acf5-8d67-44ec-a476-ad666d83361f-S0/slave.info' I1017 00:07:49.713260 6798 slave.cpp:1262] Forwarding total oversubscribed resources {} I1017 00:07:49.713407 6798 slave.cpp:4966] Received ping from slave-observer(508)@172.17.0.2:43465 I1017 00:07:49.713547 6808 master.cpp:6817] Received update of agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 at slave(528)@172.17.0.2:43465 (9c0b222740d3) with total oversubscribed resources {} I1017 00:07:49.713698 6801 hierarchical.cpp:2033] No inverse offers to send out! I1017 00:07:49.713747 6808 master.cpp:6828] Ignoring update on agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 at slave(528)@172.17.0.2:43465 (9c0b222740d3) as it reports no changes I1017 00:07:49.713747 6801 hierarchical.cpp:1486] Performed allocation for 1 agents in 1.057299ms I1017 00:07:49.714298 6808 master.cpp:7766] Sending 1 offers to framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 (default) at [email protected]:43465 I1017 00:07:49.715474 6804 sched.cpp:917] Scheduler::resourceOffers took 717292ns I1017 00:07:49.716655 6794 master.cpp:9389] Removing offer 06e1acf5-8d67-44ec-a476-ad666d83361f-O0 I1017 00:07:49.716794 6794 master.cpp:4196] Processing ACCEPT call for offers: [ 06e1acf5-8d67-44ec-a476-ad666d83361f-O0 ] on agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 at slave(528)@172.17.0.2:43465 (9c0b222740d3) for framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 (default) at [email protected]:43465 I1017 00:07:49.716887 6794 master.cpp:3565] Authorizing framework principal 'test-principal' to launch task 0 W1017 00:07:49.718471 6794 validation.cpp:1338] 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. W1017 00:07:49.718500 6794 validation.cpp:1350] 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. I1017 00:07:49.718848 6794 master.cpp:10135] Adding task 0 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] on agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 at slave(528)@172.17.0.2:43465 (9c0b222740d3) I1017 00:07:49.719202 6794 master.cpp:4879] Launching task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 (default) at [email protected]:43465 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":512.0},"type":"SCALAR"}] on agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 at slave(528)@172.17.0.2:43465 (9c0b222740d3) I1017 00:07:49.719704 6797 slave.cpp:1747] Got assigned task '0' for framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.719878 6797 slave.cpp:7202] Checkpointing FrameworkInfo to '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/meta/slaves/06e1acf5-8d67-44ec-a476-ad666d83361f-S0/frameworks/06e1acf5-8d67-44ec-a476-ad666d83361f-0000/framework.info' I1017 00:07:49.720234 6797 slave.cpp:7213] Checkpointing framework pid '[email protected]:43465' to '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/meta/slaves/06e1acf5-8d67-44ec-a476-ad666d83361f-S0/frameworks/06e1acf5-8d67-44ec-a476-ad666d83361f-0000/framework.pid' I1017 00:07:49.720896 6797 slave.cpp:2015] Authorizing task '0' for framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.720952 6797 slave.cpp:6809] Authorizing framework principal 'test-principal' to launch task 0 I1017 00:07:49.721602 6812 slave.cpp:2183] Launching task '0' for framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.722168 6792 hierarchical.cpp:887] Updated allocation of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 on agent 06e1acf5-8d67-44ec-a476-ad666d83361f-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] I1017 00:07:49.722249 6812 paths.cpp:605] Trying to chown '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/slaves/06e1acf5-8d67-44ec-a476-ad666d83361f-S0/frameworks/06e1acf5-8d67-44ec-a476-ad666d83361f-0000/executors/default/runs/57ab5523-9eff-4486-9a66-f1181a4e0154' to user 'mesos' I1017 00:07:49.722560 6812 slave.cpp:7907] Checkpointing ExecutorInfo to '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/meta/slaves/06e1acf5-8d67-44ec-a476-ad666d83361f-S0/frameworks/06e1acf5-8d67-44ec-a476-ad666d83361f-0000/executors/default/executor.info' I1017 00:07:49.723315 6812 slave.cpp:7283] Launching executor 'default' of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 with resources [] in work directory '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/slaves/06e1acf5-8d67-44ec-a476-ad666d83361f-S0/frameworks/06e1acf5-8d67-44ec-a476-ad666d83361f-0000/executors/default/runs/57ab5523-9eff-4486-9a66-f1181a4e0154' I1017 00:07:49.723445 6792 hierarchical.cpp:1161] Recovered cpus(allocated: *):1; mem(allocated: *):512; disk(allocated: *):1024; ports(allocated: *):[31000-32000] (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: cpus(allocated: *):1; mem(allocated: *):512) on agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 from framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.723592 6792 hierarchical.cpp:1207] Framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 filtered agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 for 5secs I1017 00:07:49.724651 6812 slave.cpp:7950] Checkpointing TaskInfo to '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/meta/slaves/06e1acf5-8d67-44ec-a476-ad666d83361f-S0/frameworks/06e1acf5-8d67-44ec-a476-ad666d83361f-0000/executors/default/runs/57ab5523-9eff-4486-9a66-f1181a4e0154/tasks/0/task.info' I1017 00:07:49.725256 6812 slave.cpp:2411] Queued task '0' for executor 'default' of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.725348 6812 slave.cpp:944] Successfully attached '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/slaves/06e1acf5-8d67-44ec-a476-ad666d83361f-S0/frameworks/06e1acf5-8d67-44ec-a476-ad666d83361f-0000/executors/default/runs/57ab5523-9eff-4486-9a66-f1181a4e0154' to virtual path '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/slaves/06e1acf5-8d67-44ec-a476-ad666d83361f-S0/frameworks/06e1acf5-8d67-44ec-a476-ad666d83361f-0000/executors/default/runs/latest' I1017 00:07:49.725389 6812 slave.cpp:944] Successfully attached '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/slaves/06e1acf5-8d67-44ec-a476-ad666d83361f-S0/frameworks/06e1acf5-8d67-44ec-a476-ad666d83361f-0000/executors/default/runs/57ab5523-9eff-4486-9a66-f1181a4e0154' to virtual path '/frameworks/06e1acf5-8d67-44ec-a476-ad666d83361f-0000/executors/default/runs/latest' I1017 00:07:49.725419 6812 slave.cpp:944] Successfully attached '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/slaves/06e1acf5-8d67-44ec-a476-ad666d83361f-S0/frameworks/06e1acf5-8d67-44ec-a476-ad666d83361f-0000/executors/default/runs/57ab5523-9eff-4486-9a66-f1181a4e0154' to virtual path '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/slaves/06e1acf5-8d67-44ec-a476-ad666d83361f-S0/frameworks/06e1acf5-8d67-44ec-a476-ad666d83361f-0000/executors/default/runs/57ab5523-9eff-4486-9a66-f1181a4e0154' I1017 00:07:49.725690 6812 slave.cpp:2874] Launching container 57ab5523-9eff-4486-9a66-f1181a4e0154 for executor 'default' of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 PC: @ 0x2aab1f96d3d0 process::EventQueue::Consumer::empty() W1017 00:07:49.728549 6810 process.cpp:3194] Attempted to spawn already running process [email protected]:43465 I1017 00:07:49.728843 6810 exec.cpp:162] Version: 1.5.0 I1017 00:07:49.729573 6810 exec.cpp:212] Executor started at: executor(135)@172.17.0.2:43465 with pid 6788 I1017 00:07:49.730157 6810 slave.cpp:3941] Got registration for executor 'default' of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 from executor(135)@172.17.0.2:43465 I1017 00:07:49.730365 6810 slave.cpp:4027] Checkpointing executor pid 'executor(135)@172.17.0.2:43465' to '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/meta/slaves/06e1acf5-8d67-44ec-a476-ad666d83361f-S0/frameworks/06e1acf5-8d67-44ec-a476-ad666d83361f-0000/executors/default/runs/57ab5523-9eff-4486-9a66-f1181a4e0154/pids/libprocess.pid' I1017 00:07:49.731746 6810 exec.cpp:237] Executor registered on agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 I1017 00:07:49.731842 6810 exec.cpp:249] Executor::registered took 37485ns I1017 00:07:49.732254 6810 slave.cpp:2613] Sending queued task '0' to executor 'default' of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 at executor(135)@172.17.0.2:43465 I1017 00:07:49.732717 6810 exec.cpp:331] Executor asked to run task '0' I1017 00:07:49.732939 6810 exec.cpp:340] Executor::launchTask took 132866ns I1017 00:07:49.733165 6810 exec.cpp:571] Executor sending status update TASK_RUNNING (UUID: e466b153-9f67-46d8-adc3-d0e6055d312c) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.733567 6810 slave.cpp:4395] Handling status update TASK_RUNNING (UUID: e466b153-9f67-46d8-adc3-d0e6055d312c) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 from executor(135)@172.17.0.2:43465 I1017 00:07:49.734351 6790 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: e466b153-9f67-46d8-adc3-d0e6055d312c) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.734410 6790 status_update_manager.cpp:500] Creating StatusUpdate stream for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.735263 6790 status_update_manager.cpp:834] Checkpointing UPDATE for status update TASK_RUNNING (UUID: e466b153-9f67-46d8-adc3-d0e6055d312c) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.735606 6790 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: e466b153-9f67-46d8-adc3-d0e6055d312c) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 to the agent I1017 00:07:49.735898 6797 slave.cpp:4876] Forwarding the update TASK_RUNNING (UUID: e466b153-9f67-46d8-adc3-d0e6055d312c) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 to [email protected]:43465 I1017 00:07:49.736114 6797 slave.cpp:4770] Status update manager successfully handled status update TASK_RUNNING (UUID: e466b153-9f67-46d8-adc3-d0e6055d312c) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.736176 6797 slave.cpp:4786] Sending acknowledgement for status update TASK_RUNNING (UUID: e466b153-9f67-46d8-adc3-d0e6055d312c) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 to executor(135)@172.17.0.2:43465 I1017 00:07:49.736605 6797 master.cpp:6993] Status update TASK_RUNNING (UUID: e466b153-9f67-46d8-adc3-d0e6055d312c) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 from agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 at slave(528)@172.17.0.2:43465 (9c0b222740d3) I1017 00:07:49.736666 6797 master.cpp:7055] Forwarding status update TASK_RUNNING (UUID: e466b153-9f67-46d8-adc3-d0e6055d312c) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.736865 6797 master.cpp:9157] Updating the state of task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING) I1017 00:07:49.737015 6797 exec.cpp:388] Executor received status update acknowledgement e466b153-9f67-46d8-adc3-d0e6055d312c for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.737498 6794 sched.cpp:1025] Scheduler::statusUpdate took 142706ns I1017 00:07:49.737836 6794 master.cpp:5566] Processing ACKNOWLEDGE call e466b153-9f67-46d8-adc3-d0e6055d312c for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 (default) at [email protected]:43465 on agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 I1017 00:07:49.738248 6789 status_update_manager.cpp:395] Received status update acknowledgement (UUID: e466b153-9f67-46d8-adc3-d0e6055d312c) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.738497 6811 slave.cpp:869] Agent terminating I1017 00:07:49.738652 6789 status_update_manager.cpp:834] Checkpointing ACK for status update TASK_RUNNING (UUID: e466b153-9f67-46d8-adc3-d0e6055d312c) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.742727 6811 master.cpp:1303] Agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 at slave(528)@172.17.0.2:43465 (9c0b222740d3) disconnected I1017 00:07:49.742805 6811 master.cpp:3336] Disconnecting agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 at slave(528)@172.17.0.2:43465 (9c0b222740d3) I1017 00:07:49.742928 6811 master.cpp:3355] Deactivating agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 at slave(528)@172.17.0.2:43465 (9c0b222740d3) I1017 00:07:49.746589 6811 hierarchical.cpp:690] Agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 deactivated W1017 00:07:49.746594 6788 process.cpp:3194] Attempted to spawn already running process [email protected]:43465 I1017 00:07:49.746837 6804 exec.cpp:508] Agent exited, but framework has checkpointing enabled. Waiting 15mins to reconnect with agent 06e1acf5-8d67-44ec-a476-ad666d83361f-S0 I1017 00:07:49.747247 6788 cluster.cpp:448] Creating default 'local' authorizer I1017 00:07:49.751003 6800 slave.cpp:254] Mesos agent started on (529)@172.17.0.2:43465 I1017 00:07:49.751077 6800 slave.cpp:255] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/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/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/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/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/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/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/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/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/mesos-1.5.0/_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/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST" --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/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn" --zk_session_timeout="10secs" I1017 00:07:49.751677 6800 credentials.hpp:86] Loading credential for authentication from '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/credential' I1017 00:07:49.751914 6800 slave.cpp:287] Agent using credential for: test-principal I1017 00:07:49.751935 6800 credentials.hpp:37] Loading credentials for authentication from '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_a9b3ST/http_credentials' I1017 00:07:49.752271 6800 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor' I1017 00:07:49.752482 6800 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor' I1017 00:07:49.752756 6800 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' I1017 00:07:49.752876 6800 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly' I1017 00:07:49.753098 6800 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' I1017 00:07:49.753211 6800 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite' I1017 00:07:49.755810 6800 slave.cpp:585] 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"}] I1017 00:07:49.756152 6800 slave.cpp:593] Agent attributes: [ ] I1017 00:07:49.756173 6800 slave.cpp:602] Agent hostname: 9c0b222740d3 I1017 00:07:49.756979 6811 status_update_manager.cpp:177] Pausing sending status updates I1017 00:07:49.759851 6811 state.cpp:64] Recovering state from '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/meta' I1017 00:07:49.759941 6811 state.cpp:722] No committed checkpointed resources found at '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/meta/resources/resources.info' W1017 00:07:49.762197 6811 state.cpp:485] Failed to find executor forked pid file '/tmp/SlaveTest_StateEndpointUnavailableDuringRecovery_k6Ddmn/meta/slaves/06e1acf5-8d67-44ec-a476-ad666d83361f-S0/frameworks/06e1acf5-8d67-44ec-a476-ad666d83361f-0000/executors/default/runs/57ab5523-9eff-4486-9a66-f1181a4e0154/pids/forked.pid' I1017 00:07:49.764413 6811 slave.cpp:6401] Recovering framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.765676 6811 slave.cpp:7397] Recovering executor 'default' of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.770781 6807 status_update_manager.cpp:203] Recovering status update manager I1017 00:07:49.770856 6807 status_update_manager.cpp:211] Recovering executor 'default' of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.771000 6807 status_update_manager.cpp:500] Creating StatusUpdate stream for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.771796 6807 status_update_manager.cpp:810] Replaying status update stream for task 0 I1017 00:07:49.772785 6806 slave.cpp:6260] Unable to reconnect to executor 'default' of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 because no pid or http checkpoint file was found E1017 00:07:49.773145 6803 slave.cpp:5395] Termination of executor 'default' of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 failed: unknown container I1017 00:07:49.773344 6803 slave.cpp:4395] Handling status update TASK_FAILED (UUID: 00ea0567-40d7-4120-929b-6d611d676341) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 from @0.0.0.0:0 I1017 00:07:49.774670 6803 status_update_manager.cpp:323] Received status update TASK_FAILED (UUID: 00ea0567-40d7-4120-929b-6d611d676341) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.774827 6803 status_update_manager.cpp:834] Checkpointing UPDATE for status update TASK_FAILED (UUID: 00ea0567-40d7-4120-929b-6d611d676341) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 I1017 00:07:49.775287 6803 slave.cpp:4770] Status update manager successfully handled status update TASK_FAILED (UUID: 00ea0567-40d7-4120-929b-6d611d676341) for task 0 of framework 06e1acf5-8d67-44ec-a476-ad666d83361f-0000 *** SIGSEGV (@0x8) received by PID 6788 (TID 0x2aab2d0e9700) from PID 8; stack trace: *** @ 0x2aab94be2af7 (unknown) @ 0x2aab94be7449 (unknown) @ 0x2aab22747330 (unknown) @ 0x2aab1f96d3d0 process::EventQueue::Consumer::empty() @ 0x2aab1f950de9 process::ProcessManager::resume() @ 0x2aab1f960db1 process::ProcessManager::init_threads()::$_9::operator()() @ 0x2aab1f960cf5 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvE3$_9vEE9_M_invokeIJEEEvSt12_Index_tupleIJXspT_EEE @ 0x2aab1f960cc5 std::_Bind_simple<>::operator()() @ 0x2aab1f960c9c std::thread::_Impl<>::_M_run() @ 0x2aab21fc8a60 (unknown) @ 0x2aab2273f184 start_thread @ 0x2aab22a52ffd (unknown) make[4]: *** [check-local] Segmentation fault (core dumped) make[4]: Leaving directory `/mesos/mesos-1.5.0/_build/src' make[3]: *** [check-am] Error 2 make[3]: Leaving directory `/mesos/mesos-1.5.0/_build/src' make[2]: *** [check] Error 2 make[2]: Leaving directory `/mesos/mesos-1.5.0/_build/src' make[1]: *** [check-recursive] Error 1 make[1]: Leaving directory `/mesos/mesos-1.5.0/_build' make: *** [distcheck] Error 1 + docker rmi mesos-1508195595-19779 Untagged: mesos-1508195595-19779:latest Deleted: sha256:0538b0d21efe39f575f23cf6fe692b0282af1ff19be7cdb011b4b18ed7ea0a35 Deleted: sha256:0a1a93512e15e6d1e6fc642d2c8288cec492a0cb4a3fbcdc86b819ec282488db Deleted: sha256:a74b65bd68bc9bc794b24bbad877f9f162d962a347cd2cc34714fbfda8ac2864 Deleted: sha256:587874e034c1d8172ec9dc6a4b1bf1696b620b7e685a9d08399c6cdf603c7c7c Deleted: sha256:39ff79fe9b2f263f72088a3451dfa2085a13e7032563363047a564e95ba8f67f Deleted: sha256:f624ee639961bf92ac43adf1bc6357e1d775901276e2b0c1d98020ea99ecf85e Deleted: sha256:bae78970177f10b8967f9faad1e8543b2b715cf1c823eb7103f5dc8ab23379c2 Deleted: sha256:5e1d2deb4bf89801168bd4000b7e67ac539e722943f6f1944b3bcb22e8b8e7a5 Deleted: sha256:4b0997a5ecded918ce34a1511f81967c88779dc4f922c6a2d0f9f069d5d6e430 Deleted: sha256:cf3b181a24a42a03380aff60afc0324ebe35a0d0ec7e24ab607f01bba99dcadf Deleted: sha256:6f95a9b8140c1ebc0c4593e97f3b88728938f42b0a86b8ae43cfb6e14473ce7d Deleted: sha256:d55aeb10a1d5c285f4216c8d7082a9b6d4085d6606dbe4423ec10a1aeae9b578 Deleted: sha256:7573ac3f156b409c4f22738e654e00657a641bda7f26de8271a8c01a0f9b2840 Deleted: sha256:19743a094eed7b9b341e7ffcde1ac7da3dbc13f3f6fc4a8ae775369002802719 Deleted: sha256:2ba1d5fa2356a15c01fc09db2d86f05e69664bc5d31ecf7758fbe44e1019947e Deleted: sha256:6389ec8213a1a3a3552057a10aab63648fe3bc9de39eea0377cec0b5f9e12a94 Deleted: sha256:19e02bd4df79fa086f0f31750f857a28809a2a272c36781f9dcf2d582648741c Deleted: sha256:6886aa1e8f497c0453640836015dce9bbcc9d25fb04f7cf3a35a2915ba39e1ec Deleted: sha256:ffcfe6c30c77ef2c9cdde509927e0dbf24e3ae05d8daaccbccac163ecf53072f Deleted: sha256:4f3d4119ea7bbb6461b177a782069279f2ef7359caea5c2ba145e806a5cdcdb0 Deleted: sha256:d9a3b47c9e7e4e5a1bb7c2f9ee82ac740320e91f004d01773ee471e13f2adc95 Deleted: sha256:f696f0c4836315fefeb03057dfcfc4391dc673633ee9a1197d085ae8661c8625 Deleted: sha256:c338aa8a66b92f9b210947e00fd0b51c4f12e8290740dc19b6ef76d31f2a3c50 Deleted: sha256:a9dc799e08e708ff4837b53c654c236263dd54b010e3d41c46dea060c9b4aa01 Deleted: sha256:62d509cd36d794bfa2aba5cab1fab59114b07c01d64c419d47aabe6caec09205 Deleted: sha256:bfb51aa671cf74627af59c793b619675e4b1146305348432e4a588546ddc8cfb Deleted: sha256:ced31c393a53514ca6d52cd9d7501dfb9921bb7681e20b17361cc346bcb4fb83 Deleted: sha256:79cdba291ea2dabddcac18a23080abeba4dbcad310b9cc1eba6c516ed778f2bc Build step 'Execute shell' marked build as failure
