Merge pull request #1846 from ballerina-platform/fix-interceptor-erro…

…r-logs

Fix error logging logic with interceptors

ballerina-tests/http-interceptor-tests/tests/http2_interceptors_basic_tests.bal

@@ -416,7 +416,7 @@ function tesHttp2RequestInterceptorPathAndVerb() returns error? {
 
     res = check http2InterceptorsBasicTestsClientEP3->get("/interceptorPathAndVerb/bar");
     test:assertEquals(res.statusCode, 404);
-    common:assertTextPayload(res.getTextPayload(), "no matching resource found for path");
+    common:assertTextPayload(res.getTextPayload(), "no matching resource found for path : /interceptorPathAndVerb/bar , method : GET");
     common:assertHeaderValue(check res.getHeader("last-interceptor"), "default-response-error-interceptor");
     common:assertHeaderValue(check res.getHeader("default-response-error-interceptor"), "true");
     common:assertHeaderValue(check res.getHeader("last-response-interceptor"), "true");

ballerina-tests/http-interceptor-tests/tests/interceptors_error_handling_tests.bal

@@ -87,7 +87,7 @@ function testNoMatchingServiceRegistered() returns error? {
 function testNoMatchingResourceFound() returns error? {
     http:Response res = check serviceErrorHandlingClientEP->get("/foo/new");
     test:assertEquals(res.statusCode, 404);
-    common:assertTextPayload(res.getTextPayload(), "no matching resource found for path");
+    common:assertTextPayload(res.getTextPayload(), "no matching resource found for path : /foo/new , method : GET");
     common:assertHeaderValue(check res.getHeader("last-interceptor"), "default-response-error-interceptor");
     common:assertHeaderValue(check res.getHeader("default-response-error-interceptor"), "true");
     common:assertHeaderValue(check res.getHeader("last-response-interceptor"), "true");
@@ -331,7 +331,7 @@ function testInvalidPathWithSingleService() returns error? {
     http:Client singleServiceRegisteredClientEP = check new("http://localhost:" + singleServiceRegisteredTestPort.toString(), httpVersion = http:HTTP_1_1);
     http:Response res = check singleServiceRegisteredClientEP->get("/path2");
     test:assertEquals(res.statusCode, 404);
-    test:assertEquals(res.getTextPayload(), "no matching service found for path");
+    test:assertEquals(res.getTextPayload(), "no matching service found for path: /path2");
     common:assertHeaderValue(check res.getHeader("last-interceptor"), "default-response-error-interceptor");
     common:assertHeaderValue(check res.getHeader("default-response-error-interceptor"), "true");
     common:assertHeaderValue(check res.getHeader("last-response-interceptor"), "true");
@@ -403,7 +403,7 @@ function testInvalidPathWithRootService() returns error? {
     http:Client rootServiceRegisteredClientEP = check new("http://localhost:" + rootServiceRegisteredTestPort.toString(), httpVersion = http:HTTP_1_1);
     http:Response res = check rootServiceRegisteredClientEP->get("/path2");
     test:assertEquals(res.statusCode, 404);
-    test:assertEquals(res.getTextPayload(), "no matching resource found for path");
+    test:assertEquals(res.getTextPayload(), "no matching resource found for path : /path2 , method : GET");
     common:assertHeaderValue(check res.getHeader("last-interceptor"), "default-response-error-interceptor");
     common:assertHeaderValue(check res.getHeader("default-response-error-interceptor"), "true");
     common:assertHeaderValue(check res.getHeader("last-response-interceptor"), "true");

ballerina-tests/http-test-common/utils.bal

@@ -57,7 +57,7 @@ public isolated function assertJsonPayloadtoJsonString(json|error payload, json
 }
 
 public isolated function assertJsonErrorPayload(json payload, string message, string reason, int statusCode, string path, string method) returns error? {
-    test:assertEquals(payload.message, message);
+    test:assertTrue((check payload.message).toString().startsWith(message));
     test:assertEquals(payload.reason, reason);
     test:assertEquals(payload.status, statusCode);
     test:assertEquals(payload.path, path);

ballerina/http_errors.bal

@@ -38,6 +38,8 @@ public type LoadBalanceActionErrorData record {
 # Defines the common error type for the module.
 public type Error distinct error;
 
+type InternalError distinct Error;
+
 // Level 2
 # Defines the possible listener error types.
 public type ListenerError distinct Error;
@@ -64,42 +66,56 @@ public type GenericListenerError distinct ListenerError;
 # Represents an error, which occurred due to a failure in interceptor return.
 public type InterceptorReturnError distinct ListenerError & httpscerr:InternalServerErrorError;
 
+type InternalInterceptorReturnError InterceptorReturnError & InternalError;
+
 # Represents an error, which occurred due to a header binding.
 public type HeaderBindingError distinct ListenerError & httpscerr:BadRequestError;
 
+type InternalHeaderBindingError HeaderBindingError & InternalError;
+
 // TODO: Change the error type as HeaderBindingError once this issue is fixed:
 // https://github.com/ballerina-platform/ballerina-lang/issues/40273
 # Represents an error, which occurred due to a header constraint validation.
 public type HeaderValidationError distinct HeaderBindingError & httpscerr:BadRequestError;
 
+type InternalHeaderValidationError HeaderValidationError & InternalError;
+
 # Represents an error, which occurred due to the absence of the payload.
 public type NoContentError distinct ClientError;
 
 type PayloadBindingClientError ClientError & PayloadBindingError;
 
-type PayloadBindingListenerError distinct ListenerError & PayloadBindingError & httpscerr:BadRequestError;
+type InternalPayloadBindingListenerError distinct ListenerError & PayloadBindingError & httpscerr:BadRequestError & InternalError;
 
 # Represents an error, which occurred due to payload constraint validation.
 public type PayloadValidationError distinct PayloadBindingError;
 
 type PayloadValidationClientError ClientError & PayloadValidationError;
 
-type PayloadValidationListenerError distinct ListenerError & PayloadValidationError & httpscerr:BadRequestError;
+type InternalPayloadValidationListenerError distinct ListenerError & PayloadValidationError & httpscerr:BadRequestError & InternalError;
 
 # Represents an error, which occurred due to a query parameter binding.
 public type QueryParameterBindingError distinct ListenerError & httpscerr:BadRequestError;
 
+type InternalQueryParameterBindingError QueryParameterBindingError & InternalError;
+
 // TODO: Change the error type as QueryParameterBindingError once this issue is fixed:
 // https://github.com/ballerina-platform/ballerina-lang/issues/40273
 # Represents an error, which occurred due to a query parameter constraint validation.
 public type QueryParameterValidationError distinct QueryParameterBindingError & httpscerr:BadRequestError;
 
+type InternalQueryParameterValidationError QueryParameterValidationError & InternalError;
+
 # Represents an error, which occurred due to a path parameter binding.
 public type PathParameterBindingError distinct ListenerError & httpscerr:BadRequestError;
 
+type InternalPathParameterBindingError PathParameterBindingError & InternalError;
+
 # Represents an error, which occurred during the request dispatching.
 public type RequestDispatchingError distinct ListenerError;
 
+type InternalRequestDispatchingError RequestDispatchingError & InternalError;
+
 # Represents an error, which occurred during the service dispatching.
 public type ServiceDispatchingError distinct RequestDispatchingError;
 
@@ -242,23 +258,39 @@ public type InvalidCookieError distinct OutboundResponseError;
 # Represents Service Not Found error.
 public type ServiceNotFoundError httpscerr:NotFoundError & ServiceDispatchingError;
 
+type InternalServiceNotFoundError ServiceNotFoundError & InternalError;
+
 # Represents Bad Matrix Parameter in the request error.
 public type BadMatrixParamError httpscerr:BadRequestError & ServiceDispatchingError;
 
+type InternalBadMatrixParamError BadMatrixParamError & InternalError;
+
 # Represents an error, which occurred when the resource is not found during dispatching.
 public type ResourceNotFoundError httpscerr:NotFoundError & ResourceDispatchingError;
 
+type InternalResourceNotFoundError ResourceNotFoundError & InternalError;
+
 # Represents an error, which occurred due to a path parameter constraint validation.
 public type ResourcePathValidationError httpscerr:BadRequestError & ResourceDispatchingError;
 
+type InternalResourcePathValidationError ResourcePathValidationError & InternalError;
+
 # Represents an error, which occurred when the resource method is not allowed during dispatching.
 public type ResourceMethodNotAllowedError httpscerr:MethodNotAllowedError & ResourceDispatchingError;
 
+type InternalResourceMethodNotAllowedError ResourceMethodNotAllowedError & InternalError;
+
 # Represents an error, which occurred when the media type is not supported during dispatching.
 public type UnsupportedRequestMediaTypeError httpscerr:UnsupportedMediaTypeError & ResourceDispatchingError;
 
+type InternalUnsupportedRequestMediaTypeError UnsupportedRequestMediaTypeError & InternalError;
+
 # Represents an error, which occurred when the payload is not acceptable during dispatching.
 public type RequestNotAcceptableError httpscerr:NotAcceptableError & ResourceDispatchingError;
 
+type InternalRequestNotAcceptableError RequestNotAcceptableError & InternalError;
+
 # Represents other internal server errors during dispatching.
 public type ResourceDispatchingServerError httpscerr:InternalServerErrorError & ResourceDispatchingError;
+
+type InternalResourceDispatchingServerError ResourceDispatchingServerError & InternalError;

ballerina/http_interceptors.bal

@@ -15,6 +15,7 @@
 // under the License.
 
 import ballerina/jwt;
+import ballerina/log;
 
 # The HTTP request interceptor service object type
 public type RequestInterceptor distinct service object {
@@ -57,6 +58,9 @@ service class DefaultErrorInterceptor {
     *ResponseErrorInterceptor;
 
     remote function interceptResponseError(error err, Request request) returns Response {
+        if err !is InternalError {
+            log:printError("unhandled error returned from the service", err, path = request.rawPath, method = request.method);
+        }
         return getErrorResponseForInterceptor(err, request);
     }
 }

changelog.md

@@ -15,6 +15,7 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/),
 - [Remove unused import from Http2StateUtil](https://github.com/ballerina-platform/ballerina-library/issues/5966)
 - [Fix client getting hanged when server closes connection in the ALPN handshake](https://github.com/ballerina-platform/ballerina-library/issues/6003)
 - [Fix client getting hanged when multiple requests are sent which exceed `maxHeaderSize`](https://github.com/ballerina-platform/ballerina-library/issues/6000)
+- [Fix inconsistencies with error logging](https://github.com/ballerina-platform/ballerina-library/issues/5877)
 
 ## [2.10.5] - 2023-12-06
 

native/src/main/java/io/ballerina/stdlib/http/api/BallerinaHTTPConnectorListener.java

@@ -87,7 +87,7 @@ public void onMessage(HttpCarbonMessage inboundMessage) {
         } catch (Exception ex) {
             HttpRequestInterceptorUnitCallback callback = new HttpRequestInterceptorUnitCallback(inboundMessage,
                     httpServicesRegistry.getRuntime(), this);
-            callback.invokeErrorInterceptors(HttpUtil.createError(ex), false);
+            callback.invokeErrorInterceptors(HttpUtil.createError(ex), true);
             return;
         }
 
@@ -101,7 +101,7 @@ public void onMessage(HttpCarbonMessage inboundMessage) {
             } catch (Exception ex) {
                 HttpCallableUnitCallback callback = new HttpCallableUnitCallback(inboundMessage,
                         httpServicesRegistry.getRuntime());
-                callback.invokeErrorInterceptors(HttpUtil.createError(ex), false);
+                callback.invokeErrorInterceptors(HttpUtil.createError(ex), true);
             }
         }
     }
@@ -285,7 +285,7 @@ protected void executeMainResourceOnMessage(HttpCarbonMessage inboundMessage) {
         } catch (BallerinaConnectorException ex) {
             HttpCallableUnitCallback callback = new HttpCallableUnitCallback(inboundMessage,
                     httpServicesRegistry.getRuntime());
-            callback.invokeErrorInterceptors(HttpUtil.createError(ex), false);
+            callback.invokeErrorInterceptors(HttpUtil.createError(ex), true);
         }
     }
 
@@ -319,7 +319,7 @@ private void setTargetServiceToInboundMsg(HttpCarbonMessage inboundMessage) {
         } catch (Exception e) {
             if (((BArray) listenerLevelInterceptors).size() == 1 &&
                     e instanceof BError && ((BError) e).getType().getName()
-                    .equals(HttpErrorType.SERVICE_NOT_FOUND_ERROR.getErrorName())) {
+                    .equals(HttpErrorType.INTERNAL_SERVICE_NOT_FOUND_ERROR.getErrorName())) {
                 HttpService singleService = HttpDispatcher.findSingleService(httpServicesRegistry);
                 if (singleService != null && singleService.hasInterceptors()) {
                     inboundMessage.setProperty(INTERCEPTORS, singleService.getBalInterceptorServicesArray());

native/src/main/java/io/ballerina/stdlib/http/api/HttpCallableUnitCallback.java

@@ -92,7 +92,7 @@ public void notifySuccess(Object result) {
             return;
         }
         if (result instanceof BError) {
-            invokeErrorInterceptors((BError) result, true);
+            invokeErrorInterceptors((BError) result, false);
             return;
         }
         if (isLastService) {
@@ -130,7 +130,6 @@ public void invokeBalMethod(Object[] paramFeed, String methodName) {
             @Override
             public void notifySuccess(Object result) {
                 stopObserverContext();
-                printStacktraceIfError(result);
             }
 
             @Override
@@ -166,17 +165,19 @@ public void notifyFailure(BError error) { // handles panic and check_panic
         System.exit(1);
     }
 
-    public void invokeErrorInterceptors(BError error, boolean printError) {
-        requestMessage.setProperty(HttpConstants.INTERCEPTOR_SERVICE_ERROR, error);
-        if (printError) {
-            error.printStackTrace();
+    public void invokeErrorInterceptors(BError error, boolean isInternalError) {
+        if (isInternalError) {
+            requestMessage.setProperty(HttpConstants.INTERNAL_ERROR, true);
+        } else {
+            requestMessage.removeProperty(HttpConstants.INTERNAL_ERROR);
         }
+        requestMessage.setProperty(HttpConstants.INTERCEPTOR_SERVICE_ERROR, error);
         returnErrorResponse(error);
     }
 
     public void sendFailureResponse(BError error) {
         stopObserverContext();
-        HttpUtil.handleFailure(requestMessage, error, true);
+        HttpUtil.handleFailure(requestMessage, error);
     }
 
     public void cleanupRequestMessage() {
@@ -186,19 +187,13 @@ public void cleanupRequestMessage() {
     private boolean alreadyResponded(Object result) {
         try {
             HttpUtil.methodInvocationCheck(requestMessage, HttpConstants.INVALID_STATUS_CODE, ILLEGAL_FUNCTION_INVOKED);
-        } catch (BError e) {
+        } catch (BError bError) {
             if (result != null) { // handles nil return and end of resource exec
-                printStacktraceIfError(result);
-                err.println(HttpConstants.HTTP_RUNTIME_WARNING_PREFIX + e.getMessage());
+                bError.printStackTrace();
+                err.println(HttpConstants.HTTP_RUNTIME_WARNING_PREFIX + bError.getMessage());
             }
             return true;
         }
         return false;
     }
-
-    private void printStacktraceIfError(Object result) {
-        if (result instanceof BError) {
-            ((BError) result).printStackTrace();
-        }
-    }
 }

native/src/main/java/io/ballerina/stdlib/http/api/HttpConstants.java

@@ -382,6 +382,7 @@ public final class HttpConstants {
     public static final String REQUEST_INTERCEPTOR_INDEX = "REQUEST_INTERCEPTOR_INDEX";
     public static final String RESPONSE_INTERCEPTOR_INDEX = "RESPONSE_INTERCEPTOR_INDEX";
     public static final String INTERCEPTOR_SERVICE_ERROR = "INTERCEPTOR_SERVICE_ERROR";
+    public static final String INTERNAL_ERROR = "INTERNAL_ERROR";
     public static final String WAIT_FOR_FULL_REQUEST = "WAIT_FOR_FULL_REQUEST";
     public static final String HTTP_NORMAL = "Normal";
     public static final String REQUEST_INTERCEPTOR = "RequestInterceptor";