media_addon_server crash while adjusting mixer volumes

[pulkomandy]

I decided to try if the recent changes in media helped with having no sound on my laptop.

I still have no sound, but additionally, adjusting volume controls in media preferences triggers asserts in media_addon_server

[waddlesplash]

This is pretty indicative of what the problem is, though. These messages occur when the difference between current real/performance time and the last one reported is >= (1<<24) microseconds, or around 16 seconds. So somehow the reported times are either wrong and in the past, or stuck at 0 because they never posted anything newer. If you rebuild libmedia.so with debug info and take a look it should become apparent which the problem is.

[pulkomandy]

• performance_time: 20906666
• with_latency: 0
• last_perf_time: 4096525
• last_real_time: 38784576710
• last_drift: 0.999989
• perf_time_difference: 16810141

That would be a perf_time_difference of slightly above 16 seconds, right at the limit of what's allowed?

And it looks like this function could have returned before hitting the debugger call if last_drift was 1, but it is slightly less.

I also looked at the time source fBuf values, the successive values are something like 40000 apart, both for the realtime and the performance time. The lowest drift is 0.999930, next lowest is 0.999981. Should that be "close enough"? I have no idea what these values mean.

[pulkomandy]

debug report with libmedia.so built in debug mode

[waddlesplash]

I have no idea what these values mean.

real_time is the system clock (system_time(), in microseconds as usual) performance_time is also in microseconds (for multi_audio sinks anyway; it often isn't for other streams), but it generally counts from an arbitrary start time; usually its 0 is when audio output was started (or restarted) for this particular card. "drift" is the ratio between the change of the performance time and the real time. So if they both change at 1 microsecond per microsecond then the drift value will be 1. On the other hand if the audio hardware outputs data at a rate slightly faster or slower than microseconds then we will get something other than 1.

The fact that the performance times are so different is the problem here. The audio mixer waits for the performance time to be nonzero before it starts, and then counts upward as it mixes, repeatedly asking the TimeSource what the new real time for its current performance time is. In order to compute this, it takes the performance time value passed in by the mixer, computes the difference to the last reported (by the multi_audio node) performance time, and then factors in the drift.

So for there to be a difference of over 16 seconds but the drift is around 1 probably means that the multi_audio node quit updating times 16 seconds ago. That probably means it hasn't exchanged buffers with the driver in the kernel since over 16 seconds ago.

[waddlesplash]

Please retest after hrev58097 (also merged into beta5.)

[pulkomandy]

No crash anymore when moving volume sliders. I hit a "performance time too high" assert if I try to select my soundcard as a default input source in Media preferences, however.