Hmm, strange. There are known time jumps around a suspend resume, but I don't see how they would make the capture time >= now. We don't cache time values. So perhaps the time adjustment done by the FIFO is getting out of hand.

I don't have this device nor a mac today so I can't really debug this unfortunately.

grunell@ can you see if the discrepancy is coming from here:

https://cs.chromium.org/chromium/src/media/audio/mac/audio_low_latency_input_mac.cc?l=951

I printed out the capture_time at the three places it's updated in that function. Here's right before the hit:

[58394:155675:0908/155938.373577:ERROR:audio_low_latency_input_mac.cc(905)] Capture time (1): 56499542986 bogo-microseconds
[58394:155675:0908/155938.373585:ERROR:audio_low_latency_input_mac.cc(940)] Capture time (2): 56499542986 bogo-microseconds
[58394:155675:0908/155938.373600:ERROR:audio_low_latency_input_mac.cc(955)] Capture time (3): 56499552986 bogo-microseconds
[58394:155675:0908/155938.383612:ERROR:audio_low_latency_input_mac.cc(905)] Capture time (1): 56499552986 bogo-microseconds
[58394:155675:0908/155938.383627:ERROR:audio_low_latency_input_mac.cc(940)] Capture time (2): 56499552986 bogo-microseconds
[58394:155675:0908/155938.383646:ERROR:audio_low_latency_input_mac.cc(955)] Capture time (3): 56499562986 bogo-microseconds
[58394:155675:0908/155938.393621:ERROR:audio_low_latency_input_mac.cc(905)] Capture time (1): 56499562986 bogo-microseconds
[58394:155675:0908/155938.393634:ERROR:audio_low_latency_input_mac.cc(940)] Capture time (2): 56499562986 bogo-microseconds
[58394:155675:0908/155938.393653:ERROR:audio_low_latency_input_mac.cc(955)] Capture time (3): 56499572986 bogo-microseconds
[58394:155675:0908/155938.403608:ERROR:audio_low_latency_input_mac.cc(905)] Capture time (1): 56499572986 bogo-microseconds
[58394:155675:0908/155938.403628:ERROR:audio_low_latency_input_mac.cc(940)] Capture time (2): 56499572986 bogo-microseconds
[58394:155675:0908/155938.403656:ERROR:audio_low_latency_input_mac.cc(955)] Capture time (3): 56499582986 bogo-microseconds
[58394:155675:0908/155938.413638:ERROR:audio_low_latency_input_mac.cc(905)] Capture time (1): 56499582986 bogo-microseconds
[58394:155675:0908/155938.413678:ERROR:audio_low_latency_input_mac.cc(940)] Capture time (2): 56499582986 bogo-microseconds
[58394:155675:0908/155938.413730:ERROR:audio_low_latency_input_mac.cc(955)] Capture time (3): 56499592986 bogo-microseconds
[58394:155675:0908/155938.423650:ERROR:audio_low_latency_input_mac.cc(905)] Capture time (1): 56501286919 bogo-microseconds
[58394:155675:0908/155938.423693:ERROR:audio_low_latency_input_mac.cc(940)] Capture time (2): 56501286919 bogo-microseconds
[58394:155675:0908/155938.423753:ERROR:audio_low_latency_input_mac.cc(955)] Capture time (3): 56501296919 bogo-microseconds
[58414:42019:0908/155938.423838:FATAL:audio_input_device.cc(448)] Check failed: base::TimeTicks::Now() >= capture_time (56499606433 bogo-microseconds vs. 56501286919 bogo-microseconds)
0   libbase.dylib                       0x000000010ef035fc base::debug::StackTrace::StackTrace(unsigned long) + 28
1   libbase.dylib                       0x000000010ef2dd50 logging::LogMessage::~LogMessage() + 224
2   libmedia.dylib                      0x000000011a10f111 media::AudioInputDevice::AudioThreadCallback::Process(unsigned int) + 673
3   libmedia.dylib                      0x000000011a107d52 media::AudioDeviceThread::ThreadMain() + 242
4   libbase.dylib                       0x000000010efc66af base::(anonymous namespace)::ThreadFunc(void*) + 95
5   libsystem_pthread.dylib             0x00007fff9268793b _pthread_body + 180
6   libsystem_pthread.dylib             0x00007fff92687887 _pthread_body + 0
7   libsystem_pthread.dylib             0x00007fff9268708d thread_start + 13

The capture timestamp jumps around 2 seconds compared to previous timestamp while TT::Now() is 15 ms later than previous capture timestamp.

It's the input timestamp (host time) that jumps almost 2 seconds, when Chrome's timeticks doesn't.

Thanks for testing. Very strange, it looks like their host time updates faster after suspend than our standard calls to get mach time; despite CoreAudio folks saying it's just mach time.

+miu since he knows all things time :)

Ping miu@, seems not all mach timestamps are created equal :|

Probably we should go ahead and clamp these values to zero to avoid negative delay values from having weird impacts on WebRTC. WDYT?

It's not clear to me what the bug is here. Can someone please explain?

1. Is it hardware-specific? If so, the driver is to blame; and workarounds should be specific to that situation.

2. Or, is this only triggered by a suspend+resume issue? If so, it sounds like the ideal solution would be to clear the FIFO after a suspend+resume (but that would take a lot to plumb-in).

3. Or, are we saying CoreAudio has a different source of time than mach_absolute_time() in some cases?

It's 3, somehow triggered by 2, but unrelated to the FIFO AFAICT.

Is #3 a temporary condition that occurs for a short time after resume, or are the timestamps from CoreAudio always inconsistent with TimeTicks post-resume?

Unsure, grunell@ if you remove the DCHECK does TT::Now eventually resync?

@grunell, is this due to the same as issue 825744 ?

Derp, just realized that issue is Win and this is Mac.

Needs feedback per c#11 though.