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: unexpected failure and garbage data when c-shared Go DLL on Windows receives CtrlBreak signal concurrently with runtime initialization #46354

Open
mknyszek opened this issue May 24, 2021 · 14 comments

Comments

@mknyszek
Copy link
Contributor

@mknyszek mknyszek commented May 24, 2021

In c-shared mode, when a Go DLL is loaded, it spawns a new thread that starts runtime initialization. All calls into the DLL block on runtime initialization completing.

While investigating #45638, we discovered that the previous iteration of TestLibraryCtrlHandler would often send a CtrlBreak signal to the Go test process before runtime initialization was complete, and this would result in an exception landing in a Go exception handler on a Go thread that wasn't ready to receive it (no G or M).

Then, we'd end up in badsignal2. Previously, badsignal2 would not exit after printing the message, and garbage would spew into the stdout (or Windows equivalent) of the process before badsignal2 would be called again. Still, this garbage spewing was reproducible after this was fixed.

As an example, this is what the failure looked like:

=== RUN   TestLibraryCtrlHandler
    signal_windows_test.go:210: Program exited with error: exit status 1
        runtime: signal received on thread not created by Go.
        �o�<f�N9꙾�&����vl��3U0�{\K���X�س���64oMˡ1��!
                                                    R��n��)�Џ�jG'��T��-�0�i�
                                                                            �!Ρ6�)��,p??�G�j�V���k6˩���G
                                                                                                        �
                                                                                                         �6�runtime: signal received on thread not created by Go.
        �o�<f�N9꙾�&����vl��3U0�{\K���X�س���64oMˡ1��!
                                                    R��n��)�Џ�jG'��T��-�0�i�
                                                                            �!Ρ6�)��,p??�G�j�V���k6˩���G
                                                                                                        �
                                                                                                         �6�h�h�runtime: signal received on thread not created by Go.
        �o�<f�N9꙾�&����vl��3U0�{\K���X�س���64oMˡ1��!
                                                    R��n��)�Џ�jG'��T��-�0�i�
                                                                            �!Ρ6�)��,p??�G�j�V���k6˩���G
                                                                                                        �
                                                                                                         �6�h�h�d@�?@DDD �"""C:\Windows\system32\runtime: signal received on thread not created by Go.
        �o�<f�N9꙾�&����vl��3U0�{\K���X�س���64oMˡ1��!
                                                    R��n��)�Џ�jG'��T��-�0�i�
                                                                            �!Ρ6�)��,p??�G�j�V���k6˩���G
                                                                                                        �
                                                                                                         �6�h�h�d@�?@DDD �"""C:\Windows\system32\FAILURE: No signal received
--- FAIL: TestLibraryCtrlHandler (68.32s)
FAIL
FAIL	runtime	68.350s
FAIL
Error running run: exit status 1

Sometimes there would be a lot more garbage (spanning pages and pages of terminal buffer space). Sometimes less.

The failure is rare, maybe once in 30,000 runs. It's still unclear what the root cause is, but we've narrowed it down to the control handler getting installed in the Go runtime. If that is removed, it is not reproducible. It only started showing up in Go 1.17, during which time the way our console control handler worked changed. It's unclear how the exception handler gets invoked, also, because the control handler is generally completely separate from the exception handler on Windows.

Something may be going wrong on a Go-owned thread that hasn't been set up to have an M yet (i.e. between when the first M is properly initialized and when the control handler is installed), however it's still possible to reproduce the issue even if control handler installation is delayed all the way until just before runtime.main completes (signalling that runtime initialization is done).

However, it's possible this issue is reproducible under previous Go releases (just that it's more difficult to do so). Notably, it's still possible to reproduce the issue even if one installs a trivial handler written in assembly (much less complex than callbackasm1) without any of the compileCallback machinery that was added in Go 1.17.

The workaround for this issue is to block the application until the Go runtime has fully initialized by calling any Go function in the DLL before proceeding.

CC @alexbrainman @zx2c4

@ChrisHines
Copy link
Contributor

@ChrisHines ChrisHines commented Jun 12, 2021

I have seen this error message followed by garbage in the terminal at a higher rate than reported in the above description with the following steps on a Windows desktop with go1.17beta1:

  1. Run go build ./... in a directory containing many packages (I was using github.com/go-kit/kit).
  2. Cancel the build with CTRL-C

Potentially even more interesting: If the build fails with the "signal received on a thread not created by Go" message, rerunning the same build seems to crash the same way every subsequent time without typing CTRL-C at all. Running go clean -cache will then reset the situation.

Some example output:

C:\Users\Chris\proj\kit>go build -trimpath ./...
go build google.golang.org/protobuf/internal/encoding/text: C:\Users\Chris\sdk\go1.17beta1\pkg\tool\windows_amd64\compile.exe: exit status 0xc000013a
go build os/signal: C:\Users\Chris\sdk\go1.17beta1\pkg\tool\windows_amd64\asm.exe: exit status 0xc000013a
go build github.com/casbin/casbin/v2: C:\Users\Chris\sdk\go1.17beta1\pkg\tool\windows_amd64\compile.exe: exit status 0xc000013a
go build google.golang.org/protobuf/runtime/protoiface: C:\Users\Chris\sdk\go1.17beta1\pkg\tool\windows_amd64\compile.exe: exit status 0xc000013a
go build crypto/tls: C:\Users\Chris\sdk\go1.17beta1\pkg\tool\windows_amd64\compile.exe: exit status 0xc000013a
go build google.golang.org/protobuf/reflect/protoregistry: C:\Users\Chris\sdk\go1.17beta1\pkg\tool\windows_amd64\compile.exe: exit status 0xc000013a
# google.golang.org/protobuf/internal/descopts
runtime: signal received on thread not created by Go.
�|����Π�¶@�A'�☺@�A'�☺runtime: signal received on thread not created by Go.�§�j�@��ļ������%1�2♠↨M�+��6��H�\u6uo▬Eo�$�[M
�|����Π�¶☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺runtime: signal received on thread not created by Go.�@��ļ������%1�2♠↨M�+��6��H�\u6uo▬Eo�$�[M
�|����Π�¶ �A'�☺ �A'�☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺d@�?@DDD�♠��☻"""C:\Windows\system32\☺☺runtime: signal received on thread not created by Go.
�|����Π�¶ �A'�☺ �A'�☺x�A'�☺x�A'�☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺d@�?@DDD r8��2��E♥"""C:\Windows\system32\☺☺C:\Windows\system32\bde2132919bb9861ce74e7620ee82af11b5880fdde88925ce64d0a55e38fdc8aAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAruntime: signal received on 
thread not created by Go.
�|����Π�¶��K'�☺��K'�☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺d@�?@�PVP�F""�.�♣♀$x↔���.G���♥Wge9�"@�▲ݗ�♦�?C:\Windows\system32\@J��>�L�☺�>�L�☺ ▼��������♥☻☻▬☻♣   ▼☺☺�@☺►►�.G����.G����.G����@�P↔$.(%+)▲,▼↨▬ *↑!"↓→'∟:\Windows\system32\bde2132919bb9861ce74e7620ee82af11b5880fdde88925ce64d0a55e38fdc8aAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA��A'�☺��A'�☺♦♦☺♦☺♦☺☺♥☺☻☺♥☺☺☺☻☺♦☺♦☺☺♦

C:\Users\Chris\proj\kit>go build -trimpath ./...
# google.golang.org/protobuf/internal/descopts
runtime: signal received on thread not created by Go.
�|����Π�¶@�A'�☺@�A'�☺runtime: signal received on thread not created by Go.�§�j�@��ļ������%1�2♠↨M�+��6��H�\u6uo▬Eo�$�[M
�|����Π�¶☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺runtime: signal received on thread not created by Go.�@��ļ������%1�2♠↨M�+��6��H�\u6uo▬Eo�$�[M
�|����Π�¶ �A'�☺ �A'�☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺d@�?@DDD�♠��☻"""C:\Windows\system32\☺☺runtime: signal received on thread not created by Go.
�|����Π�¶ �A'�☺ �A'�☺x�A'�☺x�A'�☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺d@�?@DDD r8��2��E♥"""C:\Windows\system32\☺☺C:\Windows\system32\bde2132919bb9861ce74e7620ee82af11b5880fdde88925ce64d0a55e38fdc8aAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAruntime: signal received on 
thread not created by Go.
�|����Π�¶��K'�☺��K'�☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺d@�?@�PVP�F""�.�♣♀$x↔���.G���♥Wge9�"@�▲ݗ�♦�?C:\Windows\system32\@J��>�L�☺�>�L�☺ ▼��������♥☻☻▬☻♣   ▼☺☺�@☺►►�.G����.G����.G����@�P↔$.(%+)▲,▼↨▬ *↑!"↓→'∟:\Windows\system32\bde2132919bb9861ce74e7620ee82af11b5880fdde88925ce64d0a55e38fdc8aAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA��A'�☺��A'�☺♦♦☺♦☺♦☺☺♥☺☻☺♥☺☺☺☻☺♦☺♦☺☺♦
^C
C:\Users\Chris\proj\kit>go build -trimpath ./...
# google.golang.org/protobuf/internal/descopts
runtime: signal received on thread not created by Go.
�|����Π�¶@�A'�☺@�A'�☺runtime: signal received on thread not created by Go.�§�j�@��ļ������%1�2♠↨M�+��6��H�\u6uo▬Eo�$�[M
�|����Π�¶☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺runtime: signal received on thread not created by Go.�@��ļ������%1�2♠↨M�+��6��H�\u6uo▬Eo�$�[M
�|����Π�¶ �A'�☺ �A'�☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺d@�?@DDD�♠��☻"""C:\Windows\system32\☺☺runtime: signal received on thread not created by Go.
�|����Π�¶ �A'�☺ �A'�☺x�A'�☺x�A'�☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺d@�?@DDD r8��2��E♥"""C:\Windows\system32\☺☺C:\Windows\system32\bde2132919bb9861ce74e7620ee82af11b5880fdde88925ce64d0a55e38fdc8aAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAruntime: signal received on 
thread not created by Go.
�|����Π�¶��K'�☺��K'�☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺d@�?@�PVP�F""�.�♣♀$x↔���.G���♥Wge9�"@�▲ݗ�♦�?C:\Windows\system32\@J��>�L�☺�>�L�☺ ▼��������♥☻☻▬☻♣   ▼☺☺�@☺►►�.G����.G����.G����@�P↔$.(%+)▲,▼↨▬ *↑!"↓→'∟:\Windows\system32\bde2132919bb9861ce74e7620ee82af11b5880fdde88925ce64d0a55e38fdc8aAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA��A'�☺��A'�☺♦♦☺♦☺♦☺☺♥☺☻☺♥☺☺☺☻☺♦☺♦☺☺♦

C:\Users\Chris\proj\kit>go build -trimpath ./...
# google.golang.org/protobuf/internal/descopts
runtime: signal received on thread not created by Go.
�|����Π�¶@�A'�☺@�A'�☺runtime: signal received on thread not created by Go.�§�j�@��ļ������%1�2♠↨M�+��6��H�\u6uo▬Eo�$�[M
�|����Π�¶☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺runtime: signal received on thread not created by Go.�@��ļ������%1�2♠↨M�+��6��H�\u6uo▬Eo�$�[M
�|����Π�¶ �A'�☺ �A'�☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺d@�?@DDD�♠��☻"""C:\Windows\system32\☺☺runtime: signal received on thread not created by Go.
�|����Π�¶ �A'�☺ �A'�☺x�A'�☺x�A'�☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺d@�?@DDD r8��2��E♥"""C:\Windows\system32\☺☺C:\Windows\system32\bde2132919bb9861ce74e7620ee82af11b5880fdde88925ce64d0a55e38fdc8aAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAruntime: signal received on 
thread not created by Go.
�|����Π�¶��K'�☺��K'�☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺☺d@�?@�PVP�F""�.�♣♀$x↔���.G���♥Wge9�"@�▲ݗ�♦�?C:\Windows\system32\@J��>�L�☺�>�L�☺ ▼��������♥☻☻▬☻♣   ▼☺☺�@☺►►�.G����.G����.G����@�P↔$.(%+)▲,▼↨▬ *↑!"↓→'∟:\Windows\system32\bde2132919bb9861ce74e7620ee82af11b5880fdde88925ce64d0a55e38fdc8aAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA��A'�☺��A'�☺♦♦☺♦☺♦☺☺♥☺☻☺♥☺☺☺☻☺♦☺♦☺☺♦

C:\Users\Chris\proj\kit>go clean -cache

C:\Users\Chris\proj\kit>go build -trimpath ./...

C:\Users\Chris\proj\kit>

@mknyszek
Copy link
Contributor Author

@mknyszek mknyszek commented Jun 12, 2021

Fascinating! Out of curiosity, does https://golang.org/cl/321789 help at all? I assume not, but it might.

@alexbrainman
Copy link
Member

@alexbrainman alexbrainman commented Jun 17, 2021

with the following steps on a Windows desktop with go1.17beta1:

@ChrisHines I cannot reproduce your problem:

go: downloading github.com/edsrzf/mmap-go v1.0.0
go: downloading gopkg.in/warnings.v0 v0.1.2
go: downloading github.com/coreos/go-semver v0.3.0
go: downloading github.com/StackExchange/wmi v0.0.0-20190523213315-cbe66965904d
go: downloading github.com/hashicorp/go-immutable-radix v1.0.0
go: downloading golang.org/x/text v0.3.5
go: downloading github.com/hashicorp/golang-lru v0.5.1

c:\Users\Alex\dev\src\github.com\go-kit\kit>go build -trimpath ./...

c:\Users\Alex\dev\src\github.com\go-kit\kit>go clean -cache

c:\Users\Alex\dev\src\github.com\go-kit\kit>go build -trimpath ./...
^C
c:\Users\Alex\dev\src\github.com\go-kit\kit>go build -trimpath ./...
^C
c:\Users\Alex\dev\src\github.com\go-kit\kit>go build -trimpath ./...
^C
c:\Users\Alex\dev\src\github.com\go-kit\kit>go clean -cache

c:\Users\Alex\dev\src\github.com\go-kit\kit>go build -trimpath ./...
^C
c:\Users\Alex\dev\src\github.com\go-kit\kit>go build -trimpath ./...
^C
c:\Users\Alex\dev\src\github.com\go-kit\kit>go build -trimpath ./...
^C
c:\Users\Alex\dev\src\github.com\go-kit\kit>go build -trimpath ./...
^C
c:\Users\Alex\dev\src\github.com\go-kit\kit>go build -trimpath ./...
^C
c:\Users\Alex\dev\src\github.com\go-kit\kit>go build -trimpath ./...
^C
c:\Users\Alex\dev\src\github.com\go-kit\kit>

I noticed that your output has many go build ... lines. I wonder why.

Also do try CL 321789 as per @mknyszek #46354 (comment)

Thank you.

Alex

@ChrisHines
Copy link
Contributor

@ChrisHines ChrisHines commented Jun 18, 2021

I was able to reproduce my above scenario with a version of Go built with CGO_ENABLED=0 built from source at the go1.17beta1 tag. I did this to make sure my build procedure wouldn't change anything since my original post was done with a go binary installed by the golang.org/dl tool. It seems to happen more often if I wait a few seconds before hitting CTRL-C.

After checking out CL 321789 and running make.bat I had this experience:

C:\Users\Chris\proj\kit>..\GoTip\go\bin\go.exe version
go version devel go1.17-451aed99db Fri May 21 17:42:29 2021 +0000 windows/amd64

C:\Users\Chris\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Chris\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Chris\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Chris\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Chris\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Chris\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Chris\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...

C:\Users\Chris\proj\kit>..\GoTip\go\bin\go.exe clean -cache

C:\Users\Chris\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
go build github.com/mitchellh/mapstructure: C:\Users\Chris\proj\GoTip\go\pkg\tool\windows_amd64\compile.exe: exit status 0xc000013a
go build github.com/fatih/color: C:\Users\Chris\proj\GoTip\go\pkg\tool\windows_amd64\compile.exe: exit status 0xc000013a
go build go/build: C:\Users\Chris\proj\GoTip\go\pkg\tool\windows_amd64\compile.exe: exit status 0xc000013a
go build crypto/x509: C:\Users\Chris\proj\GoTip\go\pkg\tool\windows_amd64\compile.exe: exit status 0xc000013a
go build github.com/openzipkin/zipkin-go: C:\Users\Chris\proj\GoTip\go\pkg\tool\windows_amd64\compile.exe: exit status 0xc000013a
go build go/types: C:\Users\Chris\proj\GoTip\go\pkg\tool\windows_amd64\compile.exe: exit status 0xc000013a

C:\Users\Chris\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Chris\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...

C:\Users\Chris\proj\kit>..\GoTip\go\bin\go.exe clean -cache

C:\Users\Chris\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
go build github.com/performancecopilot/speed/bytewriter: C:\Users\Chris\proj\GoTip\go\pkg\tool\windows_amd64\compile.exe: exit status 0xc000013a
go build github.com/go-kit/kit/metrics/influxstatsd: C:\Users\Chris\proj\GoTip\go\pkg\tool\windows_amd64\compile.exe: exit status 0xc000013a

C:\Users\Chris\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...

C:\Users\Chris\proj\kit>

So I was able to reproduce similar go build exit status results twice, but neither time resulted in the runtime: signal received on thread not created by Go. error. It's hard to prove a negative, but it seems like an improvement. With go1.17beta1 I got that error every time go build reported exit status 0xc000013a, but with the CL applied no bad signal was reported either time I got that exit status. So maybe that fixes it. 🤞

@mknyszek
Copy link
Contributor Author

@mknyszek mknyszek commented Jun 18, 2021

That definitely seems like an improvement. I will land my CL.

@gopherbot
Copy link

@gopherbot gopherbot commented Jun 18, 2021

Change https://golang.org/cl/321789 mentions this issue: runtime: exit harder in badsignal2

@mknyszek
Copy link
Contributor Author

@mknyszek mknyszek commented Jun 18, 2021

@ChrisHines It's actually kind of weird that the "bad signal" message isn't showing up anymore. That CL just makes it so that badsignal2 actually exits the process after printing the message (instead of continuing to execute on that thread).

@mknyszek
Copy link
Contributor Author

@mknyszek mknyszek commented Jun 18, 2021

Oh... I wonder if actually exiting harder in badsignal2 is masking the original issue. Generally the behavior of Ctrl+C exits the process, so that's why what you're (@ChrisHines) seeing now seems normal? But it seems like Ctrl+C ends up in the exception handler when it really should be in the console control handler.

That's very odd. Consider the situation where you press Ctrl+C that lands during runtime initialization. Even the default console control handler for Ctrl+C shouldn't land you in the exception handler. I can't find any documentation about how these two might interact.

@alexbrainman
Copy link
Member

@alexbrainman alexbrainman commented Jun 22, 2021

I was able to reproduce my above scenario with a version of Go built with CGO_ENABLED=0 built from source at the go1.17beta1 tag.

That is not enough details for me to try to reproduce your issue. I need to know whatever commands you executed to have your environment setup and built. For example, I use go1.4.3 to bootstap my build of Go, but if I try to build with CGO_ENABLED=0 , I get

set CGO_ENABLED=0 
set MYHOME=c:\users\alex\dev
set GOROOT=%MYHOME%\go
set GOROOT_BOOTSTRAP=%MYHOME%\go1.4.3
set PATH=%PATH%;%GOROOT%\bin
cd %GOROOT%\src
CMD
c:\Users\Alex\dev\go\src>make
Building Go cmd/dist using c:\users\alex\dev\go1.4.3
go tool dist: cannot invoke C compiler "gcc": exec: "gcc": executable file not found in %PATH%

Go needs a system C compiler for use with cgo.
To set a C compiler, set CC=the-compiler.
To disable cgo, set CGO_ENABLED=0.

c:\Users\Alex\dev\go\src>

Perhaps I can still use CGO_ENABLED=0, but I would need to rebuild by bootsrap version of Go with CGO_ENABLED=0.

So just give me your exact instructions, if you want me to reproduce.

With go1.17beta1 I got that error every time go build reported exit status 0xc000013a, but with the CL applied no bad signal was reported either time I got that exit status. So maybe that fixes it.

I am confused about when you see exit status 0xc000013a. You were reporting signal received on a thread not created by Go before, but now your output shows exit status 0xc000013a.

The 0xc000013a is STATUS_CONTROL_C_EXIT. STATUS_CONTROL_C_EXIT is what default Windows ctrl-break handler returns. See ... Initially, the handler list for each process contains only a default handler function that calls the ExitProcess function. ... in https://docs.microsoft.com/en-us/windows/console/setconsolectrlhandler

0xc000013a is also related to CL 243597. Before CL 243597 we would return exit code 2 when ctrl+c goes unhandled. After CL 243597 we do return 0xc000013a in the same situation.

I also noticed that 0xc000013a is always happens with compile.exe in your output. Perhaps go.exe have ctrl+c handler installed, but compile.exe does not. Perhaps we can/should fix that.

Consider the situation where you press Ctrl+C that lands during runtime initialization. Even the default console control handler for Ctrl+C shouldn't land you in the exception handler.

I agree. If Ctrl+c happens before Go runtime calls SetConsoleCtrlHandler, the signal should endup in default Windows ctrl-c handler (that calls ExitProcess(STATUS_CONTROL_C_EXIT). If signal happens after SetConsoleCtrlHandler returns, the signal should be handled by Go ctrl-c handler.

Alex

@ChrisHines
Copy link
Contributor

@ChrisHines ChrisHines commented Jun 24, 2021

Here is the sequence I used to build in my last post:

The Go repo is cloned at C:\Users\Chris\proj\GoTip\go

I have installed go1.16.3 with the Windows installer downloaded from https://golang.org/dl/.

C:\Users\Chris\proj\GoTip\go\src>go version
go version go1.16.3 windows/amd64

C:\Users\Chris\proj\GoTip\go\src>set GOROOT_BOOTSTRAP=C:\Program Files\Go

C:\Users\Chris\proj\GoTip\go\src>set CGO_ENABLED=0

C:\Users\Chris\proj\GoTip\go\src>git status
HEAD detached at 451aed99db
nothing to commit, working tree clean

C:\Users\Chris\proj\GoTip\go\src>make.bat
Building Go cmd/dist using C:\Program Files\Go
Building Go toolchain1 using C:\Program Files\Go.
Building Go bootstrap cmd/go (go_bootstrap) using Go toolchain1.
Building Go toolchain2 using go_bootstrap and Go toolchain1.
Building Go toolchain3 using go_bootstrap and Go toolchain2.
Building packages and commands for windows/amd64.
---
Installed Go for windows/amd64 in C:\Users\Chris\proj\GoTip\go
Installed commands in C:\Users\Chris\proj\GoTip\go\bin

That builds with CL 321789. I used the same steps to build go1.17beta1 after checking out that branch.

I don't know if it matters, but here is a little info about the machine I'm running this on:

OS Name	Microsoft Windows 10 Home
Version	10.0.19042 Build 19042
System Type	x64-based PC
Processor	AMD Ryzen 7 5800X 8-Core Processor, 3801 Mhz, 8 Core(s), 16 Logical Processor(s)

I am confused about when you see exit status 0xc000013a. You were reporting signal received on a thread not created by Go before, but now your output shows exit status 0xc000013a.

My first comment on this issue also has the exit status 0xc000013a messages before the signal received on a thread not created by Go, you might need to scroll to the right to see the exit status messages, but they are there. After applying CL 321789 I could still get the exit status 0xc000013a messages occasionally, but they were not followed by the signal received ... message. The full console output is posted above in my earlier comments. What else can I provide to clarify?

@alexbrainman
Copy link
Member

@alexbrainman alexbrainman commented Jul 4, 2021

Here is the sequence I used to build in my last post:

Thanks for instructions. I tried to reproduce your setup. I still cannot see ... compile.exe: exit status 0xc000013a in my output.

C:\Users\Alex\Desktop\for_issue_46354>set GOROOT_BOOTSTRAP=C:\Program Files\Go

C:\Users\Alex\Desktop\for_issue_46354>set CGO_ENABLED=0

C:\Users\Alex\Desktop\for_issue_46354>cd C:\Users\Alex\proj\kit

C:\Users\Alex\proj\kit>CMD
Microsoft Windows [Version 10.0.19042.1052]
(c) Microsoft Corporation. All rights reserved.

C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe version
go version devel go1.17-451aed99db Fri May 21 17:42:29 2021 +0000 windows/amd64

C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe clean -cache

C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...

C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...

C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe clean -cache

C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Alex\proj\kit>..\GoTip\go\bin\go.exe build -trimpath ./...
^C
C:\Users\Alex\proj\kit>git rev-parse --short HEAD
0d7a388

C:\Users\Alex\proj\kit>go version
go version go1.16.3 windows/amd64

C:\Users\Alex\proj\kit>

Hopefully I did not muck something up. I tried waiting for a few seconds before hitting ctrl+c. I also watched Tasj Manager to display some compile.exe processes before hitting ctrl+c. like this

image

Still no luck. Let me know, if you see somthing differenet with my setup.

I also tried inserting time.Sleep(3 * time.Second) in the middle of cmd/compile. That did not help either, because I still see ^C printed on the console, instead of ... compile.exe: exit status 0xc000013a.

I don't know if it matters, but here is a little info about the machine I'm running this on:

OS Name	Microsoft Windows 10 Home
Version	10.0.19042 Build 19042
System Type	x64-based PC
Processor	AMD Ryzen 7 5800X 8-Core Processor, 3801 Mhz, 8 Core(s), 16 Logical Processor(s)

I don't see how that is relevant. But here is my systeminfo output:

OS Name:                   Microsoft Windows 10 Enterprise
OS Version:                10.0.19042 N/A Build 19042
System Type:               x64-based PC
Processor(s):              1 Processor(s) Installed.
                           [01]: Intel64 Family 6 Model 60 Stepping 3 GenuineIntel ~1500 Mhz

My first comment on this issue also has the exit status 0xc000013a messages before the signal received on a thread not created by Go, you might need to scroll to the right to see the exit status messages, but they are there.

Indeed. Your original comment did have exit status 0xc000013a in it. I did not see it because I did not scroll right.

After applying CL 321789 I could still get the exit status 0xc000013a messages occasionally, but they were not followed by the signal received ... message.

That is to be expected. CL 321789 fixes memory corruption. exit status 0xc000013a is different issue altogether. I am not even sure, if returning 0xc000013a from compile.exe is an error. 0xc000013a exit code is what default Windows ctrl handler returns, so I would argue it is fine for comiple.exe to do the same.

But I would like to see 0xc000013a exit code returned before I decided how to treat it. I would like to understand why 0xc000013a exit code is returned.

Similarly, I don't understand how memory corruption happens, that you see before CL 321789, and not after. What CL 321789 does it exits immediately when Go runtme tries to run Windows exception handler on a thread without g configured. Normally process with unhandled exception should print stack trace. But printing cannot be done without g.

Alex

@ChrisHines
Copy link
Contributor

@ChrisHines ChrisHines commented Jul 11, 2021

I don't notice any difference in your setup other than the CPU. I don't know if that matters. I do not know the code paths involved here to provide any suggestions. I just happen to have encountered the behavior, found this issue that seems to have similar symptoms, and reported what I've seen. I am happy to run additional tests if needed, but I don't know what else to say at this point.

@alexbrainman
Copy link
Member

@alexbrainman alexbrainman commented Jul 13, 2021

I don't notice any difference in your setup other than the CPU. I don't know if that matters.

Same. I don't think CPU matters here.

I do not know the code paths involved here to provide any suggestions. I just happen to have encountered the behavior, found this issue that seems to have similar symptoms, and reported what I've seen. I am happy to run additional tests if needed, but I don't know what else to say at this point.

Thanks for trying to help. Perhaps this information will be helpful in the future. Unfortunately I don't see what else we can try here. Let's live it for now.

Alex

@iwdgo
Copy link
Contributor

@iwdgo iwdgo commented Sep 22, 2021

The error seems slightly different than for Ctrl-Break. The message originates from the runtime package and is loaded during init:

func setBadSignalMsg() {
const msg = "runtime: signal received on thread not created by Go.\n"

Windows signal implementation is documented as incomplete.
No technical reason is mentioned.

go/src/os/exec_posix.go

Lines 19 to 21 in 051df0d

// the process to exit). On Windows, sending os.Interrupt to a process with
// os.Process.Signal is not implemented; it will return an error instead of
// sending a signal.

It seems that some luck is required to get to interrupt the runtime itself.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
5 participants