Performance Analysis of AI Engine Graph Application

In the simulation framework, the AI Engine simulator can generate a detailed dump of the hardware signals in the form of value change dump (VCD) files. A defined set of abstract events describes the execution of a multi-kernel AI Engine program in terms of these events. The output of a VCD file is enabled using the aiesimulator --dump-vcd command.

After simulation, or emulation, the VCD file can be processed into events and viewed on a timeline in the Vitis™ analyzer. The events contain information such as time stamps, different event types, and data associated with each event. This information can be correlated to the compiler generated debug information. This includes program counter values mapped to function names and instruction offsets, and source level symbolic data offsets for memory accesses.

The abstract AI Engine events are independent of the VCD format and will be directly extracted from the hardware. The events traces can be produced as plain text, comma-separated values (CSV), common trace format (CTF), or in waveform database (WDB), and the generated event trace data can be viewed in the Vitis analyzer.

To generate a VCD file from the Vitis IDE, right-click on your AI Engine graph project from the Explorer view and select Run As > Run Configurations as described in Creating the AI Engine Graph Project and Top-Level System Project. This opens up the Run Configurations dialog box for the current project.

Select the AI Engine Emulator option and double click to open a new configuration. Select the Generate Trace check box to enable trace capture, and select the VCD Trace button. By default, this produces a VCD dump in a file called foo.vcd in the current directory. You can rename the file if you like.

The VCD file can also be generated by invoking the AI Engine simulator with the –-dump-vcd <filename> option on the command line. The VCD file is generated in the same directory as the simulation is run. Assuming that the program is compiled using the AI Engine compiler, the simulator can be invoked in a shell with the VCD option.

$ aiesimulator –-pkg-dir=./Work --dump-vcd=foo

This command produces the VCD file (foo.vcd) which is written to the current directory.

The vcdanalyze utility is provided to generate an AI Engine event trace from the VCD file. This process is integrated into the Vitis tool flow automatically. From the Vitis IDE, after a simulation run has finished capturing AI Engine events, you can right-click on the project from the Project Explorer and select Analyze AIE Events. The trace data is produced under the current project at Traces/AIE_AXI_Trace and various views are automatically loaded into the current project.

The raw event trace under the directory Traces/AIE_AXI_Trace/ctf/events.txt should look like the following:

time=1741000,event=FROM_PL,name=tl.me.shim.tile_0_0.pl_interface.pl_to_shim0.data0,col=0,streamid=0,data0=65536,data1=0,tlast=0
time=1742000,event=FROM_PL,name=tl.me.shim.tile_0_0.pl_interface.pl_to_shim0.data0,col=0,streamid=0,data0=196610,data1=0,tlast=0
time=1743000,event=FROM_PL,name=tl.me.shim.tile_0_0.pl_interface.pl_to_shim0.data0,col=0,streamid=0,data0=327684,data1=0,tlast=0
time=1743000,event=CORE_RESET,col=1,row=0
time=1744000,event=FROM_PL,name=tl.me.shim.tile_0_0.pl_interface.pl_to_shim0.data0,col=0,streamid=0,data0=458758,data1=0,tlast=0
time=1745000,event=FROM_PL,name=tl.me.shim.tile_0_0.pl_interface.pl_to_shim0.data0,col=0,streamid=0,data0=589832,data1=0,tlast=0
time=1746000,event=FROM_PL,name=tl.me.shim.tile_0_0.pl_interface.pl_to_shim0.data0,col=0,streamid=0,data0=720906,data1=0,tlast=0
time=1747000,event=FROM_PL,name=tl.me.shim.tile_0_0.pl_interface.pl_to_shim0.data0,col=0,streamid=0,data0=851980,data1=0,tlast=0
time=1748000,event=FROM_PL,name=tl.me.shim.tile_0_0.pl_interface.pl_to_shim0.data0,col=0,streamid=0,data0=983054,data1=0,tlast=0
time=1749000,event=FROM_PL,name=tl.me.shim.tile_0_0.pl_interface.pl_to_shim0.data0,col=0,streamid=0,data0=1,data1=0,tlast=0
time=1750000,event=FROM_PL,name=tl.me.shim.tile_0_0.pl_interface.pl_to_shim0.data0,col=0,streamid=0,data0=131075,data1=0,tlast=0
time=1751000,event=FROM_PL,name=tl.me.shim.tile_0_0.pl_interface.pl_to_shim0.data0,col=0,streamid=0,data0=262149,data1=0,tlast=0
time=2186000,event=DM_WRITE_REQ,col=0,row=0,port=tl.me.array.tile_0_1.mm.dm.port_AXI_write_b6
time=2190000,event=DM_WRITE_REQ,col=0,row=0,port=tl.me.array.tile_0_1.mm.dm.port_AXI_write_b7
time=2194000,event=DM_WRITE_REQ,col=0,row=0,port=tl.me.array.tile_0_1.mm.dm.port_AXI_write_b6
time=2198000,event=DM_WRITE_REQ,col=0,row=0,port=tl.me.array.tile_0_1.mm.dm.port_AXI_write_b7
time=2202000,event=DM_WRITE_REQ,col=0,row=0,port=tl.me.array.tile_0_1.mm.dm.port_AXI_write_b2
time=2206000,event=DM_WRITE_REQ,col=0,row=0,port=tl.me.array.tile_0_1.mm.dm.port_AXI_write_b3

The following command produces the AI Engine trace data for foo.vcd in text form in the ./trdata/events.txt file.

vcdanalyze -vcd foo.vcd

The following command produces a CSV file from the AI Engine trace data from the foo.vcd file.

vcdanalyze -vcd=foo.vcd -csv

The following command produces the waveform data files from the AI Engine trace data from the foo.vcd file.

vcdanalyze -vcd foo.vcd -wdb

The bandwidth of a platform I/O port can be defined as the average number of bytes transferred per second, which can be derived as the total number of bytes transferred divided by the time when the port is transferring or is stalled (for example, due to back pressure). The following example shows how to profile I/O port bandwidth using the event API. In the example, gr is the application graph object, plio_out is the PLIO object connecting to the graph output port, and the graph is designed to produce 256 int32 data samples in eight iterations.

gr.init();
event::handle handle = event::start_profiling(plio_out, event::io_total_stream_running_to_idle_cycles);
if(handle==event::invalid_handle){
  printf("ERROR:Invalid handle. Only two performance counter in a AIE-PL interface tile\n");
  return 1;
}
gr.run(8);
gr.wait();
long long cycle_count = event::read_profiling(handle);
event::stop_profiling(handle);
double bandwidth = (double)256 * sizeof(int32) / (cycle_count * 1e-9); //byte per second

In the example, after the graph is initialized, the event::start_profiling is called to configure the AI Engine to count the accumulated clock cycles between the stream running event and the stream idle event. In other words, it counts the number of cycles when the stream port is in running or in stall state. The first argument in event::start_profiling can be a PLIO or a GMIO object, in this case, it is plio_out. The second argument is event::io_profiling_option enumeration, and in this case, the enumeration is set to event::io_total_stream_running_to_idle_cycles. event::start_profiling returns a handle, which will be used later to read the counter value and to stop the profile. After the graph finishes eight iterations, you can call event::read_profiling to read the counter value by supplying the handle. After profiling is done, it is recommended to stop the performance counter by calling event::stop_profiling with the handle so the hardware resources configured to do the profile can be released for other uses. Finally, the bandwidth is derived by dividing the total number of bytes transferred (256 × sizeof(int32)) by the time spent when the stream port is active (cycle_count × 1e^-9, assuming the AI Engine is running at 1 GHz).

Graph throughput can be defined as the average number of bytes produced (or consumed) per second. The following example shows how to profile graph throughput using the event API. In the example, gr is the application graph object, plio_out is the PLIO object connecting to the graph output port, and the graph is designed to produce 256 int32 data in eight iterations.

gr.init();
event::handle handle = event::start_profiling(plio_out, event::io_stream_start_to_bytes_transferred_cycles, 256*sizeof(int32));
if(handle==event::invalid_handle){
  printf("ERROR:Invalid handle. Only two performance counter in a AIE-PL interface tile\n");
  return 1;
}
gr.run(8);
gr.wait();
long long cycle_count = event::read_profiling(handle);
event::stop_profiling(handle);
double throughput = (double)256 * sizeof(int32) / (cycle_count * 1e-9); // byte per second

In the example, after the graph is initialized, event::start_profiling is called to configure the AI Engine to count the clock cycles from the stream start event to the event that indicates 256 × sizeof(int32) bytes have been transferred, assuming that the stream stops right after the specified number of bytes are transferred. If the stream continues after the number of bytes transferred, the counter continues and never ends. The first argument in event::start_profiling is plio_out, the second argument is set to event::io_stream_start_to_bytes_transferred_cycles, and the third argument specifies the number of bytes to be transferred before stopping the counter. The graph throughput is derived by dividing the total number of bytes produced in eight iterations (256 × sizeof(int32)) by the time spent from the first output data to the last output data (cycle_count × 1e^-9, assuming the AI Engine is running at 1 GHz).

Graph latency can be defined as the time spent from receiving the first input data to producing the first output data. The following example shows how to profile graph throughput using the event API. In the example, gr is the application graph object, plio_out is the PLIO object connecting to the graph output port, and gmio_in is the GMIO object connecting to the graph input port.

gr.init();
event::handle handle = event::start_profiling(gmio_in, plio_out, event::io_stream_start_difference_cycles);
if(handle==event::invalid_handle){
  printf("ERROR:Invalid handle. Only two performance counter in a AIE-PL interface tile\n");
  return 1;
}
gr.run(8);
gr.wait();
long long latency_in_cycles = event::read_profiling(handle);
event::stop_profiling(handle);

In the example, after graph is initialized, event::start_profiling is called to configure the AI Engine to count the clock cycles from the stream start event of the input I/O port to the stream start event of the output I/O port. The first and the second argument in event::start_profiling can be GMIO or PLIO ports, representing the input and the output I/O port respectively. In this example, gmio_in is the input I/O port and plio_out is the output I/O port. The third argument is set to event::io_stream_start_difference_cycles enumeration. The counter value simply indicates the graph latency in cycles.

[AIE WARNING]: Unable to request resources. RscType: 0
ERROR: event::start_profiling: Failed to request performance counter resources.

[XRT] ERROR: ERROR: event::start_profiling: Failed to request performance counter resources.: Resource temporarily unavailable