From 9af7821eb1686c292cf037c21caf5cb2a8770ebf Mon Sep 17 00:00:00 2001 From: Tres Finocchiaro Date: Tue, 3 Apr 2018 07:37:25 -0400 Subject: [PATCH] Add PerfLog (#3974) Add `PerfTime` class representing a point in CPU time and `PerfLogTimer`, used for measuring and logging a time period. Used in `ProjectRenderer::run() --- CMakeLists.txt | 3 +- include/PerfLog.h | 73 +++++++++++++++++++ src/core/CMakeLists.txt | 1 + src/core/PerfLog.cpp | 131 +++++++++++++++++++++++++++++++++++ src/core/ProjectRenderer.cpp | 5 ++ src/lmmsconfig.h.in | 1 + 6 files changed, 213 insertions(+), 1 deletion(-) create mode 100644 include/PerfLog.h create mode 100644 src/core/PerfLog.cpp diff --git a/CMakeLists.txt b/CMakeLists.txt index 7b5520601..dde248972 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -124,6 +124,7 @@ CHECK_INCLUDE_FILES(sys/types.h LMMS_HAVE_SYS_TYPES_H) CHECK_INCLUDE_FILES(sys/ipc.h LMMS_HAVE_SYS_IPC_H) CHECK_INCLUDE_FILES(sys/shm.h LMMS_HAVE_SYS_SHM_H) CHECK_INCLUDE_FILES(sys/time.h LMMS_HAVE_SYS_TIME_H) +CHECK_INCLUDE_FILES(sys/times.h LMMS_HAVE_SYS_TIMES_H) CHECK_INCLUDE_FILES(sched.h LMMS_HAVE_SCHED_H) CHECK_INCLUDE_FILES(sys/soundcard.h LMMS_HAVE_SYS_SOUNDCARD_H) CHECK_INCLUDE_FILES(soundcard.h LMMS_HAVE_SOUNDCARD_H) @@ -250,7 +251,7 @@ IF(WANT_SDL AND NOT LMMS_HAVE_SDL2) IF(NOT SDL_INCLUDE_DIR) SET(SDL_INCLUDE_DIR "${CMAKE_FIND_ROOT_PATH}/include") ENDIF() - + ELSE() SET(STATUS_SDL "not found, please install libsdl2-dev (or similar) " "if you require SDL support") diff --git a/include/PerfLog.h b/include/PerfLog.h new file mode 100644 index 000000000..f9790113d --- /dev/null +++ b/include/PerfLog.h @@ -0,0 +1,73 @@ +/* + * PerfLog.h - Small performance logger + * + * Copyright (c) 2017-2018 LMMS Developers + * + * This file is part of LMMS - https://lmms.io + * + * This program is free software; you can redistribute it and/or + * modify it under the terms of the GNU General Public + * License as published by the Free Software Foundation; either + * version 2 of the License, or (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * General Public License for more details. + * + * You should have received a copy of the GNU General Public + * License along with this program (see COPYING); if not, write to the + * Free Software Foundation, Inc., 51 Franklin Street, Fifth Floor, + * Boston, MA 02110-1301 USA. + * + */ + +#ifndef PERFLOG_H +#define PERFLOG_H + +#include +#include + +/// \brief CPU time point +/// +/// Represents a point in CPU time (not wall-clock time) intended for measuring +/// performance. +class PerfTime +{ +public: + PerfTime(); + bool valid() const; + + clock_t real() const; + clock_t user() const; + clock_t system() const; + + static PerfTime now(); + static clock_t ticksPerSecond(); + + friend PerfTime operator-(const PerfTime& lhs, const PerfTime& rhs); +private: + clock_t m_real; + clock_t m_user; + clock_t m_system; +}; + +/// \brief The PerfLog class +/// +/// Measures time between construction and destruction and prints the result to +/// stderr, along with \p name. Alternatively, call begin() and end() explicitly. +class PerfLogTimer +{ + public: + PerfLogTimer(const QString& name); + ~PerfLogTimer(); + + void begin(); + void end(); + + private: + QString name; + PerfTime begin_time; +}; + +#endif diff --git a/src/core/CMakeLists.txt b/src/core/CMakeLists.txt index 49686f691..85a00780b 100644 --- a/src/core/CMakeLists.txt +++ b/src/core/CMakeLists.txt @@ -44,6 +44,7 @@ set(LMMS_SRCS core/NotePlayHandle.cpp core/Oscillator.cpp core/PeakController.cpp + core/PerfLog.cpp core/Piano.cpp core/PlayHandle.cpp core/Plugin.cpp diff --git a/src/core/PerfLog.cpp b/src/core/PerfLog.cpp new file mode 100644 index 000000000..951c6d842 --- /dev/null +++ b/src/core/PerfLog.cpp @@ -0,0 +1,131 @@ +/* + * PerfLog.cpp - Small performance logger + * + * Copyright (c) 2017-2018 LMMS Developers + * + * This file is part of LMMS - https://lmms.io + * + * This program is free software; you can redistribute it and/or + * modify it under the terms of the GNU General Public + * License as published by the Free Software Foundation; either + * version 2 of the License, or (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * General Public License for more details. + * + * You should have received a copy of the GNU General Public + * License along with this program (see COPYING); if not, write to the + * Free Software Foundation, Inc., 51 Franklin Street, Fifth Floor, + * Boston, MA 02110-1301 USA. + * + */ + +#include "PerfLog.h" + +#include "lmmsconfig.h" + +#if defined(LMMS_HAVE_SYS_TIMES_H) && defined(LMMS_HAVE_UNISTD_H) +# define USE_POSIX_TIME +#endif + +#ifdef USE_POSIX_TIME +# include +# include +#endif + +PerfTime::PerfTime() + : m_real(-1) +{ +} + +clock_t PerfTime::real() const +{ + return m_real; +} + +clock_t PerfTime::user() const +{ + return m_user; +} + +clock_t PerfTime::system() const +{ + return m_system; +} + +bool PerfTime::valid() const +{ + return m_real != -1; +} + +PerfTime PerfTime::now() +{ + PerfTime time; +#ifdef USE_POSIX_TIME + tms t; + time.m_real = times(&t); + time.m_user = t.tms_utime; + time.m_system = t.tms_stime; + if (time.m_real == -1) { qWarning("PerfTime: now failed"); } +#endif + return time; +} + +clock_t PerfTime::ticksPerSecond() +{ + static long clktck = 0; +#ifdef USE_POSIX_TIME + if (!clktck) { + if ((clktck = sysconf(_SC_CLK_TCK)) < 0) { + qWarning("PerfLog::end sysconf()"); + } + } +#endif + return clktck; +} + +PerfTime operator-(const PerfTime& lhs, const PerfTime& rhs) +{ + PerfTime diff; + diff.m_real = lhs.m_real - rhs.m_real; + diff.m_user = lhs.m_user - rhs.m_user; + diff.m_system = lhs.m_system - rhs.m_system; + return diff; +} + +PerfLogTimer::PerfLogTimer(const QString& what) + : name(what) +{ + begin(); +} + +PerfLogTimer::~PerfLogTimer() +{ + end(); +} + +void PerfLogTimer::begin() +{ + begin_time = PerfTime::now(); +} + +void PerfLogTimer::end() +{ + if (! begin_time.valid()) { + return; + } + + long clktck = PerfTime::ticksPerSecond(); + + PerfTime d = PerfTime::now() - begin_time; + qWarning("PERFLOG | %20s | %.2fuser, %.2fsystem %.2felapsed", + qPrintable(name), + d.user() / (double)clktck, + d.system() / (double)clktck, + d.real() / (double)clktck); + + // Invalidate so destructor won't call print another log entry + begin_time = PerfTime(); +} diff --git a/src/core/ProjectRenderer.cpp b/src/core/ProjectRenderer.cpp index c98effb80..adb715cfd 100644 --- a/src/core/ProjectRenderer.cpp +++ b/src/core/ProjectRenderer.cpp @@ -27,6 +27,7 @@ #include "ProjectRenderer.h" #include "Song.h" +#include "PerfLog.h" #include "AudioFileWave.h" #include "AudioFileOgg.h" @@ -177,6 +178,8 @@ void ProjectRenderer::run() #endif #endif + PerfLogTimer perfLog("Project Render"); + Engine::getSong()->startExport(); Engine::getSong()->updateLength(); // Skip first empty buffer. @@ -209,6 +212,8 @@ void ProjectRenderer::run() Engine::getSong()->stopExport(); + perfLog.end(); + // If the user aborted export-process, the file has to be deleted. const QString f = m_fileDev->outputFile(); if( m_abort ) diff --git a/src/lmmsconfig.h.in b/src/lmmsconfig.h.in index 248041f70..02d07f1e4 100644 --- a/src/lmmsconfig.h.in +++ b/src/lmmsconfig.h.in @@ -36,6 +36,7 @@ #cmakedefine LMMS_HAVE_SEMAPHORE_H #cmakedefine LMMS_HAVE_SYS_SHM_H #cmakedefine LMMS_HAVE_SYS_TIME_H +#cmakedefine LMMS_HAVE_SYS_TIMES_H #cmakedefine LMMS_HAVE_SCHED_H #cmakedefine LMMS_HAVE_SYS_SOUNDCARD_H #cmakedefine LMMS_HAVE_SOUNDCARD_H