A fresh boot of Rails through Webrick easily serves over 100
requests/sec. But during the course of just 100 requests performance
gradually and exponentially slides down towards zero.
Against a non-database-driven controller ("scripts/generate controller
test index"), HTTP requests grow increasingly slower:
$ ab2 -n 100 http://localhost:8080/test/index | grep "^Requests per"
Requests per second: 4.12 [#/sec] (mean)
$ ab2 -n 100 http://localhost:8080/test/index | grep "^Requests per"
Requests per second: 1.46 [#/sec] (mean)
$ ab2 -n 100 http://localhost:8080/test/index | grep "^Requests per"
Requests per second: 1.03 [#/sec] (mean)
But the slowdown is not reflected in the Rails log:
Completed in 0.001328 (753 reqs/sec) | Rendering: 0.000773 (58%)
Completed in 0.001329 (752 reqs/sec) | Rendering: 0.000774 (58%)
Completed in 0.001478 (676 reqs/sec) | Rendering: 0.000810 (54%)
...
Completed in 0.001339 (746 reqs/sec) | Rendering: 0.000752 (56%)
Completed in 0.001306 (765 reqs/sec) | Rendering: 0.000758 (58%)
Completed in 0.001388 (720 reqs/sec) | Rendering: 0.000787 (56%)
In other words, something outside the logic timed by Rails is taking an
increasing amount of time.
But against a database-driven controller -- a very simple one which
triggers a single "select" and outputs a single column value -- the
slowdown at the HTTP level is similar, but a similar slowdown is clearly
reflected inside Rails as well:
$ tail log/development.log -n0 -f | grep "^Compl"
Completed in 0.040410 (24 reqs/sec) | Rendering: 0.028661 (70%) | DB:
0.030061 (74%)
...
Completed in 0.298424 (3 reqs/sec) | Rendering: 0.028794 (9%) | DB:
0.030192 (10%)
In both cases, Ruby is eating memory as if it were candy; before the 300
test requests:
$ ps aufxwww | grep ruby
root 1103 0.0 1.4 15036 13456 pts/160 S+ 22:40 0:00 ruby
script/server -p 8080 -b 0.0.0.0
Afterwards:
$ ps aufxwww | grep ruby
root 1103 0.0 3.5 55216 31936 pts/160 S+ 22:40 1:42 ruby
script/server -p 8080 -b 0.0.0.0
The slowdown and memory hogging is not seen when running with FastCGI
for any of the controllers.
To me this implies that the problem is in Webrick, and that the reason
Rails its grows slower only in the database case is that Webrick is
somehow affecting Rails'' database layer.
The non-database case does not create TCP connections to the database;
so perhaps Webrick is leaking sockets, or is leaking buffers or
structures related to sockets, and this cruft is clogging Ruby''s
networking code.
I''m working with a fresh installation of Rails:
$ gem list --local | grep "^[a-z]"
actionmailer (0.5.0, 0.4.0)
actionpack (1.2.0, 0.9.5)
activerecord (1.4.0, 1.1.0)
rails (0.9.3, 0.8.5)
rake (0.4.15, 0.4.12)
sources (0.0.1)
$ ruby --version
ruby 1.8.2 (2004-12-23) [i386-linux]
$ uname -a
Linux bork 2.6.5 #1 Wed Dec 1 06:23:39 CET 2004 i686 GNU/Linux
Alexander.
On Sun, Jan 09, 2005 at 12:24:27AM +0100, Alexander Staubo wrote:> > [...] > > $ gem list --local | grep "^[a-z]" > actionmailer (0.5.0, 0.4.0) > actionpack (1.2.0, 0.9.5) > activerecord (1.4.0, 1.1.0) > rails (0.9.3, 0.8.5) > rake (0.4.15, 0.4.12) > sources (0.0.1)Check out the latest sources from subversion and run it again. There was recently a fix made where $: would increase in size with every request under webrick. That may be what''s causing your problems. -Scott
I experienced similar difficulties using Webrick. I fixed it by using the --daemon flag when running ./script/server. On Sun, 09 Jan 2005 00:24:27 +0100, Alexander Staubo <alex-uTpLPxngHHI4n3JXwSlx2Q@public.gmane.org> wrote:> A fresh boot of Rails through Webrick easily serves over 100 > requests/sec. But during the course of just 100 requests performance > gradually and exponentially slides down towards zero. > > Against a non-database-driven controller ("scripts/generate controller > test index"), HTTP requests grow increasingly slower: > > $ ab2 -n 100 http://localhost:8080/test/index | grep "^Requests per" > Requests per second: 4.12 [#/sec] (mean) > $ ab2 -n 100 http://localhost:8080/test/index | grep "^Requests per" > Requests per second: 1.46 [#/sec] (mean) > $ ab2 -n 100 http://localhost:8080/test/index | grep "^Requests per" > Requests per second: 1.03 [#/sec] (mean) > > But the slowdown is not reflected in the Rails log: > > Completed in 0.001328 (753 reqs/sec) | Rendering: 0.000773 (58%) > Completed in 0.001329 (752 reqs/sec) | Rendering: 0.000774 (58%) > Completed in 0.001478 (676 reqs/sec) | Rendering: 0.000810 (54%) > ... > Completed in 0.001339 (746 reqs/sec) | Rendering: 0.000752 (56%) > Completed in 0.001306 (765 reqs/sec) | Rendering: 0.000758 (58%) > Completed in 0.001388 (720 reqs/sec) | Rendering: 0.000787 (56%) > > In other words, something outside the logic timed by Rails is taking an > increasing amount of time. > > But against a database-driven controller -- a very simple one which > triggers a single "select" and outputs a single column value -- the > slowdown at the HTTP level is similar, but a similar slowdown is clearly > reflected inside Rails as well: > > $ tail log/development.log -n0 -f | grep "^Compl" > Completed in 0.040410 (24 reqs/sec) | Rendering: 0.028661 (70%) | DB: > 0.030061 (74%) > ... > Completed in 0.298424 (3 reqs/sec) | Rendering: 0.028794 (9%) | DB: > 0.030192 (10%) > > In both cases, Ruby is eating memory as if it were candy; before the 300 > test requests: > > $ ps aufxwww | grep ruby > root 1103 0.0 1.4 15036 13456 pts/160 S+ 22:40 0:00 ruby > script/server -p 8080 -b 0.0.0.0 > > Afterwards: > > $ ps aufxwww | grep ruby > root 1103 0.0 3.5 55216 31936 pts/160 S+ 22:40 1:42 ruby > script/server -p 8080 -b 0.0.0.0 > > The slowdown and memory hogging is not seen when running with FastCGI > for any of the controllers. > > To me this implies that the problem is in Webrick, and that the reason > Rails its grows slower only in the database case is that Webrick is > somehow affecting Rails'' database layer. > > The non-database case does not create TCP connections to the database; > so perhaps Webrick is leaking sockets, or is leaking buffers or > structures related to sockets, and this cruft is clogging Ruby''s > networking code. > > I''m working with a fresh installation of Rails: > > $ gem list --local | grep "^[a-z]" > actionmailer (0.5.0, 0.4.0) > actionpack (1.2.0, 0.9.5) > activerecord (1.4.0, 1.1.0) > rails (0.9.3, 0.8.5) > rake (0.4.15, 0.4.12) > sources (0.0.1) > > $ ruby --version > ruby 1.8.2 (2004-12-23) [i386-linux] > > $ uname -a > Linux bork 2.6.5 #1 Wed Dec 1 06:23:39 CET 2004 i686 GNU/Linux > > Alexander. > _______________________________________________ > Rails mailing list > Rails-1W37MKcQCpIf0INCOvqR/iCwEArCW2h5@public.gmane.org > http://lists.rubyonrails.org/mailman/listinfo/rails >
I will try this. Thanks. Alexander. Patrick Spence wrote:> I experienced similar difficulties using Webrick. I fixed it by using > the --daemon flag when running ./script/server. > > > On Sun, 09 Jan 2005 00:24:27 +0100, Alexander Staubo <alex-uTpLPxngHHI4n3JXwSlx2Q@public.gmane.org> wrote: > >>A fresh boot of Rails through Webrick easily serves over 100 >>requests/sec. But during the course of just 100 requests performance >>gradually and exponentially slides down towards zero. >> >>Against a non-database-driven controller ("scripts/generate controller >>test index"), HTTP requests grow increasingly slower: >> >>$ ab2 -n 100 http://localhost:8080/test/index | grep "^Requests per" >>Requests per second: 4.12 [#/sec] (mean) >>$ ab2 -n 100 http://localhost:8080/test/index | grep "^Requests per" >>Requests per second: 1.46 [#/sec] (mean) >>$ ab2 -n 100 http://localhost:8080/test/index | grep "^Requests per" >>Requests per second: 1.03 [#/sec] (mean) >> >>But the slowdown is not reflected in the Rails log: >> >>Completed in 0.001328 (753 reqs/sec) | Rendering: 0.000773 (58%) >>Completed in 0.001329 (752 reqs/sec) | Rendering: 0.000774 (58%) >>Completed in 0.001478 (676 reqs/sec) | Rendering: 0.000810 (54%) >>... >>Completed in 0.001339 (746 reqs/sec) | Rendering: 0.000752 (56%) >>Completed in 0.001306 (765 reqs/sec) | Rendering: 0.000758 (58%) >>Completed in 0.001388 (720 reqs/sec) | Rendering: 0.000787 (56%) >> >>In other words, something outside the logic timed by Rails is taking an >>increasing amount of time. >> >>But against a database-driven controller -- a very simple one which >>triggers a single "select" and outputs a single column value -- the >>slowdown at the HTTP level is similar, but a similar slowdown is clearly >>reflected inside Rails as well: >> >>$ tail log/development.log -n0 -f | grep "^Compl" >>Completed in 0.040410 (24 reqs/sec) | Rendering: 0.028661 (70%) | DB: >>0.030061 (74%) >>... >>Completed in 0.298424 (3 reqs/sec) | Rendering: 0.028794 (9%) | DB: >>0.030192 (10%) >> >>In both cases, Ruby is eating memory as if it were candy; before the 300 >>test requests: >> >>$ ps aufxwww | grep ruby >>root 1103 0.0 1.4 15036 13456 pts/160 S+ 22:40 0:00 ruby >>script/server -p 8080 -b 0.0.0.0 >> >>Afterwards: >> >>$ ps aufxwww | grep ruby >>root 1103 0.0 3.5 55216 31936 pts/160 S+ 22:40 1:42 ruby >>script/server -p 8080 -b 0.0.0.0 >> >>The slowdown and memory hogging is not seen when running with FastCGI >>for any of the controllers. >> >>To me this implies that the problem is in Webrick, and that the reason >>Rails its grows slower only in the database case is that Webrick is >>somehow affecting Rails'' database layer. >> >>The non-database case does not create TCP connections to the database; >>so perhaps Webrick is leaking sockets, or is leaking buffers or >>structures related to sockets, and this cruft is clogging Ruby''s >>networking code. >> >>I''m working with a fresh installation of Rails: >> >>$ gem list --local | grep "^[a-z]" >>actionmailer (0.5.0, 0.4.0) >>actionpack (1.2.0, 0.9.5) >>activerecord (1.4.0, 1.1.0) >>rails (0.9.3, 0.8.5) >>rake (0.4.15, 0.4.12) >>sources (0.0.1) >> >>$ ruby --version >>ruby 1.8.2 (2004-12-23) [i386-linux] >> >>$ uname -a >>Linux bork 2.6.5 #1 Wed Dec 1 06:23:39 CET 2004 i686 GNU/Linux >> >>Alexander. >>_______________________________________________ >>Rails mailing list >>Rails-1W37MKcQCpIf0INCOvqR/iCwEArCW2h5@public.gmane.org >>http://lists.rubyonrails.org/mailman/listinfo/rails >> > > _______________________________________________ > Rails mailing list > Rails-1W37MKcQCpIf0INCOvqR/iCwEArCW2h5@public.gmane.org > http://lists.rubyonrails.org/mailman/listinfo/rails