Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Python] Adjust logging levels in Python controller #34346

Merged
merged 1 commit into from
Jul 16, 2024
Merged

[Python] Adjust logging levels in Python controller #34346

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 5 additions & 3 deletions src/controller/python/chip/CertificateAuthority.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,8 @@
from chip.native import PyChipError
from chip.storage import PersistentStorage

LOGGER = logging.getLogger(__name__)


class CertificateAuthority:
''' This represents an operational Root Certificate Authority (CA) with a root key key pair with associated
Expand Down Expand Up @@ -64,7 +66,7 @@ def __init__(self, chipStack: ChipStack.ChipStack, caIndex: int, persistentStora
persistentStorage: An optional reference to a PersistentStorage object. If one is provided, it will pick that over
the default PersistentStorage object retrieved from the chipStack.
'''
self.logger().warning(f"New CertificateAuthority at index {caIndex}")
LOGGER.info(f"New CertificateAuthority at index {caIndex}")

self._chipStack = chipStack
self._caIndex = caIndex
Expand Down Expand Up @@ -105,7 +107,7 @@ def LoadFabricAdminsFromStorage(self):
if (not (self._isActive)):
raise RuntimeError("Object isn't active")

self.logger().warning("Loading fabric admins from storage...")
LOGGER.info("Loading fabric admins from storage...")

caList = self._persistentStorage.GetReplKey(key='caList')
if (str(self._caIndex) not in caList):
Expand Down Expand Up @@ -244,7 +246,7 @@ def LoadAuthoritiesFromStorage(self):
if (not (self._isActive)):
raise RuntimeError("Object is not active")

self.logger().warning("Loading certificate authorities from storage...")
LOGGER.info("Loading certificate authorities from storage...")

#
# Persist details to storage (read modify write).
Expand Down
33 changes: 17 additions & 16 deletions src/controller/python/chip/ChipDeviceCtrl.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -61,6 +61,8 @@
# Defined in $CHIP_ROOT/src/lib/core/CHIPError.h
CHIP_ERROR_TIMEOUT: int = 50

LOGGER = logging.getLogger(__name__)

_DevicePairingDelegate_OnPairingCompleteFunct = CFUNCTYPE(None, PyChipError)
_DeviceUnpairingCompleteFunct = CFUNCTYPE(None, c_uint64, PyChipError)
_DevicePairingDelegate_OnCommissioningCompleteFunct = CFUNCTYPE(
Expand Down Expand Up @@ -401,17 +403,17 @@ def __init__(self, name: str = ''):
def _set_dev_ctrl(self, devCtrl, pairingDelegate):
def HandleCommissioningComplete(nodeId: int, err: PyChipError):
if err.is_success:
logging.info("Commissioning complete")
LOGGER.info("Commissioning complete")
else:
logging.warning("Failed to commission: {}".format(err))
LOGGER.warning("Failed to commission: {}".format(err))

self._dmLib.pychip_DeviceController_SetIcdRegistrationParameters(False, None)

if self._dmLib.pychip_TestCommissionerUsed():
err = self._dmLib.pychip_GetCompletionError()

if self._commissioning_context.future is None:
logging.exception("HandleCommissioningComplete called unexpectedly")
LOGGER.exception("HandleCommissioningComplete called unexpectedly")
return

if err.is_success:
Expand All @@ -425,14 +427,14 @@ def HandleFabricCheck(nodeId):
def HandleOpenWindowComplete(nodeid: int, setupPinCode: int, setupManualCode: str,
setupQRCode: str, err: PyChipError) -> None:
if err.is_success:
logging.info("Open Commissioning Window complete setting nodeid {} pincode to {}".format(nodeid, setupPinCode))
LOGGER.info("Open Commissioning Window complete setting nodeid {} pincode to {}".format(nodeid, setupPinCode))
commissioningParameters = CommissioningParameters(
setupPinCode=setupPinCode, setupManualCode=setupManualCode.decode(), setupQRCode=setupQRCode.decode())
else:
logging.warning("Failed to open commissioning window: {}".format(err))
LOGGER.warning("Failed to open commissioning window: {}".format(err))

if self._open_window_context.future is None:
logging.exception("HandleOpenWindowComplete called unexpectedly")
LOGGER.exception("HandleOpenWindowComplete called unexpectedly")
return

if err.is_success:
Expand All @@ -442,12 +444,12 @@ def HandleOpenWindowComplete(nodeid: int, setupPinCode: int, setupManualCode: st

def HandleUnpairDeviceComplete(nodeid: int, err: PyChipError):
if err.is_success:
logging.info("Succesfully unpaired device with nodeid {}".format(nodeid))
LOGGER.info("Succesfully unpaired device with nodeid {}".format(nodeid))
else:
logging.warning("Failed to unpair device: {}".format(err))
LOGGER.warning("Failed to unpair device: {}".format(err))

if self._unpair_device_context.future is None:
logging.exception("HandleUnpairDeviceComplete called unexpectedly")
LOGGER.exception("HandleUnpairDeviceComplete called unexpectedly")
return

if err.is_success:
Expand All @@ -457,9 +459,9 @@ def HandleUnpairDeviceComplete(nodeid: int, err: PyChipError):

def HandlePASEEstablishmentComplete(err: PyChipError):
if not err.is_success:
logging.warning("Failed to establish secure session to device: {}".format(err))
LOGGER.warning("Failed to establish secure session to device: {}".format(err))
else:
logging.info("Established secure session with Device")
LOGGER.info("Established secure session with Device")

if self._commissioning_context.future is not None:
# During Commissioning, HandlePASEEstablishmentComplete will also be called.
Expand All @@ -469,7 +471,7 @@ def HandlePASEEstablishmentComplete(err: PyChipError):
return

if self._pase_establishment_context.future is None:
logging.exception("HandlePASEEstablishmentComplete called unexpectedly")
LOGGER.exception("HandlePASEEstablishmentComplete called unexpectedly")
return

if err.is_success:
Expand Down Expand Up @@ -926,7 +928,7 @@ def GetConnectedDeviceSync(self, nodeid, allowPASE=True, timeoutMs: int = None):
res = self._ChipStack.Call(lambda: self._dmLib.pychip_GetDeviceBeingCommissioned(
self.devCtrl, nodeid, byref(returnDevice)), timeoutMs)
if res.is_success:
logging.info('Using PASE connection')
LOGGER.info('Using PASE connection')
return DeviceProxyWrapper(returnDevice, DeviceProxyWrapper.DeviceProxyType.COMMISSIONEE, self._dmLib)

class DeviceAvailableClosure():
Expand Down Expand Up @@ -992,7 +994,7 @@ async def GetConnectedDevice(self, nodeid, allowPASE: bool = True, timeoutMs: in
res = await self._ChipStack.CallAsync(lambda: self._dmLib.pychip_GetDeviceBeingCommissioned(
self.devCtrl, nodeid, byref(returnDevice)), timeoutMs)
if res.is_success:
logging.info('Using PASE connection')
LOGGER.info('Using PASE connection')
return DeviceProxyWrapper(returnDevice, DeviceProxyWrapper.DeviceProxyType.COMMISSIONEE, self._dmLib)

eventLoop = asyncio.get_running_loop()
Expand Down Expand Up @@ -1348,7 +1350,6 @@ def _parseEventPathTuple(self, pathTuple: typing.Union[
# Wildcard
return ClusterAttribute.EventPath()
elif not isinstance(pathTuple, tuple):
logging.debug(type(pathTuple))
if isinstance(pathTuple, int):
return ClusterAttribute.EventPath(EndpointId=pathTuple)
elif issubclass(pathTuple, ClusterObjects.Cluster):
Expand Down Expand Up @@ -2115,7 +2116,7 @@ async def CommissionIP(self, ipaddr: str, setupPinCode: int, nodeid: int) -> int

def NOCChainCallback(self, nocChain):
if self._issue_node_chain_context.future is None:
logging.exception("NOCChainCallback while not expecting a callback")
LOGGER.exception("NOCChainCallback while not expecting a callback")
return
self._issue_node_chain_context.future.set_result(nocChain)
return
Expand Down
10 changes: 4 additions & 6 deletions src/controller/python/chip/FabricAdmin.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,8 @@
from chip.crypto import p256keypair
from chip.native import GetLibraryHandle

LOGGER = logging.getLogger(__name__)


class FabricAdmin:
''' Administers a fabric associated with a unique FabricID under a given CertificateAuthority
Expand All @@ -34,10 +36,6 @@ class FabricAdmin:
def _Handle(cls):
return GetLibraryHandle()

@classmethod
def logger(cls):
return logging.getLogger('FabricAdmin')

def __init__(self, certificateAuthority: CertificateAuthority.CertificateAuthority, vendorId: int, fabricId: int = 1):
''' Initializes the object.

Expand All @@ -60,7 +58,7 @@ def __init__(self, certificateAuthority: CertificateAuthority.CertificateAuthori
self._fabricId = fabricId
self._certificateAuthority = certificateAuthority

self.logger().warning(f"New FabricAdmin: FabricId: 0x{self._fabricId:016X}, VendorId = 0x{self.vendorId:04X}")
LOGGER.info(f"New FabricAdmin: FabricId: 0x{self._fabricId:016X}, VendorId = 0x{self.vendorId:04X}")

self._isActive = True
self._activeControllers = []
Expand Down Expand Up @@ -94,7 +92,7 @@ def NewController(self, nodeId: int = None, paaTrustStorePath: str = "",
if (nodeId in nodeIdList):
raise RuntimeError(f"Provided NodeId {nodeId} collides with an existing controller instance!")

self.logger().warning(
LOGGER.info(
f"Allocating new controller with CaIndex: {self._certificateAuthority.caIndex}, "
f"FabricId: 0x{self._fabricId:016X}, NodeId: 0x{nodeId:016X}, CatTags: {catTags}")

Expand Down
19 changes: 10 additions & 9 deletions src/controller/python/chip/clusters/Attribute.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,8 @@

from .ClusterObjects import Cluster, ClusterAttributeDescriptor, ClusterEvent

LOGGER = logging.getLogger(__name__)


@unique
class EventTimestampType(Enum):
Expand Down Expand Up @@ -569,7 +571,7 @@ def subscriptionId(self) -> int:

def Shutdown(self):
if (self._isDone):
print("Subscription was already terminated previously!")
LOGGER.warning("Subscription 0x%08x was already terminated previously!", self.subscriptionId)
return

handle = chip.native.GetLibraryHandle()
Expand Down Expand Up @@ -675,7 +677,7 @@ def handleAttributeData(self, path: AttributePath, dataVersion: int, status: int
self._changedPathSet.add(path)

except Exception as ex:
logging.exception(ex)
LOGGER.exception(ex)

def handleEventData(self, header: EventHeader, path: EventPath, data: bytes, status: int):
try:
Expand All @@ -693,12 +695,12 @@ def handleEventData(self, header: EventHeader, path: EventPath, data: bytes, sta
try:
eventValue = eventType.FromTLV(data)
except Exception as ex:
logging.error(
LOGGER.error(
f"Error convering TLV to Cluster Object for path: Endpoint = {path.EndpointId}/"
f"Cluster = {path.ClusterId}/Event = {path.EventId}")
logging.error(
LOGGER.error(
f"Failed Cluster Object: {str(eventType)}")
logging.error(ex)
LOGGER.error(ex)
eventValue = ValueDecodeFailure(
tlvData, ex)

Expand All @@ -715,7 +717,7 @@ def handleEventData(self, header: EventHeader, path: EventPath, data: bytes, sta
eventResult, self._subscription_handler)

except Exception as ex:
logging.exception(ex)
LOGGER.exception(ex)

def handleError(self, chipError: PyChipError):
self._resultError = chipError
Expand All @@ -726,7 +728,6 @@ def _handleSubscriptionEstablished(self, subscriptionId):
self, subscriptionId, self._devCtrl)
self._future.set_result(self._subscription_handler)
else:
logging.info("Re-subscription succeeded!")
if self._subscription_handler._onResubscriptionSucceededCb is not None:
if (self._subscription_handler._onResubscriptionSucceededCb_isAsync):
self._event_loop.create_task(
Expand Down Expand Up @@ -761,7 +762,7 @@ def _handleReportEnd(self):
attribute_path = TypedAttributePath(Path=change)
except (KeyError, ValueError) as err:
# path could not be resolved into a TypedAttributePath
logging.getLogger(__name__).exception(err)
LOGGER.exception(err)
continue
self._subscription_handler.OnAttributeChangeCb(
attribute_path, self._subscription_handler)
Expand Down Expand Up @@ -816,7 +817,7 @@ def handleResponse(self, path: AttributePath, status: int):
imStatus = chip.interaction_model.Status(status)
self._resultData.append(AttributeWriteResult(Path=path, Status=imStatus))
except ValueError as ex:
logging.exception(ex)
LOGGER.exception(ex)

def handleError(self, chipError: PyChipError):
self._resultError = chipError
Expand Down
31 changes: 14 additions & 17 deletions src/controller/python/chip/storage/__init__.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,8 @@
import chip.exceptions
import chip.native

LOGGER = logging.getLogger(__name__)

_SyncSetKeyValueCbFunct = CFUNCTYPE(
None, py_object, c_char_p, POINTER(c_char), c_uint16)
_SyncGetKeyValueCbFunct = CFUNCTYPE(
Expand Down Expand Up @@ -91,9 +93,6 @@ class PersistentStorage:

Object must be resident before the Matter stack starts up and last past its shutdown.
'''
@classmethod
def logger(cls):
return logging.getLogger('PersistentStorage')

def __init__(self, path: str = None, jsonData: Dict = None):
''' Initializes the object with either a path to a JSON file that contains the configuration OR
Expand All @@ -109,9 +108,9 @@ def __init__(self, path: str = None, jsonData: Dict = None):
raise ValueError("Can't provide both a valid path and jsonData")

if (path is not None):
self.logger().warn(f"Initializing persistent storage from file: {path}")
LOGGER.info(f"Initializing persistent storage from file: {path}")
else:
self.logger().warn("Initializing persistent storage from dict")
LOGGER.info("Initializing persistent storage from dict")

self._handle = chip.native.GetLibraryHandle()
self._isActive = True
Expand All @@ -125,24 +124,24 @@ def __init__(self, path: str = None, jsonData: Dict = None):
self._file.seek(0)

if (size != 0):
self.logger().warn(f"Loading configuration from {path}...")
LOGGER.info(f"Loading configuration from {path}...")
self._jsonData = json.load(self._file)
else:
self._jsonData = {}

except Exception as ex:
logging.error(ex)
logging.critical(f"Could not load configuration from {path} - resetting configuration...")
LOGGER.error(ex)
LOGGER.critical(f"Could not load configuration from {path} - resetting configuration...")
self._jsonData = {}
else:
self._jsonData = jsonData

if ('sdk-config' not in self._jsonData):
logging.warn("No valid SDK configuration present - clearing out configuration")
LOGGER.warn("No valid SDK configuration present - clearing out configuration")
self._jsonData['sdk-config'] = {}

if ('repl-config' not in self._jsonData):
logging.warn("No valid REPL configuration present - clearing out configuration")
LOGGER.warn("No valid REPL configuration present - clearing out configuration")
self._jsonData['repl-config'] = {}

# Clear out the file so that calling 'Commit' will re-open the file at that time in write mode.
Expand All @@ -166,7 +165,6 @@ def Commit(self):
''' Commits the cached JSON configuration to file (if one was provided in the constructor).
Otherwise, this is a no-op.
'''
self.logger().info("Committing...")

if (self._path is None):
return
Expand All @@ -175,9 +173,8 @@ def Commit(self):
try:
self._file = open(self._path, 'w')
except Exception as ex:
logging.warn(
f"Could not open {self._path} for writing configuration. Error:")
logging.warn(ex)
LOGGER.error(
f"Could not open {self._path} for writing configuration. Error: {ex}")
return

self._file.seek(0)
Expand All @@ -188,7 +185,7 @@ def Commit(self):
def SetReplKey(self, key: str, value):
''' Set a REPL key to a specific value. Creates the key if one doesn't exist already.
'''
self.logger().info(f"SetReplKey: {key} = {value}")
LOGGER.debug(f"SetReplKey: {key} = {value}")

if (key is None or key == ''):
raise ValueError("Invalid Key")
Expand All @@ -212,7 +209,7 @@ def GetReplKey(self, key: str):
def SetSdkKey(self, key: str, value: bytes):
''' Set an SDK key to a specific value. Creates the key if one doesn't exist already.
'''
self.logger().info(f"SetSdkKey: {key} = {value}")
LOGGER.debug(f"SetSdkKey: {key} = {value}")

if (key is None or key == ''):
raise ValueError("Invalid Key")
Expand All @@ -236,7 +233,7 @@ def GetSdkKey(self, key: str):
def DeleteSdkKey(self, key: str):
''' Deletes an SDK key if one exists.
'''
self.logger().info(f"DeleteSdkKey: {key}")
LOGGER.debug(f"DeleteSdkKey: {key}")

del (self._jsonData['sdk-config'][key])
self.Commit()
Expand Down
Loading