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

AnimationTimerDelta is way too low for most systems (7ms) #5436

Closed
rburchell opened this issue Dec 3, 2018 · 38 comments
Closed

AnimationTimerDelta is way too low for most systems (7ms) #5436

rburchell opened this issue Dec 3, 2018 · 38 comments
Labels

Comments

@rburchell
Copy link

rburchell commented Dec 3, 2018

Steps to reproduce

  1. Look at the power usage (using e.g. powertop on Linux) when an animation is running
  2. Notice that it is quite high (wakeups)

Expected behaviour

Wakeups should be limited to a more sensible amount to save CPU & battery resources

Actual behaviour

Notice that telegram-desktop is making ~140 wakeups per second due to a QTimer using a AnimationTimerDelta duration (7ms, 1000 / 7 = 142, but I initially found this by using GammaRay)

Configuration

Fedora 29, T-D 1.4.3, default theming.

Suggested changes

There's a range of options here. I'm not a contributor, so I'm definitely in no position to tell you what to do, but here's my advice as to what the options might be.

  • You could use a QAbstractAnimation subclass, which should provide better behaviour (for widgets applications, it looks like it will use a fixed 16ms timer IIRC, but this has the opportunity to be improved further in the future)
  • You could use a fixed 16ms interval on your existing timer (which will be much less aggressive than it is today, already a good step forward)
  • You could use a timer interval based on what the screen can handle: (https://doc.qt.io/qt-5/qscreen.html#refreshRate-prop) -- i.e. 1000/refreshRate -- note that this will change when the QScreen of the window changes, so you will need some "extra" bits to handle that case.
  • You could stop (or significantly slow) animation ticks if the window is not focused
  • You could drive animations based on window updates (i.e. issue QWidget::update on a "global" widget, and hook the repaint event to drive animations)

Sidenote

I expect this might be contributing to some other complaints about high resource usage like #4941, #4406, #4209, too.

@rburchell
Copy link
Author

This is likely the cause of #4854 too.

@artyfarty
Copy link

This issue still persists and honestly it needs more attention.

@rgb2hsl
Copy link

rgb2hsl commented Jan 23, 2019

image

When someone's typing
image

When nobody does
image

@rburchell
Copy link
Author

@john-preston I'm happy to try help with a fix for this if you aren't able to find the time, but I don't know how you want it fixed. Can you please take a look at my original report?

@john-preston
Copy link
Member

@rburchell Well, I want it to be fixed without affecting the animations frame rate :) It should not drop below current value OR below 60 FPS if current value is higher.

Right now they are repainting as fast as they can, partially because of OS X where they were very lagging when I was using only timer to request repaints - it looked like timer events were delayed in favor of mouse move handling etc. I'm not sure. But the result was trying to update the animated widget parts right from the paintEvent handler.

@john-preston
Copy link
Member

Another problem is to test the changes in all system versions. For example macOS started working much better with my animations starting from 10.13 (if I remember correctly), but was much more laggy before, on 10.10 / 10.11. And all changes should not break them.

@rburchell
Copy link
Author

Ok, well, I don't have the capabilities to do that sort of testing. I can tell you how Qt is working internally, though, if you have questions (I know the right places to look, and am somewhat familiar with most of the code).

Yes, timers can be delayed by mouse events (somewhat dependent on the platform: in theory, a platform could try to interleave events of different types, but it's not always a trivial thing to do).

Have you considered compressing multiple mouse move events to avoid this becoming a problem? (Something like, on move, start a 0-interval timer to process it, and store the last move event recieved). Assuming mouse move processing is expensive on the application side, this should give quite a large benefit, but of course if you're doing something like paint/draw on move, then it's not really practical to do this without some extra work (because you probably want to draw between every position to avoid non-smooth lines).

Generally, I'd say that you should aim to do your painting on paintEvent, unless there are some special circumstances (complex drawing/calculations, in which case, you will probably want caching on top). Animations seem like a bit of a strange case to need that sort of treatment to me, but obviously, I don't know this code well.

@Sutarat66
Copy link

Sutarat66 commented Jan 31, 2019 via email

@john-preston
Copy link
Member

@rburchell 1.5.15 should be a little bit better. Before the animation timer was running always, even when no animations on the screen were playing (there always was an invisible one, that did nothing, but timer was working). Now it at least should work only when the animation is playing.

@rburchell
Copy link
Author

Fantastic, that is a very good improvement! Do you happen to know the commits that changed it? I'd like to take a look.

@john-preston
Copy link
Member

@rburchell 26f1ade

Before this commit the connecting status widget (that has a radial progress) was always existing, but just hidden. And it's infinite radial progress animation was always playing (doing nothing — because the widget was hidden and "update" was a no-op).

After this commit only "connection status observer" is always existing and it creates a widget right before it is going to be shown — and destroys it right after it is hidden.

@john-preston
Copy link
Member

Also I did implement a (possibly) better animations manager, that hooks into QEvent::UpdateRequest and performs an animation step there + after the painting is done it sets a timer for the remaining time to get 60 FPS (if the paint was less than 1ms, the timer will be set for 16ms, if the paint took 6ms, the timer will be set for 10ms, etc).

When I find time to test it in at least some places to replace the existing animations and if it will work fine I hope it will improve this as well.

@artyfarty
Copy link

Telegram 1.5.15

Typing animation now consumes about 30% cpu, while idle telegram takes 5-10% cpu. So, there is a slight improvement. Time will tell if it's consistent, but IMO the client is still cpu-hungry.

@john-preston
Copy link
Member

@artyfarty I guess I should try the new animations on the typings first and see if it will make any difference.

Also perhaps typing animations can be optimized in terms of painting.

@artyfarty
Copy link

The problem still persists.

A funny storry: we've recently made a group chat at work where people report daily at 13:00 about their plans. As they tend to type long messages, my notebook takes off for several minutes of gorgeous typing animations.

@john-preston
Copy link
Member

I tried to make it more like 16ms, but strangely it was not looking good :( I had a couple of reports of not smooth animation and it returned back to normal with delta around 8ms, even with the new engine. You can check out beta version 1.6.6, but I'm afraid it won't be any better.

@artyfarty
Copy link

wait, how long was it there?
image

That's a nice compromise.

@kennylevinsen
Copy link

kennylevinsen commented Jul 15, 2019

I tried to make it more like 16ms, but strangely it was not looking good

This is likely because you're not rendering on paint events from Qt, but running a software timer.

A software timer will always result in tearing when not double-buffered, and often result in missed frames, and any timer that is not the exact same as the refresh rate will always waste CPU.

For 16ms, you were likely having tearing of some sort—no screen has a refresh rate of 62.5Hz, which is what 16ms gives. :)

There is only one correct way to implement continuous rendering, such as animations, which goes like this:

  1. Check if an event handler is already registered. If so, stop immediately
  2. Register paint event handler (framework-specific).
  3. Paint first frame.
  4. Wait for paint event.
  5. If we're still needed, go to Hidden group #2.
  6. Otherwise, tear down paint event handler.

Also, an important note is to ensure that one is not calling excessive paints by using QPainter's repaint() method: Instead, update() should be used so only a single paint will be done.

@kennylevinsen
Copy link

Example code (using qt4 - that's what I had lying around).

// build with qt4 and `g++ -I. -I /usr/include/QtGui -I /usr/include/QtOpenGL -lQtGui -lQtCore -lQtOpenGL -fPIC -O3 main.cpp`
#include <QtGui>
#include <QtOpenGL>
typedef QGLWidget GLWidget;

class Widget: public GLWidget
{
    Q_OBJECT

    bool mAnimate;
    QTimer mTimer;
    QPolygonF mPolygon;

    qreal angle;

    void paintEvent(QPaintEvent *) {
        if (!mAnimate) {
            // We're done drawing, stop!
            return;
        }
 
        int len = qMin(height(), width());
        QPainter p(this);
        p.translate(width()/2.0, height()/2.0);
        p.scale(len*.8, len*.8);
        p.rotate(angle);
        p.setPen(QPen(Qt::black, 0.01));
        p.drawPolygon(mPolygon);
        p.end();

        // We issue an update to request repaint next time its a good idea.
        angle += 1;
        update();
    }

public Q_SLOTS:
    // For simplicity, our animation is simply toggled on/off on a timer.
    void toggle() {
        mAnimate = !mAnimate;
        if (mAnimate) {
            update();
            // Let it run for four seconds.
            mTimer.start(4000);
        } else {
            // Take a two second break.
            mTimer.start(2000);
        }
    }

public:
    Widget(QWidget *parent = 0) : GLWidget(parent) {
        mPolygon.resize(2);
        mPolygon[0] = QPointF(0,  0);
        mPolygon[1] = QPointF(0,  0.5);
        setAutoFillBackground(true);

        mAnimate = false;

        connect(&mTimer, SIGNAL(timeout()), SLOT(toggle()));
        toggle();
    }
};

// regenerate with `moc-qt4 main.cpp > file.moc`
#include "file.moc"

int main(int argc, char *argv[])
{
    QApplication a(argc, argv);
    Widget w;
    w.show();
    return a.exec();
}

The general flow:

  1. mAnimate is set to true
  2. update() is called so that a paint event will arrive at some point
  3. On every paint where mAnimate is true, the widget will draw itself and call update() to request a new paint.
  4. When the animation should stop, mAnimate is simply set to false. Nothing will happen on next paint.

Notice that repaint() is never called, and timers are not used to paint (the timer present is just the demo enable/disable timer). This let's Qt decide the appropriate frame timing, which should follow vblank, which on my machine is a steady 60fps.

@Aokromes
Copy link
Collaborator

this bug is still valid?

@madriani
Copy link

madriani commented Jan 26, 2020

this bug is still valid?

I just did a test with the last version of Telegram (1.9.8) on my Surface Pro 3 running Windows 10 1909.
I used the same tools as in my original ticket #4914, and the result is the same.
So, I would say that, at least on Windows, the bug is still present.
PS Even disabling animations in settings and restarting Telegram did not solve the problem.

@rburchell
Copy link
Author

The timer is still there, and still being activated at a very high rate (every 8ms / 125 times a second according to PowerTop / GammaRay).

Looking at gdb, I think the timer is this one:

(gdb) bt
#0  QTimerInfoList::registerTimer(int, int, Qt::TimerType, QObject*)
    (this=0x5555579d9690, timerId=24, interval=8, timerType=Qt::PreciseTimer, object=0x7fffd8014050) at kernel/qtimerinfo_unix.cpp:447
#1  0x00007ffff7007989 in QAbstractEventDispatcher::registerTimer(int, Qt::TimerType, QObject*)
    (this=0x5555579d6be0, interval=interval@entry=8, timerType=timerType@entry=Qt::PreciseTimer, object=object@entry=0x7fffd8014050)
    at kernel/qabstracteventdispatcher.cpp:268
#2  0x00007ffff7036140 in QObject::startTimer(int, Qt::TimerType)
    (this=0x7fffd8014050, interval=8, timerType=Qt::PreciseTimer)
    at /usr/include/c++/9/bits/atomic_base.h:734
#3  0x000055555666feb4 in std::_Function_handler<void (), crl::guarded_wrap<gsl::not_null<QObject const*>, Ui::Animations::Manager::schedule()::{lambda()#1}> >::_M_invoke(std::_Any_data const&) ()
#4  0x00005555561f5742 in Core::Sandbox::decrementEventNestingLevel() ()
#5  0x00005555561ff3d5 in Core::Sandbox::notify(QObject*, QEvent*) ()
#6  0x00007ffff700a3e8 in QCoreApplication::notifyInternal2(QObject*, QEvent*) (receiver=0x7fffd8014050, event=0x555558557f70)
    at kernel/qcoreapplication.cpp:1095
<snip>

Looking at the code involved, it looks like the animations timer involved is now living at:

constexpr auto kAnimationTick = crl::time(1000) / 120;

With a tick of: constexpr auto kAnimationTick = crl::time(1000) / 120; -- which is 8.3ms (rounded down, giving 8, so indeed, I am quite confident this is the timer at fault). And confirmation: setting a backtrace in Ui::Animations::Manager::update confirms that it is being invoked regularly, and immediately hitting the return here:

if (_active.empty() || _updating || _scheduled) {
return;
}

Intriguingly, Ui::Animations::Manager::schedule is not being regularly invoked, so my guess is that an animation is going "rogue" and not being stopped when it should. Potentially noteworthy (?): I have Performance -> Enable animations disabled, with the wishful thinking from a long time ago that it might get around this bug (it did not).

@rburchell
Copy link
Author

In case it's not obvious, I would really like to see Telegram not continually drain my battery anymore - this has been going on for a really long time now, so if there's any information I can provide that might be useful here, please ask.

If you would like to replicate the testing I'm doing to verify that the timer is behaving after a fix, just attach a copy of GammaRay: https://www.kdab.com/development-resources/qt-tools/gammaray/ and look at the timers section, or stick a breakpoint in the animation manager.

(And for a high level "what is sucking my battery" on Linux answer, look at powertop.)

@rburchell
Copy link
Author

Still an issue with telegram-desktop 2.2.0 on Fedora 32. Same timer with an 8ms interval.

@ilya-fedin
Copy link
Contributor

@rburchell of course, it is not changed and there's no plan to change afaik

@rburchell
Copy link
Author

I think you misunderstand. This timer is running endlessly, burning CPU cycles and battery power, for no reason. Nothing is happening. Nothing is animating. That's the point of the bug report.

@ilya-fedin
Copy link
Contributor

ilya-fedin commented Sep 19, 2020

This timer is running endlessly, burning CPU cycles and battery power, for no reason.

Unfortunately, this doesn't change the situation. Touching that code is dangerous and no one wil fix it and PRs won't be accepted (some forks maybe accept), as preston said :(

@john-preston
Copy link
Member

@rburchell Is this in case of animations being disabled in Settings?

@rburchell
Copy link
Author

@john-preston I have seen it with animations both on and off. For perhaps a year now, I have had that setting disabled.

@whitequark
Copy link

Touching that code is dangerous and no one wil fix it and PRs won't be accepted (some forks maybe accept), as preston said :(

WTF? This is an instant messaging client, not a motor control application. There is simply no scenario in which touching animation code is "dangerous".

@ilya-fedin
Copy link
Contributor

There is simply no scenario in which touching animation code is "dangerous".

If touching animation will lead to the situation when some callbacks will stop work and application will become very buggy, it could be called dangerous, IMHO

loicmolinari added a commit to loicmolinari/lib_ui that referenced this issue Apr 10, 2021
A race condition in the animations manager can leave a dangling
timerEvent() callback firing at a high frequency (>120 FPS) in the
main loop even though there is no active animations.

An update of the animations manager returns directly when there is no
active animations. If there is at least one active animation, it stops
the timer and schedules a new update before updating animations.
Depending on the Integration implementation, the scheduling call can
be postponed after the current update. The actual postponed call
unconditionally schedules an update by starting the timer. The issue
is that in the meantime the last remaining animation could have been
removed and, when the timer callback would be fired, the update would
return directly (since there is no active animations) without being
able to stop.

The explanation above ignores the updateQueued() cases of the
postponed call for simplicity. These cases do not result in infinite
updates like the timer case but still imply one useless (invoked)
update.

This fix adds a condition in the postponed call ensuring there is at
least one active animation before processing.

telegramdesktop/tdesktop#3640
telegramdesktop/tdesktop#4854
telegramdesktop/tdesktop#5436
@loicmolinari
Copy link
Contributor

@rburchell Just stumbled upon your bug report after proposing the PR above. Seems like we had the same experience. I also came to diagnose that the timer event of the animations manager kept firing without actually updating any animations. As described in the fix, this comes down to a race condition where the last animation stops right between the deferring of the scheduling code and its execution.

I'm running with that fix for a few hours now and the timer behaves as expected. No more CPU cycles burning, no more battery drain! Two timers are still called once per sec (in minimized, unfocused states), but that's nothing compared to the previous 120+ calls per sec :)

john-preston pushed a commit to desktop-app/lib_ui that referenced this issue Apr 11, 2021
A race condition in the animations manager can leave a dangling
timerEvent() callback firing at a high frequency (>120 FPS) in the
main loop even though there is no active animations.

An update of the animations manager returns directly when there is no
active animations. If there is at least one active animation, it stops
the timer and schedules a new update before updating animations.
Depending on the Integration implementation, the scheduling call can
be postponed after the current update. The actual postponed call
unconditionally schedules an update by starting the timer. The issue
is that in the meantime the last remaining animation could have been
removed and, when the timer callback would be fired, the update would
return directly (since there is no active animations) without being
able to stop.

The explanation above ignores the updateQueued() cases of the
postponed call for simplicity. These cases do not result in infinite
updates like the timer case but still imply one useless (invoked)
update.

This fix adds a condition in the postponed call ensuring there is at
least one active animation before processing.

telegramdesktop/tdesktop#3640
telegramdesktop/tdesktop#4854
telegramdesktop/tdesktop#5436
@rburchell
Copy link
Author

@loicmolinari Nice catch! That sounds like exactly what I've seen, and tried to find a few times, without success :)

EricKotato pushed a commit to kotatogram/lib_ui that referenced this issue Apr 13, 2021
A race condition in the animations manager can leave a dangling
timerEvent() callback firing at a high frequency (>120 FPS) in the
main loop even though there is no active animations.

An update of the animations manager returns directly when there is no
active animations. If there is at least one active animation, it stops
the timer and schedules a new update before updating animations.
Depending on the Integration implementation, the scheduling call can
be postponed after the current update. The actual postponed call
unconditionally schedules an update by starting the timer. The issue
is that in the meantime the last remaining animation could have been
removed and, when the timer callback would be fired, the update would
return directly (since there is no active animations) without being
able to stop.

The explanation above ignores the updateQueued() cases of the
postponed call for simplicity. These cases do not result in infinite
updates like the timer case but still imply one useless (invoked)
update.

This fix adds a condition in the postponed call ensuring there is at
least one active animation before processing.

telegramdesktop/tdesktop#3640
telegramdesktop/tdesktop#4854
telegramdesktop/tdesktop#5436
@loicmolinari
Copy link
Contributor

Two timers are still called once per sec

Fixed in 06618a5 and 46ee559 :)

@loicmolinari
Copy link
Contributor

@Aokromes #3640 and #4854 are likely to be fixed by desktop-app/lib_ui@f783243, 336405b and the commits mentioned above.

@ilya-fedin
Copy link
Contributor

@loicmolinari github closes issues automatically if you're writing like Fixes https://github.com/telegramdesktop/tdesktop/issues/3640

@loicmolinari
Copy link
Contributor

github closes issues automatically if you're writing like Fixes https://github.com/telegramdesktop/tdesktop/issues/3640

Didn't want to take the responsibility :)

@github-actions
Copy link

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators May 30, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

No branches or pull requests