First `OutputStreamTimestamp` very odd.

[bspot]

On Linux / ALSA (via PulseAudio), the first time the audio callback is called after the stream is started, the timestamp contains nonsensical values:

fn main() {
    // Open audio device
    let host = cpal::default_host();
    println!("Host is \"{:?}\"", host.id());

    let device = host.default_output_device().ok_or_else(|| "No output device").unwrap();
    println!("Device is {:?}", device.name().unwrap());

    // Create stream
    let _stream = device
        .build_output_stream(
            &cpal::StreamConfig {
                channels: 1,
                sample_rate: cpal::SampleRate(44100),
                buffer_size: cpal::BufferSize::Default,
            },
            move |data: &mut [f32], info: &cpal::OutputCallbackInfo| {
                println!("{:?}", info.timestamp());
                data.fill(0.0);
            },
            |err| {
                println!("{:?}", err);
            },
        )
        .unwrap();

    // Wait 
    loop {
        thread::sleep(Duration::from_secs(1));
    }
}

Output:

Host is "Alsa"
Device is "default"
OutputStreamTimestamp { callback: StreamInstant { secs: 1105516, nanos: 585731676 }, playback: StreamInstant { secs: 1105516, nanos: 585731676 } }
OutputStreamTimestamp { callback: StreamInstant { secs: 0, nanos: 28177 }, playback: StreamInstant { secs: 0, nanos: 100028177 } }
OutputStreamTimestamp { callback: StreamInstant { secs: 0, nanos: 25960575 }, playback: StreamInstant { secs: 0, nanos: 166504792 } }
OutputStreamTimestamp { callback: StreamInstant { secs: 0, nanos: 56707430 }, playback: StreamInstant { secs: 0, nanos: 192081579 } }
OutputStreamTimestamp { callback: StreamInstant { secs: 0, nanos: 82378008 }, playback: StreamInstant { secs: 0, nanos: 222740819 } }
OutputStreamTimestamp { callback: StreamInstant { secs: 0, nanos: 107205332 }, playback: StreamInstant { secs: 0, nanos: 248293767 } }
OutputStreamTimestamp { callback: StreamInstant { secs: 0, nanos: 132064702 }, playback: StreamInstant { secs: 0, nanos: 273493273 } }
OutputStreamTimestamp { callback: StreamInstant { secs: 0, nanos: 162067172 }, playback: StreamInstant { secs: 0, nanos: 298665811 } }
OutputStreamTimestamp { callback: StreamInstant { secs: 0, nanos: 190642728 }, playback: StreamInstant { secs: 0, nanos: 328012342 } }
OutputStreamTimestamp { callback: StreamInstant { secs: 0, nanos: 215397391 }, playback: StreamInstant { secs: 0, nanos: 356825962 } }
OutputStreamTimestamp { callback: StreamInstant { secs: 0, nanos: 250041818 }, playback: StreamInstant { secs: 0, nanos: 381810525 } }
OutputStreamTimestamp { callback: StreamInstant { secs: 0, nanos: 279423110 }, playback: StreamInstant { secs: 0, nanos: 416248506 } }
OutputStreamTimestamp { callback: StreamInstant { secs: 0, nanos: 313084664 }, playback: StreamInstant { secs: 0, nanos: 445601670 } }
OutputStreamTimestamp { callback: StreamInstant { secs: 0, nanos: 341173837 }, playback: StreamInstant { secs: 0, nanos: 478951614 } }
OutputStreamTimestamp { callback: StreamInstant { secs: 0, nanos: 370250724 }, playback: StreamInstant { secs: 0, nanos: 507030769 } }
OutputStreamTimestamp { callback: StreamInstant { secs: 0, nanos: 404757068 }, playback: StreamInstant { secs: 0, nanos: 536389721 } }

[FreeFull]

Notably, StreamInstant is meant to be monotonic, but the first value breaks that guarantee.

[hugovdm]

I'm seeing this problem too, but it also looks like it isn't entirely nonsensical:

• When running with ALSA, the StreamInstant's generally seem to start at zero, except for that first one.
• When I run with JACK, time doesn't start at zero. I'm not sure what the "epoch" was: it's currently claiming just over 2 hours, but my laptop was sleeping, and uptime currently reports ~20.5 hours.
• The first OutputStreamTimestamp StreamInstant returned when using ALSA seems to be the same as what would be returned when using JACK.

So it would seem there's some system epoch which is leaking into the first playback callback when using ALSA, after which the epoch is reset to ~now.

I've not analyzed in depth, just peeked at src/host/alsa/mod.rs - and find myself wondering if it might e.g. be a bug in creation_instant handling?

[akulisch]

For me it seems to be the system’s uptime for the first sample (checked with cat /proc/uptime). After that it is the time since playback started (exactly like in the issue example).