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

On 14/03/2012 10:20, Tim Bunce wrote:
> 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(...)
DBD::ODBC had none of the above.
>      neatsvpv(...)   =>  DBIc_DBISTATE(imp_xxh)->neatsvpv(...)
DBD::ODBC had a number of these however, the suggested change does not work:

original:

           if (DBIc_TRACE(imp_sth, DBD_TRACING, 0, 4)) {
               TRACE2(imp_sth, "    ODBC_CLEAR_RESULTS '%s' => %s\n",
                      key, neatsvpv(value,0));
           }
new:
           if (DBIc_TRACE(imp_sth, DBD_TRACING, 0, 4)) {
               TRACE2(imp_sth, "    ODBC_CLEAR_RESULTS '%s' => %s\n",
                      key, (DBIc_DBISTATE(imp_sth)->neatsvpv(value,0)));
           }

compiler error:

dbdimp.c: In function 'odbc_clear_result_set':
dbdimp.c:233: error: expected identifier before '(' token
dbdimp.c: In function 'odbc_db_STORE_attrib':
dbdimp.c:4672: warning: cast to pointer from integer of different size
dbdimp.c:4677: warning: cast to pointer from integer of different size
dmake:  Error code 129, while making 'dbdimp.o'

I've not really looked into it yet.

> however, usually those are only called in tracing code so it may not be
> worth the effort to change them.
ok, but I'm happy to do it in my case.

I've now changed DBD::ODBC to remove all unnecessary calls to D_imp_whatever.

> 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)
I will change DBD::Oracle to use DBIc_TRACE at the weekend. I've started getting rid of DBIS from DBD::Oracle but as you said it is a bit of a PITA to do although not difficult.
> 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", ...);
>      }
Martin