pkg / profile

Simple profiling for Go
BSD 2-Clause "Simplified" License
2k stars 122 forks source link

Empty CPU Profile #16

Closed ianwalter closed 8 years ago

ianwalter commented 8 years ago

I'm trying to profile a simple application:

package main

import (
    "github.com/pkg/profile"
    "github.com/spf13/cobra"
    "strings"
)

/*
Tokenize TODO
*/
func Tokenize(text string) []string {
    return strings.Split(text, "\n")
}

func main() {
    profileCommand := &cobra.Command{
        Use: "profile",
        Run: func(cmd *cobra.Command, args []string) {
            defer profile.Start(profile.CPUProfile, profile.ProfilePath(".")).Stop()

            Tokenize("Hello\nWorld")
        },
    }

    rootCommand := &cobra.Command{Use: "bern"}
    rootCommand.AddCommand(profileCommand)
    rootCommand.Execute()
}

But when I look at the cpu.pprof file it simply contains ' and nothing else. What am I doing incorrectly?

davecheney commented 8 years ago

Maybe the program is not running long enough to generate useful profiling information. What happens if you use a program that does real work.

On 29 Nov 2015, at 17:37, Ian Walter notifications@github.com wrote:

I'm trying to profile a simple application:

package main

import ( "github.com/pkg/profile" "github.com/spf13/cobra" "strings" )

/ Tokenize TODO / func Tokenize(text string) []string { return strings.Split(text, "\n") }

func main() { profileCommand := &cobra.Command{ Use: "profile", Run: func(cmd *cobra.Command, args []string) { defer profile.Start(profile.CPUProfile, profile.ProfilePath(".")).Stop()

        Tokenize("Hello\nWorld")
    },
}

rootCommand := &cobra.Command{Use: "bern"}
rootCommand.AddCommand(profileCommand)
rootCommand.Execute()

} But when I look at the cpu.pprof file it simply contains ' and nothing else. What am I doing incorrectly?

— Reply to this email directly or view it on GitHub.

davisford commented 8 years ago

Hi @davecheney I have a similar problem. The memory and block profiles work ok for me, but

$ls -al cpu.pprof 
-rw-r--r--  1 davisford  staff  64 Apr  5 13:49 cpu.pprof
$cat cpu.pprof 
~/$

I don't necessarily have some way to peg the server I'm trying to profile (other than writing an expensive loop/func, but that isn't interesting for me to profile). I was able to instrument some things in the browser (it's a webapp) that caused some spikes up near the 30% mark, but still nothing in the cpu.pprof file. Is it possible to tune the threshold where it starts recording like you can with the memory?

EDIT -- for anyone else that arrives here, on a Mac, check if runtime/pprof has any issues on your platform. I'm guessing that might be the issue with my situation.

davecheney commented 8 years ago

@ianwalter i've not been able to reproduce this issue, and haven't had other reports of it. I'm keen to close this issue if you cannot reproduce it further.

tmrts commented 8 years ago

@davecheney I am able to reproduce this issue with the following main.go and go 1.6.2 in OSX 10.11 (contains the kernel fix for pprof) and Ubuntu 16.04

package main

import (
        "time"
        "github.com/pkg/profile"
)

func main() {
        defer profile.Start(profile.CPUProfile).Stop()

        for i := 0; i < 918231333 i++ {
                i *= 2
                i /= 2
        }

<-time.After(time.Second*3)

        for i := 0; i < 9182312232; i++ {
                i *= 2
                i /= 2
        }
}
davecheney commented 8 years ago

What happens if you remove the call to set block profile rate?

On Mon, 25 Jul 2016, 00:51 Tamer Tas notifications@github.com wrote:

@davecheney https://github.com/davecheney I am able to reproduce this issue with the following main.go and go 1.6.2

package main import ( "runtime" "github.com/davecheney/profile" ) func main() { runtime.SetBlockProfileRate(1)

defer profile.Start(profile.CPUProfile).Stop()

for i := 0; i < 9182319231998989889; i++ {
    i *= 2
    i /= 2
}

}

— You are receiving this because you were mentioned.

Reply to this email directly, view it on GitHub https://github.com/pkg/profile/issues/16#issuecomment-234781396, or mute the thread https://github.com/notifications/unsubscribe-auth/AAAcA9oQgfBnncRToJApyCSRRnBAYMEZks5qY3vqgaJpZM4Gq83x .

tmrts commented 8 years ago

@davecheney sorry for the confusion, but the first draft of my comment had the wrong code, which I fixed immediately. But since you're viewing it by e-mail, you saw the old version. I'm quoting my up-to-date comment here again:

@davecheney I am able to reproduce this issue with the following main.go and go 1.6.2 in OSX 10.11 (contains the kernel fix for pprof) and Ubuntu 16.04

package main

import (
        "time"
        "github.com/pkg/profile"
)

func main() {
        defer profile.Start(profile.CPUProfile).Stop()

        for i := 0; i < 918231333 i++ {
                i *= 2
                i /= 2
        }

<-time.After(time.Second*3)

        for i := 0; i < 9182312232; i++ {
                i *= 2
                i /= 2
        }
}
davecheney commented 8 years ago

I haven't had a chance to run your sample yet.

Which version of Go are you using? Is it possible that the conpiler has optimised away those loops leaving you with just the sleep?

On Mon, 25 Jul 2016, 17:51 Tamer Tas notifications@github.com wrote:

@davecheney https://github.com/davecheney sorry for the confusion, but the first draft of my comment had the wrong code, which I fixed immediately. But since you're viewing it by e-mail, you saw the old version. I'm quoting my up-to-date comment here again:

@davecheney https://github.com/davecheney I am able to reproduce this issue with the following main.go and go 1.6.2 in OSX 10.11 (contains the kernel fix for pprof) and Ubuntu 16.04

package main import ( "time" "github.com/davecheney/profile" ) func main() { defer profile.Start(profile.CPUProfile).Stop()

    for i := 0; i < 918231333 i++ {
            i *= 2
            i /= 2
    }

<-time.After(time.Second*3)

    for i := 0; i < 9182312232; i++ {
            i *= 2
            i /= 2
    }

}

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/pkg/profile/issues/16#issuecomment-234872618, or mute the thread https://github.com/notifications/unsubscribe-auth/AAAcA9abAqHYSoNgEYspQHWKy1q-lt27ks5qZGsAgaJpZM4Gq83x .

davecheney commented 8 years ago

"github.com/davecheney/profile"

You are using the old version of this package. Please use github.com/pkg/profile.

On Tue, Jul 26, 2016 at 8:14 AM, Dave Cheney dave@cheney.net wrote:

I haven't had a chance to run your sample yet.

Which version of Go are you using? Is it possible that the conpiler has optimised away those loops leaving you with just the sleep?

On Mon, 25 Jul 2016, 17:51 Tamer Tas notifications@github.com wrote:

@davecheney https://github.com/davecheney sorry for the confusion, but the first draft of my comment had the wrong code, which I fixed immediately. But since you're viewing it by e-mail, you saw the old version. I'm quoting my up-to-date comment here again:

@davecheney https://github.com/davecheney I am able to reproduce this issue with the following main.go and go 1.6.2 in OSX 10.11 (contains the kernel fix for pprof) and Ubuntu 16.04

package main import ( "time" "github.com/davecheney/profile" ) func main() { defer profile.Start(profile.CPUProfile).Stop()

    for i := 0; i < 918231333 i++ {
            i *= 2
            i /= 2
    }

<-time.After(time.Second*3)

    for i := 0; i < 9182312232; i++ {
            i *= 2
            i /= 2
    }

}

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/pkg/profile/issues/16#issuecomment-234872618, or mute the thread https://github.com/notifications/unsubscribe-auth/AAAcA9abAqHYSoNgEYspQHWKy1q-lt27ks5qZGsAgaJpZM4Gq83x .