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

runtime: crash on Windows-created thread calling Go code during CPU profiling #17165

Closed
supernow opened this issue Sep 20, 2016 · 25 comments

Comments

Projects
None yet
8 participants
@supernow
Copy link

commented Sep 20, 2016

Please answer these questions before submitting your issue. Thanks!

the same topic and attachment is in https://groups.google.com/forum/#!topic/golang-nuts/2YpUrnjiY6k

What version of Go are you using (go version)?

go version go1.7.1 windows/amd64

What operating system and processor architecture are you using (go env)?

set GOARCH=amd64
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOOS=windows

my env is win10, visual studio 2015

What did you do?

If possible, provide a recipe for reproducing the error.
A complete runnable program is good.
A link on play.golang.org is best.
my golang is:

package main

import (
    "C"
    "fmt"
    "net/http"
    _ "net/http/pprof"
    "os"
    "runtime/pprof"
    "syscall"
    "time"
    "unsafe"
)

var times int

func main() {
    cbStr := syscall.NewCallback(goCbStr)
    dll, error := syscall.LoadDLL("test0001.dll")
    fmt.Println(dll)
    var initConnAgent *syscall.Proc
    initConnAgent, error = dll.FindProc("init")
    fmt.Println(initConnAgent, error)
    initConnAgent.Call(uintptr(unsafe.Pointer(&cbStr)))
    f, _ := os.Create("cpu.prof")
    err := pprof.StartCPUProfile(f)
    if err != nil {
        fmt.Println("pprof.StartCPUProfile:", err)
    }
    defer pprof.StopCPUProfile()
    go func() {
        fmt.Println(http.ListenAndServe("localhost:54321", nil))
    }()
    for {
        time.Sleep(time.Second)
    }
}

func goCbStr(callId int, funtype int, str *C.char) uintptr {
    times++
    fmt.Println(times, callId, funtype, C.GoString(str))
    return uintptr(0)
}

my c.dll program is:

#include<process.h>
#include "test.h"
 #include "stdio.h"
void timeProc(void*P);
ADAPTERDLL_API void init(cbStr* p) {
goCallback = *p;
printf("init success!\n");
 _beginthread(&timeProc, 0, 0);
printf("End \n");
 }

 void timeProc(void *p) {

for (;;) {
    goCallback(1, 2, "Hello");
}
}

What did you expect to see?

C can call into golang func (goCbStr).

What did you see instead?

goroutine 17 [running, locked to thread]:
runtime.throw(0x845aa0, 0xf)
C:/Go/src/runtime/panic.go:547 +0x97 fp=0xc082025c68 sp=0xc082025c50
runtime.mallocgc(0x5, 0x0, 0x3, 0x822aa0)
C:/Go/src/runtime/malloc.go:544 +0x1e1 fp=0xc082025d40 sp=0xc082025c68
runtime.rawstring(0x5, 0x0, 0x0, 0x0, 0x0, 0x0)
C:/Go/src/runtime/string.go:284 +0x77 fp=0xc082025d88 sp=0xc082025d40
runtime.gostring(0x7ff94f7f992c, 0x0, 0x0)
C:/Go/src/runtime/string.go:341 +0x62 fp=0xc082025df0 sp=0xc082025d88
main._Cfunc_GoString(0x7ff94f7f992c, 0x0, 0x0)
test/_obj/_cgo_gotypes.go:44 +0x34 fp=0xc082025e10 sp=0xc082025df0
main.goCbStr(0x1, 0x2, 0x7ff94f7f992c, 0xa20fd0)
C:/Programming/go-src/src/test/test.go:125 +0x62 fp=0xc082025ed0 sp=0xc082025e10
runtime.call32(0x0, 0x8eb238, 0x3befdd0, 0x20)
C:/Go/src/runtime/asm_amd64.s:472 +0x45 fp=0xc082025ef8 sp=0xc082025ed0
runtime.cgocallbackg1()
C:/Go/src/runtime/cgocall.go:267 +0x11a fp=0xc082025f30 sp=0xc082025ef8
runtime.cgocallbackg()
C:/Go/src/runtime/cgocall.go:180 +0xde fp=0xc082025f90 sp=0xc082025f30
runtime.cgocallback_gofunc(0x0, 0x0, 0x0)
C:/Go/src/runtime/asm_amd64.s:716 +0x6d fp=0xc082025fa0 sp=0xc082025f90
runtime.goexit()
C:/Go/src/runtime/asm_amd64.s:1998 +0x1 fp=0xc082025fa8 sp=0xc082025fa0

goroutine 1 [sleep]:
time.Sleep(0x3b9aca00)
C:/Go/src/runtime/time.go:59 +0x107
main.main()
C:/Programming/go-src/src/test/test.go:64 +0x4c3

goroutine 18 [syscall, locked to thread]:
runtime.goexit()
C:/Go/src/runtime/asm_amd64.s:1998 +0x1

goroutine 6 [syscall]:
runtime.CPUProfile(0x0, 0x0, 0x0)
C:/Go/src/runtime/cpuprof.go:421 +0x3b
runtime/pprof.profileWriter(0x1742f0, 0xc082026038)
C:/Go/src/runtime/pprof/pprof.go:607 +0x23
created by runtime/pprof.StartCPUProfile
C:/Go/src/runtime/pprof/pprof.go:601 +0x14c
@bradfitz

This comment has been minimized.

Copy link
Member

commented Sep 20, 2016

You already emailed golang-nuts for help and that thread is active, so let's keep it there instead of the bug tracker until a bug has been identified.

Also, please gofmt your code in the future.

@bradfitz bradfitz closed this Sep 20, 2016

@ianlancetaylor

This comment has been minimized.

Copy link
Contributor

commented Sep 20, 2016

@bradfitz on the thread I asked the OP to open a bug report with a reproduction case.

@ianlancetaylor ianlancetaylor added this to the Go1.8 milestone Sep 20, 2016

@ianlancetaylor ianlancetaylor changed the title fatal error:malloc deadlock cmd/cgo: fatal error:malloc deadlock in cgo callback on Windows Sep 20, 2016

@supernow

This comment has been minimized.

Copy link
Author

commented Sep 21, 2016

Does Anyone have the same result?

@alexbrainman

This comment has been minimized.

Copy link
Member

commented Sep 22, 2016

my c.dll program is:

How do I build c.dll?
Thank you.

Alex

@supernow

This comment has been minimized.

Copy link
Author

commented Sep 22, 2016

@alexbrainman

This comment has been minimized.

Copy link
Member

commented Sep 22, 2016

I put the solution file on this site:https://groups.google.com/forum/#!topic/golang-nuts/2YpUrnjiY6k

I do not know how to use your "solution".
I was trying to follow steps you provided above, but the c.dll is missing. How do I build c.dll?

Alex

@supernow

This comment has been minimized.

Copy link
Author

commented Sep 23, 2016

Anyone can give a explanation?

@supernow

This comment has been minimized.

Copy link
Author

commented Sep 23, 2016

I think this thread is the my answer:https://github.com/golang/go/issues/14599

@ianlancetaylor

This comment has been minimized.

Copy link
Contributor

commented Sep 23, 2016

Issue #14599 is fixed in 1.7.1, so whatever you are encountering is unlikely to be the same problem.

@supernow

This comment has been minimized.

Copy link
Author

commented Sep 26, 2016

@ianlancetaylor
Do you repro the program?Or have more information ?

@ianlancetaylor

This comment has been minimized.

Copy link
Contributor

commented Sep 26, 2016

I don't use Windows, so I have not tried to reproduce this problem.

alexbrainman tried to reproduce it, ran into a problem, and asked you a question that you have not answered. See above: he asked "How do I build c.dll?"

@mattn

This comment has been minimized.

Copy link
Member

commented Sep 26, 2016

@supernow Why you take an address of callback pointer? I don't reproduce with following code.

test0001.c

#include <process.h>
#include <stdio.h>

typedef void (*callback) (int, int, char*);

callback goCallback;

void
timeProc(void *p) {
  for (;;) {
    goCallback(1, 2, "Hello");
  }
}

void
init(void* p) {
  goCallback = p;
  printf("init success!\n");
  _beginthread(&timeProc, 0, 0);
  printf("End \n");
}

test.go

package main

import (
    "C"
    "fmt"
    "net/http"
    _ "net/http/pprof"
    "os"
    "runtime/pprof"
    "syscall"
    "time"
)

var (
    times = 0
    dll   = syscall.NewLazyDLL("test0001.dll")
    proc  = dll.NewProc("init")
)

func main() {
    proc.Call(syscall.NewCallback(goCbStr))
    f, _ := os.Create("cpu.prof")
    err := pprof.StartCPUProfile(f)
    if err != nil {
        fmt.Println("pprof.StartCPUProfile:", err)
    }
    defer pprof.StopCPUProfile()
    go func() {
        fmt.Println(http.ListenAndServe("localhost:54321", nil))
    }()
    for {
        time.Sleep(time.Second)
    }
}

func goCbStr(callId int, funtype int, str *C.char) uintptr {
    times++
    fmt.Println(times, callId, funtype, C.GoString(str))
    return uintptr(0)
}
@supernow

This comment has been minimized.

Copy link
Author

commented Sep 26, 2016

@mattn
Why you take an address of callback pointer?
I only know this way to callback go. Is there another way to callback go. Can you give me a site?

@alexbrainman
I share my C.dll solution file on this site:

@supernow

This comment has been minimized.

Copy link
Author

commented Sep 27, 2016

@mattn
What's you environment?
In my program, goCbStr can be called over 2000 times,then either print "malloc deadlock" or stuck over there.

I use you golang program to call my dll, It just output:

 "init success! End".

There is no func goCbStr calleback. I change your golang program line

proc.Call(syscall.NewCallback(goCbStr))

to

callBack_ := syscall.NewCallback(goCbStr)
proc.Call(uintptr(unsafe.Pointer(&callBack_)))

It have the same the error with mine!

Thank you for repro my error!

@mattn

This comment has been minimized.

Copy link
Member

commented Sep 27, 2016

What's you environment?

Windows7 64bit.

@ianlancetaylor I'm not sure, the address given from &callBack_ is temporary? AFAIK, it's safe to access the address even though it's in C while alive in main func. Right?

@supernow

This comment has been minimized.

Copy link
Author

commented Sep 27, 2016

@mattn
I figure out that you dll code is :

init(void* p) {
  goCallback = p;

my dll code is

void init(cbStr* p) {
    goCallback = *p;

When I rewrite it like you:
I got the same error.

BTW, What's your golang edition? Is it 1.7.1 edition?

@ianlancetaylor

This comment has been minimized.

Copy link
Contributor

commented Sep 27, 2016

It's not safe to take the address of a value, convert the address to uintptr, and pass that address to a function other than syscall.Syscall. See https://golang.org/pkg/unsafe/#Pointer .

In this case I don't understand why the code is written that way.

@mattn

This comment has been minimized.

Copy link
Member

commented Sep 27, 2016

So I guess this is not a bug.

@alexbrainman

This comment has been minimized.

Copy link
Member

commented Sep 29, 2016

I share my C.dll solution file on this site:

Thank you for the link. Unfortunately this needs some MS build tool to create the DLL, and I do not have that. So I will try to comment your code without actually running it. So I could be wrong about many things.

Your golang test.cpp:15 (init function) starts new thread, and new thread (timeProc function) calls Go callback. That will not work. The syscall.NewCallback can only be called by the no-Go code that is called by syscall.Syscall (or syscall.(*Proc).Call) before it return back to Go.

Also your DLL functions must use standard calling conventions: stdcall on 386 and "whatever Windows uses" on amd64. Your C build tool must generate appropriate code for both init and goCallback.

Also syscall.Syscall and syscall.NewCallback both align its parameters and return value on 4 bytes for 386 and 8 bytes for amd64. Does your C build tool does the same? You need to make sure it does.

I hope it helps.

Alex

@supernow

This comment has been minimized.

Copy link
Author

commented Sep 30, 2016

Thank you for replies.

The syscall.NewCallback can only be called by the no-Go code that is called by syscall.Syscall (or syscall.(*Proc).Call) before it return back to Go.

As far as I understand, in this scenario I can not callback golang func. However , If I want to create a new thread that can callback Go Code, what need I do?

BTW, In my program, when I remove code

 f, _ := os.Create("cpu.prof")
    err := pprof.StartCPUProfile(f)
    if err != nil {
        fmt.Println("pprof.StartCPUProfile:", err)
    }
    defer pprof.StopCPUProfile()

The program run well.

I think the CPU profile have the effect on the callback

@ianlancetaylor

This comment has been minimized.

Copy link
Contributor

commented Sep 30, 2016

To call Go code from a new non-Go thread, use cgo (https://golang.org/cmd/cgo).

@alexbrainman

This comment has been minimized.

Copy link
Member

commented Sep 30, 2016

However , If I want to create a new thread that can callback Go Code, what need I do?

I do not know. Maybe try what Ian suggested, but I have not done that myself.

I think the CPU profile have the effect on the callback

I am not sure why. Maybe you are just lucky.

Alex

@rsc

This comment has been minimized.

Copy link
Contributor

commented Oct 21, 2016

@alexbrainman, why do you say that a syscall.NewCallback-created callback can't be invoked on a new Windows-created thread? I think that should work, and it clearly mostly works. @ianlancetaylor, syscall.NewCallback returns a Windows callback that can be used to invoke the Go code. Underneath it translates to the usual cgo entry points. In particular, when the callback is invoked, it ends up in cgocallback_gofunc (on the stack above), which will take care of borrowing an M appropriately.

But the borrowing of M's and the profiling of M's by the CPU profiler seem not synchronized enough. This code implements the CPU profiler on Windows:

func profileloop1(param uintptr) uint32 {
    stdcall2(_SetThreadPriority, currentThread, _THREAD_PRIORITY_HIGHEST)

    for {
        stdcall2(_WaitForSingleObject, profiletimer, _INFINITE)
        first := (*m)(atomic.Loadp(unsafe.Pointer(&allm)))
        for mp := first; mp != nil; mp = mp.alllink {
            thread := atomic.Loaduintptr(&mp.thread)
            // Do not profile threads blocked on Notes,
            // this includes idle worker threads,
            // idle timer thread, idle heap scavenger, etc.
            if thread == 0 || mp.profilehz == 0 || mp.blocked {
                continue
            }
            stdcall1(_SuspendThread, thread)
            if mp.profilehz != 0 && !mp.blocked {
                profilem(mp)
            }
            stdcall1(_ResumeThread, thread)
        }
    }
}

func profilem(mp *m) {
    var r *context
    rbuf := make([]byte, unsafe.Sizeof(*r)+15)

    tls := &mp.tls[0]
    gp := *((**g)(unsafe.Pointer(tls)))

    // align Context to 16 bytes
    r = (*context)(unsafe.Pointer((uintptr(unsafe.Pointer(&rbuf[15]))) &^ 15))
    r.contextflags = _CONTEXT_CONTROL
    stdcall2(_GetThreadContext, mp.thread, uintptr(unsafe.Pointer(r)))
    sigprof(r.ip(), r.sp(), 0, gp, mp)
}

func sigprof(pc, sp, lr uintptr, gp *g, mp *m) {
    if prof.hz == 0 {
        return
    }

    // Profiling runs concurrently with GC, so it must not allocate.
    mp.mallocing++

    ... lots of code ...

    mp.mallocing--
}

A borrowed M may migrate between threads. Between the atomic.Loaduintptr(&mp.thread) and the SuspendThread, mp may have moved to a new thread, so that it's in active use. In particular it might be calling malloc, as in the crash stack trace. If so, the mp.mallocing++ in sigprof would provoke the crash.

Those lines are trying to guard against allocation during sigprof. But on Windows, mp is the thread being traced, not the current thread. Those lines should really be using getg().m.mallocing, which is the same on Unix but not on Windows. With that change, it's possible the race on the actual thread is not a problem: the traceback would get confused and eventually return an error, but that's fine. The code expects that possibility.

It would be nice if we could reproduce the problem, though. It might suffice just to turn on CPU profiling and make a bunch of callbacks from multiple threads simultaneously.

@rsc rsc changed the title cmd/cgo: fatal error:malloc deadlock in cgo callback on Windows runtime: crash on Windows-created thread calling Go code during CPU profiling Oct 21, 2016

@rsc rsc added NeedsFix and removed NeedsInvestigation labels Oct 21, 2016

@alexbrainman

This comment has been minimized.

Copy link
Member

commented Oct 21, 2016

@alexbrainman, why do you say that a syscall.NewCallback-created callback can't be invoked on a new Windows-created thread? I think that should work, and it clearly mostly works.

See issue #6751. I did not look at this for a while, so it could be well fixed now.

Anyway we use syscall.NewCallback mainly for GUI. And there all callbacks happen on the same thread.

Alex

@gopherbot

This comment has been minimized.

Copy link

commented Nov 11, 2016

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

@gopherbot gopherbot closed this in e6da64b Nov 11, 2016

@golang golang locked and limited conversation to collaborators Nov 11, 2017

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