See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/1519/changes>
Changes: [bmahler] Fixed the master to drop authentication when non-leading. [bmahler] Fixed the flaky FaultTolerance.SlaveReliableRegistration test. ------------------------------------------ [...truncated 23251 lines...] 2013-12-07 07:11:49,159:22384(0x2b1f0c200700):ZOO_INFO@check_events@1632: session establishment complete on server [127.0.0.1:51092], sessionId=0x142cbe5c7d70009, negotiated timeout=10000 I1207 07:11:49.159778 22431 group.cpp:280] Group process ((1533)@140.211.11.27:50484) connected to ZooKeeper I1207 07:11:49.159797 22431 group.cpp:675] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0) I1207 07:11:49.159806 22431 group.cpp:337] Trying to create path '/znode' in ZooKeeper I1207 07:11:49.161938 22417 contender.cpp:203] New candidate (id='4', data='[email protected]:50484') has entered the contest for leadership I1207 07:11:49.162163 22422 detector.cpp:130] Detected a new leader (id='4') I1207 07:11:49.162396 22432 group.cpp:562] Trying to get '/znode/0000000004' in ZooKeeper I1207 07:11:49.162595 22411 detector.cpp:130] Detected a new leader (id='4') I1207 07:11:49.162675 22430 detector.cpp:130] Detected a new leader (id='4') I1207 07:11:49.162806 22423 group.cpp:562] Trying to get '/znode/0000000004' in ZooKeeper I1207 07:11:49.162816 22421 group.cpp:562] Trying to get '/znode/0000000004' in ZooKeeper I1207 07:11:49.163336 22419 detector.cpp:322] A new leading master ([email protected]:50484) is detected I1207 07:11:49.163419 22416 master.cpp:746] The newly elected leader is [email protected]:50484 I1207 07:11:49.163442 22416 master.cpp:750] Elected as the leading master! I1207 07:11:49.163710 22416 detector.cpp:322] A new leading master ([email protected]:50484) is detected I1207 07:11:49.163846 22433 slave.cpp:497] New master detected at [email protected]:50484 I1207 07:11:49.163951 22418 status_update_manager.cpp:160] New master detected at [email protected]:50484 I1207 07:11:49.163983 22433 slave.cpp:524] Detecting new master I1207 07:11:49.164011 22424 detector.cpp:322] A new leading master ([email protected]:50484) is detected I1207 07:11:49.164017 22415 master.cpp:1366] Attempting to register slave on hemera.apache.org at slave(136)@140.211.11.27:50484 I1207 07:11:49.164041 22415 master.cpp:2628] Adding slave 201312070711-453759884-50484-22384-0 at hemera.apache.org with cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] I1207 07:11:49.164105 22416 sched.cpp:207] New master detected at [email protected]:50484 I1207 07:11:49.164139 22416 sched.cpp:260] Authenticating with master [email protected]:50484 I1207 07:11:49.164165 22412 slave.cpp:542] Registered with master [email protected]:50484; given slave ID 201312070711-453759884-50484-22384-0 I1207 07:11:49.164340 22416 sched.cpp:229] Detecting new master I1207 07:11:49.164353 22420 authenticatee.hpp:124] Creating new client SASL connection I1207 07:11:49.164374 22427 hierarchical_allocator_process.hpp:445] Added slave 201312070711-453759884-50484-22384-0 (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] available) I1207 07:11:49.164453 22427 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201312070711-453759884-50484-22384-0 in 10308ns I1207 07:11:49.164623 22428 master.cpp:1849] Authenticating framework at scheduler(131)@140.211.11.27:50484 I1207 07:11:49.164788 22424 authenticator.hpp:140] Creating new server SASL connection I1207 07:11:49.165066 22426 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5 I1207 07:11:49.165088 22426 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5' I1207 07:11:49.165124 22431 authenticator.hpp:243] Received SASL authentication start I1207 07:11:49.165197 22431 authenticator.hpp:325] Authentication requires more steps I1207 07:11:49.165245 22429 authenticatee.hpp:258] Received SASL authentication step I1207 07:11:49.165319 22424 authenticator.hpp:271] Received SASL authentication step I1207 07:11:49.165348 22424 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1207 07:11:49.165387 22424 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1207 07:11:49.165401 22424 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1207 07:11:49.165412 22424 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1207 07:11:49.165421 22424 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1207 07:11:49.165426 22424 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1207 07:11:49.165441 22424 authenticator.hpp:317] Authentication success I1207 07:11:49.165467 22426 authenticatee.hpp:298] Authentication success I1207 07:11:49.165468 22424 master.cpp:1889] Successfully authenticated framework at scheduler(131)@140.211.11.27:50484 I1207 07:11:49.165552 22431 sched.cpp:334] Successfully authenticated with master [email protected]:50484 I1207 07:11:49.165634 22416 master.cpp:801] Received registration request from scheduler(131)@140.211.11.27:50484 I1207 07:11:49.165783 22416 master.cpp:819] Registering framework 201312070711-453759884-50484-22384-0000 at scheduler(131)@140.211.11.27:50484 I1207 07:11:49.165854 22411 sched.cpp:383] Framework registered with 201312070711-453759884-50484-22384-0000 I1207 07:11:49.165868 22417 hierarchical_allocator_process.hpp:332] Added framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.165892 22411 sched.cpp:397] Scheduler::registered took 17287ns I1207 07:11:49.165928 22417 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] on slave 201312070711-453759884-50484-22384-0 to framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.166059 22417 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 170335ns I1207 07:11:49.166106 22416 master.hpp:437] Adding offer 201312070711-453759884-50484-22384-0 with resources cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] on slave 201312070711-453759884-50484-22384-0 (hemera.apache.org) I1207 07:11:49.166165 22416 master.cpp:1804] Sending 1 offers to framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.166416 22426 sched.cpp:517] Scheduler::resourceOffers took 153008ns I1207 07:11:49.166543 22429 master.cpp:2141] Processing reply for offer 201312070711-453759884-50484-22384-0 on slave 201312070711-453759884-50484-22384-0 (hemera.apache.org) for framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.166638 22429 master.hpp:409] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201312070711-453759884-50484-22384-0 (hemera.apache.org) I1207 07:11:49.166672 22429 master.cpp:2265] Launching task 0 of framework 201312070711-453759884-50484-22384-0000 with resources cpus(*):1; mem(*):500 on slave 201312070711-453759884-50484-22384-0 (hemera.apache.org) I1207 07:11:49.166757 22426 slave.cpp:727] Got assigned task 0 for framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.166857 22429 master.hpp:447] Removing offer 201312070711-453759884-50484-22384-0 with resources cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] on slave 201312070711-453759884-50484-22384-0 (hemera.apache.org) I1207 07:11:49.166913 22426 slave.cpp:836] Launching task 0 for framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.166867 22423 hierarchical_allocator_process.hpp:547] Framework 201312070711-453759884-50484-22384-0000 left cpus(*):1; mem(*):524; disk(*):127026; ports(*):[31000-32000] unused on slave 201312070711-453759884-50484-22384-0 I1207 07:11:49.167116 22423 hierarchical_allocator_process.hpp:590] Framework 201312070711-453759884-50484-22384-0000 filtered slave 201312070711-453759884-50484-22384-0 for 5secs I1207 07:11:49.169553 22426 slave.cpp:946] Queuing task '0' for executor default of framework '201312070711-453759884-50484-22384-0000 I1207 07:11:49.169646 22414 slave.cpp:466] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_AJLI0V/slaves/201312070711-453759884-50484-22384-0/frameworks/201312070711-453759884-50484-22384-0000/executors/default/runs/3a909587-7641-4236-9561-412b9b6d8e96' I1207 07:11:49.172060 22426 exec.cpp:178] Executor started at: executor(45)@140.211.11.27:50484 with pid 22384 I1207 07:11:49.172086 22431 slave.cpp:2089] Monitoring executor default of framework 201312070711-453759884-50484-22384-0000 forked at pid 22384 I1207 07:11:49.172147 22431 slave.cpp:1422] Got registration for executor 'default' of framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.172412 22431 slave.cpp:1543] Flushing queued task 0 for executor 'default' of framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.172458 22415 exec.cpp:202] Executor registered on slave 201312070711-453759884-50484-22384-0 I1207 07:11:49.174803 22415 exec.cpp:214] Executor::registered took 15254ns I1207 07:11:49.174855 22415 exec.cpp:289] Executor asked to run task '0' I1207 07:11:49.174887 22415 exec.cpp:298] Executor::launchTask took 21541ns I1207 07:11:49.177022 22415 exec.cpp:521] Executor sending status update TASK_RUNNING (UUID: db0e6052-48b1-4b37-8df7-b9f2125d1413) for task 0 of framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.177131 22415 slave.cpp:1756] Handling status update TASK_RUNNING (UUID: db0e6052-48b1-4b37-8df7-b9f2125d1413) for task 0 of framework 201312070711-453759884-50484-22384-0000 from executor(45)@140.211.11.27:50484 I1207 07:11:49.177446 22422 status_update_manager.cpp:312] Received status update TASK_RUNNING (UUID: db0e6052-48b1-4b37-8df7-b9f2125d1413) for task 0 of framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.177516 22422 status_update_manager.cpp:491] Creating StatusUpdate stream for task 0 of framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.177747 22422 status_update_manager.cpp:365] Forwarding status update TASK_RUNNING (UUID: db0e6052-48b1-4b37-8df7-b9f2125d1413) for task 0 of framework 201312070711-453759884-50484-22384-0000 to [email protected]:50484 I1207 07:11:49.178026 22419 slave.cpp:1875] Status update manager successfully handled status update TASK_RUNNING (UUID: db0e6052-48b1-4b37-8df7-b9f2125d1413) for task 0 of framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.178047 22419 slave.cpp:1881] Sending acknowledgement for status update TASK_RUNNING (UUID: db0e6052-48b1-4b37-8df7-b9f2125d1413) for task 0 of framework 201312070711-453759884-50484-22384-0000 to executor(45)@140.211.11.27:50484 I1207 07:11:49.178155 22423 master.cpp:1552] Status update TASK_RUNNING (UUID: db0e6052-48b1-4b37-8df7-b9f2125d1413) for task 0 of framework 201312070711-453759884-50484-22384-0000 from slave(136)@140.211.11.27:50484 I1207 07:11:49.178256 22415 sched.cpp:608] Scheduler::statusUpdate took 63276ns I1207 07:11:49.178272 22410 exec.cpp:335] Executor received status update acknowledgement db0e6052-48b1-4b37-8df7-b9f2125d1413 for task 0 of framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.178480 22426 status_update_manager.cpp:390] Received status update acknowledgement (UUID: db0e6052-48b1-4b37-8df7-b9f2125d1413) for task 0 of framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.178544 22411 master.cpp:556] Master terminating I1207 07:11:49.178684 22426 slave.cpp:1362] Status update manager successfully handled status update acknowledgement (UUID: db0e6052-48b1-4b37-8df7-b9f2125d1413) for task 0 of framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.178725 22384 master.cpp:209] Shutting down master I1207 07:11:49.178752 22426 slave.cpp:1956] [email protected]:50484 exited W1207 07:11:49.178767 22426 slave.cpp:1959] Master disconnected! Waiting for a new master to be elected I1207 07:11:49.178794 22384 master.hpp:427] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201312070711-453759884-50484-22384-0 (hemera.apache.org) I1207 07:11:49.178997 22384 master.cpp:252] Removing slave 201312070711-453759884-50484-22384-0 (hemera.apache.org) I1207 07:11:49.179103 22432 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000]) on slave 201312070711-453759884-50484-22384-0 from framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.180732 22384 contender.cpp:172] Now cancelling the membership: 4 I1207 07:11:49.180951 22410 group.cpp:519] Trying to remove '/znode/0000000004' in ZooKeeper 2013-12-07 07:11:49,183:22384(0x2b1c5aea57c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x142cbe5c7d70006 to [127.0.0.1:51092] I1207 07:11:49.184684 22412 detector.cpp:116] The current leader (id=4) is lost I1207 07:11:49.184705 22412 detector.cpp:138] No new leader is elected after election I1207 07:11:49.185093 22420 sched.cpp:201] Scheduler::disconnected took 16909ns I1207 07:11:49.185112 22420 sched.cpp:223] No master detected I1207 07:11:49.185123 22420 sched.cpp:229] Detecting new master I1207 07:11:49.185153 22421 detector.cpp:116] The current leader (id=4) is lost I1207 07:11:49.185169 22421 detector.cpp:138] No new leader is elected after election I1207 07:11:49.185436 22427 slave.cpp:518] Lost leading master I1207 07:11:49.185595 22427 slave.cpp:524] Detecting new master 2013-12-07 07:11:49,185:22384(0x2b1c5aea57c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x142cbe5c7d70007 to [127.0.0.1:51092] I1207 07:11:49.187181 22422 master.cpp:284] Master started on 140.211.11.27:50484 I1207 07:11:49.187242 22422 master.cpp:298] Master ID: 201312070711-453759884-50484-22384 I1207 07:11:49.187250 22422 master.cpp:301] Master only allowing authenticated frameworks to register! I1207 07:11:49.187757 22427 master.cpp:84] No whitelist given. Advertising offers for all slaves 2013-12-07 07:11:49,188:22384(0x2b1c5c2b3700):ZOO_INFO@log_env@658: Client environment:zookeeper.version=zookeeper C client 3.3.4 2013-12-07 07:11:49,188:22384(0x2b1c5c2b3700):ZOO_INFO@log_env@662: Client environment:host.name=hemera 2013-12-07 07:11:49,188:22384(0x2b1c5c2b3700):ZOO_INFO@log_env@669: Client environment:os.name=Linux 2013-12-07 07:11:49,188:22384(0x2b1c5c2b3700):ZOO_INFO@log_env@670: Client environment:os.arch=3.2.0-51-generic 2013-12-07 07:11:49,188:22384(0x2b1c5c2b3700):ZOO_INFO@log_env@671: Client environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013 2013-12-07 07:11:49,188:22384(0x2b1c5c2b3700):ZOO_INFO@log_env@679: Client environment:user.name=(null) 2013-12-07 07:11:49,188:22384(0x2b1c5c2b3700):ZOO_INFO@log_env@687: Client environment:user.home=/home/jenkins 2013-12-07 07:11:49,188:22384(0x2b1c5c2b3700):ZOO_INFO@log_env@699: Client environment:user.dir=/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src 2013-12-07 07:11:49,188:22384(0x2b1c5c2b3700):ZOO_INFO@zookeeper_init@727: Initiating client connection, host=127.0.0.1:51092 sessionTimeout=10000 watcher=0x2b1c5875a2d0 sessionId=0 sessionPasswd=<null> context=0x2b1cbc0742d0 flags=0 I1207 07:11:49.188578 22426 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : [email protected]:50484 2013-12-07 07:11:49,188:22384(0x2b1f0c401700):ZOO_INFO@check_events@1585: initiated connection to server [127.0.0.1:51092] I1207 07:11:49.188802 22423 contender.cpp:122] Joining the ZK group with data: '[email protected]:50484' 2013-12-07 07:11:49,188:22384(0x2b1c5c0b2700):ZOO_INFO@log_env@658: Client environment:zookeeper.version=zookeeper C client 3.3.4 2013-12-07 07:11:49,188:22384(0x2b1c5c0b2700):ZOO_INFO@log_env@662: Client environment:host.name=hemera 2013-12-07 07:11:49,188:22384(0x2b1c5c0b2700):ZOO_INFO@log_env@669: Client environment:os.name=Linux 2013-12-07 07:11:49,188:22384(0x2b1c5c0b2700):ZOO_INFO@log_env@670: Client environment:os.arch=3.2.0-51-generic 2013-12-07 07:11:49,189:22384(0x2b1c5c0b2700):ZOO_INFO@log_env@671: Client environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013 2013-12-07 07:11:49,189:22384(0x2b1c5c0b2700):ZOO_INFO@log_env@679: Client environment:user.name=(null) 2013-12-07 07:11:49,189:22384(0x2b1c5c0b2700):ZOO_INFO@log_env@687: Client environment:user.home=/home/jenkins 2013-12-07 07:11:49,189:22384(0x2b1c5c0b2700):ZOO_INFO@log_env@699: Client environment:user.dir=/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src 2013-12-07 07:11:49,189:22384(0x2b1c5c0b2700):ZOO_INFO@zookeeper_init@727: Initiating client connection, host=127.0.0.1:51092 sessionTimeout=10000 watcher=0x2b1c5875a2d0 sessionId=0 sessionPasswd=<null> context=0x2b1cb8078ba0 flags=0 2013-12-07 07:11:49,189:22384(0x2b1f30401700):ZOO_INFO@check_events@1585: initiated connection to server [127.0.0.1:51092] 2013-12-07 07:11:49,190:22384(0x2b1f0c401700):ZOO_INFO@check_events@1632: session establishment complete on server [127.0.0.1:51092], sessionId=0x142cbe5c7d7000a, negotiated timeout=10000 I1207 07:11:49.190600 22427 group.cpp:280] Group process ((1548)@140.211.11.27:50484) connected to ZooKeeper I1207 07:11:49.190623 22427 group.cpp:675] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0) I1207 07:11:49.190634 22427 group.cpp:337] Trying to create path '/znode' in ZooKeeper 2013-12-07 07:11:49,191:22384(0x2b1f30401700):ZOO_INFO@check_events@1632: session establishment complete on server [127.0.0.1:51092], sessionId=0x142cbe5c7d7000b, negotiated timeout=10000 I1207 07:11:49.192121 22421 group.cpp:280] Group process ((1546)@140.211.11.27:50484) connected to ZooKeeper I1207 07:11:49.192142 22421 group.cpp:675] Syncing group operations: queue size (joins, cancels, datas) = (1, 0, 0) I1207 07:11:49.192152 22421 group.cpp:337] Trying to create path '/znode' in ZooKeeper I1207 07:11:49.195534 22430 contender.cpp:203] New candidate (id='6', data='[email protected]:50484') has entered the contest for leadership I1207 07:11:49.196617 22415 detector.cpp:130] Detected a new leader (id='6') I1207 07:11:49.196849 22411 detector.cpp:130] Detected a new leader (id='6') I1207 07:11:49.197293 22413 detector.cpp:130] Detected a new leader (id='6') I1207 07:11:49.197505 22411 group.cpp:562] Trying to get '/znode/0000000006' in ZooKeeper I1207 07:11:49.197594 22417 group.cpp:562] Trying to get '/znode/0000000006' in ZooKeeper I1207 07:11:49.198151 22421 group.cpp:562] Trying to get '/znode/0000000006' in ZooKeeper I1207 07:11:49.198890 22432 detector.cpp:322] A new leading master ([email protected]:50484) is detected I1207 07:11:49.198941 22432 master.cpp:746] The newly elected leader is [email protected]:50484 I1207 07:11:49.198953 22432 master.cpp:750] Elected as the leading master! I1207 07:11:49.199429 22417 detector.cpp:322] A new leading master ([email protected]:50484) is detected I1207 07:11:49.199549 22416 slave.cpp:497] New master detected at [email protected]:50484 I1207 07:11:49.199592 22417 detector.cpp:322] A new leading master ([email protected]:50484) is detected I1207 07:11:49.199620 22423 status_update_manager.cpp:160] New master detected at [email protected]:50484 I1207 07:11:49.199653 22416 slave.cpp:524] Detecting new master I1207 07:11:49.199750 22423 master.cpp:1455] Attempting to re-register slave 201312070711-453759884-50484-22384-0 at slave(136)@140.211.11.27:50484 (hemera.apache.org) I1207 07:11:49.199769 22423 master.cpp:2628] Adding slave 201312070711-453759884-50484-22384-0 at hemera.apache.org with cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] I1207 07:11:49.199990 22428 sched.cpp:207] New master detected at [email protected]:50484 I1207 07:11:49.200012 22428 sched.cpp:260] Authenticating with master [email protected]:50484 I1207 07:11:49.200052 22425 slave.cpp:592] Re-registered with master [email protected]:50484 I1207 07:11:49.200192 22428 sched.cpp:229] Detecting new master I1207 07:11:49.200487 22433 authenticatee.hpp:124] Creating new client SASL connection I1207 07:11:49.200938 22423 master.hpp:409] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201312070711-453759884-50484-22384-0 (hemera.apache.org) W1207 07:11:49.200973 22423 master.cpp:2723] Possibly orphaned task 0 of framework 201312070711-453759884-50484-22384-0000 running on slave 201312070711-453759884-50484-22384-0 (hemera.apache.org) I1207 07:11:49.201388 22419 hierarchical_allocator_process.hpp:445] Added slave 201312070711-453759884-50484-22384-0 (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] (and cpus(*):1; mem(*):524; disk(*):127026; ports(*):[31000-32000] available) I1207 07:11:49.201433 22419 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201312070711-453759884-50484-22384-0 in 5204ns I1207 07:11:49.201673 22423 master.cpp:1849] Authenticating framework at scheduler(131)@140.211.11.27:50484 I1207 07:11:49.201928 22423 authenticator.hpp:140] Creating new server SASL connection I1207 07:11:49.202277 22423 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5 I1207 07:11:49.202358 22423 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5' I1207 07:11:49.202553 22428 authenticator.hpp:243] Received SASL authentication start I1207 07:11:49.202626 22428 authenticator.hpp:325] Authentication requires more steps I1207 07:11:49.202656 22428 authenticatee.hpp:258] Received SASL authentication step I1207 07:11:49.202707 22428 authenticator.hpp:271] Received SASL authentication step I1207 07:11:49.202847 22428 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1207 07:11:49.202858 22428 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1207 07:11:49.202870 22428 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1207 07:11:49.202880 22428 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1207 07:11:49.202888 22428 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1207 07:11:49.202893 22428 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1207 07:11:49.202905 22428 authenticator.hpp:317] Authentication success I1207 07:11:49.202929 22428 authenticatee.hpp:298] Authentication success I1207 07:11:49.202950 22428 master.cpp:1889] Successfully authenticated framework at scheduler(131)@140.211.11.27:50484 I1207 07:11:49.203425 22422 sched.cpp:334] Successfully authenticated with master [email protected]:50484 I1207 07:11:49.203501 22413 master.cpp:889] Re-registering framework 201312070711-453759884-50484-22384-0000 at scheduler(131)@140.211.11.27:50484 I1207 07:11:49.203857 22411 sched.cpp:383] Framework registered with 201312070711-453759884-50484-22384-0000 I1207 07:11:49.203891 22411 sched.cpp:397] Scheduler::registered took 12735ns I1207 07:11:49.203913 22411 slave.cpp:1303] Updating framework 201312070711-453759884-50484-22384-0000 pid to scheduler(131)@140.211.11.27:50484 I1207 07:11:49.204007 22413 hierarchical_allocator_process.hpp:332] Added framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.204068 22413 hierarchical_allocator_process.hpp:752] Offering cpus(*):1; mem(*):524; disk(*):127026; ports(*):[31000-32000] on slave 201312070711-453759884-50484-22384-0 to framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.204301 22413 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 218540ns I1207 07:11:49.204354 22418 master.hpp:437] Adding offer 201312070711-453759884-50484-22384-0 with resources cpus(*):1; mem(*):524; disk(*):127026; ports(*):[31000-32000] on slave 201312070711-453759884-50484-22384-0 (hemera.apache.org) I1207 07:11:49.204409 22418 master.cpp:1804] Sending 1 offers to framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.204638 22420 sched.cpp:517] Scheduler::resourceOffers took 30680ns I1207 07:11:49.204912 22416 sched.cpp:719] Stopping framework '201312070711-453759884-50484-22384-0000' I1207 07:11:49.204921 22415 master.cpp:556] Master terminating I1207 07:11:49.205415 22410 slave.cpp:1956] [email protected]:50484 exited W1207 07:11:49.205438 22410 slave.cpp:1959] Master disconnected! Waiting for a new master to be elected I1207 07:11:49.205442 22384 master.cpp:209] Shutting down master I1207 07:11:49.205503 22384 master.hpp:427] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201312070711-453759884-50484-22384-0 (hemera.apache.org) I1207 07:11:49.205593 22384 master.hpp:447] Removing offer 201312070711-453759884-50484-22384-0 with resources cpus(*):1; mem(*):524; disk(*):127026; ports(*):[31000-32000] on slave 201312070711-453759884-50484-22384-0 (hemera.apache.org) I1207 07:11:49.205677 22384 master.cpp:252] Removing slave 201312070711-453759884-50484-22384-0 (hemera.apache.org) I1207 07:11:49.205720 22429 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave 201312070711-453759884-50484-22384-0 from framework 201312070711-453759884-50484-22384-0000 I1207 07:11:49.206446 22414 contender.cpp:172] Now cancelling the membership: 6 I1207 07:11:49.206876 22413 group.cpp:519] Trying to remove '/znode/0000000006' in ZooKeeper 2013-12-07 07:11:49,208:22384(0x2b1c5aea57c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x142cbe5c7d7000b to [127.0.0.1:51092] I1207 07:11:49.209091 22424 detector.cpp:116] The current leader (id=6) is lost I1207 07:11:49.209112 22424 detector.cpp:138] No new leader is elected after election I1207 07:11:49.209278 22414 detector.cpp:116] The current leader (id=6) is lost I1207 07:11:49.209300 22414 detector.cpp:138] No new leader is elected after election 2013-12-07 07:11:49,209:22384(0x2b1c5aea57c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x142cbe5c7d7000a to [127.0.0.1:51092] I1207 07:11:49.209784 22419 detector.cpp:116] The current leader (id=6) is lost I1207 07:11:49.209800 22419 detector.cpp:138] No new leader is elected after election I1207 07:11:49.210065 22425 slave.cpp:518] Lost leading master I1207 07:11:49.210083 22425 slave.cpp:524] Detecting new master I1207 07:11:49.210414 22411 slave.cpp:391] Slave terminating I1207 07:11:49.210445 22411 slave.cpp:1133] Asked to shut down framework 201312070711-453759884-50484-22384-0000 by @0.0.0.0:0 W1207 07:11:49.210458 22411 slave.cpp:1141] Ignoring shutdown framework message for 201312070711-453759884-50484-22384-0000 because the slave has not yet registered with the master I1207 07:11:49.210505 22413 exec.cpp:455] Slave exited ... shutting down I1207 07:11:49.210543 22413 exec.cpp:472] Executor::shutdown took 18402ns 2013-12-07 07:11:49,211:22384(0x2b1c5aea57c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x142cbe5c7d70009 to [127.0.0.1:51092] 2013-12-07 07:11:49,212:22384(0x2b1c5aea57c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x142cbe5c7d70008 to [127.0.0.1:51092] [ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (61 ms) I1207 07:11:49.214648 22384 zookeeper_test_server.cpp:93] Shutdown ZooKeeperTestServer on port 51092 [----------] 2 tests from AllocatorZooKeeperTest/0 (6149 ms total) [----------] Global test environment tear-down [==========] 246 tests from 43 test cases ran. (165960 ms total) [ PASSED ] 245 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 `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src' make[2]: *** [check-am] Error 2 make[2]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/src' make[1]: *** [check] Error 2 make[1]: Leaving directory `/x1/jenkins/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
