in reply to DBIx startup slow

Slow database performance when you run a query on a large table sounds like a lack of an index on that table.

What database engine are you using? (SQLite, MySQL, Postgres etc?)

Are there indexes on the relevant columns in your tables? You can specify indexes in your DBIC table definition with __PACKAGE__->add_index(name => 'idx_name', fields => ['name']); See: The DBIx::Class Cookbook.

Have you tried running the query by hand using raw SQL to see what performance you get? (You can get DBIx::Class to emit each SQL call it makes by setting the DBIC_TRACE environment variable to a true value. See: DBIx::Class::Storage. It might also be worth using the SQL EXPLAIN command on your keyword to understand a bit more how the database treats your query, and if there is anything expensive in there.

You say that you have a many to many relationship bridge. When is the link table populated? If by some mechanism it does not exist at start-up, but is created on the fly on first use, then that would explain the slow performance when you first use it, though I have never come across a system where that creates link tables automatically.

Replies are listed 'Best First'.
Re^2: DBIx startup slow
by anjalis (Novice) on Sep 05, 2011 at 10:58 UTC

    I'm using SQLite engine, i have primary key index. I'will also look on that SQL's, but slow is just first search, second and etc.. are fast, thanks

[reply]

      You don't just need indexes on the primary keys, you also need them on the foreign keys, as when you do a search on a many_to_many relationship, DBIC will do a query with a foreign key join.

      Take a look at the examples in DBIx:Class:Relationship under many_to_many.

      In one of those examples, if you do $actor->roles(), then your database has to get the primary key of the actor, run a query on the ActorRoles table for all entries matching that actor_id, look at the role_id in each matching row, and then return all roles that match. The query will be something like this:

      select * from tblRoles r where r.role_id IN ( select role_id from tblA
+ctorRole ar where ar.actor_id = ? )

      [download]

      Unless there is an index on actor_id in the ActorRoles table, the query will be very slow.

[reply]
[d/l]

        Hi all, so i done some profiling and here are the results: 1. DBIx profiling:

        E:\Documents\ProgramovanieProgramyAskripty\Symphaty0.4>perl -MDBIx::Pr
+ofile symphaty.pl
Gtk-CRITICAL **: gtk_tree_view_column_cell_layout_pack_start: assertio
+n `! gtk_t
ree_view_column_get_cell_info (column, cell)' failed at symphaty.pl li
+ne 250.
=================================================================
2444 "SELECT me.eng_id, me.engword FROM englishword me WHERE ( engword
+ = ? )"
Total wall clock time: 1.197475s
   execute ---------------------------------------
      Total
         Count        :          2
         Wall Clock   :  1.1974750 s    0.5987375 s
         Cpu Time     :  0.2020000 s    0.1010000 s
      returned 0E0
         Count        :          2
         Wall Clock   :  1.1974750 s    0.5987375 s
         Cpu Time     :  0.2020000 s    0.1010000 s

=================================================================
2444 "SELECT me.eng_id, me.engphrase, me.skphrase, me.phrase_id FROM p
+hrase me W
HERE ( me.eng_id = ? )"   Total wall clock time: 0.790816s
   execute ---------------------------------------
      Total
         Count        :          1
         Wall Clock   :  0.7908160 s    0.7908160 s
         Cpu Time     :  0.0160000 s    0.0160000 s
      returned 0E0
         Count        :          1
         Wall Clock   :  0.7908160 s    0.7908160 s
         Cpu Time     :  0.0160000 s    0.0160000 s

=================================================================
2444 "SELECT skword.sk_id, skword.skword FROM en_to_sk me  JOIN skword
+meaning sk
word ON skword.sk_id = me.sk_id WHERE ( me.eng_id = ? )"   Total wall 
+clock time
: 0.369762s
   execute ---------------------------------------
      Total
         Count        :          1
         Wall Clock   :  0.3697620 s    0.3697620 s
         Cpu Time     :  0.1250000 s    0.1250000 s
      returned 0E0
         Count        :          1
         Wall Clock   :  0.3697620 s    0.3697620 s
         Cpu Time     :  0.1250000 s    0.1250000 s

=================================================================
2444 "SELECT me.eng_id, me.infinitive, me.past, me.participle, me.irre
+gular_id F
ROM irregular me WHERE ( ( infinitive = ? OR past = ? OR participle = 
+? ) )"   T
otal wall clock time: 0.102356s
   execute ---------------------------------------
      Total
         Count        :          1
         Wall Clock   :  0.1023560 s    0.1023560 s
         Cpu Time     :  0.0000000 s    0.0000000 s
      returned 0E0
         Count        :          1
         Wall Clock   :  0.1023560 s    0.1023560 s
         Cpu Time     :  0.0000000 s    0.0000000 s

=================================================================
2444 "SELECT me.sk_id, me.skword FROM skwordmeaning me WHERE ( skword 
+= ? )"   T
otal wall clock time: 0.071004s
   execute ---------------------------------------
      Total
         Count        :          1
         Wall Clock   :  0.0710040 s    0.0710040 s
         Cpu Time     :  0.0160000 s    0.0160000 s
      returned 0E0
         Count        :          1
         Wall Clock   :  0.0710040 s    0.0710040 s
         Cpu Time     :  0.0160000 s    0.0160000 s

=================================================================
2444 "SELECT engword.eng_id, engword.engword FROM en_to_sk me  JOIN en
+glishword
engword ON engword.eng_id = me.eng_id WHERE ( me.sk_id = ? )"   Total 
+wall clock
 time: 0.004899s
   execute ---------------------------------------
      Total
         Count        :          1
         Wall Clock   :  0.0048990 s    0.0048990 s
         Cpu Time     :  0.0160000 s    0.0160000 s
      returned 0E0
         Count        :          1
         Wall Clock   :  0.0048990 s    0.0048990 s
         Cpu Time     :  0.0160000 s    0.0160000 s

        [download]

        2. whole script profiling, most important restults:

        # spent 28.7s (0ns+28.7) within Searcher::searchWord which was called 
+2 times, avg 14.4s/call: # 2 times (0ns+28.7s) by Searcher::search at
+ line 62, avg 14.4s/call
sub searchWord($) {
my $self = shift;
my $searchedString = shift;
my @word = ();
my @engwords = ();
my $engword;
my @skwordsSet = ();
my $skwordSet;
my @engwordsSet = ();
my $engwordSet;
my @skwords = ();
my $skword;
if($self->{direction} eq "eng") {
my @engwords = $schema->resultset('Engword')->search({engword =>search
+edString});
# spent 12.8s making 1 call to DBIx::Class::ResultSet::search # spent 
+1.00ms making 1 call to DBIx::Class::Schema::resultset
foreach $engword(@engwords){
my @skwordsSet = $engword->skwords;
foreach $skwordSet(@skwordsSet){
            push(@word,$skwordSet->skword);
            } # foreach
            } # foreach
            
            } # if
                
if($self->{direction} eq "svk") {
    
my @skwords = $schema->resultset('Skword')->search({skword => $searche
+dString});
# spent 9.87s making 1 call to DBIx::Class::ResultSet::search # spent 
+1.00ms making 1 call to DBIx::Class::Schema::resultset
foreach $skword(@skwords){
my @engwordsSet = $skword->engwords;
# spent 6.07s making 1 call to MyDictionary::Schema::Skword::engwords
foreach $engwordSet(@engwordsSet){
push(@word,$engwordSet->engword);
# spent 0s making 4 calls to MyDictionary::Schema::Engword::engword, a
+vg 0s/call
} # foreach
} # foreach
            
} # if

return @word;

} # method searchWord

        [download]

        So my opinion is that queries are fast, but there is something with fetching the results. Also look at this:

        # spent 21.3s (0ns+21.3) within DBIx::Class::Storage::DBI::Cursor::_db
+h_all which was called 5 times, avg 4.26s/call: # 5 times (0ns+21.3s)
+ by DBIx::Class::Storage::DBI::dbh_do at line 547 of C:/Perl/site/lib
+/DBIx/Class/Storage/DBI.pm, avg 4.26s/call
sub _dbh_all {
120    30    18.8s    628ms    my ($storage, $dbh, $self) = @_;
121                
122                $self->_check_dbh_gen;
# spent 0s making 5 calls to DBIx::Class::Storage::DBI::Cursor::_check
+_dbh_gen, avg 0s/call
123                $self->{sth}->finish if $self->{sth}->{Active};
124                delete $self->{sth};
125                my ($rv, $sth) = $storage->_select(@{$self->{args}}
+);
# spent 2.46s making 5 calls to DBIx::Class::Storage::DBI::_select, av
+g 492ms/call
126                return @{$sth->fetchall_arrayref};
# spent 18.8s making 5 calls to DBI::st::fetchall_arrayref, avg 3.77s/
+call
127                }

        [download]
[reply]
[d/l]
[select]
        indexes on link table didn't help... i've tried it
[reply]

In Section Seekers of Perl Wisdom