test map loading speed

strafe-client/src/file.rs

@@ -34,11 +34,20 @@ pub enum ReadFormat{
 }
 
 pub fn read<R:Read+std::io::Seek>(input:R)->Result<ReadFormat,ReadError>{
+	let t=std::time::Instant::now();
+	println!("reading fourcc...");
 	let mut buf=std::io::BufReader::new(input);
 	let peek=std::io::BufRead::fill_buf(&mut buf).map_err(ReadError::Io)?[0..4].to_owned();
+	let dt=t.elapsed();
+	println!("{:?} elapsed={:?}",core::str::from_utf8(&peek),dt);
+
+	let t=std::time::Instant::now();
+	println!("reading entire file...");
 	// reading the entire file is way faster than round tripping the disk constantly
 	let mut entire_file=Vec::new();
 	buf.read_to_end(&mut entire_file).map_err(ReadError::Io)?;
+	println!("elapsed={:?}",t.elapsed());
+
 	let cursor=std::io::Cursor::new(entire_file);
 	match peek.as_slice(){
 		#[cfg(feature="roblox")]
@@ -46,10 +55,15 @@ pub fn read<R:Read+std::io::Seek>(input:R)->Result<ReadFormat,ReadError>{
 		#[cfg(feature="source")]
 		b"VBSP"=>Ok(ReadFormat::Source(strafesnet_bsp_loader::read(cursor).map_err(ReadError::Source)?)),
 		#[cfg(feature="snf")]
-		b"SNFM"=>Ok(ReadFormat::SNFM(
+		b"SNFM"=>{
-			strafesnet_snf::read_map(cursor).map_err(ReadError::StrafesNET)?
+			let t=std::time::Instant::now();
-			.into_complete_map().map_err(ReadError::StrafesNETMap)?
+			println!("decoding map...");
-		)),
+			let map=
+				strafesnet_snf::read_map(cursor).map_err(ReadError::StrafesNET)?
+				.into_complete_map().map_err(ReadError::StrafesNETMap)?;
+			println!("elapsed={:?}",t.elapsed());
+			Ok(ReadFormat::SNFM(map))
+		},
 		#[cfg(feature="snf")]
 		b"SNFB"=>Ok(ReadFormat::SNFB(
 			strafesnet_snf::read_bot(cursor).map_err(ReadError::StrafesNET)?