Gwinel / gperftools

Automatically exported from code.google.com/p/gperftools
BSD 3-Clause "New" or "Revised" License
0 stars 0 forks source link

gperftools cpu profiler does not support multi process? #569

Closed GoogleCodeExporter closed 9 years ago

GoogleCodeExporter commented 9 years ago
What steps will reproduce the problem?
1. write a program that fork a child process
2. run it with CPUPROFILE enviornment variable
3. wait for the cpu profiler's output

the sample code will be pasted at the end of this post

What is the expected output? What do you see instead?
I wanna see both the parent and the child processes' profile result, but pprof 
can not generate correct result.

What version of the product are you using? On what operating system?
I have tried gperftools 2.0 and 2.1, on ubuntu 13.04 32-bit or 64-bit

Please provide any additional information below.

// main_cmd_argv.cpp

#include <stdio.h>
#include <stdlib.h>
#include <unistd.h>
#include <string.h>
#include <sys/types.h>
#include <sys/wait.h>
#include <gperftools/profiler.h>

int loop(int n) {
    int sum = 0;
    for (int i = 0; i < n; i++) {
        for (int j = 0; j < n; j++) {
            sum = i + j;
            if (sum %3 == 0) {
                sum /= 3;
            }
        }
    }
    return 0;
}

int main(int argc, char* argv[]) {

    printf("%s\n%s\n", getenv("CPUPROFILE"), getenv("CPUPROFILESIGNAL"));

    if (argc > 1 && strcmp(argv[1], "-s")==0) {
        // single process
        loop(100000);
        printf("stoped\n");
    } else if (argc > 1 && strcmp(argv[1], "-m")==0) {
        // multi process
        pid_t pid = fork();
        if (pid < 0) {
            printf("fork error\n");
            return -1;
        }
        if (pid == 0) {    
            loop(100000);
            printf("child stoped\n");
        } else if (pid > 0) {
            loop(10000);
            printf("father stoped\n");
            wait(NULL);
        }        
    }   

    return 0;
}

====================================================
// makefile

GPerfTools=/home/adenzhang/tools/gperftools

CCFLAGS=-fno-omit-frame-pointer -g -Wall

ALL_BINS=main_cmd_argv
all:$(ALL_BINS)

main_cmd_argv:main_cmd_argv.o
    g++ $(CCFLAGS) -o $@ $^ -L./ -L$(GPerfTools)/lib -Wl,-Bdynamic -lprofiler -lunwind

.cpp.o:
    g++ $(CCFLAGS) -c -I./ -I$(GPerfTools)/include -fPIC -o $@ $<
clean:
    rm -f $(ALL_BINS) *.o *.prof

========================================================
// shell command

$ make
g++ -fno-omit-frame-pointer -g -Wall -c -I./ 
-I/home/adenzhang/tools/gperftools/include -fPIC -o main_cmd_argv.o 
main_cmd_argv.cpp
g++ -fno-omit-frame-pointer -g -Wall -o main_cmd_argv main_cmd_argv.o -L./ 
-L/home/adenzhang/tools/gperftools/lib -Wl,-Bdynamic -lprofiler -lunwind
$ env CPUPROFILE=main_cmd_argv.prof ./main_cmd_argv -s
젩n_cmd_argv.prof
(null)
stoped
PROFILE: interrupts/evictions/bytes = 6686/3564/228416
$ /home/adenzhang/tools/gperftools/bin/pprof --text ./main_cmd_argv 
./main_cmd_argv.prof 
Using local file ./main_cmd_argv.
Using local file ./main_cmd_argv.prof.
Removing killpg from all stack traces.
Total: 6686 samples
    6686 100.0% 100.0%     6686 100.0% loop
       0   0.0% 100.0%     6686 100.0% __libc_start_main
       0   0.0% 100.0%     6686 100.0% _start
       0   0.0% 100.0%     6686 100.0% main
$ rm main_cmd_argv.prof 
$ env CPUPROFILE=main_cmd_argv.prof ./main_cmd_argv -m
젩n_cmd_argv.prof
(null)
father stoped
child stoped
PROFILE: interrupts/evictions/bytes = 0/0/64
PROFILE: interrupts/evictions/bytes = 68/36/2624
$ ls 
main_cmd_argv  main_cmd_argv.cpp  main_cmd_argv.o  main_cmd_argv.prof  Makefile
$ /home/adenzhang/tools/gperftools/bin/pprof --text ./main_cmd_argv 
./main_cmd_argv.prof 
Using local file ./main_cmd_argv.
Using local file ./main_cmd_argv.prof.
$

Original issue reported on code.google.com by mgl...@gmail.com on 27 Aug 2013 at 6:50

GoogleCodeExporter commented 9 years ago
Here's what I've sent via email:

My my understanding is that if you fork+exec _then_ you'll see separate 
profiles, and your case is _just_ fork. CPU profiler is started automatically 
and early. And it decides filename early as well which is before your code 
forks. So in your case both parent and child will have identical cpu profiler 
setup.

You can change your code to explicitly start profiling when it's ready (after 
fork) via ProfilerStart.

Or you can fix cpuprofiler itself to re-initialize it via atfork and send us 
patch. I think current code is actually broken in case like yours, because both 
parent and child will dump samples to same fd. Potentially interleaving bytes 
from those writes and thus producing broken profiles.

-------

With explicit ProfilerStart as workable approach I'm going to close the ticket.

Original comment by alkondratenko on 29 Aug 2013 at 1:08