Timeout executing grok '%{PHPRUNTIMEERROR}' against field 'message' with valu

Hi,

I am having a timeout for my grok filter. The logs are delivered from app1 server to logstash server via rsyslog forwarding, once the timeouts start the logstash server does not recover for several hours and is unavailable from 3 am to 6 am et. If i restart the logstash it does recover.
The filter I created for these is being ignored, but it works fine in grok filter debugging. I have enclosed the filters and config files. If you need anymore details please let me know.

Erin

**logstash version **
Installed Packages
**logstash.noarch 1:6.5.1-1 installed **
Available Packages

cat /etc/system-release
CentOS release 6.7 (Final

errors from app1 server
May 13 03:02:21 app1 tripadvisor-hotel-mapper[15557]: Hotel7230175 using /location_mapper/51.340000,0.719900?key=-mapper&category=hotels Connection Failure
May 13 03:02:21 app1 tripadvisor-hotel-mapper[15557]: Hotel7230205 using /location_mapper/51.869900,-0.409900?key=-mapper&category=hotels Connection Failure

timeout errors from logstash server
May 13 06:49:25 log1 logstash: [2019-05-13T06:49:25,068][WARN ][logstash.filters.grok ] Timeout executing grok '%{PHPRUNTIMEERROR}' against field 'message' with value 'Hotel6993615 using /location_mapper/27.710000,85.319900?key=-mapper&category=hotels Connection Failure'!
May 13 06:49:55 log1 logstash: [2019-05-13T06:49:55,121][WARN ][logstash.filters.grok ] Timeout executing grok '%{PHPRUNTIMEERROR_OLD}' against field 'message' with value 'Hotel6993615 using /location_mapper/27.710000,85.319900?key=-mapper&category=hotels Connection Failure'!
May 13 06:50:25 log1 logstash: [2019-05-13T06:50:25,151][WARN ][logstash.filters.grok ] Timeout executing grok '%{PHPRUNTIMEERROR}' against field 'message' with value 'Hotel6994725 using /location_mapper/38.840000,0.100000?key=-mapper&category=hotels Connection Failure'!

filter for errors
[root@log1 conf.d]# cat 30-filter-php.conf

Rules to filter/process all php application rules (local5)

filter {

if [facility_label] == "local5" {

if "newCCNumber=" in [message] {
  if "newCCNumber=XXXXXXXXXXXXXXXX" not in [message] {
    mutate {
      gsub => [
        "message", "newCCNumber=\d{16}", "newCCNumber=XXXXXXXXXXXXXXXX"
      ]
    }
  }
}

# Newest pattern for PHP Runtime Errors

grok {
patterns_dir => "/etc/logstash/patterns.d"
match => { "message" => "%{PHPHOTELSCONNFAILURE}" }
add_tag => ["phpconnectionerror"]
}
if "_grokparsefailure" in [tags] {

  grok {
    patterns_dir => "/etc/logstash/patterns.d"
    match => { "message" => "%{PHPQUERYERROR}" }
    add_tag => ["queryfailure"]
    remove_tag => ["_grokparsefailure"]
  }

  if "_grokparsefailure" in [tags] {

    # Check for ARI msg matching for SA-7819
    grok {
      patterns_dir => "/etc/logstash/patterns.d"
      match => { "message" => "%{PHPARIMSG}" }
      add_tag => ["ari-msg"]
      remove_tag => ["_grokparsefailure"]
    }

    if "_grokparsefailure" in [tags] {

      # Check for ITO worker (ITO) for SA-7158
      grok {
        patterns_dir => "/etc/logstash/patterns.d"
        match => { "message" => "%{PHPITOWORKER}" }
        add_tag => ["ito-worker"]
        remove_tag => ["_grokparsefailure"]
      }

      if "_grokparsefailure" in [tags] {

        # Check for old deprecated pattern
        grok {
          patterns_dir => "/etc/logstash/patterns.d"
          match => { "message" => "%{PHPQUERYERROR_OLD}" }
          add_tag => ["queryfailure"]
          remove_tag => ["_grokparsefailure"]
       }

        if "_grokparsefailure" in [tags] {

          grok {
            patterns_dir => "/etc/logstash/patterns.d"
            match => { "message" => "%{PHPRUNTIMEERROR}" }
            add_tag => ["runtimeerror"]
            remove_tag => ["_grokparsefailure"]
          }

          if "_grokparsefailure" in [tags] {

            grok {
              patterns_dir => "/etc/logstash/patterns.d"
              match => { "message" => "%{PHPRUNTIMEERROR_OLD}" }
              add_tag => ["runtimeerror"]
              remove_tag => ["_grokparsefailure"]
            }

            if "_grokparsefailure" in [tags] {

              # Searches for JS Errors
              grok {
                patterns_dir => "/etc/logstash/patterns.d"
                match => { "message" => "%{JSERROR}" }
                add_tag => ["jserror"]
                remove_tag => ["_grokparsefailure"]

                }
            }              
          }
        }
      }
    }
  }
}

}
}

grok filters on logstash server
[root@log1 patterns.d]# cat phperrors.grok

#New Hotel connection failure pattern
PHPHOTELSCONNFAILURE %{SYSLOGTIMESTAMP:[@metadata][timestamp]} %{NOTSPACE:[event][app]} %{NOTSPACE:[event][program]}[%{INT:[event][pid]}]: %{NOTSPACE:[venu][name]} using %{URIPATH:[@metadata][path]}%{URIPARAM:[@metadata][params]} %{GREEDYDATA:[event][result]}

Old Deprecated Patterns (we'll remove them later)

PHPQUERYERROR_OLD %{IPORHOST:host} %{INT:errornum} %{UNIXPATH:filepath} %{INT:line} [%{DATA:request}] [%{DATA:query}] %{GREEDYDATA:queryFailure}
PHPRUNTIMEERROR_OLD %{IPORHOST:client} %{UNIXPATH:filepath} %{INT:line} [%{DATA:request}] %{IPORHOST:host} [%{DATA:memberhash}] %{INT:errornum} %{GREEDYDATA:phpError}

New Patterns

PHPQUERYERROR %{IPORHOST:client} %{INT:errornum} %{UNIXPATH:filepath} %{INT:line} [%{DATA:request}] [%{DATA:memberhash}] [%{DATA:query}] %{GREEDYDATA:queryFailure}
PHPRUNTIMEERROR %{IPORHOST:client} %{UNIXPATH:filepath} %{INT:line} [%{DATA:request}] [%{DATA:memberhash}] %{INT:errornum} %{GREEDYDATA:phpError}

ARI Message log SA-7819

Added for SA-8058

PHPARIMSG %{WORD:ari},%{INT:channelManagerId:int},%{INT:hotelUniqueId:int},%{TIMESTAMP_ISO8601:receivedAt},%{WORD:messageType},%{WORD:processingStrategy},%{INT:elementCount:int},%{INT:totalDaysAffected:int}

ITO Worker Logs SA-7158

PHPITOWORKER [%{TIMESTAMP_ISO8601:timestamp}] [%{GREEDYDATA:queue}] %{INT:status} [%{GREEDYDATA:message}]

UNIXPATH is problematic. Do not use it.

Ok Badger, but what about it just ignoring my first filter and using the runtime ones?

It's not ignoring it, your pattern just does not match.

input { generator { count => 1 lines => [ 'May 13 03:02:21 app1 tripadvisor-hotel-mapper[15557]: Hotel7230175 using /location_mapper/51.340000,0.719900?key=-mapper&category=hotels Connection Failure' ] } }
filter {
    grok {
        pattern_definitions => { "PHPHOTELSCONNFAILURE" => "%{SYSLOGTIMESTAMP:[@metadata][timestamp]} %{NOTSPACE:[event][app]} %{NOTSPACE:[event][program]}[%{INT:[event][pid]}]: %{NOTSPACE:[venu][name]} using %{URIPATH:[@metadata][path]}%{URIPARAM:[@metadata][params]} %{GREEDYDATA:[event][result]}" }
        match => { "message" => "%{PHPHOTELSCONNFAILURE}" }
        add_tag => ["phpconnectionerror"]
    }
}
output { stdout { codec => rubydebug { metadata => false } } }

gets me a _grokparsefailure tag.

I would suggest having two windows open. In one, edit the configuration file. In the other run a configuration like the above with the -r option to logstash. Except start with the minimal grok pattern

pattern_definitions => { "PHPHOTELSCONNFAILURE" => "%{SYSLOGTIMESTAMP:[@metadata][timestamp]}" }

If that matches, add the next field you are trying to consume to your pattern and write out the configuration. logstash will notice the file has changed, re-read it, and run the generator input against the new filter. When you find the field you added does not match, change it so that it does....

Thanks Ill try that

Well I can't get any of that to work correctly. The debuggers i have put the grok filter in give me no errors. I have tried running the config you gave with /usr/share/logstash/bin/logstash -r -f /etc/logstash/conf.d/logstash.conf

Can I swap the UNIXPATH with PATH? is that less troublesome?

No. PATH is even worse than UNIXPATH since it is an alternation of UNIXPATH with WINPATH. Depending on your data NOTSPACE might work.

Ok ill try notspace.

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.