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
