Thread: Connecting Powerbuilder / EAserver to PostgreSQL server 11 via ODBCor JDBC

Connecting Powerbuilder / EAserver to PostgreSQL server 11 via ODBCor JDBC

From
Matthias Apitz
Date:
Hello,

After the very successful migration of our Library Management System
(which uses ESQL/C, DBI, JDBC) together with PostgreSQL 11.4, we want to do the
same with another LMS written in Powerbuild, running in an EAServer and
currently using Sybase ASE as DBS.

There is an error situation already on the connection phase, the ODBC
debug logs show that the connection establishment and authentication to
the PostgreSQL server is fine (also the disconnect), but the EAServer
makes an error out of this and returns to the Powerbuilder software that
the connection is invalid,
raising some error 999 without saying much in the log files what this
could mean or is caused from.

I know this is difficult to analyze with all this proprietary software
stack, but my first question here is: anybody out here who could manage
such an architecture successful working?

And please do not send hints of the type, rewrite everything in Java or
Visual Basic, as this is not an option :-)

Thanks

    matthias
-- 
Matthias Apitz, ✉ guru@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub



Hi,



On Fri, Jun 26, 2020, 8:31 AM Matthias Apitz <guru@unixarea.de> wrote:

Hello,

After the very successful migration of our Library Management System
(which uses ESQL/C, DBI, JDBC) together with PostgreSQL 11.4, we want to do the
same with another LMS written in Powerbuild, running in an EAServer and
currently using Sybase ASE as DBS.

There is an error situation already on the connection phase, the ODBC
debug logs show that the connection establishment and authentication to
the PostgreSQL server is fine (also the disconnect), but the EAServer
makes an error out of this and returns to the Powerbuilder software that
the connection is invalid,
raising some error 999 without saying much in the log files what this
could mean or is caused from.

So what operation is eroding out?
Can you try to isolate it?

Thank you.


I know this is difficult to analyze with all this proprietary software
stack, but my first question here is: anybody out here who could manage
such an architecture successful working?

And please do not send hints of the type, rewrite everything in Java or
Visual Basic, as this is not an option :-)

Thanks

        matthias
--
Matthias Apitz, ✉ guru@unixarea.de, http://www.unixarea.de/ +49-176-38902045
Public GnuPG key: http://www.unixarea.de/key.pub


On 6/26/20 6:31 AM, Matthias Apitz wrote:
> 
> Hello,
> 
> After the very successful migration of our Library Management System
> (which uses ESQL/C, DBI, JDBC) together with PostgreSQL 11.4, we want to do the
> same with another LMS written in Powerbuild, running in an EAServer and
> currently using Sybase ASE as DBS.
> 
> There is an error situation already on the connection phase, the ODBC
> debug logs show that the connection establishment and authentication to
> the PostgreSQL server is fine (also the disconnect), but the EAServer
> makes an error out of this and returns to the Powerbuilder software that
> the connection is invalid,
> raising some error 999 without saying much in the log files what this
> could mean or is caused from.

A quick search found that this code be returned if the correct server 
type is not specified in EAServer.

> 
> I know this is difficult to analyze with all this proprietary software
> stack, but my first question here is: anybody out here who could manage
> such an architecture successful working?
> 
> And please do not send hints of the type, rewrite everything in Java or
> Visual Basic, as this is not an option :-)
> 
> Thanks
> 
>     matthias
> 


-- 
Adrian Klaver
adrian.klaver@aklaver.com



>
> 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



Item 3 from my previous message is resolved.

For some reason there was a line in the odbc.ini
"ConnSettings = prepareThreshold=0"
I think this is one of the things we have tried and forgot to remove.

After removing it, the application still reports "code: 999,
sqlerrortext: An invalid handle was passed in a call to the database
driver"

This is the new driver log.

[ab1ffb40]   mylog.c[logs_on_off]274: mylog_on=1 qlog_on=0
[ab1ffb40]connection[CC_connect]1069: entering...sslmode=disable
[ab1ffb40]connection[LIBPQ_CC_connect]1041: entering...
[ab1ffb40]connection[CC_initial_log]989: [QLOG]Driver
Version='12.00.0000,Oct 29 2019'
[ab1ffb40]connection[CC_initial_log]1024: DSN = 'PG12', server =
'thehostname', port = '5601', database = 'thedb', username =
'thedb_dbo', password='xxxxx'
[ab1ffb40]connection[LIBPQ_connect]2706: connecting to the database
using thehostname as the server and pqopt={}
[ab1ffb40]connection[LIBPQ_connect]2818: [QLOG]PQconnectdbParams:
host='thehostname' port='5601' dbname='thedb' user='thedb_dbo'
sslmode='disable' password='theDBO'
[ab1ffb40]connection[LIBPQ_connect]2857: libpq connection to the
database established.
[ab1ffb40]connection[LIBPQ_connect]2864: protocol=3
[ab1ffb40]connection[LIBPQ_connect]2871: Server version=12.0.2
[ab1ffb40]connection[LIBPQ_connect]2895: leaving 1
[ab1ffb40]connection[CC_send_query_append]1769: conn=0xab097fd0,
query='SET DateStyle = 'ISO';SET extra_float_digits = 2;show
transaction_isolation'
[ab1ffb40]connection[CC_send_query_append]1849: query_len=75
[ab1ffb40]connection[CC_send_query_append]1892: [QLOG]PQsendQuery:
0xab4f0968 'SET DateStyle = 'ISO';SET extra_float_digits = 2;show
transaction_isolation'
[ab1ffb40] qresult.c[QR_Constructor]173: entering
[ab1ffb40] qresult.c[QR_Constructor]242: leaving
[ab1ffb40]connection[CC_send_query_append]1934: [QLOG] ok: - 'C' - SET
[ab1ffb40]connection[CC_send_query_append]1950:  setting cmdbuffer = 'SET'
[ab1ffb40]connection[CC_send_query_append]2034:  returning res = 0xab4f0638
[ab1ffb40]connection[CC_send_query_append]1934: [QLOG] ok: - 'C' - SET
[ab1ffb40] qresult.c[QR_Constructor]173: entering
[ab1ffb40] qresult.c[QR_Constructor]242: leaving
[ab1ffb40]connection[CC_send_query_append]1950:  setting cmdbuffer = 'SET'
[ab1ffb40]connection[CC_send_query_append]2034:  returning res = 0xab4f0790
[ab1ffb40] qresult.c[QR_Constructor]173: entering
[ab1ffb40] qresult.c[QR_Constructor]242: leaving
[ab1ffb40]connection[CC_send_query_append]2073:  'T' no result_in: res
= 0xab4f5c78
[ab1ffb40] qresult.c[QR_from_PGresult]604: [QLOG] nFields: 1
[ab1ffb40] qresult.c[QR_set_num_fields]40: entering
[ab1ffb40] qresult.c[QR_set_num_fields]44: leaving
[ab1ffb40] qresult.c[QR_from_PGresult]635: [QLOG]
fieldname='transaction_isolation', adtid=25, adtsize=-1, atttypmod=-1
(rel,att)=(0,0)
[ab1ffb40] qresult.c[QR_prepare_for_tupledata]817: REALLOC: old_count
= 0, size = 0
[ab1ffb40] qresult.c[QR_read_tuples_from_pgres]1341: [QLOG] ok: - 'T' - SHOW
[ab1ffb40]connection[handle_show_results]1324: isolation 2 to be 0
[ab1ffb40] qresult.c[QR_Destructor]344: entering
[ab1ffb40] qresult.c[QR_close_result]255: entering
[ab1ffb40] qresult.c[QR_free_memory]479: entering fcount=0
[ab1ffb40] qresult.c[QR_free_memory]577: leaving
[ab1ffb40] qresult.c[QR_free_memory]479: entering fcount=0
[ab1ffb40] qresult.c[QR_free_memory]577: leaving
[ab1ffb40] qresult.c[QR_free_memory]479: entering fcount=1
[ab1ffb40] qresult.c[QR_free_memory]577: leaving
[ab1ffb40] qresult.c[QR_close_result]319: leaving
[ab1ffb40] qresult.c[QR_Destructor]348: leaving
[ab1ffb40]connection[CC_send_settings]2458: entering...
[ab1ffb40]connection[CC_lookup_lo]2518: entering...
[ab1ffb40]connection[CC_send_query_append]1769: conn=0xab097fd0,
query='select oid, typbasetype from pg_type where typname = 'lo''
[ab1ffb40]connection[CC_send_query_append]1849: query_len=57
[ab1ffb40]connection[CC_send_query_append]1892: [QLOG]PQsendQuery:
0xab4f0968 'select oid, typbasetype from pg_type where typname = 'lo''
[ab1ffb40] qresult.c[QR_Constructor]173: entering
[ab1ffb40] qresult.c[QR_Constructor]242: leaving
[ab1ffb40]connection[CC_send_query_append]2055: [QLOG] ok: - 'T' - SELECT 0
[ab1ffb40] qresult.c[QR_from_PGresult]604: [QLOG] nFields: 2
[ab1ffb40] qresult.c[QR_set_num_fields]40: entering
[ab1ffb40] qresult.c[QR_set_num_fields]44: leaving
[ab1ffb40] qresult.c[QR_from_PGresult]635: [QLOG] fieldname='oid',
adtid=26, adtsize=4, atttypmod=-1 (rel,att)=(1247,1)
[ab1ffb40] qresult.c[QR_from_PGresult]635: [QLOG]
fieldname='typbasetype', adtid=26, adtsize=4, atttypmod=-1
(rel,att)=(1247,25)
[ab1ffb40] qresult.c[QR_read_tuples_from_pgres]1341: [QLOG] ok: - 'T' - SELECT 0
[ab1ffb40] qresult.c[QR_Destructor]344: entering
[ab1ffb40] qresult.c[QR_close_result]255: entering
[ab1ffb40] qresult.c[QR_free_memory]479: entering fcount=0
[ab1ffb40] qresult.c[QR_free_memory]577: leaving
[ab1ffb40] qresult.c[QR_close_result]319: leaving
[ab1ffb40] qresult.c[QR_Destructor]348: leaving
[ab1ffb40]connection[CC_lookup_lo]2537: Got the large object oid: -999
[ab1ffb40]connection[CC_determine_locale_encoding]597:
[QLOG]PQparameterStatus(0xab4f0968, "client_encoding")=UTF8
[ab1ffb40]connection[CC_send_query_append]1769: conn=0xab097fd0,
query='set client_encoding to 'SQL_ASCII''
[ab1ffb40]connection[CC_send_query_append]1849: query_len=34
[ab1ffb40]connection[CC_send_query_append]1892: [QLOG]PQsendQuery:
0xab4f0968 'set client_encoding to 'SQL_ASCII''
[ab1ffb40] qresult.c[QR_Constructor]173: entering
[ab1ffb40] qresult.c[QR_Constructor]242: leaving
[ab1ffb40]connection[CC_send_query_append]1934: [QLOG] ok: - 'C' - SET
[ab1ffb40]connection[CC_send_query_append]1950:  setting cmdbuffer = 'SET'
[ab1ffb40]connection[CC_send_query_append]2034:  returning res = 0xab4f0638
[ab1ffb40] qresult.c[QR_Destructor]344: entering
[ab1ffb40] qresult.c[QR_close_result]255: entering
[ab1ffb40] qresult.c[QR_free_memory]479: entering fcount=0
[ab1ffb40] qresult.c[QR_free_memory]577: leaving
[ab1ffb40] qresult.c[QR_close_result]319: leaving
[ab1ffb40] qresult.c[QR_Destructor]348: leaving
[ab1ffb40]connection[CC_connect]1150: conn->unicode=0 Client
Encoding='SQL_ASCII' (Code 0)
[ab1ffb40]connection[CC_connect]1154: leaving...1
[ab1ffb40]dlg_specif[makeConnectString]295: makeConnectString row_versioning=No
[ab1ffb40] drvconn.c[PGAPI_DriverConnect]303: szConnStrOut =

'DSN=PG12;DATABASE=thedb;SERVER=thehostname;PORT=5601;UID=thedb_dbo;PWD=theDBO;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
[ab1ffb40] drvconn.c[PGAPI_DriverConnect]318: leaving 0
[ab1ffb40] odbcapi.c[SQLGetFunctions]476: Entering
[ab1ffb40] odbcapi.c[SQLGetInfo]501: Entering
[ab1ffb40]    info.c[PGAPI_GetInfo]71: entering...fInfoType=77
[ab1ffb40]    info.c[PGAPI_GetInfo]1035: p='03.51', len=0, value=0, cbMax=20
[ab1ffb40] odbcapi.c[SQLGetInfo]501: Entering
[ab1ffb40]    info.c[PGAPI_GetInfo]71: entering...fInfoType=10000
[ab1ffb40]connection[CC_set_error_statements]1222: entering self=0xab097fd0
[ab1ffb40]connection[CC_log_error]2563: CONN ERROR:
func=SQLGetInfo(30), desc='', errnum=209, errmsg='Unrecognized key
passed to PGAPI_GetInfo.'
[ab1ffb40]odbcapi30.[SQLSetConnectAttr]429: Entering 102
[ab1ffb40] pgapi30.c[PGAPI_SetConnectAttr]1658: entering for
0xab097fd0: 102 (nil)
[ab1ffb40] options.c[PGAPI_SetConnectOption]307: entering fOption =
102 vParam = 0
[ab1ffb40] options.c[PGAPI_SetConnectOption]371: AUTOCOMMIT:
transact_status=1, vparam=0
[ab1ffb40]connection[CC_set_autocommit]534:  1->0
[ab1ffb40] odbcapi.c[SQLGetInfo]501: Entering
[ab1ffb40]    info.c[PGAPI_GetInfo]71: entering...fInfoType=46
[ab1ffb40]    info.c[PGAPI_GetInfo]1035: p='<NULL>', len=2, value=2, cbMax=0
[ab1ffb40]odbcapi30.[SQLEndTran]171: Entering
[ab1ffb40] execute.c[PGAPI_Transact]1069: entering hdbc=0xab097fd0, henv=(nil)
[ab1ffb40] odbcapi.c[SQLGetInfo]501: Entering
[ab1ffb40]    info.c[PGAPI_GetInfo]71: entering...fInfoType=23
[ab1ffb40]    info.c[PGAPI_GetInfo]1035: p='<NULL>', len=2, value=2, cbMax=8
[acbc7b40] odbcapi.c[SQLDisconnect]288: Entering for 0xab097fd0
[acbc7b40]connection[PGAPI_Disconnect]212: entering...
[acbc7b40]   mylog.c[logs_on_off]274: mylog_on=1 qlog_on=0
[acbc7b40]connection[PGAPI_Disconnect]227: about to CC_cleanup
[acbc7b40]connection[CC_cleanup]661: entering self=0xab097fd0
[acbc7b40]connection[CC_cleanup]669: [QLOG]PQfinish: 0xab4f0968
[acbc7b40]connection[CC_cleanup]674: after PQfinish
[acbc7b40]dlg_specif[CC_conninfo_init]1714: entering opt=1
[acbc7b40]connection[CC_cleanup]752: leaving
[acbc7b40]connection[PGAPI_Disconnect]232: done CC_cleanup
[acbc7b40]connection[PGAPI_Disconnect]233: leaving...
[acbc7b40]odbcapi30.[SQLFreeHandle]250: Entering
[acbc7b40]connection[PGAPI_FreeConnect]246: entering...hdbc=0xab097fd0
[acbc7b40]connection[CC_Destructor]367: entering self=0xab097fd0
[acbc7b40]connection[CC_cleanup]661: entering self=0xab097fd0
[acbc7b40]connection[CC_cleanup]674: after PQfinish
[acbc7b40]dlg_specif[CC_conninfo_init]1714: entering opt=1
[acbc7b40]connection[CC_cleanup]752: leaving
[acbc7b40]connection[CC_Destructor]374: after CC_Cleanup
[acbc7b40]connection[CC_Destructor]387: after free statement holders
[acbc7b40]connection[CC_Destructor]398: leaving
[acbc7b40]connection[PGAPI_FreeConnect]264: leaving...
[acbc7b40]odbcapi30.[SQLFreeHandle]250: Entering
[acbc7b40] environ.c[PGAPI_FreeEnv]100: entering env=0xab3c52b0
[acbc7b40] environ.c[EN_Destructor]519: entering self=0xab3c52b0
[acbc7b40] environ.c[EN_Destructor]545: clearing conns count=128
[acbc7b40] environ.c[EN_Destructor]557: leaving rv=1
[acbc7b40] environ.c[PGAPI_FreeEnv]104:    ok

Op di 30 jun. 2020 om 22:48 schreef Rene de Gek <renedegek@gmail.com>:
>
> >
> > 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



Hi Adrian,

Thank you for your reply. This was one of the things that Matthias has also suggested to us, referring to
https://sybase.public.easerver.powerbuilder.narkive.com/MsoAXSQJ/problem-connecting-to-database-from-easerver-component.

We do set the server type to ODBC.

The error 999 shows up with several error messages. For example:

When we connect to PostgreSQL using ODBC but we forget to fill in sqlca.DBMS, the application log has 999 without an errortext:

fnv_connect: -1
DBHandle is 0
Setting up n_tr
DBMS:
DBParm: CacheName='pgsqlODBC12'
Autocommit: false
connect using i_tr...
dberror event triggered on n_tr
code: 999
sqlerrortext:
sqlsyntax:
SQLErrText:
sqldbcode: 999
sqlcode: -1

When we try to connect to ODBC, but we set sqlca.DBMS incorrectly to JDBC, the code is 999, but there is a message "sqlerrortext: Java Exception : Fatal Error. Unable to initialize DatabaseMetaData class."

fnv_connect: -1
DBHandle is 0
Setting up n_tr
DBMS: JDBC
DBParm: CacheName='pgsqlODBC12'
Autocommit: false
connect using i_tr...
dberror event triggered on n_tr
code: 999
sqlerrortext: Java Exception : Fatal Error. Unable to initialize
DatabaseMetaData class.
sqlsyntax:
SQLErrText: Java Exception : Fatal Error. Unable to initialize
DatabaseMetaData class.
sqldbcode: 999
sqlcode: -1

When connecting to ODBC using the correct sqlca.DBMS=ODBC, we also get the 999, but with the errortext about the invalid handle.

fnv_connect: -1
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

Unfortunately, it seems that the error 999 can have several causes.

On the EAServer side we have tried all kind of things.
If the connection log from the driver looks okay I am afraid we have ran out of ideas.

Adrian Klaver <adrian.klaver@aklaver.com>wrote:

A quick search found that this code be returned if the correct server
type is not specified in EAServer.

System level call trace might help little bit using strace/truss utility.

Regards,
Virendra Kumar

On Wednesday, July 1, 2020, 9:26:09 PM PDT, Rene de Gek <renedegek@gmail.com> wrote:


Hi Adrian,

Thank you for your reply. This was one of the things that Matthias has also suggested to us, referring to
https://sybase.public.easerver.powerbuilder.narkive.com/MsoAXSQJ/problem-connecting-to-database-from-easerver-component.

We do set the server type to ODBC.

The error 999 shows up with several error messages. For example:

When we connect to PostgreSQL using ODBC but we forget to fill in sqlca.DBMS, the application log has 999 without an errortext:

fnv_connect: -1
DBHandle is 0
Setting up n_tr
DBMS:
DBParm: CacheName='pgsqlODBC12'
Autocommit: false
connect using i_tr...
dberror event triggered on n_tr
code: 999
sqlerrortext:
sqlsyntax:
SQLErrText:
sqldbcode: 999
sqlcode: -1

When we try to connect to ODBC, but we set sqlca.DBMS incorrectly to JDBC, the code is 999, but there is a message "sqlerrortext: Java Exception : Fatal Error. Unable to initialize DatabaseMetaData class."

fnv_connect: -1
DBHandle is 0
Setting up n_tr
DBMS: JDBC
DBParm: CacheName='pgsqlODBC12'
Autocommit: false
connect using i_tr...
dberror event triggered on n_tr
code: 999
sqlerrortext: Java Exception : Fatal Error. Unable to initialize
DatabaseMetaData class.
sqlsyntax:
SQLErrText: Java Exception : Fatal Error. Unable to initialize
DatabaseMetaData class.
sqldbcode: 999
sqlcode: -1

When connecting to ODBC using the correct sqlca.DBMS=ODBC, we also get the 999, but with the errortext about the invalid handle.

fnv_connect: -1
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

Unfortunately, it seems that the error 999 can have several causes.

On the EAServer side we have tried all kind of things.
If the connection log from the driver looks okay I am afraid we have ran out of ideas.

Adrian Klaver <adrian.klaver@aklaver.com>wrote:

A quick search found that this code be returned if the correct server
type is not specified in EAServer.