diff --git a/README.md b/README.md index d2c453c9..7edd698b 100644 --- a/README.md +++ b/README.md @@ -1690,9 +1690,13 @@ for a hand-sent run command. **Report.** `report.remote.mode` is `observe`; `report.remote.observe` has `plan`, the newest `state`, `step`, `steps`, `leg`, `kind`, `phase`, `note` and a plain-words `text`, `started`, `lines`, `polls`, `pauses`, `controls`, `ended` and `changes[]` (the newest 300 status changes with their time). `report.wipes` counts the watched party's wipes: one rising edge of "every bot dead" in the feed is one wipe, the latch re-arms only once fewer than -3 members are dead (a single member revived in place for a poll, dead again the next, does not count a second wipe), and each counted -wipe also goes to the trace as a `wipe` event with `"observe": true`, so the tracecheck deaths oracle sees it too (the run leader stops -and recovers on its own; the watch only counts). `report.legs[]` has one +3 members are dead (a single member revived in place for a poll, dead again the next, does not count a second wipe). A wipe also counts +when every member has died within 90 s of each other, each death newer than the last counted wipe, even if the lead bot revived in +between (no frame shows them all dead; the RFC run: five dead within 63 s): that `wipe` event has `"window": true`. Each counted wipe +also goes to the trace as a `wipe` event with `"observe": true`, so the tracecheck deaths oracle sees it too (the run leader stops and +recovers on its own; the watch only counts). In an observe run `report.leader_deaths`, `report.resurrections` and `report.seconds_dead` +(in all and per leg) count the lead bot's deaths and revives from the feed, each death also a `leader_death` trace event; a revive here +is any return to alive, the run leader's own revive included, not only an accepted resurrection. `report.legs[]` has one entry per leg the run leader entered, with its seconds. `report.current` is "run leader: sentinel · pull 7/41 · pulling". The orders counters stay at zero but for the end's `stay`. Not in observe mode: `tune`, `live_reload`, `cc`, `carrier`, `loot_restore`, `object_fallback`, `tank`, `healer`, `recover_wipe` and the start options that move or equip the party (`start_here`, `have_items`, `pulltest`, `give_items`) are refused, since the agent steers nothing; `from_leg`, `from_pull_group` and diff --git a/internal/dungeon/observe.go b/internal/dungeon/observe.go index bb84c8d5..62a9a492 100644 --- a/internal/dungeon/observe.go +++ b/internal/dungeon/observe.go @@ -12,6 +12,7 @@ import ( "time" "github.com/pjerra/turtle-agent/internal/events" + "github.com/pjerra/turtle-agent/internal/packet" "github.com/pjerra/turtle-agent/internal/tbm" ) @@ -63,6 +64,9 @@ const ( // wipeDeadReArm is the dead-member count below which the wipe latch re-arms (TortoiseBots DungeonRunPolicy.kWipeDead, 3): a party // that is all dead, one member alive for a poll, all dead again, is one collapse, not two. wipeDeadReArm = 3 + // wipeWindow is a wipe counted from the feed's deaths: every member of the party dying within this long, even when the lead bot + // revives in between (the RFC run: all five dead within 63 s, never in one frame). + wipeWindow = 90 * time.Second ) func (s ObserveSpec) withDefaults(plan *Plan) ObserveSpec { @@ -167,18 +171,23 @@ func (r *ObserveReport) clone() *ObserveReport { // observeState is the observer's own state. type observeState struct { - spec ObserveSpec - started bool - startedAt time.Time - last tbm.RunStatus - haveLast bool - lastAt time.Time // when the status last changed - pausedAt time.Time - seenN uint64 - baseN uint64 // lines read before the start: older ones are another run's - lastPoll time.Time - serverEnd bool // the module said the run is done: no stop is needed - wiped bool // the feed showed the whole party dead: one rising edge of it is one wipe + spec ObserveSpec + started bool + startedAt time.Time + last tbm.RunStatus + haveLast bool + lastAt time.Time // when the status last changed + pausedAt time.Time + seenN uint64 + baseN uint64 // lines read before the start: older ones are another run's + lastPoll time.Time + serverEnd bool // the module said the run is done: no stop is needed + wiped bool // the feed showed the whole party dead: one rising edge of it is one wipe + wasDead map[packet.GUID]bool // dead in the previous frame (nil until the first frame) + deathAt map[packet.GUID]time.Time // when each member last went dead + leadDownAt time.Time // when the lead bot last went dead + leadDown bool + lastWipeAt time.Time // when the last wipe was counted mu sync.Mutex reqs []string // pause, resume, skip requests from the RPC @@ -355,12 +364,17 @@ func (d *RemoteDriver) observe(ctx context.Context) (err error) { // latch re-arms only once fewer than wipeDeadReArm members are dead (the module's kWipeDead): a single in-place revive (one member // alive for a poll, dead again the next) re-arms a plain "not all dead" check and double counts the collapse. The "wipe" event goes // to the trace, so the tracecheck deaths oracle sees the wipes of an observed run too (stepFailedRecover never runs in observe mode). + // The window rule counts a wipe the frames never show: every member died within wipeWindow, each death newer than the last counted + // wipe, so a lead bot that revives between their deaths does not hide the collapse. trackObservedDeaths reads the same frames for + // the lead bot's deaths and revives. all := d.countDeaths() - if all && !o.wiped { + window := d.trackObservedDeaths(d.clk.Now()) + if (all || window) && !o.wiped { d.rep.update(func(r *Report) { r.Wipes++ }) - d.tr.Event("wipe", map[string]any{"leg": d.curLeg, "error": "the whole party is dead", "observe": true}) + o.lastWipeAt = d.clk.Now() + d.tr.Event("wipe", map[string]any{"leg": d.curLeg, "error": "the whole party is dead", "observe": true, "window": !all}) } - if all { + if all || window { o.wiped = true } else if deadCount(d.fr) < wipeDeadReArm { o.wiped = false @@ -766,6 +780,52 @@ func deadCount(fr tbm.ViewFrame) int { return n } +// trackObservedDeaths follows the party's deaths in the newest frame: the lead bot's deaths and revives go into the report +// (LeaderDeaths, Resurrections, SecondsDead, the leg's too) and the trace (event leader_death), and the result says that every +// member has died within wipeWindow, each death newer than the last counted wipe. +func (d *RemoteDriver) trackObservedDeaths(now time.Time) bool { + o := d.obs + if !d.haveFr { + return false + } + if o.wasDead == nil { // the first frame is the baseline: a bot already dead in it is not a death + o.wasDead, o.deathAt = map[packet.GUID]bool{}, map[packet.GUID]time.Time{} + for _, p := range d.fr.Party { + o.wasDead[p.GUID] = p.Dead + } + return false + } + for _, p := range d.fr.Party { + isLead := d.fr.Lead != 0 && p.GUID == d.fr.Lead + if p.Dead && !o.wasDead[p.GUID] { + o.deathAt[p.GUID] = now + if isLead { + o.leadDown, o.leadDownAt = true, now + d.rep.update(func(r *Report) { r.LeaderDeaths++ }) + d.legStat(func(l *LegReport) { l.LeaderDeaths++ }) + d.tr.Event("leader_death", map[string]any{"name": p.Name, "a": guidText(p.GUID), "leg": d.curLeg}) + } + } + if !p.Dead && o.wasDead[p.GUID] && isLead && o.leadDown { + o.leadDown = false + secs := now.Sub(o.leadDownAt).Seconds() + d.rep.update(func(r *Report) { r.Resurrections++; r.SecondsDead += secs }) + d.legStat(func(l *LegReport) { l.Resurrections++; l.SecondsDead += secs }) + } + o.wasDead[p.GUID] = p.Dead + } + if len(d.fr.Party) < 2 { + return false + } + for _, p := range d.fr.Party { + at, ok := o.deathAt[p.GUID] + if !ok || !at.After(o.lastWipeAt) || now.Sub(at) > wipeWindow { + return false + } + } + return true +} + // legOf finds the plan leg a status line names (by name, or by number when the module had no name); -1 when none. func (d *RemoteDriver) legOf(name string) int { if name == "" { diff --git a/internal/dungeon/observe_test.go b/internal/dungeon/observe_test.go index 4d285d74..9672710a 100644 --- a/internal/dungeon/observe_test.go +++ b/internal/dungeon/observe_test.go @@ -440,6 +440,272 @@ func TestObserveCountsNoWipeWhileABotLives(t *testing.T) { } } +// observeRunScript keeps an observed run going past the death tables of the window tests: a status every 20 s and done at 200 s. +func observeRunScript() []leaderStep { + return []leaderStep{ + {0, rs("running", 1, 5, "first", "move", "walk", "walking")}, + {s(20), rs("running", 2, 5, "first", "pull", "pull", "pulling")}, + {s(40), rs("running", 3, 5, "first", "boss", "pull", "pulling")}, + {s(60), rs("running", 3, 5, "first", "boss", "fight", "fighting")}, + {s(80), rs("running", 4, 5, "first", "move", "walk", "walking")}, + {s(100), rs("running", 4, 5, "first", "move", "walk", "walking on")}, + {s(120), rs("running", 4, 5, "first", "move", "walk", "walking on")}, + {s(140), rs("running", 4, 5, "first", "move", "walk", "walking on")}, + {s(160), rs("running", 4, 5, "first", "move", "walk", "walking on")}, + {s(180), rs("running", 4, 5, "first", "move", "walk", "walking on")}, + {s(200), rs("done", 5, 5, "first", "move", "walk", "plan done")}, + } +} + +// deathsOnTickTable kills the party indexes the table names for each tick of the watch (one cfg.Poll sleep, one frame): the ticks +// after the table's last key are all alive. +func deathsOnTickTable(g *fakeLeader, table map[int][]int) { + base := g.onTick + ticks := 0 + g.onTick = func(fr *fakeRemote) { + base(fr) + if !g.running { + return + } + ticks++ + dead := map[int]bool{} + for _, i := range table[ticks] { + dead[i] = true + } + for i, p := range fr.party { + if dead[i] { + p.Dead, p.HP, p.State = true, 0, "d" + } else { + p.Dead, p.HP, p.State = false, p.MaxHP, "n" + } + } + } +} + +// fiveBotLeader is the party of the wipe tests: five bots, the lead bot first (the frame's Lead). +func fiveBotLeader(t *testing.T, script ...leaderStep) *fakeLeader { + g := newFakeLeader(t, script...) + g.party = append(g.party, &tbm.PartyRec{GUID: packet.GUID(0x2D), Name: "Loxy", HP: 1000, MaxHP: 1000, Power: 1000, MaxPower: 1000, PowerType: 0, State: "n"}, + &tbm.PartyRec{GUID: packet.GUID(0x2E), Name: "Grok", HP: 1000, MaxHP: 1000, Power: 1000, MaxPower: 1000, PowerType: 0, State: "n"}) + return g +} + +// An observed run's report counts the lead bot's own deaths and revives from the feed: two deaths, each revived 5 s later, and no +// wipe (the other four never died). +func TestObserveCountsALeadDeathAndItsRevive(t *testing.T) { + g := fiveBotLeader(t, observeRunScript()...) + deathsOnTickTable(g, map[int][]int{2: {0}, 5: {0}}) + dir := t.TempDir() + rep, err := runRemote(t, g, observePlan(), observeOpts(ObserveSpec{}), func(c *Config) { + c.Poll = 5 * time.Second + c.Trace = tracerun.Config{On: true, Dir: dir, RunID: "r-lead-death"} + }) + if err != nil || rep.State != "done" { + t.Fatalf("%v %s %s", err, rep.State, rep.Error) + } + if rep.LeaderDeaths != 2 || rep.Resurrections != 2 { + t.Fatalf("leader deaths %d resurrections %d (want 2 and 2)\n%s", rep.LeaderDeaths, rep.Resurrections, notesOf(rep)) + } + if rep.SecondsDead < 5 || rep.SecondsDead > 20 { + t.Fatalf("seconds dead %v (want 5..20)", rep.SecondsDead) + } + if rep.Wipes != 0 { + t.Fatalf("wipes %d (want 0)\n%s", rep.Wipes, notesOf(rep)) + } + if len(rep.Deaths) != 2 { + t.Fatalf("deaths %d (want 2): %+v", len(rep.Deaths), rep.Deaths) + } + legDeaths := 0 + for _, l := range rep.Legs { + legDeaths += l.LeaderDeaths + } + if legDeaths != 2 { + t.Fatalf("leg leader deaths %d (want 2): %+v", legDeaths, rep.Legs) + } + f, err := trace.Read(filepath.Join(dir, "r-lead-death.jsonl")) + if err != nil { + t.Fatal(err) + } + n := 0 + for _, e := range f.Events { + if e.Ev == "leader_death" { + n++ + if e.D["name"] != "Tanky" { + t.Fatalf("leader_death names %v (want Tanky)", e.D["name"]) + } + } + } + if n != 2 { + t.Fatalf("%d leader_death events in the trace (want 2)", n) + } + if c := f.End.Counter("leader_deaths"); c != 2 { + t.Fatalf("trace end leader_deaths %v (want 2)", c) + } +} + +// The RFC case: the lead bot revives, so the whole party is never dead in one frame, but all five died within 25 s: one wipe. +func TestObserveCountsAWipeSpreadOverOneEpisode(t *testing.T) { + g := fiveBotLeader(t, observeRunScript()...) + deathsOnTickTable(g, map[int][]int{2: {0}, 3: {1}, 4: {1, 2}, 5: {1, 2, 3}, 6: {1, 2, 3, 4}, 7: {0, 2, 3, 4}}) + dir := t.TempDir() + rep, err := runRemote(t, g, observePlan(), observeOpts(ObserveSpec{}), func(c *Config) { + c.Poll = 5 * time.Second + c.Trace = tracerun.Config{On: true, Dir: dir, RunID: "r-window-wipe"} + }) + if err != nil || rep.State != "done" { + t.Fatalf("%v %s %s", err, rep.State, rep.Error) + } + if rep.Wipes != 1 { + t.Fatalf("wipes %d (want 1)\n%s", rep.Wipes, notesOf(rep)) + } + if rep.LeaderDeaths != 2 { + t.Fatalf("leader deaths %d (want 2)", rep.LeaderDeaths) + } + f, err := trace.Read(filepath.Join(dir, "r-window-wipe.jsonl")) + if err != nil { + t.Fatal(err) + } + wipes := 0 + for _, e := range f.Events { + if e.Ev == "wipe" { + wipes++ + if e.D["window"] != true { + t.Fatalf("the wipe event is not a window wipe: %+v", e.D) + } + } + } + if wipes != 1 { + t.Fatalf("%d wipe events in the trace (want 1)", wipes) + } + for _, c := range tracecheck.Score(f, tracecheck.Defaults()) { + if c.ID == tracecheck.IDDeaths && !strings.Contains(c.Detail, ", 1 wipes") { + t.Fatalf("the deaths oracle does not say 1 wipes: %+v", c) + } + } +} + +// The same deaths 30 s apart are outside the 90 s window: the lead's first death is 120 s older than the last member's, so no wipe. +func TestObserveNoWipeWhenTheDeathsAreOutsideTheWindow(t *testing.T) { + g := fiveBotLeader(t, + leaderStep{0, rs("running", 1, 5, "first", "move", "walk", "walking")}, + leaderStep{s(100), rs("running", 2, 5, "first", "pull", "pull", "pulling")}, + leaderStep{s(200), rs("running", 3, 5, "first", "boss", "pull", "pulling")}, + leaderStep{s(300), rs("running", 4, 5, "first", "move", "walk", "walking")}, + leaderStep{s(400), rs("done", 5, 5, "first", "move", "walk", "plan done")}) + deathsOnTickTable(g, map[int][]int{2: {0}, 3: {1}, 4: {1, 2}, 5: {1, 2, 3}, 6: {1, 2, 3, 4}, 7: {0, 2, 3, 4}}) + dir := t.TempDir() + rep, err := runRemote(t, g, observePlan(), observeOpts(ObserveSpec{}), func(c *Config) { + c.Poll = 30 * time.Second + c.Trace = tracerun.Config{On: true, Dir: dir, RunID: "r-window-out"} + }) + if err != nil || rep.State != "done" { + t.Fatalf("%v %s %s", err, rep.State, rep.Error) + } + if rep.Wipes != 0 { + t.Fatalf("wipes %d (want 0)\n%s", rep.Wipes, notesOf(rep)) + } + f, err := trace.Read(filepath.Join(dir, "r-window-out.jsonl")) + if err != nil { + t.Fatal(err) + } + for _, e := range f.Events { + if e.Ev == "wipe" { + t.Fatalf("a wipe event outside the window: %+v", e.D) + } + } +} + +// The window wipe and the all-dead latch are one wipe: counted at tick 6, the all-dead ticks 7 and 8 must not count it again. +func TestObserveWindowWipeIsNotCountedTwiceWhenTheyThenAllDieTogether(t *testing.T) { + g := fiveBotLeader(t, observeRunScript()...) + deathsOnTickTable(g, map[int][]int{2: {0}, 3: {1}, 4: {1, 2}, 5: {1, 2, 3}, 6: {1, 2, 3, 4}, 7: {0, 1, 2, 3, 4}, 8: {0, 1, 2, 3, 4}}) + dir := t.TempDir() + rep, err := runRemote(t, g, observePlan(), observeOpts(ObserveSpec{}), func(c *Config) { + c.Poll = 5 * time.Second + c.Trace = tracerun.Config{On: true, Dir: dir, RunID: "r-window-once"} + }) + if err != nil || rep.State != "done" { + t.Fatalf("%v %s %s", err, rep.State, rep.Error) + } + if rep.Wipes != 1 { + t.Fatalf("wipes %d (want 1)\n%s", rep.Wipes, notesOf(rep)) + } + f, err := trace.Read(filepath.Join(dir, "r-window-once.jsonl")) + if err != nil { + t.Fatal(err) + } + wipes := 0 + for _, e := range f.Events { + if e.Ev == "wipe" { + wipes++ + } + } + if wipes != 1 { + t.Fatalf("%d wipe events in the trace (want 1)", wipes) + } +} + +// A lone death after the counted wipe is no second wipe. Loxy has been dead for 100 s when the other four die: the all-dead frame counts +// the wipe while the window rule is false (Loxy's death is outside the 90 s), so the revive below three dead re-arms the latch. Loxy then +// dies again 10 s after the wipe: the window rule reads deaths newer than the counted wipe only, so the four deaths of the wipe do not +// make it fire again. The whole party dying inside the window cannot test this: the window rule then stays true for the 90 s of the +// counted wipe, the latch never re-arms, and a lone death counts nothing either way. +func TestObserveNoSecondWipeFromALoneDeathAfterAWindowWipe(t *testing.T) { + g := fiveBotLeader(t, observeRunScript()...) + base, ticks := g.onTick, 0 + g.onTick = func(fr *fakeRemote) { + base(fr) + if !g.running { + return + } + ticks++ + dead := map[int]bool{} + if ticks == 22 { + dead = map[int]bool{0: true, 1: true, 2: true, 4: true} + } + if ticks == 24 { + dead[3] = true + } + if ticks >= 2 && ticks <= 22 { + dead[3] = true // Loxy stays down through the collapse: a death older than the wipe's window + } + for i, p := range fr.party { + if dead[i] { + p.Dead, p.HP, p.State = true, 0, "d" + } else { + p.Dead, p.HP, p.State = false, p.MaxHP, "n" + } + } + } + dir := t.TempDir() + rep, err := runRemote(t, g, observePlan(), observeOpts(ObserveSpec{}), func(c *Config) { + c.Poll = 5 * time.Second + c.Trace = tracerun.Config{On: true, Dir: dir, RunID: "r-window-lone"} + }) + if err != nil || rep.State != "done" { + t.Fatalf("%v %s %s", err, rep.State, rep.Error) + } + if rep.Wipes != 1 { + t.Fatalf("wipes %d (want 1)\n%s", rep.Wipes, notesOf(rep)) + } + if len(rep.Deaths) != 6 { + t.Fatalf("deaths %d (want 6: Loxy's two and the other four in the wipe): %+v", len(rep.Deaths), rep.Deaths) + } + f, err := trace.Read(filepath.Join(dir, "r-window-lone.jsonl")) + if err != nil { + t.Fatal(err) + } + wipes := 0 + for _, e := range f.Events { + if e.Ev == "wipe" { + wipes++ + } + } + if wipes != 1 { + t.Fatalf("%d wipe events in the trace (want 1)", wipes) + } +} + func TestObserveRefusesAServerWithoutTheRunLeaderBeforeHiring(t *testing.T) { g := newFakeLeader(t) g.listText = ""