|
| 1 | +package community.solace.spring.cloud.requestreply.service; |
| 2 | + |
| 3 | +import java.time.Duration; |
| 4 | +import java.util.List; |
| 5 | +import java.util.concurrent.CompletableFuture; |
| 6 | +import java.util.concurrent.CountDownLatch; |
| 7 | +import java.util.concurrent.CopyOnWriteArrayList; |
| 8 | +import java.util.concurrent.TimeUnit; |
| 9 | +import java.util.concurrent.TimeoutException; |
| 10 | +import java.util.concurrent.atomic.AtomicReference; |
| 11 | + |
| 12 | +import community.solace.spring.cloud.requestreply.AbstractRequestReplySimpleIT; |
| 13 | +import community.solace.spring.cloud.requestreply.model.SensorReading; |
| 14 | +import community.solace.spring.cloud.requestreply.service.header.parser.errormessage.RemoteErrorException; |
| 15 | +import io.micrometer.context.ContextRegistry; |
| 16 | +import io.micrometer.context.integration.Slf4jThreadLocalAccessor; |
| 17 | +import org.junit.jupiter.api.AfterAll; |
| 18 | +import org.junit.jupiter.api.AfterEach; |
| 19 | +import org.junit.jupiter.api.BeforeAll; |
| 20 | +import org.junit.jupiter.api.BeforeEach; |
| 21 | +import org.junit.jupiter.api.Test; |
| 22 | +import org.mockito.Mockito; |
| 23 | +import org.slf4j.MDC; |
| 24 | + |
| 25 | +import org.springframework.beans.factory.annotation.Autowired; |
| 26 | +import org.springframework.cloud.stream.function.StreamBridge; |
| 27 | +import org.springframework.messaging.Message; |
| 28 | +import org.springframework.messaging.support.MessageBuilder; |
| 29 | +import org.springframework.test.context.bean.override.mockito.MockitoBean; |
| 30 | + |
| 31 | +import static org.awaitility.Awaitility.await; |
| 32 | +import static org.hamcrest.Matchers.equalTo; |
| 33 | +import static org.hamcrest.Matchers.greaterThanOrEqualTo; |
| 34 | +import static org.junit.jupiter.api.Assertions.assertEquals; |
| 35 | +import static org.junit.jupiter.api.Assertions.assertNotEquals; |
| 36 | +import static org.junit.jupiter.api.Assertions.assertNull; |
| 37 | +import static org.junit.jupiter.api.Assertions.assertThrows; |
| 38 | +import static org.junit.jupiter.api.Assertions.assertTrue; |
| 39 | +import static org.mockito.ArgumentMatchers.any; |
| 40 | +import static org.mockito.ArgumentMatchers.anyString; |
| 41 | + |
| 42 | +/** |
| 43 | + * Verifies that the MDC (and any other registered thread-local context) captured on the |
| 44 | + * calling thread is propagated to every stage of the asynchronous request/reply pipeline, |
| 45 | + * which is the behaviour requested in |
| 46 | + * <a href="https://github.com/solacecommunity/spring-cloud-stream-request-reply/issues/50">issue #50</a>. |
| 47 | + * |
| 48 | + * <p>Out of the box neither {@code context-propagation} nor this library registers a |
| 49 | + * thread-local accessor for the SLF4J MDC; observability libraries normally do. These tests |
| 50 | + * register the {@link Slf4jThreadLocalAccessor} on the global {@link ContextRegistry} for the |
| 51 | + * duration of the class to mirror that production setup, and remove it again afterwards so no |
| 52 | + * other test is affected.</p> |
| 53 | + */ |
| 54 | +class RequestReplyContextPropagationServiceTests extends AbstractRequestReplySimpleIT { |
| 55 | + |
| 56 | + private static final String TRACE_ID = "traceId"; |
| 57 | + private static final String TOPIC = "last_value/temperature/celsius/demo"; |
| 58 | + |
| 59 | + @MockitoBean |
| 60 | + private StreamBridge streamBridge; |
| 61 | + @Autowired |
| 62 | + private RequestReplyServiceImpl requestReplyService; |
| 63 | + |
| 64 | + @BeforeAll |
| 65 | + void registerMdcAccessor() { |
| 66 | + ContextRegistry.getInstance() |
| 67 | + .registerThreadLocalAccessor(new Slf4jThreadLocalAccessor()); |
| 68 | + |
| 69 | + // Guard against a logging backend without working MDC support: the whole suite is |
| 70 | + // meaningless if MDC.put is a no-op. |
| 71 | + MDC.put(TRACE_ID, "sanity"); |
| 72 | + assertEquals("sanity", MDC.get(TRACE_ID), "MDC is not backed by a real SLF4J implementation"); |
| 73 | + MDC.remove(TRACE_ID); |
| 74 | + } |
| 75 | + |
| 76 | + @AfterAll |
| 77 | + void removeMdcAccessor() { |
| 78 | + ContextRegistry.getInstance() |
| 79 | + .removeThreadLocalAccessor(Slf4jThreadLocalAccessor.KEY); |
| 80 | + } |
| 81 | + |
| 82 | + @BeforeEach |
| 83 | + void clearMdc() { |
| 84 | + MDC.clear(); |
| 85 | + } |
| 86 | + |
| 87 | + @AfterEach |
| 88 | + void clearMdcAfter() { |
| 89 | + MDC.clear(); |
| 90 | + } |
| 91 | + |
| 92 | + @Test |
| 93 | + void context_isPropagatedToRequestSendingThread() throws TimeoutException, RemoteErrorException, InterruptedException { |
| 94 | + AtomicReference<String> traceIdOnSendThread = new AtomicReference<>(); |
| 95 | + AtomicReference<String> sendThreadName = new AtomicReference<>(); |
| 96 | + |
| 97 | + stubSendAndAutoReply(traceIdOnSendThread, sendThreadName, new SensorReading()); |
| 98 | + |
| 99 | + MDC.put(TRACE_ID, "trace-send"); |
| 100 | + |
| 101 | + requestReplyService.requestAndAwaitReplyToTopic( |
| 102 | + new SensorReading(), |
| 103 | + TOPIC, |
| 104 | + SensorReading.class, |
| 105 | + Duration.ofSeconds(10) |
| 106 | + ); |
| 107 | + |
| 108 | + // The request is sent from a pooled executor thread, so propagation genuinely crossed a |
| 109 | + // thread boundary rather than reading the caller thread's own MDC. |
| 110 | + assertNotEquals(Thread.currentThread().getName(), sendThreadName.get(), |
| 111 | + "request should be sent on a pooled executor thread, not the caller thread"); |
| 112 | + assertEquals("trace-send", traceIdOnSendThread.get(), |
| 113 | + "MDC set on the caller thread must be visible on the request-sending executor thread"); |
| 114 | + |
| 115 | + resetMocks(); |
| 116 | + } |
| 117 | + |
| 118 | + @Test |
| 119 | + void context_isPropagatedToStageChainedOnReturnedFuture() throws Exception { |
| 120 | + CountDownLatch sendHappened = new CountDownLatch(1); |
| 121 | + AtomicReference<Message<?>> sentMessage = new AtomicReference<>(); |
| 122 | + |
| 123 | + // Do NOT reply from within send(): keep the internal future pending so the stage we |
| 124 | + // chain below is guaranteed to run asynchronously on a (context-restored) executor |
| 125 | + // thread rather than synchronously on the test thread. |
| 126 | + Mockito.when(streamBridge.send(anyString(), any(Message.class))) |
| 127 | + .thenAnswer(invocation -> { |
| 128 | + sentMessage.set(invocation.getArgument(1)); |
| 129 | + sendHappened.countDown(); |
| 130 | + return true; |
| 131 | + }); |
| 132 | + |
| 133 | + MDC.put(TRACE_ID, "trace-chain"); |
| 134 | + |
| 135 | + CompletableFuture<SensorReading> future = requestReplyService.requestReplyToTopic( |
| 136 | + new SensorReading(), |
| 137 | + TOPIC, |
| 138 | + SensorReading.class, |
| 139 | + Duration.ofSeconds(10) |
| 140 | + ); |
| 141 | + |
| 142 | + AtomicReference<String> traceIdInChainedStage = new AtomicReference<>(); |
| 143 | + AtomicReference<String> chainedStageThread = new AtomicReference<>(); |
| 144 | + CompletableFuture<SensorReading> observed = future.whenComplete((result, error) -> { |
| 145 | + chainedStageThread.set(Thread.currentThread().getName()); |
| 146 | + traceIdInChainedStage.set(MDC.get(TRACE_ID)); |
| 147 | + }); |
| 148 | + |
| 149 | + // Reply from a separate thread that carries no MDC of its own, emulating the Solace |
| 150 | + // consumer thread. This proves the context comes from the original request, not from |
| 151 | + // whichever thread happens to deliver the reply. |
| 152 | + assertTrue(sendHappened.await(5, TimeUnit.SECONDS), "request was never sent"); |
| 153 | + Thread replier = new Thread(() -> { |
| 154 | + MDC.clear(); |
| 155 | + requestReplyService.onReplyReceived( |
| 156 | + MessageBuilder.createMessage(new SensorReading(), sentMessage.get().getHeaders()) |
| 157 | + ); |
| 158 | + }, "reply-injector"); |
| 159 | + replier.start(); |
| 160 | + replier.join(); |
| 161 | + |
| 162 | + observed.get(5, TimeUnit.SECONDS); |
| 163 | + |
| 164 | + assertEquals("trace-chain", traceIdInChainedStage.get(), |
| 165 | + "MDC must be propagated to an application stage chained on the returned CompletableFuture"); |
| 166 | + assertNotEquals("reply-injector", chainedStageThread.get(), |
| 167 | + "the chained stage must not run on the reply-delivering thread"); |
| 168 | + |
| 169 | + resetMocks(); |
| 170 | + } |
| 171 | + |
| 172 | + @Test |
| 173 | + void context_isNotLeakedToASubsequentRequestWithoutContext() throws TimeoutException, RemoteErrorException, InterruptedException { |
| 174 | + // CopyOnWriteArrayList permits null elements, which lets us record a missing MDC verbatim. |
| 175 | + List<String> traceIdsOnSendThread = new CopyOnWriteArrayList<>(); |
| 176 | + |
| 177 | + Mockito.when(streamBridge.send(anyString(), any(Message.class))) |
| 178 | + .thenAnswer(invocation -> { |
| 179 | + traceIdsOnSendThread.add(MDC.get(TRACE_ID)); |
| 180 | + requestReplyService.onReplyReceived( |
| 181 | + MessageBuilder.createMessage( |
| 182 | + new SensorReading(), |
| 183 | + ((Message<?>) invocation.getArgument(1)).getHeaders() |
| 184 | + ) |
| 185 | + ); |
| 186 | + return true; |
| 187 | + }); |
| 188 | + |
| 189 | + // First request carries an MDC value. |
| 190 | + MDC.put(TRACE_ID, "leaky-value"); |
| 191 | + requestReplyService.requestAndAwaitReplyToTopic(new SensorReading(), TOPIC, SensorReading.class, Duration.ofSeconds(10)); |
| 192 | + |
| 193 | + // Let the pooled thread become idle so it is likely reused for the next request. |
| 194 | + await().atMost(Duration.ofSeconds(3)).until(requestReplyService::runningRequests, equalTo(0)); |
| 195 | + MDC.clear(); |
| 196 | + |
| 197 | + // Second request carries no MDC: a reused executor thread must not still see "leaky-value". |
| 198 | + requestReplyService.requestAndAwaitReplyToTopic(new SensorReading(), TOPIC, SensorReading.class, Duration.ofSeconds(10)); |
| 199 | + |
| 200 | + // Both requests run synchronously to completion on the caller thread, so the order is stable. |
| 201 | + assertEquals(2, traceIdsOnSendThread.size(), "exactly two requests should have been sent"); |
| 202 | + assertEquals("leaky-value", traceIdsOnSendThread.get(0), |
| 203 | + "the first request must observe its own MDC value on the executor thread"); |
| 204 | + assertNull(traceIdsOnSendThread.get(1), |
| 205 | + "the second request must see a clean (null) MDC on the executor thread, i.e. no context leak"); |
| 206 | + |
| 207 | + resetMocks(); |
| 208 | + } |
| 209 | + |
| 210 | + @Test |
| 211 | + void callerThreadContext_isUnchangedByARequest() throws TimeoutException, RemoteErrorException, InterruptedException { |
| 212 | + stubSendAndAutoReply(new AtomicReference<>(), new AtomicReference<>(), new SensorReading()); |
| 213 | + |
| 214 | + MDC.put(TRACE_ID, "caller-owned"); |
| 215 | + |
| 216 | + requestReplyService.requestAndAwaitReplyToTopic(new SensorReading(), TOPIC, SensorReading.class, Duration.ofSeconds(10)); |
| 217 | + |
| 218 | + assertEquals("caller-owned", MDC.get(TRACE_ID), |
| 219 | + "the caller thread's MDC must be left intact after the request completes"); |
| 220 | + |
| 221 | + resetMocks(); |
| 222 | + } |
| 223 | + |
| 224 | + @Test |
| 225 | + void runningRequests_tracksInFlightRequest() throws Exception { |
| 226 | + CountDownLatch sendHappened = new CountDownLatch(1); |
| 227 | + AtomicReference<Message<?>> sentMessage = new AtomicReference<>(); |
| 228 | + |
| 229 | + Mockito.when(streamBridge.send(anyString(), any(Message.class))) |
| 230 | + .thenAnswer(invocation -> { |
| 231 | + sentMessage.set(invocation.getArgument(1)); |
| 232 | + sendHappened.countDown(); |
| 233 | + return true; |
| 234 | + }); |
| 235 | + |
| 236 | + CompletableFuture<SensorReading> future = requestReplyService.requestReplyToTopic( |
| 237 | + new SensorReading(), TOPIC, SensorReading.class, Duration.ofSeconds(10) |
| 238 | + ); |
| 239 | + |
| 240 | + assertTrue(sendHappened.await(5, TimeUnit.SECONDS), "request was never sent"); |
| 241 | + await().atMost(Duration.ofSeconds(3)) |
| 242 | + .until(requestReplyService::runningRequests, greaterThanOrEqualTo(1)); |
| 243 | + |
| 244 | + Thread replier = new Thread(() -> requestReplyService.onReplyReceived( |
| 245 | + MessageBuilder.createMessage(new SensorReading(), sentMessage.get().getHeaders()) |
| 246 | + ), "reply-injector"); |
| 247 | + replier.start(); |
| 248 | + replier.join(); |
| 249 | + |
| 250 | + future.get(5, TimeUnit.SECONDS); |
| 251 | + |
| 252 | + await().atMost(Duration.ofSeconds(3)).until(requestReplyService::runningRequests, equalTo(0)); |
| 253 | + |
| 254 | + resetMocks(); |
| 255 | + } |
| 256 | + |
| 257 | + @Test |
| 258 | + void timeout_releasesExecutorThread() { |
| 259 | + Mockito.when(streamBridge.send(anyString(), any(Message.class))) |
| 260 | + .thenReturn(true); // never reply -> force a timeout |
| 261 | + |
| 262 | + MDC.put(TRACE_ID, "trace-timeout"); |
| 263 | + |
| 264 | + assertThrows(TimeoutException.class, () -> requestReplyService.requestAndAwaitReplyToTopic( |
| 265 | + new SensorReading(), TOPIC, SensorReading.class, Duration.ofMillis(200) |
| 266 | + )); |
| 267 | + |
| 268 | + // The blocked worker must be released by the abort path; otherwise the pool leaks threads. |
| 269 | + await().atMost(Duration.ofSeconds(5)).until(requestReplyService::runningRequests, equalTo(0)); |
| 270 | + |
| 271 | + resetMocks(); |
| 272 | + } |
| 273 | + |
| 274 | + private void stubSendAndAutoReply( |
| 275 | + AtomicReference<String> traceIdOnSendThread, |
| 276 | + AtomicReference<String> sendThreadName, |
| 277 | + SensorReading response |
| 278 | + ) { |
| 279 | + Mockito.when(streamBridge.send(anyString(), any(Message.class))) |
| 280 | + .thenAnswer(invocation -> { |
| 281 | + traceIdOnSendThread.set(MDC.get(TRACE_ID)); |
| 282 | + sendThreadName.set(Thread.currentThread().getName()); |
| 283 | + requestReplyService.onReplyReceived( |
| 284 | + MessageBuilder.createMessage( |
| 285 | + response, |
| 286 | + ((Message<?>) invocation.getArgument(1)).getHeaders() |
| 287 | + ) |
| 288 | + ); |
| 289 | + return true; |
| 290 | + }); |
| 291 | + } |
| 292 | +} |
0 commit comments