logbook icon indicating copy to clipboard operation
logbook copied to clipboard

CorrelationID deferred evaluation.

Open azakrytnoi opened this issue 3 years ago • 0 comments

When use Netty, headers and body are retrieved in separate steps. Logbook creates correlationId when only headers are requested, and both is yet not. But 1st print is happens after request is read completely. This prevents usage of some information from the body in evaluation of correlationId, for example SOAP WSA_ADDRESSING attributes.

Detailed Description

Precorrelation object is created at the very beginning of the process, in Netty pipeline body is not yet read. It's not used in pairing of request and response, and only used in writing stage. Writing stage is evaluated after request body is read from Netty channel. Currently Precorrelation contains direct string value for correlationId, which makes it impossible to use any information from the request body in generation of correlationId.

If SimplePrecorrelation would use provider instead of direct string value for correlationId, this would allow to postpone the generation of correlationId to the moment when it's really necessary and all information is available.

    private Precorrelation newPrecorrelation(final HttpRequest request) {
       // If SimplePrecorrelation would accept  _provider_ instead of direct value, issue would be solved.
        return new SimplePrecorrelation(correlationId.generate(request), clock);
    }

    public RequestWritingStage process(final HttpRequest originalRequest, final Strategy strategy) throws IOException {

        if (sink.isActive() && predicate.test(originalRequest)) {
           // Here correlationId is _already_ evaluated, but request body is not yet available
            final Precorrelation precorrelation = newPrecorrelation(originalRequest);
            final HttpRequest processedRequest = strategy.process(originalRequest);

            final HttpRequest request = new CachingHttpRequest(processedRequest);
            final HttpRequest filteredRequest = requestFilter.filter(request);

            return new RequestWritingStage() {
                @Override
                public ResponseProcessingStage write() throws IOException {
                   // Time when correlationId is _really_ necessary
                    strategy.write(precorrelation, filteredRequest, sink);

                    return this;
                }

                @Override
                public ResponseWritingStage process(final HttpResponse originalResponse) throws IOException {
                    final HttpResponse processedResponse = strategy.process(filteredRequest, originalResponse);

                    return () -> {
                        final HttpResponse response = new CachingHttpResponse(processedResponse);
                        final HttpResponse filteredResponse = responseFilter.filter(response);
                       // Next time correlationId is necessary
                        strategy.write(precorrelation.correlate(), filteredRequest, filteredResponse, sink);
                    };
                }
            };
        } else {
            return Stages.noop();
        }
    }

Context

Micronaut and might be other Netty related servers, when assembly of the request happens in several steps. SOAP processing and a business requires to use some of WSA-ADDRESSING attributes as correlationId in the logs.

Possible Implementation

As explained in detailed description - defer generation of correlationId till the moment it's actually necessary and whole request is read from Netty channel.

Your Environment

Micronaut SOAP server.

  • Version used: logbook v 2.14.0
  • Link to your project: private

azakrytnoi avatar Feb 09 '22 10:02 azakrytnoi