Not capturing MySQL Prepared Statements


#1

Hi,

I am trying to monitor the traffic to our Percona XtraDB cluster but packetbeat only catches the "start transaction" and "commit" statements of my laravel application. The rest result in "WARN Response from unknown transaction. Ignoring." messages. Also queries run through Sequel Pro result in these messages. But the same query run through the command-line MySQL application does get logged.

Here is the excerpt of the packetbeat log of the queries run by my laravel application:

2016/02/25 09:00:34.896062 mysql.go:680: DBG Mysql transaction completed: {"affected_rows":0,"error_code":0,"error_message":"","insert_id":0,"iserror":false,"num_fields":0,"num_rows":0}
2016/02/25 09:00:34.896069 mysql.go:681: DBG
2016/02/25 09:00:34.896216 publish.go:82: DBG on event
2016/02/25 09:00:34.896338 publish.go:109: DBG Publish: {
"@timestamp": "2016-02-25T09:00:34.895Z",
"beat": {
"hostname": "[hostname]",
"name": "[hostname]"
},
"bytes_in": 22,
"bytes_out": 11,
"client_ip": "[client ip]",
"client_port": 33281,
"client_proc": "",
"client_server": "",
"count": 1,
"direction": "in",
"ip": "[server ip]",
"method": "START",
"mysql": {
"affected_rows": 0,
"error_code": 0,
"error_message": "",
"insert_id": 0,
"iserror": false,
"num_fields": 0,
"num_rows": 0
},
"path": "",
"port": 3306,
"proc": "",
"query": "START TRANSACTION",
"responsetime": 0,
"server": "",
"status": "OK",
"tags": [
],
"type": "mysql"
}
2016/02/25 09:00:34.896744 mysql.go:205: DBG MySQL parser called. parseState = Start
2016/02/25 09:00:34.896756 mysql.go:221: DBG MySQL Header: Packet length 119, Seq 0, Type=22
2016/02/25 09:00:34.896760 mysql.go:315: DBG Message complete. remaining=0
2016/02/25 09:00:34.896771 mysql.go:205: DBG MySQL parser called. parseState = Start
2016/02/25 09:00:34.896775 mysql.go:221: DBG MySQL Header: Packet length 12, Seq 1, Type=0
2016/02/25 09:00:34.896778 mysql.go:247: DBG Received OK response
2016/02/25 09:00:34.896783 mysql.go:315: DBG Message complete. remaining=601
2016/02/25 09:00:34.896790 mysql.go:644: WARN Response from unknown transaction. Ignoring.
.......
2016/02/25 09:00:34.897650 mysql.go:205: DBG MySQL parser called. parseState = Start
2016/02/25 09:00:34.897659 mysql.go:221: DBG MySQL Header: Packet length 5, Seq 0, Type=25
2016/02/25 09:00:34.897662 mysql.go:315: DBG Message complete. remaining=0
2016/02/25 09:00:34.897869 mysql.go:205: DBG MySQL parser called. parseState = Start
2016/02/25 09:00:34.897878 mysql.go:221: DBG MySQL Header: Packet length 8, Seq 0, Type=3
2016/02/25 09:00:34.897882 mysql.go:315: DBG Message complete. remaining=0
2016/02/25 09:00:34.897900 mysql.go:205: DBG MySQL parser called. parseState = Start
2016/02/25 09:00:34.897909 mysql.go:221: DBG MySQL Header: Packet length 7, Seq 1, Type=0
2016/02/25 09:00:34.897913 mysql.go:247: DBG Received OK response
2016/02/25 09:00:34.897917 mysql.go:315: DBG Message complete. remaining=0
2016/02/25 09:00:34.897927 mysql.go:840: DBG mysql.results exists
2016/02/25 09:00:34.897955 mysql.go:680: DBG Mysql transaction completed: {"affected_rows":0,"error_code":0,"error_message":"","insert_id":0,"iserror":false,"num_fields":0,"num_rows":0}
2016/02/25 09:00:34.897961 mysql.go:681: DBG
2016/02/25 09:00:34.898113 publish.go:82: DBG on event
2016/02/25 09:00:34.898183 publish.go:109: DBG Publish: {
"@timestamp": "2016-02-25T09:00:34.897Z",
"beat": {
"hostname": "[hostname]",
"name": "[hostname]"
},
"bytes_in": 12,
"bytes_out": 11,
"client_ip": "[client ip]",
"client_port": 33281,
"client_proc": "",
"client_server": "",
"count": 1,
"direction": "in",
"ip": "[server ip]",
"method": "COMMIT",
"mysql": {
"affected_rows": 0,
"error_code": 0,
"error_message": "",
"insert_id": 0,
"iserror": false,
"num_fields": 0,
"num_rows": 0
},
"path": "",
"port": 3306,
"proc": "",
"query": "COMMIT",
"responsetime": 0,
"server": "",
"status": "OK",
"tags": [
],
"type": "mysql"
}
2016/02/25 09:00:35.584757 output.go:87: DBG output worker: publish 2 events


(Steffen Siering) #2

Are you using prepared statements? These are not yet supported by the protocol analyzer.


#3

The query I use to test form the command line and sequel pro is "select 1;". I'm not sure about the laravel application;


#4

Inspections of tcpdump logs revealed that laravel uses prepared statements so there is no way of monitoring these yet.


(Steffen Siering) #5

For anyone interested in status of MySQL Prepared Statements in packetbeat follow issue #683 on github.

Contributions like PRs are always welcome.


(system) #6