log

Signed-off-by: 21pages <pages21@163.com>

src/client.rs

@@ -53,7 +53,7 @@ use scrap::{
     ImageFormat,
 };
 
-use crate::common::{self, is_keyboard_mode_supported};
+use crate::common::{self, flog, is_keyboard_mode_supported};
 
 #[cfg(not(any(target_os = "android", target_os = "ios")))]
 use crate::common::{check_clipboard, ClipboardContext, CLIPBOARD_INTERVAL};
@@ -827,6 +827,10 @@ impl AudioHandler {
         log::info!("Remote input format: {:?}", format0);
         let mut config: StreamConfig = config.into();
         config.channels = format0.channels as _;
+        flog(
+            "start_audio ",
+            &format!("device:{:?}, config:{:?}", device.name(), config),
+        );
         match sample_format {
             cpal::SampleFormat::I8 => self.build_output_stream::<i8>(&config, &device)?,
             cpal::SampleFormat::I16 => self.build_output_stream::<i16>(&config, &device)?,
@@ -862,8 +866,10 @@ impl AudioHandler {
     /// Handle audio frame and play it.
     #[inline]
     pub fn handle_frame(&mut self, frame: AudioFrame) {
+        flog("handle_frame recv auido frame ", &format!(""));
         #[cfg(not(any(target_os = "android", target_os = "linux")))]
         if self.audio_stream.is_none() || !self.ready.lock().unwrap().clone() {
+            flog("handle_frame not ready ", &format!(""));
             return;
         }
         #[cfg(target_os = "linux")]
@@ -876,38 +882,50 @@ impl AudioHandler {
             return;
         }
         self.audio_decoder.as_mut().map(|(d, buffer)| {
-            if let Ok(n) = d.decode_float(&frame.data, buffer, false) {
-                let channels = self.channels;
-                let n = n * (channels as usize);
-                #[cfg(not(any(target_os = "android", target_os = "linux")))]
-                {
-                    let sample_rate0 = self.sample_rate.0;
-                    let sample_rate = self.sample_rate.1;
-                    let audio_buffer = self.audio_buffer.0.clone();
-                    if sample_rate != sample_rate0 {
-                        let buffer = crate::resample_channels(
-                            &buffer[0..n],
-                            sample_rate0,
-                            sample_rate,
-                            channels,
-                        );
-                        audio_buffer.lock().unwrap().push_slice_overwrite(&buffer);
-                    } else {
-                        audio_buffer
-                            .lock()
-                            .unwrap()
-                            .push_slice_overwrite(&buffer[0..n]);
+            match d.decode_float(&frame.data, buffer, false) {
+                Ok(n) => {
+                    flog(
+                        "handle_frame decode_float success data size ",
+                        &format!("{}", n),
+                    );
+                    let channels = self.channels;
+                    let n = n * (channels as usize);
+                    #[cfg(not(any(target_os = "android", target_os = "linux")))]
+                    {
+                        let sample_rate0 = self.sample_rate.0;
+                        let sample_rate = self.sample_rate.1;
+                        let audio_buffer = self.audio_buffer.0.clone();
+                        if sample_rate != sample_rate0 {
+                            flog("handle_frame resample_channels ", &format!(""));
+
+                            let buffer = crate::resample_channels(
+                                &buffer[0..n],
+                                sample_rate0,
+                                sample_rate,
+                                channels,
+                            );
+                            audio_buffer.lock().unwrap().push_slice_overwrite(&buffer);
+                        } else {
+                            audio_buffer
+                                .lock()
+                                .unwrap()
+                                .push_slice_overwrite(&buffer[0..n]);
+                        }
+                    }
+                    #[cfg(target_os = "android")]
+                    {
+                        self.oboe.as_mut().map(|x| x.push(&buffer[0..n]));
+                    }
+                    #[cfg(target_os = "linux")]
+                    {
+                        let data_u8 = unsafe {
+                            std::slice::from_raw_parts::<u8>(buffer.as_ptr() as _, n * 4)
+                        };
+                        self.simple.as_mut().map(|x| x.write(data_u8));
                     }
                 }
-                #[cfg(target_os = "android")]
-                {
-                    self.oboe.as_mut().map(|x| x.push(&buffer[0..n]));
-                }
-                #[cfg(target_os = "linux")]
-                {
-                    let data_u8 =
-                        unsafe { std::slice::from_raw_parts::<u8>(buffer.as_ptr() as _, n * 4) };
-                    self.simple.as_mut().map(|x| x.write(data_u8));
+                Err(e) => {
+                    flog("handle_frame decode_float failed ", &format!("{}", e));
                 }
             }
         });
@@ -923,6 +941,10 @@ impl AudioHandler {
         let err_fn = move |err| {
             // too many errors, will improve later
             log::trace!("an error occurred on stream: {}", err);
+            flog(
+                "build_output_stream err callback ",
+                &format!("err:{:?}", err),
+            );
         };
         let audio_buffer = self.audio_buffer.0.clone();
         let ready = self.ready.clone();
@@ -938,6 +960,10 @@ impl AudioHandler {
                 if lock.occupied_len() < n {
                     n = lock.occupied_len();
                 }
+                flog(
+                    "build_output_stream data callback ",
+                    &format!("data len:{:?}, n:{}", data.len(), n),
+                );
                 let mut elems = vec![0.0f32; n];
                 lock.pop_slice(&mut elems);
                 drop(lock);
@@ -953,6 +979,7 @@ impl AudioHandler {
             timeout,
         )?;
         stream.play()?;
+        flog("build_output_stream play ok", "");
         self.audio_stream = Some(Box::new(stream));
         Ok(())
     }

src/common.rs

@@ -1,6 +1,7 @@
 use std::{
     future::Future,
     sync::{Arc, Mutex},
+    time::Instant,
 };
 
 #[derive(Debug, Eq, PartialEq)]
@@ -279,6 +280,13 @@ pub fn resample_channels(
     sample_rate: u32,
     channels: u16,
 ) -> Vec<f32> {
+    flog(
+        "resample_channels",
+        &format!(
+            "sample_rate0 : {:?}, sample_rate:{:?}, channels:{:?}",
+            sample_rate0, sample_rate, channels
+        ),
+    );
     use dasp::{interpolate::linear::Linear, signal, Signal};
     let n = data.len() / (channels as usize);
     let n = n * sample_rate as usize / sample_rate0 as usize;
@@ -854,3 +862,27 @@ pub fn pk_to_fingerprint(pk: Vec<u8>) -> String {
         })
         .collect()
 }
+
+lazy_static::lazy_static! {
+    static ref INSTANTS: Arc::<Mutex<std::collections::HashMap<String,Instant>>> = Default::default();
+}
+
+pub fn flog(tag: &str, s: &str) {
+    use hbb_common::chrono::prelude::*;
+    use std::io::Write;
+    let mut lock = INSTANTS.lock().unwrap();
+    let log = if lock.contains_key(tag) {
+        lock.get(tag)
+            .map(|i| i.elapsed() > std::time::Duration::from_secs(1))
+            .unwrap_or(false)
+    } else {
+        true
+    };
+    if log {
+        let mut option = std::fs::OpenOptions::new();
+        if let Ok(mut f) = option.append(true).create(true).open("D:/log.txt") {
+            write!(&mut f, "{:?} {} {}\n", Local::now(), tag, s).ok();
+        }
+        lock.insert(tag.to_string(), Instant::now());
+    }
+}

src/server/audio_service.rs

@@ -12,6 +12,8 @@
 // https://wiki.debian.org/audio-loopback
 // https://github.com/krruzic/pulsectl
 
+use crate::common::flog;
+
 use super::*;
 use magnum_opus::{Application::*, Channels::*, Encoder};
 use std::sync::atomic::{AtomicBool, Ordering};
@@ -101,6 +103,8 @@ mod pa_impl {
 
 #[cfg(not(any(target_os = "linux", target_os = "android")))]
 mod cpal_impl {
+    use crate::common::flog;
+
     use super::*;
     use cpal::{
         traits::{DeviceTrait, HostTrait, StreamTrait},
@@ -230,6 +234,13 @@ mod cpal_impl {
         } else {
             48000
         };
+        flog(
+            "audio_service play",
+            &format!(
+                "sample_rate_0:{}, sample_rate:{}",
+                sample_rate_0, sample_rate
+            ),
+        );
         let stream = match config.sample_format() {
             I8 => build_input_stream::<i8>(device, &config, sp, sample_rate)?,
             I16 => build_input_stream::<i16>(device, &config, sp, sample_rate)?,
@@ -244,6 +255,10 @@ mod cpal_impl {
             f => bail!("unsupported audio format: {:?}", f),
         };
         stream.play()?;
+        flog(
+            "audio_service play ok",
+            &format!("sample_format: {:?}", config.sample_format()),
+        );
         Ok((
             Box::new(stream),
             Arc::new(create_format_msg(sample_rate, config.channels())),
@@ -259,9 +274,22 @@ mod cpal_impl {
     where
         T: cpal::SizedSample + dasp::sample::ToSample<f32>,
     {
+        flog(
+            "build_input_stream start",
+            &format!(
+                "config: {:?}, sample_rate:{}, channels:{}",
+                config,
+                sample_rate,
+                config.channels()
+            ),
+        );
         let err_fn = move |err| {
             // too many UnknownErrno, will improve later
             log::trace!("an error occurred on stream: {}", err);
+            flog(
+                "build_input_stream err callback",
+                &format!("err: {:?}", err),
+            );
         };
         let sample_rate_0 = config.sample_rate().0;
         log::debug!("Audio sample rate : {}", sample_rate);
@@ -290,6 +318,15 @@ mod cpal_impl {
                 let buffer: Vec<f32> = data.iter().map(|s| T::to_sample(*s)).collect();
                 let mut lock = INPUT_BUFFER.lock().unwrap();
                 lock.extend(buffer);
+                flog(
+                    "build_input_stream data callback",
+                    &format!(
+                        "data len: {:?}, lock len:{}, encode_len:{}",
+                        data.len(),
+                        lock.len(),
+                        encode_len
+                    ),
+                );
                 while lock.len() >= encode_len {
                     let frame: Vec<f32> = lock.drain(0..encode_len).collect();
                     send(
@@ -345,6 +382,12 @@ fn send_f32(data: &[f32], encoder: &mut Encoder, sp: &GenericService) {
             AUDIO_ZERO_COUNT += 1;
         }
     }
+    unsafe {
+        flog(
+            "send_f32 AUDIO_ZERO_COUNT",
+            &format!("{:?}", AUDIO_ZERO_COUNT),
+        );
+    }
     #[cfg(target_os = "android")]
     {
         // the permitted opus data size are 120, 240, 480, 960, 1920, and 2880
@@ -378,13 +421,19 @@ fn send_f32(data: &[f32], encoder: &mut Encoder, sp: &GenericService) {
     #[cfg(not(target_os = "android"))]
     match encoder.encode_vec_float(data, data.len() * 6) {
         Ok(data) => {
+            flog(
+                "send_f32 encode_vec_float success",
+                &format!(" data len {:?}", data.len()),
+            );
             let mut msg_out = Message::new();
             msg_out.set_audio_frame(AudioFrame {
                 data: data.into(),
                 ..Default::default()
             });
             sp.send(msg_out);
         }
-        Err(_) => {}
+        Err(e) => {
+            flog("send_f32 encode_vec_float err", &format!("{:?}", e));
+        }
     }
 }