[Tarantool-patches] [PATCH v1] test: move error messages into logs
Alexander V. Tikhonov
avtikhon at tarantool.org
Tue Dec 8 18:49:25 MSK 2020
Cc: tarantool-patches at dev.tarantool.org
Found that some tests on fail use box.info* calls to print information,
like:
[024] --- replication/wal_rw_stress.result Mon Nov 30 10:02:43 2020
[024] +++ var/rejects/replication/wal_rw_stress.reject Sun Dec 6 16:06:46 2020
[024] @@ -77,7 +77,45 @@
[024] r.downstream.status ~= 'stopped') \
[024] end) or box.info
[024] ---
[024] -- true
[024] +- version: 2.7.0-109-g0b3ad5d8a0
[024] + id: 2
[024] + ro: false
[024] + uuid: e0b8863f-7b50-4eb5-947f-77f92c491827
It denies test-run from rerunng these tests using checksums, because
of changing output on each fail, like 'version:' either 'uuid:' fields
values above. To avoid of it, these calls outputs should be redirected
to log files using log.error(). Also the same fix made for tests with
fio.listdir() and fio.stat() on errors.
---
Github: https://github.com/tarantool/tarantool/tree/avtikhon/tests-output-to-logs
test/app/fio.result | 7 ++--
test/app/fio.test.lua | 5 +--
test/replication/gc.result | 35 ++++++++++---------
test/replication/gc.test.lua | 33 ++++++++---------
.../gh-5195-qsync-replica-write.result | 2 +-
.../gh-5195-qsync-replica-write.test.lua | 2 +-
test/replication/status.result | 2 +-
test/replication/status.test.lua | 2 +-
test/replication/suite.ini | 2 +-
test/replication/wal_rw_stress.result | 2 +-
test/replication/wal_rw_stress.test.lua | 2 +-
11 files changed, 51 insertions(+), 43 deletions(-)
diff --git a/test/app/fio.result b/test/app/fio.result
index 8a08755a2..20cfe345d 100644
--- a/test/app/fio.result
+++ b/test/app/fio.result
@@ -10,6 +10,9 @@ fiber = require 'fiber'
buffer = require 'buffer'
---
...
+log = require 'log'
+---
+...
test_run = require('test_run').new()
---
...
@@ -1553,11 +1556,11 @@ os.setenv('TMPDIR', tmpdir)
dir = fio.tempdir()
---
...
-dir:startswith(tmpdir) or {dir, tmpdir}
+dir:startswith(tmpdir) or log.error({dir, tmpdir})
---
- true
...
-fio.stat(dir) ~= nil or fio.stat(dir)
+fio.stat(dir) ~= nil or log.error(fio.stat(dir))
---
- true
...
diff --git a/test/app/fio.test.lua b/test/app/fio.test.lua
index 92ba3ff20..d1a20e8e5 100644
--- a/test/app/fio.test.lua
+++ b/test/app/fio.test.lua
@@ -2,6 +2,7 @@ fio = require 'fio'
ffi = require 'ffi'
fiber = require 'fiber'
buffer = require 'buffer'
+log = require 'log'
test_run = require('test_run').new()
-- umask
@@ -508,8 +509,8 @@ tmpdir = cwd..'/tmp-.dot.-'
fio.mkdir(tmpdir)
os.setenv('TMPDIR', tmpdir)
dir = fio.tempdir()
-dir:startswith(tmpdir) or {dir, tmpdir}
-fio.stat(dir) ~= nil or fio.stat(dir)
+dir:startswith(tmpdir) or log.error({dir, tmpdir})
+fio.stat(dir) ~= nil or log.error(fio.stat(dir))
tmpdir = cwd..'/tmp2'
os.setenv('TMPDIR', tmpdir)
diff --git a/test/replication/gc.result b/test/replication/gc.result
index 050a6100c..0c79484b7 100644
--- a/test/replication/gc.result
+++ b/test/replication/gc.result
@@ -13,6 +13,9 @@ fiber = require('fiber')
fio = require('fio')
---
...
+log = require('log')
+---
+...
test_run:cleanup_cluster()
---
...
@@ -131,11 +134,11 @@ test_run:cmd("switch default")
...
-- Check that garbage collection removed the snapshot once
-- the replica released the corresponding checkpoint.
-wait_gc(1) or box.info.gc()
+wait_gc(1) or log.error(box.info.gc())
---
- true
...
-wait_xlog(1) or fio.listdir('./master') -- Make sure the replica will not receive data until
+wait_xlog(1) or log.error(fio.listdir('./master')) -- Make sure the replica will not receive data until
---
- true
...
@@ -168,11 +171,11 @@ box.snapshot()
---
- ok
...
-wait_gc(1) or box.info.gc()
+wait_gc(1) or log.error(box.info.gc())
---
- true
...
-wait_xlog(2) or fio.listdir('./master')
+wait_xlog(2) or log.error(fio.listdir('./master'))
---
- true
...
@@ -201,11 +204,11 @@ test_run:cmd("switch default")
...
-- Now garbage collection should resume and delete files left
-- from the old checkpoint.
-wait_gc(1) or box.info.gc()
+wait_gc(1) or log.error(box.info.gc())
---
- true
...
-wait_xlog(0) or fio.listdir('./master')
+wait_xlog(0) or log.error(fio.listdir('./master'))
---
- true
...
@@ -244,11 +247,11 @@ fiber.sleep(0.1) -- wait for master to relay data
-- Garbage collection must not delete the old xlog file
-- because it is still needed by the replica, but remove
-- the old snapshot.
-wait_gc(1) or box.info.gc()
+wait_gc(1) or log.error(box.info.gc())
---
- true
...
-wait_xlog(2) or fio.listdir('./master')
+wait_xlog(2) or log.error(fio.listdir('./master'))
---
- true
...
@@ -282,11 +285,11 @@ test_run:cmd("switch default")
- true
...
-- Now it's safe to drop the old xlog.
-wait_gc(1) or box.info.gc()
+wait_gc(1) or log.error(box.info.gc())
---
- true
...
-wait_xlog(1) or fio.listdir('./master')
+wait_xlog(1) or log.error(fio.listdir('./master'))
---
- true
...
@@ -318,11 +321,11 @@ box.snapshot()
---
- ok
...
-wait_gc(1) or box.info.gc()
+wait_gc(1) or log.error(box.info.gc())
---
- true
...
-wait_xlog(2) or fio.listdir('./master')
+wait_xlog(2) or log.error(fio.listdir('./master'))
---
- true
...
@@ -331,11 +334,11 @@ wait_xlog(2) or fio.listdir('./master')
test_run:cleanup_cluster()
---
...
-wait_gc(1) or box.info.gc()
+wait_gc(1) or log.error(box.info.gc())
---
- true
...
-wait_xlog(1) or fio.listdir('./master')
+wait_xlog(1) or log.error(fio.listdir('./master'))
---
- true
...
@@ -423,7 +426,7 @@ box.snapshot()
---
- ok
...
-wait_xlog(3) or fio.listdir('./master')
+wait_xlog(3) or log.error(fio.listdir('./master'))
---
- true
...
@@ -436,7 +439,7 @@ box.snapshot()
---
- ok
...
-wait_xlog(0, 10) or fio.listdir('./master')
+wait_xlog(0, 10) or log.error(fio.listdir('./master'))
---
- true
...
diff --git a/test/replication/gc.test.lua b/test/replication/gc.test.lua
index 7cd18402c..a0588719a 100644
--- a/test/replication/gc.test.lua
+++ b/test/replication/gc.test.lua
@@ -3,6 +3,7 @@ engine = test_run:get_cfg('engine')
replica_set = require('fast_replica')
fiber = require('fiber')
fio = require('fio')
+log = require('log')
test_run:cleanup_cluster()
test_run:cmd("create server replica with rpl_master=default, script='replication/replica.lua'")
@@ -69,8 +70,8 @@ test_run:cmd("switch default")
-- Check that garbage collection removed the snapshot once
-- the replica released the corresponding checkpoint.
-wait_gc(1) or box.info.gc()
-wait_xlog(1) or fio.listdir('./master') -- Make sure the replica will not receive data until
+wait_gc(1) or log.error(box.info.gc())
+wait_xlog(1) or log.error(fio.listdir('./master')) -- Make sure the replica will not receive data until
-- we test garbage collection.
box.error.injection.set("ERRINJ_RELAY_SEND_DELAY", true)
@@ -86,8 +87,8 @@ box.snapshot()
-- Invoke garbage collection. Check that it doesn't remove
-- xlogs needed by the replica.
box.snapshot()
-wait_gc(1) or box.info.gc()
-wait_xlog(2) or fio.listdir('./master')
+wait_gc(1) or log.error(box.info.gc())
+wait_xlog(2) or log.error(fio.listdir('./master'))
-- Resume replication so that the replica catches
-- up quickly.
@@ -101,8 +102,8 @@ test_run:cmd("switch default")
-- Now garbage collection should resume and delete files left
-- from the old checkpoint.
-wait_gc(1) or box.info.gc()
-wait_xlog(0) or fio.listdir('./master')
+wait_gc(1) or log.error(box.info.gc())
+wait_xlog(0) or log.error(fio.listdir('./master'))
--
-- Check that the master doesn't delete xlog files sent to the
-- replica until it receives a confirmation that the data has
@@ -120,8 +121,8 @@ fiber.sleep(0.1) -- wait for master to relay data
-- Garbage collection must not delete the old xlog file
-- because it is still needed by the replica, but remove
-- the old snapshot.
-wait_gc(1) or box.info.gc()
-wait_xlog(2) or fio.listdir('./master')
+wait_gc(1) or log.error(box.info.gc())
+wait_xlog(2) or log.error(fio.listdir('./master'))
-- Imitate the replica crash and, then, wake up.
-- Just 'stop server replica' (SIGTERM) is not sufficient to stop
-- a tarantool instance when ERRINJ_WAL_DELAY is set, because
@@ -134,8 +135,8 @@ test_run:wait_cond(function() return box.space.test:count() == 310 end, 10)
box.space.test:count()
test_run:cmd("switch default")
-- Now it's safe to drop the old xlog.
-wait_gc(1) or box.info.gc()
-wait_xlog(1) or fio.listdir('./master')
+wait_gc(1) or log.error(box.info.gc())
+wait_xlog(1) or log.error(fio.listdir('./master'))
-- Stop the replica.
test_run:cmd("stop server replica")
test_run:cmd("cleanup server replica")
@@ -149,14 +150,14 @@ _ = s:auto_increment{}
box.snapshot()
_ = s:auto_increment{}
box.snapshot()
-wait_gc(1) or box.info.gc()
-wait_xlog(2) or fio.listdir('./master')
+wait_gc(1) or log.error(box.info.gc())
+wait_xlog(2) or log.error(fio.listdir('./master'))
-- The xlog should only be deleted after the replica
-- is unregistered.
test_run:cleanup_cluster()
-wait_gc(1) or box.info.gc()
-wait_xlog(1) or fio.listdir('./master')
+wait_gc(1) or log.error(box.info.gc())
+wait_xlog(1) or log.error(fio.listdir('./master'))
--
-- Test that concurrent invocation of the garbage collector works fine.
--
@@ -195,13 +196,13 @@ _ = s:auto_increment{}
box.snapshot()
_ = s:auto_increment{}
box.snapshot()
-wait_xlog(3) or fio.listdir('./master')
+wait_xlog(3) or log.error(fio.listdir('./master'))
-- Delete the replica from the cluster table and check that
-- all xlog files are removed.
test_run:cleanup_cluster()
box.snapshot()
-wait_xlog(0, 10) or fio.listdir('./master')
+wait_xlog(0, 10) or log.error(fio.listdir('./master'))
-- Restore the config.
box.cfg{replication = {}}
diff --git a/test/replication/gh-5195-qsync-replica-write.result b/test/replication/gh-5195-qsync-replica-write.result
index 906f4910d..85e00e6ed 100644
--- a/test/replication/gh-5195-qsync-replica-write.result
+++ b/test/replication/gh-5195-qsync-replica-write.result
@@ -99,7 +99,7 @@ test_run:wait_cond(function()
local vclock = box.info.replication[replica_id].downstream.vclock \
return (vclock and vclock[replica_id] and \
vclock[replica_id] >= replica_lsn) \
- end) or box.info
+ end) or require('log').error(box.info)
| ---
| - true
| ...
diff --git a/test/replication/gh-5195-qsync-replica-write.test.lua b/test/replication/gh-5195-qsync-replica-write.test.lua
index d7d09fa35..64c48be99 100644
--- a/test/replication/gh-5195-qsync-replica-write.test.lua
+++ b/test/replication/gh-5195-qsync-replica-write.test.lua
@@ -44,7 +44,7 @@ test_run:wait_cond(function()
local vclock = box.info.replication[replica_id].downstream.vclock \
return (vclock and vclock[replica_id] and \
vclock[replica_id] >= replica_lsn) \
- end) or box.info
+ end) or require('log').error(box.info)
box.cfg{replication_synchro_quorum = 2}
test_run:wait_cond(function() return f:status() == 'dead' end)
diff --git a/test/replication/status.result b/test/replication/status.result
index 4f2cf56ea..a8c515dbb 100644
--- a/test/replication/status.result
+++ b/test/replication/status.result
@@ -182,7 +182,7 @@ test_run:wait_cond(function() \
return (r ~= nil and box.info.vclock ~= nil and \
r[master_id] == box.info.vclock[master_id] and \
r[replica_id] == box.info.vclock[replica_id]) \
- end) or box.info
+ end) or require('log').error(box.info)
---
- true
...
diff --git a/test/replication/status.test.lua b/test/replication/status.test.lua
index 0facd7c0a..431463d8a 100644
--- a/test/replication/status.test.lua
+++ b/test/replication/status.test.lua
@@ -71,7 +71,7 @@ test_run:wait_cond(function() \
return (r ~= nil and box.info.vclock ~= nil and \
r[master_id] == box.info.vclock[master_id] and \
r[replica_id] == box.info.vclock[replica_id]) \
- end) or box.info
+ end) or require('log').error(box.info)
--
-- Replica
diff --git a/test/replication/suite.ini b/test/replication/suite.ini
index 6c9eccb7a..156ed5c56 100644
--- a/test/replication/suite.ini
+++ b/test/replication/suite.ini
@@ -140,7 +140,7 @@ fragile = {
},
"gc.test.lua": {
"issues": [ "gh-5474" ],
- "checksums": [ "eba8a4dd4110f26e5189c24f117a1679" ]
+ "checksums": [ "b71b49a2066375eab34891f82c1ea013", "ba5a30981d31d060be39a3880422f915", "641731a65ba65c6bbd32437a45ca55d3" ]
},
"bootstrap_leader.test.lua": {
"issues": [ "gh-5478" ],
diff --git a/test/replication/wal_rw_stress.result b/test/replication/wal_rw_stress.result
index 41f307fc2..7abb7279b 100644
--- a/test/replication/wal_rw_stress.result
+++ b/test/replication/wal_rw_stress.result
@@ -75,7 +75,7 @@ test_run:wait_cond(function() \
local r = box.info.replication[1] \
return (r ~= nil and r.downstream ~= nil and \
r.downstream.status ~= 'stopped') \
-end) or box.info
+end) or require('log').error(box.info)
---
- true
...
diff --git a/test/replication/wal_rw_stress.test.lua b/test/replication/wal_rw_stress.test.lua
index 96df2d6bf..9d0748cfa 100644
--- a/test/replication/wal_rw_stress.test.lua
+++ b/test/replication/wal_rw_stress.test.lua
@@ -42,7 +42,7 @@ test_run:wait_cond(function() \
local r = box.info.replication[1] \
return (r ~= nil and r.downstream ~= nil and \
r.downstream.status ~= 'stopped') \
-end) or box.info
+end) or require('log').error(box.info)
test_run:cmd("switch default")
-- Cleanup.
--
2.25.1
More information about the Tarantool-patches
mailing list