mesos-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject Build failed in Jenkins: Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME #1626
Date Tue, 18 Feb 2014 22:13:14 GMT
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/1626/>

------------------------------------------
[...truncated 25545 lines...]
2014-02-18 22:13:13,374:4456(0x2ae0a5eff700):ZOO_INFO@log_env@733: Client environment:user.name=(null)
2014-02-18 22:13:13,374:4456(0x2ae0a5eff700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
2014-02-18 22:13:13,375:4456(0x2ae0a5eff700):ZOO_INFO@log_env@753: Client environment:user.dir=<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src>
2014-02-18 22:13:13,375:4456(0x2ae0a5eff700):ZOO_INFO@zookeeper_init@786: Initiating client
connection, host=127.0.0.1:34464 sessionTimeout=10000 watcher=0x2ae0a2e87db0 sessionId=0 sessionPasswd=<null>
context=0x2ae0b002dac0 flags=0
2014-02-18 22:13:13,375:4456(0x2ae240d49700):ZOO_INFO@check_events@1703: initiated connection
to server [127.0.0.1:34464]
I0218 22:13:13.376108  4496 state.cpp:33] Recovering state from '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_QBRFFU/meta'
I0218 22:13:13.376224  4496 status_update_manager.cpp:188] Recovering status update manager
I0218 22:13:13.376354  4490 slave.cpp:2670] Finished recovery
2014-02-18 22:13:13,576:4456(0x2ae241761700):ZOO_INFO@check_events@1750: session establishment
complete on server [127.0.0.1:34464], sessionId=0x144470f38250008, negotiated timeout=10000
I0218 22:13:13.576436  4490 group.cpp:310] Group process ((2252)@67.195.138.60:51028) connected
to ZooKeeper
I0218 22:13:13.576464  4490 group.cpp:775] Syncing group operations: queue size (joins, cancels,
datas) = (0, 0, 0)
I0218 22:13:13.576474  4490 group.cpp:382] Trying to create path '/znode' in ZooKeeper
2014-02-18 22:13:13,593:4456(0x2ae240d49700):ZOO_INFO@check_events@1750: session establishment
complete on server [127.0.0.1:34464], sessionId=0x144470f38250009, negotiated timeout=10000
I0218 22:13:13.593638  4496 group.cpp:310] Group process ((2258)@67.195.138.60:51028) connected
to ZooKeeper
I0218 22:13:13.593657  4496 group.cpp:775] Syncing group operations: queue size (joins, cancels,
datas) = (0, 0, 0)
I0218 22:13:13.593664  4496 group.cpp:382] Trying to create path '/znode' in ZooKeeper
I0218 22:13:13.594648  4495 detector.cpp:134] Detected a new leader: (id='2')
I0218 22:13:13.594759  4495 group.cpp:652] Trying to get '/znode/info_0000000002' in ZooKeeper
I0218 22:13:13.594944  4489 detector.cpp:134] Detected a new leader: (id='2')
I0218 22:13:13.595029  4496 group.cpp:652] Trying to get '/znode/info_0000000002' in ZooKeeper
I0218 22:13:13.595324  4490 detector.cpp:377] A new leading master (UPID=master@67.195.138.60:51028)
is detected
I0218 22:13:13.595381  4490 slave.cpp:397] New master detected at master@67.195.138.60:51028
I0218 22:13:13.595440  4495 status_update_manager.cpp:162] New master detected at master@67.195.138.60:51028
I0218 22:13:13.595448  4490 slave.cpp:422] Detecting new master
I0218 22:13:13.595499  4495 master.cpp:1848] Attempting to register slave on janus.apache.org
at slave(142)@67.195.138.60:51028
I0218 22:13:13.595509  4495 master.cpp:2831] Adding slave 2014-02-18-22:13:09-1015726915-51028-4456-0
at janus.apache.org with cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000]
I0218 22:13:13.595581  4496 slave.cpp:440] Registered with master master@67.195.138.60:51028;
given slave ID 2014-02-18-22:13:09-1015726915-51028-4456-0
I0218 22:13:13.595615  4496 detector.cpp:377] A new leading master (UPID=master@67.195.138.60:51028)
is detected
I0218 22:13:13.595669  4496 sched.cpp:217] New master detected at master@67.195.138.60:51028
I0218 22:13:13.595661  4495 hierarchical_allocator_process.hpp:445] Added slave 2014-02-18-22:13:09-1015726915-51028-4456-0
(janus.apache.org) with cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] (and
cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] available)
I0218 22:13:13.595679  4496 sched.cpp:267] Authenticating with master master@67.195.138.60:51028
I0218 22:13:13.595696  4495 hierarchical_allocator_process.hpp:708] Performed allocation for
slave 2014-02-18-22:13:09-1015726915-51028-4456-0 in 8514ns
I0218 22:13:13.595738  4495 authenticatee.hpp:124] Creating new client SASL connection
I0218 22:13:13.595885  4496 master.cpp:2344] Authenticating framework at scheduler(135)@67.195.138.60:51028
I0218 22:13:13.595963  4495 authenticator.hpp:140] Creating new server SASL connection
I0218 22:13:13.596047  4496 authenticatee.hpp:212] Received SASL authentication mechanisms:
CRAM-MD5
I0218 22:13:13.596061  4496 authenticatee.hpp:238] Attempting to authenticate with mechanism
'CRAM-MD5'
I0218 22:13:13.596086  4496 authenticator.hpp:243] Received SASL authentication start
I0218 22:13:13.596148  4496 authenticator.hpp:325] Authentication requires more steps
I0218 22:13:13.596174  4496 authenticatee.hpp:258] Received SASL authentication step
I0218 22:13:13.596205  4496 authenticator.hpp:271] Received SASL authentication step
I0218 22:13:13.596221  4496 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'janus.apache.org' server FQDN: 'janus.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0218 22:13:13.596228  4496 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0218 22:13:13.596241  4496 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0218 22:13:13.596251  4496 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'janus.apache.org' server FQDN: 'janus.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0218 22:13:13.596257  4496 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since
SASL_AUXPROP_AUTHZID == true
I0218 22:13:13.596262  4496 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
I0218 22:13:13.596273  4496 authenticator.hpp:317] Authentication success
I0218 22:13:13.596297  4496 authenticatee.hpp:298] Authentication success
I0218 22:13:13.596319  4495 master.cpp:2384] Successfully authenticated framework at scheduler(135)@67.195.138.60:51028
I0218 22:13:13.596361  4496 sched.cpp:341] Successfully authenticated with master master@67.195.138.60:51028
I0218 22:13:13.596374  4496 sched.cpp:460] Sending registration request to master@67.195.138.60:51028
I0218 22:13:13.596413  4496 master.cpp:819] Received registration request from scheduler(135)@67.195.138.60:51028
I0218 22:13:13.596436  4496 master.cpp:837] Registering framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
at scheduler(135)@67.195.138.60:51028
I0218 22:13:13.596483  4496 sched.cpp:391] Framework registered with 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.596500  4496 sched.cpp:405] Scheduler::registered took 8543ns
I0218 22:13:13.596526  4496 hierarchical_allocator_process.hpp:332] Added framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.596562  4496 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024;
disk(*):23038; ports(*):[31000-32000] on slave 2014-02-18-22:13:09-1015726915-51028-4456-0
to framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.596670  4496 hierarchical_allocator_process.hpp:688] Performed allocation for
1 slaves in 133275ns
I0218 22:13:13.596719  4496 master.hpp:446] Adding offer 2014-02-18-22:13:09-1015726915-51028-4456-0
with resources cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] on slave 2014-02-18-22:13:09-1015726915-51028-4456-0
(janus.apache.org)
I0218 22:13:13.596761  4496 master.cpp:2299] Sending 1 offers to framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.596983  4496 sched.cpp:528] Scheduler::resourceOffers took 152765ns
I0218 22:13:13.597117  4496 master.hpp:456] Removing offer 2014-02-18-22:13:09-1015726915-51028-4456-0
with resources cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] on slave 2014-02-18-22:13:09-1015726915-51028-4456-0
(janus.apache.org)
I0218 22:13:13.597164  4496 master.cpp:1575] Processing reply for offers: [ 2014-02-18-22:13:09-1015726915-51028-4456-0
] on slave 2014-02-18-22:13:09-1015726915-51028-4456-0 (janus.apache.org) for framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.597229  4496 master.hpp:418] Adding task 0 with resources cpus(*):1; mem(*):500
on slave 2014-02-18-22:13:09-1015726915-51028-4456-0 (janus.apache.org)
I0218 22:13:13.597254  4496 master.cpp:2468] Launching task 0 of framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
with resources cpus(*):1; mem(*):500 on slave 2014-02-18-22:13:09-1015726915-51028-4456-0
(janus.apache.org)
I0218 22:13:13.597368  4496 slave.cpp:625] Got assigned task 0 for framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.597511  4496 slave.cpp:734] Launching task 0 for framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.598492  4492 hierarchical_allocator_process.hpp:547] Framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
left cpus(*):1; mem(*):524; disk(*):23038; ports(*):[31000-32000] unused on slave 2014-02-18-22:13:09-1015726915-51028-4456-0
I0218 22:13:13.598647  4492 hierarchical_allocator_process.hpp:590] Framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
filtered slave 2014-02-18-22:13:09-1015726915-51028-4456-0 for 5secs
I0218 22:13:13.600901  4496 exec.cpp:131] Version: 0.19.0
I0218 22:13:13.600955  4492 exec.cpp:181] Executor started at: executor(46)@67.195.138.60:51028
with pid 4456
I0218 22:13:13.601006  4496 slave.cpp:844] Queuing task '0' for executor default of framework
'2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.601047  4496 slave.cpp:358] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_QBRFFU/slaves/2014-02-18-22:13:09-1015726915-51028-4456-0/frameworks/2014-02-18-22:13:09-1015726915-51028-4456-0000/executors/default/runs/72f514d3-7a7d-4798-b957-f9e72bbca365'
I0218 22:13:13.601071  4496 slave.cpp:1989] Monitoring executor 'default' of framework '2014-02-18-22:13:09-1015726915-51028-4456-0000'
in container '72f514d3-7a7d-4798-b957-f9e72bbca365'
I0218 22:13:13.601135  4496 slave.cpp:1316] Got registration for executor 'default' of framework
2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.601271  4496 slave.cpp:1434] Flushing queued task 0 for executor 'default'
of framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.601280  4492 exec.cpp:205] Executor registered on slave 2014-02-18-22:13:09-1015726915-51028-4456-0
I0218 22:13:13.602617  4492 exec.cpp:217] Executor::registered took 11984ns
I0218 22:13:13.602680  4492 exec.cpp:292] Executor asked to run task '0'
I0218 22:13:13.602713  4492 exec.cpp:301] Executor::launchTask took 22721ns
I0218 22:13:13.603937  4492 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID:
b23fdfad-8b20-45e1-81f3-8ea58db8e6bd) for task 0 of framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.604027  4492 slave.cpp:1643] Handling status update TASK_RUNNING (UUID: b23fdfad-8b20-45e1-81f3-8ea58db8e6bd)
for task 0 of framework 2014-02-18-22:13:09-1015726915-51028-4456-0000 from executor(46)@67.195.138.60:51028
I0218 22:13:13.604145  4494 status_update_manager.cpp:315] Received status update TASK_RUNNING
(UUID: b23fdfad-8b20-45e1-81f3-8ea58db8e6bd) for task 0 of framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.604183  4494 status_update_manager.cpp:494] Creating StatusUpdate stream for
task 0 of framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.604271  4494 status_update_manager.cpp:368] Forwarding status update TASK_RUNNING
(UUID: b23fdfad-8b20-45e1-81f3-8ea58db8e6bd) for task 0 of framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
to master@67.195.138.60:51028
I0218 22:13:13.604413  4490 slave.cpp:1763] Status update manager successfully handled status
update TASK_RUNNING (UUID: b23fdfad-8b20-45e1-81f3-8ea58db8e6bd) for task 0 of framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.604435  4490 slave.cpp:1769] Sending acknowledgement for status update TASK_RUNNING
(UUID: b23fdfad-8b20-45e1-81f3-8ea58db8e6bd) for task 0 of framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
to executor(46)@67.195.138.60:51028
I0218 22:13:13.604481  4492 master.cpp:2031] Status update TASK_RUNNING (UUID: b23fdfad-8b20-45e1-81f3-8ea58db8e6bd)
for task 0 of framework 2014-02-18-22:13:09-1015726915-51028-4456-0000 from slave(142)@67.195.138.60:51028
I0218 22:13:13.604524  4490 exec.cpp:338] Executor received status update acknowledgement
b23fdfad-8b20-45e1-81f3-8ea58db8e6bd for task 0 of framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.604581  4491 sched.cpp:619] Scheduler::statusUpdate took 23840ns
I0218 22:13:13.604784  4456 master.cpp:518] Master terminating
I0218 22:13:13.604799  4491 status_update_manager.cpp:393] Received status update acknowledgement
(UUID: b23fdfad-8b20-45e1-81f3-8ea58db8e6bd) for task 0 of framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.604833  4456 master.hpp:436] Removing task 0 with resources cpus(*):1; mem(*):500
on slave 2014-02-18-22:13:09-1015726915-51028-4456-0 (janus.apache.org)
I0218 22:13:13.604868  4490 slave.cpp:1256] Status update manager successfully handled status
update acknowledgement (UUID: b23fdfad-8b20-45e1-81f3-8ea58db8e6bd) for task 0 of framework
2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.604974  4491 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):500
(total allocatable: cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000]) on slave
2014-02-18-22:13:09-1015726915-51028-4456-0 from framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.605025  4490 slave.cpp:1844] master@67.195.138.60:51028 exited
W0218 22:13:13.605036  4490 slave.cpp:1847] Master disconnected! Waiting for a new master
to be elected
I0218 22:13:13.700714  4491 contender.cpp:182] Now cancelling the membership: 2
I0218 22:13:13.700842  4495 group.cpp:613] Trying to remove '/znode/info_0000000002' in ZooKeeper
2014-02-18 22:13:13,749:4456(0x2ae0a56f77c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper
sessionId=0x144470f38250006 to [127.0.0.1:34464]

I0218 22:13:13.749920  4491 detector.cpp:122] The current leader (id=2) is lost
I0218 22:13:13.749936  4491 detector.cpp:134] Detected a new leader: None
I0218 22:13:13.750093  4491 slave.cpp:418] Lost leading master
I0218 22:13:13.750104  4491 slave.cpp:422] Detecting new master
I0218 22:13:13.750228  4491 detector.cpp:122] The current leader (id=2) is lost
I0218 22:13:13.750238  4491 detector.cpp:134] Detected a new leader: None
I0218 22:13:13.750392  4489 sched.cpp:211] Scheduler::disconnected took 9963ns
I0218 22:13:13.750433  4489 sched.cpp:233] No master detected
2014-02-18 22:13:13,754:4456(0x2ae0a56f77c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper
sessionId=0x144470f38250007 to [127.0.0.1:34464]

2014-02-18 22:13:13,755:4456(0x2ae0a6301700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper
C client 3.4.5
2014-02-18 22:13:13,755:4456(0x2ae0a6301700):ZOO_INFO@log_env@716: Client environment:host.name=janus
2014-02-18 22:13:13,755:4456(0x2ae0a6301700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
2014-02-18 22:13:13,755:4456(0x2ae0a6100700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper
C client 3.4.5
2014-02-18 22:13:13,755:4456(0x2ae0a6100700):ZOO_INFO@log_env@716: Client environment:host.name=janus
I0218 22:13:13.755234  4456 master.cpp:240] Master ID: 2014-02-18-22:13:13-1015726915-51028-4456
Hostname: janus.apache.org
2014-02-18 22:13:13,755:4456(0x2ae0a6301700):ZOO_INFO@log_env@724: Client environment:os.arch=3.2.0-57-generic
2014-02-18 22:13:13,755:4456(0x2ae0a6301700):ZOO_INFO@log_env@725: Client environment:os.version=#87-Ubuntu
SMP Tue Nov 12 21:35:10 UTC 2013
I0218 22:13:13.755313  4492 master.cpp:250] Master started on 67.195.138.60:51028
I0218 22:13:13.755324  4492 master.cpp:253] Master only allowing authenticated frameworks
to register!
2014-02-18 22:13:13,755:4456(0x2ae0a6100700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
2014-02-18 22:13:13,755:4456(0x2ae0a6100700):ZOO_INFO@log_env@724: Client environment:os.arch=3.2.0-57-generic
2014-02-18 22:13:13,755:4456(0x2ae0a6100700):ZOO_INFO@log_env@725: Client environment:os.version=#87-Ubuntu
SMP Tue Nov 12 21:35:10 UTC 2013
2014-02-18 22:13:13,755:4456(0x2ae0a6301700):ZOO_INFO@log_env@733: Client environment:user.name=(null)
I0218 22:13:13.755785  4495 master.cpp:86] No whitelist given. Advertising offers for all
slaves
I0218 22:13:13.755976  4495 hierarchical_allocator_process.hpp:302] Initializing hierarchical
allocator process with master : master@67.195.138.60:51028
I0218 22:13:13.756207  4495 contender.cpp:127] Joining the ZK group
2014-02-18 22:13:13,756:4456(0x2ae0a6100700):ZOO_INFO@log_env@733: Client environment:user.name=(null)
2014-02-18 22:13:13,756:4456(0x2ae0a6100700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
2014-02-18 22:13:13,756:4456(0x2ae0a6100700):ZOO_INFO@log_env@753: Client environment:user.dir=<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src>
2014-02-18 22:13:13,756:4456(0x2ae0a6100700):ZOO_INFO@zookeeper_init@786: Initiating client
connection, host=127.0.0.1:34464 sessionTimeout=10000 watcher=0x2ae0a2e87db0 sessionId=0 sessionPasswd=<null>
context=0x2ae0c001c1c0 flags=0
2014-02-18 22:13:13,756:4456(0x2ae0a6301700):ZOO_INFO@log_env@741: Client environment:user.home=/home/jenkins
2014-02-18 22:13:13,756:4456(0x2ae0a6301700):ZOO_INFO@log_env@753: Client environment:user.dir=<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src>
2014-02-18 22:13:13,756:4456(0x2ae0a6301700):ZOO_INFO@zookeeper_init@786: Initiating client
connection, host=127.0.0.1:34464 sessionTimeout=10000 watcher=0x2ae0a2e87db0 sessionId=0 sessionPasswd=<null>
context=0x2ae0d401d320 flags=0
2014-02-18 22:13:13,756:4456(0x2ae241f9d700):ZOO_INFO@check_events@1703: initiated connection
to server [127.0.0.1:34464]
2014-02-18 22:13:13,756:4456(0x2ae2427a1700):ZOO_INFO@check_events@1703: initiated connection
to server [127.0.0.1:34464]
2014-02-18 22:13:13,797:4456(0x2ae241f9d700):ZOO_INFO@check_events@1750: session establishment
complete on server [127.0.0.1:34464], sessionId=0x144470f3825000a, negotiated timeout=10000
I0218 22:13:13.798012  4491 group.cpp:310] Group process ((2265)@67.195.138.60:51028) connected
to ZooKeeper
I0218 22:13:13.798034  4491 group.cpp:775] Syncing group operations: queue size (joins, cancels,
datas) = (0, 0, 0)
I0218 22:13:13.798044  4491 group.cpp:382] Trying to create path '/znode' in ZooKeeper
2014-02-18 22:13:13,798:4456(0x2ae2427a1700):ZOO_INFO@check_events@1750: session establishment
complete on server [127.0.0.1:34464], sessionId=0x144470f3825000b, negotiated timeout=10000
I0218 22:13:13.798535  4492 group.cpp:310] Group process ((2263)@67.195.138.60:51028) connected
to ZooKeeper
I0218 22:13:13.798550  4492 group.cpp:775] Syncing group operations: queue size (joins, cancels,
datas) = (1, 0, 0)
I0218 22:13:13.798558  4492 group.cpp:382] Trying to create path '/znode' in ZooKeeper
I0218 22:13:13.876724  4491 contender.cpp:243] New candidate (id='3') has entered the contest
for leadership
I0218 22:13:13.877375  4489 detector.cpp:134] Detected a new leader: (id='3')
I0218 22:13:13.877517  4489 detector.cpp:134] Detected a new leader: (id='3')
I0218 22:13:13.877571  4491 group.cpp:652] Trying to get '/znode/info_0000000003' in ZooKeeper
I0218 22:13:13.877713  4496 group.cpp:652] Trying to get '/znode/info_0000000003' in ZooKeeper
I0218 22:13:13.877748  4489 detector.cpp:134] Detected a new leader: (id='3')
I0218 22:13:13.877992  4494 group.cpp:652] Trying to get '/znode/info_0000000003' in ZooKeeper
I0218 22:13:13.878437  4489 detector.cpp:377] A new leading master (UPID=master@67.195.138.60:51028)
is detected
I0218 22:13:13.878578  4496 slave.cpp:397] New master detected at master@67.195.138.60:51028
I0218 22:13:13.878577  4491 detector.cpp:377] A new leading master (UPID=master@67.195.138.60:51028)
is detected
I0218 22:13:13.878671  4489 master.cpp:761] The newly elected leader is master@67.195.138.60:51028
with id 2014-02-18-22:13:13-1015726915-51028-4456
I0218 22:13:13.878691  4489 master.cpp:771] Elected as the leading master!
I0218 22:13:13.878710  4492 detector.cpp:377] A new leading master (UPID=master@67.195.138.60:51028)
is detected
I0218 22:13:13.878759  4495 status_update_manager.cpp:162] New master detected at master@67.195.138.60:51028
I0218 22:13:13.878813  4496 slave.cpp:422] Detecting new master
I0218 22:13:13.878849  4489 sched.cpp:217] New master detected at master@67.195.138.60:51028
I0218 22:13:13.878875  4489 sched.cpp:267] Authenticating with master master@67.195.138.60:51028
I0218 22:13:13.878897  4495 master.cpp:1942] Attempting to re-register slave 2014-02-18-22:13:09-1015726915-51028-4456-0
at slave(142)@67.195.138.60:51028 (janus.apache.org)
I0218 22:13:13.878916  4495 master.cpp:2831] Adding slave 2014-02-18-22:13:09-1015726915-51028-4456-0
at janus.apache.org with cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000]
I0218 22:13:13.879036  4492 slave.cpp:490] Re-registered with master master@67.195.138.60:51028
I0218 22:13:13.879058  4493 authenticatee.hpp:124] Creating new client SASL connection
I0218 22:13:13.879061  4495 master.hpp:418] Adding task 0 with resources cpus(*):1; mem(*):500
on slave 2014-02-18-22:13:09-1015726915-51028-4456-0 (janus.apache.org)
W0218 22:13:13.879086  4495 master.cpp:2926] Possibly orphaned task 0 of framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
running on slave 2014-02-18-22:13:09-1015726915-51028-4456-0 (janus.apache.org)
I0218 22:13:13.879271  4489 master.cpp:2344] Authenticating framework at scheduler(135)@67.195.138.60:51028
I0218 22:13:13.879360  4492 authenticator.hpp:140] Creating new server SASL connection
I0218 22:13:13.879374  4493 hierarchical_allocator_process.hpp:445] Added slave 2014-02-18-22:13:09-1015726915-51028-4456-0
(janus.apache.org) with cpus(*):2; mem(*):1024; disk(*):23038; ports(*):[31000-32000] (and
cpus(*):1; mem(*):524; disk(*):23038; ports(*):[31000-32000] available)
I0218 22:13:13.879430  4493 hierarchical_allocator_process.hpp:708] Performed allocation for
slave 2014-02-18-22:13:09-1015726915-51028-4456-0 in 10800ns
I0218 22:13:13.879544  4496 authenticatee.hpp:212] Received SASL authentication mechanisms:
CRAM-MD5
I0218 22:13:13.879569  4496 authenticatee.hpp:238] Attempting to authenticate with mechanism
'CRAM-MD5'
I0218 22:13:13.879600  4494 authenticator.hpp:243] Received SASL authentication start
I0218 22:13:13.879667  4494 authenticator.hpp:325] Authentication requires more steps
I0218 22:13:13.879693  4494 authenticatee.hpp:258] Received SASL authentication step
I0218 22:13:13.879734  4494 authenticator.hpp:271] Received SASL authentication step
I0218 22:13:13.879765  4494 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'janus.apache.org' server FQDN: 'janus.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0218 22:13:13.879772  4494 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0218 22:13:13.879786  4494 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0218 22:13:13.879796  4494 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'janus.apache.org' server FQDN: 'janus.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0218 22:13:13.879802  4494 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since
SASL_AUXPROP_AUTHZID == true
I0218 22:13:13.879807  4494 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
I0218 22:13:13.879818  4494 authenticator.hpp:317] Authentication success
I0218 22:13:13.879851  4489 authenticatee.hpp:298] Authentication success
I0218 22:13:13.879860  4496 master.cpp:2384] Successfully authenticated framework at scheduler(135)@67.195.138.60:51028
I0218 22:13:13.879974  4489 sched.cpp:341] Successfully authenticated with master master@67.195.138.60:51028
I0218 22:13:13.880010  4489 sched.cpp:460] Sending registration request to master@67.195.138.60:51028
I0218 22:13:13.880089  4493 master.cpp:907] Re-registering framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
at scheduler(135)@67.195.138.60:51028
I0218 22:13:13.880210  4491 sched.cpp:391] Framework registered with 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.880250  4493 slave.cpp:1197] Updating framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
pid to scheduler(135)@67.195.138.60:51028
I0218 22:13:13.880260  4491 sched.cpp:405] Scheduler::registered took 33124ns
I0218 22:13:13.880344  4491 hierarchical_allocator_process.hpp:332] Added framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.880398  4491 hierarchical_allocator_process.hpp:752] Offering cpus(*):1; mem(*):524;
disk(*):23038; ports(*):[31000-32000] on slave 2014-02-18-22:13:09-1015726915-51028-4456-0
to framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.880547  4491 hierarchical_allocator_process.hpp:688] Performed allocation for
1 slaves in 182590ns
I0218 22:13:13.880605  4493 master.hpp:446] Adding offer 2014-02-18-22:13:13-1015726915-51028-4456-0
with resources cpus(*):1; mem(*):524; disk(*):23038; ports(*):[31000-32000] on slave 2014-02-18-22:13:09-1015726915-51028-4456-0
(janus.apache.org)
I0218 22:13:13.880653  4493 master.cpp:2299] Sending 1 offers to framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.880816  4495 sched.cpp:528] Scheduler::resourceOffers took 29585ns
I0218 22:13:13.881036  4494 sched.cpp:730] Stopping framework '2014-02-18-22:13:09-1015726915-51028-4456-0000'
I0218 22:13:13.881067  4456 master.cpp:518] Master terminating
I0218 22:13:13.881171  4456 master.hpp:436] Removing task 0 with resources cpus(*):1; mem(*):500
on slave 2014-02-18-22:13:09-1015726915-51028-4456-0 (janus.apache.org)
I0218 22:13:13.881325  4456 master.hpp:456] Removing offer 2014-02-18-22:13:13-1015726915-51028-4456-0
with resources cpus(*):1; mem(*):524; disk(*):23038; ports(*):[31000-32000] on slave 2014-02-18-22:13:09-1015726915-51028-4456-0
(janus.apache.org)
I0218 22:13:13.881415  4494 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):500
(total allocatable: cpus(*):1; mem(*):500) on slave 2014-02-18-22:13:09-1015726915-51028-4456-0
from framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
I0218 22:13:13.881654  4494 slave.cpp:1844] master@67.195.138.60:51028 exited
W0218 22:13:13.881665  4494 slave.cpp:1847] Master disconnected! Waiting for a new master
to be elected
I0218 22:13:14.080015  4456 contender.cpp:182] Now cancelling the membership: 3
I0218 22:13:14.080193  4494 group.cpp:613] Trying to remove '/znode/info_0000000003' in ZooKeeper
2014-02-18 22:13:14,090:4456(0x2ae0a56f77c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper
sessionId=0x144470f3825000b to [127.0.0.1:34464]

I0218 22:13:14.091408  4493 detector.cpp:122] The current leader (id=3) is lost
I0218 22:13:14.091424  4493 detector.cpp:134] Detected a new leader: None
I0218 22:13:14.091428  4491 detector.cpp:122] The current leader (id=3) is lost
I0218 22:13:14.091475  4491 detector.cpp:134] Detected a new leader: None
I0218 22:13:14.091501  4493 slave.cpp:418] Lost leading master
I0218 22:13:14.091526  4493 slave.cpp:422] Detecting new master
2014-02-18 22:13:14,107:4456(0x2ae0a56f77c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper
sessionId=0x144470f3825000a to [127.0.0.1:34464]

I0218 22:13:14.107658  4456 slave.cpp:287] Slave terminating
I0218 22:13:14.107683  4456 slave.cpp:1027] Asked to shut down framework 2014-02-18-22:13:09-1015726915-51028-4456-0000
by @0.0.0.0:0
W0218 22:13:14.107694  4456 slave.cpp:1035] Ignoring shutdown framework message for 2014-02-18-22:13:09-1015726915-51028-4456-0000
because the slave has not yet registered with the master
I0218 22:13:14.108044  4490 exec.cpp:458] Slave exited ... shutting down
I0218 22:13:14.108078  4490 exec.cpp:475] Executor::shutdown took 23333ns
2014-02-18 22:13:14,108:4456(0x2ae0a56f77c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper
sessionId=0x144470f38250008 to [127.0.0.1:34464]

2014-02-18 22:13:14,108:4456(0x2ae0a56f77c0):ZOO_INFO@zookeeper_close@2505: Closing zookeeper
sessionId=0x144470f38250009 to [127.0.0.1:34464]

[       OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (4361 ms)
I0218 22:13:14.151783  4456 zookeeper_test_server.cpp:122] Shutdown ZooKeeperTestServer on
port 34464
[----------] 2 tests from AllocatorZooKeeperTest/0 (10456 ms total)

[----------] Global test environment tear-down
[==========] 256 tests from 45 test cases ran. (236131 ms total)
[  PASSED  ] 255 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] ExamplesTest.PythonFramework

 1 FAILED TEST
  YOU HAVE 1 DISABLED TEST

make[3]: *** [check-local] Error 1
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'>
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'>
make[1]: *** [check] Error 2
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'>
make: *** [check-recursive] Error 1
Build step 'Execute shell' marked build as failure

Mime
View raw message