[MXS-548] Maxscale 1.2.1 crash on Ubuntu 14.04.3 x86_64 Created: 2016-01-14  Updated: 2016-01-26  Resolved: 2016-01-26

Status: Closed
Project: MariaDB MaxScale
Component/s: Core
Affects Version/s: 1.2.1
Fix Version/s: 1.3.0

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

Ubuntu 14.04.3 LTS x86_64 LXC
mariadb-galera-server-5.5 (5.5.47+maria-1~trusty)


Issue Links:
Relates
relates to MXS-559 Crash due to debug assertion in readw... Closed
Sprint: 1.4.0-1

 Description   

Maxscale crashed. debug log is empty - no trace entries at this time...

MariaDB version: mariadb-galera-server-5.5 (5.5.47+maria-1~trusty)

error log shows:

2016-01-13 17:00:45.113   Fatal: MaxScale 1.2.1 received fatal signal 6. Attempting backtrace.
2016-01-13 17:00:45.113   Commit ID: 7bfda81b098bfd0db3c306495725d1910294d2e8 System name: Linux Release string: Ubuntu 14.04.3 LTS Embedded library version: 5.5.42-MariaDB
2016-01-13 17:00:45.114     /usr/bin/maxscale() [0x549855] 
2016-01-13 17:00:45.114     /lib/x86_64-linux-gnu/libpthread.so.0(+0x10340) [0x7f3e50483340] 
2016-01-13 17:00:45.114     /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39) [0x7f3e4f0bacc9] 
2016-01-13 17:00:45.114     /lib/x86_64-linux-gnu/libc.so.6(abort+0x148) [0x7f3e4f0be0d8] 
2016-01-13 17:00:45.114     /lib/x86_64-linux-gnu/libc.so.6(+0x73394) [0x7f3e4f0f7394] 
2016-01-13 17:00:45.114     /lib/x86_64-linux-gnu/libc.so.6(+0x7f66e) [0x7f3e4f10366e] 
2016-01-13 17:00:45.114     /usr/bin/maxscale(gwbuf_free+0x3d) [0x5487e5] 
2016-01-13 17:00:45.114     /usr/bin/maxscale(gwbuf_consume+0xa6) [0x548d55] 
2016-01-13 17:00:45.115     /usr/bin/maxscale(dcb_write+0x835) [0x550717] 
2016-01-13 17:00:45.115     /usr/lib/x86_64-linux-gnu/maxscale/libMySQLBackend.so(gw_send_authentication_to_backend+0x648) [0x7f3e304d5ad4] 
2016-01-13 17:00:45.115     /usr/lib/x86_64-linux-gnu/maxscale/libMySQLBackend.so(+0x479f) [0x7f3e304d179f] 
2016-01-13 17:00:45.115     /usr/bin/maxscale() [0x55fcca] 
2016-01-13 17:00:45.115     /usr/bin/maxscale(poll_waitevents+0x6d4) [0x55f57b] 
2016-01-13 17:00:45.115     /lib/x86_64-linux-gnu/libpthread.so.0(+0x8182) [0x7f3e5047b182] 
2016-01-13 17:00:45.115     /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7f3e4f17e47d] 

[MaxScale]
threads=8
ms_timestamp=1
log_messages=1
log_trace=1
log_debug=1
 
[CLI_listener]
type=listener
service=CLI
protocol=maxscaled
address=localhost
port=6603
 
[CLI]
type=service
router=cli
 
[debug]
type=service
router=debugcli
router_options=user
 
[debug_listener]
type=listener
service=debug
protocol=telnetd
port=4442
 
[galera_monitor]
type=monitor
module=galeramon
servers=db1,db2,db3,db4,db5
user=maxscalemon
passwd=5A1E57AB442F995FE330E1B68D6299F5D436EB09E4715011A32665CE378D8B1B810B73F1C0F291A85A45E55E9F4C6A51
monitor_interval=2000
disable_master_failback=1
available_when_donor=1
disable_master_role_setting=0
 
[galera_rr_service]
type=service
router=readconnroute
#connection_timeout=300
router_options=synced
servers=db1,db2,db3,db4,db5
user=maxscaleroute
passwd=50DFB08A63C42CB302B8DFE1B57F5BD0A4B410A2F97FA0776ABB8ABBE5A8F436FA8FE21CF5479013C2E53E66931EC648
enable_root_user=0
 
[galera_rw_service]
type=service
router=readwritesplit
#connection_timeout=300
router_options=slave_selection_criteria=LEAST_CURRENT_OPERATIONS
max_slave_connections=100%
servers=db1,db2,db3,db4,db5
user=maxscaleroute
passwd=50DFB08A63C42CB302B8DFE1B57F5BD0A4B410A2F97FA0776ABB8ABBE5A8F436FA8FE21CF5479013C2E53E66931EC648
enable_root_user=0
 
[galera_rr_listener]
type=listener
service=galera_rr_service
protocol=MySQLClient
address=10.0.248.201
port=3306
 
[galera_rw_listener]
type=listener
service=galera_rw_service
protocol=MySQLClient
address=10.0.248.202
port=3306
 
[db1]
type=server
address=10.0.249.11
port=3306
protocol=MySQLBackend
 
[db2]
type=server
address=10.0.249.12
port=3306
protocol=MySQLBackend
 
[db3]
type=server
address=10.0.249.13
port=3306
protocol=MySQLBackend
 
[db4]
type=server
address=10.0.249.14
port=3306
protocol=MySQLBackend
 
[db5]
type=server
address=10.0.249.15
port=3306
protocol=MySQLBackend

MariaDB [(none)]> SHOW GRANTS FOR 'maxscaleroute'@10.0.249.211;
+----------------------------------------------------------------------------------------------------------------------------------+
| Grants for maxscaleroute@10.0.249.211                                                                                            |
+----------------------------------------------------------------------------------------------------------------------------------+
| GRANT SHOW DATABASES ON *.* TO 'maxscaleroute'@'10.0.249.211' IDENTIFIED BY PASSWORD '*xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx' |
| GRANT SELECT ON `mysql`.`user` TO 'maxscaleroute'@'10.0.249.211'                                                                 |
| GRANT SELECT ON `mysql`.`db` TO 'maxscaleroute'@'10.0.249.211'                                                                   |
+----------------------------------------------------------------------------------------------------------------------------------+
3 rows in set (0.00 sec)
 
MariaDB [(none)]> SHOW GRANTS FOR 'maxscalemon'@10.0.249.211;
+-----------------------------------------------------------------------------------------------------------------------+
| Grants for maxscalemon@10.0.249.211                                                                                   |
+-----------------------------------------------------------------------------------------------------------------------+
| GRANT USAGE ON *.* TO 'maxscalemon'@'10.0.249.211' IDENTIFIED BY PASSWORD '*xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx' |
+-----------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)
 



 Comments   
Comment by Johan Wikman [ 2016-01-15 ]

Dipti, we've started a scrum process and as part of that all bugs will first go to Timofey who'll then check whether it might be an existing one, try reproduce it, assign an initial priority and also, if it's clear who that should be, assign it to someone for further assessment or fixing.

Comment by Florian Engelmann [ 2016-01-18 ]

2nd crash:

error1.log

2016-01-18 10:00:45.597   Fatal: MaxScale 1.2.1 received fatal signal 6. Attempting backtrace.
2016-01-18 10:00:45.597   Commit ID: 7bfda81b098bfd0db3c306495725d1910294d2e8 System name: Linux Release string: Ubuntu 14.04.3 LTS Embedded library version: 5.5.42-MariaDB
2016-01-18 10:00:45.599     /usr/bin/maxscale() [0x549855] 
2016-01-18 10:00:45.599     /lib/x86_64-linux-gnu/libpthread.so.0(+0x10340) [0x7f3d78d6d340] 
2016-01-18 10:00:45.599     /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39) [0x7f3d779a4cc9] 
2016-01-18 10:00:45.599     /lib/x86_64-linux-gnu/libc.so.6(abort+0x148) [0x7f3d779a80d8] 
2016-01-18 10:00:45.599     /lib/x86_64-linux-gnu/libc.so.6(+0x73394) [0x7f3d779e1394] 
2016-01-18 10:00:45.599     /lib/x86_64-linux-gnu/libc.so.6(+0x7f66e) [0x7f3d779ed66e] 
2016-01-18 10:00:45.599     /usr/bin/maxscale(gwbuf_free+0x3d) [0x5487e5] 
2016-01-18 10:00:45.599     /usr/bin/maxscale(gwbuf_consume+0xa6) [0x548d55] 
2016-01-18 10:00:45.599     /usr/bin/maxscale(dcb_write+0x835) [0x550717] 
2016-01-18 10:00:45.599     /usr/lib/x86_64-linux-gnu/maxscale/libMySQLBackend.so(gw_send_authentication_to_backend+0x648) [0x7f3d543dbad4] 
2016-01-18 10:00:45.599     /usr/lib/x86_64-linux-gnu/maxscale/libMySQLBackend.so(+0x479f) [0x7f3d543d779f] 
2016-01-18 10:00:45.599     /usr/bin/maxscale() [0x55fcca] 
2016-01-18 10:00:45.599     /usr/bin/maxscale(poll_waitevents+0x6d4) [0x55f57b] 
2016-01-18 10:00:45.599     /lib/x86_64-linux-gnu/libpthread.so.0(+0x8182) [0x7f3d78d65182] 
2016-01-18 10:00:45.599     /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7f3d77a6847d] 

debug2.log

2016-01-18 10:00:45.559   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.559   139901418772224 [poll_waitevents] event 1 dcb 0x28f12e0 role DCB_ROLE_SERVICE_LISTENER
2016-01-18 10:00:45.559   139901418772224 [poll_waitevents] Accept in fd 15
2016-01-18 10:00:45.559   139901418772224 [dcb_write] Wrote 86 Bytes to dcb 0x7f3d40000c50 in state DCB_STATE_ALLOC fd 21
2016-01-18 10:00:45.559   139901418772224 [poll_add_dcb] Added dcb 0x7f3d40000c50 in state DCB_STATE_POLLING to poll set.
2016-01-18 10:00:45.559   139901418772224 [gw_MySQLAccept] Added dcb 0x7f3d40000c50 for fd 21 to epoll set.
2016-01-18 10:00:45.559   139901410379520 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.560   139901410379520 [poll_waitevents] event 4 dcb 0x7f3d40000c50 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.560   139901410379520 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.560   139901410379520 [poll_waitevents] event 5 dcb 0x7f3d40000c50 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.560   139901410379520 [poll_waitevents] Read in dcb 0x7f3d40000c50 fd 21
2016-01-18 10:00:45.560   139901410379520 [dcb_read] Read 85 bytes from dcb 0x7f3d40000c50 in state DCB_STATE_POLLING fd 21.
2016-01-18 10:00:45.560   Receiving connection from 'admin' to database '(null)'.
2016-01-18 10:00:45.560   139901410379520 [gw_create_backend_connection] Connection pending to 10.0.249.15:3306, protocol fd 23 client fd 21.
2016-01-18 10:00:45.560   139901410379520 [poll_add_dcb] Added dcb 0x7f3d440009c0 in state DCB_STATE_POLLING to poll set.
2016-01-18 10:00:45.560   139901410379520 [gw_create_backend_connection] Connection pending to 10.0.249.14:3306, protocol fd 24 client fd 21.
2016-01-18 10:00:45.560   139901410379520 [poll_add_dcb] Added dcb 0x7f3d44005ae0 in state DCB_STATE_POLLING to poll set.
2016-01-18 10:00:45.560   139901410379520 [gw_create_backend_connection] Connection pending to 10.0.249.13:3306, protocol fd 25 client fd 21.
2016-01-18 10:00:45.560   139901410379520 [poll_add_dcb] Added dcb 0x7f3d44001f40 in state DCB_STATE_POLLING to poll set.
2016-01-18 10:00:45.560   139901410379520 [gw_create_backend_connection] Connection pending to 10.0.249.12:3306, protocol fd 26 client fd 21.
2016-01-18 10:00:45.560   139901410379520 [poll_add_dcb] Added dcb 0x7f3d440021a0 in state DCB_STATE_POLLING to poll set.
2016-01-18 10:00:45.560   139901410379520 [gw_create_backend_connection] Connection pending to 10.0.249.11:3306, protocol fd 27 client fd 21.
2016-01-18 10:00:45.560   139901410379520 [poll_add_dcb] Added dcb 0x7f3d44002770 in state DCB_STATE_POLLING to poll set.
2016-01-18 10:00:45.560   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.560   139901410379520 [dcb_write] Wrote 11 Bytes to dcb 0x7f3d40000c50 in state DCB_STATE_POLLING fd 21
2016-01-18 10:00:45.560   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.560   139901418772224 [poll_waitevents] event 4 dcb 0x7f3d440009c0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.560   139901418772224 [gw_write_backend_event] wrote to dcb 0x7f3d440009c0 fd 23, return 1
2016-01-18 10:00:45.560   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.560   139901418772224 [poll_waitevents] event 4 dcb 0x7f3d44005ae0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.560   139901418772224 [gw_write_backend_event] wrote to dcb 0x7f3d44005ae0 fd 24, return 1
2016-01-18 10:00:45.560   139901410379520 [poll_waitevents] event 4 dcb 0x7f3d44001f40 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.560   139901410379520 [gw_write_backend_event] wrote to dcb 0x7f3d44001f40 fd 25, return 1
2016-01-18 10:00:45.560   139901410379520 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.560   139901410379520 [poll_waitevents] event 4 dcb 0x7f3d440021a0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.560   139901410379520 [gw_write_backend_event] wrote to dcb 0x7f3d440021a0 fd 26, return 1
2016-01-18 10:00:45.560   139901410379520 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.560   139901410379520 [poll_waitevents] event 4 dcb 0x7f3d44002770 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.560   139901410379520 [gw_write_backend_event] wrote to dcb 0x7f3d44002770 fd 27, return 1
2016-01-18 10:00:45.560   139901410379520 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.560   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.560   139901410379520 [poll_waitevents] event 5 dcb 0x7f3d40000c50 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.560   139901410379520 [poll_waitevents] Read in dcb 0x7f3d40000c50 fd 21
2016-01-18 10:00:45.560   139901410379520 [dcb_read] Read 16 bytes from dcb 0x7f3d40000c50 in state DCB_STATE_POLLING fd 21.
2016-01-18 10:00:45.560   139901410379520 [gw_MySQLWrite_backend] delayed write to dcb 0x7f3d440009c0 fd 23 protocol state MYSQL_CONNECTED.
2016-01-18 10:00:45.560   139901410379520 [gw_MySQLWrite_backend] delayed write to dcb 0x7f3d44005ae0 fd 24 protocol state MYSQL_CONNECTED.
2016-01-18 10:00:45.560   139901410379520 [gw_MySQLWrite_backend] delayed write to dcb 0x7f3d44001f40 fd 25 protocol state MYSQL_CONNECTED.
2016-01-18 10:00:45.560   139901410379520 [gw_MySQLWrite_backend] delayed write to dcb 0x7f3d440021a0 fd 26 protocol state MYSQL_CONNECTED.
2016-01-18 10:00:45.560   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.560   139901418772224 [poll_waitevents] event 5 dcb 0x7f3d440009c0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.560   139901410379520 [gw_MySQLWrite_backend] delayed write to dcb 0x7f3d44002770 fd 27 protocol state MYSQL_CONNECTED.
2016-01-18 10:00:45.560   139901418772224 [gw_write_backend_event] wrote to dcb 0x7f3d440009c0 fd 23, return 1
2016-01-18 10:00:45.560   139901418772224 [poll_waitevents] Read in dcb 0x7f3d440009c0 fd 23
2016-01-18 10:00:45.560   139901393594112 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.560   139901418772224 [gw_read_backend_event] Read dcb 0x7f3d440009c0 fd 23 protocol state 2, MYSQL_CONNECTED.
2016-01-18 10:00:45.561   139901393594112 [poll_waitevents] event 5 dcb 0x7f3d44001f40 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.561   139901410379520 [poll_waitevents] event 5 dcb 0x7f3d44005ae0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.561   139901410379520 [gw_write_backend_event] wrote to dcb 0x7f3d44005ae0 fd 24, return 1
2016-01-18 10:00:45.561   139901418772224 [dcb_read] Read 105 bytes from dcb 0x7f3d440009c0 in state DCB_STATE_POLLING fd 23.
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d440021a0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.561   139901393594112 [gw_write_backend_event] wrote to dcb 0x7f3d44001f40 fd 25, return 1
2016-01-18 10:00:45.561   139901393594112 [poll_waitevents] Read in dcb 0x7f3d44001f40 fd 25
2016-01-18 10:00:45.561   139901410379520 [poll_waitevents] Read in dcb 0x7f3d44005ae0 fd 24
2016-01-18 10:00:45.561   139901393594112 [gw_read_backend_event] Read dcb 0x7f3d44001f40 fd 25 protocol state 2, MYSQL_CONNECTED.
2016-01-18 10:00:45.561   139901427164928 [gw_write_backend_event] wrote to dcb 0x7f3d440021a0 fd 26, return 1
2016-01-18 10:00:45.561   139901410379520 [gw_read_backend_event] Read dcb 0x7f3d44005ae0 fd 24 protocol state 2, MYSQL_CONNECTED.
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] Read in dcb 0x7f3d440021a0 fd 26
2016-01-18 10:00:45.561   139901418772224 [dcb_write] Wrote 97 Bytes to dcb 0x7f3d440009c0 in state DCB_STATE_POLLING fd 23
2016-01-18 10:00:45.561   139901410379520 [dcb_read] Read 105 bytes from dcb 0x7f3d44005ae0 in state DCB_STATE_POLLING fd 24.
2016-01-18 10:00:45.561   139901393594112 [dcb_read] Read 105 bytes from dcb 0x7f3d44001f40 in state DCB_STATE_POLLING fd 25.
2016-01-18 10:00:45.561   139901427164928 [gw_read_backend_event] Read dcb 0x7f3d440021a0 fd 26 protocol state 2, MYSQL_CONNECTED.
2016-01-18 10:00:45.561   139901410379520 [dcb_write] Wrote 97 Bytes to dcb 0x7f3d44005ae0 in state DCB_STATE_POLLING fd 24
2016-01-18 10:00:45.561   139901410379520 [gw_receive_backend_auth] Read zero bytes from backend dcb 0x7f3d44005ae0 fd 24 in state DCB_STATE_POLLING. n 0, head (nil), len 0
2016-01-18 10:00:45.561   139901393594112 [dcb_write] Wrote 97 Bytes to dcb 0x7f3d44001f40 in state DCB_STATE_POLLING fd 25
2016-01-18 10:00:45.561   139901418772224 [gw_receive_backend_auth] Read zero bytes from backend dcb 0x7f3d440009c0 fd 23 in state DCB_STATE_POLLING. n 0, head (nil), len 0
2016-01-18 10:00:45.561   139901427164928 [dcb_read] Read 105 bytes from dcb 0x7f3d440021a0 in state DCB_STATE_POLLING fd 26.
2016-01-18 10:00:45.561   139901393594112 [gw_receive_backend_auth] Read zero bytes from backend dcb 0x7f3d44001f40 fd 25 in state DCB_STATE_POLLING. n 0, head (nil), len 0
2016-01-18 10:00:45.561   139901410379520 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.561   139901427164928 [dcb_write] Wrote 97 Bytes to dcb 0x7f3d440021a0 in state DCB_STATE_POLLING fd 26
2016-01-18 10:00:45.561   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.561   139901427164928 [gw_receive_backend_auth] Read zero bytes from backend dcb 0x7f3d440021a0 fd 26 in state DCB_STATE_POLLING. n 0, head (nil), len 0
2016-01-18 10:00:45.561   139901418772224 [poll_waitevents] event 5 dcb 0x7f3d44002770 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.561   139901410379520 [poll_waitevents] event 5 dcb 0x7f3d440009c0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.561   139901418772224 [gw_write_backend_event] wrote to dcb 0x7f3d44002770 fd 27, return 1
2016-01-18 10:00:45.561   139901410379520 [gw_write_backend_event] wrote to dcb 0x7f3d440009c0 fd 23, return 1
2016-01-18 10:00:45.561   139901418772224 [poll_waitevents] Read in dcb 0x7f3d44002770 fd 27
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.561   139901410379520 [poll_waitevents] Read in dcb 0x7f3d440009c0 fd 23
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d44001f40 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.561   139901393594112 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.561   139901418772224 [gw_read_backend_event] Read dcb 0x7f3d44002770 fd 27 protocol state 2, MYSQL_CONNECTED.
2016-01-18 10:00:45.561   139901427164928 [gw_write_backend_event] wrote to dcb 0x7f3d44001f40 fd 25, return 1
2016-01-18 10:00:45.561   139901393594112 [poll_waitevents] event 5 dcb 0x7f3d44005ae0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.561   139901393594112 [gw_write_backend_event] wrote to dcb 0x7f3d44005ae0 fd 24, return 1
2016-01-18 10:00:45.561   139901393594112 [poll_waitevents] Read in dcb 0x7f3d44005ae0 fd 24
2016-01-18 10:00:45.561   139901418772224 [dcb_read] Read 105 bytes from dcb 0x7f3d44002770 in state DCB_STATE_POLLING fd 27.
2016-01-18 10:00:45.561   139901410379520 [gw_read_backend_event] Read dcb 0x7f3d440009c0 fd 23 protocol state 4, MYSQL_AUTH_RECV.
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] Read in dcb 0x7f3d44001f40 fd 25
2016-01-18 10:00:45.561   139901427164928 [gw_read_backend_event] Read dcb 0x7f3d44001f40 fd 25 protocol state 4, MYSQL_AUTH_RECV.
2016-01-18 10:00:45.561   139901393594112 [gw_read_backend_event] Read dcb 0x7f3d44005ae0 fd 24 protocol state 4, MYSQL_AUTH_RECV.
2016-01-18 10:00:45.561   139901418772224 [dcb_write] Wrote 97 Bytes to dcb 0x7f3d44002770 in state DCB_STATE_POLLING fd 27
2016-01-18 10:00:45.561   139901427164928 [dcb_read] Read 11 bytes from dcb 0x7f3d44001f40 in state DCB_STATE_POLLING fd 25.
2016-01-18 10:00:45.561   139901418772224 [gw_receive_backend_auth] Read zero bytes from backend dcb 0x7f3d44002770 fd 27 in state DCB_STATE_POLLING. n 0, head (nil), len 0
2016-01-18 10:00:45.561   139901393594112 [dcb_read] Read 11 bytes from dcb 0x7f3d44005ae0 in state DCB_STATE_POLLING fd 24.
2016-01-18 10:00:45.561   139901410379520 [dcb_read] Read 11 bytes from dcb 0x7f3d440009c0 in state DCB_STATE_POLLING fd 23.
2016-01-18 10:00:45.561   139901427164928 [dcb_write] Wrote 16 Bytes to dcb 0x7f3d44001f40 in state DCB_STATE_POLLING fd 25
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d440021a0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.561   139901427164928 [gw_write_backend_event] wrote to dcb 0x7f3d440021a0 fd 26, return 1
2016-01-18 10:00:45.561   139901393594112 [dcb_write] Wrote 16 Bytes to dcb 0x7f3d44005ae0 in state DCB_STATE_POLLING fd 24
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] Read in dcb 0x7f3d440021a0 fd 26
2016-01-18 10:00:45.561   139901410379520 [dcb_write] Wrote 16 Bytes to dcb 0x7f3d440009c0 in state DCB_STATE_POLLING fd 23
2016-01-18 10:00:45.561   139901427164928 [gw_read_backend_event] Read dcb 0x7f3d440021a0 fd 26 protocol state 4, MYSQL_AUTH_RECV.
2016-01-18 10:00:45.561   139901427164928 [dcb_read] Read 11 bytes from dcb 0x7f3d440021a0 in state DCB_STATE_POLLING fd 26.
2016-01-18 10:00:45.561   139901427164928 [dcb_write] Wrote 16 Bytes to dcb 0x7f3d440021a0 in state DCB_STATE_POLLING fd 26
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d44001f40 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.561   139901427164928 [gw_write_backend_event] wrote to dcb 0x7f3d44001f40 fd 25, return 1
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] Read in dcb 0x7f3d44001f40 fd 25
2016-01-18 10:00:45.561   139901427164928 [gw_read_backend_event] Read dcb 0x7f3d44001f40 fd 25 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.561   139901427164928 [dcb_read] Read 11 bytes from dcb 0x7f3d44001f40 in state DCB_STATE_POLLING fd 25.
2016-01-18 10:00:45.561   139901410379520 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.561   139901427164928 [protocol_get_srv_command] Read command COM_INIT_DB for fd 25.
2016-01-18 10:00:45.561   139901393594112 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.561   139901393594112 [poll_waitevents] event 5 dcb 0x7f3d440009c0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.561   139901410379520 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.561   139901427164928 [protocol_get_srv_command] Read command COM_INIT_DB for fd 25.
2016-01-18 10:00:45.561   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.561   139901427164928 [process_response_data] Read command COM_INIT_DB for DCB 0x7f3d44001f40 fd 25.
2016-01-18 10:00:45.561   139901393594112 [gw_write_backend_event] wrote to dcb 0x7f3d440009c0 fd 23, return 1
2016-01-18 10:00:45.561   139901418772224 [poll_waitevents] event 5 dcb 0x7f3d44002770 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.561   139901393594112 [poll_waitevents] Read in dcb 0x7f3d440009c0 fd 23
2016-01-18 10:00:45.561   139901410379520 [poll_waitevents] event 5 dcb 0x7f3d440021a0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.561   139901393594112 [gw_read_backend_event] Read dcb 0x7f3d440009c0 fd 23 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d44005ae0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.561   139901418772224 [gw_write_backend_event] wrote to dcb 0x7f3d44002770 fd 27, return 1
2016-01-18 10:00:45.561   139901410379520 [gw_write_backend_event] wrote to dcb 0x7f3d440021a0 fd 26, return 1
2016-01-18 10:00:45.561   139901418772224 [poll_waitevents] Read in dcb 0x7f3d44002770 fd 27
2016-01-18 10:00:45.561   139901393594112 [dcb_read] Read 11 bytes from dcb 0x7f3d440009c0 in state DCB_STATE_POLLING fd 23.
2016-01-18 10:00:45.561   139901418772224 [gw_read_backend_event] Read dcb 0x7f3d44002770 fd 27 protocol state 4, MYSQL_AUTH_RECV.
2016-01-18 10:00:45.561   139901427164928 [gw_write_backend_event] wrote to dcb 0x7f3d44005ae0 fd 24, return 1
2016-01-18 10:00:45.561   139901393594112 [protocol_get_srv_command] Read command COM_INIT_DB for fd 23.
2016-01-18 10:00:45.561   139901393594112 [protocol_get_srv_command] Read command COM_INIT_DB for fd 23.
2016-01-18 10:00:45.561   139901418772224 [dcb_read] Read 11 bytes from dcb 0x7f3d44002770 in state DCB_STATE_POLLING fd 27.
2016-01-18 10:00:45.561   139901410379520 [poll_waitevents] Read in dcb 0x7f3d440021a0 fd 26
2016-01-18 10:00:45.561   139901410379520 [gw_read_backend_event] Read dcb 0x7f3d440021a0 fd 26 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] Read in dcb 0x7f3d44005ae0 fd 24
2016-01-18 10:00:45.561   139901393594112 [process_response_data] Read command COM_INIT_DB for DCB 0x7f3d440009c0 fd 23.
2016-01-18 10:00:45.561   139901418772224 [dcb_write] Wrote 16 Bytes to dcb 0x7f3d44002770 in state DCB_STATE_POLLING fd 27
2016-01-18 10:00:45.561   139901410379520 [dcb_read] Read 11 bytes from dcb 0x7f3d440021a0 in state DCB_STATE_POLLING fd 26.
2016-01-18 10:00:45.561   139901427164928 [gw_read_backend_event] Read dcb 0x7f3d44005ae0 fd 24 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.561   139901410379520 [protocol_get_srv_command] Read command COM_INIT_DB for fd 26.
2016-01-18 10:00:45.561   139901410379520 [protocol_get_srv_command] Read command COM_INIT_DB for fd 26.
2016-01-18 10:00:45.561   139901410379520 [process_response_data] Read command COM_INIT_DB for DCB 0x7f3d440021a0 fd 26.
2016-01-18 10:00:45.561   139901410379520 [dcb_write] Wrote 11 Bytes to dcb 0x7f3d40000c50 in state DCB_STATE_POLLING fd 21
2016-01-18 10:00:45.561   139901427164928 [protocol_get_srv_command] Read command COM_INIT_DB for fd 24.
2016-01-18 10:00:45.561   139901427164928 [protocol_get_srv_command] Read command COM_INIT_DB for fd 24.
2016-01-18 10:00:45.561   139901427164928 [process_response_data] Read command COM_INIT_DB for DCB 0x7f3d44005ae0 fd 24.
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d44002770 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.561   139901427164928 [gw_write_backend_event] wrote to dcb 0x7f3d44002770 fd 27, return 1
2016-01-18 10:00:45.561   139901427164928 [poll_waitevents] Read in dcb 0x7f3d44002770 fd 27
2016-01-18 10:00:45.561   139901427164928 [gw_read_backend_event] Read dcb 0x7f3d44002770 fd 27 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.561   139901427164928 [dcb_read] Read 11 bytes from dcb 0x7f3d44002770 in state DCB_STATE_POLLING fd 27.
2016-01-18 10:00:45.561   139901427164928 [protocol_get_srv_command] Read command COM_INIT_DB for fd 27.
2016-01-18 10:00:45.561   139901427164928 [protocol_get_srv_command] Read command COM_INIT_DB for fd 27.
2016-01-18 10:00:45.561   139901427164928 [process_response_data] Read command COM_INIT_DB for DCB 0x7f3d44002770 fd 27.
2016-01-18 10:00:45.573   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.573   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d40000c50 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.573   139901427164928 [poll_waitevents] Read in dcb 0x7f3d40000c50 fd 21
2016-01-18 10:00:45.573   139901427164928 [dcb_read] Read 7 bytes from dcb 0x7f3d40000c50 in state DCB_STATE_POLLING fd 21.
2016-01-18 10:00:45.573   139901427164928 [gw_MySQLWrite_backend] write to dcb 0x7f3d440021a0 fd 26 protocol state MYSQL_IDLE.
2016-01-18 10:00:45.573   139901427164928 [dcb_write] Wrote 7 Bytes to dcb 0x7f3d440021a0 in state DCB_STATE_POLLING fd 26
2016-01-18 10:00:45.574   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.574   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d440021a0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.574   139901427164928 [gw_write_backend_event] wrote to dcb 0x7f3d440021a0 fd 26, return 1
2016-01-18 10:00:45.574   139901427164928 [poll_waitevents] Read in dcb 0x7f3d440021a0 fd 26
2016-01-18 10:00:45.574   139901427164928 [gw_read_backend_event] Read dcb 0x7f3d440021a0 fd 26 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.574   139901427164928 [dcb_read] Read 9 bytes from dcb 0x7f3d440021a0 in state DCB_STATE_POLLING fd 26.
2016-01-18 10:00:45.574   139901427164928 [protocol_get_srv_command] Read command UNKNOWN MYSQL PACKET TYPE for fd 26.
2016-01-18 10:00:45.574   139901427164928 [dcb_write] Wrote 9 Bytes to dcb 0x7f3d40000c50 in state DCB_STATE_POLLING fd 21
2016-01-18 10:00:45.574   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.574   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d40000c50 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.574   139901427164928 [poll_waitevents] Read in dcb 0x7f3d40000c50 fd 21
2016-01-18 10:00:45.574   139901427164928 [dcb_read] Read 58 bytes from dcb 0x7f3d40000c50 in state DCB_STATE_POLLING fd 21.
2016-01-18 10:00:45.574   139901427164928 [resolve_query_type] Item (null):FUNC_ITEM
2016-01-18 10:00:45.574   139901427164928 [resolve_query_type] Functype 1.
2016-01-18 10:00:45.574   139901427164928 [resolve_query_type] Item 1:INT_ITEM
2016-01-18 10:00:45.574   139901427164928 [resolve_query_type] Item pid:FIELD_ITEM
2016-01-18 10:00:45.574   139901427164928 [resolve_query_type] Item *:FIELD_ITEM
2016-01-18 10:00:45.574   139901427164928 [gw_MySQLWrite_backend] write to dcb 0x7f3d44005ae0 fd 24 protocol state MYSQL_IDLE.
2016-01-18 10:00:45.574   139901427164928 [dcb_write] Wrote 58 Bytes to dcb 0x7f3d44005ae0 in state DCB_STATE_POLLING fd 24
2016-01-18 10:00:45.574   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.574   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d44005ae0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.574   139901427164928 [gw_write_backend_event] wrote to dcb 0x7f3d44005ae0 fd 24, return 1
2016-01-18 10:00:45.574   139901427164928 [poll_waitevents] Read in dcb 0x7f3d44005ae0 fd 24
2016-01-18 10:00:45.574   139901427164928 [gw_read_backend_event] Read dcb 0x7f3d44005ae0 fd 24 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.574   139901427164928 [dcb_read] Read 888 bytes from dcb 0x7f3d44005ae0 in state DCB_STATE_POLLING fd 24.
2016-01-18 10:00:45.574   139901427164928 [protocol_get_srv_command] Read command UNKNOWN MYSQL PACKET TYPE for fd 24.
2016-01-18 10:00:45.574   139901427164928 [dcb_write] Wrote 888 Bytes to dcb 0x7f3d40000c50 in state DCB_STATE_POLLING fd 21
2016-01-18 10:00:45.575   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.575   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d40000c50 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.575   139901427164928 [poll_waitevents] Read in dcb 0x7f3d40000c50 fd 21
2016-01-18 10:00:45.575   139901427164928 [dcb_read] Read 204 bytes from dcb 0x7f3d40000c50 in state DCB_STATE_POLLING fd 21.
2016-01-18 10:00:45.575   139901427164928 [gw_MySQLWrite_backend] write to dcb 0x7f3d440021a0 fd 26 protocol state MYSQL_IDLE.
2016-01-18 10:00:45.575   139901427164928 [dcb_write] Wrote 204 Bytes to dcb 0x7f3d440021a0 in state DCB_STATE_POLLING fd 26
2016-01-18 10:00:45.576   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.576   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d440021a0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.576   139901427164928 [gw_write_backend_event] wrote to dcb 0x7f3d440021a0 fd 26, return 1
2016-01-18 10:00:45.576   139901427164928 [poll_waitevents] Read in dcb 0x7f3d440021a0 fd 26
2016-01-18 10:00:45.576   139901427164928 [gw_read_backend_event] Read dcb 0x7f3d440021a0 fd 26 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.576   139901427164928 [dcb_read] Read 52 bytes from dcb 0x7f3d440021a0 in state DCB_STATE_POLLING fd 26.
2016-01-18 10:00:45.576   139901427164928 [protocol_get_srv_command] Read command UNKNOWN MYSQL PACKET TYPE for fd 26.
2016-01-18 10:00:45.576   139901427164928 [dcb_write] Wrote 52 Bytes to dcb 0x7f3d40000c50 in state DCB_STATE_POLLING fd 21
2016-01-18 10:00:45.578   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.578   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d40000c50 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.561   139901427164928 [dcb_read] Read 11 bytes from dcb 0x7f3d44005ae0 in state DCB_STATE_POLLING fd 24.
2016-01-18 10:00:45.578   139901427164928 [poll_waitevents] Read in dcb 0x7f3d40000c50 fd 21
2016-01-18 10:00:45.578   139901427164928 [dcb_read] Read 52 bytes from dcb 0x7f3d40000c50 in state DCB_STATE_POLLING fd 21.
2016-01-18 10:00:45.578   139901427164928 [resolve_query_type] Item (null):FUNC_ITEM
2016-01-18 10:00:45.578   139901427164928 [resolve_query_type] Functype 1.
2016-01-18 10:00:45.578   139901427164928 [resolve_query_type] Item 1:INT_ITEM
2016-01-18 10:00:45.578   139901427164928 [resolve_query_type] Item pid:FIELD_ITEM
2016-01-18 10:00:45.578   139901427164928 [resolve_query_type] Item *:FIELD_ITEM
2016-01-18 10:00:45.578   139901427164928 [gw_MySQLWrite_backend] write to dcb 0x7f3d44005ae0 fd 24 protocol state MYSQL_IDLE.
2016-01-18 10:00:45.578   139901427164928 [dcb_write] Wrote 52 Bytes to dcb 0x7f3d44005ae0 in state DCB_STATE_POLLING fd 24
2016-01-18 10:00:45.578   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.578   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d44005ae0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.578   139901427164928 [gw_write_backend_event] wrote to dcb 0x7f3d44005ae0 fd 24, return 1
2016-01-18 10:00:45.578   139901427164928 [poll_waitevents] Read in dcb 0x7f3d44005ae0 fd 24
2016-01-18 10:00:45.578   139901427164928 [gw_read_backend_event] Read dcb 0x7f3d44005ae0 fd 24 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.578   139901427164928 [dcb_read] Read 493 bytes from dcb 0x7f3d44005ae0 in state DCB_STATE_POLLING fd 24.
2016-01-18 10:00:45.578   139901427164928 [protocol_get_srv_command] Read command UNKNOWN MYSQL PACKET TYPE for fd 24.
2016-01-18 10:00:45.578   139901427164928 [dcb_write] Wrote 493 Bytes to dcb 0x7f3d40000c50 in state DCB_STATE_POLLING fd 21
2016-01-18 10:00:45.596   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.596   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d40000c50 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.596   139901427164928 [poll_waitevents] Read in dcb 0x7f3d40000c50 fd 21
2016-01-18 10:00:45.596   139901427164928 [dcb_read] Read 16 bytes from dcb 0x7f3d40000c50 in state DCB_STATE_POLLING fd 21.
2016-01-18 10:00:45.596   139901427164928 [gw_MySQLWrite_backend] write to dcb 0x7f3d440009c0 fd 23 protocol state MYSQL_IDLE.
2016-01-18 10:00:45.596   139901427164928 [dcb_write] Wrote 16 Bytes to dcb 0x7f3d440009c0 in state DCB_STATE_POLLING fd 23
2016-01-18 10:00:45.596   139901427164928 [gw_MySQLWrite_backend] write to dcb 0x7f3d44005ae0 fd 24 protocol state MYSQL_IDLE.
2016-01-18 10:00:45.596   139901427164928 [dcb_write] Wrote 16 Bytes to dcb 0x7f3d44005ae0 in state DCB_STATE_POLLING fd 24
2016-01-18 10:00:45.596   139901427164928 [gw_MySQLWrite_backend] write to dcb 0x7f3d44001f40 fd 25 protocol state MYSQL_IDLE.
2016-01-18 10:00:45.596   139901427164928 [dcb_write] Wrote 16 Bytes to dcb 0x7f3d44001f40 in state DCB_STATE_POLLING fd 25
2016-01-18 10:00:45.596   139901427164928 [gw_MySQLWrite_backend] write to dcb 0x7f3d440021a0 fd 26 protocol state MYSQL_IDLE.
2016-01-18 10:00:45.596   139901427164928 [dcb_write] Wrote 16 Bytes to dcb 0x7f3d440021a0 in state DCB_STATE_POLLING fd 26
2016-01-18 10:00:45.596   139901427164928 [gw_MySQLWrite_backend] write to dcb 0x7f3d44002770 fd 27 protocol state MYSQL_IDLE.
2016-01-18 10:00:45.596   139901427164928 [dcb_write] Wrote 16 Bytes to dcb 0x7f3d44002770 in state DCB_STATE_POLLING fd 27
2016-01-18 10:00:45.596   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.596   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d440009c0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.596   139901427164928 [gw_write_backend_event] wrote to dcb 0x7f3d440009c0 fd 23, return 1
2016-01-18 10:00:45.596   139901427164928 [poll_waitevents] Read in dcb 0x7f3d440009c0 fd 23
2016-01-18 10:00:45.596   139901427164928 [gw_read_backend_event] Read dcb 0x7f3d440009c0 fd 23 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.596   139901427164928 [dcb_read] Read 11 bytes from dcb 0x7f3d440009c0 in state DCB_STATE_POLLING fd 23.
2016-01-18 10:00:45.596   139901427164928 [protocol_get_srv_command] Read command COM_INIT_DB for fd 23.
2016-01-18 10:00:45.596   139901427164928 [protocol_get_srv_command] Read command COM_INIT_DB for fd 23.
2016-01-18 10:00:45.596   139901427164928 [process_response_data] Read command COM_INIT_DB for DCB 0x7f3d440009c0 fd 23.
2016-01-18 10:00:45.596   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.596   139901410379520 [poll_waitevents] epoll_wait found 2 fds
2016-01-18 10:00:45.596   139901418772224 [poll_waitevents] event 5 dcb 0x7f3d44002770 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.596   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.596   139901410379520 [poll_waitevents] event 5 dcb 0x7f3d44005ae0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.596   139901418772224 [gw_write_backend_event] wrote to dcb 0x7f3d44002770 fd 27, return 1
2016-01-18 10:00:45.596   139901410379520 [gw_write_backend_event] wrote to dcb 0x7f3d44005ae0 fd 24, return 1
2016-01-18 10:00:45.596   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d44001f40 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.596   139901418772224 [poll_waitevents] Read in dcb 0x7f3d44002770 fd 27
2016-01-18 10:00:45.596   139901427164928 [gw_write_backend_event] wrote to dcb 0x7f3d44001f40 fd 25, return 1
2016-01-18 10:00:45.596   139901427164928 [poll_waitevents] Read in dcb 0x7f3d44001f40 fd 25
2016-01-18 10:00:45.596   139901427164928 [gw_read_backend_event] Read dcb 0x7f3d44001f40 fd 25 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.596   139901418772224 [gw_read_backend_event] Read dcb 0x7f3d44002770 fd 27 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.596   139901427164928 [dcb_read] Read 11 bytes from dcb 0x7f3d44001f40 in state DCB_STATE_POLLING fd 25.
2016-01-18 10:00:45.596   139901427164928 [protocol_get_srv_command] Read command COM_INIT_DB for fd 25.
2016-01-18 10:00:45.596   139901410379520 [poll_waitevents] Read in dcb 0x7f3d44005ae0 fd 24
2016-01-18 10:00:45.596   139901427164928 [protocol_get_srv_command] Read command COM_INIT_DB for fd 25.
2016-01-18 10:00:45.596   139901427164928 [process_response_data] Read command COM_INIT_DB for DCB 0x7f3d44001f40 fd 25.
2016-01-18 10:00:45.596   139901418772224 [dcb_read] Read 11 bytes from dcb 0x7f3d44002770 in state DCB_STATE_POLLING fd 27.
2016-01-18 10:00:45.596   139901410379520 [gw_read_backend_event] Read dcb 0x7f3d44005ae0 fd 24 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.596   139901418772224 [protocol_get_srv_command] Read command COM_INIT_DB for fd 27.
2016-01-18 10:00:45.596   139901418772224 [protocol_get_srv_command] Read command COM_INIT_DB for fd 27.
2016-01-18 10:00:45.596   139901418772224 [process_response_data] Read command COM_INIT_DB for DCB 0x7f3d44002770 fd 27.
2016-01-18 10:00:45.596   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d440021a0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.596   139901410379520 [dcb_read] Read 11 bytes from dcb 0x7f3d44005ae0 in state DCB_STATE_POLLING fd 24.
2016-01-18 10:00:45.596   139901427164928 [gw_write_backend_event] wrote to dcb 0x7f3d440021a0 fd 26, return 1
2016-01-18 10:00:45.596   139901410379520 [protocol_get_srv_command] Read command COM_INIT_DB for fd 24.
2016-01-18 10:00:45.596   139901410379520 [protocol_get_srv_command] Read command COM_INIT_DB for fd 24.
2016-01-18 10:00:45.596   139901410379520 [process_response_data] Read command COM_INIT_DB for DCB 0x7f3d44005ae0 fd 24.
2016-01-18 10:00:45.596   139901427164928 [poll_waitevents] Read in dcb 0x7f3d440021a0 fd 26
2016-01-18 10:00:45.596   139901427164928 [gw_read_backend_event] Read dcb 0x7f3d440021a0 fd 26 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.596   139901427164928 [dcb_read] Read 11 bytes from dcb 0x7f3d440021a0 in state DCB_STATE_POLLING fd 26.
2016-01-18 10:00:45.596   139901427164928 [protocol_get_srv_command] Read command COM_INIT_DB for fd 26.
2016-01-18 10:00:45.596   139901427164928 [protocol_get_srv_command] Read command COM_INIT_DB for fd 26.
2016-01-18 10:00:45.596   139901427164928 [process_response_data] Read command COM_INIT_DB for DCB 0x7f3d440021a0 fd 26.
2016-01-18 10:00:45.596   139901427164928 [dcb_write] Wrote 11 Bytes to dcb 0x7f3d40000c50 in state DCB_STATE_POLLING fd 21
2016-01-18 10:00:45.597   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.597   139901427164928 [poll_waitevents] event 1 dcb 0x28f12e0 role DCB_ROLE_SERVICE_LISTENER
2016-01-18 10:00:45.597   139901427164928 [poll_waitevents] Accept in fd 15
2016-01-18 10:00:45.597   139901427164928 [dcb_write] Wrote 86 Bytes to dcb 0x7f3d48005050 in state DCB_STATE_ALLOC fd 28
2016-01-18 10:00:45.597   139901427164928 [poll_add_dcb] Added dcb 0x7f3d48005050 in state DCB_STATE_POLLING to poll set.
2016-01-18 10:00:45.597   139901427164928 [gw_MySQLAccept] Added dcb 0x7f3d48005050 for fd 28 to epoll set.
2016-01-18 10:00:45.597   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.597   139901427164928 [poll_waitevents] event 4 dcb 0x7f3d48005050 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.597   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.597   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d48005050 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.597   139901427164928 [poll_waitevents] Read in dcb 0x7f3d48005050 fd 28
2016-01-18 10:00:45.597   139901427164928 [dcb_read] Read 85 bytes from dcb 0x7f3d48005050 in state DCB_STATE_POLLING fd 28.
2016-01-18 10:00:45.597   Receiving connection from 'admin' to database '(null)'.
2016-01-18 10:00:45.597   139901427164928 [gw_create_backend_connection] Connection pending to 10.0.249.12:3306, protocol fd 29 client fd 28.
2016-01-18 10:00:45.597   139901427164928 [poll_add_dcb] Added dcb 0x7f3d48005580 in state DCB_STATE_POLLING to poll set.
2016-01-18 10:00:45.597   139901427164928 [gw_create_backend_connection] Connection pending to 10.0.249.14:3306, protocol fd 30 client fd 28.
2016-01-18 10:00:45.597   139901427164928 [poll_add_dcb] Added dcb 0x7f3d480057d0 in state DCB_STATE_POLLING to poll set.
2016-01-18 10:00:45.597   139901427164928 [gw_create_backend_connection] Connection pending to 10.0.249.11:3306, protocol fd 31 client fd 28.
2016-01-18 10:00:45.597   139901427164928 [poll_add_dcb] Added dcb 0x7f3d48005a50 in state DCB_STATE_POLLING to poll set.
2016-01-18 10:00:45.597   139901427164928 [gw_create_backend_connection] Connection pending to 10.0.249.15:3306, protocol fd 32 client fd 28.
2016-01-18 10:00:45.597   139901427164928 [poll_add_dcb] Added dcb 0x7f3d48005d90 in state DCB_STATE_POLLING to poll set.
2016-01-18 10:00:45.597   139901427164928 [gw_create_backend_connection] Connection pending to 10.0.249.13:3306, protocol fd 33 client fd 28.
2016-01-18 10:00:45.597   139901427164928 [poll_add_dcb] Added dcb 0x7f3d48005f40 in state DCB_STATE_POLLING to poll set.
2016-01-18 10:00:45.597   139901410379520 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.597   139901427164928 [dcb_write] Wrote 11 Bytes to dcb 0x7f3d48005050 in state DCB_STATE_POLLING fd 28
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.597   139901410379520 [poll_waitevents] event 4 dcb 0x7f3d480057d0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.597   139901410379520 [gw_write_backend_event] wrote to dcb 0x7f3d480057d0 fd 30, return 1
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] event 4 dcb 0x7f3d48005580 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.597   139901418772224 [gw_write_backend_event] wrote to dcb 0x7f3d48005580 fd 29, return 1
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] epoll_wait found 2 fds
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] event 4 dcb 0x7f3d48005a50 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.597   139901418772224 [gw_write_backend_event] wrote to dcb 0x7f3d48005a50 fd 31, return 1
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] event 4 dcb 0x7f3d48005d90 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.597   139901418772224 [gw_write_backend_event] wrote to dcb 0x7f3d48005d90 fd 32, return 1
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] event 4 dcb 0x7f3d48005f40 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.597   139901418772224 [gw_write_backend_event] wrote to dcb 0x7f3d48005f40 fd 33, return 1
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] event 5 dcb 0x7f3d480057d0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.597   139901418772224 [gw_write_backend_event] wrote to dcb 0x7f3d480057d0 fd 30, return 1
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] Read in dcb 0x7f3d480057d0 fd 30
2016-01-18 10:00:45.597   139901418772224 [gw_read_backend_event] Read dcb 0x7f3d480057d0 fd 30 protocol state 2, MYSQL_CONNECTED.
2016-01-18 10:00:45.597   139901418772224 [dcb_read] Read 105 bytes from dcb 0x7f3d480057d0 in state DCB_STATE_POLLING fd 30.
2016-01-18 10:00:45.597   139901418772224 [dcb_write] Wrote 85 Bytes to dcb 0x7f3d480057d0 in state DCB_STATE_POLLING fd 30
2016-01-18 10:00:45.597   139901410379520 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.597   139901418772224 [gw_receive_backend_auth] Read zero bytes from backend dcb 0x7f3d480057d0 fd 30 in state DCB_STATE_POLLING. n 0, head (nil), len 0
2016-01-18 10:00:45.597   139901410379520 [poll_waitevents] event 5 dcb 0x7f3d48005050 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.597   139901410379520 [poll_waitevents] Read in dcb 0x7f3d48005050 fd 28
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.597   139901410379520 [dcb_read] Read 16 bytes from dcb 0x7f3d48005050 in state DCB_STATE_POLLING fd 28.
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] event 5 dcb 0x7f3d48005580 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.597   139901418772224 [gw_write_backend_event] wrote to dcb 0x7f3d48005580 fd 29, return 1
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] Read in dcb 0x7f3d48005580 fd 29
2016-01-18 10:00:45.597   139901418772224 [gw_read_backend_event] Read dcb 0x7f3d48005580 fd 29 protocol state 2, MYSQL_CONNECTED.
2016-01-18 10:00:45.597   139901427164928 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.597   139901427164928 [poll_waitevents] event 5 dcb 0x7f3d48005d90 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.597   139901410379520 [gw_MySQLWrite_backend] delayed write to dcb 0x7f3d48005580 fd 29 protocol state MYSQL_CONNECTED.
2016-01-18 10:00:45.597   139901427164928 [gw_write_backend_event] wrote to dcb 0x7f3d48005d90 fd 32, return 1
2016-01-18 10:00:45.597   139901393594112 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.597   139901427164928 [poll_waitevents] Read in dcb 0x7f3d48005d90 fd 32
2016-01-18 10:00:45.597   139901393594112 [poll_waitevents] event 5 dcb 0x7f3d48005a50 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.597   139902010603392 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.597   139901427164928 [gw_read_backend_event] Read dcb 0x7f3d48005d90 fd 32 protocol state 2, MYSQL_CONNECTED.
2016-01-18 10:00:45.597   139902010603392 [poll_waitevents] event 5 dcb 0x7f3d480057d0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.597   139901393594112 [gw_write_backend_event] wrote to dcb 0x7f3d48005a50 fd 31, return 1
2016-01-18 10:00:45.597   139902010603392 [gw_write_backend_event] wrote to dcb 0x7f3d480057d0 fd 30, return 1
2016-01-18 10:00:45.597   139902010603392 [poll_waitevents] Read in dcb 0x7f3d480057d0 fd 30
2016-01-18 10:00:45.597   139902010603392 [gw_read_backend_event] Read dcb 0x7f3d480057d0 fd 30 protocol state 4, MYSQL_AUTH_RECV.
2016-01-18 10:00:45.597   139901418772224 [dcb_read] Read 105 bytes from dcb 0x7f3d48005580 in state DCB_STATE_POLLING fd 29.
2016-01-18 10:00:45.597   139901427164928 [dcb_read] Read 105 bytes from dcb 0x7f3d48005d90 in state DCB_STATE_POLLING fd 32.
2016-01-18 10:00:45.597   139901393594112 [poll_waitevents] Read in dcb 0x7f3d48005a50 fd 31
2016-01-18 10:00:45.597   139902010603392 [dcb_read] Read 11 bytes from dcb 0x7f3d480057d0 in state DCB_STATE_POLLING fd 30.
2016-01-18 10:00:45.597   139901393594112 [gw_read_backend_event] Read dcb 0x7f3d48005a50 fd 31 protocol state 2, MYSQL_CONNECTED.
2016-01-18 10:00:45.597   139901393594112 [dcb_read] Read 105 bytes from dcb 0x7f3d48005a50 in state DCB_STATE_POLLING fd 31.
2016-01-18 10:00:45.597   139902010603392 [gw_write_backend_event] wrote to dcb 0x7f3d48005f40 fd 33, return 1
2016-01-18 10:00:45.597   139901410379520 [dcb_write] Wrote 16 Bytes to dcb 0x7f3d480057d0 in state DCB_STATE_POLLING fd 30
2016-01-18 10:00:45.597   139902010603392 [poll_waitevents] Read in dcb 0x7f3d48005f40 fd 33
2016-01-18 10:00:45.597   139901393594112 [dcb_write] Wrote 97 Bytes to dcb 0x7f3d48005a50 in state DCB_STATE_POLLING fd 31
2016-01-18 10:00:45.597   139901418772224 [gw_receive_backend_auth] Read zero bytes from backend dcb 0x7f3d48005580 fd 29 in state DCB_STATE_POLLING. n 0, head (nil), len 0
2016-01-18 10:00:45.597   139902010603392 [gw_read_backend_event] Read dcb 0x7f3d48005f40 fd 33 protocol state 2, MYSQL_CONNECTED.
2016-01-18 10:00:45.597   139901393594112 [gw_receive_backend_auth] Read zero bytes from backend dcb 0x7f3d48005a50 fd 31 in state DCB_STATE_POLLING. n 0, head (nil), len 0
2016-01-18 10:00:45.597   139902010603392 [dcb_read] Read 105 bytes from dcb 0x7f3d48005f40 in state DCB_STATE_POLLING fd 33.
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.597   139901410379520 [gw_MySQLWrite_backend] delayed write to dcb 0x7f3d48005a50 fd 31 protocol state MYSQL_AUTH_RECV.
2016-01-18 10:00:45.597   139901418772224 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.598   139902010603392 [dcb_write] Wrote 97 Bytes to dcb 0x7f3d48005f40 in state DCB_STATE_POLLING fd 33
2016-01-18 10:00:45.598   139901418772224 [poll_waitevents] event 5 dcb 0x7f3d480057d0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.598   139902010603392 [gw_receive_backend_auth] Read zero bytes from backend dcb 0x7f3d48005f40 fd 33 in state DCB_STATE_POLLING. n 0, head (nil), len 0
2016-01-18 10:00:45.598   139901418772224 [gw_write_backend_event] wrote to dcb 0x7f3d480057d0 fd 30, return 1
2016-01-18 10:00:45.598   139901393594112 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.598   139901393594112 [poll_waitevents] event 5 dcb 0x7f3d48005580 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.598   139902010603392 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.598   139901393594112 [gw_write_backend_event] wrote to dcb 0x7f3d48005580 fd 29, return 1
2016-01-18 10:00:45.598   139902010603392 [poll_waitevents] event 5 dcb 0x7f3d48005a50 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.598   139901418772224 [poll_waitevents] Read in dcb 0x7f3d480057d0 fd 30
2016-01-18 10:00:45.598   139901393594112 [poll_waitevents] Read in dcb 0x7f3d48005580 fd 29
2016-01-18 10:00:45.598   139901418772224 [gw_read_backend_event] Read dcb 0x7f3d480057d0 fd 30 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.598   139901393594112 [gw_read_backend_event] Read dcb 0x7f3d48005580 fd 29 protocol state 4, MYSQL_AUTH_RECV.
2016-01-18 10:00:45.598   139902010603392 [gw_write_backend_event] wrote to dcb 0x7f3d48005a50 fd 31, return 1
2016-01-18 10:00:45.598   139902010603392 [poll_waitevents] Read in dcb 0x7f3d48005a50 fd 31
2016-01-18 10:00:45.598   139902010603392 [gw_read_backend_event] Read dcb 0x7f3d48005a50 fd 31 protocol state 4, MYSQL_AUTH_RECV.
2016-01-18 10:00:45.598   139901418772224 [dcb_read] Read 11 bytes from dcb 0x7f3d480057d0 in state DCB_STATE_POLLING fd 30.
2016-01-18 10:00:45.598   139901393594112 [dcb_read] Read 11 bytes from dcb 0x7f3d48005580 in state DCB_STATE_POLLING fd 29.
2016-01-18 10:00:45.598   139902010603392 [dcb_read] Read 11 bytes from dcb 0x7f3d48005a50 in state DCB_STATE_POLLING fd 31.
2016-01-18 10:00:45.598   139901418772224 [protocol_get_srv_command] Read command COM_INIT_DB for fd 30.
2016-01-18 10:00:45.598   139901418772224 [protocol_get_srv_command] Read command COM_INIT_DB for fd 30.
2016-01-18 10:00:45.598   139901393594112 [dcb_write] Wrote 16 Bytes to dcb 0x7f3d48005580 in state DCB_STATE_POLLING fd 29
2016-01-18 10:00:45.598   139901311907584 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.598   139901418772224 [process_response_data] Read command COM_INIT_DB for DCB 0x7f3d480057d0 fd 30.
2016-01-18 10:00:45.598   139902010603392 [dcb_write] Wrote 16 Bytes to dcb 0x7f3d48005a50 in state DCB_STATE_POLLING fd 31
2016-01-18 10:00:45.598   139901311907584 [poll_waitevents] event 5 dcb 0x7f3d48005f40 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.598   139901311907584 [gw_write_backend_event] wrote to dcb 0x7f3d48005f40 fd 33, return 1
2016-01-18 10:00:45.598   139901311907584 [poll_waitevents] Read in dcb 0x7f3d48005f40 fd 33
2016-01-18 10:00:45.598   139901311907584 [gw_read_backend_event] Read dcb 0x7f3d48005f40 fd 33 protocol state 4, MYSQL_AUTH_RECV.
2016-01-18 10:00:45.598   139901311907584 [dcb_read] Read 11 bytes from dcb 0x7f3d48005f40 in state DCB_STATE_POLLING fd 33.
2016-01-18 10:00:45.598   139902010603392 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.598   139902010603392 [poll_waitevents] event 5 dcb 0x7f3d48005580 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.598   139902010603392 [gw_write_backend_event] wrote to dcb 0x7f3d48005580 fd 29, return 1
2016-01-18 10:00:45.598   139902010603392 [poll_waitevents] Read in dcb 0x7f3d48005580 fd 29
2016-01-18 10:00:45.598   139901393594112 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 10:00:45.598   139902010603392 [gw_read_backend_event] Read dcb 0x7f3d48005580 fd 29 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.598   139901393594112 [poll_waitevents] event 5 dcb 0x7f3d48005a50 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 10:00:45.598   139902010603392 [dcb_read] Read 11 bytes from dcb 0x7f3d48005580 in state DCB_STATE_POLLING fd 29.
2016-01-18 10:00:45.598   139901393594112 [gw_write_backend_event] wrote to dcb 0x7f3d48005a50 fd 31, return 1
2016-01-18 10:00:45.598   139902010603392 [protocol_get_srv_command] Read command COM_INIT_DB for fd 29.
2016-01-18 10:00:45.598   139901393594112 [poll_waitevents] Read in dcb 0x7f3d48005a50 fd 31
2016-01-18 10:00:45.598   139901393594112 [gw_read_backend_event] Read dcb 0x7f3d48005a50 fd 31 protocol state 11, MYSQL_IDLE.
2016-01-18 10:00:45.598   139902010603392 [protocol_get_srv_command] Read command COM_INIT_DB for fd 29.
2016-01-18 10:00:45.598   139901393594112 [dcb_read] Read 11 bytes from dcb 0x7f3d48005a50 in state DCB_STATE_POLLING fd 31.
2016-01-18 10:00:45.598   139902010603392 [process_response_data] Read command COM_INIT_DB for DCB 0x7f3d48005580 fd 29.
2016-01-18 10:00:45.598   139901393594112 [protocol_get_srv_command] Read command COM_INIT_DB for fd 31.
2016-01-18 10:00:45.598   139901393594112 [protocol_get_srv_command] Read command COM_INIT_DB for fd 31.
2016-01-18 10:00:45.598   139901393594112 [process_response_data] Read command COM_INIT_DB for DCB 0x7f3d48005a50 fd 31.
2016-01-18 10:00:45.597   139901418772224 [dcb_write] Wrote 97 Bytes to dcb 0x7f3d48005580 in state DCB_STATE_POLLING fd 29
2016-01-18 10:00:45.597   139901410379520 [gw_MySQLWrite_backend] write to dcb 0x7f3d480057d0 fd 30 protocol state MYSQL_IDLE.
2016-01-18 10:00:45.597   139902010603392 [poll_waitevents] event 5 dcb 0x7f3d48005f40 role DCB_ROLE_REQUEST_HANDLER

trace2.log

2016-01-18 10:00:45.560   Servers and router connection counts:
2016-01-18 10:00:45.560   current operations : 0 in 	10.0.249.15:3306 RUNNING SLAVE
2016-01-18 10:00:45.560   current operations : 0 in 	10.0.249.14:3306 RUNNING SLAVE
2016-01-18 10:00:45.560   current operations : 0 in 	10.0.249.13:3306 RUNNING SLAVE
2016-01-18 10:00:45.560   current operations : 0 in 	10.0.249.12:3306 RUNNING MASTER
2016-01-18 10:00:45.560   current operations : 0 in 	10.0.249.11:3306 RUNNING SLAVE
2016-01-18 10:00:45.560   Selected RUNNING SLAVE in 	10.0.249.15:3306
2016-01-18 10:00:45.560   Selected RUNNING SLAVE in 	10.0.249.14:3306
2016-01-18 10:00:45.560   Selected RUNNING SLAVE in 	10.0.249.13:3306
2016-01-18 10:00:45.560   Selected RUNNING MASTER in 	10.0.249.12:3306
2016-01-18 10:00:45.560   Selected RUNNING SLAVE in 	10.0.249.11:3306
2016-01-18 10:00:45.560   Started galera_rw_service client session [884] for 'admin' from 10.0.248.73
2016-01-18 10:00:45.560   [884]  > Autocommit: [enabled], trx is [not open], cmd: COM_INIT_DB, type: QUERY_TYPE_SESSION_WRITE, stmt: atiftest_eu 
2016-01-18 10:00:45.560   [884]  Session write, routing to all servers.
2016-01-18 10:00:45.560   [884]  Route query to slave 	10.0.249.15:3306 
2016-01-18 10:00:45.560   [884]  Route query to slave 	10.0.249.14:3306 
2016-01-18 10:00:45.560   [884]  Route query to slave 	10.0.249.13:3306 
2016-01-18 10:00:45.560   [884]  Route query to master 	10.0.249.12:3306 
2016-01-18 10:00:45.560   [884]  Route query to slave 	10.0.249.11:3306 <
2016-01-18 10:00:45.561   [884]  Slave 'db3' responded before master to a session command. Result: 0
2016-01-18 10:00:45.561   [884]  Slave 'db5' responded before master to a session command. Result: 0
2016-01-18 10:00:45.561   [884]  Master 'db2' responded to a session command.
2016-01-18 10:00:45.573   [884]  > Autocommit: [enabled], trx is [not open], cmd: UNKNOWN MYSQL PACKET TYPE, type: N/A, stmt: � 
2016-01-18 10:00:45.573   [884]  Route query to master 	10.0.249.12:3306 <
2016-01-18 10:00:45.574   [884]  > Autocommit: [enabled], trx is [not open], cmd: COM_QUERY, type: QUERY_TYPE_READ, stmt: SELECT * FROM xoops_portal_index_status WHERE pid = 1 
2016-01-18 10:00:45.574   [884]  Route query to slave 	10.0.249.14:3306 <
2016-01-18 10:00:45.575   [884]  > Autocommit: [enabled], trx is [not open], cmd: COM_QUERY, type: QUERY_TYPE_WRITE, stmt: UPDATE xoops_portal_index_status SET `structure_status` = 'PROCESSING', `structure_last_update` = '2016-01-18 09:00:45', `data_status` = 'OK', `data_last_update` = '2016-01-18 09:00:45' WHERE pid = 1 
2016-01-18 10:00:45.575   [884]  Route query to master 	10.0.249.12:3306 <
2016-01-18 10:00:45.578   [884]  > Autocommit: [enabled], trx is [not open], cmd: COM_QUERY, type: QUERY_TYPE_READ, stmt: SELECT * FROM xoops_portal_fields WHERE pid = 1 
2016-01-18 10:00:45.578   [884]  Route query to slave 	10.0.249.14:3306 <
2016-01-18 10:00:45.596   [884]  > Autocommit: [enabled], trx is [not open], cmd: COM_INIT_DB, type: QUERY_TYPE_SESSION_WRITE, stmt: atiftest_eu 
2016-01-18 10:00:45.596   [884]  Session write, routing to all servers.
2016-01-18 10:00:45.596   [884]  Route query to slave 	10.0.249.15:3306 
2016-01-18 10:00:45.596   [884]  Route query to slave 	10.0.249.14:3306 
2016-01-18 10:00:45.596   [884]  Route query to slave 	10.0.249.13:3306 
2016-01-18 10:00:45.596   [884]  Route query to master 	10.0.249.12:3306 
2016-01-18 10:00:45.596   [884]  Route query to slave 	10.0.249.11:3306 <
2016-01-18 10:00:45.596   [884]  Slave 'db5' responded before master to a session command. Result: 0
2016-01-18 10:00:45.596   [884]  Slave 'db3' responded before master to a session command. Result: 0
2016-01-18 10:00:45.596   [884]  Slave 'db1' responded before master to a session command. Result: 0
2016-01-18 10:00:45.596   [884]  Slave 'db4' responded before master to a session command. Result: 0
2016-01-18 10:00:45.596   [884]  Master 'db2' responded to a session command.
2016-01-18 10:00:45.597   Servers and router connection counts:
2016-01-18 10:00:45.597   current operations : 0 in 	10.0.249.12:3306 RUNNING MASTER
2016-01-18 10:00:45.597   current operations : 1 in 	10.0.249.14:3306 RUNNING SLAVE
2016-01-18 10:00:45.597   current operations : 1 in 	10.0.249.11:3306 RUNNING SLAVE
2016-01-18 10:00:45.597   current operations : 2 in 	10.0.249.15:3306 RUNNING SLAVE
2016-01-18 10:00:45.597   current operations : 2 in 	10.0.249.13:3306 RUNNING SLAVE
2016-01-18 10:00:45.597   Selected RUNNING MASTER in 	10.0.249.12:3306
2016-01-18 10:00:45.597   Selected RUNNING SLAVE in 	10.0.249.14:3306
2016-01-18 10:00:45.597   Selected RUNNING SLAVE in 	10.0.249.11:3306
2016-01-18 10:00:45.597   Selected RUNNING SLAVE in 	10.0.249.15:3306
2016-01-18 10:00:45.597   Selected RUNNING SLAVE in 	10.0.249.13:3306
2016-01-18 10:00:45.597   Started galera_rw_service client session [885] for 'admin' from 10.0.248.73
2016-01-18 10:00:45.597   [885]  > Autocommit: [enabled], trx is [not open], cmd: COM_INIT_DB, type: QUERY_TYPE_SESSION_WRITE, stmt: atiftest_eu 
2016-01-18 10:00:45.597   [885]  Session write, routing to all servers.
2016-01-18 10:00:45.597   [885]  Route query to master 	10.0.249.12:3306 
2016-01-18 10:00:45.597   [885]  Route query to slave 	10.0.249.14:3306 
2016-01-18 10:00:45.597   [885]  Route query to slave 	10.0.249.11:3306 
2016-01-18 10:00:45.597   [885]  Route query to slave 	10.0.249.15:3306 
2016-01-18 10:00:45.599   [885]  Starting log flushing to disk.

Comment by Florian Engelmann [ 2016-01-18 ]

more crashes:

2016-01-18 12:13:18   Error : Invalid authentication message from backend. Packet type : 0xfe
2016-01-18 12:15:28   Error : Invalid authentication message from backend. Packet type : 0xfe

Comment by Florian Engelmann [ 2016-01-18 ]

another crash

error1.log

2016-01-18 12:28:21   Error : Invalid authentication message from backend. Packet type : 0xfe
2016-01-18 12:28:34   Error : Invalid authentication message from backend. Packet type : 0xfe
2016-01-18 12:28:42   Error : Invalid authentication message from backend. Packet type : 0xfe
2016-01-18 12:29:54   Error : Invalid authentication message from backend. Packet type : 0xfe
2016-01-18 12:30:05   Error : Invalid authentication message from backend. Packet type : 0xfe
2016-01-18 12:30:07   Fatal: MaxScale 1.2.1 received fatal signal 6. Attempting backtrace.
2016-01-18 12:30:07   Commit ID: 7bfda81b098bfd0db3c306495725d1910294d2e8 System name: Linux Release string: Ubuntu 14.04.3 LTS Embedded library version: 5.5.42-MariaDB
2016-01-18 12:30:07     /usr/bin/maxscale() [0x549855] 
2016-01-18 12:30:07     /lib/x86_64-linux-gnu/libpthread.so.0(+0x10340) [0x7fd9d8a1a340] 
2016-01-18 12:30:07     /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39) [0x7fd9d7651cc9] 
2016-01-18 12:30:07     /lib/x86_64-linux-gnu/libc.so.6(abort+0x148) [0x7fd9d76550d8] 
2016-01-18 12:30:07     /lib/x86_64-linux-gnu/libc.so.6(+0x73394) [0x7fd9d768e394] 
2016-01-18 12:30:07     /lib/x86_64-linux-gnu/libc.so.6(+0x7f66e) [0x7fd9d769a66e] 
2016-01-18 12:30:07     /usr/bin/maxscale(gwbuf_free+0x3d) [0x5487e5] 
2016-01-18 12:30:07     /usr/bin/maxscale(gwbuf_consume+0xa6) [0x548d55] 
2016-01-18 12:30:07     /usr/bin/maxscale(dcb_write+0x835) [0x550717] 
2016-01-18 12:30:07     /usr/lib/x86_64-linux-gnu/maxscale/libMySQLBackend.so(gw_send_authentication_to_backend+0x648) [0x7fd9b51d4ad4] 
2016-01-18 12:30:07     /usr/lib/x86_64-linux-gnu/maxscale/libMySQLBackend.so(+0x479f) [0x7fd9b51d079f] 
2016-01-18 12:30:07     /usr/bin/maxscale() [0x55fcca] 
2016-01-18 12:30:07     /usr/bin/maxscale(poll_waitevents+0x6d4) [0x55f57b] 
2016-01-18 12:30:07     /lib/x86_64-linux-gnu/libpthread.so.0(+0x8182) [0x7fd9d8a12182] 
2016-01-18 12:30:07     /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7fd9d771547d] 

debug2.log

2016-01-18 12:30:07   140573632628608 [dcb_read] Read 11 bytes from dcb 0x7fd9a0002de0 in state DCB_STATE_POLLING fd 25.
2016-01-18 12:30:07   140573632628608 [protocol_get_srv_command] Read command COM_PING for fd 25.
2016-01-18 12:30:07   140573632628608 [protocol_get_srv_command] Read command COM_PING for fd 25.
2016-01-18 12:30:07   140573632628608 [process_response_data] Read command COM_PING for DCB 0x7fd9a0002de0 fd 25.
2016-01-18 12:30:07   140573632628608 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573632628608 [poll_waitevents] event 5 dcb 0x7fd9ac003260 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573632628608 [poll_waitevents] Read in dcb 0x7fd9ac003260 fd 21
2016-01-18 12:30:07   140573632628608 [dcb_read] Read 204 bytes from dcb 0x7fd9ac003260 in state DCB_STATE_POLLING fd 21.
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Item tpl_refid:FIELD_ITEM
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Item (null):COND_ITEM
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Item (null):FUNC_ITEM
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Functype 1.
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Item system_redirect.html:STRING_ITEM
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Item tpl_file:FIELD_ITEM
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Item (null):FUNC_ITEM
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Functype 1.
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Item alliance-2012-unterseite:STRING_ITEM
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Item tpl_tplset:FIELD_ITEM
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Item (null):FUNC_ITEM
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Functype 1.
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Item tpl_id:FIELD_ITEM
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Item tpl_id:FIELD_ITEM
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Item tpl_source:FIELD_ITEM
2016-01-18 12:30:07   140573632628608 [resolve_query_type] Item *:FIELD_ITEM
2016-01-18 12:30:07   140573632628608 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0002b80 fd 24 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573632628608 [dcb_write] Wrote 204 Bytes to dcb 0x7fd9a0002b80 in state DCB_STATE_POLLING fd 24
2016-01-18 12:30:07   140573632628608 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573632628608 [poll_waitevents] event 5 dcb 0x7fd9a0002b80 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573632628608 [gw_write_backend_event] wrote to dcb 0x7fd9a0002b80 fd 24, return 1
2016-01-18 12:30:07   140573632628608 [poll_waitevents] Read in dcb 0x7fd9a0002b80 fd 24
2016-01-18 12:30:07   140573632628608 [gw_read_backend_event] Read dcb 0x7fd9a0002b80 fd 24 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573632628608 [dcb_read] Read 847 bytes from dcb 0x7fd9a0002b80 in state DCB_STATE_POLLING fd 24.
2016-01-18 12:30:07   140573632628608 [protocol_get_srv_command] Read command UNKNOWN MYSQL PACKET TYPE for fd 24.
2016-01-18 12:30:07   140573632628608 [dcb_write] Wrote 847 Bytes to dcb 0x7fd9ac003260 in state DCB_STATE_POLLING fd 21
2016-01-18 12:30:07   140573632628608 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573632628608 [poll_waitevents] event 5 dcb 0x7fd9ac003260 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573632628608 [poll_waitevents] Read in dcb 0x7fd9ac003260 fd 21
2016-01-18 12:30:07   140573632628608 [dcb_read] Read 5 bytes from dcb 0x7fd9ac003260 in state DCB_STATE_POLLING fd 21.
2016-01-18 12:30:07   140573632628608 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0005400 fd 23 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573632628608 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0005400 in state DCB_STATE_POLLING fd 23
2016-01-18 12:30:07   140573632628608 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0002b80 fd 24 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573632628608 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0002b80 in state DCB_STATE_POLLING fd 24
2016-01-18 12:30:07   140573632628608 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0002de0 fd 25 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573632628608 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0002de0 in state DCB_STATE_POLLING fd 25
2016-01-18 12:30:07   140573632628608 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0003040 fd 26 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573632628608 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0003040 in state DCB_STATE_POLLING fd 26
2016-01-18 12:30:07   140573632628608 [gw_MySQLWrite_backend] write to dcb 0x7fd9a00032a0 fd 27 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573632628608 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a00032a0 in state DCB_STATE_POLLING fd 27
2016-01-18 12:30:07   140573632628608 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573632628608 [poll_waitevents] event 5 dcb 0x7fd9a00032a0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573632628608 [gw_write_backend_event] wrote to dcb 0x7fd9a00032a0 fd 27, return 1
2016-01-18 12:30:07   140573632628608 [poll_waitevents] Read in dcb 0x7fd9a00032a0 fd 27
2016-01-18 12:30:07   140573632628608 [gw_read_backend_event] Read dcb 0x7fd9a00032a0 fd 27 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 2 fds
2016-01-18 12:30:07   140573632628608 [dcb_read] Read 11 bytes from dcb 0x7fd9a00032a0 in state DCB_STATE_POLLING fd 27.
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9a0002b80 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [gw_write_backend_event] wrote to dcb 0x7fd9a0002b80 fd 24, return 1
2016-01-18 12:30:07   140573632628608 [protocol_get_srv_command] Read command COM_PING for fd 27.
2016-01-18 12:30:07   140573042149120 [poll_waitevents] epoll_wait found 2 fds
2016-01-18 12:30:07   140573632628608 [protocol_get_srv_command] Read command COM_PING for fd 27.
2016-01-18 12:30:07   140573632628608 [process_response_data] Read command COM_PING for DCB 0x7fd9a00032a0 fd 27.
2016-01-18 12:30:07   140573042149120 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573042149120 [poll_waitevents] event 5 dcb 0x7fd9a0002de0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573632628608 [poll_waitevents] event 5 dcb 0x7fd9a0005400 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573632628608 [gw_write_backend_event] wrote to dcb 0x7fd9a0005400 fd 23, return 1
2016-01-18 12:30:07   140573050541824 [gw_read_backend_event] Read dcb 0x7fd9a0002b80 fd 24 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [poll_waitevents] Read in dcb 0x7fd9a0002de0 fd 25
2016-01-18 12:30:07   140573632628608 [poll_waitevents] Read in dcb 0x7fd9a0005400 fd 23
2016-01-18 12:30:07   140573632628608 [gw_read_backend_event] Read dcb 0x7fd9a0005400 fd 23 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573632628608 [dcb_read] Read 11 bytes from dcb 0x7fd9a0005400 in state DCB_STATE_POLLING fd 23.
2016-01-18 12:30:07   140573632628608 [protocol_get_srv_command] Read command COM_PING for fd 23.
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 11 bytes from dcb 0x7fd9a0002b80 in state DCB_STATE_POLLING fd 24.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 24.
2016-01-18 12:30:07   140573042149120 [gw_read_backend_event] Read dcb 0x7fd9a0002de0 fd 25 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573632628608 [protocol_get_srv_command] Read command COM_PING for fd 23.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 24.
2016-01-18 12:30:07   140573050541824 [process_response_data] Read command COM_PING for DCB 0x7fd9a0002b80 fd 24.
2016-01-18 12:30:07   140573042149120 [dcb_read] Read 11 bytes from dcb 0x7fd9a0002de0 in state DCB_STATE_POLLING fd 25.
2016-01-18 12:30:07   140573632628608 [process_response_data] Read command COM_PING for DCB 0x7fd9a0005400 fd 23.
2016-01-18 12:30:07   140573042149120 [protocol_get_srv_command] Read command COM_PING for fd 25.
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9a0003040 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [gw_write_backend_event] wrote to dcb 0x7fd9a0003040 fd 26, return 1
2016-01-18 12:30:07   140573042149120 [protocol_get_srv_command] Read command COM_PING for fd 25.
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9a0003040 fd 26
2016-01-18 12:30:07   140573050541824 [gw_read_backend_event] Read dcb 0x7fd9a0003040 fd 26 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 11 bytes from dcb 0x7fd9a0003040 in state DCB_STATE_POLLING fd 26.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 26.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 26.
2016-01-18 12:30:07   140573050541824 [process_response_data] Read command COM_PING for DCB 0x7fd9a0003040 fd 26.
2016-01-18 12:30:07   140573042149120 [process_response_data] Read command COM_PING for DCB 0x7fd9a0002de0 fd 25.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 11 Bytes to dcb 0x7fd9ac003260 in state DCB_STATE_POLLING fd 21
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9ac003260 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9ac003260 fd 21
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 5 bytes from dcb 0x7fd9ac003260 in state DCB_STATE_POLLING fd 21.
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0005400 fd 23 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0005400 in state DCB_STATE_POLLING fd 23
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0002b80 fd 24 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0002b80 in state DCB_STATE_POLLING fd 24
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0002de0 fd 25 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0002de0 in state DCB_STATE_POLLING fd 25
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0003040 fd 26 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0003040 in state DCB_STATE_POLLING fd 26
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a00032a0 fd 27 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a00032a0 in state DCB_STATE_POLLING fd 27
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9a0003040 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [gw_write_backend_event] wrote to dcb 0x7fd9a0003040 fd 26, return 1
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9a0003040 fd 26
2016-01-18 12:30:07   140573050541824 [gw_read_backend_event] Read dcb 0x7fd9a0003040 fd 26 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 11 bytes from dcb 0x7fd9a0003040 in state DCB_STATE_POLLING fd 26.
2016-01-18 12:30:07   140573632628608 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573632628608 [poll_waitevents] event 5 dcb 0x7fd9a0002de0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573042149120 [poll_waitevents] event 5 dcb 0x7fd9a00032a0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 26.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 26.
2016-01-18 12:30:07   140573632628608 [gw_write_backend_event] wrote to dcb 0x7fd9a0002de0 fd 25, return 1
2016-01-18 12:30:07   140573050541824 [process_response_data] Read command COM_PING for DCB 0x7fd9a0003040 fd 26.
2016-01-18 12:30:07   140573033756416 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573632628608 [poll_waitevents] Read in dcb 0x7fd9a0002de0 fd 25
2016-01-18 12:30:07   140573033756416 [poll_waitevents] event 5 dcb 0x7fd9a0005400 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573632628608 [gw_read_backend_event] Read dcb 0x7fd9a0002de0 fd 25 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [gw_write_backend_event] wrote to dcb 0x7fd9a00032a0 fd 27, return 1
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 11 Bytes to dcb 0x7fd9ac003260 in state DCB_STATE_POLLING fd 21
2016-01-18 12:30:07   140573042149120 [poll_waitevents] Read in dcb 0x7fd9a00032a0 fd 27
2016-01-18 12:30:07   140573033756416 [gw_write_backend_event] wrote to dcb 0x7fd9a0005400 fd 23, return 1
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573632628608 [dcb_read] Read 11 bytes from dcb 0x7fd9a0002de0 in state DCB_STATE_POLLING fd 25.
2016-01-18 12:30:07   140573042149120 [gw_read_backend_event] Read dcb 0x7fd9a00032a0 fd 27 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573632628608 [protocol_get_srv_command] Read command COM_PING for fd 25.
2016-01-18 12:30:07   140573033756416 [poll_waitevents] Read in dcb 0x7fd9a0005400 fd 23
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9a0002b80 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573033756416 [gw_read_backend_event] Read dcb 0x7fd9a0005400 fd 23 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573632628608 [poll_waitevents] event 5 dcb 0x7fd9a0002de0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573042149120 [gw_read_backend_event] Read dcb 0x7fd9a0003040 fd 26 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573632628608 [protocol_get_srv_command] Read command COM_PING for fd 25.
2016-01-18 12:30:07   140573042149120 [dcb_read] Read 11 bytes from dcb 0x7fd9a00032a0 in state DCB_STATE_POLLING fd 27.
2016-01-18 12:30:07   140573632628608 [process_response_data] Read command COM_PING for DCB 0x7fd9a0002de0 fd 25.
2016-01-18 12:30:07   140573042149120 [protocol_get_srv_command] Read command COM_PING for fd 27.
2016-01-18 12:30:07   140573033756416 [dcb_read] Read 11 bytes from dcb 0x7fd9a0005400 in state DCB_STATE_POLLING fd 23.
2016-01-18 12:30:07   140573050541824 [gw_write_backend_event] wrote to dcb 0x7fd9a0002b80 fd 24, return 1
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9a0002b80 fd 24
2016-01-18 12:30:07   140573042149120 [protocol_get_srv_command] Read command COM_PING for fd 27.
2016-01-18 12:30:07   140573033756416 [protocol_get_srv_command] Read command COM_PING for fd 23.
2016-01-18 12:30:07   140573033756416 [protocol_get_srv_command] Read command COM_PING for fd 23.
2016-01-18 12:30:07   140573033756416 [process_response_data] Read command COM_PING for DCB 0x7fd9a0005400 fd 23.
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 11 bytes from dcb 0x7fd9a0002b80 in state DCB_STATE_POLLING fd 24.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 24.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 24.
2016-01-18 12:30:07   140573050541824 [process_response_data] Read command COM_PING for DCB 0x7fd9a0002b80 fd 24.
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9ac003260 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9ac003260 fd 21
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 137 bytes from dcb 0x7fd9ac003260 in state DCB_STATE_POLLING fd 21.
2016-01-18 12:30:07   140573050541824 [resolve_query_type] Item tpl_refid:FIELD_ITEM
2016-01-18 12:30:07   140573050541824 [resolve_query_type] Item (null):COND_ITEM
2016-01-18 12:30:07   140573050541824 [resolve_query_type] Item (null):FUNC_ITEM
2016-01-18 12:30:07   140573050541824 [resolve_query_type] Functype 1.
2016-01-18 12:30:07   140573050541824 [resolve_query_type] Item system_redirect.html:STRING_ITEM
2016-01-18 12:30:07   140573050541824 [resolve_query_type] Item tpl_file:FIELD_ITEM
2016-01-18 12:30:07   140573050541824 [resolve_query_type] Item (null):FUNC_ITEM
2016-01-18 12:30:07   140573050541824 [resolve_query_type] Functype 1.
2016-01-18 12:30:07   140573050541824 [resolve_query_type] Item alliance-2012-unterseite:STRING_ITEM
2016-01-18 12:30:07   140573050541824 [resolve_query_type] Item tpl_tplset:FIELD_ITEM
2016-01-18 12:30:07   140573050541824 [resolve_query_type] Item *:FIELD_ITEM
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0002b80 fd 24 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 137 Bytes to dcb 0x7fd9a0002b80 in state DCB_STATE_POLLING fd 24
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9a0002b80 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [gw_write_backend_event] wrote to dcb 0x7fd9a0002b80 fd 24, return 1
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9a0002b80 fd 24
2016-01-18 12:30:07   140573050541824 [gw_read_backend_event] Read dcb 0x7fd9a0002b80 fd 24 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 871 bytes from dcb 0x7fd9a0002b80 in state DCB_STATE_POLLING fd 24.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command UNKNOWN MYSQL PACKET TYPE for fd 24.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 871 Bytes to dcb 0x7fd9ac003260 in state DCB_STATE_POLLING fd 21
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9ac003260 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9ac003260 fd 21
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 5 bytes from dcb 0x7fd9ac003260 in state DCB_STATE_POLLING fd 21.
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0005400 fd 23 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0005400 in state DCB_STATE_POLLING fd 23
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0002b80 fd 24 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0002b80 in state DCB_STATE_POLLING fd 24
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0002de0 fd 25 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0002de0 in state DCB_STATE_POLLING fd 25
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0003040 fd 26 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0003040 in state DCB_STATE_POLLING fd 26
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a00032a0 fd 27 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a00032a0 in state DCB_STATE_POLLING fd 27
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9a00032a0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [gw_write_backend_event] wrote to dcb 0x7fd9a00032a0 fd 27, return 1
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9a00032a0 fd 27
2016-01-18 12:30:07   140573050541824 [gw_read_backend_event] Read dcb 0x7fd9a00032a0 fd 27 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 11 bytes from dcb 0x7fd9a00032a0 in state DCB_STATE_POLLING fd 27.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 27.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 27.
2016-01-18 12:30:07   140573050541824 [process_response_data] Read command COM_PING for DCB 0x7fd9a00032a0 fd 27.
2016-01-18 12:30:07   140573042149120 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573042149120 [poll_waitevents] event 5 dcb 0x7fd9a0002de0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573042149120 [gw_write_backend_event] wrote to dcb 0x7fd9a0002de0 fd 25, return 1
2016-01-18 12:30:07   140573042149120 [poll_waitevents] Read in dcb 0x7fd9a0002de0 fd 25
2016-01-18 12:30:07   140573042149120 [gw_read_backend_event] Read dcb 0x7fd9a0002de0 fd 25 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [dcb_read] Read 11 bytes from dcb 0x7fd9a0002de0 in state DCB_STATE_POLLING fd 25.
2016-01-18 12:30:07   140573042149120 [protocol_get_srv_command] Read command COM_PING for fd 25.
2016-01-18 12:30:07   140573042149120 [protocol_get_srv_command] Read command COM_PING for fd 25.
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573042149120 [process_response_data] Read command COM_PING for DCB 0x7fd9a0002de0 fd 25.
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9a0002b80 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [gw_write_backend_event] wrote to dcb 0x7fd9a0002b80 fd 24, return 1
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9a0002b80 fd 24
2016-01-18 12:30:07   140573042149120 [gw_write_backend_event] wrote to dcb 0x7fd9a0002de0 fd 25, return 1
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9a0002b80 fd 24
2016-01-18 12:30:07   140573050541824 [gw_read_backend_event] Read dcb 0x7fd9a0002b80 fd 24 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 11 bytes from dcb 0x7fd9a0002b80 in state DCB_STATE_POLLING fd 24.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 24.
2016-01-18 12:30:07   140573042149120 [poll_waitevents] event 5 dcb 0x7fd9a0005400 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 24.
2016-01-18 12:30:07   140573042149120 [gw_write_backend_event] wrote to dcb 0x7fd9a0005400 fd 23, return 1
2016-01-18 12:30:07   140573050541824 [process_response_data] Read command COM_PING for DCB 0x7fd9a0002b80 fd 24.
2016-01-18 12:30:07   140573042149120 [poll_waitevents] Read in dcb 0x7fd9a0005400 fd 23
2016-01-18 12:30:07   140573042149120 [gw_read_backend_event] Read dcb 0x7fd9a0005400 fd 23 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [dcb_read] Read 11 bytes from dcb 0x7fd9a0005400 in state DCB_STATE_POLLING fd 23.
2016-01-18 12:30:07   140573042149120 [protocol_get_srv_command] Read command COM_PING for fd 23.
2016-01-18 12:30:07   140573042149120 [protocol_get_srv_command] Read command COM_PING for fd 23.
2016-01-18 12:30:07   140573042149120 [process_response_data] Read command COM_PING for DCB 0x7fd9a0005400 fd 23.
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9a0003040 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [gw_write_backend_event] wrote to dcb 0x7fd9a0003040 fd 26, return 1
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9a0003040 fd 26
2016-01-18 12:30:07   140573050541824 [gw_read_backend_event] Read dcb 0x7fd9a0003040 fd 26 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 11 bytes from dcb 0x7fd9a0003040 in state DCB_STATE_POLLING fd 26.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 26.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 26.
2016-01-18 12:30:07   140573050541824 [process_response_data] Read command COM_PING for DCB 0x7fd9a0003040 fd 26.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 11 Bytes to dcb 0x7fd9ac003260 in state DCB_STATE_POLLING fd 21
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9ac003260 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9ac003260 fd 21
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 5 bytes from dcb 0x7fd9ac003260 in state DCB_STATE_POLLING fd 21.
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0005400 fd 23 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0005400 in state DCB_STATE_POLLING fd 23
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0002b80 fd 24 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0002b80 in state DCB_STATE_POLLING fd 24
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0002de0 fd 25 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0002de0 in state DCB_STATE_POLLING fd 25
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0003040 fd 26 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0003040 in state DCB_STATE_POLLING fd 26
2016-01-18 12:30:07   140573050541824 [gw_MySQLWrite_backend] write to dcb 0x7fd9a00032a0 fd 27 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a00032a0 in state DCB_STATE_POLLING fd 27
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9a0002b80 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [gw_write_backend_event] wrote to dcb 0x7fd9a0002b80 fd 24, return 1
2016-01-18 12:30:07   140573042149120 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9a0002b80 fd 24
2016-01-18 12:30:07   140573050541824 [gw_read_backend_event] Read dcb 0x7fd9a0002b80 fd 24 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 11 bytes from dcb 0x7fd9a0002b80 in state DCB_STATE_POLLING fd 24.
2016-01-18 12:30:07   140573632628608 [poll_waitevents] epoll_wait found 2 fds
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 24.
2016-01-18 12:30:07   140573042149120 [poll_waitevents] event 5 dcb 0x7fd9a0005400 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573632628608 [poll_waitevents] event 5 dcb 0x7fd9a00032a0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 24.
2016-01-18 12:30:07   140573042149120 [gw_write_backend_event] wrote to dcb 0x7fd9a0005400 fd 23, return 1
2016-01-18 12:30:07   140573632628608 [gw_write_backend_event] wrote to dcb 0x7fd9a00032a0 fd 27, return 1
2016-01-18 12:30:07   140573042149120 [poll_waitevents] Read in dcb 0x7fd9a0005400 fd 23
2016-01-18 12:30:07   140573050541824 [process_response_data] Read command COM_PING for DCB 0x7fd9a0002b80 fd 24.
2016-01-18 12:30:07   140573033756416 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573632628608 [poll_waitevents] Read in dcb 0x7fd9a00032a0 fd 27
2016-01-18 12:30:07   140573033756416 [poll_waitevents] event 5 dcb 0x7fd9a0002de0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573632628608 [gw_read_backend_event] Read dcb 0x7fd9a00032a0 fd 27 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9a0003040 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [gw_write_backend_event] wrote to dcb 0x7fd9a0003040 fd 26, return 1
2016-01-18 12:30:07   140573033756416 [gw_write_backend_event] wrote to dcb 0x7fd9a0002de0 fd 25, return 1
2016-01-18 12:30:07   140573632628608 [dcb_read] Read 11 bytes from dcb 0x7fd9a00032a0 in state DCB_STATE_POLLING fd 27.
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9a0003040 fd 26
2016-01-18 12:30:07   140573042149120 [gw_read_backend_event] Read dcb 0x7fd9a0005400 fd 23 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [gw_read_backend_event] Read dcb 0x7fd9a0003040 fd 26 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573632628608 [protocol_get_srv_command] Read command COM_PING for fd 27.
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 11 bytes from dcb 0x7fd9a0003040 in state DCB_STATE_POLLING fd 26.
2016-01-18 12:30:07   140573632628608 [protocol_get_srv_command] Read command COM_PING for fd 27.
2016-01-18 12:30:07   140573042149120 [dcb_read] Read 11 bytes from dcb 0x7fd9a0005400 in state DCB_STATE_POLLING fd 23.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 26.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_PING for fd 26.
2016-01-18 12:30:07   140573632628608 [process_response_data] Read command COM_PING for DCB 0x7fd9a00032a0 fd 27.
2016-01-18 12:30:07   140573050541824 [process_response_data] Read command COM_PING for DCB 0x7fd9a0003040 fd 26.
2016-01-18 12:30:07   140573033756416 [poll_waitevents] Read in dcb 0x7fd9a0002de0 fd 25
2016-01-18 12:30:07   140573042149120 [protocol_get_srv_command] Read command COM_PING for fd 23.
2016-01-18 12:30:07   140573050541824 [gw_read_backend_event] Read dcb 0x7fd9a0002b80 fd 24 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [process_response_data] Read command COM_PING for DCB 0x7fd9a00032a0 fd 27.
2016-01-18 12:30:07   140573042149120 [protocol_get_srv_command] Read command COM_PING for fd 23.
2016-01-18 12:30:07   140573033756416 [gw_read_backend_event] Read dcb 0x7fd9a0002de0 fd 25 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [process_response_data] Read command COM_PING for DCB 0x7fd9a0005400 fd 23.
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 11 Bytes to dcb 0x7fd9ac003260 in state DCB_STATE_POLLING fd 21
2016-01-18 12:30:07   140573033756416 [protocol_get_srv_command] Read command COM_PING for fd 25.
2016-01-18 12:30:07   140573033756416 [protocol_get_srv_command] Read command COM_PING for fd 25.
2016-01-18 12:30:07   140573033756416 [process_response_data] Read command COM_PING for DCB 0x7fd9a0002de0 fd 25.
2016-01-18 12:30:07   140573033756416 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573033756416 [poll_waitevents] event 5 dcb 0x7fd9ac003260 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573033756416 [poll_waitevents] Read in dcb 0x7fd9ac003260 fd 21
2016-01-18 12:30:07   140573033756416 [dcb_read] Read 187 bytes from dcb 0x7fd9ac003260 in state DCB_STATE_POLLING fd 21.
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Item tpl_refid:FIELD_ITEM
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Item (null):COND_ITEM
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Item (null):FUNC_ITEM
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Functype 1.
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Item system_redirect.html:STRING_ITEM
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Item tpl_file:FIELD_ITEM
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Item (null):FUNC_ITEM
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Functype 1.
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Item default:STRING_ITEM
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Item tpl_tplset:FIELD_ITEM
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Item (null):FUNC_ITEM
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Functype 1.
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Item tpl_id:FIELD_ITEM
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Item tpl_id:FIELD_ITEM
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Item tpl_source:FIELD_ITEM
2016-01-18 12:30:07   140573033756416 [resolve_query_type] Item *:FIELD_ITEM
2016-01-18 12:30:07   140573033756416 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0002b80 fd 24 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573033756416 [dcb_write] Wrote 187 Bytes to dcb 0x7fd9a0002b80 in state DCB_STATE_POLLING fd 24
2016-01-18 12:30:07   140573033756416 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573033756416 [poll_waitevents] event 5 dcb 0x7fd9a0002b80 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573033756416 [gw_write_backend_event] wrote to dcb 0x7fd9a0002b80 fd 24, return 1
2016-01-18 12:30:07   140573033756416 [poll_waitevents] Read in dcb 0x7fd9a0002b80 fd 24
2016-01-18 12:30:07   140573033756416 [gw_read_backend_event] Read dcb 0x7fd9a0002b80 fd 24 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573033756416 [dcb_read] Read 1330 bytes from dcb 0x7fd9a0002b80 in state DCB_STATE_POLLING fd 24.
2016-01-18 12:30:07   140573033756416 [protocol_get_srv_command] Read command UNKNOWN MYSQL PACKET TYPE for fd 24.
2016-01-18 12:30:07   140573033756416 [dcb_write] Wrote 1330 Bytes to dcb 0x7fd9ac003260 in state DCB_STATE_POLLING fd 21
2016-01-18 12:30:07   140573042149120 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573042149120 [poll_waitevents] event 8197 dcb 0x7fd9ac003260 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573042149120 [poll_waitevents] Read in dcb 0x7fd9ac003260 fd 21
2016-01-18 12:30:07   140573042149120 [dcb_read] Read 5 bytes from dcb 0x7fd9ac003260 in state DCB_STATE_POLLING fd 21.
2016-01-18 12:30:07   140573042149120 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0005400 fd 23 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0005400 in state DCB_STATE_POLLING fd 23
2016-01-18 12:30:07   140573042149120 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0002b80 fd 24 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0002b80 in state DCB_STATE_POLLING fd 24
2016-01-18 12:30:07   140573042149120 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0002de0 fd 25 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0002de0 in state DCB_STATE_POLLING fd 25
2016-01-18 12:30:07   140573042149120 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0003040 fd 26 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0003040 in state DCB_STATE_POLLING fd 26
2016-01-18 12:30:07   140573042149120 [gw_MySQLWrite_backend] write to dcb 0x7fd9a00032a0 fd 27 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a00032a0 in state DCB_STATE_POLLING fd 27
2016-01-18 12:30:07   140573042149120 [dcb_close]
2016-01-18 12:30:07   140573042149120 [dcb_close] Removed dcb 0x7fd9ac003260 in state DCB_STATE_NOPOLLING from poll set.
2016-01-18 12:30:07   140573042149120 [gw_client_close]
2016-01-18 12:30:07   140573042149120 [RWSplit:closeSession]
2016-01-18 12:30:07   140573042149120 [dcb_close]
2016-01-18 12:30:07   140573042149120 [dcb_close] Removed dcb 0x7fd9a0005400 in state DCB_STATE_NOPOLLING from poll set.
2016-01-18 12:30:07   140573042149120 [gw_backend_close]
2016-01-18 12:30:07   140573042149120 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0005400 fd 23 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0005400 in state DCB_STATE_NOPOLLING fd 23
2016-01-18 12:30:07   140573042149120 [dcb_close]
2016-01-18 12:30:07   140573042149120 [dcb_close] Removed dcb 0x7fd9a0002b80 in state DCB_STATE_NOPOLLING from poll set.
2016-01-18 12:30:07   140573042149120 [gw_backend_close]
2016-01-18 12:30:07   140573042149120 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0002b80 fd 24 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0002b80 in state DCB_STATE_NOPOLLING fd 24
2016-01-18 12:30:07   140573042149120 [dcb_close]
2016-01-18 12:30:07   140573042149120 [dcb_close] Removed dcb 0x7fd9a0002de0 in state DCB_STATE_NOPOLLING from poll set.
2016-01-18 12:30:07   140573042149120 [gw_backend_close]
2016-01-18 12:30:07   140573042149120 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0002de0 fd 25 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0002de0 in state DCB_STATE_NOPOLLING fd 25
2016-01-18 12:30:07   140573042149120 [dcb_close]
2016-01-18 12:30:07   140573042149120 [dcb_close] Removed dcb 0x7fd9a0003040 in state DCB_STATE_NOPOLLING from poll set.
2016-01-18 12:30:07   140573042149120 [gw_backend_close]
2016-01-18 12:30:07   140573042149120 [gw_MySQLWrite_backend] write to dcb 0x7fd9a0003040 fd 26 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a0003040 in state DCB_STATE_NOPOLLING fd 26
2016-01-18 12:30:07   140573042149120 [dcb_close]
2016-01-18 12:30:07   140573042149120 [dcb_close] Removed dcb 0x7fd9a00032a0 in state DCB_STATE_NOPOLLING from poll set.
2016-01-18 12:30:07   140573042149120 [gw_backend_close]
2016-01-18 12:30:07   140573042149120 [gw_MySQLWrite_backend] write to dcb 0x7fd9a00032a0 fd 27 protocol state MYSQL_IDLE.
2016-01-18 12:30:07   140573042149120 [dcb_write] Wrote 5 Bytes to dcb 0x7fd9a00032a0 in state DCB_STATE_NOPOLLING fd 27
2016-01-18 12:30:07   140573042149120 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573042149120 [poll_waitevents] EPOLLRDHUP on dcb 0x7fd9ac003260, fd 21. Errno 0, Success.
2016-01-18 12:30:07   140573042149120 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573042149120 [poll_waitevents] event 1 dcb 0x34797b0 role DCB_ROLE_SERVICE_LISTENER
2016-01-18 12:30:07   140573042149120 [poll_waitevents] Accept in fd 15
2016-01-18 12:30:07   140573042149120 [dcb_write] Wrote 86 Bytes to dcb 0x7fd9ac008980 in state DCB_STATE_ALLOC fd 22
2016-01-18 12:30:07   140573042149120 [poll_add_dcb] Added dcb 0x7fd9ac008980 in state DCB_STATE_POLLING to poll set.
2016-01-18 12:30:07   140573042149120 [gw_MySQLAccept] Added dcb 0x7fd9ac008980 for fd 22 to epoll set.
2016-01-18 12:30:07   140573042149120 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573042149120 [poll_waitevents] event 4 dcb 0x7fd9ac008980 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573042149120 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573042149120 [poll_waitevents] event 5 dcb 0x7fd9ac008980 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573042149120 [poll_waitevents] Read in dcb 0x7fd9ac008980 fd 22
2016-01-18 12:30:07   140573042149120 [dcb_read] Read 85 bytes from dcb 0x7fd9ac008980 in state DCB_STATE_POLLING fd 22.
2016-01-18 12:30:07   Receiving connection from 'admin' to database '(null)'.
2016-01-18 12:30:07   140573042149120 [gw_create_backend_connection] Connection pending to 10.0.249.15:3306, protocol fd 28 client fd 22.
2016-01-18 12:30:07   140573042149120 [poll_add_dcb] Added dcb 0x7fd9ac008f70 in state DCB_STATE_POLLING to poll set.
2016-01-18 12:30:07   140573042149120 [gw_create_backend_connection] Connection pending to 10.0.249.14:3306, protocol fd 29 client fd 22.
2016-01-18 12:30:07   140573042149120 [poll_add_dcb] Added dcb 0x7fd9ac0091f0 in state DCB_STATE_POLLING to poll set.
2016-01-18 12:30:07   140573042149120 [gw_create_backend_connection] Connection pending to 10.0.249.13:3306, protocol fd 30 client fd 22.
2016-01-18 12:30:07   140573042149120 [poll_add_dcb] Added dcb 0x7fd9ac009420 in state DCB_STATE_POLLING to poll set.
2016-01-18 12:30:07   140573042149120 [gw_create_backend_connection] Connection pending to 10.0.249.12:3306, protocol fd 31 client fd 22.
2016-01-18 12:30:07   140573042149120 [poll_add_dcb] Added dcb 0x7fd9ac009650 in state DCB_STATE_POLLING to poll set.
2016-01-18 12:30:07   140573042149120 [gw_create_backend_connection] Connection pending to 10.0.249.11:3306, protocol fd 32 client fd 22.
2016-01-18 12:30:07   140573042149120 [poll_add_dcb] Added dcb 0x7fd9ac009880 in state DCB_STATE_POLLING to poll set.
2016-01-18 12:30:07   140573042149120 [dcb_write] Wrote 11 Bytes to dcb 0x7fd9ac008980 in state DCB_STATE_POLLING fd 22
2016-01-18 12:30:07   140573042149120 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573042149120 [poll_waitevents] event 4 dcb 0x7fd9ac009420 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573042149120 [gw_write_backend_event] wrote to dcb 0x7fd9ac009420 fd 30, return 1
2016-01-18 12:30:07   140573033756416 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573033756416 [poll_waitevents] event 4 dcb 0x7fd9ac008f70 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573033756416 [gw_write_backend_event] wrote to dcb 0x7fd9ac008f70 fd 28, return 1
2016-01-18 12:30:07   140573033756416 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573033756416 [poll_waitevents] event 4 dcb 0x7fd9ac0091f0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573033756416 [gw_write_backend_event] wrote to dcb 0x7fd9ac0091f0 fd 29, return 1
2016-01-18 12:30:07   140573033756416 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573033756416 [poll_waitevents] event 4 dcb 0x7fd9ac009880 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573033756416 [gw_write_backend_event] wrote to dcb 0x7fd9ac009880 fd 32, return 1
2016-01-18 12:30:07   140573033756416 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573033756416 [poll_waitevents] event 4 dcb 0x7fd9ac009650 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573033756416 [gw_write_backend_event] wrote to dcb 0x7fd9ac009650 fd 31, return 1
2016-01-18 12:30:07   140573033756416 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573033756416 [poll_waitevents] event 5 dcb 0x7fd9ac009420 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573033756416 [gw_write_backend_event] wrote to dcb 0x7fd9ac009420 fd 30, return 1
2016-01-18 12:30:07   140573033756416 [poll_waitevents] Read in dcb 0x7fd9ac009420 fd 30
2016-01-18 12:30:07   140573033756416 [gw_read_backend_event] Read dcb 0x7fd9ac009420 fd 30 protocol state 2, MYSQL_CONNECTED.
2016-01-18 12:30:07   140573042149120 [poll_waitevents] epoll_wait found 2 fds
2016-01-18 12:30:07   140573042149120 [poll_waitevents] event 5 dcb 0x7fd9ac008980 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573033756416 [dcb_read] Read 105 bytes from dcb 0x7fd9ac009420 in state DCB_STATE_POLLING fd 30.
2016-01-18 12:30:07   140573042149120 [poll_waitevents] Read in dcb 0x7fd9ac008980 fd 22
2016-01-18 12:30:07   140573042149120 [dcb_read] Read 27 bytes from dcb 0x7fd9ac008980 in state DCB_STATE_POLLING fd 22.
2016-01-18 12:30:07   140573033756416 [dcb_write] Wrote 85 Bytes to dcb 0x7fd9ac009420 in state DCB_STATE_POLLING fd 30
2016-01-18 12:30:07   140573033756416 [gw_receive_backend_auth] Read zero bytes from backend dcb 0x7fd9ac009420 fd 30 in state DCB_STATE_POLLING. n 0, head (nil), len 0
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573042149120 [gw_MySQLWrite_backend] delayed write to dcb 0x7fd9ac008f70 fd 28 protocol state MYSQL_CONNECTED.
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9ac008f70 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573033756416 [poll_waitevents] event 5 dcb 0x7fd9ac0091f0 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [gw_write_backend_event] wrote to dcb 0x7fd9ac008f70 fd 28, return 1
2016-01-18 12:30:07   140573033756416 [gw_write_backend_event] wrote to dcb 0x7fd9ac0091f0 fd 29, return 1
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9ac008f70 fd 28
2016-01-18 12:30:07   140573033756416 [poll_waitevents] Read in dcb 0x7fd9ac0091f0 fd 29
2016-01-18 12:30:07   140573050541824 [gw_read_backend_event] Read dcb 0x7fd9ac008f70 fd 28 protocol state 2, MYSQL_CONNECTED.
2016-01-18 12:30:07   140573033756416 [gw_read_backend_event] Read dcb 0x7fd9ac0091f0 fd 29 protocol state 2, MYSQL_CONNECTED.
2016-01-18 12:30:07   140573033756416 [dcb_read] Read 105 bytes from dcb 0x7fd9ac0091f0 in state DCB_STATE_POLLING fd 29.
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 105 bytes from dcb 0x7fd9ac008f70 in state DCB_STATE_POLLING fd 28.
2016-01-18 12:30:07   140573632628608 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 108 Bytes to dcb 0x7fd9ac008f70 in state DCB_STATE_POLLING fd 28
2016-01-18 12:30:07   140573632628608 [poll_waitevents] event 5 dcb 0x7fd9ac009880 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [gw_receive_backend_auth] Read zero bytes from backend dcb 0x7fd9ac008f70 fd 28 in state DCB_STATE_POLLING. n 0, head (nil), len 0
2016-01-18 12:30:07   140573632628608 [gw_write_backend_event] wrote to dcb 0x7fd9ac009880 fd 32, return 1
2016-01-18 12:30:07   140573632628608 [poll_waitevents] Read in dcb 0x7fd9ac009880 fd 32
2016-01-18 12:30:07   140573632628608 [gw_read_backend_event] Read dcb 0x7fd9ac009880 fd 32 protocol state 2, MYSQL_CONNECTED.
2016-01-18 12:30:07   140573632628608 [dcb_read] Read 105 bytes from dcb 0x7fd9ac009880 in state DCB_STATE_POLLING fd 32.
2016-01-18 12:30:07   140573632628608 [dcb_write] Wrote 108 Bytes to dcb 0x7fd9ac009880 in state DCB_STATE_POLLING fd 32
2016-01-18 12:30:07   140573033756416 [dcb_read] Read 11 bytes from dcb 0x7fd9a0002de0 in state DCB_STATE_POLLING fd 25.
2016-01-18 12:30:07   140573632628608 [gw_receive_backend_auth] Read zero bytes from backend dcb 0x7fd9ac009880 fd 32 in state DCB_STATE_POLLING. n 0, head (nil), len 0
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9ac009650 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [gw_write_backend_event] wrote to dcb 0x7fd9ac009650 fd 31, return 1
2016-01-18 12:30:07   140573632628608 [poll_waitevents] epoll_wait found 2 fds
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9ac009650 fd 31
2016-01-18 12:30:07   140573632628608 [poll_waitevents] event 5 dcb 0x7fd9ac009420 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [gw_read_backend_event] Read dcb 0x7fd9ac009650 fd 31 protocol state 2, MYSQL_CONNECTED.
2016-01-18 12:30:07   140573632628608 [gw_write_backend_event] wrote to dcb 0x7fd9ac009420 fd 30, return 1
2016-01-18 12:30:07   140573632628608 [poll_waitevents] Read in dcb 0x7fd9ac009420 fd 30
2016-01-18 12:30:07   140573632628608 [gw_read_backend_event] Read dcb 0x7fd9ac009420 fd 30 protocol state 4, MYSQL_AUTH_RECV.
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 105 bytes from dcb 0x7fd9ac009650 in state DCB_STATE_POLLING fd 31.
2016-01-18 12:30:07   140573632628608 [dcb_read] Read 11 bytes from dcb 0x7fd9ac009420 in state DCB_STATE_POLLING fd 30.
2016-01-18 12:30:07   140573632628608 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573632628608 [poll_waitevents] event 5 dcb 0x7fd9ac008f70 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [dcb_write] Wrote 108 Bytes to dcb 0x7fd9ac009650 in state DCB_STATE_POLLING fd 31
2016-01-18 12:30:07   140573632628608 [gw_write_backend_event] wrote to dcb 0x7fd9ac008f70 fd 28, return 1
2016-01-18 12:30:07   140573050541824 [gw_receive_backend_auth] Read zero bytes from backend dcb 0x7fd9ac009650 fd 31 in state DCB_STATE_POLLING. n 0, head (nil), len 0
2016-01-18 12:30:07   140573632628608 [poll_waitevents] Read in dcb 0x7fd9ac008f70 fd 28
2016-01-18 12:30:07   140573632628608 [gw_read_backend_event] Read dcb 0x7fd9ac008f70 fd 28 protocol state 4, MYSQL_AUTH_RECV.
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9ac009880 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573632628608 [dcb_read] Read 11 bytes from dcb 0x7fd9ac008f70 in state DCB_STATE_POLLING fd 28.
2016-01-18 12:30:07   140573050541824 [gw_write_backend_event] wrote to dcb 0x7fd9ac009880 fd 32, return 1
2016-01-18 12:30:07   140573632628608 [dcb_write] Wrote 27 Bytes to dcb 0x7fd9ac008f70 in state DCB_STATE_POLLING fd 28
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9ac009880 fd 32
2016-01-18 12:30:07   140573050541824 [gw_read_backend_event] Read dcb 0x7fd9ac009880 fd 32 protocol state 4, MYSQL_AUTH_RECV.
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 11 bytes from dcb 0x7fd9ac009880 in state DCB_STATE_POLLING fd 32.
2016-01-18 12:30:07   140573632628608 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573632628608 [poll_waitevents] event 5 dcb 0x7fd9ac009650 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573632628608 [gw_write_backend_event] wrote to dcb 0x7fd9ac009650 fd 31, return 1
2016-01-18 12:30:07   140573632628608 [poll_waitevents] Read in dcb 0x7fd9ac009650 fd 31
2016-01-18 12:30:07   140573632628608 [gw_read_backend_event] Read dcb 0x7fd9ac009650 fd 31 protocol state 4, MYSQL_AUTH_RECV.
2016-01-18 12:30:07   140573632628608 [dcb_read] Read 11 bytes from dcb 0x7fd9ac009650 in state DCB_STATE_POLLING fd 31.
2016-01-18 12:30:07   140573050541824 [poll_waitevents] epoll_wait found 1 fds
2016-01-18 12:30:07   140573050541824 [poll_waitevents] event 5 dcb 0x7fd9ac008f70 role DCB_ROLE_REQUEST_HANDLER
2016-01-18 12:30:07   140573050541824 [gw_write_backend_event] wrote to dcb 0x7fd9ac008f70 fd 28, return 1
2016-01-18 12:30:07   140573050541824 [poll_waitevents] Read in dcb 0x7fd9ac008f70 fd 28
2016-01-18 12:30:07   140573050541824 [gw_read_backend_event] Read dcb 0x7fd9ac008f70 fd 28 protocol state 11, MYSQL_IDLE.
2016-01-18 12:30:07   140573050541824 [dcb_read] Read 11 bytes from dcb 0x7fd9ac008f70 in state DCB_STATE_POLLING fd 28.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_INIT_DB for fd 28.
2016-01-18 12:30:07   140573050541824 [protocol_get_srv_command] Read command COM_INIT_DB for fd 28.
2016-01-18 12:30:07   140573050541824 [process_response_data] Read command COM_INIT_DB for DCB 0x7fd9ac008f70 fd 28.

[...]
2016-01-18 12:30:07   [1101]  Session write, routing to all servers.
2016-01-18 12:30:07   [1101]  Route query to slave 	10.0.249.15:3306 
2016-01-18 12:30:07   [1101]  Route query to slave 	10.0.249.14:3306 
2016-01-18 12:30:07   [1101]  Route query to slave 	10.0.249.13:3306 
2016-01-18 12:30:07   [1101]  Route query to master 	10.0.249.12:3306 
2016-01-18 12:30:07   [1101]  Route query to slave 	10.0.249.11:3306 <
2016-01-18 12:30:07   Servers and router connection counts:
2016-01-18 12:30:07   current operations : 0 in 	10.0.249.15:3306 RUNNING SLAVE
2016-01-18 12:30:07   current operations : 0 in 	10.0.249.14:3306 RUNNING SLAVE
2016-01-18 12:30:07   current operations : 0 in 	10.0.249.13:3306 RUNNING SLAVE
2016-01-18 12:30:07   current operations : 0 in 	10.0.249.12:3306 RUNNING MASTER
2016-01-18 12:30:07   current operations : 0 in 	10.0.249.11:3306 RUNNING SLAVE
2016-01-18 12:30:07   Selected RUNNING SLAVE in 	10.0.249.15:3306
2016-01-18 12:30:07   Selected RUNNING SLAVE in 	10.0.249.14:3306
2016-01-18 12:30:07   Selected RUNNING SLAVE in 	10.0.249.13:3306
2016-01-18 12:30:07   Selected RUNNING MASTER in 	10.0.249.12:3306
2016-01-18 12:30:07   Selected RUNNING SLAVE in 	10.0.249.11:3306
2016-01-18 12:30:07   Started galera_rw_service client session [1102] for 'admin' from 10.0.248.90
2016-01-18 12:30:07   [1102]  > Autocommit: [enabled], trx is [not open], cmd: COM_INIT_DB, type: QUERY_TYPE_SESSION_WRITE, stmt: xxxxxxxxx_com 
2016-01-18 12:30:07   [1102]  Session write, routing to all servers.
2016-01-18 12:30:07   [1102]  Route query to slave 	10.0.249.15:3306 
2016-01-18 12:30:07   [1102]  Route query to slave 	10.0.249.14:3306 
2016-01-18 12:30:07   [1101]  Stopped galera_rw_service client session [1101]
2016-01-18 12:30:07   [1102]  Starting log flushing to disk.
 

Comment by Florian Engelmann [ 2016-01-18 ]

on those DB nodes I found:

Jan 18 10:00:45 wsccms-db01f-prod mysqld: 160118 10:00:45 [Warning] Aborted connection 4022 to db: 'atiftest_eu' user: 'admin' host: '10.0.249.211' (Unknown error)
Jan 18 10:00:45 wsccms-db01f-prod mysqld: 160118 10:00:45 [Warning] Aborted connection 4023 to db: 'atiftest_eu' user: 'admin' host: '10.0.249.211' (Unknown error)
Jan 18 10:00:45 wsccms-db01f-prod mysqld: 160118 10:00:45 [Warning] Aborted connection 3138 to db: 'unconnected' user: 'maxscalemon' host: '10.0.249.211' (Unknown error)
[...]
Jan 18 12:30:07 wsccms-db01f-prod mysqld: 160118 12:30:07 [Warning] Aborted connection 11528 to db: 'xxxxxxxxxxxxxm' user: 'admin' host: '10.0.249.211' (Unknown error)
Jan 18 12:30:07 wsccms-db01f-prod mysqld: 160118 12:30:07 [Warning] Aborted connection 10419 to db: 'unconnected' user: 'maxscalemon' host: '10.0.249.211' (Unknown error)
[...]

[...]
Jan 18 10:00:45 wsccms-db05f-prod mysqld: 160118 10:00:45 [Warning] Aborted connection 3853 to db: 'xxxxxxxxxxeu' user: 'admin' host: '10.0.249.211' (Unknown error)
Jan 18 10:00:45 wsccms-db05f-prod mysqld: 160118 10:00:45 [Warning] Aborted connection 2968 to db: 'unconnected' user: 'maxscalemon' host: '10.0.249.211' (Unknown error)
[...]
Jan 18 12:30:07 wsccms-db05f-prod mysqld: 160118 12:30:07 [Warning] Aborted connection 10261 to db: 'unconnected' user: 'maxscalemon' host: '10.0.249.211' (Unknown error)
Jan 18 12:30:07 wsccms-db05f-prod mysqld: 160118 12:30:07 [Warning] Aborted connection 11372 to db: 'xxxxxxxxxxxxxxxcom' user: 'admin' host: '10.0.249.211' (Unknown error)
[...]

but those where caused by the maxscale crashes...

Comment by Florian Engelmann [ 2016-01-18 ]

It looks like disabling log_trace and log_debug solved the problem. There was no warning about running out of /dev/shm space. I will test some more and update the report tomorrow.

Comment by Johan Wikman [ 2016-01-18 ]

Do you mean that the initial crash you experienced was caused by running out of /dev/shm space?

Could you consider given 1.3.0-beta a try? A fair amount of memory related issues has been fixed in that one.
It's available here: http://maxscale-jenkins.mariadb.com/ci-repository/1.3.0-beta-release/

Comment by Timofey Turenko [ 2016-01-18 ]

does not seem to be logging problem.

markus makela could you have a look at the logs?

engel75 how can I try to reproduce it? What was client doing before the crash? what kind of load was applied to Maxscale?

Comment by markus makela [ 2016-01-19 ]

Looks like an abort caused by malloc when it detects memory corruption or double freeing of memory.

Comment by Florian Engelmann [ 2016-01-19 ]

After disabling log_debug and log_trace Maxscale did NOT crash anymore!

johan.wikman

Do you mean that the initial crash you experienced was caused by running out of /dev/shm space?

As we do use LXC I am not sure if we were running out of /dev/shm (/run/shm). It is quite big:

none                        126G     0  126G   0% /run/shm

and definitly was not filled:

root@xxxxxxxx:~# du -sm  /run/shm/*
2	/run/shm/maxscale.12594
104	/run/shm/maxscale.12799
71	/run/shm/maxscale.12947
39	/run/shm/maxscale.13255
18	/run/shm/maxscale.13385
1	/run/shm/maxscale.13478
58	/run/shm/maxscale.13629
97	/run/shm/maxscale.13741
326	/run/shm/maxscale.13860
215	/run/shm/maxscale.14040
3	/run/shm/maxscale.16067
1	/run/shm/maxscale.1633
1047	/run/shm/maxscale.16460
72	/run/shm/maxscale.17144
0	/run/shm/maxscale.17250
1	/run/shm/maxscale.1932
1	/run/shm/maxscale.1977
1	/run/shm/maxscale.2020
1	/run/shm/maxscale.2211
1	/run/shm/maxscale.2256
1	/run/shm/maxscale.3758
1	/run/shm/maxscale.3814
0	/run/shm/maxscale.3853
1	/run/shm/maxscale.3973
1065	/run/shm/maxscale.4006
1132	/run/shm/maxscale.6060
116	/run/shm/maxscale.7566

But I wasn't able to find any information about how /dev/shm is handled inside of a LXC.

tturenko

how can I try to reproduce it? What was client doing before the crash? what kind of load was applied to Maxscale?

The Hosts are running Ubuntu 14.04.3. Maxscale and MariaDB Galera Cluster 5.5 are each running in its own LXC. The Maxscale LXC got:

lxc.cgroup.memory.limit_in_bytes = 4G
lxc.cgroup.memory.memsw.limit_in_bytes = 6G

The five MariaDB LXCs got:

lxc.cgroup.memory.limit_in_bytes = 16G
lxc.cgroup.memory.memsw.limit_in_bytes = 24G

We installed a customerPHP webpage and spidered it to produce load. It crashed quite random but it looked like it crashed more easy using the RW split router.

lxc-info -n <LXC name>

did show the memory was growing constant which indicated /dev/shm is taken into account. So my guess was maxscale will be killed by oom killer @4GB but there are no oom killer logentries on the host system.

Comment by Florian Engelmann [ 2016-01-19 ]

johan.wikman

After installing 1.3.0 beta there are no more logfiles stored at /dev/shm. It looks like everything is logging to

/var/log/maxscale/maxscale1.log

And logging is done without sync to save I/O?

1.3.0 beta did not crash at my 1st tests... but I am still testing.

Do you know about any release date of 1.3.0?

Comment by Florian Engelmann [ 2016-01-19 ]

2016-01-19 10:54:30   warning: In the configuration file the use of 'log_messages' is deprecated, use 'log_notice' instead.
[...]
2016-01-19 10:54:30   warning: In the configuration file the use of 'log_trace' is deprecated, use 'log_info' instead.

Is the documentation about 1.3.0 up2date?

https://github.com/mariadb-corporation/MaxScale/blob/release-1.3.0/Documentation/Getting-Started/Configuration-Guide.md

Comment by markus makela [ 2016-01-19 ]

The documentation is here: https://github.com/mariadb-corporation/MaxScale/blob/release-1.3.0/Documentation/Documentation-Contents.md

Comment by Florian Engelmann [ 2016-01-19 ]

markus makela

just found it - thank you!

Comment by Johan Wikman [ 2016-01-19 ]

engel75, 1.3.0 will be released in the end of January.

As for the logging, please check Logging Changes in the release notes: https://github.com/mariadb-corporation/MaxScale/blob/1.3.0-beta/Documentation/Release-Notes/MaxScale-1.3.0-Release-Notes.md

Comment by Florian Engelmann [ 2016-01-19 ]

johan.wikman

Great news! So we will stick with 1.3.0.

I changed the logging settings like this:

[MaxScale]
threads=4
syslog=1
maxlog=0
ms_timestamp=1
log_to_shm=0
log_warning=1
log_notice=1
log_info=0
log_debug=0

As Ubuntu Trusty does not use systemd it would be nice to get a Upstart init file. The Sysvinit file of 1.3.0 seems to start maxscale with user root:

root     27775     1  0 11:54 ?        00:00:10 /usr/bin/maxscale "--user=maxscale" "$MAXSCALE_OPTIONS"

Comment by Florian Engelmann [ 2016-01-19 ]

dependencies are broken. missing libs:

libaio1
libcurl3

/usr/bin/maxscale: error while loading shared libraries: libcurl.so.4: cannot open shared object file: No such file or directory
/usr/bin/maxscale: error while loading shared libraries: libaio.so.1: cannot open shared object file: No such file or directory

Comment by Johan Wikman [ 2016-01-19 ]

engel75 If 1.3 solved your crash, could you please close this bug-report and create a new separate bug-report regarding running maxscale as root?

Comment by Florian Engelmann [ 2016-01-19 ]

johan.wikman sorry this is the first time using Jira. I got no clue how to close this report. But I will open two sepereted new one about the process running as root and those missing dependencies.

Comment by Johan Wikman [ 2016-01-19 ]

No problem, I'll close this one. Thanks for helping out.

Comment by Johan Wikman [ 2016-01-19 ]

As the problem does not appear with 1.3 beta, this is most likely a duplicate of one of the similar ones that earlier has been reported for 1.2.[0|1] and that were fixed in 1.3.

Comment by Florian Engelmann [ 2016-01-20 ]

looks like 1.3.0 crashes the same way logging to /dev/shm/ inside of an LXC:

[MaxScale]
threads=4
syslog=1
maxlog=1
ms_timestamp=1
log_to_shm=1
log_warning=1
log_notice=1
log_info=1
log_debug=1

2016-01-19 20:08:12.413   debug  : 140021151856512 [dcb_read] Read 11 bytes from dcb 0x7f5904024150 in state DCB_STATE_POLLING fd 27.
2016-01-19 20:08:12.413   debug  : 140021151856512 [protocol_get_srv_command] Read command COM_INIT_DB for fd 27.
2016-01-19 20:08:12.413   debug  : 140021151856512 [protocol_get_srv_command] Read command COM_INIT_DB for fd 27.
2016-01-19 20:08:12.413   debug  : 140021151856512 [process_response_data] Read command COM_INIT_DB for DCB 0x7f5904024150 fd 27.
2016-01-19 20:08:12.414   error  :   /usr/bin/maxscale() [0x54ac4b] 
2016-01-19 20:08:12.413   debug  : 140021151856512 [gw_write_backend_event] wrote to dcb 0x7f5904024150 fd 27, return 1
2016-01-19 20:08:12.414   error  :   /lib/x86_64-linux-gnu/libpthread.so.0(+0x10340) [0x7f5936363340] 
2016-01-19 20:08:12.414   error  :   /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39) [0x7f5934d40cc9] 
2016-01-19 20:08:12.415   error  :   /lib/x86_64-linux-gnu/libc.so.6(abort+0x148) [0x7f5934d440d8] 
2016-01-19 20:08:12.415   error  :   /lib/x86_64-linux-gnu/libc.so.6(+0x73394) [0x7f5934d7d394] 
2016-01-19 20:08:12.415   error  :   /lib/x86_64-linux-gnu/libc.so.6(+0x7f66e) [0x7f5934d8966e] 
2016-01-19 20:08:12.415   error  :   /usr/bin/maxscale(gwbuf_free+0x3d) [0x5498dc] 
2016-01-19 20:08:12.415   error  :   /usr/bin/maxscale(gwbuf_consume+0xa6) [0x549f0a] 
2016-01-19 20:08:12.415   error  :   /usr/bin/maxscale(dcb_write+0x1c8) [0x552085] 
2016-01-19 20:08:12.415   error  :   /usr/lib/x86_64-linux-gnu/maxscale/libMySQLBackend.so(gw_send_authentication_to_backend+0x665) [0x7f591804c6db] 
2016-01-19 20:08:12.415   error  :   /usr/lib/x86_64-linux-gnu/maxscale/libMySQLBackend.so(+0x27db) [0x7f59180487db] 
2016-01-19 20:08:12.415   error  :   /usr/bin/maxscale() [0x56230c] 
2016-01-19 20:08:12.415   error  :   /usr/bin/maxscale(poll_waitevents+0x67e) [0x561b62] 
2016-01-19 20:08:12.415   error  :   /lib/x86_64-linux-gnu/libpthread.so.0(+0x8182) [0x7f593635b182] 
2016-01-19 20:08:12.415   error  :   /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7f5934e0447d] 
2016-01-19 20:08:12.415   [205]  info   : Starting log flushing to disk.

Comment by markus makela [ 2016-01-20 ]

Are you starting MaxScale directly as a process inside the LXC? If so, can you give the command you use to start it up?

Comment by Florian Engelmann [ 2016-01-20 ]

The LXC is created like:

lxc-create -n wsccms-max01-prod -B lvm --vgname=lxc --fssize=10G -t /xxxx/xxxxx

We do use custom templates to create our LXCs but those are forks of the original /usr/share/lxc/templates/lxc-ubuntu template.

You could create the LXC with:

lxc-create -n max01 -B lvm --vgname=lxc --fssize=10G -t ubuntu -- -d -r trusty 

Inside the LXC (lxc-start -d -n max01 && lxc-console -n max01) maxsacle is isntalled and started as on any other Ubuntu Trusty:

wget -O - https://code.mariadb.com/mariadb-maxscale/MariaDB-MaxScale-GPG-KEY | apt-key add -
echo "deb http://code.mariadb.com/mariadb-maxscale/1.3.0-beta/ubuntu trusty main" > /etc/apt/sources.list.d/maxscale.list
apt-get update
apt-get install libaio1 libcurl3 maxscale
vi /etc/maxscale.cnf
service maxscale start

Comment by markus makela [ 2016-01-20 ]

It crashes on line 1159 in dcb.c when the buffer is being freed. Thee call to free on line 249 in buffer.c is the one that crashes:

gwbuf_free+0x3d: server/core/buffer.c:249
gwbuf_consume+0xa6: server/core/buffer.c:500
dcb_write+0x1c8: server/core/dcb.c:1159
gw_send_authentication_to_backend+0x665: server/modules/protocol/mysql_common.c:704

Comment by markus makela [ 2016-01-20 ]

I've failed to reproduce the crash on LXC when the shared memory is used. I ran MaxScale inside an Ubuntu Trusty LXC on Ubuntu Trusty and filled the shared memory while running sysbench, no crash. The logs are disabled when the memory fills up but MaxScale still functions normally.

Comment by markus makela [ 2016-01-20 ]

If it is possible for you to create a core dump from MaxScale or run it inside GDB, that would help solve the issue more quickly. Also, can you confirm that MaxScale works if you disable the logging to shm?

Comment by Florian Engelmann [ 2016-01-20 ]

I'll try to get a core dump. Maxscale is crashing wether logging to shm is enabled or logging is disabled at all.

Comment by Florian Engelmann [ 2016-01-20 ]

root@xxxxxxxxx:~# maxscale -d 
Info : MaxScale will be run in the terminal process.
MaxScale logging is disabled.
Configuration file : /etc/maxscale.cnf
Log directory      : /var/log/maxscale
Data directory     : /var/lib/maxscale/data
Module directory   : /usr/lib/x86_64-linux-gnu/maxscale
Service cache      : /var/cache/maxscale
 
*** Error in `maxscale': free(): invalid next size (fast): 0x0000000003dd7c50 ***
 
 
MaxScale beta-1.3.0 received fatal signal 6
 
 
Writing core dump
Aborted

no core dump was written...?

root@xxxxxxxxxx:~# ulimit -a
core file size          (blocks, -c) unlimited
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 2061277
max locked memory       (kbytes, -l) 64
max memory size         (kbytes, -m) unlimited
open files                      (-n) 1024
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 2061277
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited

root@xxxxxxxx:~# cat /proc/sys/kernel/core_pattern
/tmp/cores/core.%e.%p.%t

Any suggestions about getting the core dump?

Comment by Florian Engelmann [ 2016-01-20 ]

got I dump now.. had io change:

echo '/tmp/core.%e.%p.%t' > /proc/sys/kernel/core_pattern

The xz compressed core dump is still 14MB but I am not allowed to upload files greater 10MB. So I uploaded it here:

http://filebin.ca/2U7YySSelmne/core.maxscale.3875.1453302466.xz

Comment by markus makela [ 2016-01-20 ]

Thank you, we'll let you know once we have more information.

Comment by markus makela [ 2016-01-20 ]

The error about invalid next size suggest that memory is somehow handled in a way that is not safe. Can you describe what you were doing when that happened?

Comment by Florian Engelmann [ 2016-01-20 ]

I did start an stress test with "ab" against the PHP webpage which got it's data in the Galera Cluster

~# parallel 'ab -n 200 -c 20 ....'

Comment by markus makela [ 2016-01-21 ]

We've identified one problem with PHP, pooled connections and the COM_CHANGE_USER packets it sends when the pooled connection needs to change users. An updated version of the 1.3.0-beta can be found here: http://max-tst-01.mariadb.com/ci-repository/release-1.3.0-jan21/mariadb-maxscale/ubuntu/dists/trusty/main/binary-amd64/

If the crash does not appear with this package, we can close this bug.

Comment by Florian Engelmann [ 2016-01-21 ]

Dear markus makela we are currently testing the older 1.3.0 beta package against MariaDB 10.1. We have not been able to cause a crash till now. Tests are still ongoing. We are testing the readconn router right now and will test the rw split router this afternoon. I will post a test matrix after we are finished.

I will test the updated package tomorrow or this afternoon with the same test matrix.

Comment by Florian Engelmann [ 2016-01-21 ]

Good news markus makela, we have not been able to crash the 1.3.0-jan21 version! The test matrix looks like:

loadbalancer used ab settings runtime maxscale version maxscale router maxscale log settings mariadb version result
preprod parallel 'ab -n 200 -c 2 {}' 34m53.568s 1.3.0 beta rr ms disabled, only syslog 10.1 no crash, ~15%cpu
preprod parallel 'ab -n 200 -c 2 {}' 34m57.343s 1.3.0 beta rr ms disabled, info log, to disk and syslog 10.1 no crash, ~15%cpu
preprod parallel 'ab -n 200 -c 2 {}' 32m59.518s 1.3.0 beta rr ms disabled, info + debug log, to shm 10.1 oom killer, 7,9GB log @ /dev/shm, ~17%cpu
preprod parallel 'ab -n 200 -c 2 {}' 34m55.903s 1.3.0 beta rr ms enabled, info log, to shm 10.1 no crash, ~630MB log @ /dev/shm, ~17%cpu
preprod parallel 'ab -n 200 -c 2 {}' 35m4.022s 1.3.0 beta rr ms enabled, info log, to shm 5.5 no crash, ~630MB log @ /dev/shm, ~17%cpu
preprod parallel 'ab -n 50 -c 2 {}' 3m30.188s 1.3.0 beta rw ms enabled, info log, to shm 5.5 *crash*, ~190MB log @ /dev/shm, ~40% cpu
preprod parallel 'ab -n 50 -c 2 {}' 2m13.140s 1.3.0 beta rw ms enabled, info log, to shm 10.1 *crash*, ~40MB @ /dev/shm, ??% cpu
preprod parallel 'ab -n 50 -c 2 {}' 5m9.027s 1.3.0 jan21 rw ms enabled, info log, to shm 10.1 no crash, ~434MB @ /dev/shm, ~37% cpu
prod parallel 'ab -n 50 -c 10 {}' 4m17.329s 1.3.0 jan21 rw ms enabled, info log, to shm 10.1 no crash, ~980MB @ /dev/shm, ~300% cpu
prod parallel 'ab -n 50 -c 6 {}' 3m54.632s 1.3.0 jan21 rw ms enabled, info log, to shm 10.1 no crash, ~1022MB @ /dev/shm, ~300% cpu
prod parallel 'ab -n 100 -c 8 {}' 4m39.146s 1.3.0 jan21 rw ms enabled, only warning and notice log, to disk and syslog 10.1 no crash, ~5.7KB @ disk, ~180% cpu
prod parallel 'ab -n 100 -c 8 {}' 4m37.915s 1.3.0 jan21 rw ms enabled, info log, to shm 10.1 no crash, ~2.3GB @ /dev/shm, ~300% cpu
prod parallel 'ab -n 100 -c 8 {}' 4m38.613s 1.3.0 jan21 rw ms enabled, info log, to shm 5.5 no crash, ~2.3GB @ /dev/shm, ~300% cpu
prod parallel 'ab -n 100 -c 8 {}' 4m33.888s 1.3.0 jan21 rw ms enabled, only warning and notice log, to disk and syslog 5.5 no crash, ~5.7KB @ disk, ~180% cpu

The readconn router did not crash at all (we did not test it via the produktion environment which is much more powerful) but the rw split router was easy to crash with version 1.3.0-beta. We did not test 1.2.1 because we are running out of time. 1.3.0-jan21 was running without any crashes. Thumbs up!

Hope we could help to finally solve that issue. Thank you for your great work and awsome support!

Comment by markus makela [ 2016-01-21 ]

This is very good news, I'll close the issue.

The problem with the OOM killer is most likely related to PHP and connection pooling. MaxScale stores executed commands that modify the session state in order to be able to replace failed slaves in the middle of a session but this isn't quite optimal when pooled connections are used. For more details about this feature and how to disable it, please read the readwritesplit docuemntation: https://github.com/mariadb-corporation/MaxScale/blob/release-1.3.0/Documentation/Routers/ReadWriteSplit.md#disable_sescmd_history

Comment by Florian Engelmann [ 2016-01-21 ]

I don't think OOM Killer was triggered because of any PHP issue. The LXC was limited to 8GB RAM - so this was the cause and OOM Killer did what it had to do.

As /dev/shm is using RAM it is added to the RAM the LXC uses. Easy to proof via:

lxc-info -n <containername>

Comment by markus makela [ 2016-01-21 ]

The shared authentication data each session has was modified when a COM_CHANGE_USER query was executed. This could lead to problems when string lengths were being calculated and copied and eventually led to memory corruption when more data was copied to a buffer than it could hold.

Comment by Florian Engelmann [ 2016-01-21 ]

OK that makes sense - glad to know where the issue came from.

Comment by markus makela [ 2016-01-21 ]

You are right, PHP was not at fault. This is a feature of the readwritesplit router but it is not intended for use with pooled connections and it is recommended to disable the session command history.

https://github.com/mariadb-corporation/MaxScale/blob/release-1.3.0/Documentation/Routers/ReadWriteSplit.md#disable_sescmd_history

Comment by Florian Engelmann [ 2016-01-21 ]

So my RW split router should look like:

[galera_rw_service]
type=service
router=readwritesplit
#connection_timeout=300
router_options=slave_selection_criteria=LEAST_CURRENT_OPERATIONS,disable_sescmd_history=true
max_slave_connections=100%
servers=dbf1,dbf2,dbf3,dbf4,dbf5
user=maxscaleroute
passwd=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
enable_root_user=0
version_string=5.5.47-MariaDB-RWsplit
optimize_wildcard=true
log_auth_warnings=true

Any negative impact with* disable_sescmd_history=true* ?

Comment by markus makela [ 2016-01-21 ]

Only for extremely long sessions where it is possible that multiple slaves go down over the lifetime of the session. If this were to happen and the master would still be alive, all the queries
would be routed to the master server until the session is closed and a new connection is made. This could be a minor problem with pooled connections that are not configured with a maximum duration but as disconnections aren't that rare, it usually doesn't become a problem.

Comment by Florian Engelmann [ 2016-01-21 ]

OK thank your for your detailed answer. I'll stick with those settings and do some more application tests.

Comment by markus makela [ 2016-01-21 ]

I'd also suggest removing the optimize_wildcard option, it doesn't really improve the matching of wildcard grants and could even cause a decrease in performance if large amounts of databases and wildcard grants are used.

Comment by Florian Engelmann [ 2016-01-26 ]

It looks like the "jan21" version is still crashing.

The crash was caused by using IP 10.0.248.202 which is listening to the RW split router of 5 MariaDB 5.5.47 nodes to dump a DB to the cluster:

mysql -h10.0.248.202  -uadmin -pxxxxxxxxxxxxxxxxxxxxxxxx ops_meta_db < ops_meta_db.sql

2016-01-25 16:21:34.150   error  : Backend hangup error handling.
2016-01-25 16:21:34.150   error  : Backend hangup error handling.
2016-01-25 19:04:29.502   error  : Backend hangup error handling.
2016-01-25 19:04:29.503   error  : Backend hangup error handling.
2016-01-25 19:34:53.271   error  : Backend hangup error handling.
2016-01-25 19:34:53.271   error  : Backend hangup error handling.
2016-01-25 19:34:53.273   error  : Backend hangup error handling.
2016-01-25 19:34:53.273   error  : Backend hangup error handling.
2016-01-25 20:06:34.445   error  : Backend hangup error handling.
2016-01-25 20:06:34.449   error  : Backend hangup error handling.
2016-01-25 20:06:34.452   error  : Backend hangup error handling.
2016-01-25 20:06:45.636   error  : Backend hangup error handling.
2016-01-25 20:07:26.176   error  : Backend hangup error handling.
2016-01-25 20:11:53.358   error  : debug assert /home/vagrant/workspace/server/modules/routing/readwritesplit/readwritesplit.c:1689 Dcb under- or overflow 
2016-01-25 20:11:53.358   error  : Fatal: MaxScale 1.3.0 received fatal signal 6. Attempting backtrace.
2016-01-25 20:11:53.358   error  : Commit ID: 99f39cb213511b95552c49052e77a12e46090129 System name: Linux Release string: Ubuntu 14.04.3 LTS Embedded library version: 5.5.42-MariaDB
2016-01-25 20:11:53.359   error  :   /usr/bin/maxscale() [0x54cb9e] 
2016-01-25 20:11:53.359   error  :   /lib/x86_64-linux-gnu/libpthread.so.0(+0x10340) [0x7fd6263c7340] 
2016-01-25 20:11:53.359   error  :   /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39) [0x7fd624ffecc9] 
2016-01-25 20:11:53.359   error  :   /lib/x86_64-linux-gnu/libc.so.6(abort+0x148) [0x7fd6250020d8] 
2016-01-25 20:11:53.359   error  :   /lib/x86_64-linux-gnu/libc.so.6(+0x2fb86) [0x7fd624ff7b86] 
2016-01-25 20:11:53.359   error  :   /lib/x86_64-linux-gnu/libc.so.6(+0x2fc32) [0x7fd624ff7c32] 
2016-01-25 20:11:53.359   error  :   /usr/lib/x86_64-linux-gnu/maxscale/libreadwritesplit.so(+0x4c67) [0x7fd61d420c67] 
2016-01-25 20:11:53.359   error  :   /usr/lib/x86_64-linux-gnu/maxscale/libreadwritesplit.so(+0x62a0) [0x7fd61d4222a0] 
2016-01-25 20:11:53.359   error  :   /usr/lib/x86_64-linux-gnu/maxscale/libreadwritesplit.so(+0x5a80) [0x7fd61d421a80] 
2016-01-25 20:11:53.360   error  :   /usr/lib/x86_64-linux-gnu/maxscale/libMySQLClient.so(+0x751c) [0x7fd608e2251c] 
2016-01-25 20:11:53.360   error  :   /usr/lib/x86_64-linux-gnu/maxscale/libMySQLClient.so(+0x51fa) [0x7fd608e201fa] 
2016-01-25 20:11:53.360   error  :   /usr/bin/maxscale() [0x565b59] 
2016-01-25 20:11:53.360   error  :   /usr/bin/maxscale(poll_waitevents+0x67e) [0x565137] 
2016-01-25 20:11:53.360   error  :   /lib/x86_64-linux-gnu/libpthread.so.0(+0x8182) [0x7fd6263bf182] 
2016-01-25 20:11:53.360   error  :   /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7fd6250c247d] 

/var/log/syslog from one of the Galera DB nodes:

Jan 25 16:21:34 wsccms-db05f-prod mysqld: 160125 16:21:34 [Warning] Aborted connection 694195 to db: 'ops_meta_db' user: 'admin' host: '10.0.249.211' (Unknown error)
Jan 25 19:04:29 wsccms-db05f-prod mysqld: 160125 19:04:29 [Warning] Aborted connection 704612 to db: 'ops_meta_db' user: 'admin' host: '10.0.249.211' (Unknown error)
Jan 25 19:34:53 wsccms-db05f-prod mysqld: 160125 19:34:53 [Warning] Aborted connection 706553 to db: 'ops_meta_db' user: 'admin' host: '10.0.249.211' (Unknown error)
Jan 25 20:06:34 wsccms-db05f-prod mysqld: 160125 20:06:34 [Warning] Aborted connection 708905 to db: 'ops_meta_db' user: 'admin' host: '10.0.249.211' (Unknown error)
Jan 25 20:11:53 wsccms-db05f-prod mysqld: 160125 20:11:53 [Warning] Aborted connection 331417 to db: 'unconnected' user: 'maxscalemon' host: '10.0.249.211' (Unknown error)

[MaxScale]
threads=4
syslog=1
maxlog=1
ms_timestamp=1
log_to_shm=0
log_warning=1
log_notice=1
log_info=0
log_debug=0
 
[CLI_listener]
type=listener
service=CLI
protocol=maxscaled
address=localhost
port=6603
 
[CLI]
type=service
router=cli
 
[debug]
type=service
router=debugcli
router_options=user
 
[debug_listener]
type=listener
service=debug
protocol=telnetd
port=4442
 
[galera_5_monitor]
type=monitor
module=galeramon
servers=dbf1,dbf2,dbf3,dbf4,dbf5
user=maxscalemon
passwd=euxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
monitor_interval=2000
disable_master_failback=1
available_when_donor=1
disable_master_role_setting=0
 
[galera_10_monitor]
type=monitor
module=galeramon
servers=dbg1,dbg2,dbg3,dbg4,dbg5
user=maxscalemon
passwd=exxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
monitor_interval=2000
disable_master_failback=1
available_when_donor=1
disable_master_role_setting=0
 
 
[galera_rr_service]
type=service
router=readconnroute
#connection_timeout=300
router_options=synced
servers=dbf1,dbf2,dbf3,dbf4,dbf5
user=maxscaleroute
passwd=Koxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
enable_root_user=0
version_string=5.5.47-MariaDB-RR
#optimize_wildcard=true
log_auth_warnings=true
 
[galera_rr10_service]
type=service
router=readconnroute
#connection_timeout=300
router_options=synced
servers=dbg1,dbg2,dbg3,dbg4,dbg5
user=maxscaleroute
passwd=Koxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
enable_root_user=0
version_string=10.1-MariaDB-RR
#optimize_wildcard=true
log_auth_warnings=true
 
 
[galera_rw_service]
type=service
router=readwritesplit
#connection_timeout=300
router_options=slave_selection_criteria=LEAST_CURRENT_OPERATIONS,disable_sescmd_history=true
max_slave_connections=100%
servers=dbf1,dbf2,dbf3,dbf4,dbf5
user=maxscaleroute
passwd=Kohxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
enable_root_user=0
version_string=5.5.47-MariaDB-RWsplit
#optimize_wildcard=true
log_auth_warnings=true
 
[galera_rw10_service]
type=service
router=readwritesplit
#connection_timeout=300
router_options=slave_selection_criteria=LEAST_CURRENT_OPERATIONS,disable_sescmd_history=true
max_slave_connections=100%
servers=dbg1,dbg2,dbg3,dbg4,dbg5
user=maxscaleroute
passwd=Koxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
enable_root_user=0
version_string=10.1-MariaDB-RWsplit
#optimize_wildcard=true
log_auth_warnings=true
 
 
[galera_rr_listener]
type=listener
service=galera_rr_service
protocol=MySQLClient
address=10.0.248.201
port=3306
 
[galera_rw_listener]
type=listener
service=galera_rw_service
protocol=MySQLClient
address=10.0.248.202
port=3306
 
[galera_rr10_listener]
type=listener
service=galera_rr10_service
protocol=MySQLClient
address=10.0.248.205
port=3306
 
[galera_rw10_listener]
type=listener
service=galera_rw10_service
protocol=MySQLClient
address=10.0.248.206
port=3306
 
[dbf1]
type=server
address=10.0.249.11
port=3306
protocol=MySQLBackend
 
[dbf2]
type=server
address=10.0.249.12
port=3306
protocol=MySQLBackend
 
[dbf3]
type=server
address=10.0.249.13
port=3306
protocol=MySQLBackend
 
[dbf4]
type=server
address=10.0.249.14
port=3306
protocol=MySQLBackend
 
[dbf5]
type=server
address=10.0.249.15
port=3306
protocol=MySQLBackend
 
[dbg1]
type=server
address=10.0.249.16
port=3306
protocol=MySQLBackend
 
[dbg2]
type=server
address=10.0.249.17
port=3306
protocol=MySQLBackend
 
[dbg3]
type=server
address=10.0.249.18
port=3306
protocol=MySQLBackend
 
[dbg4]
type=server
address=10.0.249.19
port=3306
protocol=MySQLBackend
 
[dbg5]
type=server
address=10.0.249.20
port=3306
protocol=MySQLBackend

Comment by markus makela [ 2016-01-26 ]

This seems to be an unrelated crash. I'll create a new bug report and copy the information there.

New bug: https://mariadb.atlassian.net/browse/MXS-559

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