Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Enhance logging #310

Closed
wants to merge 8 commits into from
Closed

Enhance logging #310

wants to merge 8 commits into from

Conversation

raviks789
Copy link
Contributor

Enhance logging by providing configuration for logging in configuration file config.yml.

@raviks789 raviks789 requested a review from lippserd July 11, 2021 22:58
@raviks789 raviks789 force-pushed the fix/enhance-logging branch 9 times, most recently from 13f80b3 to e39abed Compare July 16, 2021 08:51
@raviks789 raviks789 changed the title Fix/enhance logging Enhance logging Jul 16, 2021
@raviks789 raviks789 force-pushed the fix/enhance-logging branch 9 times, most recently from 9ffc201 to c582bdd Compare July 19, 2021 12:01
cmd/icingadb/main.go Outdated Show resolved Hide resolved
cmd/icingadb/main.go Outdated Show resolved Hide resolved
cmd/icingadb/main.go Outdated Show resolved Hide resolved
cmd/icingadb/main.go Outdated Show resolved Hide resolved
cmd/icingadb/main.go Outdated Show resolved Hide resolved
internal/logging/logging.go Outdated Show resolved Hide resolved
internal/logging/journal.go Outdated Show resolved Hide resolved
internal/logging/logging.go Outdated Show resolved Hide resolved
internal/logging/logging.go Outdated Show resolved Hide resolved
internal/logging/logging.go Outdated Show resolved Hide resolved
@raviks789 raviks789 force-pushed the fix/enhance-logging branch 4 times, most recently from 2f2d35f to 3e593fc Compare July 20, 2021 10:22
internal/logging/journal.go Outdated Show resolved Hide resolved
internal/logging/journal.go Outdated Show resolved Hide resolved
internal/logging/journal.go Outdated Show resolved Hide resolved
internal/logging/journal.go Show resolved Hide resolved
internal/logging/journal.go Outdated Show resolved Hide resolved
internal/logging/logging.go Outdated Show resolved Hide resolved
pkg/config/logging.go Outdated Show resolved Hide resolved
internal/logging/logging.go Outdated Show resolved Hide resolved
internal/logging/logging.go Outdated Show resolved Hide resolved
internal/logging/logging.go Outdated Show resolved Hide resolved
@raviks789 raviks789 force-pushed the fix/enhance-logging branch 2 times, most recently from a113bf0 to acaa913 Compare July 22, 2021 08:26
@cla-bot cla-bot bot added the cla/signed label Aug 4, 2021
cmd/icingadb/main.go Show resolved Hide resolved
cmd/icingadb/main.go Outdated Show resolved Hide resolved
etc/icingadb.service Outdated Show resolved Hide resolved
internal/logging/logging.go Outdated Show resolved Hide resolved
internal/logging/logging.go Outdated Show resolved Hide resolved
internal/logging/logging.go Outdated Show resolved Hide resolved
config.yml.example Outdated Show resolved Hide resolved
doc/03-Configuration.md Outdated Show resolved Hide resolved
doc/03-Configuration.md Outdated Show resolved Hide resolved
Option | Description
-------------------------|-----------------------------------------------
level | **Optional.** Logger default level (debug, info, warn, error, dpanic, panic or fatal). Usually set to `debug` by default.
options | **Optional.** Child loggers, with `Icinga Db component` => `logging level` map.<br /> `Icinga Db component`: database, redis, heartbeat, high-availability, config-sync, history, runtime-updates, overdue-sync, dump-signals, delta. <br /> `logging level`: debug, info, warn, error, dpanic, panic or fatal.
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I would not write long text in tables, but create a separate section under logging and document the components with a small description of what they do there. The description for options could then be something like this:

Optional. Map of component name to logging level in order to set a different logging level for each component instead of the default one. See logging components for details.

@raviks789 raviks789 force-pushed the fix/enhance-logging branch 2 times, most recently from bf7e836 to 38aaf26 Compare August 11, 2021 08:37
@N-o-X N-o-X added this to In progress in v1.0.0-rc2 via automation Aug 13, 2021
Copy link
Contributor

@N-o-X N-o-X left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Works great and the code is also fine. Just needs those 3 requested changes and a rebase and it's ready to merge.

etc/icingadb.service Outdated Show resolved Hide resolved
doc/03-Configuration.md Show resolved Hide resolved
internal/logging/journal.go Show resolved Hide resolved
v1.0.0-rc2 automation moved this from In progress to Review in progress Sep 3, 2021
The logger for each component in icingadb must be set to a level described in `logging` section in `config.yml.
If config file doesnot describe the logger level for the component, then the level for the corresponding
component is set to `info`.
Logger field is removed from Command struct in command.go
The logging package has been completely changed to handle fatal logs.
Method Logging.FatalF is added to introduce a buffer time adter the Fatal log has been displayed on the console and before the service shuts down.
logging.enabled switch is used to  disable the child loggers along with default logger
`output` field is added to `logging` section in `config.yml` file. If it is set to `systemd` then logs are sent to systemd journal.
By default it is set to `console`. `journal.go` is added to `logging` package in which the functionality to send the messages to
systemd journal is written.
Get whether the log outputs need to be written to stdErr or sent to systemd journal using daemon.SdNotify(false, daemon.SdNotifyReady) and os.LookupEnv("NOTIFY_SOCKET").
And in icingadb.service when `Type` is set to `simple` then the output will be `console` and when it is set to `notify` the output will be `systemd-journa`.

In this commit there are also changes to the code document.
@N-o-X N-o-X force-pushed the fix/enhance-logging branch 2 times, most recently from 70f414d to 66081ae Compare September 6, 2021 15:07
…e.Level

Unmarshaller is added to config.go to read sub fields which are set to default, if the main field is not present in config.yml file.
For example logging has all optional fields and hence  may not be included sometimes in config.yml file, in which case the default logging level is set to debug.
@N-o-X
Copy link
Contributor

N-o-X commented Sep 6, 2021


Option | Description
-------------------------|-----------------------------------------------
level | **Optional.** Specifies the default logging level. Can be set to `fatal`, `error`, `warning`, `info` or `debug`. Defaults to `debug`.
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why not default to a more production-ready default value?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Makes sense.

Comment on lines +77 to +89
// UnmarshalYAML implements the yaml.Unmarshaler interface.
func (c *Config) UnmarshalYAML(unmarshal func(interface{}) error) error {
if err := defaults.Set(c); err != nil {
return errors.Wrap(err, "can't set default config")
}
// Prevent recursion.
type self Config
if err := unmarshal((*self)(c)); err != nil {
return internal.CantUnmarshalYAML(err, c)
}

return nil
}
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why introduce this again? Setting defaults should now be handled there:

if err := defaults.Set(c); err != nil {
return nil, errors.Wrap(err, "can't set config defaults")
}

Comment on lines +20 to +32
// UnmarshalYAML implements the yaml.Unmarshaler interface.
func (l *Logging) UnmarshalYAML(unmarshal func(interface{}) error) error {
if err := defaults.Set(l); err != nil {
return errors.Wrap(err, "can't set default logging config")
}
// Prevent recursion.
type self Logging
if err := unmarshal((*self)(l)); err != nil {
return internal.CantUnmarshalYAML(err, l)
}

return nil
}
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should also be handled by this:

if err := defaults.Set(c); err != nil {
return nil, errors.Wrap(err, "can't set config defaults")
}

@@ -184,7 +215,7 @@ func run() int {
com.ErrgroupReceive(g, dbErrs)

g.Go(func() error {
return s.ApplyDelta(ctx, icingadb.NewDelta(ctx, actualCvs, cvs1, cv, logger))
return s.ApplyDelta(ctx, icingadb.NewDelta(ctx, actualCvs, cvs1, cv, logs.GetChildLogger("delta")))
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The delta implementation is not worth it's own logging configuration and should be seen as part of a bigger component IMHO. There's also a call to ApplyDelta() within the config sync which just uses the "config-sync" child logger. So either also use a delta child logger there or make this one here a "customvar" child logger (or maybe even also "config-sync" if we don't see custom var sync as an independent component).

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

config-sync for those components you've mentioned sounds good to me.

@@ -199,7 +230,7 @@ func run() int {
com.ErrgroupReceive(g, dbErrs)

g.Go(func() error {
return s.ApplyDelta(ctx, icingadb.NewDelta(ctx, actualCvFlats, cvFlats, cvFlat, logger))
return s.ApplyDelta(ctx, icingadb.NewDelta(ctx, actualCvFlats, cvFlats, cvFlat, logs.GetChildLogger("delta")))
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same here.

Comment on lines +46 to +47
if _, ok := os.LookupEnv("NOTIFY_SOCKET"); ok {
output = "systemd-journal"
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Or is Type=notify only there to detect whether running under systemd?

Possible alternative would be to use a combination of https://pkg.go.dev/github.com/coreos/go-systemd/v22@v22.3.2/journal#Enabled and https://pkg.go.dev/golang.org/x/term#IsTerminal

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, Type = notify is only there to say if it runs under systemd. I would leave it that way, because the alternative can write to the journal if systemd is available and Icinga DB is started somehow differently.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Well, what about just doing ExecStart=/usr/bin/icingadb -log journald? Would make it obvious why it logs to which destination.

Comment on lines +56 to +58
if err := json.NewDecoder(bytes.NewReader(p)).Decode(line); err != nil {
panic(err)
}
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Letting zap serialize to JSON just to deserialize it again within the same process feels unnecessary. Isn't there a better way to do this?

Apart from that, the io.Writer interface would allow writing partial JSON objects here, so depending on how zap handles this (and if it may change this in the future), this could panic at random.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I believe there is no better way right now without implementing a custom encoder. CoreOS does the same thing.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do you have a link to where CoreOS does that? Also haven't looked to much into zap but what would be the problem with implementing an encoder?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

return w.Writer.Write(message.Bytes())
}

return 0, nil
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should return the number of bytes written: https://pkg.go.dev/io#Writer

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Again, just return len(p)?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes

Comment on lines +81 to +84
err = journal.Send(message.String(), pri, map[string]string{
"PACKAGE": filepath.Dir(line.Caller),
"SYSLOG_IDENTIFIER": filepath.Base(os.Args[0]),
})
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shouldn't journald already set SYSLOG_IDENTIFIER by itself?

Also, to be honest, is that PACKAGE extra field really worth the effort of implementing anything systemd-specific? The log/syslog package already provides a Writer that could just be plugged into zap and should give mostly the same effect as journald provides syslog compatibility.

In addition, when testing with NOTIFY_SOCKET= go run ./cmd/icingadb, this even just logs PACKAGE=. (haven't tried if this behaves differently when properly compiling and running as a systemd unit).

panic(err)
}

return w.Writer.Write(message.Bytes())
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Also here, most likely len(p) != len(message.Bytes()), so incorrect implementation of io.Writer.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That is true. Should we just return len(p) here?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

On success, yes, on error, maybe that, maybe 0. io.Writer docs doesn't seem to forbid returning len(p) with err != nil, however it sound strange to say everything was written and return an error at the same time.

@julianbrost
Copy link
Contributor

This PR was basically split in the following two ones. Is there anything in here that's not covered by those preventing this one from being closed?

@lippserd lippserd removed this from Review in progress in v1.0.0-rc2 Oct 11, 2021
@lippserd
Copy link
Member

This PR was basically split in the following two ones. Is there anything in here that's not covered by those preventing this one from being closed?

Nope, I'll close this one.

@lippserd lippserd closed this Oct 11, 2021
@lippserd lippserd deleted the fix/enhance-logging branch May 4, 2022 14:43
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants