diff --git a/src/coreclr/ToolBox/superpmi/superpmi/jitinstance.cpp b/src/coreclr/ToolBox/superpmi/superpmi/jitinstance.cpp index 96484d4b86bcd1..07d90549de43ed 100644 --- a/src/coreclr/ToolBox/superpmi/superpmi/jitinstance.cpp +++ b/src/coreclr/ToolBox/superpmi/superpmi/jitinstance.cpp @@ -369,15 +369,12 @@ JitInstance::Result JitInstance::CompileMethod(MethodContext* MethodToCompile, i pParam->pThis->mc->cr->recMessageLog("Successful Compile"); - pParam->metrics->SuccessfulCompiles++; pParam->metrics->NumCodeBytes += NCodeSizeBlock; } else { LogDebug("compileMethod failed with result %d", jitResult); pParam->result = RESULT_ERROR; - - pParam->metrics->FailingCompiles++; } } PAL_EXCEPT_FILTER(FilterSuperPMIExceptions_CaptureExceptionAndStop) @@ -408,6 +405,20 @@ JitInstance::Result JitInstance::CompileMethod(MethodContext* MethodToCompile, i mc->cr->secondsToCompile = stj.GetSeconds(); + if (param.result == RESULT_SUCCESS) + { + metrics->SuccessfulCompiles++; + } + else + { + metrics->FailingCompiles++; + } + + if (param.result == RESULT_MISSING) + { + metrics->MissingCompiles++; + } + return param.result; } diff --git a/src/coreclr/ToolBox/superpmi/superpmi/metricssummary.cpp b/src/coreclr/ToolBox/superpmi/superpmi/metricssummary.cpp index e7c725d7845bf9..8af4e6f164184b 100644 --- a/src/coreclr/ToolBox/superpmi/superpmi/metricssummary.cpp +++ b/src/coreclr/ToolBox/superpmi/superpmi/metricssummary.cpp @@ -41,8 +41,11 @@ bool MetricsSummary::SaveToFile(const char* path) char buffer[4096]; int len = - sprintf_s(buffer, sizeof(buffer), "Successful compiles,Failing compiles,Code bytes\n%d,%d,%lld\n", - SuccessfulCompiles, FailingCompiles, NumCodeBytes); + sprintf_s( + buffer, sizeof(buffer), + "Successful compiles,Failing compiles,Missing compiles,Code bytes,Diffed code bytes\n" + "%d,%d,%d,%lld,%lld\n", + SuccessfulCompiles, FailingCompiles, MissingCompiles, NumCodeBytes, NumDiffedCodeBytes); DWORD numWritten; if (!WriteFile(file.get(), buffer, static_cast(len), &numWritten, nullptr) || numWritten != static_cast(len)) { @@ -73,18 +76,21 @@ bool MetricsSummary::LoadFromFile(const char* path, MetricsSummary* metrics) return false; } - if (sscanf_s(content.data(), "Successful compiles,Failing compiles,Code bytes\n%d,%d,%lld\n", - &metrics->SuccessfulCompiles, &metrics->FailingCompiles, &metrics->NumCodeBytes) != 3) - { - return false; - } + int scanResult = + sscanf_s( + content.data(), + "Successful compiles,Failing compiles,Missing compiles,Code bytes,Diffed code bytes\n" + "%d,%d,%d,%lld,%lld\n", + &metrics->SuccessfulCompiles, &metrics->FailingCompiles, &metrics->MissingCompiles, &metrics->NumCodeBytes, &metrics->NumDiffedCodeBytes); - return true; + return scanResult == 5; } void MetricsSummary::AggregateFrom(const MetricsSummary& other) { SuccessfulCompiles += other.SuccessfulCompiles; FailingCompiles += other.FailingCompiles; + MissingCompiles += other.MissingCompiles; NumCodeBytes += other.NumCodeBytes; + NumDiffedCodeBytes += other.NumDiffedCodeBytes; } diff --git a/src/coreclr/ToolBox/superpmi/superpmi/metricssummary.h b/src/coreclr/ToolBox/superpmi/superpmi/metricssummary.h index 4f7d825c2d43aa..335c8b972bc75d 100644 --- a/src/coreclr/ToolBox/superpmi/superpmi/metricssummary.h +++ b/src/coreclr/ToolBox/superpmi/superpmi/metricssummary.h @@ -7,14 +7,23 @@ class MetricsSummary { public: + // Number of methods successfully jitted. int SuccessfulCompiles; + // Number of methods that failed jitting. int FailingCompiles; + // Number of methods that failed jitting due to missing SPMI data. + int MissingCompiles; + // Number of code bytes produced by the JIT for the successful compiles. long long NumCodeBytes; + // Number of code bytes that were diffed with the other compiler in diff mode. + long long NumDiffedCodeBytes; MetricsSummary() : SuccessfulCompiles(0) , FailingCompiles(0) + , MissingCompiles(0) , NumCodeBytes(0) + , NumDiffedCodeBytes(0) { } diff --git a/src/coreclr/ToolBox/superpmi/superpmi/superpmi.cpp b/src/coreclr/ToolBox/superpmi/superpmi/superpmi.cpp index 5410240bdad331..f71ee9c1fe32be 100644 --- a/src/coreclr/ToolBox/superpmi/superpmi/superpmi.cpp +++ b/src/coreclr/ToolBox/superpmi/superpmi/superpmi.cpp @@ -265,8 +265,8 @@ int __cdecl main(int argc, char* argv[]) } } - MetricsSummary baseMetrics; - MetricsSummary diffMetrics; + MetricsSummary totalBaseMetrics; + MetricsSummary totalDiffMetrics; while (true) { @@ -362,17 +362,22 @@ int __cdecl main(int argc, char* argv[]) } } + MetricsSummary baseMetrics; jittedCount++; st3.Start(); res = jit->CompileMethod(mc, reader->GetMethodContextIndex(), collectThroughput, &baseMetrics); st3.Stop(); LogDebug("Method %d compiled in %fms, result %d", reader->GetMethodContextIndex(), st3.GetMilliseconds(), res); + totalBaseMetrics.AggregateFrom(baseMetrics); + if ((res == JitInstance::RESULT_SUCCESS) && Logger::IsLogLevelEnabled(LOGLEVEL_DEBUG)) { mc->cr->dumpToConsole(); // Dump the compile results if doing debug logging } + MetricsSummary diffMetrics; + if (o.nameOfJit2 != nullptr) { // Lets get the results for the 2nd JIT @@ -387,6 +392,8 @@ int __cdecl main(int argc, char* argv[]) LogDebug("Method %d compiled by JIT2 in %fms, result %d", reader->GetMethodContextIndex(), st4.GetMilliseconds(), res2); + totalDiffMetrics.AggregateFrom(diffMetrics); + if ((res2 == JitInstance::RESULT_SUCCESS) && Logger::IsLogLevelEnabled(LOGLEVEL_DEBUG)) { mc->cr->dumpToConsole(); // Dump the compile results if doing debug logging @@ -529,6 +536,9 @@ int __cdecl main(int argc, char* argv[]) else { InvokeNearDiffer(&nearDiffer, &o, &mc, &crl, &matchCount, &reader, &failingToReplayMCL, &diffMCL); + + totalBaseMetrics.NumDiffedCodeBytes += baseMetrics.NumCodeBytes; + totalDiffMetrics.NumDiffedCodeBytes += diffMetrics.NumCodeBytes; } } } @@ -609,12 +619,12 @@ int __cdecl main(int argc, char* argv[]) if (o.baseMetricsSummaryFile != nullptr) { - baseMetrics.SaveToFile(o.baseMetricsSummaryFile); + totalBaseMetrics.SaveToFile(o.baseMetricsSummaryFile); } if (o.diffMetricsSummaryFile != nullptr) { - diffMetrics.SaveToFile(o.diffMetricsSummaryFile); + totalDiffMetrics.SaveToFile(o.diffMetricsSummaryFile); } if (methodStatsEmitter != nullptr) diff --git a/src/coreclr/scripts/superpmi.py b/src/coreclr/scripts/superpmi.py index e919117d8c39ad..0c098ecc89880b 100755 --- a/src/coreclr/scripts/superpmi.py +++ b/src/coreclr/scripts/superpmi.py @@ -1471,7 +1471,7 @@ def __verify_final_mch__(self): ################################################################################ -def print_superpmi_failure_code(return_code, coreclr_args): +def print_superpmi_result(return_code, coreclr_args, base_metrics, diff_metrics): """ Print a description of a superpmi return (error) code. If the return code is zero, meaning success, don't print anything. Note that Python treats process return codes (at least on Windows) as @@ -1479,8 +1479,7 @@ def print_superpmi_failure_code(return_code, coreclr_args): those return codes. """ if return_code == 0: - # Don't print anything if the code is zero, which is success. - pass + logging.info("Clean SuperPMI {} ({} contexts processed)".format("replay" if diff_metrics is None else "diff", base_metrics["Successful compiles"])) elif return_code == -1 or return_code == 4294967295: logging.error("General fatal error") elif return_code == -2 or return_code == 4294967294: @@ -1490,7 +1489,15 @@ def print_superpmi_failure_code(return_code, coreclr_args): elif return_code == 2: logging.warning("Asm diffs found") elif return_code == 3: - logging.warning("SuperPMI missing data encountered") + missing_base = int(base_metrics["Missing compiles"]) + total_contexts = int(base_metrics["Successful compiles"]) + int(base_metrics["Failing compiles"]) + + if diff_metrics is None: + logging.warning("SuperPMI encountered missing data for {} out of {} contexts".format(missing_base, total_contexts)) + else: + missing_diff = int(diff_metrics["Missing compiles"]) + logging.warning("SuperPMI encountered missing data. Missing with base JIT: {}. Missing with diff JIT: {}. Total contexts: {}.".format(missing_base, missing_diff, total_contexts)) + elif return_code == 139 and coreclr_args.host_os != "windows": logging.error("Fatal error, SuperPMI has returned SIGSEGV (segmentation fault)") else: @@ -1636,16 +1643,20 @@ def replay(self): flags = common_flags.copy() fail_mcl_file = os.path.join(temp_location, os.path.basename(mch_file) + "_fail.mcl") + metrics_summary_file = os.path.join(temp_location, os.path.basename(mch_file) + "_metrics.csv") + flags += [ - "-f", fail_mcl_file # Failing mc List + "-f", fail_mcl_file, # Failing mc List + "-metricsSummary", metrics_summary_file ] command = [self.superpmi_path] + flags + [self.jit_path, mch_file] return_code = run_and_log(command) - print_superpmi_failure_code(return_code, self.coreclr_args) - if return_code == 0: - logging.info("Clean SuperPMI replay") - else: + + metrics = read_csv_metrics(metrics_summary_file) + + print_superpmi_result(return_code, self.coreclr_args, metrics, None) + if return_code != 0: result = False # Don't report as replay failure missing data (return code 3). # Anything else, such as compilation failure (return code 1, typically a JIT assert) will be @@ -1859,16 +1870,19 @@ def replay_with_asm_diffs(self): with ChangeDir(self.coreclr_args.core_root): command = [self.superpmi_path] + flags + [self.base_jit_path, self.diff_jit_path, mch_file] return_code = run_and_log(command) - print_superpmi_failure_code(return_code, self.coreclr_args) - if return_code == 0: - logging.info("Clean SuperPMI diff") - else: - result = False - # Don't report as replay failure asm diffs (return code 2) or missing data (return code 3). - # Anything else, such as compilation failure (return code 1, typically a JIT assert) will be - # reported as a replay failure. - if return_code != 2 and return_code != 3: - files_with_replay_failures.append(mch_file) + + base_metrics = read_csv_metrics(base_metrics_summary_file) + diff_metrics = read_csv_metrics(diff_metrics_summary_file) + + print_superpmi_result(return_code, self.coreclr_args, base_metrics, diff_metrics) + + if return_code != 0: + result = False + # Don't report as replay failure asm diffs (return code 2) or missing data (return code 3). + # Anything else, such as compilation failure (return code 1, typically a JIT assert) will be + # reported as a replay failure. + if return_code != 2 and return_code != 3: + files_with_replay_failures.append(mch_file) artifacts_base_name = create_artifacts_base_name(self.coreclr_args, mch_file) @@ -1983,16 +1997,13 @@ async def create_one_artifact(jit_path: str, location: str, flags) -> str: logging.debug(item) logging.debug("") - base_metrics = read_csv_metrics(base_metrics_summary_file) - diff_metrics = read_csv_metrics(diff_metrics_summary_file) - - if base_metrics is not None and "Code bytes" in base_metrics and diff_metrics is not None and "Code bytes" in diff_metrics: - base_bytes = int(base_metrics["Code bytes"]) - diff_bytes = int(diff_metrics["Code bytes"]) - logging.info("Total Code bytes of base: {}".format(base_bytes)) - logging.info("Total Code bytes of diff: {}".format(diff_bytes)) + if base_metrics is not None and diff_metrics is not None: + base_bytes = int(base_metrics["Diffed code bytes"]) + diff_bytes = int(diff_metrics["Diffed code bytes"]) + logging.info("Total bytes of base: {}".format(base_bytes)) + logging.info("Total bytes of diff: {}".format(diff_bytes)) delta_bytes = diff_bytes - base_bytes - logging.info("Total Code bytes of delta: {} ({:.2%} of base)".format(delta_bytes, delta_bytes / base_bytes)) + logging.info("Total bytes of delta: {} ({:.2%} of base)".format(delta_bytes, delta_bytes / base_bytes)) try: current_text_diff = text_differences.get_nowait() @@ -2044,6 +2055,15 @@ async def create_one_artifact(jit_path: str, location: str, flags) -> str: else: logging.warning("No textual differences found in generated JitDump. Is this an issue with coredistools?") + if base_metrics is not None and diff_metrics is not None: + missing_base = int(base_metrics["Missing compiles"]) + missing_diff = int(diff_metrics["Missing compiles"]) + total_contexts = int(base_metrics["Successful compiles"]) + int(base_metrics["Failing compiles"]) + + if missing_base > 0 or missing_diff > 0: + logging.warning("Warning: SuperPMI encountered missing data during the diff. The diff summary printed above may be misleading.") + logging.warning("Missing with base JIT: {}. Missing with diff JIT: {}. Total contexts: {}.".format(missing_base, missing_diff, total_contexts)) + ################################################################################################ end of processing asm diffs (if is_nonzero_length_file(diff_mcl_file)... if not self.coreclr_args.skip_cleanup: