See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/1406/>
------------------------------------------ [...truncated 16914 lines...] I0917 23:59:40.794816 3179 status_update_manager.cpp:375] Received status update acknowledgement (UUID: d1c8f6fa-3f2b-497b-811e-a3a7620de75d) for task 0 of framework 201309172359-160088899-55190-3131-0000 I0917 23:59:40.838515 3179 slave.cpp:1386] Status update manager successfully handled status update acknowledgement (UUID: d1c8f6fa-3f2b-497b-811e-a3a7620de75d) for task 0 of framework 201309172359-160088899-55190-3131-0000 I0917 23:59:40.818513 3131 master.hpp:337] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:40.854374 3131 master.cpp:237] Removing slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:40.794718 3180 exec.cpp:331] Executor received status update acknowledgement d1c8f6fa-3f2b-497b-811e-a3a7620de75d for task 0 of framework 201309172359-160088899-55190-3131-0000 I0917 23:59:40.854486 3174 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 201309172359-160088899-55190-3131-0 from framework 201309172359-160088899-55190-3131-0000 I0917 23:59:40.879102 3174 master.cpp:265] Master started on 67.195.138.9:55190 I0917 23:59:40.886173 3174 master.cpp:280] Master ID: 201309172359-160088899-55190-3131 I0917 23:59:40.901525 3176 detector.cpp:234] Master detector ([email protected]:55190) connected to ZooKeeper ... I0917 23:59:40.901808 3178 detector.cpp:420] Master detector (slave(131)@67.195.138.9:55190) found 0 registered masters I0917 23:59:40.901933 3179 detector.cpp:420] Master detector (scheduler(113)@67.195.138.9:55190) found 0 registered masters I0917 23:59:40.914134 3180 master.cpp:80] No whitelist given. Advertising offers for all slaves I0917 23:59:40.914319 3175 hierarchical_allocator_process.hpp:291] Initializing hierarchical allocator process with master : [email protected]:55190 I0917 23:59:40.921984 3176 detector.cpp:251] Trying to create path '/znode' in ZooKeeper I0917 23:59:40.929913 3178 detector.cpp:441] Master detector (slave(131)@67.195.138.9:55190) couldn't find any masters I0917 23:59:40.949795 3179 detector.cpp:441] Master detector (scheduler(113)@67.195.138.9:55190) couldn't find any masters I0917 23:59:40.985102 3176 detector.cpp:281] Created ephemeral/sequence znode at '/znode/0000000002' I0917 23:59:40.989681 3180 slave.cpp:577] Lost master(s) ... waiting I0917 23:59:40.990037 3178 detector.cpp:420] Master detector (slave(131)@67.195.138.9:55190) found 1 registered masters I0917 23:59:41.005610 3174 sched.cpp:202] No master detected, waiting for another master I0917 23:59:41.037329 3174 sched.cpp:214] Scheduler::disconnected took 11.695us I0917 23:59:41.013896 3176 detector.cpp:420] Master detector ([email protected]:55190) found 1 registered masters I0917 23:59:41.029758 3178 detector.cpp:467] Master detector (slave(131)@67.195.138.9:55190) got new master pid: [email protected]:55190 I0917 23:59:41.077564 3178 slave.cpp:543] New master detected at [email protected]:55190 I0917 23:59:41.085183 3173 status_update_manager.cpp:157] New master detected at [email protected]:55190 I0917 23:59:41.005956 3179 detector.cpp:420] Master detector (scheduler(113)@67.195.138.9:55190) found 1 registered masters I0917 23:59:41.069619 3176 detector.cpp:467] Master detector ([email protected]:55190) got new master pid: [email protected]:55190 I0917 23:59:41.101449 3179 detector.cpp:467] Master detector (scheduler(113)@67.195.138.9:55190) got new master pid: [email protected]:55190 I0917 23:59:41.109058 3176 master.cpp:644] Elected as master! I0917 23:59:41.118238 3179 sched.cpp:178] New master at [email protected]:55190 I0917 23:59:41.132972 3179 master.cpp:736] Re-registering framework 201309172359-160088899-55190-3131-0000 at scheduler(113)@67.195.138.9:55190 I0917 23:59:41.140990 3179 sched.cpp:237] Framework registered with 201309172359-160088899-55190-3131-0000 I0917 23:59:41.141141 3180 hierarchical_allocator_process.hpp:321] Added framework 201309172359-160088899-55190-3131-0000 I0917 23:59:41.156827 3180 hierarchical_allocator_process.hpp:687] No resources available to allocate! I0917 23:59:41.148871 3179 sched.cpp:251] Scheduler::registered took 14.209us I0917 23:59:41.164778 3180 hierarchical_allocator_process.hpp:649] Performed allocation for 0 slaves in 7.953297ms I0917 23:59:41.254664 3177 master.cpp:1175] Attempting to re-register slave 201309172359-160088899-55190-3131-0 at slave(131)@67.195.138.9:55190 (vesta.apache.org) I0917 23:59:41.254748 3177 master.cpp:2165] Adding slave 201309172359-160088899-55190-3131-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] I0917 23:59:41.315966 3177 master.hpp:321] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:41.315987 3178 slave.cpp:644] Re-registered with master [email protected]:55190 I0917 23:59:41.324365 3175 hierarchical_allocator_process.hpp:434] Added slave 201309172359-160088899-55190-3131-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) I0917 23:59:41.332048 3178 slave.cpp:1332] Updating framework 201309172359-160088899-55190-3131-0000 pid to scheduler(113)@67.195.138.9:55190 I0917 23:59:41.340036 3175 hierarchical_allocator_process.hpp:712] Offering cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309172359-160088899-55190-3131-0 to framework 201309172359-160088899-55190-3131-0000 I0917 23:59:41.367933 3175 hierarchical_allocator_process.hpp:669] Performed allocation for slave 201309172359-160088899-55190-3131-0 in 27.92964ms I0917 23:59:41.367980 3173 master.hpp:347] Adding offer 201309172359-160088899-55190-3131-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:41.383782 3173 master.cpp:1462] Sending 1 offers to framework 201309172359-160088899-55190-3131-0000 I0917 23:59:41.391810 3173 sched.cpp:340] Scheduler::resourceOffers took 22.542us I0917 23:59:41.391957 3131 master.cpp:481] Master terminating I0917 23:59:41.399708 3173 sched.cpp:498] Stopping framework '201309172359-160088899-55190-3131-0000' I0917 23:59:41.407696 3131 master.cpp:206] Shutting down master I0917 23:59:41.407727 3177 slave.cpp:1973] [email protected]:55190 exited I0917 23:59:41.423637 3131 master.hpp:337] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) W0917 23:59:41.463417 3177 slave.cpp:1976] Master disconnected! Waiting for a new master to be elected I0917 23:59:41.471499 3131 master.hpp:357] Removing offer 201309172359-160088899-55190-3131-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:41.471680 3175 hierarchical_allocator_process.hpp:598] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave 201309172359-160088899-55190-3131-0 from framework 201309172359-160088899-55190-3131-0000 I0917 23:59:41.487398 3131 master.cpp:237] Removing slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:41.503880 3131 slave.cpp:454] Slave terminating I0917 23:59:41.511183 3131 slave.cpp:1167] Asked to shut down framework 201309172359-160088899-55190-3131-0000 by @0.0.0.0:0 I0917 23:59:41.535099 3131 slave.cpp:1192] Shutting down framework 201309172359-160088899-55190-3131-0000 I0917 23:59:41.518678 3173 detector.cpp:420] Master detector (slave(131)@67.195.138.9:55190) found 0 registered masters I0917 23:59:41.551031 3173 detector.cpp:441] Master detector (slave(131)@67.195.138.9:55190) couldn't find any masters I0917 23:59:41.543016 3131 slave.cpp:2426] Shutting down executor 'default' of framework 201309172359-160088899-55190-3131-0000 I0917 23:59:41.567044 3176 exec.cpp:371] Executor asked to shutdown GMOCK WARNING: Uninteresting mock function call - returning directly. Function call: shutdown(0x2b638802bde0) Stack trace: I0917 23:59:41.586935 3176 exec.cpp:386] Executor::shutdown took 22.919us [ OK ] AllocatorZooKeeperTest/0.FrameworkReregistersFirst (1672 ms) [ RUN ] AllocatorZooKeeperTest/0.SlaveReregistersFirst 2013-09-17 23:59:41,596:3131(0x2b6386bc3700):ZOO_INFO@log_env@658: Client environment:zookeeper.version=zookeeper C client 3.3.4 2013-09-17 23:59:41,596:3131(0x2b6386bc3700):ZOO_INFO@log_env@662: Client environment:host.name=vesta.apache.org 2013-09-17 23:59:41,596:3131(0x2b6386bc3700):ZOO_INFO@log_env@669: Client environment:os.name=Linux 2013-09-17 23:59:41,597:3131(0x2b6386bc3700):ZOO_INFO@log_env@670: Client environment:os.arch=3.2.0-51-generic 2013-09-17 23:59:41,597:3131(0x2b6386bc3700):ZOO_INFO@log_env@671: Client environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013 2013-09-17 23:59:41,597:3131(0x2b6386bc3700):ZOO_INFO@log_env@679: Client environment:user.name=(null) 2013-09-17 23:59:41,597:3131(0x2b6386bc3700):ZOO_INFO@log_env@687: Client environment:user.home=/home/jenkins 2013-09-17 23:59:41,597:3131(0x2b6386bc3700):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-09-17 23:59:41,597:3131(0x2b6386bc3700):ZOO_INFO@zookeeper_init@727: Initiating client connection, host=127.0.0.1:38842 sessionTimeout=10000 watcher=0x2b63844a8ed0 sessionId=0 sessionPasswd=<null> context=0x2b63a4015650 flags=0 2013-09-17 23:59:41,597:3131(0x2b6386bc3700):ZOO_DEBUG@start_threads@152: starting threads... 2013-09-17 23:59:41,597:3131(0x2b6495376700):ZOO_DEBUG@do_completion@326: started completion thread 2013-09-17 23:59:41,597:3131(0x2b6494f74700):ZOO_DEBUG@do_io@279: started IO thread 2013-09-17 23:59:41,597:3131(0x2b6494f74700):ZOO_INFO@check_events@1585: initiated connection to server [127.0.0.1:38842] I0917 23:59:41.595558 3174 master.cpp:265] Master started on 67.195.138.9:55190 I0917 23:59:41.596658 3175 slave.cpp:108] Slave started on 132)@67.195.138.9:55190 I0917 23:59:41.630326 3175 slave.cpp:208] Slave resources: cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] I0917 23:59:41.610926 3180 detector.cpp:234] Master detector ([email protected]:55190) connected to ZooKeeper ... I0917 23:59:41.618680 3176 detector.cpp:234] Master detector (slave(132)@67.195.138.9:55190) connected to ZooKeeper ... I0917 23:59:41.654553 3176 detector.cpp:251] Trying to create path '/znode' in ZooKeeper I0917 23:59:41.602890 3174 master.cpp:280] Master ID: 201309172359-160088899-55190-3131 I0917 23:59:41.639307 3178 slave.cpp:399] Finished recovery I0917 23:59:41.646638 3180 detector.cpp:251] Trying to create path '/znode' in ZooKeeper I0917 23:59:41.619156 3179 detector.cpp:234] Master detector (scheduler(114)@67.195.138.9:55190) connected to ZooKeeper ... I0917 23:59:41.694394 3179 detector.cpp:251] Trying to create path '/znode' in ZooKeeper I0917 23:59:41.670681 3173 hierarchical_allocator_process.hpp:291] Initializing hierarchical allocator process with master : [email protected]:55190 I0917 23:59:41.670747 3175 master.cpp:80] No whitelist given. Advertising offers for all slaves I0917 23:59:41.663558 3176 detector.cpp:420] Master detector (slave(132)@67.195.138.9:55190) found 0 registered masters I0917 23:59:41.734189 3176 detector.cpp:441] Master detector (slave(132)@67.195.138.9:55190) couldn't find any masters I0917 23:59:41.711347 3179 detector.cpp:420] Master detector (scheduler(114)@67.195.138.9:55190) found 1 registered masters I0917 23:59:41.701203 3180 detector.cpp:281] Created ephemeral/sequence znode at '/znode/0000000004' I0917 23:59:41.742233 3177 slave.cpp:577] Lost master(s) ... waiting I0917 23:59:41.742746 3176 detector.cpp:420] Master detector (slave(132)@67.195.138.9:55190) found 1 registered masters I0917 23:59:41.750656 3179 detector.cpp:467] Master detector (scheduler(114)@67.195.138.9:55190) got new master pid: [email protected]:55190 I0917 23:59:41.758618 3180 detector.cpp:420] Master detector ([email protected]:55190) found 1 registered masters I0917 23:59:41.774526 3176 detector.cpp:467] Master detector (slave(132)@67.195.138.9:55190) got new master pid: [email protected]:55190 I0917 23:59:41.797978 3176 slave.cpp:543] New master detected at [email protected]:55190 I0917 23:59:41.790470 3180 detector.cpp:467] Master detector ([email protected]:55190) got new master pid: [email protected]:55190 I0917 23:59:41.782026 3179 sched.cpp:178] New master at [email protected]:55190 I0917 23:59:41.805965 3174 status_update_manager.cpp:157] New master detected at [email protected]:55190 W0917 23:59:41.805976 3176 master.cpp:1044] Ignoring register slave message from vesta.apache.org since not elected yet I0917 23:59:41.837765 3176 master.cpp:644] Elected as master! I0917 23:59:41.845752 3176 master.cpp:694] Registering framework 201309172359-160088899-55190-3131-0000 at scheduler(114)@67.195.138.9:55190 I0917 23:59:41.853690 3175 sched.cpp:237] Framework registered with 201309172359-160088899-55190-3131-0000 I0917 23:59:41.861629 3175 sched.cpp:251] Scheduler::registered took 10.149us I0917 23:59:41.853706 3176 hierarchical_allocator_process.hpp:321] Added framework 201309172359-160088899-55190-3131-0000 I0917 23:59:41.877554 3176 hierarchical_allocator_process.hpp:687] No resources available to allocate! I0917 23:59:41.885532 3176 hierarchical_allocator_process.hpp:649] Performed allocation for 0 slaves in 7.978649ms I0917 23:59:42.719025 3178 hierarchical_allocator_process.hpp:687] No resources available to allocate! I0917 23:59:42.719244 3178 hierarchical_allocator_process.hpp:649] Performed allocation for 0 slaves in 240.845us I0917 23:59:42.806288 3177 master.cpp:1075] Attempting to register slave on vesta.apache.org at slave(132)@67.195.138.9:55190 I0917 23:59:42.806373 3177 master.cpp:2165] Adding slave 201309172359-160088899-55190-3131-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] I0917 23:59:42.812049 3180 slave.cpp:603] Registered with master [email protected]:55190; given slave ID 201309172359-160088899-55190-3131-0 I0917 23:59:42.812180 3174 hierarchical_allocator_process.hpp:434] Added slave 201309172359-160088899-55190-3131-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) I0917 23:59:42.828006 3174 hierarchical_allocator_process.hpp:712] Offering cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309172359-160088899-55190-3131-0 to framework 201309172359-160088899-55190-3131-0000 I0917 23:59:42.835978 3174 hierarchical_allocator_process.hpp:669] Performed allocation for slave 201309172359-160088899-55190-3131-0 in 8.00529ms I0917 23:59:42.836035 3180 master.hpp:347] Adding offer 201309172359-160088899-55190-3131-0 with resources cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:42.869102 3180 master.cpp:1462] Sending 1 offers to framework 201309172359-160088899-55190-3131-0000 I0917 23:59:42.877279 3179 sched.cpp:340] Scheduler::resourceOffers took 163.326us I0917 23:59:42.893172 3179 master.cpp:1699] Processing reply for offer 201309172359-160088899-55190-3131-0 on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) for framework 201309172359-160088899-55190-3131-0000 I0917 23:59:42.923496 3179 master.hpp:321] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:42.944715 3179 master.cpp:1823] Launching task 0 of framework 201309172359-160088899-55190-3131-0000 with resources cpus(*):1; mem(*):500 on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:42.952839 3174 hierarchical_allocator_process.hpp:508] Framework 201309172359-160088899-55190-3131-0000 left cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] unused on slave 201309172359-160088899-55190-3131-0 I0917 23:59:42.952839 3180 slave.cpp:772] Got assigned task 0 for framework 201309172359-160088899-55190-3131-0000 I0917 23:59:42.952854 3179 master.hpp:357] Removing offer 201309172359-160088899-55190-3131-0 with resources cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:42.960695 3174 hierarchical_allocator_process.hpp:551] Framework 201309172359-160088899-55190-3131-0000 filtered slave 201309172359-160088899-55190-3131-0 for 5secs I0917 23:59:42.968786 3180 slave.cpp:883] Launching task 0 for framework 201309172359-160088899-55190-3131-0000 I0917 23:59:42.993932 3180 slave.cpp:994] Queuing task '0' for executor default of framework '201309172359-160088899-55190-3131-0000 I0917 23:59:42.995205 3175 exec.cpp:174] Executor started at: executor(41)@67.195.138.9:55190 with pid 3131 I0917 23:59:43.001294 3180 slave.cpp:525] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_efU1su/slaves/201309172359-160088899-55190-3131-0/frameworks/201309172359-160088899-55190-3131-0000/executors/default/runs/71f7faed-6fbc-43b1-bd3c-d6045e54a5f9' I0917 23:59:43.016410 3180 slave.cpp:1440] Got registration for executor 'default' of framework 201309172359-160088899-55190-3131-0000 I0917 23:59:43.024404 3180 slave.cpp:1561] Flushing queued task 0 for executor 'default' of framework 201309172359-160088899-55190-3131-0000 I0917 23:59:43.024446 3179 exec.cpp:198] Executor registered on slave 201309172359-160088899-55190-3131-0 I0917 23:59:43.041414 3179 exec.cpp:210] Executor::registered took 11.097us I0917 23:59:43.048290 3179 exec.cpp:285] Executor asked to run task '0' I0917 23:59:43.056238 3179 exec.cpp:294] Executor::launchTask took 24.515us I0917 23:59:43.065310 3179 exec.cpp:501] Executor sending status update TASK_RUNNING (UUID: cc87041f-7e1d-48ad-ac24-33ad97c1783f) for task 0 of framework 201309172359-160088899-55190-3131-0000 I0917 23:59:43.072185 3179 slave.cpp:1773] Handling status update TASK_RUNNING (UUID: cc87041f-7e1d-48ad-ac24-33ad97c1783f) for task 0 of framework 201309172359-160088899-55190-3131-0000 from executor(41)@67.195.138.9:55190 I0917 23:59:43.080214 3178 status_update_manager.cpp:300] Received status update TASK_RUNNING (UUID: cc87041f-7e1d-48ad-ac24-33ad97c1783f) for task 0 of framework 201309172359-160088899-55190-3131-0000 I0917 23:59:43.096055 3178 status_update_manager.cpp:471] Creating StatusUpdate stream for task 0 of framework 201309172359-160088899-55190-3131-0000 I0917 23:59:43.104048 3178 status_update_manager.cpp:351] Forwarding status update TASK_RUNNING (UUID: cc87041f-7e1d-48ad-ac24-33ad97c1783f) for task 0 of framework 201309172359-160088899-55190-3131-0000 to [email protected]:55190 I0917 23:59:43.112072 3173 master.cpp:1274] Status update TASK_RUNNING (UUID: cc87041f-7e1d-48ad-ac24-33ad97c1783f) for task 0 of framework 201309172359-160088899-55190-3131-0000 from slave(132)@67.195.138.9:55190 I0917 23:59:43.112125 3180 slave.cpp:1892] Status update manager successfully handled status update TASK_RUNNING (UUID: cc87041f-7e1d-48ad-ac24-33ad97c1783f) for task 0 of framework 201309172359-160088899-55190-3131-0000 I0917 23:59:43.127902 3180 slave.cpp:1898] Sending acknowledgement for status update TASK_RUNNING (UUID: cc87041f-7e1d-48ad-ac24-33ad97c1783f) for task 0 of framework 201309172359-160088899-55190-3131-0000 to executor(41)@67.195.138.9:55190 I0917 23:59:43.119940 3173 master.cpp:481] Master terminating I0917 23:59:43.151819 3173 slave.cpp:1973] [email protected]:55190 exited W0917 23:59:43.159739 3173 slave.cpp:1976] Master disconnected! Waiting for a new master to be elected I0917 23:59:43.112143 3175 sched.cpp:395] Scheduler::statusUpdate took 21.604us I0917 23:59:43.151871 3131 master.cpp:206] Shutting down master I0917 23:59:43.143901 3180 exec.cpp:331] Executor received status update acknowledgement cc87041f-7e1d-48ad-ac24-33ad97c1783f for task 0 of framework 201309172359-160088899-55190-3131-0000 I0917 23:59:43.175864 3175 status_update_manager.cpp:375] Received status update acknowledgement (UUID: cc87041f-7e1d-48ad-ac24-33ad97c1783f) for task 0 of framework 201309172359-160088899-55190-3131-0000 I0917 23:59:43.199630 3175 slave.cpp:1386] Status update manager successfully handled status update acknowledgement (UUID: cc87041f-7e1d-48ad-ac24-33ad97c1783f) for task 0 of framework 201309172359-160088899-55190-3131-0000 I0917 23:59:43.183760 3131 master.hpp:337] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:43.215620 3131 master.cpp:237] Removing slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:43.215625 3177 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 201309172359-160088899-55190-3131-0 from framework 201309172359-160088899-55190-3131-0000 I0917 23:59:43.232283 3177 master.cpp:265] Master started on 67.195.138.9:55190 I0917 23:59:43.239408 3177 master.cpp:280] Master ID: 201309172359-160088899-55190-3131 I0917 23:59:43.253360 3176 detector.cpp:234] Master detector ([email protected]:55190) connected to ZooKeeper ... I0917 23:59:43.253664 3174 detector.cpp:420] Master detector (slave(132)@67.195.138.9:55190) found 0 registered masters I0917 23:59:43.253762 3180 detector.cpp:420] Master detector (scheduler(114)@67.195.138.9:55190) found 0 registered masters I0917 23:59:43.261814 3175 master.cpp:80] No whitelist given. Advertising offers for all slaves I0917 23:59:43.261948 3178 hierarchical_allocator_process.hpp:291] Initializing hierarchical allocator process with master : [email protected]:55190 I0917 23:59:43.269675 3176 detector.cpp:251] Trying to create path '/znode' in ZooKeeper I0917 23:59:43.277601 3174 detector.cpp:441] Master detector (slave(132)@67.195.138.9:55190) couldn't find any masters I0917 23:59:43.285692 3180 detector.cpp:441] Master detector (scheduler(114)@67.195.138.9:55190) couldn't find any masters I0917 23:59:43.315246 3173 slave.cpp:577] Lost master(s) ... waiting I0917 23:59:43.320713 3176 detector.cpp:281] Created ephemeral/sequence znode at '/znode/0000000006' I0917 23:59:43.321197 3174 detector.cpp:420] Master detector (slave(132)@67.195.138.9:55190) found 1 registered masters I0917 23:59:43.333415 3178 sched.cpp:202] No master detected, waiting for another master I0917 23:59:43.365164 3178 sched.cpp:214] Scheduler::disconnected took 15.238us I0917 23:59:43.349810 3176 detector.cpp:420] Master detector ([email protected]:55190) found 1 registered masters I0917 23:59:43.357704 3174 detector.cpp:467] Master detector (slave(132)@67.195.138.9:55190) got new master pid: [email protected]:55190 I0917 23:59:43.333925 3180 detector.cpp:420] Master detector (scheduler(114)@67.195.138.9:55190) found 1 registered masters I0917 23:59:43.381913 3176 detector.cpp:467] Master detector ([email protected]:55190) got new master pid: [email protected]:55190 I0917 23:59:43.389170 3174 slave.cpp:543] New master detected at [email protected]:55190 I0917 23:59:43.397528 3180 detector.cpp:467] Master detector (scheduler(114)@67.195.138.9:55190) got new master pid: [email protected]:55190 I0917 23:59:43.405061 3176 master.cpp:644] Elected as master! I0917 23:59:43.413025 3177 status_update_manager.cpp:157] New master detected at [email protected]:55190 I0917 23:59:43.425282 3173 sched.cpp:178] New master at [email protected]:55190 I0917 23:59:43.428913 3176 master.cpp:1175] Attempting to re-register slave 201309172359-160088899-55190-3131-0 at slave(132)@67.195.138.9:55190 (vesta.apache.org) I0917 23:59:43.452718 3176 master.cpp:2165] Adding slave 201309172359-160088899-55190-3131-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] I0917 23:59:43.460731 3180 slave.cpp:644] Re-registered with master [email protected]:55190 I0917 23:59:43.460748 3176 master.hpp:321] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) W0917 23:59:43.476613 3176 master.cpp:2260] Possibly orphaned task 0 of framework 201309172359-160088899-55190-3131-0000 running on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:43.484920 3180 hierarchical_allocator_process.hpp:434] Added slave 201309172359-160088899-55190-3131-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) I0917 23:59:43.492491 3180 hierarchical_allocator_process.hpp:669] Performed allocation for slave 201309172359-160088899-55190-3131-0 in 14.074us I0917 23:59:44.016839 3176 monitor.cpp:187] Publishing resource usage for executor 'default' of framework '201309172359-160088899-55190-3131-0000' I0917 23:59:44.300144 3179 hierarchical_allocator_process.hpp:649] Performed allocation for 1 slaves in 42.15us I0917 23:59:44.445400 3176 master.cpp:736] Re-registering framework 201309172359-160088899-55190-3131-0000 at scheduler(114)@67.195.138.9:55190 I0917 23:59:44.445696 3175 sched.cpp:237] Framework registered with 201309172359-160088899-55190-3131-0000 I0917 23:59:44.449931 3175 sched.cpp:251] Scheduler::registered took 12.198us I0917 23:59:44.445806 3177 hierarchical_allocator_process.hpp:321] Added framework 201309172359-160088899-55190-3131-0000 I0917 23:59:44.445747 3176 slave.cpp:1332] Updating framework 201309172359-160088899-55190-3131-0000 pid to scheduler(114)@67.195.138.9:55190 I0917 23:59:44.473837 3177 hierarchical_allocator_process.hpp:712] Offering cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309172359-160088899-55190-3131-0 to framework 201309172359-160088899-55190-3131-0000 I0917 23:59:44.485946 3177 hierarchical_allocator_process.hpp:649] Performed allocation for 1 slaves in 12.146567ms I0917 23:59:44.486042 3178 master.hpp:347] Adding offer 201309172359-160088899-55190-3131-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:44.501778 3178 master.cpp:1462] Sending 1 offers to framework 201309172359-160088899-55190-3131-0000 I0917 23:59:44.509868 3179 sched.cpp:340] Scheduler::resourceOffers took 39.02us I0917 23:59:44.510155 3131 master.cpp:481] Master terminating I0917 23:59:44.517711 3179 sched.cpp:498] Stopping framework '201309172359-160088899-55190-3131-0000' I0917 23:59:44.525631 3131 master.cpp:206] Shutting down master I0917 23:59:44.525656 3176 slave.cpp:1973] [email protected]:55190 exited W0917 23:59:44.558926 3176 slave.cpp:1976] Master disconnected! Waiting for a new master to be elected I0917 23:59:44.551028 3131 master.hpp:337] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:44.581465 3131 master.hpp:357] Removing offer 201309172359-160088899-55190-3131-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:44.581672 3174 hierarchical_allocator_process.hpp:598] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave 201309172359-160088899-55190-3131-0 from framework 201309172359-160088899-55190-3131-0000 I0917 23:59:44.601336 3131 master.cpp:237] Removing slave 201309172359-160088899-55190-3131-0 (vesta.apache.org) I0917 23:59:44.617933 3177 slave.cpp:454] Slave terminating I0917 23:59:44.625174 3177 slave.cpp:1167] Asked to shut down framework 201309172359-160088899-55190-3131-0000 by @0.0.0.0:0 I0917 23:59:44.662370 3177 slave.cpp:1192] Shutting down framework 201309172359-160088899-55190-3131-0000 I0917 23:59:44.630300 3180 detector.cpp:420] Master detector (slave(132)@67.195.138.9:55190) found 0 registered masters I0917 23:59:44.670311 3177 slave.cpp:2426] Shutting down executor 'default' of framework 201309172359-160088899-55190-3131-0000 I0917 23:59:44.678275 3180 detector.cpp:441] Master detector (slave(132)@67.195.138.9:55190) couldn't find any masters I0917 23:59:44.686288 3176 exec.cpp:371] Executor asked to shutdown GMOCK WARNING: Uninteresting mock function call - returning directly. Function call: shutdown(0x2b63ac01c7b0) Stack trace: I0917 23:59:44.702188 3176 exec.cpp:386] Executor::shutdown took 26.202us [ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (3127 ms) I0917 23:59:44.723433 3131 zookeeper_test_server.cpp:93] Shutdown ZooKeeperTestServer on port 38842 [----------] 2 tests from AllocatorZooKeeperTest/0 (4799 ms total) [----------] Global test environment tear-down [==========] 220 tests from 39 test cases ran. (208006 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-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
