Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Add event timestamping #19

Open
strohel opened this issue Apr 22, 2023 · 3 comments · Fixed by #36
Open

Add event timestamping #19

strohel opened this issue Apr 22, 2023 · 3 comments · Fixed by #36
Assignees
@strohel

Comments

@strohel
Copy link
Member

strohel commented Apr 22, 2023

Follow-up to #11 (comment)

I got and idea for an empirical test to see how important would proper event timestamping be: extend #12 just a little to produce the click event at a steady and very high rate (e.g. 250 Hz, once every 4 ms), and then run it over long network like Tokyo -> Prague.

This may even turn out to be useful "hear the network jitter" probe on its own (which would depend on absence of timestamping as a twist).
@strohel strohel self-assigned this Apr 22, 2023
@skywhale
Copy link
Member

This is a great idea! I'm very curious, too :)

@strohel strohel mentioned this issue Apr 25, 2023
Merged
@strohel
Copy link
Member Author

strohel commented Apr 25, 2023

Not sure where to report this, so I'll abuse this issue.

When playing with tick_probe from #30 (which produces events at given frequency) today with @goodhoko and @bschwind, the heard "frequency" increases between tick_probe 30 and tick_probe 40, but beyond 40~80 the heard "frequency" doesn't really increase - tick_probe 400 sounds louder than tick_probe 200, but that's it. This is happening both with main and the jukebox #25 branch.

We know from Jen's research that simply overlaying the same sample can produce arbitrarily high-pitched sounds.

This problem basically reduces our time resolution to one buffer length (e.g. 25 ms), which is I think too low for good fidelity.

After musing about that a bit my theory is that this is caused by the fact the audio libraries work with buffers of samples. So when we call output_stream.play_raw(sample), the library cannot actually start playing right now - it can only start playing from the next buffer it submits. So all events that happen to arrive between the same buffer submissions play 100% aligned (and not shifted by a couple of samples as one would expect).

One way to circumvent this with rodio would be to save "inter-buffer delay" for each received event and then use https://docs.rs/rodio/latest/rodio/source/trait.Source.html#method.delay to shift playback of each sample appropriately. That circles us back to adding timestamps to events.

But I ran into problems setting or querying the buffer size/length with rodio [1], but maybe @bschwind you got more confident in the meantime that we could switch to fundsp instead, which may handle this better?

[1] I think that rodio exposes cpals API in suboptimal way: https://docs.rs/rodio/latest/rodio/struct.OutputStream.html#method.try_from_device_config accepts https://docs.rs/cpal/latest/cpal/struct.SupportedStreamConfig.html - but that is a range of possible values, and I think it should accept https://docs.rs/cpal/latest/cpal/struct.StreamConfig.html (which can specify particular buffer size) instead.

@goodhoko goodhoko mentioned this issue Apr 26, 2023
Closed
strohel added a commit that referenced this issue Apr 26, 2023
@strohel
Drive audio directly using cpal, position sounds precisely within cal…
5c12ea7 
…lbacks

This is a form of alternative to #35 to resolve #19 (comment)

Note that this should resolve the specific problem, but we still may want to use `fundsp` (somehow) to synthetize and modify sound.

We still use `rodio` for audio file decoding and processing, but we drive the `cpal` audio callback directly (using code adapted from `rodio` itself).

That allows us to run custom code during the callback, which we use to offset samples tasked to play (giving all samples the same delay of one period, rather than variable delay based on how close next to the next callback they fire).

<details><summary>See example print of ns_since_last_callback when we play 1000 samples a second</summary>
The period length is apparently ~42 ms.

```
ns_since_last_callback:  38695172.
ns_since_last_callback:  39784768.
ns_since_last_callback:  40887270.
ns_since_last_callback:  41945052.
ns_since_last_callback:    368139.
ns_since_last_callback:   1477218.
ns_since_last_callback:   2445557.
ns_since_last_callback:   3573154.
ns_since_last_callback:   4616437.
ns_since_last_callback:   5675630.
ns_since_last_callback:   6764239.
ns_since_last_callback:   7835255.
ns_since_last_callback:   8925809.
ns_since_last_callback:   9995435.
ns_since_last_callback:  11159180.
ns_since_last_callback:  12234090.
ns_since_last_callback:  13312871.
ns_since_last_callback:  14392252.
ns_since_last_callback:  15460542.
ns_since_last_callback:  16545115.
ns_since_last_callback:  17564547.
ns_since_last_callback:  18582770.
ns_since_last_callback:  19640031.
ns_since_last_callback:  20683684.
ns_since_last_callback:  21803771.
ns_since_last_callback:  22879984.
ns_since_last_callback:  23956644.
ns_since_last_callback:  25022856.
ns_since_last_callback:  26101435.
ns_since_last_callback:  27179575.
ns_since_last_callback:  28249203.
ns_since_last_callback:  29342603.
ns_since_last_callback:  30412447.
ns_since_last_callback:  31495496.
ns_since_last_callback:  32519447.
ns_since_last_callback:  33580415.
ns_since_last_callback:  34606142.
ns_since_last_callback:  35697450.
ns_since_last_callback:  36791844.
ns_since_last_callback:  37869512.
ns_since_last_callback:  38943775.
ns_since_last_callback:  40022488.
ns_since_last_callback:  41100993.
ns_since_last_callback:  42180112.
ns_since_last_callback:    481551.
ns_since_last_callback:   1608677.
ns_since_last_callback:   2667820.
ns_since_last_callback:   3745600.
ns_since_last_callback:   4785690.
```

</details>

With this I'm able to got from `tick_probe 1` all the way to `tick_probe 4000` (!) and still hear difference. [1]

[1] However, there seem to be inefficiencies somewhere that result in e.g. `composer` saying `Received 860 events (3440 bytes) in last 1.00s.` when we call `tick_probe 1000`. May be naive timing code in `tick_probe` itself (@PabloMansanet?).
@strohel strohel mentioned this issue Apr 26, 2023
Merged
strohel added a commit that referenced this issue Apr 27, 2023
@strohel
Drive audio directly using cpal, position sounds precisely within cal…
df9ea5b 
…lbacks

This is a form of alternative to #35 to resolve #19 (comment)

Note that this should resolve the specific problem, but we still may want to use `fundsp` (somehow) to synthetize and modify sound.

We still use `rodio` for audio file decoding and processing, but we drive the `cpal` audio callback directly (using code adapted from `rodio` itself).

That allows us to run custom code during the callback, which we use to offset samples tasked to play (giving all samples the same delay of one period, rather than variable delay based on how close next to the next callback they fire).

<details><summary>See example print of ns_since_last_callback when we play 1000 samples a second</summary>
The period length is apparently ~42 ms.

```
ns_since_last_callback:  38695172.
ns_since_last_callback:  39784768.
ns_since_last_callback:  40887270.
ns_since_last_callback:  41945052.
ns_since_last_callback:    368139.
ns_since_last_callback:   1477218.
ns_since_last_callback:   2445557.
ns_since_last_callback:   3573154.
ns_since_last_callback:   4616437.
ns_since_last_callback:   5675630.
ns_since_last_callback:   6764239.
ns_since_last_callback:   7835255.
ns_since_last_callback:   8925809.
ns_since_last_callback:   9995435.
ns_since_last_callback:  11159180.
ns_since_last_callback:  12234090.
ns_since_last_callback:  13312871.
ns_since_last_callback:  14392252.
ns_since_last_callback:  15460542.
ns_since_last_callback:  16545115.
ns_since_last_callback:  17564547.
ns_since_last_callback:  18582770.
ns_since_last_callback:  19640031.
ns_since_last_callback:  20683684.
ns_since_last_callback:  21803771.
ns_since_last_callback:  22879984.
ns_since_last_callback:  23956644.
ns_since_last_callback:  25022856.
ns_since_last_callback:  26101435.
ns_since_last_callback:  27179575.
ns_since_last_callback:  28249203.
ns_since_last_callback:  29342603.
ns_since_last_callback:  30412447.
ns_since_last_callback:  31495496.
ns_since_last_callback:  32519447.
ns_since_last_callback:  33580415.
ns_since_last_callback:  34606142.
ns_since_last_callback:  35697450.
ns_since_last_callback:  36791844.
ns_since_last_callback:  37869512.
ns_since_last_callback:  38943775.
ns_since_last_callback:  40022488.
ns_since_last_callback:  41100993.
ns_since_last_callback:  42180112.
ns_since_last_callback:    481551.
ns_since_last_callback:   1608677.
ns_since_last_callback:   2667820.
ns_since_last_callback:   3745600.
ns_since_last_callback:   4785690.
```

</details>

With this I'm able to got from `tick_probe 1` all the way to `tick_probe 4000` (!) and still hear difference. [1]

[1] However, there seem to be inefficiencies somewhere that result in e.g. `composer` saying `Received 860 events (3440 bytes) in last 1.00s.` when we call `tick_probe 1000`. May be naive timing code in `tick_probe` itself (@PabloMansanet?).
goodhoko pushed a commit that referenced this issue Apr 28, 2023
@strohel @goodhoko
Drive audio directly using cpal, position sounds precisely within cal…
6108302 
…lbacks

This is a form of alternative to #35 to resolve #19 (comment)

Note that this should resolve the specific problem, but we still may want to use `fundsp` (somehow) to synthetize and modify sound.

We still use `rodio` for audio file decoding and processing, but we drive the `cpal` audio callback directly (using code adapted from `rodio` itself).

That allows us to run custom code during the callback, which we use to offset samples tasked to play (giving all samples the same delay of one period, rather than variable delay based on how close next to the next callback they fire).

<details><summary>See example print of ns_since_last_callback when we play 1000 samples a second</summary>
The period length is apparently ~42 ms.

```
ns_since_last_callback:  38695172.
ns_since_last_callback:  39784768.
ns_since_last_callback:  40887270.
ns_since_last_callback:  41945052.
ns_since_last_callback:    368139.
ns_since_last_callback:   1477218.
ns_since_last_callback:   2445557.
ns_since_last_callback:   3573154.
ns_since_last_callback:   4616437.
ns_since_last_callback:   5675630.
ns_since_last_callback:   6764239.
ns_since_last_callback:   7835255.
ns_since_last_callback:   8925809.
ns_since_last_callback:   9995435.
ns_since_last_callback:  11159180.
ns_since_last_callback:  12234090.
ns_since_last_callback:  13312871.
ns_since_last_callback:  14392252.
ns_since_last_callback:  15460542.
ns_since_last_callback:  16545115.
ns_since_last_callback:  17564547.
ns_since_last_callback:  18582770.
ns_since_last_callback:  19640031.
ns_since_last_callback:  20683684.
ns_since_last_callback:  21803771.
ns_since_last_callback:  22879984.
ns_since_last_callback:  23956644.
ns_since_last_callback:  25022856.
ns_since_last_callback:  26101435.
ns_since_last_callback:  27179575.
ns_since_last_callback:  28249203.
ns_since_last_callback:  29342603.
ns_since_last_callback:  30412447.
ns_since_last_callback:  31495496.
ns_since_last_callback:  32519447.
ns_since_last_callback:  33580415.
ns_since_last_callback:  34606142.
ns_since_last_callback:  35697450.
ns_since_last_callback:  36791844.
ns_since_last_callback:  37869512.
ns_since_last_callback:  38943775.
ns_since_last_callback:  40022488.
ns_since_last_callback:  41100993.
ns_since_last_callback:  42180112.
ns_since_last_callback:    481551.
ns_since_last_callback:   1608677.
ns_since_last_callback:   2667820.
ns_since_last_callback:   3745600.
ns_since_last_callback:   4785690.
```

</details>

With this I'm able to got from `tick_probe 1` all the way to `tick_probe 4000` (!) and still hear difference. [1]

[1] However, there seem to be inefficiencies somewhere that result in e.g. `composer` saying `Received 860 events (3440 bytes) in last 1.00s.` when we call `tick_probe 1000`. May be naive timing code in `tick_probe` itself (@PabloMansanet?).
@strohel
Copy link
Member Author

strohel commented Apr 28, 2023

Hmm, there was a string to resolve https://github.com/tonarino/acoustic_profiler/issues/19#issuecomment-1522348735 in #36, but GitHub interpreted this as resolving the whole issue.

On the contrary, we've seen (heard) that network (Tokyo -> Prague) indeed introduces audible jitter (https://tonari-no.slack.com/archives/C051C9VPXKJ/p1682678798638329 - albeit only with high frequencies like 1000 Hz), so timestamping does make a difference.

@strohel strohel reopened this Apr 28, 2023
@strohel strohel changed the title Do we need event timestamping? Add event timestamping Apr 28, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@strohel strohel

Labels
None yet
Projects
None yet
Milestone
No milestone
2 participants
@strohel @skywhale