Logparser.grok does not work

EddieNejadi commented 7 years ago

Bug report

There is problem with logparser. It does not behave as it expected.

Relevant telegraf.conf:

System info:

Telegraf 1.2.1
OS Redhat 6

Steps to reproduce:

Set up configureation as follow:

## My Simple config
[global_tags]
[agent]
interval = "10s"
round_interval = true
metric_batch_size = 1000
metric_buffer_limit = 10000
collection_jitter = "0s"
flush_interval = "10s"
flush_jitter = "0s"
precision = ""
debug = true
quiet = false
hostname = ""
omit_hostname = false
[[outputs.file]]
files = ["stdout", "/tmp/metrics.out"]
[[inputs.logparser]]
files = ["/var/logfiles/studio.Tracking*"]
from_beginning = true
[inputs.logparser.grok]
patterns = ['  Open Plan Times (%{TIMESTAMP_ISO8601:save_plan_ts:ts-"2006-01-02 15:04"}):']
# patterns = ['Open Plan Times (%{TIMESTAMP_ISO8601:save_plan_ts:ts-"2006-01-02 15:04"}):'] # This pattern also failed
measurement = "cms_kpis"

Create sample log file as follow

...
2017-04-20 08:08:05 INFO rave.crc.etable Finished load of compdays.account_entry_search, read 418090 rows. Select real time 10 ms, cpu time 0 ms. R
ead real time 1820 ms, cpu time 1820 ms.
$$ Thu Apr 20 08:08:05 2017: Begin getDbPeriodStart (AbsTime('01MAY2017 00:00'),) {}
carmusr.tracking.FileHandlingExt::getDbPeriodStart:: Entered
$$ Thu Apr 20 08:08:05 2017: End   getDbPeriodStart : real= 0 ms, cpu= 0 ms
Rave string pool almost full: raising memory limit to 6291456 byte.
carmusr.tracking.FileHandlingExt::openPlanPostProc:: loaded_data_period_start: 24APR2017 00:00
Rave string pool almost full: raising memory limit to 9437184 byte.
carmusr.tracking.FileHandlingExt::openPlanPostProc:: loaded_data_period_end: 31MAY2017 23:59
carmusr.tracking.FileHandlingExt::openPlanPostProc:: Rave evaluation in LATEST revison
---------------------------------------------
Open Plan Times (2017-04-20 08:36):
Total: 156.69 s (cpu: 80.84 s)
Loading parameters and rule set: 0.52 s (cpu: 0.38 s)
Getting to setDaveLoadFilter: 0.39 s (cpu: 0.23 s)
Setup of filter: 0.30 s (cpu: 0.12 s)
CARMSYS Loading time: 102.55 s (cpu: 53.24 s)
Starting JVM: 0.04 s (cpu: 0.04 s)
Preloading tables to model: 44.41 s (cpu: 18.45 s)
Create informed temptable: 1.22 s (cpu: 1.21 s)
Preloading tables to rave: 7.04 s (cpu: 7.01 s)
Copying activity codes to temporary Etable: 0.23 s (cpu: 0.15 s)
---------------------------------------------
Number of loaded model tables: 161
activity_group_period         : 34
crew_flight_duty_attr         : 7004
crew_activity_attr            : 636
cio_status                    : 2920
urm_trail_set                 : 0
bought_days                   : 5036
account_set                   : 36
ci_exception                  : 407
....

Expected behavior:

See that the file would be parsed and see:

cms_kpis,host=hostname load_plan_time="2017-04-20 08:36" 1493135662703108603
Actual behavior:

not metrics.out entry for cms_kpis

Additional info:

I have tested my patten at https://grokdebug.herokuapp.com/ plus I followed the README instruction.

danielnelson commented 7 years ago

I don't see a line in your log file that this would match, none of them contain Save Plan Times. Also, only use the ts conversion if you would like to change the timestamp of the point.

We try to reserve GitHub Issues for actionable bug reports or feature requests. Please ask general questions at the InfluxData Community site.

EddieNejadi commented 7 years ago

It was my bad, I have update the pattern. I will ask my question in the Influx forum. Thank you for reply :+1:

influxdata / telegraf