[zorg] LitTestCommand aborts if Verbose log line is not preceded by a valid test status line.

[rfoos]

Summary

Lit expects a test status line (kTestLineRE) before a verbose log start marker (kTestVerboseLogStartRE).

FAIL: LLDB :: asdf (9 of 20)
*** TEST 'LLDB :: asdf' FAIL ***

If the test status line is malformed, LitTestCommand has an exception at outLineReceived, and testInfoFinished because lastTestResult is None.

FAIL: LLDB :: asdf
*** TEST 'LLDB :: asdf' FAIL ***

Another case of mismatched status/log lines skips the log entry.

This patch handles lastTestResult is None, and skips the log entry.

[gkistanova]

Assuming you will fix the cosmetic issue I have commented in-line.

zorg/buildbot/commands/LitTestCommand.py

63

Maybe handle it the other way around?
Handling the normal case first and the error case at the end. Something like:

if self.lastTestResult:
   # We have finished getting information for one test, handle it.
   code, name = self.lastTestResult
   ...
else:
   # We could get a malformed test status line.
   # Report an issue for verbose mode and skip it.
   if self.lastTestResult is None:
   ...

# Reset the current state.
self.lastTestResult = None
self.activeVerboseLog = None

[rfoos]

Changed testInfoFinished so normal case is first.

zorg/buildbot/commands/LitTestCommand.py

def handleVerboseLogLine(self, line):
     self.activeVerboseLog.append(line)
 
     # If this is a stop marker, process the test info.
     if self.kTestVerboseLogStopRE.match(line.strip()):
       self.testInfoFinished()
 
   def testInfoFinished(self):
     # We have finished getting information for one test, handle it.
+    if self.lastTestResult:
         code, name = self.lastTestResult
 
         # If the test failed, add a log entry for it (unless we have reached the
         # max).
         if code in self.failingCodes and (self.maxLogs is None or
                                           self.numLogs < self.maxLogs):
           # If a verbose log was not provided, just add a one line description.
           if self.activeVerboseLog is None:
             self.activeVerboseLog = ['%s: %s' % (code, name)]
 
           # Add the log to the build status.
           # Make the test name short, the qualified test name is in the log anyway.
           # Otherwise, we run out of the allowed name length on some hosts.
           name_part = name.rpartition('::')
           self.step.addCompleteLog(
                       code + ': ' + name_part[0].strip() + name_part[1] + basename(name_part[2]),
                       '\n'.join(self.activeVerboseLog))
           self.numLogs += 1
+    else:
+        if self.activeVerboseLog:
+            self.activeVerboseLog.append(
+              "error: missing test status line, skipping log")
 
     # Reset the current state.
     self.lastTestResult = None
     self.activeVerboseLog = None
 
   def handleSimplifiedLogLine(self, line):
     # Check for test status line
     m = self.kTestLineRE.match(line.strip())
def outLineReceived(self, line):
     if self.activeVerboseLog is not None:
       self.handleVerboseLogLine(line)
       return
 
     # Check for the test verbose log start marker.
     m = self.kTestVerboseLogStartRE.match(line.strip())
     if m:
       self.activeVerboseLog = [line]
-      if m.group(1) != self.lastTestResult[1]:
+      if self.lastTestResult is None:
+        if self.activeVerboseLog:
+            self.activeVerboseLog.append(
+              "error: missing test line before verbose log start.")
+      elif m.group(1) != self.lastTestResult[1]:
         # This is bogus, the verbose log test name doesn't match what we
         # expect. Just note it in the log but otherwise accumulate as normal.
         self.activeVerboseLog.append(
           "error: verbose log output name didn't match expected test name")
       return
 
     # Otherwise, if we had any previous test consider it finished.
     #

 FAIL: test-two (2 of 4)
 PASS: test-three (3 of 4)
 TIMEOUT: test-four (4 of 4)
 """)
 
     self.assertEqual(obs.resultCounts, { 'FAIL' : 1, 'TIMEOUT' : 1, 'PASS' : 2 })
     self.assertEqual(obs.step.logs, [('FAIL: test-two', 'FAIL: test-two'), ('TIMEOUT: test-four', 'TIMEOUT: test-four')])
 
+  def test_missing_lastresult(self):
+    obs = self.parse_log("""
+FAIL: LLDB :: 10-breakpoint-by-address-multiple-hit-first-add-next
+********** TEST 'LLDB :: 10-breakpoint-by-address-multiple-hit-first-add-next' FAIL **********
+bla bla bla
+**********
+         TIMEOUT: LLDB :: 57-dlopen-breakpoint (51 of 57)
+         ********** TEST 'LLDB :: 57-dlopen-breakpoint' TIMEOUT **********
+         bla
+         **********
+""")
+
+    self.assertEqual(obs.resultCounts, {'TIMEOUT': 1})
+
   def test_verbose_logs(self):
     obs = self.parse_log("""
 FAIL: test-one (1 of 3)
 FAIL: test-two (2 of 3)
 **** TEST 'test-two' FAILED ****
 bla bla bla
 **********
 FAIL: test-three (3 of 3)