Use ISO8601 timestamp format for zap log messages

[creydr]

Is this a BUG FIX or a FEATURE ?:

/kind enhancement

What this PR does / why we need it:

Currently the timestamps in the logs are in epoch format. This makes it really hard to get the time of the event. This PR uses the ISO8601 format for encoding timestamps:

{"level":"info","ts":"2021-10-01T11:42:17.421Z","logger":"controller-runtime.manager.controller.nodenetworkstate","msg":"Starting Controller","reconciler group":"nmstate.io","reconciler kind":"NodeNetworkState"}

instead of

{"level":"info","ts":"1633079530.9509594","logger":"controller-runtime.manager.controller.nodenetworkstate","msg":"Starting Controller","reconciler group":"nmstate.io","reconciler kind":"NodeNetworkState"}

In addition it adds the standard zap flags:

• zap-devel: Enable zap development mode (changes defaults to console encoder, debug log level, disables sampling and stacktrace from 'warning' level)")
• zap-encoder: Zap log encoding (json or console)
• zap-level: Zap log level (one of debug, info, error or any integer value > 0)
• zap-stacktrace-level: Set the minimum log level that triggers stacktrace generation

The --v parameter is marked as deprecated in favor of zap-devel.

Special notes for your reviewer:
Unfortunately the standard zap flags don't provide a way to specify the timestamp format, so I had to set it "hard" to ISO8601.

Release note:

Deprecates the --v flag in favor of the --zap-devel flag
Uses ISO8601 format for timestamp encoding of log messages from zap logger

[kubevirt-bot]

Hi @creydr. Thanks for your PR.

I'm waiting for a nmstate member to verify that this patch is reasonable to test. If it is, they should reply with /ok-to-test on its own line. Until that is done, I will not automatically test new commits in this PR, but the usual testing commands by org members will still work. Regular contributors should join the org to skip this step.

Once the patch is verified, the new status will be reflected by the ok-to-test label.

I understand the commands that are listed here.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

[phoracek]

Thanks for the contribution @creydr

@rhrazdil would you please help review this PR?

[rhrazdil]

Hello @creydr , thanks for your PR.
I like the idea of making the timestamp more human-readable, however, I'm not sure if this PR in it's current state
is the best approach.
I don't think it's desirable to bring in zap package - we would then effectively became maintainers of the code.
And it's a lot of code.

Why not define a configuration with the said ISO8601 format (we can discuss potential alternatives later) and passing it as
an option to zap.New?

Something like this might work, of course ideally wrapped in a function and not directly in main.go, but you get the point:

	ecfg := zapcore.EncoderConfig{
		// Keys can be anything except the empty string.
		TimeKey:        "ts",
		LevelKey:       "level",
		NameKey:        "name",
		CallerKey:      "caller",
		FunctionKey:    zapcore.OmitKey,
		MessageKey:     "msg",
		StacktraceKey:  "error",
		LineEnding:     zapcore.DefaultLineEnding,
		EncodeLevel:    zapcore.LowercaseLevelEncoder,
		EncodeTime:     zapcore.ISO8601TimeEncoder,
		EncodeDuration: zapcore.StringDurationEncoder,
		EncodeCaller:   zapcore.ShortCallerEncoder,
	}
	encoder := zapcore.NewJSONEncoder(ecfg)
	ctrl.SetLogger(zap.New(zap.UseDevMode(logType != "production"), zap.Encoder(encoder)))

[creydr]

Hello @rhrazdil,
thanks for the feedback. I thought the same at the beginning, but was struggling with the hard coding of so many options and having nothing adjustable via flags. Anyhow I found another way and updated this PR (only without the possibility to adjust the timestamp format via a flag).

[rhrazdil]

/ok-to-test

[rhrazdil]

Could you please make the setupLogger function more focused?
It's currently doing two things: setting up the logger, and parsing command line flags.
Maybe you could pass the opts as a parameter and do the flag parsing in main directly?

[creydr]

Thanks for your feedback. Makes sense. I updated the PR.

[rhrazdil]

Thanks! Just one small thing, wouldn't you mind squashing the two commits into one commit enriched by a brief description of the change?

[rhrazdil]

nit: workaround

[creydr]

🤦 Thanks. Updated it

[creydr]

Thanks! Just one small thing, wouldn't you mind squashing the two commits into one commit enriched by a brief description of the change?

If this is the usual way you do it here I can squash them. Anyhow I kept them separate as they are 2 different changes actually (whereas one was kind the "base" for the other). So let me know if this makes sense for you, or if I should squash them.
I enriched the commit messages with a brief description.

[rhrazdil]

Thanks! Just one small thing, wouldn't you mind squashing the two commits into one commit enriched by a brief description of the change?

If this is the usual way you do it here I can squash them. Anyhow I kept them separate as they are 2 different changes actually (whereas one was kind the "base" for the other). So let me know if this makes sense for you, or if I should squash them.
I enriched the commit messages with a brief description.

Thanks for the descriptions, this change makes sense as it is now. No need to squash.

/lgtm
/approve

[kubevirt-bot]

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: rhrazdil

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

• OWNERS [rhrazdil]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

[rhrazdil]

(for the record)