fix: deCONZ: support optional firmware debug logs

Currently only for ConBee III debug firmware.

Author: manup

src/adapter/deconz/adapter/deconzAdapter.ts

@@ -2,6 +2,7 @@
 
 //import Device from "../../../controller/model/device";
 import {existsSync, readFileSync} from "node:fs";
+import {dirname} from "node:path";
 import type * as Models from "../../../models";
 import type {Backup, UnifiedBackupStorage} from "../../../models";
 import {BackupUtils, Waitress} from "../../../utils";
@@ -45,7 +46,27 @@ export class DeconzAdapter extends Adapter {
 
         this.waitress = new Waitress<Events.ZclPayload, WaitressMatcher>(this.waitressValidator, this.waitressTimeoutFormatter);
 
-        this.driver = new Driver(serialPortOptions, networkOptions, this.getStoredBackup());
+        const firmwareLog = [];
+        if (backupPath) {
+            // optional: get extra logs from the firmware (debug builds)
+            const dirPath = dirname(backupPath);
+            const configPath = `${dirPath}/deconz_options.json`;
+            if (existsSync(configPath)) {
+                try {
+                    const data = JSON.parse(readFileSync(configPath).toString());
+                    const log = data.firmware_log || [];
+                    if (Array.isArray(log)) {
+                        for (const level of log) {
+                            if (level === "APS" || level === "APS_L2") {
+                                firmwareLog.push(level);
+                            }
+                        }
+                    }
+                } catch (_err) {}
+            }
+        }
+
+        this.driver = new Driver(serialPortOptions, networkOptions, this.getStoredBackup(), firmwareLog);
 
         this.driver.on("rxFrame", (frame) => processFrame(frame));
         this.openRequestsQueue = [];

src/adapter/deconz/driver/constants.ts

@@ -63,6 +63,7 @@ export enum FirmwareCommand {
     MacPollIndication = 0x1c,
     Reboot = 0x1e,
     Beacon = 0x1f,
+    DebugLog = 0x22,
 }
 
 export enum NetworkState {
@@ -107,6 +108,7 @@ export enum ParamId {
     STK_NWK_UPDATE_ID = 0x24,
     DEV_WATCHDOG_TTL = 0x26,
     STK_FRAME_COUNTER = 0x27,
+    STK_DEBUG_LOG_LEVEL = 0x29,
     // internal
     NONE = 0xff,
 }
@@ -136,6 +138,7 @@ export const stackParameters = [
     {id: ParamId.NWK_EXTENDED_PANID, type: DataType.U64},
     {id: ParamId.APS_CHANNEL_MASK, type: DataType.U32},
     {id: ParamId.STK_FRAME_COUNTER, type: DataType.U32},
+    {id: ParamId.STK_DEBUG_LOG_LEVEL, type: DataType.U32},
     {id: ParamId.APS_USE_EXTENDED_PANID, type: DataType.U64},
     {id: ParamId.APS_TRUST_CENTER_ADDRESS, type: DataType.U64},
 ];

src/adapter/deconz/driver/driver.ts

@@ -95,7 +95,7 @@ class Driver extends events.EventEmitter {
     private tickTimer: NodeJS.Timeout;
     private driverStateStart = 0;
     private driverState: DriverState = DriverState.Init;
-
+    private firmwareLog: string[];
     private transactionID = 0; // for APS and ZDO
     // in flight lockstep sending commands
     private txState: TxState = TxState.Idle;
@@ -118,13 +118,14 @@ class Driver extends events.EventEmitter {
     public paramFrameCounter = 0;
     public paramApsUseExtPanid = 0n;
 
-    public constructor(serialPortOptions: SerialPortOptions, networkOptions: NetworkOptions, backup: Backup | undefined) {
+    public constructor(serialPortOptions: SerialPortOptions, networkOptions: NetworkOptions, backup: Backup | undefined, firmwareLog: string[]) {
         super();
         this.seqNumber = 0;
         this.configChanged = 0;
         this.networkOptions = networkOptions;
         this.serialPortOptions = serialPortOptions;
         this.backup = backup;
+        this.firmwareLog = firmwareLog;
 
         this.writer = new Writer();
         this.parser = new Parser();
@@ -260,7 +261,7 @@ class Driver extends events.EventEmitter {
             }
         } else if (event === DriverEvent.Tick) {
             if (this.txState === TxState.WaitResponse) {
-                if (Date.now() - this.txTime > 1000) {
+                if (Date.now() - this.txTime > 2000) {
                     this.emitStateEvent(DriverEvent.FirmwareCommandTimeout);
                 }
             }
@@ -611,6 +612,16 @@ class Driver extends events.EventEmitter {
                             logger.debug("Zigbee configuration valid", NS);
                             this.driverStateStart = Date.now();
                             this.driverState = DriverState.Connected;
+
+                            // enable optional firmware debug messages
+                            let logLevel = 0;
+                            for (const level of this.firmwareLog) {
+                                if (level === "APS") logLevel |= 0x00000100;
+                                else if (level === "APS_L2") logLevel |= 0x00010000;
+                            }
+                            if (logLevel !== 0) {
+                                this.writeParameterRequest(ParamId.STK_DEBUG_LOG_LEVEL, logLevel);
+                            }
                         } else {
                             this.driverStateStart = Date.now();
                             this.driverState = DriverState.Reconfigure;
@@ -1176,7 +1187,8 @@ class Driver extends events.EventEmitter {
                 }
 
                 busyQueue.push(req);
-            } catch (_) {
+            } catch (err) {
+                console.error(err);
                 req.reject(new Error(`Failed to process request ${FirmwareCommand[req.commandId]}, seq: ${req.seqNumber}`));
             }
         }

src/adapter/deconz/driver/frameParser.ts

@@ -494,16 +494,50 @@ function parseGreenPowerDataIndication(view: DataView): GpDataInd | null {
 }
 function parseMacPollCommand(_view: DataView): number {
     //logger.debug("Received command MAC_POLL", NS);
-    return 28;
+    return FirmwareCommand.MacPollIndication;
 }
 function parseBeaconRequest(_view: DataView): number {
     logger.debug("Received Beacon Request", NS);
-    return 31;
+    return FirmwareCommand.Beacon;
+}
+
+function parseDebugLog(view: DataView): null {
+    let dbg = "";
+    const buf = new Buffalo(Buffer.from(view.buffer));
+
+    /* const commandId = */ buf.readUInt8();
+    /* const seqNr = */ buf.readUInt8();
+    const status = buf.readUInt8();
+
+    if (status !== CommandStatus.Success) {
+        // unlikely
+        return null;
+    }
+
+    /* const frameLength = */ buf.readUInt16();
+    const payloadLength = buf.readUInt16();
+
+    for (let i = 0; i < payloadLength && buf.isMore(); i++) {
+        const ch = buf.readUInt8();
+        if (ch >= 32 && ch <= 127) {
+            dbg += String.fromCharCode(ch);
+        }
+    }
+
+    if (dbg.length !== 0) {
+        logger.debug(`firmware log: ${dbg}`, NS);
+    }
+
+    return null;
 }
 
 function parseUnknownCommand(view: DataView): number {
     const id = view.getUint8(0);
-    logger.debug(`received unknown command - id ${id}`, NS);
+    if (id in FirmwareCommand) {
+        logger.debug(`received unsupported command: ${FirmwareCommand[id]} id: 0x${id.toString(16).padStart(2, "0")}`, NS);
+    } else {
+        logger.debug(`received unknown command: id: 0x${id.toString(16).padStart(2, "0")}`, NS);
+    }
     return id;
 }
 function getParserForCommandId(id: number): (view: DataView) => Command | object | number | null {
@@ -532,6 +566,8 @@ function getParserForCommandId(id: number): (view: DataView) => Command | object
             return parseMacPollCommand;
         case FirmwareCommand.Beacon:
             return parseBeaconRequest;
+        case FirmwareCommand.DebugLog:
+            return parseDebugLog;
         default:
             return parseUnknownCommand;
         //throw new Error(`unknown command id ${id}`);