Provided Grok expressions do not match field value

Elastic Stack Beats
1

Hi,
MySQL module does not support 5.6?

The MySQL module was tested with logs from versions 5.5 and 5.7.

I modified pipeline.json,but...

QQ20171011-161531
QQ20171011-161531873×574 62.1 KB

  • filebeat versions 5.6.2
  • elasticsearch versions 5.6.2
  • MySQL versions 5.6.33-0ubuntu0.14.04.1

And here is my sample log file:

/usr/sbin/mysqld, Version: 5.6.33-0ubuntu0.14.04.1-log ((Ubuntu)). started with:
Tcp port: 3306  Unix socket: /var/run/mysqld/mysqld.sock
Time                 Id Command    Argument
# Time: 171011 11:54:41
# User@Host: root[root] @  [10.254.254.91]  Id: 54014516
# Query_time: 21.340617  Lock_time: 0.000098 Rows_sent: 63264  Rows_examined: 63264
use aaa;
SET timestamp=1507694081;
select * from kkk;
# Time: 171011 11:55:48
# User@Host: root[root] @  [10.254.254.91]  Id: 54014516
# Query_time: 43.426563  Lock_time: 0.000093 Rows_sent: 63264  Rows_examined: 63264
SET timestamp=1507694148;
select * from kkk;

mysql/slowlog/ingest/pipeline.json

{
  "description": "Pipeline for parsing MySQL slow logs.",
  "processors": [{
    "grok": {
      "field": "message",
      "patterns":[
        "^# Time: %{NUMBER:mysql.slowlog.date} %{TIME:mysql.slowlog.time}\n# User@Host: %{USER:mysql.slowlog.user}\\[%{WORD}\\] @ %{WORD:mysql.slowlog.dbhost}? \\[%{IP:mysql.slowlog.ip}\\]?(\\s*Id: %{NUMBER:mysql.slowlog.id})?\n# Query_time: %{NUMBER:mysql.slowlog.query_time.sec}\\s* Lock_time: %{NUMBER:mysql.slowlog.lock_time.sec}\\s* Rows_sent: %{NUMBER:mysql.slowlog.rows_sent}\\s* Rows_examined: %{NUMBER:mysql.slowlog.rows_examined}\n(SET timestamp=%{NUMBER:mysql.slowlog.timestamp};\n)?%{GREEDYMULTILINE:mysql.slowlog.query}"
      ],
      "pattern_definitions" : {
        "GREEDYMULTILINE" : "(.|\n)*"
      },
      "ignore_missing": true
    }
  }, {
    "remove":{
      "field": "message"
    }
  }, {
    "date": {
      "field": "mysql.slowlog.timestamp",
      "target_field": "@timestamp",
      "formats": ["UNIX"],
      "ignore_failure": true
    }
  }
 ],
  "on_failure" : [{
    "set" : {
      "field" : "error.message",
      "value" : "{{ _ingest.on_failure_message }}"
    }
  }]
}

mysql/slowlog/config/slowlog.yml

input_type: log
paths:
{{ range $i, $path := .paths }}
 - {{$path}}
{{ end }}
exclude_files: [".gz$"]
multiline:
  pattern: '^# Time: '
  negate: true
  match: after
exclude_lines: ['^[\/\w\.]+, Version: .* started with:.*']

Thanks for your help

2

Hi,

Your line: # User@Host: root[root] @ [10.254.254.91] Id: 54014516 cannot be parsed by the default MySql Filebeat module.

However, using your pipeline and slowlog.yml file the sample logs you provided can be parsed.
Have you updated your pipeline in ES? By default it is not overwritten, so if you changed it after the default pipeline was loaded, you would not see any change. So first you need to delete the pipeline and then load your new, modified one.

3

Hi kvch,
Thanks for your immediate response .
But the problem remains the same.

Provided Grok expressions do not match field value

root@DB-1:/usr/local/filebeat-5.6.2-linux-x86_64/module/mysql/slowlog/ingest# curl -X DELETE 'http://10.254.254.60:9200/_ingest/pipeline/mysql_slow_logs' -u elastic -d '{"password" : "elasticpassword"}'
Enter host password for user 'elastic':
{"acknowledged":true}

root@DB-1:/usr/local/filebeat-5.6.2-linux-x86_64/module/mysql/slowlog/ingest# curl -H 'Content-Type: application/json' -X PUT 'http://10.254.254.60:9200/_ingest/pipeline/mysql_slow_logs' -d@pipeline.json -u elastic -d '{"password" : "elasticpassword"}'
Enter host password for user 'elastic':
{"acknowledged":true}

root@DB-1:/usr/local/filebeat-5.6.2-linux-x86_64/module/mysql/slowlog/ingest# curl -X GET 'http://10.254.254.60:9200/_ingest/pipeline/mysql_slow_logs?pretty' -u elastic -d '{"password" : "elasticpassword"}'
Enter host password for user 'elastic':
{
  "mysql_slow_logs" : {
    "description" : "Pipeline for parsing MySQL slow logs.",
    "processors" : [
      {
        "grok" : {
          "field" : "message",
          "patterns" : [
            "^# Time: %{NUMBER:mysql.slowlog.date} %{TIME:mysql.slowlog.time}\n# User@Host: %{USER:mysql.slowlog.user}(\\[[^\\]]+\\])? @ %{HOSTNAME:mysql.slowlog.host}? \\[(%{IP:mysql.slowlog.ip})?\\](\\s*Id:\\s* %{NUMBER:mysql.slowlog.id})?\n# Query_time: %{NUMBER:mysql.slowlog.query_time.sec}\\s* Lock_time: %{NUMBER:mysql.slowlog.lock_time.sec}\\s* Rows_sent: %{NUMBER:mysql.slowlog.rows_sent}\\s* Rows_examined: %{NUMBER:mysql.slowlog.rows_examined}\n(SET timestamp=%{NUMBER:mysql.slowlog.timestamp};\n)?%{GREEDYMULTILINE:mysql.slowlog.query}"
          ],
          "pattern_definitions" : {
            "GREEDYMULTILINE" : "(.|\n)*"
          },
          "ignore_missing" : true
        }
      },
      {
        "remove" : {
          "field" : "message"
        }
      },
      {
        "date" : {
          "field" : "mysql.slowlog.timestamp",
          "target_field" : "@timestamp",
          "formats" : [
            "UNIX"
          ],
          "ignore_failure" : true
        }
      }
    ],
    "on_failure" : [
      {
        "set" : {
          "field" : "error.message",
          "value" : "{{ _ingest.on_failure_message }}"
        }
      }
    ]
  }
}
4

error

Provided Grok expressions do not match field value: [# Time: 171012 11:12:59\n# User@Host: root[root] @ [10.254.254.91] Id: 54220704\n# Query_time: 65.259383 Lock_time: 0.000077 Rows_sent: 63264 Rows_examined: 63264\nSET timestamp=1507777979;\nselect * from kkk\u0000;]

json

{
  "_index": "filebeat-mysql.78",
  "_type": "doc",
  "_id": "AV8OkkvYeh6mxkDT_QWo",
  "_version": 1,
  "_score": null,
  "_source": {
    "@timestamp": "2017-10-12T03:12:59.617Z",
    "offset": 18906,
    "beat": {
      "hostname": "DB-1",
      "name": "DB-1",
      "version": "5.6.2"
    },
    "input_type": "log",
    "source": "/var/lib/mysql/DB-1-slow.log",
    "fileset": {
      "module": "mysql",
      "name": "slowlog"
    },
    "message": "# Time: 171012 11:12:59\n# User@Host: root[root] @  [10.254.254.91]  Id: 54220704\n# Query_time: 65.259383  Lock_time: 0.000077 Rows_sent: 63264  Rows_examined: 63264\nSET timestamp=1507777979;\nselect * from kkk\u0000;",
    "type": "log",
    "error": "Provided Grok expressions do not match field value: [# Time: 171012 11:12:59\\n# User@Host: root[root] @  [10.254.254.91]  Id: 54220704\\n# Query_time: 65.259383  Lock_time: 0.000077 Rows_sent: 63264  Rows_examined: 63264\\nSET timestamp=1507777979;\\nselect * from kkk\\u0000;]"
  },
  "fields": {
    "@timestamp": [
      1507777979617
    ]
  },
  "sort": [
    1507777979617
  ]
}

filebeat.yml

output.elasticsearch:
  hosts: ["http://10.254.254.60:9200"]
  index: "filebeat-mysql.78"
  pipeline: "mysql_slow_logs"

POST _ingest/pipeline/mysql_slow_logs/_simulate
{
  "docs" : [
    { "_source": {
        "message": "# Time: 171012 11:12:59\n# User@Host: root[root] @  [10.254.254.91]  Id: 54220704\n# Query_time: 65.259383  Lock_time: 0.000077 Rows_sent: 63264  Rows_examined: 63264\nSET timestamp=1507777979;\nselect * from kkk\u0000;"} }
  ]
}

Response:

{
  "docs": [
    {
      "doc": {
        "_index": "_index",
        "_type": "_type",
        "_id": "_id",
        "_source": {
          "mysql": {
            "slowlog": {
              "lock_time": {
                "sec": "0.000077"
              },
              "date": "171012",
              "rows_sent": "63264",
              "rows_examined": "63264",
              "ip": "10.254.254.91",
              "query": "select * from kkk\u0000;",
              "time": "11:12:59",
              "id": "54220704",
              "user": "root",
              "query_time": {
                "sec": "65.259383"
              },
              "timestamp": "1507777979"
            }
          },
          "@timestamp": "2017-10-12T03:12:59.000Z"
        },
        "_ingest": {
          "timestamp": "2017-10-12T03:16:23.523Z"
        }
      }
    }
  ]
}
5

Could you try loading the pipeline using Filebeat and then parsing a log message using Simulate API?

Could you try loading the pipeline using Filebeat and send logs using Filebeat? Make sure that your logs does not contain \u0000. It might cause problems in the Grok processor.

Also, are you sure that all of your log messages start with "# Time"? Time is an optional field.

6

Are you storing log files on network shares?

7

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