Pick any line to see why it is the way it is: the commit, the pull request and issue it came from, and what the agent was thinking.
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 1 | //! Running one process for a step: its output streamed to the log as it |
| 2 | //! comes, with GitHub's workflow commands (`::error::`, `::group::`, | |
| 3 | //! `::add-mask::`…) read out of it. | |
| 4 | ||
| 5 | use std::collections::BTreeMap; | |
| 6 | use std::io::{BufRead, BufReader, Read}; | |
| 7 | use std::process::{Command, Stdio}; | |
| 8 | use std::sync::mpsc; | |
| 9 | use std::time::{Duration, Instant}; | |
| 10 | ||
| 11 | use serde_json::{Map, Value}; | |
| 12 | ||
| 13 | use super::report::Log; | |
| 14 | ||
| 15 | /// What a step's workflow commands left behind. | |
| 16 | #[derive(Default)] | |
| 17 | pub(crate) struct Commands { | |
| 18 | /// `::set-output` (old, still honoured). | |
| 19 | pub(crate) outputs: BTreeMap<String, String>, | |
| 20 | /// `::save-state`, for the action's post step. | |
| 21 | pub(crate) state: BTreeMap<String, String>, | |
| 22 | /// Set by `::stop-commands::token` until `::token::`. | |
| 23 | pub(crate) stopped: Option<String>, | |
| 24 | /// Whether `::debug::` lines are shown (`ACTIONS_STEP_DEBUG`). | |
| 25 | pub(crate) debug: bool, | |
| Merge branch 'worktree-agent-a41ebf64a05c894fe' into claude/cool-newton-7nm8r9 | 26 | /// `::echo::on` or `::echo::off`: whether command lines are shown as |
| 27 | /// well as acted on. Until a step says, they are with debug logging. | |
| 28 | pub(crate) echo: Option<bool>, | |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 29 | } |
| 30 | ||
| 31 | /// `%25`, `%0D`, `%0A`, and in properties `%3A` and `%2C`, as the | |
| 32 | /// toolkit escapes them. | |
| 33 | fn unescape(text: &str, property: bool) -> String { | |
| 34 | let mut out = text.replace("%0D", "\r").replace("%0A", "\n"); | |
| 35 | if property { | |
| 36 | out = out.replace("%3A", ":").replace("%2C", ","); | |
| 37 | } | |
| 38 | out.replace("%25", "%") | |
| 39 | } | |
| 40 | ||
| 41 | /// `::name key=value,key=value::message`, if the line is a command. | |
| 42 | pub(crate) fn parse_command(line: &str) -> Option<(String, Map<String, Value>, String)> { | |
| 43 | let rest = line.trim_start().strip_prefix("::")?; | |
| 44 | let end = rest.find("::")?; | |
| 45 | let (head, data) = (&rest[..end], &rest[end + 2..]); | |
| 46 | let (name, properties) = match head.split_once(' ') { | |
| 47 | Some((name, properties)) => (name, properties), | |
| 48 | None => (head, ""), | |
| 49 | }; | |
| 50 | if name.is_empty() || !name.chars().all(|c| c.is_ascii_alphanumeric() || c == '-' || c == '_') { | |
| 51 | return None; | |
| 52 | } | |
| 53 | let mut map = Map::new(); | |
| 54 | for pair in properties.split(',').filter(|p| !p.trim().is_empty()) { | |
| 55 | if let Some((key, value)) = pair.split_once('=') { | |
| 56 | map.insert(key.trim().to_owned(), Value::String(unescape(value, true))); | |
| 57 | } | |
| 58 | } | |
| 59 | Some((name.to_owned(), map, unescape(data, false))) | |
| 60 | } | |
| 61 | ||
| 62 | impl Commands { | |
| 63 | /// Handles one line of output: a command is acted on, and the line to | |
| 64 | /// show (if any) is returned. | |
| 65 | pub(crate) fn handle(&mut self, line: &str, log: &mut Log) -> Option<String> { | |
| 66 | if let Some(token) = &self.stopped { | |
| 67 | if line.trim() == format!("::{token}::") { | |
| 68 | self.stopped = None; | |
| 69 | return None; | |
| 70 | } | |
| Merge branch 'worktree-agent-a41ebf64a05c894fe' into claude/cool-newton-7nm8r9 | 71 | return Some(output(line, log)); |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 72 | } |
| 73 | let Some((name, properties, data)) = parse_command(line) else { | |
| Merge branch 'worktree-agent-a41ebf64a05c894fe' into claude/cool-newton-7nm8r9 | 74 | return Some(output(line, log)); |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 75 | }; |
| Merge branch 'worktree-agent-a41ebf64a05c894fe' into claude/cool-newton-7nm8r9 | 76 | // Echoed as it reads, before it is acted on; `::add-mask::` never is. |
| 77 | let known = matches!( | |
| 78 | name.as_str(), | |
| 79 | "add-mask" | "error" | "warning" | "notice" | "group" | "endgroup" | "debug" | "set-output" | "save-state" | "stop-commands" | "echo" | "add-matcher" | "remove-matcher" | "add-path" | "set-env" | |
| 80 | ); | |
| 81 | if known && name != "add-mask" && self.echo.unwrap_or(self.debug) { | |
| 82 | log.line(line); | |
| 83 | } | |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 84 | match name.as_str() { |
| 85 | "add-mask" => { | |
| 86 | if !data.trim().is_empty() { | |
| Merge branch 'worktree-agent-a3abfcce648e87dca' | 87 | log.add_mask(data.trim()); |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 88 | } |
| 89 | None | |
| 90 | } | |
| 91 | "error" | "warning" | "notice" => { | |
| 92 | log.annotation(&name, &data, &properties); | |
| Merge branch 'worktree-agent-a41ebf64a05c894fe' into claude/cool-newton-7nm8r9 | 93 | Some(issue_line(&name, &data)) |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 94 | } |
| 95 | "group" => Some(format!("##[group]{data}")), | |
| 96 | "endgroup" => Some("##[endgroup]".to_owned()), | |
| 97 | "debug" => self.debug.then(|| format!("##[debug]{data}")), | |
| 98 | "set-output" => { | |
| 99 | if let Some(name) = properties.get("name").and_then(Value::as_str) { | |
| 100 | self.outputs.insert(name.to_owned(), data); | |
| 101 | } | |
| 102 | None | |
| 103 | } | |
| 104 | "save-state" => { | |
| 105 | if let Some(name) = properties.get("name").and_then(Value::as_str) { | |
| 106 | self.state.insert(name.to_owned(), data); | |
| 107 | } | |
| 108 | None | |
| 109 | } | |
| 110 | "stop-commands" => { | |
| 111 | self.stopped = Some(data); | |
| 112 | None | |
| 113 | } | |
| Merge branch 'worktree-agent-a41ebf64a05c894fe' into claude/cool-newton-7nm8r9 | 114 | "echo" => { |
| 115 | match data.trim().to_ascii_lowercase().as_str() { | |
| 116 | "on" => self.echo = Some(true), | |
| 117 | "off" => self.echo = Some(false), | |
| 118 | _ => return Some(format!("##[error]Invalid echo command value. Possible values can be: 'on', 'off'. Current value is: '{}'.", data.trim())), | |
| 119 | } | |
| 120 | None | |
| 121 | } | |
| 122 | "add-matcher" => { | |
| 123 | let path = matcher_path(data.trim(), &log.matchers.workspace); | |
| 124 | let read = std::fs::read_to_string(&path).map_err(|e| format!("{}: {e}", path.display())).and_then(|text| super::matchers::parse(&text)); | |
| 125 | match read { | |
| 126 | Ok(matchers) => { | |
| 127 | log.matchers.add(matchers); | |
| 128 | None | |
| 129 | } | |
| 130 | Err(problem) => Some(format!("##[error]Unable to process command '{line}' successfully.\n##[error]{problem}")), | |
| 131 | } | |
| 132 | } | |
| 133 | "remove-matcher" => { | |
| 134 | match properties.get("owner").and_then(Value::as_str).filter(|o| !o.trim().is_empty()) { | |
| 135 | Some(owner) => log.matchers.remove(owner.trim()), | |
| 136 | // No owner: every matcher in the file named. | |
| 137 | None => { | |
| 138 | let path = matcher_path(data.trim(), &log.matchers.workspace); | |
| 139 | match std::fs::read_to_string(&path).map_err(|e| format!("{}: {e}", path.display())).and_then(|text| super::matchers::parse(&text)) { | |
| 140 | Ok(matchers) => matchers.iter().for_each(|m| log.matchers.remove(&m.owner)), | |
| 141 | Err(problem) => return Some(format!("##[error]Unable to process command '{line}' successfully.\n##[error]{problem}")), | |
| 142 | } | |
| 143 | } | |
| 144 | } | |
| 145 | None | |
| 146 | } | |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 147 | "add-path" | "set-env" => Some(format!( |
| 148 | "##[error]The `{name}` command is disabled, as on GitHub. Write to the file in $GITHUB_{} instead.", | |
| 149 | if name == "add-path" { "PATH" } else { "ENV" } | |
| 150 | )), | |
| Merge branch 'worktree-agent-a41ebf64a05c894fe' into claude/cool-newton-7nm8r9 | 151 | _ => Some(output(line, log)), |
| 152 | } | |
| 153 | } | |
| 154 | } | |
| 155 | ||
| 156 | /// How an annotation shows in the log. | |
| 157 | fn issue_line(level: &str, message: &str) -> String { | |
| 158 | let label = match level { | |
| 159 | "error" => "Error", | |
| 160 | "warning" => "Warning", | |
| 161 | _ => "Notice", | |
| 162 | }; | |
| 163 | format!("##[{level}]{label}: {message}") | |
| 164 | } | |
| 165 | ||
| 166 | /// A line of output, as the log shows it: as it is, or, when a problem | |
| 167 | /// matcher reads an issue in it, the issue, annotated. | |
| 168 | fn output(line: &str, log: &mut Log) -> String { | |
| 169 | match log.matchers.issue(line) { | |
| 170 | Some(issue) => { | |
| 171 | log.annotation(issue.level, &issue.message, &issue.properties); | |
| 172 | issue_line(issue.level, &issue.message) | |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 173 | } |
| Merge branch 'worktree-agent-a41ebf64a05c894fe' into claude/cool-newton-7nm8r9 | 174 | None => line.to_owned(), |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 175 | } |
| 176 | } | |
| 177 | ||
| Merge branch 'worktree-agent-a41ebf64a05c894fe' into claude/cool-newton-7nm8r9 | 178 | /// A matcher file's path: relative to the workspace, and a Docker action's |
| 179 | /// `/github/workspace` read as the workspace it is. | |
| 180 | fn matcher_path(given: &str, workspace: &std::path::Path) -> std::path::PathBuf { | |
| 181 | if let Some(rest) = given.strip_prefix("/github/workspace") { | |
| 182 | return workspace.join(rest.trim_start_matches('/')); | |
| 183 | } | |
| 184 | let path = std::path::Path::new(given); | |
| 185 | if path.is_absolute() { path.to_path_buf() } else { workspace.join(path) } | |
| 186 | } | |
| 187 | ||
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 188 | /// How a process ended. |
| 189 | pub(crate) enum Ended { | |
| 190 | Exited(i32), | |
| 191 | TimedOut, | |
| Merge Actions runs: summaries, attempts and re-runs, graceful cancel, log downloads, badges (actions 0009) | 192 | /// The run was cancelled: it was interrupted, then stopped. |
| 193 | Cancelled, | |
| 194 | } | |
| 195 | ||
| 196 | /// After a cancellation, how long a step has after SIGINT before SIGTERM, | |
| 197 | /// and after SIGTERM before it is killed, as GitHub's runner waits. | |
| 198 | const INTERRUPT_GRACE: Duration = Duration::from_millis(7500); | |
| 199 | const TERMINATE_GRACE: Duration = Duration::from_millis(2500); | |
| 200 | ||
| 201 | /// Sends `signal` to the process's group (it leads its own), so what the | |
| 202 | /// step started hears it too. Windows has no signals: it is left to `kill`. | |
| Merge remote-tracking branch 'origin/main' into workspace-chat | 203 | /// Sent with kill(2) itself: a machine without the `kill` program (procps |
| 204 | /// is not in every image) would otherwise give the step no SIGINT at all, | |
| 205 | /// and leave what it started running after the step was killed. | |
| 206 | #[cfg(unix)] | |
| Merge Actions runs: summaries, attempts and re-runs, graceful cancel, log downloads, badges (actions 0009) | 207 | fn signal(child: &std::process::Child, signal: &str) { |
| Merge remote-tracking branch 'origin/main' into workspace-chat | 208 | let number = match signal { |
| 209 | "INT" => libc::SIGINT, | |
| 210 | "TERM" => libc::SIGTERM, | |
| 211 | _ => libc::SIGKILL, | |
| 212 | }; | |
| 213 | let Ok(group) = libc::pid_t::try_from(child.id()) else { | |
| 214 | return; | |
| 215 | }; | |
| 216 | // SAFETY: kill(2) with a negative pid signals that process group; it | |
| 217 | // reads no memory of ours. | |
| 218 | unsafe { | |
| 219 | libc::kill(-group, number); | |
| Merge Actions runs: summaries, attempts and re-runs, graceful cancel, log downloads, badges (actions 0009) | 220 | } |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 221 | } |
| 222 | ||
| Merge remote-tracking branch 'origin/main' into workspace-chat | 223 | #[cfg(not(unix))] |
| 224 | fn signal(_child: &std::process::Child, _signal: &str) {} | |
| 225 | ||
| A running job's log is live, as on GitHub. A step's output reaches its run's page within about two seconds: the runner sends what is printed every second, and the page asks every second while a step runs, every three while none does; an answer that fails (a 429, a 5xx, the network) is asked again after a wait that doubles to half a minute, or as long as Retry-After says, where before one such answer stopped the log for good and the step said "No output yet." until the page was reloaded, and a signed-out viewer's run page, refreshing beside its log, ran into the 30-a-minute limit within a minute; the live log now counts as a page, and only log downloads as costly. A hidden tab stops asking and catches up when shown, and the page says when it is reconnecting. The running step opens by itself, its timer counts, its log follows the newest line while its end is on screen and offers Jump to latest once the viewer scrolls up, a step that has printed nothing for a while says "Running · no output for 2m 10s", and the job's header names the step it is on. Colour that tools print (bold, dim, italic, underline, the 16 colours as theme tokens for light and dark, 256 colours and 24-bit colour, text and background) is drawn as printed, other escape codes are dropped and links keep their text, and search reads the plain text and keeps the colours around what it marks. Every line is stamped with the time it was printed, as GitHub's raw logs are, so log.txt and the run's zip have a time at the start of each line, and a clock button beside Search logs shows the times, remembered by the browser. Set up job now gives the runner's version and name, the operating system, the runner image, the machine's architecture, CPUs and memory, the token's permissions under G1T_TOKEN Permissions, the secret source and the actions it downloads; each run step opens with GitHub's folded Run group, the script in cyan, the shell's whole path and the step's env, each uses step with its with inputs (an action's defaults among them) and env; cache and artifact transfers say how far they have got every five seconds; and a last Complete job step sets the job's outputs and stops what the steps left running, found by RUNNER_TRACKING_ID as GitHub's runner finds it. Two batches of a job's log written at once can no longer reach for the same seq and lose one. The Actions guide and the rate limits page say so. | 226 | /// What the job's steps started and left running, as GitHub's "Complete |
| 227 | /// job" finds it: every process whose environment carries the job's | |
| 228 | /// `RUNNER_TRACKING_ID`, which each step's processes inherit, by pid and | |
| 229 | /// name. Read from /proc, so only on Linux; elsewhere nothing is found. | |
| 230 | pub(crate) fn orphans(tracking_id: &str) -> Vec<(u32, String)> { | |
| 231 | let Ok(entries) = std::fs::read_dir("/proc") else { | |
| 232 | return Vec::new(); | |
| 233 | }; | |
| 234 | let marker = format!("RUNNER_TRACKING_ID={tracking_id}"); | |
| 235 | let own = std::process::id(); | |
| 236 | let mut found = Vec::new(); | |
| 237 | for entry in entries.flatten() { | |
| 238 | let Some(pid) = entry.file_name().to_str().and_then(|name| name.parse::<u32>().ok()) else { | |
| 239 | continue; | |
| 240 | }; | |
| 241 | if pid == own { | |
| 242 | continue; | |
| 243 | } | |
| 244 | // Another user's process cannot be read, and is not the job's. | |
| 245 | let Ok(environ) = std::fs::read(entry.path().join("environ")) else { | |
| 246 | continue; | |
| 247 | }; | |
| 248 | if !environ.split(|byte| *byte == 0).any(|pair| pair == marker.as_bytes()) { | |
| 249 | continue; | |
| 250 | } | |
| 251 | let stat = std::fs::read_to_string(entry.path().join("stat")).unwrap_or_default(); | |
| 252 | if let Some(name) = live_name(&stat) { | |
| 253 | found.push((pid, name)); | |
| 254 | } | |
| 255 | } | |
| 256 | found.sort(); | |
| 257 | found | |
| 258 | } | |
| 259 | ||
| 260 | /// A running process's name from `/proc/<pid>/stat` (`pid (name) state …`), | |
| 261 | /// whose name may hold spaces and parentheses; None for a zombie, which | |
| 262 | /// has already ended. | |
| 263 | fn live_name(stat: &str) -> Option<String> { | |
| 264 | let open = stat.find('(')?; | |
| 265 | let close = stat.rfind(')')?; | |
| 266 | let state = stat.get(close + 1..)?.split_whitespace().next()?; | |
| 267 | (state != "Z").then(|| stat.get(open + 1..close).map(str::to_owned)).flatten() | |
| 268 | } | |
| 269 | ||
| 270 | /// Kills the processes `orphans` found. | |
| 271 | pub(crate) fn kill_orphans(found: &[(u32, String)]) { | |
| 272 | #[cfg(unix)] | |
| 273 | for (pid, _) in found { | |
| 274 | if let Ok(pid) = libc::pid_t::try_from(*pid) { | |
| 275 | // SAFETY: kill(2) on one pid; it reads no memory of ours. | |
| 276 | unsafe { | |
| 277 | libc::kill(pid, libc::SIGKILL); | |
| 278 | } | |
| 279 | } | |
| 280 | } | |
| 281 | #[cfg(not(unix))] | |
| 282 | let _ = found; | |
| 283 | } | |
| 284 | ||
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 285 | /// Runs the command, sending its output (stdout and stderr together, a |
| 286 | /// line at a time) through `commands` to the log, until it ends or | |
| 287 | /// `timeout` passes. | |
| Merge Actions runs: summaries, attempts and re-runs, graceful cancel, log downloads, badges (actions 0009) | 288 | pub(crate) fn run(command: Command, timeout: Duration, log: &mut Log, commands: &mut Commands) -> std::io::Result<Ended> { |
| 289 | run_until(command, timeout, log, commands, &super::report::interrupt) | |
| 290 | } | |
| 291 | ||
| 292 | /// `run`, stopping the process gracefully once `interrupt` says so. | |
| 293 | fn run_until( | |
| 294 | mut command: Command, | |
| 295 | timeout: Duration, | |
| 296 | log: &mut Log, | |
| 297 | commands: &mut Commands, | |
| 298 | interrupt: &dyn Fn() -> bool, | |
| 299 | ) -> std::io::Result<Ended> { | |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 300 | command.stdin(Stdio::null()).stdout(Stdio::piped()).stderr(Stdio::piped()); |
| Merge Actions runs: summaries, attempts and re-runs, graceful cancel, log downloads, badges (actions 0009) | 301 | // A group of its own, so a cancellation reaches what the step started. |
| 302 | #[cfg(unix)] | |
| Merge remote-tracking branch 'origin/main' into workspace-chat | 303 | { |
| 304 | use std::os::unix::process::CommandExt; | |
| 305 | command.process_group(0); | |
| 306 | // A shell cannot trap a signal it was started with ignored, and a | |
| 307 | // runner started in the background (as a service, or under `&`) | |
| 308 | // passes SIGINT on ignored. Back to the defaults, so a cancelled | |
| 309 | // step hears SIGINT and its own trap runs. | |
| 310 | // SAFETY: only signal(), which is async-signal-safe, between fork and exec. | |
| 311 | unsafe { | |
| 312 | command.pre_exec(|| { | |
| 313 | for signal in [libc::SIGINT, libc::SIGTERM, libc::SIGQUIT] { | |
| 314 | libc::signal(signal, libc::SIG_DFL); | |
| 315 | } | |
| 316 | Ok(()) | |
| 317 | }); | |
| 318 | } | |
| 319 | } | |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 320 | let mut child = command.spawn()?; |
| 321 | let (sender, lines) = mpsc::channel::<String>(); | |
| 322 | let mut readers = Vec::new(); | |
| 323 | let pipes: Vec<Box<dyn Read + Send>> = vec![ | |
| 324 | Box::new(child.stdout.take().expect("piped")), | |
| 325 | Box::new(child.stderr.take().expect("piped")), | |
| 326 | ]; | |
| 327 | for pipe in pipes { | |
| 328 | let sender = sender.clone(); | |
| 329 | readers.push(std::thread::spawn(move || { | |
| 330 | let mut reader = BufReader::new(pipe); | |
| 331 | let mut buffer = Vec::new(); | |
| 332 | loop { | |
| 333 | buffer.clear(); | |
| 334 | match reader.read_until(b'\n', &mut buffer) { | |
| 335 | Ok(0) | Err(_) => break, | |
| 336 | Ok(_) => { | |
| 337 | let text = String::from_utf8_lossy(&buffer); | |
| 338 | let text = text.trim_end_matches(['\n', '\r']); | |
| 339 | // A progress bar redraws with \r; keep its last state. | |
| 340 | let text = text.rsplit('\r').next().unwrap_or(text); | |
| 341 | if sender.send(text.to_owned()).is_err() { | |
| 342 | break; | |
| 343 | } | |
| 344 | } | |
| 345 | } | |
| 346 | } | |
| 347 | })); | |
| 348 | } | |
| 349 | drop(sender); | |
| 350 | let deadline = Instant::now() + timeout; | |
| 351 | let mut timed_out = false; | |
| Merge Actions runs: summaries, attempts and re-runs, graceful cancel, log downloads, badges (actions 0009) | 352 | // When the cancellation reached it, and which signal it has had. |
| 353 | let mut interrupted: Option<(Instant, u8)> = None; | |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 354 | loop { |
| 355 | match lines.recv_timeout(Duration::from_millis(250)) { | |
| 356 | Ok(line) => { | |
| 357 | if let Some(shown) = commands.handle(&line, log) { | |
| 358 | log.line(&shown); | |
| 359 | } | |
| 360 | } | |
| Merge branch 'main' into actions-toolkit-oidc-artifacts | 361 | Err(mpsc::RecvTimeoutError::Timeout) => { |
| 362 | // The job's Docker Engine starting, from its own thread. | |
| 363 | for note in crate::docker::take_notes() { | |
| 364 | log.line(¬e); | |
| 365 | } | |
| 366 | log.tick(); | |
| 367 | } | |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 368 | Err(mpsc::RecvTimeoutError::Disconnected) => break, |
| 369 | } | |
| 370 | if Instant::now() >= deadline { | |
| 371 | timed_out = true; | |
| Merge Actions runs: summaries, attempts and re-runs, graceful cancel, log downloads, badges (actions 0009) | 372 | signal(&child, "KILL"); |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 373 | let _ = child.kill(); |
| 374 | break; | |
| 375 | } | |
| Merge Actions runs: summaries, attempts and re-runs, graceful cancel, log downloads, badges (actions 0009) | 376 | // Cancelled: SIGINT, then SIGTERM, then killed, as on GitHub. |
| 377 | match interrupted { | |
| 378 | None if interrupt() => { | |
| 379 | log.line("##[error]The operation was canceled."); | |
| 380 | signal(&child, "INT"); | |
| 381 | interrupted = Some((Instant::now(), 1)); | |
| 382 | } | |
| 383 | Some((at, 1)) if at.elapsed() >= INTERRUPT_GRACE => { | |
| 384 | signal(&child, "TERM"); | |
| 385 | interrupted = Some((Instant::now(), 2)); | |
| 386 | } | |
| 387 | Some((at, 2)) if at.elapsed() >= TERMINATE_GRACE => { | |
| 388 | signal(&child, "KILL"); | |
| 389 | let _ = child.kill(); | |
| 390 | break; | |
| 391 | } | |
| 392 | _ => {} | |
| 393 | } | |
| 394 | if interrupted.is_some() && matches!(child.try_wait(), Ok(Some(_))) { | |
| 395 | // The step is gone; what it started may still hold its output. | |
| 396 | signal(&child, "KILL"); | |
| 397 | break; | |
| 398 | } | |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 399 | } |
| 400 | let status = child.wait()?; | |
| 401 | for reader in readers { | |
| 402 | let _ = reader.join(); | |
| 403 | } | |
| 404 | // Whatever arrived after the readers finished. | |
| 405 | while let Ok(line) = lines.try_recv() { | |
| 406 | if let Some(shown) = commands.handle(&line, log) { | |
| 407 | log.line(&shown); | |
| 408 | } | |
| 409 | } | |
| 410 | if timed_out { | |
| 411 | return Ok(Ended::TimedOut); | |
| 412 | } | |
| Merge Actions runs: summaries, attempts and re-runs, graceful cancel, log downloads, badges (actions 0009) | 413 | if interrupted.is_some() { |
| 414 | return Ok(Ended::Cancelled); | |
| 415 | } | |
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 416 | Ok(Ended::Exited(status.code().unwrap_or(1))) |
| 417 | } | |
| 418 | ||
| 419 | #[cfg(test)] | |
| 420 | mod tests { | |
| 421 | use super::parse_command; | |
| 422 | ||
| A running job's log is live, as on GitHub. A step's output reaches its run's page within about two seconds: the runner sends what is printed every second, and the page asks every second while a step runs, every three while none does; an answer that fails (a 429, a 5xx, the network) is asked again after a wait that doubles to half a minute, or as long as Retry-After says, where before one such answer stopped the log for good and the step said "No output yet." until the page was reloaded, and a signed-out viewer's run page, refreshing beside its log, ran into the 30-a-minute limit within a minute; the live log now counts as a page, and only log downloads as costly. A hidden tab stops asking and catches up when shown, and the page says when it is reconnecting. The running step opens by itself, its timer counts, its log follows the newest line while its end is on screen and offers Jump to latest once the viewer scrolls up, a step that has printed nothing for a while says "Running · no output for 2m 10s", and the job's header names the step it is on. Colour that tools print (bold, dim, italic, underline, the 16 colours as theme tokens for light and dark, 256 colours and 24-bit colour, text and background) is drawn as printed, other escape codes are dropped and links keep their text, and search reads the plain text and keeps the colours around what it marks. Every line is stamped with the time it was printed, as GitHub's raw logs are, so log.txt and the run's zip have a time at the start of each line, and a clock button beside Search logs shows the times, remembered by the browser. Set up job now gives the runner's version and name, the operating system, the runner image, the machine's architecture, CPUs and memory, the token's permissions under G1T_TOKEN Permissions, the secret source and the actions it downloads; each run step opens with GitHub's folded Run group, the script in cyan, the shell's whole path and the step's env, each uses step with its with inputs (an action's defaults among them) and env; cache and artifact transfers say how far they have got every five seconds; and a last Complete job step sets the job's outputs and stops what the steps left running, found by RUNNER_TRACKING_ID as GitHub's runner finds it. Two batches of a job's log written at once can no longer reach for the same seq and lose one. The Actions guide and the rate limits page say so. | 423 | /// What a step left running is found by the job's tracking id, and |
| 424 | /// only that. | |
| 425 | #[cfg(target_os = "linux")] | |
| 426 | #[test] | |
| 427 | fn orphans_are_found_by_the_jobs_tracking_id() { | |
| 428 | use super::{kill_orphans, live_name, orphans}; | |
| 429 | let id = format!("github_test{}", std::process::id()); | |
| 430 | let mut left = std::process::Command::new("sleep").arg("30").env("RUNNER_TRACKING_ID", &id).spawn().unwrap(); | |
| 431 | let mut other = std::process::Command::new("sleep").arg("30").env("RUNNER_TRACKING_ID", "github_someone_else").spawn().unwrap(); | |
| 432 | // /proc shows the new environment once exec has happened. | |
| 433 | let mut found = Vec::new(); | |
| 434 | for _ in 0..50 { | |
| 435 | found = orphans(&id); | |
| 436 | if !found.is_empty() { | |
| 437 | break; | |
| 438 | } | |
| 439 | std::thread::sleep(std::time::Duration::from_millis(20)); | |
| 440 | } | |
| 441 | assert_eq!(found, [(left.id(), "sleep".to_owned())]); | |
| 442 | kill_orphans(&found); | |
| 443 | assert!(!left.wait().unwrap().success(), "killed"); | |
| 444 | let _ = other.kill(); | |
| 445 | let _ = other.wait(); | |
| 446 | assert_eq!(live_name("12 (tmux: server) S 1 12 12"), Some("tmux: server".into())); | |
| 447 | assert_eq!(live_name("13 (gone) Z 1 13 13"), None); | |
| 448 | } | |
| 449 | ||
| Merge Actions runs: summaries, attempts and re-runs, graceful cancel, log downloads, badges (actions 0009) | 450 | /// A cancelled step hears SIGINT, and its own trap runs. |
| 451 | #[cfg(unix)] | |
| 452 | #[test] | |
| 453 | fn a_cancelled_step_is_interrupted_and_may_clean_up() { | |
| 454 | use super::{Commands, Ended, run_until}; | |
| 455 | use crate::actions::report::{Api, Log}; | |
| 456 | use std::process::Command; | |
| 457 | use std::time::{Duration, Instant}; | |
| 458 | ||
| The phone app with your own g1t, on g1t.sh/download until Google Play, and Node 24 (#5) | 459 | // Offline: on a busy machine the step can outlast a batch of the log, |
| 460 | // and sending it to an address that is not there held the loop for | |
| 461 | // seconds, past the grace this test measures. | |
| 462 | let mut log = Log::new(Api::offline(), Vec::new()); | |
| Merge Actions runs: summaries, attempts and re-runs, graceful cancel, log downloads, badges (actions 0009) | 463 | let mut command = Command::new("sh"); |
| 464 | command.args(["-c", "trap 'echo cleaned up; exit 3' INT; echo started; while true; do sleep 0.1; done"]); | |
| 465 | let began = Instant::now(); | |
| 466 | let ask = move || began.elapsed() >= Duration::from_millis(600); | |
| 467 | let ended = run_until(command, Duration::from_secs(60), &mut log, &mut Commands::default(), &ask).unwrap(); | |
| 468 | assert!(matches!(ended, Ended::Cancelled)); | |
| 469 | assert!(began.elapsed() < Duration::from_secs(8), "SIGINT ended it, not the kill after the grace period"); | |
| 470 | let text = log.buffered(); | |
| 471 | assert!(text.contains("The operation was canceled."), "{text}"); | |
| 472 | assert!(text.contains("cleaned up"), "{text}"); | |
| 473 | } | |
| 474 | ||
| Merge branch 'worktree-agent-a41ebf64a05c894fe' into claude/cool-newton-7nm8r9 | 475 | /// `::echo::on` shows command lines until `::echo::off`, which is |
| 476 | /// itself shown; `::add-mask::` never is. | |
| 477 | #[cfg(unix)] | |
| 478 | #[test] | |
| 479 | fn echo_shows_command_lines_while_on() { | |
| 480 | use super::Commands; | |
| 481 | use crate::actions::report::{Api, Log}; | |
| 482 | ||
| 483 | let mut log = Log::new(Api::offline(), Vec::new()); | |
| 484 | let mut commands = Commands::default(); | |
| 485 | for line in ["::set-output name=a::1", "::echo::on", "::save-state name=b::2", "::add-mask::s3cret", "::echo::off", "::save-state name=c::3"] { | |
| 486 | if let Some(shown) = commands.handle(line, &mut log) { | |
| 487 | log.line(&shown); | |
| 488 | } | |
| 489 | } | |
| 490 | let text = log.buffered(); | |
| 491 | assert_eq!(text, "::save-state name=b::2\n::echo::off\n"); | |
| 492 | assert_eq!((commands.outputs.len(), commands.state.len()), (1, 2)); | |
| 493 | // Debug logging echoes until a step says otherwise. | |
| 494 | let mut log = Log::new(Api::offline(), Vec::new()); | |
| 495 | let mut commands = Commands { debug: true, ..Commands::default() }; | |
| 496 | commands.handle("::set-output name=a::1", &mut log); | |
| 497 | assert!(log.buffered().contains("::set-output name=a::1")); | |
| 498 | assert!(commands.handle("::echo::maybe", &mut log).unwrap().contains("Invalid echo command value")); | |
| 499 | } | |
| 500 | ||
| 501 | /// A matcher added by one line reads the lines after it, until removed. | |
| 502 | #[cfg(unix)] | |
| 503 | #[test] | |
| 504 | fn matchers_are_added_and_removed_by_command() { | |
| 505 | use super::Commands; | |
| 506 | use crate::actions::report::{Api, Log}; | |
| 507 | ||
| 508 | let dir = std::env::temp_dir().join(format!("g1t-add-matcher-{}", std::process::id())); | |
| 509 | std::fs::create_dir_all(&dir).unwrap(); | |
| 510 | std::fs::write( | |
| 511 | dir.join("go.json"), | |
| 512 | r#"{"problemMatcher": [{"owner": "go", "pattern": [{"regexp": "^\\s*(.+\\.go):(?:(\\d+):(\\d+):)? (.*)", "file": 1, "line": 2, "column": 3, "message": 4}]}]}"#, | |
| 513 | ) | |
| 514 | .unwrap(); | |
| 515 | let mut log = Log::new(Api::offline(), Vec::new()); | |
| 516 | log.matchers.workspace = dir.clone(); | |
| 517 | let mut commands = Commands::default(); | |
| 518 | assert_eq!(commands.handle("main.go:3:1: undefined: x", &mut log).unwrap(), "main.go:3:1: undefined: x"); | |
| 519 | assert!(commands.handle("::add-matcher::go.json", &mut log).is_none()); | |
| 520 | assert_eq!(commands.handle("main.go:3:1: undefined: x", &mut log).unwrap(), "##[error]Error: undefined: x"); | |
| 521 | assert!(commands.handle("::remove-matcher owner=go::", &mut log).is_none()); | |
| 522 | assert_eq!(commands.handle("main.go:3:1: undefined: x", &mut log).unwrap(), "main.go:3:1: undefined: x"); | |
| 523 | assert!(commands.handle("::add-matcher::missing.json", &mut log).unwrap().contains("Unable to process command")); | |
| 524 | let _ = std::fs::remove_dir_all(&dir); | |
| 525 | } | |
| 526 | ||
| Team plan, an open-source pool, monthly trials and honest metering; the sidebar for everyone; a workspace that stays put | 527 | #[test] |
| 528 | fn commands_are_read_with_their_properties() { | |
| 529 | let (name, properties, data) = parse_command("::error file=app.js,line=10,title=Bad%3A thing::Something%0Abroke").unwrap(); | |
| 530 | assert_eq!(name, "error"); | |
| 531 | assert_eq!(properties["file"], "app.js"); | |
| 532 | assert_eq!(properties["line"], "10"); | |
| 533 | assert_eq!(properties["title"], "Bad: thing"); | |
| 534 | assert_eq!(data, "Something\nbroke"); | |
| 535 | let (name, properties, data) = parse_command("::group::Install").unwrap(); | |
| 536 | assert_eq!((name.as_str(), properties.len(), data.as_str()), ("group", 0, "Install")); | |
| 537 | assert_eq!(parse_command("::set-output name=version::1.2.3").unwrap().1["name"], "version"); | |
| 538 | assert!(parse_command("plain text").is_none()); | |
| 539 | assert!(parse_command(":: not a command").is_none()); | |
| 540 | } | |
| 541 | } |
This file's history is long; its oldest lines are credited to the oldest commit read.