2018-01-07 23:55:52 +00:00
|
|
|
// Copyright (c) 2016-2018, The Monero Project
|
2016-10-10 19:47:00 +00:00
|
|
|
//
|
|
|
|
// All rights reserved.
|
|
|
|
//
|
|
|
|
// Redistribution and use in source and binary forms, with or without modification, are
|
|
|
|
// permitted provided that the following conditions are met:
|
|
|
|
//
|
|
|
|
// 1. Redistributions of source code must retain the above copyright notice, this list of
|
|
|
|
// conditions and the following disclaimer.
|
|
|
|
//
|
|
|
|
// 2. 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.
|
|
|
|
//
|
|
|
|
// 3. Neither the name of the copyright holder 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
|
|
|
|
// THE COPYRIGHT HOLDER 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.
|
|
|
|
|
2017-11-25 22:25:05 +00:00
|
|
|
#include <vector>
|
|
|
|
#include "misc_os_dependent.h"
|
2016-10-10 19:47:00 +00:00
|
|
|
#include "perf_timer.h"
|
|
|
|
|
Change logging to easylogging++
This replaces the epee and data_loggers logging systems with
a single one, and also adds filename:line and explicit severity
levels. Categories may be defined, and logging severity set
by category (or set of categories). epee style 0-4 log level
maps to a sensible severity configuration. Log files now also
rotate when reaching 100 MB.
To select which logs to output, use the MONERO_LOGS environment
variable, with a comma separated list of categories (globs are
supported), with their requested severity level after a colon.
If a log matches more than one such setting, the last one in
the configuration string applies. A few examples:
This one is (mostly) silent, only outputting fatal errors:
MONERO_LOGS=*:FATAL
This one is very verbose:
MONERO_LOGS=*:TRACE
This one is totally silent (logwise):
MONERO_LOGS=""
This one outputs all errors and warnings, except for the
"verify" category, which prints just fatal errors (the verify
category is used for logs about incoming transactions and
blocks, and it is expected that some/many will fail to verify,
hence we don't want the spam):
MONERO_LOGS=*:WARNING,verify:FATAL
Log levels are, in decreasing order of priority:
FATAL, ERROR, WARNING, INFO, DEBUG, TRACE
Subcategories may be added using prefixes and globs. This
example will output net.p2p logs at the TRACE level, but all
other net* logs only at INFO:
MONERO_LOGS=*:ERROR,net*:INFO,net.p2p:TRACE
Logs which are intended for the user (which Monero was using
a lot through epee, but really isn't a nice way to go things)
should use the "global" category. There are a few helper macros
for using this category, eg: MGINFO("this shows up by default")
or MGINFO_RED("this is red"), to try to keep a similar look
and feel for now.
Existing epee log macros still exist, and map to the new log
levels, but since they're used as a "user facing" UI element
as much as a logging system, they often don't map well to log
severities (ie, a log level 0 log may be an error, or may be
something we want the user to see, such as an important info).
In those cases, I tried to use the new macros. In other cases,
I left the existing macros in. When modifying logs, it is
probably best to switch to the new macros with explicit levels.
The --log-level options and set_log commands now also accept
category settings, in addition to the epee style log levels.
2017-01-01 16:34:23 +00:00
|
|
|
#undef MONERO_DEFAULT_LOG_CATEGORY
|
|
|
|
#define MONERO_DEFAULT_LOG_CATEGORY "perf"
|
|
|
|
|
2018-01-08 10:53:42 +00:00
|
|
|
namespace
|
|
|
|
{
|
|
|
|
uint64_t get_tick_count()
|
|
|
|
{
|
|
|
|
#if defined(__x86_64__)
|
|
|
|
uint32_t hi, lo;
|
|
|
|
__asm__ volatile("rdtsc" : "=a"(lo), "=d"(hi));
|
|
|
|
return (((uint64_t)hi) << 32) | (uint64_t)lo;
|
|
|
|
#else
|
|
|
|
return epee::misc_utils::get_ns_count();
|
|
|
|
#endif
|
|
|
|
}
|
|
|
|
|
|
|
|
#ifdef __x86_64__
|
|
|
|
uint64_t get_ticks_per_ns()
|
|
|
|
{
|
2018-02-02 16:05:06 +00:00
|
|
|
uint64_t t0 = epee::misc_utils::get_ns_count(), t1;
|
2018-01-08 10:53:42 +00:00
|
|
|
uint64_t r0 = get_tick_count();
|
|
|
|
|
|
|
|
while (1)
|
|
|
|
{
|
2018-02-02 16:05:06 +00:00
|
|
|
t1 = epee::misc_utils::get_ns_count();
|
|
|
|
if (t1 - t0 > 1*1000000000) break; // work one second
|
2018-01-08 10:53:42 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
uint64_t r1 = get_tick_count();
|
|
|
|
uint64_t tpns256 = 256 * (r1 - r0) / (t1 - t0);
|
|
|
|
return tpns256 ? tpns256 : 1;
|
|
|
|
}
|
|
|
|
#endif
|
|
|
|
|
|
|
|
#ifdef __x86_64__
|
|
|
|
uint64_t ticks_per_ns = get_ticks_per_ns();
|
|
|
|
#endif
|
|
|
|
|
|
|
|
uint64_t ticks_to_ns(uint64_t ticks)
|
|
|
|
{
|
|
|
|
#if defined(__x86_64__)
|
|
|
|
return 256 * ticks / ticks_per_ns;
|
|
|
|
#else
|
|
|
|
return ticks;
|
|
|
|
#endif
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2016-10-10 19:47:00 +00:00
|
|
|
namespace tools
|
|
|
|
{
|
|
|
|
|
Change logging to easylogging++
This replaces the epee and data_loggers logging systems with
a single one, and also adds filename:line and explicit severity
levels. Categories may be defined, and logging severity set
by category (or set of categories). epee style 0-4 log level
maps to a sensible severity configuration. Log files now also
rotate when reaching 100 MB.
To select which logs to output, use the MONERO_LOGS environment
variable, with a comma separated list of categories (globs are
supported), with their requested severity level after a colon.
If a log matches more than one such setting, the last one in
the configuration string applies. A few examples:
This one is (mostly) silent, only outputting fatal errors:
MONERO_LOGS=*:FATAL
This one is very verbose:
MONERO_LOGS=*:TRACE
This one is totally silent (logwise):
MONERO_LOGS=""
This one outputs all errors and warnings, except for the
"verify" category, which prints just fatal errors (the verify
category is used for logs about incoming transactions and
blocks, and it is expected that some/many will fail to verify,
hence we don't want the spam):
MONERO_LOGS=*:WARNING,verify:FATAL
Log levels are, in decreasing order of priority:
FATAL, ERROR, WARNING, INFO, DEBUG, TRACE
Subcategories may be added using prefixes and globs. This
example will output net.p2p logs at the TRACE level, but all
other net* logs only at INFO:
MONERO_LOGS=*:ERROR,net*:INFO,net.p2p:TRACE
Logs which are intended for the user (which Monero was using
a lot through epee, but really isn't a nice way to go things)
should use the "global" category. There are a few helper macros
for using this category, eg: MGINFO("this shows up by default")
or MGINFO_RED("this is red"), to try to keep a similar look
and feel for now.
Existing epee log macros still exist, and map to the new log
levels, but since they're used as a "user facing" UI element
as much as a logging system, they often don't map well to log
severities (ie, a log level 0 log may be an error, or may be
something we want the user to see, such as an important info).
In those cases, I tried to use the new macros. In other cases,
I left the existing macros in. When modifying logs, it is
probably best to switch to the new macros with explicit levels.
The --log-level options and set_log commands now also accept
category settings, in addition to the epee style log levels.
2017-01-01 16:34:23 +00:00
|
|
|
el::Level performance_timer_log_level = el::Level::Debug;
|
2017-11-25 22:25:05 +00:00
|
|
|
|
|
|
|
static __thread std::vector<PerformanceTimer*> *performance_timers = NULL;
|
2016-10-10 19:47:00 +00:00
|
|
|
|
Change logging to easylogging++
This replaces the epee and data_loggers logging systems with
a single one, and also adds filename:line and explicit severity
levels. Categories may be defined, and logging severity set
by category (or set of categories). epee style 0-4 log level
maps to a sensible severity configuration. Log files now also
rotate when reaching 100 MB.
To select which logs to output, use the MONERO_LOGS environment
variable, with a comma separated list of categories (globs are
supported), with their requested severity level after a colon.
If a log matches more than one such setting, the last one in
the configuration string applies. A few examples:
This one is (mostly) silent, only outputting fatal errors:
MONERO_LOGS=*:FATAL
This one is very verbose:
MONERO_LOGS=*:TRACE
This one is totally silent (logwise):
MONERO_LOGS=""
This one outputs all errors and warnings, except for the
"verify" category, which prints just fatal errors (the verify
category is used for logs about incoming transactions and
blocks, and it is expected that some/many will fail to verify,
hence we don't want the spam):
MONERO_LOGS=*:WARNING,verify:FATAL
Log levels are, in decreasing order of priority:
FATAL, ERROR, WARNING, INFO, DEBUG, TRACE
Subcategories may be added using prefixes and globs. This
example will output net.p2p logs at the TRACE level, but all
other net* logs only at INFO:
MONERO_LOGS=*:ERROR,net*:INFO,net.p2p:TRACE
Logs which are intended for the user (which Monero was using
a lot through epee, but really isn't a nice way to go things)
should use the "global" category. There are a few helper macros
for using this category, eg: MGINFO("this shows up by default")
or MGINFO_RED("this is red"), to try to keep a similar look
and feel for now.
Existing epee log macros still exist, and map to the new log
levels, but since they're used as a "user facing" UI element
as much as a logging system, they often don't map well to log
severities (ie, a log level 0 log may be an error, or may be
something we want the user to see, such as an important info).
In those cases, I tried to use the new macros. In other cases,
I left the existing macros in. When modifying logs, it is
probably best to switch to the new macros with explicit levels.
The --log-level options and set_log commands now also accept
category settings, in addition to the epee style log levels.
2017-01-01 16:34:23 +00:00
|
|
|
void set_performance_timer_log_level(el::Level level)
|
2016-10-10 19:47:00 +00:00
|
|
|
{
|
Change logging to easylogging++
This replaces the epee and data_loggers logging systems with
a single one, and also adds filename:line and explicit severity
levels. Categories may be defined, and logging severity set
by category (or set of categories). epee style 0-4 log level
maps to a sensible severity configuration. Log files now also
rotate when reaching 100 MB.
To select which logs to output, use the MONERO_LOGS environment
variable, with a comma separated list of categories (globs are
supported), with their requested severity level after a colon.
If a log matches more than one such setting, the last one in
the configuration string applies. A few examples:
This one is (mostly) silent, only outputting fatal errors:
MONERO_LOGS=*:FATAL
This one is very verbose:
MONERO_LOGS=*:TRACE
This one is totally silent (logwise):
MONERO_LOGS=""
This one outputs all errors and warnings, except for the
"verify" category, which prints just fatal errors (the verify
category is used for logs about incoming transactions and
blocks, and it is expected that some/many will fail to verify,
hence we don't want the spam):
MONERO_LOGS=*:WARNING,verify:FATAL
Log levels are, in decreasing order of priority:
FATAL, ERROR, WARNING, INFO, DEBUG, TRACE
Subcategories may be added using prefixes and globs. This
example will output net.p2p logs at the TRACE level, but all
other net* logs only at INFO:
MONERO_LOGS=*:ERROR,net*:INFO,net.p2p:TRACE
Logs which are intended for the user (which Monero was using
a lot through epee, but really isn't a nice way to go things)
should use the "global" category. There are a few helper macros
for using this category, eg: MGINFO("this shows up by default")
or MGINFO_RED("this is red"), to try to keep a similar look
and feel for now.
Existing epee log macros still exist, and map to the new log
levels, but since they're used as a "user facing" UI element
as much as a logging system, they often don't map well to log
severities (ie, a log level 0 log may be an error, or may be
something we want the user to see, such as an important info).
In those cases, I tried to use the new macros. In other cases,
I left the existing macros in. When modifying logs, it is
probably best to switch to the new macros with explicit levels.
The --log-level options and set_log commands now also accept
category settings, in addition to the epee style log levels.
2017-01-01 16:34:23 +00:00
|
|
|
if (level != el::Level::Debug && level != el::Level::Trace && level != el::Level::Info
|
|
|
|
&& level != el::Level::Warning && level != el::Level::Error && level != el::Level::Fatal)
|
2016-10-10 19:47:00 +00:00
|
|
|
{
|
Change logging to easylogging++
This replaces the epee and data_loggers logging systems with
a single one, and also adds filename:line and explicit severity
levels. Categories may be defined, and logging severity set
by category (or set of categories). epee style 0-4 log level
maps to a sensible severity configuration. Log files now also
rotate when reaching 100 MB.
To select which logs to output, use the MONERO_LOGS environment
variable, with a comma separated list of categories (globs are
supported), with their requested severity level after a colon.
If a log matches more than one such setting, the last one in
the configuration string applies. A few examples:
This one is (mostly) silent, only outputting fatal errors:
MONERO_LOGS=*:FATAL
This one is very verbose:
MONERO_LOGS=*:TRACE
This one is totally silent (logwise):
MONERO_LOGS=""
This one outputs all errors and warnings, except for the
"verify" category, which prints just fatal errors (the verify
category is used for logs about incoming transactions and
blocks, and it is expected that some/many will fail to verify,
hence we don't want the spam):
MONERO_LOGS=*:WARNING,verify:FATAL
Log levels are, in decreasing order of priority:
FATAL, ERROR, WARNING, INFO, DEBUG, TRACE
Subcategories may be added using prefixes and globs. This
example will output net.p2p logs at the TRACE level, but all
other net* logs only at INFO:
MONERO_LOGS=*:ERROR,net*:INFO,net.p2p:TRACE
Logs which are intended for the user (which Monero was using
a lot through epee, but really isn't a nice way to go things)
should use the "global" category. There are a few helper macros
for using this category, eg: MGINFO("this shows up by default")
or MGINFO_RED("this is red"), to try to keep a similar look
and feel for now.
Existing epee log macros still exist, and map to the new log
levels, but since they're used as a "user facing" UI element
as much as a logging system, they often don't map well to log
severities (ie, a log level 0 log may be an error, or may be
something we want the user to see, such as an important info).
In those cases, I tried to use the new macros. In other cases,
I left the existing macros in. When modifying logs, it is
probably best to switch to the new macros with explicit levels.
The --log-level options and set_log commands now also accept
category settings, in addition to the epee style log levels.
2017-01-01 16:34:23 +00:00
|
|
|
MERROR("Wrong log level: " << el::LevelHelper::convertToString(level) << ", using Debug");
|
|
|
|
level = el::Level::Debug;
|
2016-10-10 19:47:00 +00:00
|
|
|
}
|
|
|
|
performance_timer_log_level = level;
|
|
|
|
}
|
|
|
|
|
2018-01-08 10:53:42 +00:00
|
|
|
PerformanceTimer::PerformanceTimer(const std::string &s, uint64_t unit, el::Level l): name(s), unit(unit), level(l), started(false), paused(false)
|
2017-11-25 22:25:05 +00:00
|
|
|
{
|
2018-01-08 10:53:42 +00:00
|
|
|
ticks = get_tick_count();
|
2017-11-25 22:25:05 +00:00
|
|
|
if (!performance_timers)
|
|
|
|
{
|
|
|
|
MLOG(level, "PERF ----------");
|
|
|
|
performance_timers = new std::vector<PerformanceTimer*>();
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
PerformanceTimer *pt = performance_timers->back();
|
2018-01-08 10:53:42 +00:00
|
|
|
if (!pt->started && !pt->paused)
|
2017-11-25 22:25:05 +00:00
|
|
|
{
|
2018-01-08 10:53:42 +00:00
|
|
|
size_t size = 0; for (const auto *tmp: *performance_timers) if (!tmp->paused) ++size;
|
|
|
|
MLOG(pt->level, "PERF " << std::string((size-1) * 2, ' ') << " " << pt->name);
|
2017-11-25 22:25:05 +00:00
|
|
|
pt->started = true;
|
|
|
|
}
|
|
|
|
}
|
|
|
|
performance_timers->push_back(this);
|
|
|
|
}
|
|
|
|
|
|
|
|
PerformanceTimer::~PerformanceTimer()
|
|
|
|
{
|
|
|
|
performance_timers->pop_back();
|
2018-01-08 10:53:42 +00:00
|
|
|
if (!paused)
|
|
|
|
ticks = get_tick_count() - ticks;
|
2017-11-25 22:25:05 +00:00
|
|
|
char s[12];
|
2018-01-08 10:53:42 +00:00
|
|
|
snprintf(s, sizeof(s), "%8llu ", (unsigned long long)(ticks_to_ns(ticks) / (1000000000 / unit)));
|
|
|
|
size_t size = 0; for (const auto *tmp: *performance_timers) if (!tmp->paused || tmp==this) ++size;
|
|
|
|
MLOG(level, "PERF " << s << std::string(size * 2, ' ') << " " << name);
|
2017-11-25 22:25:05 +00:00
|
|
|
if (performance_timers->empty())
|
|
|
|
{
|
|
|
|
delete performance_timers;
|
|
|
|
performance_timers = NULL;
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2018-01-08 10:53:42 +00:00
|
|
|
void PerformanceTimer::pause()
|
|
|
|
{
|
|
|
|
if (paused)
|
|
|
|
return;
|
|
|
|
ticks = get_tick_count() - ticks;
|
|
|
|
paused = true;
|
|
|
|
}
|
|
|
|
|
|
|
|
void PerformanceTimer::resume()
|
|
|
|
{
|
|
|
|
if (!paused)
|
|
|
|
return;
|
|
|
|
ticks = get_tick_count() - ticks;
|
|
|
|
paused = false;
|
|
|
|
}
|
|
|
|
|
2016-10-10 19:47:00 +00:00
|
|
|
}
|