204 lines
13 KiB
Python
204 lines
13 KiB
Python
#!/usr/bin/env python3
|
|
"""Read-only, bounded observation and deterministic test report. No bot repairs."""
|
|
from pathlib import Path
|
|
import collections,datetime,json,os,re,subprocess,sys,time
|
|
import test_driver as d
|
|
BASE=d.BASE
|
|
REPORT=d.ROOT/'doc/clientless/2026-11-02-0800-test-report.md'
|
|
def append(path,value):
|
|
with path.open('a') as f:f.write(json.dumps(value,ensure_ascii=False)+'\n')
|
|
def load(path):
|
|
result=[]
|
|
if path.exists():
|
|
for line in path.read_text().splitlines():
|
|
try:result.append(json.loads(line))
|
|
except json.JSONDecodeError:pass
|
|
return result
|
|
def manifest():return json.loads((BASE/'manifest.json').read_text())
|
|
def alive():
|
|
r=subprocess.run(['pgrep','-x','worldserver'],text=True,capture_output=True)
|
|
result=[]
|
|
for value in r.stdout.split():
|
|
try:
|
|
if os.readlink('/proc/'+value+'/exe')=='/home/wow_admin/wow_cata_server/server/debug/bin/worldserver':result.append(int(value))
|
|
except OSError:pass
|
|
return result
|
|
EVENT=re.compile(r'\b(?:GROUP_[A-Z_]+|INSTANCE_[A-Z_]+|INTENT_[A-Z_]+|EDGE_[A-Z_]+|RECOVERY_[A-Z_]+|NAV_REJECT|TEMP_TRAVEL|PORTAL_[A-Z_]+|TRAVEL_(?:PLAN[A-Z_]*|JOURNEY_COSTS|SHARED_ROUTE)|CPC_PERF)\b')
|
|
class Tail:
|
|
def __init__(self,path):self.path=path;self.file=None;self.initial=True
|
|
def poll(self):
|
|
try:
|
|
st=self.path.stat()
|
|
if self.file is None:
|
|
self.file=self.path.open();self.inode=st.st_ino
|
|
if self.initial:self.file.seek(0,2);self.initial=False
|
|
lines=self.file.readlines()
|
|
if self.inode!=st.st_ino:
|
|
self.file.close();self.file=self.path.open();self.inode=st.st_ino;lines+=self.file.readlines()
|
|
elif self.file.tell()>st.st_size:self.file.seek(0)
|
|
stamp=d.now().isoformat()
|
|
for line in lines:
|
|
match=EVENT.search(line)
|
|
if match:append(BASE/'events.jsonl',{'observed_at':stamp,'source':self.path.name,'event':match[0],'line':line.rstrip()})
|
|
except OSError as error:append(BASE/'observer-errors.jsonl',{'time':d.now().isoformat(),'error':str(error)})
|
|
def snapshot(native=True):
|
|
record={'time':d.now().isoformat(),'server_pids':alive()}
|
|
record['roster']=d.roster()
|
|
record['groups']=d.query('Character','SELECT g.guid,g.leaderGuid,g.groupType,m.memberGuid,c.name,c.level,c.online FROM groups g JOIN group_member m ON m.guid=g.guid JOIN characters c ON c.guid=m.memberGuid ORDER BY g.guid,m.memberGuid;')
|
|
record['plans']=d.plans();record['native']={}
|
|
if native and record['server_pids']:
|
|
raw=[];ids=[r['guid'] for r in record['roster'] if r['level']>=15]
|
|
for pos in range(0,len(ids),20):
|
|
chunk=ids[pos:pos+20]
|
|
for g in chunk:
|
|
for command in [f'clientless adventure status {g}',f'clientless actioninfo {g}',f'clientless interaction {g}',f'clientless adventure area {g}']:d.command(command)
|
|
time.sleep(1.5);text=d.console(1400);raw.append(text)
|
|
for g in chunk:
|
|
bot={}
|
|
for key,pattern in {
|
|
'behavior':rf'Adventure GUID {g}: enabled=(\d+) schedule=(\d+) phase=(\d+) intent=\x27([^\x27]*)\x27 location=\x27([^\x27]*)\x27.*?detail=\x27([^\x27]*)\x27',
|
|
'action':rf'Action GUID {g}: state=(\w+) action=\x27([^\x27]*)\x27 target=\x27([^\x27]*)\x27.*?detail=\x27([^\x27]*)\x27',
|
|
'area':rf'Area access GUID {g}: .*?map=(\d+) area=(\d+).*?allowed=(\d+)',
|
|
}.items():
|
|
matches=list(re.finditer(pattern,text))
|
|
if matches:bot[key]=list(matches[-1].groups())
|
|
record['native'][str(g)]=bot
|
|
(BASE/('snapshot-'+d.now().strftime('%Y%m%d-%H%M%S')+'.log')).write_text('\n'.join(raw))
|
|
append(BASE/'snapshots.jsonl',record)
|
|
return record
|
|
def observe():
|
|
end=datetime.datetime.fromisoformat(manifest()['evaluate_at'])
|
|
logs=Path('/home/wow_admin/wow_cata_server/server/debug/bin')
|
|
tails=[Tail(logs/'Server.log'),Tail(logs/'adventurebot-navigation.log')]
|
|
for tail in tails:tail.poll()
|
|
next_snapshot=0
|
|
append(BASE/'lifecycle.jsonl',{'event':'observer_started','time':d.now().isoformat(),'end':end.isoformat()})
|
|
while d.now()<end:
|
|
for tail in tails:tail.poll()
|
|
if time.monotonic()>=next_snapshot:
|
|
try:snapshot()
|
|
except Exception as error:append(BASE/'observer-errors.jsonl',{'time':d.now().isoformat(),'error':str(error)})
|
|
next_snapshot=time.monotonic()+300
|
|
# Preserve a final snapshot before the activity slot ends.
|
|
if (end-d.now()).total_seconds()<35:
|
|
try:snapshot()
|
|
except Exception as error:append(BASE/'observer-errors.jsonl',{'time':d.now().isoformat(),'error':str(error)})
|
|
while d.now()<end:
|
|
for tail in tails:tail.poll()
|
|
time.sleep(1)
|
|
break
|
|
time.sleep(2)
|
|
for tail in tails:tail.poll()
|
|
append(BASE/'lifecycle.jsonl',{'event':'observer_finished','time':d.now().isoformat()})
|
|
def report(preview=False):
|
|
m=manifest();end=datetime.datetime.fromisoformat(m['evaluate_at']);start=end.replace(hour=m['formation_hour'])
|
|
snapshots=[s for s in load(BASE/'snapshots.jsonl') if start<=datetime.datetime.fromisoformat(s['time'])<=end]
|
|
events=[]
|
|
for item in load(BASE/'events.jsonl'):
|
|
stamp=datetime.datetime.fromisoformat(item['observed_at'])
|
|
match=re.match(r'(\d{4}-\d\d-\d\d_\d\d:\d\d:\d\d)',item['line'])
|
|
if match:stamp=datetime.datetime.strptime(match[1],'%Y-%m-%d_%H:%M:%S').replace(tzinfo=d.TZ)
|
|
if start<=stamp<end:events.append(item)
|
|
# Server and navigation logs can repeat the same event; never count duplicates.
|
|
unique={}
|
|
for item in events:
|
|
line=re.sub(r'^.*?\[(?:server\.[^]]+)\]\s*','',item['line'])
|
|
key=(item['event'],line)
|
|
unique.setdefault(key,item)
|
|
events=list(unique.values());counts=collections.Counter(e['event'] for e in events)
|
|
arrivals=set();entered=set();cohort_entered=set();positions={};reasons=collections.Counter();plans=set()
|
|
cohort=set(m['raid_guids']);goal='instance_visit_at_6354_d0'
|
|
for e in events:
|
|
line=e['line'];g=re.search(r'\bguid=(\d+)\b',line)
|
|
guid=int(g[1]) if g else None
|
|
if guid is not None:
|
|
if e['event']=='INTENT_ARRIVED' and "intent='groupformation'" in line and any("location='"+v+"'" in line for v in m['meeting_locations'].values()):arrivals.add(guid)
|
|
if e['event']=='INSTANCE_ENTERED':
|
|
entered.add(guid)
|
|
if 'map=671 ' in line and 'mode=0' in line and guid in cohort:cohort_entered.add(guid)
|
|
if e['event']=='INSTANCE_PLAN' and guid in cohort:plans.add(guid)
|
|
if e['event']=='TEMP_TRAVEL' and 'position=' in line:positions[guid]=line
|
|
if e['event'] in ['RECOVERY_FAILED','PORTAL_USE_FAILED','INSTANCE_ENTRY_DENIED','INSTANCE_TRAVEL_RETRY']:
|
|
detail=re.search(r"(?:reason|status)='([^']*)'",line)
|
|
reasons[(e['event'],detail[1] if detail else 'siehe Rohlog')]+=1
|
|
max_group=0;together=False
|
|
rolemap={r['guid']:r.get('role','unknown') for r in m['roster']}
|
|
latest_group={}
|
|
for s in snapshots:
|
|
if not s['server_pids']:continue
|
|
grouped=collections.defaultdict(list)
|
|
for row in s['groups']:grouped[row['guid']].append(row)
|
|
for gid,rows in grouped.items():
|
|
members={int(r['memberGuid']) for r in rows};overlap=members&cohort
|
|
if len(overlap)>max_group:max_group=len(overlap)
|
|
if len(overlap)==10:together=True
|
|
latest_group=grouped
|
|
for snap in snapshots:
|
|
if not snap['server_pids']:continue
|
|
for guid,bot in snap.get('native',{}).items():
|
|
status=bot.get('behavior')
|
|
if status and status[2]=='2' and status[3]=='groupformation' and status[4] in m['meeting_locations'].values():arrivals.add(int(guid))
|
|
latest=snapshots[-1] if snapshots else None
|
|
leader_seeds={};copies=0;matched_seeds=0;unknown_seeds=0;mismatched_seeds=0
|
|
for e in events:
|
|
line=e['line']
|
|
if e['event']=='TRAVEL_JOURNEY_COSTS':
|
|
match=re.search(r'guid=(\d+) seed=(\d+)',line)
|
|
if match:leader_seeds[int(match[1])]=int(match[2])
|
|
elif e['event']=='TRAVEL_SHARED_ROUTE':
|
|
match=re.search(r'leader=(\d+).*?journeySeed=(\d+)',line)
|
|
if match:
|
|
copies+=1;leader=int(match[1]);seed=int(match[2])
|
|
if leader not in leader_seeds:unknown_seeds+=1
|
|
elif leader_seeds[leader]==seed:matched_seeds+=1
|
|
else:mismatched_seeds+=1
|
|
stamp=d.now();future=preview or stamp<end
|
|
title='Vorläufige Testbeobachtung' if future else 'Testauswertung'
|
|
lines=[f'# {title}: {start:%d.%m.%Y}, Gruppenbildung {m["formation_hour"]:02d}:00 / Instanzen {m["activity_hour"]:02d}:00',
|
|
'',f'Erstellt: {stamp:%d.%m.%Y %H:%M:%S %Z}. Geplanter Auswertungszeitpunkt: {end:%H:%M %Z}.',
|
|
'',f'- Geprüfte Testbots: {len(m["eligible_guids"])}. Unter Stufe 15 ausgenommen: {len(m["excluded_under15"])}.',
|
|
f'- Feste Treffpunkte: Allianz Goldene Rose in Sturmwind; Horde Broken Tusk in Orgrimmar.',
|
|
f'- Status-Snapshots: {len(snapshots)}; ausgewertete eindeutige Logereignisse: {len(events)}.',
|
|
f'- Erste erfasste Statusstichprobe: {snapshots[0]["time"] if snapshots else "keine"}; frühere Ereignisse sind nicht vollständig erfasst.',
|
|
f'- Bots mit belegter Ankunft am festgelegten Formationstreffpunkt: {len(arrivals)}.',
|
|
f'- Bots mit protokolliertem tatsächlichem Instanzbeitritt: {len(entered)}.',
|
|
f'- Snapshots ohne laufenden Testserver: {sum(not s["server_pids"] for s in snapshots)}.',
|
|
'', '## Bekannte Zehnergruppe: Bastion des Zwielichts, normal', '',
|
|
f'- Maximal gemeinsam in einer nativen Gruppe beobachtet: {max_group}/10.',
|
|
f'- Alle zehn gemeinsam nachgewiesen: {"ja" if together else "nein; durch die Stichproben nicht nachgewiesen"}.',
|
|
f'- Bots mit Instanzplanung: {len(plans)}/10; mit tatsächlichem Beitritt zu Karte 671 im Modus 0: {len(cohort_entered)}/10.',
|
|
'', '| GUID | Name | Rolle | Bastion betreten | Letzter nativer Status |', '|---:|---|---|---|---|']
|
|
byid={r['guid']:r for r in m['roster']}
|
|
for g in sorted(cohort):
|
|
row=byid.get(g,{});status=(latest or {}).get('native',{}).get(str(g),{}).get('behavior')
|
|
detail=(status[3]+' / '+status[4]+' / '+status[5]) if status else 'kein frischer Status erfasst'
|
|
lines.append(f'| {g} | {row.get("name","unbekannt")} | {rolemap.get(g,"unbekannt")} | {"ja" if g in cohort_entered else "nicht nachgewiesen"} | {detail.replace("|","/")} |')
|
|
lines+=['','## Übernahme der Anführerroute','',
|
|
f'- Protokollierte Routenübernahmen mit Journey-Seed: {copies}.',
|
|
f'- Gleicher zuletzt beobachteter Anführer-Seed: {matched_seeds}; abweichend: {mismatched_seeds}; Anführer-Seed im Beobachtungsfenster nicht bekannt: {unknown_seeds}.',
|
|
'- Ein abweichender letzter Seed erfordert Prüfung der konkreten Reise und des Zeitpunkts; diese Zählung allein beweist keinen Fehler.',
|
|
'', '## Fehler und Reiseereignisse','']
|
|
for key in ['GROUP_MERGE','GROUP_MANAGER_RUN','GROUP_EARLY_DEPART','PORTAL_USE_START','RECOVERY_FAILED','INSTANCE_TRAVEL_RETRY','INSTANCE_ENTRY_DENIED']:
|
|
lines.append(f'- {key}: {counts[key]}.')
|
|
if reasons:
|
|
lines+=['','Häufigste protokollierte Fehler:','']
|
|
for (kind,reason),count in reasons.most_common(12):lines.append(f'- {kind}: {reason} ({count} Ereignisse).')
|
|
lines+=['','## Grenzen der Auswertung','',
|
|
'- Ausgewertet werden technische Zustände und native Logereignisse; keine visuelle Gameplay-Abnahme und keine Bestätigung von Bosskämpfen.',
|
|
'- Ein Reiseplan ist kein Ankunftsnachweis. Fehlende Ereignisse werden als nicht nachgewiesen ausgewiesen.',
|
|
'- Die Gruppenmitgliedschaft und Zustände werden alle fünf Minuten stichprobenartig gelesen; kurzlebige Zwischenzustände können fehlen.',
|
|
'- Charakterpositionen aus DB-Snapshots sind zuletzt gespeicherte Positionen. Live-Reisepositionen stehen in den TEMP_TRAVEL-Ereignissen.',
|
|
'- Der Beobachter repariert, teleportiert oder startet den Server nicht. Ausfälle werden dokumentiert.',
|
|
f'- Letzter Snapshot: {latest["time"] if latest else "keiner"}.',
|
|
'',f'Rohdaten: {BASE.relative_to(d.ROOT)}/ (manifest.json, snapshots.jsonl, events.jsonl, snapshot-*.log).','']
|
|
target=BASE/'report-preview.md' if future else REPORT
|
|
tmp=target.with_suffix('.tmp');tmp.write_text('\n'.join(lines));tmp.replace(target)
|
|
(BASE/'report-status.json').write_text(json.dumps({'generated_at':stamp.isoformat(),'expected_at':end.isoformat(),'preview':future,'path':str(target),'snapshots':len(snapshots),'events':len(events),'cohort_entered':sorted(cohort_entered)},indent=2))
|
|
print(target)
|
|
if __name__=='__main__':
|
|
if sys.argv[1:]==['observe']:observe()
|
|
elif sys.argv[1:]==['snapshot']:print(json.dumps({'time':snapshot()['time']}))
|
|
elif sys.argv[1:]==['report-preview']:report(True)
|
|
elif sys.argv[1:]==['report']:report()
|
|
else:raise SystemExit('observe | snapshot | report | report-preview')
|