Restarting containers using docker file fails

[davidfowl]

var builder = DistributedApplication.CreateBuilder(args);

var db = builder.AddMongoDB("mongo")
                .AddDatabase("db");

builder.AddDockerfile("api", "node")
       .WithHttpEndpoint(targetPort: 3000, env: "PORT")
       .WithReference(db);

builder.Build().Run();

Here's what happens:
https://github.com/user-attachments/assets/04c3b6c9-78b0-4f38-a701-26eea0f39df4

Here's the console output:

Additional information: Stop and Start seem to work.

[mitchdenny]

Just as a diagnostic (wasn't clear from the video) - but had the container started by the time you pressed Restart? I've noticed sometimes there can be a bit of a delay between the container build completing and the container actually running.

[davidfowl]

It was running yep.

[mitchdenny]

I'm able to repro with Stop then Start too (on main).

[mitchdenny]

OK so I added some extra logging to the start/stop logic:

#6395

What I'm seeing based on my logging changes is this output.

warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Starting delete of resource.
info: Aspire.Hosting.Dcp.dcpctrl.ContainerReconciler[0]
      no more Container resources are being watched, cancelling container watch {"Container": {"name":"mycontainer-pjuuytar"}, "Reconciliation": 20}
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Completed delete of resource.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Getting resource.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Resource got!.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Getting resource.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Resource got!.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Getting resource.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Resource got!.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Getting resource.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Resource got!.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Getting resource.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Resource got!.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Getting resource.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Resource got!. <------ it gave up trying to start here because the resource still existed.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Starting delete of resource.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Completed delete of resource.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Getting resource.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Resource got!.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Getting resource.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Resource got!.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Getting resource.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Resource not found.
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Creating
warn: Aspire.Hosting.Dcp.ApplicationExecutor[0]
      Created! <---- second time worked.

What I think is happening is that it is taking a long time for Docker to stop the container (or for DCP to notice).

[mitchdenny]

@danegsta could use your input on this one. @davidfowl if you checkout my branch from the PR above do you see similar symptoms. I'm particularly interested in the time it takes between pressing Stop and for it to appear stopped in the portal.

It's possible I've got some local performance issues, but I haven't done much exotic to my machine other than keep up with updates.

[karolz-ms]

Using playground/withdockerfile project the restart mostly works, but occasionally I get the container to end up in "Exited" state with the following in the logs

2024-10-21T12:13:28
 Error executing command 'resource-restart'.
k8s.Autorest.HttpOperationException: Operation returned an invalid status code 'Conflict', response body {"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"Operation cannot be fulfilled on containers.usvc-dev.developer.microsoft.com \"mycontainer-vysqcupt\": the object has been modified; please apply your changes to the latest version and try again","reason":"Conflict","details":{"name":"mycontainer-vysqcupt","group":"usvc-dev.developer.microsoft.com","kind":"containers"},"code":409}

   at k8s.Kubernetes.SendRequestRaw(String requestContent, HttpRequestMessage httpRequest, CancellationToken cancellationToken)
   at k8s.AbstractKubernetes.ICustomObjectsOperations_DeleteClusterCustomObjectWithHttpMessagesAsync[T](String group, String version, String plural, String name, V1DeleteOptions body, Nullable`1 gracePeriodSeconds, Nullable`1 orphanDependents, String propagationPolicy, String dryRun, IReadOnlyDictionary`2 customHeaders, CancellationToken cancellationToken)
   at k8s.AbstractKubernetes.k8s.ICustomObjectsOperations.DeleteClusterCustomObjectWithHttpMessagesAsync(String group, String version, String plural, String name, V1DeleteOptions body, Nullable`1 gracePeriodSeconds, Nullable`1 orphanDependents, String propagationPolicy, String dryRun, IReadOnlyDictionary`2 customHeaders, CancellationToken cancellationToken)
   at Aspire.Hosting.Dcp.KubernetesService.<>c__DisplayClass19_0`1.<<DeleteAsync>b__0>d.MoveNext() in C:\code\aspire\src\Aspire.Hosting\Dcp\KubernetesService.cs:line 202
--- End of stack trace from previous location ---
   at Aspire.Hosting.Dcp.KubernetesService.ExecuteWithRetry[TResult](DcpApiOperationType operationType, String resourceType, Func`2 operation, CancellationToken cancellationToken) in C:\code\aspire\src\Aspire.Hosting\Dcp\KubernetesService.cs:line 345
   at Aspire.Hosting.Dcp.ApplicationExecutor.<>c__DisplayClass81_0.<<StartResourceAsync>g__StartExecutableOrContainerAsync|0>d`1.MoveNext() in C:\code\aspire\src\Aspire.Hosting\Dcp\ApplicationExecutor.cs:line 2080
--- End of stack trace from previous location ---
   at Aspire.Hosting.Dcp.ApplicationExecutor.StartResourceAsync(String resourceName, CancellationToken cancellationToken) in C:\code\aspire\src\Aspire.Hosting\Dcp\ApplicationExecutor.cs:line 2057
   at Aspire.Hosting.ApplicationModel.CommandsConfigurationExtensions.<>c.<<AddLifeCycleCommands>b__3_5>d.MoveNext() in C:\code\aspire\src\Aspire.Hosting\ApplicationModel\CommandsConfigurationExtensions.cs:line 94
--- End of stack trace from previous location ---
   at Aspire.Hosting.Dashboard.DashboardCommandExecutor.ExecuteCommandAsync(String resourceId, ResourceCommandAnnotation annotation, CancellationToken cancellationToken) in C:\code\aspire\src\Aspire.Hosting\Dashboard\DashboardCommandExecutor.cs:line 31
   at Aspire.Hosting.Dashboard.DashboardServiceData.ExecuteCommandAsync(String resourceId, String type, CancellationToken cancellationToken) in C:\code\aspire\src\Aspire.Hosting\Dashboard\DashboardServiceData.cs:line 123

[davidfowl]

@karolz-ms can you take this one?

[karolz-ms]

OK so I believe the error @mitchdenny saw and the "conflict" error that I saw are symptoms of the same underlying issue. We have code in ApplicationExecutor that starts a Container/Executable. That code will delete the resource if it exists: https://github.com/dotnet/aspire/blob/main/src/Aspire.Hosting/Dcp/ApplicationExecutor.cs#L2072 and it will poll DCP to ensure that the resource is really gone before trying to create it again.

This is all good; the problem is this code is giving up on the wait way to soon. Both container graceful stop, and Executable graceful shutdown can take 10+ seconds. During that time the corresponding DCP object will be still present/pending.

[karolz-ms]

@karolz-ms can you take this one?

Yep, will submit a PR

[davidfowl]

@karolz-ms instead of polling can we use Watch?