Added some debugging code to determine the cause of the "open cursors"

problem
opensourceBIM · Sep 19, 2014 · 3fcd5a6 · 3fcd5a6
1 parent 93b30d5
commit 3fcd5a6
Show file tree

Hide file tree

Showing 5 changed files with 65 additions and 16 deletions.
diff --git a/BimServer/src/org/bimserver/database/DatabaseSession.java b/BimServer/src/org/bimserver/database/DatabaseSession.java
@@ -142,7 +142,11 @@ public void close() {
 		database.unregisterSession(this);
 		database.incrementReads(reads);
 		if (bimTransaction != null) {
-			bimTransaction.close();
+			try {
+				bimTransaction.close();
+			} catch (IllegalStateException e) {
+				database.getKeyValueStore().dumpOpenCursors();
+			}
 		}
 		if (DEVELOPER_DEBUG) {
 			LOGGER.info("END SESSION");

diff --git a/BimServer/src/org/bimserver/database/KeyValueStore.java b/BimServer/src/org/bimserver/database/KeyValueStore.java
@@ -73,4 +73,6 @@ SearchingRecordIterator getRecordIterator(String tableName, byte[] mustStartWith
 	void storeNoOverwrite(String tableName, byte[] key, byte[] value, int offset, int length, DatabaseSession databaseSession) throws BimserverDatabaseException, BimserverLockConflictException;
 
 	void store(String tableName, byte[] key, byte[] value, int offset, int length, DatabaseSession databaseSession) throws BimserverDatabaseException, BimserverLockConflictException;
+
+	void dumpOpenCursors();
 }
diff --git a/BimServer/src/org/bimserver/database/berkeley/BerkeleyKeyValueStore.java b/BimServer/src/org/bimserver/database/berkeley/BerkeleyKeyValueStore.java
@@ -22,7 +22,9 @@
 import java.util.HashMap;
 import java.util.Map;
 import java.util.Set;
+import java.util.concurrent.ConcurrentHashMap;
 import java.util.concurrent.TimeUnit;
+import java.util.concurrent.atomic.AtomicLong;
 
 import org.bimserver.database.BimTransaction;
 import org.bimserver.database.BimserverDatabaseException;
@@ -62,7 +64,10 @@ public class BerkeleyKeyValueStore implements KeyValueStore {
 	private TransactionConfig transactionConfig;
 	private CursorConfig cursorConfig;
 	private long lastPrintedReads = 0;
-	private long lastPrintedCommittedWrites = 0;
+	private long lastPrintedCommittedWrites = 0;
+	private static final boolean MONITOR_CURSOR_STACK_TRACES = true;
+	private final AtomicLong cursorCounter = new AtomicLong();
+	private final Map<Long, StackTraceElement[]> openCursors = new ConcurrentHashMap<>();
 
 	public BerkeleyKeyValueStore(File dataDir) throws DatabaseInitException {
 		if (dataDir.isDirectory()) {
@@ -229,7 +234,9 @@ public RecordIterator getRecordIterator(String tableName, DatabaseSession databa
 		Cursor cursor = null;
 		try {
 			cursor = getDatabase(tableName).openCursor(getTransaction(databaseSession), cursorConfig);
-			return new BerkeleyRecordIterator(cursor);
+			BerkeleyRecordIterator berkeleyRecordIterator = new BerkeleyRecordIterator(cursor, this, cursorCounter.incrementAndGet());
+			openCursors.put(berkeleyRecordIterator.getCursorId(), new Exception().getStackTrace());
+			return berkeleyRecordIterator;
 		} catch (DatabaseException e) {
 			LOGGER.error("", e);
 		}
@@ -241,7 +248,9 @@ public SearchingRecordIterator getRecordIterator(String tableName, byte[] mustSt
 		Cursor cursor = null;
 		try {
 			cursor = getDatabase(tableName).openCursor(getTransaction(databaseSession), cursorConfig);
-			return new BerkeleySearchingRecordIterator(cursor, mustStartWith, startSearchingAt);
+			BerkeleySearchingRecordIterator berkeleySearchingRecordIterator = new BerkeleySearchingRecordIterator(cursor, this, cursorCounter.incrementAndGet(), mustStartWith, startSearchingAt);
+			openCursors.put(berkeleySearchingRecordIterator.getCursorId(), new Exception().getStackTrace());
+			return berkeleySearchingRecordIterator;
 		} catch (BimserverLockConflictException e) {
 			if (cursor != null) {
 				try {
@@ -419,5 +428,20 @@ public synchronized void incrementCommittedWrites(int committedWrites) {
 			LOGGER.info("writes: " + this.committedWrites);
 			lastPrintedCommittedWrites = this.committedWrites / 100000;
 		}
+	}
+
+	public void removeOpenCursor(long cursorId) {
+		openCursors.remove(cursorId);
+	}
+
+	@Override
+	public void dumpOpenCursors() {
+		for (StackTraceElement[] ste : openCursors.values()) {
+			System.out.println("Open cursor");
+			for (StackTraceElement stackTraceElement : ste) {
+				LOGGER.info("\t" + stackTraceElement.getClassName() + ":" + stackTraceElement.getLineNumber() + "."
+						+ stackTraceElement.getMethodName());
+			}
+		}
 	}
 }
diff --git a/BimServer/src/org/bimserver/database/berkeley/BerkeleyRecordIterator.java b/BimServer/src/org/bimserver/database/berkeley/BerkeleyRecordIterator.java
@@ -29,14 +29,22 @@
 import com.sleepycat.je.LockMode;
 import com.sleepycat.je.OperationStatus;
 
-public class BerkeleyRecordIterator implements RecordIterator {
+public class BerkeleyRecordIterator implements RecordIterator {
+	private long cursorId;
 	private static final Logger LOGGER = LoggerFactory.getLogger(BerkeleyRecordIterator.class);
 	private final Cursor cursor;
+	private BerkeleyKeyValueStore berkeleyKeyValueStore;
 
-	public BerkeleyRecordIterator(Cursor cursor) {
-		this.cursor = cursor;
-	}
-
+	public BerkeleyRecordIterator(Cursor cursor, BerkeleyKeyValueStore berkeleyKeyValueStore, long cursorId) {
+		this.cursor = cursor;
+		this.berkeleyKeyValueStore = berkeleyKeyValueStore;
+		this.cursorId = cursorId;
+	}
+
+	public long getCursorId() {
+		return cursorId;
+	}
+
 	public Record next() {
 		DatabaseEntry key = new DatabaseEntry();
 		DatabaseEntry value = new DatabaseEntry();
@@ -47,15 +55,17 @@ public Record next() {
 			} else {
 				return null;
 			}
-		} catch (DatabaseException e) {
+		} catch (DatabaseException e) {
+			LOGGER.error("", e);
 		}
 		return null;
 	}
 
 	@Override
 	public void close() {
 		try {
-			cursor.close();
+			cursor.close();
+			berkeleyKeyValueStore.removeOpenCursor(cursorId);
 		} catch (DatabaseException e) {
 			LOGGER.error("", e);
 		}

diff --git a/BimServer/src/org/bimserver/database/berkeley/BerkeleySearchingRecordIterator.java b/BimServer/src/org/bimserver/database/berkeley/BerkeleySearchingRecordIterator.java
@@ -38,13 +38,21 @@ public class BerkeleySearchingRecordIterator implements SearchingRecordIterator
 	private final Cursor cursor;
 	private final byte[] mustStartWith;
 	private byte[] nextStartSearchingAt;
+	private long cursorId;
+	private BerkeleyKeyValueStore berkeleyKeyValueStore;
 
-	public BerkeleySearchingRecordIterator(Cursor cursor, byte[] mustStartWith, byte[] startSearchingAt) throws BimserverLockConflictException {
-		this.cursor = cursor;
+	public BerkeleySearchingRecordIterator(Cursor cursor, BerkeleyKeyValueStore berkeleyKeyValueStore, long cursorId, byte[] mustStartWith, byte[] startSearchingAt) throws BimserverLockConflictException {
+		this.cursor = cursor;
+		this.berkeleyKeyValueStore = berkeleyKeyValueStore;
+		this.cursorId = cursorId;
 		this.mustStartWith = mustStartWith;
 		this.nextStartSearchingAt = startSearchingAt;
-	}
-
+	}
+
+	public long getCursorId() {
+		return cursorId;
+	}
+
 	private Record getFirstNext(byte[] startSearchingAt) throws BimserverLockConflictException {
 		this.nextStartSearchingAt = null;
 		DatabaseEntry key = new DatabaseEntry(startSearchingAt);
@@ -93,7 +101,8 @@ public Record next() throws BimserverLockConflictException {
 	@Override
 	public void close() {
 		try {
-			cursor.close();
+			cursor.close();
+			berkeleyKeyValueStore.removeOpenCursor(cursorId);
 		} catch (DatabaseException e) {
 			LOGGER.error("", e);
 		}