Skip to content

log

LogStreamHandler

Bases: StreamHandler

StreamHandler class.

This was originally designed to handle UTF errors in python 2.x hosts, however currently solely remains for backwards compatibility.

Source code in client/ayon_core/lib/log.py
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
class LogStreamHandler(logging.StreamHandler):
    """StreamHandler class.

    This was originally designed to handle UTF errors in python 2.x hosts,
    however currently solely remains for backwards compatibility.

    """

    def __init__(self, stream=None):
        super(LogStreamHandler, self).__init__(stream)
        self.enabled = True

    def enable(self):
        """Enable StreamHandler

        Make StreamHandler output again
        """
        self.enabled = True

    def disable(self):
        """Disable StreamHandler

        Used to silence output
        """
        self.enabled = False

    def emit(self, record):
        if not self.enabled or self.stream is None:
            return
        try:
            msg = self.format(record)
            msg = Terminal.log(msg)
            stream = self.stream
            stream.write(f"{msg}\n")
            self.flush()
        except (KeyboardInterrupt, SystemExit):
            raise

        except Exception:
            # Logging must never break the caller. Some hosts replace
            # 'sys.stdout' and 'sys.stderr' with streams that raise when
            # written to from a non-main thread, in which case reporting
            # the error through 'handleError' fails as well.
            try:
                self.handleError(record)
            except Exception:
                pass

disable()

Disable StreamHandler

Used to silence output

Source code in client/ayon_core/lib/log.py
44
45
46
47
48
49
def disable(self):
    """Disable StreamHandler

    Used to silence output
    """
    self.enabled = False

enable()

Enable StreamHandler

Make StreamHandler output again

Source code in client/ayon_core/lib/log.py
37
38
39
40
41
42
def enable(self):
    """Enable StreamHandler

    Make StreamHandler output again
    """
    self.enabled = True

Logger

Source code in client/ayon_core/lib/log.py
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
class Logger:
    DFT = "%(levelname)s >>> { %(name)s }: [ %(message)s ] "
    DBG = "  - { %(name)s }: [ %(message)s ] "
    INF = ">>> [ %(message)s ] "
    WRN = "*** WRN: >>> { %(name)s }: [ %(message)s ] "
    ERR = "!!! ERR: %(asctime)s >>> { %(name)s }: [ %(message)s ] "
    CRI = "!!! CRI: %(asctime)s >>> { %(name)s }: [ %(message)s ] "
    STD = "%(asctime)s %(levelname)8s [%(name)s]  %(funcName)s: %(message)s"

    FORMAT_FILE = {
        logging.INFO: STD if USE_STD_FMT else INF,
        logging.DEBUG: STD if USE_STD_FMT else DBG,
        logging.WARNING: STD if USE_STD_FMT else WRN,
        logging.ERROR: STD if USE_STD_FMT else ERR,
        logging.CRITICAL: STD if USE_STD_FMT else CRI,
    }

    # Is static class initialized
    initialized = False
    _init_lock = threading.Lock()
    _root_logger = None

    # Logging level - AYON_LOG_LEVEL
    log_level = None

    # Data same for all record documents
    process_data = None
    # Cached process name or ability to set different process name
    _process_name = None

    @classmethod
    @_deprecated_getter
    def get_logger(cls, name: str) -> logging.Logger:
        if not cls.initialized:
            cls.initialize()

        logger = logging.getLogger(name or "__main__")
        logger.setLevel(cls.log_level)
        logger.parent = cls._root_logger

        return logger

    @classmethod
    def get_root_logger(cls) -> logging.Logger:
        if not cls.initialized:
            cls.initialize()
        return cls._root_logger

    @classmethod
    def _get_console_handler(cls):
        formatter = LogFormatter(cls.FORMAT_FILE)
        console_handler = LogStreamHandler()

        console_handler.set_name("LogStreamHandler")
        console_handler.setFormatter(formatter)
        return console_handler

    @classmethod
    def initialize(cls):
        # TODO update already created loggers on re-initialization
        if not cls._init_lock.locked():
            with cls._init_lock:
                cls._initialize()
        else:
            # If lock is locked wait until is finished
            while cls._init_lock.locked():
                time.sleep(0.1)

    @classmethod
    def _initialize(cls):
        # Change initialization state to prevent runtime changes
        # if is executed during runtime
        cls.initialized = False

        # Define what is logging level
        log_level = os.getenv("AYON_LOG_LEVEL")
        if not log_level:
            # Check AYON_DEBUG for debug level
            op_debug = os.getenv("AYON_DEBUG")
            if op_debug and int(op_debug) > 0:
                log_level = 10
            else:
                log_level = 20
        cls.log_level = int(log_level)
        root_logger = logging.getLogger("AYON")
        root_logger.propagate = False
        root_logger.setLevel(cls.log_level)
        root_logger.addHandler(cls._get_console_handler())
        cls._root_logger = root_logger

        # Mark as initialized
        cls.initialized = True

    @classmethod
    def get_process_data(cls):
        """Data about current process which should be same for all records.

        Process data are used for each record sent to mongo database.
        """
        if cls.process_data is not None:
            return copy.deepcopy(cls.process_data)

        if not cls.initialized:
            cls.initialize()

        host_name = socket.gethostname()
        try:
            host_ip = socket.gethostbyname(host_name)
        except socket.gaierror:
            host_ip = "127.0.0.1"

        process_name = cls.get_process_name()

        cls.process_data = {
            "hostname": host_name,
            "hostip": host_ip,
            "username": getpass.getuser(),
            "system_name": platform.system(),
            "process_name": process_name,
        }
        return copy.deepcopy(cls.process_data)

    @classmethod
    def set_process_name(cls, process_name):
        """Set process name for mongo logs."""
        # Just change the attribute
        cls._process_name = process_name
        # Update process data if are already set
        if cls.process_data is not None:
            cls.process_data["process_name"] = process_name

    @classmethod
    def get_process_name(cls):
        """Process name that is like "label" of a process.

        AYON logging can be used from OpenPyppe itself of from hosts.
        Even in AYON process it's good to know if logs are from tray or
        from other cli commands. This should help to identify that information.
        """
        if cls._process_name is not None:
            return cls._process_name

        # Get process name
        process_name = os.environ.get("AYON_APP_NAME")
        if not process_name:
            try:
                import psutil

                process = psutil.Process(os.getpid())
                process_name = process.name()

            except ImportError:
                pass

        if not process_name:
            process_name = os.path.basename(sys.executable)

        cls._process_name = process_name
        return cls._process_name

get_process_data() classmethod

Data about current process which should be same for all records.

Process data are used for each record sent to mongo database.

Source code in client/ayon_core/lib/log.py
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
@classmethod
def get_process_data(cls):
    """Data about current process which should be same for all records.

    Process data are used for each record sent to mongo database.
    """
    if cls.process_data is not None:
        return copy.deepcopy(cls.process_data)

    if not cls.initialized:
        cls.initialize()

    host_name = socket.gethostname()
    try:
        host_ip = socket.gethostbyname(host_name)
    except socket.gaierror:
        host_ip = "127.0.0.1"

    process_name = cls.get_process_name()

    cls.process_data = {
        "hostname": host_name,
        "hostip": host_ip,
        "username": getpass.getuser(),
        "system_name": platform.system(),
        "process_name": process_name,
    }
    return copy.deepcopy(cls.process_data)

get_process_name() classmethod

Process name that is like "label" of a process.

AYON logging can be used from OpenPyppe itself of from hosts. Even in AYON process it's good to know if logs are from tray or from other cli commands. This should help to identify that information.

Source code in client/ayon_core/lib/log.py
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
@classmethod
def get_process_name(cls):
    """Process name that is like "label" of a process.

    AYON logging can be used from OpenPyppe itself of from hosts.
    Even in AYON process it's good to know if logs are from tray or
    from other cli commands. This should help to identify that information.
    """
    if cls._process_name is not None:
        return cls._process_name

    # Get process name
    process_name = os.environ.get("AYON_APP_NAME")
    if not process_name:
        try:
            import psutil

            process = psutil.Process(os.getpid())
            process_name = process.name()

        except ImportError:
            pass

    if not process_name:
        process_name = os.path.basename(sys.executable)

    cls._process_name = process_name
    return cls._process_name

set_process_name(process_name) classmethod

Set process name for mongo logs.

Source code in client/ayon_core/lib/log.py
249
250
251
252
253
254
255
256
@classmethod
def set_process_name(cls, process_name):
    """Set process name for mongo logs."""
    # Just change the attribute
    cls._process_name = process_name
    # Update process data if are already set
    if cls.process_data is not None:
        cls.process_data["process_name"] = process_name

log_timing(message)

Context manager to log the execution time of a code block.

Parameters:

Name Type Description Default
message str

Description of the operation being timed.

required

Yields:

Type Description
None

None

Example

with log_timing("Loading activities"): # Your code here data = fetch_data()

Source code in client/ayon_core/lib/log.py
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
@contextmanager
def log_timing(message: str) -> Generator[None, None, None]:
    """Context manager to log the execution time of a code block.

    Args:
        message (str): Description of the operation being timed.

    Yields:
        None

    Example:
        with log_timing("Loading activities"):
            # Your code here
            data = fetch_data()
    """

    if not _log_timing_enabled:
        yield
        return

    # Get the caller's function name with simple error handling
    func_name = "unknown"
    try:
        frame = inspect.currentframe()
        if frame and frame.f_back and frame.f_back.f_back:
            func_name = frame.f_back.f_back.f_code.co_name
    except (AttributeError, ValueError):
        pass  # Use default "unknown" if inspection fails

    start = time.perf_counter()
    try:
        yield
    finally:
        elapsed = time.perf_counter() - start
        _timing_logger.info(
            "TIMER:  %s :: %s took %.3f seconds",
            func_name,
            message,
            elapsed,
        )