smol-rs
/
polling
mirror of https://github.com/smol-rs/polling
1
0
Fork 0
Code Issues Projects Releases Wiki Activity

Replace log with tracing

This commit is contained in:
John Nunley 2023-06-11 11:09:17 -07:00
parent e2129ea879
commit b988f26be1
No known key found for this signature in database
GPG Key ID: 42B2FA4582BB1EC9
8 changed files with 197 additions and 102 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
Cargo.toml
View File

@ -23,7 +23,7 @@ std = []
[dependencies]
cfg-if = "1"
log = "0.4.11"
tracing = { version = "0.1.37", default-features = false }
[target.'cfg(any(unix, target_os = "fuchsia", target_os = "vxworks"))'.dependencies]
libc = "0.2.77"

76
src/epoll.rs
View File

@ -65,11 +65,11 @@ impl Poller {
PollMode::Oneshot,
)?;
log::trace!(
"new: epoll_fd={}, event_fd={}, timer_fd={:?}",
poller.epoll_fd.as_raw_fd(),
poller.event_fd.as_raw_fd(),
poller.timer_fd
tracing::trace!(
epoll_fd= ?poller.epoll_fd,
event_fd= ?poller.event_fd,
timer_fd= ?poller.timer_fd,
"new",
);
Ok(poller)
}
@ -86,12 +86,13 @@ impl Poller {
/// Adds a new file descriptor.
pub fn add(&self, fd: RawFd, ev: Event, mode: PollMode) -> io::Result<()> {
log::trace!(
"add: epoll_fd={}, fd={}, ev={:?}",
self.epoll_fd.as_raw_fd(),
fd,
ev
let span = tracing::trace_span!(
"add",
epoll_fd = ?self.epoll_fd,
fd= ?fd,
ev = ?ev,
);
let _enter = span.enter();
epoll::epoll_add(
&self.epoll_fd,
@ -105,12 +106,13 @@ impl Poller {
/// Modifies an existing file descriptor.
pub fn modify(&self, fd: RawFd, ev: Event, mode: PollMode) -> io::Result<()> {
log::trace!(
"modify: epoll_fd={}, fd={}, ev={:?}",
self.epoll_fd.as_raw_fd(),
fd,
ev
let span = tracing::trace_span!(
"modify",
epoll_fd = ?self.epoll_fd,
fd= ?fd,
ev = ?ev,
);
let _enter = span.enter();
epoll::epoll_mod(
&self.epoll_fd,
@ -124,7 +126,12 @@ impl Poller {
/// Deletes a file descriptor.
pub fn delete(&self, fd: RawFd) -> io::Result<()> {
log::trace!("remove: epoll_fd={}, fd={}", self.epoll_fd.as_raw_fd(), fd);
let span = tracing::trace_span!(
"delete",
epoll_fd = ?self.epoll_fd,
fd= ?fd,
);
let _enter = span.enter();
epoll::epoll_del(&self.epoll_fd, unsafe {
rustix::fd::BorrowedFd::borrow_raw(fd)
@ -136,11 +143,12 @@ impl Poller {
/// Waits for I/O events with an optional timeout.
#[allow(clippy::needless_update)]
pub fn wait(&self, events: &mut Events, timeout: Option<Duration>) -> io::Result<()> {
log::trace!(
"wait: epoll_fd={}, timeout={:?}",
self.epoll_fd.as_raw_fd(),
timeout
let span = tracing::trace_span!(
"wait",
epoll_fd = ?self.epoll_fd,
timeout = ?timeout,
);
let _enter = span.enter();
if let Some(ref timer_fd) = self.timer_fd {
// Configure the timeout using timerfd.
@ -188,10 +196,10 @@ impl Poller {
// Wait for I/O events.
epoll::epoll_wait(&self.epoll_fd, &mut events.list, timeout_ms)?;
log::trace!(
"new events: epoll_fd={}, res={}",
self.epoll_fd.as_raw_fd(),
events.list.len()
tracing::trace!(
epoll_fd = ?self.epoll_fd,
res = ?events.list.len(),
"new events",
);
// Clear the notification (if received) and re-register interest in it.
@ -211,11 +219,12 @@ impl Poller {
/// Sends a notification to wake up the current or next `wait()` call.
pub fn notify(&self) -> io::Result<()> {
log::trace!(
"notify: epoll_fd={}, event_fd={}",
self.epoll_fd.as_raw_fd(),
self.event_fd.as_raw_fd()
let span = tracing::trace_span!(
"notify",
epoll_fd = ?self.epoll_fd,
event_fd = ?self.event_fd,
);
let _enter = span.enter();
let buf: [u8; 8] = 1u64.to_ne_bytes();
let _ = write(&self.event_fd, &buf);
@ -237,12 +246,13 @@ impl AsFd for Poller {
impl Drop for Poller {
fn drop(&mut self) {
log::trace!(
"drop: epoll_fd={}, event_fd={}, timer_fd={:?}",
self.epoll_fd.as_raw_fd(),
self.event_fd.as_raw_fd(),
self.timer_fd
let span = tracing::trace_span!(
"drop",
epoll_fd = ?self.epoll_fd,
event_fd = ?self.event_fd,
timer_fd = ?self.timer_fd
);
let _enter = span.enter();
if let Some(timer_fd) = self.timer_fd.take() {
let _ = self.delete(timer_fd.as_raw_fd());

10
src/iocp/afd.rs
View File

@ -6,7 +6,7 @@ use std::cell::UnsafeCell;
use std::fmt;
use std::io;
use std::marker::{PhantomData, PhantomPinned};
use std::mem::{size_of, transmute, MaybeUninit};
use std::mem::{self, size_of, transmute, MaybeUninit};
use std::os::windows::prelude::{AsRawHandle, RawHandle, RawSocket};
use std::pin::Pin;
use std::ptr;
@ -111,7 +111,7 @@ macro_rules! define_ntdll_import {
let addr = match addr {
Some(addr) => addr,
None => {
log::error!("Failed to load ntdll function {}", NAME);
tracing::error!("Failed to load ntdll function {}", NAME);
return Err(io::Error::last_os_error());
},
};
@ -212,7 +212,7 @@ impl NtdllImports {
let ntdll = GetModuleHandleW(NTDLL_NAME.as_ptr() as *const _);
if ntdll == 0 {
log::error!("Failed to load ntdll.dll");
tracing::error!("Failed to load ntdll.dll");
return Err(io::Error::last_os_error());
}
@ -302,8 +302,8 @@ where
// Set up device attributes.
let mut device_name = UNICODE_STRING {
Length: (AFD_NAME.len() * size_of::<u16>()) as u16,
MaximumLength: (AFD_NAME.len() * size_of::<u16>()) as u16,
Length: mem::size_of_val(AFD_NAME) as u16,
MaximumLength: mem::size_of_val(AFD_NAME) as u16,
Buffer: AFD_NAME.as_ptr() as *mut _,
};
let mut device_attributes = OBJECT_ATTRIBUTES {

45
src/iocp/mod.rs
View File

@ -105,7 +105,7 @@ impl Poller {
let port = IoCompletionPort::new(0)?;
log::trace!("new: handle={:?}", &port);
tracing::trace!(handle=?port, "new");
Ok(Poller {
port,
@ -135,12 +135,13 @@ impl Poller {
/// Add a new source to the poller.
pub(super) fn add(&self, socket: RawSocket, interest: Event, mode: PollMode) -> io::Result<()> {
log::trace!(
"add: handle={:?}, sock={}, ev={:?}",
self.port,
socket,
interest
let span = tracing::trace_span!(
"add",
handle = ?self.port,
sock = ?socket,
ev = ?interest,
);
let _enter = span.enter();
// We don't support edge-triggered events.
if matches!(mode, PollMode::Edge | PollMode::EdgeOneshot) {
@ -195,12 +196,13 @@ impl Poller {
interest: Event,
mode: PollMode,
) -> io::Result<()> {
log::trace!(
"modify: handle={:?}, sock={}, ev={:?}",
self.port,
socket,
interest
let span = tracing::trace_span!(
"modify",
handle = ?self.port,
sock = ?socket,
ev = ?interest,
);
let _enter = span.enter();
// We don't support edge-triggered events.
if matches!(mode, PollMode::Edge | PollMode::EdgeOneshot) {
@ -230,7 +232,12 @@ impl Poller {
/// Delete a source from the poller.
pub(super) fn delete(&self, socket: RawSocket) -> io::Result<()> {
log::trace!("remove: handle={:?}, sock={}", self.port, socket);
let span = tracing::trace_span!(
"remove",
handle = ?self.port,
sock = ?socket,
);
let _enter = span.enter();
// Get a reference to the source.
let source = {
@ -252,7 +259,12 @@ impl Poller {
/// Wait for events.
pub(super) fn wait(&self, events: &mut Events, timeout: Option<Duration>) -> io::Result<()> {
log::trace!("wait: handle={:?}, timeout={:?}", self.port, timeout);
let span = tracing::trace_span!(
"wait",
handle = ?self.port,
timeout = ?timeout,
);
let _enter = span.enter();
let deadline = timeout.and_then(|timeout| Instant::now().checked_add(timeout));
let mut packets = lock!(self.packets.lock());
@ -279,7 +291,10 @@ impl Poller {
// Wait for I/O events.
let len = self.port.wait(&mut packets, timeout)?;
log::trace!("new events: handle={:?}, len={}", self.port, len);
tracing::trace!(
handle=?self.port,
res=?len,
"new events");
// We are no longer polling.
drop(guard);
@ -308,7 +323,7 @@ impl Poller {
break;
}
log::trace!("wait: no events found, re-entering polling loop");
tracing::trace!("wait: no events found, re-entering polling loop");
}
Ok(())

52
src/kqueue.rs
View File

@ -37,7 +37,10 @@ impl Poller {
// Register the notification pipe.
poller.notify.register(&poller)?;
log::trace!("new: kqueue_fd={:?}", poller.kqueue_fd);
tracing::trace!(
kqueue_fd = ?poller.kqueue_fd,
"new"
);
Ok(poller)
}
@ -59,14 +62,18 @@ impl Poller {
/// Modifies an existing file descriptor.
pub fn modify(&self, fd: RawFd, ev: Event, mode: PollMode) -> io::Result<()> {
if !self.notify.has_fd(fd) {
log::trace!(
"add: kqueue_fd={:?}, fd={}, ev={:?}",
self.kqueue_fd,
fd,
ev
let span = if !self.notify.has_fd(fd) {
let span = tracing::trace_span!(
"add",
kqueue_fd = ?self.kqueue_fd,
fd= ?fd,
ev = ?ev,
);
}
Some(span)
} else {
None
};
let _enter = span.as_ref().map(|s| s.enter());
let mode_flags = mode_to_flags(mode);
@ -141,18 +148,23 @@ impl Poller {
/// Waits for I/O events with an optional timeout.
pub fn wait(&self, events: &mut Events, timeout: Option<Duration>) -> io::Result<()> {
log::trace!(
"wait: kqueue_fd={:?}, timeout={:?}",
self.kqueue_fd,
timeout
let span = tracing::trace_span!(
"wait",
kqueue_fd = ?self.kqueue_fd,
timeout = ?timeout,
);
let _enter = span.enter();
// Wait for I/O events.
let changelist = [];
let eventlist = &mut events.list;
let res = unsafe { kqueue::kevent(&self.kqueue_fd, &changelist, eventlist, timeout)? };
log::trace!("new events: kqueue_fd={:?}, res={}", self.kqueue_fd, res);
tracing::trace!(
kqueue_fd = ?self.kqueue_fd,
res = ?res,
"new events",
);
// Clear the notification (if received) and re-register interest in it.
self.notify.reregister(self)?;
@ -162,7 +174,12 @@ impl Poller {
/// Sends a notification to wake up the current or next `wait()` call.
pub fn notify(&self) -> io::Result<()> {
log::trace!("notify: kqueue_fd={:?}", self.kqueue_fd);
let span = tracing::trace_span!(
"notify",
kqueue_fd = ?self.kqueue_fd,
);
let _enter = span.enter();
self.notify.notify(self).ok();
Ok(())
}
@ -182,7 +199,12 @@ impl AsFd for Poller {
impl Drop for Poller {
fn drop(&mut self) {
log::trace!("drop: kqueue_fd={:?}", self.kqueue_fd);
let span = tracing::trace_span!(
"drop",
kqueue_fd = ?self.kqueue_fd,
);
let _enter = span.enter();
let _ = self.notify.deregister(self);
}
}

9
src/lib.rs
View File

@ -483,7 +483,8 @@ impl Poller {
/// # std::io::Result::Ok(())
/// ```
pub fn wait(&self, events: &mut Vec<Event>, timeout: Option<Duration>) -> io::Result<usize> {
log::trace!("Poller::wait(_, {:?})", timeout);
let span = tracing::trace_span!("Poller::wait", timeout=?timeout);
let _enter = span.enter();
if let Ok(mut lock) = self.events.try_lock() {
// Wait for I/O events.
@ -497,7 +498,7 @@ impl Poller {
events.extend(lock.iter().filter(|ev| ev.key != usize::MAX));
Ok(events.len() - len)
} else {
log::trace!("wait: skipping because another thread is already waiting on I/O");
tracing::trace!("wait: skipping because another thread is already waiting on I/O");
Ok(0)
}
}
@ -525,7 +526,9 @@ impl Poller {
/// # std::io::Result::Ok(())
/// ```
pub fn notify(&self) -> io::Result<()> {
log::trace!("Poller::notify()");
let span = tracing::trace_span!("Poller::notify");
let _enter = span.enter();
if self
.notified
.compare_exchange(false, true, Ordering::SeqCst, Ordering::SeqCst)

67
src/poll.rs
View File

@ -89,10 +89,10 @@ impl Poller {
// Put the reading side into non-blocking mode.
fcntl_setfl(&notify_read, fcntl_getfl(&notify_read)? | OFlags::NONBLOCK)?;
log::trace!(
"new: notify_read={:?}, notify_write={:?}",
notify_read,
notify_write,
tracing::trace!(
notify_read=?notify_read,
notify_write=?notify_write,
"new"
);
Ok(Self {
@ -128,12 +128,13 @@ impl Poller {
return Err(io::Error::from(io::ErrorKind::InvalidInput));
}
log::trace!(
"add: notify_read={:?}, fd={}, ev={:?}",
self.notify_read,
fd,
ev
let span = tracing::trace_span!(
"add",
notify_read = ?self.notify_read,
fd= ?fd,
ev = ?ev,
);
let _enter = span.enter();
self.modify_fds(|fds| {
if fds.fd_data.contains_key(&fd) {
@ -162,12 +163,13 @@ impl Poller {
/// Modifies an existing file descriptor.
pub fn modify(&self, fd: RawFd, ev: Event, mode: PollMode) -> io::Result<()> {
log::trace!(
"modify: notify_read={:?}, fd={}, ev={:?}",
self.notify_read,
fd,
ev
let span = tracing::trace_span!(
"modify",
notify_read = ?self.notify_read,
fd= ?fd,
ev = ?ev,
);
let _enter = span.enter();
self.modify_fds(|fds| {
let data = fds.fd_data.get_mut(&fd).ok_or(io::ErrorKind::NotFound)?;
@ -183,7 +185,12 @@ impl Poller {
/// Deletes a file descriptor.
pub fn delete(&self, fd: RawFd) -> io::Result<()> {
log::trace!("delete: notify_read={:?}, fd={}", self.notify_read, fd);
let span = tracing::trace_span!(
"delete",
notify_read = ?self.notify_read,
fd= ?fd,
);
let _enter = span.enter();
self.modify_fds(|fds| {
let data = fds.fd_data.remove(&fd).ok_or(io::ErrorKind::NotFound)?;
@ -201,11 +208,12 @@ impl Poller {
/// Waits for I/O events with an optional timeout.
pub fn wait(&self, events: &mut Events, timeout: Option<Duration>) -> io::Result<()> {
log::trace!(
"wait: notify_read={:?}, timeout={:?}",
self.notify_read,
timeout
let span = tracing::trace_span!(
"wait",
notify_read = ?self.notify_read,
timeout = ?timeout,
);
let _enter = span.enter();
let deadline = timeout.and_then(|t| Instant::now().checked_add(t));
@ -245,10 +253,11 @@ impl Poller {
let num_events = poll(&mut fds.poll_fds, timeout_ms)?;
let notified = !fds.poll_fds[0].revents().is_empty();
let num_fd_events = if notified { num_events - 1 } else { num_events };
log::trace!(
"new events: notify_read={:?}, num={}",
self.notify_read,
num_events
tracing::trace!(
num_events = ?num_events,
notified = ?notified,
num_fd_events = ?num_fd_events,
"new events",
);
// Read all notifications.
@ -300,7 +309,11 @@ impl Poller {
/// Sends a notification to wake up the current or next `wait()` call.
pub fn notify(&self) -> io::Result<()> {
log::trace!("notify: notify_read={:?}", self.notify_read);
let span = tracing::trace_span!(
"notify",
notify_read = ?self.notify_read,
);
let _enter = span.enter();
if !self.notified.swap(true, Ordering::SeqCst) {
self.notify_inner()?;
@ -346,12 +359,6 @@ impl Poller {
}
}
impl Drop for Poller {
fn drop(&mut self) {
log::trace!("drop: notify_read={:?}", self.notify_read);
}
}
/// Get the input poll events for the given event.
fn poll_events(ev: Event) -> PollFlags {
(if ev.readable {

38
src/port.rs
View File

@ -23,6 +23,11 @@ impl Poller {
let flags = fcntl_getfd(&port_fd)?;
fcntl_setfd(&port_fd, flags | FdFlags::CLOEXEC)?;
tracing::trace!(
port_fd=?port_fd,
"new",
);
Ok(Poller { port_fd })
}
@ -44,6 +49,14 @@ impl Poller {
/// Modifies an existing file descriptor.
pub fn modify(&self, fd: RawFd, ev: Event, mode: PollMode) -> io::Result<()> {
let span = tracing::trace_span!(
"modify",
port_fd = ?self.port_fd,
fd= ?fd,
ev = ?ev,
);
let _enter = span.enter();
let mut flags = PollFlags::empty();
if ev.readable {
flags |= read_flags();
@ -67,6 +80,13 @@ impl Poller {
/// Deletes a file descriptor.
pub fn delete(&self, fd: RawFd) -> io::Result<()> {
let span = tracing::trace_span!(
"delete",
port_fd = ?self.port_fd,
fd= ?fd,
);
let _enter = span.enter();
let result = unsafe { port::port_dissociate_fd(&self.port_fd, fd) };
if let Err(e) = result {
match e {
@ -80,8 +100,20 @@ impl Poller {
/// Waits for I/O events with an optional timeout.
pub fn wait(&self, events: &mut Events, timeout: Option<Duration>) -> io::Result<()> {
let span = tracing::trace_span!(
"wait",
port_fd = ?self.port_fd,
timeout = ?timeout,
);
let _enter = span.enter();
// Wait for I/O events.
let res = port::port_getn(&self.port_fd, &mut events.list, 1, timeout);
tracing::trace!(
port_fd= ?self.port_fd,
res= ?events.list.len(),
"new events"
);
// Event ports sets the return value to -1 and returns ETIME on timer expire. The number of
// returned events is stored in nget, but in our case it should always be 0 since we set
@ -100,6 +132,12 @@ impl Poller {
pub fn notify(&self) -> io::Result<()> {
const PORT_SOURCE_USER: i32 = 3;
let span = tracing::trace_span!(
"notify",
port_fd = ?self.port_fd,
);
let _enter = span.enter();
// Use port_send to send a notification to the port.
port::port_send(&self.port_fd, PORT_SOURCE_USER, crate::NOTIFY_KEY as _)?;