Skip to content

zero cache hit rates from consumer when xcodebuild archive #202

@OliverKoo

Description

@OliverKoo

My integration setup
Automatic integration using xcprepare integrate ...

Expected/desired behavior
some cache hit rate from consumer build when run xcremotecache/xcprepare stats

Minimal reproduction of the problem with instructions
just to give some context first to help debugging. I am on okoo/xcremotecache branch, which is 4 commits ahead of master. below is git log output

9ba305ba94d (HEAD -> okoo/xcremotecache, origin/okoo/xcremotecache) debug
f4d74d88292 test consumer mode
29c6a994cd2 fix lint
9cc03240428 XCRemoteCache init commit
c40599015cc (origin/master, origin/HEAD, master)

I am using an S3 as my cache server, here are the marker files in s3
Screenshot 2023-05-04 at 12 18 41 PM

As you can see I have done some producer builds locally. I then set up our CI machine to do a consumer builds on commit 9ba305b which have been published and marked in S3.

I have CI print out cache hit rates after the build and I see 0 hit which is quite weird.

+ xcremotecache/xcprepare stats
--
  | hit_count: 0
  | miss_count: 0
  | local_cache_bytes: 109490176
  | indexing_hit_count: 0
  | indexing_miss_count: 0

Here is a snippet of my network log on CI (I don't see anything suspicious):

023-05-04 07:43:29.106 E  xcprebuild[37658:6b69d] (SocketRocket) Couldn't verify if should disable RC for c40599015ccacf0113a5541b14958d7a3edfe1e3.
--
  | 2023-05-04 07:43:29.106 E  xcprebuild[37660:6b6a3] (SPUserResizableView) Couldn't verify if should disable RC for c40599015ccacf0113a5541b14958d7a3edfe1e3.
  | 2023-05-04 07:43:29.110 I  xcprebuild[37660:6b6a3] (SPUserResizableView) Found url to remapp: file:///Users/buildkite-agent/Library/Developer/Xcode/DerivedData/MyAppXcodegen-apsetnqeojpzqbfmmuxlqxqvsdpb/Build/Intermediates.noindex/ArchiveIntermediates/MyAppEnterprise/BuildProductsPath/. Remapping: /Users/buildkite-agent/Library/Developer/Xcode/DerivedData/MyAppXcodegen-apsetnqeojpzqbfmmuxlqxqvsdpb/Build/Intermediates.noindex/ArchiveIntermediates/MyAppEnterprise/BuildProductsPath
  | 2023-05-04 07:43:29.110 I  xcprebuild[37658:6b69d] (SocketRocket) Found url to remapp: file:///Users/buildkite-agent/Library/Developer/Xcode/DerivedData/MyAppXcodegen-apsetnqeojpzqbfmmuxlqxqvsdpb/Build/Intermediates.noindex/ArchiveIntermediates/MyAppEnterprise/BuildProductsPath/. Remapping: /Users/buildkite-agent/Library/Developer/Xcode/DerivedData/MyAppXcodegen-apsetnqeojpzqbfmmuxlqxqvsdpb/Build/Intermediates.noindex/ArchiveIntermediates/MyAppEnterprise/BuildProductsPath
  | 2023-05-04 07:43:29.110 I  xcprebuild[37660:6b6a3] (SPUserResizableView) Found url to remapp: file:///opt/homebrew/var/buildkite-agent/builds/ios-staging-agent-queue-i-0f47d16fe9ce8187c-1672/MyApp/oliver-ios-fast-build/. Remapping: /opt/homebrew/var/buildkite-agent/builds/ios-staging-agent-queue-i-0f47d16fe9ce8187c-1672/MyApp/oliver-ios-fast-build
  | 2023-05-04 07:43:29.110 I  xcprebuild[37658:6b69d] (SocketRocket) Found url to remapp: file:///opt/homebrew/var/buildkite-agent/builds/ios-staging-agent-queue-i-0f47d16fe9ce8187c-1672/MyApp/oliver-ios-fast-build/. Remapping: /opt/homebrew/var/buildkite-agent/builds/ios-staging-agent-queue-i-0f47d16fe9ce8187c-1672/MyApp/oliver-ios-fast-build
  | 2023-05-04 07:43:29.111 E  xcprebuild[37662:6b6ab] (XMLCoder) Couldn't verify if should disable RC for c40599015ccacf0113a5541b14958d7a3edfe1e3.
  | 2023-05-04 07:43:29.113 I  xcprebuild[37662:6b6ab] (XMLCoder) Found url to remapp: file:///Users/buildkite-agent/Library/Developer/Xcode/DerivedData/MyAppXcodegen-apsetnqeojpzqbfmmuxlqxqvsdpb/Build/Intermediates.noindex/ArchiveIntermediates/MyAppEnterprise/BuildProductsPath/. Remapping: /Users/buildkite-agent/Library/Developer/Xcode/DerivedData/MyAppXcodegen-apsetnqeojpzqbfmmuxlqxqvsdpb/Build/Intermediates.noindex/ArchiveIntermediates/MyAppEnterprise/BuildProductsPath
  | 2023-05-04 07:43:29.113 I  xcprebuild[37662:6b6ab] (XMLCoder) Found url to remapp: file:///opt/homebrew/var/buildkite-agent/builds/ios-staging-agent-queue-i-0f47d16fe9ce8187c-1672/MyApp/oliver-ios-fast-build/. Remapping: /opt/homebrew/var/buildkite-agent/builds/ios-staging-agent-queue-i-0f47d16fe9ce8187c-1672/MyApp/oliver-ios-fast-build

I do see 2 occurrences of this type of error in the 10 minute network log window

2023-05-04 07:45:04.381 E  xcprebuild[42937:6f5c1] (PINAVVideoPlayerBridge) Prebuild step failed with error: missingFile(file:///Users/buildkite-agent/Library/Developer/Xcode/DerivedData/MyAppXcodegen-apsetnqeojpzqbfmmuxlqxqvsdpb/Build/Intermediates.noindex/ArchiveIntermediates/MyAppEnterprise/BuildProductsPath/Release-iphoneos/VideoPlayerCommonBridge.framework/Headers/VideoPlayerCommonBridge-Swift.h.md5)

but my assumption is that I should still get some cache hit.

I did some investigation - following "Trouble shooting cache misses" list from this PR https://github.com/spotify/XCRemoteCache/pull/93/files. such as checking the consumer logs at ~/Library/Caches/XCRemoteCache/{your_host_path}/meta/*.json are not abs path. CI and local are on the same arch (M1). Ci is also for sure in consumer mode. I printed out user.rcinfo

xccc_file: /opt/homebrew/var/buildkite-agent/builds/ios-staging-agent-queue-i-0f47d16fe9ce8187c-1672/myorg/oliver-ios-fast-build/xcremotecache/xccc
recommended_cache_address: https://myorg-ios-cache-staging.s3.us-east-1.amazonaws.com/
mode: consumer

To eliminate the potential issue causing by our CI environment, I tried building locally too on master commit c40599015cc. and same thing I have 0 cache hit.

023-05-04 11:39:29.384 E  xcprebuild[17130:9fcfa7] (MyAppEnterprise) Couldn't verify if should disable RC for c40599015ccacf0113a5541b14958d7a3edfe1e3.
2023-05-04 11:39:29.388 I  xcprebuild[17130:9fcfa7] (MyAppEnterprise) Found url to remapp: file:///Users/okoo/Library/Developer/Xcode/DerivedData/MyAppXcodegen-exwneyqxzopphodwxkfkatpczygl/Build/Intermediates.noindex/ArchiveIntermediates/MyAppEnterprise/BuildProductsPath/. Remapping: /Users/okoo/Library/Developer/Xcode/DerivedData/MyAppXcodegen-exwneyqxzopphodwxkfkatpczygl/Build/Intermediates.noindex/ArchiveIntermediates/MyAppEnterprise/BuildProductsPath
2023-05-04 11:39:29.388 I  xcprebuild[17130:9fcfa7] (MyAppEnterprise) Found url to remapp: file:///Users/okoo/Code/ios2/. Remapping: /Users/okoo/Code/ios2
2023-05-04 11:39:29.391 I  xcprebuild[17130:9fcfa7] (MyAppEnterprise) Making request https://MyApp-ios-cache-staging.s3.us-east-1.amazonaws.com/meta/c40599015ccacf0113a5541b14958d7a3edfe1e3-MyAppEnterprise-Release-iphoneos-14C18-be8fa8ae2f9ec27711df54eb2f59f26f.json
2023-05-04 11:40:03.257 I  xcprebuild[17130:9fcfa7] (MyAppEnterprise) Downloading artifact to file:///Users/okoo/Library/Developer/Xcode/DerivedData/MyAppXcodegen-exwneyqxzopphodwxkfkatpczygl/Build/Intermediates.noindex/ArchiveIntermediates/MyAppEnterprise/IntermediateBuildFilesPath/MyAppXcodegen.build/Release-iphoneos/MyAppEnterprise.build/xccache/6125600ffbc049e55292f0588e445df9.zip
2023-05-04 11:42:16.751 I  xcprebuild[17130:9fcfa7] (MyAppEnterprise) Artifact unzipped to file:///Users/okoo/Library/Developer/Xcode/DerivedData/MyAppXcodegen-exwneyqxzopphodwxkfkatpczygl/Build/Intermediates.noindex/ArchiveIntermediates/MyAppEnterprise/IntermediateBuildFilesPath/MyAppXcodegen.build/Release-iphoneos/MyAppEnterprise.build/xccache/6125600ffbc049e55292f0588e445df9
2023-05-04 11:46:43.999 I  xcpostbuild[25377:a00e5b] (MyAppEnterprise) Found url to remapp: file:///Users/okoo/Library/Developer/Xcode/DerivedData/MyAppXcodegen-exwneyqxzopphodwxkfkatpczygl/Build/Intermediates.noindex/ArchiveIntermediates/MyAppEnterprise/BuildProductsPath/. Remapping: /Users/okoo/Library/Developer/Xcode/DerivedData/MyAppXcodegen-exwneyqxzopphodwxkfkatpczygl/Build/Intermediates.noindex/ArchiveIntermediates/MyAppEnterprise/BuildProductsPath
2023-05-04 11:46:44.000 I  xcpostbuild[25377:a00e5b] (MyAppEnterprise) Found url to remapp: file:///Users/okoo/Code/ios2/. Remapping: /Users/okoo/Code/ios2

even building commit 9ba305ba on branch okoo/xcremotecache locally is not getting any cache hit

➜  /Users/okoo/Code/ios2 git:(okoo/xcremotecache) ✗ git rev-parse head                                                                    
9ba305ba94d5022fa2808adf4dce7dc42bb8052d
➜  /Users/okoo/Code/ios2 git:(okoo/xcremotecache) ✗ log show --predicate 'sender BEGINSWITH "xc"' --style compact --info --debug -last 1m 
Filtering the log data using "sender BEGINSWITH "xc""
Timestamp               Ty Process[PID:TID]
2023-05-04 12:45:44.586 E  xcprebuild[64625:a22c1c] (MyTooltipExperienceTests) Couldn't verify if should disable RC for c40599015ccacf0113a5541b14958d7a3edfe1e3.
2023-05-04 12:45:44.590 I  xcprebuild[64625:a22c1c] (MyTooltipExperienceTests) Found url to remapp: file:///Users/okoo/Library/Developer/Xcode/DerivedData/myappXcodegen-exwneyqxzopphodwxkfkatpczygl/Index.noindex/Build/Products/. RemapMyg: /Users/okoo/Library/Developer/Xcode/DerivedData/myappXcodegen-exwneyqxzopphodwxkfkatpczygl/Index.noindex/Build/Products
2023-05-04 12:45:44.590 I  xcprebuild[64625:a22c1c] (MyTooltipExperienceTests) Found url to remapp: file:///Users/okoo/Code/ios2/. RemapMyg: /Users/okoo/Code/ios2
2023-05-04 12:45:44.592 I  xcprebuild[64625:a22c1c] (MyTooltipExperienceTests) Making request https://myapp-ios-cache-staging.s3.us-east-1.amazonaws.com/meta/c40599015ccacf0113a5541b14958d7a3edfe1e3-MyTooltipExperienceTests-Debug-iphonesimulator-14C18-8c53e3ff645321f1ba6188c37c057c02.json
2023-05-04 12:45:45.147 I  xcprebuild[64625:a22c1f] (MyTooltipExperienceTests) Network request failed with unsuccessful code 404
2023-05-04 12:45:45.147 E  xcprebuild[64625:a22c1c] (MyTooltipExperienceTests) Prebuild step failed with error: unsuccessfulResponse(status: 404)
2023-05-04 12:45:55.457 E  xcprebuild[64663:a22d67] (MyAVVideoPlayerBridgeTests) Couldn't verify if should disable RC for c40599015ccacf0113a5541b14958d7a3edfe1e3.
2023-05-04 12:45:55.460 I  xcprebuild[64663:a22d67] (MyAVVideoPlayerBridgeTests) Found url to remapp: file:///Users/okoo/Library/Developer/Xcode/DerivedData/myappXcodegen-exwneyqxzopphodwxkfkatpczygl/Index.noindex/Build/Products/. RemapMyg: /Users/okoo/Library/Developer/Xcode/DerivedData/myappXcodegen-exwneyqxzopphodwxkfkatpczygl/Index.noindex/Build/Products
2023-05-04 12:45:55.460 I  xcprebuild[64663:a22d67] (MyAVVideoPlayerBridgeTests) Found url to remapp: file:///Users/okoo/Code/ios2/. RemapMyg: /Users/okoo/Code/ios2
2023-05-04 12:45:55.462 I  xcprebuild[64663:a22d67] (MyAVVideoPlayerBridgeTests) Making request https://myapp-ios-cache-staging.s3.us-east-1.amazonaws.com/meta/c40599015ccacf0113a5541b14958d7a3edfe1e3-MyAVVideoPlayerBridgeTests-Debug-iphonesimulator-14C18-d456ff1952b0a156ee1c94b525aaa28c.json
2023-05-04 12:45:56.368 I  xcprebuild[64663:a22d68] (MyAVVideoPlayerBridgeTests) Network request failed with unsuccessful code 404
2023-05-04 12:45:56.370 E  xcprebuild[64663:a22d67] (MyAVVideoPlayerBridgeTests) Prebuild step failed with error: unsuccessfulResponse(status: 404)
2023-05-04 12:46:00.946 E  xcprebuild[64696:a22e16] (MyInterestModelConstantsTests) Couldn't verify if should disable RC for c40599015ccacf0113a5541b14958d7a3edfe1e3.
2023-05-04 12:46:00.949 I  xcprebuild[64696:a22e16] (MyInterestModelConstantsTests) Found url to remapp: file:///Users/okoo/Library/Developer/Xcode/DerivedData/myappXcodegen-exwneyqxzopphodwxkfkatpczygl/Index.noindex/Build/Products/. RemapMyg: /Users/okoo/Library/Developer/Xcode/DerivedData/myappXcodegen-exwneyqxzopphodwxkfkatpczygl/Index.noindex/Build/Products
2023-05-04 12:46:00.949 I  xcprebuild[64696:a22e16] (MyInterestModelConstantsTests) Found url to remapp: file:///Users/okoo/Code/ios2/. RemapMyg: /Users/okoo/Code/ios2
2023-05-04 12:46:00.951 I  xcprebuild[64696:a22e16] (MyInterestModelConstantsTests) Making request https://myapp-ios-cache-staging.s3.us-east-1.amazonaws.com/meta/c40599015ccacf0113a5541b14958d7a3edfe1e3-MyInterestModelConstantsTests-Debug-iphonesimulator-14C18-e18914f406199edbcbe44a97fd5776bc.json
2023-05-04 12:46:01.470 I  xcprebuild[64696:a22e18] (MyInterestModelConstantsTests) Network request failed with unsuccessful code 404
2023-05-04 12:46:01.470 E  xcprebuild[64696:a22e16] (MyInterestModelConstantsTests) Prebuild step failed with error: unsuccessfulResponse(status: 404)

I know XCRemoteCache was working at some points, I remember my stats at one points shows non zero cache hits. I am guessing maybe I don't have my set up done correctly?

  • XCRemoteCache: 0.3.23
  • HTTP cache server: AWS s3
  • Xcode: 14.2

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type
    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions