Coverage for pyTooling / Tracing / __init__.py: 85%
218 statements
« prev ^ index » next coverage.py v7.13.1, created at 2026-01-18 14:57 +0000
1# ==================================================================================================================== #
2# _____ _ _ _____ _ #
3# _ __ _ |_ _|__ ___ | (_)_ __ __ _|_ _| __ __ _ ___(_)_ __ __ _ #
4# | '_ \| | | || |/ _ \ / _ \| | | '_ \ / _` | | || '__/ _` |/ __| | '_ \ / _` | #
5# | |_) | |_| || | (_) | (_) | | | | | | (_| |_| || | | (_| | (__| | | | | (_| | #
6# | .__/ \__, ||_|\___/ \___/|_|_|_| |_|\__, (_)_||_| \__,_|\___|_|_| |_|\__, | #
7# |_| |___/ |___/ |___/ #
8# ==================================================================================================================== #
9# Authors: #
10# Patrick Lehmann #
11# #
12# License: #
13# ==================================================================================================================== #
14# Copyright 2025-2026 Patrick Lehmann - Bötzingen, Germany #
15# #
16# Licensed under the Apache License, Version 2.0 (the "License"); #
17# you may not use this file except in compliance with the License. #
18# You may obtain a copy of the License at #
19# #
20# http://www.apache.org/licenses/LICENSE-2.0 #
21# #
22# Unless required by applicable law or agreed to in writing, software #
23# distributed under the License is distributed on an "AS IS" BASIS, #
24# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. #
25# See the License for the specific language governing permissions and #
26# limitations under the License. #
27# #
28# SPDX-License-Identifier: Apache-2.0 #
29# ==================================================================================================================== #
30#
31"""Tools for software execution tracing."""
32from datetime import datetime
33from time import perf_counter_ns
34from threading import local
35from types import TracebackType
36from typing import Optional as Nullable, List, Iterator, Type, Self, Iterable, Dict, Any, Tuple
39try:
40 from pyTooling.Decorators import export, readonly
41 from pyTooling.MetaClasses import ExtendedType
42 from pyTooling.Exceptions import ToolingException
43 from pyTooling.Common import getFullyQualifiedName
44except (ImportError, ModuleNotFoundError): # pragma: no cover
45 print("[pyTooling.Tracing] Could not import from 'pyTooling.*'!")
47 try:
48 from Decorators import export, readonly
49 from MetaClasses import ExtendedType
50 from Exceptions import ToolingException
51 from Common import getFullyQualifiedName
52 except (ImportError, ModuleNotFoundError) as ex: # pragma: no cover
53 print("[pyTooling.Tracing] Could not import directly!")
54 raise ex
57__all__ = ["_threadLocalData"]
59_threadLocalData = local()
60"""A reference to the thread local data needed by the pyTooling.Tracing classes."""
63@export
64class TracingException(ToolingException):
65 """Base-exception of all exceptions raised by :mod:`pyTooling.Tracing`."""
68@export
69class Event(metaclass=ExtendedType, slots=True):
70 """
71 Represents a named event within a timespan (:class:`Span`) used in a software execution trace.
73 It may contain arbitrary attributes (key-value pairs).
74 """
75 _name: str #: Name of the event.
76 _parent: Nullable["Span"] #: Reference to the parent span.
77 _time: Nullable[datetime] #: Timestamp of the event.
78 _dict: Dict[str, Any] #: Dictionary of associated attributes.
80 def __init__(self, name: str, time: Nullable[datetime] = None, parent: Nullable["Span"] = None) -> None:
81 """
82 Initializes a named event.
84 :param name: The name of the event.
85 :param time: The optional time when the event happened.
86 :param parent: Reference to the parent span.
87 """
88 if isinstance(name, str): 88 ↛ 94line 88 didn't jump to line 94 because the condition on line 88 was always true
89 if name == "": 89 ↛ 90line 89 didn't jump to line 90 because the condition on line 89 was never true
90 raise ValueError(f"Parameter 'name' is empty.")
92 self._name = name
93 else:
94 ex = TypeError("Parameter 'name' is not of type 'str'.")
95 ex.add_note(f"Got type '{getFullyQualifiedName(name)}'.")
96 raise ex
98 if time is None: 98 ↛ 100line 98 didn't jump to line 100 because the condition on line 98 was always true
99 self._time = None
100 elif isinstance(time, datetime):
101 self._time = time
102 else:
103 ex = TypeError("Parameter 'time' is not of type 'datetime'.")
104 ex.add_note(f"Got type '{getFullyQualifiedName(time)}'.")
105 raise ex
107 if parent is None:
108 self._parent = None
109 elif isinstance(parent, Span): 109 ↛ 113line 109 didn't jump to line 113 because the condition on line 109 was always true
110 self._parent = parent
111 parent._events.append(self)
112 else:
113 ex = TypeError("Parameter 'parent' is not of type 'Span'.")
114 ex.add_note(f"Got type '{getFullyQualifiedName(parent)}'.")
115 raise ex
117 self._dict = {}
119 @readonly
120 def Name(self) -> str:
121 """
122 Read-only property to access the event's name.
124 :returns: Name of the event.
125 """
126 return self._name
128 @readonly
129 def Time(self) -> datetime:
130 """
131 Read-only property to access the event's timestamp.
133 :returns: Timestamp of the event.
134 """
135 return self._time
137 @readonly
138 def Parent(self) -> Nullable["Span"]:
139 """
140 Read-only property to access the event's parent span.
142 :returns: Parent span.
143 """
144 return self._parent
146 def __getitem__(self, key: str) -> Any:
147 """
148 Read an event's attached attributes (key-value-pairs) by key.
150 :param key: The key to look for.
151 :returns: The value associated to the given key.
152 """
153 return self._dict[key]
155 def __setitem__(self, key: str, value: Any) -> None:
156 """
157 Create or update an event's attached attributes (key-value-pairs) by key.
159 If a key doesn't exist yet, a new key-value-pair is created.
161 :param key: The key to create or update.
162 :param value: The value to associate to the given key.
163 """
164 self._dict[key] = value
166 def __delitem__(self, key: str) -> None:
167 """
168 Remove an entry from event's attached attributes (key-value-pairs) by key.
170 :param key: The key to remove.
171 :raises KeyError: If key doesn't exist in the event's attributes.
172 """
173 del self._dict[key]
175 def __contains__(self, key: str) -> bool:
176 """
177 Checks if the key is an attached attribute (key-value-pairs) on this event.
179 :param key: The key to check.
180 :returns: ``True``, if the key is an attached attribute.
181 """
182 return key in self._dict
184 def __iter__(self) -> Iterator[Tuple[str, Any]]:
185 """
186 Returns an iterator to iterate all associated attributes of this event as :pycode:`(key, value)` tuples.
188 :returns: Iterator to iterate all attributes.
189 """
190 return iter(self._dict.items())
192 def __len__(self) -> int:
193 """
194 Returns the number of attached attributes (key-value-pairs) on this event.
196 :returns: Number of attached attributes.
197 """
198 return len(self._dict)
200 def __str__(self) -> str:
201 """
202 Return a string representation of the event.
204 :returns: The event's name.
205 """
206 return self._name
209@export
210class Span(metaclass=ExtendedType, slots=True):
211 """
212 Represents a timespan (span) within another timespan or trace.
214 It may contain sub-spans, events and arbitrary attributes (key-value pairs).
215 """
216 _name: str #: Name of the timespan
217 _parent: Nullable["Span"] #: Reference to the parent span (or trace).
219 _beginTime: Nullable[datetime] #: Timestamp when the timespan begins.
220 _endTime: Nullable[datetime] #: Timestamp when the timespan ends.
221 _startTime: Nullable[int]
222 _stopTime: Nullable[int]
223 _totalTime: Nullable[int] #: Duration of this timespan in ns.
225 _spans: List["Span"] #: Sub-timespans
226 _events: List[Event] #: Events happened within this timespan
227 _dict: Dict[str, Any] #: Dictionary of associated attributes.
229 def __init__(self, name: str, parent: Nullable["Span"] = None) -> None:
230 """
231 Initializes a timespan as part of a software execution trace.
233 :param name: Name of the timespan.
234 :param parent: Reference to a parent span or trace.
235 """
236 if isinstance(name, str): 236 ↛ 242line 236 didn't jump to line 242 because the condition on line 236 was always true
237 if name == "": 237 ↛ 238line 237 didn't jump to line 238 because the condition on line 237 was never true
238 raise ValueError(f"Parameter 'name' is empty.")
240 self._name = name
241 else:
242 ex = TypeError("Parameter 'name' is not of type 'str'.")
243 ex.add_note(f"Got type '{getFullyQualifiedName(parent)}'.")
244 raise ex
246 if parent is None:
247 self._parent = None
248 elif isinstance(parent, Span): 248 ↛ 252line 248 didn't jump to line 252 because the condition on line 248 was always true
249 self._parent = parent
250 parent._spans.append(self)
251 else:
252 ex = TypeError("Parameter 'parent' is not of type 'Span'.")
253 ex.add_note(f"Got type '{getFullyQualifiedName(parent)}'.")
254 raise ex
256 self._beginTime = None
257 self._startTime = None
258 self._endTime = None
259 self._stopTime = None
260 self._totalTime = None
262 self._spans = []
263 self._events = []
264 self._dict = {}
266 @readonly
267 def Name(self) -> str:
268 """
269 Read-only property to access the timespan's name.
271 :returns: Name of the timespan.
272 """
273 return self._name
275 @readonly
276 def Parent(self) -> Nullable["Span"]:
277 """
278 Read-only property to access the span's parent span or trace.
280 :returns: Parent span.
281 """
282 return self._parent
284 def _AddSpan(self, span: "Span") -> Self:
285 self._spans.append(span)
286 span._parent = self
288 return span
290 @readonly
291 def HasSubSpans(self) -> bool:
292 """
293 Check if this timespan contains nested sub-spans.
295 :returns: ``True``, if the span has nested spans.
296 """
297 return len(self._spans) > 0
299 @readonly
300 def SubSpanCount(self) -> int:
301 """
302 Return the number of sub-spans within this span.
304 :return: Number of nested spans.
305 """
306 return len(self._spans)
308 # iterate subspans with optional predicate
309 def IterateSubSpans(self) -> Iterator["Span"]:
310 """
311 Returns an iterator to iterate all nested sub-spans.
313 :returns: Iterator to iterate all sub-spans.
314 """
315 return iter(self._spans)
317 @readonly
318 def HasEvents(self) -> bool:
319 """
320 Check if this timespan contains events.
322 :returns: ``True``, if the span has events.
323 """
324 return len(self._events) > 0
326 @readonly
327 def EventCount(self) -> int:
328 """
329 Return the number of events within this span.
331 :return: Number of events.
332 """
333 return len(self._events)
335 # iterate events with optional predicate
336 def IterateEvents(self) -> Iterator[Event]:
337 """
338 Returns an iterator to iterate all embedded events.
340 :returns: Iterator to iterate all events.
341 """
342 return iter(self._events)
344 @readonly
345 def StartTime(self) -> Nullable[datetime]:
346 """
347 Read-only property accessing the absolute time when the span was started.
349 :return: The time when the span was entered, otherwise None.
350 """
351 return self._beginTime
353 @readonly
354 def StopTime(self) -> Nullable[datetime]:
355 """
356 Read-only property accessing the absolute time when the span was stopped.
358 :return: The time when the span was exited, otherwise None.
359 """
360 return self._endTime
362 @readonly
363 def Duration(self) -> float:
364 """
365 Read-only property accessing the duration from start operation to stop operation.
367 If the span is not yet stopped, the duration from start to now is returned.
369 :return: Duration since span was started in seconds.
370 :raises TracingException: When span was never started.
371 """
372 if self._startTime is None:
373 raise TracingException(f"{self.__class__.__name__} was never started.")
375 return ((perf_counter_ns() - self._startTime) if self._stopTime is None else self._totalTime) / 1e9
377 @classmethod
378 def CurrentSpan(cls) -> "Span":
379 """
380 Class-method to return the currently active timespan (span) or ``None``.
382 :returns: Currently active span or ``None``.
383 """
384 global _threadLocalData
386 try:
387 currentSpan = _threadLocalData.currentSpan
388 except AttributeError:
389 currentSpan = None
391 return currentSpan
393 def __enter__(self) -> Self:
394 """
395 Implementation of the :ref:`context manager protocol's <context-managers>` ``__enter__(...)`` method.
397 A span will be started.
399 :return: The span itself.
400 """
401 global _threadLocalData
403 try:
404 currentSpan = _threadLocalData.currentSpan
405 except AttributeError:
406 ex = TracingException("Can't setup span. No active trace.")
407 ex.add_note("Use with-statement using 'Trace()' to setup software execution tracing.")
408 raise ex
410 _threadLocalData.currentSpan = currentSpan._AddSpan(self)
412 self._beginTime = datetime.now()
413 self._startTime = perf_counter_ns()
415 return self
417 def __exit__(
418 self,
419 exc_type: Nullable[Type[BaseException]] = None,
420 exc_val: Nullable[BaseException] = None,
421 exc_tb: Nullable[TracebackType] = None
422 ) -> Nullable[bool]:
423 """
424 Implementation of the :ref:`context manager protocol's <context-managers>` ``__exit__(...)`` method.
426 An active span will be stopped.
428 Exit the context and ......
430 :param exc_type: Exception type
431 :param exc_val: Exception instance
432 :param exc_tb: Exception's traceback.
433 :returns: ``None``
434 """
435 global _threadLocalData
437 self._stopTime = perf_counter_ns()
438 self._endTime = datetime.now()
439 self._totalTime = self._stopTime - self._startTime
441 currentSpan = _threadLocalData.currentSpan
442 _threadLocalData.currentSpan = currentSpan._parent
444 def __getitem__(self, key: str) -> Any:
445 """
446 Read an event's attached attributes (key-value-pairs) by key.
448 :param key: The key to look for.
449 :returns: The value associated to the given key.
450 """
451 return self._dict[key]
453 def __setitem__(self, key: str, value: Any) -> None:
454 """
455 Create or update an event's attached attributes (key-value-pairs) by key.
457 If a key doesn't exist yet, a new key-value-pair is created.
459 :param key: The key to create or update.
460 :param value: The value to associate to the given key.
461 """
462 self._dict[key] = value
464 def __delitem__(self, key: str) -> None:
465 """
466 Remove an entry from event's attached attributes (key-value-pairs) by key.
468 :param key: The key to remove.
469 :raises KeyError: If key doesn't exist in the event's attributes.
470 """
471 del self._dict[key]
473 def __contains__(self, key: str) -> bool:
474 """
475 Checks if the key is an attached attribute (key-value-pairs) on this event.
477 :param key: The key to check.
478 :returns: ``True``, if the key is an attached attribute.
479 """
480 return key in self._dict
482 def __iter__(self) -> Iterator[Tuple[str, Any]]:
483 """
484 Returns an iterator to iterate all associated attributes of this timespan as :pycode:`(key, value)` tuples.
486 :returns: Iterator to iterate all attributes.
487 """
488 return iter(self._dict.items())
490 def __len__(self) -> int:
491 """
492 Returns the number of attached attributes (key-value-pairs) on this event.
494 :returns: Number of attached attributes.
495 """
496 return len(self._dict)
498 def Format(self, indent: int = 1, columnSize: int = 25) -> Iterable[str]:
499 result = []
500 result.append(f"{' ' * indent}🕑{self._name:<{columnSize - 2 * indent}} {self._totalTime/1e6:8.3f} ms")
501 for span in self._spans:
502 result.extend(span.Format(indent + 1, columnSize))
504 return result
506 def __repr__(self) -> str:
507 return f"{self._name} -> {self._parent!r}"
509 def __str__(self) -> str:
510 """
511 Return a string representation of the timespan.
513 :returns: The span's name.
514 """
515 return self._name
518@export
519class Trace(Span):
520 """
521 Represents a software execution trace made up of timespans (:class:`Span`).
523 The trace is the top-most element in a tree of timespans. All timespans share the same *TraceID*, thus even in a
524 distributed software execution, timespans can be aggregated with delay in a centralized database and the flow of
525 execution can be reassembled by grouping all timespans with same *TraceID*. Execution order can be derived from
526 timestamps and parallel execution is represented by overlapping timespans sharing the same parent *SpanID*. Thus, the
527 tree structure can be reassembled by inspecting the parent *SpanID* relations within the same *TraceID*.
529 A trace may contain sub-spans, events and arbitrary attributes (key-value pairs).
530 """
532 def __init__(self, name: str) -> None:
533 """
534 Initializes a software execution trace.
536 :param name: Name of the trace.
537 """
538 super().__init__(name)
540 def __enter__(self) -> Self:
541 global _threadLocalData
543 # TODO: check if a trace is already setup
544 # try:
545 # currentTrace = _threadLocalData.currentTrace
546 # except AttributeError:
547 # pass
549 _threadLocalData.currentTrace = self
550 _threadLocalData.currentSpan = self
552 self._beginTime = datetime.now()
553 self._startTime = perf_counter_ns()
555 return self
557 def __exit__(
558 self,
559 exc_type: Nullable[Type[BaseException]] = None,
560 exc_val: Nullable[BaseException] = None,
561 exc_tb: Nullable[TracebackType] = None
562 ) -> Nullable[bool]:
563 """
564 Exit the context and ......
566 :param exc_type: Exception type
567 :param exc_val: Exception instance
568 :param exc_tb: Exception's traceback.
569 :returns: ``None``
570 """
571 global _threadLocalData
573 self._stopTime = perf_counter_ns()
574 self._endTime = datetime.now()
575 self._totalTime = self._stopTime - self._startTime
577 del _threadLocalData.currentTrace
578 del _threadLocalData.currentSpan
580 return None
582 @classmethod
583 def CurrentTrace(cls) -> "Trace":
584 """
585 Class-method to return the currently active trace or ``None``.
587 :returns: Currently active trace or ``None``.
588 """
589 try:
590 currentTrace = _threadLocalData.currentTrace
591 except AttributeError:
592 currentTrace = None
594 return currentTrace
596 def Format(self, indent: int = 0, columnSize: int = 25) -> Iterable[str]:
597 result = []
598 result.append(f"{' ' * indent}Software Execution Trace: {self._totalTime/1e6:8.3f} ms")
599 result.append(f"{' ' * indent}📉{self._name:<{columnSize - 2}} {self._totalTime/1e6:8.3f} ms")
600 for span in self._spans:
601 result.extend(span.Format(indent + 1, columnSize - 2))
603 return result