From efb1df1a5ea3602cc3e2874c8e62295cee18b134 Mon Sep 17 00:00:00 2001 From: Kunal Pathak Date: Mon, 30 Jan 2023 16:07:39 -0800 Subject: [PATCH] Re-enable producing call stack from crashreport.json (#81387) * Revert "Revert "Produce crashreport.json and use llvm-symbolizer to create stack trace (#77578)" (#81379)" This reverts commit 3c76e140da9539e1fc0e0a44af0af3e01ceca920. * Add nativeSymbols only for PRs --- eng/pipelines/coreclr/templates/build-job.yml | 8 +- src/coreclr/debug/createdump/crashreportwriter.cpp | 1 + .../Coreclr.TestWrapper/CoreclrTestWrapperLib.cs | 310 ++++++++++++++++++++- src/tests/Common/testenvironment.proj | 3 +- 4 files changed, 315 insertions(+), 7 deletions(-) diff --git a/eng/pipelines/coreclr/templates/build-job.yml b/eng/pipelines/coreclr/templates/build-job.yml index 21b756f6..cf2a0e3 100644 --- a/eng/pipelines/coreclr/templates/build-job.yml +++ b/eng/pipelines/coreclr/templates/build-job.yml @@ -148,6 +148,12 @@ jobs: - name: clrRuntimePortableBuildArg value: '-portablebuild=false' + - name: nativeSymbols + value: '' + - ${{ if eq(variables['Build.Reason'], 'PullRequest') }}: + - name: nativeSymbols + value: '--keepnativesymbols' + - ${{ parameters.variables }} steps: @@ -190,7 +196,7 @@ jobs: # Build CoreCLR Runtime - ${{ if ne(parameters.osGroup, 'windows') }}: - - script: $(Build.SourcesDirectory)/src/coreclr/build-runtime$(scriptExt) $(buildConfig) $(archType) $(crossArg) $(osArg) -ci $(compilerArg) $(clrRuntimeComponentsBuildArg) $(pgoInstrumentArg) $(officialBuildIdArg) $(clrInterpreterBuildArg) $(clrRuntimePortableBuildArg) $(CoreClrPgoDataArg) + - script: $(Build.SourcesDirectory)/src/coreclr/build-runtime$(scriptExt) $(buildConfig) $(archType) $(crossArg) $(osArg) -ci $(compilerArg) $(clrRuntimeComponentsBuildArg) $(pgoInstrumentArg) $(officialBuildIdArg) $(clrInterpreterBuildArg) $(clrRuntimePortableBuildArg) $(CoreClrPgoDataArg) $(nativeSymbols) displayName: Build CoreCLR Runtime - ${{ if eq(parameters.osGroup, 'windows') }}: - script: $(Build.SourcesDirectory)/src/coreclr/build-runtime$(scriptExt) $(buildConfig) $(archType) -ci $(enforcePgoArg) $(pgoInstrumentArg) $(officialBuildIdArg) $(clrInterpreterBuildArg) $(CoreClrPgoDataArg) diff --git a/src/coreclr/debug/createdump/crashreportwriter.cpp b/src/coreclr/debug/createdump/crashreportwriter.cpp index 3ca3676..049c2a7 100644 --- a/src/coreclr/debug/createdump/crashreportwriter.cpp +++ b/src/coreclr/debug/createdump/crashreportwriter.cpp @@ -223,6 +223,7 @@ CrashReportWriter::WriteStackFrame(const StackFrame& frame) WriteValue64("stack_pointer", frame.StackPointer()); WriteValue64("native_address", frame.InstructionPointer()); WriteValue64("native_offset", frame.NativeOffset()); + WriteValue64("native_image_offset", (frame.InstructionPointer() - frame.ModuleAddress())); if (frame.IsManaged()) { WriteValue32("token", frame.Token()); diff --git a/src/tests/Common/Coreclr.TestWrapper/CoreclrTestWrapperLib.cs b/src/tests/Common/Coreclr.TestWrapper/CoreclrTestWrapperLib.cs index 76e3549..51af242 100644 --- a/src/tests/Common/Coreclr.TestWrapper/CoreclrTestWrapperLib.cs +++ b/src/tests/Common/Coreclr.TestWrapper/CoreclrTestWrapperLib.cs @@ -10,6 +10,9 @@ using System.IO; using System.Linq; using System.Runtime.InteropServices; using System.Text; +using System.Text.Json; +using System.Text.Json.Nodes; +using System.Text.Json.Serialization; using System.Text.RegularExpressions; using System.Threading; using System.Threading.Tasks; @@ -204,12 +207,13 @@ namespace CoreclrTestLib public const string COLLECT_DUMPS_ENVIRONMENT_VAR = "__CollectDumps"; public const string CRASH_DUMP_FOLDER_ENVIRONMENT_VAR = "__CrashDumpFolder"; - static bool CollectCrashDump(Process process, string path) + static bool CollectCrashDump(Process process, string crashDumpPath, StreamWriter outputWriter) { string coreRoot = Environment.GetEnvironmentVariable("CORE_ROOT"); string createdumpPath = Path.Combine(coreRoot, "createdump"); - string arguments = $"--name \"{path}\" {process.Id} --withheap"; + string arguments = $"--name \"{crashDumpPath}\" {process.Id} --withheap"; Process createdump = new Process(); + bool crashReportPresent = false; if (OperatingSystem.IsWindows()) { @@ -219,8 +223,8 @@ namespace CoreclrTestLib else if (OperatingSystem.IsLinux() || OperatingSystem.IsMacOS()) { createdump.StartInfo.FileName = "sudo"; - createdump.StartInfo.Arguments = $"{createdumpPath} " + arguments; - createdump.StartInfo.EnvironmentVariables.Add("DOTNET_DbgEnableElfDumpOnMacOS", "1"); + createdump.StartInfo.Arguments = $"{createdumpPath} --crashreport {arguments}"; + crashReportPresent = true; } createdump.StartInfo.UseShellExecute = false; @@ -244,6 +248,11 @@ namespace CoreclrTestLib Console.WriteLine(output); Console.WriteLine("createdump stderr:"); Console.WriteLine(error); + + if (crashReportPresent) + { + TryPrintStackTraceFromCrashReport(crashDumpPath + ".crashreport.json", outputWriter); + } } else { @@ -253,6 +262,271 @@ namespace CoreclrTestLib return fSuccess && createdump.ExitCode == 0; } + private static List knownNativeModules = new List() { "libcoreclr.so", "libclrjit.so" }; + private static string TO_BE_CONTINUE_TAG = ""; + private static string SKIP_LINE_TAG = "# "; + + + static bool RunProcess(string fileName, string arguments) + { + Process proc = new Process() + { + StartInfo = new ProcessStartInfo() + { + FileName = fileName, + Arguments = arguments, + UseShellExecute = false, + RedirectStandardOutput = true, + RedirectStandardError = true, + } + }; + + Console.WriteLine($"Invoking: {proc.StartInfo.FileName} {proc.StartInfo.Arguments}"); + proc.Start(); + + Task stdOut = proc.StandardOutput.ReadToEndAsync(); + Task stdErr = proc.StandardError.ReadToEndAsync(); + if(!proc.WaitForExit(DEFAULT_TIMEOUT_MS)) + { + proc.Kill(true); + Console.WriteLine($"Timedout: '{fileName} {arguments}"); + return false; + } + + Task.WaitAll(stdOut, stdErr); + string output = stdOut.Result; + string error = stdErr.Result; + if (!string.IsNullOrWhiteSpace(output)) + { + Console.WriteLine($"stdout: {output}"); + } + if (!string.IsNullOrWhiteSpace(error)) + { + Console.WriteLine($"stderr: {error}"); + } + return true; + } + + /// + /// Parse crashreport.json file, use llvm-symbolizer to extract symbols + /// and recreate the stacktrace that is printed on the console. + /// + /// crash dump path + /// Stream for writing logs + /// true, if we can print the stack trace, otherwise false. + static bool TryPrintStackTraceFromCrashReport(string crashReportJsonFile, StreamWriter outputWriter) + { + if (OperatingSystem.IsLinux() || OperatingSystem.IsMacOS()) + { + if (!RunProcess("sudo", $"ls -l {crashReportJsonFile}")) + { + return false; + } + + Console.WriteLine("========================================="); + string userName = Environment.GetEnvironmentVariable("USER"); + if (!string.IsNullOrEmpty(userName)) + { + if (!RunProcess("sudo", $"chown {userName} {crashReportJsonFile}")) + { + return false; + } + + Console.WriteLine("========================================="); + if (!RunProcess("sudo", $"ls -l {crashReportJsonFile}")) + { + return false; + } + + Console.WriteLine("========================================="); + if (!RunProcess("ls", $"-l {crashReportJsonFile}")) + { + return false; + } + } + } + + if (!File.Exists(crashReportJsonFile)) + { + return false; + } + outputWriter.WriteLine($"Printing stacktrace from '{crashReportJsonFile}'"); + + string contents = File.ReadAllText(crashReportJsonFile); + dynamic crashReport = JsonSerializer.Deserialize(contents); + var threads = crashReport["payload"]["threads"]; + + // The logic happens in 3 steps: + // 1. Read the crashReport.json file, locate all the addresses of interest and then build + // a string that will be passed to llvm-symbolizer. It is populated so that each address + // is in its separate line along with the file name, etc. Some TAGS are added in the + // string that is used in step 2. + // 2. llvm-symbolizer is ran and above string is passed as input. + // 3. After llvm-symbolizer completes, TAGS are used to format its output to print it in + // the way it will be printed by sos. + + StringBuilder addrBuilder = new StringBuilder(); + string coreRoot = Environment.GetEnvironmentVariable("CORE_ROOT"); + foreach (var thread in threads) + { + + if (thread["native_thread_id"] == null) + { + continue; + } + + addrBuilder.AppendLine(); + addrBuilder.AppendLine("----------------------------------"); + addrBuilder.AppendLine($"Thread Id: {thread["native_thread_id"]}"); + addrBuilder.AppendLine(" Child SP IP Call Site"); + var stack_frames = thread["stack_frames"]; + foreach (var frame in stack_frames) + { + addrBuilder.Append($"{SKIP_LINE_TAG} {frame["stack_pointer"]} {frame["native_address"]} "); + bool isNative = (string)frame["is_managed"] == "false"; + + if (isNative) + { + string nativeModuleName = (string)frame["native_module"]; + string unmanagedName = (string)frame["unmanaged_name"]; + + if ((nativeModuleName != null) && (knownNativeModules.Contains(nativeModuleName))) + { + // Need to use llvm-symbolizer (only if module_address != 0) + AppendAddress(addrBuilder, coreRoot, nativeModuleName, (string)frame["native_address"], (string)frame["module_address"]); + } + else if ((nativeModuleName != null) || (unmanagedName != null)) + { + if (nativeModuleName != null) + { + addrBuilder.Append($"{nativeModuleName}!"); + } + if (unmanagedName != null) + { + addrBuilder.Append($"{unmanagedName}"); + } + } + } + else + { + string fileName = (string)frame["filename"]; + string methodName = (string)frame["method_name"]; + + if ((fileName != null) || (methodName != null)) + { + // found the managed method name + if (fileName != null) + { + addrBuilder.Append($"{fileName}!"); + } + if (methodName != null) + { + addrBuilder.Append($"{methodName}"); + } + } + else + { + addrBuilder.Append($"{frame["native_address"]}"); + } + } + addrBuilder.AppendLine(); + + } + } + + string symbolizerOutput = null; + + Process llvmSymbolizer = new Process() + { + StartInfo = { + FileName = "llvm-symbolizer", + Arguments = $"--pretty-print", + UseShellExecute = false, + RedirectStandardOutput = true, + RedirectStandardError = true, + RedirectStandardInput = true, + } + }; + + outputWriter.WriteLine($"Invoking {llvmSymbolizer.StartInfo.FileName} {llvmSymbolizer.StartInfo.Arguments}"); + + try + { + if (!llvmSymbolizer.Start()) + { + outputWriter.WriteLine($"Unable to start {llvmSymbolizer.StartInfo.FileName}"); + } + + using (var symbolizerWriter = llvmSymbolizer.StandardInput) + { + symbolizerWriter.WriteLine(addrBuilder.ToString()); + } + + Task stdout = llvmSymbolizer.StandardOutput.ReadToEndAsync(); + Task stderr = llvmSymbolizer.StandardError.ReadToEndAsync(); + bool fSuccess = llvmSymbolizer.WaitForExit(DEFAULT_TIMEOUT_MS); + + Task.WaitAll(stdout, stderr); + + if (!fSuccess) + { + outputWriter.WriteLine("Errors while running llvm-symbolizer --pretty-print"); + string output = stdout.Result; + string error = stderr.Result; + + Console.WriteLine("llvm-symbolizer stdout:"); + Console.WriteLine(output); + Console.WriteLine("llvm-symbolizer stderr:"); + Console.WriteLine(error); + + llvmSymbolizer.Kill(true); + + return false; + } + + symbolizerOutput = stdout.Result; + + } catch (Exception e) { + outputWriter.WriteLine("Errors while running llvm-symbolizer --pretty-print"); + outputWriter.WriteLine(e.ToString()); + return false; + } + + // Go through the output of llvm-symbolizer and strip all the markers we added initially. + string[] contentsToSantize = symbolizerOutput.Split(Environment.NewLine); + StringBuilder finalBuilder = new StringBuilder(); + for (int lineNum = 0; lineNum < contentsToSantize.Length; lineNum++) + { + string line = contentsToSantize[lineNum].Replace(SKIP_LINE_TAG, string.Empty); + if (string.IsNullOrWhiteSpace(line)) continue; + + if (line.EndsWith(TO_BE_CONTINUE_TAG)) + { + finalBuilder.Append(line.Replace(TO_BE_CONTINUE_TAG, string.Empty)); + continue; + } + finalBuilder.AppendLine(line); + } + outputWriter.WriteLine("Stack trace:"); + outputWriter.WriteLine(finalBuilder.ToString()); + return true; + } + + private static void AppendAddress(StringBuilder sb, string coreRoot, string nativeModuleName, string native_address, string module_address) + { + if (module_address != "0x0") + { + sb.Append($"{nativeModuleName}!"); + sb.Append(TO_BE_CONTINUE_TAG); + sb.AppendLine(); + //addrBuilder.AppendLine(frame.native_image_offset); + ulong nativeAddress = ulong.Parse(native_address.Substring(2), System.Globalization.NumberStyles.HexNumber); + ulong moduleAddress = ulong.Parse(module_address.Substring(2), System.Globalization.NumberStyles.HexNumber); + string fullPathToModule = Path.Combine(coreRoot, nativeModuleName); + sb.AppendFormat("{0} 0x{1:x}", fullPathToModule, nativeAddress - moduleAddress); + } + } + // Finds all children processes starting with a process named childName // The children are sorted in the order they should be dumped static unsafe IEnumerable FindChildProcessesByName(Process process, string childName) @@ -343,6 +617,32 @@ namespace CoreclrTestLib exitCode = process.ExitCode; MobileAppHandler.CheckExitCode(exitCode, testBinaryBase, category, outputWriter); Task.WaitAll(copyOutput, copyError); + + if (!OperatingSystem.IsWindows()) + { + // crashreport is only for non-windows. + if (exitCode != 0) + { + // Search for dump, if created. + if (Directory.Exists(crashDumpFolder)) + { + outputWriter.WriteLine($"Test failed. Trying to see if dump file was created in {crashDumpFolder} since {startTime}"); + DirectoryInfo crashDumpFolderInfo = new DirectoryInfo(crashDumpFolder); + var dmpFilesInfo = crashDumpFolderInfo.GetFiles("*.crashreport.json").OrderByDescending(f => f.CreationTime); + foreach (var dmpFile in dmpFilesInfo) + { + if (dmpFile.CreationTime < startTime) + { + // No new files since test started. + outputWriter.WriteLine("Finish looking for *.crashreport.json. No new files created."); + break; + } + outputWriter.WriteLine($"Processing {dmpFile.FullName}"); + TryPrintStackTraceFromCrashReport(dmpFile.FullName, outputWriter); + } + } + } + } } else { @@ -370,7 +670,7 @@ namespace CoreclrTestLib { string crashDumpPath = Path.Combine(Path.GetFullPath(crashDumpFolder), string.Format("crashdump_{0}.dmp", child.Id)); Console.WriteLine($"Attempting to collect crash dump: {crashDumpPath}"); - if (CollectCrashDump(child, crashDumpPath)) + if (CollectCrashDump(child, crashDumpPath, outputWriter)) { Console.WriteLine("Collected crash dump: {0}", crashDumpPath); } diff --git a/src/tests/Common/testenvironment.proj b/src/tests/Common/testenvironment.proj index f7d45b1..ca85289 100644 --- a/src/tests/Common/testenvironment.proj +++ b/src/tests/Common/testenvironment.proj @@ -15,6 +15,7 @@ DOTNET_TieredCompilation; DOTNET_DbgEnableMiniDump; + DOTNET_EnableCrashReport; DOTNET_DbgEnableElfDumpOnMacOS; DOTNET_DbgMiniDumpName; DOTNET_EnableAES; @@ -83,8 +84,8 @@ 0 1 - 1 $HELIX_DUMP_FOLDER/coredump.%d.dmp + 1 -- 2.7.4