GTPin: Funtime Sample Tool

The Funtime tool counts the cycles it takes for each kernel to execute from the beginning to the end

Running Funtime tool

To run the Funtime tool in its default configuration, use this command:

Profilers/Bin/gtpin -t funtime -- app

How to understand Funtime results

When you run the in-house GTPin Funtime tool in its default configuration, the directory GTPIN_PROFILE_FUNTIME0 is generated. GTPin saves the profiling results in the file GTPIN_PROFILE_FUNTIME0\Session_Final\funtime.txt. The results are presented in the following format:

### Kernel/Shader execution-time profile generated by GTPin ###

Legend:
NA - kernel was not instrumented.
          Name              HashID      SIMD      Type          Freq.    Total-Cycle     Avg-Cycles        Skipped            Platform     Execution descriptor

L3_SLM_8x8_8x16    f54af91315561f54         8        CS            512      164965992         322199              0              OpenCL            0 0
L3_SLM_8x8_8x16    f54af91315561f54         8        CS            512      164442942         321177              0              OpenCL            0 1
L3_SLM_8x8_8x16    f54af91315561f54         8        CS            512      165458952         323162              0              OpenCL            0 2
L3_SLM_8x8_8x16    f54af91315561f54         8        CS            512      168150199         328418              0              OpenCL            0 3
L3_SLM_8x8_8x16    f54af91315561f54         8        CS            512      165136147         322531              0              OpenCL            0 4
L3_SLM_8x8_8x16    f54af91315561f54         8        CS            512      167331603         326819              0              OpenCL            0 5

Each line represents a single run (dispatch to HW device) of specific kernel, where the fields have the following meaning:

• Name - The name of the kernel.
• HashID - The hash ID of the IR representation of this kernel.
• SIMD - The SIMD width to which the kernel was compiled (8, 16, or 32).
• Type - The kernel type (PS - Pixel Shader, VS - Vertex Shader, DS - Domain Shader, GS - Geometry Shader, HS - Hull Shader, or CS - Compute Shader).
• Freq. - The number of times an instance of the kernel was dispatched to any of the HW threads during the current run.
• Total-Cycle - The total number of cycles (accumulated over all HW threads) it took for the kernel to run from its beginning to end.
• Avg-Cycles - The average number of cycles it takes for the kernel instance to run on a single HW thread. This number is equal to Total-Cycle/Freq.
• Skipped - Internal GTPin information.
• Platform - The platform supported by the application: Intel® oneAPI Level Zero* (Level Zero*), OpenCL*, Microsoft DX11*, Microsoft DX12*, and/or Vulkan*.
• Execution descriptor - Per platform metadata.
  • Level Zero - Device Enqueue.
  • OpenCL - Device Enqueue.
  • DX11 - Device Draw.
  • DX12 - Device CommandList Draw PSO.
  • Vulkan - Device CommandList Draw PSO.
    where:
    • Device - The ID of the logical device on which the kernel was run.
    • Enqueue - The ID of the Enqueue command.
    • Draw - The ID of the Draw command.
    • CommandList - The ID of the Command List.
    • PSO - The ID of the PSO (Pipeline State Object).

If the name of the kernel is not known to GTPin, GTPin creates an artificial name in the format: CS_asmf54af91315561f54_simd8 where the prefix indicates the kernel type; the suffix indicates the SIMD width to which this kernel was compiled; and the 16-digit number is the hash ID of the IR representation of this kernel.

(Back to the list of all GTPin Sample Tools)

funtime.h

/*========================== begin_copyright_notice ============================
Copyright (C) 2018-2022 Intel Corporation

SPDX-License-Identifier: MIT
============================= end_copyright_notice ===========================*/

/*!
 * @file Funtime tool definitions
 */

#ifndef FUNTIME_H_
#define FUNTIME_H_

#include <list>
#include <map>
#include <set>
#include <string>

#include "gtpin_api.h"
#include "gtpin_tool_utils.h"

using namespace gtpin;

/* ============================================================================================= */
// Struct FuntimeRecord
/* ============================================================================================= */
/*!
 * Layout of records collected in profile buffer by the funtime tool
 */
struct FuntimeRecord 
{
    uint64_t cycles;    ///< Total number of cycles
    uint32_t freq;      ///< Total number of executions
    uint32_t skipped;   ///< Total number of skipped executions
};

/* ============================================================================================= */
// Class FuntimeDispatchProfile
/* ============================================================================================= */
/*!
 * Profiling data collected during a single kernel dispatch
 */
struct FuntimeDispatchProfile
{
    explicit FuntimeDispatchProfile(const IGtKernelDispatch& kernelDispatch, uint32_t tile = 0);
    void Accumulate(const FuntimeRecord& record);

    GtKernelExecDesc  kernelExecDesc; ///< Kernel execution descriptor
    uint32_t          tileId;         ///< Identifier of the subdevice (tile) assigned to this kernel dispatch
    uint64_t          cycles;         ///< Total number of cycles
    uint64_t          freq;           ///< Total number of executions
    uint64_t          skipped;        ///< Total number of skipped executions
};

/* ============================================================================================= */
// Class FuntimeKernelProfile
/* ============================================================================================= */
/*!
 * Aggregated profile of all instrumented kernel dispatches
 */
class FuntimeKernelProfile
{
public:
    FuntimeKernelProfile(const IGtKernel& kernel, const GtProfileArray& profileArray);

    /// Add new dispatched kernel instance,  and return reference to its (empty) profile
    FuntimeDispatchProfile& AddKernelDispatch(const IGtKernelDispatch& kernelDispatch, uint32_t tile = 0);

    std::string           ToString()        const;                         ///< @return Text representation of the profile data
    const GtProfileArray& GetProfileArray() const { return _profileArray; }///< @return Profile buffer accessor

private:
    std::string                         _name;              ///< Kernel's name
    GtKernelType                        _type;              ///< Kernel's type
    GtGpuPlatform                       _platform;          ///< Kernel's platform
    uint64_t                            _hashId;            ///< Kernel's hash identifier
    GtSimdWidth                         _simd;              ///< Kernel's SIMD width
    GtProfileArray                      _profileArray;      ///< Profile buffer accessor
    std::list<FuntimeDispatchProfile>   _dispatchProfiles;  ///< Profiles per kernel dispatch
};

/* ============================================================================================= */
// Class Funtime
/* ============================================================================================= */
/*!
 * Implementation of the IGtTool interface for the funtime tool
 */
class Funtime : public GtTool
{
public:
    /// Implementation of the IGtTool interface
    const char* Name() const { return "funtime"; }

    void OnKernelBuild(IGtKernelInstrument& instrumentor);
    void OnKernelRun(IGtKernelDispatch& dispatcher);
    void OnKernelComplete(IGtKernelDispatch& dispatcher);

public:
    static void OnFini();                        ///< Callback function registered with atexit()
    std::string ToString() const;                ///< @return Text representation of the profile data

    static Funtime* Instance();                  ///< @return Single instance of this class

private:
    Funtime() = default;
    Funtime(const Funtime&) = delete;
    Funtime& operator = (const Funtime&) = delete;
    ~Funtime() = default;

    /// Generate code at entry/exits of the kernel
    void GeneratePreCode(GtGenProcedure& proc, const IGtGenCoder& coder);
    void GeneratePostCode(GtGenProcedure& proc, const IGtGenCoder& coder, const GtProfileArray& profileArray);

    /// @return true/false - use 64-bit/32-bit integer for the cycle counter
    static bool Use64BitCounters(const IGtGenCoder& coder);

private:
    std::map<GtKernelId, FuntimeKernelProfile> _kernels;  ///< Collection of kernel profiles

    GtReg _addrReg;     ///< Virtual register that holds address within profile buffer
    GtReg _dataReg;     ///< Virtual register that holds data to be read from/written to profile buffer 
    GtReg _timeReg;     ///< Virtual timer register
    GtReg _tmpReg32;    ///< Virtual 32-bit scratch register
};

#endif

funtime.cpp

/*========================== begin_copyright_notice ============================
Copyright (C) 2015-2025 Intel Corporation

SPDX-License-Identifier: MIT
============================= end_copyright_notice ===========================*/

/*!
 * @file Implementation of the Funtime tool
 */

#include <fstream>
#include <sstream>
#include <iomanip>
#include <algorithm>

#include "funtime.h"

using namespace gtpin;
using namespace std;

/* ============================================================================================= */
// Configuration
/* ============================================================================================= */
Knob<int>  knobNumThreadBuckets("num_thread_buckets", 32, "Number of thread buckets. Default - 32, zero - maximum thread buckets");
Knob<bool> knobPerTileProfiling("per_tile_profiling", false, "Enable per-tile (subdevice) profiling");
Knob<bool> knobSkipZeroResults("skip_zero_results", false, "Skip zero results in the Funtime output");

/* ============================================================================================= */
// Funtime implementation
/* ============================================================================================= */
Funtime* Funtime::Instance()
{
    static Funtime instance;
    return &instance;
}

void Funtime::OnKernelBuild(IGtKernelInstrument& instrumentor)
{
    const IGtKernel&            kernel          = instrumentor.Kernel();
    const IGtCfg&               cfg             = instrumentor.Cfg();
    const IGtGenCoder&          coder           = instrumentor.Coder();
    const IGtGenArch&           genArch         = GTPin_GetCore()->GenArch();
    const IGtGenModel&          genModel        = kernel.GenModel();
    IGtProfileBufferAllocator&  allocator       = instrumentor.ProfileBufferAllocator();
    IGtVregFactory&             vregs           = coder.VregFactory();
    bool                        is64BitCounter  = Use64BitCounters(coder);

    // Allocate the profile buffer. It will hold single FuntimeRecord per each thread bucket
    uint32_t numThreadBuckets = (knobNumThreadBuckets == 0) ? genModel.MaxThreadBuckets() : knobNumThreadBuckets;
    uint32_t numTiles         = (knobPerTileProfiling && coder.IsTileIdSupported()) ? genArch.MaxTiles(kernel.GpuPlatform()) : 1;
    GtProfileArray profileArray(sizeof(FuntimeRecord), numTiles, numThreadBuckets);
    profileArray.Allocate(allocator);

    // Initialize virtual registers
    _timeReg   = vregs.Make(VREG_TYPE_DWORD);
    _tmpReg32  = vregs.MakeScratch();
    _addrReg   = vregs.MakeMsgAddrScratch();
    _dataReg   = vregs.MakeMsgDataScratch(is64BitCounter? VREG_TYPE_QWORD : VREG_TYPE_DWORD);

    // Generate code that starts/stops timer at entry/exit of the kernel
    GtGenProcedure preCode;  GeneratePreCode(preCode, coder);
    GtGenProcedure postCode; GeneratePostCode(postCode, coder, profileArray);

    // Instrument kernel entries
    instrumentor.InstrumentEntries(preCode);

    // Instrument kernel exits
    for (auto bblPtr : cfg.ExitBbls())
    {
        const IGtIns& ins = bblPtr->LastIns(); GTPIN_ASSERT(ins.IsEot());
        GtGenProcedure fakeConsumers;
        coder.GenerateFakeSrcConsumers(fakeConsumers, ins);
        instrumentor.InstrumentInstruction(ins, GtIpoint::Before(), fakeConsumers);
        instrumentor.InstrumentInstruction(ins, GtIpoint::Before(), postCode);
    }

    _kernels.emplace(kernel.Id(), FuntimeKernelProfile(kernel, profileArray));
}

void Funtime::OnKernelRun(IGtKernelDispatch& dispatcher)
{
    bool isProfileEnabled = false;

    const IGtKernel& kernel = dispatcher.Kernel();
    GtKernelExecDesc execDesc; dispatcher.GetExecDescriptor(execDesc);
    if (kernel.IsInstrumented() && IsKernelExecProfileEnabled(execDesc, kernel.GpuPlatform(), kernel.Name().Get()))
    {
        auto it = _kernels.find(kernel.Id());

        if (it != _kernels.end())
        {
            IGtProfileBuffer*       buffer          = dispatcher.CreateProfileBuffer(); GTPIN_ASSERT(buffer);
            FuntimeKernelProfile&   kernelProfile   = it->second;
            const GtProfileArray&   profileArray    = kernelProfile.GetProfileArray();
            if (profileArray.Initialize(*buffer))
            {
                isProfileEnabled = true;
            }
            else
            {
                GTPIN_ERROR_MSG(string("FUNTIME : ") + string(kernel.Name()) + " : Failed to write into memory buffer");
            }
        }
    }
    dispatcher.SetProfilingMode(isProfileEnabled);
}

void Funtime::OnKernelComplete(IGtKernelDispatch& dispatcher)
{
    const IGtKernel& kernel = dispatcher.Kernel();
    GtKernelExecDesc execDesc; dispatcher.GetExecDescriptor(execDesc);
    bool isProfilingEnabled = dispatcher.IsProfilingEnabled();
    if (!isProfilingEnabled || !IsKernelExecProfileEnabled(execDesc, kernel.GpuPlatform(), kernel.Name().Get()))
    {
        return; // Do nothing with unprofiled kernel dispatches
    }

    auto it = _kernels.find(kernel.Id());

    if (it != _kernels.end())
    {
        const IGtProfileBuffer* buffer          = dispatcher.GetProfileBuffer(); GTPIN_ASSERT(buffer);
        FuntimeKernelProfile&   kernelProfile   = it->second;
        const GtProfileArray&   profileArray    = kernelProfile.GetProfileArray();

        uint32_t numTiles = profileArray.NumRecords(); // There is a single record for each tile in each thread bucket
        for (uint32_t tileId = 0; tileId < numTiles; tileId++)
        {
            FuntimeDispatchProfile& dispatchProfile = kernelProfile.AddKernelDispatch(dispatcher, tileId);

            for (uint32_t threadBucket = 0; threadBucket < profileArray.NumThreadBuckets(); ++threadBucket)
            {
                FuntimeRecord record;
                if (!profileArray.Read(*buffer, &record, tileId, 1, threadBucket))
                {
                    GTPIN_ERROR_MSG(string("FUNTIME : ") + string(kernel.Name()) + " : Failed to read from memory buffer");
                }
                else
                {
                    dispatchProfile.Accumulate(record);
                }
            }
        }
    }
}

void Funtime::OnFini()
{
    Funtime&    me     = *Instance();
    string profileDir  = GTPin_GetCore()->ProfileDir();
    string filePath    = JoinPath(profileDir, "funtime.txt");

    ofstream fs(filePath);
    if (fs.is_open())
    {
        fs << me.ToString();
        fs.close();
    }
    else
    {
        GTPIN_WARNING("FUNTIME : could not create file: " + filePath);
    }
}

string Funtime::ToString() const
{
    ostringstream ostr;
    ostr << "### Kernel/Shader execution-time profile generated by GTPin ###" << endl << endl;
    ostr << "Legend:" << endl;
    ostr << "NA - kernel was not instrumented." << endl << endl;
    ostr << setw(30) << "Name" << setw(20) << "HashID" << setw(10) << "SIMD" << setw(10) << "Type";
    ostr << setw(15) << "Freq." << setw(15) << "Total-Cycle" << setw(15) << "Avg-Cycles" << setw(15) << "Skipped";
    ostr << setw(20) << "Platform";
    if (knobPerTileProfiling)
    {
        ostr << setw(10) << "Tile";
    }
    ostr << " " << setw(35) << "Execution descriptor";
    ostr << endl;
    for (const auto& kernelEntry : _kernels)
    {
        ostr << kernelEntry.second.ToString();
    }
    return ostr.str();
}

bool Funtime::Use64BitCounters(const IGtGenCoder& coder)
{
    return coder.InstructionFactory().CanAccessAtomically(GED_DATA_TYPE_uq);
}

void Funtime::GeneratePreCode(GtGenProcedure& proc, const IGtGenCoder& coder)
{
    coder.StartTimer(proc, _timeReg);
    if (!proc.empty()) { proc.front()->AppendAnnotation(__func__); }
}

void Funtime::GeneratePostCode(GtGenProcedure& proc, const IGtGenCoder& coder, const GtProfileArray& profileArray)
{
    IGtInsFactory&  insF            = coder.InstructionFactory();
    bool            is64BitCounter  = Use64BitCounters(coder);
    GtReg           flagReg         = FlagReg(0);
    GtReg           dataRegL        = {_dataReg, sizeof(uint32_t), 0};  // Low 32-bits of the data payload register

    // Generate code that computes elapsed time, and sets flagReg in case of timer overflow
    coder.StopTimerExt(proc, _timeReg);

    // _addrReg =  address of the current thread's FuntimeRecord in the profile buffer
    if (profileArray.NumRecords() > 1)
    {
        // The record number = tile ID
        GtReg& offsetReg = _tmpReg32;
        coder.LoadTileId(proc, offsetReg);
        proc += insF.MakeMul(offsetReg, offsetReg, sizeof(FuntimeRecord));
        profileArray.ComputeAddress(coder, proc, _addrReg, offsetReg);
    }
    else
    {
        profileArray.ComputeAddress(coder, proc, _addrReg);
    }

    int32_t base = 0;
    int32_t offset;

    // cycles += _timeReg
    offset = offsetof(FuntimeRecord, cycles) - base;
    profileArray.ComputeRelAddress(coder, proc, _addrReg, _addrReg, offset); base += offset;
    proc += insF.MakeMov(dataRegL, _timeReg);   // Move timer value to the low 32-bits of the data register
    if (is64BitCounter)
    {
        // Clear the high 32-bits of the data payload register
        GtReg dataRegH = {_dataReg, sizeof(uint32_t), 1};
        proc += insF.MakeMov(dataRegH, 0);
    }
    proc += insF.MakeAtomicAdd(NullReg(), _addrReg, _dataReg, (is64BitCounter? GED_DATA_TYPE_uq : GED_DATA_TYPE_ud));

    // freq++
    offset = offsetof(FuntimeRecord, freq) - base;
    profileArray.ComputeRelAddress(coder, proc, _addrReg, _addrReg, offset); base += offset;
    proc += insF.MakeAtomicInc(NullReg(), _addrReg, GED_DATA_TYPE_ud);

    // if (flagReg) skipped++
    offset = offsetof(FuntimeRecord, skipped) - base;
    profileArray.ComputeRelAddress(coder, proc, _addrReg, _addrReg, offset); base += offset;
    proc += insF.MakeAtomicInc(NullReg(), _addrReg, GED_DATA_TYPE_ud).SetPredicate(flagReg);

    if (!proc.empty()) { proc.front()->AppendAnnotation(__func__); }
}

/* ============================================================================================= */
// FuntimeDispatchProfile implementation
/* ============================================================================================= */
FuntimeDispatchProfile::FuntimeDispatchProfile(const IGtKernelDispatch& kernelDispatch, uint32_t tile) :
    tileId(tile), cycles(0), freq(0), skipped(0)
{
    kernelDispatch.GetExecDescriptor(kernelExecDesc);
}

void FuntimeDispatchProfile::Accumulate(const FuntimeRecord& record)
{
    cycles  += record.cycles;
    freq    += record.freq;
    skipped += record.skipped;
}

/* ============================================================================================= */
// FuntimeKernelProfile implementation
/* ============================================================================================= */
FuntimeKernelProfile::FuntimeKernelProfile(const IGtKernel& kernel, const GtProfileArray& profileArray) :
    _name(GlueString(kernel.Name())), _type(kernel.Type()), _platform(kernel.GpuPlatform()), _hashId(kernel.HashId()),
    _simd(kernel.SimdWidth()), _profileArray(profileArray) {}

FuntimeDispatchProfile& FuntimeKernelProfile::AddKernelDispatch(const IGtKernelDispatch& kernelDispatch, const uint32_t tile)
{
    _dispatchProfiles.emplace_back(kernelDispatch, tile);
    return _dispatchProfiles.back();
}

string FuntimeKernelProfile::ToString() const
{
    ostringstream ostr;
    if (!_dispatchProfiles.empty())
    {
        for (const auto& dp: _dispatchProfiles)
        {
            if (knobSkipZeroResults && (dp.freq == 0))
            {
                continue; // Skip zero results if the knob is set
            }

            uint64_t avgCycles = (dp.freq ? (dp.cycles / dp.freq) : 0);

            ostr << setw(30) << _name << setw(20) << hex << _hashId << dec << setw(10) << _simd << setw(10) << _type.ToString();
            ostr << setw(15) << dp.freq << setw(15) << dp.cycles << setw(15) << avgCycles << setw(15) << dp.skipped;
            ostr << setw(20) << _platform.ToString();
            if (knobPerTileProfiling)
            {
                ostr << setw(10) << dp.tileId;
            }
            ostr << " " << setw(35) << dp.kernelExecDesc.ToString(_platform, ExecDescAlignedFormat());
            ostr << endl;
        }
    }
    else
    {
        ostr << setw(30) << _name << setw(20) << hex << _hashId << dec << setw(10) << _simd << setw(10) << _type.ToString();
        ostr << setw(15) << "NA" << setw(15) << "NA" << setw(15) << "NA" << setw(15) << "NA" << setw(20) << "NA";
        if (knobPerTileProfiling)
        {
            ostr << setw(10) << "NA";
        }
        ostr << " " << setw(35) << "NA";
    }
    ostr << endl;
    return ostr.str();
}

/* ============================================================================================= */
// GTPin_Entry
/* ============================================================================================= */
EXPORT_C_FUNC void GTPin_Entry(int argc, const char *argv[])
{
    ConfigureGTPin(argc, argv);
    Funtime::Instance()->Register();
    atexit(Funtime::OnFini);
}

(Back to the list of all GTPin Sample Tools)