Writing Scripting Data ... PANIC: unprotected error in call to Lua API

[TiborB]

Hi,

when testing the game I crashed (in fact it is second time now) .

last lines on the console
...
Writing Exploration Data ... took 22ms
 Writing Players Unseen Data ... took 96ms
 Writing Scripting Data ... PANIC: unprotected error in call to Lua API (attempt to persist a light C function (0x8b93c45))

and backtrace:

#0 0xb7fe1424 in __kernel_vsyscall ()
#1 0xb794aa31 in *__GI_raise (sig=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#2 0xb794de62 in *__GI_abort () at abort.c:92
#3 0x08b842fe in luaD_throw (L=0x98e1588, errcode=2) at /var/widelands/tibor-ai5/src/third_party/eris/ldo.c:119
#4 0x08b84125 in luaG_errormsg (L=0x98e1588) at /var/widelands/tibor-ai5/src/third_party/eris/ldebug.c:582
#5 0x08b7dc2a in lua_error (L=0x98e1588) at /var/widelands/tibor-ai5/src/third_party/eris/lapi.c:1108
#6 0x08b76054 in eris_error (info=0xbfffc26c, fmt=0x900b238 "attempt to persist a light C function (%p)")
    at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:380
#7 0x08b78605 in p_closure (info=0xbfffc26c) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:1357
#8 0x08b7a099 in persist_typed (info=0xbfffc26c, type=6) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2021
#9 0x08b7a2c4 in persist_keyed (info=0xbfffc26c, type=6) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2088
#10 0x08b7a368 in persist (info=0xbfffc26c) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2116
#11 0x08b76e7a in p_literaltable (info=0xbfffc26c) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:876
#12 0x08b7744e in p_special (info=0xbfffc26c, literal=0x8b76d52 <p_literaltable>) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:1018
#13 0x08b77663 in p_table (info=0xbfffc26c) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:1071
#14 0x08b7a08c in persist_typed (info=0xbfffc26c, type=5) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2018
#15 0x08b7a2c4 in persist_keyed (info=0xbfffc26c, type=5) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2088
#16 0x08b7a368 in persist (info=0xbfffc26c) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2116
#17 0x08b76e7a in p_literaltable (info=0xbfffc26c) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:876
#18 0x08b7744e in p_special (info=0xbfffc26c, literal=0x8b76d52 <p_literaltable>) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:1018
#19 0x08b77663 in p_table (info=0xbfffc26c) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:1071
#20 0x08b7a08c in persist_typed (info=0xbfffc26c, type=5) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2018
#21 0x08b7a2c4 in persist_keyed (info=0xbfffc26c, type=5) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2088
#22 0x08b7a368 in persist (info=0xbfffc26c) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2116
#23 0x08b784f5 in p_upval (info=0xbfffc26c) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:1322
#24 0x08b7a0cd in persist_typed (info=0xbfffc26c, type=10) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2033
#25 0x08b7a2c4 in persist_keyed (info=0xbfffc26c, type=10) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2088
#26 0x08b7887a in p_closure (info=0xbfffc26c) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:1416
#27 0x08b7a099 in persist_typed (info=0xbfffc26c, type=6) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2021
#28 0x08b7a2c4 in persist_keyed (info=0xbfffc26c, type=6) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2088
#29 0x08b7a368 in persist (info=0xbfffc26c) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2116
#30 0x08b76e7a in p_literaltable (info=0xbfffc26c) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:876
#31 0x08b7744e in p_special (info=0xbfffc26c, literal=0x8b76d52 <p_literaltable>) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:1018
#32 0x08b77663 in p_table (info=0xbfffc26c) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:1071
#33 0x08b7a08c in persist_typed (info=0xbfffc26c, type=5) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2018
#34 0x08b7a2c4 in persist_keyed (info=0xbfffc26c, type=5) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2088
#35 0x08b7a368 in persist (info=0xbfffc26c) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2116
#36 0x08b7ac49 in unchecked_persist (L=0x98e1588, writer=0x8aea4c0 <(anonymous namespace)::LuaWriter(lua_State*, void const*, size_t, void*)>,
    ud=0xbfffc374) at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2379
#37 0x08b7b697 in eris_dump (L=0x98e1588, writer=0x8aea4c0 <(anonymous namespace)::LuaWriter(lua_State*, void const*, size_t, void*)>, ud=0xbfffc374)
    at /var/widelands/tibor-ai5/src/third_party/eris/eris.c:2607
#38 0x08aeaca4 in persist_object (L=0x98e1588, fw=..., mos=...) at /var/widelands/tibor-ai5/src/scripting/persistence.cc:212
#39 0x08ad687c in LuaGameInterface::write_global_env (this=0x994d5e0, fw=..., mos=...) at /var/widelands/tibor-ai5/src/scripting/scripting.cc:387

regards

[wl-zocker (wl-zocker)]

I also saw this error several times in trunk (last one was in r7194 on Win7). I have no backtrace, but the stdout ended with the same lines. Not that in bug 1342554, several people reported about similar issues (especially comment #3).

[SirVer (sirver)]

I changed our use of eris to now give more information on this crash in r7203. This makes saving much slower, but should help tracking this issue down.

[GunChleoc (gunchleoc)]

I think I am getting the same error. Version: Widelands bzr7218[trunk](Debug), Ubuntu 14.04.

To reproduce, start a single player game, build a Lumberjack's hut, open the buildingwindow and the building's help window, then wait for the autosave.

The crash only occurs when the help window is open.

Autosave: interval elapsed (60 s), saving
Game: Writing Preload Data ... took 3ms
Game: Writing Game Class Data ... took 0ms
Game: Writing Player Info ... took 2ms
Game: Writing Map Data!
Writing Elemental Data ... took 1ms
 Writing Player Names And Tribe Data ... took 0ms
 Writing Port Spaces Data ... took 0ms
 Writing Heights Data ... took 1ms
 Writing Terrain Data ... took 8ms
 Writing Player Start Position Data ... took 1ms
 Writing Player Message Data ... took 0ms
 Writing Resources Data ... took 2ms
 Writing Map Extra Data ... took 1ms
 Writing Map Version ... took 0ms
 Writing Allowed Worker Types Data ... took 0ms
 Writing Flag Data ... took 1ms
 Writing Road Data ... took 0ms
 Writing Building Data ... took 2ms
 Writing Map Objects ... took 5ms
 Writing Flagdata Data ... took 1ms
 Writing Roaddata Data ... took 0ms
 Writing Buildingdata Data ... took 2ms
 Writing Node Ownership Data ... took 1ms
 Writing Exploration Data ... took 1ms
 Writing Players Unseen Data ... took 3ms
 Writing Scripting Data ... PANIC: unprotected error in call to Lua API (attempt to persist a light C function (0x1040f0a) (root.add_walking_animations.upvalues._ENV.string.rep))
Aborted (core dumped)

[Hans Joachim Desserud (hjd)]

I was able to trigger a crash using GunChleoc's instructions. The stacktrace I got looks like the same as Tibor's.

Since we are able to trigger it at will, I reckon this has enough information for someone to start looking into what's happening.

[GunChleoc (gunchleoc)]

I traced this bug back to http://bazaar.launchpad.net/~widelands-dev/widelands/trunk/revision/7103 where we introduced the new help windows. It has been around for 3 months without anybody noticing, so I think it is a prime candidate for an automated test, if one can be written.

[wl-zocker (wl-zocker)]

The underlying issue might be that UI elements cannot be persisted. See https://wl.widelands.org/docs/wl/autogen_wl_ui/

Has there been some other change which brought this to daylight? I cannot imagine that no one had the help window open when the autosave happened for three months.

[GunChleoc (gunchleoc)]

No, this is definitely the revision that is causing the bug. I did a bzr revert on it. r7102 s fine, r7103 crashes.

[GunChleoc (gunchleoc)]

This is what happens in helpwindow.cc:

  std::unique_ptr<LuaTable> t(
     lua->run_script(building_description.helptext_script()));
  std::unique_ptr<LuaCoroutine> cr(t->get_coroutine("func"));
  cr->push_arg(&building_description);
  cr->resume();
  const std::string help_text = cr->pop_string();
  textarea->set_text(help_text);

If I comment out "cr->resume();" the crash is gone, but so is the helptext. So, we seem to have an undead coroutine kicking around causing trouble. I tried resetting the pointers just for kicks, but that doesn't make a difference.

[SirVer (sirver)]

Should be fixed in r7222.

This was the problem: Some methods in format_help defined a variable "string" this way:

string = "blub" (instead of the correct 'local string = "blub"')

The problem here now is that all Lua methods share the same namespace - the global namespace - and that lua variables are global by default. So this little line did a ton of damage: it replaced the global string library [1] through an instance of a string. this did not do much trouble while running (since a string instance has all the methods of the string library), but on serilization, we did not know how to serialize the c methods of a string instance (we only know that we should not serialize the methods of the string library - but this one is gone).

I am quite concerned about this. It is a simple mistake to make and it could have been made in a scenario instead of a help text and would break saving of this scenario. Alas, I have no idea how to avoid it in the future. Quick googling found only this: http://stackoverflow.com/questions/7145984/making-global-environment-access-only-lua

Maybe having a Lua linter would help too - to make sure all variable declarations are always local.

[1] http://www.lua.org/pil/20.html

[GunChleoc (gunchleoc)]

It would be great if we could have something like codecheck.py for Lua as well - no idea how much work that would be though. Something like this maybe? https://code.google.com/p/lua-checker/

[SirVer (sirver)]

Something like this would be great. But the project you link too hasn't been updated in 6 years and only has 7 commits, so that is probably not what we need :).

[Hans Joachim Desserud (hjd)]

I haven't looked at any specific ones, but multiple tools exists http://lua-users.org/wiki/ProgramAnalysis. For investigation it should be easy to simply run them on the code base and note what sort of issues they find (if any).

[SirVer (sirver)]

This might be relevant too: http://lua-users.org/wiki/DetectingUndefinedVariables

Note though that whatever we come up, if we do not find a way to deploy it inside of Widelands, we can only lint our own lua scripts, not those of other people making campaigns. Having confidencen in the correctness of our own stuff would go a long way though.

[SirVer (sirver)]

There is lua_inspect here https://github.com/davidm/lua-inspect, which seems mature but has not been updated in 2 years.
And https://github.com/mpeterv/luacheck which seems mature and maintained. I would start testing here if somebody is interested in digging into this issue.

[GunChleoc (gunchleoc)]

Fixed in build19-rc1.