Thanks Martin, I agree, regardless of use case, the pool should not
generate a leak.
let me review your proposal
Filip
On Wed, Jul 18, 2018 at 07:48 Martin Knoblauch <kn...@knobisoft.de> wrote:
> On Wed, Jul 18, 2018 at 3:24 PM, Martin Knoblauch <kn...@knobisoft.de>
> wrote:
>
> > Hi Filip,
> >
> > On Fri, Jul 13, 2018 at 4:33 PM, Filip Hanik <fi...@hanik.com> wrote:
> >
> >> hi Martin,
> >>
> >> On Fri, Jul 13, 2018 at 5:48 AM, Martin Knoblauch <kn...@knobisoft.de>
> >> wrote:
> >>
> >> > Hi, (moving to developers list)
> >> >
> >> > any ideas on the problem below? This thing is kind of itching me :-)
> >> >
> >> > So I instrumented the "StatementFinalizer" class with some logging and
> >> > learned that over time a few instances of the "StatementFinalizer" are
> >> > created, used and destroyed. So far so good. For most of those
> >> instances,
> >> > the overall number of statements that are added to the "statements"
> >> list by
> >> > "createStatement" and the number of statements removed from the list
> by
> >> > "closeInvoked" is identical and after "closeInvoked" finishes, the
> list
> >> is
> >> > empty.
> >> >
> >> > But only for most instances of "StatementFinalizer". I could find
> that
> >> > there is one instance that is used (statements are added), but the
> >> > invocation of "closednvoked" stops after some minutes into the
> >> application.
> >> > As a result the "statements" list starts growing.
> >> >
> >>
> >> ​Could it be that your application checks out a connection and uses it
> for
> >> the life time of the application?
> >> Meaning Connection.close is never called?
> >>
> >>
> > So in fact some instrumentation and digging deeper showed 3 different
> > problems in the application:
> >
> > 1) there is one SQL Statement not closed (revealed by
> > "StatementFinalizer(trace=true)")
> > 2) there is one connection not closed after the "final" SQL statement
> > (revealed by properly activating the "Abandoned" mechanism)
> > 3) there is one connection that is used heavily over the entire lifetime
> > of the application, and never closed. This one accumulates the memory
> that
> > made me ask the "leak" question
> >
> > Need to address all three to the application developers.
> >
> > Given that 1+2 each only happen once, the best solution to avoid the
> > "leak" might really be to just not use the "StatementFinalizer".
> >
> >
> >
> But then, just for the fun of it, would something like this patch be of
> interest? It adds a private method "removeClosed()" to the
> "StatementFinalizer code. What it does is to remove all "closed" or "null"
> statements from the "statements" list. In order to keep it low in the
> performance profile, it only does this every "sweepMinutes" minutes (new
> interceptor property). My testing shows it keeps the memory consumption
> down.
>
> Martin
>
> ---
>
> apache-tomcat-8.0.36-src/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/StatementFinalizer.java
> 2016-06-09 16:00:49.000000000 +0200
> +++
>
> apache-tomcat-8.0.36-src-mkn/modules/jdbc-pool/src/main/java/org/apache/tomcat/jdbc/pool/interceptor/StatementFinalizer.java
> 2018-07-18 14:53:35.242785369 +0200
> @@ -18,7 +18,9 @@
>
> import java.lang.ref.WeakReference;
> import java.lang.reflect.Method;
> +import java.sql.SQLException;
> import java.sql.Statement;
> +import java.util.Iterator;
> import java.util.LinkedList;
> import java.util.List;
> import java.util.Map;
> @@ -40,15 +42,64 @@
> protected List<StatementEntry> statements = new LinkedList<>();
>
> private boolean logCreationStack = false;
> + private long sweepMillis = 0;
> + private long lastSweep = 0;
> +
> + private int addedStmts = 0;
> +
> +/**
> + * Removes closed or "null" statements from the "statements" list. Useful
> for connections that are
> + * never closed. Returns without doing anything in the following cases:
> + * - Interceptor property "sweepMinutes" is 0 (default)
> + * - First call after "borrow"
> + * - Time difference between now and last sweep has not reached yet
> + * - Only one statement on list (or list is empty)
> + */
> + private void removeClosed() {
> +
> + if (sweepMillis == 0) // Nothing to do
> + return;
> + if (lastSweep == 0) { // First time around. Nothing to do
> + lastSweep = System.currentTimeMillis();
> + return;
> + }
> + if ((System.currentTimeMillis() - lastSweep) < sweepMillis) // Age not
> reached, nothing to do
> + return;
> + if (statements.size() < 2) // empty, or exactely one statement (has
> just been added), nothing to do
> + return;
> +
> + lastSweep = System.currentTimeMillis();
> + Iterator it = statements.iterator();
> + int clsdStmts = 0;
> + int nullStmts = 0;
> + while(it.hasNext()){
> + StatementEntry ws = (StatementEntry)it.next();
> + Statement st = ws.getStatement();
> + try {
> + if (st == null) nullStmts++;
> + else if (st.isClosed()) clsdStmts++;
> + if ((st == null) || st.isClosed()) it.remove();
> + } catch (SQLException e) {
> + //ignore this one
> + }
> + }
> + if (log.isDebugEnabled())
> + log.debug(" Statements since last sweep: added= "+addedStmts+",
> closed= "+
> + clsdStmts+", null="+nullStmts+", remaining=
> "+statements.size());
> + addedStmts = 0; // re-arm
> + }
>
> @Override
> public Object createStatement(Object proxy, Method method, Object[]
> args, Object statement, long time) {
> try {
> - if (statement instanceof Statement)
> + if (statement instanceof Statement) {
> statements.add(new StatementEntry((Statement)statement));
> + addedStmts++;
> + }
> }catch (ClassCastException x) {
> //ignore this one
> }
> + removeClosed();
> return statement;
> }
>
> @@ -71,9 +122,12 @@
> } finally {
> if (logCreationStack && shallClose) {
> log.warn("Statement created, but was not closed at:",
> ws.getAllocationStack());
> - }
> + } else if (shallClose) {
> + log.warn("Statement created, but was not closed. No
> dump created");
> + }
> }
> }
> + lastSweep = 0; // Re-arm long term sweeper
> }
>
> @Override
> @@ -84,6 +138,11 @@
> if (null != logProperty) {
> logCreationStack =
> logProperty.getValueAsBoolean(logCreationStack);
> }
> +
> + PoolProperties.InterceptorProperty sweepProperty =
> properties.get("sweepMinutes");
> + if (null != sweepProperty) {
> + sweepMillis = sweepProperty.getValueAsLong(sweepMillis) * 60 *
> 1000; // in millisconds
> + }
> }
>
> @Override
>
>
> --
> ------------------------------------------------------
> Martin Knoblauch
> email: k n o b i AT knobisoft DOT de
> www: http://www.knobisoft.de
>
