runtime: enable TestNewProc0 on android/arm #10548

hyangah · 2015-04-22T20:39:07Z

http://build.golang.org/log/03a3f1901363eb8a836ab2934fdd234ab4d025ad

##### GOMAXPROCS=2 runtime -cpu=1,2,4
ok      runtime 25.233s
ok      runtime 23.734s
go_android_exec: adb shell mkdir -p /data/local/tmp/runtime.test-32257
go_android_exec: adb push /tmp/go-build375059876/runtime/_test/runtime.test /data/local/tmp/runtime.test-32257/runtime.test-32257-tmp
4831 KB/s (3396712 bytes in 0.686s)
go_android_exec: adb shell cp '/data/local/tmp/runtime.test-32257/runtime.test-32257-tmp' '/data/local/tmp/runtime.test-32257/runtime.test-32257'
go_android_exec: adb shell rm '/data/local/tmp/runtime.test-32257/runtime.test-32257-tmp'
go_android_exec: adb shell export TMPDIR="/data/local/tmp/runtime.test-32257"; export GOROOT="/data/local/tmp/goroot"; export GOPATH="/data/local/tmp/gopath"; cd "/data/local/tmp/goroot/src/runtime"; '/data/local/tmp/runtime.test-32257/runtime.test-32257' -test.short=true -test.timeout=10m0s -test.cpu=4; echo -n exitcode=$?
fatal error: unexpected signal during runtime execution
[signal 0xb code=0x1 addr=0x14 pc=0x258e8]

runtime stack:
runtime.throw(0x2291b8, 0x2a)
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/panic.go:543 +0x78
runtime.sigpanic()
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/sigpanic_unix.go:12 +0x4c
runtime.finishsweep_m()
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/mgcsweep.go:39 +0xa8
runtime.systemstack(0x10558000)
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/asm_arm.s:239 +0x80
runtime.mstart()
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/proc1.go:725

goroutine 82505 [running]:
runtime.systemstack_switch()
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/asm_arm.s:187 +0x4 fp=0x1051a550 sp=0x1051a54c
runtime.gc(0x2)
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/mgc.go:727 +0x1f0 fp=0x1051a71c sp=0x1051a550
runtime.startGC(0x2)
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/mgc.go:635 +0xd4 fp=0x1051a728 sp=0x1051a71c
runtime.GC()
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/mgc.go:610 +0x24 fp=0x1051a730 sp=0x1051a728
runtime_test.TestParForParallel(0x1110c0c0)
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/parfor_test.go:127 +0x548 fp=0x1051a7b8 sp=0x1051a730
testing.tRunner(0x1110c0c0, 0x2e69e8)
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/testing/testing.go:452 +0xc4 fp=0x1051a7e4 sp=0x1051a7b8
runtime.goexit()
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/asm_arm.s:982 +0x4 fp=0x1051a7e4 sp=0x1051a7e4
created by testing.RunTests
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/testing/testing.go:560 +0x750

goroutine 1 [chan receive, locked to thread]:
testing.RunTests(0x25232c, 0x2e6520, 0x93, 0x93, 0xbb901)
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/testing/testing.go:561 +0x77c
testing.(*M).Run(0x105101b0, 0x309070)
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/testing/testing.go:490 +0x74
main.main()
    runtime/_test/_testmain.go:828 +0x1b4

goroutine 17 [syscall, locked to thread]:
runtime.goexit()
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/asm_arm.s:982 +0x4
exitcode=2go_android_exec: adb shell rm -rf /data/local/tmp/runtime.test-32257
FAIL    runtime 11.421s
2015/04/22 15:48:52 Failed: exit status 1
Build complete, duration 6m56.118676544s. Result: error: exit status 1

hyangah · 2015-04-22T22:13:02Z

It seems the culprit is https://go-review.googlesource.com/#/c/9164
I could reliably reproduce the failure after that.

minux · 2015-04-23T00:08:03Z

Something funny is happening here. My fix (CL 9246) to CL 9164 doesn't change any code of linux/arm at all, but the builder is happy after that CL. Perhaps the culprit is not CL 9164?

hyangah · 2015-04-23T01:32:23Z

http://build.golang.org/log/730ad13c8e38c620324d13e5515cff7c412ca1c5
Failed again. There is some randomness.
Could it be a GC related issue triggered by recent changes?

fatal error: unexpected signal during runtime execution
[signal 0xb code=0x1 addr=0x14 pc=0x258e8]
runtime stack:
runtime.throw(0x2291b8, 0x2a)
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/panic.go:543
+0x78
runtime.sigpanic()
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/sigpanic_unix.go:12
+0x4c
runtime.finishsweep_m()
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/mgcsweep.go:39
+0xa8
runtime.systemstack(0x10558000)
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/asm_arm.s:239
+0x80
runtime.mstart()
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/proc1.go:725
goroutine 82505 [running]:
runtime.systemstack_switch()
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/asm_arm.s:187
+0x4 fp=0x1051a550 sp=0x1051a54c
runtime.gc(0x2)
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/mgc.go:727
+0x1f0 fp=0x1051a71c sp=0x1051a550
runtime.startGC(0x2)
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/mgc.go:635
+0xd4 fp=0x1051a728 sp=0x1051a71c
runtime.GC()
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/mgc.go:610
+0x24 fp=0x1051a730 sp=0x1051a728
runtime_test.TestParForParallel(0x1110c0c0)
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/parfor_test.go:127
+0x548 fp=0x1051a7b8 sp=0x1051a730
testing.tRunner(0x1110c0c0, 0x2e69e8)
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/testing/testing.go:452
+0xc4 fp=0x1051a7e4 sp=0x1051a7b8
runtime.goexit()
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/runtime/asm_arm.s:982
+0x4 fp=0x1051a7e4 sp=0x1051a7e4
created by testing.RunTests
    /tmp/gobuilder/android-arm-crawshaw-4655aadd00fd/go/src/testing/testing.go:560
+0x750

On Wed, Apr 22, 2015 at 8:08 PM Minux Ma notifications@github.com wrote:

Something funny is happening here.

My fix (CL 9246) to CL 9164 doesn't change any code of linux/arm at all,
but the builder is happy after that CL.

Perhaps the culprit is not CL 9164?

—
Reply to this email directly or view it on GitHub
#10548 (comment).

minux · 2015-04-23T01:54:38Z

Yeah, it looks like some memory corruption or GC issue. I can't reproduce the crash on linux/arm, and I don't think CL 9164 could cause this. The change is fairly isolated.

hyangah · 2015-04-23T16:55:19Z

My local setup fails with signal 0xb, but with slightly different stack trace.
No indication of GC involvement,

  fatal error: unexpected signal during runtime execution
  [signal 0xb code=0x1 addr=0x40 pc=0x339e8]
  ...
  fatal error: runtime: stack split at bad time
  panic during panic

The builder and mine use different android device and different ndk versions (r9 vs r10).
I am not familiar with runtime internal or compiler enough - but is there any chance that changes like different register use interfere and surface underlying bugs? I've never observed this type of failure before rev ca9128f.

cc @crawshaw

attached the full stack trace:

> git reset --hard ca9128f18fe7
> GOOS=android GOARCH=arm GOARM=7  CC_FOR_TARGET=$NDK_ROOT/bin/arm-linux-androideabi-gcc ./androidtest.bash
...
##### Testing packages.
go_android_exec: adb shell mkdir -p /data/local/tmp/runtime.test-25219
go_android_exec: adb push /tmp/go-build834869593/runtime/_test/runtime.test /data/local/tmp/runtime.test-25219/runtime.test-25219-tmp
1318 KB/s (3397048 bytes in 2.515s)
go_android_exec: adb shell cp '/data/local/tmp/runtime.test-25219/runtime.test-25219-tmp' '/data/local/tmp/runtime.test-25219/runtime.test-25219'
go_android_exec: adb shell rm '/data/local/tmp/runtime.test-25219/runtime.test-25219-tmp'
go_android_exec: adb shell export TMPDIR="/data/local/tmp/runtime.test-25219"; export GOROOT="/data/local/tmp/goroot"; export GOPATH="/data/local/tmp/gopath"; cd "/data/local/tmp/goroot/src/runtime"; '/data/local/tmp/runtime.test-25219/runtime.test-25219' -test.short=true -test.timeout=4m0s; echo -n exitcode=$?
fatal error: unexpected signal during runtime execution
[signal 0xb code=0x1 addr=0x40 pc=0x339e8]
runtime stack:
runtime: newstack sp=0x43218e30 stack=[0x1051e800, 0x1051f000]
    morebuf={pc:0x577fc sp:0x43218e30 lr:0x0}
    sched={pc:0x4802c sp:0x43218e30 lr:0x577fc ctxt:0x0}
runtime.gentraceback(0x57e3c, 0x332bc, 0x43218f88, 0x0, 0x10d9e0b0, 0x0, 0x0, 0x64, 0x0, 0x0, ...)
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/traceback.go:301 +0xcc8 fp=0x43218ed0 sp=0x43218e30
runtime.step(0x0, 0x0, 0x30922c, 0x33930, 0x332bc, 0x43218f88, 0x0, 0x10d9e0b0, 0x0, 0x5c434)
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/symtab.go:296 +0xc8 fp=0x43218ef4 sp=0x43218ed0
created by runtime.addtimerLocked
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/time.go:116 +0x22c
fatal error: runtime: stack split at bad time
panic during panic
[signal 0xb code=0x1 addr=0x40 pc=0x339e8]
runtime stack:
runtime.startpanic_m()
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/panic1.go:66 +0x130
runtime.systemstack(0x25259c)
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/asm_arm.s:253 +0xa8
runtime.startpanic()
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/panic.go:521 +0x10
runtime.throw(0x221368, 0x20)
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/panic.go:542 +0x6c
runtime.newstack()
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/stack1.go:654 +0x4f4
runtime.morestack()
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/asm_arm.s:302 +0x4c
goroutine 7 [syscall]:
runtime.gentraceback(0x57e3c, 0x332bc, 0x43218f88, 0x0, 0x10d9e0b0, 0x0, 0x0, 0x64, 0x0, 0x0, ...)
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/traceback.go:301 +0xcc8 fp=0x43218ed0 sp=0x43218e30
runtime.step(0x0, 0x0, 0x30922c, 0x33930, 0x332bc, 0x43218f88, 0x0, 0x10d9e0b0, 0x0, 0x5c434)
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/symtab.go:296 +0xc8 fp=0x43218ef4 sp=0x43218ed0
created by runtime.addtimerLocked
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/time.go:116 +0x22c
goroutine 1 [chan receive, locked to thread]:
testing.RunTests(0x25234c, 0x2e6520, 0x93, 0x93, 0xbba01)
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/testing/testing.go:561 +0x77c
testing.(*M).Run(0x1050e1b0, 0x309070)
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/testing/testing.go:490 +0x74
main.main()
    runtime/_test/_testmain.go:828 +0x1b4
goroutine 17 [syscall, locked to thread]:
runtime.goexit()
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/asm_arm.s:982 +0x4
goroutine 2491 [syscall]:
runtime_test.TestFutexsleep.func1(0x0, 0x914f0000, 0x4e94, 0x20e760, 0x14, 0x1050c100)
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/futex_test.go:47 +0x30
created by runtime_test.TestFutexsleep
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/futex_test.go:51 +0x1f4
goroutine 2492 [syscall]:
runtime_test.TestFutexsleep.func1(0x0, 0x4876e800, 0x1dcd6517, 0x2085e0, 0x13, 0x1050c140)
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/futex_test.go:47 +0x30
created by runtime_test.TestFutexsleep
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/futex_test.go:51 +0x1f4
goroutine 82619 [select]:
runtime_test.TestNewOSProc0(0x10d76120)
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/runtime/norace_linux_test.go:28 +0x17c
testing.tRunner(0x10d76120, 0x2e69b8)
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/testing/testing.go:452 +0xc4
created by testing.RunTests
    /usr/local/google/home/hakim/golang/goroots/newgo/go/src/testing/testing.go:560 +0x750
exitcode=2go_android_exec: adb shell rm -rf /data/local/tmp/runtime.test-25219
FAIL    runtime 19.319s

crawshaw · 2015-04-23T17:08:07Z

The actual code changes in CL 9164 still look OK to me, but your stack trace includes TestNewOSProc0, a new test added in that CL. Maybe newosproc0 never worked on android/arm.

crawshaw · 2015-04-23T17:17:55Z

I suspect newosproc0 does not actually work as intended (without a G) on android/arm and won't until CL 9002 is submitted. However that doesn't explain the test failure, which I believe is operating with a G and so sysAlloc should work.

@hyangah if you disable TestNewOSProc0, do you see any failures?

hyangah · 2015-04-23T17:30:05Z

Thanks. After disabling TestNewOSProc0 (on top of rev ca9128f), all other runtime tests with GOMAXPROCS=1 pass. I will check if it helps when I sync to the latest tip.

TestMemStats-4 fails but I believe that should betracked separately in #10556

hyangah · 2015-04-23T18:09:09Z

All tests passed with the tip now.
CL 9002 doesn't fix this. With the cl 9002 patch set 7, I get the following error (no stack trace).

go_android_exec: adb shell export TMPDIR="/data/local/tmp/runtime.test-17921"; export GOROOT="/data/local/tmp/goroot"; export GOPATH="/data/local/tmp/gopath"; cd "/data/local/tmp/goroot/src/runtime"; '/data/local/tmp/runtime.test-17921/runtime.test-17921' -test.short=true -test.timeout=4m0s; echo -n exitcode=$?
unexpected fault address 0x437e6004
fatal error: fatal error: unexpected signal during runtime execution
[signal 0xb code=0x1 addr=0x7b pc=0x347a4]
schedule: holding locks
runtime stack:
panic during panic
[signal 0xb code=0x1 addr=0x437e6000 pc=0x57928fatal error: ]
unexpected signal during runtime execution
runtime stack:
stack trace unavailable
exitcode=4
FAIL runtime 23.108s

newosproc0 does not work on android/arm. See issue #10548. Change-Id: Ieaf6f5d0b77cddf5bf0b6c89fd12b1c1b8723f9b Reviewed-on: https://go-review.googlesource.com/9293 Reviewed-by: David Crawshaw <crawshaw@golang.org>

hyangah · 2015-04-24T01:35:05Z

After aef54d4 to disable TestNewProc0, the android/arm builder stopped complaining.
Changing this issue to remember to re-enable the test.

spetrovic77 · 2015-04-28T23:49:55Z

On Android, the problem seems to be with the newly created thread exiting: it messes up some state that makes future tests fail.

Note that normally, Go-created threads don't exit until the program terminates. This should be the case with threads created using newosproc0(), but the test doesn't follow this directive. While this is fine on other platforms, there's something about Android that makes things go bad if a thread exits.

In any case, I'll send out a CL that prevents the newly created thread from exiting in the test, and re-enables the test on Android.

gopherbot · 2015-04-29T00:00:28Z

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

minux · 2015-04-29T06:37:50Z

I've managed to reproduce the problem on linux/arm (I don't know why it's
passing
on the builders.)

=== RUN TestNewOSProc0
fatal error: schedule: holding locks

runtime stack:
fatal error: unexpected signal during runtime execution
runtime.throwSegmentation fault

=== RUN TestNewOSProc0
fatal error: unexpected signal during runtime executionfatal error:
Segmentation fault

OK, I think I know what's happening now, will send a CL.

gopherbot · 2015-04-29T07:00:27Z

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

hyangah changed the title ~~build: runtime test fails on android/arm~~ runtime: tests fail with SIGSEGV on android/arm Apr 23, 2015

hyangah changed the title ~~runtime: tests fail with SIGSEGV on android/arm~~ runtime: enable TestNewProc0 on android/arm Apr 24, 2015

minux closed this as completed in 4d1ab2d Apr 29, 2015

golang locked and limited conversation to collaborators Jun 25, 2016

gopherbot added the FrozenDueToAge label Jun 25, 2016

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

runtime: enable TestNewProc0 on android/arm #10548

runtime: enable TestNewProc0 on android/arm #10548

hyangah commented Apr 22, 2015

hyangah commented Apr 22, 2015

minux commented Apr 23, 2015 via email

hyangah commented Apr 23, 2015

minux commented Apr 23, 2015 via email

hyangah commented Apr 23, 2015

crawshaw commented Apr 23, 2015

crawshaw commented Apr 23, 2015

hyangah commented Apr 23, 2015

hyangah commented Apr 23, 2015

hyangah commented Apr 24, 2015

spetrovic77 commented Apr 28, 2015

gopherbot commented Apr 29, 2015

minux commented Apr 29, 2015

gopherbot commented Apr 29, 2015

runtime: enable TestNewProc0 on android/arm #10548

runtime: enable TestNewProc0 on android/arm #10548

Comments

hyangah commented Apr 22, 2015

hyangah commented Apr 22, 2015

minux commented Apr 23, 2015 via email

hyangah commented Apr 23, 2015

minux commented Apr 23, 2015 via email

hyangah commented Apr 23, 2015

crawshaw commented Apr 23, 2015

crawshaw commented Apr 23, 2015

hyangah commented Apr 23, 2015

hyangah commented Apr 23, 2015

hyangah commented Apr 24, 2015

spetrovic77 commented Apr 28, 2015

gopherbot commented Apr 29, 2015

minux commented Apr 29, 2015

gopherbot commented Apr 29, 2015