Test failing when reading gelf messages

[ph]

This test is currently failing on windows and also fail from time to time on jenkins (last failing run is http://build-eu-1.elasticsearch.org/job/logstash_input_gelf_commit/161/console)

  21) inputs/gelf reads chunked gelf messages  inputs
     Failure/Error: block.call(pipeline, queue)
     Insist::Failure:
       Expected 0 > 0
     # C:\Users\Administrator\logstash\lib\logstash\runner.rb:58:in `run'
     # C:\Users\Administrator\logstash\lib\logstash\runner.rb:113:in `run'
     # C:\Users\Administrator\logstash\lib\logstash\runner.rb:171:in `run'

[ph]

tracking ticket https://github.com/elasticsearch/logstash/issues/2487

[jsvd]

After some investigation, it appears something is very slow during the first of the 4 tests the spec is doing. I added a print statement to check how many wait cycles the spec goes through during each test:

      [ "hello",
        "world",
        large_random,
        "we survived gelf!"
      ].each do |m|
        gelfclient.notify!( "short_message" => m )
        # poll at most 10 times
        waits = 0
        while waits < 5 and queue.size == 0
          puts "[#{m}] wait #{waits}"
          $stdout.flush
          sleep 0.1
          waits += 1
        end

        insist { queue.size } > 0
        insist { queue.pop["message"] } == m

With this debug I see:

% bundle exec rspec
Using Accessor#strict_set for specs
Run options: exclude {:redis=>true, :socket=>true, :performance=>true, :couchdb=>true, :elasticsearch=>true, :elasticsearch_secure=>true, :broken=>true, :export_cypher=>true, :integration=>true, :windows=>true}
[hello] wait 0
[hello] wait 1
[hello] wait 2
[hello] wait 3
[world] wait 0
[7579798989665392723857507167123601178391515011758768064107121965110339764240106351017611512466501173612392411106797894311112512262644712010745603647102518775541235190755597597342971211031006241331053311993606763661251179890121627385864835585839897576713271608011511111079829235658433111763570911176612210511478568353713747999359498711568528272911225741606976578940391253252103654745791218885102581086763117373210034104623459471161131168368367946805363731151025311781425432851108110256346410010458125104411111041119259108586395414197701044538506711875663410612543769938684791105981256367809670656554567148988955888076125363733978290385244649412291527847374388705062579842491061073411070125955842357058375175119409697505879110819058987354107464985994210363729840881221209446971106580813512566102941238940886354123341046061419551561224694795110977768496461227484107109373411948125341067593761227853977981424638645664481046262895071331108262698759110112109431127011440555457110621119233801247810496601237211747821046959727210211212310491766149969132544487101889741944047806039777596117801073312112393493982569343951235651894253118416565896275971239410011891637210112486865312049944982708549628310138486256107831236811749122971068945783249114120441161243887112981241125143741061051121091218193876412381901199611898741001187549819242981239383398655355939927432951181025811751778250537451591247780611144667699763101601146757957711651399159347611597120851118610181116391258861119111847954111676112098897741111984055716170713749668783831234111688561027010512479573657118721228310410580968871401111069591531143292119695545122773397114411006640121105118102741138010578709861974441889495951077110936751109980711041245663865061110401214473748410359963569854337331098311511468676065496711673118787950529610545481009371798410392646348829739344775814874361254739124115811031059111511512189494745106111708479449557100120498971485347423912310169993611610610311580716750486398831099110398122354038865367838511210345795599391108768927484723312211473865343813259921255644364061918161119558982745483396466787192101455571955466431094510473506797821258699507978101113676361718881558312281111661237242855812056978510762785010990125106671009292378040715750108391021228283861033385324811862731065645623494112463850596711497907076605447504962471023412288379460461071081028038971178839674079437239899010842631038187886711212565628581121558952499810711976507052854358123123595611011573106584839496250113341246289122394782112488079554792814070725139118110121829575528491451165761394710488418145475311950351048511510579727193479633616681865640441241181071118510375348970123539949679610362105686010110942123111107797893107635480338588351139733111911001159832365311358423711538703490739739371041045212211510051655040102617611787116698344573312478334210860568811156124404776116773244505544328264101928037878271733811111433339480591091251139656665572666467737312010758568765120477311767111416710611688559736916012312560524581975879881129277375940118573684102846774441221187235999410379717259121795749535312133814371886296517912295795665983575601063936116939558115123978990884573894245101476676112531256448110583589936742928981557684758371956412581598089116103367254984271611108241888733123924260398665115745464891097156614211759337678111124107118921117666873710010795113531011001146937408412359941091039648436745761069398118615581112364210512411041428537775340119413355851165310111093989172591196011340539750101121701209310910641114943335574533646750993971733452125834066988657105695098557979361163210476956291764685106122323662725057113766749363499694312111212554741178550641041055510755571151019812110764737257105661086611667401228899711025189116915196954197747261120817289854410581878755575851946111090516742801221139894591031061186695115105356858813643124636941416275861081094310888791231096897466986434362107553551431078163391241011231025875754175121536412376661134267975932548341974810179785349765047644697475947367911410238679649598210111996113107106621011188082626185641251069974567874541014652123569332105567968705344796679904139567794641133411757111543240123107124125671116697651234940594512410750417480867372114911063511410984771123560859246105120485779891106397123526042978053689711012145991031259476385366628336122117791204932511014279516963871185482944093651061159065558390851128694109924264956612092331074912196122834195388910455671164811411436988164678811911147457792121959347751113712547101120387433625071349049418012111350116116] wait 0
[we survived gelf!] wait 0
.

And this is very consistent, the first simple message always takes a long time. We might need to warm up whatever objects aren't loaded so that the test can run smoothly.

[colinsurprenant]

9 is a refactor of the specs and solves this. the initial "wait" logic was not correct and prone to intermittent fails

[ph]

I will close this since #9 is merged.