From fb517e5d7789b9c14c677147ca1a02367c9228e3 Mon Sep 17 00:00:00 2001 From: Agav Date: Sat, 16 Nov 2024 00:59:44 +0300 Subject: [PATCH 1/4] optimization of log string generation --- lib/statescontroller.js | 72 +++++++++++++++++++++++++---------------- lib/zigbeecontroller.js | 7 ++-- main.js | 36 +++++++++++++++++---- 3 files changed, 76 insertions(+), 39 deletions(-) diff --git a/lib/statescontroller.js b/lib/statescontroller.js index f4c57f09..fb324cfb 100644 --- a/lib/statescontroller.js +++ b/lib/statescontroller.js @@ -95,9 +95,10 @@ class StatesController extends EventEmitter { if (!this.adapter.zbController || !this.adapter.zbController.connected()) { return; } - if (this.debugDevices === undefined) { - this.getDebugDevices(); - } + //method checkDebugDevice check the same condition + //if (this.debugDevices === undefined) { + // this.getDebugDevices(); + //} if (state && !state.ack) { if (id.endsWith('pairingCountdown') || id.endsWith('pairingMessage') || id.endsWith('connection')) { return; @@ -147,7 +148,7 @@ class StatesController extends EventEmitter { async collectOptions(devId, model, callback) { const result = {}; // find model states for options and get it values - const devStates = await this.getDevStates('0x' + devId, model); + const devStates = await this.getDevStates('0x' + devId, model, 'collectOptions'); if (devStates == null || devStates == undefined || devStates.states == null || devStates.states == undefined) { callback(result); return; @@ -182,7 +183,7 @@ class StatesController extends EventEmitter { } } - async getDevStates(deviceId, model) { + async getDevStates(deviceId, model, debugInfo) { try { let states; let stateModel; @@ -202,6 +203,10 @@ class StatesController extends EventEmitter { } else { states = stateModel.states; } + + if (this.checkDebugDevice(deviceId)) + this.info(`ELEVATED: getDevStates deviceId="${deviceId}", model="${model}" call by:${debugInfo}`); + if (typeof states === 'function' && !states.prototype) { const entity = await this.adapter.zbController.resolveEntity(deviceId); if (entity) { @@ -217,13 +222,14 @@ class StatesController extends EventEmitter { } async publishFromState(deviceId, model, stateKey, state, options) { - if (this.debugDevices === undefined) this.getDebugDevices(); + //method checkDebugDevice check the same condition + //if (this.debugDevices === undefined) this.getDebugDevices(); this.debug(`Change state '${stateKey}' at device ${deviceId} type '${model}'`); const elevated = this.checkDebugDevice(deviceId); if (elevated) this.warn(`ELEVATED Change state '${stateKey}' at device ${deviceId} type '${model}'`); - const devStates = await this.getDevStates(deviceId, model); + const devStates = await this.getDevStates(deviceId, model,'publishFromState'); if (!devStates) { if (elevated) this.error(`ELEVATED no device states for device ${deviceId} type '${model}'`); return; @@ -331,7 +337,7 @@ class StatesController extends EventEmitter { async deleteOrphanedDeviceStates(ieeeAddr, model, force, callback) { - const devStates = await this.getDevStates(ieeeAddr, model); + const devStates = await this.getDevStates(ieeeAddr, model,'deleteOrphanedDeviceStates'); const commonStates = statesMapping.commonStates; const devId = ieeeAddr.substr(2); this.adapter.getStatesOf(devId, (err, states) => { @@ -569,7 +575,7 @@ class StatesController extends EventEmitter { async syncDevStates(dev, model) { const devId = dev.ieeeAddr.substr(2); // devId - iobroker device id - const devStates = await this.getDevStates(dev.ieeeAddr, model); + const devStates = await this.getDevStates(dev.ieeeAddr, model,'syncDevStates'); if (!devStates) { return; } @@ -617,27 +623,37 @@ class StatesController extends EventEmitter { } async publishToState(devId, model, payload) { - const devStates = await this.getDevStates(`0x${devId}`, model); - let has_debug = false; - if (this.debugDevices === undefined) this.getDebugDevices(); - if (this.checkDebugDevice(devId)) - { - if (!payload.hasOwnProperty('msg_from_zigbee')) { - this.warn(`ELEVATED publishToState: message received '${JSON.stringify(payload)}' from device ${devId} type '${model}'`); - has_debug = true; - } + + var isMsg_from_zigbee = payload.hasOwnProperty('msg_from_zigbee'); + var isCommonState = isMsg_from_zigbee|| + payload.hasOwnProperty('linkquality'); + + let has_debug = ! isMsg_from_zigbee && this.checkDebugDevice(devId); + + if (has_debug){ + this.warn(`ELEVATED publishToState: message received '${JSON.stringify(payload)}' from device ${devId} type '${model}'`); + } + + let states = undefined; + if (isCommonState){ + states = statesMapping.commonStates; } - if (!devStates) { - if (has_debug) this.error(`ELEVATED publishToState: no device states for device ${devId} type '${model}'`) - return; + else{ + const devStates = await this.getDevStates(`0x${devId}`, model, 'publishToState'); + + if (!devStates) { + if (has_debug) this.error(`ELEVATED publishToState: no device states for device ${devId} type '${model}'`) + return; + } + + states = statesMapping.commonStates.concat( + devStates.states.filter(statedesc => payload.hasOwnProperty(statedesc.prop || statedesc.id)) + ); } + // find states for payload - if (devStates.states !== undefined) { + if (states!== undefined) { try { - const states = statesMapping.commonStates.concat( - devStates.states.filter(statedesc => payload.hasOwnProperty(statedesc.prop || statedesc.id)) - ); - for (const stateInd in states) { const statedesc = states[stateInd]; let value; @@ -653,8 +669,8 @@ class StatesController extends EventEmitter { let stateID = statedesc.id; - if (has_debug && statedesc.id !== 'msg_from_zigbee') { - this.warn(`ELEVATED publishToState: value generated '${JSON.stringify(value)}' from device ${devId} for '${statedesc.name}'`); + if (has_debug) { + this.warn(`ELEVATED publishToState: value generated '${JSON.stringify(value)}' from device ${devId} for '${statedesc.name}'`); } const common = { diff --git a/lib/zigbeecontroller.js b/lib/zigbeecontroller.js index c5c8271a..a9ac4027 100644 --- a/lib/zigbeecontroller.js +++ b/lib/zigbeecontroller.js @@ -697,13 +697,12 @@ class ZigbeeController extends EventEmitter { } async handleMessage(data) { - this.debug(`handleMessage`, data); + //this.debug(`handleMessage`, data); const entity = await this.resolveEntity(data.device || data.ieeeAddr); const name = (entity && entity._modelID) ? entity._modelID : data.device.ieeeAddr; this.debug( - `Received Zigbee message from '${name}', type '${data.type}', cluster '${data.cluster}'` + - `, data '${JSON.stringify(data.data)}' from endpoint ${data.endpoint.ID}` + - (data.hasOwnProperty('groupID') ? ` with groupID ${data.groupID}` : ``) + `HandleMessage. Received Zigbee message from '${name}', type '${data.type}', cluster '${data.cluster}', from endpoint ${data.endpoint.ID}` + + (data.hasOwnProperty('groupID') ? ` with groupID ${data.groupID}` : ``) + ` data:`,data.data ); this.event(data.type, entity, data); diff --git a/main.js b/main.js index 9ea69b54..eabdfbe7 100644 --- a/main.js +++ b/main.js @@ -458,7 +458,8 @@ class Zigbee extends utils.Adapter { } async onZigbeeEvent(type, entity, message) { - this.log.debug(`Type ${type} device ${safeJsonStringify(entity)} incoming event: ${safeJsonStringify(message)}`); + //Optimization: Use checkDebugDevice as entity and message objects can be very large (ie PTVO 8chanels relay safeJsonStringify(entity) -> 90 kb size) + //this.log.debug(`Type ${type} device ${safeJsonStringify(entity)} incoming event: ${safeJsonStringify(message)}`); const device = entity.device; const mappedModel = entity.mapped; @@ -468,6 +469,11 @@ class Zigbee extends utils.Adapter { const meta = {device}; if (this.stController.checkDebugDevice(devId)) { + + //Full log: + //this.log.debug(`ELEVATED: Zigbee Event of Type "${type}" from device: ${safeJsonStringify(entity)}`); + //this.log.debug(`ELEVATED: incoming event:${safeJsonStringify(message)}`); + const shortMessage = {}; for(const propertyName in message) { shortMessage[propertyName] = message[propertyName]; @@ -475,8 +481,12 @@ class Zigbee extends utils.Adapter { shortMessage.device = device.ieeeAddr; shortMessage.meta = undefined; shortMessage.endpoint = (message.endpoint.ID ? message.endpoint.ID: -1); - this.log.warn(`ELEVATED: Zigbee Event of Type ${type} from device ${safeJsonStringify(device.ieeeAddr)}, incoming event: ${safeJsonStringify(shortMessage)}`); - } + this.log.warn(`* ELEVATED: Zigbee Event of Type "${type}" from device "${safeJsonStringify(device.ieeeAddr)}" incoming event: ${safeJsonStringify(shortMessage)}`); + }else + { + this.onLog('debug',`* Zigbee Event of Type ${type} from device ${devId}. incoming event:`, message); + }; + // this assigment give possibility to use iobroker logger in code of the converters, via meta.logger meta.logger = this.log; @@ -576,7 +586,11 @@ class Zigbee extends utils.Adapter { async processConverters(converters, devId, model, mappedModel, message, meta) { for (const converter of converters) { const publish = (payload) => { - this.log.debug(`Publish ${safeJsonStringify(payload)} to ${safeJsonStringify(devId)}`); + + if (this.stController.checkDebugDevice(devId)) + this.log.warn(`ELEVATED: ProcessConverters devId:${devId} payload: ${safeJsonStringify(payload)}`); + else this.onLog('debug', `Publish to ${devId}. payload:`, payload); + if (typeof payload === 'object') { this.publishToState(devId, model, payload); } @@ -625,7 +639,11 @@ class Zigbee extends utils.Adapter { let isGroup = false; const has_elevated_debug = this.stController.checkDebugDevice(deviceId) - this.log.debug(`publishFromState : ${deviceId} ${model} ${safeJsonStringify(stateList)}`); + + if(has_elevated_debug) + this.log.warn(`ELEVATED: PublishFromState : ${deviceId} ${model} stateList: ${safeJsonStringify(stateList)}`) + else this.onLog('debug',`PublishFromState : ${deviceId} ${model}. stateList:`, stateList); + if (model === 'group') { isGroup = true; deviceId = parseInt(deviceId); @@ -633,7 +651,9 @@ class Zigbee extends utils.Adapter { try { const entity = await this.zbController.resolveEntity(deviceId); - this.log.debug(`entity: ${deviceId} ${model} ${safeJsonStringify(entity)}`); + if (has_elevated_debug) + this.log.warn(`ELEVATED: PublishFromState. ${deviceId} ${model} entity: ${safeJsonStringify(entity)}`) + else this.onLog('debug',`PublishFromState : ${deviceId} ${model} entity:`, entity); const mappedModel = entity.mapped; @@ -1086,7 +1106,9 @@ class Zigbee extends utils.Adapter { if (typeof data === 'string') { logger(`${msg}. ${data}`); } else { - logger(`${msg}. ${safeJsonStringify(data)}`); + if (this.log.level==level) + logger(`${msg}. ${safeJsonStringify(data)}`) + else logger(`${msg}. {DATA unavailable. Check log level}`); } } else { logger(msg); From e854c3ebb61c7d5f0a90ac509c86cee591f144b3 Mon Sep 17 00:00:00 2001 From: Agav Date: Sat, 16 Nov 2024 21:35:04 +0300 Subject: [PATCH 2/4] remove the elevated source logging for calls to getDevStates --- lib/statescontroller.js | 17 +++++++---------- 1 file changed, 7 insertions(+), 10 deletions(-) diff --git a/lib/statescontroller.js b/lib/statescontroller.js index fb324cfb..f548e5b8 100644 --- a/lib/statescontroller.js +++ b/lib/statescontroller.js @@ -148,7 +148,7 @@ class StatesController extends EventEmitter { async collectOptions(devId, model, callback) { const result = {}; // find model states for options and get it values - const devStates = await this.getDevStates('0x' + devId, model, 'collectOptions'); + const devStates = await this.getDevStates('0x' + devId, model); if (devStates == null || devStates == undefined || devStates.states == null || devStates.states == undefined) { callback(result); return; @@ -183,7 +183,7 @@ class StatesController extends EventEmitter { } } - async getDevStates(deviceId, model, debugInfo) { + async getDevStates(deviceId, model) { try { let states; let stateModel; @@ -203,10 +203,7 @@ class StatesController extends EventEmitter { } else { states = stateModel.states; } - - if (this.checkDebugDevice(deviceId)) - this.info(`ELEVATED: getDevStates deviceId="${deviceId}", model="${model}" call by:${debugInfo}`); - + if (typeof states === 'function' && !states.prototype) { const entity = await this.adapter.zbController.resolveEntity(deviceId); if (entity) { @@ -229,7 +226,7 @@ class StatesController extends EventEmitter { if (elevated) this.warn(`ELEVATED Change state '${stateKey}' at device ${deviceId} type '${model}'`); - const devStates = await this.getDevStates(deviceId, model,'publishFromState'); + const devStates = await this.getDevStates(deviceId, model); if (!devStates) { if (elevated) this.error(`ELEVATED no device states for device ${deviceId} type '${model}'`); return; @@ -337,7 +334,7 @@ class StatesController extends EventEmitter { async deleteOrphanedDeviceStates(ieeeAddr, model, force, callback) { - const devStates = await this.getDevStates(ieeeAddr, model,'deleteOrphanedDeviceStates'); + const devStates = await this.getDevStates(ieeeAddr, model); const commonStates = statesMapping.commonStates; const devId = ieeeAddr.substr(2); this.adapter.getStatesOf(devId, (err, states) => { @@ -575,7 +572,7 @@ class StatesController extends EventEmitter { async syncDevStates(dev, model) { const devId = dev.ieeeAddr.substr(2); // devId - iobroker device id - const devStates = await this.getDevStates(dev.ieeeAddr, model,'syncDevStates'); + const devStates = await this.getDevStates(dev.ieeeAddr, model); if (!devStates) { return; } @@ -639,7 +636,7 @@ class StatesController extends EventEmitter { states = statesMapping.commonStates; } else{ - const devStates = await this.getDevStates(`0x${devId}`, model, 'publishToState'); + const devStates = await this.getDevStates(`0x${devId}`, model); if (!devStates) { if (has_debug) this.error(`ELEVATED publishToState: no device states for device ${devId} type '${model}'`) From 8511840af2fed6c689448c154aeeeb897c9e233f Mon Sep 17 00:00:00 2001 From: Agav Date: Sat, 16 Nov 2024 21:52:30 +0300 Subject: [PATCH 3/4] Please remove the commented checks for debug device --- lib/statescontroller.js | 7 +------ 1 file changed, 1 insertion(+), 6 deletions(-) diff --git a/lib/statescontroller.js b/lib/statescontroller.js index f548e5b8..d9b993c6 100644 --- a/lib/statescontroller.js +++ b/lib/statescontroller.js @@ -95,10 +95,6 @@ class StatesController extends EventEmitter { if (!this.adapter.zbController || !this.adapter.zbController.connected()) { return; } - //method checkDebugDevice check the same condition - //if (this.debugDevices === undefined) { - // this.getDebugDevices(); - //} if (state && !state.ack) { if (id.endsWith('pairingCountdown') || id.endsWith('pairingMessage') || id.endsWith('connection')) { return; @@ -219,8 +215,7 @@ class StatesController extends EventEmitter { } async publishFromState(deviceId, model, stateKey, state, options) { - //method checkDebugDevice check the same condition - //if (this.debugDevices === undefined) this.getDebugDevices(); + this.debug(`Change state '${stateKey}' at device ${deviceId} type '${model}'`); const elevated = this.checkDebugDevice(deviceId); From b5cb52150463cb4df4f79551c6263e66fb209494 Mon Sep 17 00:00:00 2001 From: Agav Date: Thu, 2 Jan 2025 20:57:07 +0300 Subject: [PATCH 4/4] - Check log level - Change log level for "handleDeviceJoined" message --- lib/zigbeecontroller.js | 2 +- main.js | 7 +++++-- 2 files changed, 6 insertions(+), 3 deletions(-) diff --git a/lib/zigbeecontroller.js b/lib/zigbeecontroller.js index a9ac4027..c2f3ef95 100644 --- a/lib/zigbeecontroller.js +++ b/lib/zigbeecontroller.js @@ -642,7 +642,7 @@ class ZigbeeController extends EventEmitter { } async handleDeviceJoined(message) { - this.debug('handleDeviceJoined', message); + this.warn('handleDeviceJoined', message); //const entity = await this.resolveEntity(message.device || message.ieeeAddr); //this.emit('new', entity); } diff --git a/main.js b/main.js index eabdfbe7..a2002aab 100644 --- a/main.js +++ b/main.js @@ -1106,9 +1106,12 @@ class Zigbee extends utils.Adapter { if (typeof data === 'string') { logger(`${msg}. ${data}`); } else { - if (this.log.level==level) + if ((this.log.level==level) || + ((this.log.level='warn')&&(level='error')) || + ((this.log.level='info')&&(level='error' || level=='warn')) + ) logger(`${msg}. ${safeJsonStringify(data)}`) - else logger(`${msg}. {DATA unavailable. Check log level}`); + else logger(`${msg}. DATA unavailable. Check log level. MsgLevel:${level} AdaptorLevel:${this.log.level}`); } } else { logger(msg);