Bug #107745 ODBC Massive Performance Hit (Regression starting in 8.0.27)
Submitted: 5 Jul 2022 3:30 Modified: 13 Feb 2023 21:24
Reporter: Joseph DeSantis last Email Updates:
Status: Closed Impact on me:
None 
Category:Connector / ODBC Severity:S2 (Serious)
Version:8.0.27 through latest, 8.0.32 OS:Any
Assigned to: CPU Architecture:Any

[5 Jul 2022 3:30] Joseph DeSantis last 
Description:
When upgrading from 8.0.26 to any newer ODBC release I am noticing a ~70% reduction in speed of execution attempting to run the same query. I have the entire environment scripted out below as a dockerfile and docker-compose yaml, so there is no ambiguity.

How to repeat:
I formatted this nicely on stackoverflow: https://stackoverflow.com/questions/72502771/upgrading-mysql-connector-odbc-massively-degr...

But I have broken this down to the smallest repeatable example possible with the following two test files:

docker-compose.yaml:

version: '3.1'

services:
  db:
    image: mysql:8.0.29-debian
    command: --default-authentication-plugin=mysql_native_password
    ports:
      - "3306:3306"
    environment:
      MYSQL_ROOT_PASSWORD: example
  test:
    build: ./

Dockerfile

FROM python:3.10-bullseye

ARG odbcdlurl
RUN { apt-get update && apt install -y unixodbc-dev && wget -qO- $odbcdlurl | tar -xvz -C / --strip-components 1; } && \
    cp /lib/libmyodbc8* /usr/lib/x86_64-linux-gnu/odbc/ && \
    /bin/myodbc-installer -d -a -n "MySQL" -t "DRIVER=/usr/lib/x86_64-linux-gnu/odbc/libmyodbc8w.so;"
RUN pip3 install pyodbc==4.0.32
RUN printf '\n\
import timeit \n\
import pyodbc \n\
mysql_conn = pyodbc.connect("DRIVER=/usr/lib/x86_64-linux-gnu/odbc/libmyodbc8w.so;SERVER=db;DATABASE=sys;UID=root;PWD=example;charset=utf8mb4;") \n\
mysql_cursor = mysql_conn.cursor() \n\
mysql_cursor.execute("SET GLOBAL general_log = 1;") \n\
mysql_cursor.execute("SET global log_output = \x27table\x27;") \n\
mysql_cursor.execute("create temporary table temp(junkvarchar varchar(100));") \n\
start_time = timeit.default_timer() \n\
mysql_cursor.executemany("insert into temp(junkvarchar) values (?)", [("a"*100,) for i in range(100000)]) \n\
print(f"Elapsed Time: {timeit.default_timer() - start_time}") \n\
' >> /test.py
CMD sleep 20 && python3 '/test.py'

How to run the test:
ODBC 8.0.19:
docker-compose down && docker-compose build --build-arg odbcdlurl=https://dev.mysql.com/get/Downloads/Connector-ODBC/8.0/mysql-connector-odbc-8.0.19-linux-g... && docker-compose up
result: ~13 seconds

ODBC 8.0.29:
docker-compose down && docker-compose build --build-arg odbcdlurl=https://dev.mysql.com/get/Downloads/Connector-ODBC/8.0/mysql-connector-odbc-8.0.29-linux-g... && docker-compose up
result: ~21 seconds
[5 Jul 2022 7:18] MySQL Verification Team 
Hello Joseph,

Thank you for the report and feedback.

regards,
Umesh
[5 Jul 2022 13:18] Bogdan Degtyariov 
Hi Joseph,

The bottle neck in this case is the C locale enforcement, which we had to add for compatibility reasons in 8.0.27.
Unfortunately, the process of setting the locale and restoring it back is consuming CPU time. Therefore, executing a large number of queries with parameters one after another had such negative performance impact.

This option can be disabled by adding NO_LOCALE=1 to the connection string.
I run your python code and here are the results:

--------------------------------------------
ODBC Driver 8.0.29 (locale is not disabled):

OS: Windows 10
Python: 3.10.4 (tags/v3.10.4:9d38120, Mar 23 2022, 23:13:41) [MSC v.1929 64 bit (AMD64)]
PyODBC Driver: 4.0.32
Elapsed Time: 13.221230900031514

--------------------------------------------
ODBC Driver 8.0.29 (locale is disabled by using NO_LOCALE=1):

OS: Windows 10
Python: 3.10.4 (tags/v3.10.4:9d38120, Mar 23 2022, 23:13:41) [MSC v.1929 64 bit (AMD64)]
PyODBC Driver: 4.0.32
Elapsed Time: 8.015281299944036

--------------------------------------------
ODBC Driver 8.0.26

OS: Windows 10
Python: 3.10.4 (tags/v3.10.4:9d38120, Mar 23 2022, 23:13:41) [MSC v.1929 64 bit (AMD64)]
PyODBC Driver: 4.0.32
Elapsed Time: 8.08586250001099

As you can see the version 8.0.29 with NO_LOCALE=1 even performed slightly faster than 8.0.26.

This is just a workaround, not a permanent solution.
The driver should be able to manage locales more efficiently.
[5 Jul 2022 15:59] Joseph DeSantis last 
Bogdan Degtyariov, I appreciate you taking a look into this with me.

I am unfortunately not seeing the same results using NO_LOCALE=1
As you suggested I have changed my connection string in my example code above to the following:

DRIVER=/usr/lib/x86_64-linux-gnu/odbc/libmyodbc8w.so;SERVER=db;DATABASE=sys;UID=root;PWD=example;charset=utf8mb4;NO_LOCALE=1

I have also tried with a semicolon at the end:

DRIVER=/usr/lib/x86_64-linux-gnu/odbc/libmyodbc8w.so;SERVER=db;DATABASE=sys;UID=root;PWD=example;charset=utf8mb4;NO_LOCALE=1;

There seems to be no change in performance using NO_LOCAL vs not using it for me on the latest 8.0.29.
[27 Jul 2022 11:31] Bogdan Degtyariov 
Posted by developer:
 
The patch is pushed into release/8.0.31 branch of the source tree.
[10 Aug 2022 18:30] Philip Olson 
Posted by developer:
 
Fixed as of the upcoming MySQL Connector/ODBC 8.0.31 release, and here's the proposed changelog entry from the documentation team:

Improved query parameter support and performance with prepared
statements.

Thank you for the bug report.
[20 Oct 2022 6:05] Joseph DeSantis last 
@Philip Olson @Bogdan Degtyariov
Can you please re-open this bug report.

The ODBC driver 8.0.31 did not fix this problem.
Using the above testing method run the following:

docker-compose down && docker-compose build --build-arg odbcdlurl=https://dev.mysql.com/get/Downloads/Connector-ODBC/8.0/mysql-connector-odbc-8.0.31-linux-g... && docker-compose up

Here are the performance metrics:

8.0.19 timings:
	~ 15 seconds
	
8.0.31 timings:
	~26 seconds

As such the same performance problems are still persisting in the latest release of the ODBC driver.
[20 Oct 2022 7:47] Bogdan Degtyariov 
Hi Joseph,

We used our performance tests that found huge performance impact upon the call to setlocale() function. This was eliminated and out tests showed significant improvements. Same was observed with the python script provided in the bug description. It was not done in docker environment though...

We are reopening the bug since it did not improve the situation for you.
More testing and profiling needs to be done in order to determine the bottleneck.
[25 Jan 2023 2:25] Bogdan Degtyariov 
Posted by developer:
 
The docker testing is producing inconsistent results when 8.0.32 is often outperforming 8.0.19:

8.0.19:
test_1  | Elapsed Time: 7.136530666000908
test_1  | Elapsed Time: 9.754535002997727
test_1  | Elapsed Time: 8.129148177002207

8.0.29:
test_1  | Elapsed Time: 10.258983902000182
test_1  | Elapsed Time: 9.512771303998306
test_1  | Elapsed Time: 8.810006886997144

8.0.32:
test_1  | Elapsed Time: 7.966252436002833
test_1  | Elapsed Time: 8.201184498000657
test_1  | Elapsed Time: 8.034129674000724

However, the general server log for 8.0.29 and 8.0.32 contains "Reset stmt" after each stmt execution whilst 8.0.19 doesn't.
This might have an impact on the execution time.
[27 Jan 2023 2:07] Joseph DeSantis last 
Yes, I do believe the "Reset stmt" could be to blame here.

In order to address the inconsistent results on your local machine, I have created a GitHub Repository with an associated GitHub Actions CI process to automate this Performance testing. I have simply taken the tests provided in my original bug report, automated the running of them via GitHub actions, and then finally reported back the results of the tests in the form of a GitHub comment.

I have included over 10 test runs, all of which still confirm the Massive Performance degradation. 

https://github.com/ILoveMySQL/MySQL-Connector-ODBC-Performance-Testing/pull/1
[27 Jan 2023 2:16] Joseph DeSantis last 
The following URL is a link to more test runs which also confirm the Performance issue is still in the latest version of the ODBC Connector.
https://github.com/ILoveMySQL/MySQL-Connector-ODBC-Performance-Testing/pull/2

In short, there is no indication that this performance issue has gotten better.
Most of our production processes are still running on 2 year + old ODBC versions until we can get this resolved.

I also have updated the impacted versions to include `8.0.32`.
[8 Feb 2023 3:01] Bogdan Degtyariov 
Posted by developer:
 
Two performance issues were identified and fixed in the scope of this patch:

1. The frequent use setlocale() function to enforce the use of '.' character as the decimal separator in SQLFetch() SQLGetData() causing multiple locale switches upon each fetch of the row and getting data for each column in a row, which in some cases resulted in slow-downs up to 60 times. Now setlocale() is only called once on the driver initialization stage, which should not have impact on the ODBC driver performance in all further calls.

2. The use of locale-dependent function std::strtod() was replaced by a custom implementation of the float/double conversion used internally in MySQL Server, which is at least twice faster as std::strtod().
[13 Feb 2023 21:24] Philip Olson 
Posted by developer:
 
Fixed as of the upcoming MySQL Connector/ODBC 8.0.33 release, and here's the proposed changelog entry from the documentation team:

Improved prepared statement performance by decreasing the frequency of
setlocale() calls used to enforce the '.' character as a decimal
separator.

Thank you for the bug report, and thank you for the extensive testing and re-testing.