See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2878/changes>
Changes: [adam] Marked RunTaskMessage::framework_id as optional. [adam] Do not pass FrameworkID to Framework constructor in Master/Slave. [adam] Replaced Framework.id with Framework.id() in Master/Slave. [adam] Removed FrameworkID argument from Slave::_runTask. ------------------------------------------ [...truncated 73809 lines...] I0411 10:31:59.959832 9885 master.cpp:2979] Ignoring register slave message from slave(233)@67.195.81.186:47779 (penates.apache.org) as admission is already in progress I0411 10:32:00.121997 9874 sched.cpp:310] Authenticating with master [email protected]:47779 I0411 10:32:00.122027 9874 sched.cpp:317] Using default CRAM-MD5 authenticatee I0411 10:32:00.122359 9872 authenticatee.hpp:139] Creating new client SASL connection I0411 10:32:00.122560 9879 master.cpp:3884] Authenticating [email protected]:47779 I0411 10:32:00.122731 9887 authenticator.cpp:406] Starting authentication session for crammd5_authenticatee(527)@67.195.81.186:47779 I0411 10:32:00.123015 9879 authenticator.cpp:92] Creating new server SASL connection I0411 10:32:00.123214 9879 authenticatee.hpp:230] Received SASL authentication mechanisms: CRAM-MD5 I0411 10:32:00.123240 9879 authenticatee.hpp:256] Attempting to authenticate with mechanism 'CRAM-MD5' I0411 10:32:00.123325 9879 authenticator.cpp:197] Received SASL authentication start I0411 10:32:00.123379 9879 authenticator.cpp:319] Authentication requires more steps I0411 10:32:00.123512 9882 authenticatee.hpp:276] Received SASL authentication step I0411 10:32:00.123646 9882 authenticator.cpp:225] Received SASL authentication step I0411 10:32:00.123682 9882 auxprop.cpp:101] Request to lookup properties for user: 'test-principal' realm: 'penates.apache.org' server FQDN: 'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0411 10:32:00.123699 9882 auxprop.cpp:173] Looking up auxiliary property '*userPassword' I0411 10:32:00.123745 9882 auxprop.cpp:173] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0411 10:32:00.123783 9882 auxprop.cpp:101] Request to lookup properties for user: 'test-principal' realm: 'penates.apache.org' server FQDN: 'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0411 10:32:00.123802 9882 auxprop.cpp:123] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0411 10:32:00.123816 9882 auxprop.cpp:123] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0411 10:32:00.123842 9882 authenticator.cpp:311] Authentication success I0411 10:32:00.124073 9885 authenticatee.hpp:316] Authentication success I0411 10:32:00.124120 9884 authenticator.cpp:424] Authentication session cleanup for crammd5_authenticatee(527)@67.195.81.186:47779 I0411 10:32:00.124028 9887 master.cpp:3914] Successfully authenticated principal 'test-principal' at [email protected]:47779 I0411 10:32:00.124423 9872 sched.cpp:398] Successfully authenticated with master [email protected]:47779 I0411 10:32:00.124449 9872 sched.cpp:521] Sending registration request to [email protected]:47779 I0411 10:32:00.124518 9872 sched.cpp:554] Will retry registration in 1.027862322secs if necessary I0411 10:32:00.124629 9882 master.cpp:1637] Received registration request for framework 'default' at [email protected]:47779 I0411 10:32:00.124704 9882 master.cpp:1498] Authorizing framework principal 'test-principal' to receive offers for role '*' I0411 10:32:00.125080 9875 log.cpp:684] Attempting to append 316 bytes to the log I0411 10:32:00.125138 9880 master.cpp:1704] Registering framework 20150411-103159-3125920579-47779-9858-0000 (default) at [email protected]:47779 I0411 10:32:00.125182 9887 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3 I0411 10:32:00.125543 9883 hierarchical.hpp:321] Added framework 20150411-103159-3125920579-47779-9858-0000 I0411 10:32:00.125579 9883 hierarchical.hpp:818] No resources available to allocate! I0411 10:32:00.125601 9883 hierarchical.hpp:725] Performed allocation for 0 slaves in 29427ns I0411 10:32:00.125625 9880 sched.cpp:448] Framework registered with 20150411-103159-3125920579-47779-9858-0000 I0411 10:32:00.125690 9880 sched.cpp:462] Scheduler::registered took 35694ns I0411 10:32:00.126024 9873 replica.cpp:511] Replica received write request for position 3 I0411 10:32:00.126263 9873 leveldb.cpp:343] Persisting action (335 bytes) to leveldb took 189801ns I0411 10:32:00.126288 9873 replica.cpp:679] Persisted action at 3 I0411 10:32:00.126936 9879 replica.cpp:658] Replica received learned notice for position 3 I0411 10:32:00.127652 9879 leveldb.cpp:343] Persisting action (337 bytes) to leveldb took 689050ns I0411 10:32:00.127678 9879 replica.cpp:679] Persisted action at 3 I0411 10:32:00.127699 9879 replica.cpp:664] Replica learned APPEND action at position 3 I0411 10:32:00.128602 9877 registrar.cpp:490] Successfully updated the 'registry' in 6.72384ms I0411 10:32:00.128866 9881 log.cpp:703] Attempting to truncate the log to 3 I0411 10:32:00.128989 9880 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4 I0411 10:32:00.129286 9879 slave.cpp:2834] Received ping from slave-observer(213)@67.195.81.186:47779 I0411 10:32:00.129369 9882 master.cpp:3048] Registered slave 20150411-103159-3125920579-47779-9858-S0 at slave(233)@67.195.81.186:47779 (penates.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I0411 10:32:00.129484 9879 slave.cpp:795] Registered with master [email protected]:47779; given slave ID 20150411-103159-3125920579-47779-9858-S0 I0411 10:32:00.129492 9872 hierarchical.hpp:439] Added slave 20150411-103159-3125920579-47779-9858-S0 (penates.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) I0411 10:32:00.129603 9881 status_update_manager.cpp:178] Resuming sending status updates I0411 10:32:00.129778 9879 slave.cpp:810] Checkpointing SlaveInfo to '/tmp/StatusUpdateManagerTest_IgnoreUnexpectedStatusUpdateAck_Kam2Ck/meta/slaves/20150411-103159-3125920579-47779-9858-S0/slave.info' I0411 10:32:00.130038 9884 replica.cpp:511] Replica received write request for position 4 I0411 10:32:00.130089 9872 hierarchical.hpp:743] Performed allocation for slave 20150411-103159-3125920579-47779-9858-S0 in 545903ns I0411 10:32:00.130411 9877 master.cpp:3803] Sending 1 offers to framework 20150411-103159-3125920579-47779-9858-0000 (default) at [email protected]:47779 I0411 10:32:00.130666 9884 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 572287ns I0411 10:32:00.130692 9884 replica.cpp:679] Persisted action at 4 I0411 10:32:00.130798 9873 sched.cpp:611] Scheduler::resourceOffers took 83087ns I0411 10:32:00.131911 9879 replica.cpp:658] Replica received learned notice for position 4 I0411 10:32:00.132503 9879 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 546867ns I0411 10:32:00.132560 9879 leveldb.cpp:401] Deleting ~2 keys from leveldb took 36027ns I0411 10:32:00.132576 9879 replica.cpp:679] Persisted action at 4 I0411 10:32:00.132604 9879 replica.cpp:664] Replica learned TRUNCATE action at position 4 I0411 10:32:00.132625 9872 master.cpp:2331] Processing ACCEPT call for offers: [ 20150411-103159-3125920579-47779-9858-O0 ] on slave 20150411-103159-3125920579-47779-9858-S0 at slave(233)@67.195.81.186:47779 (penates.apache.org) for framework 20150411-103159-3125920579-47779-9858-0000 (default) at [email protected]:47779 I0411 10:32:00.132676 9872 master.cpp:2176] Authorizing framework principal 'test-principal' to launch task 1 as user 'jenkins' W0411 10:32:00.133802 9872 validation.cpp:327] Executor default for task 1 uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases. W0411 10:32:00.321429 9872 validation.cpp:339] Executor default for task 1 uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases. I0411 10:32:00.321854 9872 master.hpp:801] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20150411-103159-3125920579-47779-9858-S0 (penates.apache.org) I0411 10:32:00.321993 9872 master.cpp:2603] Launching task 1 of framework 20150411-103159-3125920579-47779-9858-0000 (default) at [email protected]:47779 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20150411-103159-3125920579-47779-9858-S0 at slave(233)@67.195.81.186:47779 (penates.apache.org) I0411 10:32:00.322410 9872 slave.cpp:1128] Got assigned task 1 for framework 20150411-103159-3125920579-47779-9858-0000 I0411 10:32:00.322542 9872 slave.cpp:4146] Checkpointing FrameworkInfo to '/tmp/StatusUpdateManagerTest_IgnoreUnexpectedStatusUpdateAck_Kam2Ck/meta/slaves/20150411-103159-3125920579-47779-9858-S0/frameworks/20150411-103159-3125920579-47779-9858-0000/framework.info' I0411 10:32:00.322824 9872 slave.cpp:4153] Checkpointing framework pid '[email protected]:47779' to '/tmp/StatusUpdateManagerTest_IgnoreUnexpectedStatusUpdateAck_Kam2Ck/meta/slaves/20150411-103159-3125920579-47779-9858-S0/frameworks/20150411-103159-3125920579-47779-9858-0000/framework.pid' I0411 10:32:00.323544 9872 slave.cpp:1238] Launching task 1 for framework 20150411-103159-3125920579-47779-9858-0000 I0411 10:32:00.332937 9872 slave.cpp:4581] Checkpointing ExecutorInfo to '/tmp/StatusUpdateManagerTest_IgnoreUnexpectedStatusUpdateAck_Kam2Ck/meta/slaves/20150411-103159-3125920579-47779-9858-S0/frameworks/20150411-103159-3125920579-47779-9858-0000/executors/default/executor.info' I0411 10:32:00.333506 9872 slave.cpp:4219] Launching executor default of framework 20150411-103159-3125920579-47779-9858-0000 in work directory '/tmp/StatusUpdateManagerTest_IgnoreUnexpectedStatusUpdateAck_Kam2Ck/slaves/20150411-103159-3125920579-47779-9858-S0/frameworks/20150411-103159-3125920579-47779-9858-0000/executors/default/runs/9970a4c2-7220-458b-9960-7ba6eb17201d' I0411 10:32:00.336491 9872 exec.cpp:132] Version: 0.23.0 I0411 10:32:00.336843 9884 exec.cpp:182] Executor started at: executor(81)@67.195.81.186:47779 with pid 9858 I0411 10:32:00.336969 9872 slave.cpp:4604] Checkpointing TaskInfo to '/tmp/StatusUpdateManagerTest_IgnoreUnexpectedStatusUpdateAck_Kam2Ck/meta/slaves/20150411-103159-3125920579-47779-9858-S0/frameworks/20150411-103159-3125920579-47779-9858-0000/executors/default/runs/9970a4c2-7220-458b-9960-7ba6eb17201d/tasks/1/task.info' I0411 10:32:00.337328 9872 slave.cpp:1384] Queuing task '1' for executor default of framework '20150411-103159-3125920579-47779-9858-0000 I0411 10:32:00.337467 9872 slave.cpp:580] Successfully attached file '/tmp/StatusUpdateManagerTest_IgnoreUnexpectedStatusUpdateAck_Kam2Ck/slaves/20150411-103159-3125920579-47779-9858-S0/frameworks/20150411-103159-3125920579-47779-9858-0000/executors/default/runs/9970a4c2-7220-458b-9960-7ba6eb17201d' I0411 10:32:00.337590 9872 slave.cpp:3136] Monitoring executor 'default' of framework '20150411-103159-3125920579-47779-9858-0000' in container '9970a4c2-7220-458b-9960-7ba6eb17201d' I0411 10:32:00.337774 9872 slave.cpp:2136] Got registration for executor 'default' of framework 20150411-103159-3125920579-47779-9858-0000 from executor(81)@67.195.81.186:47779 I0411 10:32:00.337846 9872 slave.cpp:2222] Checkpointing executor pid 'executor(81)@67.195.81.186:47779' to '/tmp/StatusUpdateManagerTest_IgnoreUnexpectedStatusUpdateAck_Kam2Ck/meta/slaves/20150411-103159-3125920579-47779-9858-S0/frameworks/20150411-103159-3125920579-47779-9858-0000/executors/default/runs/9970a4c2-7220-458b-9960-7ba6eb17201d/pids/libprocess.pid' I0411 10:32:00.338421 9877 exec.cpp:206] Executor registered on slave 20150411-103159-3125920579-47779-9858-S0 I0411 10:32:00.338786 9872 slave.cpp:1536] Sending queued task '1' to executor 'default' of framework 20150411-103159-3125920579-47779-9858-0000 I0411 10:32:00.339896 9877 exec.cpp:218] Executor::registered took 30769ns I0411 10:32:00.340112 9877 exec.cpp:293] Executor asked to run task '1' I0411 10:32:00.340189 9877 exec.cpp:302] Executor::launchTask took 59974ns I0411 10:32:00.341609 9877 exec.cpp:507] Executor sending status update TASK_RUNNING (UUID: 1a6781a6-6d77-41db-a61b-21e860a6bb2b) for task 1 of framework 20150411-103159-3125920579-47779-9858-0000 I0411 10:32:00.341939 9879 slave.cpp:2503] Handling status update TASK_RUNNING (UUID: 1a6781a6-6d77-41db-a61b-21e860a6bb2b) for task 1 of framework 20150411-103159-3125920579-47779-9858-0000 from executor(81)@67.195.81.186:47779 I0411 10:32:00.342232 9877 status_update_manager.cpp:317] Received status update TASK_RUNNING (UUID: 1a6781a6-6d77-41db-a61b-21e860a6bb2b) for task 1 of framework 20150411-103159-3125920579-47779-9858-0000 I0411 10:32:00.342262 9877 status_update_manager.cpp:494] Creating StatusUpdate stream for task 1 of framework 20150411-103159-3125920579-47779-9858-0000 I0411 10:32:00.342663 9877 status_update_manager.hpp:346] Checkpointing UPDATE for status update TASK_RUNNING (UUID: 1a6781a6-6d77-41db-a61b-21e860a6bb2b) for task 1 of framework 20150411-103159-3125920579-47779-9858-0000 I0411 10:32:00.344265 9877 status_update_manager.cpp:371] Forwarding update TASK_RUNNING (UUID: 1a6781a6-6d77-41db-a61b-21e860a6bb2b) for task 1 of framework 20150411-103159-3125920579-47779-9858-0000 to the slave I0411 10:32:00.344491 9879 slave.cpp:2758] Forwarding the update TASK_RUNNING (UUID: 1a6781a6-6d77-41db-a61b-21e860a6bb2b) for task 1 of framework 20150411-103159-3125920579-47779-9858-0000 to [email protected]:47779 I0411 10:32:00.344614 9879 slave.cpp:2685] Status update manager successfully handled status update TASK_RUNNING (UUID: 1a6781a6-6d77-41db-a61b-21e860a6bb2b) for task 1 of framework 20150411-103159-3125920579-47779-9858-0000 I0411 10:32:00.344636 9879 slave.cpp:2691] Sending acknowledgement for status update TASK_RUNNING (UUID: 1a6781a6-6d77-41db-a61b-21e860a6bb2b) for task 1 of framework 20150411-103159-3125920579-47779-9858-0000 to executor(81)@67.195.81.186:47779 I0411 10:32:00.344781 9876 master.cpp:3345] Status update TASK_RUNNING (UUID: 1a6781a6-6d77-41db-a61b-21e860a6bb2b) for task 1 of framework 20150411-103159-3125920579-47779-9858-0000 from slave 20150411-103159-3125920579-47779-9858-S0 at slave(233)@67.195.81.186:47779 (penates.apache.org) I0411 10:32:00.344812 9876 master.cpp:3384] Forwarding status update TASK_RUNNING (UUID: 1a6781a6-6d77-41db-a61b-21e860a6bb2b) for task 1 of framework 20150411-103159-3125920579-47779-9858-0000 I0411 10:32:00.344948 9876 master.cpp:4656] Updating the latest state of task 1 of framework 20150411-103159-3125920579-47779-9858-0000 to TASK_RUNNING I0411 10:32:00.345262 9878 sched.cpp:717] Scheduler::statusUpdate took 36468ns I0411 10:32:00.348292 9884 status_update_manager.cpp:389] Received status update acknowledgement (UUID: a5f60233-61d8-49ab-b606-2a56052ca68d) for task 1 of framework 20150411-103159-3125920579-47779-9858-0000 W0411 10:32:00.348502 9884 status_update_manager.hpp:271] Unexpected status update acknowledgement (received a5f60233-61d8-49ab-b606-2a56052ca68d, expecting 1a6781a6-6d77-41db-a61b-21e860a6bb2b) for update TASK_RUNNING (UUID: 1a6781a6-6d77-41db-a61b-21e860a6bb2b) for task 1 of framework 20150411-103159-3125920579-47779-9858-0000 E0411 10:32:00.349014 9880 slave.cpp:2069] Failed to handle status update acknowledgement (UUID: a5f60233-61d8-49ab-b606-2a56052ca68d) for task 1 of framework 20150411-103159-3125920579-47779-9858-0000: Duplicate acknowledgement I0411 10:32:00.349354 9858 sched.cpp:1589] Asked to stop the driver I0411 10:32:00.519271 9873 sched.cpp:831] Stopping framework '20150411-103159-3125920579-47779-9858-0000' I0411 10:32:00.519350 9887 master.cpp:788] Master terminating W0411 10:32:00.519716 9887 master.cpp:4707] Removing task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework 20150411-103159-3125920579-47779-9858-0000 on slave 20150411-103159-3125920579-47779-9858-S0 at slave(233)@67.195.81.186:47779 (penates.apache.org) in non-terminal state TASK_RUNNING I0411 10:32:00.520275 9885 hierarchical.hpp:470] Removed slave 20150411-103159-3125920579-47779-9858-S0 I0411 10:32:00.520377 9887 master.cpp:4750] Removing executor 'default' with resources of framework 20150411-103159-3125920579-47779-9858-0000 on slave 20150411-103159-3125920579-47779-9858-S0 at slave(233)@67.195.81.186:47779 (penates.apache.org) I0411 10:32:00.520910 9879 hierarchical.hpp:354] Removed framework 20150411-103159-3125920579-47779-9858-0000 I0411 10:32:00.521407 9875 slave.cpp:2919] [email protected]:47779 exited W0411 10:32:00.521443 9875 slave.cpp:2922] Master disconnected! Waiting for a new master to be elected I0411 10:32:00.527526 9873 slave.cpp:3194] Executor 'default' of framework 20150411-103159-3125920579-47779-9858-0000 exited with status 0 I0411 10:32:00.529276 9873 slave.cpp:2503] Handling status update TASK_LOST (UUID: d7251811-a655-4881-acd8-5cd184c7da92) for task 1 of framework 20150411-103159-3125920579-47779-9858-0000 from @0.0.0.0:0 I0411 10:32:00.529376 9873 slave.cpp:4519] Terminating task 1 I0411 10:32:00.529716 9873 slave.cpp:509] Slave terminating [ OK ] StatusUpdateManagerTest.IgnoreUnexpectedStatusUpdateAck (781 ms) [----------] 8 tests from StatusUpdateManagerTest (5687 ms total) [----------] 1 test from HealthTest [ RUN ] HealthTest.ObserveEndpoint Using temporary directory '/tmp/HealthTest_ObserveEndpoint_xMDMgB' I0411 10:32:00.538187 9858 leveldb.cpp:176] Opened db in 2.863259ms I0411 10:32:00.539249 9858 leveldb.cpp:183] Compacted db in 1.026277ms I0411 10:32:00.539302 9858 leveldb.cpp:198] Created db iterator in 18882ns I0411 10:32:00.539324 9858 leveldb.cpp:204] Seeked to beginning of db in 1930ns I0411 10:32:00.539333 9858 leveldb.cpp:273] Iterated through 0 keys in the db in 290ns I0411 10:32:00.539369 9858 replica.cpp:744] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0411 10:32:00.539862 9884 recover.cpp:449] Starting replica recovery I0411 10:32:00.540170 9884 recover.cpp:475] Replica is in EMPTY status I0411 10:32:00.541301 9880 replica.cpp:641] Replica in EMPTY status received a broadcasted recover request I0411 10:32:00.541659 9882 recover.cpp:195] Received a recover response from a replica in EMPTY status I0411 10:32:00.542021 9875 recover.cpp:566] Updating replica status to STARTING I0411 10:32:00.542871 9877 master.cpp:359] Master 20150411-103200-3125920579-47779-9858 (penates.apache.org) started on 67.195.81.186:47779 I0411 10:32:00.542907 9885 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 598403ns I0411 10:32:00.542932 9885 replica.cpp:323] Persisted replica status to STARTING I0411 10:32:00.542896 9877 master.cpp:361] Flags at startup: --acls="" --allocation_interval="1secs" --authenticate="true" --authenticate_slaves="true" --authenticators="crammd5" --credentials="/tmp/HealthTest_ObserveEndpoint_xMDMgB/credentials" --framework_sorter="drf" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --quiet="false" --recovery_slave_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_store_timeout="25secs" --registry_strict="true" --root_submissions="true" --slave_reregister_timeout="10mins" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/HealthTest_ObserveEndpoint_xMDMgB/master" --zk_session_timeout="10secs" I0411 10:32:00.543179 9877 master.cpp:406] Master only allowing authenticated frameworks to register I0411 10:32:00.543177 9886 recover.cpp:475] Replica is in STARTING status I0411 10:32:00.543191 9877 master.cpp:411] Master only allowing authenticated slaves to register I0411 10:32:00.543212 9877 credentials.hpp:37] Loading credentials for authentication from '/tmp/HealthTest_ObserveEndpoint_xMDMgB/credentials' I0411 10:32:00.543413 9877 master.cpp:450] Using default 'crammd5' authenticator I0411 10:32:00.543527 9877 master.cpp:487] Authorization enabled I0411 10:32:00.544070 9878 whitelist_watcher.cpp:79] No whitelist given I0411 10:32:00.544142 9875 replica.cpp:641] Replica in STARTING status received a broadcasted recover request I0411 10:32:00.544236 9874 hierarchical.hpp:287] Initialized hierarchical allocator process I0411 10:32:00.544531 9879 recover.cpp:195] Received a recover response from a replica in STARTING status I0411 10:32:00.544996 9884 recover.cpp:566] Updating replica status to VOTING I0411 10:32:00.545186 9887 master.cpp:1419] The newly elected leader is [email protected]:47779 with id 20150411-103200-3125920579-47779-9858 I0411 10:32:00.545217 9887 master.cpp:1432] Elected as the leading master! I0411 10:32:00.545239 9887 master.cpp:1205] Recovering from registrar I0411 10:32:00.545377 9879 registrar.cpp:313] Recovering registrar I0411 10:32:00.545629 9886 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 425520ns I0411 10:32:00.545655 9886 replica.cpp:323] Persisted replica status to VOTING I0411 10:32:00.545776 9880 recover.cpp:580] Successfully joined the Paxos group I0411 10:32:00.545971 9880 recover.cpp:464] Recover process terminated I0411 10:32:00.546365 9886 log.cpp:660] Attempting to start the writer I0411 10:32:00.547603 9875 replica.cpp:477] Replica received implicit promise request with proposal 1 I0411 10:32:00.548096 9875 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 471111ns I0411 10:32:00.548115 9875 replica.cpp:345] Persisted promised to 1 I0411 10:32:00.548584 9885 coordinator.cpp:230] Coordinator attemping to fill missing position I0411 10:32:00.549954 9885 replica.cpp:378] Replica received explicit promise request for position 0 with proposal 2 I0411 10:32:00.550384 9885 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 400435ns I0411 10:32:00.550403 9885 replica.cpp:679] Persisted action at 0 I0411 10:32:00.551650 9883 replica.cpp:511] Replica received write request for position 0 I0411 10:32:00.551707 9883 leveldb.cpp:438] Reading position from leveldb took 30595ns I0411 10:32:00.552155 9883 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 415720ns I0411 10:32:00.552180 9883 replica.cpp:679] Persisted action at 0 I0411 10:32:00.552857 9879 replica.cpp:658] Replica received learned notice for position 0 I0411 10:32:00.553313 9879 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 422355ns I0411 10:32:00.553340 9879 replica.cpp:679] Persisted action at 0 I0411 10:32:00.553361 9879 replica.cpp:664] Replica learned NOP action at position 0 I0411 10:32:00.553938 9884 log.cpp:676] Writer started with ending position 0 I0411 10:32:00.554935 9883 leveldb.cpp:438] Reading position from leveldb took 32429ns I0411 10:32:00.557871 9876 registrar.cpp:346] Successfully fetched the registry (0B) in 12.414208ms I0411 10:32:00.753741 9876 registrar.cpp:445] Applied 1 operations in 36612ns; attempting to update the 'registry' I0411 10:32:00.756664 9874 log.cpp:684] Attempting to append 139 bytes to the log I0411 10:32:00.756850 9879 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1 I0411 10:32:00.757596 9874 replica.cpp:511] Replica received write request for position 1 I0411 10:32:00.758482 9874 leveldb.cpp:343] Persisting action (158 bytes) to leveldb took 852090ns I0411 10:32:00.758514 9874 replica.cpp:679] Persisted action at 1 I0411 10:32:00.759264 9882 replica.cpp:658] Replica received learned notice for position 1 I0411 10:32:00.759840 9882 leveldb.cpp:343] Persisting action (160 bytes) to leveldb took 544229ns I0411 10:32:00.759870 9882 replica.cpp:679] Persisted action at 1 I0411 10:32:00.759893 9882 replica.cpp:664] Replica learned APPEND action at position 1 I0411 10:32:00.760823 9873 registrar.cpp:490] Successfully updated the 'registry' in 6944us I0411 10:32:00.760956 9873 registrar.cpp:376] Successfully recovered registrar I0411 10:32:00.760999 9884 log.cpp:703] Attempting to truncate the log to 1 I0411 10:32:00.761189 9883 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2 I0411 10:32:00.761220 9878 master.cpp:1232] Recovered 0 slaves from the Registry (101B) ; allowing 10mins for slaves to re-register I0411 10:32:00.761956 9887 replica.cpp:511] Replica received write request for position 2 I0411 10:32:00.762528 9887 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 540678ns I0411 10:32:00.762554 9887 replica.cpp:679] Persisted action at 2 I0411 10:32:00.763290 9883 replica.cpp:658] Replica received learned notice for position 2 I0411 10:32:00.763842 9883 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 520292ns I0411 10:32:00.763900 9883 leveldb.cpp:401] Deleting ~1 keys from leveldb took 31739ns I0411 10:32:00.763918 9883 replica.cpp:679] Persisted action at 2 I0411 10:32:00.763941 9883 replica.cpp:664] Replica learned TRUNCATE action at position 2 I0411 10:32:00.773254 9873 process.cpp:2701] Handling HTTP event for process 'master' with path: '/master/observe' I0411 10:32:00.773421 9873 http.cpp:289] HTTP request for '/master/observe' I0411 10:32:00.776536 9881 process.cpp:2701] Handling HTTP event for process 'master' with path: '/master/observe' I0411 10:32:00.776700 9881 http.cpp:289] HTTP request for '/master/observe' I0411 10:32:00.779531 9878 process.cpp:2701] Handling HTTP event for process 'master' with path: '/master/observe' I0411 10:32:00.779702 9878 http.cpp:289] HTTP request for '/master/observe' I0411 10:32:00.782536 9883 process.cpp:2701] Handling HTTP event for process 'master' with path: '/master/observe' I0411 10:32:00.782719 9883 http.cpp:289] HTTP request for '/master/observe' I0411 10:32:00.785436 9881 process.cpp:2701] Handling HTTP event for process 'master' with path: '/master/observe' I0411 10:32:00.785611 9881 http.cpp:289] HTTP request for '/master/observe' I0411 10:32:00.788543 9877 process.cpp:2701] Handling HTTP event for process 'master' with path: '/master/observe' I0411 10:32:00.788723 9877 http.cpp:289] HTTP request for '/master/observe' I0411 10:32:00.791507 9877 process.cpp:2701] Handling HTTP event for process 'master' with path: '/master/observe' I0411 10:32:00.791710 9877 http.cpp:289] HTTP request for '/master/observe' I0411 10:32:00.794713 9874 process.cpp:2701] Handling HTTP event for process 'master' with path: '/master/observe' I0411 10:32:00.794889 9874 http.cpp:289] HTTP request for '/master/observe' I0411 10:32:00.798123 9877 process.cpp:2701] Handling HTTP event for process 'master' with path: '/master/observe' I0411 10:32:00.798305 9877 http.cpp:289] HTTP request for '/master/observe' I0411 10:32:00.801534 9873 process.cpp:2701] Handling HTTP event for process 'master' with path: '/master/observe' I0411 10:32:00.801720 9873 http.cpp:289] HTTP request for '/master/observe' I0411 10:32:00.804914 9877 process.cpp:2701] Handling HTTP event for process 'master' with path: '/master/observe' I0411 10:32:00.805100 9877 http.cpp:289] HTTP request for '/master/observe' I0411 10:32:00.808511 9872 process.cpp:2701] Handling HTTP event for process 'master' with path: '/master/observe' I0411 10:32:00.808711 9872 http.cpp:289] HTTP request for '/master/observe' I0411 10:32:00.812005 9882 process.cpp:2701] Handling HTTP event for process 'master' with path: '/master/observe' I0411 10:32:00.812191 9882 http.cpp:289] HTTP request for '/master/observe' I0411 10:32:00.814203 9878 master.cpp:788] Master terminating [ OK ] HealthTest.ObserveEndpoint (285 ms) [----------] 1 test from HealthTest (285 ms total) [----------] Global test environment tear-down [==========] 507 tests from 78 test cases ran. (167747 ms total) [ PASSED ] 506 tests. [ FAILED ] 1 test, listed below: [ FAILED ] MesosContainerizerDestroyTest.LauncherDestroyFailure 1 FAILED TEST YOU HAVE 8 DISABLED TESTS make[3]: *** [check-local] Error 1 make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'> make[2]: *** [check-am] Error 2 make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'> make[1]: *** [check] Error 2 make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'> make: *** [check-recursive] Error 1 Test finished Exit status: 2 Build step 'Execute shell' marked build as failure Recording test results
