[tarantool-patches] [PATCH] lua: show locals when a tap test fails

[tarantool-patches] [PATCH] lua: show locals when a tap test fails

[Alexander Turenko]

Fixes #3627.
---

branch: Totktonada/gh-3627-tap-show-local-variables
travis-ci: https://travis-ci.org/tarantool/tarantool/builds/417616160
issue: https://github.com/tarantool/tarantool/issues/3627

 src/lua/tap.lua           | 45 ++++++++++++++++++++++++++++++++++-----
 test/app-tap/tap.result   | 26 ++++++++++++++++++++--
 test/app-tap/tap.test.lua | 21 +++++++++++++++---
 3 files changed, 82 insertions(+), 10 deletions(-)

diff --git a/src/lua/tap.lua b/src/lua/tap.lua
index edc9f2211..9dd531422 100644
--- a/src/lua/tap.lua
+++ b/src/lua/tap.lua
@@ -1,6 +1,6 @@
 --- tap.lua internal file
 ---
---- The Test Anything Protocol vesion 13 producer
+--- The Test Anything Protocol version 13 producer
 ---
 
 -- yaml formatter must be able to encode any Lua variable
@@ -36,12 +36,43 @@ local function traceback(level)
     return trace
 end
 
+local function locals(test, level)
+    level = level or 3
+    local variables = {}
+    local idx = 1
+    while true do
+      local name, value = debug.getlocal(level, idx)
+      if name ~= nil then
+          -- compare a table with a tuple raises an error, so we check types
+          -- first
+          local eq = type(value) == type(test) and value == test
+          -- temporary values start with '('
+          if not name:startswith('(') and not eq then
+              variables[name] = value
+          end
+      else
+          break
+      end
+      idx = 1 + idx
+    end
+    return variables
+end
+
 local function diag(test, fmt, ...)
     io.write(string.rep(' ', 4 * test.level), "# ", string.format(fmt, ...),
         "\n")
 end
 
-local function ok(test, cond, message, extra)
+local function ok(test, cond, message, extra, opts)
+    opts = opts or {}
+    local show_locals
+    if opts.locals ~= nil then
+        show_locals = opts.locals
+    elseif test.locals ~= nil then
+        show_locals = test.locals
+    else
+        show_locals = true
+    end
     test.total = test.total + 1
     io.write(string.rep(' ', 4 * test.level))
     if cond then
@@ -58,6 +89,9 @@ local function ok(test, cond, message, extra)
         extra.filename = extra.trace[#extra.trace].filename
         extra.line = extra.trace[#extra.trace].line
     end
+    if show_locals then
+        extra.locals = locals(test)
+    end
     if next(extra) == nil then
         return false -- don't have extra information
     end
@@ -221,6 +255,7 @@ local function test(parent, name, fun, ...)
         failed  = 0;
         planned = 0;
         trace   = parent == nil and true or parent.trace;
+        locals  = parent == nil and true or parent.locals;
     }, test_mt)
     if fun ~= nil then
         test:diag('%s', test.name)
@@ -245,7 +280,7 @@ local function check(test)
     if test.planned ~= test.total then
         if test.parent ~= nil then
             ok(test.parent, false, "bad plan", { planned = test.planned;
-                run = test.total})
+                run = test.total}, {locals = false})
         else
             diag(test, string.format("bad plan: planned %d run %d",
                 test.planned, test.total))
@@ -255,13 +290,13 @@ local function check(test)
             ok(test.parent, false, "failed subtests", {
                 failed = test.failed;
                 planned = test.planned;
-            })
+            }, {locals = false})
         else
             diag(test, "failed subtest: %d", test.failed)
         end
     else
         if test.parent ~= nil then
-            ok(test.parent, true, test.name)
+            ok(test.parent, true, test.name, {locals = false})
         end
     end
     return test.planned == test.total and test.failed == 0
diff --git a/test/app-tap/tap.result b/test/app-tap/tap.result
index 3e7882331..36caa3023 100644
--- a/test/app-tap/tap.result
+++ b/test/app-tap/tap.result
@@ -1,5 +1,5 @@
 TAP version 13
-1..32
+1..33
 ok - true
 ok - extra information is not printed on success
 not ok - extra printed using yaml only on failure
@@ -148,4 +148,26 @@ not ok - failed subtests
     ok - unlike(abcde, acd)
     # like: end
 ok - like
-# failed subtest: 15
+    # locals
+    1..1
+        # locals nested
+        1..2
+        ok - locals are not printed in case of success
+        not ok - locals are printed in case of fail
+          ---
+          locals:
+            a: 42
+          ...
+        # locals nested: end
+    not ok - failed subtests
+      ---
+      planned: 2
+      failed: 1
+      ...
+    # locals: end
+not ok - failed subtests
+  ---
+  planned: 1
+  failed: 1
+  ...
+# failed subtest: 16
diff --git a/test/app-tap/tap.test.lua b/test/app-tap/tap.test.lua
index 0e1de7f1c..29dc0b100 100755
--- a/test/app-tap/tap.test.lua
+++ b/test/app-tap/tap.test.lua
@@ -12,15 +12,16 @@ local tap = require "tap"
 -- Create a root test
 --
 test = tap.test("root test")
--- Disable stack traces for this test because Tarantool test system also
--- checks test output.
+-- Disable stack traces and locals for this test because Tarantool test system
+-- also checks test output.
 test.trace = false
+test.locals = false
 
 --
 -- ok, fail and skip predicates
 --
 
-test:plan(32) -- plan to run 3 test
+test:plan(33) -- plan to run 3 test
 test:ok(true, 'true') -- basic function
 local extra = { state = 'some userful information to debug on failure',
         details = 'a table argument formatted using yaml.encode()' }
@@ -136,6 +137,20 @@ test:test('like', function(t)
     t:unlike('abcde', 'acd', 'unlike(abcde, acd)')
 end)
 
+-- The test case implicitly checks that locals will not be printed while
+-- checking the plan.
+test:test('locals', function(t)
+    t.locals = true
+    t:plan(1)
+    t:test('locals nested', function(t)
+        local a = 42
+        local tuple = box.tuple.new({})
+        t:plan(2)
+        t:ok(true, 'locals are not printed in case of success')
+        t:fail('locals are printed in case of fail')
+    end)
+end)
+
 --
 -- Finish root test. Since we used non-callback variant, we have to
 -- call check explicitly.
-- 
2.17.1

[tarantool-patches] Re: [PATCH] lua: show locals when a tap test fails

[Alexander Turenko]

Sorry, forgotten to update result file. Updated the branch now.

diff --git a/test/app-tap/tap.result b/test/app-tap/tap.result
index 36caa3023..ea6160191 100644
--- a/test/app-tap/tap.result
+++ b/test/app-tap/tap.result
@@ -157,6 +157,7 @@ ok - like
           ---
           locals:
             a: 42
+            tuple: []
           ...
         # locals nested: end
     not ok - failed subtests

WBR, Alexander Turenko.

On Sat, Aug 18, 2018 at 03:36:24PM +0300, Alexander Turenko wrote:
> Fixes #3627.
> ---
> 
> branch: Totktonada/gh-3627-tap-show-local-variables
> travis-ci: https://travis-ci.org/tarantool/tarantool/builds/417616160
> issue: https://github.com/tarantool/tarantool/issues/3627

[tarantool-patches] Re: [PATCH] lua: show locals when a tap test fails

[Alexander Turenko]

travis-ci: https://travis-ci.org/tarantool/tarantool/builds/417913593

WBR, Alexander Turenko.

On Sun, Aug 19, 2018 at 06:35:00PM +0300, Alexander Turenko wrote:
> Sorry, forgotten to update result file. Updated the branch now.
> 
> diff --git a/test/app-tap/tap.result b/test/app-tap/tap.result
> index 36caa3023..ea6160191 100644
> --- a/test/app-tap/tap.result
> +++ b/test/app-tap/tap.result
> @@ -157,6 +157,7 @@ ok - like
>            ---
>            locals:
>              a: 42
> +            tuple: []
>            ...
>          # locals nested: end
>      not ok - failed subtests
> 
> WBR, Alexander Turenko.
> 
> On Sat, Aug 18, 2018 at 03:36:24PM +0300, Alexander Turenko wrote:
> > Fixes #3627.
> > ---
> > 
> > branch: Totktonada/gh-3627-tap-show-local-variables
> > travis-ci: https://travis-ci.org/tarantool/tarantool/builds/417616160
> > issue: https://github.com/tarantool/tarantool/issues/3627
> 

[tarantool-patches] Re: [PATCH] lua: show locals when a tap test fails

[Vladislav Shpilevoy]

Hi! Thanks for the patch! See 7 comments below and the patch
on the branch.

On 18/08/2018 15:36, Alexander Turenko wrote:
> Fixes #3627.
> ---
> 
> branch: Totktonada/gh-3627-tap-show-local-variables
> travis-ci: https://travis-ci.org/tarantool/tarantool/builds/417616160
> issue: https://github.com/tarantool/tarantool/issues/3627
> 
>   src/lua/tap.lua           | 45 ++++++++++++++++++++++++++++++++++-----
>   test/app-tap/tap.result   | 26 ++++++++++++++++++++--
>   test/app-tap/tap.test.lua | 21 +++++++++++++++---
>   3 files changed, 82 insertions(+), 10 deletions(-)
> 
> diff --git a/src/lua/tap.lua b/src/lua/tap.lua
> index edc9f2211..9dd531422 100644
> --- a/src/lua/tap.lua
> +++ b/src/lua/tap.lua
> @@ -36,12 +36,43 @@ local function traceback(level)
>       return trace
>   end
>   
> +local function locals(test, level)
> +    level = level or 3
> +    local variables = {}
> +    local idx = 1
> +    while true do
> +      local name, value = debug.getlocal(level, idx)

1. Broken indentation: use 4 spaces, not 2.

> +      if name ~= nil then
> +          -- compare a table with a tuple raises an error, so we check types
> +          -- first

2. Please, start sentence with a capital letter and finish with
the dot.

3. Out of 66 symbols.

> +          local eq = type(value) == type(test) and value == test
> +          -- temporary values start with '('
> +          if not name:startswith('(') and not eq then
> +              variables[name] = value

4. So the variables, having nil value, are not showed?

> +          end
> +      else
> +          break
> +      end
> +      idx = 1 + idx
> +    end
> +    return variables
> +end
> @@ -221,6 +255,7 @@ local function test(parent, name, fun, ...)
>           failed  = 0;
>           planned = 0;
>           trace   = parent == nil and true or parent.trace;
> +        locals  = parent == nil and true or parent.locals;

5. If parent == nil, then this turns into 'true and true or ..',
so what is a point of 'and true'?

>       }, test_mt)
>       if fun ~= nil then
>           test:diag('%s', test.name)
> @@ -245,7 +280,7 @@ local function check(test)
>       if test.planned ~= test.total then
>           if test.parent ~= nil then
>               ok(test.parent, false, "bad plan", { planned = test.planned;
> -                run = test.total})
> +                run = test.total}, {locals = false})

6. Are we sure, that locals should be printed by default? Maybe
it would be better to print them on demand only via a global
option and remove per-test-case option? As I imagine a typical
test fail, when a test did not pass, you turn locals printing
on and run the test again.

>           else
>               diag(test, string.format("bad plan: planned %d run %d",
>                   test.planned, test.total))
> diff --git a/test/app-tap/tap.test.lua b/test/app-tap/tap.test.lua
> index 0e1de7f1c..29dc0b100 100755
> --- a/test/app-tap/tap.test.lua
> +++ b/test/app-tap/tap.test.lua
> @@ -12,15 +12,16 @@ local tap = require "tap"
>   -- Create a root test
>   --
>   test = tap.test("root test")
> --- Disable stack traces for this test because Tarantool test system also
> --- checks test output.
> +-- Disable stack traces and locals for this test because Tarantool test system
> +-- also checks test output.
>   test.trace = false
> +test.locals = false

7. In the comment 6 I meant exactly this: it is not
useful to reset locals, when I do not need them.

>   
>   --
>   -- ok, fail and skip predicates
>   --
>   
> -test:plan(32) -- plan to run 3 test
> +test:plan(33) -- plan to run 3 test
>   test:ok(true, 'true') -- basic function
>   local extra = { state = 'some userful information to debug on failure',
>           details = 'a table argument formatted using yaml.encode()' }

My diff (so far it is requested by SOP to paste it here):

[tarantool-patches] Re: [PATCH] lua: show locals when a tap test fails

[Vladislav Shpilevoy]

Sorry, forgot diff.

> 
> My diff (so far it is requested by SOP to paste it here):
> 

diff --git a/src/lua/tap.lua b/src/lua/tap.lua
index 9dd531422..625326065 100644
--- a/src/lua/tap.lua
+++ b/src/lua/tap.lua
@@ -41,21 +41,19 @@ local function locals(test, level)
      local variables = {}
      local idx = 1
      while true do
-      local name, value = debug.getlocal(level, idx)
-      if name ~= nil then
-          -- compare a table with a tuple raises an error, so we check types
-          -- first
-          local eq = type(value) == type(test) and value == test
-          -- temporary values start with '('
-          if not name:startswith('(') and not eq then
-              variables[name] = value
-          end
-      else
-          break
-      end
-      idx = 1 + idx
+        local name, value = debug.getlocal(level, idx)
+        if not name then
+            return variables
+        end
+        -- Compare a table with a tuple raises an error, so we
+        -- check types first.
+        local is_test = type(value) == type(test) and value == test
+        -- Temporary values start with '('.
+        if not name:startswith('(') and not is_test then
+            variables[name] = value
+        end
+        idx = idx + 1
      end
-    return variables
  end
  
  local function diag(test, fmt, ...)

[tarantool-patches] Re: [PATCH] lua: show locals when a tap test fails

[Alexander Turenko]

Hi!

Thanks for the comments. Answered inline.

I squashed all changes into the one commit and rebased on top of fresh
1.10.

branch: https://github.com/tarantool/tarantool/tree/Totktonada/gh-3627-tap-show-local-variables
issue: https://github.com/tarantool/tarantool/issues/3627

WBR, Alexander Turenko.

> > +local function locals(test, level)
> > +    level = level or 3
> > +    local variables = {}
> > +    local idx = 1
> > +    while true do
> > +      local name, value = debug.getlocal(level, idx)
> 
> 1. Broken indentation: use 4 spaces, not 2.
> 

Fixed by your patch.

> > +      if name ~= nil then
> > +          -- compare a table with a tuple raises an error, so we check types
> > +          -- first
> 
> 2. Please, start sentence with a capital letter and finish with
> the dot.
> 
> 3. Out of 66 symbols.
> 

Fixed by your patch.

> > +          local eq = type(value) == type(test) and value == test
> > +          -- temporary values start with '('
> > +          if not name:startswith('(') and not eq then
> > +              variables[name] = value
> 
> 4. So the variables, having nil value, are not showed?
> 

Yep. We can write it as '[nil]' or like so, but don't sure it worth to
do.

> >           trace   = parent == nil and true or parent.trace;
> > +        locals  = parent == nil and true or parent.locals;
> 
> 5. If parent == nil, then this turns into 'true and true or ..',
> so what is a point of 'and true'?
> 

Fixed.

> > @@ -245,7 +280,7 @@ local function check(test)
> >       if test.planned ~= test.total then
> >           if test.parent ~= nil then
> >               ok(test.parent, false, "bad plan", { planned = test.planned;
> > -                run = test.total})
> > +                run = test.total}, {locals = false})
> 
> 6. Are we sure, that locals should be printed by default? Maybe
> it would be better to print them on demand only via a global
> option and remove per-test-case option? As I imagine a typical
> test fail, when a test did not pass, you turn locals printing
> on and run the test again.
> 

The primary reason of the option is to omit the second run. It is more
useful when the fail is flaky or when it occurs in CI. If you going to
do second run you can print anything you want manually.

So I think it worth to enable it by default or discard the patch
entirely. Or maybe control it from an environment variable.

I personally use the patch around month locally. It sometimes gives very
large output (graphql schemas), but saves time to write something like
`print(require('yaml').encode(res))` each time a test fails.

If you dislike such extra output for failing tests, we should skip the
patch entirely. It is useful or not useful, not something in the middle.

> > --- Disable stack traces for this test because Tarantool test system also
> > --- checks test output.
> > +-- Disable stack traces and locals for this test because Tarantool test system
> > +-- also checks test output.
> >   test.trace = false
> > +test.locals = false
> 
> 7. In the comment 6 I meant exactly this: it is not
> useful to reset locals, when I do not need them.
> 

The reason here is just same as for `test.trace = false`: to compare
output of the module 'tap' easily in the test.

My diff:

diff --git a/src/lua/tap.lua b/src/lua/tap.lua
index 625326065..765c62c77 100644
--- a/src/lua/tap.lua
+++ b/src/lua/tap.lua
@@ -252,8 +252,8 @@ local function test(parent, name, fun, ...)
         total   = 0;
         failed  = 0;
         planned = 0;
-        trace   = parent == nil and true or parent.trace;
-        locals  = parent == nil and true or parent.locals;
+        trace   = parent == nil or parent.trace;
+        locals  = parent == nil or parent.locals;
     }, test_mt)
     if fun ~= nil then
         test:diag('%s', test.name)

[tarantool-patches] Re: [PATCH] lua: show locals when a tap test fails

[Vladislav Shpilevoy]

Hi! Thanks for the fixes!

>>> @@ -245,7 +280,7 @@ local function check(test)
>>>        if test.planned ~= test.total then
>>>            if test.parent ~= nil then
>>>                ok(test.parent, false, "bad plan", { planned = test.planned;
>>> -                run = test.total})
>>> +                run = test.total}, {locals = false})
>>
>> 6. Are we sure, that locals should be printed by default? Maybe
>> it would be better to print them on demand only via a global
>> option and remove per-test-case option? As I imagine a typical
>> test fail, when a test did not pass, you turn locals printing
>> on and run the test again.
>>
> 
> The primary reason of the option is to omit the second run. It is more
> useful when the fail is flaky or when it occurs in CI. If you going to
> do second run you can print anything you want manually.
> 
> So I think it worth to enable it by default or discard the patch
> entirely. Or maybe control it from an environment variable.
> 
> I personally use the patch around month locally. It sometimes gives very
> large output (graphql schemas), but saves time to write something like
> `print(require('yaml').encode(res))` each time a test fails.
> 
> If you dislike such extra output for failing tests, we should skip the
> patch entirely. It is useful or not useful, not something in the middle.

Understandable. Then LGTM, looks useful.

[tarantool-patches] Re: [PATCH] lua: show locals when a tap test fails

[Alexander Turenko]

On Mon, Sep 24, 2018 at 01:47:45PM +0300, Vladislav Shpilevoy wrote:
> Hi! Thanks for the fixes!
> 
> > > > @@ -245,7 +280,7 @@ local function check(test)
> > > >        if test.planned ~= test.total then
> > > >            if test.parent ~= nil then
> > > >                ok(test.parent, false, "bad plan", { planned = test.planned;
> > > > -                run = test.total})
> > > > +                run = test.total}, {locals = false})
> > > 
> > > 6. Are we sure, that locals should be printed by default? Maybe
> > > it would be better to print them on demand only via a global
> > > option and remove per-test-case option? As I imagine a typical
> > > test fail, when a test did not pass, you turn locals printing
> > > on and run the test again.
> > > 
> > 
> > The primary reason of the option is to omit the second run. It is more
> > useful when the fail is flaky or when it occurs in CI. If you going to
> > do second run you can print anything you want manually.
> > 
> > So I think it worth to enable it by default or discard the patch
> > entirely. Or maybe control it from an environment variable.
> > 
> > I personally use the patch around month locally. It sometimes gives very
> > large output (graphql schemas), but saves time to write something like
> > `print(require('yaml').encode(res))` each time a test fails.
> > 
> > If you dislike such extra output for failing tests, we should skip the
> > patch entirely. It is useful or not useful, not something in the middle.
> 
> Understandable. Then LGTM, looks useful.
> 

To be honest, now I don't so sure in the thought that we should enable
it by default or discard completely. Sometimes it is useful to have
clean picture which cases are passed and which are not w/o extra
information (w/o locals and w/o traces). But sometimes it is useful to
know exact reason of a certain fail and have as much info as possible
(so locals are helpful).

When work on a patch locally both situations occur. Don't sure about CI.

Now I thinking about the following implementation: save locals for a
first failing case, print it after the whole test in the uppermost
test:check() and then print cases list (with ok/not ok, name and so on)
again to bring it to the focus. It gives both benefits: a developer does
not have to scroll for pass/fail list and have detailed info available
after some scrolling.

We could simplify that to 'print traces and locals during the test, then
give a short list in the uppermost test:check()', but there is a
pitfall. When something (say, a test case preparation) lead to premature
exit (say, because of a raised error) we still want to see the whole
picture (what is passed and what is failed) at the first glance and
then, maybe, detailed information about the fail. With the proposed
implementation we'll get the cases list, but not details: I think it is
better then vice versa.

So, to sum it up, I propose to keep a during-test output short, then, if
the test reach the uppermost test:check(), give details and repeat the
short cases list.

Now I think how better to handle the raised error case. Maybe it worth
to do xpcall around the whole test and then traverse over a stack to
find a frame with the uppermost test and print locals for that frame.
I'm thinking whether it is implementable w/o extra handle from a test
writer, say, as a global option (_G.print_test_locals_before_exit) of
tarantool that can be set by test-run.

Ugh, tricky thing...

WBR, Alexander Turenko.

[tarantool-patches] Re: [PATCH] lua: show locals when a tap test fails

[Alexander Turenko]

On Thu, Sep 27, 2018 at 03:45:16AM +0300, Alexander Turenko wrote:
> On Mon, Sep 24, 2018 at 01:47:45PM +0300, Vladislav Shpilevoy wrote:
> > Hi! Thanks for the fixes!
> > 
> > > > > @@ -245,7 +280,7 @@ local function check(test)
> > > > >        if test.planned ~= test.total then
> > > > >            if test.parent ~= nil then
> > > > >                ok(test.parent, false, "bad plan", { planned = test.planned;
> > > > > -                run = test.total})
> > > > > +                run = test.total}, {locals = false})
> > > > 
> > > > 6. Are we sure, that locals should be printed by default? Maybe
> > > > it would be better to print them on demand only via a global
> > > > option and remove per-test-case option? As I imagine a typical
> > > > test fail, when a test did not pass, you turn locals printing
> > > > on and run the test again.
> > > > 
> > > 
> > > The primary reason of the option is to omit the second run. It is more
> > > useful when the fail is flaky or when it occurs in CI. If you going to
> > > do second run you can print anything you want manually.
> > > 
> > > So I think it worth to enable it by default or discard the patch
> > > entirely. Or maybe control it from an environment variable.
> > > 
> > > I personally use the patch around month locally. It sometimes gives very
> > > large output (graphql schemas), but saves time to write something like
> > > `print(require('yaml').encode(res))` each time a test fails.
> > > 
> > > If you dislike such extra output for failing tests, we should skip the
> > > patch entirely. It is useful or not useful, not something in the middle.
> > 
> > Understandable. Then LGTM, looks useful.
> > 
> 
> To be honest, now I don't so sure in the thought that we should enable
> it by default or discard completely. Sometimes it is useful to have
> clean picture which cases are passed and which are not w/o extra
> information (w/o locals and w/o traces). But sometimes it is useful to
> know exact reason of a certain fail and have as much info as possible
> (so locals are helpful).
> 
> When work on a patch locally both situations occur. Don't sure about CI.
> 
> Now I thinking about the following implementation: save locals for a
> first failing case, print it after the whole test in the uppermost
> test:check() and then print cases list (with ok/not ok, name and so on)
> again to bring it to the focus. It gives both benefits: a developer does
> not have to scroll for pass/fail list and have detailed info available
> after some scrolling.
> 
> We could simplify that to 'print traces and locals during the test, then
> give a short list in the uppermost test:check()', but there is a
> pitfall. When something (say, a test case preparation) lead to premature
> exit (say, because of a raised error) we still want to see the whole
> picture (what is passed and what is failed) at the first glance and
> then, maybe, detailed information about the fail. With the proposed
> implementation we'll get the cases list, but not details: I think it is
> better then vice versa.
> 
> So, to sum it up, I propose to keep a during-test output short, then, if
> the test reach the uppermost test:check(), give details and repeat the
> short cases list.
> 
> Now I think how better to handle the raised error case. Maybe it worth
> to do xpcall around the whole test and then traverse over a stack to
> find a frame with the uppermost test and print locals for that frame.
> I'm thinking whether it is implementable w/o extra handle from a test
> writer, say, as a global option (_G.print_test_locals_before_exit) of
> tarantool that can be set by test-run.
> 
> Ugh, tricky thing...
> 
> WBR, Alexander Turenko.

I retained myself from implementing the complex and unobvious behaviour.

Now it is disabled by default.

Rebased on top of 2.1.

The diff from the previous version and the full diff are below.

https://github.com/tarantool/tarantool/issues/3627
https://github.com/tarantool/tarantool/tree/Totktonada/gh-3627-tap-show-local-variables
https://travis-ci.org/tarantool/tarantool/builds/444149450

WBR, Alexander Turenko.

Diff from the previous version
------------------------------

diff --git a/src/lua/tap.lua b/src/lua/tap.lua
index 5074305d3..d0f8b08c6 100644
--- a/src/lua/tap.lua
+++ b/src/lua/tap.lua
@@ -69,7 +69,7 @@ local function ok(test, cond, message, extra, opts)
     elseif test.locals ~= nil then
         show_locals = test.locals
     else
-        show_locals = true
+        show_locals = false
     end
     test.total = test.total + 1
     io.write(string.rep(' ', 4 * test.level))
@@ -257,7 +257,7 @@ local function test(parent, name, fun, ...)
         failed  = 0;
         planned = 0;
         trace   = parent == nil or parent.trace;
-        locals  = parent == nil or parent.locals;
+        locals  = parent ~= nil and parent.locals;
     }, test_mt)
     if fun ~= nil then
         test:diag('%s', test.name)
@@ -281,6 +281,7 @@ local function check(test)
     test.checked = true
     if test.planned ~= test.total then
         if test.parent ~= nil then
+            -- Do not show locals with the 'bad plan' message.
             ok(test.parent, false, "bad plan", { planned = test.planned;
                 run = test.total}, {locals = false})
         else
@@ -289,6 +290,8 @@ local function check(test)
         end
     elseif test.failed > 0 then
         if test.parent ~= nil then
+            -- Do not show locals with the 'failed subtests'
+            -- message.
             ok(test.parent, false, "failed subtests", {
                 failed = test.failed;
                 planned = test.planned;
@@ -298,7 +301,7 @@ local function check(test)
         end
     else
         if test.parent ~= nil then
-            ok(test.parent, true, test.name, {locals = false})
+            ok(test.parent, true, test.name)
         end
     end
     return test.planned == test.total and test.failed == 0
diff --git a/test/app-tap/tap.test.lua b/test/app-tap/tap.test.lua
index 29dc0b100..a810be3f6 100755
--- a/test/app-tap/tap.test.lua
+++ b/test/app-tap/tap.test.lua
@@ -12,10 +12,9 @@ local tap = require "tap"
 -- Create a root test
 --
 test = tap.test("root test")
--- Disable stack traces and locals for this test because Tarantool test system
--- also checks test output.
+-- Disable stack traces for this test because Tarantool test system also
+-- checks test output.
 test.trace = false
-test.locals = false
 
 --
 -- ok, fail and skip predicates

Full diff
---------

diff --git a/src/lua/tap.lua b/src/lua/tap.lua
index 546d15392..d0f8b08c6 100644
--- a/src/lua/tap.lua
+++ b/src/lua/tap.lua
@@ -1,6 +1,6 @@
 --- tap.lua internal file
 ---
---- The Test Anything Protocol vesion 13 producer
+--- The Test Anything Protocol version 13 producer
 ---
 
 -- yaml formatter must be able to encode any Lua variable
@@ -36,12 +36,41 @@ local function traceback(level)
     return trace
 end
 
+local function locals(test, level)
+    level = level or 3
+    local variables = {}
+    local idx = 1
+    while true do
+        local name, value = debug.getlocal(level, idx)
+        if not name then
+            return variables
+        end
+        -- Compare a table with a tuple raises an error, so we
+        -- check types first.
+        local is_test = type(value) == type(test) and value == test
+        -- Temporary values start with '('.
+        if not name:startswith('(') and not is_test then
+            variables[name] = value
+        end
+        idx = idx + 1
+    end
+end
+
 local function diag(test, fmt, ...)
     io.write(string.rep(' ', 4 * test.level), "# ", string.format(fmt, ...),
         "\n")
 end
 
-local function ok(test, cond, message, extra)
+local function ok(test, cond, message, extra, opts)
+    opts = opts or {}
+    local show_locals
+    if opts.locals ~= nil then
+        show_locals = opts.locals
+    elseif test.locals ~= nil then
+        show_locals = test.locals
+    else
+        show_locals = false
+    end
     test.total = test.total + 1
     io.write(string.rep(' ', 4 * test.level))
     if cond then
@@ -58,6 +87,9 @@ local function ok(test, cond, message, extra)
         extra.filename = extra.trace[#extra.trace].filename
         extra.line = extra.trace[#extra.trace].line
     end
+    if show_locals then
+        extra.locals = locals(test)
+    end
     if next(extra) == nil then
         return false -- don't have extra information
     end
@@ -224,7 +256,8 @@ local function test(parent, name, fun, ...)
         total   = 0;
         failed  = 0;
         planned = 0;
-        trace   = parent == nil and true or parent.trace;
+        trace   = parent == nil or parent.trace;
+        locals  = parent ~= nil and parent.locals;
     }, test_mt)
     if fun ~= nil then
         test:diag('%s', test.name)
@@ -248,18 +281,21 @@ local function check(test)
     test.checked = true
     if test.planned ~= test.total then
         if test.parent ~= nil then
+            -- Do not show locals with the 'bad plan' message.
             ok(test.parent, false, "bad plan", { planned = test.planned;
-                run = test.total})
+                run = test.total}, {locals = false})
         else
             diag(test, string.format("bad plan: planned %d run %d",
                 test.planned, test.total))
         end
     elseif test.failed > 0 then
         if test.parent ~= nil then
+            -- Do not show locals with the 'failed subtests'
+            -- message.
             ok(test.parent, false, "failed subtests", {
                 failed = test.failed;
                 planned = test.planned;
-            })
+            }, {locals = false})
         else
             diag(test, "failed subtest: %d", test.failed)
         end
diff --git a/test/app-tap/tap.result b/test/app-tap/tap.result
index 3e7882331..ea6160191 100644
--- a/test/app-tap/tap.result
+++ b/test/app-tap/tap.result
@@ -1,5 +1,5 @@
 TAP version 13
-1..32
+1..33
 ok - true
 ok - extra information is not printed on success
 not ok - extra printed using yaml only on failure
@@ -148,4 +148,27 @@ not ok - failed subtests
     ok - unlike(abcde, acd)
     # like: end
 ok - like
-# failed subtest: 15
+    # locals
+    1..1
+        # locals nested
+        1..2
+        ok - locals are not printed in case of success
+        not ok - locals are printed in case of fail
+          ---
+          locals:
+            a: 42
+            tuple: []
+          ...
+        # locals nested: end
+    not ok - failed subtests
+      ---
+      planned: 2
+      failed: 1
+      ...
+    # locals: end
+not ok - failed subtests
+  ---
+  planned: 1
+  failed: 1
+  ...
+# failed subtest: 16
diff --git a/test/app-tap/tap.test.lua b/test/app-tap/tap.test.lua
index 0e1de7f1c..a810be3f6 100755
--- a/test/app-tap/tap.test.lua
+++ b/test/app-tap/tap.test.lua
@@ -20,7 +20,7 @@ test.trace = false
 -- ok, fail and skip predicates
 --
 
-test:plan(32) -- plan to run 3 test
+test:plan(33) -- plan to run 3 test
 test:ok(true, 'true') -- basic function
 local extra = { state = 'some userful information to debug on failure',
         details = 'a table argument formatted using yaml.encode()' }
@@ -136,6 +136,20 @@ test:test('like', function(t)
     t:unlike('abcde', 'acd', 'unlike(abcde, acd)')
 end)
 
+-- The test case implicitly checks that locals will not be printed while
+-- checking the plan.
+test:test('locals', function(t)
+    t.locals = true
+    t:plan(1)
+    t:test('locals nested', function(t)
+        local a = 42
+        local tuple = box.tuple.new({})
+        t:plan(2)
+        t:ok(true, 'locals are not printed in case of success')
+        t:fail('locals are printed in case of fail')
+    end)
+end)
+
 --
 -- Finish root test. Since we used non-callback variant, we have to
 -- call check explicitly.