[memprof] Filter out callstack frames which cannot be symbolized.

[snehasish]

Summary

This patch filters out callstack frames which can't be symbolized or if
the frames belong to the runtime. Symbolization may not be possible if
debug information is unavailable or if the addresses are from a shared
library. For now we only support optimization of the main binary which
is statically linked to the compiler runtime.

[snehasish]

Simplify discarded vaddrs check, rename method to indicate filtering and add comments.

[tejohnson]

llvm/lib/ProfileData/RawMemProfReader.cpp

300

Nit: parses slightly better if you say "or if we don't..."

315

I think operator new should go through memprof_new_delete.cpp? Does FileName contain any of the path, or do we have it available anywhere? I.e. could we match on "/memprof/memprof_"?

336

Rather than scan CallStack again, can you keep a flag initialized to false above the prior loop, set to true if any entries are symbolized, and check that here?

llvm/test/tools/llvm-profdata/memprof-basic.test

37

s/originae/originate/

45

Should this now be 2? Ditto for NumStackOffsets below.

[snehasish]

Address comments.

[snehasish]

Add TODO to update summary print.

[snehasish]

PTAL, thanks!

llvm/lib/ProfileData/RawMemProfReader.cpp

336

In practice all callstacks have at least one item to discard which originates from a shared library, i.e. the call to main from glibc at __libc_start_main in libc-start.c so adding a flag here doesn't help.

An alternative way to filter would be to use the procmaps to identify all addresses within the main binary and only retain those while reading the raw profile, however we don't record build ids on linux during profiling today (sanitizer_procmaps_linux does not support it). We could use a heuristic to identify the main binary but matching it to the profiled binary (passed in during llvm-profdata merge) build id would be best.

llvm/test/tools/llvm-profdata/memprof-basic.test

45

This is coming from the raw profile without symbolization and pruning. If you don't feel strongly, I'll update the summary code in a separate patch. I've added a TODO in RawMemProfReader.cpp for now.

[tejohnson]

llvm/lib/ProfileData/RawMemProfReader.cpp

336

Nevermind, I mistakenly thought this was removing all of them, but it may only be removing some frames.

llvm/test/tools/llvm-profdata/memprof-basic.test

45

That's fine, but I'm confused as to how the output of this file changed then, since it looks like printYAML prints the records immediately after the summary, but now there are only 2 MIB records printed? Is it the case that the records have been filtered by that point but the summary hasn't been updated accordingly?

[snehasish]

llvm/test/tools/llvm-profdata/memprof-basic.test

45

The issue here is that printSummaries generates the data to print on the fly by reading the DataBuffer (i.e. raw profile file) directly. This was introduced to have some basic testing and we need to migrate it to generating the summary from the internal data structures that we have now. I hope that makes it clear.

[tejohnson]

lgtm

llvm/include/llvm/ProfileData/RawMemProfReader.h

RawMemProfReader(std::unique_ptr<llvm::symbolize::SymbolizableModule> Sym,
                    CallStackMap &SM)
       : Symbolizer(std::move(Sym)), SegmentInfo(Seg.begin(), Seg.end()),
         ProfileData(Prof), StackMap(SM) {
     // We don't call initialize here since there is no raw profile to read. The
     // test should pass in the raw profile as structured data.
 
     // If there is an error here then the mock symbolizer has not been
     // initialized properly.
-    if (Error E = symbolizeStackFrames())
+    if (Error E = symbolizeAndFilterStackFrames())
       report_fatal_error(std::move(E));
   }
 
 private:
   RawMemProfReader(std::unique_ptr<MemoryBuffer> DataBuffer,
                    object::OwningBinary<object::Binary> &&Bin)
       : DataBuffer(std::move(DataBuffer)), Binary(std::move(Bin)) {}
   Error initialize();
   Error readRawProfile();
-  Error symbolizeStackFrames();
+  // Symbolize and cache all the virtual addresses we encounter in the
+  // callstacks from the raw profile. Also prune callstack frames which we can't
+  // symbolize or those that belong to the runtime. For profile entries where
+  // the entire callstack is pruned, we drop the entry from the profile.
+  Error symbolizeAndFilterStackFrames();
 
   object::SectionedAddress getModuleOffset(uint64_t VirtualAddress);
   Error fillRecord(const uint64_t Id, const MemInfoBlock &MIB,
                    MemProfRecord &Record);
   // Prints aggregate counts for each raw profile parsed from the DataBuffer in
   // YAML format.
   void printSummaries(raw_ostream &OS) const;
 

llvm/lib/ProfileData/RawMemProfReader.cpp

 //===- RawMemProfReader.cpp - Instrumented memory profiling reader --------===//
 //
 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
 // See https://llvm.org/LICENSE.txt for license information.
 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
 //
 //===----------------------------------------------------------------------===//
 //
 // This file contains support for reading MemProf profiling data.
 //
 //===----------------------------------------------------------------------===//
 
+#include <algorithm>
 #include <cstdint>
 #include <type_traits>
 
 #include "llvm/ADT/DenseMap.h"
 #include "llvm/ADT/STLExtras.h"
+#include "llvm/ADT/SmallVector.h"
 #include "llvm/DebugInfo/DWARF/DWARFContext.h"
 #include "llvm/DebugInfo/Symbolize/SymbolizableModule.h"
 #include "llvm/DebugInfo/Symbolize/SymbolizableObjectFile.h"
 #include "llvm/Object/Binary.h"
 #include "llvm/Object/ELFObjectFile.h"
 #include "llvm/Object/ObjectFile.h"
 #include "llvm/ProfileData/InstrProf.h"
 #include "llvm/ProfileData/MemProf.h"
auto SOFOr = symbolize::SymbolizableObjectFile::create(
       Object, std::move(Context), /*UntagAddresses=*/false);
   if (!SOFOr)
     return report(SOFOr.takeError(), FileName);
   Symbolizer = std::move(SOFOr.get());
 
   if (Error E = readRawProfile())
     return E;
 
-  return symbolizeStackFrames();
+  return symbolizeAndFilterStackFrames();
 }
 
-Error RawMemProfReader::symbolizeStackFrames() {
+Error RawMemProfReader::symbolizeAndFilterStackFrames() {
   // The specifier to use when symbolization is requested.
   const DILineInfoSpecifier Specifier(
       DILineInfoSpecifier::FileLineInfoKind::RawValue,
       DILineInfoSpecifier::FunctionNameKind::LinkageName);
 
-  for (const auto &Entry : StackMap) {
+  // For entries where all PCs in the callstack are discarded, we erase the
+  // entry from the stack map.
+  llvm::SmallVector<uint64_t> EntriesToErase;
+  // We keep track of all prior discarded entries so that we can avoid invoking
+  // the symbolizer for such entries.
+  llvm::DenseSet<uint64_t> AllVAddrsToDiscard;
+  for (auto &Entry : StackMap) {
     for (const uint64_t VAddr : Entry.getSecond()) {
-      // Check if we have already symbolized and cached the result.
-      if (SymbolizedFrame.count(VAddr) > 0)
+      // Check if we have already symbolized and cached the result or we don't
+      // want to attempt symbolization since we know this address is bad. In
+      // this case the address is also removed from the current callstack.
+      if (SymbolizedFrame.count(VAddr) > 0 ||
+          AllVAddrsToDiscard.contains(VAddr))
         continue;
 
       Expected<DIInliningInfo> DIOr = Symbolizer->symbolizeInlinedCode(
           getModuleOffset(VAddr), Specifier, /*UseSymbolTable=*/false);
       if (!DIOr)
         return DIOr.takeError();
       DIInliningInfo DI = DIOr.get();
 
+      // Drop frames which we can't symbolize or if they belong to the runtime.
+      if (DI.getFrame(0).FunctionName == DILineInfo::BadString ||
+          StringRef(DI.getFrame(0).FileName).contains("memprof_malloc_")) {
+        AllVAddrsToDiscard.insert(VAddr);
+        continue;
+      }
+
       for (size_t I = 0; I < DI.getNumberOfFrames(); I++) {
         const auto &Frame = DI.getFrame(I);
         SymbolizedFrame[VAddr].emplace_back(
             // We use the function guid which we expect to be a uint64_t. At
             // this time, it is the lower 64 bits of the md5 of the function
             // name. Any suffix with .llvm. is trimmed since these are added by
             // thinLTO global promotion. At the time the profile is consumed,
             // these suffixes will not be present.
             Function::getGUID(trimSuffix(Frame.FunctionName)),
             Frame.Line - Frame.StartLine, Frame.Column,
             // Only the first entry is not an inlined location.
             I != 0);
       }
     }
+
+    auto &CallStack = Entry.getSecond();
+    CallStack.erase(std::remove_if(CallStack.begin(), CallStack.end(),
+                                   [&AllVAddrsToDiscard](const uint64_t A) {
+                                     return AllVAddrsToDiscard.contains(A);
+                                   }),
+                    CallStack.end());
+    if (CallStack.empty())
+      EntriesToErase.push_back(Entry.getFirst());
+  }
+
+  // Drop the entries where the callstack is empty.
+  for (const uint64_t Id : EntriesToErase) {
+    StackMap.erase(Id);
+    ProfileData.erase(Id);
   }
+
+  if (StackMap.empty())
+    return make_error<InstrProfError>(
+        instrprof_error::malformed,
+        "no entries in callstack map after symbolization");
+
   return Error::success();
 }
 
 Error RawMemProfReader::readRawProfile() {
   const char *Next = DataBuffer->getBufferStart();
 
   while (Next < DataBuffer->getBufferEnd()) {
     auto *Header = reinterpret_cast<const memprof::Header *>(Next);

llvm/test/tools/llvm-profdata/memprof-basic.test

clang -fuse-ld=lld -Wl,--no-rosegment -gmlt -fdebug-info-for-profiling \
       -fmemory-profile -mno-omit-leaf-frame-pointer -fno-omit-frame-pointer \
       -fno-optimize-sibling-calls -m64 -Wl,-build-id source.c -o basic.memprofexe 
 
 env MEMPROF_OPTIONS=log_path=stdout ./rawprofile.out > basic.memprofraw
 ```
 
 RUN: llvm-profdata show --memory %p/Inputs/basic.memprofraw --profiled-binary %p/Inputs/basic.memprofexe -o - | FileCheck %s
 
-We expect 3 MIB entries, 1 each for the malloc calls in the program and one
-additional entry from a realloc in glibc/libio/vasprintf.c.
+We expect 2 MIB entries, 1 each for the malloc calls in the program. Any
+additional allocations which do not originae from the main binary are pruned.
 
 CHECK: MemprofProfile:
 CHECK-NEXT:   -
 CHECK-NEXT:   Header:
 CHECK-NEXT:     Version: 1
 CHECK-NEXT:     TotalSizeBytes: 1016
 CHECK-NEXT:     NumSegments: 9
 CHECK-NEXT:     NumMibInfo: 3
 CHECK-NEXT:     NumStackOffsets: 3
-CHECK-NEXT:   Records:
-CHECK-NEXT:   -
-CHECK-NEXT:     Callstack:
-CHECK-NEXT:     -
-CHECK-NEXT:       Function: {{[0-9]+}}
-CHECK-NEXT:       LineOffset: 73
-CHECK-NEXT:       Column: 3
-CHECK-NEXT:       Inline: 0
-CHECK-NEXT:     -
-CHECK-NEXT:       Function: {{[0-9]+}}
-CHECK-NEXT:       LineOffset: 0
-CHECK-NEXT:       Column: 0
-CHECK-NEXT:       Inline: 0
-CHECK-NEXT:     MemInfoBlock:
-CHECK-NEXT:       AllocCount: 1
-CHECK-NEXT:       TotalAccessCount: 0
-CHECK-NEXT:       MinAccessCount: 0
-CHECK-NEXT:       MaxAccessCount: 0
-CHECK-NEXT:       TotalSize: 53
-CHECK-NEXT:       MinSize: 53
-CHECK-NEXT:       MaxSize: 53
-CHECK-NEXT:       AllocTimestamp: 0
-CHECK-NEXT:       DeallocTimestamp: 987
-CHECK-NEXT:       TotalLifetime: 987
-CHECK-NEXT:       MinLifetime: 987
-CHECK-NEXT:       MaxLifetime: 987
-CHECK-NEXT:       AllocCpuId: 4294967295
-CHECK-NEXT:       DeallocCpuId: 56
-CHECK-NEXT:       NumMigratedCpu: 1
-CHECK-NEXT:       NumLifetimeOverlaps: 0
-CHECK-NEXT:       NumSameAllocCpu: 0
-CHECK-NEXT:       NumSameDeallocCpu: 0
-CHECK-NEXT:       DataTypeId: {{[0-9]+}}
-CHECK-NEXT:   -
-CHECK-NEXT:     Callstack:
-CHECK-NEXT:     -
-CHECK-NEXT:       Function: {{[0-9]+}}
-CHECK-NEXT:       LineOffset: 57
-CHECK-NEXT:       Column: 3
-CHECK-NEXT:       Inline: 0
-CHECK-NEXT:     -
-CHECK-NEXT:       Function: {{[0-9]+}}
-CHECK-NEXT:       LineOffset: 1
-CHECK-NEXT:       Column: 21
-CHECK-NEXT:       Inline: 0
-CHECK-NEXT:     -
-CHECK-NEXT:       Function: {{[0-9]+}}
-CHECK-NEXT:       LineOffset: 0
-CHECK-NEXT:       Column: 0
-CHECK-NEXT:       Inline: 0
-CHECK-NEXT:     MemInfoBlock:
-CHECK-NEXT:       AllocCount: 1
-CHECK-NEXT:       TotalAccessCount: 2
-CHECK-NEXT:       MinAccessCount: 2
-CHECK-NEXT:       MaxAccessCount: 2
-CHECK-NEXT:       TotalSize: 10
-CHECK-NEXT:       MinSize: 10
-CHECK-NEXT:       MaxSize: 10
-CHECK-NEXT:       AllocTimestamp: 986
-CHECK-NEXT:       DeallocTimestamp: 986
-CHECK-NEXT:       TotalLifetime: 0
-CHECK-NEXT:       MinLifetime: 0
-CHECK-NEXT:       MaxLifetime: 0
-CHECK-NEXT:       AllocCpuId: 56
-CHECK-NEXT:       DeallocCpuId: 56
-CHECK-NEXT:       NumMigratedCpu: 0
-CHECK-NEXT:       NumLifetimeOverlaps: 0
-CHECK-NEXT:       NumSameAllocCpu: 0
-CHECK-NEXT:       NumSameDeallocCpu: 0
-CHECK-NEXT:       DataTypeId: {{[0-9]+}}
-CHECK-NEXT:   -
-CHECK-NEXT:     Callstack:
-CHECK-NEXT:     -
-CHECK-NEXT:       Function: {{[0-9]+}}
-CHECK-NEXT:       LineOffset: 57
-CHECK-NEXT:       Column: 3
-CHECK-NEXT:       Inline: 0
-CHECK-NEXT:     -
-CHECK-NEXT:       Function: {{[0-9]+}}
-CHECK-NEXT:       LineOffset: 5
-CHECK-NEXT:       Column: 15
-CHECK-NEXT:       Inline: 0
-CHECK-NEXT:     -
-CHECK-NEXT:       Function: {{[0-9]+}}
-CHECK-NEXT:       LineOffset: 0
-CHECK-NEXT:       Column: 0
-CHECK-NEXT:       Inline: 0
-CHECK-NEXT:     MemInfoBlock:
-CHECK-NEXT:       AllocCount: 1
-CHECK-NEXT:       TotalAccessCount: 2
-CHECK-NEXT:       MinAccessCount: 2
-CHECK-NEXT:       MaxAccessCount: 2
-CHECK-NEXT:       TotalSize: 10
-CHECK-NEXT:       MinSize: 10
-CHECK-NEXT:       MaxSize: 10
-CHECK-NEXT:       AllocTimestamp: 987
-CHECK-NEXT:       DeallocTimestamp: 987
-CHECK-NEXT:       TotalLifetime: 0
-CHECK-NEXT:       MinLifetime: 0
-CHECK-NEXT:       MaxLifetime: 0
-CHECK-NEXT:       AllocCpuId: 56
-CHECK-NEXT:       DeallocCpuId: 56
-CHECK-NEXT:       NumMigratedCpu: 0
-CHECK-NEXT:       NumLifetimeOverlaps: 0
-CHECK-NEXT:       NumSameAllocCpu: 0
-CHECK-NEXT:       NumSameDeallocCpu: 0
-CHECK-NEXT:       DataTypeId: {{[0-9]+}}
+CHECK-NEXT:  Records:
+CHECK-NEXT:  -
+CHECK-NEXT:    Callstack:
+CHECK-NEXT:    -
+CHECK-NEXT:      Function: 15822663052811949562
+CHECK-NEXT:      LineOffset: 1
+CHECK-NEXT:      Column: 21
+CHECK-NEXT:      Inline: 0
+CHECK-NEXT:    MemInfoBlock:
+CHECK-NEXT:      AllocCount: 1
+CHECK-NEXT:      TotalAccessCount: 2
+CHECK-NEXT:      MinAccessCount: 2
+CHECK-NEXT:      MaxAccessCount: 2
+CHECK-NEXT:      TotalSize: 10
+CHECK-NEXT:      MinSize: 10
+CHECK-NEXT:      MaxSize: 10
+CHECK-NEXT:      AllocTimestamp: 986
+CHECK-NEXT:      DeallocTimestamp: 986
+CHECK-NEXT:      TotalLifetime: 0
+CHECK-NEXT:      MinLifetime: 0
+CHECK-NEXT:      MaxLifetime: 0
+CHECK-NEXT:      AllocCpuId: 56
+CHECK-NEXT:      DeallocCpuId: 56
+CHECK-NEXT:      NumMigratedCpu: 0
+CHECK-NEXT:      NumLifetimeOverlaps: 0
+CHECK-NEXT:      NumSameAllocCpu: 0
+CHECK-NEXT:      NumSameDeallocCpu: 0
+CHECK-NEXT:      DataTypeId: 18446701673792405504
+CHECK-NEXT:  -
+CHECK-NEXT:    Callstack:
+CHECK-NEXT:    -
+CHECK-NEXT:      Function: 15822663052811949562
+CHECK-NEXT:      LineOffset: 5
+CHECK-NEXT:      Column: 15
+CHECK-NEXT:      Inline: 0
+CHECK-NEXT:    MemInfoBlock:
+CHECK-NEXT:      AllocCount: 1
+CHECK-NEXT:      TotalAccessCount: 2
+CHECK-NEXT:      MinAccessCount: 2
+CHECK-NEXT:      MaxAccessCount: 2
+CHECK-NEXT:      TotalSize: 10
+CHECK-NEXT:      MinSize: 10
+CHECK-NEXT:      MaxSize: 10
+CHECK-NEXT:      AllocTimestamp: 987
+CHECK-NEXT:      DeallocTimestamp: 987
+CHECK-NEXT:      TotalLifetime: 0
+CHECK-NEXT:      MinLifetime: 0
+CHECK-NEXT:      MaxLifetime: 0
+CHECK-NEXT:      AllocCpuId: 56
+CHECK-NEXT:      DeallocCpuId: 56
+CHECK-NEXT:      NumMigratedCpu: 0
+CHECK-NEXT:      NumLifetimeOverlaps: 0
+CHECK-NEXT:      NumSameAllocCpu: 0
+CHECK-NEXT:      NumSameDeallocCpu: 0
+CHECK-NEXT:      DataTypeId: 18446701673792405504

llvm/test/tools/llvm-profdata/memprof-multi.test

clang -fuse-ld=lld -Wl,--no-rosegment -gmlt -fdebug-info-for-profiling \
       -fmemory-profile -mno-omit-leaf-frame-pointer -fno-omit-frame-pointer \
       -fno-optimize-sibling-calls -m64 -Wl,-build-id source.c -o multi.memprofexe
 
 env MEMPROF_OPTIONS=log_path=stdout ./rawprofile.out > multi.memprofraw
 ```
 
 RUN: llvm-profdata show --memory %p/Inputs/multi.memprofraw --profiled-binary %p/Inputs/multi.memprofexe -o - | FileCheck %s
 
-We expect 2 MIB entries, 1 each for the malloc calls in the program. Unlike the
-memprof-basic.test we do not see any allocation from glibc.
+We expect 2 MIB entries, 1 each for the malloc calls in the program.
 
 CHECK: MemprofProfile:
 CHECK-NEXT:   -
 CHECK-NEXT:   Header:
 CHECK-NEXT:     Version: 1
 CHECK-NEXT:     TotalSizeBytes: 864
 CHECK-NEXT:     NumSegments: 9
 CHECK-NEXT:     NumMibInfo: 2
 CHECK-NEXT:     NumStackOffsets: 2
 CHECK-NEXT:   -
 CHECK-NEXT:   Header:
 CHECK-NEXT:     Version: 1
 CHECK-NEXT:     TotalSizeBytes: 864
 CHECK-NEXT:     NumSegments: 9
 CHECK-NEXT:     NumMibInfo: 2
 CHECK-NEXT:     NumStackOffsets: 2

llvm/unittests/ProfileData/MemProfTest.cpp

public:
   }
 };
 
 struct MockInfo {
   std::string FunctionName;
   uint32_t Line;
   uint32_t StartLine;
   uint32_t Column;
+  std::string FileName = "valid/path.cc";
 };
 DIInliningInfo makeInliningInfo(std::initializer_list<MockInfo> MockFrames) {
   DIInliningInfo Result;
   for (const auto &Item : MockFrames) {
     DILineInfo Frame;
     Frame.FunctionName = Item.FunctionName;
     Frame.Line = Item.Line;
     Frame.StartLine = Item.StartLine;
     Frame.Column = Item.Column;
+    Frame.FileName = Item.FileName;
     Result.addFrame(Frame);
   }
   return Result;
 }
 
 llvm::SmallVector<SegmentEntry, 4> makeSegments() {
   llvm::SmallVector<SegmentEntry, 4> Result;
   // Mimic an entry for a non position independent executable.
TEST(MemProf, RecordSerializationRoundTrip) {
   const llvm::SmallVector<MemProfRecord, 4> GotRecords = deserializeRecords(
       Schema, reinterpret_cast<const unsigned char *>(Buffer.data()));
 
   ASSERT_TRUE(!GotRecords.empty());
   EXPECT_EQ(GotRecords.size(), Records.size());
   EXPECT_THAT(GotRecords[0], EqualsRecord(Records[0]));
   EXPECT_THAT(GotRecords[1], EqualsRecord(Records[1]));
 }
+
+TEST(MemProf, SymbolizationFilter) {
+  std::unique_ptr<MockSymbolizer> Symbolizer(new MockSymbolizer());
+
+  EXPECT_CALL(*Symbolizer, symbolizeInlinedCode(SectionedAddress{0x1000},
+                                                specifier(), false))
+      .Times(1) // once since we don't lookup invalid PCs repeatedly.
+      .WillRepeatedly(Return(makeInliningInfo({
+          {"malloc", 70, 57, 3, "memprof/memprof_malloc_linux.cpp"},
+      })));
+
+  EXPECT_CALL(*Symbolizer, symbolizeInlinedCode(SectionedAddress{0x2000},
+                                                specifier(), false))
+      .Times(1) // once since we don't lookup invalid PCs repeatedly.
+      .WillRepeatedly(Return(makeInliningInfo({
+          {DILineInfo::BadString, 0, 0, 0},
+      })));
+
+  EXPECT_CALL(*Symbolizer, symbolizeInlinedCode(SectionedAddress{0x3000},
+                                                specifier(), false))
+      .Times(1)
+      .WillRepeatedly(Return(makeInliningInfo({
+          {"foo", 10, 5, 30},
+      })));
+
+  CallStackMap CSM;
+  CSM[0x1] = {0x1000, 0x2000, 0x3000};
+  // This entry should be dropped since all PCs are either not
+  // symbolizable or belong to the runtime.
+  CSM[0x2] = {0x1000, 0x2000};
+
+  llvm::MapVector<uint64_t, MemInfoBlock> Prof;
+  Prof[0x1].AllocCount = 1;
+  Prof[0x2].AllocCount = 1;
+
+  auto Seg = makeSegments();
+
+  RawMemProfReader Reader(std::move(Symbolizer), Seg, Prof, CSM);
+
+  std::vector<MemProfRecord> Records;
+  for (const MemProfRecord &R : Reader) {
+    Records.push_back(R);
+  }
+  ASSERT_EQ(Records.size(), 1U);
+  ASSERT_EQ(Records[0].CallStack.size(), 1U);
+  EXPECT_THAT(Records[0].CallStack[0], FrameContains("foo", 5U, 30U, false));
+}
 } // namespace