[MXS-3582] [readwritesplit] Failed to execute session command Created: 2021-06-01  Updated: 2021-11-10  Resolved: 2021-06-03

Status: Closed
Project: MariaDB MaxScale
Component/s: readwritesplit
Affects Version/s: 2.3.20, 2.4.17, 2.5.11
Fix Version/s: 2.3.21, 2.4.18, 2.5.13

Type: Bug Priority: Major
Reporter: Alex Assignee: markus makela
Resolution: Fixed Votes: 0
Labels: None
Environment:

Debian buster, backend 10.4.19, 10.5.10



 Description   

Got this in logs:

2021-06-01 07:20:25   info   : (2714773) Found matching user 'meshok7'@'%' for client 'meshok7'@'::ffff:10.0.0.1' with sufficient privileges.
2021-06-01 07:20:25   info   : (2714773) [readwritesplit] (Read-Write-Service) Target connection counts:
2021-06-01 07:20:25   info   : (2714773) [readwritesplit] (Read-Write-Service) current operations : 2 in        flea Slave, Running
2021-06-01 07:20:25   info   : (2714773) [readwritesplit] (Read-Write-Service) current operations : 1 in        ladybug Slave, Running
2021-06-01 07:20:25   info   : (2714773) [readwritesplit] (Read-Write-Service) current operations : 5 in        odonata Master, Running
2021-06-01 07:20:25   info   : (2714773) (odonata) Sent COM_CHANGE_USER
2021-06-01 07:20:25   info   : (2714773) [readwritesplit] (Read-Write-Service) Connected to 'odonata'
2021-06-01 07:20:25   info   : (2714773) [readwritesplit] (Read-Write-Service) Selected Master: odonata
2021-06-01 07:20:25   info   : (2714773) [readwritesplit] (Read-Write-Service) Connected to 'ladybug'
2021-06-01 07:20:25   info   : (2714773) [readwritesplit] (Read-Write-Service) Selected Slave: ladybug
2021-06-01 07:20:25   info   : (2714773) (flea) Sent COM_CHANGE_USER
2021-06-01 07:20:25   info   : (2714773) [readwritesplit] (Read-Write-Service) Connected to 'flea'
2021-06-01 07:20:25   info   : (2714773) [readwritesplit] (Read-Write-Service) Selected Slave: flea
2021-06-01 07:20:25   info   : (2714773) Started Read-Write-Service client session [2714773] for 'meshok7' from ::ffff:10.0.0.1
2021-06-01 07:20:25   info   : (2714773) Connected to 'ladybug' with thread id 729886
2021-06-01 07:20:25   info   : (2714773) (Read-Write-Service) > Autocommit: [enabled], trx is [not open], cmd: (0x01) COM_QUIT, plen: 5, type: QUERY_TYPE_SESSION_WRITE, stmt:
2021-06-01 07:20:25   info   : (2714773) [readwritesplit] (Read-Write-Service) Session write, routing to all servers.
2021-06-01 07:20:25   info   : (2714773) (Read-Write-Service) Execute sescmd #1 on 'flea': [COM_QUIT]
2021-06-01 07:20:25   info   : (2714773) (flea) COM_QUIT received while COM_CHANGE_USER is in progress, closing pooled connection
2021-06-01 07:20:25   error  : (2714773) [readwritesplit] (Read-Write-Service) Failed to execute session command in flea
2021-06-01 07:20:25   info   : (2714773) (Read-Write-Service) Execute sescmd #1 on 'ladybug': [COM_QUIT]
2021-06-01 07:20:25   info   : (2714773) [readwritesplit] (Read-Write-Service) Route query to slave: ladybug
2021-06-01 07:20:25   info   : (2714773) (Read-Write-Service) Execute sescmd #1 on 'odonata': [COM_QUIT]
2021-06-01 07:20:25   info   : (2714773) (odonata) COM_QUIT received while COM_CHANGE_USER is in progress, closing pooled connection
2021-06-01 07:20:25   error  : (2714773) [readwritesplit] (Read-Write-Service) Failed to execute session command in odonata
2021-06-01 07:20:25   info   : (2714773) Authentication to 'ladybug' succeeded.
2021-06-01 07:20:25   info   : Stopped Read-Write-Service client session [2714773]



 Comments   
Comment by Alex [ 2021-06-01 ]

Config:

https://jira.mariadb.org/browse/MXS-3578?focusedCommentId=190701&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-190701

Comment by markus makela [ 2021-06-01 ]

Looking at the code this seems to happen when the connection is closed right after it is created (exactly what is happening here). The backend treats this scenario as an error when it should be treated the same way a normal connection shutdown is treated.

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