coordination #71926
open
[epic] t/14-grutasks.t takes multiple minutes within circleCI, only 6s locally (but errors but still succeeds?), and no log output visible in circleCI
Added by okurz almost 4 years ago.
Updated over 3 years ago.
Category:
Regressions/Crashes
Estimated time:
(Total: 0.00 h)
Description
Observation¶
In https://app.circleci.com/pipelines/github/os-autoinst/openQA/4353/workflows/072d1477-46e0-4ae1-88f1-90740da73506/jobs/41809
[14:37:26] t/14-grutasks.t ........................................... ok 274117 ms ( 0.22 usr 0.00 sys + 260.33 cusr 9.39 csys = 269.94 CPU)
but locally I have:
[21:33:58] t/14-grutasks.t .. 34/? [2020-09-26 21:34:04.39357] [15810] [error] Gru job error: No job ID specified.
[2020-09-26 21:34:04.44377] [15814] [error] Gru job error: Job 98765 does not exist.
[2020-09-26 21:34:04.51354] [15817] [error] Gru job error: Finalizing results of 1 modules failed
[21:33:58] t/14-grutasks.t .. ok 5976 ms ( 0.08 usr 0.01 sys + 3.34 cusr 0.90 csys = 4.33 CPU)
[21:34:04]
All tests successful.
Files=1, Tests=36, 6 wallclock secs ( 0.10 usr 0.01 sys + 3.34 cusr 0.90 csys = 4.35 CPU)
Result: PASS
so two differences: Insane long runtime within circleCI compared to just 6s locally but locally I have errors which do not fail the test. I can reproduce my local observations in 20 reruns with the same observation. I wonder if this is reproducible for anyone else. Comparably small runtime was confirmed by others.
Acceptance criteria¶
- AC1: No unhandled error messages in non-verbose output shown #73126
- AC2: Runtime within CI is comparable to local runtime, e.g. less than 30s #73129
Suggestions¶
- DONE:
Crosscheck locally if anyone can reproduce the observation from CI or my (okurz's) local one same for others
- If the error messages are expected, catch them with Test::Output, otherwise prevent them (or even better fail tests if there is any unexpected output)
- In case excessive runtime is reproducible in any environment, e.g. only within CI, with Devel::Cover, in a container, etc., then find a way to reduce runtime significantly
- Status changed from Workable to Feedback
- Assignee set to okurz
- Related to action #71464: Show output of failed tests within circleci log view, like on local prove calls, not only "Tests" tab added
On my machine it takes 7 seconds.
ok
All tests successful.
Files=1, Tests=36, 7 wallclock secs ( 0.10 usr 0.03 sys + 2.70 cusr 2.06 csys = 4.89 CPU)
Result: PASS
okurz wrote:
[21:33:58] t/14-grutasks.t .. 34/? [2020-09-26 21:34:04.39357] [15810] [error] Gru job error: No job ID specified.
[2020-09-26 21:34:04.44377] [15814] [error] Gru job error: Job 98765 does not exist.
[2020-09-26 21:34:04.51354] [15817] [error] Gru job error: Finalizing results of 1 modules failed
so two differences: Insane long runtime within circleCI compared to just 6s locally but locally I have errors which do not fail the test. I can reproduce my local observations in 20 reruns with the same observation. I wonder if this is reproducible for anyone else.
The above errors are present on the log in CircleCI.
It's 12 wallclock secs
for me.
cdywan wrote:
The above errors are present on the log in CircleCI.
they are? Can you show me where?
It's 12 wallclock secs
for me.
ok, good. So as expected the problem is only within circleCI, maybe because of Devel::Cover?
okurz wrote:
cdywan wrote:
The above errors are present on the log in CircleCI.
they are? Can you show me where?
In 14-grutasks.t under Artifacts.
The above errors are present on the log in CircleCI.
they are? Can you show me where?
In 14-grutasks.t under Artifacts.
Yes, correct. This is why I created https://github.com/os-autoinst/openQA/pull/3428 so that we have the same behaviour locally as within circleCI again regarding showing unhandled log output as well as failed test context.
- Copied to action #73123: t/14-grutasks.t shows errors but still succeeds added
- Copied to action #73126: No tests show unhandled output in main test summary log added
- Copied to action #73129: t/14-grutasks.t takes multiple minutes within circleCI, only 6s locally added
- Subject changed from t/14-grutasks.t takes multiple minutes within circleCI, only 6s locally (but errors but still succeeds?) to [epic] t/14-grutasks.t takes multiple minutes within circleCI, only 6s locally (but errors but still succeeds?), and no log output visible in circleCI
- Description updated (diff)
- Status changed from Feedback to Blocked
- Priority changed from High to Low
- Description updated (diff)
- Target version deleted (
Ready)
- Target version set to Ready
- Tracker changed from action to coordination
- Status changed from Blocked to New
- Status changed from New to Blocked
- Status changed from Blocked to Workable
- Assignee deleted (
okurz)
- Target version changed from Ready to future
Also available in: Atom
PDF