[Tarantool-patches] [PATCH luajit v2 1/2] Print errors from __gc finalizers instead of rethrowing them.

[Maksim Kokryashkin via Tarantool-patches <tarantool-patches@dev.tarantool.org>]

From: Mike Pall <mike>

Finalizers are not supposed to throw errors -- this is undefined behavior.
Lua 5.1 - 5.3 and (previously) LuaJIT rethrow the error. This randomly
breaks some unrelated code that just happens to do an allocation. Bad.
Lua 5.4 catches the error and emits a warning instead. But warnings are
not enabled by default, so it fails silently. Even worse.
LuaJIT (now) catches the error and emits a VM event. The default event
handler function prints "ERROR in finalizer: ...".
Set a custom handler function with: jit.attach(handler, "errfin")

(cherry-picked from commit 1c279127050e86e99970100e9c42e0f09cd54ab7)

The default handler for finalizer errors is set during the
Lua initialization. Namely, in the `luaL_newstate`.

Along with the introduction of the new `ERRFIN` VM event, the high
bits for the old VM events are removed since they are scratched
anyway by the bitwise operation `(hash)<<3` in the `VMEVENT_DEF`
macro.

This patch results in a regression in the PUC-Rio test suite. The
test in the suite for the error in the GC finalizer fails after
the patch because the error is now handled with the VM event
handler instead of being rethrown. Hence, the `collectgarbage`
finishes successfully despite the error in the GC finalizer.
Considering this change, the test was disabled.

There is also another regression in the `misclib-getmetrics-capi`,
because there are a few test cases reliant on the `lua_gettop(L)`
value, which is broken after this patch. The `_VMEVENTS` table,
where the error handler for GC finalizers is set, was not cleared
from the stack after the initialization. This issue is fixed in
the following patch.

Maxim Kokryashkin:
* added the test for the problem and the description for the patch

Part of tarantool/tarantool#9145
---
Q:
>> +-- The test below is disabled for LuaJIT, since it handles errors from
>> +-- GC finalizers via VM event.
>> -- errors during collection
>> -u = newproxy(true)
>> -getmetatable(u).__gc = function () error "!!!" end
>> -u = nil
>> -assert(not pcall(collectgarbage))
>> -
>> +-- u = newproxy(true)
>> +-- getmetatable(u).__gc = function () error "!!!" end
>> +-- u = nil
>> +-- assert(not pcall(collectgarbage))
>>
>
>Maybe its better just to setup the "errfin" handler to `error()` function?

A: Well, that is not going to fix the test case anyway. See, the
`lj_vmevent_call` is a protected call and any errros which happened
during the vmevent handling are silently printed into the stderr. So
the collectgarbage call here won't fail even in this case.

Q:
>> +local function errfin_handler()
>> + error_in_finalizer = true
>> +end
>
>Is it better just to add `test:ok(true, 'error handler called')` here?

A: Nope, because I want to test not only that there is no error, but
also that the finalizer error handler was called.


Q: I suggest to test the default handler too, within the separate test.

Also, maybe we should test other cases (error function (in default
case), function with tailcall to error, etc.), any ideas about them?

A: I've added a test for the default handler. I doubt that testing
for other cases you have mentioned is meaningful, because all of
these errors are going to be silently printed into the stderr.

 src/Makefile.dep.original                     | 14 +++----
 src/lib_aux.c                                 | 33 ++++++++++++++-
 src/lj_gc.c                                   | 10 ++++-
 src/lj_vmevent.h                              |  7 ++--
 test/PUC-Rio-Lua-5.1-tests/gc.lua             | 12 +++---
 ...6-print-errors-from-gc-fin-custom.test.lua | 42 +++++++++++++++++++
 ...-print-errors-from-gc-fin-default.test.lua | 11 +++++
 .../script.lua                                | 24 +++++++++++
 8 files changed, 133 insertions(+), 20 deletions(-)
 create mode 100644 test/tarantool-tests/lj-946-print-errors-from-gc-fin-custom.test.lua
 create mode 100644 test/tarantool-tests/lj-946-print-errors-from-gc-fin-default.test.lua
 create mode 100644 test/tarantool-tests/lj-946-print-errors-from-gc-fin-default/script.lua

diff --git a/src/Makefile.dep.original b/src/Makefile.dep.original
index d35b6d9a..53426a7e 100644
--- a/src/Makefile.dep.original
+++ b/src/Makefile.dep.original
@@ -1,6 +1,6 @@
 lib_aux.o: lib_aux.c lua.h luaconf.h lauxlib.h lj_obj.h lj_def.h \
  lj_arch.h lj_err.h lj_errmsg.h lj_state.h lj_trace.h lj_jit.h lj_ir.h \
- lj_dispatch.h lj_bc.h lj_traceerr.h lj_lib.h lj_alloc.h
+ lj_dispatch.h lj_bc.h lj_traceerr.h lj_lib.h lj_alloc.h lj_vmevent.h
 lib_base.o: lib_base.c lua.h luaconf.h lauxlib.h lualib.h lj_obj.h \
  lj_def.h lj_arch.h lj_gc.h lj_err.h lj_errmsg.h lj_debug.h lj_str.h \
  lj_tab.h lj_meta.h lj_state.h lj_frame.h lj_bc.h lj_ctype.h lj_cconv.h \
@@ -123,7 +123,7 @@ lj_func.o: lj_func.c lj_obj.h lua.h luaconf.h lj_def.h lj_arch.h lj_gc.h \
 lj_gc.o: lj_gc.c lj_obj.h lua.h luaconf.h lj_def.h lj_arch.h lj_gc.h \
  lj_err.h lj_errmsg.h lj_buf.h lj_str.h lj_tab.h lj_func.h lj_udata.h \
  lj_meta.h lj_state.h lj_frame.h lj_bc.h lj_ctype.h lj_cdata.h lj_trace.h \
- lj_jit.h lj_ir.h lj_dispatch.h lj_traceerr.h lj_vm.h
+ lj_jit.h lj_ir.h lj_dispatch.h lj_traceerr.h lj_vm.h lj_vmevent.h
 lj_gdbjit.o: lj_gdbjit.c lj_obj.h lua.h luaconf.h lj_def.h lj_arch.h \
  lj_gc.h lj_err.h lj_errmsg.h lj_debug.h lj_frame.h lj_bc.h lj_buf.h \
  lj_str.h lj_strfmt.h lj_jit.h lj_ir.h lj_dispatch.h
@@ -238,11 +238,11 @@ ljamalg.o: ljamalg.c lua.h luaconf.h lauxlib.h lj_assert.c lj_obj.h lj_def.h \
  lj_arch.h lj_gc.c lj_gc.h lj_err.h lj_errmsg.h lj_buf.h lj_str.h lj_tab.h \
  lj_func.h lj_udata.h lj_meta.h lj_state.h lj_frame.h lj_bc.h lj_ctype.h \
  lj_cdata.h lj_trace.h lj_jit.h lj_ir.h lj_dispatch.h lj_traceerr.h \
- lj_vm.h lj_err.c lj_debug.h lj_ff.h lj_ffdef.h lj_strfmt.h lj_char.c \
- lj_char.h lj_bc.c lj_bcdef.h lj_obj.c lj_buf.c lj_wbuf.c lj_wbuf.h lj_utils.h \
- lj_str.c lj_tab.c lj_func.c lj_udata.c lj_meta.c lj_strscan.h lj_lib.h \
- lj_debug.c lj_state.c lj_lex.h lj_alloc.h luajit.h lj_dispatch.c \
- lj_ccallback.h lj_profile.h lj_memprof.h lj_vmevent.c lj_vmevent.h \
+ lj_vm.h lj_vmevent.h lj_err.c lj_debug.h lj_ff.h lj_ffdef.h lj_strfmt.h \
+ lj_char.c lj_char.h lj_bc.c lj_bcdef.h lj_obj.c lj_buf.c lj_wbuf.c lj_wbuf.h \
+ lj_utils.h lj_str.c lj_tab.c lj_func.c lj_udata.c lj_meta.c lj_strscan.h \
+ lj_lib.h lj_debug.c lj_state.c lj_lex.h lj_alloc.h luajit.h lj_dispatch.c \
+ lj_ccallback.h lj_profile.h lj_memprof.h lj_vmevent.c \
  lj_vmmath.c lj_strscan.c lj_strfmt.c lj_strfmt_num.c lj_api.c lj_mapi.c \
  lmisclib.h lj_profile.c lj_profile_timer.h lj_profile_timer.c \
  lj_memprof.c lj_lex.c lualib.h lj_parse.h lj_parse.c lj_bcread.c \
diff --git a/src/lib_aux.c b/src/lib_aux.c
index c40565c3..d532a12f 100644
--- a/src/lib_aux.c
+++ b/src/lib_aux.c
@@ -21,6 +21,7 @@
 #include "lj_state.h"
 #include "lj_trace.h"
 #include "lj_lib.h"
+#include "lj_vmevent.h"

 #if LJ_TARGET_POSIX
 #include <sys/wait.h>
@@ -311,6 +312,18 @@ static int panic(lua_State *L)
   return 0;
 }

+#ifndef LUAJIT_DISABLE_VMEVENT
+static int error_finalizer(lua_State *L)
+{
+  const char *s = lua_tostring(L, -1);
+  fputs("ERROR in finalizer: ", stderr);
+  fputs(s ? s : "?", stderr);
+  fputc('\n', stderr);
+  fflush(stderr);
+  return 0;
+}
+#endif
+
 #ifdef LUAJIT_USE_SYSMALLOC

 #if LJ_64 && !LJ_GC64 && !defined(LUAJIT_USE_VALGRIND)
@@ -332,7 +345,15 @@ static void *mem_alloc(void *ud, void *ptr, size_t osize, size_t nsize)
 LUALIB_API lua_State *luaL_newstate(void)
 {
   lua_State *L = lua_newstate(mem_alloc, NULL);
-  if (L) G(L)->panic = panic;
+  if (L) {
+    G(L)->panic = panic;
+#ifndef LUAJIT_DISABLE_VMEVENT
+    luaL_findtable(L, LUA_REGISTRYINDEX, LJ_VMEVENTS_REGKEY, LJ_VMEVENTS_HSIZE);
+    lua_pushcfunction(L, error_finalizer);
+    lua_rawseti(L, -2, VMEVENT_HASH(LJ_VMEVENT_ERRFIN));
+    G(L)->vmevmask = VMEVENT_MASK(LJ_VMEVENT_ERRFIN);
+#endif
+  }
   return L;
 }

@@ -350,7 +371,15 @@ LUALIB_API lua_State *luaL_newstate(void)
 #else
   L = lua_newstate(lj_alloc_f, ud);
 #endif
-  if (L) G(L)->panic = panic;
+  if (L) {
+    G(L)->panic = panic;
+#ifndef LUAJIT_DISABLE_VMEVENT
+    luaL_findtable(L, LUA_REGISTRYINDEX, LJ_VMEVENTS_REGKEY, LJ_VMEVENTS_HSIZE);
+    lua_pushcfunction(L, error_finalizer);
+    lua_rawseti(L, -2, VMEVENT_HASH(LJ_VMEVENT_ERRFIN));
+    G(L)->vmevmask = VMEVENT_MASK(LJ_VMEVENT_ERRFIN);
+#endif
+  }
   return L;
 }

diff --git a/src/lj_gc.c b/src/lj_gc.c
index 19d4c963..591862b3 100644
--- a/src/lj_gc.c
+++ b/src/lj_gc.c
@@ -27,6 +27,7 @@
 #include "lj_trace.h"
 #include "lj_dispatch.h"
 #include "lj_vm.h"
+#include "lj_vmevent.h"

 #define GCSTEPSIZE	1024u
 #define GCSWEEPMAX	40
@@ -515,8 +516,13 @@ static void gc_call_finalizer(global_State *g, lua_State *L,
   hook_restore(g, oldh);
   if (LJ_HASPROFILE && (oldh & HOOK_PROFILE)) lj_dispatch_update(g);
   g->gc.threshold = oldt;  /* Restore GC threshold. */
-  if (errcode)
-    lj_err_throw(L, errcode);  /* Propagate errors. */
+  if (errcode) {
+    ptrdiff_t errobj = savestack(L, L->top-1);  /* Stack may be resized. */
+    lj_vmevent_send(L, ERRFIN,
+      copyTV(L, L->top++, restorestack(L, errobj));
+    );
+    L->top--;
+  }
 }

 /* Finalize one userdata or cdata object from the mmudata list. */
diff --git a/src/lj_vmevent.h b/src/lj_vmevent.h
index 050fb4dd..56c0d798 100644
--- a/src/lj_vmevent.h
+++ b/src/lj_vmevent.h
@@ -24,9 +24,10 @@
 /* VM event IDs. */
 typedef enum {
   VMEVENT_DEF(BC,	0x00003883),
-  VMEVENT_DEF(TRACE,	0xb2d91467),
-  VMEVENT_DEF(RECORD,	0x9284bf4f),
-  VMEVENT_DEF(TEXIT,	0xb29df2b0),
+  VMEVENT_DEF(TRACE,	0x12d91467),
+  VMEVENT_DEF(RECORD,	0x1284bf4f),
+  VMEVENT_DEF(TEXIT,	0x129df2b0),
+  VMEVENT_DEF(ERRFIN,	0x12d93888),
   LJ_VMEVENT__MAX
 } VMEvent;

diff --git a/test/PUC-Rio-Lua-5.1-tests/gc.lua b/test/PUC-Rio-Lua-5.1-tests/gc.lua
index 10e1f2dd..05ac0d11 100644
--- a/test/PUC-Rio-Lua-5.1-tests/gc.lua
+++ b/test/PUC-Rio-Lua-5.1-tests/gc.lua
@@ -260,13 +260,13 @@ u, m = nil
 collectgarbage()
 assert(m==10)

-
+-- The test below is disabled for LuaJIT, since it handles errors from
+-- GC finalizers via VM event.
 -- errors during collection
-u = newproxy(true)
-getmetatable(u).__gc = function () error "!!!" end
-u = nil
-assert(not pcall(collectgarbage))
-
+-- u = newproxy(true)
+-- getmetatable(u).__gc = function () error "!!!" end
+-- u = nil
+-- assert(not pcall(collectgarbage))

 if not rawget(_G, "_soft") then
   print("deep structures")
diff --git a/test/tarantool-tests/lj-946-print-errors-from-gc-fin-custom.test.lua b/test/tarantool-tests/lj-946-print-errors-from-gc-fin-custom.test.lua
new file mode 100644
index 00000000..71efc260
--- /dev/null
+++ b/test/tarantool-tests/lj-946-print-errors-from-gc-fin-custom.test.lua
@@ -0,0 +1,42 @@
+local tap = require('tap')
+local test = tap.test('lj-946-print-errors-from-gc-fin-custom'):skipcond({
+  ['Test requires JIT enabled'] = not jit.status(),
+})
+
+test:plan(2)
+
+local ffi = require('ffi')
+local error_in_finalizer = false
+
+local function errfin_handler()
+    error_in_finalizer = true
+end
+
+local function new_bad_cdata()
+  return ffi.gc(ffi.new('char [?]', 1024), 'uncallable string')
+end
+
+local function test_f()
+  collectgarbage('collect')
+  -- Make GC aggressive enough to end the atomic phase before
+  -- exiting the trace.
+  collectgarbage('setstepmul', 400)
+  -- The number of iterations is empirical, just big enough for the
+  -- issue to strike.
+  for _ = 1, 4000 do
+    new_bad_cdata()
+  end
+end
+
+jit.opt.start('hotloop=1')
+-- Handler is registered but never called before the patch.
+-- It should be called after the patch.
+jit.attach(errfin_handler, 'errfin')
+local status = pcall(test_f)
+-- We have to stop GC now because any step raises the error due to
+-- cursed cdata objects.
+collectgarbage('stop')
+test:ok(status, 'test function completed successfully')
+test:ok(error_in_finalizer, 'error handler called')
+
+test:done(true)
diff --git a/test/tarantool-tests/lj-946-print-errors-from-gc-fin-default.test.lua b/test/tarantool-tests/lj-946-print-errors-from-gc-fin-default.test.lua
new file mode 100644
index 00000000..dfef11e5
--- /dev/null
+++ b/test/tarantool-tests/lj-946-print-errors-from-gc-fin-default.test.lua
@@ -0,0 +1,11 @@
+local tap = require('tap')
+local test = tap.test('lj-flush-on-trace'):skipcond({
+  ['Test requires JIT enabled'] = not jit.status(),
+})
+
+test:plan(1)
+
+local script = require('utils').exec.makecmd(arg, { redirect = '2>&1' })
+local output = script()
+test:like(output, '.*ERROR in finalizer:.*')
+test:done(true)
diff --git a/test/tarantool-tests/lj-946-print-errors-from-gc-fin-default/script.lua b/test/tarantool-tests/lj-946-print-errors-from-gc-fin-default/script.lua
new file mode 100644
index 00000000..fdd9ced1
--- /dev/null
+++ b/test/tarantool-tests/lj-946-print-errors-from-gc-fin-default/script.lua
@@ -0,0 +1,24 @@
+local ffi = require('ffi')
+
+local function new_bad_cdata()
+  return ffi.gc(ffi.new('char [?]', 1024), 'uncallable string')
+end
+
+local function test_f()
+  collectgarbage('collect')
+  -- Make GC aggressive enough to end the atomic phase before
+  -- exiting the trace.
+  collectgarbage('setstepmul', 400)
+  -- The number of iterations is empirical, just big enough for the
+  -- issue to strike.
+  for _ = 1, 4000 do
+    new_bad_cdata()
+  end
+end
+
+jit.opt.start('hotloop=1')
+local status = pcall(test_f)
+-- We have to stop GC now because any step raises the error due to
+-- cursed cdata objects.
+collectgarbage('stop')
+assert(status, 'error is not rethrown')
--
2.39.3 (Apple Git-145)