[
https://issues.apache.org/jira/browse/MESOS-1089?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Yan Xu resolved MESOS-1089.
---------------------------
Resolution: Cannot Reproduce
Superseded by MESOS-1532 which seems to be the latest symptom for this test.
> AllocatorZooKeeperTest/0.SlaveReregistersFirst is flaky
> -------------------------------------------------------
>
> Key: MESOS-1089
> URL: https://issues.apache.org/jira/browse/MESOS-1089
> Project: Mesos
> Issue Type: Bug
> Components: test
> Reporter: Yan Xu
>
> {code}
> [ RUN ] AllocatorZooKeeperTest/0.SlaveReregistersFirst
> 2014-03-12 19:43:17,315:18527(0x2b8793868700):ZOO_INFO@log_env@712: Client
> environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-03-12 19:43:17,315:18527(0x2b8792e63700):ZOO_INFO@log_env@712: Client
> environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-03-12 19:43:17,315:18527(0x2b8792e63700):ZOO_INFO@log_env@716: Client
> environment:host.name=juno
> 2014-03-12 19:43:17,315:18527(0x2b8792e63700):ZOO_INFO@log_env@723: Client
> environment:os.name=Linux
> 2014-03-12 19:43:17,315:18527(0x2b8792e63700):ZOO_INFO@log_env@724: Client
> environment:os.arch=3.2.0-51-generic
> 2014-03-12 19:43:17,315:18527(0x2b8792e63700):ZOO_INFO@log_env@725: Client
> environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013
> I0312 19:43:17.315152 18527 master.cpp:254] Master ID:
> 2014-03-12-19:43:17-1032504131-34563-18527 Hostname: juno.apache.org
> 2014-03-12 19:43:17,315:18527(0x2b8793868700):ZOO_INFO@log_env@716: Client
> environment:host.name=juno
> 2014-03-12 19:43:17,315:18527(0x2b8793868700):ZOO_INFO@log_env@723: Client
> environment:os.name=Linux
> 2014-03-12 19:43:17,315:18527(0x2b8793868700):ZOO_INFO@log_env@724: Client
> environment:os.arch=3.2.0-51-generic
> 2014-03-12 19:43:17,315:18527(0x2b8793868700):ZOO_INFO@log_env@725: Client
> environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013
> I0312 19:43:17.315193 18684 master.cpp:264] Master started on
> 67.195.138.61:34563
> I0312 19:43:17.315275 18684 master.cpp:267] Master only allowing
> authenticated frameworks to register!
> 2014-03-12 19:43:17,315:18527(0x2b8792e63700):ZOO_INFO@log_env@733: Client
> environment:user.name=(null)
> 2014-03-12 19:43:17,315:18527(0x2b8793868700):ZOO_INFO@log_env@733: Client
> environment:user.name=(null)
> 2014-03-12 19:43:17,315:18527(0x2b8792e63700):ZOO_INFO@log_env@741: Client
> environment:user.home=/home/jenkins
> 2014-03-12 19:43:17,315:18527(0x2b8793868700):ZOO_INFO@log_env@741: Client
> environment:user.home=/home/jenkins
> 2014-03-12 19:43:17,315:18527(0x2b8793868700):ZOO_INFO@log_env@753: Client
> environment:user.dir=/home/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src
> 2014-03-12 19:43:17,315:18527(0x2b8793868700):ZOO_INFO@zookeeper_init@786:
> Initiating client connection, host=127.0.0.1:38228 sessionTimeout=10000
> watcher=0x2b87901bbd20 sessionId=0 sessionPasswd=<null>
> context=0x2b87980082e0 flags=0
> I0312 19:43:17.315691 18687 master.cpp:98] No whitelist given. Advertising
> offers for all slaves
> I0312 19:43:17.315896 18688 hierarchical_allocator_process.hpp:302]
> Initializing hierarchical allocator process with master :
> [email protected]:34563
> 2014-03-12 19:43:17,315:18527(0x2b8792e63700):ZOO_INFO@log_env@753: Client
> environment:user.dir=/home/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src
> 2014-03-12 19:43:17,316:18527(0x2b8792e63700):ZOO_INFO@zookeeper_init@786:
> Initiating client connection, host=127.0.0.1:38228 sessionTimeout=10000
> watcher=0x2b87901bbd20 sessionId=0 sessionPasswd=<null>
> context=0x2b87b8027570 flags=0
> 2014-03-12 19:43:17,316:18527(0x2b891956c700):ZOO_INFO@check_events@1703:
> initiated connection to server [127.0.0.1:38228]
> I0312 19:43:17.316247 18686 contender.cpp:127] Joining the ZK group
> 2014-03-12 19:43:17,316:18527(0x2b891a7ad700):ZOO_INFO@check_events@1703:
> initiated connection to server [127.0.0.1:38228]
> 2014-03-12 19:43:17,410:18527(0x2b891956c700):ZOO_INFO@check_events@1750:
> session establishment complete on server [127.0.0.1:38228],
> sessionId=0x144b7d1fca00006, negotiated timeout=10000
> I0312 19:43:17.411078 18684 group.cpp:310] Group process
> ((2257)@67.195.138.61:34563) connected to ZooKeeper
> I0312 19:43:17.411095 18684 group.cpp:778] Syncing group operations: queue
> size (joins, cancels, datas) = (1, 0, 0)
> I0312 19:43:17.411104 18684 group.cpp:382] Trying to create path '/znode' in
> ZooKeeper
> 2014-03-12 19:43:17,411:18527(0x2b891a7ad700):ZOO_INFO@check_events@1750:
> session establishment complete on server [127.0.0.1:38228],
> sessionId=0x144b7d1fca00007, negotiated timeout=10000
> I0312 19:43:17.411546 18687 group.cpp:310] Group process
> ((2259)@67.195.138.61:34563) connected to ZooKeeper
> I0312 19:43:17.411563 18687 group.cpp:778] Syncing group operations: queue
> size (joins, cancels, datas) = (0, 0, 0)
> I0312 19:43:17.411571 18687 group.cpp:382] Trying to create path '/znode' in
> ZooKeeper
> I0312 19:43:17.435623 18686 contender.cpp:243] New candidate (id='2') has
> entered the contest for leadership
> I0312 19:43:17.435928 18690 detector.cpp:134] Detected a new leader: (id='2')
> I0312 19:43:17.436125 18690 group.cpp:655] Trying to get
> '/znode/info_0000000002' in ZooKeeper
> I0312 19:43:17.436746 18690 detector.cpp:377] A new leading master
> ([email protected]:34563) is detected
> I0312 19:43:17.436841 18685 master.cpp:773] The newly elected leader is
> [email protected]:34563 with id 2014-03-12-19:43:17-1032504131-34563-18527
> I0312 19:43:17.436872 18685 master.cpp:783] Elected as the leading master!
> 2014-03-12 19:43:17,437:18527(0x2b8792e63700):ZOO_INFO@log_env@712: Client
> environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-03-12 19:43:17,437:18527(0x2b8792e63700):ZOO_INFO@log_env@716: Client
> environment:host.name=juno
> 2014-03-12 19:43:17,437:18527(0x2b8792e63700):ZOO_INFO@log_env@723: Client
> environment:os.name=Linux
> 2014-03-12 19:43:17,437:18527(0x2b8792e63700):ZOO_INFO@log_env@724: Client
> environment:os.arch=3.2.0-51-generic
> 2014-03-12 19:43:17,437:18527(0x2b8792e63700):ZOO_INFO@log_env@725: Client
> environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013
> 2014-03-12 19:43:17,437:18527(0x2b8792e63700):ZOO_INFO@log_env@733: Client
> environment:user.name=(null)
> 2014-03-12 19:43:17,437:18527(0x2b8792e63700):ZOO_INFO@log_env@741: Client
> environment:user.home=/home/jenkins
> 2014-03-12 19:43:17,437:18527(0x2b8792e63700):ZOO_INFO@log_env@753: Client
> environment:user.dir=/home/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src
> 2014-03-12 19:43:17,437:18527(0x2b8792e63700):ZOO_INFO@zookeeper_init@786:
> Initiating client connection, host=127.0.0.1:38228 sessionTimeout=10000
> watcher=0x2b87901bbd20 sessionId=0 sessionPasswd=<null>
> context=0x2b87b8022b30 flags=0
> I0312 19:43:17.437845 18527 sched.cpp:121] Version: 0.19.0
> 2014-03-12 19:43:17,437:18527(0x2b8793265700):ZOO_INFO@log_env@712: Client
> environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-03-12 19:43:17,437:18527(0x2b8793265700):ZOO_INFO@log_env@716: Client
> environment:host.name=juno
> 2014-03-12 19:43:17,437:18527(0x2b8793265700):ZOO_INFO@log_env@723: Client
> environment:os.name=Linux
> 2014-03-12 19:43:17,437:18527(0x2b8793265700):ZOO_INFO@log_env@724: Client
> environment:os.arch=3.2.0-51-generic
> 2014-03-12 19:43:17,437:18527(0x2b8793265700):ZOO_INFO@log_env@725: Client
> environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013
> I0312 19:43:17.437872 18688 slave.cpp:120] Slave started on
> 143)@67.195.138.61:34563
> 2014-03-12 19:43:17,438:18527(0x2b8793265700):ZOO_INFO@log_env@733: Client
> environment:user.name=(null)
> 2014-03-12 19:43:17,438:18527(0x2b8793265700):ZOO_INFO@log_env@741: Client
> environment:user.home=/home/jenkins
> I0312 19:43:17.438099 18688 slave.cpp:130] Slave resources: cpus(*):2;
> mem(*):1024; disk(*):23038; ports(*):[31000-32000]
> 2014-03-12 19:43:17,438:18527(0x2b8793265700):ZOO_INFO@log_env@753: Client
> environment:user.dir=/home/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src
> 2014-03-12 19:43:17,438:18527(0x2b8793265700):ZOO_INFO@zookeeper_init@786:
> Initiating client connection, host=127.0.0.1:38228 sessionTimeout=10000
> watcher=0x2b87901bbd20 sessionId=0 sessionPasswd=<null>
> context=0x2b87a4038630 flags=0
> I0312 19:43:17.438199 18688 slave.cpp:158] Slave hostname: juno.apache.org
> I0312 19:43:17.438218 18688 slave.cpp:159] Slave checkpoint: false
> 2014-03-12 19:43:17,438:18527(0x2b8919fa9700):ZOO_INFO@check_events@1703:
> initiated connection to server [127.0.0.1:38228]
> 2014-03-12 19:43:17,438:18527(0x2b891a3ab700):ZOO_INFO@check_events@1703:
> initiated connection to server [127.0.0.1:38228]
> I0312 19:43:17.438670 18688 state.cpp:33] Recovering state from
> '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_LaXNS9/meta'
> I0312 19:43:17.438796 18688 status_update_manager.cpp:193] Recovering status
> update manager
> I0312 19:43:17.438953 18686 slave.cpp:2707] Finished recovery
> 2014-03-12 19:43:17,461:18527(0x2b8919fa9700):ZOO_INFO@check_events@1750:
> session establishment complete on server [127.0.0.1:38228],
> sessionId=0x144b7d1fca00008, negotiated timeout=10000
> I0312 19:43:17.461163 18686 group.cpp:310] Group process
> ((2263)@67.195.138.61:34563) connected to ZooKeeper
> I0312 19:43:17.461179 18686 group.cpp:778] Syncing group operations: queue
> size (joins, cancels, datas) = (0, 0, 0)
> I0312 19:43:17.461189 18686 group.cpp:382] Trying to create path '/znode' in
> ZooKeeper
> 2014-03-12 19:43:17,494:18527(0x2b891a3ab700):ZOO_INFO@check_events@1750:
> session establishment complete on server [127.0.0.1:38228],
> sessionId=0x144b7d1fca00009, negotiated timeout=10000
> I0312 19:43:17.494899 18690 group.cpp:310] Group process
> ((2269)@67.195.138.61:34563) connected to ZooKeeper
> I0312 19:43:17.494915 18690 group.cpp:778] Syncing group operations: queue
> size (joins, cancels, datas) = (0, 0, 0)
> I0312 19:43:17.494925 18690 group.cpp:382] Trying to create path '/znode' in
> ZooKeeper
> I0312 19:43:17.495162 18686 detector.cpp:134] Detected a new leader: (id='2')
> I0312 19:43:17.495321 18686 group.cpp:655] Trying to get
> '/znode/info_0000000002' in ZooKeeper
> I0312 19:43:17.496093 18686 detector.cpp:377] A new leading master
> ([email protected]:34563) is detected
> I0312 19:43:17.496196 18691 slave.cpp:405] New master detected at
> [email protected]:34563
> I0312 19:43:17.496294 18686 detector.cpp:134] Detected a new leader: (id='2')
> I0312 19:43:17.496335 18691 slave.cpp:430] Detecting new master
> I0312 19:43:17.496348 18686 status_update_manager.cpp:167] New master
> detected at [email protected]:34563
> I0312 19:43:17.496459 18686 master.cpp:1885] Attempting to register slave on
> juno.apache.org at slave(143)@67.195.138.61:34563
> I0312 19:43:17.496480 18686 master.cpp:2869] Adding slave
> 2014-03-12-19:43:17-1032504131-34563-18527-0 at juno.apache.org with
> cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000]
> I0312 19:43:17.496497 18688 group.cpp:655] Trying to get
> '/znode/info_0000000002' in ZooKeeper
> I0312 19:43:17.496553 18691 slave.cpp:448] Registered with master
> [email protected]:34563; given slave ID
> 2014-03-12-19:43:17-1032504131-34563-18527-0
> I0312 19:43:17.496664 18687 hierarchical_allocator_process.hpp:445] Added
> slave 2014-03-12-19:43:17-1032504131-34563-18527-0 (juno.apache.org) with
> cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] (and cpus(*):2;
> mem(*):1024; disk(*):23038; ports(*):[31000-32000] available)
> I0312 19:43:17.496709 18687 hierarchical_allocator_process.hpp:708] Performed
> allocation for slave 2014-03-12-19:43:17-1032504131-34563-18527-0 in 7224ns
> I0312 19:43:17.497156 18686 detector.cpp:377] A new leading master
> ([email protected]:34563) is detected
> I0312 19:43:17.497267 18688 sched.cpp:217] New master detected at
> [email protected]:34563
> I0312 19:43:17.497295 18688 sched.cpp:267] Authenticating with master
> [email protected]:34563
> I0312 19:43:17.497376 18686 authenticatee.hpp:128] Creating new client SASL
> connection
> I0312 19:43:17.497536 18690 master.cpp:2382] Authenticating framework at
> scheduler(136)@67.195.138.61:34563
> I0312 19:43:17.497617 18686 authenticator.hpp:148] Creating new server SASL
> connection
> I0312 19:43:17.497728 18686 authenticatee.hpp:219] Received SASL
> authentication mechanisms: CRAM-MD5
> I0312 19:43:17.497753 18686 authenticatee.hpp:245] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0312 19:43:17.497786 18686 authenticator.hpp:254] Received SASL
> authentication start
> I0312 19:43:17.497854 18686 authenticator.hpp:342] Authentication requires
> more steps
> I0312 19:43:17.497892 18686 authenticatee.hpp:265] Received SASL
> authentication step
> I0312 19:43:17.497943 18686 authenticator.hpp:282] Received SASL
> authentication step
> I0312 19:43:17.497969 18686 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'juno.apache.org' server FQDN:
> 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0312 19:43:17.497978 18686 auxprop.cpp:153] Looking up auxiliary property
> '*userPassword'
> I0312 19:43:17.497992 18686 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0312 19:43:17.498003 18686 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'juno.apache.org' server FQDN:
> 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0312 19:43:17.498011 18686 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0312 19:43:17.498018 18686 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0312 19:43:17.498030 18686 authenticator.hpp:334] Authentication success
> I0312 19:43:17.498067 18686 authenticatee.hpp:305] Authentication success
> I0312 19:43:17.498123 18684 master.cpp:2422] Successfully authenticated
> framework at scheduler(136)@67.195.138.61:34563
> I0312 19:43:17.498178 18686 sched.cpp:341] Successfully authenticated with
> master [email protected]:34563
> I0312 19:43:17.498193 18686 sched.cpp:460] Sending registration request to
> [email protected]:34563
> I0312 19:43:17.498308 18684 master.cpp:831] Received registration request
> from scheduler(136)@67.195.138.61:34563
> I0312 19:43:17.498347 18684 master.cpp:849] Registering framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000 at
> scheduler(136)@67.195.138.61:34563
> I0312 19:43:17.498437 18690 sched.cpp:391] Framework registered with
> 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.498466 18684 hierarchical_allocator_process.hpp:332] Added
> framework 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.498469 18690 sched.cpp:405] Scheduler::registered took 10416ns
> I0312 19:43:17.498534 18684 hierarchical_allocator_process.hpp:752] Offering
> cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] on slave
> 2014-03-12-19:43:17-1032504131-34563-18527-0 to framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.498688 18684 hierarchical_allocator_process.hpp:688] Performed
> allocation for 1 slaves in 202093ns
> I0312 19:43:17.498759 18691 master.hpp:456] Adding offer
> 2014-03-12-19:43:17-1032504131-34563-18527-0 with resources cpus(*):2;
> mem(*):1024; disk(*):23038; ports(*):[31000-32000] on slave
> 2014-03-12-19:43:17-1032504131-34563-18527-0 (juno.apache.org)
> I0312 19:43:17.498821 18691 master.cpp:2337] Sending 1 offers to framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.499151 18688 sched.cpp:528] Scheduler::resourceOffers took
> 201610ns
> I0312 19:43:17.499358 18691 master.hpp:466] Removing offer
> 2014-03-12-19:43:17-1032504131-34563-18527-0 with resources cpus(*):2;
> mem(*):1024; disk(*):23038; ports(*):[31000-32000] on slave
> 2014-03-12-19:43:17-1032504131-34563-18527-0 (juno.apache.org)
> I0312 19:43:17.499425 18691 master.cpp:1611] Processing reply for offers: [
> 2014-03-12-19:43:17-1032504131-34563-18527-0 ] on slave
> 2014-03-12-19:43:17-1032504131-34563-18527-0 (juno.apache.org) for framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.499517 18691 master.hpp:428] Adding task 0 with resources
> cpus(*):1; mem(*):500 on slave 2014-03-12-19:43:17-1032504131-34563-18527-0
> (juno.apache.org)
> I0312 19:43:17.499554 18691 master.cpp:2506] Launching task 0 of framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000 with resources cpus(*):1;
> mem(*):500 on slave 2014-03-12-19:43:17-1032504131-34563-18527-0
> (juno.apache.org)
> I0312 19:43:17.499655 18688 slave.cpp:666] Got assigned task 0 for framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.499706 18690 hierarchical_allocator_process.hpp:547] Framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000 left cpus(*):1; mem(*):524;
> disk(*):23038; ports(*):[31000-32000] unused on slave
> 2014-03-12-19:43:17-1032504131-34563-18527-0
> I0312 19:43:17.499842 18690 hierarchical_allocator_process.hpp:590] Framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000 filtered slave
> 2014-03-12-19:43:17-1032504131-34563-18527-0 for 5secs
> I0312 19:43:17.499871 18688 slave.cpp:775] Launching task 0 for framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.503469 18688 exec.cpp:131] Version: 0.19.0
> I0312 19:43:17.503545 18687 exec.cpp:181] Executor started at:
> executor(47)@67.195.138.61:34563 with pid 18527
> I0312 19:43:17.503597 18688 slave.cpp:885] Queuing task '0' for executor
> default of framework '2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.503654 18688 slave.cpp:366] Successfully attached file
> '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_LaXNS9/slaves/2014-03-12-19:43:17-1032504131-34563-18527-0/frameworks/2014-03-12-19:43:17-1032504131-34563-18527-0000/executors/default/runs/a834e1a5-12c6-4cef-a10f-404d2c8b3ed2'
> I0312 19:43:17.503693 18688 slave.cpp:2026] Monitoring executor 'default' of
> framework '2014-03-12-19:43:17-1032504131-34563-18527-0000' in container
> 'a834e1a5-12c6-4cef-a10f-404d2c8b3ed2'
> I0312 19:43:17.503763 18688 slave.cpp:1357] Got registration for executor
> 'default' of framework 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.503885 18688 slave.cpp:1475] Flushing queued task 0 for
> executor 'default' of framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.503921 18690 exec.cpp:205] Executor registered on slave
> 2014-03-12-19:43:17-1032504131-34563-18527-0
> I0312 19:43:17.505468 18690 exec.cpp:217] Executor::registered took 15897ns
> I0312 19:43:17.505530 18690 exec.cpp:292] Executor asked to run task '0'
> I0312 19:43:17.505573 18690 exec.cpp:301] Executor::launchTask took 21401ns
> I0312 19:43:17.507102 18690 exec.cpp:524] Executor sending status update
> TASK_RUNNING (UUID: ae4696e3-e5bf-4059-bd8c-428cf3734fc2) for task 0 of
> framework 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.507189 18690 slave.cpp:1684] Handling status update
> TASK_RUNNING (UUID: ae4696e3-e5bf-4059-bd8c-428cf3734fc2) for task 0 of
> framework 2014-03-12-19:43:17-1032504131-34563-18527-0000 from
> executor(47)@67.195.138.61:34563
> I0312 19:43:17.507289 18687 status_update_manager.cpp:320] Received status
> update TASK_RUNNING (UUID: ae4696e3-e5bf-4059-bd8c-428cf3734fc2) for task 0
> of framework 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.507310 18687 status_update_manager.cpp:499] Creating
> StatusUpdate stream for task 0 of framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.507364 18687 status_update_manager.cpp:373] Forwarding status
> update TASK_RUNNING (UUID: ae4696e3-e5bf-4059-bd8c-428cf3734fc2) for task 0
> of framework 2014-03-12-19:43:17-1032504131-34563-18527-0000 to
> [email protected]:34563
> I0312 19:43:17.507488 18690 master.cpp:2069] Status update TASK_RUNNING
> (UUID: ae4696e3-e5bf-4059-bd8c-428cf3734fc2) for task 0 of framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000 from
> slave(143)@67.195.138.61:34563
> I0312 19:43:17.507500 18684 slave.cpp:1800] Status update manager
> successfully handled status update TASK_RUNNING (UUID:
> ae4696e3-e5bf-4059-bd8c-428cf3734fc2) for task 0 of framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.507526 18684 slave.cpp:1806] Sending acknowledgement for
> status update TASK_RUNNING (UUID: ae4696e3-e5bf-4059-bd8c-428cf3734fc2) for
> task 0 of framework 2014-03-12-19:43:17-1032504131-34563-18527-0000 to
> executor(47)@67.195.138.61:34563
> I0312 19:43:17.507570 18687 sched.cpp:619] Scheduler::statusUpdate took
> 18332ns
> I0312 19:43:17.507599 18685 exec.cpp:338] Executor received status update
> acknowledgement ae4696e3-e5bf-4059-bd8c-428cf3734fc2 for task 0 of framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.507825 18688 status_update_manager.cpp:398] Received status
> update acknowledgement (UUID: ae4696e3-e5bf-4059-bd8c-428cf3734fc2) for task
> 0 of framework 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.507829 18527 master.cpp:530] Master terminating
> I0312 19:43:17.507905 18688 slave.cpp:1297] Status update manager
> successfully handled status update acknowledgement (UUID:
> ae4696e3-e5bf-4059-bd8c-428cf3734fc2) for task 0 of framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.507910 18527 master.hpp:446] Removing task 0 with resources
> cpus(*):1; mem(*):500 on slave 2014-03-12-19:43:17-1032504131-34563-18527-0
> (juno.apache.org)
> I0312 19:43:17.508035 18685 hierarchical_allocator_process.hpp:637] Recovered
> cpus(*):1; mem(*):500 (total allocatable: cpus(*):2; mem(*):1024;
> disk(*):23038; ports(*):[31000-32000]) on slave
> 2014-03-12-19:43:17-1032504131-34563-18527-0 from framework
> 2014-03-12-19:43:17-1032504131-34563-18527-0000
> I0312 19:43:17.508390 18691 slave.cpp:1881] [email protected]:34563 exited
> W0312 19:43:17.508412 18691 slave.cpp:1884] Master disconnected! Waiting for
> a new master to be elected
> I0312 19:43:17.509906 18527 contender.cpp:182] Now cancelling the membership:
> 2
> I0312 19:43:17.510033 18684 group.cpp:616] Trying to remove
> '/znode/info_0000000002' in ZooKeeper
> 2014-03-12 19:43:17,523:18527(0x2b8792a5d7c0):ZOO_INFO@zookeeper_close@2505:
> Closing zookeeper sessionId=0x144b7d1fca00006 to [127.0.0.1:38228]
> 2014-03-12 19:43:17,523:18527(0x2b8792a5d7c0):ZOO_INFO@zookeeper_close@2505:
> Closing zookeeper sessionId=0x144b7d1fca00007 to [127.0.0.1:38228]
> I0312 19:43:17.524593 18685 detector.cpp:122] The current leader (id=2) is
> lost
> I0312 19:43:17.524615 18685 detector.cpp:134] Detected a new leader: None
> I0312 19:43:17.524613 18689 detector.cpp:122] The current leader (id=2) is
> lost
> 2014-03-12 19:43:17,524:18527(0x2b8793064700):ZOO_INFO@log_env@712: Client
> environment:zookeeper.version=zookeeper C client 3.4.5
> I0312 19:43:17.524638 18689 detector.cpp:134] Detected a new leader: None
> 2014-03-12 19:43:17,524:18527(0x2b8793064700):ZOO_INFO@log_env@716: Client
> environment:host.name=juno
> 2014-03-12 19:43:17,524:18527(0x2b8793064700):ZOO_INFO@log_env@723: Client
> environment:os.name=Linux
> 2014-03-12 19:43:17,524:18527(0x2b8793064700):ZOO_INFO@log_env@724: Client
> environment:os.arch=3.2.0-51-generic
> 2014-03-12 19:43:17,524:18527(0x2b8793064700):ZOO_INFO@log_env@725: Client
> environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013
> I0312 19:43:17.524718 18527 master.cpp:254] Master ID:
> 2014-03-12-19:43:17-1032504131-34563-18527 Hostname: juno.apache.org
> 2014-03-12 19:43:17,524:18527(0x2b8792e63700):ZOO_INFO@log_env@712: Client
> environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-03-12 19:43:17,524:18527(0x2b8792e63700):ZOO_INFO@log_env@716: Client
> environment:host.name=juno
> 2014-03-12 19:43:17,524:18527(0x2b8792e63700):ZOO_INFO@log_env@723: Client
> environment:os.name=Linux
> 2014-03-12 19:43:17,524:18527(0x2b8792e63700):ZOO_INFO@log_env@724: Client
> environment:os.arch=3.2.0-51-generic
> 2014-03-12 19:43:17,524:18527(0x2b8792e63700):ZOO_INFO@log_env@725: Client
> environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013
> 2014-03-12 19:43:17,524:18527(0x2b8793064700):ZOO_INFO@log_env@733: Client
> environment:user.name=(null)
> I0312 19:43:17.524904 18689 slave.cpp:426] Lost leading master
> I0312 19:43:17.524929 18689 slave.cpp:430] Detecting new master
> 2014-03-12 19:43:17,524:18527(0x2b8793064700):ZOO_INFO@log_env@741: Client
> environment:user.home=/home/jenkins
> I0312 19:43:17.524991 18689 master.cpp:264] Master started on
> 67.195.138.61:34563
> 2014-03-12 19:43:17,525:18527(0x2b8793064700):ZOO_INFO@log_env@753: Client
> environment:user.dir=/home/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src
> 2014-03-12 19:43:17,525:18527(0x2b8793064700):ZOO_INFO@zookeeper_init@786:
> Initiating client connection, host=127.0.0.1:38228 sessionTimeout=10000
> watcher=0x2b87901bbd20 sessionId=0 sessionPasswd=<null>
> context=0x2b87a801eae0 flags=0
> 2014-03-12 19:43:17,525:18527(0x2b8792e63700):ZOO_INFO@log_env@733: Client
> environment:user.name=(null)
> I0312 19:43:17.525017 18689 master.cpp:267] Master only allowing
> authenticated frameworks to register!
> I0312 19:43:17.525065 18691 sched.cpp:211] Scheduler::disconnected took 9993ns
> 2014-03-12 19:43:17,525:18527(0x2b8792e63700):ZOO_INFO@log_env@741: Client
> environment:user.home=/home/jenkins
> I0312 19:43:17.525168 18691 sched.cpp:233] No master detected
> 2014-03-12 19:43:17,525:18527(0x2b8792e63700):ZOO_INFO@log_env@753: Client
> environment:user.dir=/home/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src
> 2014-03-12 19:43:17,525:18527(0x2b8792e63700):ZOO_INFO@zookeeper_init@786:
> Initiating client connection, host=127.0.0.1:38228 sessionTimeout=10000
> watcher=0x2b87901bbd20 sessionId=0 sessionPasswd=<null>
> context=0x2b87b800f010 flags=0
> 2014-03-12 19:43:17,525:18527(0x2b891a5ac700):ZOO_INFO@check_events@1703:
> initiated connection to server [127.0.0.1:38228]
> I0312 19:43:17.525538 18691 master.cpp:98] No whitelist given. Advertising
> offers for all slaves
> 2014-03-12 19:43:17,525:18527(0x2b8918d58700):ZOO_INFO@check_events@1703:
> initiated connection to server [127.0.0.1:38228]
> I0312 19:43:17.525720 18685 hierarchical_allocator_process.hpp:302]
> Initializing hierarchical allocator process with master :
> [email protected]:34563
> I0312 19:43:17.525753 18689 contender.cpp:127] Joining the ZK group
> 2014-03-12 19:43:17,584:18527(0x2b891a5ac700):ZOO_INFO@check_events@1750:
> session establishment complete on server [127.0.0.1:38228],
> sessionId=0x144b7d1fca0000a, negotiated timeout=10000
> I0312 19:43:17.584198 18689 group.cpp:310] Group process
> ((2274)@67.195.138.61:34563) connected to ZooKeeper
> I0312 19:43:17.584218 18689 group.cpp:778] Syncing group operations: queue
> size (joins, cancels, datas) = (1, 0, 0)
> I0312 19:43:17.584226 18689 group.cpp:382] Trying to create path '/znode' in
> ZooKeeper
> 2014-03-12 19:43:17,584:18527(0x2b8918d58700):ZOO_INFO@check_events@1750:
> session establishment complete on server [127.0.0.1:38228],
> sessionId=0x144b7d1fca0000b, negotiated timeout=10000
> I0312 19:43:17.584748 18685 group.cpp:310] Group process
> ((2276)@67.195.138.61:34563) connected to ZooKeeper
> I0312 19:43:17.584761 18685 group.cpp:778] Syncing group operations: queue
> size (joins, cancels, datas) = (0, 0, 0)
> I0312 19:43:17.584769 18685 group.cpp:382] Trying to create path '/znode' in
> ZooKeeper
> I0312 19:43:17.619072 18684 contender.cpp:243] New candidate (id='3') has
> entered the contest for leadership
> I0312 19:43:17.619726 18684 detector.cpp:134] Detected a new leader: (id='3')
> I0312 19:43:17.619952 18690 group.cpp:655] Trying to get
> '/znode/info_0000000003' in ZooKeeper
> I0312 19:43:17.620018 18684 detector.cpp:134] Detected a new leader: (id='3')
> I0312 19:43:17.620246 18689 group.cpp:655] Trying to get
> '/znode/info_0000000003' in ZooKeeper
> I0312 19:43:17.620671 18685 detector.cpp:134] Detected a new leader: (id='3')
> I0312 19:43:17.620806 18686 group.cpp:655] Trying to get
> '/znode/info_0000000003' in ZooKeeper
> I0312 19:43:17.621136 18691 detector.cpp:377] A new leading master
> ([email protected]:34563) is detected
> I0312 19:43:17.621209 18691 sched.cpp:217] New master detected at
> [email protected]:34563
> I0312 19:43:17.621229 18691 sched.cpp:267] Authenticating with master
> [email protected]:34563
> I0312 19:43:17.621322 18688 authenticatee.hpp:128] Creating new client SASL
> connection
> W0312 19:43:17.621480 18685 master.cpp:2352] Ignoring authenticate message
> from authenticatee(150)@67.195.138.61:34563 since not elected yet
> I0312 19:43:17.621616 18684 detector.cpp:377] A new leading master
> ([email protected]:34563) is detected
> I0312 19:43:17.621728 18690 detector.cpp:377] A new leading master
> ([email protected]:34563) is detected
> I0312 19:43:17.621774 18686 slave.cpp:405] New master detected at
> [email protected]:34563
> I0312 19:43:17.621808 18685 master.cpp:773] The newly elected leader is
> [email protected]:34563 with id 2014-03-12-19:43:17-1032504131-34563-18527
> I0312 19:43:17.621824 18685 master.cpp:783] Elected as the leading master!
> I0312 19:43:17.621845 18684 status_update_manager.cpp:167] New master
> detected at [email protected]:34563
> I0312 19:43:17.621906 18686 slave.cpp:430] Detecting new master
> I0312 19:43:17.621964 18685 master.cpp:1980] Attempting to re-register slave
> 2014-03-12-19:43:17-1032504131-34563-18527-0 at
> slave(143)@67.195.138.61:34563 (juno.apache.org)
> I0312 19:43:17.621980 18685 master.cpp:2869] Adding slave
> 2014-03-12-19:43:17-1032504131-34563-18527-0 at juno.apache.org with
> cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000]
> I0312 19:43:17.622063 18686 slave.cpp:498] Re-registered with master
> [email protected]:34563
> I0312 19:43:17.622076 18685 master.hpp:428] Adding task 0 with resources
> cpus(*):1; mem(*):500 on slave 2014-03-12-19:43:17-1032504131-34563-18527-0
> (juno.apache.org)
> W0312 19:43:17.622107 18685 master.cpp:2965] Possibly orphaned task 0 of
> framework 2014-03-12-19:43:17-1032504131-34563-18527-0000 running on slave
> 2014-03-12-19:43:17-1032504131-34563-18527-0 (juno.apache.org)
> GMOCK WARNING:
> Uninteresting mock function call - taking default action specified at:
> ./tests/mesos.hpp:424:
> Function call: slaveAdded(@0x2b87b8040f50
> 2014-03-12-19:43:17-1032504131-34563-18527-0, @0x2b87b8040ee0 hostname:
> "juno.apache.org"
> webui_hostname: "juno.apache.org"
> resources {
> name: "cpus"
> type: SCALAR
> scalar {
> value: 2
> }
> role: "*"
> }
> resources {
> name: "mem"
> type: SCALAR
> scalar {
> value: 1024
> }
> role: "*"
> }
> resources {
> name: "disk"
> type: SCALAR
> scalar {
> value: 23038
> }
> role: "*"
> }
> resources {
> name: "ports"
> type: RANGES
> ranges {
> range {
> begin: 31000
> end: 32000
> }
> }
> role: "*"
> }
> id {
> value: "2014-03-12-19:43:17-1032504131-34563-18527-0"
> }
> checkpoint: false
> port: 34563
> , @0x2b87b8040eb0 { (2014-03-12-19:43:17-1032504131-34563-18527-0000, {
> cpus(*):1, mem(*):500 }) })
> Stack trace:
> I0312 19:43:17.622601 18685 hierarchical_allocator_process.hpp:445] Added
> slave 2014-03-12-19:43:17-1032504131-34563-18527-0 (juno.apache.org) with
> cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] (and cpus(*):1;
> mem(*):524; disk(*):23038; ports(*):[31000-32000] available)
> I0312 19:43:17.622648 18685 hierarchical_allocator_process.hpp:708] Performed
> allocation for slave 2014-03-12-19:43:17-1032504131-34563-18527-0 in 8238ns
> I0312 19:43:18.526563 18689 hierarchical_allocator_process.hpp:688] Performed
> allocation for 1 slaves in 16134ns
> I0312 19:43:19.526924 18691 hierarchical_allocator_process.hpp:688] Performed
> allocation for 1 slaves in 28730ns
> 2014-03-12
> 19:43:20,340:18527(0x2b891996e700):ZOO_ERROR@handle_socket_error_msg@1697:
> Socket [127.0.0.1:39171] zk retcode=-4, errno=111(Connection refused): server
> refused to accept the client
> I0312 19:43:20.527256 18688 hierarchical_allocator_process.hpp:688] Performed
> allocation for 1 slaves in 27283ns
> I0312 19:43:21.528138 18684 hierarchical_allocator_process.hpp:688] Performed
> allocation for 1 slaves in 28706ns
> I0312 19:43:22.525884 18690 master.cpp:98] No whitelist given. Advertising
> offers for all slaves
> I0312 19:43:22.529023 18691 hierarchical_allocator_process.hpp:688] Performed
> allocation for 1 slaves in 22973ns
> W0312 19:43:22.622232 18687 sched.cpp:362] Authentication timed out
> I0312 19:43:22.622361 18687 sched.cpp:322] Failed to authenticate with master
> [email protected]:34563: Authentication discarded
> I0312 19:43:22.622400 18687 sched.cpp:267] Authenticating with master
> [email protected]:34563
> I0312 19:43:22.622532 18684 authenticatee.hpp:128] Creating new client SASL
> connection
> I0312 19:43:22.622774 18687 master.cpp:2382] Authenticating framework at
> scheduler(136)@67.195.138.61:34563
> I0312 19:43:22.622859 18684 authenticator.hpp:148] Creating new server SASL
> connection
> I0312 19:43:22.622985 18689 authenticatee.hpp:219] Received SASL
> authentication mechanisms: CRAM-MD5
> I0312 19:43:22.623004 18689 authenticatee.hpp:245] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0312 19:43:22.623038 18689 authenticator.hpp:254] Received SASL
> authentication start
> I0312 19:43:22.623111 18689 authenticator.hpp:342] Authentication requires
> more steps
> I0312 19:43:22.623142 18689 authenticatee.hpp:265] Received SASL
> authentication step
> I0312 19:43:22.623208 18691 authenticator.hpp:282] Received SASL
> authentication step
> I0312 19:43:22.623245 18691 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'juno.apache.org' server FQDN:
> 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0312 19:43:22.623258 18691 auxprop.cpp:153] Looking up auxiliary property
> '*userPassword'
> I0312 19:43:22.623273 18691 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0312 19:43:22.623286 18691 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'juno.apache.org' server FQDN:
> 'juno.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0312 19:43:22.623294 18691 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0312 19:43:22.623299 18691 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0312 19:43:22.623317 18691 authenticator.hpp:334] Authentication success
> I0312 19:43:22.623359 18684 authenticatee.hpp:305] Authentication success
> I0312 19:43:22.623376 18691 master.cpp:2422] Successfully authenticated
> framework at scheduler(136)@67.195.138.61:34563
> I0312 19:43:22.623440 18684 sched.cpp:341] Successfully authenticated with
> master [email protected]:34563
> I0312 19:43:22.623461 18684 sched.cpp:460] Sending registration request to
> [email protected]:34563
> I0312 19:43:23.529403 18691 hierarchical_allocator_process.hpp:688] Performed
> allocation for 1 slaves in 23699ns
> I0312 19:43:23.624521 18688 sched.cpp:460] Sending registration request to
> [email protected]:34563
> 2014-03-12
> 19:43:23,676:18527(0x2b891996e700):ZOO_ERROR@handle_socket_error_msg@1697:
> Socket [127.0.0.1:39171] zk retcode=-4, errno=111(Connection refused): server
> refused to accept the client
> I0312 19:43:24.529695 18684 hierarchical_allocator_process.hpp:688] Performed
> allocation for 1 slaves in 26288ns
> I0312 19:43:24.624841 18688 sched.cpp:460] Sending registration request to
> [email protected]:34563
> I0312 19:43:25.529984 18685 hierarchical_allocator_process.hpp:688] Performed
> allocation for 1 slaves in 28142ns
> I0312 19:43:25.625077 18686 sched.cpp:460] Sending registration request to
> [email protected]:34563
> I0312 19:43:26.530828 18689 hierarchical_allocator_process.hpp:688] Performed
> allocation for 1 slaves in 20700ns
> I0312 19:43:26.625977 18688 sched.cpp:460] Sending registration request to
> [email protected]:34563
> 2014-03-12
> 19:43:27,012:18527(0x2b891996e700):ZOO_ERROR@handle_socket_error_msg@1697:
> Socket [127.0.0.1:39171] zk retcode=-4, errno=111(Connection refused): server
> refused to accept the client
> I0312 19:43:27.526388 18688 master.cpp:98] No whitelist given. Advertising
> offers for all slaves
> I0312 19:43:27.531579 18686 hierarchical_allocator_process.hpp:688] Performed
> allocation for 1 slaves in 26447ns
> tests/allocator_zookeeper_tests.cpp:290: Failure
> Failed to wait 10secs for slaveAdded
> tests/allocator_zookeeper_tests.cpp:284: Failure
> Actual function call count doesn't match EXPECT_CALL(allocator2,
> slaveAdded(_, _, _))...
> Expected: to be called once
> Actual: never called - unsatisfied and active
> I0312 19:43:27.626893 18684 sched.cpp:460] Sending registration request to
> [email protected]:34563
> I0312 19:43:28.627651 18684 sched.cpp:460] Sending registration request to
> [email protected]:34563
> I0312 19:43:29.627825 18689 sched.cpp:460] Sending registration request to
> [email protected]:34563
> 2014-03-12
> 19:43:30,349:18527(0x2b891996e700):ZOO_ERROR@handle_socket_error_msg@1697:
> Socket [127.0.0.1:39171] zk retcode=-4, errno=111(Connection refused): server
> refused to accept the client
> I0312 19:43:30.627961 18689 sched.cpp:460] Sending registration request to
> [email protected]:34563
> {code}
> The last few lines repeats forever. See [full
> log|https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/1693/consoleText].
--
This message was sent by Atlassian JIRA
(v6.2#6252)
