Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Tests failing on workstation when run at HEAD #650

Closed
mhansen opened this issue Sep 22, 2021 · 6 comments · Fixed by #668
Closed

Tests failing on workstation when run at HEAD #650

mhansen opened this issue Sep 22, 2021 · 6 comments · Fixed by #668
Assignees
@chavey

Comments

@mhansen
Copy link
Contributor

mhansen commented Sep 22, 2021

What version of pprof are you using?

02619b876842e0d0afb5e5580d3a374dad740edb

What operating system and processor architecture are you using?

$ uname -a
Linux markhansen.syd.corp.google.com 5.10.40-1rodete2-amd64 #1 SMP Debian 5.10.40-1rodete2 (2021-06-22) x86_64 GNU/Linux

What did you do?

$ git checkout origin/master
$ go test ./...
?       github.com/google/pprof [no test files]
?       github.com/google/pprof/driver  [no test files]
ok      github.com/google/pprof/fuzz    (cached)
ok      github.com/google/pprof/internal/binutils       (cached)
ok      github.com/google/pprof/internal/driver (cached)
ok      github.com/google/pprof/internal/elfexec        (cached)
ok      github.com/google/pprof/internal/graph  (cached)
ok      github.com/google/pprof/internal/measurement    (cached)
?       github.com/google/pprof/internal/plugin [no test files]
?       github.com/google/pprof/internal/proftest       [no test files]
--- FAIL: TestWebList (0.21s)
    source_test.go:52: weblist output does not contain 'callq.*mapassign':

        <!DOCTYPE html>
        <html>
        <head>
        <meta charset="UTF-8">
        <title>Pprof listing</title>
        <style type="text/css">
        body #content{
        font-family: sans-serif;
        }
        h1 {
          font-size: 1.5em;
        }
        .legend {
          font-size: 1.25em;
        }
        .line, .nop, .unimportant {
          color: #aaaaaa;
        }
        .inlinesrc {
          color: #000066;
        }
        .livesrc {
        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 6:57am (AEST)<br>
        Duration: 2s, Total samples = 1.76s (87.91%)<br>Total: 1.76s</div><h2>main.busyLoop</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%
        <span class=line>     11</span> <span class=nop>           .          .           //    Abs(NaN) = NaN </span>
        <span class=line>     12</span> <span class=nop>           .          .           func Abs(x float64) float64 { </span>
        <span class=line>     13</span> <span class=nop>           .          .                 return Float64frombits(Float64bits(x) &amp;^ (1 &lt;&lt; 63)) </span>
        <span class=line>     14</span> <span class=nop>           .          .           } </span>
        <span class=line>     16</span> <span class=livesrc>       0.10s      0.10s           ??? </span><span class=asm>                   .          .   4b445f:     ucomisd %xmm1,%xmm2                                                          <span class=unimportant>abs.go:16</span>
                       0.10s      0.10s   4b4463:     jbe    4b4473 &lt;main.busyLoop+0x163&gt;                                          <span class=unimportant>abs.go:16</span>
                           .          .   4b4465:     movsd  0x4e22b(%rip),%xmm3        # 502698 &lt;$f64.8000000000000000&gt;           <span class=unimportant>abs.go:16</span>
        </span>
        <span class=line>     17</span> <span class=livesrc>           .          .           ??? </span><span class=asm>                   .          .   4b446d:     pxor   %xmm3,%xmm1                                                           <span class=unimportant>abs.go:17</span>
        </span>
        <span class=line>     19</span> <span class=livesrc>       0.01s      0.01s           ??? </span><span class=asm>               0.01s      0.01s   4b4473:     ucomisd %xmm2,%xmm1                                                          <span class=unimportant>abs.go:19</span>
                           .          .   4b4477:     jne    4b440f &lt;main.busyLoop+0xff&gt;                                           <span class=unimportant>abs.go:19</span>
                           .          .   4b4479:     jp     4b440f &lt;main.busyLoop+0xff&gt;                                           <span class=unimportant>abs.go:19</span>
                           .          .   4b447b:     xorps  %xmm1,%xmm1                                                           <span class=unimportant>abs.go:19</span>
        </span>
        </pre>
        <h2>main.busyLoop</h2><p class="filename">/usr/local/google/home/sanjay/go/src/github.com/google/pprof/internal/report/testdata/sample/sample.go</p>
        <pre onClick="pprof_toggle_asm(event)">
          Total:       0.15s      1.65s (flat, cum) 93.75%
        <span class=line>     24</span> <span class=nop>           .          .                 &#34;os&#34; </span>
        <span class=line>     25</span> <span class=nop>           .          .                 &#34;runtime/pprof&#34; </span>
        <span class=line>     26</span> <span class=nop>           .          .           ) </span>
        <span class=line>     27</span> <span class=nop>           .          .            </span>
        <span class=line>     28</span> <span class=nop>           .          .           var cpuProfile = flag.String(&#34;cpuprofile&#34;, &#34;&#34;, &#34;where to write cpu profile&#34;) </span>
        <span class=line>     29</span> <span class=livesrc>           .          .            </span><span class=asm>                   .          .   4b4310:     mov    %fs:0xfffffffffffffff8,%rcx                                           <span class=unimportant>sample.go:29</span>
                           .          .   4b4319:     lea    -0x128(%rsp),%rax                                                     <span class=unimportant>sample.go:29</span>
                           .          .   4b4321:     cmp    0x10(%rcx),%rax                                                       <span class=unimportant>sample.go:29</span>
                           .          .   4b4325:     jbe    4b45ac &lt;main.busyLoop+0x29c&gt;                                          <span class=unimportant>sample.go:29</span>
                           .          .   4b432b:     sub    $0x1a8,%rsp                                                           <span class=unimportant>sample.go:29</span>
                           .          .   4b4332:     mov    %rbp,0x1a0(%rsp)                                                      <span class=unimportant>sample.go:29</span>
                           .          .   4b433a:     lea    0x1a0(%rsp),%rbp                                                      <span class=unimportant>sample.go:29</span>
                                             ⋮
                           .          .   4b45ac:     call   451500 &lt;runtime.morestack_noctxt&gt;                                     <span class=unimportant>sample.go:29</span>
                           .          .   4b45b1:     jmp    4b4310 &lt;main.busyLoop&gt;                                                <span class=unimportant>sample.go:29</span>
                           .          .   4b45b6:     int3                                                                         <span class=unimportant>sample.go:29</span>
                           .          .   4b45b7:     int3                                                                         <span class=unimportant>sample.go:29</span>
                           .          .   4b45b8:     int3                                                                         <span class=unimportant>sample.go:29</span>
                           .          .   4b45b9:     int3                                                                         <span class=unimportant>sample.go:29</span>
                           .          .   4b45ba:     int3                                                                         <span class=unimportant>sample.go:29</span>
                           .          .   4b45bb:     int3                                                                         <span class=unimportant>sample.go:29</span>
                           .          .   4b45bc:     int3                                                                         <span class=unimportant>sample.go:29</span>
                           .          .   4b45bd:     int3                                                                         <span class=unimportant>sample.go:29</span>
                           .          .   4b45be:     int3                                                                         <span class=unimportant>sample.go:29</span>
                           .          .   4b45bf:     int3                                                                         <span class=unimportant>sample.go:29</span>
        </span>
        <span class=line>     30</span> <span class=livesrc>           .          .           func main() { </span><span class=asm>                   .          .   4b4342:     lea    0x110(%rsp),%rdi                                                      <span class=unimportant>sample.go:30</span>
                           .          .   4b434a:     xorps  %xmm0,%xmm0                                                           <span class=unimportant>sample.go:30</span>
                           .          .   4b434d:     add    $0xfffffffffffffff0,%rdi                                              <span class=unimportant>sample.go:30</span>
                           .          .   4b4351:     mov    %rbp,-0x10(%rsp)                                                      <span class=unimportant>sample.go:30</span>
                           .          .   4b4356:     lea    -0x10(%rsp),%rbp                                                      <span class=unimportant>sample.go:30</span>
                           .          .   4b435b:     call   453b80 &lt;runtime.duffzero+0x120&gt;                                       <span class=unimportant>sample.go:30</span>
                           .          .   4b4360:     mov    0x0(%rbp),%rbp                                                        <span class=unimportant>sample.go:30</span>
                           .          .   4b4364:     lea    0x58(%rsp),%rdi                                                       <span class=unimportant>sample.go:30</span>
                           .          .   4b4369:     add    $0xffffffffffffffd0,%rdi                                              <span class=unimportant>sample.go:30</span>
                           .          .   4b436d:     mov    %rbp,-0x10(%rsp)                                                      <span class=unimportant>sample.go:30</span>
                           .          .   4b4372:     lea    -0x10(%rsp),%rbp                                                      <span class=unimportant>sample.go:30</span>
                           .          .   4b4377:     call   453b62 &lt;runtime.duffzero+0x102&gt;                                       <span class=unimportant>sample.go:30</span>
                           .          .   4b437c:     mov    0x0(%rbp),%rbp                                                        <span class=unimportant>sample.go:30</span>
                           .          .   4b4380:     lea    0x1ca19(%rip),%rax        # 4d0da0 &lt;type.*+0x1bda0&gt;                   <span class=unimportant>sample.go:30</span>
                           .          .   4b4387:     mov    %rax,(%rsp)                                                           <span class=unimportant>sample.go:30</span>
                           .          .   4b438b:     movq   $0x0,0x8(%rsp)                                                        <span class=unimportant>sample.go:30</span>
                           .          .   4b4394:     lea    0x110(%rsp),%rcx                                                      <span class=unimportant>sample.go:30</span>
                           .          .   4b439c:     mov    %rcx,0x10(%rsp)                                                       <span class=unimportant>sample.go:30</span>
                           .          .   4b43a1:     lea    0x58(%rsp),%rcx                                                       <span class=unimportant>sample.go:30</span>
                           .          .   4b43a6:     mov    %rcx,0x18(%rsp)                                                       <span class=unimportant>sample.go:30</span>
                           .          .   4b43ab:     call   407f90 &lt;runtime.makemap&gt;                                              <span class=unimportant>sample.go:30</span>
                           .          .   4b43b0:     mov    0x20(%rsp),%rax                                                       <span class=unimportant>sample.go:30</span>
                           .          .   4b43b5:     mov    %rax,0xe8(%rsp)                                                       <span class=unimportant>sample.go:30</span>
                           .          .   4b43bd:     xor    %ecx,%ecx                                                             <span class=unimportant>sample.go:30</span>
        </span>
        <span class=line>     31</span> <span class=livesrc>           .          .             flag.Parse() </span><span class=asm>                   .          .   4b43bf:             jmp    4b43fc &lt;main.busyLoop+0xec&gt;                                   <span class=unimportant>sample.go:31</span>
                           .          .   4b43c1:             mov    %rcx,0x30(%rsp)                                               <span class=unimportant>sample.go:31</span>
                           .          .   4b43c6:             lea    0x1c9d3(%rip),%rdx        # 4d0da0 &lt;type.*+0x1bda0&gt;           <span class=unimportant>sample.go:31</span>
                                             ⋮
                           .          .   4b43f1:             inc    %rcx                                                          <span class=unimportant>sample.go:31</span>
                           .          .   4b43f4:             mov    0xe8(%rsp),%rax                                               <span class=unimportant>sample.go:31</span>
                           .          .   4b43fc:             cmp    $0xf4240,%rcx                                                 <span class=unimportant>sample.go:31</span>
                           .          .   4b4403:             jl     4b43c1 &lt;main.busyLoop+0xb1&gt;                                   <span class=unimportant>sample.go:31</span>
                           .          .   4b4405:             xor    %ecx,%ecx                                                     <span class=unimportant>sample.go:31</span>
                           .          .   4b4407:             xorps  %xmm0,%xmm0                                                   <span class=unimportant>sample.go:31</span>
        </span>
        <span class=line>     32</span> <span class=livesrc>           .      0.13s             f, err := os.Create(*cpuProfile) </span><span class=asm>                   .          .   4b43cd:             mov    %rdx,(%rsp)                                                   <span class=unimportant>sample.go:32</span>
                           .          .   4b43d1:             mov    %rax,0x8(%rsp)                                                <span class=unimportant>sample.go:32</span>
                           .          .   4b43d6:             mov    %rcx,0x10(%rsp)                                               <span class=unimportant>sample.go:32</span>
                           .      0.13s   4b43db:             call   40c210 &lt;runtime.mapassign_fast64&gt;                             <span class=unimportant>sample.go:32</span>
                           .          .   4b43e0:             mov    0x18(%rsp),%rax                                               <span class=unimportant>sample.go:32</span>
                           .          .   4b43e5:             mov    0x30(%rsp),%rcx                                               <span class=unimportant>sample.go:32</span>
                           .          .   4b43ea:             lea    0xa(%rcx),%rdx                                                <span class=unimportant>sample.go:32</span>
                           .          .   4b43ee:             mov    %rdx,(%rax)                                                   <span class=unimportant>sample.go:32</span>
        </span>
        <span class=line>     33</span> <span class=nop>           .          .                 if err != nil { </span>
        <span class=line>     34</span> <span class=nop>           .          .                         log.Fatal(&#34;could not create CPU profile: &#34;, err) </span>
        <span class=line>     35</span> <span class=livesrc>       0.05s      0.05s             } </span><span class=asm>                   .          .   4b440a:             jmp    4b4491 &lt;main.busyLoop+0x181&gt;                                  <span class=unimportant>sample.go:35</span>
                       0.05s      0.05s   4b440f:             movsd  %xmm1,0x48(%rsp)                                              <span class=unimportant>sample.go:35</span>
                           .          .   4b4415:             lea    0x140(%rsp),%rax                                              <span class=unimportant>sample.go:35</span>
                                             ⋮
                           .          .   4b4485:             lea    0x1(%rdx),%rcx                                                <span class=unimportant>sample.go:35</span>
                           .          .   4b4489:             mov    0xe8(%rsp),%rax                                               <span class=unimportant>sample.go:35</span>
                           .          .   4b4491:             cmp    $0x64,%rcx                                                    <span class=unimportant>sample.go:35</span>
                           .          .   4b4495:             jge    4b44f1 &lt;main.busyLoop+0x1e1&gt;                                  <span class=unimportant>sample.go:35</span>
                           .          .   4b4497:             mov    %rcx,0x38(%rsp)                                               <span class=unimportant>sample.go:35</span>
                           .          .   4b449c:             movsd  %xmm0,0x48(%rsp)                                              <span class=unimportant>sample.go:35</span>
        </span>
        <span class=line>     36</span> <span class=livesrc>       0.05s      1.42s             if err := pprof.StartCPUProfile(f); err != nil { </span><span class=asm>                   .          .   4b441d:             mov    %rax,(%rsp)                                                   <span class=unimportant>sample.go:36</span>
                           .      1.37s   4b4421:             call   409500 &lt;runtime.mapiternext&gt;                                  <span class=unimportant>sample.go:36</span>
                           .          .   4b4426:             movsd  0x40(%rsp),%xmm0                                              <span class=unimportant>sample.go:36</span>
                       0.02s      0.02s   4b442c:             movsd  0x48(%rsp),%xmm1                                              <span class=unimportant>sample.go:36</span>
                                             ⋮
                       0.02s      0.02s   4b4436:             mov    0x140(%rsp),%rax                                              <span class=unimportant>sample.go:36</span>
                           .          .   4b443e:             test   %rax,%rax                                                     <span class=unimportant>sample.go:36</span>
                           .          .   4b4441:             je     4b4480 &lt;main.busyLoop+0x170&gt;                                  <span class=unimportant>sample.go:36</span>
                       0.01s      0.01s   4b4443:             movsd  %xmm0,0x40(%rsp)                                              <span class=unimportant>sample.go:36</span>
                           .          .   4b4449:             mov    0x148(%rsp),%rax                                              <span class=unimportant>sample.go:36</span>
                           .          .   4b4451:             mov    (%rax),%rax                                                   <span class=unimportant>sample.go:36</span>
                                             ⋮
                           .          .   4b4480:             mov    0x38(%rsp),%rdx                                               <span class=unimportant>sample.go:36</span>
                                             ⋮
                           .          .   4b44a2:             lea    0x140(%rsp),%rdi                                              <span class=unimportant>sample.go:36</span>
                           .          .   4b44aa:             xorps  %xmm0,%xmm0                                                   <span class=unimportant>sample.go:36</span>
                           .          .   4b44ad:             add    $0xffffffffffffffe0,%rdi                                      <span class=unimportant>sample.go:36</span>
                           .          .   4b44b1:             mov    %rbp,-0x10(%rsp)                                              <span class=unimportant>sample.go:36</span>
                           .          .   4b44b6:             lea    -0x10(%rsp),%rbp                                              <span class=unimportant>sample.go:36</span>
                           .          .   4b44bb:             call   453b71 &lt;runtime.duffzero+0x111&gt;                               <span class=unimportant>sample.go:36</span>
                           .          .   4b44c0:             mov    0x0(%rbp),%rbp                                                <span class=unimportant>sample.go:36</span>
                           .          .   4b44c4:             lea    0x1c8d5(%rip),%rcx        # 4d0da0 &lt;type.*+0x1bda0&gt;           <span class=unimportant>sample.go:36</span>
                           .          .   4b44cb:             mov    %rcx,(%rsp)                                                   <span class=unimportant>sample.go:36</span>
                           .          .   4b44cf:             mov    %rax,0x8(%rsp)                                                <span class=unimportant>sample.go:36</span>
                           .          .   4b44d4:             lea    0x140(%rsp),%rdx                                              <span class=unimportant>sample.go:36</span>
                           .          .   4b44dc:             mov    %rdx,0x10(%rsp)                                               <span class=unimportant>sample.go:36</span>
                           .          .   4b44e1:             call   409030 &lt;runtime.mapiterinit&gt;                                  <span class=unimportant>sample.go:36</span>
                           .          .   4b44e6:             movsd  0x48(%rsp),%xmm0                                              <span class=unimportant>sample.go:36</span>
                           .          .   4b44ec:             jmp    4b4436 &lt;main.busyLoop+0x126&gt;                                  <span class=unimportant>sample.go:36</span>
        </span>
        <span class=line>     37</span> <span class=livesrc>       0.05s      0.05s                     log.Fatal(&#34;could not start CPU profile: &#34;, err) </span><span class=asm>                   .          .   4b4432:                     addsd  %xmm1,%xmm0                                           <span class=unimportant>sample.go:37</span>
                                             ⋮
                           .          .   4b4454:                     xorps  %xmm1,%xmm1                                           <span class=unimportant>sample.go:37</span>
                       0.01s      0.01s   4b4457:                     cvtsi2sd %rax,%xmm1                                          <span class=unimportant>sample.go:37</span>
                       0.04s      0.04s   4b445c:                     xorps  %xmm2,%xmm2                                           <span class=unimportant>sample.go:37</span>
                                             ⋮
                           .          .   4b4471:                     jmp    4b440f &lt;main.busyLoop+0xff&gt;                           <span class=unimportant>sample.go:37</span>
                                             ⋮
                           .          .   4b447e:                     jmp    4b440f &lt;main.busyLoop+0xff&gt;                           <span class=unimportant>sample.go:37</span>
        </span>
        <span class=line>     38</span> <span class=nop>           .          .                 } </span>
        <span class=line>     39</span> <span class=nop>           .          .                 defer pprof.StopCPUProfile() </span>
        <span class=line>     40</span> <span class=livesrc>           .          .             busyLoop() </span><span class=asm>                   .          .   4b44f1:             movsd  %xmm0,0x50(%rsp)                                              <span class=unimportant>sample.go:40</span>
                           .          .   4b44f7:             movq   $0x0,0xf0(%rsp)                                               <span class=unimportant>sample.go:40</span>
                           .          .   4b4503:             movq   $0x0,0xf8(%rsp)                                               <span class=unimportant>sample.go:40</span>
                           .          .   4b450f:             movq   $0x0,0x100(%rsp)                                              <span class=unimportant>sample.go:40</span>
                           .          .   4b451b:             movq   $0x0,0x108(%rsp)                                              <span class=unimportant>sample.go:40</span>
                           .          .   4b4527:             lea    0x13eb2(%rip),%rax        # 4c83e0 &lt;type.*+0x133e0&gt;           <span class=unimportant>sample.go:40</span>
                           .          .   4b452e:             mov    %rax,0xf0(%rsp)                                               <span class=unimportant>sample.go:40</span>
                           .          .   4b4536:             lea    0x4e5a3(%rip),%rax        # 502ae0 &lt;main.statictmp_2&gt;         <span class=unimportant>sample.go:40</span>
                           .          .   4b453d:             mov    %rax,0xf8(%rsp)                                               <span class=unimportant>sample.go:40</span>
                           .          .   4b4545:             lea    0x13294(%rip),%rax        # 4c77e0 &lt;type.*+0x127e0&gt;           <span class=unimportant>sample.go:40</span>
                           .          .   4b454c:             mov    %rax,(%rsp)                                                   <span class=unimportant>sample.go:40</span>
                           .          .   4b4550:             lea    0x50(%rsp),%rax                                               <span class=unimportant>sample.go:40</span>
                           .          .   4b4555:             mov    %rax,0x8(%rsp)                                                <span class=unimportant>sample.go:40</span>
                           .          .   4b455a:             call   40da80 &lt;runtime.convT2E64&gt;                                    <span class=unimportant>sample.go:40</span>
                           .          .   4b455f:             mov    0x18(%rsp),%rax                                               <span class=unimportant>sample.go:40</span>
                           .          .   4b4564:             mov    0x10(%rsp),%rcx                                               <span class=unimportant>sample.go:40</span>
                           .          .   4b4569:             mov    %rcx,0x100(%rsp)                                              <span class=unimportant>sample.go:40</span>
                           .          .   4b4571:             mov    %rax,0x108(%rsp)                                              <span class=unimportant>sample.go:40</span>
                           .          .   4b4579:             lea    0xf0(%rsp),%rax                                               <span class=unimportant>sample.go:40</span>
                           .          .   4b4581:             mov    %rax,(%rsp)                                                   <span class=unimportant>sample.go:40</span>
                           .          .   4b4585:             movq   $0x2,0x8(%rsp)                                                <span class=unimportant>sample.go:40</span>
                           .          .   4b458e:             movq   $0x2,0x10(%rsp)                                               <span class=unimportant>sample.go:40</span>
                           .          .   4b4597:             call   493030 &lt;fmt.Println&gt;                                          <span class=unimportant>sample.go:40</span>
        </span>
        <span class=line>     41</span> <span class=livesrc>           .          .           } </span><span class=asm>                   .          .   4b459c:     mov    0x1a0(%rsp),%rbp                                                      <span class=unimportant>sample.go:41</span>
                           .          .   4b45a4:     add    $0x1a8,%rsp                                                           <span class=unimportant>sample.go:41</span>
                           .          .   4b45ab:     ret                                                                          <span class=unimportant>sample.go:41</span>
        </span>
        <span class=line>     42</span> <span class=nop>           .          .            </span>
        <span class=line>     43</span> <span class=nop>           .          .           func busyLoop() { </span>
        <span class=line>     44</span> <span class=nop>           .          .                 m := make(map[int]int) </span>
        <span class=line>     45</span> <span class=nop>           .          .                 for i := 0; i &lt; 1000000; i++ { </span>
        <span class=line>     46</span> <span class=nop>           .          .                         m[i] = i + 10 </span>
        </pre>

        </body>
        </html>

FAIL
FAIL    github.com/google/pprof/internal/report 0.235s
ok      github.com/google/pprof/internal/symbolizer     (cached)
ok      github.com/google/pprof/internal/symbolz        (cached)
?       github.com/google/pprof/internal/transport      [no test files]
ok      github.com/google/pprof/profile (cached)
?       github.com/google/pprof/third_party/d3  [no test files]
?       github.com/google/pprof/third_party/d3flamegraph        [no test files]
?       github.com/google/pprof/third_party/svgpan      [no test files]
FAIL

What did you expect to see?

Tests pass

What did you see instead?

One test fails.

Looks like the test is asserting that it contains callq.*mapassign but it only contains call.*mapassign.
@mhansen
Copy link
Contributor Author

mhansen commented Sep 22, 2021

Perhaps I'm missing a dependency required to make this work -- it's very likely I'm just holding this wrong.

@chavey
Copy link

chavey commented Oct 7, 2021 •
edited
Loading

I could not reproduce the failure from pprof master:HEAD

$uname -a
Linux TAZ-WLINUX 5.10.16.3-microsoft-standard-WSL2 #1 SMP Fri Apr 2 22:23:49 UTC 2021 x86_64 GNU/Linux

$cat /etc/os-release
PRETTY_NAME="Kali GNU/Linux Rolling"
NAME="Kali GNU/Linux"
ID=kali
VERSION="2021.3"
VERSION_ID="2021.3"
VERSION_CODENAME="kali-rolling"

$cd /prj/Go/src/github.com/google/pprof

$go version
go version go1.16.4 linux/amd64

$go env
GO111MODULE=""
GOARCH="amd64"
GOBIN="/Prj/Go/bin"
GOCACHE="/Prj/.cache/go-build"
GOENV="/Prj/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/Prj/Go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/Prj/Go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.16.4"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/Prj/Go/src/github.com/google/pprof/go.mod"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build3254136224=/tmp/go-build -gno-record-gcc-switches"

$git branch -a

  • master
    remotes/origin/HEAD -> origin/master

$git pull
$git log --oneline
7fe48b4 (HEAD -> master, origin/master, origin/HEAD) Add -tagroot and -tagleaf options (#649)
1096026 Get rid of Travis CI badge in README (#652)
86a2bdb Fix tests run by Github Action and update the testing matrix (#654)

$go clean --testcache
$go test ./...
? github.com/google/pprof [no test files]
? github.com/google/pprof/driver [no test files]
ok github.com/google/pprof/fuzz 0.003s
ok github.com/google/pprof/internal/binutils 0.341s
ok github.com/google/pprof/internal/driver 1.810s
ok github.com/google/pprof/internal/elfexec 0.016s
ok github.com/google/pprof/internal/graph 0.010s
ok github.com/google/pprof/internal/measurement 0.027s
? github.com/google/pprof/internal/plugin [no test files]
? github.com/google/pprof/internal/proftest [no test files]
ok github.com/google/pprof/internal/report 0.103s
ok github.com/google/pprof/internal/symbolizer 0.007s
ok github.com/google/pprof/internal/symbolz 0.004s
? github.com/google/pprof/internal/transport [no test files]
ok github.com/google/pprof/profile 0.042s
? github.com/google/pprof/third_party/d3 [no test files]
? github.com/google/pprof/third_party/d3flamegraph [no test files]
? github.com/google/pprof/third_party/svgpan [no test files]

@mhansen
Copy link
Contributor Author

mhansen commented Oct 7, 2021 •
edited
Loading

I can't repro this on my personal mac either. I'll try repro it on my work-workstation tomorrow.

$ uname -a
Darwin Marks-MBP-2.localdomain 20.6.0 Darwin Kernel Version 20.6.0: Mon Aug 30 06:12:21 PDT 2021; root:xnu-7195.141.6~3/RELEASE_X86_64 x86_64

~/projects> git clone https://github.com/google/pprof.git
~/projects> cd pprof/

~/p/pprof (master)> go version
go version go1.17 darwin/amd64

 ~/p/pprof (master)> go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/mark/Library/Caches/go-build"
GOENV="/Users/mark/Library/Application Support/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOINSECURE=""
GOMODCACHE="/Users/mark/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="darwin"
GOPATH="/Users/mark/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/Cellar/go/1.17/libexec"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/Cellar/go/1.17/libexec/pkg/tool/darwin_amd64"
GOVCS=""
GOVERSION="go1.17"
GCCGO="gccgo"
AR="ar"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD="/Users/mark/projects/pprof/go.mod"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -arch x86_64 -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/_1/bw9n24jn7_9_xbcty9rdx7j40000gn/T/go-build2916443229=/tmp/go-build -gno-record-gcc-switches -fno-common"

~/p/pprof (master)> go test ./...
?       github.com/google/pprof [no test files]
?       github.com/google/pprof/driver  [no test files]
ok      github.com/google/pprof/fuzz    0.844s
ok      github.com/google/pprof/internal/binutils       2.154s
ok      github.com/google/pprof/internal/driver 6.388s
ok      github.com/google/pprof/internal/elfexec        0.888s
ok      github.com/google/pprof/internal/graph  1.200s
ok      github.com/google/pprof/internal/measurement    0.280s
?       github.com/google/pprof/internal/plugin [no test files]
?       github.com/google/pprof/internal/proftest       [no test files]
ok      github.com/google/pprof/internal/report 0.597s
ok      github.com/google/pprof/internal/symbolizer     0.885s
ok      github.com/google/pprof/internal/symbolz        1.161s
?       github.com/google/pprof/internal/transport      [no test files]
ok      github.com/google/pprof/profile 0.978s
?       github.com/google/pprof/third_party/d3  [no test files]
?       github.com/google/pprof/third_party/d3flamegraph        [no test files]
?       github.com/google/pprof/third_party/svgpan      [no test files]

@mhansen
Copy link
Contributor Author

mhansen commented Oct 7, 2021

What tool is used to generate the assembly dump?

https://stackoverflow.com/a/46753525/171898 says call and callq are the same.

Looks like llvm-symbolizer, addr2line, nm, objdump from internal/binutils/binutils.go:114

Possibly given this is failing on my workstation the problem is a difference between packages shelled out to.

@mhansen
Copy link
Contributor Author

mhansen commented Oct 7, 2021

Anyway maybe we could fix this just by replacing the regex callq.* with call.*, if they're just different ASCII representations of the same instruction.

@mhansen
Copy link
Contributor Author

mhansen commented Oct 8, 2021

I wanted to find what commands are ran while running the test, so I ran execsnoop at the same time as the test:

$ go test ./internal/report

$ sudo execsnoop-bpfcc
PCOMM            PID    PPID   RET ARGS
[...]
report.test      1838588 1838362   0 /tmp/go-build4025630643/b001/report.test -test.testlogfile=/tmp/go-build4025630643/b001/testlog.txt -test.paniconexit0 -test.timeout=10m0s
objdump          1838595 1838588   0 /usr/bin/objdump --version
objdump          1838596 1838588   0 /usr/bin/objdump --disassemble --demangle --no-show-raw-insn --line-numbers --start-address=0x4b41eb --stop-address=0x4b4667 testdata/sample.bin
addr2line        1838597 1838588   0 /usr/bin/addr2line -aif -e testdata/sample.bin
nm               1838598 1838588   0 /usr/bin/nm --numeric-sort --print-size --format=posix testdata/sample.bin

So the problem is in one of those commands.

Running:

$ /usr/bin/objdump --version
GNU objdump (GNU Binutils for Debian) 2.37

And this version outputs call rather than callq:

$ /usr/bin/objdump --disassemble --demangle --no-show-raw-insn --line-numbers --start-address=0x4b41eb --stop-address=0x4b4667 testdata/sample.bin

testdata/sample.bin:     file format elf64-x86-64

[...]
  4b43db:       call   40c210 <runtime.mapassign_fast64>
[...]

mhansen added a commit to mhansen/pprof that referenced this issue Nov 8, 2021
@mhansen
Update mapassign regex to match both call variants
2fd738e 
Different versions of `objdump` output `call` or `callq`.

Both work fine for the purposes of the test.

Fixes google#650
@mhansen mhansen mentioned this issue Nov 8, 2021
Merged
aalexand pushed a commit that referenced this issue Nov 8, 2021
@mhansen
Update mapassign regex to match both call variants (#668)
e9b0287 
Different versions of `objdump` output `call` or `callq`.

Both work fine for the purposes of the test.

Fixes #650
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@chavey chavey

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Update mapassign regex to match both call variants mhansen/pprof
2 participants
@mhansen @chavey