internal/syscall/windows/registry: registry subkey enumeration cannot handle thread migrations #49320

mknyszek · 2021-11-03T17:09:41Z

In trying to land #44167, I discovered that an additional well-placed GC cycle in the internal/syscall/windows/registry tests caused one of the tests to mysteriously fail in a RegEnumKeyExW syscall with "access denied." This syscall is called multiple times in a row, and the first call never was what failed.

The total amount of code involved in the test is fairly small, so it was hard to see what could possibly be going wrong. Furthermore, the RegEnumKeyExW documentation doesn't indicate with certainty under what conditions it could fail (https://docs.microsoft.com/en-us/windows/win32/api/winreg/nf-winreg-regenumkeyexw#remarks). After looking at some execution traces, I stumbled upon the issue: if the goroutine executing these syscalls migrates between OS threads (not interrupting the syscall mind you, just in between consecutive calls), then subsequent calls will fail.

I confirmed this by adding runtime.LockOSThread to the ReadSubKeyNames method on Key, and that seems to fix it.

Steps forward here I think are:

Call runtime.LockOSThread in ReadSubKeyNames.
Document that RegEnumKeyExW requires the goroutine to be locked to its OS thread.

Another potential third step could be to expose a safer abstraction for this in the syscall package itself, but since the API is frozen, I don't think this is possible.

The text was updated successfully, but these errors were encountered:

bcmills · 2021-11-03T18:27:48Z

Another potential third step could be to expose a safer abstraction for this in the syscall package itself, but since the API is frozen, I don't think this is possible.

The unsafe version of the function can't be removed, but it can be deprecated in favor of a safer replacement if we can define one.

gopherbot · 2021-11-03T18:30:06Z

Change https://golang.org/cl/361154 mentions this issue: syscall: fix and document uses of RegEnumKeyEx

gopherbot · 2021-11-09T17:50:17Z

Change https://golang.org/cl/362576 mentions this issue: windows/registry: lock OS thread while enumerating keys

CL 361154 updated the standard syscall package to document that successive calls to syscall.RegEnumKeyEx must occur on the same OS thread (after that requirement was empirically discovered in golang/go#49320). This use in x/sys needs to be updated to comply with the newly-discovered requirement. Fixes golang/go#49466. Change-Id: Idc45d91f175e1db25c215213fcaa45982c2f5e6e Reviewed-on: https://go-review.googlesource.com/c/sys/+/362576 Trust: Bryan C. Mills <[email protected]> Run-TryBot: Bryan C. Mills <[email protected]> TryBot-Result: Go Bot <[email protected]> Reviewed-by: Ian Lance Taylor <[email protected]>

alexbrainman · 2021-11-12T07:12:10Z

@mknyszek I tried to reproduce this issue on my Windows 10 laptop and windows-amd64-2016 builder and I cannot reproduce it.

I build

https://go-review.googlesource.com/c/sys/+/363574

and my test fails with

--- FAIL: TestReadSubKeyNames (0.00s)
    registry_test.go:44: key Accessibility
    registry_test.go:44: key Colors
    registry_test.go:44: key Cursors
    registry_test.go:44: key Desktop
    registry_test.go:44: key Input Method
    registry_test.go:44: key International
    registry_test.go:44: key Keyboard
    registry_test.go:44: key Mouse
    registry_test.go:44: key PowerCfg
    registry_test.go:46: BOOM
FAIL
FAIL	golang.org/x/sys/windows/registry	0.025s

If my change follows your explanation of the problem, the test should fail on line 44 instead of 46.

Where did I make mistake?

Thank you.

Alex

alexbrainman · 2021-11-25T07:38:50Z

Pinging @mknyszek . Please reply to #49320 (comment)

Thank you.

Alex

alexbrainman · 2021-12-07T05:36:35Z

Pinging @mknyszek . Please reply to #49320 (comment)

Thank you.

Alex

mknyszek · 2021-12-07T17:19:40Z

@alexbrainman The restriction may be limited to windows-386-2008. Perhaps that's a bug that was fixed in later editions. I didn't try to reproduce on later Windows, or windows/amd64.

alexbrainman · 2021-12-08T07:57:29Z

The restriction may be limited to windows-386-2008.

My test #49320 (comment) was run on windows-386-2008 and windows-amd64-2016. So still I don't see any "restriction" even on windows-386-2008 builder.

What did you do differently from CL 363574 to reproduce this issue?

Thank you.

Alex

mknyszek · 2021-12-08T16:48:39Z

Then I don't know. Perhaps that assumption is wrong. What I did was I inserted a call to runtime.GC before the call to syscall.RegEnumKeyEx. An additional GC cycle should not cause a syscall API to fail. Adding in runtime.LockOSThread made it so that, even with the additional GC cycle, it still worked. Maybe it's some other effect of runtime.LockOSThread that resolved it.

It's possible this is a bug in the syscall path instead, maybe. Feel free to update the documentation if you think what I wrote is wrong.

bcmills · 2021-12-08T17:48:40Z

@alexbrainman, FWIW this failure mode also reproduced in x/sys/windows/registry.TestReadSubKeyNames on the Go dashboard builders (mainly windows-386-2008, but also twice on windows-amd64-2016). That was #49466, and seems to have been resolved by adding a runtime.LockOSThread in CL 362576.

alexbrainman · 2021-12-10T22:07:47Z

It's possible this is a bug in the syscall path instead, maybe.

Yes, it is quite possible the problem is in runtime, and not in Windows. You assumed that the problem is in OS, and that is a possibility. But we need some repro (maybe C code that fails in the same way) or at the very least repro in Go, before we should submit code based on that assumption. Your "fix" most likely just hiding a bug in runtime.

That was #49466, and seems to have been resolved by adding a runtime.LockOSThread in CL 362576.

CL 362576 assumes that there is a bug in Windows. And we cannot reproduce this bug. So we don't really know why CL 362576 fixes #49466. Like I said above, CL 362576 could be masking bug in runtime.

Alex

mknyszek · 2021-12-11T03:35:20Z

I agree with you that an OS bug is unlikely, but I don't believe it to be a bug. I never did. I believe (as I wrote in CL 362576) that I thought this was an undocumented requirement. My reasoning was the following: in C land (or really any other place), it's difficult to imagine that this syscall would be called in a loop across threads. Go is unique here where a thread switch can happen at almost any time. I think such a scenario is far likelier.

Clearly my original assertion was wrong in some way, however, and I admit that.

And we cannot reproduce this bug.

As I said before, I believe we can. Back when debugging this, I could have it fail nearly every time by adding a call to runtime.GC just before the call to syscall.RegEnumKeyEx while removing the calls to runtime.LockOSThread. Also, it should be reproducible by applying GOEXPERIMENT=heapminimum512kib and again removing the calls to runtime.LockOSThread; this was the original failure mode.

CL 362576 doesn't fix the issue as currently titled, but it does mitigate a real bug. It could be a bug in the runtime, I don't disagree. But the bug is mitigated. Given your attempts at reproduction, we should revert the changes to the documentation. But I don't think we should revert the mitigation.

On Monday I will confirm that I can reproduce it.

mknyszek · 2021-12-13T19:24:07Z

With this patch:

diff --git a/src/internal/syscall/windows/registry/key.go b/src/internal/syscall/windows/registry/key.go
index ec38cf9288..1bcc6b9b4c 100644
--- a/src/internal/syscall/windows/registry/key.go
+++ b/src/internal/syscall/windows/registry/key.go
@@ -91,12 +91,6 @@ func OpenKey(k Key, path string, access uint32) (Key, error) {

 // ReadSubKeyNames returns the names of subkeys of key k.
 func (k Key) ReadSubKeyNames() ([]string, error) {
-       // RegEnumKeyEx must be called repeatedly and to completion.
-       // During this time, this goroutine cannot migrate away from
-       // its current thread. See #49320.
-       runtime.LockOSThread()
-       defer runtime.UnlockOSThread()
-
        names := make([]string, 0)
        // Registry key size limit is 255 bytes and described there:
        // https://msdn.microsoft.com/library/windows/desktop/ms724872.aspx
@@ -105,6 +99,7 @@ loopItems:
        for i := uint32(0); ; i++ {
                l := uint32(len(buf))
                for {
+                       runtime.GC()
                        err := syscall.RegEnumKeyEx(syscall.Handle(k), i, &buf[0], &l, nil, nil, nil, nil)
                        if err == nil {
                                break

go test internal/syscall/windows/registry failed immediately for me on a windows-386-2008 gomote with:

--- FAIL: TestReadSubKeyNames (0.00s)
    registry_test.go:39: Access is denied.
FAIL
FAIL	internal/syscall/windows/registry	0.033s
FAIL
Error running run: exit status 1

I've confirmed that LockOSThread does appear to mitigate some issue here.

alexbrainman · 2021-12-31T06:50:54Z

With this patch:

diff --git a/src/internal/syscall/windows/registry/key.go b/src/internal/syscall/windows/registry/key.go
index ec38cf9288..1bcc6b9b4c 100644
--- a/src/internal/syscall/windows/registry/key.go
+++ b/src/internal/syscall/windows/registry/key.go
@@ -91,12 +91,6 @@ func OpenKey(k Key, path string, access uint32) (Key, error) {

 // ReadSubKeyNames returns the names of subkeys of key k.
 func (k Key) ReadSubKeyNames() ([]string, error) {
-       // RegEnumKeyEx must be called repeatedly and to completion.
-       // During this time, this goroutine cannot migrate away from
-       // its current thread. See #49320.
-       runtime.LockOSThread()
-       defer runtime.UnlockOSThread()
-
        names := make([]string, 0)
        // Registry key size limit is 255 bytes and described there:
        // https://msdn.microsoft.com/library/windows/desktop/ms724872.aspx
@@ -105,6 +99,7 @@ loopItems:
        for i := uint32(0); ; i++ {
                l := uint32(len(buf))
                for {
+                       runtime.GC()
                        err := syscall.RegEnumKeyEx(syscall.Handle(k), i, &buf[0], &l, nil, nil, nil, nil)
                        if err == nil {
                                break

go test internal/syscall/windows/registry failed immediately for me on a windows-386-2008 gomote with:

--- FAIL: TestReadSubKeyNames (0.00s)
    registry_test.go:39: Access is denied.
FAIL
FAIL	internal/syscall/windows/registry	0.033s
FAIL
Error running run: exit status 1

Thank you @mknyszek I can reproduce this problem pretty much anywhere.

Unfortunately I still doo not know what the problem is.

The test fails because RegEnumKeyEx after a few calls returns ERROR_ACCESS_DENIED.

RegEnumKeyEx is called in a loop starting with index 0, then 1, then 2 and so on. It always succeeds when called with index of 0. I can see it fails with either index 1 or 2.

I also added a call to print GetCurrentThreadId value. And thread id changes every loop iteration.

I also checked that RegEnumKeyEx output parameters don't move in memory between the calls (I printed buf and l addresses).

I also noticed that

https://docs.microsoft.com/en-us/windows/win32/sysinfo/enumerating-registry-subkeys

uses KEY_READ instead of KEY_ENUMERATE_SUB_KEYS. So I also replaced registry.ENUMERATE_SUB_KEYS with registry.READ. And that fixes the problem. But

https://docs.microsoft.com/en-us/windows/win32/api/winreg/nf-winreg-regenumkeyexw

says to use KEY_ENUMERATE_SUB_KEYS, so I don't think my change is appropriate.

@zx2c4 perhaps you have some suggestions here. Perhaps you can step into RegEnumKeyEx to see why it returns ERROR_ACCESS_DENIED in our test.

Thank you.

Alex

zx2c4 · 2021-12-31T13:29:47Z

@zx2c4 perhaps you have some suggestions here. Perhaps you can step into RegEnumKeyEx to see why it returns ERROR_ACCESS_DENIED in our test.

Haven't done anything dynamic yet, but just statically reverse engineering things, it looks like:

RegEnumKeyExW->LocalBaseRegEnumKey->EnumTableGetKeyState->StateObjectListFind(arg->someMember, NtCurrentTeb()->ClientId.UniqueThread), and similarly with a call into EnumTableAddKey which also looks at the TID. There are a bunch of heap allocations and lookup table things going on. That leads me to suspect that a first call is querying quite a bit of info on subkeys, which is then cached by KernelBase.dll and doled out on each successive call to RegEnumKeyExW. This cache seems to be keyed based on the thread ID, so if things are migrated to a new thread, the call fails.

The more interesting question is why KEY_READ works but KEY_ENUMERATE_SUB_KEYS does not. I suspect what's happening is that it first tries to enumerate using NtQueryKey(KeyCachedInformation) to get the number of subkeys, which requires KEY_ENUMERATE_SUB_KEYS. When this fails, it then falls back to using NtEnumerateKey, one by one with no fancy caching, which only requires KEY_READ access.

If that theory holds true, moving to KEY_READ probably isn't good for performance.

I agree this per-thread cache behavior is weird and surprising, and if it can't be fixed in Windows, it should probably at least be documented, so CCing @jstarks.

alexbrainman · 2022-01-02T07:46:08Z

Haven't done anything dynamic yet, but just statically reverse engineering things, it looks like:

Thanks for doing this. Your explanation sounds reasonable.

I agree this per-thread cache behavior is weird and surprising, and if it can't be fixed in Windows, it should probably at least be documented, so CCing @jstarks.

Yes. RegEnumKeyExW documentation does not say that all calls must come from the same thread.

I will leave this issue opened until we hear from @jstarks.

Alex

jstarks · 2022-01-03T19:14:05Z

Yes, this appears to be intentional behavior specifically for HKEY_CLASSES_ROOT as of Windows 2000. HKCU is a merged view of the machine-wide CLSID information (from HKLM) and the user-local CLSID information (from HKCU). This merging happens in user mode, and the associated state across calls is maintained in TLS.

There's no obvious way to improve this in the OS without introducing a new API, something that is quite unlikely to occur since there's a reasonable-enough workaround here.

I'll try to get the behavior documented.

alexbrainman · 2022-01-15T03:11:48Z

Thank you @jstarks for explaining.

Yes, this appears to be intentional behavior ...

We are talking about RegEnumKeyExW returning ERROR_ACCESS_DENIED when called on a different thread from the thread that opened the key. I don't see how this can be intentional. It is just a broken implementation.

This merging happens in user mode, and the associated state across calls is maintained in TLS.

There's no obvious way to improve this in the OS without introducing a new API, ...

Again this is implementation details. I don't see why you need a new API. Unless you mean that new API is required to build similarly fast implementation. Or something else.

since there's a reasonable-enough workaround here.

Are you referring to the code that keeps internal/syscall/windows/registry.ReadSubKeyNames function execution on the same thread

https://go-review.googlesource.com/c/go/+/361154/

?

Then we had no other choice. And the requirement to stay on the same thread is not documented anywhere. So @mknyszek had a good guess. I did not believe it is possible for such Windows bug.

I'll try to get the behavior documented.

That would be nice. Thank you.

Closing this issue, because I am satisfied this a Windows bug. Nothing we can do here.

Alex

mknyszek self-assigned this Nov 3, 2021

mknyszek added this to the Go1.18 milestone Nov 3, 2021

mknyszek added the NeedsFix The path to resolution is known, but the work has not been done. label Nov 3, 2021

gopherbot closed this as completed in d9bb5f6 Nov 4, 2021

bcmills mentioned this issue Nov 8, 2021

x/sys/windows/registry: TestReadSubKeyNames failures with "Access is denied" #49466

Closed

alexbrainman reopened this Dec 7, 2021

alexbrainman closed this as completed Jan 15, 2022

rsc unassigned mknyszek Jun 23, 2022

golang locked and limited conversation to collaborators Jun 23, 2023

gopherbot added the FrozenDueToAge label Jun 23, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

internal/syscall/windows/registry: registry subkey enumeration cannot handle thread migrations #49320

internal/syscall/windows/registry: registry subkey enumeration cannot handle thread migrations #49320

mknyszek commented Nov 3, 2021

bcmills commented Nov 3, 2021

gopherbot commented Nov 3, 2021

gopherbot commented Nov 9, 2021

alexbrainman commented Nov 12, 2021

alexbrainman commented Nov 25, 2021

alexbrainman commented Dec 7, 2021

mknyszek commented Dec 7, 2021 •

edited

Loading

alexbrainman commented Dec 8, 2021

mknyszek commented Dec 8, 2021 •

edited

Loading

bcmills commented Dec 8, 2021

alexbrainman commented Dec 10, 2021

mknyszek commented Dec 11, 2021 •

edited

Loading

mknyszek commented Dec 13, 2021 •

edited

Loading

alexbrainman commented Dec 31, 2021

zx2c4 commented Dec 31, 2021

alexbrainman commented Jan 2, 2022

jstarks commented Jan 3, 2022

alexbrainman commented Jan 15, 2022

internal/syscall/windows/registry: registry subkey enumeration cannot handle thread migrations #49320

internal/syscall/windows/registry: registry subkey enumeration cannot handle thread migrations #49320

Comments

mknyszek commented Nov 3, 2021

bcmills commented Nov 3, 2021

gopherbot commented Nov 3, 2021

gopherbot commented Nov 9, 2021

alexbrainman commented Nov 12, 2021

alexbrainman commented Nov 25, 2021

alexbrainman commented Dec 7, 2021

mknyszek commented Dec 7, 2021 • edited Loading

alexbrainman commented Dec 8, 2021

mknyszek commented Dec 8, 2021 • edited Loading

bcmills commented Dec 8, 2021

alexbrainman commented Dec 10, 2021

mknyszek commented Dec 11, 2021 • edited Loading

mknyszek commented Dec 13, 2021 • edited Loading

alexbrainman commented Dec 31, 2021

zx2c4 commented Dec 31, 2021

alexbrainman commented Jan 2, 2022

jstarks commented Jan 3, 2022

alexbrainman commented Jan 15, 2022

mknyszek commented Dec 7, 2021 •

edited

Loading

mknyszek commented Dec 8, 2021 •

edited

Loading

mknyszek commented Dec 11, 2021 •

edited

Loading

mknyszek commented Dec 13, 2021 •

edited

Loading