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

[plasticchris]

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 works for me when compiling your sample program natively on a raspberry pi. Have you tried building locally on your arm system? It's probably going to be simpler than maintaining a cross compilation environment.

…

On Tue, Apr 4, 2017 at 10:54 AM, Chris Johnson ***@***.***> wrote: What version of Go are you using (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? — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#19831>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAAcA-ghneoorfxtrG1WQlPURRCd6SrRks5rsZThgaJpZM4MyRGu> .

[plasticchris]

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]

/cc @aclements @randall77 @cherrymui

[plasticchris]

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]

I think you're being selective here. I wrote a simple hello world go program, no cgo, no zmq4, and strace -f reported a dozen mmap calls, one for over 800mb. That is to say, mmap is a symptom, not the cause of this bug.

…

On Wed, 5 Apr 2017, 04:53 Chris Johnson ***@***.***> wrote: 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. — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#19831 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAAcA5_BcRLa1FKWFfgyehmiPk0lr3oEks5rspGogaJpZM4MyRGu> .

[plasticchris]

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]

I don't think this is the cause. I thought the problem was the same program compiled natively vs cross compiled behaved differently. Is that the issue?

…

On Wed, 5 Apr 2017, 05:40 Chris Johnson ***@***.***> wrote: 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: ***@***.***:~$ cat hi.go package main import "fmt" func main () { fmt.Println("hi") } ***@***.***:~$ 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 +++ — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#19831 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAAcA4UcHlwbtxkYjz3Z2zJCIjv_mXzdks5rspybgaJpZM4MyRGu> .

[aclements]

@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]

@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]

'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]

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]

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