From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from smtp57.i.mail.ru (smtp57.i.mail.ru [217.69.128.37]) (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 C021A4696C3 for ; Wed, 15 Apr 2020 12:25:49 +0300 (MSK) References: From: lvasiliev Message-ID: Date: Wed, 15 Apr 2020 12:25:48 +0300 MIME-Version: 1.0 In-Reply-To: Content-Type: text/plain; charset=utf-8; format=flowed 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: Vladislav Shpilevoy , Alexander Turenko Cc: tarantool-patches@dev.tarantool.org Hi! Thanks for the review. On 14.04.2020 4:11, Vladislav Shpilevoy wrote: > 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. This is part of the errors.lua functional, which was attached as an example. After that it was also one of the functionality requested by Nazarov. > > 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. (I added Turenko to To) I have two variants: - Leave as is and to document such behavior - Add the same traceback to all errors in the stack Alexander what do you think? > > > 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? That's my mistake. After our discussion for testing I used the test added in the last commit and deleted the ones added before in misc. > > 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. I applied your patch and added you to Co-authored. But I have a couple of questions. See 4 comments below. > > 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) 1) box_error_new don't return NULL > + 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); 2) Do I understand correctly that asserts only work on debug? Will this approach not be dangerous by memory leaks on release? > + 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; 3) Why a global variable is more preferable than static? > + > 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; 4) Replaced to err_traceback. It overlaps the traceback getter. > + 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 > | --- >