This is fixed now: https://github.com/apache/mesos/commit/8c4f45d67be22cfe252ad6ed27a79ad4a1f972c6
-- Jiang Yan Xu <[email protected]> @xujyan <http://twitter.com/xujyan> On Thu, Aug 7, 2014 at 3:42 AM, Apache Jenkins Server < [email protected]> wrote: > See <https://builds.apache.org/job/Mesos-Ubuntu-distcheck/256/changes> > > Changes: > > [yan] Improved framework rate limiting by imposing the max number of > outstanding messages per framework principal. > > ------------------------------------------ > [...truncated 42275 lines...] > I0807 10:41:07.131455 13721 log.cpp:680] Attempting to append 139 bytes > to the log > I0807 10:41:07.131508 13721 coordinator.cpp:340] Coordinator attempting to > write APPEND action at position 1 > I0807 10:41:07.131765 13721 replica.cpp:508] Replica received write > request for position 1 > I0807 10:41:07.136440 13721 leveldb.cpp:343] Persisting action (158 > bytes) to leveldb took 4.654646ms > I0807 10:41:07.136468 13721 replica.cpp:676] Persisted action at 1 > I0807 10:41:07.140547 13721 replica.cpp:655] Replica received learned > notice for position 1 > I0807 10:41:07.144439 13721 leveldb.cpp:343] Persisting action (160 bytes) > to leveldb took 3.871337ms > I0807 10:41:07.144465 13721 replica.cpp:676] Persisted action at 1 > I0807 10:41:07.144479 13721 replica.cpp:661] Replica learned APPEND action > at position 1 > I0807 10:41:07.144779 13721 registrar.cpp:479] Successfully updated > 'registry' > I0807 10:41:07.144825 13721 registrar.cpp:372] Successfully recovered > registrar > I0807 10:41:07.144876 13721 log.cpp:699] Attempting to truncate the log to > 1 > I0807 10:41:07.144959 13721 master.cpp:1044] Recovered 0 slaves from the > Registry (101B) ; allowing 10mins for slaves to re-register > I0807 10:41:07.145009 13721 coordinator.cpp:340] Coordinator attempting to > write TRUNCATE action at position 2 > I0807 10:41:07.145287 13721 replica.cpp:508] Replica received write > request for position 2 > I0807 10:41:07.152439 13721 leveldb.cpp:343] Persisting action (16 bytes) > to leveldb took 7.132694ms > I0807 10:41:07.152467 13721 replica.cpp:676] Persisted action at 2 > I0807 10:41:07.160706 13723 replica.cpp:655] Replica received learned > notice for position 2 > I0807 10:41:07.161252 13723 leveldb.cpp:343] Persisting action (18 bytes) > to leveldb took 524024ns > I0807 10:41:07.161283 13723 leveldb.cpp:401] Deleting ~1 keys from > leveldb took 13607ns > I0807 10:41:07.161296 13723 replica.cpp:676] Persisted action at 2 > I0807 10:41:07.161306 13723 replica.cpp:661] Replica learned TRUNCATE > action at position 2 > I0807 10:41:07.173075 13689 containerizer.cpp:124] Using isolation: > posix/cpu,posix/mem > I0807 10:41:07.175858 13718 slave.cpp:167] Slave started on 128)@ > 67.195.81.187:52767 > I0807 10:41:07.175883 13718 credentials.hpp:84] Loading credential for > authentication from > '/tmp/ResourceOffersTest_TaskUsesMoreResourcesThanOffered_7sF3nY/credential' > I0807 10:41:07.175969 13718 slave.cpp:265] Slave using credential for: > test-principal > I0807 10:41:07.176086 13718 slave.cpp:278] Slave resources: cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] > I0807 10:41:07.176162 13718 slave.cpp:306] Slave hostname: > pomona.apache.org > I0807 10:41:07.176179 13718 slave.cpp:307] Slave checkpoint: false > I0807 10:41:07.176616 13718 state.cpp:33] Recovering state from > '/tmp/ResourceOffersTest_TaskUsesMoreResourcesThanOffered_7sF3nY/meta' > I0807 10:41:07.176722 13718 status_update_manager.cpp:193] Recovering > status update manager > I0807 10:41:07.176794 13718 containerizer.cpp:287] Recovering containerizer > I0807 10:41:07.177069 13718 slave.cpp:3175] Finished recovery > I0807 10:41:07.177332 13718 slave.cpp:589] New master detected at > [email protected]:52767 > I0807 10:41:07.177366 13718 slave.cpp:663] Authenticating with master > [email protected]:52767 > I0807 10:41:07.177417 13718 slave.cpp:636] Detecting new master > I0807 10:41:07.177467 13718 status_update_manager.cpp:167] New master > detected at [email protected]:52767 > I0807 10:41:07.177515 13718 authenticatee.hpp:128] Creating new client > SASL connection > I0807 10:41:07.177620 13718 master.cpp:3605] Authenticating slave(128)@ > 67.195.81.187:52767 > I0807 10:41:07.177719 13718 authenticator.hpp:156] Creating new server > SASL connection > I0807 10:41:07.177793 13718 authenticatee.hpp:219] Received SASL > authentication mechanisms: CRAM-MD5 > I0807 10:41:07.177819 13718 authenticatee.hpp:245] Attempting to > authenticate with mechanism 'CRAM-MD5' > I0807 10:41:07.177858 13718 authenticator.hpp:262] Received SASL > authentication start > I0807 10:41:07.177902 13718 authenticator.hpp:384] Authentication requires > more steps > I0807 10:41:07.177947 13718 authenticatee.hpp:265] Received SASL > authentication step > I0807 10:41:07.178001 13718 authenticator.hpp:290] Received SASL > authentication step > I0807 10:41:07.178026 13718 auxprop.cpp:81] 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 > I0807 10:41:07.178040 13718 auxprop.cpp:153] Looking up auxiliary > property '*userPassword' > I0807 10:41:07.178056 13718 auxprop.cpp:153] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I0807 10:41:07.178071 13718 auxprop.cpp:81] 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 > I0807 10:41:07.178083 13718 auxprop.cpp:103] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I0807 10:41:07.178093 13718 auxprop.cpp:103] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I0807 10:41:07.178112 13718 authenticator.hpp:376] Authentication success > I0807 10:41:07.178148 13718 authenticatee.hpp:305] Authentication success > I0807 10:41:07.178179 13718 master.cpp:3645] Successfully authenticated > principal 'test-principal' at slave(128)@67.195.81.187:52767 > I0807 10:41:07.178256 13718 slave.cpp:720] Successfully authenticated with > master [email protected]:52767 > I0807 10:41:07.178298 13718 slave.cpp:971] Will retry registration in > 12.412974ms if necessary > I0807 10:41:07.178369 13718 master.cpp:2827] Registering slave at > slave(128)@67.195.81.187:52767 (pomona.apache.org) with id > 20140807-104107-3142697795-52767-13689-0 > I0807 10:41:07.178484 13718 registrar.cpp:422] Attempting to update the > 'registry' > I0807 10:41:07.180132 13689 sched.cpp:139] Version: 0.20.0 > I0807 10:41:07.180609 13717 sched.cpp:235] New master detected at > [email protected]:52767 > I0807 10:41:07.180613 13715 log.cpp:680] Attempting to append 334 bytes to > the log > I0807 10:41:07.180639 13717 sched.cpp:285] Authenticating with master > [email protected]:52767 > I0807 10:41:07.180681 13715 coordinator.cpp:340] Coordinator attempting > to write APPEND action at position 3 > I0807 10:41:07.180729 13717 authenticatee.hpp:128] Creating new client > SASL connection > I0807 10:41:07.180811 13715 master.cpp:3605] Authenticating > [email protected]:52767 > I0807 10:41:07.180948 13715 replica.cpp:508] Replica received write > request for position 3 > I0807 10:41:07.180977 13717 authenticator.hpp:156] Creating new server > SASL connection > I0807 10:41:07.181042 13717 authenticatee.hpp:219] Received SASL > authentication mechanisms: CRAM-MD5 > I0807 10:41:07.181062 13717 authenticatee.hpp:245] Attempting to > authenticate with mechanism 'CRAM-MD5' > I0807 10:41:07.181098 13717 authenticator.hpp:262] Received SASL > authentication start > I0807 10:41:07.181136 13717 authenticator.hpp:384] Authentication requires > more steps > I0807 10:41:07.181174 13717 authenticatee.hpp:265] Received SASL > authentication step > I0807 10:41:07.181217 13717 authenticator.hpp:290] Received SASL > authentication step > I0807 10:41:07.181238 13717 auxprop.cpp:81] 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 > I0807 10:41:07.181251 13717 auxprop.cpp:153] Looking up auxiliary > property '*userPassword' > I0807 10:41:07.181264 13717 auxprop.cpp:153] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I0807 10:41:07.181280 13717 auxprop.cpp:81] 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 > I0807 10:41:07.181293 13717 auxprop.cpp:103] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I0807 10:41:07.181303 13717 auxprop.cpp:103] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I0807 10:41:07.181319 13717 authenticator.hpp:376] Authentication success > I0807 10:41:07.181355 13717 authenticatee.hpp:305] Authentication success > I0807 10:41:07.181385 13717 master.cpp:3645] Successfully authenticated > principal 'test-principal' at > [email protected]:52767 > I0807 10:41:07.181465 13717 sched.cpp:359] Successfully authenticated > with master [email protected]:52767 > I0807 10:41:07.181484 13717 sched.cpp:478] Sending registration request > to [email protected]:52767 > I0807 10:41:07.181536 13717 master.cpp:1305] Received registration > request from > [email protected]:52767 > I0807 10:41:07.181561 13717 master.cpp:1265] Authorizing framework > principal 'test-principal' to receive offers for role '*' > I0807 10:41:07.181681 13717 master.cpp:1364] Registering framework > 20140807-104107-3142697795-52767-13689-0000 at > [email protected]:52767 > I0807 10:41:07.181782 13717 sched.cpp:409] Framework registered with > 20140807-104107-3142697795-52767-13689-0000 > I0807 10:41:07.181810 13717 sched.cpp:423] Scheduler::registered took > 11983ns > I0807 10:41:07.181854 13717 hierarchical_allocator_process.hpp:326] Added > framework 20140807-104107-3142697795-52767-13689-0000 > I0807 10:41:07.181867 13717 hierarchical_allocator_process.hpp:688] No > resources available to allocate! > I0807 10:41:07.181879 13717 hierarchical_allocator_process.hpp:650] > Performed allocation for 0 slaves in 11034ns > I0807 10:41:07.184449 13715 leveldb.cpp:343] Persisting action (353 bytes) > to leveldb took 3.479426ms > I0807 10:41:07.184478 13715 replica.cpp:676] Persisted action at 3 > I0807 10:41:07.184717 13715 replica.cpp:655] Replica received learned > notice for position 3 > I0807 10:41:07.185027 13715 leveldb.cpp:343] Persisting action (355 bytes) > to leveldb took 285503ns > I0807 10:41:07.185051 13715 replica.cpp:676] Persisted action at 3 > I0807 10:41:07.185062 13715 replica.cpp:661] Replica learned APPEND action > at position 3 > I0807 10:41:07.185508 13716 registrar.cpp:479] Successfully updated > 'registry' > I0807 10:41:07.185528 13719 log.cpp:699] Attempting to truncate the log to > 3 > I0807 10:41:07.185593 13719 coordinator.cpp:340] Coordinator attempting to > write TRUNCATE action at position 4 > I0807 10:41:07.185737 13716 master.cpp:2867] Registered slave > 20140807-104107-3142697795-52767-13689-0 at slave(128)@67.195.81.187:52767 > (pomona.apache.org) > I0807 10:41:07.185760 13716 master.cpp:4078] Adding slave > 20140807-104107-3142697795-52767-13689-0 at slave(128)@67.195.81.187:52767 > (pomona.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; > ports(*):[31000-32000] > I0807 10:41:07.185889 13716 slave.cpp:754] Registered with master > [email protected]:52767; given slave ID > 20140807-104107-3142697795-52767-13689-0 > I0807 10:41:07.185967 13723 slave.cpp:2324] Received ping from > slave-observer(123)@67.195.81.187:52767 > I0807 10:41:07.185989 13716 hierarchical_allocator_process.hpp:439] Added > slave 20140807-104107-3142697795-52767-13689-0 (pomona.apache.org) with > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) > I0807 10:41:07.186059 13716 hierarchical_allocator_process.hpp:714] > Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on > slave 20140807-104107-3142697795-52767-13689-0 to framework > 20140807-104107-3142697795-52767-13689-0000 > I0807 10:41:07.186142 13719 replica.cpp:508] Replica received write > request for position 4 > I0807 10:41:07.186195 13716 hierarchical_allocator_process.hpp:670] > Performed allocation for slave 20140807-104107-3142697795-52767-13689-0 in > 160885ns > I0807 10:41:07.186265 13723 master.hpp:847] Adding offer > 20140807-104107-3142697795-52767-13689-0 with resources cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 20140807-104107-3142697795-52767-13689-0 (pomona.apache.org) > I0807 10:41:07.186333 13723 master.cpp:3552] Sending 1 offers to framework > 20140807-104107-3142697795-52767-13689-0000 > I0807 10:41:07.186483 13720 sched.cpp:546] Scheduler::resourceOffers took > 33812ns > I0807 10:41:07.186905 13720 master.hpp:857] Removing offer > 20140807-104107-3142697795-52767-13689-0 with resources cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 20140807-104107-3142697795-52767-13689-0 (pomona.apache.org) > I0807 10:41:07.186982 13720 master.cpp:2189] Processing reply for offers: > [ 20140807-104107-3142697795-52767-13689-0 ] on slave > 20140807-104107-3142697795-52767-13689-0 at slave(128)@67.195.81.187:52767 > (pomona.apache.org) for framework > 20140807-104107-3142697795-52767-13689-0000 > I0807 10:41:07.188462 13719 leveldb.cpp:343] Persisting action (16 bytes) > to leveldb took 2.300009ms > I0807 10:41:07.188484 13719 replica.cpp:676] Persisted action at 4 > I0807 10:41:07.188711 13714 replica.cpp:655] Replica received learned > notice for position 4 > I0807 10:41:07.188726 13720 master.cpp:3191] Sending status update > TASK_LOST (UUID: 13bb508a-9ae7-4901-9d7d-0d5b3ade25af) for task 1 of > framework 20140807-104107-3142697795-52767-13689-0000 'Task 1 attempted to > use cpus(*):2.01 which is greater than offered cpus(*):2; mem(*):1024; > disk(*):1024; ports(*):[31000-32000]' > I0807 10:41:07.188853 13719 sched.cpp:637] Scheduler::statusUpdate took > 20890ns > I0807 10:41:07.188915 13720 hierarchical_allocator_process.hpp:560] > Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] > (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; > ports(*):[31000-32000]) on slave 20140807-104107-3142697795-52767-13689-0 > from framework 20140807-104107-3142697795-52767-13689-0000 > I0807 10:41:07.188954 13720 hierarchical_allocator_process.hpp:591] > Framework 20140807-104107-3142697795-52767-13689-0000 filtered slave > 20140807-104107-3142697795-52767-13689-0 for 5secs > I0807 10:41:07.188961 13689 master.cpp:634] Master terminating > I0807 10:41:07.189009 13720 sched.cpp:747] Stopping framework > '20140807-104107-3142697795-52767-13689-0000' > I0807 10:41:07.189329 13714 leveldb.cpp:343] Persisting action (18 bytes) > to leveldb took 597369ns > I0807 10:41:07.189371 13714 leveldb.cpp:401] Deleting ~2 keys from leveldb > took 21802ns > I0807 10:41:07.189386 13714 replica.cpp:676] Persisted action at 4 > I0807 10:41:07.189398 13714 replica.cpp:661] Replica learned TRUNCATE > action at position 4 > I0807 10:41:07.189470 13714 slave.cpp:2356] [email protected]:52767 > exited > W0807 10:41:07.189487 13714 slave.cpp:2359] Master disconnected! Waiting > for a new master to be elected > I0807 10:41:07.196607 13689 slave.cpp:466] Slave terminating > [ OK ] ResourceOffersTest.TaskUsesMoreResourcesThanOffered (93 ms) > [----------] 8 tests from ResourceOffersTest (773 ms total) > > [----------] 6 tests from RateLimitingTest > [ RUN ] RateLimitingTest.DifferentPrincipalFrameworks > Using temporary directory > '/tmp/RateLimitingTest_DifferentPrincipalFrameworks_vdFf7x' > I0807 10:41:07.202009 13689 leveldb.cpp:176] Opened db in 3.353578ms > I0807 10:41:07.202390 13689 leveldb.cpp:183] Compacted db in 351984ns > I0807 10:41:07.203969 13689 leveldb.cpp:198] Created db iterator in 3650ns > I0807 10:41:07.204763 13689 leveldb.cpp:204] Seeked to beginning of db in > 857ns > I0807 10:41:07.205504 13689 leveldb.cpp:273] Iterated through 0 keys in > the db in 411ns > I0807 10:41:07.206326 13689 replica.cpp:741] Replica recovered with log > positions 0 -> 0 with 1 holes and 0 unlearned > I0807 10:41:07.208467 13724 master.cpp:286] Master > 20140807-104107-3142697795-52767-13689 (pomona.apache.org) started on > 67.195.81.187:52767 > I0807 10:41:07.208494 13724 master.cpp:325] Master allowing > unauthenticated frameworks to register > I0807 10:41:07.208511 13724 master.cpp:328] Master only allowing > authenticated slaves to register > I0807 10:41:07.208523 13724 credentials.hpp:36] Loading credentials for > authentication from > '/tmp/RateLimitingTest_DifferentPrincipalFrameworks_vdFf7x/credentials' > I0807 10:41:07.208655 13724 master.cpp:357] Authorization enabled > I0807 10:41:07.208734 13724 master.cpp:404] Framework rate limiting enabled > I0807 10:41:07.209189 13724 hierarchical_allocator_process.hpp:296] > Initializing hierarchical allocator process with master : > [email protected]:52767 > I0807 10:41:07.209233 13724 master.cpp:120] No whitelist given. > Advertising offers for all slaves > I0807 10:41:07.208492 13716 recover.cpp:425] Starting replica recovery > I0807 10:41:07.209511 13718 master.cpp:1186] The newly elected leader is > [email protected]:52767 with id 20140807-104107-3142697795-52767-13689 > I0807 10:41:07.209529 13718 master.cpp:1199] Elected as the leading master! > I0807 10:41:07.209542 13718 master.cpp:1017] Recovering from registrar > I0807 10:41:07.209631 13721 registrar.cpp:313] Recovering registrar > I0807 10:41:07.209879 13716 recover.cpp:451] Replica is in EMPTY status > I0807 10:41:07.210263 13723 replica.cpp:638] Replica in EMPTY status > received a broadcasted recover request > I0807 10:41:07.210340 13723 recover.cpp:188] Received a recover response > from a replica in EMPTY status > I0807 10:41:07.210489 13723 recover.cpp:542] Updating replica status to > STARTING > I0807 10:41:07.210952 13723 leveldb.cpp:306] Persisting metadata (8 bytes) > to leveldb took 389182ns > I0807 10:41:07.210973 13723 replica.cpp:320] Persisted replica status to > STARTING > I0807 10:41:07.211060 13723 recover.cpp:451] Replica is in STARTING status > I0807 10:41:07.211453 13723 replica.cpp:638] Replica in STARTING status > received a broadcasted recover request > I0807 10:41:07.211529 13723 recover.cpp:188] Received a recover response > from a replica in STARTING status > I0807 10:41:07.211673 13723 recover.cpp:542] Updating replica status to > VOTING > I0807 10:41:07.211825 13723 leveldb.cpp:306] Persisting metadata (8 bytes) > to leveldb took 85696ns > I0807 10:41:07.211843 13723 replica.cpp:320] Persisted replica status to > VOTING > I0807 10:41:07.211891 13723 recover.cpp:556] Successfully joined the Paxos > group > I0807 10:41:07.211962 13723 recover.cpp:440] Recover process terminated > I0807 10:41:07.212105 13723 log.cpp:656] Attempting to start the writer > I0807 10:41:07.220588 13717 replica.cpp:474] Replica received implicit > promise request with proposal 1 > I0807 10:41:07.228438 13717 leveldb.cpp:306] Persisting metadata (8 bytes) > to leveldb took 7.825833ms > I0807 10:41:07.228466 13717 replica.cpp:342] Persisted promised to 1 > I0807 10:41:07.228656 13717 coordinator.cpp:230] Coordinator attemping to > fill missing position > I0807 10:41:07.228996 13717 replica.cpp:375] Replica received explicit > promise request for position 0 with proposal 2 > I0807 10:41:07.232437 13717 leveldb.cpp:343] Persisting action (8 bytes) > to leveldb took 3.423037ms > I0807 10:41:07.232463 13717 replica.cpp:676] Persisted action at 0 > I0807 10:41:07.233072 13720 replica.cpp:508] Replica received write > request for position 0 > I0807 10:41:07.233105 13720 leveldb.cpp:438] Reading position from leveldb > took 12629ns > I0807 10:41:07.240464 13720 leveldb.cpp:343] Persisting action (14 bytes) > to leveldb took 7.336621ms > I0807 10:41:07.240489 13720 replica.cpp:676] Persisted action at 0 > I0807 10:41:07.240648 13713 replica.cpp:655] Replica received learned > notice for position 0 > I0807 10:41:07.240946 13713 leveldb.cpp:343] Persisting action (16 bytes) > to leveldb took 268837ns > I0807 10:41:07.240969 13713 replica.cpp:676] Persisted action at 0 > I0807 10:41:07.240979 13713 replica.cpp:661] Replica learned NOP action at > position 0 > I0807 10:41:07.241186 13713 log.cpp:672] Writer started with ending > position 0 > I0807 10:41:07.241446 13713 leveldb.cpp:438] Reading position from leveldb > took 10122ns > I0807 10:41:07.243196 13713 registrar.cpp:346] Successfully fetched the > registry (0B) > I0807 10:41:07.243218 13713 registrar.cpp:422] Attempting to update the > 'registry' > I0807 10:41:07.245028 13713 log.cpp:680] Attempting to append 139 bytes to > the log > I0807 10:41:07.245074 13713 coordinator.cpp:340] Coordinator attempting to > write APPEND action at position 1 > I0807 10:41:07.245288 13713 replica.cpp:508] Replica received write > request for position 1 > I0807 10:41:07.250848 13713 leveldb.cpp:343] Persisting action (158 bytes) > to leveldb took 5.540237ms > I0807 10:41:07.250871 13713 replica.cpp:676] Persisted action at 1 > I0807 10:41:07.251070 13713 replica.cpp:655] Replica received learned > notice for position 1 > I0807 10:41:07.251319 13713 leveldb.cpp:343] Persisting action (160 bytes) > to leveldb took 230911ns > I0807 10:41:07.251338 13713 replica.cpp:676] Persisted action at 1 > I0807 10:41:07.251348 13713 replica.cpp:661] Replica learned APPEND action > at position 1 > I0807 10:41:07.251610 13713 registrar.cpp:479] Successfully updated > 'registry' > I0807 10:41:07.251649 13713 registrar.cpp:372] Successfully recovered > registrar > I0807 10:41:07.251693 13713 log.cpp:699] Attempting to truncate the log to > 1 > I0807 10:41:07.251761 13713 master.cpp:1044] Recovered 0 slaves from the > Registry (101B) ; allowing 10mins for slaves to re-register > I0807 10:41:07.251801 13713 coordinator.cpp:340] Coordinator attempting to > write TRUNCATE action at position 2 > I0807 10:41:07.252030 13713 replica.cpp:508] Replica received write > request for position 2 > I0807 10:41:07.252159 13713 leveldb.cpp:343] Persisting action (16 bytes) > to leveldb took 110701ns > I0807 10:41:07.252177 13713 replica.cpp:676] Persisted action at 2 > I0807 10:41:07.252445 13721 replica.cpp:655] Replica received learned > notice for position 2 > I0807 10:41:07.252833 13721 leveldb.cpp:343] Persisting action (18 bytes) > to leveldb took 367551ns > I0807 10:41:07.252866 13721 leveldb.cpp:401] Deleting ~1 keys from leveldb > took 13596ns > I0807 10:41:07.252878 13721 replica.cpp:676] Persisted action at 2 > I0807 10:41:07.252889 13721 replica.cpp:661] Replica learned TRUNCATE > action at position 2 > I0807 10:41:07.275961 13689 sched.cpp:139] Version: 0.20.0 > I0807 10:41:07.276098 13721 sched.cpp:235] New master detected at > [email protected]:52767 > I0807 10:41:07.276118 13721 sched.cpp:243] No credentials provided. > Attempting to register without authentication > I0807 10:41:07.276128 13721 sched.cpp:478] Sending registration request to > [email protected]:52767 > I0807 10:41:07.276216 13721 master.cpp:1305] Received registration request > from [email protected]:52767 > I0807 10:41:07.276237 13721 master.cpp:1265] Authorizing framework > principal 'framework1' to receive offers for role '*' > I0807 10:41:07.276365 13721 master.cpp:1364] Registering framework > 20140807-104107-3142697795-52767-13689-0000 at > [email protected]:52767 > I0807 10:41:07.276494 13717 sched.cpp:409] Framework registered with > 20140807-104107-3142697795-52767-13689-0000 > I0807 10:41:07.276520 13717 sched.cpp:423] Scheduler::registered took > 10980ns > I0807 10:41:07.276526 13723 hierarchical_allocator_process.hpp:326] Added > framework 20140807-104107-3142697795-52767-13689-0000 > I0807 10:41:07.276538 13723 hierarchical_allocator_process.hpp:688] No > resources available to allocate! > I0807 10:41:07.276548 13723 hierarchical_allocator_process.hpp:650] > Performed allocation for 0 slaves in 10385ns > I0807 10:41:07.299358 13689 sched.cpp:139] Version: 0.20.0 > I0807 10:41:07.299615 13721 sched.cpp:235] New master detected at > [email protected]:52767 > I0807 10:41:07.299635 13721 sched.cpp:243] No credentials provided. > Attempting to register without authentication > I0807 10:41:07.299644 13721 sched.cpp:478] Sending registration request to > [email protected]:52767 > I0807 10:41:07.299720 13721 master.cpp:1305] Received registration request > from [email protected]:52767 > I0807 10:41:07.299739 13721 master.cpp:1265] Authorizing framework > principal 'framework2' to receive offers for role '*' > I0807 10:41:07.299861 13721 master.cpp:1364] Registering framework > 20140807-104107-3142697795-52767-13689-0001 at > [email protected]:52767 > I0807 10:41:07.299952 13721 sched.cpp:409] Framework registered with > 20140807-104107-3142697795-52767-13689-0001 > I0807 10:41:07.299974 13721 sched.cpp:423] Scheduler::registered took > 9494ns > I0807 10:41:07.300012 13721 hierarchical_allocator_process.hpp:326] Added > framework 20140807-104107-3142697795-52767-13689-0001 > I0807 10:41:07.300024 13721 hierarchical_allocator_process.hpp:688] No > resources available to allocate! > I0807 10:41:07.300032 13721 hierarchical_allocator_process.hpp:650] > Performed allocation for 0 slaves in 9146ns > I0807 10:41:07.319936 13721 master.cpp:1305] Received registration request > from [email protected]:52767 > I0807 10:41:07.319962 13721 master.cpp:1265] Authorizing framework > principal 'framework1' to receive offers for role '*' > lt-mesos-tests: > ../../3rdparty/libprocess/3rdparty/stout/include/stout/option.hpp:104: > const T& Option<T>::get() const [with T = > process::Owned<mesos::internal::master::Master::BoundedRateLimiter>]: > Assertion `state == SOME' failed. > make[4]: *** [check-local] Aborted > make[4]: Leaving directory `< > https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.20.0/_build/src > '> > make[3]: *** [check-am] Error 2 > make[3]: Leaving directory `< > https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.20.0/_build/src > '> > make[2]: *** [check] Error 2 > make[2]: Leaving directory `< > https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.20.0/_build/src > '> > make[1]: *** [check-recursive] Error 1 > make[1]: Leaving directory `< > https://builds.apache.org/job/Mesos-Ubuntu-distcheck/ws/build/mesos-0.20.0/_build > '> > make: *** [distcheck] Error 1 > Build step 'Execute shell' marked build as failure >
