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.

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

cmd/compile, runtime: go v1.8 fails to allocate heap bitmap on armv7 when importing zmq4 #19831

Closed
plasticchris opened this issue Apr 4, 2017 · 39 comments

Comments

Projects
None yet
5 participants
@plasticchris
Copy link

commented Apr 4, 2017

go version
1.8 linux/amd64

go env ($TOOLCHAIN and $SYSROOT are for cross compile)
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
CGO_ENABLED=1
C_INCLUDE_PATH=$SYSROOT/usr/include/
LIBRARY_PATH=$SYSROOT/usr/lib
CC=$TOOLCHAIN
PKG_CONFIG_PATH=$SYSROOT/usr/lib/pkgconfig/
GOARCH=arm
GOARM=7

I'm using go v1.8 to cross compile to an armv7 target and everything works until I import zeromq, and then not even this works:

package main

import (
	zmq "github.com/pebbe/zmq4"
	"fmt"
)

func main() {
fmt.Println(zmq.Version())
}

Running it on the target gives the following:

./zmq 
fatal error: runtime: out of memory

runtime stack:
runtime.throw(0xc8d3d, 0x16)
        /usr/lib/go/src/runtime/panic.go:596 +0x70 fp=0x7eb018a0 sp=0x7eb01894
runtime.sysMap(0x6d752000, 0x74d4000, 0x1, 0x146b60)
        /usr/lib/go/src/runtime/mem_linux.go:227 +0xb0 fp=0x7eb018c4 sp=0x7eb018a0
runtime.(*mheap).mapBits(0x139d58, 0x74d26000)
        /usr/lib/go/src/runtime/mbitmap.go:159 +0x94 fp=0x7eb018dc sp=0x7eb018c4
runtime.(*mheap).sysAlloc(0x139d58, 0x100000, 0x30414)
        /usr/lib/go/src/runtime/malloc.go:428 +0x2dc fp=0x7eb0191c sp=0x7eb018dc
runtime.(*mheap).grow(0x139d58, 0x8, 0x0)
        /usr/lib/go/src/runtime/mheap.go:774 +0xd0 fp=0x7eb0194c sp=0x7eb0191c
runtime.(*mheap).allocSpanLocked(0x139d58, 0x1, 0x0)
        /usr/lib/go/src/runtime/mheap.go:678 +0x468 fp=0x7eb0196c sp=0x7eb0194c
runtime.(*mheap).alloc_m(0x139d58, 0x1, 0x10, 0x0, 0x0)
        /usr/lib/go/src/runtime/mheap.go:562 +0xdc fp=0x7eb019a4 sp=0x7eb0196c
runtime.(*mheap).alloc.func1()
        /usr/lib/go/src/runtime/mheap.go:627 +0x3c fp=0x7eb019c0 sp=0x7eb019a4
runtime.systemstack(0x7eb019d4)
        /usr/lib/go/src/runtime/asm_arm.s:278 +0xa8 fp=0x7eb019c4 sp=0x7eb019c0
runtime.(*mheap).alloc(0x139d58, 0x1, 0x10, 0x100, 0x1)
        /usr/lib/go/src/runtime/mheap.go:628 +0x60 fp=0x7eb019ec sp=0x7eb019c4
runtime.(*mcentral).grow(0x13ab98, 0x0)
        /usr/lib/go/src/runtime/mcentral.go:212 +0x84 fp=0x7eb01a18 sp=0x7eb019ec
runtime.(*mcentral).cacheSpan(0x13ab98, 0x146b68)
        /usr/lib/go/src/runtime/mcentral.go:93 +0x104 fp=0x7eb01a5c sp=0x7eb01a18
runtime.(*mcache).refill(0x649e5000, 0x10, 0x146b68)
        /usr/lib/go/src/runtime/mcache.go:122 +0x7c fp=0x7eb01a70 sp=0x7eb01a5c
runtime.(*mcache).nextFree.func1()
        /usr/lib/go/src/runtime/malloc.go:525 +0x24 fp=0x7eb01a80 sp=0x7eb01a70
runtime.systemstack(0x7eb01aa4)
        /usr/lib/go/src/runtime/asm_arm.s:278 +0xa8 fp=0x7eb01a84 sp=0x7eb01a80
runtime.(*mcache).nextFree(0x649e5000, 0x649e5010, 0x7eb01acc, 0x1ebd4, 0x21c40)
        /usr/lib/go/src/runtime/malloc.go:526 +0x9c fp=0x7eb01ab0 sp=0x7eb01a84
runtime.mallocgc(0xf0, 0xc2548, 0x1, 0x64a26001)
        /usr/lib/go/src/runtime/malloc.go:678 +0x8c0 fp=0x7eb01b08 sp=0x7eb01ab0
runtime.newobject(0xc2548, 0x1384a0)
        /usr/lib/go/src/runtime/malloc.go:807 +0x2c fp=0x7eb01b1c sp=0x7eb01b08
runtime.malg(0x8000, 0x2710)
        /usr/lib/go/src/runtime/proc.go:2821 +0x1c fp=0x7eb01b38 sp=0x7eb01b1c
runtime.mpreinit(0x138730)
        /usr/lib/go/src/runtime/os_linux.go:302 +0x1c fp=0x7eb01b44 sp=0x7eb01b38
runtime.mcommoninit(0x138730)
        /usr/lib/go/src/runtime/proc.go:540 +0x94 fp=0x7eb01b5c sp=0x7eb01b44
runtime.schedinit()
        /usr/lib/go/src/runtime/proc.go:476 +0x40 fp=0x7eb01b78 sp=0x7eb01b5c
runtime.rt0_go(0x7eb01d14, 0x76ee4000, 0x7eb01d14, 0x1, 0x5cd10, 0x7eb01c58, 0x76f8e000, 0xcef6f281, 0xc6a63e08, 0x128, ...)
        /usr/lib/go/src/runtime/asm_arm.s:61 +0x84 fp=0x7eb01bb8 sp=0x7eb01b78

Tracing shows the offending mmap:

mmap2(0x74c54000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x74c54000
mmap2(0x6d77e000, 122511360, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = -1 ENOMEM (Cannot allocate memory)

The first one is right, that's the chunk size, but the second is where it allocates the bitmap. It should be probably 16x smaller.

I tried debugging but it works under GDB. Maybe GDB does some virtualization?

gdbserver :1000 zmq
Process zmq created; pid = 817
Listening on port 1000
Remote debugging from host 10.0.0.36
4 2 1

Child exited with status 0

So far, all pure go programs I've tested work as well.

Why does importing zeromq cause it to fail? Is there a bug in the arm port of go?

@davecheney

This comment has been minimized.

Copy link
Contributor

commented Apr 4, 2017

@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 4, 2017

That's interesting, but my target is pretty limited, as in <1ghz, <512 megs of ram. Go seemed a good fit since it seems to have great support for cross compiling, and this is the only case where it is not working as expected.

It's also possible the pi still doing it and not noticed, as the pi has much more ram than my board and could afford to allocate this much.

This issue is mainly about how unexpected this is. The bitmap should be 16x less than the chunk, not 116x larger. It makes me think something basic is not set correctly in the runtime.

@bradfitz

This comment has been minimized.

Copy link
Member

commented Apr 4, 2017

@bradfitz bradfitz changed the title go v1.8 fails to allocate heap bitmap on armv7 when importing zmq4 cmd/compile, runtime: go v1.8 fails to allocate heap bitmap on armv7 when importing zmq4 Apr 4, 2017

@bradfitz bradfitz added this to the Go1.9 milestone Apr 4, 2017

@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 4, 2017

It happens with the native build on the pi as well, here is the trace:

mmap2(0x10400000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x10400000
mmap2(0xf3b0000, 17104896, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xf3b0000

It's 16x larger in this case, not as bad as my target but still unexpected as it should be 16x smaller.

For comparison, this is the same trace on my desktop (go 1.8 linux/amd64):

mmap(0xc420000000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xc420000000
mmap(0xc41fff8000, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xc41fff8000

On linux/amd64 the bitmap is 32x smaller than the allocated chunk, as expected.

@davecheney

This comment has been minimized.

Copy link
Contributor

commented Apr 4, 2017

@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 4, 2017

The size of mmap calls in general is not an issue, but unlike the other calls this one uses MMAP_FIXED which actually allocates the memory instead of just addressing it.

That the bitmap allocation is much larger than the heap chunk seems to me to be an obvious bug.

To be more general it happens on the pi with a simple hello world:

pi@raspberrypi:~$ cat hi.go
package main

import "fmt"

func main () {
fmt.Println("hi")
}

pi@raspberrypi:~$ strace -e mmap2 ./hi
mmap2(0x200000, 807411712, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x200000
mmap2(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76f37000

mmap2(0x10400000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x10400000
mmap2(0xf3b0000, 17104896, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xf3b0000
^
mmap2(0x200000, 135168, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x200000
mmap2(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76f27000
mmap2(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76f17000
mmap2(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76ed7000
hi
+++ exited with 0 +++
@davecheney

This comment has been minimized.

Copy link
Contributor

commented Apr 4, 2017

@aclements

This comment has been minimized.

Copy link
Member

commented Apr 4, 2017

@davecheney, could you elaborate on your simple reproducer? I tried a simple hello world on linux/amd64 and all of the mmaps were completely reasonable (the largest was 1 MB).

@plasticchris, you're right that something is definitely going wrong here. Working out your stack trace from the bottom to the top:

runtime.mallocgc(0xf0, 0xc2548, 0x1, 0x64a26001) - Allocate 0xf0 bytes. This causes the runtime to get a new span, which is fine.
runtime.(*mheap).grow(0x139d58, 0x8, 0x0) - To get the new span, grow the heap by 8 pages (64K).
runtime.(*mheap).sysAlloc(0x139d58, 0x100000, 0x30414) - Map 1MB, since that's how much we grow the heap mapping by when we need to grow it.
runtime.(*mheap).mapBits(0x139d58, 0x74d26000) - Map the heap bitmap. This is where things get somewhat interesting. It's claiming that the new arena_used is 0x74d26000, or 1.8 GB. I assume you're not actually growing your heap that large?
runtime.sysMap(0x6d752000, 0x74d4000, 0x1, 0x146b60) - Finally, we actually request 0x74d4000 bytes (116MB) for the bitmap mapping, which suggests that hardly any of the bitmap was previously mapped. But we clearly didn't just grow the heap from near-nothing to 1.8 GB.

Most likely something went wrong computing the new arena_used and that propagated to a bad bitmap mapping.

The size of mmap calls in general is not an issue, but unlike the other calls this one uses MMAP_FIXED which actually allocates the memory instead of just addressing it.

MMAP_FIXED just means that the kernel must make the mapping where we requested it. It has nothing to do with pre-faulting the memory.

@davecheney

This comment has been minimized.

Copy link
Contributor

commented Apr 4, 2017

@aclements

pi@raspberrypi:~/src $ cat helloworld.go 
package main

import "fmt"

func main() {
fmt.Println("hello world")
}
pi@raspberrypi:~/src $ go build helloworld.go
pi@raspberrypi:~/src $ strace -f ./helloworld 2>&1 | grep mmap
mmap2(0x200000, 807411712, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x200000
mmap2(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76ec4000
mmap2(0x10400000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x10400000
mmap2(0xf3b0000, 17104896, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xf3b0000
mmap2(0x200000, 135168, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x200000
mmap2(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76eb4000
mmap2(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76ea4000
[pid 21510] mmap2(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76e64000
pi@raspberrypi:~/src $ go version
go version devel +78f6622 Sat Apr 1 10:41:37 2017 +0000 linux/arm
@aclements

This comment has been minimized.

Copy link
Member

commented Apr 4, 2017

'Doh, mmap2. Thanks @davecheney. I think this is a 32-bit bug, because I get the same 800MB mmap if I run that program on 386.

@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 4, 2017

MMAP_FIXED just means that the kernel must make the mapping where we requested it. It has nothing to do with pre-faulting the memory.

Thanks for the clarification, that the mmap returned ENOMEM make me think it was.

@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 4, 2017

runtime.(*mheap).mapBits(0x139d58, 0x74d26000) - Map the heap bitmap. This is where things get somewhat interesting. It's claiming that the new arena_used is 0x74d26000, or 1.8 GB. I assume you're not actually growing your heap that large?

Correct, this happens before any it gets to the main function

@aclements

This comment has been minimized.

Copy link
Member

commented Apr 4, 2017

Actually, @davecheney's example is different and not a bug. In that case, the 800MB mmap is PROT_NONE, so that's actually coming from sysReserve. That's expected behavior, since on 32-bit we reserve space for a 512MB heap plus ancillary structures first thing (but it's PROT_NONE, so it's not "really" there). OTOH, in @plasticchris' original post, the bad mmap was clearly coming from a real mapping of the heap bitmap when growing the heap.

@davecheney

This comment has been minimized.

Copy link
Contributor

commented Apr 4, 2017

@aclements

This comment has been minimized.

Copy link
Member

commented Apr 4, 2017

@plasticchris, can you post the output of readelf --segments --sections on both the locally and cross-compiled binaries?

@aclements

This comment has been minimized.

Copy link
Member

commented Apr 4, 2017

Here's my hunch: on 32-bit, we reserve space for enough heap bitmap to cover the entire 32-bit address space and we set arena_start to 0. When we map the bitmap, we have to map bitmap memory for everything from arena_start to the current top of the arena. On 64-bit, there's no waste here because the heap really starts at arena_start. On 32-bit, there's generally very little waste here because we start allocating the heap from just above the top of the mapped binary, which is generally pretty close to 0.

But your heap is starting somewhere around 0x74c54000. Nowhere near 0. That either means that the top of your mapped binary is in fact nowhere near 0 (which could have to do with linking in zmq) or zmq mapped some memory in the way of our heap and we fell back to whatever address the OS could provide, which was something huge. This is causing us to create a large bitmap mapping.

Now, why the bitmap mmap is failing with ENOMEM is another question. I think that either means overcommit is disabled on your Pi, or something (possibly zmq) made a huge number of mappings and this one happens to exceed the limit.

@plasticchris, what are the values of /proc/sys/vm/overcommit_memory, /proc/sys/vm/overcommit_ratio, and sysctl vm.max_map_count?

@aclements

This comment has been minimized.

Copy link
Member

commented Apr 4, 2017

Sorry, one more question: how many mmap calls are in your strace? (Or, if you can get it, how many lines are in /proc/PID/maps when the failure occurs?)

@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 4, 2017

It seems to me this isn't a cross compilation issue but an arm or possibly 32 bit issue as it shows up in native compiles for the pi. I posted the trace for hello world on the pi above and marked the mmaps. It's not as extreme but still present.

To be more general it happens on the pi with a simple hello world:

pi@raspberrypi:~$ cat hi.go
package main

import "fmt"

func main () {
fmt.Println("hi")
}

pi@raspberrypi:~$ strace -e mmap2 ./hi
mmap2(0x200000, 807411712, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x200000
mmap2(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76f37000

mmap2(0x10400000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x10400000
mmap2(0xf3b0000, 17104896, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xf3b0000
^

@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 4, 2017

@plasticchris, can you post the output of readelf --segments --sections on both the locally and cross-compiled binaries?

pi@raspberrypi:~ $ diff cross native
1d0
<  readelf --segments --sections hi
7,13c6,12
<   [ 1] .text             PROGBITS        00011000 001000 07017c 00  AX  0   0  4
<   [ 2] .rodata           PROGBITS        00090000 080000 025a66 00   A  0   0  8
<   [ 3] .shstrtab         STRTAB          00000000 0a5a68 000101 00      0   0  1
<   [ 4] .typelink         PROGBITS        000b5b70 0a5b70 000ac8 00   A  0   0  8
<   [ 5] .itablink         PROGBITS        000b6638 0a6638 00001c 00   A  0   0  4
<   [ 6] .gosymtab         PROGBITS        000b6654 0a6654 000000 00   A  0   0  1
<   [ 7] .gopclntab        PROGBITS        000b6658 0a6658 038bd7 00   A  0   0  8
---
>   [ 1] .text             PROGBITS        00011000 001000 0700f0 00  AX  0   0  4
>   [ 2] .rodata           PROGBITS        00090000 080000 025a55 00   A  0   0  8
>   [ 3] .shstrtab         STRTAB          00000000 0a5a58 000101 00      0   0  1
>   [ 4] .typelink         PROGBITS        000b5b60 0a5b60 000ac8 00   A  0   0  8
>   [ 5] .itablink         PROGBITS        000b6628 0a6628 00001c 00   A  0   0  4
>   [ 6] .gosymtab         PROGBITS        000b6644 0a6644 000000 00   A  0   0  1
>   [ 7] .gopclntab        PROGBITS        000b6648 0a6648 038cc4 00   A  0   0  8
19,25c18,24
<   [13] .debug_line       PROGBITS        001100ff 0f00ff 010905 00      0   0  1
<   [14] .debug_frame      PROGBITS        00120a04 100a04 00d7fc 00      0   0  1
<   [15] .debug_pubnames   PROGBITS        0012e200 10e200 0024fa 00      0   0  1
<   [16] .debug_pubtypes   PROGBITS        001306fa 1106fa 007329 00      0   0  1
<   [17] .debug_aranges    PROGBITS        00137a23 117a23 000020 00      0   0  1
<   [18] .debug_gdb_script PROGBITS        00137a43 117a43 000028 00      0   0  1
<   [19] .debug_info       PROGBITS        00137a6b 117a6b 0308ef 00      0   0  1
---
>   [13] .debug_line       PROGBITS        001100ff 0f00ff 0109e9 00      0   0  1
>   [14] .debug_frame      PROGBITS        00120ae8 100ae8 00d7fc 00      0   0  1
>   [15] .debug_pubnames   PROGBITS        0012e2e4 10e2e4 0024fa 00      0   0  1
>   [16] .debug_pubtypes   PROGBITS        001307de 1107de 007329 00      0   0  1
>   [17] .debug_aranges    PROGBITS        00137b07 117b07 000020 00      0   0  1
>   [18] .debug_gdb_script PROGBITS        00137b27 117b27 00002a 00      0   0  1
>   [19] .debug_info       PROGBITS        00137b51 117b51 0308ec 00      0   0  1
35c34
< Entry point 0x5b384
---
> Entry point 0x5b2f8
42,43c41,42
<   LOAD           0x000000 0x00010000 0x00010000 0x7117c 0x7117c R E 0x10000
<   LOAD           0x080000 0x00090000 0x00090000 0x5f22f 0x5f22f R   0x10000
---
>   LOAD           0x000000 0x00010000 0x00010000 0x710f0 0x710f0 R E 0x10000
>   LOAD           0x080000 0x00090000 0x00090000 0x5f30c 0x5f30c R   0x10000
53c52
<    03     .rodata .typelink .itablink .gosymtab .gopclntab 
---
>    03     .rodata .shstrtab .typelink .itablink .gosymtab .gopclntab 
57d55
< 
pi@raspberrypi:~ $ cat cross
 readelf --segments --sections hi
There are 23 section headers, starting at offset 0x114:

Section Headers:
  [Nr] Name              Type            Addr     Off    Size   ES Flg Lk Inf Al
  [ 0]                   NULL            00000000 000000 000000 00      0   0  0
  [ 1] .text             PROGBITS        00011000 001000 07017c 00  AX  0   0  4
  [ 2] .rodata           PROGBITS        00090000 080000 025a66 00   A  0   0  8
  [ 3] .shstrtab         STRTAB          00000000 0a5a68 000101 00      0   0  1
  [ 4] .typelink         PROGBITS        000b5b70 0a5b70 000ac8 00   A  0   0  8
  [ 5] .itablink         PROGBITS        000b6638 0a6638 00001c 00   A  0   0  4
  [ 6] .gosymtab         PROGBITS        000b6654 0a6654 000000 00   A  0   0  1
  [ 7] .gopclntab        PROGBITS        000b6658 0a6658 038bd7 00   A  0   0  8
  [ 8] .noptrdata        PROGBITS        000f0000 0e0000 001d28 00  WA  0   0  8
  [ 9] .data             PROGBITS        000f1d28 0e1d28 000e38 00  WA  0   0  8
  [10] .bss              NOBITS          000f2b60 0e2b60 00d6b8 00  WA  0   0  8
  [11] .noptrbss         NOBITS          00100218 0f0218 004120 00  WA  0   0  8
  [12] .debug_abbrev     PROGBITS        00110000 0f0000 0000ff 00      0   0  1
  [13] .debug_line       PROGBITS        001100ff 0f00ff 010905 00      0   0  1
  [14] .debug_frame      PROGBITS        00120a04 100a04 00d7fc 00      0   0  1
  [15] .debug_pubnames   PROGBITS        0012e200 10e200 0024fa 00      0   0  1
  [16] .debug_pubtypes   PROGBITS        001306fa 1106fa 007329 00      0   0  1
  [17] .debug_aranges    PROGBITS        00137a23 117a23 000020 00      0   0  1
  [18] .debug_gdb_script PROGBITS        00137a43 117a43 000028 00      0   0  1
  [19] .debug_info       PROGBITS        00137a6b 117a6b 0308ef 00      0   0  1
  [20] .note.go.buildid  NOTE            00010fc8 000fc8 000038 00   A  0   0  4
  [21] .symtab           SYMTAB          00000000 150000 007ea0 10     22  93  4
  [22] .strtab           STRTAB          00000000 157ea0 00bb59 00      0   0  1
Key to Flags:
  W (write), A (alloc), X (execute), M (merge), S (strings)
  I (info), L (link order), G (group), T (TLS), E (exclude), x (unknown)
  O (extra OS processing required) o (OS specific), p (processor specific)

Elf file type is EXEC (Executable file)
Entry point 0x5b384
There are 7 program headers, starting at offset 52

Program Headers:
  Type           Offset   VirtAddr   PhysAddr   FileSiz MemSiz  Flg Align
  PHDR           0x000034 0x00010034 0x00010034 0x000e0 0x000e0 R   0x10000
  NOTE           0x000fc8 0x00010fc8 0x00010fc8 0x00038 0x00038 R   0x4
  LOAD           0x000000 0x00010000 0x00010000 0x7117c 0x7117c R E 0x10000
  LOAD           0x080000 0x00090000 0x00090000 0x5f22f 0x5f22f R   0x10000
  LOAD           0x0e0000 0x000f0000 0x000f0000 0x02b60 0x14338 RW  0x10000
  GNU_STACK      0x000000 0x00000000 0x00000000 0x00000 0x00000 RW  0x4
  LOOS+5041580   0x000000 0x00000000 0x00000000 0x00000 0x00000     0x4

 Section to Segment mapping:
  Segment Sections...
   00     
   01     .note.go.buildid 
   02     .text .note.go.buildid 
   03     .rodata .typelink .itablink .gosymtab .gopclntab 
   04     .noptrdata .data .bss .noptrbss 
   05     
   06     

pi@raspberrypi:~ $ cat native
There are 23 section headers, starting at offset 0x114:

Section Headers:
  [Nr] Name              Type            Addr     Off    Size   ES Flg Lk Inf Al
  [ 0]                   NULL            00000000 000000 000000 00      0   0  0
  [ 1] .text             PROGBITS        00011000 001000 0700f0 00  AX  0   0  4
  [ 2] .rodata           PROGBITS        00090000 080000 025a55 00   A  0   0  8
  [ 3] .shstrtab         STRTAB          00000000 0a5a58 000101 00      0   0  1
  [ 4] .typelink         PROGBITS        000b5b60 0a5b60 000ac8 00   A  0   0  8
  [ 5] .itablink         PROGBITS        000b6628 0a6628 00001c 00   A  0   0  4
  [ 6] .gosymtab         PROGBITS        000b6644 0a6644 000000 00   A  0   0  1
  [ 7] .gopclntab        PROGBITS        000b6648 0a6648 038cc4 00   A  0   0  8
  [ 8] .noptrdata        PROGBITS        000f0000 0e0000 001d28 00  WA  0   0  8
  [ 9] .data             PROGBITS        000f1d28 0e1d28 000e38 00  WA  0   0  8
  [10] .bss              NOBITS          000f2b60 0e2b60 00d6b8 00  WA  0   0  8
  [11] .noptrbss         NOBITS          00100218 0f0218 004120 00  WA  0   0  8
  [12] .debug_abbrev     PROGBITS        00110000 0f0000 0000ff 00      0   0  1
  [13] .debug_line       PROGBITS        001100ff 0f00ff 0109e9 00      0   0  1
  [14] .debug_frame      PROGBITS        00120ae8 100ae8 00d7fc 00      0   0  1
  [15] .debug_pubnames   PROGBITS        0012e2e4 10e2e4 0024fa 00      0   0  1
  [16] .debug_pubtypes   PROGBITS        001307de 1107de 007329 00      0   0  1
  [17] .debug_aranges    PROGBITS        00137b07 117b07 000020 00      0   0  1
  [18] .debug_gdb_script PROGBITS        00137b27 117b27 00002a 00      0   0  1
  [19] .debug_info       PROGBITS        00137b51 117b51 0308ec 00      0   0  1
  [20] .note.go.buildid  NOTE            00010fc8 000fc8 000038 00   A  0   0  4
  [21] .symtab           SYMTAB          00000000 150000 007ea0 10     22  93  4
  [22] .strtab           STRTAB          00000000 157ea0 00bb59 00      0   0  1
Key to Flags:
  W (write), A (alloc), X (execute), M (merge), S (strings)
  I (info), L (link order), G (group), T (TLS), E (exclude), x (unknown)
  O (extra OS processing required) o (OS specific), p (processor specific)

Elf file type is EXEC (Executable file)
Entry point 0x5b2f8
There are 7 program headers, starting at offset 52

Program Headers:
  Type           Offset   VirtAddr   PhysAddr   FileSiz MemSiz  Flg Align
  PHDR           0x000034 0x00010034 0x00010034 0x000e0 0x000e0 R   0x10000
  NOTE           0x000fc8 0x00010fc8 0x00010fc8 0x00038 0x00038 R   0x4
  LOAD           0x000000 0x00010000 0x00010000 0x710f0 0x710f0 R E 0x10000
  LOAD           0x080000 0x00090000 0x00090000 0x5f30c 0x5f30c R   0x10000
  LOAD           0x0e0000 0x000f0000 0x000f0000 0x02b60 0x14338 RW  0x10000
  GNU_STACK      0x000000 0x00000000 0x00000000 0x00000 0x00000 RW  0x4
  LOOS+5041580   0x000000 0x00000000 0x00000000 0x00000 0x00000     0x4

 Section to Segment mapping:
  Segment Sections...
   00     
   01     .note.go.buildid 
   02     .text .note.go.buildid 
   03     .rodata .shstrtab .typelink .itablink .gosymtab .gopclntab 
   04     .noptrdata .data .bss .noptrbss 
   05     
   06     

@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 4, 2017

@plasticchris, what are the values of /proc/sys/vm/overcommit_memory, /proc/sys/vm/overcommit_ratio, and sysctl vm.max_map_count?

On the pi:

pi@raspberrypi:~ $ cat  /proc/sys/vm/overcommit_memory
0
pi@raspberrypi:~ $ cat /proc/sys/vm/overcommit_ratio
50
pi@raspberrypi:~ $  sysctl vm.max_map_count
vm.max_map_count = 65530
@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 4, 2017

On my board:

root login on 'ttyS0'
# cat  /proc/sys/vm/overcommit_memory
0
# cat /proc/sys/vm/overcommit_ratio
50
#   sysctl vm.max_map_count
vm.max_map_count = 65530
@davecheney

This comment has been minimized.

Copy link
Contributor

commented Apr 4, 2017

@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 4, 2017

Both run on the pi, they allocate more memory than expected for the bitmap but not enough to crash it. On my board both the natively and cross compiled binaries crash at the same point:

# strace -e mmap2 ./zmq_native 
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76ff7000
mmap2(NULL, 771, PROT_READ, MAP_PRIVATE, 3, 0) = 0x76ff6000
mmap2(NULL, 694688, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76f27000
mmap2(0x76fcd000, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x96000) = 0x76fcd000
mmap2(NULL, 143960, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76f03000
mmap2(0x76f23000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x10000) = 0x76f23000
mmap2(0x76f25000, 4696, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x76f25000
mmap2(NULL, 984424, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76e12000
mmap2(0x76efd000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xdb000) = 0x76efd000
mmap2(0x76f00000, 9576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x76f00000
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76ff5000
mmap2(NULL, 86544, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76dfc000
mmap2(0x76e10000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x4000) = 0x76e10000
mmap2(NULL, 1079440, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76cf4000
mmap2(0x76df3000, 28672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xef000) = 0x76df3000
mmap2(0x76dfa000, 6288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x76dfa000
mmap2(NULL, 479376, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76c7e000
mmap2(0x76cf2000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x64000) = 0x76cf2000
mmap2(NULL, 164412, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76c55000
mmap2(0x76c7d000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x18000) = 0x76c7d000
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76ff4000
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76ff3000
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76ff2000
mmap2(0x200000, 807411712, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x46a53000
mmap2(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x46a13000
mmap2(0x56c54000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x56c54000
mmap2(0x5157e000, 91054080, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = -1 ENOMEM (Cannot allocate memory)
fatal error: runtime: out of memory

runtime stack:
runtime.throw(0xca163, 0x16)
        /usr/local/go/src/runtime/panic.go:596 +0x70 fp=0x7ecf8890 sp=0x7ecf8884
runtime.sysMap(0x5157e000, 0x56d6000, 0x1, 0x147b58)
        /usr/local/go/src/runtime/mem_linux.go:227 +0xb0 fp=0x7ecf88b4 sp=0x7ecf8890
runtime.(*mheap).mapBits(0x13ad50, 0x56d54000)
        /usr/local/go/src/runtime/mbitmap.go:159 +0x94 fp=0x7ecf88cc sp=0x7ecf88b4
runtime.(*mheap).sysAlloc(0x13ad50, 0x100000, 0x3049c)
        /usr/local/go/src/runtime/malloc.go:429 +0x2dc fp=0x7ecf890c sp=0x7ecf88cc
runtime.(*mheap).grow(0x13ad50, 0x8, 0x0)
        /usr/local/go/src/runtime/mheap.go:774 +0x48 fp=0x7ecf893c sp=0x7ecf890c
runtime.(*mheap).allocSpanLocked(0x13ad50, 0x1, 0x0)
        /usr/local/go/src/runtime/mheap.go:678 +0x468 fp=0x7ecf895c sp=0x7ecf893c
runtime.(*mheap).alloc_m(0x13ad50, 0x1, 0x10, 0x0, 0x0)
        /usr/local/go/src/runtime/mheap.go:562 +0xdc fp=0x7ecf8994 sp=0x7ecf895c
runtime.(*mheap).alloc.func1()
        /usr/local/go/src/runtime/mheap.go:627 +0x3c fp=0x7ecf89b0 sp=0x7ecf8994
runtime.systemstack(0x7ecf89c4)
        /usr/local/go/src/runtime/asm_arm.s:278 +0xa8 fp=0x7ecf89b4 sp=0x7ecf89b0
runtime.(*mheap).alloc(0x13ad50, 0x1, 0x10, 0x100, 0x1)
        /usr/local/go/src/runtime/mheap.go:628 +0x60 fp=0x7ecf89dc sp=0x7ecf89b4
runtime.(*mcentral).grow(0x13bb90, 0x0)
        /usr/local/go/src/runtime/mcentral.go:212 +0x84 fp=0x7ecf8a08 sp=0x7ecf89dc
runtime.(*mcentral).cacheSpan(0x13bb90, 0x147b60)
        /usr/local/go/src/runtime/mcentral.go:93 +0x104 fp=0x7ecf8a4c sp=0x7ecf8a08
runtime.(*mcache).refill(0x46a13000, 0x10, 0x147b60)
        /usr/local/go/src/runtime/mcache.go:122 +0x7c fp=0x7ecf8a60 sp=0x7ecf8a4c
runtime.(*mcache).nextFree.func1()
        /usr/local/go/src/runtime/malloc.go:526 +0x24 fp=0x7ecf8a70 sp=0x7ecf8a60
runtime.systemstack(0x7ecf8a94)
        /usr/local/go/src/runtime/asm_arm.s:278 +0xa8 fp=0x7ecf8a74 sp=0x7ecf8a70
runtime.(*mcache).nextFree(0x46a13000, 0x46a13010, 0x7ecf8abc, 0x1ec5c, 0x21cc8)
        /usr/local/go/src/runtime/malloc.go:527 +0x9c fp=0x7ecf8aa0 sp=0x7ecf8a74
runtime.mallocgc(0xf0, 0xc3980, 0x1, 0x46a54001)
        /usr/local/go/src/runtime/malloc.go:679 +0x8c0 fp=0x7ecf8af8 sp=0x7ecf8aa0
runtime.newobject(0xc3980, 0x139498)
        /usr/local/go/src/runtime/malloc.go:808 +0x2c fp=0x7ecf8b0c sp=0x7ecf8af8
runtime.malg(0x8000, 0x2710)
        /usr/local/go/src/runtime/proc.go:2821 +0x1c fp=0x7ecf8b28 sp=0x7ecf8b0c
runtime.mpreinit(0x139728)
        /usr/local/go/src/runtime/os_linux.go:302 +0x1c fp=0x7ecf8b34 sp=0x7ecf8b28
runtime.mcommoninit(0x139728)
        /usr/local/go/src/runtime/proc.go:540 +0x94 fp=0x7ecf8b4c sp=0x7ecf8b34
runtime.schedinit()
        /usr/local/go/src/runtime/proc.go:476 +0x40 fp=0x7ecf8b68 sp=0x7ecf8b4c
runtime.rt0_go(0x7ecf8d04, 0x76eff000, 0x7ecf8d04, 0x1, 0x5cd0c, 0x7ecf8c48, 0x76ffa000, 0xa3b102d0, 0xab9c0e29, 0x128, ...)
        /usr/local/go/src/runtime/asm_arm.s:61 +0x84 fp=0x7ecf8ba8 sp=0x7ecf8b68
+++ exited with 2 +++
# strace -e mmap2 ./zmq
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76f7f000
mmap2(NULL, 771, PROT_READ, MAP_PRIVATE, 3, 0) = 0x76f7e000
mmap2(NULL, 362376, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76f00000
mmap2(0x76f56000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x46000) = 0x76f56000
mmap2(NULL, 143960, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76edc000
mmap2(0x76efc000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x10000) = 0x76efc000
mmap2(0x76efe000, 4696, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x76efe000
mmap2(NULL, 984424, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76deb000
mmap2(0x76ed6000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xdb000) = 0x76ed6000
mmap2(0x76ed9000, 9576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x76ed9000
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76f7d000
mmap2(NULL, 86544, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76dd5000
mmap2(0x76de9000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x4000) = 0x76de9000
mmap2(NULL, 73912, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76dc2000
mmap2(0x76dd3000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1000) = 0x76dd3000
mmap2(NULL, 1079440, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76cba000
mmap2(0x76db9000, 28672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xef000) = 0x76db9000
mmap2(0x76dc0000, 6288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x76dc0000
mmap2(NULL, 479376, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76c44000
mmap2(0x76cb8000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x64000) = 0x76cb8000
mmap2(NULL, 164412, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76c1b000
mmap2(0x76c43000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x18000) = 0x76c43000
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76f7c000
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76f7b000
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76f7a000
mmap2(0x200000, 304095232, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x64a19000
mmap2(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x649d9000
runtime: asks for:1048576-byte block (0 in use)
mmap2(0x74c1a000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x74c1a000
mmap2(0x6d748000, 122494976, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = -1 ENOMEM (Cannot allocate memory)
fatal error: runtime: out of memory

runtime stack:
runtime.throw(0xc8d3d, 0x16)
        /usr/lib/go/src/runtime/panic.go:596 +0x70 fp=0x7eb198a0 sp=0x7eb19894
runtime.sysMap(0x6d748000, 0x74d2000, 0x1, 0x146b60)
        /usr/lib/go/src/runtime/mem_linux.go:227 +0xb0 fp=0x7eb198c4 sp=0x7eb198a0
runtime.(*mheap).mapBits(0x139d58, 0x74d1a000)
        /usr/lib/go/src/runtime/mbitmap.go:159 +0x94 fp=0x7eb198dc sp=0x7eb198c4
runtime.(*mheap).sysAlloc(0x139d58, 0x100000, 0x30414)
        /usr/lib/go/src/runtime/malloc.go:428 +0x2dc fp=0x7eb1991c sp=0x7eb198dc
runtime.(*mheap).grow(0x139d58, 0x8, 0x0)
        /usr/lib/go/src/runtime/mheap.go:774 +0xd0 fp=0x7eb1994c sp=0x7eb1991c
runtime.(*mheap).allocSpanLocked(0x139d58, 0x1, 0x0)
        /usr/lib/go/src/runtime/mheap.go:678 +0x468 fp=0x7eb1996c sp=0x7eb1994c
runtime.(*mheap).alloc_m(0x139d58, 0x1, 0x10, 0x0, 0x0)
        /usr/lib/go/src/runtime/mheap.go:562 +0xdc fp=0x7eb199a4 sp=0x7eb1996c
runtime.(*mheap).alloc.func1()
        /usr/lib/go/src/runtime/mheap.go:627 +0x3c fp=0x7eb199c0 sp=0x7eb199a4
runtime.systemstack(0x7eb199d4)
        /usr/lib/go/src/runtime/asm_arm.s:278 +0xa8 fp=0x7eb199c4 sp=0x7eb199c0
runtime.(*mheap).alloc(0x139d58, 0x1, 0x10, 0x100, 0x1)
        /usr/lib/go/src/runtime/mheap.go:628 +0x60 fp=0x7eb199ec sp=0x7eb199c4
runtime.(*mcentral).grow(0x13ab98, 0x0)
        /usr/lib/go/src/runtime/mcentral.go:212 +0x84 fp=0x7eb19a18 sp=0x7eb199ec
runtime.(*mcentral).cacheSpan(0x13ab98, 0x146b68)
        /usr/lib/go/src/runtime/mcentral.go:93 +0x104 fp=0x7eb19a5c sp=0x7eb19a18
runtime.(*mcache).refill(0x649d9000, 0x10, 0x146b68)
        /usr/lib/go/src/runtime/mcache.go:122 +0x7c fp=0x7eb19a70 sp=0x7eb19a5c
runtime.(*mcache).nextFree.func1()
        /usr/lib/go/src/runtime/malloc.go:525 +0x24 fp=0x7eb19a80 sp=0x7eb19a70
runtime.systemstack(0x7eb19aa4)
        /usr/lib/go/src/runtime/asm_arm.s:278 +0xa8 fp=0x7eb19a84 sp=0x7eb19a80
runtime.(*mcache).nextFree(0x649d9000, 0x649d9010, 0x7eb19acc, 0x1ebd4, 0x21c40)
        /usr/lib/go/src/runtime/malloc.go:526 +0x9c fp=0x7eb19ab0 sp=0x7eb19a84
runtime.mallocgc(0xf0, 0xc2548, 0x1, 0x64a1a001)
        /usr/lib/go/src/runtime/malloc.go:678 +0x8c0 fp=0x7eb19b08 sp=0x7eb19ab0
runtime.newobject(0xc2548, 0x1384a0)
        /usr/lib/go/src/runtime/malloc.go:807 +0x2c fp=0x7eb19b1c sp=0x7eb19b08
runtime.malg(0x8000, 0x2710)
        /usr/lib/go/src/runtime/proc.go:2821 +0x1c fp=0x7eb19b38 sp=0x7eb19b1c
runtime.mpreinit(0x138730)
        /usr/lib/go/src/runtime/os_linux.go:302 +0x1c fp=0x7eb19b44 sp=0x7eb19b38
runtime.mcommoninit(0x138730)
        /usr/lib/go/src/runtime/proc.go:540 +0x94 fp=0x7eb19b5c sp=0x7eb19b44
runtime.schedinit()
        /usr/lib/go/src/runtime/proc.go:476 +0x40 fp=0x7eb19b78 sp=0x7eb19b5c
runtime.rt0_go(0x7eb19d14, 0x76ed8000, 0x7eb19d14, 0x1, 0x5cd10, 0x7eb19c58, 0x76f82000, 0xe0e41da8, 0xe8b59121, 0x128, ...)
        /usr/lib/go/src/runtime/asm_arm.s:61 +0x84 fp=0x7eb19bb8 sp=0x7eb19b78
+++ exited with 2 +++

@davecheney

This comment has been minimized.

Copy link
Contributor

commented Apr 4, 2017

@aclements

This comment has been minimized.

Copy link
Member

commented Apr 4, 2017

This is where things first go wrong:

mmap2(0x200000, 807411712, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x46a53000

Everything before this must be C/zmq initialization. This is runtime.mallocinit making its initial reservation. From this, we can tell that it's trying to make the reservation at 0x200000, which is a perfectly reasonable low address, for 807411712 bytes, which means it's trying the 512MB reservation (the first size it tries). It succeeds, but the kernel places it at 0x46a53000. Since this is where the heap starts, we later try to map a large bitmap to handle any future allocation anywhere between 0 and 0x46a53000.

Unfortunately, this doesn't explain why it got mapped there. Based on your readelf output, the binary isn't mapped there, and based on your strace output none of the earlier mmaps are there either, so the kernel should have been able to give up the requested address. It also doesn't explain why the bitmap mmap is failing, since you have overcommit (heuristically) allowed and are clearly well under the mmap limit.

Could you try running echo 1 | sudo tee /proc/sys/vm/overcommit_memory to strictly allow overcommit and re-running your binary? If that succeeds, it will at least answer one question.

@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 4, 2017

Could you try running echo 1 | sudo tee /proc/sys/vm/overcommit_memory to strictly allow overcommit and re-running your binary? If that succeeds, it will at least answer one question.

If I do this it works. I guess it was exceeding the overcommit. TIL

Thanks for explaining! That makes sense. It seems to me this extra memory won't get faulted so it's not elegant but should work. Maybe issue a warning in this case? Or use the reservation's actual address? Unless assuming the heap starts at zero saves some cycles later on?

@aclements

This comment has been minimized.

Copy link
Member

commented Apr 4, 2017

Maybe issue a warning in this case?

There are no warnings in the runtime. It would seem odd for this to be the first one. :)

I still don't understand why this is happening, though. From what you've posted, there's no obvious reason why the kernel is giving us a high address instead of the one we asked for. Could you tweak your simple program that printed the version of zmq to also print the contents of /proc/self/maps before exiting and post the output along with its strace?

Or use the reservation's actual address? Unless assuming the heap starts at zero saves some cycles later on?

It's not about cycles; it's about how much memory you can allocate. Starting the arena at zero means the Go heap can use the entire address space before running out of memory, which can be important in a limited 32-bit address space. We didn't used to do this, which meant programs OOM'ed after just 512 MB of allocation, even if there was plenty of RAM left.

It would be nice if we only had to map the bitmap for the part we're actually using, but we don't have the structures to do that right now. However, I have been thinking about whether we could unmap parts the bitmap when we release heap memory back to the OS, and supporting that may make it easier to only map the bitmap we need in the first place.

@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 5, 2017

Could you tweak your simple program that printed the version of zmq to also print the contents of /proc/self/maps

Here it is:

4 2 1
00010000-0011c000 r-xp 00000000 00:0c 2542       /root/zmq
0012b000-0013b000 rw-p 0010b000 00:0c 2542       /root/zmq
0013b000-0014d000 rw-p 00000000 00:00 0 
01500000-01525000 rw-p 00000000 00:00 0          [heap]
6393c000-6397c000 rw-p 00000000 00:00 0 
6397c000-6397d000 ---p 00000000 00:00 0 
6397d000-6417c000 rw-p 00000000 00:00 0          [stack:476]
6417c000-6417d000 ---p 00000000 00:00 0 
6417d000-64ac6000 rw-p 00000000 00:00 0          [stack:475]
64ac6000-6d70e000 ---p 00000000 00:00 0 
6d70e000-74cdc000 rw-p 00000000 00:00 0          [stack:474]
74cdc000-76bde000 ---p 00000000 00:00 0 
76bde000-76bf6000 r-xp 00000000 00:0c 935        /lib/libgcc_s.so.1
76bf6000-76c06000 ---p 00018000 00:0c 935        /lib/libgcc_s.so.1
76c06000-76c07000 rw-p 00018000 00:0c 935        /lib/libgcc_s.so.1
76c07000-76c6c000 r-xp 00000000 00:0c 896        /lib/libm-2.21.so
76c6c000-76c7b000 ---p 00065000 00:0c 896        /lib/libm-2.21.so
76c7b000-76c7c000 r--p 00064000 00:0c 896        /lib/libm-2.21.so
76c7c000-76c7d000 rw-p 00065000 00:0c 896        /lib/libm-2.21.so
76c7d000-76d6c000 r-xp 00000000 00:0c 1603       /usr/lib/libstdc++.so.6.0.21
76d6c000-76d7c000 ---p 000ef000 00:0c 1603       /usr/lib/libstdc++.so.6.0.21
76d7c000-76d81000 r--p 000ef000 00:0c 1603       /usr/lib/libstdc++.so.6.0.21
76d81000-76d83000 rw-p 000f4000 00:0c 1603       /usr/lib/libstdc++.so.6.0.21
76d83000-76d85000 rw-p 00000000 00:00 0 
76d85000-76d87000 r-xp 00000000 00:0c 915        /lib/libdl-2.21.so
76d87000-76d96000 ---p 00002000 00:0c 915        /lib/libdl-2.21.so
76d96000-76d97000 r--p 00001000 00:0c 915        /lib/libdl-2.21.so
76d97000-76d98000 rw-p 00002000 00:0c 915        /lib/libdl-2.21.so
76d98000-76d9d000 r-xp 00000000 00:0c 715        /lib/librt-2.21.so
76d9d000-76dac000 ---p 00005000 00:0c 715        /lib/librt-2.21.so
76dac000-76dad000 r--p 00004000 00:0c 715        /lib/librt-2.21.so
76dad000-76dae000 rw-p 00005000 00:0c 715        /lib/librt-2.21.so
76dae000-76e8a000 r-xp 00000000 00:0c 949        /lib/libc-2.21.so
76e8a000-76e99000 ---p 000dc000 00:0c 949        /lib/libc-2.21.so
76e99000-76e9b000 r--p 000db000 00:0c 949        /lib/libc-2.21.so
76e9b000-76e9c000 rw-p 000dd000 00:0c 949        /lib/libc-2.21.so
76e9c000-76e9f000 rw-p 00000000 00:00 0 
76e9f000-76eb0000 r-xp 00000000 00:0c 909        /lib/libpthread-2.21.so
76eb0000-76ebf000 ---p 00011000 00:0c 909        /lib/libpthread-2.21.so
76ebf000-76ec0000 r--p 00010000 00:0c 909        /lib/libpthread-2.21.so
76ec0000-76ec1000 rw-p 00011000 00:0c 909        /lib/libpthread-2.21.so
76ec1000-76ec3000 rw-p 00000000 00:00 0 
76ec3000-76f09000 r-xp 00000000 00:0c 2480       /usr/lib/libzmq.so.5
76f09000-76f19000 ---p 00046000 00:0c 2480       /usr/lib/libzmq.so.5
76f19000-76f1c000 rw-p 00046000 00:0c 2480       /usr/lib/libzmq.so.5
76f1c000-76f34000 r-xp 00000000 00:0c 890        /lib/ld-2.21.so
76f3d000-76f41000 rw-p 00000000 00:00 0 
76f42000-76f43000 rw-p 00000000 00:00 0 
76f43000-76f44000 r-xp 00000000 00:00 0          [sigpage]
76f44000-76f45000 r--p 00018000 00:0c 890        /lib/ld-2.21.so
76f45000-76f46000 rw-p 00019000 00:0c 890        /lib/ld-2.21.so
7ee93000-7eeb4000 rw-p 00000000 00:00 0 
ffff0000-ffff1000 r-xp 00000000 00:00 0          [vectors]
@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 5, 2017

strace is a bit long:

execve("./zmq", ["./zmq"], [/* 20 vars */]) = 0
brk(NULL)                               = 0x10b8000
uname({sysname="Linux", nodename="Ambarella", ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76f5a000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat64(3, {st_mode=S_IFREG|0755, st_size=771, ...}) = 0
mmap2(NULL, 771, PROT_READ, MAP_PRIVATE, 3, 0) = 0x76f59000
close(3)                                = 0
open("/lib/tls/v7l/neon/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/tls/v7l/neon/vfp", 0x7edf93b8) = -1 ENOENT (No such file or directory)
open("/lib/tls/v7l/neon/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/tls/v7l/neon", 0x7edf93b8) = -1 ENOENT (No such file or directory)
open("/lib/tls/v7l/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/tls/v7l/vfp", 0x7edf93b8)  = -1 ENOENT (No such file or directory)
open("/lib/tls/v7l/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/tls/v7l", 0x7edf93b8)      = -1 ENOENT (No such file or directory)
open("/lib/tls/neon/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/tls/neon/vfp", 0x7edf93b8) = -1 ENOENT (No such file or directory)
open("/lib/tls/neon/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/tls/neon", 0x7edf93b8)     = -1 ENOENT (No such file or directory)
open("/lib/tls/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/tls/vfp", 0x7edf93b8)      = -1 ENOENT (No such file or directory)
open("/lib/tls/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/tls", 0x7edf93b8)          = -1 ENOENT (No such file or directory)
open("/lib/v7l/neon/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/v7l/neon/vfp", 0x7edf93b8) = -1 ENOENT (No such file or directory)
open("/lib/v7l/neon/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/v7l/neon", 0x7edf93b8)     = -1 ENOENT (No such file or directory)
open("/lib/v7l/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/v7l/vfp", 0x7edf93b8)      = -1 ENOENT (No such file or directory)
open("/lib/v7l/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/v7l", 0x7edf93b8)          = -1 ENOENT (No such file or directory)
open("/lib/neon/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/neon/vfp", 0x7edf93b8)     = -1 ENOENT (No such file or directory)
open("/lib/neon/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/neon", 0x7edf93b8)         = -1 ENOENT (No such file or directory)
open("/lib/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib/vfp", 0x7edf93b8)          = -1 ENOENT (No such file or directory)
open("/lib/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/lib", {st_mode=S_IFDIR|0755, st_size=4744, ...}) = 0
open("/usr/lib/tls/v7l/neon/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/tls/v7l/neon/vfp", 0x7edf93b8) = -1 ENOENT (No such file or directory)
open("/usr/lib/tls/v7l/neon/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/tls/v7l/neon", 0x7edf93b8) = -1 ENOENT (No such file or directory)
open("/usr/lib/tls/v7l/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/tls/v7l/vfp", 0x7edf93b8) = -1 ENOENT (No such file or directory)
open("/usr/lib/tls/v7l/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/tls/v7l", 0x7edf93b8)  = -1 ENOENT (No such file or directory)
open("/usr/lib/tls/neon/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/tls/neon/vfp", 0x7edf93b8) = -1 ENOENT (No such file or directory)
open("/usr/lib/tls/neon/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/tls/neon", 0x7edf93b8) = -1 ENOENT (No such file or directory)
open("/usr/lib/tls/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/tls/vfp", 0x7edf93b8)  = -1 ENOENT (No such file or directory)
open("/usr/lib/tls/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/tls", 0x7edf93b8)      = -1 ENOENT (No such file or directory)
open("/usr/lib/v7l/neon/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/v7l/neon/vfp", 0x7edf93b8) = -1 ENOENT (No such file or directory)
open("/usr/lib/v7l/neon/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/v7l/neon", 0x7edf93b8) = -1 ENOENT (No such file or directory)
open("/usr/lib/v7l/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/v7l/vfp", 0x7edf93b8)  = -1 ENOENT (No such file or directory)
open("/usr/lib/v7l/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/v7l", 0x7edf93b8)      = -1 ENOENT (No such file or directory)
open("/usr/lib/neon/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/neon/vfp", 0x7edf93b8) = -1 ENOENT (No such file or directory)
open("/usr/lib/neon/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/neon", 0x7edf93b8)     = -1 ENOENT (No such file or directory)
open("/usr/lib/vfp/libzmq.so.5", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
stat64("/usr/lib/vfp", 0x7edf93b8)      = -1 ENOENT (No such file or directory)
open("/usr/lib/libzmq.so.5", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0(z\0\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0644, st_size=298152, ...}) = 0
mmap2(NULL, 362376, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76edb000
mprotect(0x76f21000, 65536, PROT_NONE)  = 0
mmap2(0x76f31000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x46000) = 0x76f3100
0
close(3)                                = 0
open("/lib/libpthread.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\3\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\271F\0\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=72184, ...}) = 0
mmap2(NULL, 143960, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76eb7000
mprotect(0x76ec8000, 61440, PROT_NONE)  = 0
mmap2(0x76ed7000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x10000) = 0x76ed7000

mmap2(0x76ed9000, 4696, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x76ed9000
close(3)                                = 0
open("/lib/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\3\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\255h\1\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=915232, ...}) = 0
mmap2(NULL, 984424, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76dc6000
mprotect(0x76ea2000, 61440, PROT_NONE)  = 0
mmap2(0x76eb1000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xdb000) = 0x76eb100
0
mmap2(0x76eb4000, 9576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x76eb4000
close(3)                                = 0
open("/lib/librt.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\3\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0 \27\0\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=22472, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76f58000
mmap2(NULL, 86544, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76db0000
mprotect(0x76db5000, 61440, PROT_NONE)  = 0
mmap2(0x76dc4000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x4000) = 0x76dc4000
close(3)                                = 0
open("/lib/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0<\t\0\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=9736, ...}) = 0
mmap2(NULL, 73912, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76d9d000
mprotect(0x76d9f000, 61440, PROT_NONE)  = 0
mmap2(0x76dae000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1000) = 0x76dae000
close(3)                                = 0
open("/lib/libstdc++.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/usr/lib/libstdc++.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\3\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0p\267\6\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1007180, ...}) = 0
mmap2(NULL, 1079440, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76c95000
mprotect(0x76d84000, 65536, PROT_NONE)  = 0
mmap2(0x76d94000, 28672, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xef000) = 0x76d9400
0
mmap2(0x76d9b000, 6288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x76d9b000
close(3)                                = 0
open("/lib/libm.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\0<\0\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=415240, ...}) = 0
mmap2(NULL, 479376, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76c1f000
mprotect(0x76c84000, 61440, PROT_NONE)  = 0
mmap2(0x76c93000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x64000) = 0x76c93000

close(3)                                = 0
open("/lib/libgcc_s.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\370\315\0\0004\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=100288, ...}) = 0
mmap2(NULL, 164412, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x76bf6000
mprotect(0x76c0e000, 65536, PROT_NONE)  = 0
mmap2(0x76c1e000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x18000) = 0x76c1e000

close(3)                                = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76f57000
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76f56000
set_tls(0x76f564c0, 0x76f56bb8, 0x76f5d050, 0x76f564c0, 0x3) = 0
mprotect(0x76eb1000, 8192, PROT_READ)   = 0
mprotect(0x76c93000, 4096, PROT_READ)   = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76f55000
mprotect(0x76d94000, 20480, PROT_READ)  = 0
mprotect(0x76dae000, 4096, PROT_READ)   = 0
mprotect(0x76ed7000, 4096, PROT_READ)   = 0
mprotect(0x76dc4000, 4096, PROT_READ)   = 0
mprotect(0x76f5c000, 4096, PROT_READ)   = 0
munmap(0x76f59000, 771)                 = 0
set_tid_address(0x76f56068)             = 496
set_robust_list(0x76f56070, 12)         = 0
rt_sigaction(SIGRTMIN, {sa_handler=0x76ebb1d5, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restorer=0x7
6deb591}, NULL, 8) = 0
rt_sigaction(SIGRT_1, {sa_handler=0x76ebb275, sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART|SA_SIGINFO, sa_re
storer=0x76deb591}, NULL, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
ugetrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM_INFINITY}) = 0
brk(NULL)                               = 0x10b8000
brk(0x10dd000)                          = 0x10dd000
getpid()                                = 496
sched_getaffinity(0, 8192, [0])         = 4
mmap2(0x200000, 304095232, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x649f4000
mmap2(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x649b4000
clock_gettime(CLOCK_MONOTONIC, {tv_sec=926, tv_nsec=284330541}) = 0
write(2, "runtime: asks for:", 18runtime: asks for:)      = 18
write(2, "1048576", 71048576)                  = 7
write(2, "-byte block (", 13-byte block ()           = 13
write(2, "0", 10)                        = 1
write(2, " in use)\n", 9 in use)
)               = 9
mmap2(0x74bf4000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x74bf4000
mmap2(0x6d724000, 122486784, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x6d724000

mmap2(0x649f4000, 958464, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x649f4000
mmap2(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x649a4000
clock_gettime(CLOCK_MONOTONIC, {tv_sec=926, tv_nsec=314849356}) = 0
mmap2(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x64994000
rt_sigprocmask(SIG_SETMASK, NULL, [], 8) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=926, tv_nsec=323581486}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=926, tv_nsec=325838282}) = 0
sigaltstack(NULL, {ss_sp=NULL, ss_flags=SS_DISABLE, ss_size=0}) = 0
sigaltstack({ss_sp=0x74bf6000, ss_flags=0, ss_size=32720}, NULL) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
gettid()                                = 496
clock_gettime(CLOCK_MONOTONIC, {tv_sec=926, tv_nsec=337271412}) = 0
rt_sigaction(SIGHUP, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGHUP, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) =
 0
rt_sigaction(SIGINT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGINT, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) =
 0
rt_sigaction(SIGQUIT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGQUIT, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGILL, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGILL, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) =
 0
rt_sigaction(SIGTRAP, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTRAP, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGABRT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGABRT, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGBUS, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGBUS, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) =
 0
rt_sigaction(SIGFPE, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGFPE, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) =
 0
rt_sigaction(SIGUSR1, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGUSR1, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGSEGV, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGSEGV, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGUSR2, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGUSR2, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGPIPE, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGPIPE, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGALRM, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGALRM, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGTERM, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGTERM, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGSTKFLT, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGSTKFLT, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8
) = 0
rt_sigaction(SIGCHLD, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGCHLD, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGURG, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGURG, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) =
 0
rt_sigaction(SIGXCPU, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGXCPU, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGXFSZ, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGXFSZ, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGVTALRM, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGVTALRM, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8
) = 0
rt_sigaction(SIGPROF, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGPROF, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGWINCH, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGWINCH, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGIO, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGIO, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) = 
0
rt_sigaction(SIGPWR, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGPWR, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) =
 0
rt_sigaction(SIGSYS, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGSYS, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) =
 0
rt_sigaction(SIGRTMIN, NULL, {sa_handler=0x76ebb1d5, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restor
er=0x76deb591}, 8) = 0
rt_sigaction(SIGRTMIN, NULL, {sa_handler=0x76ebb1d5, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restor
er=0x76deb591}, 8) = 0
rt_sigaction(SIGRTMIN, {sa_handler=0x76ebb1d5, sa_mask=[], sa_flags=SA_RESTORER|SA_STACK|SA_SIGINFO, sa_res
torer=0x76deb591}, NULL, 8) = 0
rt_sigaction(SIGRT_1, NULL, {sa_handler=0x76ebb275, sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART|SA_SIGINFO,
 sa_restorer=0x76deb591}, 8) = 0
rt_sigaction(SIGRT_1, NULL, {sa_handler=0x76ebb275, sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART|SA_SIGINFO,
 sa_restorer=0x76deb591}, 8) = 0
rt_sigaction(SIGRT_1, {sa_handler=0x76ebb275, sa_mask=[], sa_flags=SA_RESTORER|SA_STACK|SA_RESTART|SA_SIGIN
FO, sa_restorer=0x76deb591}, NULL, 8) = 0
rt_sigaction(SIGRT_2, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_2, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGRT_3, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_3, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGRT_4, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_4, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGRT_5, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_5, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGRT_6, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_6, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGRT_7, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_7, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGRT_8, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_8, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGRT_9, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_9, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8) 
= 0
rt_sigaction(SIGRT_10, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_10, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_11, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_11, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_12, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_12, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_13, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_13, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_14, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_14, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_15, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_15, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_16, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_16, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_17, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_17, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_18, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_18, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_19, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_19, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_20, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_20, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_21, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_21, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_22, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_22, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_23, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_23, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_24, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_24, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
rt_sigaction(SIGRT_25, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_25, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_26, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_26, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_27, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_27, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_28, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_28, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_29, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_29, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_30, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_30, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_31, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_31, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
rt_sigaction(SIGRT_32, NULL, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
rt_sigaction(SIGRT_32, {sa_handler=0x5d21c, sa_mask=~[], sa_flags=SA_STACK|SA_RESTART|SA_SIGINFO}, NULL, 8)
 = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=926, tv_nsec=613713671}) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=926, tv_nsec=615886152}) = 0
rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
mmap2(NULL, 8388608, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x64194000
mprotect(0x64194000, 4096, PROT_NONE)   = 0
clone(child_stack=0x64992f88, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|
CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x649934b8, tls=0x64993910, child_tidp
tr=0x649934b8) = 497
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
clock_gettime(CLOCK_MONOTONIC, {tv_sec=926, tv_nsec=630110819}) = 0
rt_sigprocmask(SIG_SETMASK, ~[RTMIN RT_1], [], 8) = 0
mmap2(NULL, 8388608, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x63994000
mprotect(0x63994000, 4096, PROT_NONE)   = 0
clone(child_stack=0x64192f88, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|
CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x641934b8, tls=0x64193910, child_tidp
tr=0x641934b8) = 498
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
futex(0x74c185ac, FUTEX_WAKE, 1)        = 1
readlinkat(AT_FDCWD, "/proc/self/exe", "/root/zmq", 128) = 9
mmap2(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x63954000
openat(AT_FDCWD, "/proc/sys/net/core/somaxconn", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
read(3, "128\n", 4096)                  = 4
read(3, "", 4092)                       = 0
close(3)                                = 0
socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 3
close(3)                                = 0
socket(AF_INET6, SOCK_STREAM, IPPROTO_TCP) = -1 EAFNOSUPPORT (Address family not supported by protocol)
socket(AF_INET6, SOCK_STREAM, IPPROTO_TCP) = -1 EAFNOSUPPORT (Address family not supported by protocol)
futex(0x74c185ac, FUTEX_WAKE, 1)        = 1
eventfd2(0, 0)                          = 3
fcntl64(3, F_GETFL)                     = 0x2 (flags O_RDWR)
fcntl64(3, F_SETFL, O_RDWR|O_NONBLOCK)  = 0
fcntl64(3, F_GETFL)                     = 0x802 (flags O_RDWR|O_NONBLOCK)
fcntl64(3, F_SETFL, O_RDWR|O_NONBLOCK)  = 0
open("/dev/urandom", O_RDONLY)          = 4
read(4, "f\335=M", 4)                   = 4
futex(0x13b5bc, FUTEX_WAKE, 1)          = 1
futex(0x13b548, FUTEX_WAKE, 1)          = 1
write(1, "4 2 1\n", 64 2 1
)                  = 6
futex(0x13b5bc, FUTEX_WAKE, 1)          = 1
futex(0x13b548, FUTEX_WAKE, 1)          = 1
openat(AT_FDCWD, "/proc/self/maps", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 5
futex(0x13b5bc, FUTEX_WAKE, 1)          = 1
futex(0x13b548, FUTEX_WAKE, 1)          = 1
fstat64(5, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
futex(0x13b5bc, FUTEX_WAKE, 1)          = 1
futex(0x13b548, FUTEX_WAKE, 1)          = 1
read(5, "00010000-0011c000 r-xp 00000000 "..., 512) = 512
futex(0x13b5bc, FUTEX_WAKE, 1)          = 1
futex(0x13b548, FUTEX_WAKE, 1)          = 1
read(5, "cf4000 rw-p 00000000 00:00 0    "..., 1024) = 1024
futex(0x13b5bc, FUTEX_WAKE, 1)          = 1
futex(0x13b548, FUTEX_WAKE, 1)          = 1
read(5, "5        /lib/libdl-2.21.so\n76da"..., 2048) = 1724
futex(0x13b5bc, FUTEX_WAKE, 1)          = 1
futex(0x13b548, FUTEX_WAKE, 1)          = 1
read(5, "", 4420)                       = 0
futex(0x13b5bc, FUTEX_WAKE, 1)          = 1
futex(0x13b548, FUTEX_WAKE, 1)          = 1
close(5)                                = 0
futex(0x13b5bc, FUTEX_WAKE, 1)          = 1
futex(0x13b548, FUTEX_WAKE, 1)          = 1
write(1, "00010000-0011c000 r-xp 00000000 "..., 326000010000-0011c000 r-xp 00000000 00:0c 2542       /root/
zmq
0012b000-0013b000 rw-p 0010b000 00:0c 2542       /root/zmq
0013b000-0014d000 rw-p 00000000 00:00 0 
010b8000-010dd000 rw-p 00000000 00:00 0          [heap]
63954000-63994000 rw-p 00000000 00:00 0 
63994000-63995000 ---p 00000000 00:00 0 
63995000-64194000 rw-p 00000000 00:00 0          [stack:498]
64194000-64195000 ---p 00000000 00:00 0 
64195000-64ade000 rw-p 00000000 00:00 0          [stack:497]
64ade000-6d724000 ---p 00000000 00:00 0 
6d724000-74cf4000 rw-p 00000000 00:00 0          [stack:496]
74cf4000-76bf6000 ---p 00000000 00:00 0 
76bf6000-76c0e000 r-xp 00000000 00:0c 935        /lib/libgcc_s.so.1
76c0e000-76c1e000 ---p 00018000 00:0c 935        /lib/libgcc_s.so.1
76c1e000-76c1f000 rw-p 00018000 00:0c 935        /lib/libgcc_s.so.1
76c1f000-76c84000 r-xp 00000000 00:0c 896        /lib/libm-2.21.so
76c84000-76c93000 ---p 00065000 00:0c 896        /lib/libm-2.21.so
76c93000-76c94000 r--p 00064000 00:0c 896        /lib/libm-2.21.so
76c94000-76c95000 rw-p 00065000 00:0c 896        /lib/libm-2.21.so
76c95000-76d84000 r-xp 00000000 00:0c 1603       /usr/lib/libstdc++.so.6.0.21
76d84000-76d94000 ---p 000ef000 00:0c 1603       /usr/lib/libstdc++.so.6.0.21
76d94000-76d99000 r--p 000ef000 00:0c 1603       /usr/lib/libstdc++.so.6.0.21
76d99000-76d9b000 rw-p 000f4000 00:0c 1603       /usr/lib/libstdc++.so.6.0.21
76d9b000-76d9d000 rw-p 00000000 00:00 0 
76d9d000-76d9f000 r-xp 00000000 00:0c 915        /lib/libdl-2.21.so
76d9f000-76dae000 ---p 00002000 00:0c 915        /lib/libdl-2.21.so
010b8000-010dd000 rw-p 00000000 00:00 0          [heap]
63954000-63994000 rw-p 00000000 00:00 0 
63994000-63995000 ---p 00000000 00:00 0 
63995000-64194000 rw-p 00000000 00:00 0          [stack:498]
64194000-64195000 ---p 00000000 00:00 0 
64195000-64ade000 rw-p 00000000 00:00 0          [stack:497]
64ade000-6d724000 ---p 00000000 00:00 0 
6d724000-74cf4000 rw-p 00000000 00:00 0          [stack:496]
74cf4000-76bf6000 ---p 00000000 00:00 0 
76bf6000-76c0e000 r-xp 00000000 00:0c 935        /lib/libgcc_s.so.1
76c0e000-76c1e000 ---p 00018000 00:0c 935        /lib/libgcc_s.so.1
76c1e000-76c1f000 rw-p 00018000 00:0c 935        /lib/libgcc_s.so.1
76c1f000-76c84000 r-xp 00000000 00:0c 896        /lib/libm-2.21.so
76c84000-76c93000 ---p 00065000 00:0c 896        /lib/libm-2.21.so
76c93000-76c94000 r--p 00064000 00:0c 896        /lib/libm-2.21.so
76c94000-76c95000 rw-p 00065000 00:0c 896        /lib/libm-2.21.so
76c95000-76d84000 r-xp 00000000 00:0c 1603       /usr/lib/libstdc++.so.6.0.21
76d84000-76d94000 ---p 000ef000 00:0c 1603       /usr/lib/libstdc++.so.6.0.21
76d94000-76d99000 r--p 000ef000 00:0c 1603       /usr/lib/libstdc++.so.6.0.21
76d99000-76d9b000 rw-p 000f4000 00:0c 1603       /usr/lib/libstdc++.so.6.0.21
76d9b000-76d9d000 rw-p 00000000 00:00 0 
76d9d000-76d9f000 r-xp 00000000 00:0c 915        /lib/libdl-2.21.so
76d9f000-76dae000 ---p 00002000 00:0c 915        /lib/libdl-2.21.so
76dae000-76daf000 r--p 00001000 00:0c 915        /lib/libdl-2.21.so
76daf000-76db0000 rw-p 00002000 00:0c 915        /lib/libdl-2.21.so
76db0000-76db5000 r-xp 00000000 00:0c 715        /lib/librt-2.21.so
76db5000-76dc4000 ---p 00005000 00:0c 715        /lib/librt-2.21.so
76dc4000-76dc5000 r--p 00004000 00:0c 715        /lib/librt-2.21.so
76dc5000-76dc6000 rw-p 00005000 00:0c 715        /lib/librt-2.21.so
76dc6000-76ea2000 r-xp 00000000 00:0c 949        /lib/libc-2.21.so
76ea2000-76eb1000 ---p 000dc000 00:0c 949        /lib/libc-2.21.so
76eb1000-76eb3000 r--p 000db000 00:0c 949        /lib/libc-2.21.so
76eb3000-76eb4000 rw-p 000dd000 00:0c 949        /lib/libc-2.21.so
76eb4000-76eb7000 rw-p 00000000 00:00 0 
76eb7000-76ec8000 r-xp 00000000 00:0c 909        /lib/libpthread-2.21.so
76ec8000-76ed7000 ---p 00011000 00:0c 909        /lib/libpthread-2.21.so
76ed7000-76ed8000 r--p 00010000 00:0c 909        /lib/libpthread-2.21.so
76ed8000-76ed9000 rw-p 00011000 00:0c 909        /lib/libpthread-2.21.so
76ed9000-76edb000 rw-p 00000000 00:00 0 
76edb000-76f21000 r-xp 00000000 00:0c 2480       /usr/lib/libzmq.so.5
76f21000-76f31000 ---p 00046000 00:0c 2480       /usr/lib/libzmq.so.5
76f31000-76f34000 rw-p 00046000 00:0c 2480       /usr/lib/libzmq.so.5
76f34000-76f4c000 r-xp 00000000 00:0c 890        /lib/ld-2.21.so
76f55000-76f59000 rw-p 00000000 00:00 0 
76f5a000-76f5b000 rw-p 00000000 00:00 0 
76f5b000-76f5c000 r-xp 00000000 00:00 0          [sigpage]
76f5c000-76f5d000 r--p 00018000 00:0c 890        /lib/ld-2.21.so
76f5d000-76f5e000 rw-p 00019000 00:0c 890        /lib/ld-2.21.so
7edd9000-7edfa000 rw-p 00000000 00:00 0 
ffff0000-ffff1000 r-xp 00000000 00:00 0          [vectors]
) = 3260
futex(0x13b5bc, FUTEX_WAKE, 1)          = 1
futex(0x13b548, FUTEX_WAKE, 1)          = 1
exit_group(0)                           = ?
+++ exited with 0 +++
@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 5, 2017

There are no warnings in the runtime. It would seem odd for this to be the first one. :)

Fair enough. I'm pretty new to go.

@aclements

This comment has been minimized.

Copy link
Member

commented Apr 6, 2017

Ah hah.

brk(0x10dd000)                          = 0x10dd000
...
010b8000-010dd000 rw-p 00000000 00:00 0          [heap]

Something, presumably part of zmq, is growing the process brk before Go runtime initialization. For reasons I don't entirely understand, the brk mapping wound up right in the middle of the heap mapping Go asked for, which is why that failed and the kernel put the heap mapping somewhere else.

@plasticchris, can you gdb your binary, set a breakpoint on brk and post the backtrace? I'd like to understand where that's coming from.

A possible fix for this is for the runtime to query the brk and factor that in to where it asks to put the heap mapping.

@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 6, 2017

Breakpoint 1, 0x76ef8762 in brk () from target:/lib/libc.so.6
(gdb) bt
#0  0x76ef8762 in brk () from target:/lib/libc.so.6
#1  0x76ef87f0 in sbrk () from target:/lib/libc.so.6
#2  0x76ebe88e in __default_morecore () from target:/lib/libc.so.6
#3  0x76ebb84e in ?? () from target:/lib/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

It never had a problem running under GDB, so I'm not sure if it is representative.

@aclements

This comment has been minimized.

Copy link
Member

commented Apr 6, 2017

That's too bad. Though the backtrace at least confirms that something is calling C malloc before Go runtime initialization. I took a look at Ubuntu's libzmq.so.3 (just because it was the easiest thing to get my hands on) and it does have some global constructors that the dynamic linker will run before invoking Go runtime initialization, so this isn't too surprising.

@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 6, 2017

Running it on the pi gives a bit more info:

Starting program: /home/pi/zmq 

Breakpoint 1, __brk (addr=addr@entry=0x0) at ../ports/sysdeps/unix/sysv/linux/arm/brk.c:28
28	../ports/sysdeps/unix/sysv/linux/arm/brk.c: No such file or directory.
(gdb) bt
#0  __brk (addr=addr@entry=0x0) at ../ports/sysdeps/unix/sysv/linux/arm/brk.c:28
#1  0xb6fe5ac8 in frob_brk () at ../sysdeps/unix/sysv/linux/dl-sysdep.c:35
#2  _dl_sysdep_start (start_argptr=start_argptr@entry=0xbefff780, dl_main=0x0) at ../elf/dl-sysdep.c:223
#3  0xb6fd3c78 in _dl_start_final (arg=0xbefff780, arg@entry=0x0, info=info@entry=0xbefff500) at rtld.c:330
#4  0xb6fd3f08 in _dl_start (arg=0x0) at rtld.c:558
#5  0xb6fcfd50 in _start () from /lib/ld-linux-armhf.so.3
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb) c
Continuing.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/arm-linux-gnueabihf/libthread_db.so.1".

Breakpoint 1, __brk (addr=addr@entry=0x0) at ../ports/sysdeps/unix/sysv/linux/arm/brk.c:28
28	../ports/sysdeps/unix/sysv/linux/arm/brk.c: No such file or directory.
(gdb) bt
#0  __brk (addr=addr@entry=0x0) at ../ports/sysdeps/unix/sysv/linux/arm/brk.c:28
#1  0xb6ea4ec4 in __GI___sbrk (increment=135168) at sbrk.c:43
#2  0xb6e51550 in __GI___default_morecore (increment=<optimized out>) at morecore.c:47
#3  0xb6e4d130 in sysmalloc (av=0xb6f184d4 <main_arena>, nb=16) at malloc.c:2462
#4  _int_malloc (av=av@entry=0xb6f184d4 <main_arena>, bytes=bytes@entry=12) at malloc.c:3800
#5  0xb6e4ee18 in __GI___libc_malloc (bytes=12) at malloc.c:2891
#6  0xb6e4ef18 in __GI___libc_malloc (bytes=12) at malloc.c:2883
#7  0x000a36e0 in x_cgo_thread_start ()
#8  0x0005c0a8 in runtime.asmcgocall () at /usr/local/go/src/runtime/asm_arm.s:543
#9  0x000c6b30 in type.* ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb) c
Continuing.

Breakpoint 1, __brk (addr=0x16c000) at ../ports/sysdeps/unix/sysv/linux/arm/brk.c:28
28	in ../ports/sysdeps/unix/sysv/linux/arm/brk.c
(gdb) bt
#0  __brk (addr=0x16c000) at ../ports/sysdeps/unix/sysv/linux/arm/brk.c:28
#1  0xb6ea4eac in __GI___sbrk (increment=135168) at sbrk.c:53
#2  0xb6e51550 in __GI___default_morecore (increment=<optimized out>) at morecore.c:47
#3  0xb6e4d130 in sysmalloc (av=0xb6f184d4 <main_arena>, nb=16) at malloc.c:2462
#4  _int_malloc (av=av@entry=0xb6f184d4 <main_arena>, bytes=bytes@entry=12) at malloc.c:3800
#5  0xb6e4ee18 in __GI___libc_malloc (bytes=12) at malloc.c:2891
#6  0xb6e4ef18 in __GI___libc_malloc (bytes=12) at malloc.c:2883
#7  0x000a36e0 in x_cgo_thread_start ()
#8  0x0005c0a8 in runtime.asmcgocall () at /usr/local/go/src/runtime/asm_arm.s:543
#9  0x000c6b30 in type.* ()
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb) c
Continuing.
[New Thread 0xb6bcc450 (LWP 13795)]
[New Thread 0xb63cc450 (LWP 13796)]
4 2 1
[Thread 0xb63cc450 (LWP 13796) exited]
[Thread 0xb6bcc450 (LWP 13795) exited]
[Inferior 1 (process 13794) exited normally]
@aclements

This comment has been minimized.

Copy link
Member

commented Apr 6, 2017

@plasticchris, can you try patching in https://go-review.googlesource.com/39810 and see if that works with the default overcommit setting? It implements the idea of checking and avoiding the brk while setting up the Go heap. It'll only build on linux/arm and linux/386 right now since I haven't implemented the brk syscall on anything else (which is a real pain :( ).

@plasticchris

This comment has been minimized.

Copy link
Author

commented Apr 10, 2017

@aclements the patch works, mmap2 gets the address it requests. Here is the relevant part of the strace:

ugetrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM_INFINITY}) = 0
brk(NULL)                               = 0x68d000
brk(0x6b2000)                           = 0x6b2000
getpid()                                = 483
sched_getaffinity(0, 8192, [0])         = 4
brk(NULL)                               = 0x6b2000
mmap2(0x800000, 807411712, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x800000
mmap2(NULL, 262144, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76c14000
clock_gettime(CLOCK_MONOTONIC, {tv_sec=153, tv_nsec=686234118}) = 0
mmap2(0x10a00000, 1048576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x10a00000
mmap2(0xf950000, 17498112, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xf950000
mmap2(0x800000, 139264, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x800000
mmap2(NULL, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x76c04000
@gopherbot

This comment has been minimized.

Copy link

commented Apr 12, 2017

CL https://golang.org/cl/39810 mentions this issue.

@gopherbot

This comment has been minimized.

Copy link

commented Jan 2, 2018

Change https://golang.org/cl/85887 mentions this issue: runtime: use sparse mappings for the heap

gopherbot pushed a commit that referenced this issue Feb 15, 2018

runtime: use sparse mappings for the heap
This replaces the contiguous heap arena mapping with a potentially
sparse mapping that can support heap mappings anywhere in the address
space.

This has several advantages over the current approach:

* There is no longer any limit on the size of the Go heap. (Currently
  it's limited to 512GB.) Hence, this fixes #10460.

* It eliminates many failures modes of heap initialization and
  growing. In particular it eliminates any possibility of panicking
  with an address space conflict. This can happen for many reasons and
  even causes a low but steady rate of TSAN test failures because of
  conflicts with the TSAN runtime. See #16936 and #11993.

* It eliminates the notion of "non-reserved" heap, which was added
  because creating huge address space reservations (particularly on
  64-bit) led to huge process VSIZE. This was at best confusing and at
  worst conflicted badly with ulimit -v. However, the non-reserved
  heap logic is complicated, can race with other mappings in non-pure
  Go binaries (e.g., #18976), and requires that the entire heap be
  either reserved or non-reserved. We currently maintain the latter
  property, but it's quite difficult to convince yourself of that, and
  hence difficult to keep correct. This logic is still present, but
  will be removed in the next CL.

* It fixes problems on 32-bit where skipping over parts of the address
  space leads to mapping huge (and never-to-be-used) metadata
  structures. See #19831.

This also completely rewrites and significantly simplifies
mheap.sysAlloc, which has been a source of many bugs. E.g., #21044,
 #20259, #18651, and #13143 (and maybe #23222).

This change also makes it possible to allocate individual objects
larger than 512GB. As a result, a few tests that expected huge
allocations to fail needed to be changed to make even larger
allocations. However, at the moment attempting to allocate a humongous
object may cause the program to freeze for several minutes on Linux as
we fall back to probing every page with addrspace_free. That logic
(and this failure mode) will be removed in the next CL.

Fixes #10460.
Fixes #22204 (since it rewrites the code involved).

This slightly slows down compilebench and the x/benchmarks garbage
benchmark.

name       old time/op     new time/op     delta
Template       184ms ± 1%      185ms ± 1%    ~     (p=0.065 n=10+9)
Unicode       86.9ms ± 3%     86.3ms ± 1%    ~     (p=0.631 n=10+10)
GoTypes        599ms ± 0%      602ms ± 0%  +0.56%  (p=0.000 n=10+9)
Compiler       2.87s ± 1%      2.89s ± 1%  +0.51%  (p=0.002 n=9+10)
SSA            7.29s ± 1%      7.25s ± 1%    ~     (p=0.182 n=10+9)
Flate          118ms ± 2%      118ms ± 1%    ~     (p=0.113 n=9+9)
GoParser       147ms ± 1%      148ms ± 1%  +1.07%  (p=0.003 n=9+10)
Reflect        401ms ± 1%      404ms ± 1%  +0.71%  (p=0.003 n=10+9)
Tar            175ms ± 1%      175ms ± 1%    ~     (p=0.604 n=9+10)
XML            209ms ± 1%      210ms ± 1%    ~     (p=0.052 n=10+10)

(https://perf.golang.org/search?q=upload:20171231.4)

name                       old time/op  new time/op  delta
Garbage/benchmem-MB=64-12  2.23ms ± 1%  2.25ms ± 1%  +0.84%  (p=0.000 n=19+19)

(https://perf.golang.org/search?q=upload:20171231.3)

Relative to the start of the sparse heap changes (starting at and
including "runtime: fix various contiguous bitmap assumptions"),
overall slowdown is roughly 1% on GC-intensive benchmarks:

name        old time/op     new time/op     delta
Template        183ms ± 1%      185ms ± 1%  +1.32%  (p=0.000 n=9+9)
Unicode        84.9ms ± 2%     86.3ms ± 1%  +1.65%  (p=0.000 n=9+10)
GoTypes         595ms ± 1%      602ms ± 0%  +1.19%  (p=0.000 n=9+9)
Compiler        2.86s ± 0%      2.89s ± 1%  +0.91%  (p=0.000 n=9+10)
SSA             7.19s ± 0%      7.25s ± 1%  +0.75%  (p=0.000 n=8+9)
Flate           117ms ± 1%      118ms ± 1%  +1.10%  (p=0.000 n=10+9)
GoParser        146ms ± 2%      148ms ± 1%  +1.48%  (p=0.002 n=10+10)
Reflect         398ms ± 1%      404ms ± 1%  +1.51%  (p=0.000 n=10+9)
Tar             173ms ± 1%      175ms ± 1%  +1.17%  (p=0.000 n=10+10)
XML             208ms ± 1%      210ms ± 1%  +0.62%  (p=0.011 n=10+10)
[Geo mean]      369ms           373ms       +1.17%

(https://perf.golang.org/search?q=upload:20180101.2)

name                       old time/op  new time/op  delta
Garbage/benchmem-MB=64-12  2.22ms ± 1%  2.25ms ± 1%  +1.51%  (p=0.000 n=20+19)

(https://perf.golang.org/search?q=upload:20180101.3)

Change-Id: I5daf4cfec24b252e5a57001f0a6c03f22479d0f0
Reviewed-on: https://go-review.googlesource.com/85887
Run-TryBot: Austin Clements <austin@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Rick Hudson <rlh@golang.org>
@gopherbot

This comment has been minimized.

Copy link

commented Jul 9, 2018

Change https://golang.org/cl/122587 mentions this issue: runtime: scale timeout in TestStackGrowth

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.