Initial VRC OSC commit
This commit is contained in:
every_holiday
565
src/vrc_log/log_actions.py
Normal file
565
src/vrc_log/log_actions.py
Normal file
@@ -0,0 +1,565 @@
|
||||
import os
|
||||
import re
|
||||
import subprocess
|
||||
import tempfile
|
||||
import threading
|
||||
import time
|
||||
from datetime import datetime
|
||||
from datetime import timedelta
|
||||
from pathlib import Path
|
||||
|
||||
from common.config_loader import loadVrcLogConfig
|
||||
from common.config_loader import getSecretValue
|
||||
from common.runtime_log import appendRuntimeLog
|
||||
from discord_control.actions import setDiscordMuted
|
||||
|
||||
_monitor_thread = None
|
||||
_monitor_stop_event = threading.Event()
|
||||
_last_sent_output = None
|
||||
_self_monitor_thread = None
|
||||
_self_monitor_stop_event = threading.Event()
|
||||
_last_self_state = None
|
||||
REALTIME_IDLE_SECONDS = 0.2
|
||||
|
||||
JOIN_PATTERN = re.compile(
|
||||
r"OnPlayerJoined\s+(.+?)\s+\(usr_[0-9a-fA-F-]+\)"
|
||||
)
|
||||
LEFT_PATTERN = re.compile(
|
||||
r"OnPlayerLeft\s+(.+?)\s+\(usr_[0-9a-fA-F-]+\)"
|
||||
)
|
||||
WORLD_PATTERN = re.compile(
|
||||
r"(wrld_[0-9a-fA-F-]+(?::[^\s\]\)\"']+)?)"
|
||||
)
|
||||
ENTERING_ROOM_PATTERN = re.compile(
|
||||
r"\[Behaviour\]\s+(?:Entering Room|Joining or Creating Room):\s+(.+)$"
|
||||
)
|
||||
WORLD_NAME_PATTERN = re.compile(
|
||||
r"worldId=(wrld_[0-9a-fA-F-]+)(?::[^,}]*)?,\s*worldName=([^,}]+)"
|
||||
)
|
||||
TIME_PATTERN = re.compile(
|
||||
r"(\d{4}\.\d{2}\.\d{2}\s+\d{2}:\d{2}:\d{2})"
|
||||
)
|
||||
RELEVANT_LOG_PATTERN = re.compile(
|
||||
r"OnPlayerJoined|OnPlayerLeft|Entering Room|Joining or Creating Room|worldId=|wrld_"
|
||||
)
|
||||
|
||||
|
||||
def log(level, message):
|
||||
now = datetime.now().strftime("%H:%M:%S")
|
||||
print(f"[{level}] {now} {message}", flush=True)
|
||||
|
||||
|
||||
def getWebhookUrl():
|
||||
return getSecretValue("discord", "webhook_url")
|
||||
|
||||
|
||||
def sendWebhook(text):
|
||||
webhook_url = getWebhookUrl().strip()
|
||||
if not webhook_url:
|
||||
log("ERROR", "Discord webhook URL is not set config=config/secrets.toml")
|
||||
return False
|
||||
|
||||
message = str(text).strip()
|
||||
if not message:
|
||||
log("INFO", "Webhook送信内容が空です")
|
||||
return False
|
||||
|
||||
if len(message) > 1800:
|
||||
message = message[-1800:]
|
||||
|
||||
ps_script = r'''
|
||||
param(
|
||||
[string]$WebhookUrl,
|
||||
[string]$Message
|
||||
)
|
||||
|
||||
[Console]::OutputEncoding = [System.Text.Encoding]::UTF8
|
||||
$Payload = @{ content = $Message } | ConvertTo-Json -Compress
|
||||
$Body = [System.Text.Encoding]::UTF8.GetBytes($Payload)
|
||||
Invoke-WebRequest -Uri $WebhookUrl -Method Post -ContentType 'application/json; charset=utf-8' -Body $Body -UseBasicParsing | Out-Null
|
||||
'''
|
||||
|
||||
ps_path = None
|
||||
|
||||
try:
|
||||
with tempfile.NamedTemporaryFile(
|
||||
mode="w",
|
||||
suffix=".ps1",
|
||||
delete=False,
|
||||
encoding="utf-8-sig",
|
||||
) as tmp:
|
||||
tmp.write(ps_script)
|
||||
ps_path = tmp.name
|
||||
|
||||
result = subprocess.run(
|
||||
[
|
||||
"powershell",
|
||||
"-NoProfile",
|
||||
"-ExecutionPolicy",
|
||||
"Bypass",
|
||||
"-File",
|
||||
ps_path,
|
||||
webhook_url,
|
||||
message,
|
||||
],
|
||||
capture_output=True,
|
||||
text=True,
|
||||
encoding="utf-8",
|
||||
errors="replace",
|
||||
timeout=20,
|
||||
)
|
||||
except Exception as e:
|
||||
log("ERROR", f"Discord webhook PowerShell failed detail={e}")
|
||||
return False
|
||||
finally:
|
||||
if ps_path:
|
||||
try:
|
||||
Path(ps_path).unlink(missing_ok=True)
|
||||
except Exception:
|
||||
pass
|
||||
|
||||
if result.returncode != 0:
|
||||
stderr = (result.stderr or "").strip()
|
||||
stdout = (result.stdout or "").strip()
|
||||
log("ERROR", f"Discord webhook PowerShell failed code={result.returncode} stderr={stderr} stdout={stdout}")
|
||||
return False
|
||||
|
||||
log("INFO", "Discord webhook sent via PowerShell")
|
||||
return True
|
||||
|
||||
|
||||
def getVrchatLogDir():
|
||||
userprofile = os.environ.get("USERPROFILE")
|
||||
if not userprofile:
|
||||
raise RuntimeError("USERPROFILE が取得できません")
|
||||
return Path(userprofile) / "AppData" / "LocalLow" / "VRChat" / "VRChat"
|
||||
|
||||
|
||||
def findLatestVrchatLog():
|
||||
log_dir = getVrchatLogDir()
|
||||
if not log_dir.exists():
|
||||
raise RuntimeError(f"VRChatログディレクトリが存在しません: {log_dir}")
|
||||
|
||||
candidates = []
|
||||
for pattern in ("output_log_*.txt", "Player.log", "*.log", "*.txt"):
|
||||
candidates.extend(log_dir.glob(pattern))
|
||||
|
||||
candidates = [path for path in candidates if path.is_file()]
|
||||
if not candidates:
|
||||
raise RuntimeError(f"VRChatログファイルが見つかりません: {log_dir}")
|
||||
|
||||
candidates.sort(key=lambda path: path.stat().st_mtime, reverse=True)
|
||||
return candidates[0]
|
||||
|
||||
|
||||
def readTextSafe(path):
|
||||
for encoding in ("utf-8", "utf-8-sig", "cp932", "shift_jis"):
|
||||
try:
|
||||
return path.read_text(encoding=encoding, errors="replace")
|
||||
except Exception:
|
||||
continue
|
||||
|
||||
raise RuntimeError(f"ログファイルを読めません: {path}")
|
||||
|
||||
|
||||
def parseLineTime(line):
|
||||
matched = TIME_PATTERN.search(line)
|
||||
if not matched:
|
||||
return None
|
||||
|
||||
return datetime.strptime(matched.group(1), "%Y.%m.%d %H:%M:%S")
|
||||
|
||||
|
||||
def formatClock(dt):
|
||||
return dt.strftime("%H:%M")
|
||||
|
||||
|
||||
def getLogStartTime(now):
|
||||
noon_today = now.replace(hour=12, minute=0, second=0, microsecond=0)
|
||||
if now >= noon_today:
|
||||
return noon_today
|
||||
return noon_today - timedelta(days=1)
|
||||
|
||||
|
||||
def splitWorldLocation(location):
|
||||
if ":" not in location:
|
||||
return location, ""
|
||||
|
||||
world_id, instance_id = location.split(":", 1)
|
||||
return world_id, instance_id
|
||||
|
||||
|
||||
def extractWorldNameMap(text):
|
||||
world_name_map = {}
|
||||
pending_world_name = ""
|
||||
|
||||
for raw_line in text.splitlines():
|
||||
room_match = ENTERING_ROOM_PATTERN.search(raw_line)
|
||||
if room_match:
|
||||
pending_world_name = room_match.group(1).strip()
|
||||
|
||||
match = WORLD_NAME_PATTERN.search(raw_line)
|
||||
if match:
|
||||
world_id = match.group(1).strip()
|
||||
world_name = match.group(2).strip()
|
||||
if world_id and world_name:
|
||||
world_name_map[world_id] = world_name
|
||||
continue
|
||||
|
||||
world_match = WORLD_PATTERN.search(raw_line)
|
||||
if world_match and pending_world_name:
|
||||
location = world_match.group(1).strip()
|
||||
world_id, _ = splitWorldLocation(location)
|
||||
if world_id:
|
||||
world_name_map[world_id] = pending_world_name
|
||||
pending_world_name = ""
|
||||
|
||||
return world_name_map
|
||||
|
||||
|
||||
def formatWorldLabel(world_id, world_name_map):
|
||||
world_name = world_name_map.get(world_id, "").strip()
|
||||
if not world_name:
|
||||
return "不明"
|
||||
return world_name
|
||||
|
||||
|
||||
def classifyUser(name, guest_names, staff_names):
|
||||
if name in staff_names:
|
||||
return "staff"
|
||||
if name in guest_names:
|
||||
return "guest"
|
||||
return "other"
|
||||
|
||||
|
||||
def isSelf(name, self_name):
|
||||
return bool(self_name) and name.strip() == self_name.strip()
|
||||
|
||||
|
||||
def buildNoticeLines(guest_names, guest_present_set, missing_count):
|
||||
total_guest = len(guest_names)
|
||||
current_guest = len(guest_present_set)
|
||||
threshold = total_guest - missing_count
|
||||
|
||||
if missing_count <= 0:
|
||||
return []
|
||||
if not (threshold <= current_guest < total_guest):
|
||||
return []
|
||||
|
||||
missing_guests = [name for name in guest_names if name not in guest_present_set]
|
||||
if not missing_guests:
|
||||
return []
|
||||
|
||||
lines = [f"現在Guest: {current_guest}/{total_guest}", "未入室Guest:"]
|
||||
lines.extend(f"- {name}" for name in missing_guests)
|
||||
return lines
|
||||
|
||||
|
||||
def appendNoticeIfNeeded(output_lines, state):
|
||||
notice_lines = buildNoticeLines(
|
||||
state["guest_names"],
|
||||
state["guest_present_set"],
|
||||
state["missing_count"],
|
||||
)
|
||||
notice_key = tuple(notice_lines)
|
||||
|
||||
if not notice_lines:
|
||||
state["last_notice_key"] = None
|
||||
return
|
||||
|
||||
if state["last_notice_key"] == notice_key:
|
||||
return
|
||||
|
||||
output_lines.extend(notice_lines)
|
||||
state["last_notice_key"] = notice_key
|
||||
|
||||
|
||||
def parseVrchatEvents(text, config):
|
||||
start_time = getLogStartTime(datetime.now())
|
||||
guest_names = config["guest_names"]
|
||||
staff_names = set(config["staff_names"])
|
||||
self_name = config.get("self_name", "")
|
||||
world_name_map = extractWorldNameMap(text)
|
||||
|
||||
state = {
|
||||
"location": "",
|
||||
"world_id": "",
|
||||
"instance_id": "",
|
||||
"guest_names": guest_names,
|
||||
"guest_name_set": set(guest_names),
|
||||
"staff_names": staff_names,
|
||||
"guest_present_set": set(),
|
||||
"staff_present_set": set(),
|
||||
"member_present_set": set(),
|
||||
"missing_count": config["missing_count"],
|
||||
"last_notice_key": None,
|
||||
}
|
||||
output_lines = []
|
||||
self_state = None
|
||||
|
||||
for raw_line in text.splitlines():
|
||||
line_time = parseLineTime(raw_line)
|
||||
if not line_time or line_time < start_time:
|
||||
continue
|
||||
|
||||
world_match = WORLD_PATTERN.search(raw_line)
|
||||
if world_match:
|
||||
location = world_match.group(1).strip()
|
||||
world_id, instance_id = splitWorldLocation(location)
|
||||
|
||||
if location != state["location"]:
|
||||
state["location"] = location
|
||||
state["world_id"] = world_id
|
||||
state["instance_id"] = instance_id
|
||||
state["guest_present_set"].clear()
|
||||
state["staff_present_set"].clear()
|
||||
state["member_present_set"].clear()
|
||||
state["last_notice_key"] = None
|
||||
output_lines = []
|
||||
output_lines.append(f"ワールド入室: {formatWorldLabel(world_id, world_name_map)}")
|
||||
output_lines.append(f"現在Guest: 0/{len(guest_names)}")
|
||||
|
||||
join_match = JOIN_PATTERN.search(raw_line)
|
||||
if join_match and state["world_id"]:
|
||||
name = join_match.group(1).strip()
|
||||
if isSelf(name, self_name):
|
||||
self_state = "joined"
|
||||
state["member_present_set"].add(name)
|
||||
output_lines.append(
|
||||
f'[{formatClock(line_time)}] [join] [self] {name} {len(state["member_present_set"])}/{len(guest_names)}'
|
||||
)
|
||||
continue
|
||||
|
||||
role = classifyUser(name, state["guest_name_set"], state["staff_names"])
|
||||
|
||||
if role == "guest":
|
||||
state["guest_present_set"].add(name)
|
||||
state["member_present_set"].add(name)
|
||||
output_lines.append(
|
||||
f'[{formatClock(line_time)}] [join] {name} {len(state["member_present_set"])}/{len(guest_names)}'
|
||||
)
|
||||
appendNoticeIfNeeded(output_lines, state)
|
||||
elif role == "staff":
|
||||
state["staff_present_set"].add(name)
|
||||
output_lines.append(
|
||||
f'[{formatClock(line_time)}] [join] [staff] {name} {len(state["member_present_set"])}/{len(guest_names)}'
|
||||
)
|
||||
else:
|
||||
state["member_present_set"].add(name)
|
||||
output_lines.append(
|
||||
f'[{formatClock(line_time)}] [join] {name} {len(state["member_present_set"])}/{len(guest_names)}'
|
||||
)
|
||||
continue
|
||||
|
||||
left_match = LEFT_PATTERN.search(raw_line)
|
||||
if left_match and state["world_id"]:
|
||||
name = left_match.group(1).strip()
|
||||
if isSelf(name, self_name):
|
||||
self_state = "left"
|
||||
state["member_present_set"].discard(name)
|
||||
output_lines.append(
|
||||
f'[{formatClock(line_time)}] [leave] [self] {name} {len(state["member_present_set"])}/{len(guest_names)}'
|
||||
)
|
||||
continue
|
||||
|
||||
role = classifyUser(name, state["guest_name_set"], state["staff_names"])
|
||||
|
||||
if role == "guest":
|
||||
state["guest_present_set"].discard(name)
|
||||
state["member_present_set"].discard(name)
|
||||
output_lines.append(
|
||||
f'[{formatClock(line_time)}] [leave] {name} {len(state["member_present_set"])}/{len(guest_names)}'
|
||||
)
|
||||
appendNoticeIfNeeded(output_lines, state)
|
||||
elif role == "staff":
|
||||
state["staff_present_set"].discard(name)
|
||||
output_lines.append(
|
||||
f'[{formatClock(line_time)}] [leave] [staff] {name} {len(state["member_present_set"])}/{len(guest_names)}'
|
||||
)
|
||||
else:
|
||||
state["member_present_set"].discard(name)
|
||||
output_lines.append(
|
||||
f'[{formatClock(line_time)}] [leave] {name} {len(state["member_present_set"])}/{len(guest_names)}'
|
||||
)
|
||||
|
||||
return output_lines, self_state
|
||||
|
||||
|
||||
def extractLatestSelfLogState(text, self_name):
|
||||
if not self_name:
|
||||
return None
|
||||
|
||||
latest_state = None
|
||||
|
||||
for raw_line in text.splitlines():
|
||||
join_match = JOIN_PATTERN.search(raw_line)
|
||||
if join_match and isSelf(join_match.group(1).strip(), self_name):
|
||||
latest_state = "joined"
|
||||
continue
|
||||
|
||||
left_match = LEFT_PATTERN.search(raw_line)
|
||||
if left_match and isSelf(left_match.group(1).strip(), self_name):
|
||||
latest_state = "left"
|
||||
|
||||
return latest_state
|
||||
|
||||
|
||||
def grepVrchatLog(pattern=None):
|
||||
return collectVrchatLog(pattern=pattern, notify_changed=False)
|
||||
|
||||
|
||||
def collectVrchatLog(pattern=None, notify_changed=True):
|
||||
config = loadVrcLogConfig()
|
||||
latest_log = findLatestVrchatLog()
|
||||
log("ACTION", f"parseVrchatLog file={latest_log}")
|
||||
log("INFO", f'event_file={config["event_file"]}')
|
||||
|
||||
text = readTextSafe(latest_log)
|
||||
lines, self_state = parseVrchatEvents(text, config)
|
||||
|
||||
output_text = "\n".join(lines) if lines else "[INFO] 対象イベントなし"
|
||||
output_path = appendRuntimeLog("VRC LOG", output_text)
|
||||
|
||||
if notify_changed:
|
||||
global _last_sent_output
|
||||
if output_text != _last_sent_output:
|
||||
try:
|
||||
ok = sendWebhook(output_text)
|
||||
if ok:
|
||||
log("INFO", "Discord webhook sent")
|
||||
_last_sent_output = output_text
|
||||
else:
|
||||
log("ERROR", "Discord webhook send failed")
|
||||
except Exception as e:
|
||||
log("ERROR", f"Discord webhook failed detail={e}")
|
||||
|
||||
log("INFO", f"result appended={output_path}")
|
||||
for line in lines or ["[INFO] 対象イベントなし"]:
|
||||
print(line, flush=True)
|
||||
|
||||
return output_path
|
||||
|
||||
|
||||
def _readNewText(path, offset):
|
||||
for encoding in ("utf-8", "utf-8-sig", "cp932", "shift_jis"):
|
||||
try:
|
||||
with path.open("r", encoding=encoding, errors="replace") as file:
|
||||
file.seek(offset)
|
||||
return file.read(), file.tell()
|
||||
except Exception:
|
||||
continue
|
||||
|
||||
raise RuntimeError(f"ログファイルを読めません: {path}")
|
||||
|
||||
|
||||
def _watchVrchatLogChanges(stop_event, label, on_relevant_change):
|
||||
log("ACTION", f"{label} realtime watcher started")
|
||||
|
||||
current_log = None
|
||||
offset = 0
|
||||
|
||||
while not stop_event.is_set():
|
||||
try:
|
||||
latest_log = findLatestVrchatLog()
|
||||
latest_size = latest_log.stat().st_size
|
||||
|
||||
if current_log is None:
|
||||
current_log = latest_log
|
||||
offset = latest_size
|
||||
log("INFO", f"{label} watching file={current_log}")
|
||||
continue
|
||||
|
||||
if latest_log != current_log:
|
||||
current_log = latest_log
|
||||
offset = 0
|
||||
log("INFO", f"{label} watching new file={current_log}")
|
||||
|
||||
if latest_size < offset:
|
||||
offset = 0
|
||||
|
||||
if latest_size > offset:
|
||||
text, offset = _readNewText(latest_log, offset)
|
||||
|
||||
if RELEVANT_LOG_PATTERN.search(text):
|
||||
on_relevant_change(text)
|
||||
except Exception as e:
|
||||
log("ERROR", f"{label} realtime watcher failed detail={e}")
|
||||
|
||||
stop_event.wait(REALTIME_IDLE_SECONDS)
|
||||
|
||||
log("INFO", f"{label} realtime watcher stopped")
|
||||
|
||||
|
||||
def _monitor_loop():
|
||||
def on_relevant_change(_text):
|
||||
collectVrchatLog(notify_changed=True)
|
||||
|
||||
_watchVrchatLogChanges(
|
||||
_monitor_stop_event,
|
||||
"VRC log monitor",
|
||||
on_relevant_change,
|
||||
)
|
||||
|
||||
|
||||
def _self_monitor_loop():
|
||||
def on_relevant_change(text):
|
||||
try:
|
||||
config = loadVrcLogConfig()
|
||||
self_state = extractLatestSelfLogState(
|
||||
text,
|
||||
config.get("self_name", ""),
|
||||
)
|
||||
|
||||
global _last_self_state
|
||||
if self_state and self_state != _last_self_state:
|
||||
if self_state == "joined":
|
||||
setDiscordMuted(True)
|
||||
elif self_state == "left":
|
||||
setDiscordMuted(False)
|
||||
_last_self_state = self_state
|
||||
except Exception as e:
|
||||
log("ERROR", f"VRC self monitor failed detail={e}")
|
||||
|
||||
_watchVrchatLogChanges(
|
||||
_self_monitor_stop_event,
|
||||
"VRC self monitor",
|
||||
on_relevant_change,
|
||||
)
|
||||
|
||||
|
||||
def startVrcLogMonitor(_interval_seconds=None):
|
||||
global _monitor_thread
|
||||
|
||||
if _monitor_thread and _monitor_thread.is_alive():
|
||||
log("INFO", "VRC log monitor already running")
|
||||
return
|
||||
|
||||
_monitor_stop_event.clear()
|
||||
_monitor_thread = threading.Thread(
|
||||
target=_monitor_loop,
|
||||
daemon=True,
|
||||
)
|
||||
_monitor_thread.start()
|
||||
|
||||
|
||||
def startSelfMonitor(_interval_seconds=None):
|
||||
global _self_monitor_thread
|
||||
|
||||
if _self_monitor_thread and _self_monitor_thread.is_alive():
|
||||
log("INFO", "VRC self monitor already running")
|
||||
return
|
||||
|
||||
_self_monitor_stop_event.clear()
|
||||
_self_monitor_thread = threading.Thread(
|
||||
target=_self_monitor_loop,
|
||||
daemon=True,
|
||||
)
|
||||
_self_monitor_thread.start()
|
||||
|
||||
|
||||
def stopVrcLogMonitor():
|
||||
_monitor_stop_event.set()
|
||||
|
||||
|
||||
def stopSelfMonitor():
|
||||
_self_monitor_stop_event.set()
|
||||
Reference in New Issue
Block a user