more explicit logging

lib/logitech/unifying_receiver/base.py

@@ -209,11 +209,12 @@ def _skip_incoming(handle):
 			raise NoReceiver(reason=reason)
 
 		if data:
-			report_id = ord(data[:1])
-			assert (report_id == 0x10 and len(data) == _SHORT_MESSAGE_SIZE or
-					report_id == 0x11 and len(data) == _LONG_MESSAGE_SIZE or
-					report_id == 0x20 and len(data) == _MEDIUM_MESSAGE_SIZE)
 			_unhandled(report_id, ord(data[1:2]), data[2:])
+			if _log.isEnabledFor(_DEBUG):
+				report_id = ord(data[:1])
+				assert (report_id == 0x10 and len(data) == _SHORT_MESSAGE_SIZE or
+						report_id == 0x11 and len(data) == _LONG_MESSAGE_SIZE or
+						report_id == 0x20 and len(data) == _MEDIUM_MESSAGE_SIZE)
 		else:
 			return
 

lib/logitech/unifying_receiver/hidpp10.py

@@ -5,7 +5,7 @@
 from __future__ import absolute_import, division, print_function, unicode_literals
 
 from logging import getLogger  # , DEBUG as _DEBUG
-_log = getLogger('LUR').getChild('hidpp10')
+_log = getLogger('LUR.hidpp10')
 del getLogger
 
 from .common import (strhex as _strhex,

lib/logitech/unifying_receiver/hidpp20.py

@@ -8,7 +8,7 @@ from struct import pack as _pack, unpack as _unpack
 from weakref import proxy as _proxy
 
 from logging import getLogger, DEBUG as _DEBUG
-_log = getLogger('LUR').getChild('hidpp20')
+_log = getLogger('LUR.hidpp20')
 del getLogger
 
 from .common import (FirmwareInfo as _FirmwareInfo,

lib/logitech/unifying_receiver/listener.py

@@ -14,7 +14,7 @@ except ImportError:
 	from queue import Queue as _Queue
 
 from logging import getLogger, DEBUG as _DEBUG
-_log = getLogger('LUR').getChild('listener')
+_log = getLogger('LUR.listener')
 del getLogger
 
 from . import base as _base
@@ -94,7 +94,7 @@ class ThreadedHandle(object):
 # a while for it to acknowledge it.
 _EVENT_READ_TIMEOUT = 500
 
-# After this many read that did not produce a packet, call the tick() method.
+# After this many reads that did not produce a packet, call the tick() method.
 _IDLE_READS = 4
 
 
@@ -148,11 +148,12 @@ class EventsListener(_threading.Thread):
 
 			if n:
 				# if _log.isEnabledFor(_DEBUG):
-				# 	_log.debug("processing %s", n)
+				# 	_log.debug("%s: processing %s", self.receiver, n)
 				try:
 					self._notifications_callback(n)
 				except:
 					_log.exception("processing %s", n)
+
 			elif self.tick_period:
 				idle_reads += 1
 				if idle_reads % _IDLE_READS == 0:

lib/logitech/unifying_receiver/receiver.py

@@ -8,7 +8,7 @@ import errno as _errno
 from weakref import proxy as _proxy
 
 from logging import getLogger
-_log = getLogger('LUR').getChild('receiver')
+_log = getLogger('LUR.receiver')
 del getLogger
 
 from . import base as _base
@@ -190,7 +190,7 @@ class PairedDevice(object):
 		return self.serial.__hash__()
 
 	def __str__(self):
-		return '<PairedDevice(%d,%s)>' % (self.number, self.codename or '?')
+		return '<PairedDevice(%d,%s,%s)>' % (self.number, self.wpid, self.codename or '?')
 	__unicode__ = __repr__ = __str__
 
 #
@@ -260,21 +260,26 @@ class Receiver(object):
 			# clear out all possible flags
 			ok = self.request(0x8000)
 
+		flags = self.request(0x8100)
+		if flags:
+			flags = ord(flags[0:1]) << 16 | ord(flags[1:2]) << 8 | ord(flags[2:3])
+			flags = tuple(_hidpp10.NOTIFICATION_FLAG.flag_names(flags))
+
 		if ok:
-			_log.info("device notifications %s", 'enabled' if enable else 'disabled')
+			_log.info("%s: device notifications %s %s", self, 'enabled' if enable else 'disabled', flags)
 		else:
-			_log.warn("failed to %s device notifications", 'enable' if enable else 'disable')
+			_log.warn("%s: failed to %s device notifications %s", self, 'enable' if enable else 'disable', flags)
 		return ok
 
 	def notify_devices(self):
 		"""Scan all devices."""
 		if self.handle:
 			if not self.request(0x8002, 0x02):
-				_log.warn("failed to trigger device link notifications")
+				_log.warn("%s: failed to trigger device link notifications", self)
 
 	def register_new_device(self, number):
 		if self._devices.get(number) is not None:
-			raise IndexError("device number %d already registered" % number)
+			raise IndexError("%s: device number %d already registered" % (self, number))
 		dev = PairedDevice(self, number)
 		# create a device object, but only use it if the receiver knows about it
 
@@ -287,7 +292,7 @@ class Receiver(object):
 		#	return dev
 
 		if dev.wpid:
-			_log.info("found device %d (%s)", number, dev.wpid)
+			_log.info("%s: found Unifying device %d (%s)", self, number, dev.wpid)
 			self._devices[number] = dev
 			return dev
 		self._devices[number] = None
@@ -298,7 +303,7 @@ class Receiver(object):
 			reply = self.request(0x80B2, lock, device, timeout)
 			if reply:
 				return True
-			_log.warn("failed to %s the receiver lock", 'close' if lock_closed else 'open')
+			_log.warn("%s: failed to %s the receiver lock", self, 'close' if lock_closed else 'open')
 
 	def count(self):
 		count = self.request(0x8102)

lib/logitech/unifying_receiver/status.py

@@ -218,7 +218,7 @@ class DeviceStatus(dict):
 				if _log.isEnabledFor(_DEBUG):
 					sw_present = bool(flags & 0x10)
 					has_payload = bool(flags & 0x80)
-					_log.debug("%s: connection notification: software=%s, encrypted=%s, link=%s, payload=%s",
+					_log.debug("%s: unifying connection notification: software=%s, encrypted=%s, link=%s, payload=%s",
 								self._device, sw_present, link_encrypyed, link_established, has_payload)
 				self[ENCRYPTED] = link_encrypyed
 				self._changed(link_established)

lib/solaar/cli.py

@@ -5,6 +5,7 @@
 from __future__ import absolute_import, division, print_function, unicode_literals
 
 import sys
+import logging
 
 
 NAME = 'solaar-cli'
@@ -15,6 +16,8 @@ from solaar import __version__
 #
 
 def _fail(text):
+	if sys.exc_info()[0]:
+		logging.exception(text)
 	sys.exit("%s: error: %s" % (NAME, text))
 
 
@@ -364,7 +367,6 @@ def _parse_arguments():
 
 	args = arg_parser.parse_args()
 
-	import logging
 	if args.debug > 0:
 		log_level = logging.WARNING - 10 * args.debug
 		log_format='%(asctime)s %(levelname)8s %(name)s: %(message)s'

lib/solaar/listener.py

@@ -5,7 +5,7 @@
 from __future__ import absolute_import, division, print_function, unicode_literals
 
 from logging import getLogger, DEBUG as _DEBUG
-_log = getLogger('listener')
+_log = getLogger('solaar.listener')
 del getLogger
 
 from logitech.unifying_receiver import (Receiver,
@@ -53,13 +53,13 @@ class ReceiverListener(_listener.EventsListener):
 		receiver.status = _status.ReceiverStatus(receiver, self._status_changed)
 
 	def has_started(self):
-		_log.info("notifications listener has started")
+		_log.info("%s: notifications listener has started (%s)", self.receiver, self.receiver.handle)
 		self.receiver.enable_notifications()
 		self.receiver.notify_devices()
 		self._status_changed(self.receiver, _status.ALERT.LOW)
 
 	def has_stopped(self):
-		_log.info("notifications listener has stopped")
+		_log.info("%s: notifications listener has stopped", self.receiver)
 		if self.receiver:
 			self.receiver.enable_notifications(False)
 			self.receiver.close()
@@ -68,12 +68,12 @@ class ReceiverListener(_listener.EventsListener):
 
 	def tick(self, timestamp):
 		if _log.isEnabledFor(_DEBUG):
-			_log.debug("polling status: %s %s", self.receiver, list(iter(self.receiver)))
+			_log.debug("%s: polling status: %s", self.receiver, list(iter(self.receiver)))
 
 		if self._last_tick > 0 and timestamp - self._last_tick > _POLL_TICK * 3:
 			# if we missed a couple of polls, most likely the computer went into
 			# sleep, and we have to reinitialize the receiver again
-			_log.warn("possible sleep detected, closing this listener")
+			_log.warn("%s: possible sleep detected, closing this listener", self.receiver)
 			self.stop()
 			return
 
@@ -114,6 +114,7 @@ class ReceiverListener(_listener.EventsListener):
 
 	def _notifications_handler(self, n):
 		assert self.receiver
+		# _log.debug("%s: handling %s", self.receiver, n)
 		if n.devnumber == 0xFF:
 			# a receiver notification
 			if self.receiver.status is not None:
@@ -125,7 +126,7 @@ class ReceiverListener(_listener.EventsListener):
 			dev = self.receiver[n.devnumber]
 
 			if not dev:
-				_log.warn("received %s for invalid device %d: %r", n, n.devnumber, dev)
+				_log.warn("%s: received %s for invalid device %d: %r", self.receiver, n, n.devnumber, dev)
 				return
 
 			if not already_known:
@@ -141,7 +142,7 @@ class ReceiverListener(_listener.EventsListener):
 				if self.receiver.status.lock_open and not already_known:
 					# this should be the first notification after a device was paired
 					assert n.sub_id == 0x41 and n.address == 0x04
-					_log.info("pairing detected new device")
+					_log.info("%s: pairing detected new device", self.receiver)
 					self.receiver.status.new_device = dev
 
 	def __str__(self):