[MXS-1760] Adding use_sql_variables_in=master resulted in error "Client requests unknown prepared statement ID '0' that does not map to an internal ID" Created: 2018-04-05  Updated: 2020-08-25  Resolved: 2018-09-14

Status: Closed
Project: MariaDB MaxScale
Component/s: readwritesplit
Affects Version/s: 2.2.2
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Pramod Mahto Assignee: markus makela
Resolution: Cannot Reproduce Votes: 0
Labels: need_feedback
Environment:

CentOS7 Amazon EC2


Attachments: Text File MaxScale Valgrind.txt     File maxscale.cnf    
Issue Links:
Relates
relates to MXS-2461 Unexpected internal state with ReadWr... Closed
Sprint: MXS-SPRINT-56, MXS-SPRINT-57

 Description   

Customer is getting an below error after adding use_sql_variables_in=master

2018-04-05 05:42:44 warning: (14) [readwritesplit] Client requests unknown prepared statement ID '0' that does not map to an internal ID
2018-04-05 05:42:44 warning: (14) [readwritesplit] Using unknown prepared statement with ID 0
2018-04-05 05:42:45 warning: (15) [readwritesplit] Client requests unknown prepared statement ID '0' that does not map to an internal ID (subsequent similar messages suppressed for 10000 milliseconds)
2018-04-05 05:42:45 warning: (15) [readwritesplit] Using unknown prepared statement with ID 0 (subsequent similar messages suppressed for 10000 milliseconds)
2018-04-05 05:49:43 error : (19) [readwritesplit] Unexpected internal state: received response 0x01 from server 'prod_mariadb01' when no response was expected
2018-04-05 05:52:14 error : (19) [readwritesplit] Unexpected internal state: received response 0x01 from server 'prod_mariadb01' when no response was expected

If they use_sql_variables_in=all then one of the output parameter variable p_out in one of their SP is returing null values.



 Comments   
Comment by markus makela [ 2018-04-30 ]

Please try with 2.2.5.

Comment by markus makela [ 2018-04-30 ]

pramod.mahto@mariadb.com Please try and see if this still occurs with 2.2.5.

Comment by markus makela [ 2018-05-16 ]

Also, is it verified that use_sql_variables_in=all solves the problem?

Comment by Assen Totin (Inactive) [ 2018-08-21 ]

Just saw this again.

MaxScale is 2.2.13 on RHEL-7.5. Master/slave cluster with read/write split. Client software is Matomo (previously Piwik, web stats collector) which runs aggregation jobs via cron.

Without use_sql_variables_in in config (i.e. default value) some queries fail with the following message:

"The query can't be routed to all backend servers because it includes SELECT and SQL variable modifications which is not supported. Set use_sql_variables_in=master or split the query to two, where SQL variable modifications are done in the first and the SELECT in the second one."

After several of these MaxScale got completely hosed up and was not responding to maxadmin commands, hence had to be fully restarted. I can provide the quesries inquestion (but they are up to a full page long).

After use_sql_variables_in=master is set, some queries (but we don't know whether the same as before or not) fail with:

2018-08-22 01:00:31 warning: (6742) [readwritesplit] Client requests unknown prepared statement ID '3789923308' that does not map to an internal ID
2018-08-22 01:00:31 warning: (6742) [readwritesplit] Using unknown prepared statement with ID 0

This is a live production system, so the abilities to trace and log actual queries are limited.

Pointing the client software directly to the master seems to resolve the issue, but is, of course, not a long-term solution.

Comment by Assen Totin (Inactive) [ 2018-08-24 ]

I managed to load the database dump in a separate, non-production master/slave cluster with a debug version of MaxScale 2.2.13 in front of it with use_sql_variables_in=master and run the aggregation job on it several times (taking TCP dumps on the MaxScale and master and resetting the database every time):

1. The aggregation job is really just a series of SELECTs, after which the aggregated data is written to a file and LOAD DATA LOCAL INFILE is called. This is repeated dozens and dozens of times (perhaps one for each monitored web site, of which there are ~70 in this case). The client seems to only do sequential processing, so there are not parallel requests, multi-threading etc.

2. After running a dozen or two of these cycles, MaxScale crashes with SIGSEGV. For this particular dump it always crashes at the same place, i.e. the crash is deterministic. The crash occurs while LOAD DATA LOCAL INFILE is in progress (client streams the data); the crash does not occur on the first LOAD DATA LOCAL INFILE, but after many of them complete successfully.

3. The TCP dump on teh master confirms the issue is with MaxScale itself, since the master is still receiving data from MaxScale as a part of a LOAD DATA execution when MaxScale crashes and RST packet is received by the master in the middle of the data flow.

4. The logged message about prepared statment with ID=0 may be completely wrong. The client is merely a PHP CLI script which does not use any prepared statements (and has no reasons to do so, since it is a one-off job with limited duration). The TCP dump on the MaxScale does not show any single prepared statement in use. There is no indication what may trigger this log message, but it appears every time just before the crash.

5. MaxScale lacks debuginfo as a separate RPM package, hence I was nto able to get a meaningful output from gdb, not even a backtrace.

6. I was able to run MaxScale in Valgrind which did produce some reasonable output, attached here.

Comment by markus makela [ 2018-08-24 ]

The crash appears to be a separate problem for which I've opened MXS-2024.

Generated at Thu Feb 08 04:09:12 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.