Instrument Spanner client (session pool) with OpenCensus metrics

[mayurkale22]

Is your feature request related to a problem? Please describe.
Customers run into the Cloud Spanner session pool tuning issues for their specific workload on a regular basis. Improved visibility into the state of the session pool (or client side metrics) maintained by each client can provide actionable insight and help users take informed decisions.

This will also help customers in identifying a session s.

Describe the solution you'd like
Instrument Spanner client (session pool) with OpenCensus metrics. we need to capture things including - number of max sessions, number of sessions in use, sessions, count of active spanner requests, count of released and acquired sessions.

Describe alternatives you've considered
N/A

Additional context
N/A

===================================================================
Edit1: Agreed list of useful metrics:

All the metrics will be prefixed by “cloud.google.com/java/spanner/”.

Metric	Description	Type	Labels
max_in_use_sessions	The maximum number of sessions in use during the last 10 minute interval	Gauge	database, instance_id, library_version
max_allowed_sessions	The maximum number of sessions allowed. Configurable by the user	Gauge	database, instance_id, library_version
in_use_sessions	The number of sessions currently in use	Gauge	database, instance_id, library_version
get_session_timeouts	The number of get sessions timeouts due to pool exhaustion	Counter	database, instance_id, library_version
num_acquired_sessions	The number of sessions acquired from the session pool	Counter	database, instance_id, library_version
num_released_sessions	The number of sessions released by the user and pool maintainer	Counter	database, instance_id, library_version
num_sessions_in_pool	The number of sessions in the pool.	Gauge	database, instance_id, library_version, Type

• Type : num_in_use_sessions | num_sessions_being_prepared | num_read_sessions | num_write_prepared_sessions

/cc @skuruppu

[olavloite]

I think that we should consider adding metrics for monitoring whether the user has chosen a good value for SessionPoolOptions.writeSessionsFraction. This could include:

• The number of write sessions that are present in the pool by default (i.e. minSessions * writeSessionsFraction).
• The current number of write sessions in use.
• The max number of concurrent write-prepared sessions needed during the last maintenance interval (the last 10 minutes). If this number often exceeds the default number of write-prepared sessions in the pool, it is an indication that the user should increase the number of write-prepared sessions by increasing writeSessionsFraction and/or minSessions.

[olavloite]

Another interesting metric could be to measure the duration that a session has been checked out of the pool. Currently, a user will only be informed about a session when closing the session pool, or when the pool has been exhausted. A metric that monitors this duration for all sessions in the pool will show one or more sessions that have an ever increasing checked out duration in case of a session .

[mayurkale22]

Another interesting metric could be to measure the duration that a session has been checked out of the pool.

Could you please point out the code from where I can fetch this number.

I was thinking to add a counter to measure the count of pool (resource) exhausted or no session available in the pool, to indicate session s. WDYT? If this is not the right place, It would be nice if you can point me to the code to get the session data.

java-spanner/google-cloud-spanner/src/main/java/com/google/cloud/spanner/SessionPool.java

Lines 1430 to 1440 in f3ca198

	} else if (options.isFailIfPoolExhausted()) {
	span.addAnnotation("Pool exhausted. Failing");
	// throw specific exception
	throw newSpannerException(
	ErrorCode.RESOURCE_EXHAUSTED,
	"No session available in the pool. Maximum number of sessions in the pool can be"
	+ " overridden by invoking SessionPoolOptions#Builder#setMaxSessions. Client can be made to block"
	+ " rather than fail by setting SessionPoolOptions#Builder#setBlockIfPoolExhausted.");
	}
	}
	}

[mayurkale22]

@skuruppu What do you think about #53 (comment)?

[olavloite]

Another interesting metric could be to measure the duration that a session has been checked out of the pool.

Could you please point out the code from where I can fetch this number.

It's currently not being maintained by the session pool, but we could easily add it. This method registers the session as busy by also capturing the stacktrace of the caller that is checking out the session:

java-spanner/google-cloud-spanner/src/main/java/com/google/cloud/spanner/SessionPool.java

Line 624 in f3ca198

this.Exception = new SessionException();

We could add an additional property to PooledSession called something like checkedOutTime of type Instant. This property should be set and reset at the same points as where Exception is set and reset.

[olavloite]

I was thinking to add a counter to measure the count of pool (resource) exhausted or no session available in the pool, to indicate session s. WDYT? If this is not the right place, It would be nice if you can point me to the code to get the session data.

java-spanner/google-cloud-spanner/src/main/java/com/google/cloud/spanner/SessionPool.java

Lines 1430 to 1440 in f3ca198

	} else if (options.isFailIfPoolExhausted()) {
	span.addAnnotation("Pool exhausted. Failing");
	// throw specific exception
	throw newSpannerException(
	ErrorCode.RESOURCE_EXHAUSTED,
	"No session available in the pool. Maximum number of sessions in the pool can be"
	+ " overridden by invoking SessionPoolOptions#Builder#setMaxSessions. Client can be made to block"
	+ " rather than fail by setting SessionPoolOptions#Builder#setBlockIfPoolExhausted.");
	}
	}
	}

I think that counting the number of times a session was not available in the pool (but could be created, i.e. there was no session pool exhaustion) is not something that we need to measure separately, assuming that we already measure maxSessionsInUse and numSessionsInUse. Those values should give the user a good overview of the number of sessions that is actually needed, and whether it is steadily increasing over time or whether it is relatively constant.

Counting the number of times that a session could not be checked out of the pool because of pool exhaustion could add some value for the user. In such a situation, the user will observer a value for numSessionsInUse that is equal to (or almost equal to) maxSessions all the time. While that is an indication that something is not well, it could also be that the application and the session pool are operating at their max, but without actually being exhausted. There are two places where you should read this value (or add a counter to measure this value):

1. The place that you had already identified:

   java-spanner/google-cloud-spanner/src/main/java/com/google/cloud/spanner/SessionPool.java

   Lines 1430 to 1440 in f3ca198

   	} else if (options.isFailIfPoolExhausted()) {
   	span.addAnnotation("Pool exhausted. Failing");
   	// throw specific exception
   	throw newSpannerException(
   	ErrorCode.RESOURCE_EXHAUSTED,
   	"No session available in the pool. Maximum number of sessions in the pool can be"
   	+ " overridden by invoking SessionPoolOptions#Builder#setMaxSessions. Client can be made to block"
   	+ " rather than fail by setting SessionPoolOptions#Builder#setBlockIfPoolExhausted.");
   	}
   	}
   	}

2. The Waiter.take() method:

   java-spanner/google-cloud-spanner/src/main/java/com/google/cloud/spanner/SessionPool.java

   Line 867 in f3ca198

   numWaiterTimeouts.incrementAndGet();

Some background information on the above:
Bullet 1 will only be executed if SessionPoolOptions.setFailIfPoolExhausted() has been set. That is not the default, and most users will not have set it. The other (default) option is to block and wait. This is where bullet 2 comes in.

The session pool will by default block and wait if no session can be returned from the pool. This blocking wait is implemented in the take() method of the inner class Waiter. This method will block indefinitely if all the sessions in the pool have been . It will however wake up every 30 to 240 seconds to log a DEADLINE_EXCEEDED warning. These 'timeouts' is the other metric that you should measure.

[mayurkale22]

Counting the number of times that a session could not be checked out of the pool because of pool exhaustion could add some value for the user.

SGTM. Looks like this is possible to measure via getNumWaiterTimeouts() method and this value is always increasing so makes sense to measure it as Counter (or Cumulative) instead of Gauge.

Just for my understanding: As a user, when I see 'timeouts' number growing what are the remedies would you suggest (apart from increasing the session pool size)?

[olavloite]

Just for my understanding: As a user, when I see 'timeouts' number growing what are the remedies would you suggest (apart from increasing the session pool size)?

1. Check your application log for SessionExceptions that occur when you close your Spanner instance. (Closing a Spanner instance will close the session pool, and closing the session pool will trigger these SessionExceptions for all sessions that have not been checked back in to the session pool before closing the pool.)
2. If you have SessionExceptions: Investigate the stacktrace of these and fix the code that is checking out the session, but not checking them back in, by for example not closing all ResultSets or by not closing a read-only transaction.
3. If you do not have SessionExceptions: Increase SessionPool.maxSessions.

[mayurkale22]

I see, thanks for clearing my doubt. I will include 'timeouts' metric in next PR.