Bug 1410670

Summary:	bad performance with with long tests
Product:	[Fedora] Fedora	Reporter:	Alois Mahdal <amahdal>
Component:	beakerlib	Assignee:	Dalibor Pospíšil <dapospis>
Status:	CLOSED CURRENTRELEASE	QA Contact:	Fedora Extras Quality Assurance <extras-qa>
Severity:	unspecified	Docs Contact:
Priority:	low
Version:	27	CC:	azelinka, dapospis, fsumsal, jheger, jprokes, mkyral, muller
Target Milestone:	---
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	beakerlib-1.17-6	Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2018-01-15 21:37:49 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:	1208589
Bug Blocks:

Description Alois Mahdal 2017-01-06 03:58:46 UTC

Description of problem
======================

As number of log messages in test increases, beakerlib gets slower and slower.  It has been explained to me by jprokes that this is caused by beakerlib repeatedly parsing/writing the whole XML, which naturally takes longer as the XML is bigger.

This causes a lot of resource wastage with longer tests.


Version-Release number of selected component
============================================

beakerlib-1.11-1.el7


How reproducible
================

Always, with longer tests.


Steps to Reproduce
==================

 1. Have a test with hundreds of log messages and asserts
 2. Observe logging efficiency over the course of the test


Actual results
==============

The efficiency goes down as existing log is longer.


Expected results
================

The efficiency is the same.


Additional info
===============

I have a test which runs by traversing 120 cases; with each iteration generates about 150 log messages (~50 rlLog* calls) or asserts in 5 phases.  The actual payload is roughly the same in each case (add/remove 1-2 users, edit few files, restart services...).

Today I added some time measurements:  The first iteration takes roughly 3.5 seconds and this number steadily grows larger and larger up to 17 seconds at the last iteration!  My calculations:  If each iteration took 4 seconds, the whole test would take 8 minutes, but really it takes 20.

IOW, the "beakerlib tax" comes to more than double the final test time.

Comment 1 Dalibor Pospíšil 2017-01-06 16:49:12 UTC

This is known issue. It is caused by current journaling.py which rebuilds journal.xml every time it writes anything. It is not an easy job to fix it properly.
If you are willing to participate on this you are more then welcome.

Comment 2 Fedora End Of Life 2017-07-26 00:09:51 UTC

This message is a reminder that Fedora 24 is nearing its end of life.
Approximately 2 (two) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 24. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '24'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version'
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not
able to fix it before Fedora 24 is end of life. If you would still like
to see this bug fixed and are able to reproduce it against a later version
of Fedora, you are encouraged  change the 'version' to a later Fedora
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's
lifetime, sometimes those efforts are overtaken by events. Often a
more recent Fedora release includes newer upstream software that fixes
bugs or makes them obsolete.

Comment 3 Jan Kurik 2017-08-15 06:36:23 UTC

This bug appears to have been reported against 'rawhide' during the Fedora 27 development cycle.
Changing version to '27'.