See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/1740/changes>
Changes: [dlester] Renames filenames of documentation to be lowercase and updates some documentation templates for consistency. ------------------------------------------ [...truncated 15503 lines...] I1029 04:34:33.445878 15490 slave.cpp:1856] Status update manager successfully handled status update TASK_RUNNING (UUID: d20cafd8-2c47-4b00-9a9e-c0156afeee36) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:33.445894 15490 slave.cpp:1862] Sending acknowledgement for status update TASK_RUNNING (UUID: d20cafd8-2c47-4b00-9a9e-c0156afeee36) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 to executor(1)@67.195.138.60:56740 I1029 04:34:33.446005 15493 master.cpp:1425] Status update TASK_RUNNING (UUID: d20cafd8-2c47-4b00-9a9e-c0156afeee36) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 from slave(94)@67.195.138.60:34501 I1029 04:34:33.446101 15489 sched.cpp:527] Scheduler::statusUpdate took 26294ns I1029 04:34:33.446226 17018 exec.cpp:331] Executor received status update acknowledgement d20cafd8-2c47-4b00-9a9e-c0156afeee36 for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:33.446290 17026 process.cpp:986] Socket closed while receiving I1029 04:34:33.446297 15490 status_update_manager.cpp:380] Received status update acknowledgement (UUID: d20cafd8-2c47-4b00-9a9e-c0156afeee36) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:33.446321 15490 status_update_manager.hpp:337] Checkpointing ACK for status update TASK_RUNNING (UUID: d20cafd8-2c47-4b00-9a9e-c0156afeee36) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:33.490413 15490 slave.cpp:1343] Status update manager successfully handled status update acknowledgement (UUID: d20cafd8-2c47-4b00-9a9e-c0156afeee36) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:33.721442 15497 process.cpp:986] Socket closed while receiving I1029 04:34:34.168241 15497 process.cpp:986] Socket closed while receiving I1029 04:34:34.276727 15491 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 54625ns I1029 04:34:34.299937 15490 monitor.cpp:187] Publishing resource usage for executor 'acce0134-da31-4953-a32c-df058c9ece20' of framework '201310290434-1015726915-34501-15179-0000' Command exited with status 0 (pid: 17027) I1029 04:34:34.350019 17021 exec.cpp:505] Executor sending status update TASK_FINISHED (UUID: c4f5385a-0e6d-403a-9660-08fd7bd9778e) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:34.350441 15496 slave.cpp:1737] Handling status update TASK_FINISHED (UUID: c4f5385a-0e6d-403a-9660-08fd7bd9778e) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 from executor(1)@67.195.138.60:56740 I1029 04:34:34.350486 15496 slave.cpp:3173] Terminating task acce0134-da31-4953-a32c-df058c9ece20 I1029 04:34:34.350675 15496 status_update_manager.cpp:305] Received status update TASK_FINISHED (UUID: c4f5385a-0e6d-403a-9660-08fd7bd9778e) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:34.350695 15496 status_update_manager.hpp:337] Checkpointing UPDATE for status update TASK_FINISHED (UUID: c4f5385a-0e6d-403a-9660-08fd7bd9778e) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:34.403280 15497 process.cpp:986] Socket closed while receiving I1029 04:34:34.448339 15496 status_update_manager.cpp:356] Forwarding status update TASK_FINISHED (UUID: c4f5385a-0e6d-403a-9660-08fd7bd9778e) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 to [email protected]:34501 I1029 04:34:34.448765 15495 master.cpp:1425] Status update TASK_FINISHED (UUID: c4f5385a-0e6d-403a-9660-08fd7bd9778e) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 from slave(94)@67.195.138.60:34501 I1029 04:34:34.448879 15495 master.hpp:403] Removing task acce0134-da31-4953-a32c-df058c9ece20 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310290434-1015726915-34501-15179-0 (janus.apache.org) I1029 04:34:34.449038 15495 slave.cpp:1856] Status update manager successfully handled status update TASK_FINISHED (UUID: c4f5385a-0e6d-403a-9660-08fd7bd9778e) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:34.449055 15495 slave.cpp:1862] Sending acknowledgement for status update TASK_FINISHED (UUID: c4f5385a-0e6d-403a-9660-08fd7bd9778e) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 to executor(1)@67.195.138.60:56740 I1029 04:34:34.449065 15496 sched.cpp:527] Scheduler::statusUpdate took 12543ns I1029 04:34:34.449477 17026 process.cpp:986] Socket closed while receiving I1029 04:34:34.449569 17024 exec.cpp:331] Executor received status update acknowledgement c4f5385a-0e6d-403a-9660-08fd7bd9778e for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:34.449988 15495 status_update_manager.cpp:380] Received status update acknowledgement (UUID: c4f5385a-0e6d-403a-9660-08fd7bd9778e) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:34.450022 15495 status_update_manager.hpp:337] Checkpointing ACK for status update TASK_FINISHED (UUID: c4f5385a-0e6d-403a-9660-08fd7bd9778e) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:34.450268 15489 hierarchical_allocator_process.hpp:637] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 201310290434-1015726915-34501-15179-0 from framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:34.498437 15495 status_update_manager.cpp:507] Cleaning up status update stream for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:34.498764 15495 slave.cpp:1343] Status update manager successfully handled status update acknowledgement (UUID: c4f5385a-0e6d-403a-9660-08fd7bd9778e) for task acce0134-da31-4953-a32c-df058c9ece20 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:34.498783 15495 slave.cpp:3196] Completing task acce0134-da31-4953-a32c-df058c9ece20 I1029 04:34:35.277515 15492 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310290434-1015726915-34501-15179-0 to framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:35.277709 15492 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 269342ns I1029 04:34:35.277796 15492 master.hpp:413] Adding offer 201310290434-1015726915-34501-15179-1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310290434-1015726915-34501-15179-0 (janus.apache.org) I1029 04:34:35.277851 15492 master.cpp:1668] Sending 1 offers to framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:35.277987 15492 sched.cpp:472] Scheduler::resourceOffers took 10964ns I1029 04:34:35.313392 15491 monitor.cpp:187] Publishing resource usage for executor 'acce0134-da31-4953-a32c-df058c9ece20' of framework '201310290434-1015726915-34501-15179-0000' I1029 04:34:35.350929 15497 process.cpp:986] Socket closed while receiving I1029 04:34:36.277330 15490 process_isolator.cpp:479] Telling slave of terminated executor 'acce0134-da31-4953-a32c-df058c9ece20' of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:36.277477 15491 slave.cpp:2122] Executor 'acce0134-da31-4953-a32c-df058c9ece20' of framework 201310290434-1015726915-34501-15179-0000 has exited with status 0 I1029 04:34:36.277828 15491 slave.cpp:2257] Cleaning up executor 'acce0134-da31-4953-a32c-df058c9ece20' of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:36.278204 15495 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_6yy8Lq/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/acce0134-da31-4953-a32c-df058c9ece20/runs/d198a374-c2be-4983-ad6e-67c02f1e9333' for gc 6.99999678226667days in the future I1029 04:34:36.278331 15495 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 34415ns I1029 04:34:36.278640 15495 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_6yy8Lq/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/acce0134-da31-4953-a32c-df058c9ece20' for gc 6.99999678125037days in the future I1029 04:34:36.278702 15495 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_6yy8Lq/meta/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/acce0134-da31-4953-a32c-df058c9ece20/runs/d198a374-c2be-4983-ad6e-67c02f1e9333' for gc 6.99999677504593days in the future I1029 04:34:36.278714 15491 slave.cpp:2328] Cleaning up framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:36.278769 15495 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_6yy8Lq/meta/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/acce0134-da31-4953-a32c-df058c9ece20' for gc 6.9999967745363days in the future I1029 04:34:36.278825 15495 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_6yy8Lq/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000' for gc 6.99999677376days in the future I1029 04:34:36.278878 15495 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_6yy8Lq/meta/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000' for gc 6.99999677328593days in the future I1029 04:34:36.279021 15495 status_update_manager.cpp:267] Closing status update streams for framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:36.279225 15491 slave.cpp:388] Slave terminating W1029 04:34:36.290081 15490 process_isolator.cpp:265] Failed to kill the process tree rooted at pid 16985: Failed to find process 16985 I1029 04:34:36.290217 15491 master.cpp:615] Slave 201310290434-1015726915-34501-15179-0 (janus.apache.org) disconnected I1029 04:34:36.290344 15491 master.hpp:423] Removing offer 201310290434-1015726915-34501-15179-1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310290434-1015726915-34501-15179-0 (janus.apache.org) I1029 04:34:36.290429 15489 hierarchical_allocator_process.hpp:484] Slave 201310290434-1015726915-34501-15179-0 disconnected I1029 04:34:36.290477 15491 sched.cpp:483] Rescinded offer 201310290434-1015726915-34501-15179-1 I1029 04:34:36.290511 15491 sched.cpp:494] Scheduler::offerRescinded took 13233ns I1029 04:34:36.290606 15489 hierarchical_allocator_process.hpp:637] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 201310290434-1015726915-34501-15179-0 from framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:36.291677 15492 slave.cpp:109] Slave started on 95)@67.195.138.60:34501 I1029 04:34:36.291800 15492 slave.cpp:209] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1029 04:34:36.292729 15492 slave.cpp:481] New master detected at [email protected]:34501 I1029 04:34:36.292763 15492 slave.cpp:496] Postponing registration until recovery is complete I1029 04:34:36.292788 15492 status_update_manager.cpp:158] New master detected at [email protected]:34501 I1029 04:34:36.292789 15489 state.cpp:33] Recovering state from '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_6yy8Lq/meta' I1029 04:34:36.294476 15492 slave.cpp:2798] Recovering framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:36.294497 15492 slave.cpp:2979] Recovering executor 'acce0134-da31-4953-a32c-df058c9ece20' of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:36.294608 15492 slave.cpp:3173] Terminating task acce0134-da31-4953-a32c-df058c9ece20 I1029 04:34:36.294644 15492 slave.cpp:3196] Completing task acce0134-da31-4953-a32c-df058c9ece20 I1029 04:34:36.294883 15489 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_6yy8Lq/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/acce0134-da31-4953-a32c-df058c9ece20/runs/d198a374-c2be-4983-ad6e-67c02f1e9333' for gc 6.99999658877333days in the future I1029 04:34:36.295022 15489 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_6yy8Lq/meta/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/acce0134-da31-4953-a32c-df058c9ece20/runs/d198a374-c2be-4983-ad6e-67c02f1e9333' for gc 6.99999658796148days in the future I1029 04:34:36.295035 15492 slave.cpp:2328] Cleaning up framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:36.295124 15489 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_6yy8Lq/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/acce0134-da31-4953-a32c-df058c9ece20' for gc 6.99999658757037days in the future I1029 04:34:36.295136 15496 status_update_manager.cpp:267] Closing status update streams for framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:36.295239 15489 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_6yy8Lq/meta/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/acce0134-da31-4953-a32c-df058c9ece20' for gc 6.99999658686519days in the future I1029 04:34:36.295318 15489 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_6yy8Lq/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000' for gc 6.99999658465481days in the future I1029 04:34:36.295428 15489 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_6yy8Lq/meta/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000' for gc 6.99999658408593days in the future I1029 04:34:36.295699 15490 status_update_manager.cpp:180] Recovering status update manager I1029 04:34:36.295850 15490 status_update_manager.cpp:188] Recovering executor 'acce0134-da31-4953-a32c-df058c9ece20' of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:36.295892 15490 status_update_manager.cpp:213] Skipping recovering updates of executor 'acce0134-da31-4953-a32c-df058c9ece20' of framework 201310290434-1015726915-34501-15179-0000 because its latest run d198a374-c2be-4983-ad6e-67c02f1e9333 is completed I1029 04:34:36.296020 15492 slave.cpp:463] Successfully attached file '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_6yy8Lq/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/acce0134-da31-4953-a32c-df058c9ece20/runs/d198a374-c2be-4983-ad6e-67c02f1e9333' I1029 04:34:36.296097 15496 process_isolator.cpp:314] Recovering isolator I1029 04:34:36.296187 15496 process_isolator.cpp:322] Recovering executor 'acce0134-da31-4953-a32c-df058c9ece20' of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:36.296218 15496 process_isolator.cpp:345] Skipping recovery of executor 'acce0134-da31-4953-a32c-df058c9ece20' of framework 201310290434-1015726915-34501-15179-0000 because its latest run d198a374-c2be-4983-ad6e-67c02f1e9333 is completed I1029 04:34:36.296526 15493 slave.cpp:2736] Finished recovery W1029 04:34:36.296783 15489 master.cpp:1281] Slave at slave(95)@67.195.138.60:34501 (janus.apache.org) is being allowed to re-register with an already in use id (201310290434-1015726915-34501-15179-0) I1029 04:34:36.296861 15495 slave.cpp:594] Re-registered with master [email protected]:34501 I1029 04:34:36.296872 15491 hierarchical_allocator_process.hpp:498] Slave 201310290434-1015726915-34501-15179-0 reconnected I1029 04:34:37.279456 15495 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310290434-1015726915-34501-15179-0 to framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.279630 15495 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 242859ns I1029 04:34:37.279695 15496 master.hpp:413] Adding offer 201310290434-1015726915-34501-15179-2 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310290434-1015726915-34501-15179-0 (janus.apache.org) I1029 04:34:37.279754 15496 master.cpp:1668] Sending 1 offers to framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.279908 15495 sched.cpp:472] Scheduler::resourceOffers took 24077ns I1029 04:34:37.280086 15496 sched.cpp:630] Stopping framework '201310290434-1015726915-34501-15179-0000' I1029 04:34:37.280129 15179 master.cpp:557] Master terminating I1029 04:34:37.280166 15179 master.cpp:209] Shutting down master I1029 04:34:37.280200 15492 slave.cpp:1937] [email protected]:34501 exited I1029 04:34:37.280208 15179 master.hpp:423] Removing offer 201310290434-1015726915-34501-15179-2 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310290434-1015726915-34501-15179-0 (janus.apache.org) W1029 04:34:37.280226 15492 slave.cpp:1940] Master disconnected! Waiting for a new master to be elected I1029 04:34:37.280288 15179 master.cpp:252] Removing slave 201310290434-1015726915-34501-15179-0 (janus.apache.org) I1029 04:34:37.280555 15493 slave.cpp:388] Slave terminating [ OK ] SlaveRecoveryTest/0.RecoverCompletedExecutor (4007 ms) [ RUN ] SlaveRecoveryTest/0.CleanupExecutor I1029 04:34:37.282032 15496 master.cpp:284] Master started on 67.195.138.60:34501 I1029 04:34:37.282068 15496 master.cpp:299] Master ID: 201310290434-1015726915-34501-15179 I1029 04:34:37.282075 15496 master.cpp:302] Master only allowing authenticated frameworks to register! I1029 04:34:37.282377 15492 master.cpp:85] No whitelist given. Advertising offers for all slaves I1029 04:34:37.282385 15493 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : [email protected]:34501 I1029 04:34:37.282665 15496 master.cpp:697] Elected as master! I1029 04:34:37.282894 15496 slave.cpp:109] Slave started on 96)@67.195.138.60:34501 I1029 04:34:37.283005 15496 slave.cpp:209] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1029 04:34:37.283407 15489 sched.cpp:195] New master at [email protected]:34501 I1029 04:34:37.283429 15489 sched.cpp:281] Authenticating with master [email protected]:34501 I1029 04:34:37.283668 15491 authenticatee.hpp:124] Creating new client SASL connection I1029 04:34:37.283725 15493 state.cpp:33] Recovering state from '/tmp/SlaveRecoveryTest_0_CleanupExecutor_4uNwxr/meta' I1029 04:34:37.283799 15489 master.cpp:1702] Authenticating framework at scheduler(102)@67.195.138.60:34501 I1029 04:34:37.283833 15496 slave.cpp:481] New master detected at [email protected]:34501 I1029 04:34:37.283866 15496 slave.cpp:496] Postponing registration until recovery is complete I1029 04:34:37.283870 15493 status_update_manager.cpp:158] New master detected at [email protected]:34501 I1029 04:34:37.283994 15495 authenticator.hpp:140] Creating new server SASL connection I1029 04:34:37.284092 15495 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5 I1029 04:34:37.284112 15495 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5' I1029 04:34:37.284137 15495 authenticator.hpp:243] Received SASL authentication start I1029 04:34:37.284188 15495 authenticator.hpp:325] Authentication requires more steps I1029 04:34:37.284211 15495 authenticatee.hpp:258] Received SASL authentication step I1029 04:34:37.284247 15495 authenticator.hpp:271] Received SASL authentication step I1029 04:34:37.284268 15495 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'janus.apache.org' server FQDN: 'janus.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1029 04:34:37.284277 15495 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1029 04:34:37.284292 15495 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1029 04:34:37.284304 15495 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'janus.apache.org' server FQDN: 'janus.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1029 04:34:37.284312 15495 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1029 04:34:37.284317 15495 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1029 04:34:37.284330 15495 authenticator.hpp:317] Authentication success I1029 04:34:37.284370 15496 master.cpp:1742] Successfully authenticated framework at scheduler(102)@67.195.138.60:34501 I1029 04:34:37.284385 15491 status_update_manager.cpp:180] Recovering status update manager I1029 04:34:37.284474 15490 authenticatee.hpp:298] Authentication success I1029 04:34:37.284550 15494 process_isolator.cpp:314] Recovering isolator I1029 04:34:37.284811 15496 sched.cpp:326] Successfully authenticated with master [email protected]:34501 I1029 04:34:37.284827 15492 slave.cpp:2736] Finished recovery **** DEADLOCK DETECTED! **** You are waiting on process authenticatee(113)@67.195.138.60:34501 that it is currently executing. I1029 04:34:37.284875 15494 master.cpp:755] Received registration request from scheduler(102)@67.195.138.60:34501 I1029 04:34:37.285012 15494 master.cpp:773] Registering framework 201310290434-1015726915-34501-15179-0000 at scheduler(102)@67.195.138.60:34501 I1029 04:34:37.285083 15496 sched.cpp:365] Framework registered with 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.285092 15492 hierarchical_allocator_process.hpp:332] Added framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.285096 15494 master.cpp:1223] Attempting to register slave on janus.apache.org at slave(96)@67.195.138.60:34501 I1029 04:34:37.285105 15492 hierarchical_allocator_process.hpp:726] No resources available to allocate! I1029 04:34:37.285110 15496 sched.cpp:379] Scheduler::registered took 12545ns I1029 04:34:37.285114 15492 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 7973ns I1029 04:34:37.285109 15494 master.cpp:2481] Adding slave 201310290434-1015726915-34501-15179-0 at janus.apache.org with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1029 04:34:37.285189 15489 slave.cpp:547] Registered with master [email protected]:34501; given slave ID 201310290434-1015726915-34501-15179-0 I1029 04:34:37.285282 15496 hierarchical_allocator_process.hpp:445] Added slave 201310290434-1015726915-34501-15179-0 (janus.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) I1029 04:34:37.285343 15489 slave.cpp:560] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_4uNwxr/meta/slaves/201310290434-1015726915-34501-15179-0/slave.info' I1029 04:34:37.285344 15496 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310290434-1015726915-34501-15179-0 to framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.285477 15496 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201310290434-1015726915-34501-15179-0 in 158125ns I1029 04:34:37.285527 15489 master.hpp:413] Adding offer 201310290434-1015726915-34501-15179-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310290434-1015726915-34501-15179-0 (janus.apache.org) I1029 04:34:37.285580 15489 master.cpp:1668] Sending 1 offers to framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.285694 15493 sched.cpp:472] Scheduler::resourceOffers took 25865ns I1029 04:34:37.287274 15493 master.cpp:1994] Processing reply for offer 201310290434-1015726915-34501-15179-0 on slave 201310290434-1015726915-34501-15179-0 (janus.apache.org) for framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.287416 15493 master.hpp:385] Adding task 8af83bcf-e8fa-485c-958a-8691963a7ed4 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310290434-1015726915-34501-15179-0 (janus.apache.org) I1029 04:34:37.287475 15493 master.cpp:2118] Launching task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310290434-1015726915-34501-15179-0 (janus.apache.org) I1029 04:34:37.287570 15492 slave.cpp:720] Got assigned task 8af83bcf-e8fa-485c-958a-8691963a7ed4 for framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.287612 15493 master.hpp:423] Removing offer 201310290434-1015726915-34501-15179-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310290434-1015726915-34501-15179-0 (janus.apache.org) I1029 04:34:37.287669 15492 slave.cpp:2864] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_4uNwxr/meta/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/framework.info' I1029 04:34:37.287804 15492 slave.cpp:2871] Checkpointing framework pid 'scheduler(102)@67.195.138.60:34501' to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_4uNwxr/meta/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/framework.pid' I1029 04:34:37.288033 15492 slave.cpp:831] Launching task 8af83bcf-e8fa-485c-958a-8691963a7ed4 for framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.289496 15492 slave.cpp:3128] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_4uNwxr/meta/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/8af83bcf-e8fa-485c-958a-8691963a7ed4/executor.info' I1029 04:34:37.289847 15492 slave.cpp:3217] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_4uNwxr/meta/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/8af83bcf-e8fa-485c-958a-8691963a7ed4/runs/f8b91e0f-076e-4192-97f3-efd6d0835a6f/tasks/8af83bcf-e8fa-485c-958a-8691963a7ed4/task.info' I1029 04:34:37.289896 15491 process_isolator.cpp:100] Launching 8af83bcf-e8fa-485c-958a-8691963a7ed4 (<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src/mesos-executor)> in /tmp/SlaveRecoveryTest_0_CleanupExecutor_4uNwxr/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/8af83bcf-e8fa-485c-958a-8691963a7ed4/runs/f8b91e0f-076e-4192-97f3-efd6d0835a6f with resources ' for framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.290007 15492 slave.cpp:941] Queuing task '8af83bcf-e8fa-485c-958a-8691963a7ed4' for executor 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework '201310290434-1015726915-34501-15179-0000 I1029 04:34:37.290053 15492 slave.cpp:463] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_4uNwxr/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/8af83bcf-e8fa-485c-958a-8691963a7ed4/runs/f8b91e0f-076e-4192-97f3-efd6d0835a6f' I1029 04:34:37.292917 15491 process_isolator.cpp:163] Forked executor at 18153 I1029 04:34:37.293428 15491 slave.cpp:2066] Monitoring executor 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 forked at pid 18153 Checkpointing executor's forked pid 18153 to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_4uNwxr/meta/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/8af83bcf-e8fa-485c-958a-8691963a7ed4/runs/f8b91e0f-076e-4192-97f3-efd6d0835a6f/pids/forked.pid' Fetching resources into '/tmp/SlaveRecoveryTest_0_CleanupExecutor_4uNwxr/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/8af83bcf-e8fa-485c-958a-8691963a7ed4/runs/f8b91e0f-076e-4192-97f3-efd6d0835a6f' WARNING: Logging before InitGoogleLogging() is written to STDERR I1029 04:34:37.353030 18171 process.cpp:1555] libprocess is initialized on 67.195.138.60:44340 for 8 cpus I1029 04:34:37.355249 18192 exec.cpp:174] Executor started at: executor(1)@67.195.138.60:44340 with pid 18171 I1029 04:34:37.355718 15491 slave.cpp:1403] Got registration for executor '8af83bcf-e8fa-485c-958a-8691963a7ed4' of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.355774 15491 slave.cpp:1488] Checkpointing executor pid 'executor(1)@67.195.138.60:44340' to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_4uNwxr/meta/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/8af83bcf-e8fa-485c-958a-8691963a7ed4/runs/f8b91e0f-076e-4192-97f3-efd6d0835a6f/pids/libprocess.pid' I1029 04:34:37.356240 15491 slave.cpp:1524] Flushing queued task 8af83bcf-e8fa-485c-958a-8691963a7ed4 for executor '8af83bcf-e8fa-485c-958a-8691963a7ed4' of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.356504 18185 exec.cpp:198] Executor registered on slave 201310290434-1015726915-34501-15179-0 I1029 04:34:37.357520 18193 process.cpp:986] Socket closed while receiving Registered executor on janus.apache.org I1029 04:34:37.357643 18185 exec.cpp:210] Executor::registered took 116448ns I1029 04:34:37.357772 18193 process.cpp:986] Socket closed while receiving I1029 04:34:37.357839 18189 exec.cpp:285] Executor asked to run task '8af83bcf-e8fa-485c-958a-8691963a7ed4' Starting task 8af83bcf-e8fa-485c-958a-8691963a7ed4 I1029 04:34:37.357905 18189 exec.cpp:294] Executor::launchTask took 43114ns sh -c 'sleep 1000' Forked command at 18194 I1029 04:34:37.359791 18186 exec.cpp:505] Executor sending status update TASK_RUNNING (UUID: 37dce63e-4300-43df-9985-aedddb6d75c6) for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.360224 15489 slave.cpp:1737] Handling status update TASK_RUNNING (UUID: 37dce63e-4300-43df-9985-aedddb6d75c6) for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 from executor(1)@67.195.138.60:44340 I1029 04:34:37.360462 15494 status_update_manager.cpp:305] Received status update TASK_RUNNING (UUID: 37dce63e-4300-43df-9985-aedddb6d75c6) for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.360488 15494 status_update_manager.cpp:476] Creating StatusUpdate stream for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.360710 15494 status_update_manager.hpp:337] Checkpointing UPDATE for status update TASK_RUNNING (UUID: 37dce63e-4300-43df-9985-aedddb6d75c6) for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.572690 15494 status_update_manager.cpp:356] Forwarding status update TASK_RUNNING (UUID: 37dce63e-4300-43df-9985-aedddb6d75c6) for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 to [email protected]:34501 I1029 04:34:37.573014 15493 master.cpp:1425] Status update TASK_RUNNING (UUID: 37dce63e-4300-43df-9985-aedddb6d75c6) for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 from slave(96)@67.195.138.60:34501 I1029 04:34:37.573024 15495 slave.cpp:1856] Status update manager successfully handled status update TASK_RUNNING (UUID: 37dce63e-4300-43df-9985-aedddb6d75c6) for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.573076 15495 slave.cpp:1862] Sending acknowledgement for status update TASK_RUNNING (UUID: 37dce63e-4300-43df-9985-aedddb6d75c6) for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 to executor(1)@67.195.138.60:44340 I1029 04:34:37.573144 15496 sched.cpp:527] Scheduler::statusUpdate took 19154ns I1029 04:34:37.573372 15495 status_update_manager.cpp:380] Received status update acknowledgement (UUID: 37dce63e-4300-43df-9985-aedddb6d75c6) for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.573423 18189 exec.cpp:331] Executor received status update acknowledgement 37dce63e-4300-43df-9985-aedddb6d75c6 for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.573436 15495 status_update_manager.hpp:337] Checkpointing ACK for status update TASK_RUNNING (UUID: 37dce63e-4300-43df-9985-aedddb6d75c6) for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.573421 18193 process.cpp:986] Socket closed while receiving I1029 04:34:37.648041 15496 slave.cpp:1343] Status update manager successfully handled status update acknowledgement (UUID: 37dce63e-4300-43df-9985-aedddb6d75c6) for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.648247 15489 slave.cpp:388] Slave terminating I1029 04:34:37.648334 15489 master.cpp:615] Slave 201310290434-1015726915-34501-15179-0 (janus.apache.org) disconnected I1029 04:34:37.648412 15496 hierarchical_allocator_process.hpp:484] Slave 201310290434-1015726915-34501-15179-0 disconnected I1029 04:34:37.649474 15496 slave.cpp:109] Slave started on 97)@67.195.138.60:34501 I1029 04:34:37.649595 15496 slave.cpp:209] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1029 04:34:37.649775 15493 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 27215ns I1029 04:34:37.650348 15492 state.cpp:33] Recovering state from '/tmp/SlaveRecoveryTest_0_CleanupExecutor_4uNwxr/meta' I1029 04:34:37.650465 15496 slave.cpp:481] New master detected at [email protected]:34501 I1029 04:34:37.650496 15496 slave.cpp:490] Skipping registration because slave is in 'cleanup' mode I1029 04:34:37.650521 15489 status_update_manager.cpp:158] New master detected at [email protected]:34501 I1029 04:34:37.651867 15496 slave.cpp:2798] Recovering framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.651887 15496 slave.cpp:2979] Recovering executor '8af83bcf-e8fa-485c-958a-8691963a7ed4' of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.652328 15495 status_update_manager.cpp:180] Recovering status update manager I1029 04:34:37.652511 15495 status_update_manager.cpp:188] Recovering executor '8af83bcf-e8fa-485c-958a-8691963a7ed4' of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.652578 15495 status_update_manager.cpp:476] Creating StatusUpdate stream for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.652591 15496 slave.cpp:463] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_4uNwxr/slaves/201310290434-1015726915-34501-15179-0/frameworks/201310290434-1015726915-34501-15179-0000/executors/8af83bcf-e8fa-485c-958a-8691963a7ed4/runs/f8b91e0f-076e-4192-97f3-efd6d0835a6f' I1029 04:34:37.652727 15495 status_update_manager.hpp:301] Replaying status update stream for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 I1029 04:34:37.653077 15496 process_isolator.cpp:314] Recovering isolator I1029 04:34:37.653225 15496 process_isolator.cpp:322] Recovering executor '8af83bcf-e8fa-485c-958a-8691963a7ed4' of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.653676 15495 slave.cpp:2691] Sending shutdown to executor '8af83bcf-e8fa-485c-958a-8691963a7ed4' of framework 201310290434-1015726915-34501-15179-0000 to executor(1)@67.195.138.60:44340 I1029 04:34:37.653699 15495 slave.cpp:2399] Shutting down executor '8af83bcf-e8fa-485c-958a-8691963a7ed4' of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:37.653990 18193 process.cpp:986] Socket closed while receiving I1029 04:34:37.654047 18190 exec.cpp:371] Executor asked to shutdown I1029 04:34:37.654114 18190 exec.cpp:386] Executor::shutdown took 15212ns Shutting down Killing process tree at pid 18194 I1029 04:34:37.654134 18191 exec.cpp:76] Scheduling shutdown of the executor I1029 04:34:37.654183 15495 slave.cpp:2736] Finished recovery Killed the following process trees: [ -+- 18194 sh -c sleep 1000 \--- 18195 sleep 1000 ] Command terminated with signal Killed (pid: 18194) I1029 04:34:38.355167 18188 exec.cpp:505] Executor sending status update TASK_KILLED (UUID: 2db8aaa8-2e81-42e6-a91d-6a71672de78d) for task 8af83bcf-e8fa-485c-958a-8691963a7ed4 of framework 201310290434-1015726915-34501-15179-0000 I1029 04:34:39.356071 15497 process.cpp:986] Socket closed while receiving Build timed out (after 120 minutes). Marking the build as failed. make: *** wait: No child processes. Stop. make: *** Waiting for unfinished jobs.... make: *** wait: No child processes. Stop.
