On Friday I tried to recreate this issue using iptables (to block all outgoing traffic to 3306) but was still unable to recreate it. After unblocking 3306 the pool would eventually recover and create new connections. So I still do not understand why it was necessary to restart Tomcat to resolve the original problem.
Since I cannot recreate the problem the best I can do is adjust some settings to help evaluate it if (when) it happens again in the future. 1. Turn on the 'abanonded' settings per your suggestions so I can see if the app is actually leaking connections. 2. Turn up pool logging to FINE. When a connection attempt times out or fails it logs at this level. 3. Possibly enable connect and TCP read timeouts on the mysql jdbc driver. Per the docs they are 'infinite' by default, but I think lower timeouts would help to detect network/firewall problems more quickly. And I'm writing a script to perform stack traces, heap dumps, lsof for open files, etc., to run on the jvm process before restarting in the event this happens again. Who knows, maybe the problem was 10000 open sockets or something. Thank you for your time looking into this. I appreciate it. Regards, Colin Thank you Filip for all your help. On Thu, Mar 22, 2012 at 9:39 PM, Filip Hanik Mailing Lists < devli...@hanik.com> wrote: > Pretty much you're guaranteed to have a network problem at that point. You > see Java caches DNS translations forever, and yanking VPN like that may > change around IPs but the JVM is not aware of that. Wireshark would tell > you that. Now relying in VPN is never a good thing, but maybe it's > required. You could try > 1. Use IP instead of host name in your jdbc URL > 2. Configure the JRE to not cache dns lookups, (network.properties) > > > The error you see tells you that: > 1. The pool doesn't have any idle established connections idle=0 > 2. The pool doesn't have any connections used by other threads busy=0 > 3. There is currently 1 thread trying to activate a connection size=1. The > size is an atomic counter to protect against overuse in a lock free way. > > > Filip > > > > Hi Filip, > > Today I have been trying to recreate the issue by disconnecting from the > vpn, as: > 1. Start app. Pool creates some connections via the vpn. > 2. Test app a bit to execute sql queries. > 3. Shut down the vpn > 4. Force some more queries. Predictably, connections fail and exceptions > show up in the logs. > 5. Restore vpn connection > 6. Check if pool creates new connections, which it does not. > > I also upgraded to the latest pool available in maven > central: tomcat-jdbc-7.0.26.jar > > I understand this could still be a connection leak in my application. But > the new pool version logs an error I don't understand: > ... stack trace ... > Caused by: java.sql.SQLException: [scheduler-low-1] Timeout: Pool empty. > Unable to fetch a connection in 10 seconds, none available[size:1; busy:0; > idle:0; lastwait:10000]. > ... more trace ... > > The relevant part of my current pool DataSource configuration: > removeAbandonedTimeout="10" > removeAbandoned="true" > logAbandoned="true" > > defaultAutoCommit="false" > maxActive="1" maxIdle="1" minIdle="1" maxWait="10000" > testOnBorrow="true" > validationQuery="SELECT 1" > > I also have yet to see any "abandoned" log messages. > > Should the pool always have at least 1 busy or idle connection? If not > would it create another? > > Thanks, > Colin > > > > > On Thu, Mar 22, 2012 at 11:11 AM, Filip Hanik Mailing Lists < > devli...@hanik.com> wrote: > > > > Ultimately tho I'd still like to see some debug logging from the pool > > > itself. Is there a simple way to turn it on? > > > > not to the problem you are looking at. if a connection got taken out of > > the pool, and it passed validation, then everything is ok. > > at this point the SQLException you get has all the data, and the problem > > is probably at the network level > > > > the fact that you see that for 2 hours and problem goes away with > restart, > > that can only be the app holding on to the flawed connection, cause there > > would have been several validations during the 2 hour period :) I think > > there is a loop somewhere that when it fails it just retries and retries, > > logAbandoned will show that though. > > > > Filip > > > > > > > > > > ----- Original Message ----- > > > From: "Colin Ingarfield" <colin...@gmail.com> > > > To: "Tomcat Users List" <users@tomcat.apache.org> > > > Sent: Thursday, March 22, 2012 8:06:14 AM > > > Subject: Re: how to enable debug logging for Tomcat jdbc pool (Tomcat > > 6.0.32) > > > > > > Ah, Wireshark. My friend calls it the "universal debugger". :) > > > > > > I will set the validation interval to 1 and keep an eye on the > > > network to > > > see what's going on. I may also install MySql locally so I can kill > > > it > > > easily to try and simulation connection timeouts. I won't really > > > feel this > > > is resolved until I can recreate the original issue. > > > > > > > > > > > Thanks, > > > Colin > > > > > > On Wed, Mar 21, 2012 at 11:20 AM, Filip Hanik Mailing Lists < > > > devli...@hanik.com> wrote: > > > > > > > it will take a while to see the abandoned log. I'm not implying > > > > every > > > > request hogs the connection, but that you could have ended up in a > > > > scenario > > > > where that did happen. > > > > otherwise, you would have not seen the problem for 2 hours and to > > > > go away > > > > when the system was restarted, as it should have failed on > > > > validation. > > > > > > > > You can enable validation every single time by doing > > > > > > > > validationInterval="1" > > > > > > > > after that, if it was me, I'd start pulling in something like > > > > Wireshark to > > > > see what is going on > > > > > > > > Filip > > > > > > > > ----- Original Message ----- > > > > > From: "Colin Ingarfield" <colin...@gmail.com> > > > > > To: "Tomcat Users List" <users@tomcat.apache.org> > > > > > Sent: Wednesday, March 21, 2012 10:11:43 AM > > > > > Subject: Re: how to enable debug logging for Tomcat jdbc pool > > > > > (Tomcat > > > > 6.0.32) > > > > > > > > > > I added the 3 abandoned settings but I don't see any indication > > > > > in > > > > > the > > > > > tomcat log that connections are being abandoned. I also made the > > > > > max > > > > > pool > > > > > size pretty small.. my application would have failed quickly if > > > > > all > > > > > the > > > > > connections we're being incorrectly held up. > > > > > > > > > > Anything else I can try? Thanks again for your help. > > > > > > > > > > -- Colin > > > > > > > > > > On Wed, Mar 21, 2012 at 10:41 AM, Filip Hanik Mailing Lists < > > > > > devli...@hanik.com> wrote: > > > > > > > > > > > Got it, thank you. > > > > > > The other way this can happen is if the application checks out > > > > > > a > > > > > > connection and then never returns it, and expects it to be > > > > > > used. > > > > > > For this you will want to enable > > > > > > > > > > > > removeAbandonedTimeout="60" > > > > > > removeAbandoned="true" > > > > > > logAbandoned="true" > > > > > > > > > > > > this should tell you pretty quickly if you got a component that > > > > > > is > > > > > > hogging > > > > > > the connection. So test that first. Now if that is the case, > > > > > > there > > > > > > is a way > > > > > > to fix that: > > > > > > > > > > > > 1. remove the above settings > > > > > > 2. compile and configure the interceptor described in: > > > > > > https://issues.apache.org/bugzilla/show_bug.cgi?id=52024 > > > > > > In this interceptor, when a failure occurs, it automatically > > > > > > reconnects > > > > > > and retries the operation. And that is the only way to get > > > > > > around > > > > > > the > > > > > > problem (assuming my assumption is correct) > > > > > > > > > > > > > > > > > > Filip > > > > > > ----- Original Message ----- > > > > > > > From: "Colin Ingarfield" <colin...@gmail.com> > > > > > > > To: users@tomcat.apache.org > > > > > > > Sent: Wednesday, March 21, 2012 9:30:46 AM > > > > > > > Subject: Re: how to enable debug logging for Tomcat jdbc pool > > > > > > > (Tomcat > > > > > > 6.0.32) > > > > > > > > > > > > > > My configuration: > > > > > > > > > > > > > > <Resource auth="Container" > > > > > > > name="jdbc/cdb.mysql" > > > > > > > defaultAutoCommit="false" > > > > > > > driverClassName="com.mysql.jdbc.Driver" > > > > > > > factory="org.apache.tomcat.jdbc.pool.DataSourceFactory" > > > > > > > > > url="jdbc:mysql://XXXXX.com/XXXX_dev?sessionVariables=TRANSACTION > > > > > > > ISOLATION LEVEL READ COMMITTED" > > > > > > > username="XXXXX" > > > > > > > password="XXXXX" > > > > > > > > > > > > > > maxActive="100" > > > > > > > maxIdle="100" > > > > > > > minIdle="10" > > > > > > > initialSize="10" > > > > > > > maxWait="10000" > > > > > > > testOnBorrow="true" > > > > > > > type="javax.sql.DataSource" > > > > > > > validationQuery="SELECT 1"/> > > > > > > > > > > > > > > > > > > > > > I have testOnBorrow and validationQuery set as you suggest, > > > > > > > so I > > > > > > > do > > > > > > > not > > > > > > > think that is the issue. > > > > > > > > > > > > > > Thanks, > > > > > > > Colin > > > > > > > > > > > > > > > > > > > > > --------------------------------------------------------------------- > > > > > > To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org > > > > > > For additional commands, e-mail: users-h...@tomcat.apache.org > > > > > > > > > > > > > > > > > > > > > > > > > --------------------------------------------------------------------- > > > > To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org > > > > For additional commands, e-mail: users-h...@tomcat.apache.org > > > > > > > > > > > > > > > --------------------------------------------------------------------- > > To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org > > For additional commands, e-mail: users-h...@tomcat.apache.org > > > > > > --------------------------------------------------------------------- > To unsubscribe, e-mail: users-unsubscr...@tomcat.apache.org > For additional commands, e-mail: users-h...@tomcat.apache.org > >
