See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/2301/changes>
Changes: [niklas] Removed trailing diff/ from review line in commit message. ------------------------------------------ [...truncated 73042 lines...] I1120 00:31:33.246858 9759 replica.cpp:508] Replica received write request for position 1 I1120 00:31:33.247647 9759 leveldb.cpp:343] Persisting action (161 bytes) to leveldb took 749628ns I1120 00:31:33.247680 9759 replica.cpp:676] Persisted action at 1 I1120 00:31:33.248344 9763 replica.cpp:655] Replica received learned notice for position 1 I1120 00:31:33.248913 9763 leveldb.cpp:343] Persisting action (163 bytes) to leveldb took 535506ns I1120 00:31:33.248945 9763 replica.cpp:676] Persisted action at 1 I1120 00:31:33.248970 9763 replica.cpp:661] Replica learned APPEND action at position 1 I1120 00:31:33.249984 9750 registrar.cpp:490] Successfully updated the 'registry' in 7.181056ms I1120 00:31:33.250138 9750 registrar.cpp:376] Successfully recovered registrar I1120 00:31:33.250406 9764 log.cpp:699] Attempting to truncate the log to 1 I1120 00:31:33.250458 9752 master.cpp:1121] Recovered 0 slaves from the Registry (104B) ; allowing 10mins for slaves to re-register I1120 00:31:33.250623 9763 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2 I1120 00:31:33.251741 9751 replica.cpp:508] Replica received write request for position 2 I1120 00:31:33.252291 9751 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 512376ns I1120 00:31:33.252326 9751 replica.cpp:676] Persisted action at 2 I1120 00:31:33.252954 9750 replica.cpp:655] Replica received learned notice for position 2 I1120 00:31:33.253599 9750 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 611448ns I1120 00:31:33.253656 9750 leveldb.cpp:401] Deleting ~1 keys from leveldb took 28471ns I1120 00:31:33.253675 9750 replica.cpp:676] Persisted action at 2 I1120 00:31:33.253697 9750 replica.cpp:661] Replica learned TRUNCATE action at position 2 I1120 00:31:33.273808 9761 slave.cpp:170] Slave started on 229)@67.195.81.189:36611 I1120 00:31:33.273844 9761 credentials.hpp:84] Loading credential for authentication from '/tmp/MasterSlaveReconciliationTest_SlaveReregisterTerminatedExecutor_WYM4Rz/credential' I1120 00:31:33.273977 9761 slave.cpp:279] Slave using credential for: test-principal I1120 00:31:33.274168 9761 slave.cpp:292] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1120 00:31:33.274255 9761 slave.cpp:321] Slave hostname: proserpina.apache.org I1120 00:31:33.274276 9761 slave.cpp:322] Slave checkpoint: false W1120 00:31:33.274286 9761 slave.cpp:324] Disabling checkpointing is deprecated and the --checkpoint flag will be removed in a future release. Please avoid using this flag I1120 00:31:33.274905 9759 state.cpp:33] Recovering state from '/tmp/MasterSlaveReconciliationTest_SlaveReregisterTerminatedExecutor_WYM4Rz/meta' I1120 00:31:33.275272 9764 status_update_manager.cpp:197] Recovering status update manager I1120 00:31:33.275698 9759 slave.cpp:3481] Finished recovery I1120 00:31:33.276167 9761 slave.cpp:605] New master detected at [email protected]:36611 I1120 00:31:33.276201 9764 status_update_manager.cpp:171] Pausing sending status updates I1120 00:31:33.276209 9761 slave.cpp:668] Authenticating with master [email protected]:36611 I1120 00:31:33.276237 9761 slave.cpp:673] Using default CRAM-MD5 authenticatee I1120 00:31:33.276345 9761 slave.cpp:641] Detecting new master I1120 00:31:33.276500 9759 authenticatee.hpp:138] Creating new client SASL connection I1120 00:31:33.276711 9763 master.cpp:3902] Authenticating slave(229)@67.195.81.189:36611 I1120 00:31:33.276751 9763 master.cpp:3913] Using default CRAM-MD5 authenticator I1120 00:31:33.277050 9760 authenticator.hpp:170] Creating new server SASL connection I1120 00:31:33.277246 9756 authenticatee.hpp:229] Received SASL authentication mechanisms: CRAM-MD5 I1120 00:31:33.277293 9756 authenticatee.hpp:255] Attempting to authenticate with mechanism 'CRAM-MD5' I1120 00:31:33.277401 9756 authenticator.hpp:276] Received SASL authentication start I1120 00:31:33.277452 9756 authenticator.hpp:398] Authentication requires more steps I1120 00:31:33.277550 9753 authenticatee.hpp:275] Received SASL authentication step I1120 00:31:33.277750 9764 authenticator.hpp:304] Received SASL authentication step I1120 00:31:33.277789 9764 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1120 00:31:33.277808 9764 auxprop.cpp:171] Looking up auxiliary property '*userPassword' I1120 00:31:33.277848 9764 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1120 00:31:33.277889 9764 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1120 00:31:33.277907 9764 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1120 00:31:33.277917 9764 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1120 00:31:33.277935 9764 authenticator.hpp:390] Authentication success I1120 00:31:33.278087 9764 master.cpp:3960] Successfully authenticated principal 'test-principal' at slave(229)@67.195.81.189:36611 I1120 00:31:33.278120 9753 authenticatee.hpp:315] Authentication success I1120 00:31:33.278470 9757 slave.cpp:739] Successfully authenticated with master [email protected]:36611 I1120 00:31:33.278585 9757 slave.cpp:1067] Will retry registration in 14.722299ms if necessary I1120 00:31:33.278786 9760 master.cpp:3069] Registering slave at slave(229)@67.195.81.189:36611 (proserpina.apache.org) with id 20141120-003133-3176252227-36611-9736-S0 I1120 00:31:33.279285 9763 registrar.cpp:445] Applied 1 operations in 52841ns; attempting to update the 'registry' I1120 00:31:33.280839 9736 sched.cpp:148] Version: 0.22.0 I1120 00:31:33.281347 9751 sched.cpp:245] New master detected at [email protected]:36611 I1120 00:31:33.281395 9751 sched.cpp:301] Authenticating with master [email protected]:36611 I1120 00:31:33.281412 9751 sched.cpp:308] Using default CRAM-MD5 authenticatee I1120 00:31:33.281664 9755 authenticatee.hpp:138] Creating new client SASL connection I1120 00:31:33.282006 9751 master.cpp:3902] Authenticating [email protected]:36611 I1120 00:31:33.282079 9751 master.cpp:3913] Using default CRAM-MD5 authenticator I1120 00:31:33.282414 9750 authenticator.hpp:170] Creating new server SASL connection I1120 00:31:33.282614 9761 log.cpp:680] Attempting to append 322 bytes to the log I1120 00:31:33.282757 9755 authenticatee.hpp:229] Received SASL authentication mechanisms: CRAM-MD5 I1120 00:31:33.282788 9755 authenticatee.hpp:255] Attempting to authenticate with mechanism 'CRAM-MD5' I1120 00:31:33.282878 9755 authenticator.hpp:276] Received SASL authentication start I1120 00:31:33.282929 9755 authenticator.hpp:398] Authentication requires more steps I1120 00:31:33.283012 9755 authenticatee.hpp:275] Received SASL authentication step I1120 00:31:33.283048 9751 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3 I1120 00:31:33.283278 9757 authenticator.hpp:304] Received SASL authentication step I1120 00:31:33.283323 9757 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1120 00:31:33.283335 9757 auxprop.cpp:171] Looking up auxiliary property '*userPassword' I1120 00:31:33.283368 9757 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1120 00:31:33.283393 9757 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1120 00:31:33.283406 9757 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1120 00:31:33.283413 9757 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1120 00:31:33.283431 9757 authenticator.hpp:390] Authentication success I1120 00:31:33.283547 9754 authenticatee.hpp:315] Authentication success I1120 00:31:33.283761 9762 master.cpp:3960] Successfully authenticated principal 'test-principal' at [email protected]:36611 I1120 00:31:33.283891 9751 sched.cpp:389] Successfully authenticated with master [email protected]:36611 I1120 00:31:33.283922 9751 sched.cpp:512] Sending registration request to [email protected]:36611 I1120 00:31:33.283983 9751 sched.cpp:545] Will retry registration in 315.402025ms if necessary I1120 00:31:33.284198 9755 replica.cpp:508] Replica received write request for position 3 I1120 00:31:33.284255 9762 master.cpp:1383] Received registration request for framework 'default' at [email protected]:36611 I1120 00:31:33.284338 9762 master.cpp:1342] Authorizing framework principal 'test-principal' to receive offers for role '*' I1120 00:31:33.284685 9755 leveldb.cpp:343] Persisting action (341 bytes) to leveldb took 452755ns I1120 00:31:33.284718 9755 replica.cpp:676] Persisted action at 3 I1120 00:31:33.284723 9761 master.cpp:1447] Registering framework 20141120-003133-3176252227-36611-9736-0000 (default) at [email protected]:36611 I1120 00:31:33.285146 9751 hierarchical_allocator_process.hpp:329] Added framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.285176 9751 hierarchical_allocator_process.hpp:697] No resources available to allocate! I1120 00:31:33.285187 9751 hierarchical_allocator_process.hpp:659] Performed allocation for 0 slaves in 15119ns I1120 00:31:33.285403 9750 replica.cpp:655] Replica received learned notice for position 3 I1120 00:31:33.285637 9756 sched.cpp:439] Framework registered with 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.285693 9756 sched.cpp:453] Scheduler::registered took 26361ns I1120 00:31:33.285830 9750 leveldb.cpp:343] Persisting action (343 bytes) to leveldb took 394343ns I1120 00:31:33.285862 9750 replica.cpp:676] Persisted action at 3 I1120 00:31:33.285895 9750 replica.cpp:661] Replica learned APPEND action at position 3 I1120 00:31:33.287171 9765 registrar.cpp:490] Successfully updated the 'registry' in 7.826688ms I1120 00:31:33.287648 9760 log.cpp:699] Attempting to truncate the log to 3 I1120 00:31:33.287824 9750 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4 I1120 00:31:33.287891 9759 slave.cpp:2553] Received ping from slave-observer(209)@67.195.81.189:36611 I1120 00:31:33.287894 9762 master.cpp:3123] Registered slave 20141120-003133-3176252227-36611-9736-S0 at slave(229)@67.195.81.189:36611 (proserpina.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1120 00:31:33.288127 9759 slave.cpp:773] Registered with master [email protected]:36611; given slave ID 20141120-003133-3176252227-36611-9736-S0 I1120 00:31:33.288183 9760 hierarchical_allocator_process.hpp:442] Added slave 20141120-003133-3176252227-36611-9736-S0 (proserpina.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) I1120 00:31:33.288259 9751 status_update_manager.cpp:178] Resuming sending status updates I1120 00:31:33.288487 9760 hierarchical_allocator_process.hpp:734] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141120-003133-3176252227-36611-9736-S0 to framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.288758 9756 replica.cpp:508] Replica received write request for position 4 I1120 00:31:33.288981 9760 hierarchical_allocator_process.hpp:679] Performed allocation for slave 20141120-003133-3176252227-36611-9736-S0 in 625667ns I1120 00:31:33.289255 9756 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 455932ns I1120 00:31:33.289286 9756 replica.cpp:676] Persisted action at 4 I1120 00:31:33.289324 9763 master.cpp:3844] Sending 1 offers to framework 20141120-003133-3176252227-36611-9736-0000 (default) at [email protected]:36611 I1120 00:31:33.290019 9760 replica.cpp:655] Replica received learned notice for position 4 I1120 00:31:33.290294 9754 sched.cpp:602] Scheduler::resourceOffers took 644467ns I1120 00:31:33.290500 9760 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 448968ns I1120 00:31:33.290555 9760 leveldb.cpp:401] Deleting ~2 keys from leveldb took 26854ns I1120 00:31:33.290572 9760 replica.cpp:676] Persisted action at 4 I1120 00:31:33.290596 9760 replica.cpp:661] Replica learned TRUNCATE action at position 4 I1120 00:31:33.291132 9754 master.cpp:2363] Processing reply for offers: [ 20141120-003133-3176252227-36611-9736-O0 ] on slave 20141120-003133-3176252227-36611-9736-S0 at slave(229)@67.195.81.189:36611 (proserpina.apache.org) for framework 20141120-003133-3176252227-36611-9736-0000 (default) at [email protected]:36611 I1120 00:31:33.291173 9754 master.cpp:2461] Authorizing framework principal 'test-principal' to launch task 0 as user 'jenkins' W1120 00:31:33.291971 9765 master.cpp:1998] 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. W1120 00:31:33.292031 9765 master.cpp:2010] 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. I1120 00:31:33.292399 9765 master.hpp:753] Adding task 0 with resources cpus(*):1; mem(*):512 on slave 20141120-003133-3176252227-36611-9736-S0 (proserpina.apache.org) I1120 00:31:33.292510 9765 master.cpp:2531] Launching task 0 of framework 20141120-003133-3176252227-36611-9736-0000 (default) at [email protected]:36611 with resources cpus(*):1; mem(*):512 on slave 20141120-003133-3176252227-36611-9736-S0 at slave(229)@67.195.81.189:36611 (proserpina.apache.org) I1120 00:31:33.292825 9756 slave.cpp:1098] Got assigned task 0 for framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.293000 9760 hierarchical_allocator_process.hpp:563] Recovered cpus(*):1; mem(*):512; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):1; mem(*):512; disk(*):1024; ports(*):[31000-32000]) on slave 20141120-003133-3176252227-36611-9736-S0 from framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.293099 9760 hierarchical_allocator_process.hpp:599] Framework 20141120-003133-3176252227-36611-9736-0000 filtered slave 20141120-003133-3176252227-36611-9736-S0 for 5secs I1120 00:31:33.293375 9756 slave.cpp:1208] Launching task 0 for framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.296140 9756 slave.cpp:3863] Launching executor default of framework 20141120-003133-3176252227-36611-9736-0000 in work directory '/tmp/MasterSlaveReconciliationTest_SlaveReregisterTerminatedExecutor_WYM4Rz/slaves/20141120-003133-3176252227-36611-9736-S0/frameworks/20141120-003133-3176252227-36611-9736-0000/executors/default/runs/9ba5c71e-ebf3-459a-8a40-8cedcf674694' I1120 00:31:33.298799 9756 exec.cpp:132] Version: 0.22.0 I1120 00:31:33.299001 9760 exec.cpp:182] Executor started at: executor(78)@67.195.81.189:36611 with pid 9736 I1120 00:31:33.299141 9756 slave.cpp:1331] Queuing task '0' for executor default of framework '20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.299268 9756 slave.cpp:558] Successfully attached file '/tmp/MasterSlaveReconciliationTest_SlaveReregisterTerminatedExecutor_WYM4Rz/slaves/20141120-003133-3176252227-36611-9736-S0/frameworks/20141120-003133-3176252227-36611-9736-0000/executors/default/runs/9ba5c71e-ebf3-459a-8a40-8cedcf674694' I1120 00:31:33.299374 9756 slave.cpp:2855] Monitoring executor 'default' of framework '20141120-003133-3176252227-36611-9736-0000' in container '9ba5c71e-ebf3-459a-8a40-8cedcf674694' I1120 00:31:33.299530 9756 slave.cpp:1875] Got registration for executor 'default' of framework 20141120-003133-3176252227-36611-9736-0000 from executor(78)@67.195.81.189:36611 I1120 00:31:33.299831 9756 slave.cpp:1994] Flushing queued task 0 for executor 'default' of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.299938 9761 exec.cpp:206] Executor registered on slave 20141120-003133-3176252227-36611-9736-S0 I1120 00:31:33.302284 9761 exec.cpp:218] Executor::registered took 25254ns I1120 00:31:33.302472 9761 exec.cpp:293] Executor asked to run task '0' I1120 00:31:33.302597 9761 exec.cpp:302] Executor::launchTask took 57292ns I1120 00:31:33.304903 9761 exec.cpp:525] Executor sending status update TASK_RUNNING (UUID: 865dc626-5010-40f6-adec-552081ba1018) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.305169 9761 slave.cpp:2230] Handling status update TASK_RUNNING (UUID: 865dc626-5010-40f6-adec-552081ba1018) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 from executor(78)@67.195.81.189:36611 I1120 00:31:33.305533 9754 status_update_manager.cpp:317] Received status update TASK_RUNNING (UUID: 865dc626-5010-40f6-adec-552081ba1018) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.305583 9754 status_update_manager.cpp:494] Creating StatusUpdate stream for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.305788 9754 status_update_manager.cpp:371] Forwarding update TASK_RUNNING (UUID: 865dc626-5010-40f6-adec-552081ba1018) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 to the slave I1120 00:31:33.306012 9761 slave.cpp:2473] Forwarding the update TASK_RUNNING (UUID: 865dc626-5010-40f6-adec-552081ba1018) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 to [email protected]:36611 I1120 00:31:33.306244 9761 slave.cpp:2400] Status update manager successfully handled status update TASK_RUNNING (UUID: 865dc626-5010-40f6-adec-552081ba1018) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.306288 9761 slave.cpp:2406] Sending acknowledgement for status update TASK_RUNNING (UUID: 865dc626-5010-40f6-adec-552081ba1018) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 to executor(78)@67.195.81.189:36611 I1120 00:31:33.306375 9751 master.cpp:3447] Forwarding status update TASK_RUNNING (UUID: 865dc626-5010-40f6-adec-552081ba1018) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.306453 9762 exec.cpp:339] Executor received status update acknowledgement 865dc626-5010-40f6-adec-552081ba1018 for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.306505 9751 master.cpp:3419] Status update TASK_RUNNING (UUID: 865dc626-5010-40f6-adec-552081ba1018) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 from slave 20141120-003133-3176252227-36611-9736-S0 at slave(229)@67.195.81.189:36611 (proserpina.apache.org) I1120 00:31:33.306555 9751 master.cpp:4694] Updating the latest state of task 0 of framework 20141120-003133-3176252227-36611-9736-0000 to TASK_RUNNING I1120 00:31:33.306735 9761 sched.cpp:693] Scheduler::statusUpdate took 69237ns I1120 00:31:33.307080 9757 master.cpp:2919] Forwarding status update acknowledgement 865dc626-5010-40f6-adec-552081ba1018 for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 (default) at [email protected]:36611 to slave 20141120-003133-3176252227-36611-9736-S0 at slave(229)@67.195.81.189:36611 (proserpina.apache.org) I1120 00:31:33.307587 9761 status_update_manager.cpp:389] Received status update acknowledgement (UUID: 865dc626-5010-40f6-adec-552081ba1018) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.307790 9761 slave.cpp:1815] Status update manager successfully handled status update acknowledgement (UUID: 865dc626-5010-40f6-adec-552081ba1018) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.310267 9759 exec.cpp:525] Executor sending status update TASK_FINISHED (UUID: 0e933729-a08d-4925-ac1f-072b391473d7) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.310535 9765 slave.cpp:2230] Handling status update TASK_FINISHED (UUID: 0e933729-a08d-4925-ac1f-072b391473d7) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 from executor(78)@67.195.81.189:36611 I1120 00:31:33.310621 9765 slave.cpp:4171] Terminating task 0 I1120 00:31:33.311043 9765 status_update_manager.cpp:317] Received status update TASK_FINISHED (UUID: 0e933729-a08d-4925-ac1f-072b391473d7) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.311156 9765 status_update_manager.cpp:371] Forwarding update TASK_FINISHED (UUID: 0e933729-a08d-4925-ac1f-072b391473d7) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 to the slave I1120 00:31:33.311398 9761 slave.cpp:2473] Forwarding the update TASK_FINISHED (UUID: 0e933729-a08d-4925-ac1f-072b391473d7) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 to [email protected]:36611 I1120 00:31:33.311524 9761 slave.cpp:2400] Status update manager successfully handled status update TASK_FINISHED (UUID: 0e933729-a08d-4925-ac1f-072b391473d7) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.311549 9761 slave.cpp:2406] Sending acknowledgement for status update TASK_FINISHED (UUID: 0e933729-a08d-4925-ac1f-072b391473d7) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 to executor(78)@67.195.81.189:36611 I1120 00:31:33.311765 9761 exec.cpp:339] Executor received status update acknowledgement 0e933729-a08d-4925-ac1f-072b391473d7 for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.312360 9764 slave.cpp:2913] Executor 'default' of framework 20141120-003133-3176252227-36611-9736-0000 exited with status 0 I1120 00:31:33.312849 9751 master.cpp:3499] Executor default of framework 20141120-003133-3176252227-36611-9736-0000 on slave 20141120-003133-3176252227-36611-9736-S0 at slave(229)@67.195.81.189:36611 (proserpina.apache.org) exited with status 0 I1120 00:31:33.312932 9751 master.cpp:4782] Removing executor 'default' with resources of framework 20141120-003133-3176252227-36611-9736-0000 on slave 20141120-003133-3176252227-36611-9736-S0 at slave(229)@67.195.81.189:36611 (proserpina.apache.org) I1120 00:31:33.315479 9751 status_update_manager.cpp:171] Pausing sending status updates I1120 00:31:33.315490 9750 slave.cpp:605] New master detected at [email protected]:36611 I1120 00:31:33.315575 9750 slave.cpp:668] Authenticating with master [email protected]:36611 I1120 00:31:33.315598 9750 slave.cpp:673] Using default CRAM-MD5 authenticatee I1120 00:31:33.315740 9750 slave.cpp:641] Detecting new master I1120 00:31:33.315879 9763 authenticatee.hpp:138] Creating new client SASL connection I1120 00:31:33.316216 9762 master.cpp:3902] Authenticating slave(229)@67.195.81.189:36611 I1120 00:31:33.316262 9762 master.cpp:3913] Using default CRAM-MD5 authenticator I1120 00:31:33.316598 9750 authenticator.hpp:170] Creating new server SASL connection I1120 00:31:33.316865 9765 authenticatee.hpp:229] Received SASL authentication mechanisms: CRAM-MD5 I1120 00:31:33.316890 9765 authenticatee.hpp:255] Attempting to authenticate with mechanism 'CRAM-MD5' I1120 00:31:33.316967 9765 authenticator.hpp:276] Received SASL authentication start I1120 00:31:33.317029 9765 authenticator.hpp:398] Authentication requires more steps I1120 00:31:33.317173 9765 authenticatee.hpp:275] Received SASL authentication step I1120 00:31:33.317325 9765 authenticator.hpp:304] Received SASL authentication step I1120 00:31:33.317360 9765 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1120 00:31:33.317375 9765 auxprop.cpp:171] Looking up auxiliary property '*userPassword' I1120 00:31:33.317409 9765 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1120 00:31:33.317450 9765 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1120 00:31:33.317466 9765 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1120 00:31:33.317484 9765 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1120 00:31:33.317502 9765 authenticator.hpp:390] Authentication success I1120 00:31:33.317631 9755 authenticatee.hpp:315] Authentication success I1120 00:31:33.317670 9752 master.cpp:3960] Successfully authenticated principal 'test-principal' at slave(229)@67.195.81.189:36611 I1120 00:31:33.318022 9753 slave.cpp:739] Successfully authenticated with master [email protected]:36611 I1120 00:31:33.318315 9753 slave.cpp:1067] Will retry registration in 12.959535ms if necessary I1120 00:31:33.318580 9761 master.cpp:3196] Re-registering slave 20141120-003133-3176252227-36611-9736-S0 at slave(229)@67.195.81.189:36611 (proserpina.apache.org) I1120 00:31:33.318922 9750 slave.cpp:841] Re-registered with master [email protected]:36611 I1120 00:31:33.319030 9764 status_update_manager.cpp:178] Resuming sending status updates W1120 00:31:33.319099 9764 status_update_manager.cpp:185] Resending status update TASK_FINISHED (UUID: 0e933729-a08d-4925-ac1f-072b391473d7) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.319141 9764 status_update_manager.cpp:371] Forwarding update TASK_FINISHED (UUID: 0e933729-a08d-4925-ac1f-072b391473d7) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 to the slave I1120 00:31:33.319387 9751 slave.cpp:2473] Forwarding the update TASK_FINISHED (UUID: 0e933729-a08d-4925-ac1f-072b391473d7) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 to [email protected]:36611 I1120 00:31:33.319638 9751 master.cpp:3447] Forwarding status update TASK_FINISHED (UUID: 0e933729-a08d-4925-ac1f-072b391473d7) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.319826 9751 master.cpp:3419] Status update TASK_FINISHED (UUID: 0e933729-a08d-4925-ac1f-072b391473d7) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 from slave 20141120-003133-3176252227-36611-9736-S0 at slave(229)@67.195.81.189:36611 (proserpina.apache.org) I1120 00:31:33.319880 9751 master.cpp:4694] Updating the latest state of task 0 of framework 20141120-003133-3176252227-36611-9736-0000 to TASK_FINISHED I1120 00:31:33.320018 9765 sched.cpp:693] Scheduler::statusUpdate took 56105ns I1120 00:31:33.320199 9758 hierarchical_allocator_process.hpp:563] Recovered cpus(*):1; mem(*):512 (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 20141120-003133-3176252227-36611-9736-S0 from framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.320329 9736 sched.cpp:1364] Asked to stop the driver I1120 00:31:33.320343 9761 master.cpp:4753] Removing task 0 with resources cpus(*):1; mem(*):512 of framework 20141120-003133-3176252227-36611-9736-0000 on slave 20141120-003133-3176252227-36611-9736-S0 at slave(229)@67.195.81.189:36611 (proserpina.apache.org) I1120 00:31:33.320463 9763 sched.cpp:805] Stopping framework '20141120-003133-3176252227-36611-9736-0000' I1120 00:31:33.320500 9761 master.cpp:2919] Forwarding status update acknowledgement 0e933729-a08d-4925-ac1f-072b391473d7 for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 (default) at [email protected]:36611 to slave 20141120-003133-3176252227-36611-9736-S0 at slave(229)@67.195.81.189:36611 (proserpina.apache.org) I1120 00:31:33.320703 9761 master.cpp:698] Master terminating I1120 00:31:33.320873 9753 status_update_manager.cpp:389] Received status update acknowledgement (UUID: 0e933729-a08d-4925-ac1f-072b391473d7) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.320965 9753 status_update_manager.cpp:525] Cleaning up status update stream for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.321210 9765 slave.cpp:2638] [email protected]:36611 exited W1120 00:31:33.321244 9765 slave.cpp:2641] Master disconnected! Waiting for a new master to be elected I1120 00:31:33.321280 9765 slave.cpp:1815] Status update manager successfully handled status update acknowledgement (UUID: 0e933729-a08d-4925-ac1f-072b391473d7) for task 0 of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.321323 9765 slave.cpp:4210] Completing task 0 I1120 00:31:33.321353 9765 slave.cpp:3022] Cleaning up executor 'default' of framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.321594 9756 gc.cpp:56] Scheduling '/tmp/MasterSlaveReconciliationTest_SlaveReregisterTerminatedExecutor_WYM4Rz/slaves/20141120-003133-3176252227-36611-9736-S0/frameworks/20141120-003133-3176252227-36611-9736-0000/executors/default/runs/9ba5c71e-ebf3-459a-8a40-8cedcf674694' for gc 6.99999627945482days in the future I1120 00:31:33.321688 9765 slave.cpp:3099] Cleaning up framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.321790 9756 gc.cpp:56] Scheduling '/tmp/MasterSlaveReconciliationTest_SlaveReregisterTerminatedExecutor_WYM4Rz/slaves/20141120-003133-3176252227-36611-9736-S0/frameworks/20141120-003133-3176252227-36611-9736-0000/executors/default' for gc 6.99999627754667days in the future I1120 00:31:33.321868 9755 status_update_manager.cpp:279] Closing status update streams for framework 20141120-003133-3176252227-36611-9736-0000 I1120 00:31:33.321921 9756 gc.cpp:56] Scheduling '/tmp/MasterSlaveReconciliationTest_SlaveReregisterTerminatedExecutor_WYM4Rz/slaves/20141120-003133-3176252227-36611-9736-S0/frameworks/20141120-003133-3176252227-36611-9736-0000' for gc 6.99999627568296days in the future I1120 00:31:33.336803 9758 slave.cpp:487] Slave terminating [ OK ] MasterSlaveReconciliationTest.SlaveReregisterTerminatedExecutor (136 ms) [----------] 5 tests from MasterSlaveReconciliationTest (727 ms total) [----------] Global test environment tear-down [==========] 477 tests from 75 test cases ran. (322761 ms total) [ PASSED ] 476 tests. [ FAILED ] 1 test, listed below: [ FAILED ] HealthCheckTest.GracePeriod 1 FAILED TEST YOU HAVE 6 DISABLED TESTS make[3]: *** [check-local] Error 1 make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'> make[2]: *** [check-am] Error 2 make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'> make[1]: *** [check] Error 2 make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'> make: *** [check-recursive] Error 1 Test finished Exit status: 2 Build step 'Execute shell' marked build as failure Recording test results
