Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 4 additions & 1 deletion docs/cli.md
Original file line number Diff line number Diff line change
Expand Up @@ -625,7 +625,10 @@ Service log files are appended across runs. `--run` reads only one run's own par
`log_offset` to where the next run of that service started writing, so a later generation's lines —
including the error it died on — are not reported as this run's. A run that is still writing owns
everything after its start; two runs that overlap in time write interleaved bytes, and their parts
cannot be told apart. `--run current` selects the service's current run, and any other value is an
cannot be told apart. A run that has ended owns only the bytes already in the file: when no later
generation has recorded where it took over — the newest finished run — its part ends at the end of
the file as it is when read, so following it prints and returns instead of waiting for a generation
that has not started yet. `--run current` selects the service's current run, and any other value is an
exact historical `run_id` from `status --json`. `current` prefers a process that is still running and
only falls back to the most recently finished one when there is none. Following a run that has ended
prints its lines and stops: nothing arrives for it afterwards. `--run` accepts only service names,
Expand Down
4 changes: 3 additions & 1 deletion docs/cli.zh.md
Original file line number Diff line number Diff line change
Expand Up @@ -515,7 +515,9 @@ daemon 是账本的唯一写者:它在扫描到清单时记录身份,重启
服务日志文件跨多次运行追加。`--run` 只读该文件里这一次运行自己的那一段:从 `log_offset` 到
同一服务下一次运行开始写入的位置,因此后续运行的行——包括它崩溃时那条错误——不会被当成这次
运行输出的一部分。仍在运行的那次运行拥有起点之后的全部内容;两次运行在时间上重叠时,它们的
字节交织在同一个文件里,无法区分。`--run current` 选该服务当前这次运行,其他值则是
字节交织在同一个文件里,无法区分。已经结束的那次运行只拥有文件里已写入的字节:后续运行还没有
记录接管位置时(最近一次结束的运行就是这种情况),它的这一段止于读取时的文件末尾,跟随它会
打印后返回,而不是等待一次尚未开始的运行。`--run current` 选该服务当前这次运行,其他值则是
`status --json` 里的精确 `run_id`。`current` 优先选仍在运行的进程,没有时才选最近结束的一次。
跟随一次已经结束的运行会打印它的行然后停止:之后不会再有属于它的输出。`--run` 只接受服务名,
不能和 `--ip` 同时使用;它需要 daemon,daemon 不可用时返回 `daemon_unavailable`。旧运行记录
Expand Down
7 changes: 4 additions & 3 deletions engine/internal/cmd/logs.go
Original file line number Diff line number Diff line change
Expand Up @@ -310,9 +310,10 @@ func requireLogFile(path string) error {
return nil
}

// streamFileLogsFrom follows one run's range of the file. A range with an end
// belongs to a run that has finished, so it is printed and the read stops:
// nothing that arrives afterwards can belong to that run.
// streamFileLogsFrom follows one run's range of the file. A range that cannot
// grow belongs to a run that has finished — either its end byte is recorded, or
// the run has ended and the file as it is now is its end — so it is printed and
// the read stops: nothing that arrives afterwards can belong to that run.
func streamFileLogsFrom(ctx context.Context, path string, rng logRange, asJSON bool, lines int, meta logMetadata) error {
if err := requireLogFile(path); err != nil {
return err
Expand Down
41 changes: 29 additions & 12 deletions engine/internal/cmd/logs_run.go
Original file line number Diff line number Diff line change
Expand Up @@ -60,35 +60,46 @@ func logsFromRun(ctx context.Context, c *client.Client, target, selector string)
}

// logRange is the part of a log file one read covers, in bytes: [start, end).
// A whole-file read is a range that starts at zero. end < 0 means the range
// has no known end: the run that owns it is still writing, so the end of the
// file is its end for as long as the read lasts.
// A whole-file read is a range that starts at zero. end < 0 means no byte
// position was recorded where the range stops; ended then says whether the run
// that owns it has stopped writing. A run that is still writing owns everything
// after its start, so the end of the file is its end for as long as the read
// lasts; a run that has ended owns only what is already in the file.
type logRange struct {
start int64
end int64
// ended says the run that owns this range has exited. Nothing it wrote can
// appear after the file as it is when read, so the range cannot grow a line
// even when no later generation recorded where it took over.
ended bool
}

// bounded says the range's last byte is already written: a finished run cannot
// grow another line, so following it is a read, not a wait.
func (r logRange) bounded() bool { return r.end >= 0 }
// grow another line, so following it is a read, not a wait. The one range that
// is not bounded belongs to a run that is still writing.
func (r logRange) bounded() bool { return r.end >= 0 || r.ended }

// runLogRange is where one run's bytes end in the file its service appends to
// across generations. The file is a single stream of bytes and only each run's
// start was recorded, so the end is where the next generation took over: a run
// that started after this one ended began writing exactly where this one
// stopped. Without such a run the range stays open, which is the truth for the
// newest run and for one that is still writing; closing it at the end of the
// file instead would report a later run's lines — and the error it died on —
// as this run's.
// start was recorded, so the exact end is where the next generation took over:
// a run that started after this one ended began writing exactly where this one
// stopped. Without such a run — the newest finished one is the usual case — the
// range still ends at the end of the file, because a run that has exited cannot
// append. Leaving it open instead would make a follow wait for bytes that will
// belong to a generation not yet started, under this run's name.
func runLogRange(rec rpc.RunRecord, records []rpc.RunRecord) logRange {
rng := logRange{start: *rec.LogOffset, end: -1}
if rec.Status != "exited" {
return rng
}
// From here the run has ended: whatever it wrote is already in the file, so
// a read can stop at the file's end even when the loop below finds no exact
// byte to stop at.
rng.ended = true
endedAt := parseRunTime(rec.ExitedAt)
if endedAt.IsZero() {
// Without the moment this run ended, no later run can be shown to have
// started after it; an open range is the honest answer.
// started after it; the end of the file is the best bound there is.
return rng
}
for _, other := range records {
Expand Down Expand Up @@ -266,6 +277,12 @@ func readRunLines(path string, rng logRange) ([]string, []int64, bool, error) {
}
size := info.Size()
start, end := rng.start, rng.end
if end < 0 && rng.ended {
// The run has ended, so the file as it is now is where its range stops.
// Limiting the read to the size observed here keeps out bytes a later
// generation appends while this read is in progress.
end = size
}
unknown := false
// A rotation invalidates every recorded byte position: the start lies past
// the end of the file, or the range ends behind its own start because a
Expand Down
67 changes: 63 additions & 4 deletions engine/internal/cmd/logs_run_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ import (
"path/filepath"
"strings"
"testing"
"time"

"github.com/sheathedsharp/option-berth/engine/internal/daemon/rpc"
)
Expand Down Expand Up @@ -233,10 +234,10 @@ func TestRunLogRangeEndsWhereTheNextGenerationStarted(t *testing.T) {
LogPath: "/logs/api.log", StartedAt: "2026-11-01T10:08:00Z", LogOffset: int64Ptr(90)}
records := []rpc.RunRecord{live, second, first}

if got := runLogRange(first, records); got != (logRange{start: 0, end: 40}) {
if got := runLogRange(first, records); got != (logRange{start: 0, end: 40, ended: true}) {
t.Fatalf("first run range = %+v, want [0,40)", got)
}
if got := runLogRange(second, records); got != (logRange{start: 40, end: 90}) {
if got := runLogRange(second, records); got != (logRange{start: 40, end: 90, ended: true}) {
t.Fatalf("second run range = %+v, want [40,90)", got)
}
// The run that is still writing owns everything after its own start.
Expand All @@ -262,8 +263,25 @@ func TestRunLogRangeIgnoresRunsThatDidNotWriteAfterThisOne(t *testing.T) {
LogPath: "/logs/api.log", StartedAt: "2026-11-01T10:07:00Z", ExitedAt: "2026-11-01T10:08:00Z"}

records := []rpc.RunRecord{first, overlapping, elsewhere, unrecorded}
if got := runLogRange(first, records); got != (logRange{start: 0, end: -1}) {
t.Fatalf("range = %+v, want [0,EOF): nothing recorded where this run's bytes end", got)
if got := runLogRange(first, records); got != (logRange{start: 0, end: -1, ended: true}) {
t.Fatalf("range = %+v, want an ended range: nothing recorded where this run's bytes end, but it cannot write more", got)
}
}

// The newest finished run has no successor to record where it took over. It has
// ended all the same, so its range stops at the file as it is when read: a
// follow reads and returns instead of waiting for a generation that does not
// exist yet.
func TestRunLogRangeOfANewestFinishedRunEndsAtTheFile(t *testing.T) {
ended := rpc.RunRecord{ID: "r1", Group: "shop", Name: "api", Status: "exited",
LogPath: "/logs/api.log", StartedAt: "2026-11-01T10:00:00Z", ExitedAt: "2026-11-01T10:02:00Z",
LogOffset: int64Ptr(120)}
got := runLogRange(ended, []rpc.RunRecord{ended})
if !got.bounded() {
t.Fatalf("range = %+v, want a bound: the run has ended and cannot append", got)
}
if got.start != 120 || got.end != -1 {
t.Fatalf("range = %+v, want the run's own bytes up to the file end", got)
}
}

Expand Down Expand Up @@ -308,6 +326,47 @@ func TestFollowOfAFinishedRunPrintsItsLinesAndStops(t *testing.T) {
}
}

// The same follow for a run that has ended with no successor recorded yet — the
// newest finished run. The file is still there to grow when the next generation
// starts, so the read must stop at the file rather than follow it: bytes that
// arrive afterwards belong to whichever run writes them, not to this one.
func TestFollowOfAFinishedRunWithoutASuccessorReturns(t *testing.T) {
path := filepath.Join(t.TempDir(), "api.log")
if err := os.WriteFile(path, []byte("booting\nlistening on 3000\n"), 0o600); err != nil {
t.Fatal(err)
}
ended := rpc.RunRecord{ID: "r1", Group: "shop", Name: "api", Status: "exited",
LogPath: path, StartedAt: "2026-11-01T10:00:00Z", ExitedAt: "2026-11-01T10:02:00Z",
LogOffset: int64Ptr(0)}
rng := runLogRange(ended, []rpc.RunRecord{ended})

ctx, cancel := context.WithCancel(context.Background())
defer cancel()
followed := make(chan error, 1)
done := make(chan struct{})
out := captureStdout(t, func() {
go func() {
defer close(done)
followed <- streamFileLogsFrom(ctx, path, rng, false, 10, logMetadata{Service: "api", RunID: "r1"})
}()
select {
case <-done:
case <-time.After(5 * time.Second):
// The follow had no end and started waiting for a future run's
// bytes: cancel it so the test can report it instead of hanging.
cancel()
<-done
t.Error("following a run that has ended did not return")
}
})
if err := <-followed; err != nil && !t.Failed() {
t.Fatal(err)
}
if !t.Failed() && !strings.Contains(out, "listening on 3000") {
t.Fatalf("output = %q, want the run's lines before returning", out)
}
}

func TestSelectRunForLogsPicksTheNewestRun(t *testing.T) {
records := []rpc.RunRecord{
{ID: "old", Group: "shop", Name: "api", StartedAt: "2026-10-31T09:00:00Z", Status: "exited"},
Expand Down
Loading