Fix restart not working (#12629)

This commit is contained in:
Koen Kanters
2022-05-29 10:15:47 +02:00
committed by GitHub
parent cc535f11c6
commit 68035a1256
6 changed files with 144 additions and 120 deletions
+6 -7
View File
@@ -2,7 +2,6 @@ require('core-js/features/object/from-entries');
require('core-js/features/array/flat');
const semver = require('semver');
const engines = require('./package.json').engines;
const indexJsRestart = 'indexjs.restart';
const fs = require('fs');
const os = require('os');
const path = require('path');
@@ -16,12 +15,12 @@ let stopping = false;
const hashFile = path.join(__dirname, 'dist', '.hash');
async function restart() {
await stop(indexJsRestart);
await stop(true);
await start();
}
async function exit(code, reason) {
if (reason !== indexJsRestart) {
async function exit(code, restart) {
if (!restart) {
process.exit(code);
}
}
@@ -110,14 +109,14 @@ async function start() {
await controller.start();
}
async function stop(reason=null) {
await controller.stop(reason);
async function stop(restart) {
await controller.stop(restart);
}
async function handleQuit() {
if (!stopping && controller) {
stopping = true;
await stop();
await stop(false);
}
}
+7 -6
View File
@@ -45,11 +45,12 @@ class Controller {
private state: State;
private mqtt: MQTT;
private restartCallback: () => void;
private exitCallback: (code: number) => void;
private exitCallback: (code: number, restart: boolean) => void;
private extensions: Extension[];
private extensionArgs: ExtensionArgs;
constructor(restartCallback: () => void, exitCallback: (code: number) => void) {
logger.init();
this.eventBus = new EventBus( /* istanbul ignore next */ (error) => {
logger.error(`Error: ${error.message}`);
logger.debug(error.stack);
@@ -186,7 +187,7 @@ class Controller {
await this.callExtensions('start', [extension]);
}
async stop(): Promise<void> {
async stop(restart = false): Promise<void> {
// Call extensions
await this.callExtensions('stop', this.extensions);
this.eventBus.removeListeners(this);
@@ -198,16 +199,16 @@ class Controller {
try {
await this.zigbee.stop();
logger.info('Stopped Zigbee2MQTT');
await this.exit(0);
await this.exit(0, restart);
} catch (error) {
logger.error('Failed to stop Zigbee2MQTT');
await this.exit(1);
await this.exit(1, restart);
}
}
async exit(code: number): Promise<void> {
async exit(code: number, restart = false): Promise<void> {
await logger.end();
this.exitCallback(code);
this.exitCallback(code, restart);
}
@bind async onZigbeeAdapterDisconnected(): Promise<void> {
+98 -88
View File
@@ -9,40 +9,12 @@ import assert from 'assert';
const colorizer = winston.format.colorize();
// What transports to enable
const output = settings.get().advanced.log_output;
// Directory to log to
const timestamp = moment(Date.now()).format('YYYY-MM-DD.HH-mm-ss');
const directory = settings.get().advanced.log_directory.replace('%TIMESTAMP%', timestamp);
const logFilename = settings.get().advanced.log_file.replace('%TIMESTAMP%', timestamp);
// Make sure that log directoy exsists when not logging to stdout only
if (output.includes('file')) {
fx.mkdirSync(directory);
if (settings.get().advanced.log_symlink_current) {
const current = settings.get().advanced.log_directory.replace('%TIMESTAMP%', 'current');
const actual = './' + timestamp;
if (fs.existsSync(current)) {
fs.unlinkSync(current);
}
fs.symlinkSync(actual, current);
}
}
type Z2MLogLevel = 'warn' | 'debug' | 'info' | 'error';
type WinstonLogLevel = 'warning' | 'debug' | 'info' | 'error';
const z2mToWinstonLevel = (level: Z2MLogLevel): WinstonLogLevel => level === 'warn' ? 'warning' : level;
const winstonToZ2mLevel = (level: WinstonLogLevel): Z2MLogLevel => level === 'warning' ? 'warn' : level;
// Determine the log level.
const z2mLevel = settings.get().advanced.log_level;
const validLevels = ['info', 'error', 'warn', 'debug'];
assert(validLevels.includes(z2mLevel), `'${z2mLevel}' is not valid log_level, use one of '${validLevels.join(', ')}'`);
const level = z2mToWinstonLevel(z2mLevel);
const levelWithCompensatedLength: {[s: string]: string} = {
'info': 'info ',
'error': 'error',
@@ -50,76 +22,113 @@ const levelWithCompensatedLength: {[s: string]: string} = {
'debug': 'debug',
};
const timestampFormat = (): string => moment().format(settings.get().advanced.timestamp_format);
let logger: winston.Logger;
let fileTransport : winston.transport;
let output: string[];
let directory: string;
let logFilename: string;
let transportsToUse: winston.transport[];
// Setup default console logger
const transportsToUse: winston.transport[] = [
new winston.transports.Console({
function init(): void {
// What transports to enable
output = settings.get().advanced.log_output;
// Directory to log to
const timestamp = moment(Date.now()).format('YYYY-MM-DD.HH-mm-ss');
directory = settings.get().advanced.log_directory.replace('%TIMESTAMP%', timestamp);
logFilename = settings.get().advanced.log_file.replace('%TIMESTAMP%', timestamp);
// Make sure that log directoy exsists when not logging to stdout only
if (output.includes('file')) {
fx.mkdirSync(directory);
if (settings.get().advanced.log_symlink_current) {
const current = settings.get().advanced.log_directory.replace('%TIMESTAMP%', 'current');
const actual = './' + timestamp;
/* istanbul ignore next */
if (fs.existsSync(current)) {
fs.unlinkSync(current);
}
fs.symlinkSync(actual, current);
}
}
// Determine the log level.
const z2mLevel = settings.get().advanced.log_level;
const validLevels = ['info', 'error', 'warn', 'debug'];
assert(validLevels.includes(z2mLevel),
`'${z2mLevel}' is not valid log_level, use one of '${validLevels.join(', ')}'`);
const level = z2mToWinstonLevel(z2mLevel);
const timestampFormat = (): string => moment().format(settings.get().advanced.timestamp_format);
// Setup default console logger
transportsToUse = [
new winston.transports.Console({
level,
silent: !output.includes('console'),
format: winston.format.combine(
winston.format.timestamp({format: timestampFormat}),
winston.format.printf(/* istanbul ignore next */(info) => {
const {timestamp, level, message} = info;
const l = winstonToZ2mLevel(level as WinstonLogLevel);
const plainPrefix = `Zigbee2MQTT:${levelWithCompensatedLength[l]}`;
let prefix = plainPrefix;
if (process.stdout.isTTY) {
prefix = colorizer.colorize(l, plainPrefix);
}
return `${prefix} ${timestamp.split('.')[0]}: ${message}`;
}),
),
}),
];
// Add file logger when enabled
// NOTE: the initiation of the logger, even when not added as transport tries to create the logging directory
const transportFileOptions: KeyValue = {
filename: path.join(directory, logFilename),
json: false,
level,
silent: !output.includes('console'),
format: winston.format.combine(
winston.format.timestamp({format: timestampFormat}),
winston.format.printf(/* istanbul ignore next */(info) => {
const {timestamp, level, message} = info;
const l = winstonToZ2mLevel(level as WinstonLogLevel);
const plainPrefix = `Zigbee2MQTT:${levelWithCompensatedLength[l]}`;
let prefix = plainPrefix;
if (process.stdout.isTTY) {
prefix = colorizer.colorize(l, plainPrefix);
}
return `${prefix} ${timestamp.split('.')[0]}: ${message}`;
return `${levelWithCompensatedLength[l]} ${timestamp.split('.')[0]}: ${message}`;
}),
),
}),
];
// Add file logger when enabled
// NOTE: the initiation of the logger, even when not added as transport tries to create the logging directory
const transportFileOptions: KeyValue = {
filename: path.join(directory, logFilename),
json: false,
level,
format: winston.format.combine(
winston.format.timestamp({format: timestampFormat}),
winston.format.printf(/* istanbul ignore next */(info) => {
const {timestamp, level, message} = info;
const l = winstonToZ2mLevel(level as WinstonLogLevel);
return `${levelWithCompensatedLength[l]} ${timestamp.split('.')[0]}: ${message}`;
}),
),
};
if (settings.get().advanced.log_rotation) {
transportFileOptions.tailable = true;
transportFileOptions.maxFiles = 3; // Keep last 3 files
transportFileOptions.maxsize = 10000000; // 10MB
}
let fileTransport : winston.transport;
if (output.includes('file')) {
fileTransport = new winston.transports.File(transportFileOptions);
transportsToUse.push(fileTransport);
}
/* istanbul ignore next */
if (output.includes('syslog')) {
// eslint-disable-next-line
require('winston-syslog').Syslog;
const options: KeyValue = {
app_name: 'Zigbee2MQTT',
format: winston.format.printf(/* istanbul ignore next */(info) => {
return `${info.message}`;
}),
...settings.get().advanced.log_syslog,
};
if (options.hasOwnProperty('type')) options.type = options.type.toString();
// @ts-ignore
transportsToUse.push(new winston.transports.Syslog(options));
}
// Create logger
const logger = winston.createLogger({transports: transportsToUse, levels: winston.config.syslog.levels});
if (settings.get().advanced.log_rotation) {
transportFileOptions.tailable = true;
transportFileOptions.maxFiles = 3; // Keep last 3 files
transportFileOptions.maxsize = 10000000; // 10MB
}
if (output.includes('file')) {
fileTransport = new winston.transports.File(transportFileOptions);
transportsToUse.push(fileTransport);
}
/* istanbul ignore next */
if (output.includes('syslog')) {
// eslint-disable-next-line
require('winston-syslog').Syslog;
const options: KeyValue = {
app_name: 'Zigbee2MQTT',
format: winston.format.printf(/* istanbul ignore next */(info) => {
return `${info.message}`;
}),
...settings.get().advanced.log_syslog,
};
if (options.hasOwnProperty('type')) options.type = options.type.toString();
// @ts-ignore
transportsToUse.push(new winston.transports.Syslog(options));
}
logger = winston.createLogger({transports: transportsToUse, levels: winston.config.syslog.levels});
}
// Cleanup any old log directory.
function cleanup(): void {
@@ -211,5 +220,6 @@ async function end(): Promise<void> {
}
export default {
logOutput, warn, warning, error, info, debug, setLevel, getLevel, cleanup, addTransport, end, winston: logger,
init, logOutput, warn, warning, error, info, debug, setLevel, getLevel, cleanup, addTransport, end,
winston: (): winston.Logger => logger,
};
+6 -6
View File
@@ -203,7 +203,7 @@ describe('Controller', () => {
await flushPromises();
expect(logger.error).toHaveBeenCalledWith('MQTT failed to connect: addr not found');
expect(mockExit).toHaveBeenCalledTimes(1);
expect(mockExit).toHaveBeenCalledWith(1);
expect(mockExit).toHaveBeenCalledWith(1, false);
});
it('Start controller with permit join true', async () => {
@@ -220,13 +220,13 @@ describe('Controller', () => {
expect(zigbeeHerdsman.setTransmitPower).toHaveBeenCalledWith(14);
});
it('Start controller and stop', async () => {
it('Start controller and stop with restart', async () => {
await controller.start();
await controller.stop();
await controller.stop(true);
expect(MQTT.end).toHaveBeenCalledTimes(1);
expect(zigbeeHerdsman.stop).toHaveBeenCalledTimes(1);
expect(mockExit).toHaveBeenCalledTimes(1);
expect(mockExit).toHaveBeenCalledWith(0);
expect(mockExit).toHaveBeenCalledWith(0, true);
});
it('Start controller and stop', async () => {
@@ -236,7 +236,7 @@ describe('Controller', () => {
expect(MQTT.end).toHaveBeenCalledTimes(1);
expect(zigbeeHerdsman.stop).toHaveBeenCalledTimes(1);
expect(mockExit).toHaveBeenCalledTimes(1);
expect(mockExit).toHaveBeenCalledWith(1);
expect(mockExit).toHaveBeenCalledWith(1, false);
});
it('Start controller adapter disconnects', async () => {
@@ -247,7 +247,7 @@ describe('Controller', () => {
expect(MQTT.end).toHaveBeenCalledTimes(1);
expect(zigbeeHerdsman.stop).toHaveBeenCalledTimes(1);
expect(mockExit).toHaveBeenCalledTimes(1);
expect(mockExit).toHaveBeenCalledWith(1);
expect(mockExit).toHaveBeenCalledWith(1, false);
});
it('Handle mqtt message', async () => {
+26 -13
View File
@@ -25,6 +25,7 @@ describe('Logger', () => {
it('Create log directory', () => {
const logger = require('../lib/util/logger').default;
logger.init();
logger.logOutput();
const dirs = fs.readdirSync(dir.name);
expect(dirs.length).toBe(1);
@@ -32,6 +33,7 @@ describe('Logger', () => {
it('Should cleanup', () => {
const logger = require('../lib/util/logger').default;
logger.init();
logger.logOutput();
for (const d of fs.readdirSync(dir.name)) {
@@ -49,6 +51,7 @@ describe('Logger', () => {
it('Should not cleanup when there is no timestamp set', () => {
const logger = require('../lib/util/logger').default;
logger.init();
logger.logOutput();
for (let i = 30; i < 40; i++) {
fs.mkdirSync(path.join(dir.name, `log_${i}`));
@@ -62,6 +65,7 @@ describe('Logger', () => {
it('Set and get log level', () => {
const logger = require('../lib/util/logger').default;
logger.init();
logger.logOutput();
logger.setLevel('debug');
expect(logger.getLevel()).toBe('debug');
@@ -74,23 +78,26 @@ describe('Logger', () => {
}
const logger = require('../lib/util/logger').default;
expect(logger.winston.transports.length).toBe(2);
logger.init();
expect(logger.winston().transports.length).toBe(2);
logger.addTransport(new DummyTransport());
expect(logger.winston.transports.length).toBe(3);
expect(logger.winston().transports.length).toBe(3);
});
it('Set and get log level warn <-> warning', () => {
const logger = require('../lib/util/logger').default;
logger.init();
logger.logOutput();
logger.setLevel('warn');
expect(logger.winston.transports[0].level).toBe('warning');
expect(logger.winston().transports[0].level).toBe('warning');
expect(logger.getLevel()).toBe('warn');
});
it('Logger should be console and file by default', () => {
const logger = require('../lib/util/logger').default;
logger.init();
logger.logOutput();
const pipes = logger.winston._readableState.pipes;
const pipes = logger.winston()._readableState.pipes;
expect(pipes.length).toBe(2);
expect(pipes[0].constructor.name).toBe('Console');
expect(pipes[0].silent).toBe(false);
@@ -101,8 +108,9 @@ describe('Logger', () => {
it('Logger can be file only', () => {
settings.set(['advanced', 'log_output'], ['file']);
const logger = require('../lib/util/logger').default;
logger.init();
logger.logOutput();
const pipes = logger.winston._readableState.pipes;
const pipes = logger.winston()._readableState.pipes;
expect(pipes.length).toBe(2);
expect(pipes[0].constructor.name).toBe('Console');
expect(pipes[0].silent).toBe(true);
@@ -113,8 +121,9 @@ describe('Logger', () => {
it('Logger can be console only', () => {
settings.set(['advanced', 'log_output'], ['console']);
const logger = require('../lib/util/logger').default;
logger.init();
logger.logOutput();
const pipes = logger.winston._readableState.pipes;
const pipes = logger.winston()._readableState.pipes;
expect(pipes.constructor.name).toBe('Console');
expect(pipes.silent).toBe(false);
});
@@ -122,8 +131,9 @@ describe('Logger', () => {
it('Logger can be nothing', () => {
settings.set(['advanced', 'log_output'], []);
const logger = require('../lib/util/logger').default;
logger.init();
logger.logOutput();
const pipes = logger.winston._readableState.pipes;
const pipes = logger.winston()._readableState.pipes;
expect(pipes.constructor.name).toBe('Console');
expect(pipes.silent).toBe(true);
});
@@ -131,8 +141,9 @@ describe('Logger', () => {
it('Should allow to disable log rotation', () => {
settings.set(['advanced', 'log_rotation'], false);
const logger = require('../lib/util/logger').default;
logger.init();
logger.logOutput();
const pipes = logger.winston._readableState.pipes;
const pipes = logger.winston()._readableState.pipes;
expect(pipes[1].constructor.name).toBe('File');
expect(pipes[1].maxFiles).toBeNull();
expect(pipes[1].tailable).toBeFalsy();
@@ -142,6 +153,7 @@ describe('Logger', () => {
it('Should allow to symlink logs to current directory', () => {
settings.set(['advanced', 'log_symlink_current'], true);
let logger = require('../lib/util/logger').default;
logger.init();
logger.logOutput();
expect(fs.readdirSync(dir.name).includes('current')).toBeTruthy()
@@ -151,23 +163,24 @@ describe('Logger', () => {
it('Log', () => {
const logger = require('../lib/util/logger').default;
const warn = jest.spyOn(logger.winston, 'warning');
logger.init();
const warn = jest.spyOn(logger.winston(), 'warning');
logger.warn('warn');
expect(warn).toHaveBeenCalledWith('warn');
const debug = jest.spyOn(logger.winston, 'debug');
const debug = jest.spyOn(logger.winston(), 'debug');
logger.debug('debug');
expect(debug).toHaveBeenCalledWith('debug');
const warning = jest.spyOn(logger.winston, 'warning');
const warning = jest.spyOn(logger.winston(), 'warning');
logger.warning('warning');
expect(warning).toHaveBeenCalledWith('warning');
const info = jest.spyOn(logger.winston, 'info');
const info = jest.spyOn(logger.winston(), 'info');
logger.info('info');
expect(info).toHaveBeenCalledWith('info');
const error = jest.spyOn(logger.winston, 'error');
const error = jest.spyOn(logger.winston(), 'error');
logger.error('error');
expect(error).toHaveBeenCalledWith('error');
});
+1
View File
@@ -12,6 +12,7 @@ const callTransports = (level, message) => {
}
const mock = {
init: jest.fn(),
info: jest.fn().mockImplementation((msg) => callTransports('info', msg)),
warn: jest.fn().mockImplementation((msg) => callTransports('warn', msg)),
error: jest.fn().mockImplementation((msg) => callTransports('error', msg)),