Bug 1122810 - Slow hammer startup times (1.3+ seconds)
Summary: Slow hammer startup times (1.3+ seconds)
Keywords:
Status: CLOSED NEXTRELEASE
Alias: None
Product: Red Hat Satellite 6
Classification: Red Hat
Component: Hammer
Version: 6.0.3
Hardware: Unspecified
OS: Unspecified
high
medium vote
Target Milestone: Unspecified
Assignee: Tomas Strachota
QA Contact: Roman Plevka
URL: http://projects.theforeman.org/issues...
Whiteboard:
: 1105535 (view as bug list)
Depends On: 1315660
Blocks: 1122832
TreeView+ depends on / blocked
 
Reported: 2014-07-24 07:10 UTC by Dominic Cleal
Modified: 2017-08-01 20:01 UTC (History)
9 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-08-01 20:01:20 UTC


Attachments (Terms of Use)


Links
System ID Priority Status Summary Last Updated
Foreman Issue Tracker 6761 None None None 2016-04-22 16:03:41 UTC
Foreman Issue Tracker 14092 None None None 2016-07-28 09:04:36 UTC

Description Dominic Cleal 2014-07-24 07:10:59 UTC
Description of problem:
When running "hammer --help", it's taking in excess of 1.3 seconds.  This makes it inefficient for use in a shell script, particularly when needing to retrieve IDs or run checks in other commands.

Version-Release number of selected component (if applicable):
rubygem-hammer_cli-0.1.1-5.el6sat
rubygem-hammer_cli_foreman-0.1.1-9.el6sat

How reproducible:
Always

Steps to Reproduce:
1. time hammer --help
2.
3.

Actual results:
>= 1.3 seconds

Expected results:
< 0.5 seconds?

Comment 1 Dominic Cleal 2014-07-24 07:11:15 UTC
Created redmine issue http://projects.theforeman.org/issues/6761 from this bug

Comment 4 Bryan Kearney 2014-08-06 12:05:08 UTC
Moving to POST since upstream bug http://projects.theforeman.org/issues/6761 has been closed
-------------
Tomáš Strachota
Most time consuming turned out to be command and option definition that takes place at class level. Lazy loading of subcommands strips most of the unnecessary requires.

My measurements showed times slightly <0.5s for hammer -h (or around 0.8 when running in bundler).

https://github.com/theforeman/hammer-cli/pull/126
https://github.com/theforeman/hammer-cli-foreman/pull/139
https://github.com/Katello/hammer-cli-katello/pull/210


-------------
Anonymous
Applied in changeset commit:hammer-cli-foreman|4fbd36b414aaf030e9dfda79fe4ccdd304d9faa7.

Comment 5 Tazim Kolhar 2014-10-17 08:01:03 UTC
VERIFED :

# rpm -qa | grep rubygem-hammer_cli
rubygem-hammer_cli_foreman_tasks-0.0.3-2.201409091410gitc96619d.git.0.37f3704.el6.noarch
rubygem-hammer_cli_foreman-0.1.3-1.201410151235gitbc8c449.el6.noarch
rubygem-hammer_cli_katello-0.0.6-1.201410161327gite14cd51.git.0.a8188a8.el6.noarch
rubygem-hammer_cli-0.1.3-1.201409240954gitf3c47c7.el6.noarch
rubygem-hammer_cli_import-0.10.4-1.el6.noarch


# time hammer --help

real	0m6.881s
user	0m0.684s
sys	0m0.241s

Comment 6 Dominic Cleal 2014-10-17 08:08:10 UTC
(In reply to Dominic Cleal from comment #0)
> Actual results:
> >= 1.3 seconds
> 
> Expected results:
> < 0.5 seconds?

(In reply to Tazim Kolhar from comment #5)
> # time hammer --help
> 
> real	0m6.881s

6 is greater than 0.5 seconds... in fact, it's worse than the 1.3 seconds I noted in comment #0.  Why is that verified?

Comment 7 Dominic Cleal 2014-10-17 12:45:05 UTC
I'd like a second verification please for the reason in comment #6.  It might be best to establish a baseline of your installation on 6.0.4 too.

Comment 8 Tazim Kolhar 2014-11-14 14:09:40 UTC
FAILEDQA

# rpm -qa | grep foreman
foreman-selinux-1.8.0-0.develop.201410280941git10de1c5.el6.noarch
foreman-1.8.0-0.develop.201411131901gitd5f92b3.el6.noarch
ruby193-rubygem-foreman_hooks-0.3.7-2.el6.noarch
qe-foreman-rhel65.usersys.redhat.com-foreman-client-1.0-1.noarch
qe-foreman-rhel65.usersys.redhat.com-qpid-client-cert-1.0-1.noarch
foreman-ovirt-1.8.0-0.develop.201411131901gitd5f92b3.el6.noarch
qe-foreman-rhel65.usersys.redhat.com-apache-1.0-1.noarch
ruby193-rubygem-foreman_docker-0.2.0-2.el6.noarch
rubygem-hammer_cli_foreman-0.1.3-1.201411121216git9381fc5.el6.noarch
ruby193-rubygem-foreman_discovery-1.4.0-2.el6.noarch
foreman-libvirt-1.8.0-0.develop.201411131901gitd5f92b3.el6.noarch
qe-foreman-rhel65.usersys.redhat.com-parent-cert-1.0-1.noarch
ruby193-rubygem-foreman_bootdisk-4.0.0-1.el6.noarch
foreman-proxy-1.8.0-0.develop.201411121327gitab6edc2.el6.noarch
qe-foreman-rhel65.usersys.redhat.com-puppet-client-1.0-1.noarch
foreman-compute-1.8.0-0.develop.201411131901gitd5f92b3.el6.noarch
foreman-gce-1.8.0-0.develop.201411131901gitd5f92b3.el6.noarch
rubygem-hammer_cli_foreman_tasks-0.0.3-2.201409091410gitc96619d.git.0.37f3704.el6.noarch
qe-foreman-rhel65.usersys.redhat.com-foreman-proxy-1.0-1.noarch
qe-foreman-rhel65.usersys.redhat.com-qpid-broker-1.0-1.noarch
foreman-postgresql-1.8.0-0.develop.201411131901gitd5f92b3.el6.noarch
foreman-vmware-1.8.0-0.develop.201411131901gitd5f92b3.el6.noarch
foreman-release-1.8.0-0.develop.201411131901gitd5f92b3.el6.noarch
ruby193-rubygem-foreman-tasks-0.6.10-1.el6.noarch

# time hammer --help

real	0m1.532s
user	0m0.689s
sys	0m0.297s


1 > 0.5

# hammer --version
 
hammer (0.1.3)
 * hammer_cli_import (0.10.4)
 * hammer_cli_katello (0.0.6)
 * hammer_cli_foreman (0.1.3)

Comment 9 Peter Vreman 2015-07-17 16:20:29 UTC
With Sat6.1.0 for me it is still 2+ seconds

# time hammer --help > /dev/null

real    0m2.281s
user    0m1.942s
sys     0m0.336s

# time hammer --version
hammer (0.1.4.11)
 * hammer_cli_foreman (0.1.4.14)
 * hammer_cli_foreman_bootdisk (0.1.2.7)
 * hammer_cli_foreman_discovery (0.0.1.10)
 * hammer_cli_foreman_docker (unknown version)
 * hammer_cli_gutterball (unknown version)
 * hammer_cli_import (0.10.17)
 * hammer_cli_katello (0.0.7.15)

real    0m2.219s
user    0m1.892s
sys     0m0.326s

Comment 10 Tomas Strachota 2015-11-30 13:56:20 UTC
I did some testing for Sat 6.1.4 on RHEL 7.1 and it seems to be a bit better:

time hammer --help > /dev/null
real	0m1.584s
user	0m1.453s
sys	0m0.130s

time hammer --version > /dev/null
real	0m1.532s
user	0m1.408s
sys	0m0.123s

Some deeper benchmarking discovered following pain points:
- Loading translations and searching for them in multiple FastGettext domains is quite time consuming.
- Requiring 'hammer_cli' library itself takes about 0.5s. One of the reasons seems to be that loading the 'restclient' dependency takes about 0.3s


I did some measurements with multi-domain translation switched off: 

time hammer --help > /dev/null
real	0m1.109s
user	0m1.017s
sys	0m0.092s

time hammer --version > /dev/null
real	0m1.080s
user	0m0.994s
sys	0m0.085s

Comment 11 Tomas Strachota 2016-03-08 11:34:40 UTC
I added a dependent bug for the multidomain translations performance problem as it's one of the steps towards better performance:
https://bugzilla.redhat.com/show_bug.cgi?id=1315660

Comment 12 Mike McCune 2016-03-13 21:30:21 UTC
With pre-Beta builds of 6.2 I'm seeing between 0.5 and 1.5 seconds:

real	0m0.743s
real	0m1.582s
real	0m0.673s

on various hardware

Comment 16 Roman Plevka 2016-05-13 15:03:57 UTC
FAILEDQA

sat 6.2.0 Beta GA11

I'm seeing times between 1.9 and 2.0s

real	0m2.019s
user	0m1.744s
sys	0m0.264s

Comment 18 Peter Vreman 2016-06-16 16:21:15 UTC
As initiator of the original request to create this BZ. For me the results are acceptable now for adhoc commandline usage.

The initial latency as can be seen with --version and --help is not perfect, but good enough. Also the rest of the commands that really request and present content are feeling as quick responses.

For real performance in automation the API can be used. It is much faster as shown below with the content view listing. Using the API also prevents overhead of date structure handling to generate output by hammer and then parse the output in the automation script again.


[crash] root@li-lc-1578:~# time hammer --version > /dev/null

real    0m1.380s
user    0m1.213s
sys     0m0.155s
[crash] root@li-lc-1578:~# time hammer --help > /dev/null

real    0m1.413s
user    0m1.243s
sys     0m0.157s

[crash] root@li-lc-1578:~# time hammer -c/opt/hoici/etc/sat6/hammer-hoici.yaml product list --organization=Hilti --per-page=9999 | wc -l
41

real    0m3.600s
user    0m1.343s
sys     0m0.163s

[crash] root@li-lc-1578:~# time hammer -c/opt/hoici/etc/sat6/hammer-hoici.yaml content-view list --organization=Hilti --per-page=9999 | wc -l
28

real    0m2.210s
user    0m1.575s
sys     0m0.189s

Compare with the API it is still slow

[crash] root@li-lc-1578:~# time curl -K /opt/hoici/etc/sat6/curl-hoici.conf "-HContent-Type: application/json" "-d{\"per_page\":9999}" -XGET https://localhost/katello/api/v2/content_views | wc -c
95913

real    0m0.380s
user    0m0.039s
sys     0m0.028s

Comment 19 Bryan Kearney 2016-10-07 13:51:27 UTC
*** Bug 1105535 has been marked as a duplicate of this bug. ***

Comment 20 Bryan Kearney 2017-02-09 20:46:58 UTC
This apepears to be improved for 6.3. I am moving this to POST and removing the FailedQA flag.

Comment 24 Bryan Kearney 2017-08-01 20:01:20 UTC
The fix to this bug will be delivered with release 6.3 of Satellite.


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