https://issues.apache.org/jira/browse/MESOS-988


@vinodkone


On Tue, Feb 11, 2014 at 1:18 PM, Apache Jenkins Server <
[email protected]> wrote:

> 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 (UPID=
> [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 (UPID=
> [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]:60912exited
> 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 (UPID=
> [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 (UPID=
> [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 (UPID=
> [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]:60912exited
> 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
>

Reply via email to