Bug 1114910 - [origin_cartridge_213] It will take much longer than before to create jenkins server after upgraded to 1.554
Summary: [origin_cartridge_213] It will take much longer than before to create jenkins...
Keywords:
Status: CLOSED CANTFIX
Alias: None
Product: OpenShift Online
Classification: Red Hat
Component: Image
Version: 2.x
Hardware: Unspecified
OS: Unspecified
medium
low
Target Milestone: ---
: ---
Assignee: Ben Parees
QA Contact: libra bugs
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2014-07-01 09:12 UTC by Meng Bo
Modified: 2015-05-15 00:43 UTC (History)
4 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2014-08-21 17:03:42 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)
jenkins_gear_log (3.27 KB, text/plain)
2014-07-03 03:25 UTC, Meng Bo
no flags Details
platform_trace_log (58.75 KB, text/plain)
2014-07-03 03:25 UTC, Meng Bo
no flags Details
platform_log (32.47 KB, text/plain)
2014-07-03 03:26 UTC, Meng Bo
no flags Details

Description Meng Bo 2014-07-01 09:12:58 UTC
Description of problem:
Create jenkins on devenv_4925 which has jenkins package upgraded to 1.554.2. Calculate the operation time and compare it on the devenv-stage_897 which has old version jenkins.

It will cost much longer time than before.

devenv-stage_897:
real	0m29.967s
user	0m8.566s
sys	0m1.693s

devenv_4925:
real	1m6.289s
user	0m18.251s
sys	0m4.185s


Found some waiting log in platform-trace.log during app creating for new version as below, which dose not exist in devenv-stage_897:

July 01 08:37:09 INFO oo_spawn running /sbin/runuser -s /bin/sh 53b2ab64e6ed66115a0001b1 -c "exec /usr/bin/runcon 'unconfined_u:system_r:openshift_t:s0:c0,c1001' /bin/sh -c \"set -e; /var/lib/openshift/53b2ab64e6ed66115a0001b1/jenkins/bin/control start \"": {:unsetenv_others=>true, :close_others=>true, :in=>"/dev/null", :chdir=>"/var/lib/openshift/53b2ab64e6ed66115a0001b1/jenkins", :out=>#<IO:fd 13>, :err=>#<IO:fd 10>}
July 01 08:37:09 INFO oo_spawn buffer(12/) Starting jenkins cartridge

July 01 08:37:21 INFO oo_spawn buffer(12/) Waiting ...

July 01 08:37:23 INFO oo_spawn buffer(12/) Waiting ...

July 01 08:37:25 INFO oo_spawn buffer(12/) Waiting ...

July 01 08:37:27 INFO oo_spawn buffer(12/) Waiting ...

July 01 08:37:29 INFO oo_spawn buffer(12/) Waiting ...

July 01 08:37:31 INFO oo_spawn buffer(12/) Waiting ...

July 01 08:37:33 INFO oo_spawn buffer(12/) Waiting ...

July 01 08:37:36 INFO oo_spawn buffer(12/) Waiting ...

July 01 08:37:38 INFO oo_spawn buffer(12/) Waiting ...

July 01 08:37:40 INFO oo_spawn buffer(12/) Waiting ...

July 01 08:37:42 INFO oo_spawn buffer(12/) Waiting ...

July 01 08:37:44 INFO oo_spawn buffer(12/) Waiting ...

July 01 08:37:54 INFO oo_spawn buffer(12/) Waiting ...


Then I tried to deploy the jenkins with some minor changes, and it does not have a significant difference between the two versions. And the jenkins start without so many waiting on both envs.

devenv-stage_897:
real	0m17.860s
user	0m0.012s
sys	0m0.009s

devenv_4925:
real	0m19.864s
user	0m0.007s
sys	0m0.007s


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

How reproducible:
always

Steps to Reproduce:
1. Create jenkins server and calculate the time.
2.
3.

Actual results:
It will take much longer than the old jenkins version.

Expected results:
It should not take so long.

Additional info:

Comment 1 Ben Parees 2014-07-01 22:04:39 UTC
I'm only seeing a 10-12 second increase, but it's definitely there.  Analysis of the logs shows the additional time appears to be spent here:
Jul 01, 2014 9:56:37 PM jenkins.InitReactorRunner$1 onAttained
INFO: Started initialization
Jul 01, 2014 9:56:49 PM jenkins.InitReactorRunner$1 onAttained
INFO: Listed all plugins

(in the old jenkins those two log entries were separated by only 2 seconds).

will continue to investigate.

Comment 2 Ben Parees 2014-07-02 20:11:41 UTC
Still only seeing this as 40s in a devenv today, can you check if it's still over 1 minute for you?

If so, please gather the gear logs.

If it is only the 10s increase I found in comment 1, i'm going to close this as cantfix.

Comment 3 Meng Bo 2014-07-03 03:24:02 UTC
Hi Ben, 
The time data in comment#0 were gotten from both m3.medium size instance, they are no change on the latest devenv. 
And I have tried again on devenv_4936 with m3.large, It will cost about 40s to create jenkins server. 
Compare with devenv-stage_897 with m3.large, it will cost about 25s.

Still have about 40% time spent incremental. 

I will add the logs to attachment.


# time rhc app create jenkins jenkins-1 --no-git --no-dns 
Application Options
-------------------
Domain:     bmeng1
Cartridges: jenkins-1
Gear Size:  default
Scaling:    no

Creating application 'jenkins' ... done

  Jenkins created successfully.  Please make note of these credentials:

   User: admin
   Password: XXXXXXXXXX

Note:  You can change your password at: https://jenkins-bmeng1.dev.rhcloud.com/me/configure

Your application 'jenkins' is now available.

  URL:        http://jenkins-bmeng1.dev.rhcloud.com/
  SSH to:     53b503547cf16d07ed000157.rhcloud.com
  Git remote: ssh://53b503547cf16d07ed000157.rhcloud.com/~/git/jenkins.git/

Run 'rhc show-app jenkins' for more details about your app.

real    0m37.677s
user    0m0.462s
sys     0m0.126s

Comment 4 Meng Bo 2014-07-03 03:25:17 UTC
Created attachment 914341 [details]
jenkins_gear_log

Comment 5 Meng Bo 2014-07-03 03:25:51 UTC
Created attachment 914342 [details]
platform_trace_log

Comment 6 Meng Bo 2014-07-03 03:26:18 UTC
Created attachment 914343 [details]
platform_log

Comment 7 Ben Parees 2014-07-07 17:58:52 UTC
These logs show the same thing i'm observing:  additional 13s spent in the jenkins code itself initializing plugins.  This time was not spent in 1.509.

Lowering severity for now as this is not a blocker (it's a one time initialization and the startup time is well within the openshift timeouts) but future areas of exploration include whether there are any changes that can be made to the default jenkins configuration that might affect this startup time.

Comment 8 Ben Parees 2014-07-08 13:43:58 UTC
Just one more datapoint on this, I'm seeing the same behavior when launching jenkins locally, so the new delay is unrelated to the openshift environment.

Comment 9 Balazs Varga 2014-08-21 15:52:17 UTC
@Ben : based on your research I think this can be closed.

Comment 10 Ben Parees 2014-08-21 17:03:42 UTC
@Balazs: Agreed, I don't see us doing anything further with this.


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