JSON Parse errors in elasticsearch for DNS_QUERYs

[andris]

This seems similar to #522 in that I get errors in elasticsearch about ntopng trying to send invalid UTF-8 characters, though in my case i am not using nprobe or zmq.

I have ntopng configured to export flows to elasticsearch using --dump-flows: --dump-flows="es;flows;ntopng-%Y.%m.%d;http://localhost:9200/_bulk;"

I am using the latest dev build of ntopng: v.2.5.160628 [Professional Edition] GIT rev: dev:3e0705528bb8322f67b1b9d2a2476f5294ae0ca8:20160628 Pro rev: r642 System Id: 3B2109BC550461D2 Built on: Ubuntu 16.04 LTS

As you can see from the elasticsearch logs, it seems to be related specifically to DNS_QUERYs

[2016-06-28 19:21:31,115][DEBUG][action.bulk ] [Spike Freeman] [ntopng-2016.06.28][0] failed to execute bulk item (index) index {[ntopng-2016.06.28][flows][AVWX0MtpQ8by_esQC72N], source[{ "@timestamp": "2016-06-28T16:20:53.0Z", "type": "flows", "IN_SRC_MAC": "4C:5E:0C:F6:9F:A3", "OUT_DST_MAC": "4C:5E:0C:F6:9D:93", "IPV4_SRC_ADDR": "10.60.2.165", "IPV4_DST_ADDR": "8.8.8.8", "L4_SRC_PORT": 56381, "L4_DST_PORT": 53, "PROTOCOL": 17, "L7_PROTO": 5, "L7_PROTO_NAME": "DNS", "IN_PKTS": 1, "IN_BYTES": 131, "OUT_PKTS": 1, "OUT_BYTES": 206, "FIRST_SWITCHED": 1467130853, "LAST_SWITCHED": 1467130853, "DST_IP_COUNTRY": "US", "DST_IP_LOCATION": [ -122.083801, 37.386002 ], "NTOPNG_INSTANCE_NAME": "TRAFFIC", "INTERFACE": "eth1", "DNS_QUERY": "dr._dns-sd._udp.��w.8�x.", "PASS_VERDICT": true }]} MapperParsingException[failed to parse [DNS_QUERY]]; nested: JsonParseException[Invalid UTF-8 start byte 0x98 [2016-06-28 19:30:06,583][DEBUG][action.bulk ] [Spike Freeman] [ntopng-2016.06.28][0] failed to execute bulk item (index) index {[ntopng-2016.06.28][flows][AVWX2Kj2Q8by_esQE759], source[{ "@timestamp": "2016-06-28T16:29:30.0Z", "type": "flows", "IN_SRC_MAC": "4C:5E:0C:F6:9F:A3", "OUT_DST_MAC": "4C:5E:0C:F6:9D:93", "IPV4_SRC_ADDR": "10.60.4.5", "IPV4_DST_ADDR": "77.234.43.63", "L4_SRC_PORT": 52465, "L4_DST_PORT": 53, "PROTOCOL": 17, "L7_PROTO": 5, "L7_PROTO_NAME": "DNS", "IN_PKTS": 1, "IN_BYTES": 601, "OUT_PKTS": 1, "OUT_BYTES": 329, "FIRST_SWITCHED": 1467131370, "LAST_SWITCHED": 1467131370, "DST_IP_COUNTRY": "GB", "DST_IP_LOCATION": [ -0.093100, 51.514198 ], "NTOPNG_INSTANCE_NAME": "TRAFFIC", "INTERFACE": "eth1", "DNS_QUERY": "p��d۵8h�.e��.�", "PASS_VERDICT": true }]} MapperParsingException[failed to parse [DNS_QUERY]]; nested: JsonParseException[Invalid UTF-8 start byte 0xa7 [2016-06-28 19:33:20,127][DEBUG][action.bulk ] [Spike Freeman] [ntopng-2016.06.28][2] failed to execute bulk item (index) index {[ntopng-2016.06.28][flows][AVWX25z-Q8by_esQFm3r], source[{ "@timestamp": "2016-06-28T16:32:53.0Z", "type": "flows", "IN_SRC_MAC": "4C:5E:0C:F6:9F:A3", "OUT_DST_MAC": "4C:5E:0C:F6:9D:93", "IPV4_SRC_ADDR": "10.60.8.50", "IPV4_DST_ADDR": "168.1.69.110", "L4_SRC_PORT": 62613, "L4_DST_PORT": 53, "PROTOCOL": 17, "L7_PROTO": 5, "L7_PROTO_NAME": "DNS", "IN_PKTS": 1, "IN_BYTES": 601, "OUT_PKTS": 0, "OUT_BYTES": 0, "FIRST_SWITCHED": 1467131573, "LAST_SWITCHED": 1467131573, "DST_IP_COUNTRY": "AU", "DST_IP_LOCATION": [ 144.963394, -37.813900 ], "NTOPNG_INSTANCE_NAME": "TRAFFIC", "INTERFACE": "eth1", "DNSQUERY": "���|�y�@x.�.#u����4�0}���`�!\�z�..0|����qbjܠ\/.eft�.��?�.�...�ä...e��.71n0~��=�mdo2b��� �.�to׶���+ݼ�z.j�ڱ�...�(.�.fw�.�k�tf��\/�k�d.�f�c��sc�:��x\\..�nj��,�.o��7.w���.ܠ����h��.}�", "PASS_VERDICT": true }]} MapperParsingException[failed to parse [DNS_QUERY]]; nested: JsonParseException[Invalid UTF-8 middle byte 0x7c [2016-06-28 19:33:42,855][DEBUG][action.bulk ] [Spike Freeman] [ntopng-2016.06.28][1] failed to execute bulk item (index) index {[ntopng-2016.06.28][flows][AVWX2_XHQ8by_esQFs7Y], source[{ "@timestamp": "2016-06-28T16:33:09.0Z", "type": "flows", "IN_SRC_MAC": "4C:5E:0C:F6:9F:A3", "OUT_DST_MAC": "4C:5E:0C:F6:9D:93", "IPV4_SRC_ADDR": "10.60.8.50", "IPV4_DST_ADDR": "161.202.108.200", "L4_SRC_PORT": 57872, "L4_DST_PORT": 53, "PROTOCOL": 17, "L7_PROTO": 5, "L7_PROTO_NAME": "DNS", "IN_PKTS": 1, "IN_BYTES": 601, "OUT_PKTS": 0, "OUT_BYTES": 0, "FIRST_SWITCHED": 1467131589, "LAST_SWITCHED": 1467131589, "DST_IP_COUNTRY": "JP", "DST_IP_LOCATION": [ 139.751404, 35.685001 ], "NTOPNG_INSTANCE_NAME": "TRAFFIC", "INTERFACE": "eth1", "DNS_QUERY": ".nv��..�.tek���..�.?\\�n���vs����z�.\/3������.e�+���?co9n6gڷ�.�..��m=..�a�0ʨ�rt�.h�m}�.��.5p��ϙ�lq.:m��...�.�z0���2��(.{��cn�œ��z�.w\/.�b.�$5.�@�@x�Ԝ.td�6m!>�h.�y��a�����}.3���.3f", "PASS_VERDICT": true }]}

[simonemainardi]

the reason should this one: JsonParseException[Invalid UTF-8...

Does this happen for every DNS query? Or it is a sporadic event? Are you able to generate a pcap of the DNS query that triggered the error?

[lucaderi]

Did you update nprobe to the latest version? The issue is on the nProbe side not on the ntop one

[andris]

@simonemainardi - this happens continuously - about every 10-30 seconds or so. Having done a little more research on this - I think this is likely a result of DNS queries "generated by 'Multicast/Unicast DNS Service Discovery or Zeroconf', which is a service of Apple 'Bonjour/Rendevous' or Unix Services like 'Avahi'." More info here: https://docs.menandmice.com/pages/viewpage.action?pageId=6360942

I compared my DNS logs to strings from some of the more readable elasticsearch JsonParse errors. The DNS queries that seem to cause this issue in ntopng are DNS PTR records for hosts like "dr._dns-sd._udp."

Here is a capture of some of the packets that seem to cause this issue

tcpdump_20160628_dns.pcap.zip

@lucaderi - I'm not using nProbe or netflow at all. my architecture is:

router -> TZSP to relay traffic -> ntopng -> elasticsearch

I am using the latest dev build of ntopng: v.2.5.160628 [Professional Edition] GIT rev: dev:3e0705528bb8322f67b1b9d2a2476f5294ae0ca8:20160628 Pro rev: r642 System Id: 3B2109BC550461D2 Built on: Ubuntu 16.04 LTS

[lucaderi]

I have analysed the pcap but the JSON looks good

29/Jun/2016 00:22:15 [NetworkInterface.cpp:441] [ES] { "@timestamp": "2016-06-28T17:14:56.0Z", "type": "ntopng", "IN_SRC_MAC": "4C:5E:0C:F6:9D:93", "OUT_DST_MAC": "4C:5E:0C:F6:9F:A3", "IPV4_SRC_ADDR": "8.8.4.4", "IPV4_DST_ADDR": "10.40.2.1", "L4_SRC_PORT": 53, "L4_DST_PORT": 58054, "PROTOCOL": 17, "L7_PROTO": 5, "L7_PROTO_NAME": "DNS", "IN_PKTS": 1, "IN_BYTES": 147, "OUT_PKTS": 0, "OUT_BYTES": 0, "FIRST_SWITCHED": 1467134096, "LAST_SWITCHED": 1467134096, "SRC_IP_COUNTRY": "US", "SRC_IP_LOCATION": [ -97, 38 ], "NTOPNG_INSTANCE_NAME": "Lucas-iMac.local", "INTERFACE": "tcpdump_20160628_dns.pcap", "DNS_QUERY": "dr._dns-sd._udp.0.0.168.192.in-addr.arpa", "PASS_VERDICT": true } 29/Jun/2016 00:22:15 [NetworkInterface.cpp:441] [ES] { "@timestamp": "2016-06-28T17:14:58.0Z", "type": "ntopng", "IN_SRC_MAC": "4C:5E:0C:F6:9F:A3", "OUT_DST_MAC": "4C:5E:0C:F6:9D:93", "IPV4_SRC_ADDR": "10.80.12.246", "IPV4_DST_ADDR": "8.8.8.8", "L4_SRC_PORT": 3514, "L4_DST_PORT": 53, "PROTOCOL": 17, "L7_PROTO": 5, "L7_PROTO_NAME": "DNS", "IN_PKTS": 1, "IN_BYTES": 134, "OUT_PKTS": 0, "OUT_BYTES": 0, "FIRST_SWITCHED": 1467134098, "LAST_SWITCHED": 1467134098, "DST_IP_COUNTRY": "US", "DST_IP_LOCATION": [ -122.08809661865234, 37.384498596191406 ], "NTOPNG_INSTANCE_NAME": "Lucas-iMac.local", "INTERFACE": "tcpdump_20160628_dns.pcap", "DNS_QUERY": "234.208.58.216.in-addr.arpa", "PASS_VERDICT": true } 29/Jun/2016 00:22:15 [NetworkInterface.cpp:441] [ES] { "@timestamp": "2016-06-28T17:15:06.0Z", "type": "ntopng", "IN_SRC_MAC": "4C:5E:0C:F6:9F:A3", "OUT_DST_MAC": "4C:5E:0C:F6:9D:93", "IPV4_SRC_ADDR": "10.40.2.1", "IPV4_DST_ADDR": "8.8.4.4", "L4_SRC_PORT": 36425, "L4_DST_PORT": 53, "PROTOCOL": 17, "L7_PROTO": 5, "L7_PROTO_NAME": "DNS", "IN_PKTS": 1, "IN_BYTES": 130, "OUT_PKTS": 0, "OUT_BYTES": 0, "FIRST_SWITCHED": 1467134106, "LAST_SWITCHED": 1467134106, "DST_IP_COUNTRY": "US", "DST_IP_LOCATION": [ -97, 38 ], "NTOPNG_INSTANCE_NAME": "Lucas-iMac.local", "INTERFACE": "tcpdump_20160628_dns.pcap", "DNS_QUERY": "1.90.13.31.in-addr.arpa", "PASS_VERDICT": true } 29/Jun/2016 00:22:15 [NetworkInterface.cpp:441] [ES] { "@timestamp": "2016-06-28T17:14:56.0Z", "type": "ntopng", "IN_SRC_MAC": "4C:5E:0C:F6:9F:A3", "OUT_DST_MAC": "4C:5E:0C:F6:9D:93", "IPV4_SRC_ADDR": "10.40.2.1", "IPV4_DST_ADDR": "8.8.4.4", "L4_SRC_PORT": 46171, "L4_DST_PORT": 53, "PROTOCOL": 17, "L7_PROTO": 5, "L7_PROTO_NAME": "DNS", "IN_PKTS": 1, "IN_BYTES": 146, "OUT_PKTS": 1, "OUT_BYTES": 146, "FIRST_SWITCHED": 1467134096, "LAST_SWITCHED": 1467134096, "DST_IP_COUNTRY": "US", "DST_IP_LOCATION": [ -97, 38 ], "NTOPNG_INSTANCE_NAME": "Lucas-iMac.local", "INTERFACE": "tcpdump_20160628_dns.pcap", "DNS_QUERY": "b._dns-sd._udp.0.0.168.192.in-addr.arpa", "PASS_VERDICT": true } 29/Jun/2016 00:22:15 [NetworkInterface.cpp:441] [ES] { "@timestamp": "2016-06-28T17:14:58.0Z", "type": "ntopng", "IN_SRC_MAC": "4C:5E:0C:F6:9F:A3", "OUT_DST_MAC": "4C:5E:0C:F6:9D:93", "IPV4_SRC_ADDR": "10.40.2.1", "IPV4_DST_ADDR": "8.8.4.4", "L4_SRC_PORT": 41407, "L4_DST_PORT": 53, "PROTOCOL": 17, "L7_PROTO": 5, "L7_PROTO_NAME": "DNS", "IN_PKTS": 1, "IN_BYTES": 133, "OUT_PKTS": 1, "OUT_BYTES": 193, "FIRST_SWITCHED": 1467134097, "LAST_SWITCHED": 1467134098, "DST_IP_COUNTRY": "US", "DST_IP_LOCATION": [ -97, 38 ], "NTOPNG_INSTANCE_NAME": "Lucas-iMac.local", "INTERFACE": "tcpdump_20160628_dns.pcap", "DNS_QUERY": "35.230.125.74.in-addr.arpa", "PASS_VERDICT": true }

Probably we need a different pcap

[andris]

Darn - looks like it's not as simple as finding all the DNS PTR packets with names like "dr._dns-sd._udp." some of them seem to process correctly and some not.

I will go back and continue to try to reproduce this and catch it in a pcap file.

[lucaderi]

"DNS_QUERY": "dr._dns-sd._udp.0.0.168.192.in-addr.arpa" is a valid JSON string. The problem happens with "DNS_QUERY": ".nv��..�.tek���..�.?\�n���vs����z�.\/3������.e�+���?co9n6�gڷ�.�..��m=..�a�0ʨ�rt�.h�m}�.��.5p��ϙ�lq.:m��...�.�z0���2��(.{��cn�œ��z�.w\/.�b.�$5.�@�@x�Ԝ.td�6m!>�h.�y��a�����}.3���.3f",

[andris]

it seems like some of the db._dns-sd._udp queries do have bad characters though

[2016-06-29 01:30:53,589][DEBUG][action.bulk ] [Flygirl] [ntopng-2016.06.28][3] failed to execute bulk item (index) index {[ntopng-2016.06.28][flows][AVWZIveUwQBnFnmiC6mo], source[{ "@timestamp": "2016-06-28T22:30:25.0Z", "type": "flows", "IN_SRC_MAC": "4C:5E:0C:F6:9F:A3", "OUT_DST_MAC": "4C:5E:0C:F6:9D:93", "IPV4_SRC_ADDR": "10.40.2.1", "IPV4_DST_ADDR": "8.8.4.4", "L4_SRC_PORT": 39403, "L4_DST_PORT": 53, "PROTOCOL": 17, "L7_PROTO": 5, "L7_PROTO_NAME": "DNS", "IN_PKTS": 1, "IN_BYTES": 126, "OUT_PKTS": 1, "OUT_BYTES": 201, "FIRST_SWITCHED": 1467153024, "LAST_SWITCHED": 1467153025, "DST_IP_COUNTRY": "US", "DST_IP_LOCATION": [ -97.000000, 38.000000 ], "NTOPNG_INSTANCE_NAME": "SURF-TRAFFIC", "INTERFACE": "eth1", "DNS_QUERY": "dr._dns-sd._udp.�[\/", "PASS_VERDICT": true }]} [2016-06-29 01:39:50,116][DEBUG][action.bulk ] [Flygirl] [ntopng-2016.06.28][3] failed to execute bulk item (index) index {[ntopng-2016.06.28][flows][AVWZKydiwQBnFnmiFEeW], source[{ "@timestamp": "2016-06-28T22:39:33.0Z", "type": "flows", "IN_SRC_MAC": "4C:5E:0C:F6:9F:A3", "OUT_DST_MAC": "4C:5E:0C:F6:9D:93", "IPV4_SRC_ADDR": "10.40.2.1", "IPV4_DST_ADDR": "196.200.16.2", "L4_SRC_PORT": 60591, "L4_DST_PORT": 53, "PROTOCOL": 17, "L7_PROTO": 5, "L7_PROTO_NAME": "DNS", "IN_PKTS": 1, "IN_BYTES": 126, "OUT_PKTS": 1, "OUT_BYTES": 201, "FIRST_SWITCHED": 1467153573, "LAST_SWITCHED": 1467153573, "DST_IP_COUNTRY": "KE", "DST_IP_LOCATION": [ 38.000000, 1.000000 ], "NTOPNG_INSTANCE_NAME": "SURF-TRAFFIC", "INTERFACE": "eth1", "DNS_QUERY": "dr._dns-sd._udp.�[\/", "PASS_VERDICT": true }]}

[lucaderi]

Sure but not those inside the pcap. Please try again

[lucaderi]

Closed for inactivity