From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Date: Fri, 5 Oct 2018 20:49:52 +0300 From: Vladimir Davydov Subject: Re: [tarantool-patches] [PATCH 3/3] Show names of Lua functions in backtraces Message-ID: <20181005174952.5xlypecjsjnyi63p@esperanza> References: <76f2b7de46d4a1d55a3d2b7b39eb87172749eed6.1537535602.git.georgy@tarantool.org> <20180925233847.GK3137@chai> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: To: Georgy Kirichenko Cc: tarantool-patches@freelists.org, kostja@tarantool.org List-ID: On Thu, Oct 04, 2018 at 10:55:22AM +0300, Georgy Kirichenko wrote: > Trace corresponding Lua state as well as normal C stack frames while > fiber backtracing. This might be useful for debugging purposes. > > Fixes: #3538 It would be nice to give an example of what a trace back looks like now: - - '#1 0x560068107478 in fiber_yield_timeout+154' - '#2 0x5600681108c4 in fiber_channel_get_msg_timeout+553' - '#3 0x5600680ec711 in luaT_fiber_channel_get+228' - LUA#1 get in =[C] at line -1 - LUA#2 f1 in @../test.lua at line 10 - LUA#3 f2 in @../test.lua at line 14 - LUA#4 (unnamed) in @../test.lua at line 18 - '#5 0x560068151863 in lua_pcall+398' - '#6 0x5600680f2279 in luaT_call+41' - '#7 0x5600680eb2a1 in lua_fiber_run_f+116' - '#8 0x560067ffde24 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+30' - '#9 0x560068107a81 in fiber_loop+130' - '#10 0x5600682db35b in coro_init+76' - '#11 (nil) in +76' To be honest I find it ugly, but at the same time I fail to suggest anything less ugly. May be, we could use through numbering for Lua and C frames? - - '#1 0x560068107478 in fiber_yield_timeout+154' - '#2 0x5600681108c4 in fiber_channel_get_msg_timeout+553' - '#3 0x5600680ec711 in luaT_fiber_channel_get+228' - '#4 get in =[C] at line -1' - '#5 f1 in @../test.lua at line 10' - '#6 f2 in @../test.lua at line 14' - '#7 (unnamed) in @../test.lua at line 18' - '#8 0x560068151863 in lua_pcall+398' - '#9 0x5600680f2279 in luaT_call+41' - '#10 0x5600680eb2a1 in lua_fiber_run_f+116' - '#11 0x560067ffde24 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+30' - '#12 0x560068107a81 in fiber_loop+130' - '#13 0x5600682db35b in coro_init+76' Or alternatively, we could turn a frame corresponding to lj_BC_FUNCC into an array, which would contain Lua stack frames: - - '#1 0x560068107478 in fiber_yield_timeout+154' - '#2 0x5600681108c4 in fiber_channel_get_msg_timeout+553' - '#3 0x5600680ec711 in luaT_fiber_channel_get+228' - - '#4 0x5601b399da2b in lj_BC_FUNCC+52' - - get in =[C] at line -1 - - f1 in @../test.lua at line 10 - - f2 in @../test.lua at line 14 - - (unnamed) in @../test.lua at line 18 - '#5 0x560068151863 in lua_pcall+398' - '#6 0x5600680f2279 in luaT_call+41' - '#7 0x5600680eb2a1 in lua_fiber_run_f+116' - '#8 0x560067ffde24 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+30' - '#9 0x560068107a81 in fiber_loop+130' - '#10 0x5600682db35b in coro_init+76' - '#11 (nil) in +76' > --- > src/lua/fiber.c | 86 +++++++++++++++++++++++++++++++++++------ > test/app/fiber.result | 33 ++++++++++++++++ > test/app/fiber.test.lua | 12 ++++++ > 3 files changed, 120 insertions(+), 11 deletions(-) > > diff --git a/src/lua/fiber.c b/src/lua/fiber.c > index 147add89b..428c2f938 100644 > --- a/src/lua/fiber.c > +++ b/src/lua/fiber.c > @@ -178,20 +178,79 @@ lbox_fiber_id(struct lua_State *L) > return 1; > } > > +/** > + * Lua fiber traceback context. > + */ > +struct lua_fiber_tb_ctx { > + /* Lua stack to push values. */ > + struct lua_State *L; > + /* Lua stack to trace. */ > + struct lua_State *R; > + /* Current Lua frame. */ > + int lua_frame; > + /* Count of traced frames (both C and Lua). */ > + int tb_frame; > +}; > + > #ifdef ENABLE_BACKTRACE > -static int > -fiber_backtrace_cb(int frameno, void *frameret, const char *func, size_t offset, void *cb_ctx) > +static void > +dump_lua_frame(struct lua_State *L, lua_Debug *ar, int tb_frame, int lua_frame) > { > char buf[512]; > - int l = snprintf(buf, sizeof(buf), "#%-2d %p in ", frameno, frameret); > - if (func) > - snprintf(buf + l, sizeof(buf) - l, "%s+%zu", func, offset); > - else > - snprintf(buf + l, sizeof(buf) - l, "?"); > - struct lua_State *L = (struct lua_State*)cb_ctx; > - lua_pushnumber(L, frameno + 1); > + snprintf(buf, sizeof(buf), "LUA#%-2d %s in %s at line %i", > + lua_frame + 1, > + ar->name != NULL ? ar->name : "(unnamed)", > + ar->source, ar->currentline); > + lua_pushnumber(L, tb_frame); > lua_pushstring(L, buf); > lua_settable(L, -3); > +} > + > +static int > +fiber_backtrace_cb(int frameno, void *frameret, const char *func, size_t offset, void *cb_ctx) Nitpicking: this line and a few below are longer than 80 characters. I don't see any reason why you couldn't split them. > +{ > + struct lua_fiber_tb_ctx *tb_ctx = (struct lua_fiber_tb_ctx *)cb_ctx; > + struct lua_State *L = tb_ctx->L; > + if (strstr(func, "lj_BC_FUNCC") == func) { > + /* We are in the LUA vm. */ > + lua_Debug ar; > + while (tb_ctx->R && lua_getstack(tb_ctx->R, tb_ctx->lua_frame, &ar) > 0) { > + /* Skip all following C-frames. */ > + lua_getinfo(tb_ctx->R, "Sln", &ar); > + if (*ar.what != 'C') > + break; > + if (ar.name != NULL) { > + /* Dump frame if it is a C built-in call. */ > + tb_ctx->tb_frame++; > + dump_lua_frame(L, &ar, tb_ctx->tb_frame, > + tb_ctx->lua_frame); > + } > + tb_ctx->lua_frame++; > + } > + while (tb_ctx->R && lua_getstack(tb_ctx->R, tb_ctx->lua_frame, &ar) > 0) { > + /* Trace Lua frame. */ > + lua_getinfo(tb_ctx->R, "Sln", &ar); > + if (*ar.what == 'C') { > + break; > + } > + tb_ctx->tb_frame++; > + dump_lua_frame(L, &ar, tb_ctx->tb_frame, > + tb_ctx->lua_frame); > + tb_ctx->lua_frame++; > + } I think you could rewrite this code with just one loop. It would make it more succinct. Would it make it more readable though? > + } else { I think we should include lj_BC_FUNCC into the output too. > + char buf[512]; > + int l = snprintf(buf, sizeof(buf), "#%-2d %p in ", > + frameno + 1, frameret); > + if (func) > + snprintf(buf + l, sizeof(buf) - l, "%s+%zu", func, offset); > + else > + snprintf(buf + l, sizeof(buf) - l, "?"); > + tb_ctx->tb_frame++; > + lua_pushnumber(L, tb_ctx->tb_frame); > + lua_pushstring(L, buf); > + lua_settable(L, -3); > + } > return 0; > } > #endif