Failed parsing date from field {:field=>"timestamp", :value=>"%{year} %{month} %{monthday} %{time}", :exception=>"Invalid format: "%{year} %{month} %{monthday} %{t..."", :config_parsers=>"yyyy MMM dd HH:mm:ss", :config_locale=>"en", :level=>:warn}
Using below configuration
Hi!
Would you mind sharing your current pipeline configuration in it's entirety?
There is some back and forth on that thread and knowing exactly what you're using will make it easier
input {
file {
path => "/u01/app/oracle/diag/rdbms/orcldr/orcldr/trace/alert_orcldr.log"
}
}
filter {
multiline {
pattern => "%{DAY} %{MONTH} %{MONTHDAY} %{TIME} %{YEAR}"
negate => true
what => "previous"
}
if [message] =~ /Starting ORACLE instance/ {
mutate {
add_field => [ "oradb_status", "starting" ]
}
} else if [message] =~ /Instance shutdown complete/ {
mutate {
add_field => [ "oradb_status", "shutdown" ]
}
} else {
mutate {
add_field => [ "oradb_status", "running" ]
}
}
if [message] =~ /ORA-/ {
grok {
match => [ "message","(?<ORA->ORA-[0-9]*)" ]
}
}
grok {
match => [ "message","%{DAY:day} %{MONTH:month} %{MONTHDAY:monthday} %{TIME:time} %{YEAR:year}(?<log_message>.*$)" ]
}
mutate {
add_field => {
"timestamp" => "%{year} %{month} %{monthday} %{time}"
}
}
date {
locale => "en"
match => [ "timestamp","yyyy MMM dd HH:mm:ss"]
}
mutate { replace => [ "message", "%{log_message}" ] }
mutate {
remove_field => [ "time" ,"month","monthday","year","timestamp","day","log_message"]
}
}
output {
stdout {codec => rubydebug}
elasticsearch {
hosts => ["localhost:9200"]
index => "oracle-%{+YYYY.MM.dd}"
}
}
I think this means that your timestamp field is literally the value %{year} %{month} %{monthday} %{time} this likely means your grok pattern is not actually pulling out the timestamp.
I would recommend removing one block at a time from the filter part of your configuration until you can verify that the timestamp is correctly parsing from the log into fields called year, month, monthday, and time. Once you verify each block you can readd the next one.
In addition, if you'd like more help you'll need to provide sample logs for this pipeline.
Hi @strawgate,
Thanks for your response.
Sample logs as below:
2024-01-23T10:02:40.751340+05:30
Thread 1 advanced to log sequence 95 (LGWR switch)
Current log# 2 seq# 95 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo02.log
2024-01-23T10:02:40.759293+05:30
ARC2 (PID:3672): Archived Log entry 79 added for T-1.S-94 ID 0x6484cf48 LAD:1
2024-01-23T10:07:57.844414+05:30
Thread 1 advanced to log sequence 96 (LGWR switch)
Current log# 3 seq# 96 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo03.log
2024-01-23T10:07:57.854529+05:30
ARC3 (PID:3674): Archived Log entry 80 added for T-1.S-95 ID 0x6484cf48 LAD:1
2024-01-23T10:11:53.796684+05:30
Thread 1 advanced to log sequence 97 (LGWR switch)
Current log# 1 seq# 97 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo01.log
These two lines imply you have a log line that looks like this
Mon Dec 12 10:53:12 2024 <message>
Your logs have a timestamp format of 2024-01-23T10:07:57.854529+05:30 <message>. This is also known as an ISO8601 timestamp with timezone information.
The grok pattern you'll need for this timestamp format is %{TIMESTAMP_ISO8601:timestamp}%{ISO8601_TIMEZONE:timezone}
In your date match block
date {
locale => "en"
match => [ "timestamp","yyyy MMM dd HH:mm:ss"]
}
you have yyyy MMM dd HH:mm:ss but what you need is
match => ["ISO8601" ]
And you then need to remove
mutate {
add_field => {
"timestamp" => "%{year} %{month} %{monthday} %{time}"
}
}
Great its working fine now, needs small modification on time zone, can you please help us on this.
2024-01-23T22:34:39.669866+05:30 -- log sample
2024-01-23T17:04:39.669Z --timestamp of logstash output ends with Z, we need same output as above sample log timestamp.
2024-01-23T22:34:39.669866+05:30
Thread 1 advanced to log sequence 99 (LGWR switch)
Current log# 3 seq# 99 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo03.log
2024-01-23T22:34:40.104691+05:30
ARC2 (PID:3226): Archived Log entry 83 added for T-1.S-98 ID 0x6484cf48 LAD:1
"message" => "\nThread 1 advanced to log sequence 99 (LGWR switch)\n Current log# 3 seq# 99 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo03.log\n2024-01-23T22:34:40.104691+05:30\nARC2 (PID:3226): Archived Log entry 83 added for T-1.S-98 ID 0x6484cf48 LAD:1",
"@version" => "1",
"@timestamp" => "2024-01-23T17:04:39.669Z",
"path" => "/u01/app/oracle/diag/rdbms/orcldr/orcldr/trace/alert_orcldr.log",
"host" => "srvdb03.localdomain",
"tags" => [
[0] "multiline"
],
"oradb_status" => "running",
"timezone" => "+05:30"
Oops, this suggestion I gave you is the problem:
The grok pattern you'll need for this timestamp format is
%{TIMESTAMP_ISO8601:timestamp}%{ISO8601_TIMEZONE:timezone}
TIMESTAMP_ISO8601 format already includes the timezone so I should have suggested you set the grok pattern to just %{TIMESTAMP_ISO8601:timestamp}
(remove the ISO8601_TIMEZONE part) which should then work with the date filter to get the timezone included.
Hi @strawgate,
Still same issue, sharing below grok modified configuration and its output.
grok {
match => [ "message","%{TIMESTAMP_ISO8601:timestamp}(?<log_message>.*$)" ]
}
date {
locale => "en"
match => [ "timestamp","ISO8601"]
}
Sample log:
Thread 1 advanced to log sequence 102 (LGWR switch)
Current log# 3 seq# 102 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo03.log
2024-01-23T23:14:14.004318+05:30
ARC1 (PID:3224): Archived Log entry 86 added for T-1.S-101 ID 0x6484cf48 LAD:1
Logstash Output:
"message" => "\nThread 1 advanced to log sequence 102 (LGWR switch)\n Current log# 3 seq# 102 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo03.log\n2024-01-23T23:14:14.004318+05:30\nARC1 (PID:3224): Archived Log entry 86 added for T-1.S-101 ID 0x6484cf48 LAD:1",
"@version" => "1",
"@timestamp" => "2024-01-23T17:44:13.797Z",
"path" => "/u01/app/oracle/diag/rdbms/orcldr/orcldr/trace/alert_orcldr.log",
"host" => "srvdb03.localdomain",
"tags" => [
[0] "multiline"
],
"oradb_status" => "running"
}
This looks correct to me. Logstash has normalized your timestamp to UTC and will show the timestamp according to the user's browser's timezone. See: How to set @timestamp timezone?
Example:
Original: 2024-01-23T23:14:14.004318+05:30
UTC Time: 2024-01-23T17:44:14.004Z
Which matches what you're seeing.
Though it does look like we're saving these values to timestamp and not @timestamp you might want to change your date filter to:
date {
locale => "en"
match => [ "timestamp","ISO8601"]
target => "@timestamp"
}
Otherwise my guess is that you've got a timestamp field and a @timestamp field.
Hi @strawgate ,
I modified as below, but still seeing different in original timestamp,
date {
locale => "en"
match => [ "timestamp","ISO8601"]
target => "@timestamp"
}
Original:2024-01-23T23:27:11.624120+05:30
Logstash @timestamp:2024-01-23T17:57:11.624Z
2024-01-23T23:27:11.624120+05:30
Thread 1 advanced to log sequence 103 (LGWR switch)
Current log# 1 seq# 103 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo01.log
2024-01-23T23:27:11.690924+05:30
ARC2 (PID:3226): Archived Log entry 87 added for T-1.S-102 ID 0x6484cf48 LAD:1
"message" => "\nThread 1 advanced to log sequence 103 (LGWR switch)\n Current log# 1 seq# 103 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo01.log\n2024-01-23T23:27:11.690924+05:30\nARC2 (PID:3226): Archived Log entry 87 added for T-1.S-102 ID 0x6484cf48 LAD:1",
"@version" => "1",
"@timestamp" => "2024-01-23T17:57:11.624Z",
"path" => "/u01/app/oracle/diag/rdbms/orcldr/orcldr/trace/alert_orcldr.log",
"host" => "srvdb03.localdomain",
"tags" => [
[0] "multiline"
],
"oradb_status" => "running",
"timezone" => "+05:30"
}
Can you please share the full log output (not trimmed, there should still be a timestamp field?) and the full pipeline again? I don't think I expected there to be a timezone field anymore.
Hi @strawgate,
Please find requested details,
Sample Full log:
2024-01-23T22:34:39.669866+05:30
Thread 1 advanced to log sequence 99 (LGWR switch)
Current log# 3 seq# 99 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo03.log
2024-01-23T22:34:40.104691+05:30
ARC2 (PID:3226): Archived Log entry 83 added for T-1.S-98 ID 0x6484cf48 LAD:1
2024-01-23T22:51:58.460534+05:30
Thread 1 advanced to log sequence 100 (LGWR switch)
Current log# 1 seq# 100 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo01.log
2024-01-23T22:51:58.773065+05:30
ARC3 (PID:3228): Archived Log entry 84 added for T-1.S-99 ID 0x6484cf48 LAD:1
2024-01-23T23:03:23.492049+05:30
Warning: VKTM detected a forward time drift.
Time drifts can result in unexpected behavior such as time-outs.
Please see the VKTM trace file for more details:
/u01/app/oracle/diag/rdbms/orcldr/orcldr/trace/orcldr_vktm_3146.trc
2024-01-23T23:09:57.352911+05:30
Thread 1 advanced to log sequence 101 (LGWR switch)
Current log# 2 seq# 101 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo02.log
2024-01-23T23:09:57.855023+05:30
ARC0 (PID:3218): Archived Log entry 85 added for T-1.S-100 ID 0x6484cf48 LAD:1
2024-01-23T23:14:13.797045+05:30
Thread 1 advanced to log sequence 102 (LGWR switch)
Current log# 3 seq# 102 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo03.log
2024-01-23T23:14:14.004318+05:30
ARC1 (PID:3224): Archived Log entry 86 added for T-1.S-101 ID 0x6484cf48 LAD:1
2024-01-23T23:27:11.624120+05:30
Thread 1 advanced to log sequence 103 (LGWR switch)
Current log# 1 seq# 103 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo01.log
2024-01-23T23:27:11.690924+05:30
ARC2 (PID:3226): Archived Log entry 87 added for T-1.S-102 ID 0x6484cf48 LAD:1
logstash filter:
input {
file {
path => "/u01/app/oracle/diag/rdbms/orcldr/orcldr/trace/alert_orcldr.log"
}
}
filter {
multiline {
pattern => "%{DAY} %{MONTH} %{MONTHDAY} %{TIME} %{YEAR}"
negate => true
what => "previous"
}
if [message] =~ /Starting ORACLE instance/ {
mutate {
add_field => [ "oradb_status", "starting" ]
}
} else if [message] =~ /Instance shutdown complete/ {
mutate {
add_field => [ "oradb_status", "shutdown" ]
}
} else {
mutate {
add_field => [ "oradb_status", "running" ]
}
}
if [message] =~ /ORA-/ {
grok {
match => [ "message","(?<ORA->ORA-[0-9]*)" ]
}
}
grok {
match => [ "message","%{TIMESTAMP_ISO8601:timestamp}(?<log_message>.*$)" ]
}
date {
locale => "en"
match => [ "timestamp","ISO8601"]
target => "@timestamp"
}
mutate { replace => [ "message", "%{log_message}" ] }
mutate {
remove_field => [ "time" ,"month","monthday","year","timestamp","day","log_message"]
}
}
output {
stdout {codec => rubydebug}
elasticsearch {
hosts => ["localhost:9200"]
index => "oracle-%{+YYYY.MM.dd}"
}
}
This needs to be updated to the new grok pattern %{TIMESTAMP_ISO8601} though I'm not sure that's what's causing the issue.
By the full log I meant the full log that logstash is printing when it processes the file. i.e. the full version of this that you shared earlier:
"message" => "\nThread 1 advanced to log sequence 103 (LGWR switch)\n Current log# 1 seq# 103 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo01.log\n2024-01-23T23:27:11.690924+05:30\nARC2 (PID:3226): Archived Log entry 87 added for T-1.S-102 ID 0x6484cf48 LAD:1",
"@version" => "1",
"@timestamp" => "2024-01-23T17:57:11.624Z",
"path" => "/u01/app/oracle/diag/rdbms/orcldr/orcldr/trace/alert_orcldr.log",
"host" => "srvdb03.localdomain",
"tags" => [
[0] "multiline"
],
"oradb_status" => "running",
"timezone" => "+05:30"
}
I also forgot but @timestamp is the default value for target in the date filter so that was a no-op change, sorry about that,
Also while we're testing would you mind removing
mutate {
remove_field => [ "time" ,"month","monthday","year","timestamp","day","log_message"]
}
}
so that we can see the intermediate values in the output?
Are you sure you've correctly reloaded the pipeline after updating the config? Im not sure there should be a timezone field here anymore.
Still same, sharing all log information for your analysis,
Logstash output:
"message" => "\nThread 1 advanced to log sequence 104 (LGWR switch)\n Current log# 2 seq# 104 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo02.log\n2024-01-23T23:48:50.720887+05:30\nARC3 (PID:3228): Archived Log entry 88 added for T-1.S-103 ID 0x6484cf48 LAD:1",
"@version" => "1",
"@timestamp" => "2024-01-23T18:18:50.645Z",
"path" => "/u01/app/oracle/diag/rdbms/orcldr/orcldr/trace/alert_orcldr.log",
"host" => "srvdb03.localdomain",
"tags" => [
[0] "multiline"
],
"oradb_status" => "running",
"timezone" => "+05:30"
}
Sample Full log:
2024-01-23T22:51:58.460534+05:30
Thread 1 advanced to log sequence 100 (LGWR switch)
Current log# 1 seq# 100 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo01.log
2024-01-23T22:51:58.773065+05:30
ARC3 (PID:3228): Archived Log entry 84 added for T-1.S-99 ID 0x6484cf48 LAD:1
2024-01-23T23:03:23.492049+05:30
Warning: VKTM detected a forward time drift.
Time drifts can result in unexpected behavior such as time-outs.
Please see the VKTM trace file for more details:
/u01/app/oracle/diag/rdbms/orcldr/orcldr/trace/orcldr_vktm_3146.trc
2024-01-23T23:09:57.352911+05:30
Thread 1 advanced to log sequence 101 (LGWR switch)
Current log# 2 seq# 101 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo02.log
2024-01-23T23:09:57.855023+05:30
ARC0 (PID:3218): Archived Log entry 85 added for T-1.S-100 ID 0x6484cf48 LAD:1
2024-01-23T23:14:13.797045+05:30
Thread 1 advanced to log sequence 102 (LGWR switch)
Current log# 3 seq# 102 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo03.log
2024-01-23T23:14:14.004318+05:30
ARC1 (PID:3224): Archived Log entry 86 added for T-1.S-101 ID 0x6484cf48 LAD:1
2024-01-23T23:27:11.624120+05:30
Thread 1 advanced to log sequence 103 (LGWR switch)
Current log# 1 seq# 103 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo01.log
2024-01-23T23:27:11.690924+05:30
ARC2 (PID:3226): Archived Log entry 87 added for T-1.S-102 ID 0x6484cf48 LAD:1
2024-01-23T23:48:50.645593+05:30
Thread 1 advanced to log sequence 104 (LGWR switch)
Current log# 2 seq# 104 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo02.log
2024-01-23T23:48:50.720887+05:30
ARC3 (PID:3228): Archived Log entry 88 added for T-1.S-103 ID 0x6484cf48 LAD:1
Logstash configuration:
input {
file {
path => "/u01/app/oracle/diag/rdbms/orcldr/orcldr/trace/alert_orcldr.log"
}
}
filter {
multiline {
pattern => "%{TIMESTAMP_ISO8601}"
negate => true
what => "previous"
}
if [message] =~ /Starting ORACLE instance/ {
mutate {
add_field => [ "oradb_status", "starting" ]
}
} else if [message] =~ /Instance shutdown complete/ {
mutate {
add_field => [ "oradb_status", "shutdown" ]
}
} else {
mutate {
add_field => [ "oradb_status", "running" ]
}
}
if [message] =~ /ORA-/ {
grok {
match => [ "message","(?ORA-[0-9]*)" ]
}
}
grok {
match => [ "message","%{TIMESTAMP_ISO8601:timestamp}(?<log_message>.*$)" ]
}
date {
locale => "en"
match => [ "timestamp","ISO8601"]
target => "@timestamp"
}
mutate { replace => [ "message", "%{log_message}" ] }
}
output {
stdout {codec => rubydebug}
elasticsearch {
hosts => ["localhost:9200"]
index => "oracle-%{+YYYY.MM.dd}"
}
}
Can you reload logstash and share the full log from logstash ingesting those logs?
@strawgate,
Reloaded Logstash, the issue remains same and there is no logstash configuration change.
Full log:
2024-01-23T22:34:40.104691+05:30
ARC2 (PID:3226): Archived Log entry 83 added for T-1.S-98 ID 0x6484cf48 LAD:1
2024-01-23T22:51:58.460534+05:30
Thread 1 advanced to log sequence 100 (LGWR switch)
Current log# 1 seq# 100 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo01.log
2024-01-23T22:51:58.773065+05:30
ARC3 (PID:3228): Archived Log entry 84 added for T-1.S-99 ID 0x6484cf48 LAD:1
2024-01-23T23:03:23.492049+05:30
Warning: VKTM detected a forward time drift.
Time drifts can result in unexpected behavior such as time-outs.
Please see the VKTM trace file for more details:
/u01/app/oracle/diag/rdbms/orcldr/orcldr/trace/orcldr_vktm_3146.trc
2024-01-23T23:09:57.352911+05:30
Thread 1 advanced to log sequence 101 (LGWR switch)
Current log# 2 seq# 101 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo02.log
2024-01-23T23:09:57.855023+05:30
ARC0 (PID:3218): Archived Log entry 85 added for T-1.S-100 ID 0x6484cf48 LAD:1
2024-01-23T23:14:13.797045+05:30
Thread 1 advanced to log sequence 102 (LGWR switch)
Current log# 3 seq# 102 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo03.log
2024-01-23T23:14:14.004318+05:30
ARC1 (PID:3224): Archived Log entry 86 added for T-1.S-101 ID 0x6484cf48 LAD:1
2024-01-23T23:27:11.624120+05:30
Thread 1 advanced to log sequence 103 (LGWR switch)
Current log# 1 seq# 103 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo01.log
2024-01-23T23:27:11.690924+05:30
ARC2 (PID:3226): Archived Log entry 87 added for T-1.S-102 ID 0x6484cf48 LAD:1
2024-01-23T23:48:50.645593+05:30
Thread 1 advanced to log sequence 104 (LGWR switch)
Current log# 2 seq# 104 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo02.log
2024-01-23T23:48:50.720887+05:30
ARC3 (PID:3228): Archived Log entry 88 added for T-1.S-103 ID 0x6484cf48 LAD:1
2024-01-24T00:16:35.067149+05:30
Warning: VKTM detected a forward time drift.
Time drifts can result in unexpected behavior such as time-outs.
Please see the VKTM trace file for more details:
/u01/app/oracle/diag/rdbms/orcldr/orcldr/trace/orcldr_vktm_3146.trc
2024-01-24T00:22:42.003181+05:30
Thread 1 advanced to log sequence 105 (LGWR switch)
Current log# 3 seq# 105 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo03.log
2024-01-24T00:22:42.052006+05:30
ARC0 (PID:3218): Archived Log entry 89 added for T-1.S-104 ID 0x6484cf48 LAD:1
2024-01-24T00:23:31.503422+05:30
Thread 1 advanced to log sequence 106 (LGWR switch)
Current log# 1 seq# 106 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo01.log
2024-01-24T00:23:31.514181+05:30
ARC1 (PID:3224): Archived Log entry 90 added for T-1.S-105 ID 0x6484cf48 LAD:1
where is this log coming from?
"message" => "\nThread 1 advanced to log sequence 104 (LGWR switch)\n Current log# 2 seq# 104 mem# 0: /u01/app/oracle/oradata/ORCLDR/redo02.log\n2024-01-23T23:48:50.720887+05:30\nARC3 (PID:3228): Archived Log entry 88 added for T-1.S-103 ID 0x6484cf48 LAD:1",
"@version" => "1",
"@timestamp" => "2024-01-23T18:18:50.645Z",
"path" => "/u01/app/oracle/diag/rdbms/orcldr/orcldr/trace/alert_orcldr.log",
"host" => "srvdb03.localdomain",
"tags" => [
[0] "multiline"
],
"oradb_status" => "running",
"timezone" => "+05:30"
It looks like you're sending me the Oracle log file, I'm looking for the log that Logstash is producing when you run the pipeline. I would expect one of those blocks from above for each message in the logstash log?
© 2020. All Rights Reserved - Elasticsearch
Apache, Apache Lucene, Apache Hadoop, Hadoop, HDFS and the yellow elephant logo are trademarks of the Apache Software Foundation in the United States and/or other countries.