Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Error Handling in Interceptors #98

Merged
merged 10 commits into from
Aug 20, 2024
Merged

Error Handling in Interceptors #98

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
10 commits
Select commit Hold shift + click to select a range
d40fe94
added error handling
ajay-jalgaonkar Aug 16, 2024
fb8e466
added error handling for http access logs
ajaypj Aug 16, 2024
d7d3e55
setting -1
ajaypj Aug 16, 2024
2dd8615
import
ajaypj Aug 16, 2024
5b79dc6
calls
ajaypj Aug 17, 2024
79a8105
calls
ajaypj Aug 17, 2024
2701b8a
changes
ajay-jalgaonkar Aug 20, 2024
3028e66
starttime
ajay-jalgaonkar Aug 20, 2024
9cde585
changes from master
ajay-jalgaonkar Aug 20, 2024
03c4214
changes from master
ajay-jalgaonkar Aug 20, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
17 changes: 12 additions & 5 deletions core/src/main/java/com/flipkart/gjex/core/filter/grpc/AccessLogGrpcFilter.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@
import com.google.protobuf.GeneratedMessageV3;
import io.grpc.Metadata;
import io.grpc.Status;
import io.grpc.StatusRuntimeException;
import org.apache.commons.lang3.StringUtils;
import org.slf4j.Logger;

Expand Down Expand Up @@ -57,7 +58,9 @@ public class AccessLogGrpcFilter<R extends GeneratedMessageV3, S extends Generat
private static final Logger logger = Logging.loggerWithName("ACCESS-LOG");

public AccessLogGrpcFilter() {

startTime = System.currentTimeMillis();
accessLogContextBuilder = AccessLogContext.builder()
.requestTime(startTime);
}

/**
Expand All @@ -77,9 +80,7 @@ public static void setFormat(String format) {
*/
@Override
public void doProcessRequest(R req, RequestParams<Metadata> requestParamsInput) {
startTime = System.currentTimeMillis();
accessLogContextBuilder = AccessLogContext.builder()
.requestTime(startTime)
accessLogContextBuilder
.clientIp(requestParamsInput.getClientIp())
.resourcePath(requestParamsInput.getResourcePath())
.method(requestParamsInput.getMethod());
Expand Down Expand Up @@ -125,10 +126,16 @@ public void doProcessResponse(S response) {
*/
@Override
public void doHandleException(Exception e) {
if (e instanceof StatusRuntimeException){
accessLogContextBuilder
.responseStatus(((StatusRuntimeException) e).getStatus().getCode().value());
} else {
accessLogContextBuilder
.responseStatus(Status.Code.INTERNAL.value());
}
accessLogContextBuilder
.contentLength(0)
.responseTime(System.currentTimeMillis() - startTime)
.responseStatus(Status.Code.INTERNAL.value())
.build();
logger.info(accessLogContextBuilder.build().format(format));
}
Expand Down
5 changes: 4 additions & 1 deletion examples/build.gradle
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -40,7 +40,10 @@ dependencies {
implementation "io.dropwizard.metrics5:metrics-healthchecks:5.0.0"
implementation "io.dropwizard.metrics5:metrics-annotation:5.0.0"
implementation "com.palominolabs.metrics:metrics-guice:5.0.1"
implementation 'ru.vyarus:guice-validator:1.2.0'
implementation ('ru.vyarus:guice-validator:1.2.0') {
exclude group: 'com.google.inject', module: 'guice'
}
implementation 'com.google.inject:guice:5.1.0'
implementation 'org.hibernate:hibernate-validator:5.4.2.Final'
implementation 'org.glassfish:javax.el:3.0.1-b08'
implementation 'io.reactivex.rxjava2:rxjava:2.2.0'
Expand Down
8 changes: 6 additions & 2 deletions examples/src/main/resources/log4j2.xml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,9 +7,13 @@
<Console name="console-log" target="SYSTEM_OUT">
<PatternLayout pattern="[%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{5} %X - %msg%n"/>
</Console>
<File name="access-log" fileName="${log-path}/access.log">
<Console name="access-log" target="SYSTEM_OUT">
<PatternLayout pattern="%msg%n"/>
</File>
</Console>
<!-- In case access-log to be printed to a file-->
<!-- <File name="access-log" fileName="${log-path}/access.log">-->
<!-- <PatternLayout pattern="%msg%n"/>-->
<!-- </File>-->
</Appenders>
<Loggers>
<Logger name="ACCESS-LOG" level="info" additivity="false">
Expand Down
61 changes: 47 additions & 14 deletions guice/src/main/java/com/flipkart/gjex/grpc/interceptor/FilterInterceptor.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,19 +25,30 @@
import com.flipkart.gjex.core.util.NetworkUtils;
import com.flipkart.gjex.core.util.Pair;
import com.flipkart.gjex.grpc.utils.AnnotationUtils;
import io.grpc.*;
import io.grpc.BindableService;
import io.grpc.Context;
import io.grpc.ForwardingServerCall.SimpleForwardingServerCall;
import io.grpc.ForwardingServerCallListener.SimpleForwardingServerCallListener;
import io.grpc.Grpc;
import io.grpc.Metadata;
import io.grpc.ServerCall;
import io.grpc.ServerCall.Listener;
import io.grpc.ServerCallHandler;
import io.grpc.ServerInterceptor;
import io.grpc.Status;
import io.grpc.StatusRuntimeException;
import org.apache.commons.lang.StringUtils;

import javax.inject.Named;
import javax.inject.Singleton;
import javax.validation.ConstraintViolationException;
import java.lang.reflect.Method;
import java.net.InetSocketAddress;
import java.net.SocketAddress;
import java.util.*;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
import java.util.function.Function;
import java.util.stream.Collectors;

Expand Down Expand Up @@ -115,6 +126,8 @@ public void sendMessage(final Res response) {
try {
grpcFilters.forEach(filter -> filter.doProcessResponse(response));
super.sendMessage(response);
} catch (RuntimeException e){
handleException(call, grpcFilters, e);
} finally {
detachContext(contextWithHeaders, previous); // detach headers from gRPC context
}
Expand All @@ -126,10 +139,28 @@ public void sendHeaders(final Metadata responseHeaders) {
try {
grpcFilters.forEach(filter -> filter.doProcessResponseHeaders(responseHeaders));
super.sendHeaders(responseHeaders);
} catch (Exception e) {
handleException(call, grpcFilters, e);
} finally {
detachContext(contextWithHeaders, previous); // detach headers from gRPC context
}
}

// @Override
// public void close(Status status, Metadata trailers) {
// Context previous = attachContext(contextWithHeaders); // attaching headers to gRPC context
// error("@@@@@@@@@@@@@@@@@@ got inside close");
// try {
// if (!status.isOk()){
// grpcFilters.forEach(filter -> filter.doHandleException(new StatusRuntimeException(status,trailers)));
// }
// super.close(status, trailers);
// } catch (Exception e) {
// handleException(call, grpcFilters, e);
// } finally {
// detachContext(contextWithHeaders, previous); // detach headers from gRPC context
// }
// }
Copy link
Collaborator Author

@ajaypj ajaypj Aug 16, 2024 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

with close() we can get the exact Status and print it in the access logs.
Need to check how to get this with onCancel() because close() is not guaranteed to be called always according to the javadocs.

}, headers);

RequestParams requestParams = RequestParams.builder()
Expand All @@ -145,9 +176,8 @@ public void onHalfClose() {
Context previous = attachContext(contextWithHeaders); // attaching headers to gRPC context
try {
super.onHalfClose();
} catch (RuntimeException ex) {
handleException(call, ex);
grpcFilters.forEach(filter -> filter.doHandleException(ex));
} catch (Exception e) {
handleException(call, grpcFilters, e);
} finally {
detachContext(contextWithHeaders, previous); // detach headers from gRPC context
}
Expand All @@ -157,8 +187,10 @@ public void onHalfClose() {
public void onMessage(Req request) {
Context previous = attachContext(contextWithHeaders); // attaching headers to gRPC context
try {
grpcFilters.forEach(filter -> filter.doProcessRequest(request,requestParams));
grpcFilters.forEach(filter -> filter.doProcessRequest(request, requestParams));
super.onMessage(request);
} catch (Exception e) {
handleException(call, grpcFilters, e);
} finally {
detachContext(contextWithHeaders, previous); // detach headers from gRPC context
}
Expand All @@ -168,10 +200,10 @@ public void onMessage(Req request) {
public void onCancel() {
Context previous = attachContext(contextWithHeaders); // attaching headers to gRPC context
try {
grpcFilters.forEach(filter -> filter.doHandleException(new Exception()));
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

any better way to get more specific exception/grpc status

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

check how to set more descriptive exception containing grpc status code here, like DEADLINE_EXCEEDED

super.onCancel();
} catch (RuntimeException ex) {
handleException(call, ex);
grpcFilters.forEach(filter -> filter.doHandleException(ex));
} catch (Exception e) {
handleException(call, grpcFilters, e);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

we shouldn't be calling handleException here. HandleException is for upstream. For Filter thrown error that needs to be returned without giving it back to the same filter.

} finally {
detachContext(contextWithHeaders, previous); // detach headers from gRPC context
}
Expand All @@ -182,19 +214,20 @@ public void onCancel() {
/**
* Helper method to handle RuntimeExceptions and convert it into suitable gRPC message. Closes the ServerCall
*/
private <Req, Res> void handleException(ServerCall<Req, Res> call, Exception e) {
private <Req, Res> void handleException(ServerCall<Req, Res> call,
List<GrpcFilter> grpcFilters, Exception e) {
error("Closing gRPC call due to RuntimeException.", e);
Status returnStatus = Status.INTERNAL;
if (ConstraintViolationException.class.isAssignableFrom(e.getClass())) {
returnStatus = Status.INVALID_ARGUMENT;
if (e instanceof StatusRuntimeException){
returnStatus = ((StatusRuntimeException) e).getStatus();
}

try {
call.close(returnStatus.withDescription(e.getMessage()), new Metadata());
} catch (IllegalStateException ie) {
// Simply log the exception as this is already handling the runtime-exception
warn("Exception while attempting to close ServerCall stream: " + ie.getMessage());
}
grpcFilters.forEach(filter -> filter.doHandleException(e));
}

/* Helper method to attach a context */
Expand Down
4 changes: 2 additions & 2 deletions guice/src/main/java/com/flipkart/gjex/guice/module/ApiModule.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -83,11 +83,11 @@ public Object invoke(MethodInvocation invocation) throws Throwable {
* Client deadline wins over any server specified deadline
*/
if (api != null) {
String methodInvoked = (invocation.getMethod().getDeclaringClass().getSimpleName() + "." + invocation.getMethod().getName()).toLowerCase();
// check and warn if Api is used for non BindableService classes
if (!BindableService.class.isAssignableFrom(invocation.getMethod().getDeclaringClass())) {
warn("Api declarations are interpreted only for sub-types of gRPC BindableService. Api declared for : "
+ methodInvoked + " will not be interpreted/honored");
+ (invocation.getMethod().getDeclaringClass().getSimpleName() + "."
+ invocation.getMethod().getName()).toLowerCase() + " will not be interpreted/honored");
}
int deadline = 0;
if (api.deadlineConfig().length() > 0) { // check if deadline is specified as a config property
Expand Down