From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from smtp36.i.mail.ru (smtp36.i.mail.ru [94.100.177.96]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by dev.tarantool.org (Postfix) with ESMTPS id 765644696C3 for ; Tue, 14 Apr 2020 04:11:44 +0300 (MSK) References: From: Vladislav Shpilevoy Message-ID: Date: Tue, 14 Apr 2020 03:11:42 +0200 MIME-Version: 1.0 In-Reply-To: Content-Type: text/plain; charset=utf-8 Content-Language: en-US Content-Transfer-Encoding: 7bit Subject: Re: [Tarantool-patches] [PATCH v2 1/5] error: Add a Lua backtrace to error List-Id: Tarantool development patches List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: Leonid Vasiliev Cc: tarantool-patches@dev.tarantool.org Thanks for the patch! Sorry, some of my comments may contain typos, because it is very late and I can't continue polishing it today. First of all there are some major issues with the patch, which IMO should be clarified before it is pushed. 1) Why do we need the traceback in scope of 4398? It has nothing to do with marshaling through IProto, nor with custom error types. 2) What to do with stacked errors? Currently only the first error in the stack gets a traceback, because luaT_pusherror() is called only on the top error in the stack. Consider this test: box.cfg{} lua_code = [[function(tuple) local json = require('json') return json.encode(tuple) end]] box.schema.func.create('runtimeerror', {body = lua_code, is_deterministic = true, is_sandboxed = true}) s = box.schema.space.create('withdata') pk = s:create_index('pk') idx = s:create_index('idx', {func = box.func.runtimeerror.id, parts = {{1, 'string'}}}) function test_func() return pcall(s.insert, s, {1}) end box.error.cfg{traceback_enable = true} ok, err = test_func() tarantool> err:unpack() --- - traceback: "stack traceback:\n\t[C]: at 0x010014d1b0\n\t[C]: in function 'test_func'\n\t[string \"ok, err = test_func()\"]:1: in main chunk\n\t[C]: in function 'pcall'\n\tbuiltin/box/console.lua:382: in function 'eval'\n\tbuiltin/box/console.lua:676: in function 'repl'\n\tbuiltin/box/console.lua:725: in function " ... tarantool> err.prev:unpack() --- - type: LuajitError message: '[string "return function(tuple)..."]:2: attempt to call global ''require'' (a nil value)' ... The second error does not have a traceback at all. See 10 comments below. Also I started a new branch with review fixes to speed up the process. The branch is called lvasiliev/gh-4398-expose-error-module-4-review You can find review fixes to this commit in the end of the email and on this branch in a separate commit. Note, my branch is rebased on master already. So some changes are related to cleaning the mess after it. On 10/04/2020 10:10, Leonid Vasiliev wrote: > In accordance with https://github.com/tarantool/tarantool/issues/4398 1. We don't put links when issue is in the same repository. We always use '#' reference. This concerns this and all next commits. > Lua traceback has been added for box.error. > Has been added a per server flag for turn on/off traceback adding > and ability to force it at creation time. > > @TarantoolBot document > Title: error.traceback > Was added: > Per server flag for turn on/off adding a traceback to the errors. > box.error.cfg({traceback_supplementation = true/false}) 2. The option name is utterly overcomplicated. Just use traceback_enable > Adding a traceback can be forced on creation. > box.error.new({type = "CustomType", reason = "reason", traceback = true/false}) 3. CustomType errors are not defined here, you can't use it in the request description. > Needed for #4398 4. Please, don't put issue references inside docbot requests. This concerns this and all next commits. > --- > src/box/lua/error.cc | 33 ++++++++++++++++++++++++++++++++- > src/lib/core/diag.c | 32 ++++++++++++++++++++++++++++++++ > src/lib/core/diag.h | 11 +++++++++++ > src/lib/core/exception.cc | 1 + > src/lua/error.c | 10 ++++++++++ > src/lua/error.lua | 12 +++++++++++- > test/app/fiber.result | 5 +++-- > test/box/error.result | 5 +++-- > test/engine/func_index.result | 10 ++++++---- > 9 files changed, 109 insertions(+), 10 deletions(-) > > diff --git a/src/box/lua/error.cc b/src/box/lua/error.cc > index b2625bf..4432bc8 100644 > --- a/src/box/lua/error.cc > +++ b/src/box/lua/error.cc> @@ -180,6 +193,20 @@ luaT_error_set(struct lua_State *L) > } > > static int > +luaT_error_cfg(struct lua_State *L) > +{ > + if (lua_gettop(L) < 1 || !lua_istable(L, 1)) > + return luaL_error(L, "Usage: box.error.cfg({}})"); > + > + lua_getfield(L, 1, "traceback_supplementation"); > + if (lua_isnil(L, -1) == 0) 5. If something is not nil, it does not mean it is a boolean. Better check lua_isboolean(). > + error_set_traceback_supplementation(lua_toboolean(L, -1)); > + lua_pop(L, 1); > + > + return 0; > +} > diff --git a/src/lib/core/diag.c b/src/lib/core/diag.c > index e143db1..1caa75e 100644 > --- a/src/lib/core/diag.c > +++ b/src/lib/core/diag.c > @@ -120,3 +127,28 @@ error_vformat_msg(struct error *e, const char *format, va_list ap) > vsnprintf(e->errmsg, sizeof(e->errmsg), format, ap); > } > > +void > +error_set_lua_traceback(struct error *e, const char *lua_traceback) > +{ > + if (e == NULL) > + return; 6. It makes no sense to call this function on a NULL 'e'. This should be an assertion. As well as it is not possible to 'reset' the trace, so e->lua_traceback should be always NULL here. 7. Also I don't think it is a good idea to call traceback attribute 'lua_traceback'. Because we won't have separated 'lua_traceback' and 'c_traceback'. Anyway there will be always only one. Probably with C and Lua mixed (it is possible via space triggers to mix Lua and C in layers). > + > + if (lua_traceback == NULL) { > + free(e->lua_traceback); > + e->lua_traceback = NULL; > + return; > + } > + > + size_t tb_len = strlen(lua_traceback); > + e->lua_traceback = realloc(e->lua_traceback, tb_len + 1); > + if (e->lua_traceback == NULL) > + return; > + strcpy(e->lua_traceback, lua_traceback); > + return; > +} > + > +void > +error_set_traceback_supplementation(bool traceback_mode) > +{ > + global_traceback_mode = traceback_mode; > +} > diff --git a/src/lua/error.lua b/src/lua/error.lua > index bdc9c71..46d2866 100644 > --- a/src/lua/error.lua > +++ b/src/lua/error.lua > @@ -92,6 +94,14 @@ local function error_trace(err) > } > end > > +local function error_traceback(err) > + local result = "Traceback is absent" 8. I don't think it is a good idea to add this to every error object when there is no a trace. Just leave it nil. > + if err.lua_traceback ~= ffi.nullptr then > + result = ffi.string(err.lua_traceback) > + end > + return result > +end > + > local function error_errno(err) > local e = err._saved_errno > if e == 0 then > @@ -122,7 +132,6 @@ local function error_set_prev(err, prev) > if ok ~= 0 then > error("Cycles are not allowed") > end > - 9. Please, avoid unnecessary diff. > end > > local error_fields = { > diff --git a/test/engine/func_index.result b/test/engine/func_index.result > index a827c92..28befca 100644 > --- a/test/engine/func_index.result > +++ b/test/engine/func_index.result > @@ -291,12 +292,13 @@ e = e.prev > | ... > e:unpack() > | --- > - | - type: LuajitError > - | message: '[string "return function(tuple) local ..."]:1: attempt > - | to call global ''require'' (a nil value)' > + | - traceback: Traceback is absent > | trace: > | - file: > | line: > + | type: LuajitError > + | message: '[string "return function(tuple) local ..."]:1: attempt > + | to call global ''require'' (a nil value)' > | ... > e = e.prev > | --- 10. Usually every commit should add tests on the feature it introduces. You didn't add any single test. Why? Consider my review fixes below and on a new branch in a separate commit. It solves all the code-related problems, but I still don't know what to do with the major issues described in the beginning. Branch is: lvasiliev/gh-4398-expose-error-module-4-review ==================== Review fixes New commit message proposal: error: add a Lua traceback to error Lua backtrace can be enabled for all errors using a server-wide option, or on a per-error basis using box.error() and box.error.new() arguments. Needed for #4398 @TarantoolBot document Title: Lua error.traceback Lua error objects now feature 'traceback' optional attribute. It contains Lua traceback. C part is not present here. Traceback collection is a relatively expensive operation, so it is disabled by default. In case you need to enable it, there are 2 options: * Global option `traceback_enable` for `box.error.cfg` call: ``` box.error.cfg({traceback_enable = true}) ``` * Per object option, in case you want traceback only for certain cases: ``` box.error.new({ code = 1000, reason = 'Reason', traceback = true/false }) ``` diff --git a/src/box/lua/error.cc b/src/box/lua/error.cc index 4432bc89b..a616e87a4 100644 --- a/src/box/lua/error.cc +++ b/src/box/lua/error.cc @@ -54,8 +54,8 @@ luaT_error_create(lua_State *L, int top_base) { uint32_t code = 0; const char *reason = NULL; - bool tb_parsed = false; - bool tb_mode = false; + bool is_traceback_enabled = false; + bool is_traceback_specified = false; const char *file = ""; unsigned line = 0; lua_Debug info; @@ -91,10 +91,10 @@ luaT_error_create(lua_State *L, int top_base) lua_pop(L, 1); lua_getfield(L, top_base, "traceback"); if (lua_isboolean(L, -1)) { - tb_parsed = true; - tb_mode = lua_toboolean(L, -1); + is_traceback_enabled = lua_toboolean(L, -1); + is_traceback_specified = true; } - lua_pop(L, -1); + lua_pop(L, 1); } else { return NULL; } @@ -112,9 +112,11 @@ raise: } struct error *err = box_error_new(file, line, code, "%s", reason); - if (tb_parsed) - err->traceback_mode = tb_mode; - + /* + * Explicit traceback option overrides the global setting. + */ + if (err != NULL && is_traceback_specified) + err->is_traceback_enabled = is_traceback_enabled; return err; } @@ -198,11 +200,9 @@ luaT_error_cfg(struct lua_State *L) if (lua_gettop(L) < 1 || !lua_istable(L, 1)) return luaL_error(L, "Usage: box.error.cfg({}})"); - lua_getfield(L, 1, "traceback_supplementation"); - if (lua_isnil(L, -1) == 0) - error_set_traceback_supplementation(lua_toboolean(L, -1)); - lua_pop(L, 1); - + lua_getfield(L, 1, "traceback_enable"); + if (lua_isboolean(L, -1)) + error_is_traceback_enabled = lua_toboolean(L, -1); return 0; } diff --git a/src/lib/core/diag.c b/src/lib/core/diag.c index 1caa75ee9..833454bac 100644 --- a/src/lib/core/diag.c +++ b/src/lib/core/diag.c @@ -31,10 +31,7 @@ #include "diag.h" #include "fiber.h" -/** - * Global flag to add or not backtrace to errors. - */ -static bool global_traceback_mode = false; +bool error_is_traceback_enabled = false; int error_set_prev(struct error *e, struct error *prev) @@ -102,8 +99,8 @@ error_create(struct error *e, e->errmsg[0] = '\0'; e->cause = NULL; e->effect = NULL; - e->lua_traceback = NULL; - e->traceback_mode = global_traceback_mode; + e->traceback = NULL; + e->is_traceback_enabled = error_is_traceback_enabled; } struct diag * @@ -128,27 +125,14 @@ error_vformat_msg(struct error *e, const char *format, va_list ap) } void -error_set_lua_traceback(struct error *e, const char *lua_traceback) -{ - if (e == NULL) - return; - - if (lua_traceback == NULL) { - free(e->lua_traceback); - e->lua_traceback = NULL; - return; - } - - size_t tb_len = strlen(lua_traceback); - e->lua_traceback = realloc(e->lua_traceback, tb_len + 1); - if (e->lua_traceback == NULL) - return; - strcpy(e->lua_traceback, lua_traceback); - return; -} - -void -error_set_traceback_supplementation(bool traceback_mode) +error_set_traceback(struct error *e, const char *traceback) { - global_traceback_mode = traceback_mode; + assert(e->traceback == NULL); + e->traceback = strdup(traceback); + /* + * Don't try to set it again. Traceback can be NULL in case of OOM, so + * it is not a reliable source of information whether need to collect a + * traceback. + */ + e->is_traceback_enabled = false; } diff --git a/src/lib/core/diag.h b/src/lib/core/diag.h index f38009c54..e918d3089 100644 --- a/src/lib/core/diag.h +++ b/src/lib/core/diag.h @@ -42,6 +42,13 @@ extern "C" { #endif /* defined(__cplusplus) */ +/** + * Flag to turn on/off traceback automatic collection. Currently + * it works only for Lua. Stack is collected at the moment of + * error object push onto the stack. + */ +extern bool error_is_traceback_enabled; + enum { DIAG_ERRMSG_MAX = 512, DIAG_FILENAME_MAX = 256 @@ -110,8 +117,19 @@ struct error { */ struct error *cause; struct error *effect; - char *lua_traceback; - bool traceback_mode; + /** + * Optional traceback. At the moment it can contain only + * Lua traceback, and only when it is requested + * explicitly. + */ + char *traceback; + /** + * Flag whether a traceback should be collected when the + * error object is exposed to a user next time. When the + * tracing is disabled, or it is enabled but already + * collected for this error object, it becomes false. + */ + bool is_traceback_enabled; }; static inline void @@ -174,6 +192,14 @@ error_unlink_effect(struct error *e) int error_set_prev(struct error *e, struct error *prev); +/** + * Set traceback of @a e error object. It can be done only once. + * In case of OOM the traceback is kept NULL, and can't be + * collected again. + */ +void +error_set_traceback(struct error *e, const char *traceback); + NORETURN static inline void error_raise(struct error *e) { @@ -199,15 +225,6 @@ error_format_msg(struct error *e, const char *format, ...); void error_vformat_msg(struct error *e, const char *format, va_list ap); -void -error_set_lua_traceback(struct error *e, const char *lua_traceback); - -/** -* Sets the global flag to add or not backtrace to errors. -*/ -void -error_set_traceback_supplementation(bool traceback_mode); - /** * Diagnostics Area - a container for errors */ diff --git a/src/lib/core/exception.cc b/src/lib/core/exception.cc index 0e4b6ca8b..1717b76fb 100644 --- a/src/lib/core/exception.cc +++ b/src/lib/core/exception.cc @@ -42,7 +42,7 @@ extern "C" { static void exception_destroy(struct error *e) { - free(e->lua_traceback); + free(e->traceback); delete (Exception *) e; } diff --git a/src/lua/error.c b/src/lua/error.c index cd6ab54b1..a21548ce6 100644 --- a/src/lua/error.c +++ b/src/lua/error.c @@ -86,12 +86,11 @@ luaT_pusherror(struct lua_State *L, struct error *e) */ error_ref(e); - if (e->lua_traceback == NULL && e->traceback_mode) { + if (e->traceback == NULL && e->is_traceback_enabled) { int top = lua_gettop(L); luaL_traceback(L, L, NULL, 0); - if (lua_isstring(L, -1)) { - error_set_lua_traceback(e, lua_tostring(L, -1)); - } + if (lua_isstring(L, -1)) + error_set_traceback(e, lua_tostring(L, -1)); lua_settop(L, top); } diff --git a/src/lua/error.lua b/src/lua/error.lua index 46d28667f..535110588 100644 --- a/src/lua/error.lua +++ b/src/lua/error.lua @@ -26,8 +26,8 @@ struct error { char _errmsg[DIAG_ERRMSG_MAX]; struct error *_cause; struct error *_effect; - char *lua_traceback; - bool traceback_mode; + char *traceback; + bool is_traceback_enabled; }; char * @@ -95,11 +95,7 @@ local function error_trace(err) end local function error_traceback(err) - local result = "Traceback is absent" - if err.lua_traceback ~= ffi.nullptr then - result = ffi.string(err.lua_traceback) - end - return result + return err.traceback ~= ffi.nullptr and ffi.string(err.traceback) or nil end local function error_errno(err) @@ -132,6 +128,7 @@ local function error_set_prev(err, prev) if ok ~= 0 then error("Cycles are not allowed") end + end local error_fields = { diff --git a/test/app/fiber.result b/test/app/fiber.result index fc6b3c92d..debfc6718 100644 --- a/test/app/fiber.result +++ b/test/app/fiber.result @@ -1038,13 +1038,12 @@ st; ... e:unpack(); --- -- traceback: Traceback is absent +- type: ClientError code: 1 + message: Illegal parameters, oh my trace: - file: '[string "function err() box.error(box.error.ILLEGAL_PA..."]' line: 1 - type: ClientError - message: Illegal parameters, oh my ... flag = false; --- diff --git a/test/box/error.result b/test/box/error.result index 574bc481f..2502d88c4 100644 --- a/test/box/error.result +++ b/test/box/error.result @@ -34,13 +34,12 @@ e | ... e:unpack() | --- - | - traceback: Traceback is absent + | - type: ClientError | code: 1 + | message: Illegal parameters, bla bla | trace: | - file: '[C]' | line: 4294967295 - | type: ClientError - | message: Illegal parameters, bla bla | ... e.type | --- @@ -832,3 +831,62 @@ assert(box.error.last() == e1) | --- | - true | ... + +-- +-- gh-4398: Lua traceback for errors. +-- +function t1(traceback, throw) \ + local opts = {code = 0, reason = 'Reason', traceback = traceback} \ + if throw then \ + box.error(opts) \ + else \ + return box.error.new(opts) \ + end \ +end + | --- + | ... +function t2(...) return t1(...), nil end + | --- + | ... +function t3(...) return t2(...), nil end + | --- + | ... + +function check_trace(trace) \ + local t1loc = trace:find('t1') \ + local t2loc = trace:find('t2') \ + local t3loc = trace:find('t3') \ + return t1loc < t2loc and t2loc < t3loc or {t1loc, t2loc, t3loc, trace} \ +end + | --- + | ... + +check_trace(t3(true, false):unpack().traceback) + | --- + | - true + | ... + +box.error.cfg{traceback_enable = true} + | --- + | ... +-- Explicit 'traceback = false' overrides the global setting. +t3(false, false):unpack().traceback + | --- + | - null + | ... +-- When explicit option is not specified, global setting works. +check_trace(t3(nil, false):unpack().traceback) + | --- + | - true + | ... + +box.error.cfg{traceback_enable = false} + | --- + | ... +_, e = pcall(t3, true, true) + | --- + | ... +check_trace(e:unpack().traceback) + | --- + | - true + | ... diff --git a/test/box/error.test.lua b/test/box/error.test.lua index 41baed52d..6f1271630 100644 --- a/test/box/error.test.lua +++ b/test/box/error.test.lua @@ -229,3 +229,36 @@ box.error({code = 111, reason = "err"}) box.error.last() box.error(e1) assert(box.error.last() == e1) + +-- +-- gh-4398: Lua traceback for errors. +-- +function t1(traceback, throw) \ + local opts = {code = 0, reason = 'Reason', traceback = traceback} \ + if throw then \ + box.error(opts) \ + else \ + return box.error.new(opts) \ + end \ +end +function t2(...) return t1(...), nil end +function t3(...) return t2(...), nil end + +function check_trace(trace) \ + local t1loc = trace:find('t1') \ + local t2loc = trace:find('t2') \ + local t3loc = trace:find('t3') \ + return t1loc < t2loc and t2loc < t3loc or {t1loc, t2loc, t3loc, trace} \ +end + +check_trace(t3(true, false):unpack().traceback) + +box.error.cfg{traceback_enable = true} +-- Explicit 'traceback = false' overrides the global setting. +t3(false, false):unpack().traceback +-- When explicit option is not specified, global setting works. +check_trace(t3(nil, false):unpack().traceback) + +box.error.cfg{traceback_enable = false} +_, e = pcall(t3, true, true) +check_trace(e:unpack().traceback) diff --git a/test/engine/func_index.result b/test/engine/func_index.result index 28befca39..a827c929f 100644 --- a/test/engine/func_index.result +++ b/test/engine/func_index.result @@ -276,8 +276,7 @@ e = box.error.last() | ... e:unpack() | --- - | - traceback: Traceback is absent - | code: 198 + | - code: 198 | trace: | - file: | line: @@ -292,13 +291,12 @@ e = e.prev | ... e:unpack() | --- - | - traceback: Traceback is absent + | - type: LuajitError + | message: '[string "return function(tuple) local ..."]:1: attempt + | to call global ''require'' (a nil value)' | trace: | - file: | line: - | type: LuajitError - | message: '[string "return function(tuple) local ..."]:1: attempt - | to call global ''require'' (a nil value)' | ... e = e.prev | ---