xref: /aosp_15_r20/external/executorch/docs/source/delegate-debugging.md (revision 523fa7a60841cd1ecfb9cc4201f1ca8b03ed023a)
1# Delegate Debugging
2
3[Delegate backends](compiler-delegate-and-partitioner.md) are a prominent component of on-device models due to their flexibility in defining behavior. A side effect of this flexibility is that it operates as an opaque transformation. This obfuscates rich associations and mutations that are valuable in post-processing.
4- For example, if two different operator fusions were to occur within a delegate, post processing wouldn’t be able to separate the two transformations.
5
6Specifically, it makes associating runtime information (such as profiling results) through delegated graphs difficult. Delegate Debug Identifiers provides a framework through which delegate authors can propagate this information and utilize it for post run analysis.
7
8The preparation is broken down into three stages:
9- **Ahead-of-time (AOT)**: Delegate authors generate a __Debug Handle Map__.
10- **Runtime**: Delegate authors log using the __Delegate Debug Identifiers__ registered AOT in the __Debug Handle Map__.
11- **Deserialization**: Delegate authors provide a parser for custom metadata in delegate events.
12
13## Ahead-of-Time Integration
14Delegate authors propagate what transformations occur in a lowered backend by returning a **Debug Handle Map** from the backend implementation.
15
16### Generating a Debug Handle Map
17**Debug Handle Maps** communicate what transformations occurred in a backend by mapping **Delegate Debug Identifiers** to debug handles.
18
19**Delegate Debug Identifiers** are generated or user-provided identifiers for representing points of interest during runtime. Recall that debug handles are unique identifiers to operator instances in the model graph.
20
21For example:
22- **{ 0: (10, 11), 1: (11, 12) }:** Identifiers 0 and 1 in the runtime correspond to operators with the debug handles (10, 11) and (11, 12) respectively.
23- **{ “fused_op_1_2_3”: (11, 12, 15) }**: Identifier “fused_op_1_2_3” in the runtime corresponds to operators with debug handles (11, 12, 15), and 11, 12, 15 corresponds to the op 1, op 2 and op 3.
24
25```{Note}
26Identifiers are a means of connecting runtime results to the model graph; the interpretation of the identifiers is defined by the delegate author.
27```
28
29**Debug Handle Maps** are constructed through the use of **DelegateMappingBuilder** and returned as a part of `PreprocessResult`.
30
31```python
32class PreprocessResult:
33    processed_bytes: bytes = bytes()
34
35    debug_handle_map: Optional[
36        Union[Dict[int, Tuple[int]], Dict[str, Tuple[int]]]
37    ] = None
38```
39PreprocessResult is defined [here](https://github.com/pytorch/executorch/blob/main/exir/backend/backend_details.py).
40
41#### DelegateMappingBuilder
42`DelegateMappingBuilder` is a helper class for managing and constructing Debug Handle Maps. The result of the builder should be passed in when constructing PreprocessResult.
43
44`DelegateMappingBuilder` is defined [here](https://github.com/pytorch/executorch/blob/main/exir/backend/utils.py)
45
46A `DelegateMappingBuilder` instance can be constructed in one of 2 modes: manual identifiers or generated identifiers.
47
48```python
49# Manual Identifiers, Default
50builder = DelegateMappingBuilder(generated_identifiers=False)
51
52# Generated Identifiers
53builder = DelegateMappingBuilder(generated_identifiers=True)
54```
55
56With **manual identifiers**, users pass in a **Delegate Debug Identifier** when creating entries.
57With **generated identifiers**, the builder will auto-assign a **Delegate Debug Identifier**.
58
59To add an entry to the **Debug Handle Map**, use `insert_delegate_mapping_entry`. It associates one of `fx.Node(s)` or debug handles(s) (sourced from node.meta["debug_handle"]) to an optional **Delegate Debug Identifier** (used for the manual identifiers). The identifier recorded is returned from the call.
60
61```python
62def insert_delegate_mapping_entry(
63    self,
64    nodes: Optional[Union[Node, List[Node]]] = None,
65    handles: Optional[Union[int, List[int]]] = None,
66    identifier: Optional[Union[int, str]] = None,
67) -> Union[int, str]:
68```
69
70To retrieve the **Debug Handle Map**, use `get_delegate_mapping`.
71```python
72def get_delegate_mapping(
73    self,
74) -> Union[Dict[int, Tuple[int]], Dict[str, Tuple[int]]]
75```
76
77A demo of the AOT mapping can be found [here](https://github.com/pytorch/executorch/blob/main/exir/backend/test/backend_with_delegate_mapping_demo.py)
78
79
80## Runtime Logging
81Corresponding to the AOT map, the runtime then defines the functionality through which these events are logged.
82
83### Real-Time Logging
84
85ExecuTorch allows you to log in real time. **Real time Logging** is useful when timestamps are available as the execution occurs. It provides minimal overhead and is intuitive for authors to call.
86
87To log events in real-time (for example, explicitly denoting the profiling start and stop), `event_tracer_start_profiling_delegate` is used to create an `EventEntry` and `event_tracer_end_profiling_delegate` is used to conclude the `EventEntry` for the provided `EventTracer`.
88
89To start an `EventTracerEntry` using `event_tracer_start_profiling_delegate`, the **Delegate Debug Identifier** (provided AOT to the `debug_handle_map`) is passed as either the name or `delegate_debug_id` argument depending on the **Delegate Debug Identifier** type (str and int respectively)
90
91```c++
92EventTracerEntry event_tracer_start_profiling_delegate(
93    EventTracer* event_tracer,
94    const char* name,
95    DebugHandle delegate_debug_id)
96```
97
98To conclude an `EventTracerEntry`, `event_tracer_end_profiling_delegate` is simply provided the original `EventTracerEntry`.
99
100Optionally, additional runtime `metadata` can also be logged at this point.
101
102```c++
103void event_tracer_end_profiling_delegate(
104    EventTracer* event_tracer,
105    EventTracerEntry event_tracer_entry,
106    const void* metadata = nullptr,
107    size_t metadata_len = 0)
108```
109
110### Post-Time Logging
111ExecuTorch also allows you to log in post time. Some runtime settings don't have access to timestamps while it is executing. **Post-Time Logging** enables authors to still be able to log these events.
112
113To log events in post (for example, logging start and end time simultaneously) `event_tracer_log_profiling_delegate` is called with a combination of the arguments used in the real-time logging API’s and timestamps.
114
115```c++
116void event_tracer_log_profiling_delegate(
117    EventTracer* event_tracer,
118    const char* name,
119    DebugHandle delegate_debug_id,
120    et_timestamp_t start_time,
121    et_timestamp_t end_time,
122    const void* metadata = nullptr,
123    size_t metadata_len = 0)
124```
125A demo of the runtime code can be found [here](https://github.com/pytorch/executorch/blob/main/runtime/executor/test/test_backend_with_delegate_mapping.cpp).
126
127
128## Surfacing custom metadata from delegate events
129
130As seen in the runtime logging API's above, users can log an array of bytes along with their delegate profiling event. We make this data available for users in post processing via the [Inspector API](./model-inspector.rst).
131
132Users can pass a metadata parser when creating an instance of the Inspector. The parser is a callable that deserializes the data and returns a list of strings or a dictionary containing key-value pairs. The deserialized data is then added back to the corresponding event in the event block for user consumption. Here's an example of how to write this parser:
133
134NOTE: The input to the deserializer is a list where each entry is a series of bytes (essentially each entry is an immutable bytearray). Users are expected to iterate over this list, deserialize each entry and then return it in the expected format which is either a list of strings, or a dict.
135
136```python
137Inspector(
138    etdump_path=etdump_path,
139    # Optional
140    etrecord=etrecord_path,
141    # Optional, only needed if debugging was enabled.
142    buffer_path=buffer_path,
143    delegate_metadata_parser=parse_delegate_metadata
144)
145
146
147def parse_delegate_metadata(delegate_metadatas: List[bytes]) -> Union[List[str], Dict[str, Any]]:
148    metadata_str = []
149    for metadata_bytes in delegate_metadatas:
150        metadata_str += str(metadata_bytes)
151    return metadata_str
152```
153