Re: DBD::Pg, DBD::Oracle and others are slow with threads due to DBIS

On Wed, Mar 14, 2012 at 08:24:36AM +0100, H.Merijn Brand wrote:
> On Tue, 13 Mar 2012 21:44:06 +0000, Tim Bunce <[email protected]>
> wrote:
> 
> > On Fri, Mar 02, 2012 at 03:11:17PM +0000, Tim Bunce wrote:
> > > > 
> > > > The second patch, which makes DBIS more efficient, is a lot more complex,
> > > > and more likely to break things (especially as it's changing a bunch of
> > > > macros that are directly #included by the DBD drivers. You may need to
> > > > bump API version numbers; I don't understand that bit.
> > > 
> > > I'm concerned that changing the API, and thus forcing all compiled
> > > drivers to be recompiled at the same time the DBI is installed,
> > > isn't worth the gain. Especially as drivers shouldn't be using DBIS in
> > > any hot code anyway.
> > 
> > I finally got around to looking at DBD::Pg and was horrified to discover
> > the number of DBIS calls made by hot paths in the code. Most are hidden
> > behind various tracing macros. Even fetch calls 3 + 3 * num_of_fields!
> 
> When hidden, it won't stand out to the maintainers.
> 
> How do we/I see where it happens? Do you have a (short) guide to check
> if my/a DBD (CSV, Unify, File) uses those too?

The slowness of the DBIS macro is only relevant for compiled drivers.
The DBIS macro is used to get a pointer to the DBI's struct dbistate_st.
In non-threaded perls it's simply a static variable initialised once.
In threaded perls it's a macro that has to do more expensive work.

For many years now all DBI handles have had their own pointer to
dbistate_st. Since almost all code in the driver has access to a handle
that's the best way to get the dbistate_st struct pointer.

Essentially it means changing all instances of DBIS to DBIc_DBISTATE(imp_xxh)
(where imp_xxh can be any of the imp_dbh, imp_sth etc variables).

Looking at DBIXS.h I see these other macros that use DBIS and thus
should be avoided in hot code:

    DBILOGFP        => DBIc_LOGPIO(imp_xxh)
    DBILOGMSG(...)  => DBIc_DBISTATE(imp_xxh)->logmsg(...)
    neatsvpv(...)   => DBIc_DBISTATE(imp_xxh)->neatsvpv(...)

however, usually those are only called in tracing code so it may not be
worth the effort to change them.

The DBIh_COM(h) macro also uses DBIS but there's a chicken-and-egg
problem here since DBIh_COM is the underlying mechanism of the
D_imp_xxh(h) macros used to get the imp_xxh pointer. So it can't be
avoided. Yet more reason to apply Dave's changes.

Tim.

p.s. For the logic to control tracing I recommend the DBIc_TRACE macro
(or something driver-specific like it or built using it):
    DBIc_TRACE(imp, flags, flag_level, fallback_level)

That's true if flags match the handle trace flags & handle trace
level >= flag_level, OR if handle trace_level > fallback_level

   DBIc_TRACE(imp,              0, 0, 4) = if handle trace level >= 4
   DBIc_TRACE(imp, DBDf_TRACE_FOO, 2, 4) = if tracing DBDf_TRACE_FOO & level>=2 OR level>=4
   DBIc_TRACE(imp, DBDf_TRACE_FOO, 2, 0) = as above but never trace just due to level

For example:

    if (DBIc_TRACE(imp_xxh, DBIf_TRACE_SQL|DBIf_TRACE_xxx, 3, 7)) {
        PerlIO_printf(DBIc_LOGPIO(imp_sth), "\tThe %s wibbled the %s\n", ...);
    }