profiler.h 6.34 KB
Newer Older
1
/* #######################################################################
2
# Copyright (c) 2019-2020 COBOLworx Corporation
3 4 5 6 7 8 9 10 11 12 13
# All rights reserved.
#
# Redistribution and use in source and binary forms, with or without
# modification, are permitted provided that the following conditions are met:
#
#    * Redistributions of source code must retain the above copyright
#      notice, this list of conditions and the following disclaimer.
#    * Redistributions in binary form must reproduce the above copyright
#      notice, this list of conditions and the following disclaimer in
#      the documentation and/or other materials provided with the
#      distribution.
14
#    * Neither the name of the COBOLworx Corporation nor the names of its
15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30
#      contributors may be used to endorse or promote products derived
#      from this software without specific prior written permission.
#
# THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
# AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
# IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE
# DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR CONTRIBUTORS BE LIABLE
# FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
# DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR
# SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER
# CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,
# OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
# OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
#
############################################################################ */

31 32
#pragma once

rdubner's avatar
rdubner committed
33
#if __GNUC__ >= 7 || defined(_WIN32)
34

35
#include <map>
rdubner's avatar
rdubner committed
36
#include <map>
37 38 39 40 41 42 43 44
#include <string>
#include <vector>
#include <chrono>
#include <iostream>
#include <sstream>
#include <algorithm>
#include "utils.h"

rdubner's avatar
rdubner committed
45
// #define PROFILING
46 47 48 49

class PPROFILER
{
private:
rdubner's avatar
rdubner committed
50 51
    static std::map<std::string,double> ProfilerRoutineTimes;
    static std::map<std::string,LONGLONG> ProfilerRoutineEntries;
52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97
    static std::vector<double> AccumulatedTimes;
    std::string routine;
    std::chrono::steady_clock::time_point time_in;
    std::chrono::steady_clock::time_point time_out;
    std::chrono::steady_clock::time_point lap_timer;
    std::chrono::steady_clock::time_point oh_1;
    std::chrono::steady_clock::time_point oh_2;
    std::chrono::steady_clock::time_point oh_3;
    std::chrono::steady_clock::time_point oh_4;
    double lap_time_overhead;
    bool frozen;

public:
    PPROFILER(char const * const function_name)
    {
        oh_1 = std::chrono::steady_clock::now();
        routine = function_name;
        AccumulatedTimes.push_back(0);
        frozen = false;
        lap_time_overhead = 0;
        oh_2 = lap_timer = time_in = std::chrono::steady_clock::now();
    }

    PPROFILER(const char * class_name, char const * const function_name)
    {
        oh_1 = std::chrono::steady_clock::now();
        routine = class_name;
        routine += "::";
        routine += function_name;
        AccumulatedTimes.push_back(0);
        frozen = false;
        lap_time_overhead = 0;
        oh_2 = lap_timer = time_in = std::chrono::steady_clock::now();
    }

    ~PPROFILER()
    {
        if(!frozen) {
            Freeze();
            size_t level = AccumulatedTimes.size();
            if(level == 0) {
                std::cerr << Dump();
            }
        }
    }

rdubner's avatar
rdubner committed
98 99
    void
    LapTime()
100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115
    {
        std::chrono::steady_clock::time_point lt1 = std::chrono::steady_clock::now();
        std::chrono::duration<double> lap_time = std::chrono::duration_cast<std::chrono::duration<double>>(lt1-lap_timer);

        std::stringstream ss;
        ss.flags(std::ios::right | std::ios::fixed);
        ss.width(12); // sign, 999 decimal 123456
        ss.precision(6);
        ss << lap_time.count();
        std::cerr << ss.str() << std::endl;

        lap_timer = std::chrono::steady_clock::now();
        std::chrono::duration<double> overhead = std::chrono::duration_cast<std::chrono::duration<double>>(lap_timer - lt1);
        lap_time_overhead += overhead.count();
    }

rdubner's avatar
rdubner committed
116 117
    void
    Freeze()
118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139
    {
        oh_3 = time_out = std::chrono::steady_clock::now();
        std::chrono::duration<double> time_span = std::chrono::duration_cast<std::chrono::duration<double>>(time_out - time_in);
        ProfilerRoutineTimes[routine] += time_span.count() - AccumulatedTimes.back();
        ProfilerRoutineEntries[routine] += 1;
        AccumulatedTimes.pop_back();
        size_t level = AccumulatedTimes.size();
        std::chrono::duration<double> overhead1 = std::chrono::duration_cast<std::chrono::duration<double>>(oh_2 - oh_1);
        double overhead = overhead1.count();
        oh_4 = std::chrono::steady_clock::now();
        std::chrono::duration<double> overhead2 = std::chrono::duration_cast<std::chrono::duration<double>>(oh_4 - oh_3);
        overhead += overhead2.count();
        overhead += lap_time_overhead;

        if(level > 0) {
            AccumulatedTimes[level-1] += time_span.count() - overhead;
        }
        frozen = true;
    }

    friend std::ostream &operator<<(std::ostream &os, PPROFILER const &m);

rdubner's avatar
rdubner committed
140 141
    std::string
    Dump() const
142 143 144 145 146
    {
        std::stringstream ss;

        size_t max_width = 0;
        std::map<std::string,double> smap;
rdubner's avatar
rdubner committed
147
        for(std::map<std::string,double>::const_iterator it=ProfilerRoutineTimes.begin(); it!=ProfilerRoutineTimes.end(); it++) {
148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172
            max_width = std::max(max_width,it->first.length());
            smap[it->first] = it->second;
        }
        for(std::map<std::string,double>::const_iterator it=smap.begin(); it!=smap.end(); it++) {
            ss.flags (std::ios::left);
            ss.width(max_width);
            ss << it->first;

            ss << " ";
            ss.flags(std::ios::right | std::ios::fixed);
            ss.width(12); // sign, 999 decimal 123456
            ss.precision(6);
            ss << it->second;

            ss << " ";
            ss.width(12);
            ss << ProfilerRoutineEntries[it->first];

            ss << std::endl;
        }
        return ss.str();
    }

};

173 174
#endif

175 176 177 178 179 180 181 182 183
#ifdef PROFILING
#define PROFILER PPROFILER Profiler(__func__);
#define CPROFILER PPROFILER Profiler(typeid(*this).name(),__func__);
#define LAPTIME Profiler.LapTime();
#else
#define PROFILER
#define CPROFILER
#define LAPTIME
#endif