rickymarini
commented
2 years ago Hi @renecannao and Team would be great to have your opinion on this. Many thanks
Open rickymarini opened 2 years ago
rickymarini
commented
2 years ago Hi @renecannao and Team would be great to have your opinion on this. Many thanks
renecannao
commented
2 years ago Hi @rickymarini . Thank you for the detailed report, I really apreciate the level of details.
You provided the tcpdump session between proxysql and the database server: thanks for that. Can you please provide also the tcpdump of the traffic between the client and proxysql, and again between proxysql and the database server? From proxysql's error log I suspect the client is sending a COMMIT without waiting the OK after sending the INSERT.
Also, since you are using a private network (10.x) , can you please not obfuscate the full IP address, so it makes easier to understand who originates the packet? Again, 10.x is a private network, so there is no security concern in making this information public.
Thanks
rickymarini
commented
2 years ago Hi @renecannao , thanks for looking at this. The tcpdump session I provided is already between client and proxysql (port 2035). Unluckily I am unable to get a trace between proxysql and backend since we don't have permission to do that on k8s network (db's and proxysql are hosted there). For that reason I enabled query logging on db's and provided queries that actually reach the final db instance. I did some further analysis and I see that the problem may be also related to JDBC DBCP datasource. As far as I understand, having client application that is doing pooling, and also having it proxysql side may create some problems. I read some bug report specific to this setup, involving Druid application. I tried to set fast_forward to true for user, but then the error I got is
Caused by: java.sql.SQLNonTransientConnectionException: Could not connect to address=(host=mysql-router.app-test.example.net)(port=2035)(type=master) : unexpected end of stream, read 0 bytes from 4 (socket was closed by server)This is the tcpdump trace with actual IP addresses. From client to proxySQL. Capture is on port 2035, the external port we use to connect proxysql or mysql-router.
additional detail Everything works fine for ~20 minutes using defaults, then transaction problem starts and keeps popping every few seconds. Seems like the client become stuck in it. I observed that the client is logging a different connection id each and every time.
Caused by: org.skife.jdbi.v2.exceptions.CallbackFailedException: org.skife.jdbi.v2.exceptions.UnableToManipulateTransactionIsolationLevelException: Unable to set isolation level to 2
Caused by: org.skife.jdbi.v2.exceptions.UnableToManipulateTransactionIsolationLevelException: Unable to set isolation level to 2
Caused by: java.sql.SQLNonTransientConnectionException: (conn=700) (conn=700) Connection is closed
Caused by: java.sql.SQLNonTransientConnectionException: (conn=700) Connection is closed
Caused by: org.skife.jdbi.v2.exceptions.CallbackFailedException: org.skife.jdbi.v2.exceptions.UnableToManipulateTransactionIsolationLevelException: Unable to set isolation level to 2
Caused by: org.skife.jdbi.v2.exceptions.UnableToManipulateTransactionIsolationLevelException: Unable to set isolation level to 2
Caused by: java.sql.SQLNonTransientConnectionException: (conn=704) (conn=704) Connection is closed
Caused by: java.sql.SQLNonTransientConnectionException: (conn=704) Connection is closed
Caused by: org.skife.jdbi.v2.exceptions.CallbackFailedException: org.skife.jdbi.v2.exceptions.UnableToManipulateTransactionIsolationLevelException: Unable to set isolation level to 2
Caused by: org.skife.jdbi.v2.exceptions.UnableToManipulateTransactionIsolationLevelException: Unable to set isolation level to 2
Caused by: java.sql.SQLNonTransientConnectionException: (conn=698) (conn=698) Connection is closed
Caused by: java.sql.SQLNonTransientConnectionException: (conn=698) Connection is closedwhile proxysql logs is like
2022-05-24 11:26:38 MySQL_Session.cpp:149:kill_query_thread(): [WARNING] KILL CONNECTION 76219 on server-2.example.net:3306
2022-05-24 11:26:39 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 10682367 Disconnecting it
2022-05-24 11:26:39 MySQL_Session.cpp:149:kill_query_thread(): [WARNING] KILL CONNECTION 76222 on server-2.example.net:3306
2022-05-24 11:26:40 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 10682367 Disconnecting it
2022-05-24 11:26:40 MySQL_Session.cpp:149:kill_query_thread(): [WARNING] KILL CONNECTION 76224 on server-2.example.net:3306
2022-05-24 11:26:44 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 11 Disconnecting it
2022-05-24 11:26:45 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 0 Disconnecting it
2022-05-24 11:26:48 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 10682367 Disconnecting it
2022-05-24 11:26:53 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 10682367 Disconnecting it
2022-05-24 11:26:54 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 0 Disconnecting it
2022-05-24 11:26:55 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 10682367 Disconnecting it
2022-05-24 11:26:55 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.4 . Session_status: 6 , client_status: 10682367 Disconnecting it
2022-05-24 11:27:01 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.4 . Session_status: 6 , client_status: 0 Disconnecting it
2022-05-24 11:27:01 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.4 . Session_status: 6 , client_status: 10682367 Disconnecting it
2022-05-24 11:27:04 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.4 . Session_status: 6 , client_status: 10682367 Disconnecting it
2022-05-24 11:27:05 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.4 . Session_status: 6 , client_status: 10682367 Disconnecting it
2022-05-24 11:27:07 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 11 Disconnecting it
2022-05-24 11:27:07 MySQL_Session.cpp:149:kill_query_thread(): [WARNING] KILL CONNECTION 76231 on server-2.example.net:3306
2022-05-24 11:27:07 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 10682367 Disconnecting it
2022-05-24 11:27:08 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 10682367 Disconnecting it
2022-05-24 11:27:08 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 10682367 Disconnecting it
2022-05-24 11:27:10 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 10682367 Disconnecting it
2022-05-24 11:27:11 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 10682367 Disconnecting it
2022-05-24 11:27:12 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 10682367 Disconnecting it
2022-05-24 11:27:13 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 11 Disconnecting it
2022-05-24 11:27:18 MySQL_Session.cpp:3364:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.5 . Session_status: 6 , client_status: 11 Disconnecting it
2022-05-24 11:27:18 MySQL_Session.cpp:149:kill_query_thread(): [WARNING] KILL CONNECTION 76240 on server-2.example.net:3306
2022-05-24 11:27:18 MySQL_Thread.cpp:3751:process_all_sessions(): [WARNING] Closing unhealthy client connection 10.222.15.175:60822Problem start as soon as the first kill_query_thread message is issued. In this example after ~20 minutes
rickymarini
commented
2 years ago complete tcpdump session executed on proxysql k8s container (ip masked) seems like for some reason proxy is not sending COMMIT after asking for autocommit=0 or anyway not finishing the transaction properly right after INSERT.
What you think @renecannao it is a bug? I tried almost any setup without luck
renecannao
commented
2 years ago From my comment 7 days ago:
From proxysql's error log I suspect the client is sending a COMMIT without waiting the OK after sending the INSERT.
tcpdump seems to confirm this.
In the last screenshot, the client sent 3 INSERT statements without waiting any OK.
At the end of the 1st INSERT , proxysql tries to send the OK packet to the client, but finds more data waiting in the socket, returning an error Unexpected packet from client .
The MySQL Protocol allows this, while proxysql doesn't support this batching method.
ProxySQL's internal state machine requires that a statement needs to complete before a new one is received.
This clearly seems a limitation in ProxySQL. Meanwhile, can you disable any sort of batching used by the application?
Thanks
rickymarini
commented
2 years ago @renecannao thanks! application is using mariadb JDBC, and for what I can see from the java source code it is making use of batching. Tried to set:
rewriteBatchedStatements=true
On the jdbc URL string but it breaks proxysql this way:
...
2022-05-31 09:42:12 MySQL_Session.cpp:7401:unable_to_parse_set_statement(): [WARNING] Unable to parse unknown SET query from client 10.222.10.4:47400. Setting lock_hostgroup. Please report a bug for future enhancements:set autocommit=1, session_track_schema=1, session_track_system_variables='auto_increment_increment' , sql_mode = concat(@@sql_mode,',STRICT_TRANS_TABLES')
2022-05-31 09:42:12 MySQL_Session.cpp:3471:handler___status_NONE_or_default(): [ERROR] Unexpected packet from client 10.222.10.4 . Session_status: 6 , client_status: -1414812757 Disconnecting it
2022-05-31 09:42:22 MySQL_Session.cpp:7401:unable_to_parse_set_statement(): [WARNING] Unable to parse unknown SET query from client 10.222.10.4:48268. Setting lock_hostgroup. Please report a bug for future enhancements:set autocommit=1, session_track_schema=1, session_track_system_variables='auto_increment_increment' , sql_mode = concat(@@sql_mode,',STRICT_TRANS_TABLES')
...Now I am testing useBatchMultiSend=false , will inform about outcome.
renecannao
commented
2 years ago Hi @rickymarini .
ProxySQL's doesn't send tracked variables to the client, so I suggest to completely remove session_track_system_variables='auto_increment_increment' because it has no real effect.
About batching, we are evaluating internally how to implement it and its limitation: stay tuned.
Thanks
rickymarini
commented
2 years ago Hi @renecannao ,
I confirm that setting useBatchMultiSend=false on jdbc works. Now we can effort to migrate test and pre-prod environment. We still need to understand impact for prod as this application may require batching to be efficient, and since it use up to 100 insert in a shot, we can have a potential perf. issue (but we will measure this) .
When you say
ProxySQL's doesn't send tracked variables to the client, so I suggest to completely remove
You mean to query rewrite it through a rule (cannot modify code)?
I think that rewriteBatchedStatements=true is promising as an option, since it allows to rewrite multiple statements in a single one but unable to test due to SET command issue
renecannao
commented
2 years ago I confirm that setting useBatchMultiSend=false on jdbc works. Now we can effort to migrate test and pre-prod environment.
Good to hear that!
We still need to understand impact for prod as this application may require batching to be efficient, and since it use up to 100 insert in a shot, we can have a potential perf. issue (but we will measure this) .
If the application wants to boost performance should not use "batching inserts" (I am not sure this is the right term), but multi-rows INSERT. If you follow the math described in MySQL documentation on Optimizing INSERT Statements , you will agree with me that sending 100 INSERTs in a shot will only solve the network latency: if you really want to improve performance you need to use multi-rows INSERTs.
You mean to query rewrite it through a rule (cannot modify code)?
Yes. Something like this:
INSERT INTO mysql_query_rules (active,match_pattern,replace_pattern)
VALUES
(1,"session_track_system_variables='auto_increment_increment' ,","");Thanks again @renecannao
The rewrite rule works and application is now starting, but no luck with rewriteBatchedStatements=true as I got an exception on the batch insert section, then application is firing ROLLBACK.
ProxySQL log is clean and there is nothing strange happening in the logs, I think forcing the driver to do rewrite somehow breaks the application logic, also not clear why he sends different SET parameters with the option turned on.
However, I thought batch packet was too big, but statement seems to be complete and packet way below the configured size threshold.
I think it's related to how application expects to validate the INSERT, the packet with OK answer from proxySQL is now reporting 2 affectedRows, while application wants to validate in a different way and expects 1 for each and every statement?
final int[] affectedRows = preparedBatch.execute();
final boolean succeeded = Arrays.stream(affectedRows).allMatch(eachAffectedRows -> eachAffectedRows == 1);
if (succeeded) {
log.infoSegments(partition, "Published segments to DB");
} else {
final List<DataSegment> failedToPublish = IntStream.range(0, partition.size())
.filter(i -> affectedRows[i] != 1)
.mapToObj(partition::get)
.collect(Collectors.toList());
throw new ISE(
"Failed to publish segments to DB: %s",
SegmentUtils.commaSeparatedIdentifiers(failedToPublish)
);From your description it seems that the application doesn't like to use multi-rows INSERTs, because it validates that each INSERT inserts only 1 row. This doesn't seem a smart check :thinking:
rickymarini
commented
2 years ago Yes I also think is trying to do like that, I' ll post a bug on their Github, as they are unintentionally breaking an allowed jdbc behaviour.
For now I think useBatchMultiSend=false could be our solution, until you do something proxysql side to better support batching.
Thanks a lot for the support and feel free to comment again if you need some feature testing @renecannao
arun4a
commented
2 years ago Hi @rickymarini and @renecannao , as of now, to execute any batch statements from JDBC through proxysql server. Apart from the changing url parameters, is there any configuration we can do from proxysql ?
rickymarini
commented
2 years ago Hi @rickymarini and @renecannao , as of now, to execute any batch statements from JDBC through proxysql server. Apart from the changing url parameters, is there any configuration we can do from proxysql ?
As far as I understood, no, not today. They are evaluating if worthwhile to implement batching support in proxysql. As today, you need to change jdbc properties to alter how batched statements are sent to the proxy
arun4a
commented
2 years ago Hi @rickymarini and @renecannao , as of now, to execute any batch statements from JDBC through proxysql server. Apart from the changing url parameters, is there any configuration we can do from proxysql ?
As far as I understood, no, not today. They are evaluating if worthwhile to implement batching support in proxysql. As today, you need to change jdbc properties to alter how batched statements are sent to the proxy
Thanks for the response. Ok continue as you suggested
arun4a
commented
2 years ago HI @renecannao and @rickymarini,
Is proxysql support High availability ? For example, if master server(write) goes down, can proxysql route request to other slave node(write) .
ThomasVerhoeven1998
commented
9 months ago I confirm that setting useBatchMultiSend=false on jdbc works. Now we can effort to migrate test and pre-prod environment.
Good to hear that!
We still need to understand impact for prod as this application may require batching to be efficient, and since it use up to 100 insert in a shot, we can have a potential perf. issue (but we will measure this) .
If the application wants to boost performance should not use "batching inserts" (I am not sure this is the right term), but multi-rows INSERT. If you follow the math described in MySQL documentation on Optimizing INSERT Statements , you will agree with me that sending 100 INSERTs in a shot will only solve the network latency: if you really want to improve performance you need to use multi-rows INSERTs.
You mean to query rewrite it through a rule (cannot modify code)?
Yes. Something like this:
INSERT INTO mysql_query_rules (active,match_pattern,replace_pattern) VALUES (1,"session_track_system_variables='auto_increment_increment' ,","");
@renecannao Is there a fix in a new version for this work around?
renecannao
commented
9 months ago @ThomasVerhoeven1998 , there is a POC to support this JDBC capabilities , yet we believe that:
cocorossello
commented
7 months ago RewriteBatchedStatements was removed in mariadb connector-j 3.0.3, and useBulkStmtsForInserts was introduced.
useBulkStmtsForInserts does not work neither.
It would be very useful if it could work, rewriting the application is not an easy task if there is an ORM in the middle. I can see a performance degradation when turning useBulkStmtsForInserts=false. A batch job that was around 32 seconds now is around 44 seconds.
mwilberg
commented
4 months ago Have read through this thread with great interest with hopes of actually finding a solution to my current predicament - which seems to be similar or nearly identical to that of the original poster.
We have a setup with a 3 node Galera Cluster (MariaDB 10.11.6) on Debian Bookworm - and are trying to set up Service(not exactly)NOW using ProxySQL.
I can connect to the backend servers just fine through ProxySQL, but the application seems to be running some batching of commands that is tossing out the exact same error messages as @rickymarini has documented in his post.
Sadly none of the jdbc-hacks I've seen in here have solved anything for me, and I still can't seem to get the application installed as long as I point the jdbc-url to proxysql
glide.db.properties
# glide.db.properties
glide.db.name = sntest_16000
glide.db.rdbms = mysql
glide.db.url = jdbc:mariadb://localhost:6033/sntest_16000?usePipeLineAuth=false&disablePipeLine=true&useBatchMultiSend=false
glide.db.user = sntestuser
glide.db.password = SomeLongRandomPasswordIf I bypass ProxySQL and enter either one of the Galera nodes in the jdbc-url it works fine, but one of the main reasons I wanted to use ProxySQL in the first place was to be able to use read/write splitting and being able to set up a true HA solution
Another problem is of course that our systems are air gapped and getting any kind of logs and stuff out of there is a total pain in the backside... Would love some more pointers though, if anyone has gotten ServiceNOW to work through ProxySQL
renecannao
commented
4 months ago Hi @mwilberg . Thank you for using ProxySQL . I hope you understand that although we would like to help everyone, the lack of error log and a reproducible test case make investigation almost a no started.
I am not going to imply that it will make any difference, but have you tried to use a different JDBC driver? Also, please try to use the latest version of ProxySQL .
Thanks
mwilberg
commented
4 months ago Hey again @renecannao and of course I appreciate the problem with helping someone who can't be helped ;)
I will try setting up a new test-environment in one of our more accessible zones, and get you some logs to look at. We are running ProxySQL 2.6.1-31-g9d788c0 so I don't think we are too far behind.
Will check out the possibility of trying a different JDBC driver - might be that simple :+1:
cheers
ron-azuelos
commented
3 weeks ago Hi @renecannao , just to be on the safe side. We had the same issue working with mariadb driver (we were unable to write batch inserts without changing the "useBatchMultiSend" value to "false") than we moved to work with MYSQL 8.0.33 driver and it resolved the issue ( the batch worked ) (our proxy works with MariaDB databases) Is there any issue with working that way (mariadb + mysql driver + proxy 2.5.5 + using the batch ) in production environment ?
Hi Team,
Description: Application is apache Druid, we are trying to remove mysql-router component (used only on RW port) and start using ProxySQL. Publishing segments on the metadata storage (mariadb) tasks is failing. This is not working at all and we didn't found any suitable reason for that, despite trying different combination for multiplexing, transactions, tcp, queries. During the transaction -no matter the configuration- a client disconnect is performed right before the COMMIT. Application is connecting through mariadb-java-client-2.7.3 , proxysql is running on a k8s container (as mysql-router currently is). No endpoint change during switch between the two components, we operated them on the same socket. I also tested some RW transaction using standard mysql client with similar patterns, and everything seems ok. For matter of simplification I've reduced the configuration to the minimum, keeping one single catching rule for queries, and keeping safe defaults. Also some information have been stripped or and changed with ___placeholders___. Please note that backend servers are correctly being discovered and are ONLINE in a stable manner. For what we can understand through a bit of reverse engineering, proxySQL is quitting before sending COMMIT.
proxysql docker image: 2.3.2-10-g8cd66cf, 2.3.1, 2.4.1, latest client: mariadb-java-client-2.7.3
Exception raised by application:
ProxySQL variables
Logfile:
Configuration:
Tcpdump session of what ProxySQL try to do
Tcpdump session of what mysql-router does
Statements logged on MARIADB with ProxySQL, for relevant thread
Statements logged on MARIADB with mysql router, for relevant thread