From 1d08698d0c11593bab472427b0d6ee6e9fc04f2e Mon Sep 17 00:00:00 2001 From: Scott Lamb Date: Tue, 17 Oct 2017 06:14:47 -0700 Subject: [PATCH] debug, fix panic with zero-duration recording I had an assert that fired in this case, dating back to when I hadn't plumbed Result returns through much of .mp4 construction. Now I have, so there's no excuse in having an assert here. Change to an error return, and tweak it to not fire in the zero-duration case. Also fix a problem in the test harness; I hadn't finished converting it for multi-recording tests, and it was returning the wrong recording. Because of that, I seem to have stumbled across a related problem in which asking for zero duration of a non-zero duration recording will return a recording::Segment with no frames, which will cause panics because its corresponding .mp4 slices are zero-length. I just adjusted the panic message here; I'll follow up with changes to address that. --- guide/install.md | 1 + prep.sh | 1 + src/db.rs | 7 ++++--- src/mp4.rs | 38 ++++++++++++++++++++++++++++++++++---- src/slices.rs | 8 +++++--- src/testutil.rs | 6 +++--- 6 files changed, 48 insertions(+), 13 deletions(-) diff --git a/guide/install.md b/guide/install.md index 884bfb5..1dbf0d6 100644 --- a/guide/install.md +++ b/guide/install.md @@ -171,6 +171,7 @@ been done for you. If not, Create Environment=TZ=:/etc/localtime Environment=MOONFIRE_FORMAT=google-systemd Environment=MOONFIRE_LOG=info + Environment=RUST_BACKTRACE=1 Type=simple User=moonfire-nvr Nice=-20 diff --git a/prep.sh b/prep.sh index cb97d80..eac01bd 100755 --- a/prep.sh +++ b/prep.sh @@ -228,6 +228,7 @@ ExecStart=${SERVICE_BIN} run \\ Environment=TZ=:/etc/localtime Environment=MOONFIRE_FORMAT=google-systemd Environment=MOONFIRE_LOG=info +Environment=RUST_BACKTRACE=1 Type=simple User=${NVR_USER} Nice=-20 diff --git a/src/db.rs b/src/db.rs index 4520dbe..b3a655e 100644 --- a/src/db.rs +++ b/src/db.rs @@ -646,7 +646,7 @@ impl<'a> Transaction<'a> { /// Inserts the specified recording. /// The sample file uuid must have been previously reserved. (Although this can be bypassed /// for testing; see the `bypass_reservation_for_testing` field.) - pub fn insert_recording(&mut self, r: &RecordingToInsert) -> Result<(), Error> { + pub fn insert_recording(&mut self, r: &RecordingToInsert) -> Result { self.check_must_rollback()?; // Sanity checking. @@ -670,8 +670,9 @@ impl<'a> Transaction<'a> { } self.must_rollback = true; let m = Transaction::get_mods_by_camera(&mut self.mods_by_camera, r.camera_id); + let recording_id; { - let recording_id = m.new_next_recording_id.unwrap_or(cam.next_recording_id); + recording_id = m.new_next_recording_id.unwrap_or(cam.next_recording_id); let composite_id = composite_id(r.camera_id, recording_id); let mut stmt = self.tx.prepare_cached(INSERT_RECORDING_SQL)?; stmt.execute_named(&[ @@ -706,7 +707,7 @@ impl<'a> Transaction<'a> { m.duration += r.time.end - r.time.start; m.sample_file_bytes += r.sample_file_bytes as i64; adjust_days(r.time.clone(), 1, &mut m.days); - Ok(()) + Ok(recording_id) } /// Updates the `retain_bytes` for the given camera to the specified limit. diff --git a/src/mp4.rs b/src/mp4.rs index 07e3535..955db41 100644 --- a/src/mp4.rs +++ b/src/mp4.rs @@ -1083,13 +1083,13 @@ impl FileBuilder { for s in &self.segments { // The actual range may start before the desired range because it can only start on a // key frame. This relationship should hold true: - // actual start <= desired start < desired end + // actual start <= desired start <= desired end let actual_start_90k = s.s.actual_start_90k(); let skip = s.s.desired_range_90k.start - actual_start_90k; let keep = s.s.desired_range_90k.end - s.s.desired_range_90k.start; - assert!(skip >= 0 && keep > 0, "segment {}/{}: desired={}..{} actual_start={}", - s.s.camera_id, s.s.recording_id, s.s.desired_range_90k.start, - s.s.desired_range_90k.end, actual_start_90k); + if skip < 0 || keep < 0 { + return Err(Error::new(format!("skip={} keep={} on segment {:#?}", skip, keep, s))); + } cur_media_time += skip as u64; if unflushed.segment_duration + unflushed.media_time == cur_media_time { unflushed.segment_duration += keep as u64; @@ -1660,6 +1660,12 @@ mod tests { BigEndian::read_u32(&buf[..]) } + pub fn get_u64(&self, p: u64) -> u64 { + let mut buf = [0u8; 8]; + self.get(p, &mut buf); + BigEndian::read_u64(&buf[..]) + } + /// Navigates to the next box after the current one, or up if the current one is last. pub fn next(&mut self) -> bool { let old = self.stack.pop().expect("positioned at root; there is no next"); @@ -2023,6 +2029,30 @@ mod tests { assert_eq!(cursor.get_u32(12), 2); } + #[test] + fn test_zero_duration_recording() { + testutil::init(); + let db = TestDb::new(); + let mut encoders = Vec::new(); + let mut encoder = recording::SampleIndexEncoder::new(); + encoder.add_sample(2, 1, true); + encoder.add_sample(3, 2, false); + encoders.push(encoder); + let mut encoder = recording::SampleIndexEncoder::new(); + encoder.add_sample(0, 3, true); + encoders.push(encoder); + + // Multi-segment recording with an edit list, encoding with a zero-duration recording. + let mp4 = make_mp4_from_encoders(Type::Normal, &db, encoders, 1 .. 2+3); + let track = find_track(mp4, 1); + let mut cursor = track.edts_cursor.unwrap(); + cursor.down(); + cursor.find(b"elst"); + assert_eq!(cursor.get_u32(4), 1); // entry_count + assert_eq!(cursor.get_u64(8), 4); // segment_duration + assert_eq!(cursor.get_u64(16), 1); // media_time + } + #[test] fn test_media_segment() { testutil::init(); diff --git a/src/slices.rs b/src/slices.rs index 91337e2..b3d3235 100644 --- a/src/slices.rs +++ b/src/slices.rs @@ -41,7 +41,7 @@ pub type Body = Box + Send>; /// Writes a byte range to the given `io::Write` given a context argument; meant for use with /// `Slices`. -pub trait Slice : Sync + Sized + 'static { +pub trait Slice : fmt::Debug + Sized + Sync + 'static { type Ctx: Send + Clone; type Chunk: Send; @@ -70,7 +70,7 @@ pub struct Slices where S: Slice { slices: Vec, } -impl fmt::Debug for Slices where S: fmt::Debug + Slice { +impl fmt::Debug for Slices where S: Slice { fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { write!(f, "{} slices with overall length {}:", self.slices.len(), self.len)?; let mut start = 0; @@ -94,7 +94,8 @@ impl Slices where S: Slice { /// Appends the given slice. pub fn append(&mut self, slice: S) { - assert!(slice.end() > self.len); + assert!(slice.end() > self.len, "end {} <= len {} while adding slice {:?} to slices:\n{:?}", + slice.end(), self.len, slice, self); self.len = slice.end(); self.slices.push(slice); } @@ -158,6 +159,7 @@ mod tests { range: Range, } + #[derive(Debug)] pub struct FakeSlice { end: u64, name: &'static str, diff --git a/src/testutil.rs b/src/testutil.rs index 63d8c8b..6f76de9 100644 --- a/src/testutil.rs +++ b/src/testutil.rs @@ -120,11 +120,12 @@ impl TestDb { let mut db = self.db.lock(); let video_sample_entry_id = db.insert_video_sample_entry( 1920, 1080, [0u8; 100].to_vec(), "avc1.000000".to_owned()).unwrap(); + let row_id; { let mut tx = db.tx().unwrap(); tx.bypass_reservation_for_testing = true; const START_TIME: recording::Time = recording::Time(1430006400i64 * TIME_UNITS_PER_SEC); - tx.insert_recording(&db::RecordingToInsert{ + row_id = tx.insert_recording(&db::RecordingToInsert{ camera_id: TEST_CAMERA_ID, sample_file_bytes: encoder.sample_file_bytes, time: START_TIME .. @@ -142,8 +143,7 @@ impl TestDb { tx.commit().unwrap(); } let mut row = None; - let all_time = recording::Time(i64::min_value()) .. recording::Time(i64::max_value()); - db.list_recordings_by_time(TEST_CAMERA_ID, all_time, + db.list_recordings_by_id(TEST_CAMERA_ID, row_id .. row_id + 1, |r| { row = Some(r); Ok(()) }).unwrap(); row.unwrap() }