Skip to content

Commit af4208a

Browse files
cescoffiercescoffier
authored
Merge pull request quarkusio#36010 from cescoffier/attempt-to-fix-the-vertx-mdc-test
Rewrite the Vert.x MDC tests to be more robust
2 parents 912db04 + ddfcafd commit af4208a

File tree

5 files changed

+104
-82
lines changed

5 files changed

+104
-82
lines changed

‎extensions/vertx/deployment/src/test/java/io/quarkus/vertx/mdc/InMemoryLogHandler.java‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -13,12 +13,16 @@
1313
public class InMemoryLogHandler extends Handler {
1414
private static final PatternFormatter FORMATTER = new PatternFormatter("%X{requestId} ### %s");
1515

16-
private final List<String> recordList = new CopyOnWriteArrayList<>();
16+
private static final List<String> recordList = new CopyOnWriteArrayList<>();
1717

1818
public List<String> logRecords() {
1919
return Collections.unmodifiableList(recordList);
2020
}
2121

22+
public static void reset() {
23+
recordList.clear();
24+
}
25+
2226
@Override
2327
public void publish(LogRecord record) {
2428
String loggerName = record.getLoggerName();

‎extensions/vertx/deployment/src/test/java/io/quarkus/vertx/mdc/InMemoryLogHandlerProducer.java‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -12,17 +12,25 @@
1212
@ApplicationScoped
1313
public class InMemoryLogHandlerProducer {
1414

15+
public volatile boolean initialized = false;
16+
1517
@Produces
1618
@Singleton
1719
public InMemoryLogHandler inMemoryLogHandler() {
1820
return new InMemoryLogHandler();
1921
}
2022

23+
public boolean isInitialized() {
24+
return initialized;
25+
}
26+
2127
void onStart(@Observes StartupEvent ev, InMemoryLogHandler inMemoryLogHandler) {
2228
InitialConfigurator.DELAYED_HANDLER.addHandler(inMemoryLogHandler);
29+
initialized = true;
2330
}
2431

2532
void onStop(@Observes ShutdownEvent ev, InMemoryLogHandler inMemoryLogHandler) {
33+
initialized = false;
2634
InitialConfigurator.DELAYED_HANDLER.removeHandler(inMemoryLogHandler);
2735
}
2836
}

‎extensions/vertx/deployment/src/test/java/io/quarkus/vertx/mdc/VerticleDeployer.java‎

Lines changed: 7 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -12,10 +12,7 @@
1212
import io.vertx.core.AbstractVerticle;
1313
import io.vertx.core.Promise;
1414
import io.vertx.core.http.HttpServer;
15-
import io.vertx.core.json.JsonObject;
16-
import io.vertx.ext.web.client.HttpRequest;
1715
import io.vertx.ext.web.client.WebClient;
18-
import io.vertx.ext.web.codec.BodyCodec;
1916
import io.vertx.mutiny.core.Vertx;
2017

2118
@ApplicationScoped
@@ -42,22 +39,24 @@ void onStop(@Observes ShutdownEvent ev) {
4239
private static class TestVerticle extends AbstractVerticle {
4340
private static final Logger LOGGER = Logger.getLogger(TestVerticle.class);
4441

45-
private HttpRequest<JsonObject> request;
46-
4742
@Override
4843
public void start(Promise<Void> startPromise) {
4944
WebClient webClient = WebClient.create(vertx);
50-
request = webClient.getAbs("http://worldclockapi.com/api/json/utc/now").as(BodyCodec.jsonObject());
45+
var request = webClient.getAbs("http://localhost:" + VERTICLE_PORT + "/now");
5146

5247
Promise<HttpServer> httpServerPromise = Promise.promise();
5348
httpServerPromise.future().<Void> mapEmpty().onComplete(startPromise);
5449
vertx.createHttpServer()
5550
.requestHandler(req -> {
56-
String requestId = req.getHeader(REQUEST_ID_HEADER);
5751

52+
if (req.path().equals("/now")) {
53+
req.response().end(Long.toString(System.currentTimeMillis()));
54+
return;
55+
}
56+
57+
String requestId = req.getHeader(REQUEST_ID_HEADER);
5858
MDC.put(MDC_KEY, requestId);
5959
LOGGER.info("Received HTTP request ### " + MDC.get(MDC_KEY));
60-
6160
vertx.setTimer(50, l -> {
6261
LOGGER.info("Timer fired ### " + MDC.get(MDC_KEY));
6362
vertx.executeBlocking(() -> {

‎extensions/vertx/deployment/src/test/java/io/quarkus/vertx/mdc/VertxMDCDevModeTest.java‎

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,12 +3,14 @@
33
import static io.quarkus.vertx.mdc.VerticleDeployer.REQUEST_ID_HEADER;
44
import static io.quarkus.vertx.mdc.VerticleDeployer.VERTICLE_PORT;
55
import static io.restassured.RestAssured.given;
6+
import static org.awaitility.Awaitility.await;
67
import static org.hamcrest.Matchers.is;
78
import static org.junit.jupiter.api.Assertions.assertTrue;
89

910
import java.nio.file.Files;
1011
import java.nio.file.Path;
1112
import java.nio.file.Paths;
13+
import java.util.Arrays;
1214
import java.util.UUID;
1315
import java.util.concurrent.TimeUnit;
1416

@@ -19,6 +21,7 @@
1921
import org.junit.jupiter.api.Test;
2022
import org.junit.jupiter.api.extension.RegisterExtension;
2123

24+
import io.quarkus.bootstrap.logging.InitialConfigurator;
2225
import io.quarkus.test.QuarkusDevModeTest;
2326

2427
public class VertxMDCDevModeTest {
@@ -34,6 +37,14 @@ public class VertxMDCDevModeTest {
3437

3538
@Test
3639
void mdcDevMode() {
40+
InMemoryLogHandler.reset();
41+
await().until(InitialConfigurator.DELAYED_HANDLER::isActivated);
42+
await().until(() -> {
43+
return Arrays.stream(InitialConfigurator.DELAYED_HANDLER.getHandlers())
44+
.anyMatch(h -> h.getClass().getName().contains("InMemoryLogHandler"));
45+
});
46+
;
47+
3748
Path logDirectory = Paths.get(".", "target");
3849
String value = UUID.randomUUID().toString();
3950
given().headers(REQUEST_ID_HEADER, value)

‎extensions/vertx/deployment/src/test/java/io/quarkus/vertx/mdc/VertxMDCTest.java‎

Lines changed: 73 additions & 73 deletions
Original file line numberDiff line numberDiff line change
@@ -5,17 +5,18 @@
55
import static java.util.stream.Collectors.groupingBy;
66
import static java.util.stream.Collectors.mapping;
77
import static java.util.stream.Collectors.toList;
8+
import static org.awaitility.Awaitility.await;
89
import static org.hamcrest.MatcherAssert.assertThat;
910
import static org.hamcrest.Matchers.hasItem;
1011
import static org.junit.jupiter.api.Assertions.assertEquals;
1112
import static org.junit.jupiter.api.Assertions.assertTrue;
1213

14+
import java.util.Arrays;
1315
import java.util.List;
1416
import java.util.Map;
1517
import java.util.UUID;
1618
import java.util.concurrent.CountDownLatch;
17-
import java.util.concurrent.atomic.AtomicReference;
18-
import java.util.function.Consumer;
19+
import java.util.concurrent.TimeUnit;
1920
import java.util.stream.IntStream;
2021
import java.util.stream.Stream;
2122

@@ -25,14 +26,13 @@
2526
import org.jboss.logging.MDC;
2627
import org.jboss.shrinkwrap.api.ShrinkWrap;
2728
import org.jboss.shrinkwrap.api.spec.JavaArchive;
28-
import org.junit.jupiter.api.Test;
29+
import org.junit.jupiter.api.Assertions;
30+
import org.junit.jupiter.api.RepeatedTest;
2931
import org.junit.jupiter.api.extension.RegisterExtension;
3032

33+
import io.quarkus.bootstrap.logging.InitialConfigurator;
3134
import io.quarkus.test.QuarkusUnitTest;
32-
import io.vertx.core.AsyncResult;
33-
import io.vertx.core.CompositeFuture;
3435
import io.vertx.core.Future;
35-
import io.vertx.core.Handler;
3636
import io.vertx.core.Vertx;
3737
import io.vertx.core.buffer.Buffer;
3838
import io.vertx.ext.web.client.HttpRequest;
@@ -61,102 +61,102 @@ public class VertxMDCTest {
6161

6262
@Inject
6363
InMemoryLogHandler inMemoryLogHandler;
64-
64+
@Inject
65+
InMemoryLogHandlerProducer producer;
6566
@Inject
6667
VerticleDeployer verticleDeployer;
6768

68-
static final CountDownLatch countDownLatch = new CountDownLatch(1);
69-
static final AtomicReference<Throwable> errorDuringExecution = new AtomicReference<>();
70-
71-
@Test
69+
@RepeatedTest(10)
7270
void mdc() throws Throwable {
73-
List<String> requestIds = IntStream.range(0, 10)
71+
72+
InMemoryLogHandler.reset();
73+
await().until(() -> producer.isInitialized());
74+
await().until(InitialConfigurator.DELAYED_HANDLER::isActivated);
75+
await().until(() -> {
76+
return Arrays.stream(InitialConfigurator.DELAYED_HANDLER.getHandlers()).anyMatch(h -> h == inMemoryLogHandler);
77+
});
78+
;
79+
80+
List<String> requestIds = IntStream.range(0, 1)
7481
.mapToObj(i -> UUID.randomUUID().toString())
7582
.collect(toList());
7683

77-
sendRequests(requestIds, onSuccess(v -> {
78-
try {
79-
Map<String, List<String>> allMessagesById = inMemoryLogHandler.logRecords()
80-
.stream()
81-
.map(line -> line.split(" ### "))
82-
.peek(split -> assertEquals(split[0], split[2]))
83-
.collect(groupingBy(split -> split[0],
84-
mapping(split -> split[1], toList())));
85-
86-
assertEquals(requestIds.size(), allMessagesById.size());
87-
assertTrue(requestIds.containsAll(allMessagesById.keySet()));
88-
89-
List<String> expected = Stream.<String> builder()
90-
.add("Received HTTP request")
91-
.add("Timer fired")
92-
.add("Blocking task executed")
93-
.add("Received Web Client response")
94-
.build()
95-
.collect(toList());
96-
97-
for (List<String> messages : allMessagesById.values()) {
98-
assertEquals(expected, messages);
99-
}
100-
} catch (Throwable t) {
101-
errorDuringExecution.set(t);
102-
} finally {
103-
countDownLatch.countDown();
104-
}
105-
}));
84+
CountDownLatch done = new CountDownLatch(1);
85+
sendRequests(requestIds, done);
86+
87+
Assertions.assertTrue(done.await(20, TimeUnit.SECONDS));
88+
89+
await().untilAsserted(() -> {
90+
Map<String, List<String>> allMessagesById = inMemoryLogHandler.logRecords()
91+
.stream()
92+
.map(line -> line.split(" ### "))
93+
.peek(split -> assertEquals(split[0], split[2]))
94+
.collect(groupingBy(split -> split[0],
95+
mapping(split -> split[1], toList())));
10696

107-
countDownLatch.await();
97+
assertEquals(requestIds.size(), allMessagesById.size());
98+
assertTrue(requestIds.containsAll(allMessagesById.keySet()));
10899

109-
Throwable throwable = errorDuringExecution.get();
110-
if (throwable != null) {
111-
throw throwable;
112-
}
100+
List<String> expected = Stream.<String> builder()
101+
.add("Received HTTP request")
102+
.add("Timer fired")
103+
.add("Blocking task executed")
104+
.add("Received Web Client response")
105+
.build()
106+
.collect(toList());
107+
108+
for (List<String> messages : allMessagesById.values()) {
109+
assertEquals(expected, messages);
110+
}
111+
});
113112
}
114113

115-
@Test
114+
@RepeatedTest(10)
116115
public void mdcNonVertxThreadTest() {
116+
InMemoryLogHandler.reset();
117+
await().until(() -> producer.isInitialized());
118+
await().until(InitialConfigurator.DELAYED_HANDLER::isActivated);
119+
await().until(() -> {
120+
return Arrays.stream(InitialConfigurator.DELAYED_HANDLER.getHandlers()).anyMatch(h -> h == inMemoryLogHandler);
121+
});
122+
;
123+
117124
String mdcValue = "Test MDC value";
118125
MDC.put("requestId", mdcValue);
119-
LOGGER.info("Test 1");
120126

121-
assertThat(inMemoryLogHandler.logRecords(),
122-
hasItem(mdcValue + " ### Test 1"));
127+
await().untilAsserted(() -> {
128+
LOGGER.info("Test 1");
129+
assertThat(inMemoryLogHandler.logRecords(), hasItem(mdcValue + " ### Test 1"));
130+
});
123131

124132
MDC.remove("requestId");
125-
LOGGER.info("Test 2");
126133

127-
assertThat(inMemoryLogHandler.logRecords(),
128-
hasItem(" ### Test 2"));
134+
await().untilAsserted(() -> {
135+
LOGGER.info("Test 2");
136+
assertThat(inMemoryLogHandler.logRecords(), hasItem(" ### Test 2"));
137+
});
129138

130-
mdcValue = "New test MDC value";
131-
MDC.put("requestId", mdcValue);
132-
LOGGER.info("Test 3");
139+
String mdcValue2 = "New test MDC value";
140+
MDC.put("requestId", mdcValue2);
133141

134-
assertThat(inMemoryLogHandler.logRecords(),
135-
hasItem(mdcValue + " ### Test 3"));
136-
}
137-
138-
protected <T> Handler<AsyncResult<T>> onSuccess(Consumer<T> consumer) {
139-
return result -> {
140-
if (result.failed()) {
141-
errorDuringExecution.set(result.cause());
142-
countDownLatch.countDown();
143-
} else {
144-
consumer.accept(result.result());
145-
}
146-
};
142+
await().untilAsserted(() -> {
143+
LOGGER.info("Test 3");
144+
assertThat(inMemoryLogHandler.logRecords(), hasItem(mdcValue2 + " ### Test 3"));
145+
});
147146
}
148147

149-
@SuppressWarnings({ "rawtypes" })
150-
private void sendRequests(List<String> ids, Handler<AsyncResult<Void>> handler) {
148+
private void sendRequests(List<String> ids, CountDownLatch done) {
151149
WebClient webClient = WebClient.create(vertx, new WebClientOptions().setDefaultPort(VERTICLE_PORT));
152150

153151
HttpRequest<Buffer> request = webClient.get("/")
154152
.expect(ResponsePredicate.SC_OK);
155153

156-
List<Future> futures = ids.stream()
154+
List<? extends Future<?>> futures = ids.stream()
157155
.map(id -> request.putHeader(REQUEST_ID_HEADER, id).send())
158156
.collect(toList());
159157

160-
CompositeFuture.all(futures).<Void> mapEmpty().onComplete(handler);
158+
Future.all(futures).mapEmpty().onComplete(x -> {
159+
done.countDown();
160+
});
161161
}
162162
}

0 commit comments

Comments
 (0)