d92ab6f0 |
// ==========================================================================
// SeqAn - The Library for Sequence Analysis
// ==========================================================================
// Copyright (c) 2006-2018, Knut Reinert, FU Berlin
// 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.
// * Neither the name of Knut Reinert or the FU Berlin nor the names of
// its 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 KNUT REINERT OR THE FU BERLIN 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.
//
// ==========================================================================
// Author: David Weese <david.weese@fu-berlin.de>
// ==========================================================================
// Code for profiling.
// ==========================================================================
// TODO(holtgrew): This could use some cleanup.
#include <ctime>
#include <chrono>
//SEQAN_NO_GENERATED_FORWARDS: no forwards are generated for this file
#ifndef SEQAN_INCLUDE_SEQAN_BASIC_PROFILING_H_
#define SEQAN_INCLUDE_SEQAN_BASIC_PROFILING_H_
namespace seqan
{
// todo: substitute defines with inlines
#ifndef SEQAN_PROFILE
#define SEQAN_PROSET(i,v) do {} while (false)
#define SEQAN_PROADD(i,v) do {} while (false)
#define SEQAN_PROSUB(i,v) do {} while (false)
#define SEQAN_PROVAL(i) 0
#define SEQAN_PROEXTRAS(i) do {} while (false)
#define SEQAN_PROMARK(m) do {} while (false)
#define SEQAN_PROENDMARK(m) do {} while (false)
#define SEQAN_PRORESET do {} while (false)
#define SEQAN_PROGETTIME 0
#define SEQAN_PROTIMESTART(a) do {} while (false)
#define SEQAN_PROTIMEDIFF(a) 0
#define SEQAN_PROTIMEUPDATE(a) 0
// replace malloc and free in external tools
// with SEQAN_PROMALLOC and SEQAN_PROFREE to profile
// their memory usage
#define SEQAN_PROMALLOC(s) malloc(s)
#define SEQAN_PROFREE(p) free(p)
#else
#define SEQAN_PROSET(i,v) _profileSet(i,v)
#define SEQAN_PROADD(i,v) _profileAdd(i,v)
#define SEQAN_PROSUB(i,v) _profileSub(i,v)
#define SEQAN_PROVAL(i) (ProfileData_<>::_proValue[i])
#define SEQAN_PROEXTRAS(i) {ProfileData_<>::_proExtraCount = i;}
#define SEQAN_PROMARK(m) _profileMark(m)
#define SEQAN_PROENDMARK(m) _profileEndMark(m)
#define SEQAN_PRORESET _profileReset()
#define SEQAN_PROGETTIME sysTime()
#define SEQAN_PROTIMESTART(a) _proFloat a = sysTime()
#define SEQAN_PROTIMEDIFF(a) (sysTime() - a)
#define SEQAN_PROTIMEUPDATE(a) (_profileUpdate(a))
#define SEQAN_PROMALLOC(s) _profileMalloc(s)
#define SEQAN_PROFREE(p) _profileFree(p)
#endif
#ifdef STDLIB_VS
typedef int64_t ProfileInt_; //IOREV _notio_
#else
typedef int64_t ProfileInt_; //IOREV _notio_
#endif
typedef double _proFloat;
typedef _proFloat ProfileTimeValue_; //IOREV _notio_
enum ProfileConstants_ {
SEQAN_PROPAGESIZE = 4096, // B in byte
SEQAN_PROFLOAT = 0,
SEQAN_PROINT = 1,
SEQAN_PROTIME = 2,
SEQAN_PROTYPEMASK = 3,
SEQAN_PROSTATE = 4
};
enum ProfileValueIndex_ {
SEQAN_PROSYSTIME = 0,
SEQAN_PROCPUTIME = 1,
SEQAN_PROMEMORY = 2, // current memory usage (state value)
SEQAN_PROIO = 3, // IOs done (measured in Blocks of size B)
SEQAN_PROIORANDOM = 4, // IOs calls done (read/write calls done)
SEQAN_PROIOVOLUME = 5, // current disk usage (state value)
SEQAN_PRODEPTH = 6, // algorithmic rec. depth or loop count
SEQAN_PROOPENFILES = 7, // currently opened files
SEQAN_PROIWAIT = 8, // waiting time (initiating)
SEQAN_PROCWAIT = 9, // waiting time (completing)
SEQAN_PROEXTRA1 = 10,
SEQAN_PROEXTRA2 = 11,
SEQAN_PROEXTRA3 = 12,
SEQAN_PROINDEXCOUNT = 13,
SEQAN_PROEXTRACOUNT = 3
};
const char ProfileValueType_[] = {
SEQAN_PROTIME,
SEQAN_PROTIME,
SEQAN_PROINT + SEQAN_PROSTATE,
SEQAN_PROINT,
SEQAN_PROINT,
SEQAN_PROINT + SEQAN_PROSTATE,
SEQAN_PROINT + SEQAN_PROSTATE,
SEQAN_PROINT + SEQAN_PROSTATE,
SEQAN_PROFLOAT,
SEQAN_PROFLOAT,
SEQAN_PROFLOAT + SEQAN_PROSTATE,
SEQAN_PROFLOAT + SEQAN_PROSTATE,
SEQAN_PROFLOAT + SEQAN_PROSTATE
};
typedef ProfileTimeValue_ ProfileTStates_[SEQAN_PROINDEXCOUNT]; //IOREV _notio_
typedef _proFloat ProfileTTimes[SEQAN_PROINDEXCOUNT]; //IOREV _notio_
struct ProfileFile_;
//IOREV
template <typename T = void>
struct ProfileData_
{
//IOREV _notio_
static ProfileTStates_ _proValue;
static ProfileTTimes _proLastUpdate;
static int _proExtraCount;
static clock_t _proCpuTimeLast; // clock_t wraps around every 72mins
static ProfileInt_ _proCpuTimeOffset; // we have to work around this
static ProfileFile_* _proPFile;
static ProfileFile_* _proPFileStream;
};
template <typename T> ProfileTStates_ ProfileData_<T>::_proValue = {};
template <typename T> ProfileTStates_ ProfileData_<T>::_proLastUpdate = {};
template <typename T> int ProfileData_<T>::_proExtraCount = 0;
template <typename T> clock_t ProfileData_<T>::_proCpuTimeLast = 0;
template <typename T> ProfileInt_ ProfileData_<T>::_proCpuTimeOffset = 0;
template <typename T> ProfileFile_* ProfileData_<T>::_proPFile = NULL;
template <typename T> ProfileFile_* ProfileData_<T>::_proPFileStream = NULL;
inline ProfileFile_* & _proPFile() { return ProfileData_<>::_proPFile; }
//IOREV
inline ProfileFile_* & _proPFileStream() { return ProfileData_<>::_proPFileStream; }
//IOREV
/*!
* @fn cpuTime
* @headerfile <seqan/basic.h>
* @brief Returns the cpu time in seconds.
*
* @signature double cpuTime();
*
* @return double CPU time stamp in seconds.
*
* Calls <tt>clock</tt> to retrieve the processor time used by the running thread. This implies that the thread's
* processor time does not tick if the thread is suspended. While this has its advantages, benchmarks should generally
* focus on wall clock time, not processor time. Wall clock time is returned by sysTime.
*
* @see sysTime
*/
// HINT: The unit of all time functions is second.
inline _proFloat cpuTime() {
clock_t now = clock();
if (ProfileData_<>::_proCpuTimeLast > now) { // test for time wrap
ProfileData_<>::_proCpuTimeOffset += (~0u); // got one
ProfileData_<>::_proCpuTimeOffset ++;
// printf("\n!!WRAP!! old:%d, now:%d ofs:%d\n",ProfileData_<>::_proCpuTimeLast,now,ProfileData_<>::_proCpuTimeOffset);
}
ProfileData_<>::_proCpuTimeLast = now;
return (ProfileData_<>::_proCpuTimeOffset + now) / (_proFloat)CLOCKS_PER_SEC;
}
/*!
* @fn sysTime
* @headerfile <seqan/basic.h>
* @brief Returns the system time in seconds.
*
* @signature double sysTime();
*
* @return double A <tt>double</tt>, system time stamp in seconds. Types: nolink:double
*
* In contrast to @link cpuTime @endlink, the system time corresponds to the wall clock time under Linux and Mac OS X.
* Under Windows sysTime returns the result of cpuTime.
*
* Use this for benchmarking uner Linux and Mac Os X.
*
* Calls <tt>clock_gettime</tt> under Linux and <tt>gettimeofday</tt> under Mac OS X.
*
* @section Examples
*
* We can use sysTime to instrument our code for profiling/timing information quite robustly. The following demonstrates
* how the Function.sysTime is used in many SeqAn apps for collecting timing information.
*
* @code{.cpp}
* bool printTiming = true;
*
* // ...
*
* double startTime = sysTime();
* // Do some complex calculation.
* if (printTiming)
* std::cerr << "Some complex calculation too " << sysTime() - startTime << " s." << std::endl;
* @endcode
*
* @see cpuTime
*/
inline _proFloat sysTime()
{
return static_cast<_proFloat>(std::chrono::system_clock::now().time_since_epoch() /
std::chrono::duration<_proFloat>(1));
}
struct ProfileFile_ {
//IOREV not generic, uses FILE* instead of File() and custom IO
FILE *out;
bool running;
_proFloat dumpStep; // 0 .. manual dump mode, >0 .. live stream
_proFloat dumpNext;
ProfileTStates_ all, last;
std::string mark;
unsigned lines;
ProfileFile_() {
running = false;
}
ProfileFile_(char const *fname, _proFloat _dumpStep = 300.0) { // five minutes default dump interval
running = false;
start(fname, _dumpStep);
}
~ProfileFile_() {
if (running) stop();
}
inline void start(char const *fname, _proFloat _dumpStep = 300.0, bool append = false) {
if (append)
out = fopen(fname, "a");
else {
out = fopen(fname, "w");
dumpHeader();
}
if (!out) printf("WARNING: proFile could not be opened.\n");
setTime(ProfileData_<>::_proValue);
syncAll(all);
syncAll(last);
running = true;
lines = 0;
dumpStep = _dumpStep;
dumpNext = sysTime();
dump(last);
}
inline void stop() {
dump(last);
maximize(all, last);
if (dumpStep == 0) {
mark = "Zusammenfassung";
dump(all);
}
fclose(out);
running = false;
}
inline void syncTime(ProfileTStates_ &dst) {
std::memcpy(dst, ProfileData_<>::_proValue, 2 * sizeof(ProfileTimeValue_));
}
inline void sync(ProfileTStates_ &dst) {
std::memcpy(&(dst[2]), &(ProfileData_<>::_proValue[2]), sizeof(ProfileTStates_) - 2 * sizeof(ProfileTimeValue_));
}
inline void syncAll(ProfileTStates_ &dst) {
std::memcpy(dst, ProfileData_<>::_proValue, sizeof(ProfileTStates_));
}
inline static void setTime(ProfileTStates_ &dst) {
dst[0] = sysTime();
dst[1] = cpuTime();
}
inline void maximize(ProfileTStates_ &dst, ProfileTStates_ const &src) {
for(int i = 0; i < SEQAN_PROINDEXCOUNT; ++i)
if (((ProfileValueType_[i] & SEQAN_PROSTATE) != 0))
if (dst[i] < src[i])
dst[i] = src[i];
}
inline void dumpTab() {
if (!bol)
fprintf(out, " \t");
bol = false;
}
inline void dumpEndl() { fprintf(out, "\n"); }
inline void dumpHeader() {
fprintf(out, "\"Echtzeit\"\t\"CPU-Zeit\"\t\"Speicher\"\t\"I/O-Zugriffe\"\t\"wahlfreie I/Os\"\t\"I/O-Volumen\"\t\"Rekursionstiefe\"\t\"Offene Dateien\"\t\"Idle-Zeit vor I/O\"\t\"Idle-Zeit nach I/O\"\n");
}
inline void dumpTime(_proFloat seconds) {
if (seconds < 0) {
fputc('-', out);
seconds = -seconds;
}
int secs = (int)seconds;
int mins = secs/60; secs -= 60*mins;
int hours = mins/60; mins -= 60*hours;
fprintf(out, "%d:%02d:%02d", hours, mins, secs);
}
inline void dumpTimeEx(_proFloat seconds) {
int milli = (int)(seconds * 1000.0);
int secs = (int)seconds;
int mins = secs/60; secs -= 60*mins;
int hours = mins/60; mins -= 60*hours;
fprintf(out, "%d:%02d:%02d.%03d", hours, mins, secs, milli);
}
inline void dumpValue(ProfileTStates_ &stat, int valNum) {
_proFloat f = stat[valNum];
if ((ProfileValueType_[valNum] & SEQAN_PROSTATE) == 0)
f = ProfileData_<>::_proValue[valNum] - f;
switch (ProfileValueType_[valNum] & SEQAN_PROTYPEMASK) {
case SEQAN_PROINT: // state value -> print last seen maximum
fprintf(out, "%.0f", f);
break;
case SEQAN_PROFLOAT:
fprintf(out, "%f", f);
break;
case SEQAN_PROTIME:
dumpTimeEx(f);
}
}
inline void dumpSysValues(ProfileTStates_ &stat) {
for(int i = 0; i < SEQAN_PROINDEXCOUNT - SEQAN_PROEXTRACOUNT; ++i) {
dumpTab();
dumpValue(stat, i);
}
}
inline void dumpExtraValues(ProfileTStates_ &stat) {
for(int i = 0; i < ProfileData_<>::_proExtraCount; ++i) {
dumpTab();
dumpValue(stat, SEQAN_PROINDEXCOUNT - SEQAN_PROEXTRACOUNT + i);
}
}
inline void dumpMark() {
if (!mark.empty()) {
dumpTab();
fprintf(out, "\"%s\"", mark.c_str());
mark.erase();
}
}
inline void dump(ProfileTStates_ &stat) {
setTime(ProfileData_<>::_proValue);
dumpNext += dumpStep;
bol = true;
bool _flush = ((dumpStep == 0.0)) || ((lines & 16) == 0);
dumpSysValues(stat);
dumpExtraValues(stat);
dumpMark();
dumpEndl();
if (_flush) fflush(out);
++lines;
}
inline void signalDumpTest(_proFloat now) {
if (dumpStep > 0 && now > dumpNext && running) {
dump(last);
maximize(all, last);
sync(last);
}
}
inline void signalNewMax(int valNum) {
if (running)
if (last[valNum] < ProfileData_<>::_proValue[valNum])
last[valNum] = ProfileData_<>::_proValue[valNum];
}
inline void setMark(const char *text) {
if (running) {
mark = text;
if (dumpStep == 0.0) {
dump(last); // manual dump;
maximize(all, last);
sync(last);
}
}
}
inline void reset() {
syncTime(last);
}
inline void setEndMark(const char *text) {
if (running) {
setMark(text);
reset();
}
}
private:
bool bol; // begin of line
};
/*
inline void _profileSignalDumpTest(_proFloat now);
inline void _profileSignalNewMax(int valNum);
inline void _profileMark(const char *text);
inline void _profileEndMark(const char *text);
inline void _profileReset();
inline void _profileSet(int valNum, _proFloat value);
inline void _profileAdd(int valNum, _proFloat value);
inline void _profileSub(int valNum, _proFloat value);
// simple interface for external programs
inline void *_profileMalloc(size_t size);
inline void _profileFree(void *_ptr);
*/
inline void _profileSignalDumpTest(_proFloat now) {
//IOREV _notio_
if (ProfileData_<>::_proPFileStream) ProfileData_<>::_proPFileStream->signalDumpTest(now);
}
inline void _profileSignalNewMax(int valNum) {
//IOREV _notio_
if (((ProfileValueType_[valNum] & SEQAN_PROSTATE) != 0)) {
if (ProfileData_<>::_proPFileStream) ProfileData_<>::_proPFileStream->signalNewMax(valNum);
if (ProfileData_<>::_proPFile) ProfileData_<>::_proPFile->signalNewMax(valNum);
}
}
inline void _profileMark(const char *text) {
//IOREV _notio_
if (ProfileData_<>::_proPFileStream) ProfileData_<>::_proPFileStream->setMark(text);
if (ProfileData_<>::_proPFile) ProfileData_<>::_proPFile->setMark(text);
}
inline void _profileEndMark(const char *text) {
//IOREV _notio_
if (ProfileData_<>::_proPFileStream) { ProfileData_<>::_proPFileStream->setEndMark(text); }
if (ProfileData_<>::_proPFile) { ProfileData_<>::_proPFile->setEndMark(text); }
}
inline void _profileReset() {
//IOREV _notio_
if (ProfileData_<>::_proPFileStream) { ProfileData_<>::_proPFileStream->reset(); }
if (ProfileData_<>::_proPFile) { ProfileData_<>::_proPFile->reset(); }
}
template <typename TValue>
inline void _profileSet(ProfileValueIndex_ valNum, TValue value) {
//IOREV _notio_
_proFloat now = sysTime();
ProfileData_<>::_proLastUpdate[valNum] = now;
if (ProfileData_<>::_proValue[valNum] < value) {
ProfileData_<>::_proValue[valNum] = value;
_profileSignalNewMax(valNum);
} else
ProfileData_<>::_proValue[valNum] = value;
_profileSignalDumpTest(now);
}
template <typename TValue>
inline void _profileAdd(ProfileValueIndex_ valNum, TValue value) {
//IOREV _notio_
_proFloat now = sysTime();
ProfileData_<>::_proValue[valNum] += value;
ProfileData_<>::_proLastUpdate[valNum] = now;
if (valNum == SEQAN_PROIO) _profileAdd(SEQAN_PROIORANDOM, 1);
_profileSignalNewMax(valNum);
_profileSignalDumpTest(now);
}
template <typename TValue>
inline void _profileSub(ProfileValueIndex_ valNum, TValue value) {
//IOREV _notio_
_proFloat now = sysTime();
ProfileData_<>::_proValue[valNum] -= value;
ProfileData_<>::_proLastUpdate[valNum] = now;
_profileSignalDumpTest(now);
}
// simple interface for external programs
inline void *_profileMalloc(size_t size) {
//IOREV _notio_
size_t *ptr = reinterpret_cast<size_t*>(malloc(size + sizeof(size_t)));
if (ptr) {
_profileAdd(SEQAN_PROMEMORY, (_proFloat)(*ptr = size));
// printf("_profileMalloc %x size %d\n", ptr, size);
++ptr;
}
return ptr;
}
inline void _profileFree(void *_ptr) {
//IOREV _notio_
size_t *ptr = reinterpret_cast<size_t*>(_ptr);
if (ptr) {
--ptr;
// printf("_profileFree %x size %d\n", _ptr, *ptr);
_profileSub(SEQAN_PROMEMORY, (_proFloat)*ptr);
}
free(ptr);
}
inline _proFloat _profileUpdate(_proFloat& a) {
//IOREV _notio_
_proFloat x = sysTime() - a;
a += x;
return x;
}
}
#endif // #ifndef SEQAN_INCLUDE_SEQAN_BASIC_PROFILING_H_
|