lack of logging running as service on Ubuntu

[LeeDr]

Please post all questions and issues on https://discuss.elastic.co/c/beats
before opening a Github Issue. Your questions will reach a wider audience there,
and if we confirm that there is a bug, then you can open a new issue.

For confirmed bugs, please report:

• Version: 5.0.0-alpha3 (from https://download.elastic.co/beats/packetbeat/packetbeat-5.0.0-alpha3-SNAPSHOT-amd64.deb)
• Operating System: Ubuntu 15.10 64-bit
• Steps to Reproduce:

1. Install alpha3 elasticsearch and x-pack on Ubuntu
2. wget https://download.elastic.co/beats/packetbeat/packetbeat-5.0.0-alpha3-SNAPSHOT-amd64.deb
3. dpkg -i packetbeat-5.0.0-alpha3-SNAPSHOT-amd64.deb

4. don't put elasticsearch username and password in packetbeat.yml file

5. service packetbeat start
6. journalctl -u packetbeat.service

7. I started and stopped packetbeat service several times. It never created an index, but it also didn't log anything about the problem. It also fails to stop nicely;

journalctl -u packetbeat.service
May 25 12:22:59 U14K systemd[1]: Started packetbeat.
May 25 16:04:06 U14K systemd[1]: Stopping packetbeat...
May 25 16:05:36 U14K systemd[1]: packetbeat.service: State 'stop-sigterm' timed out. Killing.
May 25 16:05:36 U14K systemd[1]: packetbeat.service: Main process exited, code=killed, status=9/KILL
May 25 16:05:36 U14K systemd[1]: Stopped packetbeat.
May 25 16:05:36 U14K systemd[1]: packetbeat.service: Unit entered failed state.
May 25 16:05:36 U14K systemd[1]: packetbeat.service: Failed with result 'signal'.
May 25 16:05:36 U14K systemd[1]: Started packetbeat.
May 25 18:35:00 U14K systemd[1]: Stopping packetbeat...
May 25 18:36:31 U14K systemd[1]: packetbeat.service: State 'stop-sigterm' timed out. Killing.
May 25 18:36:31 U14K systemd[1]: packetbeat.service: Main process exited, code=killed, status=9/KILL
May 25 18:36:31 U14K systemd[1]: Stopped packetbeat.
May 25 18:36:31 U14K systemd[1]: packetbeat.service: Unit entered failed state.
May 25 18:36:31 U14K systemd[1]: packetbeat.service: Failed with result 'signal'.
May 25 19:45:01 U14K systemd[1]: Stopped packetbeat.

After I cp /etc/topbeat/topbeat.full.yml /etc/topbeat/topbeat.yml and set the username and password, packetbeat does create an index and loads docs.

And now it stops quickly and without timeouts.

Expected Result: packetbeat logs much more information including errors about authentication errors connecting to elasticsearch.

[LeeDr]

@ruflin this is the issue I hit again. Now I'm on 5.0 alpha4

I install the deb package on Ubuntu and start the service. The journal only has a line saying it started the service;

root@U14K:~/integration-test/install_scripts# journalctl -u packetbeat.service
... older messages cut ...
Jun 23 16:08:50 U14K systemd[1]: Started packetbeat.

And there's no logs;

root@U14K:~/integration-test/install_scripts# ls -l /var/log/filebeat/
total 0
root@U14K:~/integration-test/install_scripts# ls -l /var/log/metricbeat/
total 0
root@U14K:~/integration-test/install_scripts# ls -l /var/log/packetbeat/
total 0

Why don't I have any beats indexes in Elasticsearch? It's because I didn't set the auth config parameters.

What do I have to do to see messages about that?

#================================ Logging =====================================

# Sets log level. The default log level is error.
# Available log levels are: critical, error, warning, info, debug
#logging.level: debug

Once I change that from the default error to info I get the answer;

root@U14K:~/integration-test/install_scripts# cat /var/log/metricbeat/metricbeat 
2016-06-23T16:15:40-05:00 INFO Home path: [/usr/share/metricbeat] Config path: [/etc/metricbeat] Data path: [/var/lib/metricbeat] Logs path: [/var/log/metricbeat]
2016-06-23T16:15:40-05:00 INFO Register [ModuleFactory:[], MetricSetFactory:[apache/status, mongodb/status, mysql/status, nginx/stubstatus, redis/info, redis/keyspace, system/core, system/cpu, system/diskio, system/filesystem, system/fsstat, system/memory, system/network, system/process, zookeeper/mntr]]
2016-06-23T16:15:40-05:00 INFO Setup Beat: metricbeat; Version: 5.0.0-alpha4
2016-06-23T16:15:40-05:00 INFO Loading template enabled. Reading template file: /etc/metricbeat/metricbeat.template.json
2016-06-23T16:15:40-05:00 INFO Elasticsearch url: http://localhost:9200
2016-06-23T16:15:40-05:00 INFO Activated elasticsearch as output plugin.
2016-06-23T16:15:40-05:00 INFO Publisher name: U14K
2016-06-23T16:15:40-05:00 INFO Flush Interval set to: 1s
2016-06-23T16:15:40-05:00 INFO Max Bulk Size set to: 50
2016-06-23T16:15:40-05:00 INFO metricbeat start running.
2016-06-23T16:15:41-05:00 INFO Connecting error publishing events (retrying): 401 Unauthorized
2016-06-23T16:15:41-05:00 INFO send fail
2016-06-23T16:15:42-05:00 INFO Connecting error publishing events (retrying): 401 Unauthorized
2016-06-23T16:15:42-05:00 INFO send fail
2016-06-23T16:15:44-05:00 INFO Connecting error publishing events (retrying): 401 Unauthorized
2016-06-23T16:15:44-05:00 INFO send fail
2016-06-23T16:15:48-05:00 INFO Connecting error publishing events (retrying): 401 Unauthorized
2016-06-23T16:15:48-05:00 INFO send fail
2016-06-23T16:15:56-05:00 INFO Connecting error publishing events (retrying): 401 Unauthorized
2016-06-23T16:15:56-05:00 INFO send fail

I think it would be much more user friendly if we caught that 401 and logged it at error level so it would show up without having to change the log level.

Or, change the default log level from error to info like I did. Then the message would show up.

[ruflin]

@LeeDr Thanks for pinging us on this one again.
@tsg I think we should definitively for 5.0 switch the logging level to info. Any objections?

[tsg]

Yeah, agreed that we should. I still don't like that that is an INFO and not an ERR, but we can fix it either way. I'll take this one.

[ruflin]

@tsg I would suggest to fix both. Make the above and ERR and switch to INFO by default.