Lua execution is blocked after running random operations on vinyl space #10267
Description
Bug description
- OS: Linux
- OS Version: Ubuntu 22.04
- Architecture: amd64
commit 62c4936
Tarantool 3.2.0-entrypoint-155-g065fb27dcc
Target: Linux-x86_64-RelWithDebInfo
Build options: cmake . -DCMAKE_INSTALL_PREFIX=/usr/local -DENABLE_BACKTRACE=TRUE
Compiler: GNU-11.4.0
C_FLAGS: -fexceptions -funwind-tables -fasynchronous-unwind-tables -fno-common -msse2 -Wformat -Wformat-security -Werror=format-security -fstack-protector-strong -fPIC -fmacro-prefix-map=/home/sergeyb/sources/MRG/tarantool=. -std=c11 -Wall -Wextra -Wno-gnu-alignof-expression -fno-gnu89-inline -Wno-cast-function-type -O2 -g -DNDEBUG -ggdb -O2
CXX_FLAGS: -fexceptions -funwind-tables -fasynchronous-unwind-tables -fno-common -msse2 -Wformat -Wformat-security -Werror=format-security -fstack-protector-strong -fPIC -fmacro-prefix-map=/home/sergeyb/sources/MRG/tarantool=. -std=c++11 -Wall -Wextra -Wno-invalid-offsetof -Wno-gnu-alignof-expression -Wno-cast-function-type -O2 -g -DNDEBUG -ggdb -O2
Steps to reproduce
Download script test_engine.lua from #10264.
How to run:
Just type ./build/src/tarantool test/fuzz/lua/test_engine.lua --engine vinyl --workers 10 --test_duration 10.
Actual behavior
At the end of the test, all fibers must be finished and execution of the test should be finished too. However, test is never stops:
coredump + tarantool binary: https://drive.google.com/file/d/1fRI6ijvFAZSfpLm3i7mx56qV7B3-kIZx/view?usp=sharing
log:
output
2024-07-17 19:42:46.926 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> INDEX_CREATE_OP []
2024-07-17 19:42:46.926 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> ERROR: opname "INDEX_CREATE_OP", err "Can't modify space 'test_1': t
he space is already being modified", args []
2024-07-17 19:42:46.926 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> UPSERT_OP [[772077714541.48,374740654849,"4778ca14-bf07-4711-ba4e-e7
62d31b4449",566991563301,"wrjitglocu",508178400593,true,"355864223923","2024-07-17T16:42:46Z",[1,2,3,4,5,6,7,8],{"4":4,"8":8,"1":1,"5":5,"2":2,"6":
6,"7":7,"3":3}],[["-",4,557268425295],["+",6,485099108361]]]
2024-07-17 19:42:46.926 [1042003] main/108/vinyl.scheduler I> 512/0: started compacting range (-inf..inf), runs 2/2
2024-07-17 19:42:46.927 [1042003] vinyl.dump.0/839/task I> writing `./512/1/00000000000000002364.index'
2024-07-17 19:42:46.927 [1042003] vinyl.compaction.1/359/task I> writing `./512/0/00000000000000002366.run'
2024-07-17 19:42:46.927 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> UPDATE_OP [[974377963014.65],[["-",1,788119778269.1],["-",4,64415980
5099],["=",3,"f7f2aedf-9458-4a4e-bd64-c1163c6f9736"],["-",2,521858876897],["=",5,"kfvhtgbpzq"]]]
2024-07-17 19:42:46.927 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> PUT_OP [[967490887084.4,399471645725,"a1614c29-1ea5-4a3a-86b4-060a4f
3f4064",80607767016,"gnongjqpep",698044075619,true,"757549837945","2024-07-17T16:42:46Z",[1,2,3,4,5,6,7,8],{"1":1,"2":2}]]
2024-07-17 19:42:46.928 [1042003] main/108/vinyl.scheduler I> 512/1: dump completed
2024-07-17 19:42:46.928 [1042003] main/108/vinyl.scheduler I> 512/0: dump started
2024-07-17 19:42:46.928 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> BSIZE_OP []
2024-07-17 19:42:46.928 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> TX_ROLLBACK []
2024-07-17 19:42:46.928 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> DELETE_OP [[79366894360.2]]
2024-07-17 19:42:46.928 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> INDEX_DELETE_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"
asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloo
m_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},[771346396181.12]]
2024-07-17 19:42:46.928 [1042003] vinyl.dump.0/840/task I> writing `./512/0/00000000000000002368.run'
2024-07-17 19:42:46.929 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> LEN_OP []
2024-07-17 19:42:46.929 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> INDEX_ALTER_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"a
sc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom
_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},{"page_size":2048,"parts":[["field_1"]],"if_not_exists":false,"blo
om_fpr":0.17,"unique":true,"type":"TREE","range_size":1073741824}]
2024-07-17 19:42:46.929 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> ERROR: opname "INDEX_ALTER_OP", err "Can't modify space 'test_1': th
e space is already being modified", args [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc","type":"double","exclude_null":false,"is_nullable
":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_fpr":0.32,"range_size":1073741824},"space_id":512,"t
ype":"TREE","name":"idx_1"},{"page_size":2048,"parts":[["field_1"]],"type":"TREE","bloom_fpr":0.17,"unique":true,"name":"idx_1","range_size":107374
1824}]
2024-07-17 19:42:46.929 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> INDEX_DROP_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"as
c","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_
fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.929 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> SNAPSHOT_OP []
2024-07-17 19:42:46.929 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> TX_COMMIT []
2024-07-17 19:42:46.929 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> FORMAT_OP [[{"name":"field_1","type":"double"},{"name":"field_2","ty
pe":"unsigned"},{"name":"field_3","type":"uuid"},{"name":"field_4","type":"integer"},{"name":"field_5","type":"string"},{"name":"field_6","type":"n
umber"},{"name":"field_7","type":"boolean"},{"name":"field_8","type":"decimal"},{"name":"field_9","type":"datetime"},{"name":"field_10","type":"arr
ay"},{"name":"field_11","type":"map"}]]
2024-07-17 19:42:46.929 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> ERROR: opname "FORMAT_OP", err "Can't modify space 'test_1': the spa
ce is already being modified", args [[{"name":"field_1","type":"double"},{"name":"field_2","type":"unsigned"},{"name":"field_3","type":"uuid"},{"na
me":"field_4","type":"integer"},{"name":"field_5","type":"string"},{"name":"field_6","type":"number"},{"name":"field_7","type":"boolean"},{"name":"
field_8","type":"decimal"},{"name":"field_9","type":"datetime"},{"name":"field_10","type":"array"},{"name":"field_11","type":"map"}]]
2024-07-17 19:42:46.929 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> INDEX_GET_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc
","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_f
pr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},[156263376500.53]]
2024-07-17 19:42:46.929 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> INDEX_MIN_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc
","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_f
pr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.929 [1042003] main/108/vinyl.scheduler I> 512/1: started compacting range (-inf..inf), runs 5/11
2024-07-17 19:42:46.929 [1042003] vinyl.dump.0/840/task I> writing `./512/0/00000000000000002368.index'
2024-07-17 19:42:46.929 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> INDEX_MAX_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc
","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_f
pr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.929 [1042003] vinyl.compaction.0/287/task I> writing `./512/1/00000000000000002369.run'
2024-07-17 19:42:46.930 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> INDEX_SELECT_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"
asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloo
m_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},[169797531875.54]]
2024-07-17 19:42:46.930 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> REPLACE_OP [[606564803997.38,975818031669,"2258973e-2fb8-4e65-bda8-a
2b8384f5d9d",501777464629,"ktisqiscqa",946999252412,true,"241807451019","2024-07-17T16:42:46Z",[1,2,3,4,5,6,7,8],{"4":4,"8":8,"1":1,"5":5,"2":2,"6"
:6,"7":7,"3":3}]]
2024-07-17 19:42:46.930 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> TX_BEGIN []
2024-07-17 19:42:46.930 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> GET_OP [[892144887544.32]]
2024-07-17 19:42:46.930 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> INDEX_UPDATE_OP [[287012344636.61],{"unique":true,"parts":[{"fieldno
":1,"sort_order":"asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_s
ize_ratio":4,"bloom_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},[["!",5,"moppxettex"],["-",1,38113495332.667],[
"=",7,true],["=",3,"175555f0-7aa1-46f4-be8d-92041ee2a188"],["&",2,628573078318],["-",8,"753080971475"],["-",4,481568149544],["=",10,[1,2,3,4,5,6,7,
8]],["-",6,466610806221]]]
2024-07-17 19:42:46.930 [1042003] vinyl.compaction.0/287/task I> writing `./512/1/00000000000000002369.index'
2024-07-17 19:42:46.930 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> INDEX_RENAME_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"
asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloo
m_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},"foizbyetdx"]
2024-07-17 19:42:46.930 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> ERROR: opname "INDEX_RENAME_OP", err "Can't modify space 'test_1': t
he space is already being modified", args [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc","type":"double","exclude_null":false,"is_nullabl
e":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_fpr":0.32,"range_size":1073741824},"space_id":512,"
type":"TREE","name":"idx_1"},"foizbyetdx"]
2024-07-17 19:42:46.930 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> INDEX_STAT_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"as
c","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_
fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.931 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> SELECT_OP ["TREE",[704833635664.84]]
2024-07-17 19:42:46.931 [1042003] main/108/vinyl.scheduler I> 512/0: dump completed
2024-07-17 19:42:46.931 [1042003] main/108/vinyl.scheduler I> dumped 0 bytes in 0.0 s, rate 0.0 MB/s
2024-07-17 19:42:46.931 [1042003] main/115/WRK #2 I> vinyl checkpoint completed
2024-07-17 19:42:46.931 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> INDEX_COUNT_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"a
sc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom
_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.934 [1042003] main/108/vinyl.scheduler I> 512/1: completed compacting range (-inf..inf)
2024-07-17 19:42:46.935 [1042003] coio I> removed ./00000000000000004501.snap
2024-07-17 19:42:46.935 [1042003] coio I> removed ./00000000000000004497.vylog
2024-07-17 19:42:46.935 [1042003] coio I> removed ./512/0/00000000000000002353.index
2024-07-17 19:42:46.935 [1042003] coio I> removed ./512/0/00000000000000002353.run
2024-07-17 19:42:46.936 [1042003] coio I> removed ./512/0/00000000000000002356.index
2024-07-17 19:42:46.936 [1042003] coio I> removed ./512/0/00000000000000002356.run
2024-07-17 19:42:46.936 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> INDEX_RANDOM_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"
asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloo
m_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.936 [1042003] vinyl.compaction.1/359/task I> writing `./512/0/00000000000000002366.index'
2024-07-17 19:42:46.936 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> INSERT_OP [[453852667841.9,137488261404,"4b809e4c-e4d9-4d72-9680-365
65495b175",864031538378,"ffehqenfrg",872625778976,false,"515615613456","2024-07-17T16:42:46Z",[1,2,3,4,5,6,7,8],{"4":4,"1":1,"5":5,"2":2,"3":3}]]
2024-07-17 19:42:46.936 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> ERROR: opname "INDEX_COUNT_OP", err "Transaction has been aborted by
conflict", args [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"option
s":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_
1"}]
2024-07-17 19:42:46.936 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> INDEX_COMPACT_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":
"asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"blo
om_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.936 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> INDEX_CREATE_OP []
2024-07-17 19:42:46.937 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> ERROR: opname "INDEX_CREATE_OP", err "A multi-statement transaction
can not use multiple storage engines", args []
2024-07-17 19:42:46.937 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> UPSERT_OP [[748692097044.43,210912337917,"9a8f1366-9c59-41b5-b856-d3
42b9faaa13",750928309403,"ehtfdlqujg",205064747202,true,"118136088763","2024-07-17T16:42:46Z",[1,2,3,4,5,6,7,8],{"4":4,"8":8,"1":1,"5":5,"2":2,"6":
6,"7":7,"3":3}],[["-",1,334274276424.96],["=",5,"lsurznvkpe"],["|",2,797509221545],["=",3,"f848133e-7934-4a73-a488-8620b7beec3b"]]]
2024-07-17 19:42:46.937 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> ERROR: opname "UPSERT_OP", err "Transaction has been aborted by conf
lict", args [[748692097044.43,210912337917,"9a8f1366-9c59-41b5-b856-d342b9faaa13",750928309403,"ehtfdlqujg",205064747202,true,"118136088763","2024-
07-17T16:42:46Z",[1,2,3,4,5,6,7,8],{"4":4,"8":8,"1":1,"5":5,"2":2,"6":6,"7":7,"3":3}],[["-",1,334274276424.96],["=",5,"lsurznvkpe"],["|",2,79750922
1545],["=",3,"f848133e-7934-4a73-a488-8620b7beec3b"]]]
2024-07-17 19:42:46.937 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> UPDATE_OP [[483946150304.64],[["-",1,186179261663.45]]]
2024-07-17 19:42:46.937 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> ERROR: opname "UPDATE_OP", err "Transaction has been aborted by conf
lict", args [[483946150304.64],[["-",1,186179261663.45]]]
2024-07-17 19:42:46.937 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> PUT_OP [[767218130041.86,264614892265,"eaf135ad-746d-44a0-bfc4-61d0f
b68e56f",845446708700,"eeshhrhwhw",570216892062,true,"249413629170","2024-07-17T16:42:46Z",[1,2,3,4,5,6,7,8],{"4":4,"1":1,"5":5,"2":2,"6":6,"3":3}]
]
2024-07-17 19:42:46.937 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> ERROR: opname "PUT_OP", err "Transaction has been aborted by conflic
t", args [[767218130041.86,264614892265,"eaf135ad-746d-44a0-bfc4-61d0fb68e56f",845446708700,"eeshhrhwhw",570216892062,true,"249413629170","2024-07-
17T16:42:46Z",[1,2,3,4,5,6,7,8],{"4":4,"1":1,"5":5,"2":2,"6":6,"3":3}]]
2024-07-17 19:42:46.937 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> BSIZE_OP []
2024-07-17 19:42:46.937 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> TX_ROLLBACK []
2024-07-17 19:42:46.937 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> DELETE_OP [[107916205149.05]]
2024-07-17 19:42:46.937 [1042003] main I> WAL threshold exceeded, triggering checkpoint
2024-07-17 19:42:46.938 [1042003] main/106/checkpoint_daemon I> vinyl checkpoint started
2024-07-17 19:42:46.938 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> INDEX_DELETE_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"
asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloo
m_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},[769499766022.62]]
2024-07-17 19:42:46.938 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> LEN_OP []
2024-07-17 19:42:46.938 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> INDEX_ALTER_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"a
sc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom
_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},{"page_size":6144,"parts":[["field_2"],["field_1"],["field_3"]],"i
f_not_exists":false,"bloom_fpr":0.09,"unique":true,"type":"TREE","range_size":1073741824}]
2024-07-17 19:42:46.938 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> ERROR: opname "INDEX_ALTER_OP", err "Can't modify space 'test_1': th
e space is already being modified", args [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc","type":"double","exclude_null":false,"is_nullable
":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_fpr":0.32,"range_size":1073741824},"space_id":512,"t
ype":"TREE","name":"idx_1"},{"page_size":6144,"parts":[["field_2"],["field_1"],["field_3"]],"type":"TREE","bloom_fpr":0.09,"unique":true,"name":"id
x_1","range_size":1073741824}]
2024-07-17 19:42:46.938 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> INDEX_DROP_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"as
c","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_
fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.938 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> SNAPSHOT_OP []
2024-07-17 19:42:46.938 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> TX_COMMIT []
2024-07-17 19:42:46.938 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> FORMAT_OP [[{"name":"field_1","type":"double"},{"name":"field_2","ty
pe":"unsigned"},{"name":"field_3","type":"uuid"},{"name":"field_4","type":"integer"},{"name":"field_5","type":"string"},{"name":"field_6","type":"n
umber"},{"name":"field_7","type":"boolean"},{"name":"field_8","type":"decimal"},{"name":"field_9","type":"datetime"},{"name":"field_10","type":"arr
ay"},{"name":"field_11","type":"map"}]]
2024-07-17 19:42:46.938 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> ERROR: opname "FORMAT_OP", err "Can't modify space 'test_1': the spa
ce is already being modified", args [[{"name":"field_1","type":"double"},{"name":"field_2","type":"unsigned"},{"name":"field_3","type":"uuid"},{"na
me":"field_4","type":"integer"},{"name":"field_5","type":"string"},{"name":"field_6","type":"number"},{"name":"field_7","type":"boolean"},{"name":"
field_8","type":"decimal"},{"name":"field_9","type":"datetime"},{"name":"field_10","type":"array"},{"name":"field_11","type":"map"}]]
2024-07-17 19:42:46.938 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> INDEX_GET_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc
","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_f
pr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},[173544079597.91]]
2024-07-17 19:42:46.938 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> INDEX_MIN_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc
","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_f
pr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.939 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> INDEX_MAX_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc
","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_f
pr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.939 [1042003] snapshot/101/main I> saving snapshot `./00000000000000004517.snap.inprogress'
2024-07-17 19:42:46.939 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> INDEX_SELECT_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"
asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloo
m_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},[436886695096.47]]
2024-07-17 19:42:46.939 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> REPLACE_OP [[23030352310.341,943678220709,"9f6fe394-c720-4893-b1e8-5
fe853a1e81e",271686327827,"osfzncijik",625734341872,true,"518626255209","2024-07-17T16:42:46Z",[1,2,3,4,5,6,7,8],{"1":1,"2":2}]]
2024-07-17 19:42:46.939 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> TX_BEGIN []
2024-07-17 19:42:46.939 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> GET_OP [[446778442378.45]]
2024-07-17 19:42:46.940 [1042003] main/108/vinyl.scheduler I> 512/0: completed compacting range (-inf..inf)
2024-07-17 19:42:46.940 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> ERROR: opname "INDEX_COUNT_OP", err "Transaction has been aborted by
conflict", args [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"option
s":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_
1"}]
2024-07-17 19:42:46.940 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> INDEX_UPDATE_OP [[412410715912.32],{"unique":true,"parts":[{"fieldno
":1,"sort_order":"asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_s
ize_ratio":4,"bloom_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},[["-",4,338602803640],["-",1,650072834142.17],[
"=",5,"xkanzzqmxe"],["!",7,false]]]
2024-07-17 19:42:46.940 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> ERROR: opname "INDEX_UPDATE_OP", err "Transaction has been aborted b
y conflict", args [[412410715912.32],{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc","type":"double","exclude_null":false,"is_nullable":fal
se}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_fpr":0.32,"range_size":1073741824},"space_id":512,"type":
"TREE","name":"idx_1"},[["-",4,338602803640],["-",1,650072834142.17],["=",5,"xkanzzqmxe"],["!",7,false]]]
2024-07-17 19:42:46.940 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> INDEX_RENAME_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"
asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloo
m_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},"wyhiaahibr"]
2024-07-17 19:42:46.940 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> ERROR: opname "INDEX_RENAME_OP", err "A multi-statement transaction
can not use multiple storage engines", args [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc","type":"double","exclude_null":false,"is_nulla
ble":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_fpr":0.32,"range_size":1073741824},"space_id":512
,"type":"TREE","name":"idx_1"},"wyhiaahibr"]
2024-07-17 19:42:46.940 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> INDEX_STAT_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"as
c","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_
fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.940 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> SELECT_OP ["TREE",[77068162516.717]]
2024-07-17 19:42:46.940 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> ERROR: opname "SELECT_OP", err "Transaction has been aborted by conf
lict", args ["TREE",[77068162516.717]]
2024-07-17 19:42:46.940 [1042003] snapshot/101/main I> done
2024-07-17 19:42:46.940 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> INDEX_COUNT_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"a
sc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom
_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.940 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> ERROR: opname "INDEX_COUNT_OP", err "Transaction has been aborted by
conflict", args [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"option
s":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_
1"}]
2024-07-17 19:42:46.940 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> INDEX_RANDOM_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"
asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloo
m_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.940 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> INSERT_OP [[483184078760.04,738369932581,"90f153ca-90fd-4bfe-82b9-49
6d73f51351",679208240348,"gulgzxyfyq",712860143704,true,"589461037164","2024-07-17T16:42:46Z",[1,2,3,4,5,6,7,8],{"4":4,"1":1,"5":5,"2":2,"6":6,"3":
3}]]
2024-07-17 19:42:46.940 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> ERROR: opname "INSERT_OP", err "Transaction has been aborted by conf
lict", args [[483184078760.04,738369932581,"90f153ca-90fd-4bfe-82b9-496d73f51351",679208240348,"gulgzxyfyq",712860143704,true,"589461037164","2024-
07-17T16:42:46Z",[1,2,3,4,5,6,7,8],{"4":4,"1":1,"5":5,"2":2,"6":6,"3":3}]]
2024-07-17 19:42:46.940 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> INDEX_COMPACT_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":
"asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"blo
om_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.940 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> INDEX_CREATE_OP []
2024-07-17 19:42:46.941 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> ERROR: opname "INDEX_CREATE_OP", err "A multi-statement transaction
can not use multiple storage engines", args []
2024-07-17 19:42:46.941 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> UPSERT_OP [[55318535124.151,630507504477,"ea6177a6-6051-4561-9d7d-77
c26296c224",637724614329,"bsmkoaqtnr",723943398043,false,"428633145613","2024-07-17T16:42:46Z",[1,2,3,4,5,6,7,8],{"2":2,"4":4,"1":1,"3":3}],[["#",2
,576249658266]]]
2024-07-17 19:42:46.941 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> ERROR: opname "UPSERT_OP", err "Transaction has been aborted by conf
lict", args [[55318535124.151,630507504477,"ea6177a6-6051-4561-9d7d-77c26296c224",637724614329,"bsmkoaqtnr",723943398043,false,"428633145613","2024
-07-17T16:42:46Z",[1,2,3,4,5,6,7,8],{"2":2,"4":4,"1":1,"3":3}],[["#",2,576249658266]]]
2024-07-17 19:42:46.941 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> UPDATE_OP [[13652476562.927],[["-",1,963609145824.18]]]
2024-07-17 19:42:46.941 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> ERROR: opname "UPDATE_OP", err "Transaction has been aborted by conf
lict", args [[13652476562.927],[["-",1,963609145824.18]]]
2024-07-17 19:42:46.941 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> PUT_OP [[729252628880.33,924901506257,"efcc7b5f-2cf5-4280-b27d-e7cf8
02d0331",575848605647,"kyhwdqkydz",690787115514,true,"761511360098","2024-07-17T16:42:46Z",[1,2,3,4,5,6,7,8],{"4":4,"8":8,"1":1,"5":5,"9":9,"6":6,"
3":3,"7":7,"2":2,"10":10}]]
2024-07-17 19:42:46.941 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> ERROR: opname "PUT_OP", err "Transaction has been aborted by conflic
t", args [[729252628880.33,924901506257,"efcc7b5f-2cf5-4280-b27d-e7cf802d0331",575848605647,"kyhwdqkydz",690787115514,true,"761511360098","2024-07-
17T16:42:46Z",[1,2,3,4,5,6,7,8],{"4":4,"8":8,"1":1,"5":5,"9":9,"6":6,"3":3,"7":7,"2":2,"10":10}]]
2024-07-17 19:42:46.941 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> BSIZE_OP []
2024-07-17 19:42:46.941 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> TX_ROLLBACK []
2024-07-17 19:42:46.941 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> DELETE_OP [[541317626780.97]]
2024-07-17 19:42:46.941 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> INDEX_DELETE_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"
asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloo
m_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},[648343798463.6]]
2024-07-17 19:42:46.941 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> LEN_OP []
2024-07-17 19:42:46.941 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> INDEX_ALTER_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"a
sc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom
_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},{"page_size":1024,"parts":[["field_2"],["field_1"],["field_3"],["f
ield_4"]],"if_not_exists":false,"bloom_fpr":0.43,"unique":true,"type":"TREE","range_size":1073741824}]
2024-07-17 19:42:46.941 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> ERROR: opname "INDEX_ALTER_OP", err "A multi-statement transaction c
an not use multiple storage engines", args [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc","type":"double","exclude_null":false,"is_nullab
le":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_fpr":0.32,"range_size":1073741824},"space_id":512,
"type":"TREE","name":"idx_1"},{"page_size":1024,"parts":[["field_2"],["field_1"],["field_3"],["field_4"]],"bloom_fpr":0.43,"unique":true,"type":"TR
EE","range_size":1073741824}]
2024-07-17 19:42:46.941 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> INDEX_DROP_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"as
c","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_
fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.941 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> SNAPSHOT_OP []
2024-07-17 19:42:46.941 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> TX_COMMIT []
2024-07-17 19:42:46.941 [1042003] main/108/vinyl.scheduler I> 512/1: dump started
2024-07-17 19:42:46.941 [1042003] vinyl.dump.0/841/task I> writing `./512/1/00000000000000002373.run'
2024-07-17 19:42:46.942 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> FORMAT_OP [[{"name":"field_1","type":"double"},{"name":"field_2","ty
pe":"unsigned"},{"name":"field_3","type":"uuid"},{"name":"field_4","type":"integer"},{"name":"field_5","type":"string"},{"name":"field_6","type":"n
umber"},{"name":"field_7","type":"boolean"},{"name":"field_8","type":"decimal"},{"name":"field_9","type":"datetime"},{"name":"field_10","type":"arr
ay"},{"name":"field_11","type":"map"}]]
2024-07-17 19:42:46.942 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> ERROR: opname "FORMAT_OP", err "Can't modify space 'test_1': the spa
ce is already being modified", args [[{"name":"field_1","type":"double"},{"name":"field_2","type":"unsigned"},{"name":"field_3","type":"uuid"},{"na
me":"field_4","type":"integer"},{"name":"field_5","type":"string"},{"name":"field_6","type":"number"},{"name":"field_7","type":"boolean"},{"name":"
field_8","type":"decimal"},{"name":"field_9","type":"datetime"},{"name":"field_10","type":"array"},{"name":"field_11","type":"map"}]]
2024-07-17 19:42:46.942 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> INDEX_GET_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc
","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_f
pr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},[194301331403.3]]
2024-07-17 19:42:46.942 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> INDEX_MIN_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc
","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_f
pr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.942 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> INDEX_MAX_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"asc
","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloom_f
pr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"}]
2024-07-17 19:42:46.942 [1042003] main/108/vinyl.scheduler I> 512/0: started compacting range (-inf..inf), runs 2/2
2024-07-17 19:42:46.942 [1042003] vinyl.compaction.1/360/task I> writing `./512/0/00000000000000002374.run'
2024-07-17 19:42:46.942 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> INDEX_SELECT_OP [{"unique":true,"parts":[{"fieldno":1,"sort_order":"
asc","type":"double","exclude_null":false,"is_nullable":false}],"id":0,"options":{"page_size":5120,"run_count_per_level":3,"run_size_ratio":4,"bloo
m_fpr":0.32,"range_size":1073741824},"space_id":512,"type":"TREE","name":"idx_1"},[219985359580.35]]
2024-07-17 19:42:46.942 [1042003] vinyl.dump.0/841/task I> writing `./512/1/00000000000000002373.index'
2024-07-17 19:42:46.942 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> REPLACE_OP [[43438470293.131,836803511172,"28188e09-70ce-4668-8f08-4
cc929c26cc1",488302057884,"uxdixblnam",163321812294,false,"28521067171","2024-07-17T16:42:46Z",[1,2,3,4,5,6,7,8],{"1":1}]]
2024-07-17 19:42:46.942 [1042003] coio I> removed ./00000000000000004501.xlog
2024-07-17 19:42:46.943 [1042003] main/116/WRK #3/test.fuzz.lua.test_engine I> Worker #3 has finished.
2024-07-17 19:42:46.943 [1042003] main/120/WRK #7/test.fuzz.lua.test_engine I> Worker #7 has finished.
2024-07-17 19:42:46.943 [1042003] main/115/WRK #2/test.fuzz.lua.test_engine I> Worker #2 has finished.
2024-07-17 19:42:46.943 [1042003] main/118/WRK #5/test.fuzz.lua.test_engine I> Worker #5 has finished.
2024-07-17 19:42:46.943 [1042003] main/108/vinyl.scheduler I> 512/1: dump completed
2024-07-17 19:42:46.943 [1042003] main/108/vinyl.scheduler I> 512/0: dump started
2024-07-17 19:42:46.943 [1042003] vinyl.dump.0/842/task I> writing `./512/0/00000000000000002376.run'
2024-07-17 19:42:46.944 [1042003] main/121/WRK #8/test.fuzz.lua.test_engine I> Worker #8 has finished.
2024-07-17 19:42:46.944 [1042003] vinyl.dump.0/842/task I> writing `./512/0/00000000000000002376.index'
2024-07-17 19:42:46.945 [1042003] main/108/vinyl.scheduler I> 512/0: dump completed
2024-07-17 19:42:46.945 [1042003] main/108/vinyl.scheduler I> dumped 0 bytes in 0.0 s, rate 0.0 MB/s
2024-07-17 19:42:46.945 [1042003] main/106/checkpoint_daemon I> vinyl checkpoint completed
2024-07-17 19:42:46.946 [1042003] main/122/WRK #9/test.fuzz.lua.test_engine I> Worker #9 has finished.
2024-07-17 19:42:46.946 [1042003] main/106/checkpoint_daemon I> scheduled next checkpoint for Wed Jul 17 19:43:10 2024
2024-07-17 19:42:46.946 [1042003] coio I> removed ./00000000000000004506.snap
2024-07-17 19:42:46.946 [1042003] coio I> removed ./00000000000000004501.vylog
2024-07-17 19:42:46.946 [1042003] coio I> removed ./512/0/00000000000000002360.index
2024-07-17 19:42:46.946 [1042003] coio I> removed ./512/0/00000000000000002360.run
2024-07-17 19:42:46.946 [1042003] coio I> removed ./512/0/00000000000000002362.index
2024-07-17 19:42:46.946 [1042003] coio I> removed ./512/0/00000000000000002362.run
2024-07-17 19:42:46.947 [1042003] coio I> removed ./512/1/00000000000000002364.index
2024-07-17 19:42:46.947 [1042003] coio I> removed ./512/1/00000000000000002364.run
2024-07-17 19:42:46.947 [1042003] coio I> removed ./512/1/00000000000000002354.index
2024-07-17 19:42:46.947 [1042003] coio I> removed ./512/1/00000000000000002354.run
2024-07-17 19:42:46.947 [1042003] coio I> removed ./512/1/00000000000000002342.index
2024-07-17 19:42:46.947 [1042003] coio I> removed ./512/1/00000000000000002342.run
2024-07-17 19:42:46.947 [1042003] coio I> removed ./512/1/00000000000000002348.index
2024-07-17 19:42:46.947 [1042003] coio I> removed ./512/1/00000000000000002348.run
2024-07-17 19:42:46.947 [1042003] coio I> removed ./512/1/00000000000000002358.index
2024-07-17 19:42:46.947 [1042003] coio I> removed ./512/1/00000000000000002358.run
2024-07-17 19:42:46.947 [1042003] coio I> removed ./00000000000000004506.xlog
2024-07-17 19:42:46.952 [1042003] vinyl.compaction.1/360/task I> writing `./512/0/00000000000000002374.index'
2024-07-17 19:42:46.953 [1042003] main/108/vinyl.scheduler I> 512/0: completed compacting range (-inf..inf)
2024-07-17 19:42:47.955 [1042003] main/125/ERRINJ/test.fuzz.lua.test_engine I> Fault injection fiber has finished.
2024-07-17 19:42:47.955 [1042003] main/104/test_engine.lua/test.fuzz.lua.test_engine I> ERROR: "Transaction has been aborted by conflict"
2024-07-17 19:43:10.938 [1042003] main/106/checkpoint_daemon I> vinyl checkpoint started
2024-07-17 19:43:10.938 [1042003] main/108/vinyl.scheduler I> 512/1: dump started
2024-07-17 19:43:10.938 [1042003] vinyl.dump.0/843/task I> writing `./512/1/00000000000000002379.run'
2024-07-17 19:43:10.938 [1042003] snapshot/101/main I> saving snapshot `./00000000000000004522.snap.inprogress'
2024-07-17 19:43:10.949 [1042003] snapshot/101/main I> done
2024-07-17 19:43:10.949 [1042003] vinyl.dump.0/843/task I> writing `./512/1/00000000000000002379.index'
2024-07-17 19:43:10.950 [1042003] main/108/vinyl.scheduler I> 512/1: dump completed
2024-07-17 19:43:10.950 [1042003] main/108/vinyl.scheduler I> 512/0: dump started
2024-07-17 19:43:10.950 [1042003] vinyl.dump.0/844/task I> writing `./512/0/00000000000000002381.run'
2024-07-17 19:43:10.950 [1042003] vinyl.dump.0/844/task I> writing `./512/0/00000000000000002381.index'
2024-07-17 19:43:10.951 [1042003] main/108/vinyl.scheduler I> 512/0: dump completed
2024-07-17 19:43:10.951 [1042003] main/108/vinyl.scheduler I> dumped 297740 bytes in 0.0 s, rate 21.6 MB/s
2024-07-17 19:43:10.951 [1042003] main/106/checkpoint_daemon I> vinyl checkpoint completed
2024-07-17 19:43:10.953 [1042003] main/106/checkpoint_daemon I> scheduled next checkpoint for Wed Jul 17 19:43:34 2024
2024-07-17 19:43:10.953 [1042003] coio I> removed ./00000000000000004517.snap
2024-07-17 19:43:10.953 [1042003] coio I> removed ./00000000000000004506.vylog
2024-07-17 19:43:10.953 [1042003] coio I> removed ./512/0/00000000000000002366.index
2024-07-17 19:43:10.953 [1042003] coio I> removed ./512/0/00000000000000002366.run
2024-07-17 19:43:10.953 [1042003] coio I> removed ./512/0/00000000000000002368.index
2024-07-17 19:43:10.953 [1042003] coio I> removed ./512/0/00000000000000002368.run
2024-07-17 19:43:10.953 [1042003] coio I> removed ./00000000000000004517.xlog
2024-07-17 19:43:34.939 [1042003] main/106/checkpoint_daemon I> scheduled next checkpoint for Wed Jul 17 19:43:58 2024
2024-07-17 19:43:58.939 [1042003] main/106/checkpoint_daemon I> scheduled next checkpoint for Wed Jul 17 19:44:22 2024
2024-07-17 19:44:22.939 [1042003] main/106/checkpoint_daemon I> scheduled next checkpoint for Wed Jul 17 19:44:46 2024
<snipped>
fiber.info:
output
unix/:/tmp/tarantool.sock> fiber = require('fiber')
---
...
unix/:/tmp/tarantool.sock> fiber.info({ bt = true })
---
- 105:
backtrace:
- C: '#1 0x56478aa85b91 in gc_cleanup_fiber_f+129'
- C: '#2 0x56478a9a8e81 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+17'
- C: '#3 0x56478ab75b66 in fiber_loop+70'
- C: '#4 0x56478adf337c in coro_init+76'
csw: 7605
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: gc
fid: 105
122:
backtrace:
- C: '#1 0x56478adf337c in coro_init+76'
csw: 8343
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: 'WRK #9'
fid: 122
106:
backtrace:
- C: '#1 0x56478aa86e21 in gc_checkpoint_fiber_f+337'
- C: '#2 0x56478a9a8e81 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+17'
- C: '#3 0x56478ab75b66 in fiber_loop+70'
- C: '#4 0x56478adf337c in coro_init+76'
csw: 2750
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: checkpoint_daemon
fid: 106
123:
backtrace:
- C: '#1 0x56478adf337c in coro_init+76'
csw: 28
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: 'WRK #10'
fid: 123
107:
backtrace:
- C: '#1 0x56478a9e3b09 in memtx_engine_gc_f(__va_list_tag*)+153'
- C: '#2 0x56478a9a8e81 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+17'
- C: '#3 0x56478ab75b66 in fiber_loop+70'
- C: '#4 0x56478adf337c in coro_init+76'
csw: 51
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: memtx.gc
fid: 107
124:
backtrace:
- C: '#1 0x56478ab7e4fa in coio_wait+186'
- C: '#2 0x56478ab52ee6 in lbox_socket_iowait+214'
- L: '#3 iowait in =[C]:-1'
- L: '#4 do_wait in @builtin/socket.lua:355'
- L: '#5 socket_readable in @builtin/socket.lua:367'
- L: '#6 (unnamed) in @builtin/socket.lua:1149'
- C: '#7 0x56478abb4fe5 in lua_pcall+117'
- C: '#8 0x56478ab4f2df in luaT_call+15'
- C: '#9 0x56478ab455fa in lua_fiber_run_f+106'
- C: '#10 0x56478a9a8e81 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+17'
- C: '#11 0x56478ab75b66 in fiber_loop+70'
- C: '#12 0x56478adf337c in coro_init+76'
csw: 5
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: console/unix/:/tmp/tarantool.sock
fid: 124
108:
backtrace:
- C: '#1 0x56478ab79da6 in fiber_cond_wait_timeout+102'
- C: '#2 0x56478aa39d1d in vy_scheduler_f+1373'
- C: '#3 0x56478a9a8e81 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+17'
- C: '#4 0x56478ab75b66 in fiber_loop+70'
- C: '#5 0x56478adf337c in coro_init+76'
csw: 6314
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: vinyl.scheduler
fid: 108
117:
backtrace:
- C: '#1 0x56478ab79da6 in fiber_cond_wait_timeout+102'
- C: '#2 0x56478aa3b648 in vy_scheduler_dump+40'
- C: '#3 0x56478a9f86b5 in vinyl_space_build_index+1925'
- C: '#4 0x56478aa4e0ff in CreateIndex::prepare(alter_space*)+223'
- C: '#5 0x56478aa5b615 in alter_space_do(txn_stmt*, alter_space*)+453'
- C: '#6 0x56478aa5f311 in on_replace_dd_index(trigger*, void*)+1745'
- C: '#7 0x56478ab8cedd in trigger_run_list(rlist*, void*)+141'
- C: '#8 0x56478ab8cfca in trigger_run+170'
- C: '#9 0x56478aa40912 in space_on_replace+50'
- C: '#10 0x56478aa6a189 in txn_commit_stmt+217'
- C: '#11 0x56478aa77c3c in box_process_rw+412'
- C: '#12 0x56478aa7df06 in box_insert+86'
- C: '#13 0x56478ab1bc88 in lbox_insert+440'
- L: '#14 insert in =[C]:-1'
- L: '#15 (unnamed) in @builtin/box/schema.lua:1715'
- C: '#16 0x56478abb4fe5 in lua_pcall+117'
- C: '#17 0x56478ab4f2df in luaT_call+15'
- C: '#18 0x56478ab455fa in lua_fiber_run_f+106'
- C: '#19 0x56478a9a8e81 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+17'
- C: '#20 0x56478ab75b66 in fiber_loop+70'
- C: '#21 0x56478adf337c in coro_init+76'
csw: 405
max_slice:
err: 1
warn: 0.5
memory:
total: 524752
used: 139
time: 0
name: 'WRK #4'
fid: 117
109:
backtrace:
- C: '#1 0x56478ab79da6 in fiber_cond_wait_timeout+102'
- C: '#2 0x56478aa2fc28 in vy_log_flusher_f+440'
- C: '#3 0x56478a9a8e81 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+17'
- C: '#4 0x56478ab75b66 in fiber_loop+70'
- C: '#5 0x56478adf337c in coro_init+76'
csw: 2554
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: vinyl.vylog_flusher
fid: 109
103:
backtrace: []
csw: 0
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: on_shutdown
fid: 103
118:
backtrace:
- C: '#1 0x56478adf337c in coro_init+76'
csw: 8458
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: 'WRK #5'
fid: 118
102:
backtrace:
- C: '#1 0x56478a9a8e81 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+17'
- C: '#2 0x56478ab75b66 in fiber_loop+70'
- C: '#3 0x56478adf337c in coro_init+76'
csw: 1
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: box.watchable
fid: 102
119:
backtrace:
- C: '#1 0x56478adf337c in coro_init+76'
csw: 30
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: 'WRK #6'
fid: 119
101:
backtrace:
- L: '#1 stall in =[C]:-1'
- L: '#2 (unnamed) in @builtin/fiber.lua:100'
- C: '#3 0x56478abb4fe5 in lua_pcall+117'
- C: '#4 0x56478ab4f2df in luaT_call+15'
- C: '#5 0x56478ab455fa in lua_fiber_run_f+106'
- C: '#6 0x56478a9a8e81 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+17'
- C: '#7 0x56478ab75b66 in fiber_loop+70'
- C: '#8 0x56478adf337c in coro_init+76'
csw: 1
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: tasks_worker_fiber
fid: 101
111:
backtrace:
- C: '#1 0x56478ab48693 in lbox_fiber_sleep+211'
- L: '#2 pcall in =[C]:-1'
- L: '#3 (unnamed) in @builtin/box/feedback_daemon.lua:455'
- C: '#4 0x56478abb4fe5 in lua_pcall+117'
- C: '#5 0x56478ab4f2df in luaT_call+15'
- C: '#6 0x56478ab455fa in lua_fiber_run_f+106'
- C: '#7 0x56478a9a8e81 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+17'
- C: '#8 0x56478ab75b66 in fiber_loop+70'
- C: '#9 0x56478adf337c in coro_init+76'
csw: 6
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: guard of feedback_daemon
fid: 111
120:
backtrace:
- C: '#1 0x56478adf337c in coro_init+76'
csw: 8508
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: 'WRK #7'
fid: 120
131:
backtrace:
- C: '#1 0x56478ab45fd0 in lbox_fiber_statof_map.isra.0+1008'
- C: '#2 0x56478ab460c8 in lbox_fiber_statof_bt+72'
- C: '#3 0x56478ab76024 in fiber_stat+100'
- C: '#4 0x56478ab48981 in lbox_fiber_info+49'
- L: '#5 fn in =[C]:-1'
- L: '#6 (unnamed) in @builtin/box/console.lua:429'
- C: '#7 0x56478abb4fe5 in lua_pcall+117'
- C: '#8 0x56478ab4f2df in luaT_call+15'
- C: '#9 0x56478ab455fa in lua_fiber_run_f+106'
- C: '#10 0x56478a9a8e81 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+17'
- C: '#11 0x56478ab75b66 in fiber_loop+70'
- C: '#12 0x56478adf337c in coro_init+76'
csw: 11
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: 'console/unix/:'
fid: 131
112:
backtrace:
- C: '#1 0x56478ab7ac9a in fiber_channel_get_msg_timeout+170'
- C: '#2 0x56478ab49a3a in luaT_fiber_channel_get+138'
- L: '#3 get in =[C]:-1'
- L: '#4 (unnamed) in @builtin/box/feedback_daemon.lua:352'
- C: '#5 0x56478abb4fe5 in lua_pcall+117'
- C: '#6 0x56478ab4f2df in luaT_call+15'
- C: '#7 0x56478ab455fa in lua_fiber_run_f+106'
- C: '#8 0x56478a9a8e81 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+17'
- C: '#9 0x56478ab75b66 in fiber_loop+70'
- C: '#10 0x56478adf337c in coro_init+76'
csw: 17
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: feedback_daemon
fid: 112
104:
backtrace:
- C: '#1 0x56478ab47b1e in lbox_fiber_join+414'
- L: '#2 join in =[C]:-1'
- L: '#3 run_test in @test/fuzz/lua/test_engine.lua:1392'
- L: '#4 (unnamed) in @test/fuzz/lua/test_engine.lua:1413'
- C: '#5 0x56478abb4fe5 in lua_pcall+117'
- C: '#6 0x56478ab4f2df in luaT_call+15'
- C: '#7 0x56478ab42681 in lua_main+97'
- C: '#8 0x56478ab43d70 in run_script_f+2240'
- C: '#9 0x56478a9a8e81 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+17'
- C: '#10 0x56478ab75b66 in fiber_loop+70'
- C: '#11 0x56478adf337c in coro_init+76'
csw: 32
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: test_engine.lua
fid: 104
121:
backtrace:
- C: '#1 0x56478adf337c in coro_init+76'
csw: 8375
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: 'WRK #8'
fid: 121
113:
backtrace:
- C: '#1 0x56478ab48693 in lbox_fiber_sleep+211'
- L: '#2 pcall in =[C]:-1'
- L: '#3 (unnamed) in @builtin/box/feedback_daemon.lua:420'
- C: '#4 0x56478abb4fe5 in lua_pcall+117'
- C: '#5 0x56478ab4f2df in luaT_call+15'
- C: '#6 0x56478ab455fa in lua_fiber_run_f+106'
- C: '#7 0x56478a9a8e81 in fiber_cxx_invoke(int (*)(__va_list_tag*), __va_list_tag*)+17'
- C: '#8 0x56478ab75b66 in fiber_loop+70'
- C: '#9 0x56478adf337c in coro_init+76'
csw: 64
max_slice:
err: 1
warn: 0.5
memory:
total: 520656
used: 0
time: 0
name: metrics_collector
fid: 113
...
unix/:/tmp/tarantool.sock>
fiber.top:
output
unix/:/tmp/tarantool.sock> fiber.top_enable()
---
...
unix/:/tmp/tarantool.sock> fiber.top()
---
- cpu:
105/gc:
instant: 0
time: 0
average: 0
108/vinyl.scheduler:
instant: 0
time: 0
average: 0
'119/WRK #6':
instant: 0
time: 0
average: 0
124/console/unix/:/tmp/tarantool.sock:
instant: 0
time: 0
average: 0
'120/WRK #7':
instant: 0
time: 0
average: 0
107/memtx.gc:
instant: 0
time: 0
average: 0
'123/WRK #10':
instant: 0
time: 0
average: 0
109/vinyl.vylog_flusher:
instant: 0
time: 0
average: 0
103/on_shutdown:
instant: 0
time: 0
average: 0
101/tasks_worker_fiber:
instant: 0
time: 0
average: 0
104/test_engine.lua:
instant: 0
time: 0
average: 0
'122/WRK #9':
instant: 0
time: 0
average: 0
106/checkpoint_daemon:
instant: 0
time: 0
average: 0
'121/WRK #8':
instant: 0
time: 0
average: 0
112/feedback_daemon:
instant: 0
time: 0
average: 0
1/sched:
instant: 100
time: 0.000451672
average: 100
'131/console/unix/:':
instant: 0
time: 5.1673e-05
average: 0
102/box.watchable:
instant: 0
time: 0
average: 0
113/metrics_collector:
instant: 0
time: 0
average: 0
'118/WRK #5':
instant: 0
time: 0
average: 0
111/guard of feedback_daemon:
instant: 0
time: 0
average: 0
'117/WRK #4':
instant: 0
time: 0
average: 0
cpu_misses: 0
...
unix/:/tmp/tarantool.sock>
Expected behavior
test script finished sucessfully