Hacktoberfest 2026: los issues que los mantenedores marcaron para octubre, abiertos y aptos para principiantes. Explorar issues de Hacktoberfest

API server: creating an Executable hangs 30-45 s (504) while the log storage restarts its parent resource watcher for Executables

Cerrado
  • ¿Algo no está bien?
#286 9 comentarios 0 reacciones 1 asignado Ver en GitHub

Los mantenedores suelen responder en 1 día

@danegsta ya está trabajando en esto.

Desde el 10/10/2026.

Evaluación

Dificultad
4/5
Tiempo estimado
3-5 días
Aptitud para principiantes
45/100
Tipo de issue
Error
Claridad
Bastante claro
Estado de actividad
Activo
Stack tecnológico
go
Área
api, backend

Línea de trabajo

Start in api/v1/log_storage.go, especially the 30-second watcher restart loop, ls.mutex, and stopWatcher. Reproduce or inspect the macOS timing from the attached start-apiserver logs, then determine what Stop waits for and whether a blocked watcher can stall an unrelated Executable create. Done means the blocking behavior is explained and covered by an appropriate regression check.

Escrito por el modelo de indexación a partir del texto del issue.

Descripción

Summary

On GitHub-hosted macOS runners, creating an Executable via the API server hangs until the server's own request timeout (HTTP 504 Timeout: request did not complete within requested timeout - context deadline exceeded). In both occurrences, the log storage's periodic restart of its parent resource watcher for Executable (log_storage.go, every 30 s) was stuck at "Stopping old parent resource watcher…" for the whole time, and only completed when the client (Aspire AppHost) disconnected. We could not reproduce it on Windows, where the same restart completes in the same millisecond.

I don't know the root cause. I'm reporting what the logs show in case it is a known problem or the maintainers can tell what Stop waits for.

Environment
  • DCP 0.26.4 (commit 182c961ce6b2f6b23e785d2963a500d1ed65291d, built 2026-09-24), shipped with Aspire 13.6.0 (Aspire.Hosting.Orchestration.osx-x64)
  • GitHub-hosted macos-15-intel runner (public runners; no nested virtualization), Docker 29.8.2 in a Lima 2.2.0 VM (QEMU software emulation, 2 CPUs, 6 GB) as the container runtime. Everything is very slow there: image pulls take 3+ minutes, MySQL initialization 2-3 more.
  • Client: Aspire AppHost started from DistributedApplicationTestingBuilder (integration tests), DCP_DIAGNOSTICS_LOG_LEVEL=debug
  • Not tested with DCP 0.26.5 (Aspire release/13.6 moved to it in microsoft/aspire#20636, which changes concurrency of same-kind mutations; possibly relevant)
What happens

The Aspire AppHost has a MySQL container, three project services (each waits for its own database in that container) and a web frontend project that waits for the three services, so the frontend's Executable is created some time after the services' executables. The AppHost requests log streams for every executable it observes.

Run A Run B
Services' executables started 11:23:07 12:57:37
First log stream requested for them ~11:23:07 12:57:37
Log storage logs Restarting parent resource watcher… (Kind=Executable) 11:23:37.889 (+30 s) 12:58:07.381 (+30 s)
…Stopping old parent resource watcher… 11:23:37.889 12:58:07.382
Frontend Executable create request sent ~11:23:49 12:58:18
Create fails 11:24:09.9 (client timed out after 20 s; server logged Timeout or abort while handling at 11:24:09.908) 12:58:52.8 (HTTP 504 from the API server, about 34 s after the request)
…Old parent resource watcher stopped 11:24:10.865 (33 s later) 12:58:53.616 (46 s later)
…Creating new parent resource watcher… 11:24:10.866 12:58:53.618

In both runs the "stopped" line appears within about a second of the AppHost tearing down its connections (the Context was canceled, closing log stream / Log streaming for resource completed messages, and in run B the API server switching to CleaningResources at 12:58:53.025). So, for as long as the AppHost kept its connections open, the Stop did not return, and the Executable create was stuck behind it. The controller log has no entry at all for the frontend executable during that window, so the create never got past the API server.

Relevant excerpt (run B, start-apiserver log):

12:58:07.381Z  Restarting parent resource watcher...    Kind=usvc-dev.developer.microsoft.com/v1, Kind=Executable
12:58:07.382Z  Stopping old parent resource watcher...  Kind=usvc-dev.developer.microsoft.com/v1, Kind=Executable
               ... nothing for Kind=Executable ...
12:58:53.616Z  Old parent resource watcher stopped      Kind=usvc-dev.developer.microsoft.com/v1, Kind=Executable

During the same period the restarts for Kind=Container complete immediately (14 times in run B, each Stopping / stopped in the same millisecond).

Where I think it is

api/v1/log_storage.go: the restart loop (watcherRestartInterval = 30 * time.Second) takes ls.mutex, then calls stopWatcher(ls.watcher) before creating the new watcher, and its comment says the stop has to come first to avoid a deadlock between delivering a watch event and creating a new watcher (watch set lock in shared vs. exclusive mode). If Stop waits for the watch set lock while some event delivery is blocked (for example on a slow or non-reading watch/log-stream consumer), the exclusive lock request would also block new shared acquisitions, which could explain why an unrelated Executable create stalls. That is a guess based on reading the code, not something I verified.

Why only macOS CI (probably)

On Windows, with the same AppHost shape, the restart completes in the same millisecond and the frontend is created 6 s later without problems (15:17:26.456 Restarting/Stopping/stopped right after the log streams started at 15:16:56, 30 s earlier). On the GitHub macOS runners the services take 30+ s to become healthy and the machine is heavily loaded, so the frontend create lands inside the window. Of the four macOS runs of this AppHost where the watcher problem in microsoft/aspire#20609 was worked around (so that executables were observed at all), two failed this way and two passed. In both passing runs the frontend was created 8-12 s after the services, before the first restart. In a later CI run, five other AppHosts of the same shape (PostgreSQL, RabbitMQ, Valkey, a service-discovery sample and MySQL again) all created their last project 6-12 s after the first ones, and in all of them the 30 s restart of the Executable watcher completed in the same millisecond. So the failures correlate with the last project being created more than 30 s after the first executable, which happens when the services take longer to become healthy on a loaded runner.

Expected behavior

Stop of the old parent watcher should not block unrelated API operations (creates) on the same kind, or at least not for tens of seconds.

Questions
  • Is this known, and is it possibly addressed by DCP 0.26.5?
  • What does Stop wait for here, and is there a log level or diagnostic switch that would show it?
  • Is a 30 s restart of the parent watcher still needed (the comment says it mitigates missed events)?
Related
  • microsoft/aspire#20609 (Aspire's own watches dying after 60 s; the reason these DCP logs became visible, because executables are only observed now)

I attached the relevant excerpt of the start-apiserver log from run B (dcp-apiserver-excerpt-run-b.log). The complete DCP diagnostic logs (start-apiserver and run-controllers, DCP_DIAGNOSTICS_LOG_LEVEL=debug) for both runs can be provided if useful.

dcp-apiserver-excerpt-run-b.log

Lenguaje dominante
Go
Estrellas
191
Forks
27
Merge medio
2 d 9 h
PR fusionados (30 d)
16

Preparar el entorno

Abrir en Codespaces

Inicia el contenedor de desarrollo del proyecto en tu navegador, con tu propia cuenta de GitHub.

Primeros pasos

  1. Lee el issue completo y luego la guía de contribución del proyecto.
  2. Comenta en el issue que vas a ocuparte — evita que dos personas hagan lo mismo.
  3. Haz un fork del repositorio y trabaja en una rama.
  4. Abre un pull request que haga referencia al número del issue.

Más de microsoft/dcp

Todos los issues de microsoft/dcp

Issues similares

Más issues de Go

Recibe los nuevos issues en tu correo

Un resumen breve de issues de GitHub para principiantes.