pprof icon indicating copy to clipboard operation
pprof copied to clipboard

Tests fail on CentOS 6.9 (binutils is 2.20 where addr2line does not support -a flag)

Open nehaljwani opened this issue 7 years ago • 9 comments

xref: https://github.com/golang/go/issues/23888

What version of pprof are you using?

a74ae6fb3cd7047c79272e3ea0814b08154a2d3c

What operating system and processor architecture are you using?

CentOS 6.9, x86_64

What did you do?

Compiled go from source, tests failed, came to this repo, tried running the tests, was able to reproduce the exact same failure.

What did you expect to see?

It'd be great if the tests had passed!

What did you see instead?

The following tests failed:

--- FAIL: TestObjFile (0.02s)
    --- FAIL: TestObjFile/fake_mapping (0.01s)
        binutils_test.go:252: SourceLine: unexpected error write |1: broken pipe
    --- FAIL: TestObjFile/fixed_load_address (0.01s)
        binutils_test.go:252: SourceLine: unexpected error write |1: broken pipe
    --- FAIL: TestObjFile/simulated_ASLR_address (0.01s)
        binutils_test.go:252: SourceLine: unexpected error write |1: broken pipe

Why do these tests fail?

The code at https://github.com/google/pprof/blob/a74ae6fb3cd7047c79272e3ea0814b08154a2d3c/internal/binutils/addr2liner.go#L92 assumes that the -a flag is available to the binary addr2line, which is available if the binutils version is >=2.21 ; but the latest version available on CentOS 6.9 is 2.20

nehaljwani avatar Mar 21 '18 18:03 nehaljwani

ok cmd/pack 2.860s ok cmd/trace 0.060s --- FAIL: TestDisasm (0.01s) binutils_test.go:189: Disasm: unexpected error [/home/kelvin/go/pkg/tool/linux_amd64/objdump -d -C --no-show-raw-insn -l --start-address=0x0 --stop-address=0xffffffffffffffff testdata/hello]: exit status 2 --- FAIL: TestObjFile (0.09s) binutils_test.go:231: SourceLine: unexpected error write |1: broken pipe FAIL FAIL cmd/vendor/github.com/google/pprof/internal/binutils 0.121s ok cmd/vendor/github.com/google/pprof/internal/driver 12.305s ok cmd/vendor/github.com/google/pprof/internal/elfexec 0.011s ok cmd/vendor/github.com/google/pprof/internal/graph 0.019s ok cmd/vendor/github.com/google/pprof/internal/measurement 0.024s --- FAIL: TestWebList (0.04s) source_test.go:36: weblist output does not contain 'callq':

	<!DOCTYPE html>
	<html>
	<head>
	<meta charset="UTF-8">
	<title>Pprof listing</title>
	<style type="text/css">
	body {
	font-family: sans-serif;
	}
	h1 {
	  font-size: 1.5em;
	  margin-bottom: 4px;
	}
	.legend {
	  font-size: 1.25em;
	}
	.line, .nop, .unimportant {
	  color: #aaaaaa;
	}
	.inlinesrc {
	  color: #000066;
	}
	.deadsrc {
	cursor: pointer;
	}
	.deadsrc:hover {
	background-color: #eeeeee;
	}
	.livesrc {
	color: #0000ff;
	cursor: pointer;
	}
	.livesrc:hover {
	background-color: #eeeeee;
	}
	.asm {
	color: #008800;
	display: none;
	}
	</style>
	<script type="text/javascript">
	function pprof_toggle_asm(e) {
	  var target;
	  if (!e) e = window.event;
	  if (e.target) target = e.target;
	  else if (e.srcElement) target = e.srcElement;
	
	  if (target) {
	    var asm = target.nextSibling;
	    if (asm && asm.className == "asm") {
	      asm.style.display = (asm.style.display == "block" ? "" : "block");
	      e.preventDefault();
	      return false;
	    }
	  }
	}
	</script>
	</head>
	<body>
	
	<div class="legend">File: sample.bin<br>
	Time: Sep 30, 2017 at 4:57am (CST)<br>
	Duration: 2s, Total samples = 1.76s (87.91%)<br>Total: 1.76s</div><h1>math.Abs</h1>/usr/lib/google-golang/src/math/abs.go
	<pre onClick="pprof_toggle_asm(event)">
	  Total:       0.11s      0.11s (flat, cum)  6.25%
	</pre>
	<h1>main.busyLoop</h1>testdata/sample/sample.go
	<pre onClick="pprof_toggle_asm(event)">
	  Total:       0.15s      1.76s (flat, cum)   100%
	<span class=line>     27</span> <span class=nop>           .          .           } </span>
	<span class=line>     28</span> <span class=nop>           .          .            </span>
	<span class=line>     29</span> <span class=nop>           .          .           func busyLoop() { </span>
	<span class=line>     30</span> <span class=nop>           .          .           	m := make(map[int]int) </span>
	<span class=line>     31</span> <span class=nop>           .          .           	for i := 0; i &lt; 1000000; i++ { </span>
	<span class=line>     32</span> <span class=nop>           .      0.13s           		m[i] = i + 10 </span>
	<span class=line>     33</span> <span class=nop>           .          .           	} </span>
	<span class=line>     34</span> <span class=nop>           .          .           	var sum float64 </span>
	<span class=line>     35</span> <span class=nop>       0.05s      0.05s           	for i := 0; i &lt; 100; i++ { </span>
	<span class=line>     36</span> <span class=nop>       0.05s      1.42s           		for _, v := range m { </span>
	<span class=line>     37</span> <span class=nop>       0.05s      0.16s           			sum += math.Abs(float64(v)) </span>
	<span class=line>     38</span> <span class=nop>           .          .           		} </span>
	<span class=line>     39</span> <span class=nop>           .          .           	} </span>
	<span class=line>     40</span> <span class=nop>           .          .           	fmt.Println(&#34;Sum&#34;, sum) </span>
	<span class=line>     41</span> <span class=nop>           .          .           } </span>
	</pre>
	
	</body>
	</html>
	

FAIL FAIL cmd/vendor/github.com/google/pprof/internal/report 0.053s ok cmd/vendor/github.com/google/pprof/internal/symbolizer 0.016s ok cmd/vendor/github.com/google/pprof/internal/symbolz 0.021s ok cmd/vendor/github.com/google/pprof/profile 0.049s ok cmd/vendor/github.com/ianlancetaylor/demangle 0.024s ok cmd/vendor/golang.org/x/arch/arm/armasm 0.016s ok cmd/vendor/golang.org/x/arch/arm64/arm64asm 0.067s ok cmd/vendor/golang.org/x/arch/ppc64/ppc64asm 0.028s ok cmd/vendor/golang.org/x/arch/x86/x86asm 0.147s ok cmd/vet 4.167s ok cmd/vet/internal/cfg 0.041s 2018/07/14 10:33:43 Failed: exit status 1

bsed avatar Jul 14 '18 02:07 bsed

The only way to work around this problem (On CentOS 6) is to:

wget http://people.centos.org/tru/devtools-2/devtools-2.repo -O /etc/yum.repos.d/devtools-2.repo
yum install -y devtoolset-2-binutils
scl enable devtoolset-2 bash

And then build and run the tests for pprof

nehaljwani avatar Jul 14 '18 04:07 nehaljwani

@nehaljwani what is your version of GCC ? i will try in xubuntu18.10

bsed avatar Jul 16 '18 01:07 bsed

@bsed The problem is not with the version of GCC, but with the version of binutils which provides the command: addr2line. You just need binutils >=2.21

nehaljwani avatar Jul 16 '18 05:07 nehaljwani

kelvin@~$ sudo apt install binutils
Reading package lists... Done
Building dependency tree       
Reading state information... Done
binutils is already the newest version (2.30-20ubuntu2~18.04).
0 upgraded, 0 newly installed, 0 to remove and 1 not upgraded.

bsed avatar Jul 16 '18 13:07 bsed

kelvin@src$ ./all.bash Building Go cmd/dist using /home/kelvin/go1.4. Building Go toolchain1 using /home/kelvin/go1.4. Building Go bootstrap cmd/go (go_bootstrap) using Go toolchain1. Building Go toolchain2 using go_bootstrap and Go toolchain1. Building Go toolchain3 using go_bootstrap and Go toolchain2. Building packages and commands for linux/amd64.

Testing packages.

ok archive/tar 0.119s ok archive/zip 3.005s ok bufio 0.087s ok bytes 0.301s ok compress/bzip2 0.190s ok compress/flate 1.356s ok compress/gzip 0.171s ok compress/lzw 0.112s ok compress/zlib 0.021s ok container/heap 0.007s ok container/list 0.001s ok container/ring 0.011s ok context 0.978s ok crypto 0.002s ok crypto/aes 0.024s ok crypto/cipher 0.022s ok crypto/des 0.021s ok crypto/dsa 0.015s ok crypto/ecdsa 0.228s ok crypto/elliptic 0.041s ok crypto/hmac 0.024s ok crypto/internal/subtle 0.012s ok crypto/md5 0.005s ok crypto/rand 0.102s ok crypto/rc4 0.080s ok crypto/rsa 0.120s ok crypto/sha1 0.015s ok crypto/sha256 0.008s ok crypto/sha512 0.050s ok crypto/subtle 0.016s ok crypto/tls 0.806s ok crypto/x509 2.317s ok database/sql 0.557s ok database/sql/driver 0.002s ok debug/dwarf 0.655s ok debug/elf 0.481s ok debug/gosym 0.290s ok debug/macho 0.377s ok debug/pe 0.185s ok debug/plan9obj 0.006s ok encoding/ascii85 0.038s ok encoding/asn1 0.036s ok encoding/base32 0.034s ok encoding/base64 0.011s ok encoding/binary 0.033s ok encoding/csv 0.023s ok encoding/gob 0.088s ok encoding/hex 0.021s ok encoding/json 0.463s ok encoding/pem 0.022s ok encoding/xml 0.046s ok errors 0.008s ok expvar 0.004s ok flag 0.003s ok fmt 0.105s ok go/ast 0.036s ok go/build 2.672s ok go/constant 0.006s ok go/doc 0.444s ok go/format 0.006s ok go/importer 0.077s ok go/internal/gccgoimporter 0.621s ok go/internal/gcimporter 1.137s ok go/internal/srcimporter 0.969s ok go/parser 0.272s ok go/printer 0.518s ok go/scanner 0.026s ok go/token 0.031s ok go/types 2.135s ok hash 0.039s ok hash/adler32 0.020s ok hash/crc32 0.005s ok hash/crc64 0.007s ok hash/fnv 0.007s ok html 0.011s ok html/template 0.037s ok image 0.715s ok image/color 0.019s ok image/draw 0.052s ok image/gif 0.686s ok image/jpeg 0.467s ok image/png 0.280s ok index/suffixarray 0.032s ok internal/cpu 0.017s ok internal/poll 0.023s ok internal/singleflight 0.012s ok internal/trace 2.403s ok io 0.035s ok io/ioutil 1.208s ok log 0.003s ok log/syslog 1.223s ok math 0.015s ok math/big 2.337s ok math/bits 0.008s ok math/cmplx 0.013s ok math/rand 0.305s ok mime 0.052s ok mime/multipart 0.563s ok mime/quotedprintable 0.166s ok net 2.474s ok net/http 3.504s ok net/http/cgi 0.485s ok net/http/cookiejar 0.052s ok net/http/fcgi 0.018s ok net/http/httptest 0.067s ok net/http/httptrace 0.020s ok net/http/httputil 0.057s ok net/http/internal 0.016s ok net/http/pprof 2.012s ok net/internal/socktest 0.001s ok net/mail 0.003s ok net/rpc 0.038s ok net/rpc/jsonrpc 0.008s ok net/smtp 0.012s ok net/textproto 0.010s ok net/url 0.004s ok os 1.729s ok os/exec 0.740s ok os/signal 4.808s ok os/user 0.002s ok path 0.002s ok path/filepath 0.074s ok reflect 0.181s ok regexp 0.379s ok regexp/syntax 0.542s ok runtime 60.323s ok runtime/debug 0.080s ok runtime/internal/atomic 0.088s ok runtime/internal/sys 0.031s ok runtime/pprof 9.971s ok runtime/pprof/internal/profile 0.011s ok runtime/trace 3.694s ok sort 0.073s ok strconv 0.668s ok strings 0.223s ok sync 0.309s ok sync/atomic 0.043s ok syscall 0.287s ok testing 0.791s ok testing/quick 0.100s ok text/scanner 0.004s ok text/tabwriter 0.006s ok text/template 0.398s ok text/template/parse 0.008s ok time 3.623s ok unicode 0.003s ok unicode/utf16 0.021s ok unicode/utf8 0.006s ok vendor/golang_org/x/crypto/chacha20poly1305 0.060s ok vendor/golang_org/x/crypto/cryptobyte 0.002s ok vendor/golang_org/x/crypto/curve25519 0.019s ok vendor/golang_org/x/crypto/internal/chacha20 0.062s ok vendor/golang_org/x/crypto/poly1305 0.014s ok vendor/golang_org/x/net/dns/dnsmessage 0.047s ok vendor/golang_org/x/net/http/httpguts 0.006s ok vendor/golang_org/x/net/http/httpproxy 0.005s ok vendor/golang_org/x/net/http2/hpack 0.003s ok vendor/golang_org/x/net/idna 0.003s ok vendor/golang_org/x/net/nettest 1.117s ok vendor/golang_org/x/text/transform 0.020s ok vendor/golang_org/x/text/unicode/norm 0.002s ok cmd/addr2line 1.518s ok cmd/api 1.436s ok cmd/asm/internal/asm 2.460s ok cmd/asm/internal/lex 0.010s ok cmd/compile 10.677s ok cmd/compile/internal/gc 26.194s ok cmd/compile/internal/ssa 1.577s ok cmd/compile/internal/syntax 0.043s ok cmd/compile/internal/test 0.034s [no tests to run] ok cmd/compile/internal/types 0.038s ok cmd/cover 7.904s ok cmd/doc 0.144s ok cmd/fix 5.595s ok cmd/go 97.434s ok cmd/go/internal/cache 0.246s ok cmd/go/internal/dirhash 0.002s ok cmd/go/internal/generate 0.036s ok cmd/go/internal/get 0.016s ok cmd/go/internal/imports 0.045s ok cmd/go/internal/load 0.007s ok cmd/go/internal/modconv 0.014s ok cmd/go/internal/modfetch 0.008s ok cmd/go/internal/modfetch/gitrepo 2.822s ok cmd/go/internal/modfile 0.317s ok cmd/go/internal/module 0.001s ok cmd/go/internal/mvs 0.006s ok cmd/go/internal/search 0.003s ok cmd/go/internal/semver 0.002s ok cmd/go/internal/web2 0.048s ok cmd/go/internal/work 0.050s ok cmd/gofmt 0.120s ok cmd/internal/buildid 0.244s ok cmd/internal/dwarf 0.014s ok cmd/internal/edit 0.007s ok cmd/internal/goobj 0.864s ok cmd/internal/obj 0.009s ok cmd/internal/obj/arm64 0.056s ok cmd/internal/obj/x86 0.545s ok cmd/internal/objabi 0.002s ok cmd/internal/src 0.007s ok cmd/internal/test2json 0.249s ok cmd/link 2.505s ok cmd/link/internal/ld 47.635s ok cmd/nm 5.185s ok cmd/objdump 3.195s ok cmd/pack 3.529s ok cmd/trace 0.058s --- FAIL: TestDisasm (0.04s) binutils_test.go:195: Disasm: unexpected error [/home/kelvin/go/pkg/tool/linux_amd64/objdump -d -C --no-show-raw-insn -l --start-address=0x0 --stop-address=0xffffffffffffffff testdata/exe_linux_64]: exit status 2 --- FAIL: TestObjFile (0.25s) --- FAIL: TestObjFile/fake_mapping (0.11s) binutils_test.go:252: SourceLine: unexpected error write |1: broken pipe --- FAIL: TestObjFile/fixed_load_address (0.07s) binutils_test.go:252: SourceLine: unexpected error write |1: broken pipe --- FAIL: TestObjFile/simulated_ASLR_address (0.07s) binutils_test.go:252: SourceLine: unexpected error write |1: broken pipe FAIL FAIL cmd/vendor/github.com/google/pprof/internal/binutils 0.363s ok cmd/vendor/github.com/google/pprof/internal/driver 1.006s ok cmd/vendor/github.com/google/pprof/internal/elfexec 0.020s ok cmd/vendor/github.com/google/pprof/internal/graph 0.007s ok cmd/vendor/github.com/google/pprof/internal/measurement 0.027s --- FAIL: TestWebList (0.19s) source_test.go:37: weblist output does not contain 'callq':

    <!DOCTYPE html>
    <html>
    <head>
    <meta charset="UTF-8">
    <title>Pprof listing</title>
    <style type="text/css">
    body {
    font-family: sans-serif;
    }
    h1 {
      font-size: 1.5em;
      margin-bottom: 4px;
    }
    .legend {
      font-size: 1.25em;
    }
    .line, .nop, .unimportant {
      color: #aaaaaa;
    }
    .inlinesrc {
      color: #000066;
    }
    .deadsrc {
    cursor: pointer;
    }
    .deadsrc:hover {
    background-color: #eeeeee;
    }
    .livesrc {
    color: #0000ff;
    cursor: pointer;
    }
    .livesrc:hover {
    background-color: #eeeeee;
    }
    .asm {
    color: #008800;
    display: none;
    }
    </style>
    <script type="text/javascript">
    function pprof_toggle_asm(e) {
      var target;
      if (!e) e = window.event;
      if (e.target) target = e.target;
      else if (e.srcElement) target = e.srcElement;
    
      if (target) {
        var asm = target.nextSibling;
        if (asm && asm.className == "asm") {
          asm.style.display = (asm.style.display == "block" ? "" : "block");
          e.preventDefault();
          return false;
        }
      }
    }
    </script>
    </head>
    <body>
    
    <div class="legend">File: sample.bin<br>
    Time: Sep 30, 2017 at 4:57am (CST)<br>
    Duration: 2s, Total samples = 1.76s (87.91%)<br>Total: 1.76s</div><h2>math.Abs</h2><p class="filename">/usr/lib/google-golang/src/math/abs.go</p>
    <pre onClick="pprof_toggle_asm(event)">
      Total:       0.11s      0.11s (flat, cum)  6.25%
    </pre>
    <h2>main.busyLoop</h2><p class="filename">testdata/sample/sample.go</p>
    <pre onClick="pprof_toggle_asm(event)">
      Total:       0.15s      1.76s (flat, cum)   100%
    <span class=line>     27</span> <span class=nop>           .          .           } </span>
    <span class=line>     28</span> <span class=nop>           .          .            </span>
    <span class=line>     29</span> <span class=nop>           .          .           func busyLoop() { </span>
    <span class=line>     30</span> <span class=nop>           .          .           	m := make(map[int]int) </span>
    <span class=line>     31</span> <span class=nop>           .          .           	for i := 0; i &lt; 1000000; i++ { </span>
    <span class=line>     32</span> <span class=nop>           .      0.13s           	m[i] = i + 10 </span>
    <span class=line>     33</span> <span class=nop>           .          .           	} </span>
    <span class=line>     34</span> <span class=nop>           .          .           	var sum float64 </span>
    <span class=line>     35</span> <span class=nop>       0.05s      0.05s           	for i := 0; i &lt; 100; i++ { </span>
    <span class=line>     36</span> <span class=nop>       0.05s      1.42s           	for _, v := range m { </span>
    <span class=line>     37</span> <span class=nop>       0.05s      0.16s           	sum += math.Abs(float64(v)) </span>
    <span class=line>     38</span> <span class=nop>           .          .           	} </span>
    <span class=line>     39</span> <span class=nop>           .          .           	} </span>
    <span class=line>     40</span> <span class=nop>           .          .           	fmt.Println(&#34;Sum&#34;, sum) </span>
    <span class=line>     41</span> <span class=nop>           .          .           } </span>
    </pre>
    
    </body>
    </html>
    

FAIL FAIL cmd/vendor/github.com/google/pprof/internal/report 0.247s ok cmd/vendor/github.com/google/pprof/internal/symbolizer 0.037s ok cmd/vendor/github.com/google/pprof/internal/symbolz 0.039s ok cmd/vendor/github.com/google/pprof/profile 0.172s ok cmd/vendor/github.com/ianlancetaylor/demangle 0.157s ok cmd/vendor/golang.org/x/arch/arm/armasm 0.066s ok cmd/vendor/golang.org/x/arch/arm64/arm64asm 0.216s ok cmd/vendor/golang.org/x/arch/ppc64/ppc64asm 0.036s ok cmd/vendor/golang.org/x/arch/x86/x86asm 0.163s ok cmd/vendor/golang.org/x/crypto/ssh/terminal 0.005s ok cmd/vendor/golang.org/x/sys/unix 0.392s ok cmd/vet 6.219s ok cmd/vet/internal/cfg 0.031s 2018/07/16 21:33:45 Failed: exit status 1

bsed avatar Jul 16 '18 13:07 bsed

I'm able to reproduce the TestObjFile failure on a Centos 6 GCE instance. Haven't been able to reproduce other test failures.

nolanmar511 avatar Jul 17 '18 20:07 nolanmar511

@nolanmar511 thank you! ^.^

bsed avatar Jul 18 '18 00:07 bsed

xubuntu apt install pkg-config

bsed avatar Jan 13 '19 03:01 bsed