Audible anomalies - possibly linked to handling of control events from Loopback device

[siraaris]

I've observed audible hiccups that seem to be associated with events from the "PCM Slave Active" Loopback control:

The Loopback controls are:

root@cardia:~# amixer -c0 controls numid=2,iface=PCM,name='PCM Notify' numid=1,iface=PCM,name='PCM Rate Shift 100000' numid=7,iface=PCM,name='PCM Slave Access Mode' numid=3,iface=PCM,name='PCM Slave Active' numid=6,iface=PCM,name='PCM Slave Channels' numid=4,iface=PCM,name='PCM Slave Format' numid=5,iface=PCM,name='PCM Slave Rate' numid=9,iface=PCM,name='PCM Notify',device=1 numid=8,iface=PCM,name='PCM Rate Shift 100000',device=1 numid=14,iface=PCM,name='PCM Slave Access Mode',device=1 numid=10,iface=PCM,name='PCM Slave Active',device=1 numid=13,iface=PCM,name='PCM Slave Channels',device=1 numid=11,iface=PCM,name='PCM Slave Format',device=1 numid=12,iface=PCM,name='PCM Slave Rate',device=1

In the log below, between the log entries "Loopback active: Some(false)" and "Loopback active: Some(true)", an audible pause and resume occurs that is quite noticeable with music I know well.

2024-10-15 00:47:20.110719 DEBUG [src/bin.rs:393] SetSpeed message received 2024-10-15 00:47:20.168561 DEBUG [src/alsadevice.rs:857] Setting capture loopback speed to 0.999971197740113 2024-10-15 00:47:25.146158 DEBUG [src/alsadevice.rs:624] Send SetSpeed message for speed 0.999971197740113 2024-10-15 00:47:25.146230 DEBUG [src/alsadevice.rs:633] PB: buffer level: 8192.0, signal rms: Some(HistoryRecord { time: Instant { tv_sec: 4861, tv_nsec: 338469444 }, values: [4.3349402e-5, 4.3349402e-5, 3.0471343e-5, 3.0471343e-5, 0.00011437729, 5.100116e-7, 3.8113574e-6, 0.0, 9.5944015e-5, 9.5944015e-5, 6.768083e-5, 6.768083e-5, 9.4853254e-5, 1.0312939e-6, 3.6284177e-6, 0.0, 3.045552e-5, 3.045552e-5, 4.3242275e-5, 4.3242275e-5, 3.045552e-5, 3.045552e-5, 4.3242275e-5, 4.3242275e-5, 6.765983e-5, 6.765983e-5, 9.5823816e-5, 9.5823816e-5, 6.765983e-5, 6.765983e-5, 9.5823816e-5, 9.5823816e-5] }) 2024-10-15 00:47:25.146285 DEBUG [src/bin.rs:393] SetSpeed message received 2024-10-15 00:47:25.200554 DEBUG [src/alsadevice.rs:857] Setting capture loopback speed to 0.999971197740113 2024-10-15 00:47:29.070029 DEBUG [src/alsadevice_utils.rs:406] Event from numid 3 2024-10-15 00:47:29.070113 DEBUG [src/alsadevice_utils.rs:466] Loopback active: Some(false) 2024-10-15 00:47:29.070431 DEBUG [src/alsadevice_utils.rs:406] Event from numid 3 2024-10-15 00:47:29.070477 DEBUG [src/alsadevice_utils.rs:466] Loopback active: Some(true) 2024-10-15 00:47:30.182180 DEBUG [src/alsadevice.rs:624] Send SetSpeed message for speed 0.999971197740113 2024-10-15 00:47:30.182254 DEBUG [src/alsadevice.rs:633] PB: buffer level: 8192.0, signal rms: Some(HistoryRecord { time: Instant { tv_sec: 4866, tv_nsec: 374490953 }, values: [5.9836907e-7, 5.9836907e-7, 4.284782e-7, 4.284782e-7, 6.0166735e-6, 1.2277313e-7, 1.4627021e-7, 0.0, 6.6444176e-7, 6.6444176e-7, 4.7601887e-7, 4.7601887e-7, 1.8389077e-6, 1.5761822e-7, 1.6682306e-7, 0.0, 4.2872236e-7, 4.2872236e-7, 6.0042066e-7, 6.0042066e-7, 4.2872236e-7, 4.2872236e-7, 6.0042066e-7, 6.0042066e-7, 4.7733397e-7, 4.7733397e-7, 6.66067e-7, 6.66067e-7, 4.7733397e-7, 4.7733397e-7, 6.66067e-7, 6.66067e-7] }) 2024-10-15 00:47:30.182322 DEBUG [src/bin.rs:393] SetSpeed message received

There are also events from numid 1:

2024-10-15 00:46:44.866804 DEBUG [src/bin.rs:393] SetSpeed message received 2024-10-15 00:46:44.924524 DEBUG [src/alsadevice.rs:857] Setting capture loopback speed to 0.9999191299435028 2024-10-15 00:46:44.924604 DEBUG [src/alsadevice_utils.rs:406] Event from numid 1 2024-10-15 00:46:44.924615 DEBUG [src/alsadevice_utils.rs:542] Ignoring event from unknown numid 1 2024-10-15 00:46:49.902293 DEBUG [src/alsadevice.rs:624] Send SetSpeed message for speed 0.9999133446327684 2024-10-15 00:46:49.902367 DEBUG [src/alsadevice.rs:633] PB: buffer level: 8330.8, signal rms: Some(HistoryRecord { time: Instant { tv_sec: 4826, tv_nsec: 94605102 }, values: [5.870497e-7, 5.870497e-7, 3.9922926e-7, 3.9922926e-7, 3.0607032e-5, 8.1761684e-8, 8.021576e-7, 0.0, 3.267548e-7, 3.267548e-7, 2.2799871e-7, 2.2799871e-7, 6.3669354e-6, 1.0284083e-7, 7.0537004e-7, 0.0, 3.9663945e-7, 3.9663945e-7, 5.8049636e-7, 5.8049636e-7, 3.9663945e-7, 3.9663945e-7, 5.8049636e-7, 5.8049636e-7, 2.2795562e-7, 2.2795562e-7, 3.2458522e-7, 3.2458522e-7, 2.2795562e-7, 2.2795562e-7, 3.2458522e-7, 3.2458522e-7] }) 2024-10-15 00:46:49.902445 DEBUG [src/bin.rs:393] SetSpeed message received

These don't seem to cause any issue.