Re: DBI Mysql Driver Handle Mysteriously Changes!

[Tim Bunce]

On Thu, Mar 27, 2014 at 04:43:41PM +1300, Duncan McEwan wrote:
 
   I've got 1000's of lines of debugging showing this happening.  Some of it
   is my own, inserted as print statements or cluck calls directly into 
   DBI.pm
   and some of it the standard DBI debugging set to level 9.  There is way 
   too
   much to include in this message, but I've included some small extracts 
   below
   to illustrate what I am seeing.
  
  What you've included doesn't show the drh changing.
 
 Then maybe I'm mis-interpreting the debugging I'm seeing?

No, nevermind, I was. Thanks.

  I suggest you focus on that. Specifically the code path taken by the
  request that notices that the drh has changed, _and_ the code path taken
  by the _previous_ request _in the same process_.
 
 Yes.  I had been looking at that.  Within DBI.pm I've inserted calls to
 cluck so I could see the stack trace both the case when a cached database
 handle is returned and when a new one is created.  There were *sometimes*
 differences in the call stack between those times, but sometimes not.
 
 At the moment I only turn DBI tracing on in the connect_cached() call and
 turn it off again before the call returns.  I did that because I was worried
 about the amount of output that would be produced if I left tracing on.
 But perhaps that is what I will have to do.

Perhaps you don't need to output it. Call $stacktrace = Carp::longmess
and only output it if the stacktrace is different to the last one, or
some similar logic.

Also try turning on $drh-{TraceLevel} after the $dbh is created.
That'll then log just future connect_cached calls *and* handle
destruction, which might be useful.

 A potential further complication that I didn't mention previously is that
 our application (which I *did* mention is written as a foswiki plugin)
 uses the CGI::Application perl package.  From a very quick look at its
 code, it does seem to know about the DBI and could perhaps be doing something
 too clever which is causing us problems.  I'll look more into that as
 well.

I didn't see anything suspicious in CGI::Application
https://metacpan.org/source/MARKSTOS/CGI-Application-4.50/lib/CGI/Application.pm
or CGI::Application::Plugin::DBH
https://metacpan.org/source/FREW/CGI-Application-Plugin-DBH-4.04/lib/CGI/Application/Plugin/DBH.pm

For more areas to dig, note the mention of dbi_connect_method
in https://metacpan.org/pod/DBI#connect and
https://metacpan.org/source/TIMB/DBI-1.631/DBI.pm#L571

Keep focused on why a new drh appears.

See https://metacpan.org/source/TIMB/DBI-1.631/DBI.pm#L652
Perhaps something is altering %DBI::installed_drh

Tim.

Re: DBI Mysql Driver Handle Mysteriously Changes!

[Duncan McEwan]

Hi,

  
  At the moment I only turn DBI tracing on in the connect_cached() call and
  turn it off again before the call returns.  I did that because I was worried
  about the amount of output that would be produced if I left tracing on.
  But perhaps that is what I will have to do.
 
 Perhaps you don't need to output it. Call $stacktrace = Carp::longmess
 and only output it if the stacktrace is different to the last one, or
 some similar logic.

I decided I had enough disk space to just leave debugging on for a bit and
a quick look at the debugging I'm getting now shows something that seems
odd and potentially may be interesting.

I'm now getting debugging for more than just calls to connect_cached().
It seems that as well as calling DBI-connect_cached() for it's connections to
one database, our application is also calling DBI-connect() for connections
to a different database (I think this may be buried in the CGI::Application
package that the application uses, which is why I hadn't noticed it before).

Both databases are on the same mysql server.

I haven't looked at it in detail yet (and as it's nearly home time on Friday
evening here won't have time to look at it properly until later!).  But the
quick look I have had seems to reveal that the driver handle changes after
each call (or maybe only some calls?) to DBI-connect().

Perhaps a more in-depth examination will show I've misinterpreted the debugging
and this isn't what is happening.  If so, I'll post a followup message later.
But I thought it worth posting this message now to ask if this sounds like
something that could happen.  And if it could, is it a feature or a bug?

Thanks for all the help/pointers so far...

Duncan