Refine Go runtime behavior and log handling

VRWT_Tool/VRC_OSC/internal/app/app.go

@@ -1,16 +1,25 @@
 package app
 
 import (
-	"fmt"
+	"log"
 	"os"
 	"os/signal"
+	"sync"
 	"syscall"
+	"time"
 
 	"vrc_osc_go/internal/config"
 	"vrc_osc_go/internal/consenttool"
 	"vrc_osc_go/internal/osc"
 )
 
+type discordMuteState struct {
+	mu            sync.Mutex
+	muted         bool
+	buttonPressed bool
+	lastAction    time.Time
+}
+
 func Run(configPath string, mode string) error {
 	if mode != "" {
 		return consenttool.Run(configPath, mode)
@@ -20,21 +29,43 @@ func Run(configPath string, mode string) error {
 	if err != nil {
 		return err
 	}
+	log.Printf("vrc_osc_go starting osc=%s:%d config=%s", cfg.OSC.Host, cfg.OSC.Port, configPath)
 
 	server := osc.NewServer(cfg.OSC.Host, cfg.OSC.Port)
+	discordState := &discordMuteState{muted: true}
 	server.Map("DiscordSend", func(_ string, args []osc.Value) error {
-		return fmt.Errorf("discord mute not implemented yet")
+		log.Printf("received DiscordSend args=%+v", args)
+		if err := handleDiscordSend(discordState, args); err != nil {
+			log.Printf("discord mute failed: %v", err)
+			return err
+		}
+		return nil
+	})
+	server.Map("ocrEnabled", func(_ string, args []osc.Value) error {
+		log.Printf("received ocrEnabled args=%+v", args)
+		if err := runPythonOcrFromScreen(); err != nil {
+			log.Printf("ocr failed: %v", err)
+			return err
+		}
+		return nil
 	})
 
 	errCh := make(chan error, 1)
-	go func() { errCh <- server.Serve() }()
+	go func() {
+		log.Printf("osc server listening on %s:%d", cfg.OSC.Host, cfg.OSC.Port)
+		errCh <- server.Serve()
+	}()
+	go watchVrchatLog()
+	startSelfMonitor(cfg, discordState)
 
 	sigCh := make(chan os.Signal, 1)
 	signal.Notify(sigCh, os.Interrupt, syscall.SIGTERM)
 	select {
 	case err := <-errCh:
+		log.Printf("osc server stopped: %v", err)
 		return err
 	case <-sigCh:
+		log.Printf("shutdown signal received")
 		server.Close()
 		return nil
 	}

VRWT_Tool/VRC_OSC/internal/app/discord.go

@@ -0,0 +1,36 @@
+package app
+
+import (
+	"bytes"
+	"fmt"
+	"log"
+	"os/exec"
+)
+
+func pressDiscordMuteHotkey() error {
+	script := `
+$p = Get-Process | Where-Object { $_.MainWindowTitle -match 'Discord' } | Select-Object -First 1
+if ($null -eq $p) { exit 2 }
+[void][System.Runtime.InteropServices.Marshal]::GetLastWin32Error()
+$wshell = New-Object -ComObject WScript.Shell
+$null = $wshell.AppActivate($p.Id)
+Start-Sleep -Milliseconds 150
+$wshell.SendKeys('^+m')
+`
+
+	cmd := exec.Command("powershell", "-NoProfile", "-ExecutionPolicy", "Bypass", "-Command", script)
+	out, err := cmd.CombinedOutput()
+	if len(out) > 0 {
+		log.Printf("discord mute output: %s", string(out))
+	}
+	if err != nil {
+		return fmt.Errorf("discord mute failed: %w", err)
+	}
+	return nil
+}
+
+func pressDiscordMuteHotkeyLegacy() error {
+	var buf bytes.Buffer
+	_ = buf
+	return pressDiscordMuteHotkey()
+}

VRWT_Tool/VRC_OSC/internal/app/discord_mute.go

@@ -0,0 +1,88 @@
+package app
+
+import (
+	"fmt"
+	"log"
+	"strings"
+	"time"
+
+	"vrc_osc_go/internal/osc"
+)
+
+const discordDebounce = 300 * time.Millisecond
+
+func handleDiscordSend(state *discordMuteState, args []osc.Value) error {
+	state.mu.Lock()
+	defer state.mu.Unlock()
+
+	if len(args) == 0 {
+		return fmt.Errorf("OSC args is empty")
+	}
+	isPressed, err := toBool(args[0])
+	if err != nil {
+		return err
+	}
+
+	now := time.Now()
+	if !state.lastAction.IsZero() && now.Sub(state.lastAction) < discordDebounce {
+		return nil
+	}
+
+	if isPressed && !state.buttonPressed {
+		state.buttonPressed = true
+		if state.muted {
+			log.Printf("ACTION VRChat button pressed -> Discord unmute hotkey")
+			if err := pressDiscordMuteHotkey(); err != nil {
+				return err
+			}
+			state.muted = false
+			state.lastAction = now
+		} else {
+			log.Printf("INFO already unmuted")
+		}
+		return nil
+	}
+
+	if !isPressed && state.buttonPressed {
+		state.buttonPressed = false
+		if !state.muted {
+			log.Printf("ACTION VRChat button released -> Discord mute hotkey")
+			if err := pressDiscordMuteHotkey(); err != nil {
+				return err
+			}
+			state.muted = true
+			state.lastAction = now
+		} else {
+			log.Printf("INFO already muted")
+		}
+		return nil
+	}
+
+	return nil
+}
+
+func toBool(v osc.Value) (bool, error) {
+	switch v.Type {
+	case 'T':
+		return true, nil
+	case 'F':
+		return false, nil
+	case 'i':
+		return v.Int != 0, nil
+	case 'f':
+		return v.Float != 0, nil
+	case 's':
+		switch strings.ToLower(strings.TrimSpace(v.Str)) {
+		case "true", "1", "on", "yes":
+			return true, nil
+		case "false", "0", "off", "no":
+			return false, nil
+		default:
+			return false, fmt.Errorf("unsupported OSC value: %q", v.Str)
+		}
+	case 0:
+		return false, fmt.Errorf("unsupported OSC value")
+	default:
+		return false, fmt.Errorf("unsupported OSC type: %q", v.Type)
+	}
+}

VRWT_Tool/VRC_OSC/internal/app/ocr.go

@@ -0,0 +1,28 @@
+package app
+
+import (
+	"fmt"
+	"log"
+	"os/exec"
+)
+
+func runPythonOcrFromScreen() error {
+	script := `
+import sys
+from pathlib import Path
+root = Path(r"C:\Users\kenny\Documents\git\messpy\VRC\VRWT_Tool\VRC_OSC")
+sys.path.insert(0, str(root / "src"))
+from ocr.ocr_actions import runOcrFromScreen
+runOcrFromScreen()
+`
+	cmd := exec.Command("python", "-c", script)
+	cmd.Dir = `C:\Users\kenny\Documents\git\messpy\VRC\VRWT_Tool\VRC_OSC`
+	out, err := cmd.CombinedOutput()
+	if len(out) > 0 {
+		log.Printf("ocr output: %s", string(out))
+	}
+	if err != nil {
+		return fmt.Errorf("ocr failed: %w", err)
+	}
+	return nil
+}

VRWT_Tool/VRC_OSC/internal/app/runtime.go

@@ -0,0 +1,48 @@
+package app
+
+import (
+	"fmt"
+	"os"
+	"path/filepath"
+	"time"
+
+	"vrc_osc_go/internal/common"
+)
+
+func appendRuntimeLog(title, text string) error {
+	dir := filepath.Join(common.RootDir(), "runtime")
+	if err := os.MkdirAll(dir, 0o755); err != nil {
+		return err
+	}
+	path := filepath.Join(dir, "runtime.log")
+	body := text
+	if body == "" {
+		body = "(empty)"
+	}
+	f, err := os.OpenFile(path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o644)
+	if err != nil {
+		return err
+	}
+	defer f.Close()
+	_, err = fmt.Fprintf(f, "\n[%s] %s\n%s\n", time.Now().Format("2006-01-02 15:04:05"), title, body)
+	return err
+}
+
+func appendJoinLeaveLog(text string) error {
+	dir := filepath.Join(common.RootDir(), "runtime")
+	if err := os.MkdirAll(dir, 0o755); err != nil {
+		return err
+	}
+	path := filepath.Join(dir, "join_leave.log")
+	body := text
+	if body == "" {
+		body = "(empty)"
+	}
+	f, err := os.OpenFile(path, os.O_CREATE|os.O_APPEND|os.O_WRONLY, 0o644)
+	if err != nil {
+		return err
+	}
+	defer f.Close()
+	_, err = fmt.Fprintf(f, "\n[%s] VRC JOIN/LEAVE\n%s\n", time.Now().Format("2006-01-02 15:04:05"), body)
+	return err
+}

VRWT_Tool/VRC_OSC/internal/app/self_monitor.go

@@ -0,0 +1,69 @@
+package app
+
+import (
+	"log"
+	"os"
+	"regexp"
+	"strings"
+	"time"
+
+	"vrc_osc_go/internal/config"
+	"vrc_osc_go/internal/osc"
+)
+
+var (
+	selfJoinPattern = regexp.MustCompile(`OnPlayerJoined\s+(.+?)\s+\(usr_[0-9a-fA-F-]+\)`)
+	selfLeftPattern = regexp.MustCompile(`OnPlayerLeft\s+(.+?)\s+\(usr_[0-9a-fA-F-]+\)`)
+)
+
+func startSelfMonitor(cfg *config.Config, state *discordMuteState) {
+	if cfg.VrcLog.SelfName == "" {
+		return
+	}
+	go func() {
+		lastState := ""
+		for {
+			path, err := findLatestVrchatLog()
+			if err != nil {
+				time.Sleep(2 * time.Second)
+				continue
+			}
+			text, err := os.ReadFile(path)
+			if err != nil {
+				time.Sleep(2 * time.Second)
+				continue
+			}
+			nextState := extractLatestSelfLogState(string(text), cfg.VrcLog.SelfName)
+			if nextState != "" && nextState != lastState {
+				if nextState == "joined" {
+					if err := handleDiscordSend(state, []osc.Value{{Type: 'T', Bool: true}}); err != nil {
+						log.Printf("self monitor discord mute failed: %v", err)
+					}
+				} else if nextState == "left" {
+					if err := handleDiscordSend(state, []osc.Value{{Type: 'F', Bool: false}}); err != nil {
+						log.Printf("self monitor discord mute failed: %v", err)
+					}
+				}
+				lastState = nextState
+			}
+			time.Sleep(2 * time.Second)
+		}
+	}()
+}
+
+func extractLatestSelfLogState(text, selfName string) string {
+	if selfName == "" {
+		return ""
+	}
+	state := ""
+	for _, rawLine := range strings.Split(text, "\n") {
+		if m := selfJoinPattern.FindStringSubmatch(rawLine); len(m) == 2 && strings.TrimSpace(m[1]) == selfName {
+			state = "joined"
+			continue
+		}
+		if m := selfLeftPattern.FindStringSubmatch(rawLine); len(m) == 2 && strings.TrimSpace(m[1]) == selfName {
+			state = "left"
+		}
+	}
+	return state
+}

VRWT_Tool/VRC_OSC/internal/app/vrc_log.go

@@ -0,0 +1,313 @@
+package app
+
+import (
+	"bufio"
+	"fmt"
+	"log"
+	"os"
+	"path/filepath"
+	"regexp"
+	"strings"
+	"time"
+)
+
+var (
+	joinPattern          = regexp.MustCompile(`OnPlayerJoined\s+(.+?)\s+\(usr_[0-9a-fA-F-]+\)`)
+	leftPattern          = regexp.MustCompile(`OnPlayerLeft\s+(.+?)\s+\(usr_[0-9a-fA-F-]+\)`)
+	worldIdPattern       = regexp.MustCompile(`worldId=(wrld_[0-9a-fA-F-]+)`)
+	instanceIdPattern    = regexp.MustCompile(`instanceId=([^,}\s]+)`)
+	worldNamePattern     = regexp.MustCompile(`worldName=([^,}]+)`)
+	worldLocationPattern = regexp.MustCompile(`worldId=(wrld_[0-9a-fA-F-]+):([^\s,\]\)\"']+)`)
+	worldPattern         = regexp.MustCompile(`(wrld_[0-9a-fA-F-]+(?::[^\s\]\)\"']+)?)`)
+	enteringRoomPattern  = regexp.MustCompile(`\[Behaviour\]\s+(?:Entering Room|Joining or Creating Room):\s+(.+)$`)
+)
+
+type vrcLogState struct {
+	location         string
+	worldID          string
+	instanceID       string
+	worldName        string
+	pendingWorldName string
+	presentSet       map[string]struct{}
+	initialized      bool
+}
+
+func getVrchatLogDir() (string, error) {
+	userProfile := os.Getenv("USERPROFILE")
+	if userProfile == "" {
+		return "", os.ErrNotExist
+	}
+	return filepath.Join(userProfile, "AppData", "LocalLow", "VRChat", "VRChat"), nil
+}
+
+func findLatestVrchatLog() (string, error) {
+	dir, err := getVrchatLogDir()
+	if err != nil {
+		return "", err
+	}
+
+	entries, err := os.ReadDir(dir)
+	if err != nil {
+		return "", err
+	}
+
+	var latest string
+	var latestMod time.Time
+	for _, entry := range entries {
+		if entry.IsDir() {
+			continue
+		}
+		name := entry.Name()
+		if !strings.HasSuffix(strings.ToLower(name), ".log") && !strings.HasSuffix(strings.ToLower(name), ".txt") {
+			continue
+		}
+		info, err := entry.Info()
+		if err != nil {
+			continue
+		}
+		if info.ModTime().After(latestMod) {
+			latestMod = info.ModTime()
+			latest = filepath.Join(dir, name)
+		}
+	}
+	if latest == "" {
+		return "", os.ErrNotExist
+	}
+	return latest, nil
+}
+
+func watchVrchatLog() {
+	lastPath := ""
+	lastSize := int64(0)
+	state := &vrcLogState{
+		presentSet: map[string]struct{}{},
+	}
+	for {
+		path, err := findLatestVrchatLog()
+		if err != nil {
+			time.Sleep(2 * time.Second)
+			continue
+		}
+		info, err := os.Stat(path)
+		if err != nil {
+			time.Sleep(2 * time.Second)
+			continue
+		}
+		if path != lastPath {
+			log.Printf("vrchat log watching %s", path)
+			lastPath = path
+			lastSize = 0
+			if err := scanExistingVrchatLog(path, state); err != nil {
+				log.Printf("vrchat log initial scan failed: %v", err)
+			}
+			if info2, err := os.Stat(path); err == nil {
+				lastSize = info2.Size()
+			} else {
+				lastSize = info.Size()
+			}
+			time.Sleep(2 * time.Second)
+			continue
+		}
+
+		if info.Size() < lastSize {
+			lastSize = 0
+		}
+		if info.Size() > lastSize {
+			f, err := os.Open(path)
+			if err != nil {
+				time.Sleep(2 * time.Second)
+				continue
+			}
+			_, _ = f.Seek(lastSize, 0)
+			scanner := bufio.NewScanner(f)
+			for scanner.Scan() {
+				line := scanner.Text()
+				if err := appendRuntimeLog("VRC LOG", line); err != nil {
+					log.Printf("append runtime log failed: %v", err)
+				}
+				if changed, worldLabel := updateWorldState(state, line); changed {
+					log.Printf("world changed: %s", worldLabel)
+					state.presentSet = map[string]struct{}{}
+					_ = appendRuntimeLog("VRC WORLD", worldLabel)
+				}
+				if m := joinPattern.FindStringSubmatch(line); len(m) == 2 {
+					name := strings.TrimSpace(m[1])
+					state.presentSet[name] = struct{}{}
+					out := fmt.Sprintf("[join] %s (%d)", name, len(state.presentSet))
+					log.Print(out)
+					_ = appendJoinLeaveLog(out)
+					continue
+				}
+				if m := leftPattern.FindStringSubmatch(line); len(m) == 2 {
+					name := strings.TrimSpace(m[1])
+					delete(state.presentSet, name)
+					out := fmt.Sprintf("[leave] %s (%d)", name, len(state.presentSet))
+					log.Print(out)
+					_ = appendJoinLeaveLog(out)
+					continue
+				}
+			}
+			lastSize = info.Size()
+			_ = f.Close()
+		}
+		time.Sleep(2 * time.Second)
+	}
+}
+
+func scanExistingVrchatLog(path string, state *vrcLogState) error {
+	f, err := os.Open(path)
+	if err != nil {
+		return err
+	}
+	defer f.Close()
+
+	state.presentSet = map[string]struct{}{}
+	state.location = ""
+	state.worldID = ""
+	state.instanceID = ""
+	state.worldName = ""
+	state.pendingWorldName = ""
+	state.initialized = false
+
+	scanner := bufio.NewScanner(f)
+	for scanner.Scan() {
+		line := scanner.Text()
+		if changed, _ := updateWorldState(state, line); changed {
+			state.presentSet = map[string]struct{}{}
+		}
+		if m := joinPattern.FindStringSubmatch(line); len(m) == 2 {
+			name := strings.TrimSpace(m[1])
+			state.presentSet[name] = struct{}{}
+			continue
+		}
+		if m := leftPattern.FindStringSubmatch(line); len(m) == 2 {
+			name := strings.TrimSpace(m[1])
+			delete(state.presentSet, name)
+			continue
+		}
+	}
+	if err := scanner.Err(); err != nil {
+		return err
+	}
+	state.initialized = true
+	if state.worldName != "" {
+		log.Printf("world changed: %s", state.worldName)
+		_ = appendRuntimeLog("VRC WORLD", state.worldName)
+	}
+	return nil
+}
+
+func updateWorldState(state *vrcLogState, line string) (bool, string) {
+	worldID := ""
+	instanceID := ""
+	worldName := ""
+	roomTitle := ""
+
+	if m := enteringRoomPattern.FindStringSubmatch(line); len(m) == 2 {
+		roomTitle = strings.TrimSpace(m[1])
+		state.pendingWorldName = roomTitle
+	}
+	if m := worldLocationPattern.FindStringSubmatch(line); len(m) == 3 {
+		worldID = strings.TrimSpace(m[1])
+		instanceID = strings.TrimSpace(m[2])
+	}
+
+	if m := worldIdPattern.FindStringSubmatch(line); len(m) == 2 {
+		worldID = strings.TrimSpace(m[1])
+	}
+	if m := instanceIdPattern.FindStringSubmatch(line); len(m) == 2 {
+		instanceID = strings.TrimSpace(m[1])
+	}
+	if m := worldNamePattern.FindStringSubmatch(line); len(m) == 2 {
+		worldName = strings.TrimSpace(m[1])
+	}
+
+	if m := enteringRoomPattern.FindStringSubmatch(line); len(m) == 2 && worldID == "" {
+		if worldMatch := worldPattern.FindStringSubmatch(m[1]); len(worldMatch) == 2 {
+			worldID = worldMatch[1]
+		}
+	}
+
+	nextLocation := ""
+	if worldID != "" {
+		nextLocation = worldID
+		if instanceID != "" {
+			nextLocation = worldID + ":" + instanceID
+		}
+	}
+
+	if nextLocation != "" && nextLocation != state.location {
+		state.location = nextLocation
+		state.worldID = worldID
+		state.instanceID = instanceID
+		if worldName != "" {
+			state.worldName = worldName
+		} else if shouldUseRoomTitlePreferLatest(roomTitle, state.worldName) {
+			state.worldName = roomTitle
+		}
+		label := state.worldName
+		if label == "" {
+			label = state.worldID
+		}
+		if label == "" {
+			label = nextLocation
+		}
+		if state.initialized {
+			log.Printf("world changed: %s", label)
+			_ = appendRuntimeLog("VRC WORLD", label)
+		}
+		return true, label
+	}
+
+	if worldName != "" {
+		state.worldName = worldName
+		state.pendingWorldName = ""
+		return false, ""
+	}
+	if shouldUseRoomTitlePreferLatest(roomTitle, state.worldName) {
+		state.worldName = roomTitle
+	}
+
+	return false, ""
+}
+
+func shouldUseRoomTitle(roomTitle, currentWorldName string) bool {
+	if roomTitle == "" {
+		return false
+	}
+	if strings.Contains(roomTitle, "Home Location") {
+		return false
+	}
+	if roomTitle == "Holiday-Cottage" && currentWorldName != "" && currentWorldName != roomTitle {
+		return false
+	}
+	if currentWorldName == "" {
+		return true
+	}
+	if roomTitle == currentWorldName {
+		return false
+	}
+	if len(roomTitle) > len(currentWorldName) {
+		return true
+	}
+	if strings.Contains(roomTitle, "「") || strings.Contains(roomTitle, "」") || strings.Contains(roomTitle, "[") {
+		return true
+	}
+	return false
+}
+
+func shouldUseRoomTitlePreferLatest(roomTitle, currentWorldName string) bool {
+	if roomTitle == "" {
+		return false
+	}
+	if strings.Contains(roomTitle, "Home Location") {
+		return false
+	}
+	if currentWorldName == "" {
+		return true
+	}
+	if roomTitle == currentWorldName {
+		return false
+	}
+	return true
+}