See
<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/1712/changes>
Changes:
[bmahler] Disabled the RecoveryTimeout test.
------------------------------------------
[...truncated 20134 lines...]
I1016 02:16:10.312274 12005 master.cpp:2502] Adding slave
201310160216-160088899-49405-11787-0 at vesta.apache.org with cpus(*):2;
mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]
I1016 02:16:10.316259 12004 slave.cpp:660] Re-registered with master
master@67.195.138.9:49405
I1016 02:16:10.316285 12005 master.hpp:361] Adding task 0 with resources
cpus(*):1; mem(*):500 on slave 201310160216-160088899-49405-11787-0
(vesta.apache.org)
I1016 02:16:10.360259 12005 slave.cpp:1352] Updating framework
201310160216-160088899-49405-11787-0000 pid to scheduler(127)@67.195.138.9:49405
I1016 02:16:10.360365 12004 hierarchical_allocator_process.hpp:445] Added slave
201310160216-160088899-49405-11787-0 (vesta.apache.org) with cpus(*):2;
mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] (and cpus(*):1;
mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] available)
I1016 02:16:10.379992 12004 hierarchical_allocator_process.hpp:752] Offering
cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave
201310160216-160088899-49405-11787-0 to framework
201310160216-160088899-49405-11787-0000
I1016 02:16:10.407980 12004 hierarchical_allocator_process.hpp:708] Performed
allocation for slave 201310160216-160088899-49405-11787-0 in 28.020699ms
I1016 02:16:10.408105 12000 master.hpp:389] Adding offer
201310160216-160088899-49405-11787-0 with resources cpus(*):1; mem(*):524;
disk(*):1.38501e+06; ports(*):[31000-32000] on slave
201310160216-160088899-49405-11787-0 (vesta.apache.org)
I1016 02:16:10.439774 12000 master.cpp:1689] Sending 1 offers to framework
201310160216-160088899-49405-11787-0000
I1016 02:16:10.443891 12003 sched.cpp:472] Scheduler::resourceOffers took
37.886us
I1016 02:16:10.444172 11787 master.cpp:557] Master terminating
I1016 02:16:10.447738 12003 sched.cpp:630] Stopping framework
'201310160216-160088899-49405-11787-0000'
I1016 02:16:10.451719 11787 master.cpp:209] Shutting down master
I1016 02:16:10.451750 12001 slave.cpp:1993] master@67.195.138.9:49405 exited
I1016 02:16:10.467684 11787 master.hpp:379] Removing task 0 with resources
cpus(*):1; mem(*):500 on slave 201310160216-160088899-49405-11787-0
(vesta.apache.org)
W1016 02:16:10.479646 12001 slave.cpp:1996] Master disconnected! Waiting for a
new master to be elected
I1016 02:16:10.483661 11787 master.hpp:399] Removing offer
201310160216-160088899-49405-11787-0 with resources cpus(*):1; mem(*):524;
disk(*):1.38501e+06; ports(*):[31000-32000] on slave
201310160216-160088899-49405-11787-0 (vesta.apache.org)
I1016 02:16:10.483799 11999 hierarchical_allocator_process.hpp:637] Recovered
cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave
201310160216-160088899-49405-11787-0 from framework
201310160216-160088899-49405-11787-0000
I1016 02:16:10.495612 11787 master.cpp:252] Removing slave
201310160216-160088899-49405-11787-0 (vesta.apache.org)
I1016 02:16:10.503976 11787 slave.cpp:454] Slave terminating
I1016 02:16:10.507534 11787 slave.cpp:1184] Asked to shut down framework
201310160216-160088899-49405-11787-0000 by @0.0.0.0:0
I1016 02:16:10.512676 12002 detector.cpp:420] Master detector
(slave(133)@67.195.138.9:49405) found 0 registered masters
I1016 02:16:10.523474 12002 detector.cpp:441] Master detector
(slave(133)@67.195.138.9:49405) couldn't find any masters
I1016 02:16:10.519481 11787 slave.cpp:1209] Shutting down framework
201310160216-160088899-49405-11787-0000
I1016 02:16:10.531437 11787 slave.cpp:2446] Shutting down executor 'default' of
framework 201310160216-160088899-49405-11787-0000
I1016 02:16:10.535640 12004 exec.cpp:371] Executor asked to shutdown
GMOCK WARNING:
Uninteresting mock function call - returning directly.
Function call: shutdown(0x2b5768023c70)
Stack trace:
I1016 02:16:10.539437 12004 exec.cpp:386] Executor::shutdown took 23.304us
[ OK ] AllocatorZooKeeperTest/0.FrameworkReregistersFirst (2479 ms)
[ RUN ] AllocatorZooKeeperTest/0.SlaveReregistersFirst
I1016 02:16:10.580384 12001 master.cpp:284] Master started on 67.195.138.9:49405
2013-10-16 02:16:10,581:11787(0x2b5766983700):ZOO_INFO@log_env@658: Client
environment:zookeeper.version=zookeeper C client 3.3.4
2013-10-16 02:16:10,581:11787(0x2b5766983700):ZOO_INFO@log_env@662: Client
environment:host.name=vesta.apache.org
2013-10-16 02:16:10,581:11787(0x2b5766983700):ZOO_INFO@log_env@669: Client
environment:os.name=Linux
2013-10-16 02:16:10,581:11787(0x2b5766983700):ZOO_INFO@log_env@670: Client
environment:os.arch=3.2.0-51-generic
2013-10-16 02:16:10,581:11787(0x2b5766983700):ZOO_INFO@log_env@671: Client
environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013
2013-10-16 02:16:10,581:11787(0x2b5766983700):ZOO_INFO@log_env@679: Client
environment:user.name=(null)
I1016 02:16:10.580577 12001 master.cpp:299] Master ID:
201310160216-160088899-49405-11787
I1016 02:16:10.599216 12001 master.cpp:302] Master only allowing authenticated
frameworks to register!
I1016 02:16:10.584208 11999 detector.cpp:234] Master detector
(master@67.195.138.9:49405) connected to ZooKeeper ...
I1016 02:16:10.591856 12004 detector.cpp:234] Master detector
(slave(134)@67.195.138.9:49405) connected to ZooKeeper ...
I1016 02:16:10.611156 12004 detector.cpp:251] Trying to create path '/znode' in
ZooKeeper
I1016 02:16:10.581400 12003 slave.cpp:108] Slave started on
134)@67.195.138.9:49405
I1016 02:16:10.603435 12002 hierarchical_allocator_process.hpp:302]
Initializing hierarchical allocator process with master :
master@67.195.138.9:49405
I1016 02:16:10.603452 12006 master.cpp:85] No whitelist given. Advertising
offers for all slaves
I1016 02:16:10.607153 11999 detector.cpp:251] Trying to create path '/znode' in
ZooKeeper
I1016 02:16:10.592361 12000 detector.cpp:234] Master detector
(scheduler(128)@67.195.138.9:49405) connected to ZooKeeper ...
I1016 02:16:10.635100 12000 detector.cpp:251] Trying to create path '/znode' in
ZooKeeper
I1016 02:16:10.619278 12003 slave.cpp:208] Slave resources: cpus(*):2;
mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]
I1016 02:16:10.616160 12004 detector.cpp:420] Master detector
(slave(134)@67.195.138.9:49405) found 0 registered masters
I1016 02:16:10.655005 12004 detector.cpp:441] Master detector
(slave(134)@67.195.138.9:49405) couldn't find any masters
I1016 02:16:10.648047 12000 detector.cpp:420] Master detector
(scheduler(128)@67.195.138.9:49405) found 1 registered masters
I1016 02:16:10.651490 12003 slave.cpp:399] Finished recovery
I1016 02:16:10.666998 12003 slave.cpp:581] Lost master(s) ... waiting
I1016 02:16:10.659533 12004 detector.cpp:420] Master detector
(slave(134)@67.195.138.9:49405) found 1 registered masters
I1016 02:16:10.663496 12000 detector.cpp:467] Master detector
(scheduler(128)@67.195.138.9:49405) got new master pid:
master@67.195.138.9:49405
I1016 02:16:10.678997 12000 sched.cpp:195] New master at
master@67.195.138.9:49405
I1016 02:16:10.682911 12000 sched.cpp:281] Authenticating with master
master@67.195.138.9:49405
I1016 02:16:10.687000 12000 authenticatee.hpp:124] Creating new client SASL
connection
I1016 02:16:10.690937 12000 master.cpp:1723] Authenticating framework at
scheduler(128)@67.195.138.9:49405
I1016 02:16:10.694993 12000 authenticator.hpp:140] Creating new server SASL
connection
I1016 02:16:10.698921 12000 authenticatee.hpp:212] Received SASL authentication
mechanisms: CRAM-MD5
I1016 02:16:10.702862 12000 authenticatee.hpp:238] Attempting to authenticate
with mechanism 'CRAM-MD5'
I1016 02:16:10.706871 12000 authenticator.hpp:243] Received SASL authentication
start
I1016 02:16:10.710875 12000 authenticator.hpp:325] Authentication requires more
steps
I1016 02:16:10.714807 12000 authenticatee.hpp:258] Received SASL authentication
step
I1016 02:16:10.718837 12000 authenticator.hpp:271] Received SASL authentication
step
I1016 02:16:10.722785 12000 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'vesta.apache.org' server FQDN:
'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1016 02:16:10.726766 12000 auxprop.cpp:153] Looking up auxiliary property
'*userPassword'
I1016 02:16:10.730798 12000 auxprop.cpp:153] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I1016 02:16:10.734801 12000 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'vesta.apache.org' server FQDN:
'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1016 02:16:10.738759 12000 auxprop.cpp:103] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I1016 02:16:10.742749 12000 auxprop.cpp:103] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1016 02:16:10.746736 12000 authenticator.hpp:317] Authentication success
I1016 02:16:10.750730 12000 authenticatee.hpp:298] Authentication success
I1016 02:16:10.754740 12000 sched.cpp:326] Successfully authenticated with
master master@67.195.138.9:49405
I1016 02:16:10.639489 11999 detector.cpp:281] Created ephemeral/sequence znode
at '/znode/0000000004'
I1016 02:16:10.750771 12006 master.cpp:1763] Successfully authenticated
framework at scheduler(128)@67.195.138.9:49405
W1016 02:16:10.766731 12006 master.cpp:736] Ignoring register framework message
since not elected yet
I1016 02:16:10.763229 11999 detector.cpp:420] Master detector
(master@67.195.138.9:49405) found 1 registered masters
I1016 02:16:10.675431 12004 detector.cpp:467] Master detector
(slave(134)@67.195.138.9:49405) got new master pid: master@67.195.138.9:49405
I1016 02:16:10.782677 12004 slave.cpp:547] New master detected at
master@67.195.138.9:49405
I1016 02:16:10.786667 12004 status_update_manager.cpp:157] New master detected
at master@67.195.138.9:49405
I1016 02:16:10.779115 11999 detector.cpp:467] Master detector
(master@67.195.138.9:49405) got new master pid: master@67.195.138.9:49405
W1016 02:16:10.786700 12000 master.cpp:1217] Ignoring register slave message
from vesta.apache.org since not elected yet
I1016 02:16:10.798692 12000 master.cpp:697] Elected as master!
I1016 02:16:11.623729 12002 hierarchical_allocator_process.hpp:726] No
resources available to allocate!
I1016 02:16:11.623965 12002 hierarchical_allocator_process.hpp:688] Performed
allocation for 0 slaves in 252.254us
I1016 02:16:11.759075 12000 master.cpp:768] Received registration request from
scheduler(128)@67.195.138.9:49405
I1016 02:16:11.759307 12000 master.cpp:786] Registering framework
201310160216-160088899-49405-11787-0000 at scheduler(128)@67.195.138.9:49405
I1016 02:16:11.763411 12000 sched.cpp:365] Framework registered with
201310160216-160088899-49405-11787-0000
I1016 02:16:11.767334 12000 sched.cpp:379] Scheduler::registered took 38.148us
I1016 02:16:11.763465 12002 hierarchical_allocator_process.hpp:332] Added
framework 201310160216-160088899-49405-11787-0000
I1016 02:16:11.775262 12002 hierarchical_allocator_process.hpp:726] No
resources available to allocate!
I1016 02:16:11.779245 12002 hierarchical_allocator_process.hpp:688] Performed
allocation for 0 slaves in 3.983865ms
I1016 02:16:11.787209 12006 master.cpp:1248] Attempting to register slave on
vesta.apache.org at slave(134)@67.195.138.9:49405
I1016 02:16:11.787365 12006 master.cpp:2502] Adding slave
201310160216-160088899-49405-11787-0 at vesta.apache.org with cpus(*):2;
mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]
I1016 02:16:11.791275 12000 slave.cpp:613] Registered with master
master@67.195.138.9:49405; given slave ID 201310160216-160088899-49405-11787-0
I1016 02:16:11.791368 12006 hierarchical_allocator_process.hpp:445] Added slave
201310160216-160088899-49405-11787-0 (vesta.apache.org) with cpus(*):2;
mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] (and cpus(*):2;
mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] available)
I1016 02:16:11.799214 12006 hierarchical_allocator_process.hpp:752] Offering
cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave
201310160216-160088899-49405-11787-0 to framework
201310160216-160088899-49405-11787-0000
I1016 02:16:11.803251 12006 hierarchical_allocator_process.hpp:708] Performed
allocation for slave 201310160216-160088899-49405-11787-0 in 4.087115ms
I1016 02:16:11.803318 12000 master.hpp:389] Adding offer
201310160216-160088899-49405-11787-0 with resources cpus(*):2; mem(*):1024;
disk(*):1.38501e+06; ports(*):[31000-32000] on slave
201310160216-160088899-49405-11787-0 (vesta.apache.org)
I1016 02:16:11.829928 12000 master.cpp:1689] Sending 1 offers to framework
201310160216-160088899-49405-11787-0000
I1016 02:16:11.834136 12000 sched.cpp:472] Scheduler::resourceOffers took
187.014us
I1016 02:16:11.837931 12000 master.cpp:2015] Processing reply for offer
201310160216-160088899-49405-11787-0 on slave
201310160216-160088899-49405-11787-0 (vesta.apache.org) for framework
201310160216-160088899-49405-11787-0000
I1016 02:16:11.841904 12000 master.hpp:361] Adding task 0 with resources
cpus(*):1; mem(*):500 on slave 201310160216-160088899-49405-11787-0
(vesta.apache.org)
I1016 02:16:11.845815 12000 master.cpp:2139] Launching task 0 of framework
201310160216-160088899-49405-11787-0000 with resources cpus(*):1; mem(*):500 on
slave 201310160216-160088899-49405-11787-0 (vesta.apache.org)
I1016 02:16:11.849899 12000 master.hpp:399] Removing offer
201310160216-160088899-49405-11787-0 with resources cpus(*):2; mem(*):1024;
disk(*):1.38501e+06; ports(*):[31000-32000] on slave
201310160216-160088899-49405-11787-0 (vesta.apache.org)
I1016 02:16:11.849972 12001 slave.cpp:786] Got assigned task 0 for framework
201310160216-160088899-49405-11787-0000
I1016 02:16:11.849962 12002 hierarchical_allocator_process.hpp:547] Framework
201310160216-160088899-49405-11787-0000 left cpus(*):1; mem(*):524;
disk(*):1.38501e+06; ports(*):[31000-32000] unused on slave
201310160216-160088899-49405-11787-0
I1016 02:16:11.897981 12001 slave.cpp:897] Launching task 0 for framework
201310160216-160088899-49405-11787-0000
I1016 02:16:11.901782 12002 hierarchical_allocator_process.hpp:590] Framework
201310160216-160088899-49405-11787-0000 filtered slave
201310160216-160088899-49405-11787-0 for 5secs
I1016 02:16:11.923810 12001 slave.cpp:1008] Queuing task '0' for executor
default of framework '201310160216-160088899-49405-11787-0000
I1016 02:16:11.925180 11999 exec.cpp:174] Executor started at:
executor(43)@67.195.138.9:49405 with pid 11787
I1016 02:16:11.937640 12001 slave.cpp:529] Successfully attached file
'/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_38xAIM/slaves/201310160216-160088899-49405-11787-0/frameworks/201310160216-160088899-49405-11787-0000/executors/default/runs/0999ec69-2c18-4104-b44d-80953e78e915'
I1016 02:16:11.985556 12001 slave.cpp:1460] Got registration for executor
'default' of framework 201310160216-160088899-49405-11787-0000
I1016 02:16:11.989573 12001 slave.cpp:1581] Flushing queued task 0 for executor
'default' of framework 201310160216-160088899-49405-11787-0000
I1016 02:16:11.989614 12006 exec.cpp:198] Executor registered on slave
201310160216-160088899-49405-11787-0
I1016 02:16:12.030474 12006 exec.cpp:210] Executor::registered took 19.746us
I1016 02:16:12.033263 12006 exec.cpp:285] Executor asked to run task '0'
I1016 02:16:12.037231 12006 exec.cpp:294] Executor::launchTask took 32.672us
I1016 02:16:12.042353 12006 exec.cpp:505] Executor sending status update
TASK_RUNNING (UUID: 7c5ab5b4-6947-4264-8d26-0e048c27db15) for task 0 of
framework 201310160216-160088899-49405-11787-0000
I1016 02:16:12.045274 12006 slave.cpp:1793] Handling status update TASK_RUNNING
(UUID: 7c5ab5b4-6947-4264-8d26-0e048c27db15) for task 0 of framework
201310160216-160088899-49405-11787-0000 from executor(43)@67.195.138.9:49405
I1016 02:16:12.049286 12002 status_update_manager.cpp:300] Received status
update TASK_RUNNING (UUID: 7c5ab5b4-6947-4264-8d26-0e048c27db15) for task 0 of
framework 201310160216-160088899-49405-11787-0000
I1016 02:16:12.053181 12002 status_update_manager.cpp:471] Creating
StatusUpdate stream for task 0 of framework
201310160216-160088899-49405-11787-0000
I1016 02:16:12.057198 12002 status_update_manager.cpp:351] Forwarding status
update TASK_RUNNING (UUID: 7c5ab5b4-6947-4264-8d26-0e048c27db15) for task 0 of
framework 201310160216-160088899-49405-11787-0000 to master@67.195.138.9:49405
I1016 02:16:12.061378 12000 master.cpp:1448] Status update TASK_RUNNING (UUID:
7c5ab5b4-6947-4264-8d26-0e048c27db15) for task 0 of framework
201310160216-160088899-49405-11787-0000 from slave(134)@67.195.138.9:49405
I1016 02:16:12.061434 12004 slave.cpp:1912] Status update manager successfully
handled status update TASK_RUNNING (UUID: 7c5ab5b4-6947-4264-8d26-0e048c27db15)
for task 0 of framework 201310160216-160088899-49405-11787-0000
I1016 02:16:12.061480 12005 sched.cpp:527] Scheduler::statusUpdate took 40.932us
I1016 02:16:12.065223 12000 master.cpp:557] Master terminating
I1016 02:16:12.069160 12004 slave.cpp:1918] Sending acknowledgement for status
update TASK_RUNNING (UUID: 7c5ab5b4-6947-4264-8d26-0e048c27db15) for task 0 of
framework 201310160216-160088899-49405-11787-0000 to
executor(43)@67.195.138.9:49405
I1016 02:16:12.077224 11787 master.cpp:209] Shutting down master
I1016 02:16:12.081236 12000 exec.cpp:331] Executor received status update
acknowledgement 7c5ab5b4-6947-4264-8d26-0e048c27db15 for task 0 of framework
201310160216-160088899-49405-11787-0000
I1016 02:16:12.081246 12004 slave.cpp:1993] master@67.195.138.9:49405 exited
I1016 02:16:12.081334 12006 status_update_manager.cpp:375] Received status
update acknowledgement (UUID: 7c5ab5b4-6947-4264-8d26-0e048c27db15) for task 0
of framework 201310160216-160088899-49405-11787-0000
I1016 02:16:12.085186 11787 master.hpp:379] Removing task 0 with resources
cpus(*):1; mem(*):500 on slave 201310160216-160088899-49405-11787-0
(vesta.apache.org)
I1016 02:16:12.101151 11787 master.cpp:252] Removing slave
201310160216-160088899-49405-11787-0 (vesta.apache.org)
W1016 02:16:12.093081 12004 slave.cpp:1996] Master disconnected! Waiting for a
new master to be elected
I1016 02:16:12.109052 12004 slave.cpp:1406] Status update manager successfully
handled status update acknowledgement (UUID:
7c5ab5b4-6947-4264-8d26-0e048c27db15) for task 0 of framework
201310160216-160088899-49405-11787-0000
I1016 02:16:12.101218 12006 hierarchical_allocator_process.hpp:637] Recovered
cpus(*):1; mem(*):500 (total allocatable: cpus(*):2; mem(*):1024;
disk(*):1.38501e+06; ports(*):[31000-32000]) on slave
201310160216-160088899-49405-11787-0 from framework
201310160216-160088899-49405-11787-0000
I1016 02:16:12.118439 12001 master.cpp:284] Master started on 67.195.138.9:49405
I1016 02:16:12.121073 12001 master.cpp:299] Master ID:
201310160216-160088899-49405-11787
I1016 02:16:12.144934 12001 master.cpp:302] Master only allowing authenticated
frameworks to register!
I1016 02:16:12.135485 12005 detector.cpp:420] Master detector
(scheduler(128)@67.195.138.9:49405) found 0 registered masters
I1016 02:16:12.135613 12003 detector.cpp:420] Master detector
(slave(134)@67.195.138.9:49405) found 0 registered masters
I1016 02:16:12.156903 12003 detector.cpp:441] Master detector
(slave(134)@67.195.138.9:49405) couldn't find any masters
I1016 02:16:12.149163 11999 master.cpp:85] No whitelist given. Advertising
offers for all slaves
I1016 02:16:12.149358 12006 hierarchical_allocator_process.hpp:302]
Initializing hierarchical allocator process with master :
master@67.195.138.9:49405
I1016 02:16:12.152890 12005 detector.cpp:441] Master detector
(scheduler(128)@67.195.138.9:49405) couldn't find any masters
I1016 02:16:12.135249 12000 detector.cpp:234] Master detector
(master@67.195.138.9:49405) connected to ZooKeeper ...
I1016 02:16:12.176818 12000 detector.cpp:251] Trying to create path '/znode' in
ZooKeeper
I1016 02:16:12.172871 12005 sched.cpp:235] No master detected, waiting for
another master
I1016 02:16:12.184833 12005 sched.cpp:247] Scheduler::disconnected took 29.847us
I1016 02:16:12.160915 12003 slave.cpp:581] Lost master(s) ... waiting
I1016 02:16:12.188484 12000 detector.cpp:281] Created ephemeral/sequence znode
at '/znode/0000000006'
I1016 02:16:12.188956 11999 detector.cpp:420] Master detector
(scheduler(128)@67.195.138.9:49405) found 1 registered masters
I1016 02:16:12.189185 12004 detector.cpp:420] Master detector
(slave(134)@67.195.138.9:49405) found 1 registered masters
I1016 02:16:12.205348 12000 detector.cpp:420] Master detector
(master@67.195.138.9:49405) found 1 registered masters
I1016 02:16:12.209280 11999 detector.cpp:467] Master detector
(scheduler(128)@67.195.138.9:49405) got new master pid:
master@67.195.138.9:49405
I1016 02:16:12.213316 12004 detector.cpp:467] Master detector
(slave(134)@67.195.138.9:49405) got new master pid: master@67.195.138.9:49405
I1016 02:16:12.217286 12000 detector.cpp:467] Master detector
(master@67.195.138.9:49405) got new master pid: master@67.195.138.9:49405
I1016 02:16:12.220788 11999 sched.cpp:195] New master at
master@67.195.138.9:49405
I1016 02:16:12.232705 11999 sched.cpp:281] Authenticating with master
master@67.195.138.9:49405
I1016 02:16:12.228750 12000 master.cpp:697] Elected as master!
I1016 02:16:12.224773 12004 slave.cpp:547] New master detected at
master@67.195.138.9:49405
I1016 02:16:12.236785 12002 authenticatee.hpp:124] Creating new client SASL
connection
I1016 02:16:12.244673 12003 status_update_manager.cpp:157] New master detected
at master@67.195.138.9:49405
I1016 02:16:12.244823 12005 master.cpp:1349] Attempting to re-register slave
201310160216-160088899-49405-11787-0 at slave(134)@67.195.138.9:49405
(vesta.apache.org)
I1016 02:16:12.256618 12005 master.cpp:2502] Adding slave
201310160216-160088899-49405-11787-0 at vesta.apache.org with cpus(*):2;
mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]
I1016 02:16:12.260666 12006 slave.cpp:660] Re-registered with master
master@67.195.138.9:49405
I1016 02:16:12.260679 12005 master.hpp:361] Adding task 0 with resources
cpus(*):1; mem(*):500 on slave 201310160216-160088899-49405-11787-0
(vesta.apache.org)
W1016 02:16:12.268556 12005 master.cpp:2597] Possibly orphaned task 0 of
framework 201310160216-160088899-49405-11787-0000 running on slave
201310160216-160088899-49405-11787-0 (vesta.apache.org)
I1016 02:16:12.272661 12005 master.cpp:1723] Authenticating framework at
scheduler(128)@67.195.138.9:49405
I1016 02:16:12.276648 12005 authenticator.hpp:140] Creating new server SASL
connection
I1016 02:16:12.280583 12005 authenticatee.hpp:212] Received SASL authentication
mechanisms: CRAM-MD5
I1016 02:16:12.284564 12005 authenticatee.hpp:238] Attempting to authenticate
with mechanism 'CRAM-MD5'
I1016 02:16:12.288498 12005 authenticator.hpp:243] Received SASL authentication
start
I1016 02:16:12.292536 12005 authenticator.hpp:325] Authentication requires more
steps
I1016 02:16:12.296497 12005 authenticatee.hpp:258] Received SASL authentication
step
I1016 02:16:12.300498 12005 authenticator.hpp:271] Received SASL authentication
step
I1016 02:16:12.304455 12005 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'vesta.apache.org' server FQDN:
'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1016 02:16:12.308464 12005 auxprop.cpp:153] Looking up auxiliary property
'*userPassword'
I1016 02:16:12.312432 12005 auxprop.cpp:153] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I1016 02:16:12.316459 12005 auxprop.cpp:81] Request to lookup properties for
user: 'test-principal' realm: 'vesta.apache.org' server FQDN:
'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1016 02:16:12.272876 12006 hierarchical_allocator_process.hpp:445] Added slave
201310160216-160088899-49405-11787-0 (vesta.apache.org) with cpus(*):2;
mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] (and cpus(*):1;
mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] available)
I1016 02:16:12.320446 12005 auxprop.cpp:103] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I1016 02:16:12.404361 12005 auxprop.cpp:103] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1016 02:16:12.408105 12005 authenticator.hpp:317] Authentication success
I1016 02:16:12.452206 12005 authenticatee.hpp:298] Authentication success
I1016 02:16:12.324442 12006 hierarchical_allocator_process.hpp:708] Performed
allocation for slave 201310160216-160088899-49405-11787-0 in 31.815us
I1016 02:16:12.452291 12002 master.cpp:1763] Successfully authenticated
framework at scheduler(128)@67.195.138.9:49405
I1016 02:16:12.523982 12005 sched.cpp:326] Successfully authenticated with
master master@67.195.138.9:49405
I1016 02:16:12.535851 12004 master.cpp:872] Re-registering framework
201310160216-160088899-49405-11787-0000 at scheduler(128)@67.195.138.9:49405
I1016 02:16:12.545840 12002 sched.cpp:365] Framework registered with
201310160216-160088899-49405-11787-0000
I1016 02:16:12.545878 12004 slave.cpp:1352] Updating framework
201310160216-160088899-49405-11787-0000 pid to scheduler(128)@67.195.138.9:49405
I1016 02:16:12.546095 12001 hierarchical_allocator_process.hpp:332] Added
framework 201310160216-160088899-49405-11787-0000
I1016 02:16:12.555701 12001 hierarchical_allocator_process.hpp:752] Offering
cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave
201310160216-160088899-49405-11787-0 to framework
201310160216-160088899-49405-11787-0000
I1016 02:16:12.547909 12002 sched.cpp:379] Scheduler::registered took 37.086us
I1016 02:16:12.560274 12001 hierarchical_allocator_process.hpp:688] Performed
allocation for 1 slaves in 4.619759ms
I1016 02:16:12.560425 12005 master.hpp:389] Adding offer
201310160216-160088899-49405-11787-0 with resources cpus(*):1; mem(*):524;
disk(*):1.38501e+06; ports(*):[31000-32000] on slave
201310160216-160088899-49405-11787-0 (vesta.apache.org)
I1016 02:16:12.583665 12005 master.cpp:1689] Sending 1 offers to framework
201310160216-160088899-49405-11787-0000
I1016 02:16:12.611675 12000 sched.cpp:472] Scheduler::resourceOffers took
39.428us
I1016 02:16:12.611987 11787 master.cpp:557] Master terminating
I1016 02:16:12.687325 12000 sched.cpp:630] Stopping framework
'201310160216-160088899-49405-11787-0000'
I1016 02:16:12.687528 11787 master.cpp:209] Shutting down master
I1016 02:16:12.687532 12005 slave.cpp:1993] master@67.195.138.9:49405 exited
W1016 02:16:12.759106 12005 slave.cpp:1996] Master disconnected! Waiting for a
new master to be elected
I1016 02:16:12.743155 11787 master.hpp:379] Removing task 0 with resources
cpus(*):1; mem(*):500 on slave 201310160216-160088899-49405-11787-0
(vesta.apache.org)
I1016 02:16:12.767089 11787 master.hpp:399] Removing offer
201310160216-160088899-49405-11787-0 with resources cpus(*):1; mem(*):524;
disk(*):1.38501e+06; ports(*):[31000-32000] on slave
201310160216-160088899-49405-11787-0 (vesta.apache.org)
I1016 02:16:12.767230 11999 hierarchical_allocator_process.hpp:637] Recovered
cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave
201310160216-160088899-49405-11787-0 from framework
201310160216-160088899-49405-11787-0000
I1016 02:16:12.771070 11787 master.cpp:252] Removing slave
201310160216-160088899-49405-11787-0 (vesta.apache.org)
I1016 02:16:12.779633 11787 slave.cpp:454] Slave terminating
I1016 02:16:12.782944 11787 slave.cpp:1184] Asked to shut down framework
201310160216-160088899-49405-11787-0000 by @0.0.0.0:0
I1016 02:16:12.787927 12004 detector.cpp:420] Master detector
(slave(134)@67.195.138.9:49405) found 0 registered masters
I1016 02:16:12.798907 12004 detector.cpp:441] Master detector
(slave(134)@67.195.138.9:49405) couldn't find any masters
I1016 02:16:12.794936 11787 slave.cpp:1209] Shutting down framework
201310160216-160088899-49405-11787-0000
I1016 02:16:12.806874 11787 slave.cpp:2446] Shutting down executor 'default' of
framework 201310160216-160088899-49405-11787-0000
I1016 02:16:12.810897 12002 exec.cpp:371] Executor asked to shutdown
GMOCK WARNING:
Uninteresting mock function call - returning directly.
Function call: shutdown(0x2b5774025760)
Stack trace:
I1016 02:16:12.814892 12002 exec.cpp:386] Executor::shutdown took 24.503us
[ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (2276 ms)
I1016 02:16:12.828372 11787 zookeeper_test_server.cpp:93] Shutdown
ZooKeeperTestServer on port 45806
[----------] 2 tests from AllocatorZooKeeperTest/0 (4755 ms total)
[----------] Global test environment tear-down
[==========] 235 tests from 41 test cases ran. (229849 ms total)
[ PASSED ] 234 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] AllocatorTest/0.FrameworkExited, where TypeParam =
mesos::internal::master::allocator::HierarchicalAllocatorProcess<mesos::internal::master::allocator::DRFSorter,
mesos::internal::master::allocator::DRFSorter>
1 FAILED TEST
YOU HAVE 2 DISABLED TESTS
make[3]: *** [check-local] Error 1
make[3]: Leaving directory
`/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src'
make[2]: *** [check-am] Error 2
make[2]: Leaving directory
`/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src'
make[1]: *** [check] Error 2
make[1]: Leaving directory
`/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src'
make: *** [check-recursive] Error 1
Build step 'Execute shell' marked build as failure
