3

I am using perf profiling golang program running in docker container

I record data with

# perf record -o "perf.data" -p `PID of the container`

and read it with

# perf report -i "perf.data"

Everything is ok at the first time ,I get report like this (my elf binary name is bin) :

Samples: 15  of event 'cpu-clock', Event count (approx.): 3750000
Overhead  Command  Shared Object      Symbol
  53.33%  bin      bin                [.] runtime.scanobject
   6.67%  bin      [kernel.kallsyms]  [k] __schedule
   6.67%  bin      bin                [.] runtime.getStackMap
   6.67%  bin      bin                [.] runtime.getempty
   6.67%  bin      bin                [.] runtime.gopark
   6.67%  bin      bin                [.] runtime.greyobject
   6.67%  bin      bin                [.] runtime.scanblock
   6.67%  bin      bin                [.] runtime.unlock

But after I stop the container and run the report command again ,all symbols in my program become hex address (kernel symbol still resolved)

Samples: 15  of event 'cpu-clock', Event count (approx.): 3750000
Overhead  Command  Shared Object      Symbol
  33.33%  bin      bin                [.] 0x000000000001f7ad
  13.33%  bin      bin                [.] 0x000000000001f7b0
   6.67%  bin      [kernel.kallsyms]  [k] __schedule
   6.67%  bin      bin                [.] 0x000000000000ac1a
   6.67%  bin      bin                [.] 0x000000000001f497
   6.67%  bin      bin                [.] 0x000000000001f7d6
   6.67%  bin      bin                [.] 0x000000000001fc82
   6.67%  bin      bin                [.] 0x00000000000242fd
   6.67%  bin      bin                [.] 0x0000000000035bf0
   6.67%  bin      bin                [.] 0x000000000004d5a9

I try to find the build id of the binary file but don't get any clue:

# perf buildid-list -i perf.data
38b62c386e959108a2ff514c04f7df8f39e443f9 [kernel.kallsyms]
78fa50e860a2bb2b44f03a6a0a6f99735a8b599b [vdso]

as @osgx 's suggestion I run command below

#perf script -D |grep PERF_RECORD_MMAP2|head
Failed to open /bin, continuing without symbols
0 0x2b98 [0x60]: PERF_RECORD_MMAP2 15956/15956: [0x400000(0x852000) @ 0 fc:01 656204 7434654850458070581]: r-xp /bin
0 0x2bf8 [0x60]: PERF_RECORD_MMAP2 15956/15956: [0x7ffca95a8000(0x2000) @ 0 00:00 0 7434654850458070581]: r-xp [vdso]
0 0x2c58 [0x68]: PERF_RECORD_MMAP2 15956/15956: [0xffffffffff600000(0x1000) @ 0 00:00 0 7434654850458070581]: r-xp [vsyscall]
0 0x2ce8 [0x60]: PERF_RECORD_MMAP2 15956/16020: [0x400000(0x852000) @ 0 fc:01 656204 7434654850458070581]: r-xp /bin
0 0x2d48 [0x60]: PERF_RECORD_MMAP2 15956/16020: [0x7ffca95a8000(0x2000) @ 0 00:00 0 7434654850458070581]: r-xp [vdso]
0 0x2da8 [0x68]: PERF_RECORD_MMAP2 15956/16020: [0xffffffffff600000(0x1000) @ 0 00:00 0 7434654850458070581]: r-xp [vsyscall]
0 0x2e38 [0x60]: PERF_RECORD_MMAP2 15956/16021: [0x400000(0x852000) @ 0 fc:01 656204 7434654850458070581]: r-xp /bin
0 0x2e98 [0x60]: PERF_RECORD_MMAP2 15956/16021: [0x7ffca95a8000(0x2000) @ 0 00:00 0 7434654850458070581]: r-xp [vdso]
0 0x2ef8 [0x68]: PERF_RECORD_MMAP2 15956/16021: [0xffffffffff600000(0x1000) @ 0 00:00 0 7434654850458070581]: r-xp [vsyscall]
0 0x2f88 [0x60]: PERF_RECORD_MMAP2 15956/16022: [0x400000(0x852000) @ 0 fc:01 656204 7434654850458070581]: r-xp /bin

Why is that happen? Is there any solution let perf resolve symbol after container stop ?

Here is my environment:

perf version 4.15.18
Ubuntu 18.04 LTS (GNU/Linux 4.15.0-23-generic x86_64)
docker version 18.06.1-ce

My container Dockerfile

FROM scratch
COPY artifact/bin /
ENTRYPOINT ["/bin"]
PE Xie
  • 383
  • 3
  • 9
  • Can you show the output from `perf report` before and after stopping the container ? – Arnabjyoti Kalita Mar 29 '20 at 04:09
  • 1
    Also please provide additional details like the `Dockerfile` of the container and the golang program you are profiling. – Arnabjyoti Kalita Mar 29 '20 at 04:40
  • @ArnabjyotiKalita I have add the `perf report` output and my container `Dockerfile` in the question , my go program is a http server. – PE Xie Mar 30 '20 at 05:48
  • @PEXie, please, do `perf script -D |grep PERF_RECORD_MMAP2|head ` on you perf.data to find out how the binary file path was recorded into perf.data file. I think perf tool did record some path which is not correct or not accessible after container stop. I do not know any option to point `perf report` to correct binary, but it is possible to recompile perf tool from https://mirrors.edge.kernel.org/pub/linux/kernel/tools/perf/ (any version) and hack its binary searching functions. – osgx Mar 31 '20 at 10:11
  • @osgx I have update my question and add the command output, seems like perf record the path inside the container namespace. hack the binary searching functions can be a solution, but its really hard for me, I will make a try if there is no other way ,thanks for your suggestion – PE Xie Apr 01 '20 at 03:15
  • 1
    @PEXie, there is a suggestion: put the artifact binary into the container at the path which will be equal string to real placement of the binary. For example, if you have the binary as /home/pexie/project1/artifact/bin; in dockerfile make the directory /home/pexie/project1/artifact/ and put the binary into this directory. It may work without perf source hacking. – osgx Apr 01 '20 at 05:37
  • How did you start the container? Did you mount any host volumes etc.? Please provide the command you used to start the container. – Arnabjyoti Kalita Apr 03 '20 at 04:27
  • @osgx I did a test, it works. so perf hava a fallback binary file search logic ? I have to recompile my docker images now. – PE Xie Apr 03 '20 at 08:15
  • @ArnabjyotiKalita I start the container by docker-compose , I mount a config file in the container I think this doesn't matters. the start command is `docker-compose up -d` – PE Xie Apr 03 '20 at 08:21
  • Please someone answer this question. https://stackoverflow.com/questions/70660806/why-perf-report-does-not-show-function-names-in-the-second-run-when-used-in-d – user3784418 Mar 07 '22 at 16:30

1 Answers1

3

Why is that happen?

perf tool is doing some kind of searching for binary files. In perf.data there is mmap recorded (seen with perf script -D |grep PERF_RECORD_MMAP2|head command) with path of file mapped with EXEC permission. Main binary file is mapped too, but at moment of mapping the path was relative to the container. In container this file has /bin path as you put it with COPY artifact/bin /. But perf report is started outside the container and tries to resolve /bin path outside of container fs cgroup/namespace. In host system /bin is directory, not file. When you starting perf report while container is still running it may have some heuristics to get executable file with help of /proc/$PID/exe special fs, which probably has success in accessing of files inside container fs namespace.

Is there any solution let perf resolve symbol after container stop ?

I have not too beautiful suggestion (in comments): put the artifact binary into the container at the path which will be equal string to real placement of the binary. For example, if you have the binary as /home/pexie/project1/artifact/bin; in dockerfile create the directory /home/pexie/project1/artifact/ and put the binary into this directory.

osgx
  • 90,338
  • 53
  • 357
  • 513