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?