|
13 | 13 | except ImportError: |
14 | 14 | SCIPY_AVAILABLE = False |
15 | 15 |
|
| 16 | +CYAN = "\033[96m" |
| 17 | +GREEN = "\033[92m" |
| 18 | +MAGENTA = "\033[95m" |
| 19 | +YELLOW = "\033[93m" |
| 20 | +RED = "\033[91m" |
| 21 | +BOLD = "\033[1m" |
| 22 | +RESET = "\033[0m" |
16 | 23 |
|
17 | 24 | LINE_RE = re.compile( |
18 | 25 | r"\[[^\]]*gpu-reconstruction[^\]]*\]:\s*" |
@@ -82,70 +89,135 @@ def read_timeslice_durations(logfile: Path): |
82 | 89 |
|
83 | 90 | return durations, starts, ends |
84 | 91 |
|
85 | | -def warn_about_processing_downtime(starts, ends, tolerance_s=0.001): |
86 | | - RED = "\033[91m" |
87 | | - YELLOW = "\033[93m" |
88 | | - BOLD = "\033[1m" |
89 | | - RESET = "\033[0m" |
| 92 | +def format_ranges(values): |
| 93 | + values = sorted(values) |
| 94 | + if not values: |
| 95 | + return "[]" |
| 96 | + |
| 97 | + ranges = [] |
| 98 | + start = prev = values[0] |
| 99 | + |
| 100 | + for value in values[1:]: |
| 101 | + if value == prev + 1: |
| 102 | + prev = value |
| 103 | + else: |
| 104 | + if start == prev: |
| 105 | + ranges.append(f"{start}") |
| 106 | + else: |
| 107 | + ranges.append(f"{start}-{prev}") |
| 108 | + start = prev = value |
| 109 | + |
| 110 | + if start == prev: |
| 111 | + ranges.append(f"{start}") |
| 112 | + else: |
| 113 | + ranges.append(f"{start}-{prev}") |
90 | 114 |
|
91 | | - common_timeslices = sorted(set(starts) & set(ends)) |
| 115 | + return "[" + ", ".join(ranges) + "]" |
92 | 116 |
|
93 | | - if len(common_timeslices) <= 4: |
94 | | - return set() |
95 | 117 |
|
96 | | - ignored_timeslices = set(common_timeslices[:2] + common_timeslices[-2:]) |
97 | | - excluded_timeslices = set() |
| 118 | +def analyze_processing_sequences(starts, ends, tolerance_s=0.001, n_drop_edges=2): |
| 119 | + |
| 120 | + complete_timeslices = sorted(set(starts) & set(ends)) |
98 | 121 |
|
99 | | - for ts in common_timeslices: |
100 | | - next_ts = ts + 1 |
| 122 | + if len(complete_timeslices) <= 2 * n_drop_edges: |
| 123 | + return set(), [], np.nan |
| 124 | + |
| 125 | + used_timeslices = complete_timeslices[n_drop_edges:-n_drop_edges] |
| 126 | + used_set = set(used_timeslices) |
| 127 | + |
| 128 | + excluded_timeslices = set() |
| 129 | + large_gap_boundaries = set() |
101 | 130 |
|
102 | | - if next_ts not in starts: |
| 131 | + for ts, next_ts in zip(complete_timeslices[:-1], complete_timeslices[1:]): |
| 132 | + if ts not in used_set or next_ts not in used_set: |
103 | 133 | continue |
104 | 134 |
|
105 | | - # Do not warn if the boundary touches one of the first two or last two |
106 | | - # complete timeslices. |
107 | | - if ts in ignored_timeslices or next_ts in ignored_timeslices: |
| 135 | + if next_ts != ts + 1: |
| 136 | + print( |
| 137 | + f"{RED}{BOLD}WARNING:{RESET} " |
| 138 | + f"{RED}Missing timeslice(s) between {ts} and {next_ts}. " |
| 139 | + f"Splitting processing sequence. " |
| 140 | + f"Excluding timeslices {ts} and {next_ts} from calculation.{RESET}", |
| 141 | + flush=True, |
| 142 | + ) |
| 143 | + excluded_timeslices.update({ts, next_ts}) |
| 144 | + large_gap_boundaries.add((ts, next_ts)) |
108 | 145 | continue |
109 | 146 |
|
110 | 147 | gap = starts[next_ts] - ends[ts] |
111 | 148 |
|
112 | 149 | if gap > tolerance_s: |
113 | | - affected = {ts - 1, ts, next_ts, next_ts + 1} |
114 | | - affected = { |
115 | | - x for x in affected |
116 | | - if x in common_timeslices and x not in ignored_timeslices |
117 | | - } |
118 | | - |
119 | 150 | print( |
120 | 151 | f"{YELLOW}{BOLD}WARNING:{RESET} " |
121 | 152 | f"{YELLOW}Processing downtime detected between " |
122 | 153 | f"timeslice {ts} and {next_ts}: " |
123 | 154 | f"end[{ts}] -> start[{next_ts}] gap = {gap * 1000:.3f} ms. " |
124 | | - f"Excluding timeslices {sorted(affected)} from calculation.{RESET}", |
| 155 | + f"Splitting processing sequence. " |
| 156 | + f"Excluding timeslices {ts} and {next_ts} from calculation.{RESET}", |
125 | 157 | flush=True, |
126 | 158 | ) |
127 | | - |
128 | | - excluded_timeslices.update(affected) |
| 159 | + excluded_timeslices.update({ts, next_ts}) |
| 160 | + large_gap_boundaries.add((ts, next_ts)) |
129 | 161 |
|
130 | 162 | elif gap < -tolerance_s: |
131 | | - affected = {ts - 1, ts, next_ts, next_ts + 1} |
132 | | - affected = { |
133 | | - x for x in affected |
134 | | - if x in common_timeslices and x not in ignored_timeslices |
135 | | - } |
136 | | - |
137 | 163 | print( |
138 | 164 | f"{RED}{BOLD}WARNING:{RESET} " |
139 | 165 | f"{RED}Processing overlap or timestamp ordering issue between " |
140 | 166 | f"timeslice {ts} and {next_ts}: " |
141 | 167 | f"start[{next_ts}] is {-gap * 1000:.3f} ms before end[{ts}]. " |
142 | | - f"Excluding timeslices {sorted(affected)} from calculation.{RESET}", |
| 168 | + f"Splitting processing sequence. " |
| 169 | + f"Excluding timeslices {ts} and {next_ts} from calculation.{RESET}", |
143 | 170 | flush=True, |
144 | 171 | ) |
| 172 | + excluded_timeslices.update({ts, next_ts}) |
| 173 | + large_gap_boundaries.add((ts, next_ts)) |
| 174 | + |
| 175 | + clean_timeslices = [ |
| 176 | + ts for ts in used_timeslices |
| 177 | + if ts not in excluded_timeslices |
| 178 | + ] |
| 179 | + |
| 180 | + sequences = [] |
| 181 | + current_sequence = [] |
| 182 | + |
| 183 | + for ts in clean_timeslices: |
| 184 | + if not current_sequence: |
| 185 | + current_sequence = [ts] |
| 186 | + continue |
| 187 | + |
| 188 | + previous_ts = current_sequence[-1] |
| 189 | + |
| 190 | + if ( |
| 191 | + ts == previous_ts + 1 |
| 192 | + and (previous_ts, ts) not in large_gap_boundaries |
| 193 | + ): |
| 194 | + current_sequence.append(ts) |
| 195 | + else: |
| 196 | + sequences.append(current_sequence) |
| 197 | + current_sequence = [ts] |
| 198 | + |
| 199 | + if current_sequence: |
| 200 | + sequences.append(current_sequence) |
| 201 | + |
| 202 | + total_wall_time = 0.0 |
| 203 | + total_timeslices = 0 |
145 | 204 |
|
146 | | - excluded_timeslices.update(affected) |
| 205 | + for sequence in sequences: |
| 206 | + first_ts = sequence[0] |
| 207 | + last_ts = sequence[-1] |
147 | 208 |
|
148 | | - return excluded_timeslices |
| 209 | + # This includes small allowed gaps inside the sequence. |
| 210 | + sequence_wall_time = ends[last_ts] - starts[first_ts] |
| 211 | + |
| 212 | + total_wall_time += sequence_wall_time |
| 213 | + total_timeslices += len(sequence) |
| 214 | + |
| 215 | + if total_timeslices > 0: |
| 216 | + wall_time_mean = total_wall_time / total_timeslices |
| 217 | + else: |
| 218 | + wall_time_mean = np.nan |
| 219 | + |
| 220 | + return excluded_timeslices, sequences, wall_time_mean |
149 | 221 |
|
150 | 222 | def fit_gaussian_to_histogram(values, bins): |
151 | 223 | counts, edges = np.histogram(values, bins=bins) |
@@ -213,24 +285,39 @@ def main(): |
213 | 285 | default=1.0, |
214 | 286 | help="Allowed gap between end of timeslice n and start of timeslice n+1 in ms", |
215 | 287 | ) |
| 288 | + parser.add_argument( |
| 289 | + "--summary-output", |
| 290 | + type=Path, |
| 291 | + default=Path("gpu_reconstruction_summary.txt"), |
| 292 | + help="Output text file for printed summary", |
| 293 | + ) |
216 | 294 |
|
217 | 295 | args = parser.parse_args() |
218 | 296 |
|
219 | 297 | durations_by_timeslice, starts_by_timeslice, ends_by_timeslice = read_timeslice_durations( |
220 | 298 | args.logfile |
221 | 299 | ) |
222 | 300 |
|
223 | | - excluded_timeslices = warn_about_processing_downtime( |
| 301 | + excluded_timeslices, processing_sequences, wall_time_mean = analyze_processing_sequences( |
224 | 302 | starts_by_timeslice, |
225 | 303 | ends_by_timeslice, |
226 | 304 | tolerance_s=args.gap_tolerance_ms / 1000.0, |
| 305 | + n_drop_edges=2, |
227 | 306 | ) |
| 307 | + |
228 | 308 | if excluded_timeslices: |
229 | 309 | print( |
230 | | - f"Excluded timeslices due to downtime/overlap: " |
231 | | - f"{sorted(excluded_timeslices)}" |
| 310 | + f"{RED}{BOLD}Excluded timeslices due to large gaps/overlaps:{RESET} " |
| 311 | + f"{RED}{sorted(excluded_timeslices)}{RESET}" |
232 | 312 | ) |
233 | 313 |
|
| 314 | + print( |
| 315 | + f"{RED}{BOLD}Continuous processing sequences used for wall-time average:{RESET} " |
| 316 | + f"{RED}" |
| 317 | + + ", ".join(format_ranges(seq) for seq in processing_sequences) |
| 318 | + + f"{RESET}" |
| 319 | + ) |
| 320 | + |
234 | 321 | if len(durations_by_timeslice) < 5: |
235 | 322 | raise RuntimeError( |
236 | 323 | f"Found only {len(durations_by_timeslice)} complete timeslices. " |
@@ -260,7 +347,10 @@ def main(): |
260 | 347 | sample_mean = np.mean(values) |
261 | 348 | sample_sigma = np.std(values, ddof=1) |
262 | 349 |
|
263 | | - avg_from_sum = np.mean(values) |
| 350 | + if args.unit == "ms": |
| 351 | + wall_time_mean_print = wall_time_mean * 1000.0 |
| 352 | + else: |
| 353 | + wall_time_mean_print = wall_time_mean |
264 | 354 |
|
265 | 355 | fit_result, counts, edges = fit_gaussian_to_histogram(values, args.bins) |
266 | 356 |
|
@@ -301,23 +391,73 @@ def main(): |
301 | 391 | plt.tight_layout() |
302 | 392 | plt.savefig(args.output, dpi=150) |
303 | 393 |
|
304 | | - print(f"Input file: {args.logfile}") |
305 | | - print(f"Complete timeslices found: {n_total}") |
306 | | - print(f"Timeslices used after dropping first/last two: {n_used}") |
307 | | - print(f"First used timeslice: {trimmed_timeslices[0]}") |
308 | | - print(f"Last used timeslice: {trimmed_timeslices[-1]}") |
309 | | - print(f"Average duration = sum(durations)/(processed timeslices - 4): {avg_from_sum:.6g} {unit_label}") |
310 | | - print(f"Sample mean: {sample_mean:.6g} {unit_label}") |
311 | | - print(f"Sample sigma: {sample_sigma:.6g} {unit_label}") |
| 394 | + print(f"{BOLD}Input file:{RESET} {args.logfile}") |
| 395 | + print(f"{CYAN}{BOLD}Complete timeslices found:{RESET} {n_total}") |
| 396 | + print(f"{CYAN}{BOLD}Timeslices used after dropping first/last two:{RESET} {n_used}") |
| 397 | + print(f"{CYAN}{BOLD}First used timeslice:{RESET} {trimmed_timeslices[0]}") |
| 398 | + print(f"{CYAN}{BOLD}Last used timeslice:{RESET} {trimmed_timeslices[-1]}") |
| 399 | + |
| 400 | + print( |
| 401 | + f"{GREEN}{BOLD}Wall-time mean including allowed gaps:{RESET} " |
| 402 | + f"{GREEN}{wall_time_mean_print:.6g} {unit_label}{RESET}" |
| 403 | + ) |
| 404 | + |
| 405 | + print( |
| 406 | + f"{MAGENTA}{BOLD}Individual duration sample mean:{RESET} " |
| 407 | + f"{MAGENTA}{sample_mean:.6g} {unit_label}{RESET}" |
| 408 | + ) |
| 409 | + print( |
| 410 | + f"{MAGENTA}{BOLD}Individual duration sample sigma:{RESET} " |
| 411 | + f"{MAGENTA}{sample_sigma:.6g} {unit_label}{RESET}" |
| 412 | + ) |
312 | 413 |
|
313 | 414 | if fit_result is not None: |
314 | 415 | _, fit_mean, fit_sigma = fit_result |
315 | | - print(f"Gaussian fit mean: {fit_mean:.6g} {unit_label}") |
316 | | - print(f"Gaussian fit sigma: {fit_sigma:.6g} {unit_label}") |
| 416 | + print( |
| 417 | + f"{YELLOW}{BOLD}Gaussian fit mean:{RESET} " |
| 418 | + f"{YELLOW}{fit_mean:.6g} {unit_label}{RESET}" |
| 419 | + ) |
| 420 | + print( |
| 421 | + f"{YELLOW}{BOLD}Gaussian fit sigma:{RESET} " |
| 422 | + f"{YELLOW}{fit_sigma:.6g} {unit_label}{RESET}" |
| 423 | + ) |
317 | 424 | else: |
318 | | - print("Gaussian fit failed or scipy is unavailable.") |
| 425 | + print(f"{RED}{BOLD}Gaussian fit failed or scipy is unavailable.{RESET}") |
| 426 | + |
| 427 | + if args.summary_output: |
| 428 | + |
| 429 | + def save_summary_output(output_file: Path, lines): |
| 430 | + output_file.parent.mkdir(parents=True, exist_ok=True) |
| 431 | + |
| 432 | + with output_file.open("w") as f: |
| 433 | + for line in lines: |
| 434 | + f.write(line + "\n") |
| 435 | + |
| 436 | + print(f"Saved summary output to: {output_file}") |
| 437 | + |
| 438 | + summary_lines = [ |
| 439 | + f"Input file: {args.logfile}", |
| 440 | + f"Complete timeslices found: {n_total}", |
| 441 | + f"Timeslices used after dropping first/last two: {n_used}", |
| 442 | + f"First used timeslice: {trimmed_timeslices[0]}", |
| 443 | + f"Last used timeslice: {trimmed_timeslices[-1]}", |
| 444 | + f"Wall-time mean including allowed gaps: {wall_time_mean_print:.6g} {unit_label}", |
| 445 | + f"Individual duration sample mean: {sample_mean:.6g} {unit_label}", |
| 446 | + f"Individual duration sample sigma: {sample_sigma:.6g} {unit_label}", |
| 447 | + ] |
| 448 | + |
| 449 | + if fit_result is not None: |
| 450 | + _, fit_mean, fit_sigma = fit_result |
| 451 | + summary_lines.extend( |
| 452 | + [ |
| 453 | + f"Gaussian fit mean: {fit_mean:.6g} {unit_label}", |
| 454 | + f"Gaussian fit sigma: {fit_sigma:.6g} {unit_label}", |
| 455 | + ] |
| 456 | + ) |
| 457 | + else: |
| 458 | + summary_lines.append("Gaussian fit failed or scipy is unavailable.") |
319 | 459 |
|
320 | | - print(f"Saved plot to: {args.output}") |
| 460 | + save_summary_output(args.summary_output, summary_lines) |
321 | 461 |
|
322 | 462 |
|
323 | 463 | if __name__ == "__main__": |
|
0 commit comments