Bug 915319 - job result xml should include links to logs
Summary: job result xml should include links to logs
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Beaker
Classification: Community
Component: scheduler   
(Show other bugs)
Version: 0.11
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified vote
Target Milestone: 24.0
Assignee: Dan Callaghan
QA Contact:
URL:
Whiteboard: Misc
Keywords: FutureFeature, Patch
Depends On: 1291130
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-02-25 13:45 UTC by Bill Peck
Modified: 2018-02-06 00:41 UTC (History)
7 users (show)

Fixed In Version:
Doc Type: Enhancement
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2017-02-21 18:48:33 UTC
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)


External Trackers
Tracker ID Priority Status Summary Last Updated
Red Hat Bugzilla 1123244 None None None Never

Internal Trackers: 1123244

Description Bill Peck 2013-02-25 13:45:34 UTC
Description of problem:

Currently the job result xml from a completed job in beaker does not list any links to the logs reported by tasks and recipes.  for completeness these should be in the final job xml.

Version-Release number of selected component (if applicable):
0.11

Comment 1 Dan Callaghan 2013-02-25 22:49:56 UTC
I think we considered adding logs to the results XML for bug 585153, but in the end decided not to. Maybe that was just because we already had a fairly convenient XML-RPC method for listing them.

One downside I can see with adding logs to the results XML is that it has the potential to increase the size of the XML substantially.

Comment 3 Dan Callaghan 2015-12-14 04:35:19 UTC
Bug 1291130 is an RFE for providing stable log URLs. I think we will need that in order to make this feature usable.

Comment 4 Dan Callaghan 2015-12-17 03:57:35 UTC
Adding task result logs into the XML in a backwards incompatible way is slightly problematic. The reason is that the <result/> element contains the result message as text content.

For normal results, the message is actually pretty useless: either "(Pass)" or "(Fail)" matching the result type -- except we don't actually have the result type in the XML explicitly! In other cases, the harness does put a useful message there, for example "rhts-test-runner.sh exited with rc=143" or "External Watchdog Expired".

The only sane way I can find to include the result logs inside the <result/> element while maintaining compatibility is to just append a new child element after the text content.

So we currently have things like this:

        <results>
          <result path="Setup" score="0.00" id="145958936">(Pass)</result>
          <result path="Test" score="0.00" id="145958986">(Pass)</result>
          <result path="Cleanup" score="0.00" id="145958990">(Pass)</result>
          <result path="rhts_task/exit" score="143.00" id="145959005">rhts-test-runner.sh exited with rc=143</result>
        </results>

which will instead become:

        <results>
          <result path="Setup" score="0.00" id="145958936">(Pass)<logs><log href="http://localhost:8080/recipes/1905307/tasks/29551037/results/145958936/logs/test_log-Setup.log" name="test_log-Setup.log"/><log href="http://localhost:8080/recipes/1905307/tasks/29551037/results/145958936/logs/avc_log-Setup.log" name="avc_log-Setup.log"/></logs></result>
          <result path="Test" score="0.00" id="145958986">(Pass)<logs><log href="http://localhost:8080/recipes/1905307/tasks/29551037/results/145958986/logs/test_log-Test.log" name="test_log-Test.log"/><log href="http://localhost:8080/recipes/1905307/tasks/29551037/results/145958986/logs/avc_log-Test.log" name="avc_log-Test.log"/></logs></result>
          <result path="Cleanup" score="0.00" id="145958990">(Pass)<logs><log href="http://localhost:8080/recipes/1905307/tasks/29551037/results/145958990/logs/test_log-Cleanup.log" name="test_log-Cleanup.log"/><log href="http://localhost:8080/recipes/1905307/tasks/29551037/results/145958990/logs/avc_log-Cleanup.log" name="avc_log-Cleanup.log"/></logs></result>
          <result path="rhts_task/exit" score="143.00" id="145959005">rhts-test-runner.sh exited with rc=143</result>
        </results>

It's ugly, but it shouldn't break any existing scripts which are parsing the results.

I am also going to add the result type explicitly as a separate attribute, so that scripts can avoid having to look at the result message to distinguish passes and fails.

Comment 5 Dan Callaghan 2015-12-17 07:12:24 UTC
I have a preliminary patch for this:

http://gerrit.beaker-project.org/#/c/4545/1

but I wanted to check the performance implications and they are not great...

To get an idea of the pathological case I queried a production dump for non-deleted jobs ordered by total number of tasks descending, and then picked the top-most one that was relatively recent: job id 923792. It has 3738 tasks in total.

The current results XML for that job is 3.2MB in size. With logs included, it comes out to 12MB. So almost 4x the current size. So that's the first potential issue, although there is not much I can do to reduce it.

There's also a large performance impact in terms of request time. My devel server can produce the current XML in 23 seconds but with this patch it takes 2 minutes 52 seconds. It is not CPU bound which suggests that the extra time comes from database roundtrips. The patch introduces an extra db roundtrip for every recipe, task, and result, which means the total number of roundtrips will be roughly doubled. However the request time is much, much more than doubled so there is some other factor at play. Possibly the db queries for looking up the logs are much slower than the rest of the queries.

I also got a rough estimate of the extra memory usage, by using /usr/bin/time to check max resident size. First just starting the server and killing it (no requests): 83980 KB. Then, starting the server with the existing develop branch and fetching results XML and then killing it (one request for existing XML): 205352 KB. And lastly, starting the server with this patch and fetching the results XML and then killing it (one request for XML with logs): 583472 KB. So we can estimate that the memory cost is about 4x as well.

Comment 6 Dan Callaghan 2016-09-20 01:47:41 UTC
So I don't want to hold this feature up just because it makes a bad scenario (very large jobs) worse. Even in that pathological case everything is still usable (the request comes in far under our 1.5GB address space limit, and it returns in a fairly reasonable amount of time).

I can add a parameter to all the APIs for producing results XML which will allow the caller to opt out of having the logs included. So people can use that as an escape hatch in case this makes their responses too slow or large.

Comment 7 Dan Callaghan 2016-09-20 01:48:59 UTC
We could also save a lot of data (in terms of size of the results XML we send back) if we used xml:base and then made the log hrefs relative.

This has the downside of requiring the client to know how to resolve relative hrefs according to xml:base. But it's probably worth doing.

Comment 8 Dan Callaghan 2016-09-20 02:52:14 UTC
(In reply to Dan Callaghan from comment #7)
> We could also save a lot of data (in terms of size of the results XML we
> send back) if we used xml:base and then made the log hrefs relative.
> 
> This has the downside of requiring the client to know how to resolve
> relative hrefs according to xml:base. But it's probably worth doing.

http://gerrit.beaker-project.org/5248

This only reduces the size of the results XML for job 923792 from 12MB to 11MB. So I'm not sure it's worthwhile, since it makes things more complicated for the client (they have to resolve relative URLs in the href="" attribute).

Comment 9 Dan Callaghan 2016-09-21 08:34:51 UTC
(In reply to Dan Callaghan from comment #6)
> I can add a parameter to all the APIs for producing results XML which will
> allow the caller to opt out of having the logs included. So people can use
> that as an escape hatch in case this makes their responses too slow or large.

http://gerrit.beaker-project.org/5255 refactor Recipe.to_xml() to use conventional super() chaining
http://gerrit.beaker-project.org/5256 refactor to_xml() methods to clarify from_job parameter
http://gerrit.beaker-project.org/5257 allow opting out of logs in results XML

Comment 10 matt jia 2016-09-22 05:04:01 UTC
(In reply to Dan Callaghan from comment #8)
> (In reply to Dan Callaghan from comment #7)
> > We could also save a lot of data (in terms of size of the results XML we
> > send back) if we used xml:base and then made the log hrefs relative.
> > 
> > This has the downside of requiring the client to know how to resolve
> > relative hrefs according to xml:base. But it's probably worth doing.
> 
> http://gerrit.beaker-project.org/5248
> 
> This only reduces the size of the results XML for job 923792 from 12MB to
> 11MB. So I'm not sure it's worthwhile, since it makes things more
> complicated for the client (they have to resolve relative URLs in the
> href="" attribute).

Yeah, I guess we should not make the client's life harder.

Comment 11 Dan Callaghan 2016-09-28 02:14:33 UTC
I abandoned the patch for relative URLs with xml:base. The rest are merged.

Comment 14 Dan Callaghan 2017-02-21 18:48:33 UTC
Beaker 24.0 has been released.


Note You need to log in before you can comment on or make changes to this bug.