azure-pipelines-tasks: CacheV2: Unable to find pipeline caching scopes.

Required Information

Question, Bug, or Feature?
Type: Bug (essentially a reopen of #11869)

Enter Task Name: CacheV2

Environment

Server - Azure Pipelines
Agent - Hosted
- ubuntu-latest and Ubuntu16, agent version 2.173.0

Issue Description

Same as #11869: when using the Cache task, I get the error “Unable to find pipeline caching scopes.” (see logs below).

The pipeline is a pure YAML multi-stage pipeline. The problematic stage looks like this:

stages:
  - stage: deploy_app
    displayName: Deploy app
    condition: and(succeeded(), or(eq(variables['Build.SourceBranch'], 'refs/heads/master'), eq(variables['DEPLOY'], 'true')))
    jobs:
      - deployment:
        displayName: Deploy
        environment: ${{ parameters.environment }}
        variables:
          - template: /infrastructure/azure-pipelines/state-secrets-variables.yaml
        strategy:
          runOnce:
            deploy:
              steps:
                - checkout: self
                - download: current
                  artifact: drop
[...]
                - task: Bash@3
                  displayName: Set npm_config_cache
                  inputs:
                    targetType: 'inline'
                    script: |
                      echo "##vso[task.setvariable variable=npm_config_cache]$(Pipeline.Workspace)/.npm"
                - task: Cache@2
                  displayName: Restore npm cache
                  inputs:
                    key: 'v2 | npm | "$(Agent.OS)" | infrastructure/package-lock.json'
                    path: '$(npm_config_cache)'
                    cacheHitVar: 'PULUMI_NODE_CACHE_RESTORED'
                  condition: and(succeeded(), ne(variables.PULUMI_NODE_CACHE_RESTORED, 'true'))
[...]

This issue first appeared after switching the job to a deployment job and adding an environment.

While the Cache task is nested in a template multiple levels below, it does not fail on all pipelines that use the template. The directory structure is roughly as follows:

/
- ts-apps/
  - […]/pipeline.yaml (these all work fine)
- python-apps/
  - […]/pipeline.yaml (these don’t)
- infrastructure/
  - azure-pipelines/
    - […]
    - pulumi-command.yaml (this is the template that contains the Cache task and it’s being used in all other pipelines)

Task logs

This is a log of the task in one of the failing pipelines:

2020-08-12T11:24:32.8762742Z ##[debug]Evaluating condition for step: 'Restore npm cache'
2020-08-12T11:24:32.8768744Z ##[debug]Evaluating: and(succeeded(), ne(variables['PULUMI_NODE_CACHE_RESTORED'], 'true'))
2020-08-12T11:24:32.8769321Z ##[debug]Evaluating and:
2020-08-12T11:24:32.8777713Z ##[debug]..Evaluating succeeded:
2020-08-12T11:24:32.8778640Z ##[debug]..=> True
2020-08-12T11:24:32.8779079Z ##[debug]..Evaluating ne:
2020-08-12T11:24:32.8781238Z ##[debug]....Evaluating indexer:
2020-08-12T11:24:32.8807853Z ##[debug]......Evaluating variables:
2020-08-12T11:24:32.8811680Z ##[debug]......=> Object
2020-08-12T11:24:32.8812949Z ##[debug]......Evaluating String:
2020-08-12T11:24:32.8814043Z ##[debug]......=> 'PULUMI_NODE_CACHE_RESTORED'
2020-08-12T11:24:32.8818618Z ##[debug]....=> Null
2020-08-12T11:24:32.8819553Z ##[debug]....Evaluating String:
2020-08-12T11:24:32.8820025Z ##[debug]....=> 'true'
2020-08-12T11:24:32.8826486Z ##[debug]....=> Unable to coerce String to Null.
2020-08-12T11:24:32.8826957Z ##[debug]..=> True
2020-08-12T11:24:32.8827774Z ##[debug]=> True
2020-08-12T11:24:32.8830742Z ##[debug]Expanded: and(True, ne(Null, 'true'))
2020-08-12T11:24:32.8831265Z ##[debug]Result: True
2020-08-12T11:24:32.8831873Z ##[section]Starting: Restore npm cache
2020-08-12T11:24:32.8837212Z ==============================================================================
2020-08-12T11:24:32.8837606Z Task         : Cache
2020-08-12T11:24:32.8837881Z Description  : Cache files between runs
2020-08-12T11:24:32.8838181Z Version      : 2.0.1
2020-08-12T11:24:32.8838452Z Author       : Microsoft Corporation
2020-08-12T11:24:32.8838819Z Help         : https://aka.ms/pipeline-caching-docs
2020-08-12T11:24:32.8839472Z ==============================================================================
2020-08-12T11:24:33.2287914Z Resolving key:
2020-08-12T11:24:33.2443034Z  - v2                                      [string]
2020-08-12T11:24:33.2443678Z  - npm                                     [string]
2020-08-12T11:24:33.2446565Z  - "Linux"                                 [string]
2020-08-12T11:24:33.2934066Z  - infrastructure/package-lock.json [file] --> C416E6FA791258733E1AC45409FCD865031CD54CBB0DBA3E05D52F998149B3A2
2020-08-12T11:24:33.2967388Z Resolved to: v2|npm|"Linux"|F/PBNr3ki2VwlGEI/ltlXjIXpRWDf8v9fCXR3SHt4fg=
2020-08-12T11:24:33.2984945Z ##[debug]Processed: ##vso[task.settaskvariable variable=RESTORE_STEP_RAN;issecret=False;]true
2020-08-12T11:24:33.2986084Z ##[debug]Processed: ##vso[task.settaskvariable variable=RESTORE_STEP_RESOLVED_FINGERPRINT;issecret=False;]v2|npm|"Linux"|F/PBNr3ki2VwlGEI/ltlXjIXpRWDf8v9fCXR3SHt4fg=
2020-08-12T11:24:33.5086521Z Verbose, ArtifactHttpClientFactory.CreateVssHttpClient: DedupStoreHttpClient with BaseUri: https://vsblobprodsu6weu.vsblob.visualstudio.com/Ad7b6fe08-347e-4cca-91fb-d5c313d16196/, MaxRetries:5, SendTimeout:00:00:50
2020-08-12T11:24:33.5107103Z ##[debug]Dedup parallelism: 192
2020-08-12T11:24:33.6446910Z Information, ApplicationInsightsTelemetrySender will correlate events with X-TFS-Session 30e987a5-fdc0-495b-a563-3e9bdfa55eda
2020-08-12T11:24:33.6447426Z Verbose, Started ITelemetrySender BlobStoreApplicationInsightsTelemetrySender.
2020-08-12T11:24:34.1745826Z Information, Getting a pipeline cache artifact with one of the following fingerprints:
2020-08-12T11:24:34.1746828Z Information, Fingerprint: `v2|npm|"Linux"|F/PBNr3ki2VwlGEI/ltlXjIXpRWDf8v9fCXR3SHt4fg=`
2020-08-12T11:24:34.3138190Z Verbose, ApplicationInsightsTelemetrySender waiting for 0 of 2 TrackEvent operations to complete...
2020-08-12T11:24:35.3672290Z Verbose, ApplicationInsightsTelemetrySender sent PipelineCache.RestoreCache telemetry
2020-08-12T11:24:35.9352017Z Verbose, ApplicationInsightsTelemetrySender sent Error telemetry
2020-08-12T11:24:35.9359827Z Verbose, ApplicationInsightsTelemetrySender operations completed in 1621 ms
2020-08-12T11:24:35.9363777Z Information, ApplicationInsightsTelemetrySender correlated 2 events with X-TFS-Session 30e987a5-fdc0-495b-a563-3e9bdfa55eda
2020-08-12T11:24:35.9364959Z Verbose, Stopped ITelemetrySender BlobStoreApplicationInsightsTelemetrySender.
2020-08-12T11:24:35.9414318Z ##[error]Unable to find pipeline caching scopes.
2020-08-12T11:24:35.9429197Z ##[debug]Processed: ##vso[task.logissue type=error;]Unable to find pipeline caching scopes.
2020-08-12T11:24:35.9431984Z ##[debug]Processed: ##vso[task.complete result=Failed;]
2020-08-12T11:24:35.9436790Z ##[debug]   at Microsoft.VisualStudio.Services.WebApi.VssHttpClientBase.HandleResponseAsync(HttpResponseMessage response, CancellationToken cancellationToken)
   at Microsoft.VisualStudio.Services.WebApi.VssHttpClientBase.SendAsync(HttpRequestMessage message, HttpCompletionOption completionOption, Object userState, CancellationToken cancellationToken)
   at Microsoft.VisualStudio.Services.WebApi.VssHttpClientBase.SendAsync[T](HttpRequestMessage message, Object userState, CancellationToken cancellationToken)
   at Microsoft.VisualStudio.Services.WebApi.VssHttpClientBase.SendAsync[T](HttpMethod method, IEnumerable`1 additionalHeaders, Guid locationId, Object routeValues, ApiResourceVersion version, HttpContent content, IEnumerable`1 queryParameters, Object userState, CancellationToken cancellationToken)
   at Microsoft.VisualStudio.Services.PipelineCache.WebApi.PipelineCacheClient.GetPipelineCacheArtifactAsync(Fingerprint[] fingerprints, CancellationToken cancellationToken)
   at Microsoft.VisualStudio.Services.PipelineCache.WebApi.PipelineCacheClient.<>c__DisplayClass9_0.<<GetPipelineCacheArtifactAsync>b__1>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.VisualStudio.Services.BlobStore.Common.Telemetry.BlobStoreClientTelemetry.MeasureActionAsync[TResult](BlobStoreTelemetryRecord record, Func`1 actionAsync)
   at Microsoft.VisualStudio.Services.Content.Common.ExceptionExtensions.ReThrow(Exception ex)
   at Microsoft.VisualStudio.Services.BlobStore.Common.Telemetry.BlobStoreClientTelemetry.MeasureActionAsync[TResult](BlobStoreTelemetryRecord record, Func`1 actionAsync)
   at Microsoft.VisualStudio.Services.PipelineCache.WebApi.PipelineCacheClient.GetPipelineCacheArtifactAsync(Fingerprint[] fingerprints, CancellationToken cancellationToken, PipelineCacheTelemetryRecord cacheRecordOptional)
   at Agent.Plugins.PipelineCache.PipelineCacheServer.DownloadAsync(AgentTaskPluginExecutionContext context, Fingerprint[] fingerprints, String path, String cacheHitVariable, CancellationToken cancellationToken)
   at Agent.Plugins.PipelineCache.RestorePipelineCacheV0.ProcessCommandInternalAsync(AgentTaskPluginExecutionContext context, Fingerprint fingerprint, Func`1 restoreKeysGenerator, String path, CancellationToken token)
   at Agent.Plugins.PipelineCache.PipelineCacheTaskPluginBase.RunAsync(AgentTaskPluginExecutionContext context, CancellationToken token)
   at Agent.PluginHost.Program.Main(String[] args)
2020-08-12T11:24:35.9474315Z ##[section]Finishing: Restore npm cache

And this is the log of the task in one of the working pipelines (note the identical cache fingerprints):

2020-08-12T11:42:00.6311714Z ##[debug]Evaluating condition for step: 'Restore npm cache'
2020-08-12T11:42:00.6316188Z ##[debug]Evaluating: and(succeeded(), ne(variables['PULUMI_NODE_CACHE_RESTORED'], 'true'))
2020-08-12T11:42:00.6316820Z ##[debug]Evaluating and:
2020-08-12T11:42:00.6323659Z ##[debug]..Evaluating succeeded:
2020-08-12T11:42:00.6324156Z ##[debug]..=> True
2020-08-12T11:42:00.6324487Z ##[debug]..Evaluating ne:
2020-08-12T11:42:00.6325848Z ##[debug]....Evaluating indexer:
2020-08-12T11:42:00.6338979Z ##[debug]......Evaluating variables:
2020-08-12T11:42:00.6341452Z ##[debug]......=> Object
2020-08-12T11:42:00.6342292Z ##[debug]......Evaluating String:
2020-08-12T11:42:00.6342922Z ##[debug]......=> 'PULUMI_NODE_CACHE_RESTORED'
2020-08-12T11:42:00.6345795Z ##[debug]....=> Null
2020-08-12T11:42:00.6346307Z ##[debug]....Evaluating String:
2020-08-12T11:42:00.6346611Z ##[debug]....=> 'true'
2020-08-12T11:42:00.6350673Z ##[debug]....=> Unable to coerce String to Null.
2020-08-12T11:42:00.6351026Z ##[debug]..=> True
2020-08-12T11:42:00.6351536Z ##[debug]=> True
2020-08-12T11:42:00.6353510Z ##[debug]Expanded: and(True, ne(Null, 'true'))
2020-08-12T11:42:00.6353930Z ##[debug]Result: True
2020-08-12T11:42:00.6354314Z ##[section]Starting: Restore npm cache
2020-08-12T11:42:00.6358728Z ==============================================================================
2020-08-12T11:42:00.6359059Z Task         : Cache
2020-08-12T11:42:00.6359315Z Description  : Cache files between runs
2020-08-12T11:42:00.6359559Z Version      : 2.0.1
2020-08-12T11:42:00.6359808Z Author       : Microsoft Corporation
2020-08-12T11:42:00.6360208Z Help         : https://aka.ms/pipeline-caching-docs
2020-08-12T11:42:00.6360534Z ==============================================================================
2020-08-12T11:42:00.9194575Z Resolving key:
2020-08-12T11:42:00.9333444Z  - v2                                      [string]
2020-08-12T11:42:00.9334194Z  - npm                                     [string]
2020-08-12T11:42:00.9336407Z  - "Linux"                                 [string]
2020-08-12T11:42:00.9753932Z  - infrastructure/package-lock.json [file] --> C416E6FA791258733E1AC45409FCD865031CD54CBB0DBA3E05D52F998149B3A2
2020-08-12T11:42:00.9783475Z Resolved to: v2|npm|"Linux"|F/PBNr3ki2VwlGEI/ltlXjIXpRWDf8v9fCXR3SHt4fg=
2020-08-12T11:42:00.9797253Z ##[debug]Processed: ##vso[task.settaskvariable variable=RESTORE_STEP_RAN;issecret=False;]true
2020-08-12T11:42:00.9798621Z ##[debug]Processed: ##vso[task.settaskvariable variable=RESTORE_STEP_RESOLVED_FINGERPRINT;issecret=False;]v2|npm|"Linux"|F/PBNr3ki2VwlGEI/ltlXjIXpRWDf8v9fCXR3SHt4fg=
2020-08-12T11:42:01.1781274Z Verbose, ArtifactHttpClientFactory.CreateVssHttpClient: DedupStoreHttpClient with BaseUri: https://vsblobprodsu6weu.vsblob.visualstudio.com/Ad7b6fe08-347e-4cca-91fb-d5c313d16196/, MaxRetries:5, SendTimeout:00:00:50
2020-08-12T11:42:01.1818567Z ##[debug]Dedup parallelism: 192
2020-08-12T11:42:01.3113826Z Information, ApplicationInsightsTelemetrySender will correlate events with X-TFS-Session a86db722-8664-45cc-9092-3b6564825b60
2020-08-12T11:42:01.3114834Z Verbose, Started ITelemetrySender BlobStoreApplicationInsightsTelemetrySender.
2020-08-12T11:42:01.6837124Z Information, Getting a pipeline cache artifact with one of the following fingerprints:
2020-08-12T11:42:01.6838105Z Information, Fingerprint: `v2|npm|"Linux"|F/PBNr3ki2VwlGEI/ltlXjIXpRWDf8v9fCXR3SHt4fg=`
2020-08-12T11:42:02.1604953Z Information, There is a cache hit: `v2|npm|"Linux"|F/PBNr3ki2VwlGEI/ltlXjIXpRWDf8v9fCXR3SHt4fg=`
2020-08-12T11:42:02.1607371Z Information, Used scope: 259;f5c7a962-6082-42ca-ac3f-137df246978a;refs/heads/master;78fa3cd1-67a1-4ad7-876c-fd5872ec6db5
2020-08-12T11:42:02.1609421Z Information, Missed on the following scopes: 259;f5c7a962-6082-42ca-ac3f-137df246978a;refs/heads/pipeline-environments;78fa3cd1-67a1-4ad7-876c-fd5872ec6db5
2020-08-12T11:42:02.2345897Z ##[debug]Processed: ##vso[telemetry.publish area=AzurePipelinesAgent;feature=PipelineCache]{"FileCount":"0","PlanId":"212baa79-b64f-4e48-a582-b9fbbe790e31","JobId":"7e4fa394-a526-5b11-21c4-3735ed6aef8d","TaskInstanceId":"50a0e04b-2bf7-53cf-5fc7-a2185c6eb453","CacheResult":"Hit","ActionDurationMs":"484","ActionName":"PipelineCache.RestoreCache","ActionResult":"Success","AttemptNumber":"1","ItemCount":"0","Level":"ThirdParty","CreatedUtcNow":"2020-08-12T11:42:01.6728423Z","SentUtcNow":"2020-08-12T11:42:02.1628399Z","BaseAddress":"https://vsblobprodsu6weu.vsblob.visualstudio.com/Ad7b6fe08-347e-4cca-91fb-d5c313d16196/","X_TFS_Session":"a86db722-8664-45cc-9092-3b6564825b60","DeploymentEnvironment":"PRODUCTION","DeploymentEnvironmentIsProduction":"True","VSOAccount":"vsblobprodsu6weu","OSName":"Linux","OSVersion":"2020","FrameworkDescription":".NET Core ","ProcessName":"Agent.PluginHost","DotNetReleaseDword":"-1","Version":"18.169.30119.0","ExceptionCount":"0"}
2020-08-12T11:42:02.2348658Z Entry found at fingerprint: `v2|npm|"Linux"|F/PBNr3ki2VwlGEI/ltlXjIXpRWDf8v9fCXR3SHt4fg=`
2020-08-12T11:42:02.2349038Z Verbose, PipelineCache.DownloadAsync starting
2020-08-12T11:42:02.2952828Z Verbose, ArtifactHttpRetryMessageHandler.TraceHttpRequestFailed: https://vsblobprodsu6weu.vsblob.visualstudio.com/Ad7b6fe08-347e-4cca-91fb-d5c313d16196/_apis/dedup/chunks/9524D78CD73AA02ADA29A9AC5B04E255BE474724688AA1D44687AB0C11FAFE2A01?redirect=true, HttpStatusCode.RedirectMethod, activity 
2020-08-12T11:42:02.4496173Z ##[debug]Starting 'tar' with arguments '-v -xf - -C .'...
2020-08-12T11:42:02.4854943Z Verbose, ArtifactHttpRetryMessageHandler.TraceHttpRequestFailed: https://vsblobprodsu6weu.vsblob.visualstudio.com/Ad7b6fe08-347e-4cca-91fb-d5c313d16196/_apis/dedup/nodes/45ED9CE75A7D1DE2FDD2A5E949FADA22C44122EB7E8385EE859B5E94A7D1783E02?redirect=true, HttpStatusCode.RedirectMethod, activity 
2020-08-12T11:42:02.5828232Z Information, Expected size to be downloaded: 19.6 MB
2020-08-12T11:42:02.6364412Z Information, Downloaded 0.0 MB out of 19.6 MB (0%).
2020-08-12T11:42:02.9638572Z Verbose, ApplicationInsightsTelemetrySender sent PipelineCache.RestoreCache telemetry
2020-08-12T11:42:03.9737568Z ./
2020-08-12T11:42:03.9738297Z ./_cacache/
[...]
2020-08-12T11:42:04.5091120Z Information, Downloaded 19.6 MB out of 19.6 MB (100%).
2020-08-12T11:42:04.5091362Z Information, 
2020-08-12T11:42:04.5091573Z Download statistics:
2020-08-12T11:42:04.5091806Z Total Content: 19.6 MB
2020-08-12T11:42:04.5092053Z Physical Content Downloaded: 19.1 MB
2020-08-12T11:42:04.5092324Z Compression Saved: 0.5 MB
2020-08-12T11:42:04.5092561Z Local Caching Saved: 0.0 MB
2020-08-12T11:42:04.5092809Z Chunks Downloaded: 250
2020-08-12T11:42:04.5093023Z Nodes Downloaded: 1
[...]
2020-08-12T11:42:04.5122485Z Process exit code: 0
2020-08-12T11:42:04.5122785Z Verbose, PipelineCache.DownloadAsync completed in 2.3077915 seconds
2020-08-12T11:42:04.5535807Z ##[debug]Processed: ##vso[telemetry.publish area=AzurePipelinesAgent;feature=PipelineCache]{"FileCount":"0","PlanId":"212baa79-b64f-4e48-a582-b9fbbe790e31","JobId":"7e4fa394-a526-5b11-21c4-3735ed6aef8d","TaskInstanceId":"50a0e04b-2bf7-53cf-5fc7-a2185c6eb453","ActionDurationMs":"2307","ActionName":"PipelineCache.DownloadAsync","ActionResult":"Success","AttemptNumber":"1","ItemCount":"0","Level":"ThirdParty","CreatedUtcNow":"2020-08-12T11:42:02.1692955Z","SentUtcNow":"2020-08-12T11:42:04.4802795Z","BaseAddress":"https://vsblobprodsu6weu.vsblob.visualstudio.com/Ad7b6fe08-347e-4cca-91fb-d5c313d16196/","X_TFS_Session":"a86db722-8664-45cc-9092-3b6564825b60","DeploymentEnvironment":"PRODUCTION","DeploymentEnvironmentIsProduction":"True","VSOAccount":"vsblobprodsu6weu","OSName":"Linux","OSVersion":"2020","FrameworkDescription":".NET Core ","ProcessName":"Agent.PluginHost","DotNetReleaseDword":"-1","Version":"18.169.30119.0","ExceptionCount":"0"}
2020-08-12T11:42:04.5538630Z Cache restored.
2020-08-12T11:42:04.5540163Z ##[debug]Processed: ##vso[task.setvariable variable=PULUMI_NODE_CACHE_RESTORED;issecret=False;]true
2020-08-12T11:42:04.5540788Z Verbose, ApplicationInsightsTelemetrySender waiting for 0 of 2 TrackEvent operations to complete...
2020-08-12T11:42:05.7496500Z Verbose, ApplicationInsightsTelemetrySender sent PipelineCache.DownloadAsync telemetry
2020-08-12T11:42:05.7496996Z Verbose, ApplicationInsightsTelemetrySender operations completed in 1260 ms
2020-08-12T11:42:05.7498152Z Information, ApplicationInsightsTelemetrySender correlated 2 events with X-TFS-Session a86db722-8664-45cc-9092-3b6564825b60
2020-08-12T11:42:05.7498578Z Verbose, Stopped ITelemetrySender BlobStoreApplicationInsightsTelemetrySender.
2020-08-12T11:42:05.7632583Z ##[section]Finishing: Restore npm cache

About this issue

Original URL
State: closed
Created 4 years ago
Reactions: 7
Comments: 23 (3 by maintainers)

Most upvoted comments

Hitting the same problem. We tend to use deployment due environments, so we can have traceability and other checks. Looks that Cache task is not supported when using deployments (eg, “release” pipelines) in YAML.

@vtbassmatt, team, what would be a path forward here?

avishnyakov on Feb 1, 2021

I have a theory that the cache task does not work in a deployment job unless there is a cache task in an earlier non-deployment job using the same key within the pipeline.

aholthagerty on Apr 25, 2022

never give up 😐

cforce on Oct 27, 2022