1 (edited by Schmallon 2018-11-16 11:37:12)

Topic: Bursts of clicks at audio buffer intervals

Hi all,

I recently started getting audible clicks in the recordings with my UFX and I wonder if you can help me. The clicks happen in bursts that occur once in a while. When clicks happen, they happen every ~512 samples (which IIRC resembles the buffer size I used for the recording) and each click consists of 1-5 samples that have a completely different value than surrounding samples.

Here's a screen shot: https://imgur.com/a/sbtKfWz
Here's the audio: https://wetransfer.com/downloads/a665bc … 011/a16375

I’m working on
- a MacBook 2018 Pro
- macOS 10.13.6
- The UFX is connected to a OctaMic XTC (both at the latest FW)
- The crackling happens on multiple channels

Any idea what I might do to remedy the problem?

Cheers,
Matthias

Edit:

I realized that the issues are sometimes worse than just individual clicks, see https://imgur.com/a/KekyfdO

Here's what I find in the Console output at the time of audio issues:

default    11:10:16.384283 +0100    UserEventAgent    STARTING: <private>
default    11:10:16.384409 +0100    dasd    Setting timer (isWaking=1, activityRequiresWaking=0) between <private> and <private> for <private>
default    11:10:16.434449 +0100    UserEventAgent    Initiating XPC Activity: com.apple.timed.ntp.wanted
default    11:10:16.435240 +0100    UserEventAgent    Completed XPC Activity: com.apple.timed.ntp.wanted
default    11:10:16.435573 +0100    dasd    COMPLETED 0:com.apple.timed.ntp.wanted:B665F4 <private>!
default    11:10:16.436330 +0100    UserEventAgent    Unregistered XPC Activity: com.apple.timed.ntp.wanted
default    11:10:16.458444 +0100    timed    cmd,fetchTime,num,0,result,2,mach,0,tv_sec,0,tv_usec,3,delay,0.000000,dispersion,0.000000,more,0,ip,(null),port,(null),attempts,0,slept,0,use_service_port,1
default    11:10:16.459227 +0100    kernel    outCallback (54) - returned status: e00002be
default    11:10:16.459234 +0100    kernel    outCallback (54) - frame 4 returned status: e00002be
default    11:10:16.459237 +0100    kernel    outCallback (54) - frame 5 returned status: e00002be
default    11:10:16.459240 +0100    kernel    outCallback (54) - frame 6 returned status: e00002be
default    11:10:16.459449 +0100    kernel    inCallback (54) - returned status: e00002be
default    11:10:16.459452 +0100    kernel    inCallback (54) - frame 4 returned status: e00002be
default    11:10:16.459455 +0100    kernel    inCallback (54) - frame 5 returned status: e00002be
default    11:10:16.459456 +0100    kernel    inCallback (54) - frame 6 returned status: e00002be
default    11:10:16.460098 +0100    kernel    inCallback (55) - returned status: e00002e8
default    11:10:16.460103 +0100    kernel    inCallback (55) - frame 0 returned status: e00002e8
default    11:10:16.479625 +0100    timed    cmd,SYNC,rtc_s,2166621.125061000,unc_s,0.000500000,mach,137768989910276
default    11:10:16.523063 +0100    timed    cmd,SYNC,rtc_s,2166621.167175000,unc_s,0.000500000,mach,137769032113687
default    11:10:16.523127 +0100    timed    Received source unavailable from "NTP"
default    11:10:16.523155 +0100    timed    cmd,unavailable,src,NTP,rtc_s,2166621.146224000
default    11:10:16.566863 +0100    timed    cmd,SYNC,rtc_s,2166621.212280000,unc_s,0.000500000,mach,137769077188501
default    11:10:16.567154 +0100    kernel    outCallback (162) - returned status: e00002be
default    11:10:16.567166 +0100    kernel    outCallback (162) - frame 6 returned status: e00002be
default    11:10:16.567186 +0100    kernel    outCallback (162) - frame 7 returned status: e00002be
default    11:10:16.567207 +0100    kernel    inCallback (162) - returned status: e00002be
default    11:10:16.567243 +0100    kernel    inCallback (162) - frame 6 returned status: e00002be
default    11:10:16.567246 +0100    kernel    inCallback (162) - frame 7 returned status: e00002be
default    11:10:16.568079 +0100    kernel    outCallback (163) - returned status: e00002be
default    11:10:16.568085 +0100    kernel    outCallback (163) - frame 0 returned status: e00002be
default    11:10:16.568105 +0100    kernel    inCallback (163) - returned status: e00002be
default    11:10:16.568107 +0100    kernel    inCallback (163) - frame 0 returned status: e00002be
default    11:10:16.568109 +0100    kernel    inCallback (163) - frame 2 returned status: e00002e8
error    11:10:16.578009 +0100    coreaudiod    HALS_IOA1Engine.cpp:365:EndWriting:  HALS_IOA1Engine::EndWriting: got an error from the kernel trap, Error: 0xE00002EE
default    11:10:16.578052 +0100    Live    HALC_ProxyIOContext.cpp:1068:IOWorkLoop:  HALC_ProxyIOContext::IOWorkLoop: skipping cycle due to overload
default    11:10:16.577990 +0100    kernel      performClientOutput(31dd,1684) - missed samples (31dd,1684). fCurrentLoopCount=31de
default    11:10:16.587842 +0100    timed    cmd,checkActiveTimeSourceRequired,rtc_s,2166621.233352,bb_want_unc_s,inf,want_unc_s,0.050000,need_unc_s,10.000000,bb_want_rtc_s,inf,want_rtc_s,2163199.596506,need_rtc_s,2660699.596506
default    11:10:16.588126 +0100    kernel    + IOAudioEngineUserClient[<private>]::performWatchdogOutput(<private>, 204183) - (31dd,1684)
default    11:10:16.588158 +0100    kernel    - IOAudioEngineUserClient[<private>]::performWatchdogOutput(<private>, 204183) - (31dd,1884)
default    11:10:16.589964 +0100    kernel      performClientOutput(31dd,1894) - missed samples (31dd,1884). fCurrentLoopCount=31de
error    11:10:16.589983 +0100    coreaudiod    HALS_IOA1Engine.cpp:365:EndWriting:  HALS_IOA1Engine::EndWriting: got an error from the kernel trap, Error: 0xE00002EE
default    11:10:16.590065 +0100    Live    HALC_ProxyIOContext.cpp:1068:IOWorkLoop:  HALC_ProxyIOContext::IOWorkLoop: skipping cycle due to overload
default    11:10:16.601950 +0100    kernel      performClientOutput(31dd,1aa4) - missed samples (31dd,1884). fCurrentLoopCount=31de
error    11:10:16.601976 +0100    coreaudiod    HALS_IOA1Engine.cpp:365:EndWriting:  HALS_IOA1Engine::EndWriting: got an error from the kernel trap, Error: 0xE00002EE
default    11:10:16.602106 +0100    Live    HALC_ProxyIOContext.cpp:1068:IOWorkLoop:  HALC_ProxyIOContext::IOWorkLoop: skipping cycle due to overload
default    11:10:16.609375 +0100    timed    Want active time in -0.00min. Need active time in 8234.64min. Remaining retry interval: 14.997457min.

Edit 2:
Comparing Console output over several occurences of audio issues, I realize that each time I see a bunch of "outCallback ..." messages, they are preceded by a message by "timed" similar to the one found in the above log. Here are the individual snippets


default    11:10:16.435573 +0100    dasd    COMPLETED 0:com.apple.timed.ntp.wanted:B665F4 <private>!
default    11:10:16.436330 +0100    UserEventAgent    Unregistered XPC Activity: com.apple.timed.ntp.wanted
default    11:10:16.458444 +0100    timed    cmd,fetchTime,num,0,result,2,mach,0,tv_sec,0,tv_usec,3,delay,0.000000,dispersion,0.000000,more,0,ip,(null),port,(null),attempts,0,slept,0,use_service_port,1
default    11:10:16.459227 +0100    kernel    outCallback (54) - returned status: e00002be
default    11:10:16.459234 +0100    kernel    outCallback (54) - frame 4 returned status: e00002be

----
default    11:25:15.861657 +0100    CalendarAgent    [com.apple.calendar.store.log.caldav.queue] [Resetting operation [<CalDAVAccountRefreshQueueableOperation: 0x7fcd77dc84f0; Sequence: 0>]'s retry counter]
default    11:25:15.892210 +0100    timed    cmd,checkActiveTimeSourceRequired,rtc_s,2167520.523910,bb_want_unc_s,inf,want_unc_s,0.050000,need_unc_s,10.000000,bb_want_rtc_s,inf,want_rtc_s,2163199.596506,need_rtc_s,2660699.596506
default    11:25:15.914271 +0100    timed    cmd,SYNC,rtc_s,2167520.546295000,unc_s,0.000500000,mach,138668439178163
default    11:25:15.936106 +0100    timed    Want active time in 0.00min. Need active time in 8219.65min. Remaining retry interval: 14.997355min.
default    11:25:15.936141 +0100    timed    Unscheduling wanted job
default    11:25:15.936249 +0100    timed    Scheduling wanted job
default    11:25:15.936334 +0100    timed    Scheduling needed job
default    11:25:15.937408 +0100    kernel    inCallback (28) - returned status: e00002be
default    11:25:15.937417 +0100    kernel    inCallback (28) - frame 3 returned status: e00002be

----

0>]]
default    10:40:17.960628 +0100    CalendarAgent    [com.apple.calendar.store.log.caldav.queue] [Resetting operation [<CalDAVAccountRefreshQueueableOperation: 0x7fcd77dc84f0; Sequence: 0>]'s retry counter]
default    10:40:17.983095 +0100    timed    cmd,SYNC,rtc_s,2164822.677520000,unc_s,0.000500000,mach,135970489357443
default    10:40:17.983190 +0100    timed    Received source unavailable from "NTP"
default    10:40:17.983218 +0100    timed    cmd,unavailable,src,NTP,rtc_s,2164822.656448000
default    10:40:18.006961 +0100    kernel    outCallback (63) - returned status: e00002be
default    10:40:18.006970 +0100    kernel    outCallback (63) - frame 2 returned status: e00002be


-----
default    10:55:17.389024 +0100    timed    cmd,ntp_adjtime:out,modes,0,offset_us,-24118781,freq_scaled,1336699,maxerror_us,52140
default    10:55:17.389073 +0100    kernel    SMCRTC: SYSCTL setting PMU offset
default    10:55:17.389052 +0100    timed    cmd,apply,src,adjtime,rtc_s,2165721.990513102,rtc_unc_s,0.000500009,t_s,564054917.277087212,unc_s,0.052140661,mach,136869826391030,adjust,-0.024118781,success,1,after_m,136869826391146
default    10:55:17.389078 +0100    kernel    SMCRTC: setting PMU offset to 50469155480750
default    10:55:17.389851 +0100    kernel     SMCRTC: set PMU offset to 50469155480750
default    10:55:17.389886 +0100    timed    cmd,rtc_offset,set,1540196395286574110,was,1540196395268218000,now,1540196395286560000,success,1
default    10:55:17.389927 +0100    kernel    outCallback (115) - returned status: e00002be
default    10:55:17.389931 +0100    kernel    outCallback (115) - frame 3 returned status: e00002be
default    10:55:17.389954 +0100    kernel    outCallback (115) - frame 4 returned status: e00002be
default    10:55:17.389957 +0100    kernel    outCallback (115) - frame 5 returned status: e00002be

Any ideas what might be going on?

Re: Bursts of clicks at audio buffer intervals

Which recording software did you use, which alternative/s did you try?

Regards
Daniel Fuchs
RME

Regards
Daniel Fuchs
RME

Re: Bursts of clicks at audio buffer intervals

I'm using Ableton Live 10 and haven't tried anything else, yet. I will once I get back to the studio, which will probably only be next week. Any other suggestions for what I could try, other than other recording software?

Re: Bursts of clicks at audio buffer intervals

I've managed to reproduce the issue with a different audio recording software (Audacity) and a different UFX unit.

I have a hunch that this issue might be affected by WIFI settings. When I originally ran into the issue, I had WIFI enabled but wasn't connected to any WIFI network. Then, the issue would happen every couple of minutes. Repeatedly switching WIFI on and off also seems to provoke the issue.

I'll next try recording for a longer period with WIFI disabled to understand whether it's related to that.

Re: Bursts of clicks at audio buffer intervals

Disabling WIFI doesn't help. After ~11 minutes of recording, "timed" showed up in Console again, followed by audio issues in the recording.

6 (edited by Timur Born 2018-11-16 21:49:18)

Re: Bursts of clicks at audio buffer intervals

Look in this Gearslutz thread:

https://www.gearslutz.com/board/music-c … bug-2.html

Some quotes:

In my findings, the dropout always occurs in relation to the timed-process.
(Unregistered XPC Activity: com.apple.timed.ntp.wanted)
Everytime the timed-process pops up in the console a dropout happens.

I've seen very similar things with the "timed" process. My total wild speculation is that the timed clock sync resets the internal clock and causes the usb stream to glitch because the timestamps for each packet suddenly don't quite match....

To me as a layman this sounds quite plausible.
I blocked internet access of the timed-process with an outbound firewall and the dropout doesn't happen anymore!

This does not seem to fix it for everyone, though. But it's worth a try. Later someone wrote:

This is a coreaudio software bug, apple confirmed as much to me. They are being coy and not wanting to admit the issue.

All that being said, Ableton Live has been especially prone to OS X' battery saving "features". If your Live projects only use *little*
CPU power then it might help to artificially put load on the CPU to keep it from powering down during the low audio load.