Error Handling in Interceptors

core/src/main/java/com/flipkart/gjex/core/context/AccessLogContext.java

@@ -7,7 +7,6 @@
 
 import java.lang.reflect.Field;
 import java.time.Instant;
-import java.time.LocalDateTime;
 import java.time.OffsetDateTime;
 import java.time.ZoneId;
 import java.time.format.DateTimeFormatter;

core/src/main/java/com/flipkart/gjex/core/filter/grpc/AccessLogGrpcFilter.java

@@ -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;
 
@@ -57,7 +58,8 @@ public class AccessLogGrpcFilter<R extends GeneratedMessageV3, S extends Generat
     private static final Logger logger = Logging.loggerWithName("ACCESS-LOG");
 
     public AccessLogGrpcFilter() {
-
+        accessLogContextBuilder = AccessLogContext.builder();
+        accessLogContextBuilder.requestTime(System.currentTimeMillis());
     }
 
     /**
@@ -77,9 +79,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());
@@ -125,10 +125,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));
     }

core/src/main/java/com/flipkart/gjex/core/filter/http/AccessLogHttpFilter.java

@@ -39,7 +39,8 @@ public class AccessLogHttpFilter extends HttpFilter implements Logging {
     protected static String format;
 
     public AccessLogHttpFilter() {
-
+        accessLogContextBuilder = AccessLogContext.builder();
+        accessLogContextBuilder.requestTime(System.currentTimeMillis());
     }
 
     public static void setFormat(String format) {
@@ -60,9 +61,7 @@ public HttpFilter getInstance() {
      */
     @Override
     public void doProcessRequest(ServletRequest req, RequestParams<Map<String,String>> requestParamsInput) {
-        startTime = System.currentTimeMillis();
-        accessLogContextBuilder = AccessLogContext.builder()
-            .requestTime(startTime)
+        accessLogContextBuilder
             .clientIp(requestParamsInput.getClientIp())
             .resourcePath(requestParamsInput.getResourcePath())
             .protocol(req.getProtocol())
@@ -91,7 +90,7 @@ public void doProcessResponse(ServletResponse response) {
         HttpServletResponse httpServletResponse = (HttpServletResponse) response;
         if (isSuccess(httpServletResponse.getStatus())) {
             // 2xx response
-            // TODO: check case where GET response is successful by content-length is -1.
+            // TODO: check case where GET response is successful but content-length is -1.
             int contentLength =
                 Optional.ofNullable(httpServletResponse.getHeader(HttpHeaders.CONTENT_LENGTH))
                     .map(Integer::parseInt).orElse(0);
@@ -110,7 +109,7 @@ public void doProcessResponse(ServletResponse response) {
     public void doHandleException(Exception e) {
         // This shouldn't come here for http filters, that said, ensuring that even if happens we log it.
         accessLogContextBuilder
-            .contentLength(0)
+            .contentLength(-1)
             .responseStatus(500)
             .responseTime(System.currentTimeMillis() - startTime);
         logger.info(accessLogContextBuilder.build().format(format));

examples/build.gradle

@@ -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'

examples/src/main/resources/log4j2.xml

@@ -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">

guice/src/main/java/com/flipkart/gjex/grpc/interceptor/FilterInterceptor.java

@@ -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;
 
@@ -157,7 +168,7 @@ 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);
                 }  finally  {
                     detachContext(contextWithHeaders, previous);    // detach headers from gRPC context
@@ -185,10 +196,9 @@ public void onCancel() {
     private <Req, Res> void handleException(ServerCall<Req, Res> call, 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) {

guice/src/main/java/com/flipkart/gjex/guice/module/ApiModule.java

@@ -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

guice/src/main/java/com/flipkart/gjex/http/interceptor/HttpFilterInterceptor.java

@@ -3,13 +3,16 @@
 import com.flipkart.gjex.core.filter.RequestParams;
 import com.flipkart.gjex.core.filter.http.HttpFilter;
 import com.flipkart.gjex.core.filter.http.HttpFilterParams;
+import com.flipkart.gjex.core.logging.Logging;
 import org.eclipse.jetty.http.pathmap.ServletPathSpec;
-import org.slf4j.Logger;
-import org.slf4j.LoggerFactory;
 
 import javax.inject.Named;
 import javax.inject.Singleton;
-import javax.servlet.*;
+import javax.servlet.FilterChain;
+import javax.servlet.FilterConfig;
+import javax.servlet.ServletException;
+import javax.servlet.ServletRequest;
+import javax.servlet.ServletResponse;
 import javax.servlet.http.HttpServletRequest;
 import javax.servlet.http.HttpServletResponse;
 import java.io.IOException;
@@ -21,10 +24,7 @@
 
 @Singleton
 @Named("HttpFilterInterceptor")
-public class HttpFilterInterceptor implements javax.servlet.Filter {
-
-    private static final Logger logger = LoggerFactory.getLogger(HttpFilterInterceptor.class);
-
+public class HttpFilterInterceptor implements javax.servlet.Filter, Logging {
     private static class ServletPathFiltersHolder {
         ServletPathSpec spec;
         HttpFilter filter;
@@ -100,10 +100,9 @@ public final void doFilter(ServletRequest request, ServletResponse response,
         } else {
             // For Unsupported request types, pass the request and response as is
             chain.doFilter(request, response);
-            logger.warn("Unsupported request type {}, pass the request and response as is.", request.getClass());
+            warn(String.format("Unsupported request type %s, pass the request and response as is",
+                request.getClass()));
         }
-
-
     }
 
     /**