Skillet

Skillet

112k Downloads

Improve performance of Skillet:GetInventory()

DDCorkum opened this issue ยท 8 comments

commented

Issue:

  • Skillet:GetInventory() in Inventory.lua contributes to a perceptible lag when crafting items.

Details:

  • On a retail scribe, crafting a single item results in about 10000 calls to GetItemCount at a cost of 600ms.
  • More than 5000 of these calls are in the same frame as prior calls for the same reagentID, meaning they are fetching the exact same value that was already counted.
  • Similarly, about 10000 anonymous tables are created and discarded; resulting in heavy garbage collection.
  • These numbers will vary based on the toon, what professions that toon has, how many recipes, etcetera. Take these numbers just for illustrative purposes only (measured using my own scribe).

Proposed Solution: The code chunk below rewrites GetInventory() to make the following optimizations:

  • Cache the result of GetItemCount() for the rest of the frame, but re-check on the next frame using GetTime()
  • Reuse a table called data rather than packing the result of string.split in a fresh new table
  • Comment out more debugging lines that were not contributing.

I haven't tested this extensively, but if it works then this might shave a few hundred milliseconds from every craft operation. That's just enough that a user might perceive the difference.

-- function Skillet:GetInventory()
do
	-- locals used inside the function for performance reasons
	local cachedCount, cachedTime = {}, {} -- avoid calling GetItemCount() many times in the same frame
	local data = {} -- avoid making and tossing many tables
	
	function Skillet:GetInventory(player, reagentID)
		--DA.DEBUG(0,"GetInventory("..tostring(player)..", "..tostring(reagentID)..")")
		local numCanUse
		if player and reagentID then
			if player == self.currentPlayer then			-- UnitName("player")
				if GetTime() == cachedTime[reagentID] then
					numCanUse = cachedCount[reagentID] 
				else
					numCanUse = GetItemCount(reagentID,true)
					cachedCount[reagentID] = numCanUse
					cachedTime[reagentID] = GetTime()
				end
			end
			if self.db.realm.inventoryData[player] and self.db.realm.inventoryData[player][reagentID] then
				--DA.DEBUG(1,"inventoryData= "..tostring(self.db.realm.inventoryData[player][reagentID]))
				data[1], data[2], data[3] = string.split(" ", self.db.realm.inventoryData[player][reagentID])
				--if numCanUse and data[1] and tonumber(numCanUse) ~= tonumber(data[1]) then
					--DA.DEBUG(0,"inventoryData is stale")
				--end
				return tonumber(data[1]) or 0, data2 and tonumber(data[2]) or 0, data3 and tonumber(data[3]) or 0
			elseif player == self.currentPlayer then	-- UnitName("player")
				return tonumber(numCanUse) or 0, 0, 0
			end
		end
		return 0, 0, 0		-- have, make, make with vendor
	end
end
commented

Skillet-4.27-beta has incorporated the GetInventory changes.

commented

Another alternative...

do
	local cacheBoth, cacheBags = {}, {}
	local time = 0
	
	function Skillet:GetItemCount(reagentID, includeBank)
		local newTime = GetTime()
		if newTime > time then
			time = newTime
			wipe(cacheBoth)
			wipe(cacheBags)
		end
		if (includeBank) then
			cacheBoth[reagentID] = cacheBoth[reagentID] or GetItemCount(reagentID, true)
			return cacheBoth[reagentID]
		else
			cacheBags[reagentID] = cacheBags[reagentID] or GetItemCount(reagentID, false)
			return cacheBags[reagentID]
		end
	end
end

Now change every instance of GetItemCount() to Skillet:GetItemCount() and cached results will be used across all counts.

This is actually my recommended solution over the original, because it shares the cached result across the whole addon. However, the data[1], data[2], data[3] = string.split... trick in the original post is still worth doing to avoid creating and discarding many tables.

commented

The only problem with this approach is that during crafting, I had people complain if the counts didn't change in realtime. I guess that means there should be an option for selecting speed or accuracy.

commented

My suggestions are not meant to stop updating in real time; just to more efficiently do so by not calling GetItemCount(x) many times in the same split second for the same value of x.

For example, every alchemist recipe requires a vial. If you call GetItemCount(180732) then it will take some tiny fraction of a second for the game to count all the rune-etched vials in the bags. If you call GetItemCount(180732) a hundred times, then it will take a hundred tiny fractions of a second. It adds up!

So instead, just call it once and then save the value. Use the saved value the other 99 times.

But one second later -- even just one millisecond later -- make sure to call GetItemCount() again to get the new value.

commented

PS. I would absolutely not recommend a solution that reduces accuracy. That would be very frustrating to users!

commented

The function InventoryScan builds a cache of item counts so this version of GetInventory avoids the call to GetItemCount unless absolutely necessary.

function Skillet:GetInventory(player, reagentID)
	--DA.DEBUG(0,"GetInventory("..tostring(player)..", "..tostring(reagentID)..")")
	if player and reagentID then
		if self.db.realm.inventoryData[player] and self.db.realm.inventoryData[player][reagentID] then
			--DA.DEBUG(1,"inventoryData= "..tostring(self.db.realm.inventoryData[player][reagentID]))
			local have, make, mwv = string.split(" ", self.db.realm.inventoryData[player][reagentID])
			return tonumber(have) or 0, tonumber(make) or 0, tonumber(mwv) or 0
		elseif player == self.currentPlayer then
			return GetItemCount(reagentID,true) or 0, 0, 0
		end
	end
	return 0, 0, 0		-- have, make, make with vendor
end

I believe rather than optimize GetItemCount, we should figure out how to reduce the number of times the higher level functions
are called. You can see what I mean by enabling debugging ("/skillet debugshow on"). If you don't want to watch all that chat, "/skillet debuglogging on" instead and examine the per character saved variables file Skillet.lua. Note that "/skillet debugshow" is a toggle but once debuglogging has been turned on, you have to explicitly turn it off.

commented

I see what you did. Flipped the GetItemCount() toward the end of the function so its used when useful, rather than being called every time.

I think that's a good solution. It looks like the only real downside is the loss of info for your debugging; but that was commented out anyways so its not a big deal.

have/make/mwv is also a good alternative to the table. That should cut down on garbage collection a little.

commented

The debugging info was useful when I was actually debugging an issue which has since been fixed. If I need it, I'll add it again. I tend to leave debugging statements in place but commented out because if I have an issue in the future, its quicker to uncomment the statements than to reinvent them.