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 #2630
Date Sun, 14 Dec 2014 20:56:52 GMT
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2630/changes>

Changes:

[dave] Adds Branding Brand to Mesos adopters list.

------------------------------------------
[...truncated 66646 lines...]

[----------] 1 test from SchedulerTest
[ RUN      ] SchedulerTest.TaskRunning
Using temporary directory '/tmp/SchedulerTest_TaskRunning_0UuLSy'
I1214 20:56:27.392043 11667 leveldb.cpp:176] Opened db in 2.763678ms
I1214 20:56:27.393041 11667 leveldb.cpp:183] Compacted db in 963138ns
I1214 20:56:27.393090 11667 leveldb.cpp:198] Created db iterator in 19447ns
I1214 20:56:27.393110 11667 leveldb.cpp:204] Seeked to beginning of db in 2017ns
I1214 20:56:27.393120 11667 leveldb.cpp:273] Iterated through 0 keys in the db in 333ns
I1214 20:56:27.393156 11667 replica.cpp:741] Replica recovered with log positions 0 ->
0 with 1 holes and 0 unlearned
I1214 20:56:27.393601 11694 recover.cpp:437] Starting replica recovery
I1214 20:56:27.393851 11694 recover.cpp:463] Replica is in EMPTY status
I1214 20:56:27.395179 11693 replica.cpp:638] Replica in EMPTY status received a broadcasted
recover request
I1214 20:56:27.395802 11695 recover.cpp:188] Received a recover response from a replica in
EMPTY status
I1214 20:56:27.396311 11690 recover.cpp:554] Updating replica status to STARTING
I1214 20:56:27.397222 11689 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took
605610ns
I1214 20:56:27.397255 11689 replica.cpp:320] Persisted replica status to STARTING
I1214 20:56:27.397588 11686 recover.cpp:463] Replica is in STARTING status
I1214 20:56:27.398885 11696 replica.cpp:638] Replica in STARTING status received a broadcasted
recover request
I1214 20:56:27.399435 11695 recover.cpp:188] Received a recover response from a replica in
STARTING status
I1214 20:56:27.400051 11692 recover.cpp:554] Updating replica status to VOTING
I1214 20:56:27.400722 11684 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took
372808ns
I1214 20:56:27.400748 11684 replica.cpp:320] Persisted replica status to VOTING
I1214 20:56:27.400833 11689 recover.cpp:568] Successfully joined the Paxos group
I1214 20:56:27.409098 11695 master.cpp:258] Master 20141214-205627-3142697795-57086-11667
(pomona.apache.org) started on 67.195.81.187:57086
I1214 20:56:27.515343 11695 master.cpp:304] Master only allowing authenticated frameworks
to register
I1214 20:56:27.515364 11695 master.cpp:309] Master only allowing authenticated slaves to register
I1214 20:56:27.515390 11695 credentials.hpp:36] Loading credentials for authentication from
'/tmp/SchedulerTest_TaskRunning_0UuLSy/credentials'
I1214 20:56:27.515445 11689 recover.cpp:452] Recover process terminated
I1214 20:56:27.515666 11695 master.cpp:353] Authorization enabled
I1214 20:56:27.516333 11685 whitelist_watcher.cpp:61] No whitelist given
I1214 20:56:27.516384 11689 hierarchical_allocator_process.hpp:280] Initialized hierarchical
allocator process
I1214 20:56:27.516517 11689 hierarchical_allocator_process.hpp:527] Advertising offers for
all slaves
I1214 20:56:27.517618 11693 master.cpp:1213] The newly elected leader is master@67.195.81.187:57086
with id 20141214-205627-3142697795-57086-11667
I1214 20:56:27.517652 11693 master.cpp:1226] Elected as the leading master!
I1214 20:56:27.517669 11693 master.cpp:1044] Recovering from registrar
I1214 20:56:27.517856 11690 registrar.cpp:313] Recovering registrar
I1214 20:56:27.518504 11693 log.cpp:656] Attempting to start the writer
I1214 20:56:27.520063 11681 replica.cpp:474] Replica received implicit promise request with
proposal 1
I1214 20:56:27.520660 11681 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took
562289ns
I1214 20:56:27.520678 11681 replica.cpp:342] Persisted promised to 1
I1214 20:56:27.521118 11681 coordinator.cpp:230] Coordinator attemping to fill missing position
I1214 20:56:27.522521 11696 replica.cpp:375] Replica received explicit promise request for
position 0 with proposal 2
I1214 20:56:27.523118 11696 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 556655ns
I1214 20:56:27.523145 11696 replica.cpp:676] Persisted action at 0
I1214 20:56:27.524786 11688 replica.cpp:508] Replica received write request for position 0
I1214 20:56:27.524847 11688 leveldb.cpp:438] Reading position from leveldb took 31799ns
I1214 20:56:27.525352 11688 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took
470745ns
I1214 20:56:27.525377 11688 replica.cpp:676] Persisted action at 0
I1214 20:56:27.525954 11681 replica.cpp:655] Replica received learned notice for position
0
I1214 20:56:27.526526 11681 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took
549029ns
I1214 20:56:27.526548 11681 replica.cpp:676] Persisted action at 0
I1214 20:56:27.526568 11681 replica.cpp:661] Replica learned NOP action at position 0
I1214 20:56:27.527350 11688 log.cpp:672] Writer started with ending position 0
I1214 20:56:27.528616 11695 leveldb.cpp:438] Reading position from leveldb took 24309ns
I1214 20:56:27.530694 11694 registrar.cpp:346] Successfully fetched the registry (0B) in 12.784896ms
I1214 20:56:27.530822 11694 registrar.cpp:445] Applied 1 operations in 27636ns; attempting
to update the 'registry'
I1214 20:56:27.533664 11682 log.cpp:680] Attempting to append 139 bytes to the log
I1214 20:56:27.533810 11690 coordinator.cpp:340] Coordinator attempting to write APPEND action
at position 1
I1214 20:56:27.534579 11694 replica.cpp:508] Replica received write request for position 1
I1214 20:56:27.535003 11694 leveldb.cpp:343] Persisting action (158 bytes) to leveldb took
390753ns
I1214 20:56:27.535029 11694 replica.cpp:676] Persisted action at 1
I1214 20:56:27.535671 11683 replica.cpp:655] Replica received learned notice for position
1
I1214 20:56:27.536224 11683 leveldb.cpp:343] Persisting action (160 bytes) to leveldb took
521277ns
I1214 20:56:27.536253 11683 replica.cpp:676] Persisted action at 1
I1214 20:56:27.536303 11683 replica.cpp:661] Replica learned APPEND action at position 1
I1214 20:56:27.536975 11689 registrar.cpp:490] Successfully updated the 'registry' in 6.095872ms
I1214 20:56:27.537116 11689 registrar.cpp:376] Successfully recovered registrar
I1214 20:56:27.537211 11685 log.cpp:699] Attempting to truncate the log to 1
I1214 20:56:27.537384 11688 coordinator.cpp:340] Coordinator attempting to write TRUNCATE
action at position 2
I1214 20:56:27.537408 11693 master.cpp:1071] Recovered 0 slaves from the Registry (101B) ;
allowing 10mins for slaves to re-register
I1214 20:56:27.538265 11695 replica.cpp:508] Replica received write request for position 2
I1214 20:56:27.538646 11695 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took
342709ns
I1214 20:56:27.538666 11695 replica.cpp:676] Persisted action at 2
I1214 20:56:27.539341 11689 replica.cpp:655] Replica received learned notice for position
2
I1214 20:56:27.539798 11689 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took
433843ns
I1214 20:56:27.539839 11689 leveldb.cpp:401] Deleting ~1 keys from leveldb took 23311ns
I1214 20:56:27.539852 11689 replica.cpp:676] Persisted action at 2
I1214 20:56:27.539867 11689 replica.cpp:661] Replica learned TRUNCATE action at position 2
I1214 20:56:27.556141 11686 slave.cpp:170] Slave started on 217)@67.195.81.187:57086
I1214 20:56:27.556180 11686 credentials.hpp:84] Loading credential for authentication from
'/tmp/SchedulerTest_TaskRunning_hLuzvx/credential'
I1214 20:56:27.556391 11686 slave.cpp:279] Slave using credential for: test-principal
I1214 20:56:27.556648 11686 slave.cpp:297] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000]
I1214 20:56:27.556761 11686 slave.cpp:326] Slave hostname: pomona.apache.org
I1214 20:56:27.556779 11686 slave.cpp:327] Slave checkpoint: false
W1214 20:56:27.556789 11686 slave.cpp:329] Disabling checkpointing is deprecated and the --checkpoint
flag will be removed in a future release. Please avoid using this flag
I1214 20:56:27.557198 11667 scheduler.cpp:146] Version: 0.22.0
I1214 20:56:27.557570 11682 state.cpp:33] Recovering state from '/tmp/SchedulerTest_TaskRunning_hLuzvx/meta'
I1214 20:56:27.557864 11685 status_update_manager.cpp:197] Recovering status update manager
I1214 20:56:27.558148 11690 slave.cpp:3485] Finished recovery
I1214 20:56:27.558650 11685 slave.cpp:610] New master detected at master@67.195.81.187:57086
I1214 20:56:27.558677 11695 status_update_manager.cpp:171] Pausing sending status updates
I1214 20:56:27.558756 11685 slave.cpp:673] Authenticating with master master@67.195.81.187:57086
I1214 20:56:27.558779 11685 slave.cpp:678] Using default CRAM-MD5 authenticatee
I1214 20:56:27.558925 11685 slave.cpp:646] Detecting new master
I1214 20:56:27.559078 11686 authenticatee.hpp:138] Creating new client SASL connection
I1214 20:56:27.559273 11685 master.cpp:3920] Authenticating slave(217)@67.195.81.187:57086
I1214 20:56:27.559320 11685 master.cpp:3931] Using default CRAM-MD5 authenticator
I1214 20:56:27.559617 11683 authenticator.hpp:170] Creating new server SASL connection
I1214 20:56:27.559885 11695 authenticatee.hpp:229] Received SASL authentication mechanisms:
CRAM-MD5
I1214 20:56:27.559922 11695 authenticatee.hpp:255] Attempting to authenticate with mechanism
'CRAM-MD5'
I1214 20:56:27.560040 11681 authenticator.hpp:276] Received SASL authentication start
I1214 20:56:27.560088 11694 scheduler.cpp:415] New master detected at master@67.195.81.187:57086
I1214 20:56:27.560104 11681 authenticator.hpp:398] Authentication requires more steps
I1214 20:56:27.560120 11694 scheduler.cpp:464] Authenticating with master master@67.195.81.187:57086
I1214 20:56:27.560227 11691 authenticatee.hpp:275] Received SASL authentication step
I1214 20:56:27.560407 11682 authenticator.hpp:304] Received SASL authentication step
I1214 20:56:27.560442 11682 auxprop.cpp:99] Request to lookup properties for user: 'test-principal'
realm: 'pomona.apache.org' server FQDN: 'pomona.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I1214 20:56:27.560456 11682 auxprop.cpp:171] Looking up auxiliary property '*userPassword'
I1214 20:56:27.560503 11682 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1214 20:56:27.560611 11687 authenticatee.hpp:138] Creating new client SASL connection
I1214 20:56:27.677618 11682 auxprop.cpp:99] Request to lookup properties for user: 'test-principal'
realm: 'pomona.apache.org' server FQDN: 'pomona.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I1214 20:56:27.677642 11682 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since
SASL_AUXPROP_AUTHZID == true
I1214 20:56:27.677650 11682 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
I1214 20:56:27.677673 11682 authenticator.hpp:390] Authentication success
I1214 20:56:27.677825 11684 authenticatee.hpp:315] Authentication success
I1214 20:56:27.677839 11687 master.cpp:3920] Authenticating scheduler(1)@67.195.81.187:57086
I1214 20:56:27.677868 11687 master.cpp:3931] Using default CRAM-MD5 authenticator
I1214 20:56:27.678120 11684 slave.cpp:744] Successfully authenticated with master master@67.195.81.187:57086
I1214 20:56:27.678262 11684 slave.cpp:1072] Will retry registration in 9.672723ms if necessary
I1214 20:56:27.678308 11687 master.cpp:3978] Successfully authenticated principal 'test-principal'
at slave(217)@67.195.81.187:57086
I1214 20:56:27.678490 11682 authenticator.hpp:170] Creating new server SASL connection
I1214 20:56:27.678678 11687 master.cpp:3078] Registering slave at slave(217)@67.195.81.187:57086
(pomona.apache.org) with id 20141214-205627-3142697795-57086-11667-S0
I1214 20:56:27.678701 11694 authenticatee.hpp:229] Received SASL authentication mechanisms:
CRAM-MD5
I1214 20:56:27.678725 11694 authenticatee.hpp:255] Attempting to authenticate with mechanism
'CRAM-MD5'
I1214 20:56:27.678788 11694 authenticator.hpp:276] Received SASL authentication start
I1214 20:56:27.678824 11694 authenticator.hpp:398] Authentication requires more steps
I1214 20:56:27.678915 11693 authenticatee.hpp:275] Received SASL authentication step
I1214 20:56:27.679023 11689 authenticator.hpp:304] Received SASL authentication step
I1214 20:56:27.679049 11689 auxprop.cpp:99] Request to lookup properties for user: 'test-principal'
realm: 'pomona.apache.org' server FQDN: 'pomona.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I1214 20:56:27.679059 11689 auxprop.cpp:171] Looking up auxiliary property '*userPassword'
I1214 20:56:27.679092 11689 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1214 20:56:27.679116 11689 auxprop.cpp:99] Request to lookup properties for user: 'test-principal'
realm: 'pomona.apache.org' server FQDN: 'pomona.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I1214 20:56:27.679126 11689 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since
SASL_AUXPROP_AUTHZID == true
I1214 20:56:27.679131 11689 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5'
since SASL_AUXPROP_AUTHZID == true
I1214 20:56:27.679144 11689 authenticator.hpp:390] Authentication success
I1214 20:56:27.679147 11688 registrar.cpp:445] Applied 1 operations in 87582ns; attempting
to update the 'registry'
I1214 20:56:27.679257 11689 authenticatee.hpp:315] Authentication success
I1214 20:56:27.679296 11692 master.cpp:3978] Successfully authenticated principal 'test-principal'
at scheduler(1)@67.195.81.187:57086
I1214 20:56:27.679663 11687 scheduler.cpp:535] Successfully authenticated with master master@67.195.81.187:57086
I1214 20:56:27.681074 11692 master.cpp:1333] Received registration request for framework 'default'
at scheduler(1)@67.195.81.187:57086
I1214 20:56:27.681149 11692 master.cpp:1292] Authorizing framework principal 'test-principal'
to receive offers for role '*'
I1214 20:56:27.681773 11690 master.cpp:1397] Registering framework 20141214-205627-3142697795-57086-11667-0000
(default) at scheduler(1)@67.195.81.187:57086
I1214 20:56:27.682173 11694 hierarchical_allocator_process.hpp:314] Added framework 20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.682210 11694 hierarchical_allocator_process.hpp:767] No resources available
to allocate!
I1214 20:56:27.682222 11694 hierarchical_allocator_process.hpp:674] Performed allocation for
0 slaves in 21647ns
I1214 20:56:27.682718 11684 log.cpp:680] Attempting to append 316 bytes to the log
I1214 20:56:27.682785 11689 scheduler.cpp:584] Enqueuing event 1 from master@67.195.81.187:57086
I1214 20:56:27.682839 11687 coordinator.cpp:340] Coordinator attempting to write APPEND action
at position 3
I1214 20:56:27.683965 11693 replica.cpp:508] Replica received write request for position 3
I1214 20:56:27.684310 11693 leveldb.cpp:343] Persisting action (335 bytes) to leveldb took
304957ns
I1214 20:56:27.684340 11693 replica.cpp:676] Persisted action at 3
I1214 20:56:27.684962 11688 replica.cpp:655] Replica received learned notice for position
3
I1214 20:56:27.685477 11688 leveldb.cpp:343] Persisting action (337 bytes) to leveldb took
487772ns
I1214 20:56:27.685508 11688 replica.cpp:676] Persisted action at 3
I1214 20:56:27.685534 11688 replica.cpp:661] Replica learned APPEND action at position 3
I1214 20:56:27.686558 11696 registrar.cpp:490] Successfully updated the 'registry' in 7.350016ms
I1214 20:56:27.686732 11692 log.cpp:699] Attempting to truncate the log to 3
I1214 20:56:27.686844 11695 coordinator.cpp:340] Coordinator attempting to write TRUNCATE
action at position 4
I1214 20:56:27.687173 11689 slave.cpp:2556] Received ping from slave-observer(198)@67.195.81.187:57086
I1214 20:56:27.687218 11693 master.cpp:3132] Registered slave 20141214-205627-3142697795-57086-11667-S0
at slave(217)@67.195.81.187:57086 (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000]
I1214 20:56:27.687357 11689 slave.cpp:778] Registered with master master@67.195.81.187:57086;
given slave ID 20141214-205627-3142697795-57086-11667-S0
I1214 20:56:27.687386 11686 hierarchical_allocator_process.hpp:448] Added slave 20141214-205627-3142697795-57086-11667-S0
(pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and
cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
I1214 20:56:27.687531 11681 status_update_manager.cpp:178] Resuming sending status updates
I1214 20:56:27.687615 11696 replica.cpp:508] Replica received write request for position 4
I1214 20:56:27.687806 11686 hierarchical_allocator_process.hpp:692] Performed allocation for
slave 20141214-205627-3142697795-57086-11667-S0 in 368138ns
I1214 20:56:27.687978 11696 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took
330651ns
I1214 20:56:27.688011 11696 replica.cpp:676] Persisted action at 4
I1214 20:56:27.688154 11686 master.cpp:3862] Sending 1 offers to framework 20141214-205627-3142697795-57086-11667-0000
(default) at scheduler(1)@67.195.81.187:57086
I1214 20:56:27.688673 11684 scheduler.cpp:584] Enqueuing event 3 from master@67.195.81.187:57086
I1214 20:56:27.688781 11681 replica.cpp:655] Replica received learned notice for position
4
I1214 20:56:27.689249 11681 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took
413097ns
I1214 20:56:27.689344 11681 leveldb.cpp:401] Deleting ~2 keys from leveldb took 68413ns
I1214 20:56:27.689368 11681 replica.cpp:676] Persisted action at 4
I1214 20:56:27.689395 11681 replica.cpp:661] Replica learned TRUNCATE action at position 4
I1214 20:56:27.691339 11684 master.cpp:2401] Processing reply for offers: [ 20141214-205627-3142697795-57086-11667-O0
] on slave 20141214-205627-3142697795-57086-11667-S0 at slave(217)@67.195.81.187:57086 (pomona.apache.org)
for framework 20141214-205627-3142697795-57086-11667-0000 (default) at scheduler(1)@67.195.81.187:57086
I1214 20:56:27.691376 11684 master.cpp:2507] Authorizing framework principal 'test-principal'
to launch task 1 as user 'jenkins'
W1214 20:56:27.692301 11696 master.cpp:2034] Executor default for task 1 uses less CPUs (None)
than the minimum required (0.01). Please update your executor, as this will be mandatory in
future releases.
W1214 20:56:27.835728 11696 master.cpp:2046] Executor default for task 1 uses less memory
(None) than the minimum required (32MB). Please update your executor, as this will be mandatory
in future releases.
I1214 20:56:27.836158 11696 master.hpp:758] Adding task 1 with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] on slave 20141214-205627-3142697795-57086-11667-S0 (pomona.apache.org)
I1214 20:56:27.836266 11696 master.cpp:2706] Launching task 1 of framework 20141214-205627-3142697795-57086-11667-0000
(default) at scheduler(1)@67.195.81.187:57086 with resources cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000] on slave 20141214-205627-3142697795-57086-11667-S0 at slave(217)@67.195.81.187:57086
(pomona.apache.org)
I1214 20:56:27.836807 11683 slave.cpp:1103] Got assigned task 1 for framework 20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.837564 11683 slave.cpp:1213] Launching task 1 for framework 20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.840258 11683 slave.cpp:3867] Launching executor default of framework 20141214-205627-3142697795-57086-11667-0000
in work directory '/tmp/SchedulerTest_TaskRunning_hLuzvx/slaves/20141214-205627-3142697795-57086-11667-S0/frameworks/20141214-205627-3142697795-57086-11667-0000/executors/default/runs/35d13ad6-716e-4800-a05e-10d12fd934d2'
I1214 20:56:27.843242 11683 exec.cpp:132] Version: 0.22.0
I1214 20:56:27.843632 11692 exec.cpp:182] Executor started at: executor(76)@67.195.81.187:57086
with pid 11667
I1214 20:56:27.843744 11683 slave.cpp:1336] Queuing task '1' for executor default of framework
'20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.843879 11683 slave.cpp:563] Successfully attached file '/tmp/SchedulerTest_TaskRunning_hLuzvx/slaves/20141214-205627-3142697795-57086-11667-S0/frameworks/20141214-205627-3142697795-57086-11667-0000/executors/default/runs/35d13ad6-716e-4800-a05e-10d12fd934d2'
I1214 20:56:27.844007 11683 slave.cpp:2858] Monitoring executor 'default' of framework '20141214-205627-3142697795-57086-11667-0000'
in container '35d13ad6-716e-4800-a05e-10d12fd934d2'
I1214 20:56:27.844187 11683 slave.cpp:1880] Got registration for executor 'default' of framework
20141214-205627-3142697795-57086-11667-0000 from executor(76)@67.195.81.187:57086
I1214 20:56:27.844635 11683 slave.cpp:1999] Flushing queued task 1 for executor 'default'
of framework 20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.844759 11682 exec.cpp:206] Executor registered on slave 20141214-205627-3142697795-57086-11667-S0
I1214 20:56:27.846896 11682 exec.cpp:218] Executor::registered took 26412ns
I1214 20:56:27.847084 11682 exec.cpp:293] Executor asked to run task '1'
I1214 20:56:27.847165 11682 exec.cpp:302] Executor::launchTask took 59819ns
I1214 20:56:27.849412 11682 exec.cpp:525] Executor sending status update TASK_RUNNING (UUID:
b1b5d161-1c8c-46e4-8744-81d3bd434147) for task 1 of framework 20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.849660 11682 slave.cpp:2233] Handling status update TASK_RUNNING (UUID: b1b5d161-1c8c-46e4-8744-81d3bd434147)
for task 1 of framework 20141214-205627-3142697795-57086-11667-0000 from executor(76)@67.195.81.187:57086
I1214 20:56:27.849942 11691 status_update_manager.cpp:317] Received status update TASK_RUNNING
(UUID: b1b5d161-1c8c-46e4-8744-81d3bd434147) for task 1 of framework 20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.849999 11691 status_update_manager.cpp:494] Creating StatusUpdate stream for
task 1 of framework 20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.850219 11691 status_update_manager.cpp:371] Forwarding update TASK_RUNNING
(UUID: b1b5d161-1c8c-46e4-8744-81d3bd434147) for task 1 of framework 20141214-205627-3142697795-57086-11667-0000
to the slave
I1214 20:56:27.850538 11682 slave.cpp:2476] Forwarding the update TASK_RUNNING (UUID: b1b5d161-1c8c-46e4-8744-81d3bd434147)
for task 1 of framework 20141214-205627-3142697795-57086-11667-0000 to master@67.195.81.187:57086
I1214 20:56:27.850862 11682 slave.cpp:2403] Status update manager successfully handled status
update TASK_RUNNING (UUID: b1b5d161-1c8c-46e4-8744-81d3bd434147) for task 1 of framework 20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.850893 11682 slave.cpp:2409] Sending acknowledgement for status update TASK_RUNNING
(UUID: b1b5d161-1c8c-46e4-8744-81d3bd434147) for task 1 of framework 20141214-205627-3142697795-57086-11667-0000
to executor(76)@67.195.81.187:57086
I1214 20:56:27.850957 11688 master.cpp:3455] Forwarding status update TASK_RUNNING (UUID:
b1b5d161-1c8c-46e4-8744-81d3bd434147) for task 1 of framework 20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.851085 11690 exec.cpp:339] Executor received status update acknowledgement
b1b5d161-1c8c-46e4-8744-81d3bd434147 for task 1 of framework 20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.851110 11688 master.cpp:3427] Status update TASK_RUNNING (UUID: b1b5d161-1c8c-46e4-8744-81d3bd434147)
for task 1 of framework 20141214-205627-3142697795-57086-11667-0000 from slave 20141214-205627-3142697795-57086-11667-S0
at slave(217)@67.195.81.187:57086 (pomona.apache.org)
I1214 20:56:27.851167 11688 master.cpp:4725] Updating the latest state of task 1 of framework
20141214-205627-3142697795-57086-11667-0000 to TASK_RUNNING
I1214 20:56:27.851228 11687 scheduler.cpp:584] Enqueuing event 5 from master@67.195.81.187:57086
I1214 20:56:27.852569 11667 master.cpp:648] Master terminating
W1214 20:56:27.852744 11667 master.cpp:4770] Removing task 1 with resources cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] of framework 20141214-205627-3142697795-57086-11667-0000
on slave 20141214-205627-3142697795-57086-11667-S0 at slave(217)@67.195.81.187:57086 (pomona.apache.org)
in non-terminal state TASK_RUNNING
I1214 20:56:27.853072 11695 hierarchical_allocator_process.hpp:581] Recovered cpus(*):2; mem(*):1024;
disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024;
ports(*):[31000-32000]) on slave 20141214-205627-3142697795-57086-11667-S0 from framework
20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.853247 11667 master.cpp:4813] Removing executor 'default' with resources  of
framework 20141214-205627-3142697795-57086-11667-0000 on slave 20141214-205627-3142697795-57086-11667-S0
at slave(217)@67.195.81.187:57086 (pomona.apache.org)
I1214 20:56:27.854033 11696 slave.cpp:2641] master@67.195.81.187:57086 exited
W1214 20:56:27.854066 11696 slave.cpp:2644] Master disconnected! Waiting for a new master
to be elected
I1214 20:56:27.865756 11688 slave.cpp:2916] Executor 'default' of framework 20141214-205627-3142697795-57086-11667-0000
exited with status 0
I1214 20:56:27.867316 11688 slave.cpp:2233] Handling status update TASK_LOST (UUID: df99716d-67aa-4acf-a919-95c1a5e51f3f)
for task 1 of framework 20141214-205627-3142697795-57086-11667-0000 from @0.0.0.0:0
I1214 20:56:27.867383 11688 slave.cpp:4175] Terminating task 1
I1214 20:56:27.867626 11688 slave.cpp:492] Slave terminating
I1214 20:56:27.867702 11688 slave.cpp:1553] Asked to shut down framework 20141214-205627-3142697795-57086-11667-0000
by @0.0.0.0:0
I1214 20:56:27.867720 11688 slave.cpp:1578] Shutting down framework 20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.867782 11688 slave.cpp:3025] Cleaning up executor 'default' of framework 20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.867924 11695 gc.cpp:56] Scheduling '/tmp/SchedulerTest_TaskRunning_hLuzvx/slaves/20141214-205627-3142697795-57086-11667-S0/frameworks/20141214-205627-3142697795-57086-11667-0000/executors/default/runs/35d13ad6-716e-4800-a05e-10d12fd934d2'
for gc 6.99998995548741days in the future
I1214 20:56:27.868001 11688 slave.cpp:3102] Cleaning up framework 20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.868098 11695 gc.cpp:56] Scheduling '/tmp/SchedulerTest_TaskRunning_hLuzvx/slaves/20141214-205627-3142697795-57086-11667-S0/frameworks/20141214-205627-3142697795-57086-11667-0000/executors/default'
for gc 6.99998995423704days in the future
I1214 20:56:27.868113 11684 status_update_manager.cpp:279] Closing status update streams for
framework 20141214-205627-3142697795-57086-11667-0000
I1214 20:56:27.995924 11684 status_update_manager.cpp:525] Cleaning up status update stream
for task 1 of framework 20141214-205627-3142697795-57086-11667-0000
[       OK ] SchedulerTest.TaskRunning (610 ms)
[----------] 1 test from SchedulerTest (610 ms total)

[----------] Global test environment tear-down
[==========] 452 tests from 69 test cases ran. (113108 ms total)
[  PASSED  ] 451 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] HealthCheckTest.GracePeriod

 1 FAILED TEST
  YOU HAVE 4 DISABLED TESTS

make[3]: *** [check-local] Error 1
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make[1]: *** [check] Error 2
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make: *** [check-recursive] Error 1
Test finished
Exit status: 2
Build step 'Execute shell' marked build as failure
Recording test results

Mime
View raw message