Re: [Proxool-developer] Spurious connections caused by Prototyper's apparently wrong connectionCount

[Hrvoje N. <hn...@xe...>]

Bill Horsman <arc...@gm...> writes:

>   Isn't there a hint on how I could fix the problem with the
>   Prototyper's connectionCount?  Is the protection from calling
>   reallyClose() twice the correct approach?
>
> I'm not sure. Does the number of extra connections created
> correspond with the number of reported connections that were closed
> automatically?

The additional connections apparently coincide with the occurrence of
this messag:

2005-09-27 01:36:57 WARN  [poolname] [Thread-18]: #1660 - There were some problems resetting the connection (see debug output for details). It will not be used again (just in case). The thread that is responsible is named 'Thread-18'

It seems to occur after the HouseKeeper forcibly removes the
connection.  In our logs the number of these messages equals the
number of additional connections in the pool.

An example:

2005-09-27 01:36:56 DEBUG [poolname] [HouseKeeper]: 1003445 -000257 (04/31/00) - #1660 removed because it has been active for too long.
2005-09-27 01:36:56 WARN  [poolname] [HouseKeeper]: #1660 was active for 144709 milliseconds and has been removed automaticaly. The Thread responsible was named 'Thread-18'.
2005-09-27 01:36:56 DEBUG [poolname] [Prototyper]: 1003445 -000257 (04/32/00) - Connection #1665 created to achieve minimum of 2 = AVAILABLE
2005-09-27 01:36:57 WARN  [poolname] [Thread-18]: #1660 - There were some problems resetting the connection (see debug output for details). It will not be used again (just in case). The thread that is responsible is named 'Thread-18'
2005-09-27 01:36:57 WARN  [poolname] [Thread-18]: #1660 - The connection was closed with autoCommit=false. That is fine, but it might indicate that the problems that happened whilst trying to reset it were because a transaction is still in progress.
2005-09-27 01:36:57 DEBUG [poolname] [Thread-18]: 1003445 -000257 (04/32/00) - #1660 removed because it couldn't be reset.
2005-09-27 01:36:57 WARN  [poolname] [Thread-18]: Unable to set status of connection 1660 from ACTIVEto AVAILABLE. It remains NULL

Note especially these two lines:

    2005-09-27 01:36:56 WARN  [poolname] [HouseKeeper]: #1660 was active for 144709 milliseconds and has been removed automaticaly. The Thread responsible was named 'Thread-18'.
    [...]
    2005-09-27 01:36:57 DEBUG [poolname] [Thread-18]: 1003445 -000257 (04/32/00) - #1660 removed because it couldn't be reset.

The connection #1660 has been removed twice, which means it could have
decremented connectionCount twice as well.

What do you think?