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-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui #2282
Date Tue, 29 Jul 2014 21:49:37 GMT
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2282/changes>

Changes:

[yan] Fixed a bug that caused 'make dist' unable to patch leveldb.

[bmahler] Fixed the master to accept a file:// based zk flag.

------------------------------------------
[...truncated 54988 lines...]
I0729 21:49:36.834485 23418 authenticator.hpp:376] Authentication success
I0729 21:49:36.834508 23418 authenticatee.hpp:305] Authentication success
I0729 21:49:36.834530 23418 master.cpp:3544] Successfully authenticated principal 'test-principal'
at slave(195)@140.211.11.27:60822
I0729 21:49:36.834589 23418 slave.cpp:734] Successfully authenticated with master master@140.211.11.27:60822
I0729 21:49:36.834619 23418 slave.cpp:972] Will retry registration in 15.198248ms if necessary
I0729 21:49:36.834677 23418 master.cpp:2762] Registering slave at slave(195)@140.211.11.27:60822
(hemera.apache.org) with id 20140729-214936-453759884-60822-23165-0
I0729 21:49:36.834776 23418 registrar.cpp:422] Attempting to update the 'registry'
I0729 21:49:36.836351 23418 log.cpp:680] Attempting to append 332 bytes to the log
I0729 21:49:36.836395 23418 coordinator.cpp:340] Coordinator attempting to write APPEND action
at position 3
I0729 21:49:36.836596 23418 replica.cpp:508] Replica received write request for position 3
I0729 21:49:36.853652 23418 leveldb.cpp:343] Persisting action (351 bytes) to leveldb took
17.041964ms
I0729 21:49:36.853672 23418 replica.cpp:676] Persisted action at 3
I0729 21:49:36.853713 23441 slave.cpp:972] Will retry registration in 24.094095ms if necessary
I0729 21:49:36.853734 23418 master.cpp:2750] Ignoring register slave message from slave(195)@140.211.11.27:60822
(hemera.apache.org) as admission is already in progress
I0729 21:49:36.853864 23441 replica.cpp:655] Replica received learned notice for position
3
I0729 21:49:36.869662 23441 leveldb.cpp:343] Persisting action (353 bytes) to leveldb took
15.781742ms
I0729 21:49:36.869683 23441 replica.cpp:676] Persisted action at 3
I0729 21:49:36.869691 23441 replica.cpp:661] Replica learned APPEND action at position 3
I0729 21:49:36.869976 23441 registrar.cpp:479] Successfully updated 'registry'
I0729 21:49:36.870048 23441 log.cpp:699] Attempting to truncate the log to 3
I0729 21:49:36.870100 23441 master.cpp:2802] Registered slave 20140729-214936-453759884-60822-23165-0
at slave(195)@140.211.11.27:60822 (hemera.apache.org)
I0729 21:49:36.870111 23441 master.cpp:3972] Adding slave 20140729-214936-453759884-60822-23165-0
at slave(195)@140.211.11.27:60822 (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):127026;
ports(*):[31000-32000]
I0729 21:49:36.870205 23441 coordinator.cpp:340] Coordinator attempting to write TRUNCATE
action at position 4
I0729 21:49:36.870265 23441 slave.cpp:768] Registered with master master@140.211.11.27:60822;
given slave ID 20140729-214936-453759884-60822-23165-0
I0729 21:49:36.870368 23441 slave.cpp:2325] Received ping from slave-observer(163)@140.211.11.27:60822
I0729 21:49:36.870425 23441 hierarchical_allocator_process.hpp:444] Added slave 20140729-214936-453759884-60822-23165-0
(hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] (and
cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] available)
I0729 21:49:36.870479 23441 hierarchical_allocator_process.hpp:750] Offering cpus(*):2; mem(*):1024;
disk(*):127026; ports(*):[31000-32000] on slave 20140729-214936-453759884-60822-23165-0 to
framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.870581 23441 hierarchical_allocator_process.hpp:706] Performed allocation for
slave 20140729-214936-453759884-60822-23165-0 in 123548ns
I0729 21:49:36.870661 23441 master.hpp:816] Adding offer 20140729-214936-453759884-60822-23165-0
with resources cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] on slave 20140729-214936-453759884-60822-23165-0
(hemera.apache.org)
I0729 21:49:36.870702 23441 master.cpp:3451] Sending 1 offers to framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.870931 23441 sched.cpp:546] Scheduler::resourceOffers took 130370ns
I0729 21:49:36.871111 23441 master.hpp:826] Removing offer 20140729-214936-453759884-60822-23165-0
with resources cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] on slave 20140729-214936-453759884-60822-23165-0
(hemera.apache.org)
I0729 21:49:36.871161 23441 master.cpp:2125] Processing reply for offers: [ 20140729-214936-453759884-60822-23165-0
] on slave 20140729-214936-453759884-60822-23165-0 at slave(195)@140.211.11.27:60822 (hemera.apache.org)
for framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.871181 23441 master.cpp:2211] Authorizing framework principal 'test-principal'
to launch task 0 as user 'jenkins'
I0729 21:49:36.871446 23441 replica.cpp:508] Replica received write request for position 4
I0729 21:49:36.873731 23420 master.hpp:788] Adding task 0 with resources cpus(*):1; mem(*):500
on slave 20140729-214936-453759884-60822-23165-0 (hemera.apache.org)
I0729 21:49:36.873761 23420 master.cpp:2277] Launching task 0 of framework 20140729-214936-453759884-60822-23165-0000
with resources cpus(*):1; mem(*):500 on slave 20140729-214936-453759884-60822-23165-0 at slave(195)@140.211.11.27:60822
(hemera.apache.org)
I0729 21:49:36.873890 23420 slave.cpp:1003] Got assigned task 0 for framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.874059 23420 slave.cpp:1113] Launching task 0 for framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.876996 23420 exec.cpp:131] Version: 0.20.0
I0729 21:49:36.877096 23420 slave.cpp:1223] Queuing task '0' for executor default of framework
'20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.877140 23430 exec.cpp:181] Executor started at: executor(62)@140.211.11.27:60822
with pid 23165
I0729 21:49:36.881748 23436 hierarchical_allocator_process.hpp:546] Framework 20140729-214936-453759884-60822-23165-0000
left cpus(*):1; mem(*):524; disk(*):127026; ports(*):[31000-32000] unused on slave 20140729-214936-453759884-60822-23165-0
I0729 21:49:36.881837 23436 hierarchical_allocator_process.hpp:588] Framework 20140729-214936-453759884-60822-23165-0000
filtered slave 20140729-214936-453759884-60822-23165-0 for 5secs
I0729 21:49:36.889657 23441 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took
18.192211ms
I0729 21:49:36.889677 23441 replica.cpp:676] Persisted action at 4
I0729 21:49:36.889827 23441 replica.cpp:655] Replica received learned notice for position
4
I0729 21:49:36.897675 23420 slave.cpp:2470] Monitoring executor 'default' of framework '20140729-214936-453759884-60822-23165-0000'
in container 'c0c67c96-df20-4629-a452-a90a4dddbf00'
I0729 21:49:36.897735 23420 slave.cpp:1734] Got registration for executor 'default' of framework
20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.897809 23420 slave.cpp:1853] Flushing queued task 0 for executor 'default'
of framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.897871 23420 slave.cpp:562] Successfully attached file '/tmp/AllocatorTest_0_SlaveReregistersFirst_p09RPE/slaves/20140729-214936-453759884-60822-23165-0/frameworks/20140729-214936-453759884-60822-23165-0000/executors/default/runs/c0c67c96-df20-4629-a452-a90a4dddbf00'
I0729 21:49:36.897943 23420 exec.cpp:205] Executor registered on slave 20140729-214936-453759884-60822-23165-0
I0729 21:49:36.899235 23420 exec.cpp:217] Executor::registered took 12044ns
I0729 21:49:36.899283 23420 exec.cpp:292] Executor asked to run task '0'
I0729 21:49:36.899309 23420 exec.cpp:301] Executor::launchTask took 18158ns
I0729 21:49:36.900600 23420 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID:
2e23a056-5546-4488-90eb-06c422d5eec9) for task 0 of framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.900670 23420 slave.cpp:2088] Handling status update TASK_RUNNING (UUID: 2e23a056-5546-4488-90eb-06c422d5eec9)
for task 0 of framework 20140729-214936-453759884-60822-23165-0000 from executor(62)@140.211.11.27:60822
I0729 21:49:36.900748 23420 status_update_manager.cpp:320] Received status update TASK_RUNNING
(UUID: 2e23a056-5546-4488-90eb-06c422d5eec9) for task 0 of framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.900758 23420 status_update_manager.cpp:499] Creating StatusUpdate stream for
task 0 of framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.900807 23420 status_update_manager.cpp:373] Forwarding status update TASK_RUNNING
(UUID: 2e23a056-5546-4488-90eb-06c422d5eec9) for task 0 of framework 20140729-214936-453759884-60822-23165-0000
to master@140.211.11.27:60822
I0729 21:49:36.900902 23420 master.cpp:3131] Forwarding status update TASK_RUNNING (UUID:
2e23a056-5546-4488-90eb-06c422d5eec9) for task 0 of framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.900933 23420 master.cpp:3097] Status update TASK_RUNNING (UUID: 2e23a056-5546-4488-90eb-06c422d5eec9)
for task 0 of framework 20140729-214936-453759884-60822-23165-0000 from slave 20140729-214936-453759884-60822-23165-0
at slave(195)@140.211.11.27:60822 (hemera.apache.org)
I0729 21:49:36.900962 23420 slave.cpp:2246] Status update manager successfully handled status
update TASK_RUNNING (UUID: 2e23a056-5546-4488-90eb-06c422d5eec9) for task 0 of framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.900972 23420 slave.cpp:2252] Sending acknowledgement for status update TASK_RUNNING
(UUID: 2e23a056-5546-4488-90eb-06c422d5eec9) for task 0 of framework 20140729-214936-453759884-60822-23165-0000
to executor(62)@140.211.11.27:60822
I0729 21:49:36.901038 23420 sched.cpp:637] Scheduler::statusUpdate took 15050ns
I0729 21:49:36.901072 23420 exec.cpp:338] Executor received status update acknowledgement
2e23a056-5546-4488-90eb-06c422d5eec9 for task 0 of framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.901118 23420 master.cpp:2612] Forwarding status update acknowledgement 2e23a056-5546-4488-90eb-06c422d5eec9
for task 0 of framework 20140729-214936-453759884-60822-23165-0000 to slave 20140729-214936-453759884-60822-23165-0
at slave(195)@140.211.11.27:60822 (hemera.apache.org)
I0729 21:49:36.901202 23420 status_update_manager.cpp:398] Received status update acknowledgement
(UUID: 2e23a056-5546-4488-90eb-06c422d5eec9) for task 0 of framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.901319 23420 slave.cpp:1674] Status update manager successfully handled status
update acknowledgement (UUID: 2e23a056-5546-4488-90eb-06c422d5eec9) for task 0 of framework
20140729-214936-453759884-60822-23165-0000
I0729 21:49:36.904687 23441 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took
14.837602ms
I0729 21:49:36.904727 23441 leveldb.cpp:401] Deleting ~2 keys from leveldb took 20007ns
I0729 21:49:36.904737 23441 replica.cpp:676] Persisted action at 4
I0729 21:49:36.904745 23441 replica.cpp:661] Replica learned TRUNCATE action at position 4
I0729 21:49:36.904913 23165 master.cpp:626] Master terminating
I0729 21:49:36.904948 23165 master.hpp:806] Removing task 0 with resources cpus(*):1; mem(*):500
on slave 20140729-214936-453759884-60822-23165-0 (hemera.apache.org)
W0729 21:49:36.904989 23165 master.cpp:4261] Removing task 0 of framework 20140729-214936-453759884-60822-23165-0000
and slave 20140729-214936-453759884-60822-23165-0 in non-terminal state TASK_RUNNING
I0729 21:49:36.909679 23440 slave.cpp:2332] master@140.211.11.27:60822 exited
W0729 21:49:36.909695 23440 slave.cpp:2335] Master disconnected! Waiting for a new master
to be elected
I0729 21:49:36.953749 23165 leveldb.cpp:176] Opened db in 47.425831ms
I0729 21:49:36.997776 23165 leveldb.cpp:183] Compacted db in 44.003898ms
I0729 21:49:36.997900 23165 leveldb.cpp:198] Created db iterator in 3698ns
I0729 21:49:36.997970 23165 leveldb.cpp:204] Seeked to beginning of db in 7269ns
I0729 21:49:36.998051 23165 leveldb.cpp:273] Iterated through 3 keys in the db in 18164ns
I0729 21:49:36.998121 23165 replica.cpp:741] Replica recovered with log positions 3 ->
4 with 0 holes and 0 unlearned
I0729 21:49:37.000005 23428 master.cpp:289] Master 20140729-214936-453759884-60822-23165 (hemera.apache.org)
started on 140.211.11.27:60822
I0729 21:49:37.000035 23428 master.cpp:326] Master only allowing authenticated frameworks
to register
I0729 21:49:37.000041 23428 master.cpp:331] Master only allowing authenticated slaves to register
I0729 21:49:37.000048 23428 credentials.hpp:36] Loading credentials for authentication from
'/tmp/AllocatorTest_0_SlaveReregistersFirst_iMpTJU/credentials'
I0729 21:49:37.000169 23428 master.cpp:360] Authorization enabled
I0729 21:49:37.000643 23428 recover.cpp:425] Starting replica recovery
I0729 21:49:37.000857 23437 master.cpp:123] No whitelist given. Advertising offers for all
slaves
I0729 21:49:37.001271 23428 recover.cpp:451] Replica is in VOTING status
I0729 21:49:37.001327 23428 recover.cpp:440] Recover process terminated
I0729 21:49:37.005776 23437 master.cpp:1129] The newly elected leader is master@140.211.11.27:60822
with id 20140729-214936-453759884-60822-23165
I0729 21:49:37.005792 23437 master.cpp:1142] Elected as the leading master!
I0729 21:49:37.005805 23437 master.cpp:960] Recovering from registrar
I0729 21:49:37.005863 23437 registrar.cpp:313] Recovering registrar
I0729 21:49:37.005961 23423 hierarchical_allocator_process.hpp:301] Initializing hierarchical
allocator process with master : master@140.211.11.27:60822
I0729 21:49:37.006075 23423 log.cpp:656] Attempting to start the writer
I0729 21:49:37.006387 23428 replica.cpp:474] Replica received implicit promise request with
proposal 2
I0729 21:49:37.019157 23428 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took
12.753413ms
I0729 21:49:37.019183 23428 replica.cpp:342] Persisted promised to 2
I0729 21:49:37.019361 23428 coordinator.cpp:230] Coordinator attemping to fill missing position
I0729 21:49:37.019443 23428 log.cpp:672] Writer started with ending position 4
I0729 21:49:37.019686 23428 leveldb.cpp:438] Reading position from leveldb took 24690ns
I0729 21:49:37.019712 23428 leveldb.cpp:438] Reading position from leveldb took 9283ns
I0729 21:49:37.019980 23428 registrar.cpp:346] Successfully fetched the registry (293B)
I0729 21:49:37.020002 23428 registrar.cpp:422] Attempting to update the 'registry'
I0729 21:49:37.021587 23428 log.cpp:680] Attempting to append 332 bytes to the log
I0729 21:49:37.021628 23428 coordinator.cpp:340] Coordinator attempting to write APPEND action
at position 5
I0729 21:49:37.021858 23428 replica.cpp:508] Replica received write request for position 5
I0729 21:49:37.035399 23428 leveldb.cpp:343] Persisting action (351 bytes) to leveldb took
13.524949ms
I0729 21:49:37.035420 23428 replica.cpp:676] Persisted action at 5
I0729 21:49:37.035612 23428 replica.cpp:655] Replica received learned notice for position
5
I0729 21:49:37.057674 23428 leveldb.cpp:343] Persisting action (353 bytes) to leveldb took
22.046755ms
I0729 21:49:37.057701 23428 replica.cpp:676] Persisted action at 5
I0729 21:49:37.057710 23428 replica.cpp:661] Replica learned APPEND action at position 5
I0729 21:49:37.058027 23428 registrar.cpp:479] Successfully updated 'registry'
I0729 21:49:37.058078 23428 registrar.cpp:372] Successfully recovered registrar
I0729 21:49:37.058143 23428 log.cpp:699] Attempting to truncate the log to 5
I0729 21:49:37.058238 23428 master.cpp:987] Recovered 1 slaves from the Registry (293B) ;
allowing 10mins for slaves to re-register
I0729 21:49:37.058277 23428 coordinator.cpp:340] Coordinator attempting to write TRUNCATE
action at position 6
I0729 21:49:37.058511 23428 replica.cpp:508] Replica received write request for position 6
I0729 21:49:37.071751 23428 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took
13.22495ms
I0729 21:49:37.071775 23428 replica.cpp:676] Persisted action at 6
I0729 21:49:37.071974 23428 replica.cpp:655] Replica received learned notice for position
6
I0729 21:49:37.083822 23428 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took
11.833875ms
I0729 21:49:37.083863 23428 leveldb.cpp:401] Deleting ~2 keys from leveldb took 18355ns
I0729 21:49:37.083873 23428 replica.cpp:676] Persisted action at 6
I0729 21:49:37.083881 23428 replica.cpp:661] Replica learned TRUNCATE action at position 6
I0729 21:49:37.099376 23428 slave.cpp:601] New master detected at master@140.211.11.27:60822
I0729 21:49:37.099405 23428 slave.cpp:677] Authenticating with master master@140.211.11.27:60822
I0729 21:49:37.099448 23428 slave.cpp:650] Detecting new master
I0729 21:49:37.099486 23428 status_update_manager.cpp:167] New master detected at master@140.211.11.27:60822
I0729 21:49:37.099519 23428 authenticatee.hpp:128] Creating new client SASL connection
I0729 21:49:37.099643 23428 master.cpp:3504] Authenticating slave(195)@140.211.11.27:60822
I0729 21:49:37.099715 23428 authenticator.hpp:156] Creating new server SASL connection
I0729 21:49:37.099798 23428 authenticatee.hpp:219] Received SASL authentication mechanisms:
CRAM-MD5
I0729 21:49:37.099812 23428 authenticatee.hpp:245] Attempting to authenticate with mechanism
'CRAM-MD5'
I0729 21:49:37.099835 23428 authenticator.hpp:262] Received SASL authentication start
I0729 21:49:37.099869 23428 authenticator.hpp:384] Authentication requires more steps
I0729 21:49:37.099892 23428 authenticatee.hpp:265] Received SASL authentication step
I0729 21:49:37.099921 23428 authenticator.hpp:290] Received SASL authentication step
I0729 21:49:37.099935 23428 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0729 21:49:37.099941 23428 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0729 21:49:37.099951 23428 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0729 21:49:37.099958 23428 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0729 21:49:37.099964 23428 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since
SASL_AUXPROP_AUTHZID == true
I0729 21:49:37.099969 23428 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
I0729 21:49:37.099978 23428 authenticator.hpp:376] Authentication success
I0729 21:49:37.100002 23428 authenticatee.hpp:305] Authentication success
I0729 21:49:37.100021 23428 master.cpp:3544] Successfully authenticated principal 'test-principal'
at slave(195)@140.211.11.27:60822
I0729 21:49:37.100080 23428 slave.cpp:734] Successfully authenticated with master master@140.211.11.27:60822
I0729 21:49:37.100152 23428 slave.cpp:972] Will retry registration in 11.433797ms if necessary
I0729 21:49:37.100222 23428 master.cpp:2937] Re-registering slave 20140729-214936-453759884-60822-23165-0
at slave(195)@140.211.11.27:60822 (hemera.apache.org)
I0729 21:49:37.100366 23428 registrar.cpp:422] Attempting to update the 'registry'
I0729 21:49:37.101912 23428 log.cpp:680] Attempting to append 332 bytes to the log
I0729 21:49:37.101955 23428 coordinator.cpp:340] Coordinator attempting to write APPEND action
at position 7
I0729 21:49:37.102157 23428 replica.cpp:508] Replica received write request for position 7
I0729 21:49:37.112546 23427 slave.cpp:972] Will retry registration in 2.150201ms if necessary
I0729 21:49:37.112622 23427 master.cpp:2930] Ignoring re-register slave message from slave
20140729-214936-453759884-60822-23165-0 at slave(195)@140.211.11.27:60822 (hemera.apache.org)
as readmission is already in progress
I0729 21:49:37.114987 23427 slave.cpp:972] Will retry registration in 70.279157ms if necessary
I0729 21:49:37.115057 23427 master.cpp:2930] Ignoring re-register slave message from slave
20140729-214936-453759884-60822-23165-0 at slave(195)@140.211.11.27:60822 (hemera.apache.org)
as readmission is already in progress
I0729 21:49:37.115897 23428 leveldb.cpp:343] Persisting action (351 bytes) to leveldb took
13.724569ms
I0729 21:49:37.115918 23428 replica.cpp:676] Persisted action at 7
I0729 21:49:37.116106 23428 replica.cpp:655] Replica received learned notice for position
7
I0729 21:49:37.127997 23428 leveldb.cpp:343] Persisting action (353 bytes) to leveldb took
11.877137ms
I0729 21:49:37.128021 23428 replica.cpp:676] Persisted action at 7
I0729 21:49:37.128028 23428 replica.cpp:661] Replica learned APPEND action at position 7
I0729 21:49:37.128324 23428 registrar.cpp:479] Successfully updated 'registry'
I0729 21:49:37.128427 23428 log.cpp:699] Attempting to truncate the log to 7
I0729 21:49:37.128480 23428 master.cpp:2988] Re-registered slave 20140729-214936-453759884-60822-23165-0
at slave(195)@140.211.11.27:60822 (hemera.apache.org)
I0729 21:49:37.128492 23428 master.cpp:3972] Adding slave 20140729-214936-453759884-60822-23165-0
at slave(195)@140.211.11.27:60822 (hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):127026;
ports(*):[31000-32000]
I0729 21:49:37.128566 23428 master.hpp:788] Adding task 0 with resources cpus(*):1; mem(*):500
on slave 20140729-214936-453759884-60822-23165-0 (hemera.apache.org)
W0729 21:49:37.128590 23428 master.cpp:4063] Possibly orphaned task 0 of framework 20140729-214936-453759884-60822-23165-0000
running on slave 20140729-214936-453759884-60822-23165-0 at slave(195)@140.211.11.27:60822
(hemera.apache.org)
I0729 21:49:37.128672 23428 coordinator.cpp:340] Coordinator attempting to write TRUNCATE
action at position 8
I0729 21:49:37.128734 23428 slave.cpp:818] Re-registered with master master@140.211.11.27:60822
I0729 21:49:37.128855 23428 slave.cpp:2325] Received ping from slave-observer(164)@140.211.11.27:60822
I0729 21:49:37.128926 23428 hierarchical_allocator_process.hpp:444] Added slave 20140729-214936-453759884-60822-23165-0
(hemera.apache.org) with cpus(*):2; mem(*):1024; disk(*):127026; ports(*):[31000-32000] (and
cpus(*):1; mem(*):524; disk(*):127026; ports(*):[31000-32000] available)
I0729 21:49:37.128962 23428 hierarchical_allocator_process.hpp:706] Performed allocation for
slave 20140729-214936-453759884-60822-23165-0 in 8130ns
I0729 21:49:37.129138 23428 replica.cpp:508] Replica received write request for position 8
I0729 21:49:37.131124 23436 sched.cpp:229] Scheduler::disconnected took 8056ns
I0729 21:49:37.131137 23436 sched.cpp:235] New master detected at master@140.211.11.27:60822
I0729 21:49:37.131150 23436 sched.cpp:285] Authenticating with master master@140.211.11.27:60822
I0729 21:49:37.131228 23436 authenticatee.hpp:128] Creating new client SASL connection
I0729 21:49:37.131343 23436 master.cpp:3504] Authenticating scheduler-94956444-fee9-4b8a-af85-f9945690ee07@140.211.11.27:60822
I0729 21:49:37.131417 23436 authenticator.hpp:156] Creating new server SASL connection
I0729 21:49:37.131492 23436 authenticatee.hpp:219] Received SASL authentication mechanisms:
CRAM-MD5
I0729 21:49:37.131506 23436 authenticatee.hpp:245] Attempting to authenticate with mechanism
'CRAM-MD5'
I0729 21:49:37.131527 23436 authenticator.hpp:262] Received SASL authentication start
I0729 21:49:37.131557 23436 authenticator.hpp:384] Authentication requires more steps
I0729 21:49:37.131580 23436 authenticatee.hpp:265] Received SASL authentication step
I0729 21:49:37.131609 23436 authenticator.hpp:290] Received SASL authentication step
I0729 21:49:37.131620 23436 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0729 21:49:37.131628 23436 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I0729 21:49:37.131635 23436 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0729 21:49:37.131644 23436 auxprop.cpp:81] Request to lookup properties for user: 'test-principal'
realm: 'hemera.apache.org' server FQDN: 'hemera.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0729 21:49:37.131649 23436 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since
SASL_AUXPROP_AUTHZID == true
I0729 21:49:37.131654 23436 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
I0729 21:49:37.131664 23436 authenticator.hpp:376] Authentication success
I0729 21:49:37.131686 23436 authenticatee.hpp:305] Authentication success
I0729 21:49:37.131705 23436 master.cpp:3544] Successfully authenticated principal 'test-principal'
at scheduler-94956444-fee9-4b8a-af85-f9945690ee07@140.211.11.27:60822
I0729 21:49:37.131762 23436 sched.cpp:359] Successfully authenticated with master master@140.211.11.27:60822
I0729 21:49:37.131773 23436 sched.cpp:478] Sending registration request to master@140.211.11.27:60822
I0729 21:49:37.131814 23436 master.cpp:1356] Received re-registration request from framework
20140729-214936-453759884-60822-23165-0000 at scheduler-94956444-fee9-4b8a-af85-f9945690ee07@140.211.11.27:60822
I0729 21:49:37.131832 23436 master.cpp:1208] Authorizing framework principal 'test-principal'
to receive offers for role '*'
I0729 21:49:37.131916 23436 master.cpp:1407] Re-registering framework 20140729-214936-453759884-60822-23165-0000
at scheduler-94956444-fee9-4b8a-af85-f9945690ee07@140.211.11.27:60822
I0729 21:49:37.132053 23436 sched.cpp:409] Framework registered with 20140729-214936-453759884-60822-23165-0000
I0729 21:49:37.132072 23436 sched.cpp:423] Scheduler::registered took 8566ns
I0729 21:49:37.132170 23436 slave.cpp:1584] Updating framework 20140729-214936-453759884-60822-23165-0000
pid to scheduler-94956444-fee9-4b8a-af85-f9945690ee07@140.211.11.27:60822
I0729 21:49:37.132230 23436 hierarchical_allocator_process.hpp:331] Added framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:37.132266 23436 hierarchical_allocator_process.hpp:750] Offering cpus(*):1; mem(*):524;
disk(*):127026; ports(*):[31000-32000] on slave 20140729-214936-453759884-60822-23165-0 to
framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:37.132380 23436 hierarchical_allocator_process.hpp:686] Performed allocation for
1 slaves in 137410ns
I0729 21:49:37.132441 23436 master.hpp:816] Adding offer 20140729-214936-453759884-60822-23165-0
with resources cpus(*):1; mem(*):524; disk(*):127026; ports(*):[31000-32000] on slave 20140729-214936-453759884-60822-23165-0
(hemera.apache.org)
I0729 21:49:37.132484 23436 master.cpp:3451] Sending 1 offers to framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:37.132576 23436 sched.cpp:546] Scheduler::resourceOffers took 18628ns
I0729 21:49:37.133805 23165 master.cpp:626] Master terminating
I0729 21:49:37.133855 23165 master.hpp:806] Removing task 0 with resources cpus(*):1; mem(*):500
on slave 20140729-214936-453759884-60822-23165-0 (hemera.apache.org)
W0729 21:49:37.133896 23165 master.cpp:4261] Removing task 0 of framework 20140729-214936-453759884-60822-23165-0000
and slave 20140729-214936-453759884-60822-23165-0 in non-terminal state TASK_RUNNING
I0729 21:49:37.133930 23165 master.hpp:826] Removing offer 20140729-214936-453759884-60822-23165-0
with resources cpus(*):1; mem(*):524; disk(*):127026; ports(*):[31000-32000] on slave 20140729-214936-453759884-60822-23165-0
(hemera.apache.org)
I0729 21:49:37.137677 23436 sched.cpp:747] Stopping framework '20140729-214936-453759884-60822-23165-0000'
I0729 21:49:37.137723 23436 slave.cpp:2332] master@140.211.11.27:60822 exited
W0729 21:49:37.137733 23436 slave.cpp:2335] Master disconnected! Waiting for a new master
to be elected
I0729 21:49:37.144139 23428 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took
14.921098ms
I0729 21:49:37.144162 23428 replica.cpp:676] Persisted action at 8
I0729 21:49:37.162089 23165 slave.cpp:485] Slave terminating
I0729 21:49:37.162175 23165 slave.cpp:1407] Asked to shut down framework 20140729-214936-453759884-60822-23165-0000
by @0.0.0.0:0
I0729 21:49:37.162240 23165 slave.cpp:1432] Shutting down framework 20140729-214936-453759884-60822-23165-0000
I0729 21:49:37.162299 23165 slave.cpp:2808] Shutting down executor 'default' of framework
20140729-214936-453759884-60822-23165-0000
[       OK ] AllocatorTest/0.SlaveReregistersFirst (585 ms)
[----------] 12 tests from AllocatorTest/0 (5748 ms total)

[----------] Global test environment tear-down
[==========] 351 tests from 57 test cases ran. (249674 ms total)
[  PASSED  ] 350 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] SlaveRecoveryTest/0.SchedulerFailover, where TypeParam = mesos::internal::slave::MesosContainerizer

 1 FAILED TEST
  YOU HAVE 3 DISABLED TESTS

make[3]: *** [check-local] Error 1
make[3]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make[1]: *** [check] Error 2
make[1]: Leaving directory `/x1/jenkins/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/build/src'
make: *** [check-recursive] Error 1
Build step 'Execute shell' marked build as failure

Mime
View raw message