[MXS-586] Tee filter hangs when using range Created: 2016-02-23  Updated: 2017-01-18  Resolved: 2017-01-18

Status: Closed
Project: MariaDB MaxScale
Component/s: tee
Affects Version/s: 1.2.1, 1.3.0, 2.0.0
Fix Version/s: 2.1.0

Type: Bug Priority: Major
Reporter: Frederic -lefred- Descamps Assignee: markus makela
Resolution: Fixed Votes: 0
Labels: None
Environment:

CentOS release 6.7 (Final)
MaxScale 1.3.0
Vagrant boxes


Sprint: 2017-26

 Description   

2 database servers
1 maxscale using Tee filter
1 client

Sysbench OLTP hangs, simple inserts, simple selects always work.

I tried from MySQL client a range query like used in OLTP test, and it worked several time and then it hangs, it's not always the same amount of occurrences of the query when I test again, but the result is always the same, client waits for response (stalled).

Debug output :

2016-02-23 09:11:41   [5]  info   : Routed [COM_QUERY] to 'percona1': SELECT  c FROM sbtest1 WHERE id BETWEEN 509624 AND 509723
2016-02-23 09:11:41   debug  : 140703540057856 [gw_MySQLWrite_backend] write to dcb 0x7ff80c001e90 fd 15 protocol state MYSQL_IDLE.
2016-02-23 09:11:41   debug  : 140703540057856 [dcb_write] Wrote 62 Bytes to dcb 0x7ff80c001e90 in state DCB_STATE_POLLING fd 15
2016-02-23 09:11:41   [5]  info   : Routed [COM_QUERY] to 'percona2': SELECT  c FROM sbtest1 WHERE id BETWEEN 509624 AND 509723
2016-02-23 09:11:41   debug  : 140703550547712 [poll_waitevents] epoll_wait found 1 fds
2016-02-23 09:11:41   debug  : 140703550547712 [poll_waitevents] event 5 dcb 0x7ff80c000f80 role DCB_ROLE_REQUEST_HANDLER
2016-02-23 09:11:41   debug  : 140703550547712 [gw_write_backend_event] wrote to dcb 0x7ff80c000f80 fd 14, return 1
2016-02-23 09:11:41   debug  : 140703550547712 [poll_waitevents] Read in dcb 0x7ff80c000f80 fd 14
2016-02-23 09:11:41   debug  : 140703550547712 [gw_read_backend_event] Read dcb 0x7ff80c000f80 fd 14 protocol state 11, MYSQL_IDLE.
2016-02-23 09:11:41   debug  : 140703550547712 [dcb_read] Read 12471 bytes from dcb 0x7ff80c000f80 in state DCB_STATE_POLLING fd 14.
2016-02-23 09:11:41   debug  : 140703550547712 [protocol_get_srv_command] Read command UNKNOWN MYSQL PACKET TYPE for fd 14.
2016-02-23 09:11:41   [5]  info   : Tee clientReply [parent] [open] [RSET]: 42
2016-02-23 09:11:41   [5]  info   : Tee: First reply to a query for [PARENT].
2016-02-23 09:11:41   debug  : tee.c: [0] Waiting for a result set from parent session.
2016-02-23 09:11:41   debug  : tee.c [0] parent received last EOF packet
2016-02-23 09:11:41   debug  : 140703550547712 [poll_waitevents] epoll_wait found 1 fds
2016-02-23 09:11:41   debug  : 140703550547712 [poll_waitevents] event 5 dcb 0x7ff80c001e90 role DCB_ROLE_REQUEST_HANDLER
2016-02-23 09:11:41   debug  : 140703550547712 [gw_write_backend_event] wrote to dcb 0x7ff80c001e90 fd 15, return 1
2016-02-23 09:11:41   debug  : 140703550547712 [poll_waitevents] Read in dcb 0x7ff80c001e90 fd 15
2016-02-23 09:11:41   debug  : 140703550547712 [gw_read_backend_event] Read dcb 0x7ff80c001e90 fd 15 protocol state 11, MYSQL_IDLE.
2016-02-23 09:11:41   debug  : 140703550547712 [dcb_read] Read 8688 bytes from dcb 0x7ff80c001e90 in state DCB_STATE_POLLING fd 15.
2016-02-23 09:11:41   debug  : 140703550547712 [protocol_get_srv_command] Read command UNKNOWN MYSQL PACKET TYPE for fd 15.
2016-02-23 09:11:41   [4]  info   : Tee clientReply [child] [open] [RSET]: 43
2016-02-23 09:11:41   [4]  info   : Tee: First reply to a query for [CHILD].
2016-02-23 09:11:41   debug  : tee.c: [0] Waiting for a result set from child session.
2016-02-23 09:11:41   debug  : 140703550547712 [poll_waitevents] epoll_wait found 1 fds
2016-02-23 09:11:41   debug  : 140703550547712 [poll_waitevents] event 5 dcb 0x7ff80c001e90 role DCB_ROLE_REQUEST_HANDLER
2016-02-23 09:11:41   debug  : 140703550547712 [gw_write_backend_event] wrote to dcb 0x7ff80c001e90 fd 15, return 1
2016-02-23 09:11:41   debug  : 140703550547712 [poll_waitevents] Read in dcb 0x7ff80c001e90 fd 15
2016-02-23 09:11:41   debug  : 140703550547712 [gw_read_backend_event] Read dcb 0x7ff80c001e90 fd 15 protocol state 11, MYSQL_IDLE.
2016-02-23 09:11:41   debug  : 140703550547712 [dcb_read] Read 3783 bytes from dcb 0x7ff80c001e90 in state DCB_STATE_POLLING fd 15.
2016-02-23 09:11:41   debug  : 140703550547712 [protocol_get_srv_command] Read command UNKNOWN MYSQL PACKET TYPE for fd 15.
2016-02-23 09:11:41   [4]  info   : Tee clientReply [child] [open] [RSET]: 44}}
 
This is maxscale.cnf:
 
{{
[maxscale]
threads=4
#log_to_shm=0
log_debug=1
#log_messages=1
log_trace=1
 
[Prod]
type=service
router=readconnroute
servers=percona1
user=maxscale
passwd=percona
filters=TeeFilter
 
[TeeFilter]
type=filter
module=tee
service=Stagging
 
[Stagging]
type=service
router=readconnroute
servers=percona2
user=maxscale
passwd=percona
#filters=QLA_Stagging
 
[QLA_Stagging]
type=filter
module=qlafilter
options=/tmp/Prod.log
 
[Prod Listener]
type=listener
service=Prod
protocol=MySQLClient
port=3306
 
[Stagging Listener]
type=listener
service=Stagging
protocol=MySQLClient
port=3307
 
 
[percona1]
type=server
address=192.168.90.2
port=3306
protocol=MySQLBackend
#persistpoolmax=50
 
[percona2]
type=server
address=192.168.90.3
port=3306
protocol=MySQLBackend
#persistpoolmax=50



 Comments   
Comment by Dipti Joshi (Inactive) [ 2016-02-23 ]

johan.wikman tturenko Have we done this benchmark test ?

Comment by Johan Wikman [ 2016-03-01 ]

There are issues with the tee filter; it uses various parts of the system rather incorrectly. Rather than trying to patch it now, it is better to rewrite it properly for 1.5.

Comment by Johan Wikman [ 2016-06-06 ]

No work has been done on the tee-filter, so this bug is tentatively moved to 2.1.

We should consider dropping the current tee-filter implementation and rewrite it properly.

Comment by markus makela [ 2017-01-04 ]

Possibly fixed in 2.1.

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