Contention problem

classic Classic list List threaded Threaded
12 messages Options
Reply | Threaded
Open this post in threaded view
|

Contention problem

Reza Taheri

I am running into an ODBC performance problem that looks like mutex contention and getting serialized behind some resource. We are experienced performance engineers, but not very experienced with odbc, which we have been using for a few years during the development of this TPC benchmark.

 

We use unixODBC-2.3.4, built with: ./configure --prefix=/usr --sysconfdir=/etc --enable-threads=yes --enable-drivers=yes --enable-driver-conf=yes

 

My config files have:

 

[root@w1-tpcv-vm-49 ~]# cat /etc/odbcinst.ini

# Example driver definitions

 

# Driver from the postgresql-odbc package

# Setup from the unixODBC package

[PostgreSQL]

Description   = ODBC for PostgreSQL

Driver        = /usr/lib/psqlodbcw.so

Setup         = /usr/lib/libodbcpsqlS.so

Driver64      = /usr/pgsql-9.3/lib/psqlodbcw.so

Setup64              = /usr/lib64/libodbcpsqlS.so

FileUsage     = 1

Threading     = 0

[root@w1-tpcv-vm-49 ~]# cat /etc/odbc.ini

[PSQL2]

Description     = PostgreSQL

Driver          = PostgreSQL

Database = tpcv

ServerName = w1-tpcv-vm-50

UserName = tpcv

Password = tpcv

Port            = 5432

 

We have plenty of CPU and disk resources available in our driver, client, and server VMs (all with high vCPU counts) on a dedicated server. As we increase the number of threads of execution in the benchmark, not only doesn’t throughput go up, it actually degrades. Naturally we chased the usual database performance problem suspects, but hit dead ends. We then divided the client workload between 4 separate VMs (all pointing to the same backend server), and got over 5X the throughput. Looking more closely at the client tier, below is what I see in the strace output when everything flows through one VM. The output is almost nothing but futex calls:

17:52:52.763616 futex(0x7fae351c5100, FUTEX_WAKE_PRIVATE, 1)                                        = 1 <0.000076>

17:52:52.763738 futex(0x7fae463a9f00, FUTEX_WAIT_PRIVATE, 2, NULL)                                  = -1 EAGAIN (Resource temporarily unavailable) <0.000016>

17:52:52.763793 futex(0x7fae463a9f00, FUTEX_WAKE_PRIVATE, 1)                                        = 1 <0.000010>

17:52:52.763867 futex(0x7fae351c5100, FUTEX_WAIT_PRIVATE, 2, NULL)                                  = -1 EAGAIN (Resource temporarily unavailable) <0.000038>

17:52:52.763982 futex(0x7fae351c5100, FUTEX_WAKE_PRIVATE, 1)                                        = 1 <0.000037>

17:52:52.764078 futex(0x7fae18000020, FUTEX_WAKE_PRIVATE, 1)                                        = 0 <0.000010>

17:52:52.764182 futex(0x7fae351c5100, FUTEX_WAIT_PRIVATE, 2, NULL)                                  = -1 EAGAIN (Resource temporarily unavailable) <0.000030>

17:52:52.764264 futex(0x7fae351c5100, FUTEX_WAKE_PRIVATE, 1)                                        = 1 <0.000075>

17:52:52.764401 futex(0x7fae351c5100, FUTEX_WAKE_PRIVATE, 1)                                        = 1 <0.000014>

17:52:52.764455 futex(0x7fae351c5100, FUTEX_WAIT_PRIVATE, 2, NULL)                                  = -1 EAGAIN (Resource temporarily unavailable) <0.000011>

17:52:52.764507 futex(0x7fae351c5100, FUTEX_WAKE_PRIVATE, 1)                                        = 1 <0.000025>

17:52:52.764579 futex(0x7fae351c5100, FUTEX_WAKE_PRIVATE, 1)                                        = 1 <0.000010>

17:52:52.764821 sendto(227, "\x51\x00\x00\x00\x0b\x43\x4f\x4d\x4d\x49\x54\x00", 12, MSG_NOSIGNAL, NULL, 0) = 12 <0.000029>

17:52:52.764911 recvfrom(227, 0x7fae18058760, 4096, 16384, 0, 0)                                    = -1 EAGAIN (Resource temporarily unavailable) <0.000107>

17:52:52.765065 poll([{fd=227, events=POLLIN}], 1, 4294967295)                                      = 1 ([{fd=227, revents=POLLIN}]) <0.000017>

17:52:52.765185 recvfrom(227, "\x43\x00\x00\x00\x0b\x43\x4f\x4d\x4d\x49\x54\x00\x5a\x00\x00\x00\x05\x49", 4096, MSG_NOSIGNAL, NULL, NULL) = 18 <0.000018>

17:52:52.765258 futex(0x7fae351c5100, FUTEX_WAIT_PRIVATE, 2, NULL)                                  = 0 <0.000470>

17:52:52.765764 futex(0x7fae351c5100, FUTEX_WAIT_PRIVATE, 2, NULL)                                  = -1 EAGAIN (Resource temporarily unavailable) <0.000052>

17:52:52.765908 futex(0x7fae351c5100, FUTEX_WAKE_PRIVATE, 1)                                        = 1 <0.000073>

 

And perf top shows a similar picture:

 

    9.89%  [kernel]                         [k] _raw_spin_unlock_irqrestore

  4.86%  [kernel]                         [k] finish_task_switch

  3.53%  [kernel]                         [k] _raw_spin_lock

  3.00%  libodbc.so.2.0.0                 [.] __check_stmt_from_dbc_v

  2.80%  [kernel]                         [k] __do_softirq

  2.43%  psqlodbcw.so                     [.] 0x000000000003b146

  1.95%  libodbc.so.2.0.0                 [.] __validate_stmt

  1.93%  libc-2.17.so                     [.] _IO_vfscanf

  1.91%  libodbc.so.2.0.0                 [.] __validate_dbc

  1.90%  psqlodbcw.so                     [.] copy_and_convert_field

  1.80%  libc-2.17.so                     [.] _int_malloc

  1.58%  libc-2.17.so                     [.] malloc

  1.42%  libc-2.17.so                     [.] _int_free

  1.36%  libodbc.so.2.0.0                 [.] __release_desc

 

Any ideas what is going wrong?  This might be a red herring, but the response time degradation appears worse for transactions with a higher number of output parameters and more calls to SQLBindCol() and SQLFetch()

                                                                                                         

Thanks,
Reza

 


_______________________________________________
unixODBC-support mailing list
[hidden email]
http://mailman.unixodbc.org/mailman/listinfo/unixodbc-support
Reply | Threaded
Open this post in threaded view
|

Re: Contention problem

Nick Gorham-2
On 07/04/17 15:19, Reza Taheri wrote:

I am running into an ODBC performance problem that looks like mutex contention and getting serialized behind some resource. We are experienced performance engineers, but not very experienced with odbc, which we have been using for a few years during the development of this TPC benchmark.

 

We use unixODBC-2.3.4, built with: ./configure --prefix=/usr --sysconfdir=/etc --enable-threads=yes --enable-drivers=yes --enable-driver-conf=yes

 

My config files have:

 

[root@w1-tpcv-vm-49 ~]# cat /etc/odbcinst.ini

# Example driver definitions

 

# Driver from the postgresql-odbc package

# Setup from the unixODBC package

[PostgreSQL]

Description   = ODBC for PostgreSQL

Driver        = /usr/lib/psqlodbcw.so

Setup         = /usr/lib/libodbcpsqlS.so

Driver64      = /usr/pgsql-9.3/lib/psqlodbcw.so

Setup64              = /usr/lib64/libodbcpsqlS.so

FileUsage     = 1

Threading     = 0

[root@w1-tpcv-vm-49 ~]# cat /etc/odbc.ini

[PSQL2]

Description     = PostgreSQL

Driver          = PostgreSQL

Database = tpcv

ServerName = w1-tpcv-vm-50

UserName = tpcv

Password = tpcv

Port            = 5432


Probably worth asking the folk who wrote that driver. Are the threads sharing a connection handle? if they are I would expect that the socket that points to would be a limiting factor and expect it to all become serialised behind that.

If you have a single connection and lots of statements, you could make the handle validation quicker by configuring with --enable-fastvalidate

  1.95%  libodbc.so.2.0.0                 [.] __validate_stmt

--
Nick

_______________________________________________
unixODBC-support mailing list
[hidden email]
http://mailman.unixodbc.org/mailman/listinfo/unixodbc-support
Reply | Threaded
Open this post in threaded view
|

Re: Contention problem

Reza Taheri

On 4/7/17, 7:31 AM, Nick Gorham" <[hidden email] on behalf of [hidden email]> wrote:

 

Probably worth asking the folk who wrote that driver. Are the threads sharing a connection handle? if they are I would expect that the socket that points to would be a limiting factor and expect it to all become serialised behind that.

If you have a single connection and lots of statements, you could make the handle validation quicker by configuring with --enable-fastvalidate

  1.95%  libodbc.so.2.0.0                 [.] __validate_stmt

OK, I’ll try --enable-fastvalidate. If by driver you mean the PGSQL ODBC driver psqlodbcw.so, boy chasing the PGSQL folks in not the quick fix I was hoping for . FWIW, if I am running with 80 threads of execution in the benchmark driver, I have 80 threads on the client, and there are 80 new postgres processes on the server. So I didn’t expect any sharing of connection data structures, but clearly something is being shared

 

Thanks,
Reza


_______________________________________________
unixODBC-support mailing list
[hidden email]
http://mailman.unixodbc.org/mailman/listinfo/unixodbc-support
Reply | Threaded
Open this post in threaded view
|

Re: Contention problem

Nick Gorham-2
On 07/04/17 15:57, Reza Taheri wrote:

On 4/7/17, 7:31 AM, Nick Gorham" <[hidden email] on behalf of [hidden email]> wrote:

 

Probably worth asking the folk who wrote that driver. Are the threads sharing a connection handle? if they are I would expect that the socket that points to would be a limiting factor and expect it to all become serialised behind that.

If you have a single connection and lots of statements, you could make the handle validation quicker by configuring with --enable-fastvalidate

  1.95%  libodbc.so.2.0.0                 [.] __validate_stmt

OK, I’ll try --enable-fastvalidate. If by driver you mean the PGSQL ODBC driver psqlodbcw.so, boy chasing the PGSQL folks in not the quick fix I was hoping for . FWIW, if I am running with 80 threads of execution in the benchmark driver, I have 80 threads on the client, and there are 80 new postgres processes on the server. So I didn’t expect any sharing of connection data structures, but clearly something is being shared

 

Thanks,
Reza


Out of interest, try a separate env handle for each thread as well.

--
Nick

_______________________________________________
unixODBC-support mailing list
[hidden email]
http://mailman.unixodbc.org/mailman/listinfo/unixodbc-support
Reply | Threaded
Open this post in threaded view
|

Re: Contention problem

Martin J. Evans
In reply to this post by Reza Taheri
On 07/04/17 15:57, Reza Taheri wrote:

> On 4/7/17, 7:31 AM, Nick Gorham" <[hidden email] <mailto:[hidden email]> on behalf of [hidden email] <mailto:[hidden email]>> wrote:
>
>
>
> Probably worth asking the folk who wrote that driver. Are the threads sharing a connection handle? if they are I would expect that the socket that points to would be a limiting factor and expect it to all become serialised behind that.
>
> If you have a single connection and lots of statements, you could make the handle validation quicker by configuring with --enable-fastvalidate
>
>   1.95%  libodbc.so.2.0.0                 [.] __validate_stmt
>
> OK, I’ll try --enable-fastvalidate. If by driver you mean the PGSQL ODBC driver psqlodbcw.so, boy chasing the PGSQL folks in not the quick fix I was hoping for ☺. FWIW, if I am running with 80 threads of execution in the benchmark driver, I have 80 threads on the client, and there are 80 new postgres processes on the server. So I didn’t expect any sharing of connection data structures, but clearly something is being shared

If you are going to rebuild, make sure you disable stats as well.

Martin

_______________________________________________
unixODBC-support mailing list
[hidden email]
http://mailman.unixodbc.org/mailman/listinfo/unixodbc-support
Reply | Threaded
Open this post in threaded view
|

Re: Contention problem

Reza Taheri
In reply to this post by Nick Gorham-2

On 4/7/17, 8:01 AM, "[hidden email] on behalf of Nick Gorham" <[hidden email] on behalf of [hidden email]> wrote:

 

On 07/04/17 15:57, Reza Taheri wrote:

On 4/7/17, 7:31 AM, Nick Gorham" <[hidden email] on behalf of [hidden email]> wrote:

 

Probably worth asking the folk who wrote that driver. Are the threads sharing a connection handle? if they are I would expect that the socket that points to would be a limiting factor and expect it to all become serialised behind that.

If you have a single connection and lots of statements, you could make the handle validation quicker by configuring with --enable-fastvalidate

  1.95%  libodbc.so.2.0.0                 [.] __validate_stmt


OK, I’ll try --enable-fastvalidate. If by driver you mean the PGSQL ODBC driver psqlodbcw.so, boy chasing the PGSQL folks in not the quick fix I was hoping for . FWIW, if I am running with 80 threads of execution in the benchmark driver, I have 80 threads on the client, and there are 80 new postgres processes on the server. So I didn’t expect any sharing of connection data structures, but clearly something is being shared

 

Thanks,
Reza


Out of interest, try a separate env handle for each thread as well.

--
Nick

 

Just to make sure: do you mean a separate Data Source Name label?

 

Thanks,

Reza

 




_______________________________________________
unixODBC-support mailing list
[hidden email]
http://mailman.unixodbc.org/mailman/listinfo/unixodbc-support
Reply | Threaded
Open this post in threaded view
|

Re: Contention problem

Michael König

Hi!

 

I think he means separate calls to SQLAllocHandle(SQL_HANDLE_ENV, …) (see https://docs.microsoft.com/en-us/sql/odbc/reference/syntax/sqlallochandle-function)

 

Cheers

 

Michael

 

From: <[hidden email]> on behalf of Reza Taheri <[hidden email]>
Reply-To: Support for the unixODBC project <[hidden email]>
Date: Friday, 7. April 2017 at 18:24
To: Support for the unixODBC project <[hidden email]>
Subject: Re: [unixODBC-support] Contention problem

 

On 4/7/17, 8:01 AM, "[hidden email] on behalf of Nick Gorham" <[hidden email] on behalf of [hidden email]> wrote:

 

On 07/04/17 15:57, Reza Taheri wrote:

On 4/7/17, 7:31 AM, Nick Gorham" <[hidden email] on behalf of [hidden email]> wrote:

 

Probably worth asking the folk who wrote that driver. Are the threads sharing a connection handle? if they are I would expect that the socket that points to would be a limiting factor and expect it to all become serialised behind that.

If you have a single connection and lots of statements, you could make the handle validation quicker by configuring with --enable-fastvalidate

  1.95%  libodbc.so.2.0.0                 [.] __validate_stmt



OK, I’ll try --enable-fastvalidate. If by driver you mean the PGSQL ODBC driver psqlodbcw.so, boy chasing the PGSQL folks in not the quick fix I was hoping for . FWIW, if I am running with 80 threads of execution in the benchmark driver, I have 80 threads on the client, and there are 80 new postgres processes on the server. So I didn’t expect any sharing of connection data structures, but clearly something is being shared

 

Thanks,
Reza


Out of interest, try a separate env handle for each thread as well.

--
Nick

 

Just to make sure: do you mean a separate Data Source Name label?

 

Thanks,

Reza

 





_______________________________________________
unixODBC-support mailing list
[hidden email]
http://mailman.unixodbc.org/mailman/listinfo/unixodbc-support
Reply | Threaded
Open this post in threaded view
|

Re: Contention problem

Reza Taheri

We do make a separate call to SQLAllocHandle(SQL_HANDLE_ENV, SQL_NULL_HANDLE, &m_env); and also SQLAllocHandle(SQL_HANDLE_DBC, m_env, &m_dbc); for every thread.  FWIW, we always get 19289 for m_env, and 19290 for m_dbc.  This is even the case when I spread the threads over 5 processes (and get 3X the throughput)

 

I built with -enable-driver-conf=yes --enable-fastvalidate=yes. It got maybe 10% faster.

 

 

From: [hidden email] [mailto:[hidden email]] On Behalf Of Koenig, Michael
Sent: Friday, April 7, 2017 9:31 AM
To: Support for the unixODBC project <[hidden email]>
Subject: Re: [unixODBC-support] Contention problem

 

Hi!

 

I think he means separate calls to SQLAllocHandle(SQL_HANDLE_ENV, …) (see https://docs.microsoft.com/en-us/sql/odbc/reference/syntax/sqlallochandle-function)

 

Cheers

 

Michael

 

From: <[hidden email]> on behalf of Reza Taheri <[hidden email]>
Reply-To: Support for the unixODBC project <
[hidden email]>
Date: Friday, 7. April 2017 at 18:24
To: Support for the unixODBC project <
[hidden email]>
Subject: Re: [unixODBC-support] Contention problem

 

On 4/7/17, 8:01 AM, "[hidden email] on behalf of Nick Gorham" <[hidden email] on behalf of [hidden email]> wrote:

 

On 07/04/17 15:57, Reza Taheri wrote:

On 4/7/17, 7:31 AM, Nick Gorham" <[hidden email] on behalf of [hidden email]> wrote:

 

Probably worth asking the folk who wrote that driver. Are the threads sharing a connection handle? if they are I would expect that the socket that points to would be a limiting factor and expect it to all become serialised behind that.

If you have a single connection and lots of statements, you could make the handle validation quicker by configuring with --enable-fastvalidate

  1.95%  libodbc.so.2.0.0                 [.] __validate_stmt


OK, I’ll try --enable-fastvalidate. If by driver you mean the PGSQL ODBC driver psqlodbcw.so, boy chasing the PGSQL folks in not the quick fix I was hoping for . FWIW, if I am running with 80 threads of execution in the benchmark driver, I have 80 threads on the client, and there are 80 new postgres processes on the server. So I didn’t expect any sharing of connection data structures, but clearly something is being shared

 

Thanks,
Reza


Out of interest, try a separate env handle for each thread as well.

--
Nick

 

Just to make sure: do you mean a separate Data Source Name label?

 

Thanks,

Reza

 




_______________________________________________
unixODBC-support mailing list
[hidden email]
http://mailman.unixodbc.org/mailman/listinfo/unixodbc-support
Reply | Threaded
Open this post in threaded view
|

Re: Contention problem

Nick Gorham-2
On 08/04/17 03:28, Reza Taheri wrote:

We do make a separate call to SQLAllocHandle(SQL_HANDLE_ENV, SQL_NULL_HANDLE, &m_env); and also SQLAllocHandle(SQL_HANDLE_DBC, m_env, &m_dbc); for every thread.  FWIW, we always get 19289 for m_env, and 19290 for m_dbc.  This is even the case when I spread the threads over 5 processes (and get 3X the throughput)

 

I built with -enable-driver-conf=yes --enable-fastvalidate=yes. It got maybe 10% faster.


May be worth trying without the driver manager, try linking directly to the driver.

--
Nick

_______________________________________________
unixODBC-support mailing list
[hidden email]
http://mailman.unixodbc.org/mailman/listinfo/unixodbc-support
Reply | Threaded
Open this post in threaded view
|

Re: Contention problem

Reza Taheri

Sorry Nick, I don’t know what that means. Can you please spell out what I need to do?

 

Thanks,

Reza

 

On 4/8/17, 12:10 AM, "[hidden email] on behalf of Nick Gorham" <[hidden email] on behalf of [hidden email]> wrote:

 

On 08/04/17 03:28, Reza Taheri wrote:

We do make a separate call to SQLAllocHandle(SQL_HANDLE_ENV, SQL_NULL_HANDLE, &m_env); and also SQLAllocHandle(SQL_HANDLE_DBC, m_env, &m_dbc); for every thread.  FWIW, we always get 19289 for m_env, and 19290 for m_dbc.  This is even the case when I spread the threads over 5 processes (and get 3X the throughput)

 

I built with -enable-driver-conf=yes --enable-fastvalidate=yes. It got maybe 10% faster.


May be worth trying without the driver manager, try linking directly to the driver.

--
Nick


_______________________________________________
unixODBC-support mailing list
[hidden email]
http://mailman.unixodbc.org/mailman/listinfo/unixodbc-support
Reply | Threaded
Open this post in threaded view
|

Re: Contention problem

Nick Gorham-2
On 09/04/17 15:59, Reza Taheri wrote:

Sorry Nick, I don’t know what that means. Can you please spell out what I need to do?


Its not always possible or easy, but move the libodbc.so that your app is linked to to a different name, and copy the driver lib to libodbc.so so the app calls the driver directly without the driver manager in the way.

May not work, but is one way of seeing where the bottleneck is.

--
Nick

_______________________________________________
unixODBC-support mailing list
[hidden email]
http://mailman.unixodbc.org/mailman/listinfo/unixodbc-support
Reply | Threaded
Open this post in threaded view
|

Re: Contention problem

Reza Taheri

On 4/9/17, 9:32 AM, "[hidden email] on behalf of Nick Gorham" <[hidden email] on behalf of [hidden email]> wrote:

 

On 09/04/17 15:59, Reza Taheri wrote:

Sorry Nick, I don’t know what that means. Can you please spell out what I need to do?


Its not always possible or easy, but move the libodbc.so that your app is linked to to a different name, and copy the driver lib to libodbc.so so the app calls the driver directly without the driver manager in the way.

May not work, but is one way of seeing where the bottleneck is.

--
Nick

I have narrowed the degradation down to accesses to the stmt returned by SQLAllocHandle(SQL_HANDLE_STMT, ,). If I avoid calling SQLBindCol(stmt, ), SQLFetch(stmt, ), etc., then performance with a single process and multiple threads approaches performance when I run each thread of execution in a separate process. Each thread has its own private copy of “stmt”, its own connection to the database, etc. But we still have contention

 

FWIW, the actual execution of queries is not serialized. I can see many transactions in flight on the postgres backend. The contention appears to be for accesses to data structures. Also, SQLBindCol(stmt, ), SQLFetch(stmt, ), etc are fast with a small number of threads, or when we run them in different processes

 

It seems to me that your original suggestion of using different handles would have avoided all this. But it looks like the driver insists on giving me the same environment/connection/statement handles for all the threads in a process

 

Thanks,
Reza


_______________________________________________
unixODBC-support mailing list
[hidden email]
http://mailman.unixodbc.org/mailman/listinfo/unixodbc-support