Very slow startup of web / http manager

[ieugen]

Hello,

I have configured gitblit on my machine and all was well until now. It seems whenever I start /restart the service it takes very long time to start SSH Manger and the web gui.

As you can see, it takes Started @136214ms to start =136 seconds

May 16 19:32:39 netdava.com java[2863]: 2016-05-16 19:32:39 [INFO ] ----[com.gitblit.manager.IServicesManager]----
May 16 19:32:39 netdava.com java[2863]: 2016-05-16 19:32:39 [INFO ] Federation passphrase is blank! This server can not be PULLED from.
May 16 19:32:39 netdava.com java[2863]: 2016-05-16 19:32:39 [INFO ] Fanout PubSub service is disabled.
May 16 19:32:39 netdava.com java[2863]: 2016-05-16 19:32:39 [INFO ] Git Daemon is listening on 0.0.0.0:9418
^[^[^[

May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ] SSH Daemon (NIO2) is listening on 0.0.0.0:29418
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ]
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ] ----[com.gitblit.manager.IFilestoreManager]----
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ] No filestore metadata file found
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ]
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ] ----[com.gitblit.manager.IPluginManager]----
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ] PF4J version 1.7.1 in 'deployment' mode
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ] Enabled plugins: []
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ] Disabled plugins: []
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ] No plugins
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ]
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ] All managers started.
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ]
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ] [GitBlitWebApp] init: Wicket core library initializer
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ] [GitBlitWebApp] init: Wicket extensions initializer
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ] [GitBlitWebApp] Started Wicket version 1.4.22 in deployment mode
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ] Started o.e.j.w.WebAppContext@47da3952{/,file:/opt/gitblit/data/temp/webapp/,AVAILABLE}{file:/opt/gitblit/gitblit-1.7.1/gitblit.jar}
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ] Started ServerConnector@4a254d75{HTTP/1.1}{localhost:8197}
May 16 19:34:51 netdava.com java[2863]: 2016-05-16 19:34:51 [INFO ] Started @136214ms

May 16 19:35:25 netdava.com java[2863]: 2016-05-16 19:35:25 [INFO ] Loading properties files from jar:file:/opt/gitblit/gitblit-1.7.1/gitblit.jar!/com/gitblit/wicket/GitBlitWebApp_en.properties
May 16 19:35:25 netdava.com java[2863]: 2016-05-16 19:35:25 [INFO ] Loading properties files from jar:file:/opt/gitblit/gitblit-1.7.1/gitblit.jar!/com/gitblit/wicket/GitBlitWebApp.properties
May 16 19:35:25 netdava.com java[2863]: 2016-05-16 19:35:25 [INFO ] Loading properties files from jar:file:/opt/gitblit/gitblit-1.7.1/ext/wicket-1.4.22.jar!/org/apache/wicket/Application.properties
May 16 19:35:25 netdava.com java[2863]: 2016-05-16 19:35:25 [INFO ] 12 repository models loaded for ieugen in 65 msecs

[gitblit]

I see you are loading 12 repos. How large are they? Are you serving your repos from a network share? What hardware are you running Gitblit on? How much memory does your box have? What is your Java heap setting?

[ieugen]

Hello,

Thank you for the quick response. The repositories are not large - but why should that count? Are you pre-loading the repos? This should be done lazy, no?

I'm running on Debian - Digital Ocean droplet - SSD with 1gb of RAM. Restarted gitblit to watch RAM usage - stayed at 392 MB. Files are local.

The strange thing is that now it works ok. I have no idea what changed. I did reboot the machine to fix it but it was still loading slow.

Now, I logged to get information for a response and decided to restart the service just because. Now it loads fast.

It might do some network checks when it starts and the network was running slow, and now it's ok?

$ cat /etc/default/gitblit 
MODE=service
#-Dlog4j.configuration=file:/opt/gitblit/data/log4j.properties  
JAVA_OPTS="-Xmx128M -Dcom.unboundid.ldap.sdk.debug.enabled=true -Dcom.unboundid.ldap.sdk.debug.level=DEBUG"

$ cat /etc/systemd/system/gitblit.service 
[Unit]
Description= Gitblit server
After=network.target remote-fs.target

[Service]
User=gitblit
WorkingDirectory=/opt/gitblit/current
EnvironmentFile=/etc/default/gitblit

ExecStart=/usr/bin/java $JAVA_OPTS -jar /opt/gitblit/current/gitblit.jar --baseFolder /opt/gitblit/data --shutdownPort=-1
ExecStop=/usr/bin/java $JAVA_OPTS -jar /opt/gitblit/current/gitblit.jar --baseFolder /opt/gitblit/data --stop 

[Install]
WantedBy=multi-user.target

p.s. You can use the files for systemd config examples. p.s. The reason I'm restarting the service is that I'm working on LDAP auth and things don't seem to work ok so I'm updating configs and restart - to login.

[gitblit]

The repositories are not large - but why should that count? Are you pre-loading the repos?

Yes. Pre-loading & caching. This is to reduce request processing time.

[ieugen]

Could you do that in a worker thread or lazy during startup?

[gitblit]

Possibly, but we have not identified this as the source of your slowdown.​

[ieugen]

True :). Thanks again for the support.

[shokkas]

Hi, Thanks to this thread I now understand my server's slowness. Preloading & caching >300 repo, some quite large can be VERY lengthy.

Any way to shorten the loading time?

[gitblit]

• You could disable caching altogether (not recommended).
• You could shorten the cache window (web.activityCacheDays read notes!)
• You could submit a PR that preloads/caches in a worker thread

[bviktor]

I'm pretty sure something's messed up with caching. On a fresh install (with the existing several hundred repos) it's like half a minute. Then eventually it slows down. Now I clocked it, 18 minutes.

Then I changed web.activityCacheDays to 3 (from the default 14), and it went down to 16 seconds. From 1113 seconds. Speaking of nonlinear...