fix: attempt soft-resetting controller when callback times out (#6296)

.eslintrc.js

@@ -164,7 +164,7 @@ module.exports = {
 				"@typescript-eslint/no-floating-promises": "off",
 				"@typescript-eslint/require-await": "off",
 				"@typescript-eslint/unbound-method": "off",
-				"@typescript-eslint/no-unused-vars": "warn",
+				"@typescript-eslint/no-unused-vars": "off",
 				"@typescript-eslint/dot-notation": "off",
 
 				"@zwave-js/no-debug-in-tests": "error",

packages/core/src/error/ZWaveError.ts

@@ -285,3 +285,11 @@ export function isMissingControllerACK(
 		&& e.code === ZWaveErrorCodes.Controller_Timeout
 		&& e.context === "ACK";
 }
+
+export function isMissingControllerCallback(
+	e: unknown,
+): e is ZWaveError {
+	return isZWaveError(e)
+		&& e.code === ZWaveErrorCodes.Controller_Timeout
+		&& e.context === "callback";
+}

packages/eslint-plugin/src/rules/no-debug-in-tests.ts

@@ -2,6 +2,8 @@ import { AST_NODE_TYPES, ESLintUtils } from "@typescript-eslint/utils";
 import path from "node:path";
 import { repoRoot } from "../utils.js";
 
+const isFixMode = process.argv.some((arg) => arg.startsWith("--fix"));
+
 const integrationTestDefinitionFiles = new Set(
 	[
 		"packages/zwave-js/src/lib/test/integrationTestSuite",
@@ -57,7 +59,10 @@ export const noDebugInTests = ESLintUtils.RuleCreator.withoutDocs({
 					context.report({
 						node,
 						messageId: "no-debug",
-						fix: (fixer) => fixer.insertTextBefore(node, "// "),
+						// Do not auto-fix in the editor
+						fix: isFixMode
+							? (fixer) => fixer.insertTextBefore(node, "// ")
+							: undefined,
 					});
 				}
 			},
@@ -69,7 +74,8 @@ export const noDebugInTests = ESLintUtils.RuleCreator.withoutDocs({
 				"Integration tests should have the `debug` flag set to `false` when not actively debugging.",
 		},
 		type: "problem",
-		fixable: "code",
+		// Do not auto-fix in the editor
+		fixable: isFixMode ? "code" : undefined,
 		schema: [],
 		messages: {
 			"no-debug":

packages/zwave-js/src/lib/driver/Driver.ts

@@ -85,6 +85,7 @@ import {
 	getCCName,
 	highResTimestamp,
 	isMissingControllerACK,
+	isMissingControllerCallback,
 	isZWaveError,
 	messageRecordToLines,
 	securityClassIsS2,
@@ -466,6 +467,13 @@ type PrefixedNodeEvents = {
 	]: ZWaveNodeEventCallbacks[K];
 };
 
+const enum ControllerRecoveryPhase {
+	None,
+	NoACK,
+	CallbackTimeout,
+	CallbackTimeoutAfterReset,
+}
+
 // Strongly type the event emitter events
 export interface DriverEventCallbacks extends PrefixedNodeEvents {
 	"driver ready": () => void;
@@ -538,9 +546,12 @@ export class Driver extends TypedEventEmitter<DriverEventCallbacks>
 		this.immediateQueue = new TransactionQueue({
 			name: "immediate",
 			mayStartNextTransaction: (t) => {
-				// While the controller is unresponsive, only soft resetting is allowed
+				// While the controller is unresponsive, only soft resetting is allowed.
+				// Since we use GetControllerVersionRequest to check if the controller responds after soft-reset,
+				// allow that too.
 				if (this.controller.status === ControllerStatus.Unresponsive) {
-					return t.message instanceof SoftResetRequest;
+					return t.message instanceof SoftResetRequest
+						|| t.message instanceof GetControllerVersionRequest;
 				}
 
 				// All other messages on the immediate queue may always be sent as long as the controller is ready to send
@@ -693,6 +704,9 @@ export class Driver extends TypedEventEmitter<DriverEventCallbacks>
 		return this._bootloader != undefined;
 	}
 
+	private _recoveryPhase: ControllerRecoveryPhase =
+		ControllerRecoveryPhase.None;
+
 	private _securityManager: SecurityManager | undefined;
 	/**
 	 * **!!! INTERNAL !!!**
@@ -1021,16 +1035,9 @@ export class Driver extends TypedEventEmitter<DriverEventCallbacks>
 					return;
 				}
 
-				const message = `Serial port errored: ${err.message}`;
-				this.driverLog.print(message, "error");
-
-				const error = new ZWaveError(
-					message,
-					ZWaveErrorCodes.Driver_Failed,
+				void this.destroyWithMessage(
+					`Serial port errored: ${err.message}`,
 				);
-				this.emit("error", error);
-
-				void this.destroy();
 			});
 		// If the port is already open, close it first
 		if (this.serial.isOpen) await this.serial.close();
@@ -1097,17 +1104,9 @@ export class Driver extends TypedEventEmitter<DriverEventCallbacks>
 							this._controller = new ZWaveController(this, true);
 							this.emit("bootloader ready");
 						} else {
-							const message =
-								"Failed to recover from bootloader. Please flash a new firmware to continue...";
-							this.driverLog.print(message, "error");
-							this.emit(
-								"error",
-								new ZWaveError(
-									message,
-									ZWaveErrorCodes.Driver_Failed,
-								),
+							void this.destroyWithMessage(
+								"Failed to recover from bootloader. Please flash a new firmware to continue...",
 							);
-							void this.destroy();
 						}
 
 						return;
@@ -1131,12 +1130,8 @@ export class Driver extends TypedEventEmitter<DriverEventCallbacks>
 					message =
 						`Failed to create the cache directory. Please make sure that it is writable or change the location with the "storage.cacheDir" driver option.`;
 				}
-				this.driverLog.print(message, "error");
-				this.emit(
-					"error",
-					new ZWaveError(message, ZWaveErrorCodes.Driver_Failed),
-				);
-				void this.destroy();
+
+				void this.destroyWithMessage(message);
 				return;
 			}
 
@@ -1151,12 +1146,7 @@ export class Driver extends TypedEventEmitter<DriverEventCallbacks>
 							e,
 						)
 					}`;
-					this.driverLog.print(message, "error");
-					this.emit(
-						"error",
-						new ZWaveError(message, ZWaveErrorCodes.Driver_Failed),
-					);
-					void this.destroy();
+					void this.destroyWithMessage(message);
 					return;
 				}
 			}
@@ -2764,6 +2754,18 @@ export class Driver extends TypedEventEmitter<DriverEventCallbacks>
 		);
 	}
 
+	private async destroyWithMessage(message: string): Promise<void> {
+		this.driverLog.print(message, "error");
+
+		const error = new ZWaveError(
+			message,
+			ZWaveErrorCodes.Driver_Failed,
+		);
+		this.emit("error", error);
+
+		await this.destroy();
+	}
+
 	/**
 	 * Terminates the driver instance and closes the underlying serial connection.
 	 * Must be called under any circumstances.
@@ -3461,27 +3463,38 @@ export class Driver extends TypedEventEmitter<DriverEventCallbacks>
 		}
 	}
 
-	private handleMissingControllerACK(
+	private handleUnresponsiveController(
 		transaction: Transaction,
 		error: ZWaveError,
 	): boolean {
 		if (!this._controller) return false;
 
-		const fail = () => {
-			this.driverLog.print(
-				"Recovering unresponsive controller failed. Restarting the driver...",
-				"error",
-			);
-			void this.destroy();
+		const fail = (message: string) => {
+			this.rejectTransaction(transaction, error);
+
+			void this.destroyWithMessage(message);
 		};
 
-		if (this._controller.status !== ControllerStatus.Unresponsive) {
+		if (
+			this._recoveryPhase
+				=== ControllerRecoveryPhase.CallbackTimeoutAfterReset
+		) {
+			// The controller is still timing out transmitting after a soft reset, don't try again.
+			// Reject the transaction and destroy the driver.
+			fail("Controller is still timing out. Restarting the driver...");
+
+			return true;
+		} else if (this._controller.status !== ControllerStatus.Unresponsive) {
 			// The controller was responsive before this transaction failed.
 			// Mark it as unresponsive and try to soft-reset it.
 			this.controller.setStatus(
 				ControllerStatus.Unresponsive,
 			);
 
+			this._recoveryPhase = isMissingControllerACK(error)
+				? ControllerRecoveryPhase.NoACK
+				: ControllerRecoveryPhase.CallbackTimeout;
+
 			this.driverLog.print(
 				"Attempting to recover unresponsive controller...",
 				"warn",
@@ -3496,11 +3509,21 @@ export class Driver extends TypedEventEmitter<DriverEventCallbacks>
 			void this.softReset().then(() => {
 				// The controller responded. It is no longer unresponsive
 				this._controller?.setStatus(ControllerStatus.Ready);
+
+				if (this._recoveryPhase === ControllerRecoveryPhase.NoACK) {
+					this._recoveryPhase = ControllerRecoveryPhase.None;
+				} else if (
+					this._recoveryPhase
+						=== ControllerRecoveryPhase.CallbackTimeout
+				) {
+					this._recoveryPhase =
+						ControllerRecoveryPhase.CallbackTimeoutAfterReset;
+				}
 			}).catch(() => {
-				// Soft-reset failed.
-				// Reject the original transaction and try restarting the driver.
-				this.rejectTransaction(transaction, error);
-				fail();
+				// Soft-reset failed. Reject the original transaction and try restarting the driver.
+				fail(
+					"Recovering unresponsive controller failed. Restarting the driver...",
+				);
 			});
 
 			return true;
@@ -5487,9 +5510,10 @@ ${handlers.length} left`,
 		// If a node failed to respond in time, it might be sleeping
 		if (this.isMissingNodeACK(transaction, error)) {
 			if (this.handleMissingNodeACK(transaction as any, error)) return;
-		} else if (isMissingControllerACK(error)) {
-			// If the controller failed to respond in time, we attempt to recover from this
-			if (this.handleMissingControllerACK(transaction, error)) return;
+		} else if (
+			isMissingControllerACK(error) || isMissingControllerCallback(error)
+		) {
+			if (this.handleUnresponsiveController(transaction, error)) return;
 		}
 
 		this.rejectTransaction(transaction, error);

packages/zwave-js/src/lib/test/cc-specific/notificationEnums.test.ts

@@ -7,10 +7,10 @@ import { createMockZWaveRequestFrame } from "@zwave-js/testing";
 import { wait } from "alcalzone-shared/async";
 import { integrationTest } from "../integrationTestSuite";
 
-integrationTest.only(
+integrationTest(
 	"Notifications with enum event parameters are evaluated correctly",
 	{
-		debug: true,
+		// debug: true,
 
 		nodeCapabilities: {
 			commandClasses: [

packages/zwave-js/src/lib/test/driver/controllerJammed.test.ts

@@ -85,7 +85,7 @@ integrationTest("update the controller status and wait if TX status is Fail", {
 
 					return true;
 				} else if (msg instanceof SendDataAbort) {
-					// Put the controller into sending state
+					// Put the controller into idle state
 					controller.state.set(
 						MockControllerStateKeys.CommunicationState,
 						MockControllerCommunicationState.Idle,

packages/zwave-js/src/lib/test/driver/nodeAsleepMessageOrder.test.ts

@@ -108,10 +108,10 @@ integrationTest(
 	},
 );
 
-integrationTest.only(
+integrationTest(
 	"When a sleeping node with pending commands wakes up, the queue continues executing",
 	{
-		debug: true,
+		// debug: true,
 
 		provisioningDirectory: path.join(
 			__dirname,