Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Doesn't seem to be properly cache busting when cross project dependencies change. #6193

Open
erlandsona opened this issue Jul 19, 2023 · 25 comments

Comments

@erlandsona
Copy link

Stack doesn't seem to be properly cache busting when cross project dependencies change.

Steps to reproduce

Example:
$project_root/stack.yaml

resolver: lts-21.2

packages:
- common
- db
- web

$project_root/common/package.yaml

# standard stuff
library:
  dependencies: # only 3rd party libs
  - aeson
  - bytestring
  # etc...

$project_root/db/package.yaml

# standard stuff
library:
  dependencies:
  # 3rd party libs.
  - mysql2
  # local dependencies.
  - common

$project_root/web/package.yaml

# standard stuff
library:
  dependencies:
  # 3rd party libs.
  - mysql2
  # local dependencies.
  - common
  - db

Expected

When a change is made to common or db those changes buste the cache of web such that web is recompiled with the latest changes from it's dependencies.

Actual

web seems to be stuck recompiling with stale cached data such that changes in common / db aren't propagating properly.

If you suspect that a Stack command misbehaved, please include the output of
that command in --verbose mode. If the output is larger than a page please
paste the output in a Gist.

stack install :web --verbose --color=always --fast --docker --local-bin-path ./dockerbin
Version 2.11.1, Git revision c1167a6abc3f4978ccded5ba0246a57387da0e2f x86_64 hpack-0.35.2
2023-07-19 12:06:39.322565: [debug] Checking for project config at: ~/code/project/stack.yaml
2023-07-19 12:06:39.322742: [debug] Loading project config file stack.yaml
2023-07-19 12:06:39.332394: [debug] (SQL) SELECT COUNT(*) FROM "last_performed" WHERE ("action"=?) AND ("timestamp">=?); [PersistInt64 1,PersistUTCTime 2023-07-18 17:06:39.332369826 UTC]
2023-07-19 12:06:39.332804: [debug] Run process: /usr/bin/docker --version
2023-07-19 12:06:39.346076: [debug] Process finished in 13ms: /usr/bin/docker --version
2023-07-19 12:06:39.346285: [debug] Run process: /usr/bin/docker inspect 1234.dkr.ecr.us-east-1.amazonaws.com/company-stack-build:lts21-v1-master
2023-07-19 12:06:39.360463: [debug] Process finished in 14ms: /usr/bin/docker inspect 1234.dkr.ecr.us-east-1.amazonaws.com/company-stack-build:lts21-v1-master
2023-07-19 12:06:39.361279: [debug] (SQL) SELECT "id","image_hash","exe_path","exe_timestamp","compatible" FROM "docker_image_exe_cache" WHERE "image_hash"=? AND "exe_path"=? AND "exe_timestamp"=?; [PersistText "sha256:48ee25c70cf22c0ac9d1452b5d345f2100a6dfed25701d3c346091a21b498de1",PersistText "~/.ghcup/bin/stack-2.11.1",PersistUTCTime 2023-06-27 21:01:18.568347331 UTC]
2023-07-19 12:06:39.361601: [debug] Run process within ~/code/project/: /usr/bin/docker create -e STACK_IN_CONTAINER=1 -e STACK_ROOT=~/.stack -e STACK_PLATFORM_VARIANT=dk82cbb9627cd086f74148946909b654d7 -e HOME=~/code/project/.stack-work/docker/_home -e PATH=/opt/host/bin:~/code/project/.stack-work/docker/_home/.local/bin:/root/.local/bin:/usr/local/cuda-10.0/bin:/home/stackage/.stack/programs/x86_64-linux/ghc-9.4.5/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin -e PWD=~/code/project -v ~:~ -v ~/.stack:~/.stack -v ~/code/project:~/code/project -v ~/code/project/.stack-work/docker/_home:~/code/project/.stack-work/docker/_home -w ~/code/project --net=host -e USER=erlandsona -e SSH_AUTH_SOCK=/run/user/1001/keyring/ssh -v /run/user/1001/keyring/ssh:/run/user/1001/keyring/ssh -v ~/.ghcup/bin/stack-2.11.1:/opt/host/bin/stack-2.11 -t -i 1234.dkr.ecr.us-east-1.amazonaws.com/company-stack-build:lts21-v1-master /opt/host/bin/stack-2.11 --internal-re-exec-version=2.11.1 --internal-docker-entrypoint "DockerEntrypoint {deUser = Just (DockerUser {duUid = 1001, duGid = 1001, duGroups = [4,24,27,30,46,122,134,137,1001], duUmask = 2})}" install :web --verbose --color=always --fast --docker --local-bin-path ./dockerbin
2023-07-19 12:06:39.389958: [debug] Process finished in 28ms: /usr/bin/docker create -e STACK_IN_CONTAINER=1 -e STACK_ROOT=~/.stack -e STACK_PLATFORM_VARIANT=dk82cbb9627cd086f74148946909b654d7 -e HOME=~/code/project/.stack-work/docker/_home -e PATH=/opt/host/bin:~/code/project/.stack-work/docker/_home/.local/bin:/root/.local/bin:/usr/local/cuda-10.0/bin:/home/stackage/.stack/programs/x86_64-linux/ghc-9.4.5/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin -e PWD=~/code/project -v ~:~ -v ~/.stack:~/.stack -v ~/code/project:~/code/project -v ~/code/project/.stack-work/docker/_home:~/code/project/.stack-work/docker/_home -w ~/code/project --net=host -e USER=erlandsona -e SSH_AUTH_SOCK=/run/user/1001/keyring/ssh -v /run/user/1001/keyring/ssh:/run/user/1001/keyring/ssh -v ~/.ghcup/bin/stack-2.11.1:/opt/host/bin/stack-2.11 -t -i 1234.dkr.ecr.us-east-1.amazonaws.com/company-stack-build:lts21-v1-master /opt/host/bin/stack-2.11 --internal-re-exec-version=2.11.1 --internal-docker-entrypoint "DockerEntrypoint {deUser = Just (DockerUser {duUid = 1001, duGid = 1001, duGroups = [4,24,27,30,46,122,134,137,1001], duUmask = 2})}" install :web --verbose --color=always --fast --docker --local-bin-path ./dockerbin
2023-07-19 12:06:39.390151: [debug] Run process: /usr/bin/docker start -a -i c32b4f73e3f9202e46903935cf0d4cd5f721b3fd6abfd716d7a6c71438438e68
Version 2.11.1, Git revision c1167a6abc3f4978ccded5ba0246a57387da0e2f x86_64 hpack-0.35.2
2023-07-19 17:06:39.515153: [debug] Checking for project config at: ~/code/project/stack.yaml
2023-07-19 17:06:39.515333: [debug] Loading project config file stack.yaml
2023-07-19 17:06:39.523063: [debug] Run process: /usr/sbin/groupadd -o --gid 1001 stack
2023-07-19 17:06:39.530282: [debug] Process finished in 7ms: /usr/sbin/groupadd -o --gid 1001 stack
2023-07-19 17:06:39.530413: [debug] Run process: /usr/sbin/useradd -oN --uid 1001 --gid 1001 --home ~/code/project/.stack-work/docker/_home stack
2023-07-19 17:06:39.541124: [debug] Process finished in 11ms: /usr/sbin/useradd -oN --uid 1001 --gid 1001 --home ~/code/project/.stack-work/docker/_home stack
2023-07-19 17:06:39.541193: [debug] Run process: /usr/sbin/groupadd -o --gid 4 group4
2023-07-19 17:06:39.546710: [debug] Process finished in 5ms: /usr/sbin/groupadd -o --gid 4 group4
2023-07-19 17:06:39.546790: [debug] Run process: /usr/sbin/groupadd -o --gid 24 group24
2023-07-19 17:06:39.551840: [debug] Process finished in 5ms: /usr/sbin/groupadd -o --gid 24 group24
2023-07-19 17:06:39.551906: [debug] Run process: /usr/sbin/groupadd -o --gid 27 group27
2023-07-19 17:06:39.556321: [debug] Process finished in 4ms: /usr/sbin/groupadd -o --gid 27 group27
2023-07-19 17:06:39.556357: [debug] Run process: /usr/sbin/groupadd -o --gid 30 group30
2023-07-19 17:06:39.561734: [debug] Process finished in 5ms: /usr/sbin/groupadd -o --gid 30 group30
2023-07-19 17:06:39.561822: [debug] Run process: /usr/sbin/groupadd -o --gid 46 group46
2023-07-19 17:06:39.566927: [debug] Process finished in 5ms: /usr/sbin/groupadd -o --gid 46 group46
2023-07-19 17:06:39.567008: [debug] Run process: /usr/sbin/groupadd -o --gid 122 group122
2023-07-19 17:06:39.575810: [debug] Process finished in 9ms: /usr/sbin/groupadd -o --gid 122 group122
2023-07-19 17:06:39.575910: [debug] Run process: /usr/sbin/groupadd -o --gid 134 group134
2023-07-19 17:06:39.580965: [debug] Process finished in 5ms: /usr/sbin/groupadd -o --gid 134 group134
2023-07-19 17:06:39.581012: [debug] Run process: /usr/sbin/groupadd -o --gid 137 group137
2023-07-19 17:06:39.585574: [debug] Process finished in 5ms: /usr/sbin/groupadd -o --gid 137 group137
2023-07-19 17:06:39.585638: [debug] Run process: /usr/sbin/groupadd -o --gid 1001 group1001
2023-07-19 17:06:39.590255: [debug] Process finished in 5ms: /usr/sbin/groupadd -o --gid 1001 group1001
2023-07-19 17:06:39.590910: [debug] (SQL) SELECT COUNT(*) FROM "last_performed" WHERE ("action"=?) AND ("timestamp">=?); [PersistInt64 1,PersistUTCTime 2023-07-18 17:06:39.590835774 UTC]
2023-07-19 17:06:39.591372: [debug] Using package location completions from a lock file
2023-07-19 17:06:39.594196: [debug] Loaded snapshot from Pantry database.
2023-07-19 17:06:39.683928: [debug] Running Hpack on ~/code/project/read-service/package.yaml
2023-07-19 17:06:39.687402: [debug] Hpack output unchanged in ~/code/project/read-service/read-service.cabal
2023-07-19 17:06:39.687557: [debug] Running Hpack on ~/code/project/deprecated-proxy-service/package.yaml
2023-07-19 17:06:39.691267: [debug] Hpack output unchanged in ~/code/project/deprecated-proxy-service/deprecated-proxy-service.cabal
2023-07-19 17:06:39.691461: [debug] Running Hpack on ~/code/project/company-common/package.yaml
2023-07-19 17:06:39.693147: [debug] Hpack output unchanged in ~/code/project/company-common/company-common.cabal
2023-07-19 17:06:39.693265: [debug] Running Hpack on ~/code/project/config/package.yaml
2023-07-19 17:06:39.698992: [debug] Hpack output unchanged in ~/code/project/config/config.cabal
2023-07-19 17:06:39.699142: [debug] Running Hpack on ~/code/project/web/package.yaml
2023-07-19 17:06:39.700939: [debug] Hpack output unchanged in ~/code/project/web/web.cabal
2023-07-19 17:06:39.701081: [debug] Prefetching git repos: [(Git repo at git@github.com:Company/company-auth.git, commit 1c1690ed94af8b53f96c2f893828d50ad75fbfa5,RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing}),(Git repo at git@github.com:Company/company-mq.git, commit c8797cde1c9707f349e7296692d8167226e8408d,RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing}),(Git repo at git@github.com:Company/mysql-extras, commit 8904a46a1247402079aa83c88cb5a5ef70af231a,RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing}),(Git repo at git@github.com:company/haskell-sphinx-client, commit 1b66ecdcad9697dec8804300b516e552efca4fab,RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing}),(Git repo at git@github.com:company/custom-yaml-parser.git, commit 69872d770593af1b19a99e33da18cf95d842c238,RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing}),(Git repo at git@github.com:Company/company-mysql.git, commit 5816508a785724036293065730b7566990d9b0a0,RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing}),(Git repo at git@github.com:Company/mysql-json.git, commit 0c574f760493e6f45d4c087c0e7ea57a8051c079,RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing}),(Git repo at git@github.com:Company/sql-excel, commit 064f7cfe0ecd43b014d39417111863421d394a1c,RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing})]
2023-07-19 17:06:39.701166: [debug] [AggregateRepo {aRepo = SimpleRepo {sRepoUrl = "git@github.com:Company/company-auth.git", sRepoCommit = "1c1690ed94af8b53f96c2f893828d50ad75fbfa5", sRepoType = RepoGit}, aRepoSubdirs = [("",RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing})]},AggregateRepo {aRepo = SimpleRepo {sRepoUrl = "git@github.com:Company/company-mq.git", sRepoCommit = "c8797cde1c9707f349e7296692d8167226e8408d", sRepoType = RepoGit}, aRepoSubdirs = [("",RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing})]},AggregateRepo {aRepo = SimpleRepo {sRepoUrl = "git@github.com:Company/mysql-extras", sRepoCommit = "8904a46a1247402079aa83c88cb5a5ef70af231a", sRepoType = RepoGit}, aRepoSubdirs = [("",RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing})]},AggregateRepo {aRepo = SimpleRepo {sRepoUrl = "git@github.com:company/haskell-sphinx-client", sRepoCommit = "1b66ecdcad9697dec8804300b516e552efca4fab", sRepoType = RepoGit}, aRepoSubdirs = [("",RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing})]},AggregateRepo {aRepo = SimpleRepo {sRepoUrl = "git@github.com:company/custom-yaml-parser.git", sRepoCommit = "69872d770593af1b19a99e33da18cf95d842c238", sRepoType = RepoGit}, aRepoSubdirs = [("",RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing})]},AggregateRepo {aRepo = SimpleRepo {sRepoUrl = "git@github.com:Company/company-mysql.git", sRepoCommit = "5816508a785724036293065730b7566990d9b0a0", sRepoType = RepoGit}, aRepoSubdirs = [("",RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing})]},AggregateRepo {aRepo = SimpleRepo {sRepoUrl = "git@github.com:Company/mysql-json.git", sRepoCommit = "0c574f760493e6f45d4c087c0e7ea57a8051c079", sRepoType = RepoGit}, aRepoSubdirs = [("",RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing})]},AggregateRepo {aRepo = SimpleRepo {sRepoUrl = "git@github.com:Company/sql-excel", sRepoCommit = "064f7cfe0ecd43b014d39417111863421d394a1c", sRepoType = RepoGit}, aRepoSubdirs = [("",RawPackageMetadata {rpmName = Nothing, rpmVersion = Nothing, rpmTreeKey = Nothing})]}]
2023-07-19 17:06:39.710374: [debug] Asking for a supported GHC version
2023-07-19 17:06:39.710436: [debug] Getting system compiler version
2023-07-19 17:06:39.711004: [debug] (SQL) SELECT "id","actual_version","arch","ghc_path","ghc_size","ghc_modified","ghc_pkg_path","runghc_path","haddock_path","cabal_version","global_db","global_db_cache_size","global_db_cache_modified","info","global_dump" FROM "compiler_cache" WHERE "ghc_path"=?; [PersistText "/usr/bin/ghc-8.8.4"]
2023-07-19 17:06:39.727517: [debug] Loaded compiler information from cache
2023-07-19 17:06:39.727668: [debug] Not using compiler at "/usr/bin/ghc-8.8.4": PrettyException UnwantedCompilerVersion
2023-07-19 17:06:39.727841: [debug] (SQL) SELECT "id","actual_version","arch","ghc_path","ghc_size","ghc_modified","ghc_pkg_path","runghc_path","haddock_path","cabal_version","global_db","global_db_cache_size","global_db_cache_modified","info","global_dump" FROM "compiler_cache" WHERE "ghc_path"=?; [PersistText "/usr/bin/ghc-8.8.4"]
2023-07-19 17:06:39.744952: [debug] Loaded compiler information from cache
2023-07-19 17:06:39.745094: [debug] Not using compiler at "/usr/bin/ghc-8.8.4": PrettyException UnwantedCompilerVersion
2023-07-19 17:06:39.745236: [debug] Installed tools:
 - ghc-tinfo6-9.4.5
2023-07-19 17:06:39.745380: [debug] Run process: /sbin/ldconfig -p
2023-07-19 17:06:39.746759: [debug] Process finished in 1ms: /sbin/ldconfig -p
2023-07-19 17:06:39.746917: [debug] Run process: /usr/bin/ldd --version
2023-07-19 17:06:39.748339: [debug] Process finished in 1ms: /usr/bin/ldd --version
2023-07-19 17:06:39.748402: [debug] Found shared library libc6 in version: 2.35
2023-07-19 17:06:39.748502: [debug] Did not find shared library libtinfo.so.5
2023-07-19 17:06:39.748519: [debug] Found shared library libtinfo.so.6 in 'ldconfig -p' output
2023-07-19 17:06:39.748540: [debug] Found shared library libncursesw.so.6 in 'ldconfig -p' output
2023-07-19 17:06:39.748555: [debug] Found shared library libgmp.so.10 in 'ldconfig -p' output
2023-07-19 17:06:39.748582: [debug] Did not find shared library libgmp.so.3
2023-07-19 17:06:39.748602: [debug] Potential GHC builds: tinfo6, ncurses6
2023-07-19 17:06:39.748654: [debug] Found already installed GHC builds: tinfo6
2023-07-19 17:06:39.748816: [debug] (SQL) SELECT "id","actual_version","arch","ghc_path","ghc_size","ghc_modified","ghc_pkg_path","runghc_path","haddock_path","cabal_version","global_db","global_db_cache_size","global_db_cache_modified","info","global_dump" FROM "compiler_cache" WHERE "ghc_path"=?; [PersistText "~/.stack/programs/x86_64-linux-dk82cbb9627cd086f74148946909b654d7/ghc-tinfo6-9.4.5/bin/ghc-9.4.5"]
2023-07-19 17:06:39.773485: [debug] Loaded compiler information from cache
2023-07-19 17:06:39.773631: [debug] Asking for a supported GHC version
2023-07-19 17:06:39.773675: [debug] Resolving package entries
2023-07-19 17:06:39.773704: [debug] Parsing the targets
2023-07-19 17:06:39.781840: [debug] Checking flags
2023-07-19 17:06:39.781916: [debug] SourceMap constructed
2023-07-19 17:06:39.785382: [debug] Starting to execute command inside EnvConfig
2023-07-19 17:06:39.785958: [debug] Finding out which packages are already installed
2023-07-19 17:06:39.786042: [debug] Run process: ~/.stack/programs/x86_64-linux-dk82cbb9627cd086f74148946909b654d7/ghc-tinfo6-9.4.5/bin/ghc-pkg-9.4.5 --global --no-user-package-db dump --expand-pkgroot
2023-07-19 17:06:39.818320: [debug] Process finished in 32ms: ~/.stack/programs/x86_64-linux-dk82cbb9627cd086f74148946909b654d7/ghc-tinfo6-9.4.5/bin/ghc-pkg-9.4.5 --global --no-user-package-db dump --expand-pkgroot
2023-07-19 17:06:39.833852: [debug] Run process: ~/.stack/programs/x86_64-linux-dk82cbb9627cd086f74148946909b654d7/ghc-tinfo6-9.4.5/bin/ghc-pkg-9.4.5 --user --no-user-package-db --package-db ~/.stack/snapshots/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/pkgdb dump --expand-pkgroot
2023-07-19 17:06:39.947280: [debug] Process finished in 113ms: ~/.stack/programs/x86_64-linux-dk82cbb9627cd086f74148946909b654d7/ghc-tinfo6-9.4.5/bin/ghc-pkg-9.4.5 --user --no-user-package-db --package-db ~/.stack/snapshots/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/pkgdb dump --expand-pkgroot
2023-07-19 17:06:39.958914: [debug] Run process: ~/.stack/programs/x86_64-linux-dk82cbb9627cd086f74148946909b654d7/ghc-tinfo6-9.4.5/bin/ghc-pkg-9.4.5 --user --no-user-package-db --package-db ~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/pkgdb dump --expand-pkgroot
2023-07-19 17:06:39.980982: [debug] Process finished in 22ms: ~/.stack/programs/x86_64-linux-dk82cbb9627cd086f74148946909b654d7/ghc-tinfo6-9.4.5/bin/ghc-pkg-9.4.5 --user --no-user-package-db --package-db ~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/pkgdb dump --expand-pkgroot
2023-07-19 17:06:39.982024: [debug] Constructing the build plan
2023-07-19 17:06:39.986139: [debug] (SQL) SELECT "id","directory","type","pkg_src","active","path_env_var","haddock" FROM "config_cache" WHERE "directory"=? AND "type"=?; [PersistText "~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/",PersistText "lib:company-common-0.1.0.0-L71r8Ou0mZAEHrytQZayMO"]
2023-07-19 17:06:39.986444: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 586]
2023-07-19 17:06:39.986625: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_no_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 586]
2023-07-19 17:06:39.986935: [debug] (SQL) SELECT "id", "config_cache_id", "ghc_pkg_id" FROM "config_cache_dep" WHERE ("config_cache_id"=?); [PersistInt64 586]
2023-07-19 17:06:39.987143: [debug] (SQL) SELECT "id", "config_cache_id", "component" FROM "config_cache_component" WHERE ("config_cache_id"=?); [PersistInt64 586]
2023-07-19 17:06:39.987496: [debug] Start: getPackageFiles ~/code/project/company-common/company-common.cabal
2023-07-19 17:06:39.991472: [debug] Finished in 4ms: getPackageFiles ~/code/project/company-common/company-common.cabal
2023-07-19 17:06:39.992384: [debug] (SQL) SELECT "id","directory","type","pkg_src","active","path_env_var","haddock" FROM "config_cache" WHERE "directory"=? AND "type"=?; [PersistText "~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/",PersistText "lib:read-service-0.1.0.0-IMhJJpDYdel26Vxqu5bg9X"]
2023-07-19 17:06:39.992637: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 594]
2023-07-19 17:06:39.992814: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_no_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 594]
2023-07-19 17:06:39.993466: [debug] (SQL) SELECT "id", "config_cache_id", "ghc_pkg_id" FROM "config_cache_dep" WHERE ("config_cache_id"=?); [PersistInt64 594]
2023-07-19 17:06:39.994301: [debug] (SQL) SELECT "id", "config_cache_id", "component" FROM "config_cache_component" WHERE ("config_cache_id"=?); [PersistInt64 594]
2023-07-19 17:06:39.994964: [debug] Start: getPackageFiles ~/code/project/read-service/read-service.cabal
2023-07-19 17:06:40.045863: [debug] Finished in 51ms: getPackageFiles ~/code/project/read-service/read-service.cabal
2023-07-19 17:06:40.245520: [debug] (SQL) SELECT "id","directory","type","pkg_src","active","path_env_var","haddock" FROM "config_cache" WHERE "directory"=? AND "type"=?; [PersistText "~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/",PersistText "lib:config-0.1.0.0-1cwf10xWyIXL47ARIUuTfb"]
2023-07-19 17:06:40.245727: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 593]
2023-07-19 17:06:40.245840: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_no_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 593]
2023-07-19 17:06:40.246032: [debug] (SQL) SELECT "id", "config_cache_id", "ghc_pkg_id" FROM "config_cache_dep" WHERE ("config_cache_id"=?); [PersistInt64 593]
2023-07-19 17:06:40.246200: [debug] (SQL) SELECT "id", "config_cache_id", "component" FROM "config_cache_component" WHERE ("config_cache_id"=?); [PersistInt64 593]
2023-07-19 17:06:40.246773: [debug] Start: getPackageFiles ~/code/project/config/config.cabal
2023-07-19 17:06:40.251859: [debug] Finished in 5ms: getPackageFiles ~/code/project/config/config.cabal
2023-07-19 17:06:40.386587: [debug] Checking if we are going to build multiple executables with the same name
2023-07-19 17:06:40.386714: [debug] Executing the build plan
2023-07-19 17:06:40.387178: [info] config-0.1.0.0: unregistering (local file changes: src/Root/Config/Views.hs)
2023-07-19 17:06:40.387239: [info] web-0.1.0.0: unregistering (missing dependencies: config, deprecated-proxy-service)
2023-07-19 17:06:40.387258: [info] deprecated-proxy-service-0.1.0.0: unregistering (missing dependencies: config)
2023-07-19 17:06:40.387309: [debug] Run process: ~/.stack/programs/x86_64-linux-dk82cbb9627cd086f74148946909b654d7/ghc-tinfo6-9.4.5/bin/ghc-pkg-9.4.5 --no-user-package-db --package-db=~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/pkgdb/ unregister --user --force --ipid config-0.1.0.0-1cwf10xWyIXL47ARIUuTfb web-0.1.0.0-LZETDQIEunuCZmoJL06wUk deprecated-proxy-service-0.1.0.0-FwGIz8sBJEHEMrLOjUyTzP
2023-07-19 17:06:40.418054: [debug] Process finished in 31ms: ~/.stack/programs/x86_64-linux-dk82cbb9627cd086f74148946909b654d7/ghc-tinfo6-9.4.5/bin/ghc-pkg-9.4.5 --no-user-package-db --package-db=~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/pkgdb/ unregister --user --force --ipid config-0.1.0.0-1cwf10xWyIXL47ARIUuTfb web-0.1.0.0-LZETDQIEunuCZmoJL06wUk deprecated-proxy-service-0.1.0.0-FwGIz8sBJEHEMrLOjUyTzP
2023-07-19 17:06:40.418641: [debug] (SQL) SELECT "id","directory","type","pkg_src","active","path_env_var","haddock" FROM "config_cache" WHERE "directory"=? AND "type"=?; [PersistText "~/code/project/config/",PersistText "config"]
2023-07-19 17:06:40.418768: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 294]
2023-07-19 17:06:40.418923: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_no_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 294]
2023-07-19 17:06:40.419142: [debug] (SQL) SELECT "id", "config_cache_id", "ghc_pkg_id" FROM "config_cache_dep" WHERE ("config_cache_id"=?); [PersistInt64 294]
2023-07-19 17:06:40.419656: [debug] (SQL) SELECT "id", "config_cache_id", "component" FROM "config_cache_component" WHERE ("config_cache_id"=?); [PersistInt64 294]
2023-07-19 17:06:40.420618: [info] config> build (lib)
2023-07-19 17:06:40.420741: [debug] Run process within ~/code/project/config/: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 build lib:config --ghc-options " -fdiagnostics-color=always"
2023-07-19 17:06:40.490817: [info] config> Preprocessing library for config-0.1.0.0..
2023-07-19 17:06:40.490903: [info] config> Building library for config-0.1.0.0..
2023-07-19 17:06:40.699953: [info] config> [5 of 7] Compiling Root.Config.Views [Source file changed]
2023-07-19 17:06:41.835534: [debug] Process finished in 1415ms: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 build lib:config --ghc-options " -fdiagnostics-color=always"
2023-07-19 17:06:41.835613: [debug] Start: getPackageFiles ~/code/project/config/config.cabal
2023-07-19 17:06:41.844907: [debug] Finished in 9ms: getPackageFiles ~/code/project/config/config.cabal
2023-07-19 17:06:41.847114: [info] config> copy/register
2023-07-19 17:06:41.847378: [debug] Run process within ~/code/project/config/: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 copy
2023-07-19 17:06:41.939685: [info] config> Installing library in ~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/lib/x86_64-linux-ghc-9.4.5/config-0.1.0.0-1cwf10xWyIXL47ARIUuTfb
2023-07-19 17:06:41.952370: [debug] Process finished in 105ms: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 copy
2023-07-19 17:06:41.952515: [debug] Run process within ~/code/project/config/: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 register
2023-07-19 17:06:42.136131: [info] config> Registering library for config-0.1.0.0..
2023-07-19 17:06:42.147014: [debug] Process finished in 194ms: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 register
2023-07-19 17:06:42.147205: [debug] Run process: ~/.stack/programs/x86_64-linux-dk82cbb9627cd086f74148946909b654d7/ghc-tinfo6-9.4.5/bin/ghc-pkg-9.4.5 --user --no-user-package-db --package-db ~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/pkgdb describe --simple-output config --expand-pkgroot
2023-07-19 17:06:42.168521: [debug] Process finished in 21ms: ~/.stack/programs/x86_64-linux-dk82cbb9627cd086f74148946909b654d7/ghc-tinfo6-9.4.5/bin/ghc-pkg-9.4.5 --user --no-user-package-db --package-db ~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/pkgdb describe --simple-output config --expand-pkgroot
2023-07-19 17:06:42.168824: [debug] (SQL) SELECT "id","directory","type","pkg_src","active","path_env_var","haddock" FROM "config_cache" WHERE "directory"=? AND "type"=?; [PersistText "~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/",PersistText "lib:config-0.1.0.0-1cwf10xWyIXL47ARIUuTfb"]
2023-07-19 17:06:42.169043: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 593]
2023-07-19 17:06:42.169145: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_no_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 593]
2023-07-19 17:06:42.169327: [debug] (SQL) SELECT "id", "config_cache_id", "ghc_pkg_id" FROM "config_cache_dep" WHERE ("config_cache_id"=?); [PersistInt64 593]
2023-07-19 17:06:42.169462: [debug] (SQL) SELECT "id", "config_cache_id", "component" FROM "config_cache_component" WHERE ("config_cache_id"=?); [PersistInt64 593]
2023-07-19 17:06:42.169517: [debug] (SQL) UPDATE "config_cache" SET "pkg_src"=?,"active"=?,"path_env_var"=? WHERE "id"=? ; [PersistText "local:~/code/project/config/",PersistBool True,PersistText "/opt/host/bin:~/code/project/.stack-work/docker/_home/.local/bin:/root/.local/bin:/usr/local/cuda-10.0/bin:/home/stackage/.stack/programs/x86_64-linux/ghc-9.4.5/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin",PersistInt64 593]
2023-07-19 17:06:42.169972: [debug] (SQL) SELECT "id","directory","type","pkg_src","active","path_env_var","haddock" FROM "config_cache" WHERE "directory"=? AND "type"=?; [PersistText "~/code/project/deprecated-proxy-service/",PersistText "config"]
2023-07-19 17:06:42.170399: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 298]
2023-07-19 17:06:42.170538: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_no_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 298]
2023-07-19 17:06:42.171036: [debug] (SQL) SELECT "id", "config_cache_id", "ghc_pkg_id" FROM "config_cache_dep" WHERE ("config_cache_id"=?); [PersistInt64 298]
2023-07-19 17:06:42.171280: [debug] (SQL) SELECT "id", "config_cache_id", "component" FROM "config_cache_component" WHERE ("config_cache_id"=?); [PersistInt64 298]
2023-07-19 17:06:42.171848: [debug] Start: getPackageFiles ~/code/project/deprecated-proxy-service/deprecated-proxy-service.cabal
2023-07-19 17:06:42.310459: [debug] Finished in 139ms: getPackageFiles ~/code/project/deprecated-proxy-service/deprecated-proxy-service.cabal
2023-07-19 17:06:42.724527: [info] deprecated-proxy-service > build (lib + exe)
2023-07-19 17:06:42.724648: [debug] Run process within ~/code/project/deprecated-proxy-service/: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 build lib:deprecated-proxy-service exe:njson-test --ghc-options " -fdiagnostics-color=always"
2023-07-19 17:06:42.802309: [info] deprecated-proxy-service > Preprocessing library for deprecated-proxy-service-0.1.0.0..
2023-07-19 17:06:42.802382: [info] deprecated-proxy-service > Building library for deprecated-proxy-service-0.1.0.0..
2023-07-19 17:06:44.338160: [info] deprecated-proxy-service > Preprocessing executable 'njson-test' for deprecated-proxy-service-0.1.0.0..
2023-07-19 17:06:44.338234: [info] deprecated-proxy-service > Building executable 'njson-test' for deprecated-proxy-service-0.1.0.0..
2023-07-19 17:06:44.404044: [warn] deprecated-proxy-service >
2023-07-19 17:06:44.404124: [warn] deprecated-proxy-service > <no location info>: warning: [-Wunused-packages]
2023-07-19 17:06:44.404144: [warn] deprecated-proxy-service >     The following packages were specified via -package or -package-id flags,
2023-07-19 17:06:44.404161: [warn] deprecated-proxy-service >     but were not needed for compilation:
2023-07-19 17:06:44.404192: [warn] deprecated-proxy-service >       - polysemy-1.9.1.0 (exposed by flag -package-id polysemy-1.9.1.0-AYcWoSC0ACCLNHpc8gzVWE)
2023-07-19 17:06:44.980845: [warn] deprecated-proxy-service >
2023-07-19 17:06:44.980949: [warn] deprecated-proxy-service > <no location info>: warning: [-Wunused-packages]
2023-07-19 17:06:44.980970: [warn] deprecated-proxy-service >     The following packages were specified via -package or -package-id flags,
2023-07-19 17:06:44.980986: [warn] deprecated-proxy-service >     but were not needed for compilation:
2023-07-19 17:06:44.981001: [warn] deprecated-proxy-service >       - polysemy-1.9.1.0 (exposed by flag -package-id polysemy-1.9.1.0-AYcWoSC0ACCLNHpc8gzVWE)
2023-07-19 17:06:45.550320: [debug] Process finished in 2826ms: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 build lib:deprecated-proxy-service exe:njson-test --ghc-options " -fdiagnostics-color=always"
2023-07-19 17:06:45.550392: [debug] Start: getPackageFiles ~/code/project/deprecated-proxy-service/deprecated-proxy-service.cabal
2023-07-19 17:06:45.680746: [debug] Finished in 130ms: getPackageFiles ~/code/project/deprecated-proxy-service/deprecated-proxy-service.cabal
2023-07-19 17:06:45.686819: [info] deprecated-proxy-service > copy/register
2023-07-19 17:06:45.686947: [debug] Run process within ~/code/project/deprecated-proxy-service/: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 copy
2023-07-19 17:06:45.820260: [info] deprecated-proxy-service > Installing library in ~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/lib/x86_64-linux-ghc-9.4.5/deprecated-proxy-service-0.1.0.0-FwGIz8sBJEHEMrLOjUyTzP
2023-07-19 17:06:45.899174: [info] deprecated-proxy-service > Installing executable njson-test in ~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/bin
2023-07-19 17:06:45.992423: [debug] Process finished in 305ms: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 copy
2023-07-19 17:06:45.992612: [debug] Run process within ~/code/project/deprecated-proxy-service/: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 register
2023-07-19 17:06:46.208150: [info] deprecated-proxy-service > Registering library for deprecated-proxy-service-0.1.0.0..
2023-07-19 17:06:46.219160: [debug] Process finished in 226ms: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 register
2023-07-19 17:06:46.219311: [debug] Run process: ~/.stack/programs/x86_64-linux-dk82cbb9627cd086f74148946909b654d7/ghc-tinfo6-9.4.5/bin/ghc-pkg-9.4.5 --user --no-user-package-db --package-db ~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/pkgdb describe --simple-output deprecated-proxy-service --expand-pkgroot
2023-07-19 17:06:46.241814: [debug] Process finished in 22ms: ~/.stack/programs/x86_64-linux-dk82cbb9627cd086f74148946909b654d7/ghc-tinfo6-9.4.5/bin/ghc-pkg-9.4.5 --user --no-user-package-db --package-db ~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/pkgdb describe --simple-output deprecated-proxy-service --expand-pkgroot
2023-07-19 17:06:46.242296: [debug] (SQL) SELECT "id","directory","type","pkg_src","active","path_env_var","haddock" FROM "config_cache" WHERE "directory"=? AND "type"=?; [PersistText "~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/",PersistText "lib:deprecated-proxy-service-0.1.0.0-FwGIz8sBJEHEMrLOjUyTzP"]
2023-07-19 17:06:46.242441: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 595]
2023-07-19 17:06:46.242536: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_no_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 595]
2023-07-19 17:06:46.242770: [debug] (SQL) SELECT "id", "config_cache_id", "ghc_pkg_id" FROM "config_cache_dep" WHERE ("config_cache_id"=?); [PersistInt64 595]
2023-07-19 17:06:46.242958: [debug] (SQL) SELECT "id", "config_cache_id", "component" FROM "config_cache_component" WHERE ("config_cache_id"=?); [PersistInt64 595]
2023-07-19 17:06:46.243184: [debug] (SQL) UPDATE "config_cache" SET "pkg_src"=?,"active"=?,"path_env_var"=? WHERE "id"=? ; [PersistText "local:~/code/project/deprecated-proxy-service/",PersistBool True,PersistText "/opt/host/bin:~/code/project/.stack-work/docker/_home/.local/bin:/root/.local/bin:/usr/local/cuda-10.0/bin:/home/stackage/.stack/programs/x86_64-linux/ghc-9.4.5/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin",PersistInt64 595]
2023-07-19 17:06:46.243572: [debug] (SQL) SELECT "id","directory","type","pkg_src","active","path_env_var","haddock" FROM "config_cache" WHERE "directory"=? AND "type"=?; [PersistText "~/code/project/web/",PersistText "config"]
2023-07-19 17:06:46.243662: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 300]
2023-07-19 17:06:46.243811: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_no_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 300]
2023-07-19 17:06:46.243970: [debug] (SQL) SELECT "id", "config_cache_id", "ghc_pkg_id" FROM "config_cache_dep" WHERE ("config_cache_id"=?); [PersistInt64 300]
2023-07-19 17:06:46.244086: [debug] (SQL) SELECT "id", "config_cache_id", "component" FROM "config_cache_component" WHERE ("config_cache_id"=?); [PersistInt64 300]
2023-07-19 17:06:46.244488: [debug] Start: getPackageFiles ~/code/project/web/web.cabal
2023-07-19 17:06:46.253458: [debug] Finished in 9ms: getPackageFiles ~/code/project/web/web.cabal
2023-07-19 17:06:46.632298: [info] web  > build (lib + exe)
2023-07-19 17:06:46.632430: [debug] Run process within ~/code/project/web/: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 build lib:web exe:web --ghc-options " -fdiagnostics-color=always"
2023-07-19 17:06:46.715681: [info] Preprocessing library for web-0.1.0.0..
2023-07-19 17:06:46.715763: [info] Building library for web-0.1.0.0..
2023-07-19 17:06:47.609764: [info] Preprocessing executable 'web' for web-0.1.0.0..
2023-07-19 17:06:47.609819: [info] Building executable 'web' for web-0.1.0.0..
2023-07-19 17:06:48.767963: [debug] Process finished in 2135ms: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 build lib:web exe:web --ghc-options " -fdiagnostics-color=always"
2023-07-19 17:06:48.768035: [debug] Start: getPackageFiles ~/code/project/web/web.cabal
2023-07-19 17:06:48.776523: [debug] Finished in 8ms: getPackageFiles ~/code/project/web/web.cabal
2023-07-19 17:06:48.778211: [info] web  > copy/register
2023-07-19 17:06:48.778313: [debug] Run process within ~/code/project/web/: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 copy
2023-07-19 17:06:48.923837: [info] Installing library in ~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/lib/x86_64-linux-ghc-9.4.5/web-0.1.0.0-LZETDQIEunuCZmoJL06wUk
2023-07-19 17:06:49.017257: [info] Installing executable web in ~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/bin
2023-07-19 17:06:49.203125: [debug] Process finished in 425ms: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 copy
2023-07-19 17:06:49.203294: [debug] Run process within ~/code/project/web/: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 register
2023-07-19 17:06:49.414856: [info] Registering library for web-0.1.0.0..
2023-07-19 17:06:49.428248: [debug] Process finished in 225ms: ~/.stack/setup-exe-cache/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-simple_6HauvNHV_3.8.1.0_ghc-9.4.5 --verbose=1 --builddir=.stack-work/dist/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/Cabal-3.8.1.0 register
2023-07-19 17:06:49.428403: [debug] Run process: ~/.stack/programs/x86_64-linux-dk82cbb9627cd086f74148946909b654d7/ghc-tinfo6-9.4.5/bin/ghc-pkg-9.4.5 --user --no-user-package-db --package-db ~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/pkgdb describe --simple-output web --expand-pkgroot
2023-07-19 17:06:49.450375: [debug] Process finished in 22ms: ~/.stack/programs/x86_64-linux-dk82cbb9627cd086f74148946909b654d7/ghc-tinfo6-9.4.5/bin/ghc-pkg-9.4.5 --user --no-user-package-db --package-db ~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/pkgdb describe --simple-output web --expand-pkgroot
2023-07-19 17:06:49.450611: [debug] (SQL) SELECT "id","directory","type","pkg_src","active","path_env_var","haddock" FROM "config_cache" WHERE "directory"=? AND "type"=?; [PersistText "~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/",PersistText "lib:web-0.1.0.0-LZETDQIEunuCZmoJL06wUk"]
2023-07-19 17:06:49.450839: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 596]
2023-07-19 17:06:49.450974: [debug] (SQL) SELECT "id", "config_cache_id", "index", "option" FROM "config_cache_no_dir_option" WHERE ("config_cache_id"=?) ORDER BY "index"; [PersistInt64 596]
2023-07-19 17:06:49.451117: [debug] (SQL) SELECT "id", "config_cache_id", "ghc_pkg_id" FROM "config_cache_dep" WHERE ("config_cache_id"=?); [PersistInt64 596]
2023-07-19 17:06:49.451224: [debug] (SQL) SELECT "id", "config_cache_id", "component" FROM "config_cache_component" WHERE ("config_cache_id"=?); [PersistInt64 596]
2023-07-19 17:06:49.451299: [debug] (SQL) UPDATE "config_cache" SET "pkg_src"=?,"active"=?,"path_env_var"=? WHERE "id"=? ; [PersistText "local:~/code/project/web/",PersistBool True,PersistText "/opt/host/bin:~/code/project/.stack-work/docker/_home/.local/bin:/root/.local/bin:/usr/local/cuda-10.0/bin:/home/stackage/.stack/programs/x86_64-linux/ghc-9.4.5/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin",PersistInt64 596]
2023-07-19 17:06:49.451550: [info] Completed 3 action(s).
2023-07-19 17:06:49.451899: [info] Copying from
~/code/project/.stack-work/install/x86_64-linux-dk82cbb9627cd086f74148946909b654d7-tinfo6/4e6eb4ad223c34776d4aca0112cb011e7f724da80236a6d9fda2ad28c9319d53/9.4.5/bin/web
to ~/code/project/dockerbin/web.
2023-07-19 17:06:49.500673: [info] Copied executables to ~/code/project/dockerbin/:
* web
2023-07-19 17:06:49.500941: [warn]
Warning: Installation path ~/code/project/dockerbin
         not found on the PATH environment variable.
2023-07-19 12:06:49.546903: [debug] Process finished in 10157ms: /usr/bin/docker start -a -i c32b4f73e3f9202e46903935cf0d4cd5f721b3fd6abfd716d7a6c71438438e68
2023-07-19 12:06:49.546987: [debug] Run process: /usr/bin/docker rm -f c32b4f73e3f9202e46903935cf0d4cd5f721b3fd6abfd716d7a6c71438438e68
2023-07-19 12:06:49.568425: [debug] Process finished in 21ms: /usr/bin/docker rm -f c32b4f73e3f9202e46903935cf0d4cd5f721b3fd6abfd716d7a6c71438438e68
docker-compose -f ../front-end/docker-compose.yml restart web
Restarting front-end_web_1 ... done

Stack version

stack --version
Version 2.11.1, Git revision c1167a6abc3f4978ccded5ba0246a57387da0e2f x86_64 hpack-0.35.2

Method of installation

  • Official binary, downloaded via haskellstack.org or from Stack's repository
  • Via GHCup
  • Via Cabal (the tool)
  • An unofficial package repository (please specify which)
  • Other (please specify)

Platform

Your platform (machine architecture and operating system)

@mpilgrem
Copy link
Member

@erlandsona, I tried to reproduce this with a simpler example, but without success. My example was a two-package project (packageA, packageB), package A with a library (module LibA) and package B with an executable depending on LibA. So, project stack.yaml:

resolver: lts-21.3
packages:
- packageB
- packageA

and package B's package.yaml:

name:                packageB
version:             0.1.0.0
dependencies:
- base >= 4.7 && < 5
- packageA
executables:
  packageB:
    main: Main.hs
    source-dirs: app

If I change a file in package A and build the package B component (extracts only):

> stack build :packageB
packageA-0.1.0.0: unregistering (local file changes: src\LibA.hs)
packageA> build (lib)
...
packageA> Registering library for packageA-0.1.0.0..
packageB> build (exe)
Preprocessing executable 'packageB' for packageB-0.1.0.0..
Building executable 'packageB' for packageB-0.1.0.0..
[1 of 2] Compiling Main [LibA changed]
[3 of 3] Linking .stack-work\dist\c3556505\build\packageB\packageB.exe [Objects changed]
packageB> copy/register
Installing executable packageB in C:\Users\mikep\Documents\Code\Haskell\multiTest\.stack-work\install\4ce79b7a\bin
Completed 2 action(s).

So, in my example, the change to file src\LibA.hs is being recognised.

Can we narrow down what you are experiencing? What file in your common (or dp) package are you changing that is not being detected when you build the :web component?

@erlandsona
Copy link
Author

We'll so I can show the log output without debug and maybe it'll be clearer. Issue isn't that stack doesn't show the change as detected and then hypothetically it recompiles packageB. It's that at runtime the previous version of packageA is still used.

Not at my machine rn, but I can try to create a small repro tomorrow.

Maybe try updating the string of a log statement in packageA then run packageB then update packageA again and see if the updates take effect.

@mpilgrem
Copy link
Member

mpilgrem commented Jul 20, 2023

@erlandsona, your reference to behaviour at run time has confused me, as that behaviour will depend on what source code has been compiled into the running executable file. To more fully specify my simple example: package A's LibA.hs is:

module LibA where

someFuncA :: IO ()
someFuncA = putStrLn "Message: A-1"

and package B's executable is:

module Main where

import LibA

main :: IO ()
main = someFuncA

If I change the message in the source code of someFuncA but do not then recompile the executable using that changed source code, of course, at run time there is no change in the executable's behaviour.

@erlandsona
Copy link
Author

Issue isn't that we're not recompiling the executable but that stack install :the_project_executable isn't.

@erlandsona
Copy link
Author

Okay! Got a working reproduction of the issue!

https://github.com/erlandsona/jenga

@erlandsona
Copy link
Author

When the log statement in common in changed the executable that I expect to have the latest log statement is still using a stale log.

@erlandsona
Copy link
Author

Between the "REPRO" commit and the one prior, the primary thing I added was a "3rd project".
EG: I wasn't able to repro the behavior with just 2 projects. I needed that 3rd "common" library with it's own Lib and I'm referencing it as a dependency in both projectA & projectB but when recompiling projectB, altho it seems to pick up the change the binary has stale code.

@erlandsona
Copy link
Author

Okay new info from some more tinkering. I can get rid of the "issue" by removing the fan out.
In other words, (using <- to mean "depends on")
if projectB <- projectA <- common, then all is fine. BUT
if projectB <- common && projectB <- projectA <- common...

There's 2 paths to get to common and when common is changed but projectA is not, and because there's no direct reference to common in projectB for that functionality, I think stack is picking the longer path to common through projectA which hasn't changed therefor we end up with the stale reference.

@mpilgrem
Copy link
Member

mpilgrem commented Jul 20, 2023

@erlandsona, I've cloned your example repository, but I still can't reproduce the problem. When I change common's Lib.hs to have a different message (Common 4), stack build :packageB detects the changed file and everything behaves as it should (extracts below):

> stack build :projectB # Build only project B's executable
common-0.1.0.0: unregistering (local file changes: src\Lib.hs)
projectA-0.1.0.0: unregistering (missing dependencies: common)
projectB-0.1.0.0: unregistering (missing dependencies: common, projectA)
common  > build (lib)
...
common  > Registering library for common-0.1.0.0..
projectA> build (lib)
...
projectB> build (lib + exe)
...
Building executable 'projectB' for projectB-0.1.0.0..
...
Installing executable projectB in C:\Users\mikep\Documents\Code\Haskell\jenga\.stack-work\install\4ce79b7a\bin
Registering library for projectB-0.1.0.0..
Completed 3 action(s).
> stack exec -- projectB # Run projectB executable
Common 4
ProjectA 1

EDIT: What output are you experiencing, when you do something similar?

@erlandsona
Copy link
Author

So coming back to this today... what's weird is I had it reproduced without the --fast flag but I came back to it this morning and all of a sudden the only way to trigger the weird caching behavior is to use --fast then after the caches go stale the flag doesn't matter.

Couple other variables include:

  • it only starts happening after a few changes/re-compiles.
  • My co-worker running MacOSX doesn't seem to be experiencing this issue. But the three of us who are experiencing the issue are all running some version of Ubuntu 20+.

In the following output, I expect "Common 2" to change to "Common 3" but notice in the 2nd output it still prints "Common 2".

$ stack install :projectB --fast --local-bin-path ./bin; bin/projectB
common-0.1.0.0: unregistering (local file changes: src/Lib.hs)
projectA-0.1.0.0: unregistering (missing dependencies: common)
projectB-0.1.0.0: unregistering (missing dependencies: common, projectA)
common  > configure (lib)
common  > Configuring common-0.1.0.0...
common  > build (lib)
common  > Preprocessing library for common-0.1.0.0..
common  > Building library for common-0.1.0.0..
common  > [1 of 2] Compiling Lib [Source file changed]
common  > [2 of 2] Compiling Paths_common [Optimisation flags changed]
common  > copy/register
common  > Installing library in /home/erlandsona/code/jenga/.stack-work/install/x86_64-linux/98b826d8eec4182f6e19a539ba0f2c6b4bff041ba7e189ad84465ac6f69fe0f5/9.4.5/lib/x86_64-linux-ghc-9.4.5/common-0.1.0.0-JWbNpAqBj0sJ4NuqRU3aZY
common  > Registering library for common-0.1.0.0..
projectA> configure (lib)
projectA> Configuring projectA-0.1.0.0...
projectA> build (lib)
projectA> Preprocessing library for projectA-0.1.0.0..
projectA> Building library for projectA-0.1.0.0..
projectA> [1 of 2] Compiling Lib [Optimisation flags changed]
projectA> [2 of 2] Compiling Paths_projectA [Optimisation flags changed]
projectA> copy/register
projectA> Installing library in /home/erlandsona/code/jenga/.stack-work/install/x86_64-linux/98b826d8eec4182f6e19a539ba0f2c6b4bff041ba7e189ad84465ac6f69fe0f5/9.4.5/lib/x86_64-linux-ghc-9.4.5/projectA-0.1.0.0-3vHJZZMyKjL74RQQ7ayBN
projectA> Registering library for projectA-0.1.0.0..
projectB> configure (lib + exe)
Configuring projectB-0.1.0.0...
projectB> build (lib + exe)
Preprocessing library for projectB-0.1.0.0..
Building library for projectB-0.1.0.0..
[1 of 2] Compiling Lib [Optimisation flags changed]
[2 of 2] Compiling Paths_projectB [Optimisation flags changed]
Preprocessing executable 'projectB' for projectB-0.1.0.0..
Building executable 'projectB' for projectB-0.1.0.0..
[1 of 2] Compiling Main [Optimisation flags changed]
[2 of 2] Compiling Paths_projectB [Optimisation flags changed]
[3 of 3] Linking .stack-work/dist/x86_64-linux/Cabal-3.8.1.0/build/projectB/projectB [Objects changed]
projectB> copy/register
Installing library in /home/erlandsona/code/jenga/.stack-work/install/x86_64-linux/98b826d8eec4182f6e19a539ba0f2c6b4bff041ba7e189ad84465ac6f69fe0f5/9.4.5/lib/x86_64-linux-ghc-9.4.5/projectB-0.1.0.0-IAxteA2fuQBCVNZMliTzVr
Installing executable projectB in /home/erlandsona/code/jenga/.stack-work/install/x86_64-linux/98b826d8eec4182f6e19a539ba0f2c6b4bff041ba7e189ad84465ac6f69fe0f5/9.4.5/bin
Registering library for projectB-0.1.0.0..
Completed 3 action(s).
Copying from /home/erlandsona/code/jenga/.stack-work/install/x86_64-linux/98b826d8eec4182f6e19a539ba0f2c6b4bff041ba7e189ad84465ac6f69fe0f5/9.4.5/bin/projectB to
/home/erlandsona/code/jenga/bin/projectB.
Copied executables to /home/erlandsona/code/jenga/bin/:
* projectB

Warning: Installation path /home/erlandsona/code/jenga/bin not found on the PATH environment variable.
Common 2
ProjectA 1

Bump to "Common 3"

$ stack install :projectB --fast --local-bin-path ./bin; bin/projectB
common-0.1.0.0: unregistering (local file changes: src/Lib.hs)
projectA-0.1.0.0: unregistering (missing dependencies: common)
projectB-0.1.0.0: unregistering (missing dependencies: common, projectA)
common  > build (lib)
common  > Preprocessing library for common-0.1.0.0..
common  > Building library for common-0.1.0.0..
common  > [1 of 2] Compiling Lib [Source file changed]
common  > copy/register
common  > Installing library in /home/erlandsona/code/jenga/.stack-work/install/x86_64-linux/98b826d8eec4182f6e19a539ba0f2c6b4bff041ba7e189ad84465ac6f69fe0f5/9.4.5/lib/x86_64-linux-ghc-9.4.5/common-0.1.0.0-JWbNpAqBj0sJ4NuqRU3aZY
common  > Registering library for common-0.1.0.0..
projectA> build (lib)
projectA> Preprocessing library for projectA-0.1.0.0..
projectA> Building library for projectA-0.1.0.0..
projectA> copy/register
projectA> Installing library in /home/erlandsona/code/jenga/.stack-work/install/x86_64-linux/98b826d8eec4182f6e19a539ba0f2c6b4bff041ba7e189ad84465ac6f69fe0f5/9.4.5/lib/x86_64-linux-ghc-9.4.5/projectA-0.1.0.0-3vHJZZMyKjL74RQQ7ayBN
projectA> Registering library for projectA-0.1.0.0..
projectB> build (lib + exe)
Preprocessing library for projectB-0.1.0.0..
Building library for projectB-0.1.0.0..
Preprocessing executable 'projectB' for projectB-0.1.0.0..
Building executable 'projectB' for projectB-0.1.0.0..
projectB> copy/register
Installing library in /home/erlandsona/code/jenga/.stack-work/install/x86_64-linux/98b826d8eec4182f6e19a539ba0f2c6b4bff041ba7e189ad84465ac6f69fe0f5/9.4.5/lib/x86_64-linux-ghc-9.4.5/projectB-0.1.0.0-IAxteA2fuQBCVNZMliTzVr
Installing executable projectB in /home/erlandsona/code/jenga/.stack-work/install/x86_64-linux/98b826d8eec4182f6e19a539ba0f2c6b4bff041ba7e189ad84465ac6f69fe0f5/9.4.5/bin
Registering library for projectB-0.1.0.0..
Completed 3 action(s).
Copying from /home/erlandsona/code/jenga/.stack-work/install/x86_64-linux/98b826d8eec4182f6e19a539ba0f2c6b4bff041ba7e189ad84465ac6f69fe0f5/9.4.5/bin/projectB to
/home/erlandsona/code/jenga/bin/projectB.
Copied executables to /home/erlandsona/code/jenga/bin/:
* projectB

Warning: Installation path /home/erlandsona/code/jenga/bin not found on the PATH environment variable.
Common 2
ProjectA 1

@mpilgrem
Copy link
Member

@erlandsona, that is indeed very odd (by the way, I've been testing on Windows; I'll switch to Ubuntu). When you bump the source, everything seems to get recompiled - as I would expect - but the final bin/projectB seems to be - somehow - still running the 'old' executable.

Can we take the --copy-bins (stack install) step out of the equation and just try stack build followed by stack exec -- projectB? I want to be sure that the executable file that is being run is, indeed, the executable file that Stack just built.

The --fast flag literally just adds -O0 to the GHC options (Stack.Options.BuildParser.buildOptsParser) - I find it hard to fathom how it could be involved.

@mpilgrem
Copy link
Member

@erlandsona, good news, I can reproduce what you are experiencing on Windows and Ubuntu 22.04.1 LTS (WSL 2), and it does seem to be somehow connected with the --fast flag.

@erlandsona
Copy link
Author

Phew!!! Glad I'm not sending yah on a wild goose chase!
Yeh, something to do with the --fast flag, but on our larger project with this sort of setup we're able to reproduce it without the flag as well. Of course, after a stack clean everything builds fine but the compile times are an order of magnitude off such that it's prohibitively expensive to stack clean before every re-compile when we're iterating on Lucid HTML templates for example.

@erlandsona
Copy link
Author

erlandsona commented Jul 20, 2023

I also tried you're suggestion with stack build :projectB --fast; stack exec -- projectB and was able to repro the issue.

@mpilgrem
Copy link
Member

I've compared the corresponding output (outputf1.txt versus output1.txt; and outputf2.txt versus output2.txt) of:

> stack purge
> stack --verbose --no-time-in-log install :projectB --fast --local-bin-path ./bin 2>&1 > outputf1.txt ; bin/projectB
> # Bump message in common's Lib.hs
> stack --verbose --no-time-in-log install :projectB --fast --local-bin-path ./bin 2>&1 > outputf2.txt ; bin/projectB

and

> stack purge
> stack --verbose --no-time-in-log install :projectB --local-bin-path ./bin 2>&1 > output1.txt ; bin/projectB
> # Bump message in common's Lib.hs
> stack --verbose --no-time-in-log install :projectB --local-bin-path ./bin 2>&1 > output2.txt ; bin/projectB

outputf1.txt has the --ghc-options -O0 in the Cabal configure steps which the output1.txt does not (as expected).

outputf2.txt seems to me to have different behaviour of Cabal (the library) compared to output2.txt, despite Stack passing the same commands to Cabal in each case. I am going to see what --cabal-verbose yields.

@erlandsona
Copy link
Author

Not sure what stack purge does but if it does a stack clean under the hood then your test might be flaky given clean "fixes" the bug. So you're not actually outputting a diff between the two.

@mpilgrem
Copy link
Member

mpilgrem commented Jul 20, 2023

Another test:

> stack purge # Start with a clean project
> stack build common:lib
> stack exec -- ghc-pkg field common abi
abi: 05c3e02960afdc567cf6780e0c4efa27
> # Bump message in common's Lib.hs
> stack build common:lib
> stack exec -- ghc-pkg field common abi # ABI hash of the registered package changes, as expected ...
abi: 85127eacbbc7934532c98093a375e836

but ...

> stack purge # Start with a clean project
> stack build common:lib --fast
> stack exec -- ghc-pkg field common abi
abi: 71b6f976c20ac17f186c8979b443038b
> # Bump message in common's Lib.hs
> stack build common:lib --fast
> stack exec -- ghc-pkg field common abi # !!! the ABI hash of the registered package is unchanged !!!
abi: 71b6f976c20ac17f186c8979b443038b

Something seems to be going wrong with the registration step when --fast is specified ... (EDIT: It is not --fast specific; the same behaviour results if --ghc-options -O0 is used expressly.)

@mpilgrem
Copy link
Member

My current hypothesis is that this arises because - with -O0 - changes to the source code do not affect the *.hi file or the ABI hash for the package. With optimisation greater than O0, parts of the source code are included in the *.hi file and the ABI hash for the package changes as the source code changes.

I have been investigating with the simplest of packages: library-only, single module Lib:

module Lib
    ( someFunc
    ) where

someFunc :: IO ()
someFunc = putStrLn "someFunc1"

and inspecting the resulting Lib.hi file with stack exec -- ghc --show-iface C:\Users\mikep\Documents\Code\Haskell\abiTest\.stack-work\dist\c3556505\build\Lib.hi as "someFunc1" is changed to "someFunc2".

With -O0, the src_hash changes but the ABI hash is constant. With some optimisation, Lib.hi includes some of the source code (for example, extract below) and the src_hash and ABI hash changes:

b677cd349fe756bad7775c5130ce9be8
  someFunc3 :: GHC.Prim.Addr#
  [HasNoCafRefs, LambdaFormInfo: LFUnlifted,
   Unfolding: ("someFunc1"#)]

@mpilgrem
Copy link
Member

More experimentation, with the jenga example (but after renaming the A and B 'Lib' modules to give them distinct names) (extracts only, some reformatting). It seems that it is GHC 9.4.5 that concludes that it does not need to 'recompile' and it can 'skip' because the 'fingerprint' is unchanged):

> # Turn on Cabal and GHC verbosity...
> stack build --ghc-options "-O0 -v -ddump-hi-diffs" --cabal-verbose --local-bin-path ./bin; bin/projectB
common-0.1.0.0: unregistering (local file changes: src\Lib.hs)
projectA-0.1.0.0: unregistering (missing dependencies: common)
projectB-0.1.0.0: unregistering (missing dependencies: common, projectA)
common  > build (lib)
...
common  > Installing .stack-work\dist\c3556505\build\Lib.hi to
common  > C:\Users\mikep\Documents\Code\Haskell\jenga\.stack-work\install\4ce79b7a\lib\x86_64-windows-ghc-9.4.5\common-0.1.0.0-JWbNpAqBj0sJ4NuqRU3aZY\Lib.hi
...
common  > Installing
common  > .stack-work\dist\c3556505\build\libHScommon-0.1.0.0-JWbNpAqBj0sJ4NuqRU3aZY.a
common  > to
common  > C:\Users\mikep\Documents\Code\Haskell\jenga\.stack-work\install\4ce79b7a\lib\x86_64-windows-ghc-9.4.5\common-0.1.0.0-JWbNpAqBj0sJ4NuqRU3aZY\libHScommon-0.1.0.0-JWbNpAqBj0sJ4NuqRU3aZY.a
...
projectA> build (lib)
...
projectA> "C:\Users\mikep\AppData\Local\Programs\stack\x86_64-windows\ghc-9.4.5\bin\ghc-9.4.5.exe" 
"--make" 
"-fbuilding-cabal-package" 
"-O" 
"-outputdir" ".stack-work\dist\c3556505\build" 
"-odir" ".stack-work\dist\c3556505\build" 
"-hidir" ".stack-work\dist\c3556505\build" 
"-stubdir" ".stack-work\dist\c3556505\build" 
"-i" 
"-i.stack-work\dist\c3556505\build" 
"-isrc" 
"-i.stack-work\dist\c3556505\build\autogen" 
"-i.stack-work\dist\c3556505\build\global-autogen" 
"-I.stack-work\dist\c3556505\build\autogen" 
"-I.stack-work\dist\c3556505\build\global-autogen" 
"-I.stack-work\dist\c3556505\build" 
"-IC:\Users\mikep\AppData\Local\Programs\stack\x86_64-windows\msys2-20230526\mingw64\include" 
"-optP-include" "-optP.stack-work\dist\c3556505\build\autogen\cabal_macros.h" 
"-this-unit-id" "projectA-0.1.0.0-3vHJZZMyKjL74RQQ7ayBN" 
"-hide-all-packages" 
"-Wmissing-home-modules" 
"-no-user-package-db" 
"-package-db" "C:\sr\snapshots\ce334f6e\pkgdb" 
"-package-db" "C:\Users\mikep\Documents\Code\Haskell\jenga\.stack-work\install\4ce79b7a\pkgdb" 
"-package-db" ".stack-work\dist\c3556505\package.conf.inplace" 
"-package-id" "base-4.17.1.0" 
"-package-id" "common-0.1.0.0-JWbNpAqBj0sJ4NuqRU3aZY" 
"-XHaskell2010" 
"LibA" 
"-O0" 
"-v" 
"-ddump-hi-diffs" 
"-fhide-source-paths" 
"-fdiagnostics-color=always"
projectA> Glasgow Haskell Compiler, Version 9.4.5, stage 2 booted by GHC version 9.2.2
...
projectA> *** Checking old interface for LibA (use -ddump-hi-diffs for more details):
projectA> Considering whether compilation is required for LibA:
projectA> Module flags unchanged
projectA> Optimisation flags unchanged
projectA> HPC flags unchanged
projectA> signatures to merge in unchanged
projectA> []
projectA> implementing module unchanged
projectA> Checking interface for module Prelude base
projectA> Module fingerprint unchanged
projectA> Checking interface for module System.IO base
projectA> Module fingerprint unchanged
projectA> Checking interface for module Lib common-0.1.0.0-JWbNpAqBj0sJ4NuqRU3aZY
projectA> Module fingerprint unchanged
projectA> Checking interface for module GHC.Types ghc-prim
projectA> Module fingerprint unchanged
projectA> [1 of 1] Skipping LibA
...
projectB> build (lib + exe)
...
projectB> "C:\Users\mikep\AppData\Local\Programs\stack\x86_64-windows\ghc-9.4.5\bin\ghc-9.4.5.exe" 
"--make" 
"-fbuilding-cabal-package" 
"-O" 
"-outputdir" ".stack-work\dist\c3556505\build" 
"-odir" ".stack-work\dist\c3556505\build" 
"-hidir" ".stack-work\dist\c3556505\build" 
"-stubdir" ".stack-work\dist\c3556505\build" 
"-i" 
"-i.stack-work\dist\c3556505\build" 
"-isrc" 
"-i.stack-work\dist\c3556505\build\autogen" 
"-i.stack-work\dist\c3556505\build\global-autogen" 
"-I.stack-work\dist\c3556505\build\autogen" 
"-I.stack-work\dist\c3556505\build\global-autogen" 
"-I.stack-work\dist\c3556505\build" 
"-IC:\Users\mikep\AppData\Local\Programs\stack\x86_64-windows\msys2-20230526\mingw64\include" 
"-optP-include" "-optP.stack-work\dist\c3556505\build\autogen\cabal_macros.h" 
"-this-unit-id" "projectB-0.1.0.0-IAxteA2fuQBCVNZMliTzVr" 
"-hide-all-packages" 
"-Wmissing-home-modules" 
"-no-user-package-db" 
"-package-db" "C:\sr\snapshots\ce334f6e\pkgdb" 
"-package-db" "C:\Users\mikep\Documents\Code\Haskell\jenga\.stack-work\install\4ce79b7a\pkgdb" 
"-package-db" ".stack-work\dist\c3556505\package.conf.inplace" 
"-package-id" "base-4.17.1.0" 
"-package-id" "common-0.1.0.0-JWbNpAqBj0sJ4NuqRU3aZY" 
"-package-id" "projectA-0.1.0.0-3vHJZZMyKjL74RQQ7ayBN" 
"-XHaskell2010" 
"LibB" 
"-O0" 
"-v" 
"-ddump-hi-diffs" 
"-fhide-source-paths" 
"-fdiagnostics-color=always"
projectB> Glasgow Haskell Compiler, Version 9.4.5, stage 2 booted by GHC version 9.2.2
...
projectB> *** Checking old interface for LibB (use -ddump-hi-diffs for more details):
projectB> Considering whether compilation is required for LibB:
projectB> Module flags unchanged
projectB> Optimisation flags unchanged
projectB> HPC flags unchanged
projectB> signatures to merge in unchanged
projectB> []
projectB> implementing module unchanged
projectB> Checking interface for module Prelude base
projectB> Module fingerprint unchanged
projectB> Checking interface for module LibA projectA-0.1.0.0-3vHJZZMyKjL74RQQ7ayBN
projectB> Module fingerprint unchanged
projectB> [1 of 1] Skipping LibB
...
projectB> "C:\Users\mikep\AppData\Local\Programs\stack\x86_64-windows\ghc-9.4.5\bin\ghc-9.4.5.exe" 
"--make" 
"-no-link" 
"-fbuilding-cabal-package" 
"-O" 
"-static" 
"-outputdir" ".stack-work\dist\c3556505\build\projectB\projectB-tmp" 
"-odir" ".stack-work\dist\c3556505\build\projectB\projectB-tmp" 
"-hidir" ".stack-work\dist\c3556505\build\projectB\projectB-tmp" 
"-stubdir" ".stack-work\dist\c3556505\build\projectB\projectB-tmp" 
"-i" 
"-i.stack-work\dist\c3556505\build\projectB\projectB-tmp" 
"-iapp" 
"-i.stack-work\dist\c3556505\build\projectB\autogen" 
"-i.stack-work\dist\c3556505\build\global-autogen" 
"-I.stack-work\dist\c3556505\build\projectB\autogen" 
"-I.stack-work\dist\c3556505\build\global-autogen" 
"-I.stack-work\dist\c3556505\build\projectB\projectB-tmp" 
"-IC:\Users\mikep\AppData\Local\Programs\stack\x86_64-windows\msys2-20230526\mingw64\include" 
"-optP-include" "-optP.stack-work\dist\c3556505\build\projectB\autogen\cabal_macros.h" 
"-hide-all-packages" 
"-Wmissing-home-modules" 
"-no-user-package-db" 
"-package-db" "C:\sr\snapshots\ce334f6e\pkgdb" 
"-package-db" "C:\Users\mikep\Documents\Code\Haskell\jenga\.stack-work\install\4ce79b7a\pkgdb" 
"-package-db" ".stack-work\dist\c3556505\package.conf.inplace" 
"-package-id" "base-4.17.1.0" 
"-package-id" "projectB-0.1.0.0-IAxteA2fuQBCVNZMliTzVr" 
"-XHaskell2010" 
"app\Main.hs" 
"-threaded" 
"-rtsopts" 
"-with-rtsopts=-N" 
"-O0" 
"-v" 
"-ddump-hi-diffs" 
"-fhide-source-paths" 
"-fdiagnostics-color=always"
projectB> Glasgow Haskell Compiler, Version 9.4.5, stage 2 booted by GHC version 9.2.2
...
projectB> *** Checking old interface for Main (use -ddump-hi-diffs for more details):
projectB> Considering whether compilation is required for Main:
projectB> Module flags unchanged
projectB> Optimisation flags unchanged
projectB> HPC flags unchanged
projectB> signatures to merge in unchanged
projectB> []
projectB> implementing module unchanged
projectB> Checking interface for module Prelude base
projectB> Module fingerprint unchanged
projectB> Checking interface for module GHC.Types ghc-prim
projectB> Module fingerprint unchanged
projectB> Checking interface for module LibA projectA-0.1.0.0-3vHJZZMyKjL74RQQ7ayBN
projectB> Module fingerprint unchanged
projectB> Checking interface for module LibB projectB-0.1.0.0-IAxteA2fuQBCVNZMliTzVr
projectB> Module fingerprint unchanged
projectB> [1 of 1] Skipping Main
...
projectB> Linking...
projectB> "C:\Users\mikep\AppData\Local\Programs\stack\x86_64-windows\ghc-9.4.5\bin\ghc-9.4.5.exe" 
"--make" 
"-fbuilding-cabal-package" 
"-O" 
"-static" 
"-outputdir" ".stack-work\dist\c3556505\build\projectB\projectB-tmp" 
"-odir" ".stack-work\dist\c3556505\build\projectB\projectB-tmp" 
"-hidir" ".stack-work\dist\c3556505\build\projectB\projectB-tmp" 
"-stubdir" ".stack-work\dist\c3556505\build\projectB\projectB-tmp" 
"-i" 
"-i.stack-work\dist\c3556505\build\projectB\projectB-tmp" 
"-iapp" 
"-i.stack-work\dist\c3556505\build\projectB\autogen" 
"-i.stack-work\dist\c3556505\build\global-autogen" 
"-I.stack-work\dist\c3556505\build\projectB\autogen" 
"-I.stack-work\dist\c3556505\build\global-autogen" 
"-I.stack-work\dist\c3556505\build\projectB\projectB-tmp" 
"-IC:\Users\mikep\AppData\Local\Programs\stack\x86_64-windows\msys2-20230526\mingw64\include" 
"-optP-include" 
"-optP.stack-work\dist\c3556505\build\projectB\autogen\cabal_macros.h" 
"-LC:\Users\mikep\AppData\Local\Programs\stack\x86_64-windows\msys2-20230526\mingw64\lib" 
"-LC:\Users\mikep\AppData\Local\Programs\stack\x86_64-windows\msys2-20230526\mingw64\bin" 
"-hide-all-packages" 
"-Wmissing-home-modules" 
"-no-user-package-db" 
"-package-db" "C:\sr\snapshots\ce334f6e\pkgdb" 
"-package-db" "C:\Users\mikep\Documents\Code\Haskell\jenga\.stack-work\install\4ce79b7a\pkgdb" 
"-package-db" ".stack-work\dist\c3556505\package.conf.inplace" 
"-package-id" "base-4.17.1.0" 
"-package-id" "projectB-0.1.0.0-IAxteA2fuQBCVNZMliTzVr" 
"-XHaskell2010" 
"app\Main.hs" 
"-o" ".stack-work\dist\c3556505\build\projectB\projectB.exe" 
"-threaded" 
"-rtsopts" 
"-with-rtsopts=-N" 
"-O0" 
"-v" 
"-ddump-hi-diffs" 
"-fhide-source-paths" 
"-fdiagnostics-color=always"
projectB> Glasgow Haskell Compiler, Version 9.4.5, stage 2 booted by GHC version 9.2.2
...
projectB> *** Checking old interface for Main (use -ddump-hi-diffs for more details):
projectB> Considering whether compilation is required for Main:
projectB> Module flags unchanged
projectB> Optimisation flags unchanged
projectB> HPC flags unchanged
projectB> signatures to merge in unchanged
projectB> []
projectB> implementing module unchanged
projectB> Checking interface for module Prelude base
projectB> Module fingerprint unchanged
projectB> Checking interface for module GHC.Types ghc-prim
projectB> Module fingerprint unchanged
projectB> Checking interface for module LibA projectA-0.1.0.0-3vHJZZMyKjL74RQQ7ayBN
projectB> Module fingerprint unchanged
projectB> Checking interface for module LibB projectB-0.1.0.0-IAxteA2fuQBCVNZMliTzVr
projectB> Module fingerprint unchanged
projectB> [1 of 2] Skipping Main
...
projectB> link: linkables are ...
projectB> LinkableM (2023-07-22 15:16:10.3480018 UTC) Main
projectB>    [DotO .stack-work\dist\c3556505\build\projectB\projectB-tmp\Main.o]
projectB> .stack-work\dist\c3556505\build\projectB\projectB.exe is up to date, linking not required.
projectB> [2 of 2] Skipping .stack-work\dist\c3556505\build\projectB\projectB.exe
...
Completed 3 action(s).
Common 1
ProjectA 1

@mpilgrem
Copy link
Member

mpilgrem commented Jul 22, 2023

@erlandsona, I am now fairly certain that this is a feature/bug of GHC 9.4.5. It seems that GHC's 'recompilation checker' assumes that recompilation of a module is not required if the ABI hash of its imports has not changed, even if the import module's source code has changed - and that is more likely to happen with --fast/-O0. GHC's recompilation checker can be turned off with GHC flag -fforce-recomp. Consequently, I have (extracts only):

> stack purge # Start with a project purged of build artefacts
> stack install :projectB --fast --ghc-options -fforce-recomp --local-bin-path ./bin; bin/projectB
...
Common 1
ProjectA 1
> # Bump to "Common 2" and experience the problem with --fast/-O0
> stack install :projectB --fast --local-bin-path ./bin; bin/projectB
...
Common 1
ProjectA 1
> # Bump to "Common 3" and force GHC to recompile
> stack install :projectB --fast --ghc-options -fforce-recomp --local-bin-path ./bin; bin/projectB
...
Common 3
ProjectA 1

I'll follow up elsewhere to see if I can determine if this is a feature or a bug of GHC.

@mpilgrem
Copy link
Member

I came across haskell/cabal#4381 and found it helpful to understand Cabal's use of 'installed package ID', which I could not find documentation for outside of https://cabal.readthedocs.io/en/stable/developing-packages.html#package-names-and-versions and "There is a separate installed package ID that uniquely identifies each installed package instance. Most of the time however, users need not be aware of this detail."

@erlandsona
Copy link
Author

@mpilgrem we're definitely keeping a close eye on the progress of that issue you mentioned and we'll give the --ghc-options -fforce-recomp a shot and see how that effects compile times 😬

Thanks for all your help with this!

@erlandsona
Copy link
Author

So we tried the --ghc-options -fforce-recomp and it balloons incremental recompilation from 7sec -> 33sec.
Which makes sense but is unfortunately not sufficient for our needs (authoring HTML view code).

Our current solution is to just put all the modules under a single package.yaml / library such that this bug doesn't surface.

Of course this has the drawback that any external repo's depending on this project have to compile unnecessary modules in order to leverage "shared types".

@mpilgrem
Copy link
Member

@erlandsona, there is now a related discussion at the Haskell Community. It appears that this may be a GHC bug, introduced in GHC 9.4.5 (or some other GHC 9.4 version). If you can use GHC 9.2.8, I think it may be free of the bug.

@wraithm
Copy link
Contributor

wraithm commented Aug 6, 2023

There's also now a ghc bug: https://gitlab.haskell.org/ghc/ghc/-/issues/23724

Thanks @mpilgrem and @erlandsona for figuring this out. We just upgraded to GHC 9.4.5, and I thought I was losing my mind for a bit there 😂

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants