From 67da9f68aa9890594944c6d5733cc30f20bc5f5a Mon Sep 17 00:00:00 2001 From: Alexander Ciesielski Date: Tue, 7 Apr 2020 21:44:22 +0200 Subject: [PATCH] feat: add logger --- README.md | 4 +- example/index.ts | 14 +- lib/connection/connection.ts | 424 ++++++++++++++--------------- lib/core/ha-rxjs.ts | 64 +++-- lib/core/services.ts | 3 + lib/util/logger.spec.ts | 50 ++++ lib/util/logger.ts | 38 +++ lib/util/operators/select-state.ts | 22 +- package-lock.json | 28 +- package.json | 7 +- tsconfig.json | 2 +- tsconfig.module.json | 17 +- 12 files changed, 394 insertions(+), 279 deletions(-) create mode 100644 lib/util/logger.spec.ts create mode 100644 lib/util/logger.ts diff --git a/README.md b/README.md index c7a7983..38d7ed8 100644 --- a/README.md +++ b/README.md @@ -8,11 +8,12 @@ rxjs wrapper for [home-assistant-js-websocket](https://github.com/home-assistant 2. Create long-lived access token under http://homeassistant:8123/profile -3. Create a `.env` file with two properties `HOST` and `ACCESS_TOKEN`. +3. Create a `.env` file ``` HOST=http://homeassistant.local:8123 ACCESS_TOKEN= +LOGLEVEL=INFO ``` 4. Initialize `HomeAssistantRXJS` and define your automations @@ -29,7 +30,6 @@ const motion$ = home.entities.pipe( // and after 2 seconds turn it off motion$ .pipe( - distinctUntilChanged(), filter(state => state === 'on'), switchMapTo(home.lights.turnOn('light.hall_light')), delay(2000), diff --git a/example/index.ts b/example/index.ts index fa6ab10..2cde5dc 100644 --- a/example/index.ts +++ b/example/index.ts @@ -1,26 +1,20 @@ -import { - delay, - distinctUntilChanged, - filter, - switchMapTo, -} from 'rxjs/operators'; +import { delay, filter, switchMapTo } from 'rxjs/operators'; import { HomeAssistantRXJS, select } from '../lib'; const home = new HomeAssistantRXJS(); home.initialize(); const motion$ = home.entities.pipe( - select('binary_sensor.hall_motion_sensor', 'state'), + select('binary_sensor.office_office_motion_114', 'state'), ); // When motion detected turn the light on // and after 2 seconds turn it off motion$ .pipe( - distinctUntilChanged(), filter(state => state === 'on'), - switchMapTo(home.lights.turnOn('light.hall_light')), + switchMapTo(home.lights.turnOn('light.office_office_ceiling_light_104')), delay(2000), - switchMapTo(home.lights.turnOff('light.hall_light')), + switchMapTo(home.lights.turnOff('light.office_office_ceiling_light_104')), ) .subscribe(); diff --git a/lib/connection/connection.ts b/lib/connection/connection.ts index 2d52b19..2d84a7d 100644 --- a/lib/connection/connection.ts +++ b/lib/connection/connection.ts @@ -1,213 +1,211 @@ -// https://github.com/keesschollaart81/vscode-home-assistant/blob/master/src/language-service/src/home-assistant/socket.ts - -/* -This is slightly modified version of -https://github.com/home-assistant/home-assistant-js-websocket/blob/master/lib/socket.ts -*/ - -import dotenv from 'dotenv'; -import { - Connection, - createConnection, - ERR_CANNOT_CONNECT, - ERR_INVALID_AUTH, - MSG_TYPE_AUTH_INVALID, - MSG_TYPE_AUTH_OK, - MSG_TYPE_AUTH_REQUIRED, -} from 'home-assistant-js-websocket'; -import { BehaviorSubject, Observable } from 'rxjs'; -import WebSocket from 'ws'; -import { filterNullOrUndefined } from '../util/operators/filter-truthy'; - -interface AuthOptions { - token: string; - wsUrl: string; -} - -export class HomeAssistantConnection extends BehaviorSubject { - constructor() { - super(null); - dotenv.config(); - } - - asObservable(): Observable { - return this.pipe(filterNullOrUndefined()); - } - - async connect() { - const connection = await createConnection({ - createSocket: () => - createSocket({ wsUrl: getWsURL(), token: getToken() }, true), - }); - - this.next(connection); - } - - disconnect() { - this.value?.close(); - this.complete(); - } -} - -function getWsURL() { - const host = process.env.HOST; - return host - ? `ws${host.substr(4)}/api/websocket` - : 'ws://supervisor/core/websocket'; -} - -function getToken() { - const token = process.env.ACCESS_TOKEN || process.env.SUPERVISOR_TOKEN; - - if (!token) { - throw new Error( - 'No access token (SUPERVISOR_TOKEN or ACCESS_TOKEN) found in environment variables.', - ); - } - - return token; -} - -export function createSocket( - auth: AuthOptions, - ignoreCertificates: boolean, -): Promise { - const url = auth.wsUrl; - - console.log( - '[Auth phase] Initializing WebSocket connection to Home Assistant', - url, - ); - - function connect( - triesLeft: number, - promResolve: (socket: any) => void, - promReject: (err: number) => void, - ) { - console.log( - `[Auth Phase] Connecting to Home Assistant... Tries left: ${triesLeft}`, - url, - ); - - const socket = new WebSocket(url, { - rejectUnauthorized: !ignoreCertificates, - }); - - // If invalid auth, we will not try to reconnect. - let invalidAuth = false; - - const closeMessage = (ev: { - wasClean: boolean; - code: number; - reason: string; - target: WebSocket; - }) => { - let errorMessage; - if (ev && ev.code && ev.code !== 1000) { - errorMessage = `WebSocket connection to Home Assistant closed with code ${ev.code} and reason ${ev.reason}`; - } - closeOrError(errorMessage); - }; - - const errorMessage = (ev: { - error: any; - message: any; - type: string; - target: WebSocket; - }) => { - // If we are in error handler make sure close handler doesn't also fire. - socket.removeEventListener('close', closeMessage); - let errorMessage = - 'Disconnected from Home Assistant with a WebSocket error'; - if (ev.message) { - errorMessage += ` with message: ${ev.message}`; - } - closeOrError(errorMessage); - }; - - const closeOrError = (errorText?: string) => { - console.error('closeOrError', errorText); - - if (errorText) { - console.log( - `WebSocket Connection to Home Assistant closed with an error: ${errorText}`, - ); - } - if (invalidAuth) { - promReject(ERR_INVALID_AUTH); - return; - } - - // Reject if we no longer have to retry - if (triesLeft === 0) { - // We never were connected and will not retry - promReject(ERR_CANNOT_CONNECT); - return; - } - - const newTries = triesLeft === -1 ? -1 : triesLeft - 1; - // Try again in a second - setTimeout(() => connect(newTries, promResolve, promReject), 1000); - }; - - // Auth is mandatory, so we can send the auth message right away. - const handleOpen = async () => { - try { - /* if (auth.expired) { - await auth.refreshAccessToken(); - } */ - socket.send( - JSON.stringify({ - type: 'auth', - access_token: auth.token, - }), - ); - } catch (err) { - // Refresh token failed - invalidAuth = err === ERR_INVALID_AUTH; - socket.close(); - } - }; - - const handleMessage = async (event: { - data: any; - type: string; - target: WebSocket; - }) => { - const message = JSON.parse(event.data); - - console.log( - `[Auth phase] Received a message of type ${message.type}`, - message, - ); - - switch (message.type) { - case MSG_TYPE_AUTH_INVALID: - invalidAuth = true; - socket.close(); - break; - - case MSG_TYPE_AUTH_OK: - socket.removeEventListener('open', handleOpen); - socket.removeEventListener('message', handleMessage); - socket.removeEventListener('close', closeMessage); - socket.removeEventListener('error', errorMessage); - promResolve(socket); - break; - - default: - // We already send this message when socket opens - if (message.type !== MSG_TYPE_AUTH_REQUIRED) { - console.log('[Auth phase] Unhandled message', message); - } - } - }; - - socket.addEventListener('open', handleOpen); - socket.addEventListener('message', handleMessage); - socket.addEventListener('close', closeMessage); - socket.addEventListener('error', errorMessage); - } - - return new Promise((resolve, reject) => connect(3, resolve, reject)); -} +// https://github.com/keesschollaart81/vscode-home-assistant/blob/master/src/language-service/src/home-assistant/socket.ts + +/* +This is slightly modified version of +https://github.com/home-assistant/home-assistant-js-websocket/blob/master/lib/socket.ts +*/ + +import { + Connection, + createConnection, + ERR_CANNOT_CONNECT, + ERR_INVALID_AUTH, + MSG_TYPE_AUTH_INVALID, + MSG_TYPE_AUTH_OK, + MSG_TYPE_AUTH_REQUIRED, +} from 'home-assistant-js-websocket'; +import { BehaviorSubject, Observable } from 'rxjs'; +import WebSocket from 'ws'; +import { filterNullOrUndefined } from '../util/operators/filter-truthy'; + +interface AuthOptions { + token: string; + wsUrl: string; +} + +export class HomeAssistantConnection extends BehaviorSubject { + constructor() { + super(null); + } + + asObservable(): Observable { + return this.pipe(filterNullOrUndefined()); + } + + async connect() { + const connection = await createConnection({ + createSocket: () => + createSocket({ wsUrl: getWsURL(), token: getToken() }, true), + }); + + this.next(connection); + } + + disconnect() { + this.value?.close(); + this.complete(); + } +} + +function getWsURL() { + const host = process.env.HOST; + return host + ? `ws${host.substr(4)}/api/websocket` + : 'ws://supervisor/core/websocket'; +} + +function getToken() { + const token = process.env.ACCESS_TOKEN || process.env.SUPERVISOR_TOKEN; + + if (!token) { + throw new Error( + 'No access token (SUPERVISOR_TOKEN or ACCESS_TOKEN) found in environment variables.', + ); + } + + return token; +} + +export function createSocket( + auth: AuthOptions, + ignoreCertificates: boolean, +): Promise { + const url = auth.wsUrl; + + console.log( + '[Auth phase] Initializing WebSocket connection to Home Assistant', + url, + ); + + function connect( + triesLeft: number, + promResolve: (socket: any) => void, + promReject: (err: number) => void, + ) { + console.log( + `[Auth Phase] Connecting to Home Assistant... Tries left: ${triesLeft}`, + url, + ); + + const socket = new WebSocket(url, { + rejectUnauthorized: !ignoreCertificates, + }); + + // If invalid auth, we will not try to reconnect. + let invalidAuth = false; + + const closeMessage = (ev: { + wasClean: boolean; + code: number; + reason: string; + target: WebSocket; + }) => { + let errorMessage; + if (ev && ev.code && ev.code !== 1000) { + errorMessage = `WebSocket connection to Home Assistant closed with code ${ev.code} and reason ${ev.reason}`; + } + closeOrError(errorMessage); + }; + + const errorMessage = (ev: { + error: any; + message: any; + type: string; + target: WebSocket; + }) => { + // If we are in error handler make sure close handler doesn't also fire. + socket.removeEventListener('close', closeMessage); + let errorMessage = + 'Disconnected from Home Assistant with a WebSocket error'; + if (ev.message) { + errorMessage += ` with message: ${ev.message}`; + } + closeOrError(errorMessage); + }; + + const closeOrError = (errorText?: string) => { + console.error('closeOrError', errorText); + + if (errorText) { + console.log( + `WebSocket Connection to Home Assistant closed with an error: ${errorText}`, + ); + } + if (invalidAuth) { + promReject(ERR_INVALID_AUTH); + return; + } + + // Reject if we no longer have to retry + if (triesLeft === 0) { + // We never were connected and will not retry + promReject(ERR_CANNOT_CONNECT); + return; + } + + const newTries = triesLeft === -1 ? -1 : triesLeft - 1; + // Try again in a second + setTimeout(() => connect(newTries, promResolve, promReject), 1000); + }; + + // Auth is mandatory, so we can send the auth message right away. + const handleOpen = async () => { + try { + /* if (auth.expired) { + await auth.refreshAccessToken(); + } */ + socket.send( + JSON.stringify({ + type: 'auth', + access_token: auth.token, + }), + ); + } catch (err) { + // Refresh token failed + invalidAuth = err === ERR_INVALID_AUTH; + socket.close(); + } + }; + + const handleMessage = async (event: { + data: any; + type: string; + target: WebSocket; + }) => { + const message = JSON.parse(event.data); + + console.log( + `[Auth phase] Received a message of type ${message.type}`, + message, + ); + + switch (message.type) { + case MSG_TYPE_AUTH_INVALID: + invalidAuth = true; + socket.close(); + break; + + case MSG_TYPE_AUTH_OK: + socket.removeEventListener('open', handleOpen); + socket.removeEventListener('message', handleMessage); + socket.removeEventListener('close', closeMessage); + socket.removeEventListener('error', errorMessage); + promResolve(socket); + break; + + default: + // We already send this message when socket opens + if (message.type !== MSG_TYPE_AUTH_REQUIRED) { + console.log('[Auth phase] Unhandled message', message); + } + } + }; + + socket.addEventListener('open', handleOpen); + socket.addEventListener('message', handleMessage); + socket.addEventListener('close', closeMessage); + socket.addEventListener('error', errorMessage); + } + + return new Promise((resolve, reject) => connect(3, resolve, reject)); +} diff --git a/lib/core/ha-rxjs.ts b/lib/core/ha-rxjs.ts index 84de45b..8e843a2 100644 --- a/lib/core/ha-rxjs.ts +++ b/lib/core/ha-rxjs.ts @@ -1,27 +1,37 @@ -import { Subject } from 'rxjs'; -import { HomeAssistantConnection } from '../connection'; -import { HomeAssistantLights } from '../lights'; -import { HomeAssistantEntities } from './entities'; -import { HomeAssistantServices } from './services'; - -export class HomeAssistantRXJS { - readonly destroy$ = new Subject(); - - private readonly connection = new HomeAssistantConnection(); - readonly connection$ = this.connection.asObservable(); - - readonly services = new HomeAssistantServices(this, this.destroy$); - readonly entities = new HomeAssistantEntities(this, this.destroy$); - readonly lights = new HomeAssistantLights(this); - - async initialize() { - await this.connection.connect(); - } - - destroy() { - console.log('Closing connection'); - this.destroy$.next(); - this.destroy$.complete(); - this.connection.disconnect(); - } -} +import dotenv from 'dotenv'; +import { Subject } from 'rxjs'; +import { HomeAssistantConnection } from '../connection'; +import { HomeAssistantLights } from '../lights'; +import { Logger } from '../util/logger'; +import { HomeAssistantEntities } from './entities'; +import { HomeAssistantServices } from './services'; + +export class HomeAssistantRXJS { + constructor() { + dotenv.config(); + } + readonly destroy$ = new Subject(); + readonly logger = new Logger(process.env); + + private readonly connection = new HomeAssistantConnection(); + readonly connection$ = this.connection.asObservable(); + + readonly services = new HomeAssistantServices( + this, + this.destroy$, + this.logger, + ); + readonly entities = new HomeAssistantEntities(this, this.destroy$); + readonly lights = new HomeAssistantLights(this); + + async initialize() { + await this.connection.connect(); + } + + destroy() { + console.log('Closing connection'); + this.destroy$.next(); + this.destroy$.complete(); + this.connection.disconnect(); + } +} diff --git a/lib/core/services.ts b/lib/core/services.ts index d182f4d..d1c4868 100644 --- a/lib/core/services.ts +++ b/lib/core/services.ts @@ -5,12 +5,14 @@ import { } from 'home-assistant-js-websocket'; import { BehaviorSubject, from, Observable } from 'rxjs'; import { switchMap, switchMapTo, takeUntil, tap } from 'rxjs/operators'; +import { Logger } from '../util/logger'; import { HomeAssistantRXJS } from './ha-rxjs'; export class HomeAssistantServices extends BehaviorSubject { constructor( private ha: HomeAssistantRXJS, private destroy$: Observable, + private logger: Logger, ) { super({}); this.subscribeServices(); @@ -21,6 +23,7 @@ export class HomeAssistantServices extends BehaviorSubject { switchMap(connection => from(callService(connection, domain, service, serviceData)), ), + tap(() => this.logger.info(`Called ${domain}.${service}`, serviceData)), takeUntil(this.destroy$), ); } diff --git a/lib/util/logger.spec.ts b/lib/util/logger.spec.ts new file mode 100644 index 0000000..bd24968 --- /dev/null +++ b/lib/util/logger.spec.ts @@ -0,0 +1,50 @@ +import chai, { expect } from 'chai'; +import spies from 'chai-spies'; +import 'mocha'; +import { Logger, LoggerLevel } from '../util/logger'; + +describe('Logger', () => { + let logger: Logger; + let called: any; + + before(() => { + chai.use(spies); + if (!called) { + called = chai.spy.on(console, 'log'); + } + }); + + after(() => { + chai.spy.restore(called); + }); + + describe('LoggerLevel DEBUG', () => { + beforeEach(() => { + logger = new Logger({ LOG: LoggerLevel.DEBUG }); + }); + it('debug should log', () => { + logger.debug('msg'); + expect(called).to.have.been.called; + }); + + it('info should not log', () => { + logger.info('msg'); + expect(called).to.not.have.been.called; + }); + }); + + describe('LoggerLevel INFO', () => { + beforeEach(() => { + logger = new Logger({ LOG: LoggerLevel.INFO }); + }); + it('info should log when LoggerLevel INFO', () => { + logger.info('msg'); + expect(called).to.have.been.called; + }); + + it('debug should log when LoggerLevel INFO', () => { + logger.debug('msg'); + expect(called).to.have.been.called; + }); + }); +}); diff --git a/lib/util/logger.ts b/lib/util/logger.ts new file mode 100644 index 0000000..6835b1c --- /dev/null +++ b/lib/util/logger.ts @@ -0,0 +1,38 @@ +import { format } from 'date-fns'; + +export enum LoggerLevel { + DEBUG = 'DEBUG', + INFO = 'INFO', +} + +export class Logger { + constructor(private env?: { LOG?: LoggerLevel }) {} + + get level() { + return this.env?.LOG ?? ''; + } + + debug(message: string, data?: any) { + if (LoggerLevel.DEBUG === this.level) { + this.log(message, data); + } + } + + info(message: string, data?: any) { + if ( + [LoggerLevel.DEBUG, LoggerLevel.INFO].some(level => level === this.level) + ) { + this.log(message, data); + } + } + + private log(message: string, data?: any) { + const now = format(new Date(), 'dd.MM HH:mm'); + + if (data) { + message = `${message}${data ? ` with\n${JSON.stringify(data)}` : ''}`; + } + + console.log(`${now}: ${message}`); + } +} diff --git a/lib/util/operators/select-state.ts b/lib/util/operators/select-state.ts index 18ac2d2..ef72965 100644 --- a/lib/util/operators/select-state.ts +++ b/lib/util/operators/select-state.ts @@ -1,11 +1,11 @@ -import { HassEntities, HassEntity } from 'home-assistant-js-websocket'; -import { Observable } from 'rxjs'; -import { select } from './select'; - -export function selectState(id: string) { - return function( - source$: Observable, - ): Observable { - return source$.pipe(select(id, 'state')); - }; -} +import { HassEntities, HassEntity } from 'home-assistant-js-websocket'; +import { Observable } from 'rxjs'; +import { select } from './select'; + +export function selectState(id: string) { + return function ( + source$: Observable, + ): Observable { + return source$.pipe(select(id, 'state')); + }; +} diff --git a/package-lock.json b/package-lock.json index 434e092..af04a0f 100644 --- a/package-lock.json +++ b/package-lock.json @@ -69,6 +69,15 @@ "integrity": "sha512-t7uW6eFafjO+qJ3BIV2gGUyZs27egcNRkUdalkud+Qa3+kg//f129iuOFivHDXQ+vnU3fDXuwgv0cqMCbcE8sw==", "dev": true }, + "@types/chai-spies": { + "version": "1.0.1", + "resolved": "https://registry.npmjs.org/@types/chai-spies/-/chai-spies-1.0.1.tgz", + "integrity": "sha512-vvlTzisMpzmPZaKDd0pFybCJB5bzx398JEdPsVD9Rwq4a7dcGSUDlNG2PAVhsanRBPl4hezqnlaFtL1/YwBGgw==", + "dev": true, + "requires": { + "@types/chai": "*" + } + }, "@types/color-name": { "version": "1.1.1", "resolved": "https://registry.npmjs.org/@types/color-name/-/color-name-1.1.1.tgz", @@ -587,6 +596,12 @@ "type-detect": "^4.0.5" } }, + "chai-spies": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/chai-spies/-/chai-spies-1.0.0.tgz", + "integrity": "sha512-elF2ZUczBsFoP07qCfMO/zeggs8pqCf3fZGyK5+2X4AndS8jycZYID91ztD9oQ7d/0tnS963dPkd0frQEThDsg==", + "dev": true + }, "chalk": { "version": "2.4.2", "resolved": "https://registry.npmjs.org/chalk/-/chalk-2.4.2.tgz", @@ -857,10 +872,9 @@ } }, "date-fns": { - "version": "1.30.1", - "resolved": "https://registry.npmjs.org/date-fns/-/date-fns-1.30.1.tgz", - "integrity": "sha512-hBSVCvSmWC+QypYObzwGOd9wqdDpOt+0wl0KbU+R+uuZBS1jN8VsD1ss3irQDknRj5NvxiTF6oj/nDRnN/UQNw==", - "dev": true + "version": "2.11.1", + "resolved": "https://registry.npmjs.org/date-fns/-/date-fns-2.11.1.tgz", + "integrity": "sha512-3RdUoinZ43URd2MJcquzBbDQo+J87cSzB8NkXdZiN5ia1UNyep0oCyitfiL88+R7clGTeq/RniXAc16gWyAu1w==" }, "dateformat": { "version": "1.0.12", @@ -2742,6 +2756,12 @@ "restore-cursor": "^2.0.0" } }, + "date-fns": { + "version": "1.30.1", + "resolved": "https://registry.npmjs.org/date-fns/-/date-fns-1.30.1.tgz", + "integrity": "sha512-hBSVCvSmWC+QypYObzwGOd9wqdDpOt+0wl0KbU+R+uuZBS1jN8VsD1ss3irQDknRj5NvxiTF6oj/nDRnN/UQNw==", + "dev": true + }, "figures": { "version": "2.0.0", "resolved": "https://registry.npmjs.org/figures/-/figures-2.0.0.tgz", diff --git a/package.json b/package.json index 7968354..66e2818 100644 --- a/package.json +++ b/package.json @@ -46,15 +46,17 @@ "postrelease": "npm publish" }, "dependencies": { + "date-fns": "^2.11.1", "dotenv": "^8.2.0", "esm": "^3.2.25", "home-assistant-js-websocket": "^5.1.0", "rxjs": "^6.5.4", - "ws": "^7.2.3", - "typescript": "^3.8.3" + "typescript": "^3.8.3", + "ws": "^7.2.3" }, "devDependencies": { "@types/chai": "^4.2.11", + "@types/chai-spies": "^1.0.1", "@types/command-line-args": "^5.0.0", "@types/mocha": "^7.0.2", "@types/node": "^13.9.0", @@ -62,6 +64,7 @@ "@typescript-eslint/eslint-plugin": "^2.26.0", "@typescript-eslint/parser": "^2.26.0", "chai": "^4.2.0", + "chai-spies": "^1.0.0", "eslint": "^6.8.0", "eslint-config-prettier": "^6.10.1", "eslint-plugin-prettier": "^3.1.2", diff --git a/tsconfig.json b/tsconfig.json index a521fc6..dc74f80 100644 --- a/tsconfig.json +++ b/tsconfig.json @@ -24,6 +24,6 @@ "skipLibCheck": true }, "include": ["lib"], - "exclude": ["node_modules/**"], + "exclude": ["node_modules/**", "lib/**/*.spec.ts"], "compileOnSave": false } diff --git a/tsconfig.module.json b/tsconfig.module.json index 486a382..2b201bd 100644 --- a/tsconfig.module.json +++ b/tsconfig.module.json @@ -1,9 +1,8 @@ -{ - "extends": "./tsconfig", - "compilerOptions": { - "target": "es2018", - "outDir": "dist/module", - "module": "esnext" - }, - "exclude": ["node_modules/**"] -} +{ + "extends": "./tsconfig", + "compilerOptions": { + "target": "es2018", + "outDir": "dist/module", + "module": "esnext" + } +}