Need help with setting up Apache2 to monitor the session time on every website

@magnusbaeck

Hi Magnus,

How are you doing? Wondering if you can help troubleshooting, is there any debugger I can use to find out what is stopping me from getting the login and logout time from Apache websites to Kibana?

Thanks!
Weng Sheng

I guess no one from Elastic can help on this? Right?

I moved your question to #beats:filebeat so someone from the team might be able to help.

Thanks David!

If anyone can help resolving this I'd be appreciated.

I have read the thread and I have seen you have shared various snippets of your configuration. I have also seen that you have already ran configtest. Do you mind sharing your full configuration formatted using </>? It helps us to find if there are any problems which cannot be detected by configtest. Also, it would be nice if you could share the output of ./filebeat -e -d "*".

I don't know how can you get the full config with the </> format, would u mind to show me such as what command should i run? I've reinstalled the filebeat because the previous filebeat version gave me issue, and im still not able to see the data on Apache. Just fyi, for security reason I've removed the hostname from the log.

Here's the output:

[root@m ~]# filebeat -configtest -e
Flag --configtest has been deprecated, use test config subcommand
2018-10-07T15:42:28.489-0500 INFO instance/beat.go:544 Home path: [/usr/share/filebeat] Config path: [/etc/filebeat] Data path: [/var/lib/filebeat] Logs path: [/var/log/filebeat]
2018-10-07T15:42:28.489-0500 INFO instance/beat.go:551 Beat UUID: f42611a8-fa1b-4f0e-a4c9-a6132391f6d6
2018-10-07T15:42:28.489-0500 INFO [seccomp] seccomp/seccomp.go:116 Syscall filter successfully installed
2018-10-07T15:42:28.489-0500 INFO [beat] instance/beat.go:768 Beat info {"system_info": {"beat": {"path": {"config": "/etc/filebeat", "data": "/var/lib/filebeat", "home": "/usr/share/filebeat", "logs": "/var/log/filebeat"}, "type": "filebeat", "uuid": "f42611a8-fa1b-4f0e-a4c9-a6132391f6d6"}}}
2018-10-07T15:42:28.489-0500 INFO [beat] instance/beat.go:777 Build info {"system_info": {"build": {"commit": "37b5f2d2a20f2734b2373a454b4b4cbb2627e841", "libbeat": "6.4.1", "time": "2018-09-13T21:25:47.000Z", "version": "6.4.1"}}}
2018-10-07T15:42:28.489-0500 INFO [beat] instance/beat.go:780 Go runtime info {"system_info": {"go": {"os":"linux","arch":"amd64","max_procs":40,"version":"go1.10.3"}}}
2018-10-07T15:42:28.492-0500 INFO [beat] instance/beat.go:784 Host info {"system_info": {"host": {"architecture":"x86_64","boot_time":"2018-10-03T19:57:18-05:00","containerized":true,"hostname":"","ips":["127.0.0.1/8","172./24","10./24"],"kernel_version":"3.10.0-862.11.6.el7.x86_64","mac_addresses":["0c:c4:7a:a4:af:38","0c:c4:7a:a4:af:39","0c:c4:7a:a4:af:3a","0c:c4:7a:a4:af:3b"],"os":{"family":"redhat","platform":"centos","name":"CentOS Linux","version":"7 (Core)","major":7,"minor":5,"patch":1804,"codename":"Core"},"timezone":"CDT","timezone_offset_sec":-18000,"id":"6a3d2b9ac5c84886b1742ba99b6c145c"}}}
2018-10-07T15:42:28.492-0500 INFO [beat] instance/beat.go:813 Process info {"system_info": {"process": {"capabilities": {"inheritable":null,"permitted":["chown","dac_override","dac_read_search","fowner","fsetid","kill","setgid","setuid","setpcap","linux_immutable","net_bind_service","net_broadcast","net_admin","net_raw","ipc_lock","ipc_owner","sys_module","sys_rawio","sys_chroot","sys_ptrace","sys_pacct","sys_admin","sys_boot","sys_nice","sys_resource","sys_time","sys_tty_config","mknod","lease","audit_write","audit_control","setfcap","mac_override","mac_admin","syslog","wake_alarm","block_suspend"],"effective":["chown","dac_override","dac_read_search","fowner","fsetid","kill","setgid","setuid","setpcap","linux_immutable","net_bind_service","net_broadcast","net_admin","net_raw","ipc_lock","ipc_owner","sys_module","sys_rawio","sys_chroot","sys_ptrace","sys_pacct","sys_admin","sys_boot","sys_nice","sys_resource","sys_time","sys_tty_config","mknod","lease","audit_write","audit_control","setfcap","mac_override","mac_admin","syslog","wake_alarm","block_suspend"],"bounding":["chown","dac_override","dac_read_search","fowner","fsetid","kill","setgid","setuid","setpcap","linux_immutable","net_bind_service","net_broadcast","net_admin","net_raw","ipc_lock","ipc_owner","sys_module","sys_rawio","sys_chroot","sys_ptrace","sys_pacct","sys_admin","sys_boot","sys_nice","sys_resource","sys_time","sys_tty_config","mknod","lease","audit_write","audit_control","setfcap","mac_override","mac_admin","syslog","wake_alarm","block_suspend"],"ambient":null}, "cwd": "/root", "exe": "/usr/share/filebeat/bin/filebeat", "name": "filebeat", "pid": 7644, "ppid": 7294, "seccomp": {"mode":"filter"}, "start_time": "2018-10-07T15:42:27.580-0500"}}}
2018-10-07T15:42:28.492-0500 INFO instance/beat.go:273 Setup Beat: filebeat; Version: 6.4.1
2018-10-07T15:42:28.493-0500 INFO pipeline/module.go:98 Beat name:
2018-10-07T15:42:28.493-0500 WARN [cfgwarn] beater/filebeat.go:78 DEPRECATED: prospectors are deprecated, Use inputs instead. Will be removed in version: 7.0.0
2018-10-07T15:42:28.493-0500 WARN [cfgwarn] instance/beat.go:348 DEPRECATED: -configtest flag has been deprecated, use configtest subcommand Will be removed in version: 6.0
Config OK
2018-10-07T15:42:28.493-0500 INFO [monitoring] log/log.go:114 Starting metrics logging every 30s
2018-10-07T15:42:28.495-0500 INFO [monitoring] log/log.go:149 Total non-zero metrics {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":10,"time":{"ms":14}},"total":{"ticks":20,"time":{"ms":28},"value":20},"user":{"ticks":10,"time":{"ms":14}}},"info":{"ephemeral_id":"40056ca7-99aa-4c75-ad05-4b43468eb3ba","uptime":{"ms":14}},"memstats":{"gc_next":4194304,"memory_alloc":2896360,"memory_total":4353632,"rss":13975552}},"filebeat":{"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"output":{"type":"logstash"},"pipeline":{"clients":0,"events":{"active":0}}},"registrar":{"states":{"current":0}},"system":{"cpu":{"cores":40},"load":{"1":1.27,"15":2.06,"5":2.14,"norm":{"1":0.0318,"15":0.0515,"5":0.0535}}}}}}
2018-10-07T15:42:28.495-0500 INFO [monitoring] log/log.go:150 Uptime: 15.792154ms
2018-10-07T15:42:28.495-0500 INFO [monitoring] log/log.go:127 Stopping metrics logging.

Here's the output of filebeat -e -d *

2018-10-07T15:41:05.185-0500 DEBUG [registrar] registrar/registrar.go:393 Registry file updated. 1635 states written.
2018-10-07T15:41:05.185-0500 DEBUG [registrar] registrar/registrar.go:345 Processing 1 events
2018-10-07T15:41:05.185-0500 DEBUG [registrar] registrar/registrar.go:315 Registrar state updates processed. Count: 1
2018-10-07T15:41:05.185-0500 DEBUG [acker] beater/acker.go:64 stateful ack {"count": 1}
2018-10-07T15:41:05.185-0500 DEBUG [registrar] registrar/registrar.go:335 Registrar states cleaned up. Before: 1635, After: 1635, Pending: 0
2018-10-07T15:41:05.186-0500 DEBUG [registrar] registrar/registrar.go:400 Write registry file: /var/lib/filebeat/registry
2018-10-07T15:41:05.192-0500 DEBUG [registrar] registrar/registrar.go:393 Registry file updated. 1635 states written.
2018-10-07T15:41:05.192-0500 DEBUG [registrar] registrar/registrar.go:345 Processing 1 events

Can you tell me what are you looking for from the config? What if config has no issue?

Thanks!

Unfortunately, configtest lacks a few checks to validate whether your config is correct. So if the test returns Config OK, it is still possible that your configuration is incorrect and the Beat fails.

You need co copy your config here and click on the button on this UI which looks like </> to get it preserve whitespaces.

Could you provide more debug logs? From this snippet I can see that 1 event was processed, but there is nothing about what happened to that event.

First of all, thank you for getting back to me, can you tell me what command i need to run to get u the output you want? The logs are too long to paste here, is there any specific information you need from the log?

When i ran filebeat -e -d "*", it kept printing the following, i can't paste all the log here because the logs are huge:

2018-10-09T17:48:58.275-0500 DEBUG [registrar] registrar/registrar.go:400 Write registry file: /var/lib/filebeat/registry
2018-10-09T17:48:58.281-0500 DEBUG [registrar] registrar/registrar.go:393 Registry file updated. 1636 states written.
2018-10-09T17:48:58.281-0500 DEBUG [registrar] registrar/registrar.go:345 Processing 1 events
2018-10-09T17:48:58.281-0500 DEBUG [registrar] registrar/registrar.go:315 Registrar state updates processed. Count: 1
2018-10-09T17:48:58.281-0500 DEBUG [registrar] registrar/registrar.go:335 Registrar states cleaned up. Before: 1636, After: 1636, Pending: 0
2018-10-09T17:48:58.281-0500 DEBUG [registrar] registrar/registrar.go:400 Write registry file: /var/lib/filebeat/registry
2018-10-09T17:48:58.286-0500 DEBUG [registrar] registrar/registrar.go:393 Registry file updated. 1636 states written.
2018-10-09T17:48:58.286-0500 DEBUG [registrar] registrar/registrar.go:345 Processing 1 events
2018-10-09T17:48:58.287-0500 DEBUG [registrar] registrar/registrar.go:315 Registrar state updates processed. Count: 1
2018-10-09T17:48:58.287-0500 DEBUG [registrar] registrar/registrar.go:335 Registrar states cleaned up. Before: 1636, After: 1636, Pending: 0
2018-10-09T17:48:58.287-0500 DEBUG [registrar] registrar/registrar.go:400 Write registry file: /var/lib/filebeat/registry
2018-10-09T17:48:58.292-0500 DEBUG [registrar] registrar/registrar.go:393 Registry file updated. 1636 states written.
2018-10-09T17:48:58.371-0500 INFO log/input.go:453 Scan aborted because input stopped.
2018-10-09T17:48:58.371-0500 DEBUG [input] log/input.go:195 input states cleaned up. Before: 1624, After: 1624, Pending: 0
2018-10-09T17:48:58.377-0500 INFO input/input.go:149 input ticker stopped
2018-10-09T17:48:58.377-0500 INFO input/input.go:167 Stopping Input: 17756035840838206192
2018-10-09T17:48:58.377-0500 DEBUG [publish] pipeline/client.go:148 client: closing acker
2018-10-09T17:48:58.377-0500 DEBUG [publish] pipeline/client.go:150 client: done closing acker
2018-10-09T17:48:58.377-0500 DEBUG [publish] pipeline/client.go:154 client: cancelled 0 events
2018-10-09T17:48:58.377-0500 INFO crawler/crawler.go:165 Crawler stopped
2018-10-09T17:48:58.377-0500 INFO registrar/registrar.go:356 Stopping Registrar
2018-10-09T17:48:58.377-0500 INFO registrar/registrar.go:282 Ending Registrar
2018-10-09T17:48:58.377-0500 DEBUG [registrar] registrar/registrar.go:400 Write registry file: /var/lib/filebeat/registry
2018-10-09T17:48:58.383-0500 DEBUG [registrar] registrar/registrar.go:393 Registry file updated. 1636 states written.
2018-10-09T17:48:58.385-0500 INFO [monitoring] log/log.go:149 Total non-zero metrics {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1990,"time":{"ms":1993}},"total":{"ticks":14100,"time":{"ms":14103},"value":14100},"user":{"ticks":12110,"time":{"ms":12110}}},"info":{"ephemeral_id":"29a9d48f-80f3-4d2f-8125-44fdebf7cb91","uptime":{"ms":9971}},"memstats":{"gc_next":6429904,"memory_alloc":4561008,"memory_total":1584238744,"rss":20242432}},"filebeat":{"events":{"added":1624,"done":1624},"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"output":{"type":"logstash"},"pipeline":{"clients":0,"events":{"active":0,"filtered":1624,"total":1624}}},"registrar":{"states":{"current":1636,"update":1624},"writes":{"fail":7,"success":1618,"total":1625}},"system":{"cpu":{"cores":40},"load":{"1":3.91,"15":2.6,"5":2.9,"norm":{"1":0.0978,"15":0.065,"5":0.0725}}}}}}
2018-10-09T17:48:58.385-0500 INFO [monitoring] log/log.go:150 Uptime: 9.972900824s
2018-10-09T17:48:58.385-0500 INFO [monitoring] log/log.go:127 Stopping metrics logging.
2018-10-09T17:48:58.385-0500 INFO instance/beat.go:373 filebeat stopped.

I had to stop the process otherwise it won't stop printing, can you tell me what are you looking for to help you for investigation?

Thanks!
Lee

I looked at the your logs to see if the Beat is publishing any events. It did not at the time when the logs were produced. Then I looked at the report the Beat provides about itself. Now I know that it had read 1624 events (from metrics.pipeline.events.total) and it filtered out all of them (metrics.pipeline.events.filtered). You also have zero open files which means that Filebeat is not reading anything currently (metrics.filebeat.harvester.open_files and metrics.filebeat.harvester.running). I can see that you have enabled Logstash output (metrics.libbeat.config.output).

You don't need to run any specific command to get your config. Just copy the contents of the file here and format it using the button which looks like this: </> in the toolbar of the editor.

Do you want to use apache module of Filebeat? If yes, you need to forward events to Elasticsearch, not Logstash. Also, do you have any filtering processors configured? It seems that all of your messages are filtered out.

In order to use modules you need to setup a few things in Elasticsearch and Kibana. This can be done by running ./filebeat setup -modules=apache2.

This is a minimal example config which collects apache logs from your host and forwards it to Elasticsearch (after you run setup).

filebeat.modules:
- module: apache2
  enabled: true
  var.paths: ["path/to/your/logs"]

output.elasticsearch:
  hosts: ["localhost:9200"]

can i use logstash and filebeat at the same time? I can't find </> on the UI on Kibana, can you show me where it's located?

If you want to use Filebeat modules, you don't need Logstash. You need to forward logs to Elasticsearch where the input logs are processed.

The button you are looking for is on this site in this editor you are typing your responses to me. Not on Kibana.

Selection_001

Here's the log you need, please tell me what else i need to do to get filebeat installed correctly, I can't paste everything in this email, it only limit me 7000words

[root@m filebeat]# /usr/share/filebeat/bin/filebeat -e -d *
2018/10/23 02:52:50.070113 beat.go:297: INFO Home path: [/usr/share/filebeat/bin ] Config path: [/usr/share/filebeat/bin] Data path: [/usr/share/filebeat/bin/dat a] Logs path: [/usr/share/filebeat/bin/logs]
2018/10/23 02:52:50.070160 beat.go:192: INFO Setup Beat: filebeat; Version: 5.6.
2018/10/23 02:52:50.563101 log.go:91: INFO Harvester started for file: /data/dev ice_logs/10.73.86.38/10.73.86.38-sys.log
2018/10/23 02:52:50.564638 log.go:91: INFO Harvester started for file: /data/dev ice_logs/10.184.170.43/10.184.170.43-sys.log
2018/10/23 02:52:50.564931 log.go:91: INFO Harvester started for file: /data/dev ice_logs/10.81.52.25/10.81.52.25-sys.log
2018/10/23 02:52:50.570502 log.go:91: INFO Harvester started for file: /data/dev ice_logs/10.184.170.42/10.184.170.42-sys.log ice_logs/10.143.212.57/10.143.212.57-sys.log ice_logs/10.148.7.104/10.148.7.104-sys.log ice_logs/10.51.39.254/10.51.39.254-sys.log
2018/10/23 02:52:50.721094 log.go:91: INFO Harvester started for file: /data/dev ice_logs/10.143.156.59/10.143.156.59-sys.log
2018/10/23 02:53:20.070478 metrics.go:39: INFO Non-zero metrics in the last 30s: filebeat.harvester.open_files=308 filebeat.harvester.running=308 filebeat.harve ster.started=308 libbeat.es.call_count.PublishEvents=5460 libbeat.es.publish.rea d_bytes=2593574 libbeat.es.publish.write_bytes=138225028 libbeat.es.published_an d_acked_events=272585 libbeat.publisher.published_events=273383 publish.events=2 76480 registrar.states.current=4837 registrar.states.update=276480 registrar.wri tes=135
2018/10/23 02:53:50.070467 metrics.go:39: INFO Non-zero metrics in the last 30s: libbeat.es.call_count.PublishEvents=5757 libbeat.es.publish.read_bytes=2734493 libbeat.es.publish.write_bytes=146359215 libbeat.es.published_and_acked_events=287568 libbeat.publisher.published_events=288768 publish.events=288768 registrar.states.update=287083 registrar.writes=140
2018/10/23 02:54:50.070452 metrics.go:39: INFO Non-zero metrics in the last 30s: libbeat.es.call_count.PublishEvents=5415 libbeat.es.publish.read_bytes=2574183 libbeat.es.publish.write_bytes=140734431 libbeat.es.published_and_acked_events=270486 libbeat.publisher.published_events=270336 publish.events=270336 registrar.states.update=270336 registrar.writes=132

indent preformatted text by 4 spaces

This is where i can see the modules. Please let me know what else you need in order for us to setup apache2 on filebeat correctly

[root@m module]# pwd
/usr/share/filebeat/module
[root@m module]# ls
apache2 auditd elasticsearch icinga iis kafka kibana logstash mongodb mysql nginx osquery postgresql redis system traefik

I tried to look for the config and put in

@timestamp October 22nd 2018, 22:01:37.652
t _id AWae3t1xFZ3vcM5d0Afo
t _index filebeat-2018.10.23
# _score -
t _type doc
t beat.hostname m.
t beat.name m.
t beat.version 5.6.12
t input_type log
t message Oct 22 20:01:22 2 crontab[25369]: (root) LIST (root)
# offset 1,033,270
t source /data/device_logs/10./10.-sys.log
t type log

The filebeat did show data, but not not showing Apache module:

I'm looking for result like this:
https://www.elastic.co/guide/en/beats/packetbeat/current/kibana-queries-filters.html

[root@ ~]# /usr/share/filebeat/bin/filebeat modules
filebeat2018/10/23 04:03:38.641766 beat.go:346: CRIT Exiting: error loading config file: stat filebeat.yml: no such file or directory
Exiting: error loading config file: stat filebeat.yml: no such file or directory
[root@01 ~]#

This error occured when we attempt to run ./filebeat modules list or ./filebeat modules enable apache2:

[root@ ~]# /usr/share/filebeat/bin/filebeat modules
filebeat2018/10/23 04:03:38.641766 beat.go:346: CRIT Exiting: error loading config file: stat filebeat.yml: no such file or directory
Exiting: error loading config file: stat filebeat.yml: no such file or directory
[root@01 ~]#

Have you moved your configuration file? You can set the path to the folder of the config file using --path.config.