Skip to content

fix(tracing): stop 'Unmatched response message' logs for non-stream IO #908

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Nov 9, 2025
Merged

fix(tracing): stop 'Unmatched response message' logs for non-stream IO #908

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
10 changes: 4 additions & 6 deletions ...eclipse.lsp4j.jsonrpc/src/main/java/org/eclipse/lsp4j/jsonrpc/TracingMessageConsumer.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -12,7 +12,6 @@
package org.eclipse.lsp4j.jsonrpc;

import org.eclipse.lsp4j.jsonrpc.json.MessageJsonHandler;
import org.eclipse.lsp4j.jsonrpc.json.StreamMessageConsumer;
import org.eclipse.lsp4j.jsonrpc.messages.Message;
import org.eclipse.lsp4j.jsonrpc.messages.NotificationMessage;
import org.eclipse.lsp4j.jsonrpc.messages.RequestMessage;
Expand Down Expand Up @@ -102,13 +101,12 @@ public void consume(Message message) throws MessageIssueException, JsonRpcExcept
final String date = dateTimeFormatter.format(now);
final String logString;

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

if (logString != null) {
Expand Down
92 changes: 84 additions & 8 deletions ...sp4j.jsonrpc/src/test/java/org/eclipse/lsp4j/jsonrpc/test/TracingMessageConsumerTest.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -11,12 +11,8 @@
******************************************************************************/
package org.eclipse.lsp4j.jsonrpc.test;

import org.eclipse.lsp4j.jsonrpc.*;
import org.eclipse.lsp4j.jsonrpc.TracingMessageConsumer.RequestMetadata;
import org.eclipse.lsp4j.jsonrpc.json.MessageJsonHandler;
import org.eclipse.lsp4j.jsonrpc.json.StreamMessageConsumer;
import org.eclipse.lsp4j.jsonrpc.messages.*;
import org.junit.Test;
import static java.util.Collections.emptyMap;
import static org.junit.Assert.*;

import java.io.ByteArrayOutputStream;
import java.io.File;
Expand All @@ -27,13 +23,27 @@
import java.time.Clock;
import java.time.Instant;
import java.time.ZoneId;
import java.util.ArrayList;
import java.util.HashMap;
import java.util.Locale;
import java.util.Map;
import java.util.concurrent.CompletableFuture;

import static java.util.Collections.emptyMap;
import static org.junit.Assert.assertEquals;
import org.eclipse.lsp4j.jsonrpc.Endpoint;
import org.eclipse.lsp4j.jsonrpc.JsonRpcException;
import org.eclipse.lsp4j.jsonrpc.MessageConsumer;
import org.eclipse.lsp4j.jsonrpc.MessageIssueException;
import org.eclipse.lsp4j.jsonrpc.RemoteEndpoint;
import org.eclipse.lsp4j.jsonrpc.TracingMessageConsumer;
import org.eclipse.lsp4j.jsonrpc.TracingMessageConsumer.RequestMetadata;
import org.eclipse.lsp4j.jsonrpc.json.MessageJsonHandler;
import org.eclipse.lsp4j.jsonrpc.json.StreamMessageConsumer;
import org.eclipse.lsp4j.jsonrpc.messages.Message;
import org.eclipse.lsp4j.jsonrpc.messages.NotificationMessage;
import org.eclipse.lsp4j.jsonrpc.messages.RequestMessage;
import org.eclipse.lsp4j.jsonrpc.messages.ResponseError;
import org.eclipse.lsp4j.jsonrpc.messages.ResponseMessage;
import org.junit.Test;

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

assertEquals(expectedTrace, actualTrace);
}

@Test
public void testNoUnmatchedResponseWhenOutgoingIsNotStreamConsumer() {
// Simulate an outgoing transport that is not StreamMessageConsumer (e.g., websocket)
var outgoingTrace = new StringWriter();
var outgoingPrintWriter = new PrintWriter(outgoingTrace);

var incomingTrace = new StringWriter();
var incomingPrintWriter = new PrintWriter(incomingTrace);

var sentRequests = new HashMap<String, RequestMetadata>();
var receivedRequests = new HashMap<String, RequestMetadata>();

// Pass a non-RemoteEndpoint consumer so TracingMessageConsumer treats messages as outgoing ("Sending")
var outgoingTracing = new TracingMessageConsumer(new EmptyMessageConsumer(), sentRequests, receivedRequests, outgoingPrintWriter, TEST_CLOCK_1, Locale.US);

// Send a request
var req = new RequestMessage();
req.setId("1");
req.setMethod("foo");
outgoingTracing.consume(req);

// Prepare to capture warnings from TracingMessageConsumer
var logger = java.util.logging.Logger.getLogger(TracingMessageConsumer.class.getName());
var warnings = new ArrayList<String>();
var handler = new java.util.logging.Handler() {
@Override
public void publish(java.util.logging.LogRecord record) {
if (record.getLevel() == java.util.logging.Level.WARNING)
warnings.add(record.getMessage());
}

@Override
public void flush() {
}

@Override
public void close() throws SecurityException {
}
};
logger.addHandler(handler);
try {
// Now receive a response on the RemoteEndpoint path. Expected behavior (desired):
// no warnings and a proper response trace even when the outgoing transport
// is not a StreamMessageConsumer (e.g., websockets).
var incomingTracing = new TracingMessageConsumer(TEST_REMOTE_ENDPOINT, sentRequests, receivedRequests, incomingPrintWriter, TEST_CLOCK_2, Locale.US);

var resp = new ResponseMessage();
resp.setId("1");
resp.setResult("ok");
incomingTracing.consume(resp);

// Assert NO warning and a proper trace line for the response
boolean sawUnmatched = warnings.stream().anyMatch(m -> m.contains("Unmatched response message"));
assertFalse("Did not expect unmatched response warning", sawUnmatched);
String expectedTrace = "" +
"[Trace - 06:07:30 PM] Received response 'foo - (1)' in 100ms\n" +
"Result: \"ok\"\n" +
"Error: null\n" +
"\n" +
"\n";
assertEquals(expectedTrace, incomingTrace.toString());
} finally {
logger.removeHandler(handler);
}
}
}

class EmptyRemoteEndpoint extends RemoteEndpoint {
Expand Down
Loading