diff --git a/server/pxf-service/src/main/java/org/apache/cloudberry/pxf/service/spring/PxfContextMdcLogEnhancerFilter.java b/server/pxf-service/src/main/java/org/apache/cloudberry/pxf/service/spring/PxfContextMdcLogEnhancerFilter.java index 04e2bb7a6..a8d930504 100644 --- a/server/pxf-service/src/main/java/org/apache/cloudberry/pxf/service/spring/PxfContextMdcLogEnhancerFilter.java +++ b/server/pxf-service/src/main/java/org/apache/cloudberry/pxf/service/spring/PxfContextMdcLogEnhancerFilter.java @@ -21,8 +21,17 @@ @Component public class PxfContextMdcLogEnhancerFilter extends OncePerRequestFilter { + // sessionId: composite PXF request identifier formed as ":", + // where XID is the Greenplum transaction id and the server name defaults to "default". + // Groups all log records produced while serving a single PXF request. private static final String MDC_SESSION_ID = "sessionId"; + // segmentId: the Greenplum segment id (X-GP-SEGMENT-ID) that issued the PXF request. private static final String MDC_SEGMENT_ID = "segmentId"; + // ssid: query session identifier from pg_stat_activity system view. + private static final String MDC_SSID = "ssid"; + // ccnt: the command number within this session as shown by gp_command_count. + // All records associated with the query will have the same ccnt. + private static final String MDC_CCNT = "ccnt"; private final HttpHeaderDecoder decoder; @@ -60,10 +69,16 @@ private void insertIntoMDC(HttpServletRequest request) { String serverName = StringUtils.defaultIfBlank(decoder.getHeaderValue("X-GP-OPTIONS-SERVER", request, encoded), "default"); String sessionId = String.format("%s:%s", xid, serverName); String segmentId = decoder.getHeaderValue("X-GP-SEGMENT-ID", request, encoded); + String gpSessionId = decoder.getHeaderValue("X-GP-SESSION-ID", request, encoded); + String gpCommandCount = decoder.getHeaderValue("X-GP-COMMAND-COUNT", request, encoded); MDC.put(MDC_SESSION_ID, sessionId); MDC.put(MDC_SEGMENT_ID, segmentId); - log.debug("MDC: Added {}={}", MDC_SESSION_ID, sessionId); - log.debug("MDC: Added {}={}", MDC_SEGMENT_ID, segmentId); + MDC.put(MDC_SSID, gpSessionId); + MDC.put(MDC_CCNT, gpCommandCount); + log.trace("MDC: Added {}={}", MDC_SESSION_ID, sessionId); + log.trace("MDC: Added {}={}", MDC_SEGMENT_ID, segmentId); + log.trace("MDC: Added {}={}", MDC_SSID, gpSessionId); + log.trace("MDC: Added {}={}", MDC_CCNT, gpCommandCount); } /** @@ -73,5 +88,7 @@ private void clearMDC() { // removing possibly non-existent item is OK MDC.remove(MDC_SEGMENT_ID); MDC.remove(MDC_SESSION_ID); + MDC.remove(MDC_SSID); + MDC.remove(MDC_CCNT); } } diff --git a/server/pxf-service/src/templates/conf/pxf-log4j2.xml b/server/pxf-service/src/templates/conf/pxf-log4j2.xml index d684cc2ab..de6dc3e76 100644 --- a/server/pxf-service/src/templates/conf/pxf-log4j2.xml +++ b/server/pxf-service/src/templates/conf/pxf-log4j2.xml @@ -2,7 +2,7 @@ %xwEx - %5p [%X{sessionId}:%-3X{segmentId}] + %5p [%X{sessionId}:%-3X{segmentId}][ssid=%X{ssid},ccnt=%X{ccnt}] yyyy-MM-dd HH:mm:ss.SSS zzz %clr{%d{${LOG_DATEFORMAT_PATTERN}}}{faint} %clr{${LOG_LEVEL_PATTERN}} %clr{%pid}{magenta} %clr{---}{faint} %clr{[%15.15t]}{faint} %clr{%-40.40c{1.}}{cyan} %clr{:}{faint} %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD} %d{${LOG_DATEFORMAT_PATTERN}} ${LOG_LEVEL_PATTERN} %pid --- [%-9.10t] %-40.40c{1.} : %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD} diff --git a/server/pxf-service/src/test/java/org/apache/cloudberry/pxf/service/spring/PxfContextMdcLogEnhancerFilterTest.java b/server/pxf-service/src/test/java/org/apache/cloudberry/pxf/service/spring/PxfContextMdcLogEnhancerFilterTest.java index 5b97caefd..182306114 100644 --- a/server/pxf-service/src/test/java/org/apache/cloudberry/pxf/service/spring/PxfContextMdcLogEnhancerFilterTest.java +++ b/server/pxf-service/src/test/java/org/apache/cloudberry/pxf/service/spring/PxfContextMdcLogEnhancerFilterTest.java @@ -42,6 +42,8 @@ void testNonPxfContextRequest() throws ServletException, IOException { // always removes verify(mdcMock).remove("segmentId"); verify(mdcMock).remove("sessionId"); + verify(mdcMock).remove("ssid"); + verify(mdcMock).remove("ccnt"); verifyNoMoreInteractions(mdcMock); } @@ -54,9 +56,13 @@ void testPxfContextRequest() throws ServletException, IOException { verify(mdcMock).put("sessionId", "transaction:id:default"); verify(mdcMock).put("segmentId", "5"); + verify(mdcMock).put("ssid", null); + verify(mdcMock).put("ccnt", null); verify(mdcMock).remove("segmentId"); verify(mdcMock).remove("sessionId"); + verify(mdcMock).remove("ssid"); + verify(mdcMock).remove("ccnt"); verifyNoMoreInteractions(mdcMock); } @@ -70,9 +76,34 @@ void testPxfContextRequestWithServerName() throws ServletException, IOException verify(mdcMock).put("sessionId", "transaction:id:s3"); verify(mdcMock).put("segmentId", "5"); + verify(mdcMock).put("ssid", null); + verify(mdcMock).put("ccnt", null); verify(mdcMock).remove("segmentId"); verify(mdcMock).remove("sessionId"); + verify(mdcMock).remove("ssid"); + verify(mdcMock).remove("ccnt"); + verifyNoMoreInteractions(mdcMock); + } + + @Test + void testPxfContextRequestWithGpSessionId() throws ServletException, IOException { + + mockRequest.addHeader("X-GP-XID", "transaction:id"); + mockRequest.addHeader("X-GP-SEGMENT-ID", "5"); + mockRequest.addHeader("X-GP-SESSION-ID", "12345"); + mockRequest.addHeader("X-GP-COMMAND-COUNT", "7"); + filter.doFilter(mockRequest, mockResponse, mockFilterChain); + + verify(mdcMock).put("sessionId", "transaction:id:default"); + verify(mdcMock).put("segmentId", "5"); + verify(mdcMock).put("ssid", "12345"); + verify(mdcMock).put("ccnt", "7"); + + verify(mdcMock).remove("segmentId"); + verify(mdcMock).remove("sessionId"); + verify(mdcMock).remove("ssid"); + verify(mdcMock).remove("ccnt"); verifyNoMoreInteractions(mdcMock); } @@ -86,9 +117,13 @@ void testPxfContextEncodedRequest() throws ServletException, IOException { verify(mdcMock).put("sessionId", "transaction:id:default"); verify(mdcMock).put("segmentId", "5"); + verify(mdcMock).put("ssid", null); + verify(mdcMock).put("ccnt", null); verify(mdcMock).remove("segmentId"); verify(mdcMock).remove("sessionId"); + verify(mdcMock).remove("ssid"); + verify(mdcMock).remove("ccnt"); verifyNoMoreInteractions(mdcMock); } } \ No newline at end of file