Project

General

Profile

Actions

action #57419

closed

Display time spent on particular module

Added by pvorel over 4 years ago. Updated about 4 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
Category:
Feature requests
Target version:
Start date:
2019-09-26
Due date:
% Done:

0%

Estimated time:

Description

Motivation

openQA displays a time spent on whole tests. It would be useful to have the information about the time spent on each test module.

Acceptance criteria

  • AC1: Elapsed time per test module is visible in the job details webUI page
  • AC2: Same as AC1 for API

Suggestions

We already have the information available in the scope of os-autoinst, e.g. as visible from autoinst-log.txt . We should make the information available to openQA in a structured manner and render it accordingly over API and webUI.

  • Put elapsed time into module test result, e.g. existing json file in os-autoinst scope
  • When parsing module results also read out the elapsed time
  • Provide the elapsed time when job details are requested over API
  • Provide the elapsed time in the job details webUI page
Actions #1

Updated by coolo over 4 years ago

  • Target version set to Ready

We need to properly track this from isotovideo into the DB into the UI, please no hacks

Actions #2

Updated by okurz over 4 years ago

  • Description updated (diff)
  • Status changed from New to Workable
Actions #3

Updated by Xiaojing_liu over 4 years ago

  • Status changed from Workable to In Progress
  • Assignee set to Xiaojing_liu
  • Target version changed from Ready to Current Sprint
Actions #4

Updated by Xiaojing_liu over 4 years ago

The first solution was saving the spent times in a separate file. This was not good so close the PR.
As Oliver and Mkittler suggestions, should save the spent times in details file, and change the structure of details file to HASH.

Actions #6

Updated by okurz about 4 years ago

  • Status changed from In Progress to Feedback

so the openQA PRs have been merged for a longer time already, we have the state deployed to both o3 and osd at least. The os-autoinst PR https://github.com/os-autoinst/os-autoinst/pull/1335 is still open but I guess we can merge it soon.

Actions #7

Updated by okurz about 4 years ago

  • Status changed from Feedback to Resolved

We have merged the os-autoinst change and it is effective on os-autoinst as well now. Newer jobs, e.g. https://openqa.opensuse.org/tests/1182767 show the correct display of execution time per module as well as does the api, e.g. openqa-client --host https://openqa.opensuse.org jobs/1182767/details returns execution_time => "21s" and such.

Actions #8

Updated by okurz about 4 years ago

  • Status changed from Resolved to Workable

Please see https://github.com/os-autoinst/os-autoinst/pull/1335#issuecomment-590322387 and followup.

EDIT: 2020-02-25: Suggestion by mkittler was that Xiaojing_liu continues based on the suggestions given. The latest build in https://openqa.suse.de/tests/overview?distri=sle&version=12-SP4&build=4.12.14-474.1.gcb202a6&groupid=214 has updated results after I retriggered jobs. Take a look at https://openqa.suse.de/tests/3911436#step/f00f/8 for a failed example that can also be used as a template for reproducing the problem and checking any suggested solution.

Actions #9

Updated by Xiaojing_liu about 4 years ago

  • Status changed from Workable to In Progress
Actions #10

Updated by Xiaojing_liu about 4 years ago

  • Status changed from In Progress to Feedback

The two prs has been merged, and the test works well. e.g. https://openqa.suse.de/tests/4116090

Actions #11

Updated by okurz about 4 years ago

yes, this looks good so far. I need to adjust https://github.com/os-autoinst/openqa_review but besides that everything else looks good so far.

Actions #12

Updated by okurz about 4 years ago

  • Status changed from Feedback to Resolved

AC2 fulfilled, e.g. curl -s https://openqa.suse.de/api/v1/jobs/4116090/details | jq '.job | .testresults | .[] | .name,.execution_time' | less shows:

"boot_ltp"
"22s"
"f00f"
null
"crash01"
null
"crash02"
null
"mem01"
"1s"
"fork12"
"8s"
"shutdown_ltp"
"27s"
Actions #13

Updated by pvorel about 4 years ago

Thanks for implementing this, I really appreciate it.

Actions #14

Updated by pvorel about 4 years ago

BTW some tests spent just 0s (https://openqa.suse.de/tests/4125076#step/cve-2015-0235/8), thus "execution_time" : 0 in ./testresults/result-FOO.json, but because change_sec_to_word() returns empty string instead of 0. IMHO it'd be better to write 0s instead of nothing, but not sure if we want to bother that. it's probably again some LTP specific issue.
If we do care I can fix it.

Actions #15

Updated by Xiaojing_liu about 4 years ago

pvorel wrote:

BTW some tests spent just 0s (https://openqa.suse.de/tests/4125076#step/cve-2015-0235/8), thus "execution_time" : 0 in ./testresults/result-FOO.json, but because change_sec_to_word() returns empty string instead of 0. IMHO it'd be better to write 0s instead of nothing, but not sure if we want to bother that. it's probably again some LTP specific issue.
If we do care I can fix it.

Hmm, actually it does not show the 0s is my expectation :)

Actions #16

Updated by pvorel about 4 years ago

OK, no problem for me :). It was a bit confusing, because I didn't expect that something was that quick that would take less than 1s, so it looked like error.

Actions

Also available in: Atom PDF