See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/1776/changes>
Changes: [vinod] Reduced the minimum number of cpus per offer to 0.1. [vinod] Fixed status update manager to backoff on status update retries. ------------------------------------------ [...truncated 23106 lines...] 2013-11-26 19:56:18,755:32701(0x2b2c20401700):ZOO_INFO@check_events@1632: session establishment complete on server [127.0.0.1:42374], sessionId=0x14295fbd3ed0009, negotiated timeout=10000 I1126 19:56:18.755301 32725 group.cpp:297] Trying to create path '/znode' in ZooKeeper I1126 19:56:18.755334 32728 group.cpp:297] Trying to create path '/znode' in ZooKeeper I1126 19:56:18.756033 32724 group.cpp:297] Trying to create path '/znode' in ZooKeeper I1126 19:56:18.804961 32728 contender.cpp:203] New candidate (id='4', data='[email protected]:53075') has entered the contest for leadership I1126 19:56:18.805191 32722 detector.cpp:130] Detected a new leader (id='4') I1126 19:56:18.805290 32721 group.cpp:539] Trying to get '/znode/0000000004' in ZooKeeper I1126 19:56:18.805373 32722 detector.cpp:130] Detected a new leader (id='4') I1126 19:56:18.805426 32722 group.cpp:539] Trying to get '/znode/0000000004' in ZooKeeper I1126 19:56:18.805555 32727 detector.cpp:130] Detected a new leader (id='4') I1126 19:56:18.805613 32727 group.cpp:539] Trying to get '/znode/0000000004' in ZooKeeper I1126 19:56:18.805939 32724 detector.cpp:322] A new leading master ([email protected]:53075) is detected I1126 19:56:18.805985 32721 sched.cpp:207] New master detected at [email protected]:53075 I1126 19:56:18.806001 32721 sched.cpp:260] Authenticating with master [email protected]:53075 I1126 19:56:18.806049 32721 sched.cpp:229] Detecting new master I1126 19:56:18.806053 32724 authenticatee.hpp:124] Creating new client SASL connection I1126 19:56:18.806146 32722 detector.cpp:322] A new leading master ([email protected]:53075) is detected I1126 19:56:18.806161 32724 master.cpp:1840] Authenticating framework at scheduler(131)@67.195.138.60:53075 I1126 19:56:18.806239 32724 master.cpp:744] The newly elected leader is [email protected]:53075 I1126 19:56:18.806251 32724 master.cpp:748] Elected as the leading master! I1126 19:56:18.806298 32724 authenticator.hpp:140] Creating new server SASL connection I1126 19:56:18.806347 32727 detector.cpp:322] A new leading master ([email protected]:53075) is detected I1126 19:56:18.806375 32727 slave.cpp:497] New master detected at [email protected]:53075 I1126 19:56:18.806380 32724 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5 I1126 19:56:18.806396 32724 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5' I1126 19:56:18.806413 32724 status_update_manager.cpp:160] New master detected at [email protected]:53075 I1126 19:56:18.806438 32724 authenticator.hpp:243] Received SASL authentication start I1126 19:56:18.806468 32722 master.cpp:1364] Attempting to register slave on janus.apache.org at slave(136)@67.195.138.60:53075 I1126 19:56:18.806493 32724 authenticator.hpp:325] Authentication requires more steps I1126 19:56:18.806479 32722 master.cpp:2619] Adding slave 201311261956-1015726915-53075-32701-0 at janus.apache.org with cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] I1126 19:56:18.806511 32724 authenticatee.hpp:258] Received SASL authentication step I1126 19:56:18.806550 32724 authenticator.hpp:271] Received SASL authentication step I1126 19:56:18.806566 32724 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 I1126 19:56:18.806576 32724 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1126 19:56:18.806589 32724 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1126 19:56:18.806601 32724 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 I1126 19:56:18.806608 32724 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1126 19:56:18.806614 32724 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1126 19:56:18.806602 32722 hierarchical_allocator_process.hpp:445] Added slave 201311261956-1015726915-53075-32701-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) I1126 19:56:18.806627 32724 authenticator.hpp:317] Authentication success I1126 19:56:18.806639 32722 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201311261956-1015726915-53075-32701-0 in 6963ns I1126 19:56:18.806645 32724 authenticatee.hpp:298] Authentication success I1126 19:56:18.806658 32722 master.cpp:1880] Successfully authenticated framework at scheduler(131)@67.195.138.60:53075 I1126 19:56:18.806676 32724 sched.cpp:334] Successfully authenticated with master [email protected]:53075 I1126 19:56:18.806416 32727 slave.cpp:524] Detecting new master I1126 19:56:18.806726 32727 slave.cpp:542] Registered with master [email protected]:53075; given slave ID 201311261956-1015726915-53075-32701-0 I1126 19:56:18.806769 32722 master.cpp:799] Received registration request from scheduler(131)@67.195.138.60:53075 I1126 19:56:18.806908 32722 master.cpp:817] Registering framework 201311261956-1015726915-53075-32701-0000 at scheduler(131)@67.195.138.60:53075 I1126 19:56:18.806959 32722 sched.cpp:383] Framework registered with 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.806982 32722 sched.cpp:397] Scheduler::registered took 11634ns I1126 19:56:18.807003 32722 hierarchical_allocator_process.hpp:332] Added framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.807039 32722 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] on slave 201311261956-1015726915-53075-32701-0 to framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.807158 32722 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 145703ns I1126 19:56:18.807205 32722 master.hpp:432] Adding offer 201311261956-1015726915-53075-32701-0 with resources cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] on slave 201311261956-1015726915-53075-32701-0 (janus.apache.org) I1126 19:56:18.807251 32722 master.cpp:1801] Sending 1 offers to framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.807502 32722 sched.cpp:517] Scheduler::resourceOffers took 175936ns I1126 19:56:18.807589 32722 master.cpp:2132] Processing reply for offer 201311261956-1015726915-53075-32701-0 on slave 201311261956-1015726915-53075-32701-0 (janus.apache.org) for framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.807677 32722 master.hpp:404] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201311261956-1015726915-53075-32701-0 (janus.apache.org) I1126 19:56:18.807706 32722 master.cpp:2256] Launching task 0 of framework 201311261956-1015726915-53075-32701-0000 with resources cpus(*):1; mem(*):500 on slave 201311261956-1015726915-53075-32701-0 (janus.apache.org) I1126 19:56:18.807827 32722 master.hpp:442] Removing offer 201311261956-1015726915-53075-32701-0 with resources cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] on slave 201311261956-1015726915-53075-32701-0 (janus.apache.org) I1126 19:56:18.807898 32722 slave.cpp:722] Got assigned task 0 for framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.808058 32722 slave.cpp:833] Launching task 0 for framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.808262 32727 hierarchical_allocator_process.hpp:547] Framework 201311261956-1015726915-53075-32701-0000 left cpus(*):1; mem(*):524; disk(*):23038; ports(*):[31000-32000] unused on slave 201311261956-1015726915-53075-32701-0 I1126 19:56:18.808361 32727 hierarchical_allocator_process.hpp:590] Framework 201311261956-1015726915-53075-32701-0000 filtered slave 201311261956-1015726915-53075-32701-0 for 5secs I1126 19:56:18.809957 32722 slave.cpp:943] Queuing task '0' for executor default of framework '201311261956-1015726915-53075-32701-0000 I1126 19:56:18.809993 32722 slave.cpp:466] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_3IS8Wa/slaves/201311261956-1015726915-53075-32701-0/frameworks/201311261956-1015726915-53075-32701-0000/executors/default/runs/38759f70-f58f-47b4-a423-ebe52329beb4' I1126 19:56:18.811564 32722 exec.cpp:178] Executor started at: executor(45)@67.195.138.60:53075 with pid 32701 I1126 19:56:18.811583 32721 slave.cpp:2078] Monitoring executor default of framework 201311261956-1015726915-53075-32701-0000 forked at pid 32701 I1126 19:56:18.811630 32721 slave.cpp:1411] Got registration for executor 'default' of framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.811792 32722 exec.cpp:202] Executor registered on slave 201311261956-1015726915-53075-32701-0 I1126 19:56:18.811802 32721 slave.cpp:1532] Flushing queued task 0 for executor 'default' of framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.813316 32722 exec.cpp:214] Executor::registered took 12711ns I1126 19:56:18.813355 32722 exec.cpp:289] Executor asked to run task '0' I1126 19:56:18.813385 32722 exec.cpp:298] Executor::launchTask took 20225ns I1126 19:56:18.814884 32722 exec.cpp:521] Executor sending status update TASK_RUNNING (UUID: 641431e5-f09a-4705-9aee-865430568fb7) for task 0 of framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.814946 32722 slave.cpp:1745] Handling status update TASK_RUNNING (UUID: 641431e5-f09a-4705-9aee-865430568fb7) for task 0 of framework 201311261956-1015726915-53075-32701-0000 from executor(45)@67.195.138.60:53075 I1126 19:56:18.815029 32722 status_update_manager.cpp:312] Received status update TASK_RUNNING (UUID: 641431e5-f09a-4705-9aee-865430568fb7) for task 0 of framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.815043 32722 status_update_manager.cpp:491] Creating StatusUpdate stream for task 0 of framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.815103 32722 status_update_manager.cpp:365] Forwarding status update TASK_RUNNING (UUID: 641431e5-f09a-4705-9aee-865430568fb7) for task 0 of framework 201311261956-1015726915-53075-32701-0000 to [email protected]:53075 I1126 19:56:18.815186 32722 slave.cpp:1864] Status update manager successfully handled status update TASK_RUNNING (UUID: 641431e5-f09a-4705-9aee-865430568fb7) for task 0 of framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.815201 32722 slave.cpp:1870] Sending acknowledgement for status update TASK_RUNNING (UUID: 641431e5-f09a-4705-9aee-865430568fb7) for task 0 of framework 201311261956-1015726915-53075-32701-0000 to executor(45)@67.195.138.60:53075 I1126 19:56:18.815212 32725 master.cpp:1550] Status update TASK_RUNNING (UUID: 641431e5-f09a-4705-9aee-865430568fb7) for task 0 of framework 201311261956-1015726915-53075-32701-0000 from slave(136)@67.195.138.60:53075 I1126 19:56:18.815244 32725 exec.cpp:335] Executor received status update acknowledgement 641431e5-f09a-4705-9aee-865430568fb7 for task 0 of framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.815276 32722 sched.cpp:608] Scheduler::statusUpdate took 19184ns I1126 19:56:18.815428 32724 status_update_manager.cpp:390] Received status update acknowledgement (UUID: 641431e5-f09a-4705-9aee-865430568fb7) for task 0 of framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.815493 32701 master.cpp:554] Master terminating I1126 19:56:18.815536 32701 master.cpp:210] Shutting down master I1126 19:56:18.815531 32725 slave.cpp:1351] Status update manager successfully handled status update acknowledgement (UUID: 641431e5-f09a-4705-9aee-865430568fb7) for task 0 of framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.815575 32725 slave.cpp:1945] [email protected]:53075 exited W1126 19:56:18.815594 32725 slave.cpp:1948] Master disconnected! Waiting for a new master to be elected I1126 19:56:18.815589 32701 master.hpp:422] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201311261956-1015726915-53075-32701-0 (janus.apache.org) I1126 19:56:18.815691 32701 master.cpp:253] Removing slave 201311261956-1015726915-53075-32701-0 (janus.apache.org) I1126 19:56:18.815717 32724 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000]) on slave 201311261956-1015726915-53075-32701-0 from framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:18.876852 32701 contender.cpp:172] Now cancelling the membership: 4 I1126 19:56:18.876956 32725 group.cpp:495] Trying to remove '/znode/0000000004' in ZooKeeper 2013-11-26 19:56:18,888:32701(0x2b2a53ad67c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x14295fbd3ed0007 to [127.0.0.1:42374] I1126 19:56:18.888705 32725 detector.cpp:116] The current leader (id=4) is lost I1126 19:56:18.888721 32725 detector.cpp:138] No new leader is elected after election I1126 19:56:18.888829 32725 sched.cpp:201] Scheduler::disconnected took 8493ns I1126 19:56:18.888842 32725 sched.cpp:223] No master detected I1126 19:56:18.888849 32725 sched.cpp:229] Detecting new master I1126 19:56:18.888911 32725 detector.cpp:116] The current leader (id=4) is lost I1126 19:56:18.888921 32725 detector.cpp:138] No new leader is elected after election I1126 19:56:18.889160 32721 detector.cpp:116] The current leader (id=4) is lost I1126 19:56:18.889174 32721 detector.cpp:138] No new leader is elected after election 2013-11-26 19:56:18,889:32701(0x2b2a53ad67c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x14295fbd3ed0006 to [127.0.0.1:42374] I1126 19:56:18.889281 32725 slave.cpp:518] Lost leading master I1126 19:56:18.889333 32725 slave.cpp:524] Detecting new master I1126 19:56:18.927439 32725 master.cpp:285] Master started on 67.195.138.60:53075 I1126 19:56:18.927492 32725 master.cpp:299] Master ID: 201311261956-1015726915-53075-32701 I1126 19:56:18.927501 32725 master.cpp:302] Master only allowing authenticated frameworks to register! 2013-11-26 19:56:18,927:32701(0x2b2a53cdb700):ZOO_INFO@log_env@658: Client environment:zookeeper.version=zookeeper C client 3.3.4 2013-11-26 19:56:18,927:32701(0x2b2a53cdb700):ZOO_INFO@log_env@662: Client environment:host.name=janus 2013-11-26 19:56:18,927:32701(0x2b2a53cdb700):ZOO_INFO@log_env@669: Client environment:os.name=Linux 2013-11-26 19:56:18,927:32701(0x2b2a53cdb700):ZOO_INFO@log_env@670: Client environment:os.arch=3.2.0-51-generic 2013-11-26 19:56:18,927:32701(0x2b2a53cdb700):ZOO_INFO@log_env@671: Client environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013 2013-11-26 19:56:18,927:32701(0x2b2a53cdb700):ZOO_INFO@log_env@679: Client environment:user.name=(null) I1126 19:56:18.927778 32723 master.cpp:85] No whitelist given. Advertising offers for all slaves 2013-11-26 19:56:18,927:32701(0x2b2a53cdb700):ZOO_INFO@log_env@687: Client environment:user.home=/home/jenkins 2013-11-26 19:56:18,927:32701(0x2b2a53cdb700):ZOO_INFO@log_env@699: Client environment:user.dir=<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src> 2013-11-26 19:56:18,927:32701(0x2b2a53cdb700):ZOO_INFO@zookeeper_init@727: Initiating client connection, host=127.0.0.1:42374 sessionTimeout=10000 watcher=0x2b2a51395050 sessionId=0 sessionPasswd=<null> context=0x2b2a8c029140 flags=0 I1126 19:56:18.928035 32723 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : [email protected]:53075 2013-11-26 19:56:18,928:32701(0x2b2a540dd700):ZOO_INFO@log_env@658: Client environment:zookeeper.version=zookeeper C client 3.3.4 2013-11-26 19:56:18,928:32701(0x2b2a540dd700):ZOO_INFO@log_env@662: Client environment:host.name=janus 2013-11-26 19:56:18,928:32701(0x2b2a540dd700):ZOO_INFO@log_env@669: Client environment:os.name=Linux 2013-11-26 19:56:18,928:32701(0x2b2a540dd700):ZOO_INFO@log_env@670: Client environment:os.arch=3.2.0-51-generic 2013-11-26 19:56:18,928:32701(0x2b2a540dd700):ZOO_INFO@log_env@671: Client environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013 I1126 19:56:18.928194 32720 contender.cpp:122] Joining the ZK group with data: '[email protected]:53075' 2013-11-26 19:56:18,928:32701(0x2b2c0c200700):ZOO_INFO@check_events@1585: initiated connection to server [127.0.0.1:42374] 2013-11-26 19:56:18,928:32701(0x2b2a540dd700):ZOO_INFO@log_env@679: Client environment:user.name=(null) 2013-11-26 19:56:18,928:32701(0x2b2a540dd700):ZOO_INFO@log_env@687: Client environment:user.home=/home/jenkins 2013-11-26 19:56:18,928:32701(0x2b2a540dd700):ZOO_INFO@log_env@699: Client environment:user.dir=<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src> 2013-11-26 19:56:18,928:32701(0x2b2a540dd700):ZOO_INFO@zookeeper_init@727: Initiating client connection, host=127.0.0.1:42374 sessionTimeout=10000 watcher=0x2b2a51395050 sessionId=0 sessionPasswd=<null> context=0x2b2a7004aca0 flags=0 2013-11-26 19:56:18,928:32701(0x2b2bf0d16700):ZOO_INFO@check_events@1585: initiated connection to server [127.0.0.1:42374] 2013-11-26 19:56:18,969:32701(0x2b2c0c200700):ZOO_INFO@check_events@1632: session establishment complete on server [127.0.0.1:42374], sessionId=0x14295fbd3ed000a, negotiated timeout=10000 I1126 19:56:18.970173 32720 group.cpp:297] Trying to create path '/znode' in ZooKeeper 2013-11-26 19:56:19,003:32701(0x2b2bf0d16700):ZOO_INFO@check_events@1632: session establishment complete on server [127.0.0.1:42374], sessionId=0x14295fbd3ed000b, negotiated timeout=10000 I1126 19:56:19.003269 32721 group.cpp:297] Trying to create path '/znode' in ZooKeeper I1126 19:56:19.029880 32725 contender.cpp:203] New candidate (id='6', data='[email protected]:53075') has entered the contest for leadership I1126 19:56:19.030168 32721 detector.cpp:130] Detected a new leader (id='6') I1126 19:56:19.030271 32723 group.cpp:539] Trying to get '/znode/0000000006' in ZooKeeper I1126 19:56:19.030390 32722 detector.cpp:130] Detected a new leader (id='6') I1126 19:56:19.030494 32722 group.cpp:539] Trying to get '/znode/0000000006' in ZooKeeper I1126 19:56:19.030905 32721 detector.cpp:130] Detected a new leader (id='6') I1126 19:56:19.031081 32728 group.cpp:539] Trying to get '/znode/0000000006' in ZooKeeper I1126 19:56:19.031105 32725 detector.cpp:322] A new leading master ([email protected]:53075) is detected I1126 19:56:19.031170 32721 slave.cpp:497] New master detected at [email protected]:53075 I1126 19:56:19.031231 32722 status_update_manager.cpp:160] New master detected at [email protected]:53075 I1126 19:56:19.031299 32721 slave.cpp:524] Detecting new master I1126 19:56:19.031313 32720 detector.cpp:322] A new leading master ([email protected]:53075) is detected W1126 19:56:19.031354 32725 master.cpp:1379] Ignoring re-register slave message from janus.apache.org since not elected yet I1126 19:56:19.031397 32725 master.cpp:744] The newly elected leader is [email protected]:53075 I1126 19:56:19.031411 32725 master.cpp:748] Elected as the leading master! I1126 19:56:19.031893 32725 detector.cpp:322] A new leading master ([email protected]:53075) is detected I1126 19:56:19.031958 32722 sched.cpp:207] New master detected at [email protected]:53075 I1126 19:56:19.031975 32722 sched.cpp:260] Authenticating with master [email protected]:53075 I1126 19:56:19.032027 32722 sched.cpp:229] Detecting new master I1126 19:56:19.032044 32728 authenticatee.hpp:124] Creating new client SASL connection I1126 19:56:19.032203 32722 master.cpp:1840] Authenticating framework at scheduler(131)@67.195.138.60:53075 I1126 19:56:19.032297 32728 authenticator.hpp:140] Creating new server SASL connection I1126 19:56:19.032394 32728 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5 I1126 19:56:19.032412 32728 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5' I1126 19:56:19.032444 32728 authenticator.hpp:243] Received SASL authentication start I1126 19:56:19.032498 32728 authenticator.hpp:325] Authentication requires more steps I1126 19:56:19.032528 32728 authenticatee.hpp:258] Received SASL authentication step I1126 19:56:19.032575 32728 authenticator.hpp:271] Received SASL authentication step I1126 19:56:19.032593 32728 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 I1126 19:56:19.032601 32728 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I1126 19:56:19.032616 32728 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1126 19:56:19.032629 32728 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 I1126 19:56:19.032635 32728 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1126 19:56:19.032641 32728 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1126 19:56:19.032654 32728 authenticator.hpp:317] Authentication success I1126 19:56:19.032706 32724 authenticatee.hpp:298] Authentication success I1126 19:56:19.032712 32728 master.cpp:1880] Successfully authenticated framework at scheduler(131)@67.195.138.60:53075 I1126 19:56:19.032799 32724 sched.cpp:334] Successfully authenticated with master [email protected]:53075 I1126 19:56:19.527966 32725 monitor.cpp:193] Publishing resource usage for executor 'default' of framework '201311261956-1015726915-53075-32701-0000' I1126 19:56:19.806874 32725 master.cpp:1453] Attempting to re-register slave 201311261956-1015726915-53075-32701-0 at slave(136)@67.195.138.60:53075 (janus.apache.org) I1126 19:56:19.806891 32725 master.cpp:2619] Adding slave 201311261956-1015726915-53075-32701-0 at janus.apache.org with cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] I1126 19:56:19.806982 32721 slave.cpp:592] Re-registered with master [email protected]:53075 I1126 19:56:19.806989 32725 master.hpp:404] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201311261956-1015726915-53075-32701-0 (janus.apache.org) W1126 19:56:19.807018 32725 master.cpp:2714] Possibly orphaned task 0 of framework 201311261956-1015726915-53075-32701-0000 running on slave 201311261956-1015726915-53075-32701-0 (janus.apache.org) I1126 19:56:19.807273 32721 hierarchical_allocator_process.hpp:445] Added slave 201311261956-1015726915-53075-32701-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) I1126 19:56:19.807349 32721 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201311261956-1015726915-53075-32701-0 in 10251ns I1126 19:56:19.807813 32728 master.cpp:887] Re-registering framework 201311261956-1015726915-53075-32701-0000 at scheduler(131)@67.195.138.60:53075 I1126 19:56:19.808033 32723 sched.cpp:383] Framework registered with 201311261956-1015726915-53075-32701-0000 I1126 19:56:19.808066 32723 sched.cpp:397] Scheduler::registered took 11586ns I1126 19:56:19.808074 32728 slave.cpp:1292] Updating framework 201311261956-1015726915-53075-32701-0000 pid to scheduler(131)@67.195.138.60:53075 I1126 19:56:19.808128 32725 hierarchical_allocator_process.hpp:332] Added framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:19.808181 32725 hierarchical_allocator_process.hpp:752] Offering cpus(*):1; mem(*):524; disk(*):23038; ports(*):[31000-32000] on slave 201311261956-1015726915-53075-32701-0 to framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:19.808341 32725 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 195651ns I1126 19:56:19.808393 32728 master.hpp:432] Adding offer 201311261956-1015726915-53075-32701-0 with resources cpus(*):1; mem(*):524; disk(*):23038; ports(*):[31000-32000] on slave 201311261956-1015726915-53075-32701-0 (janus.apache.org) I1126 19:56:19.808446 32728 master.cpp:1801] Sending 1 offers to framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:19.808580 32723 sched.cpp:517] Scheduler::resourceOffers took 28903ns I1126 19:56:19.808769 32723 sched.cpp:719] Stopping framework '201311261956-1015726915-53075-32701-0000' I1126 19:56:19.808794 32701 master.cpp:554] Master terminating I1126 19:56:19.808831 32701 master.cpp:210] Shutting down master I1126 19:56:19.808846 32724 slave.cpp:1945] [email protected]:53075 exited W1126 19:56:19.808862 32724 slave.cpp:1948] Master disconnected! Waiting for a new master to be elected I1126 19:56:19.808881 32701 master.hpp:422] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201311261956-1015726915-53075-32701-0 (janus.apache.org) I1126 19:56:19.808974 32701 master.hpp:442] Removing offer 201311261956-1015726915-53075-32701-0 with resources cpus(*):1; mem(*):524; disk(*):23038; ports(*):[31000-32000] on slave 201311261956-1015726915-53075-32701-0 (janus.apache.org) I1126 19:56:19.809063 32701 master.cpp:253] Removing slave 201311261956-1015726915-53075-32701-0 (janus.apache.org) I1126 19:56:19.809087 32723 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave 201311261956-1015726915-53075-32701-0 from framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:19.809473 32701 contender.cpp:172] Now cancelling the membership: 6 I1126 19:56:19.809525 32723 group.cpp:495] Trying to remove '/znode/0000000006' in ZooKeeper I1126 19:56:19.812001 32724 monitor.cpp:193] Publishing resource usage for executor 'default' of framework '201311261956-1015726915-53075-32701-0000' 2013-11-26 19:56:19,863:32701(0x2b2a53ad67c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x14295fbd3ed000a to [127.0.0.1:42374] I1126 19:56:19.863375 32725 detector.cpp:116] The current leader (id=6) is lost I1126 19:56:19.863394 32725 detector.cpp:138] No new leader is elected after election I1126 19:56:19.863458 32728 detector.cpp:116] The current leader (id=6) is lost I1126 19:56:19.863531 32728 detector.cpp:138] No new leader is elected after election 2013-11-26 19:56:19,863:32701(0x2b2a53ad67c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x14295fbd3ed000b to [127.0.0.1:42374] I1126 19:56:19.863849 32720 slave.cpp:391] Slave terminating I1126 19:56:19.863876 32720 slave.cpp:1122] Asked to shut down framework 201311261956-1015726915-53075-32701-0000 by @0.0.0.0:0 I1126 19:56:19.863880 32724 detector.cpp:116] The current leader (id=6) is lost I1126 19:56:19.863893 32720 slave.cpp:1147] Shutting down framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:19.863910 32724 detector.cpp:138] No new leader is elected after election I1126 19:56:19.863930 32720 slave.cpp:2411] Shutting down executor 'default' of framework 201311261956-1015726915-53075-32701-0000 I1126 19:56:19.863986 32720 exec.cpp:375] Executor asked to shutdown I1126 19:56:19.864035 32720 exec.cpp:390] Executor::shutdown took 13511ns 2013-11-26 19:56:19,864:32701(0x2b2a53ad67c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x14295fbd3ed0008 to [127.0.0.1:42374] 2013-11-26 19:56:19,864:32701(0x2b2a53ad67c0):ZOO_INFO@zookeeper_close@2304: Closing zookeeper sessionId=0x14295fbd3ed0009 to [127.0.0.1:42374] [ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (1149 ms) I1126 19:56:19.871340 32701 zookeeper_test_server.cpp:93] Shutdown ZooKeeperTestServer on port 42374 [----------] 2 tests from AllocatorZooKeeperTest/0 (1579 ms total) [----------] Global test environment tear-down [==========] 245 tests from 43 test cases ran. (145650 ms total) [ PASSED ] 244 tests. [ FAILED ] 1 test, listed below: [ FAILED ] FaultToleranceTest.ReregisterFrameworkExitedExecutor 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-Out-Of-Src-Set-JAVA_HOME/ws/build/src'> make[2]: *** [check-am] Error 2 make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src'> make[1]: *** [check] Error 2 make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/ws/build/src'> make: *** [check-recursive] Error 1 Build step 'Execute shell' marked build as failure
