Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add PerfLog #3974

Merged
merged 14 commits into from Apr 3, 2018
Merged

Add PerfLog #3974

merged 14 commits into from Apr 3, 2018

Conversation

tresf
Copy link
Member

@tresf tresf commented Nov 15, 2017

Add the perflog implementation as discussed in #3882.

I did not write this code. Instead I've cherry-picked the commit from a rouge branch. @softrabbit can you please decide if this is worth superseding #3882 or not and make recommends, merge, etc?

Edit: Please push directly to this branch with changes!

Conflicts:
	plugins/zynaddsubfx/zynaddsubfx
*
*/

//#ifdef LMMS_DEBUG_PERFLOG
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think LMMS_DEBUG_PERFLOG guard should be re-enabled here and added into PerfLog.h. It will fix Windows build, too.

CMakeLists.txt Outdated
@@ -68,6 +68,7 @@ OPTION(WANT_VST_NOWINE "Include partial VST support (without wine)" OFF)
OPTION(WANT_WINMM "Include WinMM MIDI support" OFF)
OPTION(WANT_QT5 "Build with Qt5" OFF)
OPTION(WANT_DEBUG_FPE "Debug floating point exceptions" OFF)
OPTION(WANT_DEBUG_PERFLOG "Log task performance" ON)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should the default value be OFF, like FPE debugging?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

OFF sounds right to me, too.


#ifndef PERFLOG_H
#define PERFLOG_H

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So lmmsconfig.h should be included in this file.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yup, to be sure. Most files that include this will probably include lmmsconfig.h too, but who knows where we'll bump into an exception from the rule.

@PhysSong
Copy link
Member

A lot of code is inconsistent with our coding convention, too.
@gi0e5b06

@PhysSong
Copy link
Member

Note that this PR doesn't make any usage of PerfLog class.
Another topic... Class PerfLog is only used by calling its static member functions. In other words, creating its instance doesn't make sense. I wonder if this class can be used with instances and/or wrapper classes.

@gi0e5b06
Copy link

@PhysSong I went for simplicity here. And for the fact that no code is added if the option is not activated. If you want to extend and/or configure it, a singleton would be better. If you want to make it an aspect, this is also possible. Both can be added later, if there is a need (which I don't really foresee for now).

OTOH, I may see a need to show cumulated times. And eventually to have it also working on Windows.

@lukas-w lukas-w self-requested a review November 15, 2017 12:12
Copy link
Member

@lukas-w lukas-w left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@gi0e5b06 I'm not quite able to relate to the design choices made in writing the PerfLog class. I find looking up instances of timers in static functions using a QHash object to be a rather strange way of approaching a problem that object oriented programming already solved for us.

The class could be a lot simpler, and should look something like this instead:

class PerfLog
{
public:
    void begin(const QString& name);
    void end();

private:
    clock_t c;
    tms t;
    QString name;
};

Alternatively, begin could become the class's constructor.

It can then be used like so:

PerfLogTimer timer;
timer.begin();

longRunningTask();

time.end();

Also, a better name is probably something like PerfLogTimer, since an instance of the class is a timer, not a log.

PerfLog::Entry e;
PerfLog::Entry b = s_running.take(what);
// | task | real | user | syst
qWarning("PERFLOG | %20s | %7.2f | %7.2f | %7.2f",
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we use an output format close to the one originally proposed by @softrabbit? It includes labels for better understanding of the output:

Real Time: %.2f, User Time %.2f, System Time %.2f

PerfLog::Entry::Entry()
{
c = times(&t);
if (c == -1) { qFatal("PerfLogEntry: init failed"); }
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think using qFatal is reasonable here or in line 52. If times fails, we can't mesaure the time here, but it doesn't mean we need to crash LMMS.

@PhysSong
Copy link
Member

I find looking up instances of timers in static functions using a QHash object to be a rather strange way of approaching a problem

Totally agree. I thought about something similar:

I wonder if this class can be used with instances

@gi0e5b06
Copy link

gi0e5b06 commented Nov 15, 2017

  • begin() and end() don't happen neither in the same method, nor in the same class, not even necessarly in the same thread.
  • PerfLog is used during the development and testing phases, not in the final product. qFaral should never happen. But if it happens, the developper should be immediately aware of it.
  • The format is to leave room for the other colums (cumulated times, file, line, etc) and to be easily parseable. A header could be added, if you feel so.

@lukas-w
Copy link
Member

lukas-w commented Nov 15, 2017

begin() and end() don't happen neither in the same method, nor in the same class, not even necessarly in the same thread.

That sounds speculative to me. Do you have an example use-case to back this statement? I can't think of any situation where this is necessary without a major design flaw being at fault. In #3882, the PR that spawned this class, begin() and end() do indeed lie in the same method.

PerfLog is used during the development and testing phases, not in the final product. qFaral should never happen. But if it happens, the developper should be immediately aware of it.

Crashing the program is not the only way of making the developer aware of a problem. qFatal() is reserved for situations when an error happens that the application cannot recover from, forcing it to abort execution. It's not intended for debugging. qWarning() is fine in this case.

The format is to leave room for the other colums (cumulated times, file, line, etc) and to be easily parseable.

Let's worry about space when we actually add more columns. Let's worry about ease of parsing when the need for parsing it arises. For now, humans read these logs, so that's who it should be made readable for.

@tresf
Copy link
Member Author

tresf commented Nov 17, 2017

A lot of code is inconsistent with our coding convention, too. @gi0e5b06

I disagree. The code formatting is actually quite clean and it doesn't seem to break any obvious rules. There are some conventions that need to die (such as 4 spaces between functions), but other than that, what's wrong with the formatting?

@tresf
Copy link
Member Author

tresf commented Nov 17, 2017

... oh I see them now. A few misplaced spaces. The if (true) doSomething(); logic is very common BTW. It's not a convention we should overly police.

@tresf
Copy link
Member Author

tresf commented Dec 24, 2017

Since @gi0e5b06 has no intentions on working together on our PRs, this should be coded by the devs commenting or closed out. @PhysSong made some fixes. @lukas-w I think you're next. If you prefer not to write this feature in this manner, we can also close it out. It should be superseding @softrabbit's #3882 so that should be decided as well.

Last, I think at least the basic benchmarks are useful enough to have on all the time. I haven't seen any valid arguments against them and there shouldn't be a severe CPU hit. Optionally we could move the benchmarks to a UI setting and CLI flag, but I don't think this belongs in the build system. Bench marking should be possible without recompilation.

@lukas-w
Copy link
Member

lukas-w commented Jan 8, 2018

@tresf I made the suggested changes. I also split the class into PerfTime, which represents a point in time, and PerfLog which does the actual logging. I removed the build options, so that it's always enabled. The implementation is still POSIX-only and will therefore not work with MSVC.

We should probably check for redundancies with MixerProfiler which appears to serve a very similar purpose.

@tresf
Copy link
Member Author

tresf commented Jan 8, 2018

and will therefore not work with MSVC.

What about Mac? I saw you had this enabled for Linux only. It seems NOT WIN32 might be a better trigger, right?

@lukas-w
Copy link
Member

lukas-w commented Jan 8, 2018

I saw you had this enabled for Linux only.

Just pushed to the wrong remote. Removed via 7615c86.

@lukas-w
Copy link
Member

lukas-w commented Jan 8, 2018

Renamed PerfLog to PerfLogTimer and added usage to ProjectRenderer::run() as in #3882.

@lukas-w
Copy link
Member

lukas-w commented Jan 8, 2018

Mistook sys/times.h for sys/time.h, fixed via 5582d96. This means it doesn't work with MinGW though.

@@ -26,6 +26,7 @@
#cmakedefine LMMS_HAVE_SF_COMPLEVEL

#cmakedefine LMMS_DEBUG_FPE
#cmakedefine LMMS_DEBUG_PERFLOG
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@lukas-w This line should be removed now, right?

@@ -250,7 +251,6 @@ IF(WANT_SDL AND NOT LMMS_HAVE_SDL2)
IF(NOT SDL_INCLUDE_DIR)
SET(SDL_INCLUDE_DIR "${CMAKE_FIND_ROOT_PATH}/include")
ENDIF()

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This newline change seems meaningless.

/*
* PerfLog.h - Small performance logger
*
* Copyright (c) 2017 gi0e5b06
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is this line enough as copyright information?

@PhysSong
Copy link
Member

When/If this PR is merged, who should get credit?

@lukas-w
Copy link
Member

lukas-w commented Jan 31, 2018

@PhysSong Well 6a809a5 was pretty close to a rewrite, there's hardly anything left from the original code by @gi0e5b06. What about just writing Copyright (c) LMMS Developers?. Any way, I don't care about being credited, so we might as well remove the notice, so long as @gi0e5b06 is fine with it.

Slightly off-topic, but would it be a good idea to license single files as e.g. MIT, while releasing LMMS as a whole as GPL? It could keep potentially re-usable components under a more liberal license, so they can be used by other projects more freely (such as the qt5 x11 embed module, which I moved to its own repository partly for this reason). The only downside I can see is that contributors may not be expect part of their work to be licensed differently when touching those files.

@tresf
Copy link
Member Author

tresf commented Jan 31, 2018

Slightly off-topic, but would it be a good idea to license single files as e.g. MIT, while releasing LMMS as a whole as GPL?

Important and valuable ones, yes. This guy is a boilerplate class though, common on projects like ours. I don't see it as falling into that category, but yes, offering a more liberal license can always help. If it's bundled, we may want to fly a larger warning/disclaimer, such as through a README.md, etc.

@tresf
Copy link
Member Author

tresf commented Jan 31, 2018

Copyright (c) LMMS Developers

Sure or @PhysSong and/or @lukas-w, you guys are actually working on making it mergeable. 👍

@PhysSong
Copy link
Member

PhysSong commented Mar 8, 2018

I guess we can merge this after reverting unnecessary changes and updating copyright statement. Are there any other things left?

@PhysSong
Copy link
Member

PhysSong commented Apr 3, 2018

@lukas-w Is this ready for merge?

@lukas-w
Copy link
Member

lukas-w commented Apr 3, 2018

@PhysSong Yup 👍

@lukas-w lukas-w merged commit 9af7821 into LMMS:master Apr 3, 2018
@gi0e5b06
Copy link

gi0e5b06 commented Apr 3, 2018

As it is now, this PR is quite useless but it is not intrusive and so not harmful to the project. I don't think anyone will use it anyway. As for the copyright, you can not use LMMS Developers because it is not a definite entity. You should credit the contributors, starting with softrabbit (but excluding me, as I don't want to be associated with code of that quality).

@lukas-w
Copy link
Member

lukas-w commented Apr 3, 2018

@gi0e5b06 You've consistently refused to help with any contributions (including this PR), so this time the team has actually gone through the trouble of getting some of your code into a merge-able state and integrating it into the project. Your reaction to this being an open devaluation of the work done is an insult to the team.

I've taken the liberty of putting an end to your presumptious behaviour here by blocking you from the tracker for now. Feel free to reach out to me or other admins via Discord or E-Mail if you feel like this should be reverted.

sdasda7777 pushed a commit to sdasda7777/lmms that referenced this pull request Jun 28, 2022
Add `PerfTime` class representing a point in CPU time and `PerfLogTimer`, used for measuring and logging a time period. Used in `ProjectRenderer::run()
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

5 participants