Adds support for log rotation (#49750)

* chore(NA): add log options to config yml

* chore(NA): remove unwanted option from config declaration

* chore(NA): add the bootstrap for the logging rotate feature

* feat(NA): base interface setup for log rotation feature

* docs(NA): add documentation for the new logging rotate options. chore(NA): added new schema validations

* chore(NA): base lifecycle methods and logic

* feat(NA): monitor logic for log rotate feature

* fix(NA): basic log rotation lifecycle

* chore(NA): fix typo on config file

* feat(NA): add rotate files feature to log rotator

* chore(NA): fix log rotate config

* chore(NA): some tests to try logging rotate lifecycle

* feat(NA): correct log rotation logic

* fix(NA): lifecycle for the log rotator

* test(NA): add a test case

* chore(NA): correctly add the new defaults to the config schema

* test(NA): change dir generation for test

* chore(NA): mock log rotate for logging service test

* test(NA): fix temp dir permission issue

* test(NA): try to fix test

* chore(NA): remove usage of mkdtemp

* refact(NA): feature logging rotation reimplementation in order to make it work across platforms

* fix(NA): bug on file size monitor handle

* fix(NA): remove wrong commented out code

* chore(NA): correctly identify if we should use polling

* chore(NA): fix some code comment

* refact(NA): minor implementation details

* chore(NA): change the order of logging mix

* test(NA): add some more test cases

* test(NA): add the majority of the test cases

* test(NA): add last test case

* test(NA): fallback conditions

* chore(NA): add logging rotate config keys to the docker image

* chore(NA): move logging.rotate.enable setting to enabled

* chore(NA): clarify documentation for logging rotate

* chore(NA): use regular instead of logWithMetadata

* chore(NA): move chokidar to a prod dep

* chore(NA): add log explaining why we had fallback to use polling

* test(NA): fix unit tests

* test(NA): fix unit tests

* chore(NA): correctly place this.running condition

* chore(NA): remove redundant call

* fix(NA): log filename containing numbers would produce invalid sorting

* chore(NA): remove existsSync function call from readRotatedFilesMetadata function

* chore(NA): Update docs/setup/settings.asciidoc

Co-Authored-By: Tyler Smalley <tylersmalley@me.com>

* chore(NA): Update docs/setup/settings.asciidoc

Co-Authored-By: Tyler Smalley <tylersmalley@me.com>

* chore(NA): Update docs/setup/settings.asciidoc

Co-Authored-By: Tyler Smalley <tylersmalley@me.com>

* chore(NA): Update docs/setup/settings.asciidoc

Co-Authored-By: Tyler Smalley <tylersmalley@me.com>

* chore(na): update src/legacy/server/logging/rotate/index.js

Co-Authored-By: Tyler Smalley <tylersmalley@me.com>

* chore(NA): remove unused config line from docker vars

* chore(NA): update documentation to include info about non exact limits

* chore(NA): remove redudant if clause

* fix(NA): correctly work with new keepFiles limit after start

* fix(NA): warning log for logging rotate

* chore(NA): replace logwithmetadate with log

* docs(NA): correct log to right terms

* docs(NA): add comment about usage of slice(-1)

* refact(NA): changing polling interval from seconds to milliseconds

* docs(NA): fix comments for shouldRotate method

* chore(NA): update src/legacy/server/logging/rotate/log_rotator.js

Co-Authored-By: Mikhail Shustov <restrry@gmail.com>

* chore(NA): update src/legacy/server/logging/rotate/log_rotator.js

Co-Authored-By: Mikhail Shustov <restrry@gmail.com>

* refact(NA): small change

* refact(NA): bound stop

* refact(NA): shouldUsePolling test function

* refact(NA): move named truncate function to delete

* refact(NA): typescript conversion

* chore(NA): type update for log rotation index file

* docs(NA): add experimental tag on docs

* chore(NA): add call protection of clearTimeout

* refact(NA): cleanup comments and wrong added logs plus inline config

* chore(NA): replace ts-ignore by non null assertion operator

* docs(NA): extend documentation for _renameRotatedFilesByOne call

* chore(NA): fix type problems for process.emit on nodejs
This commit is contained in:
Tiago Costa 2019-12-10 01:32:20 +00:00 committed by GitHub
parent ca5f6d78f1
commit 6d5c8caadc
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
12 changed files with 765 additions and 5 deletions

View file

@ -147,6 +147,36 @@ will default to `true`.
`logging.quiet:`:: *Default: false* Set the value of this setting to `true` to
suppress all logging output other than error messages.
`logging.rotate:`:: [experimental] Specifies the options for the logging rotate feature.
When not defined, all the sub options defaults would be applied.
The following example shows a valid logging rotate configuration:
+
--
logging.rotate:
enabled: true
everyBytes: 10485760
keepFiles: 10
--
`logging.rotate.enabled:`:: [experimental] *Default: false* Set the value of this setting to `true` to
enable log rotation. If you do not have a `logging.dest` set that is different from `stdout`
that feature would not take any effect.
`logging.rotate.everyBytes:`:: [experimental] *Default: 10485760* The maximum size of a log file (that is `not an exact` limit). After the
limit is reached, a new log file is generated. The default size limit is 10485760 (10 MB) and
this option should be at least greater than 1024.
`logging.rotate.keepFiles:`:: [experimental] *Default: 7* The number of most recent rotated log files to keep
on disk. Older files are deleted during log rotation. The default value is 7. The `logging.rotate.keepFiles`
option has to be in the range of 2 to 1024 files.
`logging.rotate.pollingInterval:`:: [experimental] *Default: 10000* The number of milliseconds for the polling strategy in case
the `logging.rotate.usePolling` is enabled. That option has to be in the range of 5000 to 3600000 milliseconds.
`logging.rotate.usePolling:`:: [experimental] *Default: false* By default we try to understand the best way to monitoring
the log file. However, there is some systems where it could not be always accurate. In those cases, if needed,
the `polling` method could be used enabling that option.
`logging.silent:`:: *Default: false* Set the value of this setting to `true` to
suppress all logging output.

View file

@ -150,6 +150,7 @@
"cache-loader": "^4.1.0",
"chalk": "^2.4.2",
"check-disk-space": "^2.1.0",
"chokidar": "3.2.1",
"color": "1.0.3",
"commander": "3.0.0",
"compare-versions": "3.5.1",
@ -373,7 +374,6 @@
"chai": "3.5.0",
"chance": "1.0.18",
"cheerio": "0.22.0",
"chokidar": "3.2.1",
"chromedriver": "78.0.1",
"classnames": "2.2.6",
"dedent": "^0.7.0",

View file

@ -90,6 +90,18 @@ export default class ClusterManager {
});
});
// When receive that event from server worker
// forward a reloadLoggingConfig message to master
// and all workers. This is only used by LogRotator service
// when the cluster mode is enabled
this.server.on('reloadLoggingConfigFromServerWorker', () => {
process.emit('message', { reloadLoggingConfig: true });
this.workers.forEach(worker => {
worker.fork.send({ reloadLoggingConfig: true });
});
});
bindAll(this, 'onWatcherAdd', 'onWatcherError', 'onWatcherChange');
if (opts.open) {

View file

@ -134,6 +134,9 @@ export default class Worker extends EventEmitter {
this.listening = true;
this.emit('listening');
break;
case 'RELOAD_LOGGING_CONFIG_FROM_SERVER_WORKER':
this.emit('reloadLoggingConfigFromServerWorker');
break;
}
}

View file

@ -71,7 +71,20 @@ export async function bootstrap({
const root = new Root(rawConfigService.getConfig$(), env, onRootShutdown);
process.on('SIGHUP', () => {
process.on('SIGHUP', () => reloadLoggingConfig());
// This is only used by the LogRotator service
// in order to be able to reload the log configuration
// under the cluster mode
process.on('message', msg => {
if (!msg || msg.reloadLoggingConfig !== true) {
return;
}
reloadLoggingConfig();
});
function reloadLoggingConfig() {
const cliLogger = root.logger.get('cli');
cliLogger.info('Reloading logging configuration due to SIGHUP.', { tags: ['config'] });
@ -82,7 +95,7 @@ export async function bootstrap({
}
cliLogger.info('Reloaded logging configuration due to SIGHUP.', { tags: ['config'] });
});
}
process.on('SIGINT', () => shutdown());
process.on('SIGTERM', () => shutdown());

View file

@ -23,6 +23,10 @@ jest.mock('fs', () => ({
createWriteStream: jest.fn(() => ({ write: mockStreamWrite })),
}));
jest.mock('../../../legacy/server/logging/rotate', () => ({
setupLoggingRotate: jest.fn().mockImplementation(() => Promise.resolve({})),
}));
const timestamp = new Date(Date.UTC(2012, 1, 1));
let mockConsoleLog: jest.SpyInstance;

View file

@ -42,6 +42,11 @@ kibana_vars=(
kibana.index
logging.dest
logging.quiet
logging.rotate.enabled
logging.rotate.everyBytes
logging.rotate.keepFiles
logging.rotate.pollingInterval
logging.rotate.usePolling
logging.silent
logging.useUTC
logging.verbose

View file

@ -135,7 +135,14 @@ export default () => Joi.object({
then: Joi.default(!process.stdout.isTTY),
otherwise: Joi.default(true)
}),
timezone: Joi.string()
timezone: Joi.string(),
rotate: Joi.object().keys({
enabled: Joi.boolean().default(false),
everyBytes: Joi.number().greater(1024).default(10485760),
keepFiles: Joi.number().greater(2).less(1024).default(7),
pollingInterval: Joi.number().greater(5000).less(3600000).default(10000),
usePolling: Joi.boolean().default(false)
}).default()
}).default(),
ops: Joi.object({

View file

@ -20,6 +20,7 @@
import good from '@elastic/good';
import loggingConfiguration from './configuration';
import { logWithMetadata } from './log_with_metadata';
import { setupLoggingRotate } from './rotate';
export async function setupLogging(server, config) {
return await server.register({
@ -30,5 +31,7 @@ export async function setupLogging(server, config) {
export async function loggingMixin(kbnServer, server, config) {
logWithMetadata.decorateServer(server);
return await setupLogging(server, config);
await setupLogging(server, config);
await setupLoggingRotate(server, config);
}

View file

@ -0,0 +1,59 @@
/*
* Licensed to Elasticsearch B.V. under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch B.V. licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
import { isMaster, isWorker } from 'cluster';
import { Server } from 'hapi';
import { LogRotator } from './log_rotator';
import { KibanaConfig } from '../../kbn_server';
let logRotator: LogRotator;
export async function setupLoggingRotate(server: Server, config: KibanaConfig) {
// If log rotate is not enabled we skip
if (!config.get('logging.rotate.enabled')) {
return;
}
// We just want to start the logging rotate service once
// and we choose to use the master (prod) or the worker server (dev)
if (!isMaster && isWorker && process.env.kbnWorkerType !== 'server') {
return;
}
// We don't want to run logging rotate server if
// we are not logging to a file
if (config.get('logging.dest') === 'stdout') {
server.log(
['warning', 'logging:rotate'],
'Log rotation is enabled but logging.dest is configured for stdout. Set logging.dest to a file for this setting to take effect.'
);
return;
}
// Enable Logging Rotate Service
// We need the master process and it can
// try to setupLoggingRotate more than once,
// so we'll need to assure it only loads once.
if (!logRotator) {
logRotator = new LogRotator(config, server);
await logRotator.start();
}
return logRotator;
}

View file

@ -0,0 +1,265 @@
/*
* Licensed to Elasticsearch B.V. under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch B.V. licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
import del from 'del';
import fs, { existsSync, mkdirSync, statSync, writeFileSync } from 'fs';
import { LogRotator } from './log_rotator';
import { tmpdir } from 'os';
import { dirname, join } from 'path';
const mockOn = jest.fn();
jest.mock('chokidar', () => ({
watch: jest.fn(() => ({
on: mockOn,
close: jest.fn(),
})),
}));
jest.mock('lodash', () => ({
...require.requireActual('lodash'),
throttle: (fn: any) => fn,
}));
const tempDir = join(tmpdir(), 'kbn_log_rotator_test');
const testFilePath = join(tempDir, 'log_rotator_test_log_file.log');
const createLogRotatorConfig: any = (logFilePath: string) => {
return new Map([
['logging.dest', logFilePath],
['logging.rotate.everyBytes', 2],
['logging.rotate.keepFiles', 2],
['logging.rotate.usePolling', false],
['logging.rotate.pollingInterval', 10000],
] as any);
};
const mockServer: any = {
log: jest.fn(),
};
const writeBytesToFile = (filePath: string, numberOfBytes: number) => {
writeFileSync(filePath, 'a'.repeat(numberOfBytes), { flag: 'a' });
};
describe('LogRotator', () => {
beforeEach(() => {
mkdirSync(tempDir, { recursive: true });
writeFileSync(testFilePath, '');
});
afterEach(() => {
del.sync(dirname(testFilePath), { force: true });
mockOn.mockClear();
});
it('rotates log file when bigger than set limit on start', async () => {
writeBytesToFile(testFilePath, 3);
const logRotator = new LogRotator(createLogRotatorConfig(testFilePath), mockServer);
jest.spyOn(logRotator, '_sendReloadLogConfigSignal').mockImplementation(() => {});
await logRotator.start();
expect(logRotator.running).toBe(true);
await logRotator.stop();
const testLogFileDir = dirname(testFilePath);
expect(existsSync(join(testLogFileDir, 'log_rotator_test_log_file.log.0'))).toBeTruthy();
});
it('rotates log file when equal than set limit over time', async () => {
writeBytesToFile(testFilePath, 1);
const logRotator = new LogRotator(createLogRotatorConfig(testFilePath), mockServer);
jest.spyOn(logRotator, '_sendReloadLogConfigSignal').mockImplementation(() => {});
await logRotator.start();
expect(logRotator.running).toBe(true);
const testLogFileDir = dirname(testFilePath);
expect(existsSync(join(testLogFileDir, 'log_rotator_test_log_file.log.0'))).toBeFalsy();
writeBytesToFile(testFilePath, 1);
// ['change', [asyncFunction]]
const onChangeCb = mockOn.mock.calls[0][1];
await onChangeCb(testLogFileDir, { size: 2 });
await logRotator.stop();
expect(existsSync(join(testLogFileDir, 'log_rotator_test_log_file.log.0'))).toBeTruthy();
});
it('rotates log file when file size is bigger than limit', async () => {
writeBytesToFile(testFilePath, 1);
const logRotator = new LogRotator(createLogRotatorConfig(testFilePath), mockServer);
jest.spyOn(logRotator, '_sendReloadLogConfigSignal').mockImplementation(() => {});
await logRotator.start();
expect(logRotator.running).toBe(true);
const testLogFileDir = dirname(testFilePath);
expect(existsSync(join(testLogFileDir, 'log_rotator_test_log_file.log.0'))).toBeFalsy();
writeBytesToFile(testFilePath, 2);
// ['change', [asyncFunction]]
const onChangeCb = mockOn.mock.calls[0][1];
await onChangeCb(testLogFileDir, { size: 3 });
await logRotator.stop();
expect(existsSync(join(testLogFileDir, 'log_rotator_test_log_file.log.0'))).toBeTruthy();
});
it('rotates log file service correctly keeps number of files', async () => {
writeBytesToFile(testFilePath, 3);
const logRotator = new LogRotator(createLogRotatorConfig(testFilePath), mockServer);
jest.spyOn(logRotator, '_sendReloadLogConfigSignal').mockImplementation(() => {});
await logRotator.start();
expect(logRotator.running).toBe(true);
const testLogFileDir = dirname(testFilePath);
expect(existsSync(join(testLogFileDir, 'log_rotator_test_log_file.log.0'))).toBeTruthy();
writeBytesToFile(testFilePath, 2);
// ['change', [asyncFunction]]
const onChangeCb = mockOn.mock.calls[0][1];
await onChangeCb(testLogFileDir, { size: 2 });
writeBytesToFile(testFilePath, 5);
await onChangeCb(testLogFileDir, { size: 5 });
await logRotator.stop();
expect(existsSync(join(testLogFileDir, 'log_rotator_test_log_file.log.0'))).toBeTruthy();
expect(existsSync(join(testLogFileDir, 'log_rotator_test_log_file.log.1'))).toBeTruthy();
expect(existsSync(join(testLogFileDir, 'log_rotator_test_log_file.log.2'))).toBeFalsy();
expect(statSync(join(testLogFileDir, 'log_rotator_test_log_file.log.0')).size).toBe(5);
});
it('rotates log file service correctly keeps number of files even when number setting changes', async () => {
writeBytesToFile(testFilePath, 3);
const logRotator = new LogRotator(createLogRotatorConfig(testFilePath), mockServer);
jest.spyOn(logRotator, '_sendReloadLogConfigSignal').mockImplementation(() => {});
await logRotator.start();
expect(logRotator.running).toBe(true);
const testLogFileDir = dirname(testFilePath);
expect(existsSync(join(testLogFileDir, 'log_rotator_test_log_file.log.0'))).toBeTruthy();
writeBytesToFile(testFilePath, 2);
// ['change', [asyncFunction]]
const onChangeCb = mockOn.mock.calls[0][1];
await onChangeCb(testLogFileDir, { size: 2 });
writeBytesToFile(testFilePath, 5);
await onChangeCb(testLogFileDir, { size: 5 });
await logRotator.stop();
expect(existsSync(join(testLogFileDir, 'log_rotator_test_log_file.log.0'))).toBeTruthy();
expect(existsSync(join(testLogFileDir, 'log_rotator_test_log_file.log.1'))).toBeTruthy();
expect(existsSync(join(testLogFileDir, 'log_rotator_test_log_file.log.2'))).toBeFalsy();
expect(statSync(join(testLogFileDir, 'log_rotator_test_log_file.log.0')).size).toBe(5);
logRotator.keepFiles = 1;
await logRotator.start();
writeBytesToFile(testFilePath, 5);
await onChangeCb(testLogFileDir, { size: 5 });
await logRotator.stop();
expect(existsSync(join(testLogFileDir, 'log_rotator_test_log_file.log.0'))).toBeTruthy();
expect(existsSync(join(testLogFileDir, 'log_rotator_test_log_file.log.1'))).toBeFalsy();
expect(statSync(join(testLogFileDir, 'log_rotator_test_log_file.log.0')).size).toBe(5);
});
it('rotates log file service correctly detects usePolling when it should be false', async () => {
writeBytesToFile(testFilePath, 1);
const logRotator = new LogRotator(createLogRotatorConfig(testFilePath), mockServer);
jest.spyOn(logRotator, '_sendReloadLogConfigSignal').mockImplementation(() => {});
await logRotator.start();
expect(logRotator.running).toBe(true);
expect(logRotator.usePolling).toBe(false);
const usePolling = await logRotator._shouldUsePolling();
expect(usePolling).toBe(false);
await logRotator.stop();
});
it('rotates log file service correctly detects usePolling when it should be true', async () => {
writeBytesToFile(testFilePath, 1);
const logRotator = new LogRotator(createLogRotatorConfig(testFilePath), mockServer);
jest.spyOn(logRotator, '_sendReloadLogConfigSignal').mockImplementation(() => {});
jest.spyOn(fs, 'watch').mockImplementation(
() =>
({
on: jest.fn((eventType, cb) => {
if (eventType === 'error') {
cb();
}
}),
close: jest.fn(),
} as any)
);
await logRotator.start();
expect(logRotator.running).toBe(true);
expect(logRotator.usePolling).toBe(true);
await logRotator.stop();
});
it('rotates log file service correctly fallback to usePolling true after defined timeout', async () => {
jest.useFakeTimers();
writeBytesToFile(testFilePath, 1);
const logRotator = new LogRotator(createLogRotatorConfig(testFilePath), mockServer);
jest.spyOn(logRotator, '_sendReloadLogConfigSignal').mockImplementation(() => {});
jest.spyOn(fs, 'watch').mockImplementation(
() =>
({
on: jest.fn((ev: string) => {
if (ev === 'error') {
jest.runTimersToTime(15000);
}
}),
close: jest.fn(),
} as any)
);
await logRotator.start();
expect(logRotator.running).toBe(true);
expect(logRotator.usePolling).toBe(true);
await logRotator.stop();
jest.useRealTimers();
});
});

View file

@ -0,0 +1,359 @@
/*
* Licensed to Elasticsearch B.V. under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch B.V. licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
import * as chokidar from 'chokidar';
import { isMaster } from 'cluster';
import fs from 'fs';
import { Server } from 'hapi';
import { throttle } from 'lodash';
import { tmpdir } from 'os';
import { basename, dirname, join, sep } from 'path';
import { Observable } from 'rxjs';
import { first } from 'rxjs/operators';
import { promisify } from 'util';
import { KibanaConfig } from '../../kbn_server';
const mkdirAsync = promisify(fs.mkdir);
const readdirAsync = promisify(fs.readdir);
const renameAsync = promisify(fs.rename);
const statAsync = promisify(fs.stat);
const unlinkAsync = promisify(fs.unlink);
const writeFileAsync = promisify(fs.writeFile);
export class LogRotator {
private readonly config: KibanaConfig;
private readonly log: Server['log'];
public logFilePath: string;
public everyBytes: number;
public keepFiles: number;
public running: boolean;
private logFileSize: number;
public isRotating: boolean;
public throttledRotate: () => void;
public stalker: chokidar.FSWatcher | null;
public usePolling: boolean;
public pollingInterval: number;
private stalkerUsePollingPolicyTestTimeout: NodeJS.Timeout | null;
constructor(config: KibanaConfig, server: Server) {
this.config = config;
this.log = server.log.bind(server);
this.logFilePath = config.get('logging.dest');
this.everyBytes = config.get('logging.rotate.everyBytes');
this.keepFiles = config.get('logging.rotate.keepFiles');
this.running = false;
this.logFileSize = 0;
this.isRotating = false;
this.throttledRotate = throttle(async () => await this._rotate(), 5000);
this.stalker = null;
this.usePolling = config.get('logging.rotate.usePolling');
this.pollingInterval = config.get('logging.rotate.pollingInterval');
this.stalkerUsePollingPolicyTestTimeout = null;
}
async start() {
if (this.running) {
return;
}
this.running = true;
// create exit listener for cleanup purposes
this._createExitListener();
// call rotate on startup
await this._callRotateOnStartup();
// init log file size monitor
await this._startLogFileSizeMonitor();
}
stop = () => {
if (!this.running) {
return;
}
// cleanup exit listener
this._deleteExitListener();
// stop log file size monitor
this._stopLogFileSizeMonitor();
this.running = false;
};
async _shouldUsePolling() {
try {
// Setup a test file in order to try the fs env
// and understand if we need to usePolling or not
const tempFileDir = tmpdir();
const tempFile = join(tempFileDir, 'kbn_log_rotation_use_polling_test_file.log');
await mkdirAsync(tempFileDir, { recursive: true });
await writeFileAsync(tempFile, '');
// setup fs.watch for the temp test file
const testWatcher = fs.watch(tempFile, { persistent: false });
// await writeFileAsync(tempFile, 'test');
const usePollingTest$ = new Observable<boolean>(observer => {
// observable complete function
const completeFn = (completeStatus: boolean) => {
if (this.stalkerUsePollingPolicyTestTimeout) {
clearTimeout(this.stalkerUsePollingPolicyTestTimeout);
}
testWatcher.close();
observer.next(completeStatus);
observer.complete();
};
// setup conditions that would fire the observable
this.stalkerUsePollingPolicyTestTimeout = setTimeout(() => completeFn(true), 15000);
testWatcher.on('change', () => completeFn(false));
testWatcher.on('error', () => completeFn(true));
// fire test watcher events
setTimeout(() => {
fs.writeFileSync(tempFile, 'test');
}, 0);
});
// wait for the first observable result and consider it as the result
// for our use polling test
const usePollingTestResult = await usePollingTest$.pipe(first()).toPromise();
// delete the temp file used for the test
await unlinkAsync(tempFile);
return usePollingTestResult;
} catch {
return true;
}
}
async _startLogFileSizeMonitor() {
this.usePolling = await this._shouldUsePolling();
if (this.usePolling && this.usePolling !== this.config.get('logging.rotate.usePolling')) {
this.log(
['warning', 'logging:rotate'],
'The current environment does not support `fs.watch`. Falling back to polling using `fs.watchFile`'
);
}
this.stalker = chokidar.watch(this.logFilePath, {
ignoreInitial: true,
awaitWriteFinish: false,
useFsEvents: false,
usePolling: this.usePolling,
interval: this.pollingInterval,
binaryInterval: this.pollingInterval,
alwaysStat: true,
atomic: false,
});
this.stalker.on('change', this._logFileSizeMonitorHandler);
}
_logFileSizeMonitorHandler = async (filename: string, stats: fs.Stats) => {
if (!filename || !stats) {
return;
}
this.logFileSize = stats.size || 0;
await this.throttledRotate();
};
_stopLogFileSizeMonitor() {
if (!this.stalker) {
return;
}
this.stalker.close();
if (this.stalkerUsePollingPolicyTestTimeout) {
clearTimeout(this.stalkerUsePollingPolicyTestTimeout);
}
}
_createExitListener() {
process.on('exit', this.stop);
}
_deleteExitListener() {
process.removeListener('exit', this.stop);
}
async _getLogFileSizeAndCreateIfNeeded() {
try {
const logFileStats = await statAsync(this.logFilePath);
return logFileStats.size;
} catch {
// touch the file to make the watcher being able to register
// change events
await writeFileAsync(this.logFilePath, '');
return 0;
}
}
async _callRotateOnStartup() {
this.logFileSize = await this._getLogFileSizeAndCreateIfNeeded();
await this._rotate();
}
_shouldRotate() {
// should rotate evaluation
// 1. should rotate if current log size exceeds
// the defined one on everyBytes
// 2. should not rotate if is already rotating or if any
// of the conditions on 1. do not apply
if (this.isRotating) {
return false;
}
return this.logFileSize >= this.everyBytes;
}
async _rotate() {
if (!this._shouldRotate()) {
return;
}
await this._rotateNow();
}
async _rotateNow() {
// rotate process
// 1. get rotated files metadata (list of log rotated files present on the log folder, numerical sorted)
// 2. delete last file
// 3. rename all files to the correct index +1
// 4. rename + compress current log into 1
// 5. send SIGHUP to reload log config
// rotate process is starting
this.isRotating = true;
// get rotated files metadata
const foundRotatedFiles = await this._readRotatedFilesMetadata();
// delete number of rotated files exceeding the keepFiles limit setting
const rotatedFiles: string[] = await this._deleteFoundRotatedFilesAboveKeepFilesLimit(
foundRotatedFiles
);
// delete last file
await this._deleteLastRotatedFile(rotatedFiles);
// rename all files to correct index + 1
// and normalize numbering if by some reason
// (for example log file deletion) that numbering
// was interrupted
await this._renameRotatedFilesByOne(rotatedFiles);
// rename current log into 0
await this._rotateCurrentLogFile();
// send SIGHUP to reload log configuration
this._sendReloadLogConfigSignal();
// Reset log file size
this.logFileSize = 0;
// rotate process is finished
this.isRotating = false;
}
async _readRotatedFilesMetadata() {
const logFileBaseName = basename(this.logFilePath);
const logFilesFolder = dirname(this.logFilePath);
const foundLogFiles: string[] = await readdirAsync(logFilesFolder);
return (
foundLogFiles
.filter(file => new RegExp(`${logFileBaseName}\\.\\d`).test(file))
// we use .slice(-1) here in order to retrieve the last number match in the read filenames
.sort((a, b) => Number(a.match(/(\d+)/g)!.slice(-1)) - Number(b.match(/(\d+)/g)!.slice(-1)))
.map(filename => `${logFilesFolder}${sep}${filename}`)
);
}
async _deleteFoundRotatedFilesAboveKeepFilesLimit(foundRotatedFiles: string[]) {
if (foundRotatedFiles.length <= this.keepFiles) {
return foundRotatedFiles;
}
const finalRotatedFiles = foundRotatedFiles.slice(0, this.keepFiles);
const rotatedFilesToDelete = foundRotatedFiles.slice(
finalRotatedFiles.length,
foundRotatedFiles.length
);
await Promise.all(
rotatedFilesToDelete.map((rotatedFilePath: string) => unlinkAsync(rotatedFilePath))
);
return finalRotatedFiles;
}
async _deleteLastRotatedFile(rotatedFiles: string[]) {
if (rotatedFiles.length < this.keepFiles) {
return;
}
const lastFilePath: string = rotatedFiles.pop() as string;
await unlinkAsync(lastFilePath);
}
async _renameRotatedFilesByOne(rotatedFiles: string[]) {
const logFileBaseName = basename(this.logFilePath);
const logFilesFolder = dirname(this.logFilePath);
for (let i = rotatedFiles.length - 1; i >= 0; i--) {
const oldFilePath = rotatedFiles[i];
const newFilePath = `${logFilesFolder}${sep}${logFileBaseName}.${i + 1}`;
await renameAsync(oldFilePath, newFilePath);
}
}
async _rotateCurrentLogFile() {
const newFilePath = `${this.logFilePath}.0`;
await renameAsync(this.logFilePath, newFilePath);
}
_sendReloadLogConfigSignal() {
if (isMaster) {
(process as NodeJS.EventEmitter).emit('SIGHUP');
return;
}
// Send a special message to the cluster manager
// so it can forward it correctly
// It will only run when we are under cluster mode (not under a production environment)
if (!process.send) {
this.log(
['error', 'logging:rotate'],
'For some unknown reason process.send is not defined, the rotation was not successful'
);
return;
}
process.send(['RELOAD_LOGGING_CONFIG_FROM_SERVER_WORKER']);
}
}