src/reporter.rs

   1 // Copyright 2021 Ian Jackson, yaahc and contributors to Hippotat and Eyre
   2 // SPDX-License-Identifier: GPL-3.0-or-later
   3 // There is NO WARRANTY.
   4
   5 use crate::prelude::*;
   6
   7 #[derive(StructOpt,Debug)]
   8 pub struct LogOpts {
   9   /// Increase debug level
  10   ///
  11   /// May be repeated for more verbosity.
  12   ///
  13   /// When using syslog, one `-D` this arranges to send to syslog even
  14   /// trace messages (mapped onto syslog level `DEBUG`);
  15   /// and two -`D` means to send to syslog even messages from lower layers
  16   /// (normally just the hippotat modules log to
  17   /// syslog).
  18   #[structopt(long, short="D", parse(from_occurrences))]
  19   debug: usize,
  20
  21   /// Syslog facility to use
  22   #[structopt(long, parse(try_from_str=parse_syslog_facility))]
  23   syslog_facility: Option<syslog::Facility>,
  24 }
  25
  26 #[throws(AE)]
  27 fn parse_syslog_facility(s: &str) -> syslog::Facility {
  28   s.parse().map_err(|()| anyhow!("unrecognised syslog facility: {:?}", s))?
  29 }
  30
  31 #[derive(Debug)]
  32 struct FilteringLogWrapper<T>(T);
  33
  34 impl<T> FilteringLogWrapper<T> {
  35   fn wanted(&self, md: &log::Metadata<'_>) -> bool {
  36     let first = |mod_path| {
  37       let mod_path: &str = mod_path; // can't do in args as breaks lifetimes
  38       mod_path.split_once("::").map(|s| s.0).unwrap_or(mod_path)
  39     };
  40     first(md.target()) == first(module_path!())
  41   }
  42 }
  43
  44 impl<T> log::Log for FilteringLogWrapper<T> where T: log::Log {
  45   fn enabled(&self, md: &log::Metadata<'_>) -> bool {
  46     self.wanted(md) && self.0.enabled(md)
  47   }
  48
  49   fn log(&self, record: &log::Record<'_>) {
  50     if self.wanted(record.metadata()) {
  51       self.0.log(record)
  52     }
  53   }
  54
  55   fn flush(&self) {
  56     self.0.flush()
  57   }
  58 }
  59
  60 impl LogOpts {
  61   #[throws(AE)]
  62   pub fn log_init(&self) {
  63     if let Some(facility) = self.syslog_facility {
  64       let f = syslog::Formatter3164 {
  65         facility,
  66         hostname: None,
  67         process: "hippotatd".into(),
  68         pid: std::process::id(),
  69       };
  70       let l = syslog::unix(f)
  71         // syslog::Error is not Sync.
  72         // https://github.com/Geal/rust-syslog/issues/65
  73         .map_err(|e| anyhow!(e.to_string()))
  74         .context("set up syslog logger")?;
  75       let l = syslog::BasicLogger::new(l);
  76       let l = if self.debug < 2 {
  77         Box::new(FilteringLogWrapper(l)) as _
  78       } else {
  79         Box::new(l) as _
  80       };
  81       log::set_boxed_logger(l).context("install syslog logger")?;
  82       log::set_max_level(if self.debug < 1 {
  83         log::LevelFilter::Debug
  84       } else {
  85         log::LevelFilter::Trace
  86       });
  87     } else {
  88       let env = env_logger::Env::new()
  89         .filter("HIPPOTAT_LOG")
  90         .write_style("HIPPOTAT_LOG_STYLE");
  91
  92       let mut logb = env_logger::Builder::new();
  93       logb.filter(Some("hippotat"),
  94                   *[ log::LevelFilter::Info,
  95                      log::LevelFilter::Debug ]
  96                   .get(self.debug)
  97                   .unwrap_or(
  98                     &log::LevelFilter::Trace
  99                   ));
 100       logb.parse_env(env);
 101       logb.init();
 102     }
 103   }
 104 }
 105
 106 pub struct OptionPrefixColon<T>(pub Option<T>);
 107 impl<T:Display> Display for OptionPrefixColon<T> {
 108   #[throws(fmt::Error)]
 109   fn fmt(&self, f: &mut fmt::Formatter) {
 110     if let Some(x) = &self.0 { write!(f, "{}: ", x)? }
 111   }
 112 }
 113
 114 // For clients only, really.
 115 pub struct Reporter<'r> {
 116   ic: &'r InstanceConfig,
 117   successes: u64,
 118   last_report: Option<Report>,
 119 }
 120
 121 #[derive(Debug)]
 122 struct Report {
 123   when: Instant,
 124   ok: Result<(),()>,
 125 }
 126
 127 // Reporting strategy
 128 //   - report all errors
 129 //   - report first success after a period of lack of messages
 130 //   - if error, report last success
 131
 132 impl<'r> Reporter<'r> {
 133   pub fn new(ic: &'r InstanceConfig) -> Self { Reporter {
 134     ic,
 135     successes: 0,
 136     last_report: None,
 137   } }
 138
 139   pub fn success(&mut self) {
 140     self.successes += 1;
 141     let now = Instant::now();
 142     if let Some(rep) = &self.last_report {
 143       if now - rep.when < match rep.ok {
 144         Ok(()) => match self.ic.success_report_interval {
 145           z if z == Duration::default() => return,
 146           nonzero => nonzero,
 147         },
 148         Err(()) => self.ic.effective_http_timeout,
 149       } {
 150         return
 151       }
 152     }
 153
 154     info!(target:"hippotat", "{} ({}ok): running", self.ic, self.successes);
 155     self.last_report = Some(Report { when: now, ok: Ok(()) });
 156   }
 157
 158   pub fn filter<T>(&mut self, req_num: Option<ReqNum>, r: Result<T,AE>)
 159                    -> Option<T> {
 160     let now = Instant::now();
 161     match r {
 162       Ok(t) => {
 163         Some(t)
 164       },
 165       Err(e) => {
 166         let m = (||{
 167           let mut m = self.ic.to_string();
 168           if let Some(req_num) = req_num {
 169             write!(m, " #{}", req_num)?;
 170           }
 171           if self.successes > 0 {
 172             write!(m, " ({}ok)", self.successes)?;
 173             self.successes = 0;
 174           }
 175           write!(m, ": {}", e)?;
 176           Ok::<_,fmt::Error>(m)
 177         })().unwrap();
 178         warn!(target:"hippotat", "{}", m);
 179         self.last_report = Some(Report { when: now, ok: Err(()) });
 180         None
 181       },
 182     }
 183   }
 184 }
 185
 186 use backtrace::Backtrace;
 187 use eyre::Chain;
 188 use indenter::indented;
 189
 190 #[derive(Debug)]
 191 struct EyreDedupHandler {
 192   backtrace: Option<Arc<parking_lot::Mutex<Backtrace>>>,
 193 }
 194
 195 type EyreDynError<'r> = &'r (dyn std::error::Error + 'static);
 196
 197 impl eyre::EyreHandler for EyreDedupHandler {
 198   #[throws(fmt::Error)]
 199   fn display(&self, error: EyreDynError, f: &mut fmt::Formatter) {
 200     let mut last: Option<String> = None;
 201     let mut error = Some(error);
 202     while let Some(e) = error {
 203       let m = e.to_string();
 204       match last {
 205         None => write!(f, "{}", m)?,
 206         Some(l) if l.contains(&m) => { },
 207         Some(_) => write!(f, ": {}", m)?,
 208       }
 209       last = Some(m);
 210       error = e.source();
 211     }
 212   }
 213
 214   #[throws(fmt::Error)]
 215   fn debug(&self, error: EyreDynError, f: &mut fmt::Formatter) {
 216     if f.alternate() {
 217       return core::fmt::Debug::fmt(error, f)?;
 218     }
 219
 220     write!(f, "{}", error)?;
 221
 222     if let Some(cause) = error.source() {
 223       write!(f, "\n\nCaused by:")?;
 224       let multiple = cause.source().is_some();
 225
 226       for (n, error) in Chain::new(cause).enumerate() {
 227         writeln!(f)?;
 228         if multiple {
 229           write!(indented(f).ind(n), "{}", error)?;
 230         } else {
 231           write!(indented(f), "{}", error)?;
 232         }
 233       }
 234     }
 235
 236     if let Some(bt) = &self.backtrace {
 237       let mut bt = bt.lock();
 238       bt.resolve();
 239       write!(f, "\n\nStack backtrace:\n{:?}", bt)?;
 240     }
 241   }
 242 }
 243
 244 #[throws(AE)]
 245 pub fn dedup_eyre_setup() {
 246   eyre::set_hook(Box::new(|_error| {
 247     lazy_static! {
 248       static ref BACKTRACE: bool = {
 249         match env::var("RUST_BACKTRACE") {
 250           Ok(s) if s.starts_with("1") => true,
 251           Ok(s) if s == "0" => false,
 252           Err(env::VarError::NotPresent) => false,
 253           x => {
 254             eprintln!("warning: RUST_BACKTRACE not understood: {:?}", x);
 255             false
 256           },
 257         }
 258       };
 259     }
 260     let backtrace = if *BACKTRACE {
 261       let bt = Backtrace::new_unresolved();
 262       let bt = Arc::new(bt.into());
 263       Some(bt)
 264     } else {
 265       None
 266     };
 267     Box::new(EyreDedupHandler { backtrace })
 268   }))
 269     .context("set error handler")?;
 270 }
 271
 272 const MAX_WARNINGS: usize = 15;
 273
 274 #[derive(Debug,Default)]
 275 pub struct Warnings {
 276   pub warnings: Vec<String>,
 277 }
 278
 279 #[derive(Debug,Error)]
 280 #[error("too many warnings")]
 281 pub struct TooManyWarnings;
 282
 283 impl Warnings {
 284   #[throws(TooManyWarnings)]
 285   pub fn add(&mut self, e: &dyn Display) {
 286     if self.warnings.len() >= MAX_WARNINGS { throw!(TooManyWarnings) }
 287     self.warnings.push(e.to_string());
 288   }
 289 }