rad:zwTxygwuz5LDGBq255RA2CbNGrz8 radicle-ci-broker85414e8673da912b6370f9bf0e82b71046680581{
"request": "trigger",
"version": 1,
"event_type": "push",
"repository": {
"id": "rad:zwTxygwuz5LDGBq255RA2CbNGrz8",
"name": "radicle-ci-broker",
"description": "Radicle CI broker",
"private": false,
"default_branch": "main",
"delegates": [
"did:key:z6MkgEMYod7Hxfy9qCvDv5hYHkZ4ciWmLFgfvm3Wn1b2w2FV",
"did:key:z6MksFqXN3Yhqk8pTJdUGLwATkRfQvwZXPqR2qMEhbS9wzpT"
]
},
"pusher": {
"id": "did:key:z6MkgEMYod7Hxfy9qCvDv5hYHkZ4ciWmLFgfvm3Wn1b2w2FV",
"alias": "liw"
},
"before": "f0a995900e57c181e879d6520e47d69d5d6ee891",
"after": "85414e8673da912b6370f9bf0e82b71046680581",
"branch": "main",
"commits": [
"85414e8673da912b6370f9bf0e82b71046680581"
]
}.radicle/native.yamlshell: | cargo --version rustc --version cargo fmt --check cargo clippy --all-targets --workspace -- -Dwarnings cargo build --all-targets --workspace cargo doc --workspace cargo test --workspace --no-fail-fast subplot docgen ci-broker.subplot -o doc/ci-broker.html make -C doc publish
git clone /home/_rad/.radicle/storage/zwTxygwuz5LDGBq255RA2CbNGrz8 /srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/srcgit config advice.detachedHead falsegit checkout 85414e8673da912b6370f9bf0e82b71046680581git show 85414e8673da912b6370f9bf0e82b71046680581timeout 600 bash -c set -xeuo pipefail
cargo --version
rustc --version
cargo fmt --check
cargo clippy --all-targets --workspace -- -Dwarnings
cargo build --all-targets --workspace
cargo doc --workspace
cargo test --workspace --no-fail-fast
subplot docgen ci-broker.subplot -o doc/ci-broker.html
make -C doc publish
git clone /home/_rad/.radicle/storage/zwTxygwuz5LDGBq255RA2CbNGrz8 /srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/srcCommand arguments:
"git""clone""/home/_rad/.radicle/storage/zwTxygwuz5LDGBq255RA2CbNGrz8""/srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src"In directory: /
Exit code: 0
Output (stdout and stderr):
Cloning into '/srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src'... done.
git config advice.detachedHead falseCommand arguments:
"git""config""advice.detachedHead""false"In directory: /srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src
Exit code: 0
git checkout 85414e8673da912b6370f9bf0e82b71046680581Command arguments:
"git""checkout""85414e8673da912b6370f9bf0e82b71046680581"In directory: /srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src
Exit code: 0
Output (stdout and stderr):
HEAD is now at 85414e8 feat: switch to structured logging only
git show 85414e8673da912b6370f9bf0e82b71046680581Command arguments:
"git""show""85414e8673da912b6370f9bf0e82b71046680581"In directory: /srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src
Exit code: 0
Output (stdout and stderr):
commit 85414e8673da912b6370f9bf0e82b71046680581
Author: Lars Wirzenius <liw@liw.fi>
Date: Fri Aug 23 09:50:57 2024 +0300
feat: switch to structured logging only
Replace all use of log and env-logger crates with structured logging
using slog and slog-json.
Change the recently introduced logger module to use the slog-scope
crate. This avoids having to pass a reference to logger::Logging to
every place that needs to do any logging.
Signed-off-by: Lars Wirzenius <liw@liw.fi>
diff --git a/Cargo.lock b/Cargo.lock
index 0c37144..1e35935 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -178,6 +178,12 @@ version = "1.0.86"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "b3d1d046238990b9cf5bcde22a3fb3584ee5cf65fb2765f454ed428c7a0063da"
+[[package]]
+name = "arc-swap"
+version = "1.7.1"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "69f7f8c3906b62b754cd5326047894316021dcfe5a194c8ea52bdd94934a3457"
+
[[package]]
name = "arraydeque"
version = "0.5.1"
@@ -500,6 +506,16 @@ version = "1.1.1"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "f3b7eb4404b8195a9abb6356f4ac07d8ba267045c8d6d220ac4dc992e6cc75df"
+[[package]]
+name = "ctor"
+version = "0.2.8"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "edb49164822f3ee45b17acd4a208cfc1251410cf0cad9a833234c9890774dd9f"
+dependencies = [
+ "quote",
+ "syn 2.0.75",
+]
+
[[package]]
name = "ctr"
version = "0.9.2"
@@ -702,16 +718,6 @@ dependencies = [
"cfg-if",
]
-[[package]]
-name = "env_filter"
-version = "0.1.2"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "4f2c92ceda6ceec50f43169f9ee8424fe2db276791afde7b2cd8bc084cb376ab"
-dependencies = [
- "log",
- "regex",
-]
-
[[package]]
name = "env_logger"
version = "0.10.2"
@@ -725,19 +731,6 @@ dependencies = [
"termcolor",
]
-[[package]]
-name = "env_logger"
-version = "0.11.5"
-source = "registry+https://github.com/rust-lang/crates.io-index"
-checksum = "e13fa619b91fb2381732789fc5de83b45675e882f66623b7d8cb4f643017018d"
-dependencies = [
- "anstream",
- "anstyle",
- "env_filter",
- "humantime",
- "log",
-]
-
[[package]]
name = "equivalent"
version = "1.0.1"
@@ -1729,10 +1722,9 @@ version = "0.4.0"
dependencies = [
"anyhow",
"clap",
+ "ctor",
"culpa",
- "env_logger 0.11.5",
"html-page",
- "log",
"radicle",
"radicle-git-ext",
"radicle-surf",
@@ -1742,6 +1734,7 @@ dependencies = [
"serde_yml",
"slog",
"slog-json",
+ "slog-scope",
"sqlite",
"sqlite3-sys",
"subplot-build",
@@ -2214,6 +2207,17 @@ dependencies = [
"time",
]
+[[package]]
+name = "slog-scope"
+version = "4.4.0"
+source = "registry+https://github.com/rust-lang/crates.io-index"
+checksum = "2f95a4b4c3274cd2869549da82b57ccc930859bdbf5bcea0424bc5f140b3c786"
+dependencies = [
+ "arc-swap",
+ "lazy_static",
+ "slog",
+]
+
[[package]]
name = "slug"
version = "0.1.6"
@@ -2371,7 +2375,7 @@ dependencies = [
"anyhow",
"base64 0.22.1",
"clap",
- "env_logger 0.10.2",
+ "env_logger",
"file_diff",
"git-testament",
"html-escape",
diff --git a/Cargo.toml b/Cargo.toml
index efa093d..c1590af 100644
--- a/Cargo.toml
+++ b/Cargo.toml
@@ -13,9 +13,7 @@ categories = ["development-tools::build-utils"]
[dependencies]
anyhow = "1.0.86"
clap = { version = "4.5.11", features = ["derive", "wrap_help"] }
-env_logger = "0.11.5"
html-page = "0.4.0"
-log = "0.4.22"
radicle-git-ext = "0.7.0"
radicle-surf = { version = "0.18.0", default-features = false, features = ["serde"] }
regex = "1.10.5"
@@ -24,6 +22,7 @@ serde_json = "1.0.121"
serde_yml = "0.0.11"
slog = "2.7.0"
slog-json = "2.6.1"
+slog-scope = "4.4.0"
sqlite = "0.32.0"
sqlite3-sys = "0.15.0"
subplotlib = "0.10.0"
@@ -36,6 +35,7 @@ version = "0.12.0"
features = ["default", "test"]
[dev-dependencies]
+ctor = "0.2.8"
culpa = "1.0.2"
tempfile = { version = "3.10.1" }
diff --git a/src/adapter.rs b/src/adapter.rs
index 46089db..79487ee 100644
--- a/src/adapter.rs
+++ b/src/adapter.rs
@@ -15,10 +15,9 @@ use std::{
process::{Command, Stdio},
};
-use log::{debug, error};
-
use crate::{
db::{Db, DbError},
+ logger,
msg::{MessageError, Request, Response},
run::{Run, RunState},
};
@@ -52,8 +51,6 @@ impl Adapter {
}
pub fn run(&self, trigger: &Request, run: &mut Run, db: &Db) -> Result<(), AdapterError> {
- debug!("running adapter");
-
run.set_state(RunState::Triggered);
db.update_run(run).map_err(AdapterError::UpdateRun)?;
@@ -69,7 +66,6 @@ impl Adapter {
assert!(matches!(trigger, Request::Trigger { .. }));
// Spawn the adapter sub-process.
- debug!("spawn adapter sub-process: {:?}", self.bin);
let mut child = Command::new(&self.bin)
.stdin(Stdio::piped())
.stdout(Stdio::piped())
@@ -81,7 +77,6 @@ impl Adapter {
// Write the request to trigger a run to the child's stdin.
// Then close the pipe to prevent the child from trying to
// read another message that will never be sent.
- debug!("send request to sub-process stdin");
{
let stdin = child.stdin.take().ok_or(AdapterError::StdinHandle)?;
trigger
@@ -98,7 +93,6 @@ impl Adapter {
if let Some(line) = lines.next() {
let line = line.map_err(AdapterError::ReadLine)?;
let resp = Response::from_str(&line).map_err(AdapterError::ParseResponse)?;
- debug!("first response {resp:#?}");
match resp {
Response::Triggered { run_id, info_url } => {
run.set_state(RunState::Running);
@@ -111,13 +105,12 @@ impl Adapter {
_ => return Err(AdapterError::NotTriggered(resp)),
}
} else {
- debug!("no first response message");
+ logger::adapter_no_first_response();
}
if let Some(line) = lines.next() {
let line = line.map_err(AdapterError::ReadLine)?;
let resp = Response::from_str(&line).map_err(AdapterError::ParseResponse)?;
- debug!("second response {resp:#?}");
match resp {
Response::Finished { result } => {
run.set_result(result);
@@ -126,22 +119,18 @@ impl Adapter {
_ => return Err(AdapterError::NotFinished(resp)),
}
} else {
- debug!("no second response message");
+ logger::adapter_no_second_response();
}
if let Some(line) = lines.next() {
let line = line.map_err(AdapterError::ReadLine)?;
let resp = Response::from_str(&line).map_err(AdapterError::ParseResponse)?;
- debug!("third response is too many {resp:#?}");
+ logger::adapter_too_many_responses();
return Err(AdapterError::TooMany(resp));
- } else {
- debug!("no further response messages");
}
let wait = child.wait().map_err(AdapterError::Wait)?;
- debug!("adapter wait result {wait:#?}");
if let Some(exit) = wait.code() {
- debug!("adapter exit was {exit}");
if exit != 0 {
let mut stderr = child.stderr.take().ok_or(AdapterError::StderrHandle)?;
let mut buf = vec![];
@@ -149,11 +138,11 @@ impl Adapter {
.read_to_end(&mut buf)
.map_err(AdapterError::ReadStderr)?;
let stderr = String::from_utf8_lossy(&buf);
- debug!("adapter stderr: {stderr:?}");
+ logger::adapter_result(exit, &stderr.to_string());
return Err(AdapterError::Failed(exit));
}
} else {
- error!("adapter sub-process did not exit voluntarily");
+ logger::adapter_did_not_exit_voluntarioly();
return Err(AdapterError::Failed(NOT_EXITED));
}
@@ -233,7 +222,7 @@ mod test {
adapter::AdapterError,
msg::{MessageError, Response, RunResult},
run::Whence,
- test::{log_in_tests, mock_adapter, trigger_request, TestResult},
+ test::{mock_adapter, trigger_request, TestResult},
};
fn db() -> anyhow::Result<Db> {
@@ -257,8 +246,6 @@ mod test {
#[test]
fn adapter_reports_success() -> TestResult<()> {
- log_in_tests();
-
const ADAPTER: &str = r#"#!/bin/bash
read
echo '{"response":"triggered","run_id":{"id":"xyzzy"}}'
@@ -279,8 +266,6 @@ echo '{"response":"finished","result":"success"}'
#[test]
fn adapter_reports_failure() -> TestResult<()> {
- log_in_tests();
-
const ADAPTER: &str = r#"#!/bin/bash
read
echo '{"response":"triggered","run_id":{"id":"xyzzy"}}'
@@ -306,8 +291,6 @@ echo '{"response":"finished","result":"failure"}'
#[test]
fn adapter_exits_nonzero() -> TestResult<()> {
- log_in_tests();
-
const ADAPTER: &str = r#"#!/bin/bash
read
echo '{"response":"triggered","run_id":{"id":"xyzzy"}}'
@@ -332,8 +315,6 @@ exit 1
#[test]
fn adapter_is_killed_before_any_messages() -> TestResult<()> {
- log_in_tests();
-
const ADAPTER: &str = r#"#!/bin/bash
kill -9 $BASHPID
"#;
@@ -356,8 +337,6 @@ kill -9 $BASHPID
#[test]
fn adapter_is_killed_after_first_message() -> TestResult<()> {
- log_in_tests();
-
const ADAPTER: &str = r#"#!/bin/bash
read
echo '{"response":"triggered","run_id":{"id":"xyzzy"}}'
@@ -379,8 +358,6 @@ kill -9 $BASHPID
#[test]
fn adapter_is_killed_after_second_message() -> TestResult<()> {
- log_in_tests();
-
const ADAPTER: &str = r#"#!/bin/bash
read
echo '{"response":"triggered","run_id":{"id":"xyzzy"}}'
@@ -403,8 +380,6 @@ kill -9 $BASHPID
#[test]
fn adapter_produces_as_bad_message() -> TestResult<()> {
- log_in_tests();
-
const ADAPTER: &str = r#"#!/bin/bash
read
echo '{"response":"triggered","run_id":{"id":"xyzzy"}}'
@@ -429,8 +404,6 @@ echo '{"response":"finished","result":"success","bad":"field"}'
#[test]
fn adapter_first_message_isnt_triggered() -> TestResult<()> {
- log_in_tests();
-
const ADAPTER: &str = r#"#!/bin/bash
read
echo '{"response":"finished","result":"success"}'
@@ -456,8 +429,6 @@ echo '{"response":"finished","result":"success"}'
#[test]
fn adapter_outputs_too_many_messages() -> TestResult<()> {
- log_in_tests();
-
const ADAPTER: &str = r#"#!/bin/bash
read
echo '{"response":"triggered","run_id":{"id":"xyzzy"}}'
@@ -485,8 +456,6 @@ echo '{"response":"finished","result":"success"}'
#[test]
fn adapter_does_not_exist() -> TestResult<()> {
- log_in_tests();
-
let tmp = tempdir()?;
let bin = tmp.path().join("adapter.sh");
@@ -507,8 +476,6 @@ echo '{"response":"finished","result":"success"}'
#[test]
fn adapter_is_not_executable() -> TestResult<()> {
- log_in_tests();
-
const ADAPTER: &str = r#"#!/bin/bash
read
echo '{"response":"triggered","run_id":{"id":"xyzzy"}}'
@@ -536,8 +503,6 @@ echo '{"response":"finished","result":"success"}'
#[test]
fn adapter_has_bad_interpreter() -> TestResult<()> {
- log_in_tests();
-
// We test this with a shebang. However, the same kind of code
// paths and errors should happen when a binary can't be
// loaded due to missing dynamic linker or library or such.
diff --git a/src/bin/cib.rs b/src/bin/cib.rs
index f8685cb..c027ad0 100644
--- a/src/bin/cib.rs
+++ b/src/bin/cib.rs
@@ -3,14 +3,12 @@
#![allow(clippy::result_large_err)]
use std::{
- error::Error,
fs::write,
path::{Path, PathBuf},
process::exit,
};
use clap::Parser;
-use log::{debug, error, info};
use radicle::Profile;
@@ -19,7 +17,7 @@ use radicle_ci_broker::{
broker::{Broker, BrokerError},
config::{Config, ConfigError},
db::{Db, DbError},
- logger::Logger,
+ logger,
notif::NotificationChannel,
pages::{PageBuilder, PageError},
queueadd::{AdderError, QueueAdderBuilder},
@@ -27,31 +25,22 @@ use radicle_ci_broker::{
};
fn main() {
- let logger = Logger::default();
- logger.start_cib();
+ let _logger = logger::open();
+ logger::start_cib();
if let Err(e) = fallible_main() {
- error!("ERROR: {}", e);
- let mut e = e.source();
- while let Some(source) = e {
- error!("caused by: {}", source);
- e = source.source();
- }
- logger.end_cib_in_error();
+ logger::error("ERROR", &e);
+ logger::end_cib_in_error();
exit(1);
}
-
- logger.end_cib_successfully();
+ logger::end_cib_successfully();
}
fn fallible_main() -> Result<(), CibError> {
let args = Args::parse();
- env_logger::init_from_env("RADICLE_CI_BROKER_LOG");
- info!("Radicle CI broker starts");
-
let config = Config::load(&args.config).map_err(|e| CibError::read_config(&args.config, e))?;
- debug!("loaded configuration: {:#?}", config);
+ logger::loaded_config(&config);
args.run(&config)?;
@@ -131,7 +120,6 @@ impl InsertCmd {
.join()
.expect("wait for thread to finish")
.map_err(CibError::add_events)?;
- debug!("cib ends");
Ok(())
}
}
@@ -153,7 +141,7 @@ impl QueuedCmd {
let adapter = Adapter::new(&spec.command)
.with_environment(spec.envs())
.with_environment(spec.sensitive_envs());
- debug!("default adapter: {adapter:?}");
+ logger::debug2(format!("default adapter: {adapter:?}"));
broker.set_default_adapter(&adapter);
let mut event_notifications = NotificationChannel::default();
@@ -174,7 +162,6 @@ impl QueuedCmd {
.expect("wait for thread to finish")
.map_err(CibError::process_queue)?;
- debug!("cib ends");
Ok(())
}
}
@@ -221,7 +208,7 @@ impl ProcessEventsCmd {
let adapter = Adapter::new(&spec.command)
.with_environment(spec.envs())
.with_environment(spec.sensitive_envs());
- debug!("default adapter: {adapter:?}");
+ logger::debug2(format!("default adapter: {adapter:?}"));
broker.set_default_adapter(&adapter);
let processor = QueueProcessorBuilder::default()
@@ -236,18 +223,14 @@ impl ProcessEventsCmd {
.join()
.expect("wait for processor thread to finish")
.map_err(CibError::process_queue)?;
- info!("event processing thread has ended");
// The page updating thread ends when the channel for run
// notifications is closed by the processor thread ending.
- info!("wait for page updater thread to end");
page_updater
.join()
.expect("wait for page updater thread to finish")
.expect("page updater thread succeeded");
- info!("page updater thread has ended");
- debug!("cib ends");
Ok(())
}
}
diff --git a/src/bin/cibtool.rs b/src/bin/cibtool.rs
index 209e98a..5500ae9 100644
--- a/src/bin/cibtool.rs
+++ b/src/bin/cibtool.rs
@@ -54,11 +54,8 @@ fn main() {
#[allow(clippy::result_large_err)]
fn fallible_main() -> Result<(), CibToolError> {
- env_logger::init_from_env("RADICLE_CI_BROKER_LOG");
-
let args = Args::parse();
args.cmd.run(&args)?;
-
Ok(())
}
diff --git a/src/broker.rs b/src/broker.rs
index a97d350..e524691 100644
--- a/src/broker.rs
+++ b/src/broker.rs
@@ -5,11 +5,9 @@
use std::{
collections::HashMap,
- error::Error,
path::{Path, PathBuf},
};
-use log::{debug, error, info};
use time::{macros::format_description, OffsetDateTime};
use radicle::prelude::RepoId;
@@ -17,6 +15,7 @@ use radicle::prelude::RepoId;
use crate::{
adapter::Adapter,
db::{Db, DbError},
+ logger,
msg::{PatchEvent, PushEvent, Request},
run::{Run, Whence},
};
@@ -35,7 +34,7 @@ pub struct Broker {
impl Broker {
#[allow(clippy::result_large_err)]
pub fn new(db_filename: &Path) -> Result<Self, BrokerError> {
- debug!("broker database in {}", db_filename.display());
+ logger::broker_db(db_filename);
Ok(Self {
default_adapter: None,
adapters: HashMap::new(),
@@ -66,8 +65,7 @@ impl Broker {
#[allow(clippy::result_large_err)]
pub fn execute_ci(&mut self, trigger: &Request) -> Result<Run, BrokerError> {
- info!("Start CI run");
- debug!("Start CI run on {trigger:#?}");
+ logger::broker_start_run(trigger);
let run = match trigger {
Request::Trigger {
common,
@@ -104,24 +102,17 @@ impl Broker {
// We run the adapter, but if that fails, we just
// log the error. The `Run` value records the
// result of the run.
- debug!("broker runs adapter");
if let Err(e) = adapter.run(trigger, &mut run, &self.db) {
- error!("failed to run adapter or it failed to run CI: {e}");
- let mut e = e.source();
- while let Some(source) = e {
- error!("caused by: {}", source);
- e = source.source();
- }
+ logger::error("failed to run adapter or it failed to run CI", &e);
}
- debug!("broker run {run:#?}");
run
} else {
return Err(BrokerError::NoAdapter(*rid));
}
}
};
- info!("Finish CI run: {run:?}");
+ logger::broker_end_run(&run);
self.db.update_run(&run)?;
@@ -188,7 +179,7 @@ mod test {
use crate::{
msg::{RunId, RunResult},
run::RunState,
- test::{log_in_tests, mock_adapter, trigger_request, TestResult},
+ test::{mock_adapter, trigger_request, TestResult},
};
fn broker(filename: &Path) -> anyhow::Result<Broker> {
@@ -309,8 +300,6 @@ echo '{"response":"finished","result":"success"}'
#[test]
fn adapter_fails() -> TestResult<()> {
- log_in_tests();
-
const ADAPTER: &str = r#"#!/bin/bash
read
echo '{"response":"triggered","run_id":{"id":"xyzzy"}}'
diff --git a/src/db.rs b/src/db.rs
index 954f508..42d0a91 100644
--- a/src/db.rs
+++ b/src/db.rs
@@ -16,7 +16,6 @@ use std::{
time::Duration,
};
-use log::{debug, trace};
use sqlite::{Connection, State, Statement};
use time::{macros::format_description, OffsetDateTime};
use uuid::Uuid;
@@ -38,7 +37,6 @@ impl Db {
/// If it is created, tables are created.
pub fn new<P: AsRef<Path>>(filename: P) -> Result<Self, DbError> {
let filename = filename.as_ref();
- debug!("open database {}", filename.display());
let mut db = Db {
filename: filename.into(),
conn: sqlite::open(filename).map_err(|e| DbError::open(filename, e))?,
@@ -46,7 +44,6 @@ impl Db {
debug_assert!(MAX_WAIT.as_millis() < usize::MAX as u128); // safe conversion
let ms = MAX_WAIT.as_millis() as usize;
- trace!("set busy timeout to {ms} milliseconds");
db.conn
.set_busy_timeout(ms)
.map_err(|e| DbError::busy_timer(filename, e))?;
@@ -96,7 +93,6 @@ impl Db {
// Prepare a statement for execution.
fn prepare<'a>(&'a self, sql: &str) -> Result<Stmt<'a>, DbError> {
- trace!("prepare {}", sql);
match self.conn.prepare(sql) {
Ok(stmt) => Ok(Stmt::new(sql, stmt)),
Err(e) => Err(DbError::prepare(sql, &self.filename, e)),
@@ -106,7 +102,6 @@ impl Db {
// Execute a statement that doesn't return any rows with values.
// This means basically any statement except SELECT.
fn execute_valueless(stmt: &mut Stmt) -> Result<(), DbError> {
- trace!("execute {}", stmt.sql);
stmt.stmt.reset().map_err(DbError::reset)?;
match stmt.stmt.next() {
Ok(_) => Ok(()),
diff --git a/src/event.rs b/src/event.rs
index 9abf1c6..67ebb0d 100644
--- a/src/event.rs
+++ b/src/event.rs
@@ -27,7 +27,6 @@
//! let e = Filters::try_from(filters).unwrap();
//! ```
-use log::{debug, error, info, trace};
use radicle::{
node::{Event, Handle, NodeId},
prelude::RepoId,
@@ -43,6 +42,8 @@ use std::{
time,
};
+use crate::logger;
+
/// Source of events from the local Radicle node.
///
/// The events are filtered. Only events allowed by at least one
@@ -57,30 +58,18 @@ impl NodeEventSource {
/// Create a new source of node events, for a given Radicle
/// profile.
pub fn new(profile: &Profile) -> Result<Self, NodeEventError> {
- info!("subscribing to local node events");
let socket = profile.socket();
- info!(
- "profile socket exists? {:#?} {}",
- socket.display(),
- socket.exists()
- );
if !socket.exists() {
return Err(NodeEventError::NoControlSocket(socket));
}
- debug!("about to Node::new()");
let node = radicle::Node::new(socket.clone());
- debug!("{node:#?}");
- debug!("about to node.subscribe()");
match node.subscribe(time::Duration::MAX) {
- Ok(events) => {
- trace!("subscribed OK");
- Ok(Self {
- events: Box::new(events.into_iter()),
- allowed: vec![],
- })
- }
+ Ok(events) => Ok(Self {
+ events: Box::new(events.into_iter()),
+ allowed: vec![],
+ }),
Err(err) => {
- info!("failed to subscribe to node events");
+ logger::error("failed to subscribe to node events", &err);
Err(NodeEventError::CannotSubscribe(socket.clone(), err))
}
}
@@ -94,11 +83,9 @@ impl NodeEventSource {
fn allowed(&self, event: &BrokerEvent) -> Result<bool, NodeEventError> {
for filter in self.allowed.iter() {
if !event.is_allowed(filter)? {
- trace!("event is not allowed");
return Ok(false);
}
}
- trace!("event is allowed");
Ok(true)
}
@@ -107,45 +94,34 @@ impl NodeEventSource {
/// no more events from this source, or there's an error.
pub fn event(&mut self) -> Result<Vec<BrokerEvent>, NodeEventError> {
loop {
- debug!("getting next event from local node");
if let Some(event) = self.events.next() {
- debug!("got event from local node");
match event {
Ok(event) => {
- debug!("got node event {:#?}", event);
let mut result = vec![];
if let Some(broker_events) = BrokerEvent::from_event(&event) {
- info!("node event became {} broker events", broker_events.len());
for e in broker_events {
if self.allowed(&e)? {
- info!("allowed event {e:?}");
result.push(e);
}
}
if !result.is_empty() {
- info!("got {} allowed broker events from node event", result.len());
return Ok(result);
- } else {
- info!("got no allowed broker events from node event, ignoring it");
}
}
- debug!(
- "got event, but did not result in broker events, or none were allowed"
- );
}
Err(radicle::node::Error::Io(err))
if err.kind() == std::io::ErrorKind::ConnectionReset =>
{
- error!("connection to node control socket broke");
+ logger::event_disconnected();
return Err(NodeEventError::BrokenConnection);
}
Err(err) => {
- error!("error reading event from node: {err}");
+ logger::error("error reading event from node", &err);
return Err(NodeEventError::Node(err));
}
}
} else {
- info!("no more node events from control socket: iterator ended");
+ logger::event_end();
return Ok(vec![]);
}
}
@@ -353,15 +329,12 @@ impl BrokerEvent {
RefUpdate::Skipped { name, oid }
if name.as_str() == "shutdown" && oid.is_zero() =>
{
- info!("received shutdown event from node");
events.push(Self::shutdown());
}
RefUpdate::Created { name, oid } => {
- info!("ref created {name} {oid}");
events.push(Self::new(rid, name, oid, None));
}
RefUpdate::Updated { name, old, new } => {
- info!("ref updated {name} {old} => {new}");
events.push(Self::new(rid, name, new, Some(*old)));
}
_ => (),
@@ -375,37 +348,20 @@ impl BrokerEvent {
/// Is this broker event allowed by a filter?
fn is_allowed(&self, filter: &EventFilter) -> Result<bool, NodeEventError> {
- debug!("is_allowed called: filter={filter:?}");
- let res = self.is_allowed_helper(filter, 0)?;
- debug!("is_allowed: res={res}");
+ let res = self.is_allowed_helper(filter)?;
Ok(res)
}
- fn is_allowed_helper(
- &self,
- filter: &EventFilter,
- level: usize,
- ) -> Result<bool, NodeEventError> {
- let prefix = format!("{:width$}", " ", width = level * 4);
-
- trace!("is_allowed: {prefix} called {self:?}");
-
+ fn is_allowed_helper(&self, filter: &EventFilter) -> Result<bool, NodeEventError> {
let allowed = match self {
Self::Shutdown => true,
Self::RefChanged {
rid,
name,
- oid,
- old,
+ oid: _,
+ old: _,
} => {
- trace!("is_allowed: {prefix} rid={rid:?}");
- trace!("is_allowed: {prefix} name={name:?}");
- trace!("is_allowed: {prefix} oid={oid:?}");
- trace!("is_allowed: {prefix} old={old:?}");
- trace!("is_allowed: {prefix} filter={filter:?}");
-
let parsed = parse_ref(name)?;
- trace!("is_allowed: {prefix} parsed={parsed:?}");
match filter {
EventFilter::Repository(wanted) => rid == wanted,
@@ -426,18 +382,17 @@ impl BrokerEvent {
}
EventFilter::And(conds) => conds
.iter()
- .all(|cond| self.is_allowed_helper(cond, level + 1).unwrap_or(false)),
+ .all(|cond| self.is_allowed_helper(cond).unwrap_or(false)),
EventFilter::Or(conds) => conds
.iter()
- .any(|cond| self.is_allowed_helper(cond, level + 1).unwrap_or(false)),
+ .any(|cond| self.is_allowed_helper(cond).unwrap_or(false)),
EventFilter::Not(conds) => !conds
.iter()
- .any(|cond| self.is_allowed_helper(cond, level + 1).unwrap_or(false)),
+ .any(|cond| self.is_allowed_helper(cond).unwrap_or(false)),
}
}
};
- trace!("is_allowed: {prefix} allowed={allowed}");
Ok(allowed)
}
@@ -564,18 +519,13 @@ pub enum ParsedRef {
/// }
/// ```
pub fn parse_ref(s: &str) -> Result<Option<ParsedRef>, NodeEventError> {
- trace!("parse_ref: s={s:?}");
-
const PAT_PATCH: &str = r"^refs/namespaces/[^/]+/refs/heads/patches/([^/]+)$";
let patch_re = Regex::new(PAT_PATCH).map_err(|e| NodeEventError::Regex(PAT_PATCH, e))?;
if let Some(patch_captures) = patch_re.captures(s) {
- trace!("parse_ref: patch_captures={patch_captures:?}");
if let Some(patch_id) = patch_captures.get(1) {
- trace!("parse_ref: patch_id={patch_id:?}");
let patch_id_str = patch_id.as_str();
let oid = Oid::try_from(patch_id_str)
.map_err(|e| NodeEventError::ParseOid(patch_id_str.into(), e))?;
- trace!("parse_ref: patch oid={oid:?}");
return Ok(Some(ParsedRef::Patch(oid)));
}
}
@@ -583,40 +533,26 @@ pub fn parse_ref(s: &str) -> Result<Option<ParsedRef>, NodeEventError> {
const PAT_BRANCH: &str = r"^refs/namespaces/[^/]+/refs/heads/(.+)$";
let push_re = Regex::new(PAT_BRANCH).map_err(|e| NodeEventError::Regex(PAT_BRANCH, e))?;
if let Some(push_captures) = push_re.captures(s) {
- trace!("parse_ref: push_captures={push_captures:?}");
if let Some(branch) = push_captures.get(1) {
- trace!("parse_ref: branch={branch:?}");
return Ok(Some(ParsedRef::Push(branch.as_str().to_string())));
}
}
- trace!("parse_ref: neither push nor patch");
Ok(None)
}
-#[cfg(test)]
-fn log_init() {
- let _ = env_logger::builder()
- .is_test(true)
- .format_timestamp(None)
- .filter_level(log::LevelFilter::Trace)
- .try_init();
-}
-
#[cfg(test)]
mod test_parse_ref {
- use super::{log_init, parse_ref, Oid, ParsedRef};
+ use super::{parse_ref, Oid, ParsedRef};
#[test]
fn plain_branch_name_is_none() -> anyhow::Result<()> {
- log_init();
assert_eq!(parse_ref("main")?, None);
Ok(())
}
#[test]
fn namespaced_branch() -> anyhow::Result<()> {
- log_init();
assert_eq!(
parse_ref(
"refs/namespaces/z6MkfBU2cwcZfaE6Z1dLqb7Ve7u4pdgbSo9tP6qUVsqFn2xv/refs/heads/main"
@@ -628,7 +564,6 @@ mod test_parse_ref {
#[test]
fn namespaced_branch_with_slashes() -> anyhow::Result<()> {
- log_init();
assert_eq!(
parse_ref(
"refs/namespaces/z6MkfBU2cwcZfaE6Z1dLqb7Ve7u4pdgbSo9tP6qUVsqFn2xv/refs/heads/liw/cob/draft/v2"
@@ -640,7 +575,6 @@ mod test_parse_ref {
#[test]
fn namespaced_patch() -> anyhow::Result<()> {
- log_init();
const SHA: &str = "0a4c69183fc8b8d849f5ab977d70f2a1f4788bca";
assert_eq!(
parse_ref(&format!("refs/namespaces/NID/refs/heads/patches/{SHA}"))?,
@@ -672,11 +606,10 @@ pub fn push_branch(name: &str) -> String {
#[cfg(test)]
mod test {
- use super::{is_patch_update, log_init, parse_ref, push_branch, Oid, ParsedRef};
+ use super::{is_patch_update, parse_ref, push_branch, Oid, ParsedRef};
#[test]
fn test_parse_patch_ref() -> anyhow::Result<()> {
- log_init();
let patch_ref =
"refs/namespaces/NID/refs/heads/patches/9183ed6232687d3105482960cecb01a53018b80a";
@@ -691,7 +624,6 @@ mod test {
#[test]
fn test_parse_push_ref() -> anyhow::Result<()> {
- log_init();
let push_ref =
"refs/namespaces/z6MkuhvCnrcow7vzkyQzkuFixzpTa42iC2Cfa4DA8HRLCmys/refs/heads/main";
let parsed_ref = parse_ref(push_ref)?;
@@ -708,7 +640,6 @@ mod test {
#[test]
fn test_parse_invalid_ref() -> anyhow::Result<()> {
- log_init();
let invalid_ref = "invalid_ref";
let parsed_ref = parse_ref(invalid_ref)?;
assert!(parsed_ref.is_none());
@@ -717,7 +648,6 @@ mod test {
#[test]
fn branch_is_not_patch_update() {
- log_init();
assert_eq!(
is_patch_update(
"refs/namespaces/z6MkuhvCnrcow7vzkyQzkuFixzpTa42iC2Cfa4DA8HRLCmys/refs/heads/main"
@@ -728,7 +658,6 @@ mod test {
#[test]
fn patch_branch_is_not_patch_update() {
- log_init();
assert_eq!(
is_patch_update(
"refs/namespaces/z6MkuhvCnrcow7vzkyQzkuFixzpTa42iC2Cfa4DA8HRLCmys/refs/heads/patches/bbb54a2c9314a528a4fff9d6c2aae874ed098433"
@@ -739,7 +668,6 @@ mod test {
#[test]
fn patch_update() {
- log_init();
assert_eq!(
is_patch_update(
"refs/namespaces/z6MkuhvCnrcow7vzkyQzkuFixzpTa42iC2Cfa4DA8HRLCmys/refs/cobs/xyz.radicle.patch/bbb54a2c9314a528a4fff9d6c2aae874ed098433"
@@ -750,7 +678,6 @@ mod test {
#[test]
fn get_push_branch() {
- log_init();
assert_eq!(
push_branch(
"refs/namespaces/z6MkuhvCnrcow7vzkyQzkuFixzpTa42iC2Cfa4DA8HRLCmys/refs/heads/branch_name"
@@ -761,7 +688,6 @@ mod test {
#[test]
fn get_no_push_branch() {
- log_init();
assert_eq!(
push_branch(
"refs/namespaces/z6MkuhvCnrcow7vzkyQzkuFixzpTa42iC2Cfa4DA8HRLCmys/refs/rad/sigrefs"
diff --git a/src/logger.rs b/src/logger.rs
index 04a89b9..f331f23 100644
--- a/src/logger.rs
+++ b/src/logger.rs
@@ -1,34 +1,224 @@
//! A logger abstraction for the CI broker.
-use std::sync::Mutex;
+#[cfg(test)]
+use std::sync::Once;
+use std::{path::Path, sync::Mutex, time::Duration};
-use slog::{info, o, Drain};
+use radicle::{git::raw::Oid, identity::RepoId};
+use slog::{debug, error, info, o, warn, Drain};
+use slog_scope::GlobalLoggerGuard;
-pub struct Logger {
- root: slog::Logger,
+use crate::{config::Config, db::QueueId, event::BrokerEvent, msg::Request, run::Run};
+
+pub fn open() -> GlobalLoggerGuard {
+ let logger = slog_json::Json::new(std::io::stderr())
+ .add_default_keys()
+ .set_flush(true)
+ .set_newlines(true)
+ .build();
+ let log = slog::Logger::root(Mutex::new(logger).fuse(), o!());
+ slog_scope::set_global_logger(log)
}
-impl Default for Logger {
- fn default() -> Self {
- Self {
- root: slog::Logger::root(
- Mutex::new(slog_json::Json::default(std::io::stderr())).map(slog::Fuse),
- o!(),
- ),
- }
- }
+// Set up structured logging for tests.
+//
+// We have to keep the GlobalLoggerGuard we get when we initialize
+// `slog-scope` alive as long as we may need to do any logging. We can
+// only create that once per process. For tests, we do that here.
+//
+// We can't do the same thing for non-test processes, as that would
+// interfere with use of `radicle-ci-broker` as a library. Libraries
+// should not interfere with global state, unless they're specifically
+// intended to do that.
+//
+// This is for tests only: otherwise
+
+// We use this to make sure we initialize the logger only once.
+#[cfg(test)]
+static INIT: Once = Once::new();
+
+// This is the actual logger for tests.
+#[cfg(test)]
+static mut LOGGER: Option<GlobalLoggerGuard> = None;
+
+#[cfg(test)]
+#[ctor::ctor]
+fn open_for_tests() {
+ INIT.call_once(|| unsafe {
+ LOGGER = Some(open());
+ });
}
-impl Logger {
- pub fn start_cib(&self) {
- info!(&self.root, "CI broker starts");
- }
+pub fn start_cib() {
+ info!(slog_scope::logger(), "CI broker starts");
+}
- pub fn end_cib_successfully(&self) {
- info!(&self.root, "CI broker ends successfully");
- }
+pub fn end_cib_successfully() {
+ info!(slog_scope::logger(), "CI broker ends successfully");
+}
+
+pub fn end_cib_in_error() {
+ info!(
+ slog_scope::logger(),
+ "CI broker ends in unrecoverable error"
+ );
+}
+
+pub fn loaded_config(config: &Config) {
+ debug!(slog_scope::logger(), "loaded configuration {config:#?}");
+}
+
+pub fn queueproc_start() {
+ info!(
+ slog_scope::logger(),
+ "start thread to process events until a shutdown event"
+ );
+}
+
+pub fn queueproc_end() {
+ info!(slog_scope::logger(), "start thread to process events ends");
+}
+
+pub fn queueproc_channel_disconnect() {
+ info!(
+ slog_scope::logger(),
+ "event notification channel disconnected"
+ );
+}
+
+pub fn queueproc_remove_event(id: &QueueId) {
+ info!(slog_scope::logger(), "remove event from queue: {id}");
+}
+
+pub fn queueproc_action_run(rid: &RepoId, oid: &Oid) {
+ info!(slog_scope::logger(), "Action: run: {rid} {oid}");
+}
+
+pub fn queueproc_action_shutdown() {
+ info!(slog_scope::logger(), "Action: shutdown");
+}
+
+pub fn queueadd_start() {
+ info!(
+ slog_scope::logger(),
+ "start thread to add events from node to event queue"
+ );
+}
+
+pub fn queueadd_control_socket_close() {
+ info!(
+ slog_scope::logger(),
+ "no more events from node control sockets"
+ );
+}
+
+pub fn queueadd_push_event(e: &BrokerEvent) {
+ debug!(
+ slog_scope::logger(),
+ "insert broker event into queue: {e:?}"
+ );
+}
+
+pub fn queueadd_end() {
+ info!(slog_scope::logger(), "start thread to process events ends");
+}
+
+pub fn pages_directory_unset() {
+ warn!(
+ slog_scope::logger(),
+ "not writing HTML report pages as output directory has not been set"
+ );
+}
+
+pub fn pages_interval(interval: Duration) {
+ info!(
+ slog_scope::logger(),
+ "wait about {} seconds to update HTML report pages again",
+ interval.as_secs()
+ );
+}
+
+pub fn pages_disconnected() {
+ info!(
+ slog_scope::logger(),
+ "page updater: run notification channel disconnected"
+ );
+}
+
+pub fn pages_start() {
+ info!(slog_scope::logger(), "start page updater thread");
+}
+
+pub fn pages_end() {
+ info!(slog_scope::logger(), "end page updater thread");
+}
+
+pub fn event_disconnected() {
+ info!(
+ slog_scope::logger(),
+ "connection to node control socket broke"
+ );
+}
+
+pub fn event_end() {
+ info!(
+ slog_scope::logger(),
+ "no more node events from control socket: iterator ended"
+ );
+}
+
+pub fn broker_db(filename: &Path) {
+ info!(
+ slog_scope::logger(),
+ "broker database: {}",
+ filename.display()
+ );
+}
+
+pub fn broker_start_run(trigger: &Request) {
+ info!(slog_scope::logger(), "start CI run");
+ debug!(slog_scope::logger(), "trigger event: {trigger:#?}");
+}
+
+pub fn broker_end_run(run: &Run) {
+ info!(slog_scope::logger(), "Finish CI run");
+ debug!(slog_scope::logger(), "finished CI run: {run:#?}");
+}
+
+pub fn adapter_no_first_response() {
+ error!(slog_scope::logger(), "no first response message");
+}
+
+pub fn adapter_no_second_response() {
+ error!(slog_scope::logger(), "no second response message");
+}
+
+pub fn adapter_too_many_responses() {
+ error!(slog_scope::logger(), "too many response messages");
+}
+
+pub fn adapter_result(exit: i32, stderr: &String) {
+ debug!(slog_scope::logger(), "adapter exit code: {exit}");
+ debug!(slog_scope::logger(), "adapter stderr: {stderr}");
+}
+
+pub fn adapter_did_not_exit_voluntarioly() {
+ warn!(slog_scope::logger(), "adapter did not exit voluntarily");
+}
+
+pub fn debug(msg: &str) {
+ debug!(slog_scope::logger(), "{msg}");
+}
+
+pub fn debug2(msg: String) {
+ debug!(slog_scope::logger(), "{msg}");
+}
- pub fn end_cib_in_error(&self) {
- info!(&self.root, "CI broker ends in unrecoverable error");
+pub fn error(msg: &str, e: &impl std::error::Error) {
+ error!(slog_scope::logger(), "{msg}: {e}");
+ let mut e = e.source();
+ while let Some(source) = e {
+ error!(slog_scope::logger(), "caused by: {}", source);
+ e = source.source();
}
}
diff --git a/src/pages.rs b/src/pages.rs
index e07058b..b3b43f2 100644
--- a/src/pages.rs
+++ b/src/pages.rs
@@ -17,7 +17,6 @@ use std::{
};
use html_page::{Element, HtmlPage, Tag};
-use log::{debug, info, trace, warn};
use serde::Serialize;
use time::{macros::format_description, OffsetDateTime};
@@ -30,6 +29,7 @@ use radicle::{
use crate::{
db::{Db, DbError, QueuedEvent},
event::{parse_ref, BrokerEvent, ParsedRef},
+ logger,
msg::RunId,
notif::NotificationReceiver,
run::{Run, RunState, Whence},
@@ -96,7 +96,7 @@ impl PageBuilder {
for run in self.runs.iter() {
runs.insert(run.adapter_run_id().unwrap().clone(), run.clone());
}
- debug!("broker database has {} CI runs", runs.len());
+ logger::debug2(format!("broker database has {} CI runs", runs.len()));
Ok(StatusPage::new())
}
@@ -525,15 +525,15 @@ impl StatusPage {
db: Db,
once: bool,
) -> JoinHandle<Result<(), PageError>> {
+ logger::pages_start();
+
if self.dirname.is_none() {
- warn!("not writing HTML report pages as output directory has not been set");
+ logger::pages_directory_unset();
}
self.node_alias = profile.config.alias().to_string();
- info!(
- "wait about {} seconds to update HTML report pages again",
- UPDATE_INTERVAL.as_secs()
- );
+ logger::pages_interval(UPDATE_INTERVAL);
+
spawn(move || {
'processing_loop: loop {
self.update_and_write(&profile, &db)?;
@@ -541,35 +541,26 @@ impl StatusPage {
return Ok(());
}
- trace!("wait for run notification or timeout");
match run_rx.recv_timeout(UPDATE_INTERVAL) {
- Ok(_) => trace!("page updater: got a run notification"),
- Err(RecvTimeoutError::Timeout) => {
- trace!("page updater: timeout on run notification channel")
- }
+ Ok(_) => (),
+ Err(RecvTimeoutError::Timeout) => (),
Err(RecvTimeoutError::Disconnected) => {
- debug!("page updater: run notification channel disconnected");
+ logger::pages_disconnected();
break 'processing_loop;
}
}
}
// Make sure we update reports and status JSON at least once.
- info!("make sure we update reports and status JSON at least once");
self.update_and_write(&profile, &db)?;
- info!("end page updater thread");
+ logger::pages_end();
Ok(())
})
}
fn update_and_write(&mut self, profile: &Profile, db: &Db) -> Result<(), PageError> {
if let Some(dirname) = &self.dirname {
- info!(
- "write HTML report pages and {STATUS_JSON} to {}",
- dirname.display()
- );
-
let runs = db.get_all_runs()?;
// Create list of events, except ones for private
@@ -655,7 +646,6 @@ impl StatusPage {
}
fn write_file(filename: &Path, text: &str) -> Result<(), PageError> {
- debug!("write file {}", filename.display());
write(filename, text).map_err(|e| PageError::Write(filename.into(), e))?;
Ok(())
}
diff --git a/src/queueadd.rs b/src/queueadd.rs
index ab50928..8eaf77e 100644
--- a/src/queueadd.rs
+++ b/src/queueadd.rs
@@ -2,11 +2,10 @@ use std::thread::{spawn, JoinHandle};
use radicle::Profile;
-use log::{debug, info};
-
use crate::{
db::{Db, DbError},
event::{BrokerEvent, EventFilter, NodeEventError, NodeEventSource},
+ logger,
notif::NotificationSender,
};
@@ -62,31 +61,26 @@ impl QueueAdder {
}
pub fn add_events(&self) -> Result<(), AdderError> {
- info!("start thread to add events from node to event queue");
+ logger::queueadd_start();
let profile = Profile::load()?;
- debug!("loaded profile {profile:#?}");
let mut source = NodeEventSource::new(&profile)?;
- debug!("created node event source");
for filter in self.filters.iter() {
source.allow(filter.clone());
}
- debug!("added filters to node event source");
// This loop ends when there's an error, e.g., failure to read an
// event from the node.
'event_loop: loop {
- debug!("waiting for event from node");
let events = source.event()?;
if events.is_empty() {
- info!("no more events from node control sockets");
+ logger::queueadd_control_socket_close();
break 'event_loop;
} else {
for e in events {
- debug!("got event {e:#?}");
- info!("insert broker event into queue: {e:?}");
+ logger::queueadd_push_event(&e);
self.push_event(e)?;
}
}
@@ -95,10 +89,10 @@ impl QueueAdder {
// Add a shutdown event to the queue so that the queue
// processing thread knows to stop.
if self.push_shutdown {
- info!("push a shutdown event into queue");
self.push_event(BrokerEvent::Shutdown)?;
}
+ logger::queueadd_end();
Ok(())
}
diff --git a/src/queueproc.rs b/src/queueproc.rs
index ef5e809..81233b6 100644
--- a/src/queueproc.rs
+++ b/src/queueproc.rs
@@ -8,13 +8,13 @@ use std::{
time::Duration,
};
-use log::{debug, info};
use radicle::Profile;
use crate::{
broker::{Broker, BrokerError},
db::{Db, DbError, QueueId, QueuedEvent},
event::BrokerEvent,
+ logger,
msg::{MessageError, RequestBuilder},
notif::{NotificationReceiver, NotificationSender},
};
@@ -75,38 +75,30 @@ impl QueueProcessor {
}
fn process_until_shutdown(&mut self) -> Result<(), QueueError> {
- info!("start thread to process events until a shutdown event");
+ logger::queueproc_start();
let mut done = false;
while !done {
- info!("Looking for an event to process");
while let Some(qe) = self.pick_event()? {
- info!("picked event from queue: {}: {:?}", qe.id(), qe.event());
done = self.process_event(qe.event())?;
self.drop_event(qe.id())?;
self.run_tx.send(()).map_err(|_| QueueError::NotifyRun)?;
}
- info!("waiting for next event from node");
match self.events_rx.recv_timeout(RECV_TIMEOUT) {
- Ok(_) => {
- info!("got event notification");
- }
- Err(RecvTimeoutError::Timeout) => {
- info!("timed out on event notification");
- }
+ Ok(_) => {}
+ Err(RecvTimeoutError::Timeout) => {}
Err(RecvTimeoutError::Disconnected) => {
- info!("event notification channel disconnected");
+ logger::queueproc_channel_disconnect();
done = true;
}
}
}
- info!("thread to process events ends");
+ logger::queueproc_end();
Ok(())
}
fn pick_event(&self) -> Result<Option<QueuedEvent>, QueueError> {
let ids = self.db.queued_events().map_err(QueueError::db)?;
- debug!("event queue has {} events", ids.len());
let mut queue = vec![];
for id in ids.iter() {
@@ -131,7 +123,7 @@ impl QueueProcessor {
oid,
old: _,
} => {
- info!("Action: run: {rid} {oid}");
+ logger::queueproc_action_run(rid, oid);
let trigger = RequestBuilder::default()
.profile(&self.profile)
@@ -144,14 +136,14 @@ impl QueueProcessor {
Ok(false)
}
BrokerEvent::Shutdown => {
- info!("Action: shutdown");
+ logger::queueproc_action_shutdown();
Ok(true)
}
}
}
fn drop_event(&mut self, id: &QueueId) -> Result<(), QueueError> {
- debug!("remove event {id}");
+ logger::queueproc_remove_event(id);
self.db.remove_queued_event(id).map_err(QueueError::db)?;
Ok(())
}
diff --git a/src/test.rs b/src/test.rs
index 2e248e3..facb7ae 100644
--- a/src/test.rs
+++ b/src/test.rs
@@ -90,11 +90,3 @@ pub fn mock_adapter(filename: &Path, script: &str) -> TestResult<Adapter> {
Ok(Adapter::new(filename))
}
-
-pub fn log_in_tests() {
- env_logger::builder()
- .filter_level(log::LevelFilter::Debug)
- .is_test(true)
- .try_init()
- .ok();
-}
timeout 600 bash -c set -xeuo pipefail
cargo --version
rustc --version
cargo fmt --check
cargo clippy --all-targets --workspace -- -Dwarnings
cargo build --all-targets --workspace
cargo doc --workspace
cargo test --workspace --no-fail-fast
subplot docgen ci-broker.subplot -o doc/ci-broker.html
make -C doc publish
Command arguments:
"timeout""600""bash""-c""set -xeuo pipefail\ncargo --version\nrustc --version\n\ncargo fmt --check\ncargo clippy --all-targets --workspace -- -Dwarnings\ncargo build --all-targets --workspace\ncargo doc --workspace\ncargo test --workspace --no-fail-fast\n\nsubplot docgen ci-broker.subplot -o doc/ci-broker.html\nmake -C doc publish\n"In directory: /srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src
Exit code: 101
Output (stdout and stderr):
+ cargo --version
cargo 1.77.0 (3fe68eabf 2024-02-29)
+ rustc --version
rustc 1.77.0 (aedd173a2 2024-03-17)
+ cargo fmt --check
+ cargo clippy --all-targets --workspace -- -Dwarnings
Compiling proc-macro2 v1.0.86
Compiling unicode-ident v1.0.12
Compiling version_check v0.9.5
Compiling libc v0.2.158
Compiling typenum v1.17.0
Checking cfg-if v1.0.0
Compiling serde v1.0.208
Compiling shlex v1.3.0
Compiling thiserror v1.0.63
Compiling once_cell v1.19.0
Compiling memchr v2.7.4
Compiling byteorder v1.5.0
Compiling syn v1.0.109
Compiling bitflags v2.6.0
Checking subtle v2.6.1
Compiling pkg-config v0.3.30
Compiling crossbeam-utils v0.8.20
Compiling rustix v0.38.34
Compiling itoa v1.0.11
Compiling anyhow v1.0.86
Compiling linux-raw-sys v0.4.14
Compiling allocator-api2 v0.2.18
Compiling regex-syntax v0.8.4
Compiling generic-array v0.14.7
Compiling ahash v0.8.11
Checking cpufeatures v0.2.13
Compiling log v0.4.22
Compiling num-conv v0.1.0
Compiling time-core v0.1.2
Compiling same-file v1.0.6
Compiling time-macros v0.2.18
Compiling aho-corasick v1.1.3
Compiling walkdir v2.5.0
Compiling utf8parse v0.2.2
Compiling ucd-trie v0.1.6
Compiling anstyle-parse v0.2.5
Compiling bstr v1.10.0
Compiling serde_json v1.0.125
Compiling quote v1.0.36
Compiling heck v0.5.0
Compiling ryu v1.0.18
Compiling is_terminal_polyfill v1.70.1
Compiling doc-comment v0.3.3
Compiling syn v2.0.75
Compiling jobserver v0.1.32
Compiling getrandom v0.2.15
Compiling crossbeam-epoch v0.9.18
Compiling anstyle v1.0.8
Compiling unicode-width v0.1.13
Compiling rand_core v0.6.4
Compiling powerfmt v0.2.0
Compiling unic-common v0.9.0
Compiling vcpkg v0.2.15
Compiling cc v1.1.13
Compiling unic-char-range v0.9.0
Compiling anstyle-query v1.1.1
Compiling libm v0.2.8
Compiling colorchoice v1.0.2
Compiling deranged v0.3.11
Compiling unic-char-property v0.9.0
Compiling anstream v0.6.15
Compiling crossbeam-deque v0.8.5
Compiling unic-ucd-version v0.9.0
Compiling proc-macro-error-attr v1.0.4
Compiling unicase v2.7.0
Compiling encoding_rs v0.8.34
Compiling fastrand v2.1.0
Checking tinyvec_macros v0.1.1
Compiling arraydeque v0.5.1
Compiling strsim v0.11.1
Compiling clap_lex v0.7.2
Checking tinyvec v1.8.0
Compiling clap_builder v4.5.15
Checking crypto-common v0.1.6
Checking block-buffer v0.10.4
Checking block-padding v0.3.3
Checking inout v0.1.3
Checking digest v0.10.7
Checking universal-hash v0.5.1
Compiling unic-ucd-segment v0.9.0
Checking cipher v0.4.4
Compiling proc-macro-error v1.0.4
Compiling deunicode v1.6.0
Checking opaque-debug v0.3.1
Compiling regex-automata v0.4.7
Compiling tempfile v3.12.0
Compiling time v0.3.36
Compiling pulldown-cmark v0.9.6
Compiling amplify_syn v2.0.1
Checking signature v1.6.4
Compiling unicode-linebreak v0.1.5
Compiling equivalent v1.0.1
Compiling smawk v0.3.2
Checking ed25519 v1.5.3
Compiling textwrap v0.16.1
Checking unicode-normalization v0.1.23
Compiling unic-segment v0.9.0
Compiling humansize v2.1.3
Compiling slug v0.1.6
Compiling getopts v0.2.21
Compiling is-terminal v0.4.13
Compiling subplot v0.10.0
Compiling percent-encoding v2.3.1
Compiling libz-sys v1.1.19
Compiling pikchr v0.1.3
Compiling libgit2-sys v0.16.2+1.7.2
Checking ct-codecs v1.1.1
Compiling lazy_static v1.5.0
Checking amplify_num v0.5.3
Checking unicode-bidi v0.3.15
Compiling utf8-width v0.1.7
Checking ascii v1.1.0
Compiling termcolor v1.4.1
Compiling humantime v2.1.0
Compiling unsafe-libyaml v0.2.11
Checking form_urlencoded v1.2.1
Checking idna v0.5.0
Compiling html-escape v0.2.13
Checking ec25519 v0.1.0
Compiling amplify_derive v4.0.1
Compiling sqlite3-src v0.5.1
Checking polyval v0.6.2
Checking sha2 v0.10.8
Compiling tracing-core v0.1.32
Compiling pin-project-lite v0.2.14
Compiling base64 v0.22.1
Checking keccak v0.1.5
Checking base64ct v1.6.0
Compiling file_diff v1.0.0
Compiling line-col v0.2.1
Compiling globset v0.4.14
Compiling regex v1.10.6
Checking sha3 v0.10.8
Checking pem-rfc7468 v0.7.0
Checking url v2.5.2
Checking ghash v0.5.1
Checking ctr v0.9.2
Checking aes v0.8.4
Checking aead v0.5.2
Compiling data-encoding v2.6.0
Compiling ignore v0.4.22
Compiling env_logger v0.10.2
Checking base32 v0.4.0
Checking hashbrown v0.14.5
Compiling cfg_aliases v0.2.1
Compiling nix v0.29.0
Checking aes-gcm v0.10.3
Checking ssh-encoding v0.2.0
Checking blowfish v0.9.1
Checking chacha20 v0.9.1
Checking cbc v0.1.2
Checking poly1305 v0.8.0
Compiling globwalk v0.9.1
Checking pbkdf2 v0.12.2
Checking zeroize v1.8.1
Compiling adler v1.0.2
Checking radicle-std-ext v0.1.0
Checking ssh-cipher v0.2.0
Checking indexmap v2.4.0
Compiling miniz_oxide v0.7.4
Checking bcrypt-pbkdf v0.10.0
Checking rand v0.8.5
Compiling xattr v1.3.1
Compiling filetime v0.2.24
Compiling crc32fast v1.4.2
Checking base-x v0.2.11
Compiling data-encoding-macro-internal v0.1.13
Checking signature v2.2.0
Compiling slog v2.7.0
Checking ssh-key v0.6.6
Compiling tar v0.4.41
Compiling flate2 v1.0.31
Checking qcheck v1.0.0
Checking cvt v0.1.2
Compiling glob v0.3.1
Checking data-encoding-macro v0.1.15
Checking multibase v0.9.1
Checking terminal_size v0.3.0
Checking radicle-dag v0.9.0
Checking normpath v1.3.0
Compiling serde_yml v0.0.11
Checking amplify v4.7.0
Compiling radicle-surf v0.18.0
Checking fs2 v0.4.3
Checking unescape v0.1.0
Checking base64 v0.13.1
Checking state v0.5.3
Checking shell-words v1.1.0
Checking nonempty v0.5.0
Checking fs_at v0.2.1
Checking crossbeam-channel v0.5.13
Checking siphasher v1.0.1
Checking base64 v0.21.7
Checking cyphergraphy v0.3.0
Checking arc-swap v1.7.1
Checking libyml v0.0.4
Checking remove_dir_all v0.8.3
Checking uuid v1.10.0
Checking cypheraddr v0.4.0
Checking slog-scope v4.4.0
Compiling serde_derive v1.0.208
Compiling thiserror-impl v1.0.63
Compiling zerocopy-derive v0.7.35
Compiling clap_derive v4.5.13
Compiling git-testament-derive v0.2.0
Compiling tracing-attributes v0.1.27
Compiling culpa-macros v1.0.2
Compiling ctor v0.2.8
Checking html-page v0.4.0
Checking socks5-client v0.4.1
Checking cyphernet v0.5.2
Compiling git-testament v0.2.5
Compiling zerocopy v0.7.35
Compiling pest v2.7.11
Compiling git-ref-format-core v0.3.0
Checking radicle-ssh v0.9.0
Compiling culpa v1.0.2
Compiling tracing v0.1.40
Compiling subplotlib-derive v0.10.0
Compiling ppv-lite86 v0.2.20
Compiling git-ref-format-macro v0.3.0
Compiling rand_chacha v0.3.1
Compiling clap v4.5.16
Compiling hashlink v0.8.4
Compiling hashlink v0.9.1
Compiling pest_meta v2.7.11
Compiling yaml-rust2 v0.8.1
Compiling tempfile-fast v0.3.4
Compiling pest_generator v2.7.11
Compiling pest_derive v2.7.11
Checking nonempty v0.9.0
Checking localtime v1.3.1
Checking git-ref-format v0.3.0
Compiling serde_path_to_error v0.1.16
Compiling serde_yaml v0.9.34+deprecated
Compiling marked-yaml v0.7.1
Checking slog-json v2.6.1
Compiling roadmap v0.6.1
Compiling serde-aux v4.5.0
Compiling tera v1.20.0
Checking git2 v0.18.3
Checking radicle-git-ext v0.7.0
Compiling subplot-build v0.10.0
Compiling subplotlib v0.10.0
Compiling radicle-ci-broker v0.4.0 (/srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src)
Checking sqlite3-sys v0.15.2
Checking sqlite v0.32.0
Checking radicle-crypto v0.10.0
Checking radicle-cob v0.11.0
Checking radicle v0.12.0
Finished dev [unoptimized + debuginfo] target(s) in 20.62s
+ cargo build --all-targets --workspace
Compiling cfg-if v1.0.0
Compiling bitflags v2.6.0
Compiling memchr v2.7.4
Compiling once_cell v1.19.0
Compiling itoa v1.0.11
Compiling log v0.4.22
Compiling subtle v2.6.1
Compiling typenum v1.17.0
Compiling libc v0.2.158
Compiling ryu v1.0.18
Compiling fastrand v2.1.0
Compiling percent-encoding v2.3.1
Compiling serde v1.0.208
Compiling thiserror v1.0.63
Compiling regex-syntax v0.8.4
Compiling equivalent v1.0.1
Compiling crossbeam-utils v0.8.20
Compiling utf8parse v0.2.2
Compiling cpufeatures v0.2.13
Compiling anyhow v1.0.86
Compiling rustix v0.38.34
Compiling ahash v0.8.11
Compiling anstyle-parse v0.2.5
Compiling powerfmt v0.2.0
Compiling anstyle v1.0.8
Compiling anstyle-query v1.1.1
Compiling num-conv v0.1.0
Compiling is_terminal_polyfill v1.70.1
Compiling colorchoice v1.0.2
Compiling time-core v0.1.2
Compiling getrandom v0.2.15
Compiling deranged v0.3.11
Compiling strsim v0.11.1
Compiling hashbrown v0.14.5
Compiling time-macros v0.2.18
Compiling anstream v0.6.15
Compiling clap_lex v0.7.2
Compiling encoding_rs v0.8.34
Compiling crossbeam-epoch v0.9.18
Compiling aho-corasick v1.1.3
Compiling pest v2.7.11
Compiling generic-array v0.14.7
Compiling bstr v1.10.0
Compiling rand_core v0.6.4
Compiling crossbeam-deque v0.8.5
Compiling rand_chacha v0.3.1
Compiling hashlink v0.8.4
Compiling tinyvec_macros v0.1.1
Compiling hashlink v0.9.1
Compiling clap_builder v4.5.15
Compiling tinyvec v1.8.0
Compiling opaque-debug v0.3.1
Compiling rand v0.8.5
Compiling signature v1.6.4
Compiling crypto-common v0.1.6
Compiling block-buffer v0.10.4
Compiling block-padding v0.3.3
Compiling inout v0.1.3
Compiling digest v0.10.7
Compiling universal-hash v0.5.1
Compiling lazy_static v1.5.0
Compiling cipher v0.4.4
Compiling utf8-width v0.1.7
Compiling ed25519 v1.5.3
Compiling html-escape v0.2.13
Compiling yaml-rust2 v0.8.1
Compiling indexmap v2.4.0
Compiling subplot v0.10.0
Compiling ct-codecs v1.1.1
Compiling tempfile v3.12.0
Compiling linux-raw-sys v0.4.14
Compiling regex-automata v0.4.7
Compiling pest_meta v2.7.11
Compiling unicode-normalization v0.1.23
Compiling amplify_num v0.5.3
Compiling unicode-bidi v0.3.15
Compiling ascii v1.1.0
Compiling tempfile-fast v0.3.4
Compiling ec25519 v0.1.0
Compiling time v0.3.36
Compiling pulldown-cmark v0.9.6
Compiling idna v0.5.0
Compiling sha2 v0.10.8
Compiling polyval v0.6.2
Compiling libz-sys v1.1.19
Compiling pest_generator v2.7.11
Compiling serde_json v1.0.125
Compiling serde_path_to_error v0.1.16
Compiling serde_yaml v0.9.34+deprecated
Compiling tracing-core v0.1.32
Compiling clap v4.5.16
Compiling marked-yaml v0.7.1
Compiling form_urlencoded v1.2.1
Compiling git-ref-format-core v0.3.0
Compiling base64 v0.22.1
Compiling amplify v4.7.0
Compiling roadmap v0.6.1
Compiling serde-aux v4.5.0
Compiling base64ct v1.6.0
Compiling byteorder v1.5.0
Compiling keccak v0.1.5
Compiling tracing v0.1.40
Compiling cyphergraphy v0.3.0
Compiling globset v0.4.14
Compiling regex v1.10.6
Compiling git-testament-derive v0.2.0
Compiling sha3 v0.10.8
Compiling pem-rfc7468 v0.7.0
Compiling git-ref-format-macro v0.3.0
Compiling pest_derive v2.7.11
Compiling url v2.5.2
Compiling ignore v0.4.22
Compiling env_logger v0.10.2
Compiling ghash v0.5.1
Compiling libgit2-sys v0.16.2+1.7.2
Compiling aes v0.8.4
Compiling ctr v0.9.2
Compiling aead v0.5.2
Compiling base32 v0.4.0
Compiling git2 v0.18.3
Compiling git-ref-format v0.3.0
Compiling cypheraddr v0.4.0
Compiling ssh-encoding v0.2.0
Compiling sqlite3-src v0.5.1
Compiling blowfish v0.9.1
Compiling chacha20 v0.9.1
Compiling cbc v0.1.2
Compiling pbkdf2 v0.12.2
Compiling poly1305 v0.8.0
Compiling globwalk v0.9.1
Compiling zeroize v1.8.1
Compiling radicle-std-ext v0.1.0
Compiling data-encoding v2.6.0
Compiling aes-gcm v0.10.3
Compiling bcrypt-pbkdf v0.10.0
Compiling tera v1.20.0
Compiling socks5-client v0.4.1
Compiling sqlite3-sys v0.15.2
Compiling ssh-cipher v0.2.0
Compiling git-testament v0.2.5
Compiling xattr v1.3.1
Compiling crc32fast v1.4.2
Compiling filetime v0.2.24
Compiling data-encoding-macro v0.1.15
Compiling signature v2.2.0
Compiling base-x v0.2.11
Compiling flate2 v1.0.31
Compiling tar v0.4.41
Compiling cyphernet v0.5.2
Compiling ssh-key v0.6.6
Compiling multibase v0.9.1
Compiling nix v0.29.0
Compiling sqlite v0.32.0
Compiling radicle-ssh v0.9.0
Compiling qcheck v1.0.0
Compiling cvt v0.1.2
Compiling culpa v1.0.2
Compiling slog v2.7.0
Compiling terminal_size v0.3.0
Compiling nonempty v0.9.0
Compiling radicle-dag v0.9.0
Compiling normpath v1.3.0
Compiling subplotlib-derive v0.10.0
Compiling localtime v1.3.1
Compiling fs2 v0.4.3
Compiling crossbeam-channel v0.5.13
Compiling base64 v0.13.1
Compiling radicle-surf v0.18.0
Compiling fs_at v0.2.1
Compiling base64 v0.21.7
Compiling nonempty v0.5.0
Compiling remove_dir_all v0.8.3
Compiling shell-words v1.1.0
Compiling state v0.5.3
Compiling libyml v0.0.4
Compiling siphasher v1.0.1
Compiling arc-swap v1.7.1
Compiling unescape v0.1.0
Compiling html-page v0.4.0
Compiling uuid v1.10.0
Compiling slog-scope v4.4.0
Compiling radicle-git-ext v0.7.0
Compiling slog-json v2.6.1
Compiling serde_yml v0.0.11
Compiling radicle-crypto v0.10.0
Compiling radicle-cob v0.11.0
Compiling subplot-build v0.10.0
Compiling radicle v0.12.0
Compiling subplotlib v0.10.0
Compiling radicle-ci-broker v0.4.0 (/srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src)
Finished dev [unoptimized + debuginfo] target(s) in 18.42s
+ cargo doc --workspace
Checking unicode-ident v1.0.12
Documenting unicode-ident v1.0.12
Documenting cfg-if v1.0.0
Documenting typenum v1.17.0
Documenting libc v0.2.158
Documenting subtle v2.6.1
Documenting bitflags v2.6.0
Documenting cpufeatures v0.2.13
Documenting tinyvec_macros v0.1.1
Documenting opaque-debug v0.3.1
Documenting memchr v2.7.4
Documenting ed25519 v1.5.3
Documenting unicode-bidi v0.3.15
Documenting ct-codecs v1.1.1
Documenting log v0.4.22
Documenting percent-encoding v2.3.1
Checking proc-macro2 v1.0.86
Documenting tinyvec v1.8.0
Documenting amplify_num v0.5.3
Documenting ascii v1.1.0
Documenting linux-raw-sys v0.4.14
Documenting proc-macro2 v1.0.86
Checking quote v1.0.36
Checking git-ref-format-core v0.3.0
Documenting byteorder v1.5.0
Documenting itoa v1.0.11
Checking syn v2.0.75
Checking syn v1.0.109
Documenting form_urlencoded v1.2.1
Documenting keccak v0.1.5
Documenting base64ct v1.6.0
Documenting fastrand v2.1.0
Documenting equivalent v1.0.1
Documenting base32 v0.4.0
Documenting hashbrown v0.14.5
Checking data-encoding v2.6.0
Documenting unicode-normalization v0.1.23
Documenting quote v1.0.36
Documenting sqlite3-src v0.5.1
Documenting data-encoding v2.6.0
Documenting zeroize v1.8.1
Documenting ryu v1.0.18
Documenting pem-rfc7468 v0.7.0
Documenting radicle-std-ext v0.1.0
Documenting rustix v0.38.34
Checking amplify_syn v2.0.1
Checking proc-macro-error v1.0.4
Documenting getrandom v0.2.15
Documenting libz-sys v1.1.19
Documenting data-encoding-macro-internal v0.1.13
Documenting once_cell v1.19.0
Documenting sqlite3-sys v0.15.2
Documenting serde_derive v1.0.208
Documenting amplify_syn v2.0.1
Documenting thiserror-impl v1.0.63
Documenting proc-macro-error-attr v1.0.4
Documenting powerfmt v0.2.0
Documenting utf8parse v0.2.2
Documenting signature v2.2.0
Documenting idna v0.5.0
Documenting ec25519 v0.1.0
Documenting generic-array v0.14.7
Documenting rand_core v0.6.4
Documenting indexmap v2.4.0
Documenting libgit2-sys v0.16.2+1.7.2
Documenting data-encoding-macro v0.1.15
Documenting base-x v0.2.11
Documenting deranged v0.3.11
Documenting anstyle-parse v0.2.5
Documenting proc-macro-error v1.0.4
Documenting tempfile v3.12.0
Documenting sqlite v0.32.0
Documenting rand v0.8.5
Documenting nix v0.29.0
Documenting amplify_derive v4.0.1
Documenting thiserror v1.0.63
Documenting multibase v0.9.1
Documenting url v2.5.2
Documenting aho-corasick v1.1.3
Documenting time-macros v0.2.18
Documenting crypto-common v0.1.6
Documenting block-buffer v0.10.4
Documenting block-padding v0.3.3
Documenting git-ref-format-macro v0.3.0
Documenting cvt v0.1.2
Documenting anstyle v1.0.8
Documenting serde v1.0.208
Documenting radicle-ssh v0.9.0
Documenting regex-syntax v0.8.4
Documenting time-core v0.1.2
Documenting qcheck v1.0.0
Documenting git2 v0.18.3
Documenting universal-hash v0.5.1
Documenting amplify v4.7.0
Documenting digest v0.10.7
Documenting inout v0.1.3
Documenting aead v0.5.2
Documenting anstyle-query v1.1.1
Documenting colorchoice v1.0.2
Documenting num-conv v0.1.0
Documenting is_terminal_polyfill v1.70.1
Documenting terminal_size v0.3.0
Documenting fs_at v0.2.1
Documenting culpa-macros v1.0.2
Documenting radicle-dag v0.9.0
Documenting cipher v0.4.4
Compiling radicle-ci-broker v0.4.0 (/srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src)
Documenting polyval v0.6.2
Documenting poly1305 v0.8.0
Documenting cyphergraphy v0.3.0
Documenting slog v2.7.0
Documenting time v0.3.36
Documenting anstream v0.6.15
Documenting regex-automata v0.4.7
Documenting sha2 v0.10.8
Documenting sha3 v0.10.8
Documenting pbkdf2 v0.12.2
Documenting crossbeam-utils v0.8.20
Documenting lazy_static v1.5.0
Documenting utf8-width v0.1.7
Documenting normpath v1.3.0
Documenting git-ref-format-core v0.3.0
Documenting ghash v0.5.1
Documenting serde_json v1.0.125
Documenting nonempty v0.9.0
Checking heck v0.5.0
Documenting clap_lex v0.7.2
Documenting ctr v0.9.2
Documenting aes v0.8.4
Documenting ssh-encoding v0.2.0
Documenting chacha20 v0.9.1
Documenting blowfish v0.9.1
Documenting cypheraddr v0.4.0
Documenting cbc v0.1.2
Documenting strsim v0.11.1
Documenting heck v0.5.0
Documenting regex v1.10.6
Documenting remove_dir_all v0.8.3
Documenting crossbeam-channel v0.5.13
Documenting html-escape v0.2.13
Documenting git-ref-format v0.3.0
Documenting localtime v1.3.1
Documenting culpa v1.0.2
Documenting subplotlib-derive v0.10.0
Documenting aes-gcm v0.10.3
Documenting bcrypt-pbkdf v0.10.0
Documenting filetime v0.2.24
Documenting clap_derive v4.5.13
Documenting clap_builder v4.5.15
Documenting fs2 v0.4.3
Documenting arc-swap v1.7.1
Documenting socks5-client v0.4.1
Documenting shell-words v1.1.0
Documenting state v0.5.3
Documenting radicle-git-ext v0.7.0
Documenting base64 v0.22.1
Documenting unescape v0.1.0
Documenting libyml v0.0.4
Documenting siphasher v1.0.1
Documenting ssh-cipher v0.2.0
Documenting html-page v0.4.0
Documenting slog-json v2.6.1
Documenting uuid v1.10.0
Documenting anyhow v1.0.86
Documenting slog-scope v4.4.0
Documenting cyphernet v0.5.2
Documenting subplotlib v0.10.0
Documenting radicle-surf v0.18.0
Documenting serde_yml v0.0.11
Documenting clap v4.5.16
Documenting ssh-key v0.6.6
Documenting radicle-crypto v0.10.0
Documenting radicle-cob v0.11.0
Documenting radicle v0.12.0
Documenting radicle-ci-broker v0.4.0 (/srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src)
Finished dev [unoptimized + debuginfo] target(s) in 33.15s
Generated /srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src/target/doc/radicle_ci_broker/index.html
Generated /srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src/target/doc/cib/index.html
Generated /srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src/target/doc/cibtool/index.html
Generated /srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src/target/doc/synthetic_events/index.html
+ cargo test --workspace --no-fail-fast
Finished test [unoptimized + debuginfo] target(s) in 0.11s
Running unittests src/lib.rs (target/debug/deps/radicle_ci_broker-a0fa34f091896d04)
running 40 tests
{"msg":"broker database: /tmp/.tmp3dIuhz/db.db","level":"INFO","ts":"2024-08-23T07:11:57.873548553Z"}
{"msg":"broker database: /tmp/.tmpPGwiL1/db.db","level":"INFO","ts":"2024-08-23T07:11:57.873656083Z"}
{"msg":"broker database: /tmp/.tmpo1E6nw/db.db","level":"INFO","ts":"2024-08-23T07:11:57.873756634Z"}
{"msg":"broker database: /tmp/.tmp9po3Z7/db.db","level":"INFO","ts":"2024-08-23T07:11:57.873845524Z"}
test broker::test::adds_adapter ... ok
{"msg":"broker database: /tmp/.tmpqlrZ3W/db.db","level":"INFO","ts":"2024-08-23T07:11:58.100919588Z"}
test broker::test::does_not_have_a_default_adapter_initially ... ok
{test broker::test::does_not_find_unknown_repo ... ok
"msg":"broker database: /tmp/.tmpySoN10/db.db","level":"INFO","ts":"2024-08-23T07:11:58.11505923Z"}
{"msg":"broker database: /tmp/.tmpkxwIDD/db.db","level":"INFO","ts":"2024-08-23T07:11:58.11523502Z"}
test adapter::test::adapter_has_bad_interpreter ... ok
{"msg":"broker database: /tmp/.tmp4CshKq/db.db","level":"INFO","ts":"2024-08-23T07:11:58.167537832Z"}
{"msg":"adapter exit code: 1","level":"DEBG","ts":"2024-08-23T07:11:58.171086848Z"}
{"msg":"adapter stderr: woe be me\n","level":"DEBG","ts":"2024-08-23T07:11:58.171130148Z"}
test adapter::test::adapter_exits_nonzero ... ok
test event::test::branch_is_not_patch_update ... ok
test event::test::get_no_push_branch ... ok
test event::test::get_push_branch ... ok
test event::test::patch_branch_is_not_patch_update ... ok
test event::test::patch_update ... ok
test event::test::test_parse_invalid_ref ... ok
test adapter::test::adapter_first_message_isnt_triggered ... ok
test event::test::test_parse_patch_ref ... ok
test event::test_broker_event::name_for_branch ... ok
test event::test_broker_event::name_for_shutdown ... ok
test event::test_broker_event::nid_for_plain_branch_name ... ok
test event::test_broker_event::nid_for_ref_with_namespace ... ok
test event::test::test_parse_push_ref ... ok
test event::test_broker_event::nid_for_ref_without_namespace ... ok
test event::test_parse_ref::namespaced_branch ... ok
test event::test_parse_ref::namespaced_branch_with_slashes ... ok
test adapter::test::adapter_does_not_exist ... ok
{"msg":"start CI run","level":"INFO","ts":"2024-08-23T07:11:58.183138976Z"}
{"msg":"trigger event: Trigger {\n common: EventCommonFields {\n version: 1,\n event_type: Push,\n repository: Repository {\n id: RepoId(rad:z4JEEz69XqCEcp95caqJzZDM29Zb8),\n name: \"acme\",\n description: \"Acme's repository\",\n private: false,\n default_branch: \"master\",\n delegates: [\n Did(\"did:key:z6MkqufocYq3PWoG4SwYE1emmiDrKNCowdrrmou9gyVxqxwR\"),\n ],\n },\n },\n push: Some(\n PushEvent {\n pusher: Author {\n id: Did(\"did:key:z6MkqufocYq3PWoG4SwYE1emmiDrKNCowdrrmou9gyVxqxwR\"),\n alias: None,\n },\n before: Oid(\n f2de534b5e81d7c6e2dcaf58c3dd91573c0a0354,\n ),\n after: Oid(\n 532c92e4ec973d79c25652c581ae82d238e46a06,\n ),\n branch: \"master\",\n commits: [\n Oid(\n 532c92e4ec973d79c25652c581ae82d238e46a06,\n ),\n ],\n },\n ),\n patch: None,\n}","level":"DEBG","ts":"2024-08-23T07:11:58.183344037Z"}
test event::test_parse_ref::namespaced_patch ... ok
{"msg":"no first response message","level":"ERRO","ts":"2024-08-23T07:11:58.184062458Z"}
{"msg":"no second response message","level":"ERRO","ts":"2024-08-23T07:11:58.184106258Z"}
{"msg":"adapter did not exit voluntarily","level":"WARN","ts":"2024-08-23T07:11:58.184138808Z"}
test adapter::test::adapter_is_killed_before_any_messages ... ok
test run::test::serialize_run_state ... ok
test event::test_parse_ref::plain_branch_name_is_none ... ok
{"msg":"no second response message","level":"ERRO","ts":"2024-08-23T07:11:58.18567721Z"}
{"msg":"adapter did not exit voluntarily","level":"WARN","ts":"2024-08-23T07:11:58.18572119Z"}
test adapter::test::adapter_is_killed_after_first_message ... ok
{"msg":"too many response messages","level":"ERRO","ts":"2024-08-23T07:11:58.186047291Z"}
test adapter::test::adapter_outputs_too_many_messages ... ok
{"msg":"adapter did not exit voluntarily","level":"WARN","ts":"2024-08-23T07:11:58.188749845Z"}
test adapter::test::adapter_is_killed_after_second_message ... ok
test adapter::test::adapter_is_not_executable ... ok
test adapter::test::adapter_reports_success ... ok
test adapter::test::adapter_reports_failure ... ok
test adapter::test::adapter_produces_as_bad_message ... ok
test msg::tests::trigger_push ... ok
test msg::tests::trigger_patch ... ok
test broker::test::finds_default_adapter_for_unknown_repo ... ok
test broker::test::has_no_adapters_initially ... ok
test broker::test::sets_a_default_adapter_initially ... ok
{"msg":"adapter exit code: 1","level":"DEBG","ts":"2024-08-23T07:11:58.480675801Z"}
{"msg":"adapter stderr: woe be me\n","level":"DEBG","ts":"2024-08-23T07:11:58.480735871Z"}
{"msg":"start CI run","level":"INFO","ts":"2024-08-23T07:11:58.522429906Z"}
{"msg":"trigger event: Trigger {\n common: EventCommonFields {\n version: 1,\n event_type: Push,\n repository: Repository {\n id: RepoId(rad:z3tybkYvJU8HqCQmnkBqwaWHajbcn),\n name: \"acme\",\n description: \"Acme's repository\",\n private: false,\n default_branch: \"master\",\n delegates: [\n Did(\"did:key:z6MkhUCHYkVvFpfwFf4pxJFUeZRiKWkZAuRKFECbStgvzLk2\"),\n ],\n },\n },\n push: Some(\n PushEvent {\n pusher: Author {\n id: Did(\"did:key:z6MkhUCHYkVvFpfwFf4pxJFUeZRiKWkZAuRKFECbStgvzLk2\"),\n alias: None,\n },\n before: Oid(\n f2de534b5e81d7c6e2dcaf58c3dd91573c0a0354,\n ),\n after: Oid(\n 532c92e4ec973d79c25652c581ae82d238e46a06,\n ),\n branch: \"master\",\n commits: [\n Oid(\n 532c92e4ec973d79c25652c581ae82d238e46a06,\n ),\n ],\n },\n ),\n patch: None,\n}","level":"DEBG","ts":"2024-08-23T07:11:58.522711726Z"}
{"msg":"failed to run adapter or it failed to run CI: child process failed with wait status 1","level":"ERRO","ts":"2024-08-23T07:11:58.525937271Z"}
{"msg":"Finish CI run","level":"INFO","ts":"2024-08-23T07:11:58.525972121Z"}
{"msg":"finished CI run: Run {\n broker_run_id: RunId {\n id: \"addfb18d-cac5-496a-b81b-975b0ca685fc\",\n },\n adapter_run_id: Some(\n RunId {\n id: \"xyzzy\",\n },\n ),\n adapter_info_url: None,\n repo_id: RepoId(rad:z4JEEz69XqCEcp95caqJzZDM29Zb8),\n repo_name: \"acme\",\n timestamp: \"2024-08-23 07:11:58Z\",\n whence: Branch {\n name: \"push-event-has-no-branch-name\",\n commit: Oid(\n 532c92e4ec973d79c25652c581ae82d238e46a06,\n ),\n who: Some(\n \"did:key:z6MkqufocYq3PWoG4SwYE1emmiDrKNCowdrrmou9gyVxqxwR\",\n ),\n },\n state: Finished,\n result: Some(\n Success,\n ),\n}","level":"DEBG","ts":"2024-08-23T07:11:58.526092421Z"}
test broker::test::adapter_fails ... ok
{"msg":"Finish CI run","level":"INFO","ts":"2024-08-23T07:11:58.681107663Z"}
{"msg":"finished CI run: Run {\n broker_run_id: RunId {\n id: \"6eac6b27-c21e-494c-8ab9-7b8e378fc3e1\",\n },\n adapter_run_id: Some(\n RunId {\n id: \"xyzzy\",\n },\n ),\n adapter_info_url: None,\n repo_id: RepoId(rad:z3tybkYvJU8HqCQmnkBqwaWHajbcn),\n repo_name: \"acme\",\n timestamp: \"2024-08-23 07:11:58Z\",\n whence: Branch {\n name: \"push-event-has-no-branch-name\",\n commit: Oid(\n 532c92e4ec973d79c25652c581ae82d238e46a06,\n ),\n who: Some(\n \"did:key:z6MkhUCHYkVvFpfwFf4pxJFUeZRiKWkZAuRKFECbStgvzLk2\",\n ),\n },\n state: Finished,\n result: Some(\n Success,\n ),\n}","level":"DEBG","ts":"2024-08-23T07:11:58.681212813Z"}
test broker::test::executes_adapter ... ok
test result: ok. 40 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.81s
Running unittests src/bin/cib.rs (target/debug/deps/cib-d7be6a7c3ca0f24f)
running 0 tests
test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
Running unittests src/bin/cibtool.rs (target/debug/deps/cibtool-0eb13d3132e032d7)
running 0 tests
test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
Running unittests src/bin/synthetic-events.rs (target/debug/deps/synthetic_events-da3fee5d5719402f)
running 0 tests
test result: ok. 0 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.00s
Running tests/subplot.rs (target/debug/deps/subplot-0db116672a3bb717)
running 28 tests
test dummy_adapter_runs_successfully ... ok
test adapter_with_url_runs_successfully ... ok
test event_synthesizer_terminates_after_first_connection ... ok
test can_add_shutdown_event_to_queue ... ok
test logs_termination_due_to_error ... FAILED
test gives_helpful_error_message_if_it_doesn_t_understand_its_configuration_file ... ok
test gives_helpful_error_message_if_node_socket_can_t_be_found ... ok
test don_t_insert_events_into_queue_when_not_allowed_by_filter ... ok
test add_information_about_run_that_s_finished_successfully_to_database ... ok
test can_trigger_a_ci_run ... ok
test add_information_about_run_that_s_running_to_database ... ok
test add_information_about_triggered_run_to_database ... ok
test add_information_about_run_that_s_finished_in_failure_to_database ... ok
test shows_config_as_json ... ok
test events_can_be_queued_and_removed_from_queue ... ok
test insert_events_into_queue ... ok
test adapter_can_provide_url_for_info_on_run ... ok
test logs_start_and_successful_end ... ok
test reports_it_version ... ok
test process_queued_events ... ok
test produces_a_report_page_upon_request ... ok
test stops_if_the_node_connection_breaks ... ok
test shuts_down_when_requested ... ok
test update_and_show_information_about_run_to_running ... ok
test smoke_test__runs_adapter ... ok
test count_in_a_single_process has been running for over 60 seconds
test count_in_concurrent_processes has been running for over 60 seconds
test insert_many_events_into_queue has been running for over 60 seconds
test count_in_a_single_process ... ok
test insert_many_events_into_queue ... ok
test count_in_concurrent_processes ... ok
failures:
---- logs_termination_due_to_error stdout ----
ci-broker.md:1077:1: scenario: Logs termination due to error
ci-broker.md:1090:1: step: given an installed cib
ci-broker.md:1092:1: step: given file broker.yaml
ci-broker.md:1093:1: step: when I try to run cib --config broker.yaml queued
Running `cib` with args ["--config", "broker.yaml", "queued"]
Running in /tmp/subplotXxXRmLogs-termination-due-to-error
ENV: SHELL = /bin/sh
PATH: /srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src/target/debug:/home/_rad/.cargo/bin:/bin:/usr/bin:/sbin:/usr/sbin
Exit code: 0
Stdout:
Stderr:
{"msg":"CI broker starts","level":"INFO","ts":"2024-08-23T07:11:59.097468004Z"}
{"msg":"loaded configuration Config {\n default_adapter: \"mcadapterface\",\n adapters: {\n \"mcadapterface\": Adapter { \n command: \"./adapter.sh\", \n env: {\n \"RADICLE_NATIVE_CI\": \"native-ci.yaml\",\n }, \n sensitive_env: {} },\n },\n filters: [\n Branch(\n \"main\",\n ),\n ],\n report_dir: Some(\n \"reports\",\n ),\n status_update_interval_seconds: None,\n db: \"ci-broker.db\",\n}","level":"DEBG","ts":"2024-08-23T07:11:59.098034795Z"}
{"msg":"broker database: ci-broker.db","level":"INFO","ts":"2024-08-23T07:11:59.420056787Z"}
{"msg":"default adapter: Adapter { bin: \"./adapter.sh\", env: {\"RADICLE_NATIVE_CI\": \"native-ci.yaml\"} }","level":"DEBG","ts":"2024-08-23T07:11:59.420611848Z"}
{"msg":"start thread to process events until a shutdown event","level":"INFO","ts":"2024-08-23T07:11:59.427508559Z"}
{"msg":"event notification channel disconnected","level":"INFO","ts":"2024-08-23T07:11:59.427748119Z"}
{"msg":"start thread to process events ends","level":"INFO","ts":"2024-08-23T07:11:59.427804199Z"}
{"msg":"CI broker ends successfully","level":"INFO","ts":"2024-08-23T07:11:59.428051469Z"}
ci-broker.md:1095:1: step: then stderr contains "CI broker starts"
ci-broker.md:1096:1: step: then stderr contains "CI broker ends in unrecoverable error"
return: Failure
thread 'logs_termination_due_to_error' panicked at /srv/http/a0fda6cb-d079-41e7-b0ad-85c6ecd58b24/src/target/debug/build/radicle-ci-broker-196714280edcb383/out/ci-broker.rs:4003:20:
called `Result::unwrap()` on an `Err` value: "stderr does not contain \"CI broker ends in unrecoverable error\""
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
failures:
logs_termination_due_to_error
test result: FAILED. 27 passed; 1 failed; 0 ignored; 0 measured; 0 filtered out; finished in 80.16s
error: test failed, to rerun pass `--test subplot`
Doc-tests radicle-ci-broker
running 2 tests
test src/msg.rs - msg::RunId (line 44) ... ok
test src/event.rs - event (line 11) ... ok
test result: ok. 2 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 1.60s
error: 1 target failed:
`--test subplot`