ActiveRecord is slower on JRuby than on MRI
-------------------------------------------
Key: JRUBY-2184
URL: http://jira.codehaus.org/browse/JRUBY-2184
Project: JRuby
Issue Type: Bug
Components: Performance
Reporter: Marcin Mielzynski
Thanks to Radoslaw Bulat (radarek on #jruby channel) we've got a set of AR
benchmarks under jruby.
He's running linux, bechmarks are performed with jdk6u4, and MRI 1.8.6 compiled
from source, they have been run on trunk (1.1).
Here are the pasties (content copied below as noformat):
http://pastie.caboo.se/157185
http://pastie.caboo.se/157188
http://pastie.caboo.se/157193
http://pastie.caboo.se/157215 # with logger
http://pastie.caboo.se/157228 # without logger
http://pastie.caboo.se/157234 # logger itself
http://pastie.caboo.se/157237
http://pastie.caboo.se/157246
http://pastie.caboo.se/157272 # new empty AR
http://pastie.caboo.se/157266 # new AR with atts
For the following table:
{noformat}
-----------+------+-----+---------+-----------------+----------------+
| Field | Type | Null | Key | Default | Extra |
+-------------+--------------+------+-----+---------+----------------+
| id | int(11) | NO | PRI | NULL | auto_increment |
| name | varchar(255) | YES | | NULL | |
| description | text | YES | | NULL | |
| created_at | datetime | YES | | NULL | |
| updated_at | datetime | YES | | NULL | |
+-------------+--------------+------+-----+---------+----------------+
{noformat}
{noformat}
Benchmark.bm do |make|
10.times do
make.report do
100_000.times do
Widget.new.valid?
end
end
end
end
=== ruby18
$ ruby1.8 ./lib/script/db.rb
user system total real
4.010000 0.000000 4.010000 ( 4.020835)
3.990000 0.000000 3.990000 ( 4.012227)
3.980000 0.000000 3.980000 ( 3.991904)
4.000000 0.000000 4.000000 ( 4.027158)
4.000000 0.000000 4.000000 ( 4.029483)
3.990000 0.000000 3.990000 ( 3.994495)
4.010000 0.000000 4.010000 ( 4.027560)
4.000000 0.000000 4.000000 ( 4.026101)
4.020000 0.000000 4.020000 ( 4.044257)
3.990000 0.000000 3.990000 ( 4.000114)
=== jruby
$ jruby -J-server -J-Djruby.compile.fastest=true
-J-Djruby.compile.frameless=true ./lib/script/db.rb
user system total real
6.999000 0.000000 6.999000 ( 6.999000)
4.622000 0.000000 4.622000 ( 4.622000)
4.636000 0.000000 4.636000 ( 4.635000)
4.571000 0.000000 4.571000 ( 4.571000)
4.573000 0.000000 4.573000 ( 4.572000)
4.569000 0.000000 4.569000 ( 4.569000)
4.574000 0.000000 4.574000 ( 4.574000)
4.583000 0.000000 4.583000 ( 4.583000)
4.577000 0.000000 4.577000 ( 4.577000)
4.572000 0.000000 4.572000 ( 4.572000)
{noformat}
{noformat}
Benchmark.bm do |make|
10.times do
make.report do
100_000.times do
Widget.new
end
end
end
end
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp$ ruby1.8
./lib/script/db2.rb user system total real
1.450000 0.010000 1.460000 ( 1.477560)
1.440000 0.000000 1.440000 ( 1.452845)
1.450000 0.000000 1.450000 ( 1.455343)
1.450000 0.000000 1.450000 ( 1.468160)
1.450000 0.000000 1.450000 ( 1.467478)
1.440000 0.000000 1.440000 ( 1.449292)
1.450000 0.000000 1.450000 ( 1.449435)
1.440000 0.000000 1.440000 ( 1.466980)
1.450000 0.000000 1.450000 ( 1.456367)
1.450000 0.000000 1.450000 ( 1.449763)
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp$ jruby -J-server
-J-Djruby.compile.fastest=true -J-Djruby.compile.frameless=true
./lib/script/db2.rb
user system total real
3.463000 0.000000 3.463000 ( 3.463000)
2.077000 0.000000 2.077000 ( 2.077000)
2.069000 0.000000 2.069000 ( 2.068000)
2.039000 0.000000 2.039000 ( 2.040000)
2.042000 0.000000 2.042000 ( 2.042000)
2.052000 0.000000 2.052000 ( 2.052000)
2.035000 0.000000 2.035000 ( 2.035000)
2.055000 0.000000 2.055000 ( 2.055000)
2.036000 0.000000 2.036000 ( 2.035000)
2.043000 0.000000 2.043000 ( 2.044000)
{noformat}
{noformat}
Benchmark.bm do |make|
10.times do
w = Widget.new
make.report do
100_000.times do
w.valid?
end
end
end
end
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp$ ruby1.8
./lib/script/db3.rb
user system total real
2.110000 0.000000 2.110000 ( 2.129940)
2.080000 0.000000 2.080000 ( 2.078367)
2.100000 0.000000 2.100000 ( 2.110602)
2.100000 0.000000 2.100000 ( 2.112235)
2.060000 0.000000 2.060000 ( 2.078087)
2.110000 0.000000 2.110000 ( 2.108611)
2.090000 0.000000 2.090000 ( 2.104657)
2.070000 0.000000 2.070000 ( 2.068924)
2.090000 0.000000 2.090000 ( 2.110685)
2.100000 0.000000 2.100000 ( 2.101212)
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp$ jruby -J-server
-J-Djruby.compile.fastest=true -J-Djruby.compile.frameless=true
./lib/script/db3.rb
user system total real
2.911000 0.000000 2.911000 ( 2.911000)
2.118000 0.000000 2.118000 ( 2.119000)
2.027000 0.000000 2.027000 ( 2.027000)
2.031000 0.000000 2.031000 ( 2.031000)
2.107000 0.000000 2.107000 ( 2.106000)
2.059000 0.000000 2.059000 ( 2.060000)
2.072000 0.000000 2.072000 ( 2.072000)
2.051000 0.000000 2.051000 ( 2.052000)
2.062000 0.000000 2.062000 ( 2.062000)
2.074000 0.000000 2.074000 ( 2.073000)
{noformat}
With Logger ON
{noformat}
Benchmark.bm do |make|
10.times do
make.report do
10_000.times do
Widget.find(:all)
end
end
end
end
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp$ ruby1.8
lib/script/db4.rb
user system total real
2.250000 0.150000 2.400000 ( 2.562183)
2.250000 0.140000 2.390000 ( 2.545450)
2.170000 0.200000 2.370000 ( 2.552200)
2.170000 0.200000 2.370000 ( 2.533839)
2.200000 0.180000 2.380000 ( 2.553121)
2.220000 0.160000 2.380000 ( 2.544484)
2.200000 0.180000 2.380000 ( 2.552828)
2.180000 0.160000 2.340000 ( 2.538723)
2.130000 0.210000 2.340000 ( 2.554477)
2.210000 0.150000 2.360000 ( 2.538447)
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp$ jruby -J-server
-J-Djruby.compile.fastest=true -J-Djruby.compile.frameless=true
./lib/script/db4.rb
user system total real
11.654000 0.000000 11.654000 ( 11.653000)
5.945000 0.000000 5.945000 ( 5.944000)
4.035000 0.000000 4.035000 ( 4.035000)
4.137000 0.000000 4.137000 ( 4.138000)
4.010000 0.000000 4.010000 ( 4.010000)
3.979000 0.000000 3.979000 ( 3.980000)
3.909000 0.000000 3.909000 ( 3.910000)
3.920000 0.000000 3.920000 ( 3.921000)
3.896000 0.000000 3.896000 ( 3.896000)
3.892000 0.000000 3.892000 ( 3.892000)
{noformat}
With Logger OFF
{noformat}
Benchmark.bm do |make|
10.times do
make.report do
10_000.times do
Widget.find(:all)
end
end
end
end
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp$ ruby1.8
lib/script/db5.rb user system total real
1.590000 0.100000 1.690000 ( 1.853620)
1.590000 0.080000 1.670000 ( 1.854516)
1.550000 0.140000 1.690000 ( 1.841983)
1.600000 0.100000 1.700000 ( 1.846823)
1.610000 0.100000 1.710000 ( 1.881888)
1.580000 0.120000 1.700000 ( 1.842732)
1.550000 0.120000 1.670000 ( 1.861359)
1.550000 0.120000 1.670000 ( 1.844078)
1.580000 0.110000 1.690000 ( 1.840608)
1.530000 0.130000 1.660000 ( 1.862033)
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp$ jruby -J-server
-J-Djruby.compile.fastest=true -J-Djruby.compile.frameless=true
./lib/script/db5.rb
user system total real
8.040000 0.000000 8.040000 ( 8.040000)
4.005000 0.000000 4.005000 ( 4.005000)
3.169000 0.000000 3.169000 ( 3.169000)
3.126000 0.000000 3.126000 ( 3.125000)
3.187000 0.000000 3.187000 ( 3.188000)
3.168000 0.000000 3.168000 ( 3.168000)
3.116000 0.000000 3.116000 ( 3.116000)
3.141000 0.000000 3.141000 ( 3.141000)
3.122000 0.000000 3.122000 ( 3.122000)
3.131000 0.000000 3.131000 ( 3.131000)
{noformat}
Logger itself
{noformat}
Benchmark.bm do |make|
10.times do
logger = Logger.new("file.log")
make.report do
100_000.times do
logger.debug("hello")
end
end
logger.close
end
end
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp/lib/script$
ruby1.8 logger.rb
user system total real
1.960000 0.460000 2.420000 ( 2.430892)
2.020000 0.420000 2.440000 ( 2.445514)
2.080000 0.360000 2.440000 ( 2.460246)
2.060000 0.400000 2.460000 ( 2.453739)
1.990000 0.450000 2.440000 ( 2.456820)
2.030000 0.420000 2.450000 ( 2.446001)
2.070000 0.370000 2.440000 ( 2.465550)
2.030000 0.400000 2.430000 ( 2.446837)
2.100000 0.360000 2.460000 ( 2.463839)
2.030000 0.420000 2.450000 ( 2.448888)
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp/lib/script$
jruby -J-server -J-Djruby.compile.fastest=true -J-Djruby.compile.frameless=true
logger.rb
user system total real
6.101000 0.000000 6.101000 ( 6.101000)
3.013000 0.000000 3.013000 ( 3.013000)
2.914000 0.000000 2.914000 ( 2.914000)
2.793000 0.000000 2.793000 ( 2.792000)
2.812000 0.000000 2.812000 ( 2.813000)
2.750000 0.000000 2.750000 ( 2.751000)
2.891000 0.000000 2.891000 ( 2.890000)
2.744000 0.000000 2.744000 ( 2.744000)
2.738000 0.000000 2.738000 ( 2.737000)
2.750000 0.000000 2.750000 ( 2.749000)
{noformat}
{noformat}
Benchmark.bm do |make|
10.times do
logger = ActiveSupport::BufferedLogger.new("file.log")
make.report do
100_000.times do
logger.add(ActiveSupport::BufferedLogger::DEBUG, "dupa")
end
end
logger.close
end
end
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp/lib/script$
ruby1.8 buffered_logger.rb
user system total real
0.570000 0.120000 0.690000 ( 0.689881)
0.540000 0.150000 0.690000 ( 0.697821)
0.510000 0.180000 0.690000 ( 0.693132)
0.530000 0.160000 0.690000 ( 0.695423)
0.530000 0.170000 0.700000 ( 0.705588)
0.520000 0.150000 0.670000 ( 0.687026)
0.540000 0.160000 0.700000 ( 0.701501)
0.530000 0.160000 0.690000 ( 0.684573)
0.550000 0.140000 0.690000 ( 0.698574)
0.520000 0.160000 0.680000 ( 0.693477)
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp/lib/script$
jruby -J-server -J-Djruby.compile.fastest=true -J-Djruby.compile.frameless=true
buffered_logger.rb
user system total real
1.887000 0.000000 1.887000 ( 1.887000)
0.991000 0.000000 0.991000 ( 0.990000)
0.945000 0.000000 0.945000 ( 0.944000)
0.793000 0.000000 0.793000 ( 0.794000)
0.834000 0.000000 0.834000 ( 0.834000)
0.818000 0.000000 0.818000 ( 0.818000)
0.804000 0.000000 0.804000 ( 0.804000)
0.808000 0.000000 0.808000 ( 0.808000)
0.801000 0.000000 0.801000 ( 0.801000)
0.803000 0.000000 0.803000 ( 0.804000)
{noformat}
{noformat}
Benchmark.bm do |make|
10.times do
w = Widget.find(:first)
make.report do
10_000.times do
w.attributes # rails makes copy for every call
end
end
end
end
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp$ ruby1.8
./lib/script/ar_attributes.rb
user system total real
0.600000 0.040000 0.640000 ( 0.640588)
0.600000 0.020000 0.620000 ( 0.626348)
0.630000 0.010000 0.640000 ( 0.646735)
0.620000 0.020000 0.640000 ( 0.644046)
0.610000 0.010000 0.620000 ( 0.624194)
0.630000 0.020000 0.650000 ( 0.652418)
0.620000 0.020000 0.640000 ( 0.647553)
0.600000 0.020000 0.620000 ( 0.636091)
0.630000 0.020000 0.650000 ( 0.646214)
0.630000 0.020000 0.650000 ( 0.647887)
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp$ jruby -J-server
-J-Djruby.compile.fastest=true -J-Djruby.compile.frameless=true
./lib/script/ar_attributes.rb
user system total real
3.925000 0.000000 3.925000 ( 3.925000)
1.048000 0.000000 1.048000 ( 1.048000)
1.009000 0.000000 1.009000 ( 1.009000)
0.938000 0.000000 0.938000 ( 0.937000)
0.969000 0.000000 0.969000 ( 0.969000)
0.926000 0.000000 0.926000 ( 0.927000)
0.935000 0.000000 0.935000 ( 0.935000)
0.931000 0.000000 0.931000 ( 0.930000)
0.939000 0.000000 0.939000 ( 0.938000)
0.931000 0.000000 0.931000 ( 0.932000)
{noformat}
new empty AR instance
{noformat}
Benchmark.bm do |make|
10.times do
make.report do
100_000.times do
Widget.new
end
end
end
end
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp$ ruby1.8
./lib/script/ar_creating_new.rb user system total real
1.450000 0.000000 1.450000 ( 1.455953)
1.460000 0.000000 1.460000 ( 1.456910)
1.460000 0.000000 1.460000 ( 1.457109)
1.450000 0.000000 1.450000 ( 1.458126)
1.470000 0.000000 1.470000 ( 1.459992)
1.460000 0.000000 1.460000 ( 1.459783)
1.460000 0.000000 1.460000 ( 1.468527)
1.460000 0.000000 1.460000 ( 1.461333)
1.470000 0.000000 1.470000 ( 1.464491)
1.460000 0.000000 1.460000 ( 1.463433)
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp$ jruby -J-server
-J-Djruby.compile.fastest=true -J-Djruby.compile.frameless=true
./lib/script/ar_creating_new.rb
user system total real
3.560000 0.000000 3.560000 ( 3.559000)
2.109000 0.000000 2.109000 ( 2.110000)
2.109000 0.000000 2.109000 ( 2.109000)
2.061000 0.000000 2.061000 ( 2.061000)
2.056000 0.000000 2.056000 ( 2.056000)
2.053000 0.000000 2.053000 ( 2.054000)
2.057000 0.000000 2.057000 ( 2.057000)
2.057000 0.000000 2.057000 ( 2.057000)
2.056000 0.000000 2.056000 ( 2.056000)
2.053000 0.000000 2.053000 ( 2.054000)
{noformat}
New AR instance constructed with attributes
{noformat}
Benchmark.bm do |make|
10.times do
w = Widget.find(:first)
params = w.attributes
make.report do
10_000.times do
Widget.new(params)
end
end
end
end
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp$ ruby1.8
./lib/script/ar_creating.rb
user system total real
0.760000 0.000000 0.760000 ( 0.757167)
0.730000 0.000000 0.730000 ( 0.732888)
0.760000 0.000000 0.760000 ( 0.756183)
0.760000 0.000000 0.760000 ( 0.758768)
0.730000 0.000000 0.730000 ( 0.732527)
0.750000 0.000000 0.750000 ( 0.760008)
0.760000 0.000000 0.760000 ( 0.762963)
0.730000 0.000000 0.730000 ( 0.734364)
0.760000 0.000000 0.760000 ( 0.755586)
0.750000 0.000000 0.750000 ( 0.754439)
[EMAIL PROTECTED]:~/language-shootout/benchmarks/rails/testapp$ jruby -J-server
-J-Djruby.compile.fastest=true -J-Djruby.compile.frameless=true
./lib/script/ar_creating.rb
user system total real
3.241000 0.000000 3.241000 ( 3.240000)
1.349000 0.000000 1.349000 ( 1.349000)
0.791000 0.000000 0.791000 ( 0.791000)
0.781000 0.000000 0.781000 ( 0.781000)
0.828000 0.000000 0.828000 ( 0.828000)
0.784000 0.000000 0.784000 ( 0.784000)
0.758000 0.000000 0.758000 ( 0.758000)
0.754000 0.000000 0.754000 ( 0.754000)
0.754000 0.000000 0.754000 ( 0.754000)
0.758000 0.000000 0.758000 ( 0.758000)
{noformat}
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://jira.codehaus.org/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
To unsubscribe from this list, please visit:
http://xircles.codehaus.org/manage_email
