See <https://builds.apache.org/job/Mesos-Ubuntu-distcheck/259/changes>
Changes: [vinodkone] Temporarily disabled HealthcheckTest.ConsecutiveFailures test due to ------------------------------------------ [...truncated 62998 lines...] I0808 08:29:20.398154 11422 log.cpp:699] Attempting to truncate the log to 3 I0808 08:29:20.398218 11422 master.cpp:2877] Registered slave 20140808-082920-453759884-51004-11187-0 at slave(200)@140.211.11.27:51004 (hemera.apache.org) I0808 08:29:20.398233 11422 master.cpp:4088] Adding slave 20140808-082920-453759884-51004-11187-0 at slave(200)@140.211.11.27:51004 (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I0808 08:29:20.398331 11422 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4 I0808 08:29:20.398399 11422 slave.cpp:754] Registered with master [email protected]:51004; given slave ID 20140808-082920-453759884-51004-11187-0 I0808 08:29:20.398474 11422 hierarchical_allocator_process.hpp:439] Added slave 20140808-082920-453759884-51004-11187-0 (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) I0808 08:29:20.398525 11422 hierarchical_allocator_process.hpp:714] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140808-082920-453759884-51004-11187-0 to framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.398625 11422 hierarchical_allocator_process.hpp:670] Performed allocation for slave 20140808-082920-453759884-51004-11187-0 in 121105ns I0808 08:29:20.398672 11422 slave.cpp:2324] Received ping from slave-observer(169)@140.211.11.27:51004 I0808 08:29:20.398731 11422 master.hpp:847] Adding offer 20140808-082920-453759884-51004-11187-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140808-082920-453759884-51004-11187-0 (hemera.apache.org) I0808 08:29:20.398780 11422 master.cpp:3562] Sending 1 offers to framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.398898 11422 sched.cpp:546] Scheduler::resourceOffers took 17914ns I0808 08:29:20.399065 11422 replica.cpp:508] Replica received write request for position 4 I0808 08:29:20.401845 11441 master.hpp:857] Removing offer 20140808-082920-453759884-51004-11187-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140808-082920-453759884-51004-11187-0 (hemera.apache.org) I0808 08:29:20.401904 11441 master.cpp:2199] Processing reply for offers: [ 20140808-082920-453759884-51004-11187-0 ] on slave 20140808-082920-453759884-51004-11187-0 at slave(200)@140.211.11.27:51004 (hemera.apache.org) for framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.401937 11441 master.cpp:2285] Authorizing framework principal 'test-principal' to launch task 1 as user 'jenkins' I0808 08:29:20.402268 11441 master.hpp:819] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140808-082920-453759884-51004-11187-0 (hemera.apache.org) I0808 08:29:20.402304 11441 master.cpp:2351] Launching task 1 of framework 20140808-082920-453759884-51004-11187-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140808-082920-453759884-51004-11187-0 at slave(200)@140.211.11.27:51004 (hemera.apache.org) I0808 08:29:20.402441 11441 slave.cpp:1002] Got assigned task 1 for framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.402626 11441 slave.cpp:1112] Launching task 1 for framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.406697 11441 exec.cpp:131] Version: 0.20.0 I0808 08:29:20.406791 11441 slave.cpp:1222] Queuing task '1' for executor default of framework '20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.406847 11441 slave.cpp:2515] Monitoring executor 'default' of framework '20140808-082920-453759884-51004-11187-0000' in container '0380ad43-ec85-4eee-8d49-b30842953c70' I0808 08:29:20.406939 11441 exec.cpp:181] Executor started at: executor(63)@140.211.11.27:51004 with pid 11187 I0808 08:29:20.407003 11441 slave.cpp:543] Successfully attached file '/tmp/FaultToleranceTest_ForwardStatusUpdateUnknownExecutor_d8SX0S/slaves/20140808-082920-453759884-51004-11187-0/frameworks/20140808-082920-453759884-51004-11187-0000/executors/default/runs/0380ad43-ec85-4eee-8d49-b30842953c70' I0808 08:29:20.407027 11441 slave.cpp:1733] Got registration for executor 'default' of framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.407120 11441 slave.cpp:1852] Flushing queued task 1 for executor 'default' of framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.407191 11441 exec.cpp:205] Executor registered on slave 20140808-082920-453759884-51004-11187-0 I0808 08:29:20.408954 11441 exec.cpp:217] Executor::registered took 11280ns I0808 08:29:20.409006 11441 exec.cpp:292] Executor asked to run task '1' I0808 08:29:20.409035 11441 exec.cpp:301] Executor::launchTask took 20017ns I0808 08:29:20.410871 11441 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: 35c4ce01-90e2-4860-8165-387763d9b86e) for task 1 of framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.410979 11441 slave.cpp:2087] Handling status update TASK_RUNNING (UUID: 35c4ce01-90e2-4860-8165-387763d9b86e) for task 1 of framework 20140808-082920-453759884-51004-11187-0000 from executor(63)@140.211.11.27:51004 I0808 08:29:20.411139 11441 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 35c4ce01-90e2-4860-8165-387763d9b86e) for task 1 of framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.411206 11441 status_update_manager.cpp:499] Creating StatusUpdate stream for task 1 of framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.411309 11441 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: 35c4ce01-90e2-4860-8165-387763d9b86e) for task 1 of framework 20140808-082920-453759884-51004-11187-0000 to [email protected]:51004 I0808 08:29:20.411461 11441 master.cpp:3206] Forwarding status update TASK_RUNNING (UUID: 35c4ce01-90e2-4860-8165-387763d9b86e) for task 1 of framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.411552 11441 master.cpp:3172] Status update TASK_RUNNING (UUID: 35c4ce01-90e2-4860-8165-387763d9b86e) for task 1 of framework 20140808-082920-453759884-51004-11187-0000 from slave 20140808-082920-453759884-51004-11187-0 at slave(200)@140.211.11.27:51004 (hemera.apache.org) I0808 08:29:20.411636 11441 slave.cpp:2245] Status update manager successfully handled status update TASK_RUNNING (UUID: 35c4ce01-90e2-4860-8165-387763d9b86e) for task 1 of framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.411696 11441 slave.cpp:2251] Sending acknowledgement for status update TASK_RUNNING (UUID: 35c4ce01-90e2-4860-8165-387763d9b86e) for task 1 of framework 20140808-082920-453759884-51004-11187-0000 to executor(63)@140.211.11.27:51004 I0808 08:29:20.411815 11441 sched.cpp:637] Scheduler::statusUpdate took 12580ns I0808 08:29:20.411909 11441 exec.cpp:338] Executor received status update acknowledgement 35c4ce01-90e2-4860-8165-387763d9b86e for task 1 of framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.412014 11441 master.cpp:2687] Forwarding status update acknowledgement 35c4ce01-90e2-4860-8165-387763d9b86e for task 1 of framework 20140808-082920-453759884-51004-11187-0000 to slave 20140808-082920-453759884-51004-11187-0 at slave(200)@140.211.11.27:51004 (hemera.apache.org) I0808 08:29:20.412189 11441 status_update_manager.cpp:398] Received status update acknowledgement (UUID: 35c4ce01-90e2-4860-8165-387763d9b86e) for task 1 of framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.412297 11441 slave.cpp:1673] Status update manager successfully handled status update acknowledgement (UUID: 35c4ce01-90e2-4860-8165-387763d9b86e) for task 1 of framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.417728 11412 slave.cpp:2087] Handling status update TASK_RUNNING (UUID: ab64bf94-f691-4dc9-8436-b32c098a758a) for task task2 of framework 20140808-082920-453759884-51004-11187-0000 from @0.0.0.0:0 W0808 08:29:20.417768 11412 slave.cpp:2120] Could not find the executor for status update TASK_RUNNING (UUID: ab64bf94-f691-4dc9-8436-b32c098a758a) for task task2 of framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.417868 11412 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: ab64bf94-f691-4dc9-8436-b32c098a758a) for task task2 of framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.417881 11412 status_update_manager.cpp:499] Creating StatusUpdate stream for task task2 of framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.417945 11412 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: ab64bf94-f691-4dc9-8436-b32c098a758a) for task task2 of framework 20140808-082920-453759884-51004-11187-0000 to [email protected]:51004 I0808 08:29:20.418081 11412 master.cpp:3206] Forwarding status update TASK_RUNNING (UUID: ab64bf94-f691-4dc9-8436-b32c098a758a) for task task2 of framework 20140808-082920-453759884-51004-11187-0000 W0808 08:29:20.418114 11412 master.cpp:3165] Could not lookup task for status update TASK_RUNNING (UUID: ab64bf94-f691-4dc9-8436-b32c098a758a) for task task2 of framework 20140808-082920-453759884-51004-11187-0000 from slave 20140808-082920-453759884-51004-11187-0 at slave(200)@140.211.11.27:51004 (hemera.apache.org) I0808 08:29:20.418143 11412 slave.cpp:2245] Status update manager successfully handled status update TASK_RUNNING (UUID: ab64bf94-f691-4dc9-8436-b32c098a758a) for task task2 of framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.418203 11412 sched.cpp:637] Scheduler::statusUpdate took 16494ns I0808 08:29:20.418262 11412 master.cpp:2687] Forwarding status update acknowledgement ab64bf94-f691-4dc9-8436-b32c098a758a for task task2 of framework 20140808-082920-453759884-51004-11187-0000 to slave 20140808-082920-453759884-51004-11187-0 at slave(200)@140.211.11.27:51004 (hemera.apache.org) I0808 08:29:20.418369 11412 status_update_manager.cpp:398] Received status update acknowledgement (UUID: ab64bf94-f691-4dc9-8436-b32c098a758a) for task task2 of framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.418414 11412 slave.cpp:1673] Status update manager successfully handled status update acknowledgement (UUID: ab64bf94-f691-4dc9-8436-b32c098a758a) for task task2 of framework 20140808-082920-453759884-51004-11187-0000 E0808 08:29:20.418426 11412 slave.cpp:1697] Status update acknowledgement (UUID: ab64bf94-f691-4dc9-8436-b32c098a758a) for task task2 of unknown executor I0808 08:29:20.418453 11422 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 19.37043ms I0808 08:29:20.418474 11422 replica.cpp:676] Persisted action at 4 I0808 08:29:20.418665 11422 replica.cpp:655] Replica received learned notice for position 4 I0808 08:29:20.418769 11187 master.cpp:634] Master terminating I0808 08:29:20.418823 11187 master.hpp:837] Removing task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140808-082920-453759884-51004-11187-0 (hemera.apache.org) W0808 08:29:20.418896 11187 master.cpp:4381] Removing task 1 of framework 20140808-082920-453759884-51004-11187-0000 and slave 20140808-082920-453759884-51004-11187-0 in non-terminal state TASK_RUNNING I0808 08:29:20.421694 11410 sched.cpp:747] Stopping framework '20140808-082920-453759884-51004-11187-0000' I0808 08:29:20.425740 11412 slave.cpp:2356] [email protected]:51004 exited W0808 08:29:20.425762 11412 slave.cpp:2359] Master disconnected! Waiting for a new master to be elected I0808 08:29:20.439975 11422 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 21.281756ms I0808 08:29:20.440028 11422 leveldb.cpp:401] Deleting ~2 keys from leveldb took 25608ns I0808 08:29:20.440042 11422 replica.cpp:676] Persisted action at 4 I0808 08:29:20.440052 11422 replica.cpp:661] Replica learned TRUNCATE action at position 4 I0808 08:29:20.440588 11187 slave.cpp:466] Slave terminating I0808 08:29:20.440608 11187 slave.cpp:1406] Asked to shut down framework 20140808-082920-453759884-51004-11187-0000 by @0.0.0.0:0 I0808 08:29:20.440623 11187 slave.cpp:1431] Shutting down framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.440634 11187 slave.cpp:2855] Shutting down executor 'default' of framework 20140808-082920-453759884-51004-11187-0000 [ OK ] FaultToleranceTest.ForwardStatusUpdateUnknownExecutor (423 ms) [ RUN ] FaultToleranceTest.SchedulerFailoverRetriedReregistration Using temporary directory '/tmp/FaultToleranceTest_SchedulerFailoverRetriedReregistration_ZoUr0Y' I0808 08:29:20.501770 11187 leveldb.cpp:176] Opened db in 59.693953ms I0808 08:29:20.521766 11187 leveldb.cpp:183] Compacted db in 19.97515ms I0808 08:29:20.521787 11187 leveldb.cpp:198] Created db iterator in 3148ns I0808 08:29:20.521795 11187 leveldb.cpp:204] Seeked to beginning of db in 607ns I0808 08:29:20.521801 11187 leveldb.cpp:273] Iterated through 0 keys in the db in 327ns I0808 08:29:20.521814 11187 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I0808 08:29:20.526613 11421 master.cpp:286] Master 20140808-082920-453759884-51004-11187 (hemera.apache.org) started on 140.211.11.27:51004 I0808 08:29:20.526633 11421 master.cpp:323] Master only allowing authenticated frameworks to register I0808 08:29:20.526639 11421 master.cpp:328] Master only allowing authenticated slaves to register I0808 08:29:20.526646 11421 credentials.hpp:36] Loading credentials for authentication from '/tmp/FaultToleranceTest_SchedulerFailoverRetriedReregistration_ZoUr0Y/credentials' I0808 08:29:20.526762 11421 master.cpp:357] Authorization enabled I0808 08:29:20.527204 11421 recover.cpp:425] Starting replica recovery I0808 08:29:20.527487 11421 hierarchical_allocator_process.hpp:296] Initializing hierarchical allocator process with master : [email protected]:51004 I0808 08:29:20.527523 11421 master.cpp:120] No whitelist given. Advertising offers for all slaves I0808 08:29:20.527598 11421 master.cpp:1196] The newly elected leader is [email protected]:51004 with id 20140808-082920-453759884-51004-11187 I0808 08:29:20.527609 11421 master.cpp:1209] Elected as the leading master! I0808 08:29:20.527616 11421 master.cpp:1027] Recovering from registrar I0808 08:29:20.527675 11421 recover.cpp:451] Replica is in EMPTY status I0808 08:29:20.527729 11421 registrar.cpp:313] Recovering registrar I0808 08:29:20.528209 11421 replica.cpp:638] Replica in EMPTY status received a broadcasted recover request I0808 08:29:20.528271 11421 recover.cpp:188] Received a recover response from a replica in EMPTY status I0808 08:29:20.528380 11421 recover.cpp:542] Updating replica status to STARTING I0808 08:29:20.541652 11421 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 13.213068ms I0808 08:29:20.541674 11421 replica.cpp:320] Persisted replica status to STARTING I0808 08:29:20.541750 11421 recover.cpp:451] Replica is in STARTING status I0808 08:29:20.542052 11421 replica.cpp:638] Replica in STARTING status received a broadcasted recover request I0808 08:29:20.542110 11421 recover.cpp:188] Received a recover response from a replica in STARTING status I0808 08:29:20.542215 11421 recover.cpp:542] Updating replica status to VOTING I0808 08:29:20.556958 11421 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 14.692875ms I0808 08:29:20.556978 11421 replica.cpp:320] Persisted replica status to VOTING I0808 08:29:20.557020 11421 recover.cpp:556] Successfully joined the Paxos group I0808 08:29:20.557075 11421 recover.cpp:440] Recover process terminated I0808 08:29:20.557186 11421 log.cpp:656] Attempting to start the writer I0808 08:29:20.557487 11421 replica.cpp:474] Replica received implicit promise request with proposal 1 I0808 08:29:20.577652 11421 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 20.151979ms I0808 08:29:20.577675 11421 replica.cpp:342] Persisted promised to 1 I0808 08:29:20.577860 11421 coordinator.cpp:230] Coordinator attemping to fill missing position I0808 08:29:20.578196 11421 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2 I0808 08:29:20.597290 11421 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 19.078578ms I0808 08:29:20.597311 11421 replica.cpp:676] Persisted action at 0 I0808 08:29:20.597597 11421 replica.cpp:508] Replica received write request for position 0 I0808 08:29:20.597620 11421 leveldb.cpp:438] Reading position from leveldb took 11134ns I0808 08:29:20.617655 11421 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 20.021955ms I0808 08:29:20.617677 11421 replica.cpp:676] Persisted action at 0 I0808 08:29:20.617840 11421 replica.cpp:655] Replica received learned notice for position 0 I0808 08:29:20.633283 11421 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 15.427933ms I0808 08:29:20.633304 11421 replica.cpp:676] Persisted action at 0 I0808 08:29:20.633312 11421 replica.cpp:661] Replica learned NOP action at position 0 I0808 08:29:20.639484 11413 log.cpp:672] Writer started with ending position 0 I0808 08:29:20.639817 11413 leveldb.cpp:438] Reading position from leveldb took 21073ns I0808 08:29:20.641841 11413 registrar.cpp:346] Successfully fetched the registry (0B) I0808 08:29:20.641863 11413 registrar.cpp:422] Attempting to update the 'registry' I0808 08:29:20.643923 11413 log.cpp:680] Attempting to append 138 bytes to the log I0808 08:29:20.643980 11413 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1 I0808 08:29:20.644218 11413 replica.cpp:508] Replica received write request for position 1 I0808 08:29:20.657707 11413 leveldb.cpp:343] Persisting action (157 bytes) to leveldb took 13.462174ms I0808 08:29:20.657757 11413 replica.cpp:676] Persisted action at 1 I0808 08:29:20.658113 11413 replica.cpp:655] Replica received learned notice for position 1 I0808 08:29:20.673476 11413 leveldb.cpp:343] Persisting action (159 bytes) to leveldb took 15.344599ms I0808 08:29:20.673506 11413 replica.cpp:676] Persisted action at 1 I0808 08:29:20.673516 11413 replica.cpp:661] Replica learned APPEND action at position 1 I0808 08:29:20.673897 11413 registrar.cpp:479] Successfully updated 'registry' I0808 08:29:20.673949 11413 registrar.cpp:372] Successfully recovered registrar I0808 08:29:20.674033 11413 master.cpp:1054] Recovered 0 slaves from the Registry (100B) ; allowing 10mins for slaves to re-register I0808 08:29:20.677769 11443 log.cpp:699] Attempting to truncate the log to 1 I0808 08:29:20.681736 11430 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2 I0808 08:29:20.682004 11430 replica.cpp:508] Replica received write request for position 2 I0808 08:29:20.697659 11430 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 15.637516ms I0808 08:29:20.697685 11430 replica.cpp:676] Persisted action at 2 I0808 08:29:20.697895 11430 replica.cpp:655] Replica received learned notice for position 2 I0808 08:29:20.709648 11430 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 11.731527ms I0808 08:29:20.709691 11430 leveldb.cpp:401] Deleting ~1 keys from leveldb took 19188ns I0808 08:29:20.709700 11430 replica.cpp:676] Persisted action at 2 I0808 08:29:20.709709 11430 replica.cpp:661] Replica learned TRUNCATE action at position 2 I0808 08:29:20.733861 11187 sched.cpp:139] Version: 0.20.0 I0808 08:29:20.737797 11430 sched.cpp:235] New master detected at [email protected]:51004 I0808 08:29:20.737814 11430 sched.cpp:285] Authenticating with master [email protected]:51004 I0808 08:29:20.737893 11430 authenticatee.hpp:128] Creating new client SASL connection I0808 08:29:20.738020 11430 master.cpp:3615] Authenticating [email protected]:51004 I0808 08:29:20.738106 11430 authenticator.hpp:156] Creating new server SASL connection I0808 08:29:20.738191 11430 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I0808 08:29:20.738206 11430 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I0808 08:29:20.738231 11430 authenticator.hpp:262] Received SASL authentication start I0808 08:29:20.738265 11430 authenticator.hpp:384] Authentication requires more steps I0808 08:29:20.738291 11430 authenticatee.hpp:265] Received SASL authentication step I0808 08:29:20.738323 11430 authenticator.hpp:290] Received SASL authentication step I0808 08:29:20.738337 11430 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0808 08:29:20.738343 11430 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0808 08:29:20.738353 11430 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0808 08:29:20.738363 11430 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0808 08:29:20.738368 11430 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0808 08:29:20.738373 11430 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0808 08:29:20.738384 11430 authenticator.hpp:376] Authentication success I0808 08:29:20.738409 11430 authenticatee.hpp:305] Authentication success I0808 08:29:20.738430 11430 master.cpp:3655] Successfully authenticated principal 'test-principal' at [email protected]:51004 I0808 08:29:20.738493 11430 sched.cpp:359] Successfully authenticated with master [email protected]:51004 I0808 08:29:20.738504 11430 sched.cpp:478] Sending registration request to [email protected]:51004 I0808 08:29:20.738545 11430 master.cpp:1315] Received registration request from [email protected]:51004 I0808 08:29:20.738562 11430 master.cpp:1275] Authorizing framework principal 'test-principal' to receive offers for role '*' I0808 08:29:20.738670 11430 master.cpp:1374] Registering framework 20140808-082920-453759884-51004-11187-0000 at [email protected]:51004 I0808 08:29:20.738759 11430 sched.cpp:409] Framework registered with 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.738780 11430 sched.cpp:423] Scheduler::registered took 12915ns I0808 08:29:20.738814 11430 hierarchical_allocator_process.hpp:326] Added framework 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.738822 11430 hierarchical_allocator_process.hpp:688] No resources available to allocate! I0808 08:29:20.738827 11430 hierarchical_allocator_process.hpp:650] Performed allocation for 0 slaves in 6004ns I0808 08:29:20.743126 11187 sched.cpp:139] Version: 0.20.0 I0808 08:29:20.753739 11437 sched.cpp:235] New master detected at [email protected]:51004 I0808 08:29:20.753757 11437 sched.cpp:285] Authenticating with master [email protected]:51004 I0808 08:29:20.753829 11437 authenticatee.hpp:128] Creating new client SASL connection I0808 08:29:20.753943 11437 master.cpp:3615] Authenticating [email protected]:51004 I0808 08:29:20.754015 11437 authenticator.hpp:156] Creating new server SASL connection I0808 08:29:20.754092 11437 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I0808 08:29:20.754106 11437 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I0808 08:29:20.754129 11437 authenticator.hpp:262] Received SASL authentication start I0808 08:29:20.754159 11437 authenticator.hpp:384] Authentication requires more steps I0808 08:29:20.754184 11437 authenticatee.hpp:265] Received SASL authentication step I0808 08:29:20.754215 11437 authenticator.hpp:290] Received SASL authentication step I0808 08:29:20.754226 11437 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0808 08:29:20.754233 11437 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0808 08:29:20.754241 11437 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0808 08:29:20.754250 11437 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0808 08:29:20.754256 11437 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0808 08:29:20.754261 11437 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0808 08:29:20.754271 11437 authenticator.hpp:376] Authentication success I0808 08:29:20.754295 11437 authenticatee.hpp:305] Authentication success I0808 08:29:20.754317 11437 master.cpp:3655] Successfully authenticated principal 'test-principal' at [email protected]:51004 I0808 08:29:20.754372 11437 sched.cpp:359] Successfully authenticated with master [email protected]:51004 I0808 08:29:20.754382 11437 sched.cpp:478] Sending registration request to [email protected]:51004 I0808 08:29:20.754422 11437 master.cpp:1423] Received re-registration request from framework 20140808-082920-453759884-51004-11187-0000 at [email protected]:51004 I0808 08:29:20.754441 11437 master.cpp:1275] Authorizing framework principal 'test-principal' to receive offers for role '*' I0808 08:29:20.754521 11437 master.cpp:1474] Re-registering framework 20140808-082920-453759884-51004-11187-0000 at [email protected]:51004 I0808 08:29:20.754534 11437 master.cpp:1501] Framework 20140808-082920-453759884-51004-11187-0000 failed over I0808 08:29:20.754576 11437 sched.cpp:731] Got error 'Framework failed over' I0808 08:29:20.754597 11437 sched.cpp:742] Scheduler::error took 8852ns I0808 08:29:20.754613 11437 sched.cpp:772] Aborting framework '20140808-082920-453759884-51004-11187-0000' W0808 08:29:20.754652 11437 master.cpp:1640] Ignoring deactivate framework message for framework 20140808-082920-453759884-51004-11187-0000 from '[email protected]:51004' because it is not from the registered framework '[email protected]:51004' I0808 08:29:20.765862 11437 hierarchical_allocator_process.hpp:688] No resources available to allocate! I0808 08:29:20.765874 11437 hierarchical_allocator_process.hpp:650] Performed allocation for 0 slaves in 15646ns I0808 08:29:20.765916 11437 sched.cpp:478] Sending registration request to [email protected]:51004 I0808 08:29:20.765955 11437 master.cpp:1423] Received re-registration request from framework 20140808-082920-453759884-51004-11187-0000 at [email protected]:51004 I0808 08:29:20.765974 11437 master.cpp:1275] Authorizing framework principal 'test-principal' to receive offers for role '*' I0808 08:29:20.766053 11437 master.cpp:1474] Re-registering framework 20140808-082920-453759884-51004-11187-0000 at [email protected]:51004 I0808 08:29:20.766065 11437 master.cpp:1501] Framework 20140808-082920-453759884-51004-11187-0000 failed over I0808 08:29:20.766099 11437 sched.cpp:409] Framework registered with 20140808-082920-453759884-51004-11187-0000 I0808 08:29:20.766115 11437 sched.cpp:423] Scheduler::registered took 8119ns I0808 08:29:20.785738 11414 sched.cpp:747] Stopping framework '20140808-082920-453759884-51004-11187-0000' I0808 08:29:20.785786 11414 sched.cpp:747] Stopping framework '20140808-082920-453759884-51004-11187-0000' I0808 08:29:20.785889 11187 master.cpp:634] Master terminating [ OK ] FaultToleranceTest.SchedulerFailoverRetriedReregistration (346 ms) [----------] 24 tests from FaultToleranceTest (16559 ms total) [----------] Global test environment tear-down 2014-08-08 08:29:20,825:11187(0x2ab3c259b700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:44357] zk retcode=-4, errno=111(Connection refused): server refused to accept the client [==========] 398 tests from 64 test cases ran. (516194 ms total) [ PASSED ] 397 tests. [ FAILED ] 1 test, listed below: [ FAILED ] SlaveRecoveryTest/0.ShutdownSlave, where TypeParam = mesos::internal::slave::MesosContainerizer 1 FAILED TEST YOU HAVE 5 DISABLED TESTS make[4]: *** [check-local] Error 1 make[4]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build/src' make[3]: *** [check-am] Error 2 make[3]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build/src' make[2]: *** [check] Error 2 make[2]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build/src' make[1]: *** [check-recursive] Error 1 make[1]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build' make: *** [distcheck] Error 1 Build step 'Execute shell' marked build as failure
