Skip to content

Commit cb8fa3d

Browse files
ostinruostinru
authored
Observability: Add gp_session_id and gp_command_count to MDC (#111) (#58)
* Observability: Add gp_session_id and gp_command_count to MDC * review: add new parameters to log4j2
1 parent 559808d commit cb8fa3d

3 files changed

Lines changed: 55 additions & 3 deletions

File tree

‎server/pxf-service/src/main/java/org/greenplum/pxf/service/spring/PxfContextMdcLogEnhancerFilter.java‎

Lines changed: 19 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -21,8 +21,17 @@
2121
@Component
2222
public class PxfContextMdcLogEnhancerFilter extends OncePerRequestFilter {
2323

24+
// sessionId: composite PXF request identifier formed as "<X-GP-XID>:<X-GP-OPTIONS-SERVER>",
25+
// where XID is the Greenplum transaction id and the server name defaults to "default".
26+
// Groups all log records produced while serving a single PXF request.
2427
private static final String MDC_SESSION_ID = "sessionId";
28+
// segmentId: the Greenplum segment id (X-GP-SEGMENT-ID) that issued the PXF request.
2529
private static final String MDC_SEGMENT_ID = "segmentId";
30+
// ssid: query session identifier from pg_stat_activity system view.
31+
private static final String MDC_SSID = "ssid";
32+
// ccnt: the command number within this session as shown by gp_command_count.
33+
// All records associated with the query will have the same ccnt.
34+
private static final String MDC_CCNT = "ccnt";
2635

2736
private final HttpHeaderDecoder decoder;
2837

@@ -60,10 +69,16 @@ private void insertIntoMDC(HttpServletRequest request) {
6069
String serverName = StringUtils.defaultIfBlank(decoder.getHeaderValue("X-GP-OPTIONS-SERVER", request, encoded), "default");
6170
String sessionId = String.format("%s:%s", xid, serverName);
6271
String segmentId = decoder.getHeaderValue("X-GP-SEGMENT-ID", request, encoded);
72+
String gpSessionId = decoder.getHeaderValue("X-GP-SESSION-ID", request, encoded);
73+
String gpCommandCount = decoder.getHeaderValue("X-GP-COMMAND-COUNT", request, encoded);
6374
MDC.put(MDC_SESSION_ID, sessionId);
6475
MDC.put(MDC_SEGMENT_ID, segmentId);
65-
log.debug("MDC: Added {}={}", MDC_SESSION_ID, sessionId);
66-
log.debug("MDC: Added {}={}", MDC_SEGMENT_ID, segmentId);
76+
MDC.put(MDC_SSID, gpSessionId);
77+
MDC.put(MDC_CCNT, gpCommandCount);
78+
log.trace("MDC: Added {}={}", MDC_SESSION_ID, sessionId);
79+
log.trace("MDC: Added {}={}", MDC_SEGMENT_ID, segmentId);
80+
log.trace("MDC: Added {}={}", MDC_SSID, gpSessionId);
81+
log.trace("MDC: Added {}={}", MDC_CCNT, gpCommandCount);
6782
}
6883

6984
/**
@@ -73,5 +88,7 @@ private void clearMDC() {
7388
// removing possibly non-existent item is OK
7489
MDC.remove(MDC_SEGMENT_ID);
7590
MDC.remove(MDC_SESSION_ID);
91+
MDC.remove(MDC_SSID);
92+
MDC.remove(MDC_CCNT);
7693
}
7794
}

‎server/pxf-service/src/templates/conf/pxf-log4j2.xml‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
<Configuration status="WARN">
33
<Properties>
44
<Property name="LOG_EXCEPTION_CONVERSION_WORD">%xwEx</Property>
5-
<Property name="LOG_LEVEL_PATTERN">%5p [%X{sessionId}:%-3X{segmentId}]</Property>
5+
<Property name="LOG_LEVEL_PATTERN">%5p [%X{sessionId}:%-3X{segmentId}][ssid=%X{ssid},ccnt=%X{ccnt}]</Property>
66
<Property name="LOG_DATEFORMAT_PATTERN">yyyy-MM-dd HH:mm:ss.SSS zzz</Property>
77
<Property name="CONSOLE_LOG_PATTERN">%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}</Property>
88
<Property name="FILE_LOG_PATTERN">%d{${LOG_DATEFORMAT_PATTERN}} ${LOG_LEVEL_PATTERN} %pid --- [%-9.10t] %-40.40c{1.} : %m%n${sys:LOG_EXCEPTION_CONVERSION_WORD}</Property>

‎server/pxf-service/src/test/java/org/greenplum/pxf/service/spring/PxfContextMdcLogEnhancerFilterTest.java‎

Lines changed: 35 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -42,6 +42,8 @@ void testNonPxfContextRequest() throws ServletException, IOException {
4242
// always removes
4343
verify(mdcMock).remove("segmentId");
4444
verify(mdcMock).remove("sessionId");
45+
verify(mdcMock).remove("ssid");
46+
verify(mdcMock).remove("ccnt");
4547
verifyNoMoreInteractions(mdcMock);
4648
}
4749

@@ -54,9 +56,13 @@ void testPxfContextRequest() throws ServletException, IOException {
5456

5557
verify(mdcMock).put("sessionId", "transaction:id:default");
5658
verify(mdcMock).put("segmentId", "5");
59+
verify(mdcMock).put("ssid", null);
60+
verify(mdcMock).put("ccnt", null);
5761

5862
verify(mdcMock).remove("segmentId");
5963
verify(mdcMock).remove("sessionId");
64+
verify(mdcMock).remove("ssid");
65+
verify(mdcMock).remove("ccnt");
6066
verifyNoMoreInteractions(mdcMock);
6167
}
6268

@@ -70,9 +76,34 @@ void testPxfContextRequestWithServerName() throws ServletException, IOException
7076

7177
verify(mdcMock).put("sessionId", "transaction:id:s3");
7278
verify(mdcMock).put("segmentId", "5");
79+
verify(mdcMock).put("ssid", null);
80+
verify(mdcMock).put("ccnt", null);
7381

7482
verify(mdcMock).remove("segmentId");
7583
verify(mdcMock).remove("sessionId");
84+
verify(mdcMock).remove("ssid");
85+
verify(mdcMock).remove("ccnt");
86+
verifyNoMoreInteractions(mdcMock);
87+
}
88+
89+
@Test
90+
void testPxfContextRequestWithGpSessionId() throws ServletException, IOException {
91+
92+
mockRequest.addHeader("X-GP-XID", "transaction:id");
93+
mockRequest.addHeader("X-GP-SEGMENT-ID", "5");
94+
mockRequest.addHeader("X-GP-SESSION-ID", "12345");
95+
mockRequest.addHeader("X-GP-COMMAND-COUNT", "7");
96+
filter.doFilter(mockRequest, mockResponse, mockFilterChain);
97+
98+
verify(mdcMock).put("sessionId", "transaction:id:default");
99+
verify(mdcMock).put("segmentId", "5");
100+
verify(mdcMock).put("ssid", "12345");
101+
verify(mdcMock).put("ccnt", "7");
102+
103+
verify(mdcMock).remove("segmentId");
104+
verify(mdcMock).remove("sessionId");
105+
verify(mdcMock).remove("ssid");
106+
verify(mdcMock).remove("ccnt");
76107
verifyNoMoreInteractions(mdcMock);
77108
}
78109

@@ -86,9 +117,13 @@ void testPxfContextEncodedRequest() throws ServletException, IOException {
86117

87118
verify(mdcMock).put("sessionId", "transaction:id:default");
88119
verify(mdcMock).put("segmentId", "5");
120+
verify(mdcMock).put("ssid", null);
121+
verify(mdcMock).put("ccnt", null);
89122

90123
verify(mdcMock).remove("segmentId");
91124
verify(mdcMock).remove("sessionId");
125+
verify(mdcMock).remove("ssid");
126+
verify(mdcMock).remove("ccnt");
92127
verifyNoMoreInteractions(mdcMock);
93128
}
94129
}

0 commit comments

Comments
 (0)