Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

simultaneously updating a dependency and a dependent plugin can produce incorrect error messages #17

Open
XertroV opened this issue Nov 17, 2022 · 2 comments

Comments

@XertroV
Copy link
Contributor

XertroV commented Nov 17, 2022

This situation arose when ppl updated MLFeed and Buffer Time at the same time.
I think plugin manager will reload them in a way that means a dependent plugin has a chance to issue an error notification, but then gets reloaded in a way that means no output is generated.
This leads to confusion on the part of the user.

Example 1 via AR_Down: https://www.twitch.tv/videos/1654817065?t=00h18m30s
Example 2 via JNic: https://www.twitch.tv/videos/1655110358?t=00h10m12s

I'm happy to look at a patch if you like. I guess that it's just a matter of unloading in the right order, then updating dependencies, then updating dependents.

@codecat
Copy link
Member

codecat commented Nov 17, 2022

It would be good to see the log of this, and perhaps some reproduce steps (eg. install old versions & click update). The log should say the order in which plugins are loaded.

@XertroV
Copy link
Contributor Author

XertroV commented Nov 20, 2022

Reproduction steps:

  1. ensure auto updating disabled in plugin manager settings
  2. have MLHook installed in Plugins/ already
  3. TM is closed
  4. Download MLFeed 0.3.7 and Buffer Time 1.0.7 and put them in Plugins/
  5. Start TM
  6. wait for initialization so logs are clean
  7. press update all

image

FYI my plan to avoid this in upcoming versions is just to sleep for a second before notifying the user about a missing dependency. That is hopefully enough time.

Filtered log corresponding to the above (with a bit more included)

[   ScriptRuntime] [10:22:47] [PluginManager]  Plugin cache: Synchronized Dashboard 1.9.4
[   ScriptRuntime] [10:22:47] [PluginManager]  Plugin cache: Synchronized SplitSpeeds 1.0.5
[   ScriptRuntime] [10:22:47] [PluginManager]  Checking for plugin updates..
[   ScriptRuntime] [10:22:47] [PluginManager]  API request: https://openplanet.dev/api/versions?ids=192,49,103,206,144,241,125,69,145,216,146,131,82,162,170,256,134,79,118,99,154,163,255,217,279,71,too-many-ghosts-0.1.0,238,205,158,271,62,225,250,164
[   ScriptRuntime] [10:22:47] [MLFeedRaceData]  registered MLHook event for type: MLHook_Event_RaceStats_PlayerCP
[   ScriptRuntime] [10:22:47] [MLFeedRaceData]  registered MLHook event for type: MLHook_Event_RaceStats_PlayerLeft
[   ScriptRuntime] [10:22:47] [MLFeedRaceData]  registered MLHook event for type: MLHook_Event_RaceStats_PlayerRaceTimes
[   ScriptRuntime] [10:22:47] [MLFeedRaceData]  registered MLHook event for type: MLHook_Event_MLFeedKOs_PlayerStatus
[   ScriptRuntime] [10:22:47] [MLFeedRaceData]  registered MLHook event for type: MLHook_Event_MLFeedKOs_MatchKeyPair
[   ScriptRuntime] [10:22:47] [MLFeedRaceData]  registered MLHook event for type: TMxSM_Race_Record_NewRecord
[   ScriptRuntime] [10:22:47] [MLFeedRaceData]  registered MLHook event for type: MLHook_Event_GhostData
[   ScriptRuntime] [10:22:47] [PluginManager]  Saved PluginCache.json
[   ScriptRuntime] [10:22:48] [PluginManager]  New plugin update available for COTD Buffer Time: 1.0.7 -> 2.1.12
[   ScriptRuntime] [10:22:48] [PluginManager]  New plugin update available for MLFeed: Race Data: 0.3.7 -> 0.3.8
[   ScriptRuntime] [10:23:16] [PluginManager]  Uninstalling plugin COTD Buffer Time
[   ScriptRuntime] [10:23:16] [PluginManager]  Plugin cache: Removed CotdBufferTime
[   ScriptRuntime] [10:23:16] [PluginManager]  Installing plugin with site ID 256 and identifier "CotdBufferTime"
[   ScriptRuntime] [10:23:16] [PluginManager]  Saved PluginCache.json
[   ScriptRuntime] [10:23:18] [PluginManager]  Uninstalling plugin MLFeed: Race Data
[    ScriptEngine] [10:23:18]  Unloading dependent plugin "better-splits-history-dev" of "MLFeedRaceData"
[    ScriptEngine] [10:23:18]  Unloading dependent plugin "players-pbs-dev" of "MLFeedRaceData"
[    ScriptEngine] [10:23:18]  Unloading dependent plugin "race-stats-dev" of "MLFeedRaceData"
[    ScriptEngine] [10:23:18]  Unloading dependent plugin "buffer-time-dev" of "MLFeedRaceData"
[   ScriptRuntime] [10:23:18] [MLFeedRaceData]  _Unload, unloading hooks and removing injected ML
[   ScriptRuntime] [10:23:18] [MLFeedRaceData]  UnregisteredMLHook object for types: MLHook_Event_RaceStats_PlayerCP, MLHook_Event_RaceStats_PlayerLeft, MLHook_Event_RaceStats_PlayerRaceTimes
[   ScriptRuntime] [10:23:18] [MLFeedRaceData]  UnregisteredMLHook object for types: MLHook_Event_MLFeedKOs_PlayerStatus, MLHook_Event_MLFeedKOs_MatchKeyPair
[   ScriptRuntime] [10:23:18] [MLFeedRaceData]  UnregisteredMLHook object for types: TMxSM_Race_Record_NewRecord
[   ScriptRuntime] [10:23:18] [MLFeedRaceData]  UnregisteredMLHook object for types: MLHook_Event_GhostData
[   ScriptRuntime] [10:23:18] [PluginManager]  Plugin cache: Removed MLFeedRaceData
[   ScriptRuntime] [10:23:18] [PluginManager]  Installing plugin with site ID 255 and identifier "MLFeedRaceData"
[   ScriptRuntime] [10:23:18] [PluginManager]  Saved PluginCache.json
[    ScriptEngine] [10:23:20] [PluginManager]  Couldn't find required plugin dependency "MLFeedRaceData" while loading plugin "CotdBufferTime"
[    ScriptEngine] [10:23:20] [PluginManager]  Loaded zipped plugin 'CotdBufferTime' (version 2.1.12)
[    ScriptEngine] [10:23:20] [MLFeedRaceData]  HookGhostData.as (84, 5) : INFO : Compiling void DrawGhost(uint, const MLFeed::GhostInfo@)
[    ScriptEngine] [10:23:20] [MLFeedRaceData]  HookGhostData.as (99, 23) : WARN : Variable 'i' hides another variable of same name in outer scope
[    ScriptEngine] [10:23:20] [MLFeedRaceData]  RaceFeedDemoUI.as (6, 5) : INFO : Compiling void Render()
[    ScriptEngine] [10:23:20] [MLFeedRaceData]  RaceFeedDemoUI.as (58, 31) : WARN : Variable 'i' hides another variable of same name in outer scope
[    ScriptEngine] [10:23:20] [PluginManager]  Loaded zipped plugin 'MLFeedRaceData' (version 0.3.8)
[   ScriptRuntime] [10:23:20] [PluginManager]  Reloading dependent plugin 'CotdBufferTime'
[    ScriptEngine] [10:23:20] [PluginManager]  Loaded zipped plugin 'CotdBufferTime' (version 2.1.12)
[    ScriptEngine] [10:23:20] [PluginManager]  Loaded plugin 'better-splits-history-dev' (version 0.1.0)
[    ScriptEngine] [10:23:20] [PluginManager]  Loaded plugin 'players-pbs-dev' (version 0.1.9)
[    ScriptEngine] [10:23:21] [PluginManager]  Loaded plugin 'race-stats-dev' (version 0.1.0)
[    ScriptEngine] [10:23:21] [PluginManager]  Loaded plugin 'buffer-time-dev' (version 2.1.12)
[   ScriptRuntime] [10:23:21] [CotdBufferTime]  buffer time starting.
[   ScriptRuntime] [10:23:21] [players-pbs-dev]  MLFeed detected: true
[   ScriptRuntime] [10:23:21]  Plugin PluginManager just hung for 620.02 ms!
[   ScriptRuntime] [10:23:21] [MLFeedRaceData]  registered MLHook event for type: MLHook_Event_RaceStats_PlayerCP
[   ScriptRuntime] [10:23:21] [MLFeedRaceData]  registered MLHook event for type: MLHook_Event_RaceStats_PlayerLeft
[   ScriptRuntime] [10:23:21] [MLFeedRaceData]  registered MLHook event for type: MLHook_Event_RaceStats_PlayerRaceTimes
[   ScriptRuntime] [10:23:21] [MLFeedRaceData]  registered MLHook event for type: MLHook_Event_MLFeedKOs_PlayerStatus
[   ScriptRuntime] [10:23:21] [MLFeedRaceData]  registered MLHook event for type: MLHook_Event_MLFeedKOs_MatchKeyPair
[   ScriptRuntime] [10:23:21] [MLFeedRaceData]  registered MLHook event for type: TMxSM_Race_Record_NewRecord
[   ScriptRuntime] [10:23:21] [MLFeedRaceData]  registered MLHook event for type: MLHook_Event_GhostData

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants