Fexty12573 / SharpPluginLoader

A C# plugin loader for Monster Hunter World
MIT License
32 stars 2 forks source link

[Bug] Log Messages Are Messed Up #23

Open GreenComfyTea opened 6 months ago

GreenComfyTea commented 6 months ago

Describe The Bug

Stracker's Loader console seems to not be thread-safe/fast enough. Calling Log.Info (or any other logging function) from different threads and/or too fast causes 2 side effects:

  1. Lines are leaking into each other.

image

  1. Green Color of the [ TIME ] is leaking into the message.

image

If I hot-reload the plugin it will go even crazier.

image

I can see how this can become a bigger issue when there are multiple plugins trying to log stuff.

FileSystemWatcher fires Changed event twice, this is known bug/feature of it (-> Remarks), and a good way to reproduce the issue.

As a side note, Console.WriteLine() has a similar bug, even thou it is supposed to be thread-safe. StackOverflow post.

To Reproduce

1) Make a plugin log stuff from different threads at the same time or have a FileSystemWatcher with Change event; 2) Launch the game; 3) Hot-reload the plugin; 3) Observe.

Expected Behavior

Console shouldn't behave like that. The Logger should be made thread-safe and, perhaps, buffered and throttled a little bit? While I can do that plugin-side, I think that the issue should be addressed on SPL level. Not sure how to fix that exactly thou, since I can see how buffering/throttling can lead to an overflow quickly if a plugin tries to log caught exceptions repeatedly.

Priority

Suggested P4 Priority. The issue is only visual and doesn't affect the functionality of SPL or plugins.

PC Specs

Show/Hide - `Motherboard`**: Asus ROG Strix Z390-H Gaming** - `CPU`**: Intel Core i9-9900k** - `RAM`**: 32 GB 3200MHz** - `GPU`**: Nvidia GeForce RTX 3090 Ti** - `System and Game SSD`**: Samsung SSD 970 EVO Plus NVMe M.2 1TB** - `Plugin Repo SSD`**: Western Digital Blue SATA M.2 2280 2TB**

Environment

Show/Hide - `OS`: **Window 10 Enterprise Version 22H2 (OS Build 19045.3996)** - `Monster Hunter: World`: **v15.21.00** - `SharpPluginLoader`: **pre-v0.0.4.0 (bea10943ea02b8d3f75d99a328e8012a45595b84)** - `Nvidia Drivers`**: v551.52**

Game Display Settings

Show/Hide - `DirectX 12 API`**: On** - `Screen Mode`**: Borderless Window** - `Resolution Settings`**: 2880x1620** (Supersampled down to 1920x1080) - `Aspect Ratio`**: Wide (16:9)** - `Nvidia DLSS`**: Off** - `FidelityFX CAS + Upscaling`**: Off** - `Frame Rate`**: No Limit** - `V-Sync`**: On**

Game Advanced Graphics Settings

Show/Hide - `Image Quality`**: High** - `Texture Quality`**: High Resolution Texture Pack** - `Ambient Occlusion`**: High** - `Volume Rendering Quality`**: Highest** - `Shadow Quality`**: High** - `Capsule AO`**: On** - `Contact Shadows`**: On** - `Anti-Aliasing`**: Off** - `LOD Bias`**: High** - `Max LOD Level`**: No Limit** - `Foliage Sway`**: On** - `Subsurface Scattering`**: On** - `Screen Space Reflection`**: On** - `Anisotropic Filtering`**: Highest** - `Water Reflection`**: On** - `Snow Quality`**: High** - `SH Diffuse Quality`**: High** - `Dynamic Range`**: 64-bit** - `Motion Blur`**: On** - `DOF (Depth of Field)`**: On** - `Vignette Effects`**: Normal** - `Z-Prepass`**: On**

Mods and External Tools:

Show/Hide - [RTSS Overlay v7.3.4](https://www.guru3d.com/page/rivatuner-rtss-homepage/) - [Reshade 6.0.0](https://reshade.me/) with SMAA.fx - [Stracker's Loader v3.0.1](https://www.nexusmods.com/monsterhunterworld/mods/1982) - [Performance Booster and Plugin Extender v1.3](https://www.nexusmods.com/monsterhunterworld/mods/3473) - [HunterPie v2.10.0.134](https://www.nexusmods.com/monsterhunterrise/mods/181) - [HelloWorld (an overlay that shows lots and lots of stuff) v10.4](https://www.nexusmods.com/monsterhunterworld/mods/142) - [Bow Spread Pattern Fix v1.0](https://www.nexusmods.com/monsterhunterworld/mods/6914) - [Tic Rate Fix v1.0](https://www.nexusmods.com/monsterhunterworld/mods/3474) - [Guiding Lands Gathering Indicator v1.12.11.01](https://www.nexusmods.com/monsterhunterworld/mods/1986) - [Gems Sorted by Name (Alphabetized Gems) v1.6.1](https://www.nexusmods.com/monsterhunterworld/mods/2364) - [Reshade Hook v1.0](https://www.nexusmods.com/monsterhunterworld/mods/7015) - [Endemic Quality (Iceborne Edition) v1.4](https://www.nexusmods.com/monsterhunterworld/mods/2137) - [Remove censor bad word banned word filter v1.0](https://www.nexusmods.com/monsterhunterworld/mods/6956) - [Monster Weakness Icon Indicator for Iceborne (Hi-Res) vFinal](https://www.nexusmods.com/monsterhunterworld/mods/1938) - [Cuter Handler Face Model (Post-Iceborne) aka Make Handler Cuter Again v3.0](https://www.nexusmods.com/monsterhunterworld/mods/1914)

Additional Context

Plugin Repo

Andoryuuta commented 6 months ago

We might consider just swapping our C++ logging class to use spdlog. It would handle the async logging/flushing, multiple sinks (e.g. to stdout + log file on disk), timestamps, prefixes, colorized text, etc.

(The issue with the C#/managed logger is the same, as it's just a wrapper around the C++ implementation)