feat: Implemented logging with changable level

package.json

@@ -19,11 +19,12 @@
  "build": "tsc",
  "prepack": "npm run build",
  "semantic-release": "semantic-release",
- "test": "eslint ./src/*.ts ./src/*.js && exit 0" 
+ "test": "eslint ./src/*.ts ./src/*.js && exit 0"
  },
  "dependencies": {
  "@svrooij/sonos": "^2.0.1",
  "mqtt": "3.0.0",
+ "serilogger": "^0.3.0",
  "strict-event-emitter-types": "^2.0.0",
  "yalm": "4.1.0",
  "yargs": "15.3.1"

src/Config.ts

@@ -2,20 +2,32 @@
 import yargs from 'yargs'
 import fs from 'fs'
 import path from 'path'
+import { StaticLogger } from './static-logger';
 
 export interface Config {
  mqtt: string;
- prefix?: string;
- distinct?: boolean;
+ prefix: string;
+ distinct: boolean;
  device?: string;
  ttslang?: string;
  ttsendpoint?: string;
- discovery?: boolean;
- discoveryprefix?: string;
+ discovery: boolean;
+ discoveryprefix: string;
+ log: string;
 }
+
+const defaultConfig: Config = {
+ mqtt: 'mqtt:https://127.0.0.1',
+ prefix: 'sonos',
+ distinct: false,
+ discovery: true,
+ discoveryprefix: 'homeassistant',
+ log: 'information'
+}
+
 export class ConfigLoader {
  static LoadConfig(): Config {
- const config = ConfigLoader.LoadConfigFromFile() ?? ConfigLoader.LoadConfigFromArguments();
+ const config = {...defaultConfig,...(ConfigLoader.LoadConfigFromFile() ?? ConfigLoader.LoadConfigFromArguments())};
 
  if (config.ttsendpoint !== undefined && process.env.SONOS_TTS_ENDPOINT === undefined) {
  process.env.SONOS_TTS_ENDPOINT = config.ttsendpoint
@@ -25,26 +37,27 @@ export class ConfigLoader {
  process.env.SONOS_TTS_LANG = config.ttslang
  }
 
+ StaticLogger.setLevel(config.log)
+
  return config;
  }
 
- private static LoadConfigFromFile(): Config | undefined {
+ private static LoadConfigFromFile(): Partial<Config> | undefined {
  if(process.env.CONFIG_FILE !== undefined && fs.existsSync(process.env.CONFIG_FILE)) {
  const fileContent = fs.readFileSync(process.env.CONFIG_FILE).toString()
- const config = JSON.parse(fileContent) as Config
- if(config.mqtt === '' || config.mqtt === undefined) config.mqtt = 'mqtt:https://127.0.0.1'
- if(config.prefix === undefined) config.prefix = 'sonos'
- if(config.discovery === true && config.discoveryprefix === undefined) config.discoveryprefix = 'homeassistant'
+ return JSON.parse(fileContent) as Partial<Config>
+
  }
  return;
  }
 
- private static LoadConfigFromArguments(): Config {
+ private static LoadConfigFromArguments(): Partial<Config> {
  const pkg = JSON.parse(fs.readFileSync(path.join(__dirname, '..', 'package.json')).toString())
  return yargs
  .usage(pkg.name + ' ' + pkg.version + '\n' + pkg.description + '\n\nUsage: $0 [options]')
  .describe('prefix', 'instance name. used as mqtt client id and as prefix for connected topic')
  .describe('mqtt', 'mqtt broker url. See https://github.com/mqttjs/MQTT.js#connect-using-a-url')
+ .describe('log', 'Set the loglevel')
  .describe('d', 'Publish distinct track states')
  .describe('h', 'show help')
  .describe('ttslang', 'Default TTS language')
@@ -64,12 +77,14 @@ export class ConfigLoader {
  d: false,
  'ttslang': 'en-US',
  'ttsendpoint': undefined,
- discoveryprefix: 'homeassistant'
+ discoveryprefix: 'homeassistant',
+ log: 'information'
  })
+ .choices('log', ['warning', 'information', 'debug'])
  .wrap(80)
  .version()
  .help('help')
  .env('SONOS2MQTT')
- .argv as Config
+ .argv as Partial<Config>
  }
 }

src/device-control.ts

@@ -5,7 +5,6 @@ export class DeviceControl {
  constructor(command?: string, public readonly sonosCommand?: string, public readonly input?: any) {
  if(command !== undefined && Object.values(SonosCommands).some(v => v === command.toLowerCase())) {
  this.command = command.toLowerCase() as SonosCommands;
- // console.log('Command set to %s', this.command)
  }
  }
 

src/index.ts

@@ -1,20 +1,20 @@
 import {SonosToMqtt} from './sonos-to-mqtt'
 import {ConfigLoader} from './config'
+import { StaticLogger } from './static-logger'
 
 const sonosToMqtt = new SonosToMqtt(ConfigLoader.LoadConfig())
 
 sonosToMqtt
  .start()
  .then(success => {
  if(success) {
- console.log('Sonos2Mqtt started')
  process.on('SIGINT', async () => {
- console.log('Shutting down listeners, please wait')
+ StaticLogger.Default().info('Shutdown sonos2mqtt, please wait.')
  sonosToMqtt.stop()
  setTimeout(() => { process.exit(0) }, 800)
  })
  }
  })
  .catch(err => {
- console.error('Sonos2Mqtt failed to start', err)
+ StaticLogger.Default().fatal(err, 'Error starting sonos2mqtt')
  })

src/smarthome-mqtt.ts

@@ -1,9 +1,9 @@
-import debug = require('debug')
 import mqtt, { IClientPublishOptions } from 'mqtt'
 import { MqttClient } from 'mqtt'
 import {StrictEventEmitter} from 'strict-event-emitter-types'
 import {EventEmitter} from 'events'
 import { DeviceControl } from './device-control'
+import {StaticLogger} from './static-logger'
 
 interface MqttEvents {
  connected: (connected: boolean) => void;
@@ -12,7 +12,7 @@ interface MqttEvents {
 }
 
 export class SmarthomeMqtt{
- private readonly debug = debug('sonos2mqtt:mqtt')
+ private readonly log = StaticLogger.CreateLoggerForSource('sonos2mqtt.SmarthomeMqtt')
  private readonly uri: URL
  private mqttClient?: MqttClient;
  public readonly Events: StrictEventEmitter<EventEmitter, MqttEvents> = new EventEmitter();
@@ -31,7 +31,7 @@ export class SmarthomeMqtt{
  keepalive: 60000
  });
  this.mqttClient.on('connect',() => {
- this.debug('Connected to server %s', this.uri.host)
+ this.log.debug('Connected to server {server}', this.uri.host)
  this.Events.emit('connected', true)
  this.mqttClient?.subscribe(`${this.prefix}/set/+/+`)
  this.mqttClient?.subscribe(`${this.prefix}/cmd/+`)
@@ -41,19 +41,22 @@ export class SmarthomeMqtt{
  this.mqttClient.on('message', (topic, payload, packet) => {this.handleIncomingMessage(topic,payload,packet)})
  this.mqttClient.on('close', () => {
  this.Events.emit('connected', false)
- this.debug('mqtt closed ' + this.uri.host)
+ this.log.debug('Mqtt connection closed with {server}', this.uri.host)
+
  })
 
  this.mqttClient.on('error', (err) => {
- this.debug('mqtt %s', err)
+ this.log.warn(err, 'Mqtt error')
  })
 
  this.mqttClient.on('offline', () => {
- this.debug('mqtt offline')
+ this.log.warn('Mqtt offline {server}', this.uri.host)
+
  })
 
  this.mqttClient.on('reconnect', () => {
- this.debug('mqtt reconnect')
+ this.log.info('Mqtt reconnecting {server}', this.uri.host)
+
  })
  }
 
@@ -62,10 +65,12 @@ export class SmarthomeMqtt{
  }
 
  publish(topic: string, payload: string | any, options: IClientPublishOptions = {} as IClientPublishOptions): void {
+ topic = `${this.prefix}/${topic}`
  if(typeof payload === 'number') payload = payload.toString();
  if(typeof payload === 'boolean') payload = payload === true ? 'true': 'false'
+ this.log.verbose('Mqtt publish to {topic} {payload}', topic, payload)
  if(typeof payload !== 'string') payload = JSON.stringify(payload);
- this.mqttClient?.publish(`${this.prefix}/${topic}`, payload, options)
+ this.mqttClient?.publish(topic, payload, options)
  }
 
  publishAutodiscovery(prefix: string, uuid: string, payload: any): void {
@@ -80,7 +85,7 @@ export class SmarthomeMqtt{
  const parts = topic.toLocaleLowerCase().split('/')
 
  if(parts.length === 4 && parts[1] === 'set') {
- this.debug('Got command %s for %s', parts[3], parts[2])
+ this.log.debug('Mqtt parsing {command} for {device}', parts[3], parts[2])
  const control = new DeviceControl(parts[3], undefined, parsedPayload);
  if(control.isValid()) {
  this.Events.emit('deviceControl', parts[2], control)
@@ -89,13 +94,14 @@ export class SmarthomeMqtt{
  && parts[2] === 'control'
  && typeof parsedPayload !== "number" 
  && typeof parsedPayload !== 'string') {
+ this.log.debug('Mqtt parsing {command} for {device}', parsedPayload.cmd ?? parsedPayload.command, parts[1])
  const control = new DeviceControl(parsedPayload.cmd ?? parsedPayload.command, parsedPayload.sonosCommand, parsedPayload.input)
 
  if(control.isValid()) {
  this.Events.emit('deviceControl', parts[1], control)
  }
  } else if (parts.length === 3 && parts[1] === 'cmd') {
- this.debug('Got generic command %s', parts[2])
+ this.log.debug('Mqtt got generic command {command}', parts[2])
  this.Events.emit('generic', parts[2], parsedPayload)
  }
  }

src/sonos-command-mapping.ts

@@ -109,6 +109,9 @@ export class SonosCommandMapping {
  return await device.RenderingControlService.SetRelativeVolume({ 
  InstanceID: 0, Channel: 'Master', 
  Adjustment: ((typeof payload === 'number') ? payload : 4)})
+
+ default:
+ throw new Error(`Command '${command}' not implemented`)
  }
  }
 }

src/sonos-state.ts

@@ -19,4 +19,5 @@ export interface SonosState {
  nextTrack: Track;
  enqueuedMetadata: Track;
  transportState: string;
+ playmode: string;
 }

src/sonos-to-mqtt.ts

@@ -1,5 +1,5 @@
 import { Config } from './config'
-import debug = require('debug')
+import { StaticLogger } from './static-logger'
 import { SonosManager, SonosEvents } from '@svrooij/sonos'
 import { SmarthomeMqtt } from './smarthome-mqtt';
 import { SonosCommandMapping } from './sonos-command-mapping';
@@ -9,7 +9,7 @@ import { SonosCommands } from './sonos-commands';
 export class SonosToMqtt {
  private readonly sonosManager: SonosManager;
  private readonly mqtt: SmarthomeMqtt;
- private readonly debug = debug('sonos2mqtt:main')
+ private readonly log = StaticLogger.CreateLoggerForSource('Sonos2mqtt.main')
  private readonly states: Array<Partial<SonosState>> = [];
  private readonly stateTimers: {[key: string]: NodeJS.Timeout} = {};
  constructor(private config: Config) {
@@ -18,6 +18,7 @@ export class SonosToMqtt {
  }
 
  async start(): Promise<boolean> {
+ this.log.info('Starting sonos2mqtt')
  let success: boolean
  if(this.config.device !== undefined) {
  success = await this.sonosManager.InitializeFromDevice(this.config.device);
@@ -27,6 +28,7 @@ export class SonosToMqtt {
  success = success && this.sonosManager.Devices.length > 0;
 
  if (success) {
+ this.log.info('Found {numDevices} sonos speakers', this.sonosManager.Devices.length)
  this.setupMqttEvents()
  this.setupSonosEvents()
  this.mqtt.connect()
@@ -50,11 +52,13 @@ export class SonosToMqtt {
  * Will setup all events from mqtt with the correct handler.
  */
  private setupMqttEvents(): void {
+ this.log.debug('Setting up mqtt events')
  this.mqtt.Events.on('connected', (connected) => {
- this.debug('Mqtt is %s', connected === true ? 'connected' : 'disconnected')
+ this.log.info('Mqtt connection changed to connected: {connected}', connected)
  })
 
  this.mqtt.Events.on('generic', async (command, payload) => {
+ this.log.debug('Got generic command {command} from mqtt', command)
  switch (command) {
  case 'notify':
  return Promise.all(this.sonosManager.Devices.map(d => d.PlayNotification(payload)))
@@ -66,19 +70,22 @@ export class SonosToMqtt {
  break;
  case 'setalarm':
  return this.sonosManager.Devices[0].AlarmClockService.PatchAlarm(payload);
+ case 'setlogging':
+ return StaticLogger.setLevel(payload);
  }
  })
 
  this.mqtt.Events.on('deviceControl', async (uuid, payload)=> {
  const correctDevice = this.sonosManager.Devices.find(d => d.Uuid.toLocaleLowerCase() === uuid || SonosToMqtt.CleanName(d.Name) === uuid);
  if(correctDevice === undefined) {
- this.debug('Device not found')
+ this.log.warn('Device {uuid} not found', uuid)
  return;
  }
  try {
- return await SonosCommandMapping.ExecuteControl(correctDevice, payload)
+ await SonosCommandMapping.ExecuteControl(correctDevice, payload)
+ this.log.debug('Executed {command} for {device} ({uuid})', payload.command ?? payload.sonosCommand, correctDevice.Name, correctDevice.Uuid)
  } catch (e) {
- console.error('Error executing %s for %s', payload.command ?? payload.sonosCommand, uuid, e)
+ this.log.warn(e, 'Error executing {command} for {device} ({uuid})', payload.command ?? payload.sonosCommand, correctDevice.Name, correctDevice.Uuid)
  }
  })
  }
@@ -166,7 +173,8 @@ export class SonosToMqtt {
  currentTrack: data.CurrentTrackMetaData,
  enqueuedMetadata: data.EnqueuedTransportURIMetaData,
  nextTrack: data.NextTrackMetaData,
- transportState: data.TransportState
+ transportState: data.TransportState,
+ playmode: data.CurrentPlayMode,
  })
  }
 
@@ -207,6 +215,7 @@ export class SonosToMqtt {
 
  // Publish new state on a 400 ms delay. For changes that happen in rapid succession.
  this.stateTimers[uuid] = setTimeout(() => {
+ this.log.verbose('Publishing state for {uuid}', this.states[index].uuid)
  this.mqtt.publish(this.states[index].uuid ?? '', this.states[index], { qos: 0, retain: true });
  }, 400)
  }