Skip to content

Commit a055cdb

Browse files
committed
Include review suggestion
- add formatting rules - caution MDC use on thread switch - logging framework information - clarify what "request" means
1 parent 26f37a2 commit a055cdb

File tree

3 files changed

+57
-27
lines changed

3 files changed

+57
-27
lines changed

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

Lines changed: 10 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -23,8 +23,8 @@
2323
@Beta
2424
public class RequestLogContext {
2525

26-
private static void setRequestId(@Nonnull final String requestId) {
27-
MDC.put(MdcKeys.REQUEST_ID, requestId);
26+
private static void setCallId(@Nonnull final String callId) {
27+
MDC.put(MdcKeys.CALL_ID, callId);
2828
}
2929

3030
/**
@@ -65,7 +65,7 @@ public static void setService(@Nonnull final Service service) {
6565

6666
/** Clear all MDC request context information. */
6767
public static void clear() {
68-
MDC.remove(MdcKeys.REQUEST_ID);
68+
MDC.remove(MdcKeys.CALL_ID);
6969
MDC.remove(MdcKeys.ENDPOINT);
7070
MDC.remove(MdcKeys.DESTINATION);
7171
MDC.remove(MdcKeys.MODE);
@@ -74,13 +74,13 @@ public static void clear() {
7474

7575
/** Log the start of a request with generated request ID. */
7676
public static void logRequestStart() {
77-
val reqId = UUID.randomUUID().toString().substring(0, 8);
78-
RequestLogContext.setRequestId(reqId);
77+
val callId = UUID.randomUUID().toString().substring(0, 8);
78+
RequestLogContext.setCallId(callId);
7979

80-
val message = "[reqId={}] Starting {} {} request to {}, destination={}.";
80+
val message = "[callId={}] Starting {} {} request to {}, destination={}.";
8181
log.debug(
8282
message,
83-
reqId,
83+
callId,
8484
MDC.get(MdcKeys.SERVICE),
8585
MDC.get(MdcKeys.MODE),
8686
MDC.get(MdcKeys.ENDPOINT),
@@ -105,13 +105,13 @@ public static void logResponseSuccess(@Nonnull final ClassicHttpResponse respons
105105
.filter(length -> length >= 0)
106106
.map(length -> "%.1fKB".formatted(length / 1024.0))
107107
.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);
108+
val message = "[callId={}] {} request completed successfully with duration={}, size={}.";
109+
log.debug(message, MDC.get(MdcKeys.CALL_ID), MDC.get(MdcKeys.SERVICE), duration, sizeInfo);
110110
}
111111

112112
@UtilityClass
113113
private static class MdcKeys {
114-
private static final String REQUEST_ID = "reqId";
114+
private static final String CALL_ID = "callId";
115115
private static final String ENDPOINT = "endpoint";
116116
private static final String DESTINATION = "destination";
117117
private static final String MODE = "mode";

core/src/test/java/com/sap/ai/sdk/core/common/IterableStreamConverterTest.java

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -106,7 +106,7 @@ void testLinesThrows() {
106106
final var sut = IterableStreamConverter.lines(response, new TestClientExceptionFactory());
107107
assertThatThrownBy(sut::count)
108108
.isInstanceOf(TestClientException.class)
109-
.hasMessage("Parsing response content was interrupted")
109+
.hasMessage("Parsing response content was interrupted.")
110110
.cause()
111111
.isInstanceOf(IOException.class)
112112
.hasMessage("Ups!");

docs/adrs/006-logging-strategy.md

Lines changed: 46 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -21,34 +21,42 @@ Key drivers for this decision include:
2121

2222
We will implement and enforce comprehensive logging guidelines that prioritize **debugging capability** and **user visibility**.
2323
This approach mandates descriptive, human-readable logs with structured request tracking through Mapped Diagnostic Context (MDC).
24+
The SDK uses SLF4J API for all logging statements.
2425

2526
## Guidelines
2627

2728
### 1. Log Content and Security
2829

29-
- **Do not log sensitive information.**
30+
* **Do not log sensitive information.**
3031
Never log full request or response bodies.
3132
Ensure that personally identifiable or confidential data — such as names, IDs, tokens, or payload content — is always excluded from logs.
3233

33-
- **Write concise and relevant logs.**
34+
* **Write concise and relevant logs.**
3435
Every log must convey meaningful information.
3536
Avoid verbose, repetitive, or purely cosmetic details.
3637

37-
- **Use descriptive, human-readable formats.**
38-
Logs must be clear enough for a developer to understand what happened without checking the code.
39-
Use the `metric=value` pattern to include structured details with extensibility in mind.
38+
* **Use descriptive, human-readable and standard formats.**
39+
- Logs must be clear enough for a developer to understand what happened without checking the code.
40+
- Start log messages with a capital letter (exceptions include case-sensitive identifiers) and end with a period (`.`).
41+
- Avoid newlines (`\n`) and emojis within log messages to prevent parsing and encoding concerns.
42+
- Use the `metric=value` pattern to include structured details with extensibility in mind.
4043

41-
```[reqId=e3eaa45c] OpenAI request completed successfully with duration=1628ms, responseSize=1.2KB.```
44+
```
45+
[callId=e3eaa45c] OpenAI request completed successfully with duration=1628ms, responseSize=1.2KB.
46+
```
4247
4348
* **Correlate logs.**
44-
Include a request identifier (e.g., `reqId`) in per-request logs to assist with correlation and debugging.
45-
In this SDK, a "request" represents a single AI service operation (e.g., one chat completion call, one embedding generation).
46-
The `reqId` is generated for each AI service call and is distinct from any HTTP request tracking in user's application framework.
49+
Include a call identifier (e.g., `callId`) in outgoing per-request logs to assist with correlation and debugging.
50+
Throughout this document, the term 'request' refers to a single SDK operation that calls an AI service (e.g., `OrchestrationClient.chatCompletion()`, `OpenAiClient.embed()`), distinct from HTTP requests to the user's application.
4751
4852
* **Exception logging.**
4953
When logging exceptions, use standard logging methods (e.g., `log.error("Operation failed", exception)`) rather than serializing exception objects.
5054
Exception objects may contain custom fields with sensitive data that could be exposed through JSON serialization or custom `toString()` implementations.
5155
56+
* **Logging framework**
57+
Write all logging statements against the SLF4J API.
58+
The AI SDK relies on `logback-classic` as the provided runtime implementation.
59+
5260
---
5361
5462
### 2. Log Levels and Scope
@@ -69,10 +77,12 @@ This approach mandates descriptive, human-readable logs with structured request
6977
Do not rely solely on response-time logging — requests may fail, hang, or take long durations.
7078
This approach also avoids the need for stack-trace investigation when surface error responses are ambiguous.
7179
72-
```[reqId=e3eaa45c] Starting OpenAI synchronous request to /v1/chat/completions, destination=<some-uri>.```
80+
```
81+
[callId=e3eaa45c] Starting OpenAI synchronous request to /v1/chat/completions, destination=<some-uri>.
82+
```
7383
7484
* **Performance-aware logging.**
75-
If a log statement requires any object creation, guard it with a log-level check to prevent performance degradation.
85+
If a log statement requires computation (such as object creation or method invocation), guard it with a log-level check to prevent performance degradation.
7686
7787
``` java
7888
Optional<Destination> maybeDestination;
@@ -84,7 +94,7 @@ This approach mandates descriptive, human-readable logs with structured request
8494
log.debug("Destination: {}", maybeDestination.orElseGet(this::getFallback));
8595
log.debug("Destination: {}", maybeDestination.orElse(getFallback()));
8696
87-
// Good: No object creation or method invocation
97+
// Good: No additional computation
8898
log.debug("Destination: {}", maybeDestination);
8999
log.debug("Destination: {}", maybeDestination.orElse(fallbackDestination));
90100
@@ -103,11 +113,11 @@ This approach mandates descriptive, human-readable logs with structured request
103113
### 3. MDC (Mapped Diagnostic Context)
104114

105115
* **Purpose and usage.**
106-
MDC is used to carry contextual information (e.g., `reqId`, `endpoint`, `service`) across execution blocks within the same thread.
116+
MDC is used to carry contextual information (e.g., `callId`, `endpoint`, `service`) across execution blocks within the same thread.
107117

108118
* **Setting and clearing context.**
109119
Set MDC values deliberately and close to their scope of relevance.
110-
Per-request MDC context must be cleared when the response completes.
120+
Per-request MDC context must be cleared appropriately when the response completes.
111121
Avoid setting per-request values in long-lived objects that outlive the request lifecycle, as this can result in corrupted or incomplete log context.
112122

113123
* **Centralized MDC management.**
@@ -124,7 +134,7 @@ This approach mandates descriptive, human-readable logs with structured request
124134
```
125135

126136
* **Granular clearing only.**
127-
Never clear the entire MDC context.
137+
Never clear the entire MDC context, as this will remove entries set by the application developer or other libraries.
128138
Instead, remove entries key-by-key to preserve unrelated context items that may remain valid for longer periods.
129139
```java
130140
// Bad: Risk clearing useful context entries from other components
@@ -134,7 +144,7 @@ This approach mandates descriptive, human-readable logs with structured request
134144
class RequestLogContext {
135145
//...
136146
static void clear(){
137-
MDC.remove(MdcKeys.REQUEST_ID);
147+
MDC.remove(MdcKeys.CALL_ID);
138148
MDC.remove(MdcKeys.SERVICE);
139149
}
140150
}
@@ -144,6 +154,26 @@ This approach mandates descriptive, human-readable logs with structured request
144154
The component or class that sets MDC context values is also responsible for clearing them.
145155
This maintains clarity and ensures proper lifecycle management.
146156

157+
* **Safe consumption.**
158+
Since MDC uses `ThreadLocal` storage, any new thread (created implicitly or explicitly) will not have access to the parent thread's MDC context.
159+
Always audit for possible thread switches that may lead to corrupted logs due to invalid MDC.
160+
Below is an example contrasting safe usage (logging in the calling thread) with unsafe usage (logging in callbacks):
161+
162+
```java
163+
// Thread A
164+
RequestLogContext.setCallId("abc123");
165+
log.debug("[callId={}] Starting request", RequestLogContext.get(MdcKeys.CALL_ID));
166+
167+
// Bad: Logging within callbacks executed in other threads
168+
client.executeAsync(() -> {
169+
// Thread B: RequestLogContext.get(MdcKeys.CALL_ID) is null
170+
log.debug("[callId={}] Processing", RequestLogContext.get(MdcKeys.CALL_ID));
171+
});
172+
173+
// Good: Thread A's context has been restored
174+
log.debug("[callId={}] Completed request", RequestLogContext.get(MdcKeys.CALL_ID));
175+
```
176+
147177
---
148178

149179
### 4. Logging Boundaries and Generation

0 commit comments

Comments
 (0)