Replication caused assertion

[Dimitry Sibiryakov]

Hello All.

I try to set up replication for debug build and got this stack trace as soon
as replication is attempts to start. `fb_assert(!cached)` throws it.

[0x0] ucrtbased!issue_debug_notification+0x45 0x3b7d4c0 0x7fff5aff8103
[0x1] ucrtbased!__acrt_report_runtime_error+0x13 0x3b7d510 0x7fff5b00d7dd
[0x2] ucrtbased!abort+0x1d 0x3b7d570 0x7fff3b322f2c
[0x3] Engine13!fb_assert_impl+0x9c 0x3b7d5b0 0x7fff3b9f53da
[0x4] Engine13!Firebird::CachedMasterInterface::set+0x6a 0x3b7d600
0x7fff3b72cf08
[0x5] Engine13!firebird_plugin+0x28 0x3b7d630 0x7fff4a636cb8
[0x6] fbclient!`anonymous namespace'::PluginSet::loadModule+0x438 0x3b7d670
0x7fff4a6363d0
[0x7] fbclient!`anonymous namespace'::PluginSet::next+0x350 0x3b7da50
0x7fff4a642de8
[0x8] fbclient!Firebird::IPluginSetBaseImpl<`anonymous
namespace'::PluginSet,Firebird::CheckStatusWrapper,Firebird::IReferenceCountedImpl<`anonymous
namespace'::PluginSet,Firebird::CheckStatusWrapper,Firebird::Inherit<Firebird::IVersionedImpl<`anonymous
namespace'::PluginSet,Firebird::CheckStatusWrapper,Firebird::Inherit<Firebird::IPluginSet>
> > > >::cloopnextDispatcher+0x78 0x3b7dec0 0x7fff4a5e121e
[0x9] fbclient!Firebird::IPluginSet::next<Firebird::CheckStatusWrapper>+0x6e
0x3b7df40 0x7fff4a6c47f7
[0xa] fbclient!Firebird::GetPlugins<Firebird::IProvider>::next+0x67
0x3b7df80 0x7fff4a677dcb
[0xb] fbclient!Why::Dispatcher::attachOrCreateDatabase+0x51b 0x3b7dfc0
0x7fff4a676186
[0xc] fbclient!Why::Dispatcher::attachDatabase+0x56 0x3b7e880
0x7fff4a62ebeb
[0xd]
fbclient!Firebird::IProviderBaseImpl<Why::Dispatcher,Firebird::CheckStatusWrapper,Firebird::IPluginBaseImpl<Why::Dispatcher,Firebird::CheckStatusWrapper,Firebird::Inherit<Firebird::IReferenceCountedImpl<Why::Dispatcher,Firebird::CheckStatusWrapper,Firebird::Inherit<Firebird::IVersionedImpl<Why::Dispatcher,Firebird::CheckStatusWrapper,Firebird::Inherit<Firebird::IProvider>
> > > > > >::cloopattachDatabaseDispatcher+0xab 0x3b7e8c0 0x14000fa89
[0xe]
firebird!Firebird::IProvider::attachDatabase<Firebird::CheckStatusWrapper>+0x99
0x3b7e980 0x14005e862
[0xf] firebird!`anonymous namespace'::Target::initReplica+0x1b2 0x3b7e9e0
0x14005a759
[0x10] firebird!`anonymous namespace'::process_archive+0xc39 0x3b7edc0
0x14005b5f6
[0x11] firebird!`anonymous namespace'::process_thread+0x116 0x3b7fcd0
0x14008bd68
[0x12] firebird!`anonymous namespace'::ThreadArgs::run+0x38 0x3b7fda0
0x14008bbff
[0x13] firebird!threadStart+0x10f 0x3b7fde0 0x7fff5b014fb8
[0x14] ucrtbased!invoke_thread_procedure+0x28 0x3b7fea0 0x7fff5b014bf1
[0x15] ucrtbased!thread_start<unsigned int (__cdecl*)(void * __ptr64)>+0x91
0x3b7fee0 0x7fff80ad7344
[0x16] KERNEL32!BaseThreadInitThunk+0x14 0x3b7ff30 0x7fff80fa26b1
[0x17] ntdll!RtlUserThreadStart+0x21 0x3b7ff60 0x0

--
WBR, SD.

[Alex Peshkoff]

On 5/27/24 19:13, 'Dimitry Sibiryakov' via firebird-devel wrote:
> Hello All.
>
>   I try to set up replication for debug build and got this stack trace
> as soon as replication is attempts to start. `fb_assert(!cached)`
> throws it.
>

That's typically resut of races. Can you show other threads?

[Alex Peshkoff]

On 5/27/24 19:13, 'Dimitry Sibiryakov' via firebird-devel wrote:

> Hello All.
>
>   I try to set up replication for debug build and got this stack trace
> as soon as replication is attempts to start. `fb_assert(!cached)`
> throws it.
>

That's typically result of races. Can you show other threads?

[Piergiorgio Valli]

Hi,

If your are in Windows,I used Dr Mingw to catch a dump, there more info.

https://github.com/jrfonseca/drmingw

You can install with drmingw -i -v

--
You received this message because you are subscribed to the Google Groups "firebird-devel" group.
To unsubscribe from this group and stop receiving emails from it, send an email to firebird-deve...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/firebird-devel/ac6f5798-4db4-4a70-a7c3-2ce772bd3637%40gmail.com.

[Dimitry Sibiryakov]

Alex Peshkoff wrote 28.05.2024 8:38:
>>   I try to set up replication for debug build and got this stack trace as soon
>> as replication is attempts to start. `fb_assert(!cached)` throws it.
>>
>
> That's typically resut of races. Can you show other threads?

So far I cannot reproduce exactly this assert but running QA replication
tests looks like opening a can of worms:

fb_assert(idxStatus == MET_object_active);

[0x3] Engine13!fb_assert_impl+0x9c 0x3977200 0x7fff30aaf071
[0x4] Engine13!Jrd::Applier::lookupRecord+0x1f1 0x3977250 0x7fff30aacec9
[0x5] Engine13!Jrd::Applier::insertRecord+0x409 0x39796e0 0x7fff30aabd56
[0x6] Engine13!Jrd::Applier::process+0x376 0x3979d30 0x7fff3098946f
[0x7] Engine13!Jrd::JReplicator::process+0xff 0x397e680 0x7fff309be3f2
[0x8]
Engine13!Firebird::IReplicatorBaseImpl<Jrd::JReplicator,Firebird::CheckStatusWrapper,Firebird::IReferenceCountedImpl<Jrd::JReplicator,Firebird::CheckStatusWrapper,Firebird::Inherit<Firebird::IVersionedImpl<Jrd::JReplicator,Firebird::CheckStatusWrapper,Firebird::Inherit<Firebird::IReplicator>
> > > >::cloopprocessDispatcher+0x92 0x397e990 0x7fff51be7d5a
[0x9]
fbclient!Firebird::IReplicator::process<Firebird::CheckStatusWrapper>+0x8a
0x397ea10 0x7fff51bcfc12
[0xa] fbclient!Why::YReplicator::process+0xa2 0x397ea60 0x7fff51c15522

Other thread processing "select.
rdb$get_context('SYSTEM','REPLICA_MODE') replica_mode.
,crypt_hash(b using sha512) as blob_hash. from test"

[0x0] Engine13!sha512_compress+0x118 0x4b9d710 0x7fff30d844bf
[0x1] Engine13!sha512_process+0xdf 0x4b9da60 0x7fff30d2d0c7
[0x2] Engine13!Firebird::LibTomCryptHashContext::update+0x57 0x4b9daa0
0x7fff30b1b45b
[0x3] Engine13!`anonymous namespace'::evlHash+0x33b 0x4b9dae0
0x7fff30707671
[0x4] Engine13!Jrd::SysFuncCallNode::execute+0x91 0x4b9e1a0 0x7fff305e56cd
[0x5] Engine13!Jrd::EVL_expr+0x9d 0x4b9e1f0 0x7fff308f3ab1
[0x6] Engine13!EXE_assignment+0xa1 0x4b9e230 0x7fff307da01e
[0x7] Engine13!Jrd::CompoundStmtNode::execute+0x10e 0x4b9e2c0
0x7fff308f5e91
[0x8] Engine13!EXE_looper+0x551 0x4b9e330 0x7fff308f9202
[0x9] Engine13!looper_seh+0x72 0x4b9e610 0x7fff308f9104
[0xa] Engine13!execute_looper+0xe4 0x4b9e690 0x7fff308f78b6
[0xb] Engine13!EXE_receive+0x6e6 0x4b9e6e0 0x7fff30998827
[0xc] Engine13!JRD_receive+0x57 0x4b9e9a0 0x7fff306b7af2
[0xd] Engine13!Jrd::DsqlDmlRequest::fetch+0x6e2 0x4b9e9e0 0x7fff306b2bcc
[0xe] Engine13!Jrd::DsqlCursor::fetchNext+0x5c 0x4b9ed60 0x7fff30986b22
[0xf] Engine13!Jrd::JResultSet::fetchNext+0xf2 0x4b9eda0 0x7fff309bb798
[0x10]
Engine13!Firebird::IResultSetBaseImpl<Jrd::JResultSet,Firebird::CheckStatusWrapper,Firebird::IReferenceCountedImpl<Jrd::JResultSet,Firebird::CheckStatusWrapper,Firebird::Inherit<Firebird::IVersionedImpl<Jrd::JResultSet,Firebird::CheckStatusWrapper,Firebird::Inherit<Firebird::IResultSet>
> > > >::cloopfetchNextDispatcher+0x88 0x4b9f0c0 0x7fff51b748c2
[0x11]
fbclient!Firebird::IResultSet::fetchNext<Firebird::CheckStatusWrapper>+0x82
0x4b9f150 0x7fff51bce2d5
[0x12] fbclient!Why::YResultSet::fetchNext+0x95 0x4b9f1a0 0x7fff51c12308
[0x13]
fbclient!Firebird::IResultSetBaseImpl<Why::YResultSet,Firebird::CheckStatusWrapper,Firebird::IReferenceCountedImpl<Why::YResultSet,Firebird::CheckStatusWrapper,Firebird::Inherit<Firebird::IVersionedImpl<Why::YResultSet,Firebird::CheckStatusWrapper,Firebird::Inherit<Firebird::IResultSet>
> > > >::cloopfetchNextDispatcher+0x88 0x4b9f240 0x14003dd42
[0x14]
firebird!Firebird::IResultSet::fetchNext<Firebird::CheckStatusWrapper>+0x82
0x4b9f2d0 0x1400281c1
[0x15] firebird!rem_port::fetch+0xd91 0x4b9f320 0x140039306
[0x16] firebird!process_packet+0x886 0x4b9f7c0 0x14003a893

The rest of threads are in wait and do nothing.

After that restarting of Firebird server consistently produces the error
without any working parallel thread so it looks like either database of log
segment is brought to a stable invalid state. Validation find a log of orphan
pages and fix them but it doesn't help.

--
WBR, SD.

[Alex Peshkoff]

On 5/28/24 13:11, 'Dimitry Sibiryakov' via firebird-devel wrote:
> Alex Peshkoff wrote 28.05.2024 8:38:
>>>   I try to set up replication for debug build and got this stack
>>> trace as soon as replication is attempts to start.
>>> `fb_assert(!cached)` throws it.
>>>
>>
>> That's typically resut of races. Can you show other threads?
>
>   So far I cannot reproduce exactly this assert

not surprise in case of races

[Dimitry Sibiryakov]

Dimitry Sibiryakov wrote 28.05.2024 12:11:
>
>   So far I cannot reproduce exactly this assert but running QA replication
> tests looks like opening a can of worms:
>
> fb_assert(idxStatus == MET_object_active);

This one has an interesting cause:
test test_blob_not_found_in_rw_replica_if_target_row_exists.py creates a
table with an explicit index name for PK constraint. As the result constraint
name and index name are different. Applier::insertRecord() gets a name from
status vector and interprets it as an index name while it is really a constraint
name so Applier::lookupRecord() is getting wrong name and got no index id. And
the assert is fired.
I have no idea how it can work in release version.

--
WBR, SD.