Resource cleanup misses fast deletions between informer LIST and WATCH and times out with no remaining objects
I maintainer di solito rispondono entro 1 giorno
Nessuno ha ancora preso questa issue.
Valutazione
- Difficoltà
- 4/5
- Tempo stimato
- 3-5 giorni
- Idoneità per principianti
- 42/100
Direzione di ricerca
Read internal/appmgmt/shutdown.go, focusing on cleanupResource, its informer callbacks, and cache synchronization. Reproduce the LIST/WATCH timing gap with the PowerShell script in the issue, then inspect how cleanup tracks remaining resources and handles cache.DeletedFinalStateUnknown. Done means cleanup completes when all resources are actually gone, with a regression covering delayed WATCH registration and without reporting success when objects remain.
Scritto dal modello di indicizzazione a partire dal testo della issue.
Descrizione
Failure
Native resource cleanup can time out even after every Service object and proxy has been removed. Reproduced on Windows with DCP 0.26.6, commit 6096b60432a281962920b8c7d2e9cba20118b750. This is not a claim that this version introduced the defect.
Deterministic standalone reproduction
The script below starts its own native apiserver and five standalone TCP Service objects. It redirects only the new cleanup clients through a local reverse proxy that delays the Service WATCH request by two seconds; existing controllers keep their original direct connection. LIST and DELETE requests proceed normally. This makes the existing LIST/WATCH race deterministic without changing the native two-minute cleanup budget. Docker must be running for normal native controller startup. No application framework or test framework is involved.
Run on Windows with PowerShell 7, Python 3, kubectl, and a DCP executable. Save the script under a directory without spaces, for example C:/dcp-repro/repro.ps1, then run:
pwsh -File C:/dcp-repro/repro.ps1 -DcpPath C:/tools/dcp/dcp.exe
The evidence directory includes temporary kubeconfig credentials; do not publish those files. The script does not print credentials. It only stops the proxy it starts; DCP monitors the script process and shuts down if the script exits.
Standalone reproduction script
param(
[Parameter(Mandatory)][string]$DcpPath,
[string]$PythonPath = 'python',
[string]$EvidenceDirectory = (Join-Path $PSScriptRoot 'runs')
)
$ErrorActionPreference='Stop'
$runPath=Join-Path $EvidenceDirectory ('native-delay-watch-'+[Guid]::NewGuid().ToString('N'))
New-Item -ItemType Directory $runPath | Out-Null
$env:DCP_DIAGNOSTICS_LOG_FOLDER=$runPath
$env:DCP_DIAGNOSTICS_LOG_LEVEL='debug'
$kubeconfigPath=Join-Path $runPath 'kubeconfig'
$native=Start-Process -FilePath $DcpPath -ArgumentList @('start-apiserver','--monitor', $PID, '--kubeconfig', $kubeconfigPath) -WindowStyle Hidden -PassThru -RedirectStandardOutput (Join-Path $runPath 'stdout.log') -RedirectStandardError (Join-Path $runPath 'stderr.log')
Write-Output "Native PID=$($native.Id) evidence=$runPath"
try {
$deadline=[DateTime]::UtcNow.AddSeconds(20)
while (!(Test-Path $kubeconfigPath)) { if ([DateTime]::UtcNow -gt $deadline) { throw 'Native startup did not produce kubeconfig' }; Start-Sleep -Milliseconds 100 }
$services=@{apiVersion='usvc-dev.developer.microsoft.com/v1';kind='ServiceList';items=@(1..5 | ForEach-Object { @{apiVersion='usvc-dev.developer.microsoft.com/v1';kind='Service';metadata=@{name="probe-$_"};spec=@{protocol='TCP';addressAllocationMode='Localhost'}}})} | ConvertTo-Json -Depth 9
$services | kubectl --kubeconfig $kubeconfigPath create -f -
if ($LASTEXITCODE -ne 0) { throw 'Service creation failed' }
kubectl --kubeconfig $kubeconfigPath wait services.usvc-dev.developer.microsoft.com --all --for=jsonpath='{.metadata.finalizers}' --timeout=20s
if ($LASTEXITCODE -ne 0) { throw 'Service startup failed' }
$server=((Get-Content $kubeconfigPath | Select-String '^ server: ').Line -replace '^ server: ','')
$token=((Get-Content $kubeconfigPath | Select-String '^ token: ').Line -replace '^ token: ','')
$originalKubeconfigPath=Join-Path $runPath 'original-kubeconfig'
Copy-Item $kubeconfigPath $originalKubeconfigPath
$proxyPortPath=Join-Path $runPath 'proxy-port.txt'
$proxyLogPath=Join-Path $runPath 'proxy.log'
$proxyScript=Join-Path $runPath 'delay-watch-proxy.py'
@'
import http.client
import http.server
import ssl
import sys
import threading
import time
import urllib.parse
upstream = urllib.parse.urlparse(sys.argv[1])
log_path = sys.argv[3]
log_lock = threading.Lock()
with open(sys.argv[4], encoding='utf-8-sig') as stream:
token = next(line.strip().removeprefix('token: ') for line in stream if line.strip().startswith('token: '))
def log(value):
with log_lock:
with open(log_path, 'a', encoding='utf-8') as stream:
stream.write(f'{time.time():.6f} {value}\n')
class Proxy(http.server.BaseHTTPRequestHandler):
protocol_version = 'HTTP/1.1'
def do_GET(self): self.forward()
def do_DELETE(self): self.forward()
def do_PATCH(self): self.forward()
def do_POST(self): self.forward()
def do_PUT(self): self.forward()
def log_message(self, *args): pass
def forward(self):
params = urllib.parse.parse_qs(urllib.parse.urlparse(self.path).query)
watch = self.path.startswith('/apis/usvc-dev.developer.microsoft.com/v1/services?') and params.get('watch') == ['true']
log(f'{self.command} {self.path} delay={watch}')
if watch:
time.sleep(2)
log(f'forward delayed watch {self.path}')
length = int(self.headers.get('Content-Length', 0))
body = self.rfile.read(length) if length else None
headers = {key: value for key, value in self.headers.items() if key.lower() not in ['host', 'connection', 'accept-encoding']}
headers['Authorization'] = 'Bearer ' + token
connection = http.client.HTTPSConnection(upstream.hostname, upstream.port, context=ssl._create_unverified_context(), timeout=180)
try:
connection.request(self.command, self.path, body, headers)
response = connection.getresponse()
log(f'{self.command} {self.path} response={response.status}')
self.send_response(response.status)
for key, value in response.getheaders():
if key.lower() not in ['connection', 'transfer-encoding']:
self.send_header(key, value)
self.send_header('Connection', 'close')
self.end_headers()
while chunk := response.read1(65536):
self.wfile.write(chunk)
self.wfile.flush()
except (BrokenPipeError, ConnectionResetError, TimeoutError, ssl.SSLError) as error:
log(f'{self.command} {self.path} transport={type(error).__name__}')
finally:
self.close_connection = True
connection.close()
server = http.server.ThreadingHTTPServer(('127.0.0.1', 0), Proxy)
server.daemon_threads = True
with open(sys.argv[2], 'w', encoding='utf-8') as stream:
stream.write(str(server.server_port))
server.serve_forever()
'@ | Set-Content $proxyScript
$proxy=Start-Process -FilePath $PythonPath -ArgumentList @($proxyScript,$server,$proxyPortPath,$proxyLogPath,$originalKubeconfigPath) -WindowStyle Hidden -PassThru -RedirectStandardOutput (Join-Path $runPath 'proxy-stdout.log') -RedirectStandardError (Join-Path $runPath 'proxy-stderr.log')
while (!(Test-Path $proxyPortPath)) { Start-Sleep -Milliseconds 50 }
$proxyPort=Get-Content $proxyPortPath -Raw
(Get-Content $kubeconfigPath -Raw).Replace($server,"http://127.0.0.1:$proxyPort") | Set-Content $kubeconfigPath
$headers=@{}; if ($token) { $headers.Authorization="Bearer $token" }
Invoke-RestMethod "$server/admin/execution" -Method Patch -ContentType 'application/merge-patch+json' -Body '{"status":"CleaningResources","shutdownResourceCleanup":"Full"}' -SkipCertificateCheck -Headers $headers | Select-Object status,shutdownResourceCleanup | ConvertTo-Json -Compress
$deadline=[DateTime]::UtcNow.AddSeconds(140)
do {
$state=Invoke-RestMethod "$server/admin/execution" -SkipCertificateCheck -Headers $headers
$objects=kubectl --kubeconfig $originalKubeconfigPath get services.usvc-dev.developer.microsoft.com -o json --request-timeout=3s | ConvertFrom-Json
@{time=[DateTimeOffset]::UtcNow.ToString('O');status=$state.status;count=@($objects.items).Count;items=@($objects.items | ForEach-Object { @{name=$_.metadata.name;finalizers=$_.metadata.finalizers;deletionTimestamp=$_.metadata.deletionTimestamp}})} | ConvertTo-Json -Compress -Depth 7 | Add-Content (Join-Path $runPath 'state.ndjson')
if ($state.status -eq 'CleanupComplete') { break }
Start-Sleep -Seconds 1
} while ([DateTime]::UtcNow -lt $deadline)
Invoke-RestMethod "$server/admin/execution" -Method Patch -ContentType 'application/merge-patch+json' -Body '{"status":"Stopping","shutdownResourceCleanup":"Full"}' -SkipCertificateCheck -Headers $headers | Out-Null
$native.WaitForExit(10000) | Out-Null
Write-Output "Native exited=$($native.HasExited) exit=$($native.ExitCode) state=$($state.status) objects=$(@($objects.items).Count)"
} finally {
if ($proxy -and !$proxy.HasExited) { Stop-Process -Id $proxy.Id }
if (!$native.HasExited) { Write-Output "Owned process still running PID=$($native.Id); monitor will stop it at script exit" }
}
Observed behavior
In the delayed-watch run:
- 05:29:07.805 UTC: cleanup Service LIST returns five objects and starts a WATCH request that the proxy delays.
- By 05:29:07.916: all five DELETE requests return successfully. Controllers remove their finalizers and delete the objects.
- 05:29:09.813: the delayed WATCH reaches the API server. The objects have already disappeared.
- Direct API snapshots show
items: [], count zero, while/admin/executionremainsCleaningResources. - Native cleanup reports
InitialCount: 5but never reports a ServiceObject deletedcallback. Cleanup begins at 05:29:05.716 UTC, reaches its unchanged two-minute deadline at 05:31:05.720 withcontext deadline exceeded, and the native process exits code 1 at 05:31:06.145. All actual Service objects remain absent.
Without the delayed watch, the five-Service control run completes with CleanupComplete, zero objects, and native exit code 0. The two-second delay is a scheduling perturbation, not an application dependency failure.
Source mechanism
In internal/appmgmt/shutdown.go, cleanupResource increments resourceCount in the informer's AddFunc, then closes cacheSyncDone after factory.WaitForCacheSync. That cache synchronization does not establish the subsequent WATCH connection. Closing the channel lets deletion goroutines remove fast resources before the WATCH is registered. Successful DELETE completion only decrements the count through DeleteFunc.
Tilt filepath storage's Watch implementation initializes from objects that currently exist and does not replay deleted events from the earlier LIST's resourceVersion. A deletion in this gap therefore leaves cleanup's counter positive forever. In addition, DeleteFunc casts directly to client.Object and ignores cache.DeletedFinalStateUnknown, preventing a later relist from repairing that missing deletion through a tombstone.
Current DCP main still has this cleanup implementation. I have not run this reproduction against DCP 0.27.2, so this report only claims binary reproduction on 0.26.6.
Expected correction
Cleanup must determine completion from authoritative remaining resource state, without assuming that every successful DELETE will produce an observed deletion event. A missed watch event must not cause a false leak/timeout. Handle informer tombstones if retaining that observation path, and add a regression that delays WATCH registration while allowing deletion to finish. Preserve the existing cleanup budget and error visibility; do not force-remove finalizers or treat actual remaining objects as success.
- Lingua principale
- Go
- Stelle
- 192
- Fork
- 27
- Merge medio
- 2g 2h
- PR unite (30g)
- 30
Preparare l'ambiente
Avvia il container di sviluppo del progetto nel browser, con il tuo account GitHub.
- Nessun Dockerfile né file Docker Compose
- Nessun modello di pull request
- Leggi la guida per i contributori
Come iniziare
- Leggi tutta la issue e poi la guida ai contributi del progetto.
- Commenta sulla issue per dire che te ne occupi tu — evita che due persone facciano lo stesso lavoro.
- Fai un fork del repository e lavora su un branch.
- Apri una pull request che faccia riferimento al numero della issue.
Altre issue di microsoft/dcp
-
Difficoltà 2/5 1-3 ore Idoneità per principianti 75/100
I maintainer di solito rispondono entro 1 giorno
-
ContainerVolume stuck in PendingForse già presa Una pull request collegata a questa issue è aperta o già unita. Aperta
Difficoltà 2/5 1-3 ore Idoneità per principianti 76/100
I maintainer di solito rispondono entro 1 giorno
-
Add application iconAperta
Difficoltà 2/5 1-3 ore Idoneità per principianti 72/100
I maintainer di solito rispondono entro 1 giorno
-
Difficoltà 4/5 3-5 giorni Idoneità per principianti 45/100
I maintainer di solito rispondono entro 1 giorno
-
Difficoltà 4/5 3-5 giorni Idoneità per principianti 52/100
I maintainer di solito rispondono entro 1 giorno
Tutte le issue di microsoft/dcp
Issue simili
-
bug from-studio
Difficoltà 2/5 1-3 ore Idoneità per principianti 65/100
esengine/DeepSeek-Reasonix#14868 ·
I maintainer di solito rispondono entro 1 giorno
-
Difficoltà 2/5 1-3 ore Idoneità per principianti 80/100
project-zot/zot#4636 ·
I maintainer di solito rispondono entro 1 giorno
-
Difficoltà 2/5 1-3 ore Idoneità per principianti 76/100
keyxmakerx/Chronicle#1911 ·
I maintainer di solito rispondono entro 1 giorno
-
Difficoltà 2/5 1-3 ore Idoneità per principianti 68/100
eugenioenko/ttt#1293 · 1 commento · 1 reazione ·
I maintainer di solito rispondono entro 1 giorno
-
needs/area needs/kind needs/priority
Difficoltà 2/5 1-3 ore Idoneità per principianti 80/100
I maintainer di solito rispondono entro 1 giorno