Facepunch / garrysmod-issues

Garry's Mod issue tracker
142 stars 56 forks source link

file.Exists is super slow when used with "LUA" path #5674

Closed wrefgtzweve closed 8 months ago

wrefgtzweve commented 9 months ago

After investigating long lua startup times when joining a server i've noticed that file.Exists( file, "LUA" ) seems to be incredibly slow This was tested on 64x cl, seems to be the same on 32x servers though.

My test:

print( "file.Exists LUA" )
print( file.Exists( "entities/sent_ball.lua", "LUA" ) )
local start = SysTime()
for i = 1, 100 do
    file.Exists( "entities/sent_ball.lua", "LUA" )
end
print( SysTime() - start )

print( "file.Exists GAME" )
print( tobool( file.Read( "lua/entities/sent_ball.lua", "GAME" ) ) )
local start = SysTime()
for i = 1, 100 do
    tobool( file.Read( "lua/entities/sent_ball.lua", "GAME" ) )
end
print( SysTime() - start )

print( "file.Read LUA" )
print( tobool( file.Read( "entities/sent_ball.lua", "LUA" ) ) )
local start = SysTime()
for i = 1, 100 do
    tobool( file.Read( "entities/sent_ball.lua", "LUA" ) )
end
print( SysTime() - start )

print( "file.Read GAME" )
print( tobool( file.Read( "lua/entities/sent_ball.lua", "GAME" ) ) )
local start = SysTime()
for i = 1, 100 do
    tobool( file.Read( "lua/entities/sent_ball.lua", "GAME" ) )
end
print( SysTime() - start )

local function fileExists( path, dir )
    local f = file.Open( path, "r", dir )
    if f then
        f:Close()
        return true
    end
    return false
end

print( "Custom file exist GAME" )
print( fileExists( "lua/entities/sent_ball.lua", "GAME" ) )
local start = SysTime()
for i = 1, 100 do
    fileExists( "lua/entities/sent_ball.lua", "GAME" )
end
print( SysTime() - start )

print( "Custom file exist LUA" )
print( fileExists( "entities/sent_ball.lua", "LUA" ) )
local start = SysTime()
for i = 1, 100 do
    fileExists( "entities/sent_ball.lua", "LUA" )
end
print( SysTime() - start )

Results:

Small amount of addons, local dev server, clientside:

file.Exists LUA
true
0.69640199999998
file.Exists GAME
true
0.33176890000004
file.Read LUA
true
0.2955905
file.Read GAME
true
0.32984709999999
Custom file exist GAME
true
0.2006068
Custom file exist LUA
true
0.18350279999999

Public dedicated prod server with addons, clientside:

file.Exists LUA
true
6.9172338000001
file.Exists GAME
true
0.35067989999993
file.Read LUA
true
0.31082429999992
file.Read GAME
true
0.33976000000007
Custom file exist GAME
true
0.2093010000001
Custom file exist LUA
true
0.18773499999998

Both tests were carried out on the same PC, do note that my fileExists likely cant be used as a drop in replacement for file.Exists as file.Read doesn't play nicely with lua files sometimes.

Grocel commented 9 months ago

I can confirm this with a similar but a quite faster result.

Results

Server

----------------------------

REALM:  SERVER
file.Exists LUA
true
0.069304200000033
file.Exists GAME
true
0.093234999999936
file.Read LUA
true
0.064957800000002
file.Read GAME
true
0.092480499999965
Custom file exist GAME
true
0.063004299999989
Custom file exist LUA
true
0.045790199999942

----------------------------

Client

----------------------------

REALM:  CLIENT
file.Exists LUA
true
0.31779099999994
file.Exists GAME
true
0.092465199999992
file.Read LUA
true
0.065484999999967
file.Read GAME
true
0.092128900000034
Custom file exist GAME
true
0.064726500000006
Custom file exist LUA
true
0.045994599999972

----------------------------

PrintTable( debug.getinfo( file.Exists ) ):

currentline =   -1
func    =   function: 0xdb993faa
isvararg    =   true
lastlinedefined =   -1
linedefined =   -1
namewhat    =   
nparams =   0
nups    =   0
short_src   =   [C]
source  =   =[C]
what    =   C

PrintTable( debug.getinfo( file.Read ) ):

currentline =   -1
func    =   function: 0xdded4a2a
isvararg    =   false
lastlinedefined =   19
linedefined =   4
namewhat    =   
nparams =   2
nups    =   0
short_src   =   lua/includes/extensions/file.lua
source  =   @lua/includes/extensions/file.lua
what    =   Lua

----------------------------

Test script

print("\n----------------------------\n")

print( "REALM:", SERVER and "SERVER" or "CLIENT")

print( "file.Exists LUA" )
print( file.Exists( "entities/sent_ball.lua", "LUA" ) )
local start = SysTime()
for i = 1, 100 do
    file.Exists( "entities/sent_ball.lua", "LUA" )
end
print( SysTime() - start )

print( "file.Exists GAME" )
print( tobool( file.Read( "lua/entities/sent_ball.lua", "GAME" ) ) )
local start = SysTime()
for i = 1, 100 do
    tobool( file.Read( "lua/entities/sent_ball.lua", "GAME" ) )
end
print( SysTime() - start )

print( "file.Read LUA" )
print( tobool( file.Read( "entities/sent_ball.lua", "LUA" ) ) )
local start = SysTime()
for i = 1, 100 do
    tobool( file.Read( "entities/sent_ball.lua", "LUA" ) )
end
print( SysTime() - start )

print( "file.Read GAME" )
print( tobool( file.Read( "lua/entities/sent_ball.lua", "GAME" ) ) )
local start = SysTime()
for i = 1, 100 do
    tobool( file.Read( "lua/entities/sent_ball.lua", "GAME" ) )
end
print( SysTime() - start )

local function fileExists( path, dir )
    local f = file.Open( path, "r", dir )
    if f then
        f:Close()
        return true
    end
    return false
end

print( "Custom file exist GAME" )
print( fileExists( "lua/entities/sent_ball.lua", "GAME" ) )
local start = SysTime()
for i = 1, 100 do
    fileExists( "lua/entities/sent_ball.lua", "GAME" )
end
print( SysTime() - start )

print( "Custom file exist LUA" )
print( fileExists( "entities/sent_ball.lua", "LUA" ) )
local start = SysTime()
for i = 1, 100 do
    fileExists( "entities/sent_ball.lua", "LUA" )
end
print( SysTime() - start )

print("\n----------------------------\n")

print("PrintTable( debug.getinfo( file.Exists ) ):\n")
PrintTable( debug.getinfo( file.Exists ) )

print("\n")

print("PrintTable( debug.getinfo( file.Read ) ):\n")
PrintTable( debug.getinfo( file.Read ) )

print("\n----------------------------")

My Specs

Grocel commented 9 months ago

Today I did a bit more research on that issue and oh boy I did not expect this result.

Apparently the performance slows down when you have many addon's installed in general. But it is at worst if the addon contain Lua files.

Summary

This is what I found:

The weirdest part I have found: A serverside only addon containing a Lua file still affects the clients performance, even though the client never downloads or runs the Lua file. The Lua files don't even need to be run on the server to affect the performance. It just need to exist on the server.

Setup

The testing setup has been moved to:

These Gists contains descriptions, scripts for addon generation and a benchmark that will help you to easily reproduce the issue.

Test case: 5k Lua files in a single addon

The zip file below contains a single addon with 5000 Lua files. The addon also contains a batch script ('_test_addon_many_luas/create_dummy_luas.bat') in case you want to build a case with more or less Lua files. _test_addon_many_luas.zip (5k Lua files)

Performance

This test case does a little influence to the reported issue.

The CustomFileExists function

This function was proposed as a file.Exist replacement, as this function has been shown to be significantly faster. This function is called CustomFileExists in the test results.

local function CustomFileExists( path, dir )
    -- Note: It will NOT find AddCSLuaFile() files on the client if file is not physically present as an actual file on said client.
    -- This is the case for server exclusive content or not installed addons that are used on the server.

    local f = file.Open( path, "r", dir )

    if f then
        f:Close()

        return true
    end

    return false
end

Please note that it does not work correctly with AddCSLuaFile() files. Using the GAME path with file.Exists or any other function also does not work correctly on AddCSLuaFile() files.

Results

In my measurements I have read these values:

Client on Dedicated server, 500 non-lua addons on server, 1 single sound file each, no clientside addons

Function Search Path Timing
file.Exists LUA 0.12998589999998
file.Exists GAME 0.10211290000001
file.Read LUA 0.074022999999983
file.Read GAME 0.1029106
CustomFileExists LUA 0.052157199999982
CustomFileExists GAME 0.070933999999994

Result: FAST

Client on Dedicated server, 500 lua-addons on server, 1 single lua file each (serverside only), no clientside addons

Function Search Path Timing
file.Exists LUA 3.6613277
file.Exists GAME 0.098917599999993
file.Read LUA 0.071523799999966
file.Read GAME 0.099444300000016
CustomFileExists LUA 0.054489700000033
CustomFileExists GAME 0.068561799999998

Result: file.Exists SLOW

Client on Dedicated server, 500 lua-addons on server, 1 single lua file each (serverside only, not auto-included), no clientside addons

Function Search Path Timing
file.Exists LUA 3.683936
file.Exists GAME 0.10147770000003
file.Read LUA 0.072730400000012
file.Read GAME 0.099444300000016
CustomFileExists LUA 0.051760799999954
CustomFileExists GAME 0.069727

Result: file.Exists SLOW

Grocel commented 9 months ago

Update

Datapacks

After some discussion on GMod Discord I have found out that you can print out a list of networked datapacks using datapack_paths (cliendside only, sv_cheats).

] datapack_paths 
[...]
9. "addons/wire/lua/"
10. "addons/wire-extras/lua/"
11. "addons/_test_addon_dummy_00001/lua/"
12. "addons/_test_addon_dummy_00002/lua/"
13. "addons/_test_addon_dummy_00003/lua/"
14. "addons/_test_addon_dummy_00004/lua/"
15. "addons/_test_addon_dummy_00005/lua/"
16. "addons/_test_addon_dummy_00006/lua/"
17. "addons/_test_addon_dummy_00007/lua/"
18. "addons/_test_addon_dummy_00008/lua/"

[...]

494. "addons/_test_addon_dummy_00484/lua/"
495. "addons/_test_addon_dummy_00485/lua/"
496. "addons/_test_addon_dummy_00486/lua/"
497. "addons/_test_addon_dummy_00487/lua/"
498. "addons/_test_addon_dummy_00488/lua/"
499. "addons/_test_addon_dummy_00489/lua/"
500. "addons/_test_addon_dummy_00490/lua/"
501. "addons/_test_addon_dummy_00491/lua/"
502. "addons/_test_addon_dummy_00492/lua/"
503. "addons/_test_addon_dummy_00493/lua/"
504. "addons/_test_addon_dummy_00494/lua/"
505. "addons/_test_addon_dummy_00495/lua/"
506. "addons/_test_addon_dummy_00496/lua/"
507. "addons/_test_addon_dummy_00497/lua/"
508. "addons/_test_addon_dummy_00498/lua/"
509. "addons/_test_addon_dummy_00499/lua/"
510. "addons/_test_addon_dummy_00500/lua/"
511. "workshop/lua/"
512. "workshop/gamemodes/"
513. "lua/"
514. "gamemodes/"
515. "workshop/gamemodes/base/entities/"
516. "gamemodes/base/entities/"
517. "workshop/gamemodes/sandbox/entities/"
518. "gamemodes/sandbox/entities/"

We have found that file.Exists grows linearly by the size of the above list when run on a "LUA" path. If an addon has Lua files (even serverside only or not loaded/included), the server will network the path to the client and the client's file.Exists will iterate it on every call.

Replacements for file.Exists

Today I noticed that file.Exists can't be replaced without sacrificing reliability on some cases. Using the function with the "GAME" path and using the custom function for checking a file existence will result in false negatives if the requested file is only available via AddCSLuaFile() on the client, e.g the file/addon not installed on said client.

In other words: All replacement implementations for file.Exists do NOT find files added by AddCSLuaFile().

So the original file.Exists can NOT be replaced in Lua. According to RaphaelIT7 on Discord the function could maybe be improved, though. grafik grafik

brandonsturgeon commented 9 months ago

I know the established wisdom is to have as few addons as possible.

In our community, we opted to.. ignore this wisdom - but only in a way. We have a standard number of Lua files, but we keep our code very segmented. Each project is in its own addon directory.

This helps us with permission boundaries on the Github side of things, as well as letting us provide useful automatic update messages. It's also just a common practice in most development environments.

Doing it this way meant we paid a huge tax on startup time. I was okay with that, I thought it was a fair trade.

Now we know that it causes performance issues that can (in some cases) severely impact player experience. Am I supposed to compile all of my addons into a single directory to "trick" the game into performing well?

Thanks for the thorough research and reporting @Grocel - Great work🥇

Grocel commented 9 months ago

I have refreshed testing setup a bit. I have added 2 more cases for reproduction. In total we have:

Both single addon cases have shown to have no or very little effect to the run times of file.Exist or other file IO operations. My above post have been updated accordingly. I also updated the post to be a bit more clear.

robotboy655 commented 8 months ago

I have done some changes to address this, even though I don't even understand what scenario you'd want file.Exists for Lua path.

Grocel commented 8 months ago

Thinks Rubat. I can confirm that the update increased the performance quite a lot, good work on that.

However I have found regression in file.IsDir(). It no longer finds directories added via AddCSLuaFile() on the client. I'm not sure if it is a trade off or an unintended mistake. The function file.exists works just fine and does not have that regression. The results has showen that the file.Exists was a bit slower on server after the update. Can someone confirms this?

Benchmark

I did the benchmarks and tests using these scripts: https://gist.github.com/Grocel/f8eff1ba32f2ef0e46f91e0ae1a79c4f

The test were ran on a dedicated server with a locally connected client. All test were done on the main (live) and development (dev) branches. NOTE: The reported BRANCH in the files is unknown on both server versions.

Result files

These are the raw results: FileExistsBenchmark.zip

Summary

Supports AddCSLuaFile

Function Search Path supports AddCSLuaFile on main supports AddCSLuaFile on dev
file.Exists LUA Yes Yes
file.Exists GAME No No
file.IsDir LUA Yes No (regression or trade off)
file.IsDir GAME No No
tobool(file.Read()) LUA No No
tobool(file.Read()) GAME No No
Custom file exist (file.Open) LUA No No
Custom file exist (file.Open) GAME No No

Timings

All timing values are given in milliseconds. They are the average runtimes of single function calls. Each function was called 100 times during the test. All Addon cases are serverside only. The client doesn't have any addon beside some common ones. The cases with Lua files are serverside only without AddCSLuaFile().

Case: No addons

Function Search Path CLIENT on main CLIENT on dev SERVER on main SERVER on dev
file.Exists LUA 1.0364 0.1567 0.4047 0.4836
file.Exists GAME 1.0426 1.0406 0.5041 0.5811
file.IsDir LUA 1.4552 0.0392 0.6885 0.0118
file.IsDir GAME 0.0132 0.0135 0.0102 0.0096
tobool(file.Read()) LUA 0.7416 0.7423 0.4327 0.4890
tobool(file.Read()) GAME 1.0515 1.0656 0.5151 0.5582
Custom file exist (file.Open) LUA 0.4848 0.5254 0.3321 0.3389
Custom file exist (file.Open) GAME 0.6806 0.7283 0.3972 0.4200

Case: 500 addons with a sound file

Function Search Path CLIENT on main CLIENT on dev SERVER on main SERVER on dev
file.Exists LUA 1.0054 0.1596 0.6203 0.7158
file.Exists GAME 1.0359 1.0382 33.4058 32.8321
file.IsDir LUA 1.4262 0.0394 0.8444 0.0292
file.IsDir GAME 0.0132 0.0133 0.0268 0.0268
tobool(file.Read()) LUA 0.7317 0.7412 0.7017 0.7473
tobool(file.Read()) GAME 1.0483 1.0855 33.1853 33.2276
Custom file exist (file.Open) LUA 0.5153 0.5275 0.5433 0.6368
Custom file exist (file.Open) GAME 0.7138 0.7270 25.4823 24.9065

Case: 500 addons with a Lua file file and a sound file

Function Search Path CLIENT on main CLIENT on dev SERVER on main SERVER on dev
file.Exists LUA 31.6935 6.1780 17.1791 36.6961 (?)
file.Exists GAME 1.0622 1.0468 36.7566 37.0381
file.IsDir LUA 32.1035 0.5925 17.7347 0.0312 (?)
file.IsDir GAME 0.0132 0.0133 0.0350 0.0334
tobool(file.Read()) LUA 0.7419 0.7580 36.3106 36.5833
tobool(file.Read()) GAME 1.0355 1.0600 36.1863 36.7394
Custom file exist (file.Open) LUA 0.5079 0.5065 28.2398 28.2288
Custom file exist (file.Open) GAME 0.7251 0.7247 28.5915 29.0190

Conclusion

BullyHunter32 commented 8 months ago

Thinks Rubat. I can confirm that the update increased the performance quite a lot, good work on that.

...snip

file.Exists has support for * wildcards, your custom implementation does not however.

wrefgtzweve commented 8 months ago

I did state that my version isnt a drop in replacement. image

Grocel commented 8 months ago

Thinks Rubat. I can confirm that the update increased the performance quite a lot, good work on that. ...snip

file.Exists has support for * wildcards, your custom implementation does not however.

Using wildcards with or without * on file.Exist() or file.IsDir() makes no sense to to honest. For that you would use file.Find() and check the result table to not be empty. If used it to check for binary module, you use this instead: https://wiki.facepunch.com/gmod/util.IsBinaryModuleInstalled

Your issue is represented in: https://github.com/Facepunch/garrysmod-issues/issues/5705

It also seems you missed the entire point of the discussion. The Custom file exist function based file.Open() was just there for a comparison, not as a proper replacement. I would like to recommend to read the entire thing, it has everything you need to know about the issue. The recent update is likely unrelated to the replacement function.

robotboy655 commented 8 months ago

Wildcard search for file.Exists in LUA paths was not intentional, and cannot remain if this performance improvement is desired to stay.

I am also not seeing file.IsDir issue reported where it does not support AddCSLuaFile()'d files clientside. In my tests it does. image

I am able to reproduce slower file.Exists on LUA serverside, but only in the extreme case of 500 single file addons.

Perhaps file.Find and file.Exists scale differently with the amount of mounted paths for some reason.

Grocel commented 8 months ago

I am also not seeing file.IsDir issue reported where it does not support AddCSLuaFile()'d files clientside. In my tests it does.

Please make sure the file/folder does not actually exist physically on the client, like it wouldn't in real life in many cases. A dedicated server is needed to test it properly. If tested on a local listen server the file/folder would be reported to be existing, because of the actual file/folder physically existing, not because it has been transferred via AddCSLuaFile().

My test results have been done on a client connected to a dedicated server that shipped the test files.

robotboy655 commented 8 months ago

The issue was that is was not detecting files in addons/ properly, and will be corrected.