https://issues.apache.org/jira/browse/MESOS-977
On Thu, Feb 6, 2014 at 8:05 PM, Apache Jenkins Server < [email protected]> wrote: > See < > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/1607/changes > > > > Changes: > > [bmahler] Added a function that captures the stack trace when a pure > virtual > > [bmahler] Fixed flaky test GroupTest.GroupWatchWithSessionExpiration. > > [bmahler] Group now aborts in the face of a ZNOAUTH error when creating the > > ------------------------------------------ > [...truncated 25376 lines...] > 2014-02-07 04:05:46,339:31385(0x2b6139b6f700):ZOO_INFO@check_events@1750: > session establishment complete on server [127.0.0.1:41512], > sessionId=0x1440a85bd860008, negotiated timeout=10000 > I0207 04:05:46.340257 31417 group.cpp:310] Group process ((1999)@ > 67.195.138.60:56892) connected to ZooKeeper > I0207 04:05:46.340340 31417 group.cpp:752] Syncing group operations: queue > size (joins, cancels, datas) = (0, 0, 0) > I0207 04:05:46.340353 31417 group.cpp:367] Trying to create path '/znode' > in ZooKeeper > 2014-02-07 04:05:46,381:31385(0x2b6139f71700):ZOO_INFO@check_events@1750: > session establishment complete on server [127.0.0.1:41512], > sessionId=0x1440a85bd860009, negotiated timeout=10000 > I0207 04:05:46.382623 31424 group.cpp:310] Group process ((2006)@ > 67.195.138.60:56892) connected to ZooKeeper > I0207 04:05:46.382647 31424 group.cpp:752] Syncing group operations: queue > size (joins, cancels, datas) = (0, 0, 0) > I0207 04:05:46.382657 31424 group.cpp:367] Trying to create path '/znode' > in ZooKeeper > I0207 04:05:46.383662 31418 detector.cpp:134] Detected a new leader: > (id='2') > I0207 04:05:46.383824 31419 group.cpp:629] Trying to get > '/znode/info_0000000002' in ZooKeeper > I0207 04:05:46.384037 31421 detector.cpp:134] Detected a new leader: > (id='2') > I0207 04:05:46.384255 31418 group.cpp:629] Trying to get > '/znode/info_0000000002' in ZooKeeper > I0207 04:05:46.384455 31419 detector.cpp:351] A new leading master (UPID= > [email protected]:56892) is detected > I0207 04:05:46.384513 31419 slave.cpp:501] New master detected at > [email protected]:56892 > I0207 04:05:46.384582 31424 status_update_manager.cpp:162] New master > detected at [email protected]:56892 > I0207 04:05:46.384599 31419 slave.cpp:526] Detecting new master > I0207 04:05:46.384696 31417 master.cpp:1813] Attempting to register slave > on janus.apache.org at slave(143)@67.195.138.60:56892 > I0207 04:05:46.384719 31417 master.cpp:2783] Adding slave > 201402070405-1015726915-56892-31385-0 at janus.apache.org with cpus(*):2; > mem(*):1024; disk(*):23038; ports(*):[31000-32000] > I0207 04:05:46.384848 31424 slave.cpp:544] Registered with master > [email protected]:56892; given slave ID > 201402070405-1015726915-56892-31385-0 > I0207 04:05:46.384987 31424 hierarchical_allocator_process.hpp:445] Added > slave 201402070405-1015726915-56892-31385-0 (janus.apache.org) with > cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] (and > cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] available) > I0207 04:05:46.385040 31424 hierarchical_allocator_process.hpp:708] > Performed allocation for slave 201402070405-1015726915-56892-31385-0 in > 11933ns > I0207 04:05:46.385421 31422 detector.cpp:351] A new leading master (UPID= > [email protected]:56892) is detected > I0207 04:05:46.385529 31424 sched.cpp:210] New master detected at > [email protected]:56892 > I0207 04:05:46.385550 31424 sched.cpp:261] Authenticating with master > [email protected]:56892 > I0207 04:05:46.385612 31424 sched.cpp:230] Detecting new master > I0207 04:05:46.385663 31417 authenticatee.hpp:124] Creating new client > SASL connection > I0207 04:05:46.385959 31424 master.cpp:2296] Authenticating framework at > scheduler(136)@67.195.138.60:56892 > I0207 04:05:46.386051 31417 authenticator.hpp:140] Creating new server > SASL connection > I0207 04:05:46.386201 31422 authenticatee.hpp:212] Received SASL > authentication mechanisms: CRAM-MD5 > I0207 04:05:46.386235 31422 authenticatee.hpp:238] Attempting to > authenticate with mechanism 'CRAM-MD5' > I0207 04:05:46.386287 31422 authenticator.hpp:243] Received SASL > authentication start > I0207 04:05:46.386464 31422 authenticator.hpp:325] Authentication requires > more steps > I0207 04:05:46.386508 31422 authenticatee.hpp:258] Received SASL > authentication step > I0207 04:05:46.386576 31422 authenticator.hpp:271] Received SASL > authentication step > I0207 04:05:46.386608 31422 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'janus.apache.org' server FQDN: ' > janus.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false > I0207 04:05:46.386620 31422 auxprop.cpp:153] Looking up auxiliary property > '*userPassword' > I0207 04:05:46.386641 31422 auxprop.cpp:153] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I0207 04:05:46.386654 31422 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'janus.apache.org' server FQDN: ' > janus.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true > I0207 04:05:46.386662 31422 auxprop.cpp:103] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I0207 04:05:46.386668 31422 auxprop.cpp:103] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I0207 04:05:46.386683 31422 authenticator.hpp:317] Authentication success > I0207 04:05:46.386740 31417 authenticatee.hpp:298] Authentication success > I0207 04:05:46.386754 31419 master.cpp:2336] Successfully authenticated > framework at scheduler(136)@67.195.138.60:56892 > I0207 04:05:46.386904 31417 sched.cpp:335] Successfully authenticated with > master [email protected]:56892 > I0207 04:05:46.386986 31417 master.cpp:791] Received registration request > from scheduler(136)@67.195.138.60:56892 > I0207 04:05:46.387024 31417 master.cpp:809] Registering framework > 201402070405-1015726915-56892-31385-0000 at scheduler(136)@ > 67.195.138.60:56892 > I0207 04:05:46.387102 31417 sched.cpp:384] Framework registered with > 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.387130 31417 sched.cpp:398] Scheduler::registered took > 12285ns > I0207 04:05:46.387174 31417 hierarchical_allocator_process.hpp:332] Added > framework 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.387238 31417 hierarchical_allocator_process.hpp:752] > Offering cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] on > slave 201402070405-1015726915-56892-31385-0 to framework > 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.387377 31417 hierarchical_allocator_process.hpp:688] > Performed allocation for 1 slaves in 184557ns > I0207 04:05:46.387444 31417 master.hpp:431] Adding offer > 201402070405-1015726915-56892-31385-0 with resources cpus(*):2; > mem(*):1024; disk(*):23038; ports(*):[31000-32000] on slave > 201402070405-1015726915-56892-31385-0 (janus.apache.org) > I0207 04:05:46.387497 31417 master.cpp:2251] Sending 1 offers to framework > 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.387825 31417 sched.cpp:518] Scheduler::resourceOffers took > 200778ns > I0207 04:05:46.387995 31417 master.hpp:441] Removing offer > 201402070405-1015726915-56892-31385-0 with resources cpus(*):2; > mem(*):1024; disk(*):23038; ports(*):[31000-32000] on slave > 201402070405-1015726915-56892-31385-0 (janus.apache.org) > I0207 04:05:46.388052 31417 master.cpp:1547] Processing reply for offers: > [ 201402070405-1015726915-56892-31385-0 ] on slave > 201402070405-1015726915-56892-31385-0 (janus.apache.org) for framework > 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.388139 31417 master.hpp:403] Adding task 0 with resources > cpus(*):1; mem(*):500 on slave 201402070405-1015726915-56892-31385-0 ( > janus.apache.org) > I0207 04:05:46.388172 31417 master.cpp:2420] Launching task 0 of framework > 201402070405-1015726915-56892-31385-0000 with resources cpus(*):1; > mem(*):500 on slave 201402070405-1015726915-56892-31385-0 ( > janus.apache.org) > I0207 04:05:46.388315 31417 slave.cpp:729] Got assigned task 0 for > framework 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.388519 31417 slave.cpp:838] Launching task 0 for framework > 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.390516 31418 hierarchical_allocator_process.hpp:547] > Framework 201402070405-1015726915-56892-31385-0000 left cpus(*):1; > mem(*):524; disk(*):23038; ports(*):[31000-32000] unused on slave > 201402070405-1015726915-56892-31385-0 > I0207 04:05:46.390648 31418 hierarchical_allocator_process.hpp:590] > Framework 201402070405-1015726915-56892-31385-0000 filtered slave > 201402070405-1015726915-56892-31385-0 for 5secs > I0207 04:05:46.396747 31417 slave.cpp:948] Queuing task '0' for executor > default of framework '201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.396744 31421 exec.cpp:178] Executor started at: > executor(46)@67.195.138.60:56892 with pid 31385 > I0207 04:05:46.396926 31417 slave.cpp:466] Successfully attached file > '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_09ZpmW/slaves/201402070405-1015726915-56892-31385-0/frameworks/201402070405-1015726915-56892-31385-0000/executors/default/runs/a1e31567-8434-4113-a16e-f9a3364a988b' > I0207 04:05:46.396971 31417 slave.cpp:2091] Monitoring executor default of > framework 201402070405-1015726915-56892-31385-0000 forked at pid 31385 > I0207 04:05:46.397094 31417 slave.cpp:1424] Got registration for executor > 'default' of framework 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.397348 31417 slave.cpp:1545] Flushing queued task 0 for > executor 'default' of framework 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.397385 31419 exec.cpp:202] Executor registered on slave > 201402070405-1015726915-56892-31385-0 > I0207 04:05:46.398952 31419 exec.cpp:214] Executor::registered took 12932ns > I0207 04:05:46.399024 31419 exec.cpp:289] Executor asked to run task '0' > I0207 04:05:46.399060 31419 exec.cpp:298] Executor::launchTask took 23975ns > I0207 04:05:46.400550 31419 exec.cpp:521] Executor sending status update > TASK_RUNNING (UUID: 7eaa4a51-9bc5-4496-b6e7-d9ac6cf4c337) for task 0 of > framework 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.400636 31419 slave.cpp:1758] Handling status update > TASK_RUNNING (UUID: 7eaa4a51-9bc5-4496-b6e7-d9ac6cf4c337) for task 0 of > framework 201402070405-1015726915-56892-31385-0000 from executor(46)@ > 67.195.138.60:56892 > I0207 04:05:46.400730 31419 status_update_manager.cpp:314] Received status > update TASK_RUNNING (UUID: 7eaa4a51-9bc5-4496-b6e7-d9ac6cf4c337) for task 0 > of framework 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.400745 31419 status_update_manager.cpp:493] Creating > StatusUpdate stream for task 0 of framework > 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.400813 31419 status_update_manager.cpp:367] Forwarding > status update TASK_RUNNING (UUID: 7eaa4a51-9bc5-4496-b6e7-d9ac6cf4c337) for > task 0 of framework 201402070405-1015726915-56892-31385-0000 to > [email protected]:56892 > I0207 04:05:46.401005 31418 slave.cpp:1877] Status update manager > successfully handled status update TASK_RUNNING (UUID: > 7eaa4a51-9bc5-4496-b6e7-d9ac6cf4c337) for task 0 of framework > 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.401062 31418 slave.cpp:1883] Sending acknowledgement for > status update TASK_RUNNING (UUID: 7eaa4a51-9bc5-4496-b6e7-d9ac6cf4c337) for > task 0 of framework 201402070405-1015726915-56892-31385-0000 to > executor(46)@67.195.138.60:56892 > I0207 04:05:46.401191 31419 exec.cpp:335] Executor received status update > acknowledgement 7eaa4a51-9bc5-4496-b6e7-d9ac6cf4c337 for task 0 of > framework 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.401185 31421 master.cpp:1999] Status update TASK_RUNNING > (UUID: 7eaa4a51-9bc5-4496-b6e7-d9ac6cf4c337) for task 0 of framework > 201402070405-1015726915-56892-31385-0000 from slave(143)@ > 67.195.138.60:56892 > I0207 04:05:46.401273 31420 sched.cpp:609] Scheduler::statusUpdate took > 30241ns > I0207 04:05:46.401543 31422 master.cpp:562] Master terminating > I0207 04:05:46.401593 31420 slave.cpp:1958] [email protected]:56892exited > W0207 04:05:46.401608 31420 slave.cpp:1961] Master disconnected! Waiting > for a new master to be elected > I0207 04:05:46.401645 31421 status_update_manager.cpp:392] Received status > update acknowledgement (UUID: 7eaa4a51-9bc5-4496-b6e7-d9ac6cf4c337) for > task 0 of framework 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.401650 31385 master.cpp:210] Shutting down master > I0207 04:05:46.401723 31385 master.hpp:421] Removing task 0 with resources > cpus(*):1; mem(*):500 on slave 201402070405-1015726915-56892-31385-0 ( > janus.apache.org) > I0207 04:05:46.401782 31418 slave.cpp:1364] Status update manager > successfully handled status update acknowledgement (UUID: > 7eaa4a51-9bc5-4496-b6e7-d9ac6cf4c337) for task 0 of framework > 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.401820 31385 master.cpp:253] Removing slave > 201402070405-1015726915-56892-31385-0 (janus.apache.org) > I0207 04:05:46.401902 31421 hierarchical_allocator_process.hpp:637] > Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):2; mem(*):1024; > disk(*):23038; ports(*):[31000-32000]) on slave > 201402070405-1015726915-56892-31385-0 from framework > 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.407778 31385 contender.cpp:182] Now cancelling the > membership: 2 > I0207 04:05:46.407951 31421 group.cpp:590] Trying to remove > '/znode/info_0000000002' in ZooKeeper > 2014-02-07 04:05:46,422:31385(0x2b5faa46ab00):ZOO_INFO@zookeeper_close@2505: > Closing zookeeper sessionId=0x1440a85bd860007 to [127.0.0.1:41512] > > I0207 04:05:46.423082 31419 detector.cpp:122] The current leader (id=2) is > lost > I0207 04:05:46.423152 31419 detector.cpp:134] Detected a new leader: None > I0207 04:05:46.423434 31420 detector.cpp:122] The current leader (id=2) is > lost > I0207 04:05:46.423449 31420 detector.cpp:134] Detected a new leader: None > I0207 04:05:46.423619 31423 sched.cpp:204] Scheduler::disconnected took > 11972ns > I0207 04:05:46.423635 31423 sched.cpp:226] No master detected > I0207 04:05:46.423641 31423 sched.cpp:230] Detecting new master > I0207 04:05:46.423892 31420 detector.cpp:122] The current leader (id=2) is > lost > I0207 04:05:46.423907 31420 detector.cpp:134] Detected a new leader: None > 2014-02-07 04:05:46,423:31385(0x2b5faa46ab00):ZOO_INFO@zookeeper_close@2505: > Closing zookeeper sessionId=0x1440a85bd860006 to [127.0.0.1:41512] > > I0207 04:05:46.424058 31421 slave.cpp:522] Lost leading master > I0207 04:05:46.424104 31421 slave.cpp:526] Detecting new master > I0207 04:05:46.424962 31420 master.cpp:285] Master started on > 67.195.138.60:56892 > I0207 04:05:46.424998 31420 master.cpp:300] Master ID: > 201402070405-1015726915-56892-31385 > I0207 04:05:46.425005 31420 master.cpp:303] Master only allowing > authenticated frameworks to register! > 2014-02-07 04:05:46,425:31385(0x2b5fab276700):ZOO_INFO@log_env@712: > Client environment:zookeeper.version=zookeeper C client 3.4.5 > 2014-02-07 04:05:46,425:31385(0x2b5fab276700):ZOO_INFO@log_env@716: > Client environment:host.name=janus > 2014-02-07 04:05:46,425:31385(0x2b5fab276700):ZOO_INFO@log_env@723: > Client environment:os.name=Linux > 2014-02-07 04:05:46,425:31385(0x2b5fab276700):ZOO_INFO@log_env@724: > Client environment:os.arch=3.2.0-57-generic > 2014-02-07 04:05:46,425:31385(0x2b5fab276700):ZOO_INFO@log_env@725: > Client environment:os.version=#87-Ubuntu SMP Tue Nov 12 21:35:10 UTC 2013 > 2014-02-07 04:05:46,425:31385(0x2b5faa871700):ZOO_INFO@log_env@712: > Client environment:zookeeper.version=zookeeper C client 3.4.5 > 2014-02-07 04:05:46,425:31385(0x2b5faa871700):ZOO_INFO@log_env@716: > Client environment:host.name=janus > 2014-02-07 04:05:46,425:31385(0x2b5faa871700):ZOO_INFO@log_env@723: > Client environment:os.name=Linux > 2014-02-07 04:05:46,425:31385(0x2b5faa871700):ZOO_INFO@log_env@724: > Client environment:os.arch=3.2.0-57-generic > 2014-02-07 04:05:46,425:31385(0x2b5faa871700):ZOO_INFO@log_env@725: > Client environment:os.version=#87-Ubuntu SMP Tue Nov 12 21:35:10 UTC 2013 > I0207 04:05:46.425539 31417 master.cpp:86] No whitelist given. Advertising > offers for all slaves > 2014-02-07 04:05:46,425:31385(0x2b5faa871700):ZOO_INFO@log_env@733: > Client environment:user.name=(null) > I0207 04:05:46.425705 31420 hierarchical_allocator_process.hpp:302] > Initializing hierarchical allocator process with master : > [email protected]:56892 > 2014-02-07 04:05:46,425:31385(0x2b5faa871700):ZOO_INFO@log_env@741: > Client environment:user.home=/home/jenkins > 2014-02-07 04:05:46,425:31385(0x2b5faa871700):ZOO_INFO@log_env@753: > Client environment:user.dir=< > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src > > > 2014-02-07 04:05:46,425:31385(0x2b5faa871700):ZOO_INFO@zookeeper_init@786: > Initiating client connection, host=127.0.0.1:41512 sessionTimeout=10000 > watcher=0x2b5fa3711480 sessionId=0 sessionPasswd=<null> > context=0x2b5fb8027a40 flags=0 > I0207 04:05:46.425802 31417 contender.cpp:127] Joining the ZK group > 2014-02-07 04:05:46,425:31385(0x2b5fab276700):ZOO_INFO@log_env@733: > Client environment:user.name=(null) > 2014-02-07 04:05:46,425:31385(0x2b5fab276700):ZOO_INFO@log_env@741: > Client environment:user.home=/home/jenkins > 2014-02-07 04:05:46,425:31385(0x2b5fab276700):ZOO_INFO@log_env@753: > Client environment:user.dir=< > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src > > > 2014-02-07 04:05:46,426:31385(0x2b5fab276700):ZOO_INFO@zookeeper_init@786: > Initiating client connection, host=127.0.0.1:41512 sessionTimeout=10000 > watcher=0x2b5fa3711480 sessionId=0 sessionPasswd=<null> > context=0x2b5fd002eef0 flags=0 > 2014-02-07 04:05:46,426:31385(0x2b613a373700):ZOO_INFO@check_events@1703: > initiated connection to server [127.0.0.1:41512] > 2014-02-07 04:05:46,426:31385(0x2b613996e700):ZOO_INFO@check_events@1703: > initiated connection to server [127.0.0.1:41512] > 2014-02-07 04:05:46,463:31385(0x2b613a373700):ZOO_INFO@check_events@1750: > session establishment complete on server [127.0.0.1:41512], > sessionId=0x1440a85bd86000a, negotiated timeout=10000 > I0207 04:05:46.463577 31422 group.cpp:310] Group process ((2014)@ > 67.195.138.60:56892) connected to ZooKeeper > I0207 04:05:46.463590 31422 group.cpp:752] Syncing group operations: queue > size (joins, cancels, datas) = (0, 0, 0) > I0207 04:05:46.463598 31422 group.cpp:367] Trying to create path '/znode' > in ZooKeeper > 2014-02-07 04:05:46,463:31385(0x2b613996e700):ZOO_INFO@check_events@1750: > session establishment complete on server [127.0.0.1:41512], > sessionId=0x1440a85bd86000b, negotiated timeout=10000 > I0207 04:05:46.463956 31417 group.cpp:310] Group process ((2012)@ > 67.195.138.60:56892) connected to ZooKeeper > I0207 04:05:46.464031 31417 group.cpp:752] Syncing group operations: queue > size (joins, cancels, datas) = (1, 0, 0) > I0207 04:05:46.464043 31417 group.cpp:367] Trying to create path '/znode' > in ZooKeeper > I0207 04:05:46.485545 31423 contender.cpp:243] New candidate (id='3') has > entered the contest for leadership > I0207 04:05:46.486096 31422 detector.cpp:134] Detected a new leader: > (id='3') > I0207 04:05:46.486224 31422 group.cpp:629] Trying to get > '/znode/info_0000000003' in ZooKeeper > I0207 04:05:46.486271 31419 detector.cpp:134] Detected a new leader: > (id='3') > I0207 04:05:46.486546 31420 group.cpp:629] Trying to get > '/znode/info_0000000003' in ZooKeeper > I0207 04:05:46.486671 31423 detector.cpp:134] Detected a new leader: > (id='3') > I0207 04:05:46.486893 31423 group.cpp:629] Trying to get > '/znode/info_0000000003' in ZooKeeper > I0207 04:05:46.487171 31422 detector.cpp:351] A new leading master (UPID= > [email protected]:56892) is detected > I0207 04:05:46.487293 31419 slave.cpp:501] New master detected at > [email protected]:56892 > I0207 04:05:46.487628 31420 detector.cpp:351] A new leading master (UPID= > [email protected]:56892) is detected > I0207 04:05:46.487684 31420 status_update_manager.cpp:162] New master > detected at [email protected]:56892 > I0207 04:05:46.487731 31420 master.cpp:735] The newly elected leader is > [email protected]:56892 > I0207 04:05:46.487740 31419 slave.cpp:526] Detecting new master > I0207 04:05:46.487741 31420 master.cpp:743] Elected as the leading master! > I0207 04:05:46.487921 31420 master.cpp:1902] Attempting to re-register > slave 201402070405-1015726915-56892-31385-0 at slave(143)@ > 67.195.138.60:56892 (janus.apache.org) > I0207 04:05:46.487936 31420 master.cpp:2783] Adding slave > 201402070405-1015726915-56892-31385-0 at janus.apache.org with cpus(*):2; > mem(*):1024; disk(*):23038; ports(*):[31000-32000] > I0207 04:05:46.488062 31419 slave.cpp:594] Re-registered with master > [email protected]:56892 > I0207 04:05:46.488065 31420 master.hpp:403] Adding task 0 with resources > cpus(*):1; mem(*):500 on slave 201402070405-1015726915-56892-31385-0 ( > janus.apache.org) > W0207 04:05:46.488097 31420 master.cpp:2878] Possibly orphaned task 0 of > framework 201402070405-1015726915-56892-31385-0000 running on slave > 201402070405-1015726915-56892-31385-0 (janus.apache.org) > I0207 04:05:46.488595 31418 hierarchical_allocator_process.hpp:445] Added > slave 201402070405-1015726915-56892-31385-0 (janus.apache.org) with > cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] (and > cpus(*):1; mem(*):524; disk(*):23038; ports(*):[31000-32000] available) > I0207 04:05:46.488680 31418 hierarchical_allocator_process.hpp:708] > Performed allocation for slave 201402070405-1015726915-56892-31385-0 in > 16217ns > I0207 04:05:46.489020 31424 detector.cpp:351] A new leading master (UPID= > [email protected]:56892) is detected > I0207 04:05:46.489102 31423 sched.cpp:210] New master detected at > [email protected]:56892 > I0207 04:05:46.489127 31423 sched.cpp:261] Authenticating with master > [email protected]:56892 > I0207 04:05:46.489193 31423 sched.cpp:230] Detecting new master > I0207 04:05:46.489212 31424 authenticatee.hpp:124] Creating new client > SASL connection > I0207 04:05:46.489516 31423 master.cpp:2296] Authenticating framework at > scheduler(136)@67.195.138.60:56892 > I0207 04:05:46.489599 31424 authenticator.hpp:140] Creating new server > SASL connection > I0207 04:05:46.489732 31417 authenticatee.hpp:212] Received SASL > authentication mechanisms: CRAM-MD5 > I0207 04:05:46.489760 31417 authenticatee.hpp:238] Attempting to > authenticate with mechanism 'CRAM-MD5' > I0207 04:05:46.489796 31417 authenticator.hpp:243] Received SASL > authentication start > I0207 04:05:46.489882 31417 authenticator.hpp:325] Authentication requires > more steps > I0207 04:05:46.489913 31417 authenticatee.hpp:258] Received SASL > authentication step > I0207 04:05:46.489992 31423 authenticator.hpp:271] Received SASL > authentication step > I0207 04:05:46.490034 31423 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'janus.apache.org' server FQDN: ' > janus.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false > I0207 04:05:46.490044 31423 auxprop.cpp:153] Looking up auxiliary property > '*userPassword' > I0207 04:05:46.490062 31423 auxprop.cpp:153] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I0207 04:05:46.490074 31423 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'janus.apache.org' server FQDN: ' > janus.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true > I0207 04:05:46.490082 31423 auxprop.cpp:103] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I0207 04:05:46.490088 31423 auxprop.cpp:103] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I0207 04:05:46.490108 31423 authenticator.hpp:317] Authentication success > I0207 04:05:46.490147 31417 authenticatee.hpp:298] Authentication success > I0207 04:05:46.490151 31423 master.cpp:2336] Successfully authenticated > framework at scheduler(136)@67.195.138.60:56892 > I0207 04:05:46.490228 31417 sched.cpp:335] Successfully authenticated with > master [email protected]:56892 > I0207 04:05:46.490314 31423 master.cpp:879] Re-registering framework > 201402070405-1015726915-56892-31385-0000 at scheduler(136)@ > 67.195.138.60:56892 > I0207 04:05:46.490504 31420 sched.cpp:384] Framework registered with > 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.490542 31423 slave.cpp:1305] Updating framework > 201402070405-1015726915-56892-31385-0000 pid to scheduler(136)@ > 67.195.138.60:56892 > I0207 04:05:46.490550 31420 sched.cpp:398] Scheduler::registered took > 30584ns > I0207 04:05:46.490655 31423 hierarchical_allocator_process.hpp:332] Added > framework 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.490710 31423 hierarchical_allocator_process.hpp:752] > Offering cpus(*):1; mem(*):524; disk(*):23038; ports(*):[31000-32000] on > slave 201402070405-1015726915-56892-31385-0 to framework > 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.490846 31423 hierarchical_allocator_process.hpp:688] > Performed allocation for 1 slaves in 174601ns > I0207 04:05:46.490906 31420 master.hpp:431] Adding offer > 201402070405-1015726915-56892-31385-0 with resources cpus(*):1; mem(*):524; > disk(*):23038; ports(*):[31000-32000] on slave > 201402070405-1015726915-56892-31385-0 (janus.apache.org) > I0207 04:05:46.490962 31420 master.cpp:2251] Sending 1 offers to framework > 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.491142 31424 sched.cpp:518] Scheduler::resourceOffers took > 32089ns > I0207 04:05:46.491382 31420 sched.cpp:720] Stopping framework > '201402070405-1015726915-56892-31385-0000' > I0207 04:05:46.491427 31424 master.cpp:562] Master terminating > I0207 04:05:46.491472 31424 slave.cpp:1958] [email protected]:56892exited > W0207 04:05:46.491490 31424 slave.cpp:1961] Master disconnected! Waiting > for a new master to be elected > I0207 04:05:46.491500 31385 master.cpp:210] Shutting down master > I0207 04:05:46.491575 31385 master.hpp:421] Removing task 0 with resources > cpus(*):1; mem(*):500 on slave 201402070405-1015726915-56892-31385-0 ( > janus.apache.org) > I0207 04:05:46.491701 31385 master.hpp:441] Removing offer > 201402070405-1015726915-56892-31385-0 with resources cpus(*):1; mem(*):524; > disk(*):23038; ports(*):[31000-32000] on slave > 201402070405-1015726915-56892-31385-0 (janus.apache.org) > I0207 04:05:46.491803 31385 master.cpp:253] Removing slave > 201402070405-1015726915-56892-31385-0 (janus.apache.org) > I0207 04:05:46.491806 31418 hierarchical_allocator_process.hpp:637] > Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) > on slave 201402070405-1015726915-56892-31385-0 from framework > 201402070405-1015726915-56892-31385-0000 > I0207 04:05:46.550092 31385 contender.cpp:182] Now cancelling the > membership: 3 > I0207 04:05:46.550223 31417 group.cpp:590] Trying to remove > '/znode/info_0000000003' in ZooKeeper > 2014-02-07 04:05:46,564:31385(0x2b5faa46ab00):ZOO_INFO@zookeeper_close@2505: > Closing zookeeper sessionId=0x1440a85bd86000b to [127.0.0.1:41512] > > I0207 04:05:46.564524 31418 detector.cpp:122] The current leader (id=3) is > lost > I0207 04:05:46.564594 31418 detector.cpp:134] Detected a new leader: None > I0207 04:05:46.564867 31424 detector.cpp:122] The current leader (id=3) is > lost > I0207 04:05:46.564884 31424 detector.cpp:134] Detected a new leader: None > I0207 04:05:46.565120 31423 detector.cpp:122] The current leader (id=3) is > lost > I0207 04:05:46.565168 31423 detector.cpp:134] Detected a new leader: None > I0207 04:05:46.565279 31419 slave.cpp:522] Lost leading master > I0207 04:05:46.565296 31419 slave.cpp:526] Detecting new master > 2014-02-07 04:05:46,565:31385(0x2b5faa46ab00):ZOO_INFO@zookeeper_close@2505: > Closing zookeeper sessionId=0x1440a85bd86000a to [127.0.0.1:41512] > > I0207 04:05:46.565614 31385 slave.cpp:391] Slave terminating > I0207 04:05:46.565641 31385 slave.cpp:1135] Asked to shut down framework > 201402070405-1015726915-56892-31385-0000 by @0.0.0.0:0 > W0207 04:05:46.565652 31385 slave.cpp:1143] Ignoring shutdown framework > message for 201402070405-1015726915-56892-31385-0000 because the slave has > not yet registered with the master > I0207 04:05:46.565708 31419 exec.cpp:455] Slave exited ... shutting down > I0207 04:05:46.565749 31419 exec.cpp:472] Executor::shutdown took 18170ns > 2014-02-07 04:05:46,566:31385(0x2b5faa46ab00):ZOO_INFO@zookeeper_close@2505: > Closing zookeeper sessionId=0x1440a85bd860008 to [127.0.0.1:41512] > > 2014-02-07 04:05:46,566:31385(0x2b5faa46ab00):ZOO_INFO@zookeeper_close@2505: > Closing zookeeper sessionId=0x1440a85bd860009 to [127.0.0.1:41512] > > [ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (338 ms) > I0207 04:05:46.572150 31385 zookeeper_test_server.cpp:122] Shutdown > ZooKeeperTestServer on port 41512 > [----------] 2 tests from AllocatorZooKeeperTest/0 (5698 ms total) > > [----------] Global test environment tear-down > [==========] 258 tests from 46 test cases ran. (252682 ms total) > [ PASSED ] 257 tests. > [ FAILED ] 1 test, listed below: > [ FAILED ] MasterZooKeeperTest.LostZooKeeperCluster > > 1 FAILED TEST > YOU HAVE 2 DISABLED TESTS > > make[3]: *** [check-local] Error 1 > make[3]: Leaving directory `< > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src > '> > make[2]: *** [check-am] Error 2 > make[2]: Leaving directory `< > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src > '> > make[1]: *** [check] Error 2 > make[1]: Leaving directory `< > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src > '> > make: *** [check-recursive] Error 1 > Build step 'Execute shell' marked build as failure >
