Indexer Failure: Can't get text on a START_OBJECT

[erasedhammer]

1. Describe your incident:
I have recently (in the past couple of weeks) noticed a large number of index failures.
They are all identical and I have never had this issue before.

2. Describe your environment:
Debian 11 - Graylog 5.0.5 (Eclipse Adoptium 17.0.6 on Linux 5.10.0-21-amd64)
Opensearch 2.7

I am having trouble deciphering the indexer failure log - some googling results in nothing similar.

Timestamp	Index	Letter ID	Error message
an hour ago	dnsdhcp_0	546c96c0-f125-11ed-b5e2-3cecefdadccf	OpenSearchException[OpenSearch exception [type=mapper_parsing_exception, reason=failed to parse field [dns_rewrite_result] of type [keyword] in document with id '546c96c0-f125-11ed-b5e2-3cecefdadccf'. Preview of field's value: '{Exchange=smtp.mydomain.com, Preference=1}']]; nested: OpenSearchException[OpenSearch exception [type=illegal_state_exception, reason=Can't get text on a START_OBJECT at 1:105]];
an hour ago	dnsdhcp_0	54651cbe-f125-11ed-b5e2-3cecefdadccf	OpenSearchException[OpenSearch exception [type=mapper_parsing_exception, reason=failed to parse field [dns_rewrite_result] of type [keyword] in document with id '54651cbe-f125-11ed-b5e2-3cecefdadccf'. Preview of field's value: '{Exchange=smtp.mydomain.com, Preference=1}']]; nested: OpenSearchException[OpenSearch exception [type=illegal_state_exception, reason=Can't get text on a START_OBJECT at 1:105]];
an hour ago	dnsdhcp_0	546bac60-f125-11ed-b5e2-3cecefdadccf	OpenSearchException[OpenSearch exception [type=mapper_parsing_exception, reason=failed to parse field [dns_rewrite_result] of type [keyword] in document with id '546bac60-f125-11ed-b5e2-3cecefdadccf'. Preview of field's value: '{Exchange=smtp.mydomain.com, Preference=1}']]; nested: OpenSearchException[OpenSearch exception [type=illegal_state_exception, reason=Can't get text on a START_OBJECT at 1:104]];
an hour ago	dnsdhcp_0	54706750-f125-11ed-b5e2-3cecefdadccf	OpenSearchException[OpenSearch exception [type=mapper_parsing_exception, reason=failed to parse field [dns_rewrite_result] of type [keyword] in document with id '54706750-f125-11ed-b5e2-3cecefdadccf'. Preview of field's value: '{Exchange=smtp.mydomain.com, Preference=1}']]; nested: OpenSearchException[OpenSearch exception [type=illegal_state_exception, reason=Can't get text on a START_OBJECT at 1:104]];
an hour ago	dnsdhcp_0	546543c0-f125-11ed-b5e2-3cecefdadccf	OpenSearchException[OpenSearch exception [type=mapper_parsing_exception, reason=failed to parse field [dns_rewrite_result] of type [keyword] in document with id '546543c0-f125-11ed-b5e2-3cecefdadccf'. Preview of field's value: '{Exchange=smtp.mydomain.com, Preference=1}']]; nested: OpenSearchException[OpenSearch exception [type=illegal_state_exception, reason=Can't get text on a START_OBJECT at 1:105]];
an hour ago	dnsdhcp_0	546bd370-f125-11ed-b5e2-3cecefdadccf	OpenSearchException[OpenSearch exception [type=mapper_parsing_exception, reason=failed to parse field [dns_rewrite_result] of type [keyword] in document with id '546bd370-f125-11ed-b5e2-3cecefdadccf'. Preview of field's value: '{Exchange=smtp.mydomain.com, Preference=1}']]; nested: OpenSearchException[OpenSearch exception [type=illegal_state_exception, reason=Can't get text on a START_OBJECT at 1:104]];
an hour ago	dnsdhcp_0	546b1020-f125-11ed-b5e2-3cecefdadccf	OpenSearchException[OpenSearch exception [type=mapper_parsing_exception, reason=failed to parse field [dns_rewrite_result] of type [keyword] in document with id '546b1020-f125-11ed-b5e2-3cecefdadccf'. Preview of field's value: '{Exchange=smtp.mydomain.com, Preference=1}']]; nested: OpenSearchException[OpenSearch exception [type=illegal_state_exception, reason=Can't get text on a START_OBJECT at 1:105]];
an hour ago	dnsdhcp_0	546f7cf0-f125-11ed-b5e2-3cecefdadccf	OpenSearchException[OpenSearch exception [type=mapper_parsing_exception, reason=failed to parse field [dns_rewrite_result] of type [keyword] in document with id '546f7cf0-f125-11ed-b5e2-3cecefdadccf'. Preview of field's value: '{Exchange=smtp.mydomain.com, Preference=1}']]; nested: OpenSearchException[OpenSearch exception [type=illegal_state_exception, reason=Can't get text on a START_OBJECT at 1:104]];
2 hours ago	dnsdhcp_0	ce8eab10-f11f-11ed-b5e2-3cecefdadccf	OpenSearchException[OpenSearch exception [type=mapper_parsing_exception, reason=failed to parse field [dns_rewrite_result] of type [keyword] in document with id 'ce8eab10-f11f-11ed-b5e2-3cecefdadccf'. Preview of field's value: '{Exchange=smtp.mydomain.com, Preference=1}']]; nested: OpenSearchException[OpenSearch exception [type=illegal_state_exception, reason=Can't get text on a START_OBJECT at 1:105]];
2 hours ago	dnsdhcp_0	ce8e8400-f11f-11ed-b5e2-3cecefdadccf	OpenSearchException[OpenSearch exception [type=mapper_parsing_exception, reason=failed to parse field [dns_rewrite_result] of type [keyword] in document with id 'ce8e8400-f11f-11ed-b5e2-3cecefdadccf'. Preview of field's value: '{Exchange=smtp.mydomain.com, Preference=1}']]; nested: OpenSearchException[OpenSearch exception [type=illegal_state_exception, reason=Can't get text on a START_OBJECT at 1:104]];

Offending Index:

 1 indices with a total of 10,994 messages under management, current write-active index is dnsdhcp_0.
 Elasticsearch cluster is green. Shards: 37 active, 0 initializing, 0 relocating, 0 unassigned

For reference, I have a single input for my plain text udp syslog. I have two streams (one for dhcp, and one for dns) that drop logs into the dnsdhcp index. I have a single pipeline connected to the stream, and it is successfully pulling fields out (0 errors/s)

I do not know what the “Exchange” or “Preference” fields are; they are nothing I have configured.
The smtp domain is my internal email domain which all my alerts go to, but alerts are working just fine.
I also tried searching those values over the past day, no results (as expected?).
When these errors started, I had not modified the configuration of graylog in a couple of days.

Can someone help me understand the errors, and how to triage this problem?

[gsmith]

Hey @erasedhammer

This message here…

reason=failed to parse field [dns_rewrite_result] of type [keyword] in document with id

EDIT: I see you do have a piepline. How is your pipeline on that input where this field dns_rewrite_result confgiured?

So it seams Opnsearch is unable to parse that field.

@erasedhammer

I had not modified the configuration of graylog in a couple of days.

Were there new devices sending logs to Graylog on those inputs?
How long has this been happing? Was it more then a couple days?

Have you tried to rotate the index set manually? Sometimes the field like dns_rewrite_result might need to be a string instead of a keyword. A rotation may clear that up.

[erasedhammer]

During that time, yes logs of various inputs were starting up.
The logs processed by the pipeline are JSON format.
Checking over the pipeline rules, I did notice the dns_rewrite_result field is pulling from a section of the json that sometimes exists, sometimes is empty, and sometimes contains data.

Here is the pipeline rule:

rule "DNSJSONFieldExtractor"
when
  true
then
  let x = parse_json(to_string($message.message));
  let new_fields = select_jsonpath(x,
            { dns_query_time: "$['T']",
              dns_query_header: "$['QH']"
              dns_query_type: "$['QT']"
              dns_query_class: "$['QC']"
              dns_cp: "$['CP']"
              dns_upstream: "['Upstream']"
              dns_raw_answer: "['Answer']"
              dns_clientip: "['IP']"
              dns_result_ip: "['Result']['IPList']"
              dns_result_reason: "['Result']['Reason']"
              dns_result_response_time: "['Elapsed']"
              dns_result_blocked: "['Result']['IsFiltered']"
              dns_rewrite_result: "['Result']['DNSRewriteResult']['Response'][*]"
              dns_result_rule_text: "['Result']['Rules'][*]['Text']"
              dns_result_rule_filterlistid: "['Result']['Rules'][*]['FilterListID']"
              dns_cached: "['Cached']"
            });
  set_fields(new_fields);
end

The data is always a string as far as I can tell in historical logs.
An Example of the JSON log:

{"T":"2023-05-12T22:11:11.057819585-04:00","QH":"2.3.168.192.in-addr.arpa","QT":"PTR","QC":"IN","CP":"","Answer":"umCBgAABAAEAAAAAATIBMwIxMAIxMAdpbi1hZGRyBGFycGEAAAwAAcAMAAwAAQAAAApAfgNjbXELNXGlYeNdcmfD","IP":"192.168.20.3","Result":{"DNSRewriteResult":{"Response":{"12":["nms.mydomain.com."]}},"Rules":[{"Text":"||2.3.168.192.in-addr.arpa^$dnsrewrite=NOERROR;PTR;nms.mydomain.com."}],"Reason":11},"Elapsed":177291}

I just checked too, there is no logs for the search “dns_rewrite_result:smtp.mydomain.com.”
But “dns_rewrite_result:nms.mydomain.com.” does come back with results.
Last 10 days for both

Do I need to change the pipeline rule?

[gsmith]

Hey @erasedhammer

@erasedhammer

The data is always a string as far as I can tell in historical logs

Check your index mapping for dns_rewrite_result
Example:

curl -X GET "localhost:9200/dnsdhcp/_mapping?pretty"

@gsmith

Have you tried to rotate the index set manually?

EDIT: I forgot to ask, What are you using for a log shipper for DNS/DHCP? Depending on the setup you could use GELF/UDP input.

[erasedhammer]

For the index:

{
  "dnsdhcp_0" : {
    "mappings" : {
      "dynamic_templates" : [
        {
          "internal_fields" : {
            "match" : "gl2_*",
            "match_mapping_type" : "string",
            "mapping" : {
              "type" : "keyword"
            }
          }
        },
        {
          "store_generic" : {
            "match_mapping_type" : "string",
            "mapping" : {
              "type" : "keyword"
            }
          }
        }
      ],
      "properties" : {
        "COMMONMAC" : {
          "type" : "keyword"
        },
        "IP" : {
          "type" : "keyword"
        },
        "IPV4" : {
          "type" : "keyword"
        },
        "IPV4_reserved_ip" : {
          "type" : "boolean"
        },
        "IP_reserved_ip" : {
          "type" : "boolean"
        },
        "dhcp_action" : {
          "type" : "keyword"
        },
        "dhcp_clientHostname" : {
          "type" : "keyword"
        },
        "dhcp_clientIP" : {
          "type" : "keyword"
        },
        "dhcp_clientIP_city_name" : {
          "type" : "keyword"
        },
        "dhcp_clientIP_country_code" : {
          "type" : "keyword"
        },
        "dhcp_clientIP_geolocation" : {
          "type" : "keyword"
        },
        "dhcp_clientIP_reserved_ip" : {
          "type" : "boolean"
        },
        "dhcp_clientMAC" : {
          "type" : "keyword"
        },
        "dhcp_interface" : {
          "type" : "keyword"
        },
        "dhcp_srvAddr" : {
          "type" : "keyword"
        },
        "dhcp_srvAddr_reserved_ip" : {
          "type" : "boolean"
        },
        "dhcp_srvIP" : {
          "type" : "keyword"
        },
        "dhcp_srvIP_city_name" : {
          "type" : "keyword"
        },
        "dhcp_srvIP_country_code" : {
          "type" : "keyword"
        },
        "dhcp_srvIP_geolocation" : {
          "type" : "keyword"
        },
        "dhcp_toport" : {
          "type" : "keyword"
        },
        "dns_cached" : {
          "type" : "boolean"
        },
        "dns_clientip" : {
          "type" : "keyword"
        },
        "dns_clientip_reserved_ip" : {
          "type" : "boolean"
        },
        "dns_query_class" : {
          "type" : "keyword"
        },
        "dns_query_header" : {
          "type" : "keyword"
        },
        "dns_query_time" : {
          "type" : "date"
        },
        "dns_query_type" : {
          "type" : "keyword"
        },
        "dns_raw_answer" : {
          "type" : "keyword"
        },
        "dns_result_blocked" : {
          "type" : "boolean"
        },
        "dns_result_ip" : {
          "type" : "keyword"
        },
        "dns_result_reason" : {
          "type" : "long"
        },
        "dns_result_response_time" : {
          "type" : "long"
        },
        "dns_result_rule_filterlistid" : {
          "type" : "long"
        },
        "dns_result_rule_text" : {
          "type" : "keyword"
        },
        "dns_rewrite_result" : {
          "type" : "keyword"
        },
        "dns_upstream" : {
          "type" : "keyword"
        },
        "full_message" : {
          "type" : "text",
          "analyzer" : "standard"
        },
        "gl2_accounted_message_size" : {
          "type" : "long"
        },
        "gl2_message_id" : {
          "type" : "keyword"
        },
        "gl2_processing_timestamp" : {
          "type" : "date",
          "format" : "uuuu-MM-dd HH:mm:ss.SSS"
        },
        "gl2_receive_timestamp" : {
          "type" : "date",
          "format" : "uuuu-MM-dd HH:mm:ss.SSS"
        },
        "gl2_remote_ip" : {
          "type" : "keyword"
        },
        "gl2_remote_port" : {
          "type" : "long"
        },
        "gl2_source_input" : {
          "type" : "keyword"
        },
        "gl2_source_node" : {
          "type" : "keyword"
        },
        "message" : {
          "type" : "text",
          "analyzer" : "standard"
        },
        "source" : {
          "type" : "text",
          "analyzer" : "analyzer_keyword",
          "fielddata" : true
        },
        "source_reserved_ip" : {
          "type" : "boolean"
        },
        "streams" : {
          "type" : "keyword"
        },
        "timestamp" : {
          "type" : "date",
          "format" : "uuuu-MM-dd HH:mm:ss.SSS"
        }
      }
    }
  }
}

I just checked the original log. The DNS server does not support anything but writing its logs into a local file in JSON format, and I had to figure out the fields myself (no docs). I send out the logs with rsyslog.
This is the offending messages that doesn’t process right in the pipeline:

{"T":"2023-05-12T19:53:36.368616158-04:00","QH":"_http._tcp.apt.mydomain.com","QT":"SRV","QC":"IN","CP":"","Answer":"heuBgAABAAEAAAAABV9odHRwBF90Y3ADYXB0DGFwZXJ0dXJlY29ycANuZXQAACEAAcAMACEAAQAAAAoAHAAKADwMRgNhcHQMYXBlcnR1cmVjb3JwA25ldAA=","IP":"192.168.0.2","Result":{"DNSRewriteResult":{"Response":{"15":[{"Exchange":"smtp.mydomain.com","Preference":1}],"33":[{"Target":"apt.mydomain.com","Priority":10,"Weight":60,"Port":3142}]}},"Rules":[{"Text":"||_http._tcp.apt.mydomain.com^$dnsrewrite=NOERROR;SRV;10 60 3142 apt.mydomain.com"},{"Text":"||mydomain.com^$dnsrewrite=NOERROR;MX;1 smtp.mydomain.com"}],"Reason":11},"Elapsed":168398}
{"T":"2023-05-12T22:35:12.750925774-04:00","QH":"mt2p.vivox.com.mydomain.com","QT":"A","QC":"IN","CP":"","Answer":"+yiBgAABAAAAAAAABG10MnAFdml2b3gDY29tDGFwZXJ0dXJlY29ycANuZXQAAAEAAQ==","IP":"192.168.0.1","Result":{"DNSRewriteResult":{"Response":{"15":[{"Exchange":"smtp.mydomain.com","Preference":1}]}},"Rules":[{"Text":"||mydomain.com^$dnsrewrite=NOERROR;MX;1 smtp.mydomain.com"}],"Reason":11},"Elapsed":317863}

Normally, I don’t receive a lot of actual MX queries, mostly just A queries for the domain name itself.
I believe a recent change in the firewall (192.168.0.1) caused it to start doing actual MX queries.
When I built the pipeline rule, I didn’t have any example datasets for this JSON format.

For reference, I am using Adguard Home and wanted to process the logs in Graylog. While they don’t have remote log or journal log options for their server, they did at least dump their logs into a JSON format (more than I can say for a lot of programs out there).

I used the JSON extractor pipeline rule syntax from somewhere online, so I am not very familiar with its capability or if there is a better way (while still using pipeline rules).

How can I extract JSON objects and arrays that may or may not be present in the ingested logs? Do I have to write another rule for that particular format, or can I do it all in one rule?

I appreciate your help.

~ Im out for now - I’ll be back online tomorrow

[gsmith]

Hey @erasedhammer

@erasedhammer

How can I extract JSON objects and arrays that may or may not be present in the ingested logs?

That would be beyond my capabilities, But when some issues arise like another device sending log into INPUT and they all go to the same index set, easy way would build out the inputs for different devices that would go into their own index set. For example Firewall log go into input called "Firewall /w syslog/UDP”, then route them into index set called firewall logs. Think you get the point.
This will avoid mapping conflicts down the road. This will alos avoid errors called

 ElasticsearchException[Elasticsearch exception [type=illegal_argument_exception, reason=Limit of total fields [1000] has been exceeded]]

Unless you have a custom index templates, Elasticsearch/OpenSearch will dynamically map anything it can.

As for JSON pipeline you may want to try to flatten it.

Example from here.

Parsing nested json message in field with parent object in pipeline

Have you experimented with flatten_json? Here’s a source and example with something I did to bring in logs into my test system. rule "Random User Data Flatten Json Rule" // From sample data : https://randomuser.me/api/ // Api input path: * when true then let sJson = to_string($message.result); let sJson = regex_replace( pattern: "^\\[|\\]$", value: sJson, replacement: "" ); let rsJson = flatten_json(to_string(sJson), "flatten"); set_fields(to…

EDIT @erasedhammer i for got to metion , perhaps use a key value, something like this…

Issue with Key=Value Parser Pipeline for specific log-messages

Try to use this, I’ve added parameters to remove "{} from key and values. But, it’s not perfect, because of Country contains json. rule "key_value_parser" when has_field("Full_Response") then set_fields( fields: key_value( value: to_string($message.Full_Response), delimiters:",", kv_delimiters:":", trim_key_chars:"\"", trim_value_chars: "\"{}") ); end

[erasedhammer]

Thank you for your help.

I did not know about the to_map option for flattened JSONs, it saves me a lot of manual work.
Now I don’t have to query the JSON for each field, much more extractor-like!

The tweaks I made:

rule "AdguardJSONFieldExtractor"
when
  has_field("jsonmsg")
then
  let x = flatten_json(to_string($message.jsonmsg), "flatten");
  set_fields(to_map(x), "dns_");
end