Fixes #10487: Add custom logging support.

[ehelms]

This change moves away from the Rails logger to the 'logging' gem
to support more configurability of logging. Further, this allows for
the creation of custom loggers that plugins can then register through
settings.

For example, the plugin katello could define within its settings file
(settings.plugins.d/katello.yaml) the following:

:katello:
  :loggers:
    :pulp_rest:
      :enabled: false
    :cp_rest:
      :enabled: true

Which would define 2 loggers, pulp_rest and cp_rest where the latter
is turned on be default, but the former can be enabled such that
the log file isn't continuously filled with messages from that particular
layer.

[ohadlevy]

warn ?

[ares]

I think logger is not ready at this moment so warn can't be used

[ohadlevy]

I mean Kernel.warn

see http://apidock.com/ruby/Kernel/warn

[ares]

ah right, makes sense

[ohadlevy]

missing tests?

[ohadlevy]

[test] seems like jenkins oom failures

[domcleal]

seems like jenkins oom failures

That's because it's generating a 150MB log file from each test run. Please don't re-run it until this is fixed.

The tests are outputting all debug level logs to stdout or stderr, which is generating a huge amount of data, can that be disabled?

[domcleal]

If a plugin tries to use a logger X that doesn't exist in SETTINGS, what happens?

[ehelms]

AFAIK this would be the same condition as if a logger is disabled (i.e. nothing would get output to the log file).

[ehelms]

An example of this we use today is for Pulp rest call logging. We hand the Runcible library that makes our calls down to Pulp a logger and then can disable/enable it (or if undefined, nothing would happen) - https://github.com/Katello/katello/blob/master/app/lib/katello/util/thread_session.rb#L67

One question I am not sure on is whether plugins should be able to define per environment settings for their loggers. Per environment settings was something I missed in the first pass of this implementation (and resulted in the massive log files and console printing) and will be accounted for in the next push.

[domcleal]

Seems like we need a mechanism for default configuration which doesn't rely on SETTINGS, or a way to prepopulate SETTINGS with that default configuration, else plugins aren't going to be configured well by default - especially on upgrade if config files aren't updated.

It's also a different configuration mechanism to Foreman core which appears to now use the logging.yaml file, which could be confusing for users.

[ehelms]

For Foreman core, I considered putting the configuration into the settings.yaml file, but due to the size of the default configuration I thought a separate yaml file more consumable (and not crowd the settings.yaml file). If folks would prefer I can rework this to have :logging: node in settings.yaml with what is in logging.yaml now.

When you say default configuration - are you referring to default configurations for plugins or for logging in general?

[domcleal]

I'm referring to default configuration for logging in plugins, as that's what this seems to depend upon. It seems that if the settings file is older or not present then we won't have any good defaults for plugin logging as their loggers won't have been configured.

I do agree about keeping Foreman core's logging in a separate config file, that seems like a good idea, but it does mean one rule for core and one for plugins, which isn't good for consistency.

Perhaps break the configuration into two, with the configuration of stuff like paths and rotation in a logging.yaml as that applies to both core+plugins, the per-logger levels in settings files and ensure that both core+plugins can set sensible defaults for their loggers in code without requiring those settings files.

(Sorry if this is a bit rambly.)

[ehelms]

Not rambly at all, its good feedback to consider.

For the defaults, I am not able to think what defaults a plugin would need to worry about out of the gate. If the plugin is using things like 'Rails.logger' then they will continue to log to the same place and in the same way as before this patch. The log messages will show up as 'app' in the log files.

If we want to, for the purpose of making logs easier to read, start to enforce per-plugin logs then we would need some default log creation if not specified within the settings file for the plugin. This could be based on the Rails engine name for consistency across the board. Note that this would only apply to specifically inserted log messages (Rails will continue to log requests and such under the 'app' logger). For example,

Katello.logger = ::Logging.logger['katello']
Katello.logger.debug "Debugging message for this katello action"

Which would then appear within the logs as:

2015-05-13 13:28:22 [katello] [D] Debugging message for this Katello action

I think splitting the config and the definition of the loggers themselves makes sense across settings and logging. I would expect then, that the 'environmental' configurations would also live under settings (https://github.com/theforeman/foreman/pull/2376/files#diff-d71db24719150ef52a8afd6ef934f9b4R54)?

[domcleal]

For the defaults, I am not able to think what defaults a plugin would need to worry about out of the gate. If the plugin is using things like 'Rails.logger' then they will continue to log to the same place and in the same way as before this patch.

It was the custom loggers I was thinking about, so if a plugin decided to use a custom logger to make some of its log messages more categorised, and assuming they should be logged by default, we should ensure the logger is set up even without an explicit config file.

If we want to, for the purpose of making logs easier to read, start to enforce per-plugin logs then we would need some default log creation if not specified within the settings file for the plugin. This could be based on the Rails engine name for consistency across the board.

I think that'd be a great idea.

I think splitting the config and the definition of the loggers themselves makes sense across settings and logging. I would expect then, that the 'environmental' configurations would also live under settings (https://github.com/theforeman/foreman/pull/2376/files#diff-d71db24719150ef52a8afd6ef934f9b4R54)?

Yeah, I guess if the rotation settings aren't there then we minimise what's in the general settings file. My aim is to keep the commonly changed things (log levels) away from rarely changed things (formatting/rotation etc) so misconfigurations (or rather reusing old config files) are less likely to cause bad or missing logging.

[lzap]

Big improvement, I like it a lot!

[ehelms]

One design question I have been debating is how we handle user configuration in the event they want to escalate a log level. If logging.yaml is not deployed by the puppet module then users do not run a risk of losing their settings. However, for plugins that deploy and configure their settings files with the installer, the changed settings being over written is a possibility.

[domcleal]

1. Do we see any reason to support logger specific log files?

I don't really see a use at the moment.

2. With this design, if a user wants to bump the logging level for all loggers from say info to debug, they would need to edit logging.yaml and change it there, then restart the application. If they wanted to bump a single logger, say 'sql' to debug while the rest stayed at info, they would need to edit settings.yaml and change that loggers config level. Is this workflow ok?

Yeah, that's ended up a little oddly. What do you think, maybe move global level to settings.yaml too?

3. Do we want to support syslog in production? or the ability to do both syslog and file in production?

Yeah, we should, but probably syslog-only rather than both.

[ehelms]

Updated with:

1. Production environment set to 'syslog' by default
2. Logging settings can now be set for the current environment through settings.yaml (see https://github.com/theforeman/foreman/pull/2376/files#diff-c08285198f9b2708ddd77e0faef7baa8R26)
3. Tried 'green' for the date in console mode for contrast, if that is still ugly I will just update to white.

[domcleal]

1. Production environment set to 'syslog' by default

Sorry, I guess I misunderstood earlier, I thought this was just to enable it as an option rather than to change the default.

I'm not sure with the amount we log and because it's multi-line that we should be doing this - we might be best keeping the file as default, then later on integrating to journald as an option. Sorry for the confusion.

[domcleal]

3. Tried 'green' for the date in console mode for contrast, if that is still ugly I will just update to white.

Works for me, thanks.

[ehelms]

Updated to move back to file as the default for production.

[domcleal]

It looks like plugins might have the same issue you fixed for core, where the default loggers need to be defined by a settings file to work. Can you add an API for plugins to be able to define their default loggers so they don't hit errors when trying to use something not defined by a config file?

[ehelms]

I updated the way plugins are handled to allow defining loggers in the plugin definition or settings. Or, if the loggers are defined in the plugin definition, whatever is in the settings file will override. API for loggers would look like:

Foreman::Plugin.register :test_plugin do

  logger :test, :enabled => true
  logger :rest_api, :enabled => true

end

Which, in the same way, would result in two loggers: test_plugin/test and test_plugin/rest_api

[domcleal]

[test]

[domcleal]

Looks good, thanks.

There seems to be a problem with the Katello tests, probably the pinning of logging to < 2.0.0 causing bundler some problems with our GCE bundler group. I'd suggest loosening it to < 3.0.0 if possible to fix it.

Edit: I see you have a PR open, so shall I just merge this?

[ehelms]

I updated my PR to Katello to make use of the new plugin API and fix some tests. My run of the two PRs together passed and it is in review. So I'd say when you want to merge this you can. I'll follow this up with an update to the plugin wiki page describing custom loggers.

[domcleal]

Merged as 3088e64, thanks @ehelms.

The wiki update would be much appreciated, cheers.