add some basic structured logging to the builder

This commit is contained in:
Daiderd Jordan 2020-05-01 20:13:50 +02:00
parent 35e08cb5d1
commit 82e12ebe52
No known key found for this signature in database
GPG key ID: D02435D05B810C96
3 changed files with 18 additions and 12 deletions

View file

@ -126,11 +126,7 @@ impl Config {
pub fn nix(&self) -> Nix { pub fn nix(&self) -> Nix {
if self.nix.build_timeout_seconds < 1200 { if self.nix.build_timeout_seconds < 1200 {
error!( error!(?self.nix.build_timeout_seconds, "Please set build_timeout_seconds to at least 1200");
"Note: {} is way too low for build_timeout_seconds!",
self.nix.build_timeout_seconds
);
error!("Please set build_timeout_seconds to at least 1200");
panic!(); panic!();
} }

View file

@ -96,6 +96,7 @@ impl<W: SimpleWorker + 'static> ConsumerExt<W> for CloseOnDrop<Channel> {
))?; ))?;
Ok(Box::pin(async move { Ok(Box::pin(async move {
while let Some(Ok(deliver)) = consumer.next().await { while let Some(Ok(deliver)) = consumer.next().await {
debug!(?deliver.delivery_tag, "consumed delivery");
let content_type = deliver.properties.content_type(); let content_type = deliver.properties.content_type();
let job = worker let job = worker
.msg_to_job( .msg_to_job(
@ -110,6 +111,7 @@ impl<W: SimpleWorker + 'static> ConsumerExt<W> for CloseOnDrop<Channel> {
.await .await
.expect("action deliver failure"); .expect("action deliver failure");
} }
debug!(?deliver.delivery_tag, "done");
} }
})) }))
} }
@ -147,7 +149,7 @@ impl<W: SimpleNotifyWorker + 'static> ConsumerExt<W> for NotifyChannel {
let mut chan = self.0; let mut chan = self.0;
Ok(Box::pin(async move { Ok(Box::pin(async move {
while let Some(Ok(deliver)) = consumer.next().await { while let Some(Ok(deliver)) = consumer.next().await {
debug!("delivery {}", deliver.delivery_tag); debug!(?deliver.delivery_tag, "consumed delivery");
let mut receiver = ChannelNotificationReceiver { let mut receiver = ChannelNotificationReceiver {
channel: &mut chan, channel: &mut chan,
deliver: &deliver, deliver: &deliver,
@ -163,6 +165,7 @@ impl<W: SimpleNotifyWorker + 'static> ConsumerExt<W> for NotifyChannel {
.expect("worker unexpected message consumed"); .expect("worker unexpected message consumed");
worker.consumer(&job, &mut receiver); worker.consumer(&job, &mut receiver);
debug!(?deliver.delivery_tag, "done");
} }
})) }))
} }
@ -175,25 +178,25 @@ async fn action_deliver(
) -> Result<(), lapin::Error> { ) -> Result<(), lapin::Error> {
match action { match action {
Action::Ack => { Action::Ack => {
debug!("action ack"); debug!(?deliver.delivery_tag, "action ack");
chan.basic_ack(deliver.delivery_tag, BasicAckOptions::default()) chan.basic_ack(deliver.delivery_tag, BasicAckOptions::default())
.await .await
} }
Action::NackRequeue => { Action::NackRequeue => {
debug!("action nack requeue"); debug!(?deliver.delivery_tag, "action nack requeue");
let mut opts = BasicNackOptions::default(); let mut opts = BasicNackOptions::default();
opts.requeue = true; opts.requeue = true;
chan.basic_nack(deliver.delivery_tag, opts).await chan.basic_nack(deliver.delivery_tag, opts).await
} }
Action::NackDump => { Action::NackDump => {
debug!("action nack dump"); debug!(?deliver.delivery_tag, "action nack dump");
chan.basic_nack(deliver.delivery_tag, BasicNackOptions::default()) chan.basic_nack(deliver.delivery_tag, BasicNackOptions::default())
.await .await
} }
Action::Publish(mut msg) => { Action::Publish(mut msg) => {
let exch = msg.exchange.take().unwrap_or_else(|| "".to_owned()); let exch = msg.exchange.take().unwrap_or_else(|| "".to_owned());
let key = msg.routing_key.take().unwrap_or_else(|| "".to_owned()); let key = msg.routing_key.take().unwrap_or_else(|| "".to_owned());
debug!("action publish {}", exch); debug!(?exch, ?key, "action publish");
let mut props = BasicProperties::default().with_delivery_mode(2); // persistent. let mut props = BasicProperties::default().with_delivery_mode(2); // persistent.

View file

@ -8,8 +8,8 @@ use crate::worker;
use std::collections::VecDeque; use std::collections::VecDeque;
use tracing::{debug, debug_span, error, info};
use uuid::Uuid; use uuid::Uuid;
use tracing::{error, info};
pub struct BuildWorker { pub struct BuildWorker {
cloner: checkout::CachedCloner, cloner: checkout::CachedCloner,
@ -276,14 +276,21 @@ impl notifyworker::SimpleNotifyWorker for BuildWorker {
job: &buildjob::BuildJob, job: &buildjob::BuildJob,
notifier: &mut dyn notifyworker::NotificationReceiver, notifier: &mut dyn notifyworker::NotificationReceiver,
) { ) {
let span = debug_span!("job", pr = ?job.pr.number);
let _enter = span.enter();
let mut actions = self.actions(&job, notifier); let mut actions = self.actions(&job, notifier);
if job.attrs.is_empty() { if job.attrs.is_empty() {
debug!("No attrs to build");
actions.nothing_to_do(); actions.nothing_to_do();
return; return;
} }
info!("Working on {}", job.pr.number); info!(
"Working on https://github.com/{}/pull/{}",
job.repo.full_name, job.pr.number
);
let project = self let project = self
.cloner .cloner
.project(&job.repo.full_name, job.repo.clone_url.clone()); .project(&job.repo.full_name, job.repo.clone_url.clone());