From 27fe85989a7eccd33b5b301d92a34db3c889e8d3 Mon Sep 17 00:00:00 2001 From: Piotr Sarnacki Date: Wed, 5 Dec 2012 21:20:58 +0100 Subject: [PATCH] Make rendering long logs faster when rendering huge chunks at once After change log rendering method, to append HTML elements instead of rerendering the entire thing, the case of gradual rendering of a log started to behave much better (because we just append new elements), but the initial render took a bit longer, because of the fact that appending large separate HTML elements to DOM at once is not a good idea. In order to make the situation better I added simple optimization. Elements are added to DocumentFragment node before inserting to DOM and appended to DOM only after all elements are processed. That way, when log needs to be rendered all at once, we will not do any DOM operations until log is ready. --- assets/scripts/app/templates/jobs/log.hbs | 7 +- assets/scripts/app/templates/jobs/pre.hbs | 4 + assets/scripts/app/views/job.coffee | 150 +++++++++------- assets/scripts/spec/unit/log_spec.coffee | 51 +++--- assets/scripts/spec/unit/pre_view_spec.coffee | 161 ++++++++++++++++++ .../spec/unit/views/log_view_spec.coffee | 74 -------- 6 files changed, 281 insertions(+), 166 deletions(-) create mode 100644 assets/scripts/app/templates/jobs/pre.hbs create mode 100644 assets/scripts/spec/unit/pre_view_spec.coffee delete mode 100644 assets/scripts/spec/unit/views/log_view_spec.coffee diff --git a/assets/scripts/app/templates/jobs/log.hbs b/assets/scripts/app/templates/jobs/log.hbs index b0f49128..c601a99a 100644 --- a/assets/scripts/app/templates/jobs/log.hbs +++ b/assets/scripts/app/templates/jobs/log.hbs @@ -5,12 +5,7 @@ this should probably be refactored to use container view}} {{#with view.job.log}} {{#if id}} - {{#view view.PreView logBinding="view.context.log" logUrlBinding="view.logUrl"}} - 

-          
-          
-
- {{/view}} + {{view Travis.PreView logBinding="view.context.log" logUrlBinding="view.logUrl"}} {{/if}} {{/with}} diff --git a/assets/scripts/app/templates/jobs/pre.hbs b/assets/scripts/app/templates/jobs/pre.hbs new file mode 100644 index 00000000..72cb78d1 --- /dev/null +++ b/assets/scripts/app/templates/jobs/pre.hbs @@ -0,0 +1,4 @@ +

+  
+  
+
diff --git a/assets/scripts/app/views/job.coffee b/assets/scripts/app/views/job.coffee index 57c6b52b..5b400cb7 100644 --- a/assets/scripts/app/views/job.coffee +++ b/assets/scripts/app/views/job.coffee @@ -128,79 +128,111 @@ Travis.app.get('router').urlForEvent(event, repo, item) ).property('job.repo', 'parentView.currentItem') - PreView: Em.View.extend - init: -> - @_super.apply this, arguments - @set 'logManager', Travis.Log.create(target: this) + PreView: Em.View.extend + templateName: 'jobs/pre' + init: -> + @_super.apply this, arguments + @set 'logManager', Travis.Log.create(target: this) - didInsertElement: -> - @_super.apply this, arguments + didInsertElement: -> + @_super.apply this, arguments - Ember.run.next this, -> - if @get 'log.isInitialized' - @logDidChange() + Ember.run.next this, -> + if @get 'log.isInitialized' + @logDidChange() - willDestroy: -> - @get('logManager').destroy() - @get('log.parts').removeArrayObserver this, + willDestroy: -> + @get('logManager').destroy() + @get('log.parts').removeArrayObserver this, + didChange: 'logContentsDidChange' + willChange: 'logContentsWillChange' + + version: (-> + @rerender() + @set 'logManager', Travis.Log.create(target: this) + ).observes('log.version') + + logDidChange: (-> + if @get('log.isInitialized') && @state == 'inDOM' + @attachLogObservers() + ).observes('log', 'log.isInitialized') + + attachLogObservers: -> + return if @get('logPartsObserversAttached') == Ember.guidFor(@get('log')) + @set 'logPartsObserversAttached', Ember.guidFor(@get('log')) + + Ember.run.next this, -> + @get('logManager').append @get('log.parts') + + @get('log.parts').addArrayObserver this, didChange: 'logContentsDidChange' willChange: 'logContentsWillChange' - version: (-> - @rerender() - @set 'logManager', Travis.Log.create(target: this) - ).observes('log.version') + logContentsDidChange: (lines, index, removedCount, addedCount) -> + addedLines = lines.slice(index, index + addedCount) + @get('logManager').append addedLines - logDidChange: (-> - if @get('log.isInitialized') && @state == 'inDOM' - @attachLogObservers() - ).observes('log', 'log.isInitialized') + logContentsWillChange: (-> ) - attachLogObservers: -> - return if @get('logPartsObserversAttached') == Ember.guidFor(@get('log')) - @set 'logPartsObserversAttached', Ember.guidFor(@get('log')) + appendLog: (payloads) -> + url = @get('logUrl') - Ember.run.next this, -> - @get('logManager').append @get('log.parts') + leftOut = [] + fragment = document.createDocumentFragment() - @get('log.parts').addArrayObserver this, - didChange: 'logContentsDidChange' - willChange: 'logContentsWillChange' + # TODO: refactor this loop, it's getting messy + for payload in payloads + line = payload.content + number = payload.number - logContentsDidChange: (lines, index, removedCount, addedCount) -> - addedLines = lines.slice(index, index + addedCount) - @get('logManager').append addedLines + unless payload.append + pathWithNumber = "#{url}#L#{number}" + p = document.createElement('p') + p.innerHTML = '%@%@'.fmt(pathWithNumber, number, number, number, line) + line = p - logContentsWillChange: (-> ) + if payload.fold && !payload.foldContinuation + div = document.createElement('div') + div.appendChild line + div.className = "fold #{payload.fold} show-first-line" + line = div - appendLog: (payloads) -> - url = @get('logUrl') - - for payload in payloads - line = payload.content - number = payload.number - - unless payload.append - pathWithNumber = "#{url}#L#{number}" - line = '

%@%@

'.fmt(pathWithNumber, number, number, number, line) - - if payload.fold && !payload.foldContinuation - line = "
#{line}
" - - if payload.replace - this.$("#log #L#{number}").parent().replaceWith line - else if payload.append - this.$("#log #L#{number}").parent().append line - else if payload.foldContinuation - this.$("#log .fold.#{payload.fold}:last").append line + if payload.replace + if link = fragment.querySelector("#L#{number}") + link.parentElement.innerHTML = line.innerHTML else - this.$('#log').append(line) + this.$("#L#{number}").parent().replaceWith line + else if payload.append + if link = fragment.querySelector("#L#{number}") + link.parentElement.innerHTML += line + else + this.$("#L#{number}").parent().append line + else if payload.foldContinuation + folds = fragment.querySelectorAll(".fold.#{payload.fold}") + if fold = folds[folds.length - 1] + fold.appendChild line + else + this.$("#log .fold.#{payload.fold}:last").append line + else + fragment.appendChild(line) - if payload.openFold - this.$("#log .fold.#{payload.openFold}:last"). - removeClass('show-first-line'). - addClass('open') + if payload.openFold + folds = fragment.querySelectorAll(".fold.#{payload.fold}") + if fold = folds[folds.length - 1] + fold = $(fold) + else + fold = this.$(".fold.#{payload.fold}:last") - if payload.foldEnd - this.$("#log .fold.#{payload.fold}:last").removeClass('show-first-line') + fold.removeClass('show-first-line').addClass('open') + + if payload.foldEnd + folds = fragment.querySelectorAll(".fold.#{payload.fold}") + if fold = folds[folds.length - 1] + fold = $(fold) + else + fold = this.$(".fold.#{payload.fold}:last") + + fold.removeClass('show-first-line') + + this.$('#log')[0].appendChild fragment diff --git a/assets/scripts/spec/unit/log_spec.coffee b/assets/scripts/spec/unit/log_spec.coffee index 4c0d1ce9..a8ff7d1d 100644 --- a/assets/scripts/spec/unit/log_spec.coffee +++ b/assets/scripts/spec/unit/log_spec.coffee @@ -76,8 +76,8 @@ describe 'Travis.Log', -> { number: 8, fold: 'qux', foldContinuation: true }, { number: 9, fold: 'qux', foldContinuation: true, foldEnd: true }] - expect( lines[4] ).toEqual ['$ end', ''] - expect( options[4]).toEqual [{ number: 10 }, { number: 11 }] + expect( lines[4] ).toEqual ['$ end'] + expect( options[4]).toEqual [{ number: 10 }] it 'works properly when log is started with fold', -> fold = Em.Object.create name: 'foo', startPattern: /^\$ foo/, endPattern: /^\$/ @@ -97,8 +97,8 @@ describe 'Travis.Log', -> { number: 1, fold: 'foo' }, { number: 2, fold: 'foo', foldContinuation: true, foldEnd: true }] - expect( lines[1] ).toEqual ['$ bar', ''] - expect( options[1]).toEqual [{ number: 3 }, { number: 4 }] + expect( lines[1] ).toEqual ['$ bar'] + expect( options[1]).toEqual [{ number: 3 }] it 'works properly for 2 consecutive folds', -> fold = Em.Object.create name: 'foo', startPattern: /^\$ foo/, endPattern: /^\$/ @@ -124,8 +124,8 @@ describe 'Travis.Log', -> { number: 3, fold: 'foo' }, { number: 4, fold: 'foo', foldContinuation: true, foldEnd: true }] - expect( lines[2] ).toEqual ['$ bar', ''] - expect( options[2]).toEqual [{ number: 5 }, { number: 6 }] + expect( lines[2] ).toEqual ['$ bar'] + expect( options[2]).toEqual [{ number: 5 }] it 'works fine with not finalized fold', -> fold = Em.Object.create name: 'foo', startPattern: /^\$ foo/, endPattern: /^\$/ @@ -139,11 +139,10 @@ describe 'Travis.Log', -> lines = target.get('calls').map (call) -> call.lines options = target.get('calls').map (call) -> call.options - expect( lines[0] ).toEqual ['$ foo --foo', '1', ''] + expect( lines[0] ).toEqual ['$ foo --foo', '1'] expect( options[0]).toEqual [ { fold: 'foo', number: 1 }, - { fold: 'foo', number: 2, foldContinuation: true }, - { fold: 'foo', number: 3, foldContinuation: true }] + { fold: 'foo', number: 2, foldContinuation: true }] it 'allows to continue fold', -> fold = Em.Object.create name: 'foo', startPattern: /^\$ foo/, endPattern: /^\$/ @@ -164,25 +163,23 @@ describe 'Travis.Log', -> lines = target.get('calls').map (call) -> call.lines options = target.get('calls').map (call) -> call.options - expect( lines[0] ).toEqual ['$ foo --foo', '1', ''] + expect( lines[0] ).toEqual ['$ foo --foo', '1'] expect( options[0]).toEqual [ { fold: 'foo', number: 1 }, - { fold: 'foo', number: 2, foldContinuation: true }, - { fold: 'foo', number: 3, foldContinuation: true }] + { fold: 'foo', number: 2, foldContinuation: true }] - expect( lines[1] ).toEqual ['2', ''] + expect( lines[1] ).toEqual ['2'] expect( options[1]).toEqual [ - { fold: 'foo', number: 3, foldContinuation: true, append: true } - { fold: 'foo', number: 4, foldContinuation: true } + { fold: 'foo', number: 3, foldContinuation: true } ] expect( lines[2] ).toEqual ['3'] expect( options[2]).toEqual [ - { fold: 'foo', number: 4, foldContinuation: true, append: true, foldEnd: true } + { fold: 'foo', number: 4, foldContinuation: true, foldEnd: true } ] - expect( lines[3] ).toEqual ['$ bar', ''] - expect( options[3]).toEqual [{ number: 5 }, { number: 6 }] + expect( lines[3] ).toEqual ['$ bar'] + expect( options[3]).toEqual [{ number: 5 }] it 'notifies that the line should be appended', -> log.append '$ foo\n.' @@ -201,8 +198,8 @@ describe 'Travis.Log', -> expect( lines[1] ).toEqual ['...'] expect( options[1]).toEqual [{ append: true, number: 2 }] - expect( lines[2] ).toEqual ['..', '$ bar', ''] - expect( options[2]).toEqual [{ append: true, number: 2 }, { number: 3 }, { number: 4 }] + expect( lines[2] ).toEqual ['..', '$ bar'] + expect( options[2]).toEqual [{ append: true, number: 2 }, { number: 3 }] it 'notifies that the line should be replaced', -> log.append '$ foo\n' @@ -216,17 +213,17 @@ describe 'Travis.Log', -> lines = target.get('calls').map (call) -> call.lines options = target.get('calls').map (call) -> call.options - expect( lines[0] ).toEqual ['$ foo', ''] - expect( options[0]).toEqual [{ number: 1 }, { number: 2 }] + expect( lines[0] ).toEqual ['$ foo'] + expect( options[0]).toEqual [{ number: 1 }] expect( lines[1] ).toEqual ['', 'Downloading 50%'] - expect( options[1]).toEqual [{ number: 2, append: true }, { number: 2, replace: true }] + expect( options[1]).toEqual [{ number: 2 }, { number: 2, replace: true }] - expect( lines[2] ).toEqual ['', 'Downloading 100%', ''] - expect( options[2]).toEqual [{ number: 2, append: true }, { number: 2, replace: true }, { number: 3 }] + expect( lines[2] ).toEqual ['', 'Downloading 100%'] + expect( options[2]).toEqual [{ number: 2, append: true }, { number: 2, replace: true }] - expect( lines[3] ).toEqual ['$ bar', ''] - expect( options[3]).toEqual [{ number: 3, append: true }, { number: 4 }] + expect( lines[3] ).toEqual ['$ bar'] + expect( options[3]).toEqual [{ number: 3 }] it 'notifies that the line should be replaced even if carriage return is in the middle', -> diff --git a/assets/scripts/spec/unit/pre_view_spec.coffee b/assets/scripts/spec/unit/pre_view_spec.coffee new file mode 100644 index 00000000..c1a95ce5 --- /dev/null +++ b/assets/scripts/spec/unit/pre_view_spec.coffee @@ -0,0 +1,161 @@ +view = null +store = null +record = null + +describe 'Travis.PreView', -> + beforeEach -> + store = Travis.Store.create() + + afterEach -> + store.destroy() + view.remove() + view.destroy() + + it 'works fine with existing log, which is appended', -> + store.load Travis.Artifact, 1, { id: 1, body: '$ start\n' } + log = Travis.Artifact.find(1) + log.set('version', 1) + + Ember.run -> + view = Travis.PreView.create(log: null) + view.append() + + expect( view.$('#log').length ).toEqual 1 + + Ember.run -> + view.set 'log', log + log.set 'isLoaded', true + + waits 50 + runs -> + expect( view.$('#log p').length ).toEqual 1 + expect( view.$('#log p').text().trim() ).toEqual '1$ start' + + Ember.run -> + log.append('$ end') + + waits 50 + runs -> + expect( view.$('#log p').length ).toEqual 2 + expect( view.$('#log p').text().trim() ).toEqual '1$ start2$ end' + + it 'works fine with log already attahed to view', -> + store.load Travis.Artifact, 1, { id: 1, body: '$ start\n' } + log = Travis.Artifact.find(1) + + Ember.run -> + view = Travis.PreView.create() + view.set('log', log) + view.append() + + Ember.run -> + log.append('end') + + waits 50 + runs -> + expect( view.$('#log p').length ).toEqual 2 + expect( view.$('#log p').text().trim() ).toEqual '1$ start2end' + + it 'folds items', -> + store.load Travis.Artifact, 1, { id: 1, body: '$ start\n' } + log = Travis.Artifact.find(1) + + Ember.run -> + view = Travis.PreView.create() + view.set('log', log) + view.append() + + Ember.run -> + log.append '$ bundle install\n1\n2\n' + + Ember.run -> + log.append '3\n4\n$ something' + + waits 50 + runs -> + expect( view.$('#log > p').length ).toEqual 2 + expect( view.$('#log .fold.bundle').length ).toEqual 1 + expect( view.$('#log .fold.bundle > p').length ).toEqual 5 + + + it 'works properly with fragment document', -> + store.load Travis.Artifact, 1, { id: 1, body: '' } + log = Travis.Artifact.find(1) + + Ember.run -> + view = Travis.PreView.create() + view.set('log', log) + view.append() + + waits 50 + runs -> + payloads = [ + { number: 1, content: 'foo' } + { number: 1, content: 'bar', append: true } + ] + + # it should work even if we need to append to fragment in memory + view.appendLog(payloads) + + expect( view.$('#L1').parent().text().trim() ).toEqual '1foobar' + + # now, let's append more to this line, it's in DOM already + view.appendLog([ { number: 1, content: 'baz', append: true } ]) + + expect( view.$('#L1').parent().text().trim() ).toEqual '1foobarbaz' + + payloads = [ + { number: 1, content: 'foo', replace: true } + ] + # replace should work in DOM + view.appendLog(payloads) + expect( view.$('#L1').parent().text().trim() ).toEqual '1foo' + + payloads = [ + { number: 2, content: 'foo' } + { number: 2, content: 'bar', replace: true } + ] + # replace should work when element is in fragment + view.appendLog(payloads) + expect( view.$('#L2').parent().text().trim() ).toEqual '2bar' + + payloads = [ + { number: 3, content: '$ bundle install', fold: 'bundle' } + { number: 4, content: 'Installing rails', fold: 'bundle', foldContinuation: true } + ] + # folds should work properly with fragment + view.appendLog(payloads) + expect( view.$('.bundle #L3').parent().text().trim() ).toEqual '3$ bundle install' + expect( view.$('.bundle #L4').parent().text().trim() ).toEqual '4Installing rails' + expect( view.$('.bundle > p').length ).toEqual 2 + + payloads = [ + { number: 5, content: 'Installing travis', fold: 'bundle', foldContinuation: true } + ] + # folds should also work when already in DOM + view.appendLog(payloads) + expect( view.$('.bundle #L5').parent().text().trim() ).toEqual '5Installing travis' + expect( view.$('.bundle > p').length ).toEqual 3 + + # regular line append + view.appendLog([ { number: 6, content: 'next'} ]) + expect( view.$('#L6').parent().text().trim() ).toEqual '6next' + + # openFold when in fragment + payloads = [ + { number: 7, content: '$ install', fold: 'install' } + { number: 8, content: 'Installing foo', fold: 'install', foldContinuation: true } + { number: 9, content: 'error', openFold: true, fold: 'install', foldContinuation: true } + ] + # folds should work properly with fragment + view.appendLog(payloads) + expect( view.$('.install').hasClass('show-first-line') ).toEqual false + + # end fold when in fragment + payloads = [ + { number: 10, content: '$ install', fold: 'install2' } + { number: 11, content: 'Installing foo', fold: 'install2', foldEnd: true, foldContinuation: true } + ] + # folds should work properly with fragment + view.appendLog(payloads) + expect( view.$('.install2').hasClass('show-first-line') ).toEqual false diff --git a/assets/scripts/spec/unit/views/log_view_spec.coffee b/assets/scripts/spec/unit/views/log_view_spec.coffee deleted file mode 100644 index fc6394a2..00000000 --- a/assets/scripts/spec/unit/views/log_view_spec.coffee +++ /dev/null @@ -1,74 +0,0 @@ -view = null -store = null -record = null - -describe 'Travis.LogView', -> - beforeEach -> - store = Travis.Store.create() - - afterEach -> - store.destroy() - view.remove() - view.destroy() - - it 'works fine with existing log, which is appended', -> - store.load Travis.Artifact, 1, { id: 1, body: '$ start' } - log = Travis.Artifact.find(1) - - Ember.run -> - view = Travis.LogView.create(context: null) - view.append() - - expect( $('#log').length ).toEqual 1 - console.log $('#log') - - job = Ember.Object.create log: log, subscribe: (-> ) - - Ember.run -> - view.set 'context', job - log.set 'isLoaded', true - - expect( view.$('#log p').length ).toEqual 1 - expect( view.$('#log p').text().trim() ).toEqual '1$ start' - - Ember.run -> - log.append('$ end') - - expect( view.$('#log p').length ).toEqual 2 - expect( view.$('#log p').text().trim() ).toEqual '1$ start2$ end' - - it 'works fine with log already attahed to view', -> - store.load Travis.Artifact, 1, { id: 1, body: '$ start' } - log = Travis.Artifact.find(1) - job = Ember.Object.create log: log, subscribe: (-> ) - - Ember.run -> - view = Travis.LogView.create() - view.set('context', job) - view.append() - - Ember.run -> - log.append('end') - - expect( view.$('#log p').length ).toEqual 2 - expect( view.$('#log p').text().trim() ).toEqual '1$ start2end' - - it 'folds items', -> - store.load Travis.Artifact, 1, { id: 1, body: '$ start' } - log = Travis.Artifact.find(1) - job = Ember.Object.create log: log, subscribe: (-> ) - - Ember.run -> - view = Travis.LogView.create() - view.set('context', job) - view.append() - - Ember.run -> - log.append '$ bundle install\n1\n2' - - Ember.run -> - log.append '3\n4\n$ something' - - expect( view.$('#log > p').length ).toEqual 2 - expect( view.$('#log .fold.bundle').length ).toEqual 1 - expect( view.$('#log .fold.bundle > p').length ).toEqual 5