search

KDAB / hotspot

The Linux perf GUI for performance analysis.
4.16k stars 257 forks source link

strange " Could not find ELF file for ." when opening a CentOS7 perf.data file on Debian10 #551

Closed GitMensch closed 1 year ago

GitMensch commented 1 year ago

Describe the bug While I don't expect the details to work (because that's a different system) the paths searched look quite wrong.

PerfUnwind::MissingElfFile: Could not find ELF file for . This can break stack unwinding and lead to missing symbols.
PerfUnwind::MissingElfFile: Could not find ELF file for 64/ld-2.17.so. This can break stack unwinding and lead to missing symbols.
PerfUnwind::MissingElfFile: Could not find ELF file for 64/ld-2.17.so. This can break stack unwinding and lead to missing symbols.
PerfUnwind::MissingElfFile: Could not find ELF file for . This can break stack unwinding and lead to missing symbols.
PerfUnwind::MissingElfFile: Could not find ELF file for . This can break stack unwinding and lead to missing symbols.
PerfUnwind::MissingElfFile: Could not find ELF file for . This can break stack unwinding and lead to missing symbols.
PerfUnwind::MissingElfFile: Could not find ELF file for 64/libc-2.17.so. This can break stack unwinding and lead to missing symbols.
PerfUnwind::MissingElfFile: Could not find ELF file for 64/libc-2.17.so. This can break stack unwinding and lead to missing symbols.
PerfUnwind::MissingElfFile: Could not find ELF file for 64/libc-2.17.so. This can break stack unwinding and lead to missing symbols.
PerfUnwind::MissingElfFile: Could not find ELF file for . This can break stack unwinding and lead to missing symbols.
PerfUnwind::MissingElfFile: Could not find ELF file for . This can break stack unwinding and lead to missing symbols.
PerfUnwind::MissingElfFile: Could not find ELF file for . This can break stack unwinding and lead to missing symbols.

To Reproduce Steps to reproduce the behavior:

  1. Use the attached perf.data
  2. Execute hotspot --appPath /bin perf.data.true.v2
  3. See warning messages with strange paths

Expected behavior Searching for /lib64/libc-2.17.so (that's the place the library is on CentOS7) instead of 64/libc-2.17.so; not searching for ..

Additional context If I get the library from http://mirror.centos.org/centos/7/os/x86_64/Packages/glibc-2.17-317.el7.x86_64.rpm, extract it and add the relevant --extraLibPaths /tmp/centos7/lib64 the error messages for the strange "64" folder are removed and the recording can be seen.

Furthermore, testing hints at that with each output of

PerfUnwind::MissingElfFile: Could not find ELF file for 64/ld-2.17.so. This can break stack unwinding and lead to missing symbols.

we see, the perfparser binary takes longer. I guess perfparerser caches registered elf files (return of PerfSymbolTable::registerElf()), but only those that can be resolved. In this case it would be good to also cache "invalid" / empty returns; allowing to also decrease the wait time for perf recordings with missing elf files in general and for this repo in the specific tests - see https://github.com/KDAB/hotspot/pull/539/commits/69ad59b2351cd70d2f6ca19b94b34bccf6a34514#r1382617529.

milianw commented 1 year ago

It's not searching for . - it was searching for a file with an empty name.

GitMensch commented 1 year ago

Good, that you've found this. Should we move the following to a separate issue?

Furthermore, testing hints at that with each output of

PerfUnwind::MissingElfFile: Could not find ELF file for 64/ld-2.17.so. This can break stack unwinding and lead to missing symbols.

we see, the perfparser binary takes longer. I guess perfparerser caches registered elf files (return of PerfSymbolTable::registerElf()), but only those that can be resolved. In this case it would be good to also cache "invalid" / empty returns; allowing to also decrease the wait time for perf recordings with missing elf files in general and for this repo in the specific tests - see 69ad59b#r1382617529.

milianw commented 1 year ago

No, as I don't see this as an issue? you only guess without showing any proof

GitMensch commented 1 year ago

You're reight about the missing proof. Rechecked with current hotspot-perfparser alone - and could not reproduce it. Without that:

perf stat /tmp/squashfs-root/usr/bin/hotspot-perfparser --input perf.data.true.v2 --output=/dev/null --app /bin #--extra ./lib64/
unhandled feature PerfHeader::CACHE 888
feature not properly read PerfHeader::CPU_TOPOLOGY 228 212
FINISHED_ROUND detected. Switching to automatic buffering
PerfUnwind::MissingElfFile: Could not find ELF file for 64/ld-2.17.so. This can break stack unwinding and lead to missing symbols.
PerfUnwind::MissingElfFile: Could not find ELF file for 64/ld-2.17.so. This can break stack unwinding and lead to missing symbols.
PerfUnwind::MissingElfFile: Could not find ELF file for 64/libc-2.17.so. This can break stack unwinding and lead to missing symbols.
PerfUnwind::MissingElfFile: Could not find ELF file for 64/libc-2.17.so. This can break stack unwinding and lead to missing symbols.
PerfUnwind::MissingElfFile: Could not find ELF file for 64/libc-2.17.so. This can break stack unwinding and lead to missing symbols.

 Performance counter stats for '/tmp/squashfs-root/usr/bin/hotspot-perfparser --input perf.data.true.v2 --output=/dev/null --app /bin':

              4.90 msec task-clock:u              #    0.945 CPUs utilized
                 0      context-switches:u        #    0.000 /sec
                 0      cpu-migrations:u          #    0.000 /sec
               488      page-faults:u             #   99.576 K/sec
          11031879      cycles:u                  #    2.251 GHz
            527937      stalled-cycles-frontend:u #    4.79% frontend cycles idle
           2621572      stalled-cycles-backend:u  #   23.76% backend cycles idle
          15618606      instructions:u            #    1.42  insn per cycle
                                                  #    0.17  stalled cycles per insn
           3389329      branches:u                #  691.587 M/sec
             60722      branch-misses:u           #    1.79% of all branches

       0.005186040 seconds time elapsed

       0.005265000 seconds user
       0.000000000 seconds sys

With the additional extra paths the warning message vanishes, but the instructions and computing time increases.

 perf stat /tmp/squashfs-root/usr/bin/hotspot-perfparser --input perf.data.true.v2 --output=/dev/null --app /bin --extra ./lib64/
feature not properly read PerfHeader::CPU_TOPOLOGY 228 212
unhandled feature PerfHeader::CACHE 888
FINISHED_ROUND detected. Switching to automatic buffering

 Performance counter stats for '/tmp/squashfs-root/usr/bin/hotspot-perfparser --input perf.data.true.v2 --output=/dev/null --app /bin --extra ./lib64/':

              5.73 msec task-clock:u              #    0.942 CPUs utilized
                 0      context-switches:u        #    0.000 /sec
                 0      cpu-migrations:u          #    0.000 /sec
               555      page-faults:u             #   96.908 K/sec
          14401613      cycles:u                  #    2.515 GHz
            667260      stalled-cycles-frontend:u #    4.63% frontend cycles idle
           3414886      stalled-cycles-backend:u  #   23.71% backend cycles idle
          21621729      instructions:u            #    1.50  insn per cycle
                                                  #    0.16  stalled cycles per insn
           4615838      branches:u                #  805.964 M/sec
             75026      branch-misses:u           #    1.63% of all branches

       0.006081037 seconds time elapsed

       0.006199000 seconds user
       0.000000000 seconds sys

Therefore, caching the "empty" seems to primarily drop the amount of warnings from 2 + 3 to 1 + 1. This may still be useful, but possibly not worth the effort, at least if - as I guess this is a question of adjusting multiple callers.

... but I can check that with the debugger, so:

This message comes from findFile which is commonly called 2+ times for the same entry, no matter if its found or not. Caching the result seems useful (and would then also raise the messages only once):

#0  PerfSymbolTable::findFile (this=0x4d7d30, path="/true", fileName="true", buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:162
#1  0x0000000000439aae in PerfSymbolTable::registerElf (this=0x4d7d30, mmap=..., buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:209
#2  0x0000000000420d66 in PerfUnwind::forwardMmapBuffer (this=0x7fffffffd4d0, mmapIt=..., mmapEnd=..., timestamp=43325196779752733) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfunwind.cpp:1008
#3  0x0000000000425f6b in PerfUnwind::flushEventBuffer (this=0x7fffffffd4d0, desiredBufferSize=9772) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfunwind.cpp:1113
#0  PerfSymbolTable::findFile (this=0x4d7d30, path="/true", fileName="true", buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:162
#1  0x0000000000439aae in PerfSymbolTable::registerElf (this=0x4d7d30, mmap=..., buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:209
#2  0x0000000000420d66 in PerfUnwind::forwardMmapBuffer (this=0x7fffffffd4d0, mmapIt=..., mmapEnd=..., timestamp=43325196779752733) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfunwind.cpp:1008
#3  0x0000000000425f6b in PerfUnwind::flushEventBuffer (this=0x7fffffffd4d0, desiredBufferSize=9772) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfunwind.cpp:1113
#0  PerfSymbolTable::findFile (this=0x4d7d30, path="64/ld-2.17.so", fileName="ld-2.17.so", buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:162
#1  0x0000000000439aae in PerfSymbolTable::registerElf (this=0x4d7d30, mmap=..., buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:209
#2  0x0000000000420d66 in PerfUnwind::forwardMmapBuffer (this=0x7fffffffd4d0, mmapIt=..., mmapEnd=..., timestamp=43325196779752733) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfunwind.cpp:1008
#3  0x0000000000425f6b in PerfUnwind::flushEventBuffer (this=0x7fffffffd4d0, desiredBufferSize=9772) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfunwind.cpp:1113
PerfUnwind::MissingElfFile: Could not find ELF file for 64/ld-2.17.so. This can break stack unwinding and lead to missing symbols.
#0  PerfSymbolTable::findFile (this=0x4d7d30, path="64/ld-2.17.so", fileName="ld-2.17.so", buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:162
#1  0x0000000000439aae in PerfSymbolTable::registerElf (this=0x4d7d30, mmap=..., buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:209
#2  0x0000000000420d66 in PerfUnwind::forwardMmapBuffer (this=0x7fffffffd4d0, mmapIt=..., mmapEnd=..., timestamp=43325196779752733) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfunwind.cpp:1008
#3  0x0000000000425f6b in PerfUnwind::flushEventBuffer (this=0x7fffffffd4d0, desiredBufferSize=9772) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfunwind.cpp:1113
PerfUnwind::MissingElfFile: Could not find ELF file for 64/ld-2.17.so. This can break stack unwinding and lead to missing symbols.
#0  PerfSymbolTable::findFile (this=0x4d7d30, path="64/libc-2.17.so", fileName="libc-2.17.so", buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:162
#1  0x0000000000439aae in PerfSymbolTable::registerElf (this=0x4d7d30, mmap=..., buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:209
#2  0x0000000000420d66 in PerfUnwind::forwardMmapBuffer (this=0x7fffffffd4d0, mmapIt=..., mmapEnd=..., timestamp=43325196779752733) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfunwind.cpp:1008
#3  0x0000000000425f6b in PerfUnwind::flushEventBuffer (this=0x7fffffffd4d0, desiredBufferSize=9772) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfunwind.cpp:1113
PerfUnwind::MissingElfFile: Could not find ELF file for 64/libc-2.17.so. This can break stack unwinding and lead to missing symbols.
#0  PerfSymbolTable::findFile (this=0x4d7d30, path="64/libc-2.17.so", fileName="libc-2.17.so", buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:162
#1  0x0000000000439aae in PerfSymbolTable::registerElf (this=0x4d7d30, mmap=..., buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:209
#2  0x0000000000420d66 in PerfUnwind::forwardMmapBuffer (this=0x7fffffffd4d0, mmapIt=..., mmapEnd=..., timestamp=43325196779752733) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfunwind.cpp:1008
#3  0x0000000000425f6b in PerfUnwind::flushEventBuffer (this=0x7fffffffd4d0, desiredBufferSize=9772) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfunwind.cpp:1113
PerfUnwind::MissingElfFile: Could not find ELF file for 64/libc-2.17.so. This can break stack unwinding and lead to missing symbols.
#0  PerfSymbolTable::findFile (this=0x4d7d30, path="64/libc-2.17.so", fileName="libc-2.17.so", buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:162
#1  0x0000000000439aae in PerfSymbolTable::registerElf (this=0x4d7d30, mmap=..., buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:209
#2  0x0000000000420d66 in PerfUnwind::forwardMmapBuffer (this=0x7fffffffd4d0, mmapIt=..., mmapEnd=..., timestamp=43325196779752733) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfunwind.cpp:1008
#3  0x0000000000425f6b in PerfUnwind::flushEventBuffer (this=0x7fffffffd4d0, desiredBufferSize=9772) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfunwind.cpp:1113
PerfUnwind::MissingElfFile: Could not find ELF file for 64/libc-2.17.so. This can break stack unwinding and lead to missing symbols.
#0  PerfSymbolTable::findFile (this=0x4d7d30, path="66dccb7324bc63b326940668f597b476868c0a.debug", fileName="66dccb7324bc63b326940668f597b476868c0a.debug", buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:162
#1  0x0000000000438a03 in PerfSymbolTable::findDebugInfo (this=0x4d7d30, module=<optimized out>, moduleName=<optimized out>, base=4194304, file=0x4f1ee0 "/bin/true", debugLink=<optimized out>, crc=1976527923, debugInfoFilename=0x4fdaf8) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:472
#2  0x000000000040df2f in ?? ()
#3  0x000000000045790c in ?? ()
#0  PerfSymbolTable::findFile (this=0x4d7d30, path="66dccb7324bc63b326940668f597b476868c0a.debug", fileName="66dccb7324bc63b326940668f597b476868c0a.debug", buildId=<QArrayData::shared_null+24> "") at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:162
#1  0x0000000000438a03 in PerfSymbolTable::findDebugInfo (this=0x4d7d30, module=<optimized out>, moduleName=<optimized out>, base=4194304, file=0x4f1ee0 "/bin/true", debugLink=<optimized out>, crc=1976527923, debugInfoFilename=0x4fdaf8) at /__w/hotspot/hotspot/3rdparty/perfparser/app/perfsymboltable.cpp:472
#2  0x000000000040df2f in ?? ()
#3  0x0000000000457e69 in ?? ()

... but again I have no idea where to cache the result.