util: fix encounter start bug in make/test timeline scripts (#15)

(sorry for the git bork/closed PR - one more time...) This PR should address the encounter sync drift referenced in quisquous#5635 and quisquous#6048, as well as the missing zone-seal sync referenced in quisquous#5716. There were a couple of separate but related issues that I found: 1. `encounter_tools` had not (yet) been updated to use `InCombat` lines to start encounters, even though `make_timeline` is inserting an `InCombat` sync at the start of a new timeline. 2. For fights that do not have zone seals, `encounter_tools` would fall back on using `playerAttackingMob` or `mobAttackingPlayer` regex. While this mostly still worked (with minor drift issues), it was also counting faerie healing actions as the start of the fight. I confirmed this was the case with the log in issue 6048. I don't have logs for the original report from issue 5635, but I suspect a similar cause there, as I was unable to repro in e6n when on non-pet classes. 3. I think there was a minor logic bug in `encounter_tools` re: pushing the fight-starting log line into `logLines`. When encountering certain log lines that should trigger a new fight encounter, `onStartFight()` would reinitialize `this.currentFight` and set `.startTime`; but when `storeStartLine()` was subsequently called, it would not push the starting log line into `.logLines` because the fight already had a start time set. This was causing make/test_timeline to sometimes not have access to (and not be able to sync on) the log line that started the encounter. I'm wary about unintentional breakage, given the various different events that should (or should not) start a timeline. cc: @xiashtra and @JLGarber, would appreciate an extra set of eyes.
OverlayPlugin · Dec 24, 2023 · eab4545 · eab4545
1 parent c6130d5
commit eab4545
Show file tree

Hide file tree

Showing 4 changed files with 107 additions and 88 deletions.
diff --git a/docs/TimelineGuide.md b/docs/TimelineGuide.md
@@ -597,9 +597,9 @@ $ node --loader=ts-node/esm util/logtools/make_timeline.ts -f docs/logs/TheAbyss
 ┌───────┬──────────────┬────────────────┬──────────┬──────────────────────────────────┬──────────────────────────────────┬──────────┐
 │ Index │  Start Date  │   Start Time   │ Duration │            Zone Name             │          Encounter Name          │ End Type │
 ├───────┼──────────────┼────────────────┼──────────┼──────────────────────────────────┼──────────────────────────────────┼──────────┤
-│   1   │  2023-10-06  │  20:20:08.265  │   10m    │  The Abyssal Fracture (Extreme)  │  The Abyssal Fracture (Extreme)  │   Win    │
-│   2   │  2023-10-06  │  21:09:43.014  │   12m    │  The Abyssal Fracture (Extreme)  │  The Abyssal Fracture (Extreme)  │   Win    │
-│   3   │  2023-10-06  │  21:55:12.239  │    9m    │  The Abyssal Fracture (Extreme)  │  The Abyssal Fracture (Extreme)  │   Win    │
+│   1   │  2023-10-06  │  20:21:20.456  │    9m    │  The Abyssal Fracture (Extreme)  │  The Abyssal Fracture (Extreme)  │   Win    │
+│   2   │  2023-10-06  │  21:11:44.502  │   10m    │  The Abyssal Fracture (Extreme)  │  The Abyssal Fracture (Extreme)  │   Win    │
+│   3   │  2023-10-06  │  21:55:24.409  │    9m    │  The Abyssal Fracture (Extreme)  │  The Abyssal Fracture (Extreme)  │   Win    │
 └───────┴──────────────┴────────────────┴──────────┴──────────────────────────────────┴──────────────────────────────────┴──────────┘
 ```
 
@@ -622,32 +622,18 @@ hideall "--Reset--"
 hideall "--sync--"
 
 0.0 "--sync--" InCombat { inGameCombat: "1" } window 0,1
-72.8 "--sync--" Ability { id: "8C49", source: "Zeromus" }
-75.8 "--sync--" Ability { id: "8C49", source: "Zeromus" }
-83.9 "Abyssal Nox" Ability { id: "8B3F", source: "Zeromus" }
-92.9 "--sync--" Ability { id: "8B41", source: "Zeromus" }
-92.9 "--sync--" #Ability { id: "8B40", source: "Zeromus" }
-92.9 "--sync--" #Ability { id: "8B40", source: "Zeromus" }
-92.9 "--sync--" Ability { id: "8D2B", source: "Zeromus" }
-97.9 "--sync--" Ability { id: "8B41", source: "Zeromus" }
-97.9 "--sync--" Ability { id: "8B40", source: "Zeromus" }
-99.9 "Abyssal Echoes" Ability { id: "8B42", source: "Zeromus" }
+3.6 "--sync--" Ability { id: "8C49", source: "Zeromus" }
+11.7 "Abyssal Nox" Ability { id: "8B3F", source: "Zeromus" }
+20.7 "--sync--" Ability { id: "8B41", source: "Zeromus" }
+20.7 "--sync--" #Ability { id: "8B40", source: "Zeromus" }
+20.7 "--sync--" #Ability { id: "8B40", source: "Zeromus" }
+20.7 "--sync--" Ability { id: "8D2B", source: "Zeromus" }
+25.7 "--sync--" Ability { id: "8B41", source: "Zeromus" }
+25.7 "--sync--" Ability { id: "8B40", source: "Zeromus" }
+27.7 "Abyssal Echoes" Ability { id: "8B42", source: "Zeromus" }
 # etc etc etc
 ```
 
-TODO: for some reason, `make_timeline.ts` is confused here and thinks the first
-real ability (Abyssal Nox 8B3F) occurs at time=83.9.
-It's clear from the log that it should be t=11.1.
-See: <https://github.com/quisquous/cactbot/issues/6048>
-
-```text
-260|2023-10-06T20:21:19.9510000-07:00|1|0|
-20|2023-10-06T20:21:27.1110000-07:00|40022550|Zeromus|8B3F|Abyssal Nox|40022550|Zeromus|4.700|100.00|80.10|0.00|0.00|
-22|2023-10-06T20:21:32.1010000-07:00|40022550|Zeromus|8B3F|Abyssal Nox|10FF0007|Kehabiqo Febiqo|4A|10000|E|6E90000|1B|8B3F8000|0|0|0|0|0|0|0|0|0|0|126650|128564|10000|10000|||99.95|97.53|0.00|3.14|39444801|40478540|10000|10000|||100.00|80.10|0.00|0.00|0001A48D|0|8|
-```
-
-You can fix this by running with `-p 8B3F:11.1` which will set the first use of `8B3F` to be time `11.`1.
-
 From here, it's a question of massaging this timeline into something that's usable.
 
 It may be tedious, but the best place to start when making a timeline is by filling out the
@@ -1216,11 +1202,8 @@ There's plenty of feature work and fixes for timelines if you are interested in
 * make it so you can pass multiple mob names to `-it`
 * `test_timeline.ts` could know which file to use without `-t` (it could use `ZoneChange` lines to look up the correct timeline)
 * `make_timeline.ts` has issues with empty names: <https://github.com/quisquous/cactbot/issues/5943>
-* `test_timeline.ts` sometimes misses seal lines that are in the log: <https://github.com/quisquous/cactbot/issues/5716>
-* investigate this drift issue: <https://github.com/quisquous/cactbot/issues/5635>
 * make it possible to pass a set of ids that should be named `--sync--`: <https://github.com/quisquous/cactbot/issues/5510>
 * fix the log splitter so that when importing into ACT separate fights stay separate (maybe need to keep one new zone line? or just insert a fake `/echo end`?)
-* fix the offset issue with make/test timeline on zeromus log file: <https://github.com/quisquous/cactbot/issues/6048>
 
 ### Larger Features
 

diff --git a/resources/netregexes.ts b/resources/netregexes.ts
@@ -594,6 +594,13 @@ export default class NetRegexes {
     return buildRegex('CEDirector', params);
   }
 
+  /**
+   * matches: https://github.com/OverlayPlugin/cactbot/blob/main/docs/LogGuide.md#line-260-0x104-incombat
+   */
+  static inCombat(params?: NetParams['InCombat']): CactbotBaseRegExp<'InCombat'> {
+    return buildRegex('InCombat', params);
+  }
+
   /**
    * matches: https://github.com/OverlayPlugin/cactbot/blob/main/docs/LogGuide.md#line-261-0x105-combatantmemory
    */

diff --git a/util/logtools/encounter_tools.ts b/util/logtools/encounter_tools.ts
@@ -2,6 +2,7 @@ import ContentType from '../../resources/content_type';
 import DTFuncs from '../../resources/datetime';
 import NetRegexes, { commonNetRegex } from '../../resources/netregexes';
 import { UnreachableCode } from '../../resources/not_reached';
+import PetData from '../../resources/pet_names';
 import StringFuncs from '../../resources/stringhandlers';
 import ZoneInfo from '../../resources/zone_info';
 import { NetAnyMatches, NetMatches } from '../../types/net_matches';
@@ -26,6 +27,7 @@ type FightEncInfo = ZoneEncInfo & {
   sealName?: string;
   sealId?: string;
   logLines?: string[];
+  inferredStartFromAbility?: boolean;
 };
 
 export class EncounterFinder {
@@ -45,13 +47,63 @@ export class EncounterFinder {
     win: CactbotBaseRegExp<'ActorControl'>;
     wipe: CactbotBaseRegExp<'ActorControl'>;
     commence: CactbotBaseRegExp<'ActorControl'>;
+    inCombat: CactbotBaseRegExp<'InCombat'>;
     playerAttackingMob: CactbotBaseRegExp<'Ability'>;
     mobAttackingPlayer: CactbotBaseRegExp<'Ability'>;
   };
 
   sealRegexes: Array<CactbotBaseRegExp<'GameLog'>> = [];
   unsealRegexes: Array<CactbotBaseRegExp<'GameLog'>> = [];
 
+  // Some NPCs can be picked up by our entry processor.
+  // We list them out explicitly here so we can ignore them at will.
+  ignoredCombatants = PetData['en'].concat([
+    '',
+    'Alisaie',
+    'Alisaie\'s Avatar',
+    'Alphinaud',
+    'Alphinaud\'s Avatar',
+    'Arenvald',
+    'Carbuncle',
+    'Carvallain',
+    'Crystal Exarch',
+    'Doman Liberator',
+    'Doman Shaman',
+    'Earthly Star',
+    'Emerald Carbuncle',
+    'Emerald Garuda',
+    'Estinien',
+    'Estinien\'s Avatar',
+    'G\'raha Tia',
+    'G\'raha Tia\'s Avatar',
+    'Gosetsu',
+    'Hien',
+    'Liturgic Bell',
+    'Lyse',
+    'Mikoto',
+    'Minfilia',
+    'Mol Youth',
+    'Moonstone Carbuncle',
+    'Obsidian Carbuncle',
+    'Raubahn',
+    'Resistance Fighter',
+    'Resistance Pikedancer',
+    'Ruby Carbuncle',
+    'Ruby Ifrit',
+    'Ryne',
+    'Thancred',
+    'Thancred\'s Avatar',
+    'Topaz Carbuncle',
+    'Topaz Titan',
+    'Urianger',
+    'Urianger\'s Avatar',
+    'Varshahn',
+    'Y\'shtola',
+    'Y\'shtola\'s Avatar',
+    'Yugiri',
+    'Zero',
+  ]);
+
   initializeZone(): void {
     this.currentZone = {};
     this.zoneInfo = undefined;
@@ -70,6 +122,7 @@ export class EncounterFinder {
       win: NetRegexes.network6d({ command: '4000000[23]' }),
       wipe: commonNetRegex.wipe,
       commence: NetRegexes.network6d({ command: '4000000[16]' }),
+      inCombat: NetRegexes.inCombat({ inGameCombat: '1', isGameChanged: '1' }),
       playerAttackingMob: NetRegexes.ability({ sourceId: '1.{7}', targetId: '4.{7}' }),
       mobAttackingPlayer: NetRegexes.ability({ sourceId: '4.{7}', targetId: '1.{7}' }),
     };
@@ -187,7 +240,6 @@ export class EncounterFinder {
     const netSeal = this.regex.netSeal.exec(line)?.groups;
     if (netSeal) {
       this.onNetSeal(line, netSeal.param1, netSeal);
-      this.storeStartLine(line, store);
       return;
     }
 
@@ -219,14 +271,35 @@ export class EncounterFinder {
 
     // Most dungeons and some older raid content have zone zeals that indicate encounters.
     // If they don't, we need to start encounters by looking for combat.
+    // InCombat (0x104) log lines (w/ isChanged fields) were implemented in OverlayPlugin v0.19.23.
+    // They are the preferred method of detection, but to maintain backwards compatibility
+    // with prior logs and to account for potentially strange edge cases, we should continue
+    // to use mobAttackingPlayer / playerAttackingMob as a fallback method to detect encounters.
     if (!(this.currentFight.startTime || this.haveWon || this.haveSeenSeals)) {
-      let a = this.regex.playerAttackingMob.exec(line);
-      if (!a)
-        // TODO: This regex catches faerie healing and could potentially give false positives!
-        a = this.regex.mobAttackingPlayer.exec(line);
-      if (a?.groups) {
-        this.onStartFight(line, a.groups, this.currentZone.zoneName);
-        this.storeStartLine(line, store);
+      const combatLine = this.regex.inCombat.exec(line);
+      if (combatLine?.groups) {
+        this.onStartFight(line, combatLine.groups, this.currentZone.zoneName);
+        return;
+      }
+      const pAttack = this.regex.playerAttackingMob.exec(line);
+      if (pAttack?.groups && !this.ignoredCombatants.includes(pAttack.groups?.target)) {
+        this.onStartFight(line, pAttack.groups, this.currentZone.zoneName);
+        this.currentFight.inferredStartFromAbility = true;
+        return;
+      }
+      const mAttack = this.regex.mobAttackingPlayer.exec(line);
+      if (mAttack?.groups && !this.ignoredCombatants.includes(mAttack.groups?.source)) {
+        this.onStartFight(line, mAttack.groups, this.currentZone.zoneName);
+        this.currentFight.inferredStartFromAbility = true;
+        return;
+      }
+    }
+
+    // If we've started a fight due to ability use, we should restart the fight on an InCombat line.
+    if (this.currentFight.startTime && this.currentFight.inferredStartFromAbility) {
+      const combatLine = this.regex.inCombat.exec(line);
+      if (combatLine?.groups) {
+        this.onStartFight(line, combatLine.groups, this.currentZone.zoneName);
         return;
       }
     }
@@ -246,7 +319,7 @@ export class EncounterFinder {
   }
   onStartFight(
     line: string,
-    matches: NetMatches['Ability' | 'GameLog' | 'SystemLogMessage'],
+    matches: NetMatches['Ability' | 'GameLog' | 'SystemLogMessage' | 'InCombat'],
     fightName?: string,
     sealId?: string,
   ): void {
@@ -257,6 +330,8 @@ export class EncounterFinder {
       startLine: line,
       startTime: TLFuncs.dateFromMatches(matches),
       zoneId: this.currentZone.zoneId,
+      inferredStartFromAbility: false,
+      logLines: [line],
     };
   }
 
@@ -302,7 +377,7 @@ class EncounterCollector extends EncounterFinder {
 
   override onStartFight(
     line: string,
-    matches: NetMatches['Ability' | 'GameLog' | 'SystemLogMessage'],
+    matches: NetMatches['Ability' | 'GameLog' | 'SystemLogMessage' | 'InCombat'],
     fightName?: string,
     sealId?: string,
   ): void {
@@ -313,6 +388,8 @@ class EncounterCollector extends EncounterFinder {
       startLine: line,
       startTime: TLFuncs.dateFromMatches(matches),
       zoneId: this.currentZone.zoneId,
+      inferredStartFromAbility: false,
+      logLines: [line],
     };
   }
 

diff --git a/util/logtools/make_timeline.ts b/util/logtools/make_timeline.ts
@@ -4,7 +4,6 @@ import readline from 'readline';
 import { Namespace } from 'argparse';
 
 import NetRegexes from '../../resources/netregexes';
-import PetData from '../../resources/pet_names';
 import SFuncs from '../../resources/stringhandlers';
 import { NetMatches } from '../../types/net_matches';
 
@@ -63,54 +62,7 @@ class ExtendedArgsRequired extends Namespace implements TimelineArgs {
 
 type ExtendedArgs = Partial<ExtendedArgsRequired>;
 
-// Some NPCs can be picked up by our entry processor.
-// We list them out explicitly here so we can ignore them at will.
-const ignoredCombatants = PetData['en'].concat([
-  '',
-  'Alisaie',
-  'Alisaie\'s Avatar',
-  'Alphinaud',
-  'Alphinaud\'s Avatar',
-  'Arenvald',
-  'Carbuncle',
-  'Carvallain',
-  'Crystal Exarch',
-  'Doman Liberator',
-  'Doman Shaman',
-  'Earthly Star',
-  'Emerald Carbuncle',
-  'Emerald Garuda',
-  'Estinien',
-  'Estinien\'s Avatar',
-  'G\'raha Tia',
-  'G\'raha Tia\'s Avatar',
-  'Gosetsu',
-  'Hien',
-  'Liturgic Bell',
-  'Lyse',
-  'Mikoto',
-  'Minfilia',
-  'Mol Youth',
-  'Moonstone Carbuncle',
-  'Obsidian Carbuncle',
-  'Raubahn',
-  'Resistance Fighter',
-  'Resistance Pikedancer',
-  'Ruby Carbuncle',
-  'Ruby Ifrit',
-  'Ryne',
-  'Thancred',
-  'Thancred\'s Avatar',
-  'Topaz Carbuncle',
-  'Topaz Titan',
-  'Urianger',
-  'Urianger\'s Avatar',
-  'Varshahn',
-  'Y\'shtola',
-  'Y\'shtola\'s Avatar',
-  'Yugiri',
-  'Zero',
-]);
+const ignoredCombatants = new EncounterCollector().ignoredCombatants;
 
 const timelineParse = new LogUtilArgParse();