Menu
▾
▴
Re: [Gusdev-gusdev] plugins speed difference due to dsn string
|
From: Fidel S. <fi...@vb...> - 2003-12-03 16:16:21
|
Steve,
No, there is not a performance problem.
Fidel
Steve Fischer <st...@pc...> writes:
> Fidel-
> Thanks for the profiler info.
> About the multiple connections. I agree that ideally it should be one
> connection. But, there are some non-obvious issues around this, such
> as keeping independent transactions alive, that i don't fully
> understand. Two of the connections seem to be caused by ga and the
> rest by the object layer. When we renovate the object layer i will
> pay attention to this. But for now, besides the fact that it is
> suspicious and wasteful, is there any particular performance problem
> it is causing?
> steve
> Fidel Salas wrote:
>
> Steve,
>
> The profiler I used is Devel::DProf. It is run like this:
>
> $ perl -d:DProf ga GUS::Common::Plugin::SubmitRow --tablename SRes::ExternalDat
> abase --attrlist external_database_id,name,lowercase_name --valuelist "200^^^Ge
> nBank(main)^^^genbank(main)"
>
> The profile output is written to a file called 'tmon.out.' This file is interp
> reted
> by the program 'dprofpp.'
>
>>From your sample output below, it seems like it is the same profiler you used.
>
> There were two main points to my original post:
>
> 1. The dbiDsn issue. I do not know what your oracle setup is at CBIL or what
> it is at
> other places where people are using GUS. As I pointed out before, we connect t
> o oracle
> from a client machine, that is, the oracle server and client are on different m
> achines.
> Oracle has multiple ways of making connections (using environment variables or
> tnsname.ora)
> and I am not sure whether the server/client configuration impacts what the dsn
> must be in
> order for things to work properly.
>
> 2. Connecting to the database (by SubmitRow) multiple times. The reason I spo
> ke to you
> (Steve) about how slow things were running has to do with the multiple connecti
> ons to
> the database. I probably would have ignored the issue (due to my limited time
> at VBI)
> if SubmitRow had been taking 3 minutes to run, but since it was taking 12 min.
> or more,
> it became a concern. There is no reason for SubmitRow or any other plugin to h
> ave to
> connect to the database more than once per invocation. In the course of debugg
> ing the
> problem, I placed a few print statements in various places. Here is the output
> after
> one invocation:
>
> gus@tyler-lab:/home/apps/gus/debug$ ga GUS::Common::Plugin::SubmitRow
> --tablename SRes::ExternalDatabase --attrlist external_database_id,name,lowerc
> ase_name --valuelist "200^^^GenBank(main)^^^genbank(main)"
>
> Creating GusApplication Object
> Reading properties from /home/apps/gus/gushome/config/GUS-PluginMgr.pro
> p
>
> Created GusApplication object
>
> Entering GA parseAndRun
>
> Entering doMajorMode
>
> Entering doMajorMode_Run
>
> I am in GusApplication module. Entering connect_to_database method
>
> PlugIn is:GUS::PluginMgr::GusApplication=HASH(0x813361c)
> Reading properties from /home/apps/gus/.gus.properties
>
> My login is:GUSrw core is:Core dbiDsn is:dbi:Oracle:host=tuor.
> bioinformatics.vt.edu;sid=gusdev oraDfltRbs is:none
>
> Creating DbiDatabase
>
> Created DbiDatabase
>
> *************I am in DbiDbHandle and about to connect to database with
> following parameters:
> class: GUS::ObjRelP::DbiDbHandle dsn: dbi:Oracle:host=tu
> or.bioinformatics.vt.edu;sid=gusdev
> user: GUSrw autoCommit: *****************
>
> I am in GusApplication module. Entering connect_to_database method
>
> PlugIn is:GUS::Common::Plugin::SubmitRow=HASH(0x8143fb4)
>
> My login is:GUSrw core is:Core dbiDsn is:dbi:Oracle:host=tuor.
> bioinformatics.vt.edu;sid=gusdev oraDfltRbs is:none
>
> Creating DbiDatabase
>
> Created DbiDatabase
>
> *************I am in DbiDbHandle and about to connect to database with
> following parameters:
> class: GUS::ObjRelP::DbiDbHandle dsn: dbi:Oracle:host=tu
> or.bioinformatics.vt.edu;sid=gusdev
> user: GUSrw autoCommit: *****************
>
> *************I am in DbiDbHandle and about to connect to database with
> following parameters:
> class: GUS::ObjRelP::DbiDbHandle dsn: dbi:Oracle:host=tu
> or.bioinformatics.vt.edu;sid=gusdev
> user: GUSrw autoCommit: 1 *****************
>
> Creating DbiTable object
>
> Created DbiTable object
>
> *************I am in DbiDbHandle and about to connect to database with
> following parameters:
> class: GUS::ObjRelP::DbiDbHandle dsn: dbi:Oracle:host=tu
> or.bioinformatics.vt.edu;sid=gusdev
> user: GUSrw autoCommit: *****************
>
> Creating DbiTable object
>
> Created DbiTable object
>
> Entering openInvocation
>
> PlugIn is: GUS::Common::Plugin::SubmitRow=HASH(0x8143fb4)
>
> Creating DbiTable object
>
> Created DbiTable object
>
> Creating DbiTable object
>
> Created DbiTable object
>
> Creating DbiTable object
>
> Created DbiTable object
>
> Creating DbiTable object
>
> Created DbiTable object
> Mon Nov 10 10:44:14 2003 ALGINVID 10
> Mon Nov 10 10:44:14 2003 COMMIT commit off
>
> Creating DbiTable object
>
> Created DbiTable object
> Mon Nov 10 10:44:14 2003 Row updated
> Mon Nov 10 10:44:14 2003 RESULT Updated one row
> gus@tyler-lab:/home/apps/gus/debug$
>
> Connecting to the database is expensive and it is, obviously, desirable to mini
> mize
> the number of connections made.
>
> Fidel
>
>
> Steve Fischer <st...@pc...> writes:
>
> > Folks-
>
> > I ran the SubmitRow plugin command mentioned below, with this dsn:
>
> > dbiDsn=dbi:Oracle:host=cbilbld.pcbi.upenn.edu;sid=cbilbld
>
> > It took less than a second. So, whatever the problem is on Fidel's
> > site is not reproducable here. I will forward the dsn question to our
> > SA folks. Maybe they'll have a clue.
>
> > As far as the surprising profile: much of it is explained by the call
> > to GUS::ObjRelP::DbiDatabase::cacheTableNames which builds a cache of
> > table names. This is a bit of object layer overhead. There are about
> > 900 tables in our GUS's TableInfo table. The real mystery is why this
> > is in one profile but not in the other:
>
> > 11.2 0.060 0.055 2470 0.0000 0.0000 GUS::ObjRelP::DbiRow::getTa
> ble
>
>
>
>
> > Fidel- what tool did you use for the profiling?
>
> > Steve
>
>
>
>
>
> > Fidel Salas wrote:
>
>
> Hi folks!
>
> This message is mostly with the hope that it may be of benefit
> to those experiencing performance issues running plugins. I also
> ask two questions at the end related to implementation of the
> plugins, specifically the SubmitRow plugin.
>
> We had been experiencing performance issues when running plugins
> and discovered that it was because of the dbiDsn string we were
> using in the .gus.properties file.
>
> First, let me describe our environment:
> Our oracle is 9i with the server running on a big Sun machine
> and the client running on linux, with following:
> DBD::Oracle : 1.14
> DBI : 1.38
> OS : linux
> Perl : 5.008
>
> The dbiDsn causing the slow performance follows the same form as
> the one found in the gus.properties.sample in the GUS distribution
> (in install directory). In our case, that dbiDsn is:
> dbiDsn=dbi:Oracle:host=tuor.bioinformatics.vt.edu;sid=gusdev
>
> Following is the result of profiling the following call:
> ga GUS::Common::Plugin::SubmitRow --tablename SRes::ExternalDatabase\
> --attrlist external_database_id,name,lowercase_name\
> --valuelist "200^^^GenBank(main)^^^genbank(main)"
> Total Elapsed Time = 757.1146 Seconds
> User+System Time = 0.484621 Seconds
> Exclusive Times
> %Time ExclSec CumulS #Calls sec/call Csec/c Name
> 12.3 0.060 0.208 11 0.0054 0.0189 GUS::PluginMgr::GusApplication::BEG
> IN
> 8.25 0.040 0.040 4 0.0100 0.0100 DBD::Oracle::db::_login
> 6.19 0.030 0.050 3 0.0100 0.0166 GUS::Model::Core::Algorithm_Row::BE
> GIN
> 6.19 0.030 0.021 914 0.0000 0.0000 GUS::ObjRelP::DbiTable::getFullClas
> sName
> 6.19 0.030 0.039 5 0.0059 0.0078 GUS::ObjRelP::DbiDbHandle::BEGIN
> 4.13 0.020 0.020 3 0.0067 0.0067 DynaLoader::dl_load_file
> 4.13 0.020 0.020 37 0.0005 0.0005 DBI::_setup_handle
> 4.13 0.020 0.020 28 0.0007 0.0007 DBI::st::execute
> 4.13 0.020 0.020 6 0.0033 0.0033 GUS::Model::GusRow::BEGIN
> 4.13 0.020 0.078 37 0.0005 0.0021 GUS::ObjRelP::DbiDatabase::getTable
> 4.13 0.020 0.042 11 0.0018 0.0038 GUS::ObjRelP::DbiTable::BEGIN
> 4.13 0.020 0.238 3 0.0067 0.0793 main::BEGIN
> 4.13 0.020 0.069 4 0.0050 0.0173 GUS::ObjRelP::DbiDatabase::BEGIN
> 3.71 0.018 0.026 1 0.0183 0.0264 GUS::ObjRelP::DbiDatabase::cacheTab
> leNames
> 2.06 0.010 0.008 870 0.0000 0.0000 DBI::st::fetchrow_array
>
> When I change the dbiDsn string to:
> dbiDsn=dbi:Oracle:gusdev.bioinformatics.vt.edu
> profiling results in:
>
> Total Elapsed Time = 1.104655 Seconds
> User+System Time = 0.534655 Seconds
> Exclusive Times
> %Time ExclSec CumulS #Calls sec/call Csec/c Name
> 11.2 0.060 0.055 2470 0.0000 0.0000 GUS::ObjRelP::DbiRow::getTable
> 7.48 0.040 0.050 3 0.0133 0.0166 GUS::Model::Core::Algorithm_Row::BE
> GIN
> 7.48 0.040 0.208 11 0.0036 0.0189 GUS::PluginMgr::GusApplication::BEG
> IN
> 5.61 0.030 0.030 4 0.0075 0.0075 DBD::Oracle::db::_login
> 5.61 0.030 0.028 870 0.0000 0.0000 DBI::st::fetchrow_array
> 5.61 0.030 0.084 951 0.0000 0.0001 GUS::ObjRelP::DbiDatabase::getFullT
> ableClassName
> 5.61 0.030 0.109 15 0.0020 0.0073 GUS::PluginMgr::Plugin::BEGIN
> 5.61 0.030 0.118 37 0.0008 0.0032 GUS::ObjRelP::DbiDatabase::getTable
> 5.61 0.030 0.039 5 0.0059 0.0078 GUS::ObjRelP::DbiDbHandle::BEGIN
> 3.74 0.020 0.020 3 0.0067 0.0067 DynaLoader::dl_load_file
> 3.74 0.020 0.238 3 0.0067 0.0793 main::BEGIN
> 3.37 0.018 0.056 1 0.0183 0.0564 GUS::ObjRelP::DbiDatabase::cacheTab
> leNames
> 1.87 0.010 0.010 30 0.0003 0.0003 Exporter::import
> 1.87 0.010 0.010 15 0.0007 0.0007 CBIL::Util::PropertySet::getProp
> 1.87 0.010 0.010 37 0.0003 0.0003 DBI::st::TIEHASH
>
> As you can see, that's a difference of > 12 minutes vs a little more than 1 sec
> ond.
>
> Question 1:
> Now, looking at the profile results and walking over the code, I see
> that there are several connects made to the database (4 logins shown
> above) with the same parameters.
> An obvious question, is why are several connections made?
>
> Question 2:
> Looking at the profiles above, does it make sense for such a simple submit row
> plugin
> to make so many calls to GUS::ObjRelP::DbiRow::getTable, DBI::st::fetchrow_arra
> y,
> GUS::ObjRelP::DbiDatabase::getFullTableClassName, and others?
>
> Regards
>
> Fidel
>
>
>
> -------------------------------------------------------
> This SF.Net email sponsored by: ApacheCon 2003,
> 16-19 November in Las Vegas. Learn firsthand the latest
> developments in Apache, PHP, Perl, XML, Java, MySQL,
> WebDAV, and more! http://www.apachecon.com/
> _______________________________________________
> Gusdev-gusdev mailing list
> Gus...@li...
> https://lists.sourceforge.net/lists/listinfo/gusdev-gusdev
>
>
>
>
>
> -------------------------------------------------------
> This SF.net email is sponsored by: SF.net Giveback Program.
> Does SourceForge.net help you be more productive? Does it
> help you create better code? SHARE THE LOVE, and help us help
> YOU! Click Here: http://sourceforge.net/donate/
> _______________________________________________
> Gusdev-gusdev mailing list
> Gus...@li...
> https://lists.sourceforge.net/lists/listinfo/gusdev-gusdev
|
