[#MXS-2157] Packet received out-of-order. Expected 1; got 0

[MXS-2157] Packet received out-of-order. Expected 1; got 0 Created: 2018-11-09 Updated: 2019-06-17 Resolved: 2019-05-15
Status:	Closed
Project:	MariaDB MaxScale
Component/s:	readconnroute
Affects Version/s:	2.2.16
Fix Version/s:	2.2.20

Type:

Bug

Priority:

Major

Reporter:

Wagner Bianchi (Inactive)

Assignee:

markus makela

Resolution:

Fixed

Votes:

Labels:

None

Attachments:

Screen Shot 2018-12-07 at 16.24.34.png

Issue Links:

Relates
relates to	~~MXS-2562~~	Oracle's MySQL Connector/ODBC gets pa...	Closed

Sprint:

MXS-SPRINT-70

Description

Folks,

I've seen this happening again on 2.2.16. We worked together some time ago and sorted that out but, using the ReadWriteSplut Router; not sure if the ReadConnRouter, being used this way, also has some similar code to create this situation. This below error was happening when running 2.2.16:

Packet received out-of-order. Expected 1; got 3

So, we downgraded Maxscale to 2.2.4, and then, the error stopped occurring. Interesting is that we didn't change anything in the configuration file, just replace the .deb package. Below, the configurations in use:

[maxscale]

threads=auto

log_augmentation=1

ms_timestamp=1

log_info=0

#: maxctrl

admin_host=0.0.0.0

admin_port=8989

admin_auth=1

admin_log_auth_failures=1

[replication-cluster-monitor]

type=monitor

module=mariadbmon

user=maxmon

password=80071DBFF3A797CD2E453845F8781BB3BD1E8D12FB1F7604A12B86F9FA18BF93

monitor_interval=5000

backend_connect_timeout=3

backend_write_timeout=2

backend_read_timeout=1

backend_connect_attempts=1

journal_max_age=28800

script_timeout=90

servers=mariadb01,mariadb02,mariadb03

servers_no_promotion=gtprd-mariadb03

auto_rejoin=true

auto_failover=true

failcount=5

replication_password=14F9823438455408191AC3CBA100C54B4984B1D24F8E1099301B4F15FBD7807C

replication_user=mariadb

detect_replication_lag=false

detect_stale_master=true

detect_stale_slave=true

mysql51_replication=false

multimaster=false

detect_standalone_master=true

allow_cluster_recovery=true

ignore_external_masters=false

events=master_down,master_up,slave_down,slave_up,server_down,server_up,synced_down,synced_up,donor_down,donor_up,ndb_down,ndb_up,lost_master,lost_slave,lost_synced,lost_donor,lost_ndb,new_master,new_slave,new_synced,new_donor,new_ndb

failover_timeout=90

switchover_timeout=90

verify_master_failure=true

master_failure_timeout=10

[readconn-service-master]

type=service

router=readconnroute

router_options=master

servers=mariadb01,mariadb02,mariadb03

user=maxuser

password=F1105B285F8FF06817A58459887038431CEDAAFA9575EEDBD91CBA0095E3E3F1

[readconn-listener-master]

type=listener

service=readconn-service-master

protocol=MariaDBClient

port=3306

[mariadb01]

type=server

protocol=mariadbbackend

address=10.81.21.11

port=3306

authenticator=MySQLBackendAuth

[mariadb02]

type=server

protocol=mariadbbackend

address=10.81.21.12

port=3306

authenticator=MySQLBackendAuth

[mariadb03]

type=server

protocol=mariadbbackend

address=10.81.21.13

port=3306

authenticator=MySQLBackendAuth

[CLI]

type=service

router=cli

[CLI-Unix-Listener]

type=listener

service=CLI

protocol=maxscaled

socket=default

[CLI-Inet-Listener]

type=listener

service=CLI

protocol=maxscaled

address=localhost

port=6603

Thanks!

Comments

Comment by markus makela [ 2018-11-10 ]

Does this happen with a specific query?

Comment by markus makela [ 2018-11-15 ]

Might actually be fixed by this commit:

commit f4dd0628dab050f669d544beafa51246ced9cb90

Author: Markus Mäkelä <markus.makela@mariadb.com>

Date:   Sun Nov 11 17:19:52 2018 +0200

    Fix COM_CHANGE_USER handling

    If the service doesn't require collection of complete packets, the user

    reauthentication done with COM_CHANGE_USER would be skipped. This caused

    the change_user test to fail.

    By temporarily switching to full packet collection mode for the duration

    of the COM_CHANGE_USER, we avoid duplicating the code for the streaming

    router types.

This would mean that this will be fixed in 2.2.17.

Comment by markus makela [ 2018-11-19 ]

Can you try which exact version causes the problem? There are a lot of releases between 2.2.4 and 2.2.16 so knowing which one causes it would greatly reduce the amount of possible causes for this.

Comment by Wagner Bianchi (Inactive) [ 2018-12-07 ]

Markus,

Working a different environment today, I found this error message appearing for a Lambda Function being executed against the Maxscale. When the processes executed by the function hits Maxscale, the error events are like these ones below:

2018-12-07 17:45:20.401   error  : (5935) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:20.401   error  : (5935) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.433   error  : (6076) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.433   error  : (6076) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.433   error  : (6078) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.433   error  : (6078) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.433   error  : (6080) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.433   error  : (6080) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.433   error  : (6082) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.433   error  : (6082) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.433   error  : (6084) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.433   error  : (6084) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.438   error  : (6086) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.438   error  : (6086) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.438   error  : (6088) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.438   error  : (6088) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.438   error  : (6090) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.438   error  : (6090) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.438   error  : (6092) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.439   error  : (6092) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.441   error  : (6096) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.441   error  : (6096) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.442   error  : (6098) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.442   error  : (6098) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.442   error  : (6100) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.442   error  : (6100) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.442   error  : (6102) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.442   error  : (6102) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.442   error  : (6104) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.442   error  : (6104) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.442   error  : (6094) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.442   error  : (6094) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.446   error  : (6106) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.446   error  : (6106) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.446   error  : (6108) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.

2018-12-07 17:45:22.446   error  : (6108) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed.

2018-12-07 17:45:22.446   error  : (6110) [readconnroute] (log_closed_session): Failed to route MySQL command 3 to backend server.  (subsequent similar messages suppressed for 10000 milliseconds)

2018-12-07 17:45:22.446   error  : (6110) [mariadbclient] (gw_read_finish_processing): Routing the query failed. Session will be closed. (subsequent similar messages suppressed for 10000 milliseconds)

From the AWS Console standpoint, the below image is showing the errors:

Any luck to get to know how to workaround this error?

Thanks much!!!

Comment by markus makela [ 2019-03-13 ]

Possibly caused by ~~MXS-2311~~

Comment by markus makela [ 2019-03-13 ]

wagnerbianchi please verify whether this is still a problem.

Comment by markus makela [ 2019-03-18 ]

Most likely a duplicate of ~~MXS-2311~~.

Comment by Wagner Bianchi (Inactive) [ 2019-05-15 ]

MySQL Connector causes this issue. Use MariaDB Connector instead.

Comment by Kathryn Sizemore [ 2019-06-11 ]

This isn't fixed. It would greatly help us on many different projects if we could use Oracle's MySQL Connector through MaxScale. Can we find a fix please?

Comment by markus makela [ 2019-06-11 ]

If this is still reproducible with MySQL's Connector and the latest MaxScale version then should be investigated. You can help expedite the fix by providing a simple test case that reproduces the problem. Also, try if using the latest 2.3 version has any difference.

Comment by markus makela [ 2019-06-13 ]

I created ~~MXS-2562~~ for the problem with the Oracle .NET connector.

Comment by markus makela [ 2019-06-17 ]

ksizemore Do you know of a way to reproduce this or have you spotted a specific pattern that seems to trigger these errors?

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

[MXS-2157] Packet received out-of-order. Expected 1; got 0 Created: 2018-11-09 Updated: 2019-06-17 Resolved: 2019-05-15