ALOpsAppCompiler: 5-Minute Delay Between Docker Registry Login on Azure Container Registry and Image Pull? #913
Description
We are encountering a significant delay of approximately 5 minutes between logging into the Docker registry and the start of the image pulling process. The detailed environment and setup are as follows:
- Platform Used: Azure Container Registry (ACR) with Premium SKU, Germany West Central
- Server Configuration:
- Operating System: Windows Server 2019
- VM Specs: 4 CPU cores, 16 GB RAM
- Storage: Average read/write performance (HPE Alletra Storage)
- Hosting Environment: VM on VMware in Hetzner Colocation, Nuermberg, Germany with 1 Gbps shared uplink
Observations:
- The
docker logincommand reports a successful login immediately. - Even with this success, there is a delay of about 5 minutes before starting to pull the image.
Key Questions:
- What happens during this delay between login and the initiation of the image pull (e.g., internal ACR tasks, validations, throttling)?
- Are there any diagnostics, configurations, or performance insights available to help understand or address this latency?
Logs:
The relevant logs from the process are provided below for context:
2025-12-22T06:16:58.3987640Z *** Login into docker: ***.azurecr.io
2025-12-22T06:16:58.5115623Z Login Succeeded
2025-12-22T06:21:22.6944613Z sandbox-27.3.43787.0-w1-ltsc2019: Pulling from cronus
2025-12-22T06:21:22.7118485Z *** Pull Docker Image: ***.azurecr.io/cronus:sandbox-27.3.43787.0-w1-ltsc2019 [OK]
The logs show that the image pull begins only after this unexplained 5-minute delay. Any insights or recommendations to reduce this delay would be greatly appreciated.
These 4-5 minutes are also very consistent for different images:
Full Log:
2025-12-22T06:16:54.3842853Z ##[section]Starting: ALOps Docker Create W1 SaaS
2025-12-22T06:16:54.3863814Z ==============================================================================
2025-12-22T06:16:54.3863922Z Task : ALOps Docker Create
2025-12-22T06:16:54.3863969Z Description : Create Docker image from Business Central Artifacts
2025-12-22T06:16:54.3864041Z Version : 1.473.9825
2025-12-22T06:16:54.3864087Z Author : Hodor
2025-12-22T06:16:54.3864140Z Help : Create Docker image based on NAV/BC Artifacts.
2025-12-22T06:16:54.3864192Z ==============================================================================
2025-12-22T06:16:54.9809489Z *** Validate configuration
2025-12-22T06:16:55.1203072Z *** Task Inputs:
2025-12-22T06:16:55.1251628Z
2025-12-22T06:16:55.1356229Z name value
2025-12-22T06:16:55.1356704Z ---- -----
2025-12-22T06:16:55.1357314Z artifactspecification Specific
2025-12-22T06:16:55.1357853Z artifactversion
2025-12-22T06:16:55.1358633Z artifacttype Sandbox
2025-12-22T06:16:55.1359219Z artifactcountry w1
2025-12-22T06:16:55.1360025Z versionselect Latest
2025-12-22T06:16:55.1360655Z artifacthint
2025-12-22T06:16:55.1361299Z multitenant False
2025-12-22T06:16:55.1361940Z memory 8G
2025-12-22T06:16:55.1362614Z imageprefix cronus
2025-12-22T06:16:55.1363286Z dockerregistry ***.azurecr.io
2025-12-22T06:16:55.1363888Z dockerusername ***
2025-12-22T06:16:55.1364682Z dockerpassword ***
2025-12-22T06:16:55.1365198Z storageaccount
2025-12-22T06:16:55.1365887Z sastoken
2025-12-22T06:16:55.1366592Z forcecreateimage False
2025-12-22T06:16:55.1367221Z myscripts
2025-12-22T06:16:55.1367899Z imagenametemplate %IMAGE_PREFIX%:%ARTIFACT_TYPE%-%ARTIFACT_VERSION%-%ARTIFACT_COUNTRY%-%OS_VERSION%-%OS_LTSC%
2025-12-22T06:16:55.1368463Z use_generic_image
2025-12-22T06:16:55.1369067Z licensefile
2025-12-22T06:16:55.1369731Z includetesttoolkit True
2025-12-22T06:16:55.1370247Z includetestlibrariesonly False
2025-12-22T06:16:55.1371664Z includetestframeworkonly False
2025-12-22T06:16:55.1371785Z includeperformancetoolkit False
2025-12-22T06:16:55.1372633Z accept_insider_eula False
2025-12-22T06:16:55.1374230Z alternativeartifacturl https://bcinsider-fvh2ekdjecfjd6gk.b02.azurefd.net/sandbox/27.3.43787.0/w1
2025-12-22T06:16:55.1374552Z
2025-12-22T06:16:55.1389543Z
2025-12-22T06:16:55.1396359Z
2025-12-22T06:16:55.1555824Z True
2025-12-22T06:16:55.1677597Z *** For documentation, please visit : https://www.alops.be/documentation
2025-12-22T06:16:55.5500406Z
2025-12-22T06:16:55.5618689Z *** Importing required PS-Functions
2025-12-22T06:16:55.5856768Z *** Install/Update BCContainerHelper [https://github.com/microsoft/navcontainerhelper]
2025-12-22T06:16:55.5927169Z *** Check BcContainerHelper
2025-12-22T06:16:55.6746893Z *** Load BcContainerHelper
2025-12-22T06:16:55.7337023Z BcContainerHelper version 6.1.10
2025-12-22T06:16:56.0645498Z BC.HelperFunctions emits usage statistics telemetry to Microsoft
2025-12-22T06:16:56.1770542Z Running on Windows, PowerShell 5.1.17763.8146
2025-12-22T06:16:57.2298344Z
2025-12-22T06:16:57.2298958Z ModuleType Version Name ExportedCommands
2025-12-22T06:16:57.2299198Z ---------- ------- ---- ----------------
2025-12-22T06:16:57.2299645Z Script 6.1.10 BcContainerHelper {Add-FontsToBcContainer, Add-GitToAlProjectFolder, AddTele...
2025-12-22T06:16:57.2300178Z
2025-12-22T06:16:57.2300379Z
2025-12-22T06:16:57.2300511Z
2025-12-22T06:16:57.2303123Z
2025-12-22T06:16:57.2373428Z *** Overwrite BC-Artifact-Url [https://bcinsider-fvh2ekdjecfjd6gk.b02.azurefd.net/sandbox/27.3.43787.0/w1]
2025-12-22T06:16:57.2380877Z *** Artifact Url: [https://bcinsider-fvh2ekdjecfjd6gk.b02.azurefd.net/sandbox/27.3.43787.0/w1]
2025-12-22T06:16:57.2387325Z *** Build new Image based on [https://bcinsider-fvh2ekdjecfjd6gk.b02.azurefd.net/sandbox/27.3.43787.0/w1]
2025-12-22T06:16:57.2432582Z *** Artifact Type : [sandbox]
2025-12-22T06:16:57.2437711Z *** Artifact Version: [27.3.43787.0]
2025-12-22T06:16:57.2442670Z *** Artifact Country: [w1]
2025-12-22T06:16:57.3356386Z *** OS: [2019]
2025-12-22T06:16:58.3398761Z *** OS version: [ltsc2019]
2025-12-22T06:16:58.3406007Z *** Image Template: [%IMAGE_PREFIX%:%ARTIFACT_TYPE%-%ARTIFACT_VERSION%-%ARTIFACT_COUNTRY%-%OS_VERSION%-%OS_LTSC%]
2025-12-22T06:16:58.3422509Z *** ImageName: [***.azurecr.io/cronus:sandbox-27.3.43787.0-w1-ltsc2019]
2025-12-22T06:16:58.3468023Z *** Set Pipeline variable $(ALOPS_BC_IMAGE) = '***.azurecr.io/cronus:sandbox-27.3.43787.0-w1-ltsc2019'
2025-12-22T06:16:58.3905838Z Error response from daemon: No such image: ***.azurecr.io/cronus:sandbox-27.3.43787.0-w1-ltsc2019
2025-12-22T06:16:58.3953168Z *** Pull Docker Image: ***.azurecr.io/cronus:sandbox-27.3.43787.0-w1-ltsc2019
2025-12-22T06:16:58.3974426Z *** Login into docker: ***.azurecr.io
2025-12-22T06:16:58.3987640Z U: 8
2025-12-22T06:16:58.3993124Z P: 52
2025-12-22T06:16:58.5114252Z WARNING! Your password will be stored unencrypted in C:\Users\script-service\.docker\config.json.
2025-12-22T06:16:58.5114698Z Configure a credential helper to remove this warning. See
2025-12-22T06:16:58.5115234Z https://docs.docker.com/engine/reference/commandline/login/#credential-stores
2025-12-22T06:16:58.5115623Z
2025-12-22T06:16:58.5123190Z Login Succeeded
2025-12-22T06:21:22.6944613Z sandbox-27.3.43787.0-w1-ltsc2019: Pulling from cronus
2025-12-22T06:21:22.6949084Z 14438130d31b: Already exists
2025-12-22T06:21:22.6955062Z 4800cb6f9111: Already exists
2025-12-22T06:21:22.6960176Z 512638e09bdd: Already exists
2025-12-22T06:21:22.6966021Z 23bb5f078ec5: Already exists
2025-12-22T06:21:22.6971106Z e70bce6d9507: Already exists
2025-12-22T06:21:22.6976198Z ab9fc0bbd555: Already exists
2025-12-22T06:21:22.6981502Z 2949e8ed8e99: Already exists
2025-12-22T06:21:22.6988732Z 7761256af9c0: Already exists
2025-12-22T06:21:22.6994897Z 0c2930d9a65a: Already exists
2025-12-22T06:21:22.7000113Z 14ca546e8459: Already exists
2025-12-22T06:21:22.7006556Z ca0b5ed4d368: Already exists
2025-12-22T06:21:22.7011702Z 3592129a45e6: Already exists
2025-12-22T06:21:22.7017386Z 1c2912a91d0b: Already exists
2025-12-22T06:21:22.7022208Z c580bf6033b8: Already exists
2025-12-22T06:21:22.7028828Z 09b5c3a200f5: Pulling fs layer
2025-12-22T06:21:22.7033302Z aad27f23f17c: Pulling fs layer
2025-12-22T06:21:22.7037621Z c9f1d93ac595: Pulling fs layer
2025-12-22T06:21:22.7040070Z cc654fdf9851: Pulling fs layer
2025-12-22T06:21:22.7044154Z f421c9e660d7: Pulling fs layer
2025-12-22T06:21:22.7046556Z cc654fdf9851: Waiting
2025-12-22T06:21:22.7050625Z f421c9e660d7: Waiting
2025-12-22T06:21:22.7052786Z aad27f23f17c: Verifying Checksum
2025-12-22T06:21:22.7056540Z aad27f23f17c: Download complete
2025-12-22T06:21:22.7058620Z 09b5c3a200f5: Verifying Checksum
2025-12-22T06:21:22.7062945Z 09b5c3a200f5: Pull complete
2025-12-22T06:21:22.7065155Z aad27f23f17c: Pull complete
2025-12-22T06:21:22.7069230Z f421c9e660d7: Verifying Checksum
2025-12-22T06:21:22.7071257Z f421c9e660d7: Download complete
2025-12-22T06:21:22.7075225Z c9f1d93ac595: Verifying Checksum
2025-12-22T06:21:22.7077521Z c9f1d93ac595: Download complete
2025-12-22T06:21:22.7080289Z cc654fdf9851: Verifying Checksum
2025-12-22T06:21:22.7084288Z cc654fdf9851: Download complete
2025-12-22T06:21:22.7090129Z c9f1d93ac595: Pull complete
2025-12-22T06:21:22.7094542Z cc654fdf9851: Pull complete
2025-12-22T06:21:22.7099354Z f421c9e660d7: Pull complete
2025-12-22T06:21:22.7104091Z Digest: sha256:41a5d34ec47556f4f1cc39f44c213761b07042fd90b4f737b4b6caef64af86e2
2025-12-22T06:21:22.7108775Z Status: Downloaded newer image for ***.azurecr.io/cronus:sandbox-27.3.43787.0-w1-ltsc2019
2025-12-22T06:21:22.7113300Z ***.azurecr.io/cronus:sandbox-27.3.43787.0-w1-ltsc2019
2025-12-22T06:21:22.7118485Z *** Pull Docker Image: ***.azurecr.io/cronus:sandbox-27.3.43787.0-w1-ltsc2019 [OK]
2025-12-22T06:21:22.7120518Z
2025-12-22T06:21:22.7125572Z *** Logout docker: ***.azurecr.io
2025-12-22T06:21:22.7493848Z Removing login credentials for ***.azurecr.io
2025-12-22T06:21:22.7553718Z *** Docker Create Succeeded.
2025-12-22T06:21:22.7638195Z *** Cleanup VSTS Environment: True
2025-12-22T06:21:25.1031380Z ##[section]Finishing: ALOps Docker Create W1 SaaS