LUA Blueprint and Category lookup speeds - FAForever/fa GitHub Wiki

TestThread = function(self)
    WARN("Test thread activated")

    local t = GetSystemTimeSecondsOnlyForProfileUse()
    for i = 1, 10000 do
        local cat = EntityCategoryContains(categories.AIR, self)
    end
    t = GetSystemTimeSecondsOnlyForProfileUse() - t
    WARN("Test 1 complete, time elapsed for EntityCategoryContains is " .. t)
    
    t = GetSystemTimeSecondsOnlyForProfileUse()
    for i = 1, 10000 do
        local bp = self:GetBlueprint()
        local cat = bp.CategoriesHash.AIR
    end
    t = GetSystemTimeSecondsOnlyForProfileUse() - t
    WARN("Test 2 complete, time elapsed for self:GetBlueprint followed by bp.CategoriesHash.AIR is " .. t)
    
    t = GetSystemTimeSecondsOnlyForProfileUse()
    for i = 1, 10000 do
        local bp = GetBlueprint(self)
        local cat = bp.CategoriesHash.AIR
    end
    t = GetSystemTimeSecondsOnlyForProfileUse() - t
    WARN("Test 3 complete, time elapsed for globally localised GetBlueprint(self) followed by bp.CategoriesHash.AIR is " .. t)
    
    t = GetSystemTimeSecondsOnlyForProfileUse()
    for i = 1, 10000 do
        local cat = BluePrints[self.UnitId].CategoriesHash.AIR
    end
    t = GetSystemTimeSecondsOnlyForProfileUse() - t
    WARN("Test 4 complete, time elapsed for globally localised __blueprints table lookup of BluePrints = __blueprints.Unit -> BluePrints[self.UnitId].CategoriesHash.AIR is " .. t)
    
    t = GetSystemTimeSecondsOnlyForProfileUse()
    for i = 1, 10000 do
        local cat = __blueprints.Unit[self.UnitId].CategoriesHash.AIR
    end
    t = GetSystemTimeSecondsOnlyForProfileUse() - t
    WARN("Test 5 complete, time elapsed for __blueprints.Unit[self.UnitId].CategoriesHash.AIR is " .. t)
    
    t = GetSystemTimeSecondsOnlyForProfileUse()
    for i = 1, 10000 do
        local cat = _G.__blueprints.Unit[self.UnitId].CategoriesHash.AIR
    end
    t = GetSystemTimeSecondsOnlyForProfileUse() - t
    WARN("Test 6 complete, time elapsed for _G.__blueprints.Unit[self.UnitId].CategoriesHash.AIR is " .. t)
    
    local bp = GetBlueprint(self)
    t = GetSystemTimeSecondsOnlyForProfileUse()
    for i = 1, 10000 do
        local cat = bp.CategoriesHash.AIR
    end
    t = GetSystemTimeSecondsOnlyForProfileUse() - t
    WARN("Test 7 complete, time elapsed for cases where local bp = GetBlueprint(self) has been done for other reasons already, followed by bp.CategoriesHash.AIR is " .. t)
end,

This code resulted the following:

WARNING: Test thread activated
WARNING: Test 1 complete, time elapsed for EntityCategoryContains is 0.00274658203125
WARNING: Test 2 complete, time elapsed for self:GetBlueprint followed by bp.CategoriesHash.AIR is 0.00299072265625
WARNING: Test 3 complete, time elapsed for globally localised GetBlueprint(self) followed by bp.CategoriesHash.AIR is 0.00274658203125
WARNING: Test 4 complete, time elapsed for globally localised __blueprints table lookup of BluePrints = __blueprints.Unit -> BluePrints[self.UnitId].CategoriesHash.AIR is 0.00079345703125
WARNING: Test 5 complete, time elapsed for __blueprints.Unit[self.UnitId].CategoriesHash.AIR is 0.00103759765625
WARNING: Test 6 complete, time elapsed for _G.__blueprints.Unit[self.UnitId].CategoriesHash.AIR is 0.00115966796875
WARNING: Test 7 complete, time elapsed for cases where local bp = GetBlueprint(self) has been done for other reasons already, followed by bp.CategoriesHash.AIR is 0.000244140625

From this we can see several things.

Calling self:GetBlueprint() is slightly slower than using a local GetBlueprint(self) defined as local GetBlueprint = moho.entity_methods.GetBlueprint at top of file.

Where bp has already been fetched, it is much faster to simply grab the value from bp.CategoriesHash[cat] than to use EntityCategoryContains

Where it hasn't. the hash lookup + a new function call to get the blueprint is slower than just using EntityCategoryContains

All methods of getting a blueprint directly from the Global table are faster than either of the functions, but using local bps = __blueprints.Unit at top of file results in the fastest of these (It skips checking _G and __blueprints and jumps right in)

Conclusion:

• All unit blueprint lookups should be changed from using functions to using bps[self.UnitId], with UnitId stored in OnCreate. Further investigation of function vs lookup below.
• Where a single category is being looked up, use the CategoriesHash blueprint entry

Additional testing of a more realistic set of situations is as follows:

    TestThread = function(self)
        WARN('Test thread activated')

        local t = GetSystemTimeSecondsOnlyForProfileUse()
        for i = 1, 10000 do
            local bp = GetBlueprint(self)
            local a = bp.Air.AutoLandTime
            local b = bp.Defense.Health
            local c = bp.Defense.RegenRate
            local d = bp.Economy.BuildCostEnergy
            local e = bp.Economy.BuildCostMass
        end
        t = GetSystemTimeSecondsOnlyForProfileUse() - t
        WARN('Test 1 complete, time elapsed for GetBlueprint(self) is ' .. t)

        local t = GetSystemTimeSecondsOnlyForProfileUse()
        for i = 1, 10000 do
            local bp = self:GetBlueprint()
            local a = bp.Air.AutoLandTime
            local b = bp.Defense.Health
            local c = bp.Defense.RegenRate
            local d = bp.Economy.BuildCostEnergy
            local e = bp.Economy.BuildCostMass
        end
        t = GetSystemTimeSecondsOnlyForProfileUse() - t
        WARN('Test 1 complete, time elapsed for self:GetBlueprint() is ' .. t)

        local t = GetSystemTimeSecondsOnlyForProfileUse()
        for i = 1, 10000 do
            local bp = bps[self.UnitId]
            local a = bp.Air.AutoLandTime
            local b = bp.Defense.Health
            local c = bp.Defense.RegenRate
            local d = bp.Economy.BuildCostEnergy
            local e = bp.Economy.BuildCostMass
        end
        t = GetSystemTimeSecondsOnlyForProfileUse() - t
        WARN('Test 1 complete, time elapsed for local bps[self.UnitId] is ' .. t)

        local t = GetSystemTimeSecondsOnlyForProfileUse()
        for i = 1, 10000 do
            local a = bps[self.UnitId].Air.AutoLandTime
            local b = bps[self.UnitId].Defense.Health
            local c = bps[self.UnitId].Defense.RegenRate
            local d = bps[self.UnitId].Economy.BuildCostEnergy
            local e = bps[self.UnitId].Economy.BuildCostMass
        end
        t = GetSystemTimeSecondsOnlyForProfileUse() - t
        WARN('Test 1 complete, time elapsed for bps[self.UnitId] instead of any local is ' .. t)
    end,

Resulting in:

WARNING: Set unit ID to uea0303
WARNING: Test thread activated
WARNING: Test 1 complete, time elapsed for GetBlueprint(self) is 0.0035743713378906
WARNING: Test 1 complete, time elapsed for self:GetBlueprint() is 0.0038337707519531
WARNING: Test 1 complete, time elapsed for local bps[self.UnitId] is 0.0019111633300781
WARNING: Test 1 complete, time elapsed for bps[self.UnitId] instead of any local is 0.00372314453125

And so we find that, by replacing all function-based Blueprint lookup calls with a local based on the __blueprints table, we cut execution time roughly in half. Small gains, but it's something!