From: <ssk...@vh...> - 2005-09-15 12:37:04
|
Author: sskracic Date: 2005-09-15 14:27:38 +0200 (Thu, 15 Sep 2005) New Revision: 813 Modified: ccm-core/trunk/src/com/arsdigita/persistence/PooledConnectionSource.java ccm-core/trunk/src/com/arsdigita/runtime/RuntimeConfig.java Log: JDBC connection debugging aid. Keeps track of all open JDBC connections in a CacheTable, so they can be monitored through webdev support. In addition to connection count tracking, a 'tag' is associated with every open JDBC connection. The tag is obtained as a db-dependent query result. For postgres, it will be the PID of a server backend serving that JDBC conn. For Oracle, it will be audited session identifier. /ccm/ds/cache-table browser will display all JDBC connections together with their associated tags (under 'Value' column). The tag can also be used to rename the thread using a particular JDBC conn. Whenever a thread acquires JDBC connection, its name gets '-db$tag' suffix. This can be of great help when a thread dump is performed, b/c we can now correlate Java threads with database sessions to see, for example, where Java code holds exclusive db locks so that other threads are waiting etc. There are two caveats though: 1. single persistence Session can span multiple JDBC connections 2. thread renaming is sticky, which means a thread will retain its '-db$tag' suffix even after it releases the database connection. In practice, this will often manifest as two or more threads having the same -'db$tag' suffix when a thread dump is performed. However, it's not such a big deal, b/c at most one of them will be involved in db activity. And finally, thread renaming gimmick can be disabled by setting the waf.runtime.thread_tagging to 'false' (it's enabled by default). Modified: ccm-core/trunk/src/com/arsdigita/persistence/PooledConnectionSource.java =================================================================== --- ccm-core/trunk/src/com/arsdigita/persistence/PooledConnectionSource.java 2005-09-15 09:03:01 UTC (rev 812) +++ ccm-core/trunk/src/com/arsdigita/persistence/PooledConnectionSource.java 2005-09-15 12:27:38 UTC (rev 813) @@ -18,10 +18,14 @@ */ package com.arsdigita.persistence; +import com.arsdigita.caching.CacheTable; +import com.arsdigita.db.DbHelper; +import com.arsdigita.runtime.RuntimeConfig; import com.arsdigita.util.UncheckedWrapperException; import com.arsdigita.util.jdbc.Connections; import java.sql.Connection; import java.sql.DatabaseMetaData; +import java.sql.PreparedStatement; import java.sql.ResultSet; import java.sql.SQLException; import java.util.ArrayList; @@ -45,6 +49,11 @@ private static final Logger s_log = Logger.getLogger(PooledConnectionSource.class); + private static CacheTable s_connectionTags = + new CacheTable("jdbcConnectionTags", + RuntimeConfig.getConfig().getJDBCPoolSize() + 10, + CacheTable.MAX_CACHE_AGE); + private String m_url; private int m_size; private long m_interval; @@ -52,6 +61,9 @@ private List m_available = new ArrayList(); private List m_untested = new ArrayList(); + private static boolean s_taggingEnabled = + RuntimeConfig.getConfig().isThreadTaggingEnabled(); + public PooledConnectionSource(String url, int size, long interval) { m_url = url; m_size = size; @@ -82,7 +94,8 @@ return (Connection) m_available.remove(ndx); } else { if (s_log.isDebugEnabled()) { - s_log.debug("Reacquisition failed: " + pref); + s_log.debug("Reacquisition failed: " + pref + + ", tag: " + s_connectionTags.get(pref.toString())); } return acquire(); } @@ -91,10 +104,14 @@ public synchronized Connection acquire() { while (true) { if (!m_available.isEmpty()) { - return (Connection) m_available.remove(0); + Connection conn = (Connection) m_available.remove(0); + renameThread(conn); + return conn; } else if (m_connections.size() < m_size) { Connection result = (Connection) Connections.acquire(m_url); + s_connectionTags.put(result.toString(), tag(result)); m_connections.add(result); + renameThread(result); return result; } else { try { wait(); } @@ -105,6 +122,53 @@ } } + private void renameThread(Connection conn) { + if (s_taggingEnabled) { + Thread curr = Thread.currentThread(); + String tname = curr.getName(); + String ctag = (String) s_connectionTags.get(conn.toString()); + if (ctag == null) { + s_log.warn("Could not obtain conn tag for: " + conn); + return; + } + String newName = tname.replaceAll("(-db[0-9]*)*$", "") + "-db" + ctag; + if (!tname.equals(newName)) { + if (s_log.isDebugEnabled()) { + s_log.debug("setting the thread name to: " + newName); + } + curr.setName(newName); + } + } + } + + private static final String tag(final Connection conn) { + final int database = DbHelper.getDatabase(conn); + try { + String sql = ""; + String tag = ""; + switch (database) { + case DbHelper.DB_POSTGRES: + sql = "select pg_backend_pid() as tag"; + break; + case DbHelper.DB_ORACLE: + sql = "select userenv('SESSIONID') as tag from dual"; + break; + } + PreparedStatement stmt = conn.prepareStatement(sql); + ResultSet rs = stmt.executeQuery(); + if (rs.next()) { + tag = rs.getString(1).trim(); + rs.close(); + } + stmt.close(); + s_log.info("Tagging JDBC connection: " + conn + " with tag: " + tag); + return tag; + } catch (SQLException e) { + throw new UncheckedWrapperException(e); + } + } + + public synchronized void release(Connection conn) { if (!m_connections.contains(conn)) { throw new IllegalArgumentException @@ -131,6 +195,8 @@ private synchronized void remove(Connection conn) { m_connections.remove(conn); m_available.remove(conn); + s_log.info("removed: " + conn + ", tag: " + s_connectionTags.get(conn.toString())); + s_connectionTags.remove(conn.toString()); } synchronized void testAvailable() { @@ -173,7 +239,9 @@ Connection conn = (Connection) it.next(); SQLException e = test(conn); if (e != null) { - s_log.warn("connection failed test", e); + s_log.warn("connection " + conn + + ", tag: " + s_connectionTags.get(conn.toString()) + + " failed test", e); try { conn.close(); } catch (SQLException ex) { Modified: ccm-core/trunk/src/com/arsdigita/runtime/RuntimeConfig.java =================================================================== --- ccm-core/trunk/src/com/arsdigita/runtime/RuntimeConfig.java 2005-09-15 09:03:01 UTC (rev 812) +++ ccm-core/trunk/src/com/arsdigita/runtime/RuntimeConfig.java 2005-09-15 12:27:38 UTC (rev 813) @@ -19,6 +19,7 @@ package com.arsdigita.runtime; import com.arsdigita.util.jdbc.JDBCURLParameter; +import com.arsdigita.util.parameter.BooleanParameter; import com.arsdigita.util.parameter.IntegerParameter; import com.arsdigita.util.parameter.Parameter; import org.apache.log4j.Logger; @@ -59,6 +60,7 @@ private final Parameter m_poolSize; private final Parameter m_pingInterval; private final Parameter m_queryCacheSize; + private final Parameter m_threadTagging; /** * Constructs an empty RuntimeConfig object. @@ -75,11 +77,16 @@ m_queryCacheSize = new IntegerParameter ("waf.runtime.query_cache_size", Parameter.OPTIONAL, new Integer(2000)); + m_threadTagging = new BooleanParameter + ("waf.runtime.thread_tagging", + Parameter.REQUIRED, + Boolean.TRUE); register(m_url); register(m_poolSize); register(m_pingInterval); register(m_queryCacheSize); + register(m_threadTagging); loadInfo(); } @@ -112,4 +119,8 @@ return ((Integer) get(m_queryCacheSize)).intValue(); } + public final boolean isThreadTaggingEnabled() { + return ((Boolean)get(m_threadTagging)).booleanValue(); + } + } |