diff --git a/.gitea/workflows/pr-checks.yml b/.gitea/workflows/pr-checks.yml index 8c264ae..26ed66d 100644 --- a/.gitea/workflows/pr-checks.yml +++ b/.gitea/workflows/pr-checks.yml @@ -57,3 +57,7 @@ jobs: # not portable across the Node versions this project runs on. - name: Test the checker itself run: node --test scripts/checkPlugin.test.js + + # The staging drill's pure parts (tools/drill/drill.js): its stall limit and fresh-data list. + - name: Test the staging drill + run: node --test tools/drill/drill.test.js diff --git a/README.md b/README.md index 891a161..2d3c296 100644 --- a/README.md +++ b/README.md @@ -98,7 +98,7 @@ The API version moves when a call or a raised hook changes shape, not on every r ## After a Rust update: the swap's field list Our NPC is Rust's scientist with two components swapped, and the swap copies a fixed list of fields (D232), -generated from Rust's unmodified assembly. `rnpc.status` reports it as `swap fields: npc=55/55 brain=32/32 +generated from Rust's unmodified assembly. `rnpc.status` reports it as `swap fields: npc=58/58 brain=32/32 missing=- added=-`. On Carbon, where the assembly is unmodified, `added` names any field Rust has added since the list was made. To regenerate it: @@ -121,7 +121,7 @@ shows it, so the drill's live half and `rnpc.status` are what catch it. | Rust type | What RunicNPC depends on | Where (`plugin/RunicNPC.cs`) | Caught by | |---|---|---|---| -| `ScientistNPC` (prefabs `scientistnpc_*`) | Subclassed by `RunicNpcPlayer`; the swap replaces the prefab's component before spawn and copies `SwapNpcFields` (55 fields up its chain to `BaseNetworkable`) | `#region The swap`, `CreateNpc` | compile; field list | +| `ScientistNPC` (prefabs `scientistnpc_*`) | Subclassed by `RunicNpcPlayer`; the swap replaces the prefab's component before spawn and copies `SwapNpcFields` (58 fields up its chain to `BaseNetworkable`) | `#region The swap`, `CreateNpc` | compile; field list | | `ScientistBrain` | Subclassed by `RunicNpcBrain`; the swap copies `SwapBrainFields` (32 fields of `BaseAIBrain`) | `#region The swap` | compile; field list | | `ScientistNPC` / `HumanNPC` virtuals | `displayName`, `AttackerInfo(PlayerLifeStory.DeathInfo)`, `ShotTest(float)`, `TriggerDown()`, `Hurt(HitInfo)`, `OnDied(HitInfo)` overridden | `RunicNpcPlayer` | compile | | `IAIAttack`, `IAISenses` | Re-implemented on `RunicNpcPlayer`: `IsTargetInRange`, `EngagementRange`, `GetBestTarget`, `AttackTick`, `IsTarget`, `IsThreat`, `IsFriendly`. Rust's `HumanNPC.IsTarget` is not virtual, which is why | `RunicNpcPlayer` | compile; a changed meaning only at run time | @@ -153,8 +153,11 @@ the week. A run by hand always goes ahead. plugin against them. - **Live, once per build** (`tools/drill/drill.js live`): the `rust-staging` server (Oxide, a 3500 map) installs the same pair at start (`tools/drill/rig-start.sh`), loads RunicNPC, Kits and - `tools/RunicNpcTest.cs`, and runs `rnt.run all`. When both 6000-map rigs are running, `rust-carbon` is - stopped for it and started again. + `tools/RunicNpcTest.cs`, and runs `rnt.run all`. It starts the server from fresh Kits and RunicNPC data + (RunicNPC's files are deleted and Kits' file holds only the harness's kit, so the example kits are written + afresh) and gives up on the harness after + 5 minutes with no new output (45 minutes at most), putting the tail of the server's log in the issue. When + both 6000-map rigs are running, `rust-carbon` is stopped for it and started again. - **Report:** anything that fails or differs opens one issue for that build, labelled `staging-drill`. The last build checked is kept on the `drill` branch. diff --git a/plugin/RunicNPC.cs b/plugin/RunicNPC.cs index 67b29a8..90b1d1c 100644 --- a/plugin/RunicNPC.cs +++ b/plugin/RunicNPC.cs @@ -947,6 +947,7 @@ namespace Oxide.Plugins "BasePlayer.debugCommandedNpcs", "BasePlayer.GestureViewModel", "BasePlayer.lastPlayerVisibility", + "BasePlayer.timeSinceAiming", "BasePlayer.eyeHistory", "BasePlayer.tickHistory", "BasePlayer.fallDamageEffect", @@ -974,12 +975,14 @@ namespace Oxide.Plugins "BaseEntity.model", "BaseEntity.flags", "BaseEntity.HasBrain", + "BaseEntity.ServerPreProcessed", "BaseNetworkable.postNetworkUpdateComponents", "BaseNetworkable.prefabID", "BaseNetworkable.globalBroadcast", "BaseNetworkable.globalNetworkBehavior", "BaseNetworkable.globalBuildingBlock", "BaseNetworkable.networkRange", + "BaseNetworkable.ignoreNetworkLod", }; private static readonly string[] SwapBrainFields = { diff --git a/tools/RunicNpcTest.cs b/tools/RunicNpcTest.cs index a16a4a2..f2fdb27 100644 --- a/tools/RunicNpcTest.cs +++ b/tools/RunicNpcTest.cs @@ -45,7 +45,7 @@ namespace Oxide.Plugins /// a made-up user id (11400000001 and up), so IsNpc is false. They take no damage. /// /// - [Info("RunicNpcTest", "Runic Gateway", "0.7.3")] + [Info("RunicNpcTest", "Runic Gateway", "0.7.4")] [Description("RunicNPC stage 2 to 7 tests, the stage 6 spike and stage 9's cost check. A developer tool: never ship it.")] internal class RunicNpcTest : RustPlugin { @@ -753,7 +753,25 @@ namespace Oxide.Plugins continue; } - while (inner.MoveNext()) yield return inner.Current; + // A group that throws is a FAIL line, not the end of the run: yield cannot sit inside a try, so + // each step is taken inside one and the value is yielded outside it. + while (true) + { + object step; + try + { + if (!inner.MoveNext()) break; + step = inner.Current; + } + catch (Exception e) + { + Check($"{g}.exception", false, $"{e.GetType().Name}: {e.Message} at {(e.StackTrace ?? "").Split('\n').FirstOrDefault()?.Trim()}"); + break; + } + + yield return step; + } + Api("RunicNpc_DespawnOwner", Owner); ClearWorld(); yield return new WaitForSeconds(1f); @@ -1095,16 +1113,28 @@ namespace Oxide.Plugins private IEnumerator Place(Vector3 field) { - Vector3 a = field + new Vector3(-40, 0, 0); - Vector3 b = field + new Vector3(-40, 0, 30); - StandIn(field + new Vector3(-40, 0, 110), 8); - Check("place.set.each", Api("RunicNpc_SetPlacement", "t_each", Placement("t_each", a, 3, 20f, "each")) == null, ""); - Check("place.set.group", Api("RunicNpc_SetPlacement", "t_group", Placement("t_roam", b, 3, 20f, "group")) == null, ""); + // A roamer's spot must be on the navmesh when it is set (D219), so both spots are put there; the + // wider search because a fixed offset from the field can land a few metres off it (run 49: 4.4 m). + Vector3 a = OnMesh(field + new Vector3(-40, 0, 0), 15f); + Vector3 b = OnMesh(field + new Vector3(-40, 0, 30), 15f); + StandIn(OnMesh(field + new Vector3(-40, 0, 110)), 8); + string eachRefusal = Api("RunicNpc_SetPlacement", "t_each", Placement("t_each", a, 3, 20f, "each")); + Check("place.set.each", eachRefusal == null, eachRefusal ?? ""); + string groupRefusal = Api("RunicNpc_SetPlacement", "t_group", Placement("t_roam", b, 3, 20f, "group")); + Check("place.set.group", groupRefusal == null, groupRefusal ?? ""); yield return new WaitForSeconds(4f); List> each = List("placement:t_each"); List> group = List("placement:t_group"); Check("place.spawned", each.Count == 3 && group.Count == 3, $"each {each.Count}, group {group.Count}"); + if (each.Count != 3 || group.Count != 3) + { + // Everything below needs both sets alive. Take back what was set and end the group, so the run goes on. + Api("RunicNpc_RemovePlacement", "t_each"); + Api("RunicNpc_RemovePlacement", "t_group"); + Note("place: the placements did not spawn, so the rest of the group is skipped"); + yield break; + } // each: kill one; the other two stay, and it alone returns after ~20 s. var survivors = new HashSet(each.Skip(1).Select(x => (ulong)x["netId"])); @@ -1540,11 +1570,11 @@ namespace Oxide.Plugins return floor; } - private static Vector3 OnMesh(Vector3 p) + private static Vector3 OnMesh(Vector3 p, float radius = 3f) { p.y = TerrainMeta.HeightMap.GetHeight(p); NavMeshHit hit; - return SampleNavmesh(p, 3f, out hit) ? hit.position : p; + return SampleNavmesh(p, radius, out hit) ? hit.position : p; } private static JObject Placement(string profile, Vector3 at, int count, float respawn, string mode) => diff --git a/tools/drill/drill.js b/tools/drill/drill.js index d7bf19e..1ea36d3 100644 --- a/tools/drill/drill.js +++ b/tools/drill/drill.js @@ -30,6 +30,22 @@ const BIG = (process.env.DRILL_BIG_RIGS || 'rust-oxide,rust-carbon').split(',') const STOPPABLE = process.env.DRILL_STOPPABLE || 'rust-carbon' const KITS_URL = 'https://umod.org/plugins/Kits.cs' const WAIT_DAYS = 3 // D317: how long a build waits for Oxide to catch up +const HARNESS_CAP_MS = 45 * 60000 // the whole harness run +const HARNESS_STALL_MS = 5 * 60000 // no new line in its file for this long: it has stopped (issue #20) + +// What a fresh server would not have (issue #20). RunicNPC writes its four example kits once, into +// Kits' own file, and never again, so a file kept from an older build keeps that build's kits; the drill +// starts from none of it. Files, never directories: a directory the panel's file API creates is not +// writable by the game (docs/runicnpc/PLAN.md ยง1.5), and the game makes these itself on its first boot. +// Kits' file is not deleted but replaced by one holding only the harness's kit (KITS_FILE, harnessKits): +// Kits reads it at boot and RunicNPC adds its examples beside it, so no reload is needed for it (#22). +const KITS_FILE = '/oxide/data/Kits/kits_data.json' +const FRESH_DATA = [ + '/oxide/data/RunicNPC/profiles.json', + '/oxide/data/RunicNPC/placements.json', + '/oxide/data/RunicNPC/routes.json', + '/oxide/data/RunicNPC/state.json', +] const sleep = (ms) => new Promise((r) => setTimeout(r, ms)) const now = () => new Date().toISOString() @@ -262,7 +278,10 @@ async function live(a) { await p.rm(rig, '/oxide/plugins/RunicNpcTest.cs') await p.rm(rig, '/oxide/data/RunicNpcTest.json') await p.rm(rig, '/staging-drill.json') + for (const f of FRESH_DATA) await p.rm(rig, f) // already gone is fine: rm swallows it + await p.write(rig, KITS_FILE, JSON.stringify(harnessKits(), null, 2)) + const logMark = await oxideLogMark(p, rig) log(`starting ${RIG} on ${branch}`) const started = Date.now() await p.power(rig, 'start') @@ -280,7 +299,7 @@ async function live(a) { const status = await waitStatus(p, rig, 30 * 60000) if (!status) { finding('RunicNPC did not load: `rnpc.status` never answered.') - result.oxideErrors = await oxideErrors(p, rig) + result.oxideErrors = await oxideErrors(p, rig, logMark) return } result.status = status @@ -294,7 +313,7 @@ async function live(a) { } // The harness needs the hidden Kits kit rnhrevolver (tools/RunicNpcTest.cs). - await ensureKit(p, rig) + await ensureKit(p, rig, finding) await p.write(rig, '/oxide/plugins/RunicNpcTest.cs', fs.readFileSync(path.join(ROOT, 'tools', 'RunicNpcTest.cs'), 'utf8')) let accepted = false @@ -304,18 +323,22 @@ async function live(a) { } if (!accepted) { finding('The test harness did not load (`rnt.run all` was not answered).') - result.oxideErrors = await oxideErrors(p, rig) + result.oxideErrors = await oxideErrors(p, rig, logMark) return } result.ran = true log('rnt.run all: running') - const lines = await waitHarness(p, rig, 45 * 60000) + const { lines, ended } = await waitHarness(p, rig, HARNESS_CAP_MS, HARNESS_STALL_MS) result.harness = summarise(lines) - if (!result.harness.done) finding(`The harness did not finish in 45 minutes (${result.harness.pass} pass, ${result.harness.fail} fail so far).`) + if (!result.harness.done) { + finding(unfinishedFinding(result.harness, lines, ended)) + // What the server said while it stalled (an exception in the harness's coroutine lands here, not in its file). + result.consoleTail = safeTail(await p.readOr(rig, '/latest.log', ''), 40) + } for (const f of result.harness.failed) finding(`Harness: ${f}`) log(`harness: ${result.harness.pass} pass, ${result.harness.fail} fail`) - result.oxideErrors = await oxideErrors(p, rig) + result.oxideErrors = await oxideErrors(p, rig, logMark) if (result.oxideErrors.length) finding(`RunicNPC logged ${result.oxideErrors.length} error line(s) in Oxide's log during the run.`) await p.command(rig, 'rnt.clear').catch(() => {}) } catch (e) { @@ -368,8 +391,18 @@ async function waitStatus(p, id, timeoutMs) { return last } -async function ensureKit(p, id) { - const file = '/oxide/data/Kits/kits_data.json' +/** Kits' data file holding only the harness's hidden kit, which the drill lays down before the start. */ +function harnessKits() { + return { _kits: { rnhrevolver: harnessKit() } } +} + +/** + * The harness's kit is laid down before the start (harnessKits), so it is normally there. If it is not + * (RunicNPC rewrote the file without it), it is added and Kits reloaded through the console's websocket: + * the panel's fire-and-forget command left no reload in run 48 (#22), so the reply is logged. + */ +async function ensureKit(p, id, finding) { + const file = KITS_FILE let data = null for (let i = 0; i < 12 && !data; i++) { data = readJsonText(await p.readOr(id, file, null)) @@ -377,9 +410,21 @@ async function ensureKit(p, id) { } if (!data) throw new Error(`Kits wrote no ${file}`) data._kits = data._kits || {} - if (data._kits.rnhrevolver) return + if (data._kits.rnhrevolver) { + log('the rnhrevolver kit is in Kits\' file, laid down before the start') + return + } + data._kits.rnhrevolver = harnessKit() + await p.write(id, file, JSON.stringify(data, null, 2)) + const reply = await p.console(id, 'oxide.reload Kits', 15) + const loaded = reply.some((l) => /Loaded plugin Kits/.test(l)) + log(`added the rnhrevolver kit and reloaded Kits: ${loaded ? 'Kits loaded again' : `no "Loaded plugin Kits" in 15 s (${reply.length} console line(s))`}`) + if (!loaded) finding('Kits did not reload after the drill added the harness\'s rnhrevolver kit; the harness\'s profiles may be refused.') +} + +function harnessKit() { const item = (Shortname, Amount, Position, Condition = 0) => ({ Shortname, Skin: 0, Amount, Condition, MaxCondition: Condition, Ammo: 0, Position, Frequency: -1 }) - data._kits.rnhrevolver = { + return { Name: 'rnhrevolver', Description: 'RunicNPC test harness: revolver + burlap (staging drill)', RequiredPermission: '', @@ -394,10 +439,6 @@ async function ensureKit(p, id) { WearItems: [item('burlap.shirt', 1, 0), item('burlap.trousers', 1, 1), item('hat.boonie', 1, 2)], BeltItems: [item('pistol.revolver', 1, 0, 100)], } - await p.write(id, file, JSON.stringify(data, null, 2)) - await p.command(id, 'oxide.reload Kits') - await sleep(10000) - log('added the rnhrevolver kit and reloaded Kits') } function readJsonText(t) { @@ -408,15 +449,38 @@ function readJsonText(t) { } } -async function waitHarness(p, id, timeoutMs) { - const end = Date.now() + timeoutMs +/** + * Where the harness stands, given its lines now and what was last seen of them ({ count, at }): done + * (`# done all:`), stalled (no new line for stallMs: it died without saying so, as in issue #20), or running. + */ +function harnessProgress(lines, seen, nowMs, stallMs) { + if (lines.some((l) => /^# done all:/.test(l))) return { state: 'done', seen } + if (lines.length > seen.count) return { state: 'running', seen: { count: lines.length, at: nowMs } } + if (nowMs - seen.at >= stallMs) return { state: 'stalled', seen } + return { state: 'running', seen } +} + +/** Waits for the harness; `ended` is done, stalled or capped (timeoutMs passed). */ +async function waitHarness(p, id, timeoutMs, stallMs) { + const start = Date.now() let lines = [] - while (Date.now() < end) { + let seen = { count: 0, at: start } + while (Date.now() < start + timeoutMs) { await sleep(30000) lines = readJsonText(await p.readOr(id, '/oxide/data/RunicNpcTest.json', null)) || lines - if (lines.some((l) => /^# done all:/.test(l))) break + const v = harnessProgress(lines, seen, Date.now(), stallMs) + seen = v.seen + if (v.state !== 'running') return { lines, ended: v.state } } - return lines + return { lines, ended: 'capped' } +} + +/** The finding for a harness that never wrote `# done all:`. */ +function unfinishedFinding(h, lines, ended) { + const so = `${h.pass} pass, ${h.fail} fail so far` + if (ended !== 'stalled') return `The harness did not finish in ${HARNESS_CAP_MS / 60000} minutes (${so}).` + const last = (lines[lines.length - 1] || 'no line at all').replace(/`/g, "'").slice(0, 200) + return `The harness stopped after \`${last}\` (no output for ${HARNESS_STALL_MS / 60000} minutes; ${so}).` } function summarise(lines) { @@ -427,10 +491,17 @@ function summarise(lines) { } /** RunicNPC's and the harness's error lines from today's Oxide log. */ -async function oxideErrors(p, id) { +/** Where Oxide's log of today ends now, so oxideErrors reads only what a run adds (run 49 counted run 48's). */ +async function oxideLogMark(p, id) { + const day = now().slice(0, 10) + return { day, length: ((await p.readOr(id, `/oxide/logs/oxide_${day}.txt`, '')) || '').length } +} + +async function oxideErrors(p, id, since = null) { const day = now().slice(0, 10) const text = (await p.readOr(id, `/oxide/logs/oxide_${day}.txt`, '')) || '' return text + .slice(since && since.day === day ? since.length : 0) .split('\n') .filter((l) => /RunicNPC|RunicNpcTest/.test(l) && /\[Error\]|Exception|Failed|error CS/.test(l)) .slice(-40) @@ -578,14 +649,19 @@ async function fileIssue(title, body) { // ---------------------------------------------------------------- main -const a = args() -const commands = { window: window_, gate, live, report } -const command = commands[a._[0]] -if (!command) { - console.error('usage: node tools/drill/drill.js window|gate|live|report [--state f] [--work dir] [--branch b] [--force]') - process.exit(2) +// The pure parts, for drill.test.js; run as a script, it is the command line. +module.exports = { harnessProgress, unfinishedFinding, FRESH_DATA, KITS_FILE, harnessKits, HARNESS_STALL_MS } + +if (require.main === module) { + const a = args() + const commands = { window: window_, gate, live, report } + const command = commands[a._[0]] + if (!command) { + console.error('usage: node tools/drill/drill.js window|gate|live|report [--state f] [--work dir] [--branch b] [--force]') + process.exit(2) + } + command(a).catch((e) => { + console.error(e.message || e) + process.exit(1) + }) } -command(a).catch((e) => { - console.error(e.message || e) - process.exit(1) -}) diff --git a/tools/drill/drill.test.js b/tools/drill/drill.test.js new file mode 100644 index 0000000..73ad312 --- /dev/null +++ b/tools/drill/drill.test.js @@ -0,0 +1,67 @@ +// The drill's pure parts: how it decides the harness has stopped (issue #20), and what it starts clean. +// node --test tools/drill/drill.test.js + +const test = require('node:test') +const assert = require('node:assert') +const { harnessProgress, unfinishedFinding, FRESH_DATA, KITS_FILE, harnessKits, HARNESS_STALL_MS } = require('./drill.js') + +const MIN = 60000 +const T0 = 1000000 + +test('a harness that keeps writing is running, and its clock restarts on each new line', () => { + let v = harnessProgress(['# run all'], { count: 0, at: T0 }, T0 + 30000, HARNESS_STALL_MS) + assert.equal(v.state, 'running') + assert.deepEqual(v.seen, { count: 1, at: T0 + 30000 }) + // Four silent minutes, then a line: still running, and the clock restarts. + v = harnessProgress(['# run all', 'a: PASS '], v.seen, T0 + 30000 + 4 * MIN, HARNESS_STALL_MS) + assert.equal(v.state, 'running') + assert.equal(v.seen.at, T0 + 30000 + 4 * MIN) +}) + +test('no new line for five minutes is a stall; four minutes and a bit is not', () => { + const seen = { count: 2, at: T0 } + const lines = ['# run all', 'a: PASS '] + assert.equal(harnessProgress(lines, seen, T0 + 5 * MIN - 1, HARNESS_STALL_MS).state, 'running') + assert.equal(harnessProgress(lines, seen, T0 + 5 * MIN, HARNESS_STALL_MS).state, 'stalled') +}) + +test('a harness that never wrote a line stalls from when the wait began', () => { + assert.equal(harnessProgress([], { count: 0, at: T0 }, T0 + 5 * MIN, HARNESS_STALL_MS).state, 'stalled') +}) + +test('done wins, even when the file has been still for a long time', () => { + const lines = ['# run all', '# done all: 10 pass, 1 fail'] + assert.equal(harnessProgress(lines, { count: 2, at: T0 }, T0 + 30 * MIN, HARNESS_STALL_MS).state, 'done') +}) + +test('the stall finding names the last line and the counts', () => { + const lines = ['# run all', 'place.set.each: FAIL position: off the navmesh', 'place.spawned: FAIL each 0, group 3'] + const f = unfinishedFinding({ pass: 40, fail: 2 }, lines, 'stalled') + assert.equal(f, 'The harness stopped after `place.spawned: FAIL each 0, group 3` (no output for 5 minutes; 40 pass, 2 fail so far).') +}) + +test('a backtick in the last line cannot break the issue body, and a long line is cut', () => { + const f = unfinishedFinding({ pass: 0, fail: 0 }, ['x`y' + 'z'.repeat(500)], 'stalled') + assert.equal(f.split('`').length, 3) + assert.ok(f.length < 330) + assert.match(unfinishedFinding({ pass: 0, fail: 0 }, [], 'stalled'), /stopped after `no line at all`/) +}) + +test('a capped wait keeps the 45-minute message', () => { + assert.equal(unfinishedFinding({ pass: 3, fail: 1 }, ['# run all'], 'capped'), 'The harness did not finish in 45 minutes (3 pass, 1 fail so far).') +}) + +test('the clean start deletes files only: every path ends in .json and none is a directory', () => { + assert.ok(FRESH_DATA.includes('/oxide/data/RunicNPC/state.json')) + for (const f of FRESH_DATA) assert.match(f, /^\/oxide\/data\/RunicNPC\/[a-z_]+\.json$/) +}) + +test("Kits' file is replaced, not deleted, by one holding only the harness's kit (#22)", () => { + assert.ok(!FRESH_DATA.includes(KITS_FILE)) + assert.equal(KITS_FILE, '/oxide/data/Kits/kits_data.json') + const kits = harnessKits()._kits + assert.deepEqual(Object.keys(kits), ['rnhrevolver']) + assert.equal(kits.rnhrevolver.Name, 'rnhrevolver') + assert.equal(kits.rnhrevolver.IsHidden, true) + assert.deepEqual(kits.rnhrevolver.BeltItems.map((i) => i.Shortname), ['pistol.revolver']) +})