search

dotnet / runtime

.NET is a cross-platform runtime for cloud, mobile, desktop, and IoT apps.
https://docs.microsoft.com/dotnet/core/
MIT License
15.46k stars 4.76k forks source link

System.Data.SqlClient.Stress.Tests failed to generate the test result #23490

Closed KristinXie1 closed 4 years ago

KristinXie1 commented 7 years ago

System.Data.SqlClient.Stress.Tests failed to generate the test result

Failed configuration: Windows.10.Amd64-arm

Detail: https://mc.dot.net/#/product/netcore/uwp60/source/official~2Fcorefx~2Frelease~2Fuwp6.0~2F/type/test~2Ffunctional~2Filc~2F/build/20170908.01/workItem/System.Data.SqlClient.Stress.Tests/wilogs

2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error : Unhandled Exception: System.InvalidOperationException: Method failed with unexpected error code 122.
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at System.Security.AccessControl.NativeObjectSecurity.Persist(String name, SafeHandle handle, AccessControlSections includeSections, Object exceptionContext)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at System.Security.AccessControl.NativeObjectSecurity.Persist(SafeHandle handle, AccessControlSections includeSections, Object exceptionContext)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at System.Security.AccessControl.NativeObjectSecurity.Persist(SafeHandle handle, AccessControlSections includeSections)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at System.Security.AccessControl.RegistrySecurity.Persist(SafeRegistryHandle hKey, String keyName)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at Microsoft.Win32.RegistryKey.SetAccessControl(RegistrySecurity registrySecurity)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at Microsoft.VisualStudio.Telemetry.RegistryPropertyBag.SetAccessControl(RegistryKey key)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at Microsoft.VisualStudio.Telemetry.RegistryPropertyBag.<>c__DisplayClass14_0.<SetProperty>b__0()
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at Microsoft.VisualStudio.Telemetry.RegistryPropertyBag.SafeRegistryCall(Action action)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at Microsoft.VisualStudio.Telemetry.RegistryPropertyBag.SetProperty(String propertyName, Object value)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at Microsoft.VisualStudio.Telemetry.RegistryPropertyBag.SetProperty(String propertyName, String value)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at Microsoft.VisualStudio.Telemetry.MACInformationProvider.<>c__DisplayClass13_0.<RunProcessIfNecessary>b__0(String data)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at Microsoft.VisualStudio.Telemetry.ProcessTools.<>c__DisplayClass1_0.<RunCommand>b__1(Object sender, EventArgs e)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at System.Diagnostics.Process.OnExited()
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at System.Diagnostics.Process.RaiseOnExited()
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at System.Diagnostics.Process.CompletionCallback(Object context, Boolean wasSignaled)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at System.Threading._ThreadPoolWaitOrTimerCallback.WaitOrTimerCallback_Context(Object state, Boolean timedOut)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at System.Threading._ThreadPoolWaitOrTimerCallback.WaitOrTimerCallback_Context_f(Object state)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
2017-09-08 02:00:15,917: INFO: proc(54): run_and_log_output: Output: MSBUILD : error :    at System.Threading._ThreadPoolWaitOrTimerCallback.PerformWaitOrTimerCallback(Object state, Boolean timedOut)
danmoseley commented 7 years ago

@joshfree where should this go? seems like Microsoft.VisualStudio.Telemetry perhaps should be robust to failing to write to the registry .. telemetry shoudn't bring down the app. There might be a bug in us also. 122= buffer too small.

joshfree commented 7 years ago

@vitek-karas can you take a look please

vitek-karas commented 7 years ago

We've seen this before - but it's VERY rare. It's a bug in the telemetry SDK which we have no control over. Basically they write to stderr of the process they run in - in some cases. We already had them fix it for one such case. This one we weren't able to provide a repro for though... (The fact that it writes to stderr then leads to us capturing that stderr from gatekeeper process and we treat anything in stderr as a fatal error, thus the failure). For now we simply ignored this since it is really very rare (we've probably seen it like 3 times total). Alternatively we could add a filter into the ILC to recognize this particular failure and ignore it... sort of a hacky solution though.

@AntonLapounov - any ideas about this in the context of selfhosting?

danmoseley commented 7 years ago

As for the cause of the failure, per Raymond When can GetSecurityInfo API return ERROR_INSUFFICIENT_BUFFER? https://blogs.msdn.microsoft.com/oldnewthing/20170622-00/?p=96445 this is probably a race with another thread modifying the same descriptor. I can't see any hits on any other reason for it. I'm guessing that other thread may be telemetry also?

vitek-karas commented 7 years ago

Interesting - thanks a lot for finding that. I'll contact the telemetry SDK team with this, hopefully they'll be able to tell where exactly in their code this is coming from and fix it (both the GetSecurityInfo as well as writing to stderr).

vitek-karas commented 7 years ago

I filed a bug on the Telemetry SDK team about this. I also tracked down why we're seeing it show up (through the stderr). Turns out that part was already fixed (they don't write to stderr anymore), we just didn't pick up a version of the SDK with the fix. I'm discussing with them what it would take to get a new build with that fix. If I don't get that soon, I'll probably try to implement the filtering solution as an interim step.

vitek-karas commented 7 years ago

Updated the Telemetry SDK in .NET Native. The new SDK will not write anything into stderr (That we know off), so even if telemetry fails for some reason it will not cause ILC failures. Tomorrow's build of TestILC package should have the fix.