+tim, nik Looks like the health check test is still flaky, can you take a look? :)
On Sun, Dec 14, 2014 at 12:56 PM, Apache Jenkins Server < [email protected]> wrote: > > 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 > [email protected]: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 > [email protected]: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 > [email protected]: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 > [email protected]: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 > [email protected]: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 [email protected]: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 [email protected]: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 > [email protected]: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 > [email protected]: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 > [email protected]: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 > [email protected]: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 > [email protected]: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] [email protected]: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 >
