Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
38 changes: 23 additions & 15 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand All @@ -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

Expand All @@ -160,19 +161,24 @@ 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
queue full, so memory stays bounded even for a program that reports a new
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
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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.

Expand Down
38 changes: 24 additions & 14 deletions src/main/java/software/stephenson/trace/TraceClient.java
Original file line number Diff line number Diff line change
Expand Up @@ -74,7 +74,8 @@
* {@code 0}, {@code no}) or {@code DO_NOT_TRACK=1} (or {@code true},
* {@code yes}), case-insensitive -- reason {@code environment};</li>
* <li>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};</li>
* <li>the program's own setting, {@link Builder#enabled(boolean)
* enabled(false)} -- reason {@code config.yml};</li>
Expand Down Expand Up @@ -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.
*
* <p>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
Expand Down Expand Up @@ -393,7 +395,8 @@ private String resolveInstallId(Builder builder, ServerWideConfig serverWide) {
*
* <p>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.
*
* <p><b>Called directly, this writes whatever the opt-outs say.</b> Pass
* the file to {@link Builder#installIdFile(File)} instead to keep the
Expand Down Expand Up @@ -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:}
Expand Down Expand Up @@ -776,12 +780,16 @@ public void report(String name) {
* counted nothing ends. {@link #close()} sends every count still open.
*
* <p>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.
*
* <p>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.
*
* <p>{@code startup} is never coalesced, nor held back: every one is
* sent at once.
Expand Down Expand Up @@ -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) {
Expand Down Expand Up @@ -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
Expand Down
48 changes: 48 additions & 0 deletions src/test/java/software/stephenson/trace/TraceClientTest.java
Original file line number Diff line number Diff line change
Expand Up @@ -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<String> 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
Expand Down
Loading