Skip to content

feat(lib): switch from log to tracing #475

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 3 commits into from
Jul 7, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -47,7 +47,7 @@ tokio-util = { version = "0.3.1", features = ["codec"] }
tokio = { version = "0.2", features = ["io-util"] }
bytes = "0.5.2"
http = "0.2"
log = "0.4.1"
tracing = { version = "0.1.13", default-features = false, features = ["std", "log"] }
fnv = "1.0.5"
slab = "0.4.0"
indexmap = "1.0"
Expand Down
4 changes: 2 additions & 2 deletions src/client.rs
Original file line number Diff line number Diff line change
Expand Up @@ -1129,12 +1129,12 @@ where
mut io: T,
builder: Builder,
) -> Result<(SendRequest<B>, Connection<T, B>), crate::Error> {
log::debug!("binding client connection");
tracing::debug!("binding client connection");

let msg: &'static [u8] = b"PRI * HTTP/2.0\r\n\r\nSM\r\n\r\n";
io.write_all(msg).await.map_err(crate::Error::from_io)?;

log::debug!("client connection bound");
tracing::debug!("client connection bound");

// Create the codec
let mut codec = Codec::new(io);
Expand Down
12 changes: 6 additions & 6 deletions src/codec/framed_read.rs
Original file line number Diff line number Diff line change
Expand Up @@ -62,7 +62,7 @@ impl<T> FramedRead<T> {
fn decode_frame(&mut self, mut bytes: BytesMut) -> Result<Option<Frame>, RecvError> {
use self::RecvError::*;

log::trace!("decoding frame from {}B", bytes.len());
tracing::trace!("decoding frame from {}B", bytes.len());

// Parse the head
let head = frame::Head::parse(&bytes);
Expand All @@ -74,7 +74,7 @@ impl<T> FramedRead<T> {

let kind = head.kind();

log::trace!(" -> kind={:?}", kind);
tracing::trace!(" -> kind={:?}", kind);

macro_rules! header_block {
($frame:ident, $head:ident, $bytes:ident) => ({
Expand Down Expand Up @@ -124,7 +124,7 @@ impl<T> FramedRead<T> {
if is_end_headers {
frame.into()
} else {
log::trace!("loaded partial header block");
tracing::trace!("loaded partial header block");
// Defer returning the frame
self.partial = Some(Partial {
frame: Continuable::$frame(frame),
Expand Down Expand Up @@ -339,16 +339,16 @@ where

fn poll_next(mut self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll<Option<Self::Item>> {
loop {
log::trace!("poll");
tracing::trace!("poll");
let bytes = match ready!(Pin::new(&mut self.inner).poll_next(cx)) {
Some(Ok(bytes)) => bytes,
Some(Err(e)) => return Poll::Ready(Some(Err(map_err(e)))),
None => return Poll::Ready(None),
};

log::trace!("poll; bytes={}B", bytes.len());
tracing::trace!("poll; bytes={}B", bytes.len());
if let Some(frame) = self.decode_frame(bytes)? {
log::debug!("received; frame={:?}", frame);
tracing::debug!("received; frame={:?}", frame);
return Poll::Ready(Some(Ok(frame)));
}
}
Expand Down
22 changes: 11 additions & 11 deletions src/codec/framed_write.rs
Original file line number Diff line number Diff line change
Expand Up @@ -106,7 +106,7 @@ where
// Ensure that we have enough capacity to accept the write.
assert!(self.has_capacity());

log::debug!("send; frame={:?}", item);
tracing::debug!("send; frame={:?}", item);

match item {
Frame::Data(mut v) => {
Expand Down Expand Up @@ -150,31 +150,31 @@ where
}
Frame::Settings(v) => {
v.encode(self.buf.get_mut());
log::trace!("encoded settings; rem={:?}", self.buf.remaining());
tracing::trace!("encoded settings; rem={:?}", self.buf.remaining());
}
Frame::GoAway(v) => {
v.encode(self.buf.get_mut());
log::trace!("encoded go_away; rem={:?}", self.buf.remaining());
tracing::trace!("encoded go_away; rem={:?}", self.buf.remaining());
}
Frame::Ping(v) => {
v.encode(self.buf.get_mut());
log::trace!("encoded ping; rem={:?}", self.buf.remaining());
tracing::trace!("encoded ping; rem={:?}", self.buf.remaining());
}
Frame::WindowUpdate(v) => {
v.encode(self.buf.get_mut());
log::trace!("encoded window_update; rem={:?}", self.buf.remaining());
tracing::trace!("encoded window_update; rem={:?}", self.buf.remaining());
}

Frame::Priority(_) => {
/*
v.encode(self.buf.get_mut());
log::trace!("encoded priority; rem={:?}", self.buf.remaining());
tracing::trace!("encoded priority; rem={:?}", self.buf.remaining());
*/
unimplemented!();
}
Frame::Reset(v) => {
v.encode(self.buf.get_mut());
log::trace!("encoded reset; rem={:?}", self.buf.remaining());
tracing::trace!("encoded reset; rem={:?}", self.buf.remaining());
}
}

Expand All @@ -183,18 +183,18 @@ where

/// Flush buffered data to the wire
pub fn flush(&mut self, cx: &mut Context) -> Poll<io::Result<()>> {
log::trace!("flush");
tracing::trace!("flush");

loop {
while !self.is_empty() {
match self.next {
Some(Next::Data(ref mut frame)) => {
log::trace!(" -> queued data frame");
tracing::trace!(" -> queued data frame");
let mut buf = (&mut self.buf).chain(frame.payload_mut());
ready!(Pin::new(&mut self.inner).poll_write_buf(cx, &mut buf))?;
}
_ => {
log::trace!(" -> not a queued data frame");
tracing::trace!(" -> not a queued data frame");
ready!(Pin::new(&mut self.inner).poll_write_buf(cx, &mut self.buf))?;
}
}
Expand Down Expand Up @@ -234,7 +234,7 @@ where
}
}

log::trace!("flushing buffer");
tracing::trace!("flushing buffer");
// Flush the upstream
ready!(Pin::new(&mut self.inner).poll_flush(cx))?;

Expand Down
2 changes: 1 addition & 1 deletion src/frame/go_away.rs
Original file line number Diff line number Diff line change
Expand Up @@ -51,7 +51,7 @@ impl GoAway {
}

pub fn encode<B: BufMut>(&self, dst: &mut B) {
log::trace!("encoding GO_AWAY; code={:?}", self.error_code);
tracing::trace!("encoding GO_AWAY; code={:?}", self.error_code);
let head = Head::new(Kind::GoAway, 0, StreamId::zero());
head.encode(8, dst);
dst.put_u32(self.last_stream_id.into());
Expand Down
21 changes: 12 additions & 9 deletions src/frame/headers.rs
Original file line number Diff line number Diff line change
Expand Up @@ -153,7 +153,7 @@ impl Headers {
let flags = HeadersFlag(head.flag());
let mut pad = 0;

log::trace!("loading headers; flags={:?}", flags);
tracing::trace!("loading headers; flags={:?}", flags);

// Read the padding length
if flags.is_padded() {
Expand Down Expand Up @@ -817,10 +817,10 @@ impl HeaderBlock {
macro_rules! set_pseudo {
($field:ident, $val:expr) => {{
if reg {
log::trace!("load_hpack; header malformed -- pseudo not at head of block");
tracing::trace!("load_hpack; header malformed -- pseudo not at head of block");
malformed = true;
} else if self.pseudo.$field.is_some() {
log::trace!("load_hpack; header malformed -- repeated pseudo");
tracing::trace!("load_hpack; header malformed -- repeated pseudo");
malformed = true;
} else {
let __val = $val;
Expand All @@ -829,7 +829,7 @@ impl HeaderBlock {
if headers_size < max_header_list_size {
self.pseudo.$field = Some(__val);
} else if !self.is_over_size {
log::trace!("load_hpack; header list size over max");
tracing::trace!("load_hpack; header list size over max");
self.is_over_size = true;
}
}
Expand All @@ -856,10 +856,13 @@ impl HeaderBlock {
|| name == "keep-alive"
|| name == "proxy-connection"
{
log::trace!("load_hpack; connection level header");
tracing::trace!("load_hpack; connection level header");
malformed = true;
} else if name == header::TE && value != "trailers" {
log::trace!("load_hpack; TE header not set to trailers; val={:?}", value);
tracing::trace!(
"load_hpack; TE header not set to trailers; val={:?}",
value
);
malformed = true;
} else {
reg = true;
Expand All @@ -868,7 +871,7 @@ impl HeaderBlock {
if headers_size < max_header_list_size {
self.fields.append(name, value);
} else if !self.is_over_size {
log::trace!("load_hpack; header list size over max");
tracing::trace!("load_hpack; header list size over max");
self.is_over_size = true;
}
}
Expand All @@ -882,12 +885,12 @@ impl HeaderBlock {
});

if let Err(e) = res {
log::trace!("hpack decoding error; err={:?}", e);
tracing::trace!("hpack decoding error; err={:?}", e);
return Err(e.into());
}

if malformed {
log::trace!("malformed message");
tracing::trace!("malformed message");
return Err(Error::MalformedMessage);
}

Expand Down
2 changes: 1 addition & 1 deletion src/frame/ping.rs
Original file line number Diff line number Diff line change
Expand Up @@ -85,7 +85,7 @@ impl Ping {

pub fn encode<B: BufMut>(&self, dst: &mut B) {
let sz = self.payload.len();
log::trace!("encoding PING; ack={} len={}", self.ack, sz);
tracing::trace!("encoding PING; ack={} len={}", self.ack, sz);

let flags = if self.ack { ACK_FLAG } else { 0 };
let head = Head::new(Kind::Ping, flags, StreamId::zero());
Expand Down
2 changes: 1 addition & 1 deletion src/frame/reset.rs
Original file line number Diff line number Diff line change
Expand Up @@ -38,7 +38,7 @@ impl Reset {
}

pub fn encode<B: BufMut>(&self, dst: &mut B) {
log::trace!(
tracing::trace!(
"encoding RESET; id={:?} code={:?}",
self.stream_id,
self.error_code
Expand Down
6 changes: 3 additions & 3 deletions src/frame/settings.rs
Original file line number Diff line number Diff line change
Expand Up @@ -141,7 +141,7 @@ impl Settings {

// Ensure the payload length is correct, each setting is 6 bytes long.
if payload.len() % 6 != 0 {
log::debug!("invalid settings payload length; len={:?}", payload.len());
tracing::debug!("invalid settings payload length; len={:?}", payload.len());
return Err(Error::InvalidPayloadAckSettings);
}

Expand Down Expand Up @@ -199,13 +199,13 @@ impl Settings {
let head = Head::new(Kind::Settings, self.flags.into(), StreamId::zero());
let payload_len = self.payload_len();

log::trace!("encoding SETTINGS; len={}", payload_len);
tracing::trace!("encoding SETTINGS; len={}", payload_len);

head.encode(payload_len, dst);

// Encode the settings
self.for_each(|setting| {
log::trace!("encoding setting; val={:?}", setting);
tracing::trace!("encoding setting; val={:?}", setting);
setting.encode(dst)
});
}
Expand Down
2 changes: 1 addition & 1 deletion src/frame/window_update.rs
Original file line number Diff line number Diff line change
Expand Up @@ -48,7 +48,7 @@ impl WindowUpdate {
}

pub fn encode<B: BufMut>(&self, dst: &mut B) {
log::trace!("encoding WINDOW_UPDATE; id={:?}", self.stream_id);
tracing::trace!("encoding WINDOW_UPDATE; id={:?}", self.stream_id);
let head = Head::new(Kind::WindowUpdate, 0, self.stream_id);
head.encode(4, dst);
dst.put_u32(self.size_increment);
Expand Down
16 changes: 8 additions & 8 deletions src/hpack/decoder.rs
Original file line number Diff line number Diff line change
Expand Up @@ -183,22 +183,22 @@ impl Decoder {
self.last_max_update = size;
}

log::trace!("decode");
tracing::trace!("decode");

while let Some(ty) = peek_u8(src) {
// At this point we are always at the beginning of the next block
// within the HPACK data. The type of the block can always be
// determined from the first byte.
match Representation::load(ty)? {
Indexed => {
log::trace!(" Indexed; rem={:?}", src.remaining());
tracing::trace!(" Indexed; rem={:?}", src.remaining());
can_resize = false;
let entry = self.decode_indexed(src)?;
consume(src);
f(entry);
}
LiteralWithIndexing => {
log::trace!(" LiteralWithIndexing; rem={:?}", src.remaining());
tracing::trace!(" LiteralWithIndexing; rem={:?}", src.remaining());
can_resize = false;
let entry = self.decode_literal(src, true)?;

Expand All @@ -209,14 +209,14 @@ impl Decoder {
f(entry);
}
LiteralWithoutIndexing => {
log::trace!(" LiteralWithoutIndexing; rem={:?}", src.remaining());
tracing::trace!(" LiteralWithoutIndexing; rem={:?}", src.remaining());
can_resize = false;
let entry = self.decode_literal(src, false)?;
consume(src);
f(entry);
}
LiteralNeverIndexed => {
log::trace!(" LiteralNeverIndexed; rem={:?}", src.remaining());
tracing::trace!(" LiteralNeverIndexed; rem={:?}", src.remaining());
can_resize = false;
let entry = self.decode_literal(src, false)?;
consume(src);
Expand All @@ -226,7 +226,7 @@ impl Decoder {
f(entry);
}
SizeUpdate => {
log::trace!(" SizeUpdate; rem={:?}", src.remaining());
tracing::trace!(" SizeUpdate; rem={:?}", src.remaining());
if !can_resize {
return Err(DecoderError::InvalidMaxDynamicSize);
}
Expand All @@ -248,7 +248,7 @@ impl Decoder {
return Err(DecoderError::InvalidMaxDynamicSize);
}

log::debug!(
tracing::debug!(
"Decoder changed max table size from {} to {}",
self.table.size(),
new_size
Expand Down Expand Up @@ -302,7 +302,7 @@ impl Decoder {
let len = decode_int(buf, 7)?;

if len > buf.remaining() {
log::trace!(
tracing::trace!(
"decode_string underflow; len={}; remaining={}",
len,
buf.remaining()
Expand Down
4 changes: 2 additions & 2 deletions src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -84,10 +84,10 @@

macro_rules! proto_err {
(conn: $($msg:tt)+) => {
log::debug!("connection error PROTOCOL_ERROR -- {};", format_args!($($msg)+))
tracing::debug!("connection error PROTOCOL_ERROR -- {};", format_args!($($msg)+))
};
(stream: $($msg:tt)+) => {
log::debug!("stream error PROTOCOL_ERROR -- {};", format_args!($($msg)+))
tracing::debug!("stream error PROTOCOL_ERROR -- {};", format_args!($($msg)+))
};
}

Expand Down
Loading