This site works best with JavaScript enabled. Please enable JavaScript to get the best experience from this site.
Version: r688-release-2
I've been trying to optimize my game and look at any performance issues with my addons, and I noticed if I enabled CPU profiling quick enough Rarity would shoot up to about 400ms. It freezes my game for about an entire second and has been doing this for months now but I assumed it was my computer. The line that appears after the freeze stops is the one saying Tooltip rendering took 843ms. Disabling the tooltip options doesn't do anything.
Rarity: Scanning archaeology projects (RESEARCH_ARTIFACT_HISTORY_READY) Rarity: Loading 838 item(s) from server... Rarity: Scanning instance locks (DELAYED INIT) Rarity: Building initial statistics table Rarity: BuildStatistics: 0.307200ms Rarity: BuildStatistics: 0.372300ms Rarity: ScanStatistics: 2.496500ms Rarity: Scanning calendar (DELAYED INIT) Rarity: Scanning toys (DELAYED INIT) Rarity: Scanning transmog (DELAYED INIT) Rarity: Currency updated (DELAYED INIT) Rarity: BAG_UPDATE Rarity: Scanning instance locks (DELAYED INIT 2) Rarity: Initialization failed to retrieve 742 item(s) Rarity: UpdateText: 0.140500ms Rarity: BuildStatistics: 0.501400ms Rarity: ScanStatistics: 4.200400ms Rarity: Scanning calendar (DELAYED INIT) Rarity: Scanning toys (DELAYED INIT) Rarity: Scanning transmog (DELAYED INIT) Rarity: UpdateText: 0.055500ms Rarity: Tooltip rendering took 843.814100ms (90.364700, 257.283300, 99.089000, 0.010900, 78.904000, 257.171000, 60.827500, 0.009100) Rarity: Loading 520 item(s) from server... Rarity: UpdateText: 0.045900ms Rarity: UpdateText: 0.047600ms Rarity: UpdateText: 0.040100ms Rarity: UpdateText: 0.045200ms Rarity: UpdateText: 0.039500ms Rarity: UpdateText: 0.041200ms Rarity: UpdateText: 0.039900ms Rarity: UpdateText: 0.042500ms Rarity: UpdateText: 0.041700ms Rarity: UpdateText: 0.049700ms Rarity: UpdateText: 0.052200ms Rarity: UpdateText: 0.041100ms Rarity: UpdateText: 0.042300ms Rarity: UpdateText: 0.049700ms Rarity: UpdateText: 0.053500ms Rarity: UpdateText: 0.043900ms Rarity: UpdateText: 0.041400ms Rarity: UpdateText: 0.041200ms Rarity: UpdateText: 0.043800ms Rarity: UpdateText: 0.042700ms Rarity: UpdateText: 0.043600ms Rarity: UpdateText: 0.042100ms Rarity: UpdateText: 0.042200ms Rarity: UpdateText: 0.049800ms Rarity: UpdateText: 0.049400ms Rarity: UpdateText: 0.042100ms Rarity: UpdateText: 0.041900ms Rarity: UpdateText: 0.040000ms Rarity: UpdateText: 0.041200ms Rarity: UpdateText: 0.040600ms Rarity: UpdateText: 0.039300ms Rarity: UpdateText: 0.041000ms Rarity: UpdateText: 0.043500ms Rarity: UpdateText: 0.039600ms Rarity: UpdateText: 0.041700ms Rarity: UpdateText: 0.040800ms Rarity: UpdateText: 0.041300ms Rarity: UpdateText: 0.041600ms Rarity: UpdateText: 0.041200ms Rarity: UpdateText: 0.043000ms Rarity: UpdateText: 0.052800ms Rarity: UpdateText: 0.040800ms Rarity: UpdateText: 0.040000ms Rarity: UpdateText: 0.051900ms Rarity: UpdateText: 0.042600ms Rarity: UpdateText: 0.061900ms Rarity: UpdateText: 0.041100ms Rarity: UpdateText: 0.041100ms Rarity: UpdateText: 0.049000ms Rarity: UpdateText: 0.041500ms Rarity: UpdateText: 0.053600ms Rarity: Initialization failed to retrieve 14 item(s) Rarity: UpdateText: 0.034300ms Rarity: BuildStatistics: 0.328800ms Rarity: ScanStatistics: 2.537000ms Rarity: Scanning calendar (DELAYED INIT) Rarity: Scanning toys (DELAYED INIT) Rarity: Scanning transmog (DELAYED INIT) Rarity: UpdateText: 0.045100ms Rarity: Loading 14 item(s) from server... Rarity: UpdateText: 0.041000ms Rarity: Finished loading 14 item(s) from server Rarity: UpdateText: 0.036500ms
Did you test this with just Rarity enabled? Can you pinpoint a specific time when this started happening, say a new Rarity update or a WOW patch that was released? Also, do you mean the CPU Profiling as provided by Blizzard? It severely impacts performance and can cause certain addon functionality to take a LOT longer than it normally would when loading the UI.
The "tooltip rendering" is referring to the main window, which is technically a tooltip as it is implemented via the LibQTip library. Since that functionality has been untouched for many years I don't know why it would suddenly cause performance issues. It's also not really something I want to mess with right now, as it's deeply intertwined with the addon's core code (that I didn't write). Without a specific place to start looking I wouldn't even know where to begin.
---
After looking into the specific parts that seem to be taking the most time, it looks like Rarity takes a lot of time to add especially the pets from the database to the GUI. It might be possible to further optimize this depending on how search and iteration over internal data structures take place, though I'd need a lot more time than I currently have to optimize this (if it hasn't already been done by the original authors). It's not a trivial task by any means, but I'll add it to the list... :/
I don't blame you for not wanting to tackle this problem, but it has annoyed me for such a long time I'm going to stop using Rarity. I have appreciated using the addon for quite a few years though! I'll be glad to provide follow up if you ever look into this.
Thanks for your feedback! I do agree that there are many things to be improved, but I'm the only maintainer and I've very little time so I must work efficiently :)
Since I personally like algorithmic problems I've looked into this further, and here is what I can say (so far):
* The tooltip rendering doesn't appear to be blocking for me. That is, even if it might take a while the game is already responsive and continues to be so while Rarity adds the various items to its internal data structures to display later. Rarity will display "Loading..." and the tooltip can't yet be displayed while it is being assembled, but there is no freezing while this takes place
* Your profiling log doesn't contain any of the startup tasks that appear to take a significant amount of time. Most notably, scanning pets and toy collections seems to take a long time for me, but that's because Blizzard's UI has to load the respective collections addon first (only once per login)
* Tooltip rendering itself can take a LOT longer if you change the sorting order, which is a known issue and something that could likely be optimized (see https://github.com/SacredDuckwhale/Rarity/issues/100). Still doesn't cause any freezes for me, but YMMV
Therefore I would suggest a few things you could try out:
* Change the sort order to different values and see if this helps. ZONE makes the tooltip rendering jump up to 1100ms for me, anything else remains in the 200-300ms range
* Download the latest alpha and post the complete profiling log. I've added more detailed profiling for the various collection scans inside of the tooltip rendering routine, so we can check if they're taking an insubordinate amount of time (addGroup() is not being profiled in the latest release yet)
* The one thing that does seem to cause a small-ish freeze for me is Blizzard's toy box/collection loading. There isn't really a way around it as it has to be done before toys can be checked, and it will even happen if you manually open the toy box UI for the first time
I could try to optimize the various iteration and sort procedures, but with the exception of ZONE they seem pretty decent already. Additionally, they aren't all run at startup so it appears unlikely they would cause an actual freeze, which sounds more like the Blizzard_Collections addon being loaded for the first time.
Tooltip rendering has to wait for that to happen, which would explain why the "Tooltip rendering took X ms" text appears after the freeze finishes. Watch for the "Toys took X ms" text and you'll see that the FIRST time it appears it will take a lot of time, while subsequent calls are almost instantaneous.
This is because the game has to load Blizzard_Collections once before it can be used, and the only workaround I can think of would be to delay/disable it entirely, meaning Rarity won't know which toys are already learned
Rarity: addGroup(Mounts, nil) took 45.186800ms (Total: 45.178900, Sort: 13.128400, Iteration: 32.044800, Tooltip: 0.000500 Rarity: addGroup(Battle Pets, nil) took 101.348300ms (Total: 101.341500, Sort: 38.875600, Iteration: 62.459300, Tooltip: 0.000200 Rarity: addGroup(Toys & Items, nil) took 40.467300ms (Total: 40.459600, Sort: 7.536800, Iteration: 32.917000, Tooltip: 0.000500 Rarity: addGroup(Custom, nil) took 0.017100ms (Total: 0.010200, Sort: 0.003900, Iteration: 0.000600, Tooltip: 0.000200 Rarity: addGroup(Mounts, true) took 26.669700ms (Total: 26.663800, Sort: 10.556900, Iteration: 16.104100, Tooltip: 0.000400 Rarity: addGroup(Battle Pets, true) took 69.350800ms (Total: 69.343700, Sort: 41.626600, Iteration: 27.712100, Tooltip: 0.000200 Rarity: addGroup(Toys & Items, true) took 15.927000ms (Total: 15.921000, Sort: 8.564000, Iteration: 7.352000, Tooltip: 0.000300 Rarity: addGroup(Custom, true) took 0.011800ms (Total: 0.007600, Sort: 0.002300, Iteration: 0.000300, Tooltip: 0.000100 Rarity: Tooltip rendering took 299.407700ms (45.206200, 101.365200, 40.488500, 0.029800, 26.685200, 69.368300, 15.948200, 0.020800)
This was the only section of consequence it seemed, I cannot get a full log anyway since my chat log floods too quickly with updateText messages.
I ran a few tests and it seems like the freezing is coming from the addGroups, not from the Blizzard_Collections loading. Collections do not freeze with no addons loaded, or if manually loaded with UIParentLoadAddOn. The only lag I've ever encountered from it is when addons iterate over them rapidly, like an addon skinning all of the icons.
The tests I did that had Rarity enabled were not overly different, and I've never changed the sorting method of the minimap icon (I don't use it).
Is there not a way you could throttle this process?
Thanks, I've now found out a bit more and it might be possible to delay the sorting and tooltip additions until they're actually needed. I'll have to think about it some more, but the main causes of performance drops are:
* LibQTip iterating over the entire tooltip each time an individual item is being added (not much to be done there, per se)
* Rarity using different sorting algorithms based on the sort order setting, some of which take a long time (not sure if they can be optimized further yet)
Both these things are done after an initial delay on startup. I'm hoping that delaying them until the tooltip window is actually opened will remove this annoyance in lieu of causing a freeze when the tooltip is first opened (which wouldn't be quite as problematic). I still have to find out if the tracking etc. can work independently of this, but as long as you aren't displaying the tooltip it shouldn't be necessary to have items sorted nor to have the tooltip frames built in advance.
In the meantime, please do try using a different sorting setting. It makes a huge difference, even if you don't use the tooltip itself. I haven't found a way to reduce it to lower than the 200ms or so that sorting by name allows for, but that's still miles better than 800-1100ms.
I will try some other sorting orders, but initially it doesn't look like it's going to be of impact like you mentioned.
I only really use Rarity to see the text after killing a mob or boss that says how many attempts I've had on an item. In the rare instance I do go out of my way to repeatedly farm some item, I prefer to use the progress bar. The tooltip is rather cumbersome. I always wished the tooltip only held specific opt-in things to track, or compiled a list of recent attempts. The big tooltip with statistics on everything would be a window instead, which would only load those sections when I cared to open the window.
Half of this problem should be fixed in the latest release. The other half is due to some limitations of the WOW UI and we're looking into workarounds to the problem. However, it should be much more usable now in virtually all scenarios.
If you're still experiencing significant a performance drops after updating, please open a new issue.
To post a comment, please login or register a new account.
