From fa436c08457d2f1d9427c5cac030f12eae05065a Mon Sep 17 00:00:00 2001 From: bunnie Date: Mon, 5 Jun 2023 22:50:59 +0800 Subject: [PATCH] fix bugs so that the implementation is working as suspected, the shared lock is killer on performance. --- apps/vault/src/actions.rs | 128 +++++++-------------------------- apps/vault/src/itemcache.rs | 85 +++++++++++++++++++--- apps/vault/src/main.rs | 5 +- apps/vault/src/ux/framework.rs | 33 ++++----- services/pddb/src/lib.rs | 2 +- 5 files changed, 119 insertions(+), 134 deletions(-) diff --git a/apps/vault/src/actions.rs b/apps/vault/src/actions.rs index c41188887..0189f0ab8 100644 --- a/apps/vault/src/actions.rs +++ b/apps/vault/src/actions.rs @@ -51,95 +51,6 @@ pub enum ActionOp { /// Testing GenerateTests, } -/* -pub(crate) fn start_actions_thread<'a> ( - main_conn: xous::CID, - sid: SID, mode: Arc::>, - item_lists: Arc::>>, - action_active: Arc::, - opensk_mutex: Arc::>, -) { - let _ = thread::spawn({ - move || { - let mut manager = ActionManager::new(main_conn, mode, item_lists, action_active, opensk_mutex); - loop { - let msg = xous::receive_message(sid).unwrap(); - let opcode: Option = FromPrimitive::from_usize(msg.body.id()); - log::debug!("{:?}", opcode); - match opcode { - Some(ActionOp::MenuAddnew) => { - manager.activate(); - manager.menu_addnew(); - // this is necessary so the next redraw shows the newly added entry - // no cache clear is called for because new entries will always add to the list; - // there is no risk of "stale" entries persisting - manager.retrieve_db(); - manager.deactivate(); - }, - Some(ActionOp::MenuDeleteStage2) => { - let buffer = unsafe { Buffer::from_memory_message(msg.body.memory_message().unwrap()) }; - let entry = buffer.to_original::().unwrap(); - manager.activate(); - manager.menu_delete(entry); - manager.retrieve_db(); - manager.deactivate(); - }, - Some(ActionOp::MenuEditStage2) => { - let buffer = unsafe { Buffer::from_memory_message(msg.body.memory_message().unwrap()) }; - let entry = buffer.to_original::().unwrap(); - manager.activate(); - manager.menu_edit(entry); - manager.retrieve_db(); - manager.deactivate(); - }, - Some(ActionOp::MenuUnlockBasis) => { - manager.activate(); - manager.unlock_basis(); - manager.item_lists.lock().unwrap().pw.clear(); // clear the cached item list for passwords (totp/fido are not cached and don't need clearing) - manager.retrieve_db(); - manager.deactivate(); - }, - Some(ActionOp::MenuManageBasis) => { - manager.activate(); - manager.manage_basis(); - manager.item_lists.lock().unwrap().pw.clear(); // clear the cached item list for passwords - manager.retrieve_db(); - manager.deactivate(); - } - Some(ActionOp::MenuClose) => { - // dummy activate/de-activate cycle because we have to trigger a redraw of the underlying UX - manager.activate(); - manager.deactivate(); - }, - Some(ActionOp::UpdateOneItem) => { - let buffer = unsafe { Buffer::from_memory_message(msg.body.memory_message().unwrap()) }; - let entry = buffer.to_original::().unwrap(); - manager.activate(); - manager.update_db_entry(entry); - manager.deactivate(); - } - Some(ActionOp::UpdateMode) => msg_blocking_scalar_unpack!(msg, _, _, _, _,{ - manager.retrieve_db(); - xous::return_scalar(msg.sender, 1).unwrap(); - }), - Some(ActionOp::Quit) => { - break; - } - None => { - log::error!("msg could not be decoded {:?}", msg); - } - #[cfg(feature="vault-testing")] - Some(ActionOp::GenerateTests) => { - manager.populate_tests(); - manager.retrieve_db(); - } - } - } - xous::destroy_server(sid).ok(); - } - }); -} -*/ pub struct ActionManager<'a> { modals: modals::Modals, @@ -758,7 +669,10 @@ impl<'a> ActionManager<'a> { // remove the entry from the old UX list let mut desc = String::new(); make_pw_name(&pw.description, &pw.username, &mut desc); - + match self.item_lists.try_lock() { + Ok(_) => log::debug!("list is not locked"), + Err(_) => log::debug!("list is locked"), + } self.item_lists.lock().unwrap().remove(VaultMode::Password, ListItem::key_from_parts(&desc, key_name)); // display previous data for edit @@ -967,7 +881,7 @@ impl<'a> ActionManager<'a> { let mut extra = String::with_capacity(256); let mut desc = String::with_capacity(256); let mut lookup_key = String::with_capacity(384); - let il = self.item_lists.lock().unwrap(); + let mut il = self.item_lists.lock().unwrap(); for key in keys { #[cfg(feature="vaultperf")] self.perfentry(&self.pm, PERFMETA_STARTBLOCK, 2, std::line!()); @@ -988,13 +902,14 @@ impl<'a> ActionManager<'a> { #[cfg(feature="vaultperf")] self.perfentry(&self.pm, PERFMETA_NONE, 2, std::line!()); - if let Some(prev_entry) = il.get(self.mode_cache, &lookup_key) { + if let Some(prev_entry_locked) = il.get(self.mode_cache, &lookup_key) { + let mut prev_entry = prev_entry_locked.lock().unwrap(); #[cfg(feature="vaultperf")] self.perfentry(&self.pm, PERFMETA_STARTBLOCK, 3, std::line!()); - prev_entry.lock().unwrap().dirty = true; + prev_entry.dirty = true; #[cfg(feature="vaultperf")] self.perfentry(&self.pm, PERFMETA_NONE, 3, std::line!()); - if prev_entry.lock().unwrap().atime != pw_rec.atime || prev_entry.lock().unwrap().count != pw_rec.count { + if prev_entry.atime != pw_rec.atime || prev_entry.count != pw_rec.count { // this is expensive, so don't run it unless we have to let human_time = atime_to_str(pw_rec.atime); // note this code is duplicated in update_db_entry() @@ -1002,20 +917,20 @@ impl<'a> ActionManager<'a> { extra.push_str("; "); extra.push_str(t!("vault.u2f.appinfo.authcount", xous::LANG)); extra.push_str(&pw_rec.count.to_string()); - prev_entry.lock().unwrap().extra.clear(); - prev_entry.lock().unwrap().extra.push_str(&extra); + prev_entry.extra.clear(); + prev_entry.extra.push_str(&extra); } #[cfg(feature="vaultperf")] self.perfentry(&self.pm, PERFMETA_NONE, 3, std::line!()); - if prev_entry.lock().unwrap().name != desc { // this check should be redundant, but, leave it in to be safe - prev_entry.lock().unwrap().name.clear(); - prev_entry.lock().unwrap().name.push_str(&desc); + if prev_entry.name != desc { // this check should be redundant, but, leave it in to be safe + prev_entry.name.clear(); + prev_entry.name.push_str(&desc); } #[cfg(feature="vaultperf")] self.perfentry(&self.pm, PERFMETA_NONE, 3, std::line!()); - if prev_entry.lock().unwrap().guid != key.name { - prev_entry.lock().unwrap().guid.clear(); - prev_entry.lock().unwrap().guid.push_str(&key.name); + if prev_entry.guid != key.name { + prev_entry.guid.clear(); + prev_entry.guid.push_str(&key.name); } #[cfg(feature="vaultperf")] self.perfentry(&self.pm, PERFMETA_ENDBLOCK, 3, std::line!()); @@ -1038,8 +953,10 @@ impl<'a> ActionManager<'a> { atime: pw_rec.atime, count: pw_rec.count, }; - self.item_lists.lock().unwrap() - .insert(self.mode_cache, li.key(), li); // this push is very slow, but we only have to do it once on boot + unsafe { // safety: fixup_filter() is called after this loop + // this push is very slow, but we only have to do it once on boot + il.bulk_insert(self.mode_cache, li.key(), li); + } #[cfg(feature="vaultperf")] self.perfentry(&self.pm, PERFMETA_ENDBLOCK, 4, std::line!()); } @@ -1067,6 +984,8 @@ impl<'a> ActionManager<'a> { #[cfg(feature="vaultperf")] self.perfentry(&self.pm, PERFMETA_ENDBLOCK, 2, std::line!()); } + log::debug!("before fixup_filter: {}", self.tt.elapsed_ms() - start); + il.fixup_filter(); // meets the safety condition for bulk_insert() if oom_keys != 0 { log::warn!("Ran out of cache space handling password keys. {} keys are not loaded.", oom_keys); self.report_err(&format!("Ran out of cache space handling passwords. {} passwords not loaded", oom_keys), None::); @@ -1260,6 +1179,7 @@ impl<'a> ActionManager<'a> { } } } + self.item_lists.lock().unwrap().filter_reset(self.mode_cache); log::debug!("heap usage B: {}", heap_usage()); #[cfg(feature="vaultperf")] { diff --git a/apps/vault/src/itemcache.rs b/apps/vault/src/itemcache.rs index 4d6fa24e0..0500d06cb 100644 --- a/apps/vault/src/itemcache.rs +++ b/apps/vault/src/itemcache.rs @@ -90,6 +90,28 @@ impl ItemLists { selection_index: 0, } } + /// safety: caller must call fixup_filter() after successive calls to this are done. + pub unsafe fn bulk_insert(&mut self, list_type: VaultMode, key: String, item: ListItem) { + match list_type { + VaultMode::Fido => self.fido.insert(key, Arc::new(Mutex::new(item))), + VaultMode::Totp => self.totp.insert(key, Arc::new(Mutex::new(item))), + VaultMode::Password => self.pw.insert(key, Arc::new(Mutex::new(item))), + }; + } + pub fn fixup_filter(&mut self) { + // grow the filter to accommodate the largest possible list + let new_len = self.fido.len() + .max(self.totp.len()) + .max(self.pw.len()); + // clear the existing records + self.filtered_list.iter_mut().for_each(|i| *i = None); + self.valid_len = 0; + // fill in any growth with null records, guaranteeing that we can always index using slice offsets + for _ in 0..new_len.saturating_sub(self.filtered_list.len()) { + self.filtered_list.push(None); + } + self.max_len = new_len; + } pub fn insert(&mut self, list_type: VaultMode, key: String, item: ListItem) -> Option { let maybe_replaced = match list_type { VaultMode::Fido => self.fido.insert(key, Arc::new(Mutex::new(item))), @@ -101,12 +123,14 @@ impl ItemLists { VaultMode::Totp => self.totp.len(), VaultMode::Password => self.pw.len(), }; + // clear the filter, because we don't know where in the sort that the updated record should go... + self.filtered_list.iter_mut().for_each(|i| *i = None); + self.valid_len = 0; + // fill in any growth with null records, guaranteeing that we can always index using slice offsets for _ in 0..new_len.saturating_sub(self.filtered_list.len()) { - // fills in any growth with null records, guaranteeing that - // we can always index into the vector. self.filtered_list.push(None); } - self.max_len = new_len; + self.max_len = self.max_len.max(new_len); if let Some(replaced) = maybe_replaced { Some( Arc::<_>::try_unwrap(replaced).unwrap().into_inner().unwrap() @@ -129,9 +153,10 @@ impl ItemLists { VaultMode::Password => self.pw.remove(&key), }; if let Some(item) = maybe_item { + log::debug!("count bef: {}", Arc::<_>::strong_count(&item)); self.filtered_list.retain(|x| if let Some(filter_item) = x { - if filter_item.lock().unwrap().guid == item.lock().unwrap().guid { + if Arc::as_ptr(filter_item) == Arc::as_ptr(&item) { false // don't retain } else { true @@ -140,6 +165,7 @@ impl ItemLists { true } ); + log::debug!("count aft: {}", Arc::<_>::strong_count(&item)); Some( Arc::<_>::try_unwrap(item).unwrap().into_inner().unwrap() ) @@ -190,6 +216,9 @@ impl ItemLists { }; ts[2] = tt.elapsed_ms(); let mut filter_index = 0; + // search the whole list for now -- maybe optimize to a subset later on, + // but would require keeping two copies of the filtered list because we can't do + // in-place operation on an already filtered list for item in itemlist.values_mut() { if item.lock().unwrap().name.to_lowercase().starts_with(criteria) { item.lock().unwrap().dirty = true; @@ -211,7 +240,36 @@ impl ItemLists { log::info!("{}: {}", index + 1, elapsed - ts[0]); } } - pub fn nav(&mut self, list_type: VaultMode, dir: NavDir) { + /// Sets the filter's buffer to point to the entire contents of the specified list (no filtering) + pub fn filter_reset(&mut self, list_type: VaultMode) { + // clear the list + self.filtered_list.iter_mut().for_each(|i| *i = None); + self.valid_len = 0; + + let itemlist = match list_type { + VaultMode::Fido => &mut self.fido, + VaultMode::Totp => &mut self.totp, + VaultMode::Password => &mut self.pw, + }; + assert!(itemlist.len() <= self.filtered_list.len(), "consistency error in filter vector size"); + for (item, filt) + in itemlist.values_mut().zip(self.filtered_list.iter_mut()) { + item.lock().unwrap().dirty = true; + *filt = Some(item.clone()); + } + self.valid_len = itemlist.len(); + if self.selection_index >= self.valid_len { + if self.valid_len > 0 { + self.selection_index = self.valid_len - 1; + } else { + self.selection_index = 0; + } + } + } + pub fn filter_len(&self) -> usize { + self.valid_len + } + pub fn nav(&mut self, dir: NavDir) { match dir { NavDir::Up => { if self.selection_index > 0 { @@ -266,6 +324,13 @@ impl ItemLists { } } } + pub fn mark_all_dirty(&mut self) { + for maybe_item in self.filtered_list.iter_mut() { + if let Some(item) = maybe_item { + item.lock().unwrap().dirty = true; + } + } + } fn mark_screen_as_dirty(&mut self, index: usize) { let page = index as i16 / self.items_per_screen.get() as i16; for item in self.filtered_list[ @@ -311,21 +376,23 @@ impl ItemLists { self.filtered_list[self.selection_index].as_mut().unwrap().lock().unwrap().dirty = true; } pub fn selected_entry(&self, mode: VaultMode) -> Option { - if self.selection_index > self.valid_len { + let ret = if self.selection_index > self.valid_len { None } else { if let Some(entry) = &self.filtered_list[self.selection_index] { + let guarded_entry = entry.lock().unwrap(); Some( SelectedEntry { - key_name: xous_ipc::String::from_str(entry.lock().unwrap().guid.to_string()), - description: xous_ipc::String::from_str(entry.lock().unwrap().name.to_string()), + key_name: xous_ipc::String::from_str(guarded_entry.guid.to_string()), + description: xous_ipc::String::from_str(guarded_entry.name.to_string()), mode } ) } else { None } - } + }; + ret } } \ No newline at end of file diff --git a/apps/vault/src/main.rs b/apps/vault/src/main.rs index aab925600..65b76f284 100644 --- a/apps/vault/src/main.rs +++ b/apps/vault/src/main.rs @@ -113,7 +113,7 @@ const ERR_TIMEOUT_MS: usize = 5000; fn main() -> ! { log_server::init_wait().unwrap(); - log::set_max_level(log::LevelFilter::Info); + log::set_max_level(log::LevelFilter::Debug); log::info!("my PID is {}", xous::process::id()); let xns = xous_names::XousNames::new().unwrap(); @@ -171,7 +171,9 @@ fn main() -> ! { Some(ActionOp::MenuEditStage2) => { let buffer = unsafe { Buffer::from_memory_message(msg.body.memory_message().unwrap()) }; let entry = buffer.to_original::().unwrap(); + log::debug!("bef activate"); manager.activate(); + log::debug!("bef edit"); manager.menu_edit(entry); manager.retrieve_db(); manager.deactivate(); @@ -657,6 +659,7 @@ fn main() -> ! { } Some(VaultOp::MenuEditStage1) => { // stage 1 happens here because the filtered list and selection entry are in the responsive UX section. + log::debug!("selecting entry for edit"); if let Some(entry) = vaultux.selected_entry() { let buf = Buffer::into_buf(entry).expect("IPC error"); buf.send(actions_conn, ActionOp::MenuEditStage2.to_u32().unwrap()).expect("messaging error"); diff --git a/apps/vault/src/ux/framework.rs b/apps/vault/src/ux/framework.rs index 2fc85af3f..71e8b270e 100644 --- a/apps/vault/src/ux/framework.rs +++ b/apps/vault/src/ux/framework.rs @@ -16,7 +16,6 @@ use std::convert::TryFrom; use usb_device_xous::UsbDeviceType; use locales::t; use num_traits::*; -use crate::ListItem; pub enum NavDir { Up, @@ -45,8 +44,6 @@ pub struct VaultUx { /// list of all items to be displayed item_lists: Arc::>, - /// list of items displayable after filtering - filtered_list: Vec::, /// last filter query, so we can re-use it when mode is changed last_query: String, @@ -141,7 +138,6 @@ impl VaultUx { mode, title_dirty: true, item_lists, - filtered_list: Vec::new(), pddb: RefCell::new(pddb), style, item_height, @@ -240,12 +236,12 @@ impl VaultUx { GlyphStyle::Regular }, }; - // force redraw of all the items - self.title_dirty = true; - for item in self.filtered_list.iter_mut() { - item.dirty = true; + if self.style != style { + // force redraw of all the items + self.title_dirty = true; + self.item_lists.lock().unwrap().mark_all_dirty(); + self.style = style; } - self.style = style; let available_height = self.screensize.y - TITLE_HEIGHT; let glyph_height = self.gam.glyph_height_hint(self.style).unwrap(); self.item_height = (glyph_height * 2) as i16 + self.margin.y * 2 + 2; // +2 because of the border width @@ -271,7 +267,7 @@ impl VaultUx { self.get_glyph_style(); } pub(crate) fn nav(&mut self, dir: NavDir) { - self.item_lists.lock().unwrap().nav(self.mode.lock().unwrap().clone(), dir); + self.item_lists.lock().unwrap().nav(dir); } /// accept a new input string pub(crate) fn input(&mut self, line: &str) -> Result<(), xous::Error> { @@ -285,7 +281,7 @@ impl VaultUx { let items_height = self.items_per_screen * self.item_height; let mut insert_at = 1 + self.screensize.y - items_height; // +1 to get the border to overlap at the bottom - if self.filtered_list.len() == 0 || self.action_active.load(AtomicOrdering::SeqCst) { + if self.item_lists.lock().unwrap().filter_len() == 0 || self.action_active.load(AtomicOrdering::SeqCst) { // no items in list case -- just blank the whole area self.gam.draw_rectangle(self.content, Rectangle::new_with_style( @@ -299,7 +295,7 @@ impl VaultUx { )).expect("can't clear content area"); self.title_dirty = true; // just blanked the whole area, have to redraw the title. return; - } else if self.title_dirty && self.filtered_list.len() != 0 { + } else if self.title_dirty && self.item_lists.lock().unwrap().filter_len() != 0 { // handle the title region separately self.gam.draw_rectangle(self.content, Rectangle::new_with_style( @@ -396,9 +392,7 @@ impl VaultUx { if self.last_epoch != epoch { self.last_epoch = epoch; // force a redraw of all the items if the epoch has changed - for item in self.filtered_list.iter_mut() { - item.dirty = true; - } + self.item_lists.lock().unwrap().mark_all_dirty(); } } self.clear_area(); @@ -449,7 +443,7 @@ impl VaultUx { let items_height = self.items_per_screen * self.item_height; let mut insert_at = 1 + self.screensize.y - items_height; // +1 to get the border to overlap at the bottom - if self.filtered_list.len() == 0 { + if self.item_lists.lock().unwrap().filter_len() == 0 { let mut box_text = TextView::new(self.content, graphics_server::TextBounds::CenteredBot( Rectangle::new( @@ -470,6 +464,7 @@ impl VaultUx { let selected = self.item_lists.lock().unwrap().selected_index(); let mut guarded_list = self.item_lists.lock().unwrap(); let current_page = guarded_list.selected_page(); + log::debug!("current_page len {}", current_page.len()); for (index, maybe_item) in current_page.iter_mut().enumerate() { if insert_at - 1 > self.screensize.y - self.item_height { // -1 because of the overlapping border break; @@ -477,6 +472,7 @@ impl VaultUx { if let Some(item_mutex) = maybe_item { let mut item = item_mutex.lock().unwrap(); if item.dirty { + log::debug!("drawing {}", item.name); let mut box_text = TextView::new(self.content, graphics_server::TextBounds::BoundingBox( Rectangle::new( @@ -776,9 +772,8 @@ impl VaultUx { Ok(()) } pub(crate) fn selected_entry(&self) -> Option { - self.item_lists.lock().unwrap().selected_entry( - (*self.mode.lock().unwrap()).clone() - ) + let mode = (*self.mode.lock().unwrap()).clone(); + self.item_lists.lock().unwrap().selected_entry(mode) } pub(crate) fn ensure_hid(&self) { self.usb_dev.ensure_core(self.usb_type).unwrap(); diff --git a/services/pddb/src/lib.rs b/services/pddb/src/lib.rs index 9b2203c94..a2b1838c0 100644 --- a/services/pddb/src/lib.rs +++ b/services/pddb/src/lib.rs @@ -1046,7 +1046,7 @@ impl Pddb { index += size_of::(); let pos = u32::from_le_bytes(msg_mem.as_slice()[index..index + size_of::()].try_into().unwrap()); index += size_of::(); - log::debug!("unpacking message at {}({})", size, pos); + log::trace!("unpacking message at {}({})", size, pos); if size != 0 && pos != 0 { //log::info!("extract archive: {}, {}, {}, {}", index, size, pos, msg_mem.len()); //log::info!("{:x?}", &msg_mem.as_slice::()[index..index + (size as usize)]);