Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
17 changes: 15 additions & 2 deletions .github/workflows/test.yml
Original file line number Diff line number Diff line change
Expand Up @@ -24,10 +24,10 @@ jobs:
PYMSBUILD_VERBOSE: true

steps:
- uses: actions/checkout@v2
- uses: actions/checkout@v4

- name: Set up Python ${{ matrix.python-version }}
uses: actions/setup-python@v2
uses: actions/setup-python@v5
with:
python-version: ${{ matrix.python-version }}

Expand All @@ -43,6 +43,19 @@ jobs:
run: |
python -m etwtrace --info
python -m etwtrace --info --instrumented
python -m etwtrace --info --diaghubtest
python -m pytest -vv
env:
PYTHONPATH: ${{ github.workspace }}\src

- name: Test build sdist
run: |
python -m pymsbuild sdist
python -m pip wheel (gi dist\*.tar.gz) -w dist
dir dist

- name: Test CLI from wheel install
run: |
python -m venv test-env
test-env/Scripts/python -m pip install (gi dist\*.whl) pytest
test-env/Scripts/python -m pytest -vv tests/test_cli.py
2 changes: 2 additions & 0 deletions .gitignore
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,8 @@ __pycache__/
/build/
/dist/
/env*/
/src/etwtrace/profiles/
/src/etwtrace/_version-ver.py
/venv*/
/.venv*/
*.pdb
Expand Down
53 changes: 40 additions & 13 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -6,19 +6,30 @@ It supports Python 3.9 and later on Windows 64-bit and Windows ARM64.

![Windows Performance Analyzer with a mixed Python/native flame graph](https://github.com/microsoft/python-etwtrace/raw/main/WPA-Python.png)

(Note that the WPA integration shown above requires an as-yet unreleased update.)

Two forms of profiling are supported:

* stack sampling, where regular CPU sampling will include Python calls
* instrumentation, where events are raised on entry/exit of Python functions

If you will inspect results using Windows Performance Analyzer (WPA),
then you will prefer stack sampling (the default).
If you will inspect results using [Windows Performance Analyzer](https://www.microsoft.com/store/productId/9N0W1B2BXGNZ?ocid=pdpshare)
(WPA), then you will prefer stack sampling (the default).
This method inserts additional native function calls in place of pure-Python calls,
and provides WPA with the metadata necessary to display the function.
Configure the provided [stack tags](https://learn.microsoft.com/en-us/windows-hardware/test/wpt/stack-tags)
file (`python -m etwtrace --stacktags`) in WPA and view the "Stack (Frame Tags)"
column to filter out internal Python calls.
You will need Python symbols for the best results;
these are an optional component in the installer from python.org.

If you are capturing ETW events some other way for analysis,
If you are capturing ETW events for some other form of analysis,
you may prefer more traditional instrumentation.
This method generates ETW events on entry and exit of each function.
This method generates ETW events on entry and exit of each function,
which can be reconstructed into call stacks at any point.
It also provides more accurate call count data than stack sampling.

![Windows Performance Analyzer with a call count, function info, and sequence views over instrumented data](https://github.com/microsoft/python-etwtrace/raw/main/WPA-Instrumented.png)

## Capturing events

Expand All @@ -32,11 +43,19 @@ and to export the results to an `.etl` file.
The trace must be started and stopped as Administrator, however,
the code under test may be run as a regular user.

For basic capture, use the `--capture` argument to have `etwtrace` launch and
stop `wpr`:

```
> python -m etwtrace --capture output.etl -- .\my-script.py
```

A [recording profile](https://learn.microsoft.com/windows-hardware/test/wpt/recording-profiles)
is used to select the event sources that will be recorded. We include a profile
configured for Python as [python.wprp](https://github.com/microsoft/python-etwtrace/blob/main/src/python.wprp).
We recommend downloading this file from here,
or finding it in the `etwtrace` package's install directory.
or finding it in the `etwtrace` package's install directory
by running `python -m etwtrace --profile`.

To record a Python trace:

Expand All @@ -63,7 +82,8 @@ The WPR docs above provide more information.

## Launching with tracing

To enable for a single command, launch with `-m etwtrace -- <script>`:
To enable for a single command, launch with `-m etwtrace -- <script>` or
`-m etwtrace -- -m <module>`:

```
> python -m etwtrace -- .\my-script.py arg1 arg2
Expand All @@ -72,7 +92,13 @@ To enable for a single command, launch with `-m etwtrace -- <script>`:
Pass `--instrumented` before the `--` to select that mode.

```
> python -m etwtrace --instrumented -- .\my-script.py arg1 arg2
> python -m etwtrace --instrumented -- -m test_module
```

Pass `--capture FILE` before the `--` to automatically start and stop `wpr`.

```
> python -m etwtrace --capture output.etl -- .\my-script.py arg1 arg2
```

To enable permanently for an environment, run the module with `--enable`:
Expand All @@ -85,14 +111,14 @@ Set %ETWTRACE_TYPE% to 'instrumented' to use instrumented events rather than sta

To enable permanently but only when an environment variable is set, also provide
the variable name. A second variable name may be provided to specify the kind
of tracing ('instrumented' (default) or 'stack'); if omitted, it will be derived
from the first.
of tracing ('instrumented' or 'stack' (default)); if omitted, the variable name
will be derived from the first.

```
> python -m etwtrace --enable PYTHON_ETW_TRACE
> python -m etwtrace --enable PYTHON_ETW_TRACE TRACE_TYPE
Created etwtrace.pth
Set %PYTHON_ETW_TRACE% to activate
Set %PYTHON_ETW_TRACE_TYPE% to 'instrumented' to use instrumented events rather than stacks
Set %TRACE_TYPE% to 'instrumented' to use instrumented events rather than stacks

> $env:PYTHON_ETW_TRACE = "1"
> python .\my-script.py arg1 arg2
Expand Down Expand Up @@ -140,7 +166,7 @@ The `PythonFunction` event provides the range of memory that will appear in
stack samples when the specified function is called. It can be used to map
sampled frames back to the source file and line number of the function being
executed. The `FunctionID` argument is a unique value for the lifetime of the
process representing the function, though it is not used in any other events.
process representing the function.

The `PythonThread` event typically comes as a range (using start and stop
opcodes) and is intended to highlight a region of interest. Similarly, the
Expand All @@ -149,7 +175,8 @@ opcodes) and is intended to highlight a region of interest. Similarly, the
The `PythonStackSample` event is primarily used by tests to force a stack sample
to be collected at a particular point in execution. When used for this, it
should be configured in the collection profile to include the stack, as there is
nothing inherent to the event that causes it.
nothing inherent to the event that causes collection. This event is raised by
the private and undocumented `_mark_stack` function.

The `PythonFunctionPush` and `PythonFunctionPop` events are raised in
instrumentation mode on entry and exit of a function. The `FunctionID` and
Expand Down
Binary file added WPA-Instrumented.png
Loading
Sorry, something went wrong. Reload?
Sorry, we cannot display this file.
Sorry, this file is invalid so it cannot be displayed.
30 changes: 25 additions & 5 deletions _msbuild.py
Original file line number Diff line number Diff line change
Expand Up @@ -54,10 +54,20 @@
),
]


PACKAGE = Package(
'etwtrace',
PyFile("etwtrace/*.py"),
File("python.wprp"),
PyFile("etwtrace/__main__.py"),
PyFile("etwtrace/__init__.py"),
PyFile("etwtrace/_cli.py"),
# _version-ver is generated at build with the correct version number
PyFile("etwtrace/_version-ver.py", name="_version.py"),

Package(
'profiles',
File("../python.wprp"),
File("../python.stacktags"),
),

PydFile(
'_etwtrace',
Expand Down Expand Up @@ -106,7 +116,7 @@
'DiagnosticsHub.InstrumentationCollector',
*PYD_OPTS,
CSourceFile('etwtrace/_diaghubstub.c'),
TargetExt='.dll'
TargetExt='.dll',
),
),
source='src',
Expand All @@ -121,5 +131,15 @@ def init_METADATA():
METADATA["Version"] = version


#def init_PACKAGE(tag=None):
# pass
def init_PACKAGE(tag=None):
# Create _version-ver.py with replaced %VERSION% from METADATA
VER_PY = PACKAGE.find("_version.py")
try:
f = open("src/etwtrace/_version.py", "r", encoding="utf-8")
except FileNotFoundError:
return
with f:
ver_py = f.read()
ver_py = ver_py.replace("%VERSION%", METADATA["Version"])
with open(f"src/etwtrace/_version-ver.py", "w", encoding="utf-8") as f:
f.write(ver_py)
File renamed without changes.
94 changes: 92 additions & 2 deletions src/etwtrace/__init__.py
Original file line number Diff line number Diff line change
@@ -1,3 +1,29 @@
"""Microsoft etwtrace for Python

Provides functionality for emitting tracing events using Windows ETW.
Enabling a tracer will hook function entry/exit events and produce
information suitable for capture by Windows Performance Recorder (WPR)
or another ETW logging tool.

StackSamplingTracer will inject Python frames into stack samples
captured by ETW. InstrumentedTracer will emit function entry and
exit events. Both emit a detailed event the first time a function
is called and later refer to it by ID.

The mark() function and mark_range() context manager emit an event
(or start/stop pair) with custom text. These are useful for identifying
spans of interest during analysis.

with etwtrace.StackSamplingTracer():
# Code to trace
etwtrace.mark("marker event")
with etwtrace.mark_range("start/stop span"):
# Code to trace
"""

__author__ = "Microsoft Corporation <python@microsoft.com>"
from ._version import __version__

_tracer = None


Expand Down Expand Up @@ -99,15 +125,27 @@ def disable(self):


def enable_if(enable_var, type_var):
from os import getenv as getenv
global enable_if
enable_if = lambda *a: None

from os import getenv as getenv
if enable_var and getenv(enable_var, "0").lower()[:1] in ("0", "n", "f"):
return

import sys
if sys.orig_argv[1:3] == ["-m", "etwtrace"]:
# Never trace ourselves
print("Skipping automatic tracing for etwtrace module", file=sys.stderr)
import traceback
return

trace_type = getenv(type_var, "").lower() if type_var else ""
if trace_type in ("stack",):
if trace_type in ("stack", ""):
tracer = StackSamplingTracer()
elif trace_type in ("diaghub",):
tracer = DiagnosticsHubTracer()
elif trace_type in ("diaghubtest",):
tracer = DiagnosticsHubTracer(stub=True)
elif trace_type in ("instrument", "instrumented"):
tracer = InstrumentedTracer()
else:
Expand All @@ -119,12 +157,14 @@ def enable_if(enable_var, type_var):


def mark(name):
"""Emits a mark event with the provided text."""
if not _tracer:
raise RuntimeError("unable to mark when global tracer is not enabled")
_tracer.mark(name)


def mark_range(name):
"""Context manager to emit start/stop mark events with the provided text."""
if not _tracer:
raise RuntimeError("unable to mark when global tracer is not enabled")
return _tracer.mark_range(name)
Expand All @@ -134,3 +174,53 @@ def _mark_stack(mark):
if not _tracer:
raise RuntimeError("unable to mark when global tracer is not enabled")
return _tracer._mark_stack(mark)


_TEMP_PROFILE = None

def _get_content_path(name, allow_direct=True):
global _TEMP_PROFILE
import etwtrace
import importlib.resources
import os
from pathlib import Path
path = importlib.resources.files(etwtrace) / "profiles" / name
# Return real files directly
if allow_direct and Path(str(path)).is_file():
return str(path)
try:
# Read contents (from embedded file?)
data = path.read_bytes()
except FileNotFoundError:
# Really doesn't exist, check if this is a dev layout
path = Path(__file__).absolute().parent
if path.parent.name == "src" and path.name == "etwtrace":
path = path.parent.parent / name
if path.is_file():
return str(path)
raise
if _TEMP_PROFILE is None:
import tempfile
_TEMP_PROFILE = tempfile.mkdtemp()
dest = os.path.join(_TEMP_PROFILE, name)
with open(dest, "wb") as f_out:
f_out.write(data)
return dest


def get_profile_path():
"""Returns the path to the default python.wprp profile.

In some circumstances, this may involve copying the file to a temporary
location and returning that path.
"""
return _get_content_path("python.wprp")


def get_stacktags_path():
"""Returns the path to the default python.wprp profile.

In some circumstances, this may involve copying the file to a temporary
location and returning that path.
"""
return _get_content_path("python.stacktags")
Loading