See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/1933/changes>
Changes: [vinod] Updated dash in front of flags for tar command in fetcher. ------------------------------------------ [...truncated 26133 lines...] 2014-03-03 19:51:21,553:9813(0x2b22e1ff8700):ZOO_INFO@log_env@733: Client environment:user.name=(null) 2014-03-03 19:51:21,553:9813(0x2b22e1ff8700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins 2014-03-03 19:51:21,553:9813(0x2b22e1ff8700):ZOO_INFO@log_env@753: Client environment:user.dir=/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src 2014-03-03 19:51:21,553:9813(0x2b22e1ff8700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:35684 sessionTimeout=10000 watcher=0x2b22def7c620 sessionId=0 sessionPasswd=<null> context=0x2b22e4030510 flags=0 I0303 19:51:21.553370 9839 state.cpp:33] Recovering state from '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_aIwxDm/meta' 2014-03-03 19:51:21,553:9813(0x2b23fe1f9700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:35684] I0303 19:51:21.553586 9839 status_update_manager.cpp:193] Recovering status update manager 2014-03-03 19:51:21,553:9813(0x2b23fd7bc700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:35684] I0303 19:51:21.553792 9836 slave.cpp:2710] Finished recovery 2014-03-03 19:51:21,573:9813(0x2b23fe1f9700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:35684], sessionId=0x144898023580008, negotiated timeout=10000 I0303 19:51:21.573262 9833 group.cpp:310] Group process ((2261)@67.195.138.9:57972) connected to ZooKeeper I0303 19:51:21.573318 9833 group.cpp:778] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0) I0303 19:51:21.573326 9833 group.cpp:382] Trying to create path '/znode' in ZooKeeper 2014-03-03 19:51:21,584:9813(0x2b23fd7bc700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:35684], sessionId=0x144898023580009, negotiated timeout=10000 I0303 19:51:21.584229 9834 group.cpp:310] Group process ((2267)@67.195.138.9:57972) connected to ZooKeeper I0303 19:51:21.584272 9834 group.cpp:778] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0) I0303 19:51:21.584286 9834 group.cpp:382] Trying to create path '/znode' in ZooKeeper I0303 19:51:21.585268 9835 detector.cpp:134] Detected a new leader: (id='2') I0303 19:51:21.585489 9833 group.cpp:655] Trying to get '/znode/info_0000000002' in ZooKeeper I0303 19:51:21.585907 9835 detector.cpp:134] Detected a new leader: (id='2') I0303 19:51:21.586088 9835 group.cpp:655] Trying to get '/znode/info_0000000002' in ZooKeeper I0303 19:51:21.586385 9838 detector.cpp:377] A new leading master ([email protected]:57972) is detected I0303 19:51:21.586527 9833 slave.cpp:404] New master detected at [email protected]:57972 I0303 19:51:21.586590 9838 status_update_manager.cpp:167] New master detected at [email protected]:57972 I0303 19:51:21.586637 9833 slave.cpp:429] Detecting new master I0303 19:51:21.586690 9838 master.cpp:1858] Attempting to register slave on vesta.apache.org at slave(143)@67.195.138.9:57972 I0303 19:51:21.586719 9838 master.cpp:2842] Adding slave 2014-03-03-19:51:21-160088899-57972-9813-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] I0303 19:51:21.586848 9833 slave.cpp:447] Registered with master [email protected]:57972; given slave ID 2014-03-03-19:51:21-160088899-57972-9813-0 I0303 19:51:21.586995 9836 hierarchical_allocator_process.hpp:445] Added slave 2014-03-03-19:51:21-160088899-57972-9813-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) I0303 19:51:21.587050 9836 hierarchical_allocator_process.hpp:708] Performed allocation for slave 2014-03-03-19:51:21-160088899-57972-9813-0 in 10177ns I0303 19:51:21.586854 9835 detector.cpp:377] A new leading master ([email protected]:57972) is detected I0303 19:51:21.587170 9838 sched.cpp:217] New master detected at [email protected]:57972 I0303 19:51:21.587193 9838 sched.cpp:267] Authenticating with master [email protected]:57972 I0303 19:51:21.587282 9835 authenticatee.hpp:128] Creating new client SASL connection I0303 19:51:21.587424 9838 master.cpp:2355] Authenticating framework at scheduler(136)@67.195.138.9:57972 I0303 19:51:21.587532 9839 authenticator.hpp:148] Creating new server SASL connection I0303 19:51:21.587625 9835 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I0303 19:51:21.587645 9835 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I0303 19:51:21.587682 9835 authenticator.hpp:254] Received SASL authentication start I0303 19:51:21.587759 9835 authenticator.hpp:342] Authentication requires more steps I0303 19:51:21.587818 9835 authenticatee.hpp:265] Received SASL authentication step I0303 19:51:21.587874 9835 authenticator.hpp:282] Received SASL authentication step I0303 19:51:21.587899 9835 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 I0303 19:51:21.587908 9835 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0303 19:51:21.587921 9835 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0303 19:51:21.587931 9835 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 I0303 19:51:21.587939 9835 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0303 19:51:21.587942 9835 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0303 19:51:21.587954 9835 authenticator.hpp:334] Authentication success I0303 19:51:21.587999 9835 authenticatee.hpp:305] Authentication success I0303 19:51:21.588019 9833 master.cpp:2395] Successfully authenticated framework at scheduler(136)@67.195.138.9:57972 I0303 19:51:21.588120 9835 sched.cpp:341] Successfully authenticated with master [email protected]:57972 I0303 19:51:21.588140 9835 sched.cpp:460] Sending registration request to [email protected]:57972 I0303 19:51:21.588212 9833 master.cpp:829] Received registration request from scheduler(136)@67.195.138.9:57972 I0303 19:51:21.588240 9833 master.cpp:847] Registering framework 2014-03-03-19:51:21-160088899-57972-9813-0000 at scheduler(136)@67.195.138.9:57972 I0303 19:51:21.588330 9838 sched.cpp:391] Framework registered with 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.588359 9838 sched.cpp:405] Scheduler::registered took 10041ns I0303 19:51:21.588361 9839 hierarchical_allocator_process.hpp:332] Added framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.588418 9839 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-03-03-19:51:21-160088899-57972-9813-0 to framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.588557 9839 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 180856ns I0303 19:51:21.588634 9833 master.hpp:456] Adding offer 2014-03-03-19:51:21-160088899-57972-9813-0 with resources cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-03-03-19:51:21-160088899-57972-9813-0 (vesta.apache.org) I0303 19:51:21.588691 9833 master.cpp:2310] Sending 1 offers to framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.588986 9836 sched.cpp:528] Scheduler::resourceOffers took 174152ns I0303 19:51:21.589184 9833 master.hpp:466] Removing offer 2014-03-03-19:51:21-160088899-57972-9813-0 with resources cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-03-03-19:51:21-160088899-57972-9813-0 (vesta.apache.org) I0303 19:51:21.589234 9833 master.cpp:1585] Processing reply for offers: [ 2014-03-03-19:51:21-160088899-57972-9813-0 ] on slave 2014-03-03-19:51:21-160088899-57972-9813-0 (vesta.apache.org) for framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.589318 9833 master.hpp:428] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 2014-03-03-19:51:21-160088899-57972-9813-0 (vesta.apache.org) I0303 19:51:21.589344 9833 master.cpp:2479] Launching task 0 of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 with resources cpus(*):1; mem(*):500 on slave 2014-03-03-19:51:21-160088899-57972-9813-0 (vesta.apache.org) I0303 19:51:21.589426 9836 slave.cpp:665] Got assigned task 0 for framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.589488 9833 hierarchical_allocator_process.hpp:547] Framework 2014-03-03-19:51:21-160088899-57972-9813-0000 left cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] unused on slave 2014-03-03-19:51:21-160088899-57972-9813-0 I0303 19:51:21.589593 9833 hierarchical_allocator_process.hpp:590] Framework 2014-03-03-19:51:21-160088899-57972-9813-0000 filtered slave 2014-03-03-19:51:21-160088899-57972-9813-0 for 5secs I0303 19:51:21.589612 9836 slave.cpp:774] Launching task 0 for framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.605667 9836 exec.cpp:131] Version: 0.19.0 I0303 19:51:21.605767 9834 exec.cpp:181] Executor started at: executor(47)@67.195.138.9:57972 with pid 9813 I0303 19:51:21.605801 9836 slave.cpp:884] Queuing task '0' for executor default of framework '2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.605875 9836 slave.cpp:365] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_aIwxDm/slaves/2014-03-03-19:51:21-160088899-57972-9813-0/frameworks/2014-03-03-19:51:21-160088899-57972-9813-0000/executors/default/runs/ff4d77bb-7cf5-4ac2-a56a-709398169df0' I0303 19:51:21.605901 9836 slave.cpp:2029] Monitoring executor 'default' of framework '2014-03-03-19:51:21-160088899-57972-9813-0000' in container 'ff4d77bb-7cf5-4ac2-a56a-709398169df0' I0303 19:51:21.605963 9836 slave.cpp:1356] Got registration for executor 'default' of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.606128 9836 slave.cpp:1474] Flushing queued task 0 for executor 'default' of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.606154 9835 exec.cpp:205] Executor registered on slave 2014-03-03-19:51:21-160088899-57972-9813-0 I0303 19:51:21.607411 9835 exec.cpp:217] Executor::registered took 15511ns I0303 19:51:21.607480 9835 exec.cpp:292] Executor asked to run task '0' I0303 19:51:21.607516 9835 exec.cpp:301] Executor::launchTask took 20456ns I0303 19:51:21.608743 9835 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: d2742626-f337-4be6-bb8b-a791918c0db6) for task 0 of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.608841 9839 slave.cpp:1683] Handling status update TASK_RUNNING (UUID: d2742626-f337-4be6-bb8b-a791918c0db6) for task 0 of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 from executor(47)@67.195.138.9:57972 I0303 19:51:21.608932 9835 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: d2742626-f337-4be6-bb8b-a791918c0db6) for task 0 of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.608949 9835 status_update_manager.cpp:499] Creating StatusUpdate stream for task 0 of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.609015 9835 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING (UUID: d2742626-f337-4be6-bb8b-a791918c0db6) for task 0 of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 to [email protected]:57972 I0303 19:51:21.609097 9835 slave.cpp:1803] Status update manager successfully handled status update TASK_RUNNING (UUID: d2742626-f337-4be6-bb8b-a791918c0db6) for task 0 of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.609114 9835 slave.cpp:1809] Sending acknowledgement for status update TASK_RUNNING (UUID: d2742626-f337-4be6-bb8b-a791918c0db6) for task 0 of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 to executor(47)@67.195.138.9:57972 I0303 19:51:21.609117 9839 master.cpp:2042] Status update TASK_RUNNING (UUID: d2742626-f337-4be6-bb8b-a791918c0db6) for task 0 of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 from slave(143)@67.195.138.9:57972 I0303 19:51:21.609179 9835 exec.cpp:338] Executor received status update acknowledgement d2742626-f337-4be6-bb8b-a791918c0db6 for task 0 of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.609204 9839 sched.cpp:619] Scheduler::statusUpdate took 30175ns I0303 19:51:21.609313 9834 status_update_manager.cpp:398] Received status update acknowledgement (UUID: d2742626-f337-4be6-bb8b-a791918c0db6) for task 0 of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.609381 9834 slave.cpp:1296] Status update manager successfully handled status update acknowledgement (UUID: d2742626-f337-4be6-bb8b-a791918c0db6) for task 0 of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.609545 9813 master.cpp:528] Master terminating I0303 19:51:21.609588 9813 master.hpp:446] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 2014-03-03-19:51:21-160088899-57972-9813-0 (vesta.apache.org) I0303 19:51:21.609721 9839 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-03-03-19:51:21-160088899-57972-9813-0 from framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.609822 9833 slave.cpp:1884] [email protected]:57972 exited W0303 19:51:21.609837 9833 slave.cpp:1887] Master disconnected! Waiting for a new master to be elected I0303 19:51:21.644598 9813 contender.cpp:182] Now cancelling the membership: 2 I0303 19:51:21.644683 9835 group.cpp:616] Trying to remove '/znode/info_0000000002' in ZooKeeper 2014-03-03 19:51:21,656:9813(0x2b22e17f07c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x144898023580006 to [127.0.0.1:35684] 2014-03-03 19:51:21,656:9813(0x2b22e17f07c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x144898023580007 to [127.0.0.1:35684] I0303 19:51:21.657244 9813 master.cpp:252] Master ID: 2014-03-03-19:51:21-160088899-57972-9813 Hostname: vesta.apache.org 2014-03-03 19:51:21,657:9813(0x2b22e1bf6700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5 2014-03-03 19:51:21,657:9813(0x2b22e1bf6700):ZOO_INFO@log_env@716: Client environment:host.name=vesta.apache.org 2014-03-03 19:51:21,657:9813(0x2b22e1bf6700):ZOO_INFO@log_env@723: Client environment:os.name=Linux 2014-03-03 19:51:21,657:9813(0x2b22e1bf6700):ZOO_INFO@log_env@724: Client environment:os.arch=3.2.0-51-generic 2014-03-03 19:51:21,657:9813(0x2b22e1bf6700):ZOO_INFO@log_env@725: Client environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013 2014-03-03 19:51:21,657:9813(0x2b22e1df7700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5 2014-03-03 19:51:21,657:9813(0x2b22e1df7700):ZOO_INFO@log_env@716: Client environment:host.name=vesta.apache.org 2014-03-03 19:51:21,657:9813(0x2b22e1df7700):ZOO_INFO@log_env@723: Client environment:os.name=Linux 2014-03-03 19:51:21,657:9813(0x2b22e1df7700):ZOO_INFO@log_env@724: Client environment:os.arch=3.2.0-51-generic 2014-03-03 19:51:21,657:9813(0x2b22e1df7700):ZOO_INFO@log_env@725: Client environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013 2014-03-03 19:51:21,657:9813(0x2b22e1df7700):ZOO_INFO@log_env@733: Client environment:user.name=(null) I0303 19:51:21.657862 9837 master.cpp:262] Master started on 67.195.138.9:57972 I0303 19:51:21.657891 9837 master.cpp:265] Master only allowing authenticated frameworks to register! 2014-03-03 19:51:21,657:9813(0x2b22e1df7700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins 2014-03-03 19:51:21,657:9813(0x2b22e1df7700):ZOO_INFO@log_env@753: Client environment:user.dir=/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src 2014-03-03 19:51:21,657:9813(0x2b22e1df7700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:35684 sessionTimeout=10000 watcher=0x2b22def7c620 sessionId=0 sessionPasswd=<null> context=0x2b22fc0176b0 flags=0 I0303 19:51:21.657958 9839 detector.cpp:122] The current leader (id=2) is lost I0303 19:51:21.657971 9839 detector.cpp:134] Detected a new leader: None I0303 19:51:21.658041 9839 detector.cpp:122] The current leader (id=2) is lost I0303 19:51:21.658047 9839 detector.cpp:134] Detected a new leader: None 2014-03-03 19:51:21,657:9813(0x2b22e1bf6700):ZOO_INFO@log_env@733: Client environment:user.name=(null) 2014-03-03 19:51:21,658:9813(0x2b22e1bf6700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins 2014-03-03 19:51:21,658:9813(0x2b22e1bf6700):ZOO_INFO@log_env@753: Client environment:user.dir=/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src 2014-03-03 19:51:21,658:9813(0x2b22e1bf6700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:35684 sessionTimeout=10000 watcher=0x2b22def7c620 sessionId=0 sessionPasswd=<null> context=0x2b230401cd80 flags=0 I0303 19:51:21.658352 9839 master.cpp:96] No whitelist given. Advertising offers for all slaves I0303 19:51:21.658426 9837 slave.cpp:425] Lost leading master I0303 19:51:21.658435 9837 slave.cpp:429] Detecting new master I0303 19:51:21.658511 9832 contender.cpp:127] Joining the ZK group 2014-03-03 19:51:21,658:9813(0x2b23fddf7700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:35684] I0303 19:51:21.658699 9833 sched.cpp:211] Scheduler::disconnected took 28196ns I0303 19:51:21.658728 9833 sched.cpp:233] No master detected I0303 19:51:21.659028 9835 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : [email protected]:57972 2014-03-03 19:51:21,659:9813(0x2b23fd3ba700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:35684] 2014-03-03 19:51:21,680:9813(0x2b23fddf7700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:35684], sessionId=0x14489802358000a, negotiated timeout=10000 2014-03-03 19:51:21,680:9813(0x2b23fd3ba700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:35684], sessionId=0x14489802358000b, negotiated timeout=10000 I0303 19:51:21.680413 9837 group.cpp:310] Group process ((2272)@67.195.138.9:57972) connected to ZooKeeper I0303 19:51:21.680428 9837 group.cpp:778] Syncing group operations: queue size (joins, cancels, datas) = (1, 0, 0) I0303 19:51:21.680436 9837 group.cpp:382] Trying to create path '/znode' in ZooKeeper I0303 19:51:21.680470 9839 group.cpp:310] Group process ((2274)@67.195.138.9:57972) connected to ZooKeeper I0303 19:51:21.680501 9839 group.cpp:778] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0) I0303 19:51:21.680510 9839 group.cpp:382] Trying to create path '/znode' in ZooKeeper I0303 19:51:21.695996 9836 contender.cpp:243] New candidate (id='3') has entered the contest for leadership I0303 19:51:21.696038 9839 detector.cpp:134] Detected a new leader: (id='3') I0303 19:51:21.696118 9839 group.cpp:655] Trying to get '/znode/info_0000000003' in ZooKeeper I0303 19:51:21.696233 9832 detector.cpp:134] Detected a new leader: (id='3') I0303 19:51:21.696357 9832 group.cpp:655] Trying to get '/znode/info_0000000003' in ZooKeeper I0303 19:51:21.696676 9835 detector.cpp:134] Detected a new leader: (id='3') I0303 19:51:21.696799 9835 group.cpp:655] Trying to get '/znode/info_0000000003' in ZooKeeper I0303 19:51:21.696928 9837 detector.cpp:377] A new leading master ([email protected]:57972) is detected I0303 19:51:21.697001 9837 master.cpp:771] The newly elected leader is [email protected]:57972 with id 2014-03-03-19:51:21-160088899-57972-9813 I0303 19:51:21.697026 9837 master.cpp:781] Elected as the leading master! I0303 19:51:21.697139 9832 detector.cpp:377] A new leading master ([email protected]:57972) is detected I0303 19:51:21.697223 9834 slave.cpp:404] New master detected at [email protected]:57972 I0303 19:51:21.697320 9832 status_update_manager.cpp:167] New master detected at [email protected]:57972 I0303 19:51:21.697381 9834 slave.cpp:429] Detecting new master I0303 19:51:21.697469 9839 master.cpp:1953] Attempting to re-register slave 2014-03-03-19:51:21-160088899-57972-9813-0 at slave(143)@67.195.138.9:57972 (vesta.apache.org) I0303 19:51:21.697484 9839 master.cpp:2842] Adding slave 2014-03-03-19:51:21-160088899-57972-9813-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] I0303 19:51:21.697521 9834 detector.cpp:377] A new leading master ([email protected]:57972) is detected I0303 19:51:21.697571 9833 slave.cpp:497] Re-registered with master [email protected]:57972 I0303 19:51:21.697581 9834 sched.cpp:217] New master detected at [email protected]:57972 I0303 19:51:21.697576 9839 master.hpp:428] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 2014-03-03-19:51:21-160088899-57972-9813-0 (vesta.apache.org) I0303 19:51:21.697605 9834 sched.cpp:267] Authenticating with master [email protected]:57972 W0303 19:51:21.697621 9839 master.cpp:2938] Possibly orphaned task 0 of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 running on slave 2014-03-03-19:51:21-160088899-57972-9813-0 (vesta.apache.org) I0303 19:51:21.697654 9833 authenticatee.hpp:128] Creating new client SASL connection I0303 19:51:21.697757 9839 master.cpp:2355] Authenticating framework at scheduler(136)@67.195.138.9:57972 I0303 19:51:21.697851 9833 hierarchical_allocator_process.hpp:445] Added slave 2014-03-03-19:51:21-160088899-57972-9813-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) I0303 19:51:21.697902 9833 hierarchical_allocator_process.hpp:708] Performed allocation for slave 2014-03-03-19:51:21-160088899-57972-9813-0 in 8210ns I0303 19:51:21.697914 9839 authenticator.hpp:148] Creating new server SASL connection I0303 19:51:21.697993 9835 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I0303 19:51:21.698019 9835 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I0303 19:51:21.698045 9833 authenticator.hpp:254] Received SASL authentication start I0303 19:51:21.698133 9833 authenticator.hpp:342] Authentication requires more steps I0303 19:51:21.698161 9833 authenticatee.hpp:265] Received SASL authentication step I0303 19:51:21.698194 9833 authenticator.hpp:282] Received SASL authentication step I0303 19:51:21.698220 9833 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 I0303 19:51:21.698226 9833 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0303 19:51:21.698240 9833 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0303 19:51:21.698251 9833 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 I0303 19:51:21.698257 9833 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0303 19:51:21.698262 9833 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0303 19:51:21.698273 9833 authenticator.hpp:334] Authentication success I0303 19:51:21.698293 9835 authenticatee.hpp:305] Authentication success I0303 19:51:21.698298 9833 master.cpp:2395] Successfully authenticated framework at scheduler(136)@67.195.138.9:57972 I0303 19:51:21.698338 9835 sched.cpp:341] Successfully authenticated with master [email protected]:57972 I0303 19:51:21.698357 9835 sched.cpp:460] Sending registration request to [email protected]:57972 I0303 19:51:21.698396 9833 master.cpp:917] Re-registering framework 2014-03-03-19:51:21-160088899-57972-9813-0000 at scheduler(136)@67.195.138.9:57972 I0303 19:51:21.698493 9834 sched.cpp:391] Framework registered with 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.698513 9834 sched.cpp:405] Scheduler::registered took 10474ns I0303 19:51:21.698530 9834 slave.cpp:1237] Updating framework 2014-03-03-19:51:21-160088899-57972-9813-0000 pid to scheduler(136)@67.195.138.9:57972 I0303 19:51:21.698565 9833 hierarchical_allocator_process.hpp:332] Added framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.698601 9833 hierarchical_allocator_process.hpp:752] Offering cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-03-03-19:51:21-160088899-57972-9813-0 to framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.698725 9833 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 148689ns I0303 19:51:21.698763 9834 master.hpp:456] Adding offer 2014-03-03-19:51:21-160088899-57972-9813-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-03-03-19:51:21-160088899-57972-9813-0 (vesta.apache.org) I0303 19:51:21.698808 9834 master.cpp:2310] Sending 1 offers to framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.698897 9834 sched.cpp:528] Scheduler::resourceOffers took 18393ns I0303 19:51:21.699053 9832 sched.cpp:730] Stopping framework '2014-03-03-19:51:21-160088899-57972-9813-0000' I0303 19:51:21.699059 9813 master.cpp:528] Master terminating I0303 19:51:21.699123 9813 master.hpp:446] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 2014-03-03-19:51:21-160088899-57972-9813-0 (vesta.apache.org) I0303 19:51:21.699249 9813 master.hpp:466] Removing offer 2014-03-03-19:51:21-160088899-57972-9813-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 2014-03-03-19:51:21-160088899-57972-9813-0 (vesta.apache.org) I0303 19:51:21.699481 9839 slave.cpp:1884] [email protected]:57972 exited W0303 19:51:21.699497 9839 slave.cpp:1887] Master disconnected! Waiting for a new master to be elected I0303 19:51:21.699491 9836 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave 2014-03-03-19:51:21-160088899-57972-9813-0 from framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.770603 9813 contender.cpp:182] Now cancelling the membership: 3 I0303 19:51:21.770736 9832 group.cpp:616] Trying to remove '/znode/info_0000000003' in ZooKeeper 2014-03-03 19:51:21,783:9813(0x2b22e17f07c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x14489802358000a to [127.0.0.1:35684] 2014-03-03 19:51:21,783:9813(0x2b22e17f07c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x14489802358000b to [127.0.0.1:35684] I0303 19:51:21.784052 9813 slave.cpp:294] Slave terminating I0303 19:51:21.784087 9813 slave.cpp:1067] Asked to shut down framework 2014-03-03-19:51:21-160088899-57972-9813-0000 by @0.0.0.0:0 I0303 19:51:21.784097 9813 slave.cpp:1092] Shutting down framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.784112 9813 slave.cpp:2372] Shutting down executor 'default' of framework 2014-03-03-19:51:21-160088899-57972-9813-0000 I0303 19:51:21.784168 9835 exec.cpp:378] Executor asked to shutdown I0303 19:51:21.784201 9835 exec.cpp:393] Executor::shutdown took 20778ns I0303 19:51:21.784272 9839 detector.cpp:122] The current leader (id=3) is lost I0303 19:51:21.784307 9839 detector.cpp:134] Detected a new leader: None I0303 19:51:21.784337 9834 detector.cpp:122] The current leader (id=3) is lost I0303 19:51:21.784384 9834 detector.cpp:134] Detected a new leader: None 2014-03-03 19:51:21,784:9813(0x2b22e17f07c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x144898023580008 to [127.0.0.1:35684] 2014-03-03 19:51:21,785:9813(0x2b22e17f07c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x144898023580009 to [127.0.0.1:35684] [ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (285 ms) I0303 19:51:21.795384 9813 zookeeper_test_server.cpp:122] Shutdown ZooKeeperTestServer on port 35684 [----------] 2 tests from AllocatorZooKeeperTest/0 (1633 ms total) [----------] Global test environment tear-down [==========] 261 tests from 46 test cases ran. (267303 ms total) [ PASSED ] 260 tests. [ FAILED ] 1 test, listed below: [ FAILED ] ExamplesTest.PythonFramework 1 FAILED TEST YOU HAVE 1 DISABLED TEST make[3]: *** [check-local] Error 1 make[3]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src' make[2]: *** [check-am] Error 2 make[2]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src' make[1]: *** [check] Error 2 make[1]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src' make: *** [check-recursive] Error 1 Build step 'Execute shell' marked build as failure
