Skip to content

Commit

Permalink
Refactor logging mechanism for kuksa-client
Browse files Browse the repository at this point in the history
Keep print only for things that can be printed in CLI
Adapt config to method used by other providers
Fixes #25
  • Loading branch information
erikbosch committed May 8, 2024
1 parent db00030 commit 3c0b289
Show file tree
Hide file tree
Showing 8 changed files with 180 additions and 50 deletions.
23 changes: 23 additions & 0 deletions docs/cli.md
Original file line number Diff line number Diff line change
Expand Up @@ -48,6 +48,29 @@ If you wish to connect to a VISS server e.g. `kuksa-val-server` (not using TLS),
kuksa-client ws://127.0.0.1:8090
```

## Logging

The log level of `kuksa-client` can be set using the LOG_LEVEL environment variable. The following levels are supported

* `error`
* `warning`
* `info` (default)
* `debug`


To set the log level to DEBUG

```console
$ LOG_LEVEL=debug kuksa-client
```

It is possible to control log level in detail.
The example below sets log level to DEBUG, but for asyncio INFO.

```console
$ LOG_LEVEL=debug,asyncio=info kuksa-client
```

## TLS with databroker

KUKSA Client uses TLS to connect to Databroker when the schema part of the server URI is `grpcs`.
Expand Down
15 changes: 5 additions & 10 deletions kuksa-client/kuksa_client/__main__.py
Original file line number Diff line number Diff line change
Expand Up @@ -41,13 +41,11 @@

from kuksa_client import KuksaClientThread
from kuksa_client import _metadata
from kuksa_client.kuksa_logger import KuksaLogger

scriptDir = os.path.dirname(os.path.realpath(__file__))

DEFAULT_KUKSA_ADDRESS = os.environ.get("KUKSA_ADDRESS", "grpc://127.0.0.1:55555")
DEFAULT_LOGGING_CONFIG = os.environ.get(
"LOGGING_CONFIG", os.path.join(scriptDir, "logging.ini")
)
DEFAULT_TOKEN_OR_TOKENFILE = os.environ.get("TOKEN_OR_TOKENFILE", None)
DEFAULT_CERTIFICATE = os.environ.get("CERTIFICATE", None)
DEFAULT_KEYFILE = os.environ.get("KEYFILE", None)
Expand Down Expand Up @@ -667,6 +665,10 @@ def do_version(self, _args):
# Main Function

def main():

kuksa_logger = KuksaLogger()
kuksa_logger.init_logging()

parser = argparse.ArgumentParser()
parser.add_argument(
"server",
Expand All @@ -675,11 +677,6 @@ def main():
Supported protocols: [grpc, grpcs, ws, wss]. Example: {DEFAULT_KUKSA_ADDRESS}",
default=DEFAULT_KUKSA_ADDRESS,
)
parser.add_argument(
"--logging-config",
default=DEFAULT_LOGGING_CONFIG,
help="Path to logging configuration file",
)
parser.add_argument(
"--token_or_tokenfile",
default=DEFAULT_TOKEN_OR_TOKENFILE,
Expand Down Expand Up @@ -716,8 +713,6 @@ def main():

args = parser.parse_args()

logging.config.fileConfig(args.logging_config)

clientApp = TestClient(
args.server,
token_or_tokenfile=args.token_or_tokenfile,
Expand Down
7 changes: 5 additions & 2 deletions kuksa-client/kuksa_client/_metadata.py
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,9 @@
# SPDX-License-Identifier: Apache-2.0
########################################################################


import logging

__all__ = (
"__title__",
"__summary__",
Expand Down Expand Up @@ -56,5 +59,5 @@
__license__ = metadata["license"]

except importlib_metadata.PackageNotFoundError as e:
print(e)
print("skip configuring metadata")
logger = logging.getLogger(__name__)
logger.info("skip configuring metadata", e)
17 changes: 12 additions & 5 deletions kuksa-client/kuksa_client/cli_backend/grpc.py
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@
from typing import Optional
import uuid
import os
import logging

from kuksa_client import cli_backend
import kuksa_client.grpc
Expand All @@ -36,9 +37,15 @@
from kuksa.val.v1 import types_pb2


logger = logging.getLogger(__name__)


def callback_wrapper(callback: Callable[[str], None]) -> Callable[[Iterable[EntryUpdate]], None]:
def wrapper(updates: Iterable[EntryUpdate]) -> None:
callback(json.dumps([update.to_dict() for update in updates], cls=DatabrokerEncoder))
try:
callback(json.dumps([update.to_dict() for update in updates], cls=DatabrokerEncoder))
except Exception as e:
logger.error("Callback could not be executed", e)
return wrapper


Expand Down Expand Up @@ -93,7 +100,7 @@ def connection_established(self) -> bool:
def stop(self):
self.disconnect()
self.run = False
print("gRPC channel disconnected.")
logger.info("gRPC channel disconnected.")

# Function to implement fetching of metadata
def getMetaData(self, path: str, timeout=5):
Expand Down Expand Up @@ -264,14 +271,14 @@ async def _grpcHandler(self, vss_client: kuksa_client.grpc.aio.VSSClient):

# Update VSS Tree Entry
def updateVSSTree(self, jsonStr, timeout=5):
print("Command not supported by KUKSA Databroker or KUKSA gRPC!")
logger.warning("Command not supported by KUKSA Databroker or KUKSA gRPC!")

# Main loop for handling gRPC communication
async def mainLoop(self):
if self.insecure:

async with kuksa_client.grpc.aio.VSSClient(self.serverIP, self.serverPort, token=self.token) as vss_client:
print("gRPC channel connected.")
logger.info("gRPC channel connected.")
await self._grpcHandler(vss_client)
else:
async with kuksa_client.grpc.aio.VSSClient(
Expand All @@ -283,5 +290,5 @@ async def mainLoop(self):
tls_server_name=self.tls_server_name,
token=self.token
) as vss_client:
print("Secure gRPC channel connected.")
logger.info("Secure gRPC channel connected.")
await self._grpcHandler(vss_client)
23 changes: 13 additions & 10 deletions kuksa-client/kuksa_client/cli_backend/ws.py
Original file line number Diff line number Diff line change
Expand Up @@ -26,11 +26,14 @@
import ssl
import time
import uuid
import logging

import websockets

from kuksa_client import cli_backend

logger = logging.getLogger(__name__)


class Backend(cli_backend.Backend):
def __init__(self, config):
Expand Down Expand Up @@ -58,7 +61,7 @@ async def _receiver_handler(self, webSocket):
self.subscriptionCallbacks[resJson["subscriptionId"]](
message)
except Exception as e: # pylint: disable=broad-except
print(e)
logger.warning("Receiver Handler exception", e)

async def _sender_handler(self, webSocket):
while self.run:
Expand All @@ -68,7 +71,7 @@ async def _sender_handler(self, webSocket):
except queue.Empty:
await asyncio.sleep(0.01)
except Exception as e: # pylint: disable=broad-except
print(e)
logger.warning("Sender Handler exception", e)
return

async def _msgHandler(self, webSocket):
Expand Down Expand Up @@ -113,7 +116,7 @@ def _sendReceiveMsg(self, req, timeout):
def stop(self):
self.ws_connection_established = False
self.run = False
print("Server disconnected.")
logger.info("Server disconnected.")

def disconnect(self, _):
self.stop()
Expand Down Expand Up @@ -302,7 +305,7 @@ async def connect(self, _=None):
# If using your own certificates make sure that name is included or use tls_server_name work-around
context.check_hostname = True
try:
print("connect to wss://"+self.serverIP+":"+str(self.serverPort))
logger.info("connect to wss://"+self.serverIP+":"+str(self.serverPort))
args = {
"uri": "wss://"+self.serverIP+":"+str(self.serverPort),
"ssl": context,
Expand All @@ -316,22 +319,22 @@ async def connect(self, _=None):

async with websockets.connect(**args) as ws:
self.subprotocol = ws.subprotocol
print(f"Websocket connected. Negotiated subprotocol {self.subprotocol}")
logger.info(f"Websocket connected. Negotiated subprotocol {self.subprotocol}")
await self._msgHandler(ws)
except OSError as e:
print("Disconnected!! " + str(e))
logger.warning("Disconnected!!", e)
else:
try:
uri = "ws://"+self.serverIP+":"+str(self.serverPort)
print(f"connect to {uri}")
logger.info("connect to %s", uri)
async with websockets.connect(uri, subprotocols=subprotocols) as ws:
self.subprotocol = ws.subprotocol
if self.subprotocol == "VISSv2":
print("subprotocol matches condition")
print(f"Websocket connected. Negotiated subprotocol {self.subprotocol}")
logger.info("subprotocol matches condition")
logger.info("Websocket connected. Negotiated subprotocol %s", self.subprotocol)
await self._msgHandler(ws)
except OSError as e:
print("Disconnected!! " + str(e))
logger.warning("Disconnected!!", e)

# Main loop for handling websocket communication
async def mainLoop(self):
Expand Down
1 change: 1 addition & 0 deletions kuksa-client/kuksa_client/grpc/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@
# SPDX-License-Identifier: Apache-2.0
########################################################################

from __future__ import absolute_import
import contextlib
import dataclasses
import datetime
Expand Down
121 changes: 121 additions & 0 deletions kuksa-client/kuksa_client/kuksa_logger/__init__.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,121 @@
# /********************************************************************************
# * Copyright (c) 2024 Contributors to the Eclipse Foundation
# *
# * See the NOTICE file(s) distributed with this work for additional
# * information regarding copyright ownership.
# *
# * This program and the accompanying materials are made available under the
# * terms of the Apache License 2.0 which is available at
# * http://www.apache.org/licenses/LICENSE-2.0
# *
# * SPDX-License-Identifier: Apache-2.0
# ********************************************************************************/

# This file contains a logger that could be useful for clients using kuksa-python-sdk

import logging
import sys
import os


class KuksaLogger:
def init_logging(self):
# Example
#
# Set log level to debug
# LOG_LEVEL=debug kuksa-client
#
# Set log level to INFO, but for dbcfeederlib.databrokerclientwrapper set it to DEBUG
# LOG_LEVEL=info,dbcfeederlib.databrokerclientwrapper=debug kuksa-client
#
#

loglevels = self.parse_env_log(os.environ.get("LOG_LEVEL"))

# set root loglevel etc
self.init_root_logging(loglevels["root"])

# set loglevels for other loggers
for logger, level in loglevels.items():
if logger != "root":
logging.getLogger(logger).setLevel(level)

def init_root_logging(self, loglevel):
"""Set up console logger"""
# create console handler and set level to debug. This just means that it can show DEBUG messages.
# What actually is shown is controlled by logging configuration
console_logger = logging.StreamHandler()
console_logger.setLevel(logging.DEBUG)

# create formatter
if sys.stdout.isatty():
formatter = ColorFormatter()
else:
formatter = logging.Formatter(
fmt="%(asctime)s %(levelname)s %(name)s: %(message)s"
)

# add formatter to console_logger
console_logger.setFormatter(formatter)

# add console_logger as a global handler
root_logger = logging.getLogger()
root_logger.setLevel(loglevel)
root_logger.addHandler(console_logger)

def parse_env_log(self, env_log, default=logging.INFO):
def parse_level(specified_level, default=default):
if isinstance(specified_level, str):
if specified_level.lower() in [
"debug",
"info",
"warn",
"warning",
"error",
"critical",
]:
return specified_level.upper()
raise ValueError(f"could not parse '{specified_level}' as a log level")
return default

parsed_loglevels = {}

if env_log is not None:
log_specs = env_log.split(",")
for log_spec in log_specs:
spec_parts = log_spec.split("=")
if len(spec_parts) == 1:
# This is a root level spec
if "root" in parsed_loglevels:
raise ValueError("multiple root loglevels specified")
parsed_loglevels["root"] = parse_level(spec_parts[0])
if len(spec_parts) == 2:
logger_name = spec_parts[0]
logger_level = spec_parts[1]
parsed_loglevels[logger_name] = parse_level(logger_level)

if "root" not in parsed_loglevels:
parsed_loglevels["root"] = default

return parsed_loglevels


class ColorFormatter(logging.Formatter):
"""Color formatter that can be used for terminals"""
FORMAT = "{time} {{loglevel}} {logger} {msg}".format(
time="\x1b[2m%(asctime)s\x1b[0m", # grey
logger="\x1b[2m%(name)s:\x1b[0m", # grey
msg="%(message)s",
)
FORMATS = {
logging.DEBUG: FORMAT.format(loglevel="\x1b[34mDEBUG\x1b[0m"), # blue
logging.INFO: FORMAT.format(loglevel="\x1b[32mINFO\x1b[0m"), # green
logging.WARNING: FORMAT.format(loglevel="\x1b[33mWARNING\x1b[0m"), # yellow
logging.ERROR: FORMAT.format(loglevel="\x1b[31mERROR\x1b[0m"), # red
logging.CRITICAL: FORMAT.format(loglevel="\x1b[31mCRITICAL\x1b[0m"), # red
}

def format(self, record):
log_fmt = self.FORMATS.get(record.levelno)
formatter = logging.Formatter(log_fmt)
return formatter.format(record)
23 changes: 0 additions & 23 deletions kuksa-client/kuksa_client/logging.ini

This file was deleted.

0 comments on commit 3c0b289

Please sign in to comment.