> > So what operation is eroding out? > Can you try to isolate it? > > Thank you. Hi, Thank you for posting the question Matthias! And for your replies. We've now managed to collect the log files now from the application, driver manager and driver. And there are actually some things that might be more interesting that the 999 'invalid handle' that the application gives us: 1. The driver manager also shows [SQLGetInfo.c][528]Error: SQL_INVALID_HANDLE 2. The driver log has 'Unrecognized key passed to PGAPI_GetInfo' for fInfoType=10000. I've found this infotype 10000 as SQL_XOPEN_CLI_YEAR, in https://pubs.opengroup.org/onlinepubs/9695949899/toc.pdf and I am wondering if this can cause things to fail. 3. Also, the driver log shows a message: syntax error at or near "prepareThreshold". I don't know there this prepareThreshold statement comes from. Is it the application? Or can it be the driver manager? I've added the logs top this message. Thanks for your help. ================ APPLICATION LOG ================ DBHandle is 0 Setting up n_tr DBMS: ODBC DBParm: CacheName='pgsqlODBC12' Autocommit: false connect using i_tr... dberror event triggered on n_tr code: 999 sqlerrortext: An invalid handle was passed in a call to the database driver. sqlsyntax: SQLErrText: An invalid handle was passed in a call to the database driver. sqldbcode: 999 sqlcode: -1 ============== UNIX-ODBC LOG ============== [ODBC][8732][SQLAllocHandle.c][345] Entry: Handle Type = 2 Input Handle = 0xad6f9b98 [ODBC][8732][SQLAllocHandle.c][463] Exit:[SQL_SUCCESS] Output Handle = 0xac4d31c8 [ODBC][8732][SQLDriverConnect.c][678] Entry: Connection = 0xac4d31c8 Window Hdl = (nil) Str In = [DSN=PG12;UID=thedb_dbo;PWD=******][length = 33 (SQL_NTS)] Str Out = 0xac2bf7b8 Str Out Max = 2048 Str Out Ptr = 0xa8caaa7a Completion = 0 UNICODE Using encoding ASCII 'ISO8859-1' and UNICODE 'UCS-2LE' DIAG [01S02] ERROR: syntax error at or near "prepareThreshold" [ODBC][8732][SQLDriverConnect.c][1487] Exit:[SQL_SUCCESS_WITH_INFO] Connection Out [DSN=PG12;DATABASE=thedb;SERVER=server.domain.org;PORT=5...] DIAG [HYC00] Unrecognized key passed to PGAPI_GetInfo. [ODBC][8732][SQLSetConnectAttr.c][318] Entry: Connection = 0xac4d31c8 Attribute = SQL_ATTR_AUTOCOMMIT Value = (nil) StrLen = 0 [ODBC][8732][SQLSetConnectAttr.c][671] Exit:[SQL_SUCCESS] [ODBC][8732][SQLEndTran.c][315] Entry: Connection = 0xac4d31c8 Completion Type = 0 [ODBC][8732][SQLGetInfo.c][214] Entry: Connection = 0xac4d31c8 Info Type = SQL_CURSOR_COMMIT_BEHAVIOR (23) Info Value = 0xa8caaaee Buffer Length = 8 StrLen = 0xa8caaaec [ODBC][8732][SQLGetInfo.c][528] Exit:[SQL_SUCCESS] [ODBC][8732][SQLEndTran.c][488] Exit:[SQL_SUCCESS] [ODBC][8732][1593175526.538650][SQLGetInfo.c][528]Error: SQL_INVALID_HANDLE [ODBC][8732][1593175526.538683][SQLGetInfo.c][528]Error: SQL_INVALID_HANDLE =========== DRIVER LOG =========== [ab4ffb40] mylog.c[logs_on_off]274: mylog_on=1 qlog_on=0 [ab4ffb40]connection[CC_connect]1069: entering...sslmode=disable [ab4ffb40]connection[LIBPQ_CC_connect]1041: entering... [ab4ffb40]connection[CC_initial_log]989: [QLOG]Driver Version='12.00.0000,Oct 29 2019' [ab4ffb40]connection[CC_initial_log]1024: DSN = 'PG12', server = 'server.domain.org', port = '5601', database = 'thedb', username = 'thedb_dbo', password='xxxxx' [ab4ffb40]connection[LIBPQ_connect]2706: connecting to the database using server.domain.org as the server and pqopt={} [ab4ffb40]connection[LIBPQ_connect]2818: [QLOG]PQconnectdbParams: host='server.domain.org' port='5601' dbname='thedb' user='thedb_dbo' sslmode='disable' password='thepassword' [ab4ffb40]connection[LIBPQ_connect]2857: libpq connection to the database established. [ab4ffb40]connection[LIBPQ_connect]2864: protocol=3 [ab4ffb40]connection[LIBPQ_connect]2871: Server version=12.0.2 [ab4ffb40]connection[LIBPQ_connect]2895: leaving 1 [ab4ffb40]connection[CC_send_query_append]1769: conn=0xa5c69680, query='SET DateStyle = 'ISO';SET extra_float_digits = 2;show transaction_isolation' [ab4ffb40]connection[CC_send_query_append]1849: query_len=75 [ab4ffb40]connection[CC_send_query_append]1892: [QLOG]PQsendQuery: 0xa5c4d1a8 'SET DateStyle = 'ISO';SET extra_float_digits = 2;show transaction_isolation' [ab4ffb40] qresult.c[QR_Constructor]173: entering [ab4ffb40] qresult.c[QR_Constructor]242: leaving [ab4ffb40]connection[CC_send_query_append]1934: [QLOG] ok: - 'C' - SET [ab4ffb40]connection[CC_send_query_append]1950: setting cmdbuffer = 'SET' [ab4ffb40]connection[CC_send_query_append]2034: returning res = 0xa5c4cec8 [ab4ffb40]connection[CC_send_query_append]1934: [QLOG] ok: - 'C' - SET [ab4ffb40] qresult.c[QR_Constructor]173: entering [ab4ffb40] qresult.c[QR_Constructor]242: leaving [ab4ffb40]connection[CC_send_query_append]1950: setting cmdbuffer = 'SET' [ab4ffb40]connection[CC_send_query_append]2034: returning res = 0xa5c4cf90 [ab4ffb40] qresult.c[QR_Constructor]173: entering [ab4ffb40] qresult.c[QR_Constructor]242: leaving [ab4ffb40]connection[CC_send_query_append]2073: 'T' no result_in: res = 0xa5c70548 [ab4ffb40] qresult.c[QR_from_PGresult]604: [QLOG] nFields: 1 [ab4ffb40] qresult.c[QR_set_num_fields]40: entering [ab4ffb40] qresult.c[QR_set_num_fields]44: leaving [ab4ffb40] qresult.c[QR_from_PGresult]635: [QLOG] fieldname='transaction_isolation', adtid=25, adtsize=-1, atttypmod=-1 (rel,att)=(0,0) [ab4ffb40] qresult.c[QR_prepare_for_tupledata]817: REALLOC: old_count = 0, size = 0 [ab4ffb40] qresult.c[QR_read_tuples_from_pgres]1341: [QLOG] ok: - 'T' - SHOW [ab4ffb40]connection[handle_show_results]1324: isolation 2 to be 0 [ab4ffb40] qresult.c[QR_Destructor]344: entering [ab4ffb40] qresult.c[QR_close_result]255: entering [ab4ffb40] qresult.c[QR_free_memory]479: entering fcount=0 [ab4ffb40] qresult.c[QR_free_memory]577: leaving [ab4ffb40] qresult.c[QR_free_memory]479: entering fcount=0 [ab4ffb40] qresult.c[QR_free_memory]577: leaving [ab4ffb40] qresult.c[QR_free_memory]479: entering fcount=1 [ab4ffb40] qresult.c[QR_free_memory]577: leaving [ab4ffb40] qresult.c[QR_close_result]319: leaving [ab4ffb40] qresult.c[QR_Destructor]348: leaving [ab4ffb40]connection[CC_send_settings]2458: entering... [ab4ffb40]statement.[PGAPI_AllocStmt]186: entering... [ab4ffb40]statement.[PGAPI_AllocStmt]196: **** : hdbc = 0xa5c69680, stmt = 0xa5c6f290 [ab4ffb40]connection[CC_add_statement]1174: self=0xa5c69680, stmt=0xa5c6f290 [ab4ffb40] execute.c[PGAPI_ExecDirect]148: entering...0 [ab4ffb40]statement.[SC_recycle_statement]812: entering self=0xa5c6f290 [ab4ffb40] execute.c[PGAPI_ExecDirect]165: **** hstmt=0xa5c6f290, statement='prepareThreshold=0' [ab4ffb40] execute.c[PGAPI_ExecDirect]189: calling PGAPI_Execute... [ab4ffb40] execute.c[PGAPI_Execute]830: entering...0 [ab4ffb40] execute.c[PGAPI_Execute]845: clear errors... [ab4ffb40] bind.c[PGAPI_NumParams]425: entering... [ab4ffb40]statement.[SC_scanQueryAndCountParams]920: entering... [ab4ffb40]statement.[SC_scanQueryAndCountParams]1078: leaving...num_p=0 multi=0 [ab4ffb40] execute.c[PGAPI_Execute]926: prepareParameters was not called, prepare state:8 [ab4ffb40]statement.[SC_recycle_statement]812: entering self=0xa5c6f290 [ab4ffb40] bind.c[PDATA_free_params]663: entering self=0xa5c6f464 [ab4ffb40] execute.c[Exec_with_parameters_resolved]421: copying statement params: trans_status=1, len=18, stmt='prepareThreshold=0' [ab4ffb40]connection[CC_get_escape]1261: [QLOG]PQparameterStatus(0xa5c4d1a8, "standard_conforming_strings")=on [ab4ffb40] convert.c[inner_process_tokens]3909: token_len=16 status=1 token=prepareThreshold [ab4ffb40] convert.c[inner_process_tokens]3909: token_len=1 status=0 token== [ab4ffb40] execute.c[Exec_with_parameters_resolved]444: stmt_with_params = 'prepareThreshold=0' [ab4ffb40] execute.c[Exec_with_parameters_resolved]449: about to begin SC_execute [ab4ffb40]statement.[SC_execute]2037: it's NOT a select statement: stmt=0xa5c6f290 [ab4ffb40]connection[CC_send_query_append]1769: conn=0xa5c69680, query='prepareThreshold=0' [ab4ffb40]connection[CC_send_query_append]1849: query_len=18 [ab4ffb40]connection[CC_send_query_append]1892: [QLOG]PQsendQuery: 0xa5c4d1a8 'prepareThreshold=0' [ab4ffb40] qresult.c[QR_Constructor]173: entering [ab4ffb40] qresult.c[QR_Constructor]242: leaving [ab4ffb40]connection[handle_pgres_error]851: PG_DIAG_SEVERITY_NONLOCALIZED=ERROR [ab4ffb40]connection[handle_pgres_error]868: [QLOG] ERROR(ERROR) 42601 'syntax error at or near "prepareThreshold"' [ab4ffb40]connection[handle_pgres_error]902: error message=ERROR: syntax error at or near "prepareThreshold"(49) [ab4ffb40]statement.[SC_log_error]2354: STATEMENT ERROR: func=SC_set_errorinfo, desc='', errnum=35, errmsg='The connection has been lost' [ab4ffb40]connection[CC_log_error]2563: CONN ERROR: func=SC_set_errorinfo, desc='', errnum=110, errmsg='ERROR: syntax error at or near "prepareThreshold"' [ab4ffb40]statement.[SC_set_Result]531: (0xa5c6f290, 0xa5c4d0c0) [ab4ffb40] qresult.c[QR_Destructor]344: entering [ab4ffb40] execute.c[PGAPI_Execute]1052: leaving retval=-1 [ab4ffb40] execute.c[PGAPI_ExecDirect]193: leaving -1 [ab4ffb40]connection[CC_send_settings]2491: result -1, status 0 from 'prepareThreshold=0' [ab4ffb40]statement.[PGAPI_FreeStmt]245: entering...hstmt=0xa5c6f290, fOption=1 [ab4ffb40] qresult.c[QR_Destructor]344: entering [ab4ffb40] qresult.c[QR_close_result]255: entering [ab4ffb40] qresult.c[QR_free_memory]479: entering fcount=0 [ab4ffb40] qresult.c[QR_free_memory]577: leaving [ab4ffb40] qresult.c[QR_close_result]319: leaving [ab4ffb40] qresult.c[QR_Destructor]348: leaving [ab4ffb40]statement.[SC_init_Result]523: leaving(0xa5c6f290) [ab4ffb40]statement.[SC_Destructor]472: entering self=0xa5c6f290, self->result=(nil), self->hdbc=0xa5c69680 [ab4ffb40] bind.c[APD_free_params]643: entering self=0xa5c6f3a0 [ab4ffb40] bind.c[IPD_free_params]698: entering self=0xa5c6f3e0 [ab4ffb40] bind.c[PDATA_free_params]663: entering self=0xa5c6f464 [ab4ffb40]statement.[SC_Destructor]513: leaving [ab4ffb40]connection[CC_lookup_lo]2518: entering... [ab4ffb40]connection[CC_send_query_append]1769: conn=0xa5c69680, query='select oid, typbasetype from pg_type where typname = 'lo'' [ab4ffb40]connection[CC_send_query_append]1849: query_len=57 [ab4ffb40]connection[CC_send_query_append]1892: [QLOG]PQsendQuery: 0xa5c4d1a8 'select oid, typbasetype from pg_type where typname = 'lo'' [ab4ffb40] qresult.c[QR_Constructor]173: entering [ab4ffb40] qresult.c[QR_Constructor]242: leaving [ab4ffb40]connection[CC_send_query_append]2055: [QLOG] ok: - 'T' - SELECT 0 [ab4ffb40] qresult.c[QR_from_PGresult]604: [QLOG] nFields: 2 [ab4ffb40] qresult.c[QR_set_num_fields]40: entering [ab4ffb40] qresult.c[QR_set_num_fields]44: leaving [ab4ffb40] qresult.c[QR_from_PGresult]635: [QLOG] fieldname='oid', adtid=26, adtsize=4, atttypmod=-1 (rel,att)=(1247,1) [ab4ffb40] qresult.c[QR_from_PGresult]635: [QLOG] fieldname='typbasetype', adtid=26, adtsize=4, atttypmod=-1 (rel,att)=(1247,25) [ab4ffb40] qresult.c[QR_read_tuples_from_pgres]1341: [QLOG] ok: - 'T' - SELECT 0 [ab4ffb40] qresult.c[QR_Destructor]344: entering [ab4ffb40] qresult.c[QR_close_result]255: entering [ab4ffb40] qresult.c[QR_free_memory]479: entering fcount=0 [ab4ffb40] qresult.c[QR_free_memory]577: leaving [ab4ffb40] qresult.c[QR_close_result]319: leaving [ab4ffb40] qresult.c[QR_Destructor]348: leaving [ab4ffb40]connection[CC_lookup_lo]2537: Got the large object oid: -999 [ab4ffb40]connection[CC_determine_locale_encoding]597: [QLOG]PQparameterStatus(0xa5c4d1a8, "client_encoding")=UTF8 [ab4ffb40]connection[CC_send_query_append]1769: conn=0xa5c69680, query='set client_encoding to 'SQL_ASCII'' [ab4ffb40]connection[CC_send_query_append]1849: query_len=34 [ab4ffb40]connection[CC_send_query_append]1892: [QLOG]PQsendQuery: 0xa5c4d1a8 'set client_encoding to 'SQL_ASCII'' [ab4ffb40] qresult.c[QR_Constructor]173: entering [ab4ffb40] qresult.c[QR_Constructor]242: leaving [ab4ffb40]connection[CC_send_query_append]1934: [QLOG] ok: - 'C' - SET [ab4ffb40]connection[CC_send_query_append]1950: setting cmdbuffer = 'SET' [ab4ffb40]connection[CC_send_query_append]2034: returning res = 0xa5c4ce78 [ab4ffb40] qresult.c[QR_Destructor]344: entering [ab4ffb40] qresult.c[QR_close_result]255: entering [ab4ffb40] qresult.c[QR_free_memory]479: entering fcount=0 [ab4ffb40] qresult.c[QR_free_memory]577: leaving [ab4ffb40] qresult.c[QR_close_result]319: leaving [ab4ffb40] qresult.c[QR_Destructor]348: leaving [ab4ffb40]connection[CC_connect]1150: conn->unicode=0 Client Encoding='SQL_ASCII' (Code 0) [ab4ffb40]connection[CC_connect]1154: leaving...1 [ab4ffb40]connection[CC_set_error_statements]1222: entering self=0xa5c69680 [ab4ffb40]connection[CC_log_error]2563: CONN ERROR: func=CC_connect, desc='', errnum=-1, errmsg='ERROR: syntax error at or near "prepareThreshold"' [ab4ffb40]dlg_specif[makeConnectString]295: makeConnectString row_versioning=No [ab4ffb40] drvconn.c[PGAPI_DriverConnect]303: szConnStrOut = 'DSN=PG12;DATABASE=thedb;SERVER=server.domain.org;PORT=5601;UID=thedb_dbo;PWD=thepassword;SSLmode=disable;ReadOnly=No;Protocol=7.4;FakeOidIndex=0;ShowOidColumn=0;RowVersioning=No;ShowSystemTables=No;Fetch=100;UnknownSizes=0;MaxVarcharSize=255;MaxLongVarcharSize=8190;Debug=1;CommLog=0;UseDeclareFetch=0;TextAsLongVarchar=1;UnknownsAsLongVarchar=0;BoolsAsChar=1;Parse=0;ExtraSysTablePrefixes=;LFConversion=0;UpdatableCursors=1;TrueIsMinus1=0;BI=0;ByteaAsLongVarBinary=1;UseServerSidePrepare=1;LowerCaseIdentifier=0;D6=-101;' len=525,2048 [ab4ffb40] drvconn.c[PGAPI_DriverConnect]318: leaving 1 [ab4ffb40]odbcapi30.[SQLGetDiagRec]340: Entering [ab4ffb40] pgapi30.c[PGAPI_GetDiagRec]43: entering type=2 rec=1 [ab4ffb40] environ.c[PGAPI_ConnectError]284: entering hdbc=0xa5c69680 <513> [ab4ffb40]connection[CC_get_error]1387: entering [ab4ffb40]connection[CC_get_error]1400: leaving [ab4ffb40] environ.c[PGAPI_ConnectError]301: CC_get_error: status = -1, msg = #ERROR: syntax error at or near "prepareThreshold"# [ab4ffb40] environ.c[PGAPI_ConnectError]388: szSqlState = '01S02',len=49, szError='ERROR: syntax error at or near "prepareThreshold"' [ab4ffb40] pgapi30.c[PGAPI_GetDiagRec]70: leaving 0 [ab4ffb40]odbcapi30.[SQLGetDiagRec]340: Entering [ab4ffb40] pgapi30.c[PGAPI_GetDiagRec]43: entering type=2 rec=2 [ab4ffb40] environ.c[PGAPI_ConnectError]284: entering hdbc=0xa5c69680 <513> [ab4ffb40] pgapi30.c[PGAPI_GetDiagRec]70: leaving 100 [ab4ffb40] odbcapi.c[SQLGetFunctions]476: Entering [ab4ffb40] odbcapi.c[SQLGetInfo]501: Entering [ab4ffb40] info.c[PGAPI_GetInfo]71: entering...fInfoType=77 [ab4ffb40] info.c[PGAPI_GetInfo]1035: p='03.51', len=0, value=0, cbMax=20 [ab4ffb40] odbcapi.c[SQLGetInfo]501: Entering [ab4ffb40] info.c[PGAPI_GetInfo]71: entering...fInfoType=10000 [ab4ffb40]connection[CC_set_error_statements]1222: entering self=0xa5c69680 [ab4ffb40]connection[CC_log_error]2563: CONN ERROR: func=SQLGetInfo(30), desc='', errnum=209, errmsg='Unrecognized key passed to PGAPI_GetInfo.' [ab4ffb40]odbcapi30.[SQLGetDiagRec]340: Entering [ab4ffb40] pgapi30.c[PGAPI_GetDiagRec]43: entering type=2 rec=1 [ab4ffb40] environ.c[PGAPI_ConnectError]284: entering hdbc=0xa5c69680 <512> [ab4ffb40]connection[CC_get_error]1387: entering [ab4ffb40]connection[CC_get_error]1400: leaving [ab4ffb40] environ.c[PGAPI_ConnectError]301: CC_get_error: status = 209, msg = #Unrecognized key passed to PGAPI_GetInfo.# [ab4ffb40] environ.c[PGAPI_ConnectError]388: szSqlState = 'HYC00',len=41, szError='Unrecognized key passed to PGAPI_GetInfo.' [ab4ffb40] pgapi30.c[PGAPI_GetDiagRec]70: leaving 0 [ab4ffb40]odbcapi30.[SQLGetDiagRec]340: Entering [ab4ffb40] pgapi30.c[PGAPI_GetDiagRec]43: entering type=2 rec=2 [ab4ffb40] environ.c[PGAPI_ConnectError]284: entering hdbc=0xa5c69680 <512> [ab4ffb40] pgapi30.c[PGAPI_GetDiagRec]70: leaving 100 [ab4ffb40]odbcapi30.[SQLSetConnectAttr]429: Entering 102 [ab4ffb40] pgapi30.c[PGAPI_SetConnectAttr]1658: entering for 0xa5c69680: 102 (nil) [ab4ffb40] options.c[PGAPI_SetConnectOption]307: entering fOption = 102 vParam = 0 [ab4ffb40] options.c[PGAPI_SetConnectOption]371: AUTOCOMMIT: transact_status=1, vparam=0 [ab4ffb40]connection[CC_set_autocommit]534: 1->0 [ab4ffb40] odbcapi.c[SQLGetInfo]501: Entering [ab4ffb40] info.c[PGAPI_GetInfo]71: entering...fInfoType=46 [ab4ffb40] info.c[PGAPI_GetInfo]1035: p='<NULL>', len=2, value=2, cbMax=0 [ab4ffb40]odbcapi30.[SQLEndTran]171: Entering [ab4ffb40] execute.c[PGAPI_Transact]1069: entering hdbc=0xa5c69680, henv=(nil) [ab4ffb40] odbcapi.c[SQLGetInfo]501: Entering [ab4ffb40] info.c[PGAPI_GetInfo]71: entering...fInfoType=23 [ab4ffb40] info.c[PGAPI_GetInfo]1035: p='<NULL>', len=2, value=2, cbMax=8 [accc5b40] odbcapi.c[SQLDisconnect]288: Entering for 0xa5c69680 [accc5b40]connection[PGAPI_Disconnect]212: entering... [accc5b40] mylog.c[logs_on_off]274: mylog_on=1 qlog_on=0 [accc5b40]connection[PGAPI_Disconnect]227: about to CC_cleanup [accc5b40]connection[CC_cleanup]661: entering self=0xa5c69680 [accc5b40]connection[CC_cleanup]669: [QLOG]PQfinish: 0xa5c4d1a8 [accc5b40]connection[CC_cleanup]674: after PQfinish [accc5b40]dlg_specif[CC_conninfo_init]1714: entering opt=1 [accc5b40]connection[CC_cleanup]752: leaving [accc5b40]connection[PGAPI_Disconnect]232: done CC_cleanup [accc5b40]connection[PGAPI_Disconnect]233: leaving... [accc5b40]odbcapi30.[SQLFreeHandle]250: Entering [accc5b40]connection[PGAPI_FreeConnect]246: entering...hdbc=0xa5c69680 [accc5b40]connection[CC_Destructor]367: entering self=0xa5c69680 [accc5b40]connection[CC_cleanup]661: entering self=0xa5c69680 [accc5b40]connection[CC_cleanup]674: after PQfinish [accc5b40]dlg_specif[CC_conninfo_init]1714: entering opt=1 [accc5b40]connection[CC_cleanup]752: leaving [accc5b40]connection[CC_Destructor]374: after CC_Cleanup [accc5b40]connection[CC_Destructor]387: after free statement holders [accc5b40]connection[CC_Destructor]398: leaving [accc5b40]connection[PGAPI_FreeConnect]264: leaving... [accc5b40]odbcapi30.[SQLFreeHandle]250: Entering [accc5b40] environ.c[PGAPI_FreeEnv]100: entering env=0xa6025c30 [accc5b40] environ.c[EN_Destructor]519: entering self=0xa6025c30 [accc5b40] environ.c[EN_Destructor]545: clearing conns count=128 [accc5b40] environ.c[EN_Destructor]557: leaving rv=1 [accc5b40] environ.c[PGAPI_FreeEnv]104: ok
