Pattern error - but which pattern? (logstash 2.4.0) (SOLVED)

Elastic Stack Logstash
1

Greetings.

I am trying (and failing) in getting custom patterns to work with logstash 2.4.0. Here is the relevant part of the conf file:

#some parsing happens above...
    grok {
       patterns_dir => ["/config_dir/patterns"]
       match => [ "syslog_message", "%{QID:qid}:" ]
    }

(Edit: full config is at the end) - the patterns directory contains only the file sendmail.grok:

#########
QID a

Running this I get (reformatted exception):

{:exception=>"Grok::PatternError",
 :backtrace=>["/opt/logstash/vendor/bundle/jruby/1.9/gems/jls-grok-0.11.3/lib/grok-pure.rb:123:in `compile'",
              "org/jruby/RubyKernel.java:1479:in `loop'",
              "/opt/logstash/vendor/bundle/jruby/1.9/gems/jls-grok-0.11.3/lib/grok-pure.rb:93:in `compile'",
              "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-filter-grok-2.0.5/lib/logstash/filters/grok.rb:264:in `register'",
              "org/jruby/RubyArray.java:1613:in `each'",
              "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-filter-grok-2.0.5/lib/logstash/filters/grok.rb:259:in `register'",
              "org/jruby/RubyHash.java:1342:in `each'",
              "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-filter-grok-2.0.5/lib/logstash/filters/grok.rb:255:in `register'",
              "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.4.0-java/lib/logstash/pipeline.rb:182:in `start_workers'",
              "org/jruby/RubyArray.java:1613:in `each'",
              "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.4.0-java/lib/logstash/pipeline.rb:182:in `start_workers'",
              "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.4.0-java/lib/logstash/pipeline.rb:136:in `run'",
              "/opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-2.4.0-java/lib/logstash/agent.rb:491:in `start_pipeline'"],
 :level=>:error,
 :file=>"logstash/agent.rb",
 :line=>"493",
 :method=>"start_pipeline"
}

This exeption is invariant with the contents of the patterns/sendmail.grok. It is a PatternError, but does not tell me where the error happens. If , however, I comment the match line out, everything is just fine (sample otput below):

{
                 "message" => "Oct 25 13:18:27 alpha opendkim[1160]: u9PBIMwu011394: authsmtp79.register.it [195.110.122.164] not internal",
                "@version" => "1",
              "@timestamp" => "2016-10-25T11:25:35.072Z",
                    "path" => "/log/maillog",
                    "host" => "93fe70f98023",
    "syslog_severity_code" => 5,
    "syslog_facility_code" => 1,
         "syslog_facility" => "user-level",
         "syslog_severity" => "notice",
                    "tags" => [
        [0] "syslog_message_unparsed",
        [1] "syslog_relay"
    ],
        "syslog_timestamp" => "Oct 25 13:18:27",
             "syslog_host" => "alpha",
                 "program" => "opendkim",
                     "pid" => "1160",
          "syslog_message" => "u9PBIMwu011394: authsmtp79.register.it [195.110.122.164] not internal",
         "syslog_fullhost" => "alpha"
}

Ideas?

TIA,
alf

===== Full configuration:

input {
    file {
        path => "/log/maillog"
    }
}

filter {
  syslog_pri {
  }
  mutate {
    add_tag => [ "syslog_parsefailure", "syslog_message_unparsed" ]
  }

  grok {
     match => [ "message", "%{CISCOTIMESTAMP:syslog_timestamp} %{IPORHOST:syslog_host} %{SYSLOGPROG}: %{GREEDYDATA:syslog_message}" ]
    add_field => { "syslog_fullhost" => "%{syslog_host}" }
    add_tag => [ "syslog_relay" ]
    remove_tag => [ "syslog_parsefailure" ]
    tag_on_failure => [ ]
  }
  
  if [program] == "sendmail" {
     mutate {
      add_tag => [ "sendmail_log" ]
     }
     grok {
       patterns_dir => ["/config_dir/patterns"]
       match => [ "syslog_message", "%{QID:qid}:" ]
     }
 }

}

output {
  stdout { codec => rubydebug }
}
2

OK, so it appears something was wrong with the environment hosting my docker container (a CentOS7 VM). I rebuilt the same exact environment on an FC24 (non-VM) machine (newer docker, same containers, etc.) and the exception just disappeared.

Lessons learned:

  • The dream of liberating oneself from environment dependencies through containerisation is, on the face of it, a delusion. Ghost bugs/execptions can - and do - appear due to the container host environment, without telling you much about it, and being therefore more elusive than ever.
  • Logstash (well gork's) exception logging is less than ideal. Whatever was causing the original exception (if I had to bet, I'd bet file system and/or SELinux problems, but I really still don't know) was most emphatically not a pattern problem

Thanks to all who bothered to (even) read wasted time on this.

3

Alessandro,
I did read your message and I was in fact reading the grok code to see if it could be breaking on the ######### opening line of your pattern file - it should not and it does not.

What you are trying to do is very common and has been used successfully many times for some years. What you posted seemed to have no flaws. Very few people here will have the confidence to state it all looks OK and you **must** be doing something else wrong. Maybe people here expect that before posting here there has been some troubleshooting steps done already, e.g. can I reproduce this on a different machine; on bare metal etc.

4

I see that my closing line may have been misinterpreted. I was not complaining about lack of interest form the forum. I easily guessed that that was due to puzzlement as all my googling and experimenting appeared to confirm that the setup was not particularly strange.

In the end, I was just half embarrassed and half dispirited by my findings (which cost me 2 days) - hence my message closing. Actually, I am sorry that I wasted your time in chasing this particular red herring of a failure, though I still feel that the failure mode should be less terse (assuming that's possible indeed: I tried -vvvvv and --debug without being able to have hints of the failure reason. If I had more than 0 ruby under my belt I'd have attempted some debugging)