Add CI build trace sections extractor

2 files changed, 174 insertions, 0 deletions

diff --git a/spec/lib/gitlab/ci/trace/section_parser_spec.rb b/spec/lib/gitlab/ci/trace/section_parser_spec.rb
new file mode 100644
index 00000000000..ca53ff87c6f
--- /dev/null
+++ b/spec/lib/gitlab/ci/trace/section_parser_spec.rb
@@ -0,0 +1,87 @@
+require 'spec_helper'
+
+describe Gitlab::Ci::Trace::SectionParser do
+  def lines_with_pos(text)
+    pos = 0
+    StringIO.new(text).each_line do |line|
+      yield line, pos
+      pos += line.bytesize + 1 # newline
+    end
+  end
+
+  def build_lines(text)
+    to_enum(:lines_with_pos, text)
+  end
+
+  def section(name, start, duration, text)
+    end_ = start + duration
+    "section_start:#{start.to_i}:#{name}\r\033[0K#{text}section_end:#{end_.to_i}:#{name}\r\033[0K"
+  end
+
+  let(:lines) { build_lines('') }
+  subject { described_class.new(lines) }
+
+  describe '#sections' do
+    before do
+      subject.parse!
+    end
+
+    context 'empty trace' do
+      let(:lines) { build_lines('') }
+
+      it { expect(subject.sections).to be_empty }
+    end
+
+    context 'with a sectionless trace' do
+      let(:lines) { build_lines("line 1\nline 2\n") }
+
+      it { expect(subject.sections).to be_empty }
+    end
+
+    context 'with trace markers' do
+      let(:start_time) { Time.new(2017, 10, 5).utc }
+      let(:section_b_duration) { 1.second }
+      let(:section_a) { section('a', start_time, 0, 'a line') }
+      let(:section_b) { section('b', start_time, section_b_duration, "another line\n") }
+      let(:lines) { build_lines(section_a + section_b) }
+
+      it { expect(subject.sections.size).to eq(2) }
+      it { expect(subject.sections[1][:name]).to eq('b') }
+      it { expect(subject.sections[1][:date_start]).to eq(start_time) }
+      it { expect(subject.sections[1][:date_end]).to eq(start_time + section_b_duration) }
+    end
+  end
+
+  describe '#parse!' do
+    context 'multiple "section_" but no complete markers' do
+      let(:lines) { build_lines('section_section_section_') }
+
+      it 'must find 3 possible section start but no complete sections' do
+        expect(subject).to receive(:find_next_marker).exactly(3).times.and_call_original
+
+        subject.parse!
+
+        expect(subject.sections).to be_empty
+      end
+    end
+
+    context 'trace with UTF-8 chars' do
+      let(:line) { 'GitLab ❤️ 狸 (tanukis)\n' }
+      let(:trace) { section('test_section', Time.new(2017, 10, 5).utc, 3.seconds, line) }
+      let(:lines) { build_lines(trace) }
+
+      it 'must handle correctly byte positioning' do
+        expect(subject).to receive(:find_next_marker).exactly(2).times.and_call_original
+
+        subject.parse!
+
+        sections = subject.sections
+
+        expect(sections.size).to eq(1)
+        s = sections[0]
+        len = s[:byte_end] - s[:byte_start]
+        expect(trace.byteslice(s[:byte_start], len)).to eq(line)
+      end
+    end
+  end
+end
diff --git a/spec/lib/gitlab/ci/trace_spec.rb b/spec/lib/gitlab/ci/trace_spec.rb
index 9cb0b62590a..3546532b9b4 100644
--- a/spec/lib/gitlab/ci/trace_spec.rb
+++ b/spec/lib/gitlab/ci/trace_spec.rb
@@ -61,6 +61,93 @@ describe Gitlab::Ci::Trace do
     end
   end
 
+  describe '#extract_sections' do
+    let(:log) { 'No sections' }
+    let(:sections) { trace.extract_sections }
+
+    before do
+      trace.set(log)
+    end
+
+    context 'no sections' do
+      it 'returs []' do
+        expect(trace.extract_sections).to eq([])
+      end
+    end
+
+    context 'multiple sections available' do
+      let(:log) { File.read(expand_fixture_path('trace/trace_with_sections')) }
+      let(:sections_data) do
+        [
+          { name: 'prepare_script', lines: 2, duration: 3.seconds },
+          { name: 'get_sources', lines: 4, duration: 1.second },
+          { name: 'restore_cache', lines: 0, duration: 0.seconds },
+          { name: 'download_artifacts', lines: 0, duration: 0.seconds },
+          { name: 'build_script', lines: 2, duration: 1.second },
+          { name: 'after_script', lines: 0, duration: 0.seconds },
+          { name: 'archive_cache', lines: 0, duration: 0.seconds },
+          { name: 'upload_artifacts', lines: 0, duration: 0.seconds }
+        ]
+      end
+
+      it "returns valid sections" do
+        expect(sections).not_to be_empty
+        expect(sections.size).to eq(sections_data.size),
+                                 "expected #{sections_data.size} sections, got #{sections.size}"
+
+        buff = StringIO.new(log)
+        sections.each_with_index do |s, i|
+          expected = sections_data[i]
+
+          expect(s[:name]).to eq(expected[:name])
+          expect(s[:date_end] - s[:date_start]).to eq(expected[:duration])
+
+          buff.seek(s[:byte_start], IO::SEEK_SET)
+          length = s[:byte_end] - s[:byte_start]
+          lines = buff.read(length).count("\n")
+          expect(lines).to eq(expected[:lines])
+        end
+      end
+    end
+
+    context 'logs contains "section_start"' do
+      let(:log) { "section_start:1506417476:a_section\r\033[0Klooks like a section_start:invalid\nsection_end:1506417477:a_section\r\033[0K"}
+
+      it "returns only one section" do
+        expect(sections).not_to be_empty
+        expect(sections.size).to eq(1)
+
+        section = sections[0]
+        expect(section[:name]).to eq('a_section')
+        expect(section[:byte_start]).not_to eq(section[:byte_end]), "got an empty section"
+      end
+    end
+
+    context 'missing section_end' do
+      let(:log) { "section_start:1506417476:a_section\r\033[0KSome logs\nNo section_end\n"}
+
+      it "returns no sections" do
+        expect(sections).to be_empty
+      end
+    end
+
+    context 'missing section_start' do
+      let(:log) { "Some logs\nNo section_start\nsection_end:1506417476:a_section\r\033[0K"}
+
+      it "returns no sections" do
+        expect(sections).to be_empty
+      end
+    end
+
+    context 'inverted section_start section_end' do
+      let(:log) { "section_end:1506417476:a_section\r\033[0Klooks like a section_start:invalid\nsection_start:1506417477:a_section\r\033[0K"}
+
+      it "returns no sections" do
+        expect(sections).to be_empty
+      end
+    end
+  end
+
   describe '#set' do
     before do
       trace.set("12")