Merge pull request #302 from flagon-io/289-flaky-gitedge-log
The git edge's tests wait for the log lines they expect
1 file+19−70/1 viewed
| 110 | 110 | self.log.lock().unwrap().clone() | |
| 111 | 111 | } | |
| 112 | 112 | ||
| 113 | + | /// Waits for the log to hold every one of `lines`, and returns it: the | |
| 114 | + | /// server writes a line before it answers, but the thread reading its | |
| 115 | + | /// stderr may not have kept it yet when the answer arrives (#289). | |
| 116 | + | fn logged(&self, lines: &[&str]) -> String { | |
| 117 | + | let started = Instant::now(); | |
| 118 | + | loop { | |
| 119 | + | let log = self.log(); | |
| 120 | + | if lines.iter().all(|line| log.contains(line)) { | |
| 121 | + | return log; | |
| 122 | + | } | |
| 123 | + | assert!(started.elapsed() < Duration::from_secs(10), "the log never had {lines:?}:\n{log}"); | |
| 124 | + | std::thread::sleep(Duration::from_millis(20)); | |
| 125 | + | } | |
| 126 | + | } | |
| 127 | + | ||
| 113 | 128 | fn sync(&self, remote: &str, version: u64) { | |
| 114 | 129 | let body = json!({ "remote": remote, "token": TOKEN, "version": version, "head": "refs/heads/main" }); | |
| 115 | 130 | let response = ureq::post(&self.url("/sync")).send_json(body).unwrap(); | |
| ⋯ | |||
| 246 | 261 | git(&work, &["push", "--quiet", "origin", ":refs/tags/light"]); | |
| 247 | 262 | edge.sync(&remote, 2); | |
| 248 | 263 | assert_eq!(edge.settled(), json!(2)); | |
| 249 | − | assert!(edge.log().contains("synced to version 2"), "{}", edge.log()); | |
| 264 | + | edge.logged(&["synced to version 2"]); | |
| 250 | 265 | // The old version is behind now: git is refused. | |
| 251 | 266 | assert!(!edge_git(&clones[0], 1, &["fetch", "--quiet", "origin"]).status.success()); | |
| 252 | 267 | let trace = root.join("trace.txt"); | |
| ⋯ | |||
| 261 | 276 | // A failed sync leaves the version, and the mirror still serves it. | |
| 262 | 277 | edge.sync(&file_url(&root.join("missing.git")), 3); | |
| 263 | 278 | assert_eq!(edge.settled(), json!(2)); | |
| 264 | − | assert!(edge.log().contains("the sync to version 3 failed"), "{}", edge.log()); | |
| 279 | + | edge.logged(&["the sync to version 3 failed"]); | |
| 265 | 280 | assert_ok(&edge_git(&root, 2, &["ls-remote", &git_url]), "ls-remote after a failed sync"); | |
| 266 | 281 | ||
| 267 | 282 | // Syncs asked for together: the latest is where the mirror ends up. | |
| ⋯ | |||
| 270 | 285 | assert_eq!(edge.settled(), json!(4)); | |
| 271 | 286 | ||
| 272 | 287 | // Each sync and git request is logged; the token never is. | |
| 273 | − | let log = edge.log(); | |
| 274 | − | assert!(log.contains("GET info/refs 200"), "{log}"); | |
| 275 | − | assert!(log.contains("POST git-upload-pack 200"), "{log}"); | |
| 276 | − | assert!(log.contains("synced to version 1") && log.contains("repacked in full"), "{log}"); | |
| 288 | + | let log = edge.logged(&["GET info/refs 200", "POST git-upload-pack 200", "synced to version 1", "repacked in full", "synced to version 4"]); | |
| 277 | 289 | assert!(!log.contains(TOKEN), "the token was logged:\n{log}"); | |
| 278 | 290 | drop(edge); | |
| 279 | 291 | let _ = std::fs::remove_dir_all(&root); | |
| ⋯ | |||
| 397 | 409 | }; | |
| 398 | 410 | assert_eq!(fetch(&had), (200, None)); | |
| 399 | 411 | assert_eq!(fetch(&new), (409, Some("behind".to_owned()))); | |
| 400 | − | assert!(edge.log().contains(&format!("the mirror has no {new}")), "{}", edge.log()); | |
| 412 | + | edge.logged(&[&format!("the mirror has no {new}")]); | |
| 401 | 413 | // Once it has caught up, it answers. | |
| 402 | 414 | edge.sync(&file_url(&origin), 2); | |
| 403 | 415 | assert_eq!(edge.settled(), json!(2)); | |
Comments
Sign in to comment.