See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/1613/changes>
Changes: [vinod] Logged Mesos version in master, slave and drivers. ------------------------------------------ [...truncated 25762 lines...] I0211 21:18:05.299909 20401 group.cpp:310] Group process ((1894)@67.195.138.9:60912) connected to ZooKeeper I0211 21:18:05.299926 20401 group.cpp:775] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0) I0211 21:18:05.299936 20401 group.cpp:382] Trying to create path '/znode' in ZooKeeper 2014-02-11 21:18:05,307:20373(0x2b1c74401700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:60204], sessionId=0x14422d04a4a0009, negotiated timeout=10000 I0211 21:18:05.307950 20398 group.cpp:310] Group process ((1900)@67.195.138.9:60912) connected to ZooKeeper I0211 21:18:05.307968 20398 group.cpp:775] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0) I0211 21:18:05.307976 20398 group.cpp:382] Trying to create path '/znode' in ZooKeeper I0211 21:18:05.308604 20399 detector.cpp:134] Detected a new leader: (id='2') I0211 21:18:05.308797 20403 group.cpp:652] Trying to get '/znode/info_0000000002' in ZooKeeper I0211 21:18:05.309306 20404 detector.cpp:134] Detected a new leader: (id='2') I0211 21:18:05.309463 20401 group.cpp:652] Trying to get '/znode/info_0000000002' in ZooKeeper I0211 21:18:05.309814 20404 detector.cpp:377] A new leading master ([email protected]:60912) is detected I0211 21:18:05.309923 20403 slave.cpp:508] New master detected at [email protected]:60912 I0211 21:18:05.310027 20404 status_update_manager.cpp:162] New master detected at [email protected]:60912 I0211 21:18:05.310063 20403 slave.cpp:533] Detecting new master I0211 21:18:05.310098 20398 detector.cpp:377] A new leading master ([email protected]:60912) is detected I0211 21:18:05.310153 20404 master.cpp:1840] Attempting to register slave on vesta.apache.org at slave(143)@67.195.138.9:60912 I0211 21:18:05.310173 20403 sched.cpp:217] New master detected at [email protected]:60912 I0211 21:18:05.310189 20403 sched.cpp:268] Authenticating with master [email protected]:60912 I0211 21:18:05.310166 20404 master.cpp:2810] Adding slave 2014-02-11-21:18:05-160088899-60912-20373-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] I0211 21:18:05.310235 20403 sched.cpp:237] Detecting new master I0211 21:18:05.310248 20398 authenticatee.hpp:124] Creating new client SASL connection I0211 21:18:05.310292 20401 slave.cpp:551] Registered with master [email protected]:60912; given slave ID 2014-02-11-21:18:05-160088899-60912-20373-0 I0211 21:18:05.310369 20404 master.cpp:2323] Authenticating framework at scheduler(136)@67.195.138.9:60912 I0211 21:18:05.310417 20398 hierarchical_allocator_process.hpp:445] Added slave 2014-02-11-21:18:05-160088899-60912-20373-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) I0211 21:18:05.310474 20399 authenticator.hpp:140] Creating new server SASL connection I0211 21:18:05.310487 20398 hierarchical_allocator_process.hpp:708] Performed allocation for slave 2014-02-11-21:18:05-160088899-60912-20373-0 in 11160ns I0211 21:18:05.310577 20403 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5 I0211 21:18:05.310601 20403 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5' I0211 21:18:05.310632 20403 authenticator.hpp:243] Received SASL authentication start I0211 21:18:05.310699 20403 authenticator.hpp:325] Authentication requires more steps I0211 21:18:05.310734 20403 authenticatee.hpp:258] Received SASL authentication step I0211 21:18:05.310781 20403 authenticator.hpp:271] Received SASL authentication step I0211 21:18:05.310807 20403 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 I0211 21:18:05.310816 20403 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0211 21:18:05.310830 20403 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0211 21:18:05.310842 20403 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 I0211 21:18:05.310848 20403 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0211 21:18:05.310854 20403 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0211 21:18:05.310866 20403 authenticator.hpp:317] Authentication success I0211 21:18:05.310924 20399 authenticatee.hpp:298] Authentication success I0211 21:18:05.310940 20403 master.cpp:2363] Successfully authenticated framework at scheduler(136)@67.195.138.9:60912 I0211 21:18:05.311072 20399 sched.cpp:342] Successfully authenticated with master [email protected]:60912 I0211 21:18:05.311148 20404 master.cpp:818] Received registration request from scheduler(136)@67.195.138.9:60912 I0211 21:18:05.311213 20404 master.cpp:836] Registering framework 2014-02-11-21:18:05-160088899-60912-20373-0000 at scheduler(136)@67.195.138.9:60912 I0211 21:18:05.311290 20399 sched.cpp:391] Framework registered with 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.311310 20404 hierarchical_allocator_process.hpp:332] Added framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.311316 20399 sched.cpp:405] Scheduler::registered took 10649ns I0211 21:18:05.311367 20404 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:18:05-160088899-60912-20373-0 to framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.311491 20404 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 168396ns I0211 21:18:05.311548 20404 master.hpp:439] Adding offer 2014-02-11-21:18:05-160088899-60912-20373-0 with resources cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:18:05-160088899-60912-20373-0 (vesta.apache.org) I0211 21:18:05.311609 20404 master.cpp:2278] Sending 1 offers to framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.311883 20404 sched.cpp:525] Scheduler::resourceOffers took 170513ns I0211 21:18:05.312036 20404 master.hpp:449] Removing offer 2014-02-11-21:18:05-160088899-60912-20373-0 with resources cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:18:05-160088899-60912-20373-0 (vesta.apache.org) I0211 21:18:05.312083 20404 master.cpp:1574] Processing reply for offers: [ 2014-02-11-21:18:05-160088899-60912-20373-0 ] on slave 2014-02-11-21:18:05-160088899-60912-20373-0 (vesta.apache.org) for framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.312160 20404 master.hpp:411] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 2014-02-11-21:18:05-160088899-60912-20373-0 (vesta.apache.org) I0211 21:18:05.312186 20404 master.cpp:2447] Launching task 0 of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 with resources cpus(*):1; mem(*):500 on slave 2014-02-11-21:18:05-160088899-60912-20373-0 (vesta.apache.org) I0211 21:18:05.312310 20404 slave.cpp:736] Got assigned task 0 for framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.312485 20404 slave.cpp:845] Launching task 0 for framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.314120 20404 slave.cpp:955] Queuing task '0' for executor default of framework '2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.314177 20404 hierarchical_allocator_process.hpp:547] Framework 2014-02-11-21:18:05-160088899-60912-20373-0000 left cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] unused on slave 2014-02-11-21:18:05-160088899-60912-20373-0 I0211 21:18:05.314282 20404 hierarchical_allocator_process.hpp:590] Framework 2014-02-11-21:18:05-160088899-60912-20373-0000 filtered slave 2014-02-11-21:18:05-160088899-60912-20373-0 for 5secs I0211 21:18:05.314334 20399 slave.cpp:469] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_9Rww9K/slaves/2014-02-11-21:18:05-160088899-60912-20373-0/frameworks/2014-02-11-21:18:05-160088899-60912-20373-0000/executors/default/runs/6edb86d4-9853-42f2-99ff-87a89f14e3c6' I0211 21:18:05.315659 20400 exec.cpp:131] Version: 0.18.0 I0211 21:18:05.315732 20404 exec.cpp:181] Executor started at: executor(46)@67.195.138.9:60912 with pid 20373 I0211 21:18:05.315803 20402 slave.cpp:2098] Monitoring executor default of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 forked at pid 20373 I0211 21:18:05.315871 20402 slave.cpp:1431] Got registration for executor 'default' of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.316100 20402 slave.cpp:1552] Flushing queued task 0 for executor 'default' of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.316138 20399 exec.cpp:205] Executor registered on slave 2014-02-11-21:18:05-160088899-60912-20373-0 I0211 21:18:05.317487 20399 exec.cpp:217] Executor::registered took 10848ns I0211 21:18:05.317571 20399 exec.cpp:292] Executor asked to run task '0' I0211 21:18:05.317615 20399 exec.cpp:301] Executor::launchTask took 26780ns I0211 21:18:05.318840 20399 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: 0cc0a238-9721-408c-9d04-2a460ee310f7) for task 0 of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.318958 20399 slave.cpp:1765] Handling status update TASK_RUNNING (UUID: 0cc0a238-9721-408c-9d04-2a460ee310f7) for task 0 of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 from executor(46)@67.195.138.9:60912 I0211 21:18:05.319063 20398 status_update_manager.cpp:314] Received status update TASK_RUNNING (UUID: 0cc0a238-9721-408c-9d04-2a460ee310f7) for task 0 of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.319097 20398 status_update_manager.cpp:493] Creating StatusUpdate stream for task 0 of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.319165 20398 status_update_manager.cpp:367] Forwarding status update TASK_RUNNING (UUID: 0cc0a238-9721-408c-9d04-2a460ee310f7) for task 0 of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 to [email protected]:60912 I0211 21:18:05.319291 20403 slave.cpp:1884] Status update manager successfully handled status update TASK_RUNNING (UUID: 0cc0a238-9721-408c-9d04-2a460ee310f7) for task 0 of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.319295 20399 master.cpp:2026] Status update TASK_RUNNING (UUID: 0cc0a238-9721-408c-9d04-2a460ee310f7) for task 0 of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 from slave(143)@67.195.138.9:60912 I0211 21:18:05.319329 20403 slave.cpp:1890] Sending acknowledgement for status update TASK_RUNNING (UUID: 0cc0a238-9721-408c-9d04-2a460ee310f7) for task 0 of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 to executor(46)@67.195.138.9:60912 I0211 21:18:05.319398 20402 exec.cpp:338] Executor received status update acknowledgement 0cc0a238-9721-408c-9d04-2a460ee310f7 for task 0 of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.319422 20404 sched.cpp:616] Scheduler::statusUpdate took 29839ns I0211 21:18:05.319648 20373 master.cpp:587] Master terminating I0211 21:18:05.319672 20404 status_update_manager.cpp:392] Received status update acknowledgement (UUID: 0cc0a238-9721-408c-9d04-2a460ee310f7) for task 0 of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.319687 20373 master.cpp:247] Shutting down master I0211 21:18:05.319704 20402 slave.cpp:1965] [email protected]:60912 exited W0211 21:18:05.319716 20402 slave.cpp:1968] Master disconnected! Waiting for a new master to be elected I0211 21:18:05.319744 20373 master.hpp:429] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 2014-02-11-21:18:05-160088899-60912-20373-0 (vesta.apache.org) I0211 21:18:05.319774 20401 slave.cpp:1371] Status update manager successfully handled status update acknowledgement (UUID: 0cc0a238-9721-408c-9d04-2a460ee310f7) for task 0 of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.319834 20373 master.cpp:290] Removing slave 2014-02-11-21:18:05-160088899-60912-20373-0 (vesta.apache.org) I0211 21:18:05.319972 20404 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 2014-02-11-21:18:05-160088899-60912-20373-0 from framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:05.444697 20400 contender.cpp:182] Now cancelling the membership: 2 I0211 21:18:05.444866 20398 group.cpp:613] Trying to remove '/znode/info_0000000002' in ZooKeeper 2014-02-11 21:18:05,499:20373(0x2b1b17178b00):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x14422d04a4a0007 to [127.0.0.1:60204] I0211 21:18:05.499738 20397 detector.cpp:122] The current leader (id=2) is lost I0211 21:18:05.499755 20397 detector.cpp:134] Detected a new leader: None I0211 21:18:05.499907 20397 detector.cpp:122] The current leader (id=2) is lost I0211 21:18:05.499924 20397 detector.cpp:134] Detected a new leader: None I0211 21:18:05.500010 20402 slave.cpp:529] Lost leading master I0211 21:18:05.500035 20402 slave.cpp:533] Detecting new master I0211 21:18:05.500141 20397 detector.cpp:122] The current leader (id=2) is lost I0211 21:18:05.500156 20397 detector.cpp:134] Detected a new leader: None I0211 21:18:05.500365 20397 sched.cpp:211] Scheduler::disconnected took 9888ns I0211 21:18:05.500383 20397 sched.cpp:233] No master detected I0211 21:18:05.500392 20397 sched.cpp:237] Detecting new master 2014-02-11 21:18:05,500:20373(0x2b1b17178b00):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x14422d04a4a0006 to [127.0.0.1:60204] 2014-02-11 21:18:05,501:20373(0x2b1b1737e700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5 2014-02-11 21:18:05,501:20373(0x2b1b1737e700):ZOO_INFO@log_env@716: Client environment:host.name=vesta.apache.org 2014-02-11 21:18:05,501:20373(0x2b1b1737e700):ZOO_INFO@log_env@723: Client environment:os.name=Linux 2014-02-11 21:18:05,501:20373(0x2b1b1737e700):ZOO_INFO@log_env@724: Client environment:os.arch=3.2.0-51-generic 2014-02-11 21:18:05,501:20373(0x2b1b1737e700):ZOO_INFO@log_env@725: Client environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013 2014-02-11 21:18:05,501:20373(0x2b1b17780700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5 2014-02-11 21:18:05,501:20373(0x2b1b17780700):ZOO_INFO@log_env@716: Client environment:host.name=vesta.apache.org 2014-02-11 21:18:05,501:20373(0x2b1b1737e700):ZOO_INFO@log_env@733: Client environment:user.name=(null) 2014-02-11 21:18:05,501:20373(0x2b1b17780700):ZOO_INFO@log_env@723: Client environment:os.name=Linux 2014-02-11 21:18:05,501:20373(0x2b1b17780700):ZOO_INFO@log_env@724: Client environment:os.arch=3.2.0-51-generic I0211 21:18:05.501672 20373 master.cpp:240] Master ID: 2014-02-11-21:18:05-160088899-60912-20373 Hostname: vesta.apache.org 2014-02-11 21:18:05,501:20373(0x2b1b1737e700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins 2014-02-11 21:18:05,501:20373(0x2b1b17780700):ZOO_INFO@log_env@725: Client environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013 2014-02-11 21:18:05,501:20373(0x2b1b1737e700):ZOO_INFO@log_env@753: Client environment:user.dir=/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src 2014-02-11 21:18:05,501:20373(0x2b1b1737e700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:60204 sessionTimeout=10000 watcher=0x2b1b104268a0 sessionId=0 sessionPasswd=<null> context=0x2b1b3c021f70 flags=0 I0211 21:18:05.501799 20404 master.cpp:322] Master started on 67.195.138.9:60912 I0211 21:18:05.501852 20404 master.cpp:325] Master only allowing authenticated frameworks to register! 2014-02-11 21:18:05,501:20373(0x2b1b17780700):ZOO_INFO@log_env@733: Client environment:user.name=(null) 2014-02-11 21:18:05,502:20373(0x2b1b17780700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins 2014-02-11 21:18:05,502:20373(0x2b1b17780700):ZOO_INFO@log_env@753: Client environment:user.dir=/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src 2014-02-11 21:18:05,502:20373(0x2b1b17780700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:60204 sessionTimeout=10000 watcher=0x2b1b104268a0 sessionId=0 sessionPasswd=<null> context=0x2b1b24051670 flags=0 I0211 21:18:05.502224 20400 master.cpp:86] No whitelist given. Advertising offers for all slaves 2014-02-11 21:18:05,502:20373(0x2b1c35fd5700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:60204] I0211 21:18:05.502512 20403 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : [email protected]:60912 2014-02-11 21:18:05,502:20373(0x2b1c34fb6700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:60204] I0211 21:18:05.502739 20397 contender.cpp:127] Joining the ZK group 2014-02-11 21:18:05,539:20373(0x2b1c35fd5700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:60204], sessionId=0x14422d04a4a000a, negotiated timeout=10000 I0211 21:18:05.539362 20404 group.cpp:310] Group process ((1905)@67.195.138.9:60912) connected to ZooKeeper I0211 21:18:05.539396 20404 group.cpp:775] Syncing group operations: queue size (joins, cancels, datas) = (1, 0, 0) I0211 21:18:05.539404 20404 group.cpp:382] Trying to create path '/znode' in ZooKeeper 2014-02-11 21:18:05,539:20373(0x2b1c34fb6700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:60204], sessionId=0x14422d04a4a000b, negotiated timeout=10000 I0211 21:18:05.539824 20402 group.cpp:310] Group process ((1907)@67.195.138.9:60912) connected to ZooKeeper I0211 21:18:05.539840 20402 group.cpp:775] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0) I0211 21:18:05.539847 20402 group.cpp:382] Trying to create path '/znode' in ZooKeeper I0211 21:18:05.555068 20399 contender.cpp:243] New candidate (id='3') has entered the contest for leadership I0211 21:18:05.555323 20399 detector.cpp:134] Detected a new leader: (id='3') I0211 21:18:05.555448 20399 group.cpp:652] Trying to get '/znode/info_0000000003' in ZooKeeper I0211 21:18:05.555734 20402 detector.cpp:134] Detected a new leader: (id='3') I0211 21:18:05.555868 20402 group.cpp:652] Trying to get '/znode/info_0000000003' in ZooKeeper I0211 21:18:05.556220 20397 detector.cpp:134] Detected a new leader: (id='3') I0211 21:18:05.556399 20403 group.cpp:652] Trying to get '/znode/info_0000000003' in ZooKeeper I0211 21:18:05.556650 20402 detector.cpp:377] A new leading master ([email protected]:60912) is detected I0211 21:18:05.556740 20402 sched.cpp:217] New master detected at [email protected]:60912 I0211 21:18:05.556762 20402 sched.cpp:268] Authenticating with master [email protected]:60912 I0211 21:18:05.556790 20399 detector.cpp:377] A new leading master ([email protected]:60912) is detected I0211 21:18:05.556809 20402 sched.cpp:237] Detecting new master I0211 21:18:05.556860 20399 authenticatee.hpp:124] Creating new client SASL connection I0211 21:18:05.556957 20402 master.cpp:760] The newly elected leader is [email protected]:60912 with id 2014-02-11-21:18:05-160088899-60912-20373 I0211 21:18:05.556977 20402 master.cpp:770] Elected as the leading master! I0211 21:18:05.557096 20402 master.cpp:2323] Authenticating framework at scheduler(136)@67.195.138.9:60912 I0211 21:18:05.557168 20399 authenticator.hpp:140] Creating new server SASL connection I0211 21:18:05.557245 20402 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5 I0211 21:18:05.557267 20402 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5' I0211 21:18:05.557293 20403 detector.cpp:377] A new leading master ([email protected]:60912) is detected I0211 21:18:05.557296 20402 authenticator.hpp:243] Received SASL authentication start I0211 21:18:05.557348 20403 slave.cpp:508] New master detected at [email protected]:60912 I0211 21:18:05.557389 20402 authenticator.hpp:325] Authentication requires more steps I0211 21:18:05.557411 20402 status_update_manager.cpp:162] New master detected at [email protected]:60912 I0211 21:18:05.557448 20402 authenticatee.hpp:258] Received SASL authentication step I0211 21:18:05.557492 20403 slave.cpp:533] Detecting new master I0211 21:18:05.557550 20399 authenticator.hpp:271] Received SASL authentication step I0211 21:18:05.557580 20399 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 I0211 21:18:05.557590 20399 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0211 21:18:05.557595 20402 master.cpp:1929] Attempting to re-register slave 2014-02-11-21:18:05-160088899-60912-20373-0 at slave(143)@67.195.138.9:60912 (vesta.apache.org) I0211 21:18:05.557605 20399 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0211 21:18:05.557615 20399 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 I0211 21:18:05.557622 20399 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0211 21:18:05.557605 20402 master.cpp:2810] Adding slave 2014-02-11-21:18:05-160088899-60912-20373-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] I0211 21:18:05.557627 20399 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0211 21:18:05.557651 20399 authenticator.hpp:317] Authentication success I0211 21:18:05.557695 20399 authenticatee.hpp:298] Authentication success I0211 21:18:05.557700 20402 master.hpp:411] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 2014-02-11-21:18:05-160088899-60912-20373-0 (vesta.apache.org) W0211 21:18:05.557739 20402 master.cpp:2905] Possibly orphaned task 0 of framework 2014-02-11-21:18:05-160088899-60912-20373-0000 running on slave 2014-02-11-21:18:05-160088899-60912-20373-0 (vesta.apache.org) I0211 21:18:05.557760 20399 sched.cpp:342] Successfully authenticated with master [email protected]:60912 I0211 21:18:05.557858 20402 master.cpp:2363] Successfully authenticated framework at scheduler(136)@67.195.138.9:60912 I0211 21:18:05.557972 20399 hierarchical_allocator_process.hpp:445] Added slave 2014-02-11-21:18:05-160088899-60912-20373-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) I0211 21:18:05.558022 20399 hierarchical_allocator_process.hpp:708] Performed allocation for slave 2014-02-11-21:18:05-160088899-60912-20373-0 in 14573ns I0211 21:18:05.558145 20403 slave.cpp:601] Re-registered with master [email protected]:60912 I0211 21:18:06.311724 20399 master.cpp:906] Re-registering framework 2014-02-11-21:18:05-160088899-60912-20373-0000 at scheduler(136)@67.195.138.9:60912 I0211 21:18:06.311882 20399 sched.cpp:391] Framework registered with 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:06.311918 20399 sched.cpp:405] Scheduler::registered took 19304ns I0211 21:18:06.311939 20399 slave.cpp:1312] Updating framework 2014-02-11-21:18:05-160088899-60912-20373-0000 pid to scheduler(136)@67.195.138.9:60912 I0211 21:18:06.312180 20400 hierarchical_allocator_process.hpp:332] Added framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:06.312268 20400 hierarchical_allocator_process.hpp:752] Offering cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:18:05-160088899-60912-20373-0 to framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:06.312429 20400 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 208531ns I0211 21:18:06.312536 20401 master.hpp:439] Adding offer 2014-02-11-21:18:05-160088899-60912-20373-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:18:05-160088899-60912-20373-0 (vesta.apache.org) I0211 21:18:06.312634 20401 master.cpp:2278] Sending 1 offers to framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:06.312793 20399 sched.cpp:525] Scheduler::resourceOffers took 28903ns I0211 21:18:06.313040 20403 sched.cpp:727] Stopping framework '2014-02-11-21:18:05-160088899-60912-20373-0000' I0211 21:18:06.313050 20373 master.cpp:587] Master terminating I0211 21:18:06.313176 20373 master.cpp:247] Shutting down master I0211 21:18:06.313192 20397 slave.cpp:1965] [email protected]:60912 exited W0211 21:18:06.313207 20397 slave.cpp:1968] Master disconnected! Waiting for a new master to be elected I0211 21:18:06.313236 20373 master.hpp:429] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 2014-02-11-21:18:05-160088899-60912-20373-0 (vesta.apache.org) I0211 21:18:06.313345 20373 master.hpp:449] Removing offer 2014-02-11-21:18:05-160088899-60912-20373-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-02-11-21:18:05-160088899-60912-20373-0 (vesta.apache.org) I0211 21:18:06.313462 20373 master.cpp:290] Removing slave 2014-02-11-21:18:05-160088899-60912-20373-0 (vesta.apache.org) I0211 21:18:06.313473 20402 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave 2014-02-11-21:18:05-160088899-60912-20373-0 from framework 2014-02-11-21:18:05-160088899-60912-20373-0000 I0211 21:18:06.313982 20373 contender.cpp:182] Now cancelling the membership: 3 I0211 21:18:06.314074 20397 group.cpp:613] Trying to remove '/znode/info_0000000003' in ZooKeeper I0211 21:18:06.326462 20402 detector.cpp:122] The current leader (id=3) is lost I0211 21:18:06.326486 20402 detector.cpp:134] Detected a new leader: None 2014-02-11 21:18:06,326:20373(0x2b1b17178b00):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x14422d04a4a000a to [127.0.0.1:60204] I0211 21:18:06.326690 20398 detector.cpp:122] The current leader (id=3) is lost I0211 21:18:06.326711 20398 detector.cpp:134] Detected a new leader: None I0211 21:18:06.326745 20400 detector.cpp:122] The current leader (id=3) is lost 2014-02-11 21:18:06,327:20373(0x2b1b17178b00):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x14422d04a4a000b to [127.0.0.1:60204] I0211 21:18:06.326963 20402 slave.cpp:529] Lost leading master I0211 21:18:06.327065 20400 detector.cpp:134] Detected a new leader: None I0211 21:18:06.327100 20402 slave.cpp:533] Detecting new master I0211 21:18:06.327154 20402 slave.cpp:394] Slave terminating I0211 21:18:06.327193 20402 slave.cpp:1142] Asked to shut down framework 2014-02-11-21:18:05-160088899-60912-20373-0000 by @0.0.0.0:0 W0211 21:18:06.327214 20402 slave.cpp:1150] Ignoring shutdown framework message for 2014-02-11-21:18:05-160088899-60912-20373-0000 because the slave has not yet registered with the master I0211 21:18:06.327256 20402 exec.cpp:458] Slave exited ... shutting down I0211 21:18:06.327294 20402 exec.cpp:475] Executor::shutdown took 17539ns 2014-02-11 21:18:06,327:20373(0x2b1b17178b00):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x14422d04a4a0008 to [127.0.0.1:60204] 2014-02-11 21:18:06,328:20373(0x2b1b17178b00):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x14422d04a4a0009 to [127.0.0.1:60204] [ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (1061 ms) I0211 21:18:06.339318 20373 zookeeper_test_server.cpp:122] Shutdown ZooKeeperTestServer on port 60204 [----------] 2 tests from AllocatorZooKeeperTest/0 (6574 ms total) [----------] Global test environment tear-down [==========] 258 tests from 46 test cases ran. (213734 ms total) [ PASSED ] 257 tests. [ FAILED ] 1 test, listed below: [ FAILED ] ExamplesTest.PythonFramework 1 FAILED TEST YOU HAVE 2 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
