Hey Kvch,
Sure, again sorry for the stupid questions are you looking for the Filebeat log or the actual system logs ?
Hey Kvch,
Sure, again sorry for the stupid questions are you looking for the Filebeat log or the actual system logs ?
Sorry, I was not clear. I would like to see the debug logs of Filebeat.
2018-03-28T11:11:13.194-0400 INFO instance/beat.go:468 Home path: [/usr/share/filebeat] Config path: [/etc/filebeat] Data path: [/var/lib/filebeat] Logs path: [/var/log/filebeat]
2018-03-28T11:11:13.194-0400 DEBUG [beat] instance/beat.go:495 Beat metadata path: /var/lib/filebeat/meta.json
2018-03-28T11:11:13.194-0400 INFO instance/beat.go:475 Beat UUID: 86e97091-703c-4735-b170-fc2c435279bb
2018-03-28T11:11:13.194-0400 INFO instance/beat.go:213 Setup Beat: filebeat; Version: 6.2.3
2018-03-28T11:11:13.194-0400 DEBUG [beat] instance/beat.go:230 Initializing output plugins
2018-03-28T11:11:13.194-0400 DEBUG [processors] processors/processor.go:49 Processors:
2018-03-28T11:11:13.195-0400 INFO elasticsearch/client.go:145 Elasticsearch url: http://atlptgelk-dev1:9200
2018-03-28T11:11:13.195-0400 INFO pipeline/module.go:76 Beat name: atlptgnag-dev1.turner.com
2018-03-28T11:11:13.195-0400 INFO instance/beat.go:301 filebeat start running.
2018-03-28T11:11:13.195-0400 INFO [monitoring] log/log.go:97 Starting metrics logging every 30s
2018-03-28T11:11:13.195-0400 DEBUG [registrar] registrar/registrar.go:88 Registry file set to: /var/lib/filebeat/registry
2018-03-28T11:11:13.196-0400 INFO registrar/registrar.go:108 Loading registrar data from /var/lib/filebeat/registry
2018-03-28T11:11:13.196-0400 INFO registrar/registrar.go:119 States Loaded from registrar: 17
2018-03-28T11:11:13.196-0400 INFO crawler/crawler.go:48 Loading Prospectors: 1
2018-03-28T11:11:13.196-0400 DEBUG [registrar] registrar/registrar.go:150 Starting Registrar
2018-03-28T11:11:13.196-0400 DEBUG [processors] processors/processor.go:49 Processors:
2018-03-28T11:11:13.196-0400 DEBUG [prospector] log/config.go:178 recursive glob enabled
2018-03-28T11:11:13.196-0400 DEBUG [prospector] log/prospector.go:120 exclude_files: []. Number of stats: 17
2018-03-28T11:11:13.197-0400 DEBUG [prospector] file/state.go:82 New state added for /var/log/boot.log
2018-03-28T11:11:13.197-0400 DEBUG [prospector] file/state.go:82 New state added for /var/log/vmware-vmsvc.log
2018-03-28T11:11:13.197-0400 DEBUG [prospector] file/state.go:82 New state added for /var/log/yum.log
2018-03-28T11:11:13.197-0400 DEBUG [registrar] registrar/registrar.go:200 Processing 1 events
2018-03-28T11:11:13.197-0400 DEBUG [prospector] log/prospector.go:141 Prospector with previous states loaded: 3
2018-03-28T11:11:13.197-0400 DEBUG [registrar] registrar/registrar.go:193 Registrar states cleaned up. Before: 17, After: 17
2018-03-28T11:11:13.197-0400 INFO log/prospector.go:111 Configured paths: [/var/log/*.log]
2018-03-28T11:11:13.197-0400 DEBUG [prospector] prospector/prospector.go:87 Starting prospector of type: log; ID: 11204088409762598069
2018-03-28T11:11:13.197-0400 DEBUG [registrar] registrar/registrar.go:228 Write registry file: /var/lib/filebeat/registry
2018-03-28T11:11:13.197-0400 DEBUG [cfgfile] cfgfile/reload.go:95 Checking module configs from: /etc/filebeat/modules.d/*.yml
2018-03-28T11:11:13.197-0400 DEBUG [cfgfile] cfgfile/cfgfile.go:143 Load config from file: /etc/filebeat/modules.d/icinga.yml
2018-03-28T11:11:13.197-0400 DEBUG [cfgfile] cfgfile/cfgfile.go:143 Load config from file: /etc/filebeat/modules.d/system.yml
2018-03-28T11:11:13.197-0400 DEBUG [cfgfile] cfgfile/reload.go:109 Number of module configs found: 2
2018-03-28T11:11:13.198-0400 DEBUG [registrar] registrar/registrar.go:253 Registry file updated. 17 states written.
2018-03-28T11:11:13.198-0400 DEBUG [registrar] registrar/registrar.go:200 Processing 1 events
2018-03-28T11:11:13.198-0400 DEBUG [registrar] registrar/registrar.go:193 Registrar states cleaned up. Before: 17, After: 17
2018-03-28T11:11:13.198-0400 DEBUG [registrar] registrar/registrar.go:228 Write registry file: /var/lib/filebeat/registry
2018-03-28T11:11:13.199-0400 DEBUG [registrar] registrar/registrar.go:253 Registry file updated. 17 states written.
2018-03-28T11:11:13.199-0400 DEBUG [registrar] registrar/registrar.go:200 Processing 1 events
2018-03-28T11:11:13.199-0400 DEBUG [registrar] registrar/registrar.go:193 Registrar states cleaned up. Before: 17, After: 17
2018-03-28T11:11:13.199-0400 DEBUG [registrar] registrar/registrar.go:228 Write registry file: /var/lib/filebeat/registry
2018-03-28T11:11:13.199-0400 DEBUG [processors] processors/processor.go:49 Processors:
2018-03-28T11:11:13.199-0400 DEBUG [prospector] log/config.go:178 recursive glob enabled
2018-03-28T11:11:13.200-0400 DEBUG [prospector] log/prospector.go:120 exclude_files: [(?-s:.)gz(?-m:$)]. Number of stats: 17
2018-03-28T11:11:13.200-0400 DEBUG [prospector] log/prospector.go:147 Start next scan
2018-03-28T11:11:13.200-0400 DEBUG [registrar] registrar/registrar.go:253 Registry file updated. 17 states written.
2018-03-28T11:11:13.201-0400 DEBUG [prospector] file/state.go:82 New state added for /var/log/icinga2/debug.log-20180328
2018-03-28T11:11:13.201-0400 DEBUG [prospector] file/state.go:82 New state added for /var/log/icinga2/debug.log
2018-03-28T11:11:13.201-0400 DEBUG [prospector] log/prospector.go:141 Prospector with previous states loaded: 2
2018-03-28T11:11:13.201-0400 INFO log/prospector.go:111 Configured paths: [/var/log/icinga2/debug.log*]
2018-03-28T11:11:13.201-0400 DEBUG [processors] processors/processor.go:49 Processors:
2018-03-28T11:11:13.201-0400 DEBUG [registrar] registrar/registrar.go:200 Processing 1 events
2018-03-28T11:16:02.143-0400 INFO instance/beat.go:468 Home path: [/usr/share/filebeat] Config path: [/etc/filebeat] Data path: [/var/lib/filebeat] Logs path: [/var/log/filebeat]
2018-03-28T11:16:02.143-0400 INFO instance/beat.go:475 Beat UUID: 86e97091-703c-4735-b170-fc2c435279bb
2018-03-28T11:16:02.143-0400 INFO instance/beat.go:213 Setup Beat: filebeat; Version: 6.2.3
2018-03-28T11:16:02.143-0400 INFO elasticsearch/client.go:145 Elasticsearch url: http://atlptgelk-dev1:9200
2018-03-28T11:16:02.144-0400 INFO pipeline/module.go:76 Beat name: atlptgnag-dev1.turner.com
2018-03-28T11:16:02.144-0400 INFO [monitoring] log/log.go:97 Starting metrics logging every 30s
2018-03-28T11:16:02.144-0400 INFO instance/beat.go:301 filebeat start running.
2018-03-28T11:16:02.144-0400 INFO registrar/registrar.go:108 Loading registrar data from /var/lib/filebeat/registry
2018-03-28T11:16:02.145-0400 INFO registrar/registrar.go:119 States Loaded from registrar: 17
2018-03-28T11:16:02.145-0400 INFO crawler/crawler.go:48 Loading Prospectors: 1
2018-03-28T11:16:02.146-0400 INFO log/prospector.go:111 Configured paths: [/var/log/*.log]
2018-03-28T11:16:02.149-0400 INFO log/prospector.go:111 Configured paths: [/var/log/icinga2/debug.log*]
2018-03-28T11:16:02.150-0400 INFO log/prospector.go:111 Configured paths: [/var/log/icinga2/icinga2.log*]
2018-03-28T11:16:02.151-0400 INFO log/prospector.go:111 Configured paths: [/var/log/icinga2/startup.log]
2018-03-28T11:16:02.157-0400 INFO log/prospector.go:111 Configured paths: [/var/log/auth.log* /var/log/secure*]
2018-03-28T11:16:02.161-0400 INFO log/prospector.go:111 Configured paths: [/var/log/messages* /var/log/syslog*]
2018-03-28T11:16:02.161-0400 INFO crawler/crawler.go:82 Loading and starting Prospectors completed. Enabled prospectors: 1
2018-03-28T11:16:02.161-0400 INFO cfgfile/reload.go:127 Config reloader started
2018-03-28T11:16:02.165-0400 INFO log/prospector.go:111 Configured paths: [/var/log/icinga2/debug.log*]
2018-03-28T11:16:02.167-0400 INFO log/prospector.go:111 Configured paths: [/var/log/icinga2/icinga2.log*]
2018-03-28T11:16:02.167-0400 INFO log/prospector.go:111 Configured paths: [/var/log/icinga2/startup.log]
2018-03-28T11:16:02.173-0400 INFO log/prospector.go:111 Configured paths: [/var/log/auth.log* /var/log/secure*]
2018-03-28T11:16:02.183-0400 INFO log/prospector.go:111 Configured paths: [/var/log/messages* /var/log/syslog*]
2018-03-28T11:16:02.183-0400 INFO cfgfile/reload.go:258 Starting 2 runners ...
2018-03-28T11:16:02.183-0400 INFO elasticsearch/client.go:145 Elasticsearch url: http://atlptgelk-dev1:9200
2018-03-28T11:16:02.187-0400 INFO elasticsearch/client.go:690 Connected to Elasticsearch version 6.2.3
2018-03-28T11:16:02.191-0400 INFO elasticsearch/client.go:145 Elasticsearch url: http://atlptgelk-dev1:9200
2018-03-28T11:16:02.191-0400 INFO log/harvester.go:216 Harvester started for file: /var/log/icinga2/debug.log
2018-03-28T11:16:02.191-0400 INFO log/harvester.go:216 Harvester started for file: /var/log/icinga2/icinga2.log
2018-03-28T11:16:02.194-0400 INFO elasticsearch/client.go:690 Connected to Elasticsearch version 6.2.3
2018-03-28T11:16:02.198-0400 INFO cfgfile/reload.go:219 Loading of config files completed.
2018-03-28T11:16:03.195-0400 INFO elasticsearch/client.go:690 Connected to Elasticsearch version 6.2.3
2018-03-28T11:16:03.197-0400 INFO template/load.go:73 Template already exists and will not be overwritten.
2018-03-28T11:16:22.200-0400 INFO log/harvester.go:216 Harvester started for file: /var/log/secure
2018-03-28T11:16:32.146-0400 INFO [monitoring] log/log.go:124 Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":30,"time":38},"total":{"ticks":110,"time":120,"value":110},"user":{"ticks":80,"time":82}},"info":{"ephemeral_id":"c047f3b7-3f32-41da-aa2d-449cc7f66425","uptime":{"ms":30012}},"memstats":{"gc_next":4199840,"memory_alloc":2669280,"memory_total":13158672,"rss":18026496}},"filebeat":{"events":{"added":218,"done":218},"harvester":{"open_files":3,"running":3,"started":3}},"libbeat":{"config":{"module":{"running":2,"starts":2},"reloads":1},"output":{"events":{"acked":184,"batches":24,"total":184},"read":{"bytes":13216},"type":"elasticsearch","write":{"bytes":112489}},"pipeline":{"clients":11,"events":{"active":0,"filtered":34,"published":184,"retry":11,"total":218},"queue":{"acked":184}}},"registrar":{"states":{"current":17,"update":218},"writes":58},"system":{"cpu":{"cores":2},"load":{"1":0,"15":0.05,"5":0.01,"norm":{"1":0,"15":0.025,"5":0.005}}}}}}
It seems like that you've run Filebeat before, because it has a registry file. Are you sure you haven't had Filebeat send those logs before? Filebeat does not reread event which had been sent already to the output.
I have started the filebeat service before. I've checked all my indexes and I don't see any information from the syslog, nor any new information from it.
You could try to check if your data/registry
if the logfiles of icinga are present or not.
Looks like they are there ?
{
"source": "\/var\/log\/icinga2\/icinga2.log",
"offset": 440055,
"timestamp": "2018-03-28T12:49:13.606248672-04:00",
"ttl": -1,
"type": "log",
"FileStateOS": {
"inode": 68021964,
"device": 2051
}
},
{
"source": "\/var\/log\/messages",
"offset": 204070,
"timestamp": "2018-03-28T12:44:26.5957917-04:00",
"ttl": -1,
"type": "log",
"FileStateOS": {
"inode": 67551084,
"device": 2051
}
},
This means that Filebeat have already processed these files. You could delete these entries, if you want Filebeat to reread the whole files.
So just noticed a new index and I'm getting the following when I look at it in Kibana. Think it's anyway related ?
|@timestamp| |March 28th 2018, 10:01:15.321|
|---|---|---|
|t @version| |1|
|t _id| |IhbpbGIB6hgWxpLsqUug|
|t _index| |%{[@metadata][beat]}-2018.03.28|
|# _score| | - |
|t _type| |%{[@metadata][type]}|
|# facility| |0|
|t facility_label| |kernel|
|t host| |10.185.165.30|
|t message| |\aNHHP\u000EN\xE2\xA6Y\xECNd\xBB\x91\xAA\xAA\xFF\u001D\xD1 Q8\u0010W\x8B\x9C\xE5^՚\xE7}\xE6\xCD$\xEF\t!\u0001!Au\x80\xA5\xED\x940\x96\xAB\u001E\u0018$\x8B\xB8\xBCZ\xA4WI\xF11.X\x9E\xB0\xAC\x8C\xE28\xFF\f\u0014\x96JX\xDEpˁ\u001D\xA0\u0012\xDC\u0002\x83u'E%\xB8\u0005\n|
|# priority| |0|
|# severity| |0|
|t severity_label| |Emergency|
|t syslog_facility| |user-level|
|# syslog_facility_code| |1|
|t syslog_severity| |notice|
|# syslog_severity_code| |5|
|t tags| |_grokparsefailure_sysloginput, _grokparsefailure|
|t type| |syslog|
it's possible that your logs are not matching the Grok pattern in the pipeline of icinga. Could you share example logs?
Sure think. Snippet below.
Mar 28 12:42:05 atlptgnag-dev1 systemd: Started Session 5602 of user root.
Mar 28 12:42:05 atlptgnag-dev1 systemd-logind: New session 5602 of user root.
Mar 28 12:42:05 atlptgnag-dev1 systemd: Starting Session 5602 of user root.
Mar 28 12:42:05 atlptgnag-dev1 dbus[560]: [system] Activating service name='org.freedesktop.problems' (using servicehelper)
Mar 28 12:42:05 atlptgnag-dev1 dbus-daemon: dbus[560]: [system] Activating service name='org.freedesktop.problems' (using servicehelper)
Mar 28 12:42:05 atlptgnag-dev1 dbus[560]: [system] Successfully activated service 'org.freedesktop.problems'
Mar 28 12:42:05 atlptgnag-dev1 dbus-daemon: dbus[560]: [system] Successfully activated service 'org.freedesktop.problems'
Mar 28 12:44:15 atlptgnag-dev1 systemd: Stopping filebeat...
Mar 28 12:44:15 atlptgnag-dev1 systemd: Stopped filebeat.
Mar 28 12:50:01 atlptgnag-dev1 systemd: Started Session 5603 of user root.
Mar 28 12:50:01 atlptgnag-dev1 systemd: Starting Session 5603 of user root.
That reminds me. Why don't you use icinga module of Filebeat instead of system?
Ah I am =) the Icinga module is working correctly to pull Icinga logs. The system Module is not pulling the system logs at all, thats the issues im running into =(
Ok I feel stupid for not realizing this earlier.
System module is sending data like it should and it is being logged, it looks like a time and date issues ( I never went more than 4 hours back and being Eastern Time UTC is -5:00 ) So the question is now. Why are time stamps being saved as two different times and dates in Elastic. Is this a configuration issue somewhere else ? Posted a snippet noticed the @timestamp is 11:00 and the Time in the syslog is 15:00 with a -4 ? )
Again sorry for my newbieness
|@timestamp| |March 28th 2018, 11:00:23.000|
|---|---|---|
|t _id| |qZL7bWIBXBZ59wnDnxoL|
|t _index| |filebeat-6.2.3-2018.03.28|
|# _score| | - |
|t _type| |doc|
|t beat.hostname| |atlptgnagdb-01|
|t beat.name| |atlptgnagdb-01|
|t beat.version| |6.2.3|
|t fileset.module| |system|
|t fileset.name| |syslog|
|# offset| |823,506|
|t prospector.type| |log|
|t source| |/var/log/syslog|
|t system.syslog.hostname| |atlptgnagdb-01|
|t system.syslog.message| |[httpd] 10.185.165.146 - icinga [28/Mar/2018:15:00:23 -0400] "POST /write?db=icinga&p=%5BREDACTED%5D&precision=s&u=icinga HTTP/1.1" 204 0 "-" "Icinga/r2.8.0-1" 44c760ac-32ba-11e8-8613-000000000000 4843|
|t system.syslog.pid| |1130|
|t system.syslog.program| |influxd|
|t system.syslog.timestamp| |Mar 28 15:00:23|
@timestamp
is added by Filebeat. This value is the time the log was read. system.syslog.timestamp
contains the timestamp in the log. It can be different in multiple cases. E.g you send old logs to ES or the hosts of Filebeat and Elasticsearch are in different time zones.
Interesting. Looks like this continued to happen overnight to all the current logs, not just the ones previously ingested by filebeat, everything seems 5 hours in the past. As for the physical systems they are on the same Vmfarm connected to the same NTP server and all appear to be in sync.
Going to try this from the manual and let you know what i find.
var.convert_timezone
If this option is enabled, Filebeat reads the local timezone and uses it at log parsing time to convert the timestamp to UTC. The local timezone is also added in each event in a dedicated field (beat.timezone). The conversion is only possible in Elasticsearch >= 6.1. If the Elasticsearch version is less than 6.1, the beat.timezone field is added, but the conversion to UTC is not made. The default is false.
Ah that didn't help. Any other thoughts on why the data would be shown 4 hours behind ?
Hey guys found a solution to my latest issue from this thread. Thank all yall for the help. Marking as solved.
This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.
© 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.