diff --git a/LogWatcher.cs b/LogWatcher.cs index e684321d..2f530520 100644 --- a/LogWatcher.cs +++ b/LogWatcher.cs @@ -12,20 +12,21 @@ using System.Threading; namespace VRCX { - public class LogWatcherFile - { - public long Length; - public long Position; - public string Tag; - } - public class LogWatcher { + private class LogContext + { + public long Length; + public long Position; + } + public static LogWatcher Instance { get; private set; } - private static readonly ReaderWriterLockSlim m_Lock = new ReaderWriterLockSlim(); - private static List m_GameLog = new List(); - private static Thread m_Thread; - private static bool m_Reset; + private readonly DirectoryInfo m_LogDirectoryInfo; + private readonly Dictionary m_LogContextMap; // + private readonly ReaderWriterLockSlim m_LogListLock; + private readonly List m_LogList; + private Thread m_WatchThread; + private bool m_ResetLog; // NOTE // FileSystemWatcher() is unreliable @@ -35,218 +36,145 @@ namespace VRCX Instance = new LogWatcher(); } - public static void Init() + public LogWatcher() { - m_Thread = new Thread(() => - { - var D = new Dictionary(); - var di = new DirectoryInfo(Environment.GetFolderPath(Environment.SpecialFolder.LocalApplicationData) + @"Low\VRChat\VRChat"); - while (m_Thread != null) - { - try - { - Thread.Sleep(1000); - } - catch - { - // ThreadInterruptedException - } - if (m_Reset) - { - m_Reset = false; - D.Clear(); - m_Lock.EnterWriteLock(); - try - { - m_GameLog.Clear(); - } - finally - { - m_Lock.ExitWriteLock(); - } - } - var S = new HashSet(D.Keys); - di.Refresh(); - if (di.Exists) - { - var files = di.GetFiles("output_log_*.txt", SearchOption.TopDirectoryOnly); - Array.Sort(files, (A, B) => A.CreationTimeUtc.CompareTo(B.CreationTimeUtc)); - var bias = DateTime.UtcNow.AddMinutes(-5d); - foreach (var fi in files) - { - if (bias.CompareTo(fi.LastWriteTimeUtc) <= 0) - { - fi.Refresh(); - } - if (D.TryGetValue(fi.Name, out LogWatcherFile F)) - { - S.Remove(fi.Name); - if (F.Length == fi.Length) - { - continue; - } - } - else - { - F = new LogWatcherFile(); - D.Add(fi.Name, F); - } - F.Length = fi.Length; - Parse(fi, F); - } - } - foreach (var key in S) - { - D.Remove(key); - } - } - }) + var logPath = Environment.GetFolderPath(Environment.SpecialFolder.LocalApplicationData) + @"Low\VRChat\VRChat"; + m_LogDirectoryInfo = new DirectoryInfo(logPath); + m_LogContextMap = new Dictionary(); + m_LogListLock = new ReaderWriterLockSlim(); + m_LogList = new List(); + m_WatchThread = new Thread(WatchLoop) { IsBackground = true }; - m_Thread.Start(); } - public static void Exit() + public void Init() { - var T = m_Thread; - m_Thread = null; - T.Interrupt(); - T.Join(); + m_WatchThread.Start(); } - public static void Parse(FileInfo info, LogWatcherFile F) + public void Exit() + { + var watchThread = m_WatchThread; + m_WatchThread = null; + watchThread.Interrupt(); + watchThread.Join(); + } + + private void WatchLoop() + { + while (m_WatchThread != null) + { + try + { + Thread.Sleep(1000); + } + catch + { + // ThreadInterruptedException + } + + Update(); + } + } + + private void Update() + { + if (m_ResetLog == true) + { + m_ResetLog = false; + m_LogContextMap.Clear(); + m_LogListLock.EnterWriteLock(); + try + { + m_LogList.Clear(); + } + finally + { + m_LogListLock.ExitWriteLock(); + } + } + + var deletedNameSet = new HashSet(m_LogContextMap.Keys); + m_LogDirectoryInfo.Refresh(); + + if (m_LogDirectoryInfo.Exists == true) + { + var fileInfos = m_LogDirectoryInfo.GetFiles("output_log_*.txt", SearchOption.TopDirectoryOnly); + + // sort by creation time + Array.Sort(fileInfos, (a, b) => a.CreationTimeUtc.CompareTo(b.CreationTimeUtc)); + + var bias = DateTime.UtcNow.AddMinutes(-3d); + + foreach (var fileInfo in fileInfos) + { + if (bias.CompareTo(fileInfo.LastWriteTimeUtc) <= 0) + { + fileInfo.Refresh(); + if (fileInfo.Exists == false) + { + continue; + } + } + + if (m_LogContextMap.TryGetValue(fileInfo.Name, out LogContext logContext) == true) + { + deletedNameSet.Remove(fileInfo.Name); + } + else + { + logContext = new LogContext(); + m_LogContextMap.Add(fileInfo.Name, logContext); + } + + if (logContext.Length == fileInfo.Length) + { + continue; + } + + logContext.Length = fileInfo.Length; + ParseLog(fileInfo, logContext); + } + } + + foreach (var name in deletedNameSet) + { + m_LogContextMap.Remove(name); + } + } + + private void ParseLog(FileInfo fileInfo, LogContext logContext) { try { - using (var stream = info.Open(FileMode.Open, FileAccess.Read, FileShare.ReadWrite)) + using (var fileStream = fileInfo.Open(FileMode.Open, FileAccess.Read, FileShare.ReadWrite)) { - stream.Position = F.Position; - using (var reader = new StreamReader(stream, Encoding.UTF8)) + fileStream.Position = logContext.Position; + using (var streamReader = new StreamReader(fileStream, Encoding.UTF8)) { - var s = string.Empty; - while ((s = reader.ReadLine()) != null) + while (true) { - s = s.Trim(); - if (s.Length <= 35) + var line = streamReader.ReadLine(); + if (line == null) + { + logContext.Position = fileStream.Position; + break; + } + + if (line.Length <= 34 || + line[31] != '-' || + ParseLogOnPlayerJoined(fileInfo, line) == true || + ParseLogOnPlayerLeft(fileInfo, line) == true || + ParseLogNotification(fileInfo, line) == true || + ParseLogLocation(fileInfo, line) == true || + ParseLogHMDModel(fileInfo, line) == true || + ParseLogAuth(fileInfo, line) == true) { continue; } - var c = s[35]; - if (c == 'N') - { - if (s.Length > 66 && - string.Compare(s, 34, "[NetworkManager] OnPlayerJoined ", 0, 32, StringComparison.Ordinal) == 0) - { - // 2020.10.28 22:57:04 Log - [NetworkManager] OnPlayerJoined pypy - var time = ConvertLogTimeToISO8601(s); - var data = s.Substring(66); - m_Lock.EnterWriteLock(); - try - { - m_GameLog.Add(new[] - { - time, - "OnPlayerJoined", - data - }); - } - finally - { - m_Lock.ExitWriteLock(); - } - } - else if (s.Length > 64 && - string.Compare(s, 34, "[NetworkManager] OnPlayerLeft ", 0, 30, StringComparison.Ordinal) == 0) - { - // 2020.10.28 22:57:42 Log - [NetworkManager] OnPlayerLeft pypy - var time = ConvertLogTimeToISO8601(s); - var data = s.Substring(64); - m_Lock.EnterWriteLock(); - try - { - m_GameLog.Add(new[] - { - time, - "OnPlayerLeft", - data - }); - } - finally - { - m_Lock.ExitWriteLock(); - } - } - } - else if (c == 'R') - { - if (s.Length > 56 && - string.Compare(s, 34, "[RoomManager] Joining ", 0, 22, StringComparison.Ordinal) == 0) - { - if (string.Compare(s, 56, "or ", 0, 3, StringComparison.Ordinal) == 0) - { - // 2019.07.31 22:26:24 Log - [RoomManager] Joining or Creating Room: VRChat Home - var time = ConvertLogTimeToISO8601(s); - var data = string.Empty; - if (s.Length > 74) - { - data = s.Substring(74); - } - m_Lock.EnterWriteLock(); - try - { - m_GameLog.Add(new[] - { - time, - "Location", - F.Tag ?? string.Empty, - data - }); - } - finally - { - m_Lock.ExitWriteLock(); - } - } - else - { - // 2019.07.31 22:26:24 Log - [RoomManager] Joining wrld_4432ea9b-729c-46e3-8eaf-846aa0a37fdd:6974~private(usr_4f76a584-9d4b-46f6-8209-8305eb683661)~nonce(0000000000000000000000000000000000000000000000000000000000000000) - F.Tag = s.Substring(56); - } - } - } - else if (c == 'e') - { - if (s.Length > 82 && - string.Compare(s, 34, "Received Message of type: notification content: ", 0, 48, StringComparison.Ordinal) == 0) - { - // 2020.06.28 06:28:18 Log - Received Message of type: notification content: {{"id":"not_7ba7c14f-e9e4-4e2f-a2e7-f5ccb7ffdad5","type":"invite","senderUserId":"usr_4f76a584-9d4b-46f6-8209-8305eb683661","senderUsername":"pypy","receiverUserId":"usr_f38006b4-eab5-4243-bcb1-206138e629d8","message":"This is a generated invite","details":{{"worldId":"wrld_03f52086-965c-456f-a5e9-4ba6df473173:72562~friends(usr_8a2f5b19-4f97-4642-b0fe-d8b338691b47)~nonce(1158A2215996CF893F29D270E47681DED8B6C226BCEF9B767F66EB7B55144E58)","worldName":"Shy Avatars"}},"created_at":"2020-06-27T21:28:18.520Z"}} received at 2020-06-27 PM 9:28:18 UTC - // 2020.06.28 06:28:18 Log - Received Notification: received at 2020-06-27 PM 9:28:18 UTC - var time = ConvertLogTimeToISO8601(s); - var data = s.Substring(82); - var pos = data.LastIndexOf('}'); - if (pos >= 0) - { - data = data.Substring(0, pos + 1); // including brace - } - m_Lock.EnterWriteLock(); - try - { - m_GameLog.Add(new[] - { - time, - "Notification", - data - }); - } - finally - { - m_Lock.ExitWriteLock(); - } - } - } } - F.Position = stream.Position; } } } @@ -255,55 +183,264 @@ namespace VRCX } } - private static string ConvertLogTimeToISO8601(string s) + private void AppendLog(string[] item) { - // 2019.07.31 22:26:24 - if (!DateTime.TryParseExact(s.Substring(0, 19), + m_LogListLock.EnterWriteLock(); + try + { + m_LogList.Add(item); + } + finally + { + m_LogListLock.ExitWriteLock(); + } + } + + private string ConvertLogTimeToISO8601(string line) + { + // 2020.10.31 23:36:22 + + if (DateTime.TryParseExact( + line.Substring(0, 19), "yyyy.MM.dd HH:mm:ss", CultureInfo.InvariantCulture, DateTimeStyles.AdjustToUniversal | DateTimeStyles.AssumeLocal, - out DateTime dt)) + out DateTime dt + ) == false) { dt = DateTime.UtcNow; } + return $"{dt:yyyy'-'MM'-'dd'T'HH':'mm':'ss'Z'}"; } + private bool ParseLogHMDModel(FileInfo fileInfo, string line) + { + // 2020.10.31 23:36:23 Log - STEAMVR HMD Model: VIVE_Pro MV + + if (line.Length <= 53 || + line[34] != 'S' || + string.Compare(line, 34, "STEAMVR HMD Model: ", 0, 19, StringComparison.Ordinal) != 0) + { + return false; + } + + var hmdModel = line.Substring(53); + + AppendLog(new[] + { + fileInfo.Name, + ConvertLogTimeToISO8601(line), + "hmd-model", + hmdModel + }); + + return true; + } + + private bool ParseLogAuth(FileInfo fileInfo, string line) + { + // 2020.10.31 23:36:26 Log - [VRCFlowNetworkManager] Sending token from provider vrchat as user zetyx + + if (line.Length <= 86 || + line[35] != 'V' || + string.Compare(line, 34, "[VRCFlowNetworkManager] Sending token from provider ", 0, 41, StringComparison.Ordinal) != 0) + { + return false; + } + + var pos = line.IndexOf(" as user ", 86); + if (pos < 0) + { + return false; + } + + var loginProvider = line.Substring(86, pos - 86); + var loginUser = line.Substring(pos + 9); + + AppendLog(new[] + { + fileInfo.Name, + ConvertLogTimeToISO8601(line), + "auth", + loginProvider, + loginUser + }); + + return true; + } + + private bool ParseLogLocation(FileInfo fileInfo, string line) + { + // 2020.10.31 23:36:28 Log - [VRCFlowManagerVRC] Destination fetching: wrld_4432ea9b-729c-46e3-8eaf-846aa0a37fdd + // 2020.10.31 23:36:28 Log - [VRCFlowManagerVRC] Destination set: wrld_4432ea9b-729c-46e3-8eaf-846aa0a37fdd + // 2020.10.31 23:36:31 Log - [RoomManager] Entering Room: VRChat Home + // 2020.10.31 23:36:31 Log - [RoomManager] Joining wrld_4432ea9b-729c-46e3-8eaf-846aa0a37fdd:67646~private(usr_4f76a584-9d4b-46f6-8209-8305eb683661)~nonce(D9298A536FEEEDDBB61633661A4BDAA09717C5178DEF865C4C09372FE12E09A6) + // 2020.10.31 23:36:31 Log - [RoomManager] Joining or Creating Room: VRChat Home + // 2020.10.31 23:36:31 Log - [RoomManager] Successfully joined room + + if (line.Length <= 56 || + line[35] != 'R' || + string.Compare(line, 34, "[RoomManager] Joining ", 0, 22, StringComparison.Ordinal) != 0) + { + return false; + } + + if (string.Compare(line, 56, "or ", 0, 3, StringComparison.Ordinal) != 0) + { + var location = line.Substring(56); + + AppendLog(new[] + { + fileInfo.Name, + ConvertLogTimeToISO8601(line), + "location", + location + }); + + return true; + } + + var worldName = (line.Length <= 74) + ? string.Empty + : line.Substring(74); + + AppendLog(new[] + { + fileInfo.Name, + ConvertLogTimeToISO8601(line), + "world", + worldName + }); + + return true; + } + + private bool ParseLogOnPlayerJoined(FileInfo fileInfo, string line) + { + // 2020.10.31 23:36:58 Log - [NetworkManager] OnPlayerJoined pypy + // 2020.10.31 23:36:58 Log - [Player] Initialized PlayerAPI "pypy" is local + // 2020.10.31 23:36:58 Log - [NetworkManager] OnPlayerJoined Rize♡ + // 2020.10.31 23:36:58 Log - [Player] Initialized PlayerAPI "Rize♡" is remote + + if (line.Length <= 66 || + line[35] != 'N' || + string.Compare(line, 34, "[NetworkManager] OnPlayerJoined ", 0, 32, StringComparison.Ordinal) != 0) + { + return false; + } + + var userDisplayName = line.Substring(66); + + AppendLog(new[] + { + fileInfo.Name, + ConvertLogTimeToISO8601(line), + "player-joined", + userDisplayName + }); + + return true; + } + + private bool ParseLogOnPlayerLeft(FileInfo fileInfo, string line) + { + // 2020.11.01 00:07:01 Log - [NetworkManager] OnPlayerLeft Rize♡ + // 2020.11.01 00:07:01 Log - [PlayerManager] Removed player 2 / Rize♡ + // 2020.11.01 00:07:02 Log - [Player] Unregistering Rize♡ + + if (line.Length <= 64 || + line[35] != 'N' || + string.Compare(line, 34, "[NetworkManager] OnPlayerLeft ", 0, 30, StringComparison.Ordinal) != 0) + { + return false; + } + + var userDisplayName = line.Substring(64); + + AppendLog(new[] + { + fileInfo.Name, + ConvertLogTimeToISO8601(line), + "player-left", + userDisplayName + }); + + return true; + } + + private bool ParseLogNotification(FileInfo fileInfo, string line) + { + // 2020.10.31 23:36:28 Log - Received Message of type: notification content: {{"id":"not_3a8f66eb-613c-4351-bee3-9980e6b5652c","senderUserId":"usr_4f76a584-9d4b-46f6-8209-8305eb683661","senderUsername":"pypy","type":"friendRequest","message":"","details":"{{}}","seen":false,"created_at":"2020-08-16T11:03:59.291Z"}} received at 10/31/2020 14:36:28 UTC + + if (line.Length <= 82 || + line[34] != 'R' || + string.Compare(line, 34, "Received Message of type: notification content: ", 0, 48, StringComparison.Ordinal) != 0) + { + return false; + } + + var pos = line.LastIndexOf("}} received at"); + if (pos < 0) + { + return false; + } + + var json = line.Substring(82, pos - 82 + 2); // including brace + json = json.Replace("{{", "{"); + json = json.Replace("}}", "}"); + + AppendLog(new[] + { + fileInfo.Name, + ConvertLogTimeToISO8601(line), + "notification", + json + }); + + return true; + } + public void Reset() { - if (m_Thread != null) + m_ResetLog = true; + if (m_WatchThread != null) { - m_Reset = true; - m_Thread.Interrupt(); + m_WatchThread.Interrupt(); } } public string[][] Get() { - m_Lock.EnterUpgradeableReadLock(); - try + if (m_ResetLog == false && + m_LogList.Count > 0) { - if (m_Reset || - m_GameLog.Count == 0) - { - return new string[][] { }; - } - var array = m_GameLog.ToArray(); - m_Lock.EnterWriteLock(); + m_LogListLock.EnterWriteLock(); try { - m_GameLog.Clear(); + string[][] array; + + if (m_LogList.Count > 100) + { + array = new string[100][]; + m_LogList.CopyTo(0, array, 0, 100); + m_LogList.RemoveRange(0, 100); + } + else + { + array = m_LogList.ToArray(); + m_LogList.Clear(); + } + + return array; } finally { - m_Lock.ExitWriteLock(); + m_LogListLock.ExitWriteLock(); } - return array; - } - finally - { - m_Lock.ExitUpgradeableReadLock(); } + + return new string[][] { }; } } } \ No newline at end of file diff --git a/Program.cs b/Program.cs index d9af6eb1..e96879a7 100644 --- a/Program.cs +++ b/Program.cs @@ -60,11 +60,11 @@ namespace VRCX SQLite.Init(); CpuMonitor.Init(); Discord.Init(); - LogWatcher.Init(); + LogWatcher.Instance.Init(); VRCXVR.Init(); Application.Run(new MainForm()); VRCXVR.Exit(); - LogWatcher.Exit(); + LogWatcher.Instance.Exit(); Discord.Exit(); CpuMonitor.Exit(); SQLite.Exit(); diff --git a/html/src/app.js b/html/src/app.js index 1bccfcb8..3c577217 100644 --- a/html/src/app.js +++ b/html/src/app.js @@ -3288,6 +3288,7 @@ CefSharp.BindObjectAsync( API.$on('SHOW_WORLD_DIALOG', (tag) => this.showWorldDialog(tag)); API.$on('SHOW_LAUNCH_DIALOG', (tag) => this.showLaunchDialog(tag)); setInterval(() => this.update(), 1000); + setInterval(() => this.refreshGameLog(), 100); this.update(); this.$nextTick(function () { this.$el.style.display = ''; @@ -3378,7 +3379,6 @@ CefSharp.BindObjectAsync( }); } this.checkActiveFriends(); - this.refreshGameLog(); VRCX.CheckGameRunning().then(([isGameRunning, isGameNoVR]) => { if (isGameRunning !== this.isGameRunning) { this.isGameRunning = isGameRunning; @@ -4417,6 +4417,8 @@ CefSharp.BindObjectAsync( // App: gameLog + var gameLogContextMap = new Map(); + $app.data.lastLocation = ''; $app.data.lastLocation$ = {}; $app.data.discordActive = VRCXStorage.GetBool('discordActive'); @@ -4468,38 +4470,100 @@ CefSharp.BindObjectAsync( }); }; - $app.methods.refreshGameLog = function () { - LogWatcher.Get().then((logs) => { - if (logs.length) { - var { data } = this.gameLogTable; - for (var log of logs) { - var ctx = { - created_at: String(log[0]), - type: String(log[1]), - data: String(log[2]) - }; - if (ctx.data === API.currentUser.displayName) { - continue; - } - if (ctx.type === 'Location') { - var tag = ctx.data; - if (tag.endsWith(':')) { - tag = tag.substr(0, tag.length - 1); - ctx.data = tag; - } - this.lastLocation = tag; - } - data.push(ctx); - } - this.sweepGameLog(); - // sweepGameLog로 기록이 삭제되면 - // 아무 것도 없는데 알림이 떠서 이상함 - if (data.length) { - this.notifyMenu('gameLog'); - } + $app.methods.refreshGameLog = async function () { + if (API.isLoggedIn !== true) { + return; + } + + var currentUser = API.currentUser.username; + + for (var [fileName, dt, type, ...args] of await LogWatcher.Get()) { + var gameLogContext = gameLogContextMap.get(fileName); + if (gameLogContext === undefined) { + gameLogContext = { + // auth + loginProvider: null, + loginUser: null, + + // hmd + hmdModel: null, + + // location + location: null, + }; + gameLogContextMap.set(fileName, gameLogContext); } - this.updateSharedFeed(); - }); + + var gameLogTableData = null; + + switch (type) { + case 'auth': + gameLogContext.loginProvider = args[0]; + gameLogContext.loginUser = args[1]; + break; + + case 'hmd-model': + gameLogContext.hmdModel = args[0]; + break; + + case 'location': + var location = args[0]; + gameLogContext.location = location; + if (gameLogContext.loginUser === currentUser) { + this.lastLocation = location; + } + break; + + case 'world': + // var worldName = params[0]; + gameLogTableData = { + created_at: dt, + type: 'Location', + data: gameLogContext.location + }; + break; + + case 'player-join': + var userDisplayName = args[0]; + gameLogTableData = { + created_at: dt, + type: 'OnPlayerJoined', + data: userDisplayName + }; + break; + + case 'player-left': + var userDisplayName = args[0]; + gameLogTableData = { + created_at: dt, + type: 'OnPlayerLeft', + data: userDisplayName + }; + break; + + case 'notification': + var json = args[0]; + gameLogTableData = { + created_at: dt, + type: 'Notification', + data: json + }; + break; + } + + if (gameLogTableData !== null && + gameLogContext.loginUser === currentUser) { + this.gameLogTable.data.push(gameLogTableData); + } + } + + this.sweepGameLog(); + + if (this.gameLogTable.data.length > 0) { + this.notifyMenu('gameLog'); + } + + this.updateSharedFeed(); }; $app.methods.sweepGameLog = function () {