SSL timeout?
am 23.11.2009 17:08:05 von Jan-Peter.SeifertHello,
there's a problem with running some of our update-scripts via a SSL-encry=
pted connection. Our application is submitting the sql queries within tra=
nsactions via psqlODBC.
Everything is fine as long as no encryption is used. However, as soon as =
ssl is being used the connection seems to close on transactions / command=
s taking longer than about 10 minutes:
This is the application's log for the part that fails:
[SQL 23.11.2009 14:41:01] [5300] BEGIN;
[SQL 23.11.2009 14:41:01] [5300] SELECT pg_class.oid FROM pg_catalog.pg_c=
lass JOIN pg_namespace ON pg_class.relnamespace =3D pg_namespace.oid WHER=
E relname=3D'tabelle' AND pg_namespace.nspname =3D current_schema()
[SQL 23.11.2009 14:41:01] [5300] SELECT a.atttypid, t.typname, d.adsrc FR=
OM pg_catalog.pg_attribute a JOIN pg_catalog.pg_type t ON a.atttypid=3Dt=
..oid LEFT OUTER JOIN pg_catalog.pg_attrdef d ON (a.attnum=3Dd.adnum AND =
a.attrelid=3Dd.adrelid) WHERE a.attrelid=3D109253095 AND a.attname=3D'spa=
lte';
[SQL 23.11.2009 14:41:01] [5300] SELECT atttypmod FROM pg_catalog.pg_attr=
ibute WHERE attname=3D'spalte' AND attrelid=3D109253095;
[SQL 23.11.2009 14:41:01] [5300] SELECT attnotnull FROM pg_catalog.pg_att=
ribute WHERE attname=3D'spalte' AND attrelid=3D109253095;
[SQL 23.11.2009 14:41:01] [5300] SELECT COUNT(*) FROM tabelle;
[SQL 23.11.2009 14:41:01] [5300] CREATE TABLE tmp_mc_NUXKDB WITH OIDS AS =
SELECT * FROM tabelle;
[SQL 23.11.2009 14:41:54] [5300] DELETE FROM tabelle;
[SQL 23.11.2009 14:43:25] [5300] UPDATE pg_catalog.pg_attribute SET attty=
pmod=3D18 WHERE attname=3D'spalte' AND attrelid=3D109253095;
[SQL 23.11.2009 14:43:25] [5300] INSERT INTO tabelle SELECT * FROM tmp_mc=
_NUXKDB;
[SQL 23.11.2009 14:51:41] [5300] ROLLBACK WORK;
The first error message is:
ODBC-Error - SQLExecDirect/ExecuteSQL: SQLSTATE =3D 42883 Native Error =3D=
26 Error Message: No response from the backend; No response from the bac=
kend
The rollback fails because of the closed connection.
During the transaction in question a pretty large table ( 1.500.000 rows,=
=20
67633 relpages ) is being written to a temporary table, dropped, recreate=
d and filled with the data from the temporary table. It seems that the co=
nnection closes on the INSERT command from the temporary table. The pgAdm=
in status window still shows this insert after the error message.
The app's code is pretty old, but it seems that this behaviour with ssl c=
auses problems elsewhere as well.
* your ODBC driver version
08.04.0100 on Windows (seems to happen on earlier versions as well: 8.2.3=
00, 8.3.400 ...)
* your PostgreSQL database version
v8.3.8 Windows and Linux
Thank you very much,
Peter
--------------------------------------------------
Mylog:
....
[5652-524.361]SC_init_Result(437b5a8)[5652-524.362]SC_Destru ctor: self=3D=
0437B5A8, self->result=3D00000000, self->hdbc=3D01783E20
[5652-524.363]APD_free_params: ENTER, self=3D0437B6A8
[5652-524.363]IPD_free_params: ENTER, self=3D0437B6E8
[5652-524.364]PDATA_free_params: ENTER, self=3D0437B74C
[5652-524.364]SC_Destructor: EXIT
[5652-524.366][[SQLAllocHandle]][5652-524.366]PGAPI_AllocStm t: entering..=
..
[5652-524.366]**** PGAPI_AllocStmt: hdbc =3D 01783E20, stmt =3D 0437B5A8
[5652-524.367]CC_add_statement: self=3D01783E20, stmt=3D0437B5A8
[5652-524.368][[SQLGetStmtAttr]] Handle=3D70759848 10010
[5652-524.369]PGAPI_GetStmtAttr Handle=3D0437B5A8 10010
[5652-524.369][[SQLGetStmtAttr]] Handle=3D70759848 10011
[5652-524.370]PGAPI_GetStmtAttr Handle=3D0437B5A8 10011
[5652-524.370][[SQLGetStmtAttr]] Handle=3D70759848 10012
[5652-524.371]PGAPI_GetStmtAttr Handle=3D0437B5A8 10012
[5652-524.372][[SQLGetStmtAttr]] Handle=3D70759848 10013
[5652-524.372]PGAPI_GetStmtAttr Handle=3D0437B5A8 10013
[5652-524.373][SQLExecDirect][5652-524.373]PGAPI_ExecDirect: entering...1
[5652-524.374]SC_recycle_statement: self=3D 0437B5A8
[5652-524.374]**** PGAPI_ExecDirect: hstmt=3D0437B5A8, statement=3D'INSER=
T INTO tabelle SELECT * FROM tmp_mc_NPDZRM;'
[5652-524.375]PGAPI_ExecDirect: calling PGAPI_Execute...
[5652-524.376]PGAPI_Execute: entering...1
[5652-524.376]PGAPI_Execute: clear errors...
[5652-524.377]PGAPI_NumParams: entering...
[5652-524.377]SC_scanQueryAndCountParams: entering...
[5652-524.378]prepareParameters 0 end
[5652-524.378]SC_recycle_statement: self=3D 0437B5A8
[5652-524.379]Exec_with_parameters_resolved: copying statement params: tr=
ans_status=3D6, len=3D45, stmt=3D'INSERT INTO tabelle SELECT * FROM tmp_m=
c_NPDZRM;'
[5652-524.381] stmt_with_params =3D 'INSERT INTO tabelle SELECT * FROM =
tmp_mc_NPDZRM;'
[5652-524.382]about to begin SC_execute
[5652-524.382] it's NOT a select statement: stmt=3D0437B5A8
[5652-524.383]CC_send_query: conn=3D01783E20, query=3D'INSERT INTO tabell=
e SELECT * FROM tmp_mc_NPDZRM;'
[5652-524.385]CC_send_query: conn=3D01783E20, query=3D'SAVEPOINT _EXEC_SV=
P_0437B5A8'
[5652-524.386]send_query: done sending query 34bytes flushed
[5652-524.386]in QR_Constructor
[5652-524.387]exit QR_Constructor
[5652-524.387]read 21, global_socket_buffersize=3D4096
[5652-524.388]send_query: got id =3D 'C'
[5652-524.388]send_query: ok - 'C' - SAVEPOINT
[5652-524.389]send_query: setting cmdbuffer =3D 'SAVEPOINT'
[5652-524.389]send_query: returning res =3D 0437BFA0
[5652-524.390]send_query: got id =3D 'Z'
[5652-524.390]QResult: enter DESTRUCTOR
[5652-524.391]QResult: in QR_close_result
[5652-524.391]QResult: free memory in, fcount=3D0
[5652-524.392]QResult: free memory out
[5652-524.392]QResult: enter DESTRUCTOR
[5652-524.392]QResult: exit close_result
[5652-524.393]QResult: exit DESTRUCTOR
[5652-524.393]send_query: done sending query 51bytes flushed
[5652-524.394]in QR_Constructor
[5652-524.395]exit QR_Constructor
[5652-524.395]read -1, global_socket_buffersize=3D4096
[5652-524.396]Lasterror=3D10035
[5652-525.396]read -1, global_socket_buffersize=3D4096
[5652-525.396]Lasterror=3D10035
[5652-527.397]read -1, global_socket_buffersize=3D4096
[5652-527.397]Lasterror=3D10035
[5652-530.398]read -1, global_socket_buffersize=3D4096
[5652-530.398]Lasterror=3D10035
[5652-534.399]read -1, global_socket_buffersize=3D4096
[5652-534.399]Lasterror=3D10035
[5652-539.400]read -1, global_socket_buffersize=3D4096
[5652-539.400]Lasterror=3D10035
[5652-545.401]read -1, global_socket_buffersize=3D4096
[5652-545.401]Lasterror=3D10035
[5652-552.402]read -1, global_socket_buffersize=3D4096
[5652-552.402]Lasterror=3D10035
[5652-560.403]read -1, global_socket_buffersize=3D4096
[5652-560.403]Lasterror=3D10035
[5652-569.404]read -1, global_socket_buffersize=3D4096
[5652-569.404]Lasterror=3D10035
[5652-579.405]read -1, global_socket_buffersize=3D4096
[5652-579.405]Lasterror=3D10035
[5652-590.406]read -1, global_socket_buffersize=3D4096
[5652-590.406]Lasterror=3D10035
[5652-602.406]read -1, global_socket_buffersize=3D4096
[5652-602.406]Lasterror=3D10035
[5652-615.407]read -1, global_socket_buffersize=3D4096
[5652-615.407]Lasterror=3D10035
[5652-629.408]read -1, global_socket_buffersize=3D4096
[5652-629.408]Lasterror=3D10035
[5652-644.409]read -1, global_socket_buffersize=3D4096
[5652-644.409]Lasterror=3D10035
[5652-660.410]read -1, global_socket_buffersize=3D4096
[5652-660.410]Lasterror=3D10035
[5652-677.411]read -1, global_socket_buffersize=3D4096
[5652-677.411]Lasterror=3D10035
[5652-695.412]read -1, global_socket_buffersize=3D4096
[5652-695.412]Lasterror=3D10035
[5652-714.413]read -1, global_socket_buffersize=3D4096
[5652-714.413]Lasterror=3D10035
[5652-734.414]read -1, global_socket_buffersize=3D4096
[5652-734.414]Lasterror=3D10035
[5652-755.415]read -1, global_socket_buffersize=3D4096
[5652-755.415]Lasterror=3D10035
[5652-777.416]read -1, global_socket_buffersize=3D4096
[5652-777.416]Lasterror=3D10035
[5652-800.417]read -1, global_socket_buffersize=3D4096
[5652-800.417]Lasterror=3D10035
[5652-824.418]read -1, global_socket_buffersize=3D4096
[5652-824.418]Lasterror=3D10035
[5652-849.419]read -1, global_socket_buffersize=3D4096
[5652-849.419]Lasterror=3D10035
[5652-875.420]read -1, global_socket_buffersize=3D4096
[5652-875.420]Lasterror=3D10035
[5652-902.420]read -1, global_socket_buffersize=3D4096
[5652-902.420]Lasterror=3D10035
[5652-930.421]read -1, global_socket_buffersize=3D4096
[5652-930.421]Lasterror=3D10035
[5652-959.422]read -1, global_socket_buffersize=3D4096
[5652-959.422]Lasterror=3D10035
[5652-989.422]read -1, global_socket_buffersize=3D4096
[5652-989.422]Lasterror=3D10035
[5652-1020.423](11)SOCK_wait_for_ready timeout ERRNO=3D0
[5652-1020.423]CC_error_statements: self=3D01783E20
[5652-1020.425]CONN ERROR: func=3DCC_send_query, desc=3D'', errnum=3D107,=
errmsg=3D'No response from the backend'
[5652-1020.431]send_query: 'id' - No response from the backend
[5652-1020.432]CC_on_abort in
[5652-1020.432]SOCK_Destructor
[5652-1020.433]CC_on_abort in
[5652-1020.434]QResult: enter DESTRUCTOR
[5652-1020.434]QResult: in QR_close_result
[5652-1020.434]QResult: free memory in, fcount=3D0
[5652-1020.435]QResult: free memory out
[5652-1020.435]QResult: enter DESTRUCTOR
[5652-1020.436]QResult: exit close_result
[5652-1020.436]QResult: exit DESTRUCTOR
[5652-1020.438]STATEMENT ERROR: func=3DSC_execute, desc=3D'', errnum=3D26=
, errmsg=3D'No response from the backend'
[5652-1020.451]CONN ERROR: func=3DSC_execute, desc=3D'', errnum=3D107, er=
rmsg=3D'No response from the backend'
....
--=20
GRATIS für alle GMX-Mitglieder: Die maxdome Movie-FLAT!
Jetzt freischalten unter http://portal.gmx.net/de/go/maxdome01
--=20
Sent via pgsql-odbc mailing list (pgsql-odbc@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-odbc