Skip to content

Commit

Permalink
Improve debug logging, disable new interface if logging is enabled
Browse files Browse the repository at this point in the history
  • Loading branch information
@kpcyrd
kpcyrd committed Dec 31, 2021
1 parent f48680d commit b169521
Show file tree
Hide file tree
Showing 3 changed files with 116 additions and 39 deletions.
51 changes: 32 additions & 19 deletions src/main.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ use pacman_bintrans::proof;
use pacman_bintrans::reproducible;
use pacman_bintrans_common::errors::*;
use pacman_bintrans_common::http;
use std::env;
use std::fs;
use std::rc::Rc;
use structopt::StructOpt;
Expand Down Expand Up @@ -37,14 +38,17 @@ fn filename_from_url(url: &Url) -> Option<String> {
async fn main() -> Result<()> {
let args = Args::from_args();

let log = match args.verbose {
0 => "warn",
1 => "info",
2 => "info,pacman_bintrans=debug",
_ => "debug",
let log = match (args.verbose, env::var("RUST_LOG")) {
(0, Err(_)) => None,
(_, Ok(_)) => Some("warn"),
(1, _) => Some("info"),
(2, _) => Some("info,pacman_bintrans=debug"),
_ => Some("debug"),
};

env_logger::init_from_env(Env::default().default_filter_or(log));
if let Some(log) = log {
env_logger::init_from_env(Env::default().default_filter_or(log));
}

let pubkey = PublicKey::from_base64(&args.pubkey)
.context("Failed to load transparency public key")?
Expand Down Expand Up @@ -76,10 +80,12 @@ async fn main() -> Result<()> {
let pkg = pkg_client.download_to_mem(args.url.as_str(), None).await?;
debug!("Downloaded {} bytes", pkg.len());

println!(
"\x1b[1m[\x1b[32m+\x1b[0;1m]\x1b[0m Downloaded {:?}",
args.url.as_str()
);
if log.is_none() {
println!(
"\x1b[1m[\x1b[32m+\x1b[0;1m]\x1b[0m Downloaded {:?}",
args.url.as_str()
);
}

let url = if let Some(transparency_url) = &args.transparency_url {
let file_name = filename_from_url(&args.url).ok_or_else(|| {
Expand All @@ -95,19 +101,24 @@ async fn main() -> Result<()> {
args.url
};

println!("\x1b[2K\r\x1b[1m[\x1b[34m%\x1b[0;1m]\x1b[0m Checking transparency log...");
if log.is_none() {
println!("\x1b[2K\r\x1b[1m[\x1b[34m%\x1b[0;1m]\x1b[0m Checking transparency log...");
}

// security critical code happens here
proof::fetch_and_verify(&client, &pubkey, &url, &pkg)
.await
.context("Failed to check transparency log")?;

println!("\x1b[1A\x1b[2K\r\x1b[1m[\x1b[32m+\x1b[0;1m]\x1b[0m Package is present in transparency log");
if log.is_none() {
println!("\x1b[1A\x1b[2K\r\x1b[1m[\x1b[32m+\x1b[0;1m]\x1b[0m Package is present in transparency log");
}

if !args.rebuilders.is_empty() || args.required_rebuild_confirms > 0 {
let rebuild_confirms = reproducible::check_rebuilds(&client, &pkg, &args.rebuilders)
.await
.context("Failed to check rebuilds")?;
let rebuild_confirms =
reproducible::check_rebuilds(&client, &pkg, &args.rebuilders, &log)
.await
.context("Failed to check rebuilds")?;

if rebuild_confirms < args.required_rebuild_confirms {
bail!(
Expand All @@ -128,10 +139,12 @@ async fn main() -> Result<()> {
.await?;
debug!("Downloaded {} bytes", n);

println!(
"\x1b[1m[\x1b[32m+\x1b[0;1m]\x1b[0m Downloaded {:?}",
args.url.as_str()
);
if log.is_none() {
println!(
"\x1b[1m[\x1b[32m+\x1b[0;1m]\x1b[0m Downloaded {:?}",
args.url.as_str()
);
}
}

Ok(())
Expand Down
37 changes: 31 additions & 6 deletions src/proof.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -10,17 +10,29 @@ use tokio::io::AsyncWriteExt;
use tokio::process::Command;
use url::Url;

const REKOR_BIN: &str = "rekor-cli";
const PROOF_SIZE_LIMIT: usize = 1024; // 1K

async fn rekor_verify(pubkey: &PublicKeyBox, artifact: &[u8], signature: &[u8]) -> Result<()> {
let pubkey_file = NamedTempFile::new()?;
let sig_file = NamedTempFile::new()?;

fs::write(pubkey_file.path(), pubkey.to_string())?;
let pubkey = pubkey.to_string();
debug!(
"Writing to pubkey temp file {:?}: {:?}",
pubkey_file.path(),
pubkey
);
fs::write(pubkey_file.path(), pubkey)?;
debug!(
"Writing to signature temp file {:?}: {:?}",
sig_file.path(),
signature
);
fs::write(sig_file.path(), signature)?;

let mut child = Command::new("rekor-cli")
.arg("verify")
let mut cmd = Command::new(REKOR_BIN);
cmd.arg("verify")
.arg("--pki-format=minisign")
.arg("--public-key")
.arg(pubkey_file.path())
Expand All @@ -31,20 +43,33 @@ async fn rekor_verify(pubkey: &PublicKeyBox, artifact: &[u8], signature: &[u8])
.arg("--format")
.arg("json")
.stdin(Stdio::piped())
.stdout(Stdio::piped())
.spawn()
.context("failed to spawn")?;
.stdout(Stdio::piped());

debug!(
"Executing {:?} {:?}",
REKOR_BIN,
cmd.as_std().get_args().collect::<Vec<_>>()
);
let mut child = cmd.spawn().context("failed to spawn")?;

let mut stdin = child
.stdin
.take()
.context("child did not have a handle to stdin")?;

debug!("Sending to child stdin: {:?}", artifact);
stdin.write_all(artifact).await?;
stdin.flush().await?;
drop(stdin);

let exit = child.wait_with_output().await?;

debug!(
"Child wrote to stdout: {:?}",
String::from_utf8_lossy(&exit.stdout)
);
debug!("Child exited with {:?}", exit.status);

if exit.status.success() {
Ok(())
} else {
Expand Down
67 changes: 53 additions & 14 deletions src/reproducible.rs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,12 @@ async fn query_rebuilder(
let pkgs = serde_json::from_slice::<Vec<PkgRelease>>(&json)
.context("Failed to deserialize response")?;

debug!(
"Received response from rebuilder {:?}: {:?}",
rebuilder.as_str(),
pkgs
);

for pkg in pkgs {
if pkg.name != name {
continue;
Expand All @@ -49,6 +55,11 @@ async fn query_rebuilder(
continue;
}

debug!(
"Found matching package (status: {:?}): {:?}",
pkg.status, pkg
);

if pkg.status != Status::Good {
continue;
}
Expand Down Expand Up @@ -98,6 +109,7 @@ fn parse_pkg_info(pkg: &[u8]) -> Result<PkgInfo> {
let mut pkgname = None;
let mut pkgver = None;

info!("Extracting .PKGINFO from package...");
let content = extract_dot_pkginfo_from_archive(pkg)?;
for line in content.split('\n') {
if let Some(value) = line.strip_prefix("pkgname = ") {
Expand All @@ -108,40 +120,67 @@ fn parse_pkg_info(pkg: &[u8]) -> Result<PkgInfo> {
}
}

Ok(PkgInfo {
let pkginfo = PkgInfo {
name: pkgname.context("Missing pkgname field in .PKGINFO")?,
version: pkgver.context("Missing pkgver field in .PKGINFO")?,
})
};
debug!("Parsed pkginfo: {:?}", pkginfo);
Ok(pkginfo)
}

pub async fn check_rebuilds(client: &Client, pkg: &[u8], rebuilders: &[Url]) -> Result<usize> {
println!("\x1b[1m[\x1b[34m%\x1b[0;1m]\x1b[0m Inspecting .PKGINFO in package...");
pub async fn check_rebuilds(
client: &Client,
pkg: &[u8],
rebuilders: &[Url],
log: &Option<&str>,
) -> Result<usize> {
if log.is_none() {
println!("\x1b[1m[\x1b[34m%\x1b[0;1m]\x1b[0m Inspecting .PKGINFO in package...");
}

let pkginfo = parse_pkg_info(pkg).context("Failed to parse infos from package")?;
print!("\x1b[1A\x1b[2K");
if log.is_none() {
print!("\x1b[1A\x1b[2K");
}

let mut confirms = 0;
for rebuilder in rebuilders {
println!(
"\x1b[2K\r\x1b[1m[\x1b[34m%\x1b[0;1m]\x1b[0m Checking rebuilder {:?}...",
rebuilder.as_str()
);
if log.is_none() {
println!(
"\x1b[2K\r\x1b[1m[\x1b[34m%\x1b[0;1m]\x1b[0m Checking rebuilder {:?}...",
rebuilder.as_str()
);
}

match query_rebuilder(client, rebuilder, &pkginfo.name, &pkginfo.version).await {
Ok(true) => {
let msg = format!(
"Package was reproduced by rebuilder: {:?}",
rebuilder.as_str()
);

println!("\x1b[1A\x1b[2K\r\x1b[1m[\x1b[32m+\x1b[0;1m]\x1b[0m {:95} \x1b[32mREPRODUCIBLE\x1b[0m", msg);
info!("{}", msg);

if log.is_none() {
println!("\x1b[1A\x1b[2K\r\x1b[1m[\x1b[32m+\x1b[0;1m]\x1b[0m {:95} \x1b[32mREPRODUCIBLE\x1b[0m", msg);
}

confirms += 1;
}
Ok(false) => {
print!("\x1b[1A\x1b[2K");
if log.is_none() {
print!("\x1b[1A\x1b[2K");
}
}
Err(err) => {
// TODO: Using warn! moves the cursor in ways the terminal control characters don't expect
// warn!("Failed to query rebuilder: {:?}", err);
println!("\x1b[1A\x1b[2K\r\x1b[1m[\x1b[31m-\x1b[0;1m]\x1b[0m Failed to query rebuilder {:?}: {:#}", rebuilder.as_str(), err);
warn!(
"Failed to query rebuilder {:?}: {:#}",
rebuilder.as_str(),
err
);
if log.is_none() {
println!("\x1b[1A\x1b[2K\r\x1b[1m[\x1b[31m-\x1b[0;1m]\x1b[0m Failed to query rebuilder {:?}: {:#}", rebuilder.as_str(), err);
}
}
}
}
Expand Down

0 comments on commit b169521

Please sign in to comment.