You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/10/16 04:16:13 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME #1712
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
Re: Build failed in Jenkins: Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME
#1712
Posted by Vinod Kone <vi...@twitter.com>.
the fix is under review at https://reviews.apache.org/r/14097/.
@vinodkone
On Tue, Oct 15, 2013 at 7:16 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> 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:49405exited
> 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:49405exited
> 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:49405exited
> 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
>
Jenkins build is back to normal :
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME #1713
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/1713/changes>