ThreadSanitizor crash in Go 1.4rc1

Matt Joiner

unread,

Nov 20, 2014, 9:01:42 PM11/20/14

to golan...@googlegroups.com

==29040==ERROR: ThreadSanitizer failed to allocate 0x2901000 (42995712) bytes of deadlock detector (ph

ysical thread) (errno: 12)

==29040==Process memory map follows:

yada yada

==29040==End of process memory map.

FATAL: ThreadSanitizer CHECK failed: gotsan.cc:8893 "(("unable to mmap" && 0)) != (0)" (0x0, 0x0)

Dmitry Vyukov

unread,

Nov 20, 2014, 11:49:06 PM11/20/14

to Matt Joiner, golang-nuts

Hi,

It seems that you just run our of memory or set rlimit -v.
Try to run with GORACE=detect_deadlocks=0 env variable.

Matt Joiner

unread,

Nov 21, 2014, 1:52:04 AM11/21/14

to Dmitry Vyukov, golang-nuts

With GORACE=detect_deadlocks=0 I get 'Killed' with exit code 137 after about the same timeframe.

Dmitry Vyukov

unread,

Nov 21, 2014, 1:58:50 AM11/21/14

to Matt Joiner, golang-nuts

Race detector fail to allocate memory with ENOMEM. This means that
either it uses too much memory, or you have too little memory.
What is the amount of memory on your system? What is ulimit -a output?
What is the program memory consumption (you can monitor it with 'top
-d1 | grep your_binary')?

Konstantin Khomoutov

unread,

Nov 21, 2014, 5:54:56 AM11/21/14

to Dmitry Vyukov, golan...@googlegroups.com, Matt Joiner

On Fri, 21 Nov 2014 10:57:43 +0400
"'Dmitry Vyukov' via golang-nuts" <golan...@googlegroups.com> wrote:

> Race detector fail to allocate memory with ENOMEM. This means that
> either it uses too much memory, or you have too little memory.
> What is the amount of memory on your system? What is ulimit -a output?
> What is the program memory consumption (you can monitor it with
> 'top -d1 | grep your_binary')?

Just a note:

top -d 1 -p <pid_of_the_process>

is even better.

Dmitry Vyukov

unread,

Nov 21, 2014, 6:48:25 AM11/21/14

to Konstantin Khomoutov, golang-nuts, Matt Joiner

grep prints a nice history:

$ top -d 1 | grep 30208
30208 dvyukov 20 0 781400 53632 12156 S 6.2 0.1 13:34.85
chrome
30208 dvyukov 20 0 781400 53632 12156 S 3.0 0.1
13:34.88 chrome
30208 dvyukov 20 0 781400 53632 12156 S 2.0 0.1
13:34.90 chrome
30208 dvyukov 20 0 781400 53632 12156 S 4.0
0.1 13:34.94 chrome
30208 dvyukov 20 0 781400 53632 12156 S 2.0
0.1 13:34.96 chrome
...
that is easy to copy-paste and analyze.

Matt Joiner

unread,

Nov 21, 2014, 11:53:56 AM11/21/14

to Dmitry Vyukov, Konstantin Khomoutov, golang-nuts

ulimit -a:

core file size (blocks, -c) 0

data seg size (kbytes, -d) unlimited

scheduling priority (-e) 0

file size (blocks, -f) unlimited

pending signals (-i) 3750

max locked memory (kbytes, -l) 64

max memory size (kbytes, -m) unlimited

open files (-n) 1024

pipe size (512 bytes, -p) 8

POSIX message queues (bytes, -q) 819200

real-time priority (-r) 0

stack size (kbytes, -s) 8192

cpu time (seconds, -t) unlimited

max user processes (-u) 3750

virtual memory (kbytes, -v) unlimited

file locks (-x) unlimited

The machine has 512MB ram.

Matt Joiner

unread,

Nov 21, 2014, 12:03:22 PM11/21/14

to Dmitry Vyukov, Konstantin Khomoutov, golang-nuts

When I memory map ~250MB in my Go program, this happens:

32644 root 20 0 1009796 73680 4548 S 1.0 14.7 0:00.34

32644 root 20 0 19.274g 144248 4848 S 34.9 28.7 0:00.69

It then crashes here:

32644 root 20 0 23.790g 428748 2912 S 25.9 85.4 0:04.74

32644 root 20 0 23.794g 432044 1984 S 4.0 86.1 0:04.78

Dmitry Vyukov

unread,

Nov 21, 2014, 12:07:33 PM11/21/14

to Matt Joiner, Konstantin Khomoutov, golang-nuts

The race detector increases memory consumption by ~5-10x. So on a
machine with 512MB you can run Go program that consume <~50MB.

Matt Joiner

unread,

Dec 4, 2014, 6:17:03 PM12/4/14

to golan...@googlegroups.com, anac...@gmail.com, flat...@users.sourceforge.net

Where are these GORACE options in the Go source? I notice this one isn't documented.

I've attempted to run on a machine with 4x the memory, now I get a clear "runtime out of memory" panic with detect_deadlocks=0.

I'm quite sure my use of gommap is contributing to this crash, as I mmap() about 15GB of data prior to the crash. Without the race detector on, this doesn't cause an issue.

minux

unread,

Dec 4, 2014, 11:43:46 PM12/4/14

to Matt Joiner, golang-nuts, flat...@users.sourceforge.net

On Thu, Dec 4, 2014 at 6:17 PM, Matt Joiner <anac...@gmail.com> wrote:

Where are these GORACE options in the Go source? I notice this one isn't documented.

To find out more about obscure but supported flags, you need to dig into tsan source code:

http://llvm.org/viewvc/llvm-project/compiler-rt/trunk/lib/tsan/rtl/

flags.cc is a good starting point.

Flags more relevant to Go programmers are documented here:

golang.org/doc/articles/race_detector.html#Options

Dmitry Vyukov

unread,

Dec 5, 2014, 3:56:53 AM12/5/14

to Matt Joiner, golang-nuts, Konstantin Khomoutov

Looks like you don't have enough memory to run with race detector...

What is the amount of memory on your system? What is ulimit -a output?

Do you have swap enabled?
What is the program memory consumption with and without race detector

(you can monitor it with 'top
-d1 | grep your_binary')?

> --
> You received this message because you are subscribed to the Google Groups
> "golang-nuts" group.
> To unsubscribe from this group and stop receiving emails from it, send an
> email to golang-nuts...@googlegroups.com.
> For more options, visit https://groups.google.com/d/optout.

Matt Joiner

unread,

Feb 7, 2015, 9:49:54 AM2/7/15

to Dmitry Vyukov, golang-nuts, Konstantin Khomoutov

I'm now running this on a machine with 2GB memory. I turn off all the options that lead to large memory use in my program. This is without -race:

29459 root 20 0 203876 10296 4288 S 27.8 0.5 0:07.81

29459 root 20 0 203876 10296 4288 R 25.9 0.5 0:08.07

29459 root 20 0 203876 10532 4288 S 25.8 0.5 0:08.33

29459 root 20 0 203876 10784 4472 R 25.8 0.5 0:08.59

29459 root 20 0 204964 10784 4472 S 23.8 0.5 0:08.83

29459 root 20 0 204964 11016 4476 S 22.9 0.5 0:09.06

29459 root 20 0 204964 11016 4476 S 24.9 0.5 0:09.31

29459 root 20 0 204964 11016 4476 S 26.8 0.5 0:09.58

29459 root 20 0 204964 11512 4476 R 29.8 0.6 0:09.88

29459 root 20 0 204964 11512 4476 S 26.8 0.6 0:10.15

And this is with -race (crash after last line):

29459 root 20 0 204964 11512 4476 S 25.5 0.6 0:12.62

29459 root 20 0 204964 11512 4476 S 26.8 0.6 0:12.89

29459 root 20 0 204964 11512 4476 S 27.8 0.6 0:13.17

29459 root 20 0 204964 11768 4488 S 25.8 0.6 0:13.43

29459 root 20 0 204964 11768 4488 S 26.8 0.6 0:13.70

29459 root 20 0 206052 12012 4488 S 31.8 0.6 0:14.02

29459 root 20 0 206052 12012 4488 S 25.8 0.6 0:14.28

29459 root 20 0 206052 12264 4488 S 25.9 0.6 0:14.54

29459 root 20 0 206052 12524 4488 S 32.8 0.6 0:14.87

29488 root 20 0 2679060 34504 4700 S 17.9 1.7 0:00.30

29488 root 20 0 23.922g 161924 4788 R 151.0 7.9 0:01.82

29488 root 20 0 42.486g 258900 4788 S 157.1 12.6 0:03.41

29488 root 20 0 56.890g 348908 4788 R 158.9 17.0 0:05.01

29488 root 20 0 62.764g 415764 4796 R 161.9 20.3 0:06.64

29488 root 20 0 72.008g 469596 4804 R 165.8 22.9 0:08.31

29488 root 20 0 81.625g 542292 4804 R 168.8 26.5 0:10.01

29488 root 20 0 89.334g 606220 4804 S 169.8 29.6 0:11.72

29488 root 20 0 93.250g 664324 4804 S 171.9 32.4 0:13.45

29488 root 20 0 98.775g 719612 4808 S 175.7 35.1 0:15.22

29488 root 20 0 0.105t 793280 4808 S 174.5 38.7 0:16.98

29488 root 20 0 0.109t 854148 4808 S 173.8 41.7 0:18.73

29488 root 20 0 0.115t 914416 4808 S 170.8 44.6 0:20.45

29488 root 20 0 0.120t 966244 4808 S 175.7 47.1 0:22.22

29488 root 20 0 0.125t 0.977g 4808 S 180.8 50.0 0:24.04

29488 root 20 0 0.130t 1.042g 4808 S 179.7 53.3 0:25.85

29488 root 20 0 0.137t 1.098g 4808 S 179.1 56.2 0:27.66

29488 root 20 0 0.143t 1.159g 4808 S 180.8 59.3 0:29.48

29488 root 20 0 0.148t 1.217g 4808 S 178.2 62.2 0:31.28

29488 root 20 0 0.152t 1.276g 4808 S 181.7 65.3 0:33.11

29488 root 20 0 0.158t 1.335g 4808 S 178.8 68.3 0:34.91

29488 root 20 0 0.163t 1.400g 4808 S 177.8 71.6 0:36.70

29488 root 20 0 0.170t 1.462g 4808 S 179.6 74.8 0:38.51

You can see the non-race is using barely 12MB. The race version fills the available memory.

Dmitry Vyukov

unread,

Feb 7, 2015, 9:57:36 AM2/7/15

to Matt Joiner, golang-nuts, Konstantin Khomoutov

Please capture contents of /proc/PID/smaps as close to crash as
possible. Or give me a reproducer.

James Defelice

unread,

Apr 8, 2015, 6:40:34 PM4/8/15

to golan...@googlegroups.com, anac...@gmail.com, flat...@users.sourceforge.net

I'm having a similar problem. I've captured some smaps and top logs. The smaps were being captured in a 10s loop, so the data may be up to 10s old.

smaps :: http://pastebin.com/1ic6fmS1

top :: http://pastebin.com/9YAJ8WZq

$ ulimit -a

core file size (blocks, -c) 0

data seg size (kbytes, -d) unlimited

scheduling priority (-e) 0

file size (blocks, -f) unlimited

pending signals (-i) 29937

max locked memory (kbytes, -l) 64

max memory size (kbytes, -m) unlimited

open files (-n) 1024

pipe size (512 bytes, -p) 8

POSIX message queues (bytes, -q) 819200

real-time priority (-r) 0

stack size (kbytes, -s) 8192

cpu time (seconds, -t) unlimited

max user processes (-u) 29937

virtual memory (kbytes, -v) unlimited

file locks (-x) unlimited

The same process running on another box (VM) without race detection compiled in:

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND

6478 jclouds 20 0 139m 44m 19m S 9.6 0.6 14:41.90 km

Thanks in advance.

James Defelice

unread,

Apr 8, 2015, 6:40:34 PM4/8/15

to golan...@googlegroups.com, anac...@gmail.com, flat...@users.sourceforge.net

In reference to my prior post, the ThreadSanitizer stack trace: http://pastebin.com/ibFJY5VM

On Saturday, February 7, 2015 at 9:57:36 AM UTC-5, Dmitry Vyukov wrote:

Dmitry Vyukov

unread,

Apr 9, 2015, 3:23:15 AM4/9/15

to James Defelice, golang-nuts, Matt Joiner, Konstantin Khomoutov

The issue is fixed on tip. I had done everything I could to reduce
per-goroutine memory consumption.
If you test with Go tip, memory consumption should drop 2x or so.

Reply all

Reply to author

Forward