Skip to content

Commit bbc2657

Browse files
pietroalbinipietroalbini
authored
Merge pull request #50 from pietroalbini/tracing
Switch to tracing for logging
2 parents 117f635 + 9cb81df commit bbc2657

File tree

11 files changed

+327
-196
lines changed

11 files changed

+327
-196
lines changed

‎Cargo.lock

Lines changed: 238 additions & 103 deletions
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

‎Cargo.toml

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -11,15 +11,13 @@ atomicwrites = "0.2"
1111
bincode = "1.0"
1212
brotli = "1.2"
1313
digest = "0.7"
14-
env_logger = "0.5"
1514
failure = "0.1"
1615
futures = "0.1"
1716
fnv = "1.0"
1817
hex = "0.3"
1918
hmac = "0.6"
2019
hyper = "0.12"
2120
lazy_static = "1.0"
22-
log = "0.4"
2321
regex = "0.2"
2422
reqwest = "0.9"
2523
serde = "1.0"
@@ -32,3 +30,5 @@ dotenv = "0.14"
3230
crossbeam = "0.7"
3331
percent-encoding = "2.1.0"
3432
threadpool = "1.8.1"
33+
tracing = "0.1.16"
34+
tracing-subscriber = "0.2.8"

‎src/bin/offline/extract.rs

Lines changed: 12 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,6 @@
11
use crate::offline;
22
use crate::rla;
33

4-
use log;
54
use std::fs;
65
use std::io::{self, Write};
76
use std::path::Path;
@@ -61,19 +60,20 @@ pub fn dir(
6160

6261
let now = Instant::now();
6362

64-
let level = if now - last_print >= progress_every {
63+
if now - last_print >= progress_every {
6564
last_print = now;
66-
log::Level::Debug
65+
debug!(
66+
"Extracting errors from {} [{}/?]...",
67+
entry.path().display(),
68+
count
69+
);
6770
} else {
68-
log::Level::Trace
69-
};
70-
71-
log!(
72-
level,
73-
"Extracting errors from {} [{}/?]...",
74-
entry.path().display(),
75-
count
76-
);
71+
trace!(
72+
"Extracting errors from {} [{}/?]...",
73+
entry.path().display(),
74+
count
75+
);
76+
}
7777

7878
let log = offline::fs::load_maybe_compressed(entry.path())?;
7979
let lines = load_lines(ci, &log);

‎src/bin/offline/learn.rs

Lines changed: 4 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,6 @@
11
use crate::offline;
22
use crate::rla;
33

4-
use log;
54
use std::path::{Path, PathBuf};
65
use std::time::Duration;
76
use std::time::Instant;
@@ -30,19 +29,12 @@ pub fn learn(
3029

3130
let now = Instant::now();
3231

33-
let level = if now - last_print >= progress_every {
32+
if now - last_print >= progress_every {
3433
last_print = now;
35-
log::Level::Debug
34+
debug!("Learning from {} [{}/?]...", input.path().display(), count);
3635
} else {
37-
log::Level::Trace
38-
};
39-
40-
log!(
41-
level,
42-
"Learning from {} [{}/?]...",
43-
input.path().display(),
44-
count
45-
);
36+
trace!("Learning from {} [{}/?]...", input.path().display(), count);
37+
}
4638

4739
let data = offline::fs::load_maybe_compressed(input.path())?;
4840

‎src/bin/rla-offline.rs

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -6,11 +6,10 @@
66
)]
77

88
extern crate brotli;
9-
extern crate env_logger;
109
#[macro_use]
1110
extern crate failure;
1211
#[macro_use]
13-
extern crate log;
12+
extern crate tracing;
1413
extern crate rust_log_analyzer as rla;
1514
extern crate walkdir;
1615

‎src/bin/rla-server.rs

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -5,13 +5,12 @@
55
clippy::useless_let_if_seq
66
)]
77

8-
extern crate env_logger;
98
#[macro_use]
109
extern crate failure;
1110
extern crate futures;
1211
extern crate hyper;
1312
#[macro_use]
14-
extern crate log;
13+
extern crate tracing;
1514
extern crate crossbeam;
1615
extern crate regex;
1716
extern crate rust_log_analyzer as rla;

‎src/bin/server/mod.rs

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -6,7 +6,12 @@ pub use self::worker::Worker;
66
mod service;
77
mod worker;
88

9-
pub enum QueueItem {
9+
pub struct QueueItem {
10+
pub kind: QueueItemKind,
11+
pub delivery_id: String,
12+
}
13+
14+
pub enum QueueItemKind {
1015
GitHubStatus(rla::github::CommitStatusEvent),
1116
GitHubCheckRun(rla::github::CheckRunEvent),
1217
}

‎src/bin/server/service.rs

Lines changed: 31 additions & 25 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
use super::QueueItem;
1+
use super::{QueueItem, QueueItemKind};
22

33
use crate::rla;
44
use futures::{future, Future, Stream};
@@ -68,7 +68,17 @@ impl RlaService {
6868
}
6969
};
7070

71-
match event {
71+
let delivery_header = headers
72+
.get("X-GitHub-Delivery")
73+
.and_then(|s| s.to_str().ok())
74+
.map(|s| s.to_string());
75+
let delivery_id = if let Some(id) = delivery_header {
76+
id
77+
} else {
78+
return reply(StatusCode::BAD_REQUEST, "Missing delivery ID.\n");
79+
};
80+
81+
let item_kind = match event {
7282
"status" => {
7383
let payload = match serde_json::from_slice(body) {
7484
Ok(p) => p,
@@ -77,17 +87,7 @@ impl RlaService {
7787
return reply(StatusCode::BAD_REQUEST, "Failed to decode payload.\n");
7888
}
7989
};
80-
81-
match self.queue.send(QueueItem::GitHubStatus(payload)) {
82-
Ok(()) => reply(StatusCode::OK, "Event processed.\n"),
83-
Err(e) => {
84-
error!("Failed to queue payload: {}", e);
85-
reply(
86-
StatusCode::INTERNAL_SERVER_ERROR,
87-
"Failed to process the event.\n",
88-
)
89-
}
90-
}
90+
QueueItemKind::GitHubStatus(payload)
9191
}
9292
"check_run" => {
9393
let payload = match serde_json::from_slice(body) {
@@ -98,24 +98,30 @@ impl RlaService {
9898
}
9999
};
100100

101-
match self.queue.send(QueueItem::GitHubCheckRun(payload)) {
102-
Ok(()) => reply(StatusCode::OK, "Event processed.\n"),
103-
Err(e) => {
104-
error!("Failed to queue payload: {}", e);
105-
reply(
106-
StatusCode::INTERNAL_SERVER_ERROR,
107-
"Failed to process the event.\n",
108-
)
109-
}
110-
}
101+
QueueItemKind::GitHubCheckRun(payload)
111102
}
112103
"issue_comment" => {
113104
debug!("Ignoring 'issue_comment' event.");
114-
reply(StatusCode::OK, "Event ignored.\n")
105+
return reply(StatusCode::OK, "Event ignored.\n");
115106
}
116107
_ => {
117108
warn!("Unexpected '{}' event.", event);
118-
reply(StatusCode::BAD_REQUEST, "Unexpected event.\n")
109+
return reply(StatusCode::BAD_REQUEST, "Unexpected event.\n");
110+
}
111+
};
112+
113+
let item = QueueItem {
114+
kind: item_kind,
115+
delivery_id,
116+
};
117+
match self.queue.send(item) {
118+
Ok(()) => reply(StatusCode::OK, "Event processed.\n"),
119+
Err(e) => {
120+
error!("Failed to queue payload: {}", e);
121+
reply(
122+
StatusCode::INTERNAL_SERVER_ERROR,
123+
"Failed to process the event.\n",
124+
)
119125
}
120126
}
121127
}

‎src/bin/server/worker.rs

Lines changed: 27 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
use super::QueueItem;
1+
use super::{QueueItem, QueueItemKind};
22

33
use crate::rla;
44
use crate::rla::ci::{self, BuildCommit, CiPlatform};
@@ -78,7 +78,16 @@ impl Worker {
7878
pub fn main(&mut self) -> rla::Result<()> {
7979
loop {
8080
let item = self.queue.recv()?;
81-
match self.process(item) {
81+
82+
let span = span!(
83+
tracing::Level::INFO,
84+
"request",
85+
delivery = item.delivery_id.as_str(),
86+
build_id = tracing::field::Empty
87+
);
88+
let _enter = span.enter();
89+
90+
match self.process(item, &span) {
8291
Ok(()) => (),
8392
Err(e) => error!("Processing queue item failed: {}", e),
8493
}
@@ -92,9 +101,9 @@ impl Worker {
92101
self.secondary_repos.iter().find(|r| *r == repo).is_some()
93102
}
94103

95-
fn process(&mut self, item: QueueItem) -> rla::Result<()> {
96-
let (repo, build_id, outcome) = match &item {
97-
QueueItem::GitHubStatus(ev) => match self.ci.build_id_from_github_status(&ev) {
104+
fn process(&mut self, item: QueueItem, span: &tracing::Span) -> rla::Result<()> {
105+
let (repo, build_id, outcome) = match &item.kind {
106+
QueueItemKind::GitHubStatus(ev) => match self.ci.build_id_from_github_status(&ev) {
98107
Some(id) if self.is_repo_valid(&ev.repository.full_name) => {
99108
(&ev.repository.full_name, id, None)
100109
}
@@ -106,7 +115,7 @@ impl Worker {
106115
return Ok(());
107116
}
108117
},
109-
QueueItem::GitHubCheckRun(ev) => match self.ci.build_id_from_github_check(&ev) {
118+
QueueItemKind::GitHubCheckRun(ev) => match self.ci.build_id_from_github_check(&ev) {
110119
Some(id) if self.is_repo_valid(&ev.repository.full_name) => {
111120
(&ev.repository.full_name, id, Some(&ev.check_run.outcome))
112121
}
@@ -120,10 +129,12 @@ impl Worker {
120129
},
121130
};
122131

123-
info!("build {}: started processing", build_id);
132+
span.record("build_id", &build_id);
133+
134+
info!("started processing");
124135

125136
if self.seen.contains(&build_id) {
126-
info!("build {}: ignoring recently seen id", build_id);
137+
info!("ignoring recently seen id");
127138
return Ok(());
128139
}
129140
let query_from = if self.query_builds_from_primary_repo {
@@ -138,34 +149,31 @@ impl Worker {
138149
_ => build.outcome(),
139150
};
140151

141-
debug!("build {}: current outcome: {:?}", build_id, outcome);
142-
debug!("build {}: PR number: {:?}", build_id, build.pr_number());
143-
debug!("build {}: branch name: {:?}", build_id, build.pr_number());
152+
debug!("current outcome: {:?}", outcome);
153+
debug!("PR number: {:?}", build.pr_number());
154+
debug!("branch name: {:?}", build.branch_name());
144155

145156
if !outcome.is_finished() {
146-
info!("build {}: ignoring in-progress build", build_id);
157+
info!("ignoring in-progress build");
147158
return Ok(());
148159
}
149160

150161
// Avoid processing the same build multiple times.
151-
info!("build {}: marked as seen", build_id);
162+
info!("marked as seen");
152163
self.seen.push_front(build_id);
153164
if self.seen.len() > KEEP_IDS {
154165
self.seen.pop_back();
155166
}
156167

157168
if !outcome.is_passed() {
158-
info!("build {}: preparing report", build_id);
169+
info!("preparing report");
159170
self.report_failed(build.as_ref())?;
160171
}
161172
if build.pr_number().is_none() && build.branch_name() == "auto" {
162-
info!("build {}: learning from the log", build_id);
173+
info!("learning from the log");
163174
self.learn(build.as_ref())?;
164175
} else {
165-
info!(
166-
"build {}: did not learn as it's not an auto build",
167-
build_id
168-
);
176+
info!("did not learn as it's not an auto build");
169177
}
170178

171179
Ok(())

‎src/bin/util/mod.rs

Lines changed: 3 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,5 @@
11
use crate::rla;
2-
use env_logger;
32
use failure::ResultExt;
4-
use log;
5-
use std::env;
63
use std::process;
74

85
pub(crate) enum CliCiPlatform {
@@ -40,19 +37,9 @@ impl std::str::FromStr for CliCiPlatform {
4037
}
4138

4239
pub fn run<F: FnOnce() -> rla::Result<()>>(f: F) {
43-
let mut log_builder = env_logger::Builder::new();
44-
45-
if let Ok(s) = env::var("RLA_LOG") {
46-
log_builder.parse(&s);
47-
} else {
48-
log_builder.filter(None, log::LevelFilter::Info);
49-
}
50-
51-
if let Ok(s) = env::var("RLA_LOG_STYLE") {
52-
log_builder.parse_write_style(&s);
53-
}
54-
55-
log_builder.init();
40+
tracing_subscriber::fmt()
41+
.with_env_filter(tracing_subscriber::EnvFilter::from_env("RLA_LOG"))
42+
.init();
5643

5744
log_and_exit_error(|| f());
5845
}

‎src/lib.rs

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -16,14 +16,14 @@ extern crate hmac;
1616
extern crate hyper;
1717
#[macro_use]
1818
extern crate lazy_static;
19-
#[macro_use]
20-
extern crate log;
2119
extern crate regex;
2220
extern crate reqwest;
2321
extern crate serde;
2422
#[macro_use]
2523
extern crate serde_derive;
2624
extern crate sha1;
25+
#[macro_use]
26+
extern crate tracing;
2727

2828
pub mod ci;
2929
pub mod extract;

0 commit comments

Comments
 (0)