mirror of
https://github.com/xcat2/xcat-core.git
synced 2026-10-21 15:18:19 +00:00
Merge pull request #7958 from VersatusHPC/fix/genesis-journal-selection
fix(genesis): retain the selected journal entry across history rollover
This commit is contained in:
Daniel Hilst
GitHub
+78
-46
@@ -266,19 +266,36 @@ static bool genesis_journal_entry(sd_journal *journal, char *source, size_t sour
|
||||
return true;
|
||||
}
|
||||
|
||||
static void format_logs(char *text, size_t size) {
|
||||
struct log_record {
|
||||
char text[LOG_LINE_SIZE];
|
||||
char *cursor;
|
||||
unsigned int first_row;
|
||||
unsigned int row_count;
|
||||
bool selected;
|
||||
};
|
||||
|
||||
struct log_view {
|
||||
struct log_record records[LOG_LINE_COUNT];
|
||||
unsigned int count;
|
||||
unsigned int start;
|
||||
};
|
||||
|
||||
static void free_log_view(struct log_view *view) {
|
||||
for (unsigned int index = 0; index < LOG_LINE_COUNT; index++)
|
||||
free(view->records[index].cursor);
|
||||
}
|
||||
|
||||
static void load_logs(struct log_view *view, const char *selected_cursor) {
|
||||
sd_journal *journal = NULL;
|
||||
char lines[LOG_LINE_COUNT][LOG_LINE_SIZE] = {{0}};
|
||||
unsigned int count = 0;
|
||||
unsigned int next = 0;
|
||||
int result;
|
||||
|
||||
if (size == 0)
|
||||
return;
|
||||
text[0] = '\0';
|
||||
result = sd_journal_open(&journal, SD_JOURNAL_LOCAL_ONLY | SD_JOURNAL_SYSTEM);
|
||||
if (result < 0) {
|
||||
xcat_set_text(text, size, "Genesis journal is unavailable: %s", strerror(-result));
|
||||
xcat_set_text(view->records[0].text, LOG_LINE_SIZE, "Genesis journal is unavailable: %s",
|
||||
strerror(-result));
|
||||
view->count = 1;
|
||||
return;
|
||||
}
|
||||
|
||||
@@ -289,6 +306,7 @@ static void format_logs(char *text, size_t size) {
|
||||
char source[96] = "";
|
||||
char timestamp[16] = "--:--:--";
|
||||
uint64_t realtime;
|
||||
struct log_record *record = &view->records[next];
|
||||
|
||||
if (!genesis_journal_entry(journal, source, sizeof(source)) ||
|
||||
!journal_value(journal, "MESSAGE", message, sizeof(message)))
|
||||
@@ -300,32 +318,25 @@ static void format_logs(char *text, size_t size) {
|
||||
if (localtime_r(&seconds, &local_time) != NULL)
|
||||
strftime(timestamp, sizeof(timestamp), "%H:%M:%S", &local_time);
|
||||
}
|
||||
snprintf(lines[next], sizeof(lines[next]), "%s %-24.24s %s", timestamp, source, message);
|
||||
free(record->cursor);
|
||||
record->cursor = NULL;
|
||||
sd_journal_get_cursor(journal, &record->cursor);
|
||||
record->selected =
|
||||
selected_cursor != NULL && sd_journal_test_cursor(journal, selected_cursor) > 0;
|
||||
snprintf(record->text, sizeof(record->text), "%s %-24.24s %s", timestamp, source, message);
|
||||
next = (next + 1) % LOG_LINE_COUNT;
|
||||
count++;
|
||||
}
|
||||
sd_journal_close(journal);
|
||||
|
||||
if (count == 0) {
|
||||
xcat_set_text(text, size, "No Genesis journal entries are available.");
|
||||
xcat_set_text(view->records[0].text, LOG_LINE_SIZE,
|
||||
"No Genesis journal entries are available.");
|
||||
view->count = 1;
|
||||
return;
|
||||
}
|
||||
{
|
||||
unsigned int available = count < LOG_LINE_COUNT ? count : LOG_LINE_COUNT;
|
||||
unsigned int start = count < LOG_LINE_COUNT ? 0 : next;
|
||||
unsigned int index;
|
||||
size_t used = 0;
|
||||
|
||||
for (index = 0; index < available && used + 1 < size; index++) {
|
||||
unsigned int line = (start + index) % LOG_LINE_COUNT;
|
||||
int written =
|
||||
snprintf(text + used, size - used, "%s%s", index > 0 ? "\n" : "", lines[line]);
|
||||
|
||||
if (written < 0 || (size_t)written >= size - used)
|
||||
break;
|
||||
used += (size_t)written;
|
||||
}
|
||||
}
|
||||
view->count = count < LOG_LINE_COUNT ? count : LOG_LINE_COUNT;
|
||||
view->start = count < LOG_LINE_COUNT ? 0 : next;
|
||||
}
|
||||
|
||||
static unsigned int append_wrapped_log_record(newtComponent list_box, const char *record,
|
||||
@@ -365,30 +376,48 @@ static unsigned int append_wrapped_log_record(newtComponent list_box, const char
|
||||
return count;
|
||||
}
|
||||
|
||||
static unsigned int populate_log_listbox(newtComponent list_box, const char *text) {
|
||||
const char *record = text;
|
||||
static unsigned int populate_log_listbox(newtComponent list_box, struct log_view *view) {
|
||||
unsigned int count = 0;
|
||||
|
||||
while (*record != '\0') {
|
||||
const char *end = strchr(record, '\n');
|
||||
size_t length = end != NULL ? (size_t)(end - record) : strlen(record);
|
||||
for (unsigned int index = 0; index < view->count; index++) {
|
||||
struct log_record *record = &view->records[(view->start + index) % LOG_LINE_COUNT];
|
||||
|
||||
count = append_wrapped_log_record(list_box, record, length, count);
|
||||
if (end == NULL)
|
||||
break;
|
||||
record = end + 1;
|
||||
record->first_row = count + 1;
|
||||
count = append_wrapped_log_record(list_box, record->text, strlen(record->text), count);
|
||||
record->row_count = count + 1 - record->first_row;
|
||||
}
|
||||
if (count == 0)
|
||||
count = append_wrapped_log_record(list_box, "", 0, count);
|
||||
return count;
|
||||
}
|
||||
|
||||
static const struct log_record *selected_log_record(const struct log_view *view,
|
||||
unsigned int selected) {
|
||||
for (unsigned int index = 0; index < view->count; index++) {
|
||||
const struct log_record *record = &view->records[(view->start + index) % LOG_LINE_COUNT];
|
||||
|
||||
if (selected >= record->first_row && selected - record->first_row < record->row_count)
|
||||
return record;
|
||||
}
|
||||
return NULL;
|
||||
}
|
||||
|
||||
static unsigned int retained_log_row(const struct log_view *view, unsigned int offset) {
|
||||
for (unsigned int index = 0; index < view->count; index++) {
|
||||
const struct log_record *record = &view->records[(view->start + index) % LOG_LINE_COUNT];
|
||||
|
||||
if (record->selected) {
|
||||
if (offset >= record->row_count)
|
||||
offset = record->row_count - 1;
|
||||
return record->first_row + offset;
|
||||
}
|
||||
}
|
||||
return 1;
|
||||
}
|
||||
|
||||
static void show_logs(void) {
|
||||
struct newtExitStruct event;
|
||||
newtComponent form;
|
||||
newtComponent list_box;
|
||||
char text[LOG_LINE_COUNT * LOG_LINE_SIZE];
|
||||
char previous[LOG_LINE_COUNT * LOG_LINE_SIZE] = "";
|
||||
struct log_view previous = {0};
|
||||
unsigned int item_count = 0;
|
||||
unsigned int selected = 0;
|
||||
bool follow = true;
|
||||
@@ -410,15 +439,17 @@ static void show_logs(void) {
|
||||
newtPushHelpLine(" F3 Back Esc Back Up/Down Scroll End Follow");
|
||||
|
||||
while (!xcat_console_stop_requested) {
|
||||
format_logs(text, sizeof(text));
|
||||
if (previous[0] == '\0' || strcmp(previous, text) != 0) {
|
||||
newtListboxClear(list_box);
|
||||
item_count = populate_log_listbox(list_box, text);
|
||||
if (follow || selected == 0 || selected > item_count)
|
||||
selected = item_count;
|
||||
newtListboxSetCurrentByKey(list_box, (void *)(uintptr_t)selected);
|
||||
xcat_copy_printable(previous, sizeof(previous), text);
|
||||
}
|
||||
struct log_view current = {0};
|
||||
const struct log_record *record = selected_log_record(&previous, selected);
|
||||
unsigned int offset = record != NULL ? selected - record->first_row : 0;
|
||||
|
||||
load_logs(¤t, !follow && record != NULL ? record->cursor : NULL);
|
||||
newtListboxClear(list_box);
|
||||
item_count = populate_log_listbox(list_box, ¤t);
|
||||
selected = follow ? item_count : retained_log_row(¤t, offset);
|
||||
newtListboxSetCurrentByKey(list_box, (void *)(uintptr_t)selected);
|
||||
free_log_view(&previous);
|
||||
previous = current;
|
||||
newtRefresh();
|
||||
newtFormRun(form, &event);
|
||||
if (event.reason == NEWT_EXIT_ERROR ||
|
||||
@@ -452,6 +483,7 @@ static void show_logs(void) {
|
||||
newtListboxSetCurrentByKey(list_box, (void *)(uintptr_t)selected);
|
||||
}
|
||||
|
||||
free_log_view(&previous);
|
||||
newtFormDestroy(form);
|
||||
newtPopHelpLine();
|
||||
newtPopWindow();
|
||||
|
||||
@@ -278,14 +278,17 @@ dependencies plus the `pyte` Python package, bubblewrap,
|
||||
systemd-journal-remote and journalctl. It runs the linked console in a
|
||||
pseudo-terminal and checks help and diagnostics navigation, scrolling,
|
||||
return to the main screen, and F3 journal filtering, order and history limits.
|
||||
Rollover cases check paused selection, expired entries, duplicate messages,
|
||||
wrapped lines and returning to follow mode.
|
||||
It checks termination from the main screen, not from inside a dialog.
|
||||
|
||||
The journal cases need working Linux user and mount namespaces. On Ubuntu
|
||||
24.04, the CI job enables them with
|
||||
`sudo sysctl -w kernel.apparmor_restrict_unprivileged_userns=0`.
|
||||
They import private journal files and verify their contents with journalctl
|
||||
before opening F3. They do not start a journal service or read the host
|
||||
journal. Missing tools or namespace support fail the tests; they do not skip.
|
||||
They import private journal files, including appends while F3 is open, and
|
||||
verify each import with journalctl. They do not start a journal service or
|
||||
read the host journal. Missing tools or namespace support fail the tests;
|
||||
they do not skip.
|
||||
|
||||
The Genesis runtime BATS cases need Bash, Perl, OpenSSL, coreutils, diffutils
|
||||
and bubblewrap. The credential-file cases use a private `/etc` in a Linux
|
||||
|
||||
@@ -38,7 +38,9 @@ class ConsoleTerminal(unittest.TestCase):
|
||||
self.addCleanup(temporary.cleanup)
|
||||
root = Path(temporary.name)
|
||||
self.root = root
|
||||
environment = {"PATH": os.environ["PATH"], "LC_ALL": "C.UTF-8", "TERM": "xterm"}
|
||||
environment = {"PATH": os.environ["PATH"], "LC_ALL": "C.UTF-8", "TERM": "xterm",
|
||||
"NEWT_COLORS": "listbox=black,white\nactlistbox=black,white\n"
|
||||
"sellistbox=white,red\nactsellistbox=white,red"}
|
||||
for name in ("CMDLINE_FILE", "UPTIME_FILE", "OS_RELEASE", "STATUS_DIR", "STATE_FILE",
|
||||
"DESTINY_FILE", "RESPONSE_FILE", "SYS_ROOT", "PROC_ROOT", "EXTENSION_DIR", "PROVIDER_DIR"):
|
||||
environment["XCAT_" + name] = str(root / name.lower())
|
||||
@@ -75,13 +77,16 @@ class ConsoleTerminal(unittest.TestCase):
|
||||
return "\n".join(self.screen.display)
|
||||
|
||||
def wait_text(self, text):
|
||||
return self.wait_screen(lambda display: text in display, repr(text))
|
||||
|
||||
def wait_screen(self, predicate, description):
|
||||
deadline = time.monotonic() + 5
|
||||
while time.monotonic() < deadline:
|
||||
display = self.read_screen(0.1)
|
||||
if text in display:
|
||||
if predicate(display):
|
||||
return display
|
||||
self.assertIsNone(self.process.poll(), display)
|
||||
self.fail(f"Terminal did not show {text!r}:\n{display}")
|
||||
self.fail(f"Terminal did not show {description}:\n{display}")
|
||||
|
||||
def key(self, sequence):
|
||||
os.write(self.master, sequence)
|
||||
@@ -117,7 +122,8 @@ class ConsoleJournal(ConsoleTerminal):
|
||||
"""Read real journal files in a private machine and journal namespace.
|
||||
|
||||
Requires bubblewrap, systemd-journal-remote, journalctl and user namespaces.
|
||||
The host filesystem is read-only; /run and /var/log are private mounts.
|
||||
The host filesystem is read-only except for the fixture directory.
|
||||
/run and /var/log are private tmpfs mounts with the journal bound read-only.
|
||||
No journal service is started and no host journal is read or changed.
|
||||
"""
|
||||
|
||||
@@ -128,11 +134,13 @@ class ConsoleJournal(ConsoleTerminal):
|
||||
journal_directory = journal_root / self.machine_id
|
||||
journal_directory.mkdir(parents=True)
|
||||
self.journal = journal_directory / "system.journal"
|
||||
self.entries = []
|
||||
machine_id_file = self.root / "machine-id"
|
||||
machine_id_file.write_text(self.machine_id + "\n")
|
||||
sandbox = [
|
||||
"bwrap", "--unshare-all", "--die-with-parent", "--ro-bind", "/", "/",
|
||||
"--dev", "/dev", "--proc", "/proc", "--tmpfs", "/run", "--tmpfs", "/var/log",
|
||||
"--bind", str(self.root), str(self.root),
|
||||
"--ro-bind", str(machine_id_file), "/etc/machine-id",
|
||||
"--ro-bind", str(journal_root), "/var/log/journal",
|
||||
]
|
||||
@@ -140,34 +148,145 @@ class ConsoleJournal(ConsoleTerminal):
|
||||
capture_output=True, timeout=10)
|
||||
self.assertEqual(result.returncode, 0,
|
||||
"Journal tests require working Bubblewrap namespaces: " + result.stderr)
|
||||
self.sandbox = sandbox
|
||||
return sandbox + [str(self.binary)]
|
||||
|
||||
def write_journal(self, entries):
|
||||
def write_journal(self, entries, interval=1000000):
|
||||
records = []
|
||||
for sequence, (message, unit, identifier) in enumerate(entries, 1):
|
||||
for sequence, (message, unit, identifier) in enumerate(entries, len(self.entries) + 1):
|
||||
records.append(
|
||||
f"__REALTIME_TIMESTAMP={1700000000000000 + sequence * 1000000}\n"
|
||||
f"__MONOTONIC_TIMESTAMP={sequence * 1000000}\n"
|
||||
f"__REALTIME_TIMESTAMP={1700000000000000 + sequence * interval}\n"
|
||||
f"__MONOTONIC_TIMESTAMP={sequence * interval}\n"
|
||||
f"_MACHINE_ID={self.machine_id}\n_BOOT_ID={self.boot_id}\n"
|
||||
f"_SYSTEMD_UNIT={unit}\nSYSLOG_IDENTIFIER={identifier}\n"
|
||||
f"MESSAGE={message}\n\n")
|
||||
result = subprocess.run(
|
||||
["/usr/lib/systemd/systemd-journal-remote", "--split-mode=none",
|
||||
self.sandbox + ["/usr/lib/systemd/systemd-journal-remote", "--split-mode=none",
|
||||
"--output=" + str(self.journal), "-"],
|
||||
input="".join(records), text=True, capture_output=True, timeout=10)
|
||||
self.assertEqual(result.returncode, 0, result.stderr)
|
||||
self.entries.extend(entries)
|
||||
exported = subprocess.check_output(
|
||||
["journalctl", "--file=" + str(self.journal), "--output=json", "--no-pager"],
|
||||
text=True, timeout=10)
|
||||
actual = [json.loads(line) for line in exported.splitlines()]
|
||||
self.assertEqual([(entry["MESSAGE"], entry["_SYSTEMD_UNIT"], entry["SYSLOG_IDENTIFIER"])
|
||||
for entry in actual], entries)
|
||||
for entry in actual], self.entries)
|
||||
|
||||
def open_logs(self):
|
||||
self.key(b"\x1bOR")
|
||||
self.wait_text("Genesis logs")
|
||||
self.wait_text("F3 Back")
|
||||
|
||||
def selected_text(self):
|
||||
return "\n".join("".join(self.screen.buffer[row][column].data
|
||||
for column in range(self.screen.columns)
|
||||
if self.screen.buffer[row][column].bg == "red").strip()
|
||||
for row in range(self.screen.lines)).strip()
|
||||
|
||||
def wait_selected(self, text):
|
||||
return self.wait_screen(lambda display: self.selected_text().endswith(text),
|
||||
f"selected log entry {text!r}")
|
||||
|
||||
def assert_selection_stays(self, text):
|
||||
deadline = time.monotonic() + 3
|
||||
while time.monotonic() < deadline:
|
||||
self.read_screen(0.1)
|
||||
self.assertEqual(self.selected_text(), text)
|
||||
self.assertIsNone(self.process.poll())
|
||||
|
||||
def test_paused_entry_survives_history_rollover(self):
|
||||
self.write_journal([(f"RECORD-{number:04d}", "other.service", "xcat-genesis-register")
|
||||
for number in range(1, 130)])
|
||||
self.open_logs()
|
||||
self.wait_selected("RECORD-0129")
|
||||
self.key(b"\x1b[H")
|
||||
self.wait_selected("RECORD-0002")
|
||||
self.key(b"\x1b[B" * 60)
|
||||
self.wait_selected("RECORD-0062")
|
||||
selected = self.selected_text()
|
||||
for number in (130, 131):
|
||||
self.write_journal([(f"RECORD-{number:04d}", "other.service", "xcat-genesis-register")])
|
||||
self.assert_selection_stays(selected)
|
||||
self.key(b"\x1b[F")
|
||||
self.wait_selected("RECORD-0131")
|
||||
self.write_journal([("FOLLOWED", "other.service", "xcat-genesis-register")])
|
||||
self.wait_selected("FOLLOWED")
|
||||
|
||||
def test_expired_selection_stays_paused_at_oldest_entry(self):
|
||||
self.write_journal([(f"RECORD-{number:04d}", "other.service", "xcat-genesis-register")
|
||||
for number in range(1, 130)])
|
||||
self.open_logs()
|
||||
self.wait_selected("RECORD-0129")
|
||||
self.key(b"\x1b[H")
|
||||
self.wait_selected("RECORD-0002")
|
||||
for first, last, oldest in ((130, 140, 12), (140, 270, 142)):
|
||||
self.write_journal([(f"RECORD-{number:04d}", "other.service", "xcat-genesis-register")
|
||||
for number in range(first, last)])
|
||||
self.wait_selected(f"RECORD-{oldest:04d}")
|
||||
self.assert_selection_stays(self.selected_text())
|
||||
if first == 130:
|
||||
self.key(b"\x1b[B" * 50)
|
||||
self.wait_selected("RECORD-0062")
|
||||
self.write_journal([("STILL-PAUSED", "other.service", "xcat-genesis-register")])
|
||||
self.wait_selected("RECORD-0143")
|
||||
self.key(b"\x1b[F")
|
||||
self.wait_selected("STILL-PAUSED")
|
||||
|
||||
def test_duplicate_text_keeps_the_selected_record(self):
|
||||
self.write_journal([("DUPLICATE" if number in (60, 62, 63) else f"RECORD-{number:04d}",
|
||||
"other.service", "xcat-genesis-register")
|
||||
for number in range(1, 130)], interval=1)
|
||||
self.open_logs()
|
||||
self.wait_selected("RECORD-0129")
|
||||
self.key(b"\x1b[H")
|
||||
self.wait_selected("RECORD-0002")
|
||||
self.key(b"\x1b[B" * 58)
|
||||
self.wait_selected("DUPLICATE")
|
||||
duplicate = self.selected_text()
|
||||
self.key(b"\x1b[B")
|
||||
self.wait_selected("RECORD-0061")
|
||||
self.key(b"\x1b[B")
|
||||
self.wait_selected("DUPLICATE")
|
||||
self.assertEqual(self.selected_text(), duplicate)
|
||||
self.write_journal([("APPENDED", "other.service", "xcat-genesis-register")], interval=1)
|
||||
self.assert_selection_stays(duplicate)
|
||||
self.key(b"\x1b[A")
|
||||
self.wait_selected("RECORD-0061")
|
||||
self.key(b"\x1b[H")
|
||||
self.wait_selected("RECORD-0003")
|
||||
|
||||
def test_wrapped_selection_survives_history_rollover(self):
|
||||
self.write_journal([
|
||||
(" ".join(f"OLD-{number:02d}" for number in range(20)),
|
||||
"other.service", "xcat-genesis-register"),
|
||||
(" ".join(f"CONTEXT-{number:02d}" for number in range(16)) + " SELECTED-TAIL",
|
||||
"other.service", "xcat-genesis-register"),
|
||||
] + [(f"RECORD-{number:04d}", "other.service", "xcat-genesis-register")
|
||||
for number in range(3, 129)])
|
||||
self.open_logs()
|
||||
self.wait_selected("RECORD-0128")
|
||||
self.key(b"\x1b[H")
|
||||
self.wait_screen(lambda display: "OLD-00" in self.selected_text(), "oldest wrapped entry")
|
||||
for _ in range(12):
|
||||
if self.selected_text().endswith("CONTEXT-08"):
|
||||
break
|
||||
previous = self.selected_text()
|
||||
self.key(b"\x1b[B")
|
||||
self.wait_screen(lambda display: self.selected_text() != previous, "next wrapped row")
|
||||
self.assertTrue(self.selected_text().endswith("CONTEXT-08"), self.selected_text())
|
||||
selected = self.selected_text()
|
||||
self.assertIn("OLD-00", self.read_screen(0))
|
||||
self.write_journal([("APPENDED", "other.service", "xcat-genesis-register")])
|
||||
self.wait_screen(lambda display: "OLD-00" not in display, "expired wrapped entry removed")
|
||||
self.assert_selection_stays(selected)
|
||||
self.key(b"\x1b[B")
|
||||
self.wait_selected("CONTEXT-14")
|
||||
self.key(b"\x1b[B")
|
||||
self.wait_selected("SELECTED-TAIL")
|
||||
self.key(b"\x1b[B")
|
||||
self.wait_selected("RECORD-0003")
|
||||
|
||||
def test_empty_journal(self):
|
||||
self.open_logs()
|
||||
self.wait_text("No Genesis journal entries are available.")
|
||||
|
||||
Reference in New Issue
Block a user