2024-03-22 16:37:40.802652 INFO [src/bin.rs:683] CamillaDSP version 2.0.3
2024-03-22 16:37:40.802673 INFO [src/bin.rs:684] Running on linux, aarch64
2024-03-22 16:37:40.802760 DEBUG [src/bin.rs:728] Loaded state: Some(State { config_path: Some("/home/tforsythe/camilladsp/configs/mchstreamer_96c_96p.yml"), mute: [false, false, false, false, false], volume: [0.0, 0.0, 0.0, 0.0, 0.0] })
2024-03-22 16:37:40.802777 DEBUG [src/bin.rs:735] Using statefile for initial volume
2024-03-22 16:37:40.802780 DEBUG [src/bin.rs:752] Using statefile for initial mute
2024-03-22 16:37:40.802783 DEBUG [src/bin.rs:765] Initial mute: [false, false, false, false, false]
2024-03-22 16:37:40.802786 DEBUG [src/bin.rs:766] Initial volume: [0.0, 0.0, 0.0, 0.0, 0.0]
2024-03-22 16:37:40.802789 DEBUG [src/bin.rs:768] Read config file None
2024-03-22 16:37:40.802792 DEBUG [src/bin.rs:800] No change to state from camilladsp/statefile.yml, not overwriting.
2024-03-22 16:37:40.803085 DEBUG [src/config.rs:1549] ../coeffs/LeftCH-96000.wav is relative
2024-03-22 16:37:40.803098 DEBUG [src/config.rs:1553] Using ../coeffs/LeftCH-96000.wav found relative to config file dir
2024-03-22 16:37:40.803103 DEBUG [src/config.rs:1549] ../coeffs/RightCH-96000.wav is relative
2024-03-22 16:37:40.803108 DEBUG [src/config.rs:1553] Using ../coeffs/RightCH-96000.wav found relative to config file dir
2024-03-22 16:37:40.809355 DEBUG [src/filters.rs:178] Read raw data from: '/home/tforsythe/camilladsp/configs/../coeffs/LeftCH-96000.wav', format: FLOAT32LE, number of coeffs: 262145
2024-03-22 16:37:40.810764 DEBUG [src/filters.rs:337] Read wav file '/home/tforsythe/camilladsp/configs/../coeffs/LeftCH-96000.wav', format: FLOAT32LE, channel: 0 of 1, samplerate: 96000, length: 262145
2024-03-22 16:37:40.817058 DEBUG [src/filters.rs:178] Read raw data from: '/home/tforsythe/camilladsp/configs/../coeffs/RightCH-96000.wav', format: FLOAT32LE, number of coeffs: 262145
2024-03-22 16:37:40.818617 DEBUG [src/filters.rs:337] Read wav file '/home/tforsythe/camilladsp/configs/../coeffs/RightCH-96000.wav', format: FLOAT32LE, channel: 0 of 1, samplerate: 96000, length: 262145
2024-03-22 16:37:40.818639 DEBUG [src/bin.rs:808] Config is valid
2024-03-22 16:37:40.818801 DEBUG [src/socketserver.rs:432] Start websocket server on 127.0.0.1:1234
2024-03-22 16:37:40.818978 DEBUG [src/bin.rs:994] Wait for config
2024-03-22 16:37:40.818992 DEBUG [src/bin.rs:1010] Waiting to receive a command
2024-03-22 16:37:40.818998 DEBUG [src/bin.rs:1013] Config change command received
2024-03-22 16:37:40.819006 DEBUG [src/bin.rs:999] New config is available and there are no queued commands, continuing
2024-03-22 16:37:40.819010 DEBUG [src/bin.rs:1036] Config ready, start processing
2024-03-22 16:37:40.819178 DEBUG [src/bin.rs:157] Using channels [true, true]
2024-03-22 16:37:40.819184 DEBUG [src/filters.rs:488] Build new pipeline
2024-03-22 16:37:40.819306 DEBUG [src/filters.rs:364] Build filter group from config
2024-03-22 16:37:40.819305 DEBUG [src/audiodevice.rs:465] Creating asynchronous resampler with parameters: SincInterpolationParameters { sinc_len: 256, f_cutoff: 0.9470547, oversampling_factor: 256, interpolation: Cubic, window: BlackmanHarris2 }
2024-03-22 16:37:40.825656 DEBUG [src/filters.rs:178] Read raw data from: '/home/tforsythe/camilladsp/configs/../coeffs/LeftCH-96000.wav', format: FLOAT32LE, number of coeffs: 262145
2024-03-22 16:37:40.827541 DEBUG [src/filters.rs:337] Read wav file '/home/tforsythe/camilladsp/configs/../coeffs/LeftCH-96000.wav', format: FLOAT32LE, channel: 0 of 1, samplerate: 96000, length: 262145
2024-03-22 16:37:40.837181 DEBUG [src/fftconv.rs:50] Conv Left Channel Correction is using 129 segments
2024-03-22 16:37:40.846586 DEBUG [src/alsadevice.rs:334] Available Playback devices: [("hw:TosLink,0,0", "MCHStreamer TosLink, USB Audio, subdevice #0"), ("hw:vc4hdmi0,0,0", "vc4-hdmi-0, MAI PCM i2s-hifi-0, subdevice #0"), ("hw:vc4hdmi1,0,0", "vc4-hdmi-1, MAI PCM i2s-hifi-0, subdevice #0"), ("null", "Discard all samples (playback) or generate zero samples (capture)"), ("default", "Default Audio Device"), ("sysdefault", "Default Audio Device"), ("hw:CARD=TosLink,DEV=0", "MCHStreamer TosLink, USB Audio\nDirect hardware device without any conversions"), ("plughw:CARD=TosLink,DEV=0", "MCHStreamer TosLink, USB Audio\nHardware device with all software conversions"), ("default:CARD=TosLink", "MCHStreamer TosLink, USB Audio\nDefault Audio Device"), ("sysdefault:CARD=TosLink", "MCHStreamer TosLink, USB Audio\nDefault Audio Device"), ("front:CARD=TosLink,DEV=0", "MCHStreamer TosLink, USB Audio\nFront output / input"), ("surround21:CARD=TosLink,DEV=0", "MCHStreamer TosLink, USB Audio\n2.1 Surround output to Front and Subwoofer speakers"), ("surround40:CARD=TosLink,DEV=0", "MCHStreamer TosLink, USB Audio\n4.0 Surround output to Front and Rear speakers"), ("surround41:CARD=TosLink,DEV=0", "MCHStreamer TosLink, USB Audio\n4.1 Surround output to Front, Rear and Subwoofer speakers"), ("surround50:CARD=TosLink,DEV=0", "MCHStreamer TosLink, USB Audio\n5.0 Surround output to Front, Center and Rear speakers"), ("surround51:CARD=TosLink,DEV=0", "MCHStreamer TosLink, USB Audio\n5.1 Surround output to Front, Center, Rear and Subwoofer speakers"), ("surround71:CARD=TosLink,DEV=0", "MCHStreamer TosLink, USB Audio\n7.1 Surround output to Front, Center, Side, Rear and Woofer speakers"), ("iec958:CARD=TosLink,DEV=0", "MCHStreamer TosLink, USB Audio\nIEC958 (S/PDIF) Digital Audio Output"), ("dmix:CARD=TosLink,DEV=0", "MCHStreamer TosLink, USB Audio\nDirect sample mixing device"), ("hw:CARD=vc4hdmi0,DEV=0", "vc4-hdmi-0, MAI PCM i2s-hifi-0\nDirect hardware device without any conversions"), ("plughw:CARD=vc4hdmi0,DEV=0", "vc4-hdmi-0, MAI PCM i2s-hifi-0\nHardware device with all software conversions"), ("default:CARD=vc4hdmi0", "vc4-hdmi-0, MAI PCM i2s-hifi-0\nDefault Audio Device"), ("sysdefault:CARD=vc4hdmi0", "vc4-hdmi-0, MAI PCM i2s-hifi-0\nDefault Audio Device"), ("hdmi:CARD=vc4hdmi0,DEV=0", "vc4-hdmi-0, MAI PCM i2s-hifi-0\nHDMI Audio Output"), ("dmix:CARD=vc4hdmi0,DEV=0", "vc4-hdmi-0, MAI PCM i2s-hifi-0\nDirect sample mixing device"), ("hw:CARD=vc4hdmi1,DEV=0", "vc4-hdmi-1, MAI PCM i2s-hifi-0\nDirect hardware device without any conversions"), ("plughw:CARD=vc4hdmi1,DEV=0", "vc4-hdmi-1, MAI PCM i2s-hifi-0\nHardware device with all software conversions"), ("default:CARD=vc4hdmi1", "vc4-hdmi-1, MAI PCM i2s-hifi-0\nDefault Audio Device"), ("sysdefault:CARD=vc4hdmi1", "vc4-hdmi-1, MAI PCM i2s-hifi-0\nDefault Audio Device"), ("hdmi:CARD=vc4hdmi1,DEV=0", "vc4-hdmi-1, MAI PCM i2s-hifi-0\nHDMI Audio Output"), ("dmix:CARD=vc4hdmi1,DEV=0", "vc4-hdmi-1, MAI PCM i2s-hifi-0\nDirect sample mixing device")]
2024-03-22 16:37:40.847172 DEBUG [src/filters.rs:364] Build filter group from config
2024-03-22 16:37:40.847319 DEBUG [src/alsadevice.rs:352] Playback: supported channels, min: 2, max: 2, list: [2]
2024-03-22 16:37:40.847329 DEBUG [src/alsadevice.rs:353] Playback: setting channels to 2
2024-03-22 16:37:40.847364 DEBUG [src/alsadevice.rs:357] Playback: supported samplerates: Discrete([44100, 48000, 88200, 96000, 176400, 192000])
2024-03-22 16:37:40.847371 DEBUG [src/alsadevice.rs:358] Playback: setting rate to 96000
2024-03-22 16:37:40.847380 DEBUG [src/alsadevice.rs:362] Playback: supported sample formats: [S16LE, S32LE]
2024-03-22 16:37:40.847384 DEBUG [src/alsadevice.rs:363] Playback: setting format to S32LE
2024-03-22 16:37:40.847410 DEBUG [src/alsadevice_buffermanager.rs:57] Setting buffer size to 8192 frames
2024-03-22 16:37:40.847425 DEBUG [src/alsadevice_buffermanager.rs:70] Device is using a buffer size of 8192 frames
2024-03-22 16:37:40.847431 DEBUG [src/alsadevice_buffermanager.rs:78] Setting period size to 1024 frames
2024-03-22 16:37:40.852222 DEBUG [src/alsadevice.rs:334] Available Capture devices: [("hw:TosLink,0,0", "MCHStreamer TosLink, USB Audio, subdevice #0"), ("null", "Discard all samples (playback) or generate zero samples (capture)"), ("default", "Default Audio Device"), ("sysdefault", "Default Audio Device"), ("hw:CARD=TosLink,DEV=0", "MCHStreamer TosLink, USB Audio\nDirect hardware device without any conversions"), ("plughw:CARD=TosLink,DEV=0", "MCHStreamer TosLink, USB Audio\nHardware device with all software conversions"), ("default:CARD=TosLink", "MCHStreamer TosLink, USB Audio\nDefault Audio Device"), ("sysdefault:CARD=TosLink", "MCHStreamer TosLink, USB Audio\nDefault Audio Device"), ("front:CARD=TosLink,DEV=0", "MCHStreamer TosLink, USB Audio\nFront output / input"), ("dsnoop:CARD=TosLink,DEV=0", "MCHStreamer TosLink, USB Audio\nDirect sample snooping device")]
2024-03-22 16:37:40.853244 DEBUG [src/filters.rs:178] Read raw data from: '/home/tforsythe/camilladsp/configs/../coeffs/RightCH-96000.wav', format: FLOAT32LE, number of coeffs: 262145
2024-03-22 16:37:40.853804 DEBUG [src/filters.rs:337] Read wav file '/home/tforsythe/camilladsp/configs/../coeffs/RightCH-96000.wav', format: FLOAT32LE, channel: 0 of 1, samplerate: 96000, length: 262145
2024-03-22 16:37:40.862007 DEBUG [src/fftconv.rs:50] Conv Right Channel Correction is using 129 segments
2024-03-22 16:37:40.868992 DEBUG [src/alsadevice.rs:387] Opening Playback device "hw:TosLink" with parameters: HwParams { channels: Ok(2), rate: "Ok(96000) Hz", format: Ok(S32LE), access: Ok(RWInterleaved), period_size: "Ok(1024) frames", buffer_size: "Ok(8192) frames" }, SwParams(avail_min: Ok(2048) frames, start_threshold: Ok(1) frames, stop_threshold: Ok(8192) frames)
2024-03-22 16:37:40.869042 DEBUG [src/alsadevice.rs:392] Playback device "hw:TosLink" successfully opened
2024-03-22 16:37:40.869101 DEBUG [src/bin.rs:265] Playback thread ready to start
2024-03-22 16:37:40.869478 DEBUG [src/alsadevice.rs:387] Opening Capture device "hw:TosLink" with parameters: HwParams { channels: Ok(2), rate: "Ok(96000) Hz", format: Ok(S32LE), access: Ok(RWInterleaved), period_size: "Ok(1024) frames", buffer_size: "Ok(8192) frames" }, SwParams(avail_min: Ok(2048) frames, start_threshold: Ok(0) frames, stop_threshold: Ok(8192) frames)
2024-03-22 16:37:40.869497 DEBUG [src/alsadevice.rs:392] Capture device "hw:TosLink" successfully opened
2024-03-22 16:37:40.869511 DEBUG [src/bin.rs:275] Capture thread ready to start
2024-03-22 16:37:40.869519 DEBUG [src/bin.rs:278] Both capture and playback ready, release barrier
2024-03-22 16:37:40.871440 DEBUG [src/processing.rs:19] build filters, waiting to start processing loop
2024-03-22 16:37:40.871453 DEBUG [src/processing.rs:21] Processing loop starts now!
2024-03-22 16:37:40.871458 DEBUG [src/bin.rs:280] Supervisor loop starts now!
2024-03-22 16:37:40.871459 DEBUG [src/alsadevice.rs:1037] Starting captureloop
2024-03-22 16:37:40.871478 DEBUG [src/alsadevice.rs:951] Starting playback loop
2024-03-22 16:37:40.871485 DEBUG [src/alsadevice.rs:415] Playback loop uses a buffer of 2048 frames
2024-03-22 16:37:40.871640 DEBUG [src/alsadevice.rs:657] Capture loop uses a buffer of 8192 frames
2024-03-22 16:37:40.871671 DEBUG [src/alsadevice.rs:253] Starting capture from state: SND_PCM_STATE_PREPARED, Ready to start
2024-03-22 16:37:40.907238 INFO [src/alsadevice.rs:142] PB: Starting playback from Prepared state
2024-03-22 16:37:41.140921 DEBUG [/home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tungstenite-0.21.0/src/handshake/server.rs:285] Server handshake done.
2024-03-22 16:37:41.141382 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetVersion)
2024-03-22 16:37:43.036896 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetSignalLevelsSince(0.124))
2024-03-22 16:37:43.046941 DEBUG [/home/runner/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tungstenite-0.21.0/src/handshake/server.rs:285] Server handshake done.
2024-03-22 16:37:47.332295 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetVolume)
2024-03-22 16:37:47.333179 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetMute)
2024-03-22 16:37:47.348131 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetState)
2024-03-22 16:37:47.348356 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetSignalLevelsSince(0.12))
2024-03-22 16:37:47.469221 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetState)
2024-03-22 16:37:47.469466 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetSignalLevelsSince(0.12))
2024-03-22 16:37:47.626657 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetState)
2024-03-22 16:37:47.627172 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetSignalLevelsSince(0.157))
2024-03-22 16:37:47.627528 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetCaptureRate)
2024-03-22 16:37:47.627716 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetRateAdjust)
2024-03-22 16:37:47.627988 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetBufferLevel)
2024-03-22 16:37:47.628132 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetClippedSamples)
2024-03-22 16:37:47.628268 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetProcessingLoad)
2024-03-22 16:37:50.738497 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetRateAdjust)
2024-03-22 16:37:50.738632 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetBufferLevel)
2024-03-22 16:37:50.738760 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetClippedSamples)
2024-03-22 16:37:50.738893 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetProcessingLoad)
2024-03-22 16:37:50.875271 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetState)
2024-03-22 16:37:50.875513 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetSignalLevelsSince(0.137))
2024-03-22 16:37:50.892136 DEBUG [src/alsadevice.rs:573] PB: buffer level: 2204.2, signal rms: Some(HistoryRecord { time: Instant { tv_sec: 23192, tv_nsec: 580353512 }, values: [4.9585313e-5, 8.4343956e-5] })
2024-03-22 16:37:51.033047 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetState)
2024-03-22 16:37:51.033293 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetSignalLevelsSince(0.158))
2024-03-22 16:38:00.892611 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetSignalLevelsSince(0.12))
2024-03-22 16:38:00.897474 DEBUG [src/alsadevice_utils.rs:251] Avg. buffer delay: 2157.8, target delay: 2048, diff: 109.825159914712, prev_div: 156.19444444444434, corrected capture rate: 100.0000%
2024-03-22 16:38:00.897508 DEBUG [src/alsadevice.rs:573] PB: buffer level: 2157.8, signal rms: Some(HistoryRecord { time: Instant { tv_sec: 23202, tv_nsec: 585691634 }, values: [8.435464e-5, 0.00013597931] })
2024-03-22 16:38:00.897520 DEBUG [src/bin.rs:386] SetSpeed message received
2024-03-22 16:38:01.012470 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetState)
2024-03-22 16:38:05.047424 DEBUG [src/bin.rs:835] Received signal: 15
2024-03-22 16:38:05.047506 INFO [src/bin.rs:868] Shutting down
2024-03-22 16:38:05.047599 DEBUG [src/bin.rs:244] Exit requested...
2024-03-22 16:38:05.055533 DEBUG [src/alsadevice.rs:688] Exit message received, sending EndOfStream
2024-03-22 16:38:05.068675 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetState)
2024-03-22 16:38:05.068922 DEBUG [src/socketserver.rs:522] parsed command: Ok(GetSignalLevelsSince(0.136))
2024-03-22 16:38:05.093792 DEBUG [src/bin.rs:1038] Processing ended with status Ok(Exit)
2024-03-22 16:38:05.093805 DEBUG [src/bin.rs:1048] Exiting