|
| 1 | +.. meta:: |
| 2 | + :description: Enabling logging in rocFFT |
| 3 | + :keywords: rocFFT, ROCm, API, documentation, logging |
| 4 | + |
| 5 | + |
| 6 | +.. _enabling-logging: |
| 7 | + |
| 8 | +******************************************************************** |
| 9 | +Enabling logging in rocFFT |
| 10 | +******************************************************************** |
| 11 | + |
| 12 | +rocFFT can write a variety of log messages to aid troubleshooting. Here are the different |
| 13 | +logs that rocFFT supports. |
| 14 | + |
| 15 | +* **Trace logging**: Logs the library entry points (for example, ``rocfft_plan_create`` or ``rocfft_execute``) and their parameter |
| 16 | + values when they are called. Error messages during plan creation and execution are also logged here. |
| 17 | +* **Benchmark logging**: Logs the ``rocfft-bench`` command line when a plan is created. |
| 18 | + You can use this command to rerun the same transform later. |
| 19 | +* **Profile logging**: Logs a message for each kernel launched during plan execution. |
| 20 | + This message contains the following elements: |
| 21 | + |
| 22 | + * Kernel duration |
| 23 | + * The size of the user data buffers seen by the kernel |
| 24 | + * Estimates for the observed memory bandwidth and bandwidth efficiency |
| 25 | + |
| 26 | + .. note:: |
| 27 | + |
| 28 | + To provide the kernel duration, rocFFT must use ``hipEvents`` and wait for each kernel to complete. |
| 29 | + This might interfere with time measurement at higher levels, for example, for ``rocfft-bench``. |
| 30 | + |
| 31 | +* **Plan logging**: Logs the plan details when a transform is executed, including the following: |
| 32 | + |
| 33 | + * Each TreeNode in the plan |
| 34 | + * The work buffer size required by the plan |
| 35 | + * The kernel grid and block dimensions |
| 36 | + * The kernel maximum occupancy (estimated by HIP) |
| 37 | + |
| 38 | +* **Kernel I/O logging**: Logs the kernel details during plan execution, including the input to each |
| 39 | + kernel (the data provided by the user) and the final output of the transform. |
| 40 | + |
| 41 | + .. note:: |
| 42 | + |
| 43 | + The amount of data logged can become very large, particularly for 2D and 3D transforms, so |
| 44 | + logging it to a file instead of stderr is usually a good idea. See the next section for more details. |
| 45 | + |
| 46 | + Writing the data involves extra ``hipMemcpy`` operations and serializing the |
| 47 | + data to the log can also take a significant amount of time. Both of these factors affect performance. |
| 48 | + |
| 49 | +* **Runtime compilation logging**: Logs details about runtime compilation during plan creation, |
| 50 | + including the following: |
| 51 | + |
| 52 | + * The source code |
| 53 | + * Messages indicating a kernel was found in a cache, and did not need to be compiled at runtime |
| 54 | + * Compilation errors (if any) |
| 55 | + * Duration measurements indicating the time it took to generate source code for the kernel and compile the kernel |
| 56 | + |
| 57 | + The source code for the kernels is delimited by lines containing the strings ``ROCFFT_RTC_BEGIN`` |
| 58 | + and ``ROCFFT_RTC_END``. This lets you isolate the source code for each kernel if a |
| 59 | + single log contains code for multiple kernels. |
| 60 | + |
| 61 | + .. note:: |
| 62 | + |
| 63 | + All non-code messages (except for compile errors) are written as C++ comments, so |
| 64 | + you can pass the whole file to clang-format to inspect the source code. |
| 65 | + |
| 66 | + The source code details for the runtime compilation can be very large, so consider writing |
| 67 | + this log to a file instead of stderr. |
| 68 | + |
| 69 | +* **Tuning logging**: Logs details about any kernels that are tried and rejected while tuning is running. |
| 70 | + It also logs messages when tuned solutions are used during plan building. |
| 71 | +* **Graph logging**: Logs the graph of subplans during multi-GPU or multi-process plan execution. |
| 72 | + Subplans include FFT plans, transpose plans (to reshape data for communication), and communication steps. |
| 73 | + This is written as Graphviz data. The view of the global graph might be slightly different from |
| 74 | + different nodes. This is because the current node has more visibility into subplans that run locally |
| 75 | + than those that run on other nodes. |
| 76 | + |
| 77 | +Configuring the logging output |
| 78 | +============================== |
| 79 | + |
| 80 | +The logging output can be controlled using the ``ROCFFT_LAYER`` environment variable. |
| 81 | +``ROCFFT_LAYER`` is a numerical bitmask, where zero or more bits can be set to enable one or more logging layers. |
| 82 | +The log output is written to stderr by default. |
| 83 | + |
| 84 | +The following table maps the different logging layers to a ``ROCFFT_LAYER`` bit field value. |
| 85 | +To determine what value to set for ``ROCFFT_LAYER``, add up the values of all the layers you want to see. |
| 86 | +For example, to see the output for trace, profile, and plan logging, set ``ROCFFT_LAYER`` to ``13`` |
| 87 | +(``1`` + ``4`` + ``8``). |
| 88 | + |
| 89 | +.. csv-table:: |
| 90 | + :header: "Log type","ROCFFT_LAYER bit field value" |
| 91 | + :widths: 20, 20 |
| 92 | + |
| 93 | + "Trace logging","1" |
| 94 | + "Benchmark logging","2" |
| 95 | + "Profile logging","4" |
| 96 | + "Plan logging","8" |
| 97 | + "Kernel I/O logging","16" |
| 98 | + "Runtime compilation logging","32" |
| 99 | + "Tuning logging","64" |
| 100 | + "Graph logging","128" |
| 101 | + |
| 102 | +Logging to a file |
| 103 | +============================= |
| 104 | + |
| 105 | +By default, messages are written to stderr, but they can be redirected to |
| 106 | +output files using the environment variables described in this section. |
| 107 | +Each type of log can be redirected separately using a unique environment variable. |
| 108 | +The corresponding log must be enabled using the ``ROCFFT_LAYER`` variable |
| 109 | +before any details can be logged to the file. |
| 110 | +For example, to redirect the trace log to a file, trace logging must |
| 111 | +also be enabled in the ``ROCFFT_LAYER`` bit field. |
| 112 | + |
| 113 | +.. note:: |
| 114 | + |
| 115 | + Some log types, such as kernel I/O logging and runtime compilation logging, can generate |
| 116 | + a large number of log entries, so redirecting their output to a file is recommended. |
| 117 | + |
| 118 | +The following table lists the environment variable to redirect logging for each |
| 119 | +log type. Set this variable to a valid file path to redirect the output of the corresponding log type. |
| 120 | +For example, to send the trace logging output to a file, enable the trace log, then set the |
| 121 | +``ROCFFT_LOG_TRACE_PATH`` variable to the name of the destination file. |
| 122 | + |
| 123 | +.. csv-table:: |
| 124 | + :header: "Log type","File redirection variable" |
| 125 | + :widths: 20, 30 |
| 126 | + |
| 127 | + "Trace logging","``ROCFFT_LOG_TRACE_PATH``" |
| 128 | + "Benchmark logging","``ROCFFT_LOG_BENCH_PATH``" |
| 129 | + "Profile logging","``ROCFFT_LOG_PROFILE_PATH``" |
| 130 | + "Plan logging","``ROCFFT_LOG_PLAN_PATH``" |
| 131 | + "Kernel I/O logging","``ROCFFT_LOG_KERNELIO_PATH``" |
| 132 | + "Runtime compilation logging","``ROCFFT_LOG_RTC_PATH``" |
| 133 | + "Tuning logging","``ROCFFT_LOG_TUNING_PATH``" |
| 134 | + "Graph logging","``ROCFFT_LOG_GRAPH_PATH``" |
0 commit comments