CPU spike when Gain is cranked up

Bug #742388 reported by jus
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Mixxx
Expired
High
Unassigned
1.10
Won't Fix
High
Unassigned
1.9
Won't Fix
High
Unassigned
2.0
Won't Fix
High
Unassigned

Bug Description

1. Use u skin with big waveform (for more visible effect)
2. Load tracks in both decks and jump mid track (don't play)
3. Watch CPU usage (25% for me)
4. Crank up Gain knob for both decks
5. Watch CPU usage spike. (+100% for me)
6. Reset Gain knobs (Right-click)
7. Watch CPU usage goes back to normal

MacOS 10.6.7
Tested with latest http://bazaar.launchpad.net/~mixxxdevelopers/mixxx/release-1.9.x/revision/2784 but it is the same with the 1.9.0 release.

I compared 2 runs (Default Gain/Full gain) and attached the diff. Hopefully it is useful for a dev.

Revision history for this message
jus (jus) wrote :
Revision history for this message
RJ Skerry-Ryan (rryan) wrote : Re: [Bug 742388] Re: CPU spike when Gain is cranked up

do waveforms being on or off make a difference? My first suspicion is
OpenGL.

On Fri, Mar 25, 2011 at 7:27 AM, jus <email address hidden> wrote:

> ** Attachment added: "Time Profiler - Mixxx1.9r2784diff.csv"
>
> https://bugs.launchpad.net/bugs/742388/+attachment/1939642/+files/Time%20Profiler%20-%20Mixxx1.9r2784diff.csv
>
> --
> You received this bug notification because you are subscribed to Mixxx.
> https://bugs.launchpad.net/bugs/742388
>
> Title:
> CPU spike when Gain is cranked up
>

Revision history for this message
jus (jus) wrote :

Whoa, turning Waveform off drops default idle CPU usage by 75% and the spike described in #1 by 90%.

Nonetheless i think there is something on with Gain. Attached a diff for 2 runs (Default Gain/Full gain) with waveforms off.

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

Hmm, I'm pretty confused. That trace has tons of Qt OpenGL calls in it,
while the waveforms should be off...

On Fri, Mar 25, 2011 at 10:43 AM, jus <email address hidden> wrote:

> Whoa, turning Waveform off drops default idle CPU usage by 75% and the
> spike described in #1 by 90%.
>
> Nonetheless i think there is something on with Gain. Attached a diff for
> 2 runs (Default Gain/Full gain) with waveforms off.
>
> ** Attachment added: "Time Profiler - Mixxx1.9r2784diff -WaveformOff.csv"
>
> https://bugs.launchpad.net/mixxx/+bug/742388/+attachment/1940160/+files/Time%20Profiler%20-%20Mixxx1.9r2784diff%20-WaveformOff.csv
>
> --
> You received this bug notification because you are subscribed to Mixxx.
> https://bugs.launchpad.net/bugs/742388
>
> Title:
> CPU spike when Gain is cranked up
>

Revision history for this message
jus (jus) wrote :

Well, maybe some error on my side?
I restarted Mixxx with waveform off and made a new single run trace. Hope it help.

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

Thanks -- no more GL in that one. Very confusing though -- especially since
the decks are not playing.

Is a MIDI device enabled?

On Fri, Mar 25, 2011 at 11:56 AM, jus <email address hidden> wrote:

> Well, maybe some error on my side?
> I restarted Mixxx with waveform off and made a new single run trace. Hope
> it help.
>
> ** Attachment added: "Time Profiler - Mixxx1.9r2784 -WaveformOff.csv"
>
> https://bugs.launchpad.net/mixxx/+bug/742388/+attachment/1940406/+files/Time%20Profiler%20-%20Mixxx1.9r2784%20-WaveformOff.csv
>
> --
> You received this bug notification because you are subscribed to Mixxx.
> https://bugs.launchpad.net/bugs/742388
>
> Title:
> CPU spike when Gain is cranked up
>

Revision history for this message
jus (jus) wrote :

There was not even a MIDI device connected.

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

Hmm, I can't seem to reproduce on Linux. No noticable increase in CPU usage for me even with waveforms on. I'll try this on OSX when I get a chance. What Qt version did you build with?

RJ Skerry-Ryan (rryan)
Changed in mixxx:
assignee: nobody → RJ Ryan (rryan)
Revision history for this message
jus (jus) wrote :

Qt version i build with is: 4.7.2

Is all the MidiLedHandler stuff eating up the cpu ?

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

It's hard to tell. QList<MidiLedHandler*>::clear() sure shows up in your
trace a ton, but I can't understand why. That call is very rare.

On Sun, Mar 27, 2011 at 3:53 AM, jus <email address hidden> wrote:

> Qt version i build with is: 4.7.2
>
> Is all the MidiLedHandler stuff eating up the cpu ?
>
> --
> You received this bug notification because you are a bug assignee.
> https://bugs.launchpad.net/bugs/742388
>
> Title:
> CPU spike when Gain is cranked up
>

Revision history for this message
jus (jus) wrote :

I just learned that this is not limited to GAIN.

* Start Mixxx trunk with waveform off and no Midi device connect
* Do not load any track
* Mixxx is idle , CPU is around 5%
* Now move any slider or rotary
* CPU goes up to 20%

Hope it helps to investigate this any further.

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

Any slider? What about the crossfader only ? Changing the crossfader
shouldn't cause any changes in the work done in processing.

Certain knobs, like EQ in particular, but also volume and gain cause extra
processing to go on if they move from their default. The reason is that to
save CPU, for example when volume is applied, if the volume is full, we
don't do any processing.

On Fri, Apr 1, 2011 at 1:38 PM, jus <email address hidden> wrote:

> I just learned that this is not limited to GAIN.
>
> * Start Mixxx trunk with waveform off and no Midi device connect
> * Do not load any track
> * Mixxx is idle , CPU is around 5%
> * Now move any slider or rotary
> * CPU goes up to 20%
>
> Hope it helps to investigate this any further.
>
> --
> You received this bug notification because you are a bug assignee.
> https://bugs.launchpad.net/bugs/742388
>
> Title:
> CPU spike when Gain is cranked up
>

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

Hm, CPU goes up to 20%, and then back to idle at 5%? Or does it stay at 20 ?

On Fri, Apr 1, 2011 at 1:53 PM, RJ Ryan <email address hidden> wrote:

> Any slider? What about the crossfader only ? Changing the crossfader
> shouldn't cause any changes in the work done in processing.
>
> Certain knobs, like EQ in particular, but also volume and gain cause extra
> processing to go on if they move from their default. The reason is that to
> save CPU, for example when volume is applied, if the volume is full, we
> don't do any processing.
>
> On Fri, Apr 1, 2011 at 1:38 PM, jus <email address hidden> wrote:
>
>> I just learned that this is not limited to GAIN.
>>
>> * Start Mixxx trunk with waveform off and no Midi device connect
>> * Do not load any track
>> * Mixxx is idle , CPU is around 5%
>> * Now move any slider or rotary
>> * CPU goes up to 20%
>>
>> Hope it helps to investigate this any further.
>>
>> --
>> You received this bug notification because you are a bug assignee.
>> https://bugs.launchpad.net/bugs/742388
>>
>> Title:
>> CPU spike when Gain is cranked up
>>
>
>

Revision history for this message
jus (jus) wrote :

Right, any slider (including crossfader) and knob.
CPU normal>>move control>>CPU spike>>release control>>CPU normal

Small screencap with latest trunk where only the crossfader on an idle/waveform off instance is moved. Pretty visible effect. http://dl.dropbox.com/u/3077984/Mixxx/lp742388.mkv

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

We're stumped :).

I chatted w/ Albert about this and we have no idea why QList<MidiLedHandler*> appears to show up so much.

I can't reproduce this on Linux, but I'll try reproducing on a mac.

Changed in mixxx:
status: New → Confirmed
Revision history for this message
Sean M. Pappalardo (pegasus-renegadetech) wrote :

Sounds fishy to me. MidiLEDHandler needing an overhaul notwithstanding, it shouldn't be appearing at all if no MIDI controller is attached! My guess is that mappings stored in .mixxx/midi/ are being loaded anyway. Jus, can you check to see if there are files in there and delete them if so, test again, and get another gprof output?

RJ Skerry-Ryan (rryan)
Changed in mixxx:
status: Confirmed → Triaged
Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

FWIW -- can't reproduce on a 32-bit Macbook.

Changed in mixxx:
importance: Undecided → High
Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

32-bit Macbook Pro with 10.6.8

Changed in mixxx:
assignee: RJ Ryan (rryan) → nobody
Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

Part of me just didn't believe this was possible. But I just reproduced this with master.

1) Set waveforms to 60 FPS
2) Load tracks into all decks.
3) Adjust so gain is very low (no clipping on any waveform)
4) Observe FPS meter -- ~60FPs
5) Crank gain up on one deck so that it's clipping.
6) Observe FPS drop through the floor (~20fps) and GUI interactivity completely drop (whole seconds pass between input events being delivered).

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

For me, CPU usage was stable throughout. But the GUI interactivity and waveform FPS were significantly impacted.

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

Hm, removing VU meters from my skin ended up helping drastically.

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

With gain cranked up, clipping, choppy waveforms (30fps with 60fps desired)

Debug [Main]: Stat("WaveformWidgetFactory::render() 4waveforms","count=2342,sum=2.11997e+09ns,average=905195ns,min=280486ns,max=2.55239e+07ns,variance=5.53894e+11ns^2,stddev=744240ns")
Debug [Main]: Stat("WaveformWidgetFactory::swap() 4waveforms","count=2341,sum=1.38949e+10ns,average=5.93544e+06ns,min=418626ns,max=1.25616e+08ns,variance=4.62099e+13ns^2,stddev=6.79778e+06ns")

With no clipping, smooth 60fps waveforms:

Debug [Main]: Stat("WaveformWidgetFactory::render() 4waveforms","count=2403,sum=2.9498e+09ns,average=1.22755e+06ns,min=282950ns,max=2.30159e+07ns,variance=5.85469e+11ns^2,stddev=765159ns")
Debug [Main]: Stat("WaveformWidgetFactory::swap() 4waveforms","count=2402,sum=9.25037e+09ns,average=3.85111e+06ns,min=433235ns,max=7.98366e+07ns,variance=1.08655e+13ns^2,stddev=3.29629e+06ns")

So, what I gather from this is that there is not that meaningful a difference in waveform render times. Swap times look a little slower (10x larger max, 1.5x slower average, much higher stddev).

Revision history for this message
Daniel Schürmann (daschuer) wrote :

Hi RJ,

the problem might be at https://github.com/mixxxdj/mixxx/blob/master/src/widget/wstatuslight.cpp#L119
We call update() uncontrolled.
I cannot see why this is not required in wvumeter. But this is updated more often in normal conditions, so it should share a common solution.

--

By the way, it is the right time to get rid of:
clipped = SampleUtil::copyClampBuffer(kfMaxAmp, -kfMaxAmp,
                                          pOutput, pIn, iBufferSize);

IMHO it is just a bad idea to just clamp the buffer. Can't we just allow samples > 1? Everything that will happen due to it in the following signal processing can't be worth. I am sure it is camped before it is copied to a 24 bit DAC.

If we allow Samples > 1.0 inside Mixxx we just allow a grater dynamic range. The user only have to be sure, by using the Master volume that the output is not clipped. That's all.

The peakIndicator can be calulates in sumAbsPerChannel inside EngineVUMeter.

Oh sorry for be off topic, will file a new bug.

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

4 spinnies, 4 GL filtered waveforms, gain cranked up:

Debug [Main]: Stat("WaveformWidgetFactory::render() 4waveforms","count=10313,sum=1.26813e+10ns,average=1.22964e+06ns,min=225702ns,max=3.17419e+07ns,variance=8.7429e+11ns^2,stddev=935035ns")
Debug [Main]: Stat("WaveformWidgetFactory::swap() 4waveforms","count=10312,sum=6.32683e+10ns,average=6.1354e+06ns,min=369739ns,max=5.36677e+08ns,variance=1.96071e+14ns^2,stddev=1.40025e+07ns")

Swap average times are 6ms on average render average times are 1.2ms.

I then disabled the signal rendering itself, repeated the experiment and it held 60fps with no problem:

Debug [Main]: Stat("WaveformWidgetFactory::render() 4waveforms","count=5547,sum=4.70622e+09ns,average=848427ns,min=212468ns,max=5.17742e+07ns,variance=7.22005e+11ns^2,stddev=849709ns")
Debug [Main]: Stat("WaveformWidgetFactory::swap() 4waveforms","count=5546,sum=1.75351e+10ns,average=3.16176e+06ns,min=349209ns,max=1.12333e+08ns,variance=2.079e+13ns^2,stddev=4.55961e+06ns")

Next, I added signal rendering back in except I replaced the waveform with a dummy signal that was just half-value for the entire waveform.

By changing the visual gain (independent of track gain) I can make the FPS go from 60 to 20 by just making the gain higher and higher. It doesn't even have to clip. Starting at visual gain 0.5 for low/mid/high and all, I get 60fps. As I increment the overall gain by 0.1 the FPS decreases linearly.

This is boggling. All that changes is that we draw some lines longer when we change the gain. They aren't even clipping outside the widget (I added clamping so that hte widget isn't even allowed to draw waveform signal outside of the ortho matrix ranges we set up.)

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

Not only that but just changing the visual gain causes my entire machine to become unstable. This is madness. We should be able to draw a few hundred lines with a GPU and not cause a 2013 MBP to become unusable.

Revision history for this message
Owen Williams (ywwg) wrote :

What if instead of having the dummy waveform be half-value, make it full-value? ie, make it draw the gained version without doing the gain calculation.

Revision history for this message
Owen Williams (ywwg) wrote :

(ie ie, is the CPU slowdown actually in the rendering, or is it somewhere else)

Revision history for this message
Owen Williams (ywwg) wrote :

also, any difference with QT4 or QT5?

Revision history for this message
Daniel Schürmann (daschuer) wrote :

Ubuntu Saucy Qt version 4.8.4, can confirm the issue.

Revision history for this message
Owen Williams (ywwg) wrote :

Can people check what their RAM situation is when the issue happens? Also is anyone seeing the issue that is not on OSX?

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

Dividing the # of lines being pumped at the GPU by 10 does help -- I get 60 FPS w/ 4 spinnies and 4 478x118 waveforms .

Using the OS X Driver Inspector tool, I found that when this happens we are sending about 6-10MB/sec of render commands to the GPU. I think we need to create the waveform as a vertex buffer once (so it's stored on the GPU) and then issue a single render(start-vertex, end-vertex) command.

Revision history for this message
Owen Williams (ywwg) wrote :

Should we mark this fixed? We did a lot of work on vumeters that made this better.

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

I don't think so -- this happens with no VU meters.

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

It's isolated to certain waveform types (Filtered GL).

Revision history for this message
Max Linke (max-linke) wrote :

rryan can you update your steps to reproduce this. I just tried them and noticed nothing out of the ordinary.

I'm using the current trunk on Arch Linux right now.

Revision history for this message
RJ Skerry-Ryan (rryan) wrote :

I think the issue is mac specific since Jus and I are the only two who have reproduced.

Revision history for this message
Sean M. Pappalardo (pegasus-renegadetech) wrote :

Is this still a problem in Mixxx 2.0 RC1?

Changed in mixxx:
status: Triaged → Incomplete
Revision history for this message
Launchpad Janitor (janitor) wrote :

[Expired for Mixxx because there has been no activity for 60 days.]

Changed in mixxx:
status: Incomplete → Expired
Revision history for this message
Swiftb0y (swiftb0y) wrote :

Mixxx now uses GitHub for bug tracking. This bug has been migrated to:
https://github.com/mixxxdj/mixxx/issues/5833

lock status: Metadata changes locked and limited to project staff
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.