From 0115dbaa452008adf33ee347c14f818ef2d5065c Mon Sep 17 00:00:00 2001 From: Andrew Tridgell Date: Sun, 19 Jul 2026 14:00:59 +1000 Subject: [PATCH 1/9] keydb: add per-entry log-naming timezone offset MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Add float tz_offset_hours to KeyEntry — a GMT offset in hours (fractional allowed, e.g. 5.5 for IST, -3.75 for Chatham) that will drive both the date subdir and the log filename. It claims one of the reserved words (168-byte record size unchanged), so old records read back as 0.0 = GMT with no conversion. An offset is stored rather than a named zone deliberately: a fixed offset is unambiguous and DST-free, which is what a stable log-naming convention wants. New 'keydb.py settz PORT2 HOURS' CLI action, shown in list output as e.g. tz=GMT+05:30. --- keydb.h | 3 ++- keydb.py | 14 ++++++++++++ keydb_lib.py | 64 ++++++++++++++++++++++++++++++++++++++++++---------- 3 files changed, 68 insertions(+), 13 deletions(-) diff --git a/keydb.h b/keydb.h index 283c666..136fb61 100644 --- a/keydb.h +++ b/keydb.h @@ -46,7 +46,8 @@ struct KeyEntry { uint32_t flags; float log_retention_days; // tlog + bin; 0.0 = forever; fractional values allowed for tests uint32_t fc_sysid; // 0 = match any; otherwise only monitor packets from this MAVLink sysid (binlog reboot detection) - uint32_t reserved[15]; + float tz_offset_hours; // log naming: offset from GMT in hours (fractional allowed); 0 = GMT + uint32_t reserved[14]; }; /* diff --git a/keydb.py b/keydb.py index e8a2fa9..6e0d0cc 100755 --- a/keydb.py +++ b/keydb.py @@ -27,6 +27,7 @@ def main(): 'setflag', 'clearflag', 'flags', 'setretention', 'setsysid', + 'settz', 'stats'], help="action to perform") parser.add_argument("args", default=[], nargs=argparse.REMAINDER) @@ -135,6 +136,19 @@ def main(): else: print("Set fc_sysid=%u for %s" % (sysid, ke)) + elif args.action == "settz": + _expect(args.args, 2, + "keydb.py settz PORT2 HOURS " + "(GMT offset in hours, fractional ok; 0 = GMT)") + try: + hours = float(args.args[1]) + except ValueError: + raise CLIError("HOURS must be a number, got %r" + % args.args[1]) + ke = keydb_lib.set_timezone(db, int(args.args[0]), hours) + print("Set log timezone=%s for %s" + % (keydb_lib.format_tz_offset(hours), ke)) + elif args.action == "stats": # Live-connection stats from connections.tdb (sibling of # keys.tdb), joined with each entry's name from this DB. diff --git a/keydb_lib.py b/keydb_lib.py index df5bc7a..6c016a2 100644 --- a/keydb_lib.py +++ b/keydb_lib.py @@ -24,14 +24,16 @@ # is acceptable (extra trailing bytes belong to a newer schema we ignore). # # The current C++ struct ends with `uint32_t flags`, `float log_retention_days`, -# `uint32_t fc_sysid`, and `uint32_t reserved[15]`. All are 4-byte aligned and -# slot in cleanly after the existing fields, so the struct is 168 bytes with -# no trailing pad. When a future field is added, claim another `reserved[]` -# slot (renumber: shrink reserved by 1, add a named field) so the on-disk byte -# layout stays compatible — the zero-init paths in db_load_key (C++) and -# unpack() (Python) handle older records transparently. +# `uint32_t fc_sysid`, `float tz_offset_hours`, and `uint32_t reserved[14]`. All +# are 4-byte aligned and slot in cleanly after the existing fields, so the +# struct is 168 bytes with no trailing pad. When a future field is added, claim +# another `reserved[]` slot (renumber: shrink reserved by 1, add a named field) +# so the on-disk byte layout stays compatible — the zero-init paths in +# db_load_key (C++) and unpack() (Python) handle older records transparently. +# tz_offset_hours took a slot that was previously a zeroed reserved word, so +# older records read back as 0.0 (GMT) with no conversion. KEYENTRY_MIN_SIZE = 96 -PACK_FORMAT = "= 0 else '-' + total_min = int(round(abs(hours) * 60.0)) + return 'GMT%s%02d:%02d' % (sign, total_min // 60, total_min % 60) class CLIError(Exception): @@ -68,6 +89,7 @@ def __init__(self, port2): self.flags = 0 self.log_retention_days = 0.0 self.fc_sysid = 0 + self.tz_offset_hours = 0.0 self.reserved = [0] * RESERVED_WORDS self.port2 = port2 # opaque trailing bytes from a record written by a future schema @@ -82,6 +104,7 @@ def pack(self): self.count2, name, self.flags, self.log_retention_days, self.fc_sysid, + self.tz_offset_hours, *reserved[:RESERVED_WORDS]) return body + self._tail @@ -99,8 +122,8 @@ def unpack(self, data): (self.magic, self.timestamp, secret_key, self.port1, self.connections, self.count1, self.count2, name, self.flags, self.log_retention_days, - self.fc_sysid) = unpacked[:11] - self.reserved = list(unpacked[11:11 + RESERVED_WORDS]) + self.fc_sysid, self.tz_offset_hours) = unpacked[:12] + self.reserved = list(unpacked[12:12 + RESERVED_WORDS]) self.secret_key = bytearray(secret_key) self.name = name.decode('utf-8', errors='ignore').rstrip('\0') @@ -156,10 +179,13 @@ def __str__(self): sysstr = '' if self.fc_sysid: sysstr = ' fc_sysid=%u' % self.fc_sysid - return ("%u/%u '%s' counts=%u/%u connections=%u ts=%u%s%s%s" + tzstr = '' + if self.tz_offset_hours: + tzstr = ' tz=%s' % format_tz_offset(self.tz_offset_hours) + return ("%u/%u '%s' counts=%u/%u connections=%u ts=%u%s%s%s%s" % (self.port1, self.port2, self.name, self.count1, self.count2, self.connections, - self.timestamp, flagstr, retstr, sysstr)) + self.timestamp, flagstr, retstr, sysstr, tzstr)) def open_db(path='keys.tdb'): @@ -349,6 +375,20 @@ def set_log_retention(db, port2, days): return ke +def set_timezone(db, port2, hours): + """Set the per-entry log-naming timezone as a GMT offset in hours + (fractional allowed). Affects the date subdir and the log filename.""" + ke = KeyEntry(port2) + if not ke.fetch(db): + raise CLIError("No entry for port2 %d" % port2) + if hours < TZ_MIN_OFFSET or hours > TZ_MAX_OFFSET: + raise CLIError("timezone offset must be in %g..%g hours (got %r)" + % (TZ_MIN_OFFSET, TZ_MAX_OFFSET, hours)) + ke.tz_offset_hours = float(hours) + ke.store(db) + return ke + + def set_fc_sysid(db, port2, sysid): """Set the MAVLink sysid filter for this entry. 0 = match any (default); non-zero restricts binlog reboot detection to packets from that sysid.""" From b722aace78cdd5a8409561c0e021320249b7584b Mon Sep 17 00:00:00 2001 From: Andrew Tridgell Date: Sun, 19 Jul 2026 14:07:30 +1000 Subject: [PATCH 2/9] logging: name session files by timestamp in the entry's timezone Replace the sessionN.tlog / sessionN.bin naming with a timestamp basename YYYY_MM_DD_HH:MM:SS of the session start, and form both the date subdir and the filename in the entry's log-naming timezone (tz_offset_hours, a GMT offset). session_time_strings() applies the offset then formats with gmtime so the machine's own TZ never leaks in; offset 0 is GMT. A single basename is computed once at fork (made unique across .tlog/.bin so a same-second start can't clobber) and shared by both writers, keeping the paired files together. binlog's reboot rotation recomputes a fresh reboot-time basename. next_session_n is gone; the writers now take (datedir, name). --- binlog.cpp | 56 +++++++++++++++++-------------------- binlog.h | 66 ++++++++++++++++++++++++++++---------------- session.cpp | 72 +++++++++++++++++++++++++++++------------------- session.h | 37 +++++++++++++++++++------ supportproxy.cpp | 38 +++++++++++++++++++------ tlog.cpp | 15 +++------- tlog.h | 11 ++++---- 7 files changed, 177 insertions(+), 118 deletions(-) diff --git a/binlog.cpp b/binlog.cpp index 59dd255..62ec13d 100644 --- a/binlog.cpp +++ b/binlog.cpp @@ -37,22 +37,14 @@ BinlogWriter::~BinlogWriter() close(); } -bool BinlogWriter::open(uint32_t port2, unsigned session_n, const char *base_dir) +bool BinlogWriter::open(uint32_t port2, const char *base_dir) { if (fp != nullptr) { return true; } - time_t now = time(nullptr); - struct tm tm_now; - localtime_r(&now, &tm_now); - char dir[768]; - snprintf(dir, sizeof(dir), "%s/%u/%04d-%02d-%02d", - base_dir, port2, - tm_now.tm_year + 1900, - tm_now.tm_mon + 1, - tm_now.tm_mday); + snprintf(dir, sizeof(dir), "%s/%u/%s", base_dir, port2, datedir_.c_str()); if (mkpath_0700(dir) < 0) { ::printf("binlog: mkdir %s failed: %s\n", dir, strerror(errno)); @@ -60,14 +52,12 @@ bool BinlogWriter::open(uint32_t port2, unsigned session_n, const char *base_dir } char path[1024]; - snprintf(path, sizeof(path), "%s/session%u.bin", dir, session_n); - - // O_RDWR via "rb+"-then-"wb+" dance: blocks arrive out of order so - // we need to seek + write to arbitrary offsets. fopen "ab" forces - // every write to the end. Use "wb+" to truncate and create, or - // "rb+" to keep an existing file (rare — child crashed mid-session - // and a new fork is reusing the same N? next_session_n() rules - // that out, but defensively allow it). + snprintf(path, sizeof(path), "%s/%s.bin", dir, name_.c_str()); + + // O_RDWR via "wb+": blocks arrive out of order so we seek + write to + // arbitrary offsets ("ab" would force every write to the end). The + // basename is made unique before the session starts, so this creates + // a fresh file rather than truncating a live one. fp = fopen(path, "wb+"); if (fp == nullptr) { ::printf("binlog: fopen %s failed: %s\n", path, strerror(errno)); @@ -181,7 +171,7 @@ void BinlogWriter::mark_seqno_seen(uint32_t seqno) seen_bitmap[byte] |= uint8_t(1u << (seqno & 7)); } -void BinlogWriter::handle_block(uint32_t port2, unsigned session_n, +void BinlogWriter::handle_block(uint32_t port2, const mavlink_message_t &msg) { mavlink_remote_log_data_block_t blk {}; @@ -225,11 +215,9 @@ void BinlogWriter::handle_block(uint32_t port2, unsigned session_n, } return; } - unsigned n = (pending_session_n_ != 0) ? pending_session_n_ : session_n; - if (!open(port2, n)) { + if (!open(port2)) { return; } - pending_session_n_ = 0; gated_block_count_ = 0; } @@ -606,14 +594,20 @@ bool BinlogWriter::rotate_for_reboot() // pre-stream loop; the 5 s keep-alive (re-armed above) covers // reboot recovery. - // Pre-compute the next session N but do NOT open the file yet. - // The handle_block() strict-start gate (fp == nullptr + seqno!=0 - // is dropped) keeps the file unopened until a fresh seqno=0 from - // the rebooted vehicle, so any delayed pre-reboot blocks still - // in flight can't sparse-write into sessionN+1.bin. The open() - // happens lazily in handle_block using pending_session_n_. - pending_session_n_ = next_session_n(port2_, base_dir_.c_str()); - ::printf("binlog: rotation armed; next open will be session%u.bin " - "(awaiting fresh seqno=0)\n", pending_session_n_); + // Rebuild datedir_/name_ with a fresh reboot-time timestamp but do + // NOT open the file yet. The handle_block() strict-start gate + // (fp == nullptr + seqno!=0 dropped) keeps the file unopened until a + // fresh seqno=0 from the rebooted vehicle, so delayed pre-reboot + // blocks can't sparse-write into the new file. The open() happens + // lazily in handle_block using the new datedir_/name_. + char datedir[16], name[64]; + session_time_strings(time(nullptr), tz_offset_hours_, + datedir, sizeof(datedir), name, sizeof(name)); + session_unique_basename(base_dir_.c_str(), port2_, datedir, + name, sizeof(name)); + datedir_ = datedir; + name_ = name; + ::printf("binlog: rotation armed; next open will be %s/%s.bin " + "(awaiting fresh seqno=0)\n", datedir_.c_str(), name_.c_str()); return true; } diff --git a/binlog.h b/binlog.h index 981b873..29b2e84 100644 --- a/binlog.h +++ b/binlog.h @@ -39,14 +39,31 @@ class BinlogWriter { BinlogWriter &operator=(const BinlogWriter &) = delete; /* - open logs///sessionN.bin. Caller supplies - session_n via the shared next_session_n() helper so the .bin - and .tlog for one child fork share their N. + open logs///.bin. The timestamp datedir + + basename come from set_session_paths() (set once at fork so the + .bin and .tlog for one child share their name), or are recomputed + by rotate_for_reboot() for the post-reboot file. */ - bool open(uint32_t port2, unsigned session_n, - const char *base_dir = "logs"); + bool open(uint32_t port2, const char *base_dir = "logs"); bool is_open() const { return fp != nullptr; } + /* + Set the timestamp date subdir + basename for the (lazy) initial + open. Called once by the parent at fork with the shared session + name so .bin and .tlog pair up. rotate_for_reboot() overwrites + these with the reboot-time name for the next file. + */ + void set_session_paths(const char *datedir, const char *name) { + datedir_ = datedir; + name_ = name; + } + + /* + Log-naming timezone (GMT offset in hours) for the reboot-rotated + file's name. Sourced from KeyEntry.tz_offset_hours at fork. + */ + void set_tz(double offset_hours) { tz_offset_hours_ = offset_hours; } + /* Decode a REMOTE_LOG_DATA_BLOCK message and process it. @@ -66,12 +83,10 @@ class BinlogWriter { jump (seqno > highest_seen + 1) the gap is recorded for NACK in tick(). - port2 + session_n are used only on the (lazy) open. They're - passed every call rather than stored so BinlogWriter doesn't - need to copy strings. + port2 is used only on the (lazy) open; the datedir/name come from + set_session_paths(). */ - void handle_block(uint32_t port2, unsigned session_n, - const mavlink_message_t &msg); + void handle_block(uint32_t port2, const mavlink_message_t &msg); /* Observe an arbitrary user-side MAVLink message for FC-reboot @@ -247,12 +262,20 @@ class BinlogWriter { double last_stop_sent_s = 0.0; // Captured on the first successful open() so rotate_for_reboot() - // can re-scan the per-day dir for a fresh session N without - // dragging port2/base_dir through every observe() / handle_block() - // signature. + // can rebuild paths without dragging port2/base_dir through every + // observe() / handle_block() signature. uint32_t port2_ = 0; std::string base_dir_; + // Timestamp date subdir ("YYYY-MM-DD") and basename + // ("YYYY_MM_DD_HH:MM:SS") for the file. Set once at fork via + // set_session_paths() so .bin and .tlog pair up; rebuilt by + // rotate_for_reboot() for the post-reboot file. + std::string datedir_; + std::string name_; + // Log-naming timezone (GMT offset in hours) for rotate's new name. + double tz_offset_hours_ = 0.0; + // Current size of fp (= the largest seqno+1 we've written * 200). // Tracked locally rather than fstat'ing on every write. off_t current_file_size_ = 0; @@ -280,17 +303,12 @@ class BinlogWriter { // SYSTEM_TIME can't trigger a spurious reboot). uint32_t last_system_time_boot_ms_ = 0; - // Close + reset per-log state + arm pending_session_n_ for the - // NEXT open. Used when observe() decides the FC has rebooted. - // Does NOT re-open here — the new file is only opened when a - // fresh seqno=0 arrives, so the existing strict-start gate keeps - // protecting the rotated file from delayed pre-reboot blocks. - // Does NOT reset per-vehicle state (target_system/component, + // Close + reset per-log state + rebuild datedir_/name_ for the NEXT + // open (a fresh reboot-time timestamp). Used when observe() decides + // the FC has rebooted. Does NOT re-open here — the new file is only + // opened when a fresh seqno=0 arrives, so the existing strict-start + // gate keeps protecting the rotated file from delayed pre-reboot + // blocks. Does NOT reset per-vehicle state (target_system/component, // fc_sysid_filter_). bool rotate_for_reboot(); - - // Session N to use on the NEXT open(), set by rotate_for_reboot() - // and consumed on the gate-triggered open in handle_block. - // 0 = no pending rotation; use the caller's session_n argument. - unsigned pending_session_n_ = 0; }; diff --git a/session.cpp b/session.cpp index ac717f0..d38a1aa 100644 --- a/session.cpp +++ b/session.cpp @@ -1,10 +1,11 @@ /* - Shared sessionN + mkdir-p helpers for TlogWriter / BinlogWriter. + Shared timestamp-naming + mkdir-p helpers for TlogWriter / BinlogWriter. */ #include "session.h" #include #include +#include #include #include #include @@ -29,37 +30,50 @@ int mkpath_0700(const char *path) return 0; } -unsigned next_session_n(uint32_t port2, const char *base_dir) +void session_time_strings(time_t utc, double tz_offset_hours, + char *datedir, size_t datedir_len, + char *name, size_t name_len) { - time_t now = time(nullptr); - struct tm tm_now; - localtime_r(&now, &tm_now); + // Apply the offset then format with gmtime, so the machine's local + // timezone plays no part — offset 0 is GMT. + time_t shifted = utc + (time_t)llround(tz_offset_hours * 3600.0); + struct tm tm; + gmtime_r(&shifted, &tm); - char dir[768]; - snprintf(dir, sizeof(dir), "%s/%u/%04d-%02d-%02d", - base_dir, port2, - tm_now.tm_year + 1900, - tm_now.tm_mon + 1, - tm_now.tm_mday); + snprintf(datedir, datedir_len, "%04d-%02d-%02d", + tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday); + snprintf(name, name_len, "%04d_%02d_%02d_%02d:%02d:%02d", + tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday, + tm.tm_hour, tm.tm_min, tm.tm_sec); +} - DIR *d = opendir(dir); - if (d == nullptr) { - // No dir yet -> first session of the day. - return 1; - } - unsigned highest = 0; - struct dirent *ent; - while ((ent = readdir(d)) != nullptr) { - unsigned n = 0; - // Match either sessionN.tlog or sessionN.bin so paired N stays - // paired across both extensions. - if (sscanf(ent->d_name, "session%u.tlog", &n) == 1 - || sscanf(ent->d_name, "session%u.bin", &n) == 1) { - if (n > highest) { - highest = n; - } +void session_unique_basename(const char *base_dir, uint32_t port2, + const char *datedir, + char *name, size_t name_len) +{ + char base[64]; + snprintf(base, sizeof(base), "%s", name); + + char dir[1024]; + snprintf(dir, sizeof(dir), "%s/%u/%s", base_dir, unsigned(port2), datedir); + + for (int suffix = 1; suffix < 1000; suffix++) { + char candidate[80]; + if (suffix == 1) { + snprintf(candidate, sizeof(candidate), "%s", base); + } else { + snprintf(candidate, sizeof(candidate), "%s-%d", base, suffix); + } + char p_tlog[2048], p_bin[2048]; + snprintf(p_tlog, sizeof(p_tlog), "%s/%s.tlog", dir, candidate); + snprintf(p_bin, sizeof(p_bin), "%s/%s.bin", dir, candidate); + struct stat st; + if (stat(p_tlog, &st) != 0 && stat(p_bin, &st) != 0) { + snprintf(name, name_len, "%s", candidate); + return; } } - closedir(d); - return highest + 1; + // 1000 collisions in one second/dir is not going to happen; keep the + // plain base rather than loop forever. + snprintf(name, name_len, "%s", base); } diff --git a/session.h b/session.h index 6c9a6f4..8ff3788 100644 --- a/session.h +++ b/session.h @@ -1,14 +1,18 @@ /* Helpers shared by TlogWriter and BinlogWriter. - Both writers store files at logs///sessionN. - with paired N — when a child fork records both kinds of session - files, sessionN.tlog and sessionN.bin sit next to each other, which - makes the per-day file list in the web UI read naturally. + Both writers store files at logs///., + where is a timestamp "YYYY_MM_DD_HH:MM:SS" of the session + start. A child fork that records both kinds computes one and + passes it to both writers, so the .tlog and .bin sit next to each + other with matching names. The date subdir and the filename are both + formed in the entry's log-naming timezone (a GMT offset in hours). */ #pragma once #include +#include +#include /* mkdir -p with mode 0700 for every component of `path` (logs may @@ -19,9 +23,24 @@ int mkpath_0700(const char *path); /* - Scan logs/// for sessionN.tlog and sessionN.bin, - return max(N) + 1 (so the first call against a fresh dir returns 1). - Considers BOTH extensions so a tlog-then-bin or bin-then-tlog open - ordering yields the same N for both writers in one child fork. + Format the date subdir ("YYYY-MM-DD") and the log basename + ("YYYY_MM_DD_HH:MM:SS") for the UTC time `utc` shifted by + tz_offset_hours (fractional hours allowed). The shifted time is + formatted with gmtime so the machine's own timezone never affects + naming — an offset of 0 yields GMT/UTC. */ -unsigned next_session_n(uint32_t port2, const char *base_dir); +void session_time_strings(time_t utc, double tz_offset_hours, + char *datedir, size_t datedir_len, + char *name, size_t name_len); + +/* + Make `name` (a basename from session_time_strings) unique within + logs/// across BOTH the .tlog and .bin extensions: if + a file with that base already exists (a same-second session start, or + a reboot rotation landing in the same second), append "-2", "-3", … + until free. Modifies `name` in place. Cheap — only touched once per + file open. + */ +void session_unique_basename(const char *base_dir, uint32_t port2, + const char *datedir, + char *name, size_t name_len); diff --git a/supportproxy.cpp b/supportproxy.cpp index 3df2170..38c1fd0 100644 --- a/supportproxy.cpp +++ b/supportproxy.cpp @@ -82,6 +82,7 @@ struct listen_port { uint32_t flags; uint8_t fc_sysid; // 0 = match any; otherwise the FC's MAVLink // sysid for binlog reboot detection + float tz_offset_hours; // log-naming timezone (GMT offset in hours) bool seen; // set true by handle_record() during reload_ports() // for any entry that's still in the DB; entries left // unseen after a reload have been removed. @@ -134,7 +135,8 @@ static void close_sockets(struct listen_port *p); Used both at startup and on each reload; reload_ports() handles the flip side (entries that were in keys.tdb last time and aren't now). */ -static void upsert_port(int port1, int port2, uint32_t flags, uint8_t fc_sysid) +static void upsert_port(int port1, int port2, uint32_t flags, uint8_t fc_sysid, + float tz_offset_hours) { for (auto *p = ports; p; p=p->next) { if (p->port2 == port2) { @@ -146,6 +148,7 @@ static void upsert_port(int port1, int port2, uint32_t flags, uint8_t fc_sysid) p->port1 = port1; p->flags = flags; p->fc_sysid = fc_sysid; + p->tz_offset_hours = tz_offset_hours; if (p->pid == 0) { open_sockets(p); } @@ -161,12 +164,14 @@ static void upsert_port(int port1, int port2, uint32_t flags, uint8_t fc_sysid) p->port1 = port1; p->flags = flags; p->fc_sysid = fc_sysid; + p->tz_offset_hours = tz_offset_hours; if (p->pid == 0) { open_sockets(p); } } else { p->flags = flags; p->fc_sysid = fc_sysid; + p->tz_offset_hours = tz_offset_hours; } return; } @@ -182,6 +187,7 @@ static void upsert_port(int port1, int port2, uint32_t flags, uint8_t fc_sysid) p->pid = 0; p->flags = flags; p->fc_sysid = fc_sysid; + p->tz_offset_hours = tz_offset_hours; p->seen = true; p->removed = false; ports = p; @@ -204,7 +210,8 @@ static int handle_record(struct tdb_context *db, TDB_DATA key, TDB_DATA data, vo // KeyEntry.fc_sysid is uint32 for forward compat; the wire value is // a MAVLink sysid (0..255), so truncate to uint8 once it crosses the // C++/binlog boundary. The CLI / web UI already cap at 255. - upsert_port(k.port1, port2, k.flags, uint8_t(k.fc_sysid)); + upsert_port(k.port1, port2, k.flags, uint8_t(k.fc_sysid), + k.tz_offset_hours); return 0; } @@ -276,11 +283,20 @@ static void main_loop(struct listen_port *p) sigaction(SIGUSR1, &sa, nullptr); } - // session_n is computed once at fork start and shared between the - // tlog and (further down) the binlog writer so the paired files - // — sessionN.tlog + sessionN.bin — share their N regardless of - // which writer activates first or whether one of them never does. - const unsigned session_n = next_session_n(uint32_t(p->port2), "logs"); + // Log naming: one timestamp basename computed once at fork start + // (in the entry's log-naming timezone) and shared between the tlog + // and (further down) the binlog writer, so the paired files — + // .tlog + .bin — share their name and date subdir + // regardless of which writer activates first or whether one never + // does. Made unique up front so a same-second session start doesn't + // clobber an existing file. + char log_datedir[16]; + char log_name[64]; + session_time_strings(time(nullptr), p->tz_offset_hours, + log_datedir, sizeof(log_datedir), + log_name, sizeof(log_name)); + session_unique_basename("logs", uint32_t(p->port2), log_datedir, + log_name, sizeof(log_name)); // bidi: initialise the user-side validator once. Re-initialising // per unsigned datagram (as the pre-latch path originally did) @@ -299,7 +315,7 @@ static void main_loop(struct listen_port *p) const bool tlog_enabled = (p->flags & KEY_FLAG_TLOG) != 0; auto ensure_tlog_open = [&]() { if (tlog_enabled && !tlog.is_open()) { - tlog.open(uint32_t(p->port2), session_n); + tlog.open(uint32_t(p->port2), log_datedir, log_name); } }; auto tlog_ptr = [&]() -> TlogWriter * { @@ -318,6 +334,10 @@ static void main_loop(struct listen_port *p) // Per-entry sysid filter for SYSTEM_TIME-based reboot // detection. 0 (default) accepts any sysid. binlog.set_fc_sysid_filter(p->fc_sysid); + // Timezone (for the reboot-rotated file's timestamp name) and + // the shared session paths for the initial lazy open. + binlog.set_tz(p->tz_offset_hours); + binlog.set_session_paths(log_datedir, log_name); } // Tap helper: returns true if the message was consumed by binlog // and the caller should NOT forward it to the engineer side. @@ -335,7 +355,7 @@ static void main_loop(struct listen_port *p) return false; } if (m.msgid == MAVLINK_MSG_ID_REMOTE_LOG_DATA_BLOCK) { - binlog.handle_block(uint32_t(p->port2), session_n, m); + binlog.handle_block(uint32_t(p->port2), m); } return true; // strip from user→engineer }; diff --git a/tlog.cpp b/tlog.cpp index c563828..e14a8e6 100644 --- a/tlog.cpp +++ b/tlog.cpp @@ -19,22 +19,15 @@ TlogWriter::~TlogWriter() close(); } -bool TlogWriter::open(uint32_t port2, unsigned session_n, const char *base_dir) +bool TlogWriter::open(uint32_t port2, const char *datedir, const char *name, + const char *base_dir) { if (fp != nullptr) { return true; } - time_t now = time(nullptr); - struct tm tm_now; - localtime_r(&now, &tm_now); - char dir[768]; - snprintf(dir, sizeof(dir), "%s/%u/%04d-%02d-%02d", - base_dir, port2, - tm_now.tm_year + 1900, - tm_now.tm_mon + 1, - tm_now.tm_mday); + snprintf(dir, sizeof(dir), "%s/%u/%s", base_dir, port2, datedir); if (mkpath_0700(dir) < 0) { ::printf("tlog: mkdir %s failed: %s\n", dir, strerror(errno)); @@ -42,7 +35,7 @@ bool TlogWriter::open(uint32_t port2, unsigned session_n, const char *base_dir) } char path[1024]; - snprintf(path, sizeof(path), "%s/session%u.tlog", dir, session_n); + snprintf(path, sizeof(path), "%s/%s.tlog", dir, name); fp = fopen(path, "ab"); if (fp == nullptr) { diff --git a/tlog.h b/tlog.h index 218393e..6b3bd4a 100644 --- a/tlog.h +++ b/tlog.h @@ -20,12 +20,13 @@ class TlogWriter { TlogWriter &operator=(const TlogWriter &) = delete; /* - open logs///sessionN.tlog. The caller supplies - session_n via the shared next_session_n() helper so the paired - .tlog / .bin files for one child fork share their N. Creates parent - dirs as needed. Returns true on success. + open logs///.tlog. The caller supplies the + timestamp datedir + basename (from session_time_strings / + session_unique_basename) so the paired .tlog / .bin files for one + child fork share their name. Creates parent dirs as needed. + Returns true on success. */ - bool open(uint32_t port2, unsigned session_n, + bool open(uint32_t port2, const char *datedir, const char *name, const char *base_dir = "logs"); /* From 240e0370cb4459f406f155a688648ea4393f6a56 Mon Sep 17 00:00:00 2001 From: Andrew Tridgell Date: Sun, 19 Jul 2026 14:09:37 +1000 Subject: [PATCH 3/9] webadmin: browse timestamp log names and edit the log timezone Broaden the session-file regex to accept the new YYYY_MM_DD_HH:MM:SS[-N] timestamp names (keeping the legacy sessionN names so old logs stay browsable); the natural-sort key already orders the timestamps chronologically. Add a 'Log timezone (GMT offset in hours)' field to the owner and admin edit forms (validated -12..14), wired through both routes and rendered in both templates. --- webadmin/forms.py | 8 ++++++++ webadmin/logs.py | 14 ++++++++++---- webadmin/routes_admin.py | 3 +++ webadmin/routes_owner.py | 3 +++ webadmin/templates/admin_edit.html | 1 + webadmin/templates/owner.html | 1 + 6 files changed, 26 insertions(+), 4 deletions(-) diff --git a/webadmin/forms.py b/webadmin/forms.py index 8c132ce..3e6b69a 100644 --- a/webadmin/forms.py +++ b/webadmin/forms.py @@ -59,6 +59,10 @@ class OwnerEditForm(FlaskForm): 'Flight-controller MAVLink sysid (0 = any) — restricts binlog ' 'reboot detection to packets from this sysid', validators=[Optional(), NumberRange(min=0, max=255)]) + tz_offset_hours = FloatField( + 'Log timezone (GMT offset in hours, fractional ok; 0 = GMT) — ' + 'sets the date folder and filename of .tlog/.bin logs', + validators=[Optional(), NumberRange(min=-12.0, max=14.0)]) reset_timestamp = BooleanField('Reset signing timestamp (recover from clock skew)') submit = SubmitField('Save') @@ -94,6 +98,10 @@ class AdminEditForm(FlaskForm): 'Flight-controller MAVLink sysid (0 = any) — restricts binlog ' 'reboot detection to packets from this sysid', validators=[Optional(), NumberRange(min=0, max=255)]) + tz_offset_hours = FloatField( + 'Log timezone (GMT offset in hours, fractional ok; 0 = GMT) — ' + 'sets the date folder and filename of .tlog/.bin logs', + validators=[Optional(), NumberRange(min=-12.0, max=14.0)]) reset_timestamp = BooleanField('Reset signing timestamp (recover from clock skew)') submit = SubmitField('Save') diff --git a/webadmin/logs.py b/webadmin/logs.py index 4ed8eb3..0713195 100644 --- a/webadmin/logs.py +++ b/webadmin/logs.py @@ -2,8 +2,12 @@ Covers both file types written under logs///: - * sessionN.tlog — raw MAVLink frame captures (KEY_FLAG_TLOG) - * sessionN.bin — ArduPilot dataflash logs over MAVLink (KEY_FLAG_BINLOG) + * .tlog — raw MAVLink frame captures (KEY_FLAG_TLOG) + * .bin — ArduPilot dataflash logs over MAVLink (KEY_FLAG_BINLOG) + +where is a YYYY_MM_DD_HH:MM:SS session-start timestamp (with an +optional "-N" collision suffix). Legacy sessionN.* names are still +accepted so older logs remain browsable. Two parallel views, sharing the listing/download helpers below: @@ -29,8 +33,10 @@ # Cover both .tlog (raw MAVLink frames) and .bin (ArduPilot dataflash # logs over MAVLink). Listing + download flow through this regex, so # broadening it surfaces .bin files alongside .tlog without further -# changes. -SESSION_RE = re.compile(r'^session\d+\.(tlog|bin)$') +# changes. Accept the current YYYY_MM_DD_HH:MM:SS[-N] timestamp names +# and the legacy sessionN names so old logs stay browsable. +SESSION_RE = re.compile( + r'^(session\d+|\d{4}_\d{2}_\d{2}_\d{2}:\d{2}:\d{2}(-\d+)?)\.(tlog|bin)$') # Natural-sort key: treat embedded digit runs as numbers so that # session10.tlog sorts AFTER session2.tlog (not between session1 and diff --git a/webadmin/routes_admin.py b/webadmin/routes_admin.py index 1e3b239..36197a0 100644 --- a/webadmin/routes_admin.py +++ b/webadmin/routes_admin.py @@ -205,6 +205,8 @@ def edit(port2): ke.log_retention_days = keydb_lib.DEFAULT_LOG_RETENTION_DAYS if form.fc_sysid.data is not None: ke.fc_sysid = int(form.fc_sysid.data) + if form.tz_offset_hours.data is not None: + ke.tz_offset_hours = float(form.tz_offset_hours.data) if form.reset_timestamp.data: ke.timestamp = 0 ke.store(db) @@ -227,6 +229,7 @@ def edit(port2): form.binlog_enabled.data = bool(ke.flags & keydb_lib.FLAG_BINLOG) form.log_retention_days.data = ke.log_retention_days form.fc_sysid.data = ke.fc_sysid + form.tz_offset_hours.data = ke.tz_offset_hours return render_template('admin_edit.html', form=form, entry=ke, delete_form=delete_form) diff --git a/webadmin/routes_owner.py b/webadmin/routes_owner.py index d31217e..dd4dffd 100644 --- a/webadmin/routes_owner.py +++ b/webadmin/routes_owner.py @@ -81,6 +81,8 @@ def me(): ke.log_retention_days = keydb_lib.DEFAULT_LOG_RETENTION_DAYS if form.fc_sysid.data is not None: ke.fc_sysid = int(form.fc_sysid.data) + if form.tz_offset_hours.data is not None: + ke.tz_offset_hours = float(form.tz_offset_hours.data) if form.reset_timestamp.data: ke.timestamp = 0 ke.store(db) @@ -101,6 +103,7 @@ def me(): form.binlog_enabled.data = bool(ke.flags & keydb_lib.FLAG_BINLOG) form.log_retention_days.data = ke.log_retention_days form.fc_sysid.data = ke.fc_sysid + form.tz_offset_hours.data = ke.tz_offset_hours active = conn_db.list_for_port2(port2) return render_template('owner.html', form=form, entry=ke, active=active, kill_form=KillForm()) diff --git a/webadmin/templates/admin_edit.html b/webadmin/templates/admin_edit.html index f4a7c2c..e69e192 100644 --- a/webadmin/templates/admin_edit.html +++ b/webadmin/templates/admin_edit.html @@ -20,6 +20,7 @@

Edit entry {{ entry.port1 }}/{{ entry.port2 }}

{{ form.binlog_enabled() }} {{ form.binlog_enabled.label }}
{{ form.log_retention_days.label }}: {{ form.log_retention_days() }}
{{ form.fc_sysid.label }}: {{ form.fc_sysid() }}
+
{{ form.tz_offset_hours.label }}: {{ form.tz_offset_hours() }}
browse logs →
{{ form.reset_timestamp() }} {{ form.reset_timestamp.label }}
{{ form.submit() }}
diff --git a/webadmin/templates/owner.html b/webadmin/templates/owner.html index afb932a..e5f9f98 100644 --- a/webadmin/templates/owner.html +++ b/webadmin/templates/owner.html @@ -55,6 +55,7 @@

My entry

{{ form.binlog_enabled() }} {{ form.binlog_enabled.label }}
{{ form.log_retention_days.label }}: {{ form.log_retention_days() }}
{{ form.fc_sysid.label }}: {{ form.fc_sysid() }}
+
{{ form.tz_offset_hours.label }}: {{ form.tz_offset_hours() }}
browse logs →
{{ form.reset_timestamp() }} {{ form.reset_timestamp.label }}
{{ form.submit() }}
From e7ac587ec34dff11aef141dc0d4b71ed8cb3d8cc Mon Sep 17 00:00:00 2001 From: Andrew Tridgell Date: Sun, 19 Jul 2026 14:32:51 +1000 Subject: [PATCH 4/9] tests: cover timestamp log names and the timezone offset Update the binlog/tlog tests to glob the timestamp-named session files instead of hardcoded sessionN paths (filtering to the session-name pattern so seeded fixtures like prefill.bin don't get mistaken for a session, and sorting by mtime since the '-N' collision suffix breaks lexical order). Switch the date-dir helpers to UTC to match the proxy's GMT-default naming. Add coverage: a .bin named by the session timestamp in a +10h entry timezone; keydb tz round-trip, formatting, and settz CLI; webadmin listing/download of timestamp (and -N suffix) names; and saving the timezone via the owner edit form. Adjust the reserved-word count assertions (15 -> 14) for the slot the timezone field claimed. --- tests/test_binlog_capture.py | 157 +++++++++++++++++++++++------- tests/test_keydb_log.py | 46 ++++++++- tests/test_tlog_capture.py | 52 ++++++---- tests/webadmin/test_log_routes.py | 57 +++++++++++ 4 files changed, 258 insertions(+), 54 deletions(-) diff --git a/tests/test_binlog_capture.py b/tests/test_binlog_capture.py index 2713c61..5a71ec1 100644 --- a/tests/test_binlog_capture.py +++ b/tests/test_binlog_capture.py @@ -21,6 +21,7 @@ import datetime import hashlib import os +import re import signal import socket import struct @@ -52,7 +53,10 @@ def _today_str(): - return datetime.datetime.now().strftime('%Y-%m-%d') + # The proxy names date dirs in the entry's log timezone; with none + # set that's GMT, so use UTC here (a local date could land in the + # wrong dir near midnight on a non-UTC host). + return time.strftime('%Y-%m-%d', time.gmtime()) @pytest.fixture @@ -134,9 +138,49 @@ def _terminate(proc): time.sleep(0.3) +# Proxy-written session .bin names: YYYY_MM_DD_HH:MM:SS[-N].bin. Used to +# distinguish real session files from test-seeded fixtures like +# prefill.bin that share the .bin suffix. +_SESSION_BIN_RE = re.compile( + r'^\d{4}_\d{2}_\d{2}_\d{2}:\d{2}:\d{2}(-\d+)?\.bin$') + + +def _bins(workdir, port_eng): + """Proxy-written session .bin files under today's dir, oldest-first. + + Filters to the timestamp naming so test-seeded fixtures (prefill.bin) + are excluded, and sorts by mtime — the '-N' collision suffix makes + lexical order unreliable ('-' < '.').""" + d = workdir / 'logs' / str(port_eng) / _today_str() + if not d.is_dir(): + return [] + fs = [p for p in d.iterdir() if _SESSION_BIN_RE.match(p.name)] + fs.sort(key=lambda p: (p.stat().st_mtime, p.name)) + return fs + + def _bin_path(workdir, port_eng, n=1): + """The n-th (1-indexed, oldest-first) .bin file, or a placeholder + path that does not exist when fewer than n files are present (so + callers' .exists() polling works unchanged).""" + fs = _bins(workdir, port_eng) + if len(fs) >= n: + return fs[n - 1] return (workdir / 'logs' / str(port_eng) / _today_str() - / ('session%d.bin' % n)) + / ('__pending_%d.bin' % n)) + + +def _wait_bin(workdir, port_eng, n=1, min_size=1, timeout=5.0): + """Poll until the n-th session .bin exists with at least min_size + bytes; return its Path, or None on timeout. Re-resolves the glob each + poll because the timestamp name isn't known ahead of time.""" + deadline = time.time() + timeout + while time.time() < deadline: + p = _bin_path(workdir, port_eng, n) + if p.exists() and p.stat().st_size >= min_size: + return p + time.sleep(0.05) + return None def _wait_for(predicate, timeout=5.0): @@ -226,6 +270,59 @@ def _recv_block_statuses(sock, timeout=2.0): reason='supportproxy binary not built') class TestBinlogCapture: + def test_bin_named_by_timestamp_in_entry_timezone(self, proxy_workdir): + """The .bin file (and its date subdir) are named by the session + timestamp formed in the entry's log timezone. With a +10h offset + the name must be ~10h ahead of the UTC wall clock.""" + db_path = str(proxy_workdir / 'keys.tdb') + db = keydb_lib.init_db(db_path) + db.transaction_start() + keydb_lib.add_entry(db, PORT_USER, PORT_ENG, 'tzbin', 'bp') + keydb_lib.set_flag(db, PORT_ENG, 'binlog') + keydb_lib.set_timezone(db, PORT_ENG, 10.0) # GMT+10 + db.transaction_prepare_commit() + db.transaction_commit() + db.close() + + proc = _start_proxy(proxy_workdir, PORT_ENG) + try: + sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM) + sock.bind(('127.0.0.1', 0)) + dest = ('127.0.0.1', PORT_USER) + utc_before = time.time() + for seq in range(3): + _send_data_block(sock, dest, seq, b'\x77' * 50) + time.sleep(0.05) + + # The date dir + file are in GMT+10, so glob the whole tree. + root = proxy_workdir / 'logs' / str(PORT_ENG) + deadline = time.time() + 5 + found = [] + while time.time() < deadline and not found: + found = list(root.glob('*/*.bin')) + time.sleep(0.05) + assert found, 'no .bin written; proxy log:\n%s' % ''.join( + proc._lines[-10:]) + base = found[0].name[:-4] # strip .bin + m = re.match( + r'^(\d{4})_(\d{2})_(\d{2})_(\d{2}):(\d{2}):(\d{2})(-\d+)?$', + base) + assert m, 'bad timestamp basename: %r' % base + # Reconstruct the named epoch (interpreted as GMT+10) and check + # it matches now+10h within a small window. + import calendar + named = calendar.timegm((int(m[1]), int(m[2]), int(m[3]), + int(m[4]), int(m[5]), int(m[6]), 0, 0, 0)) + expected = utc_before + 10 * 3600 + assert abs(named - expected) < 5, \ + 'named %s (%d) not ~10h ahead of UTC %d' % ( + base, named, utc_before) + # date subdir agrees with the filename's date + assert found[0].parent.name == '%s-%s-%s' % (m[1], m[2], m[3]) + sock.close() + finally: + _terminate(proc) + def test_data_blocks_land_in_bin_file(self, proxy_workdir): _setup_db(proxy_workdir, PORT_USER, PORT_ENG, 'bintest', 'bp', 'binlog') @@ -550,10 +647,10 @@ def test_bin_parses_with_dfreader(self, proxy_workdir): _terminate(proc) def test_paired_session_n_with_tlog(self, proxy_workdir): - """tlog + binlog flags both set on one entry should produce - sessionN.tlog and sessionN.bin sharing the same N. We drive - traffic from a single raw socket (sending DATA_BLOCKs) so the - proxy's connect() on first peer doesn't lock us out of + """tlog + binlog flags both set on one entry should produce a + .tlog and a .bin sharing the same timestamp basename. We + drive traffic from a single raw socket (sending DATA_BLOCKs) so + the proxy's connect() on first peer doesn't lock us out of subsequent sends. DATA_BLOCK frames are valid MAVLink, so they trip the tlog tap @@ -590,11 +687,14 @@ def test_paired_session_n_with_tlog(self, proxy_workdir): date_dir = (proxy_workdir / 'logs' / str(PORT_ENG_PAIR) / _today_str()) files = sorted(p.name for p in date_dir.iterdir()) - assert (date_dir / 'session1.tlog').exists(), \ - 'no session1.tlog; have %r' % files - assert (date_dir / 'session1.bin').exists(), \ - 'no session1.bin; have %r\nproxy log:\n%s' % ( + tlogs = [p.name[:-5] for p in date_dir.glob('*.tlog')] + bins = [p.name[:-4] for p in date_dir.glob('*.bin')] + assert len(tlogs) == 1 and len(bins) == 1, \ + 'expected one .tlog and one .bin; have %r\nproxy log:\n%s' % ( files, ''.join(getattr(proc, '_lines', []))) + # paired: the .tlog and .bin share the timestamp basename + assert tlogs[0] == bins[0], \ + 'paired basenames differ: %r vs %r' % (tlogs[0], bins[0]) finally: _terminate(proc) @@ -902,10 +1002,8 @@ def test_quota_breach_triggers_immediate_cleanup(self, proxy_workdir): # the write lands. _send_data_block(sock, dest, 0, b'\xaa' * 50) - bin_path = _bin_path(proxy_workdir, PORT_ENG) - assert _wait_for( - lambda: bin_path.exists() and bin_path.stat().st_size >= 200, - timeout=5.0), \ + assert _wait_bin(proxy_workdir, PORT_ENG, min_size=200) \ + is not None, \ 'write did not proceed after quota breach; proxy log:\n%s' \ % ''.join(proc._lines[-10:]) assert not prefilled.exists(), \ @@ -936,10 +1034,8 @@ def test_quota_boundary_prospective_breach_frees(self, proxy_workdir): dest = ('127.0.0.1', PORT_USER) _send_data_block(sock, dest, 0, b'\xaa' * 50) - bin_path = _bin_path(proxy_workdir, PORT_ENG) - assert _wait_for( - lambda: bin_path.exists() and bin_path.stat().st_size >= 200, - timeout=5.0), \ + assert _wait_bin(proxy_workdir, PORT_ENG, min_size=200) \ + is not None, \ 'boundary breach never freed; proxy log:\n%s' \ % ''.join(proc._lines[-10:]) assert not prefilled.exists(), \ @@ -972,11 +1068,8 @@ def test_sparse_forward_jump_not_charged_as_logical_size( _send_data_block(sock, dest, 0, b'\xaa' * 50) _send_data_block(sock, dest, 1600, b'\xbb' * 50) - bin_path = _bin_path(proxy_workdir, PORT_ENG) - assert _wait_for( - lambda: bin_path.exists() - and bin_path.stat().st_size == 1600 * 200 + 200, - timeout=5.0), \ + assert _wait_bin(proxy_workdir, PORT_ENG, + min_size=1600 * 200 + 200) is not None, \ 'sparse jump falsely tripped the quota; proxy log:\n%s' \ % ''.join(proc._lines[-10:]) @@ -1101,10 +1194,8 @@ def test_instream_seqno0_restart_rotates(self, proxy_workdir): _send_data_block(sock, dest, 0, b'\x33' * 50) _send_data_block(sock, dest, 1, b'\x33' * 50) - session2 = _bin_path(proxy_workdir, PORT_ENG, n=2) - assert _wait_for( - lambda: session2.exists() and session2.stat().st_size >= 400, - timeout=5.0), \ + assert _wait_bin(proxy_workdir, PORT_ENG, n=2, min_size=400) \ + is not None, \ 'no rotation on in-stream seqno=0; proxy log:\n%s' \ % ''.join(proc._lines[-10:]) @@ -1161,10 +1252,8 @@ def test_midstream_vehicle_gets_stop_nudge(self, proxy_workdir): # START restarts it from seqno 0 — data must now land. _send_data_block(sock, dest, 0, b'\x55' * 50) _send_data_block(sock, dest, 1, b'\x55' * 50) - bin_path = _bin_path(proxy_workdir, PORT_ENG) - assert _wait_for( - lambda: bin_path.exists() and bin_path.stat().st_size >= 400, - timeout=5.0), 'restart from seqno 0 did not open the file' + assert _wait_bin(proxy_workdir, PORT_ENG, min_size=400) \ + is not None, 'restart from seqno 0 did not open the file' sock.close() finally: @@ -1183,10 +1272,8 @@ def test_malformed_quota_env_ignored(self, proxy_workdir): dest = ('127.0.0.1', PORT_USER) _send_data_block(sock, dest, 0, b'\xaa' * 50) - bin_path = _bin_path(proxy_workdir, PORT_ENG) - assert _wait_for( - lambda: bin_path.exists() and bin_path.stat().st_size >= 200, - timeout=5.0), \ + assert _wait_bin(proxy_workdir, PORT_ENG, min_size=200) \ + is not None, \ "writes blocked - '1GB' was prefix-parsed; proxy log:\n%s" \ % ''.join(proc._lines[-10:]) sock.close() diff --git a/tests/test_keydb_log.py b/tests/test_keydb_log.py index 5ea315e..8090780 100644 --- a/tests/test_keydb_log.py +++ b/tests/test_keydb_log.py @@ -44,7 +44,8 @@ def test_pack_unpack_roundtrip(): assert e2.flags == keydb_lib.FLAG_TLOG | keydb_lib.FLAG_ADMIN # float32 quantisation: tolerate ~1e-7 relative error assert abs(e2.log_retention_days - 0.0001) < 1e-7 - assert e2.reserved == [0] * 15 + assert e2.tz_offset_hours == 0.0 + assert e2.reserved == [0] * 14 def test_legacy_104byte_record_zero_extends(): @@ -69,7 +70,8 @@ def test_legacy_104byte_record_zero_extends(): assert decoded.flags == keydb_lib.FLAG_ADMIN assert decoded.log_retention_days == 0.0 assert decoded.fc_sysid == 0 - assert decoded.reserved == [0] * 15 + assert decoded.tz_offset_hours == 0.0 + assert decoded.reserved == [0] * 14 # Re-pack: should emit the full 168-byte modern layout. re = decoded.pack() @@ -307,3 +309,43 @@ def test_legacy_104byte_record_decodes_fc_sysid_zero(tmp_path): decoded = keydb_lib.KeyEntry(0) decoded.unpack(legacy) assert decoded.fc_sysid == 0 + + +def test_tz_offset_round_trip(): + e = keydb_lib.KeyEntry(21002) + e.port1 = 21001 + e.tz_offset_hours = 5.5 + e2 = keydb_lib.KeyEntry(0) + e2.unpack(e.pack()) + assert abs(e2.tz_offset_hours - 5.5) < 1e-6 + assert e2.reserved == [0] * 14 + + +def test_format_tz_offset(): + assert keydb_lib.format_tz_offset(0) == 'GMT' + assert keydb_lib.format_tz_offset(5.5) == 'GMT+05:30' + assert keydb_lib.format_tz_offset(-3.75) == 'GMT-03:45' + assert keydb_lib.format_tz_offset(14) == 'GMT+14:00' + + +def test_cli_settz_and_list(tmp_path): + p = str(tmp_path / 'keys.tdb') + assert _run_cli(p, 'initialise').returncode == 0 + assert _run_cli(p, 'add', '22001', '22002', 'CliTz', 'pw').returncode == 0 + r = _run_cli(p, 'settz', '22002', '5.5') + assert r.returncode == 0, r.stderr + assert 'GMT+05:30' in r.stdout + r = _run_cli(p, 'list') + assert 'tz=GMT+05:30' in r.stdout + # back to GMT (0) drops the display + assert _run_cli(p, 'settz', '22002', '0').returncode == 0 + assert 'tz=' not in _run_cli(p, 'list').stdout + + +def test_cli_settz_rejects_out_of_range(tmp_path): + p = str(tmp_path / 'keys.tdb') + _run_cli(p, 'initialise') + _run_cli(p, 'add', '23001', '23002', 'CliTzBad', 'pw') + r = _run_cli(p, 'settz', '23002', '20') + assert r.returncode == 1 + assert 'must be in' in r.stdout diff --git a/tests/test_tlog_capture.py b/tests/test_tlog_capture.py index d1763d4..a6ba197 100644 --- a/tests/test_tlog_capture.py +++ b/tests/test_tlog_capture.py @@ -4,10 +4,10 @@ starts supportproxy there, drives a few HEARTBEATs in each direction, kills the proxy, and asserts: - * logs///session1.tlog exists, is non-empty, and parses + * logs///.tlog exists, is non-empty, and parses with pymavlink.mavutil.mavlink_connection - * a second connection (after the first child idles out) produces - session2.tlog + * a second connection (after the first child idles out) produces a + second .tlog * timestamps in the tlog are monotonic * messages from BOTH directions appear (at minimum, both sides' HEARTBEATs are seen) @@ -43,8 +43,29 @@ def _today_str(): - """Match the proxy's localtime-based directory naming.""" - return datetime.datetime.now().strftime('%Y-%m-%d') + """Match the proxy's date-dir naming. With no per-entry timezone set + the proxy names in GMT, so use UTC here (a local date would land in + the wrong dir near midnight on a non-UTC host).""" + return time.strftime('%Y-%m-%d', time.gmtime()) + + +def _tlogs(workdir, port_eng): + """All .tlog files under today's dir for port_eng, oldest-first.""" + d = workdir / 'logs' / str(port_eng) / _today_str() + if not d.is_dir(): + return [] + fs = [p for p in d.iterdir() if p.suffix == '.tlog'] + fs.sort(key=lambda p: (p.stat().st_mtime, p.name)) + return fs + + +def _only_tlog(workdir, port_eng): + """The single .tlog for this session, or a placeholder path that + doesn't exist yet.""" + fs = _tlogs(workdir, port_eng) + if fs: + return fs[0] + return workdir / 'logs' / str(port_eng) / _today_str() / '__pending.tlog' @pytest.fixture @@ -224,10 +245,9 @@ def test_session1_created_with_bidirectional_traffic(self, proxy_workdir): finally: _terminate(proc) - tlog = (proxy_workdir / 'logs' / str(PORT_ENG) - / _today_str() / 'session1.tlog') - assert tlog.exists(), 'expected %s to exist; proxy stdout: %s' % ( - tlog, ''.join(getattr(proc, '_lines', []))) + tlog = _only_tlog(proxy_workdir, PORT_ENG) + assert tlog.exists(), 'expected a .tlog to exist; proxy stdout: %s' % ( + ''.join(getattr(proc, '_lines', []))) assert tlog.stat().st_size > 0 # Validate every record has a sane framed packet behind its 8-byte ts. @@ -263,8 +283,7 @@ def test_pymavlink_can_read_tlog(self, proxy_workdir): finally: _terminate(proc) - tlog = (proxy_workdir / 'logs' / str(PORT_ENG) - / _today_str() / 'session1.tlog') + tlog = _only_tlog(proxy_workdir, PORT_ENG) assert tlog.exists() msgs = _parse_tlog_with_pymavlink(str(tlog)) # We sent at minimum a few HEARTBEATs each way; pymavlink should @@ -302,11 +321,10 @@ def test_user_only_traffic_records_to_tlog(self, proxy_workdir): finally: _terminate(proc) - tlog = (proxy_workdir / 'logs' / str(PORT_ENG) - / _today_str() / 'session1.tlog') + tlog = _only_tlog(proxy_workdir, PORT_ENG) proxy_log = ''.join(getattr(proc, '_lines', [])) assert tlog.exists(), \ - ('session1.tlog missing — user-only traffic was discarded.\n' + ('.tlog missing — user-only traffic was discarded.\n' 'sent %d heartbeats. proxy log:\n%s' % (n_sent, proxy_log)) assert tlog.stat().st_size > 0, \ 'tlog is empty; parse loop did not write the user frames' @@ -342,8 +360,8 @@ def test_second_connection_creates_session2(self, proxy_workdir): date_dir = proxy_workdir / 'logs' / str(PORT_ENG) / _today_str() proxy_log = ''.join(getattr(proc, '_lines', [])) - assert (date_dir / 'session1.tlog').exists(), proxy_log - assert (date_dir / 'session2.tlog').exists(), ( - 'expected session2.tlog after second connection; have %r\n' + tlogs = _tlogs(proxy_workdir, PORT_ENG) + assert len(tlogs) == 2, ( + 'expected two .tlog files after a second connection; have %r\n' 'proxy log:\n%s' % ( sorted(p.name for p in date_dir.iterdir()), proxy_log)) diff --git a/tests/webadmin/test_log_routes.py b/tests/webadmin/test_log_routes.py index a629a1b..72327c4 100644 --- a/tests/webadmin/test_log_routes.py +++ b/tests/webadmin/test_log_routes.py @@ -192,6 +192,27 @@ def test_admin_can_set_fractional(self, client, keydb_path): ke = fetch_entry(keydb_path, ALICE_PORT2) assert ke.log_retention_days == 0.5 + def test_owner_can_set_timezone(self, client, keydb_path): + login_as(client, ALICE_PORT1, ALICE_PASS) + client.post('/me/', data={ + 'name': 'alice', + 'tz_offset_hours': '5.5', + 'submit': 'Save', + }) + ke = fetch_entry(keydb_path, ALICE_PORT2) + assert abs(ke.tz_offset_hours - 5.5) < 1e-6 + + def test_owner_timezone_out_of_range_rejected(self, client, keydb_path): + login_as(client, ALICE_PORT1, ALICE_PASS) + r = client.post('/me/', data={ + 'name': 'alice', + 'tz_offset_hours': '20', + 'submit': 'Save', + }) + # form validation fails -> re-render, value not stored + ke = fetch_entry(keydb_path, ALICE_PORT2) + assert ke.tz_offset_hours == 0.0 + # --------------------------------------------------------------------------- # listing & download @@ -302,6 +323,42 @@ def test_bogus_extension_still_404s(self, client, logs_dir): assert r.status_code == 404 +class TestTimestampNames: + """Session files are named by YYYY_MM_DD_HH:MM:SS timestamp now. + The listing regex must accept them (with the ':' in the name) and + downloads must work despite the colons in the URL path.""" + + TS = '2026_07_19_09:37:10' + + def test_timestamp_names_listed(self, client, keydb_path, logs_dir): + seed_session(logs_dir, ALICE_PORT2, '2026-07-19', + self.TS + '.tlog', content=b'TLOG') + seed_session(logs_dir, ALICE_PORT2, '2026-07-19', + self.TS + '.bin', content=b'BIN') + login_as(client, ALICE_PORT1, ALICE_PASS) + r = client.get('/me/logs/2026-07-19/') + assert r.status_code == 200 + assert (self.TS + '.tlog').encode() in r.data + assert (self.TS + '.bin').encode() in r.data + + def test_timestamp_name_downloads(self, client, keydb_path, logs_dir): + seed_session(logs_dir, ALICE_PORT2, '2026-07-19', + self.TS + '.bin', content=b'\x00ARDUPILOT') + login_as(client, ALICE_PORT1, ALICE_PASS) + r = client.get('/me/logs/2026-07-19/' + self.TS + '.bin') + assert r.status_code == 200 + assert r.data.endswith(b'ARDUPILOT') + + def test_collision_suffix_name_ok(self, client, keydb_path, logs_dir): + seed_session(logs_dir, ALICE_PORT2, '2026-07-19', + self.TS + '-2.tlog', content=b'X') + login_as(client, ALICE_PORT1, ALICE_PASS) + r = client.get('/me/logs/2026-07-19/') + assert (self.TS + '-2.tlog').encode() in r.data + r = client.get('/me/logs/2026-07-19/' + self.TS + '-2.tlog') + assert r.status_code == 200 + + class TestTlogDownloadCacheHeaders: """Tlog payloads contain raw vehicle telemetry. They must not be cached by browsers or intermediaries — even though the rest of From 581bf1ab1fa154f0c8eb47e511a613f5ff1cfea4 Mon Sep 17 00:00:00 2001 From: Andrew Tridgell Date: Sun, 19 Jul 2026 19:19:22 +1000 Subject: [PATCH 5/9] keydb: gate the log timezone behind a use_tz flag; reject non-finite MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Add KEY_FLAG_USE_TZ: when set, logs are named with the fixed tz_offset_hours GMT offset; when clear (the default, and what legacy records get) they are named in the server's own local timezone — so an existing install keeps its local-time naming with no migration, and 0 is a genuine GMT offset only when the flag is on. settz sets the offset and enables the flag; clear the flag to revert to local without losing the value. Validate the offset with math.isfinite() (NaN slips past plain range checks) and render a non-finite value as 'invalid'. (supersedes the earlier '0 = server local' approach; found by review.) --- keydb.h | 3 ++- keydb.py | 3 ++- keydb_lib.py | 34 +++++++++++++++++++++++++++------- 3 files changed, 31 insertions(+), 9 deletions(-) diff --git a/keydb.h b/keydb.h index 136fb61..e75ccd0 100644 --- a/keydb.h +++ b/keydb.h @@ -33,6 +33,7 @@ #define KEY_FLAG_BIDI_SIGN (1u << 1) // require signed MAVLink on the user side too #define KEY_FLAG_TLOG (1u << 2) // record per-connection MAVProxy-format tlogs #define KEY_FLAG_BINLOG (1u << 3) // record ArduPilot bin logs over MAVLink +#define KEY_FLAG_USE_TZ (1u << 4) // name logs with tz_offset_hours; else server local struct KeyEntry { uint64_t magic; @@ -46,7 +47,7 @@ struct KeyEntry { uint32_t flags; float log_retention_days; // tlog + bin; 0.0 = forever; fractional values allowed for tests uint32_t fc_sysid; // 0 = match any; otherwise only monitor packets from this MAVLink sysid (binlog reboot detection) - float tz_offset_hours; // log naming: offset from GMT in hours (fractional allowed); 0 = GMT + float tz_offset_hours; // log naming: GMT offset in hours (fractional allowed), used only when KEY_FLAG_USE_TZ is set uint32_t reserved[14]; }; diff --git a/keydb.py b/keydb.py index 6e0d0cc..bb2c7f7 100755 --- a/keydb.py +++ b/keydb.py @@ -139,7 +139,8 @@ def main(): elif args.action == "settz": _expect(args.args, 2, "keydb.py settz PORT2 HOURS " - "(GMT offset in hours, fractional ok; 0 = GMT)") + "(GMT offset in hours, fractional ok; enables use_tz. " + "Clear the use_tz flag to revert to server-local naming.)") try: hours = float(args.args[1]) except ValueError: diff --git a/keydb_lib.py b/keydb_lib.py index 6c016a2..80c7a64 100644 --- a/keydb_lib.py +++ b/keydb_lib.py @@ -12,6 +12,7 @@ import errno import hashlib import hmac +import math import os import struct import time @@ -41,12 +42,14 @@ FLAG_BIDI_SIGN = 1 << 1 # require signed MAVLink on the user side too FLAG_TLOG = 1 << 2 # record per-connection MAVProxy-format tlogs FLAG_BINLOG = 1 << 3 # record ArduPilot bin logs over MAVLink +FLAG_USE_TZ = 1 << 4 # name logs with tz_offset_hours; else server local FLAG_NAMES = { "admin": FLAG_ADMIN, "bidi_sign": FLAG_BIDI_SIGN, "tlog": FLAG_TLOG, "binlog": FLAG_BINLOG, + "use_tz": FLAG_USE_TZ, } DEFAULT_LOG_RETENTION_DAYS = 7.0 @@ -54,17 +57,24 @@ # Timezone offset is a plain GMT offset in hours (fractional allowed, e.g. -# 5.5 for IST, -3.5 for Newfoundland). We deliberately store an offset -# rather than a named zone: a fixed offset is unambiguous and DST-free, -# which is what a log-naming convention wants (a name would need the full -# tz database plus DST handling that shifts mid-session). The offset drives +# 5.5 for IST, -3.75 for Chatham). We deliberately store an offset rather +# than a named zone: a fixed offset is unambiguous and DST-free, which is +# what a log-naming convention wants (a name would need the full tz +# database plus DST handling that shifts mid-session). The offset drives # both the YYYY-MM-DD date subdir and the YYYY_MM_DD_HH:MM:SS filename. +# +# The offset is only used when the KEY_FLAG_USE_TZ flag is set; otherwise +# logs are named in the server's own local timezone (the default, and +# what legacy records — flag clear — get, matching the pre-timestamp +# behaviour). 0 with the flag set is a genuine GMT offset. TZ_MIN_OFFSET = -12.0 TZ_MAX_OFFSET = 14.0 def format_tz_offset(hours): """Render a GMT offset as e.g. 'GMT+05:30', 'GMT-03:45', 'GMT'.""" + if not math.isfinite(hours): + return 'invalid' if not hours: return 'GMT' sign = '+' if hours >= 0 else '-' @@ -180,8 +190,12 @@ def __str__(self): if self.fc_sysid: sysstr = ' fc_sysid=%u' % self.fc_sysid tzstr = '' - if self.tz_offset_hours: + if self.flags & FLAG_USE_TZ: tzstr = ' tz=%s' % format_tz_offset(self.tz_offset_hours) + elif self.tz_offset_hours: + # offset stored but not active — show it parenthesised so it + # is clear the server-local default is in effect + tzstr = ' tz=local(%s off)' % format_tz_offset(self.tz_offset_hours) return ("%u/%u '%s' counts=%u/%u connections=%u ts=%u%s%s%s%s" % (self.port1, self.port2, self.name, self.count1, self.count2, self.connections, @@ -376,15 +390,21 @@ def set_log_retention(db, port2, days): def set_timezone(db, port2, hours): - """Set the per-entry log-naming timezone as a GMT offset in hours - (fractional allowed). Affects the date subdir and the log filename.""" + """Set the per-entry log-naming GMT offset (hours, fractional) and + enable its use (KEY_FLAG_USE_TZ). Setting a timezone means you want + it applied; clear the 'use_tz' flag to revert to server-local naming + without discarding the stored offset.""" ke = KeyEntry(port2) if not ke.fetch(db): raise CLIError("No entry for port2 %d" % port2) + if not math.isfinite(hours): + raise CLIError("timezone offset must be a finite number (got %r)" + % hours) if hours < TZ_MIN_OFFSET or hours > TZ_MAX_OFFSET: raise CLIError("timezone offset must be in %g..%g hours (got %r)" % (TZ_MIN_OFFSET, TZ_MAX_OFFSET, hours)) ke.tz_offset_hours = float(hours) + ke.flags |= FLAG_USE_TZ ke.store(db) return ke From cd7af65fa658e617c3860bb88918df18ca90fb69 Mon Sep 17 00:00:00 2001 From: Andrew Tridgell Date: Sun, 19 Jul 2026 19:19:22 +1000 Subject: [PATCH 6/9] logging: flag-gated timezone naming; harden session naming session_time_strings takes a use_offset flag: true applies the fixed GMT offset via gmtime (no DST), false formats in the server's local timezone. supportproxy derives it from KEY_FLAG_USE_TZ and threads it (plus the offset) to the tlog/binlog writers; binlog's reboot rotation carries both. Guard the localtime_r/gmtime_r NULL return, and make session_unique_basename fall back to a pid+nanosecond suffix rather than ever returning an occupied basename when the -2..-999 range is exhausted (which would truncate/append into another session's log). Found by review (codex). --- binlog.cpp | 2 +- binlog.h | 14 ++++++++++---- session.cpp | 39 ++++++++++++++++++++++++++++++--------- session.h | 16 ++++++++++------ supportproxy.cpp | 5 +++-- 5 files changed, 54 insertions(+), 22 deletions(-) diff --git a/binlog.cpp b/binlog.cpp index 62ec13d..e33787a 100644 --- a/binlog.cpp +++ b/binlog.cpp @@ -601,7 +601,7 @@ bool BinlogWriter::rotate_for_reboot() // blocks can't sparse-write into the new file. The open() happens // lazily in handle_block using the new datedir_/name_. char datedir[16], name[64]; - session_time_strings(time(nullptr), tz_offset_hours_, + session_time_strings(time(nullptr), tz_use_offset_, tz_offset_hours_, datedir, sizeof(datedir), name, sizeof(name)); session_unique_basename(base_dir_.c_str(), port2_, datedir, name, sizeof(name)); diff --git a/binlog.h b/binlog.h index 29b2e84..44b9404 100644 --- a/binlog.h +++ b/binlog.h @@ -59,10 +59,14 @@ class BinlogWriter { } /* - Log-naming timezone (GMT offset in hours) for the reboot-rotated - file's name. Sourced from KeyEntry.tz_offset_hours at fork. + Log-naming timezone for the reboot-rotated file's name: whether to + apply the fixed GMT offset (KEY_FLAG_USE_TZ) and the offset itself. + Sourced from the KeyEntry at fork. */ - void set_tz(double offset_hours) { tz_offset_hours_ = offset_hours; } + void set_tz(bool use_offset, double offset_hours) { + tz_use_offset_ = use_offset; + tz_offset_hours_ = offset_hours; + } /* Decode a REMOTE_LOG_DATA_BLOCK message and process it. @@ -273,7 +277,9 @@ class BinlogWriter { // rotate_for_reboot() for the post-reboot file. std::string datedir_; std::string name_; - // Log-naming timezone (GMT offset in hours) for rotate's new name. + // Log-naming timezone for rotate's new name: whether the fixed GMT + // offset is in use (KEY_FLAG_USE_TZ) and its value. + bool tz_use_offset_ = false; double tz_offset_hours_ = 0.0; // Current size of fp (= the largest seqno+1 we've written * 200). diff --git a/session.cpp b/session.cpp index d38a1aa..9a7fe3a 100644 --- a/session.cpp +++ b/session.cpp @@ -11,6 +11,7 @@ #include #include #include +#include int mkpath_0700(const char *path) { @@ -30,15 +31,30 @@ int mkpath_0700(const char *path) return 0; } -void session_time_strings(time_t utc, double tz_offset_hours, +void session_time_strings(time_t utc, bool use_offset, double tz_offset_hours, char *datedir, size_t datedir_len, char *name, size_t name_len) { - // Apply the offset then format with gmtime, so the machine's local - // timezone plays no part — offset 0 is GMT. - time_t shifted = utc + (time_t)llround(tz_offset_hours * 3600.0); - struct tm tm; - gmtime_r(&shifted, &tm); + struct tm tm {}; + struct tm *r; + if (use_offset && isfinite(tz_offset_hours)) { + // Explicit fixed GMT offset: apply it then format with gmtime so + // the machine's own timezone plays no part. No DST — a fixed + // offset by design. + time_t shifted = utc + (time_t)llround(tz_offset_hours * 3600.0); + r = gmtime_r(&shifted, &tm); + } else { + // Default (KEY_FLAG_USE_TZ clear, or a non-finite offset): name + // in the server's local timezone, as configured on the host — + // the least-surprising default and what the pre-timestamp + // naming did. + r = localtime_r(&utc, &tm); + } + if (r == nullptr) { + // gmtime_r/localtime_r only fail on absurd inputs; format a + // zeroed tm rather than uninitialised stack. + memset(&tm, 0, sizeof(tm)); + } snprintf(datedir, datedir_len, "%04d-%02d-%02d", tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday); @@ -73,7 +89,12 @@ void session_unique_basename(const char *base_dir, uint32_t port2, return; } } - // 1000 collisions in one second/dir is not going to happen; keep the - // plain base rather than loop forever. - snprintf(name, name_len, "%s", base); + // 1000 collisions in one second/dir cannot happen in practice, but + // never return an occupied basename (that would truncate/append into + // another session's log). A pid+nanosecond suffix can't match any of + // the "-N" candidates above, so it stays unique. + struct timespec ts {}; + clock_gettime(CLOCK_REALTIME, &ts); + snprintf(name, name_len, "%s-%d-%09ld", + base, int(getpid()), long(ts.tv_nsec)); } diff --git a/session.h b/session.h index 8ff3788..2c23cb2 100644 --- a/session.h +++ b/session.h @@ -6,7 +6,9 @@ start. A child fork that records both kinds computes one and passes it to both writers, so the .tlog and .bin sit next to each other with matching names. The date subdir and the filename are both - formed in the entry's log-naming timezone (a GMT offset in hours). + formed in the entry's log-naming timezone: an explicit GMT offset in + hours, or — when the offset is 0/unset (the default) — the server's + own local timezone. */ #pragma once @@ -24,12 +26,14 @@ int mkpath_0700(const char *path); /* Format the date subdir ("YYYY-MM-DD") and the log basename - ("YYYY_MM_DD_HH:MM:SS") for the UTC time `utc` shifted by - tz_offset_hours (fractional hours allowed). The shifted time is - formatted with gmtime so the machine's own timezone never affects - naming — an offset of 0 yields GMT/UTC. + ("YYYY_MM_DD_HH:MM:SS") for the UTC time `utc`. When `use_offset` is + true the finite tz_offset_hours (fractional allowed) is applied and + formatted with gmtime, so the host timezone never affects naming (a + fixed offset, no DST). When false, the time is formatted in the + server's own local timezone — the default when KEY_FLAG_USE_TZ is + clear. */ -void session_time_strings(time_t utc, double tz_offset_hours, +void session_time_strings(time_t utc, bool use_offset, double tz_offset_hours, char *datedir, size_t datedir_len, char *name, size_t name_len); diff --git a/supportproxy.cpp b/supportproxy.cpp index 38c1fd0..c0eecab 100644 --- a/supportproxy.cpp +++ b/supportproxy.cpp @@ -290,9 +290,10 @@ static void main_loop(struct listen_port *p) // regardless of which writer activates first or whether one never // does. Made unique up front so a same-second session start doesn't // clobber an existing file. + const bool use_tz = (p->flags & KEY_FLAG_USE_TZ) != 0; char log_datedir[16]; char log_name[64]; - session_time_strings(time(nullptr), p->tz_offset_hours, + session_time_strings(time(nullptr), use_tz, p->tz_offset_hours, log_datedir, sizeof(log_datedir), log_name, sizeof(log_name)); session_unique_basename("logs", uint32_t(p->port2), log_datedir, @@ -336,7 +337,7 @@ static void main_loop(struct listen_port *p) binlog.set_fc_sysid_filter(p->fc_sysid); // Timezone (for the reboot-rotated file's timestamp name) and // the shared session paths for the initial lazy open. - binlog.set_tz(p->tz_offset_hours); + binlog.set_tz(use_tz, p->tz_offset_hours); binlog.set_session_paths(log_datedir, log_name); } // Tap helper: returns true if the message was consumed by binlog From 93f820e66aad2987c95ba8e512405514748fa334 Mon Sep 17 00:00:00 2001 From: Andrew Tridgell Date: Sun, 19 Jul 2026 19:19:22 +1000 Subject: [PATCH 7/9] webadmin: use_tz checkbox; order collision suffixes chronologically Add a 'Name logs in a fixed timezone' checkbox (KEY_FLAG_USE_TZ) beside the offset field on the owner and admin edit forms, wired through both routes and templates. Also normalise an unsuffixed timestamp name to an implicit '-1' in the listing sort key so a same-second original lists before its '-N' collision siblings (lexically '-' < '.'). Found by review (codex). --- webadmin/forms.py | 10 ++++++++-- webadmin/logs.py | 11 +++++++++++ webadmin/routes_admin.py | 5 +++++ webadmin/routes_owner.py | 5 +++++ webadmin/templates/admin_edit.html | 1 + webadmin/templates/owner.html | 1 + 6 files changed, 31 insertions(+), 2 deletions(-) diff --git a/webadmin/forms.py b/webadmin/forms.py index 3e6b69a..8efab84 100644 --- a/webadmin/forms.py +++ b/webadmin/forms.py @@ -59,9 +59,12 @@ class OwnerEditForm(FlaskForm): 'Flight-controller MAVLink sysid (0 = any) — restricts binlog ' 'reboot detection to packets from this sysid', validators=[Optional(), NumberRange(min=0, max=255)]) + use_tz = BooleanField( + 'Name logs in a fixed timezone (below) instead of the server\'s ' + 'local time') tz_offset_hours = FloatField( 'Log timezone (GMT offset in hours, fractional ok; 0 = GMT) — ' - 'sets the date folder and filename of .tlog/.bin logs', + 'used only when the box above is ticked', validators=[Optional(), NumberRange(min=-12.0, max=14.0)]) reset_timestamp = BooleanField('Reset signing timestamp (recover from clock skew)') submit = SubmitField('Save') @@ -98,9 +101,12 @@ class AdminEditForm(FlaskForm): 'Flight-controller MAVLink sysid (0 = any) — restricts binlog ' 'reboot detection to packets from this sysid', validators=[Optional(), NumberRange(min=0, max=255)]) + use_tz = BooleanField( + 'Name logs in a fixed timezone (below) instead of the server\'s ' + 'local time') tz_offset_hours = FloatField( 'Log timezone (GMT offset in hours, fractional ok; 0 = GMT) — ' - 'sets the date folder and filename of .tlog/.bin logs', + 'used only when the box above is ticked', validators=[Optional(), NumberRange(min=-12.0, max=14.0)]) reset_timestamp = BooleanField('Reset signing timestamp (recover from clock skew)') submit = SubmitField('Save') diff --git a/webadmin/logs.py b/webadmin/logs.py index 0713195..2e3da2a 100644 --- a/webadmin/logs.py +++ b/webadmin/logs.py @@ -45,8 +45,19 @@ # digit chunks. _NATKEY_RE = re.compile(r'(\d+)') +# A timestamp session name, with an optional "-N" collision suffix. An +# unsuffixed file is the original for that second and must sort BEFORE +# its "-N" siblings — but lexically "-" < ".", so "-2.bin" would +# otherwise beat ".bin". Normalise the unsuffixed name to "-1" for +# the sort key so the numeric suffix orders it correctly. +_TS_NAME_RE = re.compile( + r'^(\d{4}_\d{2}_\d{2}_\d{2}:\d{2}:\d{2})(-\d+)?(\.\w+)$') + def _natural_key(name): + m = _TS_NAME_RE.match(name) + if m and not m.group(2): + name = m.group(1) + '-1' + m.group(3) return [int(tok) if tok.isdigit() else tok.lower() for tok in _NATKEY_RE.split(name)] diff --git a/webadmin/routes_admin.py b/webadmin/routes_admin.py index 36197a0..97463b4 100644 --- a/webadmin/routes_admin.py +++ b/webadmin/routes_admin.py @@ -207,6 +207,10 @@ def edit(port2): ke.fc_sysid = int(form.fc_sysid.data) if form.tz_offset_hours.data is not None: ke.tz_offset_hours = float(form.tz_offset_hours.data) + if form.use_tz.data: + ke.flags |= keydb_lib.FLAG_USE_TZ + else: + ke.flags &= ~keydb_lib.FLAG_USE_TZ if form.reset_timestamp.data: ke.timestamp = 0 ke.store(db) @@ -230,6 +234,7 @@ def edit(port2): form.log_retention_days.data = ke.log_retention_days form.fc_sysid.data = ke.fc_sysid form.tz_offset_hours.data = ke.tz_offset_hours + form.use_tz.data = bool(ke.flags & keydb_lib.FLAG_USE_TZ) return render_template('admin_edit.html', form=form, entry=ke, delete_form=delete_form) diff --git a/webadmin/routes_owner.py b/webadmin/routes_owner.py index dd4dffd..028b3db 100644 --- a/webadmin/routes_owner.py +++ b/webadmin/routes_owner.py @@ -83,6 +83,10 @@ def me(): ke.fc_sysid = int(form.fc_sysid.data) if form.tz_offset_hours.data is not None: ke.tz_offset_hours = float(form.tz_offset_hours.data) + if form.use_tz.data: + ke.flags |= keydb_lib.FLAG_USE_TZ + else: + ke.flags &= ~keydb_lib.FLAG_USE_TZ if form.reset_timestamp.data: ke.timestamp = 0 ke.store(db) @@ -104,6 +108,7 @@ def me(): form.log_retention_days.data = ke.log_retention_days form.fc_sysid.data = ke.fc_sysid form.tz_offset_hours.data = ke.tz_offset_hours + form.use_tz.data = bool(ke.flags & keydb_lib.FLAG_USE_TZ) active = conn_db.list_for_port2(port2) return render_template('owner.html', form=form, entry=ke, active=active, kill_form=KillForm()) diff --git a/webadmin/templates/admin_edit.html b/webadmin/templates/admin_edit.html index e69e192..0870eb6 100644 --- a/webadmin/templates/admin_edit.html +++ b/webadmin/templates/admin_edit.html @@ -20,6 +20,7 @@

Edit entry {{ entry.port1 }}/{{ entry.port2 }}

{{ form.binlog_enabled() }} {{ form.binlog_enabled.label }}
{{ form.log_retention_days.label }}: {{ form.log_retention_days() }}
{{ form.fc_sysid.label }}: {{ form.fc_sysid() }}
+
{{ form.use_tz() }} {{ form.use_tz.label }}
{{ form.tz_offset_hours.label }}: {{ form.tz_offset_hours() }}
browse logs →
{{ form.reset_timestamp() }} {{ form.reset_timestamp.label }}
diff --git a/webadmin/templates/owner.html b/webadmin/templates/owner.html index e5f9f98..4df4093 100644 --- a/webadmin/templates/owner.html +++ b/webadmin/templates/owner.html @@ -55,6 +55,7 @@

My entry

{{ form.binlog_enabled() }} {{ form.binlog_enabled.label }}
{{ form.log_retention_days.label }}: {{ form.log_retention_days() }}
{{ form.fc_sysid.label }}: {{ form.fc_sysid() }}
+
{{ form.use_tz() }} {{ form.use_tz.label }}
{{ form.tz_offset_hours.label }}: {{ form.tz_offset_hours() }}
browse logs →
{{ form.reset_timestamp() }} {{ form.reset_timestamp.label }}
From bca92d0105721c611263662fb865886938f54bda Mon Sep 17 00:00:00 2001 From: Andrew Tridgell Date: Sun, 19 Jul 2026 19:19:22 +1000 Subject: [PATCH 8/9] tests: use_tz flag gating, collision ordering, NaN rejection Cover the timezone flag: settz enables use_tz and shows a fixed offset; clearing the flag reverts to server-local (date helpers stay local, the default). Add NaN-rejection, collision-suffix ordering, and webadmin use_tz enable/disable tests. --- tests/test_binlog_capture.py | 6 ++--- tests/test_keydb_log.py | 33 ++++++++++++++++++++++++--- tests/test_tlog_capture.py | 6 ++--- tests/webadmin/test_log_routes.py | 37 ++++++++++++++++++++++++++++++- 4 files changed, 72 insertions(+), 10 deletions(-) diff --git a/tests/test_binlog_capture.py b/tests/test_binlog_capture.py index 5a71ec1..8e99620 100644 --- a/tests/test_binlog_capture.py +++ b/tests/test_binlog_capture.py @@ -54,9 +54,9 @@ def _today_str(): # The proxy names date dirs in the entry's log timezone; with none - # set that's GMT, so use UTC here (a local date could land in the - # wrong dir near midnight on a non-UTC host). - return time.strftime('%Y-%m-%d', time.gmtime()) + # set that's the server's local timezone (the default), so use + # localtime here. + return time.strftime('%Y-%m-%d', time.localtime()) @pytest.fixture diff --git a/tests/test_keydb_log.py b/tests/test_keydb_log.py index 8090780..894db89 100644 --- a/tests/test_keydb_log.py +++ b/tests/test_keydb_log.py @@ -326,6 +326,7 @@ def test_format_tz_offset(): assert keydb_lib.format_tz_offset(5.5) == 'GMT+05:30' assert keydb_lib.format_tz_offset(-3.75) == 'GMT-03:45' assert keydb_lib.format_tz_offset(14) == 'GMT+14:00' + assert keydb_lib.format_tz_offset(float('nan')) == 'invalid' def test_cli_settz_and_list(tmp_path): @@ -336,10 +337,17 @@ def test_cli_settz_and_list(tmp_path): assert r.returncode == 0, r.stderr assert 'GMT+05:30' in r.stdout r = _run_cli(p, 'list') + # settz enables the use_tz flag and the fixed offset shows assert 'tz=GMT+05:30' in r.stdout - # back to GMT (0) drops the display - assert _run_cli(p, 'settz', '22002', '0').returncode == 0 - assert 'tz=' not in _run_cli(p, 'list').stdout + assert 'use_tz' in r.stdout + # settz 0 with the flag on is a genuine GMT offset + r = _run_cli(p, 'settz', '22002', '0') + assert r.returncode == 0 + assert 'tz=GMT' in _run_cli(p, 'list').stdout + # clearing the flag reverts to server-local naming (no fixed tz shown) + assert _run_cli(p, 'clearflag', '22002', 'use_tz').returncode == 0 + out = _run_cli(p, 'list').stdout + assert 'tz=GMT' not in out and 'use_tz' not in out def test_cli_settz_rejects_out_of_range(tmp_path): @@ -349,3 +357,22 @@ def test_cli_settz_rejects_out_of_range(tmp_path): r = _run_cli(p, 'settz', '23002', '20') assert r.returncode == 1 assert 'must be in' in r.stdout + + +def test_set_timezone_rejects_nan(tmp_path): + import math + p = str(tmp_path / 'keys.tdb') + db = keydb_lib.init_db(p) + db.transaction_start() + keydb_lib.add_entry(db, 24001, 24002, 'nan', 'pw') + try: + keydb_lib.set_timezone(db, 24002, float('nan')) + assert False, 'NaN offset should be rejected' + except keydb_lib.CLIError: + pass + # stored value stays finite (unchanged default 0.0) + ke = keydb_lib.KeyEntry(24002) + ke.fetch(db) + assert math.isfinite(ke.tz_offset_hours) and ke.tz_offset_hours == 0.0 + db.transaction_cancel() + db.close() diff --git a/tests/test_tlog_capture.py b/tests/test_tlog_capture.py index a6ba197..f0c1880 100644 --- a/tests/test_tlog_capture.py +++ b/tests/test_tlog_capture.py @@ -44,9 +44,9 @@ def _today_str(): """Match the proxy's date-dir naming. With no per-entry timezone set - the proxy names in GMT, so use UTC here (a local date would land in - the wrong dir near midnight on a non-UTC host).""" - return time.strftime('%Y-%m-%d', time.gmtime()) + the proxy names in the server's local timezone (the default), so use + localtime here.""" + return time.strftime('%Y-%m-%d', time.localtime()) def _tlogs(workdir, port_eng): diff --git a/tests/webadmin/test_log_routes.py b/tests/webadmin/test_log_routes.py index 72327c4..532a1b9 100644 --- a/tests/webadmin/test_log_routes.py +++ b/tests/webadmin/test_log_routes.py @@ -192,20 +192,38 @@ def test_admin_can_set_fractional(self, client, keydb_path): ke = fetch_entry(keydb_path, ALICE_PORT2) assert ke.log_retention_days == 0.5 - def test_owner_can_set_timezone(self, client, keydb_path): + def test_owner_can_enable_fixed_timezone(self, client, keydb_path): + import keydb_lib login_as(client, ALICE_PORT1, ALICE_PASS) client.post('/me/', data={ 'name': 'alice', + 'use_tz': 'y', 'tz_offset_hours': '5.5', 'submit': 'Save', }) ke = fetch_entry(keydb_path, ALICE_PORT2) assert abs(ke.tz_offset_hours - 5.5) < 1e-6 + assert ke.flags & keydb_lib.FLAG_USE_TZ + + def test_owner_unticking_use_tz_reverts_to_local(self, client, keydb_path): + import keydb_lib + login_as(client, ALICE_PORT1, ALICE_PASS) + # enable, then submit again without the box -> flag cleared, + # offset retained. + client.post('/me/', data={ + 'name': 'alice', 'use_tz': 'y', 'tz_offset_hours': '5.5', + 'submit': 'Save'}) + client.post('/me/', data={ + 'name': 'alice', 'tz_offset_hours': '5.5', 'submit': 'Save'}) + ke = fetch_entry(keydb_path, ALICE_PORT2) + assert not (ke.flags & keydb_lib.FLAG_USE_TZ) + assert abs(ke.tz_offset_hours - 5.5) < 1e-6 def test_owner_timezone_out_of_range_rejected(self, client, keydb_path): login_as(client, ALICE_PORT1, ALICE_PASS) r = client.post('/me/', data={ 'name': 'alice', + 'use_tz': 'y', 'tz_offset_hours': '20', 'submit': 'Save', }) @@ -358,6 +376,23 @@ def test_collision_suffix_name_ok(self, client, keydb_path, logs_dir): r = client.get('/me/logs/2026-07-19/' + self.TS + '-2.tlog') assert r.status_code == 200 + def test_collision_suffix_chronological_order(self, client, keydb_path, + logs_dir): + # The unsuffixed original is the first session that second and + # must list BEFORE its -2 / -10 collision siblings, even though + # lexically '-' < '.'. + for suffix in ('-10', '', '-2'): + seed_session(logs_dir, ALICE_PORT2, '2026-07-19', + self.TS + suffix + '.bin', content=b'X') + login_as(client, ALICE_PORT1, ALICE_PASS) + body = client.get('/me/logs/2026-07-19/').data.decode() + i_base = body.index(self.TS + '.bin') + i_2 = body.index(self.TS + '-2.bin') + i_10 = body.index(self.TS + '-10.bin') + assert i_base < i_2 < i_10, \ + 'collision suffixes out of order: base=%d -2=%d -10=%d' % ( + i_base, i_2, i_10) + class TestTlogDownloadCacheHeaders: """Tlog payloads contain raw vehicle telemetry. They must not be From 3c56359d93bc0ac81530d06eeeb37a65d174c8be Mon Sep 17 00:00:00 2001 From: Andrew Tridgell Date: Sun, 19 Jul 2026 20:02:03 +1000 Subject: [PATCH 9/9] logging: fail-closed collision names, clamp offset, doc fixes MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Address the second review pass (codex): - session_unique_basename now occupancy-checks every candidate, including the exhaustion fallback, so it can never return a name that would truncate/append another session's log. The fallback is a single numeric '-N' suffix (pid+nanoseconds concatenated), which the web UI's session regex already accepts — so fallback logs stay browsable. - session_time_strings clamps the offset to [-12,+14] before the time_t arithmetic, so a hand-edited record with use_tz set and an absurd offset can't overflow rather than just being non-finite-checked. - Correct the stale 'offset 0 = GMT/local' comments: the KEY_FLAG_USE_TZ flag is authoritative, not the value. Tests: occupancy-checked collision (harness-verified), pid+ns fallback browsable/downloadable, and an out-of-range offset clamped to +14h. --- keydb_lib.py | 4 +- session.cpp | 61 ++++++++++++++++++++++--------- session.h | 12 +++--- tests/test_binlog_capture.py | 53 +++++++++++++++++++++++++++ tests/webadmin/test_log_routes.py | 13 +++++++ 5 files changed, 119 insertions(+), 24 deletions(-) diff --git a/keydb_lib.py b/keydb_lib.py index 80c7a64..e43ad82 100644 --- a/keydb_lib.py +++ b/keydb_lib.py @@ -32,7 +32,9 @@ # so the on-disk byte layout stays compatible — the zero-init paths in # db_load_key (C++) and unpack() (Python) handle older records transparently. # tz_offset_hours took a slot that was previously a zeroed reserved word, so -# older records read back as 0.0 (GMT) with no conversion. +# older records read back as 0.0 with the KEY_FLAG_USE_TZ bit clear — i.e. +# server-local naming (the flag, not the value, decides whether the offset +# is used), needing no conversion. KEYENTRY_MIN_SIZE = 96 PACK_FORMAT = " 14.0) off = 14.0; + time_t shifted = utc + (time_t)llround(off * 3600.0); r = gmtime_r(&shifted, &tm); } else { // Default (KEY_FLAG_USE_TZ clear, or a non-finite offset): name @@ -63,6 +68,16 @@ void session_time_strings(time_t utc, bool use_offset, double tz_offset_hours, tm.tm_hour, tm.tm_min, tm.tm_sec); } +// True if neither /.tlog nor /.bin exists. +static bool basename_free(const char *dir, const char *candidate) +{ + char p_tlog[2048], p_bin[2048]; + snprintf(p_tlog, sizeof(p_tlog), "%s/%s.tlog", dir, candidate); + snprintf(p_bin, sizeof(p_bin), "%s/%s.bin", dir, candidate); + struct stat st; + return stat(p_tlog, &st) != 0 && stat(p_bin, &st) != 0; +} + void session_unique_basename(const char *base_dir, uint32_t port2, const char *datedir, char *name, size_t name_len) @@ -73,28 +88,40 @@ void session_unique_basename(const char *base_dir, uint32_t port2, char dir[1024]; snprintf(dir, sizeof(dir), "%s/%u/%s", base_dir, unsigned(port2), datedir); - for (int suffix = 1; suffix < 1000; suffix++) { - char candidate[80]; + // Plain basename, then "-2", "-3", … — every candidate is checked + // for occupancy across BOTH extensions, so we never hand back a name + // that would truncate (.bin) or append into (.tlog) another session's + // log. A single "-N" suffix keeps the name browsable by the web UI. + // The cap is a safety bound; the first free slot is normally "-2". + for (int suffix = 1; suffix < 100000; suffix++) { + char candidate[96]; if (suffix == 1) { snprintf(candidate, sizeof(candidate), "%s", base); } else { snprintf(candidate, sizeof(candidate), "%s-%d", base, suffix); } - char p_tlog[2048], p_bin[2048]; - snprintf(p_tlog, sizeof(p_tlog), "%s/%s.tlog", dir, candidate); - snprintf(p_bin, sizeof(p_bin), "%s/%s.bin", dir, candidate); - struct stat st; - if (stat(p_tlog, &st) != 0 && stat(p_bin, &st) != 0) { + if (basename_free(dir, candidate)) { + snprintf(name, name_len, "%s", candidate); + return; + } + } + // 100000 files in one second/dir cannot happen; as an absolute last + // resort append the pid+nanoseconds as ONE numeric suffix (still a + // single "-N" the web UI accepts) and still check occupancy, so we + // never return an occupied name. + for (int i = 0; i < 100; i++) { + struct timespec ts {}; + clock_gettime(CLOCK_REALTIME, &ts); + char candidate[96]; + snprintf(candidate, sizeof(candidate), "%s-%d%09ld", + base, int(getpid()), long(ts.tv_nsec)); + if (basename_free(dir, candidate)) { snprintf(name, name_len, "%s", candidate); return; } } - // 1000 collisions in one second/dir cannot happen in practice, but - // never return an occupied basename (that would truncate/append into - // another session's log). A pid+nanosecond suffix can't match any of - // the "-N" candidates above, so it stays unique. - struct timespec ts {}; - clock_gettime(CLOCK_REALTIME, &ts); - snprintf(name, name_len, "%s-%d-%09ld", - base, int(getpid()), long(ts.tv_nsec)); + // Unreachable: there is genuinely no free name. Leave `name` as the + // plain base (its value on entry) — no worse than the impossible + // exhaustion above. + snprintf(name, name_len, "%s", base); } diff --git a/session.h b/session.h index 2c23cb2..a98fe36 100644 --- a/session.h +++ b/session.h @@ -26,12 +26,12 @@ int mkpath_0700(const char *path); /* Format the date subdir ("YYYY-MM-DD") and the log basename - ("YYYY_MM_DD_HH:MM:SS") for the UTC time `utc`. When `use_offset` is - true the finite tz_offset_hours (fractional allowed) is applied and - formatted with gmtime, so the host timezone never affects naming (a - fixed offset, no DST). When false, the time is formatted in the - server's own local timezone — the default when KEY_FLAG_USE_TZ is - clear. + ("YYYY_MM_DD_HH:MM:SS") for the UTC time `utc`. `use_offset` mirrors + KEY_FLAG_USE_TZ: when true, the finite tz_offset_hours (fractional + allowed, clamped to [-12,+14]) is applied and formatted with gmtime — + a fixed GMT offset, no DST, so 0 is genuine GMT. When false (the + default, and every legacy entry), the time is formatted in the + server's own local timezone; tz_offset_hours is ignored. */ void session_time_strings(time_t utc, bool use_offset, double tz_offset_hours, char *datedir, size_t datedir_len, diff --git a/tests/test_binlog_capture.py b/tests/test_binlog_capture.py index 8e99620..a5ebede 100644 --- a/tests/test_binlog_capture.py +++ b/tests/test_binlog_capture.py @@ -323,6 +323,59 @@ def test_bin_named_by_timestamp_in_entry_timezone(self, proxy_workdir): finally: _terminate(proc) + def test_out_of_range_offset_is_clamped(self, proxy_workdir): + """A hand-edited record with use_tz set and an absurd offset (past + the [-12,+14] range) must be clamped by the proxy, not overflow + time_t. The name should land at UTC+14, not UTC+1000.""" + db_path = str(proxy_workdir / 'keys.tdb') + db = keydb_lib.init_db(db_path) + db.transaction_start() + keydb_lib.add_entry(db, PORT_USER, PORT_ENG, 'tzclamp', 'bp') + keydb_lib.set_flag(db, PORT_ENG, 'binlog') + # Bypass set_timezone's validation to plant a garbage offset with + # the use_tz flag on, as a corrupted/hand-edited record would. + ke = keydb_lib.KeyEntry(PORT_ENG) + ke.fetch(db) + ke.tz_offset_hours = 1000.0 + ke.flags |= keydb_lib.FLAG_USE_TZ + ke.store(db) + db.transaction_prepare_commit() + db.transaction_commit() + db.close() + + proc = _start_proxy(proxy_workdir, PORT_ENG) + try: + sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM) + sock.bind(('127.0.0.1', 0)) + dest = ('127.0.0.1', PORT_USER) + utc_before = time.time() + for seq in range(3): + _send_data_block(sock, dest, seq, b'\x77' * 50) + time.sleep(0.05) + root = proxy_workdir / 'logs' / str(PORT_ENG) + deadline = time.time() + 5 + found = [] + while time.time() < deadline and not found: + found = list(root.glob('*/*.bin')) + time.sleep(0.05) + assert proc.poll() is None, 'proxy crashed on absurd offset' + assert found, 'no .bin written; proxy log:\n%s' % ''.join( + proc._lines[-10:]) + import calendar + m = re.match( + r'^(\d{4})_(\d{2})_(\d{2})_(\d{2}):(\d{2}):(\d{2})(-\d+)?$', + found[0].name[:-4]) + assert m, 'bad basename: %r' % found[0].name + named = calendar.timegm((int(m[1]), int(m[2]), int(m[3]), + int(m[4]), int(m[5]), int(m[6]), 0, 0, 0)) + # clamped to +14h, not +1000h + assert abs(named - (utc_before + 14 * 3600)) < 5, \ + 'offset not clamped to +14h: named epoch %d vs utc %d' % ( + named, utc_before) + sock.close() + finally: + _terminate(proc) + def test_data_blocks_land_in_bin_file(self, proxy_workdir): _setup_db(proxy_workdir, PORT_USER, PORT_ENG, 'bintest', 'bp', 'binlog') diff --git a/tests/webadmin/test_log_routes.py b/tests/webadmin/test_log_routes.py index 532a1b9..bf3f072 100644 --- a/tests/webadmin/test_log_routes.py +++ b/tests/webadmin/test_log_routes.py @@ -376,6 +376,19 @@ def test_collision_suffix_name_ok(self, client, keydb_path, logs_dir): r = client.get('/me/logs/2026-07-19/' + self.TS + '-2.tlog') assert r.status_code == 200 + def test_pid_ns_fallback_name_browsable(self, client, keydb_path, + logs_dir): + # The exhaustion fallback is a single big numeric "-N" suffix + # (pid+nanoseconds concatenated); it must list and download like + # any other session file. + fb = self.TS + '-149785439335901.bin' + seed_session(logs_dir, ALICE_PORT2, '2026-07-19', fb, content=b'F') + login_as(client, ALICE_PORT1, ALICE_PASS) + r = client.get('/me/logs/2026-07-19/') + assert fb.encode() in r.data + r = client.get('/me/logs/2026-07-19/' + fb) + assert r.status_code == 200 + def test_collision_suffix_chronological_order(self, client, keydb_path, logs_dir): # The unsuffixed original is the first session that second and