Mysql data not seen in packetbeats


(Shaik Muzakkir) #1

I do not see the mysql data in the packetbeats when I run the command packetbeat -e -d "publish" -N. Whereas I see the DNS and Redis data flowing in. I have used the 127.0.0.1 ip to access mysql instead of localhost. My configuration fie has the port 3306 and is not commented. Please suggest.

Here is the output on running "select1;" in mysql console.:

[root@ip-10-39-196-70 ec2-user]# packetbeat -e -d "publish" -N
2016/07/26 05:04:05.097061 publish.go:202: INFO Dry run mode. All output types except the file based one are disabled.
2016/07/26 05:04:05.097175 geolite.go:24: INFO GeoIP disabled: No paths were set under output.geoip.paths
2016/07/26 05:04:05.097226 publish.go:288: INFO Publisher name: ip-10-39-196-70
2016/07/26 05:04:05.097381 beat.go:147: INFO Init Beat: packetbeat; Version: 1.2.3
2016/07/26 05:04:05.242745 beat.go:173: INFO packetbeat sucessfully setup. Start running.


(ruflin) #2

Can you share your config and share some more log output? Perhaps use * instead of publish to see all debug output.


(Shaik Muzakkir) #3

Hi,

Is there an email id I can send the config file and the packetbeat output to? Both the files seem to be quite large.

Regards,
Muzakkir


(ruflin) #4

Best would be to use a gist.


(Shaik Muzakkir) #5

Sure Ruflin.

Here is my config:

interfaces:
  device: any


protocols:
  dns:
    
    #ports: [53]


    include_authorities: true

    include_additionals: true

  http:

    ports: [80, 8080, 8000, 5000, 8002]

  memcache:

    ports: [11211]

  mysql:
    ports: [3306]
    send_response: true

  pgsql:
    ports: [5432]

  redis:
    #ports: [6379]

  thrift:
    ports: [9090]

  mongodb:
    ports: [27017]


output:

  elasticsearch:
    hosts: ["127.0.0.1:9200"]


shipper:
  #name:

  #tags: ["service-X", "web-tier"]

logging:

  files:
    # The directory where the log files will written to.
    #path: /var/log/mybeat

    rotateeverybytes: 10485760 # = 10MB

(Shaik Muzakkir) #6

And here are the output for packetbeat -e -d "*" -N

[root@ip-10-39-196-70 ec2-user]# packetbeat -e -d "*" -N
2016/07/26 06:48:26.260064 beat.go:135: DBG Initializing output plugins
2016/07/26 06:48:26.260241 publish.go:202: INFO Dry run mode. All output types except the file based one are disabled.
2016/07/26 06:48:26.260249 geolite.go:24: INFO GeoIP disabled: No paths were set under output.geoip.paths
2016/07/26 06:48:26.260264 publish.go:288: INFO Publisher name: ip-10-39-196-70
2016/07/26 06:48:26.260360 beat.go:147: INFO Init Beat: packetbeat; Version: 1.2.3
2016/07/26 06:48:26.295922 packetbeat.go:166: DBG Initializing protocol plugins
2016/07/26 06:48:26.295945 memcache.go:105: DBG init memcache plugin
2016/07/26 06:48:26.296644 memcache.go:158: DBG maxValues = 0
2016/07/26 06:48:26.296649 memcache.go:159: DBG maxBytesPerValue = 2147483647
2016/07/26 06:48:26.296682 mongodb.go:73: DBG Init a MongoDB protocol parser
2016/07/26 06:48:26.296811 icmp.go:69: DBG Local IP addresses: [127.0.0.1 10.39.196.70 ::1 fe80::4f8:aaff:fe0c:fddf]
2016/07/26 06:48:26.296878 tcp.go:251: DBG tcp%!(EXTRA string=Port map: %v, map[uint16]protos.Protocol=map[8000:http 5000:http 8002:http 11211:memcache 27017:mongodb 80:http 8080:http 3306:mysql 5432:pgsql 9090:thrift])
2016/07/26 06:48:26.296887 udp.go:93: DBG Port map: map[11211:memcache]
2016/07/26 06:48:26.296891 packetbeat.go:212: DBG Initializing sniffer
2016/07/26 06:48:26.296910 sniffer.go:251: DBG BPF filter: tcp port 80 or tcp port 8080 or tcp port 8000 or tcp port 5000 or tcp port 8002 or tcp port 3306 or tcp port 5432 or tcp port 9090 or tcp port 27017 or port 11211
2016/07/26 06:48:26.296917 sniffer.go:130: DBG Sniffer type: pcap device: any
2016/07/26 06:48:26.442449 decoder.go:63: DBG Layer type: Linux SLL
2016/07/26 06:48:26.442608 beat.go:173: INFO packetbeat sucessfully setup. Start running.
2016/07/26 06:48:26.442619 packetbeat.go:244: DBG Waiting for the sniffer to finish
2016/07/26 06:48:26.947780 sniffer.go:297: DBG Interrupted
2016/07/26 06:48:27.458546 sniffer.go:297: DBG Interrupted
2016/07/26 06:48:27.549473 sniffer.go:354: DBG Packet number: 1
2016/07/26 06:48:27.549503 decoder.go:92: DBG decode packet data
2016/07/26 06:48:27.549528 decoder.go:143: DBG IPv4 packet
2016/07/26 06:48:27.549534 decoder.go:172: DBG TCP packet
2016/07/26 06:48:27.549572 tcp.go:192: DBG Connection src[127.0.0.1:46600] dst[127.0.0.1:3306] doesn't exist, creating new
2016/07/26 06:48:27.549584 tcp.go:132: DBG pkt.start_seq=908553710 pkt.last_seq=908553843 stream.last_seq=0 (len=133)
2016/07/26 06:48:27.549595 mysql.go:205: DBG MySQL parser called. parseState = Start
2016/07/26 06:48:27.549600 mysql.go:221: DBG MySQL Header: Packet length 131863, Seq 0, Type=128
2016/07/26 06:48:27.604528 sniffer.go:354: DBG Packet number: 2
2016/07/26 06:48:27.604557 decoder.go:92: DBG decode packet data
2016/07/26 06:48:27.604569 decoder.go:143: DBG IPv4 packet
2016/07/26 06:48:27.604574 decoder.go:172: DBG TCP packet
2016/07/26 06:48:27.604578 decoder.go:179: DBG Ignore empty non-FIN packet
2016/07/26 06:48:27.622399 sniffer.go:354: DBG Packet number: 3
2016/07/26 06:48:27.622423 decoder.go:92: DBG decode packet data
2016/07/26 06:48:27.622433 decoder.go:143: DBG IPv4 packet
2016/07/26 06:48:27.622438 decoder.go:172: DBG TCP packet
2016/07/26 06:48:27.622454 tcp.go:132: DBG pkt.start_seq=4186220379 pkt.last_seq=4186220544 stream.last_seq=0 (len=165)
2016/07/26 06:48:27.622468 mysql.go:205: DBG MySQL parser called. parseState = Start
2016/07/26 06:48:27.622473 mysql.go:221: DBG MySQL Header: Packet length 131863, Seq 0, Type=160
2016/07/26 06:48:27.622854 sniffer.go:354: DBG Packet number: 4
2016/07/26 06:48:27.622864 decoder.go:92: DBG decode packet data
2016/07/26 06:48:27.622868 decoder.go:143: DBG IPv4 packet
2016/07/26 06:48:27.622871 decoder.go:172: DBG TCP packet
2016/07/26 06:48:27.622874 decoder.go:179: DBG Ignore empty non-FIN packet
2016/07/26 06:48:27.622881 sniffer.go:354: DBG Packet number: 5
2016/07/26 06:48:27.622885 decoder.go:92: DBG decode packet data
2016/07/26 06:48:27.622888 decoder.go:143: DBG IPv4 packet
2016/07/26 06:48:27.622890 decoder.go:172: DBG TCP packet
2016/07/26 06:48:27.622897 tcp.go:132: DBG pkt.start_seq=908553843 pkt.last_seq=908553912 stream.last_seq=908553843 (len=69)
2016/07/26 06:48:27.622904 mysql.go:205: DBG MySQL parser called. parseState = EatMessage
2016/07/26 06:48:27.622917 sniffer.go:354: DBG Packet number: 6
2016/07/26 06:48:27.622922 decoder.go:92: DBG decode packet data


(Steffen Siering) #7

is your application using prepared statements?


(Shaik Muzakkir) #8

Hey Steffens,

Not using prepared statements. Even if I execute a sample select statement like "select 1;" packetbeat does not show any result.


(ruflin) #9

In the logs there seems to be some MySQL traffic. @steffens Any idea why it should not be pushed?


(Steffen Siering) #10

I guess the parser not supporting the mysql message type being send. Not sure what Type=160 is for example.

Some tcpdump trace would be helpful.


(Shaik Muzakkir) #11

[root@ip-10-39-196-70 ec2-user]# tcpdump -ttttnr trace.pcap
reading from file trace.pcap, link-type EN10MB (Ethernet)
2016-07-26 05:29:12.064829 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 1253330924, win 8701, options [nop,nop,TS val 1033526457 ecr 1033526447], length 0
2016-07-26 05:29:12.086495 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 0:165, ack 1, win 8702, options [nop,nop,TS val 1033526462 ecr 1033526447], length 165
2016-07-26 05:29:12.127315 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [.], ack 165, win 3076, options [nop,nop,TS val 1033526472 ecr 1033526462], length 0
2016-07-26 05:29:12.129445 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 1:70, ack 165, win 3076, options [nop,nop,TS val 1033526473 ecr 1033526462], length 69
2016-07-26 05:29:12.129453 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 70, win 8702, options [nop,nop,TS val 1033526473 ecr 1033526473], length 0
2016-07-26 05:29:12.129618 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 165:234, ack 70, win 8702, options [nop,nop,TS val 1033526473 ecr 1033526473], length 69
2016-07-26 05:29:12.129675 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [.], ack 234, win 3076, options [nop,nop,TS val 1033526473 ecr 1033526473], length 0
2016-07-26 05:29:12.130822 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 70:203, ack 234, win 3076, options [nop,nop,TS val 1033526473 ecr 1033526473], length 133
2016-07-26 05:29:12.168799 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 203, win 8702, options [nop,nop,TS val 1033526483 ecr 1033526473], length 0
2016-07-26 05:29:12.208502 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 234:399, ack 203, win 8702, options [nop,nop,TS val 1033526492 ecr 1033526473], length 165
2016-07-26 05:29:12.208765 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 203:272, ack 399, win 3076, options [nop,nop,TS val 1033526492 ecr 1033526492], length 69
2016-07-26 05:29:12.208790 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 272, win 8702, options [nop,nop,TS val 1033526493 ecr 1033526492], length 0
2016-07-26 05:29:12.208938 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 399:468, ack 272, win 8702, options [nop,nop,TS val 1033526493 ecr 1033526492], length 69
2016-07-26 05:29:12.248878 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [.], ack 468, win 3076, options [nop,nop,TS val 1033526503 ecr 1033526493], length 0
2016-07-26 05:29:15.120777 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 272:405, ack 468, win 3076, options [nop,nop,TS val 1033527220 ecr 1033526493], length 133
2016-07-26 05:29:15.157651 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 405, win 8702, options [nop,nop,TS val 1033527230 ecr 1033527220], length 0
2016-07-26 05:29:15.387525 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 468:633, ack 405, win 8702, options [nop,nop,TS val 1033527287 ecr 1033527220], length 165
2016-07-26 05:29:15.387604 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [.], ack 633, win 3076, options [nop,nop,TS val 1033527287 ecr 1033527287], length 0
2016-07-26 05:29:15.387798 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 405:474, ack 633, win 3076, options [nop,nop,TS val 1033527287 ecr 1033527287], length 69
2016-07-26 05:29:15.387803 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 474, win 8702, options [nop,nop,TS val 1033527287 ecr 1033527287], length 0
2016-07-26 05:29:15.408938 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 633:702, ack 474, win 8702, options [nop,nop,TS val 1033527293 ecr 1033527287], length 69
2016-07-26 05:29:15.409180 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 474:607, ack 702, win 3076, options [nop,nop,TS val 1033527293 ecr 1033527293], length 133
2016-07-26 05:29:15.448813 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 607, win 8702, options [nop,nop,TS val 1033527303 ecr 1033527293], length 0
2016-07-26 05:29:15.898243 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 702:867, ack 607, win 8702, options [nop,nop,TS val 1033527415 ecr 1033527293], length 165
2016-07-26 05:29:15.898467 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 607:676, ack 867, win 3076, options [nop,nop,TS val 1033527415 ecr 1033527415], length 69
2016-07-26 05:29:15.898478 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 676, win 8702, options [nop,nop,TS val 1033527415 ecr 1033527415], length 0
2016-07-26 05:29:15.936887 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 867:936, ack 676, win 8702, options [nop,nop,TS val 1033527425 ecr 1033527415], length 69
2016-07-26 05:29:15.937134 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 676:809, ack 936, win 3076, options [nop,nop,TS val 1033527425 ecr 1033527425], length 133
2016-07-26 05:29:15.937145 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 809, win 8701, options [nop,nop,TS val 1033527425 ecr 1033527425], length 0
2016-07-26 05:29:15.940571 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 936:1101, ack 809, win 8702,


(Shaik Muzakkir) #12

So I found that when I test it on the below database version, the packetbeat captures data :

mysql> SHOW VARIABLES LIKE "%version%";
+-------------------------+---------------------------------------------------------+
| Variable_name | Value |
+-------------------------+---------------------------------------------------------+
| innodb_version | 5.6.23 |
| protocol_version | 10 |
| slave_type_conversions | |
| version | 5.6.23-enterprise-commercial-advanced-log |
| version_comment | MySQL Enterprise Server - Advanced Edition (Commercial) |
| version_compile_machine | x86_64 |
| version_compile_os | Linux |
+-------------------------+---------------------------------------------------------+
7 rows in set (0.00 sec)

But packetbeat on the below mysql version does not work :

mysql> SHOW VARIABLES LIKE "%version%";
+-------------------------+------------------------------+
| Variable_name | Value |
+-------------------------+------------------------------+
| innodb_version | 5.7.13 |
| protocol_version | 10 |
| slave_type_conversions | |
| tls_version | TLSv1,TLSv1.1 |
| version | 5.7.13 |
| version_comment | MySQL Community Server (GPL) |
| version_compile_machine | x86_64 |
| version_compile_os | Linux |
+-------------------------+------------------------------+
8 rows in set (0.22 sec)

Is packetbeat not supported for mysql community version?


(Steffen Siering) #13

No idea why it's not working with 5.7.13 for you. But I wonder if TLS or plain TCP is used when connecting to 5.7.13.

Can you get us a test pcap, so we can check the actual content and message types with packetbeat?


(Shaik Muzakkir) #14

Here is the test pcap with tcpdump :

[root@ip-10-39-196-70 ec2-user]# tcpdump -ttttnr trace.pcap
reading from file trace.pcap, link-type EN10MB (Ethernet)
2016-07-26 05:29:12.064829 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 1253330924, win 8701, options [nop,nop,TS val 1033526457 ecr 1033526447], length 0
2016-07-26 05:29:12.086495 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 0:165, ack 1, win 8702, options [nop,nop,TS val 1033526462 ecr 1033526447], length 165
2016-07-26 05:29:12.127315 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [.], ack 165, win 3076, options [nop,nop,TS val 1033526472 ecr 1033526462], length 0
2016-07-26 05:29:12.129445 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 1:70, ack 165, win 3076, options [nop,nop,TS val 1033526473 ecr 1033526462], length 69
2016-07-26 05:29:12.129453 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 70, win 8702, options [nop,nop,TS val 1033526473 ecr 1033526473], length 0
2016-07-26 05:29:12.129618 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 165:234, ack 70, win 8702, options [nop,nop,TS val 1033526473 ecr 1033526473], length 69
2016-07-26 05:29:12.129675 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [.], ack 234, win 3076, options [nop,nop,TS val 1033526473 ecr 1033526473], length 0
2016-07-26 05:29:12.130822 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 70:203, ack 234, win 3076, options [nop,nop,TS val 1033526473 ecr 1033526473], length 133
2016-07-26 05:29:12.168799 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 203, win 8702, options [nop,nop,TS val 1033526483 ecr 1033526473], length 0
2016-07-26 05:29:12.208502 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 234:399, ack 203, win 8702, options [nop,nop,TS val 1033526492 ecr 1033526473], length 165
2016-07-26 05:29:12.208765 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 203:272, ack 399, win 3076, options [nop,nop,TS val 1033526492 ecr 1033526492], length 69
2016-07-26 05:29:12.208790 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 272, win 8702, options [nop,nop,TS val 1033526493 ecr 1033526492], length 0
2016-07-26 05:29:12.208938 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 399:468, ack 272, win 8702, options [nop,nop,TS val 1033526493 ecr 1033526492], length 69
2016-07-26 05:29:12.248878 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [.], ack 468, win 3076, options [nop,nop,TS val 1033526503 ecr 1033526493], length 0
2016-07-26 05:29:15.120777 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 272:405, ack 468, win 3076, options [nop,nop,TS val 1033527220 ecr 1033526493], length 133
2016-07-26 05:29:15.157651 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 405, win 8702, options [nop,nop,TS val 1033527230 ecr 1033527220], length 0
2016-07-26 05:29:15.387525 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 468:633, ack 405, win 8702, options [nop,nop,TS val 1033527287 ecr 1033527220], length 165
2016-07-26 05:29:15.387604 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [.], ack 633, win 3076, options [nop,nop,TS val 1033527287 ecr 1033527287], length 0
2016-07-26 05:29:15.387798 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 405:474, ack 633, win 3076, options [nop,nop,TS val 1033527287 ecr 1033527287], length 69
2016-07-26 05:29:15.387803 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 474, win 8702, options [nop,nop,TS val 1033527287 ecr 1033527287], length 0
2016-07-26 05:29:15.408938 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 633:702, ack 474, win 8702, options [nop,nop,TS val 1033527293 ecr 1033527287], length 69
2016-07-26 05:29:15.409180 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 474:607, ack 702, win 3076, options [nop,nop,TS val 1033527293 ecr 1033527293], length 133
2016-07-26 05:29:15.448813 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 607, win 8702, options [nop,nop,TS val 1033527303 ecr 1033527293], length 0
2016-07-26 05:29:15.898243 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 702:867, ack 607, win 8702, options [nop,nop,TS val 1033527415 ecr 1033527293], length 165
2016-07-26 05:29:15.898467 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 607:676, ack 867, win 3076, options [nop,nop,TS val 1033527415 ecr 1033527415], length 69
2016-07-26 05:29:15.898478 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 676, win 8702, options [nop,nop,TS val 1033527415 ecr 1033527415], length 0
2016-07-26 05:29:15.936887 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [P.], seq 867:936, ack 676, win 8702, options [nop,nop,TS val 1033527425 ecr 1033527415], length 69
2016-07-26 05:29:15.937134 IP 127.0.0.1.47914 > 127.0.0.1.mysql: Flags [P.], seq 676:809, ack 936, win 3076, options [nop,nop,TS val 1033527425 ecr 1033527425], length 133
2016-07-26 05:29:15.937145 IP 127.0.0.1.mysql > 127.0.0.1.47914: Flags [.], ack 809, win 8701, options [nop,nop,TS val 1033527425 ecr 1033527425], length 0


(Steffen Siering) #15

this is not the pcap, but the output. I'm asking for the pcap file itself.


(Shaik Muzakkir) #16

Did you mean the pcap file I get after running the below command?

tcpdump -i lo -s 0 -w trace.pcap "port 3306"


(Shaik Muzakkir) #17

Can you give me an email id where I can send the file to?


(ruflin) #18

Could you put it into the gist?


(Shaik Muzakkir) #19

I have uploaded it on the github repository here - https://github.com/shaikmuzakkir/Packetbeat/tree/master/Packetbeat

Can you access from there?


(Steffen Siering) #20

Thanks I can access the pcap. It the connection is encrypted. Wireshark tells me TLS 1.1 is used. packetbeat can not analyze encrypted traffic.