Aspnetcore: ChangeToken.OnChange fires twice when listening for configuration changes

[aspnet-hello]

_From @Tratcher on Wednesday, July 19, 2017 9:08:36 AM_

_From @magnusbakken on March 20, 2017 10:22_

When I use ChangeToken.OnChange to listen to configuration changes as described in https://github.com/aspnet/Configuration/issues/432, my handler usually gets called twice in quick succession.

To reproduce:

1. Create a new ASP.NET Core targeting .NET Framework project using the Web API template (I haven't tested targeting .NET Core).
2. Add this line in the Configure method in Startup.cs: ChangeToken.OnChange(Configuration.GetReloadToken, () => loggerFactory.CreateLogger<Startup>().LogWarning("Configuration changed"));
3. Start the app.
4. While the app is running, make a change in appsettings.json and save the file.

The line "Configuration changed" shows up twice in the console output.

I've tried to make the file change from multiple programs (Visual Studio, Notepad, emacs), and by copying and replacing the file in its entirety. At least once I think I saw the change only being logged once, but usually you get it twice with just a few milliseconds between the log events.

I've attached the call stacks I see from the debugger for the first and second call respectively:
first-callstack.txt
second-callstack.txt

The only difference is the following five lines in the middle of the second stack:

mscorlib.dll!System.Threading.CancellationTokenSource.InternalRegister(System.Action<object> callback, object stateForCallback, System.Threading.SynchronizationContext targetSyncContext, System.Threading.ExecutionContext executionContext)  Unknown
mscorlib.dll!System.Threading.CancellationToken.Register(System.Action<object> callback, object state, bool useSynchronizationContext, bool useExecutionContext)    Unknown
mscorlib.dll!System.Threading.CancellationToken.Register(System.Action<object> callback, object state)  Unknown
Microsoft.Extensions.Primitives.dll!Microsoft.Extensions.Primitives.CancellationChangeToken.RegisterChangeCallback(System.Action<object> callback, object state)    Unknown
Microsoft.Extensions.Primitives.dll!Microsoft.Extensions.Primitives.ChangeToken.OnChange.AnonymousMethod__0(object s)   Unknown

_Copied from original issue: aspnet/Configuration#624_

_Copied from original issue: aspnet/FileSystem#287_

[aspnet-hello]

_From @Tratcher on Wednesday, July 19, 2017 9:08:37 AM_

_From @hcoona on April 28, 2017 6:52_

Reproduced also on .NET Framework 4.5.1

[aspnet-hello]

_From @Tratcher on Wednesday, July 19, 2017 9:08:37 AM_

_From @HaoK on June 15, 2017 23:45_

Yeah this is just how change tokens work, what we did to somewhat mitgate this when we are listening for changes was to add a delay before invoking callback so the changes hopefully will be finished:

https://github.com/aspnet/Configuration/blob/dev/src/Microsoft.Extensions.Configuration.FileExtensions/FileConfigurationProvider.cs#L35

                ChangeToken.OnChange(
                    () => Source.FileProvider.Watch(Source.Path),
                    () => {
                        Thread.Sleep(Source.ReloadDelay);
                        Load(reload: true);
                    });

[aspnet-hello]

_From @Tratcher on Wednesday, July 19, 2017 9:08:37 AM_

_From @HaoK on June 15, 2017 23:45_

You likely need to do something similar if you don't want to get called multiple times for the same underlying change.

[aspnet-hello]

_From @Tratcher on Wednesday, July 19, 2017 9:09:37 AM_

Note this is actually caused by the underlying file watcher triggering multiple times for the same change. The second call to Watch sometimes fires immediately because of this.

[aspnet-hello]

_From @guardrex on Saturday, October 21, 2017 10:37:05 PM_

@divega @HaoK @Tratcher I'm coming up real quick on the topic for ChangeToken. I'll outline the topic to use ChangeToken with config files (as I'm mess'in around with below) and for general file watching. More on that later over in the doc issue. Right now, I'm just playing with it.

I couldn't get a reliable solution to the double-firing problem using a delay, so what do you cats think about a hash check approach? ~Even if fine for appsettings.json, this would require expansion to cover the appsettings.{environment}.json file, which I could roll in easily enough.~ [EDIT] Added some bits below to cover the environment version of the file.

public class Startup
{
    private ConfigurationReloadToken _changeToken = new ConfigurationReloadToken();
    private byte[] _configFileHash1 = new byte[20];
    private byte[] _configFileHash2 = new byte[20];

    public void ConfigureServices(IServiceCollection services)
    {
        ...
    }

    public void Configure(IApplicationBuilder app, IHostingEnvironment env, 
        IConfiguration config)
    {
        ChangeToken.OnChange(
            () => config.GetReloadToken(),
            () => 
            {
                byte[] configFileHash1 = ComputeHash("appSettings.json");
                byte[] configFileHash2 = ComputeHash($"appSettings.{env.EnvironmentName}.json");

                if (!_configFileHash1.SequenceEqual(configFileHash1) ||
                    !_configFileHash2.SequenceEqual(configFileHash2))
                {
                    DoSomething();
                    _configFileHash1 = configFileHash1;
                    _configFileHash2 = configFileHash2;
                }

                var previousToken = 
                    Interlocked.Exchange(ref _changeToken, new ConfigurationReloadToken());
                previousToken.OnReload();
            });

        ... 
    }

    private byte[] ComputeHash(string file)
    {
        if (File.Exists(file))
        {
            using (var fs = File.OpenRead(file))
            {
                return System.Security.Cryptography.SHA1.Create().ComputeHash(fs);
            }
        }
        else
        {
            return new byte[20];
        }
    }

    private void DoSomething()
    {
        Console.WriteLine($"********** CONFIG CHANGED! {DateTime.Now}");
    }
}

[EDIT] Also works fine for other files (as long as I don't use VS Code to save/update the file ... VSC seems to lock the file a little bit too long. Notepad seems better about not locking the file long).

ChangeToken.OnChange(
    () => env.ContentRootFileProvider.Watch("file.txt"),

[aspnet-hello]

_From @HaoK on Monday, October 23, 2017 2:09:43 PM_

Computing a hash to prevent extra firing seems reasonable

[aspnet-hello]

_From @akamyshanov on Wednesday, October 25, 2017 6:37:04 AM_

While computing the extra hash does seem like a good idea, experience has shown that issues like file locking or double save are very common and likely to cause problems, at least on Windows systems.

At my company we've come up with this workaround using delayed invocation. The idea is to wait some time before reading the file and restart the timer if another write is detected.

A singleton anti-pattern is used due to the implementation being an extension method.

However, if such an approach is acceptable, I can do a pull request with a cleaner implementation with a CancellationToken inside the monitor itself.

```C#
using System;
using System.Collections.Concurrent;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.Extensions.Options;

namespace ABC.Extensions.Configuration
{
public static class OptionsMonitorExtensions
{
private static readonly ConcurrentDictionary Tokens
= new ConcurrentDictionary();

    private const int DefaultDelay = 1000;

    public static IDisposable OnChangeDelayed<T>(this IOptionsMonitor<T> monitor, Action<T> listener, int delay = DefaultDelay)
    {
        return monitor.OnChangeDelayed(
            (obj, _) => listener(obj),
            delay);
    }

    public static IDisposable OnChangeDelayed<T>(this IOptionsMonitor<T> monitor, Action<T, string> listener, int delay = DefaultDelay)
    {
        return monitor.OnChange((obj, name) => ChangeHandler(monitor, listener, obj, name));
    }

    private static void ChangeHandler<T>(IOptionsMonitor<T> monitor, Action<T, string> listener, T obj, string name)
    {
        var tokenSource = GetCancellationTokenSource(monitor);
        var token = tokenSource.Token;
        var delay = Task.Delay(DefaultDelay, token);

        delay.ContinueWith(
            _ => ListenerInvoker(monitor, listener, obj, name),
            token
            );
    }

    private static CancellationTokenSource GetCancellationTokenSource<T>(IOptionsMonitor<T> monitor)
    {
        return Tokens.AddOrUpdate(monitor, CreateTokenSource, ReplaceTokenSource);
    }

    private static CancellationTokenSource CreateTokenSource(object key)
    {
        return new CancellationTokenSource();
    }

    private static CancellationTokenSource ReplaceTokenSource(object key, CancellationTokenSource existing)
    {
        existing.Cancel();
        existing.Dispose();
        return new CancellationTokenSource();
    }

    private static void ListenerInvoker<T>(IOptionsMonitor<T> monitor, Action<T, string> listener, T obj, string name)
    {
        listener(obj, name);
        if (Tokens.TryRemove(monitor, out var tokenSource))
        {
            tokenSource.Dispose();
        }
    }
}

}
```

[aspnet-hello]

_From @HaoK on Wednesday, October 25, 2017 9:23:01 AM_

@akamyshanov sure go ahead and file a PR in options and we will take a look

[hcoona]

Does we need every user make this hash preventing routine or would fix it later?

[hcoona]

So I wrote a library helps it: https://github.com/hcoona/MicrosoftExtensions.Options.DedupChangeExtensions

[Anupam-]

ChangeToken.OnChange( () => Source.FileProvider.Watch(Source.Path), () => { Thread.Sleep(Source.ReloadDelay); Load(reload: true); });
This solves the issue triggering change event multiple times.
But I have a scenario where I have to write configuration file at startup and just after that I using configuration to instantiate another class as follows

step 1 - pull configuration from the remote source and write to configuration file
step 2 - use above configuration values. (at this point I don't receive the configurations)

[muratg]

We are closing this issue because no further action is planned for this issue. If you still have any issues or questions, please log a new issue with any additional details that you have.

[cocowalla]

@muratg could you say something on _why_ no firther action is needed? It's not great to leave it up to individual devs to solve this - I believe a solution should be built in, perhaps by debouncing the FSW events.

[muratg]

@cocowalla it's been a while, but if I remember correctly, there's no great solution that would solve this without regressing other scenarios. IIRC, best possible solution was going to cause delays for example.

edit: close -> cause :)

[cocowalla]

@muratg not sure what you mean by "going to close delays"?

[guardrex]

going to _cause_ delays

?? I think

Presumably, delays in change token firing. (guessing after a ⏲ looooong time since we were chatting about these issues. lol)

[muratg]

@cocowalla https://github.com/aspnet/AspNetCore/issues/2542#issuecomment-354685749

[cocowalla]

@muratg I'm already debouncing reload events using a much simpler debouncing method, but thanks for the thought :smile:

My main point here is that, as an API consumer, I reasonably expect 1 event to be fired for 1 change, and I shouldn't have to workaround what I (and obviously others) see as a bug.

[muratg]

@cocowalla I'm open to ideas that would solve this cross-platform and consistently without any regressions.

[cocowalla]

@muratg Is it acceptable for there to be a 2-3 second delay between the change being made and the event being raised? I can't see any issues with that myself.

[muratg]

@cocowalla No, I don't think that's an acceptable regression. For some apps, it may be fine, for others, that would be breaking.

[dazinator]

I can't see an issue with an in-built delay personally. I suspect more people will be tripped up by the duplicate signalling, than not having an immediate invocation. Keep in mind, on certain platforms dotnet already relies on polling to detect file changes, so in those situations there is already going to be some potential delay. However if it is a problem to change existing behaviour, why not add the "delayed" version as an optional way to subscribe (or wrap a change token) and then document that so that no one need roll their own api's to work around this issue?
@cocowalla 2-3 seconds seems very long! From my testing, a delay of a few hundred ms was enough to debounce the duplicate signal when saving a change to a javascript file via VS 2017. This begs the question, do we understand the intricacies of this issue - because I certainly don't. Is it just windows? Is it other os's? What should the delay be - does it depend on hardware perf? Does it depend on which editor you use? (I.e is it an editor actually doing a double write / save on a file? Or is it an O/S issue? Runtime issue?)
I am not in a position to answer these questions, i'm just in a position to note the problem when using the API. However a configurable delay seems like a useful general purpose piece of functionality that would be good to have out of the box for IChangeToken's anyway. The link to a suggested workaround provided earlier seemed to be coupled with IOptionsMonitor, but the problem as far as I can tell stems from the IChangeToken returned from IFileProvider.Watch - so the IOptionsMonitor stuff isn't useful when you bypass it and are doing IFileProvider.Watch directly.

[cocowalla]

@muratg I can't personally think of any scenario where it's OK to have a bug that raises duplicate events, yet not OK to have a delay as short as 2-3s before raising a single event as expected, but I guess it's your call 🤷‍♂️

To help others arriving here, here is how I'm working around this bug. It provides a nice extension method so you can do this and it won't raise duplicate events:

config.OnChange(() =>
{
    // TODO: Config has been changed, do stuff here
});

@dazinator TBH, I picked 2-3s for no good reason - it's just as likely that a fraction of a second would be enough in almost all cases. I also agree that a delay is probably useful anyway; even if genuine changes happen in quick succession, you almost certainly only care about the last one. Come to think of it, without this, depending on the logic you use, you might be able to DoS an app by spamming appsettings with changes!

Regarding understanding of the issue, it's partially a general problem with real-time change tracking, and partially a Windows thing (I've done quite a bit of work with minifilter drivers, so I know how complex change detection can be!)

[dazinator]

@cocowalla nice and simple debouncing - thanks for sharing, I'll probably replace my implementation with yours tbh.

[guardrex]

and then document that so that no one need roll their own api's to work around this issue

We discussed this on the issue for the change tokens topic and settled on checking file hashes and an exponential backoff approach.

@muratg We could surface @cocowalla's approach in the topic ... even if only a linking to it as an alternative approach. If we link, I would request that the "and they have no interest in fixing or even receiving a PR" remark be reconsidered ...... unless it's true. :smile:

[cocowalla]

@guardrex hehe, I copy/pasted out of some real code, and forgot to remove that catty comment - I've updated it now 😆

[guardrex]

Thanks. I've gotten to know these cats a little over the past couple of years, and I've concluded that they represent the highest standards of character and disposition in software engineering.

.... except for @blowdart, of course. :trollface: :smile:

If they want to expand (or even revise) the current approach in the change tokens topic, I'll open an issue on the docs repo to take it forward. I'll monitor this discussion to hear if they want to go that way.

[muratg]

@guardrex You mean on the docs? Sure go ahead? :)

(Edit: I'd recommend not linking to his repo, but copying the code as long as @cocowalla is fine with that. Definitely do credit him though!)

BTW, I'm interested in fixing or receiving a PR for this, as long as it doesn't regress other folks' scenarios!

[SidShetye]

FYI, we got hit by this bug even on .net core 3.0. Also in agreement with @dazinator and @cocowalla that most scenarios will be far more willing to accept a delay of 1-2 seconds rather than get hit multiple times for a single change. Configuration changes typically re-init several core components of the app (=>ripple effect), so re-initializing those multiple times in one instant is bad.

Also, please do fix this in the framework rather than hoping every consumer fixes it in their app after debugging, googling and finding this thread.