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
Closed
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done. OS-Windows
Milestone

Comments

@supernow
Copy link

supernow 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
Copy link
Contributor

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.

@ianlancetaylor
Copy link
Contributor

@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
Copy link
Author

Does Anyone have the same result?

@alexbrainman
Copy link
Member

my c.dll program is:

How do I build c.dll?
Thank you.

Alex

@supernow
Copy link
Author

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

@alexbrainman
Copy link
Member

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
Copy link
Author

Anyone can give a explanation?

@supernow
Copy link
Author

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

@ianlancetaylor
Copy link
Contributor

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

@supernow
Copy link
Author

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

@ianlancetaylor
Copy link
Contributor

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
Copy link
Member

mattn 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
Copy link
Author

@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
Copy link
Author

supernow 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
Copy link
Member

mattn 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
Copy link
Author

@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
Copy link
Contributor

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
Copy link
Member

mattn commented Sep 27, 2016

So I guess this is not a bug.

@alexbrainman
Copy link
Member

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
Copy link
Author

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
Copy link
Contributor

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

@alexbrainman
Copy link
Member

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

@quentinmit quentinmit added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Oct 5, 2016
@rsc
Copy link
Contributor

rsc 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 The path to resolution is known, but the work has not been done. and removed NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Oct 21, 2016
@alexbrainman
Copy link
Member

@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
Copy link

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

@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.
Labels
FrozenDueToAge NeedsFix The path to resolution is known, but the work has not been done. OS-Windows
Projects
None yet
Development

No branches or pull requests

8 participants