1| Supported Targets | ESP32 | ESP32-S2 | 2| ----------------- | ----- | -------- | 3 4# Application Level Tracing Example (Logging to Host) 5 6(See the README.md file in the upper level 'examples' directory for more information about examples.) 7 8This example demonstrates how to use the [Application Level Tracing Library](https://docs.espressif.com/projects/esp-idf/en/latest/api-guides/app_trace.html#) (henceforth referred to as **App Trace**) to log messages to a host via JTAG instead of the normal method of logging via UART. 9 10UART logs are time consuming and can significantly slow down the function that calls it. Therefore, it is generally a bad idea to use UART logs in time-critical functions. Logging to host via JTAG is significantly faster and can be used in time-critical functions. For more details regarding logging to host via JTAG, refer to the [Logging to Host Documentation](https://docs.espressif.com/projects/esp-idf/en/latest/api-guides/app_trace.html#app-trace-logging-to-host). 11 12This example demonstrates JTAG logging to host in the context of polling for a [zero crossing](https://en.wikipedia.org/wiki/Zero_crossing). The example app will continuously sample a 50 to 60 Hz sinusoidal signal (using the ADC) and log the sampled values (via JTAG). Due to the higher speed of JTAG logging, the polling rate of the ADC should be high enough to detect a zero crossing. 13 14This example utilizes the following ESP-IDF features: 15* [DAC driver](https://docs.espressif.com/projects/esp-idf/en/latest/api-reference/peripherals/dac.html) to generate the 50 Hz sinusoidal signal. 16* [ADC driver](https://docs.espressif.com/projects/esp-idf/en/latest/api-reference/peripherals/adc.html) to sample the sinusoidal signal. 17* [Application Level Tracing Library](https://docs.espressif.com/projects/esp-idf/en/latest/api-guides/app_trace.html#) to log ADC samples to host. 18* [OpenOCD](https://docs.espressif.com/projects/esp-idf/en/latest/api-guides/jtag-debugging/index.html#setup-of-openocd) to interface with the target and receive the log output over JTAG. 19 20## How to use example 21 22### Hardware Required 23 24To run this example, you need a supported target dev board connected to a JTAG adapter, which can come in the following forms: 25 26* [ESP-WROVER-KIT](https://docs.espressif.com/projects/esp-idf/en/latest/hw-reference/modules-and-boards.html#esp-wrover-kit-v4-1) which integrates an on-board JTAG adapter. Ensure that the [required jumpers to enable JTAG are connected](https://docs.espressif.com/projects/esp-idf/en/latest/get-started/get-started-wrover-kit.html#setup-options) on the WROVER-KIT. 27* ESP32 or ESP32-S2 core board (e.g. ESP32-DevKitC, [ESP32-S2-Saola-1](https://docs.espressif.com/projects/esp-idf/en/latest/esp32s2/hw-reference/esp32s2/user-guide-saola-1-v1.2.html)) can also work as long as you connect it to an external JTAG adapter (e.g. FT2232H, J-LINK). 28 29This example will assume that that an ESP-WROVER-KIT is used. 30 31#### Pin Assignment: 32 33The sinusoidal signal of 50 to 60 Hz ranging from 0 V ~ 3.1 V should be input into `ADC1_CHANNEL_6`. Users may provide this signal themselves, or use the example-generated signal in `DAC_CHANNEL_1`. Listed below are the corresponding DAC/ADC channel pins for supported targets. 34 35| Target | DAC Output | ADC Input | 36| ------------------ | ------------------ | ------------------ | 37| ESP32 | Channel 1 (GPIO25) | Channel 6 (GPIO34) | 38| ESP32S2 | Channel 1 (GPIO17) | Channel 6 (GPIO7) | 39 40#### Extra Connections: 41 421. Connect the JTAG interface to the target board. For details about how to set up JTAG interface, please see [JTAG Debugging](https://docs.espressif.com/projects/esp-idf/en/latest/api-guides/jtag-debugging/index.html). Power up both the JTAG debugger and target board. 43 442. After connecting JTAG interface, you need to [Run OpenOCD](https://docs.espressif.com/projects/esp-idf/en/latest/api-guides/jtag-debugging/index.html#run-openocd). 45 463. Open a separate terminal window and run telnet by entering the command below. The telnet terminal window is used to feed commands to OpenOCD: 47 48 ```bash 49 telnet localhost 4444 50 ``` 51 52### Configure the project 53 54``` 55idf.py menuconfig 56``` 57 58* By default, the DAC will generate 130 Hz signal ranging from 0 V ~ 3.1 V. To generate a 50 Hz signal, the RTC 8 MHz clock will need to use a non-standard divider. This is achieved by enabling the `Example Configuration > Set custom RTC 8 MHz clock divider to lower CW frequency` configuration option. 59 60* To enable application tracing, select the `(X) Trace memory` option under `Component config > Application Level Tracing`. This option should have been selected by default. 61 62### Build, Flash, and Run 63 64Build the project and flash it to the board, then run monitor tool to view serial output: 65 66``` 67idf.py -p PORT flash monitor 68``` 69 70(Replace PORT with the name of the serial port to use.) 71 72**Start App Trace:** In the telnet session window, trigger OpenOCD to start App Trace on the target by entering the command below. This command will collect 9000 bytes of JTAG log data and save them to the file `file://adc.log` (note `file://` depends on 73where OpenOCD was started). Assuming that OpenOCD was started in this example's directory, `adc.log` will be saved here as well. 74 75 76```bash 77esp apptrace start file://adc.log 0 9000 5 0 0 78``` 79 80**Note:** For more details on OpenOCD commands regarding App Trace, refer to the [OpenOCD Application Level Tracing Commands](https://docs.espressif.com/projects/esp-idf/en/latest/api-guides/app_trace.html#openocd-application-level-tracing-commands) 81 82(To exit the serial monitor, type ``Ctrl-]``.) 83 84See the Getting Started Guide for full steps to configure and use ESP-IDF to build projects. 85 86## Example Output 87 88The example will continuously sample the ADC for 20ms per iteration, and will alternate between JTAG and UART logging per iteration. However, the JTAG logs should be captured by OpenOCD, thus will not appear in the monitor's output. Therefore, the monitor should only display the iterations where UART logging was used (i.e. every alternate iteration) such as the following: 89 90``` 91I (4289) example: Sampling ADC and sending data to the host... 92I (4309) example: Collected 427 samples in 20 ms. 93 94I (4309) example: Sampling ADC and sending data to the UART... 95I (4309) example: Sample:1, Value:2224 96I (4309) example: Sample:2, Value:840 97I (4309) example: Sample:3, Value:3503 98I (4319) example: Sample:4, Value:27 99I (4319) example: Sample:5, Value:4095 100I (4329) example: Collected 5 samples in 20 ms. 101``` 102 103**Note:** The UART log above was produced with the CPU running at 240 MHz. 104 105To access the JTAG logs, the `adc.log` file should be decoded. This can be done by using the `logtrace_proc.py` script as such: 106 107```bash 108$IDF_PATH/tools/esp_app_trace/logtrace_proc.py adc.log build/app_trace_to_host.elf 109``` 110 111The `logtrace_proc.py` script should produce the following output when decoding: 112 113``` 114Parse trace file '/user-home/esp/openocd-esp32/adc.log'... 115Unprocessed 7 bytes of log record args! 116Parsing completed. 117==================================================================== 118I (59369) example: Sample:1, Value:3717 119I (59369) example: Sample:2, Value:3647 120I (59369) example: Sample:3, Value:3575 121I (59369) example: Sample:4, Value:3491 122... 123 124I (59379) example: Sample:398, Value:78 125I (59379) example: Sample:399, Value:58 126I (59379) example: Sample:400, Value:22 127I (59379) example: Sample:401, Value:14 128I (59379) example: Sample:402, Value:0 129I (59379) example: Sample:403, Value:0 130I (59379) example: Sample:404, Value:0 131I (59379) example: Sample:405, Value:0 132I (59379) example: Sample:406, Value:0 133I (59379) example: Sample:407, Value:0 134I (59379) example: Sample:408, Value:0 135I (59379) example: Sample:409, Value:0 136I (59379) example: Sample:410, Value:0 137I (59379) example: Sample:411, Value:0 138I (59379) example: Sample:412, Value:0 139I (59379) example: Sample:413, Value:0 140I (59379) example: Sample:414, Value:16 141I (59379) example: Sample:415, Value:32 142I (59379) example: Sample:416, Value:40 143I (59379) example: Sample:417, Value:74 144I (59379) example: Sample:418, Value:89 145I (59379) example: Sample:419, Value:113 146I (59379) example: Sample:420, Value:160 147I (59379) example: Sample:421, Value:192 148I (59379) example: Sample:422, Value:221 149I (59379) example: Sample:423, Value:256 150I (59379) example: Sample:424, Value:298 151I (59379) example: Sample:425, Value:345 152I (59379) example: Sample:426, Value:386 153I (59379) example: Sample:427, Value:432 154I (61409) example: Sample:1, Value:2653 155 156==================================================================== 157 158Log records count: 428 159``` 160 161## Troubleshooting 162 163### Unable to flash when OpenOCD is connected to the target 164 165On ESP32 boards, one likely cause would be an incorrect SPI flash voltage when starting OpenOCD. Suppose a target board/module with a 3.3 V powered SPI flash is being used, but the configuration file (ex. `board/esp32-wrover.cfg` for ESP32) is selected when starting OpenOCD which can set the SPI flash voltage to 1.8 V. In this situation, the SPI flash will not work after OpenOCD connects to the target as OpenOCD has changed the SPI flash voltage. Therefore, you might not be able to flash to the target when OpenOCD is connected. 166 167To work around this issue, users are suggested to use `board/esp32-wrover.cfg` for ESP32 boards/modules operating with an SPI flash voltage of 1.8 V, and `board/esp-wroom-32.cfg` for 3.3 V. Refer to [ESP32 Modules and Boards](https://docs.espressif.com/projects/esp-idf/en/latest/hw-reference/modules-and-boards.html) and [Set SPI Flash Voltage](https://docs.espressif.com/projects/esp-idf/en/latest/api-guides/jtag-debugging/tips-and-quirks.html#why-to-set-spi-flash-voltage-in-openocd-configuration) for more details. 168 169(For any technical queries, please open an [issue](https://github.com/espressif/esp-idf/issues) on GitHub. We will get back to you as soon as possible.) 170 171The log should be identical to those printed via UART (complete with timestamps), but almost two orders of magnitude faster. 172 173## Example Breakdown 174 175The following code snippet demonstrates a loop of the sampling and logging the ADC over a 20 ms period in order to capture one full period of a 50 Hz signal. 176 177```c 178int sampling_period = 20; 179int i = 0; 180uint32_t sampling_start = esp_log_timestamp(); //this clock counts milliseconds 181do { 182 ESP_LOGI(TAG, "Sample:%d, Value:%d", ++i, adc1_get_raw(ADC1_TEST_CHANNEL)); 183} while (esp_log_timestamp() - sampling_start < sampling_period); 184``` 185 186If `ESP_LOGI()` is routed via UART (occurs by default), the log output produced will likely resemble the output shown below. Notice that due to UART logging is time consuming, thus the ADC is only sampled five times, which is too infrequent to consistently detect a zero crossing (where the zero crossing is `4096/2 = 2048` i.e., the mid point of the 12-bit ADC). 187 188```bash 189I (4309) example: Sample:1, Value:2224 190I (4309) example: Sample:2, Value:840 191I (4309) example: Sample:3, Value:3503 192I (4319) example: Sample:4, Value:27 193I (4319) example: Sample:5, Value:4095 194I (4329) example: Collected 5 samples in 20 ms. 195``` 196 197However, by logging via JTAG, the logging is much quicker hence allows a much higher sampling frequency (over 400 times) as shown the the log output below thus would be able to detect a zero crossing more consistently. 198 199```c 200esp_log_set_vprintf(esp_apptrace_vprintf); 201``` 202 203```bash 204... 205 206I (59379) example: Sample:423, Value:256 207I (59379) example: Sample:424, Value:298 208I (59379) example: Sample:425, Value:345 209I (59379) example: Sample:426, Value:386 210I (59379) example: Sample:427, Value:432 211I (61409) example: Sample:1, Value:2653 212 213==================================================================== 214 215Log records count: 428 216 217``` 218 219This example has demonstrated powerful functionality of logging to host via JTAG interface. With standard UART communication at a baud rate of 115200, printing out a single line log message takes approximately 4 ms. This also means that logged tasks cannot run more frequently than every 4 ms. By providing the same logging over JTAG, logging performance is improved 80 fold.
