search

dotnet / runtime

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

PhysicalFilesWatcher: Log file/path triggering a change notification #100872

Open CodeBlanch opened 5 months ago

CodeBlanch commented 5 months ago

I'm working with a user reporting a bug in OpenTelemetry .NET. It seems some file system change is triggering an IConfiguration reload which is manifesting a bug in OpenTelemetry causing some resources to be created (background threads) which aren't ever used or cleaned up. We're fixing that bug in OpenTelemetry but so far we haven't been able to figure out why that configuration reload is firing.

In the call stack we see:

Microsoft.Extensions.FileProviders.Physical.dll!Microsoft.Extensions.FileProviders.Physical.PhysicalFilesWatcher..cctor.AnonymousMethod__43_0(object state) Line 29 C#

I'm wondering if we could add some EventSource info/verbose logging inside PhysicalFilesWatcher to help troubleshoot issues in the future.

OTel issue: https://github.com/open-telemetry/opentelemetry-dotnet/issues/5513

More of the stack trace ``` ...user portion removed... Microsoft.Extensions.Options.dll!Microsoft.Extensions.Options.ConfigureNamedOptions.Configure(string name, System.__Canon options) Line 49 C# Microsoft.Extensions.Options.dll!Microsoft.Extensions.Options.OptionsFactory.Create(string name) Line 87 C# Microsoft.Extensions.Options.dll!Microsoft.Extensions.Options.OptionsMonitor.Get.AnonymousMethod__10_0(string name, Microsoft.Extensions.Options.IOptionsFactory factory) Line 94 C# Microsoft.Extensions.Options.dll!Microsoft.Extensions.Options.OptionsCache.GetOrAdd.AnonymousMethod__2() Line 68 C# System.Private.CoreLib.dll!System.Lazy.ViaFactory(System.Threading.LazyThreadSafetyMode mode) Line 321 C# System.Private.CoreLib.dll!System.Lazy.ExecutionAndPublication(System.LazyHelper executionAndPublication, bool useDefaultConstructor) Line 345 C# System.Private.CoreLib.dll!System.Lazy.CreateValue() Line 433 C# System.Private.CoreLib.dll!System.Lazy.Value.get() Line 505 C# Microsoft.Extensions.Options.dll!Microsoft.Extensions.Options.OptionsCache.GetOrAdd>(string name, System.Func, OpenTelemetry.Logs.OpenTelemetryLoggerOptions> createOptions, Microsoft.Extensions.Options.IOptionsFactory factoryArgument) Line 66 C# Microsoft.Extensions.Options.dll!Microsoft.Extensions.Options.OptionsMonitor.Get(string name) Line 94 C# Microsoft.Extensions.Options.dll!Microsoft.Extensions.Options.OptionsMonitor.InvokeChanged(string name) Line 68 C# Microsoft.Extensions.Primitives.dll!Microsoft.Extensions.Primitives.ChangeToken.ChangeTokenRegistration.OnChangeTokenFired() Line 87 C# Microsoft.Extensions.Primitives.dll!Microsoft.Extensions.Primitives.ChangeToken.ChangeTokenRegistration.RegisterChangeTokenCallback.AnonymousMethod__7_0(object s) Line 103 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.Invoke(System.Delegate d, object state, System.Threading.CancellationTokenSource source) Line 902 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.CallbackNode.ExecuteCallback.AnonymousMethod__9_0(object s) Line 1139 C# System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 183 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.CallbackNode.ExecuteCallback() Line 1141 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(bool throwOnFirstException) Line 722 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.NotifyCancellation(bool throwOnFirstException) Line 639 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.Cancel() Line 221 C# Microsoft.Extensions.Configuration.dll!Microsoft.Extensions.Configuration.ConfigurationReloadToken.OnReload() Line 41 C# Microsoft.Extensions.Configuration.dll!Microsoft.Extensions.Configuration.ConfigurationRoot.RaiseChanged() Line 93 C# Microsoft.Extensions.Primitives.dll!Microsoft.Extensions.Primitives.ChangeToken.OnChange.AnonymousMethod__0_0(System.Action callback) Line 32 C# Microsoft.Extensions.Primitives.dll!Microsoft.Extensions.Primitives.ChangeToken.ChangeTokenRegistration.OnChangeTokenFired() Line 87 C# Microsoft.Extensions.Primitives.dll!Microsoft.Extensions.Primitives.ChangeToken.ChangeTokenRegistration.RegisterChangeTokenCallback.AnonymousMethod__7_0(object s) Line 103 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.Invoke(System.Delegate d, object state, System.Threading.CancellationTokenSource source) Line 902 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.CallbackNode.ExecuteCallback.AnonymousMethod__9_0(object s) Line 1139 C# System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 183 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.CallbackNode.ExecuteCallback() Line 1141 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(bool throwOnFirstException) Line 722 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.NotifyCancellation(bool throwOnFirstException) Line 639 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.Cancel() Line 221 C# Microsoft.Extensions.Configuration.dll!Microsoft.Extensions.Configuration.ConfigurationReloadToken.OnReload() Line 41 C# Microsoft.Extensions.Configuration.dll!Microsoft.Extensions.Configuration.ConfigurationRoot.RaiseChanged() Line 93 C# Microsoft.Extensions.Primitives.dll!Microsoft.Extensions.Primitives.ChangeToken.OnChange.AnonymousMethod__0_0(System.Action callback) Line 32 C# Microsoft.Extensions.Primitives.dll!Microsoft.Extensions.Primitives.ChangeToken.ChangeTokenRegistration.OnChangeTokenFired() Line 87 C# Microsoft.Extensions.Primitives.dll!Microsoft.Extensions.Primitives.ChangeToken.ChangeTokenRegistration.RegisterChangeTokenCallback.AnonymousMethod__7_0(object s) Line 103 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.Invoke(System.Delegate d, object state, System.Threading.CancellationTokenSource source) Line 902 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.CallbackNode.ExecuteCallback.AnonymousMethod__9_0(object s) Line 1139 C# System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 183 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.CallbackNode.ExecuteCallback() Line 1141 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(bool throwOnFirstException) Line 722 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.NotifyCancellation(bool throwOnFirstException) Line 639 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.Cancel() Line 221 C# Microsoft.Extensions.Configuration.dll!Microsoft.Extensions.Configuration.ConfigurationReloadToken.OnReload() Line 41 C# Microsoft.Extensions.Configuration.dll!Microsoft.Extensions.Configuration.ConfigurationProvider.OnReload() Line 118 C# Microsoft.Extensions.Configuration.FileExtensions.dll!Microsoft.Extensions.Configuration.FileConfigurationProvider.Load(bool reload) Line 113 C# Microsoft.Extensions.Configuration.FileExtensions.dll!Microsoft.Extensions.Configuration.FileConfigurationProvider..ctor.AnonymousMethod__1_1() Line 40 C# Microsoft.Extensions.Primitives.dll!Microsoft.Extensions.Primitives.ChangeToken.OnChange.AnonymousMethod__0_0(System.Action callback) Line 32 C# Microsoft.Extensions.Primitives.dll!Microsoft.Extensions.Primitives.ChangeToken.ChangeTokenRegistration.OnChangeTokenFired() Line 87 C# Microsoft.Extensions.Primitives.dll!Microsoft.Extensions.Primitives.ChangeToken.ChangeTokenRegistration.RegisterChangeTokenCallback.AnonymousMethod__7_0(object s) Line 103 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.Invoke(System.Delegate d, object state, System.Threading.CancellationTokenSource source) Line 902 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.CallbackNode.ExecuteCallback() Line 1141 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(bool throwOnFirstException) Line 722 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.NotifyCancellation(bool throwOnFirstException) Line 639 C# System.Private.CoreLib.dll!System.Threading.CancellationTokenSource.Cancel() Line 221 C# > Microsoft.Extensions.FileProviders.Physical.dll!Microsoft.Extensions.FileProviders.Physical.PhysicalFilesWatcher..cctor.AnonymousMethod__43_0(object state) Line 29 C# System.Private.CoreLib.dll!System.Threading.Tasks.Task.InnerInvoke() Line 2397 C# System.Private.CoreLib.dll!System.Threading.Tasks.Task..cctor.AnonymousMethod__272_0(object obj) Line 2376 C# System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(System.Threading.Thread threadPoolThread, System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) Line 268 C# System.Private.CoreLib.dll!System.Threading.Tasks.Task.ExecuteWithThreadLocal(ref System.Threading.Tasks.Task currentTaskSlot, System.Threading.Thread threadPoolThread) Line 2337 C# System.Private.CoreLib.dll!System.Threading.Tasks.Task.ExecuteEntryUnsafe(System.Threading.Thread threadPoolThread) Line 2277 C# System.Private.CoreLib.dll!System.Threading.ThreadPoolWorkQueue.Dispatch() Line 790 C# System.Private.CoreLib.dll!System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart() Line 63 C# System.Private.CoreLib.dll!System.Threading.Thread.StartCallback() Line 106 C# [Native to Managed Transition] ```

/cc @tarekgh

jozkee commented 2 months ago

That method you are seeing seems to be spawned when a change token matches a path reported by the underlying FileSystemWatcher. I wonder if its possible that the PhysicalFilesWatcher is being disposed before the thread finish execution, not sure if that would cause problems. What's the error message? Do you have a consoleapp repro?