Fix default clearml logger level cannot be changed (#741)

clearml/backend_api/session/session.py

@@ -1,5 +1,6 @@
 from __future__ import print_function
 import json as json_lib
+import logging
 import os
 import sys
 import types
@@ -35,6 +36,7 @@ from .token_manager import TokenManager
 from ..config import load
 from ..utils import get_http_session_with_retry, urllib_log_warning_setup
 from ...debugging import get_logger
+from ...debugging.log import resolve_logging_level
 from ...utilities.pyhocon import ConfigTree, ConfigFactory
 from ...version import __version__
 from ...backend_config.utils import apply_files, apply_environment
@@ -142,16 +144,13 @@ class Session(TokenManager):
 
         self._verbose = verbose if verbose is not None else ENV_VERBOSE.get()
         self._logger = logger
+        if self._verbose and not self._logger:
+            level = resolve_logging_level(ENV_VERBOSE.get(converter=str))
+            self._logger = get_logger(level=level, stream=sys.stderr if level is logging.DEBUG else None)
+
         self.__auth_token = None
 
-        if not ENV_API_DEFAULT_REQ_METHOD.get(default=None) and self.config.get("api.http.default_method", None):
-            def_method = str(self.config.get("api.http.default_method", None)).strip()
-            if def_method.upper() not in ("GET", "POST", "PUT"):
-                raise ValueError(
-                    "api.http.default_method variable must be 'get' or 'post' (any case is allowed)."
-                )
-            Request.def_method = def_method
-            Request._method = Request.def_method
+        self._update_default_api_method()
 
         if ENV_AUTH_TOKEN.get():
             self.__access_key = self.__secret_key = None
@@ -372,8 +371,15 @@ class Session(TokenManager):
             else:
                 timeout = self._session_timeout
             try:
+                if self._verbose and self._logger:
+                    size = len(data or "")
+                    if json and self._logger.level == logging.DEBUG:
+                        size += len(json_lib.dumps(json))
+                    self._logger.debug("%s: %s [%d bytes, %d headers]", method.upper(), url, size, len(headers or {}))
                 res = self.__http_session.request(
-                    method, url, headers=headers, auth=auth, data=data, json=json, timeout=timeout)
+                    method, url, headers=headers, auth=auth, data=data, json=json, timeout=timeout, params=params)
+                if self._verbose and self._logger:
+                    self._logger.debug("--> took %s", res.elapsed)
             # except Exception as ex:
             except SSLError as ex:
                 retry_counter += 1

clearml/backend_config/config.py

@@ -2,6 +2,7 @@ from __future__ import print_function
 
 import functools
 import json
+import logging
 import os
 import sys
 import warnings
@@ -216,11 +217,19 @@ class Config(object):
                     file.parent.mkdir(parents=True, exist_ok=True)
                     file.touch()
 
+        loggers = logging_config.get("loggers", {})
+
+        for name, data in loggers.items():
+            if data.pop("force_level", True):
+                # Force the specified level (this is the default)
+                continue
+            if self._logger_exists(name):
+                # Use the currently defined level (don't change it)
+                data["level"] = logging.getLogger(name).level
+
         # remove dependency in deleted handlers
         root_logger = logging_config.get("root", None)
-        loggers = list(logging_config.get("loggers", {}).values()) + (
-            [root_logger] if root_logger else []
-        )
+        loggers = list(loggers.values()) + ([root_logger] if root_logger else [])
         for logger in loggers:
             handlers = logger.get("handlers", None)
             if not handlers:
@@ -233,6 +242,19 @@ class Config(object):
         initialize_log(logging_config, extra=extra)
         return True
 
+    @staticmethod
+    def _logger_exists(name):
+        """
+        Check if logger by this name exists.
+        If not already created, it will either not appear in logging.Logger.manager.loggerDict or will have a type
+        of logging.PlaceHolder
+        """
+        # noinspection PyBroadException
+        try:
+            return isinstance(logging.Logger.manager.loggerDict.get(name, None), logging.Logger)
+        except Exception:
+            pass
+
     def __getitem__(self, key):
         return self._config[key]
 

clearml/config/default/logging.conf

@@ -4,6 +4,9 @@
     loggers {
         clearml {
             level: INFO
+            # force the above-mentioned level even if such a logger already exists (default true)
+            # setting this to false causes clearml to preserve the log level if it was set before loading clearml
+            force_level: false
         }
         boto {
             level: WARNING

clearml/debugging/log.py

@@ -4,13 +4,48 @@ import logging
 import logging.handlers
 import os
 import sys
+from os import getenv
 from platform import system
+from typing import Optional, Union
 
 from pathlib2 import Path
 from six import BytesIO
 
 default_level = logging.INFO
 
+_levelToName = {
+    logging.CRITICAL: 'CRITICAL',
+    logging.ERROR: 'ERROR',
+    logging.WARNING: 'WARNING',
+    logging.INFO: 'INFO',
+    logging.DEBUG: 'DEBUG',
+    logging.NOTSET: 'NOTSET',
+}
+
+_nameToLevel = {
+    'CRITICAL': logging.CRITICAL,
+    'FATAL': logging.FATAL,
+    'ERROR': logging.ERROR,
+    'WARN': logging.WARNING,
+    'WARNING': logging.WARNING,
+    'INFO': logging.INFO,
+    'DEBUG': logging.DEBUG,
+    'NOTSET': logging.NOTSET,
+}
+
+
+def resolve_logging_level(level):
+    # type: (Union[str, int]) -> Optional[int]
+    # noinspection PyBroadException
+    try:
+        level = int(level)
+    except Exception:
+        pass
+    if isinstance(level, str):
+        return _nameToLevel.get(level.upper(), None)
+    if level in _levelToName:
+        return level
+
 
 class PickledLogger(logging.getLoggerClass()):
 
@@ -86,13 +121,28 @@ class LoggerRoot(object):
     def get_base_logger(cls, level=None, stream=sys.stdout, colored=False):
         if LoggerRoot.__base_logger:
             return LoggerRoot.__base_logger
+
+        # Note we can't use LOG_LEVEL_ENV_VAR defined in clearml.config.defs due to a circular dependency
+        if level is None and getenv("CLEARML_LOG_LEVEL"):
+            level = resolve_logging_level(getenv("CLEARML_LOG_LEVEL").strip())
+            if level is None:
+                print('Invalid value in environment variable CLEARML_LOG_LEVEL: %s' % getenv("CLEARML_LOG_LEVEL"))
+
+        clearml_logger = logging.getLogger('clearml')
+
+        if level is None:
+            level = clearml_logger.level
+
         # avoid nested imports
         from ..config import get_log_redirect_level
         LoggerRoot.__base_logger = PickledLogger.wrapper(
-            logging.getLogger('clearml'),
+            clearml_logger,
             func=cls.get_base_logger,
-            level=level, stream=stream, colored=colored)
-        level = level if level is not None else default_level
+            level=level,
+            stream=stream,
+            colored=colored
+        )
+
         LoggerRoot.__base_logger.setLevel(level)
 
         redirect_level = get_log_redirect_level()
@@ -149,7 +199,7 @@ def get_logger(path=None, level=None, stream=None, colored=False):
     except BaseException:
         # if for some reason we could not find the calling file, use our own
         path = os.path.abspath(__file__)
-    root_log = LoggerRoot.get_base_logger(level=default_level, stream=sys.stdout, colored=colored)
+    root_log = LoggerRoot.get_base_logger(stream=sys.stdout, colored=colored)
     log = root_log.getChild(Path(path).stem)
     if level is not None:
         log.setLevel(level)
@@ -157,6 +207,7 @@ def get_logger(path=None, level=None, stream=None, colored=False):
         ch = logging.StreamHandler(stream=stream)
         if level is not None:
             ch.setLevel(level)
+        log.addHandler(ch)
     log.propagate = True
     return PickledLogger.wrapper(
         log, func=get_logger, path=path, level=level, stream=stream, colored=colored)