firebird icon indicating copy to clipboard operation
firebird copied to clipboard
verified publisher icon FirebirdSQL

Internal consistency check (page in use during flush) with small number of DefaultDbCachePages

Open Noremos opened this issue 1 year ago • 3 comments

I ran some fireird-qt test with DefaultDbCachePages=128 and sometimes the following errors occurred: internal Firebird consistency check (page in use during flush (210), file: cch.cpp line: 2827) internal Firebird consistency check (page in use during flush (210), file: cch.cpp line: 2757) The srack tarce:

libEngine13.so!flushAll(Jrd::thread_db * tdbb, USHORT flush_flag) (src/jrd/cch.cpp:2757)
libEngine13.so!CCH_flush(Jrd::thread_db * tdbb, USHORT flush_flag, TraNumber tra_number) (src/jrd/cch.cpp:1226)
libEngine13.so!Jrd::JProvider::createDatabase(Jrd::JProvider * const this, Firebird::CheckStatusWrapper * user_status, const char * filename, unsigned int dpb_length, const unsigned char * dpb) (src/jrd/jrd.cpp:3215)
libEngine13.so!Firebird::IProviderBaseImpl<Jrd::JProvider, Firebird::CheckStatusWrapper, Firebird::IPluginBaseImpl<Jrd::JProvider, Firebird::CheckStatusWrapper, Firebird::Inherit<Firebird::IReferenceCountedImpl<Jrd::JProvider, Firebird::CheckStatusWrapper, Firebird::Inherit<Firebird::IVersionedImpl<Jrd::JProvider, Firebird::CheckStatusWrapper, Firebird::Inherit<Firebird::IProvider> > > > > > >::cloopcreateDatabaseDispatcher(Firebird::IProvider * self, Firebird::IStatus * status, const char * fileName, unsigned int dpbLength, const unsigned char * dpb) (src/include/firebird/IdlFbInterfaces.h:12274)
libfbclient.so.2!Firebird::IProvider::createDatabase<Firebird::CheckStatusWrapper>(Firebird::IProvider * const this, Firebird::CheckStatusWrapper * status, const char * fileName, unsigned int dpbLength, const unsigned char * dpb) (src/include/firebird/IdlFbInterfaces.h:2923)
libfbclient.so.2!Why::Dispatcher::attachOrCreateDatabase(Why::Dispatcher * const this, Firebird::CheckStatusWrapper * status, bool createFlag, const char * filename, unsigned int dpbLength, const unsigned char * dpb) (src/yvalve/why.cpp:6464)
libfbclient.so.2!Why::Dispatcher::createDatabase(Why::Dispatcher * const this, Firebird::CheckStatusWrapper * status, const char * filename, unsigned int dpbLength, const unsigned char * dpb) (src/yvalve/why.cpp:6383)
libfbclient.so.2!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> > > > > > >::cloopcreateDatabaseDispatcher(Firebird::IProvider * self, Firebird::IStatus * status, const char * fileName, unsigned int dpbLength, const unsigned char * dpb) (src/include/firebird/IdlFbInterfaces.h:12274)
Firebird::IProvider::createDatabase<Firebird::CheckStatusWrapper>(Firebird::IProvider * const this, Firebird::CheckStatusWrapper * status, const char * fileName, unsigned int dpbLength, const unsigned char * dpb) (src/include/firebird/IdlFbInterfaces.h:2923)
(anonymous namespace)::DatabaseAuth::accept((anonymous namespace)::DatabaseAuth * const this, PACKET * send, Auth::WriterImplementation * authBlock) (src/remote/server/server.cpp:2529)
(anonymous namespace)::ServerAuth::authenticate((anonymous namespace)::ServerAuth * const this, PACKET * send, unsigned int flags) (src/remote/server/server.cpp:622)
attach_database(rem_port * port, P_OP operation, P_ATCH * attach, PACKET * send) (src/remote/server/server.cpp:2465)
process_packet(rem_port * port, PACKET * sendL, PACKET * receive, rem_port ** result) (src/remote/server/server.cpp:5011)
loopThread() (src/remote/server/server.cpp:6748)
(anonymous namespace)::ThreadArgs::run((anonymous namespace)::ThreadArgs * const this) (src/common/ThreadStart.cpp:78)
(anonymous namespace)::threadStart(void * arg) (src/common/ThreadStart.cpp:94)
libc.so.6!start_thread(void * arg) (pthread_create.c:442)
libc.so.6!clone3() (clone3.S:81)


Jrd::BufferDesc::unLockIO(Jrd::thread_db*) (/home/art/wspace/reps/github-fb/src/jrd/cch.cpp:5288)
::write_buffer(Jrd::thread_db *, Jrd::BufferDesc *, Jrd::PageNumber, const bool, Jrd::FbStatusVector *const, const bool) (/home/art/wspace/reps/github-fb/src/jrd/cch.cpp:4848)
Jrd::BufferControl::cache_writer(Jrd::BufferControl*) (/home/art/wspace/reps/github-fb/src/jrd/cch.cpp:3094)
ThreadFinishSync<Jrd::BufferControl*, (void (*)(Jrd::BufferControl*))0>::internalRun() (/home/art/wspace/reps/github-fb/src/common/ThreadStart.h:189)
ThreadFinishSync<Jrd::BufferControl*, (void (*)(Jrd::BufferControl*))0>::internalRun(void*) (/home/art/wspace/reps/github-fb/src/common/ThreadStart.h:181)
(anonymous namespace)::ThreadArgs::run() const (/home/art/wspace/reps/github-fb/src/common/ThreadStart.cpp:78)
(anonymous namespace)::threadStart(void *) (/home/art/wspace/reps/github-fb/src/common/ThreadStart.cpp:94)
start_thread (@start_thread:162)
__clone3 (@__clone3:20)

The easiest way to reproduce this is to use the following test: Firebird.conf: DefaultDbCachePages = 128

The firebird-qa test:

import pytest
from firebird.qa import *

db = db_factory()
act = python_act('db')

@pytest.mark.version('>=5.0')
def test_1(act: Action):
    for i in range(500):
        act.db.drop()
        act.db.create()
    assert 1==1

The native python firebird-driver seems to trigger the issue as well but with some strangers. The python program to reproduce:

from firebird.driver import driver_config, create_database

srv_cfg = """
[local]
host = localhost
user = SYSDBA
password = masterkey
"""
driver_config.register_server('local', srv_cfg)
# driver_config.fb_client_library.value = 'gen/Release/firebird/lib/libfbclient.so'
driver_config.fb_client_library.value = 'gen/Debug/firebird/lib/libfbclient.so'

db_cfg = """[test]
server = local
database = /tmp/test.fdb
charset = utf8
"""
driver_config.register_database('test', db_cfg)

for i in range(1000):
	con = create_database('test', overwrite= True)
	con.drop_database()

The release Firebird build results with the error: firebird.driver.types.DatabaseError: internal Firebird consistency check (page in use during flush (210), file: cch.cpp line: 2827)

But the Debug one stops at completely unrelated assert:

fb_assert_impl(char const*, char const*, int, bool) (src/common/gdsassert.h:48)
Jrd::LiteralNode::dsqlPass(Jrd::DsqlCompilerScratch*) (src/dsql/ExprNodes.cpp:7930)
Jrd::ValueExprNode* Jrd::Node::doDsqlPass<Jrd::ValueExprNode>(Jrd::DsqlCompilerScratch*, NestConst<Jrd::ValueExprNode>&) (src/dsql/Nodes.h:130)
Jrd::ComparativeBoolNode::dsqlPass(Jrd::DsqlCompilerScratch*) (src/dsql/BoolNodes.cpp:491)
Jrd::BoolExprNode* Jrd::Node::doDsqlPass<Jrd::BoolExprNode>(Jrd::DsqlCompilerScratch*, NestConst<Jrd::BoolExprNode>&) (src/dsql/Nodes.h:130)
Jrd::BinaryBoolNode::dsqlPass(Jrd::DsqlCompilerScratch*) (src/dsql/BoolNodes.cpp:198)
Jrd::BoolExprNode* Jrd::Node::doDsqlPass<Jrd::BoolExprNode>(Jrd::DsqlCompilerScratch*, NestConst<Jrd::BoolExprNode>&) (src/dsql/Nodes.h:130)
Jrd::BinaryBoolNode::dsqlPass(Jrd::DsqlCompilerScratch*) (src/dsql/BoolNodes.cpp:198)
Jrd::BoolExprNode* Jrd::Node::doDsqlPass<Jrd::BoolExprNode>(Jrd::DsqlCompilerScratch*, NestConst<Jrd::BoolExprNode>&) (src/dsql/Nodes.h:130)
Jrd::BinaryBoolNode::dsqlPass(Jrd::DsqlCompilerScratch*) (src/dsql/BoolNodes.cpp:198)
Jrd::BoolExprNode* Jrd::Node::doDsqlPass<Jrd::BoolExprNode>(Jrd::DsqlCompilerScratch*, NestConst<Jrd::BoolExprNode>&) (src/dsql/Nodes.h:130)
Jrd::BoolExprNode* Jrd::Node::doDsqlPass<Jrd::BoolExprNode>(Jrd::DsqlCompilerScratch*, NestConst<Jrd::BoolExprNode>&, bool) (src/dsql/Nodes.h:148)
::pass1_rse_impl(Jrd::DsqlCompilerScratch *, Jrd::RecordSourceNode *, Jrd::ValueListNode *, Jrd::RowsClause *, bool, bool, USHORT) (src/dsql/pass1.cpp:1879)
::pass1_rse(Jrd::DsqlCompilerScratch *, Jrd::RecordSourceNode *, Jrd::ValueListNode *, Jrd::RowsClause *, bool, bool, USHORT) (src/dsql/pass1.cpp:1779)
::pass1_union(Jrd::DsqlCompilerScratch *, Jrd::UnionSourceNode *, Jrd::ValueListNode *, Jrd::RowsClause *, bool, bool, USHORT) (src/dsql/pass1.cpp:2480)
::pass1_rse_impl(Jrd::DsqlCompilerScratch *, Jrd::RecordSourceNode *, Jrd::ValueListNode *, Jrd::RowsClause *, bool, bool, USHORT) (src/dsql/pass1.cpp:1827)
::pass1_rse(Jrd::DsqlCompilerScratch *, Jrd::RecordSourceNode *, Jrd::ValueListNode *, Jrd::RowsClause *, bool, bool, USHORT) (src/dsql/pass1.cpp:1779)
::pass1_union(Jrd::DsqlCompilerScratch *, Jrd::UnionSourceNode *, Jrd::ValueListNode *, Jrd::RowsClause *, bool, bool, USHORT) (src/dsql/pass1.cpp:2480)
PASS1_derived_table(Jrd::DsqlCompilerScratch*, Jrd::SelectExprNode*, char const*, Jrd::SelectNode const*) (src/dsql/pass1.cpp:1041)
::dsqlPassRelProc(Jrd::DsqlCompilerScratch *, Jrd::RecordSourceNode *) (src/jrd/RecordSourceNodes.cpp:3721)
Jrd::ProcedureSourceNode::dsqlPass(Jrd::DsqlCompilerScratch*) (src/jrd/RecordSourceNodes.cpp:1196)
Jrd::RecordSourceNode* Jrd::Node::doDsqlPass<Jrd::RecordSourceNode>(Jrd::DsqlCompilerScratch*, NestConst<Jrd::RecordSourceNode>&) (src/dsql/Nodes.h:130)
Jrd::RseNode::dsqlPass(Jrd::DsqlCompilerScratch*) (src/jrd/RecordSourceNodes.cpp:2720)
Jrd::RecordSourceNode* Jrd::Node::doDsqlPass<Jrd::RecordSourceNode>(Jrd::DsqlCompilerScratch*, NestConst<Jrd::RecordSourceNode>&) (src/dsql/Nodes.h:130)
Jrd::RecSourceListNode::dsqlPass(Jrd::DsqlCompilerScratch*) (src/jrd/RecordSourceNodes.cpp:416)
Jrd::RecSourceListNode* Jrd::Node::doDsqlPass<Jrd::RecSourceListNode>(Jrd::DsqlCompilerScratch*, NestConst<Jrd::RecSourceListNode>&) (src/dsql/Nodes.h:130)
Jrd::RecSourceListNode* Jrd::Node::doDsqlPass<Jrd::RecSourceListNode>(Jrd::DsqlCompilerScratch*, NestConst<Jrd::RecSourceListNode>&, bool) (src/dsql/Nodes.h:148)
::pass1_rse_impl(Jrd::DsqlCompilerScratch *, Jrd::RecordSourceNode *, Jrd::ValueListNode *, Jrd::RowsClause *, bool, bool, USHORT) (src/dsql/pass1.cpp:1844)
::pass1_rse(Jrd::DsqlCompilerScratch *, Jrd::RecordSourceNode *, Jrd::ValueListNode *, Jrd::RowsClause *, bool, bool, USHORT) (src/dsql/pass1.cpp:1779)
::pass1_rse_impl(Jrd::DsqlCompilerScratch *, Jrd::RecordSourceNode *, Jrd::ValueListNode *, Jrd::RowsClause *, bool, bool, USHORT) (src/dsql/pass1.cpp:1806)
::pass1_rse(Jrd::DsqlCompilerScratch *, Jrd::RecordSourceNode *, Jrd::ValueListNode *, Jrd::RowsClause *, bool, bool, USHORT) (src/dsql/pass1.cpp:1779)
PASS1_rse(Jrd::DsqlCompilerScratch*, Jrd::SelectExprNode*, Jrd::SelectNode const*) (src/dsql/pass1.cpp:625)
Jrd::SelectNode::dsqlProcess(Jrd::DsqlCompilerScratch*) (src/dsql/StmtNodes.cpp:8992)
Jrd::SelectNode::dsqlPass(Jrd::DsqlCompilerScratch*) (src/dsql/StmtNodes.cpp:9022)
Jrd::StmtNode* Jrd::Node::doDsqlPass<Jrd::StmtNode>(Jrd::DsqlCompilerScratch*, NestConst<Jrd::StmtNode>&) (src/dsql/Nodes.h:130)
Jrd::DsqlDmlStatement::dsqlPass(Jrd::thread_db*, Jrd::DsqlCompilerScratch*, unsigned int*) (src/dsql/DsqlStatements.cpp:145)
::prepareStatement(Jrd::thread_db *, Jrd::dsql_dbb *, Jrd::jrd_tra *, ULONG, const TEXT *, USHORT, unsigned int, bool, ntrace_result_t *) (src/dsql/dsql.cpp:619)
::prepareRequest(Jrd::thread_db *, Jrd::dsql_dbb *, Jrd::jrd_tra *, ULONG, const TEXT *, USHORT, unsigned int, bool) (src/dsql/dsql.cpp:454)
DSQL_prepare(Jrd::thread_db*, Jrd::Attachment*, Jrd::jrd_tra*, unsigned int, char const*, unsigned short, unsigned int, Firebird::Array<unsigned char, Firebird::EmptyStorage<unsigned char>>*, Firebird::Array<unsigned char, Firebird::EmptyStorage<unsigned char>>*, bool) (src/dsql/dsql.cpp:263)
Jrd::PreparedStatement::init(Jrd::thread_db*, Jrd::Attachment*, Jrd::jrd_tra*, Firebird::StringBase<Firebird::StringComparator> const&, bool) (src/jrd/PreparedStatement.cpp:429)
Jrd::PreparedStatement::PreparedStatement(Jrd::thread_db*, Firebird::MemoryPool&, Jrd::Attachment*, Jrd::jrd_tra*, Jrd::PreparedStatement::Builder const&, bool) (src/jrd/PreparedStatement.cpp:401)
Jrd::Attachment::prepareStatement(Jrd::thread_db*, Jrd::jrd_tra*, Jrd::PreparedStatement::Builder const&, Firebird::MemoryPool*) (src/jrd/Attachment.cpp:332)
Jrd::UserId::findGrantedRoles(Jrd::thread_db*) const (temp/Debug/jrd/scl.cpp:2270)
Jrd::UserId::locksmith(Jrd::thread_db*, unsigned int) const (src/jrd/scl.h:309)
Jrd::Attachment::locksmith(Jrd::thread_db*, Jrd::SystemPrivilege) const (src/jrd/Attachment.h:879)
::get_sys_privileges(Jrd::thread_db *) (temp/Debug/jrd/scl.cpp:2730)
::compute_access(Jrd::thread_db *, const Jrd::SecurityClass *, SLONG, const Jrd::MetaName &) (temp/Debug/jrd/scl.cpp:2772)
SCL_get_class(Jrd::thread_db*, char const*) (temp/Debug/jrd/scl.cpp:2103)
Jrd::UserId::sclInit(Jrd::thread_db*, bool) (temp/Debug/jrd/scl.cpp:2411)
Jrd::JProvider::internalAttach(Firebird::CheckStatusWrapper*, char const*, unsigned int, unsigned char const*, Jrd::UserId const*) (src/jrd/jrd.cpp:1976)
Jrd::JProvider::createDatabase(Firebird::CheckStatusWrapper*, char const*, unsigned int, unsigned char const*) (src/jrd/jrd.cpp:3039)
Firebird::IProviderBaseImpl<Jrd::JProvider, Firebird::CheckStatusWrapper, Firebird::IPluginBaseImpl<Jrd::JProvider, Firebird::CheckStatusWrapper, Firebird::Inherit<Firebird::IReferenceCountedImpl<Jrd::JProvider, Firebird::CheckStatusWrapper, Firebird::Inherit<Firebird::IVersionedImpl<Jrd::JProvider, Firebird::CheckStatusWrapper, Firebird::Inherit<Firebird::IProvider>>>>>>>::cloopcreateDatabaseDispatcher(Firebird::IProvider*, Firebird::IStatus*, char const*, unsigned int, unsigned char const*) (src/include/firebird/IdlFbInterfaces.h:12274)
Firebird::IAttachment* Firebird::IProvider::createDatabase<Firebird::CheckStatusWrapper>(Firebird::CheckStatusWrapper*, char const*, unsigned int, unsigned char const*) (src/include/firebird/IdlFbInterfaces.h:2923)
Why::Dispatcher::attachOrCreateDatabase(Firebird::CheckStatusWrapper*, bool, char const*, unsigned int, unsigned char const*) (src/yvalve/why.cpp:6464)
Why::Dispatcher::createDatabase(Firebird::CheckStatusWrapper*, char const*, unsigned int, unsigned char const*) (src/yvalve/why.cpp:6383)
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>>>>>>>::cloopcreateDatabaseDispatcher(Firebird::IProvider*, Firebird::IStatus*, char const*, unsigned int, unsigned char const*) (src/include/firebird/IdlFbInterfaces.h:12274)
Firebird::IAttachment* Firebird::IProvider::createDatabase<Firebird::CheckStatusWrapper>(Firebird::CheckStatusWrapper*, char const*, unsigned int, unsigned char const*) (src/include/firebird/IdlFbInterfaces.h:2923)
(anonymous namespace)::DatabaseAuth::accept(PACKET *, Auth::WriterImplementation *) const (src/remote/server/server.cpp:2529)
(anonymous namespace)::ServerAuth::authenticate(PACKET *, unsigned int) const (src/remote/server/server.cpp:622)
::attach_database(rem_port *, P_OP, P_ATCH *, PACKET *) (src/remote/server/server.cpp:2465)
::process_packet(rem_port *, PACKET *, PACKET *, rem_port **) (src/remote/server/server.cpp:5011)
::loopThread(void *) (src/remote/server/server.cpp:6748)
(anonymous namespace)::ThreadArgs::run() const (src/common/ThreadStart.cpp:78)
(anonymous namespace)::threadStart(void *) (src/common/ThreadStart.cpp:94)
start_thread (@start_thread:162)
__clone3 (@__clone3:20)

Moreover, if you remove the charset = utf8 option from the python program, both the release and debug builds work fine. I'm not sure if this is related to the original internal consistency check or not.

My system: Description: Ubuntu 22.04.4 LTS Release: 22.04 6.5.0-44-generic Tested on master and Firebird 5

Noremos avatar Jul 24 '24 08:07 Noremos

Here is a dump form the Debug virsion with consistency check: https://drive.google.com/file/d/1Gv9KYzSeVBNlkixLcWuL_aqi3zWKuJyI/view?usp=sharing

Noremos avatar Jul 24 '24 08:07 Noremos

Looks like the bugcheck happens due to using FLUSH_FINI in call to CCH_flush() from JProvider::createDatabase(). Could you try with FLUSH_ALL ? Also, it should be reproducible with SS only.

hvlad avatar Jul 28 '24 20:07 hvlad

Could you try with FLUSH_ALL ?

It seems to have helped. The bugcheck no longer occurs

Noremos avatar Jul 29 '24 06:07 Noremos