From 217fa0f592ca0f14db4bdb3423bceba823a34cff Mon Sep 17 00:00:00 2001 From: Johannes Krobath Date: Thu, 9 Jul 2026 22:00:25 +0200 Subject: [PATCH] fix: consistent devLabel use - pass the model where it is in scope Full review of all devLabel call sites (172 active, 5 in comment blocks) as requested in #2933, split into the three cases: 1) The model is in scope (function parameter, mappedModel/mappedDevice, or a resolved entity): 111 sites now pass it as third parameter. The expression used is always the mapped model (the common.type key space, 'group' for groups) - never a raw modelID where a mapped model exists. 2) Calling devLabel makes no sense: messages concerning missing, empty or orphaned states/objects are object-tree diagnostics - the object id is the key for finding them there, so these print the raw id (14 sites, see below). Same for the deleteObj warning: devId there can be any object path (e.g. a state id from deleteOrphanedDeviceStates). 3) The model is not available at the call site (before/without entity resolution, admin messages, delayed actions): 35 sites deliberately stay id-only; the custom name and the cached object name still apply. The case-2 messages in the statescontroller (review feedback): the elevated-debug missing-state/value messages in publishFromState and publishToState (NOSTATES/NOVAL1/NOSTATE/ESTATE and 'No value published'), the disconnected-state cleanup messages in deleteOrphanedDeviceStates, and the delete-device debug in leaveDevice now print the raw object id instead of the device label. Two icon warnings (AddModelFromHerdsman, updateDev) printed a bare device name without any id at all - they now print the id instead, and the name lookup that only served that message is gone. Name resolution order in devLabel is now: local-config override (per-device wins over per-model; the per-model lookup is what needs the model parameter) -> cached object name (matches the admin display, including group names) -> model as last resort (no object yet, e.g. while pairing) -> 'unnamed (id)'. An empty-string model is treated as absent so it cannot suppress these fallbacks (publishFromState can be reached with model ''). Fixed on the way, all label-related: - publishPayload error path labelled via payload.device, which is undefined when the payload arrives as JSON string ('unknown device' in the log); now payloadObj.device. - removeDevFromGroup exception message printed the device label a second time where the group id belongs. - two group member read labels used member.id, which does not exist on the members the zigbee controller's getGroupMembersFromController returns ({ieee, model, epid, ...}); now member.ieee like the neighbouring labels. The devLabel methods on StatesController, ZigbeeController and BaseExtension remain exact (idOrIeee, model) pass-throughs to lib/deviceLabel.js. Addresses #2933 Co-Authored-By: Claude Fable 5 --- lib/deviceLabel.js | 14 ++++--- lib/groups.js | 14 +++---- lib/ota.js | 20 ++++----- lib/statescontroller.js | 79 ++++++++++++++++++----------------- lib/zbDeviceAvailability.js | 24 +++++------ lib/zbDeviceConfigure.js | 34 +++++++-------- lib/zbDeviceEvent.js | 2 +- lib/zigbeecontroller.js | 83 +++++++++++++++++++------------------ main.js | 8 ++-- 9 files changed, 143 insertions(+), 135 deletions(-) diff --git a/lib/deviceLabel.js b/lib/deviceLabel.js index f4c2348f..66733b0e 100644 --- a/lib/deviceLabel.js +++ b/lib/deviceLabel.js @@ -4,9 +4,10 @@ const utils = require('./utils'); /** * Resolve a device log label from any id/IEEE/group-id form (with or without namespace prefix). - * Looks up the user-assigned name via the adapter's state controller; when the user has not - * renamed the device, the name of the device object (usually the model, cached by the state - * controller) is used, so an un-named device is labelled the same way the admin shows it. The id + * Name resolution order: user override from the local config (per-device wins over per-model, + * the per-model lookup needs the model parameter) -> name of the device object (usually the + * model, cached by the state controller), so the label matches what the admin shows -> the model + * parameter itself (covers devices without an object, e.g. while pairing) -> "unnamed". The id * is always kept for unique identification (see utils.deviceDisplayName). Never throws — a log * line can never fail because of this. An invalid id resolves to "unknown device" (via * deviceDisplayName), a lookup failure to "failed to get name". @@ -15,7 +16,8 @@ const utils = require('./utils'); * * @param {object} adapter the ioBroker adapter instance (needs .stController.verifyDeviceName) * @param {string|number} idOrIeee the device id / IEEE address / group id (always shown in the label) - * @param {string} [model] the device model — per-model override key and default name when un-named + * @param {string} [model] the mapped model (common.type key space, 'group' for groups) — per-model + * override key and last-resort default name; empty/non-string values are ignored * @returns {string} the display label ("name (id)"), or "failed to get name (id)" on error */ function devLabel(adapter, idOrIeee, model) { @@ -23,8 +25,10 @@ function devLabel(adapter, idOrIeee, model) { try { const bareId = adapter && adapter.namespace ? String(idOrIeee).replace(`${adapter.namespace}.`, '') : idOrIeee; const adId = utils.zbIdorIeeetoAdId(adapter, bareId, false); + // '' must not reach verifyDeviceName: it is not nullish and would suppress the fallbacks + const mdl = typeof model === 'string' && model.length > 0 ? model : undefined; if (adapter && adapter.stController && typeof adapter.stController.verifyDeviceName === 'function') { - name = adapter.stController.verifyDeviceName(adId, model, model); + name = adapter.stController.verifyDeviceName(adId, mdl, undefined); } } catch { return `failed to get name (${idOrIeee})`; diff --git a/lib/groups.js b/lib/groups.js index fa71c7cd..41001d82 100644 --- a/lib/groups.js +++ b/lib/groups.js @@ -241,7 +241,7 @@ class Groups { if (!mappedModel) return; const obj = await this.adapter.getObjectAsync((member.ieee.includes('x') ? member.ieee.split('x')[1] : member.ieee)); if (obj && obj.common.deactivated) { - this.debug(`omitting reading member state for deactivated device '${devLabel(this.adapter, member.ieee)}'`); + this.debug(`omitting reading member state for deactivated device '${devLabel(this.adapter, member.ieee, mappedModel.model)}'`); return; } const converter = mappedModel.toZigbee.find(c => c && (c.key.includes(item.state))); @@ -250,10 +250,10 @@ class Groups { try { await converter.convertGet(endpoint, item.state, {device:entity.device}); } catch (error) { - this.debug(`reading ${item.state} from '${devLabel(this.adapter, member.id)}'${member.ieee ? '/' + member.epid : ''} via convertGet failed with ${error && error.message ? error.message : 'no reason given'}`); + this.debug(`reading ${item.state} from '${devLabel(this.adapter, member.ieee, mappedModel.model)}'${member.ieee ? '/' + member.epid : ''} via convertGet failed with ${error && error.message ? error.message : 'no reason given'}`); return {unread:member.device}; } - this.debug(`reading ${item.state} from '${devLabel(this.adapter, member.ieee)}'${member.ep ? '/' + member.epid : ''} via convertGet succeeded` ); + this.debug(`reading ${item.state} from '${devLabel(this.adapter, member.ieee, mappedModel.model)}'${member.ep ? '/' + member.epid : ''} via convertGet succeeded` ); return {read:member.device}; } if (toRead.cluster) { @@ -261,17 +261,17 @@ class Groups { if (entity.endpoint.inputClusters.includes(toRead.cluster)) { try { const result = await endpoint.read(toRead.cluster, toRead.attributes,{disableDefaultResponse : true }); - this.debug(`readGroupMemberStatus for ${item.state} from '${devLabel(this.adapter, member.ieee)}'${member.ep ? '/' + member.epid : ''} resulted in ${JSON.stringify(result)}`); + this.debug(`readGroupMemberStatus for ${item.state} from '${devLabel(this.adapter, member.ieee, mappedModel.model)}'${member.ep ? '/' + member.epid : ''} resulted in ${JSON.stringify(result)}`); } catch (error) { - this.debug(`reading ${item.state} from '${devLabel(this.adapter, member.ieee)}'${member.ep ? '/' + member.epid : ''} via endpoint.read with ${toRead.cluster}, ${JSON.stringify(toRead.attributes)} resulted in ${error && error.message ? error.message : 'an unspecified error'}`); + this.debug(`reading ${item.state} from '${devLabel(this.adapter, member.ieee, mappedModel.model)}'${member.ep ? '/' + member.epid : ''} via endpoint.read with ${toRead.cluster}, ${JSON.stringify(toRead.attributes)} resulted in ${error && error.message ? error.message : 'an unspecified error'}`); } - this.debug(`reading ${item.state} from '${devLabel(this.adapter, member.ieee)}'${member.ep ? '/' + member.epid : ''} via endpoint.read with ${toRead.cluster}, ${JSON.stringify(toRead.attributes)} succeeded`); + this.debug(`reading ${item.state} from '${devLabel(this.adapter, member.ieee, mappedModel.model)}'${member.ep ? '/' + member.epid : ''} via endpoint.read with ${toRead.cluster}, ${JSON.stringify(toRead.attributes)} succeeded`); } else this.debug(`omitting cluster ${toRead.cluster} - not supported`); } else { - this.debug(`unable to read ${item.state} from '${devLabel(this.adapter, member.id)}'${member.ep ? '/' + member.epid : ''} - unable to resolve the entity`); + this.debug(`unable to read ${item.state} from '${devLabel(this.adapter, member.ieee, mappedModel.model)}'${member.ep ? '/' + member.epid : ''} - unable to resolve the entity`); } return; } diff --git a/lib/ota.js b/lib/ota.js index 9d2b3dd9..c247113f 100755 --- a/lib/ota.js +++ b/lib/ota.js @@ -164,28 +164,28 @@ class Ota { return result; } if (this.inProgress.has(devIeee)) { - this.error(`Update or check already in progress for '${devLabel(this.adapter, devIeee)}', skipping...`); + this.error(`Update or check already in progress for '${devLabel(this.adapter, devIeee, entity?.mapped?.model)}', skipping...`); return; } // do not attempt update for a device which has been deactivated or is unavailable const stateObj = await this.adapter.getObjectAsync(objID); if (stateObj && stateObj.common && stateObj.common.deactivated) { - this.info(`Device '${devLabel(this.adapter, devIeee)}' is deactivated, skipping ota check`); + this.info(`Device '${devLabel(this.adapter, devIeee, entity?.mapped?.model)}' is deactivated, skipping ota check`); return; } const availablestate = await this.adapter.getStateAsync(`${objID}.available`); const lqi = await this.adapter.getStateAsync(`${objID}.link_quality`); if ((availablestate && (!availablestate.val)) || (lqi && lqi.val < 1)) { - this.info(`Device '${devLabel(this.adapter, devIeee)}' is marked unavailable, skipping ota check`); + this.info(`Device '${devLabel(this.adapter, devIeee, entity?.mapped?.model)}' is marked unavailable, skipping ota check`); return; } const result = { status: 'unknown', decice:entity?.name ?? 'no name'}; this.inProgress.add(entity.device.ieeeAddr); try { - this.info('Start firmware update for ' + "'" + devLabel(this.adapter, entity.device.ieeeAddr) + "'"); + this.info('Start firmware update for ' + "'" + devLabel(this.adapter, entity.device.ieeeAddr, entity.mapped?.model) + "'"); const onProgress = (progress, remaining) => { - let message = `Update of '${devLabel(this.adapter, entity.device.ieeeAddr)}' at ${progress}%`; + let message = `Update of '${devLabel(this.adapter, entity.device.ieeeAddr, entity.mapped?.model)}' at ${progress}%`; if (remaining) { message += `, +- ${Math.round(remaining / 60)} minutes remaining`; } @@ -225,7 +225,7 @@ class Ota { this.info(result.msg); } catch (error) { - const message = `Update of '${devLabel(this.adapter, entity.device.ieeeAddr)}' failed (${error.message})`; + const message = `Update of '${devLabel(this.adapter, entity.device.ieeeAddr, entity.mapped?.model)}' failed (${error.message})`; result.status = 'fail'; result.msg = message; this.error(message); @@ -282,20 +282,20 @@ class Ota { } this.inProgress.add(ieeeAddr); try { - this.debug(`Checking if firmware update is available for '${devLabel(this.adapter, ieeeAddr)}'`); + this.debug(`Checking if firmware update is available for '${devLabel(this.adapter, ieeeAddr, entity?.mapped?.model)}'`); if (entity && entity.mapped.ota) { const available = await entity.device.checkOta({ downgrade:false }, undefined, typeof entity.mapped.ota === 'object' ? entity.mapped.ota : {}, undefined); result.status = available.available ? 'available' : 'not_available'; if (available.currentFileVersion !== available.otaFileVersion) { - this.debug(`current Firmware for '${devLabel(this.adapter, ieeeAddr)}' is ${available.currentFileVersion} new is ${available.otaFileVersion}`); + this.debug(`current Firmware for '${devLabel(this.adapter, ieeeAddr, entity?.mapped?.model)}' is ${available.currentFileVersion} new is ${available.otaFileVersion}`); } } else { result.status = 'not_supported'; } - this.debug(`Firmware update for '${devLabel(this.adapter, ieeeAddr)}' is ${result.status}`); + this.debug(`Firmware update for '${devLabel(this.adapter, ieeeAddr, entity?.mapped?.model)}' is ${result.status}`); } catch (error) { - const message = `Failed to check if update available for '${devLabel(this.adapter, ieeeAddr)}' ${error.message}`; + const message = `Failed to check if update available for '${devLabel(this.adapter, ieeeAddr, entity?.mapped?.model)}' ${error.message}`; result.status = 'fail'; result.msg = message; if (!message.includes(`Device didn't respond to OTA request`)) this.warn(message); diff --git a/lib/statescontroller.js b/lib/statescontroller.js index ffa4e55e..88446b11 100644 --- a/lib/statescontroller.js +++ b/lib/statescontroller.js @@ -99,10 +99,10 @@ class StatesController extends EventEmitter { } leaveDevice(ieeeAddr, model) { - this.debug(`Leave device event: '${this.devLabel(ieeeAddr)}'`); + this.debug(`Leave device event: '${this.devLabel(ieeeAddr, model)}'`); if (ieeeAddr) { const devId = utils.zbIdorIeeetoAdId(this, ieeeAddr, false); - this.debug(`Delete device '${this.devLabel(devId)}' from iobroker.`); + this.debug(`Delete device '${devId}' from iobroker.`); this.deleteObj(devId); } } @@ -151,8 +151,7 @@ class StatesController extends EventEmitter { const namespace = `${this.adapter.name}.admin`; const isLegacy = Boolean(this.localConfig.getModelOption(model, 'legacy')); if (model === undefined) { - const dev_name = this.verifyDeviceName(utils.zbIdorIeeetoAdId(this.adapter, device.ieeeAddr, false), model, device.modelID); - this.warn(`icon ${dev_name} for undefined Device not available. Check your devices.`); + this.warn(`icon for undefined Device '${utils.zbIdorIeeetoAdId(this.adapter, device.ieeeAddr, false)}' not available. Check your devices.`); return; } @@ -347,7 +346,7 @@ class StatesController extends EventEmitter { if (model && model.id === 'device_query') { if (this.query_device_block.indexOf(deviceId) > -1 && !state.source.includes('.admin.')) { - this.info(`Device query for '${this.devLabel(deviceId)}' blocked - device query timeout has not elapsed yet.`); + this.info(`Device query for '${this.devLabel(deviceId, model)}' blocked - device query timeout has not elapsed yet.`); return; } this.emit('device_query', { deviceId, debugId }); @@ -387,7 +386,7 @@ class StatesController extends EventEmitter { this.adapter.getState(id, (err, state) => { cnt = cnt + 1; if (!err && state) { - this.debug(`collect options for '${this.devLabel(devId)}': ${JSON.stringify(result)}`); + this.debug(`collect options for '${this.devLabel(devId, model)}': ${JSON.stringify(result)}`); result[statedesc.id] = statedesc.setter ? statedesc.setter(state.val) : state.val; } if (cnt === len) { @@ -400,11 +399,11 @@ class StatesController extends EventEmitter { } } catch (error) { this.sendError(error); - this.error(`Error collectOptions for '${this.devLabel(devId)}'. Error: ${error.stack}`); + this.error(`Error collectOptions for '${this.devLabel(devId, model)}'. Error: ${error.stack}`); } } catch (error) { - this.error(`Error in collectOptions for '${this.devLabel(devId)}' , ${model} : ${error && error.message ? error.message : 'no message given'}`); + this.error(`Error in collectOptions for '${this.devLabel(devId, model)}' , ${model} : ${error && error.message ? error.message : 'no message given'}`); callback({}); } @@ -437,7 +436,7 @@ class StatesController extends EventEmitter { return {states, stateModel}; } catch (error) { this.sendError(error); - this.error(`Error getDevStates for '${this.devLabel(deviceId)}'. Error: ${error.stack}`); + this.error(`Error getDevStates for '${this.devLabel(deviceId, model)}'. Error: ${error.stack}`); } } @@ -591,18 +590,18 @@ class StatesController extends EventEmitter { } async publishFromState(deviceId, model, stateKey, state, options, debugID) { - if (this.debugActive) this.debug(`Change state '${stateKey}' at device '${this.devLabel(deviceId)}' type '${model}'`); + if (this.debugActive) this.debug(`Change state '${stateKey}' at device '${this.devLabel(deviceId, model)}' type '${model}'`); const has_elevated_debug = this.checkDebugDevice(typeof deviceId == 'number' ? `group_${deviceId}` : deviceId); if (has_elevated_debug) { - const message = (`Change state '${stateKey}' at device '${this.devLabel(deviceId)}' type '${model}'`); + const message = (`Change state '${stateKey}' at device '${this.devLabel(deviceId, model)}' type '${model}'`); this.emit('device_debug', { ID:debugID, data: { ID: deviceId, model: model, flag:'02', IO:false }, message:message}); } const devStates = await this.getDevStates(deviceId, model); if (!devStates) { if (has_elevated_debug) { - const message = (`no device states for device '${this.devLabel(deviceId)}' type '${model}'`); + const message = (`no device states for device '${utils.zbIdorIeeetoAdId(this.adapter, deviceId, false)}' type '${model}'`); this.emit('device_debug', { ID:debugID, data: { error: 'NOSTATES' , IO:false }, message:message}); } return; @@ -610,7 +609,7 @@ class StatesController extends EventEmitter { const stateDesc = devStates.states.find(statedesc => stateKey === statedesc.id); const stateModel = devStates.stateModel; if (!stateDesc) { - const message = (`No state available for '${model}' with key '${stateKey}'`); + const message = (`No state available for device '${utils.zbIdorIeeetoAdId(this.adapter, deviceId, false)}' type '${model}' with key '${stateKey}'`); if (has_elevated_debug) this.emit('device_debug', { ID:debugID, data: { states:[{id:state.ID, value:'unknown', payload:'unknown'}], error: 'NOSTKEY' , IO:false }, message:message}); return; } @@ -618,7 +617,7 @@ class StatesController extends EventEmitter { const value = state.val; if (value === undefined || value === '') { if (has_elevated_debug) { - const message = (`no value for device '${this.devLabel(deviceId)}' type '${model}'`); + const message = (`no value for device '${utils.zbIdorIeeetoAdId(this.adapter, deviceId, false)}' type '${model}'`); this.emit('device_debug', { ID:debugID, data: { states:[{id:state.ID, value:'--', payload:'error', ep:stateDesc.epname}],error: 'NOVAL1' , IO:false }, message:message}); } return; @@ -735,7 +734,9 @@ class StatesController extends EventEmitter { } verifyDeviceName(id, model, name) { - return this.localConfig.NameForId(id, model, name ?? this.cachedDeviceNames.get(id)); + // default-name chain: explicit name from the caller -> cached object name (matches what + // the admin shows, includes group names) -> the model as last resort (no object yet) + return this.localConfig.NameForId(id, model, name ?? this.cachedDeviceNames.get(id) ?? model); } // Prime the device name cache from the adapter's own device/group objects. Called once on @@ -789,7 +790,9 @@ class StatesController extends EventEmitter { this.cachedDeviceNames.delete(devId); return {status:true}; } catch (error) { - this.adapter.log.warn(`Cannot delete Object '${this.devLabel(devId)}': ${error && error.message ? error.message : 'without error message'}`); + // no devLabel here: devId can be any object path (e.g. a state id from + // deleteOrphanedDeviceStates) and the message is about the object, not the device + this.adapter.log.warn(`Cannot delete Object '${devId}': ${error && error.message ? error.message : 'without error message'}`); return { status:false, message: `Cannot delete Object ${devId}: ${error && error.message ? error.message : 'without error message'}`}; } } @@ -833,8 +836,8 @@ class StatesController extends EventEmitter { ) { this.cleanupRequired |= markOnly; if (state.common.hasOwnProperty('custom') && !force && !markOnly) { - messages.push(`keeping disconnected state ${JSON.stringify(statename)} of '${this.devLabel(devId)}' `) - this.info(`keeping disconnected state ${JSON.stringify(statename)} of '${this.devLabel(devId)}' `); + messages.push(`keeping disconnected state ${JSON.stringify(statename)} of '${devId}' `) + this.info(`keeping disconnected state ${JSON.stringify(statename)} of '${devId}' `); this.cleanupRequired = true; } else { if (markOnly) { @@ -844,8 +847,8 @@ class StatesController extends EventEmitter { else { try { - this.info(`deleting disconnected state ${JSON.stringify(statename)} of '${this.devLabel(devId)}' `); - messages.push(`deleting disconnected state ${JSON.stringify(statename)} of '${this.devLabel(devId)}' `); + this.info(`deleting disconnected state ${JSON.stringify(statename)} of '${devId}' `); + messages.push(`deleting disconnected state ${JSON.stringify(statename)} of '${devId}' `); this.deleteObj(devId.concat('.',statename)); } catch (error) { @@ -855,8 +858,8 @@ class StatesController extends EventEmitter { } } else { if (!markOnly) { - if (this.debugActive) this.debug(`keeping connected state ${JSON.stringify(statename)} of '${this.devLabel(devId)}' `); - messages.push(`keeping connecte state ${JSON.stringify(statename)} of '${this.devLabel(devId)}' `); + if (this.debugActive) this.debug(`keeping connected state ${JSON.stringify(statename)} of '${devId}' `); + messages.push(`keeping connected state ${JSON.stringify(statename)} of '${devId}' `); } } }); @@ -1040,7 +1043,7 @@ class StatesController extends EventEmitter { async updateDev(dev_id, dev_name, model) { const __dev_name = this.verifyDeviceName(dev_id, model, (dev_name ? dev_name : model)); - if (this.debugActive) this.debug(`UpdateDev called with '${this.devLabel(dev_id)}', ${dev_name}, ${model}, ${__dev_name}`); + if (this.debugActive) this.debug(`UpdateDev called with '${this.devLabel(dev_id, model)}', ${dev_name}, ${model}, ${__dev_name}`); const id = '' + dev_id; const objId = model=='group' ? `group_${dev_id}` : dev_id; const obj = await this.adapter.getObjectAsync(objId); @@ -1053,7 +1056,7 @@ class StatesController extends EventEmitter { // download icon if it external and not undefined if (model === undefined) { - this.warn(`download icon ${__dev_name} for undefined Device not available. Check your devices.`); + this.warn(`download icon for undefined Device '${dev_id}' not available. Check your devices.`); } else { const model_modif = model.replace(/\//g, '-'); const pathToAdminIcon = `img/${model_modif}.png`; @@ -1153,7 +1156,7 @@ class StatesController extends EventEmitter { } async syncDevStates(dev, model) { - if (this.debugActive) this.debug('synchronizing device states for ' + "'" + this.devLabel(dev.ieeeAddr) + "'" + ' (' + model + ')'); + if (this.debugActive) this.debug('synchronizing device states for ' + "'" + this.devLabel(dev.ieeeAddr, model) + "'" + ' (' + model + ')'); const devId = utils.zbIdorIeeetoAdId(this.adapter, dev.ieeeAddr, false); // devId - iobroker device id const devStates = await this.getDevStates(dev.ieeeAddr, model); @@ -1244,13 +1247,13 @@ class StatesController extends EventEmitter { // checking value if (value === undefined || value === null) { - const message = `value '${JSON.stringify(value)}' from device '${this.devLabel(devId)}' via ${mode} for '${statedesc.name} (ID ${statedesc.id} ${statedesc.prop ? 'with property '+statedesc.prop : ''})`; + const message = `value '${JSON.stringify(value)}' from device '${this.devLabel(devId, model)}' via ${mode} for '${statedesc.name} (ID ${statedesc.id} ${statedesc.prop ? 'with property '+statedesc.prop : ''})`; if (has_elevated_debug) this.emit('device_debug', { ID:debugId, data: { states:[{id:stateID, value:value, payload:payload }],flag:'04', IO:true }, message}); else if (this.debugActive) this.debug(message); return {}; } - const message = `value generated '${typeof(value) == 'object' ? JSON.stringify(value) : value}' from device '${this.devLabel(devId)}' for '${statedesc.name}'`; + const message = `value generated '${typeof(value) == 'object' ? JSON.stringify(value) : value}' from device '${this.devLabel(devId, model)}' for '${statedesc.name}'`; if (statedesc.id != 'msg_from_zigbee' && has_elevated_debug ) { this.emit('device_debug', { ID:debugId, data: { states:[{id:stateID, value:value, payload:payload }],flag:'04', IO:true }, message}); } @@ -1309,14 +1312,14 @@ class StatesController extends EventEmitter { const has_elevated_debug = (this.checkDebugDevice(devId) && !payload.hasOwnProperty('msg_from_zigbee')); - const message = `message received '${JSON.stringify(payload)}' from device '${this.devLabel(devId)}' type '${model}'`; + const message = `message received '${JSON.stringify(payload)}' from device '${this.devLabel(devId, model)}' type '${model}'`; if (has_elevated_debug) this.emit('device_debug', { ID:debugId, data: { deviceID: devId, flag:'03', IO:true }, message:message}); else if (this.debugActive) this.debug(message); if (!devStates) { - const message = `no device states for device '${this.devLabel(devId)}' type '${model}'`; + const message = `no device states for device '${devId}' type '${model}'`; if (has_elevated_debug)this.emit('device_debug', { ID:debugId, data: { error:'NOSTATE',states:[{ id:'--', value:'--', payload:payload}], IO:true }, message:message}); else if (this.debugActive) this.debug(message); return undefined; @@ -1334,18 +1337,18 @@ class StatesController extends EventEmitter { publishedStates[publishResult.key] = publishResult.value; } } catch (e) { - const message = `unable to enumerate states of '${this.devLabel(devId)}' for payload ${JSON.stringify(payload)}, ${(e ? e.name : 'undefined')} (${(e ? e.message : '')}).`; + const message = `unable to enumerate states of '${devId}' for payload ${JSON.stringify(payload)}, ${(e ? e.name : 'undefined')} (${(e ? e.message : '')}).`; if (has_elevated_debug) this.emit('device_debug', { ID:debugId, data:{ error:'ESTATE', IO:true }, message:message}); else if (this.debugActive) this.debug(message); } - const message = `No value published for device '${this.devLabel(devId)}'`; + const message = `No value published for device '${devId}'`; if (Object.keys(publishedStates).length == 0) { if (has_elevated_debug) this.emit('device_debug', { ID:debugId, data:{ states:[{id:'no state', value:'no value', inError:true, payload:payload }], flag:'04', IO:true }, message:message}); else if (this.debugActive) this.debug(message); } } else { - const message = `ELEVATED IE05 - NOSTATE: No states matching the payload ${JSON.stringify(payload)} for device '${this.devLabel(devId)}'`; + const message = `ELEVATED IE05 - NOSTATE: No states matching the payload ${JSON.stringify(payload)} for device '${devId}'`; if (has_elevated_debug) this.emit('device_debug', { ID:debugId, data:{ error:'NOSTATE', IO:true }, message}); else if (this.debugActive) this.debug(message); } @@ -1436,7 +1439,7 @@ class StatesController extends EventEmitter { else resolve({}); } catch (error) { - const msg = `Error while processing converters DEVICE_ID: '${this.devLabel(devId)}' cluster '${converter.cluster}' type '${converter.type}' ${error && error.message ? ' message: ' + error.message : ''}`; + const msg = `Error while processing converters DEVICE_ID: '${this.devLabel(devId, model)}' cluster '${converter.cluster}' type '${converter.type}' ${error && error.message ? ' message: ' + error.message : ''}`; if (has_elevated_debug) this.emit('device_debug', { ID:debugId, data: { error:'EPROC', IO:true }, message: `${msg} - ${error?.stack ?? 'no stack available'}` }); this.warn(msg); resolve ({}) @@ -1483,7 +1486,7 @@ class StatesController extends EventEmitter { const has_elevated_debug = this.checkDebugDevice(devId); const debugId = Date.now(); if (entity.device.interviewing) { - this.debug(`zigbee event for '${this.devLabel(device.ieeeAddr)}' received during interview!`); + this.debug(`zigbee event for '${this.devLabel(device.ieeeAddr, model)}' received during interview!`); return; } @@ -1557,7 +1560,7 @@ class StatesController extends EventEmitter { } } if (has_elevated_debug) { - const message = `Zigbee Event of Type ${type} from device '${this.devLabel(device.ieeeAddr)}', incoming event: ${safeJsonStringify(msgForState)}`; + const message = `Zigbee Event of Type ${type} from device '${this.devLabel(device.ieeeAddr, model)}', incoming event: ${safeJsonStringify(msgForState)}`; this.emit('device_debug', { ID:debugId, data: { ID: device.ieeeAddr, payload:safeJsonStringify(msgForState), flag:'01', IO:true }, message:message}); } @@ -1630,13 +1633,13 @@ class StatesController extends EventEmitter { } if (has_elevated_debug) { - const message = `${converters.length} converter${converters.length > 1 ? 's' : ''} available for '${mappedModel.model}' '${this.devLabel(devId)}' with cluster '${cluster}' and type '${type}'`; + const message = `${converters.length} converter${converters.length > 1 ? 's' : ''} available for '${mappedModel.model}' '${this.devLabel(devId, model)}' with cluster '${cluster}' and type '${type}'`; this.emit('device_debug', { ID:debugId, data: { flag:'02', IO:true }, message:message}) } if (!converters.length) { if (type !== 'readResponse' && type !== 'commandQueryNextImageRequest') { - const message = `No converter available for '${mappedModel.model}' '${this.devLabel(devId)}' with cluster '${cluster}' and type '${type}'`; + const message = `No converter available for '${mappedModel.model}' '${this.devLabel(devId, model)}' with cluster '${cluster}' and type '${type}'`; if (has_elevated_debug) this.emit('device_debug', { ID:debugId, data: { error:'NOCONV', IO:true }, message:message}); else if (this.debugActive) this.debug(message); } @@ -1675,7 +1678,7 @@ class StatesController extends EventEmitter { // 'Error: Expected one of: 0, 1, got: 'undefined'' if (cluster !== '64529') { if (has_elevated_debug) this.emit('device_debug', { ID:debugId, data: { error:'EPROC', IO:true }}); - this.error(`Error while processing converters DEVICE_ID: '${this.devLabel(devId)}' cluster '${cluster}' type '${type}'`); + this.error(`Error while processing converters DEVICE_ID: '${this.devLabel(devId, model)}' cluster '${cluster}' type '${type}'`); this.error(`error message: ${error && error.message ? error.message : ''}`); } } diff --git a/lib/zbDeviceAvailability.js b/lib/zbDeviceAvailability.js index f6cfd3e6..2e29d3a3 100644 --- a/lib/zbDeviceAvailability.js +++ b/lib/zbDeviceAvailability.js @@ -99,7 +99,7 @@ class DeviceAvailability extends BaseExtension { async registerDevicePing(device, entity) { if (!this.isStarted) return; - this.debug(`register device Ping for '${this.devLabel(device.ieeeAddr)}'`); + this.debug(`register device Ping for '${this.devLabel(device.ieeeAddr, entity?.mapped?.model)}'`); this.forcedNonPingable[device.ieeeAddr] = false; if (!this.isPingable(device)) { return; @@ -112,7 +112,7 @@ class DeviceAvailability extends BaseExtension { } }); this.number_of_registered_devices++; - this.debug(`registering device Ping (${this.number_of_registered_devices}) for '${this.devLabel(device.ieeeAddr)}'`); + this.debug(`registering device Ping (${this.number_of_registered_devices}) for '${this.devLabel(device.ieeeAddr, entity?.mapped?.model)}'`); this.availability_timeout = Math.max(Math.min(this.number_of_registered_devices * AverageTimeBetweenPings, MaxAvailabilityTimeout), MinAvailabilityTimeout); this.startDevicePingQueue.push({device, entity}); if (this.startDevicePingTimeout == null) { @@ -212,7 +212,7 @@ class DeviceAvailability extends BaseExtension { } try { if (!this.pingCluster || !this.pingCluster.hasOwnProperty('id')) { - const message = `Pinging '${this.devLabel(ieeeAddr)}' (${device.modelID}) via ZH Ping` + const message = `Pinging '${this.devLabel(ieeeAddr, resolvedEntity.mapped?.model)}' (${device.modelID}) via ZH Ping` if (has_elevated_debug) { this.zigbee.emit('device_debug', { ID:debugID, data: { ID: device.ieeeAddr, flag:'PI', IO:false, states:[{ id:'ping', value: 'zh_default', payload: { method:'default'}}]}, message:message}); } @@ -222,7 +222,7 @@ class DeviceAvailability extends BaseExtension { else { const zclData = {}; zclData[this.pingCluster.attribute] = {}; - const message = `Pinging '${this.devLabel(ieeeAddr)}' (${device.modelID}) via ZCL Read with ${this.pingCluster.id}:${this.pingCluster.attribute}` + const message = `Pinging '${this.devLabel(ieeeAddr, resolvedEntity.mapped?.model)}' (${device.modelID}) via ZCL Read with ${this.pingCluster.id}:${this.pingCluster.attribute}` if (has_elevated_debug) { this.zigbee.emit('device_debug', { ID:debugID, data: { ID: device.ieeeAddr, flag:'PI', states:[{id:'ping', value:'cluster/id', payload: { method: 'custom', cluster:this.pingCluster.id, command:'read', zcl:zclData}}], IO:false}, message:message}); } @@ -231,7 +231,7 @@ class DeviceAvailability extends BaseExtension { } this.publishAvailability(device, true, false, has_elevated_debug ? debugID : undefined); if (has_elevated_debug) { - const message = `Successfully pinged '${this.devLabel(ieeeAddr)}' in ${Date.now()-debugID} ms` + const message = `Successfully pinged '${this.devLabel(ieeeAddr, resolvedEntity.mapped?.model)}' in ${Date.now()-debugID} ms` this.zigbee.emit('device_debug', { ID:debugID, data: {ID: device.ieeeAddr, flag:'SUCCESS', IO:false}, message:message}); } this.setTimerPingable(device, 1); @@ -241,16 +241,16 @@ class DeviceAvailability extends BaseExtension { // this error is acceptable, as it is raised off an answer of the device. this.publishAvailability(device, true); if (has_elevated_debug) - this.zigbee.emit('device_debug', { ID:debugID, data: {ID: device.ieeeAddr, flag:'SUCCESS', IO:false}, message:`Successfully pinged '${this.devLabel(ieeeAddr)}' in ${Date.now()-debugID} ms`}); + this.zigbee.emit('device_debug', { ID:debugID, data: {ID: device.ieeeAddr, flag:'SUCCESS', IO:false}, message:`Successfully pinged '${this.devLabel(ieeeAddr, resolvedEntity.mapped?.model)}' in ${Date.now()-debugID} ms`}); this.setTimerPingable(device, 1); this.ping_counters[device.ieeeAddr].failed = 0; return; } if (has_elevated_debug) - this.zigbee.emit('device_debug',{ ID:debugID, data: {ID: device.ieeeAddr, error:'PIFAIL', IO:false}, message:`Failed to ping '${this.devLabel(ieeeAddr)}' after ${Date.now()-debugID} ms${error && error.message ? ' - '+error.message : ''}`}); + this.zigbee.emit('device_debug',{ ID:debugID, data: {ID: device.ieeeAddr, error:'PIFAIL', IO:false}, message:`Failed to ping '${this.devLabel(ieeeAddr, resolvedEntity.mapped?.model)}' after ${Date.now()-debugID} ms${error && error.message ? ' - '+error.message : ''}`}); this.publishAvailability(device, false, false, has_elevated_debug ? debugID : undefined); if (pingCount.failed++ <= this.max_ping) { - const message = `Failed to ping '${this.devLabel(ieeeAddr)}' for ${JSON.stringify(pingCount)} attempts` + const message = `Failed to ping '${this.devLabel(ieeeAddr, resolvedEntity.mapped?.model)}' for ${JSON.stringify(pingCount)} attempts` if (pingCount.reported < this.max_ping) { if (!has_elevated_debug) this.info(message); @@ -261,7 +261,7 @@ class DeviceAvailability extends BaseExtension { this.setTimerPingable(device, pingCount.failed); this.ping_counters[device.ieeeAddr] = pingCount; } else { - const msg = `Stopping to ping '${this.devLabel(ieeeAddr)}' after ${pingCount.failed} ping attempts`; + const msg = `Stopping to ping '${this.devLabel(ieeeAddr, resolvedEntity.mapped?.model)}' after ${pingCount.failed} ping attempts`; if (has_elevated_debug) this.zigbee.emit('device_debug',{ ID:debugID, data: {ID: device.ieeeAddr, error:'PISTOP', IO:false}, message:msg}); else @@ -282,11 +282,11 @@ class DeviceAvailability extends BaseExtension { if (ago > Hours25) { this.publishAvailability(entity.device, false); - const msg = `Non-pingable device '${this.devLabel(entity.device.ieeeAddr)}' was last seen over 25 hrs ago - setting it offline.` + const msg = `Non-pingable device '${this.devLabel(entity.device.ieeeAddr, entity.mapped?.model)}' was last seen over 25 hrs ago - setting it offline.` if (this.checkDebugDevice(device.ieeeAddr)) this.warn(`ELEVATED: ${msg}`); else this.debug(msg); return; } - const msg = `Non-pingable device '${this.devLabel(entity.device.ieeeAddr)}' was last seen '${ago / 1000}' seconds ago.` + const msg = `Non-pingable device '${this.devLabel(entity.device.ieeeAddr, entity.mapped?.model)}' was last seen '${ago / 1000}' seconds ago.` if (this.checkDebugDevice(device.ieeeAddr)) this.warn(`ELEVATED: ${msg}`); else this.debug(msg); } @@ -326,7 +326,7 @@ class DeviceAvailability extends BaseExtension { } } catch (error) { this.sendError(error); - this.debug(`Failed to read state of '${this.devLabel(entity.device.ieeeAddr)}' after reconnect`); + this.debug(`Failed to read state of '${this.devLabel(entity.device.ieeeAddr, entity.mapped.model)}' after reconnect`); } } } diff --git a/lib/zbDeviceConfigure.js b/lib/zbDeviceConfigure.js index 0ac90dba..8c5db77f 100755 --- a/lib/zbDeviceConfigure.js +++ b/lib/zbDeviceConfigure.js @@ -32,7 +32,7 @@ class DeviceConfigure extends BaseExtension { return; } const configureItem = this.deviceConfigureQueue.shift(); - this.info(`DeviceConfigureQueue configuring '${this.devLabel(configureItem.dev.ieeeAddr)}'`) + this.info(`DeviceConfigureQueue configuring '${this.devLabel(configureItem.dev.ieeeAddr, configureItem.mapped?.model)}'`) this.doConfigure(configureItem.dev, configureItem.mapped); } @@ -75,7 +75,7 @@ class DeviceConfigure extends BaseExtension { const t = Date.now(); const cfgkey = definitionVersion; const result = device.meta.hasOwnProperty('configured') && device.meta.configured !== cfgkey && definitionVersion != '0.0.0'; - this.debug(`should configure for device '${this.devLabel(device.ieeeAddr)}' (${mappedDevice.model}: ${device.meta.hasOwnProperty('configured') ? device.meta.configured: 'none'} - ${cfgkey} (query took ${Date.now()- t} ms)`); + this.debug(`should configure for device '${this.devLabel(device.ieeeAddr, mappedDevice.model)}' (${mappedDevice.model}: ${device.meta.hasOwnProperty('configured') ? device.meta.configured: 'none'} - ${cfgkey} (query took ${Date.now()- t} ms)`); return result; } @@ -86,10 +86,10 @@ class DeviceConfigure extends BaseExtension { for (const device of await this.zigbee.getClientIterator()) { const mappedDevice = await zigbeeHerdsmanConverters.findByDevice(device); if (this.shouldConfigure(device, mappedDevice)) { - this.info(`DeviceConfigure '${this.devLabel(device.ieeeAddr)}' needed - Device added to Configuration Queue`); + this.info(`DeviceConfigure '${this.devLabel(device.ieeeAddr, mappedDevice?.model)}' needed - Device added to Configuration Queue`); this.PushDeviceToQueue(device, mappedDevice); } else { - this.debug(`DeviceConfigure '${this.devLabel(device.ieeeAddr)}' not needed`); + this.debug(`DeviceConfigure '${this.devLabel(device.ieeeAddr, mappedDevice?.model)}' not needed`); } } } catch (error) { @@ -107,7 +107,7 @@ class DeviceConfigure extends BaseExtension { this.info(`checking configure on message : next attempt in ${30000 - (Date.now() - com.timestamp)} seconds`); if (Date.now() - com.timestamp > 30000 && !this.configuring.has(device.ieeeAddr)) { com.timestamp = Date.now(); - this.info('Configure on Message for ' + "'" + this.devLabel(device.ieeeAddr) + "'"); + this.info('Configure on Message for ' + "'" + this.devLabel(device.ieeeAddr, mappedDevice.model) + "'"); this.doConfigure(device, mappedDevice); } return; @@ -155,12 +155,12 @@ class DeviceConfigure extends BaseExtension { await this.doConfigure(device, mappedDevice) } catch (error) { this.sendError(error); - this.warn(`DeviceConfigure failed '${this.devLabel(device.ieeeAddr)}'`); + this.warn(`DeviceConfigure failed '${this.devLabel(device.ieeeAddr, mappedDevice?.model)}'`); } } } catch (error) { this.sendError(error); - this.error(`Failed to DeviceConfigure.configure '${this.devLabel(device.ieeeAddr)}': ${error && error.message ? error.message : 'no error message'})`); + this.error(`Failed to DeviceConfigure.configure '${this.devLabel(device.ieeeAddr, mappedDevice?.model)}': ${error && error.message ? error.message : 'no error message'})`); } } @@ -181,11 +181,11 @@ class DeviceConfigure extends BaseExtension { const cfgKey = mappedDevice?.version ?? '0.0.0'; try { if (mappedDevice) { - if (mappedDevice.configure === undefined) return `No configure available for '${this.devLabel(device.ieeeAddr)}'.`; + if (mappedDevice.configure === undefined) return `No configure available for '${this.devLabel(device.ieeeAddr, mappedDevice.model)}'.`; if (cfgKey != device.meta.configured) - this.info(`Configuring '${this.devLabel(device.ieeeAddr)}' ${device.meta.configured ? 'from V'+ device.meta.configured : ''} to V${cfgKey}`); + this.info(`Configuring '${this.devLabel(device.ieeeAddr, mappedDevice.model)}' ${device.meta.configured ? 'from V'+ device.meta.configured : ''} to V${cfgKey}`); else - this.info(`Reconfiguring '${this.devLabel(device.ieeeAddr)}' with V${cfgKey}`); + this.info(`Reconfiguring '${this.devLabel(device.ieeeAddr, mappedDevice.model)}' with V${cfgKey}`); this.configuring.add(device.ieeeAddr); if (typeof mappedDevice.configure === 'function') await mappedDevice.configure(device, coordinatorEndpoint, mappedDevice); else { @@ -197,7 +197,7 @@ class DeviceConfigure extends BaseExtension { this.configuring.delete(device.ieeeAddr); delete this.configureOnMessageAttempts[device.ieeeAddr]; device.save(); - this.info(`DeviceConfigure to V${device.meta.configured} for '${this.devLabel(device.ieeeAddr)}' successful.`); + this.info(`DeviceConfigure to V${device.meta.configured} for '${this.devLabel(device.ieeeAddr, mappedDevice.model)}' successful.`); return ''; } } catch (error) { @@ -210,7 +210,7 @@ class DeviceConfigure extends BaseExtension { this.configuring.delete(device.ieeeAddr); delete this.configureOnMessageAttempts[device.ieeeAddr]; device.save(); - this.info(`DeviceConfigure to V${device.meta.configured} for '${this.devLabel(device.ieeeAddr)}' successful.`); + this.info(`DeviceConfigure to V${device.meta.configured} for '${this.devLabel(device.ieeeAddr, mappedDevice.model)}' successful.`); return ''; } // https://github.com/Koenkk/zigbee2mqtt/issues/14857 @@ -224,22 +224,22 @@ class DeviceConfigure extends BaseExtension { com.timestamp = Date.now(); if ( com.count < 0) { delete this.configureOnMessageAttempts[device.ieeeAddr]; - this.info(`Configure on message abandoned for '${this.devLabel(device.ieeeAddr)}' after failing ${com.attempts} times.`) + this.info(`Configure on message abandoned for '${this.devLabel(device.ieeeAddr, mappedDevice.model)}' after failing ${com.attempts} times.`) } - else this.info(`Timeout trying to configure '${this.devLabel(device.ieeeAddr)}' (${com.count}).`) + else this.info(`Timeout trying to configure '${this.devLabel(device.ieeeAddr, mappedDevice.model)}' (${com.count}).`) } else { - this.info(`Timeout trying to configure '${this.devLabel(device.ieeeAddr)}' (starting CoM).`) + this.info(`Timeout trying to configure '${this.devLabel(device.ieeeAddr, mappedDevice.model)}' (starting CoM).`) this.configureOnMessageAttempts[device.ieeeAddr] = { count: 5, timestamp: 0, attempts: 0, }; } - return `Configuration timed out '${this.devLabel(device.ieeeAddr)}'. The device did not repond in time to the configuration request. Another attempt will be made when the device is awake.`; + return `Configuration timed out '${this.devLabel(device.ieeeAddr, mappedDevice.model)}'. The device did not repond in time to the configuration request. Another attempt will be made when the device is awake.`; } else { this.sendError(error); - const msg = `'${this.devLabel(device.ieeeAddr)}' Failed to configure. --> ${errmsg}${errmsg.includes(`UNSUPPORTED_CLUSTER`) ? ' - You may need to restart the adapter and reconfigure the device for this device to work properly' : ''}` + const msg = `'${this.devLabel(device.ieeeAddr, mappedDevice.model)}' Failed to configure. --> ${errmsg}${errmsg.includes(`UNSUPPORTED_CLUSTER`) ? ' - You may need to restart the adapter and reconfigure the device for this device to work properly' : ''}` this.warn(msg); return msg; diff --git a/lib/zbDeviceEvent.js b/lib/zbDeviceEvent.js index b403d8fb..df051c60 100644 --- a/lib/zbDeviceEvent.js +++ b/lib/zbDeviceEvent.js @@ -33,7 +33,7 @@ class DeviceEvent extends BaseExtension { } async deviceExposeChanged(device, mapped) { - this.warn(`deviceExposesChanged called with '${this.devLabel(device.ieeeAddr)}' / ${JSON.stringify(mapped.model)}`); + this.warn(`deviceExposesChanged called with '${this.devLabel(device.ieeeAddr, mapped.model)}' / ${JSON.stringify(mapped.model)}`); } async callOnEvent(device, type, data, mappedDevice) { diff --git a/lib/zigbeecontroller.js b/lib/zigbeecontroller.js index 94f15e1f..c0830ae4 100644 --- a/lib/zigbeecontroller.js +++ b/lib/zigbeecontroller.js @@ -323,7 +323,7 @@ class ZigbeeController extends EventEmitter { if (entity.mapped) { this.emit('new', entity); } - const msg = ("'" + this.devLabel(entity.device.ieeeAddr) + "'" + + const msg = ("'" + this.devLabel(entity.device.ieeeAddr, entity.mapped?.model) + "'" + ` (addr ${entity.device.networkAddress}): ` + (entity.mapped ? `${entity.mapped.model} - ${entity.mapped.vendor} ${entity.mapped.description} ` : `Unsupported (model ${entity.device.modelID})`) + `(${entity.device.type})`); @@ -529,9 +529,9 @@ class ZigbeeController extends EventEmitter { { const entity = await this.resolveEntity(devId); if (entity) try { - this.info(`manual Interview for '${this.devLabel(entity.device.ieeeAddr)}'`); + this.info(`manual Interview for '${this.devLabel(entity.device.ieeeAddr, entity.mapped?.model)}'`); await entity.device.interview(true); - this.info(`interview for '${this.devLabel(entity.device.ieeeAddr)}' complete`); + this.info(`interview for '${this.devLabel(entity.device.ieeeAddr, entity.mapped?.model)}' complete`); } catch (error) { return {error:`Interview failed ${entity.device.ieeeAddr} ${entity.device.modelID}, (${error.message})`} } @@ -1062,7 +1062,7 @@ class ZigbeeController extends EventEmitter { const entity = await this.resolveEntity(message.device || message.ieeeAddr); if (entity) { if (this.localConfig.getDeviceOption(entity.device.ieeeAddr, entity.mapped?.model, 'ignore_device_delete', true)) { - this.warn(`Ignoring device_leave message from '${this.devLabel(message.ieeeAddr)}' (${entity.device.modelID})`); + this.warn(`Ignoring device_leave message from '${this.devLabel(message.ieeeAddr, entity.mapped?.model)}' (${entity.device.modelID})`); return; } } @@ -1175,7 +1175,7 @@ class ZigbeeController extends EventEmitter { */ try { const entity = await this.resolveEntity(message.device || message.ieeeAddr); - const friendlyName = this.devLabel(entity.device.ieeeAddr); + const friendlyName = this.devLabel(entity.device.ieeeAddr, entity.mapped?.model); const onZigbeeEventparameters = [message, entity.mapped ? entity.mapped: null]; switch (message.status) { @@ -1392,7 +1392,7 @@ class ZigbeeController extends EventEmitter { return; } - if (this.debugActive) this.debug(`Zigbee publish to '${this.devLabel(deviceID)}', ${cid} - cmd ${cmd} - payload ${JSON.stringify(zclData)} - cfg ${JSON.stringify(cfg)} - endpoint ${ep}`); + if (this.debugActive) this.debug(`Zigbee publish to '${this.devLabel(deviceID, entity.mapped?.model)}', ${cid} - cmd ${cmd} - payload ${JSON.stringify(zclData)} - cfg ${JSON.stringify(cfg)} - endpoint ${ep}`); if (cfg == null) { cfg = {}; @@ -1463,24 +1463,24 @@ class ZigbeeController extends EventEmitter { if (has_elevated_debug) { const stateNames = stateList.map((state) => state.stateDesc.id); - const message = `Publishing to '${this.devLabel(deviceId)}' of model ${model} with ${stateNames.join(', ')}`; + const message = `Publishing to '${this.devLabel(deviceId, model)}' of model ${model} with ${stateNames.join(', ')}`; this.emit('device_debug', { ID:debugID, data: { ID: deviceId, flag: '03', IO:false }, message: message}); } else - if (this.debugActive) this.debug(`main publishFromState : '${this.devLabel(deviceId)}' ${model} ${safeJsonStringify(stateList)}`); + if (this.debugActive) this.debug(`main publishFromState : '${this.devLabel(deviceId, model)}' ${model} ${safeJsonStringify(stateList)}`); if (model === 'group') { isGroup = true; deviceId = parseInt(deviceId); } try { const entity = await this.resolveEntity(deviceId); - if (this.debugActive) this.debug(`entity: '${this.devLabel(deviceId)}' ${model} ${safeJsonStringify(utils.entityData(entity,{entity:true, device:true, model: true}))}))}`); + if (this.debugActive) this.debug(`entity: '${this.devLabel(deviceId, model)}' ${model} ${safeJsonStringify(utils.entityData(entity,{entity:true, device:true, model: true}))}))}`); const mappedModel = entity ? entity.mapped : undefined; if (!mappedModel) { if (this.debugActive) this.debug(`No mapped model for ${model}`); if (has_elevated_debug) { - const message=`No mapped model '${this.devLabel(deviceId)}' (model ${model})`; + const message=`No mapped model '${this.devLabel(deviceId, model)}' (model ${model})`; this.emit('device_debug', { ID:debugID, data: { error: 'NOMODEL' , IO:false }, message: message}); } return; @@ -1508,11 +1508,11 @@ class ZigbeeController extends EventEmitter { let msg_counter = 0; if (stateDesc.isOption) { if (has_elevated_debug) { - const message = `No converter needed on option state for '${this.devLabel(deviceId)}' of type ${model}`; + const message = `No converter needed on option state for '${this.devLabel(deviceId, model)}' of type ${model}`; this.emit('device_debug', { ID:debugID, data: { flag: `SUCCESS` , IO:false }, message:message}); } else - if (this.debugActive) this.debug(`No converter needed on option state for '${this.devLabel(deviceId)}' of type ${model}`); + if (this.debugActive) this.debug(`No converter needed on option state for '${this.devLabel(deviceId, model)}' of type ${model}`); continue; } @@ -1537,22 +1537,22 @@ class ZigbeeController extends EventEmitter { } converter = c; if (has_elevated_debug) { - const message = `Setting converter to keyless converter for '${this.devLabel(deviceId)}' of type ${model}`; + const message = `Setting converter to keyless converter for '${this.devLabel(deviceId, model)}' of type ${model}`; this.emit('device_debug', { ID:debugID, data: { flag: `s4.${msg_counter}` , IO:false }, message:message}); } else - if (this.debugActive) this.debug(`Setting converter to keyless converter for '${this.devLabel(deviceId)}' of type ${model}`); + if (this.debugActive) this.debug(`Setting converter to keyless converter for '${this.devLabel(deviceId, model)}' of type ${model}`); msg_counter++; } else { if (has_elevated_debug) { - const message = `ignoring keyless converter for '${this.devLabel(deviceId)}' of type ${model}`; + const message = `ignoring keyless converter for '${this.devLabel(deviceId, model)}' of type ${model}`; this.emit('device_debug', { ID:debugID, data: { flag: `i4.${msg_counter}` , IO:false} , message:message}); } else - if (this.debugActive) this.debug(`ignoring keyless converter for '${this.devLabel(deviceId)}' of type ${model}`); + if (this.debugActive) this.debug(`ignoring keyless converter for '${this.devLabel(deviceId, model)}' of type ${model}`); msg_counter++; } continue; @@ -1604,7 +1604,7 @@ class ZigbeeController extends EventEmitter { const epName = stateDesc.epname !== undefined ? stateDesc.epname : (stateDesc.prop || stateDesc.id); const key = stateDesc.setattr || stateDesc.prop || stateDesc.id; - const message = `convert ${key} with value ${safeJsonStringify(preparedValue)} and options ${safeJsonStringify(preparedOptions)} for device '${this.devLabel(deviceId)}' ${stateDesc.epname ? `with Endpoint ${epName}` : 'without Endpoint'}`; + const message = `convert ${key} with value ${safeJsonStringify(preparedValue)} and options ${safeJsonStringify(preparedOptions)} for device '${this.devLabel(deviceId, model)}' ${stateDesc.epname ? `with Endpoint ${epName}` : 'without Endpoint'}`; if (has_elevated_debug) { this.emit('device_debug', { ID:debugID, data: { flag: '04', payload: {key:key, ep: stateDesc.epname, value:preparedValue, options:preparedOptions}, IO:false }, message:message}); } @@ -1701,7 +1701,7 @@ class ZigbeeController extends EventEmitter { const fromObject = false; const preparedObject = null; //const { result, fromObject } = await this.getConverterValue(converter, target, key, preparedValue, preparedObject, meta); - const message = `convert result ${safeJsonStringify(result)} for device '${this.devLabel(deviceId)}'`; + const message = `convert result ${safeJsonStringify(result)} for device '${this.devLabel(deviceId, model)}'`; if (isGroup) this.emit('published', deviceId, model, stateModel, stateList, options, debugID, has_elevated_debug ); if (has_elevated_debug) { @@ -1719,7 +1719,7 @@ class ZigbeeController extends EventEmitter { else { if (has_elevated_debug) { const stringvalue = fromObject ? safeJsonStringify(preparedObject) : typeof preparedValue == 'object' ? safeJsonStringify(preparedValue) : preparedValue; - const message = `Convert does not return a result result for ${key} with ${stringvalue} on device '${this.devLabel(deviceId)}'.`; + const message = `Convert does not return a result result for ${key} with ${stringvalue} on device '${this.devLabel(deviceId, model)}'.`; this.emit('device_debug', { ID:debugID, data: { flag: `0${OCnt++}` , IO:false }, message:message}); } } @@ -1738,7 +1738,7 @@ class ZigbeeController extends EventEmitter { try { await c.convertGet(target, key, {device:entity.device}) } catch (error) { - this.warn(`error reading ${key} from '${this.devLabel(deviceId)}' : ${error?.message}`); + this.warn(`error reading ${key} from '${this.devLabel(deviceId, model)}' : ${error?.message}`); } }, tt ? tt * 1000+250 : 1000); } @@ -1746,11 +1746,11 @@ class ZigbeeController extends EventEmitter { } } catch (error) { if (has_elevated_debug) { - const message = `caught error ${error?.message ?? 'no reason given'} when setting value for device '${this.devLabel(deviceId)}' (${error?.stack ?? ''}).`; + const message = `caught error ${error?.message ?? 'no reason given'} when setting value for device '${this.devLabel(deviceId, model)}' (${error?.stack ?? ''}).`; this.emit('device_debug', { ID:debugID, data: { error: `EXSET${error.code == 25 ? retry : ''}` , IO:false },message:message}); } if (error.code === 25 && retry > 0) { - this.warn(`Error ${error.code} on send command to '${this.devLabel(deviceId)}'. (${retry} tries left.), Error: ${error.message}`); + this.warn(`Error ${error.code} on send command to '${this.devLabel(deviceId, model)}'. (${retry} tries left.), Error: ${error.message}`); retry--; await new Promise(resolve => setTimeout(resolve, 200)); } @@ -1758,7 +1758,7 @@ class ZigbeeController extends EventEmitter { retry = 0; // stash key: repeated send failures to the same device (e.g. while it // is unreachable) are counted instead of logged, until a send succeeds - this.adapter.filterError(`Error ${error.code} on send command to '${this.devLabel(deviceId)}'.` + + this.adapter.filterError(`Error ${error.code} on send command to '${this.devLabel(deviceId, model)}'.` + ` Error: ${error.message}`, `Send command to ${deviceId} failed with`, error, `send:${String(deviceId).replace('0x', '')}`); } } @@ -1769,7 +1769,7 @@ class ZigbeeController extends EventEmitter { } catch (err) { - const message = `No entity for '${this.devLabel(deviceId)}' : ${err && err.message ? err.message : 'no error message'}`; + const message = `No entity for '${this.devLabel(deviceId, model)}' : ${err && err.message ? err.message : 'no error message'}`; if (has_elevated_debug) { this.emit('device_debug', { ID:debugID, data: { error: 'EXPUB' , IO:false }, message:message}); } @@ -1872,8 +1872,9 @@ class ZigbeeController extends EventEmitter { } return {success: true}; } catch (error) { - this.error(`Error ${error.code} on send command to '${this.devLabel(payload.device)}'.` + ` Error: ${error.stack} ` + `Send command to '${this.devLabel(payload.device)}' failed with ` + error); - this.adapter.filterError(`Error ${error.code} on send command to '${this.devLabel(payload.device)}'.` + ` Error: ${error.stack}`, `Send command to '${this.devLabel(payload.device)}' failed with`, error); + // payloadObj, not payload: payload may be the raw JSON string (no .device) + this.error(`Error ${error.code} on send command to '${this.devLabel(payloadObj.device, mappedModel.model)}'.` + ` Error: ${error.stack} ` + `Send command to '${this.devLabel(payloadObj.device, mappedModel.model)}' failed with ` + error); + this.adapter.filterError(`Error ${error.code} on send command to '${this.devLabel(payloadObj.device, mappedModel.model)}'.` + ` Error: ${error.stack}`, `Send command to '${this.devLabel(payloadObj.device, mappedModel.model)}' failed with`, error); return {success: false, error}; } } catch (e) { @@ -1891,12 +1892,12 @@ class ZigbeeController extends EventEmitter { if (mappedModel) { const epmap = mappedModel.endpoint ? mappedModel.endpoint(entity.device) : []; if (elevated) { - const message = `Device query for '${this.devLabel(entity.device.ieeeAddr)}' triggered`; + const message = `Device query for '${this.devLabel(entity.device.ieeeAddr, mappedModel.model)}' triggered`; this.emit('device_debug', { ID:debugID, data: { flag: 'qs' ,states:[{id:'device_query', value:true, payload:'device_query'}], IO:false }, message:message}); } else - if (this.debugActive) this.debug(`Device query for '${this.devLabel(entity.device.ieeeAddr)}' started`); - else this.info(`Device query for '${this.devLabel(entity.device.ieeeAddr)}' started`); + if (this.debugActive) this.debug(`Device query for '${this.devLabel(entity.device.ieeeAddr, mappedModel.model)}' started`); + else this.info(`Device query for '${this.devLabel(entity.device.ieeeAddr, mappedModel.model)}' started`); const payload = { key:'device_query', read_states:[], unread_states:[] }; let cCount = 0; @@ -1920,12 +1921,12 @@ class ZigbeeController extends EventEmitter { await converter.convertGet(source, k, {device:entity.device}); payload.read_states.push(`${cCount}.${k}`); if (elevated) { - const message = `read for state ${k} of '${converter.key.join(',')}' of '${this.devLabel(entity.device.ieeeAddr)}/${source.ID}' after device query`; + const message = `read for state ${k} of '${converter.key.join(',')}' of '${this.devLabel(entity.device.ieeeAddr, mappedModel.model)}/${source.ID}' after device query`; this.warn(`ELEVATED O02.1 ${message}`); this.emit('device_debug', { ID:debugID, data: { flag: '03', IO:false }, message:message }); } else - this.debug(`read for state${converter.key.length ? '' : 's'} '${converter.key.join(',')}' of '${this.devLabel(entity.device.ieeeAddr)}/${source.ID}' after device query`); + this.debug(`read for state${converter.key.length ? '' : 's'} '${converter.key.join(',')}' of '${this.devLabel(entity.device.ieeeAddr, mappedModel.model)}/${source.ID}' after device query`); } catch (error) { payload.unread_states.push(`${cCount}.${k}`); if (elevated) { @@ -1940,11 +1941,11 @@ class ZigbeeController extends EventEmitter { } } if (elevated) { - const message = `ELEVATED O07: Device query for '${this.devLabel(entity.device.ieeeAddr)}}' complete`; + const message = `ELEVATED O07: Device query for '${this.devLabel(entity.device.ieeeAddr, mappedModel.model)}}' complete`; this.emit('device_debug', { ID:debugID, data: { flag: 'qe' , IO:false , payload }, message:message}); } else - this.info(`Device query for '${this.devLabel(entity.device.ieeeAddr)}' complete`); + this.info(`Device query for '${this.devLabel(entity.device.ieeeAddr, mappedModel.model)}' complete`); } } @@ -1982,18 +1983,18 @@ class ZigbeeController extends EventEmitter { if (this.debugActive) this.debug(`addDevToGroup ${groupId} with ${memberIDs.length} members ${safeJsonStringify(memberIDs)}`); if (epid != undefined) { for (const ep of entity.endpoints) { - if (this.debugActive) this.debug(`checking ep ${ep.ID} of '${this.devLabel(devId)}' (${epid})`); + if (this.debugActive) this.debug(`checking ep ${ep.ID} of '${this.devLabel(devId, entity.mapped?.model)}' (${epid})`); if (ep.ID == epid) { if (ep.inputClusters.includes(4) || ep.outputClusters.includes(4)) { if (this.debugActive) this.debug(`adding endpoint ${ep.ID} (${epid}) to group ${groupId}`); await (ep.addToGroup(group.mapped)); } - else this.error(`cluster genGroups not supported for endpoint ${epid} of '${this.devLabel(devId)}'`); + else this.error(`cluster genGroups not supported for endpoint ${epid} of '${this.devLabel(devId, entity.mapped?.model)}'`); } } } else { if (entity.endpoint.inputClusters.includes(4)) { - this.info(`adding endpoint ${entity.endpoint.ID} of '${this.devLabel(devId)}' to group`); + this.info(`adding endpoint ${entity.endpoint.ID} of '${this.devLabel(devId, entity.mapped?.model)}' to group`); await entity.endpoint.addToGroup(group.mapped); } else { let added = false; @@ -2027,26 +2028,26 @@ class ZigbeeController extends EventEmitter { if (group) { if (epid != undefined) { for (const ep of entity.endpoints) { - if (this.debugActive) this.debug(`checking ep ${ep.ID} of '${this.devLabel(devId)}' (${epid})`); + if (this.debugActive) this.debug(`checking ep ${ep.ID} of '${this.devLabel(devId, entity.mapped?.model)}' (${epid})`); if (ep.ID == epid && (ep.inputClusters.includes(4) || ep.outputClusters.includes(4))) { await ep.removeFromGroup(group); - this.info(`removing endpoint ${ep.ID} of '${this.devLabel(devId)}' from group ${groupId}`); + this.info(`removing endpoint ${ep.ID} of '${this.devLabel(devId, entity.mapped?.model)}' from group ${groupId}`); } } } else { await entity.endpoint.removeFromGroup(group); - this.info(`removing endpoint ${entity.endpoint.ID} of '${this.devLabel(devId)}' from group ${groupId}`); + this.info(`removing endpoint ${entity.endpoint.ID} of '${this.devLabel(devId, entity.mapped?.model)}' from group ${groupId}`); } } else { - const msg = `Unable to resolve group ${groupId} when removing '${this.devLabel(devId)}' (ep ${epid ? epid : (entity ? entity.endpoint.ID : '')}) from group` + const msg = `Unable to resolve group ${groupId} when removing '${this.devLabel(devId, entity.mapped?.model)}' (ep ${epid ? epid : (entity ? entity.endpoint.ID : '')}) from group` this.error(msg); return {error: msg}; } } catch (error) { this.sendError(error); - const msg = `Exception when trying remove '${this.devLabel(devId)}' (ep ${epid ? epid : (entity ? entity.endpoint.ID : '')}) from group '${this.devLabel(devId)}'` + const msg = `Exception when trying remove '${this.devLabel(devId, entity?.mapped?.model)}' (ep ${epid ? epid : (entity ? entity.endpoint.ID : '')}) from group ${groupId}` this.error(msg, error); return {error: msg}; } diff --git a/main.js b/main.js index 3b154925..51819a9f 100644 --- a/main.js +++ b/main.js @@ -773,17 +773,17 @@ class Zigbee extends adapterCore.Adapter { const model = (entity.mapped) ? entity.mapped.model : device.modelID; this.log.debug(`New device event: ${safeJsonStringify(utils.entityData(entity))}`); if (!entity.mapped && !entity.device.interviewing) { - const msg = `New device: '${devLabel(this, device.ieeeAddr)}' does not have a known model. please provide an external converter for '${device.modelID}'.`; + const msg = `New device: '${devLabel(this, device.ieeeAddr, model)}' does not have a known model. please provide an external converter for '${device.modelID}'.`; this.log.warn(msg); this.logToPairing(msg, true); } await this.stController.AddModelFromHerdsman(entity.device, model) if (device) { this.getObjectAsync(utils.zbIdorIeeetoAdId(this, device.ieeeAddr, false), (_err, obj) => { - if (!obj) this.logToPairing(`New device joined '${devLabel(this, device.ieeeAddr)}' model ${model}`, true); + if (!obj) this.logToPairing(`New device joined '${devLabel(this, device.ieeeAddr, model)}' model ${model}`, true); }); const model = (entity.mapped) ? entity.mapped.model : entity.device.modelID; - if (this.debugActive) this.log.debug(`new device '${devLabel(this, device.ieeeAddr)}' ${device.networkAddress} ${model} `); + if (this.debugActive) this.log.debug(`new device '${devLabel(this, device.ieeeAddr, model)}' ${device.networkAddress} ${model} `); await this.stController.updateDev(utils.zbIdorIeeetoAdId(this, device.ieeeAddr, false), entity.name, model); await this.stController.syncDevStates(device, model); } @@ -1121,7 +1121,7 @@ class Zigbee extends adapterCore.Adapter { return rv; } const dev = entity ? entity.device || {} : {} - const msg = entity ? `device '${devLabel(this, dev.ieeeAddr)}' (${dev.ieeeAddr}, NWK ${dev.networkAddres}, ID: ${dev.ID})` : 'undefined device'; + const msg = entity ? `device '${devLabel(this, dev.ieeeAddr, entity.mapped?.model)}' (${dev.ieeeAddr}, NWK ${dev.networkAddres}, ID: ${dev.ID})` : 'undefined device'; this.log.warn(`Error ${error && error.message ? error.message + ' ' : ''}building device info for ${msg}`); } return rv;