Skip to content

Commit

Permalink
fix: Ember: fixed logging levels (#1006)
Browse files Browse the repository at this point in the history
  • Loading branch information
@Nerivec
Nerivec authored Apr 4, 2024
1 parent 66e333d commit 8a6bba8
Show file tree
Hide file tree
Showing 3 changed files with 56 additions and 50 deletions.
90 changes: 51 additions & 39 deletions src/adapter/ember/adapter/emberAdapter.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -492,20 +492,24 @@ export class EmberAdapter extends Adapter {
}
case EmberStatus.NETWORK_OPENED: {
this.oneWaitress.resolveEvent(OneWaitressEvents.STACK_STATUS_NETWORK_OPENED);
this.requestQueue.enqueue(
async (): Promise<EmberStatus> => {
const setJPstatus = (await this.emberSetJoinPolicy(EmberJoinDecision.USE_PRECONFIGURED_KEY));

if (setJPstatus !== EzspStatus.SUCCESS) {
logger.error(`[ZDO] Failed set join policy with status=${EzspStatus[setJPstatus]}.`, NS);
return EmberStatus.ERR_FATAL;
}
await new Promise<void>((resolve, reject): void => {
this.requestQueue.enqueue(
async (): Promise<EmberStatus> => {
const setJPstatus = (await this.emberSetJoinPolicy(EmberJoinDecision.USE_PRECONFIGURED_KEY));

return EmberStatus.SUCCESS;
},
(e) => logger.error(e, NS),// no reject, just log error if any
true,// prioritize just to avoid delays if queue is busy
);
if (setJPstatus !== EzspStatus.SUCCESS) {
logger.error(`[ZDO] Failed set join policy with status=${EzspStatus[setJPstatus]}.`, NS);
return EmberStatus.ERR_FATAL;
}

resolve();
return EmberStatus.SUCCESS;
},
reject,
true,/*prioritize*/
);
});
logger.info(`[STACK STATUS] Network opened.`, NS);
break;
}
Expand Down Expand Up @@ -546,7 +550,7 @@ export class EmberAdapter extends Adapter {
case EmberOutgoingMessageType.MULTICAST_WITH_ALIAS: {
// BC/MC not checking for message sent, avoid unnecessary waitress lookups
logger.error(`Delivery of ${EmberOutgoingMessageType[type]} failed for "${indexOrDestination}" `
+ `[apsFrame=${JSON.stringify(apsFrame)} messageTag=${messageTag}]`, NS);
+ `[apsFrame=${JSON.stringify(apsFrame)} messageTag=${messageTag}]`, NS);
break;
}
default: {
Expand Down Expand Up @@ -727,19 +731,22 @@ export class EmberAdapter extends Adapter {
const joinManufCode = WORKAROUND_JOIN_MANUF_IEEE_PREFIX_TO_CODE[newNodeEui64.substring(0, 8)] ?? DEFAULT_MANUFACTURER_CODE;

if (this.manufacturerCode !== joinManufCode) {
this.requestQueue.enqueue(
async (): Promise<EmberStatus> => {
logger.debug(`[WORKAROUND] Setting coordinator manufacturer code to ${ManufacturerCode[joinManufCode]}.`, NS);
await this.ezsp.ezspSetManufacturerCode(joinManufCode);
await new Promise<void>((resolve, reject): void => {
this.requestQueue.enqueue(
async (): Promise<EmberStatus> => {
logger.debug(`[WORKAROUND] Setting coordinator manufacturer code to ${ManufacturerCode[joinManufCode]}.`, NS);
await this.ezsp.ezspSetManufacturerCode(joinManufCode);

this.manufacturerCode = joinManufCode;
this.manufacturerCode = joinManufCode;

this.emit(Events.deviceJoined, payload);
return EmberStatus.SUCCESS;
},
(e) => logger.error(e, NS),// no reject, just log error if any
true,// prioritize just to avoid delays if queue is busy
);
this.emit(Events.deviceJoined, payload);
resolve();
return EmberStatus.SUCCESS;
},
reject,
true,/*prioritize*/
);
});
} else {
this.emit(Events.deviceJoined, payload);
}
Expand All @@ -750,17 +757,20 @@ export class EmberAdapter extends Adapter {
}

private async watchdogCounters(): Promise<void> {
this.requestQueue.enqueue(
async (): Promise<EmberStatus> => {
// listed as per EmberCounterType
const counters = (await this.ezsp.ezspReadAndClearCounters());
await new Promise<void>((resolve, reject): void => {
this.requestQueue.enqueue(
async (): Promise<EmberStatus> => {
// listed as per EmberCounterType
const counters = (await this.ezsp.ezspReadAndClearCounters());

logger.info(`[NCP COUNTERS] ${counters.join(',')}`, NS);
logger.info(`[NCP COUNTERS] ${counters.join(',')}`, NS);

return EmberStatus.SUCCESS;
},
(e) => logger.error(e, NS), // no reject, just log error if any
);
resolve();
return EmberStatus.SUCCESS;
},
reject,
);
});
}

private initVariables(): void {
Expand Down Expand Up @@ -1432,7 +1442,7 @@ export class EmberAdapter extends Adapter {
}
}

logger.debug(`[BACKUP] Imported ${backupData.length} keys.`, NS);
logger.info(`[BACKUP] Imported ${backupData.length} keys.`, NS);
}

/**
Expand Down Expand Up @@ -1701,8 +1711,11 @@ export class EmberAdapter extends Adapter {
// can be ZLL where not all NCPs need or support it.
logger.warning(`[EzspConfigId] Unsupported configuration ID ${EzspConfigId[configId]} by NCP.`, NS);
} else if (status !== EzspStatus.SUCCESS) {
// don't fail in case a set value gets called "out of time"
logger.error(`[EzspConfigId] Failed to SET "${EzspConfigId[configId]}" TO "${value}" with status=${EzspStatus[status]}.`, NS);
logger.warning(
`[EzspConfigId] Failed to SET "${EzspConfigId[configId]}" TO "${value}" with status=${EzspStatus[status]}. `
+ `Firmware value will be used instead.`,
NS,
);
}

return status;
Expand Down Expand Up @@ -2364,7 +2377,7 @@ export class EmberAdapter extends Adapter {
: Promise<[EmberStatus, apsFrame: EmberApsFrame, messageTag: number]> {
logger.debug(
`~~~> [ZDO UNBIND_REQUEST target=${target} source=${source} sourceEndpoint=${sourceEndpoint} clusterId=${clusterId} type=${type} `
+ `destination=${destination} groupAddress=${groupAddress} destinationEndpoint=${destinationEndpoint}]`,
+ `destination=${destination} groupAddress=${groupAddress} destinationEndpoint=${destinationEndpoint}]`,
NS,
);
return this.emberSendZigDevBindRequest(
Expand Down Expand Up @@ -2767,7 +2780,6 @@ export class EmberAdapter extends Adapter {
// this.ezsp,
// Buffer.from(this.networkCache.eui64.substring(2/*0x*/), 'hex').reverse()
// ));
// logger.info(tokensBuf.toString('hex'), NS);

let context: SecManContext = initSecurityManagerContext();
context.coreKeyType = SecManKeyType.TC_LINK;
Expand Down Expand Up @@ -2825,7 +2837,7 @@ export class EmberAdapter extends Adapter {
return EmberStatus.SUCCESS;
},
reject,
true,// takes prio
true,/*prioritize*/
);
});

Expand Down
3 changes: 1 addition & 2 deletions src/adapter/ember/ezsp/ezsp.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -5061,7 +5061,7 @@ export class Ezsp extends EventEmitter {
*/
ezspIdConflictHandler(id: EmberNodeId): void {
logger.debug(`ezspIdConflictHandler(): callback called with: [id=${id}]`, NS);
logger.error(`An ID conflict was detected for network address "${id}". Corresponding devices removed from the network.`, NS);
logger.warning(`An ID conflict was detected for network address "${id}". Corresponding devices kicked from the network.`, NS);

// XXX: this is currently causing more problems than not doing it, so disabled for now.
// devices should rejoin on ID conflict anyway, so the database isn't out of sync for very long.
Expand Down Expand Up @@ -6814,7 +6814,6 @@ export class Ezsp extends EventEmitter {
ezspMfglibRxHandler(linkQuality: number, rssi: number, packetLength: number, packetContents: number[]): void {
logger.debug(`ezspMfglibRxHandler(): callback called with: [linkQuality=${linkQuality}], [rssi=${rssi}], `
+ `[packetLength=${packetLength}], [packetContents=${packetContents}]`, NS);
// gecko_sdk_4.4.0\protocol\zigbee\app\framework\plugin\manufacturing-library-cli\manufacturing-library-cli-host.c
}

//-----------------------------------------------------------------------------
Expand Down
13 changes: 4 additions & 9 deletions src/adapter/ember/uart/ash.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -490,7 +490,7 @@ export class UartAsh extends EventEmitter {

// enable software flow control if RTS/CTS not enabled in config
if (!serialOpts.rtscts) {
logger.debug(`RTS/CTS config is off, enabling software flow control.`, NS);
logger.info(`RTS/CTS config is off, enabling software flow control.`, NS);
serialOpts.xon = true;
serialOpts.xoff = true;
}
Expand All @@ -513,7 +513,7 @@ export class UartAsh extends EventEmitter {

try {
await this.serialPort.asyncOpen();
logger.debug(`Serial port opened: ${JSON.stringify(await this.serialPort.asyncGet())}`, NS);
logger.info(`Serial port opened`, NS);

this.serialPort.once('close', this.onPortClose.bind(this));
this.serialPort.on('error', this.onPortError.bind(this));
Expand Down Expand Up @@ -545,10 +545,10 @@ export class UartAsh extends EventEmitter {
};

this.socketPort.on('connect', () => {
logger.debug('Socket connected', NS);
logger.debug(`Socket connected`, NS);
});
this.socketPort.on('ready', async (): Promise<void> => {
logger.debug('Socket ready', NS);
logger.info(`Socket ready`, NS);
this.socketPort.removeListener('error', openError);
this.socketPort.once('close', this.onPortClose.bind(this));
this.socketPort.on('error', this.onPortError.bind(this));
Expand Down Expand Up @@ -686,8 +686,6 @@ export class UartAsh extends EventEmitter {
if (this.serialPort?.isOpen) {
try {
await this.serialPort.asyncFlushAndClose();

logger.debug(`Serial port closed.`, NS);
} catch (err) {
logger.error(`Failed to close serial port ${err}.`, NS);
}
Expand All @@ -696,8 +694,6 @@ export class UartAsh extends EventEmitter {
} else if (this.socketPort != null && !this.socketPort.closed) {
this.socketPort.destroy();
this.socketPort.removeAllListeners();

logger.debug(`Socket port closed.`, NS);
}
}

Expand Down Expand Up @@ -1374,7 +1370,6 @@ export class UartAsh extends EventEmitter {
this.flags &= ~Flag.NR;

this.stopNrTimer(); // needed??
// logger.debug(`READY - Signaling NCP`, NS);// spams-a-lot
}

// Force an ACK (or possibly NAK) if we need to send an updated nFlag
Expand Down

0 comments on commit 8a6bba8

Please sign in to comment.