From 9cc63faf29477cb34cce76cc9bfe23aa7128c1c5 Mon Sep 17 00:00:00 2001 From: Scott Lamb Date: Fri, 4 Jun 2021 23:28:48 -0700 Subject: [PATCH] logging improvements * allow debug/trace logging on release builds again * enable log messages from hyper. I didn't notice they went away with 0.14.0, although there's a breaking change in the log: https://github.com/hyperium/hyper/blob/master/CHANGELOG.md#v0140-2020-12-23 * downgrade some particularly spammy messages --- server/Cargo.lock | 14 ++++++++++++++ server/Cargo.toml | 3 ++- server/src/mp4.rs | 6 +++--- server/src/stream.rs | 3 +-- server/src/streamer.rs | 4 ---- server/src/web.rs | 12 +++++++----- 6 files changed, 27 insertions(+), 15 deletions(-) diff --git a/server/Cargo.lock b/server/Cargo.lock index 25f9664..34b1ee8 100644 --- a/server/Cargo.lock +++ b/server/Cargo.lock @@ -1273,6 +1273,7 @@ dependencies = [ "tokio", "tokio-stream", "tokio-tungstenite", + "tracing", "url", "uuid", ] @@ -2356,10 +2357,23 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "09adeb8c97449311ccd28a427f96fb563e7fd31aabf994189879d9da2394b89d" dependencies = [ "cfg-if 1.0.0", + "log", "pin-project-lite", + "tracing-attributes", "tracing-core", ] +[[package]] +name = "tracing-attributes" +version = "0.1.15" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c42e6fa53307c8a17e4ccd4dc81cf5ec38db9209f59b222210375b54ee40d1e2" +dependencies = [ + "proc-macro2", + "quote", + "syn", +] + [[package]] name = "tracing-core" version = "0.1.18" diff --git a/server/Cargo.toml b/server/Cargo.toml index 552d851..64bbf4c 100644 --- a/server/Cargo.toml +++ b/server/Cargo.toml @@ -39,7 +39,7 @@ http-serve = { version = "0.3.1", features = ["dir"] } hyper = { version = "0.14.2", features = ["http1", "server", "stream", "tcp"] } lazy_static = "1.0" libc = "0.2" -log = { version = "0.4", features = ["release_max_level_info"] } +log = { version = "0.4" } memchr = "2.0.2" moonfire-tflite = { git = "https://github.com/scottlamb/moonfire-tflite", features = ["edgetpu"], optional = true } mylog = { git = "https://github.com/scottlamb/mylog" } @@ -59,6 +59,7 @@ time = "0.1" tokio = { version = "1.0", features = ["macros", "parking_lot", "rt-multi-thread", "signal", "time"] } tokio-stream = "0.1.5" tokio-tungstenite = "0.14.0" +tracing = { version = "0.1", features = ["log"] } url = "2.1.1" uuid = { version = "0.8", features = ["serde", "std", "v4"] } diff --git a/server/src/mp4.rs b/server/src/mp4.rs index 040cac7..38db3b2 100644 --- a/server/src/mp4.rs +++ b/server/src/mp4.rs @@ -1111,8 +1111,8 @@ impl FileBuilder { self.body.buf.len() ); } - debug!("segments: {:#?}", self.segments); - debug!("slices: {:?}", self.body.slices); + trace!("segments: {:#?}", self.segments); + trace!("slices: {:?}", self.body.slices); let last_modified = ::std::time::UNIX_EPOCH + ::std::time::Duration::from_secs(max_end as u64); let etag = etag.finalize(); @@ -1410,7 +1410,7 @@ impl FileBuilder { flushed.push(unflushed); - debug!("Using edit list: {:?}", flushed); + trace!("Using edit list: {:?}", flushed); write_length!(self, { self.body.buf.extend_from_slice(b"edts"); write_length!(self, { diff --git a/server/src/stream.rs b/server/src/stream.rs index eaedc06..52e4749 100644 --- a/server/src/stream.rs +++ b/server/src/stream.rs @@ -6,7 +6,7 @@ use crate::h264; use cstr::cstr; use failure::{bail, Error}; use lazy_static::lazy_static; -use log::{debug, warn}; +use log::warn; use std::convert::TryFrom; use std::ffi::CString; use std::result::Result; @@ -117,7 +117,6 @@ impl Opener for Ffmpeg { let s = input.streams(); for i in 0..s.len() { if s.get(i).codecpar().codec_type().is_video() { - debug!("Video stream index is {}", i); video_i = Some(i); break; } diff --git a/server/src/streamer.rs b/server/src/streamer.rs index 22a0c63..01d4ad8 100644 --- a/server/src/streamer.rs +++ b/server/src/streamer.rs @@ -135,10 +135,6 @@ where let _t = TimerGuard::new(&clocks, || "inserting video sample entry"); self.db.lock().insert_video_sample_entry(extra_data.entry)? }; - debug!( - "{}: video_sample_entry_id={}", - self.short_name, video_sample_entry_id - ); let mut seen_key_frame = false; // Seconds since epoch at which to next rotate. diff --git a/server/src/web.rs b/server/src/web.rs index 1cc006c..f071a90 100644 --- a/server/src/web.rs +++ b/server/src/web.rs @@ -19,7 +19,7 @@ use http::header::{self, HeaderValue}; use http::{status::StatusCode, Request, Response}; use http_serve::dir::FsDir; use hyper::body::Bytes; -use log::{debug, info, warn}; +use log::{debug, info, trace, warn}; use memchr::memchr; use nom::bytes::complete::{tag, take_while1}; use nom::combinator::{all_consuming, map, map_res, opt}; @@ -836,7 +836,7 @@ impl Service { format!("invalid s parameter: {}", value), ) })?; - debug!("stream_view_mp4: appending s={:?}", s); + trace!("stream_view_mp4: appending s={:?}", s); let mut est_segments = usize::try_from(s.ids.end - s.ids.start).unwrap(); if let Some(end) = s.end_time { // There should be roughly ceil((end - start) / @@ -887,10 +887,12 @@ impl Service { let start = cmp::max(0, s.start_time - cur_off); let end = cmp::min(wd, end_time - cur_off); let wr = i32::try_from(start).unwrap()..i32::try_from(end).unwrap(); - debug!( + trace!( "...appending recording {} with wall duration {:?} \ (out of total {})", - r.id, wr, wd + r.id, + wr, + wd ); if start_time_for_filename.is_none() { start_time_for_filename = @@ -906,7 +908,7 @@ impl Service { ); builder.append(&db, r, mr, true)?; } else { - debug!("...skipping recording {} wall dur {}", r.id, wd); + trace!("...skipping recording {} wall dur {}", r.id, wd); } cur_off += wd; Ok(())