search

BeamMP / BeamMP-Server

Server for the multiplayer mod BeamMP for BeamNG.drive
https://beammp.com
GNU Affero General Public License v3.0
116 stars 49 forks source link

In v3.4.0, calling an event will create an SOL2 assertion failure #317

Closed Neptnium closed 1 month ago

Neptnium commented 1 month ago

Fill out general information OS (windows, linux, ...): BeamMP-Server Version: v3.4.0 (BeamMP-Server.debian.11.x86_64)

Describe the bug When calling an event with MP.TriggerLocalEvent or MP.TriggerGlobalEvent you will get an SOL2 assertion failure. Getting the return value with Future:GetResults() will also make an SOL2 assertion failure. BUT, everything works nomrally execpt for this assertion failure, the right data is passed to the event, and you get the right data that is returned.

To Reproduce Here are examples of code that will make the errors:

function testHandler(data)

end

MP.RegisterEvent("testEvent", "testHandler")
MP.TriggerLocalEvent("testEvent", "test data")

Will make 1 assertion error

function testHandler(data)

end

MP.RegisterEvent("testEvent", "testHandler")
MP.TriggerGlobalEvent("testEvent", "test data")

Will make 1 assertion error

function testHandler(data)
  print(data)
  return "Hey, this is a test"
end

MP.RegisterEvent("testEvent", "testHandler")

local Future = MP.TriggerGlobalEvent("testEvent", "test data")
while not Future:IsDone() do
  MP.Sleep(10)
end
print(Future:GetResults()[1])

Will make 2 assertion errors

Expected behavior No SOL3 assertion failure

Logs (For only 1 assertion error)

[10/05/24 09:55:58] [INFO] BeamMP Server v3.4.0
[10/05/24 09:55:58] [INFO] Loaded 3 Mods
[10/05/24 09:55:58] [INFO] Vehicle data network online on port 31000 with a Max of 64 Clients
[10/05/24 09:55:58] [INFO] Vehicle event network online
[10/05/24 09:55:58] [LUA ERROR] SOL2 assertion failure: Assertion `push_count == 1` failed in /__w/BeamMP-Server/BeamMP-Server/bin/vcpkg_installed/x64-linux/include/sol/stack.hpp:208. This *should* be a fatal error, but BeamMP Server overrides it to not be fatal. This may cause the Lua Engine to crash, or cause other issues.
[10/05/24 09:55:58] [INFO] Server up-to-date!
[10/05/24 09:55:58] [INFO] PluginMonitor started
... and all following is normal
Neptnium commented 1 month ago

Update on tests:

I enabled debug in config and here are the results: For the code:

function testHandler(data)
  print(data)
end

MP.RegisterEvent("testEvent", "testHandler")
MP.TriggerGlobalEvent("testEvent", "test data")

I get the following logs:

[10/05/24 10:23:08.286] [DEBUG] renamed old log file to 'Server.old.log'
[10/05/24 10:23:08.286] [INFO] BeamMP Server v3.4.0
[10/05/24 10:23:08.286] Main [INFO] Loaded 3 Mods
[10/05/24 10:23:08.286] LuaEngine [DEBUG] Creating lua state for state id "!test"
[10/05/24 10:23:08.287] PPSMonitor [DEBUG] PPSMonitor starting
[10/05/24 10:23:08.287] TCPServer [INFO] Vehicle event network online
[10/05/24 10:23:08.287] UDPServer [INFO] Vehicle data network online on port 31000 with a Max of 64 Clients
[10/05/24 10:23:08.287] LuaEngine [DEBUG] Lua plugin "!test" starting in "Resources/Server/!test"
[10/05/24 10:23:08.599] Main [INFO] Server up-to-date!
[10/05/24 10:23:08.599] PluginMonitor [INFO] PluginMonitor started
[10/05/24 10:23:08.787] Lua:!test [LUA ERROR] SOL2 assertion failure: Assertion `push_count == 1` failed in /__w/BeamMP-Server/BeamMP-Server/bin/vcpkg_installed/x64-linux/include/sol/stack.hpp:208. This *should* be a fatal error, but BeamMP Server overrides it to not be fatal. This may cause the Lua Engine to crash, or cause other issues.
[10/05/24 10:23:08.787] Lua:!test [DEBUG] json: ["test data"]
[10/05/24 10:23:08.787] Lua:!test [EVENT] testEvent
[10/05/24 10:23:08.787] Lua:!test [LUA] test data   
[10/05/24 10:23:08.787] LuaEngine [EVENT] onInit
[10/05/24 10:23:13.292] Heartbeat [DEBUG] heartbeat (after 5s)
[10/05/24 10:23:14.103] Main(Waiting) [INFO] ALL SYSTEMS STARTED SUCCESSFULLY, EVERYTHING IS OKAY

I tried running it inside of the onInit event, but I get the same issue:

function testHandler(data)
  print(data)
end

MP.RegisterEvent("testEvent", "testHandler")

function initHandler()
  print("initHandler Called")
  MP.TriggerGlobalEvent("testEvent", "test data")
end
MP.RegisterEvent("onInit", "initHandler")

I get logs:

[10/05/24 10:25:18.176] [DEBUG] renamed old log file to 'Server.old.log'
[10/05/24 10:25:18.176] [INFO] BeamMP Server v3.4.0
[10/05/24 10:25:18.176] Main [INFO] Loaded 3 Mods
[10/05/24 10:25:18.177] PPSMonitor [DEBUG] PPSMonitor starting
[10/05/24 10:25:18.177] LuaEngine [DEBUG] Creating lua state for state id "!test"
[10/05/24 10:25:18.177] TCPServer [INFO] Vehicle event network online
[10/05/24 10:25:18.177] UDPServer [INFO] Vehicle data network online on port 31000 with a Max of 64 Clients
[10/05/24 10:25:18.177] LuaEngine [DEBUG] Lua plugin "!test" starting in "Resources/Server/!test"
[10/05/24 10:25:18.401] Main [INFO] Server up-to-date!
[10/05/24 10:25:18.401] PluginMonitor [INFO] PluginMonitor started
[10/05/24 10:25:18.677] LuaEngine [EVENT] onInit
[10/05/24 10:25:18.677] Lua:!test [LUA] initHandler Called  
[10/05/24 10:25:18.677] Lua:!test [LUA ERROR] SOL2 assertion failure: Assertion `push_count == 1` failed in /__w/BeamMP-Server/BeamMP-Server/bin/vcpkg_installed/x64-linux/include/sol/stack.hpp:208. This *should* be a fatal error, but BeamMP Server overrides it to not be fatal. This may cause the Lua Engine to crash, or cause other issues.
[10/05/24 10:25:18.677] Lua:!test [DEBUG] json: ["test data"]
[10/05/24 10:25:18.677] Lua:!test [EVENT] testEvent
[10/05/24 10:25:18.677] Lua:!test [LUA] test data   
[10/05/24 10:25:23.181] Heartbeat [DEBUG] heartbeat (after 5s)
[10/05/24 10:25:23.905] Main(Waiting) [INFO] ALL SYSTEMS STARTED SUCCESSFULLY, EVERYTHING IS OKAY

Hypothesis : The bug is in the validation of values.

I'm not sure, but will look in the code and keep updated on my findings

Neptnium commented 1 month ago

Update on Tests

Feels like this is the right track, by passing 2 arguments to the event, you will get 2 assertion failures!

function testHandler(data1, data2)
  print(data1, data2)
end

MP.RegisterEvent("testEvent", "testHandler")

MP.TriggerGlobalEvent("testEvent", "test1", "test2")

Log:

[10/05/24 10:52:19.703] [INFO] BeamMP Server v3.4.0
[10/05/24 10:52:19.704] Main [INFO] Loaded 3 Mods
[10/05/24 10:52:19.704] PPSMonitor [DEBUG] PPSMonitor starting
[10/05/24 10:52:19.704] LuaEngine [DEBUG] Creating lua state for state id "!test"
[10/05/24 10:52:19.704] UDPServer [INFO] Vehicle data network online on port 31000 with a Max of 64 Clients
[10/05/24 10:52:19.704] LuaEngine [DEBUG] Lua plugin "!test" starting in "Resources/Server/!test"
[10/05/24 10:52:19.704] TCPServer [INFO] Vehicle event network online
[10/05/24 10:52:19.950] Main [INFO] Server up-to-date!
[10/05/24 10:52:19.950] PluginMonitor [INFO] PluginMonitor started
[10/05/24 10:52:20.204] Lua:!test [LUA ERROR] SOL2 assertion failure: Assertion `push_count == 1` failed in /__w/BeamMP-Server/BeamMP-Server/bin/vcpkg_installed/x64-linux/include/sol/stack.hpp:208. This *should* be a fatal error, but BeamMP Server overrides it to not be fatal. This may cause the Lua Engine to crash, or cause other issues.
[10/05/24 10:52:20.204] Lua:!test [LUA ERROR] SOL2 assertion failure: Assertion `push_count == 1` failed in /__w/BeamMP-Server/BeamMP-Server/bin/vcpkg_installed/x64-linux/include/sol/stack.hpp:208. This *should* be a fatal error, but BeamMP Server overrides it to not be fatal. This may cause the Lua Engine to crash, or cause other issues.
[10/05/24 10:52:20.204] Lua:!test [DEBUG] json: ["test1","test2"]
[10/05/24 10:52:20.204] Lua:!test [EVENT] testEvent
[10/05/24 10:52:20.204] Lua:!test [LUA] test1   test2   
[10/05/24 10:52:20.204] LuaEngine [EVENT] onInit
Neptnium commented 1 month ago

New Update

For me the issue is located here: https://github.com/BeamMP/BeamMP-Server/blob/minor/src/TLuaEngine.cpp#L461-L462

While testing the follwing code:

function testHandler(data1, data2)
  print(data1, data2)
end

MP.RegisterEvent("testEvent", "testHandler")

local test = function() return true end

MP.TriggerGlobalEvent("testEvent", "test Str", test)

I got the following logs:

[10/05/24 11:20:13.344] [DEBUG] renamed old log file to 'Server.old.log'
[10/05/24 11:20:13.344] [INFO] BeamMP Server v3.4.0
[10/05/24 11:20:13.344] Main [INFO] Loaded 3 Mods
[10/05/24 11:20:13.345] LuaEngine [DEBUG] Creating lua state for state id "!test"
[10/05/24 11:20:13.345] PPSMonitor [DEBUG] PPSMonitor starting
[10/05/24 11:20:13.345] UDPServer [INFO] Vehicle data network online on port 31000 with a Max of 64 Clients
[10/05/24 11:20:13.345] LuaEngine [DEBUG] Lua plugin "!test" starting in "Resources/Server/!test"
[10/05/24 11:20:13.345] TCPServer [INFO] Vehicle event network online
[10/05/24 11:20:13.345] Lua:!test [LUA ERROR] SOL2 assertion failure: Assertion `push_count == 1` failed in /__w/BeamMP-Server/BeamMP-Server/bin/vcpkg_installed/x64-linux/include/sol/stack.hpp:208. This *should* be a fatal error, but BeamMP Server overrides it to not be fatal. This may cause the Lua Engine to crash, or cause other issues.
[10/05/24 11:20:13.345] Lua:!test [LUA ERROR] SOL2 assertion failure: Assertion `push_count == 1` failed in /__w/BeamMP-Server/BeamMP-Server/bin/vcpkg_installed/x64-linux/include/sol/stack.hpp:208. This *should* be a fatal error, but BeamMP Server overrides it to not be fatal. This may cause the Lua Engine to crash, or cause other issues.
[10/05/24 11:20:13.345] Lua:!test [WARN] Passed a value of type 'function' to TriggerGlobalEvent("testEvent", ...). This type can not be serialized, and cannot be passed between states. It will arrive as <nil> in handlers.
[10/05/24 11:20:13.345] Lua:!test [DEBUG] json: ["test Str","BEAMMP_SERVER_INTERNAL_NIL_VALUE"]
[10/05/24 11:20:13.345] Lua:!test [EVENT] testEvent
[10/05/24 11:20:13.345] Lua:!test [LUA] test Str    <nil>   
[10/05/24 11:20:13.345] LuaEngine [EVENT] onInit
[10/05/24 11:20:13.588] Main [INFO] Server up-to-date!

The interesting part is:

[10/05/24 11:20:13.345] Lua:!test [LUA ERROR] SOL2 assertion failure: Assertion `push_count == 1` failed in /__w/BeamMP-Server/BeamMP-Server/bin/vcpkg_installed/x64-linux/include/sol/stack.hpp:208. This *should* be a fatal error, but BeamMP Server overrides it to not be fatal. This may cause the Lua Engine to crash, or cause other issues.
[10/05/24 11:20:13.345] Lua:!test [LUA ERROR] SOL2 assertion failure: Assertion `push_count == 1` failed in /__w/BeamMP-Server/BeamMP-Server/bin/vcpkg_installed/x64-linux/include/sol/stack.hpp:208. This *should* be a fatal error, but BeamMP Server overrides it to not be fatal. This may cause the Lua Engine to crash, or cause other issues.
[10/05/24 11:20:13.345] Lua:!test [WARN] Passed a value of type 'function' to TriggerGlobalEvent("testEvent", ...). This type can not be serialized, and cannot be passed between states. It will arrive as <nil> in handlers.
[10/05/24 11:20:13.345] Lua:!test [DEBUG] json: ["test Str","BEAMMP_SERVER_INTERNAL_NIL_VALUE"]
[10/05/24 11:20:13.345] Lua:!test [EVENT] testEvent
[10/05/24 11:20:13.345] Lua:!test [LUA] test Str    <nil>

Which tells me that the issue is before the type validation for the arguments, and the fact that by passing 2 args, i get the error twice makes me think that is is located between line 461 and 462!

Neptnium commented 1 month ago

Update

It could also be Table.add that causes the issue https://github.com/BeamMP/BeamMP-Server/blob/minor/src/TLuaEngine.cpp#L469 https://github.com/BeamMP/BeamMP-Server/blob/minor/src/TLuaEngine.cpp#L473 https://github.com/BeamMP/BeamMP-Server/blob/minor/src/TLuaEngine.cpp#L479

All of this seems to correspond to raw_table_set of SOL2's stack.hpp function wich calls SOL_ASSERT(push_count == 1);

lionkor commented 1 month ago

Update

It could also be Table.add that causes the issue https://github.com/BeamMP/BeamMP-Server/blob/minor/src/TLuaEngine.cpp#L469 https://github.com/BeamMP/BeamMP-Server/blob/minor/src/TLuaEngine.cpp#L473 https://github.com/BeamMP/BeamMP-Server/blob/minor/src/TLuaEngine.cpp#L479

All of this seems to correspond to raw_table_set of SOL2's stack.hpp function wich calls SOL_ASSERT(push_count == 1);

it was exactly this, thank you very much :)

lionkor commented 1 month ago

I wrote this in the commit for the fix as well, but basically, the behavior of add is not well defined when the table is not sequential, and we're also using it in a bit of an odd way. Replacing it with set and some boilerplate seems to work fine!

Neptnium commented 1 month ago

I wrote this in the commit for the fix as well, but basically, the behavior of add is not well defined when the table is not sequential, and we're also using it in a bit of an odd way. Replacing it with set and some boilerplate seems to work fine!

Ok, this explains it, Thanks a lot for the quick fix !!!