Mctalian / RPGLootFeed

A non-intrusive way to see what you just looted.
MIT License
2 stars 2 forks source link

Latest version may be causing huge game pauses? #134

Closed arcadepro closed 1 month ago

arcadepro commented 2 months ago

I've just started using 1.7.2 on my alt (levelling 70-80) and occasionally, while looting, the whole wow.exe is stalling. i.e. the rarely seen 'this exe may have crashed' spinning cursor scenario kicks in. The game does recover but this has only occurred since updating to this new version. The loot messages are all collapsed on top of each other when the game recovers. I've reverted back to 1.6.2 to test.

Mctalian commented 2 months ago

Thanks for the heads up. I'll take a look at changes since 1.6.2 to see if anything jumps out as a potential cause for this.

If you experience it again, you can type /rlf log and it'll open a window and you can copy and paste some of the recent events over here that may help me narrow this down as well.

If it is RPGLootFeed, I'll get it fixed! Thanks for the report and for helping me track this down.

arcadepro commented 2 months ago

I'll play on 1.6.2 tomorrow performing the same tasks on my alt. The only change made will be the revert from 1.7.2 to 1.6.2. If no issues occur I'll re-try 1.7.2.

This may or may not help but the first pause occurred when my herbalist shaman looted Irradiated Mycobloom for the first time. Thus gaining knowledge points, XP and acuity simultaneously while getting an on screen blizzard pop up.

Mctalian commented 2 months ago

Just some extra questions I thought of:

This is happening when looting a corpse? (I'm assuming this is the case) If so:

If not:

I think /rlf log will help a ton when you encounter it again, but I'm still trying to think through some potential areas.

Also, since it's performance based (I think the above questions are more important, but just to cover our bases):

arcadepro commented 2 months ago
Mctalian commented 2 months ago

Thank you! I'll see if I can reproduce it on my end 🀞🏼

Mctalian commented 2 months ago

I logged on an alt last night on my steam deck and did some herbalism and a few world quests and didn't see anything (probably played for about an hour). I'll try on my laptop and PC throughout the week and keep an eye out for things.

I had lockups happening while developing other features and it was something with too many events at once so I added event bucketing and that cleared it up.

I wonder if it's happening when the rows are disappearing or when they are appearing πŸ€”

Hopefully I can see this on my side so I can figure it out. If not, I can try some things and send you some test packages to try later this week.

Karlo121 commented 2 months ago

My wow window stalls and freezes on Mac.

I get lua error

Message: ...ed/LootDisplay/LootDisplayFrame/LootDisplayFrame.lua:16: script ran too long

==== Addon Info RPGLootFeed v1.7.2-1-4f0c622 ====

Log traces related to Currency
-------------------------------------------------
[01:03:27]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 10) [3008]
[01:02:24]{I}(RLF)[CURR]: [Valorstones] x10 (tot: 10) [3008]
[01:02:24]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 10) [3008]
[00:51:15]{I}(RLF)[CURR]: [Valorstones] x30 (tot: 30 (diff: +10)) ~UPDATE~ [3008]
[00:51:15]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 10) [3008]
[00:46:19]{I}(RLF)[CURR]: [Valorstones] x20 (tot: 20 (diff: +10)) ~UPDATE~ [3008]
[00:46:19]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 10) [3008]
[00:46:10]{I}(RLF)[CURR]: [Valorstones] x10 (tot: 10) [3008]
[00:46:10]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 10) [3008]
[00:39:20]{D}(RLF)[CURR]: SKIP: Something was missing, don't display
-------------------------------------------------

Please report this issue @ github: McTalian/RPGLootFeed

Time: Wed Sep 25 01:03:46 2024
Count: 1
Stack: ...ed/LootDisplay/LootDisplayFrame/LootDisplayFrame.lua:16: script ran too long

==== Addon Info RPGLootFeed v1.7.2-1-4f0c622 ====

Log traces related to Currency
-------------------------------------------------
[01:03:27]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 10) [3008]
[01:02:24]{I}(RLF)[CURR]: [Valorstones] x10 (tot: 10) [3008]
[01:02:24]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 10) [3008]
[00:51:15]{I}(RLF)[CURR]: [Valorstones] x30 (tot: 30 (diff: +10)) ~UPDATE~ [3008]
[00:51:15]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 10) [3008]
[00:46:19]{I}(RLF)[CURR]: [Valorstones] x20 (tot: 20 (diff: +10)) ~UPDATE~ [3008]
[00:46:19]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 10) [3008]
[00:46:10]{I}(RLF)[CURR]: [Valorstones] x10 (tot: 10) [3008]
[00:46:10]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 10) [3008]
[00:39:20]{D}(RLF)[CURR]: SKIP: Something was missing, don't display
-------------------------------------------------

Please report this issue @ github: McTalian/RPGLootFeed
Mctalian commented 2 months ago

@Karlo121 thanks! I'll take a look in a bit and I'll try to double check it on a mac as well 🀞🏼

Mctalian commented 2 months ago

@arcadepro are you also playing on Mac by chance?

EDIT: nvm, looks like Windows based on the issue description

Mctalian commented 2 months ago

Ok, give this a shot: https://github.com/Mctalian/RPGLootFeed/actions/runs/11027541748/artifacts/1975324759

🀞🏼

Mctalian commented 2 months ago

I found a bug while I was looking into this, so I'm going to ship a fix to that as well as my attempt to fix the client hanging issues. Let me know if v1.7.3 works better for y'all!

arcadepro commented 2 months ago

Played for two days with 0 issues on 1.6.2. Will try 1.7.3.

arcadepro commented 2 months ago

Still has the bug. I killed and looted a mob. The only mob I'd killed since using the new version. I looted it immediately which triggered a long pause. (Top 6 lines of rlf log. The lines previous to this are all XP gains from exploration discovery)

Switched back to 1.6.2 killed some mobs. No issue.


==== Addon Info RPGLootFeed v1.7.3-1-b5abaae ====

Please report this issue @ github: McTalian/RPGLootFeed

[string "@RPGLootFeed/LootDisplay/LootDisplayFrame/LootDisplayFrame.lua"]:144: in function `GetRow'
[string "@RPGLootFeed/LootDisplay/LootDisplay.lua"]:98: in function <...rfaceRPGLootFeed/LootDisplay/LootDisplay.lua:81>
[string "@RPGLootFeed/LootDisplay/LootDisplay.lua"]:146: in function <...rfaceRPGLootFeed/LootDisplay/LootDisplay.lua:138>
[string "=[C]"]: ?
[string "@RPGLootFeed/Core.lua"]:19: in function `fn'
[string "@RPGLootFeed/LootDisplay/LootDisplay.lua"]:24: in function <...rfaceRPGLootFeed/LootDisplay/LootDisplay.lua:23>
[string "=[C]"]: ?
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:69: in function <...es_TheWarWithin/libs/AceBucket-3.0/AceBucket-3.0.lua:67>
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:85: in function `func'
[string "@Details/Libs/AceTimer-3.0-17/AceTimer-3.0.lua"]:57: in function <...ceDetails/Libs/AceTimer-3.0/AceTimer-3.0.lua:50>

Locals:
self = LootDisplayFrame {
 ArrowUp = Texture {
 }
 InstructionText = FontString {
 }
 BoundingBox = Texture {
 }
 ArrowRight = Texture {
 }
 arrows = <table> {
 }
 ArrowLeft = Texture {
 }
 ArrowDown = Texture {
 }
}
key = "102542"
(for state) = <table> {
 length = 1
 last = Frame {
 }
 first = Frame {
 }
}
(for control) = Frame {
 RightBorder = LootDisplayFrameRightBorder {
 }
 _prev = Frame {
 }
 _next = Frame {
 }
 key = "EXPERIENCE"
 amount = 548
 Background = Texture {
 }
 Icon = Button {
 }
 TopBorder = LootDisplayFrameTopBorder {
 }
 BottomBorder = LootDisplayFrameBottomBorder {
 }
 LeftBorder = LootDisplayFrameLeftBorder {
 }
 HighlightAnimation = <table> {
 }
 AmountText = FontString {
 }
 FadeOutAnimation = AnimationGroup {
 }
}
row = Frame {
 RightBorder = LootDisplayFrameRightBorder {
 }
 _prev = Frame {
 }
 _next = Frame {
 }
 key = "EXPERIENCE"
 amount = 548
 Background = Texture {
 }
 Icon = Button {
 }
 TopBorder = LootDisplayFrameTopBorder {
 }
 BottomBorder = LootDisplayFrameBottomBorder {
 }
 LeftBorder = LootDisplayFrameLeftBorder {
 }
 HighlightAnimation = <table> {
 }
 AmountText = FontString {
 }
 FadeOutAnimation = AnimationGroup {
 }
}
(*temporary) = <table> {
 length = 1
 last = Frame {
 }
 first = Frame {
 }
}
(*temporary) = Frame {
 RightBorder = LootDisplayFrameRightBorder {
 }
 _prev = Frame {
 }
 _next = Frame {
 }
 key = "EXPERIENCE"
 amount = 548
 Background = Texture {
 }
 Icon = Button {
 }
 TopBorder = LootDisplayFrameTopBorder {
 }
 BottomBorder = LootDisplayFrameBottomBorder {
 }
 LeftBorder = LootDisplayFrameLeftBorder {
 }
 HighlightAnimation = <table> {
 }
 AmountText = FontString {
 }
 FadeOutAnimation = AnimationGroup {
 }
}
(*temporary) = "script ran too long"
rows = <table> {
 length = 1
 last = Frame {
 }
 first = Frame {
 }
}
[string "@RPGLootFeed/Core.lua"]:19: in function `fn'
[string "@RPGLootFeed/LootDisplay/LootDisplay.lua"]:24: in function <...rfaceRPGLootFeed/LootDisplay/LootDisplay.lua:23>
[string "=[C]"]: ?
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:69: in function <...es_TheWarWithin/libs/AceBucket-3.0/AceBucket-3.0.lua:67>
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:85: in function `func'
[string "@Details/Libs/AceTimer-3.0-17/AceTimer-3.0.lua"]:57: in function <...ceDetails/Libs/AceTimer-3.0/AceTimer-3.0.lua:50>

Locals:
self = <table> {
 defaults = <table> {
 }
 addonVersion = "v1.7.3-1-b5abaae"
 LootDisplay = <table> {
 }
 DisableBossBanner = <table> {
 }
 L = <table> {
 }
 options = <table> {
 }
 TestMode = <table> {
 }
 addonName = "RPGLootFeed"
 localeName = "RPGLootFeedLocale"
 list = <table> {
 }
 db = <table> {
 }
 dbName = "RPGLootFeedDB"
 RLF = <table> {
 }
}
(*temporary) = false
(*temporary) = nil
(*temporary) = "script ran too long"
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:69: in function <...es_TheWarWithin/libs/AceBucket-3.0/AceBucket-3.0.lua:67>
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:85: in function `func'
[string "@Details/Libs/AceTimer-3.0-17/AceTimer-3.0.lua"]:57: in function <...ceDetails/Libs/AceTimer-3.0/AceTimer-3.0.lua:50>

Locals:
(*temporary) = false
(*temporary) = nil
(*temporary) = "script ran too long"

rlf log: https://pastebin.com/njyNJLhJ

Mctalian commented 2 months ago

That's helpful thanks! I'll dig into this and see if I can figure out what's going on.

Mctalian commented 2 months ago

@arcadepro I have some ideas on how to optimize this. It's gonna take a bit of time but hopefully I can get you a test build later today

Mctalian commented 2 months ago

Ok try this one 🀞🏼 https://github.com/Mctalian/RPGLootFeed/actions/runs/11077492320/artifacts/1989332803

Mctalian commented 2 months ago

I released v1.7.4 - I'm hopeful that it will help

arcadepro commented 2 months ago

Tested it. Was looking fine until I made a herbing 'new herb' discovery. ('You have made a new discovery: Crystallized Luredrop'). I also gained experience from this and [Khaz Algar Herbalism Knowledge] x1

This is exactly the same 'herb discovery' event that triggered the first occurance of this bug.

To me, as a user, the only change from these versions versus 1.6.2 is that you're now displaying the 'quality' texture of items on the icons as well as in the text link. I don't know if it's related. I do also have the display row timer set to 30s if that is of any help.

[string "@Blizzard_SharedXML/Color.lua"]:44: in function `SetRGBA'
[string "@Blizzard_SharedXML/Color.lua"]:10: in function `OnLoad'
[string "@Blizzard_SharedXML/Color.lua"]:5: in function `CreateColor'
[string "@RPGLootFeed/LootDisplay/LootDisplayFrame/LootDisplayRow/LootDisplayRow.lua"]:10: in function <...y/LootDisplayFrame/LootDisplayRow/LootDisplayRow.lua:9>
[string "@RPGLootFeed/LootDisplay/LootDisplayFrame/LootDisplayRow/LootDisplayRow.lua"]:160: in function <...y/LootDisplayFrame/LootDisplayRow/LootDisplayRow.lua:158>
[string "@RPGLootFeed/LootDisplay/LootDisplayFrame/LootDisplayRow/LootDisplayRow.lua"]:193: in function `UpdateStyles'
[string "@RPGLootFeed/LootDisplay/LootDisplayFrame/LootDisplayFrame.lua"]:201: in function `UpdateRowPositions'
[string "@RPGLootFeed/LootDisplay/LootDisplay.lua"]:27: in function <...rfaceRPGLootFeed/LootDisplay/LootDisplay.lua:26>
[string "=[C]"]: ?
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:69: in function <...es_TheWarWithin/libs/AceBucket-3.0/AceBucket-3.0.lua:67>
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:85: in function `func'
[string "@Details/Libs/AceTimer-3.0-17/AceTimer-3.0.lua"]:57: in function <...ceDetails/Libs/AceTimer-3.0/AceTimer-3.0.lua:50>

Locals:
(*temporary) = <table> {
 a = 0.800000
 b = 0.100000
 g = 0.100000
 r = 0.100000
}
(*temporary) = 0.100000
(*temporary) = 0.100000
(*temporary) = 0.100000
(*temporary) = 0.800000
(*temporary) = 0.800000
(*temporary) = "script ran too long"
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:69: in function <...es_TheWarWithin/libs/AceBucket-3.0/AceBucket-3.0.lua:67>
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:85: in function `func'
[string "@Details/Libs/AceTimer-3.0-17/AceTimer-3.0.lua"]:57: in function <...ceDetails/Libs/AceTimer-3.0/AceTimer-3.0.lua:50>

Locals:
(*temporary) = false
(*temporary) = nil
(*temporary) = "script ran too long"

rlf log: https://pastebin.com/zmhd8UGS

Mctalian commented 2 months ago

@arcadepro Thank you. This is certainly a head scratcher. I really appreciate your patience with this and thank you immensely for working with me on this.

Behind the scenes, the change was a refactor from a single, large file that handled all the Loot Display stuff into 3 different files. So it was a large enough change that it's difficult to just revert the pieces that seem to be impacted, though I've considered it.

Looking at your stack trace, it seems I was on the right track, though, as UpdateRowPositions seems to be part of this issue.

One interesting thing about the rlf log is that right before it happens, it's processing 3 elements to add to the feed. Most of the logs show 1 or 2. I know when I'm paying on my main, I open chests that contain 3-5 items, and at the end of a Bountiful Delve, I easily have close to 10 rows showing. πŸ€”

If you can add in WOWEVENTS to the rlf logs (source drop down in the upper left), that may help me narrow down the scenario in terms of what's happening from the WOW side. Mostly just the top 20 or so lines closest to the issue. It looks like you've already got Debug events in there so that's good. If it's too much trouble, no worries. You've already done so much to help πŸ’š

Overall I have a few things I can try. But a few more questions pop up that may help me figure this out.

Question 1: Do you use Masque?

Are you using Masque by chance? In 1.6.2 the icons were just textures if you weren't using Masque, and if you were using Masque, it was a button that could be skinned/themed/whatever. So that could be the difference that you're referring to (if you're not using Masque). I'll try turning off Masque and trying out

Question 2: How many rows are in the feed when this happens?

You mention you have the fade delay to 30 seconds... How many rows would you say are on the screen when this happens?

Question 3: Is it more prevalent after you're playing for a while?

Would you say this happens after you're playing for a while? Timestamps it looks like you were playing for over an hour before this happened, almost 2.

Question 4: Do you feel like 1.7.4 is performing better than earlier 1.7.x versions?

I'm wondering if I'm on the right track/making improvements. If it feels like it's getting better, then I think I'm getting closer. If it feels mostly the same, I will probably need to look elsewhere.

arcadepro commented 2 months ago

1 - No. 2 - Not many 4 or so. 3 - No. 4 - Performs the same until the pause kicks in.

Just happened again. Looted a Delve chest. Different character.

[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:69: in function <...es_TheWarWithin/libs/AceBucket-3.0/AceBucket-3.0.lua:67>
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:85: in function `func'
[string "@Details/Libs/AceTimer-3.0-17/AceTimer-3.0.lua"]:57: in function <...ceDetails/Libs/AceTimer-3.0/AceTimer-3.0.lua:50>

Locals:
(*temporary) = false
(*temporary) = nil
(*temporary) = "script ran too long"
[string "@Blizzard_SharedXMLBase/Mixin.lua"]:21: in function `CreateFromMixins'
[string "@Blizzard_SharedXML/Color.lua"]:4: in function `CreateColor'
[string "@RPGLootFeed/LootDisplay/LootDisplayFrame/LootDisplayRow/LootDisplayRow.lua"]:11: in function <...y/LootDisplayFrame/LootDisplayRow/LootDisplayRow.lua:9>
[string "@RPGLootFeed/LootDisplay/LootDisplayFrame/LootDisplayRow/LootDisplayRow.lua"]:160: in function <...y/LootDisplayFrame/LootDisplayRow/LootDisplayRow.lua:158>
[string "@RPGLootFeed/LootDisplay/LootDisplayFrame/LootDisplayRow/LootDisplayRow.lua"]:193: in function `UpdateStyles'
[string "@RPGLootFeed/LootDisplay/LootDisplayFrame/LootDisplayFrame.lua"]:201: in function `UpdateRowPositions'
[string "@RPGLootFeed/LootDisplay/LootDisplay.lua"]:27: in function <...rfaceRPGLootFeed/LootDisplay/LootDisplay.lua:26>
[string "=[C]"]: ?
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:69: in function <...es_TheWarWithin/libs/AceBucket-3.0/AceBucket-3.0.lua:67>
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:85: in function `func'
[string "@HandyNotes_TheWarWithin/libs/AceTimer-3.0-17/AceTimer-3.0.lua"]:57: in function <...otes_TheWarWithin/libs/AceTimer-3.0/AceTimer-3.0.lua:50>

Locals:
(*temporary) = <table> {
}
(*temporary) = <table> {
}
(*temporary) = "script ran too long"
[14:19:25]{I}(RLF)[REPU]: +1250 Hallowfall Arathi (tot: 1250) [REP_Hallowfall Arathi]
[14:19:25]{I}(RLF)[ITEM]: [Abyssal Trap] x1 (tot: 1) [215170]
[14:19:25]{I}(RLF)[ITEM]: [Brute Force Idol] x1 (tot: 1) [225897]
[14:19:25]{I}(RLF)[CURR]: [Torchbearer's Greatcloak] x96 (tot: 96 (diff: +95)) ~UPDATE~ [2803]
[14:19:25]{I}(RLF)[CURR]: [Resonance Crystals] x100 (tot: 100) [2815]
[14:19:25]{D}(RLF): Processing 6 items from element queue
[14:19:25]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Radiant Echo]
[14:19:25]{I}(WOW)[REPU]: CHAT_MSG_COMBAT_FACTION_CHANGE Your Warband's reputation with Hallowfall Arathi increased by 1250.
[14:19:25]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Abyssal Trap]
[14:19:25]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Brute Force Idol]
[14:19:25]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 95) [2803]
[14:19:25]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 100) [2815]
[14:19:24]{D}(RLF)[CURR]: SKIP: Something was missing, don't display (tot: -1) [3028]
[14:19:24]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: -1) [3028]
[14:19:19]{I}(RLF)[CURR]: [Valorstones] x25 (tot: 25) [3008]
[14:19:19]{D}(RLF): Processing 1 items from element queue
[14:19:19]{D}(WOW)[ITEM]: Flaski receives loot: [Cave Topographer's Leggings].
[14:19:19]{I}(WOW)[ITEM]: CHAT_MSG_LOOT Flaski receives loot: [Cave Topographer's Leggings].
[14:19:19]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 25) [3008]
[14:19:19]{D}(RLF)[ITEM]: Peeled Fungal Scale ignored by quality: Poor
[14:19:19]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Peeled Fungal Scale]
[14:19:19]{D}(WOW)[ITEM]: Flaski receives loot: [Radiant Echo].
[14:19:19]{I}(WOW)[ITEM]: CHAT_MSG_LOOT Flaski receives loot: [Radiant Echo].
[14:19:16]{D}(WOW)[ITEM]: Flaski receives loot: [Rattling Bag o' Gold].
[14:19:16]{I}(WOW)[ITEM]: CHAT_MSG_LOOT Flaski receives loot: [Rattling Bag o' Gold].
[14:19:16]{D}(WOW)[ITEM]: Flaski receives loot: [Adventures of Libarbie and Lichen].
[14:19:16]{I}(WOW)[ITEM]: CHAT_MSG_LOOT Flaski receives loot: [Adventures of Libarbie and Lichen].
[14:19:16]{D}(WOW)[ITEM]: Flaski receives loot: [Titan Disc Fragment]x35.
[14:19:16]{I}(WOW)[ITEM]: CHAT_MSG_LOOT Flaski receives loot: [Titan Disc Fragment]x35.
[14:18:57]{I}(RLF)[ITEM]: [Torchbearer's Greatcloak] x1 (tot: 1) [211007]
[14:18:57]{I}(RLF)[CURR]: [Runed Harbinger Crest] x2 (tot: 2) [2916]
[14:18:57]{I}(RLF)[CURR]: [Undercoin] x79 (tot: 79) [2803]
[14:18:57]{D}(RLF): Processing 3 items from element queue
[14:18:57]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Torchbearer's Greatcloak]
[14:18:57]{D}(RLF)[ITEM]: Technique: Patient Alchemist's Mixing Rod ignored by quality: Common
[14:18:57]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Technique: Patient Alchemist's Mixing Rod]
[14:18:56]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 2) [2916]
[14:18:56]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 79) [2803]
[14:18:52]{I}(RLF)[GOLD]: 48 68 18 (tot: 486818 (diff: +70710)) ~UPDATE~ [MONEY_LOOT]
[14:18:52]{D}(RLF): Processing 1 items from element queue
[14:18:52]{I}(WOW)[GOLD]: PLAYER_MONEY
[14:18:51]{I}(RLF)[GOLD]: 41 61 8 (tot: 416108 (diff: +66290)) ~UPDATE~ [MONEY_LOOT]
[14:18:51]{D}(RLF): Processing 1 items from element queue
[14:18:51]{I}(WOW)[GOLD]: PLAYER_MONEY
[14:18:51]{I}(RLF)[GOLD]: 34 98 18 (tot: 349818 (diff: +67964)) ~UPDATE~ [MONEY_LOOT]
[14:18:51]{D}(RLF): Processing 1 items from element queue
[14:18:50]{I}(WOW)[GOLD]: PLAYER_MONEY
[14:18:49]{I}(RLF)[GOLD]: 28 18 54 (tot: 281854 (diff: +68538)) ~UPDATE~ [MONEY_LOOT]
[14:18:49]{D}(RLF): Processing 1 items from element queue
[14:18:49]{I}(WOW)[GOLD]: PLAYER_MONEY
[14:18:49]{I}(RLF)[GOLD]: 21 33 16 (tot: 213316 (diff: +71521)) ~UPDATE~ [MONEY_LOOT]
[14:18:49]{D}(RLF): Processing 1 items from element queue
[14:18:49]{I}(WOW)[GOLD]: PLAYER_MONEY
[14:18:49]{I}(RLF)[GOLD]: 14 17 95 (tot: 141795) [MONEY_LOOT]
[14:18:49]{D}(RLF): Processing 1 items from element queue
[14:18:48]{I}(WOW)[GOLD]: PLAYER_MONEY
[14:18:32]{D}(RLF)[CURR]: SKIP: This is a known hidden currencyType (tot: 3) [3104]
[14:18:32]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 3) [3104]
[14:18:32]{D}(RLF)[CURR]: SKIP: Something was missing, don't display (tot: -3) [3104]
[14:18:32]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: -3) [3104]
[14:18:32]{E}(RLF)[REPU]: Could not determine faction and/or rep change from message
[14:18:32]{I}(WOW)[REPU]: CHAT_MSG_COMBAT_FACTION_CHANGE Brann Bronzebeard has gained 45000 experience.
arcadepro commented 2 months ago

Looting [Sureki Intelligence] for a WQ/Rumor quest. I wonder if it's reputation gains?

[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:69: in function <...es_TheWarWithin/libs/AceBucket-3.0/AceBucket-3.0.lua:67>
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:85: in function `func'
[string "@Details/Libs/AceTimer-3.0-17/AceTimer-3.0.lua"]:57: in function <...ceDetails/Libs/AceTimer-3.0/AceTimer-3.0.lua:50>

Locals:
(*temporary) = false
(*temporary) = nil
(*temporary) = "script ran too long"
[string "@RPGLootFeed/LootDisplay/LootDisplayFrame/LootDisplayRow/LootDisplayRow.lua"]:153: in function <...y/LootDisplayFrame/LootDisplayRow/LootDisplayRow.lua:141>
[string "@RPGLootFeed/LootDisplay/LootDisplayFrame/LootDisplayRow/LootDisplayRow.lua"]:164: in function <...y/LootDisplayFrame/LootDisplayRow/LootDisplayRow.lua:158>
[string "@RPGLootFeed/LootDisplay/LootDisplayFrame/LootDisplayRow/LootDisplayRow.lua"]:193: in function `UpdateStyles'
[string "@RPGLootFeed/LootDisplay/LootDisplayFrame/LootDisplayFrame.lua"]:201: in function `UpdateRowPositions'
[string "@RPGLootFeed/LootDisplay/LootDisplay.lua"]:27: in function <...rfaceRPGLootFeed/LootDisplay/LootDisplay.lua:26>
[string "=[C]"]: ?
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:69: in function <...es_TheWarWithin/libs/AceBucket-3.0/AceBucket-3.0.lua:67>
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:85: in function `func'
[string "@HandyNotes_TheWarWithin/libs/AceTimer-3.0-17/AceTimer-3.0.lua"]:57: in function <...otes_TheWarWithin/libs/AceTimer-3.0/AceTimer-3.0.lua:50>

Locals:
row = Frame {
 RightBorder = LootDisplayFrameRightBorder {
 }
 LeftBorder = LootDisplayFrameLeftBorder {
 }
 _next = Frame {
 }
 _prev = Frame {
 }
 amount = 17
 Background = Texture {
 }
 Icon = Button {
 }
 TopBorder = LootDisplayFrameTopBorder {
 }
 key = "REP_The General"
 BottomBorder = LootDisplayFrameBottomBorder {
 }
 HighlightAnimation = <table> {
 }
 AmountText = FontString {
 }
 FadeOutAnimation = AnimationGroup {
 }
}
(*temporary) = Alpha {
}
(*temporary) = "OnFinished"
(*temporary) = "script ran too long"
[16:58:59]{D}(RLF): Processing 1 items from element queue
[16:58:59]{I}(WOW)[GOLD]: PLAYER_MONEY
[16:58:59]{D}(RLF)[ITEM]: Sureki Intelligence ignored by quality: Common
[16:58:59]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Sureki Intelligence]x2
[16:58:34]{I}(RLF)[REPU]: +17 The Weaver (tot: 17) [REP_The Weaver]
[16:58:34]{I}(RLF)[REPU]: +17 The Vizier (tot: 17) [REP_The Vizier]
[16:58:34]{D}(RLF): Processing 2 items from element queue
[16:58:34]{I}(WOW)[REPU]: CHAT_MSG_COMBAT_FACTION_CHANGE Your Warband's reputation with The Weaver increased by 17.
[16:58:34]{I}(WOW)[REPU]: CHAT_MSG_COMBAT_FACTION_CHANGE Your Warband's reputation with The Vizier increased by 17.
[16:58:34]{I}(RLF)[REPU]: +17 The General (tot: 17) [REP_The General]
[16:58:34]{I}(RLF)[CURR]: [Weathered Harbinger Crest] x2 (tot: 2) [2914]
[16:58:34]{I}(RLF)[CURR]: [Kej] x48 (tot: 48 (diff: +43)) ~UPDATE~ [3008]
[16:58:34]{D}(RLF): Processing 3 items from element queue
[16:58:34]{I}(WOW)[REPU]: CHAT_MSG_COMBAT_FACTION_CHANGE Your Warband's reputation with The General increased by 17.
[16:58:34]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 2) [2914]
[16:58:34]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 43) [3008]
[16:56:57]{I}(RLF)[CURR]: [Kej] x5 (tot: 5 (diff: +1)) ~UPDATE~ [3008]
[16:56:57]{I}(RLF)[CURR]: [Kej] x4 (tot: 4) [3056]
[16:56:57]{D}(RLF): Processing 2 items from element queue
[16:56:57]{D}(RLF)[ITEM]: Crystalline Sturgeon ignored by quality: Common
[16:56:57]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Crystalline Sturgeon]x4
[16:56:56]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 1) [3008]
[16:56:56]{I}(WOW)[CURR]: CURRENCY_DISPLAY_UPDATE (tot: 4) [3056]
[16:56:56]{D}(RLF)[ITEM]: Jar of Pickled Insects ignored by quality: Poor
[16:56:56]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Jar of Pickled Insects]
[16:55:59]{D}(RLF)[ITEM]: Bismuth ignored by quality: Common
[16:55:59]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Bismuth |A:Professions-ChatIcon-Quality-Tier2:17:23::1|a]x3
[16:55:59]{D}(RLF)[ITEM]: Bismuth ignored by quality: Common
[16:55:59]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Bismuth |A:Professions-ChatIcon-Quality-Tier3:17:18::1|a]x2
[16:55:45]{D}(RLF)[ITEM]: Bismuth ignored by quality: Common
[16:55:45]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Bismuth |A:Professions-ChatIcon-Quality-Tier2:17:23::1|a]x2
[16:55:26]{D}(RLF)[ITEM]: Bismuth ignored by quality: Common
[16:55:26]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Bismuth |A:Professions-ChatIcon-Quality-Tier2:17:23::1|a]x3
[16:55:04]{D}(RLF)[ITEM]: Bismuth ignored by quality: Common
[16:55:04]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Bismuth |A:Professions-ChatIcon-Quality-Tier2:17:23::1|a]x3
[16:54:16]{I}(RLF)[CURR]: [Weathered Harbinger Crest] x7 (tot: 7 (diff: +5)) ~UPDATE~ [3008]
[16:54:16]{I}(RLF)[CURR]: [Kej] x50 (tot: 50) [3056]
Mctalian commented 2 months ago

Thank you for all the new info!

Yeah it looks like you're filtering out commons so no items should've gotten through. Only money and rep πŸ€”πŸ€”

You could try to turn off all feed features except for money, rep, etc. and see if you can isolate it.

Seeing the code in the stack, I think it's something shared by all of them so I think you'll see it no matter what you have enabled. Except for maybe money and XP since you can only have one row of those each.

All of your recent traces show update styles, so that's where I'll look next.

My original thought that it could be related to Masque (or not having it, really) seems to be out the window since your most recent message looks like it was just money and rep.

What kind of CPU do you have? I'm thinking I just need to focus really heavily on more efficient algorithms, but if you've got a beefy CPU, then efficiency may not help here. Such a tough one, I wish I could encounter it on my own machines, I'm confident I'd be able to fix it if I could see it 😞

arcadepro commented 2 months ago

The CPU is pretty old but I can't see how it's really CPU related when nothing is going on other than looting an item. Something in the code is going into some crazy loop perhaps? I'm tabbed out from a hang just now after having disabled Reputation and it managed to crash World of Warcraft.

Mctalian commented 2 months ago

I think an older CPU will just amplify inefficient logic. Especially when WoW puts a limit in how long a script can run, and I think it's actually time-based, it certainly makes sense that I'm not seeing it. I think I have an i9 that's like 4 years old, so nothing top of the line, but it must be chugging through the loops faster. Either way, I think this narrows it down for me. I'll keep moving forward!

Mctalian commented 2 months ago

@arcadepro ok, I'm feeling more confident about this one: https://github.com/Mctalian/RPGLootFeed/actions/runs/11085774605/artifacts/1991017835

Let me know if you see improvements and I'll tag it and release it 🀞🏼🀞🏼 if you're busy/I don't hear from you, I may tag and release in a few hours.

arcadepro commented 2 months ago

Nope. Still has the bug. Took a little longer to manifest. Shortly before the error the rows had stopped moving correctly and were overlapping each other. ie everything was appearing on one row.

[19:56:38]{I}(RLF)[ITEM]: [Imperfect Null Stone] x1 (tot: 1) [217707]
[19:56:38]{D}(RLF): Processing 2 items from element queue
[19:56:37]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Aqirite |A:Professions-ChatIcon-Quality-Tier1:17:15::1|a]
[19:56:37]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Imperfect Null Stone]
[19:56:16]{I}(RLF)[ITEM]: [Bismuth |A:Professions-ChatIcon-Quality-Tier1:17:15::1|a] x2 (tot: 2) [210930]
[19:56:16]{D}(RLF): Processing 1 items from element queue
[19:56:16]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive loot: [Bismuth |A:Professions-ChatIcon-Quality-Tier1:17:15::1|a]x2
[19:55:26]{I}(RLF)[ITEM]: [Bismuth |A:Professions-ChatIcon-Quality-Tier3:17:18::1|a] x3 (tot: 3) [210932]
[19:55:26]{D}(RLF): Processing 1 items from element queue
[19:55:25]{I}(WOW)[ITEM]: CHAT_MSG_LOOT You receive item: [Bismuth |A:Professions-ChatIcon-Quality-Tier3:17:18::1|a]x3
[19:55:17]{I}(RLF)[GOLD]: 5 48 31 (tot: 54831 (diff: +20385)) ~UPDATE~ [MONEY_LOOT]
[19:55:17]{D}(RLF): Processing 1 items from element queue
[19:55:17]{I}(WOW)[GOLD]: PLAYER_MONEY
[19:55:17]{I}(RLF)[GOLD]: 3 44 46 (tot: 34446 (diff: +7025)) ~UPDATE~ [MONEY_LOOT]
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:69: in function <...es_TheWarWithin/libs/AceBucket-3.0/AceBucket-3.0.lua:67>
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:85: in function `func'
[string "@HandyNotes_TheWarWithin/libs/AceTimer-3.0-17/AceTimer-3.0.lua"]:57: in function <...otes_TheWarWithin/libs/AceTimer-3.0/AceTimer-3.0.lua:50>

Locals:
(*temporary) = false
(*temporary) = nil
(*temporary) = "script ran too long"
[string "@RPGLootFeed/LootDisplay/LootDisplayFrame/LootDisplayFrame.lua"]:194: in function `UpdateRowPositions'
[string "@RPGLootFeed/LootDisplay/LootDisplay.lua"]:27: in function <...rfaceRPGLootFeed/LootDisplay/LootDisplay.lua:26>
[string "=[C]"]: ?
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:69: in function <...es_TheWarWithin/libs/AceBucket-3.0/AceBucket-3.0.lua:67>
[string "@HandyNotes_TheWarWithin/libs/AceBucket-3.0-4/AceBucket-3.0.lua"]:85: in function `func'
[string "@HandyNotes_TheWarWithin/libs/AceTimer-3.0-17/AceTimer-3.0.lua"]:57: in function <...otes_TheWarWithin/libs/AceTimer-3.0/AceTimer-3.0.lua:50>

Locals:
self = LootDisplayFrame {
 ArrowUp = Texture {
 }
 InstructionText = FontString {
 }
 BoundingBox = Texture {
 }
 ArrowRight = Texture {
 }
 arrows = <table> {
 }
 ArrowLeft = Texture {
 }
 ArrowDown = Texture {
 }
}
index = 5478495
(for state) = <table> {
 length = 2
 last = Frame {
 }
 first = Frame {
 }
}
(for control) = Frame {
 RightBorder = LootDisplayFrameRightBorder {
 }
 LeftBorder = LootDisplayFrameLeftBorder {
 }
 _prev = Frame {
 }
 _next = Frame {
 }
 key = "210933"
 amount = 1
 Background = Texture {
 }
 icon = 5704419
 TopBorder = LootDisplayFrameTopBorder {
 }
 link = "|cff1eff00|Hitem:210933::::::::80:73::::1:38:1:::::|h[Aqirite |A:Professions-ChatIcon-Quality-Tier1:17:15::1|a]|h|r"
 BottomBorder = LootDisplayFrameBottomBorder {
 }
 Icon = Button {
 }
 HighlightAnimation = <table> {
 }
 AmountText = FontString {
 }
 FadeOutAnimation = AnimationGroup {
 }
}
row = Frame {
 RightBorder = LootDisplayFrameRightBorder {
 }
 LeftBorder = LootDisplayFrameLeftBorder {
 }
 _prev = Frame {
 }
 _next = Frame {
 }
 key = "210933"
 amount = 1
 Background = Texture {
 }
 icon = 5704419
 TopBorder = LootDisplayFrameTopBorder {
 }
 link = "|cff1eff00|Hitem:210933::::::::80:73::::1:38:1:::::|h[Aqirite |A:Professions-ChatIcon-Quality-Tier1:17:15::1|a]|h|r"
 BottomBorder = LootDisplayFrameBottomBorder {
 }
 Icon = Button {
 }
 HighlightAnimation = <table> {
 }
 AmountText = FontString {
 }
 FadeOutAnimation = AnimationGroup {
 }
}
vertDir = "BOTTOM"
yOffset = 131483880
(*temporary) = <table> {
 defaults = <table> {
 }
 callbacks = <table> {
 }
 keys = <table> {
 }
 global = <table> {
 }
 sv = <table> {
 }
}
(*temporary) = Frame {
 RightBorder = LootDisplayFrameRightBorder {
 }
 LeftBorder = LootDisplayFrameLeftBorder {
 }
 _prev = Frame {
 }
 _next = Frame {
 }
 key = "210933"
 amount = 1
 Background = Texture {
 }
 icon = 5704419
 TopBorder = LootDisplayFrameTopBorder {
 }
 link = "|cff1eff00|Hitem:210933::::::::80:73::::1:38:1:::::|h[Aqirite |A:Professions-ChatIcon-Quality-Tier1:17:15::1|a]|h|r"
 BottomBorder = LootDisplayFrameBottomBorder {
 }
 Icon = Button {
 }
 HighlightAnimation = <table> {
 }
 AmountText = FontString {
 }
 FadeOutAnimation = AnimationGroup {
 }
}
(*temporary) = true
(*temporary) = LootDisplayFrame {
 ArrowUp = Texture {
 }
 InstructionText = FontString {
 }
 BoundingBox = Texture {
 }
 ArrowRight = Texture {
 }
 arrows = <table> {
 }
 ArrowLeft = Texture {
 }
 ArrowDown = Texture {
 }
}
(*temporary) = "BOTTOM"
(*temporary) = 0
(*temporary) = 131483856
(*temporary) = "script ran too long"
rows = <table> {
 length = 2
 last = Frame {
 }
 first = Frame {
 }
}
Mctalian commented 2 months ago

Damn!... Ok. I'll go back to the drawing board.

Mctalian commented 2 months ago

Ok, try this one: https://github.com/Mctalian/RPGLootFeed/actions/runs/11085774605/artifacts/1991017835

Mctalian commented 2 months ago

Actually, I think I figured it out. The one above will probably appear to work, but another bug is likely to pop up at some point.

If my theory is correct, this test package will throw one of two errors:

I believe that because I changed the process for releasing a row back to the pool in v1.7.0 to a message-based approach, that the order in which rows are getting removed from the list is indeterminate and it's possible that it is creating a circular reference in the list.

So I'm thinking the second error will pop up and the first will not.

If I am correct, then this test package is going to fix it.

If the push a row error pops up, then I'll have to look one more time and see what the issue is there, but the other error is the path that makes the most sense to me given the changes from v1.6.2 to v1.7.0

Mctalian commented 2 months ago

A few more improvements for performance: https://github.com/Mctalian/RPGLootFeed/actions/runs/11095370928/artifacts/1992850483

I'm going to play a bit with this build before I tag and release. The only thing I noticed is sometimes a row would just get "stuck" - I noticed it in other builds too but it happens so rarely that I didn't look into it until now. I put some code in that should handle that, but I would like to see that work before I release it.

Hopefully this new build does not have the same bug

arcadepro commented 2 months ago

I've been using https://github.com/Mctalian/RPGLootFeed/actions/runs/11090073058/artifacts/1991841523 and while there has been some glitchy row collapsing, and some weirdness because of the test functions it hasn't crashed yet.

I'll try the newer one.

Mctalian commented 2 months ago

Nice! I think v1.7.5 should work really well for you 🀞🀞

It's much more refined than the test builds. I think I finally got to the bottom of this. Thanks for all the support and patience!

Mctalian commented 1 month ago

@Karlo121 and @arcadepro let me know how things are going after you've been able to try out v1.7.5 for a few days! I want to make sure you both are having smooth experiences once again 😊

Karlo121 commented 1 month ago

@Mctalian Hello, I haven't had any freezes since the 1.7.5 update so far but I did notice that there seems to be an issue either with cutscenes or another addon called Dialogue UI, basically one of these two tends to scale up the loot text to a higher font size and it stays there on the screen until a UI refresh, nothing game breaking but weird nontheless. I'll take a picture of it next time it happens. Otherwise everything seems to be working so far and if I experience a freeze i'll let you know.

Mctalian commented 1 month ago

Thanks @Karlo121 ! We're looking at the stuck rows in #147

Good to know about Dialogue UI as a possibility on the text getting scaled. I'll keep that in mind

Mctalian commented 1 month ago

I think the freezes are solved and the stuck rows should be resolved in v1.7.6 which I'm about to release. If any issue still remains, we can open this one back up or create a new one. Thanks again for the help and support!