Skip to content

Commit 978b324

Browse files
sebthomsebthom
authored
fix(tracing): stop 'Unmatched response message' logs for non-stream IO (#908)
Fixes #593. - Previously only StreamMessageConsumer was treated as "sending". With WebSocket and other non-stream transports, sentRequests stayed empty, so every incoming response looked unmatched, emitted a warning, and produced no trace. - Now any consumer that is not a RemoteEndpoint is treated as "sending", ensuring sentRequests is populated regardless of transport and responses are matched correctly. - Removed the "Unknown MessageConsumer type" branch to avoid misclassification and improve compatibility with custom/non-stream transports.
1 parent 4b6d14b commit 978b324

File tree

2 files changed

+88
-14
lines changed

2 files changed

+88
-14
lines changed

‎org.eclipse.lsp4j.jsonrpc/src/main/java/org/eclipse/lsp4j/jsonrpc/TracingMessageConsumer.java‎

Lines changed: 4 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,6 @@
1212
package org.eclipse.lsp4j.jsonrpc;
1313

1414
import org.eclipse.lsp4j.jsonrpc.json.MessageJsonHandler;
15-
import org.eclipse.lsp4j.jsonrpc.json.StreamMessageConsumer;
1615
import org.eclipse.lsp4j.jsonrpc.messages.Message;
1716
import org.eclipse.lsp4j.jsonrpc.messages.NotificationMessage;
1817
import org.eclipse.lsp4j.jsonrpc.messages.RequestMessage;
@@ -102,13 +101,12 @@ public void consume(Message message) throws MessageIssueException, JsonRpcExcept
102101
final String date = dateTimeFormatter.format(now);
103102
final String logString;
104103

105-
if (messageConsumer instanceof StreamMessageConsumer) {
106-
logString = consumeMessageSending(message, now, date);
107-
} else if (messageConsumer instanceof RemoteEndpoint) {
104+
if (messageConsumer instanceof RemoteEndpoint) {
108105
logString = consumeMessageReceiving(message, now, date);
109106
} else {
110-
LOG.log(WARNING, String.format("Unknown MessageConsumer type: %s", messageConsumer));
111-
logString = null;
107+
// Treat any non-RemoteEndpoint consumer as an outgoing transport (sending),
108+
// so tracing works for WebSocket and other non-stream consumers as well.
109+
logString = consumeMessageSending(message, now, date);
112110
}
113111

114112
if (logString != null) {

‎org.eclipse.lsp4j.jsonrpc/src/test/java/org/eclipse/lsp4j/jsonrpc/test/TracingMessageConsumerTest.java‎

Lines changed: 84 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -11,12 +11,8 @@
1111
******************************************************************************/
1212
package org.eclipse.lsp4j.jsonrpc.test;
1313

14-
import org.eclipse.lsp4j.jsonrpc.*;
15-
import org.eclipse.lsp4j.jsonrpc.TracingMessageConsumer.RequestMetadata;
16-
import org.eclipse.lsp4j.jsonrpc.json.MessageJsonHandler;
17-
import org.eclipse.lsp4j.jsonrpc.json.StreamMessageConsumer;
18-
import org.eclipse.lsp4j.jsonrpc.messages.*;
19-
import org.junit.Test;
14+
import static java.util.Collections.emptyMap;
15+
import static org.junit.Assert.*;
2016

2117
import java.io.ByteArrayOutputStream;
2218
import java.io.File;
@@ -27,13 +23,27 @@
2723
import java.time.Clock;
2824
import java.time.Instant;
2925
import java.time.ZoneId;
26+
import java.util.ArrayList;
3027
import java.util.HashMap;
3128
import java.util.Locale;
3229
import java.util.Map;
3330
import java.util.concurrent.CompletableFuture;
3431

35-
import static java.util.Collections.emptyMap;
36-
import static org.junit.Assert.assertEquals;
32+
import org.eclipse.lsp4j.jsonrpc.Endpoint;
33+
import org.eclipse.lsp4j.jsonrpc.JsonRpcException;
34+
import org.eclipse.lsp4j.jsonrpc.MessageConsumer;
35+
import org.eclipse.lsp4j.jsonrpc.MessageIssueException;
36+
import org.eclipse.lsp4j.jsonrpc.RemoteEndpoint;
37+
import org.eclipse.lsp4j.jsonrpc.TracingMessageConsumer;
38+
import org.eclipse.lsp4j.jsonrpc.TracingMessageConsumer.RequestMetadata;
39+
import org.eclipse.lsp4j.jsonrpc.json.MessageJsonHandler;
40+
import org.eclipse.lsp4j.jsonrpc.json.StreamMessageConsumer;
41+
import org.eclipse.lsp4j.jsonrpc.messages.Message;
42+
import org.eclipse.lsp4j.jsonrpc.messages.NotificationMessage;
43+
import org.eclipse.lsp4j.jsonrpc.messages.RequestMessage;
44+
import org.eclipse.lsp4j.jsonrpc.messages.ResponseError;
45+
import org.eclipse.lsp4j.jsonrpc.messages.ResponseMessage;
46+
import org.junit.Test;
3747

3848
public class TracingMessageConsumerTest {
3949
private static final RemoteEndpoint TEST_REMOTE_ENDPOINT = new EmptyRemoteEndpoint();
@@ -299,6 +309,72 @@ public void testSendingNotificationWithCustomAdapter() {
299309

300310
assertEquals(expectedTrace, actualTrace);
301311
}
312+
313+
@Test
314+
public void testNoUnmatchedResponseWhenOutgoingIsNotStreamConsumer() {
315+
// Simulate an outgoing transport that is not StreamMessageConsumer (e.g., websocket)
316+
var outgoingTrace = new StringWriter();
317+
var outgoingPrintWriter = new PrintWriter(outgoingTrace);
318+
319+
var incomingTrace = new StringWriter();
320+
var incomingPrintWriter = new PrintWriter(incomingTrace);
321+
322+
var sentRequests = new HashMap<String, RequestMetadata>();
323+
var receivedRequests = new HashMap<String, RequestMetadata>();
324+
325+
// Pass a non-RemoteEndpoint consumer so TracingMessageConsumer treats messages as outgoing ("Sending")
326+
var outgoingTracing = new TracingMessageConsumer(new EmptyMessageConsumer(), sentRequests, receivedRequests, outgoingPrintWriter, TEST_CLOCK_1, Locale.US);
327+
328+
// Send a request
329+
var req = new RequestMessage();
330+
req.setId("1");
331+
req.setMethod("foo");
332+
outgoingTracing.consume(req);
333+
334+
// Prepare to capture warnings from TracingMessageConsumer
335+
var logger = java.util.logging.Logger.getLogger(TracingMessageConsumer.class.getName());
336+
var warnings = new ArrayList<String>();
337+
var handler = new java.util.logging.Handler() {
338+
@Override
339+
public void publish(java.util.logging.LogRecord record) {
340+
if (record.getLevel() == java.util.logging.Level.WARNING)
341+
warnings.add(record.getMessage());
342+
}
343+
344+
@Override
345+
public void flush() {
346+
}
347+
348+
@Override
349+
public void close() throws SecurityException {
350+
}
351+
};
352+
logger.addHandler(handler);
353+
try {
354+
// Now receive a response on the RemoteEndpoint path. Expected behavior (desired):
355+
// no warnings and a proper response trace even when the outgoing transport
356+
// is not a StreamMessageConsumer (e.g., websockets).
357+
var incomingTracing = new TracingMessageConsumer(TEST_REMOTE_ENDPOINT, sentRequests, receivedRequests, incomingPrintWriter, TEST_CLOCK_2, Locale.US);
358+
359+
var resp = new ResponseMessage();
360+
resp.setId("1");
361+
resp.setResult("ok");
362+
incomingTracing.consume(resp);
363+
364+
// Assert NO warning and a proper trace line for the response
365+
boolean sawUnmatched = warnings.stream().anyMatch(m -> m.contains("Unmatched response message"));
366+
assertFalse("Did not expect unmatched response warning", sawUnmatched);
367+
String expectedTrace = "" +
368+
"[Trace - 06:07:30 PM] Received response 'foo - (1)' in 100ms\n" +
369+
"Result: \"ok\"\n" +
370+
"Error: null\n" +
371+
"\n" +
372+
"\n";
373+
assertEquals(expectedTrace, incomingTrace.toString());
374+
} finally {
375+
logger.removeHandler(handler);
376+
}
377+
}
302378
}
303379

304380
class EmptyRemoteEndpoint extends RemoteEndpoint {

0 commit comments

Comments
 (0)