commit 9ffbbf741419eba4413f6bafd92053513a123b8d Author: Karsten Loesing karsten.loesing@gmx.net Date: Thu Oct 13 08:00:11 2011 +0200

Add log statements to analyze database connection usage. --- src/org/torproject/ernie/web/ConsensusServlet.java | 4 +++ .../torproject/ernie/web/DescriptorServlet.java | 12 +++++++++ .../ernie/web/ExoneraTorBetaServlet.java | 25 ++++++++++++++++++++ .../torproject/ernie/web/ExoneraTorServlet.java | 12 +++++++++ .../ernie/web/ExtraInfoDescriptorServlet.java | 4 +++ .../torproject/ernie/web/NetworkStatusServlet.java | 4 +++ .../torproject/ernie/web/RelaySearchServlet.java | 4 +++ src/org/torproject/ernie/web/RelayServlet.java | 12 +++++++++ .../torproject/ernie/web/RouterDetailServlet.java | 4 +++ .../ernie/web/ServerDescriptorServlet.java | 8 ++++++ src/org/torproject/ernie/web/VotesServlet.java | 4 +++ 11 files changed, 93 insertions(+), 0 deletions(-)

diff --git a/src/org/torproject/ernie/web/ConsensusServlet.java b/src/org/torproject/ernie/web/ConsensusServlet.java index d9a6ae1..ad3f4a7 100644 --- a/src/org/torproject/ernie/web/ConsensusServlet.java +++ b/src/org/torproject/ernie/web/ConsensusServlet.java @@ -66,6 +66,7 @@ public class ConsensusServlet extends HttpServlet { String databaseParameter = databaseFormat.format(parsedTimestamp); byte[] rawDescriptor = null; try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); Statement statement = conn.createStatement(); String query = "SELECT rawdesc FROM consensus " @@ -77,6 +78,9 @@ public class ConsensusServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool after " + + (System.currentTimeMillis() - requestedConnection) + + " millis."); } catch (SQLException e) { response.sendError(HttpServletResponse.SC_INTERNAL_SERVER_ERROR); return; diff --git a/src/org/torproject/ernie/web/DescriptorServlet.java b/src/org/torproject/ernie/web/DescriptorServlet.java index 9e84baf..7ee454b 100644 --- a/src/org/torproject/ernie/web/DescriptorServlet.java +++ b/src/org/torproject/ernie/web/DescriptorServlet.java @@ -151,6 +151,7 @@ public class DescriptorServlet extends HttpServlet { if (descId.length() < 40) { SortedSet<String> allDescIds = new TreeSet<String>(); try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); Statement statement = conn.createStatement(); String query = "SELECT DISTINCT descriptor FROM statusentry " @@ -162,6 +163,9 @@ public class DescriptorServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool " + + "after " + (System.currentTimeMillis() + - requestedConnection) + " millis."); } catch (SQLException e) { out.println("<p><font color="red"><b>Warning: </b></font>We " + "experienced an unknown database problem while looking up " @@ -198,6 +202,7 @@ public class DescriptorServlet extends HttpServlet { extrainfo = null; byte[] rawDescriptor = null, rawExtrainfo = null; try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); Statement statement = conn.createStatement(); String query = "SELECT descriptor, nickname, published, extrainfo, " @@ -220,6 +225,9 @@ public class DescriptorServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool after " + + (System.currentTimeMillis() - requestedConnection) + + " millis."); } catch (SQLException e) { out.write("<br/><p><font color="red"><b>Warning: </b></font>" + "Internal server error when looking up descriptor. If this " @@ -267,6 +275,7 @@ public class DescriptorServlet extends HttpServlet {

/* Print out in which consensuses this descriptor is referenced. */ try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); Statement statement = conn.createStatement(); String query = "SELECT validafter, rawdesc FROM statusentry " @@ -297,6 +306,9 @@ public class DescriptorServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool after " + + (System.currentTimeMillis() - requestedConnection) + + " millis."); } catch (SQLException e) { out.println("<p><font color="red"><b>Warning: </b></font>We " + "experienced an unknown database problem while looking up " diff --git a/src/org/torproject/ernie/web/ExoneraTorBetaServlet.java b/src/org/torproject/ernie/web/ExoneraTorBetaServlet.java index c2e7b96..a02b68d 100644 --- a/src/org/torproject/ernie/web/ExoneraTorBetaServlet.java +++ b/src/org/torproject/ernie/web/ExoneraTorBetaServlet.java @@ -151,6 +151,7 @@ public class ExoneraTorBetaServlet extends HttpServlet { /* Open a database connection that we'll use to handle the whole * request. */ Connection conn = null; + long requestedConnection = System.currentTimeMillis(); try { conn = this.ds.getConnection(); } catch (SQLException e) { @@ -187,6 +188,9 @@ public class ExoneraTorBetaServlet extends HttpServlet { writeFooter(out); try { conn.close(); + this.logger.info("Returned a database connection to the pool " + + "after " + (System.currentTimeMillis() + - requestedConnection) + " millis."); } catch (SQLException e) { } return; @@ -374,6 +378,9 @@ public class ExoneraTorBetaServlet extends HttpServlet { writeFooter(out); try { conn.close(); + this.logger.info("Returned a database connection to the pool " + + "after " + (System.currentTimeMillis() + - requestedConnection) + " millis."); } catch (SQLException e) { } return; @@ -455,6 +462,9 @@ public class ExoneraTorBetaServlet extends HttpServlet { writeFooter(out); try { conn.close(); + this.logger.info("Returned a database connection to the pool " + + "after " + (System.currentTimeMillis() + - requestedConnection) + " millis."); } catch (SQLException e) { } return; @@ -584,6 +594,9 @@ public class ExoneraTorBetaServlet extends HttpServlet { writeFooter(out); try { conn.close(); + this.logger.info("Returned a database connection to the pool " + + "after " + (System.currentTimeMillis() + - requestedConnection) + " millis."); } catch (SQLException e) { } return; @@ -670,6 +683,9 @@ public class ExoneraTorBetaServlet extends HttpServlet { writeFooter(out); try { conn.close(); + this.logger.info("Returned a database connection to the pool " + + "after " + (System.currentTimeMillis() + - requestedConnection) + " millis."); } catch (SQLException e) { } return; @@ -722,6 +738,9 @@ public class ExoneraTorBetaServlet extends HttpServlet { writeFooter(out); try { conn.close(); + this.logger.info("Returned a database connection to the pool " + + "after " + (System.currentTimeMillis() + - requestedConnection) + " millis."); } catch (SQLException e) { } return; @@ -908,6 +927,9 @@ public class ExoneraTorBetaServlet extends HttpServlet { writeFooter(out); try { conn.close(); + this.logger.info("Returned a database connection to the pool " + + "after " + (System.currentTimeMillis() + - requestedConnection) + " millis."); } catch (SQLException e) { } return; @@ -983,6 +1005,9 @@ public class ExoneraTorBetaServlet extends HttpServlet { } try { conn.close(); + this.logger.info("Returned a database connection to the pool " + + "after " + (System.currentTimeMillis() + - requestedConnection) + " millis."); } catch (SQLException e) { } writeFooter(out); diff --git a/src/org/torproject/ernie/web/ExoneraTorServlet.java b/src/org/torproject/ernie/web/ExoneraTorServlet.java index 9f7c0cc..da17f3f 100644 --- a/src/org/torproject/ernie/web/ExoneraTorServlet.java +++ b/src/org/torproject/ernie/web/ExoneraTorServlet.java @@ -140,6 +140,7 @@ public class ExoneraTorServlet extends HttpServlet { /* Look up first and last consensus in the database. */ long firstValidAfter = -1L, lastValidAfter = -1L; try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); Statement statement = conn.createStatement(); String query = "SELECT MIN(validafter) AS first, " @@ -152,6 +153,9 @@ public class ExoneraTorServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool after " + + (System.currentTimeMillis() - requestedConnection) + + " millis."); } catch (SQLException e) { /* Looks like we don't have any consensuses. */ } @@ -358,6 +362,7 @@ public class ExoneraTorServlet extends HttpServlet { SortedMap<Long, String> tooNewConsensuses = new TreeMap<Long, String>(); try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); Statement statement = conn.createStatement(); String query = "SELECT validafter, rawdesc FROM consensus " @@ -378,6 +383,9 @@ public class ExoneraTorServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool after " + + (System.currentTimeMillis() - requestedConnection) + + " millis."); } catch (SQLException e) { /* Looks like we don't have any consensuses in the requested interval. */ @@ -601,6 +609,7 @@ public class ExoneraTorServlet extends HttpServlet { for (String descriptor : descriptors) { byte[] rawDescriptor = null; try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); Statement statement = conn.createStatement(); String query = "SELECT rawdesc FROM descriptor " @@ -612,6 +621,9 @@ public class ExoneraTorServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool " + + "after " + (System.currentTimeMillis() + - requestedConnection) + " millis."); } catch (SQLException e) { /* Consider this descriptors as 'missing'. */ continue; diff --git a/src/org/torproject/ernie/web/ExtraInfoDescriptorServlet.java b/src/org/torproject/ernie/web/ExtraInfoDescriptorServlet.java index 8ba33be..0a06865 100644 --- a/src/org/torproject/ernie/web/ExtraInfoDescriptorServlet.java +++ b/src/org/torproject/ernie/web/ExtraInfoDescriptorServlet.java @@ -54,6 +54,7 @@ public class ExtraInfoDescriptorServlet extends HttpServlet { String extrainfo = null; byte[] rawDescriptor = null; try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); Statement statement = conn.createStatement(); String query = "SELECT extrainfo, rawdesc FROM extrainfo " @@ -66,6 +67,9 @@ public class ExtraInfoDescriptorServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool after " + + (System.currentTimeMillis() - requestedConnection) + + " millis."); } catch (SQLException e) { response.sendError(HttpServletResponse.SC_INTERNAL_SERVER_ERROR); return; diff --git a/src/org/torproject/ernie/web/NetworkStatusServlet.java b/src/org/torproject/ernie/web/NetworkStatusServlet.java index 67727c4..7d4abd1 100644 --- a/src/org/torproject/ernie/web/NetworkStatusServlet.java +++ b/src/org/torproject/ernie/web/NetworkStatusServlet.java @@ -76,6 +76,7 @@ public class NetworkStatusServlet extends HttpServlet {

/* Connect to the database and retrieve data set. */ try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); Statement statement = conn.createStatement();

@@ -142,6 +143,9 @@ public class NetworkStatusServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool after " + + (System.currentTimeMillis() - requestedConnection) + + " millis."); request.setAttribute("status", status); request.setAttribute("sort", sortParameter); request.setAttribute("order", (orderParameter.equals("desc")) diff --git a/src/org/torproject/ernie/web/RelaySearchServlet.java b/src/org/torproject/ernie/web/RelaySearchServlet.java index 1791017..4cb9694 100644 --- a/src/org/torproject/ernie/web/RelaySearchServlet.java +++ b/src/org/torproject/ernie/web/RelaySearchServlet.java @@ -383,6 +383,7 @@ public class RelaySearchServlet extends HttpServlet { Map<String, String> rawStatusEntries = new HashMap<String, String>(); int matches = 0; try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); Statement statement = conn.createStatement(); ResultSet rs = statement.executeQuery(query); @@ -434,6 +435,9 @@ public class RelaySearchServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool " + + "after " + (System.currentTimeMillis() + - requestedConnection) + " millis."); } catch (SQLException e) {

/* Tell the user we have a database problem. */ diff --git a/src/org/torproject/ernie/web/RelayServlet.java b/src/org/torproject/ernie/web/RelayServlet.java index 48da03b..037a1e4 100644 --- a/src/org/torproject/ernie/web/RelayServlet.java +++ b/src/org/torproject/ernie/web/RelayServlet.java @@ -162,6 +162,7 @@ public class RelayServlet extends HttpServlet { if (fingerprint.length() < 40) { SortedSet<String> allFingerprints = new TreeSet<String>(); try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); Statement statement = conn.createStatement(); String query = "SELECT DISTINCT fingerprint FROM statusentry " @@ -176,6 +177,9 @@ public class RelayServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool " + + "after " + (System.currentTimeMillis() + - requestedConnection) + " millis."); } catch (SQLException e) { out.println("<p><font color="red"><b>Warning: </b></font>We " + "experienced an unknown database problem while looking up " @@ -211,6 +215,7 @@ public class RelayServlet extends HttpServlet { boolean foundRelay = false; String lastDescriptor = null; try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); Statement statement = conn.createStatement(); String query = "SELECT validafter, rawdesc FROM statusentry WHERE " @@ -266,6 +271,9 @@ public class RelayServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool after " + + (System.currentTimeMillis() - requestedConnection) + + " millis."); } catch (SQLException e) { out.println("<p><font color="red"><b>Warning: </b></font>We " + "experienced an unknown database problem while looking up " @@ -293,6 +301,7 @@ public class RelayServlet extends HttpServlet { byte[] rawDescriptor = null, rawExtrainfo = null; if (lastDescriptor != null) { try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); Statement statement = conn.createStatement(); query = "SELECT descriptor, nickname, published, extrainfo, " @@ -315,6 +324,9 @@ public class RelayServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool " + + "after " + (System.currentTimeMillis() + - requestedConnection) + " millis."); } catch (SQLException e) { out.write("<br/><p><font color="red"><b>Warning: </b></font>" + "Internal server error when looking up descriptor. The " diff --git a/src/org/torproject/ernie/web/RouterDetailServlet.java b/src/org/torproject/ernie/web/RouterDetailServlet.java index c8c4648..033e9e6 100644 --- a/src/org/torproject/ernie/web/RouterDetailServlet.java +++ b/src/org/torproject/ernie/web/RouterDetailServlet.java @@ -75,6 +75,7 @@ public class RouterDetailServlet extends HttpServlet { + "AND statusentry.fingerprint = ?";

try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); PreparedStatement ps = conn.prepareStatement(query); ps.setString(1, fingerprintParameter); @@ -118,6 +119,9 @@ public class RouterDetailServlet extends HttpServlet { return; } conn.close(); + this.logger.info("Returned a database connection to the pool after " + + (System.currentTimeMillis() - requestedConnection) + + " millis.");

} catch (SQLException e) { response.sendError(HttpServletResponse.SC_INTERNAL_SERVER_ERROR); diff --git a/src/org/torproject/ernie/web/ServerDescriptorServlet.java b/src/org/torproject/ernie/web/ServerDescriptorServlet.java index 1db68c4..a970971 100644 --- a/src/org/torproject/ernie/web/ServerDescriptorServlet.java +++ b/src/org/torproject/ernie/web/ServerDescriptorServlet.java @@ -62,6 +62,7 @@ public class ServerDescriptorServlet extends HttpServlet {

/* Look up descriptor in the database. */ try { + long requestedConnection = System.currentTimeMillis(); Connection conn = ds.getConnection(); Statement statement = conn.createStatement(); String query = "SELECT descriptor, rawdesc FROM descriptor " @@ -74,6 +75,9 @@ public class ServerDescriptorServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool " + + "after " + (System.currentTimeMillis() + - requestedConnection) + " millis."); } catch (SQLException e) { response.sendError(HttpServletResponse.SC_INTERNAL_SERVER_ERROR); return; @@ -111,6 +115,7 @@ public class ServerDescriptorServlet extends HttpServlet { databaseFormat.setTimeZone(TimeZone.getTimeZone("UTC")); String databaseParameter = databaseFormat.format(parsedTimestamp); try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); Statement statement = conn.createStatement(); String query = "SELECT descriptor.rawdesc FROM statusentry " @@ -124,6 +129,9 @@ public class ServerDescriptorServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool " + + "after " + (System.currentTimeMillis() + - requestedConnection) + " millis."); } catch (SQLException e) { response.sendError(HttpServletResponse.SC_INTERNAL_SERVER_ERROR); return; diff --git a/src/org/torproject/ernie/web/VotesServlet.java b/src/org/torproject/ernie/web/VotesServlet.java index 6755495..2f07e5d 100644 --- a/src/org/torproject/ernie/web/VotesServlet.java +++ b/src/org/torproject/ernie/web/VotesServlet.java @@ -66,6 +66,7 @@ public class VotesServlet extends HttpServlet { String databaseParameter = databaseFormat.format(parsedTimestamp); List<byte[]> rawDescriptors = new ArrayList<byte[]>(); try { + long requestedConnection = System.currentTimeMillis(); Connection conn = this.ds.getConnection(); Statement statement = conn.createStatement(); String query = "SELECT rawdesc FROM vote " @@ -77,6 +78,9 @@ public class VotesServlet extends HttpServlet { rs.close(); statement.close(); conn.close(); + this.logger.info("Returned a database connection to the pool after " + + (System.currentTimeMillis() - requestedConnection) + + " millis."); } catch (SQLException e) { response.sendError(HttpServletResponse.SC_INTERNAL_SERVER_ERROR); return;