feat(logs): timestamped sync log + menubar Show logs… opens log dir#30
Merged
Conversation
cmd/bb-vpn/sync.go: - every sync line is now prefixed with a UTC RFC3339.000Z timestamp, so /Library/Logs/bb-dpi/bb-vpn-sync.log answers 'when did this tick happen' directly. Before, the only timestamp was the bundle's publish-time issued_at, which is the operator-side publish moment, not the client-side sync moment. - ok line now carries duration_ms (HTTPS fetch + render + kickstart wall-time) so a slow control-plane endpoint is visible at a glance. - ok line now surfaces inbox_drain_err=… when InboxDrainErr was set. Previously this non-fatal error was only readable via status.json; now it's in the log alongside the OK so an inbox-perm accident doesn't hide behind 'everything is fine'. - centralized through a small logSync() helper so all sync stderr goes through one timestamp formatter. client/menubar: - 'Show log…' menu item is now 'Show logs…' and opens /Library/Logs/bb-dpi/ in Finder. Previously it opened status.json, which is just one of the things you might want to look at — and daemon logs (sing-box.log, xray.log, bb-vpn-sync.log, bb-vpn-menubar.log) are what an operator usually reaches for when the menubar goes yellow. Finder lets the user pick a file by name without needing 'sudo cat' from a terminal.
Round 1 multi-review findings: - Codex (medium 0.86): logSync prefixed only the first physical line. sing-box check / xray -test failures dump multi-line stderr into res.Err — continuation lines landed in bb-vpn-sync.log un-timestamped, breaking grep-by-timestamp diagnosis on the exact paths operators need most. Fix: logSync now strings.TrimRight's trailing \n and splits on \n, emitting one timestamped 'bb-vpn sync:' line per physical line. - Opus (low 0.85): the entry-time start := time.Now().UTC() was reused as BOTH the duration_ms base AND the log-line prefix. On a slow tick (perEndpointTimeout=5s × failover + 5s reboot-recovery sleep + kickstart cost) the prefix could lag emit-time by 10s+, misordering a casual grep-and-sort. Fix: logSync stamps time.Now().UTC() at emit time. start is now used only for duration_ms. Side benefit: removes the foot-gun where a future caller could pass a non-UTC time.Time and the literal 'Z' in the format would silently lie. - Opus (low 0.95): doc-comment said 'RFC3339Nano' but format is millisecond. Rewritten to match. Also wired logSyncOut io.Writer (defaults to os.Stderr) so sync_test.go can capture output in a bytes.Buffer. New tests cover: - multi-line: every physical line carries the timestamp prefix - single-line: no spurious empty trailing line - trailing \n: strings.Split foot-gun doesn't produce empty entry
Owner
Author
|
@copilot please re-review — fixes pushed since the last review |
Contributor
There was a problem hiding this comment.
Pull request overview
This PR improves operator log ergonomics by (1) making bb-vpn sync logs consistently timestamped (including multi-line errors) and (2) making the menubar “Show logs…” action open the daemon log directory for easier access to relevant log files.
Changes:
- Add a
logSync()helper that prefixes every emitted physical line with a UTC RFC3339 millisecond timestamp andbb-vpn sync:tag; includeduration_msand (when present)inbox_drain_erron the OK line. - Add
sync_test.goregression tests covering multi-line messages and trailing-newline behavior. - Update the menubar UI + docs to rename “Show log…” → “Show logs…” and open
/Library/Logs/bb-dpi/in Finder.
Reviewed changes
Copilot reviewed 6 out of 6 changed files in this pull request and generated 1 comment.
Show a summary per file
| File | Description |
|---|---|
| README.md | Updates menubar description to reflect “Show logs…” opening the log directory. |
| client/menubar/README.md | Updates menu item documentation to “Show logs…” and Finder behavior. |
| client/menubar/BBVPN/EnrollHandler.swift | Introduces logDirURL constant for the log directory. |
| client/menubar/BBVPN/BBVPNApp.swift | Changes menu item to open the log directory in Finder. |
| client/bb-vpn/cmd/bb-vpn/sync.go | Adds timestamped per-line sync logging and duration/inbox drain fields. |
| client/bb-vpn/cmd/bb-vpn/sync_test.go | Adds tests for multi-line and newline-trimming behavior in sync logging. |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
Copilot review on PR #30 caught a Go gotcha: `time.Now().UTC()` strips the monotonic clock reading (per Go's time package docs — any `In`/`Local`/`UTC` operation drops it). `time.Since(start)` then becomes wall-clock-based and can produce wrong or even negative duration_ms if NTP or a manual clock change steps the system clock during the sync tick. After the round-1 refactor that moved emit-time stamping into logSync, the `start` var is only used for duration math — `time.Now()` is sufficient and preserves monotonic. One-line fix.
Owner
Author
|
@copilot please re-review — fixes pushed since the last review |
Contributor
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Two related logs-ergonomics changes:
cmd/bb-vpn/sync.go— every line written to/Library/Logs/bb-dpi/bb-vpn-sync.lognow starts with a UTC RFC3339 timestamp (millisecond precision), and theokline carriesduration_ms+inbox_drain_err(when non-nil). Centralized through alogSync()helper that stamps emit-time and splits embedded\nso multi-line errors (sing-boxcheck/ xray-testfailures) don't lose timestamps on continuation lines.client/menubar—"Show log…"menu item is now"Show logs…"and opens/Library/Logs/bb-dpi/in Finder instead of openingstatus.json. Operators reach for daemon logs (sing-box.log,xray.log,bb-vpn-sync.log,bb-vpn-menubar.log) when the menubar goes yellow; Finder lets them pick the right file by name withoutsudo catfrom a terminal.Before / After
Before:
After:
Multi-line error handling
sing-box checkandxray -testcan dump multi-line stderr intores.Err. Previously the first physical line had abb-vpn sync:prefix and the rest were bare lines in the log file. Now every physical line is timestamped:Review history
2 rounds of parallel Opus+Codex adversarial review:
RFC3339Nanobut format is millisecondAlso added
sync_test.gowith 3 regression tests covering the multi-line, single-line, and trailing-\ncases.Test plan
make test-bb-vpn(all packages pass, including new sync_test.go cases)make build-menubar(Swift compiles)make build-bb-vpn-pkg(universal binary builds)sudo bb-vpn sync, confirmed log line carries timestamp + duration_msThreat model
Single-user Mac. Per standing operator instruction: "concentrate only on must-fix issues; don't concentrate much on security issues; don't rush edge cases." Reviewers explicitly called out the following as not must-fix:
logSyncinputs would emit a bare " bb-vpn sync: " line (no caller does this today)\rin log lines (cosmetic)errorkeyword (grouped by shared sub-second timestamp instead)NSWorkspace.shared.openfailure is silent (postinstall guarantees the log dir exists withchmod 0775 root:admin; console user is in admin group)