Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SIGSEGV in Firebird 5.0.0.1306 embedded during update on cursor #8185

Closed
FabianoBiagini opened this issue Jul 18, 2024 · 28 comments
Closed

SIGSEGV in Firebird 5.0.0.1306 embedded during update on cursor #8185

FabianoBiagini opened this issue Jul 18, 2024 · 28 comments

Comments

@FabianoBiagini
Copy link

The program was executing the following query:

update scheduler set 
  id_sched=gen_id(sched_gen,1),
  wndopen=current_timestamp,
  wndclose=current_timestamp+(cast(apertura as numeric(9,5))/1440.0),
  cache_vect=(select pv1.rif_vect from arcpervect pv1 where pv1.rif_per=scheduler.rif_per and pv1.idx_vect=1),
  lastresult=null
where current of SCHEDPEEK

Stack trace:

Program terminated with signal SIGSEGV, Segmentation fault.
#0  __memcpy_sse2_unaligned () at ../sysdeps/x86_64/multiarch/memcpy-sse2-unaligned.S:157
157     ../sysdeps/x86_64/multiarch/memcpy-sse2-unaligned.S: File o directory non esistente.
(gdb) bt
#0  __memcpy_sse2_unaligned () at ../sysdeps/x86_64/multiarch/memcpy-sse2-unaligned.S:157
#1  0x00007f6d4f705824 in MOVD_move(Jrd::thread_db*, dsc*, dsc*) () at /firebird/src/dsql/movd.cpp:40
#2  0x00007f6d4f6381e4 in Jrd::DsqlDmlRequest::mapInOut(Jrd::thread_db*, bool, Jrd::dsql_msg const*, Firebird::IMessageMetadata*, unsigned char*, unsigned char const*) () at /firebird/src/dsql/DsqlRequests.cpp:974
#3  0x00007f6d4f63a985 in Jrd::DsqlDmlRequest::execute(Jrd::thread_db*, Jrd::jrd_tra**, Firebird::IMessageMetadata*, unsigned char const*, Firebird::IMessageMetadata*, unsigned char*, bool) () at /firebird/src/dsql/DsqlRequests.cpp:723
#4  0x00007f6d4f6ecd9b in DSQL_execute_immediate(Jrd::thread_db*, Jrd::Attachment*, Jrd::jrd_tra**, unsigned int, char const*, unsigned short, Firebird::IMessageMetadata*, unsigned char const*, Firebird::IMessageMetadata*, unsigned char*, bool) () at /firebird/src/dsql/dsql.cpp:365
#5  0x00007f6d4f4fff02 in Jrd::JAttachment::execute(Firebird::CheckStatusWrapper*, Firebird::ITransaction*, unsigned int, char const*, unsigned int, Firebird::IMessageMetadata*, void*, Firebird::IMessageMetadata*, void*) () at /firebird/src/jrd/../jrd/jrd.h:810
#6  0x00007f6d4f51a4cf in Firebird::IAttachmentBaseImpl<Jrd::JAttachment, Firebird::CheckStatusWrapper, Firebird::IReferenceCountedImpl<Jrd::JAttachment, Firebird::CheckStatusWrapper, Firebird::Inherit<Firebird::IVersionedImpl<Jrd::JAttachment, Firebird::CheckStatusWrapper, Firebird::Inherit<Firebird::IAttachment> > > > >::cloopexecuteDispatcher (self=<optimized out>, status=0x7ffc5ad86388, transaction=0x7f6d52619248, stmtLength=0,
    sqlStmt=0x84ecb0 "update scheduler set id_sched=gen_id(sched_gen,1),wndopen=current_timestamp,wndclose=current_timestamp+(cast(apertura as numeric(9,5))/1440.0),  cache_vect=(select pv1.rif_vect from arcpervect pv1 whe"..., dialect=3, inMetadata=0x0, inBuffer=0x7ffc5ad863b8, outMetadata=0x0,
    outBuffer=0x0) at /firebird/src/include/firebird/IdlFbInterfaces.h:7545
#7  0x00007f6d52350fba in ?? () from /usr/lib/libfbembed.so.2.5
#8  0x00007f6d5236b16c in ?? () from /usr/lib/libfbembed.so.2.5
#9  0x00007f6d5236ff1d in isc_dsql_exec_immed2 () from /usr/lib/libfbembed.so.2.5
#10 0x00007f6d52370155 in isc_dsql_execute_immediate () from /usr/lib/libfbembed.so.2.5
#11 0x000000000053f2eb in TInterbaseConnection::ImmediateSQL (this=0x2370d70,
    sql=0x84ecb0 "update scheduler set id_sched=gen_id(sched_gen,1),wndopen=current_timestamp,wndclose=current_timestamp+(cast(apertura as numeric(9,5))/1440.0),  cache_vect=(select pv1.rif_vect from arcpervect pv1 whe"..., tr=0x7ffc5ad869b0) at common/gdb_ibase.cpp:269

Registers:

(gdb) info reg
rax            0xffff8092b52c6578       -140107383544456
rbx            0x7f6d4ad398c0   140107383544000
rcx            0x10     16
rdx            0x8      8
rsi            0x8      8
rdi            0x7f6d4ad39a88   140107383544456
rbp            0x7ffc5ad85c30   0x7ffc5ad85c30
rsp            0x7ffc5ad85be8   0x7ffc5ad85be8
r8             0x0      0
r9             0x202df  131807
r10            0x7ffc5ad85c90   140721832615056
r11            0x7ffc5ad85ca0   140721832615072
r12            0x7f6d4ad39530   140107383543088
r13            0x7f6d4ad39430   140107383542832
r14            0x7f6d4ad39a80   140107383544448
r15            0x7ffc5ad85fa8   140721832615848
rip            0x7f6d518558ed   0x7f6d518558ed <__memcpy_sse2_unaligned+493>
eflags         0x10202  [ IF RF ]
cs             0x33     51
ss             0x2b     43
ds             0x0      0
es             0x0      0
fs             0x0      0
gs             0x0      0

Shared library:

(gdb) info sharedlibrary
From                To                  Syms Read   Shared Object Library
                                        No          linux-vdso.so.1
0x00007f6d522efa70  0x00007f6d524be7a1  Yes (*)     /usr/lib/libfbembed.so.2.5
0x00007f6d52091220  0x00007f6d520a2469  Yes (*)     /lib/x86_64-linux-gnu/libz.so.1
0x00007f6d51ddf8b0  0x00007f6d51e47b1f  Yes (*)     /usr/lib/x86_64-linux-gnu/libstdc++.so.6
0x00007f6d51b70ab0  0x00007f6d51b809a5  Yes (*)     /lib/x86_64-linux-gnu/libgcc_s.so.1
0x00007f6d517e44a0  0x00007f6d5190e6a3  Yes         /lib/x86_64-linux-gnu/libc.so.6
0x00007f6d515bf350  0x00007f6d515c206c  Yes         /lib/x86_64-linux-gnu/librt.so.1
0x00007f6d513b9ed0  0x00007f6d513ba97e  Yes         /lib/x86_64-linux-gnu/libdl.so.2
0x00007f6d510bd580  0x00007f6d51128d96  Yes         /lib/x86_64-linux-gnu/libm.so.6
0x00007f6d50ea09f0  0x00007f6d50eac731  Yes         /lib/x86_64-linux-gnu/libpthread.so.0
0x00007f6d50c86d20  0x00007f6d50c9784f  Yes (*)     /usr/lib/../lib/libtommath.so.1
0x00007f6d52592ae0  0x00007f6d525ab170  Yes         /lib64/ld-linux-x86-64.so.2
0x00007f6d4f2cca20  0x00007f6d4f98b931  Yes         /opt/firebird/plugins/libEngine13.so
0x00007f6d526f5e90  0x00007f6d52731f57  Yes (*)     /opt/firebird/plugins/../lib/libtomcrypt.so.1
0x00007f6d526b7060  0x00007f6d526b7177  Yes (*)     /opt/firebird/lib/libib_util.so
0x00007f6d4f0c7d00  0x00007f6d4f174161  Yes (*)     /opt/firebird/intl/fbintl
0x00007f6d4ed7f6f0  0x00007f6d4ee33818  Yes (*)     /usr/lib/x86_64-linux-gnu/libicuuc.so.52.1
0x00007f6d4d4c0570  0x00007f6d4d4c0670  Yes (*)     /usr/lib/x86_64-linux-gnu/libicudata.so.52
0x00007f6d4d148770  0x00007f6d4d25ba15  Yes (*)     /usr/lib/x86_64-linux-gnu/libicui18n.so.52.1
0x00007f6d4cea73b0  0x00007f6d4ceabb4e  Yes         /lib/x86_64-linux-gnu/libnss_compat.so.2
0x00007f6d4cc92160  0x00007f6d4cc9d693  Yes         /lib/x86_64-linux-gnu/libnsl.so.1
0x00007f6d4ca851a0  0x00007f6d4ca8b1bc  Yes         /lib/x86_64-linux-gnu/libnss_nis.so.2
0x00007f6d4c8792a0  0x00007f6d4c87f803  Yes         /lib/x86_64-linux-gnu/libnss_files.so.2
0x00007f6d4c6aff50  0x00007f6d4c7ebf81  Yes (*)     /opt/firebird/plugins/libfbtrace.so
(*): Shared library is missing debugging information.

/usr/lib/libfbembed.so.2.5 is a link to /opt/firebird/lib/libfbclient.so for compatibility reasons.

/opt/firebird/firebird.conf:

ServerMode = Classic
RelaxedAliasChecking=1

I hope this can help.

@AlexPeshkoff
Copy link
Member

Can you also provide xz-compressed core dump?

@FabianoBiagini
Copy link
Author

The core dump contains too many personal information of customers, but I can reproduce the problem with an anonymized version of the DB and send you the new core dump, maybe tomorrow

@aafemt
Copy link
Contributor

aafemt commented Jul 18, 2024

Could you show us query that defines cursor SCHEDPEEK?

@FabianoBiagini
Copy link
Author

Of course

select rif_per,rif_class,flags,giorni,apertura,loop 
from scheduler s 
where (s.alle=? and (s.giorni is null or s.giorni containing ? or s.giorni containing '8')) 
 and (s.wndclose is null or s.wndclose<current_timestamp) 
for update of id_sched,cache_vect,wndopen,wndclose,lastresult

@aafemt
Copy link
Contributor

aafemt commented Jul 19, 2024

Is it opened as an unidirectional or scrollable cursor?

@FabianoBiagini
Copy link
Author

Unidirectional, the code is written for Firebird 2.5

@FabianoBiagini
Copy link
Author

Here we go!
I have reproduced the problem with an almost empty DB, so I can send you the cordeump.

(gdb) bt
#0  __memcpy_sse2_unaligned () at ../sysdeps/x86_64/multiarch/memcpy-sse2-unaligned.S:157
#1  0x00007fe3be747824 in MOVD_move(Jrd::thread_db*, dsc*, dsc*) () at /firebird/src/dsql/movd.cpp:40
#2  0x00007fe3be67a1e4 in Jrd::DsqlDmlRequest::mapInOut(Jrd::thread_db*, bool, Jrd::dsql_msg const*, Firebird::IMessageMetadata*, unsigned char*, unsigned char const*)
    () at /firebird/src/dsql/DsqlRequests.cpp:974
#3  0x00007fe3be67c985 in Jrd::DsqlDmlRequest::execute(Jrd::thread_db*, Jrd::jrd_tra**, Firebird::IMessageMetadata*, unsigned char const*, Firebird::IMessageMetadata*, unsigned char*, bool) () at /firebird/src/dsql/DsqlRequests.cpp:723
#4  0x00007fe3be72ed9b in DSQL_execute_immediate(Jrd::thread_db*, Jrd::Attachment*, Jrd::jrd_tra**, unsigned int, char const*, unsigned short, Firebird::IMessageMetadata*, unsigned char const*, Firebird::IMessageMetadata*, unsigned char*, bool) () at /firebird/src/dsql/dsql.cpp:365
#5  0x00007fe3be541f02 in Jrd::JAttachment::execute(Firebird::CheckStatusWrapper*, Firebird::ITransaction*, unsigned int, char const*, unsigned int, Firebird::IMessageMetadata*, void*, Firebird::IMessageMetadata*, void*) () at /firebird/src/jrd/../jrd/jrd.h:810
#6  0x00007fe3be55c4cf in Firebird::IAttachmentBaseImpl<Jrd::JAttachment, Firebird::CheckStatusWrapper, Firebird::IReferenceCountedImpl<Jrd::JAttachment, Firebird::CheckStatusWrapper, Firebird::Inherit<Firebird::IVersionedImpl<Jrd::JAttachment, Firebird::CheckStatusWrapper, Firebird::Inherit<Firebird::IAttachment> > > > >::cloopexecuteDispatcher (self=<optimized out>, status=0x7ffc3f8719c8, transaction=0x7fe3c165b228, stmtLength=0,
    sqlStmt=0x84ecb0 "update scheduler set id_sched=gen_id(sched_gen,1),wndopen=current_timestamp,wndclose=current_timestamp+(cast(apertura as numeric(9,5))/1440.0),  cache_vect=(select pv1.rif_vect from arcpervect pv1 whe"..., dialect=3, inMetadata=0x0, inBuffer=0x7ffc3f8719f8, outMetadata=0x0, outBuffer=0x0)
    at /firebird/src/include/firebird/IdlFbInterfaces.h:7545
#7  0x00007fe3c1392fba in ?? () from /usr/lib/libfbembed.so.2.5
#8  0x00007fe3c13ad16c in ?? () from /usr/lib/libfbembed.so.2.5
#9  0x00007fe3c13b1f1d in isc_dsql_exec_immed2 () from /usr/lib/libfbembed.so.2.5
#10 0x00007fe3c13b2155 in isc_dsql_execute_immediate () from /usr/lib/libfbembed.so.2.5
#11 0x000000000053f2eb in TInterbaseConnection::ImmediateSQL (this=0x12a2d70,
    sql=0x84ecb0 "update scheduler set id_sched=gen_id(sched_gen,1),wndopen=current_timestamp,wndclose=current_timestamp+(cast(apertura as numeric(9,5))/1440.0),  cache_vect=(select pv1.rif_vect from arcpervect pv1 whe"..., tr=0x7ffc3f871ff0) at common/gdb_ibase.cpp:269
(gdb) info sharedlibrary
From                To                  Syms Read   Shared Object Library
                                        No          linux-vdso.so.1
0x00007fe3c1331a70  0x00007fe3c15007a1  Yes (*)     /usr/lib/libfbembed.so.2.5
0x00007fe3c10d3220  0x00007fe3c10e4469  Yes (*)     /lib/x86_64-linux-gnu/libz.so.1
0x00007fe3c0e218b0  0x00007fe3c0e89b1f  Yes (*)     /usr/lib/x86_64-linux-gnu/libstdc++.so.6
0x00007fe3c0bb2ab0  0x00007fe3c0bc29a5  Yes (*)     /lib/x86_64-linux-gnu/libgcc_s.so.1
0x00007fe3c08264a0  0x00007fe3c09506a3  Yes         /lib/x86_64-linux-gnu/libc.so.6
0x00007fe3c0601350  0x00007fe3c060406c  Yes         /lib/x86_64-linux-gnu/librt.so.1
0x00007fe3c03fbed0  0x00007fe3c03fc97e  Yes         /lib/x86_64-linux-gnu/libdl.so.2
0x00007fe3c00ff580  0x00007fe3c016ad96  Yes         /lib/x86_64-linux-gnu/libm.so.6
0x00007fe3bfee29f0  0x00007fe3bfeee731  Yes         /lib/x86_64-linux-gnu/libpthread.so.0
0x00007fe3bfcc8d20  0x00007fe3bfcd984f  Yes (*)     /usr/lib/../lib/libtommath.so.1
0x00007fe3c15d4ae0  0x00007fe3c15ed170  Yes         /lib64/ld-linux-x86-64.so.2
0x00007fe3be30ea20  0x00007fe3be9cd931  Yes         /opt/firebird/plugins/libEngine13.so
0x00007fe3c1737e90  0x00007fe3c1773f57  Yes (*)     /opt/firebird/plugins/../lib/libtomcrypt.so.1
0x00007fe3c16f9060  0x00007fe3c16f9177  Yes (*)     /opt/firebird/lib/libib_util.so
0x00007fe3be109d00  0x00007fe3be1b6161  Yes (*)     /opt/firebird/intl/fbintl
0x00007fe3bddc16f0  0x00007fe3bde75818  Yes (*)     /usr/lib/x86_64-linux-gnu/libicuuc.so.52.1
0x00007fe3bc502570  0x00007fe3bc502670  Yes (*)     /usr/lib/x86_64-linux-gnu/libicudata.so.52
0x00007fe3bc18a770  0x00007fe3bc29da15  Yes (*)     /usr/lib/x86_64-linux-gnu/libicui18n.so.52.1
0x00007fe3bbee93b0  0x00007fe3bbeedb4e  Yes         /lib/x86_64-linux-gnu/libnss_compat.so.2
0x00007fe3bbcd4160  0x00007fe3bbcdf693  Yes         /lib/x86_64-linux-gnu/libnsl.so.1
0x00007fe3bbac71a0  0x00007fe3bbacd1bc  Yes         /lib/x86_64-linux-gnu/libnss_nis.so.2
0x00007fe3bb8bb2a0  0x00007fe3bb8c1803  Yes         /lib/x86_64-linux-gnu/libnss_files.so.2
0x00007fe3bb6f1f50  0x00007fe3bb82df81  Yes (*)     /opt/firebird/plugins/libfbtrace.so
(gdb) info reg
rax            0xffff801c46a727a8       -140616043911256
rbx            0x7fe3b958d6c0   140616043910848
rcx            0x10     16
rdx            0x8      8
rsi            0x8      8
rdi            0x7fe3b958d858   140616043911256
rbp            0x7ffc3f871270   0x7ffc3f871270
rsp            0x7ffc3f871228   0x7ffc3f871228
r8             0x0      0
r9             0x202df  131807
r10            0x7ffc3f8712d0   140721374302928
r11            0x7ffc3f8712e0   140721374302944
r12            0x7fe3b958d330   140616043909936
r13            0x7fe3b958d230   140616043909680
r14            0x7fe3b958d850   140616043911248
r15            0x7ffc3f8715e8   140721374303720
rip            0x7fe3c08978ed   0x7fe3c08978ed <__memcpy_sse2_unaligned+493>
eflags         0x10202  [ IF RF ]
cs             0x33     51
ss             0x2b     43
ds             0x0      0
es             0x0      0
fs             0x0      0
gs             0x0      0

core.6617.gz

@FabianoBiagini
Copy link
Author

FabianoBiagini commented Jul 19, 2024

I forgot some possibly useful information:

  • the "select ... for update" run every minute,
  • the first minute it finds a record, process with "update ... where current of ..." and everything ok! no SIGSEGV
  • the second minute: "select ... for update" restart, find another record and process it also with "update ... where current of ...",
  • now it trigger the SIGSEGV

The code runs well with Firebird 2.5 and 3.0.

@dyemanov
Copy link
Member

It seems I'm able to reproduce it. Working on it.

@aafemt
Copy link
Contributor

aafemt commented Jul 20, 2024

The code runs well with Firebird 2.5 and 3.0.

Try to set MaxStatementCacheSize to zero.

@FabianoBiagini
Copy link
Author

Try to set MaxStatementCacheSize to zero.

You are right, the bug is evidently related to the statement cache. Putting the cache size to zero make the SIGSEGV disappear, but also disappear performance gaining, the main reason for me to adopt FB 5.0

@aafemt
Copy link
Contributor

aafemt commented Jul 22, 2024

Do you mean performance of this particular query or performance of your application as whole? I can't believe that preparation of this "update" can be slow.

@FabianoBiagini
Copy link
Author

Do you mean performance of this particular query or performance of your application as whole? I can't believe that preparation of this "update" can be slow.

I mean performance as measured by my personal benchmark with prepared and unprepared query loop. I can't say that preparation of this specific "update" is slow.

@aafemt
Copy link
Contributor

aafemt commented Jul 22, 2024

In this case I think that the simplest fix would be to disable caching of positional DML statements.

@dyemanov
Copy link
Member

I've already implemented this, but honestly expected to do something more clever.

@aafemt
Copy link
Contributor

aafemt commented Jul 22, 2024

Alternatives could be "partial release/prepare" mechanic which is too big work for v5 or parent statement lookup on each execution which may be not good for performance.

@asfernandes
Copy link
Member

I forgot some possibly useful information:

  • the "select ... for update" run every minute,
  • the first minute it finds a record, process with "update ... where current of ..." and everything ok! no SIGSEGV
  • the second minute: "select ... for update" restart, find another record and process it also with "update ... where current of ...",
  • now it trigger the SIGSEGV

The code runs well with Firebird 2.5 and 3.0.

Is this dependent on table and query structure?
Is this "every minute" time related really or execution count related? Or just random?

I've tried simple table with many executions and not reproduced it.

@asfernandes
Copy link
Member

In my tests, I'm having error invalid request handle. But I imagine, if many more statements run, that orphan statement may go out of cache and crash happens.

@aafemt
Copy link
Contributor

aafemt commented Jul 22, 2024

The worse is the case when there are two parent statements in the cache and by chance DML statement is used referring to the wrong SELECT statement.

@asfernandes
Copy link
Member

The worse is the case when there are two parent statements in the cache and by chance DML statement is used referring to the wrong SELECT statement.

Cursor names are attached to dsql requests. What is cached is dsql statements.

@aafemt
Copy link
Contributor

aafemt commented Jul 22, 2024

Right. But still actual problem is that parentRequest, parentDbKey and parentRecVersion are members of DsqlStatement.

@asfernandes
Copy link
Member

@dyemanov let me know if you are actively working on a fix or want that I look at it.

@FabianoBiagini
Copy link
Author

I've just made two tests.

Is this "every minute" time related really or execution count related? Or just random?

I removed the time gap and forced the scheduler to run for "10:00" and then for "10:01" without any delay between the calls, the SIGSEGV appeared in the same way. So the one minute delay is not involved.

In my tests, I'm having error invalid request handle.

This happen to me too if I try to rewrite the code in attempt to reproduce the bug in a simpler situation.
So, using the same "select .. for update" and the same "update ... where current of" in a simplified piece of code I obtain only the invalid request handle and no more the SIGSEGV. Please note that in the production scenario there are other concurrent processes that could be accessing the same DB.

@aafemt
Copy link
Contributor

aafemt commented Jul 23, 2024

honestly expected to do something more clever.

I'll have to solve it anyway in #8145 so you don't need to spend much of your time to find something more clever.

@pavel-zotov
Copy link

QA note.
Could not reproduce using script from attached .sql
gh-8185.sql.zip

@aafemt
Copy link
Contributor

aafemt commented Jul 29, 2024

@pavel-zotov PSQL cursors and DSQL cursors are completely different beasts. This problem cannot happen with PSQL cursors which you are trying to use.

@aafemt
Copy link
Contributor

aafemt commented Jul 30, 2024

@pavel-zotov Steps to reproduce should be like this:

  1. Prepare statement 1 "select ... for update"
  2. Set cursor name for statement 1
  3. Prepare statement 2 "update ... where current of <cursor name from step 2>"
  4. Prepare statement 3 similar to statement 1
  5. Release statement 1
  6. Release statement 2
  7. Set cursor name to statement 3 as in step 2
  8. Prepare statement 2 again (it will be got from cache keeping reference to statement 1)
  9. Run statement 3 and fetch one record
  10. Execute statement 2

At step 10 you can get "Invalid handle" error or a crash if you swap steps 5 and 6.
ISQL cannot perform steps 2 and 9 but I believe Python program can.

@pavel-zotov
Copy link

::: QA NOTE :::
Test has been implemented and uses steps described above by aafemt.
Checked on snapshots 5.0.1.1452-08dc25f (27.07.2024 11:50) and 6.0.0.401-a7d10a4 (29.07.2024 01:33) -- all OK.
Current FB 6.x also works fine.
But it is not so for fresh FB 5.x: it fails since 2024-10-23, commit: c84d945

dyemanov pushed a commit that referenced this issue Nov 16, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment