Fixed tracing causing huge unneeded bottleneck in non `bytes` builds.

Fortune for collect's current commit: Future small blessing − 末小吉

.gitignore

@@ -7,3 +7,4 @@
 perf.*
 vgcore.*
 
+collect-*

Cargo.toml

@@ -6,7 +6,7 @@ edition = "2021"
 # See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html
 
 [features]
-default = ["jemalloc"]
+default = ["jemalloc", "tracing/release_max_level_warn"]
 
 # TODO: mmap, memfd_create() ver
 
@@ -17,6 +17,9 @@ default = ["jemalloc"]
 # Seems to reduce overall memory usage at the cost of a very small speed drop.
 jemalloc = ["jemallocator"]
 
+# Remove all tracing points
+no-logging = ["tracing/max_level_off"]
+
 [profile.release]
 opt-level = 3
 lto = "fat"
@@ -29,7 +32,7 @@ inherits="release"
 strip=false
 
 [dependencies]
-bytes = {version = "1.1.0", optional = true }
+bytes = { version = "1.1.0", optional = true }
 color-eyre = { version = "0.6.1", features = ["capture-spantrace"] }
 jemallocator = { version = "0.3.2", optional = true }
 libc = "0.2.122"

src/buffers.rs

@@ -85,6 +85,7 @@ const _: () = {
 impl<'a, B: ?Sized + Buffer> io::Read for BufferReader<'a, B>
 {
     #[inline] 
+    #[instrument(level="trace", skip_all, fields(buf = ?buf.len()))]
     fn read(&mut self, buf: &mut [u8]) -> io::Result<usize> {
 	let adv = self.0.copy_to_slice(self.1, buf);
 	self.1 += adv;
@@ -95,7 +96,7 @@ impl<'a, B: ?Sized + Buffer> io::Read for BufferReader<'a, B>
 impl<'a, B: ?Sized + MutBuffer> io::Write for BufferWriter<'a, B>
 {
     #[inline]
-    #[instrument(skip(self))]
+    #[instrument(level="trace", skip_all, fields(buf = ?buf.len()))]
     fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
 	let adv = self.0.copy_from_slice(self.1, buf);
 	
@@ -112,7 +113,8 @@ impl<'a, B: ?Sized + MutBuffer> io::Write for BufferWriter<'a, B>
 /// An immutable contiguous buffer
 pub trait Buffer: AsRef<[u8]>
 {
-    #[inline] 
+    #[inline]
+    #[instrument(level="trace", skip_all, fields(buf = ?slice.len()))]
     fn copy_to_slice(&self, st: usize, slice: &mut [u8]) -> usize
     {
 	let by = self.as_ref();
@@ -160,7 +162,7 @@ pub trait MutBuffer: AsMut<[u8]>
     fn freeze(self) -> Self::Frozen;
 
     #[inline]
-    #[instrument(skip(self))]
+    #[instrument(level="debug", skip_all, fields(st, buflen = ?slice.len()))]
     fn copy_from_slice(&mut self, st: usize, slice: &[u8]) -> usize
     {
 	let by = self.as_mut();
@@ -187,13 +189,14 @@ pub trait MutBuffer: AsMut<[u8]>
 pub trait MutBufferExt: MutBuffer
 {
     #[inline(always)]
-    #[instrument(skip(self))]
+    #[instrument(level="info", skip(self))]
     fn writer_from(&mut self, st: usize) -> BufferWriter<'_, Self>
     {
+	debug!("creating writer at start {st}");
 	BufferWriter(self, st)
     }
     #[inline]
-    #[instrument(skip(self))]
+    //#[instrument(level="info", skip(self))]
     fn writer(&mut self) -> BufferWriter<'_, Self>
     {
 	self.writer_from(0)
@@ -205,23 +208,44 @@ impl<B: ?Sized + MutBuffer> MutBufferExt for B{}
 impl MutBuffer for bytes::BytesMut
 {
     type Frozen = bytes::Bytes;
-    #[inline(always)] 
+    
+    #[inline(always)]
+    #[instrument(level="trace")]
     fn freeze(self) -> Self::Frozen {
 	bytes::BytesMut::freeze(self)
     }
     //TODO: XXX: Impl copy_from_slice() as is done in impl for Vec<u8>
+    /*#[instrument]
+    fn copy_from_slice(&mut self, st: usize, buf: &[u8]) -> usize
+    {
+    //TODO: Special case for `st == 0` maybe? No slicing of the BytesMut might increase perf? Idk.
+    if  (st + buf.len()) <= self.len() {
+    // We can put `buf` in st..buf.len()
+    self[st..].copy_from_slice(buf); 
+} else if  st <= self.len() {
+    // The start is lower but the end is not
+    let rem = self.len() - st;
+    self[st..].copy_from_slice(&buf[..rem]);
+    self.extend_from_slice(&buf[rem..]);
+} else {
+    // it is past the end, extend.
+    self.extend_from_slice(buf);
+}
+    buf.len()
+}*/
 }
 
 impl MutBuffer for Vec<u8>
 {
     type Frozen = Box<[u8]>;
+    
     #[inline]
-    #[instrument]
+    #[instrument(level="trace")]
     fn freeze(self) -> Self::Frozen {
 	self.into_boxed_slice()
     }
 
-    #[instrument]
+    #[instrument(level="trace", skip_all, fields(st, buflen = ?buf.len()))]
     fn copy_from_slice(&mut self, st: usize, buf: &[u8]) -> usize
     {
 	if  (st + buf.len()) <= self.len() {
@@ -249,12 +273,16 @@ pub trait WithCapacity: Sized
 
 impl WithCapacity for Box<[u8]>
 {
-    #[inline(always)] 
+    #[inline(always)]
+    #[instrument(level="info", fields(cap = "(unbound)"))]
     fn wc_new() -> Self {
+	info!("creating new boxed slice with size 0");
 	Vec::wc_new().into_boxed_slice()
     }
-    #[inline(always)] 
+    #[inline(always)]
+    #[instrument(level="info")]
     fn wc_with_capacity(cap: usize) -> Self {
+	info!("creating new boxed slice with size {cap}");
 	Vec::wc_with_capacity(cap).into_boxed_slice()
     }
 }
@@ -308,14 +336,18 @@ macro_rules! cap_buffer  {
     ($name:ty) => {
 	impl $crate::buffers::WithCapacity for $name
 	{
-	    #[inline(always)] 
+	    #[inline(always)]
+	    #[instrument(level="info", fields(cap = "(unbound)"))]
 	    fn wc_new() -> Self
 	    {
+		info!("creating {} with no cap", std::any::type_name::<Self>());
 		Self::new()
 	    }
-	    #[inline(always)] 
+	    #[inline(always)]
+	    #[instrument(level="info")]
 	    fn wc_with_capacity(cap: usize) -> Self
 	    {
+		info!("creating {} with {cap}", std::any::type_name::<Self>());
 		Self::with_capacity(cap)
 	    }
 	}
@@ -360,5 +392,7 @@ pub mod prelude
 
 pub(crate) use cap_buffer;
 
+// cap_buffer impls
+
 #[cfg(feature="bytes")] buffers::cap_buffer!(bytes::BytesMut);
 cap_buffer!(Vec<u8>);

src/main.rs

@@ -37,6 +37,7 @@ use bytes::{
     BufMut,
 };
 
+#[instrument(level="debug", skip(reader), fields(reader = ?std::any::type_name::<R>()))]
 fn try_get_size<R: ?Sized>(reader: &R) -> Option<NonZeroUsize>
 where R: AsRawFd
 {
@@ -70,33 +71,43 @@ fn init() -> eyre::Result<()>
 	use tracing_subscriber::prelude::*;
 	use tracing_subscriber::{fmt, EnvFilter};
 
-	let fmt_layer = fmt::layer().with_target(false);
+	let fmt_layer = fmt::layer()
+	    .with_target(false)
+	    .with_writer(io::stderr);
+	
 	let filter_layer = EnvFilter::try_from_default_env()
-	    .or_else(|_| EnvFilter::try_new("info"))
+	    .or_else(|_| EnvFilter::try_new(if cfg!(debug_assertions) {
+		"info"
+	    } else if cfg!(feature="no-logging") {
+		"off"
+	    } else {
+		"warn"
+	    }))
 	    .unwrap();
 
 	tracing_subscriber::registry()
-	    .with(filter_layer)
 	    .with(fmt_layer)
+	    .with(filter_layer)
 	    .with(ErrorLayer::default())
 	    .init();
     }
-    
+
-    install_tracing();
+    //if !cfg!(feature="no-logging") {
+	install_tracing();
+    //}
     
     color_eyre::install()
 }
 
-#[instrument]
+#[instrument(err)]
 fn main() -> eyre::Result<()> {
     init()?;
-    //info!("Initialised");
     
     let (bytes, read) = {
 	let stdin = io::stdin();
 	let mut bytes: buffers::DefaultMut = try_get_size(&stdin).create_buffer();
 	
-	let read = io::copy(&mut stdin.lock(), &mut bytes.writer())
+	let read = io::copy(&mut stdin.lock(), &mut (&mut bytes).writer())
 	    .with_section(|| bytes.len().header("Buffer size is"))
 	    .with_section(|| bytes.capacity().header("Buffer cap is"))
 	    .with_section(|| format!("{:?}", bytes).header("Buffer is"))