See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/1255/>
------------------------------------------ [...truncated 17348 lines...] I0727 21:17:51.980293 26641 master.hpp:318] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201307272117-160088899-40967-26641-0 I0727 21:17:51.980366 26661 exec.cpp:360] Executor asked to shutdown I0727 21:17:51.980412 26661 exec.cpp:375] Executor::shutdown took 9.72us I0727 21:17:51.980475 26660 hierarchical_allocator_process.hpp:595] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):2; mem(*):1024; disk(*):763020; ports(*):[31000-32000]) on slave 201307272117-160088899-40967-26641-0 from framework 201307272117-160088899-40967-26641-0000 I0727 21:17:51.980567 26660 hierarchical_allocator_process.hpp:348] Removed framework 201307272117-160088899-40967-26641-0000 I0727 21:17:51.980675 26660 hierarchical_allocator_process.hpp:456] Removed slave 201307272117-160088899-40967-26641-0 I0727 21:17:51.981559 26664 master.cpp:230] Master started on 67.195.138.9:40967 I0727 21:17:51.981618 26664 master.cpp:245] Master ID: 201307272117-160088899-40967-26641 W0727 21:17:51.981812 26661 master.cpp:83] No whitelist given. Advertising offers for all slaves I0727 21:17:51.981978 26661 hierarchical_allocator_process.hpp:287] Initializing hierarchical allocator process with master : [email protected]:40967 I0727 21:17:52.015789 26661 detector.cpp:234] Master detector ([email protected]:40967) connected to ZooKeeper ... I0727 21:17:52.015820 26661 detector.cpp:251] Trying to create path '/znode' in ZooKeeper I0727 21:17:52.016043 26665 detector.cpp:420] Master detector (slave(108)@67.195.138.9:40967) found 0 registered masters I0727 21:17:52.016068 26665 detector.cpp:441] Master detector (slave(108)@67.195.138.9:40967) couldn't find any masters I0727 21:17:52.016108 26665 slave.cpp:571] Lost master(s) ... waiting I0727 21:17:52.016238 26664 detector.cpp:420] Master detector (scheduler(99)@67.195.138.9:40967) found 0 registered masters I0727 21:17:52.016264 26664 detector.cpp:441] Master detector (scheduler(99)@67.195.138.9:40967) couldn't find any masters I0727 21:17:52.016325 26664 sched.cpp:202] No master detected, waiting for another master I0727 21:17:52.016357 26664 sched.cpp:214] Scheduler::disconnected took 13.434us I0727 21:17:52.035528 26661 detector.cpp:281] Created ephemeral/sequence znode at '/znode/0000000002' I0727 21:17:52.035931 26667 detector.cpp:420] Master detector (scheduler(99)@67.195.138.9:40967) found 1 registered masters I0727 21:17:52.036387 26661 detector.cpp:420] Master detector ([email protected]:40967) found 1 registered masters I0727 21:17:52.036433 26666 detector.cpp:420] Master detector (slave(108)@67.195.138.9:40967) found 1 registered masters I0727 21:17:52.036530 26667 detector.cpp:467] Master detector (scheduler(99)@67.195.138.9:40967) got new master pid: [email protected]:40967 I0727 21:17:52.036687 26667 sched.cpp:178] New master at [email protected]:40967 W0727 21:17:52.036758 26664 master.cpp:655] Ignoring re-register framework message since not elected yet I0727 21:17:52.037176 26666 detector.cpp:467] Master detector (slave(108)@67.195.138.9:40967) got new master pid: [email protected]:40967 I0727 21:17:52.037258 26661 detector.cpp:467] Master detector ([email protected]:40967) got new master pid: [email protected]:40967 I0727 21:17:52.037291 26666 slave.cpp:537] New master detected at [email protected]:40967 I0727 21:17:52.037425 26667 master.cpp:583] Elected as master! I0727 21:17:52.037448 26663 status_update_manager.cpp:155] New master detected at [email protected]:40967 I0727 21:17:52.974319 26661 master.cpp:675] Re-registering framework 201307272117-160088899-40967-26641-0000 at scheduler(99)@67.195.138.9:40967 I0727 21:17:52.974496 26660 sched.cpp:268] Framework re-registered with 201307272117-160088899-40967-26641-0000 I0727 21:17:52.974537 26660 sched.cpp:282] Scheduler::reregistered took 9.253us I0727 21:17:52.974582 26664 hierarchical_allocator_process.hpp:317] Added framework 201307272117-160088899-40967-26641-0000 I0727 21:17:52.974611 26664 hierarchical_allocator_process.hpp:684] No resources available to allocate! I0727 21:17:52.974624 26664 hierarchical_allocator_process.hpp:646] Performed allocation for 0 slaves in 13.533us I0727 21:17:52.982388 26667 hierarchical_allocator_process.hpp:684] No resources available to allocate! I0727 21:17:52.982486 26667 hierarchical_allocator_process.hpp:646] Performed allocation for 0 slaves in 106.202us I0727 21:17:53.037739 26660 master.cpp:1034] Attempting to re-register slave 201307272117-160088899-40967-26641-0 at slave(108)@67.195.138.9:40967 (vesta.apache.org) I0727 21:17:53.037777 26660 master.cpp:1941] Adding slave 201307272117-160088899-40967-26641-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):763020; ports(*):[31000-32000] I0727 21:17:53.037868 26662 slave.cpp:638] Re-registered with master [email protected]:40967 I0727 21:17:53.037897 26660 master.hpp:306] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201307272117-160088899-40967-26641-0 W0727 21:17:53.038089 26663 slave.cpp:1301] Ignoring updating pid for framework 201307272117-160088899-40967-26641-0000 because it is terminating I0727 21:17:53.038247 26666 hierarchical_allocator_process.hpp:430] Added slave 201307272117-160088899-40967-26641-0 (vesta.apache.org) with cpus(*):2; mem(*):1024; disk(*):763020; ports(*):[31000-32000] (and cpus(*):1; mem(*):524; disk(*):763020; ports(*):[31000-32000] available) I0727 21:17:53.038346 26666 hierarchical_allocator_process.hpp:709] Offering cpus(*):1; mem(*):524; disk(*):763020; ports(*):[31000-32000] on slave 201307272117-160088899-40967-26641-0 to framework 201307272117-160088899-40967-26641-0000 I0727 21:17:53.038486 26666 hierarchical_allocator_process.hpp:666] Performed allocation for slave 201307272117-160088899-40967-26641-0 in 177.015us I0727 21:17:53.038568 26667 master.hpp:328] Adding offer 201307272117-160088899-40967-26641-0 with resources cpus(*):1; mem(*):524; disk(*):763020; ports(*):[31000-32000] on slave 201307272117-160088899-40967-26641-0 I0727 21:17:53.038650 26667 master.cpp:1322] Sending 1 offers to framework 201307272117-160088899-40967-26641-0000 I0727 21:17:53.038790 26660 sched.cpp:340] Scheduler::resourceOffers took 35.944us I0727 21:17:53.039026 26663 sched.cpp:498] Stopping framework '201307272117-160088899-40967-26641-0000' I0727 21:17:53.039052 26667 master.cpp:436] Master terminating I0727 21:17:53.039134 26666 slave.cpp:493] Slave asked to shut down by [email protected]:40967 I0727 21:17:53.039155 26641 master.cpp:209] Shutting down master I0727 21:17:53.039191 26666 slave.cpp:1140] Asked to shut down framework 201307272117-160088899-40967-26641-0000 by [email protected]:40967 W0727 21:17:53.039263 26666 slave.cpp:1161] Ignoring shutdown framework 201307272117-160088899-40967-26641-0000 because it is terminating I0727 21:17:53.039293 26666 slave.cpp:1912] [email protected]:40967 exited W0727 21:17:53.039309 26666 slave.cpp:1915] Master disconnected! Waiting for a new master to be elected I0727 21:17:53.039319 26664 hierarchical_allocator_process.hpp:393] Deactivated framework 201307272117-160088899-40967-26641-0000 I0727 21:17:53.039333 26666 slave.cpp:1140] Asked to shut down framework 201307272117-160088899-40967-26641-0000 by [email protected]:40967 W0727 21:17:53.039386 26666 slave.cpp:1161] Ignoring shutdown framework 201307272117-160088899-40967-26641-0000 because it is terminating I0727 21:17:53.039338 26641 master.hpp:318] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201307272117-160088899-40967-26641-0 I0727 21:17:53.039695 26661 hierarchical_allocator_process.hpp:595] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave 201307272117-160088899-40967-26641-0 from framework 201307272117-160088899-40967-26641-0000 I0727 21:17:53.039710 26641 master.hpp:338] Removing offer 201307272117-160088899-40967-26641-0 with resources cpus(*):1; mem(*):524; disk(*):763020; ports(*):[31000-32000] on slave 201307272117-160088899-40967-26641-0 I0727 21:17:53.039805 26661 hierarchical_allocator_process.hpp:595] Recovered cpus(*):1; mem(*):524; disk(*):763020; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):763020; ports(*):[31000-32000]) on slave 201307272117-160088899-40967-26641-0 from framework 201307272117-160088899-40967-26641-0000 I0727 21:17:53.039955 26664 hierarchical_allocator_process.hpp:348] Removed framework 201307272117-160088899-40967-26641-0000 I0727 21:17:53.040014 26664 hierarchical_allocator_process.hpp:456] Removed slave 201307272117-160088899-40967-26641-0 I0727 21:17:53.040575 26641 slave.cpp:448] Slave terminating I0727 21:17:53.040603 26641 slave.cpp:1140] Asked to shut down framework 201307272117-160088899-40967-26641-0000 by @0.0.0.0:0 W0727 21:17:53.040624 26641 slave.cpp:1161] Ignoring shutdown framework 201307272117-160088899-40967-26641-0000 because it is terminating [ OK ] AllocatorZooKeeperTest/0.FrameworkReregistersFirst (3281 ms) [ RUN ] AllocatorZooKeeperTest/0.SlaveReregistersFirst I0727 21:17:53.041898 26662 master.cpp:230] Master started on 67.195.138.9:40967 I0727 21:17:53.041947 26662 master.cpp:245] Master ID: 201307272117-160088899-40967-26641 I0727 21:17:53.042163 26667 hierarchical_allocator_process.hpp:287] Initializing hierarchical allocator process with master : [email protected]:40967 W0727 21:17:53.042232 26667 master.cpp:83] No whitelist given. Advertising offers for all slaves I0727 21:17:53.042580 26667 slave.cpp:113] Slave started on 109)@67.195.138.9:40967 I0727 21:17:53.042721 26667 slave.cpp:213] Slave resources: cpus(*):2; mem(*):1024; disk(*):763022; ports(*):[31000-32000] 2013-07-27 21:17:53,042:26641(0x2b55c6785700):ZOO_INFO@log_env@658: Client environment:zookeeper.version=zookeeper C client 3.3.4 2013-07-27 21:17:53,042:26641(0x2b55c6785700):ZOO_INFO@log_env@662: Client environment:host.name=vesta.apache.org 2013-07-27 21:17:53,042:26641(0x2b55c6785700):ZOO_INFO@log_env@669: Client environment:os.name=Linux 2013-07-27 21:17:53,042:26641(0x2b55c6785700):ZOO_INFO@log_env@670: Client environment:os.arch=3.2.0-38-generic 2013-07-27 21:17:53,042:26641(0x2b55c6785700):ZOO_INFO@log_env@671: Client environment:os.version=#61-Ubuntu SMP Tue Feb 19 12:18:21 UTC 2013 2013-07-27 21:17:53,042:26641(0x2b55c6785700):ZOO_INFO@log_env@679: Client environment:user.name=(null) 2013-07-27 21:17:53,042:26641(0x2b55c6785700):ZOO_INFO@log_env@687: Client environment:user.home=/home/jenkins 2013-07-27 21:17:53,042:26641(0x2b55c6785700):ZOO_INFO@log_env@699: Client environment:user.dir=/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src 2013-07-27 21:17:53,042:26641(0x2b55c6785700):ZOO_INFO@zookeeper_init@727: Initiating client connection, host=127.0.0.1:41499 sessionTimeout=10000 watcher=0x2b55c347da90 sessionId=0 sessionPasswd=<null> context=0x2b55c800f7d0 flags=0 2013-07-27 21:17:53,043:26641(0x2b55c6785700):ZOO_DEBUG@start_threads@152: starting threads... I0727 21:17:53.043462 26667 slave.cpp:398] Finished recovery I0727 21:17:53.060055 26660 detector.cpp:234] Master detector ([email protected]:40967) connected to ZooKeeper ... I0727 21:17:53.060101 26660 detector.cpp:251] Trying to create path '/znode' in ZooKeeper I0727 21:17:53.060633 26662 detector.cpp:234] Master detector (slave(109)@67.195.138.9:40967) connected to ZooKeeper ... I0727 21:17:53.060688 26662 detector.cpp:251] Trying to create path '/znode' in ZooKeeper I0727 21:17:53.061375 26663 detector.cpp:234] Master detector (scheduler(100)@67.195.138.9:40967) connected to ZooKeeper ... I0727 21:17:53.061439 26663 detector.cpp:251] Trying to create path '/znode' in ZooKeeper I0727 21:17:53.086369 26660 detector.cpp:281] Created ephemeral/sequence znode at '/znode/0000000004' I0727 21:17:53.086585 26662 detector.cpp:420] Master detector (slave(109)@67.195.138.9:40967) found 1 registered masters I0727 21:17:53.086900 26660 detector.cpp:420] Master detector ([email protected]:40967) found 1 registered masters I0727 21:17:53.087136 26663 detector.cpp:420] Master detector (scheduler(100)@67.195.138.9:40967) found 1 registered masters I0727 21:17:53.087213 26662 detector.cpp:467] Master detector (slave(109)@67.195.138.9:40967) got new master pid: [email protected]:40967 I0727 21:17:53.087352 26662 slave.cpp:537] New master detected at [email protected]:40967 I0727 21:17:53.087437 26661 status_update_manager.cpp:155] New master detected at [email protected]:40967 W0727 21:17:53.087450 26667 master.cpp:943] Ignoring register slave message from vesta.apache.org since not elected yet I0727 21:17:53.087584 26660 detector.cpp:467] Master detector ([email protected]:40967) got new master pid: [email protected]:40967 I0727 21:17:53.087666 26660 master.cpp:583] Elected as master! I0727 21:17:53.087795 26663 detector.cpp:467] Master detector (scheduler(100)@67.195.138.9:40967) got new master pid: [email protected]:40967 I0727 21:17:53.087854 26663 sched.cpp:178] New master at [email protected]:40967 I0727 21:17:53.088067 26664 master.cpp:633] Registering framework 201307272117-160088899-40967-26641-0000 at scheduler(100)@67.195.138.9:40967 I0727 21:17:53.088172 26663 sched.cpp:237] Framework registered with 201307272117-160088899-40967-26641-0000 I0727 21:17:53.088197 26664 hierarchical_allocator_process.hpp:317] Added framework 201307272117-160088899-40967-26641-0000 I0727 21:17:53.088246 26664 hierarchical_allocator_process.hpp:684] No resources available to allocate! I0727 21:17:53.088238 26663 sched.cpp:251] Scheduler::registered took 24.209us I0727 21:17:53.088264 26664 hierarchical_allocator_process.hpp:646] Performed allocation for 0 slaves in 23.475us I0727 21:17:54.042845 26660 hierarchical_allocator_process.hpp:684] No resources available to allocate! I0727 21:17:54.042912 26660 hierarchical_allocator_process.hpp:646] Performed allocation for 0 slaves in 71.339us I0727 21:17:54.088052 26666 master.cpp:962] Attempting to register slave on vesta.apache.org at slave(109)@67.195.138.9:40967 I0727 21:17:54.088093 26666 master.cpp:1941] Adding slave 201307272117-160088899-40967-26641-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):763022; ports(*):[31000-32000] I0727 21:17:54.088171 26667 slave.cpp:597] Registered with master [email protected]:40967; given slave ID 201307272117-160088899-40967-26641-0 I0727 21:17:54.088322 26661 hierarchical_allocator_process.hpp:430] Added slave 201307272117-160088899-40967-26641-0 (vesta.apache.org) with cpus(*):2; mem(*):1024; disk(*):763022; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):763022; ports(*):[31000-32000] available) I0727 21:17:54.088414 26661 hierarchical_allocator_process.hpp:709] Offering cpus(*):2; mem(*):1024; disk(*):763022; ports(*):[31000-32000] on slave 201307272117-160088899-40967-26641-0 to framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.088549 26661 hierarchical_allocator_process.hpp:666] Performed allocation for slave 201307272117-160088899-40967-26641-0 in 160.785us I0727 21:17:54.088613 26660 master.hpp:328] Adding offer 201307272117-160088899-40967-26641-0 with resources cpus(*):2; mem(*):1024; disk(*):763022; ports(*):[31000-32000] on slave 201307272117-160088899-40967-26641-0 I0727 21:17:54.088671 26660 master.cpp:1322] Sending 1 offers to framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.088989 26660 sched.cpp:340] Scheduler::resourceOffers took 165.871us I0727 21:17:54.089122 26660 master.cpp:1555] Processing reply for offer 201307272117-160088899-40967-26641-0 on slave 201307272117-160088899-40967-26641-0 (vesta.apache.org) for framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.089222 26660 master.hpp:306] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201307272117-160088899-40967-26641-0 I0727 21:17:54.089261 26660 master.cpp:1674] Launching task 0 of framework 201307272117-160088899-40967-26641-0000 with resources cpus(*):1; mem(*):500 on slave 201307272117-160088899-40967-26641-0 (vesta.apache.org) I0727 21:17:54.089339 26665 slave.cpp:747] Got assigned task 0 for framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.089396 26660 master.hpp:338] Removing offer 201307272117-160088899-40967-26641-0 with resources cpus(*):2; mem(*):1024; disk(*):763022; ports(*):[31000-32000] on slave 201307272117-160088899-40967-26641-0 I0727 21:17:54.089437 26664 hierarchical_allocator_process.hpp:505] Framework 201307272117-160088899-40967-26641-0000 left cpus(*):1; mem(*):524; disk(*):763022; ports(*):[31000-32000] unused on slave 201307272117-160088899-40967-26641-0 I0727 21:17:54.089557 26665 slave.cpp:845] Launching task 0 for framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.089570 26664 hierarchical_allocator_process.hpp:548] Framework 201307272117-160088899-40967-26641-0000 filtered slave 201307272117-160088899-40967-26641-0 for 5secs I0727 21:17:54.090917 26665 paths.hpp:303] Created executor directory '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_CLOJdl/slaves/201307272117-160088899-40967-26641-0/frameworks/201307272117-160088899-40967-26641-0000/executors/default/runs/3721b8bd-73fc-4065-839a-8336feebaaa3' I0727 21:17:54.091092 26665 slave.cpp:956] Queuing task '0' for executor default of framework '201307272117-160088899-40967-26641-0000 I0727 21:17:54.091199 26665 slave.cpp:519] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_CLOJdl/slaves/201307272117-160088899-40967-26641-0/frameworks/201307272117-160088899-40967-26641-0000/executors/default/runs/3721b8bd-73fc-4065-839a-8336feebaaa3' I0727 21:17:54.091488 26663 exec.cpp:171] Executor started at: executor(39)@67.195.138.9:40967 with pid 26641 I0727 21:17:54.091629 26665 slave.cpp:1423] Got registration for executor 'default' of framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.091881 26665 slave.cpp:1538] Flushing queued task 0 for executor 'default' of framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.091914 26660 exec.cpp:195] Executor registered on slave 201307272117-160088899-40967-26641-0 I0727 21:17:54.091959 26660 exec.cpp:206] Executor::registered took 10.336us I0727 21:17:54.092013 26660 exec.cpp:274] Executor asked to run task '0' I0727 21:17:54.092058 26660 exec.cpp:283] Executor::launchTask took 22.709us I0727 21:17:54.093246 26660 exec.cpp:464] Executor sending status update TASK_RUNNING (UUID: 6ea59174-40a4-4b58-8200-2352b745769a) for task 0 of framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.093324 26660 slave.cpp:1720] Handling status update TASK_RUNNING (UUID: 6ea59174-40a4-4b58-8200-2352b745769a) for task 0 of framework 201307272117-160088899-40967-26641-0000 from executor(39)@67.195.138.9:40967 I0727 21:17:54.093457 26660 status_update_manager.cpp:290] Received status update TASK_RUNNING (UUID: 6ea59174-40a4-4b58-8200-2352b745769a) for task 0 of framework 201307272117-160088899-40967-26641-0000 with checkpoint=false I0727 21:17:54.093484 26660 status_update_manager.cpp:450] Creating StatusUpdate stream for task 0 of framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.093550 26660 status_update_manager.cpp:336] Forwarding status update TASK_RUNNING (UUID: 6ea59174-40a4-4b58-8200-2352b745769a) for task 0 of framework 201307272117-160088899-40967-26641-0000 to [email protected]:40967 I0727 21:17:54.093631 26667 master.cpp:1093] Status update from slave(109)@67.195.138.9:40967: task 0 of framework 201307272117-160088899-40967-26641-0000 is now in state TASK_RUNNING I0727 21:17:54.093657 26664 slave.cpp:1831] Status update manager successfully handled status update TASK_RUNNING (UUID: 6ea59174-40a4-4b58-8200-2352b745769a) for task 0 of framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.093734 26664 slave.cpp:1837] Sending acknowledgement for status update TASK_RUNNING (UUID: 6ea59174-40a4-4b58-8200-2352b745769a) for task 0 of framework 201307272117-160088899-40967-26641-0000 to executor(39)@67.195.138.9:40967 I0727 21:17:54.093772 26667 sched.cpp:395] Scheduler::statusUpdate took 25.613us I0727 21:17:54.093863 26660 exec.cpp:320] Executor received status update acknowledgement 6ea59174-40a4-4b58-8200-2352b745769a for task 0 of framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.094023 26665 status_update_manager.cpp:360] Received status update acknowledgement 6ea59174-40a4-4b58-8200-2352b745769a for task 0 of framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.094398 26664 slave.cpp:1371] Status update manager successfully handled status update acknowledgement 6ea59174-40a4-4b58-8200-2352b745769a for task 0 of framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.094451 26641 master.cpp:436] Master terminating I0727 21:17:54.094558 26641 master.cpp:209] Shutting down master I0727 21:17:54.094646 26666 slave.cpp:1912] [email protected]:40967 exited W0727 21:17:54.094694 26666 slave.cpp:1915] Master disconnected! Waiting for a new master to be elected I0727 21:17:54.094715 26664 hierarchical_allocator_process.hpp:393] Deactivated framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.094724 26641 master.hpp:318] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201307272117-160088899-40967-26641-0 I0727 21:17:54.094773 26666 slave.cpp:1140] Asked to shut down framework 201307272117-160088899-40967-26641-0000 by [email protected]:40967 I0727 21:17:54.094830 26666 slave.cpp:1165] Shutting down framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.094852 26666 slave.cpp:2356] Shutting down executor 'default' of framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.094912 26666 exec.cpp:360] Executor asked to shutdown I0727 21:17:54.094897 26663 hierarchical_allocator_process.hpp:595] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):2; mem(*):1024; disk(*):763022; ports(*):[31000-32000]) on slave 201307272117-160088899-40967-26641-0 from framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.094959 26666 exec.cpp:375] Executor::shutdown took 11.193us I0727 21:17:54.095001 26663 hierarchical_allocator_process.hpp:348] Removed framework 201307272117-160088899-40967-26641-0000 I0727 21:17:54.095091 26663 hierarchical_allocator_process.hpp:456] Removed slave 201307272117-160088899-40967-26641-0 I0727 21:17:54.095875 26666 master.cpp:230] Master started on 67.195.138.9:40967 I0727 21:17:54.095921 26666 master.cpp:245] Master ID: 201307272117-160088899-40967-26641 W0727 21:17:54.096074 26663 master.cpp:83] No whitelist given. Advertising offers for all slaves I0727 21:17:54.096271 26665 hierarchical_allocator_process.hpp:287] Initializing hierarchical allocator process with master : [email protected]:40967 I0727 21:17:54.129958 26666 detector.cpp:234] Master detector ([email protected]:40967) connected to ZooKeeper ... I0727 21:17:54.129995 26666 detector.cpp:251] Trying to create path '/znode' in ZooKeeper I0727 21:17:54.130172 26663 detector.cpp:420] Master detector (scheduler(100)@67.195.138.9:40967) found 0 registered masters I0727 21:17:54.130192 26663 detector.cpp:441] Master detector (scheduler(100)@67.195.138.9:40967) couldn't find any masters I0727 21:17:54.130231 26663 sched.cpp:202] No master detected, waiting for another master I0727 21:17:54.130259 26663 sched.cpp:214] Scheduler::disconnected took 8.345us I0727 21:17:54.130311 26664 detector.cpp:420] Master detector (slave(109)@67.195.138.9:40967) found 0 registered masters I0727 21:17:54.130352 26664 detector.cpp:441] Master detector (slave(109)@67.195.138.9:40967) couldn't find any masters I0727 21:17:54.130447 26664 slave.cpp:571] Lost master(s) ... waiting I0727 21:17:54.139071 26666 detector.cpp:281] Created ephemeral/sequence znode at '/znode/0000000006' I0727 21:17:54.139377 26667 detector.cpp:420] Master detector (scheduler(100)@67.195.138.9:40967) found 1 registered masters I0727 21:17:54.139732 26666 detector.cpp:420] Master detector ([email protected]:40967) found 1 registered masters I0727 21:17:54.139890 26667 detector.cpp:467] Master detector (scheduler(100)@67.195.138.9:40967) got new master pid: [email protected]:40967 I0727 21:17:54.140003 26662 detector.cpp:420] Master detector (slave(109)@67.195.138.9:40967) found 1 registered masters I0727 21:17:54.140008 26667 sched.cpp:178] New master at [email protected]:40967 I0727 21:17:54.140322 26666 detector.cpp:467] Master detector ([email protected]:40967) got new master pid: [email protected]:40967 I0727 21:17:54.140445 26666 master.cpp:583] Elected as master! I0727 21:17:54.140624 26662 detector.cpp:467] Master detector (slave(109)@67.195.138.9:40967) got new master pid: [email protected]:40967 I0727 21:17:54.140705 26662 slave.cpp:537] New master detected at [email protected]:40967 I0727 21:17:54.140777 26663 status_update_manager.cpp:155] New master detected at [email protected]:40967 I0727 21:17:54.140877 26664 master.cpp:1034] Attempting to re-register slave 201307272117-160088899-40967-26641-0 at slave(109)@67.195.138.9:40967 (vesta.apache.org) I0727 21:17:54.140907 26664 master.cpp:1941] Adding slave 201307272117-160088899-40967-26641-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):763022; ports(*):[31000-32000] I0727 21:17:54.140997 26667 slave.cpp:638] Re-registered with master [email protected]:40967 I0727 21:17:54.141017 26664 master.hpp:306] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201307272117-160088899-40967-26641-0 W0727 21:17:54.141060 26664 master.cpp:2033] Possibly orphaned task 0 of framework 201307272117-160088899-40967-26641-0000 running on slave 201307272117-160088899-40967-26641-0 (vesta.apache.org) I0727 21:17:54.141361 26667 hierarchical_allocator_process.hpp:430] Added slave 201307272117-160088899-40967-26641-0 (vesta.apache.org) with cpus(*):2; mem(*):1024; disk(*):763022; ports(*):[31000-32000] (and cpus(*):1; mem(*):524; disk(*):763022; ports(*):[31000-32000] available) I0727 21:17:54.141463 26667 hierarchical_allocator_process.hpp:666] Performed allocation for slave 201307272117-160088899-40967-26641-0 in 8.685us I0727 21:17:55.097129 26661 hierarchical_allocator_process.hpp:646] Performed allocation for 1 slaves in 18.684us I0727 21:17:55.141290 26665 master.cpp:675] Re-registering framework 201307272117-160088899-40967-26641-0000 at scheduler(100)@67.195.138.9:40967 I0727 21:17:55.141549 26666 sched.cpp:268] Framework re-registered with 201307272117-160088899-40967-26641-0000 W0727 21:17:55.141592 26661 slave.cpp:1301] Ignoring updating pid for framework 201307272117-160088899-40967-26641-0000 because it is terminating I0727 21:17:55.141625 26666 sched.cpp:282] Scheduler::reregistered took 15.144us I0727 21:17:55.141722 26660 hierarchical_allocator_process.hpp:317] Added framework 201307272117-160088899-40967-26641-0000 I0727 21:17:55.141834 26660 hierarchical_allocator_process.hpp:709] Offering cpus(*):1; mem(*):524; disk(*):763022; ports(*):[31000-32000] on slave 201307272117-160088899-40967-26641-0 to framework 201307272117-160088899-40967-26641-0000 I0727 21:17:55.141978 26660 hierarchical_allocator_process.hpp:646] Performed allocation for 1 slaves in 177.391us I0727 21:17:55.142093 26663 master.hpp:328] Adding offer 201307272117-160088899-40967-26641-0 with resources cpus(*):1; mem(*):524; disk(*):763022; ports(*):[31000-32000] on slave 201307272117-160088899-40967-26641-0 I0727 21:17:55.142176 26663 master.cpp:1322] Sending 1 offers to framework 201307272117-160088899-40967-26641-0000 I0727 21:17:55.142354 26665 sched.cpp:340] Scheduler::resourceOffers took 25.688us I0727 21:17:55.142571 26660 sched.cpp:498] Stopping framework '201307272117-160088899-40967-26641-0000' I0727 21:17:55.142598 26663 master.cpp:436] Master terminating I0727 21:17:55.142701 26665 slave.cpp:493] Slave asked to shut down by [email protected]:40967 I0727 21:17:55.142730 26641 master.cpp:209] Shutting down master I0727 21:17:55.142747 26665 slave.cpp:1140] Asked to shut down framework 201307272117-160088899-40967-26641-0000 by [email protected]:40967 W0727 21:17:55.142823 26665 slave.cpp:1161] Ignoring shutdown framework 201307272117-160088899-40967-26641-0000 because it is terminating I0727 21:17:55.142846 26665 slave.cpp:1912] [email protected]:40967 exited W0727 21:17:55.142865 26665 slave.cpp:1915] Master disconnected! Waiting for a new master to be elected I0727 21:17:55.142879 26667 hierarchical_allocator_process.hpp:393] Deactivated framework 201307272117-160088899-40967-26641-0000 I0727 21:17:55.142885 26641 master.hpp:318] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201307272117-160088899-40967-26641-0 I0727 21:17:55.142892 26665 slave.cpp:1140] Asked to shut down framework 201307272117-160088899-40967-26641-0000 by [email protected]:40967 W0727 21:17:55.143004 26665 slave.cpp:1161] Ignoring shutdown framework 201307272117-160088899-40967-26641-0000 because it is terminating I0727 21:17:55.143100 26663 hierarchical_allocator_process.hpp:595] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave 201307272117-160088899-40967-26641-0 from framework 201307272117-160088899-40967-26641-0000 I0727 21:17:55.143115 26641 master.hpp:338] Removing offer 201307272117-160088899-40967-26641-0 with resources cpus(*):1; mem(*):524; disk(*):763022; ports(*):[31000-32000] on slave 201307272117-160088899-40967-26641-0 I0727 21:17:55.143345 26665 hierarchical_allocator_process.hpp:595] Recovered cpus(*):1; mem(*):524; disk(*):763022; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):763022; ports(*):[31000-32000]) on slave 201307272117-160088899-40967-26641-0 from framework 201307272117-160088899-40967-26641-0000 I0727 21:17:55.143491 26667 hierarchical_allocator_process.hpp:348] Removed framework 201307272117-160088899-40967-26641-0000 I0727 21:17:55.143558 26667 hierarchical_allocator_process.hpp:456] Removed slave 201307272117-160088899-40967-26641-0 I0727 21:17:55.144284 26641 slave.cpp:448] Slave terminating I0727 21:17:55.144335 26641 slave.cpp:1140] Asked to shut down framework 201307272117-160088899-40967-26641-0000 by @0.0.0.0:0 W0727 21:17:55.144397 26641 slave.cpp:1161] Ignoring shutdown framework 201307272117-160088899-40967-26641-0000 because it is terminating [ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (2104 ms) I0727 21:17:55.157040 26641 zookeeper_test_server.cpp:93] Shutdown ZooKeeperTestServer on port 41499 [----------] 2 tests from AllocatorZooKeeperTest/0 (5385 ms total) [----------] Global test environment tear-down [==========] 208 tests from 38 test cases ran. (159776 ms total) [ PASSED ] 207 tests. [ FAILED ] 1 test, listed below: [ FAILED ] GroupTest.GroupWatchWithSessionExpiration 1 FAILED TEST make[3]: *** [check-local] Error 1 make[3]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src' make[2]: *** [check-am] Error 2 make[2]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src' make[1]: *** [check] Error 2 make[1]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src' make: *** [check-recursive] Error 1 Build step 'Execute shell' marked build as failure
