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

AV. Problem in MET_procedure [CORE4239] #4563

Closed
firebird-automations opened this issue Sep 27, 2013 · 8 comments
Closed

AV. Problem in MET_procedure [CORE4239] #4563

firebird-automations opened this issue Sep 27, 2013 · 8 comments

Comments

@firebird-automations
Copy link
Collaborator

Submitted by: @ibprovider

I executed my old tests (in four threads) and get the (think, reproducible) AV in Firebird's engine:

Необработанное исключение в "0x0000000140256da2" в "fb_inet_server.exe": 0xC0000005: Нарушение прав доступа при записи "0x0000000000000000".

----------
[27.09.2013 08:54:24] [ExecuteTests] CommandLine:

target\ibp_oledb_test_vc10_x64_Release.exe /thread_count 4 /log_dir ..\_log /log_file_prefix w64_local_d3 /cn_str "provider=LCPI.IBProvider.3;location=d:\database\ibp_test_fb25_d3.gdb;user id=gamer;password=vermut;ctype=win1251;icu_library=icuuc30.dll" /test schema*

[27.09.2013 08:54:24] [ExecuteTests] Test Mask : [schema*]

[27.09.2013 08:54:24] [info] Provider DLL :_IBProvider_v3_vc10_w64_i.dll
[27.09.2013 08:54:24] [info] Provider Version:3.16.4.15390
[27.09.2013 08:54:24] [info] Server Name :Firebird x64 [SuperClassic]. Release build [VS2010]
[27.09.2013 08:54:24] [info] Server Version :2.5.3.26640
[27.09.2013 08:54:24] [info] Client Name :Firebird SQL Server
[27.09.2013 08:54:24] [info] Client Version :2.5.3.26640
[27.09.2013 08:54:24] [info] Database ODS :11.2
[27.09.2013 08:54:24] [info] Database Dialect:3

---------------- [problem FB-thread stack]

[SRC]
Parameter* parameter = *ptr;
// check for parameter to be null, this can only happen if the
// parameter numbers get out of sync. This was added to fix bug
// 10534. -Shaunak Mistry 12-May-99
if (parameter)
{
*desc = parameter->prm_desc; //<---------------- HERE
length = MET_align(dbb, &(*desc), length);
desc->dsc_address = (UCHAR *) (IPTR) length;
length += desc->dsc_length;
}

[ASM]
if (parameter)
0000000140256D99 test rcx,rcx
0000000140256D9C je 0000000140256DF1
{
*desc = parameter->prm_desc;
0000000140256D9E mov rax,qword ptr [rcx+8]
0000000140256DA2 mov qword ptr [r8],rax //<------------ HERE

[STACK]
> fb_inet_server.exe!MET_procedure(Jrd::thread_db * tdbb=0x305f504d545f5053, int id=67718520, bool noscan=true, unsigned short flags=61472) Строка 5067 + 0x4 байт C++
fb_inet_server.exe!MET_lookup_procedure(Jrd::thread_db * tdbb=0x00000000053af020, const Firebird::MetaName & name={...}, bool noscan=false) Строка 3979 + 0x14 байт C++
fb_inet_server.exe!create_procedure(Jrd::thread_db * tdbb=0x000000000c99b608, short phase=-27224, Jrd::DeferredWork * work=0x000000000f2f3368, Jrd::jrd_tra * transaction=0x0000000000000001) Строка 3468 C++
fb_inet_server.exe!DFW_perform_work(Jrd::thread_db * tdbb=0x000000000c99b608, Jrd::jrd_tra * transaction=0x0000000000000000) Строка 1174 + 0x11 байт C++
fb_inet_server.exe!TRA_commit(Jrd::thread_db * tdbb=0x000000000f2f3368, Jrd::jrd_tra * transaction=0x0000000000000000, const bool retaining_flag=true) Строка 444 C++
fb_inet_server.exe!commit(Jrd::thread_db * tdbb=0x00000000053af270, Jrd::jrd_tra * transaction=0x00000000053af9b0, const bool retaining_flag=true) Строка 4539 + 0xf байт C++
fb_inet_server.exe!jrd8_commit_transaction(__int64 * user_status=0x000000000eed4720, Jrd::jrd_tra * * tra_handle=0x000000000efc0198) Строка 1744 + 0x13 байт C++
fb_inet_server.exe!isc_commit_transaction(__int64 * user_status=0x000000000eed4720, unsigned int * tra_handle=0x0000000007178910) Строка 1749 + 0x34 байт C++
fb_inet_server.exe!rem_port::end_transaction(P_OP operation=118982928, p_rlse * release=0x0000000007178910, packet * sendL=0x0000000007178910) Строка 2086 C++
fb_inet_server.exe!process_packet(rem_port * port=0x0000000000db0020, packet * sendL=0x0000000007178910, packet * receive=0x0000000000dba7a8, rem_port * * result=0x0000000000000038) Строка 3419 C++
fb_inet_server.exe!SRVR_main(rem_port * main_port=0x00000000043a6f00, unsigned short flags=0) Строка 402 + 0x1a байт C++
fb_inet_server.exe!process_connection_thread(void * arg=0x00000000043a6f10) Строка 348 + 0x14 байт C++
fb_inet_server.exe!`anonymous namespace'::threadStart(void * arg=0x0000000000000000) Строка 139 + 0x5 байт C++

---------------- [problem FB-thread local vars]
+ tdbb 0x305f504d545f5053 {tdbb_default=??? database=??? attachment=??? ...} Jrd::thread_db *
id 67718520 int
noscan true bool
flags 61472 unsigned short
+ jrd_160 {jrd_161=0x00000000053aeb20 "IN4 " jrd_162=0x00000000053aeb40 "SP_TMP_007_32096 " } MET_procedure::__l2::<unnamed-type-jrd_160>
+ jrd_151 {jrd_152=0 } MET_procedure::__l2::<unnamed-type-jrd_151>
+ procedure 0x0000000004022060 {prc_id=677 prc_flags=8 prc_inputs=4 ...} Jrd::jrd_prc *
+ jrd_190 {jrd_191={...} jrd_192=0x00000000053aea08 "SQL$32855 " jrd_193=0x00000000053aea28 "SP_TMP_007_32096 " ...} MET_procedure::__l2::<unnamed-type-jrd_190>
+ jrd_170 {jrd_171=0x00000000053aeb00 "SP_TMP_007_32096 " } MET_procedure::__l2::<unnamed-type-jrd_170>
+ dbb 0x0000000002c2de10 {dbb_sync={...} dbb_lock_mgr=0x0000000000dbeb58 dbb_event_mgr=0x0000000000000000 ...} Jrd::Database *
+ jrd_153 {jrd_154={...} jrd_155=27680 jrd_156=1486 ...} MET_procedure::__l2::<unnamed-type-jrd_153>
+ jrd_188 {jrd_189=677 } MET_procedure::__l2::<unnamed-type-jrd_188>
+ jrd_172 {jrd_173={...} jrd_174=0x00000000053aea88 "RDB$126807 " jrd_175=0x00000000053aeaa8 "IN4 " ...} MET_procedure::__l2::<unnamed-type-jrd_172>
+ jrd_163 {jrd_164={...} jrd_165=0 jrd_166=-1 ...} MET_procedure::__l2::<unnamed-type-jrd_163>
+ guard {mutex={...} } Jrd::Database::CheckoutLockGuard
+ csb_pool 0x0000000004094d78 {parent_redirect=true freeBlocks={...} extents_os=0x0000000000001770 ...} Firebird::MemoryPool *
+ pa_default_value {bid_internal={...} bid_quad={...} } Jrd::bid
+ pool 0x0000000004095928 {parent_redirect=true freeBlocks={...} extents_os=0x0000000004095fe0 ...} Firebird::MemoryPool *
+ context {savedThreadData=0x0000000000000000 savedPool=0x000000000c99b608 } Firebird::SubsystemContextPoolHolderJrd::thread\_db,Firebird::MemoryPool\
+ csb {ptr=0x0000000004094d78 } Firebird::AutoPtr<Jrd::CompilerScratch,Firebird::SimpleDeleteJrd::CompilerScratch\ >
+ context {savedThreadData=0x00000000053af020 savedPool=0x0000000000000000 } Firebird::SubsystemContextPoolHolderJrd::thread\_db,Firebird::MemoryPool\
+ csb {ptr=0x0000000004095928 } Firebird::AutoPtr<Jrd::CompilerScratch,Firebird::SimpleDeleteJrd::CompilerScratch\ >

Unfortunately, because I used "release" Firebird's binaries, I have the problem with the exact information about all local variables.

------------ [IBProvider test thread]
[THR:006088] [27.09.2013 11:05:19] [test] Prepare Command:

"CREATE PROCEDURE SP_TMP_007_32096
(IN1 VARCHAR(31) CHARACTER SET UNICODE_FSS,
IN2 BLOB SUB_TYPE 1 SEGMENT SIZE 256,
IN3 SMALLINT,
IN4 BLOB SUB_TYPE 0 SEGMENT SIZE 256)
AS
DECLARE VARIABLE X INTEGER;
BEGIN
X=0;
END"

[THR:006088] [27.09.2013 11:05:19] [test] EXECUTE COMMAND (or=true,rpi=true) [NO PARAMS] ...
[THR:006088] [27.09.2013 11:05:19] [test] COMMIT TRANSACTION [RETAINING=false]...
<AV in FB engine>

@firebird-automations
Copy link
Collaborator Author

Commented by: @asfernandes

Is multiple threads required to crash?

Does the crash happens in every run?

@firebird-automations
Copy link
Collaborator Author

Commented by: @ibprovider

>Is multiple threads required to crash?

I think, yes.

Rules:
- Only one DDL statement execute in each time (isc_dsql_execute for DDL). It not lock the other operations (start_tr, commit_tr, prepare_stmt, execute_stmt for DML ...)
- Other operations (start_tr, commit_tr, prepare_stmt ...) can be performed in parallel

Each thread uses own connection (local protocol).

>Does the crash happens in every run?

I ran this set of tests twice. And twice got the AV (within 2 hours after start) in more or less equal situations. I have the logs in both cases.

[------------------ TEST_THREAD1]

This thread reads the system tables. No any DDL.

[THR:003668] [27.09.2013 09:04:52] [read_schema] Fetch schema data [Test Restrictions]
<resume execution of FB>
[THR:003668] [27.09.2013 14:50:52] ERROR: [read_schema] Schema DBSCHEMA_COLUMN_PRIVILEGES [{C8B52221-5CF3-11CE-ADE5-00AA0044773D}]
Open schema {C8B52221-5CF3-11CE-ADE5-00AA0044773D}
1. [LCPI.IBProvider.3]: Cursor fetch row failed.

Error reading data from the connection.

[------------------ TEST_THREAD2]
[THR:006088] [27.09.2013 11:05:19] [test] Prepare Command:

"CREATE PROCEDURE SP_TMP_007_32096
(IN1 VARCHAR(31) CHARACTER SET UNICODE_FSS,
IN2 BLOB SUB_TYPE 1 SEGMENT SIZE 256,
IN3 SMALLINT,
IN4 BLOB SUB_TYPE 0 SEGMENT SIZE 256)
AS
DECLARE VARIABLE X INTEGER;
BEGIN
X=0;
END"

[THR:006088] [27.09.2013 11:05:19] [test] EXECUTE COMMAND (or=true,rpi=true) [NO PARAMS] ...
[THR:006088] [27.09.2013 11:05:19] [test] COMMIT TRANSACTION [RETAINING=false]... <----------- STOP FB IN DEBUGER
<resume execution of FB>
[THR:006088] [27.09.2013 14:50:52] ERROR: [schema|schema.007.sp_text.03.IN_4.sp_3711] Commit transaction
1. [LCPI.IBProvider.3]: Transaction commit failed. Transaction will be aborted.

connection lost to database

[------------------ TEST_THREAD3]
[THR:005932] [27.09.2013 11:05:19] [test] START TRANSACTION ...
<resume execution of FB>
[THR:005932] [27.09.2013 14:50:52] [test] GENERATE ID [GEN_ID_DDL]. Count:1...
[THR:005932] [27.09.2013 14:50:52] ERROR: [schema|schema.007.sp_text.03.IN_4.sp_3712] Fetching of rows
1. [LCPI.IBProvider.3]: Cursor fetch row failed.

Error reading data from the connection.

[------------------ TEST_THREAD4]
[THR:005864] [27.09.2013 11:05:19] [test] Create command ...
[THR:005864] [27.09.2013 11:05:19] [test] START TRANSACTION ...
<resume execution of FB>
[THR:005864] [27.09.2013 14:50:52] [test] GENERATE ID [GEN_ID_DDL]. Count:1...
[THR:005864] [27.09.2013 14:50:52] ERROR: [schema|schema.007.sp_text.03.IN_4.sp_3713] Fetching of rows
1. [LCPI.IBProvider.3]: Cursor fetch row failed.

Error reading data from the connection.

------------------
At current time, I try to reproduce this problem with debug build of FB.

@firebird-automations
Copy link
Collaborator Author

Commented by: @ibprovider

With debug build I cannot reproduce this problem :(

But with release build (include build from latest source of FB) - no problem.

http://www.ibprovider.com/download/fb/2013_09_28__fb_crash__001.7z [30MB]

@firebird-automations
Copy link
Collaborator Author

Commented by: @hvlad

The issue is related to procedure SP_TMP_007_8.
Could you tell us if this procedure created once or it was recreated or altered ?
Could you show us all DDL statements with this procedure ?

@firebird-automations
Copy link
Collaborator Author

Commented by: @ibprovider

>Could you tell us if this procedure created once or it was recreated or altered ?

All procedures were created and deleted at test time.

No "recreate" or "alter" operations.

Only "create" and "drop" operations.

Each test:
0. Create connection
1. Start Transaction1. Creates Test Stored Procedure. Commit.
2. Start Transaction2. Reads information from RDB$PROCEDURES, RDB$PROCEDURE_PARAMETERS for this Test Stored Procedure. Commit.
3. Start Transaction3. Deletes this Test Stored Procedure. Commit.

At each time works 8 test threads.

>Could you show us all DDL statements with this procedure ?

1. CREATE PROCEDURE ...;
2. DROP PROCEDURE ...;

@firebird-automations
Copy link
Collaborator Author

Commented by: @AlexPeshkoff

The bug was finally reproduced by IbPhoenix & GLDS. The reason was very bad code working with vectors of procedure parameters. That was fixed be Adriano in FB3 initial but was not backprted to 2.5. Due to finished lifecycle of 2.5 and missing of complete fix in 2.5.9 I mark bug as fixed only in FB 3 & 4.

@firebird-automations
Copy link
Collaborator Author

Modified by: @AlexPeshkoff

status: Open [ 1 ] => Resolved [ 5 ]

resolution: Fixed [ 1 ]

Fix Version: 4.0 Alpha 1 [ 10731 ]

Fix Version: 3.0.0 [ 10740 ]

@firebird-automations
Copy link
Collaborator Author

Commented by: @ibprovider

Wow, thanks :)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

1 participant