fix playlist data errors & logging & tests

logger.yaml

@@ -0,0 +1,27 @@
+refresh_rate: 30 seconds
+
+appenders:
+  stdout:
+    kind: console
+
+  requests:
+    kind: file
+    path: "/tmp/twba/logs/downloader.log"
+    encoder:
+      pattern: "[{d:35}] [{h({l:5})}] {M}::{file}:{L} - {m}{n}"
+    rolling:
+      kind: size
+      trigger:
+        max_size: 100mb
+      policy:
+        kind: compound
+        trigger:
+          kind: fixed_window
+          pattern: "/tmp/twba/logs/archive/downloader.{}.log"
+          count: 5
+
+root:
+  level: debug
+  appenders:
+    - stdout
+    - file

src/lib.rs

@@ -330,8 +330,8 @@ pub async fn split_video_into_parts(
 
     //region run ffmpeg split command
     //example: ffmpeg -i input.mp4 -c copy -map 0 -segment_time 00:20:00 -f segment output%03d.mp4
-    trace!(
+    debug!(
-        "Running ffmpeg command: ffmpeg -i {:?} -c copy -map 0 -segment_time {} -reset_timestamps 1\
+        "Running ffmpeg command: ffmpeg -i {:?} -c copy -map 0 -segment_time {} -reset_timestamps 1 \
          -segment_list {} -segment_list_type m3u8 -avoid_negative_ts 1 -f segment {}",
         filepath,
         duration_str,
@@ -362,65 +362,40 @@ pub async fn split_video_into_parts(
         ])
         .output()
         .await?;
-    trace!("Finished running ffmpeg command");
+    debug!("Finished running ffmpeg command");
     //endregion
 
     //region extract parts from playlist file (create by ffmpeg 'output.m3u8')
-    let mut res = vec![];
+    let (mut paths, second_last_time, last_time, second_last_path, last_path) =
-    info!("Reading playlist file: {}", file_playlist.display());
+        extract_track_info_from_playlist_file(&parent_dir, &file_playlist).await?;
-    let playlist = tokio::fs::read_to_string(&file_playlist).await;
-    if playlist.is_err() {
-        warn!("Failed to read playlist file: {}", file_playlist.display());
-    }
-    let playlist =
-        playlist.expect(format!("Failed to read playlist {}", file_playlist.display()).as_str());
-    let mut last_time = 0.0;
-    let mut time = 0.0;
-    let mut last_path: Option<PathBuf> = None;
-    let mut current_path: Option<PathBuf> = None;
-    for line in playlist.lines() {
-        if line.starts_with("#") {
-            if line.starts_with("#EXTINF:") {
-                last_time = time;
-                time = line["#EXTINF:".len()..].parse::<f64>().unwrap_or(0.0);
-            }
-            continue;
-        }
-        last_path = current_path;
-        current_path = Some(Path::join(&parent_dir, line));
-        res.push(current_path.clone().unwrap());
-    }
     //endregion
 
     //region maybe join last two parts
     debug!("Deciding if last two parts should be joined");
-    if let Some(last_path) = last_path {
+    if let Some(second_last_path) = second_last_path {
-        if let Some(current_path) = current_path {
+        if let Some(last_path) = last_path {
-            let joined_time = last_time + time;
+            let joined_time = second_last_time + last_time;
-            if joined_time < duration_soft_cap.num_seconds() as f64 {
+            let general_info = format!("second last part duration: {} seconds, \
+                    last part duration: {} seconds, joined duration: {} seconds (hard cap: {} seconds)",
+                    second_last_time, last_time, joined_time, duration_hard_cap.num_seconds());
+            if joined_time < duration_hard_cap.num_seconds() as f64 {
                 //region join last two parts
-                info!(
+                info!("Joining last two parts. {}", general_info);
-                    "Joining last two parts. second last part duration: {} seconds, \
-                    last part duration: {} seconds, joined duration: {} seconds",
-                    last_time, time, joined_time
-                );
 
                 //remove the part from the result that is going to be joined
-                res.pop();
+                paths.pop();
 
                 let join_txt_path = Path::join(&parent_dir, "join.txt");
                 let join_mp4_path = Path::join(&parent_dir, "join.mp4");
+                let second_last_path = clean(&second_last_path);
+                let second_last_path_str = second_last_path
+                    .to_str()
+                    .expect("to_str on path did not work!");
+                let last_path = clean(&last_path);
+                let last_path = last_path.to_str().expect("to_str on path did not work!");
                 tokio::fs::write(
                     join_txt_path.clone(),
-                    format!(
+                    format!("file '{}'\nfile '{}'", last_path, second_last_path_str,),
-                        "file '{}'\nfile '{}'",
-                        clean(&last_path)
-                            .to_str()
-                            .expect("to_str on path did not work!"),
-                        clean(&current_path)
-                            .to_str()
-                            .expect("to_str on path did not work!")
-                    ),
                 )
                 .await?;
 
@@ -431,10 +406,9 @@ pub async fn split_video_into_parts(
                 let join_txt_path = clean(join_txt_path);
                 let join_mp4_path = clean(join_mp4_path);
 
-                trace!(
+                debug!(
                     "Running ffmpeg command: ffmpeg -f concat -safe 0 -i {:?} -c copy {:?}",
-                    join_txt_path,
+                    join_txt_path, join_mp4_path
-                    join_mp4_path
                 );
                 Command::new("ffmpeg")
                     .args([
@@ -454,34 +428,100 @@ pub async fn split_video_into_parts(
                     ])
                     .output()
                     .await?;
-                trace!("Finished running ffmpeg command");
+                debug!("Finished running ffmpeg command");
                 //region remove files
-                trace!(
+                debug!(
                     "Removing files: {:?}, {:?}, {:?} {:?}",
-                    current_path,
+                    second_last_path, last_path, join_txt_path, file_playlist,
-                    last_path,
-                    join_txt_path,
-                    file_playlist,
                 );
-                tokio::fs::remove_file(current_path).await?;
+                tokio::fs::remove_file(&second_last_path).await?;
                 tokio::fs::remove_file(&last_path).await?;
                 tokio::fs::remove_file(join_txt_path).await?;
                 tokio::fs::remove_file(file_playlist).await?;
                 //endregion
-                trace!("Renaming file: {:?} to {:?}", join_mp4_path, last_path);
+                debug!(
-                tokio::fs::rename(join_mp4_path, last_path).await?;
+                    "Renaming file: {:?} to {:?}",
+                    join_mp4_path, second_last_path
+                );
+                tokio::fs::rename(join_mp4_path, second_last_path).await?;
                 info!("Joined last two parts");
                 //endregion
+            } else {
+                info!("Not joining last two parts: {}", general_info);
             }
+        } else {
+            warn!("second_last_path was Some but last_path was None. This should not happen!");
         }
+    } else {
+        warn!("second_last_path was None. This should only happen if the total length is shorter than the hard cap!");
     }
     //endregion
 
     info!("removing the original file");
     tokio::fs::remove_file(&path).await?;
 
-    info!("Split video into {} parts", res.len());
+    info!("Split video into {} parts", paths.len());
-    Ok(res)
+    Ok(paths)
+}
+
+pub fn extract_track_info_from_playlist(playlist: String) -> Result<(f64, Vec<(String, f64)>)> {
+    let mut res = vec![];
+    let mut total_time: f64 = -1.0;
+
+    let mut last_time = None;
+    for line in playlist.lines() {
+        if line.starts_with("#EXTINF:") {
+            let time_str = line.replace("#EXTINF:", "");
+            let time_str = time_str.trim();
+            let time_str = time_str.strip_suffix(",").unwrap_or(time_str);
+            last_time = Some(time_str.parse::<f64>()?);
+        } else if line.starts_with("#EXT-X-ENDLIST") {
+            break;
+        } else if line.starts_with("#EXT-X-TARGETDURATION:") {
+            let time_str = line.replace("#EXT-X-TARGETDURATION:", "");
+            total_time = time_str.parse::<f64>()?;
+        } else if let Some(time) = last_time {
+            let path = line.trim().to_string();
+            res.push((path, time));
+            last_time = None;
+        }
+    }
+
+    Ok((total_time, res))
+}
+
+///
+pub async fn extract_track_info_from_playlist_file(
+    parent_dir: &PathBuf,
+    file_playlist: &PathBuf,
+) -> Result<(Vec<PathBuf>, f64, f64, Option<PathBuf>, Option<PathBuf>)> {
+    let mut res = vec![];
+    info!("Reading playlist file: {}", file_playlist.display());
+    let playlist = tokio::fs::read_to_string(&file_playlist).await;
+    if playlist.is_err() {
+        warn!("Failed to read playlist file: {}", file_playlist.display());
+    }
+    let playlist = playlist?;
+    let mut last_time = 0.0;
+    let mut time = 0.0;
+    let mut last_path: Option<PathBuf> = None;
+    let mut current_path: Option<PathBuf> = None;
+
+    let (_total, parts) = extract_track_info_from_playlist(playlist)?;
+
+    for (path, part_time) in &parts {
+        last_time = time;
+        time = *part_time;
+        last_path = current_path;
+        current_path = Some(Path::join(parent_dir, path));
+    }
+
+    res = parts
+        .iter()
+        .map(|(path, _)| Path::join(parent_dir, path))
+        .collect::<Vec<PathBuf>>();
+
+    Ok((res, last_time, time, last_path, current_path))
 }
 
 //region get title stuff
@@ -611,3 +651,85 @@ fn duration_to_string(duration: &Duration) -> String {
     let seconds = seconds % 60;
     format!("{:02}:{:02}:{:02}", hours, minutes, seconds)
 }
+
+//region tests
+#[cfg(test)]
+mod tests {
+    use std::fs::File;
+
+    use tokio::io::AsyncReadExt;
+
+    use super::*;
+
+    #[test]
+    fn test_duration_to_string() {
+        let duration = Duration::seconds(0);
+        let res = duration_to_string(&duration);
+        assert_eq!(res, "00:00:00");
+
+        let duration = Duration::seconds(1);
+        let res = duration_to_string(&duration);
+        assert_eq!(res, "00:00:01");
+
+        let duration = Duration::seconds(60);
+        let res = duration_to_string(&duration);
+        assert_eq!(res, "00:01:00");
+
+        let duration = Duration::seconds(3600);
+        let res = duration_to_string(&duration);
+        assert_eq!(res, "01:00:00");
+
+        let duration = Duration::seconds(3600 + 60 + 1);
+        let res = duration_to_string(&duration);
+        assert_eq!(res, "01:01:01");
+    }
+
+    #[tokio::test]
+    async fn test_extract_track_info_from_playlist() {
+        let sample_playlist_content = tokio::fs::read_to_string("tests/test_data/playlist.m3u8")
+            .await
+            .unwrap();
+
+        let (total_time, parts) = extract_track_info_from_playlist(sample_playlist_content)
+            .expect("failed to extract track info from playlist");
+        assert_eq!(total_time, 18002.0 as f64);
+        assert_eq!(parts.len(), 2);
+
+        assert_eq!(
+            parts[0],
+            ("1740252892.mp4_000.mp4".to_string(), 18001.720898 as f64)
+        );
+        assert_eq!(
+            parts[1],
+            ("1740252892.mp4_001.mp4".to_string(), 14633.040755 as f64)
+        );
+    }
+    #[tokio::test]
+    async fn test_extract_track_info_from_playlist_file() {
+        let parent_dir = Path::new("tests/test_data/");
+        let res = extract_track_info_from_playlist_file(
+            &parent_dir.into(),
+            &Path::join(parent_dir, "playlist.m3u8"),
+        )
+        .await
+        .unwrap();
+        // .expect("failed to extract track info from playlist");
+        let (parts, second_last_time, last_time, second_last_path, last_path) = res;
+        assert_eq!(parts.len(), 2);
+
+        assert_eq!(
+            second_last_path,
+            Some(Path::join(parent_dir, "1740252892.mp4_000.mp4"))
+        );
+        assert_eq!(
+            last_path,
+            Some(Path::join(parent_dir, "1740252892.mp4_001.mp4"))
+        );
+        assert_eq!(parts[0], Path::join(parent_dir, "1740252892.mp4_000.mp4"));
+        assert_eq!(parts[1], Path::join(parent_dir, "1740252892.mp4_001.mp4"));
+        assert_eq!(second_last_time, 18001.720898 as f64);
+        assert_eq!(last_time, 14633.040755 as f64);
+    }
+}
+
+//endregion

src/main.rs

@@ -9,6 +9,14 @@ use google_bigquery::{BigDataTable, BigqueryClient};
 use google_youtube::scopes;
 use google_youtube::YoutubeClient;
 use log::{debug, error, info, trace, warn};
+use log4rs::append::console::ConsoleAppender;
+use log4rs::append::rolling_file::policy::compound::roll;
+use log4rs::append::rolling_file::policy::compound::roll::fixed_window::FixedWindowRoller;
+use log4rs::append::rolling_file::policy::compound::trigger::size::SizeTrigger;
+use log4rs::append::rolling_file::policy::{compound::CompoundPolicy, Policy};
+use log4rs::append::rolling_file::{RollingFileAppender, RollingFileAppenderBuilder};
+use log4rs::config::{Appender, Root};
+use log4rs::encode::pattern::PatternEncoder;
 use nameof::name_of;
 use simplelog::*;
 use tokio::fs::File;
@@ -29,6 +37,59 @@ const DATASET_ID: &str = "backup_data";
 
 #[tokio::main]
 async fn main() -> Result<(), Box<dyn Error>> {
+    initialize_logger2().await;
+    info!("Hello, world!");
+    start_backup().await?;
+    // sample().await?;
+    Ok(())
+}
+
+async fn initialize_logger2() -> Result<(), Box<dyn Error>> {
+    // // example:
+    // // [2023-04-07T13:00:03.689100600+02:00] [INFO ] downloader::src\main.rs:42 - Hello, world!
+    // let encoder = PatternEncoder::new("[{d:35}] [{h({l:5})}] {M}::{file}:{L} - {m}{n}");
+    // use log4rs::append::rolling_file::policy::compound::trigger::size::SizeTriggerDeserializer;
+    // let stdout = ConsoleAppender::builder()
+    //     .encoder(Box::new(encoder.clone()))
+    //     .build();
+    // let size_trigger = SizeTrigger::new(gb_to_bytes(1.0));
+    // // let size_trigger = SizeTrigger::new(1000);
+    // let roller = FixedWindowRoller::builder()
+    //     .build("downloader/logs/archive/downloader.{}.log", 3)
+    //     .unwrap();
+    // let policy = CompoundPolicy::new(Box::new(size_trigger), Box::new(roller));
+    // let file = RollingFileAppender::builder()
+    //     .encoder(Box::new(encoder.clone()))
+    //     .build("downloader/logs/downloader.log", Box::new(policy))
+    //     .unwrap();
+    // let config = log4rs::Config::builder()
+    //     .appender(Appender::builder().build("stdout", Box::new(stdout)))
+    //     .appender(Appender::builder().build("file", Box::new(file)))
+    //     .build(
+    //         Root::builder()
+    //             .appender("stdout")
+    //             .appender("file")
+    //             .build(LevelFilter::Debug),
+    //     )
+    //     .unwrap();
+    //
+    // let _handle = log4rs::init_config(config).unwrap();
+    log4rs::init_file("logger.yaml", Default::default()).unwrap();
+    info!("==================================================================================");
+    info!(
+        "Start of new log on {}",
+        chrono::Utc::now().format("%Y-%m-%d %H:%M:%S")
+    );
+    info!("==================================================================================");
+
+    Ok(())
+}
+
+fn gb_to_bytes(gb: f32) -> u64 {
+    (gb * 1000000000.0) as u64
+}
+
+async fn initialize_logger() -> Result<(), Box<dyn Error>> {
     let log_folder = "downloader/logs/";
     tokio::fs::create_dir_all(log_folder).await?;
     let timestamp = chrono::Utc::now().format("%Y-%m-%d_%H-%M-%S").to_string();
@@ -60,9 +121,6 @@ async fn main() -> Result<(), Box<dyn Error>> {
     ])
     .unwrap();
     log_panics::init();
-    println!("Hello, world!");
-    start_backup().await?;
-    // sample().await?;
     Ok(())
 }
 

tests/lib_tests.rs

@@ -1,8 +1,10 @@
 use std::path::{Path, PathBuf};
+use std::sync::Once;
 
 use chrono::{DateTime, NaiveDateTime, Utc};
 // use bigquery_googleapi::BigqueryClient;
 use google_bigquery::BigqueryClient;
+use log::info;
 use log::LevelFilter;
 use simplelog::{ColorChoice, TermLogger, TerminalMode};
 
@@ -13,14 +15,17 @@ use downloader::{
     get_video_title_from_twitch_video,
 };
 
+static INIT: Once = Once::new();
 fn init_console_logging(log_level: LevelFilter) {
-    TermLogger::init(
+    INIT.call_once(|| {
-        log_level,
+        TermLogger::init(
-        simplelog::Config::default(),
+            log_level,
-        TerminalMode::Mixed,
+            simplelog::Config::default(),
-        ColorChoice::Auto,
+            TerminalMode::Mixed,
-    )
+            ColorChoice::Auto,
-    .unwrap();
+        )
+        .unwrap();
+    });
 }
 
 async fn get_sample_client() -> BigqueryClient {
@@ -80,6 +85,7 @@ const LONG_TITLE: &'static str =
 
 #[tokio::test]
 async fn get_video_title() {
+    init_console_logging(LevelFilter::Debug);
     let client = get_sample_client().await;
     let mut video = get_sample_video(&client);
 
@@ -88,12 +94,13 @@ async fn get_video_title() {
 
     video.video.title = Some(LONG_TITLE.to_string());
     let title = get_video_title_from_twitch_video(&video, 5, 20).unwrap();
-    println!("part title:\n{}", title);
+    info!("part title:\n{}", title);
     assert_eq!(title, "[2021-01-01][Part 05/20] long title with over a hundred characters that is definitely going to be...");
 }
 
 #[tokio::test]
 async fn get_video_title_single_part() {
+    init_console_logging(LevelFilter::Debug);
     let client = get_sample_client().await;
     let mut video = get_sample_video(&client);
 
@@ -102,7 +109,7 @@ async fn get_video_title_single_part() {
 
     video.video.title = Some(LONG_TITLE.to_string());
     let title = get_video_title_from_twitch_video(&video, 1, 1).unwrap();
-    println!("single part title:\n{}", title);
+    info!("single part title:\n{}", title);
     assert_eq!(
         title,
         "long title with over a hundred characters that is definitely going to be..."
@@ -111,6 +118,7 @@ async fn get_video_title_single_part() {
 
 #[tokio::test]
 async fn get_playlist_title() {
+    init_console_logging(LevelFilter::Debug);
     let client = get_sample_client().await;
     let mut video = get_sample_video(&client);
 
@@ -119,7 +127,7 @@ async fn get_playlist_title() {
 
     video.video.title = Some(LONG_TITLE.to_string());
     let title = get_playlist_title_from_twitch_video(&video).unwrap();
-    println!("playlist title:\n{}", title);
+    info!("playlist title:\n{}", title);
     assert_eq!(
         title,
         "long title with over a hundred characters that is definitely going to be..."
@@ -128,28 +136,19 @@ async fn get_playlist_title() {
 
 #[tokio::test]
 async fn get_video_prefix() {
+    init_console_logging(LevelFilter::Debug);
     let client = get_sample_client().await;
     let video = get_sample_video(&client);
 
     let prefix = get_video_prefix_from_twitch_video(&video, 5, 20).unwrap();
-    println!("prefix:\n{}", prefix);
+    info!("prefix:\n{}", prefix);
     assert_eq!(prefix, "[2021-01-01][Part 05/20]");
 }
 
 #[tokio::test]
-async fn split_video_into_parts() {
+async fn split_video_into_parts_with_join() {
     init_console_logging(LevelFilter::Debug);
-
+    let (tmp_folder_path, video_path) = prepare_existing_video_test_data(1);
-    //region prepare test data
-    let video_source = Path::new("tests/test_data/short_video/short_video.mp4");
-    let tmp_folder_path = Path::new("tests/test_data/tmp/");
-    let video_path = Path::join(tmp_folder_path, "short_video/short_video.mp4");
-    if tmp_folder_path.exists() {
-        std::fs::remove_dir_all(tmp_folder_path).unwrap();
-    }
-    std::fs::create_dir_all(video_path.parent().unwrap()).unwrap();
-    std::fs::copy(video_source, &video_path).unwrap();
-    //endregion
 
     let parts = downloader::split_video_into_parts(
         PathBuf::from(&video_path),
@@ -163,6 +162,40 @@ async fn split_video_into_parts() {
     //endregion
 
     let parts = parts.expect("failed to split video into parts");
-    println!("parts: {:?}", parts);
+    info!("parts: {:?}", parts);
-    assert_eq!(parts.len(), 5);
+    assert_eq!(5, parts.len(),);
+}
+
+#[tokio::test]
+async fn split_video_into_parts_without_join() {
+    init_console_logging(LevelFilter::Debug);
+    let (tmp_folder_path, video_path) = prepare_existing_video_test_data(2);
+
+    let parts = downloader::split_video_into_parts(
+        PathBuf::from(&video_path),
+        chrono::Duration::seconds(5),
+        chrono::Duration::seconds(6),
+    )
+    .await;
+
+    //region clean up
+    std::fs::remove_dir_all(tmp_folder_path).unwrap();
+    //endregion
+
+    let parts = parts.expect("failed to split video into parts");
+    info!("parts: {:?}", parts);
+    assert_eq!(6, parts.len(),);
+}
+
+fn prepare_existing_video_test_data(temp_subname: i32) -> (PathBuf, PathBuf) {
+    let video_source = Path::new("tests/test_data/short_video/short_video.mp4");
+    let tmp_folder_path = format!("tests/test_data/tmp_{}", temp_subname);
+    let tmp_folder_path: PathBuf = tmp_folder_path.as_str().into();
+    let video_path = Path::join(&tmp_folder_path, "short_video/short_video.mp4");
+    if tmp_folder_path.exists() {
+        std::fs::remove_dir_all(&tmp_folder_path).unwrap();
+    }
+    std::fs::create_dir_all(video_path.parent().unwrap()).unwrap();
+    std::fs::copy(video_source, &video_path).unwrap();
+    (tmp_folder_path.to_path_buf(), video_path)
 }

tests/test_data/playlist.m3u8

@@ -0,0 +1,10 @@
+#EXTM3U
+#EXT-X-VERSION:3
+#EXT-X-MEDIA-SEQUENCE:0
+#EXT-X-ALLOW-CACHE:YES
+#EXT-X-TARGETDURATION:18002
+#EXTINF:18001.720898,
+1740252892.mp4_000.mp4
+#EXTINF:14633.040755,
+1740252892.mp4_001.mp4
+#EXT-X-ENDLIST