Open clawster opened 5 years ago
# /var/lib/proxysql.log contents
Main phase3 : GloAdmin initialized in 0.016581 secs.
Standard Query Processor rev. 2.0.6.0805_DEBUG -- Query_Processor.cpp -- Tue Aug 13 13:32:45 2019
Main phase3 : Query Processor initialized in 0.001024 secs.
Main phase3 : MySQL Threads Handler initialized in 0.000189 secs.
In memory Standard Query Cache (SQC) rev. 1.2.0905_DEBUG -- Query_Cache.cpp -- Tue Aug 13 13:32:45 2019
Main phase3 : Query Cache initialized in 0.000454 secs.
2019-09-09 06:54:46 MySQL_Logger.cpp:518:events_open_log_unlocked(): [INFO] Starting new mysql event log file /var/lib/proxysql/queries.log.00000005
Main phase3 : MySQL Threads Handler listeners started in 0.000197 secs.
Standard MySQL Monitor (StdMyMon) rev. 2.0.1226_DEBUG -- MySQL_Monitor.cpp -- Tue Aug 13 13:32:45 2019
Main phase3 : MySQL Monitor initialized in 0.000247 secs.
Main init phase3 completed in 0.03962 secs.
2019-09-09 06:55:10 ProxySQL_GloVars.cpp:9:term_handler(): [WARNING] Received TERM signal: shutdown in progress...
2019-09-09 06:55:10 main.cpp:1675:main(): [INFO] Starting shutdown...
GloMTH joined in 0.010018 secs.
GloMyMon joined in 0.16201 secs.
GloQC joined in 0.181502 secs.
All threads joined in 0.35359 secs.
GloMyMon shutdown in 0.000441 secs.
GloQC shutdown in 0.000101 secs.
GloQPro shutdown in 0.000118 secs.
GloMyAuth shutdown in 8.2e-05 secs.
GloMTH shutdown in 8.2e-05 secs.
GloMyLogger shutdown in 1.1e-05 secs.
GloAdmin shutdown in 0.005596 secs.
GloHGM shutdown in 0.004471 secs.
Main init phase4 shutdown completed in 0.364596 secs.
2019-09-09 06:55:10 main.cpp:1679:main(): [INFO] Shutdown completed!
2019-09-09 06:55:10 main.cpp:1692:main(): [INFO] Exiting...
2019-09-09 06:55:10 main.cpp:1382:ProxySQL_daemonize_phase3(): [INFO] Shutdown angel process
# journalctl -u proxysql
Sep 09 06:54:45 proxysql systemd[1]: Stopping High Performance Advanced Proxy for MySQL...
Sep 09 06:54:45 proxysql systemd[1]: proxysql.service: Succeeded.
Sep 09 06:54:45 proxysql systemd[1]: Stopped High Performance Advanced Proxy for MySQL.
Sep 09 06:54:45 proxysql systemd[1]: Starting High Performance Advanced Proxy for MySQL...
Sep 09 06:54:45 proxysql proxysql[26975]: 2019-09-09 06:54:45 main.cpp:703:ProxySQL_Main_process_global_variables(): [INFO] Using config file /etc/proxysql.cnf
Sep 09 06:54:45 proxysql proxysql[26975]: Main init global variables completed in 0.000657 secs.
Sep 09 06:54:45 proxysql proxysql[26975]: List of cipher avaiable:
Sep 09 06:54:45 proxysql proxysql[26975]: TLS_AES_256_GCM_SHA384: TLS_AES_256_GCM_SHA384 TLSv1.3 Kx=any Au=any Enc=AESGCM(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: TLS_CHACHA20_POLY1305_SHA256: TLS_CHACHA20_POLY1305_SHA256 TLSv1.3 Kx=any Au=any Enc=CHACHA20/POLY1305(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: TLS_AES_128_GCM_SHA256: TLS_AES_128_GCM_SHA256 TLSv1.3 Kx=any Au=any Enc=AESGCM(128) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-ECDSA-AES256-GCM-SHA384: ECDHE-ECDSA-AES256-GCM-SHA384 TLSv1.2 Kx=ECDH Au=ECDSA Enc=AESGCM(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-RSA-AES256-GCM-SHA384: ECDHE-RSA-AES256-GCM-SHA384 TLSv1.2 Kx=ECDH Au=RSA Enc=AESGCM(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: DHE-RSA-AES256-GCM-SHA384: DHE-RSA-AES256-GCM-SHA384 TLSv1.2 Kx=DH Au=RSA Enc=AESGCM(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-ECDSA-CHACHA20-POLY1305: ECDHE-ECDSA-CHACHA20-POLY1305 TLSv1.2 Kx=ECDH Au=ECDSA Enc=CHACHA20/POLY1305(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-RSA-CHACHA20-POLY1305: ECDHE-RSA-CHACHA20-POLY1305 TLSv1.2 Kx=ECDH Au=RSA Enc=CHACHA20/POLY1305(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: DHE-RSA-CHACHA20-POLY1305: DHE-RSA-CHACHA20-POLY1305 TLSv1.2 Kx=DH Au=RSA Enc=CHACHA20/POLY1305(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-ECDSA-AES128-GCM-SHA256: ECDHE-ECDSA-AES128-GCM-SHA256 TLSv1.2 Kx=ECDH Au=ECDSA Enc=AESGCM(128) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-RSA-AES128-GCM-SHA256: ECDHE-RSA-AES128-GCM-SHA256 TLSv1.2 Kx=ECDH Au=RSA Enc=AESGCM(128) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: DHE-RSA-AES128-GCM-SHA256: DHE-RSA-AES128-GCM-SHA256 TLSv1.2 Kx=DH Au=RSA Enc=AESGCM(128) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-ECDSA-AES256-SHA384: ECDHE-ECDSA-AES256-SHA384 TLSv1.2 Kx=ECDH Au=ECDSA Enc=AES(256) Mac=SHA384
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-RSA-AES256-SHA384: ECDHE-RSA-AES256-SHA384 TLSv1.2 Kx=ECDH Au=RSA Enc=AES(256) Mac=SHA384
Sep 09 06:54:45 proxysql proxysql[26975]: DHE-RSA-AES256-SHA256: DHE-RSA-AES256-SHA256 TLSv1.2 Kx=DH Au=RSA Enc=AES(256) Mac=SHA256
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-ECDSA-AES128-SHA256: ECDHE-ECDSA-AES128-SHA256 TLSv1.2 Kx=ECDH Au=ECDSA Enc=AES(128) Mac=SHA256
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-RSA-AES128-SHA256: ECDHE-RSA-AES128-SHA256 TLSv1.2 Kx=ECDH Au=RSA Enc=AES(128) Mac=SHA256
Sep 09 06:54:45 proxysql proxysql[26975]: DHE-RSA-AES128-SHA256: DHE-RSA-AES128-SHA256 TLSv1.2 Kx=DH Au=RSA Enc=AES(128) Mac=SHA256
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-ECDSA-AES256-SHA: ECDHE-ECDSA-AES256-SHA TLSv1 Kx=ECDH Au=ECDSA Enc=AES(256) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-RSA-AES256-SHA: ECDHE-RSA-AES256-SHA TLSv1 Kx=ECDH Au=RSA Enc=AES(256) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: DHE-RSA-AES256-SHA: DHE-RSA-AES256-SHA SSLv3 Kx=DH Au=RSA Enc=AES(256) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-ECDSA-AES128-SHA: ECDHE-ECDSA-AES128-SHA TLSv1 Kx=ECDH Au=ECDSA Enc=AES(128) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-RSA-AES128-SHA: ECDHE-RSA-AES128-SHA TLSv1 Kx=ECDH Au=RSA Enc=AES(128) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: DHE-RSA-AES128-SHA: DHE-RSA-AES128-SHA SSLv3 Kx=DH Au=RSA Enc=AES(128) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: RSA-PSK-AES256-GCM-SHA384: RSA-PSK-AES256-GCM-SHA384 TLSv1.2 Kx=RSAPSK Au=RSA Enc=AESGCM(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: DHE-PSK-AES256-GCM-SHA384: DHE-PSK-AES256-GCM-SHA384 TLSv1.2 Kx=DHEPSK Au=PSK Enc=AESGCM(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: RSA-PSK-CHACHA20-POLY1305: RSA-PSK-CHACHA20-POLY1305 TLSv1.2 Kx=RSAPSK Au=RSA Enc=CHACHA20/POLY1305(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: DHE-PSK-CHACHA20-POLY1305: DHE-PSK-CHACHA20-POLY1305 TLSv1.2 Kx=DHEPSK Au=PSK Enc=CHACHA20/POLY1305(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-PSK-CHACHA20-POLY1305: ECDHE-PSK-CHACHA20-POLY1305 TLSv1.2 Kx=ECDHEPSK Au=PSK Enc=CHACHA20/POLY1305(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: AES256-GCM-SHA384: AES256-GCM-SHA384 TLSv1.2 Kx=RSA Au=RSA Enc=AESGCM(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: PSK-AES256-GCM-SHA384: PSK-AES256-GCM-SHA384 TLSv1.2 Kx=PSK Au=PSK Enc=AESGCM(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: PSK-CHACHA20-POLY1305: PSK-CHACHA20-POLY1305 TLSv1.2 Kx=PSK Au=PSK Enc=CHACHA20/POLY1305(256) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: RSA-PSK-AES128-GCM-SHA256: RSA-PSK-AES128-GCM-SHA256 TLSv1.2 Kx=RSAPSK Au=RSA Enc=AESGCM(128) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: DHE-PSK-AES128-GCM-SHA256: DHE-PSK-AES128-GCM-SHA256 TLSv1.2 Kx=DHEPSK Au=PSK Enc=AESGCM(128) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: AES128-GCM-SHA256: AES128-GCM-SHA256 TLSv1.2 Kx=RSA Au=RSA Enc=AESGCM(128) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: PSK-AES128-GCM-SHA256: PSK-AES128-GCM-SHA256 TLSv1.2 Kx=PSK Au=PSK Enc=AESGCM(128) Mac=AEAD
Sep 09 06:54:45 proxysql proxysql[26975]: AES256-SHA256: AES256-SHA256 TLSv1.2 Kx=RSA Au=RSA Enc=AES(256) Mac=SHA256
Sep 09 06:54:45 proxysql proxysql[26975]: AES128-SHA256: AES128-SHA256 TLSv1.2 Kx=RSA Au=RSA Enc=AES(128) Mac=SHA256
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-PSK-AES256-CBC-SHA384: ECDHE-PSK-AES256-CBC-SHA384 TLSv1 Kx=ECDHEPSK Au=PSK Enc=AES(256) Mac=SHA384
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-PSK-AES256-CBC-SHA: ECDHE-PSK-AES256-CBC-SHA TLSv1 Kx=ECDHEPSK Au=PSK Enc=AES(256) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: SRP-RSA-AES-256-CBC-SHA: SRP-RSA-AES-256-CBC-SHA SSLv3 Kx=SRP Au=RSA Enc=AES(256) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: SRP-AES-256-CBC-SHA: SRP-AES-256-CBC-SHA SSLv3 Kx=SRP Au=SRP Enc=AES(256) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: RSA-PSK-AES256-CBC-SHA384: RSA-PSK-AES256-CBC-SHA384 TLSv1 Kx=RSAPSK Au=RSA Enc=AES(256) Mac=SHA384
Sep 09 06:54:45 proxysql proxysql[26975]: DHE-PSK-AES256-CBC-SHA384: DHE-PSK-AES256-CBC-SHA384 TLSv1 Kx=DHEPSK Au=PSK Enc=AES(256) Mac=SHA384
Sep 09 06:54:45 proxysql proxysql[26975]: RSA-PSK-AES256-CBC-SHA: RSA-PSK-AES256-CBC-SHA SSLv3 Kx=RSAPSK Au=RSA Enc=AES(256) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: DHE-PSK-AES256-CBC-SHA: DHE-PSK-AES256-CBC-SHA SSLv3 Kx=DHEPSK Au=PSK Enc=AES(256) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: AES256-SHA: AES256-SHA SSLv3 Kx=RSA Au=RSA Enc=AES(256) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: PSK-AES256-CBC-SHA384: PSK-AES256-CBC-SHA384 TLSv1 Kx=PSK Au=PSK Enc=AES(256) Mac=SHA384
Sep 09 06:54:45 proxysql proxysql[26975]: PSK-AES256-CBC-SHA: PSK-AES256-CBC-SHA SSLv3 Kx=PSK Au=PSK Enc=AES(256) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-PSK-AES128-CBC-SHA256: ECDHE-PSK-AES128-CBC-SHA256 TLSv1 Kx=ECDHEPSK Au=PSK Enc=AES(128) Mac=SHA256
Sep 09 06:54:45 proxysql proxysql[26975]: ECDHE-PSK-AES128-CBC-SHA: ECDHE-PSK-AES128-CBC-SHA TLSv1 Kx=ECDHEPSK Au=PSK Enc=AES(128) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: SRP-RSA-AES-128-CBC-SHA: SRP-RSA-AES-128-CBC-SHA SSLv3 Kx=SRP Au=RSA Enc=AES(128) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: SRP-AES-128-CBC-SHA: SRP-AES-128-CBC-SHA SSLv3 Kx=SRP Au=SRP Enc=AES(128) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: RSA-PSK-AES128-CBC-SHA256: RSA-PSK-AES128-CBC-SHA256 TLSv1 Kx=RSAPSK Au=RSA Enc=AES(128) Mac=SHA256
Sep 09 06:54:45 proxysql proxysql[26975]: DHE-PSK-AES128-CBC-SHA256: DHE-PSK-AES128-CBC-SHA256 TLSv1 Kx=DHEPSK Au=PSK Enc=AES(128) Mac=SHA256
Sep 09 06:54:45 proxysql proxysql[26975]: RSA-PSK-AES128-CBC-SHA: RSA-PSK-AES128-CBC-SHA SSLv3 Kx=RSAPSK Au=RSA Enc=AES(128) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: DHE-PSK-AES128-CBC-SHA: DHE-PSK-AES128-CBC-SHA SSLv3 Kx=DHEPSK Au=PSK Enc=AES(128) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: AES128-SHA: AES128-SHA SSLv3 Kx=RSA Au=RSA Enc=AES(128) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: PSK-AES128-CBC-SHA256: PSK-AES128-CBC-SHA256 TLSv1 Kx=PSK Au=PSK Enc=AES(128) Mac=SHA256
Sep 09 06:54:45 proxysql proxysql[26975]: PSK-AES128-CBC-SHA: PSK-AES128-CBC-SHA SSLv3 Kx=PSK Au=PSK Enc=AES(128) Mac=SHA1
Sep 09 06:54:45 proxysql proxysql[26975]: 2019-09-09 06:54:45 main.cpp:447:ssl_mkit(): [INFO] SSL keys/certificates found in datadir (/var/lib/proxysql): loading them.
Sep 09 06:54:45 proxysql proxysql[26975]: Main SSL init variables completed in 0.00417 secs.
Sep 09 06:54:45 proxysql proxysql[26975]: SHA1 generated in 0.031291 secs.
Sep 09 06:54:45 proxysql proxysql[26975]: Main daemonize phase1 completed in 7.8e-05 secs.
Sep 09 06:54:45 proxysql systemd[1]: Started High Performance Advanced Proxy for MySQL.
Sep 09 06:55:10 proxysql systemd[1]: Stopping High Performance Advanced Proxy for MySQL...
Sep 09 06:55:10 proxysql systemd[1]: proxysql.service: Succeeded.
Sep 09 06:55:10 proxysql systemd[1]: Stopped High Performance Advanced Proxy for MySQL.
Hi. Does this happen with a regular mysql cli client? Or some other client? We need to reproduce it
I can easily reproduce it. Thank you for the report.
ProxySQL 2.0.3 , using openssl-1.1.0h , it is not affected. So it is likely that the issues is related to upgrade to openssl-1.1.1b in ProxySQL 2.0.4 . Investigating
When there is no data queued to be sent:
Implementation of BIO_read()
in OpenSSL has changed, causing this bug
We opted to downgrade openssl back to 1.1.0h .
@clawster : thank you again for the report!
@pondix : our automated tests do not show this sort of regression because they run benchmark and do not evaluate CPU usage in idle or mostly idle conditions. We need to improve that. Let's leave this issue open until we are also able to test this.
@renecannao : Thanks for the quick response! Glad I could contribute. Keep up the good work :+1:
Closing this as solve. @clawster : thank you again!
I still have this problem in v2.0.12, with an environment without SSL everything is fine, as soon as there is SSL the ProxySQL servers go up to 200% and it becomes impossible to see the processlists.
The other problem I encounter when enabling SSL is requests that return ECONNRESET after fifteen minutes of inactivity.
Reopening, as "ECONNRESET after fifteen minutes of inactivity" hints some further debugging
I have run in to a problem that as soon as a client connects to the frontend with SSL the proxysql process consumes 100% cpu.
But when the SSL based connection is terminated, the CPU drops down to 1-2%.
I have tried with the following binary distributions
Some notes...
Backend is AWS Aurora (using ssl). But that part seems to be working fine.
It does not seem to be related to hardware (tried t3a.nano and c5.large without any success).
The issue can reproduced with the following simple setup.
PROXYSQL ADMIN