On 05/12/12 03:33, Duncan McEwan wrote:
Hi,

So to summarize, you are seeing that sometimes connect_cached uses
a previous entry, and sometimes it does not, right? ...
... When the connect_cached fails with a false negative, it is because
the CachedKids hash is empty, when it should have at least one existing
item, right?

Good summary!  Yes, the problem only occurs occasionally.  Based on the
debugging I have in DBI.pm, out of approx 160,000 calls to connect_cached()
over the last 2 days, the problem occurred around 360 times.

I'd bump up the trace level to at least 3 ...

I had thought about turning on DBI tracing but I was a bit worried about
the amount of output that would be generated.  But having just read the
"TRACING" section of the DBI pod I see that I can also specify that I only
want to trace the connection process, so maybe it won't be so bad.  I'll try
it and find out!

If you mean the CON trace flag I think you are going to be disappointed. 
Although DBI defines this trace flag you'll get very little out of it. There is 
only one DBD which I know (DBD::ODBC) which adds anything for CON tracing. When 
I connect using CON tracing and DBD::mysql I get:

$ perl -le 'use DBI; DBI->trace(DBI->parse_trace_flag('CON'));my $h = 
DBI->connect_cached("dbi:mysql:database=test");$h->disconnect; $h = undef;$h = 
DBI->connect_cached("dbi:mysql:database=test");'

    -> default_user in DBD::_::dr for DBD::mysql::dr 
(DBI::dr=HASH(0x8f7d180)~0x8f7d2f0 undef undef HASH(0x8f8c130))
    <- default_user= ( undef undef ) [2 items] at DBI.pm line 646
    -> connect_cached in DBD::_::dr for DBD::mysql::dr 
(DBI::dr=HASH(0x8f7d180)~0x8f7d2f0 'database=test' undef **** HASH(0x8f8c130))
    <- connect_cached= ( DBI::db=HASH(0x9018e80) ) [1 items] at DBI.pm line 658
    -> connected in DBD::_::db for DBD::mysql::db 
(DBI::db=HASH(0x9018e80)~0x9018f70 'dbi:mysql:database=test' undef **** 
HASH(0x8eed1a8))
    <- connected= ( undef ) [1 items] at DBI.pm line 720
    -> disconnect for DBD::mysql::db (DBI::db=HASH(0x9018e80)~0x9018f70)
    <- disconnect= ( 1 ) [1 items] at -e line 1
    -> default_user in DBD::_::dr for DBD::mysql::dr 
(DBI::dr=HASH(0x8f7d180)~0x8f7d2f0 undef undef HASH(0x9018d00))
    <- default_user= ( undef undef ) [2 items] at DBI.pm line 646
    -> connect_cached in DBD::_::dr for DBD::mysql::dr 
(DBI::dr=HASH(0x8f7d180)~0x8f7d2f0 'database=test' undef **** HASH(0x9018d00))
    <- connect_cached= ( DBI::db=HASH(0x8f80ab0) ) [1 items] at DBI.pm line 658
    -> connected in DBD::_::db for DBD::mysql::db 
(DBI::db=HASH(0x8f80ab0)~0x8f80b10 'dbi:mysql:database=test' undef **** 
HASH(0x9019530))
    <- connected= ( undef ) [1 items] at DBI.pm line 720
    -> disconnect_all for DBD::mysql::dr (DBI::dr=HASH(0x8f7d180)~0x8f7d2f0)
    <- disconnect_all= ( ) [0 items] (not implemented) at DBI.pm line 737
    >> DESTROY DBI::dr=HASH(0x8f7d2f0) clearing 1 CachedKids

which apart from the clearing 1 CachedKids I don't think tells you much.

If you add/change tracing whilst you are debugging and you think it is useful 
please feed it back.

or at least check out the clear_cached_kids function inside of DBI.xs
and get some debugging there to see who is clearing that cache ...

Delving into the C code was also something I was hoping to avoid, but if
turning on DBI connection tracing doesn't reveal anything I'll have a
look at that.

It is not that bad. The clear_cached_kids is in DBI.xs and the tracing code is 
fairly straight forward. Bear in mind you might have to rebuild DBD::mysql 
after some changes to DBI.


As far as DBI itself, I
think only destroying a handle will call that function, and that
function is the only thing that will empty out {CachedKids}.

Sounds reasonable.  I'll see if debugging or code inspection reveals any
way that a handle could be destroyed without the connection being closed.

The other thing to consider is the web app. I know that Apache::DBI/
modperl has a lot of special rules regarding connecting and reconnecting:
it's possible your fastcgi does as well.  You might also want to poke
around with the mysql_auto_reconnect setting; it's possible it is on and
causing issues.

Yes - I did see a test for the GATEWAY_INTERFACE env variable in
DBD::mysql::connect() which causes the mysql_auto_reconnect setting to be
turned on.  That was the only reference I found (in the perl code at least)
to that environment variable.  From what I could make out, if MOD_PERL is set
a whole different connection procedure is invoked using Apache::DBI::connect,
but that doesn't seem to be the case if running under fastcgi.

Anyway, thanks for the pointers.  I'll report back with any extra information
I find.

Duncan

Martin
--
Martin J. Evans
Easysoft Limited
http://www.easysoft.com

Reply via email to