Skip to content

Commit

Permalink
Fix HTTP/2.0 stacked logging
Browse files Browse the repository at this point in the history
  • Loading branch information
AzeemMuzammil committed Jun 10, 2024
1 parent d1321ec commit baf054a
Show file tree
Hide file tree
Showing 7 changed files with 36 additions and 44 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,6 @@

import java.util.LinkedHashMap;
import java.util.List;
import java.util.Locale;
import java.util.Map;
import java.util.Objects;
import java.util.stream.Collectors;
Expand All @@ -52,10 +51,6 @@ public class HttpAccessLogger {

private HttpAccessLogger() {}

public static boolean isEnabled() {
return ACCESS_LOGGER.isEnabled(InternalLogLevel.INFO);
}

public static void log(HttpAccessLogMessage inboundMessage, List<HttpAccessLogMessage> outboundMessages) {
String formattedAccessLogMessage = formatAccessLogMessage(inboundMessage, outboundMessages,
HttpAccessLogConfig.getInstance().getAccessLogFormat(),
Expand Down Expand Up @@ -156,8 +151,13 @@ private static String getCustomHeaderValueForAttribute(HttpAccessLogMessage http
String attribute) {
Map<String, String> customHeaders = httpAccessLogMessage.getCustomHeaders();
if (attribute.startsWith("http_")) {
String customHeaderKey = attribute.substring(5).toLowerCase(Locale.getDefault());
return customHeaders.getOrDefault(customHeaderKey, "-");
String customHeaderKey = attribute.substring(5);
for (Map.Entry<String, String> entry : customHeaders.entrySet()) {
if (entry.getKey().equalsIgnoreCase(customHeaderKey)) {
return entry.getValue();
}
}
return "-";
}
return null;
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -63,6 +63,7 @@
import org.slf4j.LoggerFactory;

import java.net.InetSocketAddress;
import java.util.ArrayList;

import static io.ballerina.stdlib.http.transport.contract.Constants.BASE_64_ENCODED_CERT;
import static io.ballerina.stdlib.http.transport.contract.Constants.CHNL_HNDLR_CTX;
Expand All @@ -74,6 +75,7 @@
import static io.ballerina.stdlib.http.transport.contract.Constants.LISTENER_PORT;
import static io.ballerina.stdlib.http.transport.contract.Constants.LOCAL_ADDRESS;
import static io.ballerina.stdlib.http.transport.contract.Constants.MUTUAL_SSL_HANDSHAKE_RESULT;
import static io.ballerina.stdlib.http.transport.contract.Constants.OUTBOUND_ACCESS_LOG_MESSAGES;
import static io.ballerina.stdlib.http.transport.contract.Constants.POOLED_BYTE_BUFFER_FACTORY;
import static io.ballerina.stdlib.http.transport.contract.Constants.PROMISED_STREAM_REJECTED_ERROR;
import static io.ballerina.stdlib.http.transport.contract.Constants.PROTOCOL;
Expand Down Expand Up @@ -158,6 +160,7 @@ public static HttpCarbonRequest setupCarbonRequest(HttpRequest httpRequest, Http
String uri = httpRequest.uri();
sourceReqCMsg.setRequestUrl(uri);
sourceReqCMsg.setProperty(TO, uri);
sourceReqCMsg.setProperty(OUTBOUND_ACCESS_LOG_MESSAGES, new ArrayList<>());
return sourceReqCMsg;
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -290,10 +290,6 @@ private void triggerPipeliningLogic(HttpCarbonMessage outboundResponseMsg) {
}

private void logAccessInfo(HttpCarbonMessage inboundRequestMsg, HttpCarbonMessage outboundResponseMsg) {
if (!HttpAccessLogger.isEnabled()) {
return;
}

HttpHeaders headers = inboundRequestMsg.getHeaders();
if (headers.contains(HTTP_X_FORWARDED_FOR)) {
String forwardedHops = headers.get(HTTP_X_FORWARDED_FOR);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -53,14 +53,13 @@
import org.slf4j.LoggerFactory;

import java.io.IOException;
import java.util.ArrayList;
import java.util.Calendar;
import java.util.List;

import static io.ballerina.stdlib.http.transport.contract.Constants.HTTP_X_FORWARDED_FOR;
import static io.ballerina.stdlib.http.transport.contract.Constants.IDLE_TIMEOUT_TRIGGERED_WHILE_WRITING_OUTBOUND_RESPONSE_BODY;
import static io.ballerina.stdlib.http.transport.contract.Constants.OUTBOUND_ACCESS_LOG_MESSAGES;
import static io.ballerina.stdlib.http.transport.contract.Constants.REMOTE_CLIENT_CLOSED_WHILE_WRITING_OUTBOUND_RESPONSE_BODY;
import static io.ballerina.stdlib.http.transport.contract.Constants.SRC_HANDLER;
import static io.ballerina.stdlib.http.transport.contractimpl.common.states.Http2StateUtil.validatePromisedStreamState;

/**
Expand Down Expand Up @@ -213,9 +212,6 @@ private void writeData(HttpContent httpContent, int streamId, boolean endStream)

private void logAccessInfo(HttpCarbonMessage inboundRequestMsg, HttpCarbonMessage outboundResponseMsg,
int streamId) {
if (!HttpAccessLogger.isEnabled()) {
return;
}
if (originalStreamId != streamId) { // Skip access logs for server push messages
LOG.debug("Access logging skipped for server push response");
return;
Expand Down Expand Up @@ -256,12 +252,23 @@ private void logAccessInfo(HttpCarbonMessage inboundRequestMsg, HttpCarbonMessag
inboundMessage.setRequestBodySize((long) inboundRequestMsg.getContentSize());
inboundMessage.setRequestTime(requestTime);

List<HttpAccessLogMessage> outboundMessages = new ArrayList<>();
Object sourceHandlerObject = inboundRequestMsg.getProperty(SRC_HANDLER);
List<HttpAccessLogMessage> outboundMessages = getHttpAccessLogMessages(inboundRequestMsg);

if (sourceHandlerObject instanceof Http2SourceHandler http2SourceHandler) {
outboundMessages.addAll(http2SourceHandler.getHttpAccessLogMessages());
}
HttpAccessLogger.log(inboundMessage, outboundMessages);
}

private List<HttpAccessLogMessage> getHttpAccessLogMessages(HttpCarbonMessage request) {
Object outboundAccessLogMessagesObject = request.getProperty(OUTBOUND_ACCESS_LOG_MESSAGES);
if (outboundAccessLogMessagesObject instanceof List<?> rawList) {
for (Object item : rawList) {
if (!(item instanceof HttpAccessLogMessage)) {
return null;
}
}
@SuppressWarnings("unchecked")
List<HttpAccessLogMessage> outboundAccessLogMessages = (List<HttpAccessLogMessage>) rawList;
return outboundAccessLogMessages;
}
return null;
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -124,7 +124,6 @@ public HttpClientChannelInitializer(SenderConfiguration senderConfiguration, Htt
connectionHandlerBuilder.initialSettings().initialWindowSize(senderConfiguration.getHttp2InitialWindowSize());
http2ConnectionHandler = connectionHandlerBuilder.connection(connection).frameListener(frameListener).build();
http2TargetHandler = new Http2TargetHandler(connection, http2ConnectionHandler.encoder());
http2TargetHandler.setHttpClientChannelInitializer(this);
if (sslConfig != null) {
sslHandlerFactory = new SSLHandlerFactory(sslConfig);
}
Expand All @@ -140,6 +139,7 @@ protected void initChannel(SocketChannel socketChannel) throws Exception {
targetHandler.setHttp2TargetHandler(http2TargetHandler);
targetHandler.setKeepAliveConfig(getKeepAliveConfig());
targetHandler.setHttpClientChannelInitializer(this);
http2TargetHandler.setHttpClientChannelInitializer(this);
if (http2) {
if (sslConfig != null) {
configureSslForHttp2(socketChannel, clientPipeline, sslConfig);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -20,12 +20,9 @@

import io.ballerina.stdlib.http.api.logging.accesslog.HttpAccessLogConfig;
import io.ballerina.stdlib.http.api.logging.accesslog.HttpAccessLogMessage;
import io.ballerina.stdlib.http.transport.contract.Constants;
import io.ballerina.stdlib.http.transport.contract.HttpResponseFuture;
import io.ballerina.stdlib.http.transport.contractimpl.common.states.SenderReqRespStateManager;
import io.ballerina.stdlib.http.transport.contractimpl.common.states.StateUtil;
import io.ballerina.stdlib.http.transport.contractimpl.listener.SourceHandler;
import io.ballerina.stdlib.http.transport.contractimpl.listener.http2.Http2SourceHandler;
import io.ballerina.stdlib.http.transport.contractimpl.sender.TargetHandler;
import io.ballerina.stdlib.http.transport.message.HttpCarbonMessage;
import io.netty.channel.ChannelHandlerContext;
Expand Down Expand Up @@ -173,11 +170,11 @@ private void updateAccessLogInfo(TargetHandler targetHandler,

outboundAccessLogMessage.setRequestMethod(httpOutboundRequest.getHttpMethod());
outboundAccessLogMessage.setRequestUri((String) httpOutboundRequest.getProperty(TO));
HttpMessage outboundRequest = httpOutboundRequest.getNettyHttpRequest();
if (outboundRequest != null) {
outboundAccessLogMessage.setScheme(outboundRequest.protocolVersion().toString());
HttpMessage inboundResponse = inboundResponseMsg.getNettyHttpResponse();
if (inboundResponse != null) {
outboundAccessLogMessage.setScheme(inboundResponse.protocolVersion().toString());
} else {
outboundAccessLogMessage.setScheme(httpOutboundRequest.getHttpVersion());
outboundAccessLogMessage.setScheme(inboundResponseMsg.getHttpVersion());
}
outboundAccessLogMessage.setRequestBodySize((long) httpOutboundRequest.getContentSize());
outboundAccessLogMessage.setStatus(inboundResponseMsg.getHttpStatusCode());
Expand All @@ -188,16 +185,12 @@ private void updateAccessLogInfo(TargetHandler targetHandler,

HttpCarbonMessage inboundReqMsg =
getTypedProperty(httpOutboundRequest, INBOUND_MESSAGE, HttpCarbonMessage.class);
Http2SourceHandler http2SourceHandler =
getTypedProperty(httpOutboundRequest, Constants.SRC_HANDLER, Http2SourceHandler.class);

if (inboundReqMsg != null) {
List<HttpAccessLogMessage> outboundAccessLogMessages = getHttpAccessLogMessages(inboundReqMsg);
if (outboundAccessLogMessages != null) {
outboundAccessLogMessages.add(outboundAccessLogMessage);
}
} else if (http2SourceHandler != null) {
http2SourceHandler.addHttpAccessLogMessage(outboundAccessLogMessage);
}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -20,10 +20,7 @@

import io.ballerina.stdlib.http.api.logging.accesslog.HttpAccessLogConfig;
import io.ballerina.stdlib.http.api.logging.accesslog.HttpAccessLogMessage;
import io.ballerina.stdlib.http.transport.contract.Constants;
import io.ballerina.stdlib.http.transport.contractimpl.common.states.Http2MessageStateContext;
import io.ballerina.stdlib.http.transport.contractimpl.listener.SourceHandler;
import io.ballerina.stdlib.http.transport.contractimpl.listener.http2.Http2SourceHandler;
import io.ballerina.stdlib.http.transport.contractimpl.sender.http2.Http2ClientChannel;
import io.ballerina.stdlib.http.transport.contractimpl.sender.http2.Http2TargetHandler;
import io.ballerina.stdlib.http.transport.contractimpl.sender.http2.OutboundMsgHolder;
Expand Down Expand Up @@ -236,11 +233,11 @@ private void updateAccessLogInfo(OutboundMsgHolder outboundMsgHolder) {

outboundAccessLogMessage.setRequestMethod(httpOutboundRequest.getHttpMethod());
outboundAccessLogMessage.setRequestUri((String) httpOutboundRequest.getProperty(TO));
HttpMessage outboundRequest = httpOutboundRequest.getNettyHttpRequest();
if (outboundRequest != null) {
outboundAccessLogMessage.setScheme(outboundRequest.protocolVersion().toString());
HttpMessage inboundResponse = outboundMsgHolder.getResponse().getNettyHttpResponse();
if (inboundResponse != null) {
outboundAccessLogMessage.setScheme(inboundResponse.protocolVersion().toString());
} else {
outboundAccessLogMessage.setScheme(httpOutboundRequest.getHttpVersion());
outboundAccessLogMessage.setScheme(outboundMsgHolder.getResponse().getHttpVersion());
}
outboundAccessLogMessage.setRequestBodySize((long) httpOutboundRequest.getContentSize());
outboundAccessLogMessage.setStatus(outboundMsgHolder.getResponse().getHttpStatusCode());
Expand All @@ -251,16 +248,12 @@ private void updateAccessLogInfo(OutboundMsgHolder outboundMsgHolder) {

HttpCarbonMessage inboundReqMsg =
getTypedProperty(httpOutboundRequest, INBOUND_MESSAGE, HttpCarbonMessage.class);
Http2SourceHandler http2SourceHandler =
getTypedProperty(httpOutboundRequest, Constants.SRC_HANDLER, Http2SourceHandler.class);

if (inboundReqMsg != null) {
List<HttpAccessLogMessage> outboundAccessLogMessages = getHttpAccessLogMessages(inboundReqMsg);
if (outboundAccessLogMessages != null) {
outboundAccessLogMessages.add(outboundAccessLogMessage);
}
} else if (http2SourceHandler != null) {
http2SourceHandler.addHttpAccessLogMessage(outboundAccessLogMessage);
}
}

Expand Down

0 comments on commit baf054a

Please sign in to comment.