Cache misses when launching through Add-AppPackage on Windows

[JanisErdmanis]

I have been grappling with the intricacies of the cache relocability fix in julia-1.11 for AppBundler, particularly in my attempts to include the pkgimages in the bundle. While I've succeeded with MacOS and Linux snap bundles, but the journey has been arduous on Windows with MSIX packaging.

I have a PowerShell launch script that can run it as:

$JULIA="$PSScriptRoot\julia\bin\julia.exe"
& $JULIA --startup-file=no "$PSScriptRoot\main.jl"

where the main.jl file sets up LOAD_PATH and DEPOT_PATH and launches the application itself. Before that, a cache is generated in a bundle directory with a separate precompile.ps1 script. I have tested that moving the bundle around keeps the cache valid and is reused when loading the app.

When running adding package with Add-AppPackage -register MyApp\AppxManifest.xml where the relevant part is under Application tag:

<Application EntryPoint="Windows.FullTrustApplication" 
		 Executable="julia\bin\julia.exe" 
		 Id="{{APP_NAME}}" 
		 uap10:RuntimeBehavior="packagedClassicApp" 
		 uap10:Subsystem="windows" 
		 uap10:SupportsMultipleInstances="true" 
		 uap10:TrustLevel="mediumIL"
		 uap11:Parameters="--startup-file=no --eval=&quot;include(joinpath(dirname(dirname(Sys.BINDIR)), \&quot;main.jl\&quot;)) &quot;">

With this configuration, I get some cache misses when I launch the application from the Start menu. Furthermore, the cache fails to recompile, as can be seen from the logs:

┌ Warning: The call to compilecache failed to create a usable precompiled cache file for HTTP [cd3eb016-35fb-5094-929b-558a96fad6f3]
│   exception = nothing
└ @ Base loading.jl:2407
┌ Debug: Aborting `create_expr_cache'
│   exception =
│    Declaration of __precompile__(false) not allowed
│    Stacktrace:
│      [1] _require(pkg::Base.PkgId, env::String)
│        @ Base .\loading.jl:2414
│      [2] __require_prelocked(uuidkey::Base.PkgId, env::String)
│        @ Base .\loading.jl:2217
│      [3] #invoke_in_world#3
│        @ .\essentials.jl:1065 [inlined]
│      [4] invoke_in_world
│        @ .\essentials.jl:1062 [inlined]
│      [5] _require_prelocked(uuidkey::Base.PkgId, env::String)
│        @ Base .\loading.jl:2208
│      [6] macro expansion
│        @ .\loading.jl:2148 [inlined]
│      [7] macro expansion
│        @ .\lock.jl:273 [inlined]
│      [8] __require(into::Module, mod::Symbol)
│        @ Base .\loading.jl:2105
│      [9] #invoke_in_world#3
│        @ .\essentials.jl:1065 [inlined]
│     [10] invoke_in_world
│        @ .\essentials.jl:1062 [inlined]
│     [11] require(into::Module, mod::Symbol)
│        @ Base .\loading.jl:2098
│     [12] include(mod::Module, _path::String)
│        @ Base .\Base.jl:558
│     [13] include(x::String)
│        @ PeaceFounder C:\Users\jerdmanis\Desktop\BuildDir\peacefounder-0.1.0-x64\packages\PeaceFounder\src\PeaceFounder.jl:1
│     [14] top-level scope
│        @ C:\Users\jerdmanis\Desktop\BuildDir\peacefounder-0.1.0-x64\packages\PeaceFounder\src\PeaceFounder.jl:23
│     [15] include
│        @ .\Base.jl:558 [inlined]
│     [16] include_package_for_output(pkg::Base.PkgId, input::String, depot_path::Vector{String}, dl_load_path::Vector{String}, load_path::Vector{String}, concrete_deps::Vector{Pair{Base.PkgId, UInt128}}, source::String)
│        @ Base .\loading.jl:2721
│     [17] top-level scope
│        @ stdin:4
│     [18] eval
│        @ .\boot.jl:428 [inlined]
│     [19] include_string(mapexpr::typeof(identity), mod::Module, code::String, filename::String)
│        @ Base .\loading.jl:2543
│     [20] include_string
│        @ .\loading.jl:2553 [inlined]
│     [21] exec_options(opts::Base.JLOptions)
│        @ Base .\client.jl:316
│     [22] _start()
│        @ Base .\client.jl:526
└ @ Base loading.jl:2724

The logs for launching using JULIA_DEBUG=loading are available in a gist.

[fatteneder]

Did you insert the depot with the new caches as the first one in DEPOT_PATH?

Did you insert the depot at the start or end of DEPOT_PATH?
Could you check if it makes a difference where you insert it?

[JanisErdmanis]

The first entry of DEPOT_PATH is an empty directory. The second one is precompiled caches. The DEPOT_PATH is constructed in the same main.jl script, which works fine when launched with the PowerShell script. The relevant parts from main.jl are:

popfirst!(DEPOT_PATH)
pushfirst!(DEPOT_PATH, @__DIR__) # This is a location for the precompilation cache that needs to be loaded
pushfirst!(DEPOT_PATH, joinpath(ENV["USER_DATA"], "cache"))
ENV["JULIA_DEPOT_PATH"] = join(DEPOT_PATH, ";")

pushfirst!(LOAD_PATH, @__DIR__) # Needed for the app
pushfirst!(LOAD_PATH, joinpath(@__DIR__, "packages"))
ENV["JULIA_LOAD_PATH"] = join(LOAD_PATH, ";")

[JanisErdmanis]

Part of the issue seems to come from having @ in LOAD_PATH. I will try to set up LOAD_PATH and DEPOT_PATH starting wtih empty!.

[JanisErdmanis]

Now, the Add-AppPackage issues are resolved using the following LOAD_PATH and DEPOT_PATH setup:

Base.ACTIVE_PROJECT[] = joinpath(@__DIR__, ENV["APP_NAME"])

empty!(LOAD_PATH)
append!(LOAD_PATH, [
    joinpath(@__DIR__, "packages"),
    "@",
    "@stdlib"
])

empty!(DEPOT_PATH)
append!(DEPOT_PATH, [
    joinpath(ENV["USER_DATA"], "cache"),
    @__DIR__
])

However, when installed from msix, I get cache misses due to mtime being changed:

User data directory: C:\Users\jerdmanis\AppData\Local\Packages\org.peacefounder.client_s0by06ay2112j\LocalState
DEPOT_PATH:
        C:\Users\jerdmanis\AppData\Local\Packages\org.peacefounder.client_s0by06ay2112j\LocalState\cache
        C:\Program Files\WindowsApps\org.peacefounder.client_0.1.0.0_neutral__s0by06ay2112j
LOAD_PATH:
        C:\Program Files\WindowsApps\org.peacefounder.client_0.1.0.0_neutral__s0by06ay2112j\packages
        @
        @stdlib
[ Info: Loading startup modules
┌ Debug: Rejecting stale cache file C:\Program Files\WindowsApps\org.peacefounder.client_0.1.0.0_neutral__s0by06ay2112j\compiled\v1.11\ConstructionBase\sBbW6_ZLuUt.ji because mtime of include_dependency C:\Program Files\WindowsApps\org.peacefounder.client_0.1.0.0_neutral__s0by06ay2112j\packages\ConstructionBase\README.md has changed (mtime 1.7194947857526646e9, before 1.71948844e9)
└ @ Base loading.jl:3721
┌ Debug: Rejecting cache file C:\Program Files\WindowsApps\org.peacefounder.client_0.1.0.0_neutral__s0by06ay2112j\compiled\v1.11\PeaceFounderClient\dHRJx_ZLuUt.ji because required dependency Base.PkgId(Base.UUID("187b0558-2788-49d3-abe0-74a17ed4e7c9"), "ConstructionBase") with build ID fafbfcfd-6ea8-c2ab-0000-01399ef913c5 is missing from the cache.
└ @ Base loading.jl:1865
┌ Debug: Rejecting stale cache file C:\Program Files\WindowsApps\org.peacefounder.client_0.1.0.0_neutral__s0by06ay2112j\compiled\v1.11\ConstructionBase\sBbW6_ZLuUt.ji because mtime of include_dependency C:\Program Files\WindowsApps\org.peacefounder.client_0.1.0.0_neutral__s0by06ay2112j\packages\ConstructionBase\README.md has changed (mtime 1.7194947857526646e9, before 1.71948844e9)
└ @ Base loading.jl:3721
┌ Debug: Rejecting stale cache file C:\Program Files\WindowsApps\org.peacefounder.client_0.1.0.0_neutral__s0by06ay2112j\compiled\v1.11\Infiltrator\ge3PS_ZLuUt.ji because mtime of include_dependency C:\Program Files\WindowsApps\org.peacefounder.client_0.1.0.0_neutral__s0by06ay2112j\packages\Infiltrator\README.md has changed (mtime 1.7194947866892085e9, before 1.71948844e9)
└ @ Base loading.jl:3721
┌ Debug: Rejecting stale cache file C:\Program Files\WindowsApps\org.peacefounder.client_0.1.0.0_neutral__s0by06ay2112j\compiled\v1.11\ExceptionUnwrapping\DKnWN_ZLuUt.ji because mtime of include_dependency C:\Program Files\WindowsApps\org.peacefounder.client_0.1.0.0_neutral__s0by06ay2112j\packages\ExceptionUnwrapping\README.md has changed (mtime 1.719494786282999e9, before 1.719488442e9)
└ @ Base loading.jl:3721
Precompiling PeaceFounderClient...┌ Debug: Rejecting stale cache file C:\Program Files\WindowsApps\org.peacefounder.client_0.1.0.0_neutral__s0by06ay2112j\compiled\v1.11\CxxWrap\WGIJU_ZLuUt.ji because mtime of include_dependency C:\Program Files\WindowsApps\org.peacefounder.client_0.1.0.0_neutral__s0by06ay2112j\artifacts\aa1909b98a44e20f201a871d5b4ce07a2010b7eb\bin\libcxxwrap_julia_stl.dll has changed (mtime 1.7194947413766532e9, before 1.719488444e9)
└ @ Base loading.jl:3721

The full log file is available in https://gist.github.com/JanisErdmanis/308c1a65ed7f065af69e60a5502ce5f7

[JanisErdmanis]

The last issue is fixed with added ensure_track_content utility function that with regex replaces include_dependency that has track_content=true.