[PATCH 0/2] fix bodiless requests handling.

[PATCH 0/2] fix bodiless requests handling.

[Serge Petrenko]

The first patch fixes an error when trying to parse a bodiless request
such as IPROTO_NOP in `tarantoolctl cat` and `tarantoolctl play`.
Now cat displays such requests correctly and play ignores them.
https://github.com/tarantool/tarantool/issues/3675

The second patch fixes parsing xlogs containing transactions with
empty body requests. Such requests weren't handled correctly which lead to
header of the next request become body of a no-op request. This messed up recovery
and `tarantoolctl cat`. Both fixed.
https://github.com/tarantool/tarantool/issues/3678

Branch:
https://github.com/tarantool/tarantool/tree/sp/gh-3675-tarantoolctl-cat-empty-body

Serge Petrenko (2):
  tarantoolctl: fix cat and play for empty body requests
  recovery: fix incorrect handling of empty-body requests.

 extra/dist/tarantoolctl.in         | 11 +++---
 src/box/xrow.c                     |  6 +++-
 test/app-tap/tarantoolctl.test.lua | 14 ++++++--
 test/xlog/recover_nop.result       | 72 ++++++++++++++++++++++++++++++++++++++
 test/xlog/recover_nop.test.lua     | 28 +++++++++++++++
 5 files changed, 123 insertions(+), 8 deletions(-)
 create mode 100644 test/xlog/recover_nop.result
 create mode 100644 test/xlog/recover_nop.test.lua

-- 
2.15.2 (Apple Git-101.1)

[PATCH 1/2] tarantoolctl: fix cat and play for empty body requests

[Serge Petrenko]

If space.before_replace returns the old tuple, the operation turns into
no-op, but is still written to WAL as IPROTO_NOP for the sake of
replication. Such a request doesn't have a body, and tarantoolctl failed
to parse such requests in `tarantoolctl cat` and `tarantoolctl play`.
Fix this by checking whether a request has a body. Also skip such
requests in `play`, since they have no effect.

Closes #3675
---
 extra/dist/tarantoolctl.in         | 11 +++++++----
 test/app-tap/tarantoolctl.test.lua | 14 +++++++++++---
 2 files changed, 18 insertions(+), 7 deletions(-)

diff --git a/extra/dist/tarantoolctl.in b/extra/dist/tarantoolctl.in
index 3d7ff3ec5..a6bd15e95 100755
--- a/extra/dist/tarantoolctl.in
+++ b/extra/dist/tarantoolctl.in
@@ -373,6 +373,9 @@ write_lua_table = function(tuple)
 end
 
 local function cat_lua_cb(record)
+    if record.HEADER.type == 'NOP' then
+        return
+    end
     io.stdout:write(('box.space[%d]'):format(record.BODY.space_id))
     local op = record.HEADER.type:lower()
     io.stdout:write((':%s('):format(op))
@@ -816,7 +819,7 @@ local function cat()
     for id, file in ipairs(positional_arguments) do
         log.error("Processing file '%s'", file)
         for lsn, record in xlog.pairs(file) do
-            local sid = record.BODY.space_id
+            local sid = record.BODY and record.BODY.space_id
             local rid = record.HEADER.replica_id
             if (lsn < from) or
                (not spaces and sid and sid < 512 and not show_system) or
@@ -857,11 +860,11 @@ local function play()
     for id, file in ipairs(positional_arguments) do
         log.info(("Processing file '%s'"):format(file))
         for lsn, record in xlog.pairs(file) do
-            local sid = record.BODY.space_id
+            local sid = record.BODY and record.BODY.space_id
             local rid = record.HEADER.replica_id
-            if (lsn < from) or
+            if (lsn < from) or sid == nil or
                (not spaces and sid and sid < 512 and not show_system) or
-               (spaces and (sid == nil or not find_in_list(sid, spaces))) or
+               (spaces and not find_in_list(sid, spaces)) or
                (replicas and not find_in_list(rid, replicas)) then
                 -- pass this tuple
             elseif lsn >= to then
diff --git a/test/app-tap/tarantoolctl.test.lua b/test/app-tap/tarantoolctl.test.lua
index 340232ace..458e6c030 100755
--- a/test/app-tap/tarantoolctl.test.lua
+++ b/test/app-tap/tarantoolctl.test.lua
@@ -345,6 +345,10 @@ do
         space:update({[1] = 2}, {[1] = {[1] = '\x3d', [2] = 3, [3] = 4}})
         space:upsert({[1] = 3, [2] = 4, [3] = 5, [4] = 6}, {[1] = {[1] = '\x3d', [2] = 3, [3] = 4}})
         space:upsert({[1] = 3, [2] = 4, [3] = 5, [4] = 6}, {[1] = {[1] = '\x3d', [2] = 3, [3] = 4}})
+        f = function(old, new) return old end
+        space:before_replace(f)
+        space:replace{1,5}
+        space:before_replace(nil, f)
         os.exit(0)
     ]]
 
@@ -372,11 +376,11 @@ do
         test:test("fill and test cat output", function(test_i)
             test_i:plan(29)
             check_ok(test_i, dir, 'start', 'filler', 0)
-            check_ctlcat_xlog(test_i, dir, nil, "---\n", 6)
+            check_ctlcat_xlog(test_i, dir, nil, "---\n", 7)
             check_ctlcat_xlog(test_i, dir, "--space=512", "---\n", 6)
             check_ctlcat_xlog(test_i, dir, "--space=666", "---\n", 0)
-            check_ctlcat_xlog(test_i, dir, "--show-system", "---\n", 9)
-            check_ctlcat_xlog(test_i, dir, "--format=json", "\n", 6)
+            check_ctlcat_xlog(test_i, dir, "--show-system", "---\n", 10)
+            check_ctlcat_xlog(test_i, dir, "--format=json", "\n", 7)
             check_ctlcat_xlog(test_i, dir, "--format=lua",  "\n", 6)
             check_ctlcat_xlog(test_i, dir, "--from=3 --to=6 --format=json", "\n", 2)
             check_ctlcat_xlog(test_i, dir, "--from=3 --to=6 --format=json --show-system", "\n", 3)
@@ -411,6 +415,10 @@ do
         space:update({[1] = 2}, {[1] = {[1] = '\x3d', [2] = 3, [3] = 4}})
         space:upsert({[1] = 3, [2] = 4, [3] = 5, [4] = 6}, {[1] = {[1] = '\x3d', [2] = 3, [3] = 4}})
         space:upsert({[1] = 3, [2] = 4, [3] = 5, [4] = 6}, {[1] = {[1] = '\x3d', [2] = 3, [3] = 4}})
+        f = function(old, new) return old end
+        space:before_replace(f)
+        space:replace{1,5}
+        space:before_replace(nil, f)
         os.exit(0)
     ]]
     create_script(dir, 'filler.lua', filler_code)
-- 
2.15.2 (Apple Git-101.1)

[PATCH 2/2] recovery: fix incorrect handling of empty-body requests.

[Serge Petrenko]

In some cases no-ops are written to xlog. They have no effect but are
needed to bump lsn. Such ops have no body, and empty body requests are
not handled in xrow_header_decode(). This leads to recovery errors in
special case: when we have a multi-statement transaction containing
no-ops written to xlog, upon recovering from such xlog, all data after
the no-op end till the start of new transaction will become no-ops body,
so, effectively, it will be ignored. Here's example `tarantoolctl cat`
output showing this (BODY contains next request data):
```
    ---
    HEADER:
      lsn: 5
      replica_id: 1
      type: NOP
      timestamp: 1536656270.5092
    BODY:
      type: 3
      timestamp: 1536656270.5092
      lsn: 6
      replica_id: 1
    ---
    HEADER:
      type: 0
    ...
```
This patch handles no-ops correctly in xrow_header_decode().

Closes #3678
---
 src/box/xrow.c                 |  6 +++-
 test/xlog/recover_nop.result   | 72 ++++++++++++++++++++++++++++++++++++++++++
 test/xlog/recover_nop.test.lua | 28 ++++++++++++++++
 3 files changed, 105 insertions(+), 1 deletion(-)
 create mode 100644 test/xlog/recover_nop.result
 create mode 100644 test/xlog/recover_nop.test.lua

diff --git a/src/box/xrow.c b/src/box/xrow.c
index 7a35d0db1..99dce5395 100644
--- a/src/box/xrow.c
+++ b/src/box/xrow.c
@@ -99,6 +99,8 @@ error:
 	if (mp_typeof(**pos) != MP_MAP)
 		goto error;
 
+	bool expect_body = true;
+
 	uint32_t size = mp_decode_map(pos);
 	for (uint32_t i = 0; i < size; i++) {
 		if (mp_typeof(**pos) != MP_UINT)
@@ -110,6 +112,8 @@ error:
 		switch (key) {
 		case IPROTO_REQUEST_TYPE:
 			header->type = mp_decode_uint(pos);
+			if (header->type == IPROTO_NOP)
+				expect_body = false;
 			break;
 		case IPROTO_SYNC:
 			header->sync = mp_decode_uint(pos);
@@ -135,7 +139,7 @@ error:
 		}
 	}
 	assert(*pos <= end);
-	if (*pos < end) {
+	if (*pos < end && expect_body) {
 		const char *body = *pos;
 		if (mp_check(pos, end)) {
 			diag_set(ClientError, ER_INVALID_MSGPACK, "packet body");
diff --git a/test/xlog/recover_nop.result b/test/xlog/recover_nop.result
new file mode 100644
index 000000000..e6aad41a7
--- /dev/null
+++ b/test/xlog/recover_nop.result
@@ -0,0 +1,72 @@
+test_run = require('test_run').new()
+---
+...
+test_run:cmd('restart server default with cleanup=1')
+-- gh-3678 check for correct recovery with nops in transaction.
+s = box.schema.space.create('test')
+---
+...
+_ = s:create_index('pk')
+---
+...
+s:replace{1,1}
+---
+- [1, 1]
+...
+f = function(old, new) return old end
+---
+...
+box.begin() s:before_replace(f) s:replace{1,2} s:before_replace(nil, f) s:replace{1,3} box.commit()
+---
+...
+s:select{}
+---
+- - [1, 3]
+...
+test_run:cmd('restart server default')
+xlog = require('xlog')
+---
+...
+fio = require('fio')
+---
+...
+box.space.test:select{}
+---
+- - [1, 3]
+...
+xlog_path = fio.pathjoin(box.cfg.wal_dir, string.format('%020d.xlog', 0))
+---
+...
+fun, param, state = xlog.pairs(xlog_path)
+---
+...
+repeat state, row = fun(param, state) until row.HEADER.type == 'NOP'
+---
+...
+row.BODY == nil
+---
+- true
+...
+state, row = fun(param, state)
+---
+...
+row.HEADER.lsn
+---
+- 6
+...
+row.HEADER.replica_id
+---
+- 1
+...
+row.HEADER.type
+---
+- REPLACE
+...
+row.BODY
+---
+- space_id: 512
+  tuple: [1, 3]
+...
+box.space.test:drop()
+---
+...
diff --git a/test/xlog/recover_nop.test.lua b/test/xlog/recover_nop.test.lua
new file mode 100644
index 000000000..de8f8ef42
--- /dev/null
+++ b/test/xlog/recover_nop.test.lua
@@ -0,0 +1,28 @@
+test_run = require('test_run').new()
+
+test_run:cmd('restart server default with cleanup=1')
+-- gh-3678 check for correct recovery with nops in transaction.
+s = box.schema.space.create('test')
+_ = s:create_index('pk')
+s:replace{1,1}
+f = function(old, new) return old end
+box.begin() s:before_replace(f) s:replace{1,2} s:before_replace(nil, f) s:replace{1,3} box.commit()
+s:select{}
+
+test_run:cmd('restart server default')
+
+xlog = require('xlog')
+fio = require('fio')
+
+box.space.test:select{}
+xlog_path = fio.pathjoin(box.cfg.wal_dir, string.format('%020d.xlog', 0))
+fun, param, state = xlog.pairs(xlog_path)
+repeat state, row = fun(param, state) until row.HEADER.type == 'NOP'
+row.BODY == nil
+state, row = fun(param, state)
+row.HEADER.lsn
+row.HEADER.replica_id
+row.HEADER.type
+row.BODY
+
+box.space.test:drop()
-- 
2.15.2 (Apple Git-101.1)

Re: [PATCH 1/2] tarantoolctl: fix cat and play for empty body requests

[Vladimir Davydov]

On Fri, Sep 14, 2018 at 05:36:40PM +0300, Serge Petrenko wrote:
> If space.before_replace returns the old tuple, the operation turns into
> no-op, but is still written to WAL as IPROTO_NOP for the sake of
> replication. Such a request doesn't have a body, and tarantoolctl failed
> to parse such requests in `tarantoolctl cat` and `tarantoolctl play`.
> Fix this by checking whether a request has a body. Also skip such
> requests in `play`, since they have no effect.
> 
> Closes #3675
> ---
>  extra/dist/tarantoolctl.in         | 11 +++++++----
>  test/app-tap/tarantoolctl.test.lua | 14 +++++++++++---
>  2 files changed, 18 insertions(+), 7 deletions(-)
> 
> diff --git a/extra/dist/tarantoolctl.in b/extra/dist/tarantoolctl.in
> index 3d7ff3ec5..a6bd15e95 100755
> --- a/extra/dist/tarantoolctl.in
> +++ b/extra/dist/tarantoolctl.in
> @@ -373,6 +373,9 @@ write_lua_table = function(tuple)
>  end
>  
>  local function cat_lua_cb(record)
> +    if record.HEADER.type == 'NOP' then
> +        return
> +    end

IMO better check 'record.BODY.space_id' instead of the type, because the
code below tries to use it.

>      io.stdout:write(('box.space[%d]'):format(record.BODY.space_id))
>      local op = record.HEADER.type:lower()
>      io.stdout:write((':%s('):format(op))
> @@ -816,7 +819,7 @@ local function cat()
>      for id, file in ipairs(positional_arguments) do
>          log.error("Processing file '%s'", file)
>          for lsn, record in xlog.pairs(file) do
> -            local sid = record.BODY.space_id
> +            local sid = record.BODY and record.BODY.space_id
>              local rid = record.HEADER.replica_id
>              if (lsn < from) or
>                 (not spaces and sid and sid < 512 and not show_system) or
> @@ -857,11 +860,11 @@ local function play()
>      for id, file in ipairs(positional_arguments) do
>          log.info(("Processing file '%s'"):format(file))
>          for lsn, record in xlog.pairs(file) do
> -            local sid = record.BODY.space_id
> +            local sid = record.BODY and record.BODY.space_id
>              local rid = record.HEADER.replica_id
> -            if (lsn < from) or
> +            if (lsn < from) or sid == nil or
>                 (not spaces and sid and sid < 512 and not show_system) or

'and sid' is useless after this change

Anyway, strictly speaking this is incorrect, because you won't stop on
a NOP record with lsn >= to, as you're supposed to.

> -               (spaces and (sid == nil or not find_in_list(sid, spaces))) or
> +               (spaces and not find_in_list(sid, spaces)) or
>                 (replicas and not find_in_list(rid, replicas)) then
>                  -- pass this tuple
>              elseif lsn >= to then

Re: [PATCH 2/2] recovery: fix incorrect handling of empty-body requests.

[Vladimir Davydov]

On Fri, Sep 14, 2018 at 05:36:41PM +0300, Serge Petrenko wrote:
> In some cases no-ops are written to xlog. They have no effect but are
> needed to bump lsn. Such ops have no body, and empty body requests are
> not handled in xrow_header_decode(). This leads to recovery errors in
> special case: when we have a multi-statement transaction containing
> no-ops written to xlog, upon recovering from such xlog, all data after
> the no-op end till the start of new transaction will become no-ops body,
> so, effectively, it will be ignored. Here's example `tarantoolctl cat`
> output showing this (BODY contains next request data):
> ```
>     ---
>     HEADER:
>       lsn: 5
>       replica_id: 1
>       type: NOP
>       timestamp: 1536656270.5092
>     BODY:
>       type: 3
>       timestamp: 1536656270.5092
>       lsn: 6
>       replica_id: 1
>     ---
>     HEADER:
>       type: 0
>     ...
> ```
> This patch handles no-ops correctly in xrow_header_decode().
> 
> Closes #3678
> ---
>  src/box/xrow.c                 |  6 +++-
>  test/xlog/recover_nop.result   | 72 ++++++++++++++++++++++++++++++++++++++++++
>  test/xlog/recover_nop.test.lua | 28 ++++++++++++++++
>  3 files changed, 105 insertions(+), 1 deletion(-)
>  create mode 100644 test/xlog/recover_nop.result
>  create mode 100644 test/xlog/recover_nop.test.lua
> 
> diff --git a/src/box/xrow.c b/src/box/xrow.c
> index 7a35d0db1..99dce5395 100644
> --- a/src/box/xrow.c
> +++ b/src/box/xrow.c
> @@ -99,6 +99,8 @@ error:
>  	if (mp_typeof(**pos) != MP_MAP)
>  		goto error;
>  
> +	bool expect_body = true;
> +
>  	uint32_t size = mp_decode_map(pos);
>  	for (uint32_t i = 0; i < size; i++) {
>  		if (mp_typeof(**pos) != MP_UINT)
> @@ -110,6 +112,8 @@ error:
>  		switch (key) {
>  		case IPROTO_REQUEST_TYPE:
>  			header->type = mp_decode_uint(pos);
> +			if (header->type == IPROTO_NOP)
> +				expect_body = false;
>  			break;
>  		case IPROTO_SYNC:
>  			header->sync = mp_decode_uint(pos);
> @@ -135,7 +139,7 @@ error:
>  		}
>  	}
>  	assert(*pos <= end);
> -	if (*pos < end) {
> +	if (*pos < end && expect_body) {

Why not simply

	/* NOP request isn't supposed to have a body. */
	if (*pos < end && header->type != IPROTO_NOP) {

?

Anyway, there's a problem here: NOP requests used to have a body, see
commit 89e5b7846c9d ("xrow: make NOP requests bodiless"), i.e. this
function has to decode NOP requests with and without a body.

I don't know what to do about it, because we can't discern a BODY from a
HEADER in an xlog without decoding it. Solutions I can see:

 1. Assume nobody has ever used before_replace and hence there shouldn't
    be NOP requests in old xlogs. Then this patch would be OK.
 2. Take a peek inside the next map and try to determine whether it's a
    body or a header.
 3. Introduce a separate op-code for NOP without body.

> diff --git a/test/xlog/recover_nop.result b/test/xlog/recover_nop.result
> new file mode 100644

NOP recovery is already tested in box/before_replace.test.lua.
I think you'd better extend that rather than introducing a new test.