SSL timeout?

Hello,

there's a problem with running some of our update-scripts via a SSL-encrypted connection. Our application is submitting the sql queries within transactions 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 / commands 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_class JOIN pg_namespace ON pg_class.relnamespace = pg_namespace.oid WHERE relname='tabelle' AND pg_namespace.nspname = current_schema()
[SQL 23.11.2009 14:41:01] [5300] SELECT a.atttypid, t.typname, d.adsrc FROM pg_catalog.pg_attribute a JOIN pg_catalog.pg_type t ON a.atttypid=t.oid LEFT OUTER JOIN pg_catalog.pg_attrdef d ON (a.attnum=d.adnum AND a.attrelid=d.adrelid) WHERE a.attrelid=109253095 AND a.attname='spalte';
[SQL 23.11.2009 14:41:01] [5300] SELECT atttypmod FROM pg_catalog.pg_attribute WHERE attname='spalte' AND attrelid=109253095;
[SQL 23.11.2009 14:41:01] [5300] SELECT attnotnull FROM pg_catalog.pg_attribute WHERE attname='spalte' AND attrelid=109253095;
[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 atttypmod=18 WHERE attname='spalte' AND attrelid=109253095;
[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 = 42883 Native Error = 26 Error Message: No response from the backend; No response from the backend

The rollback fails because of the closed connection.

During the transaction in question a pretty large table ( 1.500.000 rows,
67633 relpages ) is being written to a temporary table, dropped, recreated and filled with the data from the temporary table. It seems that the connection closes on the INSERT command from the temporary table. The pgAdmin 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 causes problems elsewhere as well.

* your ODBC driver version
08.04.0100 on Windows (seems to happen on earlier versions as well: 8.2.300, 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_Destructor: self=0437B5A8, self->result=00000000, self->hdbc=01783E20
[5652-524.363]APD_free_params: ENTER, self=0437B6A8
[5652-524.363]IPD_free_params: ENTER, self=0437B6E8
[5652-524.364]PDATA_free_params: ENTER, self=0437B74C
[5652-524.364]SC_Destructor: EXIT
[5652-524.366][[SQLAllocHandle]][5652-524.366]PGAPI_AllocStmt: entering...
[5652-524.366]**** PGAPI_AllocStmt: hdbc = 01783E20, stmt = 0437B5A8
[5652-524.367]CC_add_statement: self=01783E20, stmt=0437B5A8
[5652-524.368][[SQLGetStmtAttr]] Handle=70759848 10010
[5652-524.369]PGAPI_GetStmtAttr Handle=0437B5A8 10010
[5652-524.369][[SQLGetStmtAttr]] Handle=70759848 10011
[5652-524.370]PGAPI_GetStmtAttr Handle=0437B5A8 10011
[5652-524.370][[SQLGetStmtAttr]] Handle=70759848 10012
[5652-524.371]PGAPI_GetStmtAttr Handle=0437B5A8 10012
[5652-524.372][[SQLGetStmtAttr]] Handle=70759848 10013
[5652-524.372]PGAPI_GetStmtAttr Handle=0437B5A8 10013
[5652-524.373][SQLExecDirect][5652-524.373]PGAPI_ExecDirect: entering...1
[5652-524.374]SC_recycle_statement: self= 0437B5A8
[5652-524.374]**** PGAPI_ExecDirect: hstmt=0437B5A8, statement='INSERT 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= 0437B5A8
[5652-524.379]Exec_with_parameters_resolved: copying statement params: trans_status=6, len=45, stmt='INSERT INTO tabelle SELECT * FROM tmp_mc_NPDZRM;'
[5652-524.381] stmt_with_params = '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=0437B5A8
[5652-524.383]CC_send_query: conn=01783E20, query='INSERT INTO tabelle SELECT * FROM tmp_mc_NPDZRM;'
[5652-524.385]CC_send_query: conn=01783E20, query='SAVEPOINT _EXEC_SVP_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=4096
[5652-524.388]send_query: got id = 'C'
[5652-524.388]send_query: ok - 'C' - SAVEPOINT
[5652-524.389]send_query: setting cmdbuffer = 'SAVEPOINT'
[5652-524.389]send_query: returning res = 0437BFA0
[5652-524.390]send_query: got id = 'Z'
[5652-524.390]QResult: enter DESTRUCTOR
[5652-524.391]QResult: in QR_close_result
[5652-524.391]QResult: free memory in, fcount=0
[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=4096
[5652-524.396]Lasterror=10035
[5652-525.396]read -1, global_socket_buffersize=4096
[5652-525.396]Lasterror=10035
[5652-527.397]read -1, global_socket_buffersize=4096
[5652-527.397]Lasterror=10035
[5652-530.398]read -1, global_socket_buffersize=4096
[5652-530.398]Lasterror=10035
[5652-534.399]read -1, global_socket_buffersize=4096
[5652-534.399]Lasterror=10035
[5652-539.400]read -1, global_socket_buffersize=4096
[5652-539.400]Lasterror=10035
[5652-545.401]read -1, global_socket_buffersize=4096
[5652-545.401]Lasterror=10035
[5652-552.402]read -1, global_socket_buffersize=4096
[5652-552.402]Lasterror=10035
[5652-560.403]read -1, global_socket_buffersize=4096
[5652-560.403]Lasterror=10035
[5652-569.404]read -1, global_socket_buffersize=4096
[5652-569.404]Lasterror=10035
[5652-579.405]read -1, global_socket_buffersize=4096
[5652-579.405]Lasterror=10035
[5652-590.406]read -1, global_socket_buffersize=4096
[5652-590.406]Lasterror=10035
[5652-602.406]read -1, global_socket_buffersize=4096
[5652-602.406]Lasterror=10035
[5652-615.407]read -1, global_socket_buffersize=4096
[5652-615.407]Lasterror=10035
[5652-629.408]read -1, global_socket_buffersize=4096
[5652-629.408]Lasterror=10035
[5652-644.409]read -1, global_socket_buffersize=4096
[5652-644.409]Lasterror=10035
[5652-660.410]read -1, global_socket_buffersize=4096
[5652-660.410]Lasterror=10035
[5652-677.411]read -1, global_socket_buffersize=4096
[5652-677.411]Lasterror=10035
[5652-695.412]read -1, global_socket_buffersize=4096
[5652-695.412]Lasterror=10035
[5652-714.413]read -1, global_socket_buffersize=4096
[5652-714.413]Lasterror=10035
[5652-734.414]read -1, global_socket_buffersize=4096
[5652-734.414]Lasterror=10035
[5652-755.415]read -1, global_socket_buffersize=4096
[5652-755.415]Lasterror=10035
[5652-777.416]read -1, global_socket_buffersize=4096
[5652-777.416]Lasterror=10035
[5652-800.417]read -1, global_socket_buffersize=4096
[5652-800.417]Lasterror=10035
[5652-824.418]read -1, global_socket_buffersize=4096
[5652-824.418]Lasterror=10035
[5652-849.419]read -1, global_socket_buffersize=4096
[5652-849.419]Lasterror=10035
[5652-875.420]read -1, global_socket_buffersize=4096
[5652-875.420]Lasterror=10035
[5652-902.420]read -1, global_socket_buffersize=4096
[5652-902.420]Lasterror=10035
[5652-930.421]read -1, global_socket_buffersize=4096
[5652-930.421]Lasterror=10035
[5652-959.422]read -1, global_socket_buffersize=4096
[5652-959.422]Lasterror=10035
[5652-989.422]read -1, global_socket_buffersize=4096
[5652-989.422]Lasterror=10035
[5652-1020.423](11)SOCK_wait_for_ready timeout ERRNO=0
[5652-1020.423]CC_error_statements: self=01783E20
[5652-1020.425]CONN ERROR: func=CC_send_query, desc='', errnum=107, errmsg='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=0
[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=SC_execute, desc='', errnum=26, errmsg='No response from the backend'
[5652-1020.451]CONN ERROR: func=SC_execute, desc='', errnum=107, errmsg='No response from the backend'
...

--
GRATIS für alle GMX-Mitglieder: Die maxdome Movie-FLAT!
Jetzt freischalten unter http://portal.gmx.net/de/go/maxdome01