journalctl: make the read path 1.7x to 2.5x faster (#43663)
Three independent fixes to code on `journalctl`'s per-entry read and output path. Each of them removes work that was never needed, rather than trading away anything. There is no behaviour change: the output is byte for byte identical for every format except `-o json`, where only the order of the keys within each object can shift, which is already nondeterministic between two runs of the unpatched binary (see the correctness section below). Nothing about the formats, tunables or public API changes. Measured on a 730 MB journal spread over 100 files (roughly 2M entries): | command | before | after | | |---|---:|---:|---:| | `journalctl -o cat` | 1.93s | 0.77s | **2.51x** | | `journalctl --grep=<no match>` | 1.97s | 0.82s | **2.40x** | | `journalctl -o export` | 4.06s | 1.73s | **2.35x** | | `journalctl -n 100000 -o short` | 0.86s | 0.43s | **2.00x** | | `journalctl -o json -n 200000` | 5.85s | 3.50s | 1.67x | | `journalctl -o short` (the default) | 3.32s | 1.96s | **1.69x** | | `journalctl -o verbose` | 5.99s | 3.61s | 1.66x | ### 1. `utf8_is_printable_newline()` decoded every character twice `utf8_encoded_valid_unichar()` decodes the character internally in order to validate it, and then throws the codepoint away. The caller immediately called `utf8_encoded_to_unichar()` again to get the very same codepoint back. So for every byte of every field printed, the UTF-8 decoder ran twice, only to answer whether the byte was a control character. This is fixed where it originates rather than at the call site: `utf8_encoded_valid_unichar_full()` optionally returns the character it had to decode anyway, so a caller that wants both the validity and the value decodes once. On top of that, eight bytes are tested at once for plain printable ASCII, which is what almost all journal content is. A word that does not qualify falls through to the per character path unchanged, so tabs, newlines and multibyte sequences behave exactly as before. On its own, against unmodified main: `-o export` 4.02s to 2.89s. ### 2. sd-journal read the clock once per journal file, per entry `sd_journal_next()` sweeps every open journal file to find the next entry, and `next_beyond_location()` rate limits its tail timestamp refresh per file. Since `ratelimit_below()` reads the clock itself, a journal spread over a hundred files meant a hundred `clock_gettime()` calls for every single entry iterated, nearly all of them only to conclude that the one second interval had not elapsed yet. This was the single largest cost in `journalctl`. In a profile of `-o export` it was over a fifth of the entire run, spent deciding not to do the thing it was guarding. Add `ratelimit_below_at()`, which takes the timestamp from the caller, and read the clock once per sweep instead. `ratelimit_below()` keeps its behaviour and becomes a wrapper. The timestamp is now sampled once per sweep rather than once per file. The interval being rate limited is one second and a sweep takes microseconds, so this makes no practical difference. On its own: `-o export` 4.02s to 2.93s, and `-o short` 3.30s to 2.14s. This is the largest single contributor for the default output mode. ### 3. The JSON output built a fresh, unsized hashmap for every entry `journal_entry_to_json()` creates an empty hashmap per entry and fills it with that entry's fields, of which there are typically around twenty. Because it starts empty it has to grow several times per entry, and every growth rehashes everything inserted so far. `-o json` spent about a quarter of its time in siphash, a third of that under `resize_buckets()`. Reserving room up front is a one line change. On its own: `-o json -n 200000` 5.71s to 4.64s.
This commit is contained in:
+11
-5
@@ -6,16 +6,12 @@
|
||||
/* Modelled after Linux' lib/ratelimit.c by Dave Young
|
||||
* <hidave.darkstar@gmail.com>, which is licensed GPLv2. */
|
||||
|
||||
bool ratelimit_below(RateLimit *rl) {
|
||||
usec_t ts;
|
||||
|
||||
bool ratelimit_below_at(RateLimit *rl, usec_t ts) {
|
||||
assert(rl);
|
||||
|
||||
if (!ratelimit_configured(rl))
|
||||
return true;
|
||||
|
||||
ts = now(CLOCK_BOOTTIME);
|
||||
|
||||
if (rl->begin <= 0 ||
|
||||
usec_sub_unsigned(ts, rl->begin) > rl->interval) {
|
||||
rl->begin = ts; /* Start a new time window */
|
||||
@@ -30,6 +26,16 @@ bool ratelimit_below(RateLimit *rl) {
|
||||
return rl->num <= rl->burst;
|
||||
}
|
||||
|
||||
bool ratelimit_below(RateLimit *rl) {
|
||||
assert(rl);
|
||||
|
||||
if (!ratelimit_configured(rl)) /* Keep this check here too: the argument below is evaluated
|
||||
* before the callee could short-circuit on it. */
|
||||
return true;
|
||||
|
||||
return ratelimit_below_at(rl, now(CLOCK_BOOTTIME));
|
||||
}
|
||||
|
||||
unsigned ratelimit_num_dropped(const RateLimit *rl) {
|
||||
assert(rl);
|
||||
|
||||
|
||||
@@ -21,6 +21,11 @@ static inline bool ratelimit_configured(const RateLimit *rl) {
|
||||
}
|
||||
|
||||
bool ratelimit_below(RateLimit *rl);
|
||||
/* Like ratelimit_below(), but takes the current CLOCK_BOOTTIME timestamp from the caller, for callers
|
||||
* that check many rate limits in a row and should not read the clock for each of them. The timestamps
|
||||
* passed for a given RateLimit must not go backwards: a ts before the one that opened the current
|
||||
* window makes usec_sub_unsigned() return 0, i.e. the window looks like it just started. */
|
||||
bool ratelimit_below_at(RateLimit *rl, usec_t ts);
|
||||
|
||||
unsigned ratelimit_num_dropped(const RateLimit *rl);
|
||||
|
||||
|
||||
+57
-7
@@ -11,6 +11,7 @@
|
||||
#include "gunicode.h"
|
||||
#include "hexdecoct.h"
|
||||
#include "string-util.h"
|
||||
#include "unaligned.h"
|
||||
#include "utf8.h"
|
||||
|
||||
bool unichar_is_valid(char32_t ch) {
|
||||
@@ -102,6 +103,20 @@ int utf8_encoded_to_unichar(const char *str, char32_t *ret_unichar) {
|
||||
return len;
|
||||
}
|
||||
|
||||
/* Tests whether all eight bytes of a word are plain printable ASCII, i.e. within 0x20…0x7e. The three
|
||||
* terms below cover the three ways a byte can fail. A byte that fails is always flagged in its own
|
||||
* lane, but the converse does not hold: the two subtractions are whole-word ones, so a borrow out of
|
||||
* a failing lane also flags bytes above it. Only the aggregate test is meaningful, the mask is not a
|
||||
* per-byte map of which bytes failed. */
|
||||
static bool is_printable_fastpath_u64(uint64_t w) {
|
||||
uint64_t x = w ^ UINT64_C(0x7f7f7f7f7f7f7f7f);
|
||||
|
||||
return (((w & UINT64_C(0x8080808080808080)) | /* >= 0x80 */
|
||||
((w - UINT64_C(0x2020202020202020)) & ~w) | /* < 0x20 */
|
||||
((x - UINT64_C(0x0101010101010101)) & ~x)) & /* == 0x7f */
|
||||
UINT64_C(0x8080808080808080)) == 0;
|
||||
}
|
||||
|
||||
bool utf8_is_printable_newline(const char* str, size_t length, bool allow_newline) {
|
||||
assert(str);
|
||||
|
||||
@@ -109,14 +124,41 @@ bool utf8_is_printable_newline(const char* str, size_t length, bool allow_newlin
|
||||
int encoded_len;
|
||||
char32_t val;
|
||||
|
||||
encoded_len = utf8_encoded_valid_unichar(p, length);
|
||||
/* Bulk fast path: almost everything we are asked about is plain printable ASCII, so
|
||||
* test eight bytes of it at once. Anything else falls through to the per-character
|
||||
* path below, which handles it as before. A remainder of less than eight bytes is
|
||||
* copied into a word padded with spaces, so that it can be tested the same way. */
|
||||
while (length > 0) {
|
||||
uint64_t w;
|
||||
size_t n;
|
||||
|
||||
if (length < sizeof(uint64_t)) {
|
||||
n = length;
|
||||
w = UINT64_C(0x2020202020202020);
|
||||
memcpy(&w, p, n);
|
||||
} else {
|
||||
n = sizeof(uint64_t);
|
||||
w = unaligned_read_ne64(p);
|
||||
}
|
||||
|
||||
if (!is_printable_fastpath_u64(w))
|
||||
break;
|
||||
|
||||
length -= n;
|
||||
p += n;
|
||||
}
|
||||
|
||||
/* Note that this is not redundant with the loop condition above: the fast path may
|
||||
* have consumed the remainder of the string, and then there's nothing left to decode. */
|
||||
if (length == 0)
|
||||
break;
|
||||
|
||||
encoded_len = utf8_encoded_valid_unichar_full(p, length, &val);
|
||||
if (encoded_len < 0)
|
||||
return false;
|
||||
assert(encoded_len > 0 && (size_t) encoded_len <= length);
|
||||
|
||||
if (utf8_encoded_to_unichar(p, &val) < 0 ||
|
||||
unichar_is_control(val) ||
|
||||
(!allow_newline && val == '\n'))
|
||||
if (unichar_is_control(val) || (!allow_newline && val == '\n'))
|
||||
return false;
|
||||
|
||||
length -= encoded_len;
|
||||
@@ -541,7 +583,7 @@ static int utf8_unichar_to_encoded_len(char32_t unichar) {
|
||||
}
|
||||
|
||||
/* validate one encoded unicode char and return its length */
|
||||
int utf8_encoded_valid_unichar(const char *str, size_t length /* bytes */) {
|
||||
int utf8_encoded_valid_unichar_full(const char *str, size_t length /* bytes */, char32_t *ret_unichar) {
|
||||
char32_t unichar;
|
||||
size_t len;
|
||||
int r;
|
||||
@@ -549,7 +591,9 @@ int utf8_encoded_valid_unichar(const char *str, size_t length /* bytes */) {
|
||||
assert(str);
|
||||
assert(length > 0);
|
||||
|
||||
/* We read until NUL, at most length bytes. SIZE_MAX may be used to disable the length check. */
|
||||
/* We read until NUL, at most length bytes. SIZE_MAX may be used to disable the length check.
|
||||
* If ret_unichar is non-NULL the decoded character is returned in it, so that callers
|
||||
* interested in both validity and value needn't decode the character a second time. */
|
||||
|
||||
len = utf8_encoded_expected_len(str[0]);
|
||||
if (len == 0)
|
||||
@@ -560,8 +604,11 @@ int utf8_encoded_valid_unichar(const char *str, size_t length /* bytes */) {
|
||||
return -EINVAL;
|
||||
|
||||
/* ascii is valid */
|
||||
if (len == 1)
|
||||
if (len == 1) {
|
||||
if (ret_unichar)
|
||||
*ret_unichar = (char32_t) (uint8_t) str[0];
|
||||
return 1;
|
||||
}
|
||||
|
||||
/* check if expected encoded chars are available */
|
||||
for (size_t i = 0; i < len; i++)
|
||||
@@ -580,6 +627,9 @@ int utf8_encoded_valid_unichar(const char *str, size_t length /* bytes */) {
|
||||
if (!unichar_is_valid(unichar))
|
||||
return -EINVAL;
|
||||
|
||||
if (ret_unichar)
|
||||
*ret_unichar = unichar;
|
||||
|
||||
return (int) len;
|
||||
}
|
||||
|
||||
|
||||
+4
-1
@@ -38,7 +38,10 @@ char16_t *utf8_to_utf16(const char *s, size_t length);
|
||||
size_t char16_strlen(const char16_t *s) _pure_; /* returns the number of 16-bit words in the string (not bytes!) */
|
||||
size_t char16_strsize(const char16_t *s) _pure_;
|
||||
|
||||
int utf8_encoded_valid_unichar(const char *str, size_t length) _pure_;
|
||||
int utf8_encoded_valid_unichar_full(const char *str, size_t length, char32_t *ret_unichar);
|
||||
static inline int _pure_ utf8_encoded_valid_unichar(const char *str, size_t length) {
|
||||
return utf8_encoded_valid_unichar_full(str, length, NULL);
|
||||
}
|
||||
int utf8_encoded_to_unichar(const char *str, char32_t *ret_unichar);
|
||||
|
||||
static inline bool utf16_is_surrogate(char16_t c) {
|
||||
|
||||
Reference in New Issue
Block a user