Uploaded image for project: 'MariaDB Connector/C'
  1. MariaDB Connector/C
  2. CONC-594

Non blocking api appears to be blocking for secure connections

Details

    • Bug
    • Status: Open (View Workflow)
    • Major
    • Resolution: Unresolved
    • 3.1.12
    • None
    • Non blocking API
    • None

    Description

      From https://mariadb.com/kb/en/non-blocking-api-appears-to-be-blocking-for-secure-connections/

      I am encountering delays when using secure connections to AuroraDB, and wondering if the client lib (C-connector) is making lengthy system calls.

      Here is a callstack when not connected (and want to connected):

      #0  0x00007f34ce333394 in __libc_read (fd=227, buf=0x7e3bc664ed93, nbytes=5) at ../sysdeps/unix/sysv/linux/read.c:27
      #1  0x00007f34cd1a8b7e in ?? () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
      #2  0x00007f34cd1a3fba in ?? () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
      #3  0x00007f34cd1a2e53 in ?? () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
      #4  0x00007f34cd1a3403 in BIO_read () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
      #5  0x00007f34cd5e4913 in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.1
      #6  0x00007f34cd5e8fbd in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.1
      #7  0x00007f34cd5e66c2 in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.1
      #8  0x00007f34cd5ed995 in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.1
      #9  0x00007f34cd5f8232 in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.1
      #10 0x00007f34cd5f8353 in SSL_read () from /usr/lib/x86_64-linux-gnu/libssl.so.1.1
      #11 0x00007f34ccec5437 in ma_tls_read_async (pvio=pvio@entry=0x7e3bc6982110, buffer=buffer@entry=0x7e3bc7b9b5b0 "9", length=length@entry=16384) at /mariadb-connector-c-3.1.12-src/libmariadb/secure/openssl.c:589
      #12 0x00007f34cceb54cc in ma_pvio_read (pvio=pvio@entry=0x7e3bc6982110, buffer=0x7e3bc7b9b5b0 "9", length=length@entry=16384) at /mariadb-connector-c-3.1.12-src/libmariadb/ma_pvio.c:228
      #13 0x00007f34cceb56e3 in ma_pvio_cache_read (pvio=0x7e3bc6982110, buffer=buffer@entry=0x7e3bc7291cd0 "\021", length=length@entry=7) at /mariadb-connector-c-3.1.12-src/libmariadb/ma_pvio.c:297
      #14 0x00007f34cceaba76 in ma_real_read (net=net@entry=0x7e13c7594fa8, complen=complen@entry=0x7e3bc756c628) at /mariadb-connector-c-3.1.12-src/libmariadb/ma_net.c:380
      #15 0x00007f34cceac4ac in ma_net_read (net=net@entry=0x7e13c7594fa8) at /mariadb-connector-c-3.1.12-src/libmariadb/ma_net.c:555
      #16 0x00007f34cceb1571 in ma_net_safe_read (mysql=mysql@entry=0x7e13c7594fa8) at /mariadb-connector-c-3.1.12-src/libmariadb/mariadb_lib.c:200
      #17 0x00007f34cceb4ca8 in mthd_my_read_query_result (mysql=0x7e13c7594fa8) at /mariadb-connector-c-3.1.12-src/libmariadb/mariadb_lib.c:2314
      #18 0x00007f34cceb27c2 in mthd_my_real_connect (mysql=0x7e13c7594fa8, host=<optimized out>, user=<optimized out>, passwd=0x7e13c74f03b0 "B1b-_1824b448ffb3f497064872ef54fe1a4a035451c1d8478b71e4ce4ce3e76f4f",
          db=0x7e13c74f1650 "test_gsilt_1m_common_main_xone_Load7d44167e04", port=<optimized out>, unix_socket=<optimized out>, client_flag=2147549344) at /mariadb-connector-c-3.1.12-src/libmariadb/mariadb_lib.c:1678
      #19 0x00007f34cceaf308 in mysql_real_connect (mysql=0x7e13c7594fa8, host=0x7e13c7594f70 "10.94.7.87", user=0x7e13c74f0774 "rwapp_355bf29784", passwd=0x7e13c74f03b0 "B1b-_1824b448ffb3f497064872ef54fe1a4a035451c1d8478b71e4ce4ce3e76f4f",
          db=0x7e13c74f1650 "test_gsilt_1m_common_main_xone_Load7d44167e04", port=3306, unix_socket=0x0, client_flag=2147549184) at /mariadb-connector-c-3.1.12-src/libmariadb/mariadb_lib.c:1295
      #20 0x00007f34cced7031 in mysql_real_connect_start_internal (d=<optimized out>) at /mariadb-connector-c-3.1.12-src/libmariadb/mariadb_async.c:332
      #21 0x00007f34cceda851 in my_context_spawn (c=0x7e3bc69c3000, f=0x7e3bc664ed93, d=0x5) at /mariadb-connector-c-3.1.12-src/libmariadb/ma_context.c:201
      

      and callstack when already connected:

      #0  0x00007ffb4282d394 in __libc_read (fd=232, buf=0x7f023b656033, nbytes=5) at ../sysdeps/unix/sysv/linux/read.c:27
      #1  0x00007ffb416a2b7e in ?? () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
      #2  0x00007ffb4169dfba in ?? () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
      #3  0x00007ffb4169ce53 in ?? () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
      #4  0x00007ffb4169d403 in BIO_read () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
      #5  0x00007ffb41ade913 in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.1
      #6  0x00007ffb41ae2fbd in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.1
      #7  0x00007ffb41ae06c2 in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.1
      #8  0x00007ffb41ae7995 in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.1
      #9  0x00007ffb41af2232 in ?? () from /usr/lib/x86_64-linux-gnu/libssl.so.1.1
      #10 0x00007ffb41af2353 in SSL_read () from /usr/lib/x86_64-linux-gnu/libssl.so.1.1
      #11 0x00007ffb413bf437 in ma_tls_read_async (pvio=pvio@entry=0x7f023b6495f0, buffer=buffer@entry=0x7f023b6fedf0 "\035", length=length@entry=16384) at /mariadb-connector-c-3.1.12-src/libmariadb/secure/openssl.c:589
      #12 0x00007ffb413af4cc in ma_pvio_read (pvio=pvio@entry=0x7f023b6495f0, buffer=0x7f023b6fedf0 "\035", length=length@entry=16384) at /mariadb-connector-c-3.1.12-src/libmariadb/ma_pvio.c:228
      #13 0x00007ffb413af6e3 in ma_pvio_cache_read (pvio=0x7f023b6495f0, buffer=buffer@entry=0x7f023b85e810 "\001", length=length@entry=7) at /mariadb-connector-c-3.1.12-src/libmariadb/ma_pvio.c:297
      #14 0x00007ffb413a5a76 in ma_real_read (net=net@entry=0x7eda3bab9088, complen=complen@entry=0x7f023b898f08) at /mariadb-connector-c-3.1.12-src/libmariadb/ma_net.c:380
      #15 0x00007ffb413a64ac in ma_net_read (net=net@entry=0x7eda3bab9088) at /mariadb-connector-c-3.1.12-src/libmariadb/ma_net.c:555
      #16 0x00007ffb413ab571 in ma_net_safe_read (mysql=mysql@entry=0x7eda3bab9088) at /mariadb-connector-c-3.1.12-src/libmariadb/mariadb_lib.c:200
      #17 0x00007ffb413ad82b in mthd_my_send_cmd (mysql=0x7eda3bab9088, command=<optimized out>, arg=0x7ffb413d8232 "", length=<optimized out>, skipp_check=0 '\000', opt_arg=<optimized out>)
          at /mariadb-connector-c-3.1.12-src/libmariadb/mariadb_lib.c:427
      #18 0x00007ffb413adad8 in mysql_ping (mysql=0x7eda3bab9088) at /mariadb-connector-c-3.1.12-src/libmariadb/mariadb_lib.c:2792
      #19 0x00007ffb413d12e4 in mysql_ping_start_internal (d=<optimized out>) at /mariadb-connector-c-3.1.12-src/libmariadb/mariadb_async.c:1028
      #20 0x00007ffb413d4851 in my_context_spawn (c=0x7f023bb4f480, f=0x7f023b656033, d=0x5) at /mariadb-connector-c-3.1.12-src/libmariadb/ma_context.c:201
      

      Using a more recent version (3.2.6) did not make a difference.

      Attachments

        Activity

          wlad Vladislav Vaintroub created issue -
          georg Georg Richter made changes -
          Field Original Value New Value
          Affects Version/s 3.1.12 [ 25200 ]
          georg Georg Richter added a comment -

          Is there a difference when not using init_command option?

          georg Georg Richter added a comment - Is there a difference when not using init_command option?
          Trakhtenberg Jacob added a comment -

          Removing the use of init_command option appears to have resolved the blocking occurring from 'mysql_real_connect_start_internal'; however, when testing DB failover failure (by having a read slave become unresponsive) the mysql_ping_start_internal still appears to have the same unexpected blocking behavior.

          Trakhtenberg Jacob added a comment - Removing the use of init_command option appears to have resolved the blocking occurring from 'mysql_real_connect_start_internal'; however, when testing DB failover failure (by having a read slave become unresponsive) the mysql_ping_start_internal still appears to have the same unexpected blocking behavior.
          Trakhtenberg Jacob added a comment - - edited

          Hi Georg(georg@mariadb.com) I managed to reproduce several related issues that were causing SSL implementation to block the main thread with async connections. I have made hopefully minimal code changes to address these and have validated that the issues are now all resolved. I am attaching a patch that fixes all the issues found. Please review it and let me know if there are any questions. I hope that this patch (or a variant of it) can be accepted into the mariadb C client library mainline.

          One note, among the issues I have identified/fixed with my patch was a double free that appears to have been since fixed in mainline: https://github.com/mariadb-corporation/mariadb-connector-c/commit/da9bb98c0cef8097ee50341722f08d5042efbe49. That said, I believe that my fix may be more robust than the solution above, so I am still including it.

          Trakhtenberg Jacob added a comment - - edited Hi Georg(georg@mariadb.com) I managed to reproduce several related issues that were causing SSL implementation to block the main thread with async connections. I have made hopefully minimal code changes to address these and have validated that the issues are now all resolved. I am attaching a patch that fixes all the issues found. Please review it and let me know if there are any questions. I hope that this patch (or a variant of it) can be accepted into the mariadb C client library mainline. One note, among the issues I have identified/fixed with my patch was a double free that appears to have been since fixed in mainline: https://github.com/mariadb-corporation/mariadb-connector-c/commit/da9bb98c0cef8097ee50341722f08d5042efbe49 . That said, I believe that my fix may be more robust than the solution above, so I am still including it.
          Trakhtenberg Jacob made changes -
          Attachment mariadb-async-ssl.patch [ 67584 ]
          Trakhtenberg Jacob added a comment -

          In case it's helpful I am including the steps I use to apply the patch to the 3.3.3 version of the MariaDB C client library.

          wget https://downloads.mariadb.com/Connectors/c/connector-c-3.3.3/mariadb-connector-c-3.3.3-src.tar.gz
          tar -xvf mariadb-connector-*.tar.gz
          patch -s -p0 < mariadb-async-ssl.patch
          

          Trakhtenberg Jacob added a comment - In case it's helpful I am including the steps I use to apply the patch to the 3.3.3 version of the MariaDB C client library. wget https://downloads.mariadb.com/Connectors/c/connector-c-3.3.3/mariadb-connector-c-3.3.3-src.tar.gz tar -xvf mariadb-connector-*.tar.gz patch -s -p0 < mariadb-async-ssl.patch
          georg Georg Richter added a comment -

          Hi Jacob,

          thanks for your contribution would it be possible to open a PR on github for your patch?

          Thanks!

          /Georg

          georg Georg Richter added a comment - Hi Jacob, thanks for your contribution would it be possible to open a PR on github for your patch? Thanks! /Georg
          Trakhtenberg Jacob added a comment -

          Hi Georg

          Unfortunately I haven't got a GitHub account setup yet. Is it required to have the patch considered for inclusion? If so, I'll schedule time to setup an account/fork the branch and go through the steps of creating a proper pull request.

          Trakhtenberg Jacob added a comment - Hi Georg Unfortunately I haven't got a GitHub account setup yet. Is it required to have the patch considered for inclusion? If so, I'll schedule time to setup an account/fork the branch and go through the steps of creating a proper pull request.

          No, it's not required, we can apply a patch too. PRs help to provide proper attribution though (you'll be shown as an author).

          serg Sergei Golubchik added a comment - No, it's not required, we can apply a patch too. PRs help to provide proper attribution though (you'll be shown as an author).
          Trakhtenberg Jacob added a comment - - edited

          I created a pull request: https://github.com/mariadb-corporation/mariadb-connector-c/pull/211 but it seems to have failed a newly added unit test. However, when I ran the test locally with my changes it passes.

          The error reported in the unit test: https://app.travis-ci.com/github/mariadb-corporation/mariadb-connector-c/jobs/592736627

          21: # Testing against MySQL Server 10.3.37-MariaDB-1:10.3.37+maria~ubu1804-log
          21: # Host: mariadb.example.com via TCP/IP
          21: # Client library: 3.3.4
          21: ok 1 - test_async
          21: ok 2 - async1
          21: ok 3 - test_conc131
          21: ok 4 - test_conc129
          21: # Expected error when connection to host '0.0.0.0'
          21: not ok 5 - test_conc622
          21: # close default
          21: # Failed 1 tests!
          21/21 Test #21: async ............................***Failed    0.12 sec
          

          Seems to indicate that this code is triggering:

              /* Returns 0 when done, else flag for what to wait for when need to block. */
              status= mysql_real_connect_start(&ret, &mysql, "0.0.0.0", username, password, schema, port, socketname, 0);
              while (status)
              {
                status= wait_for_mysql(&mysql, status);
                status= mysql_real_connect_cont(&ret, &mysql, status);
              }
              if (!ret)
              {
                status= mysql_close_start(&mysql);
                while (status)
                {
                  status= wait_for_mysql(&mysql, status);
                  status= mysql_close_cont(&mysql, status);
                }
              } else {
                diag("Expected error when connection to host '0.0.0.0'");               /// ERROR reported here
                return FAIL;
              }
          

          One thing I am not clear about is why does returning ret != NULL constitute an error in this case when the purpose of the test is to validate connection failure? Probably it would also be good to report the mysq_errno(&mysql) in this case so that it can be determined what precisely is failing.

          Trakhtenberg Jacob added a comment - - edited I created a pull request: https://github.com/mariadb-corporation/mariadb-connector-c/pull/211 but it seems to have failed a newly added unit test. However, when I ran the test locally with my changes it passes. The error reported in the unit test: https://app.travis-ci.com/github/mariadb-corporation/mariadb-connector-c/jobs/592736627 21: # Testing against MySQL Server 10.3.37-MariaDB-1:10.3.37+maria~ubu1804-log 21: # Host: mariadb.example.com via TCP/IP 21: # Client library: 3.3.4 21: ok 1 - test_async 21: ok 2 - async1 21: ok 3 - test_conc131 21: ok 4 - test_conc129 21: # Expected error when connection to host '0.0.0.0' 21: not ok 5 - test_conc622 21: # close default 21: # Failed 1 tests! 21/21 Test #21: async ............................***Failed 0.12 sec Seems to indicate that this code is triggering: /* Returns 0 when done, else flag for what to wait for when need to block. */ status= mysql_real_connect_start(&ret, &mysql, "0.0.0.0", username, password, schema, port, socketname, 0); while (status) { status= wait_for_mysql(&mysql, status); status= mysql_real_connect_cont(&ret, &mysql, status); } if (!ret) { status= mysql_close_start(&mysql); while (status) { status= wait_for_mysql(&mysql, status); status= mysql_close_cont(&mysql, status); } } else { diag("Expected error when connection to host '0.0.0.0'"); /// ERROR reported here return FAIL; } One thing I am not clear about is why does returning ret != NULL constitute an error in this case when the purpose of the test is to validate connection failure? Probably it would also be good to report the mysq_errno(&mysql) in this case so that it can be determined what precisely is failing.
          Trakhtenberg Jacob added a comment -

          Hi Georg, I have managed to address the above issues of failing async.c unit test when run by the travis pipeline. Seems like the usage of 0.0.0.0 IP was causing the connection to succeed due to there being a locally hosted mysql instance that was being successfully connected to, which caused the test to fail to err... fail to connect. Anyhow by changing the ip to 1.2.3.4 it started passing (sort of) I actually had to reduce the number of iterations from 100 to 10 since 100 iterations was running really close to the 180s of running time in travis for some reason. I cannot repro such a long running time locally either for this test.

          Anyhow there is now still one remaining unit test issue that I cannot seem to repro locally, this time in connection.c unit test: test_auth256

          Details are in this pull request but the errors are a bit confusing to me:

          15: # error: Access denied for user 'sha256user'@'172.18.0.1' (using password: YES)
          15: # error: Access denied for user 'sha256user'@'172.18.0.1' (using password: YES)
          15: not ok 23 - test_auth256
          

          It looks like the mysql 5.7 and 8.0 versions of these tests are the only ones failing, but when I run it locally against 5.7.40 MYSQL server it passes for me.

          Would you be able to take a look and let me know if this test passes without my changes?

          Trakhtenberg Jacob added a comment - Hi Georg, I have managed to address the above issues of failing async.c unit test when run by the travis pipeline. Seems like the usage of 0.0.0.0 IP was causing the connection to succeed due to there being a locally hosted mysql instance that was being successfully connected to, which caused the test to fail to err... fail to connect. Anyhow by changing the ip to 1.2.3.4 it started passing (sort of) I actually had to reduce the number of iterations from 100 to 10 since 100 iterations was running really close to the 180s of running time in travis for some reason. I cannot repro such a long running time locally either for this test. Anyhow there is now still one remaining unit test issue that I cannot seem to repro locally, this time in connection.c unit test: test_auth256 Details are in this pull request but the errors are a bit confusing to me: 15: # error: Access denied for user 'sha256user'@'172.18.0.1' (using password: YES) 15: # error: Access denied for user 'sha256user'@'172.18.0.1' (using password: YES) 15: not ok 23 - test_auth256 It looks like the mysql 5.7 and 8.0 versions of these tests are the only ones failing, but when I run it locally against 5.7.40 MYSQL server it passes for me. Would you be able to take a look and let me know if this test passes without my changes?

          Hi Georg, Just following up on the status of this. It would be great to get the changes from the other Jacob ( https://github.com/mariadb-corporation/mariadb-connector-c/pull/216 ) included in a future version.

          JacobC Jacob Cossairt added a comment - Hi Georg, Just following up on the status of this. It would be great to get the changes from the other Jacob ( https://github.com/mariadb-corporation/mariadb-connector-c/pull/216 ) included in a future version.
          georg Georg Richter made changes -
          Component/s Non blocking API [ 19006 ]

          People

            georg Georg Richter
            wlad Vladislav Vaintroub
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

            Dates

              Created:
              Updated:

              Git Integration

                Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.