Re: The psqlodbcw.so will be crashed during connect to postgres server

hi
I got it.
Thanks for you clarify it.

Br
Dinghaiqiang

From: Inoue, Hiroshi [mailto:h-inoue(at)dream(dot)email(dot)ne(dot)jp]
Sent: Tuesday, August 29, 2017 11:34 AM
To: Ding, Haiqiang (NSB - CN/Hangzhou) <haiqiang(dot)ding(at)nokia-sbell(dot)com>
Cc: pgsql-odbc(at)postgresql(dot)org
Subject: Re: [ODBC] The psqlodbcw.so will be crashed during connect to postgres server

Hi,
On 2017/08/28 10:03, Ding, Haiqiang (NSB - CN/Hangzhou) wrote:
hi Hiroshi
Thanks for your correction, it will always avoid the crash.

However, On the other hand, I think we should also refactor the function “handle_pgres_error” , for example:
……
/*
* If the error is continuable after rollback?
*/
if (PQstatus(self->pqconn) == CONNECTION_BAD)
{
CC_set_errornumber(self, CONNECTION_COMMUNICATION_ERROR); ==> DHQ: the function “CC_set_errornumber” can be replaced with “CC_set_error”, so one error number will be mapped to one error message

I'm suspicious if the modification works as you expect because CC_set_error() replaces the current error number and error message unconditionally.
I am planning to change that CC...error.. or SC_...error.. handles multiple error messages in the near future.

BTW I committed a change to git which may improve error messages in case of fast shutdown while connecting.
If you are interested in that, please try it.

regards,
Hiroshi Inoue

CC_on_abort(self, CONN_DEAD); /* give up the connection */
}
else if ((errseverity_nonloc && strcmp(errseverity_nonloc, "FATAL") == 0) ||
(NULL == errseverity_nonloc && errseverity && strcmp(errseverity, "FATAL") == 0)) /* no */
{
CC_set_errornumber(self, CONNECTION_SERVER_REPORTED_SEVERITY_FATAL);
CC_on_abort(self, CONN_DEAD); /* give up the connection */
}
else /* yes */
{
CC_set_errornumber(self, CONNECTION_SERVER_REPORTED_SEVERITY_ERROR);
if (CC_is_in_trans(self))
CC_set_in_error_trans(self);
}
……

What’t your opinion of that ?

Br
Dinghaiqiang

From: Ding, Haiqiang (NSB - CN/Hangzhou)
Sent: Friday, August 25, 2017 11:25 AM
To: 'Inoue, Hiroshi' <h-inoue(at)dream(dot)email(dot)ne(dot)jp><mailto:h-inoue(at)dream(dot)email(dot)ne(dot)jp>
Cc: pgsql-odbc(at)postgresql(dot)org<mailto:pgsql-odbc(at)postgresql(dot)org>
Subject: RE: [ODBC] The psqlodbcw.so will be crashed during connect to postgres server

hi
Thank you very much.

BR
Dinghaiqiang

From: Inoue, Hiroshi [mailto:h-inoue(at)dream(dot)email(dot)ne(dot)jp]
Sent: Friday, August 25, 2017 11:12 AM
To: Ding, Haiqiang (NSB - CN/Hangzhou) <haiqiang(dot)ding(at)nokia-sbell(dot)com<mailto:haiqiang(dot)ding(at)nokia-sbell(dot)com>>
Cc: pgsql-odbc(at)postgresql(dot)org<mailto:pgsql-odbc(at)postgresql(dot)org>
Subject: Re: [ODBC] The psqlodbcw.so will be crashed during connect to postgres server

Hi,
On 2017/08/25 11:21, Ding, Haiqiang (NSB - CN/Hangzhou) wrote:
hi

“Could you build if I update git?”
==>DHQ: Thanks for your reply. But i’m confuse of it, it’s that to say you will correct this issue?
if you can correct it, please send your git link to me about this issue. So I can git pull the patch for our application.

I committed a change to official repository of psqlodbc.
git.postgresql.org/git/postgresql.git

You can also look at the page
https://git.postgresql.org/gitweb/?p=psqlodbc.git;a=summary
.

regards,
Hiroshi Inoue

Thanks.

Br
Dinghaiqiang

From: Inoue, Hiroshi [mailto:h-inoue(at)dream(dot)email(dot)ne(dot)jp]
Sent: Thursday, August 24, 2017 9:35 PM
To: Ding, Haiqiang (NSB - CN/Hangzhou) <haiqiang(dot)ding(at)nokia-sbell(dot)com><mailto:haiqiang(dot)ding(at)nokia-sbell(dot)com>
Cc: pgsql-odbc(at)postgresql(dot)org<mailto:pgsql-odbc(at)postgresql(dot)org>
Subject: Re: [ODBC] The psqlodbcw.so will be crashed during connect to postgres server

Hi,

Thanks for the report.
Could you build if I update git?

regards
Hiroshi Inoue

On 2017/08/24 10:07, Ding, Haiqiang (NSB - CN/Hangzhou) wrote:

hi

psql odbc expert, recently we met an occasional issue that psqlodbcw.so will be crashed during connect the postgres server.
psqlodbcw.so version: psqlodbc-09.05.0400
postgres server version: postgresql-9.6.2

Test step:
1 Start up postgres server
2 Launcher a process which call psqlodbc driver to connect and disconnect postgres server in sequential.
3 Fast shutdown the postgres server, however, the client process will crash occasionally.

Crash information:

Program terminated with signal SIGSEGV, Segmentation fault.
#0 strlen () at ../sysdeps/x86_64/strlen.S:106
106 in ../sysdeps/x86_64/strlen.S
(gdb) bt full
#0 strlen () at ../sysdeps/x86_64/strlen.S:106
No locals.
#1 0x00007f5ede5db7ce in __GI___strdup (s=0x0) at strdup.c:41 ==> if the parameter is null, the “strdup” will crashed
len = <optimized out>
new = <optimized out>
#2 0x00007f5ed40e0c0d in CC_connect (self=0x7f5eb0014740, salt_para=0x7f5ed8d4e3b0 "") at connection.c:1045
ci = 0x7f5eb0014828
func = 0x7f5ed413831f "CC_connect"
ret = 1 '\001'
saverr = 0x0
retsend = 1 '\001'
#3 0x00007f5ed40f3cbd in PGAPI_DriverConnect (hdbc=0x7f5eb0014740, hwnd=0x0,
szConnStrIn=0x7f5eb00026b0 "Driver=PostgreSQL;Server=192.168.1.3;Port=5433;Database=postgreswd;Uid=_nokfssystestpostgres;Pwd=", cbConnStrIn=-3,
0;Protocol=7.4;FakeOidIndex=0;ShowOidColumn=0;RowVersioning=0;ShowSystemTable"..., cbConnStrOutMax=2048, pcbConnStrOut=0x0, fDriverCompletion=1)
at drvconn.c:221
func = 0x7f5ed413a2c0 "PGAPI_DriverConnect"
conn = 0x7f5eb0014740
ci = 0x7f5eb0014828
paramRequired = 0
didUI = 0
result = -11251
connStrIn = 0x0
mes>, "\246\346\027\340^\177", '\000' <repeats 58 times>...
retval = 0
salt = "\000\000\000\000"
len = 0
---Type <return> to continue, or q <return> to quit---
lenStrout = -904
#4 0x00007f5ed4124984 in SQLDriverConnect (hdbc=0x7f5eb0014740, hwnd=0x0,
szConnStrIn=0x7f5eb00026b0 "Driver=PostgreSQL;Server=192.168.1.3;Port=5433;Database=postgreswd;Uid=_nokfssystestpostgres;Pwd=", cbConnStrIn=-3,
0;Protocol=7.4;FakeOidIndex=0;ShowOidColumn=0;RowVersioning=0;ShowSystemTable"..., cbConnStrOutMax=2048, pcbConnStrOut=0x0, fDriverCompletion=1)
at odbcapi.c:190
ret = 0
conn = 0x7f5eb0014740
#5 0x00007f5ee0141309 in SQLDriverConnect () from /usr/lib64/libodbc.so.2
……

The stack information of address (0x7f5eb0014740):

(gdb) p self
$1 = (ConnectionClass *) 0x7f5eb0014740
(gdb) p* self
$2 = {henv = 0x7f5eb0014700, login_timeout = 5, autocommit_public = 1 '\001', stmtOptions = {maxRows = 0, maxLength = 0, keyset_size = 0, cursor_type = 0,
scroll_concurrency = 1, retrieve_data = 1, use_bookmarks = 0, bookmark_ptr = 0x0, metadata_id = 0, stmt_timeout = 0}, ardOptions = {
size_of_rowset = 1, bind_size = 0, row_operation_ptr = 0x0, row_offset_ptr = 0x0, bookmark = 0x0, bindings = 0x0, allocated = 0,
size_of_rowset_odbc2 = 1}, apdOptions = {paramset_size = 1, param_bind_type = 0, param_operation_ptr = 0x0, param_offset_ptr = 0x0, bookmark = 0x0,
parameters = 0x0, allocated = 0, paramset_size_dummy = 1}, __error_message = 0x0, __error_number = 110, sqlstate = "\000\000\000\000\000\000\000",
status = CONN_NOT_CONNECTED, connInfo = {dsn = '\000' <repeats 255 times>, desc = '\000' <repeats 255 times>,
drivername = "PostgreSQL", '\000' <repeats 245 times>, server = "192.168.1.3", '\000' <repeats 244 times>,
database = "postgreswd", '\000' <repeats 245 times>, username = "_nokfssystestpostgres", '\000' <repeats 234 times>, password = {name = 0x0},
port = "5433\000\000\000\000\000", sslmode = "disable\000\000\000\000\000\000\000\000", onlyread = "0\000\000\000\000\000\000\000\000",
fake_oid_index = "0\000\000\000\000\000\000\000\000", show_oid_column = "0\000\000\000\000\000\000\000\000",
row_versioning = "0\000\000\000\000\000\000\000\000", show_system_tables = "0\000\000\000\000\000\000\000\000",
translation_dll = '\000' <repeats 255 times>, translation_option = "\000\000\000\000\000\000\000\000\000", password_required = 0 '\000',
conn_settings = {name = 0x0}, allow_keyset = 1 '\001', updatable_cursors = 0 '\000', lf_conversion = 0 '\000', true_is_minus1 = 0 '\000',
int8_as = 0 '\000', bytea_as_longvarbinary = 0 '\000', use_server_side_prepare = 1 '\001', lower_case_identifier = 0 '\000',
rollback_on_error = -1 '\377', force_abbrev_connstr = 0 '\000', bde_environment = 0 '\000', fake_mss = 0 '\000', cvt_null_date_string = 0 '\000',
accessible_only = 0 '\000', ignore_round_trip_time = 0 '\000', disable_keepalive = 0 '\000', gssauth_use_gssapi = 0 '\000', extra_opts = 0,
keepalive_idle = -1, keepalive_interval = -1, drivers = {drivername = {name = 0x7f5eb0014620 "PostgreSQL Unicode"}, fetch_max = 100,
unknown_sizes = 0, max_varchar_size = 255, max_longvarchar_size = 8190, debug = 0 '\000', commlog = 0 '\000', unique_index = 1 '\001',
onlyread = 0 '\000', use_declarefetch = 0 '\000', text_as_longvarchar = 1 '\001', unknowns_as_longvarchar = 0 '\000', bools_as_char = 1 '\001',
lie = 0 '\000', parse = 0 '\000', extra_systable_prefixes = "dd_", '\000' <repeats 252 times>, protocol = "7.4\000\000\000\000\000\000",
conn_settings = {name = 0x0}}}, stmts = 0x7f5eb0014590, num_stmts = 16, ncursors = 0, pqconn = 0x7f5eb0015800, lobj_type = -999, coli_allocated = 0,
ntables = 0, col_info = 0x0, translation_option = 0, translation_handle = 0x0, DataSourceToDriver = 0x0, DriverToDataSource = 0x0,
transact_status = 1 '\001', pg_version = "9.6.2", '\000' <repeats 122 times>, pg_version_major = 9, pg_version_minor = 6, ms_jet = 0 '\000',
unicode = 0 '\000', result_uncommitted = 0 '\000', lo_is_domain = 0 '\000', original_client_encoding = 0x0, server_encoding = 0x0, ccsc = 0,
mb_maxbyte_per_char = 1, isolation = 2, current_schema = 0x0, current_schema_valid = 0 '\000', unnamed_prepared_stmt = 0x0, max_identifier_length = -1,
num_discardp = 0, discardp = 0x0, num_descs = 16, descs = 0x7f5eb0015280, schemaIns = {name = 0x0}, tableIns = {name = 0x0}, stmt_timeout_in_effect = 0,
cs = {__data = {__lock = 1, __count = 1, __owner = 3492, __nusers = 1, __kind = 1, __spins = 0, __elision = 0, __list = {__prev = 0x0, __next = 0x0}},
__size = "\001\000\000\000\001\000\000\000\244\r\000\000\001\000\000\000\001", '\000' <repeats 22 times>, __align = 4294967297}, slock = {__data = {
__lock = 0, __count = 0, __owner = 0, __nusers = 0, __kind = 1, __spins = 0, __elision = 0, __list = {__prev = 0x0, __next = 0x0}},
__size = '\000' <repeats 16 times>, "\001", '\000' <repeats 22 times>, __align = 0}}

Crash reason:

Following is the part related psqlodbcw.so function “CC_connect”:

……
ret = LIBPQ_CC_connect(self, salt_para);
if (ret <= 0)
return ret;

CC_set_translation(self);

/*
* Send any initial settings
*/

/*
* Since these functions allocate statements, and since the connection
* is not established yet, it would violate odbc state transition
* rules. Therefore, these functions call the corresponding local
* function instead.
*/

/* Global settings */
retsend = CC_send_settings(self, GET_NAME(self->connInfo.drivers.conn_settings));
/* Per Datasource settings */
if (retsend)
retsend = CC_send_settings(self, GET_NAME(self->connInfo.conn_settings));

if (CC_get_errornumber(self) > 0)
saverr = strdup(CC_get_errormsg(self)); ==> Dinghaiqiang: if the errormessage is null, it will cause crashed.
CC_clear_error(self); /* clear any error */
CC_lookup_lo(self); /* a hack to get the oid of
our large object oid type */

……

From the coredump information we know that the function “CC_connect” call “strdup” to copy the errormessage directly when the error number > 0. However the “strdup ” will crash when the parameter is null.

How to generate that error？ we have reproduced this issue and then found following scenarios will cause this crash.

gdb) where
#0 handle_pgres_error (self=0x647490, pgres=0x64d1a0, comment=0x7ffff1934321 "CC_send_query", res=0x64ca60, fatal=0) at connection.c:812
#1 0x00007ffff18dc7c2 in receive_libpq_notice (arg=0x7fffffff6ed0, pgres=0x64d1a0) at connection.c:917
#2 0x00007ffff7537650 in pqGetErrorNotice3 () from /opt/nokia/lib64/libpq.so.5
#3 0x00007ffff753779f in pqParseInput3 () from /opt/nokia/lib64/libpq.so.5
#4 0x00007ffff753131d in PQgetResult () from /opt/nokia/lib64/libpq.so.5
#5 0x00007ffff18defec in CC_send_query_append (self=0x647490, query=0x6609b0 "SET extra_float_digits = 2", qi=0x0, flag=0, stmt=0x64cd80, appendq=0x0) at connection.c:1715
#6 0x00007ffff1917e35 in SC_execute (self=0x64cd80) at statement.c:2006
#7 0x00007ffff18f2193 in Exec_with_parameters_resolved (stmt=0x64cd80, exec_end=0x7fffffff7248) at execute.c:448
#8 0x00007ffff18f3cdf in PGAPI_Execute (hstmt=0x64cd80, flag=0) at execute.c:1077
#9 0x00007ffff18f1ae8 in PGAPI_ExecDirect (hstmt=0x64cd80, szSqlStr=0x64c766 "SET extra_float_digits = 2", cbSqlStr=-3, flag=0) at execute.c:196
#10 0x00007ffff18df8ad in CC_send_settings (self=0x647490, set_query=0x7ffff19338b8 "SET DateStyle = 'ISO';SET extra_float_digits = 2") at connection.c:2178
#11 0x00007ffff18dcb15 in LIBPQ_CC_connect (self=0x647490, salt_para=0x7fffffff7440 "") at connection.c:1005
#12 0x00007ffff18dcb8e in CC_connect (self=0x647490, salt_para=0x7fffffff7440 "") at connection.c:1021
#13 0x00007ffff18efcbd in PGAPI_DriverConnect (hdbc=0x647490, hwnd=0x0,
szConnStrIn=0x619710 "Driver=PostgreSQL;Server=192.168.1.3;Port=5433;Database=DBTestPostgres;Uid=_nokfssystestpostgres;ReadOnly=No;", cbConnStrIn=-3,
szConnStrOut=0x7fffffffa170 "", cbConnStrOutMax=2048, pcbConnStrOut=0x0, fDriverCompletion=1) at drvconn.c:221
#14 0x00007ffff1920964 in SQLDriverConnect (hdbc=0x647490, hwnd=0x0,
szConnStrIn=0x619710 "Driver=PostgreSQL;Server=192.168.1.3;Port=5433;Database=DBTestPostgres;Uid=_nokfssystestpostgres;ReadOnly=No;", cbConnStrIn=-3,
szConnStrOut=0x7fffffffa170 "", cbConnStrOutMax=2048, pcbConnStrOut=0x0, fDriverCompletion=1) at odbcapi.c:190
#15 0x00007ffff775c309 in SQLDriverConnect () from /usr/lib64/libodbc.so.2

And check the function “handle_pgres_error”:
……
if (PQstatus(self->pqconn) == CONNECTION_BAD)
{
CC_set_errornumber(self, CONNECTION_SERVER_REPORTED_ERROR);
abort_opt = CONN_DEAD;
}
else
{
CC_set_errornumber(self, CONNECTION_SERVER_REPORTED_WARNING);
if (fatal && CC_is_in_trans(self))
CC_set_in_error_trans(self);
}
…..

It’s that to say, during the client was ready to connect to postgres server, fast shutdown the postgres server will result to the client receive the notice that from the server. The client will set error number, but not set the error message, it will cause the client crash when call “strdup” which not judge the error message whether it is null.
So this is a bug in this version.

And then I have check the newest version of psqlodbc and found that “CC_connect” and “handle_pgres_error”, it is also have this issue.

The following code is the part of version: psqlodbc-09.06.0410.
Part of function “CC_connect”:
……
if (CC_get_errornumber(self) > 0)
saverr = strdup(CC_get_errormsg(self));
CC_clear_error(self); /* clear any error */
CC_lookup_lo(self); /* a hack to get the oid of
……

Part of function “handle_pgres_error”:

……
/*
* If the error is continuable after rollback?
*/
if (PQstatus(self->pqconn) == CONNECTION_BAD)
{
CC_set_errornumber(self, CONNECTION_COMMUNICATION_ERROR);
CC_on_abort(self, CONN_DEAD); /* give up the connection */
}
else if ((errseverity_nonloc && strcmp(errseverity_nonloc, "FATAL") == 0) ||
(NULL == errseverity_nonloc && errseverity && strcmp(errseverity, "FATAL") == 0)) /* no */
{
CC_set_errornumber(self, CONNECTION_SERVER_REPORTED_SEVERITY_FATAL);
CC_on_abort(self, CONN_DEAD); /* give up the connection */
}
else /* yes */
{
CC_set_errornumber(self, CONNECTION_SERVER_REPORTED_SEVERITY_ERROR);
if (CC_is_in_trans(self))
CC_set_in_error_trans(self);
}
……

The newest version of psqlodbcw also have this issue, could you help to check this issue and correct it ? If you have any correction of that, please reply me, it’s important to us to receive your reply.
The attachment is the odbc driver debug log.

Best regards,

Dinghaiqiang