Subject | IBOQuery.open Crashes IBServer on 27th open |
---|---|
Author | danialwidner |
Post date | 2002-06-19T23:16:36Z |
Jason,
I have a situation where many many opens and closes of about 70
queries goes along just fine. Then on the 27th pass (we changed the
client at this location and it got nailed on the new #27) it crashes
the interbase server (6.5). Each client can be processed one at a
time with no problem. The query runs fine in the console for that
and all the other clients. Data problem unlikely.
We have been looking all day at the server and the database to solve
the problem of the crashes that started today. Getting a new copy of
the database from a (several dating back weeks) backup and testing
locally (End users were getting tired of the server crashing in the
middle of their work) we were getting the "Lost connection to server
message" that the clients were getting. The IB log shows the server
crashed and restarted.
We stepped through the code and found it was crashing on one
particular query. I put a trace around that close and open sequence
(
frmETS.IB_Monitor1.Enabled := True;
qryPaymentReturns.Close;
qryPaymentReturns.ParamByName('ClientID').AsString :=
qryClientClient_ID.Value;
qryPaymentReturns.ParamByName('FromDate').AsDate := FromDate;
qryPaymentReturns.ParamByName('ToDate').AsDate := ToDate;
qryPaymentReturns.Open;
qryPaymentReturns.First;
frmETS.IB_Monitor1.Enabled := False;
)
and got the following (cut to just the 26th and 27th pass for
comparison):
/*===
[ 6/19/2002 6:18:35 PM ]
PROFILE DIFF REPORT -- Before execute
*** OVERALL SERVER PROCESS ***
Current Memory = 44,273,224 (-525,420)
Num Buffer Reads = 4,382,001 (+6,863)
Num Buffer Writes = 1,986 (+42)
Num Page Reads = 3,390 (+2)
Num Page Writes = 1,205 (+36)
*** SEQUENTIAL (NON-INDEXED) READS *** 2,740
1,240 RELATION_ID=138
1,500 RELATION_ID=272
*** INDEXED READS *** 275
100 RELATION_ID=178
19 RELATION_ID=138
10 RELATION_ID=140
19 RELATION_ID=152
21 RELATION_ID=157
16 RELATION_ID=162
15 RELATION_ID=170
13 RELATION_ID=181
51 RELATION_ID=301
5 RELATION_ID=139
1 RELATION_ID=155
3 RELATION_ID=166
1 RELATION_ID=302
1 RELATION_ID=312
*** INSERT COUNT *** 6
1 RELATION_ID=210
5 RELATION_ID=211
*** UPDATE COUNT *** 6
1 RELATION_ID=166
5 RELATION_ID=170
PROFILE DATA MARKED AS START
====*/
/*---
[ 6/19/2002 6:18:35 PM ]
EXECUTE STATEMENT
TR_HANDLE = 37645768
STMT_HANDLE = 37642836
PARAMS = [ Version 1 SQLd 3 SQLn 3
[CLIENTID] = '384 '
[FROMDATE] = '01 Apr 2002'
[TODATE] = '30 Jun 2002' ]
SECONDS = 0.625
----*/
/*---
[ 6/19/2002 6:18:36 PM ]
DATABASE INFO
DB_HANDLE = 37645860
----*/
/*===
[ 6/19/2002 6:18:36 PM ]
PROFILE DIFF REPORT -- After execute
*** OVERALL SERVER PROCESS ***
Current Memory = 44,798,611 (+525,387)
Num Buffer Reads = 4,431,657 (+49,656)
Num Page Reads = 3,405 (+15)
*** SEQUENTIAL (NON-INDEXED) READS *** 1,240
1,240 RELATION_ID=138
*** INDEXED READS *** 23,304
23,116 RELATION_ID=157
188 RELATION_ID=291
PROFILE DATA MARKED AS START
====*/
/*---
[ 6/19/2002 6:18:36 PM ]
DATABASE INFO
DB_HANDLE = 37645860
----*/
/*===
[ 6/19/2002 6:18:36 PM ]
PROFILE DIFF REPORT -- Before execute
*** OVERALL SERVER PROCESS ***
Current Memory = 44,273,215 (-525,396)
Num Buffer Reads = 4,438,766 (+7,109)
Num Buffer Writes = 2,057 (+71)
Num Page Reads = 3,422 (+17)
Num Page Writes = 1,264 (+59)
*** SEQUENTIAL (NON-INDEXED) READS *** 2,740
1,240 RELATION_ID=138
1,500 RELATION_ID=272
*** INDEXED READS *** 328
160 RELATION_ID=178
16 RELATION_ID=138
16 RELATION_ID=140
11 RELATION_ID=152
30 RELATION_ID=157
14 RELATION_ID=162
24 RELATION_ID=170
34 RELATION_ID=301
8 RELATION_ID=139
1 RELATION_ID=155
3 RELATION_ID=166
9 RELATION_ID=181
1 RELATION_ID=302
1 RELATION_ID=312
*** INSERT COUNT *** 9
1 RELATION_ID=210
8 RELATION_ID=211
*** UPDATE COUNT *** 9
1 RELATION_ID=166
8 RELATION_ID=170
PROFILE DATA MARKED AS START
====*/
/*---
[ 6/19/2002 6:18:36 PM ]
EXECUTE STATEMENT
TR_HANDLE = 37645768
STMT_HANDLE = 37642836
PARAMS = [ Version 1 SQLd 3 SQLn 3
[CLIENTID] = '432 '
[FROMDATE] = '01 Apr 2002'
[TODATE] = '30 Jun 2002' ]
SECONDS = 0.438
ERRCODE = 335544741
----*/
/*---
[ 6/19/2002 6:18:36 PM ]
DATABASE INFO
DB_HANDLE = 37645860
ERRCODE = 335544741
----*/
/*---
[ 6/19/2002 6:18:36 PM ]
INTERPRETE BUFFER =
ERRCODE = 27
----*/
/*---
[ 6/19/2002 6:18:36 PM ]
INTERPRETE BUFFER = connection lost to database
ERRCODE = -1
----*/
/*===
$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$
__________________________________________________________________
The first and only other error in the log is a schema error before
the very first pass :
[ 6/19/2002 6:17:59 PM ]
//>>> ERROR <<<//
ISC ERROR CODE:335544569
ISC ERROR MESSAGE:
Dynamic SQL Error
SQL error code = -504
Cursor unknown
STATEMENT:
TIB_SchemaCursor: "DefaultSession.<TIB_SchemaCursor>."
stHandle=37692808 (ERROR)
//>>> SQL MESSAGE <<<//
SQL ERROR CODE:-504
SQL ERROR MESSAGE:
Unknown cursor
====*/
/*===
[ 6/19/2002 6:17:59 PM ]
PROFILE ERROR -- EXCEPTION RAISED
ISC ERROR CODE:335544569
ISC ERROR MESSAGE:
Dynamic SQL Error
SQL error code = -504
Cursor unknown
====*/
/*---
[ 6/19/2002 6:18:11 PM ]
EXECUTE STATEMENT
TR_HANDLE = 37645768
STMT_HANDLE = 37642836
PARAMS = [ Version 1 SQLd 3 SQLn 3
[CLIENTID] = '190 '
[FROMDATE] = '01 Apr 2002'
[TODATE] = '30 Jun 2002' ]
SECONDS = 0.578
----*/
Help!!!!!!
Dan
I have a situation where many many opens and closes of about 70
queries goes along just fine. Then on the 27th pass (we changed the
client at this location and it got nailed on the new #27) it crashes
the interbase server (6.5). Each client can be processed one at a
time with no problem. The query runs fine in the console for that
and all the other clients. Data problem unlikely.
We have been looking all day at the server and the database to solve
the problem of the crashes that started today. Getting a new copy of
the database from a (several dating back weeks) backup and testing
locally (End users were getting tired of the server crashing in the
middle of their work) we were getting the "Lost connection to server
message" that the clients were getting. The IB log shows the server
crashed and restarted.
We stepped through the code and found it was crashing on one
particular query. I put a trace around that close and open sequence
(
frmETS.IB_Monitor1.Enabled := True;
qryPaymentReturns.Close;
qryPaymentReturns.ParamByName('ClientID').AsString :=
qryClientClient_ID.Value;
qryPaymentReturns.ParamByName('FromDate').AsDate := FromDate;
qryPaymentReturns.ParamByName('ToDate').AsDate := ToDate;
qryPaymentReturns.Open;
qryPaymentReturns.First;
frmETS.IB_Monitor1.Enabled := False;
)
and got the following (cut to just the 26th and 27th pass for
comparison):
/*===
[ 6/19/2002 6:18:35 PM ]
PROFILE DIFF REPORT -- Before execute
*** OVERALL SERVER PROCESS ***
Current Memory = 44,273,224 (-525,420)
Num Buffer Reads = 4,382,001 (+6,863)
Num Buffer Writes = 1,986 (+42)
Num Page Reads = 3,390 (+2)
Num Page Writes = 1,205 (+36)
*** SEQUENTIAL (NON-INDEXED) READS *** 2,740
1,240 RELATION_ID=138
1,500 RELATION_ID=272
*** INDEXED READS *** 275
100 RELATION_ID=178
19 RELATION_ID=138
10 RELATION_ID=140
19 RELATION_ID=152
21 RELATION_ID=157
16 RELATION_ID=162
15 RELATION_ID=170
13 RELATION_ID=181
51 RELATION_ID=301
5 RELATION_ID=139
1 RELATION_ID=155
3 RELATION_ID=166
1 RELATION_ID=302
1 RELATION_ID=312
*** INSERT COUNT *** 6
1 RELATION_ID=210
5 RELATION_ID=211
*** UPDATE COUNT *** 6
1 RELATION_ID=166
5 RELATION_ID=170
PROFILE DATA MARKED AS START
====*/
/*---
[ 6/19/2002 6:18:35 PM ]
EXECUTE STATEMENT
TR_HANDLE = 37645768
STMT_HANDLE = 37642836
PARAMS = [ Version 1 SQLd 3 SQLn 3
[CLIENTID] = '384 '
[FROMDATE] = '01 Apr 2002'
[TODATE] = '30 Jun 2002' ]
SECONDS = 0.625
----*/
/*---
[ 6/19/2002 6:18:36 PM ]
DATABASE INFO
DB_HANDLE = 37645860
----*/
/*===
[ 6/19/2002 6:18:36 PM ]
PROFILE DIFF REPORT -- After execute
*** OVERALL SERVER PROCESS ***
Current Memory = 44,798,611 (+525,387)
Num Buffer Reads = 4,431,657 (+49,656)
Num Page Reads = 3,405 (+15)
*** SEQUENTIAL (NON-INDEXED) READS *** 1,240
1,240 RELATION_ID=138
*** INDEXED READS *** 23,304
23,116 RELATION_ID=157
188 RELATION_ID=291
PROFILE DATA MARKED AS START
====*/
/*---
[ 6/19/2002 6:18:36 PM ]
DATABASE INFO
DB_HANDLE = 37645860
----*/
/*===
[ 6/19/2002 6:18:36 PM ]
PROFILE DIFF REPORT -- Before execute
*** OVERALL SERVER PROCESS ***
Current Memory = 44,273,215 (-525,396)
Num Buffer Reads = 4,438,766 (+7,109)
Num Buffer Writes = 2,057 (+71)
Num Page Reads = 3,422 (+17)
Num Page Writes = 1,264 (+59)
*** SEQUENTIAL (NON-INDEXED) READS *** 2,740
1,240 RELATION_ID=138
1,500 RELATION_ID=272
*** INDEXED READS *** 328
160 RELATION_ID=178
16 RELATION_ID=138
16 RELATION_ID=140
11 RELATION_ID=152
30 RELATION_ID=157
14 RELATION_ID=162
24 RELATION_ID=170
34 RELATION_ID=301
8 RELATION_ID=139
1 RELATION_ID=155
3 RELATION_ID=166
9 RELATION_ID=181
1 RELATION_ID=302
1 RELATION_ID=312
*** INSERT COUNT *** 9
1 RELATION_ID=210
8 RELATION_ID=211
*** UPDATE COUNT *** 9
1 RELATION_ID=166
8 RELATION_ID=170
PROFILE DATA MARKED AS START
====*/
/*---
[ 6/19/2002 6:18:36 PM ]
EXECUTE STATEMENT
TR_HANDLE = 37645768
STMT_HANDLE = 37642836
PARAMS = [ Version 1 SQLd 3 SQLn 3
[CLIENTID] = '432 '
[FROMDATE] = '01 Apr 2002'
[TODATE] = '30 Jun 2002' ]
SECONDS = 0.438
ERRCODE = 335544741
----*/
/*---
[ 6/19/2002 6:18:36 PM ]
DATABASE INFO
DB_HANDLE = 37645860
ERRCODE = 335544741
----*/
/*---
[ 6/19/2002 6:18:36 PM ]
INTERPRETE BUFFER =
ERRCODE = 27
----*/
/*---
[ 6/19/2002 6:18:36 PM ]
INTERPRETE BUFFER = connection lost to database
ERRCODE = -1
----*/
/*===
$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$$
__________________________________________________________________
The first and only other error in the log is a schema error before
the very first pass :
[ 6/19/2002 6:17:59 PM ]
//>>> ERROR <<<//
ISC ERROR CODE:335544569
ISC ERROR MESSAGE:
Dynamic SQL Error
SQL error code = -504
Cursor unknown
STATEMENT:
TIB_SchemaCursor: "DefaultSession.<TIB_SchemaCursor>."
stHandle=37692808 (ERROR)
//>>> SQL MESSAGE <<<//
SQL ERROR CODE:-504
SQL ERROR MESSAGE:
Unknown cursor
====*/
/*===
[ 6/19/2002 6:17:59 PM ]
PROFILE ERROR -- EXCEPTION RAISED
ISC ERROR CODE:335544569
ISC ERROR MESSAGE:
Dynamic SQL Error
SQL error code = -504
Cursor unknown
====*/
/*---
[ 6/19/2002 6:18:11 PM ]
EXECUTE STATEMENT
TR_HANDLE = 37645768
STMT_HANDLE = 37642836
PARAMS = [ Version 1 SQLd 3 SQLn 3
[CLIENTID] = '190 '
[FROMDATE] = '01 Apr 2002'
[TODATE] = '30 Jun 2002' ]
SECONDS = 0.578
----*/
Help!!!!!!
Dan