See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/1621/>
------------------------------------------ [...truncated 17218 lines...] I0907 13:28:27.161635 14494 slave.cpp:1562] Flushing queued task 0 for executor 'default' of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:27.161684 14499 exec.cpp:198] Executor registered on slave 201309071328-160088899-33984-14363-0 I0907 13:28:27.178604 14499 exec.cpp:210] Executor::registered took 10.793us I0907 13:28:27.185443 14499 exec.cpp:285] Executor asked to run task '0' I0907 13:28:27.193395 14499 exec.cpp:294] Executor::launchTask took 20.828us I0907 13:28:27.202461 14499 exec.cpp:501] Executor sending status update TASK_RUNNING (UUID: bc8f6214-28be-4e53-b18f-2a43b9262f4a) for task 0 of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:27.209372 14496 slave.cpp:1772] Handling status update TASK_RUNNING (UUID: bc8f6214-28be-4e53-b18f-2a43b9262f4a) for task 0 of framework 201309071328-160088899-33984-14363-0000 from executor(40)@67.195.138.9:33984 I0907 13:28:27.217329 14496 status_update_manager.cpp:300] Received status update TASK_RUNNING (UUID: bc8f6214-28be-4e53-b18f-2a43b9262f4a) for task 0 of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:27.225236 14496 status_update_manager.cpp:471] Creating StatusUpdate stream for task 0 of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:27.233253 14496 status_update_manager.cpp:351] Forwarding status update TASK_RUNNING (UUID: bc8f6214-28be-4e53-b18f-2a43b9262f4a) for task 0 of framework 201309071328-160088899-33984-14363-0000 to [email protected]:33984 I0907 13:28:27.241228 14501 master.cpp:1211] Status update TASK_RUNNING (UUID: bc8f6214-28be-4e53-b18f-2a43b9262f4a) for task 0 of framework 201309071328-160088899-33984-14363-0000 from slave(131)@67.195.138.9:33984 I0907 13:28:27.241261 14497 slave.cpp:1891] Status update manager successfully handled status update TASK_RUNNING (UUID: bc8f6214-28be-4e53-b18f-2a43b9262f4a) for task 0 of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:27.257067 14497 slave.cpp:1897] Sending acknowledgement for status update TASK_RUNNING (UUID: bc8f6214-28be-4e53-b18f-2a43b9262f4a) for task 0 of framework 201309071328-160088899-33984-14363-0000 to executor(40)@67.195.138.9:33984 I0907 13:28:27.249420 14363 master.cpp:478] Master terminating I0907 13:28:27.272989 14363 master.cpp:206] Shutting down master I0907 13:28:27.280974 14363 master.hpp:331] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:27.249227 14501 sched.cpp:395] Scheduler::statusUpdate took 24.359us I0907 13:28:27.273051 14495 slave.cpp:1972] [email protected]:33984 exited W0907 13:28:27.304800 14495 slave.cpp:1975] Master disconnected! Waiting for a new master to be elected I0907 13:28:27.289074 14363 master.cpp:234] Removing slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:27.289095 14498 hierarchical_allocator_process.hpp:598] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]) on slave 201309071328-160088899-33984-14363-0 from framework 201309071328-160088899-33984-14363-0000 I0907 13:28:27.265094 14497 exec.cpp:331] Executor received status update acknowledgement bc8f6214-28be-4e53-b18f-2a43b9262f4a for task 0 of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:27.312868 14495 status_update_manager.cpp:375] Received status update acknowledgement (UUID: bc8f6214-28be-4e53-b18f-2a43b9262f4a) for task 0 of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:27.329380 14500 master.cpp:262] Master started on 67.195.138.9:33984 I0907 13:28:27.360378 14501 detector.cpp:234] Master detector ([email protected]:33984) connected to ZooKeeper ... I0907 13:28:27.360630 14496 detector.cpp:420] Master detector (scheduler(113)@67.195.138.9:33984) found 0 registered masters I0907 13:28:27.360756 14494 detector.cpp:420] Master detector (slave(131)@67.195.138.9:33984) found 0 registered masters I0907 13:28:27.401792 14494 detector.cpp:441] Master detector (slave(131)@67.195.138.9:33984) couldn't find any masters I0907 13:28:27.377940 14500 master.cpp:277] Master ID: 201309071328-160088899-33984-14363 W0907 13:28:27.417958 14498 master.cpp:80] No whitelist given. Advertising offers for all slaves I0907 13:28:27.393811 14496 detector.cpp:441] Master detector (scheduler(113)@67.195.138.9:33984) couldn't find any masters I0907 13:28:27.433696 14496 sched.cpp:202] No master detected, waiting for another master I0907 13:28:27.441622 14496 sched.cpp:214] Scheduler::disconnected took 9.392us I0907 13:28:27.418083 14497 hierarchical_allocator_process.hpp:291] Initializing hierarchical allocator process with master : [email protected]:33984 I0907 13:28:27.370048 14495 slave.cpp:1387] Status update manager successfully handled status update acknowledgement (UUID: bc8f6214-28be-4e53-b18f-2a43b9262f4a) for task 0 of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:27.465566 14495 slave.cpp:578] Lost master(s) ... waiting I0907 13:28:27.385851 14501 detector.cpp:251] Trying to create path '/znode' in ZooKeeper I0907 13:28:27.523682 14501 detector.cpp:281] Created ephemeral/sequence znode at '/znode/0000000002' I0907 13:28:27.523993 14497 detector.cpp:420] Master detector (scheduler(113)@67.195.138.9:33984) found 1 registered masters I0907 13:28:27.524207 14494 detector.cpp:420] Master detector (slave(131)@67.195.138.9:33984) found 1 registered masters I0907 13:28:27.524430 14501 detector.cpp:420] Master detector ([email protected]:33984) found 1 registered masters I0907 13:28:27.533859 14497 detector.cpp:467] Master detector (scheduler(113)@67.195.138.9:33984) got new master pid: [email protected]:33984 I0907 13:28:27.541805 14494 detector.cpp:467] Master detector (slave(131)@67.195.138.9:33984) got new master pid: [email protected]:33984 I0907 13:28:27.549741 14501 detector.cpp:467] Master detector ([email protected]:33984) got new master pid: [email protected]:33984 I0907 13:28:27.573185 14501 master.cpp:642] Elected as master! I0907 13:28:27.565243 14494 slave.cpp:544] New master detected at [email protected]:33984 I0907 13:28:27.557297 14497 sched.cpp:178] New master at [email protected]:33984 I0907 13:28:27.589148 14500 status_update_manager.cpp:157] New master detected at [email protected]:33984 I0907 13:28:27.597120 14497 master.cpp:734] Re-registering framework 201309071328-160088899-33984-14363-0000 at scheduler(113)@67.195.138.9:33984 I0907 13:28:27.613100 14497 sched.cpp:237] Framework registered with 201309071328-160088899-33984-14363-0000 I0907 13:28:27.620933 14497 sched.cpp:251] Scheduler::registered took 11.491us I0907 13:28:27.613200 14494 hierarchical_allocator_process.hpp:321] Added framework 201309071328-160088899-33984-14363-0000 I0907 13:28:27.636875 14494 hierarchical_allocator_process.hpp:687] No resources available to allocate! I0907 13:28:27.644827 14494 hierarchical_allocator_process.hpp:649] Performed allocation for 0 slaves in 7.953207ms I0907 13:28:28.146905 14498 monitor.cpp:187] Publishing resource usage for executor 'default' of framework '201309071328-160088899-33984-14363-0000' I0907 13:28:28.458055 14497 hierarchical_allocator_process.hpp:687] No resources available to allocate! I0907 13:28:28.458216 14497 hierarchical_allocator_process.hpp:649] Performed allocation for 0 slaves in 170.877us I0907 13:28:28.589346 14501 master.cpp:1165] Attempting to re-register slave 201309071328-160088899-33984-14363-0 at slave(131)@67.195.138.9:33984 (vesta.apache.org) I0907 13:28:28.589448 14501 master.cpp:2135] Adding slave 201309071328-160088899-33984-14363-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] I0907 13:28:28.594072 14500 slave.cpp:645] Re-registered with master [email protected]:33984 I0907 13:28:28.594105 14501 master.hpp:318] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:28.610102 14501 slave.cpp:1333] Updating framework 201309071328-160088899-33984-14363-0000 pid to scheduler(113)@67.195.138.9:33984 I0907 13:28:28.610180 14500 hierarchical_allocator_process.hpp:434] Added slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] (and cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] available) I0907 13:28:28.625886 14500 hierarchical_allocator_process.hpp:712] Offering cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309071328-160088899-33984-14363-0 to framework 201309071328-160088899-33984-14363-0000 I0907 13:28:28.633920 14500 hierarchical_allocator_process.hpp:669] Performed allocation for slave 201309071328-160088899-33984-14363-0 in 8.081452ms I0907 13:28:28.634016 14499 master.hpp:341] Adding offer 201309071328-160088899-33984-14363-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:28.649795 14499 master.cpp:1445] Sending 1 offers to framework 201309071328-160088899-33984-14363-0000 I0907 13:28:28.657856 14498 sched.cpp:340] Scheduler::resourceOffers took 24.885us I0907 13:28:28.658099 14363 master.cpp:478] Master terminating I0907 13:28:28.673624 14363 master.cpp:206] Shutting down master I0907 13:28:28.681622 14363 master.hpp:331] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:28.689600 14363 master.hpp:351] Removing offer 201309071328-160088899-33984-14363-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:28.697546 14363 master.cpp:234] Removing slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:28.665745 14498 sched.cpp:498] Stopping framework '201309071328-160088899-33984-14363-0000' I0907 13:28:28.689748 14496 hierarchical_allocator_process.hpp:598] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave 201309071328-160088899-33984-14363-0 from framework 201309071328-160088899-33984-14363-0000 I0907 13:28:28.673657 14500 slave.cpp:1972] [email protected]:33984 exited I0907 13:28:28.729675 14494 detector.cpp:420] Master detector (slave(131)@67.195.138.9:33984) found 0 registered masters I0907 13:28:28.753208 14494 detector.cpp:441] Master detector (slave(131)@67.195.138.9:33984) couldn't find any masters W0907 13:28:28.745259 14500 slave.cpp:1975] Master disconnected! Waiting for a new master to be elected I0907 13:28:28.769130 14500 slave.cpp:454] Slave terminating I0907 13:28:28.777062 14500 slave.cpp:1168] Asked to shut down framework 201309071328-160088899-33984-14363-0000 by @0.0.0.0:0 I0907 13:28:28.785024 14500 slave.cpp:1193] Shutting down framework 201309071328-160088899-33984-14363-0000 I0907 13:28:28.792983 14500 slave.cpp:2423] Shutting down executor 'default' of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:28.801015 14501 exec.cpp:371] Executor asked to shutdown GMOCK WARNING: Uninteresting mock function call - returning directly. Function call: shutdown(0x2b00e802bf10) Stack trace: I0907 13:28:28.808951 14501 exec.cpp:386] Executor::shutdown took 47.061us [ OK ] AllocatorZooKeeperTest/0.FrameworkReregistersFirst (3100 ms) [ RUN ] AllocatorZooKeeperTest/0.SlaveReregistersFirst I0907 13:28:28.826134 14498 master.cpp:262] Master started on 67.195.138.9:33984 I0907 13:28:28.832831 14498 master.cpp:277] Master ID: 201309071328-160088899-33984-14363 W0907 13:28:28.840975 14499 master.cpp:80] No whitelist given. Advertising offers for all slaves I0907 13:28:28.835793 14497 detector.cpp:234] Master detector ([email protected]:33984) connected to ZooKeeper ... I0907 13:28:28.868578 14497 detector.cpp:251] Trying to create path '/znode' in ZooKeeper I0907 13:28:28.826150 14501 slave.cpp:108] Slave started on 132)@67.195.138.9:33984 I0907 13:28:28.849319 14495 detector.cpp:234] Master detector (scheduler(114)@67.195.138.9:33984) connected to ZooKeeper ... I0907 13:28:28.892459 14495 detector.cpp:251] Trying to create path '/znode' in ZooKeeper I0907 13:28:28.840996 14500 hierarchical_allocator_process.hpp:291] Initializing hierarchical allocator process with master : [email protected]:33984 I0907 13:28:28.880903 14497 detector.cpp:281] Created ephemeral/sequence znode at '/znode/0000000004' I0907 13:28:28.884624 14501 slave.cpp:208] Slave resources: cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] I0907 13:28:28.849814 14494 detector.cpp:234] Master detector (slave(132)@67.195.138.9:33984) connected to ZooKeeper ... I0907 13:28:28.932237 14494 detector.cpp:251] Trying to create path '/znode' in ZooKeeper I0907 13:28:28.916905 14497 detector.cpp:420] Master detector ([email protected]:33984) found 1 registered masters I0907 13:28:28.924736 14501 slave.cpp:399] Finished recovery I0907 13:28:28.901518 14495 detector.cpp:420] Master detector (scheduler(114)@67.195.138.9:33984) found 1 registered masters I0907 13:28:28.941288 14494 detector.cpp:420] Master detector (slave(132)@67.195.138.9:33984) found 1 registered masters I0907 13:28:28.948758 14497 detector.cpp:467] Master detector ([email protected]:33984) got new master pid: [email protected]:33984 I0907 13:28:28.980052 14497 master.cpp:642] Elected as master! I0907 13:28:28.972583 14494 detector.cpp:467] Master detector (slave(132)@67.195.138.9:33984) got new master pid: [email protected]:33984 I0907 13:28:28.995975 14494 slave.cpp:544] New master detected at [email protected]:33984 I0907 13:28:29.003939 14494 status_update_manager.cpp:157] New master detected at [email protected]:33984 I0907 13:28:28.964643 14495 detector.cpp:467] Master detector (scheduler(114)@67.195.138.9:33984) got new master pid: [email protected]:33984 I0907 13:28:29.019856 14495 sched.cpp:178] New master at [email protected]:33984 I0907 13:28:29.003994 14498 master.cpp:1065] Attempting to register slave on vesta.apache.org at slave(132)@67.195.138.9:33984 I0907 13:28:29.035703 14498 master.cpp:2135] Adding slave 201309071328-160088899-33984-14363-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] I0907 13:28:29.043763 14501 slave.cpp:604] Registered with master [email protected]:33984; given slave ID 201309071328-160088899-33984-14363-0 I0907 13:28:29.043819 14498 master.cpp:692] Registering framework 201309071328-160088899-33984-14363-0000 at scheduler(114)@67.195.138.9:33984 I0907 13:28:29.043825 14499 hierarchical_allocator_process.hpp:434] Added slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] available) I0907 13:28:29.067551 14499 hierarchical_allocator_process.hpp:669] Performed allocation for slave 201309071328-160088899-33984-14363-0 in 6.55us I0907 13:28:29.075508 14499 hierarchical_allocator_process.hpp:321] Added framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.059646 14498 sched.cpp:237] Framework registered with 201309071328-160088899-33984-14363-0000 I0907 13:28:29.091460 14498 sched.cpp:251] Scheduler::registered took 26.945us I0907 13:28:29.083516 14499 hierarchical_allocator_process.hpp:712] Offering cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309071328-160088899-33984-14363-0 to framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.107434 14499 hierarchical_allocator_process.hpp:649] Performed allocation for 1 slaves in 23.963097ms I0907 13:28:29.107498 14501 master.hpp:341] Adding offer 201309071328-160088899-33984-14363-0 with resources cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:29.123292 14501 master.cpp:1445] Sending 1 offers to framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.131438 14501 sched.cpp:340] Scheduler::resourceOffers took 147.543us I0907 13:28:29.139293 14496 master.cpp:1682] Processing reply for offer 201309071328-160088899-33984-14363-0 on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) for framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.147238 14496 master.hpp:318] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:29.155092 14496 master.cpp:1802] Launching task 0 of framework 201309071328-160088899-33984-14363-0000 with resources cpus(*):1; mem(*):500 on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:29.163159 14496 master.hpp:351] Removing offer 201309071328-160088899-33984-14363-0 with resources cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:29.163203 14500 slave.cpp:773] Got assigned task 0 for framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.179124 14500 slave.cpp:884] Launching task 0 for framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.163223 14501 hierarchical_allocator_process.hpp:508] Framework 201309071328-160088899-33984-14363-0000 left cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] unused on slave 201309071328-160088899-33984-14363-0 I0907 13:28:29.192975 14500 paths.hpp:336] Created executor directory '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_2vYQB4/slaves/201309071328-160088899-33984-14363-0/frameworks/201309071328-160088899-33984-14363-0000/executors/default/runs/e9c025d9-c518-4696-a925-f575fefc7d05' I0907 13:28:29.210978 14500 slave.cpp:995] Queuing task '0' for executor default of framework '201309071328-160088899-33984-14363-0000 I0907 13:28:29.202641 14501 hierarchical_allocator_process.hpp:551] Framework 201309071328-160088899-33984-14363-0000 filtered slave 201309071328-160088899-33984-14363-0 for 5secs I0907 13:28:29.212227 14495 exec.cpp:174] Executor started at: executor(41)@67.195.138.9:33984 with pid 14363 I0907 13:28:29.218811 14500 slave.cpp:526] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_2vYQB4/slaves/201309071328-160088899-33984-14363-0/frameworks/201309071328-160088899-33984-14363-0000/executors/default/runs/e9c025d9-c518-4696-a925-f575fefc7d05' I0907 13:28:29.242710 14500 slave.cpp:1441] Got registration for executor 'default' of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.254673 14500 slave.cpp:1562] Flushing queued task 0 for executor 'default' of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.254719 14496 exec.cpp:198] Executor registered on slave 201309071328-160088899-33984-14363-0 I0907 13:28:29.271602 14496 exec.cpp:210] Executor::registered took 10.811us I0907 13:28:29.278457 14496 exec.cpp:285] Executor asked to run task '0' I0907 13:28:29.286418 14496 exec.cpp:294] Executor::launchTask took 20.163us I0907 13:28:29.295454 14496 exec.cpp:501] Executor sending status update TASK_RUNNING (UUID: d9e25a63-8bc3-4f74-a2ad-f3f8fb51f064) for task 0 of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.302382 14496 slave.cpp:1772] Handling status update TASK_RUNNING (UUID: d9e25a63-8bc3-4f74-a2ad-f3f8fb51f064) for task 0 of framework 201309071328-160088899-33984-14363-0000 from executor(41)@67.195.138.9:33984 I0907 13:28:29.310359 14496 status_update_manager.cpp:300] Received status update TASK_RUNNING (UUID: d9e25a63-8bc3-4f74-a2ad-f3f8fb51f064) for task 0 of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.318233 14496 status_update_manager.cpp:471] Creating StatusUpdate stream for task 0 of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.326249 14496 status_update_manager.cpp:351] Forwarding status update TASK_RUNNING (UUID: d9e25a63-8bc3-4f74-a2ad-f3f8fb51f064) for task 0 of framework 201309071328-160088899-33984-14363-0000 to [email protected]:33984 I0907 13:28:29.334269 14498 master.cpp:1211] Status update TASK_RUNNING (UUID: d9e25a63-8bc3-4f74-a2ad-f3f8fb51f064) for task 0 of framework 201309071328-160088899-33984-14363-0000 from slave(132)@67.195.138.9:33984 I0907 13:28:29.334285 14494 slave.cpp:1891] Status update manager successfully handled status update TASK_RUNNING (UUID: d9e25a63-8bc3-4f74-a2ad-f3f8fb51f064) for task 0 of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.350075 14494 slave.cpp:1897] Sending acknowledgement for status update TASK_RUNNING (UUID: d9e25a63-8bc3-4f74-a2ad-f3f8fb51f064) for task 0 of framework 201309071328-160088899-33984-14363-0000 to executor(41)@67.195.138.9:33984 I0907 13:28:29.342402 14363 master.cpp:478] Master terminating I0907 13:28:29.365998 14363 master.cpp:206] Shutting down master I0907 13:28:29.358106 14495 exec.cpp:331] Executor received status update acknowledgement d9e25a63-8bc3-4f74-a2ad-f3f8fb51f064 for task 0 of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.342217 14498 sched.cpp:395] Scheduler::statusUpdate took 15.106us I0907 13:28:29.366047 14494 slave.cpp:1972] [email protected]:33984 exited W0907 13:28:29.397825 14494 slave.cpp:1975] Master disconnected! Waiting for a new master to be elected I0907 13:28:29.373993 14363 master.hpp:331] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:29.413835 14363 master.cpp:234] Removing slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:29.405951 14494 status_update_manager.cpp:375] Received status update acknowledgement (UUID: d9e25a63-8bc3-4f74-a2ad-f3f8fb51f064) for task 0 of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.413920 14496 hierarchical_allocator_process.hpp:598] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]) on slave 201309071328-160088899-33984-14363-0 from framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.429832 14497 slave.cpp:1387] Status update manager successfully handled status update acknowledgement (UUID: d9e25a63-8bc3-4f74-a2ad-f3f8fb51f064) for task 0 of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:29.438419 14499 master.cpp:262] Master started on 67.195.138.9:33984 I0907 13:28:29.450695 14495 detector.cpp:234] Master detector ([email protected]:33984) connected to ZooKeeper ... I0907 13:28:29.450891 14496 detector.cpp:420] Master detector (scheduler(114)@67.195.138.9:33984) found 0 registered masters I0907 13:28:29.473525 14496 detector.cpp:441] Master detector (scheduler(114)@67.195.138.9:33984) couldn't find any masters I0907 13:28:29.457655 14499 master.cpp:277] Master ID: 201309071328-160088899-33984-14363 I0907 13:28:29.465569 14495 detector.cpp:251] Trying to create path '/znode' in ZooKeeper I0907 13:28:29.451071 14498 detector.cpp:420] Master detector (slave(132)@67.195.138.9:33984) found 0 registered masters I0907 13:28:29.505413 14498 detector.cpp:441] Master detector (slave(132)@67.195.138.9:33984) couldn't find any masters W0907 13:28:29.489617 14494 master.cpp:80] No whitelist given. Advertising offers for all slaves I0907 13:28:29.489761 14501 hierarchical_allocator_process.hpp:291] Initializing hierarchical allocator process with master : [email protected]:33984 I0907 13:28:29.502187 14495 detector.cpp:281] Created ephemeral/sequence znode at '/znode/0000000006' I0907 13:28:29.502725 14497 detector.cpp:420] Master detector (scheduler(114)@67.195.138.9:33984) found 1 registered masters I0907 13:28:29.481540 14496 sched.cpp:202] No master detected, waiting for another master I0907 13:28:29.513464 14500 slave.cpp:578] Lost master(s) ... waiting I0907 13:28:29.513937 14498 detector.cpp:420] Master detector (slave(132)@67.195.138.9:33984) found 1 registered masters I0907 13:28:29.537819 14495 detector.cpp:420] Master detector ([email protected]:33984) found 1 registered masters I0907 13:28:29.545790 14497 detector.cpp:467] Master detector (scheduler(114)@67.195.138.9:33984) got new master pid: [email protected]:33984 I0907 13:28:29.553205 14496 sched.cpp:214] Scheduler::disconnected took 11.626us I0907 13:28:29.593066 14496 sched.cpp:178] New master at [email protected]:33984 I0907 13:28:29.577636 14495 detector.cpp:467] Master detector ([email protected]:33984) got new master pid: [email protected]:33984 I0907 13:28:29.609055 14495 master.cpp:642] Elected as master! I0907 13:28:29.569679 14498 detector.cpp:467] Master detector (slave(132)@67.195.138.9:33984) got new master pid: [email protected]:33984 I0907 13:28:29.624969 14498 slave.cpp:544] New master detected at [email protected]:33984 I0907 13:28:29.632930 14496 status_update_manager.cpp:157] New master detected at [email protected]:33984 I0907 13:28:29.633023 14500 master.cpp:1165] Attempting to re-register slave 201309071328-160088899-33984-14363-0 at slave(132)@67.195.138.9:33984 (vesta.apache.org) I0907 13:28:29.648804 14500 master.cpp:2135] Adding slave 201309071328-160088899-33984-14363-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] I0907 13:28:29.656844 14500 master.hpp:318] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:29.656860 14498 slave.cpp:645] Re-registered with master [email protected]:33984 W0907 13:28:29.684340 14500 master.cpp:2227] Possibly orphaned task 0 of framework 201309071328-160088899-33984-14363-0000 running on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:29.736795 14500 hierarchical_allocator_process.hpp:434] Added slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] (and cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] available) I0907 13:28:29.744591 14500 hierarchical_allocator_process.hpp:669] Performed allocation for slave 201309071328-160088899-33984-14363-0 in 8.234us I0907 13:28:30.028378 14499 master.cpp:734] Re-registering framework 201309071328-160088899-33984-14363-0000 at scheduler(114)@67.195.138.9:33984 I0907 13:28:30.028640 14496 sched.cpp:237] Framework registered with 201309071328-160088899-33984-14363-0000 I0907 13:28:30.034507 14496 sched.cpp:251] Scheduler::registered took 12.923us I0907 13:28:30.028800 14501 hierarchical_allocator_process.hpp:321] Added framework 201309071328-160088899-33984-14363-0000 I0907 13:28:30.028671 14499 slave.cpp:1333] Updating framework 201309071328-160088899-33984-14363-0000 pid to scheduler(114)@67.195.138.9:33984 I0907 13:28:30.051280 14501 hierarchical_allocator_process.hpp:712] Offering cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309071328-160088899-33984-14363-0 to framework 201309071328-160088899-33984-14363-0000 I0907 13:28:30.067277 14501 hierarchical_allocator_process.hpp:649] Performed allocation for 1 slaves in 16.049199ms I0907 13:28:30.067338 14495 master.hpp:341] Adding offer 201309071328-160088899-33984-14363-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:30.083140 14495 master.cpp:1445] Sending 1 offers to framework 201309071328-160088899-33984-14363-0000 I0907 13:28:30.091250 14494 sched.cpp:340] Scheduler::resourceOffers took 25.719us I0907 13:28:30.099063 14494 sched.cpp:498] Stopping framework '201309071328-160088899-33984-14363-0000' I0907 13:28:30.091472 14363 master.cpp:478] Master terminating I0907 13:28:30.114981 14363 master.cpp:206] Shutting down master I0907 13:28:30.115025 14498 slave.cpp:1972] [email protected]:33984 exited W0907 13:28:30.130900 14498 slave.cpp:1975] Master disconnected! Waiting for a new master to be elected I0907 13:28:30.122990 14363 master.hpp:331] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:30.146920 14363 master.hpp:351] Removing offer 201309071328-160088899-33984-14363-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:30.147044 14497 hierarchical_allocator_process.hpp:598] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave 201309071328-160088899-33984-14363-0 from framework 201309071328-160088899-33984-14363-0000 I0907 13:28:30.154888 14363 master.cpp:234] Removing slave 201309071328-160088899-33984-14363-0 (vesta.apache.org) I0907 13:28:30.171257 14501 slave.cpp:454] Slave terminating I0907 13:28:30.175669 14496 detector.cpp:420] Master detector (slave(132)@67.195.138.9:33984) found 0 registered masters I0907 13:28:30.186949 14496 detector.cpp:441] Master detector (slave(132)@67.195.138.9:33984) couldn't find any masters I0907 13:28:30.178719 14501 slave.cpp:1168] Asked to shut down framework 201309071328-160088899-33984-14363-0000 by @0.0.0.0:0 I0907 13:28:30.202596 14501 slave.cpp:1193] Shutting down framework 201309071328-160088899-33984-14363-0000 I0907 13:28:30.210582 14501 slave.cpp:2423] Shutting down executor 'default' of framework 201309071328-160088899-33984-14363-0000 I0907 13:28:30.218618 14501 exec.cpp:371] Executor asked to shutdown GMOCK WARNING: Uninteresting mock function call - returning directly. Function call: shutdown(0x2b00fc013c00) Stack trace: I0907 13:28:30.226577 14501 exec.cpp:386] Executor::shutdown took 45.184us [ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (1409 ms) I0907 13:28:30.235841 14363 zookeeper_test_server.cpp:93] Shutdown ZooKeeperTestServer on port 45351 [----------] 2 tests from AllocatorZooKeeperTest/0 (4509 ms total) [----------] Global test environment tear-down [==========] 220 tests from 39 test cases ran. (195441 ms total) [ PASSED ] 219 tests. [ FAILED ] 1 test, listed below: [ FAILED ] AllocatorTest/0.FrameworkExited, where TypeParam = mesos::internal::master::allocator::HierarchicalAllocatorProcess<mesos::internal::master::allocator::DRFSorter, mesos::internal::master::allocator::DRFSorter> 1 FAILED TEST make[3]: *** [check-local] Error 1 make[3]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src' make[2]: *** [check-am] Error 2 make[2]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src' make[1]: *** [check] Error 2 make[1]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src' make: *** [check-recursive] Error 1 Build step 'Execute shell' marked build as failure
