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