Skip to content

Commit 0faa85b

Browse files
committed
feat(logging): add timestamp markers to job log files
Add clear run separation with timestamps for job start, finish, and error events to make log files easier to read and debug.
1 parent dcc2eb6 commit 0faa85b

File tree

1 file changed

+41
-6
lines changed

1 file changed

+41
-6
lines changed

src/actor/job/executor.rs

Lines changed: 41 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,4 @@
1+
use chrono::{Local, Utc};
12
use rand::Rng;
23
use std::collections::HashMap;
34
use std::fs::{self, File, OpenOptions};
@@ -8,7 +9,7 @@ use tokio::process::Command;
89
use tokio::time::sleep;
910
use tracing::{debug, error, info, warn};
1011

11-
use crate::config::{Job, RetryConfig, RunnerConfig};
12+
use crate::config::{Job, RetryConfig, RunnerConfig, TimezoneConfig};
1213
use crate::env;
1314
use crate::git;
1415
use crate::webhook::{self, BuildFailure, JobFailure};
@@ -318,8 +319,17 @@ pub async fn execute_job(job: &Job, sot_path: &Path, runner: &RunnerConfig) -> b
318319
"Starting job"
319320
);
320321

322+
if let Some(ref mut file) = log_file {
323+
let marker = if attempt > 0 {
324+
format!("Job started (retry {}/{})", attempt, max_attempts - 1)
325+
} else {
326+
"Job started".to_string()
327+
};
328+
write_log_marker(file, &runner.timezone, job.timezone.as_ref(), &marker);
329+
}
330+
321331
let result = run_command(job, &work_dir, sot_path, runner).await;
322-
let success = handle_result(job, &result, log_file.as_mut());
332+
let success = handle_result(job, &result, log_file.as_mut(), &runner.timezone);
323333

324334
if success {
325335
return true;
@@ -614,41 +624,51 @@ enum CommandResult {
614624
Timeout,
615625
}
616626

617-
fn handle_result(job: &Job, result: &CommandResult, log_file: Option<&mut File>) -> bool {
627+
fn handle_result(job: &Job, result: &CommandResult, log_file: Option<&mut File>, runner_tz: &TimezoneConfig) -> bool {
618628
match result {
619629
CommandResult::Completed(output) => {
620630
let stdout = String::from_utf8_lossy(&output.stdout);
621631
let stderr = String::from_utf8_lossy(&output.stderr);
632+
let success = output.status.success();
622633

623634
if let Some(file) = log_file {
624635
let _ = file.write_all(stdout.as_bytes());
625636
let _ = file.write_all(stderr.as_bytes());
637+
let marker = if success {
638+
"Job finished (success)".to_string()
639+
} else {
640+
format!("Job finished (failed, exit code {:?})", output.status.code())
641+
};
642+
write_log_marker(file, runner_tz, job.timezone.as_ref(), &marker);
626643
}
627644

628-
if output.status.success() {
645+
if success {
629646
info!(target: "rollcron::job", job_id = %job.id, "Completed");
630-
true
631647
} else {
632648
error!(
633649
target: "rollcron::job",
634650
job_id = %job.id,
635651
exit_code = ?output.status.code(),
636652
"Failed"
637653
);
638-
false
639654
}
655+
success
640656
}
641657
CommandResult::ExecError(e) => {
642658
error!(target: "rollcron::job", job_id = %job.id, error = %e, "Failed to execute");
643659
if let Some(file) = log_file {
644660
let _ = writeln!(file, "[rollcron] Error: {}", e);
661+
let marker = format!("Job finished (error: {})", e);
662+
write_log_marker(file, runner_tz, job.timezone.as_ref(), &marker);
645663
}
646664
false
647665
}
648666
CommandResult::Timeout => {
649667
error!(target: "rollcron::job", job_id = %job.id, timeout = ?job.timeout, "Timeout");
650668
if let Some(file) = log_file {
651669
let _ = writeln!(file, "[rollcron] Timeout after {:?}", job.timeout);
670+
let marker = format!("Job finished (timeout after {:?})", job.timeout);
671+
write_log_marker(file, runner_tz, job.timezone.as_ref(), &marker);
652672
}
653673
false
654674
}
@@ -714,6 +734,21 @@ fn create_log_file(job_dir: &Path, log_path: &str, max_size: u64) -> Option<File
714734
}
715735
}
716736

737+
fn format_timestamp(runner_tz: &TimezoneConfig, job_tz: Option<&TimezoneConfig>) -> String {
738+
let fmt = "%Y-%m-%d %H:%M:%S %Z";
739+
let tz = job_tz.unwrap_or(runner_tz);
740+
match tz {
741+
TimezoneConfig::Utc => Utc::now().format(fmt).to_string(),
742+
TimezoneConfig::Inherit => Local::now().format(fmt).to_string(),
743+
TimezoneConfig::Named(tz) => Utc::now().with_timezone(tz).format(fmt).to_string(),
744+
}
745+
}
746+
747+
fn write_log_marker(file: &mut File, runner_tz: &TimezoneConfig, job_tz: Option<&TimezoneConfig>, marker: &str) {
748+
let timestamp = format_timestamp(runner_tz, job_tz);
749+
let _ = writeln!(file, "\n[{timestamp}] === {marker} ===");
750+
}
751+
717752
#[cfg(test)]
718753
mod tests {
719754
use super::*;

0 commit comments

Comments
 (0)