Wait for Docker Container to start - Takes to long

[NAVFreak]

We are running several pipelines but it is only pipelines in a certain project that we have problem with "Wait for container to start". For other pipelines it just takes a couple of minutes but in this project it takes around 10-40 minutes(!) and they are running on same machines. I saw #462 but in this case it has been turned off.

Is it the artifact that causes this? 🤔 I created a pipeline that was a copy with next minor and then it went fast, < 1:20 minutes two times

the used yaml The only difference that I can see between the pipelines is the artifact version because we create everything via a template.

- task: ALOpsAgentMaintenance@1
  inputs:
    removeoldtasks: true
    removeunusedcontainers: true
    pruneimagesdayscreated: $(Pipeline-pruneimagesdayscreated) # Force docker image pruning based on creation date (x days).
    removebcartifacts: true
    daysunused: $(Pipeline-daysunused)

- task: ALOpsDockerCreate@1
  displayName: 'ALOPS - Create Docker Image' # It will reuse the image if already exists, or build one if it doesn't.
  inputs:
    artifacttype: 'OnPrem'
    artifactversion: '20.3.42673.43026' 
    artifactcountry: se     
    versionselect: 'Closest'

- task: ALOpsDockerStart@1
  displayName: 'ALOPS - Start Docker Container' # No need to provide any details - it will get the details from previous step
  inputs:
    taskscheduler: Disable   #options Disable,Enable,Keep

- task: ALOpsDockerWait@1
  displayName: 'ALOPS - Wait for Docker Container to start'
  inputs:
    search_string: 'Ready for connections!'

the output Output of: ALOPS - Wait for Docker Container to start

2022-11-07T03:01:08.5014240Z ##[section]Starting: ALOPS - Wait for Docker Container to start
2022-11-07T03:01:08.5228801Z ==============================================================================
2022-11-07T03:01:08.5229440Z Task         : ALOps Docker Wait
2022-11-07T03:01:08.5229985Z Description  : Wait until the Business Central container is started
2022-11-07T03:01:08.5230562Z Version      : ***.453.3***83
2022-11-07T03:01:08.5230931Z Author       : Hodor
2022-11-07T03:01:08.5231472Z Help         : Wait until the Business Central container is started.
2022-11-07T03:01:08.5232136Z ==============================================================================
2022-11-07T03:01:10.2623834Z *** Validate configuration
2022-11-07T03:01:10.5972909Z *** Task Inputs:
2022-11-07T03:01:10.6026812Z 
2022-11-07T03:01:10.6125950Z name                 value                 
2022-11-07T03:01:10.6129002Z ----                 -----                 
2022-11-07T03:01:10.6132098Z fixed_tag                                  
2022-11-07T03:01:10.6135348Z search_string        Ready for connections!
2022-11-07T03:01:10.6136067Z warning_string                             
2022-11-07T03:01:10.6137085Z error_string                               
2022-11-07T03:01:10.6138356Z setup_working_folder True                  
2022-11-07T03:01:10.6139494Z usecompression       True                  
2022-11-07T03:01:10.6140757Z printlogs            True                  
2022-11-07T03:01:10.6141121Z 
2022-11-07T03:01:10.6171496Z 
2022-11-07T03:01:10.6184956Z 
2022-11-07T03:01:10.6408889Z *** For documentation, please visit   : https://www.alops.be/documentation
2022-11-07T03:01:10.6413636Z 
2022-11-07T03:01:10.9323343Z *** ALOps License:
2022-11-07T03:01:10.9350344Z   * Licensed To: CompanyName AB (Collection/Organization License)
2022-11-07T03:01:10.9407080Z 
2022-11-07T03:01:11.0199123Z *** Importing required PS-Functions
2022-11-07T03:01:11.6735203Z *** Waiting for Docker Container Log Entry: Ready for connections!
2022-11-07T03:01:12.8909398Z Initializing...
2022-11-07T03:01:12.8929862Z Starting Container
2022-11-07T03:01:12.8941910Z Hostname is c9d5b69***c3a
2022-11-07T03:01:12.8952798Z PublicDnsName is c9d5b69***c3a
2022-11-07T03:01:12.8963310Z Using NavUserPassword Authentication
2022-11-07T03:01:12.8975144Z Starting Local SQL Server
2022-11-07T03:01:12.8986091Z Starting Internet Information Server
2022-11-07T03:01:12.8998037Z Creating Self Signed Certificate
2022-11-07T03:01:12.9011807Z Self Signed Certificate Thumbprint 3E8B9DADF***8BBE48D4076CD45A83***0BA74BBD035
2022-11-07T03:01:12.9027596Z DNS identity c9d5b69***c3a
2022-11-07T03:01:12.9032262Z Modifying Service Tier Config File with Instance Specific Settings
2022-11-07T03:01:12.9042821Z Modifying Service Tier Config File with settings from environment variable
2022-11-07T03:01:12.9068159Z Setting EnableTaskScheduler to false
2022-11-07T03:01:14.3159687Z Starting Service Tier
2022-11-07T03:01:48.4800819Z CertificateThumprint 3E8B9DADF***8BBE48D4076CD45A83***0BA74BBD035
2022-11-07T03:01:48.4918017Z Registering event sources
2022-11-07T03:01:48.4971038Z Creating DotNetCore Web Server Instance
2022-11-07T03:01:48.4985187Z Using application pool name: BC
2022-11-07T03:01:48.4996867Z Using default container name: NavWebApplicationContainer
2022-11-07T03:01:48.5008072Z Copy files to WWW root C:\inetpub\wwwroot\BC
2022-11-07T03:01:54.4115455Z Create the application pool BC
2022-11-07T03:01:54.4127853Z Create website: NavWebApplicationContainer with SSL
2022-11-07T03:01:55.7836034Z Update configuration: navsettings.json
2022-11-07T03:01:55.7850969Z Done Configuring Web Client
2022-11-07T03:01:55.7863246Z Creating http download site
2022-11-07T03:01:57.1976911Z Setting SA Password and enabling SA
2022-11-07T03:01:57.1988351Z Creating admin as SQL User and add to sysadmin
2022-11-07T03:02:05.7868837Z Creating SUPER user
2022-11-07T03:02:10.0179726Z Container IP Address: ***7***.***.***96.***58
2022-11-07T03:02:10.0191213Z Container Hostname  : c9d5b69***c3a
2022-11-07T03:02:10.0206511Z Container Dns Name  : c9d5b69***c3a
2022-11-07T03:02:10.0217414Z Web Client          : https://c9d5b69***c3a/BC/
2022-11-07T03:02:10.0228075Z Admin Username      : admin
2022-11-07T03:02:10.0240154Z Admin Password      : xxxxx
2022-11-07T03:02:10.0253055Z Dev. Server         : https://c9d5b69***c3a
2022-11-07T03:02:10.0264724Z Dev. ServerInstance : BC
2022-11-07T03:02:10.0268791Z 
2022-11-07T03:02:10.0280327Z Files:
2022-11-07T03:02:10.0294049Z http://c9d5b69***c3a:8080/ALLanguage.vsix
2022-11-07T03:02:10.0305080Z http://c9d5b69***c3a:8080/certificate.cer
2022-11-07T03:02:10.0309657Z 
2022-11-07T03:02:10.0321282Z Container Total Physical Memory is ***6.0Gb
2022-11-07T03:02:10.0332628Z Container Free Physical Memory is 5.7Gb
2022-11-07T03:02:10.0337493Z 
2022-11-07T03:02:10.0349707Z Initialization took 6*** seconds
2022-11-07T03:02:10.0362614Z Ready for connections!
2022-11-07T03:02:10.0373772Z Starting EventLog Monitor
2022-11-07T03:02:10.0385164Z Monitoring EventSources from EventLog[Application]:
2022-11-07T03:02:10.0396167Z - MicrosoftDynamicsNAVClientClientService
2022-11-07T03:02:10.0407299Z - MicrosoftDynamicsNAVClientWebClient
2022-11-07T03:02:10.0421712Z - MicrosoftDynamicsNavServer$BC
2022-11-07T03:02:10.0430947Z - MSSQL$SQLEXPRESS
2022-11-07T03:02:10.0434035Z 
2022-11-07T03:02:10.2576268Z 
2022-11-07T03:02:10.7787984Z *** BC Container Parameters:
2022-11-07T03:02:10.7810074Z 
2022-11-07T03:02:10.7822270Z *** Mapping container info to global variables:
2022-11-07T03:02:10.7862128Z *** Set Pipeline variable $(ALOPS_DOCKER_CONTAINER_ID) = 'c9d5b69***c3a083457***b4aa***4***c8758899***de68***bdae7***d35f***9bfcde***c59df'
2022-11-07T03:02:10.7998601Z *** Set Pipeline variable $(ALOPS_DOCKER_IPADDRESS) = '***7***.***.***96.***58'
2022-11-07T03:02:10.8033470Z *** Set Pipeline variable $(ALOPS_DOCKER_HOSTNAME) = 'c9d5b69***c3a'
2022-11-07T03:02:10.8069275Z *** Set Pipeline variable $(ALOPS_DOCKER_DNSNAME) = 'c9d5b69***c3a'
2022-11-07T03:02:10.8102246Z *** Set Pipeline variable $(ALOPS_DOCKER_WEBCLIENT) = 'https://c9d5b69***c3a/BC/'
2022-11-07T03:02:10.8134853Z *** Set Pipeline variable $(ALOPS_DOCKER_VSIX) = 'http://c9d5b69***c3a:8080/ALLanguage.vsix'
2022-11-07T03:02:10.8169445Z *** Set Pipeline variable $(ALOPS_DOCKER_CERTIFICATE) = 'http://c9d5b69***c3a:8080/certificate.cer'
2022-11-07T03:02:10.8207156Z *** Set Pipeline variable $(ALOPS_DOCKER_ADMINUSER) = 'admin'
2022-11-07T03:02:10.8239717Z *** Set Pipeline variable $(ALOPS_DOCKER_ADMINPASSWORD) = 'Caqi6633'
2022-11-07T03:02:10.8275144Z *** Set Pipeline variable $(ALOPS_DOCKER_NAVSERVERINSTANCE) = 'BC'
2022-11-07T03:02:10.8375601Z *** Initiate Docker Session
2022-11-07T03:02:11.1077345Z *** Set Docker Container ErrorActionPreference = Stop
2022-11-07T03:02:11.1878030Z *** Working folder: c:\vsts-agent-win-x64-***.***0***.0\_work\30\s
2022-11-07T03:02:11.1889595Z ***
2022-11-07T03:02:11.1901493Z *** Copy Working folder to Docker Container: c9d5b69***c3a083457***b4aa***4***c8758899***de68***bdae7***d35f***9bfcde***c59df
2022-11-07T03:02:11.1914321Z *** Docker Working Folder: c:\Run\DevOps\
2022-11-07T03:02:11.1927380Z *** Copy from [c:\vsts-agent-win-x64-***.***0***.0\_work\30\s] to [c:\Run\DevOps\]
2022-11-07T03:02:11.2700753Z *** Compression Enabled Transfer (Dotnet)
2022-11-07T03:02:11.2805605Z *** Compress Source Files
2022-11-07T03:07:24.1304459Z *** Transfer compressed Archive to session (7035***0635*** bytes)
2022-11-07T03:37:11.3298920Z *** Expand source files in target session
2022-11-07T03:38:45.0100874Z *** Source File setup completed
2022-11-07T03:38:45.0352234Z *** Cleanup VSTS Environment: True
2022-11-07T03:38:47.4186018Z ##[section]Finishing: ALOPS - Wait for Docker Container to start

Expected behavior That it shouldnt take that loong.

Screenshots

Additional context Images

[waldo1001]

Hard to see for us what causes this.

Can you check the build agent to see what is in your folder? Or check our repository for big files? Or a huge amount of files?

ALOps transfers all files in the repo to the container - that is slowed down for this project it seems, so it must be something in your repo...

[waldo1001]

@NAVFreak, any feedback on this?

[waldo1001]

@NAVFreak ?

[NAVFreak]

Sorry. It seemed to disappear by itself. But... It maybe disappeared when we start using new agent servers and "tossed" the old ones with this problem 🤷

Den ons 8 mars 2023 11:19waldo @.***> skrev:

@NAVFreak https://github.com/NAVFreak ?

— Reply to this email directly, view it on GitHub https://github.com/HodorNV/ALOps/issues/584#issuecomment-1459940230, or unsubscribe https://github.com/notifications/unsubscribe-auth/AIKZT4CC5TICFUEOGTVMCXDW3BMM7ANCNFSM6AAAAAARY3NWFE . You are receiving this because you were mentioned.Message ID: @.***>

[JeremyVyska]

In case searching folks come across this later:

We had a client with ALOps running a build agent with this problem. Very very slow on this step. I finally noticed that the "Transfer compressed Archive to session" line? That was the hold up. When I dug in, it was zipping, transferring, and unzipping 7gb into the docker for a 134mb app.

The "fix" for us ended up being to empty out the #\ folders in the agent Work path. Presumably, some clean up step hadn't run to flush old things out. Builds went from 1+ hour to a reasonable number of minutes again.

@waldo1001 - adding #672 PR so you don't have to figure out writing this up. 😄