Commit 41dd6825 authored by eta's avatar eta
Browse files

Merge branch 'report-skew' into 'main'

Report skew estimates from arti-client

See merge request !455
parents 9689468a 11a90916
Loading
Loading
Loading
Loading
+1 −0
Original line number Original line Diff line number Diff line
@@ -3468,6 +3468,7 @@ dependencies = [
 "humantime-serde",
 "humantime-serde",
 "itertools",
 "itertools",
 "pin-project",
 "pin-project",
 "postage",
 "rand 0.8.5",
 "rand 0.8.5",
 "retain_mut",
 "retain_mut",
 "serde",
 "serde",
+2 −0
Original line number Original line Diff line number Diff line
@@ -388,11 +388,13 @@ impl<R: Runtime> TorClient<R> {


        let conn_status = chanmgr.bootstrap_events();
        let conn_status = chanmgr.bootstrap_events();
        let dir_status = dirmgr.bootstrap_events();
        let dir_status = dirmgr.bootstrap_events();
        let skew_status = circmgr.skew_events();
        runtime
        runtime
            .spawn(status::report_status(
            .spawn(status::report_status(
                status_sender,
                status_sender,
                conn_status,
                conn_status,
                dir_status,
                dir_status,
                skew_status,
            ))
            ))
            .map_err(|e| ErrorDetail::from_spawn("top-level status reporter", e))?;
            .map_err(|e| ErrorDetail::from_spawn("top-level status reporter", e))?;


+45 −6
Original line number Original line Diff line number Diff line
@@ -8,6 +8,7 @@ use educe::Educe;
use futures::{Stream, StreamExt};
use futures::{Stream, StreamExt};
use tor_basic_utils::skip_fmt;
use tor_basic_utils::skip_fmt;
use tor_chanmgr::{ConnBlockage, ConnStatus, ConnStatusEvents};
use tor_chanmgr::{ConnBlockage, ConnStatus, ConnStatusEvents};
use tor_circmgr::{ClockSkewEvents, SkewEstimate};
use tor_dirmgr::DirBootstrapStatus;
use tor_dirmgr::DirBootstrapStatus;
use tracing::debug;
use tracing::debug;


@@ -29,6 +30,8 @@ pub struct BootstrapStatus {
    conn_status: ConnStatus,
    conn_status: ConnStatus,
    /// Status for our directory information.
    /// Status for our directory information.
    dir_status: DirBootstrapStatus,
    dir_status: DirBootstrapStatus,
    /// Current estimate of our clock skew.
    skew: Option<SkewEstimate>,
}
}


impl BootstrapStatus {
impl BootstrapStatus {
@@ -73,7 +76,15 @@ impl BootstrapStatus {
        if let Some(b) = self.conn_status.blockage() {
        if let Some(b) = self.conn_status.blockage() {
            let message = b.to_string().into();
            let message = b.to_string().into();
            let kind = b.into();
            let kind = b.into();
            if matches!(kind, BlockageKind::ClockSkewed) && self.skew_is_noteworthy() {
                Some(Blockage {
                    kind,
                    message: format!("Clock is {}", self.skew.as_ref().expect("logic error"))
                        .into(),
                })
            } else {
                Some(Blockage { kind, message })
                Some(Blockage { kind, message })
            }
        } else {
        } else {
            None
            None
        }
        }
@@ -88,6 +99,16 @@ impl BootstrapStatus {
    fn apply_dir_status(&mut self, status: DirBootstrapStatus) {
    fn apply_dir_status(&mut self, status: DirBootstrapStatus) {
        self.dir_status = status;
        self.dir_status = status;
    }
    }

    /// Adjust this status based on new estimated clock skew information.
    fn apply_skew_estimate(&mut self, status: Option<SkewEstimate>) {
        self.skew = status;
    }

    /// Return true if our current clock skew estimate is considered noteworthy.
    fn skew_is_noteworthy(&self) -> bool {
        matches!(&self.skew, Some(s) if s.noteworthy())
    }
}
}


/// A reason why a client believes it is stuck.
/// A reason why a client believes it is stuck.
@@ -115,6 +136,10 @@ pub enum BlockageKind {
    /// We have some other kind of problem connecting to Tor
    /// We have some other kind of problem connecting to Tor
    #[display(fmt = "Can't reach the Tor network")]
    #[display(fmt = "Can't reach the Tor network")]
    CantReachTor,
    CantReachTor,
    /// We believe our clock is set incorrectly, and that's preventing us from
    /// successfully with relays and/or from finding a directory that we trust.
    #[display(fmt = "Clock is skewed.")]
    ClockSkewed,
}
}


impl From<ConnBlockage> for BlockageKind {
impl From<ConnBlockage> for BlockageKind {
@@ -122,6 +147,7 @@ impl From<ConnBlockage> for BlockageKind {
        match b {
        match b {
            ConnBlockage::NoTcp => BlockageKind::Offline,
            ConnBlockage::NoTcp => BlockageKind::Offline,
            ConnBlockage::NoHandshake => BlockageKind::Filtering,
            ConnBlockage::NoHandshake => BlockageKind::Filtering,
            ConnBlockage::CertsExpired => BlockageKind::ClockSkewed,
            _ => BlockageKind::CantReachTor,
            _ => BlockageKind::CantReachTor,
        }
        }
    }
    }
@@ -136,14 +162,20 @@ impl fmt::Display for BootstrapStatus {
    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
        let percent = (self.as_frac() * 100.0).round() as u32;
        let percent = (self.as_frac() * 100.0).round() as u32;
        if let Some(problem) = self.blocked() {
        if let Some(problem) = self.blocked() {
            write!(f, "Stuck at {}%: {}", percent, problem)
            write!(f, "Stuck at {}%: {}", percent, problem)?;
        } else {
        } else {
            write!(
            write!(
                f,
                f,
                "{}%: {}; {}",
                "{}%: {}; {}",
                percent, &self.conn_status, &self.dir_status
                percent, &self.conn_status, &self.dir_status
            )
            )?;
        }
        if let Some(skew) = &self.skew {
            if skew.noteworthy() {
                write!(f, ". Clock is {}", skew)?;
            }
        }
        }
        Ok(())
    }
    }
}
}


@@ -159,7 +191,8 @@ impl fmt::Display for BootstrapStatus {
pub(crate) async fn report_status(
pub(crate) async fn report_status(
    mut sender: postage::watch::Sender<BootstrapStatus>,
    mut sender: postage::watch::Sender<BootstrapStatus>,
    conn_status: ConnStatusEvents,
    conn_status: ConnStatusEvents,
    dir_status: impl Stream<Item = DirBootstrapStatus> + Unpin,
    dir_status: impl Stream<Item = DirBootstrapStatus> + Send + Unpin,
    skew_status: ClockSkewEvents,
) {
) {
    /// Internal enumeration to combine incoming status changes.
    /// Internal enumeration to combine incoming status changes.
    enum Event {
    enum Event {
@@ -167,15 +200,21 @@ pub(crate) async fn report_status(
        Conn(ConnStatus),
        Conn(ConnStatus),
        /// A directory status change
        /// A directory status change
        Dir(DirBootstrapStatus),
        Dir(DirBootstrapStatus),
        /// A clock skew change
        Skew(Option<SkewEstimate>),
    }
    }
    let mut stream =
    let mut stream = futures::stream::select_all(vec![
        futures::stream::select(conn_status.map(Event::Conn), dir_status.map(Event::Dir));
        conn_status.map(Event::Conn).boxed(),
        dir_status.map(Event::Dir).boxed(),
        skew_status.map(Event::Skew).boxed(),
    ]);


    while let Some(event) = stream.next().await {
    while let Some(event) = stream.next().await {
        let mut b = sender.borrow_mut();
        let mut b = sender.borrow_mut();
        match event {
        match event {
            Event::Conn(e) => b.apply_conn_status(e),
            Event::Conn(e) => b.apply_conn_status(e),
            Event::Dir(e) => b.apply_dir_status(e),
            Event::Dir(e) => b.apply_dir_status(e),
            Event::Skew(e) => b.apply_skew_estimate(e),
        }
        }
        debug!("{}", *b);
        debug!("{}", *b);
    }
    }
+4 −0
Original line number Original line Diff line number Diff line
@@ -192,6 +192,10 @@ impl<R: Runtime> ChanBuilder<R> {
            .check(target, &peer_cert, Some(now))
            .check(target, &peer_cert, Some(now))
            .map_err(|source| match &source {
            .map_err(|source| match &source {
                tor_proto::Error::HandshakeCertsExpired { .. } => {
                tor_proto::Error::HandshakeCertsExpired { .. } => {
                    self.event_sender
                        .lock()
                        .expect("Lock poisoned")
                        .record_handshake_done_with_skewed_clock();
                    Error::Proto { source, clock_skew }
                    Error::Proto { source, clock_skew }
                }
                }
                _ => Error::from_proto_no_skew(source),
                _ => Error::from_proto_no_skew(source),
+83 −20
Original line number Original line Diff line number Diff line
@@ -20,13 +20,22 @@ pub struct ConnStatus {
    /// None if we haven't succeeded yet, but it's too early to say if
    /// None if we haven't succeeded yet, but it's too early to say if
    /// that's a problem.
    /// that's a problem.
    online: Option<bool>,
    online: Option<bool>,

    /// Have we ever been able to make TLS handshakes and negotiate
    /// certificates, _not including timeliness checking_?
    ///
    /// True if we've been able to make TLS handshakes and talk to Tor relays we
    /// like recently. False if we've definitely been failing. None if we
    /// haven't succeeded yet, but it's too early to say if that's a problem.
    auth_works: Option<bool>,

    /// Have we been able to successfully negotiate full Tor handshakes?
    /// Have we been able to successfully negotiate full Tor handshakes?
    ///
    ///
    /// True if we've been able to make TLS sessions recently.
    /// True if we've been able to make Tor handshakes recently.
    /// False if we've definitely been failing.
    /// False if we've definitely been failing.
    /// None if we haven't succeeded yet, but it's too early to say if
    /// None if we haven't succeeded yet, but it's too early to say if
    /// that's a problem.
    /// that's a problem.
    tls_works: Option<bool>,
    handshake_works: Option<bool>,
}
}


/// A problem detected while connecting to the Tor network.
/// A problem detected while connecting to the Tor network.
@@ -40,6 +49,11 @@ pub enum ConnBlockage {
    /// got hit by an attempted man-in-the-middle attack.
    /// got hit by an attempted man-in-the-middle attack.
    #[display(fmt = "our internet connection seems to be filtered")]
    #[display(fmt = "our internet connection seems to be filtered")]
    NoHandshake,
    NoHandshake,
    /// We've made TCP connections, and our TLS connections mostly succeeded,
    /// but we encountered failures that are well explained by clock skew,
    /// or expired certificates.
    #[display(fmt = "relays all seem to be using expired certificates")]
    CertsExpired,
}
}


impl ConnStatus {
impl ConnStatus {
@@ -48,12 +62,12 @@ impl ConnStatus {
    /// Note:(This would just be a PartialEq implementation, but I'm not sure I
    /// Note:(This would just be a PartialEq implementation, but I'm not sure I
    /// want to expose that PartialEq for this struct.)
    /// want to expose that PartialEq for this struct.)
    fn eq(&self, other: &ConnStatus) -> bool {
    fn eq(&self, other: &ConnStatus) -> bool {
        self.online == other.online && self.tls_works == other.tls_works
        self.online == other.online && self.handshake_works == other.handshake_works
    }
    }


    /// Return true if this status indicates that we can successfully open Tor channels.
    /// Return true if this status indicates that we can successfully open Tor channels.
    pub fn usable(&self) -> bool {
    pub fn usable(&self) -> bool {
        self.online == Some(true) && self.tls_works == Some(true)
        self.online == Some(true) && self.handshake_works == Some(true)
    }
    }


    /// Return a float representing "how bootstrapped" we are with respect to
    /// Return a float representing "how bootstrapped" we are with respect to
@@ -66,7 +80,8 @@ impl ConnStatus {
        match self {
        match self {
            Self {
            Self {
                online: Some(true),
                online: Some(true),
                tls_works: Some(true),
                auth_works: Some(true),
                handshake_works: Some(true),
            } => 1.0,
            } => 1.0,
            Self {
            Self {
                online: Some(true), ..
                online: Some(true), ..
@@ -84,9 +99,13 @@ impl ConnStatus {
                ..
                ..
            } => Some(ConnBlockage::NoTcp),
            } => Some(ConnBlockage::NoTcp),
            Self {
            Self {
                tls_works: Some(false),
                auth_works: Some(false),
                ..
                ..
            } => Some(ConnBlockage::NoHandshake),
            } => Some(ConnBlockage::NoHandshake),
            Self {
                handshake_works: Some(false),
                ..
            } => Some(ConnBlockage::CertsExpired),
            _ => None,
            _ => None,
        }
        }
    }
    }
@@ -101,15 +120,25 @@ impl fmt::Display for ConnStatus {
                ..
                ..
            } => write!(f, "unable to connect to the internet"),
            } => write!(f, "unable to connect to the internet"),
            ConnStatus {
            ConnStatus {
                tls_works: None, ..
                handshake_works: None,
                ..
            } => write!(f, "handshaking with Tor relays"),
            } => write!(f, "handshaking with Tor relays"),
            ConnStatus {
            ConnStatus {
                tls_works: Some(false),
                auth_works: Some(true),
                handshake_works: Some(false),
                ..
            } => write!(
                f,
                "unable to handshake with Tor relays, possibly due to clock skew"
            ),
            ConnStatus {
                handshake_works: Some(false),
                ..
                ..
            } => write!(f, "unable to handshake with Tor relays"),
            } => write!(f, "unable to handshake with Tor relays"),
            ConnStatus {
            ConnStatus {
                online: Some(true),
                online: Some(true),
                tls_works: Some(true),
                handshake_works: Some(true),
                ..
            } => write!(f, "connecting successfully"),
            } => write!(f, "connecting successfully"),
        }
        }
    }
    }
@@ -180,6 +209,10 @@ struct ChanMgrStatus {
    // where TLS fails.
    // where TLS fails.
    last_tls_success: Option<Instant>,
    last_tls_success: Option<Instant>,


    /// When (if ever) have we ever finished the inner Tor handshake with a relay,
    /// up to the point where we check for certificate timeliness?
    last_chan_auth_success: Option<Instant>,

    /// When (if ever) have we successfully finished the inner Tor handshake
    /// When (if ever) have we successfully finished the inner Tor handshake
    /// with a relay?
    /// with a relay?
    ///
    ///
@@ -198,6 +231,7 @@ impl ChanMgrStatus {
            n_attempts: 0,
            n_attempts: 0,
            last_tcp_success: None,
            last_tcp_success: None,
            last_tls_success: None,
            last_tls_success: None,
            last_chan_auth_success: None,
            last_chan_success: None,
            last_chan_success: None,
        }
        }
    }
    }
@@ -221,13 +255,23 @@ impl ChanMgrStatus {
            (false, false) => Some(false),
            (false, false) => Some(false),
        };
        };


        let tls_works = match (self.last_chan_success.is_some(), early) {
        let auth_works = match (self.last_chan_auth_success.is_some(), early) {
            (true, _) => Some(true),
            (true, _) => Some(true),
            (_, true) => None,
            (_, true) => None,
            (false, false) => Some(false),
            (false, false) => Some(false),
        };
        };


        ConnStatus { online, tls_works }
        let handshake_works = match (self.last_chan_success.is_some(), early) {
            (true, _) => Some(true),
            (_, true) => None,
            (false, false) => Some(false),
        };

        ConnStatus {
            online,
            auth_works,
            handshake_works,
        }
    }
    }


    /// Note that an attempt to connect has been started.
    /// Note that an attempt to connect has been started.
@@ -247,11 +291,18 @@ impl ChanMgrStatus {
        self.last_tls_success = Some(now);
        self.last_tls_success = Some(now);
    }
    }


    /// Note that we've completed a Tor handshake with a relay, _but failed to
    /// verify the certificates in a way that could indicate clock skew_.
    fn record_handshake_done_with_skewed_clock(&mut self, now: Instant) {
        self.last_chan_auth_success = Some(now);
    }

    /// Note that we've completed a Tor handshake with a relay.
    /// Note that we've completed a Tor handshake with a relay.
    ///
    ///
    /// (This includes performing the TLS handshake, and verifying that the
    /// (This includes performing the TLS handshake, and verifying that the
    /// relay was indeed the one that we wanted to reach.)
    /// relay was indeed the one that we wanted to reach.)
    fn record_handshake_done(&mut self, now: Instant) {
    fn record_handshake_done(&mut self, now: Instant) {
        self.last_chan_auth_success = Some(now);
        self.last_chan_success = Some(now);
        self.last_chan_success = Some(now);
    }
    }
}
}
@@ -312,6 +363,14 @@ impl ChanMgrEventSender {
        self.push_at(now);
        self.push_at(now);
    }
    }


    /// Record that a handshake has succeeded _except for the certificate
    /// timeliness check, which may indicate a skewed clock.
    pub(crate) fn record_handshake_done_with_skewed_clock(&mut self) {
        let now = Instant::now();
        self.mgr_status.record_handshake_done_with_skewed_clock(now);
        self.push_at(now);
    }

    /// Note that we've completed a Tor handshake with a relay.
    /// Note that we've completed a Tor handshake with a relay.
    ///
    ///
    /// (This includes performing the TLS handshake, and verifying that the
    /// (This includes performing the TLS handshake, and verifying that the
@@ -355,7 +414,8 @@ mod test {


        let s2 = ConnStatus {
        let s2 = ConnStatus {
            online: Some(false),
            online: Some(false),
            tls_works: None,
            auth_works: None,
            handshake_works: None,
        };
        };
        assert_eq!(s2.to_string(), "unable to connect to the internet");
        assert_eq!(s2.to_string(), "unable to connect to the internet");
        assert_float_eq!(s2.frac(), 0.0, abs <= TOL);
        assert_float_eq!(s2.frac(), 0.0, abs <= TOL);
@@ -370,7 +430,8 @@ mod test {


        let s3 = ConnStatus {
        let s3 = ConnStatus {
            online: Some(true),
            online: Some(true),
            tls_works: None,
            auth_works: None,
            handshake_works: None,
        };
        };
        assert_eq!(s3.to_string(), "handshaking with Tor relays");
        assert_eq!(s3.to_string(), "handshaking with Tor relays");
        assert_float_eq!(s3.frac(), 0.5, abs <= TOL);
        assert_float_eq!(s3.frac(), 0.5, abs <= TOL);
@@ -380,7 +441,8 @@ mod test {


        let s4 = ConnStatus {
        let s4 = ConnStatus {
            online: Some(true),
            online: Some(true),
            tls_works: Some(false),
            auth_works: Some(false),
            handshake_works: Some(false),
        };
        };
        assert_eq!(s4.to_string(), "unable to handshake with Tor relays");
        assert_eq!(s4.to_string(), "unable to handshake with Tor relays");
        assert_float_eq!(s4.frac(), 0.5, abs <= TOL);
        assert_float_eq!(s4.frac(), 0.5, abs <= TOL);
@@ -397,7 +459,8 @@ mod test {


        let s5 = ConnStatus {
        let s5 = ConnStatus {
            online: Some(true),
            online: Some(true),
            tls_works: Some(true),
            auth_works: Some(true),
            handshake_works: Some(true),
        };
        };
        assert_eq!(s5.to_string(), "connecting successfully");
        assert_eq!(s5.to_string(), "connecting successfully");
        assert_float_eq!(s5.frac(), 1.0, abs <= TOL);
        assert_float_eq!(s5.frac(), 1.0, abs <= TOL);
@@ -418,7 +481,7 @@ mod test {
        // when we start, we're unable to reach any conclusions.
        // when we start, we're unable to reach any conclusions.
        let s0 = ms.conn_status_at(start);
        let s0 = ms.conn_status_at(start);
        assert!(s0.online.is_none());
        assert!(s0.online.is_none());
        assert!(s0.tls_works.is_none());
        assert!(s0.handshake_works.is_none());


        // Time won't let us make conclusions either, unless there have been
        // Time won't let us make conclusions either, unless there have been
        // attempts.
        // attempts.
@@ -436,22 +499,22 @@ mod test {
        // (... but after a while.)
        // (... but after a while.)
        let s = ms.conn_status_at(start + hour);
        let s = ms.conn_status_at(start + hour);
        assert_eq!(s.online, Some(false));
        assert_eq!(s.online, Some(false));
        assert_eq!(s.tls_works, Some(false));
        assert_eq!(s.handshake_works, Some(false));


        // If TCP has succeeded, we should notice that.
        // If TCP has succeeded, we should notice that.
        ms.record_tcp_success(start + sec);
        ms.record_tcp_success(start + sec);
        let s = ms.conn_status_at(start + sec * 2);
        let s = ms.conn_status_at(start + sec * 2);
        assert_eq!(s.online, Some(true));
        assert_eq!(s.online, Some(true));
        assert!(s.tls_works.is_none());
        assert!(s.handshake_works.is_none());
        let s = ms.conn_status_at(start + hour);
        let s = ms.conn_status_at(start + hour);
        assert_eq!(s.online, Some(true));
        assert_eq!(s.online, Some(true));
        assert_eq!(s.tls_works, Some(false));
        assert_eq!(s.handshake_works, Some(false));


        // If the handshake succeeded, we can notice that too.
        // If the handshake succeeded, we can notice that too.
        ms.record_handshake_done(start + sec * 2);
        ms.record_handshake_done(start + sec * 2);
        let s = ms.conn_status_at(start + sec * 3);
        let s = ms.conn_status_at(start + sec * 3);
        assert_eq!(s.online, Some(true));
        assert_eq!(s.online, Some(true));
        assert_eq!(s.tls_works, Some(true));
        assert_eq!(s.handshake_works, Some(true));
    }
    }


    #[test]
    #[test]
Loading