Merge pull request #301 from travis-ci/ps-pusher-timeout

Implement fallback for pusher log messages

assets/scripts/app/models/log.coffee

@@ -1,5 +1,5 @@
 require 'travis/model'
-require 'travis/chunk_buffer'
+require 'travis/log_chunks'
 
 @Travis.Log = Em.Object.extend
   version: 0 # used to refresh log on requeue
@@ -9,8 +9,30 @@ require 'travis/chunk_buffer'
   init: ->
     @setParts()
 
+  fetchMissingParts: (partNumbers, after) ->
+    return if @get('notStarted')
+
+    data = {}
+    data['part_numbers'] = partNumbers if partNumbers
+    data['after'] = after if after
+
+    Travis.ajax.ajax "/jobs/#{@get('job.id')}/log", 'GET',
+      dataType: 'json'
+      headers:
+        accept: 'application/json; chunked=true; version=2'
+      data: data
+      success: (body, status, xhr) =>
+        Ember.run this, ->
+          if parts = body.log.parts
+            for part in parts
+              @append part
+
   setParts: ->
-    @set 'parts', Ember.ArrayProxy.create(content: [])
+    if parts = @get('parts')
+      parts.destroy()
+
+    parts = Travis.LogChunks.create(content: [], missingPartsCallback: => @fetchMissingParts.apply(this, arguments))
+    @set 'parts', parts
     # @set 'parts', Travis.ChunkBuffer.create(content: [])
 
   fetch: ->

assets/scripts/lib/travis/log_chunks.coffee

@@ -0,0 +1,81 @@
+Travis.LogChunks = Em.ArrayProxy.extend
+  timeout: 10000
+
+  init: ->
+    @setTimeout()
+
+    @_super.apply(this, arguments)
+
+  resetTimeout: ->
+    id = @get('timeoutId')
+    clearTimeout(id)
+
+    @setTimeout()
+
+  setTimeout: ->
+    id = setTimeout( =>
+      return if @get('finalized') || @get('isDestroyed')
+
+      @triggerMissingParts()
+      @setTimeout()
+    , @get('timeout'))
+
+    @set('timeoutId', id)
+
+  triggerMissingParts: ->
+    callback = @get('missingPartsCallback')
+    return unless callback
+
+    content  = @get('content')
+    last     = @get('last')
+    missing  = null
+    after = null
+
+    if last
+      existing = content.mapBy('number')
+      all      = [1..last.number]
+
+      missing = all.removeObjects(existing)
+
+      unless last.final
+        # if last chunk is not final, we should try a few next chunks. At the moment
+        # there's no API for that, so let's just try 10 next chunks
+        after = last.number
+
+    callback(missing, after)
+
+  last: (->
+    max = -1
+    last = null
+    for part in @get('content')
+      if part.number > max
+        max = part.number
+        last = part
+
+    last
+  ).property('content.[]', 'final')
+
+  final: (->
+    @get('content').findBy('final', true)
+  ).property()
+
+  tryFinalizing: ->
+    content = @get('content')
+    last    = @get('last')
+
+    if last.final && last.number == content.length
+      # we have all parts
+      @set('finalized', true)
+
+  contentArrayDidChange: (array, index, removedCount, addedCount) ->
+    @_super.apply this, arguments
+
+    if addedCount
+      addedObjects = array.slice(index, index + addedCount)
+      for part in addedObjects
+        if part.final
+          @notifyPropertyChange('final')
+
+      Ember.run.once this, ->
+        @tryFinalizing()
+        @resetTimeout()

assets/scripts/spec/unit/log_chunks_spec.coffee

@@ -0,0 +1,73 @@
+module "Travis.LogChunks"
+
+test "it doesn't trigger downloading missing parts if they come in timely fashion", ->
+  expect(2)
+  stop()
+
+  callback = -> ok false, 'callback should not be called'
+
+  chunks = Travis.LogChunks.create(timeout: 15, missingPartsCallback: callback, content: [])
+
+  setTimeout (-> chunks.pushObject(number: 1, final: false)), 10
+  setTimeout (-> chunks.pushObject(number: 2, final: false)), 20
+  setTimeout ->
+    ok true
+    chunks.pushObject(number: 3, final: true)
+    start()
+
+    equal(chunks.get('finalized'), true, 'log should be finalized')
+  , 30
+
+test "it triggers downloading missing parts if there is a missing part, even though final part arrived", ->
+  expect(2)
+  stop()
+
+  callback = (missingNumbers) ->
+    deepEqual(missingNumbers, [2, 3], 'callback should be called with missing numbers')
+
+  chunks = Travis.LogChunks.create(timeout: 15, missingPartsCallback: callback, content: [])
+
+  chunks.pushObject(number: 1, final: false)
+  setTimeout ->
+    chunks.pushObject(number: 4, final: true)
+
+    ok(!chunks.get('finalized'), "log shouldn't be finalized")
+  , 10
+
+  setTimeout ->
+    Ember.run -> chunks.destroy() # destroy object to not fire more callbacks
+    start()
+  , 40
+
+test "it triggers downloading next parts if there is no final part", ->
+  expect(2)
+  stop()
+
+  callback = (missingNumbers, after) ->
+    deepEqual(missingNumbers, [2], 'callback should be called with missing numbers')
+    equal(after, 3, 'callback should be called with "after" argument')
+
+  chunks = Travis.LogChunks.create(timeout: 15, missingPartsCallback: callback, content: [])
+
+  chunks.pushObject(number: 1, final: false)
+  chunks.pushObject(number: 3, final: false)
+
+  setTimeout ->
+    Ember.run -> chunks.destroy() # destroy object to not fire more callbacks
+    start()
+  , 35
+
+test "it triggers downloading all available parts if there is no parts yet", ->
+  expect(1)
+  stop()
+
+  callback = (missingNumbers, after) ->
+    ok(!missingNumbers, 'there should be no missing parts')
+    ok(!after, 'after should not be specified')
+
+  chunks = Travis.LogChunks.create(timeout: 15, missingPartsCallback: callback, content: [])
+
+  setTimeout ->
+    Ember.run -> chunks.destroy() # destroy object to not fire more callbacks
+    start()
+  , 25