test: create reproducer for #5141

Created the stable reproducer for the issue #5141:

  box.snapshot()
  ---
 -- ok
 +- error: 'Invalid VYLOG file: Slice <NUM> deleted but not registered'
  ...

flaky occured in vinyl/ suite tests if running after the test:

  vinyl/gh-4957-too-many-upserts.test.lua

as new standalone test:

  vinyl/gh-5141-invalid-vylog-file.test.lua

based on test:

  vinyl/gh-4957-too-many-upserts.test.lua

Due to issue not reproduced on FreeBSD 12, then test was blocked with:

  vinyl/gh-5141-invalid-vylog-file.skipcond

Needed for #5141

test/vinyl/gh-5141-invalid-vylog-file.result

+-- test-run result file version 2
+test_run = require('test_run').new()
+ | ---
+ | ...
+test_run:cmd("push filter 'Invalid VYLOG file: Slice [0-9]+ deleted but not registered'" .. \
+             "to 'Invalid VYLOG file: Slice <NUM> deleted but not registered'")
+ | ---
+ | - true
+ | ...
+
+-- restart the current server to avoid of issues from previous runs
+test_run:cmd("restart server default with cleanup=True")
+ | 
+
+-- Let's test number of upserts in one transaction that exceeds
+-- the limit of operations allowed in one update.
+--
+ups_cnt = 10000
+ | ---
+ | ...
+
+s = box.schema.create_space('test', {engine = 'vinyl'})
+ | ---
+ | ...
+pk = s:create_index('pk')
+ | ---
+ | ...
+
+tuple = {}
+ | ---
+ | ...
+for i = 1, ups_cnt do tuple[i] = i end
+ | ---
+ | ...
+_ = s:insert(tuple)
+ | ---
+ | ...
+box.snapshot()
+ | ---
+ | - ok
+ | ...
+
+box.begin()
+ | ---
+ | ...
+for k = 1, ups_cnt do s:upsert({1}, {{'+', k, 1}}) end
+ | ---
+ | ...
+box.commit()
+ | ---
+ | ...
+-- Upserts are not able to squash, so scheduler will get stuck.
+-- So let's not waste much time here, just check that no crash
+-- takes place.
+--
+box.snapshot()
+ | ---
+ | - ok
+ | ...
+require('fiber').sleep(0.01)
+ | ---
+ | ...
+
+s:drop()
+ | ---
+ | ...
+
+--
+-- WARNING: do not split from previous subtest.
+-- gh-5141: vinyl: after test with number of upserts in one transaction
+-- that exceeded the limit of operations allowed in one update, then
+-- box.snapshot() call may fail with error:
+--   "Invalid VYLOG file: Slice <NUM> deleted but not registered".
+-- To avoid of the issue tarantool server restart is needed.
+--
+
+-- let's check the issue reproduced
+s0 = box.schema.space.create('tweedledum', {engine = 'vinyl'})
+ | ---
+ | ...
+i0 = s0:create_index('primary', { type = 'tree', parts = {1, 'unsigned'}})
+ | ---
+ | ...
+cnt = 1
+ | ---
+ | ...
+s0:replace{cnt, 'tuple'}
+ | ---
+ | - [1, 'tuple']
+ | ...
+test_run:wait_cond(function()							\
+    cnt = cnt + 1								\
+    s0:replace{cnt, 'tuple ' .. cnt}						\
+    local ok, err = pcall(box.snapshot)                  			\
+    if ok == false then                                  			\
+        require('log').info(                            			\
+            "box.snapshot() returned on loop " .. cnt .. " 'err': " .. err) 	\
+    end                                                  			\
+    return err:match "Invalid VYLOG file: Slice %d+ deleted but not registered"	\
+end, 10)
+ | ---
+ | - 'Invalid VYLOG file: Slice <NUM> deleted but not registered'
+ | ...
+s0:drop()
+ | ---
+ | ...
+
+-- let's check the issue is stable
+s1 = box.schema.space.create('tweedledum', {engine = 'vinyl'})
+ | ---
+ | ...
+i1 = s1:create_index('primary', { type = 'tree', parts = {1, 'unsigned'}})
+ | ---
+ | ...
+box.snapshot()
+ | ---
+ | - error: 'Invalid VYLOG file: Slice <NUM> deleted but not registered'
+ | ...
+s1:drop()
+ | ---
+ | ...
+
+-- restart the current server to resolve the issue
+test_run:cmd("restart server default with cleanup=True")
+ | 
+
+-- let's check the issue resolved
+s2 = box.schema.space.create('tweedledum', {engine = 'vinyl'})
+ | ---
+ | ...
+i2 = s2:create_index('primary', { type = 'tree', parts = {1, 'unsigned'}})
+ | ---
+ | ...
+box.snapshot()
+ | ---
+ | - ok
+ | ...
+s2:drop()
+ | ---
+ | ...

test/vinyl/gh-5141-invalid-vylog-file.skipcond

+# vim: set ft=python :
+import platform
+
+# Disabled on FreeBSD due to issue #5141 not reproduced.
+if platform.system() == 'FreeBSD':
+    self.skip = 1

test/vinyl/gh-5141-invalid-vylog-file.test.lua

+test_run = require('test_run').new()
+test_run:cmd("push filter 'Invalid VYLOG file: Slice [0-9]+ deleted but not registered'" .. \
+             "to 'Invalid VYLOG file: Slice <NUM> deleted but not registered'")
+
+-- restart the current server to avoid of issues from previous runs
+test_run:cmd("restart server default with cleanup=True")
+
+-- Let's test number of upserts in one transaction that exceeds
+-- the limit of operations allowed in one update.
+--
+ups_cnt = 10000
+
+s = box.schema.create_space('test', {engine = 'vinyl'})
+pk = s:create_index('pk')
+
+tuple = {}
+for i = 1, ups_cnt do tuple[i] = i end
+_ = s:insert(tuple)
+box.snapshot()
+
+box.begin()
+for k = 1, ups_cnt do s:upsert({1}, {{'+', k, 1}}) end
+box.commit()
+-- Upserts are not able to squash, so scheduler will get stuck.
+-- So let's not waste much time here, just check that no crash
+-- takes place.
+--
+box.snapshot()
+require('fiber').sleep(0.01)
+
+s:drop()
+
+--
+-- WARNING: do not split from previous subtest.
+-- gh-5141: vinyl: after test with number of upserts in one transaction
+-- that exceeded the limit of operations allowed in one update, then
+-- box.snapshot() call may fail with error:
+--   "Invalid VYLOG file: Slice <NUM> deleted but not registered".
+-- To avoid of the issue tarantool server restart is needed.
+--
+
+-- let's check the issue reproduced
+s0 = box.schema.space.create('tweedledum', {engine = 'vinyl'})
+i0 = s0:create_index('primary', { type = 'tree', parts = {1, 'unsigned'}})
+cnt = 1
+s0:replace{cnt, 'tuple'}
+test_run:wait_cond(function()							\
+    cnt = cnt + 1								\
+    s0:replace{cnt, 'tuple ' .. cnt}						\
+    local ok, err = pcall(box.snapshot)                  			\
+    if ok == false then                                  			\
+        require('log').info(                            			\
+            "box.snapshot() returned on loop " .. cnt .. " 'err': " .. err) 	\
+    end                                                  			\
+    return err:match "Invalid VYLOG file: Slice %d+ deleted but not registered"	\
+end, 10)
+s0:drop()
+
+-- let's check the issue is stable
+s1 = box.schema.space.create('tweedledum', {engine = 'vinyl'})
+i1 = s1:create_index('primary', { type = 'tree', parts = {1, 'unsigned'}})
+box.snapshot()
+s1:drop()
+
+-- restart the current server to resolve the issue
+test_run:cmd("restart server default with cleanup=True")
+
+-- let's check the issue resolved
+s2 = box.schema.space.create('tweedledum', {engine = 'vinyl'})
+i2 = s2:create_index('primary', { type = 'tree', parts = {1, 'unsigned'}})
+box.snapshot()
+s2:drop()

test/vinyl/suite.ini

@@ -55,6 +55,10 @@ fragile = {
             "issues": [ "gh-5141" ],
             "checksums": [ "f1286e9e4710062ddfbffb61b2fe2743", "96b22440ab8a881d6b8d14c5ee1672fb" ]
         },
+        "gh-5141-invalid-vylog-file.test.lua": {
+            "issues": [ "gh-5141" ],
+            "checksums": [ "1f4d4261fc63291c4020372986c62e2e" ]
+        },
         "iterator.test.lua": {
             "issues": [ "gh-5336" ],
             "checksums": [ "f56d6d279692e46d84a06f470af0090d", "a8a2824fb09380330a70a589d4fc545e", "e03548bcb918e824c349dc4c52ae3715", "adbd4ad9878302d570e40aef9a6b92cc", "39ee43ee7b2004166ca54402dfe02238" ]