Search code examples
elasticsearchlogstashelastic-stackfilebeat

LogStash Error: Can't get text on a START_OBJECT at 1:708


I am trying to configure SpringBoot <> FileBeat <> LogStash <> ElasticSearch <> Kibana.

But I am getting error at LogStash, here is my code snippets:

filebeat.yml:

filebeat:
  inputs:
    - type: log
      paths:
        - /Users/Smit/Downloads/chrome/observability/spring_app_log_file.log
      
output:
  logstash:
    hosts: ["localhost:5044"]

logstash.config:

input {
  beats {
        port => "5044"
    }
}
 
filter {
  #If log line contains tab character followed by 'at' then we will tag that entry as stacktrace
  if [message] =~ "\tat" {
    grok {
      match => ["message", "^(\tat)"]
      add_tag => ["stacktrace"]
    }
  }
 
}
 
output {
   
  stdout {
    codec => rubydebug
  }
 
  # Sending properly parsed log events to elasticsearch
  elasticsearch {
    hosts => ["localhost:9200"]
  }
}

Error Related in info: Log:

{
      "@version" => "1",
           "ecs" => {
        "version" => "1.5.0"
    },
         "agent" => {
            "hostname" => "Smits-MacBook-Pro.local",
                "type" => "filebeat",
        "ephemeral_id" => "76f5b858-bc2d-4f13-bdb1-98f4cad7ce28",
             "version" => "7.8.0",
                  "id" => "864be1a9-e233-4d41-8624-cf94e916a0b7",
                "name" => "Smits-MacBook-Pro.local"
    },
    "@timestamp" => 2020-06-27T17:30:53.807Z,
          "tags" => [
        [0] "beats_input_codec_plain_applied"
    ],
           "log" => {
        "offset" => 8939,
          "file" => {
            "path" => "/Users/Smit/Downloads/chrome/observability/spring_app_log_file.log"
        }
    },
         "input" => {
        "type" => "log"
    },
       "message" => "2020-06-28 01:30:50.017  INFO 41266 --- [http-nio-8080-exec-6] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.service.GreetingService with args [godknows]",
          "host" => {
        "name" => "Smits-MacBook-Pro.local"
    }
}

Error:

[2020-06-28T01:30:54,983][WARN ][logstash.outputs.elasticsearch][main][e355ceb00d3e298d5bee1962185a3aac2c9bdd4e945037e76fdcce0f773027e6] Could not index event to Elasticsearch. {:status=>400, :action=>["index", {:_id=>nil, :_index=>"logstash", :routing=>nil, :_type=>"_doc"}, #<LogStash::Event:0x2103d045>], :response=>{"index"=>{"_index"=>"logstash-2020.06.27-000001", "_type"=>"_doc", "_id"=>"znzV9nIBBsHFC7FTBLmF", "status"=>400, "error"=>{"type"=>"mapper_parsing_exception", "reason"=>"failed to parse field [host] of type [text] in document with id 'znzV9nIBBsHFC7FTBLmF'. Preview of field's value: '{name=Smits-MacBook-Pro.local}'", "caused_by"=>{"type"=>"illegal_state_exception", "reason"=>"Can't get text on a START_OBJECT at 1:708"}}}}}

Sample Data:

2020-06-28 00:46:55.616  INFO 39115 --- [SpringContextShutdownHook] o.s.s.concurrent.ThreadPoolTaskExecutor  : Shutting down ExecutorService 'applicationTaskExecutor'
2020-06-28 00:48:28.929  INFO 40835 --- [main] c.e.o.ObservabilityApplication           : Starting ObservabilityApplication on Smits-MacBook-Pro.local with PID 40835 (/Users/Smit/Downloads/chrome/observability/target/classes started by Smit in /Users/Smit/Downloads/chrome/observability)
2020-06-28 00:48:28.980  INFO 40835 --- [main] c.e.o.ObservabilityApplication           : No active profile set, falling back to default profiles: default
2020-06-28 00:48:52.142  INFO 40835 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2020-06-28 00:48:52.360  INFO 40835 --- [main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2020-06-28 00:48:52.362  INFO 40835 --- [main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.36]
2020-06-28 00:48:54.063  INFO 40835 --- [main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2020-06-28 00:48:54.065  INFO 40835 --- [main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 24049 ms
2020-06-28 00:49:00.008  INFO 40835 --- [main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2020-06-28 00:49:04.347  INFO 40835 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2020-06-28 00:49:04.666  INFO 40835 --- [main] c.e.o.ObservabilityApplication           : Started ObservabilityApplication in 47.356 seconds (JVM running for 62.67)
2020-06-28 00:55:49.970  INFO 40835 --- [http-nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2020-06-28 00:55:49.971  INFO 40835 --- [http-nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2020-06-28 00:55:49.981  INFO 40835 --- [http-nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 10 ms
2020-06-28 00:55:50.017  INFO 40835 --- [http-nio-8080-exec-1] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.controller.HomeController with args [pubg]
2020-06-28 00:55:50.032  INFO 40835 --- [http-nio-8080-exec-1] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.service.GreetingService with args [pubg]
2020-06-28 00:55:50.039  INFO 40835 --- [http-nio-8080-exec-1] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello pubg
2020-06-28 00:55:50.039  INFO 40835 --- [http-nio-8080-exec-1] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello pubg
2020-06-28 01:25:38.444  INFO 40835 --- [SpringContextShutdownHook] o.s.s.concurrent.ThreadPoolTaskExecutor  : Shutting down ExecutorService 'applicationTaskExecutor'
2020-06-28 01:25:40.440  INFO 41266 --- [main] c.e.o.ObservabilityApplication           : Starting ObservabilityApplication on Smits-MacBook-Pro.local with PID 41266 (/Users/Smit/Downloads/chrome/observability/target/classes started by Smit in /Users/Smit/Downloads/chrome/observability)
2020-06-28 01:25:40.443  INFO 41266 --- [main] c.e.o.ObservabilityApplication           : No active profile set, falling back to default profiles: default
2020-06-28 01:25:41.820  INFO 41266 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2020-06-28 01:25:41.833  INFO 41266 --- [main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2020-06-28 01:25:41.833  INFO 41266 --- [main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.36]
2020-06-28 01:25:41.917  INFO 41266 --- [main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2020-06-28 01:25:41.917  INFO 41266 --- [main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1350 ms
2020-06-28 01:25:42.220  INFO 41266 --- [main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2020-06-28 01:25:42.416  INFO 41266 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2020-06-28 01:25:42.431  INFO 41266 --- [main] c.e.o.ObservabilityApplication           : Started ObservabilityApplication in 2.528 seconds (JVM running for 2.938)
2020-06-28 01:30:45.161  INFO 41266 --- [http-nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2020-06-28 01:30:45.162  INFO 41266 --- [http-nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2020-06-28 01:30:45.173  INFO 41266 --- [http-nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 11 ms
2020-06-28 01:30:45.211  INFO 41266 --- [http-nio-8080-exec-1] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.controller.HomeController with args [pubg]
2020-06-28 01:30:45.224  INFO 41266 --- [http-nio-8080-exec-1] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.service.GreetingService with args [pubg]
2020-06-28 01:30:45.233  INFO 41266 --- [http-nio-8080-exec-1] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello pubg
2020-06-28 01:30:45.234  INFO 41266 --- [http-nio-8080-exec-1] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello pubg
2020-06-28 01:30:45.333  INFO 41266 --- [http-nio-8080-exec-2] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.controller.HomeController with args [pubg]
2020-06-28 01:30:45.333  INFO 41266 --- [http-nio-8080-exec-2] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.service.GreetingService with args [pubg]
2020-06-28 01:30:45.333  INFO 41266 --- [http-nio-8080-exec-2] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello pubg
2020-06-28 01:30:45.333  INFO 41266 --- [http-nio-8080-exec-2] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello pubg
2020-06-28 01:30:45.511  INFO 41266 --- [http-nio-8080-exec-3] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.controller.HomeController with args [pubg]
2020-06-28 01:30:45.511  INFO 41266 --- [http-nio-8080-exec-3] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.service.GreetingService with args [pubg]
2020-06-28 01:30:45.511  INFO 41266 --- [http-nio-8080-exec-3] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello pubg
2020-06-28 01:30:45.511  INFO 41266 --- [http-nio-8080-exec-3] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello pubg
2020-06-28 01:30:45.686  INFO 41266 --- [http-nio-8080-exec-4] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.controller.HomeController with args [pubg]
2020-06-28 01:30:45.686  INFO 41266 --- [http-nio-8080-exec-4] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.service.GreetingService with args [pubg]
2020-06-28 01:30:45.686  INFO 41266 --- [http-nio-8080-exec-4] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello pubg
2020-06-28 01:30:45.686  INFO 41266 --- [http-nio-8080-exec-4] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello pubg
2020-06-28 01:30:45.863  INFO 41266 --- [http-nio-8080-exec-5] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.controller.HomeController with args [pubg]
2020-06-28 01:30:45.863  INFO 41266 --- [http-nio-8080-exec-5] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.service.GreetingService with args [pubg]
2020-06-28 01:30:45.863  INFO 41266 --- [http-nio-8080-exec-5] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello pubg
2020-06-28 01:30:45.863  INFO 41266 --- [http-nio-8080-exec-5] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello pubg
2020-06-28 01:30:50.017  INFO 41266 --- [http-nio-8080-exec-6] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.controller.HomeController with args [godknows]
2020-06-28 01:30:50.017  INFO 41266 --- [http-nio-8080-exec-6] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.service.GreetingService with args [godknows]
2020-06-28 01:30:50.017  INFO 41266 --- [http-nio-8080-exec-6] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello godknows
2020-06-28 01:30:50.018  INFO 41266 --- [http-nio-8080-exec-6] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello godknows
2020-06-28 01:30:51.665  INFO 41266 --- [http-nio-8080-exec-7] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.controller.HomeController with args [tms]
2020-06-28 01:30:51.665  INFO 41266 --- [http-nio-8080-exec-7] c.e.observability.aop.LoggingAdvice      : Method Invoked getGreeting in class class com.example.observability.service.GreetingService with args [tms]
2020-06-28 01:30:51.666  INFO 41266 --- [http-nio-8080-exec-7] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello tms
2020-06-28 01:30:51.666  INFO 41266 --- [http-nio-8080-exec-7] c.e.observability.aop.LoggingAdvice      : Method getGreeting return Hello tms

Solution

  • mutate {
        rename => ["host", "hostname"]
        convert => {"hostname" => "string"} 
    }
    

    Add this to your filter plugin to avoid the issue.

    Such that, logstash.conf will look like:

    input {
      beats {
            port => "5044"
        }
    }
    
     
    filter {
      #If log line contains tab character followed by 'at' then we will tag that entry as stacktrace
      if [message] =~ "\tat" {
        grok {
          match => ["message", "^(\tat)"]
          add_tag => ["stacktrace"]
        }
      }
      mutate {
        rename => ["host", "hostname"]
        convert => {"hostname" => "string"} 
      }
     
    }
     
    output {
       
      stdout {
        codec => rubydebug
      }
     
      # Sending properly parsed log events to elasticsearch
      elasticsearch {
        hosts => ["localhost:9200"]
      }
    }