MonitorEventsAsync Progress Action is one event behind

kosimas commented 9 months ago

Output of dotnet --info:

.NET SDK:
 Version:           8.0.100
 Commit:            57efcf1350
 Workload version:  8.0.100-manifests.6a1e483a

Runtime Environment:
 OS Name:     Windows
 OS Version:  10.0.22621
 OS Platform: Windows
 RID:         win-x64
 Base Path:   C:\Program Files\dotnet\sdk\8.0.100\

.NET workloads installed:
 Workload version: 8.0.100-manifests.6a1e483a
There are no installed workloads to display.

Host:
  Version:      8.0.0
  Architecture: x64
  Commit:       5535e31a71

.NET SDKs installed:
  6.0.320 [C:\Program Files\dotnet\sdk]
  6.0.417 [C:\Program Files\dotnet\sdk]
  7.0.404 [C:\Program Files\dotnet\sdk]
  8.0.100 [C:\Program Files\dotnet\sdk]

.NET runtimes installed:
  Microsoft.AspNetCore.App 6.0.25 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 7.0.14 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.AspNetCore.App 8.0.0 [C:\Program Files\dotnet\shared\Microsoft.AspNetCore.App]
  Microsoft.NETCore.App 3.1.32 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 5.0.17 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 6.0.25 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 7.0.14 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.NETCore.App 8.0.0 [C:\Program Files\dotnet\shared\Microsoft.NETCore.App]
  Microsoft.WindowsDesktop.App 3.1.32 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 5.0.17 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 6.0.25 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 7.0.14 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]
  Microsoft.WindowsDesktop.App 8.0.0 [C:\Program Files\dotnet\shared\Microsoft.WindowsDesktop.App]

Other architectures found:
  x86   [C:\Program Files (x86)\dotnet]
    registered at [HKLM\SOFTWARE\dotnet\Setup\InstalledVersions\x86\InstallLocation]

Environment variables:
  Not set

global.json file:
  Not found

Learn more:
  https://aka.ms/dotnet/info

Download .NET:
  https://aka.ms/dotnet/download

What version of Docker.DotNet?:

3.125.15

Steps to reproduce the issue:

Create a Console Application.
Install Docker.DotNet via NuGet.

Replace the Program class in Program.cs with the following code

internal class Program
{
static int Main(string[] args)
{
    var dockerClient = new DockerClientConfiguration()
        .CreateClient();

    if (dockerClient == null)
        return 1;

    var eventParameters = new ContainerEventsParameters
    {
        Filters = new Dictionary<string, IDictionary<string, bool>>
        {
            {
                "event", new Dictionary<string, bool>
                {
                    { "start", true },
                    { "stop", true },
                }

            },
            {
                "type", new Dictionary<string, bool>
                {
                    { "container", true }
                }
            }
        }
    };

    var progress = new Progress<Message>(response =>
    {
        Console.WriteLine($"Docker Event {response.Action} fired for {response.ID}.");
    });

    dockerClient.System.MonitorEventsAsync(
        parameters: eventParameters,
        progress: (IProgress<Message>)progress,
        cancellationToken: CancellationToken.None
    ).Wait();

    Console.ReadKey();

    return 0;
}
}

Start the program and start and stop some container a few times.

What actually happened?: The first time an container has been stopped or started, nothing happens. The second time container gets stopped or started, the Progress Action gets executed with the response message from the event before that event. So if you stopped an container at first and started it in the second step, the program will log Docker Event stop fired for <your_container_id>.

What did you expect to happen?: I would expect that when the first event gets triggered, the Progress Action gets executed for that event and not the event that happened before that event.

Additional information: I think this issue can be considered related: https://github.com/dotnet/Docker.DotNet/issues/576

kosimas commented 9 months ago

I cloned the repository and created a unit test method for this case in the ISystemOperationsTests class.

[Fact]
public async Task MonitorEventsFiltered_Container_StartStop()
{
    var createContainerResponse = await _dockerClient.Containers.CreateContainerAsync(
        new CreateContainerParameters
        {
            Image = $"{_repositoryName}:{_tag}"
        }
    );

    var eventParameters = new ContainerEventsParameters
    {
        Filters = new Dictionary<string, IDictionary<string, bool>>
        {
            {
                "event", new Dictionary<string, bool>
                {
                    { "start", true },
                    { "stop", true },
                }

            },
            {
                "type", new Dictionary<string, bool>
                {
                    { "container", true }
                }
            },
            {
                "container", new Dictionary<string, bool>
                {
                    { createContainerResponse.ID, true },
                }
            }
        }
    };

    var i = 0;
    var eventProgress = new Progress<Message>((message) =>
    {
        Assert.Equal(createContainerResponse.ID, message.ID);
        _output.WriteLine($"Container {createContainerResponse.ID} event: {message.Action}");
        if (i == 0)
        {
            Assert.Equal("start", message.Action);
            i++;
        }
        else if (i == 1)
        {
            Assert.Equal("stop", message.Action);
        }
    });

    using var cts = CancellationTokenSource.CreateLinkedTokenSource(_cts.Token);

    var task = Task.Run(() => _dockerClient.System.MonitorEventsAsync(eventParameters, eventProgress, cts.Token));

    await Task.Delay(TimeSpan.FromSeconds(3));
    await _dockerClient.Containers.StartContainerAsync(createContainerResponse.ID, new ContainerStartParameters());

    await Task.Delay(TimeSpan.FromSeconds(3));
    await _dockerClient.Containers.StopContainerAsync(createContainerResponse.ID, new ContainerStopParameters());
    await _dockerClient.Containers.RemoveContainerAsync(createContainerResponse.ID, new ContainerRemoveParameters(), cts.Token);

    await Task.Delay(TimeSpan.FromSeconds(1));
    cts.Cancel();

    Assert.Equal(1, i);
    Assert.True(task.IsCanceled);
}

The test will pass without any problems. Maybe the problem is caused by an Docker Engine API mismatch? I'm not sure about this. I'm using Docker Desktop 4.25.2 on an Windows 11 machine. I tested it(in the console app not in the unit test) with an npipe connection and I also tried enabling the tcp daemon. The results with the tcp daemon are the same as with an npipe connection.

noelex commented 9 months ago

I've encountered the same issue. I guess it's caused by the JSON deserializer's internal buffering. It works fine with the following workaround:

async Task MonitorEventsAsync(IDockerClient client, IProgress<Message> progress, CancellationToken cancellationToken)
{
    using var stream = await client.System.MonitorEventsAsync(new ContainerEventsParameters(), cancellationToken);
    using var reader = new StreamReader(stream, Encoding.UTF8, false);
    while (!cancellationToken.IsCancellationRequested)
    {
        var line = await reader.ReadLineAsync(cancellationToken);
        if (line is null) break;
        var msg = System.Text.Json.JsonSerializer.Deserialize<Message>(line);
        if (msg is null) continue;
        progress.Report(msg);
    }
}

kosimas commented 9 months ago

I've encountered the same issue. I guess it's caused by the JSON deserializer's internal buffering. It works fine with the following workaround:

async Task MonitorEventsAsync(IDockerClient client, IProgress<Message> progress, CancellationToken cancellationToken)
{
    using var stream = await client.System.MonitorEventsAsync(new ContainerEventsParameters(), cancellationToken);
    using var reader = new StreamReader(stream, Encoding.UTF8, false);
    while (!cancellationToken.IsCancellationRequested)
    {
        var line = await reader.ReadLineAsync(cancellationToken);
        if (line is null) break;
        var msg = System.Text.Json.JsonSerializer.Deserialize<Message>(line);
        if (msg is null) continue;
        progress.Report(msg);
    }
}

Your method works definitely better then the Docker.DotNet MonitorEventsAsync method. However if I change the Filters to the code below below, your method is reporting nothing anymore. This leads me to think that even the Obsolete MonitorEventsAsync method has its flaws.

var eventParameters = new ContainerEventsParameters
{
    Filters = new Dictionary<string, IDictionary<string, bool>>
    {
        {
            "event", new Dictionary<string, bool>
            {
                { "start", true },
                { "stop", true },
                { "destroy", true },
                { "create", true },
            }

        },
        {
            "type", new Dictionary<string, bool>
            {
                { "containers", true },
            }
        },
    }
};

Running this in the terminal reports everything as it should be docker events --filter 'type=container' --filter 'event=start' --filter 'event=stop' --filter 'event=create' --filter 'event=destroy' --format 'Type={{.Type}} Status={{.Status}} ID={{.ID}}'

kosimas commented 9 months ago

I stumbled upon this comment https://github.com/dotnet/Docker.DotNet/issues/653#issuecomment-1744948138 This is an important information for this issue I think.

noelex commented 9 months ago

You have a typo in your filters. The type should be container not containers.

kosimas commented 9 months ago

Your right! Be careful when renaming variables with the vs2022 shortcut :)

dotnet / Docker.DotNet

MonitorEventsAsync Progress Action is one event behind #663