runtimes: dont log unauthenticated as error

runtimes/core/src/api/auth/local.rs

@@ -100,7 +100,13 @@ impl AuthHandler for LocalAuthHandler {
  let duration = tokio::time::Instant::now().duration_since(req.start);
 
  if let Err(e) = &auth_response {
- logger.error(Some(&req), "auth handler failed", Some(e), None);
+ if e.code == api::ErrCode::Unauthenticated {
+ logger.debug(Some(&req), "auth handler returned unauthenticated", None);
+ } else {
+ logger
+ .with_error(e)
+ .error(Some(&req), "auth handler failed", None);
+ }
  }
  logger.info(Some(&req), "auth handler completed", {
  let mut fields = crate::log::Fields::new();

runtimes/core/src/api/endpoint.rs

@@ -613,30 +613,32 @@ impl EndpointHandler {
 
  // If we had a request failure, log that separately.
  if let ResponseData::Typed(Err(err)) = &resp {
- logger.error(Some(&request), "request failed", Some(err), {
- let mut fields = crate::log::Fields::new();
- fields.insert(
- "code".into(),
- serde_json::Value::String(err.code.to_string()),
- );
-
- if let Some(internal_message) = &err.internal_message {
+ logger
+ .with_error(err)
+ .error(Some(&request), "request failed", {
+ let mut fields = crate::log::Fields::new();
  fields.insert(
- "internal_message".into(),
- serde_json::Value::String(internal_message.clone()),
+ "code".into(),
+ serde_json::Value::String(err.code.to_string()),
  );
- }
 
- if *ENCORE_LOG_INCLUDE_ERROR_STACK {
- if let Some(stack) = &err.stack {
- if let Ok(value) = serde_json::to_value(stack) {
- fields.insert("stack".into(), value);
+ if let Some(internal_message) = &err.internal_message {
+ fields.insert(
+ "internal_message".into(),
+ serde_json::Value::String(internal_message.clone()),
+ );
+ }
+
+ if *ENCORE_LOG_INCLUDE_ERROR_STACK {
+ if let Some(stack) = &err.stack {
+ if let Ok(value) = serde_json::to_value(stack) {
+ fields.insert("stack".into(), value);
+ }
  }
  }
- }
 
- Some(fields)
- });
+  Some(fields)
+  });
  }
 
  let code = match &resp {

runtimes/core/src/log/logger.rs

@@ -22,6 +22,7 @@ pub struct Logger {
  writer: Arc<dyn Writer>,
  extra_fields: Fields,
  tracer: Arc<RwLock<Tracer>>,
+ error: Option<AppError>,
 }
 
 impl Logger {
@@ -38,6 +39,7 @@ impl Logger {
  writer: default_writer(field_config),
  extra_fields: Fields::new(),
  tracer: Arc::new(RwLock::new(Tracer::noop())),
+ error: None,
  }
  }
 
@@ -77,6 +79,15 @@ impl Logger {
  replacement
  }
 
+ /// Returns a new logger with the given error attached.
+ /// The error will be included in subsequent log calls.
+ pub fn with_error<Err: Into<AppError>>(&self, error: Err) -> Self {
+ Self {
+ error: Some(error.into()),
+ ..self.clone()
+ }
+ }
+
  /// Returns the current log level as expected by the `log` crate.
  fn level_to_value(&self, level: ::log::Level) -> serde_json::Value {
  serde_json::Value::from(match level {
@@ -332,24 +343,9 @@ impl Logger {
 pub trait LogFromRust<T: std::fmt::Display> {
  fn trace(&self, req: Option<&model::Request>, msg: T, fields: Option<Fields>);
  fn debug(&self, req: Option<&model::Request>, msg: T, fields: Option<Fields>);
-
  fn info(&self, req: Option<&model::Request>, msg: T, fields: Option<Fields>);
-
- fn warn<Err: Into<AppError>>(
- &self,
- req: Option<&model::Request>,
- msg: T,
- error: Option<Err>,
- fields: Option<Fields>,
- );
-
- fn error<Err: Into<AppError>>(
- &self,
- req: Option<&model::Request>,
- msg: T,
- error: Option<Err>,
- fields: Option<Fields>,
- );
+ fn warn(&self, req: Option<&model::Request>, msg: T, fields: Option<Fields>);
+ fn error(&self, req: Option<&model::Request>, msg: T, fields: Option<Fields>);
 }
 
 /// This trait defines the logging functions that are available on the `Logger` type.
@@ -407,8 +403,15 @@ where
  return;
  }
 
- self.try_log(req, log::Level::Trace, msg.to_string(), None, None, fields)
- .expect("failed to log");
+ self.try_log(
+ req,
+ log::Level::Trace,
+ msg.to_string(),
+ self.error.clone(),
+ None,
+ fields,
+ )
+ .expect("failed to log");
  }
 
  #[track_caller]
@@ -417,8 +420,15 @@ where
  return;
  }
 
- self.try_log(req, log::Level::Debug, msg.to_string(), None, None, fields)
- .expect("failed to log");
+ self.try_log(
+ req,
+ log::Level::Debug,
+ msg.to_string(),
+ self.error.clone(),
+ None,
+ fields,
+ )
+ .expect("failed to log");
  }
 
  #[track_caller]
@@ -427,18 +437,19 @@ where
  return;
  }
 
- self.try_log(req, log::Level::Info, msg.to_string(), None, None, fields)
- .expect("failed to log");
+ self.try_log(
+ req,
+ log::Level::Info,
+ msg.to_string(),
+ self.error.clone(),
+ None,
+ fields,
+ )
+ .expect("failed to log");
  }
 
  #[track_caller]
- fn warn<Err: Into<AppError>>(
- &self,
- req: Option<&model::Request>,
- msg: T,
- error: Option<Err>,
- fields: Option<Fields>,
- ) {
+ fn warn(&self, req: Option<&model::Request>, msg: T, fields: Option<Fields>) {
  if log::Level::Warn > self.app_level {
  return;
  }
@@ -447,21 +458,15 @@ where
  req,
  log::Level::Warn,
  msg.to_string(),
- error.map(|e| e.into().trim_stack(file!(), line!(), 1)),
+ self.error.clone(),
  None,
  fields,
  )
  .expect("failed to log");
  }
 
  #[track_caller]
- fn error<Err: Into<AppError>>(
- &self,
- req: Option<&model::Request>,
- msg: T,
- error: Option<Err>,
- fields: Option<Fields>,
- ) {
+ fn error(&self, req: Option<&model::Request>, msg: T, fields: Option<Fields>) {
  if log::Level::Error > self.app_level {
  return;
  }
@@ -470,7 +475,7 @@ where
  req,
  log::Level::Error,
  msg.to_string(),
- error.map(|e| e.into().trim_stack(file!(), line!(), 1)),
+ self.error.clone(),
  None,
  fields,
  )

runtimes/go/appruntime/apisdk/api/reqtrack.go

@@ -188,7 +188,11 @@ func (s *Server) finishRequest(resp *model.Response) {
 if resp.Err != nil {
 switch req.Type {
 case model.AuthHandler:
-req.Logger.Error().Err(resp.Err).Msg("auth handler failed")
+if errs.Code(resp.Err) == errs.Unauthenticated {
+req.Logger.Debug().Msg("auth handler returned unauthenticated")
+} else {
+req.Logger.Error().Err(resp.Err).Msg("auth handler failed")
+}
 default:
 e := errs.Convert(resp.Err).(*errs.Error)
 ev := req.Logger.Error()