I can't speak to the details of ScopedTimer but at these timings I'd
be concerned about clock granularity and accuracy. Might be worth
doing a few thousand of them and measuring the time it takes to do
that.
On Sat, Oct 22, 2016 at 10:52 PM, Daniel Schürmann <dasch...@mixxx.org> wrote:
> Hi
>
> I was exited to see if her is a measurable difference.
> So I added a Scoped timer around
>
> {
> ScopedTimer t("emit(valueChanged())");
> emit(valueChanged(value, pSender));
> }
>
> I did 3 test runs QT_NO_GLIB unset and 3 set. Every time I play 10
> seconds of the same track:
>
> ./mixxx --devloper
>
> Debug [Main]:
> Stat("emit(valueChanged())","count=20178,sum=1.0176e+08ns,average=5043.1ns,min=123ns,max=1.20981e+07ns,variance=1.71805e+10ns^2,stddev=131074ns")
> Debug [Main]:
> Stat("emit(valueChanged())","count=20268,sum=9.97117e+07ns,average=4919.66ns,min=127ns,max=1.2527e+07ns,variance=1.78212e+10ns^2,stddev=133496ns")
> Debug [Main]:
> Stat("emit(valueChanged())","count=20289,sum=1.01444e+08ns,average=4999.94ns,min=124ns,max=1.23328e+07ns,variance=1.50495e+10ns^2,stddev=122676ns")
>
>
> QT_NO_GLIB=1 ./mixxx --developer
>
> Debug [Main]:
> Stat("emit(valueChanged())","count=20603,sum=9.09682e+07ns,average=4415.29ns,min=128ns,max=1.56305e+07ns,variance=1.53043e+10ns^2,stddev=123711ns")
> Debug [Main]:
> Stat("emit(valueChanged())","count=20242,sum=1.04024e+08ns,average=5139ns,min=137ns,max=1.51701e+07ns,variance=2.29287e+10ns^2,stddev=151422ns")
> Debug [Main]:
> Stat("emit(valueChanged())","count=20601,sum=1.01946e+08ns,average=4948.57ns,min=130ns,max=1.25509e+07ns,variance=1.57278e+10ns^2,stddev=125410ns")
>
> There is no measurable difference!
> Is the test significant?
>
> Kind regards, Daniel
>
>
>
>
> Am 21.10.2016 um 14:53 schrieb RJ Ryan:
>> Gah, the sorts of things we do in the audio callback thread. This
>> definitely sounds worth testing, thanks Nils!
>>
>> I'm not sure we would see any difference in profiling since it would
>> likely affect tail latency only. Does anybody have a test environment
>> they could run some good A/B tests on? It sounds like a netbook or other
>> resource constrained environment would be a good place to start -- set
>> the latency to a value it just starts to xrun on and then test with and
>> without this flag.
>>
>> On Fri, Oct 21, 2016 at 8:02 AM, Nils Goroll <sl...@schokola.de
>> <mailto:sl...@schokola.de>> wrote:
>>
>> Hi,
>>
>> TL;DR: setting QT_NO_GLIB may make QT event delivery more efficient
>> which could
>> help reduce latencies.
>>
>> -
>>
>> I'm using mixxx master on Debian 8.6. While checking for possible
>> underrun
>> causes, I noticed that an strace of the portaudio callback thread
>> shows many
>> writes which appear unnecessary:
>>
>> poll([{fd=56, events=POLLOUT|POLLERR|POLLNVAL}], 1, 11) = 1 ([{fd=56,
>> revents=POLLOUT}])
>> ioctl(56, SNDRV_PCM_IOCTL_STATUS, 0x7fd3153d4b20) = 0
>> write(3, "\1\0\0\0\0\0\0\0", 8) = 8
>> write(3, "\1\0\0\0\0\0\0\0", 8) = 8
>> ioctl(56, SNDRV_PCM_IOCTL_STATUS, 0x7fd3153d4b20) = 0
>> poll([{fd=56, events=POLLOUT|POLLERR|POLLNVAL}], 1, 11) = 1 ([{fd=56,
>> revents=POLLOUT}])
>> ioctl(56, SNDRV_PCM_IOCTL_STATUS, 0x7fd3153d4b20) = 0
>> write(3, "\1\0\0\0\0\0\0\0", 8) = 8
>> write(3, "\1\0\0\0\0\0\0\0", 8) = 8
>> ioctl(56, SNDRV_PCM_IOCTL_STATUS, 0x7fd3153d4b20) = 0
>> poll([{fd=56, events=POLLOUT|POLLERR|POLLNVAL}], 1, 11) = 1 ([{fd=56,
>> revents=POLLOUT}])
>> ioctl(56, SNDRV_PCM_IOCTL_STATUS, 0x7fd3153d4b20) = 0
>> write(3, "\1\0\0\0\0\0\0\0", 8) = 8
>> write(3, "\1\0\0\0\0\0\0\0", 8) = 8
>> write(3, "\1\0\0\0\0\0\0\0", 8) = 8
>> write(3, "\1\0\0\0\0\0\0\0", 8) = 8
>> futex(0x2d9f4dc, FUTEX_CMP_REQUEUE_PRIVATE, 1, 2147483647,
>> 0x2d9f4b0, 2230) = 1
>> futex(0x2d9f4b0, FUTEX_WAKE_PRIVATE, 1) = 1
>> ioctl(56, SNDRV_PCM_IOCTL_STATUS, 0x7fd3153d4b20) = 0
>>
>> turns out that these are caused by glib g_wakeup_signal() writes to
>> the glib
>> eventfd caused by postEvent()s because QT defaults to
>> QEventDispatcherGlib. See
>> bottom of the email for some exemplary stack traces.
>>
>> Also, the receiving side (main thread) needs to read all these off
>> the eventfd
>> (ultimately happening in g_wakeup_acknowledge()).
>>
>> I _think_ that glib could do better and avoid notifications
>> altogether unless
>> the receiving thread is actually polling and reducing the eventfd
>> notifications
>> to just one, but nevertheless there seems to be an easy way out:
>> Instruct QT not
>> to use the glib event loop by setting
>>
>> QT_NO_GLIB=whatever
>>
>> This instructs QT to fall back to QEventDispatcherUNIX which should
>> be less
>> efficient for a large number of file descriptors, but appears to be
>> significantly more efficient in handling QT events: Only one event
>> write is
>> generated to wake up poll as can be seen in the strace of the
>> portaudio callback
>> thread:
>>
>> poll([{fd=73, events=POLLOUT|POLLERR|POLLNVAL}], 1, 11) = 1 ([{fd=73,
>> revents=POLLOUT}])
>> ioctl(73, SNDRV_PCM_IOCTL_STATUS, 0x7f72abd81b30) = 0
>> ioctl(73, SNDRV_PCM_IOCTL_STATUS, 0x7f72abd81b30) = 0
>> poll([{fd=73, events=POLLOUT|POLLERR|POLLNVAL}], 1, 11) = 1 ([{fd=73,
>> revents=POLLOUT}])
>> ioctl(73, SNDRV_PCM_IOCTL_STATUS, 0x7f72abd81b30) = 0
>> write(4, "\0", 1) = 1
>> ioctl(73, SNDRV_PCM_IOCTL_STATUS, 0x7f72abd81b30) = 0
>> poll([{fd=73, events=POLLOUT|POLLERR|POLLNVAL}], 1, 11) = 1 ([{fd=73,
>> revents=POLLOUT}])
>> ioctl(73, SNDRV_PCM_IOCTL_STATUS, 0x7f72abd81b30) = 0
>> futex(0x19315ec, FUTEX_CMP_REQUEUE_PRIVATE, 1, 2147483647,
>> 0x19315c0, 730) = 1
>> futex(0x19315c0, FUTEX_WAKE_PRIVATE, 1) = 1
>> ioctl(73, SNDRV_PCM_IOCTL_STATUS, 0x7f72abd81b30) = 0
>>
>>
>> This won't make that much of a difference, but reducing the number
>> of syscalls
>> is always a good idea, so I wonder if setting QT_NO_GLIB should be
>> recommended?
>>
>> Cheers, Nils
>>
>> -
>>
>>
>>
>>
>> (gdb) break write
>> Breakpoint 1 at 0x7ffb7a767bf0: write. (2 locations)
>> (gdb) cont
>> Continuing.
>>
>> Breakpoint 1, write () at ../sysdeps/unix/syscall-template.S:81
>> 81 ../sysdeps/unix/syscall-template.S: No such file or directory.
>> (gdb) bt
>> #0 write () at ../sysdeps/unix/syscall-template.S:81
>> #1 0x00007ffb7b2e5ef2 in ?? () from
>> /lib/x86_64-linux-gnu/libglib-2.0.so.0
>> #2 0x00007ffb7ef0b81e in QCoreApplication::postEvent(QObject*,
>> QEvent*, int) ()
>> from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
>> #3 0x00007ffb7ef1ca44 in QMetaObject::activate(QObject*,
>> QMetaObject const*,
>> int, void**) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
>> #4 0x00000000004fb547 in ControlDoublePrivate::valueChanged (
>> this=this@entry=0x31e38e0, _t1=_t1@entry=3, _t2=_t2@entry=0x39ce2d0)
>> at lin64_build/control/moc_control.cc:101
>> #5 0x00000000004ea565 in setInner (pSender=0x39ce2d0, value=3,
>> this=0x31e38e0)
>> at src/control/control.cpp:203
>> #6 ControlDoublePrivate::set (this=0x31e38e0, value=3,
>> pSender=0x39ce2d0)
>> at src/control/control.cpp:190
>> #7 0x0000000000b07be2 in set (v=<optimized out>, this=<optimized out>)
>> at src/control/controlproxy.h:78
>> #8 SoundDevicePortAudio::callbackProcessClkRef (this=0x39ce190,
>> framesPerBuffer=1024,
>> out=0x3c3952f0, in=0x0, timeInfo=<optimized out>,
>> statusFlags=<optimized out>)
>> at src/soundio/sounddeviceportaudio.cpp:916
>> #9 0x00007ffb82094f04 in NonAdaptingProcess (bp=bp@entry=0x3bba98e8,
>> streamCallbackResult=streamCallbackResult@entry=0x7ffb0f971d08,
>> hostInputChannels=0x0, hostOutputChannels=0x2bf24b80,
>> framesToProcess=<optimized out>) at src/common/pa_process.c:873
>> #10 0x00007ffb82096ec0 in PaUtil_EndBufferProcessing
>> (bp=bp@entry=0x3bba98e8,
>> streamCallbackResult=streamCallbackResult@entry=0x7ffb0f971d08)
>> at src/common/pa_process.c:1585
>> #11 0x00007ffb8209e37e in CallbackThreadFunc (userData=0x3bba9880)
>> at src/hostapi/alsa/pa_linux_alsa.c:4346
>> #12 0x00007ffb7cb2b0a4 in start_thread (arg=0x7ffb0f972700) at
>> pthread_create.c:309
>> #13 0x00007ffb7a77462d in clone () at
>> ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
>> (gdb) cont
>> Continuing.
>>
>> Breakpoint 1, write () at ../sysdeps/unix/syscall-template.S:81
>> 81 in ../sysdeps/unix/syscall-template.S
>> (gdb) bt
>> #0 write () at ../sysdeps/unix/syscall-template.S:81
>> #1 0x00007ffb7b2e5ef2 in ?? () from
>> /lib/x86_64-linux-gnu/libglib-2.0.so.0
>> #2 0x00007ffb7ef0b81e in QCoreApplication::postEvent(QObject*,
>> QEvent*, int) ()
>> from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
>> #3 0x00007ffb7ef1ca44 in QMetaObject::activate(QObject*,
>> QMetaObject const*,
>> int, void**) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
>> #4 0x00000000004fb547 in ControlDoublePrivate::valueChanged (
>> this=this@entry=0x3228840, _t1=_t1@entry=0.82023751735687256,
>> _t2=_t2@entry=0x3228740) at lin64_build/control/moc_control.cc:101
>> #5 0x00000000004ea565 in setInner (pSender=0x3228740,
>> value=0.82023751735687256,
>> this=0x3228840) at src/control/control.cpp:203
>> #6 ControlDoublePrivate::set (this=0x3228840,
>> value=value@entry=0.82023751735687256,
>> pSender=0x3228740) at src/control/control.cpp:190
>> #7 0x00000000007f6b09 in set (value=0.82023751735687256,
>> this=<optimized out>)
>> at src/control/controlobject.h:94
>> #8 EngineVuMeter::process (this=0x3224a90, pIn=<optimized out>,
>> iBufferSize=2048)
>> at src/engine/enginevumeter.cpp:86
>> #9 0x00000000007f0a03 in EngineMaster::process (this=0x325ecb0,
>> iBufferSize=iBufferSize@entry=2048) at
>> src/engine/enginemaster.cpp:523
>> #10 0x0000000000b0a2eb in SoundManager::onDeviceOutputCallback
>> (this=<optimized
>> out>,
>> iFramesPerBuffer=iFramesPerBuffer@entry=1024) at
>> src/soundio/soundmanager.cpp:547
>> #11 0x0000000000b07c76 in SoundDevicePortAudio::callbackProcessClkRef
>> (this=0x39ce190,
>> framesPerBuffer=1024, out=0x3c3952f0, in=<optimized out>,
>> timeInfo=<optimized out>,
>> statusFlags=<optimized out>) at
>> src/soundio/sounddeviceportaudio.cpp:947
>> #12 0x00007ffb82094f04 in NonAdaptingProcess (bp=bp@entry=0x3bba98e8,
>> streamCallbackResult=streamCallbackResult@entry=0x7ffb0f971d08,
>> hostInputChannels=0x0, hostOutputChannels=0x2bf24b80,
>> framesToProcess=<optimized out>) at src/common/pa_process.c:873
>> #13 0x00007ffb82096ec0 in PaUtil_EndBufferProcessing
>> (bp=bp@entry=0x3bba98e8,
>> streamCallbackResult=streamCallbackResult@entry=0x7ffb0f971d08)
>> at src/common/pa_process.c:1585
>> #14 0x00007ffb8209e37e in CallbackThreadFunc (userData=0x3bba9880)
>> at src/hostapi/alsa/pa_linux_alsa.c:4346
>> #15 0x00007ffb7cb2b0a4 in start_thread (arg=0x7ffb0f972700) at
>> pthread_create.c:309
>> #16 0x00007ffb7a77462d in clone () at
>> ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
>>
>>
>> ------------------------------------------------------------------------------
>> Check out the vibrant tech community on one of the world's most
>> engaging tech sites, SlashDot.org! http://sdm.link/slashdot
>> _______________________________________________
>> Get Mixxx, the #1 Free MP3 DJ Mixing software Today
>> http://mixxx.org
>>
>>
>> Mixxx-devel mailing list
>> Mixxx-devel@lists.sourceforge.net
>> <mailto:Mixxx-devel@lists.sourceforge.net>
>> https://lists.sourceforge.net/lists/listinfo/mixxx-devel
>> <https://lists.sourceforge.net/lists/listinfo/mixxx-devel>
>>
>>
>>
>>
>> ------------------------------------------------------------------------------
>> Check out the vibrant tech community on one of the world's most
>> engaging tech sites, SlashDot.org! http://sdm.link/slashdot
>>
>>
>>
>> _______________________________________________
>> Get Mixxx, the #1 Free MP3 DJ Mixing software Today
>> http://mixxx.org
>>
>>
>> Mixxx-devel mailing list
>> Mixxx-devel@lists.sourceforge.net
>> https://lists.sourceforge.net/lists/listinfo/mixxx-devel
>>
>
> ------------------------------------------------------------------------------
> Check out the vibrant tech community on one of the world's most
> engaging tech sites, SlashDot.org! http://sdm.link/slashdot
> _______________________________________________
> Get Mixxx, the #1 Free MP3 DJ Mixing software Today
> http://mixxx.org
>
>
> Mixxx-devel mailing list
> Mixxx-devel@lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/mixxx-devel
------------------------------------------------------------------------------
The Command Line: Reinvented for Modern Developers
Did the resurgence of CLI tooling catch you by surprise?
Reconnect with the command line and become more productive.
Learn the new .NET and ASP.NET CLI. Get your free copy!
http://sdm.link/telerik
_______________________________________________
Get Mixxx, the #1 Free MP3 DJ Mixing software Today
http://mixxx.org
Mixxx-devel mailing list
Mixxx-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/mixxx-devel
