Skip to content

Commit

Permalink
feat: capture stack trace for session checkout is now optional (#2350)
Browse files Browse the repository at this point in the history
* feat: capture stack trace for session checkout is now optional

The session pool by default captures the stack trace of the thread that
checks out a session of the pool, so this can be used in case the
session is leaked. This is done by creating an exception already at the
moment that the session is checked out. Some monitoring tools log the
creation of this exception, giving the impression that the application
is throwing a large number of errors, while the error is actually never
thrown.
This commit makes this capturing optional. The default is to capture the
call stack, but users can turn this off in the SessionPoolOptions.

* 🦉 Updates from OwlBot post-processor

See https://github.com/googleapis/repo-automation-bots/blob/main/packages/owl-bot/README.md

* docs: improve javadoc and comments

* 🦉 Updates from OwlBot post-processor

See https://github.com/googleapis/repo-automation-bots/blob/main/packages/owl-bot/README.md

---------

Co-authored-by: Owl Bot <gcf-owl-bot[bot]@users.noreply.github.com>
  • Loading branch information
olavloite and gcf-owl-bot[bot] committed Apr 7, 2023
1 parent 36eb38f commit 6b6427a
Show file tree
Hide file tree
Showing 3 changed files with 122 additions and 1 deletion.
Original file line number Diff line number Diff line change
Expand Up @@ -1099,6 +1099,10 @@ final class LeakedSessionException extends RuntimeException {
private LeakedSessionException() {
super("Session was checked out from the pool at " + clock.instant());
}

private LeakedSessionException(String message) {
super(message);
}
}

private enum SessionState {
Expand Down Expand Up @@ -1131,7 +1135,9 @@ void clearLeakedException() {
}

private void markCheckedOut() {
this.leakedException = new LeakedSessionException();
if (options.isTrackStackTraceOfSessionCheckout()) {
this.leakedException = new LeakedSessionException();
}
}

@Override
Expand Down Expand Up @@ -2324,6 +2330,16 @@ ListenableFuture<Void> closeAsync(ClosedException closedException) {
} else {
logger.log(Level.WARNING, "Leaked session", session.leakedException);
}
} else {
String message =
"Leaked session. "
+ "Call SessionOptions.Builder#setTrackStackTraceOfSessionCheckout(true) to start "
+ "tracking the call stack trace of the thread that checked out the session.";
if (options.isFailOnSessionLeak()) {
throw new LeakedSessionException(message);
} else {
logger.log(Level.WARNING, message);
}
}
}
for (final PooledSession session : ImmutableList.copyOf(allSessions)) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -49,6 +49,7 @@ public class SessionPoolOptions {
private final Duration removeInactiveSessionAfter;
private final ActionOnSessionNotFound actionOnSessionNotFound;
private final ActionOnSessionLeak actionOnSessionLeak;
private final boolean trackStackTraceOfSessionCheckout;
private final long initialWaitForSessionTimeoutMillis;
private final boolean autoDetectDialect;
private final Duration waitForMinSessions;
Expand All @@ -65,6 +66,7 @@ private SessionPoolOptions(Builder builder) {
this.actionOnExhaustion = builder.actionOnExhaustion;
this.actionOnSessionNotFound = builder.actionOnSessionNotFound;
this.actionOnSessionLeak = builder.actionOnSessionLeak;
this.trackStackTraceOfSessionCheckout = builder.trackStackTraceOfSessionCheckout;
this.initialWaitForSessionTimeoutMillis = builder.initialWaitForSessionTimeoutMillis;
this.loopFrequency = builder.loopFrequency;
this.keepAliveIntervalMinutes = builder.keepAliveIntervalMinutes;
Expand All @@ -87,6 +89,8 @@ public boolean equals(Object o) {
&& Objects.equals(this.actionOnExhaustion, other.actionOnExhaustion)
&& Objects.equals(this.actionOnSessionNotFound, other.actionOnSessionNotFound)
&& Objects.equals(this.actionOnSessionLeak, other.actionOnSessionLeak)
&& Objects.equals(
this.trackStackTraceOfSessionCheckout, other.trackStackTraceOfSessionCheckout)
&& Objects.equals(
this.initialWaitForSessionTimeoutMillis, other.initialWaitForSessionTimeoutMillis)
&& Objects.equals(this.loopFrequency, other.loopFrequency)
Expand All @@ -107,6 +111,7 @@ public int hashCode() {
this.actionOnExhaustion,
this.actionOnSessionNotFound,
this.actionOnSessionLeak,
this.trackStackTraceOfSessionCheckout,
this.initialWaitForSessionTimeoutMillis,
this.loopFrequency,
this.keepAliveIntervalMinutes,
Expand Down Expand Up @@ -190,6 +195,10 @@ boolean isFailOnSessionLeak() {
return actionOnSessionLeak == ActionOnSessionLeak.FAIL;
}

public boolean isTrackStackTraceOfSessionCheckout() {
return trackStackTraceOfSessionCheckout;
}

@VisibleForTesting
Duration getWaitForMinSessions() {
return waitForMinSessions;
Expand Down Expand Up @@ -234,6 +243,17 @@ public static class Builder {
private long initialWaitForSessionTimeoutMillis = 30_000L;
private ActionOnSessionNotFound actionOnSessionNotFound = ActionOnSessionNotFound.RETRY;
private ActionOnSessionLeak actionOnSessionLeak = ActionOnSessionLeak.WARN;
/**
* Capture the call stack of the thread that checked out a session of the pool. This will
* pre-create a {@link com.google.cloud.spanner.SessionPool.LeakedSessionException} already when
* a session is checked out. This can be disabled by users, for example if their monitoring
* systems log the pre-created exception. If disabled, the {@link
* com.google.cloud.spanner.SessionPool.LeakedSessionException} will only be created when an
* actual session leak is detected. The stack trace of the exception will in that case not
* contain the call stack of when the session was checked out.
*/
private boolean trackStackTraceOfSessionCheckout = true;

private long loopFrequency = 10 * 1000L;
private int keepAliveIntervalMinutes = 30;
private Duration removeInactiveSessionAfter = Duration.ofMinutes(55L);
Expand All @@ -253,6 +273,7 @@ private Builder(SessionPoolOptions options) {
this.initialWaitForSessionTimeoutMillis = options.initialWaitForSessionTimeoutMillis;
this.actionOnSessionNotFound = options.actionOnSessionNotFound;
this.actionOnSessionLeak = options.actionOnSessionLeak;
this.trackStackTraceOfSessionCheckout = options.trackStackTraceOfSessionCheckout;
this.loopFrequency = options.loopFrequency;
this.keepAliveIntervalMinutes = options.keepAliveIntervalMinutes;
this.removeInactiveSessionAfter = options.removeInactiveSessionAfter;
Expand Down Expand Up @@ -393,6 +414,21 @@ Builder setFailOnSessionLeak() {
return this;
}

/**
* Sets whether the session pool should capture the call stack trace when a session is checked
* out of the pool. This will internally prepare a {@link
* com.google.cloud.spanner.SessionPool.LeakedSessionException} that will only be thrown if the
* session is actually leaked. This makes it easier to debug session leaks, as the stack trace
* of the thread that checked out the session will be available in the exception.
*
* <p>Some monitoring tools might log these exceptions even though they are not thrown. This
* option can be used to suppress the creation and logging of these exceptions.
*/
public Builder setTrackStackTraceOfSessionCheckout(boolean trackStackTraceOfSessionCheckout) {
this.trackStackTraceOfSessionCheckout = trackStackTraceOfSessionCheckout;
return this;
}

/**
* @deprecated This configuration value is no longer in use. The session pool does not prepare
* any sessions for read/write transactions. Instead, a transaction will automatically be
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,15 @@
import com.google.api.gax.grpc.testing.LocalChannelProvider;
import com.google.cloud.NoCredentials;
import com.google.cloud.spanner.MockSpannerServiceImpl.SimulatedExecutionTime;
import com.google.cloud.spanner.MockSpannerServiceImpl.StatementResult;
import com.google.cloud.spanner.SessionPool.LeakedSessionException;
import com.google.protobuf.ListValue;
import com.google.protobuf.Value;
import com.google.spanner.v1.ResultSetMetadata;
import com.google.spanner.v1.StructType;
import com.google.spanner.v1.StructType.Field;
import com.google.spanner.v1.Type;
import com.google.spanner.v1.TypeCode;
import io.grpc.Server;
import io.grpc.StatusRuntimeException;
import io.grpc.inprocess.InProcessServerBuilder;
Expand Down Expand Up @@ -94,6 +103,66 @@ public void tearDown() {
spanner.close();
}

@Test
public void testIgnoreLeakedSession() {
for (boolean trackStackTraceofSessionCheckout : new boolean[] {true, false}) {
SpannerOptions.Builder builder =
SpannerOptions.newBuilder()
.setProjectId("[PROJECT]")
.setChannelProvider(channelProvider)
.setCredentials(NoCredentials.getInstance());
builder.setSessionPoolOption(
SessionPoolOptions.newBuilder()
.setMinSessions(0)
.setMaxSessions(2)
.setIncStep(1)
.setFailOnSessionLeak()
.setTrackStackTraceOfSessionCheckout(trackStackTraceofSessionCheckout)
.build());
Spanner spanner = builder.build().getService();
DatabaseClient client =
spanner.getDatabaseClient(DatabaseId.of("[PROJECT]", "[INSTANCE]", "[DATABASE]"));
mockSpanner.putStatementResult(
StatementResult.query(
Statement.of("SELECT 1"),
com.google.spanner.v1.ResultSet.newBuilder()
.setMetadata(
ResultSetMetadata.newBuilder()
.setRowType(
StructType.newBuilder()
.addFields(
Field.newBuilder()
.setName("c")
.setType(
Type.newBuilder().setCode(TypeCode.INT64).build())
.build())
.build())
.build())
.addRows(
ListValue.newBuilder()
.addValues(Value.newBuilder().setStringValue("1").build())
.build())
.build()));

// Start a read-only transaction without closing it before closing the Spanner instance.
// This will cause a session leak.
ReadOnlyTransaction transaction = client.readOnlyTransaction();
try (ResultSet resultSet = transaction.executeQuery(Statement.of("SELECT 1"))) {
while (resultSet.next()) {
// ignore
}
}
LeakedSessionException exception = assertThrows(LeakedSessionException.class, spanner::close);
// The top of the stack trace will be "markCheckedOut" if we keep track of the point where the
// session was checked out, while it will be "closeAsync" if we don't. In the latter case, we
// get the stack trace of the method that tries to close the Spanner instance, while in the
// former the stack trace will contain the method that checked out the session.
assertEquals(
trackStackTraceofSessionCheckout ? "markCheckedOut" : "closeAsync",
exception.getStackTrace()[0].getMethodName());
}
}

@Test
public void testReadWriteTransactionExceptionOnCreateSession() {
readWriteTransactionTest(
Expand Down

0 comments on commit 6b6427a

Please sign in to comment.