Add rolling-file appender to core logging

[pgayvallet]

Summary

Fix #56291

This PR adds a new rolling-file appender to core's logging system.

The appender currently supports two triggering policy: time-based (time-interval) and size-base (size-limit), and one rolling strategy: appending a numeric-based suffix at the end of the file when rolling it (numeric). See src/core/server/logging/README.md in the PR for more documentation

Examples

Rolling every 24h

logging:
  appenders:
    lets-roll:
      kind: rolling-file
      path: /var/logs/kibana.log
      policy:
        kind: time-interval
        interval: 24h
        modulate: true
      strategy:
        kind: numeric
        pattern: '-%i'
        max: 2
      layout:
        kind: pattern

This appender is configured to roll the file every 24h hours (interval: 24h) everyday at 0:00am (modulate: true). it will retain a maximum of 2 (max: 2) rolled files:

• During the first rollover, kibana.log is renamed to kibana-1.log. A new kibana.log file is created and starts
  being written to.
• During the second rollover, kibana-1.log is renamed to kibana-2.log and kibana.log is renamed to kibana-1.log.
  A new kibana.log file is created and starts being written to.
• During the third and subsequent rollovers, kibana-2.log is deleted, kibana-1.log is renamed to kibana-2.log and
  kibana.log is renamed to kibana-1.log. A new kibana.log file is created and starts being written to.

Rolling once the file reaches 50mb

logging:
  appenders:
    rock-n-roll:
      kind: rolling-file
      path: /var/logs/kibana.log
      policy:
        kind: size-limit
        size: 50mb
      strategy:
        kind: numeric
        pattern: '-%i'
        max: 2
      layout:
        kind: pattern

This appender is configured to roll the file once it reaches 50mb. The same rolling strategy than previous example applies.

Checklist

• Documentation was added for features that require explanation or tutorials
• Unit or functional tests were updated or added to match the most common scenarios

[pgayvallet]

self-review

[pgayvallet]

I'm forced to try/catch this, else it could result in an unhandled promise rejection from the call in append.

I'm not sure what to do with the error though. Crashing the server if the rollout failed seems extreme, but I'm not sure console.log is enough. I could eventually keep an internal ConsoleAppender and use it to log the error instead of relying on console.log, WDYT?

[legrego]

Would a failed rollout never, sometimes, or always prevent future logs from being written? My guess is sometimes?

Eventually keeping an internal ConsoleAppender sounds like a good idea to me. In the short term, I don't have many other suggestions, other than changing console.log to console.error, so that we can at least see this in stderr instead of stdout.

In the context of audit logging specifically, we've discussed optionally halting the server to prevent users from interacting with Kibana when we can't audit their actions: #60636. This is out of scope for this PR, but it might inform how we decide to handle these failures.

In the hypothetical future, we could leverage the notification center to alert administrators about this as well.

[pgayvallet]

Would a failed rollout never, sometimes, or always prevent future logs from being written?

it's never never when you interact with filesystem, but except in case of hard I/O failure, I think the worth case would be that we would not be able to roll the log file, and that the next rolling cycle would still write in the previous (non-renamed) file. We skip a rolling, basically, which seemed acceptable (also we can't really do anything except warning about the failure)

[mshustov]

I'm not sure what to do with the error though. Crashing the server if the rollout failed seems extreme, but I'm not sure console.log is enough.

It seems Elasticsearch logs a caught exception without any additional measurements (we can further check with them). see elastic/elasticsearch#45523

[elasticmachine]

Pinging @elastic/kibana-core (Team:Core)

[legrego]

I tested this new appender for Kibana's new audit log, and it's working very nicely! This is a really impressive PR, thanks again for putting this up so quickly

[legrego]

Would a failed rollout never, sometimes, or always prevent future logs from being written? My guess is sometimes?

Eventually keeping an internal ConsoleAppender sounds like a good idea to me. In the short term, I don't have many other suggestions, other than changing console.log to console.error, so that we can at least see this in stderr instead of stdout.

In the context of audit logging specifically, we've discussed optionally halting the server to prevent users from interacting with Kibana when we can't audit their actions: #60636. This is out of scope for this PR, but it might inform how we decide to handle these failures.

In the hypothetical future, we could leverage the notification center to alert administrators about this as well.

[legrego]

Are there only certain failure scenarios that should cause us to reset the file info like this? Or do we really want to reset whenever any error is caught?

[pgayvallet]

Ideally, we would only catch ENOENT (or such) errors. But that's kinda the first time we got a logger/appender implementation complex enough to potentially throw errors, so I'm not really sure how we should handle failures internal to the logger system or its appenders, so for safety I used a catch-all instead.

[mshustov]

Ideally, we would only catch ENOENT (or such) errors. But that's kinda the first time we got a logger/appender implementation complex enough to potentially throw errors,

shouldn't we log an exception different from ENOENT to console at least?

[pgayvallet]

Good point, will add a ENOENT check and logs the error.

Remaining question (same as in #84735 (comment)) is, should we:

1. use console.log
2. use console.error
3. create a ConsoleAppender in the RollingFileAppender and use it internally for all error logging (we would use the same layout as the one provided to the rolling file appender). In that case, it will logs in stdout as if we were using console.log

wdyt?

[mshustov]

The 3rd option looks fine. However, I'd expect that it uses the default layout that a user specifies for the root context.
If the 3rd option is too hard to implement, the 2nd one is well enough.

[legrego]

Since we only have a single strategy available, what do you think about providing a default value, so that consumers aren't forced to specify it? I mistakenly omitted this from my yml, and the @kbn/config-schema error message was hard to decipher at best.

[pgayvallet]

Yea, I even added default values for both the policy and the strategy at some point, so that

rolling-file:
    kind: rolling-file
    path: /Users/pierregayvallet/Documents/test-log/kibana.log
    layout:
        kind: pattern

would be enough, then I reverted it, thinking that we didn't do that for other appenders (like you must always specify layout, there isn't a default value for it).

@elastic/kibana-core do you have any opinion on this?

[mshustov]

don't see a reason not to add defaults. we have got them for some values

kibana/src/core/server/logging/layouts/pattern_layout.ts

Lines 36 to 48 in ab92bbb

	const DEFAULT_PATTERN = `[%date][%level][%logger]%meta %message`;
	export const patternSchema = schema.string({
	validate: (string) => {
	DateConversion.validate!(string);
	},
	});
	const patternLayoutSchema = schema.object({
	highlight: schema.maybe(schema.boolean()),
	kind: schema.literal('pattern'),
	pattern: schema.maybe(patternSchema),
	});

[mshustov]

Have you discussed the defaults with Cloud? The legacy appender has other limits + we might want to have higher min and explicit max limits

kibana/packages/kbn-legacy-logging/src/schema.ts

Lines 77 to 82 in e176def

	// > 1MB
	.greater(1048576)
	// < 1GB
	.less(1073741825)
	// 10MB
	.default(10485760),

[pgayvallet]

I haven't. @Kushmaro maybe you can help us here?

[Kushmaro]

@pgayvallet
By our log delivery feature design (see storage section) we concluded that the smallest kibana instance in cloud will have around 1GB of storage space

is the 100mb referring to the log size rotation limit? cloud also enforces a quota on the log path, and I * think * that quota is 100mb total, so maybe a more sensible rotation limit would be 10mb.

@s-nel for awareness and further guidelines (he's on PTO though so may take a while)

[pgayvallet]

is the 100mb referring to the log size rotation limit

That's the maximum size of the log file before it got rolled out.

[s-nel]

We use 100MB rollover size for ES audit logs and keep 2 files. We might choose something smaller for Kibana since the instances don't have much storage.

[mshustov]

Ideally, we would only catch ENOENT (or such) errors. But that's kinda the first time we got a logger/appender implementation complex enough to potentially throw errors,

shouldn't we log an exception different from ENOENT to console at least?

[mshustov]

we can create a buffer of fixed size to make sure to have better control over the rolling process

const asciiBuf = Buffer.alloc(5, 'a', 'utf8');

[pgayvallet]

I'm only using ascii chars in the message, so we kinda know that sizeInBytes === msg.length, but I can use a buffer to add more control if we want to.

[pgayvallet]

@restrry I addressed most of your comments. The points I still need input on are

• Add rolling-file appender to core logging #84735 (comment)
• Add rolling-file appender to core logging #84735 (comment)
• Add rolling-file appender to core logging #84735 (comment)

PTAL

[mshustov]

We can change size-limit policy defaults in a follow up

[kibanamachine]

💚 Build Succeeded

• continuous-integration/kibana-ci/pull-request
• Commit: bbb96f4

Metrics [docs]

Distributable file count

id	before	after	diff
default	46991	47768	+777
oss	27598	27615	+17

History

• 💚 Build #93004 succeeded bf0e390
• 💚 Build #92791 succeeded 3aa0bc7
• 💚 Build #92267 succeeded 6694e24
• 💚 Build #91806 succeeded 3e740c6
• 💚 Build #91795 succeeded a9e21d5

To update your PR or re-run it, just comment with:
@elasticmachine merge upstream