From 2d85cb20f2bcacb3e34b02ab2685c6f53e153c70 Mon Sep 17 00:00:00 2001 From: jon Date: Mon, 29 Apr 2024 15:32:09 +1200 Subject: [PATCH 1/4] v11: - Fix slice lengths, set debug mode --- src/core1_task.rs | 4 ++-- src/cptv_encoder/streaming_cptv.rs | 3 ++- src/device_config.rs | 1 + 3 files changed, 5 insertions(+), 3 deletions(-) diff --git a/src/core1_task.rs b/src/core1_task.rs index ed92d15..dce6485 100644 --- a/src/core1_task.rs +++ b/src/core1_task.rs @@ -222,7 +222,7 @@ pub fn core_1_task( woken_by_alarm: bool, mut timer: Timer, ) { - let dev_mode = false; + let dev_mode = true; info!("=== Core 1 start ==="); if dev_mode { warn!("DEV MODE"); @@ -819,7 +819,7 @@ pub fn core_1_task( } let one_min_check_start = timer.get_counter(); - let expected_rtc_sync_time_us = 2100; + let expected_rtc_sync_time_us = 4300; if (frames_seen > 1 && frames_seen % (60 * 9) == 0) && cptv_stream.is_none() { let sync_rtc_start = timer.get_counter(); // NOTE: We only advise the RPi that it can shut down if we're not currently recording – diff --git a/src/cptv_encoder/streaming_cptv.rs b/src/cptv_encoder/streaming_cptv.rs index aad6bc4..033e08e 100644 --- a/src/cptv_encoder/streaming_cptv.rs +++ b/src/cptv_encoder/streaming_cptv.rs @@ -715,6 +715,7 @@ pub fn push_header_iterator(header: &Cptv2Header) -> impl Iterator { header.loc_timestamp.is_some(), header.altitude.is_some(), header.accuracy.is_some(), + header.status_recording.is_some(), ] .iter() .filter(|x| **x) @@ -828,7 +829,7 @@ impl Cptv2Header { } let status_recording = if is_status_recording { let mut status = [0u8; 30]; - status.copy_from_slice("status: true".as_bytes()); + status[0..12].copy_from_slice("status: true".as_bytes()); Some(status) } else { None diff --git a/src/device_config.rs b/src/device_config.rs index 58d4335..7ad6d30 100644 --- a/src/device_config.rs +++ b/src/device_config.rs @@ -146,6 +146,7 @@ impl DeviceConfig { } pub fn use_low_power_mode(&self) -> bool { + return true; self.config_inner.use_low_power_mode } From c113f582a7d52299b7dd13ce97e8db1eefefacf1 Mon Sep 17 00:00:00 2001 From: jon Date: Mon, 29 Apr 2024 15:53:25 +1200 Subject: [PATCH 2/4] v11: - Fix slice lengths, set debug mode (2) --- src/core1_task.rs | 56 ++++++++++++++++++------------ src/cptv_encoder/streaming_cptv.rs | 1 + src/onboard_flash.rs | 10 ++++-- 3 files changed, 41 insertions(+), 26 deletions(-) diff --git a/src/core1_task.rs b/src/core1_task.rs index dce6485..dfeb418 100644 --- a/src/core1_task.rs +++ b/src/core1_task.rs @@ -585,11 +585,35 @@ pub fn core_1_task( let motion_detection_triggered_this_frame = this_frame_motion_detection.got_new_trigger(); should_start_new_recording = !flash_storage.is_too_full_to_start_new_recordings() - && (motion_detection_triggered_this_frame - || !made_startup_status_recording - || !made_shutdown_status_recording) + && (motion_detection_triggered_this_frame || !made_startup_status_recording) && cptv_stream.is_none(); // wait until lepton stabilises before recording + if made_startup_status_recording + && !made_shutdown_status_recording + && !motion_detection_triggered_this_frame + && cptv_stream.is_none() + { + if dev_mode { + if synced_date_time.date_time_utc + Duration::minutes(1) + > startup_date_time_utc + Duration::minutes(4) + { + warn!("Make shutdown status recording"); + should_start_new_recording = true; + made_shutdown_status_recording = true; + making_status_recording = true; + } + } else { + if let Some((_, window_end)) = ¤t_recording_window { + if synced_date_time.date_time_utc + Duration::minutes(1) > *window_end { + warn!("Make shutdown status recording"); + should_start_new_recording = true; + made_shutdown_status_recording = true; + making_status_recording = true; + } + } + } + } + // TODO: Do we want to have a max recording length timeout, or just pause recording if a subject stays in the frame // but doesn't move for a while? Maybe if a subject is stationary for 1 minute, we pause, and only resume // recording if there is new movement, or it moves again? If the night ends in this way, we end the recording then. @@ -632,29 +656,11 @@ pub fn core_1_task( // Should we make a 2-second status recording at the beginning or end of the window? if !made_startup_status_recording && !motion_detection_triggered_this_frame { + warn!("Make startup status recording"); made_startup_status_recording = true; making_status_recording = true; } else { - if !made_shutdown_status_recording && !motion_detection_triggered_this_frame - { - if dev_mode { - if synced_date_time.date_time_utc + Duration::minutes(1) - > startup_date_time_utc + Duration::minutes(4) - { - made_shutdown_status_recording = true; - making_status_recording = true; - } - } else { - if let Some((_, window_end)) = ¤t_recording_window { - if synced_date_time.date_time_utc + Duration::minutes(1) - > *window_end - { - made_shutdown_status_recording = true; - making_status_recording = true; - } - } - } - } + // We're making a shutdown recording. } warn!("Setting recording flag on attiny"); @@ -664,6 +670,10 @@ pub fn core_1_task( let _ = shared_i2c .set_recording_flag(&mut delay, true) .map_err(|e| error!("Error setting recording flag on attiny: {}", e)); + warn!( + "Making a status recording? {}, Triggered motion? {}", + making_status_recording, motion_detection_triggered_this_frame + ); error!("Starting new recording, {:?}", &frame_telemetry); // TODO: Pass in various cptv header info bits. let mut cptv_streamer = CptvStream::new( diff --git a/src/cptv_encoder/streaming_cptv.rs b/src/cptv_encoder/streaming_cptv.rs index 033e08e..d4a1341 100644 --- a/src/cptv_encoder/streaming_cptv.rs +++ b/src/cptv_encoder/streaming_cptv.rs @@ -829,6 +829,7 @@ impl Cptv2Header { } let status_recording = if is_status_recording { let mut status = [0u8; 30]; + info!("Creating status recording"); status[0..12].copy_from_slice("status: true".as_bytes()); Some(status) } else { diff --git a/src/onboard_flash.rs b/src/onboard_flash.rs index 9ffa0f6..830f634 100644 --- a/src/onboard_flash.rs +++ b/src/onboard_flash.rs @@ -765,9 +765,13 @@ impl OnboardFlash { self.read_from_cache_at_column_offset(block, 0, None); } pub fn spi_write(&mut self, bytes: &[u8]) { - self.cs.set_low().unwrap(); - self.spi.as_mut().unwrap().write(bytes).unwrap(); - self.cs.set_high().unwrap(); + if let Some(spi) = self.spi.as_mut() { + self.cs.set_low().unwrap(); + spi.write(bytes).unwrap(); + self.cs.set_high().unwrap(); + } else { + error!("Onboard flash doesn't own SPI, can't do write"); + } } fn print_feature(&mut self, name: &str, feature: u8) { From d57a9182507b86f4c27c2a8585e7deec55355565 Mon Sep 17 00:00:00 2001 From: jon Date: Tue, 30 Apr 2024 09:31:17 +1200 Subject: [PATCH 3/4] Local testing (2) --- src/attiny_rtc_i2c.rs | 1 + src/core0_task.rs | 8 ++++---- src/core1_sub_tasks.rs | 2 +- src/core1_task.rs | 40 ++++++++++++++++++++++++++++++++-------- 4 files changed, 38 insertions(+), 13 deletions(-) diff --git a/src/attiny_rtc_i2c.rs b/src/attiny_rtc_i2c.rs index a438253..cf1442e 100644 --- a/src/attiny_rtc_i2c.rs +++ b/src/attiny_rtc_i2c.rs @@ -329,6 +329,7 @@ impl SharedI2C { ); return Err(e); } + warn!("ATTiny write error, retrying in 500µs"); num_attempts += 1; delay.delay_us(500); } diff --git a/src/core0_task.rs b/src/core0_task.rs index a862d06..a80ad96 100644 --- a/src/core0_task.rs +++ b/src/core0_task.rs @@ -56,7 +56,7 @@ fn go_dormant_until_woken( } pub fn frame_acquisition_loop( - rosc: RingOscillator, // NOTE: not using dormant at the moment, so don't need mut + mut rosc: RingOscillator, // NOTE: not using dormant at the moment, so don't need mut lepton: &mut LeptonModule, sio_fifo: &mut SioFifo, peripheral_clock_freq: HertzU32, @@ -130,7 +130,7 @@ pub fn frame_acquisition_loop( // FIXME - Whenever recording starts, we lose a frame here. It's the all important first frame of the recording. // Let's just use a bit more power for now until we figure out how to fix this. - // rosc = go_dormant_until_next_vsync(rosc, lepton, clocks.system_clock.freq(), got_sync); + //rosc = go_dormant_until_next_vsync(rosc, lepton, clocks.system_clock.freq(), got_sync); continue 'frame_loop; } if !transferring_prev_frame && prev_frame_needs_transfer { @@ -524,8 +524,8 @@ pub fn frame_acquisition_loop( recording_ended = false; } // if !is_recording && !transferring_prev_frame && current_segment_num == 3 { - // // rosc = - // // go_dormant_until_next_vsync(rosc, lepton, clocks.system_clock.freq(), got_sync); + // rosc = + // go_dormant_until_next_vsync(rosc, lepton, clocks.system_clock.freq(), got_sync); // } else if current_segment_num == 3 { // //warn!("Overrunning frame time"); // } diff --git a/src/core1_sub_tasks.rs b/src/core1_sub_tasks.rs index ab33657..bc0dcd0 100644 --- a/src/core1_sub_tasks.rs +++ b/src/core1_sub_tasks.rs @@ -192,7 +192,7 @@ pub fn offload_flash_storage_and_events( info!("Erasing after successful offload"); //flash_storage.erase_all_good_used_blocks(); flash_storage.erase_all_blocks(); - true + file_count != 0 } else { warn!("File transfer to pi failed"); false diff --git a/src/core1_task.rs b/src/core1_task.rs index dfeb418..b118fcc 100644 --- a/src/core1_task.rs +++ b/src/core1_task.rs @@ -249,7 +249,7 @@ pub fn core_1_task( let mut shared_i2c = SharedI2C::new(i2c_config, unlocked_pin, &mut delay); let (pio0, sm0, _, _, _) = peripherals.PIO0.split(&mut peripherals.RESETS); - let should_record_to_flash = true; + let should_record_to_flash = false; loop { // NOTE: Keep retrying until we get a datetime from RTC. @@ -829,7 +829,7 @@ pub fn core_1_task( } let one_min_check_start = timer.get_counter(); - let expected_rtc_sync_time_us = 4300; + let expected_rtc_sync_time_us = 3500; if (frames_seen > 1 && frames_seen % (60 * 9) == 0) && cptv_stream.is_none() { let sync_rtc_start = timer.get_counter(); // NOTE: We only advise the RPi that it can shut down if we're not currently recording – @@ -850,7 +850,12 @@ pub fn core_1_task( ); logged_told_rpi_to_sleep = true; } + info!( + "Advise pi to shutdown took {}µs", + (timer.get_counter() - sync_rtc_start).to_micros() + ); } + let sync_rtc_start_real = timer.get_counter(); synced_date_time = match shared_i2c.get_datetime(&mut delay) { Ok(now) => SyncedDateTime::new(get_naive_datetime(now), &timer), Err(err_str) => { @@ -865,6 +870,10 @@ pub fn core_1_task( synced_date_time } }; + info!( + "RTC Sync time took {}µs", + (timer.get_counter() - sync_rtc_start_real).to_micros() + ); // NOTE: In continuous recording mode, the device will only shut down briefly when the flash storage // is nearly full, and it needs to offload files. Or, in the case of non-low-power-mode, it will @@ -873,9 +882,12 @@ pub fn core_1_task( let is_outside_recording_window = if !dev_mode { !device_config.time_is_in_recording_window(&synced_date_time.date_time_utc, &None) } else { - let is_inside_recording_window = synced_date_time.date_time_utc - < startup_date_time_utc + chrono::Duration::minutes(5); - !is_inside_recording_window + !device_config.time_is_in_recording_window(&synced_date_time.date_time_utc, &None) + + // DEV_MODE + // let is_inside_recording_window = + // synced_date_time.date_time_utc < startup_date_time_utc + Duration::minutes(5); + // !is_inside_recording_window }; let flash_storage_nearly_full = flash_storage.is_too_full_to_start_new_recordings(); @@ -893,6 +905,7 @@ pub fn core_1_task( if flash_storage_nearly_full || (is_outside_recording_window && flash_storage.has_files_to_offload()) { + warn!("Recording window ended with files to offload, request restart"); // If flash storage is nearly full, or we're now outside the recording window, // Trigger a restart now via the watchdog timer, so that flash storage will // be offloaded during the startup sequence. @@ -917,6 +930,7 @@ pub fn core_1_task( logged_told_rpi_to_sleep = true; } } + let check_power_down_state_start = timer.get_counter(); if let Ok(pi_is_powered_down) = shared_i2c.pi_is_powered_down(&mut delay, true) { if pi_is_powered_down { if !logged_pi_powered_down { @@ -1026,19 +1040,29 @@ pub fn core_1_task( } else { warn!("Pi is still awake, so rp2040 must stay awake"); } + } else { + warn!("Failed to get Pi powered down state from Attiny"); } + warn!( + "Check pi power down state took {}", + (timer.get_counter() - check_power_down_state_start).to_micros() + ); } else if !is_outside_recording_window && !device_config.use_low_power_mode() { wake_raspberry_pi(&mut shared_i2c, &mut delay); } + // Make sure timing is as close as possible to the non-sync case let sync_rtc_end = timer.get_counter(); let sync_time = (sync_rtc_end - sync_rtc_start).to_micros() as i32; - let additional_wait = (expected_rtc_sync_time_us - sync_time).max(0); + let additional_wait = (expected_rtc_sync_time_us - sync_time).min(0); if additional_wait > 0 { - warn!("Additional wait after RTC sync {}µs", additional_wait); + warn!( + "Additional wait after RTC sync {}µs, total sync time {}", + additional_wait, sync_time + ); delay.delay_us(additional_wait as u32); } else { - warn!("RTC sync took {}µs", sync_time) + warn!("I2C messages took {}µs", sync_time) } } else { // Increment the datetime n frame's worth. From 7a77cc918978c35971840c960cfe4e0197e47d41 Mon Sep 17 00:00:00 2001 From: jon Date: Tue, 7 May 2024 11:37:41 +1200 Subject: [PATCH 4/4] Remove debug-mode stuff --- src/core1_task.rs | 13 ++++++------- src/device_config.rs | 1 - 2 files changed, 6 insertions(+), 8 deletions(-) diff --git a/src/core1_task.rs b/src/core1_task.rs index b118fcc..2f54214 100644 --- a/src/core1_task.rs +++ b/src/core1_task.rs @@ -222,7 +222,7 @@ pub fn core_1_task( woken_by_alarm: bool, mut timer: Timer, ) { - let dev_mode = true; + let dev_mode = false; info!("=== Core 1 start ==="); if dev_mode { warn!("DEV MODE"); @@ -249,7 +249,7 @@ pub fn core_1_task( let mut shared_i2c = SharedI2C::new(i2c_config, unlocked_pin, &mut delay); let (pio0, sm0, _, _, _) = peripherals.PIO0.split(&mut peripherals.RESETS); - let should_record_to_flash = false; + let should_record_to_flash = true; loop { // NOTE: Keep retrying until we get a datetime from RTC. @@ -882,12 +882,11 @@ pub fn core_1_task( let is_outside_recording_window = if !dev_mode { !device_config.time_is_in_recording_window(&synced_date_time.date_time_utc, &None) } else { - !device_config.time_is_in_recording_window(&synced_date_time.date_time_utc, &None) + // !device_config.time_is_in_recording_window(&synced_date_time.date_time_utc, &None) - // DEV_MODE - // let is_inside_recording_window = - // synced_date_time.date_time_utc < startup_date_time_utc + Duration::minutes(5); - // !is_inside_recording_window + let is_inside_recording_window = + synced_date_time.date_time_utc < startup_date_time_utc + Duration::minutes(5); + !is_inside_recording_window }; let flash_storage_nearly_full = flash_storage.is_too_full_to_start_new_recordings(); diff --git a/src/device_config.rs b/src/device_config.rs index 7ad6d30..58d4335 100644 --- a/src/device_config.rs +++ b/src/device_config.rs @@ -146,7 +146,6 @@ impl DeviceConfig { } pub fn use_low_power_mode(&self) -> bool { - return true; self.config_inner.use_low_power_mode }