fetchSize (around 1000), as the default fetch size caused up to 60× slowdown from network overhead.
PhysicalConnection.removeFromTemporaryLobs.
A closer look at the code
class PhysicalConnection {
protected List<OracleLargeObject> temporaryLobs;
public void removeFromTemporaryLobs(OracleLargeObject paramOracleLargeObject) {
try {
Iterator<OracleLargeObject> iterator = this.temporaryLobs.iterator();
while (iterator.hasNext()) {
OracleLargeObject oracleLargeObject = iterator.next();
if (oracleLargeObject.equals(paramOracleLargeObject))
iterator.remove();
}
} catch (Exception exception) {}
}From this code we can consider the potential problems to be:
- No indexing/distinguishing (for example, by hashCode()) for temporaryLobs
- Missing break after
iterator.remove() - CPU usage of oracleLargeObject.equals(paramOracleLargeObject)
- Unnecessary ignored exceptions
- Calling .remove() without break suggests that one CLOB can be registered multiple times.
- At the same time, removing one of the duplicates will remove all of them and make others unavailable, which negates the point of having duplicates in the first place.
- Scanning on add would cost CPU, and we don’t know whether duplicates really occur. Given known memory leak issues related to CLOB-s, duplicates might be intentional as a workaround.
Investigation
- Replacing CLOBs with null removed all delay on the MyBatis/Java side - confirming focus placed on this aspect.
- Moving row reading (CLOBs included) to pure JDBC removed the delays - which initially confused attempts to establish the problem source.
- Passing CLOB as VARCHAR removed delays (in both pure JDBC and MyBatis) as well - so data transfer itself was not the problem.
- To gauge potential damage I tried to introduce variables into the process. Sadly, inducing the problem gradually was difficult, as it either did not happen at all or turned a 2‑minute query into an hour‑long run.
- The only constant was the size of PhysicalConnection.temporaryLobs:
- when execution was fast its size correlated with one row;
- when execution was slow, its size correlated with the large fetch size
- Some tests showed that executing the same SQL on a heavily used server could be faster (due to lower CLOB accumulation), so to avoid misleading results, meaningful measurements were collected at night, when traffic is low and the server is more stable.
- Search showed that there were CLOB‑related issues in ojdbc; for this reason I switched from ojdbc 19.3.0.0 to ojdbc 19.32.0.0. This seems to have solved the MyBatis problem, but from the overall situation I was not sure how much was fixed, as degradation seems to depend on many seemingly irrelevant conditions. I also wanted to be sure it will not come back or show itself in Hibernate or under higher load/GC spikes.
- Factors that seem to influence the problem’s appearance pattern:
- Faster servers
- Slower clients
- Slower row handlers like MyBatis
- Higher fetch size (indirectly)
- Temporary local CPU usage spikes
- More columns and their types
Dedicated test
create or replace type o_JdbcClobRow as object (no NUMBER, varText VARCHAR2(4000 BYTE), clobText CLOB
, t1 TIMESTAMP, t2 TIMESTAMP, t3 TIMESTAMP, t4 TIMESTAMP, t5 TIMESTAMP, t6 TIMESTAMP, t7 TIMESTAMP, t8 TIMESTAMP, t9 TIMESTAMP);
create or replace type t_JdbcClobRows as table of o_JdbcClobRow;
create or replace FUNCTION generateJdbcClobRows(
pSize IN NUMBER
, pMode IN VARCHAR2 DEFAULT 'both'
, pOversized IN NUMBER DEFAULT 0
, pOversizedLength IN NUMBER DEFAULT 65536
, pSleepEvery IN INTEGER DEFAULT 0
)
RETURN t_JdbcClobRows PIPELINED
AS
vMode VARCHAR2(32767) := LOWER(TRIM(pMode));
vNo NUMBER := 1;
vMarker VARCHAR2(100);
vVarText VARCHAR2(4000);
vClob CLOB;
vClobBase CLOB;
vRow o_JdbcClobRow;
vBaseLength INTEGER;
vIsOversized BOOLEAN;
BEGIN
IF pSize IS NULL OR pSize < 0 OR pSize <> TRUNC(pSize) THEN
raise_application_error(-20000, 'pSize must be a nonnegative integer');
END IF;
IF vMode IS NULL OR vMode NOT IN ('both', 'var', 'clob', 'bothsame') THEN
raise_application_error(-20000, 'pMode must be both, var or clob');
END IF;
IF pOversized IS NULL OR pOversized < 0 OR pOversized <> TRUNC(pOversized) THEN
raise_application_error(-20000, 'pOversized must be a nonnegative integer (0 disables oversizing)');
END IF;
DBMS_LOB.CREATETEMPORARY(vClobBase, TRUE, DBMS_LOB.CALL);
DBMS_LOB.WRITEAPPEND(vClobBase, LENGTH('(chunk)'), '(chunk)');
vBaseLength := DBMS_LOB.GETLENGTH(vClobBase);
WHILE vBaseLength <= pOversizedLength LOOP
DBMS_LOB.COPY(vClobBase, vClobBase, vBaseLength, vBaseLength + 1, 1);
vBaseLength := DBMS_LOB.GETLENGTH(vClobBase);
END LOOP;
WHILE vNo <= pSize LOOP
vIsOversized := pOversized > 0 AND MOD(vNo, pOversized) = 0;
vMarker := TO_CHAR(vNo, 'TM9');
vVarText := NULL;
vClob := NULL;
IF vIsOversized THEN
IF vMode IN ('both', 'clob', 'bothsame') THEN
vClob := vClobBase || ' : '||vMode||'[' || vMarker || ']' ;
ELSE
vVarText := 'var[' || vMarker || ']';
END IF;
ELSE
IF vMode IN ('bothsame') THEN
vVarText := vClobBase || ' : '||vMode||'[' || vMarker || ']' ;
ELSE
vVarText := 'var[' || vMarker || ']';
END IF;
END IF;
vRow := o_JdbcClobRow(vNo, vVarText, vClob, SYSTIMESTAMP, SYSTIMESTAMP, SYSTIMESTAMP, SYSTIMESTAMP, SYSTIMESTAMP, SYSTIMESTAMP, SYSTIMESTAMP, SYSTIMESTAMP, SYSTIMESTAMP);
vClob := NULL;
IF pSleepEvery>0 and MOD(vNo, pSleepEvery) = 0 THEN
DBMS_SESSION.SLEEP(1/100);
END IF;
IF pSleepEvery<0 THEN
DBMS_SESSION.SLEEP(-pSleepEvery/100);
END IF;
PIPE ROW(vRow);
vRow := NULL;
vNo := vNo + 1;
END LOOP;
IF DBMS_LOB.ISTEMPORARY(vClobBase) = 1 THEN
DBMS_LOB.FREETEMPORARY(vClobBase);
END IF;
RETURN;
EXCEPTION
WHEN NO_DATA_NEEDED THEN
IF DBMS_LOB.ISTEMPORARY(vClob) = 1 THEN
DBMS_LOB.FREETEMPORARY(vClob);
END IF;
IF DBMS_LOB.ISTEMPORARY(vClobBase) = 1 THEN
DBMS_LOB.FREETEMPORARY(vClobBase);
END IF;
RETURN;
WHEN OTHERS THEN
IF DBMS_LOB.ISTEMPORARY(vClob) = 1 THEN
DBMS_LOB.FREETEMPORARY(vClob);
END IF;
IF DBMS_LOB.ISTEMPORARY(vClobBase) = 1 THEN
DBMS_LOB.FREETEMPORARY(vClobBase);
END IF;
RAISE;
END generateJdbcClobRows;
public List<Object[]> generateJdbcClobRowsRaw(Integer size, String mode, Integer oversized, Integer oversizedLength, Integer cacheSize, int fetchSize) {
final String sql = "select * from table (generateJdbcClobRows(?, ?, ?, ?))";
final ArrayList<Clob> cache = new ArrayList<java.sql.Clob>();
final ArrayList<Object[]> ret = getJdbcTemplate().query(connection -> {
final java.sql.PreparedStatement ps = connection.prepareStatement(sql);
ps.setObject(1, size);
ps.setObject(2, mode);
ps.setObject(3, oversized);
ps.setObject(4, oversizedLength);
ps.setFetchSize(1000);
return ps;
}, rs -> {
final ArrayList<Object[]> rows = new ArrayList<Object[]>();
final int columnCount = rs.getMetaData().getColumnCount();
while (rs.next()) {
final Object[] row = new Object[columnCount];
for (int i = 1; i <= columnCount; i++) {
Object object = rs.getObject(i);
if (object instanceof java.sql.Clob) {
if (cacheSize == null) {
object = clobToString((java.sql.Clob) object);
} else {
object = clobToString((java.sql.Clob) object, cache, cacheSize);
}
}
row[i - 1] = object;
}
rows.add(row);
}
return rows;
});
while (!cache.isEmpty()) {
try {
cache.remove(0).free();
} catch (SQLException e) {}
}
return ret;
}
public static String clobToString(java.sql.Clob clob) throws java.sql.SQLException {
return clobToString(clob, null, null);
}
public static String clobToString(java.sql.Clob clob, List<java.sql.Clob> cache, Integer cacheSize) throws java.sql.SQLException {
if (clob == null) {
return null;
}
if (cache!=null && cache.size()>cacheSize) {
final Clob remove = cache.remove(0);
remove.free();
}
try {
try (java.io.Reader reader = clob.getCharacterStream()) {
StringBuilder result = new StringBuilder();
char[] buffer = new char[8192];
int count;
while ((count = reader.read(buffer)) != -1) {
result.append(buffer, 0, count);
}
return result.toString();
} catch (java.io.IOException e) {
throw new java.sql.SQLException("Failed to read CLOB", e);
}
} catch (java.sql.SQLException | RuntimeException | Error e) {
throw e;
} finally {
if (cache!=null) {
cache.add(clob);
}
else {
clob.free();
}
}
}Results: for 100 000 rows
Varying fetch size | ||||||
|---|---|---|---|---|---|---|
| clob aperance frequency |
clob length |
cache size |
fetch size |
time (19.3.0.0) |
time (19.23.0.0) |
time (19.32.0.0) |
| 1/1 | 200 | 1000 | 5 | 13 s | 15 s | 15 s |
| 1/1 | 200 | 1000 | 50 | 15 s | 13 s | 12 s |
| 1/1 | 200 | 1000 | 200 | 12 s | 13 s | 12 s |
| 1/1 | 200 | 1000 | 500 | 12 s | 13 s | 12 s |
| 1/1 | 200 | 1000 | 1000 | 12 s | 13 s | 11 s |
| 1/1 | 200 | 1000 | 10000 | 14 s | 14 s | 11 s |
Varying CLOB length | ||||||
| clob aperance frequency |
clob length |
cache size |
fetch size |
time (19.3.0.0) |
time (19.23.0.0) |
time (19.32.0.0) |
| 1/1 | 20 | 1000 | 200 | 13 s | 11 s | 11 s |
| 1/1 | 200 | 1000 | 200 | 12 s | 13 s | 12 s |
| 1/1 | 2000 | 1000 | 200 | 138 s | 138 s | 144 s |
| 1/1 | 4000 | 1000 | 200 | 5054 s | ||
Varying CLOB length with lower CLOB frequency (1/10): | ||||||
| clob aperance frequency |
clob length |
cache size |
fetch size |
time (19.3.0.0) |
time (19.23.0.0) |
time (19.32.0.0) |
| 1/10 | 200 | 1000 | 200 | 11 s | 11 s | 12 s |
| 1/10 | 2000 | 1000 | 200 | 16 s | 20 s | 14 s |
| 1/10 | 20000 | 1000 | 200 | 473 s | 474 s | 493 s |
Varying cache size | ||||||
| clob aperance frequency |
clob length |
cache size |
fetch size |
time (19.3.0.0) |
time (19.23.0.0) |
time (19.32.0.0) |
| 1/1 | 200 | null | 200 | 12 s | 12 s | 16 s |
| 1/1 | 200 | 100 | 200 | 13 s | 12 s | 13 s |
| 1/1 | 200 | 1000 | 200 | 12 s | 12 s | 11 s |
| 1/1 | 200 | 10000 | 200 | 33 s | 38 s | 13 s |
| 1/1 | 200 | 20000 | 200 | 72 s | 66 s | 16 s |
| 1/1 | 200 | 30000 | 200 | 112 s | 104 s | 14 s |
VARCHAR data carrier for same data volume | ||||||
| clob aperance frequency |
clob length |
cache size |
fetch size |
time (19.3.0.0) |
time (19.32.0.0) | |
| 1/1 | 2000 | 1000 | 200 | 143 s | 139 s | |
| 1/10 | 2000 | 100 | 200 | 67 s | 65 s | |
| 1/20 | 2000 | 50 | 200 | 67 s | 62 s | |
| 1/50 | 2000 | 20 | 200 | 43 s | 37 s | |
| 1/100 | 2000 | 10 | 200 | 34 s | 42 s | |
Conclusions:
- Fetch size - Alone, it does not cause performance degradation. However, depending on the execution engine, it can correlate with how CLOBs are released.
- CLOB length - Has a strong impact on performance. Particular attention should be paid to large CLOBs multiplied by JOIN operations. With ordinary strings, comparisons often terminate early when a difference is found. With CLOBs, however, long values combined with JOIN multiplication can result in repeated full scans during comparison.
- Cache size - Shows direct correlation to problems with exception of ojdbc 19.32.0.0
- VARCHAR data carier - Transferring the same data using VARCHAR columns provides measurable performance improvements.
Summary
- I would recommend temporarily excluding CLOBs (replacing them with NULL) when investigating suspected performance problems. This is a quick and effective way to determine whether CLOB handling is contributing to the problem.
- Although it's not really good style, the analytic function LAG can help int eliminating duplicated CLOBs. As Oracle documentation describes it, LAG provides access to a row at a specified physical offset before the current position in the result set.
- Separating short strings into VARCHAR columns can provide excellent performance resluts.
- Investing in a more powerful database server can actually be detrimental to overall application performance.
- The 5054 seconds example is not an isolated case. I simply wasn't patient enough to wait for the other tests to finish.
0 comments / komentarz(y):
Post a Comment