Re: PostgreSQL, and ODBC statement handles

Hi Reza,

On 2017/05/05 8:47, Reza Taheri wrote:
>
> Hi Hiroshi,
>
> *From:*Inoue, Hiroshi [mailto:h-inoue(at)dream(dot)email(dot)ne(dot)jp]
> *Sent:* Thursday, May 4, 2017 4:20 PM
> *To:* Reza Taheri <rtaheri(at)vmware(dot)com>
> *Cc:* pgsql-odbc(at)postgresql(dot)org
> *Subject:* Re: [ODBC] PostgreSQL, and ODBC statement handles
>
> Hi Reza,
>
> On 2017/05/04 17:15, Inoue, Hiroshi wrote:
>
> Hi Reza,
>
> On 2017/05/04 16:57, Reza Taheri wrote:
>
> On 5/4/17, 12:11 AM, "Inoue, Hiroshi"
> <h-inoue(at)dream(dot)email(dot)ne(dot)jp <mailto:h-inoue(at)dream(dot)email(dot)ne(dot)jp>>
> wrote:
>
> On 2017/05/04 15:17, Reza Taheri wrote:
>
> Hi Hiroshi,
>
> In /etc/odbcinst.ini, I set “Threading = 0”. I
> can see multiple server processes in transaction in the
> backend server. The contention appears to be only for
> access to the statement handle, not actual database
> access. For example, when I replaced looping over
> SQLFetch(stmt) with a single SQLFetchScroll(stmt,
> SQL_FETCH_NEXT, 0), I got better results. Same with
> reducing the frequency of calls to SQLBindCol()
>
> Thanks,
> Reza
>
> On 5/3/17, 10:38 PM, "Inoue, Hiroshi"
> <h-inoue(at)dream(dot)email(dot)ne(dot)jp
> <mailto:h-inoue(at)dream(dot)email(dot)ne(dot)jp>> wrote:
>
> Hi Reza,
>
> How are you setting 'Threading' in odbcinst.ini?
>
> regards,
> Hiroshi
>
> On 2017/05/04 14:08, Reza Taheri wrote:
>
> I am running a benchmark (TPCx-V) with a single
> process on the client system handing all the load.
> Each connection to the server is in a separate thread
> with its own connection to PGSQL, and its own
> connection handle and statement handle. I am facing a
> contention problem with ODBC on the client side.
> strace and perf top show we are serializing over what
> appears to be accesses to the ODBC statement
> handlepgsq. Contention goes away if I use multiple
> processes instead of multiple threads within a process.
>
> I suppose I don’t understand the concept of “handles”
> well, but I am surprised that
>
>
>
> all the threads get the same connection handle number
> and the same statement handle number.
>
>
> Hmm, strange. Can I confirm the situation?
>
> regards,
> Hiroshi Inoue
>
>
> Does that mean some data structure is shared between
> the different threads? Is there a way to force
> different statement handles (or handle numbers???) for
> different threads within one process? I have asked
> this question on the ODBC mailing list, and they
> suggested it could be something in the postgresql
> driver. I can provide detailed performance data, but
> maybe someone can help me figure out what might be a
> very basic configuration or parameter setting problem.
> I am running the following RPMs on RHEL 7.1:
>
> postgresql93-9.3.5-2PGDG.rhel7.x86_64
>
> postgresql93-odbc-09.03.0300-1PGDG.rhel7.x86_64
>
> unixODBC-2.3.1-10.el7.x86_64
>
> Thanks,
> Reza
>
> Hi Hiroshi,
>
> I am not sure what you mean by “Can I confirm the situation”.
> Is there some data you would like me to collect and share?
>
>
> I'd like to see the record of each thread what connection handle
> was allocated and where it was connected to.
>
>
> Or the code how you allocate a connection handle and connect.
>
> regards,
> Hiroshi Inoue
>
> Below is a snippet of code, along with the output I get. Each thread
> maintains simultaneous connections to two databases, and routes each
> transaction to one of them based on the transaction type. So, each
> thread calls this routine twice, hence the two sets of outputs. Also,
> I had noticed that just having an extra statement handle in the thread
> causes a performance slow down. So, the code and output are from when
> I tested this theory by creating 3 statements per connection. I
> normally have only one statement handle per connection. But this
> output is interesting in that it shows (to my untrained eye) that we
> always get the same statement handle number. (I removed the error
> checking from the code fragment to make it more readable)
>
> tid = syscall(SYS_gettid);
>
> sprintf(threadID, "%lu", pthread_self());
>
> tid = syscall(SYS_gettid);
>
> gettimeofday(&tv, NULL);
>
> strftime(ascii_buf, 100, "%b %d %Y %T", localtime(&tv.tv_sec));
>
> printf("%s.%ld: - entered DBConnector.connect()... TID %ld threadID
> %s, dsn_str: <%s>\n", ascii_buf, tv.tv_usec, tid, threadID, dsn_str);
>
> SQLAllocHandle(SQL_HANDLE_ENV, SQL_NULL_HANDLE, &m_env)
>
> SQLSetEnvAttr(m_env, SQL_ATTR_ODBC_VERSION, (void *) SQL_OV_ODBC3, 0)
>
> SQLAllocHandle(SQL_HANDLE_DBC, m_env, &m_dbc)
>

Where do you define m_env, m_dbc or m_stmt?
Don't you define them outside the thread function?

regards,
Hiroshi Inoue

> SQLDriverConnect(m_dbc, NULL, (SQLCHAR *)dsn_str, SQL_NTS,
>
> m_outstr, sizeof(m_outstr), &m_outstrlen,
>
> SQL_DRIVER_COMPLETE);
>
> SQLAllocHandle(SQL_HANDLE_STMT, m_dbc, &m_stmt)
>
> SQLAllocHandle(SQL_HANDLE_STMT, m_dbc, &m_stmt2)
>
> SQLAllocHandle(SQL_HANDLE_STMT, m_dbc, &m_stmt3)
>
> gettimeofday(&tv, NULL);
>
> strftime(ascii_buf, 100, "%b %d %Y %T", localtime(&tv.tv_sec));
>
> sprintf(threadID, "%lu", pthread_self());
>
> printf("%s.%ld: TID %ld threadID %s Connected - Returned connection
> string was:\n\t%s\n", ascii_buf, tv.tv_usec, tid, threadID, m_outstr);
>
> printf("%s.%ld: TID %ld threadID %s m_ret %d, m_env %lld, *m_env %lld,
> m_dbc %lld, *m_dbc %lld, m_stmt %lld *m_stmt %lld, m_stmt2 %lld
> *m_stmt2 %lld *m_stmt3 %lld\n", ascii_buf, tv.tv_usec, tid, threadID,
> m_ret, m_env, *((uint64_t *)m_env), m_dbc, *((uint64_t *)m_dbc),
> m_stmt, *((uint64_t *)m_stmt), m_stmt2, *((uint64_t *)m_stmt2),
> *((uint64_t *)m_stmt3));
>
> And the output:
>
> Apr 13 2017 10:50:00.950259: TID 22623 threadID 139999585187584
> Connected - Returned connection string was:
>
> DSN=PSQL2;DATABASE=tpcv;SERVER=w1-tpcv-vm-50;PORT=5432;UID=tpcv;PWD=tpcv;SSLmode=disable;ReadOnly=0;Protocol=7.4;FakeOidIndex=0;ShowOidColumn=0;RowVersioning=0;ShowSystemTables=0;Conn
>
> Settings=;Fetch=100;Socket=4096;UnknownSizes=0;MaxVarcharSize=255;MaxLongVarcharSize=8190;Debug=0;CommLog=0;Optimizer=0;Ksqo=1;UseDeclareFetch=0;TextAsLongVarchar=1;UnknownsAsLongVarchar=0;Bo
>
> olsAsChar=1;Parse=0;CancelAsFreeStmt=0;ExtraSysTablePrefixes=dd_;;LFConversion=0;UpdatableCursors=1;DisallowPremature=0;TrueIsMinus1=0;BI=0;ByteaAsLongVarBinary=0;UseServerSidePrepare=1;Lower
>
> CaseIdentifier=0;
>
> Apr 13 2017 10:50:00.950259: TID 22623 threadID 139999585187584 m_ret
> 0, m_env 139997344700496, *m_env 19289, m_dbc 139997344702256, *m_dbc
> 19290, m_stmt 139997344865232 *m_stmt 19291, m_stmt
>
> 2 139997344875200 *m_stmt2 19291 *m_stmt3 19291
>
> Apr 13 2017 10:50:00.966972: TID 22623 threadID 139999585187584
> Connected - Returned connection string was:
>
> DSN=PSQL5;DATABASE=tpcv2;SERVER=w1-tpcv-vm-60;PORT=5432;UID=tpcv;PWD=tpcv;SSLmode=disable;ReadOnly=0;Protocol=7.4;FakeOidIndex=0;ShowOidColumn=0;RowVersioning=0;ShowSystemTables=0;Con
>
> nSettings=;Fetch=100;Socket=4096;UnknownSizes=0;MaxVarcharSize=255;MaxLongVarcharSize=8190;Debug=0;CommLog=0;Optimizer=0;Ksqo=1;UseDeclareFetch=0;TextAsLongVarchar=1;UnknownsAsLongVarchar=0;B
>
> oolsAsChar=1;Parse=0;CancelAsFreeStmt=0;ExtraSysTablePrefixes=dd_;;LFConversion=0;UpdatableCursors=1;DisallowPremature=0;TrueIsMinus1=0;BI=0;ByteaAsLongVarBinary=0;UseServerSidePrepare=1;Lowe
>
> rCaseIdentifier=0;
>
> Apr 13 2017 10:50:00.966972: TID 22623 threadID 139999585187584 m_ret
> 0, m_env 139997344893504, *m_env 19289, m_dbc 139997344895264, *m_dbc
> 19290, m_stmt 139997344999312 *m_stmt 19291, m_stmt
>
> 2 139997345008176 *m_stmt2 19291 *m_stmt3 19291
>
> Apr 13 2017 10:50:00.980048: TID 22625 threadID 139999460394752
> Connected - Returned connection string was:
>
> DSN=PSQL2;DATABASE=tpcv;SERVER=w1-tpcv-vm-50;PORT=5432;UID=tpcv;PWD=tpcv;SSLmode=disable;ReadOnly=0;Protocol=7.4;FakeOidIndex=0;ShowOidColumn=0;RowVersioning=0;ShowSystemTables=0;ConnSettings=;Fetch=100;Socket=4096;UnknownSizes=0;MaxVarcharSize=255;MaxLongVarcharSize=8190;Debug=0;CommLog=0;Optimizer=0;Ksqo=1;UseDeclareFetch=0;TextAsLongVarchar=1;UnknownsAsLongVarchar=0;BoolsAsChar=1;Parse=0;CancelAsFreeStmt=0;ExtraSysTablePrefixes=dd_;;LFConversion=0;UpdatableCursors=1;DisallowPremature=0;TrueIsMinus1=0;BI=0;ByteaAsLongVarBinary=0;UseServerSidePrepare=1;LowerCaseIdentifier=0;
>
> Apr 13 2017 10:50:00.980048: TID 22625 threadID 139999460394752 m_ret
> 0, m_env 139997210482768, *m_env 19289, m_dbc 139997210484528, *m_dbc
> 19290, m_stmt 139997210588720 *m_stmt 19291, m_stmt2 139997210598688
> *m_stmt2 19291 *m_stmt3 19291
>
> Apr 13 2017 10:50:00.994637: TID 22625 threadID 139999460394752
> Connected - Returned connection string was:
>
> DSN=PSQL5;DATABASE=tpcv2;SERVER=w1-tpcv-vm-60;PORT=5432;UID=tpcv;PWD=tpcv;SSLmode=disable;ReadOnly=0;Protocol=7.4;FakeOidIndex=0;ShowOidColumn=0;RowVersioning=0;ShowSystemTables=0;ConnSettings=;Fetch=100;Socket=4096;UnknownSizes=0;MaxVarcharSize=255;MaxLongVarcharSize=8190;Debug=0;CommLog=0;Optimizer=0;Ksqo=1;UseDeclareFetch=0;TextAsLongVarchar=1;UnknownsAsLongVarchar=0;BoolsAsChar=1;Parse=0;CancelAsFreeStmt=0;ExtraSysTablePrefixes=dd_;;LFConversion=0;UpdatableCursors=1;DisallowPremature=0;TrueIsMinus1=0;BI=0;ByteaAsLongVarBinary=0;UseServerSidePrepare=1;LowerCaseIdentifier=0;
>
> Apr 13 2017 10:50:00.994637: TID 22625 threadID 139999460394752 m_ret
> 0, m_env 139997210616992, *m_env 19289, m_dbc 139997210618752, *m_dbc
> 19290, m_stmt 139997210722800 *m_stmt 19291, m_stmt2 139997210731664
> *m_stmt2 19291 *m_stmt3 19291
>
> Apr 13 2017 10:50:01.7984: TID 22627 threadID 139999349565184
> Connected - Returned connection string was:
>
> DSN=PSQL2;DATABASE=tpcv;SERVER=w1-tpcv-vm-50;PORT=5432;UID=tpcv;PWD=tpcv;SSLmode=disable;ReadOnly=0;Protocol=7.4;FakeOidIndex=0;ShowOidColumn=0;RowVersioning=0;ShowSystemTables=0;ConnSettings=;Fetch=100;Socket=4096;UnknownSizes=0;MaxVarcharSize=255;MaxLongVarcharSize=8190;Debug=0;CommLog=0;Optimizer=0;Ksqo=1;UseDeclareFetch=0;TextAsLongVarchar=1;UnknownsAsLongVarchar=0;BoolsAsChar=1;Parse=0;CancelAsFreeStmt=0;ExtraSysTablePrefixes=dd_;;LFConversion=0;UpdatableCursors=1;DisallowPremature=0;TrueIsMinus1=0;BI=0;ByteaAsLongVarBinary=0;UseServerSidePrepare=1;LowerCaseIdentifier=0;
>
> Apr 13 2017 10:50:01.7984: TID 22627 threadID 139999349565184 m_ret 0,
> m_env 139997076265040, *m_env 19289, m_dbc 139997076266800, *m_dbc
> 19290, m_stmt 139997076370992 *m_stmt 19291, m_stmt2 139997076380960
> *m_stmt2 19291 *m_stmt3 19291
>
> Apr 13 2017 10:50:01.22112: TID 22627 threadID 139999349565184
> Connected - Returned connection string was:
>
> DSN=PSQL5;DATABASE=tpcv2;SERVER=w1-tpcv-vm-60;PORT=5432;UID=tpcv;PWD=tpcv;SSLmode=disable;ReadOnly=0;Protocol=7.4;FakeOidIndex=0;ShowOidColumn=0;RowVersioning=0;ShowSystemTables=0;ConnSettings=;Fetch=100;Socket=4096;UnknownSizes=0;MaxVarcharSize=255;MaxLongVarcharSize=8190;Debug=0;CommLog=0;Optimizer=0;Ksqo=1;UseDeclareFetch=0;TextAsLongVarchar=1;UnknownsAsLongVarchar=0;BoolsAsChar=1;Parse=0;CancelAsFreeStmt=0;ExtraSysTablePrefixes=dd_;;LFConversion=0;UpdatableCursors=1;DisallowPremature=0;TrueIsMinus1=0;BI=0;ByteaAsLongVarBinary=0;UseServerSidePrepare=1;LowerCaseIdentifier=0;
>
> Apr 13 2017 10:50:01.22112: TID 22627 threadID 139999349565184 m_ret
> 0, m_env 139997076399264, *m_env 19289, m_dbc 139997076401024, *m_dbc
> 19290, m_stmt 139997076505072 *m_stmt 19291, m_stmt2 139997076513936
> *m_stmt2 19291 *m_stmt3 19291
>