Skip to content

Commit ccdc935

Browse files
vkediavkedia
authored
Cloud Spanner: Adds tracing (#2677)
* More fixes * Fixed findbugs version * Add tracing to cloud spanner client * Fix version of findbugs * Made changes per code review comments * Fixed dependencies * Fixes style issues * Removed empty spaces * Fixed NPE * Handles the case of null SampledSpanStore * Changed error_prone version to 2.1.2 * Changed opencensus version to 0.9.1 * Reverts the change to eclipse prefs file
1 parent 7f56ab1 commit ccdc935

10 files changed

Lines changed: 533 additions & 128 deletions

File tree

‎google-cloud-bom/pom.xml‎

Lines changed: 12 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -138,6 +138,7 @@
138138
<guava.version>20.0</guava.version>
139139
<http-client.version>1.23.0</http-client.version>
140140
<protobuf.version>3.4.0</protobuf.version>
141+
<opencensus.version>0.9.1</opencensus.version>
141142

142143
<cloud.version>0.32.1-alpha-SNAPSHOT</cloud.version>
143144
<bigtable.version>0.32.1-beta-SNAPSHOT</bigtable.version>
@@ -872,7 +873,7 @@
872873
<dependency>
873874
<groupId>com.google.code.findbugs</groupId>
874875
<artifactId>jsr305</artifactId>
875-
<version>3.0.0</version>
876+
<version>3.0.1</version>
876877
</dependency>
877878
<dependency>
878879
<groupId>com.google.protobuf</groupId>
@@ -979,6 +980,16 @@
979980
<artifactId>netty-tcnative-boringssl-static</artifactId>
980981
<version>${nettyssl.version}</version>
981982
</dependency>
983+
<dependency>
984+
<groupId>io.opencensus</groupId>
985+
<artifactId>opencensus-api</artifactId>
986+
<version>${opencensus.version}</version>
987+
</dependency>
988+
<dependency>
989+
<groupId>io.opencensus</groupId>
990+
<artifactId>opencensus-contrib-grpc-util</artifactId>
991+
<version>${opencensus.version}</version>
992+
</dependency>
982993

983994
<!-- testlib deps. Only put testlib dependencies here, which are testlib packages
984995
that correspond to another non-test package. Put pure test dependencies (e.g.

‎google-cloud-spanner/pom.xml‎

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -99,6 +99,12 @@
9999
<dependency>
100100
<groupId>io.grpc</groupId>
101101
<artifactId>grpc-netty</artifactId>
102+
<exclusions>
103+
<exclusion>
104+
<groupId>io.opencensus</groupId>
105+
<artifactId>opencensus-api</artifactId>
106+
</exclusion>
107+
</exclusions>
102108
</dependency>
103109
<dependency>
104110
<groupId>io.grpc</groupId>
@@ -153,5 +159,13 @@
153159
<classifier>testlib</classifier>
154160
<scope>test</scope>
155161
</dependency>
162+
<dependency>
163+
<groupId>io.opencensus</groupId>
164+
<artifactId>opencensus-api</artifactId>
165+
</dependency>
166+
<dependency>
167+
<groupId>io.opencensus</groupId>
168+
<artifactId>opencensus-contrib-grpc-util</artifactId>
169+
</dependency>
156170
</dependencies>
157171
</project>

‎google-cloud-spanner/src/main/java/com/google/cloud/spanner/DatabaseClientImpl.java‎

Lines changed: 82 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -17,10 +17,23 @@
1717
package com.google.cloud.spanner;
1818

1919
import com.google.cloud.Timestamp;
20+
2021
import com.google.common.util.concurrent.ListenableFuture;
2122

22-
class DatabaseClientImpl implements DatabaseClient {
23+
import io.opencensus.common.Scope;
24+
import io.opencensus.trace.Span;
25+
import io.opencensus.trace.Tracer;
26+
import io.opencensus.trace.Tracing;
2327

28+
class DatabaseClientImpl implements DatabaseClient {
29+
private static final String READ_WRITE_TRANSACTION = "CloudSpanner.ReadWriteTransaction";
30+
private static final String READ_ONLY_TRANSACTION = "CloudSpanner.ReadOnlyTransaction";
31+
private static final Tracer tracer = Tracing.getTracer();
32+
33+
static {
34+
TraceUtil.exportSpans(READ_WRITE_TRANSACTION, READ_ONLY_TRANSACTION);
35+
}
36+
2437
private final SessionPool pool;
2538

2639
DatabaseClientImpl(SessionPool pool) {
@@ -29,47 +42,106 @@ class DatabaseClientImpl implements DatabaseClient {
2942

3043
@Override
3144
public Timestamp write(Iterable<Mutation> mutations) throws SpannerException {
32-
return pool.getReadWriteSession().write(mutations);
45+
Span span = tracer.spanBuilder(READ_WRITE_TRANSACTION).startSpan();
46+
try (Scope s = tracer.withSpan(span)) {
47+
return pool.getReadWriteSession().write(mutations);
48+
} catch (RuntimeException e) {
49+
TraceUtil.endSpanWithFailure(span, e);
50+
throw e;
51+
} finally {
52+
span.end();
53+
}
3354
}
3455

3556
@Override
3657
public Timestamp writeAtLeastOnce(Iterable<Mutation> mutations) throws SpannerException {
37-
return pool.getReadSession().writeAtLeastOnce(mutations);
58+
Span span = tracer.spanBuilder(READ_WRITE_TRANSACTION).startSpan();
59+
try (Scope s = tracer.withSpan(span)) {
60+
return pool.getReadSession().writeAtLeastOnce(mutations);
61+
} catch (RuntimeException e) {
62+
TraceUtil.endSpanWithFailure(span, e);
63+
throw e;
64+
} finally {
65+
span.end();
66+
}
3867
}
3968

4069
@Override
4170
public ReadContext singleUse() {
42-
return pool.getReadSession().singleUse();
71+
Span span = tracer.spanBuilder(READ_ONLY_TRANSACTION).startSpan();
72+
try (Scope s = tracer.withSpan(span)) {
73+
return pool.getReadSession().singleUse();
74+
} catch (RuntimeException e) {
75+
TraceUtil.endSpanWithFailure(span, e);
76+
throw e;
77+
}
78+
4379
}
4480

4581
@Override
4682
public ReadContext singleUse(TimestampBound bound) {
47-
return pool.getReadSession().singleUse(bound);
83+
Span span = tracer.spanBuilder(READ_ONLY_TRANSACTION).startSpan();
84+
try (Scope s = tracer.withSpan(span)) {
85+
return pool.getReadSession().singleUse(bound);
86+
} catch (RuntimeException e) {
87+
TraceUtil.endSpanWithFailure(span, e);
88+
throw e;
89+
}
4890
}
4991

5092
@Override
5193
public ReadOnlyTransaction singleUseReadOnlyTransaction() {
52-
return pool.getReadSession().singleUseReadOnlyTransaction();
94+
Span span = tracer.spanBuilder(READ_ONLY_TRANSACTION).startSpan();
95+
try (Scope s = tracer.withSpan(span)) {
96+
return pool.getReadSession().singleUseReadOnlyTransaction();
97+
} catch (RuntimeException e) {
98+
TraceUtil.endSpanWithFailure(span, e);
99+
throw e;
100+
}
53101
}
54102

55103
@Override
56104
public ReadOnlyTransaction singleUseReadOnlyTransaction(TimestampBound bound) {
57-
return pool.getReadSession().singleUseReadOnlyTransaction(bound);
105+
Span span = tracer.spanBuilder(READ_ONLY_TRANSACTION).startSpan();
106+
try (Scope s = tracer.withSpan(span)) {
107+
return pool.getReadSession().singleUseReadOnlyTransaction(bound);
108+
} catch (RuntimeException e) {
109+
TraceUtil.endSpanWithFailure(span, e);
110+
throw e;
111+
}
58112
}
59113

60114
@Override
61115
public ReadOnlyTransaction readOnlyTransaction() {
62-
return pool.getReadSession().readOnlyTransaction();
116+
Span span = tracer.spanBuilder(READ_ONLY_TRANSACTION).startSpan();
117+
try (Scope s = tracer.withSpan(span)) {
118+
return pool.getReadSession().readOnlyTransaction();
119+
} catch (RuntimeException e) {
120+
TraceUtil.endSpanWithFailure(span, e);
121+
throw e;
122+
}
63123
}
64124

65125
@Override
66126
public ReadOnlyTransaction readOnlyTransaction(TimestampBound bound) {
67-
return pool.getReadSession().readOnlyTransaction(bound);
127+
Span span = tracer.spanBuilder(READ_ONLY_TRANSACTION).startSpan();
128+
try (Scope s = tracer.withSpan(span)) {
129+
return pool.getReadSession().readOnlyTransaction(bound);
130+
} catch (RuntimeException e) {
131+
TraceUtil.endSpanWithFailure(span, e);
132+
throw e;
133+
}
68134
}
69135

70136
@Override
71137
public TransactionRunner readWriteTransaction() {
72-
return pool.getReadWriteSession().readWriteTransaction();
138+
Span span = tracer.spanBuilder(READ_WRITE_TRANSACTION).startSpan();
139+
try (Scope s = tracer.withSpan(span)) {
140+
return pool.getReadWriteSession().readWriteTransaction();
141+
} catch (RuntimeException e) {
142+
TraceUtil.endSpanWithFailure(span, e);
143+
throw e;
144+
}
73145
}
74146

75147
ListenableFuture<Void> closeAsync() {

‎google-cloud-spanner/src/main/java/com/google/cloud/spanner/ErrorCode.java‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -65,6 +65,10 @@ int getCode() {
6565
return this.code.value();
6666
}
6767

68+
Status getGrpcStatus() {
69+
return this.code.toStatus();
70+
}
71+
6872
/**
6973
* Returns the error code represents by {@code name}, or {@code defaultValue} if {@code name} does
7074
* not map to a known code.

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

Lines changed: 34 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -26,10 +26,17 @@
2626
import com.google.common.annotations.VisibleForTesting;
2727
import com.google.common.base.Preconditions;
2828
import com.google.common.collect.ImmutableList;
29+
import com.google.common.collect.ImmutableMap;
2930
import com.google.common.util.concurrent.ListenableFuture;
3031
import com.google.common.util.concurrent.MoreExecutors;
3132
import com.google.common.util.concurrent.SettableFuture;
3233
import com.google.common.util.concurrent.Uninterruptibles;
34+
35+
import io.opencensus.trace.Annotation;
36+
import io.opencensus.trace.AttributeValue;
37+
import io.opencensus.trace.Span;
38+
import io.opencensus.trace.Tracing;
39+
3340
import java.util.HashSet;
3441
import java.util.Iterator;
3542
import java.util.LinkedList;
@@ -731,30 +738,40 @@ private PooledSession findSessionToKeepAlive(
731738
* </ol>
732739
*/
733740
Session getReadSession() throws SpannerException {
741+
Span span = Tracing.getTracer().getCurrentSpan();
742+
span.addAnnotation("Acquiring session");
734743
Waiter waiter = null;
735744
PooledSession sess = null;
736745
synchronized (lock) {
737746
if (closureFuture != null) {
747+
span.addAnnotation("Pool has been closed");
738748
throw new IllegalStateException("Pool has been closed");
739749
}
740750
sess = readSessions.poll();
741751
if (sess == null) {
742752
sess = writePreparedSessions.poll();
743753
if (sess == null) {
754+
span.addAnnotation("No session available");
744755
maybeCreateSession();
745756
waiter = new Waiter();
746757
readWaiters.add(waiter);
758+
} else {
759+
span.addAnnotation("Acquired read write session");
747760
}
761+
} else {
762+
span.addAnnotation("Acquired read only session");
748763
}
749764
}
750765
if (waiter != null) {
751766
logger.log(
752767
Level.FINE,
753768
"No session available in the pool. Blocking for one to become available/created");
769+
span.addAnnotation("Waiting for read only session to be available");
754770
sess = waiter.take();
755771
}
756772
sess.markBusy();
757773
incrementNumSessionsInUse();
774+
span.addAnnotation(sessionAnnotation(sess));
758775
return sess;
759776
}
760777

@@ -777,6 +794,8 @@ Session getReadSession() throws SpannerException {
777794
* </ol>
778795
*/
779796
Session getReadWriteSession() {
797+
Span span = Tracing.getTracer().getCurrentSpan();
798+
span.addAnnotation("Acquiring read write session");
780799
Waiter waiter = null;
781800
PooledSession sess = null;
782801
synchronized (lock) {
@@ -788,26 +807,38 @@ Session getReadWriteSession() {
788807
if (numSessionsBeingPrepared <= readWriteWaiters.size()) {
789808
PooledSession readSession = readSessions.poll();
790809
if (readSession != null) {
810+
span.addAnnotation("Acquired read only session. Preparing for read write transaction");
791811
prepareSession(readSession);
792812
} else {
813+
span.addAnnotation("No session available");
793814
maybeCreateSession();
794815
}
795816
}
796817
waiter = new Waiter();
797818
readWriteWaiters.add(waiter);
819+
} else {
820+
span.addAnnotation("Acquired read write session");
798821
}
799822
}
800823
if (waiter != null) {
801824
logger.log(
802825
Level.FINE,
803826
"No session available in the pool. Blocking for one to become available/created");
827+
span.addAnnotation("Waiting for read write session to be available");
804828
sess = waiter.take();
805829
}
806830
sess.markBusy();
807831
incrementNumSessionsInUse();
832+
span.addAnnotation(sessionAnnotation(sess));
808833
return sess;
809834
}
810835

836+
private Annotation sessionAnnotation(Session session) {
837+
AttributeValue sessionId = AttributeValue.stringAttributeValue(session.getName());
838+
return Annotation.fromDescriptionAndAttributes("Using Session",
839+
ImmutableMap.of("sessionId", sessionId));
840+
}
841+
811842
private void incrementNumSessionsInUse() {
812843
synchronized (lock) {
813844
if (maxSessionsInUse < ++numSessionsInUse) {
@@ -817,11 +848,14 @@ private void incrementNumSessionsInUse() {
817848
}
818849

819850
private void maybeCreateSession() {
851+
Span span = Tracing.getTracer().getCurrentSpan();
820852
synchronized (lock) {
821853
if (numWaiters() >= numSessionsBeingCreated) {
822854
if (canCreateSession()) {
855+
span.addAnnotation("Creating session");
823856
createSession();
824857
} else if (options.isFailIfPoolExhausted()) {
858+
span.addAnnotation("Pool exhausted. Failing");
825859
// throw specific exception
826860
throw newSpannerException(
827861
ErrorCode.RESOURCE_EXHAUSTED,

0 commit comments

Comments
 (0)