Golang:什么是etext?

huangapple go评论75阅读模式
英文:

Golang: What is etext?

问题

我开始对我的Go1.2代码进行分析,而排在首位的总是一个名为'etext'的东西。我搜索了一下,但除了它可能与Go协程的调用深度有关之外,没有找到太多关于它的信息。然而,我并没有使用任何Go协程,而且'etext'仍然占据了总执行时间的75%或更多。

(pprof) top20
总共:171个样本
128 74.9% 74.9% 128 74.9% etext

有人能解释一下这是什么,并且是否有任何方法可以减少其影响吗?

英文:

I've started to profile some of my Go1.2 code and the top item is always something named 'etext'. I've searched around but couldn't find much information about it other than it might relate to call depth in Go routines. However, I'm not using any Go routines and 'etext' is still taking up 75% or more of the total execution time.

(pprof) top20 
Total: 171 samples
    128  74.9%  74.9%      128  74.9% etext

Can anybody explain what this is and if there is any way to reduce the impact?

答案1

得分: 3

我遇到了同样的问题,然后我找到了这个解决方法:pprof在go 1.2中失效?。为了验证这是否真的是一个1.2的bug,我编写了以下的“hello world”程序:

package main

import (
    "fmt"
    "testing"
)

func BenchmarkPrintln(t *testing.B) {
    TestPrintln(nil)
}

func TestPrintln(t *testing.T) {
    for i := 0; i < 10000; i++ {
        fmt.Println("hello " + "world!")
    }
}

如你所见,它只调用了fmt.Println

你可以使用go test -c .编译它,
使用./test.test -test.bench . -test.cpuprofile=test.prof运行它,
使用go tool pprof test.test test.prof查看结果。

(pprof) top10
Total: 36 samples
  18  50.0%  50.0%       18  50.0% syscall.Syscall
   8  22.2%  72.2%        8  22.2% etext
   4  11.1%  83.3%        4  11.1% runtime.usleep
   3   8.3%  91.7%        3   8.3% runtime.futex
   1   2.8%  94.4%        1   2.8% MHeap_AllocLocked
   1   2.8%  97.2%        1   2.8% fmt.(*fmt).padString
   1   2.8% 100.0%        1   2.8% os.epipecheck
   0   0.0% 100.0%        1   2.8% MCentral_Grow
   0   0.0% 100.0%       33  91.7% System
   0   0.0% 100.0%        3   8.3% _/home/xxiao/work/test.BenchmarkPrintln

上述结果是使用go 1.2.1得到的。
然后我使用go 1.1.1做了同样的事情,得到了以下结果:

(pprof) top10
Total: 10 samples
   2  20.0%  20.0%        2  20.0% scanblock
   1  10.0%  30.0%        1  10.0% fmt.(*pp).free
   1  10.0%  40.0%        1  10.0% fmt.(*pp).printField
   1  10.0%  50.0%        2  20.0% fmt.newPrinter
   1  10.0%  60.0%        2  20.0% os.(*File).Write
   1  10.0%  70.0%        1  10.0% runtime.MCache_Alloc
   1  10.0%  80.0%        1  10.0% runtime.exitsyscall
   1  10.0%  90.0%        1  10.0% sweepspan
   1  10.0% 100.0%        1  10.0% sync.(*Mutex).Lock
   0   0.0% 100.0%        6  60.0% _/home/xxiao/work/test.BenchmarkPrintln

你可以看到1.2.1的结果没有太多意义。Syscall和etext占用了大部分时间。而1.1.1的结果看起来是正确的。

所以我相信这确实是一个1.2.1的bug。我在我的实际项目中切换到了使用go 1.1.1,并对分析结果感到满意。

英文:

I hit the same problem then I found this: pprof broken in go 1.2?. To verify that it is really a 1.2 bug I wrote the following "hello world" program:

package main

import (
    &quot;fmt&quot;
    &quot;testing&quot;
)

func BenchmarkPrintln( t *testing.B ){
    TestPrintln( nil )
}

func TestPrintln( t *testing.T ){
    for i := 0; i &lt; 10000; i++ {
            fmt.Println(&quot;hello &quot; + &quot; world!&quot;)
    }
}

As you can see it only calls fmt.Println.

You can compile this with “go test –c .”
Run with “./test.test -test.bench . -test.cpuprofile=test.prof”
See the result with “go tool pprof test.test test.prof”

(pprof) top10
Total: 36 samples
  18  50.0%  50.0%       18  50.0% syscall.Syscall
   8  22.2%  72.2%        8  22.2% etext
   4  11.1%  83.3%        4  11.1% runtime.usleep
   3   8.3%  91.7%        3   8.3% runtime.futex
   1   2.8%  94.4%        1   2.8% MHeap_AllocLocked
   1   2.8%  97.2%        1   2.8% fmt.(*fmt).padString
   1   2.8% 100.0%        1   2.8% os.epipecheck
   0   0.0% 100.0%        1   2.8% MCentral_Grow
   0   0.0% 100.0%       33  91.7% System
   0   0.0% 100.0%        3   8.3% _/home/xxiao/work/test.BenchmarkPrintln

The above result is got using go 1.2.1
Then I did the same thing using go 1.1.1 and got the following result:

(pprof) top10
Total: 10 samples
   2  20.0%  20.0%        2  20.0% scanblock
   1  10.0%  30.0%        1  10.0% fmt.(*pp).free
   1  10.0%  40.0%        1  10.0% fmt.(*pp).printField
   1  10.0%  50.0%        2  20.0% fmt.newPrinter
   1  10.0%  60.0%        2  20.0% os.(*File).Write
   1  10.0%  70.0%        1  10.0% runtime.MCache_Alloc
   1  10.0%  80.0%        1  10.0% runtime.exitsyscall
   1  10.0%  90.0%        1  10.0% sweepspan
   1  10.0% 100.0%        1  10.0% sync.(*Mutex).Lock
   0   0.0% 100.0%        6  60.0% _/home/xxiao/work/test.BenchmarkPrintln

You can see that the 1.2.1 result does not make much sense. Syscall and etext takes most of the time. And the 1.1.1 result looks right.

So I'm convinced that it is really a 1.2.1 bug. And I switched to use go 1.1.1 in my real project and I'm satisfied with the profiling result now.

答案2

得分: 2

我认为Mathias Urlichs在你的cgo代码中缺少调试符号方面是正确的。值得注意的是,一些标准包如net和syscall使用了cgo。

如果你滚动到这个文档的底部,找到名为"Caveats"的部分,你会看到第三个要点说...

如果程序链接了一个没有足够符号信息编译的库,所有与该库相关的样本可能会被计入该库之前程序中找到的最后一个符号。这将人为地增加该符号的计数。

我不能百分之百确定这就是发生的情况,但我敢打赌这就是为什么etext看起来如此繁忙的原因(换句话说,etext是一组各种函数,没有足够的信息供pprof进行正确分析)。

英文:

I think Mathias Urlichs is right regarding missing debugging symbols in your cgo code. Its worth noting that some standard pkgs like net and syscall make use of cgo.

If you scroll down to the bottom of this doc to the section called Caveats, you can see that the third bullet says...
>If the program linked in a library that was not compiled with enough symbolic information, all samples associated with the library may be charged to the last symbol found in the program before the library. This will artificially inflate the count for that symbol.

I'm not 100% positive this is what's happening but i'm betting that this is why etext appears to be so busy (in other words etext is a collection of various functions that doesn't have enough information for pprof to analysis properly.).

huangapple
  • 本文由 发表于 2014年1月23日 14:33:19
  • 转载请务必保留本文链接:https://go.coder-hub.com/21301018.html
匿名

发表评论

匿名网友

:?: :razz: :sad: :evil: :!: :smile: :oops: :grin: :eek: :shock: :???: :cool: :lol: :mad: :twisted: :roll: :wink: :idea: :arrow: :neutral: :cry: :mrgreen:

确定