From 353a0c9e8aa6f3e8487ef503910b459a4b492b85 Mon Sep 17 00:00:00 2001 From: Dominic Griesel Date: Tue, 31 Oct 2023 10:04:57 +0100 Subject: [PATCH 1/2] fix: reopen serial port if controller is missing ACKs after soft-reset --- packages/serial/src/SerialPortBindingMock.ts | 3 + packages/zwave-js/src/lib/driver/Driver.ts | 80 +++++++++++++------ .../lib/test/driver/unresponsiveStick.test.ts | 38 +++++++-- 3 files changed, 88 insertions(+), 33 deletions(-) diff --git a/packages/serial/src/SerialPortBindingMock.ts b/packages/serial/src/SerialPortBindingMock.ts index 343f8b8af46f..9c8a7d55f0f3 100644 --- a/packages/serial/src/SerialPortBindingMock.ts +++ b/packages/serial/src/SerialPortBindingMock.ts @@ -151,6 +151,7 @@ export const MockBinding: MockBindingInterface = { interface MockPortBindingEvents { write: (data: Buffer) => void; + close: () => void; } /** @@ -221,6 +222,8 @@ export class MockPortBinding extends TypedEventEmitter if (this.pendingRead) { this.pendingRead(new CanceledError("port is closed")); } + + this.emit("close"); } async read( diff --git a/packages/zwave-js/src/lib/driver/Driver.ts b/packages/zwave-js/src/lib/driver/Driver.ts index 756dbcc8c888..f2dacdff9704 100644 --- a/packages/zwave-js/src/lib/driver/Driver.ts +++ b/packages/zwave-js/src/lib/driver/Driver.ts @@ -513,7 +513,8 @@ type PrefixedNodeEvents = { const enum ControllerRecoveryPhase { None, - NoACK, + ACKTimeout, + ACKTimeoutAfterReset, CallbackTimeout, CallbackTimeoutAfterReset, } @@ -3529,46 +3530,73 @@ export class Driver extends TypedEventEmitter ): boolean { if (!this._controller) return false; - const fail = (message: string) => { - this.rejectTransaction(transaction, error); - void this.destroyWithMessage(message); + const recoverByReopeningSerialport = async () => { + if (!this.serial) return; + this.driverLog.print( + "Attempting to recover unresponsive controller by reopening the serial port...", + "warn", + ); + if (this.serial.isOpen) await this.serial.close(); + await wait(1000); + await this.openSerialport(); + + this.driverLog.print( + "Serial port reopened. Returning to normal operation and hoping for the best...", + "warn", + ); + + // We don't know if this worked + // Go back to normal operation and hope for the best. + this._controller?.setStatus(ControllerStatus.Ready); + this._recoveryPhase = ControllerRecoveryPhase.None; }; - if (this._controller.status !== ControllerStatus.Unresponsive) { + if ( + (this._controller.status !== ControllerStatus.Unresponsive + && !this.maySoftReset()) + || this._recoveryPhase + === ControllerRecoveryPhase.ACKTimeoutAfterReset + ) { + // Either we can/could not do a soft reset or the controller is still timing out afterwards + void recoverByReopeningSerialport().catch(noop); + + 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 = ControllerRecoveryPhase.NoACK; + this._recoveryPhase = ControllerRecoveryPhase.ACKTimeout; this.driverLog.print( - "Attempting to recover unresponsive controller...", + "Attempting to recover unresponsive controller by restarting it...", "warn", ); - // Re-queue the transaction. - // Its message generator may have finished, so reset that too. - transaction.reset(); - this.queue.add(transaction.clone()); - // Execute the soft-reset asynchronously void this.softReset().then(() => { // The controller responded. It is no longer unresponsive + + // Re-queue the transaction, so it can get handled next. + // Its message generator may have finished, so reset that too. + transaction.reset(); + this.queue.add(transaction.clone()); + this._controller?.setStatus(ControllerStatus.Ready); this._recoveryPhase = ControllerRecoveryPhase.None; }).catch(() => { - // Soft-reset failed. Reject the original transaction and try restarting the driver. - fail( - "Recovering unresponsive controller failed. Restarting the driver...", - ); + // Soft-reset failed. Reject the transaction + this.rejectTransaction(transaction, error); + + // and reopen the serial port + return recoverByReopeningSerialport(); }); return true; } else { - // We already attempted to recover from an unresponsive controller. - // Ending up here means the soft-reset also failed and the driver is about to be destroyed + // Not sure what to do here return false; } } @@ -3661,20 +3689,20 @@ export class Driver extends TypedEventEmitter "warn", ); - // Re-queue the transaction. - // Its message generator may have finished, so reset that too. - transaction.reset(); - this.queue.add(transaction.clone()); - // Execute the soft-reset asynchronously void this.softReset().then(() => { - // The controller responded. It is no longer unresponsive - this._controller?.setStatus(ControllerStatus.Ready); + // The controller responded. It is no longer unresponsive. + // Re-queue the transaction, so it can get handled next. + // Its message generator may have finished, so reset that too. + transaction.reset(); + this.queue.add(transaction.clone()); + + this._controller?.setStatus(ControllerStatus.Ready); this._recoveryPhase = ControllerRecoveryPhase.CallbackTimeoutAfterReset; }).catch(() => { - // Soft-reset failed. Just reject the original transaction. + // Soft-reset failed. Just reject the transaction this.rejectTransaction(transaction, error); this.driverLog.print( diff --git a/packages/zwave-js/src/lib/test/driver/unresponsiveStick.test.ts b/packages/zwave-js/src/lib/test/driver/unresponsiveStick.test.ts index 3d95d6dd6f62..764cca027461 100644 --- a/packages/zwave-js/src/lib/test/driver/unresponsiveStick.test.ts +++ b/packages/zwave-js/src/lib/test/driver/unresponsiveStick.test.ts @@ -55,10 +55,16 @@ integrationTest( ); integrationTest( - "When the controller is still unresponsive after soft reset, destroy the driver", + "When the controller is still unresponsive after soft reset, re-open the serial port", { // debug: true, + additionalDriverOptions: { + testingHooks: { + skipNodeInterview: true, + }, + }, + async customSetup(driver, mockController, mockNode) { const doNotRespond: MockControllerBehavior = { onHostMessage(host, controller, msg) { @@ -74,8 +80,13 @@ integrationTest( shouldRespond = false; mockController.autoAckHostMessages = false; - const errorSpy = Sinon.spy(); - driver.on("error", errorSpy); + const serialPortCloseSpy = Sinon.stub().callsFake(() => { + shouldRespond = true; + mockController.autoAckHostMessages = true; + }); + mockController.serial.on("close", serialPortCloseSpy); + + await wait(1000); await assertZWaveError( t, @@ -90,11 +101,24 @@ integrationTest( }, ); - // The driver should have been destroyed + // The serial port should have been closed and reopened await wait(100); - assertZWaveError(t, errorSpy.getCall(0).args[0], { - errorCode: ZWaveErrorCodes.Driver_Failed, - }); + t.true(serialPortCloseSpy.called); + + // FIXME: When closing the serial port, we lose the connection between the mock port instance and the controller + // Fix it at some point, then enable the below test. + + // await wait(1000); + + // // Sending a command should work again, assuming the controller is responsive again + // await t.notThrowsAsync(() => + // driver.sendMessage( + // new GetControllerIdRequest(driver), + // { supportCheck: false }, + // ) + // ); + + // driver.driverLog.print("TEST PASSED"); }, }, ); From fcd38f2eb27011d2f6864000986789b3bd154495 Mon Sep 17 00:00:00 2001 From: Dominic Griesel Date: Tue, 31 Oct 2023 10:10:33 +0100 Subject: [PATCH 2/2] fix: speed up test --- .../zwave-js/src/lib/test/driver/unresponsiveStick.test.ts | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/packages/zwave-js/src/lib/test/driver/unresponsiveStick.test.ts b/packages/zwave-js/src/lib/test/driver/unresponsiveStick.test.ts index 764cca027461..5b7707ca7abd 100644 --- a/packages/zwave-js/src/lib/test/driver/unresponsiveStick.test.ts +++ b/packages/zwave-js/src/lib/test/driver/unresponsiveStick.test.ts @@ -63,6 +63,10 @@ integrationTest( testingHooks: { skipNodeInterview: true, }, + attempts: { + // Spend less time waiting + controller: 1, + }, }, async customSetup(driver, mockController, mockNode) {