Re: [CDBI] Make name_lc go fast

Perrin Harkins wrote:
> On 4/2/07, Brad Bowman <[email protected]> wrote:
>> After profiling a CDBI app I found that Class::DBI::Column::name_lc is
>> second on the list and in my case, actually does nothing, the names are
>> already in lower case:
>>
>> dprofpp
> 
> Please use the -r flag, so you can measure real time.  It's not very
> useful to measure CPU time when doing something like DBI calls that
> wait a long time but don't use much CPU.

Thanks for pointing that out.  I should also make it clear that I'm using
SQLite so the times probably don't reflect typical CDBI time vs db time
anyway.

Rerunning with -r I get the opposite result, somehow not doing the lc
makes things slower.  If this is a real effect, it could be due to my
Column class inheriting Class::DBI::Column.  I also suspect that
the subs may be so small and quick that the differences are artifacts
of the profiling.  The results:

# With the normal name_lc
dprofpp -r
Total Elapsed Time = 36.17648 Seconds
          Real Time = 36.17648 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
  13.6   4.937  4.937  16543   0.0003 0.0003  DBI::st::execute
  10.8   3.911  3.911 146409   0.0000 0.0000  Class::Accessor::Fast::__ANON__
  9.37   3.389  6.984 134747   0.0000 0.0000  Class::DBI::Column::name_lc
  6.78   2.454  2.453 752834   0.0000 0.0000  Class::Data::Inheritable::__ANON__
  5.99   2.167 24.691   8270   0.0003 0.0030  Class::DBI::_insert
  5.74   2.078 33.448   8270   0.0003 0.0040  Class::DBI::insert
  5.09   1.843  8.822 134667   0.0000 0.0000  Class::DBI::Column::__ANON__
  4.50   1.628  1.628 266059   0.0000 0.0000  Class::DBI::Column::groups
[...]

# With name_lc hacked out (not doing lc() at all)
dprofpp -r
Total Elapsed Time = 53.41692 Seconds
          Real Time = 53.41692 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
  10.8   5.786  5.786 146409   0.0000 0.0000  Class::Accessor::Fast::__ANON__
  10.3   5.536 10.979 134667   0.0000 0.0000  DDict::CDBI::Column::__ANON__
  8.62   4.603  4.603  16543   0.0003 0.0003  DBI::st::execute
  5.54   2.957  2.957 752834   0.0000 0.0000
Class::Data::Inheritable::__ANON__
  5.09   2.719 31.835   8270   0.0003 0.0038  Class::DBI::_insert
  5.04   2.694  7.665 351877   0.0000 0.0000  Class::DBI::find_column
  4.31   2.304 42.810   8270   0.0003 0.0052  Class::DBI::insert
[...]

I timed the commands separately and found a small ~5% improvement
without the name_lc so I can't explain the Elapsed Times above.
Any hints?

Brad

-- 
  Among the words spoken by great generals, there are some that were said
  offhandedly. One should not receive these words in the same manner, however.
     -- Hagakure http://bereft.net/hagakure/