[tarantool-patches] Re: [PATCH 3/3] Show names of Lua functions in backtraces

  • From: Vladimir Davydov <vdavydov.dev@xxxxxxxxx>
  • To: Georgy Kirichenko <georgy@xxxxxxxxxxxxx>
  • Date: Fri, 5 Oct 2018 20:49:52 +0300

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  <Lua> get in =[C] at line -1'
  - '#5  <Lua> f1 in @../test.lua at line 10'
  - '#6  <Lua> f2 in @../test.lua at line 14'
  - '#7  <Lua> (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'
  - - <Lua> get in =[C] at line -1
  - - <Lua> f1 in @../test.lua at line 10
  - - <Lua> f2 in @../test.lua at line 14
  - - <Lua> (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

Other related posts: