From 524803942e6a83a446c21b643817d282f9d71598 Mon Sep 17 00:00:00 2001 From: Daniel McCoy Stephenson Date: Wed, 4 Nov 2026 05:24:24 -0700 Subject: [PATCH] Drop a report whose tags map cannot be read instead of throwing report() copied and serialized the caller's map on the caller's thread with nothing around it, so a map another thread was changing threw ConcurrentModificationException into the host program, and a raw map holding a non-String threw ClassCastException. Both now drop that one report, silently like the other drops on that thread, since a logging handler may do IO there. Co-Authored-By: Claude Opus 5.5 --- README.md | 2 +- .../stephenson/trace/TraceClient.java | 29 +++++++--- .../stephenson/trace/TraceClientTest.java | 55 +++++++++++++++++++ 3 files changed, 76 insertions(+), 10 deletions(-) diff --git a/README.md b/README.md index fc74bbf..1e4a5bd 100644 --- a/README.md +++ b/README.md @@ -136,7 +136,7 @@ generates, reads or writes an ID. | Property | Meaning | |---|---| | **Returns immediately** | The HTTP call runs on one daemon thread the client owns. A Spigot plugin can report from the server thread and no tick waits on the network. | -| **Never throws** | A server that is down, slow, or rejecting the key is a dropped report, not an exception in your program. Such a failure is logged at `FINE` if you gave a logger, otherwise not at all. | +| **Never throws** | A server that is down, slow, or rejecting the key is a dropped report, not an exception in your program. Such a failure is logged at `FINE` if you gave a logger, otherwise not at all. A tags map that fails while being read — changed by another thread during the call, or holding a non-`String` through an unchecked cast — is a dropped report too, without a log line. | | **Bounded** | At most 256 reports wait to be sent; past that, new ones are dropped without a log line, even at `FINE`. A trace server that is unreachable for a week costs a few kilobytes, not your heap. | | **Throttled** | Repeats of one event within a minute are counted, not sent: the first goes out at once, the rest as one event when the minute is up. See [below](#repeated-events-are-coalesced). | | **`close()` drains** | Reports already queued get up to the client timeout (5 s total) to be sent before the thread stops, so a CLI that reports and exits at once does not lose its event. Still bounded: an unreachable server delays exit by at most the timeout. | diff --git a/src/main/java/software/stephenson/trace/TraceClient.java b/src/main/java/software/stephenson/trace/TraceClient.java index 8d7a177..82afc90 100644 --- a/src/main/java/software/stephenson/trace/TraceClient.java +++ b/src/main/java/software/stephenson/trace/TraceClient.java @@ -49,7 +49,8 @@ *
  • It never throws. A server that is down, slow, or rejecting the * key is a dropped report, not an exception in the host program. Failures * are logged at {@link Level#FINE} if a logger was given, and otherwise - * not at all.
    • + * not at all. A tags map that cannot be read is a dropped report too, + * without a log line. *
  • It is bounded. At most {@value #QUEUE_CAPACITY} reports wait to * be sent; beyond that, new reports are dropped rather than accumulated, * without a log line, even at {@link Level#FINE}. A trace server @@ -758,7 +759,9 @@ public void report(String name) { /** * Reports that {@code name} happened, with an optional numeric value and * optional string tags. Returns immediately; see the class comment. A - * {@code null} or blank name sends nothing. + * {@code null} or blank name sends nothing, and so does a {@code tags} + * map that fails while being read -- changed by another thread during + * the call, or holding a non-{@code String} through an unchecked cast. * *

    Repeats are coalesced. The first report of an event -- its name, * value and tags, once {@code version}, {@code install} and the @@ -790,9 +793,17 @@ public void report(String name, Double value, Map tags) { // json() leaves out a value that is NaN or infinite, so they are the // same event as no value at all. Double finite = value == null || value.isNaN() || value.isInfinite() ? null : value; - Map merged = - withServerWideTags(withInstall(withVersion(tags, version), installId), serverWideTags); - String body = json(application, name, finite, merged); + Map merged; + String body; + try { + merged = withServerWideTags(withInstall(withVersion(tags, version), installId), serverWideTags); + body = json(application, name, finite, merged); + } catch (RuntimeException unreadable) { + // The caller's map, read on the caller's thread: another thread + // changing it, or a raw map holding a non-String, fails here. Not + // logged, like the other drops on this thread: a handler may do IO. + return; + } synchronized (lock) { if (closed) { return; @@ -1180,10 +1191,10 @@ public Builder installIdFile(File installIdFile) { * {@code [trace]}: a report the server did not answer {@code 201} * to or that could not be delivered, and a server-wide config or * install ID file that could not be read or written in - * {@link #build()}. A report dropped because the queue is full, or - * because {@value TraceClient#MAX_COALESCED_EVENTS} other events are - * already being counted, is not mentioned. Optional; without one, - * nothing is logged. + * {@link #build()}. A report dropped because the queue is full, because + * {@value TraceClient#MAX_COALESCED_EVENTS} other events are already + * being counted, or because its tags map could not be read, is not + * mentioned. Optional; without one, nothing is logged. */ public Builder logger(Logger logger) { this.logger = logger; diff --git a/src/test/java/software/stephenson/trace/TraceClientTest.java b/src/test/java/software/stephenson/trace/TraceClientTest.java index 8c6016f..891b31a 100644 --- a/src/test/java/software/stephenson/trace/TraceClientTest.java +++ b/src/test/java/software/stephenson/trace/TraceClientTest.java @@ -13,13 +13,16 @@ import java.nio.charset.StandardCharsets; import java.nio.file.Files; import java.nio.file.Path; +import java.util.AbstractMap; import java.util.ArrayList; import java.util.Arrays; import java.util.Collections; +import java.util.ConcurrentModificationException; import java.util.HashMap; import java.util.LinkedHashMap; import java.util.List; import java.util.Map; +import java.util.Set; import java.util.concurrent.CopyOnWriteArrayList; import java.util.concurrent.CountDownLatch; import java.util.concurrent.TimeUnit; @@ -224,6 +227,58 @@ void report_doesNotThrowWhenTheServerRejectsTheKey() throws Exception { client.close(); } + @Test + void report_aTagsMapChangedMidReadIsDroppedWithoutThrowing() throws Exception { + // Arrange + // What a HashMap does when another thread changes it during the + // copy, without needing to win that race. + Map beingChanged = new AbstractMap() { + @Override + public Set> entrySet() { + throw new ConcurrentModificationException(); + } + }; + RecordingHandler log = new RecordingHandler(); + Logger logger = Logger.getLogger("TraceClientTest.unreadableTags"); + logger.setLevel(Level.ALL); + logger.addHandler(log); + TraceClient client = TraceClient.builder(baseUrl(), "MyPlugin", "1.2.3").key("k").logger(logger).build(); + + // Act + assertDoesNotThrow(() -> client.report("command", 1.0, beingChanged)); + client.report("after", null, null); + + // Assert + assertTrue(arrived.await(5, TimeUnit.SECONDS), "the client should keep working"); + assertEquals(1, client.coalescing(), "only the good report opened a window"); + client.close(); + assertEquals(1, received.size(), "the unreadable report is dropped"); + assertTrue(received.get(0).body.contains("\"name\":\"after\""), received.get(0).body); + assertTrue(log.records.isEmpty(), "nothing is logged on the caller's thread: " + log.records); + } + + @Test + @SuppressWarnings({"unchecked", "rawtypes"}) + void report_aNonStringTagSmuggledInByARawMapIsDroppedWithoutThrowing() throws Exception { + // Arrange + // A Bukkit getValues(false) is a Map; one unchecked + // cast puts an Integer where json() needs a String. + Map raw = new HashMap(); + raw.put("count", 5); + Map tags = raw; + TraceClient client = TraceClient.builder(baseUrl(), "MyPlugin", "1.2.3").key("k").build(); + + // Act + assertDoesNotThrow(() -> client.report("command", null, tags)); + client.report("after", null, null); + + // Assert + assertTrue(arrived.await(5, TimeUnit.SECONDS), "the client should keep working"); + client.close(); + assertEquals(1, received.size(), "the unreadable report is dropped"); + assertTrue(received.get(0).body.contains("\"name\":\"after\""), received.get(0).body); + } + @Test void disabledClient_sendsNothing() throws Exception { // Arrange