diff --git a/README.md b/README.md index 1e4a5bd..8f7d665 100644 --- a/README.md +++ b/README.md @@ -121,9 +121,10 @@ TraceClient.builder(url, "MyCli", version).key(key) **Precedence.** An explicit `installId(...)` wins over `installIdFile(...)`, which wins over the server-wide `server-id:` (the server-wide file then gains no `server-id:` line; its `enabled:` switch and `tags:` still apply). An -event that passes its own `install` tag keeps it. `trace.installId()` returns -the ID in use (`null` when disabled or when there is none), so a program can -print it. +event that passes its own `install` tag keeps it, and one that already +carries 32 tags with `version`, the most the server accepts, goes out without +the ID. `trace.installId()` returns the ID in use (`null` when disabled or +when there is none), so a program can print it. `TraceClient.installIdFromFile(file)` is the same load-or-create step on its own, for a program that wants the ID for something else. **Called directly, @@ -139,7 +140,7 @@ generates, reads or writes an ID. | **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. | +| **`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. A report made after `close()` is dropped. | ## Repeated events are coalesced @@ -160,6 +161,8 @@ reports. Before, one server whose `/power` command was being run every without pause costs one report a minute. A window that counted nothing just ends. - `close()` sends every count still open, inside the same 5-second bound. +- A count goes through the same queue as any report. One that finds the queue + full is dropped without a log line, and what it counted is lost. - `startup` is never coalesced or held back. - At most 256 distinct events are counted at once. A new event while 256 are being counted is dropped without a log line, like a report that finds the @@ -167,12 +170,15 @@ reports. Before, one server whose `/power` command was being run every tag every call. So the number of times something happened is the sum, over stored events, -of `value` for events tagged `coalesced` and 1 for the rest — for a valueless -event like `command`, simply `SUM(COALESCE(value, 1))`. Counting rows still -works for "was it used, by how many servers"; it now undercounts "how many -times", by design. One exception: an event that already carries 32 tags, -or its own `coalesced` tag, has its count sent without the `coalesced` tag -(the server accepts at most 32), so that count reads as a single report. +of the `coalesced` tag for events that carry it and 1 for the rest. For an +event reported without a value, the count is its `value` too, so that is +simply `SUM(COALESCE(value, 1))`; for an event reported with a value, such as +`command` with `1.0` in the example above, `value` is not the count, and only +the tag says how many. Counting rows still works for "was it used, by how many +servers"; it now undercounts "how many times", by design. Two exceptions: an +event that already carries 32 tags has its count sent without the `coalesced` +tag (the server accepts at most 32), so that count reads as a single report; +and an event with its own `coalesced` tag keeps it, so that tag is not a count. A minute is long enough that a command dispatched every tick is one event a minute instead of 1,200, and short enough that a person trying a command @@ -215,10 +221,11 @@ tags: - `tags:` starts at column 0 and is followed by indented `key: value` lines. Values may be double-quoted, single-quoted or bare; blank lines and `#` - comments inside the block are skipped, and so is any line indented - differently from the block's first entry. The block ends at the next line - that is not indented, or at the end of the file. An `enabled:` line inside - the block is a tag like any other, not the switch. + comments inside the block are skipped, at any indent, and so is any line + indented differently from the block's first entry. The block ends at the + next line that is not blank, a comment or indented, or at the end of the + file. An `enabled:` line inside the block is a tag like any other, not the + switch. - An event's own tag always wins, and the program's version is the event's own: a server-wide `version` never overwrites it. - Entries the trace server would reject are dropped one by one, never the @@ -269,7 +276,8 @@ Shade it into a plugin jar; it is one class. `value` is omitted when not given, and when it is NaN or infinite (neither is JSON); `tags` always holds at least `version`, and -`install` whenever the client has an [installation ID](#every-event-carries-a-random-server-id), and the count of a +`install` whenever the client has an [installation ID](#every-event-carries-a-random-server-id) and the event is under +32 tags, and the count of a [coalesced](#repeated-events-are-coalesced) event also carries `coalesced`. The server assigns the timestamp. A `201` is success; anything else is logged at `FINE` and dropped. diff --git a/src/main/java/software/stephenson/trace/TraceClient.java b/src/main/java/software/stephenson/trace/TraceClient.java index 82afc90..d1b4b48 100644 --- a/src/main/java/software/stephenson/trace/TraceClient.java +++ b/src/main/java/software/stephenson/trace/TraceClient.java @@ -74,7 +74,8 @@ * {@code 0}, {@code no}) or {@code DO_NOT_TRACK=1} (or {@code true}, * {@code yes}), case-insensitive -- reason {@code environment}; *
  • the server-wide switch, when {@link Builder#serverWideConfig(File)} - * was given: {@code enabled: false} in {@code plugins/trace/config.yml} + * was given: {@code enabled: false} (or {@code off}, {@code 0}, + * {@code no}, case-insensitive) in {@code plugins/trace/config.yml} * -- reason {@code server-wide config: plugins/trace/config.yml};
    • *
  • the program's own setting, {@link Builder#enabled(boolean) * enabled(false)} -- reason {@code config.yml};
    • @@ -105,7 +106,8 @@ * server-wide {@code server-id:}; with none of them, no {@code install} tag * is sent. The ID is random: it names no person, account or address. A * disabled client never generates, reads or writes one. An event's own - * {@code install} tag wins over it. + * {@code install} tag wins over it, and an event already at + * {@value #MAX_TAGS} tags with {@code version} goes out without it. * *

    A disabled client is a no-op that costs nothing. Programs that run on * other people's machines should expose their own switch in their @@ -393,7 +395,8 @@ private String resolveInstallId(Builder builder, ServerWideConfig serverWide) { * *

    Never throws: if the file exists but cannot be read, or cannot be * written, a fresh random ID is returned for this process only, and an - * unreadable file is left as it is. + * unreadable file is left as it is. The same goes for a {@code null} + * file or a blank path, which nothing is written to. * *

    Called directly, this writes whatever the opt-outs say. Pass * the file to {@link Builder#installIdFile(File)} instead to keep the @@ -536,9 +539,10 @@ private ServerWideConfig readServerWideConfig(File pluginsDirectory) { * Reads the switch and the tags from the lines of the server-wide file. * The first {@code enabled:} line outside a {@code tags:} block is the * switch. A {@code tags:} line at column 0 opens a block of indented - * {@code key: value} lines, which ends at the next non-blank line that is - * not indented; blank and {@code #} lines inside it are skipped, as are - * lines indented differently from its first entry. Values may be bare, + * {@code key: value} lines, which ends at the next line that is not + * blank, a comment or indented; blank and {@code #} lines inside it are + * skipped, at any indent, as are lines indented differently from its + * first entry. Values may be bare, * double- or single-quoted. Entries the trace server would reject -- and * anything this reader does not understand -- are dropped, one by one, * and at most {@link #MAX_TAGS} are kept. The first {@code server-id:} @@ -776,12 +780,16 @@ public void report(String name) { * counted nothing ends. {@link #close()} sends every count still open. * *

    So the number of times an event happened is the sum, over the - * events the server stored, of {@code value} where the - * {@value #COALESCED_TAG} tag is present and 1 where it is not -- for - * a valueless event, simply {@code COALESCE(value, 1)}. The one - * exception: a count is not tagged when the event already carries - * {@value #MAX_TAGS} tags or its own {@value #COALESCED_TAG} tag, and - * such a count is then indistinguishable from a single report. + * events the server stored, of the {@value #COALESCED_TAG} tag where it + * is present and 1 where it is not -- for an event reported without a + * value, simply {@code COALESCE(value, 1)}; an event reported with one + * keeps it, so only the tag holds the count. Two exceptions: a count is + * not tagged when the event already carries {@value #MAX_TAGS} tags, so + * it reads as a single report; and an event with its own + * {@value #COALESCED_TAG} tag keeps it, so that tag is not a count. + * + *

    A count goes through the same queue as any report: one that finds + * it full is dropped, without a log line, and what it counted is lost. * *

    {@code startup} is never coalesced, nor held back: every one is * sent at once. @@ -939,7 +947,8 @@ int coalescing() { * would otherwise lose its one event to the race between queueing it * and the thread picking it up. The bound still holds: an unreachable server delays exit * by at most the timeout, never a hang; whatever has not been sent by - * then is dropped. Safe to call more than once, and on a disabled client. + * then is dropped. A report made after this is dropped too. Safe to call + * more than once, and on a disabled client. */ public void close() { if (executor == null) { @@ -1120,7 +1129,8 @@ public Builder enabled(boolean enabled) { * in a Bukkit plugin), {@link #build()} makes sure * {@code plugins/trace/config.yml} exists -- creating it with * {@code enabled: true} if it is missing -- and honours - * {@code enabled: false} in it. Its optional {@code tags:} block is + * {@code enabled: false} (or {@code off}, {@code 0}, {@code no}, + * case-insensitive) in it. Its optional {@code tags:} block is * added to every event this client reports, below the event's own * tags. Its {@code server-id:} line is sent as the tag * {@code install}; when an enabled client finds none, it appends one diff --git a/src/test/java/software/stephenson/trace/TraceClientTest.java b/src/test/java/software/stephenson/trace/TraceClientTest.java index f165380..967e31b 100644 --- a/src/test/java/software/stephenson/trace/TraceClientTest.java +++ b/src/test/java/software/stephenson/trace/TraceClientTest.java @@ -2209,6 +2209,54 @@ void close_sendsEveryCountStillOpen() throws Exception { assertEquals(1, bodies.stream().filter(b -> b.contains("\"once\"")).count(), "nothing to count, nothing more sent"); } + @Test + void close_aCountThatFindsTheQueueFullIsDropped() throws Exception { + // Arrange + // Hold the sending thread on the first report, so nothing behind it + // leaves the queue until close() has tried to queue the count. + CountDownLatch holding = new CountDownLatch(1); + CountDownLatch release = new CountDownLatch(1); + List bodies = new CopyOnWriteArrayList<>(); + HttpServer slow = HttpServer.create(new InetSocketAddress("127.0.0.1", 0), 0); + slow.createContext("/", exchange -> { + bodies.add(new String(readAll(exchange.getRequestBody()), StandardCharsets.UTF_8)); + holding.countDown(); + try { + release.await(10, TimeUnit.SECONDS); + } catch (InterruptedException ignored) { + Thread.currentThread().interrupt(); + } + exchange.sendResponseHeaders(201, -1); + exchange.close(); + }); + slow.start(); + TraceClient client = TraceClient.builder("http://127.0.0.1:" + slow.getAddress().getPort(), "MyPlugin", "1.2.3") + .key("k").build(); + client.report("command"); + client.report("command"); // counted, so close() has a count to send + assertTrue(holding.await(5, TimeUnit.SECONDS), "the first report is in flight"); + for (int i = 0; i < TraceClient.QUEUE_CAPACITY; i++) { + client.report("startup"); // never coalesced: every one takes a place in the queue + } + + // Act + Thread closing = new Thread(client::close); + closing.start(); + long deadline = System.nanoTime() + TimeUnit.SECONDS.toNanos(5); + while (client.coalescing() > 0 && System.nanoTime() < deadline) { + Thread.sleep(10); + } + assertEquals(0, client.coalescing(), "close() has flushed"); + release.countDown(); + closing.join(10_000); + + // Assert + assertFalse(closing.isAlive(), "close() returned"); + assertTrue(bodies.size() > 1, "the queue behind the first report drained"); + assertTrue(bodies.stream().noneMatch(b -> b.contains(TraceClient.COALESCED_TAG)), bodies.toString()); + slow.stop(0); + } + @Test void coalesce_keysOnNameValueAndTagsButNotTagOrder() throws Exception { // Arrange