You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/10/26 00:34:20 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME #1461
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/1461/changes>
Changes:
[vinod] Fixed regression in properly gc'ing completed executors.
------------------------------------------
[...truncated 15881 lines...]
I1025 21:10:14.890548 30228 slave.cpp:1862] Sending acknowledgement for status update TASK_RUNNING (UUID: b763b0b9-3897-4db3-96fb-85f1eac11f47) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000 to executor(1)@67.195.138.61:41473
I1025 21:10:14.890708 30225 sched.cpp:527] Scheduler::statusUpdate took 17928ns
I1025 21:10:14.890732 30229 master.cpp:1425] Status update TASK_RUNNING (UUID: b763b0b9-3897-4db3-96fb-85f1eac11f47) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000 from slave(94)@67.195.138.61:41545
I1025 21:10:14.890842 2556 process.cpp:986] Socket closed while receiving
II1025 21:10:14.890902 2550 exec.cpp:331] Executor received status update acknowledgement b763b0b9-3897-4db3-96fb-85f1eac11f47 for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000
1025 21:10:14.890888 30225 status_update_manager.cpp:380] Received status update acknowledgement (UUID: b763b0b9-3897-4db3-96fb-85f1eac11f47) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:14.891047 30225 status_update_manager.hpp:337] Checkpointing ACK for status update TASK_RUNNING (UUID: b763b0b9-3897-4db3-96fb-85f1eac11f47) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:14.940520 30228 slave.cpp:1343] Status update manager successfully handled status update acknowledgement (UUID: b763b0b9-3897-4db3-96fb-85f1eac11f47) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:15.053516 30233 process.cpp:986] Socket closed while receiving
I1025 21:10:15.481385 30233 process.cpp:986] Socket closed while receiving
I1025 21:10:15.704061 30227 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 45055ns
I1025 21:10:15.730725 30226 monitor.cpp:187] Publishing resource usage for executor 'c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f' of framework '201310252110-1032504131-41545-30098-0000'
I1025 21:10:15.732558 30233 process.cpp:986] Socket closed while receiving
Command exited with status 0 (pid: 2557)
I1025 21:10:15.780931 2555 exec.cpp:505] Executor sending status update TASK_FINISHED (UUID: 734c9f7b-a17b-457a-8b8e-f8c98642a14a) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:15.781286 30226 slave.cpp:1737] Handling status update TASK_FINISHED (UUID: 734c9f7b-a17b-457a-8b8e-f8c98642a14a) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000 from executor(1)@67.195.138.61:41473
I1025 21:10:15.781338 30226 slave.cpp:3170] Terminating task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f
I1025 21:10:15.781555 30230 status_update_manager.cpp:305] Received status update TASK_FINISHED (UUID: 734c9f7b-a17b-457a-8b8e-f8c98642a14a) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:15.781580 30230 status_update_manager.hpp:337] Checkpointing UPDATE for status update TASK_FINISHED (UUID: 734c9f7b-a17b-457a-8b8e-f8c98642a14a) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:15.840138 30230 status_update_manager.cpp:356] Forwarding status update TASK_FINISHED (UUID: 734c9f7b-a17b-457a-8b8e-f8c98642a14a) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000 to master@67.195.138.61:41545
I1025 21:10:15.840368 30225 slave.cpp:1856] Status update manager successfully handled status update TASK_FINISHED (UUID: 734c9f7b-a17b-457a-8b8e-f8c98642a14a) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:15.840401 30225 slave.cpp:1862] Sending acknowledgement for status update TASK_FINISHED (UUID: 734c9f7b-a17b-457a-8b8e-f8c98642a14a) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000 to executor(1)@67.195.138.61:41473
I1025 21:10:15.840417 30226 master.cpp:1425] Status update TASK_FINISHED (UUID: 734c9f7b-a17b-457a-8b8e-f8c98642a14a) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000 from slave(94)@67.195.138.61:41545
I1025 21:10:15.840478 30228 sched.cpp:527] Scheduler::statusUpdate took 13781ns
I1025 21:10:15.840512 30226 master.hpp:403] Removing task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310252110-1032504131-41545-30098-0 (juno.apache.org)
I1025 21:10:15.840672 2556 process.cpp:986] Socket closed while receiving
I1025 21:10:15.840700 2548 exec.cpp:331] Executor received status update acknowledgement 734c9f7b-a17b-457a-8b8e-f8c98642a14a for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:15.840809 30225 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 201310252110-1032504131-41545-30098-0 from framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:15.840873 30230 status_update_manager.cpp:380] Received status update acknowledgement (UUID: 734c9f7b-a17b-457a-8b8e-f8c98642a14a) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:15.840899 30230 status_update_manager.hpp:337] Checkpointing ACK for status update TASK_FINISHED (UUID: 734c9f7b-a17b-457a-8b8e-f8c98642a14a) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:15.882971 30230 status_update_manager.cpp:507] Cleaning up status update stream for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:15.883194 30231 slave.cpp:1343] Status update manager successfully handled status update acknowledgement (UUID: 734c9f7b-a17b-457a-8b8e-f8c98642a14a) for task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:15.883219 30231 slave.cpp:3193] Completing task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f
I1025 21:10:16.704608 30225 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310252110-1032504131-41545-30098-0 to framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:16.704753 30225 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 188018ns
I1025 21:10:16.704934 30231 master.hpp:413] Adding offer 201310252110-1032504131-41545-30098-1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310252110-1032504131-41545-30098-0 (juno.apache.org)
I1025 21:10:16.705027 30231 master.cpp:1668] Sending 1 offers to framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:16.705200 30230 sched.cpp:472] Scheduler::resourceOffers took 14072ns
I1025 21:10:16.742607 30228 monitor.cpp:187] Publishing resource usage for executor 'c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f' of framework '201310252110-1032504131-41545-30098-0000'
I1025 21:10:16.781702 30233 process.cpp:986] Socket closed while receiving
I1025 21:10:17.705904 30229 process_isolator.cpp:479] Telling slave of terminated executor 'c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f' of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:17.705940 30226 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 49728ns
I1025 21:10:17.706089 30231 slave.cpp:2119] Executor 'c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f' of framework 201310252110-1032504131-41545-30098-0000 has exited with status 0
I1025 21:10:17.706153 30231 slave.cpp:2254] Cleaning up executor 'c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f' of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:17.706408 30225 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_KlWdr7/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f/runs/ca8f9360-43b8-4e22-9086-0102f17f70fa' for gc 6.99999182572741days in the future
I1025 21:10:17.706529 30225 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_KlWdr7/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f' for gc 6.99999182502519days in the future
I1025 21:10:17.706576 30225 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_KlWdr7/meta/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f/runs/ca8f9360-43b8-4e22-9086-0102f17f70fa' for gc 6.9999918245837days in the future
I1025 21:10:17.706676 30231 slave.cpp:2325] Cleaning up framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:17.706696 30225 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_KlWdr7/meta/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f' for gc 6.99999182397037days in the future
I1025 21:10:17.706729 30226 status_update_manager.cpp:267] Closing status update streams for framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:17.706761 30226 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_KlWdr7/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000' for gc 6.99999182034667days in the future
I1025 21:10:17.706792 30231 slave.cpp:388] Slave terminating
I1025 21:10:17.706888 30226 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_KlWdr7/meta/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000' for gc 6.99999181992889days in the future
W1025 21:10:17.718610 30229 process_isolator.cpp:265] Failed to kill the process tree rooted at pid 2516: Failed to find process 2516
I1025 21:10:17.718739 30231 master.cpp:615] Slave 201310252110-1032504131-41545-30098-0 (juno.apache.org) disconnected
I1025 21:10:17.718811 30225 hierarchical_allocator_process.hpp:484] Slave 201310252110-1032504131-41545-30098-0 disconnected
I1025 21:10:17.718834 30231 master.hpp:423] Removing offer 201310252110-1032504131-41545-30098-1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310252110-1032504131-41545-30098-0 (juno.apache.org)
I1025 21:10:17.718897 30225 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 201310252110-1032504131-41545-30098-0 from framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:17.718937 30226 sched.cpp:483] Rescinded offer 201310252110-1032504131-41545-30098-1
I1025 21:10:17.718986 30226 sched.cpp:494] Scheduler::offerRescinded took 9399ns
I1025 21:10:17.720441 30227 slave.cpp:109] Slave started on 95)@67.195.138.61:41545
I1025 21:10:17.720546 30227 slave.cpp:209] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1025 21:10:17.721143 30227 slave.cpp:481] New master detected at master@67.195.138.61:41545
I1025 21:10:17.721168 30227 slave.cpp:496] Postponing registration until recovery is complete
I1025 21:10:17.721181 30231 status_update_manager.cpp:158] New master detected at master@67.195.138.61:41545
I1025 21:10:17.721207 30230 state.cpp:33] Recovering state from '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_KlWdr7/meta'
I1025 21:10:17.722537 30225 slave.cpp:2795] Recovering framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:17.722555 30225 slave.cpp:2976] Recovering executor 'c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f' of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:17.722646 30225 slave.cpp:3170] Terminating task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f
I1025 21:10:17.722674 30225 slave.cpp:3193] Completing task c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f
I1025 21:10:17.722901 30225 slave.cpp:2325] Cleaning up framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:17.722904 30229 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_KlWdr7/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f/runs/ca8f9360-43b8-4e22-9086-0102f17f70fa' for gc 6.99999163488593days in the future
I1025 21:10:17.722959 30229 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_KlWdr7/meta/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f/runs/ca8f9360-43b8-4e22-9086-0102f17f70fa' for gc 6.99999163413333days in the future
I1025 21:10:17.723007 30229 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_KlWdr7/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f' for gc 6.99999163380741days in the future
I1025 21:10:17.723049 30229 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_KlWdr7/meta/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f' for gc 6.99999163342518days in the future
I1025 21:10:17.723088 30229 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_KlWdr7/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000' for gc 6.99999163275556days in the future
I1025 21:10:17.723126 30229 gc.cpp:56] Scheduling '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_KlWdr7/meta/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000' for gc 6.99999163239704days in the future
I1025 21:10:17.723186 30229 status_update_manager.cpp:267] Closing status update streams for framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:17.723227 30229 status_update_manager.cpp:180] Recovering status update manager
I1025 21:10:17.723335 30229 status_update_manager.cpp:188] Recovering executor 'c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f' of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:17.723371 30229 status_update_manager.cpp:213] Skipping recovering updates of executor 'c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f' of framework 201310252110-1032504131-41545-30098-0000 because its latest run ca8f9360-43b8-4e22-9086-0102f17f70fa is completed
I1025 21:10:17.723443 30225 slave.cpp:463] Successfully attached file '/tmp/SlaveRecoveryTest_0_RecoverCompletedExecutor_KlWdr7/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f/runs/ca8f9360-43b8-4e22-9086-0102f17f70fa'
I1025 21:10:17.723541 30225 process_isolator.cpp:314] Recovering isolator
I1025 21:10:17.723625 30225 process_isolator.cpp:322] Recovering executor 'c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f' of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:17.723659 30225 process_isolator.cpp:345] Skipping recovery of executor 'c3cf3d1e-b396-4ba1-807b-7b1a414a9c4f' of framework 201310252110-1032504131-41545-30098-0000 because its latest run ca8f9360-43b8-4e22-9086-0102f17f70fa is completed
I1025 21:10:17.723960 30226 slave.cpp:2733] Finished recovery
W1025 21:10:17.724231 30230 master.cpp:1281] Slave at slave(95)@67.195.138.61:41545 (juno.apache.org) is being allowed to re-register with an already in use id (201310252110-1032504131-41545-30098-0)
I1025 21:10:17.724285 30226 slave.cpp:594] Re-registered with master master@67.195.138.61:41545
I1025 21:10:17.724314 30228 hierarchical_allocator_process.hpp:498] Slave 201310252110-1032504131-41545-30098-0 reconnected
I1025 21:10:18.707092 30225 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310252110-1032504131-41545-30098-0 to framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.707273 30225 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 271781ns
I1025 21:10:18.707413 30226 master.hpp:413] Adding offer 201310252110-1032504131-41545-30098-2 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310252110-1032504131-41545-30098-0 (juno.apache.org)
I1025 21:10:18.707505 30226 master.cpp:1668] Sending 1 offers to framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.707700 30227 sched.cpp:472] Scheduler::resourceOffers took 28619ns
I1025 21:10:18.707943 30098 master.cpp:557] Master terminating
I1025 21:10:18.707957 30231 sched.cpp:630] Stopping framework '201310252110-1032504131-41545-30098-0000'
I1025 21:10:18.707991 30098 master.cpp:209] Shutting down master
I1025 21:10:18.708047 30098 master.hpp:423] Removing offer 201310252110-1032504131-41545-30098-2 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310252110-1032504131-41545-30098-0 (juno.apache.org)
I1025 21:10:18.708077 30231 slave.cpp:1937] master@67.195.138.61:41545 exited
W1025 21:10:18.708091 30231 slave.cpp:1940] Master disconnected! Waiting for a new master to be elected
I1025 21:10:18.708132 30098 master.cpp:252] Removing slave 201310252110-1032504131-41545-30098-0 (juno.apache.org)
I1025 21:10:18.708503 30098 slave.cpp:388] Slave terminating
[ OK ] SlaveRecoveryTest/0.RecoverCompletedExecutor (4007 ms)
[ RUN ] SlaveRecoveryTest/0.CleanupExecutor
I1025 21:10:18.709867 30227 master.cpp:284] Master started on 67.195.138.61:41545
I1025 21:10:18.709907 30227 master.cpp:299] Master ID: 201310252110-1032504131-41545-30098
I1025 21:10:18.709915 30227 master.cpp:302] Master only allowing authenticated frameworks to register!
I1025 21:10:18.710162 30228 master.cpp:85] No whitelist given. Advertising offers for all slaves
I1025 21:10:18.710217 30231 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : master@67.195.138.61:41545
I1025 21:10:18.710489 30227 master.cpp:697] Elected as master!
I1025 21:10:18.754046 30231 slave.cpp:109] Slave started on 96)@67.195.138.61:41545
I1025 21:10:18.754137 30231 slave.cpp:209] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1025 21:10:18.754459 30225 sched.cpp:195] New master at master@67.195.138.61:41545
I1025 21:10:18.754482 30225 sched.cpp:281] Authenticating with master master@67.195.138.61:41545
I1025 21:10:18.754622 30227 authenticatee.hpp:124] Creating new client SASL connection
I1025 21:10:18.754757 30227 state.cpp:33] Recovering state from '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Jp3veo/meta'
I1025 21:10:18.754776 30225 master.cpp:1702] Authenticating framework at scheduler(102)@67.195.138.61:41545
I1025 21:10:18.754837 30231 slave.cpp:481] New master detected at master@67.195.138.61:41545
I1025 21:10:18.754904 30231 slave.cpp:496] Postponing registration until recovery is complete
I1025 21:10:18.754914 30227 status_update_manager.cpp:158] New master detected at master@67.195.138.61:41545
I1025 21:10:18.754948 30228 authenticator.hpp:140] Creating new server SASL connection
I1025 21:10:18.755009 30227 status_update_manager.cpp:180] Recovering status update manager
I1025 21:10:18.755091 30228 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5
I1025 21:10:18.755149 30230 process_isolator.cpp:314] Recovering isolator
I1025 21:10:18.755185 30228 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I1025 21:10:18.755245 30227 authenticator.hpp:243] Received SASL authentication start
I1025 21:10:18.755326 30227 authenticator.hpp:325] Authentication requires more steps
I1025 21:10:18.755406 30228 authenticatee.hpp:258] Received SASL authentication step
I1025 21:10:18.755436 30231 slave.cpp:2733] Finished recovery
I1025 21:10:18.755447 30228 authenticator.hpp:271] Received SASL authentication step
I1025 21:10:18.755467 30228 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1025 21:10:18.755475 30228 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I1025 21:10:18.755491 30228 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1025 21:10:18.755503 30228 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'juno.apache.org' server FQDN: 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1025 21:10:18.755511 30228 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1025 21:10:18.755517 30228 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1025 21:10:18.755528 30228 authenticator.hpp:317] Authentication success
I1025 21:10:18.755527 30231 master.cpp:1223] Attempting to register slave on juno.apache.org at slave(96)@67.195.138.61:41545
I1025 21:10:18.755560 30231 master.cpp:2481] Adding slave 201310252110-1032504131-41545-30098-0 at juno.apache.org with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1025 21:10:18.755575 30228 authenticatee.hpp:298] Authentication success
I1025 21:10:18.755648 30228 sched.cpp:326] Successfully authenticated with master master@67.195.138.61:41545
I1025 21:10:18.755692 30231 master.cpp:1742] Successfully authenticated framework at scheduler(102)@67.195.138.61:41545
I1025 21:10:18.755702 30226 slave.cpp:547] Registered with master master@67.195.138.61:41545; given slave ID 201310252110-1032504131-41545-30098-0
I1025 21:10:18.755751 30229 hierarchical_allocator_process.hpp:445] Added slave 201310252110-1032504131-41545-30098-0 (juno.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
I1025 21:10:18.755805 30229 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201310252110-1032504131-41545-30098-0 in 7143ns
I1025 21:10:18.755913 30231 master.cpp:755] Received registration request from scheduler(102)@67.195.138.61:41545
I1025 21:10:18.755947 30226 slave.cpp:560] Checkpointing SlaveInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Jp3veo/meta/slaves/201310252110-1032504131-41545-30098-0/slave.info'
I1025 21:10:18.756001 30231 master.cpp:773] Registering framework 201310252110-1032504131-41545-30098-0000 at scheduler(102)@67.195.138.61:41545
I1025 21:10:18.756052 30231 sched.cpp:365] Framework registered with 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.756062 30230 hierarchical_allocator_process.hpp:332] Added framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.756072 30231 sched.cpp:379] Scheduler::registered took 8487ns
I1025 21:10:18.756095 30230 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310252110-1032504131-41545-30098-0 to framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.756198 30230 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 124339ns
I1025 21:10:18.756252 30226 master.hpp:413] Adding offer 201310252110-1032504131-41545-30098-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310252110-1032504131-41545-30098-0 (juno.apache.org)
I1025 21:10:18.756309 30226 master.cpp:1668] Sending 1 offers to framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.756438 30225 sched.cpp:472] Scheduler::resourceOffers took 23249ns
I1025 21:10:18.757865 30231 master.cpp:1994] Processing reply for offer 201310252110-1032504131-41545-30098-0 on slave 201310252110-1032504131-41545-30098-0 (juno.apache.org) for framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.757966 30231 master.hpp:385] Adding task 719ac759-24d5-484e-87f2-9eb081376f4a with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310252110-1032504131-41545-30098-0 (juno.apache.org)
I1025 21:10:18.758010 30231 master.cpp:2118] Launching task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310252110-1032504131-41545-30098-0 (juno.apache.org)
I1025 21:10:18.758096 30226 slave.cpp:720] Got assigned task 719ac759-24d5-484e-87f2-9eb081376f4a for framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.758117 30231 master.hpp:423] Removing offer 201310252110-1032504131-41545-30098-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 201310252110-1032504131-41545-30098-0 (juno.apache.org)
I1025 21:10:18.758211 30226 slave.cpp:2861] Checkpointing FrameworkInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Jp3veo/meta/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/framework.info'
I1025 21:10:18.758342 30226 slave.cpp:2868] Checkpointing framework pid 'scheduler(102)@67.195.138.61:41545' to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Jp3veo/meta/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/framework.pid'
I1025 21:10:18.758581 30226 slave.cpp:831] Launching task 719ac759-24d5-484e-87f2-9eb081376f4a for framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.760103 30226 slave.cpp:3125] Checkpointing ExecutorInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Jp3veo/meta/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/719ac759-24d5-484e-87f2-9eb081376f4a/executor.info'
I1025 21:10:18.760475 30226 slave.cpp:3214] Checkpointing TaskInfo to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Jp3veo/meta/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/719ac759-24d5-484e-87f2-9eb081376f4a/runs/8012f3b7-c925-42e3-bef6-c38277238c61/tasks/719ac759-24d5-484e-87f2-9eb081376f4a/task.info'
I1025 21:10:18.760478 30230 process_isolator.cpp:100] Launching 719ac759-24d5-484e-87f2-9eb081376f4a (<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src/mesos-executor)> in /tmp/SlaveRecoveryTest_0_CleanupExecutor_Jp3veo/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/719ac759-24d5-484e-87f2-9eb081376f4a/runs/8012f3b7-c925-42e3-bef6-c38277238c61 with resources ' for framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.762639 30226 slave.cpp:941] Queuing task '719ac759-24d5-484e-87f2-9eb081376f4a' for executor 719ac759-24d5-484e-87f2-9eb081376f4a of framework '201310252110-1032504131-41545-30098-0000
I1025 21:10:18.762862 30226 slave.cpp:463] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Jp3veo/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/719ac759-24d5-484e-87f2-9eb081376f4a/runs/8012f3b7-c925-42e3-bef6-c38277238c61'
I1025 21:10:18.763118 30230 process_isolator.cpp:163] Forked executor at 2623
Checkpointing executor's forked pid 2623 to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Jp3veo/meta/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/719ac759-24d5-484e-87f2-9eb081376f4a/runs/8012f3b7-c925-42e3-bef6-c38277238c61/pids/forked.pid'
Fetching resources into '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Jp3veo/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/719ac759-24d5-484e-87f2-9eb081376f4a/runs/8012f3b7-c925-42e3-bef6-c38277238c61'
WARNING: Logging before InitGoogleLogging() is written to STDERR
I1025 21:10:18.823992 2641 process.cpp:1555] libprocess is initialized on 67.195.138.61:35737 for 8 cpus
I1025 21:10:18.826452 2656 exec.cpp:174] Executor started at: executor(1)@67.195.138.61:35737 with pid 2641
I1025 21:10:18.826946 30226 slave.cpp:1403] Got registration for executor '719ac759-24d5-484e-87f2-9eb081376f4a' of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.826995 30226 slave.cpp:1488] Checkpointing executor pid 'executor(1)@67.195.138.61:35737' to '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Jp3veo/meta/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/719ac759-24d5-484e-87f2-9eb081376f4a/runs/8012f3b7-c925-42e3-bef6-c38277238c61/pids/libprocess.pid'
I1025 21:10:18.827430 30226 slave.cpp:1524] Flushing queued task 719ac759-24d5-484e-87f2-9eb081376f4a for executor '719ac759-24d5-484e-87f2-9eb081376f4a' of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.827725 2661 exec.cpp:198] Executor registered on slave 201310252110-1032504131-41545-30098-0
I1025 21:10:18.827725 2663 process.cpp:986] Socket closed while receiving
I1025 21:10:18.828783 2661 exec.cpp:210] Executor::registered took 98279ns
Registered executor on juno.apache.org
I1025 21:10:18.828949 2661 exec.cpp:285] Executor asked to run task '719ac759-24d5-484e-87f2-9eb081376f4a'
Starting task 719ac759-24d5-484e-87f2-9eb081376f4a
I1025 21:10:18.829013 2661 exec.cpp:294] Executor::launchTask took 47260ns
Forked command at 2664
sh -c 'sleep 1000'
I1025 21:10:18.830796 2658 exec.cpp:505] Executor sending status update TASK_RUNNING (UUID: ca1ab971-026f-473c-843f-6152e6068ca5) for task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.831136 30231 slave.cpp:1737] Handling status update TASK_RUNNING (UUID: ca1ab971-026f-473c-843f-6152e6068ca5) for task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000 from executor(1)@67.195.138.61:35737
I1025 21:10:18.831346 30225 status_update_manager.cpp:305] Received status update TASK_RUNNING (UUID: ca1ab971-026f-473c-843f-6152e6068ca5) for task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.831365 30225 status_update_manager.cpp:476] Creating StatusUpdate stream for task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.831548 30225 status_update_manager.hpp:337] Checkpointing UPDATE for status update TASK_RUNNING (UUID: ca1ab971-026f-473c-843f-6152e6068ca5) for task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.968857 30225 status_update_manager.cpp:356] Forwarding status update TASK_RUNNING (UUID: ca1ab971-026f-473c-843f-6152e6068ca5) for task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000 to master@67.195.138.61:41545
I1025 21:10:18.969137 30231 slave.cpp:1856] Status update manager successfully handled status update TASK_RUNNING (UUID: ca1ab971-026f-473c-843f-6152e6068ca5) for task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.969171 30231 slave.cpp:1862] Sending acknowledgement for status update TASK_RUNNING (UUID: ca1ab971-026f-473c-843f-6152e6068ca5) for task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000 to executor(1)@67.195.138.61:35737
I1025 21:10:18.969202 30229 master.cpp:1425] Status update TASK_RUNNING (UUID: ca1ab971-026f-473c-843f-6152e6068ca5) for task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000 from slave(96)@67.195.138.61:41545
I1025 21:10:18.969250 30225 sched.cpp:527] Scheduler::statusUpdate took 25967ns
I1025 21:10:18.969446 30225 status_update_manager.cpp:380] Received status update acknowledgement (UUID: ca1ab971-026f-473c-843f-6152e6068ca5) for task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.969455 2663 process.cpp:986] Socket closed while receiving
I1025 21:10:18.969461 2661 exec.cpp:331] Executor received status update acknowledgement ca1ab971-026f-473c-843f-6152e6068ca5 for task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:18.969467 30225 status_update_manager.hpp:337] Checkpointing ACK for status update TASK_RUNNING (UUID: ca1ab971-026f-473c-843f-6152e6068ca5) for task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:19.017230 30228 slave.cpp:1343] Status update manager successfully handled status update acknowledgement (UUID: ca1ab971-026f-473c-843f-6152e6068ca5) for task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:19.017334 30231 slave.cpp:388] Slave terminating
I1025 21:10:19.017415 30231 master.cpp:615] Slave 201310252110-1032504131-41545-30098-0 (juno.apache.org) disconnected
I1025 21:10:19.017529 30230 hierarchical_allocator_process.hpp:484] Slave 201310252110-1032504131-41545-30098-0 disconnected
I1025 21:10:19.018504 30226 slave.cpp:109] Slave started on 97)@67.195.138.61:41545
I1025 21:10:19.018615 30226 slave.cpp:209] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I1025 21:10:19.018695 30230 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 32231ns
I1025 21:10:19.019378 30225 state.cpp:33] Recovering state from '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Jp3veo/meta'
I1025 21:10:19.019425 30226 slave.cpp:481] New master detected at master@67.195.138.61:41545
I1025 21:10:19.019459 30226 slave.cpp:490] Skipping registration because slave is in 'cleanup' mode
I1025 21:10:19.019486 30231 status_update_manager.cpp:158] New master detected at master@67.195.138.61:41545
I1025 21:10:19.020802 30228 slave.cpp:2795] Recovering framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:19.020825 30228 slave.cpp:2976] Recovering executor '719ac759-24d5-484e-87f2-9eb081376f4a' of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:19.021286 30226 status_update_manager.cpp:180] Recovering status update manager
I1025 21:10:19.021389 30226 status_update_manager.cpp:188] Recovering executor '719ac759-24d5-484e-87f2-9eb081376f4a' of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:19.021440 30226 status_update_manager.cpp:476] Creating StatusUpdate stream for task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:19.021512 30228 slave.cpp:463] Successfully attached file '/tmp/SlaveRecoveryTest_0_CleanupExecutor_Jp3veo/slaves/201310252110-1032504131-41545-30098-0/frameworks/201310252110-1032504131-41545-30098-0000/executors/719ac759-24d5-484e-87f2-9eb081376f4a/runs/8012f3b7-c925-42e3-bef6-c38277238c61'
I1025 21:10:19.021574 30226 status_update_manager.hpp:301] Replaying status update stream for task 719ac759-24d5-484e-87f2-9eb081376f4a
I1025 21:10:19.021857 30225 process_isolator.cpp:314] Recovering isolator
I1025 21:10:19.021934 30225 process_isolator.cpp:322] Recovering executor '719ac759-24d5-484e-87f2-9eb081376f4a' of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:19.022282 30227 slave.cpp:2688] Sending shutdown to executor '719ac759-24d5-484e-87f2-9eb081376f4a' of framework 201310252110-1032504131-41545-30098-0000 to executor(1)@67.195.138.61:35737
I1025 21:10:19.022305 30227 slave.cpp:2396] Shutting down executor '719ac759-24d5-484e-87f2-9eb081376f4a' of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:19.022505 2657 exec.cpp:371] Executor asked to shutdown
I1025 21:10:19.022557 2657 exec.cpp:386] Executor::shutdown took 5288ns
Shutting down
Killing process tree at pid 2664
I1025 21:10:19.022583 2658 exec.cpp:76] Scheduling shutdown of the executor
I1025 21:10:19.022627 30227 slave.cpp:2733] Finished recovery
I1025 21:10:19.025210 2663 process.cpp:986] Socket closed while receiving
Killed the following process trees:
[
-+- 2664 sh -c sleep 1000
\--- 2665 sleep 1000
]
Command terminated with signal Killed (pid: 2664)
I1025 21:10:19.826316 2660 exec.cpp:505] Executor sending status update TASK_KILLED (UUID: 9726a5a7-e5a1-4b22-8c72-acb77fae6416) for task 719ac759-24d5-484e-87f2-9eb081376f4a of framework 201310252110-1032504131-41545-30098-0000
I1025 21:10:20.827052 30233 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.
../3rdparty/libprocess/include/process/gmock.hpp:135: ERROR: this mock object (used in test SlaveRecoveryTest/0.CleanupExecutor) should be deleted but never is. Its address is @0x1e3a528.
tests/slave_recovery_tests.cpp:932: ERROR: this mock object (used in test SlaveRecoveryTest/0.CleanupExecutor) should be deleted but never is. Its address is @0x7fff3bfce240.
ERROR: 2 leaked mock objects found at program exit.
make[3]: *** [check-local] Error 1
make[2]: *** [check-am] Terminated
make[1]: *** [check] Terminated
Jenkins build is back to normal :
Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME #1462
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/1462/changes>