JRuby on Rails: Performance Issue when rendering Views

Ruby JRuby
1

Hey,

I have a problem: We (i.e. my company) is right in the middle of
preparing
the live release of our first major project for a client. We’re using
JRuby
1.7.2 running Rails on a Tomcat 6 Application Server under Debian
Squeeze
with Java 6. The application is basically a small search engine which
wraps
a SOLR-Server with a nicer interface, presenting the enduser certain
local
Offers within their reach, displaying the locations as well.

So far, performance was fine (“good enough”) as far as we could tell,
but
that was before we did our load tests.

Long story short: My main Problem right now is the view rendering, which
is
terribly slow:

INFO: Rendered layouts/_footer.html.erb (37.0ms)
INFO: Rendered base/_messages.html.erb (0.0ms)
INFO: Rendered search/_offer.html.erb (33.0ms)
INFO: Rendered search/_offer.html.erb (27.0ms)
INFO: Rendered search/_offer.html.erb (26.0ms)
INFO: Rendered search/_offer.html.erb (26.0ms)
INFO: Rendered search/_offer.html.erb (22.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (178.0ms)
INFO: Rendered search/_offer.html.erb (28.0ms)
INFO: Rendered search/_offer.html.erb (27.0ms)
INFO: Rendered search/_offer.html.erb (26.0ms)
INFO: Rendered search/_offer.html.erb (27.0ms)
INFO: Rendered search/_offer.html.erb (20.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (168.0ms)
INFO: Rendered search/_offer.html.erb (27.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (19.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (174.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (26.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (20.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (160.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (26.0ms)
INFO: Rendered search/_offer.html.erb (23.0ms)
INFO: Rendered search/_offer.html.erb (18.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (156.0ms)
INFO: Rendered search/_offer.html.erb (23.0ms)
INFO: Rendered search/_offer.html.erb (23.0ms)
INFO: Rendered search/_offer.html.erb (23.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (18.0ms)
INFO: Rendered search/_infowindow.html.erb (0.0ms)
INFO: Rendered search/_shop.html.erb (150.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (28.0ms)
INFO: Rendered search/_offer.html.erb (31.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (168.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (29.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (19.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (158.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (19.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (156.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (20.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (155.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (35.0ms)
INFO: Rendered search/_offer.html.erb (20.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (167.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (26.0ms)
INFO: Rendered search/_offer.html.erb (20.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (159.0ms)
INFO: Rendered search/_offer.html.erb (26.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (23.0ms)
INFO: Rendered search/_offer.html.erb (23.0ms)
INFO: Rendered search/_offer.html.erb (18.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (156.0ms)
INFO: Rendered search/_offer.html.erb (26.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (19.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (154.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (34.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (19.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (164.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (19.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (155.0ms)
INFO: Rendered search/_offer.html.erb (26.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (19.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (159.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (19.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (153.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (35.0ms)
INFO: Rendered search/_offer.html.erb (26.0ms)
INFO: Rendered search/_offer.html.erb (23.0ms)
INFO: Rendered search/_offer.html.erb (19.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (167.0ms)
INFO: Rendered search/_offer.html.erb (26.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (26.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (20.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (161.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (20.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (155.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (19.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (154.0ms)
INFO: Rendered search/_offer.html.erb (34.0ms)
INFO: Rendered search/_offer.html.erb (28.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (19.0ms)
INFO: Rendered search/_infowindow.html.erb (0.0ms)
INFO: Rendered search/_shop.html.erb (169.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (19.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (155.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (18.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_shop.html.erb (161.0ms)
INFO: Rendered search/search.html.erb within layouts/application
(9703.0ms)
INFO: Rendered base/_top_menu.html.erb (23.0ms)
INFO: Rendered layouts/_header.html.erb (100.0ms)
INFO: Rendered base/_bottom_menu.html.erb (10.0ms)
INFO: Rendered layouts/_footer.html.erb (31.0ms)
INFO: Rendered home/index.html.erb within layouts/home (29.0ms)
INFO: Rendered base/_top_menu.html.erb (34.0ms)
INFO: Rendered layouts/_header_start.html.erb (60.0ms)
INFO: Rendered base/_bottom_menu.html.erb (11.0ms)
INFO: Rendered layouts/_footer.html.erb (28.0ms)

It’s the list of search results. In summation, the rendering takes about
ten 10 seconds on average, which is far too long considering everything
else (ActiveRecord/SOLr query) takes about .5 to 1 second. MRI runs fine
btw. the whole thing renders in about 2-3 seconds which is okay. Funny
enough, using WEBrick on JRuby locally takes about 4-6 seconds. The
views
do not contain any voodoo, as in calling to the database and what not.

Aside from asking here I already looked around a bit and found several
performance tips for JRuby (including the wiki and a stackoverflow
answer)
which all seem to recommend increasing memory options for Tomcat and
JRuby
through options. Problem is, I am not a experienced administrator and i
am
pretty new to Tomcat.

So, could anyone of you give me a starting point/any other performance
tips? I have full access to a copy of the acceptance/production server,
so
i can basically play around as much as I want.

I’d really like to see going this project into production with JRuby
instead of switching to MRI.

Anyway,

thanks,

flo

2

Hi Florian,

just checking some basics: Are you using a single shared runtime in
threadsafe mode? (either check your warbler config or the log when
tomcat starts up)

regards
felix

On Feb 15, 2013, at 8:18 AM, Florian K. wrote:

INFO: Rendered search/_offer.html.erb (33.0ms)
INFO: Rendered search/_offer.html.erb (20.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_shop.html.erb (158.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (18.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_shop.html.erb (167.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (34.0ms)
INFO: Rendered search/_offer.html.erb (19.0ms)
INFO: Rendered base/_top_menu.html.erb (23.0ms)

flo

–
Felix Gilcher
Geschftsfhrer

m. +49 172 840 88 28

asquera GmbH
Ohlauer Strae 43
D-10999 Berlin

AG Charlottenburg, HRB 140808 B
Geschftsfhrung: Felix Gilcher, Florian G.

3

just checked:

INFO: jruby 1.7.2 (1.9.3p327) 2013-01-04 302c706 on Java HotSpot™
64-Bit
Server VM 1.7.0-b147 [linux-amd64]
INFO: using a shared (threadsafe!) runtime

I switched to Java 7 just to try it out. did not do a thing.

4

Addendum: After experimenting with restricting the number of partials (i
resolved them and now the whole page is one big partial (layout and
headers
being the others) nothing changed.

5

Maybe try using tomcat 7 and java 7?

As for increasing memory you can make a setenv.sh file in your tomcat
bin directory and then place something like this in it:

export JAVA_OPTS="-Xmx1024m"

6

It’s Rails 3.2.12 and i am running on tomcat 6 for now - i tried it
locally
with tomcat7 but again, no changes.

I’ll try using tomcat7 on debian this weekend.

7

Also what version rails are you using?

8

Have you cracked open a profiler?

Might give some insight into what exactly is so expensive in rendering
those views.

From: Florian K. <[email protected]mailto:[email protected]>
Reply-To: “[email protected]mailto:[email protected]”
<[email protected]mailto:[email protected]>
Date: Friday, February 15, 2013 9:55 AM
To: “[email protected]mailto:[email protected]”
<[email protected]mailto:[email protected]>
Subject: Re: [jruby-user] JRuby on Rails: Performance Issue when
rendering Views

It’s Rails 3.2.12 and i am running on tomcat 6 for now - i tried it
locally with tomcat7 but again, no changes.

I’ll try using tomcat7 on debian this weekend.

On Fri, Feb 15, 2013 at 3:46 PM, Michael A.
<[email protected]mailto:[email protected]> wrote:
Also what version rails are you using?

On Fri, Feb 15, 2013 at 9:32 AM, Alex T.
<[email protected]mailto:[email protected]> wrote:
Maybe try using tomcat 7 and java 7?

As for increasing memory you can make a setenv.sh file in your tomcat
bin directory and then place something like this in it:

export JAVA_OPTS=“-Xmx1024m”

On Feb 15, 2013, at 5:53 AM, Florian K.
<[email protected]mailto:[email protected]> wrote:

Addendum: After experimenting with restricting the number of partials (i
resolved them and now the whole page is one big partial (layout and
headers being the others) nothing changed.

On Fri, Feb 15, 2013 at 9:59 AM, Florian K.
<[email protected]mailto:[email protected]> wrote:
just checked:

INFO: jruby 1.7.2 (1.9.3p327) 2013-01-04 302c706 on Java HotSpot™
64-Bit Server VM 1.7.0-b147 [linux-amd64]
INFO: using a shared (threadsafe!) runtime

I switched to Java 7 just to try it out. did not do a thing.

On Fri, Feb 15, 2013 at 9:38 AM, Felix Gilcher
<[email protected]mailto:[email protected]> wrote:
Hi Florian,

just checking some basics: Are you using a single shared runtime in
threadsafe mode? (either check your warbler config or the log when
tomcat starts up)

regards
felix

On Feb 15, 2013, at 8:18 AM, Florian K. wrote:

INFO: Rendered search/_offer.html.erb (33.0ms)
INFO: Rendered search/_offer.html.erb (20.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_shop.html.erb (158.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (18.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_infowindow.html.erb (1.0ms)
INFO: Rendered search/_offer.html.erb (24.0ms)
INFO: Rendered search/_shop.html.erb (167.0ms)
INFO: Rendered search/_offer.html.erb (25.0ms)
INFO: Rendered search/_offer.html.erb (34.0ms)
INFO: Rendered search/_offer.html.erb (19.0ms)
INFO: Rendered base/_top_menu.html.erb (23.0ms)

flo

–
Felix Gilcher
Geschftsfhrer

m. +49 172 840 88 28tel:%2B49%20172%20840%2088%2028

asquera GmbH
Ohlauer Strae 43
D-10999 Berlin

AG Charlottenburg, HRB 140808 B
Geschftsfhrung: Felix Gilcher, Florian G.

9

I agree that increasing the JVM’s memory setting would be a good thing
to try.

I’d also be curious to poke around the system to see various things:

“free -h” will show you the total and available memory in
“human-readable” format. I’d be interested to see how constrained the
system is regarding memory. JRuby running will consume more memory than
MRI Ruby, and if memory is scarce it could trigger swapping or otherwise
slow the system.

“top” shows you several things, among them, the amount of CPU used by
the running processes. It would be interesting to see how much CPU is
used by your server when it’s rendering the page.

Are the resources being loaded and sent to the web client all on your
server, or is there much that has to be fetched over the network? (It
shouldn’t matter, but it would be interesting to know.) Is there
anything unusual about your filesystem or network?

Do you have any kind of security software running that could slow it
down (e.g. SELinux)?

Also, what kind of machine is this running on? Anything notable about
it? Have you tried the test on other machines?

Another useful tool is jvisualvm, which comes standard with the Oracle
JDK’s, and is separately available for the Mac. When you run it, it
shows you the running JVM’s on your system. You can select one and see
various kinds of information about it, including Java version and
runtime arguments, and live graphs of CPU use, thread activity, number
of classes loaded, and heap activity.

  • Keith

Keith R. Bennett

10

And just a quick check via top:

Java uses 1 core at 100% ad about 45% memory. Result:

Completed 200 OK in 31707ms (Views: 10355.0ms | ActiveRecord: 1135.0ms |
Solr: 277.0ms)

AR takes slightly longer currently, as the DB Server being used is being
backed up at the moment.

11

Florian -

It’s not clear to me – you ran this on 2 different machines? A 2 GB
VM, and a 16 GB system, and they both had the same result? And the 100%
CPU and timings were on which one?

Although 2 GB might be plenty for an MRI server, it may not be enough
for JRuby. I suspect that Solr might be rather memory intensive, and
it might be important to up the heap size of the JVM; 2 GB would be a
good number to try; but then you wouldn’t have room for it on your VM.

I’d suggest trying it on your server by increasing the -Xmx1024m to
-Xmx2048m or something like that.

It would be interesting to see how much of that 100% CPU usage is used
by garbage collection. JVisualVM will show that information in a “GC
activity” percentage above the CPU graph in the Monitor panel.

By the way, when you ran this on MRI, how did you run Solr?

  • Keith
12

The box is virtual machine, nothing different from other virtual text
boxes
we have in the company.

Some stats:

CPUs:
Intel® Xeon® CPU E5620 @ 2.40GHz, 2400 MHz
Intel® Xeon® CPU E5620 @ 2.40GHz, 2400 MHz

Memory Size: 2 GB

Tomcat6 currently runs with these options:

JAVA_OPTS="-Djava.awt.headless=true -Xss512m -Xmx1024m
-XX:+UseConcMarkSweepGC"

We have our application on another server - the production environment.
Out
of my head i can’t give you any configuration - but i know it’s 16GB of
RAM
available.

I used VisualVM already for local development. I know it can be used to
profile remote applications, i just have to find out how :slight_smile:

13

Florian -

Are the JRuby/Rails app and Solr in separate JVM’s? (When you say “on
that Tomcat” do you mean the same running Tomcat or are they separate
invocations of Tomcat?)

Regarding “MRI runs fine btw. the whole thing renders in about 2-3
seconds which is okay.”, which machine was this?

+1 for upping the RAM on your testserver; I’m interested to see if that
helps. I guess you’ll experiment with upping the JVM’s memory too as
per Alex’s suggestion, right? And you might then have enough RAM to run
jvisualvm on testserver to see more about what’s going on.

  • Keith
14

Just an overview:

I have three environments to work with:

  • local; this is my macbook (16GB ram, 2,3ghz i7), i usually develop on
    MRI
    using thin as the server; SOLR is run on a Tomcat7, i am using sunspot
    to
    talk to it from Rails, but for some reason i could not use the
    development
    server the gem ships with
  • testserver: Debian Squeeze, 2 GB RAM; JRuby 1.7.2 run on Tomcat6; Java
    6;
    SOLR is also run on that Tomcat
  • production: Debian Squeeze, 16GB RAM; JRuby 1.7.2 run on Tomcat6; SOLR
    is
    run on the same Tomcat

I have no access to the production system. The issues with view
rendering
occur on test and production environments.

I’ll probably try to get more RAM for the testserver on monday, just to
try.

15

Keith -

they run on the same Tomcat. I testet MRI locally on my macbook and on
the
testserver (via apache passenger).

16

Excellent! Glad to hear it.

  • Keith
17

Excellent! Glad to hear it.

  • Keith
18

Quick update:

giving tomcat more memory seems to resolve the issue. The app runs
smoothly
:slight_smile:

thank you all for the support!

lg

flo