See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/1522/changes>
Changes: [bmahler] Fixed the python tests in the presence of muliple eggs. ------------------------------------------ [...truncated 22233 lines...] I1210 20:55:35.079139 2473 slave.cpp:524] Detecting new master I1210 20:55:35.079169 2469 master.cpp:1366] Attempting to register slave on hemera.apache.org at slave(136)@140.211.11.27:39024 I1210 20:55:35.079190 2469 master.cpp:2628] Adding slave 201312102055-453759884-39024-2442-0 at hemera.apache.org with cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] I1210 20:55:35.079254 2476 slave.cpp:542] Registered with master [email protected]:39024; given slave ID 201312102055-453759884-39024-2442-0 I1210 20:55:35.079336 2469 master.cpp:1849] Authenticating framework at scheduler(131)@140.211.11.27:39024 I1210 20:55:35.079336 2477 hierarchical_allocator_process.hpp:445] Added slave 201312102055-453759884-39024-2442-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) I1210 20:55:35.079377 2477 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201312102055-453759884-39024-2442-0 in 4503ns I1210 20:55:35.079463 2466 authenticator.hpp:140] Creating new server SASL connection I1210 20:55:35.079566 2462 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5 I1210 20:55:35.079581 2462 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5' I1210 20:55:35.079608 2467 authenticator.hpp:243] Received SASL authentication start I1210 20:55:35.079668 2467 authenticator.hpp:325] Authentication requires more steps I1210 20:55:35.079695 2462 authenticatee.hpp:258] Received SASL authentication step I1210 20:55:35.079726 2462 authenticator.hpp:271] Received SASL authentication step I1210 20:55:35.079746 2462 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 I1210 20:55:35.079756 2462 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1210 20:55:35.079768 2462 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1210 20:55:35.079777 2462 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 I1210 20:55:35.079782 2462 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1210 20:55:35.079784 2462 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1210 20:55:35.079793 2462 authenticator.hpp:317] Authentication success I1210 20:55:35.079820 2469 authenticatee.hpp:298] Authentication success I1210 20:55:35.079839 2467 master.cpp:1889] Successfully authenticated framework at scheduler(131)@140.211.11.27:39024 I1210 20:55:35.079907 2479 sched.cpp:334] Successfully authenticated with master [email protected]:39024 I1210 20:55:35.079957 2483 master.cpp:801] Received registration request from scheduler(131)@140.211.11.27:39024 I1210 20:55:35.080063 2483 master.cpp:819] Registering framework 201312102055-453759884-39024-2442-0000 at scheduler(131)@140.211.11.27:39024 I1210 20:55:35.080106 2461 sched.cpp:383] Framework registered with 201312102055-453759884-39024-2442-0000 I1210 20:55:35.080119 2479 hierarchical_allocator_process.hpp:332] Added framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.080126 2461 sched.cpp:397] Scheduler::registered took 9692ns I1210 20:55:35.080160 2479 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] on slave 201312102055-453759884-39024-2442-0 to framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.080278 2479 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 143324ns I1210 20:55:35.080307 2483 master.hpp:437] Adding offer 201312102055-453759884-39024-2442-0 with resources cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] on slave 201312102055-453759884-39024-2442-0 (hemera.apache.org) I1210 20:55:35.080340 2483 master.cpp:1804] Sending 1 offers to framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.080519 2466 sched.cpp:517] Scheduler::resourceOffers took 97815ns I1210 20:55:35.080590 2466 master.cpp:2141] Processing reply for offer 201312102055-453759884-39024-2442-0 on slave 201312102055-453759884-39024-2442-0 (hemera.apache.org) for framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.080653 2466 master.hpp:409] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201312102055-453759884-39024-2442-0 (hemera.apache.org) I1210 20:55:35.080674 2466 master.cpp:2265] Launching task 0 of framework 201312102055-453759884-39024-2442-0000 with resources cpus(*):1; mem(*):500 on slave 201312102055-453759884-39024-2442-0 (hemera.apache.org) I1210 20:55:35.080734 2469 slave.cpp:727] Got assigned task 0 for framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.080792 2479 hierarchical_allocator_process.hpp:547] Framework 201312102055-453759884-39024-2442-0000 left cpus(*):1; mem(*):524; disk(*):127026; ports(*):[31000-32000] unused on slave 201312102055-453759884-39024-2442-0 I1210 20:55:35.080801 2466 master.hpp:447] Removing offer 201312102055-453759884-39024-2442-0 with resources cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] on slave 201312102055-453759884-39024-2442-0 (hemera.apache.org) I1210 20:55:35.080879 2479 hierarchical_allocator_process.hpp:590] Framework 201312102055-453759884-39024-2442-0000 filtered slave 201312102055-453759884-39024-2442-0 for 5secs I1210 20:55:35.080899 2469 slave.cpp:836] Launching task 0 for framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.083348 2469 slave.cpp:946] Queuing task '0' for executor default of framework '201312102055-453759884-39024-2442-0000 I1210 20:55:35.083608 2468 slave.cpp:466] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_dkDInR/slaves/201312102055-453759884-39024-2442-0/frameworks/201312102055-453759884-39024-2442-0000/executors/default/runs/2a497e5f-329e-435b-a161-36f08e2e4108' I1210 20:55:35.085834 2469 exec.cpp:178] Executor started at: executor(45)@140.211.11.27:39024 with pid 2442 I1210 20:55:35.085880 2467 slave.cpp:2089] Monitoring executor default of framework 201312102055-453759884-39024-2442-0000 forked at pid 2442 I1210 20:55:35.085922 2467 slave.cpp:1422] Got registration for executor 'default' of framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.085991 2467 slave.cpp:1543] Flushing queued task 0 for executor 'default' of framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.086069 2477 exec.cpp:202] Executor registered on slave 201312102055-453759884-39024-2442-0 I1210 20:55:35.087465 2477 exec.cpp:214] Executor::registered took 9713ns I1210 20:55:35.087501 2477 exec.cpp:289] Executor asked to run task '0' I1210 20:55:35.087519 2477 exec.cpp:298] Executor::launchTask took 13157ns I1210 20:55:35.088785 2477 exec.cpp:521] Executor sending status update TASK_RUNNING (UUID: f58e75b8-c8ad-46d1-b579-16307a83e49f) for task 0 of framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.088850 2477 slave.cpp:1756] Handling status update TASK_RUNNING (UUID: f58e75b8-c8ad-46d1-b579-16307a83e49f) for task 0 of framework 201312102055-453759884-39024-2442-0000 from executor(45)@140.211.11.27:39024 I1210 20:55:35.088999 2483 status_update_manager.cpp:312] Received status update TASK_RUNNING (UUID: f58e75b8-c8ad-46d1-b579-16307a83e49f) for task 0 of framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.089015 2483 status_update_manager.cpp:491] Creating StatusUpdate stream for task 0 of framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.089048 2483 status_update_manager.cpp:365] Forwarding status update TASK_RUNNING (UUID: f58e75b8-c8ad-46d1-b579-16307a83e49f) for task 0 of framework 201312102055-453759884-39024-2442-0000 to [email protected]:39024 I1210 20:55:35.089876 2483 slave.cpp:1875] Status update manager successfully handled status update TASK_RUNNING (UUID: f58e75b8-c8ad-46d1-b579-16307a83e49f) for task 0 of framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.089889 2483 slave.cpp:1881] Sending acknowledgement for status update TASK_RUNNING (UUID: f58e75b8-c8ad-46d1-b579-16307a83e49f) for task 0 of framework 201312102055-453759884-39024-2442-0000 to executor(45)@140.211.11.27:39024 I1210 20:55:35.090023 2473 master.cpp:1552] Status update TASK_RUNNING (UUID: f58e75b8-c8ad-46d1-b579-16307a83e49f) for task 0 of framework 201312102055-453759884-39024-2442-0000 from slave(136)@140.211.11.27:39024 I1210 20:55:35.090114 2477 sched.cpp:608] Scheduler::statusUpdate took 14339ns I1210 20:55:35.090396 2481 master.cpp:556] Master terminating I1210 20:55:35.090411 2468 exec.cpp:335] Executor received status update acknowledgement f58e75b8-c8ad-46d1-b579-16307a83e49f for task 0 of framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.090437 2442 master.cpp:209] Shutting down master I1210 20:55:35.090456 2483 slave.cpp:1956] [email protected]:39024 exited W1210 20:55:35.090471 2483 slave.cpp:1959] Master disconnected! Waiting for a new master to be elected I1210 20:55:35.090476 2442 master.hpp:427] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201312102055-453759884-39024-2442-0 (hemera.apache.org) I1210 20:55:35.090481 2470 status_update_manager.cpp:390] Received status update acknowledgement (UUID: f58e75b8-c8ad-46d1-b579-16307a83e49f) for task 0 of framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.090534 2470 slave.cpp:1362] Status update manager successfully handled status update acknowledgement (UUID: f58e75b8-c8ad-46d1-b579-16307a83e49f) for task 0 of framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.090631 2442 master.cpp:252] Removing slave 201312102055-453759884-39024-2442-0 (hemera.apache.org) I1210 20:55:35.090647 2482 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000]) on slave 201312102055-453759884-39024-2442-0 from framework 201312102055-453759884-39024-2442-0000 I1210 20:55:35.091474 2480 contender.cpp:172] Now cancelling the membership: 4 I1210 20:55:35.092222 2484 group.cpp:519] Trying to remove '/znode/0000000004' in ZooKeeper 2013-12-10 20:55:35,093:2442(0x2ac226ca17c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x142de4b1d980007 to [127.0.0.1:58949] I1210 20:55:35.093782 2468 detector.cpp:116] The current leader (id=4) is lost I1210 20:55:35.093794 2468 detector.cpp:138] No new leader is elected after election I1210 20:55:35.094171 2474 detector.cpp:116] The current leader (id=4) is lost I1210 20:55:35.094182 2474 detector.cpp:138] No new leader is elected after election I1210 20:55:35.094398 2466 slave.cpp:518] Lost leading master I1210 20:55:35.094409 2466 slave.cpp:524] Detecting new master I1210 20:55:35.094502 2478 detector.cpp:116] The current leader (id=4) is lost I1210 20:55:35.094516 2478 detector.cpp:138] No new leader is elected after election 2013-12-10 20:55:35,094:2442(0x2ac226ca17c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x142de4b1d980006 to [127.0.0.1:58949] I1210 20:55:35.094759 2474 sched.cpp:201] Scheduler::disconnected took 4700ns I1210 20:55:35.094769 2474 sched.cpp:223] No master detected I1210 20:55:35.094771 2474 sched.cpp:229] Detecting new master I1210 20:55:35.095448 2479 master.cpp:284] Master started on 140.211.11.27:39024 I1210 20:55:35.095476 2479 master.cpp:298] Master ID: 201312102055-453759884-39024-2442 I1210 20:55:35.095485 2479 master.cpp:301] Master only allowing authenticated frameworks to register! I1210 20:55:35.095654 2465 master.cpp:84] No whitelist given. Advertising offers for all slaves I1210 20:55:35.095803 2472 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : [email protected]:39024 2013-12-10 20:55:35,095:2442(0x2ac2298bb700):ZOO_INFO@log_env@658: Client environment:zookeeper.version=zookeeper C client 3.3.4 2013-12-10 20:55:35,095:2442(0x2ac2298bb700):ZOO_INFO@log_env@662: Client environment:host.name=hemera 2013-12-10 20:55:35,095:2442(0x2ac2298bb700):ZOO_INFO@log_env@669: Client environment:os.name=Linux 2013-12-10 20:55:35,095:2442(0x2ac2298bb700):ZOO_INFO@log_env@670: Client environment:os.arch=3.2.0-57-generic 2013-12-10 20:55:35,095:2442(0x2ac2298bb700):ZOO_INFO@log_env@671: Client environment:os.version=#87-Ubuntu SMP Tue Nov 12 21:35:10 UTC 2013 2013-12-10 20:55:35,095:2442(0x2ac228eb6700):ZOO_INFO@log_env@658: Client environment:zookeeper.version=zookeeper C client 3.3.4 2013-12-10 20:55:35,095:2442(0x2ac228eb6700):ZOO_INFO@log_env@662: Client environment:host.name=hemera 2013-12-10 20:55:35,095:2442(0x2ac228eb6700):ZOO_INFO@log_env@669: Client environment:os.name=Linux 2013-12-10 20:55:35,095:2442(0x2ac228eb6700):ZOO_INFO@log_env@670: Client environment:os.arch=3.2.0-57-generic 2013-12-10 20:55:35,095:2442(0x2ac2298bb700):ZOO_INFO@log_env@679: Client environment:user.name=(null) 2013-12-10 20:55:35,095:2442(0x2ac228eb6700):ZOO_INFO@log_env@671: Client environment:os.version=#87-Ubuntu SMP Tue Nov 12 21:35:10 UTC 2013 I1210 20:55:35.095990 2480 contender.cpp:122] Joining the ZK group with data: '[email protected]:39024' 2013-12-10 20:55:35,096:2442(0x2ac2298bb700):ZOO_INFO@log_env@687: Client environment:user.home=/home/jenkins 2013-12-10 20:55:35,096:2442(0x2ac2298bb700):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-10 20:55:35,096:2442(0x2ac228eb6700):ZOO_INFO@log_env@679: Client environment:user.name=(null) 2013-12-10 20:55:35,096:2442(0x2ac2298bb700):ZOO_INFO@zookeeper_init@727: Initiating client connection, host=127.0.0.1:58949 sessionTimeout=10000 watcher=0x2ac2245552d0 sessionId=0 sessionPasswd=<null> context=0x2ac2600c1190 flags=0 2013-12-10 20:55:35,096:2442(0x2ac228eb6700):ZOO_INFO@log_env@687: Client environment:user.home=/home/jenkins 2013-12-10 20:55:35,096:2442(0x2ac228eb6700):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-10 20:55:35,096:2442(0x2ac228eb6700):ZOO_INFO@zookeeper_init@727: Initiating client connection, host=127.0.0.1:58949 sessionTimeout=10000 watcher=0x2ac2245552d0 sessionId=0 sessionPasswd=<null> context=0x2ac298081b90 flags=0 2013-12-10 20:55:35,096:2442(0x2ac4b121c700):ZOO_INFO@check_events@1585: initiated connection to server [127.0.0.1:58949] 2013-12-10 20:55:35,096:2442(0x2ac4b141d700):ZOO_INFO@check_events@1585: initiated connection to server [127.0.0.1:58949] 2013-12-10 20:55:35,097:2442(0x2ac4b121c700):ZOO_INFO@check_events@1632: session establishment complete on server [127.0.0.1:58949], sessionId=0x142de4b1d98000a, negotiated timeout=10000 I1210 20:55:35.097123 2461 group.cpp:280] Group process ((1546)@140.211.11.27:39024) connected to ZooKeeper I1210 20:55:35.097133 2461 group.cpp:675] Syncing group operations: queue size (joins, cancels, datas) = (1, 0, 0) I1210 20:55:35.097138 2461 group.cpp:337] Trying to create path '/znode' in ZooKeeper 2013-12-10 20:55:35,097:2442(0x2ac4b141d700):ZOO_INFO@check_events@1632: session establishment complete on server [127.0.0.1:58949], sessionId=0x142de4b1d98000b, negotiated timeout=10000 I1210 20:55:35.097609 2466 group.cpp:280] Group process ((1548)@140.211.11.27:39024) connected to ZooKeeper I1210 20:55:35.097623 2466 group.cpp:675] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0) I1210 20:55:35.097631 2466 group.cpp:337] Trying to create path '/znode' in ZooKeeper I1210 20:55:35.099056 2463 contender.cpp:203] New candidate (id='6', data='[email protected]:39024') has entered the contest for leadership I1210 20:55:35.099130 2474 detector.cpp:130] Detected a new leader (id='6') I1210 20:55:35.099445 2483 detector.cpp:130] Detected a new leader (id='6') I1210 20:55:35.099465 2474 group.cpp:562] Trying to get '/znode/0000000006' in ZooKeeper I1210 20:55:35.099695 2468 group.cpp:562] Trying to get '/znode/0000000006' in ZooKeeper I1210 20:55:35.099954 2463 detector.cpp:322] A new leading master ([email protected]:39024) is detected I1210 20:55:35.100010 2464 sched.cpp:207] New master detected at [email protected]:39024 I1210 20:55:35.100030 2464 sched.cpp:260] Authenticating with master [email protected]:39024 I1210 20:55:35.100078 2464 sched.cpp:229] Detecting new master I1210 20:55:35.100091 2484 authenticatee.hpp:124] Creating new client SASL connection I1210 20:55:35.100225 2470 detector.cpp:130] Detected a new leader (id='6') W1210 20:55:35.100256 2464 master.cpp:1819] Ignoring authenticate message from authenticatee(150)@140.211.11.27:39024 since not elected yet I1210 20:55:35.100262 2466 detector.cpp:322] A new leading master ([email protected]:39024) is detected I1210 20:55:35.100311 2463 master.cpp:746] The newly elected leader is [email protected]:39024 I1210 20:55:35.100325 2463 master.cpp:750] Elected as the leading master! I1210 20:55:35.100368 2484 group.cpp:562] Trying to get '/znode/0000000006' in ZooKeeper I1210 20:55:35.100739 2464 detector.cpp:322] A new leading master ([email protected]:39024) is detected I1210 20:55:35.100785 2469 slave.cpp:497] New master detected at [email protected]:39024 I1210 20:55:35.100838 2463 status_update_manager.cpp:160] New master detected at [email protected]:39024 I1210 20:55:35.100874 2469 slave.cpp:524] Detecting new master I1210 20:55:35.100919 2466 master.cpp:1455] Attempting to re-register slave 201312102055-453759884-39024-2442-0 at slave(136)@140.211.11.27:39024 (hemera.apache.org) I1210 20:55:35.100932 2466 master.cpp:2628] Adding slave 201312102055-453759884-39024-2442-0 at hemera.apache.org with cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] I1210 20:55:35.100996 2468 slave.cpp:592] Re-registered with master [email protected]:39024 I1210 20:55:35.101009 2466 master.hpp:409] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201312102055-453759884-39024-2442-0 (hemera.apache.org) W1210 20:55:35.101033 2466 master.cpp:2723] Possibly orphaned task 0 of framework 201312102055-453759884-39024-2442-0000 running on slave 201312102055-453759884-39024-2442-0 (hemera.apache.org) I1210 20:55:35.101199 2482 hierarchical_allocator_process.hpp:445] Added slave 201312102055-453759884-39024-2442-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) I1210 20:55:35.101235 2482 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201312102055-453759884-39024-2442-0 in 3971ns I1210 20:55:36.066045 2462 monitor.cpp:193] Publishing resource usage for executor 'default' of framework '201312102055-453759884-39024-2442-0000' I1210 20:55:36.087582 2482 monitor.cpp:193] Publishing resource usage for executor 'default' of framework '201312102055-453759884-39024-2442-0000' I1210 20:55:36.096761 2461 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 17710ns I1210 20:55:37.068197 2461 monitor.cpp:193] Publishing resource usage for executor 'default' of framework '201312102055-453759884-39024-2442-0000' I1210 20:55:37.088235 2461 monitor.cpp:193] Publishing resource usage for executor 'default' of framework '201312102055-453759884-39024-2442-0000' I1210 20:55:37.097439 2461 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 18510ns 2013-12-10 20:55:37,523:2442(0x2ac500401700):ZOO_ERROR@handle_socket_error_msg@1579: Socket [127.0.0.1:33938] zk retcode=-4, errno=111(Connection refused): server refused to accept the client I1210 20:55:38.069762 2461 monitor.cpp:193] Publishing resource usage for executor 'default' of framework '201312102055-453759884-39024-2442-0000' I1210 20:55:38.088994 2473 monitor.cpp:193] Publishing resource usage for executor 'default' of framework '201312102055-453759884-39024-2442-0000' I1210 20:55:38.098119 2473 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 57932ns I1210 20:55:39.071090 2473 monitor.cpp:193] Publishing resource usage for executor 'default' of framework '201312102055-453759884-39024-2442-0000' I1210 20:55:39.089685 2475 monitor.cpp:193] Publishing resource usage for executor 'default' of framework '201312102055-453759884-39024-2442-0000' I1210 20:55:39.098814 2471 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 48007ns I1210 20:55:40.073209 2475 monitor.cpp:193] Publishing resource usage for executor 'default' of framework '201312102055-453759884-39024-2442-0000' I1210 20:55:40.090739 2484 monitor.cpp:193] Publishing resource usage for executor 'default' of framework '201312102055-453759884-39024-2442-0000' I1210 20:55:40.095819 2483 master.cpp:84] No whitelist given. Advertising offers for all slaves I1210 20:55:40.098955 2464 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 62043ns W1210 20:55:40.101080 2483 sched.cpp:355] Authentication timed out W1210 20:55:40.101202 2483 sched.cpp:315] Failed to authenticate with master [email protected]:39024: future discarded I1210 20:55:40.101232 2483 sched.cpp:260] Authenticating with master [email protected]:39024 I1210 20:55:40.101397 2479 authenticatee.hpp:124] Creating new client SASL connection I1210 20:55:40.101953 2479 master.cpp:1849] Authenticating framework at scheduler(131)@140.211.11.27:39024 I1210 20:55:40.102612 2475 authenticator.hpp:140] Creating new server SASL connection I1210 20:55:40.102812 2475 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5 I1210 20:55:40.102833 2475 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5' I1210 20:55:40.102857 2475 authenticator.hpp:243] Received SASL authentication start I1210 20:55:40.103025 2475 authenticator.hpp:325] Authentication requires more steps I1210 20:55:40.103049 2475 authenticatee.hpp:258] Received SASL authentication step I1210 20:55:40.103083 2475 authenticator.hpp:271] Received SASL authentication step I1210 20:55:40.103211 2475 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 I1210 20:55:40.103227 2475 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1210 20:55:40.103245 2475 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1210 20:55:40.103261 2475 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 I1210 20:55:40.103271 2475 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1210 20:55:40.103278 2475 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1210 20:55:40.103296 2475 authenticator.hpp:317] Authentication success I1210 20:55:40.103812 2475 master.cpp:1889] Successfully authenticated framework at scheduler(131)@140.211.11.27:39024 I1210 20:55:40.103819 2483 authenticatee.hpp:298] Authentication success I1210 20:55:40.104408 2483 sched.cpp:334] Successfully authenticated with master [email protected]:39024 I1210 20:55:40.105216 2473 master.cpp:889] Re-registering framework 201312102055-453759884-39024-2442-0000 at scheduler(131)@140.211.11.27:39024 I1210 20:55:40.105681 2479 sched.cpp:383] Framework registered with 201312102055-453759884-39024-2442-0000 I1210 20:55:40.105723 2468 slave.cpp:1303] Updating framework 201312102055-453759884-39024-2442-0000 pid to scheduler(131)@140.211.11.27:39024 I1210 20:55:40.105787 2473 hierarchical_allocator_process.hpp:332] Added framework 201312102055-453759884-39024-2442-0000 I1210 20:55:40.105803 2479 sched.cpp:397] Scheduler::registered took 14583ns I1210 20:55:40.105849 2473 hierarchical_allocator_process.hpp:752] Offering cpus(*):1; mem(*):524; disk(*):127026; ports(*):[31000-32000] on slave 201312102055-453759884-39024-2442-0 to framework 201312102055-453759884-39024-2442-0000 I1210 20:55:40.106117 2473 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 225523ns I1210 20:55:40.106183 2480 master.hpp:437] Adding offer 201312102055-453759884-39024-2442-0 with resources cpus(*):1; mem(*):524; disk(*):127026; ports(*):[31000-32000] on slave 201312102055-453759884-39024-2442-0 (hemera.apache.org) I1210 20:55:40.106250 2480 master.cpp:1804] Sending 1 offers to framework 201312102055-453759884-39024-2442-0000 I1210 20:55:40.106432 2472 sched.cpp:517] Scheduler::resourceOffers took 33625ns I1210 20:55:40.106974 2442 master.cpp:556] Master terminating I1210 20:55:40.106976 2470 sched.cpp:719] Stopping framework '201312102055-453759884-39024-2442-0000' I1210 20:55:40.107023 2442 master.cpp:209] Shutting down master I1210 20:55:40.107064 2481 slave.cpp:1956] [email protected]:39024 exited W1210 20:55:40.107090 2481 slave.cpp:1959] Master disconnected! Waiting for a new master to be elected I1210 20:55:40.107082 2442 master.hpp:427] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201312102055-453759884-39024-2442-0 (hemera.apache.org) I1210 20:55:40.107163 2442 master.hpp:447] Removing offer 201312102055-453759884-39024-2442-0 with resources cpus(*):1; mem(*):524; disk(*):127026; ports(*):[31000-32000] on slave 201312102055-453759884-39024-2442-0 (hemera.apache.org) I1210 20:55:40.107215 2442 master.cpp:252] Removing slave 201312102055-453759884-39024-2442-0 (hemera.apache.org) I1210 20:55:40.107527 2471 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave 201312102055-453759884-39024-2442-0 from framework 201312102055-453759884-39024-2442-0000 I1210 20:55:40.108193 2467 contender.cpp:172] Now cancelling the membership: 6 I1210 20:55:40.108335 2461 group.cpp:519] Trying to remove '/znode/0000000006' in ZooKeeper 2013-12-10 20:55:40,110:2442(0x2ac226ca17c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x142de4b1d98000a to [127.0.0.1:58949] I1210 20:55:40.110330 2475 detector.cpp:116] The current leader (id=6) is lost I1210 20:55:40.110348 2475 detector.cpp:138] No new leader is elected after election I1210 20:55:40.110489 2476 slave.cpp:518] Lost leading master I1210 20:55:40.110509 2476 slave.cpp:524] Detecting new master I1210 20:55:40.110868 2475 detector.cpp:116] The current leader (id=6) is lost I1210 20:55:40.110890 2475 detector.cpp:138] No new leader is elected after election 2013-12-10 20:55:40,110:2442(0x2ac226ca17c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x142de4b1d98000b to [127.0.0.1:58949] I1210 20:55:40.111310 2462 slave.cpp:391] Slave terminating I1210 20:55:40.111333 2462 slave.cpp:1133] Asked to shut down framework 201312102055-453759884-39024-2442-0000 by @0.0.0.0:0 W1210 20:55:40.111342 2462 slave.cpp:1141] Ignoring shutdown framework message for 201312102055-453759884-39024-2442-0000 because the slave has not yet registered with the master I1210 20:55:40.111408 2477 exec.cpp:455] Slave exited ... shutting down I1210 20:55:40.111456 2477 exec.cpp:472] Executor::shutdown took 19815ns 2013-12-10 20:55:40,111:2442(0x2ac226ca17c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x142de4b1d980008 to [127.0.0.1:58949] 2013-12-10 20:55:40,112:2442(0x2ac226ca17c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x142de4b1d980009 to [127.0.0.1:58949] [ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (5041 ms) I1210 20:55:40.113980 2442 zookeeper_test_server.cpp:93] Shutdown ZooKeeperTestServer on port 58949 [----------] 2 tests from AllocatorZooKeeperTest/0 (6071 ms total) [----------] Global test environment tear-down [==========] 246 tests from 43 test cases ran. (152930 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
