Skip to content

Commit

Permalink
feat: prevent flooding the logs with errors on state polling
Browse files Browse the repository at this point in the history
  • Loading branch information
jvandenaardweg committed Dec 20, 2024
1 parent b4d54af commit 1e3d889
Show file tree
Hide file tree
Showing 2 changed files with 89 additions and 9 deletions.
80 changes: 80 additions & 0 deletions src/energy-socket-accessory.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ import { mockIdentifyResponse } from './api/mocks/data/identify';
import { mockStateResponse } from './api/mocks/data/state';
import { EnergySocketAccessory } from './energy-socket-accessory';
import { accessoryMock, platformMock } from './mocks/platform';
import { SHOW_POLLING_ERRORS_INTERVAL } from './settings';

let mockApiAgent: MockAgent;
let mockApiPool: Interceptable;
Expand Down Expand Up @@ -277,4 +278,83 @@ describe('EnergySocketAccessory', () => {
// Verify no more polls occurred after stopping
expect(getStateSpy).not.toHaveBeenCalled();
});

// ... existing imports ...

it('should handle polling errors according to interval', async () => {
const logErrorSpy = vi.spyOn(platformMock.log, 'error');

// Mock API to always throw an error
mockApiPool
.intercept({
path: `/api/v1/state`,
method: 'GET',
})
.reply(() => {
throw new Error('Polling failed');
});

const energySocketAccessory = new EnergySocketAccessory(platformMock, accessoryMock, mockApi);

expect(energySocketAccessory).toBeDefined();

// First poll should log error
await vi.advanceTimersByTimeAsync(999); // 999 because of the first poll on the constructor, if we do 1000 it's already on the second poll

expect(logErrorSpy).toHaveBeenCalledTimes(1);
expect(logErrorSpy).toHaveBeenLastCalledWith(
'[Energy Socket: HWE-SKT 1234567890] -> ',
'Error polling state:',
expect.any(Error),
);

expect(energySocketAccessory.statePollingErrorCount).toBe(1);
expect(logErrorSpy).toHaveBeenCalledTimes(1);

// Fast forward to the next poll
await vi.advanceTimersByTimeAsync(1);

expect(energySocketAccessory.statePollingErrorCount).toBe(2);

// Count should be updated, but logger should not have been called again
expect(logErrorSpy).toHaveBeenCalledTimes(1);

await vi.advanceTimersByTimeAsync(1000);

expect(energySocketAccessory.statePollingErrorCount).toBe(3);

// Count should be updated, but logger should not have been called again
expect(logErrorSpy).toHaveBeenCalledTimes(1);

// Set the error count to the interval
energySocketAccessory.statePollingErrorCount = SHOW_POLLING_ERRORS_INTERVAL;

await vi.advanceTimersByTimeAsync(1000);

// The logger should now have been called again and display the total errors
expect(logErrorSpy).toHaveBeenCalledTimes(2);
expect(logErrorSpy).toHaveBeenLastCalledWith(
'[Energy Socket: HWE-SKT 1234567890] -> ',
'Error polling state: Total errors: 901',
expect.any(Error),
);

// The error count should be reset to 0, since we've reached the interval
expect(energySocketAccessory.statePollingErrorCount).toBe(0);

await vi.advanceTimersByTimeAsync(1000);

expect(logErrorSpy).toHaveBeenCalledTimes(3);
expect(logErrorSpy).toHaveBeenLastCalledWith(
'[Energy Socket: HWE-SKT 1234567890] -> ',
'Error polling state:',
expect.any(Error),
);

// Fast forward to the next poll
await vi.advanceTimersByTimeAsync(1000);

// Should not have been called again
expect(logErrorSpy).toHaveBeenCalledTimes(3);
});
});
18 changes: 9 additions & 9 deletions src/energy-socket-accessory.ts
Original file line number Diff line number Diff line change
Expand Up @@ -35,7 +35,7 @@ export class EnergySocketAccessory {
longPollErrorCount = 0;
longPollCrossedThresholdAboveAt: Date | null = null;
longPollCrossedThresholdBelowAt: Date | null = null;
private statePollingErrorCount = 0;
statePollingErrorCount = 0;

// Add a method to allow setting the service for testing
protected setService(service: Service) {
Expand Down Expand Up @@ -546,21 +546,24 @@ export class EnergySocketAccessory {
this.syncOutletInUseStateWithOnState(response.power_on);
}
} catch (error) {
const isFirstError = this.statePollingErrorCount === 0;
const isErrorCountAfterInterval = this.statePollingErrorCount > SHOW_POLLING_ERRORS_INTERVAL;
// Increment the error count first
this.statePollingErrorCount += 1;

const isFirstError = this.statePollingErrorCount === 1;
const isErrorCountAfterInterval = this.statePollingErrorCount >= SHOW_POLLING_ERRORS_INTERVAL;

// Only show the error if it's the first error or after the interval
if (isErrorCountAfterInterval || isFirstError) {
if (isFirstError || isErrorCountAfterInterval) {
if (error instanceof Undici.errors.HeadersTimeoutError) {
this.log.error(
`Error during state polling. Device is probably offline.${
this.statePollingErrorCount ? ` Total errors: ${this.statePollingErrorCount}` : ''
this.statePollingErrorCount > 1 ? ` Total errors: ${this.statePollingErrorCount}` : ''
}`,
);
} else {
this.log.error(
`Error polling state:${
this.statePollingErrorCount ? ` Total errors: ${this.statePollingErrorCount}` : ''
this.statePollingErrorCount > 1 ? ` Total errors: ${this.statePollingErrorCount}` : ''
}`,
error,
);
Expand All @@ -570,9 +573,6 @@ export class EnergySocketAccessory {
// Reset the counter after showing the error
this.statePollingErrorCount = 0;
}
} else {
// Continue counting
this.statePollingErrorCount += 1;
}
}

Expand Down

0 comments on commit 1e3d889

Please sign in to comment.