diff --git a/lib/controller.ts b/lib/controller.ts index 587add0e..ca32921f 100644 --- a/lib/controller.ts +++ b/lib/controller.ts @@ -8,7 +8,8 @@ import utils from './util/utils'; import stringify from 'json-stable-stringify-without-jsonify'; import assert from 'assert'; import bind from 'bind-decorator'; -import * as zhc from 'zigbee-herdsman-converters'; +import {setLogger as zhcSetLogger} from 'zigbee-herdsman-converters'; +import {setLogger as zhSetLogger} from 'zigbee-herdsman'; // Extensions import ExtensionFrontend from './extension/frontend'; @@ -60,6 +61,8 @@ export class Controller { constructor(restartCallback: () => void, exitCallback: (code: number, restart: boolean) => void) { logger.init(); + zhSetLogger(logger); + zhcSetLogger(logger); this.eventBus = new EventBus(); this.zigbee = new Zigbee(this.eventBus); this.mqtt = new MQTT(this.eventBus); @@ -92,8 +95,6 @@ export class Controller { /* istanbul ignore next */ settings.get().advanced.soft_reset_timeout !== 0 && new ExtensionSoftReset(...this.extensionArgs), ].filter((n) => n); - - zhc.setLogger(logger); } async start(): Promise { @@ -138,9 +139,9 @@ export class Controller { // Enable zigbee join try { if (settings.get().permit_join) { - logger.warn('`permit_join` set to `true` in configuration.yaml.'); - logger.warn('Allowing new devices to join.'); - logger.warn('Set `permit_join` to `false` once you joined all devices.'); + logger.warning('`permit_join` set to `true` in configuration.yaml.'); + logger.warning('Allowing new devices to join.'); + logger.warning('Set `permit_join` to `false` once you joined all devices.'); } await this.zigbee.permitJoin(settings.get().permit_join); diff --git a/lib/extension/availability.ts b/lib/extension/availability.ts index 04d7dd37..df19e91e 100644 --- a/lib/extension/availability.ts +++ b/lib/extension/availability.ts @@ -87,7 +87,7 @@ export default class Availability extends Extension { logger.debug(`Successfully pinged '${device.name}' (attempt ${i + 1}/${attempts})`); break; } catch (error) { - logger.warn(`Failed to ping '${device.name}' (attempt ${i + 1}/${attempts}, ${error.message})`); + logger.warning(`Failed to ping '${device.name}' (attempt ${i + 1}/${attempts}, ${error.message})`); // Try again in 3 seconds. const lastAttempt = i - 1 === attempts; !lastAttempt && await utils.sleep(3); diff --git a/lib/extension/bind.ts b/lib/extension/bind.ts index acc9af15..1a254e08 100755 --- a/lib/extension/bind.ts +++ b/lib/extension/bind.ts @@ -394,7 +394,7 @@ export default class Bind extends Extension { await endpoint.configureReporting(bind.cluster.name, items); logger.info(`Successfully setup reporting for '${entity}' cluster '${bind.cluster.name}'`); } catch (error) { - logger.warn(`Failed to setup reporting for '${entity}' cluster '${bind.cluster.name}'`); + logger.warning(`Failed to setup reporting for '${entity}' cluster '${bind.cluster.name}'`); } } } @@ -436,7 +436,7 @@ export default class Bind extends Extension { await endpoint.configureReporting(cluster, items); logger.info(`Successfully disabled reporting for '${entity}' cluster '${cluster}'`); } catch (error) { - logger.warn(`Failed to disable reporting for '${entity}' cluster '${cluster}'`); + logger.warning(`Failed to disable reporting for '${entity}' cluster '${cluster}'`); } } diff --git a/lib/extension/configure.ts b/lib/extension/configure.ts index bc366a7b..3178f5c9 100644 --- a/lib/extension/configure.ts +++ b/lib/extension/configure.ts @@ -35,7 +35,7 @@ export default class Configure extends Extension { } if (!device.definition || !device.definition.configure) { - logger.warn(`Skipping configure of '${device.name}', device does not require this.`); + logger.warning(`Skipping configure of '${device.name}', device does not require this.`); return; } diff --git a/lib/extension/homeassistant.ts b/lib/extension/homeassistant.ts index e490e164..cace4729 100644 --- a/lib/extension/homeassistant.ts +++ b/lib/extension/homeassistant.ts @@ -128,7 +128,7 @@ export default class HomeAssistant extends Extension { override async start(): Promise { if (!settings.get().advanced.cache_state) { - logger.warn('In order for Home Assistant integration to work properly set `cache_state: true'); + logger.warning('In order for Home Assistant integration to work properly set `cache_state: true'); } this.zigbee2MQTTVersion = (await utils.getZigbee2MQTTVersion(false)).version; diff --git a/lib/extension/legacy/bridgeLegacy.ts b/lib/extension/legacy/bridgeLegacy.ts index a94f09d3..4e185771 100644 --- a/lib/extension/legacy/bridgeLegacy.ts +++ b/lib/extension/legacy/bridgeLegacy.ts @@ -445,7 +445,7 @@ export default class BridgeLegacy extends Extension { stringify({type: `touchlink`, message: 'reset_success', meta: {status: 'success'}}), ); } else { - logger.warn('Failed to factory reset device through Touchlink'); + logger.warning('Failed to factory reset device through Touchlink'); this.mqtt.publish( 'bridge/log', stringify({type: `touchlink`, message: 'reset_failed', meta: {status: 'failed'}}), diff --git a/lib/extension/legacy/deviceGroupMembership.ts b/lib/extension/legacy/deviceGroupMembership.ts index 9f51a735..21750a57 100644 --- a/lib/extension/legacy/deviceGroupMembership.ts +++ b/lib/extension/legacy/deviceGroupMembership.ts @@ -36,7 +36,7 @@ export default class DeviceGroupMembership extends Extension { ); if (!response) { - logger.warn(`Couldn't get group membership of ${device.ieeeAddr}`); + logger.warning(`Couldn't get group membership of ${device.ieeeAddr}`); return; } diff --git a/lib/extension/legacy/softReset.ts b/lib/extension/legacy/softReset.ts index 522b05c5..5522ee80 100644 --- a/lib/extension/legacy/softReset.ts +++ b/lib/extension/legacy/softReset.ts @@ -39,16 +39,16 @@ export default class SoftReset extends Extension { } private async handleTimeout(): Promise { - logger.warn('Soft reset timeout triggered'); + logger.warning('Soft reset timeout triggered'); try { await this.zigbee.reset('soft'); - logger.warn('Soft reset ZNP due to timeout'); + logger.warning('Soft reset ZNP due to timeout'); } catch (error) { - logger.warn('Soft reset failed, trying stop/start'); + logger.warning('Soft reset failed, trying stop/start'); await this.zigbee.stop(); - logger.warn('Zigbee stopped'); + logger.warning('Zigbee stopped'); try { await this.zigbee.start(); diff --git a/lib/util/logger.ts b/lib/util/logger.ts index f35de3c1..065c9d83 100644 --- a/lib/util/logger.ts +++ b/lib/util/logger.ts @@ -7,20 +7,8 @@ import fx from 'mkdir-recursive'; import {rimrafSync} from 'rimraf'; import assert from 'assert'; -const colorizer = winston.format.colorize(); - -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; - -const levelWithCompensatedLength: {[s: string]: string} = { - 'info': 'info ', - 'error': 'error', - 'warn': 'warn ', - 'debug': 'debug', -}; +const LOG_LEVELS = ['error', 'warning', 'info', 'debug'] as const; +type LogLevel = typeof LOG_LEVELS[number]; let logger: winston.Logger; let fileTransport : winston.transport; @@ -32,14 +20,36 @@ let transportsToUse: winston.transport[]; 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); + // Determine the log level. + const settingLevel = settings.get().advanced.log_level; + // workaround for syslog<>npm level conflict + const level = settingLevel === 'warn' ? 'warning' : settingLevel; + + assert(LOG_LEVELS.includes(level), `'${level}' is not valid log_level, use one of '${LOG_LEVELS.join(', ')}'`); + + const timestampFormat = (): string => moment().format(settings.get().advanced.timestamp_format); + + // Setup default console logger + transportsToUse = [ + new winston.transports.Console({ + level, + silent: !output.includes('console'), + // winston.config.syslog.levels sets 'warning' as 'red' + format: winston.format.combine( + winston.format.colorize({colors: {debug: 'blue', info: 'green', warning: 'yellow', error: 'red'}}), + winston.format.printf(/* istanbul ignore next */(info) => { + return `[${info.timestamp}] ${info.level}: \t${info.namespace}: ${info.message}`; + }), + ), + }), + ]; - // Make sure that log directory exists when not logging to stdout only if (output.includes('file')) { + // Make sure that log directory exists when not logging to stdout only fx.mkdirSync(directory); if (settings.get().advanced.log_symlink_current) { @@ -51,62 +61,24 @@ function init(): void { } 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({ + // 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}`; - }), - ), - }), - ]; - - // 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}`; + format: winston.format.printf(/* istanbul ignore next */(info) => { + return `[${info.timestamp}] ${info.level}: \t${info.namespace}: ${info.message}`; }), - ), - }; + }; - if (settings.get().advanced.log_rotation) { - transportFileOptions.tailable = true; - transportFileOptions.maxFiles = 3; // Keep last 3 files - transportFileOptions.maxsize = 10000000; // 10MB - } + 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); } @@ -115,19 +87,78 @@ function init(): void { 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}`; + return `${info.namespace}: ${info.message}`; }), ...settings.get().advanced.log_syslog, }; - if (options.hasOwnProperty('type')) options.type = options.type.toString(); - // @ts-ignore + + if (options.hasOwnProperty('type')) { + options.type = options.type.toString(); + } + + // @ts-expect-error custom transport transportsToUse.push(new winston.transports.Syslog(options)); } - logger = winston.createLogger({transports: transportsToUse, levels: winston.config.syslog.levels}); + logger = winston.createLogger({ + format: winston.format.combine( + winston.format.errors({stack: true}), + winston.format.timestamp({format: timestampFormat}), + ), + transports: transportsToUse, + levels: winston.config.syslog.levels, + }); +} + +function addTransport(transport: winston.transport): void { + transport.level = transportsToUse[0].level; + logger.add(transport); +} + +// TODO refactor Z2M level to 'warning' to simplify logic +function getLevel(): LogLevel | 'warn' { + let level = transportsToUse[0].level; + + if (level === 'warning') { + level = 'warn'; + } + + return transportsToUse[0].level as LogLevel | 'warn'; +} + +function setLevel(level: LogLevel | 'warn'): void { + if (level === 'warn') { + level = 'warning'; + } + + logger.transports.forEach((transport) => transport.level = level); +} + +function warning(message: string, namespace: string = 'z2m'): void { + // @ts-expect-error syslog level + logger.warning(message, {namespace}); +} + +function info(message: string, namespace: string = 'z2m'): void { + logger.info(message, {namespace}); +} + +function debug(message: string, namespace: string = 'z2m'): void { + logger.debug(message, {namespace}); +} + +function error(message: string, namespace: string = 'z2m'): void { + logger.error(message, {namespace}); +} + +// Print to user what logging is enabled +function logOutput(): void { + const filename = output.includes('file') ? ` (filename: ${logFilename})` : ``; + info(`Logging to ${output.join(', ')}${filename}.`); } // Cleanup any old log directory. @@ -143,61 +174,12 @@ function cleanup(): void { directories.sort((a: KeyValue, b: KeyValue) => b.birth - a.birth); directories = directories.slice(10, directories.length); directories.forEach((dir) => { - logger.debug(`Removing old log directory '${dir.path}'`); + debug(`Removing old log directory '${dir.path}'`); rimrafSync(dir.path); }); } } -// Print to user what logging is enabled -function logOutput(): void { - if (output.includes('file')) { - if (output.includes('console')) { - logger.info(`Logging to console and directory: '${directory}' filename: ${logFilename}`); - } else { - logger.info(`Logging to directory: '${directory}' filename: ${logFilename}`); - } - cleanup(); - } else if (output.includes('console')) { - logger.info(`Logging to console only'`); - } -} - -function addTransport(transport: winston.transport): void { - transport.level = transportsToUse[0].level; - logger.add(transport); -} - -function getLevel(): Z2MLogLevel { - return winstonToZ2mLevel(transportsToUse[0].level as WinstonLogLevel); -} - -function setLevel(level: Z2MLogLevel): void { - logger.transports.forEach((transport) => transport.level = z2mToWinstonLevel(level as Z2MLogLevel)); -} - -function warn(message: string): void { - // @ts-expect-error - logger.warning(message); -} - -function warning(message: string): void { - // @ts-expect-error - logger.warning(message); -} - -function info(message: string): void { - logger.info(message); -} - -function debug(message: string): void { - logger.debug(message); -} - -function error(message: string): void { - logger.error(message); -} - // Workaround for https://github.com/winstonjs/winston/issues/1629. // https://github.com/Koenkk/zigbee2mqtt/pull/10905 /* istanbul ignore next */ @@ -221,6 +203,6 @@ async function end(): Promise { } export default { - init, logOutput, warn, warning, error, info, debug, setLevel, getLevel, cleanup, addTransport, end, + init, logOutput, warning, error, info, debug, setLevel, getLevel, cleanup, addTransport, end, winston: (): winston.Logger => logger, }; diff --git a/lib/util/settings.ts b/lib/util/settings.ts index 0d6868ac..7f09ebd0 100644 --- a/lib/util/settings.ts +++ b/lib/util/settings.ts @@ -80,7 +80,7 @@ const defaults: RecursivePartial = { log_symlink_current: false, log_output: ['console', 'file'], log_directory: path.join(data.getPath(), 'log', '%TIMESTAMP%'), - log_file: 'log.txt', + log_file: 'log.log', log_level: /* istanbul ignore next */ process.env.DEBUG ? 'debug' : 'info', log_syslog: {}, pan_id: 0x1a62, diff --git a/lib/zigbee.ts b/lib/zigbee.ts index 467d7d1d..0339cf6f 100644 --- a/lib/zigbee.ts +++ b/lib/zigbee.ts @@ -58,7 +58,7 @@ export default class Zigbee { let startResult; try { - this.herdsman = new Controller(herdsmanSettings, logger); + this.herdsman = new Controller(herdsmanSettings); startResult = await this.herdsman.start(); } catch (error) { logger.error(`Error while starting zigbee-herdsman`); @@ -103,7 +103,7 @@ export default class Zigbee { }); this.herdsman.on('deviceLeave', (data: ZHEvents.DeviceLeavePayload) => { const name = settings.getDevice(data.ieeeAddr)?.friendly_name || data.ieeeAddr; - logger.warn(`Device '${name}' left the network`); + logger.warning(`Device '${name}' left the network`); this.eventBus.emitDeviceLeave({ieeeAddr: data.ieeeAddr, name}); }); this.herdsman.on('message', async (data: ZHEvents.MessagePayload) => { @@ -134,11 +134,11 @@ export default class Zigbee { }; if (passlist.length > 0) { if (!passlist.includes(device.ieeeAddr)) { - logger.warn(`Device which is not on passlist connected (${device.ieeeAddr}), removing...`); + logger.warning(`Device which is not on passlist connected (${device.ieeeAddr}), removing...`); await remove(device); } } else if (blocklist.includes(device.ieeeAddr)) { - logger.warn(`Device on blocklist is connected (${device.ieeeAddr}), removing...`); + logger.warning(`Device on blocklist is connected (${device.ieeeAddr}), removing...`); await remove(device); } } @@ -162,7 +162,7 @@ export default class Zigbee { const {vendor, description, model} = data.device.definition; logger.info(`Device '${name}' is supported, identified as: ${vendor} ${description} (${model})`); } else { - logger.warn(`Device '${name}' with Zigbee model '${data.device.zh.modelID}' and manufacturer name ` + + logger.warning(`Device '${name}' with Zigbee model '${data.device.zh.modelID}' and manufacturer name ` + `'${data.device.zh.manufacturerName}' is NOT supported, ` + // eslint-disable-next-line max-len `please follow https://www.zigbee2mqtt.io/advanced/support-new-devices/01_support_new_devices.html`); diff --git a/test/availability.test.js b/test/availability.test.js index 9103a858..c7754f66 100644 --- a/test/availability.test.js +++ b/test/availability.test.js @@ -10,7 +10,7 @@ import Availability from '../lib/extension/availability'; import flushPromises from './lib/flushPromises'; import stringify from 'json-stable-stringify-without-jsonify'; -const mocks = [MQTT.publish, logger.warn, logger.debug]; +const mocks = [MQTT.publish, logger.warning, logger.debug]; const devices = zigbeeHerdsman.devices; zigbeeHerdsman.returnDevices.push( ...[devices.bulb_color.ieeeAddr, devices.bulb_color_2.ieeeAddr, devices.coordinator.ieeeAddr, devices.remote.ieeeAddr]) diff --git a/test/bridge.test.js b/test/bridge.test.js index 6b4ac800..bea5a6dc 100644 --- a/test/bridge.test.js +++ b/test/bridge.test.js @@ -61,7 +61,7 @@ describe('Bridge', () => { settings.set(['advanced', 'legacy_api'], false); data.writeDefaultState(); logger.info.mockClear(); - logger.warn.mockClear(); + logger.warning.mockClear(); logger.setTransportsEnabled(false); MQTT.publish.mockClear(); const device = zigbeeHerdsman.devices.bulb; @@ -85,7 +85,7 @@ describe('Bridge', () => { // console.log(MQTT.publish.mock.calls.find((c) => c[0] === 'zigbee2mqtt/bridge/info')[1]) expect(MQTT.publish).toHaveBeenCalledWith( 'zigbee2mqtt/bridge/info', - stringify({ "restart_required": false, "commit": version.commitHash, "config": { "advanced": { "legacy_availability_payload": true,"output":"json","adapter_concurrent": null, "adapter_delay": null, "availability_blacklist": [], "availability_blocklist": [], "availability_passlist": [], "availability_whitelist": [], "cache_state": true, "cache_state_persistent": true, "cache_state_send_on_startup": true, "channel": 11, "elapsed": false, "ext_pan_id": [221, 221, 221, 221, 221, 221, 221, 221], "last_seen": "disable", "legacy_api": false, "log_directory": directory, "log_file": "log.txt", "log_level": "info", "log_output": ["console", "file"], "log_rotation": true, "log_symlink_current": false, "log_syslog": {}, "pan_id": 6754, "report": false, "soft_reset_timeout": 0, "timestamp_format": "YYYY-MM-DD HH:mm:ss" }, "blocklist": [], "device_options": {}, "devices": { "0x000b57fffec6a5b2": { "friendly_name": "bulb", "description": "this is my bulb", "retain": true }, "0x000b57fffec6a5b3": { "friendly_name": "bulb_color", "retain": false }, "0x000b57fffec6a5b4": { "friendly_name": "bulb_color_2", "retain": false }, "0x000b57fffec6a5b7": { "friendly_name": "bulb_2", "retain": false }, "0x0017880104a44559": { "friendly_name": "J1_cover" }, "0x0017880104e43559": { "friendly_name": "U202DST600ZB" }, "0x0017880104e44559": { "friendly_name": "3157100_thermostat" }, "0x0017880104e45517": { "friendly_name": "remote", "retain": true }, "0x0017880104e45520": { "friendly_name": "button", "retain": false }, "0x0017880104e45521": { "friendly_name": "button_double_key", "retain": false }, "0x0017880104e45522": { "friendly_name": "weather_sensor", "qos": 1, "retain": false }, "0x0017880104e45523": { "friendly_name": "occupancy_sensor", "retain": false }, "0x0017880104e45524": { "friendly_name": "power_plug", "retain": false }, "0x0017880104e45526": { "friendly_name": "GL-S-007ZS" }, "0x0017880104e45529": { "friendly_name": "unsupported2", "retain": false }, "0x0017880104e45530": { "friendly_name": "button_double_key_interviewing", "retain": false }, "0x0017880104e45540": { "friendly_name": "ikea_onoff" }, "0x0017880104e45541": { "friendly_name": "wall_switch", "retain": false }, "0x0017880104e45542": { "friendly_name": "wall_switch_double", "retain": false }, "0x0017880104e45543": { "friendly_name": "led_controller_1", "retain": false }, "0x0017880104e45544": { "friendly_name": "led_controller_2", "retain": false }, "0x0017880104e45545": { "friendly_name": "dimmer_wall_switch", "retain": false }, "0x0017880104e45547": { "friendly_name": "curtain", "retain": false }, "0x0017880104e45548": { "friendly_name": "fan", "retain": false }, "0x0017880104e45549": { "friendly_name": "siren", "retain": false }, "0x0017880104e45550": { "friendly_name": "thermostat", "retain": false }, "0x0017880104e45551": { "friendly_name": "smart vent", "retain": false }, "0x0017880104e45552": { "friendly_name": "j1", "retain": false }, "0x0017880104e45553": { "friendly_name": "bulb_enddevice", "retain": false }, "0x0017880104e45559": { "friendly_name": "cc2530_router", "retain": false }, "0x0017880104e45560": { "friendly_name": "livolo", "retain": false }, "0x0017880104e45724":{"friendly_name":"GLEDOPTO_2ID"}, "0xf4ce368a38be56a1":{"cover_1_enabled":"true","cover_1_tilt_enabled":"true","cover_2_enabled":"true","cover_2_tilt_enabled":"true","dimmer_1_dimming_enabled":"true","dimmer_1_enabled":"true","dimmer_2_dimming_enabled":"true","dimmer_2_enabled":"true","dimmer_3_dimming_enabled":"true","dimmer_3_enabled":"true","dimmer_4_dimming_enabled":"true","dimmer_4_enabled":"true","friendly_name":"zigfred_plus","front_surface_enabled":"true","retain":false}, "0x0017882104a44559": { "friendly_name": "TS0601_thermostat" }, "0x0017882104a44560":{"friendly_name":"TS0601_switch"}, "0x0017882104a44562":{"friendly_name":"TS0601_cover_switch"}, "0x0017882194e45543": { "friendly_name": "QS-Zigbee-D02-TRIAC-2C-LN" }, "0x90fd9ffffe4b64aa": { "friendly_name": "SP600_OLD" }, "0x90fd9ffffe4b64ab": { "friendly_name": "SP600_NEW" }, "0x90fd9ffffe4b64ac": { "friendly_name": "MKS-CM-W5" }, "0x90fd9ffffe4b64ae": { "friendly_name": "tradfri_remote", "retain": false }, "0x90fd9ffffe4b64af": { "friendly_name": "roller_shutter" }, "0x90fd9ffffe4b64ax": { "friendly_name": "ZNLDP12LM" }, "0x0017880104e45561": { "friendly_name": "temperature_sensor" }, "0x0017880104e45562": { "friendly_name": "heating_actuator" } }, "external_converters": [], "groups": { "1": { "friendly_name": "group_1", "retain": false }, "9": { "devices": ['bulb_color_2', 'bulb_2', 'wall_switch_double/right'], "friendly_name": "ha_discovery_group"}, "11": { "devices": ["bulb_2"], "friendly_name": "group_with_tradfri", "retain": false }, "14": { "devices": ["power_plug", "bulb_2"], "friendly_name": "switch_group", "retain": false }, "12": { "devices": ["TS0601_thermostat"], "friendly_name": "thermostat_group", "retain": false }, "15071": { "devices": ["bulb_color_2", "bulb_2"], "friendly_name": "group_tradfri_remote", "retain": false }, "2": { "friendly_name": "group_2", "retain": false }, "21":{"devices":["GLEDOPTO_2ID/cct"],"friendly_name":"gledopto_group"} }, "homeassistant": false, "map_options": { "graphviz": { "colors": { "fill": { "coordinator": "#e04e5d", "enddevice": "#fff8ce", "router": "#4ea3e0" }, "font": { "coordinator": "#ffffff", "enddevice": "#000000", "router": "#ffffff" }, "line": { "active": "#009900", "inactive": "#994444" } } } }, "mqtt": { "base_topic": "zigbee2mqtt", "include_device_information": false, "server": "mqtt://localhost", "force_disable_retain": false, }, "ota":{"disable_automatic_update_check":false,"update_check_interval":1440}, "passlist": [], "permit_join": true, "serial": { "disable_led": false, "port": "/dev/dummy" } }, "coordinator": { "ieee_address":"0x00124b00120144ae","meta": { "revision": 20190425, "version": 1 }, "type": "z-Stack" }, "log_level": "info", "network": { "channel": 15, "extended_pan_id": [0, 11, 22], "pan_id": 5674 }, "permit_join": false, "version": version.version, "zigbee_herdsman_converters": zhcVersion, "zigbee_herdsman": zhVersion, config_schema: settings.schema }), + stringify({ "restart_required": false, "commit": version.commitHash, "config": { "advanced": { "legacy_availability_payload": true,"output":"json","adapter_concurrent": null, "adapter_delay": null, "availability_blacklist": [], "availability_blocklist": [], "availability_passlist": [], "availability_whitelist": [], "cache_state": true, "cache_state_persistent": true, "cache_state_send_on_startup": true, "channel": 11, "elapsed": false, "ext_pan_id": [221, 221, 221, 221, 221, 221, 221, 221], "last_seen": "disable", "legacy_api": false, "log_directory": directory, "log_file": "log.log", "log_level": "info", "log_output": ["console", "file"], "log_rotation": true, "log_symlink_current": false, "log_syslog": {}, "pan_id": 6754, "report": false, "soft_reset_timeout": 0, "timestamp_format": "YYYY-MM-DD HH:mm:ss" }, "blocklist": [], "device_options": {}, "devices": { "0x000b57fffec6a5b2": { "friendly_name": "bulb", "description": "this is my bulb", "retain": true }, "0x000b57fffec6a5b3": { "friendly_name": "bulb_color", "retain": false }, "0x000b57fffec6a5b4": { "friendly_name": "bulb_color_2", "retain": false }, "0x000b57fffec6a5b7": { "friendly_name": "bulb_2", "retain": false }, "0x0017880104a44559": { "friendly_name": "J1_cover" }, "0x0017880104e43559": { "friendly_name": "U202DST600ZB" }, "0x0017880104e44559": { "friendly_name": "3157100_thermostat" }, "0x0017880104e45517": { "friendly_name": "remote", "retain": true }, "0x0017880104e45520": { "friendly_name": "button", "retain": false }, "0x0017880104e45521": { "friendly_name": "button_double_key", "retain": false }, "0x0017880104e45522": { "friendly_name": "weather_sensor", "qos": 1, "retain": false }, "0x0017880104e45523": { "friendly_name": "occupancy_sensor", "retain": false }, "0x0017880104e45524": { "friendly_name": "power_plug", "retain": false }, "0x0017880104e45526": { "friendly_name": "GL-S-007ZS" }, "0x0017880104e45529": { "friendly_name": "unsupported2", "retain": false }, "0x0017880104e45530": { "friendly_name": "button_double_key_interviewing", "retain": false }, "0x0017880104e45540": { "friendly_name": "ikea_onoff" }, "0x0017880104e45541": { "friendly_name": "wall_switch", "retain": false }, "0x0017880104e45542": { "friendly_name": "wall_switch_double", "retain": false }, "0x0017880104e45543": { "friendly_name": "led_controller_1", "retain": false }, "0x0017880104e45544": { "friendly_name": "led_controller_2", "retain": false }, "0x0017880104e45545": { "friendly_name": "dimmer_wall_switch", "retain": false }, "0x0017880104e45547": { "friendly_name": "curtain", "retain": false }, "0x0017880104e45548": { "friendly_name": "fan", "retain": false }, "0x0017880104e45549": { "friendly_name": "siren", "retain": false }, "0x0017880104e45550": { "friendly_name": "thermostat", "retain": false }, "0x0017880104e45551": { "friendly_name": "smart vent", "retain": false }, "0x0017880104e45552": { "friendly_name": "j1", "retain": false }, "0x0017880104e45553": { "friendly_name": "bulb_enddevice", "retain": false }, "0x0017880104e45559": { "friendly_name": "cc2530_router", "retain": false }, "0x0017880104e45560": { "friendly_name": "livolo", "retain": false }, "0x0017880104e45724":{"friendly_name":"GLEDOPTO_2ID"}, "0xf4ce368a38be56a1":{"cover_1_enabled":"true","cover_1_tilt_enabled":"true","cover_2_enabled":"true","cover_2_tilt_enabled":"true","dimmer_1_dimming_enabled":"true","dimmer_1_enabled":"true","dimmer_2_dimming_enabled":"true","dimmer_2_enabled":"true","dimmer_3_dimming_enabled":"true","dimmer_3_enabled":"true","dimmer_4_dimming_enabled":"true","dimmer_4_enabled":"true","friendly_name":"zigfred_plus","front_surface_enabled":"true","retain":false}, "0x0017882104a44559": { "friendly_name": "TS0601_thermostat" }, "0x0017882104a44560":{"friendly_name":"TS0601_switch"}, "0x0017882104a44562":{"friendly_name":"TS0601_cover_switch"}, "0x0017882194e45543": { "friendly_name": "QS-Zigbee-D02-TRIAC-2C-LN" }, "0x90fd9ffffe4b64aa": { "friendly_name": "SP600_OLD" }, "0x90fd9ffffe4b64ab": { "friendly_name": "SP600_NEW" }, "0x90fd9ffffe4b64ac": { "friendly_name": "MKS-CM-W5" }, "0x90fd9ffffe4b64ae": { "friendly_name": "tradfri_remote", "retain": false }, "0x90fd9ffffe4b64af": { "friendly_name": "roller_shutter" }, "0x90fd9ffffe4b64ax": { "friendly_name": "ZNLDP12LM" }, "0x0017880104e45561": { "friendly_name": "temperature_sensor" }, "0x0017880104e45562": { "friendly_name": "heating_actuator" } }, "external_converters": [], "groups": { "1": { "friendly_name": "group_1", "retain": false }, "9": { "devices": ['bulb_color_2', 'bulb_2', 'wall_switch_double/right'], "friendly_name": "ha_discovery_group"}, "11": { "devices": ["bulb_2"], "friendly_name": "group_with_tradfri", "retain": false }, "14": { "devices": ["power_plug", "bulb_2"], "friendly_name": "switch_group", "retain": false }, "12": { "devices": ["TS0601_thermostat"], "friendly_name": "thermostat_group", "retain": false }, "15071": { "devices": ["bulb_color_2", "bulb_2"], "friendly_name": "group_tradfri_remote", "retain": false }, "2": { "friendly_name": "group_2", "retain": false }, "21":{"devices":["GLEDOPTO_2ID/cct"],"friendly_name":"gledopto_group"} }, "homeassistant": false, "map_options": { "graphviz": { "colors": { "fill": { "coordinator": "#e04e5d", "enddevice": "#fff8ce", "router": "#4ea3e0" }, "font": { "coordinator": "#ffffff", "enddevice": "#000000", "router": "#ffffff" }, "line": { "active": "#009900", "inactive": "#994444" } } } }, "mqtt": { "base_topic": "zigbee2mqtt", "include_device_information": false, "server": "mqtt://localhost", "force_disable_retain": false, }, "ota":{"disable_automatic_update_check":false,"update_check_interval":1440}, "passlist": [], "permit_join": true, "serial": { "disable_led": false, "port": "/dev/dummy" } }, "coordinator": { "ieee_address":"0x00124b00120144ae","meta": { "revision": 20190425, "version": 1 }, "type": "z-Stack" }, "log_level": "info", "network": { "channel": 15, "extended_pan_id": [0, 11, 22], "pan_id": 5674 }, "permit_join": false, "version": version.version, "zigbee_herdsman_converters": zhcVersion, "zigbee_herdsman": zhVersion, config_schema: settings.schema }), { retain: true, qos: 0 }, expect.any(Function) ); @@ -1181,7 +1181,7 @@ describe('Bridge', () => { fs.mkdirSync(path.join(data.mockDir, 'ext_converters')); fs.writeFileSync(path.join(data.mockDir, 'ext_converters', 'afile.js'), 'test123') fs.mkdirSync(path.join(data.mockDir, 'log')); - fs.writeFileSync(path.join(data.mockDir, 'log', 'log.txt'), 'test123') + fs.writeFileSync(path.join(data.mockDir, 'log', 'log.log'), 'test123') fs.mkdirSync(path.join(data.mockDir, 'ext_converters', '123')); fs.writeFileSync(path.join(data.mockDir, 'ext_converters', '123', 'myfile.js'), 'test123') MQTT.publish.mockClear(); diff --git a/test/configure.test.js b/test/configure.test.js index a7c16d71..8f7a6265 100644 --- a/test/configure.test.js +++ b/test/configure.test.js @@ -8,7 +8,7 @@ const flushPromises = require('./lib/flushPromises'); const wait = (ms) => new Promise((resolve) => setTimeout(resolve, ms)); const stringify = require('json-stable-stringify-without-jsonify'); -const mocksClear = [MQTT.publish, logger.warn, logger.debug]; +const mocksClear = [MQTT.publish, logger.warning, logger.debug]; describe('Configure', () => { let controller; @@ -202,7 +202,7 @@ describe('Configure', () => { it('Legacy api: Should skip reconfigure when device does not require this', async () => { await MQTT.events.message('zigbee2mqtt/bridge/configure', '0x0017882104a44559'); await flushPromises(); - expect(logger.warn).toHaveBeenCalledWith(`Skipping configure of 'TS0601_thermostat', device does not require this.`) + expect(logger.warning).toHaveBeenCalledWith(`Skipping configure of 'TS0601_thermostat', device does not require this.`) }); it('Should not configure when interview not completed', async () => { diff --git a/test/controller.test.js b/test/controller.test.js index 4ee8a0f2..dad2d0b5 100644 --- a/test/controller.test.js +++ b/test/controller.test.js @@ -53,7 +53,7 @@ describe('Controller', () => { it('Start controller', async () => { await controller.start(); - expect(zigbeeHerdsman.constructor).toHaveBeenCalledWith({"network":{"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11],"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13]},"databasePath":path.join(data.mockDir, "database.db"), "databaseBackupPath":path.join(data.mockDir, "database.db.backup"),"backupPath":path.join(data.mockDir, "coordinator_backup.json"),"acceptJoiningDeviceHandler": expect.any(Function),adapter: {concurrent: null, delay: null, disableLED: false}, "serialPort":{"baudRate":undefined,"rtscts":undefined,"path":"/dev/dummy"}}, logger); + expect(zigbeeHerdsman.constructor).toHaveBeenCalledWith({"network":{"panID":6754,"extendedPanID":[221,221,221,221,221,221,221,221],"channelList":[11],"networkKey":[1,3,5,7,9,11,13,15,0,2,4,6,8,10,12,13]},"databasePath":path.join(data.mockDir, "database.db"), "databaseBackupPath":path.join(data.mockDir, "database.db.backup"),"backupPath":path.join(data.mockDir, "coordinator_backup.json"),"acceptJoiningDeviceHandler": expect.any(Function),adapter: {concurrent: null, delay: null, disableLED: false}, "serialPort":{"baudRate":undefined,"rtscts":undefined,"path":"/dev/dummy"}}); expect(zigbeeHerdsman.start).toHaveBeenCalledTimes(1); expect(zigbeeHerdsman.setTransmitPower).toHaveBeenCalledTimes(0); expect(zigbeeHerdsman.permitJoin).toHaveBeenCalledTimes(1); diff --git a/test/homeassistant.test.js b/test/homeassistant.test.js index 070f42db..0a5f6892 100644 --- a/test/homeassistant.test.js +++ b/test/homeassistant.test.js @@ -993,9 +993,9 @@ describe('HomeAssistant extension', () => { it('Should warn when starting with cache_state false', async () => { settings.set(['advanced', 'cache_state'], false); - logger.warn.mockClear(); + logger.warning.mockClear(); await resetExtension(); - expect(logger.warn).toHaveBeenCalledWith("In order for Home Assistant integration to work properly set `cache_state: true"); + expect(logger.warning).toHaveBeenCalledWith("In order for Home Assistant integration to work properly set `cache_state: true"); }); it('Should set missing values to null', async () => { diff --git a/test/legacy/bridgeLegacy.test.js b/test/legacy/bridgeLegacy.test.js index 65d65ba0..61c673f2 100644 --- a/test/legacy/bridgeLegacy.test.js +++ b/test/legacy/bridgeLegacy.test.js @@ -25,7 +25,7 @@ describe('Bridge legacy', () => { data.writeDefaultConfiguration(); settings.reRead(); logger.info.mockClear(); - logger.warn.mockClear(); + logger.warning.mockClear(); }); afterAll(async () => { @@ -478,6 +478,6 @@ describe('Bridge legacy', () => { MQTT.events.message('zigbee2mqtt/bridge/config/touchlink/factory_reset', ''); await flushPromises(); expect(zigbeeHerdsman.touchlinkFactoryResetFirst).toHaveBeenCalledTimes(1); - expect(logger.warn).toHaveBeenCalledWith('Failed to factory reset device through Touchlink'); + expect(logger.warning).toHaveBeenCalledWith('Failed to factory reset device through Touchlink'); }); }); diff --git a/test/legacy/report.test.js b/test/legacy/report.test.js index 27e18f0a..1b79bbb5 100644 --- a/test/legacy/report.test.js +++ b/test/legacy/report.test.js @@ -16,7 +16,7 @@ const Controller = require('../../lib/controller'); const flushPromises = require('../lib/flushPromises'); const wait = (ms) => new Promise((resolve) => setTimeout(resolve, ms)); -const mocksClear = [MQTT.publish, logger.warn, logger.debug]; +const mocksClear = [MQTT.publish, logger.warning, logger.debug]; describe('Report', () => { let controller; diff --git a/test/logger.test.js b/test/logger.test.js index 645c857e..9e5f9df1 100644 --- a/test/logger.test.js +++ b/test/logger.test.js @@ -69,6 +69,25 @@ describe('Logger', () => { logger.logOutput(); logger.setLevel('debug'); expect(logger.getLevel()).toBe('debug'); + logger.setLevel('info'); + expect(logger.getLevel()).toBe('info'); + logger.setLevel('warning'); + expect(logger.getLevel()).toBe('warning'); + logger.setLevel('warn'); + expect(logger.getLevel()).toBe('warning'); + logger.setLevel('error'); + expect(logger.getLevel()).toBe('error'); + }); + + it('Set warning when log level is warn', () => { + settings.set(['advanced', 'log_level'], 'warn'); + settings.reRead(); + const logger = require('../lib/util/logger').default; + logger.init(); + logger.logOutput(); + expect(logger.getLevel()).toBe('warning'); + settings.set(['advanced', 'log_level'], 'info'); + settings.reRead(); }); it('Add transport', () => { @@ -84,15 +103,6 @@ describe('Logger', () => { 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.getLevel()).toBe('warn'); - }); - it('Logger should be console and file by default', () => { const logger = require('../lib/util/logger').default; logger.init(); @@ -164,24 +174,29 @@ describe('Logger', () => { it('Log', () => { const logger = require('../lib/util/logger').default; logger.init(); - const warn = jest.spyOn(logger.winston(), 'warning'); - logger.warn('warn'); - expect(warn).toHaveBeenCalledWith('warn'); + logger.setLevel('debug'); const debug = jest.spyOn(logger.winston(), 'debug'); logger.debug('debug'); - expect(debug).toHaveBeenCalledWith('debug'); - - const warning = jest.spyOn(logger.winston(), 'warning'); - logger.warning('warning'); - expect(warning).toHaveBeenCalledWith('warning'); + expect(debug).toHaveBeenCalledWith('debug', {namespace: 'z2m'}); + expect(debug).toHaveBeenCalledTimes(1); const info = jest.spyOn(logger.winston(), 'info'); logger.info('info'); - expect(info).toHaveBeenCalledWith('info'); + expect(info).toHaveBeenCalledWith('info', {namespace: 'z2m'}); + expect(info).toHaveBeenCalledTimes(1); + + const warning = jest.spyOn(logger.winston(), 'warning'); + logger.warning('warning'); + expect(warning).toHaveBeenCalledWith('warning', {namespace: 'z2m'}); + expect(warning).toHaveBeenCalledTimes(1); const error = jest.spyOn(logger.winston(), 'error'); logger.error('error'); - expect(error).toHaveBeenCalledWith('error'); + expect(error).toHaveBeenCalledWith('error', {namespace: 'z2m'}); + + logger.error(new Error('error'));// test for stack=true + expect(error).toHaveBeenCalledWith('error', {namespace: 'z2m'}); + expect(error).toHaveBeenCalledTimes(2); }); }); diff --git a/test/networkMap.test.js b/test/networkMap.test.js index 5b4ca9a0..33fdaa4d 100644 --- a/test/networkMap.test.js +++ b/test/networkMap.test.js @@ -17,7 +17,7 @@ const MQTT = require('./stub/mqtt'); const settings = require('../lib/util/settings'); const Controller = require('../lib/controller'); const flushPromises = require('./lib/flushPromises'); -const mocksClear = [MQTT.publish, logger.warn, logger.debug]; +const mocksClear = [MQTT.publish, logger.warning, logger.debug]; const setTimeoutNative = setTimeout; describe('Networkmap', () => { diff --git a/test/onEvent.test.js b/test/onEvent.test.js index 10cc67b4..f55489ea 100644 --- a/test/onEvent.test.js +++ b/test/onEvent.test.js @@ -8,7 +8,7 @@ const settings = require('../lib/util/settings'); const Controller = require('../lib/controller'); const flushPromises = require('./lib/flushPromises'); -const mocksClear = [MQTT.publish, logger.warn, logger.debug]; +const mocksClear = [MQTT.publish, logger.warning, logger.debug]; const zigbeeHerdsmanConverters = require('zigbee-herdsman-converters'); const mockOnEvent = jest.fn(); diff --git a/test/publish.test.js b/test/publish.test.js index e5b3026a..d4182035 100644 --- a/test/publish.test.js +++ b/test/publish.test.js @@ -9,7 +9,7 @@ const settings = require('../lib/util/settings'); const Controller = require('../lib/controller'); const flushPromises = require('./lib/flushPromises'); -const mocksClear = [MQTT.publish, logger.warn, logger.debug]; +const mocksClear = [MQTT.publish, logger.warning, logger.debug]; const expectNothingPublished = () => { Object.values(zigbeeHerdsman.devices).forEach((d) => { diff --git a/test/receive.test.js b/test/receive.test.js index e4078dbd..0c88207e 100755 --- a/test/receive.test.js +++ b/test/receive.test.js @@ -8,7 +8,7 @@ const settings = require('../lib/util/settings'); const Controller = require('../lib/controller'); const flushPromises = require('./lib/flushPromises'); -const mocksClear = [MQTT.publish, logger.warn, logger.debug]; +const mocksClear = [MQTT.publish, logger.warning, logger.debug]; describe('Receive', () => { let controller; diff --git a/test/stub/logger.js b/test/stub/logger.js index bfafb5f5..627051a2 100644 --- a/test/stub/logger.js +++ b/test/stub/logger.js @@ -3,10 +3,10 @@ let level = 'info'; const transports = []; let transportsEnabled = false; -const callTransports = (level, message) => { +const callTransports = (level, message, namespace) => { if (transportsEnabled) { for (const transport of transports) { - transport.log({level, message}, () => {}); + transport.log({level, message, namespace}, () => {}); } } } @@ -14,7 +14,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)), + warning: jest.fn().mockImplementation((msg) => callTransports('warning', msg)), error: jest.fn().mockImplementation((msg) => callTransports('error', msg)), debug: jest.fn().mockImplementation((msg) => callTransports('debug', msg)), cleanup: jest.fn(), diff --git a/test/stub/zigbeeHerdsman.js b/test/stub/zigbeeHerdsman.js index db22cf41..ee79c4ea 100644 --- a/test/stub/zigbeeHerdsman.js +++ b/test/stub/zigbeeHerdsman.js @@ -261,6 +261,7 @@ const mock = { const mockConstructor = jest.fn().mockImplementation(() => mock); jest.mock('zigbee-herdsman', () => ({ + ...jest.requireActual('zigbee-herdsman'), Controller: mockConstructor, Zcl: {ManufacturerCode: {SIGNIFY_NETHERLANDS_B_V: 4107}}, }));