[tarantool-patches] [PATCH v2 0/3] Dump lua frames for a fiber traceback

[tarantool-patches] [PATCH v2 0/3] Dump lua frames for a fiber traceback

[Georgy Kirichenko]

Lua frames are now dumped as well as plain C-frames for a
fiber backtrace. The main patch follows two preparation fixes:
 - enable backtrace for an active coroutine;
 - setup lua state for the main fiber;

Georgy Kirichenko (3):
  fiber: do not inline coro unwind function
  Proper unwind for currently executing fiber
  Show names of Lua functions in backtraces

 src/backtrace.cc        | 27 ++++++++++++-
 src/lua/fiber.c         | 86 +++++++++++++++++++++++++++++++++++------
 test/app/fiber.result   | 33 ++++++++++++++++
 test/app/fiber.test.lua | 12 ++++++
 4 files changed, 146 insertions(+), 12 deletions(-)

-- 
2.19.1

https://github.com/tarantool/tarantool/issues/3538
https://github.com/tarantool/tarantool/compare/g.kirichenko/gh-3538-lua-backtrace

Changes in v2:
 - Rebased against the latest 1.10
 - Segmentation fault fixed

[tarantool-patches] [PATCH 1/3] fiber: do not inline coro unwind function

[Georgy Kirichenko]

Call coro_unwcontext via function pointer to protect the
function from inlining.
---
 src/backtrace.cc | 7 ++++++-
 1 file changed, 6 insertions(+), 1 deletion(-)

diff --git a/src/backtrace.cc b/src/backtrace.cc
index 2512bc045..66dcc0047 100644
--- a/src/backtrace.cc
+++ b/src/backtrace.cc
@@ -363,12 +363,17 @@ __asm__ volatile(
 #endif
 }
 
+typedef void (*coro_unwcontext_indirect_f)(unw_context_t *unw_context,
+					   struct coro_context *coro_ctx);
+/* Variable to process coro_unwcontext indirect call to avoid inlining. */
+static volatile coro_unwcontext_indirect_f coro_unwcontext_indirect = coro_unwcontext;
+
 void
 backtrace_foreach(backtrace_cb cb, coro_context *coro_ctx, void *cb_ctx)
 {
 	unw_cursor_t unw_cur;
 	unw_context_t unw_ctx;
-	coro_unwcontext(&unw_ctx, coro_ctx);
+	coro_unwcontext_indirect(&unw_ctx, coro_ctx);
 	unw_init_local(&unw_cur, &unw_ctx);
 	int frame_no = 0;
 	unw_word_t sp = 0, old_sp = 0, ip, offset;
-- 
2.19.1

[tarantool-patches] [PATCH 2/3] Proper unwind for currently executing fiber

[Georgy Kirichenko]

Each yielded fiber has a preserved coro state stored in a corresponding
variable however an executing fiber has a volatile state placed in CPU
registers (stack pointer, instruction pointer and non-volatile registers)
and corresponding context-storing variable value is invalid.
For already yielded fiber we have to use a special asm-written handler to make
a temporary switch to the preserved state and capture executing context what
is not needed for executing fiber.
After the patch for the executing fiber NULL is passed to the backtrace
function as coro context and then backtrace function could decide should
it use special context-switching handler or might just use unw_getcontext
from the unwind library.
---
 src/backtrace.cc | 22 +++++++++++++++++++++-
 1 file changed, 21 insertions(+), 1 deletion(-)

diff --git a/src/backtrace.cc b/src/backtrace.cc
index 66dcc0047..51e8b54da 100644
--- a/src/backtrace.cc
+++ b/src/backtrace.cc
@@ -368,12 +368,32 @@ typedef void (*coro_unwcontext_indirect_f)(unw_context_t *unw_context,
 /* Variable to process coro_unwcontext indirect call to avoid inlining. */
 static volatile coro_unwcontext_indirect_f coro_unwcontext_indirect = coro_unwcontext;
 
+/*
+ * Call `cb' callback for each `coro_ctx' contained frame or the current
+ * executed coroutine if `coro_ctx' is NULL. A coro_context is a structure
+ * created on each coroutine yield to store execution context so for an on-CPU
+ * coroutine there is no valid coro_context could be defined and NULL is
+ * passed.
+*/
 void
 backtrace_foreach(backtrace_cb cb, coro_context *coro_ctx, void *cb_ctx)
 {
 	unw_cursor_t unw_cur;
 	unw_context_t unw_ctx;
-	coro_unwcontext_indirect(&unw_ctx, coro_ctx);
+	if (coro_ctx == NULL) {
+		/*
+		 * Current executing coroutine and simple unw_getcontext
+		 * should function.
+		 */
+		unw_getcontext(&unw_ctx);
+	} else {
+		/*
+		 * Execution context is stored in the coro_ctx
+		 * so use special context-switching handler to
+		 * capture an unwind context.
+		 */
+		coro_unwcontext_indirect(&unw_ctx, coro_ctx);
+	}
 	unw_init_local(&unw_cur, &unw_ctx);
 	int frame_no = 0;
 	unw_word_t sp = 0, old_sp = 0, ip, offset;
-- 
2.19.1

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

[Georgy Kirichenko]

Trace corresponding Lua state as well as normal C stack frames while
fiber backtracing. This might be useful for debugging purposes.

Fixes: #3538
---
 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)
+{
+	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++;
+		}
+	} else {
+		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
@@ -229,10 +288,15 @@ lbox_fiber_statof(struct fiber *f, void *cb_ctx, bool backtrace)
 
 	if (backtrace) {
 #ifdef ENABLE_BACKTRACE
+		struct lua_fiber_tb_ctx tb_ctx;
+		tb_ctx.L = L;
+		tb_ctx.R = f->storage.lua.stack;
+		tb_ctx.lua_frame = 0;
+		tb_ctx.tb_frame = 0;
 		lua_pushstring(L, "backtrace");
 		lua_newtable(L);
-		if (f != fiber())
-			backtrace_foreach(fiber_backtrace_cb, &f->ctx, L);
+		backtrace_foreach(fiber_backtrace_cb,
+				  f != fiber() ? &f->ctx : NULL, &tb_ctx);
 		lua_settable(L, -3);
 #endif /* ENABLE_BACKTRACE */
 	}
diff --git a/test/app/fiber.result b/test/app/fiber.result
index 77144e661..1a7827fa1 100644
--- a/test/app/fiber.result
+++ b/test/app/fiber.result
@@ -849,6 +849,39 @@ f2:cancel()
 f3:cancel()
 ---
 ...
+function sf1() loop() end
+---
+...
+function sf2() sf1() end
+---
+...
+function sf3() sf2() end
+---
+...
+f1 = fiber.create(sf3)
+---
+...
+info = fiber.info()
+---
+...
+backtrace = info[f1:id()].backtrace
+---
+...
+bt_str = table.concat(backtrace, '\n')
+---
+...
+bt_str:find('sf1') ~= nil
+---
+- true
+...
+bt_str:find('loop') ~= nil
+---
+- true
+...
+bt_str:find('sf3') ~= nil
+---
+- true
+...
 -- # gh-666: nulls in output
 --
 getmetatable(fiber.info())
diff --git a/test/app/fiber.test.lua b/test/app/fiber.test.lua
index 98a136090..9df751cc8 100644
--- a/test/app/fiber.test.lua
+++ b/test/app/fiber.test.lua
@@ -334,6 +334,18 @@ f1:cancel()
 f2:cancel()
 f3:cancel()
 
+function sf1() loop() end
+function sf2() sf1() end
+function sf3() sf2() end
+f1 = fiber.create(sf3)
+
+info = fiber.info()
+backtrace = info[f1:id()].backtrace
+bt_str = table.concat(backtrace, '\n')
+bt_str:find('sf1') ~= nil
+bt_str:find('loop') ~= nil
+bt_str:find('sf3') ~= nil
+
 -- # gh-666: nulls in output
 --
 getmetatable(fiber.info())
-- 
2.19.1

Re: [tarantool-patches] [PATCH 1/3] fiber: do not inline coro unwind function

[Vladimir Davydov]

On Wed, Oct 10, 2018 at 07:39:24PM +0300, Georgy Kirichenko wrote:
> Call coro_unwcontext via function pointer to protect the
> function from inlining.
> ---
>  src/backtrace.cc | 7 ++++++-
>  1 file changed, 6 insertions(+), 1 deletion(-)
> 
> diff --git a/src/backtrace.cc b/src/backtrace.cc
> index 2512bc045..66dcc0047 100644
> --- a/src/backtrace.cc
> +++ b/src/backtrace.cc
> @@ -363,12 +363,17 @@ __asm__ volatile(
>  #endif
>  }
>  
> +typedef void (*coro_unwcontext_indirect_f)(unw_context_t *unw_context,
> +					   struct coro_context *coro_ctx);
> +/* Variable to process coro_unwcontext indirect call to avoid inlining. */
> +static volatile coro_unwcontext_indirect_f coro_unwcontext_indirect = coro_unwcontext;
> +

Why must not it be inlined? I think it deserves an explanation in
the comment.

Also, may be we'd better use NOINLINE attribute instead of function
pointer?

>  void
>  backtrace_foreach(backtrace_cb cb, coro_context *coro_ctx, void *cb_ctx)
>  {
>  	unw_cursor_t unw_cur;
>  	unw_context_t unw_ctx;
> -	coro_unwcontext(&unw_ctx, coro_ctx);
> +	coro_unwcontext_indirect(&unw_ctx, coro_ctx);
>  	unw_init_local(&unw_cur, &unw_ctx);
>  	int frame_no = 0;
>  	unw_word_t sp = 0, old_sp = 0, ip, offset;

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

[Vladimir Davydov]

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

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

[Georgy Kirichenko]

Trace corresponding Lua state as well as normal C stack frames while
fiber backtracing. This might be useful for debugging purposes.

Fixes: #3538
---
 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)
+{
+	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++;
+		}
+	} else {
+		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
@@ -229,10 +288,15 @@ lbox_fiber_statof(struct fiber *f, void *cb_ctx, bool backtrace)
 
 	if (backtrace) {
 #ifdef ENABLE_BACKTRACE
+		struct lua_fiber_tb_ctx tb_ctx;
+		tb_ctx.L = L;
+		tb_ctx.R = f->storage.lua.stack;
+		tb_ctx.lua_frame = 0;
+		tb_ctx.tb_frame = 0;
 		lua_pushstring(L, "backtrace");
 		lua_newtable(L);
-		if (f != fiber())
-			backtrace_foreach(fiber_backtrace_cb, &f->ctx, L);
+		backtrace_foreach(fiber_backtrace_cb,
+				  f != fiber() ? &f->ctx : NULL, &tb_ctx);
 		lua_settable(L, -3);
 #endif /* ENABLE_BACKTRACE */
 	}
diff --git a/test/app/fiber.result b/test/app/fiber.result
index 77144e661..1a7827fa1 100644
--- a/test/app/fiber.result
+++ b/test/app/fiber.result
@@ -849,6 +849,39 @@ f2:cancel()
 f3:cancel()
 ---
 ...
+function sf1() loop() end
+---
+...
+function sf2() sf1() end
+---
+...
+function sf3() sf2() end
+---
+...
+f1 = fiber.create(sf3)
+---
+...
+info = fiber.info()
+---
+...
+backtrace = info[f1:id()].backtrace
+---
+...
+bt_str = table.concat(backtrace, '\n')
+---
+...
+bt_str:find('sf1') ~= nil
+---
+- true
+...
+bt_str:find('loop') ~= nil
+---
+- true
+...
+bt_str:find('sf3') ~= nil
+---
+- true
+...
 -- # gh-666: nulls in output
 --
 getmetatable(fiber.info())
diff --git a/test/app/fiber.test.lua b/test/app/fiber.test.lua
index 98a136090..9df751cc8 100644
--- a/test/app/fiber.test.lua
+++ b/test/app/fiber.test.lua
@@ -334,6 +334,18 @@ f1:cancel()
 f2:cancel()
 f3:cancel()
 
+function sf1() loop() end
+function sf2() sf1() end
+function sf3() sf2() end
+f1 = fiber.create(sf3)
+
+info = fiber.info()
+backtrace = info[f1:id()].backtrace
+bt_str = table.concat(backtrace, '\n')
+bt_str:find('sf1') ~= nil
+bt_str:find('loop') ~= nil
+bt_str:find('sf3') ~= nil
+
 -- # gh-666: nulls in output
 --
 getmetatable(fiber.info())
-- 
2.19.0

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

[Georgy Kirichenko]

Trace corresponding Lua state as well as normal C stack frames while
fiber backtracing. This might be useful for debugging purposes.

Fixes: #3538
---
 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..289d240f6 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:#%d %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)
+{
+	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) {
+		// LUA code.
+		lua_Debug ar;
+		while (tb_ctx->R && lua_getstack(tb_ctx->R, tb_ctx->lua_frame, &ar) > 0) {
+			// Skip all C-frames.
+			lua_getinfo(tb_ctx->R, "Sln", &ar);
+			if (*ar.what != 'C')
+				break;
+			if (ar.name != NULL) {
+				// Dump frame if it is a 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 frames.
+			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++;
+		}
+	} else {
+		char buf[512];
+		int l = snprintf(buf, sizeof(buf), "C:#%d %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
@@ -229,10 +288,15 @@ lbox_fiber_statof(struct fiber *f, void *cb_ctx, bool backtrace)
 
 	if (backtrace) {
 #ifdef ENABLE_BACKTRACE
+		struct lua_fiber_tb_ctx tb_ctx;
+		tb_ctx.L = L;
+		tb_ctx.R = f->storage.lua.stack;
+		tb_ctx.lua_frame = 0;
+		tb_ctx.tb_frame = 0;
 		lua_pushstring(L, "backtrace");
 		lua_newtable(L);
-		if (f != fiber())
-			backtrace_foreach(fiber_backtrace_cb, &f->ctx, L);
+		backtrace_foreach(fiber_backtrace_cb,
+				  f != fiber() ? &f->ctx : NULL, &tb_ctx);
 		lua_settable(L, -3);
 #endif /* ENABLE_BACKTRACE */
 	}
diff --git a/test/app/fiber.result b/test/app/fiber.result
index 77144e661..1a7827fa1 100644
--- a/test/app/fiber.result
+++ b/test/app/fiber.result
@@ -849,6 +849,39 @@ f2:cancel()
 f3:cancel()
 ---
 ...
+function sf1() loop() end
+---
+...
+function sf2() sf1() end
+---
+...
+function sf3() sf2() end
+---
+...
+f1 = fiber.create(sf3)
+---
+...
+info = fiber.info()
+---
+...
+backtrace = info[f1:id()].backtrace
+---
+...
+bt_str = table.concat(backtrace, '\n')
+---
+...
+bt_str:find('sf1') ~= nil
+---
+- true
+...
+bt_str:find('loop') ~= nil
+---
+- true
+...
+bt_str:find('sf3') ~= nil
+---
+- true
+...
 -- # gh-666: nulls in output
 --
 getmetatable(fiber.info())
diff --git a/test/app/fiber.test.lua b/test/app/fiber.test.lua
index 98a136090..9df751cc8 100644
--- a/test/app/fiber.test.lua
+++ b/test/app/fiber.test.lua
@@ -334,6 +334,18 @@ f1:cancel()
 f2:cancel()
 f3:cancel()
 
+function sf1() loop() end
+function sf2() sf1() end
+function sf3() sf2() end
+f1 = fiber.create(sf3)
+
+info = fiber.info()
+backtrace = info[f1:id()].backtrace
+bt_str = table.concat(backtrace, '\n')
+bt_str:find('sf1') ~= nil
+bt_str:find('loop') ~= nil
+bt_str:find('sf3') ~= nil
+
 -- # gh-666: nulls in output
 --
 getmetatable(fiber.info())
-- 
2.19.0