Author: reschke
Date: Fri Apr 26 09:08:45 2019
New Revision: 1858186
URL: http://svn.apache.org/viewvc?rev=1858186&view=rev
Log:
OAK-8147: RDBBlobStore: add perf logging for JDBC read operations (ported to
1.10)
Modified:
jackrabbit/oak/branches/1.10/ (props changed)
jackrabbit/oak/branches/1.10/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/rdb/RDBBlobStore.java
jackrabbit/oak/branches/1.10/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/blob/RDBBlobStoreTest.java
Propchange: jackrabbit/oak/branches/1.10/
------------------------------------------------------------------------------
--- svn:mergeinfo (original)
+++ svn:mergeinfo Fri Apr 26 09:08:45 2019
@@ -1,3 +1,3 @@
/jackrabbit/oak/branches/1.0:1665962
-/jackrabbit/oak/trunk:1850874,1850882,1851236,1851253,1851451,1851533-1851535,1851619,1852052,1852084,1852120,1852451,1852492-1852493,1852528,1852582,1852584,1852601,1852920,1853083,1853141,1853229,1853393,1853429,1853433,1853441,1853866,1853868,1853870,1853893,1853969,1853997,1854034,1854044,1854055,1854058,1854113,1854373,1854377,1854380,1854385,1854401,1854403,1854455,1854461-1854462,1854466,1854468,1854515,1854533,1854539,1854701,1854773-1854774,1854827,1854848,1854859,1854930,1854990-1854991,1855032,1855221,1855477-1855478,1855776,1855993,1857010,1857104,1857159,1857212,1857221,1857238,1857247,1857253,1857294,1857314,1857577,1857635,1857638,1857640,1857687,1857936,1858032,1858123
+/jackrabbit/oak/trunk:1850874,1850882,1851236,1851253,1851451,1851533-1851535,1851619,1852052,1852084,1852120,1852451,1852492-1852493,1852528,1852582,1852584,1852601,1852920,1853083,1853141,1853229,1853393,1853429,1853433,1853441,1853866,1853868,1853870,1853893,1853969,1853997,1854034,1854044,1854055,1854058,1854113,1854373,1854377,1854380,1854385,1854401,1854403,1854455,1854461-1854462,1854466,1854468,1854515,1854533,1854539,1854701,1854773-1854774,1854827,1854848,1854859,1854930,1854990-1854991,1855032,1855221,1855477-1855478,1855776,1855993,1856049,1857010,1857104,1857159,1857212,1857221,1857238,1857247,1857253,1857294,1857314,1857577,1857635,1857638,1857640,1857687,1857936,1858032,1858123
/jackrabbit/trunk:1345480
Modified:
jackrabbit/oak/branches/1.10/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/rdb/RDBBlobStore.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/branches/1.10/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/rdb/RDBBlobStore.java?rev=1858186&r1=1858185&r2=1858186&view=diff
==============================================================================
---
jackrabbit/oak/branches/1.10/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/rdb/RDBBlobStore.java
(original)
+++
jackrabbit/oak/branches/1.10/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/rdb/RDBBlobStore.java
Fri Apr 26 09:08:45 2019
@@ -41,6 +41,7 @@ import java.util.concurrent.TimeUnit;
import javax.sql.DataSource;
+import org.apache.jackrabbit.oak.commons.PerfLogger;
import org.apache.jackrabbit.oak.commons.StringUtils;
import org.apache.jackrabbit.oak.plugins.blob.CachingBlobStore;
import org.apache.jackrabbit.oak.plugins.document.DocumentStoreException;
@@ -121,6 +122,8 @@ public class RDBBlobStore extends Cachin
}
private static final Logger LOG =
LoggerFactory.getLogger(RDBBlobStore.class);
+ private static final PerfLogger PERFLOG = new PerfLogger(
+ LoggerFactory.getLogger(RDBBlobStore.class.getName() + ".perf"));
// ID size we need to support; is 2 * (hex) size of digest length
protected static final int IDSIZE;
@@ -345,20 +348,29 @@ public class RDBBlobStore extends Cachin
// needed in test
protected byte[] readBlockFromBackend(byte[] digest) throws Exception {
- String id = StringUtils.convertBytesToHex(digest);
+ return readBlockFromBackend(StringUtils.convertBytesToHex(digest));
+ }
+
+ private byte[] readBlockFromBackend(String id) throws Exception {
Connection con = this.ch.getROConnection();
byte[] data;
try {
+ long pstart = PERFLOG.start(PERFLOG.isDebugEnabled() ? ("reading:
" + id) : null);
PreparedStatement prep = con.prepareStatement("select DATA from "
+ this.tnData + " where ID = ?");
ResultSet rs = null;
try {
prep.setString(1, id);
rs = prep.executeQuery();
if (!rs.next()) {
+ PERFLOG.end(pstart, 10, "read: table={}, id={} -> not
found", this.tnData, id);
throw new IOException("Datastore block " + id + " not
found");
}
data = rs.getBytes(1);
+ PERFLOG.end(pstart, 10, "read: table={}, id={} -> data={}",
this.tnData, id, (data == null ? 0 : data.length));
+ } catch (SQLException ex) {
+ PERFLOG.end(pstart, 10, "read: table={} -> exception={}",
this.tnData, ex.getMessage());
+ throw ex;
} finally {
closeResultSet(rs);
closeStatement(prep);
@@ -377,32 +389,12 @@ public class RDBBlobStore extends Cachin
byte[] data = cache.get(id);
if (data == null) {
- Connection con = this.ch.getROConnection();
long start = System.nanoTime();
- try {
- PreparedStatement prep = con.prepareStatement("select DATA
from " + this.tnData + " where ID = ?");
- ResultSet rs = null;
- try {
- prep.setString(1, id);
- rs = prep.executeQuery();
- if (!rs.next()) {
- throw new IOException("Datastore block " + id + " not
found");
- }
- data = rs.getBytes(1);
- } finally {
- closeResultSet(rs);
- closeStatement(prep);
- }
-
- getStatsCollector().downloaded(id, System.nanoTime() - start,
TimeUnit.NANOSECONDS, data.length);
- cache.put(id, data);
- } finally {
- con.commit();
- this.ch.closeConnection(con);
- }
+ data = readBlockFromBackend(id);
+ getStatsCollector().downloaded(id, System.nanoTime() - start,
TimeUnit.NANOSECONDS, data.length);
+ cache.put(id, data);
}
- // System.out.println(" read block " + id + " blockLen: " +
- // data.length + " [0]: " + data[0]);
+
if (blockId.getPos() == 0) {
return data;
}
Modified:
jackrabbit/oak/branches/1.10/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/blob/RDBBlobStoreTest.java
URL:
http://svn.apache.org/viewvc/jackrabbit/oak/branches/1.10/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/blob/RDBBlobStoreTest.java?rev=1858186&r1=1858185&r2=1858186&view=diff
==============================================================================
---
jackrabbit/oak/branches/1.10/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/blob/RDBBlobStoreTest.java
(original)
+++
jackrabbit/oak/branches/1.10/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/blob/RDBBlobStoreTest.java
Fri Apr 26 09:08:45 2019
@@ -16,6 +16,7 @@
*/
package org.apache.jackrabbit.oak.plugins.document.blob;
+import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertTrue;
import static org.junit.Assert.fail;
@@ -30,6 +31,7 @@ import java.util.List;
import java.util.Random;
import org.apache.jackrabbit.oak.commons.StringUtils;
+import org.apache.jackrabbit.oak.commons.junit.LogCustomizer;
import org.apache.jackrabbit.oak.plugins.document.rdb.RDBBlobStore;
import org.apache.jackrabbit.oak.plugins.document.rdb.RDBBlobStoreFriend;
import org.apache.jackrabbit.oak.plugins.document.rdb.RDBDataSourceWrapper;
@@ -42,6 +44,7 @@ import org.junit.runner.RunWith;
import org.junit.runners.Parameterized;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
+import org.slf4j.event.Level;
import com.google.common.collect.ImmutableList;
import com.google.common.collect.Lists;
@@ -274,4 +277,30 @@ public class RDBBlobStoreTest extends Ab
messageDigest.update(bytes, 0, bytes.length);
return messageDigest.digest();
}
+
+ @Test
+ public void testRDBJDBCPerfLog() throws Exception {
+ LogCustomizer logCustomizerRead =
LogCustomizer.forLogger(RDBBlobStore.class.getName() +
".perf").enable(Level.TRACE)
+ .matchesRegex("read: .*").create();
+ logCustomizerRead.starting();
+ try {
+ byte[] data = new byte[256];
+ Random r = new Random(0);
+ r.nextBytes(data);
+ byte[] digest = getDigest(data);
+ RDBBlobStoreFriend.storeBlock(blobStore, digest, 0, data);
+
Assert.assertNotNull(RDBBlobStoreFriend.readBlockFromBackend(blobStore,
digest));
+ assertEquals(1, logCustomizerRead.getLogs().size());
+
+ r.nextBytes(data);
+ digest = getDigest(data);
+ try {
+
Assert.assertNotNull(RDBBlobStoreFriend.readBlockFromBackend(blobStore,
digest));
+ } catch (IOException expected) {
+ assertEquals(2, logCustomizerRead.getLogs().size());
+ }
+ } finally {
+ logCustomizerRead.finished();
+ }
+ }
}
