1565497 - Intermittent GTest No tests run or test summary not found because it is generating the summary when the last test is still running

Status: RESOLVED FIXED

(Testing :: GTest, defect, P5)

Description

Filed by: dluca [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=256136053&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/Y2o-Vs_lQFi_YUqjx-B5pA/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-07-12T07:53:14.670Z] 07:53:14     INFO -  TEST-START | UrlClassifierPrefixSetTest/UrlClassifierPrefixSetTest.VariableLengthRandomSet/0
[task 2019-07-12T07:53:14.670Z] 07:53:14     INFO -  TEST-PASS | UrlClassifierPrefixSetTest/UrlClassifierPrefixSetTest.VariableLengthRandomSet/0 | test completed (time: 29ms)
[task 2019-07-12T07:53:14.670Z] 07:53:14     INFO -  TEST-START | UrlClassifierPrefixSetTest/UrlClassifierPrefixSetTest.VariableLengthRandomSet/1
[task 2019-07-12T07:53:24.959Z] 07:53:24     INFO -  gtest INFO | gtest | wait for org.mozilla.geckoview.test complete; top activity=com.android.launcher3
[task 2019-07-12T07:53:26.489Z] 07:53:26     INFO - Return code: 0
[task 2019-07-12T07:53:26.489Z] 07:53:26    ERROR - No tests run or test summary not found
[task 2019-07-12T07:53:26.489Z] 07:53:26     INFO - TinderboxPrint: gtest<br/><em class="testfail">T-FAIL</em>
[task 2019-07-12T07:53:26.489Z] 07:53:26     INFO - ##### gtest log ends
[task 2019-07-12T07:53:26.489Z] 07:53:26  WARNING - # TBPL WARNING #
[task 2019-07-12T07:53:26.489Z] 07:53:26  WARNING - setting return code to 1
[task 2019-07-12T07:53:26.489Z] 07:53:26  WARNING - The gtest suite: gtest ran with return status: WARNING

Comment 1

[Intermittent Failures Robot]

1 failures in 4710 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• android-em-7-0-x86_64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1565497&startday=2019-07-08&endday=2019-07-14&tree=all

Comment 2

[Geoff Brown [:gbrown] (pto Apr 11-18)]

Logcat confirms that all tests completed.

https://taskcluster-artifacts.net/Y2o-Vs_lQFi_YUqjx-B5pA/0/public/test_info//logcat-emulator-5554.log

07-12 08:53:15.115  2897  2913 I gtest   : TEST-PASS | UrlClassifierPrefixSetTest/UrlClassifierPrefixSetTest.LoadSaveNoDelta/0 | test completed (time: 6ms)
07-12 08:53:15.115  2897  2913 I gtest   : TEST-START | UrlClassifierPrefixSetTest/UrlClassifierPrefixSetTest.LoadSaveNoDelta/1
07-12 08:53:15.119  2897  2913 I gtest   : TEST-PASS | UrlClassifierPrefixSetTest/UrlClassifierPrefixSetTest.LoadSaveNoDelta/1 | test completed (time: 4ms)
07-12 08:53:15.119  2897  2913 I gtest   : TEST-START | SrtpParamInit/TransportSrtpParameterTest.TestSrtpCiphersMismatchCombinations/0
07-12 08:53:15.332  2897  2913 I gtest   : TEST-PASS | SrtpParamInit/TransportSrtpParameterTest.TestSrtpCiphersMismatchCombinations/0 | test completed (time: 213ms)
07-12 08:53:15.332  2897  2913 I gtest   : TEST-START | SrtpParamInit/TransportSrtpParameterTest.TestSrtpCiphersMismatchCombinations/1
07-12 08:53:15.547  2897  2913 I gtest   : TEST-PASS | SrtpParamInit/TransportSrtpParameterTest.TestSrtpCiphersMismatchCombinations/1 | test completed (time: 215ms)
07-12 08:53:15.547  2897  2913 I gtest   : TEST-START | SrtpParamInit/TransportSrtpParameterTest.TestSrtpCiphersMismatchCombinations/2
07-12 08:53:15.760  2897  2913 I gtest   : TEST-PASS | SrtpParamInit/TransportSrtpParameterTest.TestSrtpCiphersMismatchCombinations/2 | test completed (time: 213ms)
07-12 08:53:15.760  2897  2913 I gtest   : TEST-PASS | GTest unit test: passed
07-12 08:53:15.760  2897  2913 I gtest   : Passed: 2340
07-12 08:53:15.760  2897  2913 I gtest   : Failed: 0
07-12 08:53:15.777  2897  2913 D GeckoThread: State changed to EXITED

Comment 3

[Geoff Brown [:gbrown] (pto Apr 11-18)]

There are other examples in bug 1335554 (but the majority are due to browser crashes, rather than this case).

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=256030969&repo=autoland&lineNumber=5975

Comment 4

[Geoff Brown [:gbrown] (pto Apr 11-18)]

Attachment: Bug 1565497 - Improve android gtest's wait for final output; r=jmaher

A possible explanation for the infrequent observation of an incomplete log is that
the log is still being written when the harness detects that the process has completed.
Waiting for one extra polling interval may avoid this.

Comment 5

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/0bcbb4f418a8
Improve android gtest's wait for final output; r=jmaher

Comment 6

[Alexandru Michis [:malexandru]]

https://hg.mozilla.org/mozilla-central/rev/0bcbb4f418a8

Comment 7

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/798dfb5c0825