Skip to content

Commit 955b3e0

Browse files
rpanackaln-o-u-r-h-a-nCharlesDuboisSAPnewtorkbot-sdk-js
authored
refactor: [DevOps] Improve MDC handling across multiple modules (#645)
* Reducing service key logs to minimum. * Some formatting * Custom Info Logs per LLM call * Formatting the ClientResponseHandler.java class. * Removing unused dependency from grounding pom * Added Implicit Tool Calls Logging * Added LLM Calls Logging * Some Formatting * Some Formatting * Some Formatting * Some Formatting * formatting * Updating Pom Dependencies * service bindings static * fix tests * Added useful debug log but as an info one as log.debug() does not show/appear in terminal for some reason. * logback config file * Per request logging update * Review suggestion * fix minor * Update foundation-models/openai/src/main/java/com/sap/ai/sdk/foundationmodels/openai/OpenAiChatCompletionResponse.java * Formatting * Minor format * Minor format * Fix PMD * Centralize MDC management * Add review suggestions * Apply additional review suggestion --------- Co-authored-by: Nourhan Shata <nourhan.islam10f@gmail.com> Co-authored-by: I538344 <charles.dubois@sap.com> Co-authored-by: Alexander Dümont <22489773+newtork@users.noreply.github.com> Co-authored-by: SAP Cloud SDK Bot <cloudsdk@sap.com> Co-authored-by: Alexander Dümont <alexander.duemont@gmail.com>
1 parent 6e293fe commit 955b3e0

File tree

5 files changed

+210
-59
lines changed

5 files changed

+210
-59
lines changed

‎core/src/main/java/com/sap/ai/sdk/core/common/ClientResponseHandler.java‎

Lines changed: 1 addition & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -18,7 +18,6 @@
1818
import org.apache.hc.core5.http.HttpEntity;
1919
import org.apache.hc.core5.http.io.HttpClientResponseHandler;
2020
import org.apache.hc.core5.http.io.entity.EntityUtils;
21-
import org.slf4j.MDC;
2221

2322
/**
2423
* Parse incoming JSON responses and handles any errors. For internal use only.
@@ -87,7 +86,7 @@ private T parseSuccess(@Nonnull final ClassicHttpResponse response) throws E {
8786
val content =
8887
tryGetContent(responseEntity)
8988
.getOrElseThrow(e -> exceptionFactory.build(message, e).setHttpResponse(response));
90-
logResponseSuccess(response);
89+
RequestLogContext.logResponseSuccess(response);
9190

9291
try {
9392
return objectMapper.readValue(content, successType);
@@ -172,16 +171,4 @@ private static String getErrorMessage(
172171
val message = Optional.ofNullable(additionalMessage).orElse("");
173172
return message.isEmpty() ? baseErrorMessage : "%s: %s".formatted(baseErrorMessage, message);
174173
}
175-
176-
private static void logResponseSuccess(final @Nonnull ClassicHttpResponse response) {
177-
if (!log.isDebugEnabled()) {
178-
return;
179-
}
180-
val headerTime = Optional.ofNullable(response.getFirstHeader("x-upstream-service-time"));
181-
val duration = headerTime.map(h -> h.getValue() + "ms").orElseGet(() -> "unknown");
182-
val entityLength = response.getEntity().getContentLength();
183-
val sizeInfo = entityLength >= 0 ? String.format("%.1fKB", entityLength / 1024.0) : "unknown";
184-
val msg = "[reqId={}] {} request completed successfully with duration={}, size={}.";
185-
log.debug(msg, MDC.get("reqId"), MDC.get("service"), duration, sizeInfo);
186-
}
187174
}

‎core/src/main/java/com/sap/ai/sdk/core/common/RequestLogContext.java‎

Lines changed: 140 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,140 @@
1+
package com.sap.ai.sdk.core.common;
2+
3+
import com.google.common.annotations.Beta;
4+
import java.util.Optional;
5+
import java.util.UUID;
6+
import javax.annotation.Nonnull;
7+
import lombok.Getter;
8+
import lombok.RequiredArgsConstructor;
9+
import lombok.experimental.UtilityClass;
10+
import lombok.extern.slf4j.Slf4j;
11+
import lombok.val;
12+
import org.apache.hc.core5.http.ClassicHttpResponse;
13+
import org.apache.hc.core5.http.HttpEntity;
14+
import org.slf4j.MDC;
15+
16+
/**
17+
* Utility for managing MDC (Mapped Diagnostic Context) for logging of AI Core requests.
18+
*
19+
* <p>This class is intended for internal use only.
20+
*/
21+
@Slf4j
22+
@UtilityClass
23+
@Beta
24+
public class RequestLogContext {
25+
26+
private static void setRequestId(@Nonnull final String requestId) {
27+
MDC.put(MdcKeys.REQUEST_ID, requestId);
28+
}
29+
30+
/**
31+
* Set the endpoint for the current request context.
32+
*
33+
* @param endpoint the endpoint URL
34+
*/
35+
public static void setEndpoint(@Nonnull final String endpoint) {
36+
MDC.put(MdcKeys.ENDPOINT, endpoint);
37+
}
38+
39+
/**
40+
* Set the destination for the current request context.
41+
*
42+
* @param destination the destination name
43+
*/
44+
public static void setDestination(@Nonnull final String destination) {
45+
MDC.put(MdcKeys.DESTINATION, destination);
46+
}
47+
48+
/**
49+
* Set the mode for the current request context.
50+
*
51+
* @param mode the request mode
52+
*/
53+
public static void setMode(@Nonnull final Mode mode) {
54+
MDC.put(MdcKeys.MODE, mode.getValue());
55+
}
56+
57+
/**
58+
* Set the service for the current request context.
59+
*
60+
* @param service the service type
61+
*/
62+
public static void setService(@Nonnull final Service service) {
63+
MDC.put(MdcKeys.SERVICE, service.getValue());
64+
}
65+
66+
/** Clear all MDC request context information. */
67+
public static void clear() {
68+
MDC.remove(MdcKeys.REQUEST_ID);
69+
MDC.remove(MdcKeys.ENDPOINT);
70+
MDC.remove(MdcKeys.DESTINATION);
71+
MDC.remove(MdcKeys.MODE);
72+
MDC.remove(MdcKeys.SERVICE);
73+
}
74+
75+
/** Log the start of a request with generated request ID. */
76+
public static void logRequestStart() {
77+
val reqId = UUID.randomUUID().toString().substring(0, 8);
78+
RequestLogContext.setRequestId(reqId);
79+
80+
val message = "[reqId={}] Starting {} {} request to {}, destination={}";
81+
log.debug(
82+
message,
83+
reqId,
84+
MDC.get(MdcKeys.SERVICE),
85+
MDC.get(MdcKeys.MODE),
86+
MDC.get(MdcKeys.ENDPOINT),
87+
MDC.get(MdcKeys.DESTINATION));
88+
}
89+
90+
/**
91+
* Log successful response with duration and size information.
92+
*
93+
* @param response the HTTP response
94+
*/
95+
public static void logResponseSuccess(@Nonnull final ClassicHttpResponse response) {
96+
if (!log.isDebugEnabled()) {
97+
return;
98+
}
99+
100+
val headerTime = Optional.ofNullable(response.getFirstHeader("x-upstream-service-time"));
101+
val duration = headerTime.map(h -> h.getValue() + "ms").orElse("unknown");
102+
val sizeInfo =
103+
Optional.ofNullable(response.getEntity())
104+
.map(HttpEntity::getContentLength)
105+
.filter(length -> length >= 0)
106+
.map(length -> "%.1fKB".formatted(length / 1024.0))
107+
.orElse("unknown");
108+
val message = "[reqId={}] {} request completed successfully with duration={}, size={}.";
109+
log.debug(message, MDC.get(MdcKeys.REQUEST_ID), MDC.get(MdcKeys.SERVICE), duration, sizeInfo);
110+
}
111+
112+
@UtilityClass
113+
private static class MdcKeys {
114+
private static final String REQUEST_ID = "reqId";
115+
private static final String ENDPOINT = "endpoint";
116+
private static final String DESTINATION = "destination";
117+
private static final String MODE = "mode";
118+
private static final String SERVICE = "service";
119+
}
120+
121+
/** Request execution modes. */
122+
@RequiredArgsConstructor
123+
public enum Mode {
124+
/** Synchronous request mode */
125+
SYNCHRONOUS("synchronous"),
126+
/** Streaming request mode */
127+
STREAMING("streaming");
128+
@Getter private final String value;
129+
}
130+
131+
/** AI service types. */
132+
@RequiredArgsConstructor
133+
public enum Service {
134+
/** OpenAI service */
135+
OPENAI("OpenAI"),
136+
/** Orchestration service */
137+
ORCHESTRATION("Orchestration");
138+
@Getter private final String value;
139+
}
140+
}

‎core/src/test/java/com/sap/ai/sdk/core/common/RequestLogContextTest.java‎

Lines changed: 38 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,38 @@
1+
package com.sap.ai.sdk.core.common;
2+
3+
import static com.sap.ai.sdk.core.common.RequestLogContext.Mode.STREAMING;
4+
import static com.sap.ai.sdk.core.common.RequestLogContext.Service.OPENAI;
5+
import static org.assertj.core.api.Assertions.assertThat;
6+
7+
import org.junit.jupiter.api.Test;
8+
import org.slf4j.MDC;
9+
10+
class RequestLogContextTest {
11+
12+
@Test
13+
void testRequestLogContextLifecycle() {
14+
// Setup customer MDC entries (to test clear() safety)
15+
MDC.put("consumer-key", "consumer-value");
16+
17+
RequestLogContext.setService(OPENAI);
18+
RequestLogContext.setMode(STREAMING);
19+
RequestLogContext.setEndpoint("/api/endpoint");
20+
RequestLogContext.setDestination("http://localhost:8000");
21+
22+
assertThat(MDC.get("service")).isEqualTo("OpenAI");
23+
assertThat(MDC.get("mode")).isEqualTo("streaming");
24+
assertThat(MDC.get("endpoint")).isEqualTo("/api/endpoint");
25+
assertThat(MDC.get("destination")).isEqualTo("http://localhost:8000");
26+
27+
RequestLogContext.logRequestStart();
28+
assertThat(MDC.get("reqId")).isNotNull().hasSize(8);
29+
30+
RequestLogContext.clear();
31+
assertThat(MDC.get("service")).isNull();
32+
assertThat(MDC.get("mode")).isNull();
33+
assertThat(MDC.get("endpoint")).isNull();
34+
assertThat(MDC.get("destination")).isNull();
35+
assertThat(MDC.get("reqId")).isNull();
36+
assertThat(MDC.get("consumer-key")).isEqualTo("consumer-value");
37+
}
38+
}

‎foundation-models/openai/src/main/java/com/sap/ai/sdk/foundationmodels/openai/OpenAiClient.java‎

Lines changed: 16 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,8 @@
11
package com.sap.ai.sdk.foundationmodels.openai;
22

3+
import static com.sap.ai.sdk.core.common.RequestLogContext.Mode.STREAMING;
4+
import static com.sap.ai.sdk.core.common.RequestLogContext.Mode.SYNCHRONOUS;
5+
import static com.sap.ai.sdk.core.common.RequestLogContext.Service.OPENAI;
36
import static com.sap.ai.sdk.foundationmodels.openai.OpenAiClientException.FACTORY;
47
import static com.sap.ai.sdk.foundationmodels.openai.OpenAiUtils.getOpenAiObjectMapper;
58

@@ -10,6 +13,7 @@
1013
import com.sap.ai.sdk.core.DeploymentResolutionException;
1114
import com.sap.ai.sdk.core.common.ClientResponseHandler;
1215
import com.sap.ai.sdk.core.common.ClientStreamingHandler;
16+
import com.sap.ai.sdk.core.common.RequestLogContext;
1317
import com.sap.ai.sdk.core.common.StreamedDelta;
1418
import com.sap.ai.sdk.foundationmodels.openai.generated.model.ChatCompletionStreamOptions;
1519
import com.sap.ai.sdk.foundationmodels.openai.generated.model.CreateChatCompletionRequest;
@@ -30,19 +34,16 @@
3034
import java.io.IOException;
3135
import java.util.ArrayList;
3236
import java.util.List;
33-
import java.util.UUID;
3437
import java.util.stream.Stream;
3538
import javax.annotation.Nonnull;
3639
import javax.annotation.Nullable;
3740
import lombok.AccessLevel;
3841
import lombok.RequiredArgsConstructor;
3942
import lombok.extern.slf4j.Slf4j;
40-
import lombok.val;
4143
import org.apache.hc.client5.http.classic.methods.HttpPost;
4244
import org.apache.hc.core5.http.ContentType;
4345
import org.apache.hc.core5.http.io.entity.StringEntity;
4446
import org.apache.hc.core5.http.message.BasicClassicHttpRequest;
45-
import org.slf4j.MDC;
4647

4748
/** Client for interacting with OpenAI models. */
4849
@Slf4j
@@ -420,7 +421,7 @@ private <T> T execute(
420421
@Nonnull final Class<T> responseType) {
421422
final var request = new HttpPost(path);
422423
serializeAndSetHttpEntity(request, payload, this.customHeaders);
423-
MDC.put("endpoint", path);
424+
RequestLogContext.setEndpoint(path);
424425
return executeRequest(request, responseType);
425426
}
426427

@@ -431,7 +432,7 @@ private <D extends StreamedDelta> Stream<D> executeStream(
431432
@Nonnull final Class<D> deltaType) {
432433
final var request = new HttpPost(path);
433434
serializeAndSetHttpEntity(request, payload, this.customHeaders);
434-
MDC.put("endpoint", path);
435+
RequestLogContext.setEndpoint(path);
435436
return streamRequest(request, deltaType);
436437
}
437438

@@ -454,15 +455,16 @@ private <T> T executeRequest(
454455
final BasicClassicHttpRequest request, @Nonnull final Class<T> responseType) {
455456
try {
456457
final var client = ApacheHttpClient5Accessor.getHttpClient(destination);
457-
MDC.put("destination", ((HttpDestination) destination).getUri().toASCIIString());
458-
MDC.put("mode", "synchronous");
459-
logRequestStart();
458+
RequestLogContext.setDestination(destination.asHttp().getUri().toString());
459+
RequestLogContext.setMode(SYNCHRONOUS);
460+
RequestLogContext.setService(OPENAI);
461+
RequestLogContext.logRequestStart();
460462
return client.execute(
461463
request, new ClientResponseHandler<>(responseType, OpenAiError.class, FACTORY));
462464
} catch (final IOException e) {
463465
throw new OpenAiClientException("Request to OpenAI model failed", e).setHttpRequest(request);
464466
} finally {
465-
MDC.clear();
467+
RequestLogContext.clear();
466468
}
467469
}
468470

@@ -471,28 +473,17 @@ private <D extends StreamedDelta> Stream<D> streamRequest(
471473
final BasicClassicHttpRequest request, @Nonnull final Class<D> deltaType) {
472474
try {
473475
final var client = ApacheHttpClient5Accessor.getHttpClient(destination);
474-
MDC.put("destination", ((HttpDestination) destination).getUri().toASCIIString());
475-
MDC.put("mode", "streaming");
476-
logRequestStart();
476+
RequestLogContext.setDestination(destination.asHttp().getUri().toString());
477+
RequestLogContext.setMode(STREAMING);
478+
RequestLogContext.setService(OPENAI);
479+
RequestLogContext.logRequestStart();
477480
return new ClientStreamingHandler<>(deltaType, OpenAiError.class, FACTORY)
478481
.objectMapper(JACKSON)
479482
.handleStreamingResponse(client.executeOpen(null, request, null));
480483
} catch (final IOException e) {
481484
throw new OpenAiClientException("Request to OpenAI model failed", e).setHttpRequest(request);
482485
} finally {
483-
MDC.clear();
486+
RequestLogContext.clear();
484487
}
485488
}
486-
487-
private static void logRequestStart() {
488-
val reqId = UUID.randomUUID().toString().substring(0, 8);
489-
MDC.put("reqId", reqId);
490-
MDC.put("service", "OpenAI");
491-
log.debug(
492-
"[reqId={}] Starting OpenAI {} request to {}, destination={}",
493-
reqId,
494-
MDC.get("mode"),
495-
MDC.get("endpoint"),
496-
MDC.get("destination"));
497-
}
498489
}

0 commit comments

Comments
 (0)