Statime crash in filter; Inferno not working with JACK

[jcelerier]

running up-to-date archlinux, kernel 6.13.8

• On statime@00ab361d951ccef18bcbd84fb03ba300170ef8d7 (branch inferno-dev so I think it's more meaningful to post here?) - it will crash randomly after some time:

thread 'main' panicked at statime-linux/src/main.rs:523:31:
Clock mode change failed: SendError { .. }

• Trying to run jack on top of the ALSA plug-in (inferno@bee9b33) - I cannot get any sound out, it gets stuck the first time I try to connect a client. The second time it just crashes.

JackPosixProcessSync::LockedTimedWait error usec = 5000000 err = Connection timed out
Driver is not running
Cannot create new client
thread '<unnamed>' panicked at alsa_pcm_inferno/src/lib.rs:185:68:
called `Result::unwrap()` on an `Err` value: TryFromIntError(())
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
ALSA: poll time out, polled for 7999051 usecs, Retrying with a recovery, retry cnt = 3
thread '<unnamed>' panicked at core/src/panicking.rs:223:5:
panic in a function that cannot unwind


   0:     0x7905b7b3288e - <std::sys::backtrace::BacktraceLock::print::DisplayBacktrace as core::fmt::Display>::fmt::hfa95d474a300358f
   1:     0x7905b7b58783 - core::fmt::write::h6cb81b0f6ad3059a
   2:     0x7905b7b2f793 - std::io::Write::write_fmt::hcd7e8a932ef5deab
   3:     0x7905b7b326d2 - std::sys::backtrace::BacktraceLock::print::h7f99276441c6cad1
   4:     0x7905b7b3380e - std::panicking::default_hook::{{closure}}::hf0743ce94de533f1
   5:     0x7905b7b33654 - std::panicking::default_hook::h589cb4b0f5669762
   6:     0x7905b7b33dd7 - std::panicking::rust_panic_with_hook::h8a2d807994fcaf4c
   7:     0x7905b7b33c36 - std::panicking::begin_panic_handler::{{closure}}::h36e74a30fe164220
   8:     0x7905b7b32d99 - std::sys::backtrace::__rust_end_short_backtrace::h0b759bcce926471b
   9:     0x7905b7b338fe - rust_begin_unwind
  10:     0x7905b783fb4c - core::panicking::panic_nounwind_fmt::h18bc0dbea7b17fe1
  11:     0x7905b783fbdb - core::panicking::panic_nounwind::h38d64692eea4d2ea
  12:     0x7905b783fce6 - core::panicking::panic_cannot_unwind::h8d6c33bd0112d77a
  13:     0x7905b78b4be5 - asound_module_pcm_inferno::plugin_pointer::hd4f4fdee1b3f9540
  14:     0x7905b968c31f - <unknown>
  15:     0x7905b968c610 - <unknown>
  16:     0x7905b96cb8db - snd_pcm_status
  17:     0x7905ba535e64 - <unknown>
  18:     0x7905ba537c2a - alsa_driver_wait
  19:     0x7905ba52e1ad - _ZN4Jack14JackAlsaDriver4ReadEv
  20:     0x7905ba799c7e - _ZN4Jack15JackAudioDriver11ProcessSyncEv
  21:     0x7905ba7ac1f6 - _ZThn16_N4Jack18JackThreadedDriver7ExecuteEv
  22:     0x7905ba796822 - _ZN4Jack15JackPosixThread13ThreadHandlerEPv
  23:     0x7905ba09f90c - <unknown>
  24:     0x7905ba1214dc - <unknown>
  25:                0x0 - <unknown>

[teodly]

thread 'main' panicked at statime-linux/src/main.rs:523:31:
Clock mode change failed: SendError { .. }

Looks like clock_task stopped working and thus send through channel failed, was there any error in the log before?

thread '' panicked at alsa_pcm_inferno/src/lib.rs:185:68:
called Result::unwrap() on an Err value: TryFromIntError(())

There is no unwrap in alsa_pcm_inferno/src/lib.rs line 185, are you sure this error originated from commit bee9b33?

[jcelerier]

My bad, I was indeed on an older commit - forgot to build in release profile. The statime crash happens all the time, I will share a full log as soon as I try this again

[jcelerier]

Here is a longer log for the statime crash: https://paste.ofcode.org/33kmuGwC4uSfmJ2EB9TM5Ux

I see line 882

thread 'tokio-runtime-worker' panicked at statime/src/filters/kalman.rs:261:9:
assertion failed: time >= self.filter_time

followed by

thread 'main' panicked at statime-linux/src/main.rs:523:31:
Clock mode change failed: SendError { .. }

With the current head on inferno I get:

[2025-04-07T20:49:11.770147Z DEBUG inferno_aoip::device_server::info_mcast_server] no clock available
[2025-04-07T20:49:12.770877Z DEBUG inferno_aoip::device_server::info_mcast_server] no clock available
[2025-04-07T20:49:13.770587Z DEBUG inferno_aoip::device_server::info_mcast_server] no clock available
[2025-04-07T20:49:14.770004Z DEBUG inferno_aoip::device_server::info_mcast_server] no clock available

when I try to use the alsa pcm plug-in - is there maybe some permission issue that would prevent the jackd process to read statime output ?

[jcelerier]

Another statime crash:

2025-04-07T21:03:43.183169Z  INFO log: Wander update log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=737
2025-04-07T21:03:43.183176Z  INFO log: Wander uncertainty: 12570726.795596072ns log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=706
2025-04-07T21:03:43.183182Z  INFO log: Wander update predict: -828196.47694182ns, actual: -1104827ns log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=720
2025-04-07T21:03:43.183189Z  INFO log: p: 0.017556858537571496 log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=729
2025-04-07T21:03:43.183194Z  INFO log: Wander update log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=737
2025-04-07T21:03:43.183201Z  INFO log: wander score: 2 log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=757
2025-04-07T21:03:43.183210Z  INFO log: Measurement too far from state, resetting log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=387
2025-04-07T21:03:43.183226Z  INFO log: Estimated offset -1097768.8573785939ns+-707113.8766910802ns, freq 0+-100, delay 7057.857378593828+-707113.8766910802 log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=669
2025-04-07T21:03:43.183272Z  INFO log: Stepped clock by 0.001097768857378594s log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="/home/jcelerier/projets/oss/statime/statime/src/filters/kalman.rs" log.line=662
2025-04-07T21:03:43.435348Z DEBUG log: Interclock measurement: 1744059823435303697 1744059823435037270 1744059823435321827 log.target="statime" log.module_path="statime" log.file="statime-linux/src/main.rs" log.line=181
2025-04-07T21:03:43.435393Z  INFO log: New entry 18129.99999999999 log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=163
2025-04-07T21:03:43.435404Z  INFO log: New uncertainty estimate: 6371.484044944309ns log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=201
2025-04-07T21:03:43.435424Z  INFO log: Wander uncertainty: 1135799590302.6003ns log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=706
2025-04-07T21:03:43.435431Z  INFO log: Wander update predict: infns, actual: -266427ns log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=720
2025-04-07T21:03:43.435439Z  INFO log: p: 1 log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=729
2025-04-07T21:03:43.435445Z  INFO log: Wander update log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=737
2025-04-07T21:03:43.435453Z  INFO log: Wander uncertainty: 6357.2091223128655ns log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=706
2025-04-07T21:03:43.435461Z  INFO log: wander score: 3 log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=757
2025-04-07T21:03:43.435481Z  INFO log: Estimated offset -275491.99551493156ns+-4379.561589673464ns, freq -1651.652968050396+-1379929091.1054149, delay 9064.923008250773+-4379.477876373323 log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=669
2025-04-07T21:03:43.435538Z  INFO log: Steered frequency by -infppm (target: 137.74599775746577ppm) log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="/home/jcelerier/projets/oss/statime/statime/src/filters/kalman.rs" log.line=649
2025-04-07T21:03:43.525625Z DEBUG log: Recommended state port 1: Some(M2(InternalDefaultDS { clock_identity: ClockIdentity([212, 147, 144, 21, 85, 146, 0, 0]), number_ports: 1, clock_quality: ClockQuality { clock_class: 248, clock_accuracy: Unknown, offset_scaled_log_variance: 26880 }, priority_1: 249, priority_2: 128, domain_number: 0, slave_only: false, sdo_id: SdoId(0) })) log.target="statime::ptp_instance" log.module_path="statime::ptp_instance" log.file="/home/jcelerier/projets/oss/statime/statime/src/ptp_instance.rs" log.line=131
2025-04-07T21:03:43.687290Z DEBUG log: Interclock measurement: 1744059823687233050 1744059823686697580 1744059823687260921 log.target="statime" log.module_path="statime" log.file="statime-linux/src/main.rs" log.line=181
2025-04-07T21:03:43.687344Z  INFO log: New entry NaN log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=163
2025-04-07T21:03:43.687380Z  INFO log: New uncertainty estimate: NaNns log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=201
2025-04-07T21:03:43.687397Z  INFO log: Wander uncertainty: 1134594857099.4907ns log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=706
2025-04-07T21:03:43.687408Z  INFO log: Wander update predict: NaNns, actual: -535470ns log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=720
2025-04-07T21:03:43.687415Z  INFO log: p: NaN log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=729
2025-04-07T21:03:43.687422Z  INFO log: Wander update log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=737
2025-04-07T21:03:43.687429Z  INFO log: Wander uncertainty: 280104696.6307287ns log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=706
2025-04-07T21:03:43.687436Z  INFO log: wander score: 2 log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=757
2025-04-07T21:03:43.687445Z  INFO log: Measurement too far from state, resetting log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=387
2025-04-07T21:03:43.687461Z  INFO log: Estimated offset NaNns+-NaNns, freq NaN+-NaN, delay NaN+-NaN log.target="statime::filters::kalman" log.module_path="statime::filters::kalman" log.file="statime/src/filters/kalman.rs" log.line=669

thread 'tokio-runtime-worker' panicked at /home/jcelerier/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/fixed-1.28.0/src/cast.rs:197:1:
NaN
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
2025-04-07T21:03:45.526687Z DEBUG log: Recommended state port 1: Some(M2(InternalDefaultDS { clock_identity: ClockIdentity([212, 147, 144, 21, 85, 146, 0, 0]), number_ports: 1, clock_quality: ClockQuality { clock_class: 248, clock_accuracy: Unknown, offset_scaled_log_variance: 26880 }, priority_1: 249, priority_2: 128, domain_number: 0, slave_only: false, sdo_id: SdoId(0) })) log.target="statime::ptp_instance" log.module_path="statime::ptp_instance" log.file="/home/jcelerier/projets/oss/statime/statime/src/ptp_instance.rs" log.line=131

thread 'main' panicked at statime-linux/src/main.rs:523:31:
Clock mode change failed: SendError { .. }

[jcelerier]

note that we have a hefty amount of varied Dante and AES67 devices plugged in here - I'm suspecting that maybe there's some clock mismatch on the network that could cause an issue:

• multiple DVS
• RME digiface dante
• multiple Q-SYS Core devices
• DAD Pro 256
• Tascam ML-16D
• Ferrofish A32

If I can get this to work, I'll gladly validate that the driver is able to work with all of these :)

[jcelerier]

If I set INFERNO_CLOCK_PATH=/dev/ptp0 I don't get the "no clock available" messages anymore. That said, ALSA apps seem to be stuck in poll loops.

[jcelerier]

log of running jack:

/usr/bin/jackd -S -dalsa -dinferno -r48000 -p256 -n2 -s -Xseq                                  jackdmp 1.9.22         
Copyright 2001-2005 Paul Davis and others.
Copyright 2004-2016 Grame.
Copyright 2016-2023 Filipe Coelho.
jackdmp comes with ABSOLUTELY NO WARRANTY
This is free software, and you are welcome to redistribute it
under certain conditions; see the file COPYING for details
jack_get_descriptor : dll 
jack_get_descriptor returns null for 'jack_inprocess.so'
jack_get_descriptor : dll 
jack_get_descriptor returns null for 'jack_internal_metro.so'
jack_get_descriptor : dll 
jack_get_descriptor returns null for 'jack_intime.so'
no message buffer overruns
no message buffer overruns
no message buffer overruns
JACK server starting in realtime mode with priority 10
self-connect-mode is "Don't restrict self connect requests"
ALSA lib control.c:1575:(snd_ctl_open_noupdate) Invalid CTL inferno
control open "inferno" (No such file or directory)
ALSA lib control.c:1575:(snd_ctl_open_noupdate) Invalid CTL inferno
control open "inferno" (No such file or directory)
creating alsa driver ... inferno|inferno|256|2|48000|0|0|nomon|swmeter|soft-mode|32bit
ALSA lib control.c:1575:(snd_ctl_open_noupdate) Invalid CTL inferno
control open "inferno" (No such file or directory)
[2025-04-07T21:20:25.100061Z DEBUG asound_module_pcm_inferno] HW_PERIOD_BYTES: [4096, 8192, 16384, 32768, 65536, 131072, 262144, 524288, 1048576, 2097152, 4194304, 8388608]
[2025-04-07T21:20:25.100071Z DEBUG asound_module_pcm_inferno] HW_BUFFER_BYTES: [262144, 524288, 1048576, 2097152, 4194304, 8388608, 16777216]
[2025-04-07T21:20:25.100076Z DEBUG asound_module_pcm_inferno] HW_PERIODS: [2, 4, 8, 16, 32, 64, 128, 256, 512, 1024, 2048, 4096, 8192, 16384, 32768, 65536, 131072, 262144, 524288, 1048576]
plugin_define end
[2025-04-07T21:20:25.100375Z DEBUG asound_module_pcm_inferno] HW_PERIOD_BYTES: [4096, 8192, 16384, 32768, 65536, 131072, 262144, 524288, 1048576, 2097152, 4194304, 8388608]
[2025-04-07T21:20:25.100378Z DEBUG asound_module_pcm_inferno] HW_BUFFER_BYTES: [262144, 524288, 1048576, 2097152, 4194304, 8388608, 16777216]
[2025-04-07T21:20:25.100380Z DEBUG asound_module_pcm_inferno] HW_PERIODS: [2, 4, 8, 16, 32, 64, 128, 256, 512, 1024, 2048, 4096, 8192, 16384, 32768, 65536, 131072, 262144, 524288, 1048576]
plugin_define end
configuring for 48000Hz, period = 256 frames (5.3 ms), buffer = 2 periods
ALSA: final selected sample format for capture: 32bit integer little-endian
ALSA: use 4 periods for capture
plugin_prepare called
[2025-04-07T21:20:25.100414Z DEBUG asound_module_pcm_inferno] got buffer size 1024 samples * 64 channels, first channel: address 587585068040 with first 0b, step 2048b
period size: 256
boundary: 4611686018427387904
[2025-04-07T21:20:25.100729Z INFO  inferno_aoip::state_storage] using state directory: /home/jcelerier/.local/state/inferno_aoip/00000a0a1ea60000
[2025-04-07T21:20:25.100881Z INFO  inferno_aoip::device_server] clock path: Some("/dev/ptp0")
[2025-04-07T21:20:25.100936Z INFO  inferno_aoip::device_server] waiting for clock
[2025-04-07T21:20:25.100945Z INFO  inferno_aoip::device_server] clock ready
[2025-04-07T21:20:25.100976Z INFO  inferno_aoip::device_server] all common tasks spawned
ALSA: final selected sample format for playback: 32bit integer little-endian
started receiver
ALSA: use 4 periods for playback
plugin_prepare called
[2025-04-07T21:20:25.101103Z DEBUG asound_module_pcm_inferno] got buffer size 1024 samples * 64 channels, first channel: address 5875850ad2a0 with first 0b, step 2048b
period size: 256
boundary: 4611686018427387904
[2025-04-07T21:20:25.101153Z WARN  inferno_aoip::device_server::channels_subscriber] Unable to load state (this is normal in first run): Os { code: 2, kind: NotFound, message: "No such file or directory" }
plugin_prepare called
[2025-04-07T21:20:25.102155Z DEBUG asound_module_pcm_inferno] got buffer size 1024 samples * 64 channels, first channel: address 5875850ad2a0 with first 0b, step 2048b
period size: 256
boundary: 4611686018427387904
[2025-04-07T21:20:25.102244Z ERROR inferno_aoip::device_server::flows_tx] unable to get start timestamp for ring buffer output: RecvError(())
started transmitter
[2025-04-07T21:20:25.102313Z WARN  inferno_aoip::common] Encountered error SendError { .. } at <disabled>
[2025-04-07T21:20:25.102349Z INFO  inferno_aoip::device_server] transmitter stopped
stopped transmitter
plugin_prepare called
[2025-04-07T21:20:25.102357Z DEBUG asound_module_pcm_inferno] got buffer size 1024 samples * 64 channels, first channel: address 587585068040 with first 0b, step 2048b
period size: 256
boundary: 4611686018427387904
started transmitter
[2025-04-07T21:20:25.103589Z ERROR inferno_aoip::device_server::channels_subscriber] unable to receive start time, ring_buffer addressing will be wrong!
[2025-04-07T21:20:25.103602Z INFO  inferno_aoip::device_server] receiver stopped
stopped receiver
started receiver
[2025-04-07T21:20:25.103790Z WARN  inferno_aoip::device_server::channels_subscriber] Unable to load state (this is normal in first run): Os { code: 2, kind: NotFound, message: "No such file or directory" }
port created: Midi-Through:midi/playback_1
port created: Midi-Through:midi/capture_1
warning: setting start_time in plugin_pointer, not plugin_start
plugin_start called
plugin_start called
plugin_stop called
plugin_stop called
plugin_prepare called
ALSA: poll time out, polled for 7999044 usecs, Retrying with a recovery, retry cnt = 1
[2025-04-07T21:20:33.103239Z DEBUG asound_module_pcm_inferno] got buffer size 1024 samples * 64 channels, first channel: address 5875850ad2a0 with first 0b, step 2048b
period size: 256
boundary: 4611686018427387904
[2025-04-07T21:20:33.103395Z INFO  inferno_aoip::device_server] transmitter stopped
stopped transmitter
[2025-04-07T21:20:33.103559Z INFO  inferno_aoip::device_server] receiver stopped
stopped receiver
plugin_prepare called
[2025-04-07T21:20:33.103587Z DEBUG asound_module_pcm_inferno] got buffer size 1024 samples * 64 channels, first channel: address 587585068040 with first 0b, step 2048b
period size: 256
boundary: 4611686018427387904
started transmitter
started receiver
[2025-04-07T21:20:33.105364Z WARN  inferno_aoip::device_server::channels_subscriber] Unable to load state (this is normal in first run): Os { code: 2, kind: NotFound, message: "No such file or directory" }
warning: setting start_time in plugin_pointer, not plugin_start
plugin_start called
plugin_start called
plugin_stop called
plugin_stop called
plugin_prepare called
[2025-04-07T21:20:41.104909Z DEBUG asound_module_pcm_inferno] got buffer size 1024 samples * 64 channels, first channel: address 5875850ad2a0 with first 0b, step 2048b
period size: 256
boundary: 4611686018427387904
ALSA: poll time out, polled for 7999215 usecs, Retrying with a recovery, retry cnt = 2
[2025-04-07T21:20:41.105081Z INFO  inferno_aoip::device_server] transmitter stopped
stopped transmitter
[2025-04-07T21:20:41.105267Z INFO  inferno_aoip::device_server] receiver stopped
stopped receiver
plugin_prepare called
[2025-04-07T21:20:41.105338Z DEBUG asound_module_pcm_inferno] got buffer size 1024 samples * 64 channels, first channel: address 587585068040 with first 0b, step 2048b
period size: 256
boundary: 4611686018427387904
started transmitter
started receiver
[2025-04-07T21:20:41.106846Z WARN  inferno_aoip::device_server::channels_subscriber] Unable to load state (this is normal in first run): Os { code: 2, kind: NotFound, message: "No such file or directory" }
warning: setting start_time in plugin_pointer, not plugin_start
plugin_start called
plugin_start called
plugin_stop called
plugin_stop called
plugin_prepare called
[2025-04-07T21:20:49.106183Z DEBUG asound_module_pcm_inferno] got buffer size 1024 samples * 64 channels, first channel: address 5875850ad2a0 with first 0b, step 2048b
period size: 256
boundary: 4611686018427387904
ALSA: poll time out, polled for 7999066 usecs, Retrying with a recovery, retry cnt = 3
[2025-04-07T21:20:49.106344Z INFO  inferno_aoip::device_server] transmitter stopped
stopped transmitter
[2025-04-07T21:20:49.106461Z INFO  inferno_aoip::device_server] receiver stopped
stopped receiver
plugin_prepare called
[2025-04-07T21:20:49.106535Z DEBUG asound_module_pcm_inferno] got buffer size 1024 samples * 64 channels, first channel: address 587585068040 with first 0b, step 2048b
period size: 256
boundary: 4611686018427387904
started transmitter
started receiver
[2025-04-07T21:20:49.107907Z WARN  inferno_aoip::device_server::channels_subscriber] Unable to load state (this is normal in first run): Os { code: 2, kind: NotFound, message: "No such file or directory" }
warning: setting start_time in plugin_pointer, not plugin_start
plugin_start called
plugin_start called
plugin_stop called
plugin_stop called
plugin_prepare called
[2025-04-07T21:20:57.107253Z DEBUG asound_module_pcm_inferno] got buffer size 1024 samples * 64 channels, first channel: address 5875850ad2a0 with first 0b, step 2048b
period size: 256
boundary: 4611686018427387904
ALSA: poll time out, polled for 7999043 usecs, Retrying with a recovery, retry cnt = 4
[2025-04-07T21:20:57.107444Z INFO  inferno_aoip::device_server] transmitter stopped
stopped transmitter
[2025-04-07T21:20:57.107515Z INFO  inferno_aoip::device_server] receiver stopped
stopped receiver
plugin_prepare called
[2025-04-07T21:20:57.107598Z DEBUG asound_module_pcm_inferno] got buffer size 1024 samples * 64 channels, first channel: address 587585068040 with first 0b, step 2048b
period size: 256
boundary: 4611686018427387904
started transmitter
started receiver
warning: setting start_time in plugin_pointer, not plugin_start
[2025-04-07T21:20:57.109075Z WARN  inferno_aoip::device_server::channels_subscriber] Unable to load state (this is normal in first run): Os { code: 2, kind: NotFound, message: "No such file or directory" }
plugin_start called
plugin_start called
ALSA: poll time out, polled for 7999102 usecs, Retrying with a recovery, retry cnt = 5
plugin_stop called
plugin_stop called
plugin_prepare called
[2025-04-07T21:21:05.108394Z DEBUG asound_module_pcm_inferno] got buffer size 1024 samples * 64 channels, first channel: address 5875850ad2a0 with first 0b, step 2048b
period size: 256
boundary: 4611686018427387904
[2025-04-07T21:21:05.108543Z INFO  inferno_aoip::device_server] transmitter stopped
stopped transmitter
[2025-04-07T21:21:05.108659Z INFO  inferno_aoip::device_server] receiver stopped
stopped receiver
plugin_prepare called
[2025-04-07T21:21:05.108723Z DEBUG asound_module_pcm_inferno] got buffer size 1024 samples * 64 channels, first channel: address 587585068040 with first 0b, step 2048b
period size: 256
boundary: 4611686018427387904
started transmitter
started receiver
warning: setting start_time in plugin_pointer, not plugin_start
[2025-04-07T21:21:05.110325Z WARN  inferno_aoip::device_server::channels_subscriber] Unable to load state (this is normal in first run): Os { code: 2, kind: NotFound, message: "No such file or directory" }
plugin_start called
plugin_start called
ALSA: poll time out, polled for 7999056 usecs, Reached max retry cnt = 5, Exiting
JackAudioDriver::ProcessSync: read error, stopping...

starting any JACK app - even just a state visualizer like qjackctl - hangs

[jcelerier]

if that can be a useful data point I'm able to for instance stream 64 channels of AES67 to compatible dante hardware through the same computer through aes67-linux-daemon and ptp4l with the following ptp4l invocation:

sudo /usr/bin/ptp4l -i eno0 -p /dev/ptp0  -l6 -E -H -s -m --step_threshold 0.00000001 -4 --priority1 255 --priority2 255 --domainNumber 0 --dscp_event 46

for reference:

$ ethtool -T eno0
Time stamping parameters for eno0:
Capabilities:
	hardware-transmit
	software-transmit
	hardware-receive
	software-receive
	software-system-clock
	hardware-raw-clock
PTP Hardware Clock: 0
Hardware Transmit Timestamp Modes:
	off
	on
Hardware Receive Filter Modes:
	none
	all
	ptpv1-l4-sync
	ptpv1-l4-delay-req
	ptpv2-l4-sync
	ptpv2-l4-delay-req
	ptpv2-l2-sync
	ptpv2-l2-delay-req
	ptpv2-event
	ptpv2-sync
	ptpv2-delay-req

[teodly]

What happens if you don't run Statime at all and instead use ptp4l and INFERNO_CLOCK_PATH=/dev/ptp0? At least one Dante device must have AES67 enabled then (to be PTPv2 master)

I have never tried Inferno with JACK, I will have to think about such tests but it requires some mechanism of containerization not to break the whole audio setup of my desktop system. It will be useful anyway for automated tests so it's on the roadmap.

If PipeWire is not an option for you, could you try running the script inferno2pipe/save_to_file? Or alsa_pcm_inferno/test_effect_processor.sh?