Test NP logging config reload on SIGHUP (#57681)

* TSify reload config test and simplify logic

* get rid of mutable config in tests

* increase timeouts

* address comments
This commit is contained in:
Mikhail Shustov 2020-02-20 12:05:08 +01:00 committed by GitHub
parent 0b644117b8
commit dd8eb62d9a
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
5 changed files with 310 additions and 224 deletions

View file

@ -1,4 +1,5 @@
server: server:
autoListen: false
port: 8274 port: 8274
logging: logging:
json: true json: true
@ -6,3 +7,5 @@ optimize:
enabled: false enabled: false
plugins: plugins:
initialize: false initialize: false
migrations:
skip: true

View file

@ -0,0 +1,22 @@
server:
autoListen: false
port: 8274
logging:
loggers:
- context: root
appenders:
- console
level: debug
appenders:
console:
kind: console
layout:
kind: json
root:
level: debug
optimize:
enabled: false
plugins:
initialize: false
migrations:
skip: true

View file

@ -0,0 +1,22 @@
server:
autoListen: false
port: 8274
logging:
loggers:
- context: root
appenders:
- file
level: debug
appenders:
file:
kind: file
layout:
kind: pattern
root:
level: debug
optimize:
enabled: false
plugins:
initialize: false
migrations:
skip: true

View file

@ -1,224 +0,0 @@
/*
* 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 { spawn } from 'child_process';
import fs from 'fs';
import path from 'path';
import os from 'os';
import del from 'del';
import { safeDump } from 'js-yaml';
import {
createMapStream,
createSplitStream,
createPromiseFromStreams,
} from '../../../legacy/utils/streams';
import { getConfigFromFiles } from '../../../core/server/config/read_config';
const testConfigFile = follow('__fixtures__/reload_logging_config/kibana.test.yml');
const kibanaPath = follow('../../../../scripts/kibana.js');
const second = 1000;
const minute = second * 60;
const tempDir = path.join(os.tmpdir(), 'kbn-reload-test');
function follow(file) {
return path.relative(process.cwd(), path.resolve(__dirname, file));
}
function setLoggingJson(enabled) {
const conf = getConfigFromFiles([testConfigFile]);
conf.logging = conf.logging || {};
conf.logging.json = enabled;
const yaml = safeDump(conf);
fs.writeFileSync(testConfigFile, yaml);
}
describe('Server logging configuration', function() {
let child;
let isJson;
beforeEach(() => {
isJson = true;
setLoggingJson(true);
fs.mkdirSync(tempDir, { recursive: true });
});
afterEach(() => {
isJson = true;
setLoggingJson(true);
if (child !== undefined) {
child.kill();
child = undefined;
}
del.sync(tempDir, { force: true });
});
const isWindows = /^win/.test(process.platform);
if (isWindows) {
it('SIGHUP is not a feature of Windows.', () => {
// nothing to do for Windows
});
} else {
it(
'should be reloadable via SIGHUP process signaling',
async function() {
expect.assertions(3);
child = spawn(
process.execPath,
[kibanaPath, '--config', testConfigFile, '--oss', '--verbose'],
{
stdio: 'pipe',
}
);
let sawJson = false;
let sawNonjson = false;
const [exitCode] = await Promise.all([
Promise.race([
new Promise(r => child.once('exit', r)).then(code => (code === null ? 0 : code)),
new Promise(r => child.once('error', r)).then(err => {
throw new Error(
`error in child process while attempting to reload config. ${err.stack ||
err.message ||
err}`
);
}),
]),
createPromiseFromStreams([
child.stdout,
createSplitStream('\n'),
createMapStream(async line => {
if (!line) {
// skip empty lines
return;
}
if (isJson) {
const data = JSON.parse(line);
sawJson = true;
// We know the sighup handler will be registered before
// root.setup() is called
if (data.message.includes('setting up root')) {
isJson = false;
setLoggingJson(false);
// Reload logging config. We give it a little bit of time to just make
// sure the process sighup handler is registered.
await new Promise(r => setTimeout(r, 100));
child.kill('SIGHUP');
}
} else if (line.startsWith('{')) {
// We have told Kibana to stop logging json, but it hasn't completed
// the switch yet, so we ignore before switching over.
} else {
// Kibana has successfully stopped logging json, so kill the server.
sawNonjson = true;
child && child.kill();
child = undefined;
}
}),
]),
]);
expect(exitCode).toEqual(0);
expect(sawJson).toEqual(true);
expect(sawNonjson).toEqual(true);
},
minute
);
it(
'should recreate file handler on SIGHUP',
function(done) {
expect.hasAssertions();
const logPath = path.resolve(tempDir, 'kibana.log');
const logPathArchived = path.resolve(tempDir, 'kibana_archive.log');
function watchFileUntil(path, matcher, timeout) {
return new Promise((resolve, reject) => {
const timeoutHandle = setTimeout(() => {
fs.unwatchFile(path);
reject(`watchFileUntil timed out for "${matcher}"`);
}, timeout);
fs.watchFile(path, () => {
try {
const contents = fs.readFileSync(path);
if (matcher.test(contents)) {
clearTimeout(timeoutHandle);
fs.unwatchFile(path);
resolve(contents);
}
} catch (e) {
// noop
}
});
});
}
child = spawn(process.execPath, [
kibanaPath,
'--oss',
'--config',
testConfigFile,
'--logging.dest',
logPath,
'--plugins.initialize',
'false',
'--logging.json',
'false',
'--verbose',
]);
watchFileUntil(logPath, /starting server/, 2 * minute)
.then(() => {
// once the server is running, archive the log file and issue SIGHUP
fs.renameSync(logPath, logPathArchived);
child.kill('SIGHUP');
})
.then(() =>
watchFileUntil(logPath, /Reloaded logging configuration due to SIGHUP/, 10 * second)
)
.then(contents => {
const lines = contents.toString().split('\n');
// should be the first line of the new log file
expect(lines[0]).toMatch(/Reloaded logging configuration due to SIGHUP/);
child.kill();
})
.then(done, done);
},
3 * minute
);
}
});

View file

@ -0,0 +1,263 @@
/*
* 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 Child from 'child_process';
import Fs from 'fs';
import Path from 'path';
import Os from 'os';
import Del from 'del';
import * as Rx from 'rxjs';
import { map, filter, take } from 'rxjs/operators';
import { safeDump } from 'js-yaml';
import { getConfigFromFiles } from '../../../core/server/config/read_config';
const legacyConfig = follow('__fixtures__/reload_logging_config/kibana.test.yml');
const configFileLogConsole = follow(
'__fixtures__/reload_logging_config/kibana_log_console.test.yml'
);
const configFileLogFile = follow('__fixtures__/reload_logging_config/kibana_log_file.test.yml');
const kibanaPath = follow('../../../../scripts/kibana.js');
const second = 1000;
const minute = second * 60;
const tempDir = Path.join(Os.tmpdir(), 'kbn-reload-test');
function follow(file: string) {
return Path.relative(process.cwd(), Path.resolve(__dirname, file));
}
function watchFileUntil(path: string, matcher: RegExp, timeout: number) {
return new Promise<string>((resolve, reject) => {
const timeoutHandle = setTimeout(() => {
Fs.unwatchFile(path);
reject(`watchFileUntil timed out for "${matcher}"`);
}, timeout);
Fs.watchFile(path, () => {
try {
const contents = Fs.readFileSync(path, 'utf-8');
if (matcher.test(contents)) {
clearTimeout(timeoutHandle);
Fs.unwatchFile(path);
resolve(contents);
}
} catch (e) {
// noop
}
});
});
}
function containsJsonOnly(content: string[]) {
return content.every(line => line.startsWith('{'));
}
function createConfigManager(configPath: string) {
return {
modify(fn: (input: Record<string, any>) => Record<string, any>) {
const oldContent = getConfigFromFiles([configPath]);
const yaml = safeDump(fn(oldContent));
Fs.writeFileSync(configPath, yaml);
},
};
}
describe('Server logging configuration', function() {
let child: Child.ChildProcess;
beforeEach(() => {
Fs.mkdirSync(tempDir, { recursive: true });
});
afterEach(async () => {
if (child !== undefined) {
child.kill();
// wait for child to be killed otherwise jest complains that process not finished
await new Promise(res => setTimeout(res, 1000));
}
Del.sync(tempDir, { force: true });
});
const isWindows = /^win/.test(process.platform);
if (isWindows) {
it('SIGHUP is not a feature of Windows.', () => {
// nothing to do for Windows
});
} else {
describe('legacy logging', () => {
it(
'should be reloadable via SIGHUP process signaling',
async function() {
const configFilePath = Path.resolve(tempDir, 'kibana.yml');
Fs.copyFileSync(legacyConfig, configFilePath);
child = Child.spawn(process.execPath, [
kibanaPath,
'--oss',
'--config',
configFilePath,
'--verbose',
]);
const message$ = Rx.fromEvent(child.stdout, 'data').pipe(
map(messages =>
String(messages)
.split('\n')
.filter(Boolean)
)
);
await message$
.pipe(
// We know the sighup handler will be registered before this message logged
filter(messages => messages.some(m => m.includes('setting up root'))),
take(1)
)
.toPromise();
const lastMessage = await message$.pipe(take(1)).toPromise();
expect(containsJsonOnly(lastMessage)).toBe(true);
createConfigManager(configFilePath).modify(oldConfig => {
oldConfig.logging.json = false;
return oldConfig;
});
child.kill('SIGHUP');
await message$
.pipe(
filter(messages => !containsJsonOnly(messages)),
take(1)
)
.toPromise();
},
minute
);
it(
'should recreate file handle on SIGHUP',
async function() {
const logPath = Path.resolve(tempDir, 'kibana.log');
const logPathArchived = Path.resolve(tempDir, 'kibana_archive.log');
child = Child.spawn(process.execPath, [
kibanaPath,
'--oss',
'--config',
legacyConfig,
'--logging.dest',
logPath,
'--verbose',
]);
await watchFileUntil(logPath, /setting up root/, 30 * second);
// once the server is running, archive the log file and issue SIGHUP
Fs.renameSync(logPath, logPathArchived);
child.kill('SIGHUP');
await watchFileUntil(
logPath,
/Reloaded logging configuration due to SIGHUP/,
30 * second
);
},
minute
);
});
describe('platform logging', () => {
it(
'should be reloadable via SIGHUP process signaling',
async function() {
const configFilePath = Path.resolve(tempDir, 'kibana.yml');
Fs.copyFileSync(configFileLogConsole, configFilePath);
child = Child.spawn(process.execPath, [kibanaPath, '--oss', '--config', configFilePath]);
const message$ = Rx.fromEvent(child.stdout, 'data').pipe(
map(messages =>
String(messages)
.split('\n')
.filter(Boolean)
)
);
await message$
.pipe(
// We know the sighup handler will be registered before this message logged
filter(messages => messages.some(m => m.includes('setting up root'))),
take(1)
)
.toPromise();
const lastMessage = await message$.pipe(take(1)).toPromise();
expect(containsJsonOnly(lastMessage)).toBe(true);
createConfigManager(configFilePath).modify(oldConfig => {
oldConfig.logging.appenders.console.layout.kind = 'pattern';
return oldConfig;
});
child.kill('SIGHUP');
await message$
.pipe(
filter(messages => !containsJsonOnly(messages)),
take(1)
)
.toPromise();
},
30 * second
);
it(
'should recreate file handle on SIGHUP',
async function() {
const configFilePath = Path.resolve(tempDir, 'kibana.yml');
Fs.copyFileSync(configFileLogFile, configFilePath);
const logPath = Path.resolve(tempDir, 'kibana.log');
const logPathArchived = Path.resolve(tempDir, 'kibana_archive.log');
createConfigManager(configFilePath).modify(oldConfig => {
oldConfig.logging.appenders.file.path = logPath;
return oldConfig;
});
child = Child.spawn(process.execPath, [kibanaPath, '--oss', '--config', configFilePath]);
await watchFileUntil(logPath, /setting up root/, 30 * second);
// once the server is running, archive the log file and issue SIGHUP
Fs.renameSync(logPath, logPathArchived);
child.kill('SIGHUP');
await watchFileUntil(
logPath,
/Reloaded logging configuration due to SIGHUP/,
30 * second
);
},
minute
);
});
}
});