I have Filebeat transporting my logs to logstash and then to ES.
The behaviour I have noticed is that some of my logs are processed and available in Kibana by not all. I see all the logs in the logstash debug log with a json output which I have pasted below:
Mai 10 16:49:15 mon-1 logstash[23980]: "log_timestamp" => "20210510 164915",
Mai 10 16:49:15 mon-1 logstash[23980]: "@version" => "1",
Mai 10 16:49:15 mon-1 logstash[23980]: "tags" => [
Mai 10 16:49:15 mon-1 logstash[23980]: [0] "live-778-0",
Mai 10 16:49:15 mon-1 logstash[23980]: [1] "beats_input_codec_plain_applied"
Mai 10 16:49:15 mon-1 logstash[23980]: ],
Mai 10 16:49:15 mon-1 logstash[23980]: "message" => "Regenerate session Id successful. Old: 68fba27224d7356696a Session: ab10f7923481c0a788a3c6401 IP: xx.xx.xx.253",
Mai 10 16:49:15 mon-1 logstash[23980]: "input" => {
Mai 10 16:49:15 mon-1 logstash[23980]: "type" => "log"
Mai 10 16:49:15 mon-1 logstash[23980]: },
Mai 10 16:49:15 mon-1 logstash[23980]: "ecs" => {
Mai 10 16:49:15 mon-1 logstash[23980]: "version" => "1.5.0"
Mai 10 16:49:15 mon-1 logstash[23980]: },
Mai 10 16:49:15 mon-1 logstash[23980]: "@timestamp" => 2021-05-10T14:49:15.000Z,
Mai 10 16:49:15 mon-1 logstash[23980]: "pid" => "9040",
Mai 10 16:49:15 mon-1 logstash[23980]: "debug" => "timestampMatched",
Mai 10 16:49:15 mon-1 logstash[23980]: "loglevel" => "INFO"
Mai 10 16:49:15 mon-1 logstash[23980]: }
Mai 10 16:49:15 mon-1 logstash[23980]: {
Mai 10 16:49:15 mon-1 logstash[23980]: "host" => {
Mai 10 16:49:15 mon-1 logstash[23980]: "name" => "live-778-0-filebeat"
Mai 10 16:49:15 mon-1 logstash[23980]: },
Mai 10 16:49:15 mon-1 logstash[23980]: "log" => {
Mai 10 16:49:15 mon-1 logstash[23980]: "file" => {
Mai 10 16:49:15 mon-1 logstash[23980]: "path" => "/var/log/main.log"
Mai 10 16:49:15 mon-1 logstash[23980]: },
Mai 10 16:49:15 mon-1 logstash[23980]: "offset" => 11443834
Mai 10 16:49:15 mon-1 logstash[23980]: },
Mai 10 16:49:15 mon-1 logstash[23980]: "agent" => {
Mai 10 16:49:15 mon-1 logstash[23980]: "name" => "live778-0-filebeat",
Mai 10 16:49:15 mon-1 logstash[23980]: "ephemeral_id" => "c6d8e18d-a3ed-4f86-a8a7-7d1938ee22f1",
Mai 10 16:49:15 mon-1 logstash[23980]: "hostname" => "live778-0",
Mai 10 16:49:15 mon-1 logstash[23980]: "type" => "filebeat",
Mai 10 16:49:15 mon-1 logstash[23980]: "version" => "7.7.0",
Mai 10 16:49:15 mon-1 logstash[23980]: "id" => "d5360ac6-52a9-408c-b439-dc6f5e8d7ae2"
Mai 10 16:49:15 mon-1 logstash[23980]: },
The raw timedatestamp for one of the logs is as follows:
[20210510 163257]
This is a copy of my logstash config:
filter {
if [log][file][path] =~ /(\/var\/lib\/mysql\/shop-1-slow\.log|\/var\/log\/mysql\/mysql-slow\.log|\/var\/lib\/mysql\/.*slow\.log)/ {
# Drop "Time" line since it does not appear on every log entry
if [message] =~ "^# Time: [0-9]+ " {
drop {}
}
grok {
patterns_dir => ["/etc/logstash/patterns"]
match => [ "message", "%{MYSQLSLOWLOGCOMBINED}%{GREEDYDATA:message}" ]
remove_field => [ "message" ]
}
date {
match => [ "query_timestamp", "UNIX" ]
target => "@timestamp"
timezone => "Europe/Berlin"
add_field => { "debug" => "timestampMatched" }
}
}
grok {
patterns_dir => ["/etc/logstash/patterns"]
match => { "message" => "\[%{DATESTAMP_ADMIN_LOG:log_timestamp}\] Logger\.%{LOGLEVEL:loglevel}\: %{GREEDYDATA:message}" }
match => { "message" => "\[%{DATESTAMP_ADMIN_LOG:log_timestamp}\] %{LOGLEVEL:loglevel} %{WORD:thread_name} %{NUMBER:application_runtime_ms}ms \(*%{WORD:user_name}\)* - %{GREEDYDATA:message}" }
match => { "message" => "\[%{DATESTAMP_ADMIN_LOG:log_timestamp}\] %{LOGLEVEL:loglevel} - %{GREEDYDATA:message}" }
match => { "message" => "\[%{DATESTAMP_ADMIN_LOG:log_timestamp}\] %{LOGLEVEL:loglevel}\: %{GREEDYDATA:message}" }
match => { "message" => "\[%{DATESTAMP_ADMIN_LOG:log_timestamp}\] %{PID:pid} %{LOGLEVEL:loglevel} - %{GREEDYDATA:message}" }
#match => { "message" => "\[%{TIMESTAMP_ISO8601:log_timestamp}\] %{PID:pid} %{LOGLEVEL:loglevel}\: %{GREEDYDATA:message}" }
match => { "message" => "\[%{TIMESTAMP_ISO8601:log_timestamp}\] %{IP:remote_ip} %{LOGLEVEL:loglevel} %{GREEDYDATA:message} %{CONTEXT_PATTERN:context} %{EXTRA_PATTERN:extra}" }
match => { "message" => "%{COMBINEDAPACHELOG} %{NOTSPACE:Host_header} %{NOTSPACE:x-forwarded-for} (?<connection_status>[X\+\-]) %{NOTSPACE:process_id} %{NOTSPACE:request_time:int} %{DATA:x-debug-id} %{NOTSPACE:ssl_protcol} %{NOTSPACE:ssl_cipher} %{NOTSPACE:ssl_tls_sni}" }
match => { "message" => "%{COMBINEDAPACHELOG} %{NOTSPACE:Host_header} %{NOTSPACE:x-forwarded-for} (?<connection_status>[X\+\-]) %{NOTSPACE:process_id} %{NOTSPACE:request_time:int} %{DATA:x-debug-id}" }
match => { "message" => "%{COMBINEDAPACHELOG} %{NOTSPACE:Host_header} (?<connection_status>[X\+\-]) %{NOTSPACE:process_id} %{NOTSPACE:request_time:int} %{DATA:x-debug-id} %{NOTSPACE:ssl_protcol} %{NOTSPACE:ssl_cipher} %{NOTSPACE:ssl_tls_sni}" }
match => { "message" => "%{COMBINEDAPACHELOG} %{NOTSPACE:Host_header} (?<connection_status>[X\+\-]) %{NOTSPACE:process_id} %{NOTSPACE:request_time:int} %{DATA:x-debug-id}" }
match => { "message" => "%{COMBINEDAPACHELOG} %{NOTSPACE:Host_header} (?<connection_status>[X\+\-]) %{NOTSPACE:process_id} %{NOTSPACE:ssl_protcol} %{NOTSPACE:ssl_cipher} %{NOTSPACE:ssl_tls_sni}" }
match => { "message" => "%{HTTPD_ERRORLOG}" }
match => { "message" => "\[%{DATESTAMP_PHPERROR:timestamp}\] %{DATA:level}[\.\:][\ ]+%{GREEDYDATA:error}" }
match => { "message" => "\[%{DATESTAMP_PHP_FPMERROR:timestamp}\] %{LOGLEVEL:loglevel}[\:]( \[pool %{DATA:pool}\])?[\ ]+%{GREEDYDATA:error}" }
overwrite => [ "message" ]
}
mutate {
gsub => ["timestamp","\.\d\d\d\d\d\d "," "]
}
mutate {
convert => {"bytes" => "integer" }
}
date {
match => [ "log_timestamp", "yyyyMMdd HHmmss", "yyyyMMdd HHmmss,SSS", " yyyy-MM-dd'T'HH:mm:ssZZ", "yyyy-MM-dd HHmmssZZZ" ]
target => "@timestamp"
timezone => "Europe/Berlin"
add_field => { "debug" => "timestampMatched" }
}
date {
match => [ "timestamp", "dd/MMM/yyyy:HH:mm:ss Z", "EEE MMM dd HH:mm:ss yyyy", "dd-MMM-yyyy HH:mm:ss ZZZ", "dd-MMM-yyyy HH:mm:ss", "yyyyMMdd HH:mm:ss" ]
target => "@timestamp"
timezone => "Europe/Berlin"
add_field => { "debug" => "timestampMatched" }
}
}
Here are the patterns for the datestamp in admin_log:
DATESTAMP_ADMIN_LOG %{YEAR}%{MONTHNUM}%{MONTHDAY} %{HOUR}%{MINUTE}%{SECOND}
I am guessing it will take a careful eye to see what mistake I have made here.
I am guess this error in the debug mode of elasticsearch though:
[2021-05-10T16:30:19,583][DEBUG][o.e.a.b.TransportShardBulkAction] [mon-1] [var_log_2021.05.10][0] failed to execute bulk item (index) index {[var_log_2021.05.10][_doc][myavVnkB8pecyBjVmne8], source[_na_]}
org.elasticsearch.index.mapper.MapperParsingException: failed to parse field [log_timestamp] of type [date] in document with id 'myavVnkB8pecyBjVmne8'. Preview of field's value: '20210510 163018'
at org.elasticsearch.index.mapper.FieldMapper.parse(FieldMapper.java:263) ~[elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.index.mapper.DocumentParser.parseObjectOrField(DocumentParser.java:485) ~[elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.index.mapper.DocumentParser.parseValue(DocumentParser.java:615) ~[elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.index.mapper.DocumentParser.innerParseObject(DocumentParser.java:424) ~[elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.index.mapper.DocumentParser.parseObjectOrNested(DocumentParser.java:395) ~[elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.index.mapper.DocumentParser.internalParseDocument(DocumentParser.java:112) ~[elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.index.mapper.DocumentParser.parseDocument(DocumentParser.java:71) ~[elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:227) ~[elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.index.shard.IndexShard.prepareIndex(IndexShard.java:803) ~[elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.index.shard.IndexShard.applyIndexOperation(IndexShard.java:780) ~[elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.index.shard.IndexShard.applyIndexOperationOnPrimary(IndexShard.java:752) ~[elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.action.bulk.TransportShardBulkAction.executeBulkItemRequest(TransportShardBulkAction.java:285) [elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.action.bulk.TransportShardBulkAction$2.doRun(TransportShardBulkAction.java:175) [elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.action.bulk.TransportShardBulkAction.performOnPrimary(TransportShardBulkAction.java:220) [elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.action.bulk.TransportShardBulkAction.dispatchedShardOperationOnPrimary(TransportShardBulkAction.java:126) [elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.action.bulk.TransportShardBulkAction.dispatchedShardOperationOnPrimary(TransportShardBulkAction.java:85) [elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.action.support.replication.TransportWriteAction$1.doRun(TransportWriteAction.java:179) [elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:737) [elasticsearch-7.10.0.jar:7.10.0]
at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:37) [elasticsearch-7.10.0.jar:7.10.0]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630) [?:?]
at java.lang.Thread.run(Thread.java:832) [?:?]
Caused by: java.lang.IllegalArgumentException: failed to parse date field [20210510 163018] with format [strict_date_optional_time||epoch_millis]
If anyone has any ideas of what can be going wrong I would be very grateful?