Skip to content

Commit

Permalink
[write-fonts] Improve packing diagnostics & logging
Browse files Browse the repository at this point in the history 
This is mostly just a cleanup of various log statements, and a general
attempt to rationalize our logging: choosing higher levels for less
frequent, more important messages, and ensuring that logging provides
overall good visibility into packing behaviour.

This patch includes a few other related tweaks to panic messages and
other debug printing code.
  • Loading branch information
@cmyr
cmyr committed Sep 12, 2023
1 parent bfb8d56 commit 51769de
Show file tree
Hide file tree
Showing 2 changed files with 46 additions and 22 deletions.
56 changes: 37 additions & 19 deletions write-fonts/src/graph.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -131,6 +131,7 @@ struct Priority(u8);

/// A record of an overflowing offset
#[derive(Clone, Debug)]
#[allow(dead_code)] // my debugging needs change over time
pub(crate) struct Overflow {
parent: ObjectId,
child: ObjectId,
Expand Down Expand Up @@ -305,22 +306,26 @@ impl Graph {
return true;
}

log::info!("basic sorting failed, trying splitting & promotion");

self.try_splitting_subtables();
self.try_promoting_subtables();

log::info!("assigning spaces");
self.assign_spaces_hb();
self.sort_shortest_distance();

if !self.has_overflows() {
log::debug!("packing succeded");
return true;
}

log::debug!("packing failed, trying to isolate subgraphs");

// now isolate spaces in a loop, until there are no more left:
let overflows = loop {
let overflows = self.find_overflows();
if overflows.is_empty() {
// we're done
log::info!("resolved overflows successfully");
return true;
}
log::trace!(
Expand All @@ -329,7 +334,11 @@ impl Graph {
self.debug_len()
);
if !self.try_isolating_subgraphs(&overflows) {
log::debug!("finished isolating all subgraphs without solution");
// if we stop making forward progress, we stop trying.
// NOTE: harfbuzz tries some additional resolution strategies
// here, but that is largely legacy code and we don't know if
// we need it.
log::error!("finished isolating all subgraphs without solution");
break overflows;
}
self.sort_shortest_distance();
Expand All @@ -347,13 +356,11 @@ impl Graph {
///
/// returns `true` if sort succeeds with no overflows
fn basic_sort(&mut self) -> bool {
log::trace!("sorting {} objects", self.objects.len());

self.sort_kahn();
if !self.has_overflows() {
return true;
}
log::trace!("kahn failed, trying shortest distance");
log::debug!("kahn failed, trying shortest distance");
self.sort_shortest_distance();
!self.has_overflows()
}
Expand Down Expand Up @@ -404,12 +411,19 @@ impl Graph {
children.len()
);

for overflow in overflows {
log::debug!(
"{:?} -> {:?} type {} dist {}",
overflow.parent,
overflow.child,
overflow.offset_type,
for overflow in overflows
.iter()
// if we have 5k overflows we don't need to print them all
.take(100)
{
let child = &self.objects[&overflow.child];
let parent = &self.objects[&overflow.parent];
log::trace!(
"{} ({}) -> {} ({}) dist {}",
overflow.parent.0,
parent.type_,
overflow.child.0,
child.type_,
overflow.distance
);
}
Expand Down Expand Up @@ -726,7 +740,7 @@ impl Graph {
}

let next_space = self.next_space();
log::debug!("moved {} roots to {next_space:?}", roots.len(),);
log::trace!("moved {} roots to {next_space:?}", roots.len(),);
self.num_roots_per_space.insert(next_space, roots.len());
let mut id_map = HashMap::new();
//let mut made_changes = false;
Expand Down Expand Up @@ -816,9 +830,7 @@ impl Graph {
debug_assert!(n_total_roots >= 2, "checked in the loop above");
let max_to_move = n_total_roots / 2;
log::trace!(
"moving {} of {} candidate roots from {space:?} to new space",
max_to_move.min(roots.len()),
roots.len()
"moving {max_to_move} of {} candidate roots ({n_total_roots} total) from {space:?} to new space", roots.len(),
);
while roots.len() > max_to_move {
roots.pop_last();
Expand Down Expand Up @@ -848,6 +860,7 @@ impl Graph {

fn try_promoting_subtables(&mut self) {
let Some((can_promote, parent_id)) = self.get_promotable_subtables() else {
log::info!("found no subtables to promote");
return;
};
let to_promote = self.select_promotions_hb(&can_promote, parent_id);
Expand Down Expand Up @@ -936,11 +949,15 @@ impl Graph {
// the only promotable subtables should be lookups, and there should
// be a single LookupList that is their parent; if there is more than
// one parent then something weird is going on.
if parents.len() > 1 {
if parents.len() != 1 {
if cfg!(debug_assertions) {
panic!("Promotable subtables exist with multiple parents");
panic!(
"Promotable subtables have unexpected number of parents.\n\
If this happens during a test, you probably need to embed
the lookup in a lookuplist."
);
} else {
log::warn!("Promotable subtables exist with multiple parents");
log::warn!("Promotable subtables exist with none or multiple parents");
return None;
}
}
Expand Down Expand Up @@ -1044,6 +1061,7 @@ impl Graph {
.iter()
.filter_map(|(id, obj)| obj.type_.is_splittable().then_some(*id))
.collect::<Vec<_>>();
log::debug!("found {} splittable subtables", splittable.len());
for lookup in &splittable {
self.split_subtables_if_needed(*lookup);
}
Expand Down
12 changes: 9 additions & 3 deletions write-fonts/src/graph/splitting.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -42,7 +42,11 @@ fn split_subtables(
data.reparse::<rgpos::PositionLookup>().is_ok(),
"table splitting is only relevant for GPOS?"
);
log::debug!("trying to split subtables in '{}'", data.type_);
log::debug!(
"trying to split subtables in lookup '{}' with {} subtables",
data.type_,
data.offsets.len()
);

let mut new_subtables = HashMap::new();
for (i, subtable) in data.offsets.iter().enumerate() {
Expand All @@ -64,8 +68,8 @@ fn split_subtables(
// - 1 because each group of new subtables replaces an old subtable
.map(|ids| ids.len() - 1)
.sum::<usize>();
log::debug!("Splitting produced {n_new_subtables} new subtables");

log::debug!("splitting produced {n_new_subtables} new subtables");
let n_total_subtables: u16 = (data.offsets.len() + n_new_subtables).try_into().unwrap();
// we just want the lookup type/flag/etc, but we need a generic FontRead type
let generic_lookup: rlayout::Lookup<()> = data.reparse().unwrap();
Expand Down Expand Up @@ -101,6 +105,7 @@ fn split_pair_pos_subtable(graph: &mut Graph, lookup: ObjectId) -> Option<Vec<Ob
// <https://github.com/harfbuzz/harfbuzz/blob/5d543d64222c6ce45332d0c188790f90691ef112/src/graph/pairpos-graph.hh#L50>
fn split_pair_pos_format_1(graph: &mut Graph, subtable: ObjectId) -> Option<Vec<ObjectId>> {
const BASE_SIZE: usize = 5 * u16::RAW_BYTE_LEN;
log::debug!("splitting PairPos format 1 subtable");

let data = &graph.objects[&subtable];

Expand Down Expand Up @@ -150,11 +155,12 @@ fn split_pair_pos_format_1(graph: &mut Graph, subtable: ObjectId) -> Option<Vec<
}
}

log::debug!(
log::trace!(
"nothing to split, size '{}'",
accumulated + coverage_size.min(partial_coverage_size)
);

log::debug!("identified {} split points", split_points.len());
if split_points.is_empty() {
return None;
}
Expand Down

0 comments on commit 51769de

Please sign in to comment.