[MXS-2270] MaxScale 2.3 readwritesplit will not route temporary tables to master with leading comments Created: 2019-01-16  Updated: 2019-02-11  Resolved: 2019-02-11

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

Type: Bug Priority: Critical
Reporter: Dave Juntgen Assignee: markus makela
Resolution: Duplicate Votes: 0
Labels: None
Environment:

Centos 6

Attachments: File test.c    
Issue Links:
Duplicate
duplicates MXS-2268 readwritesplitter is not routing quer... Closed

 Description   

MaxScale will not route to master when comments are given in a multi-statement query.

Orignal Query (redacted)

# table of orders (cmp_order_id) which when completed,
 
# will cause another order (dec_order_id) to be auto-declined.
 
CREATE TEMPORARY TABLE tmp_order_decliners
 
(
 
  cmp_order_id int unsigned not null,
 
  dec_order_id int unsigned not null,
 
  KEY cmp_order_id(cmp_order_id),
 
  KEY dec_order_id(dec_order_id)
 
);
 
 
 
# this is the mapping.
 
INSERT INTO tmp_order_decliners (cmp_order_id, dec_order_id) VALUES 
$WCINCLUDE|OrderDeclineOrderList$
 
;
 
 
 
# The actual query
 
SELECT 
CONCAT('<ORDERS><ENCORDER pat_id="',eo.pat_id,'" completed_dt="',
 
IF(ceo.completed_dt != '0000-00-00 00:00:00', ceo.completed_dt, NOW()),
 
'" enc_order_id="',
 
eo.enc_order_id,
 
'" status="-4" comments="xxxx-xxxxx by ',
 
ceo.enc_order_id,
 
' (',
 
ceo.order_name,
 
')" /></ORDERS>') AS `eorder_xml`,
 
'?f=xxxxx&s=xxxxxx' AS `URL`
 
FROM tmp_order_decliners t
 
INNER JOIN xxxxxxx ceo
 
  ON ceo.order_id=t.cmp_order_id
 
  AND ceo.status=2
 
INNER JOIN xxxxx eo
 
  ON eo.order_id=t.dec_order_id
 
  AND (eo.status=0 OR eo.status=3)
 
  AND eo.pat_id=ceo.pat_id
 
  AND ceo.completed_dt >= eo.create_dt

Failed Query, sends to slave

2019-01-16 16:49:15   info   : (307) > Autocommit: [enabled], trx is [not open], cmd: (0x03) COM_QUERY, plen: 1102, type: QUERY_TYPE_READ, stmt: CREATE TEMPORARY TABLE /* db=xxxxxxxx dbuser=xxxxxxxx file=xxxxxx.c func=SysRep_Execute user_comment=uid:xxxx,uname:xxxx,rc:RC201806,hdl:xxxxxxx,aid:xxxx line:1718*/ tmp_order_decliners (   cmp_order_id int unsigned not null,   dec_order_id int unsigned not null,   KEY cmp_order_id(cmp_order_id),   KEY dec_order_id(dec_order_id) );
 
# this is the mapping.
 
INSERT INTO tmp_order_decliners (cmp_order_id, dec_order_id) VALUES
 
(3151, 3152)
 
;
 
# The actual query
 
SELECT
 
CONCAT('<ORDERS><ENCORDER pat_id="',eo.pat_id,'" completed_dt="', IF(ceo.completed_dt != '0000-00-00 00:00:00', ceo.completed_dt, NOW()), '" enc_order_id="', eo.enc_order_id, '" status="-4" comments="Auto-Declined by ', ceo.enc_order_id, ' (', ceo.order_name, ')" /></ORDERS>') AS `eorder_xml`, '?f=ajaxpost&s=encounterorders' AS `URL` FROM tmp_order_decliners t INNER JOIN encounter_orders ceo   ON ceo.order_id=t.cmp_order_id   AND ceo.status=2 INNER JOIN encounter_orders eo   ON eo.order_id=t.dec_order_id   A
 
2019-01-16 16:49:15   info   : (307) Route query to slave: fw-mm-db1    [xxxxxxx]:3306 <

Successful query, sends to master

2019-01-16 17:01:03   info   : (414) Write operation detected, next 100 queries routed to master
 
2019-01-16 17:01:03   info   : (414) Write operation detected, queries routed to master for 1 seconds
 
2019-01-16 17:01:03   info   : (414) Added temporary table xxxxxxxx.tmp_order_decliners
 
2019-01-16 17:01:03   info   : (414) > Autocommit: [enabled], trx is [not open], cmd: (0x03) COM_QUERY, plen: 1105, type: QUERY_TYPE_WRITE|QUERY_TYPE_CREATE_TMP_TABLE, stmt: CREATE TEMPORARY TABLE /* db=xxxxxxxx dbuser=xxxxxxxx file=xxxxxx.c func=SysRep_Perform user_comment=uid:xxxxx,uname:xxxxxx,rc:RC201806,hdl:xxxxxxx,aid:xxxx line:1904*/ tmp_order_decliners (   cmp_order_id int unsigned not null,   dec_order_id int unsigned not null,   KEY cmp_order_id(cmp_order_id),   KEY dec_order_id(dec_order_id) );
 
# this is the mapping.
 
INSERT INTO tmp_order_decliners (cmp_order_id, dec_order_id) VALUES
 
(3151, 3152)
 
;
 
# The actual query
 
SELECT
 
CONCAT('<ORDERS><ENCORDER pat_id="',eo.pat_id,'" completed_dt="', IF(ceo.completed_dt != '0000-00-00 00:00:00', ceo.completed_dt, NOW()), '" enc_order_id="', eo.enc_order_id, '" status="-4" comments="Auto-Declined by ', ceo.enc_order_id, ' (', ceo.order_name, ')" /></ORDERS>') AS `eorder_xml`, '?f=ajaxpost&s=encounterorders' AS `URL` FROM tmp_order_decliners t INNER JOIN encounter_orders ceo   ON ceo.order_id=t.cmp_order_id   AND ceo.status=2 INNER JOIN encounter_orders eo   ON eo.order_id=t.dec_order_id
 
2019-01-16 17:01:03   info   : (414) Route query to master: db2   [xxxxxxx]:3306 <
 
2019-01-16 17:01:03   info   : (414) Reply complete, last reply from db2

MaxScale Read/Writer Service / CCR and Query Log Filter config

[MM-RW-Service]
 
type=service
 
router=readwritesplit
 
max_slave_replication_lag=1
 
strict_multi_stmt=1
 
master_accept_reads=1
 
servers=db1,db2
 
user=maxscale
 
password=xXXXXX
 
filters=CCRFilter | QueryLogger
 
 
 
[CCRFilter]
 
type=filter
 
module=ccrfilter
 
time=1
 
count=100
 
 
 
# Query Log Filter
 
[QueryLogger]
 
type=filter
 
module=qlafilter
 
separator=" | "
 
log_data=date,session,user,reply_time,query
 
log_type=unified
 
filebase=/var/log/maxscale/querylog



 Comments   
Comment by Dave Juntgen [ 2019-01-17 ]

I should note that the SQL was delivered via the mysql C API with MYSQL_OPTION_MULTI_STATEMENTS_ON. When running the SQL from the command line, the results are not the same.

C code is as such:

mysql_set_server_option(conn,MYSQL_OPTION_MULTI_STATEMENTS_ON);
...
mysql_query()

Comment by Dave Juntgen [ 2019-01-17 ]

Please see the attach C problem presents the problem.

test.c

Basically, it comes down to the following:

Broken Comment before creating table stmt

# Comment line 1 
# Comment line 2 
CREATE TEMPORARY TABLE tmp_table 
( 
  id1 int unsigned not null, 
  id2 int unsigned not null, 
  KEY id1(id1), 
  KEY id2(id2) 
);

MaxScale Log

2019-01-16 22:46:39   info   : (3452) Route query to slave: db1   [172.27.238.14]:3306
 
2019-01-16 22:46:39   info   : (3452) Route query to master: db2  [172.27.238.15]:3306
 
2019-01-16 22:46:39   info   : (3452) Reply complete, last reply from db1
 
2019-01-16 22:46:39   info   : (3452) Reply complete, last reply from db2
 
2019-01-16 22:46:39   info   : (3452) > Autocommit: [enabled], trx is [not open], cmd: (0x03) COM_QUERY, plen: 290, type: QUERY_TYPE_READ, stmt: # Comment line 1 # Comment line 2 CREATE TEMPORARY TABLE tmp_table (   id1 int unsigned not null,   id2 int unsigned not null,   KEY id1(id1),   KEY id2(id2) );  # this is the mapping. INSERT INTO tmp_table (id1, id2) VALUES  (1,2) ;  # The actual query SELECT  * * FROM tmp_table t *
 
2019-01-16 22:46:39   info   : (3452) Route query to slave: db1   [172.27.238.14]:3306 <

Working Query

/* This comment will trigger a MASTER hint */
 
CREATE TEMPORARY TABLE tmp ( id1 int, id2 int);

MaxScale Log of working log

2019-01-16 22:46:39   info   : (3452) Write operation detected, next 100 queries routed to master
 
2019-01-16 22:46:39   info   : (3452) Write operation detected, queries routed to master for 1 seconds
 
2019-01-16 22:46:39   info   : (3452) Added temporary table test.tmp_table
 
2019-01-16 22:46:39   info   : (3452) > Autocommit: [enabled], trx is [not open], cmd: (0x03) COM_QUERY, plen: 279, type: QUERY_TYPE_WRITE|QUERY_TYPE_CREATE_TMP_TABLE, stmt:  /* WORKING COMMENT */ CREATE TEMPORARY TABLE tmp_table (   id1 int unsigned not null,   id2 int unsigned not null,   KEY id1(id1),   KEY id2(id2) );  # this is the mapping. INSERT INTO tmp_table (id1, id2) VALUES  (1,2) ;  # The actual query SELECT  * * FROM tmp_table t *
 
2019-01-16 22:46:39   info   : (3452) Route query to master: fw-mm-db2  [172.27.238.15]:3306 <

Comment by markus makela [ 2019-01-18 ]

We can see that the broken query has been somehow transformed into a single-line entry which of course comments out the whole statement. The parser sets the type of comments as READ which should explain why they end up going to the master.

Can you try and see if it works without the filters?

Comment by markus makela [ 2019-01-18 ]

I took a look at your example code and it doesn't add newlines after the statement. Try adding \n before each backslash that terminates a line the query string.

Comment by markus makela [ 2019-01-18 ]

If possible, please try and see if adding query_classifier_cache_size=0 in the [maxscale] section helps.

Comment by markus makela [ 2019-02-06 ]

If possible, please read this comment here: https://jira.mariadb.org/browse/MXS-2268?focusedCommentId=123004&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-123004
and test the debug packages available here: https://downloads.mariadb.com/MaxScale/2.3.3-debug/

Comment by markus makela [ 2019-02-06 ]

You can ignore the comment I made earlier, we've found a bug that is quite likely to cause this problem. We built packages with the fix which can be found here: http://max-tst-01.mariadb.com/ci-repository/MXS-2268/mariadb-maxscale/
Please test with these packages instead of the ones mentioned in the earlier comment and let us know if it helps.

Comment by markus makela [ 2019-02-11 ]

Closing as a duplicate now that the real cause of MXS-2268 was found out.

Comment by Dave Juntgen [ 2019-02-11 ]

Thank you!

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