ConfigValueOption("warning", "WARNING"),
ConfigValueOption("error", "ERROR"),
ConfigValueOption("debug", "DEBUG"),
+ ConfigValueOption("verbose", "VERBOSE"),
),
default_value="GLOBAL",
advanced=True,
self._set_logger(log_level)
await self.setup(config)
- def _set_logger(self, log_level: int | None = None) -> None:
+ def _set_logger(self, log_level: str | None = None) -> None:
"""Set the logger settings."""
mass_logger = logging.getLogger(ROOT_LOGGER_NAME)
self.logger = logging.getLogger(f"{ROOT_LOGGER_NAME}.{self.domain}")
log_level = self.mass.config.get_raw_core_config_value(
self.domain, CONF_LOG_LEVEL, "GLOBAL"
)
+ self.log_level = log_level
if log_level == "GLOBAL":
self.logger.setLevel(mass_logger.level)
else:
- self.logger.setLevel(log_level)
+ self.logger.setLevel("DEBUG" if log_level == "VERBOSE" else log_level)
# if the root logger's level is higher, we need to adjust that too
if logging.getLogger().level > self.logger.level:
logging.getLogger().setLevel(self.logger.level)
self.config = config
mass_logger = logging.getLogger(ROOT_LOGGER_NAME)
self.logger = mass_logger.getChild(f"providers.{self.domain}")
- log_level = config.get_value(CONF_LOG_LEVEL)
+ self.log_level = log_level = config.get_value(CONF_LOG_LEVEL)
if log_level == "GLOBAL":
self.logger.setLevel(mass_logger.level)
else:
- self.logger.setLevel(log_level)
+ self.logger.setLevel("DEBUG" if log_level == "VERBOSE" else log_level)
# if the root logger's level is higher, we need to adjust that too
if logging.getLogger().level > self.logger.level:
logging.getLogger().setLevel(self.logger.level)
- # apply logger settings to modules/packages used by this provider
- for pkg_name in manifest.requirements:
- dependency = pkg_name.split("=")[0].split("<")[0].split(">")[0]
- # unless log level is explicitly set to debug,
- # we silence the dependency logger to warning level
- conf_log_level = self.config.get_value(CONF_LOG_LEVEL)
- level = logging.DEBUG if conf_log_level == logging.DEBUG else logging.WARNING
- logging.getLogger(dependency).setLevel(level)
self.logger.debug("Log level configured to %s", log_level)
self.cache = mass.cache
self.available = False
# NOTE: This may not work as we might need to do
# some fancy hashing with the plain password first?!
extra_args += ["-P", device_password]
- if self.airplay_player.logger.level == logging.DEBUG:
+ if self.prov.log_level == "DEBUG":
extra_args += ["-d", "5"]
+ elif self.prov.log_level == "VERBOSE":
+ extra_args += ["-d", "10"]
args = [
self.prov.cliraop_bin,
with open(named_pipe, "w") as f:
f.write(command)
- self.airplay_player.logger.debug("sending command %s", command)
+ if self.prov.log_level == "VERBOSE":
+ self.airplay_player.logger.debug("sending command %s", command)
await self.mass.create_task(send_data)
async def _log_watcher(self) -> None:
mass_player.elapsed_time_last_updated = time.time()
continue
if "set pause" in line or "Pause at" in line:
- logger.info("raop streaming paused")
+ logger.debug("raop streaming paused")
mass_player.state = PlayerState.PAUSED
self.mass.players.update(airplay_player.player_id)
continue
if "Restarted at" in line or "restarting w/ pause" in line:
- logger.info("raop streaming restarted after pause")
+ logger.debug("raop streaming restarted after pause")
mass_player.state = PlayerState.PLAYING
self.mass.players.update(airplay_player.player_id)
continue
if "Stopped at" in line:
- logger.info("raop streaming stopped")
+ logger.debug("raop streaming stopped")
mass_player.state = PlayerState.IDLE
self.mass.players.update(airplay_player.player_id)
continue
if "restarting w/o pause" in line:
# streaming has started
- logger.info("raop streaming started")
+ logger.debug("raop streaming started")
mass_player.state = PlayerState.PLAYING
mass_player.elapsed_time = 0
mass_player.elapsed_time_last_updated = time.time()
logger.warning(line)
continue
# debug log everything else
- logger.debug(line)
+ if self.prov.log_level == "VERBOSE":
+ logger.debug(line)
# if we reach this point, the process exited
logger.debug(
player_id = f"ap{raw_id.lower()}"
# handle removed player
if state_change == ServiceStateChange.Removed:
- self.logger.debug("Airplay device %s removed", name)
if mass_player := self.mass.players.get(player_id):
# the player has become unavailable
- self.logger.info("Player removed %s", display_name)
+ self.logger.info("Player offline: %s", display_name)
mass_player.available = False
self.mass.players.update(player_id)
return
# should not happen, but just in case
raise RuntimeError("Player is synced")
synced_player_ids = [x.player_id for x in self._get_sync_clients(player_id)]
- self.logger.info(
+ self.logger.debug(
"Starting RAOP stream for Queue %s to %s",
queue.display_name,
"/".join(synced_player_ids),
),
self.mass.aiozc.zeroconf,
)
- # silence pychromecast logging
- logging.getLogger("pychromecast").setLevel(self.logger.level + 10)
+ # set-up pychromecast logging
+ if self.log_level == "VERBOSE":
+ logging.getLogger("pychromecast").setLevel(logging.DEBUG)
+ else:
+ logging.getLogger("pychromecast").setLevel(self.logger.level + 10)
async def loaded_in_mass(self) -> None:
"""Call after the provider has been loaded."""
player_id = kwargs["player_id"] if "player_id" in kwargs else args[0]
dlna_player = self.dlnaplayers[player_id]
dlna_player.last_command = time.time()
- self.logger.debug(
- "Handling command %s for player %s",
- func.__name__,
- dlna_player.player.display_name,
- )
+ if self.log_level == "VERBOSE":
+ self.logger.debug(
+ "Handling command %s for player %s",
+ func.__name__,
+ dlna_player.player.display_name,
+ )
if not dlna_player.available:
self.logger.warning("Device disappeared when trying to call %s", func.__name__)
return None
self.dlnaplayers = {}
self.lock = asyncio.Lock()
# silence the async_upnp_client logger
- logging.getLogger("async_upnp_client").setLevel(self.logger.level + 10)
+ if self.log_level == "VERBOSE":
+ logging.getLogger("async_upnp_client").setLevel(logging.DEBUG)
+ else:
+ logging.getLogger("async_upnp_client").setLevel(self.logger.level + 10)
self.requester = AiohttpSessionRequester(self.mass.http_session, with_sleep=True)
self.upnp_factory = UpnpFactory(self.requester, non_strict=True)
self.notify_server = DLNANotifyServer(self.requester, self.mass)
soco_config.REQUEST_TIMEOUT = 9.5
soco_config.ZGT_EVENT_FALLBACK = False
zonegroupstate.EVENT_CACHE_TIMEOUT = SUBSCRIPTION_TIMEOUT
- # silence the soco logger a bit
- logging.getLogger("soco").setLevel(logging.INFO)
- logging.getLogger("urllib3.connectionpool").setLevel(logging.INFO)
prov = SonosPlayerProvider(mass, manifest, config)
+ # set-up soco logging
+ if prov.log_level == "VERBOSE":
+ logging.getLogger("soco").setLevel(logging.DEBUG)
+ logging.getLogger("urllib3.connectionpool").setLevel(logging.INFO)
+ else:
+ logging.getLogger("pychromecast").setLevel(prov.logger.level + 10)
+ logging.getLogger("urllib3.connectionpool").setLevel(logging.WARNING)
await prov.handle_async_init()
return prov