Skip to content

Unnecessary timeout in diff tests #413

Open
@ImeevMA

Description

@ImeevMA

If Tarantool is aborted, diff tests (at least from sql/) only produce diff after a timeout.

For example, let's say that we applied this diff:

diff --git a/src/box/sql/parse.y b/src/box/sql/parse.y
index fb9332c80..f65f91d57 100644
--- a/src/box/sql/parse.y
+++ b/src/box/sql/parse.y
@@ -399,6 +399,7 @@ ifexists(A) ::= .            {A = 0;}
 //
 cmd ::= createkw(X) VIEW ifnotexists(E) nm(Y) eidlist_opt(C)
           AS select(S). {
+  assert(0);
   if (!pParse->parse_only) {
     create_view_def_init(&pParse->create_view_def, &Y, &X, C, S, E);
     pParse->initiateTTrans = true;

And ran the following command in tarantool/test/:

./test-run.py sql/gh-4111-format-in-sysview. -j1

Result on the commit just before test: bump test-run to new version:

Detected build mode: Debug

======================================================================================
WORKR TEST                                            PARAMS          RESULT
---------------------------------------------------------------------------------
2023-11-09 10:20:28.973 [207074] main/103/app I> update replication_synchro_quorum = 1
2023-11-09 10:20:28.973 [207074] main/103/app I> replicaset uuid 74bac459-c3b8-454f-b6ae-ff9bf46128b7
2023-11-09 10:20:28.976 [207074] snapshot/101/main I> saving snapshot `/tmp/t/001_sql/app/00000000000000000000.snap.inprogress'
2023-11-09 10:20:28.981 [207074] snapshot/101/main I> done
2023-11-09 10:20:28.982 [207074] main/103/app I> ready to accept requests
2023-11-09 10:20:28.982 [207074] main/105/gc I> wal/engine cleanup is resumed
2023-11-09 10:20:28.982 [207074] main/103/app/box.load_cfg I> set 'replication_sync_timeout' configuration option to 100
2023-11-09 10:20:28.982 [207074] main/103/app/box.load_cfg I> set 'log' configuration option to "/tmp/t/001_sql/app.log"
2023-11-09 10:20:28.982 [207074] main/103/app/box.load_cfg I> set 'vinyl_max_tuple_size' configuration option to 5242880
2023-11-09 10:20:28.982 [207074] main/103/app/box.load_cfg I> set 'memtx_max_tuple_size' configuration option to 5242880
2023-11-09 10:20:28.982 [207074] main/103/app/box.load_cfg I> set 'listen' configuration option to "/tmp/t/001_sql/app.i"
2023-11-09 10:20:28.982 [207074] main/106/checkpoint_daemon I> scheduled next checkpoint for Thu Nov  9 11:28:13 2023
2023-11-09 10:20:28.983 [207074] main/114/console/unix/:/tmp/t/001_sql/app.c/socket I> started
2023-11-09 10:20:28.983 [207074] main I> entering the event loop
tarantool: ./src/box/sql/parse.y:402: yy_reduce: Assertion `0' failed.
[001] sql/gh-4111-format-in-sysview.test.lua          memtx           
[001] 
[001] [Instance "app" killed by signal: 6 (SIGABRT)]
[001] Found assertion fail in the results file [/tmp/t/001_sql/app.log]:
[001] [ fail ]
[Main process] Got failed test; gently terminate all workers...
[001] Worker "001_sql" got failed test; stopping the server...
---------------------------------------------------------------------------------

The result on commit test: bump test-run to new version:

Detected build mode: Debug

======================================================================================
WORKR TEST                                            PARAMS          RESULT
---------------------------------------------------------------------------------
No output during 10 seconds. Will abort after 120 seconds without output. List of workers not reporting the status:
- 001_sql [sql/gh-4111-format-in-sysview.test.lua, memtx] at /tmp/t/001_sql/gh-4111-format-in-sysview.result:0
No output during 20 seconds. Will abort after 120 seconds without output. List of workers not reporting the status:
- 001_sql [sql/gh-4111-format-in-sysview.test.lua, memtx] at /tmp/t/001_sql/gh-4111-format-in-sysview.result:0
No output during 30 seconds. Will abort after 120 seconds without output. List of workers not reporting the status:
- 001_sql [sql/gh-4111-format-in-sysview.test.lua, memtx] at /tmp/t/001_sql/gh-4111-format-in-sysview.result:0
No output during 40 seconds. Will abort after 120 seconds without output. List of workers not reporting the status:
- 001_sql [sql/gh-4111-format-in-sysview.test.lua, memtx] at /tmp/t/001_sql/gh-4111-format-in-sysview.result:0
No output during 51 seconds. Will abort after 120 seconds without output. List of workers not reporting the status:
- 001_sql [sql/gh-4111-format-in-sysview.test.lua, memtx] at /tmp/t/001_sql/gh-4111-format-in-sysview.result:0
No output during 61 seconds. Will abort after 120 seconds without output. List of workers not reporting the status:
- 001_sql [sql/gh-4111-format-in-sysview.test.lua, memtx] at /tmp/t/001_sql/gh-4111-format-in-sysview.result:0
No output during 71 seconds. Will abort after 120 seconds without output. List of workers not reporting the status:
- 001_sql [sql/gh-4111-format-in-sysview.test.lua, memtx] at /tmp/t/001_sql/gh-4111-format-in-sysview.result:0
No output during 81 seconds. Will abort after 120 seconds without output. List of workers not reporting the status:
- 001_sql [sql/gh-4111-format-in-sysview.test.lua, memtx] at /tmp/t/001_sql/gh-4111-format-in-sysview.result:0
No output during 91 seconds. Will abort after 120 seconds without output. List of workers not reporting the status:
- 001_sql [sql/gh-4111-format-in-sysview.test.lua, memtx] at /tmp/t/001_sql/gh-4111-format-in-sysview.result:0
No output during 101 seconds. Will abort after 120 seconds without output. List of workers not reporting the status:
- 001_sql [sql/gh-4111-format-in-sysview.test.lua, memtx] at /tmp/t/001_sql/gh-4111-format-in-sysview.result:0
[001] sql/gh-4111-format-in-sysview.test.lua          memtx           Test timeout of 110 secs reached [ fail ]
[001] 
[001] Test failed! Result content mismatch:
[001] --- sql/gh-4111-format-in-sysview.result Thu Nov  9 09:58:19 2023
[001] +++ /tmp/t/rejects/sql/gh-4111-format-in-sysview.reject Thu Nov  9 10:18:39 2023
[001] @@ -11,18 +11,6 @@
[001]  - true
[001]  ...
[001]  box.execute([[CREATE VIEW t AS SELECT "name" FROM "_vspace" y]])
[001] ----
[001] -- row_count: 1
[001] -...
[001]  box.execute([[SELECT * from t WHERE "name" = 'T']])
[001] ----
[001] -- metadata:
[001] -  - name: name
[001] -    type: string
[001] -  rows:
[001] -  - ['T']
[001] -...
[001] +[Lost current connection]
[001]  box.execute([[DROP VIEW t]])
[001] ----
[001] -- row_count: 1
[001] -...
[001] 
[001] [test-run server "app"] Last 15 lines of the log file /tmp/t/001_sql/app.log:
[001] 2023-11-09 10:16:49.213 [194592] main/103/app I> update replication_synchro_quorum = 1
[001] 2023-11-09 10:16:49.214 [194592] main/103/app I> replicaset uuid 6575c51c-7049-4c3b-9aa7-acf72a872bff
[001] 2023-11-09 10:16:49.217 [194592] snapshot/101/main I> saving snapshot `/tmp/t/001_sql/app/00000000000000000000.snap.inprogress'
[001] 2023-11-09 10:16:49.221 [194592] snapshot/101/main I> done
[001] 2023-11-09 10:16:49.222 [194592] main/103/app I> ready to accept requests
[001] 2023-11-09 10:16:49.222 [194592] main/105/gc I> wal/engine cleanup is resumed
[001] 2023-11-09 10:16:49.222 [194592] main/103/app/box.load_cfg I> set 'replication_sync_timeout' configuration option to 100
[001] 2023-11-09 10:16:49.222 [194592] main/103/app/box.load_cfg I> set 'log' configuration option to "/tmp/t/001_sql/app.log"
[001] 2023-11-09 10:16:49.222 [194592] main/103/app/box.load_cfg I> set 'vinyl_max_tuple_size' configuration option to 5242880
[001] 2023-11-09 10:16:49.222 [194592] main/103/app/box.load_cfg I> set 'memtx_max_tuple_size' configuration option to 5242880
[001] 2023-11-09 10:16:49.222 [194592] main/103/app/box.load_cfg I> set 'listen' configuration option to "/tmp/t/001_sql/app.i"
[001] 2023-11-09 10:16:49.222 [194592] main/106/checkpoint_daemon I> scheduled next checkpoint for Thu Nov  9 11:20:21 2023
[001] 2023-11-09 10:16:49.223 [194592] main/114/console/unix/:/tmp/t/001_sql/app.c/socket I> started
[001] 2023-11-09 10:16:49.223 [194592] main I> entering the event loop
[001] tarantool: ./src/box/sql/parse.y:402: yy_reduce: Assertion `0' failed.
[Main process] Got failed test; gently terminate all workers...
[001] Worker "001_sql" got failed test; stopping the server...
---------------------------------------------------------------------------------

Note that the latter result is better because it shows the difference, but only after a timeout. It would be great if the timeout could be removed in such cases.

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions