Skip to content

Commit 6d7eb68

Browse files
rmichelarmichela
authored
Merge pull request #51 from salesforce/feature/stopwatch
Implemented stopwatch interceptor
2 parents fde110d + 2226a1e commit 6d7eb68

File tree

6 files changed

+247
-1
lines changed

6 files changed

+247
-1
lines changed

‎grpc-contrib/pom.xml‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,11 @@
4040
<artifactId>grpc-testing</artifactId>
4141
<scope>test</scope>
4242
</dependency>
43+
<dependency>
44+
<groupId>org.slf4j</groupId>
45+
<artifactId>slf4j-api</artifactId>
46+
<scope>provided</scope>
47+
</dependency>
4348
<dependency>
4449
<groupId>junit</groupId>
4550
<artifactId>junit</artifactId>

‎grpc-contrib/src/main/java/com/salesforce/grpc/contrib/interceptor/StopwatchClientInterceptor.java‎

Lines changed: 65 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,65 @@
1+
/*
2+
* Copyright (c) 2017, salesforce.com, inc.
3+
* All rights reserved.
4+
* Licensed under the BSD 3-Clause license.
5+
* For full license text, see LICENSE.txt file in the repo root or https://opensource.org/licenses/BSD-3-Clause
6+
*/
7+
8+
package com.salesforce.grpc.contrib.interceptor;
9+
10+
import com.google.common.base.Stopwatch;
11+
import io.grpc.*;
12+
import org.slf4j.Logger;
13+
import org.slf4j.LoggerFactory;
14+
15+
import java.time.Duration;
16+
import java.util.concurrent.TimeUnit;
17+
18+
/**
19+
* {@code StopwatchClientInterceptor} logs the beginning and end of an outbound gRPC request, along with the total
20+
* round-trip time.
21+
*
22+
* <p>Typical usage would override {@link #logStart(MethodDescriptor)} and {@link #logStop(MethodDescriptor, Duration)}.
23+
*/
24+
public class StopwatchClientInterceptor implements ClientInterceptor {
25+
private final Logger logger = LoggerFactory.getLogger(StopwatchClientInterceptor.class);
26+
27+
@Override
28+
public <ReqT, RespT> ClientCall<ReqT, RespT> interceptCall(MethodDescriptor<ReqT, RespT> method, CallOptions callOptions, Channel next) {
29+
logStart(method);
30+
31+
return new ForwardingClientCall.SimpleForwardingClientCall<ReqT, RespT>(next.newCall(method, callOptions)) {
32+
private Stopwatch stopwatch = Stopwatch.createStarted();
33+
34+
@Override
35+
public void start(Listener<RespT> responseListener, Metadata headers) {
36+
super.start(new ForwardingClientCallListener.SimpleForwardingClientCallListener<RespT>(responseListener) {
37+
@Override
38+
public void onClose(Status status, Metadata trailers) {
39+
super.onClose(status, trailers);
40+
logStop(method, Duration.ofNanos(stopwatch.stop().elapsed(TimeUnit.NANOSECONDS)));
41+
}
42+
}, headers);
43+
}
44+
};
45+
}
46+
47+
/**
48+
* Override this method to change how start messages are logged. Ex: use log4j.
49+
*
50+
* @param method The operation being called
51+
*/
52+
protected void logStart(MethodDescriptor method) {
53+
logger.info("Begin call op:" + method.getFullMethodName());
54+
}
55+
56+
/**
57+
* Override this method to change how stop messages are logged. Ex: use log4j.
58+
*
59+
* @param method The operation being called
60+
* @param duration Total round-trip time
61+
*/
62+
protected void logStop(MethodDescriptor method, Duration duration) {
63+
logger.info("End call op:" + method.getFullMethodName() + " duration:" + duration);
64+
}
65+
}

‎grpc-contrib/src/main/java/com/salesforce/grpc/contrib/interceptor/StopwatchServerInterceptor.java‎

Lines changed: 74 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,74 @@
1+
/*
2+
* Copyright (c) 2017, salesforce.com, inc.
3+
* All rights reserved.
4+
* Licensed under the BSD 3-Clause license.
5+
* For full license text, see LICENSE.txt file in the repo root or https://opensource.org/licenses/BSD-3-Clause
6+
*/
7+
8+
package com.salesforce.grpc.contrib.interceptor;
9+
10+
import com.google.common.base.Stopwatch;
11+
import io.grpc.*;
12+
13+
import java.time.Duration;
14+
import java.util.concurrent.TimeUnit;
15+
16+
/**
17+
* {@code StopwatchServerInterceptor} logs the beginning and end of an inbound gRPC request, along with the total
18+
* processing time.
19+
*
20+
* <p>Typical usage would override {@link #logStart(MethodDescriptor)} and {@link #logStop(MethodDescriptor, Duration)}.
21+
*/
22+
public class StopwatchServerInterceptor implements ServerInterceptor {
23+
@Override
24+
public <ReqT, RespT> ServerCall.Listener<ReqT> interceptCall(ServerCall<ReqT, RespT> call, Metadata headers, ServerCallHandler<ReqT, RespT> next) {
25+
logStart(call.getMethodDescriptor());
26+
27+
return new ForwardingServerCallListener.SimpleForwardingServerCallListener<ReqT>(next.startCall(call, headers)) {
28+
private Stopwatch stopwatch = Stopwatch.createStarted();
29+
30+
@Override
31+
public void onCancel() {
32+
super.onCancel();
33+
logCancel(call.getMethodDescriptor(), Duration.ofNanos(stopwatch.stop().elapsed(TimeUnit.NANOSECONDS)));
34+
}
35+
36+
@Override
37+
public void onComplete() {
38+
super.onComplete();
39+
logStop(call.getMethodDescriptor(), Duration.ofNanos(stopwatch.stop().elapsed(TimeUnit.NANOSECONDS)));
40+
}
41+
};
42+
}
43+
44+
/**
45+
* Override this method to change how "start" messages are logged. Ex: use log4j.
46+
*
47+
* @param method The operation being called
48+
*/
49+
protected void logStart(MethodDescriptor method) {
50+
System.out.println("Begin service op:" + method.getFullMethodName());
51+
}
52+
53+
/**
54+
* Override this method to change how "stop" messages are logged. Ex: use log4j.
55+
*
56+
* @param method The operation being called
57+
* @param duration Total round-trip time
58+
*/
59+
protected void logStop(MethodDescriptor method, Duration duration) {
60+
System.out.println("End service op:" + method.getFullMethodName() + " duration:" + duration);
61+
}
62+
63+
/**
64+
* Override this method to change how "cancel" messages are logged. Ex: use log4j.
65+
*
66+
* <p>By default, this delegates to {@link #logStop(MethodDescriptor, Duration)}.
67+
*
68+
* @param method The operation being called
69+
* @param duration Total round-trip time
70+
*/
71+
protected void logCancel(MethodDescriptor method, Duration duration) {
72+
logStop(method, duration);
73+
}
74+
}

‎grpc-contrib/src/test/java/com/salesforce/grpc/contrib/interceptor/StopwatchInterceptorTest.java‎

Lines changed: 94 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,94 @@
1+
/*
2+
* Copyright (c) 2017, salesforce.com, inc.
3+
* All rights reserved.
4+
* Licensed under the BSD 3-Clause license.
5+
* For full license text, see LICENSE.txt file in the repo root or https://opensource.org/licenses/BSD-3-Clause
6+
*/
7+
8+
package com.salesforce.grpc.contrib.interceptor;
9+
10+
import com.salesforce.grpc.contrib.GreeterGrpc;
11+
import com.salesforce.grpc.contrib.HelloRequest;
12+
import com.salesforce.grpc.contrib.HelloResponse;
13+
import io.grpc.MethodDescriptor;
14+
import io.grpc.ServerInterceptors;
15+
import io.grpc.stub.StreamObserver;
16+
import io.grpc.testing.GrpcServerRule;
17+
import org.junit.Rule;
18+
import org.junit.Test;
19+
20+
import java.time.Duration;
21+
import java.util.concurrent.atomic.AtomicReference;
22+
23+
import static org.assertj.core.api.Assertions.assertThat;
24+
25+
public class StopwatchInterceptorTest {
26+
@Rule public final GrpcServerRule serverRule = new GrpcServerRule().directExecutor();
27+
28+
GreeterGrpc.GreeterImplBase svc = new GreeterGrpc.GreeterImplBase() {
29+
@Override
30+
public void sayHello(HelloRequest request, StreamObserver<HelloResponse> responseObserver) {
31+
responseObserver.onNext(HelloResponse.newBuilder().setMessage("Hello " + request.getName()).build());
32+
responseObserver.onCompleted();
33+
}
34+
};
35+
36+
@Test
37+
public void clientStopwatchWorks() {
38+
AtomicReference<MethodDescriptor> startDesc = new AtomicReference<>();
39+
AtomicReference<MethodDescriptor> stopDesc = new AtomicReference<>();
40+
AtomicReference<Duration> stopDur = new AtomicReference<>();
41+
42+
//Setup
43+
serverRule.getServiceRegistry().addService(svc);
44+
GreeterGrpc.GreeterBlockingStub stub = GreeterGrpc
45+
.newBlockingStub(serverRule.getChannel())
46+
.withInterceptors(new StopwatchClientInterceptor() {
47+
@Override
48+
protected void logStart(MethodDescriptor method) {
49+
startDesc.set(method);
50+
}
51+
52+
@Override
53+
protected void logStop(MethodDescriptor method, Duration duration) {
54+
stopDesc.set(method);
55+
stopDur.set(duration);
56+
}
57+
});
58+
59+
stub.sayHello(HelloRequest.newBuilder().setName("World").build());
60+
61+
assertThat(startDesc.get().getFullMethodName()).contains("SayHello");
62+
assertThat(startDesc.get().getFullMethodName()).contains("SayHello");
63+
assertThat(stopDur.get()).isGreaterThan(Duration.ZERO);
64+
}
65+
66+
@Test
67+
public void serverStopwatchWorks() {
68+
AtomicReference<MethodDescriptor> startDesc = new AtomicReference<>();
69+
AtomicReference<MethodDescriptor> stopDesc = new AtomicReference<>();
70+
AtomicReference<Duration> stopDur = new AtomicReference<>();
71+
72+
//Setup
73+
serverRule.getServiceRegistry().addService(ServerInterceptors.intercept(svc,
74+
new StopwatchServerInterceptor() {
75+
@Override
76+
protected void logStart(MethodDescriptor method) {
77+
startDesc.set(method);
78+
}
79+
80+
@Override
81+
protected void logStop(MethodDescriptor method, Duration duration) {
82+
stopDesc.set(method);
83+
stopDur.set(duration);
84+
}
85+
}));
86+
GreeterGrpc.GreeterBlockingStub stub = GreeterGrpc.newBlockingStub(serverRule.getChannel());
87+
88+
stub.sayHello(HelloRequest.newBuilder().setName("World").build());
89+
90+
assertThat(startDesc.get().getFullMethodName()).contains("SayHello");
91+
assertThat(startDesc.get().getFullMethodName()).contains("SayHello");
92+
assertThat(stopDur.get()).isGreaterThan(Duration.ZERO);
93+
}
94+
}

‎grpc-contrib/src/test/proto/helloworld.proto‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -6,7 +6,7 @@ import "google/protobuf/empty.proto";
66
import "google/protobuf/timestamp.proto";
77

88
option java_multiple_files = true;
9-
option java_package = "com.salesforce.jprotoc";
9+
option java_package = "com.salesforce.grpc.contrib";
1010
option java_outer_classname = "HelloWorldProto";
1111

1212
// The greeting service definition.

‎pom.xml‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -69,6 +69,7 @@
6969
<!-- Keep grpc.version in sync with srpc-grpc/java/pom.xml and srpc-grpc-dependencies/pom.xml -->
7070
<grpc.version>1.6.1</grpc.version>
7171
<protoc.version>3.3.0</protoc.version> <!-- Same version as grpc-proto -->
72+
<slf4j.version>1.7.21</slf4j.version>
7273
<mustache-java.version>0.9.4</mustache-java.version>
7374
<spring.version>4.2.0.RELEASE</spring.version>
7475

@@ -165,6 +166,13 @@
165166
<artifactId>spring-webmvc</artifactId>
166167
<version>${spring.version}</version>
167168
</dependency>
169+
<!-- Provided dependencies -->
170+
<dependency>
171+
<groupId>org.slf4j</groupId>
172+
<artifactId>slf4j-api</artifactId>
173+
<version>${slf4j.version}</version>
174+
<scope>provided</scope>
175+
</dependency>
168176
<!-- Test dependencies -->
169177
<dependency>
170178
<groupId>io.grpc</groupId>

0 commit comments

Comments
 (0)