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 2014/01/17 06:07:37 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME #1839
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/1839/changes>
Changes:
[bmahler] Added missing include guards in set.hpp.
------------------------------------------
[...truncated 24436 lines...]
2014-01-17 05:07:36,994:17987(0x2b89691c8700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:48726]
I0117 05:07:36.994511 18033 slave.cpp:2769] Finished recovery
2014-01-17 05:07:37,002:17987(0x2b8969bcd700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:48726], sessionId=0x1439e98dfb00008, negotiated timeout=10000
I0117 05:07:37.002835 18033 group.cpp:307] Group process ((1710)@67.195.138.9:60124) connected to ZooKeeper
I0117 05:07:37.002871 18033 group.cpp:724] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0)
I0117 05:07:37.002878 18033 group.cpp:364] Trying to create path '/znode' in ZooKeeper
2014-01-17 05:07:37,034:17987(0x2b89691c8700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:48726], sessionId=0x1439e98dfb00009, negotiated timeout=10000
I0117 05:07:37.035112 18037 group.cpp:307] Group process ((1716)@67.195.138.9:60124) connected to ZooKeeper
I0117 05:07:37.035187 18037 group.cpp:724] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0)
I0117 05:07:37.035194 18037 group.cpp:364] Trying to create path '/znode' in ZooKeeper
I0117 05:07:37.035956 18033 detector.cpp:134] Detected a new leader: '(id='2')
I0117 05:07:37.036073 18038 group.cpp:611] Trying to get '/znode/0000000002' in ZooKeeper
I0117 05:07:37.036808 18034 detector.cpp:134] Detected a new leader: '(id='2')
I0117 05:07:37.036835 18038 detector.cpp:322] A new leading master (UPID=master@67.195.138.9:60124) is detected
I0117 05:07:37.036875 18034 slave.cpp:500] New master detected at master@67.195.138.9:60124
I0117 05:07:37.036937 18036 group.cpp:611] Trying to get '/znode/0000000002' in ZooKeeper
I0117 05:07:37.036957 18037 status_update_manager.cpp:162] New master detected at master@67.195.138.9:60124
I0117 05:07:37.036967 18034 slave.cpp:525] Detecting new master
I0117 05:07:37.037014 18037 master.cpp:1353] Attempting to register slave on vesta.apache.org at slave(138)@67.195.138.9:60124
I0117 05:07:37.037025 18037 master.cpp:2615] Adding slave 201401170507-160088899-60124-17987-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]
I0117 05:07:37.037137 18032 slave.cpp:543] Registered with master master@67.195.138.9:60124; given slave ID 201401170507-160088899-60124-17987-0
I0117 05:07:37.037180 18037 hierarchical_allocator_process.hpp:445] Added slave 201401170507-160088899-60124-17987-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)
I0117 05:07:37.037219 18037 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201401170507-160088899-60124-17987-0 in 7437ns
I0117 05:07:37.037809 18036 detector.cpp:322] A new leading master (UPID=master@67.195.138.9:60124) is detected
I0117 05:07:37.037876 18032 sched.cpp:210] New master detected at master@67.195.138.9:60124
I0117 05:07:37.037936 18032 sched.cpp:261] Authenticating with master master@67.195.138.9:60124
I0117 05:07:37.037992 18032 sched.cpp:230] Detecting new master
I0117 05:07:37.038005 18036 authenticatee.hpp:124] Creating new client SASL connection
I0117 05:07:37.038084 18032 master.cpp:1836] Authenticating framework at scheduler(132)@67.195.138.9:60124
I0117 05:07:37.038162 18034 authenticator.hpp:140] Creating new server SASL connection
I0117 05:07:37.038251 18036 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0117 05:07:37.038275 18036 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0117 05:07:37.038313 18036 authenticator.hpp:243] Received SASL authentication start
I0117 05:07:37.038382 18036 authenticator.hpp:325] Authentication requires more steps
I0117 05:07:37.038419 18036 authenticatee.hpp:258] Received SASL authentication step
I0117 05:07:37.038460 18036 authenticator.hpp:271] Received SASL authentication step
I0117 05:07:37.038480 18036 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
I0117 05:07:37.038488 18036 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0117 05:07:37.038502 18036 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0117 05:07:37.038512 18036 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
I0117 05:07:37.038518 18036 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0117 05:07:37.038523 18036 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0117 05:07:37.038540 18036 authenticator.hpp:317] Authentication success
I0117 05:07:37.038584 18035 authenticatee.hpp:298] Authentication success
I0117 05:07:37.038590 18036 master.cpp:1876] Successfully authenticated framework at scheduler(132)@67.195.138.9:60124
I0117 05:07:37.038660 18035 sched.cpp:335] Successfully authenticated with master master@67.195.138.9:60124
I0117 05:07:37.038713 18035 master.cpp:788] Received registration request from scheduler(132)@67.195.138.9:60124
I0117 05:07:37.038743 18035 master.cpp:806] Registering framework 201401170507-160088899-60124-17987-0000 at scheduler(132)@67.195.138.9:60124
I0117 05:07:37.038800 18035 sched.cpp:384] Framework registered with 201401170507-160088899-60124-17987-0000
I0117 05:07:37.038822 18035 sched.cpp:398] Scheduler::registered took 10101ns
I0117 05:07:37.038835 18038 hierarchical_allocator_process.hpp:332] Added framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.038882 18038 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201401170507-160088899-60124-17987-0 to framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.039062 18038 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 207307ns
I0117 05:07:37.039140 18032 master.hpp:437] Adding offer 201401170507-160088899-60124-17987-0 with resources cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201401170507-160088899-60124-17987-0 (vesta.apache.org)
I0117 05:07:37.039197 18032 master.cpp:1791] Sending 1 offers to framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.039437 18036 sched.cpp:518] Scheduler::resourceOffers took 152562ns
I0117 05:07:37.039572 18034 master.cpp:2128] Processing reply for offer 201401170507-160088899-60124-17987-0 on slave 201401170507-160088899-60124-17987-0 (vesta.apache.org) for framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.039671 18034 master.hpp:409] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201401170507-160088899-60124-17987-0 (vesta.apache.org)
I0117 05:07:37.039705 18034 master.cpp:2252] Launching task 0 of framework 201401170507-160088899-60124-17987-0000 with resources cpus(*):1; mem(*):500 on slave 201401170507-160088899-60124-17987-0 (vesta.apache.org)
I0117 05:07:37.039775 18036 slave.cpp:737] Got assigned task 0 for framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.039846 18034 master.hpp:447] Removing offer 201401170507-160088899-60124-17987-0 with resources cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201401170507-160088899-60124-17987-0 (vesta.apache.org)
I0117 05:07:37.039855 18038 hierarchical_allocator_process.hpp:547] Framework 201401170507-160088899-60124-17987-0000 left cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] unused on slave 201401170507-160088899-60124-17987-0
I0117 05:07:37.039932 18036 slave.cpp:846] Launching task 0 for framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.039973 18038 hierarchical_allocator_process.hpp:590] Framework 201401170507-160088899-60124-17987-0000 filtered slave 201401170507-160088899-60124-17987-0 for 5secs
I0117 05:07:37.041474 18036 slave.cpp:956] Queuing task '0' for executor default of framework '201401170507-160088899-60124-17987-0000
I0117 05:07:37.041533 18034 slave.cpp:465] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_5t8Wqv/slaves/201401170507-160088899-60124-17987-0/frameworks/201401170507-160088899-60124-17987-0000/executors/default/runs/606daeeb-5052-4ab6-83a9-348d44c3c59e'
I0117 05:07:37.042790 18032 exec.cpp:178] Executor started at: executor(45)@67.195.138.9:60124 with pid 17987
I0117 05:07:37.042835 18037 slave.cpp:2099] Monitoring executor default of framework 201401170507-160088899-60124-17987-0000 forked at pid 17987
I0117 05:07:37.042907 18037 slave.cpp:1432] Got registration for executor 'default' of framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.043079 18037 slave.cpp:1553] Flushing queued task 0 for executor 'default' of framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.043102 18036 exec.cpp:202] Executor registered on slave 201401170507-160088899-60124-17987-0
I0117 05:07:37.044302 18036 exec.cpp:214] Executor::registered took 15526ns
I0117 05:07:37.044345 18036 exec.cpp:289] Executor asked to run task '0'
I0117 05:07:37.044373 18036 exec.cpp:298] Executor::launchTask took 17442ns
I0117 05:07:37.045544 18036 exec.cpp:521] Executor sending status update TASK_RUNNING (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for task 0 of framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.045616 18036 slave.cpp:1766] Handling status update TASK_RUNNING (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for task 0 of framework 201401170507-160088899-60124-17987-0000 from executor(45)@67.195.138.9:60124
I0117 05:07:37.045764 18035 status_update_manager.cpp:314] Received status update TASK_RUNNING (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for task 0 of framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.045799 18035 status_update_manager.cpp:493] Creating StatusUpdate stream for task 0 of framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.045902 18035 status_update_manager.cpp:367] Forwarding status update TASK_RUNNING (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for task 0 of framework 201401170507-160088899-60124-17987-0000 to master@67.195.138.9:60124
I0117 05:07:37.046066 18037 slave.cpp:1885] Status update manager successfully handled status update TASK_RUNNING (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for task 0 of framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.046082 18036 master.cpp:1539] Status update TASK_RUNNING (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for task 0 of framework 201401170507-160088899-60124-17987-0000 from slave(138)@67.195.138.9:60124
I0117 05:07:37.046164 18037 slave.cpp:1891] Sending acknowledgement for status update TASK_RUNNING (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for task 0 of framework 201401170507-160088899-60124-17987-0000 to executor(45)@67.195.138.9:60124
I0117 05:07:37.046216 18033 sched.cpp:609] Scheduler::statusUpdate took 21758ns
I0117 05:07:37.046228 18037 exec.cpp:335] Executor received status update acknowledgement ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc for task 0 of framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.046491 17987 master.cpp:559] Master terminating
I0117 05:07:37.046565 17987 master.cpp:209] Shutting down master
I0117 05:07:37.046525 18037 status_update_manager.cpp:392] Received status update acknowledgement (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for task 0 of framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.046615 18036 slave.cpp:1966] master@67.195.138.9:60124 exited
W0117 05:07:37.046633 18036 slave.cpp:1969] Master disconnected! Waiting for a new master to be elected
I0117 05:07:37.046622 17987 master.hpp:427] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201401170507-160088899-60124-17987-0 (vesta.apache.org)
I0117 05:07:37.046720 18034 slave.cpp:1372] Status update manager successfully handled status update acknowledgement (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for task 0 of framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.046728 17987 master.cpp:252] Removing slave 201401170507-160088899-60124-17987-0 (vesta.apache.org)
I0117 05:07:37.046789 18037 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 201401170507-160088899-60124-17987-0 from framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.152441 17987 contender.cpp:176] Now cancelling the membership: 2
I0117 05:07:37.152557 18031 group.cpp:568] Trying to remove '/znode/0000000002' in ZooKeeper
2014-01-17 05:07:37,161:17987(0x2b885bc2c7c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x1439e98dfb00007 to [127.0.0.1:48726]
I0117 05:07:37.162299 18031 detector.cpp:122] The current leader (id=2) is lost
I0117 05:07:37.162322 18031 detector.cpp:134] Detected a new leader: None
2014-01-17 05:07:37,162:17987(0x2b885bc2c7c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x1439e98dfb00006 to [127.0.0.1:48726]
I0117 05:07:37.162678 18035 detector.cpp:122] The current leader (id=2) is lost
I0117 05:07:37.162701 18035 detector.cpp:134] Detected a new leader: None
I0117 05:07:37.162873 18031 slave.cpp:521] Lost leading master
I0117 05:07:37.162889 18031 slave.cpp:525] Detecting new master
I0117 05:07:37.162960 18037 detector.cpp:122] The current leader (id=2) is lost
I0117 05:07:37.162996 18037 detector.cpp:134] Detected a new leader: None
I0117 05:07:37.163137 18037 sched.cpp:204] Scheduler::disconnected took 20300ns
I0117 05:07:37.163158 18037 sched.cpp:226] No master detected
I0117 05:07:37.163166 18037 sched.cpp:230] Detecting new master
I0117 05:07:37.163729 18035 master.cpp:284] Master started on 67.195.138.9:60124
I0117 05:07:37.163764 18035 master.cpp:298] Master ID: 201401170507-160088899-60124-17987
I0117 05:07:37.163772 18035 master.cpp:301] Master only allowing authenticated frameworks to register!
2014-01-17 05:07:37,163:17987(0x2b885be31700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
2014-01-17 05:07:37,163:17987(0x2b885be31700):ZOO_INFO@log_env@716: Client environment:host.name=vesta.apache.org
2014-01-17 05:07:37,163:17987(0x2b885be31700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
2014-01-17 05:07:37,163:17987(0x2b885be31700):ZOO_INFO@log_env@724: Client environment:os.arch=3.2.0-51-generic
2014-01-17 05:07:37,164:17987(0x2b885be31700):ZOO_INFO@log_env@725: Client environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013
I0117 05:07:37.164106 18038 master.cpp:85] No whitelist given. Advertising offers for all slaves
2014-01-17 05:07:37,164:17987(0x2b885be31700):ZOO_INFO@log_env@733: Client environment:user.name=(null)
2014-01-17 05:07:37,164:17987(0x2b885be31700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
2014-01-17 05:07:37,164:17987(0x2b885be31700):ZOO_INFO@log_env@753: Client environment:user.dir=/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src
2014-01-17 05:07:37,164:17987(0x2b885be31700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:48726 sessionTimeout=10000 watcher=0x2b88594038e0 sessionId=0 sessionPasswd=<null> context=0x2b886c026900 flags=0
I0117 05:07:37.164345 18032 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : master@67.195.138.9:60124
2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@716: Client environment:host.name=vesta.apache.org
2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@724: Client environment:os.arch=3.2.0-51-generic
2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@725: Client environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013
2014-01-17 05:07:37,164:17987(0x2b8968bb4700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:48726]
I0117 05:07:37.164485 18034 contender.cpp:121] Joining the ZK group with data: 'master@67.195.138.9:60124'
2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@733: Client environment:user.name=(null)
2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@753: Client environment:user.dir=/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src
2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=127.0.0.1:48726 sessionTimeout=10000 watcher=0x2b88594038e0 sessionId=0 sessionPasswd=<null> context=0x2b888802dab0 flags=0
2014-01-17 05:07:37,165:17987(0x2b8969dce700):ZOO_INFO@check_events@1703: initiated connection to server [127.0.0.1:48726]
2014-01-17 05:07:37,182:17987(0x2b8968bb4700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:48726], sessionId=0x1439e98dfb0000a, negotiated timeout=10000
I0117 05:07:37.182538 18034 group.cpp:307] Group process ((1722)@67.195.138.9:60124) connected to ZooKeeper
I0117 05:07:37.182554 18034 group.cpp:724] Syncing group operations: queue size (joins, cancels, datas) = (1, 0, 0)
I0117 05:07:37.182561 18034 group.cpp:364] Trying to create path '/znode' in ZooKeeper
2014-01-17 05:07:37,182:17987(0x2b8969dce700):ZOO_INFO@check_events@1750: session establishment complete on server [127.0.0.1:48726], sessionId=0x1439e98dfb0000b, negotiated timeout=10000
I0117 05:07:37.183274 18036 group.cpp:307] Group process ((1724)@67.195.138.9:60124) connected to ZooKeeper
I0117 05:07:37.183394 18036 group.cpp:724] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0)
I0117 05:07:37.183449 18036 group.cpp:364] Trying to create path '/znode' in ZooKeeper
I0117 05:07:37.190279 18031 contender.cpp:237] New candidate (id='3', data='master@67.195.138.9:60124') has entered the contest for leadership
I0117 05:07:37.191222 18032 detector.cpp:134] Detected a new leader: '(id='3')
I0117 05:07:37.191360 18038 group.cpp:611] Trying to get '/znode/0000000003' in ZooKeeper
I0117 05:07:37.191390 18034 detector.cpp:134] Detected a new leader: '(id='3')
I0117 05:07:37.191544 18031 group.cpp:611] Trying to get '/znode/0000000003' in ZooKeeper
I0117 05:07:37.191727 18035 detector.cpp:134] Detected a new leader: '(id='3')
I0117 05:07:37.191874 18035 group.cpp:611] Trying to get '/znode/0000000003' in ZooKeeper
I0117 05:07:37.192060 18036 detector.cpp:322] A new leading master (UPID=master@67.195.138.9:60124) is detected
I0117 05:07:37.192179 18032 master.cpp:732] The newly elected leader is master@67.195.138.9:60124
I0117 05:07:37.192194 18032 master.cpp:740] Elected as the leading master!
I0117 05:07:37.192384 18031 detector.cpp:322] A new leading master (UPID=master@67.195.138.9:60124) is detected
I0117 05:07:37.192437 18031 slave.cpp:500] New master detected at master@67.195.138.9:60124
I0117 05:07:37.192546 18031 slave.cpp:525] Detecting new master
I0117 05:07:37.192596 18031 status_update_manager.cpp:162] New master detected at master@67.195.138.9:60124
I0117 05:07:37.192698 18031 master.cpp:1442] Attempting to re-register slave 201401170507-160088899-60124-17987-0 at slave(138)@67.195.138.9:60124 (vesta.apache.org)
I0117 05:07:37.192708 18031 master.cpp:2615] Adding slave 201401170507-160088899-60124-17987-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]
I0117 05:07:37.192798 18031 master.hpp:409] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201401170507-160088899-60124-17987-0 (vesta.apache.org)
W0117 05:07:37.192826 18031 master.cpp:2710] Possibly orphaned task 0 of framework 201401170507-160088899-60124-17987-0000 running on slave 201401170507-160088899-60124-17987-0 (vesta.apache.org)
I0117 05:07:37.192939 18031 slave.cpp:602] Re-registered with master master@67.195.138.9:60124
I0117 05:07:37.193081 18031 hierarchical_allocator_process.hpp:445] Added slave 201401170507-160088899-60124-17987-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)
I0117 05:07:37.193119 18031 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201401170507-160088899-60124-17987-0 in 11019ns
I0117 05:07:37.193238 18031 detector.cpp:322] A new leading master (UPID=master@67.195.138.9:60124) is detected
I0117 05:07:37.193286 18031 sched.cpp:210] New master detected at master@67.195.138.9:60124
I0117 05:07:37.193300 18031 sched.cpp:261] Authenticating with master master@67.195.138.9:60124
I0117 05:07:37.193347 18031 sched.cpp:230] Detecting new master
I0117 05:07:37.193351 18033 authenticatee.hpp:124] Creating new client SASL connection
I0117 05:07:37.193397 18031 master.cpp:1836] Authenticating framework at scheduler(132)@67.195.138.9:60124
I0117 05:07:37.193436 18033 authenticator.hpp:140] Creating new server SASL connection
I0117 05:07:37.193496 18033 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5
I0117 05:07:37.193510 18033 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I0117 05:07:37.193527 18033 authenticator.hpp:243] Received SASL authentication start
I0117 05:07:37.193574 18033 authenticator.hpp:325] Authentication requires more steps
I0117 05:07:37.193599 18033 authenticatee.hpp:258] Received SASL authentication step
I0117 05:07:37.193624 18033 authenticator.hpp:271] Received SASL authentication step
I0117 05:07:37.193641 18033 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
I0117 05:07:37.193649 18033 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0117 05:07:37.193670 18033 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0117 05:07:37.193680 18033 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
I0117 05:07:37.193686 18033 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0117 05:07:37.193689 18033 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0117 05:07:37.193701 18033 authenticator.hpp:317] Authentication success
I0117 05:07:37.193717 18033 authenticatee.hpp:298] Authentication success
I0117 05:07:37.193735 18031 master.cpp:1876] Successfully authenticated framework at scheduler(132)@67.195.138.9:60124
I0117 05:07:37.193850 18033 sched.cpp:335] Successfully authenticated with master master@67.195.138.9:60124
I0117 05:07:37.193922 18035 master.cpp:876] Re-registering framework 201401170507-160088899-60124-17987-0000 at scheduler(132)@67.195.138.9:60124
I0117 05:07:37.194026 18034 sched.cpp:384] Framework registered with 201401170507-160088899-60124-17987-0000
I0117 05:07:37.194047 18032 slave.cpp:1313] Updating framework 201401170507-160088899-60124-17987-0000 pid to scheduler(132)@67.195.138.9:60124
I0117 05:07:37.194057 18034 sched.cpp:398] Scheduler::registered took 12348ns
I0117 05:07:37.194149 18034 hierarchical_allocator_process.hpp:332] Added framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.194190 18034 hierarchical_allocator_process.hpp:752] Offering cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201401170507-160088899-60124-17987-0 to framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.194319 18034 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 159005ns
I0117 05:07:37.194377 18031 master.hpp:437] Adding offer 201401170507-160088899-60124-17987-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201401170507-160088899-60124-17987-0 (vesta.apache.org)
I0117 05:07:37.194445 18031 master.cpp:1791] Sending 1 offers to framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.194540 18032 sched.cpp:518] Scheduler::resourceOffers took 23324ns
I0117 05:07:37.194730 18031 sched.cpp:720] Stopping framework '201401170507-160088899-60124-17987-0000'
I0117 05:07:37.194746 17987 master.cpp:559] Master terminating
I0117 05:07:37.194821 17987 master.cpp:209] Shutting down master
I0117 05:07:37.194823 18033 slave.cpp:1966] master@67.195.138.9:60124 exited
W0117 05:07:37.194907 18033 slave.cpp:1969] Master disconnected! Waiting for a new master to be elected
I0117 05:07:37.194918 17987 master.hpp:427] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201401170507-160088899-60124-17987-0 (vesta.apache.org)
I0117 05:07:37.195016 17987 master.hpp:447] Removing offer 201401170507-160088899-60124-17987-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201401170507-160088899-60124-17987-0 (vesta.apache.org)
I0117 05:07:37.195147 18031 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave 201401170507-160088899-60124-17987-0 from framework 201401170507-160088899-60124-17987-0000
I0117 05:07:37.195173 17987 master.cpp:252] Removing slave 201401170507-160088899-60124-17987-0 (vesta.apache.org)
I0117 05:07:37.340455 17987 contender.cpp:176] Now cancelling the membership: 3
I0117 05:07:37.340541 18034 group.cpp:568] Trying to remove '/znode/0000000003' in ZooKeeper
2014-01-17 05:07:37,346:17987(0x2b885bc2c7c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x1439e98dfb0000a to [127.0.0.1:48726]
I0117 05:07:37.346509 18035 detector.cpp:122] The current leader (id=3) is lost
I0117 05:07:37.346524 18035 detector.cpp:134] Detected a new leader: None
I0117 05:07:37.350237 18034 slave.cpp:521] Lost leading master
I0117 05:07:37.350253 18034 slave.cpp:525] Detecting new master
I0117 05:07:37.350378 18031 detector.cpp:122] The current leader (id=3) is lost
I0117 05:07:37.350389 18031 detector.cpp:134] Detected a new leader: None
2014-01-17 05:07:37,350:17987(0x2b885bc2c7c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x1439e98dfb0000b to [127.0.0.1:48726]
I0117 05:07:37.350677 18034 slave.cpp:390] Slave terminating
I0117 05:07:37.350695 18034 slave.cpp:1143] Asked to shut down framework 201401170507-160088899-60124-17987-0000 by @0.0.0.0:0
W0117 05:07:37.350704 18034 slave.cpp:1151] Ignoring shutdown framework message for 201401170507-160088899-60124-17987-0000 because the slave has not yet registered with the master
I0117 05:07:37.350782 18036 exec.cpp:455] Slave exited ... shutting down
I0117 05:07:37.350810 18036 exec.cpp:472] Executor::shutdown took 11777ns
2014-01-17 05:07:37,351:17987(0x2b885bc2c7c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x1439e98dfb00008 to [127.0.0.1:48726]
2014-01-17 05:07:37,352:17987(0x2b885bc2c7c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper sessionId=0x1439e98dfb00009 to [127.0.0.1:48726]
[ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (383 ms)
I0117 05:07:37.353945 17987 zookeeper_test_server.cpp:122] Shutdown ZooKeeperTestServer on port 48726
[----------] 2 tests from AllocatorZooKeeperTest/0 (1880 ms total)
[----------] Global test environment tear-down
[==========] 253 tests from 46 test cases ran. (197312 ms total)
[ PASSED ] 252 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] RecoverTest.RacingCatchup
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
#1839
Posted by Jie Yu <yu...@gmail.com>.
A bug in the log recover test.
Fix: https://reviews.apache.org/r/17036/
On Thu, Jan 16, 2014 at 9:07 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/1839/changes
> >
>
> Changes:
>
> [bmahler] Added missing include guards in set.hpp.
>
> ------------------------------------------
> [...truncated 24436 lines...]
> 2014-01-17 05:07:36,994:17987(0x2b89691c8700):ZOO_INFO@check_events@1703:
> initiated connection to server [127.0.0.1:48726]
> I0117 05:07:36.994511 18033 slave.cpp:2769] Finished recovery
> 2014-01-17 05:07:37,002:17987(0x2b8969bcd700):ZOO_INFO@check_events@1750:
> session establishment complete on server [127.0.0.1:48726],
> sessionId=0x1439e98dfb00008, negotiated timeout=10000
> I0117 05:07:37.002835 18033 group.cpp:307] Group process ((1710)@
> 67.195.138.9:60124) connected to ZooKeeper
> I0117 05:07:37.002871 18033 group.cpp:724] Syncing group operations: queue
> size (joins, cancels, datas) = (0, 0, 0)
> I0117 05:07:37.002878 18033 group.cpp:364] Trying to create path '/znode'
> in ZooKeeper
> 2014-01-17 05:07:37,034:17987(0x2b89691c8700):ZOO_INFO@check_events@1750:
> session establishment complete on server [127.0.0.1:48726],
> sessionId=0x1439e98dfb00009, negotiated timeout=10000
> I0117 05:07:37.035112 18037 group.cpp:307] Group process ((1716)@
> 67.195.138.9:60124) connected to ZooKeeper
> I0117 05:07:37.035187 18037 group.cpp:724] Syncing group operations: queue
> size (joins, cancels, datas) = (0, 0, 0)
> I0117 05:07:37.035194 18037 group.cpp:364] Trying to create path '/znode'
> in ZooKeeper
> I0117 05:07:37.035956 18033 detector.cpp:134] Detected a new leader:
> '(id='2')
> I0117 05:07:37.036073 18038 group.cpp:611] Trying to get
> '/znode/0000000002' in ZooKeeper
> I0117 05:07:37.036808 18034 detector.cpp:134] Detected a new leader:
> '(id='2')
> I0117 05:07:37.036835 18038 detector.cpp:322] A new leading master (UPID=
> master@67.195.138.9:60124) is detected
> I0117 05:07:37.036875 18034 slave.cpp:500] New master detected at
> master@67.195.138.9:60124
> I0117 05:07:37.036937 18036 group.cpp:611] Trying to get
> '/znode/0000000002' in ZooKeeper
> I0117 05:07:37.036957 18037 status_update_manager.cpp:162] New master
> detected at master@67.195.138.9:60124
> I0117 05:07:37.036967 18034 slave.cpp:525] Detecting new master
> I0117 05:07:37.037014 18037 master.cpp:1353] Attempting to register slave
> on vesta.apache.org at slave(138)@67.195.138.9:60124
> I0117 05:07:37.037025 18037 master.cpp:2615] Adding slave
> 201401170507-160088899-60124-17987-0 at vesta.apache.org with cpus(*):2;
> mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]
> I0117 05:07:37.037137 18032 slave.cpp:543] Registered with master
> master@67.195.138.9:60124; given slave ID
> 201401170507-160088899-60124-17987-0
> I0117 05:07:37.037180 18037 hierarchical_allocator_process.hpp:445] Added
> slave 201401170507-160088899-60124-17987-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)
> I0117 05:07:37.037219 18037 hierarchical_allocator_process.hpp:708]
> Performed allocation for slave 201401170507-160088899-60124-17987-0 in
> 7437ns
> I0117 05:07:37.037809 18036 detector.cpp:322] A new leading master (UPID=
> master@67.195.138.9:60124) is detected
> I0117 05:07:37.037876 18032 sched.cpp:210] New master detected at
> master@67.195.138.9:60124
> I0117 05:07:37.037936 18032 sched.cpp:261] Authenticating with master
> master@67.195.138.9:60124
> I0117 05:07:37.037992 18032 sched.cpp:230] Detecting new master
> I0117 05:07:37.038005 18036 authenticatee.hpp:124] Creating new client
> SASL connection
> I0117 05:07:37.038084 18032 master.cpp:1836] Authenticating framework at
> scheduler(132)@67.195.138.9:60124
> I0117 05:07:37.038162 18034 authenticator.hpp:140] Creating new server
> SASL connection
> I0117 05:07:37.038251 18036 authenticatee.hpp:212] Received SASL
> authentication mechanisms: CRAM-MD5
> I0117 05:07:37.038275 18036 authenticatee.hpp:238] Attempting to
> authenticate with mechanism 'CRAM-MD5'
> I0117 05:07:37.038313 18036 authenticator.hpp:243] Received SASL
> authentication start
> I0117 05:07:37.038382 18036 authenticator.hpp:325] Authentication requires
> more steps
> I0117 05:07:37.038419 18036 authenticatee.hpp:258] Received SASL
> authentication step
> I0117 05:07:37.038460 18036 authenticator.hpp:271] Received SASL
> authentication step
> I0117 05:07:37.038480 18036 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
> I0117 05:07:37.038488 18036 auxprop.cpp:153] Looking up auxiliary property
> '*userPassword'
> I0117 05:07:37.038502 18036 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0117 05:07:37.038512 18036 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
> I0117 05:07:37.038518 18036 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0117 05:07:37.038523 18036 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0117 05:07:37.038540 18036 authenticator.hpp:317] Authentication success
> I0117 05:07:37.038584 18035 authenticatee.hpp:298] Authentication success
> I0117 05:07:37.038590 18036 master.cpp:1876] Successfully authenticated
> framework at scheduler(132)@67.195.138.9:60124
> I0117 05:07:37.038660 18035 sched.cpp:335] Successfully authenticated with
> master master@67.195.138.9:60124
> I0117 05:07:37.038713 18035 master.cpp:788] Received registration request
> from scheduler(132)@67.195.138.9:60124
> I0117 05:07:37.038743 18035 master.cpp:806] Registering framework
> 201401170507-160088899-60124-17987-0000 at scheduler(132)@
> 67.195.138.9:60124
> I0117 05:07:37.038800 18035 sched.cpp:384] Framework registered with
> 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.038822 18035 sched.cpp:398] Scheduler::registered took
> 10101ns
> I0117 05:07:37.038835 18038 hierarchical_allocator_process.hpp:332] Added
> framework 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.038882 18038 hierarchical_allocator_process.hpp:752]
> Offering cpus(*):2; mem(*):1024; disk(*):1.38501e+06;
> ports(*):[31000-32000] on slave 201401170507-160088899-60124-17987-0 to
> framework 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.039062 18038 hierarchical_allocator_process.hpp:688]
> Performed allocation for 1 slaves in 207307ns
> I0117 05:07:37.039140 18032 master.hpp:437] Adding offer
> 201401170507-160088899-60124-17987-0 with resources cpus(*):2; mem(*):1024;
> disk(*):1.38501e+06; ports(*):[31000-32000] on slave
> 201401170507-160088899-60124-17987-0 (vesta.apache.org)
> I0117 05:07:37.039197 18032 master.cpp:1791] Sending 1 offers to framework
> 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.039437 18036 sched.cpp:518] Scheduler::resourceOffers took
> 152562ns
> I0117 05:07:37.039572 18034 master.cpp:2128] Processing reply for offer
> 201401170507-160088899-60124-17987-0 on slave
> 201401170507-160088899-60124-17987-0 (vesta.apache.org) for framework
> 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.039671 18034 master.hpp:409] Adding task 0 with resources
> cpus(*):1; mem(*):500 on slave 201401170507-160088899-60124-17987-0 (
> vesta.apache.org)
> I0117 05:07:37.039705 18034 master.cpp:2252] Launching task 0 of framework
> 201401170507-160088899-60124-17987-0000 with resources cpus(*):1;
> mem(*):500 on slave 201401170507-160088899-60124-17987-0 (vesta.apache.org
> )
> I0117 05:07:37.039775 18036 slave.cpp:737] Got assigned task 0 for
> framework 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.039846 18034 master.hpp:447] Removing offer
> 201401170507-160088899-60124-17987-0 with resources cpus(*):2; mem(*):1024;
> disk(*):1.38501e+06; ports(*):[31000-32000] on slave
> 201401170507-160088899-60124-17987-0 (vesta.apache.org)
> I0117 05:07:37.039855 18038 hierarchical_allocator_process.hpp:547]
> Framework 201401170507-160088899-60124-17987-0000 left cpus(*):1;
> mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] unused on slave
> 201401170507-160088899-60124-17987-0
> I0117 05:07:37.039932 18036 slave.cpp:846] Launching task 0 for framework
> 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.039973 18038 hierarchical_allocator_process.hpp:590]
> Framework 201401170507-160088899-60124-17987-0000 filtered slave
> 201401170507-160088899-60124-17987-0 for 5secs
> I0117 05:07:37.041474 18036 slave.cpp:956] Queuing task '0' for executor
> default of framework '201401170507-160088899-60124-17987-0000
> I0117 05:07:37.041533 18034 slave.cpp:465] Successfully attached file
> '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_5t8Wqv/slaves/201401170507-160088899-60124-17987-0/frameworks/201401170507-160088899-60124-17987-0000/executors/default/runs/606daeeb-5052-4ab6-83a9-348d44c3c59e'
> I0117 05:07:37.042790 18032 exec.cpp:178] Executor started at:
> executor(45)@67.195.138.9:60124 with pid 17987
> I0117 05:07:37.042835 18037 slave.cpp:2099] Monitoring executor default of
> framework 201401170507-160088899-60124-17987-0000 forked at pid 17987
> I0117 05:07:37.042907 18037 slave.cpp:1432] Got registration for executor
> 'default' of framework 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.043079 18037 slave.cpp:1553] Flushing queued task 0 for
> executor 'default' of framework 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.043102 18036 exec.cpp:202] Executor registered on slave
> 201401170507-160088899-60124-17987-0
> I0117 05:07:37.044302 18036 exec.cpp:214] Executor::registered took 15526ns
> I0117 05:07:37.044345 18036 exec.cpp:289] Executor asked to run task '0'
> I0117 05:07:37.044373 18036 exec.cpp:298] Executor::launchTask took 17442ns
> I0117 05:07:37.045544 18036 exec.cpp:521] Executor sending status update
> TASK_RUNNING (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for task 0 of
> framework 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.045616 18036 slave.cpp:1766] Handling status update
> TASK_RUNNING (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for task 0 of
> framework 201401170507-160088899-60124-17987-0000 from executor(45)@
> 67.195.138.9:60124
> I0117 05:07:37.045764 18035 status_update_manager.cpp:314] Received status
> update TASK_RUNNING (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for task 0
> of framework 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.045799 18035 status_update_manager.cpp:493] Creating
> StatusUpdate stream for task 0 of framework
> 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.045902 18035 status_update_manager.cpp:367] Forwarding
> status update TASK_RUNNING (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for
> task 0 of framework 201401170507-160088899-60124-17987-0000 to
> master@67.195.138.9:60124
> I0117 05:07:37.046066 18037 slave.cpp:1885] Status update manager
> successfully handled status update TASK_RUNNING (UUID:
> ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for task 0 of framework
> 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.046082 18036 master.cpp:1539] Status update TASK_RUNNING
> (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for task 0 of framework
> 201401170507-160088899-60124-17987-0000 from slave(138)@67.195.138.9:60124
> I0117 05:07:37.046164 18037 slave.cpp:1891] Sending acknowledgement for
> status update TASK_RUNNING (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for
> task 0 of framework 201401170507-160088899-60124-17987-0000 to executor(45)@
> 67.195.138.9:60124
> I0117 05:07:37.046216 18033 sched.cpp:609] Scheduler::statusUpdate took
> 21758ns
> I0117 05:07:37.046228 18037 exec.cpp:335] Executor received status update
> acknowledgement ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc for task 0 of
> framework 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.046491 17987 master.cpp:559] Master terminating
> I0117 05:07:37.046565 17987 master.cpp:209] Shutting down master
> I0117 05:07:37.046525 18037 status_update_manager.cpp:392] Received status
> update acknowledgement (UUID: ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for
> task 0 of framework 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.046615 18036 slave.cpp:1966] master@67.195.138.9:60124exited
> W0117 05:07:37.046633 18036 slave.cpp:1969] Master disconnected! Waiting
> for a new master to be elected
> I0117 05:07:37.046622 17987 master.hpp:427] Removing task 0 with resources
> cpus(*):1; mem(*):500 on slave 201401170507-160088899-60124-17987-0 (
> vesta.apache.org)
> I0117 05:07:37.046720 18034 slave.cpp:1372] Status update manager
> successfully handled status update acknowledgement (UUID:
> ac4d6b8e-b16d-4392-ae3e-ddaa52e7b6cc) for task 0 of framework
> 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.046728 17987 master.cpp:252] Removing slave
> 201401170507-160088899-60124-17987-0 (vesta.apache.org)
> I0117 05:07:37.046789 18037 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
> 201401170507-160088899-60124-17987-0 from framework
> 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.152441 17987 contender.cpp:176] Now cancelling the
> membership: 2
> I0117 05:07:37.152557 18031 group.cpp:568] Trying to remove
> '/znode/0000000002' in ZooKeeper
> 2014-01-17 05:07:37,161:17987(0x2b885bc2c7c0):ZOO_INFO@zookeeper_close@2505:
> Closing zookeeper sessionId=0x1439e98dfb00007 to [127.0.0.1:48726]
>
> I0117 05:07:37.162299 18031 detector.cpp:122] The current leader (id=2) is
> lost
> I0117 05:07:37.162322 18031 detector.cpp:134] Detected a new leader: None
> 2014-01-17 05:07:37,162:17987(0x2b885bc2c7c0):ZOO_INFO@zookeeper_close@2505:
> Closing zookeeper sessionId=0x1439e98dfb00006 to [127.0.0.1:48726]
>
> I0117 05:07:37.162678 18035 detector.cpp:122] The current leader (id=2)
> is lost
> I0117 05:07:37.162701 18035 detector.cpp:134] Detected a new leader: None
> I0117 05:07:37.162873 18031 slave.cpp:521] Lost leading master
> I0117 05:07:37.162889 18031 slave.cpp:525] Detecting new master
> I0117 05:07:37.162960 18037 detector.cpp:122] The current leader (id=2) is
> lost
> I0117 05:07:37.162996 18037 detector.cpp:134] Detected a new leader: None
> I0117 05:07:37.163137 18037 sched.cpp:204] Scheduler::disconnected took
> 20300ns
> I0117 05:07:37.163158 18037 sched.cpp:226] No master detected
> I0117 05:07:37.163166 18037 sched.cpp:230] Detecting new master
> I0117 05:07:37.163729 18035 master.cpp:284] Master started on
> 67.195.138.9:60124
> I0117 05:07:37.163764 18035 master.cpp:298] Master ID:
> 201401170507-160088899-60124-17987
> I0117 05:07:37.163772 18035 master.cpp:301] Master only allowing
> authenticated frameworks to register!
> 2014-01-17 05:07:37,163:17987(0x2b885be31700):ZOO_INFO@log_env@712:
> Client environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-01-17 05:07:37,163:17987(0x2b885be31700):ZOO_INFO@log_env@716:
> Client environment:host.name=vesta.apache.org
> 2014-01-17 05:07:37,163:17987(0x2b885be31700):ZOO_INFO@log_env@723:
> Client environment:os.name=Linux
> 2014-01-17 05:07:37,163:17987(0x2b885be31700):ZOO_INFO@log_env@724:
> Client environment:os.arch=3.2.0-51-generic
> 2014-01-17 05:07:37,164:17987(0x2b885be31700):ZOO_INFO@log_env@725:
> Client environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013
> I0117 05:07:37.164106 18038 master.cpp:85] No whitelist given. Advertising
> offers for all slaves
> 2014-01-17 05:07:37,164:17987(0x2b885be31700):ZOO_INFO@log_env@733:
> Client environment:user.name=(null)
> 2014-01-17 05:07:37,164:17987(0x2b885be31700):ZOO_INFO@log_env@741:
> Client environment:user.home=/home/jenkins
> 2014-01-17 05:07:37,164:17987(0x2b885be31700):ZOO_INFO@log_env@753:
> Client
> environment:user.dir=/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src
> 2014-01-17 05:07:37,164:17987(0x2b885be31700):ZOO_INFO@zookeeper_init@786:
> Initiating client connection, host=127.0.0.1:48726 sessionTimeout=10000
> watcher=0x2b88594038e0 sessionId=0 sessionPasswd=<null>
> context=0x2b886c026900 flags=0
> I0117 05:07:37.164345 18032 hierarchical_allocator_process.hpp:302]
> Initializing hierarchical allocator process with master :
> master@67.195.138.9:60124
> 2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@712:
> Client environment:zookeeper.version=zookeeper C client 3.4.5
> 2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@716:
> Client environment:host.name=vesta.apache.org
> 2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@723:
> Client environment:os.name=Linux
> 2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@724:
> Client environment:os.arch=3.2.0-51-generic
> 2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@725:
> Client environment:os.version=#77-Ubuntu SMP Wed Jul 24 20:18:19 UTC 2013
> 2014-01-17 05:07:37,164:17987(0x2b8968bb4700):ZOO_INFO@check_events@1703:
> initiated connection to server [127.0.0.1:48726]
> I0117 05:07:37.164485 18034 contender.cpp:121] Joining the ZK group with
> data: 'master@67.195.138.9:60124'
> 2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@733:
> Client environment:user.name=(null)
> 2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@741:
> Client environment:user.home=/home/jenkins
> 2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@log_env@753:
> Client
> environment:user.dir=/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src
> 2014-01-17 05:07:37,164:17987(0x2b885c233700):ZOO_INFO@zookeeper_init@786:
> Initiating client connection, host=127.0.0.1:48726 sessionTimeout=10000
> watcher=0x2b88594038e0 sessionId=0 sessionPasswd=<null>
> context=0x2b888802dab0 flags=0
> 2014-01-17 05:07:37,165:17987(0x2b8969dce700):ZOO_INFO@check_events@1703:
> initiated connection to server [127.0.0.1:48726]
> 2014-01-17 05:07:37,182:17987(0x2b8968bb4700):ZOO_INFO@check_events@1750:
> session establishment complete on server [127.0.0.1:48726],
> sessionId=0x1439e98dfb0000a, negotiated timeout=10000
> I0117 05:07:37.182538 18034 group.cpp:307] Group process ((1722)@
> 67.195.138.9:60124) connected to ZooKeeper
> I0117 05:07:37.182554 18034 group.cpp:724] Syncing group operations: queue
> size (joins, cancels, datas) = (1, 0, 0)
> I0117 05:07:37.182561 18034 group.cpp:364] Trying to create path '/znode'
> in ZooKeeper
> 2014-01-17 05:07:37,182:17987(0x2b8969dce700):ZOO_INFO@check_events@1750:
> session establishment complete on server [127.0.0.1:48726],
> sessionId=0x1439e98dfb0000b, negotiated timeout=10000
> I0117 05:07:37.183274 18036 group.cpp:307] Group process ((1724)@
> 67.195.138.9:60124) connected to ZooKeeper
> I0117 05:07:37.183394 18036 group.cpp:724] Syncing group operations: queue
> size (joins, cancels, datas) = (0, 0, 0)
> I0117 05:07:37.183449 18036 group.cpp:364] Trying to create path '/znode'
> in ZooKeeper
> I0117 05:07:37.190279 18031 contender.cpp:237] New candidate (id='3',
> data='master@67.195.138.9:60124') has entered the contest for leadership
> I0117 05:07:37.191222 18032 detector.cpp:134] Detected a new leader:
> '(id='3')
> I0117 05:07:37.191360 18038 group.cpp:611] Trying to get
> '/znode/0000000003' in ZooKeeper
> I0117 05:07:37.191390 18034 detector.cpp:134] Detected a new leader:
> '(id='3')
> I0117 05:07:37.191544 18031 group.cpp:611] Trying to get
> '/znode/0000000003' in ZooKeeper
> I0117 05:07:37.191727 18035 detector.cpp:134] Detected a new leader:
> '(id='3')
> I0117 05:07:37.191874 18035 group.cpp:611] Trying to get
> '/znode/0000000003' in ZooKeeper
> I0117 05:07:37.192060 18036 detector.cpp:322] A new leading master (UPID=
> master@67.195.138.9:60124) is detected
> I0117 05:07:37.192179 18032 master.cpp:732] The newly elected leader is
> master@67.195.138.9:60124
> I0117 05:07:37.192194 18032 master.cpp:740] Elected as the leading master!
> I0117 05:07:37.192384 18031 detector.cpp:322] A new leading master (UPID=
> master@67.195.138.9:60124) is detected
> I0117 05:07:37.192437 18031 slave.cpp:500] New master detected at
> master@67.195.138.9:60124
> I0117 05:07:37.192546 18031 slave.cpp:525] Detecting new master
> I0117 05:07:37.192596 18031 status_update_manager.cpp:162] New master
> detected at master@67.195.138.9:60124
> I0117 05:07:37.192698 18031 master.cpp:1442] Attempting to re-register
> slave 201401170507-160088899-60124-17987-0 at slave(138)@
> 67.195.138.9:60124 (vesta.apache.org)
> I0117 05:07:37.192708 18031 master.cpp:2615] Adding slave
> 201401170507-160088899-60124-17987-0 at vesta.apache.org with cpus(*):2;
> mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]
> I0117 05:07:37.192798 18031 master.hpp:409] Adding task 0 with resources
> cpus(*):1; mem(*):500 on slave 201401170507-160088899-60124-17987-0 (
> vesta.apache.org)
> W0117 05:07:37.192826 18031 master.cpp:2710] Possibly orphaned task 0 of
> framework 201401170507-160088899-60124-17987-0000 running on slave
> 201401170507-160088899-60124-17987-0 (vesta.apache.org)
> I0117 05:07:37.192939 18031 slave.cpp:602] Re-registered with master
> master@67.195.138.9:60124
> I0117 05:07:37.193081 18031 hierarchical_allocator_process.hpp:445] Added
> slave 201401170507-160088899-60124-17987-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)
> I0117 05:07:37.193119 18031 hierarchical_allocator_process.hpp:708]
> Performed allocation for slave 201401170507-160088899-60124-17987-0 in
> 11019ns
> I0117 05:07:37.193238 18031 detector.cpp:322] A new leading master (UPID=
> master@67.195.138.9:60124) is detected
> I0117 05:07:37.193286 18031 sched.cpp:210] New master detected at
> master@67.195.138.9:60124
> I0117 05:07:37.193300 18031 sched.cpp:261] Authenticating with master
> master@67.195.138.9:60124
> I0117 05:07:37.193347 18031 sched.cpp:230] Detecting new master
> I0117 05:07:37.193351 18033 authenticatee.hpp:124] Creating new client
> SASL connection
> I0117 05:07:37.193397 18031 master.cpp:1836] Authenticating framework at
> scheduler(132)@67.195.138.9:60124
> I0117 05:07:37.193436 18033 authenticator.hpp:140] Creating new server
> SASL connection
> I0117 05:07:37.193496 18033 authenticatee.hpp:212] Received SASL
> authentication mechanisms: CRAM-MD5
> I0117 05:07:37.193510 18033 authenticatee.hpp:238] Attempting to
> authenticate with mechanism 'CRAM-MD5'
> I0117 05:07:37.193527 18033 authenticator.hpp:243] Received SASL
> authentication start
> I0117 05:07:37.193574 18033 authenticator.hpp:325] Authentication requires
> more steps
> I0117 05:07:37.193599 18033 authenticatee.hpp:258] Received SASL
> authentication step
> I0117 05:07:37.193624 18033 authenticator.hpp:271] Received SASL
> authentication step
> I0117 05:07:37.193641 18033 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
> I0117 05:07:37.193649 18033 auxprop.cpp:153] Looking up auxiliary
> property '*userPassword'
> I0117 05:07:37.193670 18033 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0117 05:07:37.193680 18033 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
> I0117 05:07:37.193686 18033 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0117 05:07:37.193689 18033 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0117 05:07:37.193701 18033 authenticator.hpp:317] Authentication success
> I0117 05:07:37.193717 18033 authenticatee.hpp:298] Authentication success
> I0117 05:07:37.193735 18031 master.cpp:1876] Successfully authenticated
> framework at scheduler(132)@67.195.138.9:60124
> I0117 05:07:37.193850 18033 sched.cpp:335] Successfully authenticated
> with master master@67.195.138.9:60124
> I0117 05:07:37.193922 18035 master.cpp:876] Re-registering framework
> 201401170507-160088899-60124-17987-0000 at scheduler(132)@
> 67.195.138.9:60124
> I0117 05:07:37.194026 18034 sched.cpp:384] Framework registered with
> 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.194047 18032 slave.cpp:1313] Updating framework
> 201401170507-160088899-60124-17987-0000 pid to scheduler(132)@
> 67.195.138.9:60124
> I0117 05:07:37.194057 18034 sched.cpp:398] Scheduler::registered took
> 12348ns
> I0117 05:07:37.194149 18034 hierarchical_allocator_process.hpp:332] Added
> framework 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.194190 18034 hierarchical_allocator_process.hpp:752]
> Offering cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000]
> on slave 201401170507-160088899-60124-17987-0 to framework
> 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.194319 18034 hierarchical_allocator_process.hpp:688]
> Performed allocation for 1 slaves in 159005ns
> I0117 05:07:37.194377 18031 master.hpp:437] Adding offer
> 201401170507-160088899-60124-17987-0 with resources cpus(*):1; mem(*):524;
> disk(*):1.38501e+06; ports(*):[31000-32000] on slave
> 201401170507-160088899-60124-17987-0 (vesta.apache.org)
> I0117 05:07:37.194445 18031 master.cpp:1791] Sending 1 offers to framework
> 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.194540 18032 sched.cpp:518] Scheduler::resourceOffers took
> 23324ns
> I0117 05:07:37.194730 18031 sched.cpp:720] Stopping framework
> '201401170507-160088899-60124-17987-0000'
> I0117 05:07:37.194746 17987 master.cpp:559] Master terminating
> I0117 05:07:37.194821 17987 master.cpp:209] Shutting down master
> I0117 05:07:37.194823 18033 slave.cpp:1966] master@67.195.138.9:60124exited
> W0117 05:07:37.194907 18033 slave.cpp:1969] Master disconnected! Waiting
> for a new master to be elected
> I0117 05:07:37.194918 17987 master.hpp:427] Removing task 0 with resources
> cpus(*):1; mem(*):500 on slave 201401170507-160088899-60124-17987-0 (
> vesta.apache.org)
> I0117 05:07:37.195016 17987 master.hpp:447] Removing offer
> 201401170507-160088899-60124-17987-0 with resources cpus(*):1; mem(*):524;
> disk(*):1.38501e+06; ports(*):[31000-32000] on slave
> 201401170507-160088899-60124-17987-0 (vesta.apache.org)
> I0117 05:07:37.195147 18031 hierarchical_allocator_process.hpp:637]
> Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500)
> on slave 201401170507-160088899-60124-17987-0 from framework
> 201401170507-160088899-60124-17987-0000
> I0117 05:07:37.195173 17987 master.cpp:252] Removing slave
> 201401170507-160088899-60124-17987-0 (vesta.apache.org)
> I0117 05:07:37.340455 17987 contender.cpp:176] Now cancelling the
> membership: 3
> I0117 05:07:37.340541 18034 group.cpp:568] Trying to remove
> '/znode/0000000003' in ZooKeeper
> 2014-01-17 05:07:37,346:17987(0x2b885bc2c7c0):ZOO_INFO@zookeeper_close@2505:
> Closing zookeeper sessionId=0x1439e98dfb0000a to [127.0.0.1:48726]
>
> I0117 05:07:37.346509 18035 detector.cpp:122] The current leader (id=3) is
> lost
> I0117 05:07:37.346524 18035 detector.cpp:134] Detected a new leader: None
> I0117 05:07:37.350237 18034 slave.cpp:521] Lost leading master
> I0117 05:07:37.350253 18034 slave.cpp:525] Detecting new master
> I0117 05:07:37.350378 18031 detector.cpp:122] The current leader (id=3) is
> lost
> I0117 05:07:37.350389 18031 detector.cpp:134] Detected a new leader: None
> 2014-01-17 05:07:37,350:17987(0x2b885bc2c7c0):ZOO_INFO@zookeeper_close@2505:
> Closing zookeeper sessionId=0x1439e98dfb0000b to [127.0.0.1:48726]
>
> I0117 05:07:37.350677 18034 slave.cpp:390] Slave terminating
> I0117 05:07:37.350695 18034 slave.cpp:1143] Asked to shut down framework
> 201401170507-160088899-60124-17987-0000 by @0.0.0.0:0
> W0117 05:07:37.350704 18034 slave.cpp:1151] Ignoring shutdown framework
> message for 201401170507-160088899-60124-17987-0000 because the slave has
> not yet registered with the master
> I0117 05:07:37.350782 18036 exec.cpp:455] Slave exited ... shutting down
> I0117 05:07:37.350810 18036 exec.cpp:472] Executor::shutdown took 11777ns
> 2014-01-17 05:07:37,351:17987(0x2b885bc2c7c0):ZOO_INFO@zookeeper_close@2505:
> Closing zookeeper sessionId=0x1439e98dfb00008 to [127.0.0.1:48726]
>
> 2014-01-17 05:07:37,352:17987(0x2b885bc2c7c0):ZOO_INFO@zookeeper_close@2505:
> Closing zookeeper sessionId=0x1439e98dfb00009 to [127.0.0.1:48726]
>
> [ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (383 ms)
> I0117 05:07:37.353945 17987 zookeeper_test_server.cpp:122] Shutdown
> ZooKeeperTestServer on port 48726
> [----------] 2 tests from AllocatorZooKeeperTest/0 (1880 ms total)
>
> [----------] Global test environment tear-down
> [==========] 253 tests from 46 test cases ran. (197312 ms total)
> [ PASSED ] 252 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] RecoverTest.RacingCatchup
>
> 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 #1840
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/1840/>