Assert at MET_current [CORE5396]

Submitted by: @ibprovider

Firebird 3.0.2.32629. Original source code, custom DEBUG build VS2015 SP3, SuperServer, x64.

IBProvider tests. 4 test threads.

Problem in test thread #⁠3 [table name: TEST_TABLE_6327]

Crash stack engine12.dll!fb_assert_impl(const char * msg, const char * file, int line, bool do_abort) Line 40 C++ > engine12.dll!MET_current(Jrd::thread_db * tdbb, Jrd::jrd_rel * relation) Line 5303 C++ engine12.dll!VIO_gc_record(Jrd::thread_db * tdbb, Jrd::jrd_rel * relation) Line 2073 C++ engine12.dll!purge(Jrd::thread_db * tdbb, Jrd::record_param * rpb) Line 5938 C++ engine12.dll!VIO_chase_record_version(Jrd::thread_db * tdbb, Jrd::record_param * rpb, Jrd::jrd_tra * transaction, Firebird::MemoryPool * pool, bool writelock, bool noundo) Line 1234 C++ engine12.dll!VIO_next_record(Jrd::thread_db * tdbb, Jrd::record_param * rpb, Jrd::jrd_tra * transaction, Firebird::MemoryPool * pool, bool onepage) Line 3015 C++ engine12.dll!garbage_collector(void * arg) Line 4894 C++ engine12.dll!`anonymous namespace'::ThreadArgs::run() Line 78 C++ engine12.dll!threadStart(void * arg) Line 94 C++

Local variables [MET_current]: + attachment 0x0000000003a95920 {att_pool=0x0000000003a921b0 {pool=0x0000000003a91e10 {smallObjects={freeObjects=...} ...} } ...} Jrd::Attachment * + jrd_481 {jrd_482=4156 } MET_current::__l2::<unnamed-type-jrd_481> + jrd_483 {jrd_484=0 jrd_485=1 } MET_current::__l2::<unnamed-type-jrd_483> - relation 0x0000000030bf37b0 {rel_pool=0x0000000003a921b0 {pool=0x0000000003a91e10 {smallObjects={freeObjects=...} ...} } ...} Jrd::jrd_rel * + pool_alloc<9> {...} pool_alloc<9> + rel_pool 0x0000000003a921b0 {pool=0x0000000003a91e10 {smallObjects={freeObjects=0x0000000003a91e18 {0x0000000000000000 <NULL>, ...} ...} ...} } Firebird::MemoryPool * rel_id 4156 unsigned short rel_current_fmt 0 unsigned short rel_flags 800 unsigned long + rel_current_format 0x0000000000000000 <NULL> Jrd::Format * + rel_name {data=0x0000000030bf37d0 "TEST_TABLE_6327" count=15 } Firebird::MetaName + rel_owner_name {data=0x0000000030bf37f4 "" count=0 } Firebird::MetaName + rel_security_name {data=0x0000000030bf3818 "" count=0 } Firebird::MetaName + rel_formats 0x0000000000000000 <NULL> Jrd::vec<Jrd::Format *> * + rel_fields 0x0000000000000000 <NULL> Jrd::vec<Jrd::jrd_fld *> * + rel_view_rse 0x0000000000000000 <NULL> Jrd::RseNode * + rel_view_contexts {sortMode=1 sorted=true } Firebird::SortedArray<Jrd::ViewContext *,Firebird::EmptyStorage<Jrd::ViewContext *>,unsigned short,Jrd::ViewContext,Firebird::DefaultComparator<unsigned short> > + rel_file 0x0000000000000000 <NULL> Jrd::ExternalFile * + rel_gc_records {...} Firebird::HalfStaticArray<Jrd::Record *,4> rel_use_count 0 unsigned short rel_sweep_count 2 unsigned short rel_scan_count 0 short + rel_existence_lock 0x0000000093600148 {lck_dbb=0x000000000208ec50 {dbb_sync={lockState={...} waiters={...} monitorCount=...} ...} ...} Jrd::Lock * + rel_partners_lock 0x0000000030bf3a48 {lck_dbb=0x000000000208ec50 {dbb_sync={lockState={...} waiters={...} monitorCount=...} ...} ...} Jrd::Lock * + rel_rescan_lock 0x0000000093600090 {lck_dbb=0x000000000208ec50 {dbb_sync={lockState={...} waiters={...} monitorCount=...} ...} ...} Jrd::Lock * + rel_gc_lock 0x0000000093600200 {lck_dbb=0x000000000208ec50 {dbb_sync={lockState={...} waiters={...} monitorCount=...} ...} ...} Jrd::Lock * + rel_index_locks 0x0000000000000000 <NULL> Jrd::IndexLock * + rel_index_blocks 0x0000000000000000 <NULL> Jrd::IndexBlock * + rel_pre_erase 0x0000000000000000 <NULL> Firebird::ObjectsArray<Jrd::Trigger,Firebird::Array<Jrd::Trigger *,Firebird::InlineStorage<Jrd::Trigger *,8> > > * + rel_post_erase 0x0000000000000000 <NULL> Firebird::ObjectsArray<Jrd::Trigger,Firebird::Array<Jrd::Trigger *,Firebird::InlineStorage<Jrd::Trigger *,8> > > * + rel_pre_modify 0x0000000000000000 <NULL> Firebird::ObjectsArray<Jrd::Trigger,Firebird::Array<Jrd::Trigger *,Firebird::InlineStorage<Jrd::Trigger *,8> > > * + rel_post_modify 0x0000000000000000 <NULL> Firebird::ObjectsArray<Jrd::Trigger,Firebird::Array<Jrd::Trigger *,Firebird::InlineStorage<Jrd::Trigger *,8> > > * + rel_pre_store 0x0000000000000000 <NULL> Firebird::ObjectsArray<Jrd::Trigger,Firebird::Array<Jrd::Trigger *,Firebird::InlineStorage<Jrd::Trigger *,8> > > * + rel_post_store 0x0000000000000000 <NULL> Firebird::ObjectsArray<Jrd::Trigger,Firebird::Array<Jrd::Trigger *,Firebird::InlineStorage<Jrd::Trigger *,8> > > * + rel_primary_dpnds {prim_reference_ids=0x0000000000000000 <NULL> prim_relations=0x0000000000000000 <NULL> prim_indexes=...} Jrd::prim + rel_foreign_refs {frgn_reference_ids=0x0000000000000000 <NULL> frgn_relations=0x0000000000000000 <NULL> frgn_indexes=...} Jrd::frgn + rel_drop_mutex {spinlock={DebugInfo=0xffffffffffffffff {Type=??? CreatorBackTraceIndex=??? CriticalSection=??? ...} ...} ...} Firebird::Mutex + rel_pages_inst 0x0000000000000000 <NULL> Firebird::SortedArray<Jrd::RelationPages *,Firebird::EmptyStorage<Jrd::RelationPages *>,__int64,Jrd::RelationPages,Firebird::DefaultComparator<__int64> > * + rel_pages_base {rel_pages=0x0000000093600cf8 {...} rel_instance_id=0 rel_index_root=453499 ...} Jrd::RelationPages + rel_pages_free 0x0000000000000000 <NULL> Jrd::RelationPages * + tdbb 0x0000000007a9f780 {defaultPool=0x0000000001ff8d20 {pool=0x0000000001bb7cb0 {smallObjects={freeObjects=...} ...} } ...} Jrd::thread_db *

Last items from IBProvider logs:

----------------------------------------------------------------------------------------- Thread1: [THR:010660] [15.11.2016 11:38:43] * START TEST [rowset.update.upd_row__defer_data.auto_tr.tr_READCOMMITTED.separate.modify_tr_REPEATABLEREAD] [THR:010660] [15.11.2016 11:38:43] * [THR:010660] [15.11.2016 11:38:43] * PREPARE [THR:010660] [15.11.2016 11:38:43] * RUN [THR:010660] [15.11.2016 11:38:43] [tmp_table] create pooled data source... [THR:010660] [15.11.2016 11:38:43] [tmp_table] connect to database ...OK [THR:010660] [15.11.2016 11:38:43] [tmp_table] session.create(data_source) [THR:010660] [15.11.2016 11:38:43] [tmp_table] CREATE TMP TABLE ... [THR:010660] [15.11.2016 11:38:43] [tmp_table] EXEC IMMED:

"SET TRANSACTION WAIT"

[THR:010660] [15.11.2016 11:38:43] [tmp_table] GENERATE ID [GEN_ID_DDL]. Count:1... range: 6329...6329 [THR:010660] [15.11.2016 11:38:43] [tmp_table] EXEC IMMED:

"create table TEST_TABLE_6329 (TEST_ID INTEGER NOT NULL PRIMARY KEY, COL_BLOB BLOB SUB_TYPE TEXT CHARACTER SET WIN1251, COL_ARRAY INTEGER[1:2])"

[THR:010660] [15.11.2016 11:38:43] [tmp_table] COMMIT TRANSACTION [RETAINING=false]... [THR:010660] [15.11.2016 11:38:43] [tmp_table] TMP TABLE NAME: TEST_TABLE_6329 [THR:010660] [15.11.2016 11:38:43] [test] set_init_prop: [auto_commit]=true [THR:010660] [15.11.2016 11:38:43] [test] set_init_prop: [auto_commit_level]=4096 [THR:010660] [15.11.2016 11:38:43] [test] set_init_prop: [ctype]=win1251 [THR:010660] [15.11.2016 11:38:43] [test] set_init_prop: [modify_trans_level]=65536 [THR:010660] [15.11.2016 11:38:43] [test] set_init_prop: [modify_trans_type]=2 [THR:010660] [15.11.2016 11:38:43] [test]

----------------------------------------------------------------------------------------- Thread2: [THR:007212] [15.11.2016 11:38:43] * START TEST [rowset.update.upd_row__defer_data.auto_tr.tr_REPEATABLEREAD.mutable.modify_tr_READCOMMITTED] [THR:007212] [15.11.2016 11:38:43] * [THR:007212] [15.11.2016 11:38:43] * PREPARE [THR:007212] [15.11.2016 11:38:43] * RUN [THR:007212] [15.11.2016 11:38:43] [tmp_table] create pooled data source... [THR:007212] [15.11.2016 11:38:43] [tmp_table] connect to database ...OK [THR:007212] [15.11.2016 11:38:43] [tmp_table] session.create(data_source) [THR:007212] [15.11.2016 11:38:43] [tmp_table] CREATE TMP TABLE ...

----------------------------------------------------------------------------------------- Thread3 [exec problem statement]: [THR:007412] [15.11.2016 11:38:43] [test] EXECUTE COMMAND (or=true,rpi=true) [NO PARAMS] ... [THR:007412] [15.11.2016 11:38:43] [test] FETCH(FORWARD)... OK [THR:007412] [15.11.2016 11:38:43] [test] FETCH TO EOF(FORWARD)... OK [THR:007412] [15.11.2016 11:38:43] [tmp_table] DROP TMP TABLE TEST_TABLE_6327... [THR:007412] [15.11.2016 11:38:43] [tmp_table] create pooled data source... [THR:007412] [15.11.2016 11:38:43] [tmp_table] connect to database ...OK [THR:007412] [15.11.2016 11:38:43] [tmp_table] session.create(data_source) [THR:007412] [15.11.2016 11:38:43] [tmp_table] EXEC IMMED:

"SET TRANSACTION WAIT"

[THR:007412] [15.11.2016 11:38:43] [tmp_table] EXEC IMMED:

"DROP TABLE TEST_TABLE_6327"

----------------------------------------------------------------------------------------- Thread4: [THR:009340] [15.11.2016 11:38:43] [test] CREATE OPEN ROWSET ...OK [THR:009340] [15.11.2016 11:38:43] [test] "Own Changes Visible"=FALSE [0] [THR:009340] [15.11.2016 11:38:43] [test] "IRowsetChange"=TRUE [-1] [THR:009340] [15.11.2016 11:38:43] [test] "IRowsetUpdate"=FALSE [0] [THR:009340] [15.11.2016 11:38:43] [test] "update_sql"=bstr"update TEST_TABLE_6328 set TEST_ID=:NEW.TEST_ID, COL_BLOB=NULL, COL_ARRAY=NULL where TEST_ID=:OLD.TEST_ID"

FirebirdSQL / firebird

Assert at MET_current [CORE5396] #5669