You are viewing a plain text version of this content. The canonical link for it is here.
Posted to oak-commits@jackrabbit.apache.org by re...@apache.org on 2019/06/24 03:03:01 UTC
svn commit: r1861970 - in /jackrabbit/oak/branches/1.8: ./
oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/rdb/
oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/blob/
Author: reschke
Date: Mon Jun 24 03:03:01 2019
New Revision: 1861970
URL: http://svn.apache.org/viewvc?rev=1861970&view=rev
Log:
OAK-8147: RDBBlobStore: add perf logging for JDBC read operations (ported to 1.8)
Modified:
jackrabbit/oak/branches/1.8/ (props changed)
jackrabbit/oak/branches/1.8/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/rdb/RDBBlobStore.java
jackrabbit/oak/branches/1.8/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/blob/RDBBlobStoreTest.java
Propchange: jackrabbit/oak/branches/1.8/
------------------------------------------------------------------------------
--- svn:mergeinfo (original)
+++ svn:mergeinfo Mon Jun 24 03:03:01 2019
@@ -1,3 +1,3 @@
/jackrabbit/oak/branches/1.0:1665962
-/jackrabbit/oak/trunk:1820660-1820661,1820729,1820734,1820859,1820861,1820878,1820888,1820947,1821027,1821130,1821140-1821141,1821178,1821237,1821240,1821249,1821258,1821325,1821358,1821361-1821362,1821370,1821375,1821393,1821477,1821487,1821516,1821617,1821663,1821665,1821668,1821681,1821847,1821975-1821983,1822121,1822182,1822201,1822207,1822527,1822642,1822723,1822808,1822850,1822934,1823135,1823163,1823169,1823172,1823655,1823669,1824196,1824198,1824253,1824255,1824896,1824962,1825065,1825362,1825381,1825442,1825448,1825466,1825470-1825471,1825475,1825523,1825525,1825561,1825619-1825621,1825651,1825654,1825992,1826079,1826090,1826096,1826216,1826237,1826338,1826516,1826532,1826551,1826560,1826638,1826640,1826730,1826833,1826932,1826957,1827423,1827472,1827486,1827816,1827977,1828349,1828439,1828502,1828529,1828827,1828868,1828948,1829527,1829534,1829546,1829569,1829587,1829665,1829854,1829864,1829978,1829985,1829987,1829998,1830019,1830048,1830160,1830171,1830197,1830209,1830239
,1830347,1830748,1830911,1830923,1831157-1831158,1831163,1831190,1831374,1831560,1831689,1832258,1832376,1832379,1832535,1833308,1833347,1833702,1833833,1834109,1834112,1834117,1834287,1834291,1834302,1834312,1834326,1834328,1834336,1834428,1834468,1834483,1834610,1834648-1834649,1834681,1834823,1834857-1834858,1835060,1835518,1835521,1835635,1835642,1835780,1835819,1836082,1836121,1836167-1836168,1836170-1836187,1836189-1836196,1836206,1836487,1836493,1836548,1837057,1837274,1837296,1837326,1837475,1837503,1837547,1837569,1837596,1837600,1837657,1837718,1837998,1838076,1838637,1839549,1839570,1839637,1839746,1840019,1840024,1840031,1840226,1840455,1840462,1840574,1840769,1841314,1841352,1841909,1842089,1842677,1843175,1843222,1843231,1843398,1843618,1843621,1843637,1843652,1843669,1843905,1843911,1844070,1844110,1844325,1844549,1844625,1844627,1844642,1844728,1844775,1844932,1845135,1845336,1845405,1845415,1845730-1845731,1845863,1845865,1846057,1846396,1846429,1846486,1846581,1846
617,1847088,1847096,1848073,1848181-1848182,1848191,1848217,1848822-1848823,1850221,1850343,1850837,1850874,1851533-1851535,1851619,1852120,1852135,1852451,1852492-1852493,1852528,1852582,1852584,1852601,1853141,1853229,1853393,1853429,1853433,1853866,1853868,1853870,1853893,1853969,1853997,1854034,1854044,1854055,1854113,1854455,1854461-1854462,1854466,1854468,1854515,1854539,1854701,1854773,1854827,1854848,1854859,1854930,1855032,1855776,1856056,1856538,1856545,1856818,1857000,1857010,1857221,1857247,1857253,1857294,1857314,1857463,1857480,1857638,1857936,1858032,1858139,1858385,1858424,1858571,1858578,1858810,1858926,1859231,1859292,1859294,1859609,1859612,1859711,1859716,1859772,1859776,1859780,1859843,1859881,1860120,1860131,1860202,1860328,1860548,1861626
+/jackrabbit/oak/trunk:1820660-1820661,1820729,1820734,1820859,1820861,1820878,1820888,1820947,1821027,1821130,1821140-1821141,1821178,1821237,1821240,1821249,1821258,1821325,1821358,1821361-1821362,1821370,1821375,1821393,1821477,1821487,1821516,1821617,1821663,1821665,1821668,1821681,1821847,1821975-1821983,1822121,1822182,1822201,1822207,1822527,1822642,1822723,1822808,1822850,1822934,1823135,1823163,1823169,1823172,1823655,1823669,1824196,1824198,1824253,1824255,1824896,1824962,1825065,1825362,1825381,1825442,1825448,1825466,1825470-1825471,1825475,1825523,1825525,1825561,1825619-1825621,1825651,1825654,1825992,1826079,1826090,1826096,1826216,1826237,1826338,1826516,1826532,1826551,1826560,1826638,1826640,1826730,1826833,1826932,1826957,1827423,1827472,1827486,1827816,1827977,1828349,1828439,1828502,1828529,1828827,1828868,1828948,1829527,1829534,1829546,1829569,1829587,1829665,1829854,1829864,1829978,1829985,1829987,1829998,1830019,1830048,1830160,1830171,1830197,1830209,1830239
,1830347,1830748,1830911,1830923,1831157-1831158,1831163,1831190,1831374,1831560,1831689,1832258,1832376,1832379,1832535,1833308,1833347,1833702,1833833,1834109,1834112,1834117,1834287,1834291,1834302,1834312,1834326,1834328,1834336,1834428,1834468,1834483,1834610,1834648-1834649,1834681,1834823,1834857-1834858,1835060,1835518,1835521,1835635,1835642,1835780,1835819,1836082,1836121,1836167-1836168,1836170-1836187,1836189-1836196,1836206,1836487,1836493,1836548,1837057,1837274,1837296,1837326,1837475,1837503,1837547,1837569,1837596,1837600,1837657,1837718,1837998,1838076,1838637,1839549,1839570,1839637,1839746,1840019,1840024,1840031,1840226,1840455,1840462,1840574,1840769,1841314,1841352,1841909,1842089,1842677,1843175,1843222,1843231,1843398,1843618,1843621,1843637,1843652,1843669,1843905,1843911,1844070,1844110,1844325,1844549,1844625,1844627,1844642,1844728,1844775,1844932,1845135,1845336,1845405,1845415,1845730-1845731,1845863,1845865,1846057,1846396,1846429,1846486,1846581,1846
617,1847088,1847096,1848073,1848181-1848182,1848191,1848217,1848822-1848823,1850221,1850343,1850837,1850874,1851533-1851535,1851619,1852120,1852135,1852451,1852492-1852493,1852528,1852582,1852584,1852601,1853141,1853229,1853393,1853429,1853433,1853866,1853868,1853870,1853893,1853969,1853997,1854034,1854044,1854055,1854113,1854455,1854461-1854462,1854466,1854468,1854515,1854539,1854701,1854773,1854827,1854848,1854859,1854930,1855032,1855776,1856049,1856056,1856538,1856545,1856818,1857000,1857010,1857221,1857247,1857253,1857294,1857314,1857463,1857480,1857638,1857936,1858032,1858139,1858385,1858424,1858571,1858578,1858810,1858926,1859231,1859292,1859294,1859609,1859612,1859711,1859716,1859772,1859776,1859780,1859843,1859881,1860120,1860131,1860202,1860328,1860548,1861626
/jackrabbit/trunk:1345480
Modified: jackrabbit/oak/branches/1.8/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.8/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/rdb/RDBBlobStore.java?rev=1861970&r1=1861969&r2=1861970&view=diff
==============================================================================
--- jackrabbit/oak/branches/1.8/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/rdb/RDBBlobStore.java (original)
+++ jackrabbit/oak/branches/1.8/oak-store-document/src/main/java/org/apache/jackrabbit/oak/plugins/document/rdb/RDBBlobStore.java Mon Jun 24 03:03:01 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.8/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.8/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/blob/RDBBlobStoreTest.java?rev=1861970&r1=1861969&r2=1861970&view=diff
==============================================================================
--- jackrabbit/oak/branches/1.8/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/blob/RDBBlobStoreTest.java (original)
+++ jackrabbit/oak/branches/1.8/oak-store-document/src/test/java/org/apache/jackrabbit/oak/plugins/document/blob/RDBBlobStoreTest.java Mon Jun 24 03:03:01 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();
+ }
+ }
}