See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/1489/changes>
Changes: [benjamin.hindman] Included mesos-cat and mesos-tail in installation. [benjamin.hindman] Created 'usage' and moved 'get' helper to cli.py. [benjamin.hindman] Refactored mesos-cat to use helpers from cli.py. [benjamin.hindman] Revised os::realpath to return Result for when path does not exist. ------------------------------------------ [...truncated 20316 lines...] I1109 05:05:56.216871 8138 sched.cpp:347] Successfully authenticated with master [email protected]:48003 I1109 05:05:56.216923 8138 status_update_manager.cpp:158] New master detected at [email protected]:48003 I1109 05:05:56.216950 8135 master.cpp:1735] Successfully authenticated framework at scheduler(127)@67.195.138.9:48003 I1109 05:05:56.217033 8135 master.cpp:706] Elected as master! I1109 05:05:56.217067 8135 master.cpp:852] Re-registering framework 201311090505-160088899-48003-8115-0000 at scheduler(127)@67.195.138.9:48003 I1109 05:05:56.217241 8141 sched.cpp:386] Framework registered with 201311090505-160088899-48003-8115-0000 I1109 05:05:56.217270 8141 sched.cpp:400] Scheduler::registered took 12402ns I1109 05:05:56.217339 8135 hierarchical_allocator_process.hpp:332] Added framework 201311090505-160088899-48003-8115-0000 I1109 05:05:56.217352 8135 hierarchical_allocator_process.hpp:726] No resources available to allocate! I1109 05:05:56.217358 8135 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 7437ns I1109 05:05:57.181954 8140 master.cpp:1321] Attempting to re-register slave 201311090505-160088899-48003-8115-0 at slave(133)@67.195.138.9:48003 (vesta.apache.org) I1109 05:05:57.181996 8140 master.cpp:2474] Adding slave 201311090505-160088899-48003-8115-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] I1109 05:05:57.182139 8139 slave.cpp:601] Re-registered with master [email protected]:48003 I1109 05:05:57.182157 8140 master.hpp:391] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:57.182337 8138 slave.cpp:1297] Updating framework 201311090505-160088899-48003-8115-0000 pid to scheduler(127)@67.195.138.9:48003 I1109 05:05:57.182488 8138 hierarchical_allocator_process.hpp:445] Added slave 201311090505-160088899-48003-8115-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) I1109 05:05:57.182564 8138 hierarchical_allocator_process.hpp:752] Offering cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201311090505-160088899-48003-8115-0 to framework 201311090505-160088899-48003-8115-0000 I1109 05:05:57.182687 8138 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201311090505-160088899-48003-8115-0 in 152720ns I1109 05:05:57.182778 8140 master.hpp:419] Adding offer 201311090505-160088899-48003-8115-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:57.182826 8140 master.cpp:1661] Sending 1 offers to framework 201311090505-160088899-48003-8115-0000 I1109 05:05:57.182981 8141 sched.cpp:493] Scheduler::resourceOffers took 25008ns I1109 05:05:57.183174 8136 sched.cpp:651] Stopping framework '201311090505-160088899-48003-8115-0000' I1109 05:05:57.183219 8140 master.cpp:566] Master terminating I1109 05:05:57.183305 8141 slave.cpp:1945] [email protected]:48003 exited W1109 05:05:57.183321 8141 slave.cpp:1948] Master disconnected! Waiting for a new master to be elected I1109 05:05:57.183373 8115 master.cpp:218] Shutting down master I1109 05:05:57.183449 8115 master.hpp:409] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:57.183552 8115 master.hpp:429] Removing offer 201311090505-160088899-48003-8115-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:57.183655 8115 master.cpp:261] Removing slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:57.184504 8115 slave.cpp:395] Slave terminating I1109 05:05:57.184561 8115 slave.cpp:1127] Asked to shut down framework 201311090505-160088899-48003-8115-0000 by @0.0.0.0:0 I1109 05:05:57.184582 8115 slave.cpp:1152] Shutting down framework 201311090505-160088899-48003-8115-0000 I1109 05:05:57.184603 8115 slave.cpp:2411] Shutting down executor 'default' of framework 201311090505-160088899-48003-8115-0000 I1109 05:05:57.184700 8137 exec.cpp:371] Executor asked to shutdown I1109 05:05:57.184754 8137 exec.cpp:386] Executor::shutdown took 34225ns [ OK ] AllocatorZooKeeperTest/0.FrameworkReregistersFirst (2488 ms) [ RUN ] AllocatorZooKeeperTest/0.SlaveReregistersFirst I1109 05:05:57.186148 8140 master.cpp:293] Master started on 67.195.138.9:48003 I1109 05:05:57.186187 8140 master.cpp:308] Master ID: 201311090505-160088899-48003-8115 I1109 05:05:57.186194 8140 master.cpp:311] Master only allowing authenticated frameworks to register! I1109 05:05:57.186765 8134 master.cpp:85] No whitelist given. Advertising offers for all slaves I1109 05:05:57.186841 8140 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : [email protected]:48003 I1109 05:05:57.186874 8139 slave.cpp:109] Slave started on 134)@67.195.138.9:48003 I1109 05:05:57.187000 8139 slave.cpp:209] Slave resources: cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] 2013-11-09 05:05:57,187:8115(0x2b37f56b9700):ZOO_INFO@log_env@658: Client environment:zookeeper.version=zookeeper C client 3.3.4 2013-11-09 05:05:57,187:8115(0x2b37f56b9700):ZOO_INFO@log_env@662: Client environment:host.name=vesta.apache.org I1109 05:05:57.187645 8141 state.cpp:33] Recovering state from '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_SbKa8x/meta' I1109 05:05:57.187770 8134 status_update_manager.cpp:180] Recovering status update manager I1109 05:05:57.187952 8134 slave.cpp:2748] Finished recovery I1109 05:05:57.330103 8136 detector.cpp:241] Master detector (scheduler(128)@67.195.138.9:48003) connected to ZooKeeper ... I1109 05:05:57.330124 8136 detector.cpp:258] Trying to create path '/znode' in ZooKeeper I1109 05:05:57.330582 8134 detector.cpp:241] Master detector (slave(134)@67.195.138.9:48003) connected to ZooKeeper ... I1109 05:05:57.330605 8134 detector.cpp:258] Trying to create path '/znode' in ZooKeeper I1109 05:05:57.331015 8137 detector.cpp:241] Master detector ([email protected]:48003) connected to ZooKeeper ... I1109 05:05:57.331038 8137 detector.cpp:258] Trying to create path '/znode' in ZooKeeper I1109 05:05:57.331773 8136 detector.cpp:427] Master detector (scheduler(128)@67.195.138.9:48003) found 0 registered masters I1109 05:05:57.331789 8136 detector.cpp:448] Master detector (scheduler(128)@67.195.138.9:48003) couldn't find any masters I1109 05:05:57.331814 8136 sched.cpp:239] No master detected, waiting for another master I1109 05:05:57.332147 8134 detector.cpp:427] Master detector (slave(134)@67.195.138.9:48003) found 0 registered masters I1109 05:05:57.332170 8134 detector.cpp:448] Master detector (slave(134)@67.195.138.9:48003) couldn't find any masters I1109 05:05:57.332196 8134 slave.cpp:522] Lost master(s) ... waiting I1109 05:05:57.351495 8137 detector.cpp:288] Created ephemeral/sequence znode at '/znode/0000000004' I1109 05:05:57.351845 8140 detector.cpp:427] Master detector (slave(134)@67.195.138.9:48003) found 1 registered masters I1109 05:05:57.352212 8141 detector.cpp:427] Master detector (scheduler(128)@67.195.138.9:48003) found 1 registered masters I1109 05:05:57.352375 8137 detector.cpp:427] Master detector ([email protected]:48003) found 1 registered masters I1109 05:05:57.352659 8140 detector.cpp:474] Master detector (slave(134)@67.195.138.9:48003) got new master pid: [email protected]:48003 I1109 05:05:57.352732 8140 slave.cpp:488] New master detected at [email protected]:48003 I1109 05:05:57.352773 8134 status_update_manager.cpp:158] New master detected at [email protected]:48003 W1109 05:05:57.352825 8134 master.cpp:1201] Ignoring register slave message from vesta.apache.org since not elected yet I1109 05:05:57.352903 8141 detector.cpp:474] Master detector (scheduler(128)@67.195.138.9:48003) got new master pid: [email protected]:48003 I1109 05:05:57.352953 8141 sched.cpp:199] New master at [email protected]:48003 I1109 05:05:57.352967 8141 sched.cpp:285] Authenticating with master [email protected]:48003 I1109 05:05:57.353055 8139 authenticatee.hpp:124] Creating new client SASL connection I1109 05:05:57.353072 8137 detector.cpp:474] Master detector ([email protected]:48003) got new master pid: [email protected]:48003 I1109 05:05:57.353127 8139 master.cpp:1695] Authenticating framework at scheduler(128)@67.195.138.9:48003 I1109 05:05:57.353180 8137 authenticator.hpp:140] Creating new server SASL connection I1109 05:05:57.353211 8139 master.cpp:706] Elected as master! I1109 05:05:57.353226 8137 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5 I1109 05:05:57.353241 8137 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5' I1109 05:05:57.353265 8137 authenticator.hpp:243] Received SASL authentication start I1109 05:05:57.353338 8137 authenticator.hpp:325] Authentication requires more steps I1109 05:05:57.353358 8137 authenticatee.hpp:258] Received SASL authentication step I1109 05:05:57.353389 8137 authenticator.hpp:271] Received SASL authentication step I1109 05:05:57.353404 8137 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1109 05:05:57.353411 8137 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1109 05:05:57.353425 8137 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1109 05:05:57.353436 8137 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1109 05:05:57.353442 8137 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1109 05:05:57.353446 8137 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1109 05:05:57.353459 8137 authenticator.hpp:317] Authentication success I1109 05:05:57.353477 8139 authenticatee.hpp:298] Authentication success I1109 05:05:57.353478 8137 master.cpp:1735] Successfully authenticated framework at scheduler(128)@67.195.138.9:48003 I1109 05:05:57.353534 8139 sched.cpp:347] Successfully authenticated with master [email protected]:48003 I1109 05:05:57.353588 8141 master.cpp:764] Received registration request from scheduler(128)@67.195.138.9:48003 I1109 05:05:57.353653 8141 master.cpp:782] Registering framework 201311090505-160088899-48003-8115-0000 at scheduler(128)@67.195.138.9:48003 I1109 05:05:57.353708 8137 sched.cpp:386] Framework registered with 201311090505-160088899-48003-8115-0000 I1109 05:05:57.353721 8139 hierarchical_allocator_process.hpp:332] Added framework 201311090505-160088899-48003-8115-0000 I1109 05:05:57.353732 8139 hierarchical_allocator_process.hpp:726] No resources available to allocate! I1109 05:05:57.353749 8139 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 17416ns I1109 05:05:57.353734 8137 sched.cpp:400] Scheduler::registered took 12642ns I1109 05:05:58.187023 8141 hierarchical_allocator_process.hpp:726] No resources available to allocate! I1109 05:05:58.187041 8141 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 27727ns I1109 05:05:58.353405 8135 master.cpp:1232] Attempting to register slave on vesta.apache.org at slave(134)@67.195.138.9:48003 I1109 05:05:58.353422 8135 master.cpp:2474] Adding slave 201311090505-160088899-48003-8115-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] I1109 05:05:58.353538 8139 slave.cpp:554] Registered with master [email protected]:48003; given slave ID 201311090505-160088899-48003-8115-0 I1109 05:05:58.353631 8137 hierarchical_allocator_process.hpp:445] Added slave 201311090505-160088899-48003-8115-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) I1109 05:05:58.353729 8137 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201311090505-160088899-48003-8115-0 to framework 201311090505-160088899-48003-8115-0000 I1109 05:05:58.353860 8137 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201311090505-160088899-48003-8115-0 in 169061ns I1109 05:05:58.353932 8139 master.hpp:419] Adding offer 201311090505-160088899-48003-8115-0 with resources cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:58.354001 8139 master.cpp:1661] Sending 1 offers to framework 201311090505-160088899-48003-8115-0000 I1109 05:05:58.354275 8135 sched.cpp:493] Scheduler::resourceOffers took 166303ns I1109 05:05:58.354435 8139 master.cpp:1987] Processing reply for offer 201311090505-160088899-48003-8115-0 on slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) for framework 201311090505-160088899-48003-8115-0000 I1109 05:05:58.354542 8139 master.hpp:391] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:58.354570 8139 master.cpp:2111] Launching task 0 of framework 201311090505-160088899-48003-8115-0000 with resources cpus(*):1; mem(*):500 on slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:58.354657 8138 slave.cpp:728] Got assigned task 0 for framework 201311090505-160088899-48003-8115-0000 I1109 05:05:58.354723 8135 hierarchical_allocator_process.hpp:547] Framework 201311090505-160088899-48003-8115-0000 left cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] unused on slave 201311090505-160088899-48003-8115-0 I1109 05:05:58.354728 8139 master.hpp:429] Removing offer 201311090505-160088899-48003-8115-0 with resources cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:58.354874 8138 slave.cpp:839] Launching task 0 for framework 201311090505-160088899-48003-8115-0000 I1109 05:05:58.354877 8135 hierarchical_allocator_process.hpp:590] Framework 201311090505-160088899-48003-8115-0000 filtered slave 201311090505-160088899-48003-8115-0 for 5secs I1109 05:05:58.356438 8138 slave.cpp:949] Queuing task '0' for executor default of framework '201311090505-160088899-48003-8115-0000 I1109 05:05:58.356575 8137 slave.cpp:470] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_SbKa8x/slaves/201311090505-160088899-48003-8115-0/frameworks/201311090505-160088899-48003-8115-0000/executors/default/runs/ea48e90d-ad64-4c29-b9be-f5621d758183' I1109 05:05:58.357771 8141 slave.cpp:2078] Monitoring executor default of framework 201311090505-160088899-48003-8115-0000 forked at pid 8115 I1109 05:05:58.357815 8139 exec.cpp:174] Executor started at: executor(43)@67.195.138.9:48003 with pid 8115 I1109 05:05:58.357945 8135 slave.cpp:1411] Got registration for executor 'default' of framework 201311090505-160088899-48003-8115-0000 I1109 05:05:58.358093 8135 slave.cpp:1532] Flushing queued task 0 for executor 'default' of framework 201311090505-160088899-48003-8115-0000 I1109 05:05:58.358111 8134 exec.cpp:198] Executor registered on slave 201311090505-160088899-48003-8115-0 I1109 05:05:58.359264 8134 exec.cpp:210] Executor::registered took 20158ns I1109 05:05:58.359307 8134 exec.cpp:285] Executor asked to run task '0' I1109 05:05:58.359349 8134 exec.cpp:294] Executor::launchTask took 23451ns I1109 05:05:58.360522 8134 exec.cpp:505] Executor sending status update TASK_RUNNING (UUID: 3575b9f5-72a4-4449-a38a-370de5d73211) for task 0 of framework 201311090505-160088899-48003-8115-0000 I1109 05:05:58.360592 8134 slave.cpp:1745] Handling status update TASK_RUNNING (UUID: 3575b9f5-72a4-4449-a38a-370de5d73211) for task 0 of framework 201311090505-160088899-48003-8115-0000 from executor(43)@67.195.138.9:48003 I1109 05:05:58.360702 8138 status_update_manager.cpp:305] Received status update TASK_RUNNING (UUID: 3575b9f5-72a4-4449-a38a-370de5d73211) for task 0 of framework 201311090505-160088899-48003-8115-0000 I1109 05:05:58.360726 8138 status_update_manager.cpp:476] Creating StatusUpdate stream for task 0 of framework 201311090505-160088899-48003-8115-0000 I1109 05:05:58.360780 8138 status_update_manager.cpp:356] Forwarding status update TASK_RUNNING (UUID: 3575b9f5-72a4-4449-a38a-370de5d73211) for task 0 of framework 201311090505-160088899-48003-8115-0000 to [email protected]:48003 I1109 05:05:58.360853 8139 slave.cpp:1864] Status update manager successfully handled status update TASK_RUNNING (UUID: 3575b9f5-72a4-4449-a38a-370de5d73211) for task 0 of framework 201311090505-160088899-48003-8115-0000 I1109 05:05:58.360874 8139 slave.cpp:1870] Sending acknowledgement for status update TASK_RUNNING (UUID: 3575b9f5-72a4-4449-a38a-370de5d73211) for task 0 of framework 201311090505-160088899-48003-8115-0000 to executor(43)@67.195.138.9:48003 I1109 05:05:58.360896 8134 master.cpp:1418] Status update TASK_RUNNING (UUID: 3575b9f5-72a4-4449-a38a-370de5d73211) for task 0 of framework 201311090505-160088899-48003-8115-0000 from slave(134)@67.195.138.9:48003 I1109 05:05:58.360949 8136 exec.cpp:331] Executor received status update acknowledgement 3575b9f5-72a4-4449-a38a-370de5d73211 for task 0 of framework 201311090505-160088899-48003-8115-0000 I1109 05:05:58.361008 8135 sched.cpp:548] Scheduler::statusUpdate took 52441ns I1109 05:05:58.361253 8140 status_update_manager.cpp:380] Received status update acknowledgement (UUID: 3575b9f5-72a4-4449-a38a-370de5d73211) for task 0 of framework 201311090505-160088899-48003-8115-0000 I1109 05:05:58.361311 8115 master.cpp:566] Master terminating I1109 05:05:58.361340 8115 master.cpp:218] Shutting down master I1109 05:05:58.361343 8137 slave.cpp:1351] Status update manager successfully handled status update acknowledgement (UUID: 3575b9f5-72a4-4449-a38a-370de5d73211) for task 0 of framework 201311090505-160088899-48003-8115-0000 I1109 05:05:58.361378 8115 master.hpp:409] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:58.361397 8137 slave.cpp:1945] [email protected]:48003 exited W1109 05:05:58.361429 8137 slave.cpp:1948] Master disconnected! Waiting for a new master to be elected I1109 05:05:58.361495 8115 master.cpp:261] Removing slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:58.361541 8137 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]) on slave 201311090505-160088899-48003-8115-0 from framework 201311090505-160088899-48003-8115-0000 I1109 05:05:58.362767 8140 master.cpp:293] Master started on 67.195.138.9:48003 I1109 05:05:58.362802 8140 master.cpp:308] Master ID: 201311090505-160088899-48003-8115 I1109 05:05:58.362810 8140 master.cpp:311] Master only allowing authenticated frameworks to register! I1109 05:05:58.363030 8138 master.cpp:85] No whitelist given. Advertising offers for all slaves I1109 05:05:58.363250 8136 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : [email protected]:48003 I1109 05:05:58.408854 8136 detector.cpp:241] Master detector ([email protected]:48003) connected to ZooKeeper ... I1109 05:05:58.408879 8136 detector.cpp:258] Trying to create path '/znode' in ZooKeeper I1109 05:05:58.409106 8138 detector.cpp:427] Master detector (slave(134)@67.195.138.9:48003) found 0 registered masters I1109 05:05:58.409121 8138 detector.cpp:448] Master detector (slave(134)@67.195.138.9:48003) couldn't find any masters I1109 05:05:58.409173 8138 slave.cpp:522] Lost master(s) ... waiting I1109 05:05:58.409291 8141 detector.cpp:427] Master detector (scheduler(128)@67.195.138.9:48003) found 0 registered masters I1109 05:05:58.409313 8141 detector.cpp:448] Master detector (scheduler(128)@67.195.138.9:48003) couldn't find any masters I1109 05:05:58.409353 8141 sched.cpp:239] No master detected, waiting for another master I1109 05:05:58.409368 8141 sched.cpp:251] Scheduler::disconnected took 7735ns I1109 05:05:58.468514 8136 detector.cpp:288] Created ephemeral/sequence znode at '/znode/0000000006' I1109 05:05:58.468998 8140 detector.cpp:427] Master detector (slave(134)@67.195.138.9:48003) found 1 registered masters I1109 05:05:58.469144 8134 detector.cpp:427] Master detector (scheduler(128)@67.195.138.9:48003) found 1 registered masters I1109 05:05:58.469483 8140 detector.cpp:474] Master detector (slave(134)@67.195.138.9:48003) got new master pid: [email protected]:48003 I1109 05:05:58.469573 8140 slave.cpp:488] New master detected at [email protected]:48003 I1109 05:05:58.469658 8140 status_update_manager.cpp:158] New master detected at [email protected]:48003 W1109 05:05:58.469718 8140 master.cpp:1247] Ignoring re-register slave message from vesta.apache.org since not elected yet I1109 05:05:58.469816 8136 detector.cpp:427] Master detector ([email protected]:48003) found 1 registered masters I1109 05:05:58.469928 8134 detector.cpp:474] Master detector (scheduler(128)@67.195.138.9:48003) got new master pid: [email protected]:48003 I1109 05:05:58.470103 8134 sched.cpp:199] New master at [email protected]:48003 I1109 05:05:58.470118 8134 sched.cpp:285] Authenticating with master [email protected]:48003 I1109 05:05:58.470182 8137 authenticatee.hpp:124] Creating new client SASL connection I1109 05:05:58.470273 8137 master.cpp:1695] Authenticating framework at scheduler(128)@67.195.138.9:48003 I1109 05:05:58.470382 8136 detector.cpp:474] Master detector ([email protected]:48003) got new master pid: [email protected]:48003 I1109 05:05:58.470396 8138 authenticator.hpp:140] Creating new server SASL connection I1109 05:05:58.470458 8136 master.cpp:706] Elected as master! I1109 05:05:58.470459 8138 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5 I1109 05:05:58.470491 8138 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5' I1109 05:05:58.470523 8138 authenticator.hpp:243] Received SASL authentication start I1109 05:05:58.470595 8138 authenticator.hpp:325] Authentication requires more steps I1109 05:05:58.470633 8138 authenticatee.hpp:258] Received SASL authentication step I1109 05:05:58.470677 8138 authenticator.hpp:271] Received SASL authentication step I1109 05:05:58.470705 8138 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1109 05:05:58.470713 8138 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1109 05:05:58.470727 8138 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1109 05:05:58.470738 8138 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1109 05:05:58.470744 8138 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1109 05:05:58.470749 8138 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1109 05:05:58.470760 8138 authenticator.hpp:317] Authentication success I1109 05:05:58.470787 8138 authenticatee.hpp:298] Authentication success I1109 05:05:58.470805 8137 master.cpp:1735] Successfully authenticated framework at scheduler(128)@67.195.138.9:48003 I1109 05:05:58.470834 8138 sched.cpp:347] Successfully authenticated with master [email protected]:48003 I1109 05:05:59.353713 8141 master.cpp:1321] Attempting to re-register slave 201311090505-160088899-48003-8115-0 at slave(134)@67.195.138.9:48003 (vesta.apache.org) I1109 05:05:59.353734 8141 master.cpp:2474] Adding slave 201311090505-160088899-48003-8115-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] I1109 05:05:59.353842 8140 slave.cpp:601] Re-registered with master [email protected]:48003 I1109 05:05:59.353839 8141 master.hpp:391] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) W1109 05:05:59.353889 8141 master.cpp:2569] Possibly orphaned task 0 of framework 201311090505-160088899-48003-8115-0000 running on slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:59.354136 8137 hierarchical_allocator_process.hpp:445] Added slave 201311090505-160088899-48003-8115-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) I1109 05:05:59.354208 8137 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201311090505-160088899-48003-8115-0 in 9010ns I1109 05:05:59.358749 8134 monitor.cpp:187] Publishing resource usage for executor 'default' of framework '201311090505-160088899-48003-8115-0000' I1109 05:05:59.363780 8136 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 15175ns I1109 05:05:59.471076 8134 master.cpp:852] Re-registering framework 201311090505-160088899-48003-8115-0000 at scheduler(128)@67.195.138.9:48003 I1109 05:05:59.471235 8136 sched.cpp:386] Framework registered with 201311090505-160088899-48003-8115-0000 I1109 05:05:59.471281 8134 slave.cpp:1297] Updating framework 201311090505-160088899-48003-8115-0000 pid to scheduler(128)@67.195.138.9:48003 I1109 05:05:59.471326 8136 sched.cpp:400] Scheduler::registered took 78821ns I1109 05:05:59.471386 8135 hierarchical_allocator_process.hpp:332] Added framework 201311090505-160088899-48003-8115-0000 I1109 05:05:59.471431 8135 hierarchical_allocator_process.hpp:752] Offering cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201311090505-160088899-48003-8115-0 to framework 201311090505-160088899-48003-8115-0000 I1109 05:05:59.471564 8135 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 164402ns I1109 05:05:59.471627 8137 master.hpp:419] Adding offer 201311090505-160088899-48003-8115-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:59.471690 8137 master.cpp:1661] Sending 1 offers to framework 201311090505-160088899-48003-8115-0000 I1109 05:05:59.471807 8138 sched.cpp:493] Scheduler::resourceOffers took 24891ns I1109 05:05:59.472152 8141 sched.cpp:651] Stopping framework '201311090505-160088899-48003-8115-0000' I1109 05:05:59.472153 8139 master.cpp:566] Master terminating I1109 05:05:59.472254 8135 slave.cpp:1945] [email protected]:48003 exited W1109 05:05:59.472265 8135 slave.cpp:1948] Master disconnected! Waiting for a new master to be elected I1109 05:05:59.472291 8115 master.cpp:218] Shutting down master I1109 05:05:59.472399 8115 master.hpp:409] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:59.472548 8115 master.hpp:429] Removing offer 201311090505-160088899-48003-8115-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:59.472621 8139 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave 201311090505-160088899-48003-8115-0 from framework 201311090505-160088899-48003-8115-0000 I1109 05:05:59.472663 8115 master.cpp:261] Removing slave 201311090505-160088899-48003-8115-0 (vesta.apache.org) I1109 05:05:59.784178 8115 slave.cpp:395] Slave terminating I1109 05:05:59.784214 8115 slave.cpp:1127] Asked to shut down framework 201311090505-160088899-48003-8115-0000 by @0.0.0.0:0 I1109 05:05:59.784229 8115 slave.cpp:1152] Shutting down framework 201311090505-160088899-48003-8115-0000 I1109 05:05:59.784246 8115 slave.cpp:2411] Shutting down executor 'default' of framework 201311090505-160088899-48003-8115-0000 I1109 05:05:59.784292 8134 exec.cpp:371] Executor asked to shutdown I1109 05:05:59.784324 8134 exec.cpp:386] Executor::shutdown took 17460ns [ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (2600 ms) I1109 05:05:59.791285 8115 zookeeper_test_server.cpp:93] Shutdown ZooKeeperTestServer on port 53075 [----------] 2 tests from AllocatorZooKeeperTest/0 (5088 ms total) [----------] Global test environment tear-down [==========] 237 tests from 42 test cases ran. (122893 ms total) [ PASSED ] 236 tests. [ FAILED ] 1 test, listed below: [ FAILED ] ExamplesTest.PythonFramework 1 FAILED TEST YOU HAVE 3 DISABLED TESTS 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
