Bug 13645 - DBIx connection needs to be cached
Summary: DBIx connection needs to be cached
Status: CLOSED FIXED
Alias: None
Product: Koha
Classification: Unclassified
Component: Architecture, internals, and plumbing (show other bugs)
Version: master
Hardware: All All
: P5 - low normal (vote)
Assignee: Jonathan Druart
QA Contact: Testopia
URL:
Whiteboard:
Keywords: rel_3_16_candidate
Depends on:
Blocks: 14374
  Show dependency treegraph
 
Reported: 2015-01-30 11:39 UTC by Jacek Ablewicz
Modified: 2016-12-05 21:23 UTC (History)
10 users (show)

See Also:
Change sponsored?: ---
Patch complexity: ---
Bot Control: ---
When did the bot last check this:
Who signed the patch off:
Text to go in the release notes:


Attachments
Bug 13645: Cache the DBIx connection (3.57 KB, patch)
2015-01-30 16:14 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 13645: Cache the DBIx connection (3.63 KB, patch)
2015-02-03 10:09 UTC, Jacek Ablewicz
Details | Diff | Splinter Review
[PASSED QA] Bug 13645: Cache the DBIx connection (3.69 KB, patch)
2015-02-05 12:09 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 13645: Use DBIx::Connector (1.29 KB, patch)
2015-02-10 09:51 UTC, Jonathan Druart
Details | Diff | Splinter Review
[PASSED QA] Bug 13645: Cache the DBIx connection (3.74 KB, patch)
2015-02-17 03:51 UTC, Tomás Cohen Arazi
Details | Diff | Splinter Review
[SIGNED OFF] Bug 13645: Use DBIx::Connector (1.36 KB, patch)
2015-02-17 03:52 UTC, Tomás Cohen Arazi
Details | Diff | Splinter Review
[PASSED QA] Bug 13645: Cache the DBIx connection (3.80 KB, patch)
2015-02-20 14:55 UTC, Kyle M Hall
Details | Diff | Splinter Review
[PASSED QA] Bug 13645: Use DBIx::Connector (1.42 KB, patch)
2015-02-20 14:55 UTC, Kyle M Hall
Details | Diff | Splinter Review
[PASSED QA] Bug 13645 [QA Followup] - Add DBIx::Connector to the list of dependancies (936 bytes, patch)
2015-02-20 14:55 UTC, Kyle M Hall
Details | Diff | Splinter Review
Bug 13645: dependencies for libdbix-connector-perl (879 bytes, patch)
2015-02-24 05:33 UTC, Robin Sheat
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Jacek Ablewicz 2015-01-30 11:39:57 UTC
After Bug 12896, loading times for some acqui scripts increased quite significantly, e.g. (for a test setup with ca 170 bookseller records in the database):

   acqui/booksellers.pl: before - 800ms, after - 4100ms
   acqui/invoices.pl: before - 650ms, after - 3900ms

Koha::Acquisition::Bookseller->search(), especially when called with empty search string in order to fetch list of all booksellers, seems to be very inefficient.

Looks like it is predominantly caused by lack of DBIx object / DB connection caching (?). For each bookseller record found, search() method calls fetch() individually. Each time fetch() is getting called, it creates (and destroys on exit) a brand new Koha::Database object (and probably a brand new DB connection as well ?), which is rather expensive performance-wise.
Comment 1 Jonathan Druart 2015-01-30 16:14:50 UTC Comment hidden (obsolete)
Comment 2 Jonathan Druart 2015-01-30 16:17:09 UTC
Here my try.
Comment 3 Jacek Ablewicz 2015-02-03 10:09:02 UTC Comment hidden (obsolete)
Comment 4 Jacek Ablewicz 2015-02-03 11:20:09 UTC
(In reply to Jonathan Druart from comment #2)
> Here my try.

It does vastly improve Koha DBIx performace, and as far as I can tell after eyeballing it comprehensively, it rather shouldn't break anything important. So I change status to signed off.

Would be nice to have some kind of test plan for it, though..

OTOH, in theory it can indirectly affect a lot of different places where
Koha::Database->.. calls are being used, so any meaningfull test plan is probably out of the question anyway ;).
Comment 5 Jonathan Druart 2015-02-03 11:34:51 UTC
(In reply to Jacek Ablewicz from comment #4)
> (In reply to Jonathan Druart from comment #2)
> > Here my try.
> 
> It does vastly improve Koha DBIx performace, and as far as I can tell after
> eyeballing it comprehensively, it rather shouldn't break anything important.
> So I change status to signed off.

Thanks Jacek!
Did you benchmark the scripts booksellers.pl and invoices.pl with this patch?

> Would be nice to have some kind of test plan for it, though..
> 
> OTOH, in theory it can indirectly affect a lot of different places where
> Koha::Database->.. calls are being used, so any meaningfull test plan is
> probably out of the question anyway ;).

Yes, a test plan could be: Verify there is no regression/error with scripts using a dbic connection :)
Which is vague...
Comment 6 Jacek Ablewicz 2015-02-04 09:59:51 UTC
(In reply to Jonathan Druart from comment #5)

> Did you benchmark the scripts booksellers.pl and invoices.pl with this patch?

Patched master:

166 booksellers:

 - acqui/booksellers.pl: 1.3 sec
 - acqui/invoices.pl: 1.2 sec

1660 booksellers:

 - acqui/booksellers.pl: 6.4 sec
 - acqui/invoices.pl: 5.5 sec

16600 booksellers:

 - acqui/booksellers.pl: 55.8 sec
 - acqui/invoices.pl: 47.5 sec


Unpatched master:

166 booksellers:

 - acqui/booksellers.pl: 4.06 sec
 - acqui/invoices.pl: 3.94 sec

1660 booksellers:

 - acqui/booksellers.pl: 33.2 sec
 - acqui/invoices.pl: 31.7 sec


Test setup with pre-DBIx bookseller code (3.17.00.014), different server
with ca 10-25% faster CPU, but otherwise rather similar software and
hardware-wise:

166 booksellers:

- acqui/booksellers.pl: 0.68 sec
- acqui/invoices.pl: 0.61 sec

1660 booksellers:

- acqui/booksellers.pl: 1.71 sec
- acqui/invoices.pl: 0.64 sec

16600 booksellers:

- acqui/booksellers.pl: 10.8 sec
- acqui/invoices.pl: 1.16 sec

Other difference between patched and unpatched master is that when running booksellers.pl on the unpatched master, CPU usage is 99+% for booksellers.pl and just 1.2-1.5% for mysqld, while for patched master it is ca 87% for a script and 12% for mysqld.

Before filing this bug report I've tried to profile booksellers.pl with nytprof; there are some intriguing things in the results, for example: suspiciously high amount of CPU time (20% or so) is being spent in the various XML::* modules - I think I figured why it does that, separate bug report + patch will follow.
Comment 7 Jonathan Druart 2015-02-04 12:47:56 UTC
I did a quick test (master):
inserted 1000 booksellers, launched

  use Modern::Perl;
  use Koha::Acquisition::Bookseller;
  Koha::Acquisition::Bookseller->search;

perl benchmark_bookseller.pl  33.83s user 0.12s system 99% cpu 34.280 total

I quickly implemented Koha::Acquisition::Bookseller using Koha::Object (see bug 13019) and tested with

  use Modern::Perl;
  use Koha::Acquisition::Booksellers;
  my $booksellers = Koha::Acquisition::Booksellers->search;
  while ( my $b = $booksellers->next ) {
      say $b->name;
  }

perl benchmark_bookseller.pl  1.00s user 0.03s system 96% cpu 1.072 total
Comment 8 Jacek Ablewicz 2015-02-04 14:48:41 UTC
(In reply to Jonathan Druart from comment #7)

> I quickly implemented Koha::Acquisition::Bookseller using Koha::Object (see
> bug 13019) and tested with
> 
>   use Modern::Perl;
>   use Koha::Acquisition::Booksellers;
>   my $booksellers = Koha::Acquisition::Booksellers->search;
>   while ( my $b = $booksellers->next ) {
>       say $b->name;
>   }
> 
> perl benchmark_bookseller.pl  1.00s user 0.03s system 96% cpu 1.072 total

Speed-wise, I'm getting pretty much the same results with the following quick&dirty mod:

--- a/Koha/Acquisition/Bookseller.pm
+++ b/Koha/Acquisition/Bookseller.pm
@@ -46,13 +46,12 @@ sub search {
     }
     my $rs = $schema->resultset('Aqbookseller')->search(
         $search_params,
-        { order_by => 'name' }
+        { order_by => 'name' }, { result_class => 'DBIx::Class::ResultClass::HashRefInflator' }
     );

     my @booksellers;
     while ( my $b = $rs->next ) {
-        my $t = Koha::Acquisition::Bookseller->fetch({ id => $b->id });
-        push @booksellers, $t;
+        push @booksellers, $b;
     }
     return @booksellers;
 }

With it, booksellers.pl loading times are 0.96 sec / 1.82 sec / 10.3 sec for 170 / 1700 / 17000 booksellers in the database.
Whenever DBIx object is cached or not cached doesn't seem to matter much with such mod - I guess because there would be just one DBIx schema/connection object created in this case anyway?
Comment 9 Kyle M Hall 2015-02-05 12:09:07 UTC Comment hidden (obsolete)
Comment 10 Jonathan Druart 2015-02-10 09:51:55 UTC Comment hidden (obsolete)
Comment 11 Jonathan Druart 2015-02-10 10:07:48 UTC
This needs discussion, I really would like to see more people involved here.

I submitted a second patch, here the benchmark result for
  Koha::Acquisition::Bookseller->search;

Patch 1 is "Cache the DBIx connection"
Patch 2 is "Use DBIx::Connector"

With 14 suppliers in DB

On master
Perl benchmark_bookseller.pl  1.34s user 0.05s system 96% cpu 1.444 total
Perl benchmark_bookseller.pl  1.38s user 0.03s system 97% cpu 1.448 total
Perl benchmark_bookseller.pl  1.37s user 0.04s system 97% cpu 1.445 total
Perl benchmark_bookseller.pl  1.38s user 0.02s system 97% cpu 1.437 total
Perl benchmark_bookseller.pl  1.35s user 0.03s system 97% cpu 1.418 total

On master + patch 1
Perl benchmark_bookseller.pl  0.92s user 0.04s system 96% cpu 0.999 total
Perl benchmark_bookseller.pl  0.94s user 0.05s system 96% cpu 1.031 total
Perl benchmark_bookseller.pl  0.90s user 0.06s system 96% cpu 0.988 total
Perl benchmark_bookseller.pl  0.94s user 0.04s system 96% cpu 1.021 total
Perl benchmark_bookseller.pl  0.93s user 0.04s system 96% cpu 1.003 total

On master + patch 1 & patch 2
Perl benchmark_bookseller.pl  0.93s user 0.03s system 95% cpu 1.002 total
Perl benchmark_bookseller.pl  0.96s user 0.03s system 95% cpu 1.031 total
Perl benchmark_bookseller.pl  0.97s user 0.03s system 95% cpu 1.046 total
Perl benchmark_bookseller.pl  0.99s user 0.02s system 96% cpu 1.048 total
Perl benchmark_bookseller.pl  0.93s user 0.04s system 95% cpu 1.013 total

On master + patch 2
Perl benchmark_bookseller.pl  1.40s user 0.02s system 97% cpu 1.464 total
Perl benchmark_bookseller.pl  1.36s user 0.04s system 96% cpu 1.436 total
Perl benchmark_bookseller.pl  1.36s user 0.04s system 97% cpu 1.428 total
Perl benchmark_bookseller.pl  1.39s user 0.01s system 97% cpu 1.439 total
Perl benchmark_bookseller.pl  1.37s user 0.05s system 97% cpu 1.454 total

With 1014 suppliers in DB
On master
perl benchmark_bookseller.pl  35.66s user 0.14s system 99% cpu 35.977 total                                                                           
perl benchmark_bookseller.pl  35.36s user 0.14s system 99% cpu 35.591 total

On master + patch 1
perl benchmark_bookseller.pl  2.50s user 0.07s system 95% cpu 2.675 total
perl benchmark_bookseller.pl  2.56s user 0.07s system 95% cpu 2.739 total
perl benchmark_bookseller.pl  2.66s user 0.05s system 95% cpu 2.849 total
perl benchmark_bookseller.pl  2.49s user 0.06s system 96% cpu 2.655 total
perl benchmark_bookseller.pl  2.42s user 0.08s system 96% cpu 2.581 total

On master + patch 1 & patch 2
perl benchmark_bookseller.pl  2.45s user 0.05s system 96% cpu 2.596 total
perl benchmark_bookseller.pl  2.49s user 0.04s system 96% cpu 2.629 total
perl benchmark_bookseller.pl  2.49s user 0.04s system 96% cpu 2.629 total
perl benchmark_bookseller.pl  2.48s user 0.09s system 96% cpu 2.678 total
perl benchmark_bookseller.pl  2.40s user 0.08s system 96% cpu 2.562 total

On master + patch 2
perl benchmark_bookseller.pl  34.75s user 0.11s system 99% cpu 34.927 total
perl benchmark_bookseller.pl  34.22s user 0.12s system 99% cpu 34.397 total
perl benchmark_bookseller.pl  35.12s user 0.15s system 99% cpu 35.343 total

At first glance, patch 2 does not seem to be efficient, but I am not confident with patch 1, I got bad results with other tests.
Comment 12 Jacek Ablewicz 2015-02-10 11:01:00 UTC
(In reply to Jonathan Druart from comment #11)

> I got bad results with other tests.

What kinds of bad results? Do you mean something performance-related only, or did you perhaps encountered some unforseen problems, regressions etc elsewhere?
Comment 13 Jonathan Druart 2015-02-10 11:19:26 UTC
It's performance-related only, I will sent an email to koha-devel today (hopefully).
Comment 14 Jonathan Druart 2015-02-12 09:18:39 UTC
Switch the status back to Needs Signoff.
Comment 15 Jacek Ablewicz 2015-02-12 12:36:18 UTC
Not sure what to think about patch #2 (Bug 13645: Use DBIx::Connector) - is it needed for patch #1 or patch #3 (from Bug 13690) to work properly?

I'm not seeing any measurable performance gains with patch #2 (on the contrary, in most test performed so far it seems to be a little bit slower to me - but in any case, the differences are insignificant, +3/-2 msec or so); same results when tested alone, or in combination with #1 and #3.

Generally, DBIx::Connector looks like a move in the right direction (I guess it should improve stability/DBI connection handling safety in persistent environments, at least in theory ?), but in comparison with #1 & #3, it would be a lot harder to evaluate it for possible regressions, issues etc. While testing #2 I found one issue (Bug 13699), but this bug is also reproducible in unpatched master :).

BTW, DBIx::Connector is not on the dependencies list (don't know if it needs to be added, on my test setup I had this module package already installed because I was toying with it previously).
Comment 16 Jonathan Druart 2015-02-12 14:49:43 UTC
(In reply to Jacek Ablewicz from comment #15)
> Not sure what to think about patch #2 (Bug 13645: Use DBIx::Connector) - is
> it needed for patch #1 or patch #3 (from Bug 13690) to work properly?

No, there are all independent.

> I'm not seeing any measurable performance gains with patch #2 (on the
> contrary, in most test performed so far it seems to be a little bit slower
> to me - but in any case, the differences are insignificant, +3/-2 msec or
> so); same results when tested alone, or in combination with #1 and #3.

In my tests, it was better, see the png file on bug 13690.

> BTW, DBIx::Connector is not on the dependencies list (don't know if it needs
> to be added, on my test setup I had this module package already installed
> because I was toying with it previously).

Yes, should be added if the patch is validated.
Comment 17 Tomás Cohen Arazi 2015-02-17 02:58:13 UTC
I think both patches should be used together: in a persistent environment (in the sense of plack-like one-time-load execution) we need a module to take care of reconnections and keep connections open as needed.

Caching the database connection object to reuse it, seems ok. But how long? what if the connection drops for some reason? That's when DBIx::Connector proves handy.

My only concern was about this approach being kosher or not, and that's why I tried to contact ribasushi on the IRC channel, because it smells like a trivial use case everyone faces when using DBIx::Class :-D
Comment 18 Tomás Cohen Arazi 2015-02-17 03:51:25 UTC Comment hidden (obsolete)
Comment 19 Tomás Cohen Arazi 2015-02-17 03:52:09 UTC Comment hidden (obsolete)
Comment 20 Kyle M Hall 2015-02-20 14:55:35 UTC
Created attachment 36092 [details] [review]
[PASSED QA] Bug 13645: Cache the DBIx connection

We don't want to recreate a new connection to the DB every time we want
a new schema.

This patch creates a $database package level variable on the same way
it's done in C4::Context for $dbh.

Signed-off-by: Jacek Ablewicz <abl@biblos.pk.edu.pl>
Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Signed-off-by: Tomas Cohen Arazi <tomascohen@gmail.com>

Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Comment 21 Kyle M Hall 2015-02-20 14:55:44 UTC
Created attachment 36093 [details] [review]
[PASSED QA] Bug 13645: Use DBIx::Connector

Signed-off-by: Tomas Cohen Arazi <tomascohen@gmail.com>

Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Comment 22 Kyle M Hall 2015-02-20 14:55:47 UTC
Created attachment 36094 [details] [review]
[PASSED QA] Bug 13645 [QA Followup] - Add DBIx::Connector to the list of dependancies

Signed-off-by: Kyle M Hall <kyle@bywatersolutions.com>
Comment 23 Tomás Cohen Arazi 2015-02-20 18:49:44 UTC
Patches pushed to master.

Thanks Jonathan and Kyle!
Comment 24 Chris Cormack 2015-02-22 23:17:58 UTC
Holding for 3.18.5, I need to test this more.
Comment 25 Robin Sheat 2015-02-24 04:22:39 UTC
Needs a squeeze package for DBIx::Connector. I'll have a go at building the wheezy one for it.
Comment 26 Robin Sheat 2015-02-24 05:02:28 UTC
(In reply to Robin Sheat from comment #25)
> Needs a squeeze package for DBIx::Connector. I'll have a go at building the
> wheezy one for it.

So the packages built surprisingly easily on squeeze. And then a series of cockups on my part made it take forever to actually get into the repo :)

It's there now though.
Comment 27 Robin Sheat 2015-02-24 05:33:11 UTC
Created attachment 36131 [details] [review]
Bug 13645: dependencies for libdbix-connector-perl
Comment 28 Robin Sheat 2015-02-24 05:34:14 UTC
The patch I've attached will need to go in alongside this.
Comment 29 Robin Sheat 2015-02-24 05:49:36 UTC
I've uploaded a master build, and included my patch in it. It seemed to be happy. Have a go with that if you want an easy test.
Comment 30 Tomás Cohen Arazi 2015-02-24 17:25:42 UTC
Followup pushed to master.

Thanks Robin!
Comment 31 Chris Cormack 2015-03-10 19:00:27 UTC
Pushed to 3.18.x will be in 3.18.5
Comment 32 Mason James 2015-03-26 00:58:31 UTC
(In reply to Chris Cormack from comment #31)
> Pushed to 3.18.x will be in 3.18.5

hmm, possible selection for 3.16.x