Refs #22559 - Add parameters for structured logging #631

ekohl · 2018-03-27T10:38:33Z

No description provided.

ekohl · 2018-03-27T10:40:26Z

This will also need code to install packages if any logger other than file is used.

lzap

Issue number must be 22559.

lzap · 2018-03-27T11:21:25Z

manifests/params.pp

@@ -253,6 +253,8 @@

  # Application logging
  $logging_level = 'info'
+  $logging_type = 'file'
+  $logging_layout = 'pattern'


Default was multiline_pattern, but I am fine with switching to pattern. The difference is that the former adds | characters at the beginning of each line, which is useful for development but in syslog/journald this might not be the best thing to do. So +1.

Was multiline_pattern also used before structured logging was introduced? I thought it was pattern so stayed with it here.

It was the default, yes. I mean for development setup, not sure about production, but we did not explicitly set it so it was the default (so yes)? I actually like pattern more than the other one - it's cleaner.

lzap · 2018-03-27T11:27:32Z

manifests/params.pp

@@ -253,6 +253,8 @@

  # Application logging
  $logging_level = 'info'
+  $logging_type = 'file'


This is indeed the most sane default - everything stays the same for production instance.

But logging to files is considered bad practice, except some corner cases (e.g. apache httpd access logs) using standard logging mechanisms should be preferred. I was hoping to default to journald (if present), syslog (otherwise) and just dropping /etc/rsyslog.d/foreman.conf configuration file and alerting daemon to reload (similarly for syslog-ng). If that's too complex in Puppet, we can just leave file logging for now.

This is indeed the most sane default - everything stays the same for production instance.

That was indeed exactly what I thought, also because I can't quite oversee what else is affected. Start with configuration options and safe defaults.

If journald is just drop in, we could use facts to determine if systemd is used. I'm hesitant to start managing syslog since that can be fairly complex and more up to the admin to set up. That's why I'd fall back to file if systemd is not used. My plan was to revisit the defaults later.

The question is how or when do we find out it's now safe to change the default, too bad didn't have this in the beginning of 1.18 dev window. Would it make sense to change the default just after we branch out?

I agree that we shouldn't manage syslog but dropping a oneliner to /etc/rsyslog.d/foreman.conf would be acceptable I think?

The question is how or when do we find out it's now safe to change the default, too bad didn't have this in the beginning of 1.18 dev window. Would it make sense to change the default just after we branch out?

For me it depends on whether journald is a drop in replacement:

Does journald also log to a file?

Can foreman-debug extract logs from journald?

I agree that we shouldn't manage syslog but dropping a oneliner to /etc/rsyslog.d/foreman.conf would be acceptable I think?

The difficulty is that we can't rely on any syslog implementation. I can imagine users are using syslog-ng for example. Then we also need to support that. Suddenly we have a few extra parameters for things that IMHO belong in a profile module. Will we manage the syslog daemon as well for example. We've worked hard to keep that out of puppet-foreman. It just doesn't fit the design. I really don't want to touch syslog at all.

Unfortunately, journald main idea is all around binary journal that can be sealed - there is no file logging in journald. It can however forward to syslog and that's what it does by default on most systems these days.

I will create patch for foreman-debug to collect the logs from there for sure.

If we don't want to touch syslog, then another option is to ditch /var/log/foreman/production.log completely. An installer could archive/rename all files in pattern production*.log* and drop a dummy file with short explanation that this is not used. I don't think this is a bad experience for users after upgrade at all. Things change.

Structured logging patch is not only about structured logging, but also about collecting things from other parties like backend systems or smart proxy. With files, we can't achieve that, but having things in journald allows us to start working towards this goal.

To me it sounds like we should talk to our users about their expectations because nowadays I'm somewhat removed from actual deployments. Should we open a topic on community.theforeman.org?

Yep, started it: https://community.theforeman.org/t/default-logging-in-foreman-file-syslog-or-journald/8675

ekohl · 2018-03-27T15:26:09Z

I've expanded the PR to include acceptance tests. This told me we don't have the foreman-journald package in RPM nightly yet so I'm going to focus on that. Locally the Debian 9 tests looked good. I'm still running a last test run because I had an incorrect text in my test, but expecting it to pass.

ekohl · 2018-03-27T15:56:29Z

Tests now pass locally:

debian-9-x64.example.com 17:54:52$ /bin/sh -c journalctl\ -u\ apache2
  -- Logs begin at Tue 2018-03-27 15:47:49 UTC, end at Tue 2018-03-27 15:54:51 UTC. --
  Mar 27 15:49:53 debian-9-x64.example.com systemd[1]: Starting The Apache HTTP Server...
  Mar 27 15:49:53 debian-9-x64.example.com systemd[1]: Started The Apache HTTP Server.
  Mar 27 15:53:48 debian-9-x64.example.com systemd[1]: Stopping The Apache HTTP Server...
  Mar 27 15:53:48 debian-9-x64.example.com systemd[1]: Stopped The Apache HTTP Server.
  Mar 27 15:53:48 debian-9-x64.example.com systemd[1]: Starting The Apache HTTP Server...
  Mar 27 15:53:48 debian-9-x64.example.com systemd[1]: Started The Apache HTTP Server.
  Mar 27 15:54:04 debian-9-x64.example.com foreman[18917]: [I|dyn|] start terminating throttle_limiter...
  Mar 27 15:54:04 debian-9-x64.example.com foreman[18917]: [I|dyn|] start terminating client dispatcher...
  Mar 27 15:54:04 debian-9-x64.example.com foreman[18917]: [I|dyn|] stop listening for new events...
  Mar 27 15:54:04 debian-9-x64.example.com foreman[18917]: [I|dyn|] start terminating clock...
  Mar 27 15:54:14 debian-9-x64.example.com foreman[18971]: [I|app|] Started HEAD "/" for 127.0.0.1 at 2018-03-27 15:54:14 +0000
  Mar 27 15:54:14 debian-9-x64.example.com foreman[18971]: [I|app|cc02b] Processing by DashboardController#index as HTML
  Mar 27 15:54:14 debian-9-x64.example.com foreman[18971]: [I|app|cc02b] Redirected to https://debian-9-x64.example.com/
  Mar 27 15:54:14 debian-9-x64.example.com foreman[18971]: [I|app|cc02b] Filter chain halted as #<Proc:0x00564bec4d09e8@/usr/share/foreman/vendor/ruby/2.3.0/gems/actionpack-5.1.4/lib/action_controller/metal/force_ssl.rb:65> rendered or redirected
  Mar 27 15:54:14 debian-9-x64.example.com foreman[18971]: [I|app|cc02b] Completed 301 Moved Permanently in 31ms (ActiveRecord: 8.1ms)
  Mar 27 15:54:14 debian-9-x64.example.com foreman[18971]: [I|app|] Started HEAD "/" for 127.0.0.1 at 2018-03-27 15:54:14 +0000
  Mar 27 15:54:14 debian-9-x64.example.com foreman[18971]: [I|app|54c81] Processing by DashboardController#index as HTML
  Mar 27 15:54:14 debian-9-x64.example.com foreman[18971]: [I|app|54c81] Redirected to https://debian-9-x64.example.com/users/login
  Mar 27 15:54:14 debian-9-x64.example.com foreman[18971]: [I|app|54c81] Filter chain halted as :require_login rendered or redirected
  Mar 27 15:54:14 debian-9-x64.example.com foreman[18971]: [I|app|54c81] Completed 302 Found in 42ms (ActiveRecord: 16.3ms)

debian-9-x64.example.com executed in 0.05 seconds
      should match /Redirected to https:\/\/debian-9-x64.example.com\/users\/login/

ekohl · 2018-04-09T11:18:44Z

With RPMs I have an issue with loading the gem. theforeman/foreman#5421 solves it for me.

Split off other commits in separate PRs that can be merged before this:

lzap · 2018-04-10T08:45:32Z

Shall I re-review now? 2/3 merged atm.

ekohl · 2018-04-10T08:56:21Z

@lzap previously the tests on Debian failed because it wasn't logging in a situation where it first used file logging and then moved to journald. I still want to reproduce this.

ekohl · 2018-04-10T10:25:45Z

@lzap looks like we have the same issue on CentOS in containers. Going to test it on a VM on my desktop now to see if I can reproduce it.

lzap · 2018-04-10T10:37:33Z

Oh interesting, no journald in container? It was designed to be container friendly, let's see.

ekohl · 2018-04-10T10:38:31Z

@lzap when i manually ran only the journald test it did work for me locally. On Travis it first installs a basic Foreman with file logging. It could be that the upgrade doesn't work.

ekohl · 2018-04-10T16:07:46Z

@lzap I know what the problem is. For the redirect log line I relied on the apache preloader to do a request but that isn't sent when you reload the app by touching restart.txt. I'll modify the tests to explicitly do a curl request to trigger a log line.

ekohl · 2018-04-10T16:54:50Z

Ready for re-review now.

ekohl · 2018-04-10T17:35:43Z

(Debian tests are now failing because nightly doesn't install).

mmoll · 2018-04-10T19:29:26Z

this needs a rebase now

pondrejk · 2018-04-11T13:55:13Z

Tested various combinations of --foreman-logging-layout --foreman-logging-level and --foreman-logging-type on rhel 7.4 based on docs in https://github.com/theforeman/theforeman.org/pull/1053/files
Some claims form that document that document I didn't verify, but that may be my misunderstanding of what parts are in progress. In short:

-- journald part works all right with all three patterns, foreman fields are logged as expected, filtering and persistent storage works
-- systemd setting for me just keeps logging to journald, logs land in /var/log/messages but that is I suppose due to journald default. So so far, these two options have the same effect, I also don't see the default facility setting mentioned in the doc
-- I din't find a way to set json_items in installer, is it something only configurable in the config file?

ekohl · 2018-04-11T14:23:19Z

-- systemd setting for me just keeps logging to journald, logs land in /var/log/messages but that is I suppose due to journald default. So so far, these two options have the same effect, I also don't see the default facility setting mentioned in the doc

Do you mean syslog here?

-- I din't find a way to set json_items in installer, is it something only configurable in the config file?

We don't have that setting, but it should be easy to add. Shall I modify the PR?

mmoll · 2018-04-11T15:48:46Z

please rebase :)

ekohl · 2018-04-11T17:10:18Z

Rebased again :)

pondrejk · 2018-04-12T10:05:36Z

@ekohl

Do you mean syslog here?

Yes syslog, sorry

We don't have that setting, but it should be easy to add. Shall I modify the PR?

To me it makes sense to have yaml-configurable options also as installer parameters, so I'd say yes.

lzap · 2018-04-17T12:53:34Z

The current version stays on file appender by default, I started discussion in forums and it turned into poll which I did not want to do actually to be honest as I was hoping for more discussion around how to implement this in puppet. Anyway, I am fine with this version.

mmoll · 2018-04-17T20:13:00Z

Let's bring this in as-is for now 👍

mmoll · 2018-04-17T20:13:14Z

merged, bedankt @ekohl!

lzap · 2018-04-19T15:58:21Z

Thanks a bunch @ekohl !

I realized one thing, when journald or syslog is set, we should configure logrotate NOT to poke httpd because it's not necessary anymore.

theforeman-bot added Needs testing Not yet reviewed labels Mar 27, 2018

ekohl changed the title ~~Refs #22493 - Add parameters for structured logging~~ [WIP] Refs #22493 - Add parameters for structured logging Mar 27, 2018

lzap requested changes Mar 27, 2018

View reviewed changes

theforeman-bot added Waiting on contributor and removed Not yet reviewed labels Mar 27, 2018

ekohl force-pushed the structured-logging branch from b2a8deb to 09ab49e Compare March 27, 2018 14:43

theforeman-bot added Needs re-review Needs testing and removed Waiting on contributor labels Mar 27, 2018

ekohl force-pushed the structured-logging branch 2 times, most recently from 7f1192b to d4fbd24 Compare March 27, 2018 15:25

ekohl force-pushed the structured-logging branch from d4fbd24 to 893d806 Compare March 27, 2018 15:55

ekohl force-pushed the structured-logging branch 2 times, most recently from 16b7ad3 to cb6fee8 Compare March 27, 2018 18:14

lzap changed the title ~~[WIP] Refs #22493 - Add parameters for structured logging~~ [WIP] Refs #22559 - Add parameters for structured logging Mar 29, 2018

ekohl force-pushed the structured-logging branch from cb6fee8 to 64a5686 Compare April 9, 2018 11:24

ekohl force-pushed the structured-logging branch from 64a5686 to c5ccbdc Compare April 10, 2018 08:48

ekohl force-pushed the structured-logging branch 2 times, most recently from 5474923 to 08407fa Compare April 10, 2018 16:30

ekohl force-pushed the structured-logging branch from 08407fa to e10610e Compare April 11, 2018 08:46

ekohl changed the title ~~[WIP] Refs #22559 - Add parameters for structured logging~~ Refs #22559 - Add parameters for structured logging Apr 11, 2018

Refs #22559 - Add parameters for structured logging

7d8d0fe

ekohl force-pushed the structured-logging branch from e10610e to 7d8d0fe Compare April 11, 2018 17:10

lzap approved these changes Apr 17, 2018

View reviewed changes

theforeman-bot removed the Needs re-review label Apr 17, 2018

mmoll merged commit 1279251 into theforeman:master Apr 17, 2018

ekohl added the Enhancement label May 7, 2018

ekohl deleted the structured-logging branch October 26, 2018 08:59

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Refs #22559 - Add parameters for structured logging #631

Refs #22559 - Add parameters for structured logging #631

ekohl commented Mar 27, 2018

ekohl commented Mar 27, 2018

lzap left a comment

lzap Mar 27, 2018

ekohl Mar 27, 2018

lzap Mar 27, 2018

lzap Mar 27, 2018

ekohl Mar 27, 2018

ares Mar 27, 2018

ekohl Mar 27, 2018

lzap Mar 27, 2018

ekohl Mar 27, 2018

lzap Mar 29, 2018

ekohl commented Mar 27, 2018

ekohl commented Mar 27, 2018

ekohl commented Apr 9, 2018

lzap commented Apr 10, 2018

ekohl commented Apr 10, 2018

ekohl commented Apr 10, 2018

lzap commented Apr 10, 2018

ekohl commented Apr 10, 2018

ekohl commented Apr 10, 2018

ekohl commented Apr 10, 2018

ekohl commented Apr 10, 2018

mmoll commented Apr 10, 2018

pondrejk commented Apr 11, 2018

ekohl commented Apr 11, 2018

mmoll commented Apr 11, 2018

ekohl commented Apr 11, 2018

pondrejk commented Apr 12, 2018

lzap commented Apr 17, 2018

mmoll commented Apr 17, 2018

mmoll commented Apr 17, 2018

lzap commented Apr 19, 2018

Refs #22559 - Add parameters for structured logging #631

Refs #22559 - Add parameters for structured logging #631

Conversation

ekohl commented Mar 27, 2018

ekohl commented Mar 27, 2018

lzap left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ekohl commented Mar 27, 2018

ekohl commented Mar 27, 2018

ekohl commented Apr 9, 2018

lzap commented Apr 10, 2018

ekohl commented Apr 10, 2018

ekohl commented Apr 10, 2018

lzap commented Apr 10, 2018

ekohl commented Apr 10, 2018

ekohl commented Apr 10, 2018

ekohl commented Apr 10, 2018

ekohl commented Apr 10, 2018

mmoll commented Apr 10, 2018

pondrejk commented Apr 11, 2018

ekohl commented Apr 11, 2018

mmoll commented Apr 11, 2018

ekohl commented Apr 11, 2018

pondrejk commented Apr 12, 2018

lzap commented Apr 17, 2018

mmoll commented Apr 17, 2018

mmoll commented Apr 17, 2018

lzap commented Apr 19, 2018