using Timer with read_binary

abstutil/src/io.rs

@@ -10,7 +10,7 @@ use std::hash::Hash;
 use std::io::{stdout, BufReader, Error, ErrorKind, Read, Write};
 use std::path::Path;
 use std::time::Instant;
-use {elapsed_seconds, PROGRESS_FREQUENCY_SECONDS};
+use {elapsed_seconds, Timer, PROGRESS_FREQUENCY_SECONDS};
 
 pub fn to_json<T: Serialize>(obj: &T) -> String {
     serde_json::to_string_pretty(obj).unwrap()
@@ -46,8 +46,9 @@ pub fn write_binary<T: Serialize>(path: &str, obj: &T) -> Result<(), Error> {
     serde_cbor::to_writer(&mut file, obj).map_err(|err| Error::new(ErrorKind::Other, err))
 }
 
-pub fn read_binary<T: DeserializeOwned>(path: &str) -> Result<T, Error> {
+pub fn read_binary<T: DeserializeOwned>(path: &str, timer: &mut Timer) -> Result<T, Error> {
     let reader = FileWithProgress::new(path)?;
+    timer.add_file_reader_result(reader.get_timer_result());
     let obj: T =
         serde_cbor::from_reader(reader).map_err(|err| Error::new(ErrorKind::Other, err))?;
     Ok(obj)
@@ -194,6 +195,15 @@ impl FileWithProgress {
             last_printed_at: Instant::now(),
         })
     }
+
+    fn get_timer_result(&self) -> String {
+        format!(
+            "Reading {} ({} MB)... {}s",
+            self.path,
+            self.total_bytes / 1024 / 1024,
+            elapsed_seconds(self.started_at)
+        )
+    }
 }
 
 impl Read for FileWithProgress {

abstutil/src/time.rs

@@ -151,4 +151,9 @@ impl Timer {
             self.stack.pop();
         }
     }
+
+    pub(crate) fn add_file_reader_result(&mut self, line: String) {
+        self.results
+            .push(format!("{} - {}", "  ".repeat(self.stack.len()), line));
+    }
 }

convert_osm/src/lib.rs

@@ -65,6 +65,8 @@ pub struct Flags {
 }
 
 pub fn convert(flags: &Flags) -> raw_data::Map {
+    let mut timer = abstutil::Timer::new();
+
     let elevation = Elevation::new(&flags.elevation).expect("loading .hgt failed");
     let raw_map = osm::osm_to_raw_roads(&flags.osm);
     let mut map = split_ways::split_up_roads(&raw_map, &elevation);
@@ -73,7 +75,7 @@ pub fn convert(flags: &Flags) -> raw_data::Map {
 
     println!("Loading parcels from {}", flags.parcels);
     let parcels_map: raw_data::Map =
-        abstutil::read_binary(&flags.parcels).expect("loading parcels failed");
+        abstutil::read_binary(&flags.parcels, &mut timer).expect("loading parcels failed");
     println!(
         "Finding matching parcels from {} candidates",
         parcels_map.parcels.len()
@@ -124,5 +126,7 @@ pub fn convert(flags: &Flags) -> raw_data::Map {
         .unwrap();
     neighborhoods::convert(&flags.neighborhoods, map_name, &bounds);
 
+    timer.done();
+
     map
 }

map_model/src/make/bus_stops.rs

@@ -102,10 +102,12 @@ pub fn make_bus_stops(
     (bus_stops, routes)
 }
 
-pub fn verify_bus_routes(map: &Map, routes: Vec<BusRoute>) -> Vec<BusRoute> {
+pub fn verify_bus_routes(map: &Map, routes: Vec<BusRoute>, timer: &mut Timer) -> Vec<BusRoute> {
+    timer.start_iter("verify bus routes are connected", routes.len());
     routes
         .into_iter()
         .filter(|r| {
+            timer.next();
             let mut ok = true;
             for (stop1, stop2) in r
                 .stops

map_model/src/map.rs

@@ -35,10 +35,7 @@ pub struct Map {
 
 impl Map {
     pub fn new(path: &str, road_edits: RoadEdits, timer: &mut Timer) -> Result<Map, io::Error> {
-        // TODO use read_binary's timer magic, not this
-        timer.start("read raw_data");
-        let data: raw_data::Map = abstutil::read_binary(path)?;
-        timer.stop("read raw_data");
+        let data: raw_data::Map = abstutil::read_binary(path, timer)?;
         Ok(Map::create_from_raw(
             path::Path::new(path)
                 .file_stem()
@@ -228,7 +225,7 @@ impl Map {
             });
         }
 
-        m.bus_routes = make::verify_bus_routes(&m, routes);
+        m.bus_routes = make::verify_bus_routes(&m, routes, timer);
 
         timer.stop("raw_map to Map");
         m

sim/src/helpers.rs

@@ -58,10 +58,10 @@ pub fn load(
         )).unwrap();
 
         // Try loading the pre-baked map first
-        let map: Map = abstutil::read_binary(&format!(
-            "../data/maps/{}_{}.abst",
-            sim.map_name, sim.edits_name
-        )).unwrap_or_else(|_| {
+        let map: Map = abstutil::read_binary(
+            &format!("../data/maps/{}_{}.abst", sim.map_name, sim.edits_name),
+            timer,
+        ).unwrap_or_else(|_| {
             let map_path = format!("../data/raw_maps/{}.abst", sim.map_name);
             Map::new(&map_path, edits.road_edits.clone(), timer)
                 .expect(&format!("Couldn't load map from {}", map_path))
@@ -75,10 +75,13 @@ pub fn load(
         let edits = load_edits(&scenario.map_name, &flags);
 
         // Try loading the pre-baked map first
-        let map: Map = abstutil::read_binary(&format!(
-            "../data/maps/{}_{}.abst",
-            scenario.map_name, edits.edits_name
-        )).unwrap_or_else(|_| {
+        let map: Map = abstutil::read_binary(
+            &format!(
+                "../data/maps/{}_{}.abst",
+                scenario.map_name, edits.edits_name
+            ),
+            timer,
+        ).unwrap_or_else(|_| {
             let map_path = format!("../data/raw_maps/{}.abst", scenario.map_name);
             Map::new(&map_path, edits.road_edits.clone(), timer)
                 .expect(&format!("Couldn't load map from {}", map_path))
@@ -113,10 +116,7 @@ pub fn load(
         assert_eq!(flags.edits_name, "no_edits");
 
         info!("Loading map {}", flags.load);
-        // TODO dont do this
-        timer.start("load binary map");
-        let map: Map = abstutil::read_binary(&flags.load).expect("Couldn't load map");
-        timer.stop("load binary map");
+        let map: Map = abstutil::read_binary(&flags.load, timer).expect("Couldn't load map");
         // TODO Bit sad to load edits to reconstitute ControlMap, but this is necessary right now
         let edits: MapEdits = abstutil::read_json(&format!(
             "../data/edits/{}/{}.json",