Nginx logs from stdout coming to error pipeline instead of access pipeline

edit: read below for update to initial question

I'm getting Provided Grok expressions do not match field value even though _simulate works with exact same string.

Error message:

"message": "172.18.0.2 - - [12/Aug/2019:01:20:27 +0000] \"GET /censored HTTP/1.1\" 200 457049 \"http://censored.com/censored\" \"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1)\"",
"error": {
  "message": "Provided Grok expressions do not match field value: [172.18.0.2 - - [12/Aug/2019:01:20:27 +0000] \\\"GET /censored HTTP/1.1\\\" 200 457049 \\\"http://censored.com/censored\\\" \\\"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1)\\\"]"
},

The pipeline is standard nginx filebeat

$ curl -XGET -u elastic:censored 'http://127.0.0.1:9200/_ingest/pipeline/filebeat-7.3.0-nginx-access-default?pretty'
{
  "filebeat-7.3.0-nginx-access-default" : {
    "description" : "Pipeline for parsing Nginx access logs. Requires the geoip and user_agent plugins.",
    "processors" : [
      {
        "grok" : {
          "field" : "message",
          "patterns" : [
            "\"?(?:%{IP_LIST:nginx.access.remote_ip_list}|%{DATA:source.address}) - %{DATA:user.name} \\[%{HTTPDATE:nginx.access.time}\\] \"%{DATA:nginx.access.info}\" %{NUMBER:http.response.status_code:long} %{NUMBER:http.response.body.bytes:long} \"%{DATA:http.request.referrer}\" \"%{DATA:user_agent.original}\""
          ],
          "pattern_definitions" : {
            "IP_LIST" : "%{IP}(\"?,?\\s*%{IP})*"
          },
          "ignore_missing" : true
        }
      },
      .....

But it works fine if I simulate such message:

$ cat data.json
{"docs" : [{ "_source": {"message": "172.18.0.2 - - [12/Aug/2019:01:20:27 +0000] \"GET /censored HTTP/1.1\" 200 457049 \"http://censored.com/censored\" \"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1)\""} }]}
$ curl -XPOST -u elastic:censored -d '@data.json' 'http://127.0.0.1:9200/_ingest/pipeline/filebeat-7.3.0-nginx-access-default/_simulate?pretty' --header "Content-Type:application/json"
{
  "docs" : [
    {
      "doc" : {
        "_index" : "_index",
        ===== correctly parsed document below =====

It collects logs from docker:

filebeat.autodiscover:
  providers:
    - type: docker
      hints.enabled: true

processors:
  - add_cloud_metadata: ~
  - add_docker_metadata: ~
  - add_locale:
      format: offset
  - add_host_metadata:
      netinfo.enabled: true

output.elasticsearch:
  hosts: ['elasticsearch:9200']
  protocol: "http"
  username: elastic
  password: censored

What I might be missing?

Ok I found that for some reason logs are processing with nginx error pipeline even though they are coming from stdout:

{
  "_index": "filebeat-7.3.0-2019.08.12-000001",
  "_type": "_doc",
  "_id": "VimPg2wBx9EL3Owdgsyu",
  "_version": 1,
  "_score": null,
  "_source": {
    "container": {
      "image": {
        "name": "vhost"
      },
      "name": "censored_web_censord_1",
      "id": "fdb081668feea07061f6b2acd7e840164c6020e158257afce9472dab9f94339b",
      "labels": {
        "co_elastic_logs/module": "nginx",
        "com_docker_compose_config-hash": "7651070843f55e203706ceb46b8bd465fe94a52d3ccb2e6d7061cb9bb1cc5b5a",
        "co_elastic_logs/fileset_stdout": "access",
        "com_docker_compose_oneoff": "False",
        "com_docker_compose_project": "censored",
        "co_elastic_logs/fileset_stderr": "error",
        "com_docker_compose_service": "web_censord",
        "com_docker_compose_container-number": "1",
        "com_docker_compose_version": "1.24.1"
      }
    },
    "agent": {
      "hostname": "3244cd1e9a45",
      "id": "fb28a171-9f3f-4879-b78a-b827c9f33a61",
      "type": "filebeat",
      "ephemeral_id": "4827faef-cc07-4752-b8f9-70cd343bb221",
      "version": "7.3.0"
    },
    "log": {
      "file": {
        "path": "/var/lib/docker/containers/fdb081668feea07061f6b2acd7e840164c6020e158257afce9472dab9f94339b/fdb081668feea07061f6b2acd7e840164c6020e158257afce9472dab9f94339b-json.log"
      },
      "offset": 110443
    },
    "message": "172.18.0.2 - - [12/Aug/2019:01:57:27 +0000] \"GET /favicon.ico HTTP/1.1\" 200 5695 \"http://censord.com/my/register/?target=/my/Affiliate_program\" \"Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/75.0.3770.143 YaBrowser/19.7.2.455 Yowser/2.5 Safari/537.36\"",
    "fileset": {
      "name": "error"
    },
    "error": {
      "message": "Provided Grok expressions do not match field value: [172.18.0.2 - - [12/Aug/2019:01:57:27 +0000] \\\"GET /favicon.ico HTTP/1.1\\\" 200 5695 \\\"http://censord.com/my/register/?target=/my/Affiliate_program\\\" \\\"Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/75.0.3770.143 YaBrowser/19.7.2.455 Yowser/2.5 Safari/537.36\\\"]"
    },
    "docker": {
      "container": {
        "labels": {
          "co_elastic_logs/module": "nginx",
          "co_elastic_logs/fileset_stdout": "access",
          "com_docker_compose_config-hash": "7651070843f55e203706ceb46b8bd465fe94a52d3ccb2e6d7061cb9bb1cc5b5a",
          "com_docker_compose_oneoff": "False",
          "com_docker_compose_project": "censored",
          "com_docker_compose_service": "web_censord",
          "co_elastic_logs/fileset_stderr": "error",
          "com_docker_compose_container-number": "1",
          "com_docker_compose_version": "1.24.1"
        }
      }
    },
    "input": {
      "type": "container"
    },
    "@timestamp": "2019-08-12T01:57:27.303Z",
    "ecs": {
      "version": "1.0.1"
    },
    "stream": "stdout",
    "service": {
      "type": "nginx"
    },
    "event": {
      "timezone": "+00:00",
      "module": "nginx",
      "dataset": "nginx.error"
    }
  }
}

compose file labels:

web_censored:
  image: censored
  labels:
    co.elastic.logs/module: nginx
    co.elastic.logs/fileset.stdout: access
    co.elastic.logs/fileset.stderr: error

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