pants package: error setting permissions on cache file

[bjkeller]

The following cache error just occurred.

$ pants package src/python/form_uploader:lambda
22:36:25.82 [ERROR] 1 Exception encountered:

Engine traceback:
  in `package` goal

IntrinsicError: Error setting permissions on /home/vscode/.cache/pants/lmdb_store/immutable/files/39/39589a7ed7a41afde02019677c33017641bb0ad1187d6efd9c45e06bb6b4eef6: Permission denied (os error 13)

Environment is a VSCode devcontainer (image: "mcr.microsoft.com/devcontainers/python:1-3.11-bullseye")

pants version: 2.17.0

[bjkeller]

.pants.d/pants.log:

14:54:05.46 [INFO] pantsd 2.17.0 running with PID: 1195
14:54:05.51 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] init`
14:54:05.98 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] init`
14:55:19.91 [INFO] notify invalidation: cleared 2 and dirtied 2 nodes for: {".gitignore", ""}
14:55:19.91 [INFO] notify invalidation: cleared 2 and dirtied 2 nodes for: {"", ".gitignore"}
14:55:25.88 [INFO] Extending leases
14:55:25.88 [INFO] Done extending leases
14:56:30.99 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {".gitignore"}
14:56:30.99 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {".gitignore"}
14:56:30.99 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {".gitignore"}
14:56:30.99 [INFO] Filesystem changed during run: retrying `DigestFile(.gitignore)` in 500ms...
14:56:30.99 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {".gitignore"}
14:56:30.99 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"", ".gitignore"}
14:56:30.99 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"", ".gitignore"}
14:56:31.00 [ERROR] saw filesystem changes covered by invalidation globs: content changed (Digest('bb4adeff7487901b14ec9777d6af5295c7c30f7d784fbbccf43f5429bf129731', 169) fs Digest('4ec9e93affbc44bf4b1cf9cbeb241fbba3e4bf6e54783bc05fb32819f291033f', 169)). terminating the daemon.
14:56:31.64 [ERROR] service failure for <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f207c01af40>.
14:56:31.65 [INFO] Waiting for ongoing runs to complete before exiting...
14:56:31.65 [INFO] Server exiting with Ok(())
14:56:31.65 [INFO] Waiting for Sessions to complete before exiting...
14:56:31.65 [INFO] Waiting for shutdown of: ["scheduler_service_session", "store_gc_service_session"]
14:56:31.66 [INFO] Shutdown completed: "scheduler_service_session"
14:56:31.66 [INFO] Shutdown completed: "store_gc_service_session"
14:56:31.66 [INFO] Exiting pantsd
14:56:31.66 [WARN] File watcher exiting with: The watcher was shut down.
14:56:31.70 [WARN] File watcher exiting with: The watcher was shut down.
15:50:59.57 [INFO] pantsd 2.17.0 running with PID: 5506
15:50:59.64 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] tailor ::`
15:50:59.70 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] tailor ::`
15:51:00.58 [ERROR] Client failed to create a Scheduler: shutting down.
15:51:00.60 [INFO] Waiting for ongoing runs to complete before exiting...
15:51:00.60 [INFO] Server exiting with Ok(())
15:51:00.60 [INFO] Waiting for Sessions to complete before exiting...
15:51:00.60 [INFO] Exiting pantsd
15:51:00.63 [WARN] File watcher exiting with: The watcher was shut down.
15:52:06.05 [INFO] pantsd 2.17.0 running with PID: 5786
15:52:06.08 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] tailor ::`
15:52:13.87 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] tailor ::`
15:53:33.75 [INFO] Extending leases
15:53:33.75 [INFO] Done extending leases
15:54:53.76 [INFO] Extending leases
15:54:53.77 [INFO] Done extending leases
15:56:13.77 [INFO] Extending leases
15:56:13.78 [INFO] Done extending leases
15:57:05.36 [INFO] notify invalidation: cleared 1 and dirtied 25 nodes for: {"", "src"}
15:57:33.78 [INFO] Extending leases
15:57:33.79 [INFO] Done extending leases
15:58:01.69 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] tailor ::`
15:58:01.89 [INFO] notify invalidation: cleared 1 and dirtied 36 nodes for: {"src/python/form-uploader", "src/python/form-uploader/BUILD"}
15:58:01.89 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/BUILD"}
15:58:01.89 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] tailor ::`
15:58:01.89 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/BUILD"}
15:58:53.80 [INFO] Extending leases
15:58:53.80 [INFO] Done extending leases
16:00:12.16 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] roots`
16:00:12.36 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] roots`
16:00:13.81 [INFO] Extending leases
16:00:13.81 [INFO] Done extending leases
16:01:33.82 [INFO] Extending leases
16:01:33.83 [INFO] Done extending leases
16:02:53.84 [INFO] Extending leases
16:02:53.84 [INFO] Done extending leases
16:03:17.41 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/uploader_handler.py"}
16:03:17.41 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/uploader_handler.py"}
16:03:17.41 [INFO] notify invalidation: cleared 1 and dirtied 42 nodes for: {"src/python/form-uploader/uploader_handler.py", "src/python/form-uploader"}
16:04:13.85 [INFO] Extending leases
16:04:13.86 [INFO] Done extending leases
16:05:33.87 [INFO] Extending leases
16:05:33.88 [INFO] Done extending leases
16:06:27.40 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/uploader_handler.py"}
16:06:27.41 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py", "src/python/form-uploader"}
16:06:27.41 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/uploader_handler.py", "src/python/form-uploader/lambda_function.py"}
16:06:53.88 [INFO] Extending leases
16:06:53.89 [INFO] Done extending leases
16:08:13.89 [INFO] Extending leases
16:08:13.90 [INFO] Done extending leases
16:09:33.91 [INFO] Extending leases
16:09:33.92 [INFO] Done extending leases
16:10:53.92 [INFO] Extending leases
16:10:53.93 [INFO] Done extending leases
16:12:13.93 [INFO] Extending leases
16:12:13.94 [INFO] Done extending leases
16:13:33.94 [INFO] Extending leases
16:13:33.95 [INFO] Done extending leases
16:14:53.96 [INFO] Extending leases
16:14:53.96 [INFO] Done extending leases
16:16:13.97 [INFO] Extending leases
16:16:13.97 [INFO] Done extending leases
16:17:33.98 [INFO] Extending leases
16:17:33.99 [INFO] Done extending leases
16:18:53.99 [INFO] Extending leases
16:18:54.00 [INFO] Done extending leases
16:20:14.00 [INFO] Extending leases
16:20:14.01 [INFO] Done extending leases
16:21:34.02 [INFO] Extending leases
16:21:34.02 [INFO] Done extending leases
16:22:54.03 [INFO] Extending leases
16:22:54.04 [INFO] Done extending leases
16:24:14.04 [INFO] Extending leases
16:24:14.05 [INFO] Done extending leases
16:25:34.06 [INFO] Extending leases
16:25:34.06 [INFO] Done extending leases
16:26:54.07 [INFO] Extending leases
16:26:54.08 [INFO] Done extending leases
16:28:14.08 [INFO] Extending leases
16:28:14.09 [INFO] Done extending leases
16:29:34.09 [INFO] Extending leases
16:29:34.10 [INFO] Done extending leases
16:30:54.11 [INFO] Extending leases
16:30:54.12 [INFO] Done extending leases
16:32:14.12 [INFO] Extending leases
16:32:14.13 [INFO] Done extending leases
16:33:34.13 [INFO] Extending leases
16:33:34.14 [INFO] Done extending leases
16:34:54.14 [INFO] Extending leases
16:34:54.15 [INFO] Done extending leases
16:36:14.16 [INFO] Extending leases
16:36:14.17 [INFO] Done extending leases
16:37:34.17 [INFO] Extending leases
16:37:34.18 [INFO] Done extending leases
16:38:54.19 [INFO] Extending leases
16:38:54.20 [INFO] Done extending leases
16:40:14.20 [INFO] Extending leases
16:40:14.21 [INFO] Done extending leases
16:41:28.77 [INFO] notify invalidation: cleared 1 and dirtied 49 nodes for: {"", "requirements.txt"}
16:41:28.78 [INFO] notify invalidation: cleared 1 and dirtied 49 nodes for: {"", "requirements.txt"}
16:41:34.21 [INFO] Extending leases
16:41:34.22 [INFO] Done extending leases
16:41:53.02 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"requirements.txt"}
16:41:53.02 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"requirements.txt"}
16:41:53.02 [INFO] notify invalidation: cleared 1 and dirtied 49 nodes for: {"", "requirements.txt"}
16:42:54.22 [INFO] Extending leases
16:42:54.23 [INFO] Done extending leases
16:44:14.23 [INFO] Extending leases
16:44:14.24 [INFO] Done extending leases
16:45:34.24 [INFO] Extending leases
16:45:34.25 [INFO] Done extending leases
16:46:54.25 [INFO] Extending leases
16:46:54.26 [INFO] Done extending leases
16:48:14.27 [INFO] Extending leases
16:48:14.28 [INFO] Done extending leases
16:48:48.66 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
16:48:48.66 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
16:48:48.66 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py", "src/python/form-uploader"}
16:57:44.05 [INFO] pantsd 2.17.0 running with PID: 2107
16:57:44.11 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] roots --roots-sep= `
16:57:51.31 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] roots --roots-sep= `
16:57:51.43 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] generate-lockfiles`
16:57:51.62 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] generate-lockfiles`
16:57:51.64 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] export --symlink-python-virtualenv --resolve=python-default`
16:57:51.86 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] export --symlink-python-virtualenv --resolve=python-default`
16:59:11.21 [INFO] Extending leases
16:59:11.22 [INFO] Done extending leases
16:59:56.57 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"pants.toml"}
16:59:56.57 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"pants.toml"}
16:59:56.57 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"pants.toml"}
16:59:56.57 [INFO] Filesystem changed during run: retrying `DigestFile(pants.toml)` in 500ms...
16:59:56.58 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"pants.toml"}
16:59:56.58 [INFO] notify invalidation: cleared 1 and dirtied 35 nodes for: {"", "pants.toml"}
16:59:56.58 [INFO] notify invalidation: cleared 1 and dirtied 35 nodes for: {"", "pants.toml"}
16:59:56.59 [ERROR] saw filesystem changes covered by invalidation globs: content changed (Digest('d3255e0f87fdd722cad1d452dcf0a5aa670d95be6d178c9555d80dc978c28304', 170) fs Digest('2ff7d1d17a7733d106d108ab36bcc5b407a7eb7e4b68250addcd1f7dfd3c0206', 170)). terminating the daemon.
16:59:57.37 [ERROR] service failure for <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f7686840f10>.
16:59:57.38 [INFO] Waiting for ongoing runs to complete before exiting...
16:59:57.38 [INFO] Server exiting with Ok(())
16:59:57.38 [INFO] Waiting for Sessions to complete before exiting...
16:59:57.38 [INFO] Waiting for shutdown of: ["scheduler_service_session", "store_gc_service_session", "pants_run_2023_09_08_16_57_51_257_2fe4f873f6644a8c8ae6173d24dd47b4", "pants_run_2023_09_08_16_57_51_554_90660dc819fa49c79ccfa47abac3677a", "pants_run_2023_09_08_16_57_51_777_1a3c2cf6eaa442c3bda3386bfd55ccff"]
16:59:57.38 [INFO] Shutdown completed: "scheduler_service_session"
16:59:57.38 [INFO] Shutdown completed: "store_gc_service_session"
16:59:57.38 [INFO] Shutdown completed: "pants_run_2023_09_08_16_57_51_257_2fe4f873f6644a8c8ae6173d24dd47b4"
16:59:57.38 [INFO] Shutdown completed: "pants_run_2023_09_08_16_57_51_554_90660dc819fa49c79ccfa47abac3677a"
16:59:57.38 [INFO] Shutdown completed: "pants_run_2023_09_08_16_57_51_777_1a3c2cf6eaa442c3bda3386bfd55ccff"
16:59:57.39 [INFO] Exiting pantsd
16:59:57.39 [WARN] File watcher exiting with: The watcher was shut down.
17:07:44.46 [INFO] pantsd 2.17.0 running with PID: 3801
17:07:44.47 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] roots --roots-sep= `
17:07:51.55 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] roots --roots-sep= `
17:07:51.66 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] generate-lockfiles`
17:07:55.78 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] generate-lockfiles`
17:07:55.80 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] export --py-resolve-format=symlinked_immutable_virtualenv --resolve=python-default`
17:07:57.28 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] export --py-resolve-format=symlinked_immutable_virtualenv --resolve=python-default`
17:09:10.24 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"bin/set-venv.sh"}
17:09:10.24 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"bin/set-venv.sh"}
17:09:10.25 [INFO] notify invalidation: cleared 1 and dirtied 14 nodes for: {"bin", "bin/set-venv.sh"}
17:09:11.45 [INFO] Extending leases
17:09:11.45 [INFO] Done extending leases
17:09:18.63 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] roots --roots-sep= `
17:09:18.86 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] roots --roots-sep= `
17:09:18.89 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] generate-lockfiles`
17:09:20.44 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] generate-lockfiles`
17:09:20.46 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] export --py-resolve-format=symlinked_immutable_virtualenv --resolve=python-default`
17:09:21.92 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] export --py-resolve-format=symlinked_immutable_virtualenv --resolve=python-default`
17:09:21.94 [INFO] notify invalidation: cleared 1 and dirtied 50 nodes for: {"", "venv"}
17:10:31.46 [INFO] Extending leases
17:10:31.46 [INFO] Done extending leases
17:11:13.65 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"pants.toml"}
17:11:13.65 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"pants.toml"}
17:11:13.66 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"pants.toml"}
17:11:13.66 [INFO] Filesystem changed during run: retrying `DigestFile(pants.toml)` in 500ms...
17:11:13.66 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"pants.toml"}
17:11:13.66 [INFO] notify invalidation: cleared 1 and dirtied 50 nodes for: {"", "pants.toml"}
17:11:13.66 [INFO] notify invalidation: cleared 1 and dirtied 50 nodes for: {"", "pants.toml"}
17:11:13.67 [ERROR] saw filesystem changes covered by invalidation globs: content changed (Digest('11780a59fd0004f910bfebf492432354c401e23a3f8887eccd651263dbff32ad', 170) fs Digest('bbc0480ec79702b555c00af755b499d4120cec567161eb424d18e9dee9db3f0f', 170)). terminating the daemon.
17:11:13.70 [ERROR] service failure for <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f91ed1f5f10>.
17:11:13.71 [INFO] Waiting for ongoing runs to complete before exiting...
17:11:13.72 [INFO] Server exiting with Ok(())
17:11:13.72 [INFO] Waiting for Sessions to complete before exiting...
17:11:13.72 [INFO] Waiting for shutdown of: ["scheduler_service_session", "store_gc_service_session", "pants_run_2023_09_08_17_07_51_495_826da5f990e44ba19dba3f4cf50a2f94", "pants_run_2023_09_08_17_07_51_783_af5b29f1bddb45d1bebbc6ea05a79daa", "pants_run_2023_09_08_17_07_55_943_b80ed326b2d34e26a194046b48e19096", "pants_run_2023_09_08_17_09_18_810_7cb5f1d50cbd4784a5b6452aecd34795", "pants_run_2023_09_08_17_09_19_17_2b82bc573ed24487a67dd1de01b36297", "pants_run_2023_09_08_17_09_20_596_62261bc17a2e44bc9546aeba980652a7"]
17:11:13.72 [INFO] Shutdown completed: "scheduler_service_session"
17:11:13.72 [INFO] Shutdown completed: "store_gc_service_session"
17:11:13.72 [INFO] Shutdown completed: "pants_run_2023_09_08_17_07_51_495_826da5f990e44ba19dba3f4cf50a2f94"
17:11:13.72 [INFO] Shutdown completed: "pants_run_2023_09_08_17_07_51_783_af5b29f1bddb45d1bebbc6ea05a79daa"
17:11:13.72 [INFO] Shutdown completed: "pants_run_2023_09_08_17_07_55_943_b80ed326b2d34e26a194046b48e19096"
17:11:13.72 [INFO] Shutdown completed: "pants_run_2023_09_08_17_09_18_810_7cb5f1d50cbd4784a5b6452aecd34795"
17:11:13.72 [INFO] Shutdown completed: "pants_run_2023_09_08_17_09_19_17_2b82bc573ed24487a67dd1de01b36297"
17:11:13.73 [INFO] Shutdown completed: "pants_run_2023_09_08_17_09_20_596_62261bc17a2e44bc9546aeba980652a7"
17:11:13.73 [INFO] Exiting pantsd
17:11:13.73 [WARN] File watcher exiting with: The watcher was shut down.
17:11:33.40 [INFO] pantsd 2.17.0 running with PID: 4714
17:11:33.48 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] roots --roots-sep= `
17:11:40.53 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] roots --roots-sep= `
17:11:40.65 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] generate-lockfiles`
17:11:42.27 [INFO] notify invalidation: cleared 1 and dirtied 44 nodes for: {"", "python-default.lock"}
17:11:42.27 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"python-default.lock"}
17:11:42.27 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] generate-lockfiles`
17:11:42.27 [INFO] notify invalidation: cleared 1 and dirtied 46 nodes for: {"", "python-default.lock"}
17:11:42.29 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] export --py-resolve-format=symlinked_immutable_virtualenv --resolve=python-default`
17:11:46.20 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] export --py-resolve-format=symlinked_immutable_virtualenv --resolve=python-default`
17:11:46.22 [INFO] notify invalidation: cleared 1 and dirtied 55 nodes for: {"", "CuVSSJqi"}
17:11:46.22 [INFO] notify invalidation: cleared 1 and dirtied 55 nodes for: {"", "CuVSSJqi"}
17:11:46.22 [INFO] notify invalidation: cleared 2 and dirtied 55 nodes for: {"", "venv"}
17:11:46.22 [INFO] Filesystem changed during run: retrying `Scandir()` in 500ms...
17:11:46.22 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"venv", "", "CuVSSJqi"}
17:11:46.22 [INFO] Filesystem changed during run: retrying `Scandir()` in 500ms...
17:11:46.22 [INFO] Filesystem changed during run: retrying `Scandir()` in 500ms...
17:13:00.43 [INFO] Extending leases
17:13:00.44 [INFO] Done extending leases
17:14:20.45 [INFO] Extending leases
17:14:20.45 [INFO] Done extending leases
17:15:40.46 [INFO] Extending leases
17:15:40.47 [INFO] Done extending leases
17:16:41.48 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:16:41.48 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:16:41.49 [INFO] notify invalidation: cleared 1 and dirtied 27 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
17:17:00.47 [INFO] Extending leases
17:17:00.48 [INFO] Done extending leases
17:18:20.49 [INFO] Extending leases
17:18:20.50 [INFO] Done extending leases
17:19:40.51 [INFO] Extending leases
17:19:40.51 [INFO] Done extending leases
17:21:00.52 [INFO] Extending leases
17:21:00.53 [INFO] Done extending leases
17:26:04.24 [INFO] pantsd 2.17.0 running with PID: 2134
17:26:04.26 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] roots --roots-sep= `
17:26:11.35 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] roots --roots-sep= `
17:26:11.46 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] generate-lockfiles`
17:26:15.85 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"python-default.lock"}
17:26:15.86 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"python-default.lock"}
17:26:15.86 [INFO] notify invalidation: cleared 1 and dirtied 47 nodes for: {"python-default.lock", ""}
17:26:15.86 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] generate-lockfiles`
17:26:15.88 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] export --py-resolve-format=symlinked_immutable_virtualenv --resolve=python-default`
17:26:19.76 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] export --py-resolve-format=symlinked_immutable_virtualenv --resolve=python-default`
17:26:19.77 [INFO] notify invalidation: cleared 1 and dirtied 56 nodes for: {"", "CuN7ZjRq"}
17:26:19.77 [INFO] notify invalidation: cleared 1 and dirtied 56 nodes for: {"", "CuN7ZjRq"}
17:26:19.77 [INFO] notify invalidation: cleared 2 and dirtied 56 nodes for: {"venv", ""}
17:26:19.77 [INFO] Filesystem changed during run: retrying `Scandir()` in 500ms...
17:26:19.77 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"", "venv", "CuN7ZjRq"}
17:26:19.77 [INFO] Filesystem changed during run: retrying `Scandir()` in 500ms...
17:26:19.77 [INFO] Filesystem changed during run: retrying `Scandir()` in 500ms...
17:27:31.25 [INFO] Extending leases
17:27:31.26 [INFO] Done extending leases
17:28:51.27 [INFO] Extending leases
17:28:51.27 [INFO] Done extending leases
17:30:11.28 [INFO] Extending leases
17:30:11.29 [INFO] Done extending leases
17:31:31.29 [INFO] Extending leases
17:31:31.30 [INFO] Done extending leases
17:32:51.31 [INFO] Extending leases
17:32:51.32 [INFO] Done extending leases
17:34:11.32 [INFO] Extending leases
17:34:11.33 [INFO] Done extending leases
17:35:31.34 [INFO] Extending leases
17:35:31.35 [INFO] Done extending leases
17:36:59.12 [INFO] Extending leases
17:36:59.25 [INFO] Done extending leases
17:38:19.46 [INFO] Extending leases
17:38:19.47 [INFO] Done extending leases
17:39:39.47 [INFO] Extending leases
17:39:39.48 [INFO] Done extending leases
17:40:59.48 [INFO] Extending leases
17:40:59.49 [INFO] Done extending leases
17:41:13.87 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"BUILD", ""}
17:41:13.87 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"", "BUILD"}
17:41:55.13 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"BUILD"}
17:41:55.13 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"BUILD"}
17:41:55.14 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"", "BUILD"}
17:42:02.77 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] roots --roots-sep= `
17:42:03.04 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] roots --roots-sep= `
17:42:03.08 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] generate-lockfiles`
17:42:19.50 [INFO] Extending leases
17:42:19.50 [INFO] Done extending leases
17:42:38.70 [INFO] notify invalidation: cleared 1 and dirtied 9 nodes for: {"python-default.lock"}
17:42:38.70 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"python-default.lock"}
17:42:38.71 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"python-default.lock"}
17:42:38.71 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] generate-lockfiles`
17:42:38.71 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"python-default.lock"}
17:42:38.71 [INFO] notify invalidation: cleared 1 and dirtied 69 nodes for: {"", "python-default.lock"}
17:42:38.71 [INFO] notify invalidation: cleared 1 and dirtied 69 nodes for: {"", "python-default.lock"}
17:42:38.71 [INFO] Filesystem changed during run: retrying `Scandir()` in 500ms...
17:42:38.72 [INFO] Filesystem changed during run: retrying `Scandir()` in 500ms...
17:42:38.72 [INFO] Filesystem changed during run: retrying `Scandir()` in 500ms...
17:42:38.73 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] export --py-resolve-format=symlinked_immutable_virtualenv --resolve=python-default`
17:42:47.18 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] export --py-resolve-format=symlinked_immutable_virtualenv --resolve=python-default`
17:42:47.19 [INFO] notify invalidation: cleared 1 and dirtied 71 nodes for: {"CubcP47v", ""}
17:42:47.19 [INFO] notify invalidation: cleared 1 and dirtied 71 nodes for: {"", "CubcP47v"}
17:42:47.19 [INFO] Filesystem changed during run: retrying `Scandir()` in 500ms...
17:42:47.20 [INFO] Filesystem changed during run: retrying `Scandir()` in 500ms...
17:42:47.19 [INFO] notify invalidation: cleared 1 and dirtied 18 nodes for: {"", "venv"}
17:42:47.20 [INFO] Filesystem changed during run: retrying `Scandir()` in 500ms...
17:42:47.20 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"CubcP47v", "venv", ""}
17:43:39.51 [INFO] Extending leases
17:43:39.52 [INFO] Done extending leases
17:43:54.52 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:43:54.53 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:43:54.53 [INFO] notify invalidation: cleared 1 and dirtied 31 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
17:44:48.00 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:44:48.00 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:44:48.00 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py", "src/python/form-uploader"}
17:44:59.52 [INFO] Extending leases
17:44:59.53 [INFO] Done extending leases
17:46:19.54 [INFO] Extending leases
17:46:19.56 [INFO] Done extending leases
17:46:48.48 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:46:48.48 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:46:48.48 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
17:47:20.81 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:47:20.81 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:47:20.81 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
17:47:39.56 [INFO] Extending leases
17:47:39.60 [INFO] Done extending leases
17:47:55.31 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:47:55.32 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:47:55.32 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py", "src/python/form-uploader"}
17:48:15.83 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:48:15.83 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:48:15.83 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
17:48:59.60 [INFO] Extending leases
17:48:59.61 [INFO] Done extending leases
17:49:35.47 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:49:35.47 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
17:49:35.48 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
17:50:19.62 [INFO] Extending leases
17:50:19.63 [INFO] Done extending leases
17:51:39.63 [INFO] Extending leases
17:51:39.64 [INFO] Done extending leases
17:52:59.65 [INFO] Extending leases
17:52:59.66 [INFO] Done extending leases
17:54:19.66 [INFO] Extending leases
17:54:19.68 [INFO] Done extending leases
17:55:39.68 [INFO] Extending leases
17:55:39.69 [INFO] Done extending leases
17:56:59.70 [INFO] Extending leases
17:56:59.71 [INFO] Done extending leases
17:58:19.71 [INFO] Extending leases
17:58:19.72 [INFO] Done extending leases
17:59:39.73 [INFO] Extending leases
17:59:39.74 [INFO] Done extending leases
18:00:59.74 [INFO] Extending leases
18:00:59.75 [INFO] Done extending leases
18:02:19.76 [INFO] Extending leases
18:02:19.77 [INFO] Done extending leases
18:03:39.77 [INFO] Extending leases
18:03:39.78 [INFO] Done extending leases
18:04:59.79 [INFO] Extending leases
18:04:59.80 [INFO] Done extending leases
18:06:19.80 [INFO] Extending leases
18:06:19.81 [INFO] Done extending leases
18:07:39.82 [INFO] Extending leases
18:07:39.83 [INFO] Done extending leases
18:08:59.83 [INFO] Extending leases
18:08:59.84 [INFO] Done extending leases
18:10:19.85 [INFO] Extending leases
18:10:19.86 [INFO] Done extending leases
18:11:39.86 [INFO] Extending leases
18:11:39.87 [INFO] Done extending leases
18:12:59.88 [INFO] Extending leases
18:12:59.89 [INFO] Done extending leases
18:14:19.89 [INFO] Extending leases
18:14:19.90 [INFO] Done extending leases
18:15:39.91 [INFO] Extending leases
18:15:39.92 [INFO] Done extending leases
18:16:59.92 [INFO] Extending leases
18:16:59.93 [INFO] Done extending leases
18:18:19.94 [INFO] Extending leases
18:18:19.95 [INFO] Done extending leases
18:19:39.95 [INFO] Extending leases
18:19:39.97 [INFO] Done extending leases
18:20:59.97 [INFO] Extending leases
18:20:59.98 [INFO] Done extending leases
18:22:19.99 [INFO] Extending leases
18:22:19.99 [INFO] Done extending leases
18:23:40.00 [INFO] Extending leases
18:23:40.01 [INFO] Done extending leases
18:25:00.01 [INFO] Extending leases
18:25:00.02 [INFO] Done extending leases
18:25:10.66 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:25:10.66 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:25:10.67 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
18:25:58.93 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:25:58.94 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:25:58.94 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
18:26:09.21 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:26:09.21 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:26:09.21 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py", "src/python/form-uploader"}
18:26:20.03 [INFO] Garbage collecting store. target_size=28,800,000,000
18:26:20.03 [INFO] Done garbage collecting store
18:26:20.03 [INFO] Extending leases
18:26:20.04 [INFO] Done extending leases
18:27:40.04 [INFO] Extending leases
18:27:40.05 [INFO] Done extending leases
18:27:42.84 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:27:42.84 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:27:42.85 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
18:29:00.06 [INFO] Extending leases
18:29:00.06 [INFO] Done extending leases
18:30:20.07 [INFO] Extending leases
18:30:20.08 [INFO] Done extending leases
18:31:40.08 [INFO] Extending leases
18:31:40.09 [INFO] Done extending leases
18:33:00.10 [INFO] Extending leases
18:33:00.11 [INFO] Done extending leases
18:33:55.85 [INFO] notify invalidation: cleared 1 and dirtied 20 nodes for: {"src/python/form-uploader/BUILD"}
18:33:55.85 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/BUILD"}
18:33:55.85 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/BUILD"}
18:33:55.85 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/BUILD"}
18:33:55.85 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/BUILD"}
18:33:55.85 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/BUILD", "src/python/form-uploader"}
18:34:20.11 [INFO] Extending leases
18:34:20.13 [INFO] Done extending leases
18:35:21.85 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] package form-uploader`
18:35:22.19 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] package form-uploader`
18:35:34.36 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] package form-uploader:lambda`
18:35:34.54 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] package form-uploader:lambda`
18:35:40.13 [INFO] Extending leases
18:35:40.14 [INFO] Done extending leases
18:35:48.59 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] package src/python/form-uploader:lambda`
18:35:57.98 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] package src/python/form-uploader:lambda`
18:37:00.14 [INFO] Extending leases
18:37:00.16 [INFO] Done extending leases
18:37:41.88 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"README.md"}
18:37:41.88 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"README.md"}
18:37:41.88 [INFO] notify invalidation: cleared 1 and dirtied 171 nodes for: {"", "README.md"}
18:37:47.63 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"README.md"}
18:37:47.63 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"README.md"}
18:37:47.63 [INFO] notify invalidation: cleared 1 and dirtied 171 nodes for: {"README.md", ""}
18:38:20.16 [INFO] Extending leases
18:38:20.18 [INFO] Done extending leases
18:39:32.82 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"README.md"}
18:39:32.82 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"README.md"}
18:39:32.83 [INFO] notify invalidation: cleared 1 and dirtied 171 nodes for: {"", "README.md"}
18:39:40.18 [INFO] Extending leases
18:39:40.20 [INFO] Done extending leases
18:41:00.20 [INFO] Extending leases
18:41:00.21 [INFO] Done extending leases
18:42:20.22 [INFO] Extending leases
18:42:20.23 [INFO] Done extending leases
18:43:40.24 [INFO] Extending leases
18:43:40.25 [INFO] Done extending leases
18:45:00.26 [INFO] Extending leases
18:45:00.27 [INFO] Done extending leases
18:46:20.27 [INFO] Extending leases
18:46:20.29 [INFO] Done extending leases
18:47:34.65 [INFO] notify invalidation: cleared 1 and dirtied 25 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:47:34.65 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:47:34.66 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:47:34.66 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:47:34.66 [INFO] notify invalidation: cleared 1 and dirtied 97 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
18:47:34.66 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py", "src/python/form-uploader"}
18:47:40.29 [INFO] Extending leases
18:47:40.31 [INFO] Done extending leases
18:49:00.31 [INFO] Extending leases
18:49:00.33 [INFO] Done extending leases
18:50:20.33 [INFO] Extending leases
18:50:20.35 [INFO] Done extending leases
18:50:43.64 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:50:43.64 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:50:43.64 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:50:43.64 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:50:43.64 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
18:50:43.65 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
18:50:51.16 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:50:51.16 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:50:51.16 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:50:51.16 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:50:51.16 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
18:50:51.16 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py", "src/python/form-uploader"}
18:51:11.59 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] fmt src::`
18:51:11.77 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] fmt src::`
18:51:40.35 [INFO] Extending leases
18:51:40.38 [INFO] Done extending leases
18:52:39.02 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"pants.toml"}
18:52:39.02 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"pants.toml"}
18:52:39.03 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"pants.toml"}
18:52:39.03 [INFO] Filesystem changed during run: retrying `DigestFile(pants.toml)` in 500ms...
18:52:39.03 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"pants.toml"}
18:52:39.03 [INFO] notify invalidation: cleared 1 and dirtied 171 nodes for: {"", "pants.toml"}
18:52:39.03 [INFO] notify invalidation: cleared 1 and dirtied 171 nodes for: {"pants.toml", ""}
18:52:39.04 [ERROR] saw filesystem changes covered by invalidation globs: content changed (Digest('3a0fdc9ee50d0f84ec8d4b03c443a8cba3ab50724764a57256f7e4ccf1a0bf7c', 170) fs Digest('c894d2bf9b3c9c848105a2a2050bd4bc55a5bc9073e489b69c97c262b0fa6da2', 170)). terminating the daemon.
18:52:39.67 [ERROR] service failure for <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7fb8080a5f70>.
18:52:39.68 [INFO] Waiting for ongoing runs to complete before exiting...
18:52:39.68 [INFO] Server exiting with Ok(())
18:52:39.68 [INFO] Waiting for Sessions to complete before exiting...
18:52:39.68 [INFO] Waiting for shutdown of: ["scheduler_service_session", "store_gc_service_session", "pants_run_2023_09_08_17_26_11_296_261661f48ce0427c8098f83a8ef39096", "pants_run_2023_09_08_17_26_11_580_c704fd7053bc4477b270344bcfab675b", "pants_run_2023_09_08_17_26_16_13_a12e9beb528c4fc68a1d103c48e41fcf", "pants_run_2023_09_08_17_42_02_980_044f140d67b149589de1c96153817d6d", "pants_run_2023_09_08_17_42_03_193_30fdb30b79be4283928301fd4cd4047a", "pants_run_2023_09_08_17_42_38_876_1567c5b452f4446e904b2e11853dd510", "pants_run_2023_09_08_18_35_34_489_55a04f7412f44338ad536e0b8a0a5345", "pants_run_2023_09_08_18_35_48_723_ef31e40b1b0245ab81dc0dd9610c3e73"]
18:52:39.69 [INFO] Shutdown completed: "scheduler_service_session"
18:52:39.69 [INFO] Shutdown completed: "store_gc_service_session"
18:52:39.69 [INFO] Shutdown completed: "pants_run_2023_09_08_17_26_11_296_261661f48ce0427c8098f83a8ef39096"
18:52:39.69 [INFO] Shutdown completed: "pants_run_2023_09_08_17_26_11_580_c704fd7053bc4477b270344bcfab675b"
18:52:39.69 [INFO] Shutdown completed: "pants_run_2023_09_08_17_26_16_13_a12e9beb528c4fc68a1d103c48e41fcf"
18:52:39.69 [INFO] Shutdown completed: "pants_run_2023_09_08_17_42_02_980_044f140d67b149589de1c96153817d6d"
18:52:39.69 [INFO] Shutdown completed: "pants_run_2023_09_08_17_42_03_193_30fdb30b79be4283928301fd4cd4047a"
18:52:39.69 [INFO] Shutdown completed: "pants_run_2023_09_08_17_42_38_876_1567c5b452f4446e904b2e11853dd510"
18:52:39.69 [INFO] Shutdown completed: "pants_run_2023_09_08_18_35_34_489_55a04f7412f44338ad536e0b8a0a5345"
18:52:39.70 [INFO] Shutdown completed: "pants_run_2023_09_08_18_35_48_723_ef31e40b1b0245ab81dc0dd9610c3e73"
18:52:39.70 [INFO] Exiting pantsd
18:52:39.71 [WARN] File watcher exiting with: The watcher was shut down.
18:53:02.23 [INFO] pantsd 2.17.0 running with PID: 17244
18:53:02.30 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] fmt src::`
18:53:02.35 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] fmt src::`
18:53:03.24 [ERROR] Client failed to create a Scheduler: shutting down.
18:53:03.25 [INFO] Waiting for ongoing runs to complete before exiting...
18:53:03.25 [INFO] Server exiting with Ok(())
18:53:03.25 [INFO] Waiting for Sessions to complete before exiting...
18:53:03.26 [INFO] Exiting pantsd
18:53:03.29 [WARN] File watcher exiting with: The watcher was shut down.
18:53:35.65 [INFO] pantsd 2.17.0 running with PID: 17442
18:53:35.77 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] fmt src::`
18:53:59.31 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"src/python/form-uploader/__init__.py"}
18:53:59.32 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/__init__.py"}
18:53:59.32 [INFO] notify invalidation: cleared 1 and dirtied 52 nodes for: {"src/python/form-uploader/__init__.py", "src/python/form-uploader"}
18:53:59.32 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] fmt src::`
18:53:59.32 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/__init__.py", "src/python/form-uploader"}
18:53:59.33 [INFO] notify invalidation: cleared 1 and dirtied 31 nodes for: {"src/python/form-uploader/BUILD"}
18:53:59.33 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/BUILD"}
18:53:59.33 [INFO] notify invalidation: cleared 1 and dirtied 4 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:53:59.33 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:53:59.33 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/BUILD"}
18:53:59.33 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/BUILD"}
18:53:59.33 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/BUILD", "src/python/form-uploader"}
18:53:59.33 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/BUILD"}
18:53:59.33 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:53:59.34 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:53:59.34 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
18:53:59.34 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py", "src/python/form-uploader"}
18:54:10.68 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] lint src::`
18:54:24.21 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] lint src::`
18:55:05.38 [INFO] Extending leases
18:55:05.42 [INFO] Done extending leases
18:56:20.79 [INFO] notify invalidation: cleared 1 and dirtied 31 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:56:20.79 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:56:20.79 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:56:20.79 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:56:20.80 [INFO] notify invalidation: cleared 1 and dirtied 125 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
18:56:20.80 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py", "src/python/form-uploader"}
18:56:25.43 [INFO] Extending leases
18:56:25.45 [INFO] Done extending leases
18:56:34.43 [INFO] handling request: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] lint src::`
18:56:35.99 [INFO] request completed: `--python-repos-find-links=-['https://wheels.pantsbuild.org/simple/'] lint src::`
18:57:40.49 [INFO] notify invalidation: cleared 1 and dirtied 33 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:57:40.49 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:57:40.49 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:57:40.49 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
18:57:40.49 [INFO] notify invalidation: cleared 1 and dirtied 132 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
18:57:40.49 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
18:57:45.46 [INFO] Extending leases
18:57:45.50 [INFO] Done extending leases
18:59:05.50 [INFO] Extending leases
18:59:05.53 [INFO] Done extending leases
19:00:25.54 [INFO] Extending leases
19:00:25.57 [INFO] Done extending leases
19:01:45.58 [INFO] Extending leases
19:01:45.61 [INFO] Done extending leases
19:03:05.62 [INFO] Extending leases
19:03:05.66 [INFO] Done extending leases
19:04:22.56 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
19:04:22.56 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
19:04:22.56 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
19:04:22.56 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
19:04:22.57 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
19:04:22.57 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
19:04:25.66 [INFO] Extending leases
19:04:25.70 [INFO] Done extending leases
19:05:45.70 [INFO] Extending leases
19:05:45.73 [INFO] Done extending leases
19:07:05.74 [INFO] Extending leases
19:07:05.77 [INFO] Done extending leases
19:08:25.78 [INFO] Extending leases
19:08:25.81 [INFO] Done extending leases
19:09:45.81 [INFO] Extending leases
19:09:45.85 [INFO] Done extending leases
19:11:05.86 [INFO] Extending leases
19:11:05.89 [INFO] Done extending leases
19:12:25.89 [INFO] Extending leases
19:12:25.93 [INFO] Done extending leases
19:13:45.94 [INFO] Extending leases
19:13:45.97 [INFO] Done extending leases
19:15:05.98 [INFO] Extending leases
19:15:06.00 [INFO] Done extending leases
19:16:26.00 [INFO] Extending leases
19:16:26.04 [INFO] Done extending leases
19:17:46.05 [INFO] Extending leases
19:17:46.08 [INFO] Done extending leases
19:19:04.21 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"README.md"}
19:19:04.21 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"README.md"}
19:19:04.21 [INFO] notify invalidation: cleared 1 and dirtied 186 nodes for: {"", "README.md"}
19:19:06.09 [INFO] Extending leases
19:19:06.12 [INFO] Done extending leases
19:20:26.13 [INFO] Extending leases
19:20:26.16 [INFO] Done extending leases
19:21:46.16 [INFO] Extending leases
19:21:46.20 [INFO] Done extending leases
19:21:59.14 [INFO] notify invalidation: cleared 1 and dirtied 61 nodes for: {"requirements.txt"}
19:21:59.14 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"requirements.txt"}
19:21:59.14 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"requirements.txt"}
19:21:59.15 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"requirements.txt"}
19:21:59.15 [INFO] notify invalidation: cleared 1 and dirtied 186 nodes for: {"", "requirements.txt"}
19:21:59.15 [INFO] notify invalidation: cleared 1 and dirtied 186 nodes for: {"", "requirements.txt"}
19:22:00.86 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"requirements.txt"}
19:22:00.86 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"requirements.txt"}
19:22:00.86 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"requirements.txt"}
19:22:00.86 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"requirements.txt"}
19:22:00.87 [INFO] notify invalidation: cleared 1 and dirtied 186 nodes for: {"requirements.txt", ""}
19:22:00.87 [INFO] notify invalidation: cleared 1 and dirtied 186 nodes for: {"requirements.txt", ""}
19:23:06.20 [INFO] Extending leases
19:23:06.24 [INFO] Done extending leases
19:24:26.25 [INFO] Extending leases
19:24:26.28 [INFO] Done extending leases
19:25:46.29 [INFO] Extending leases
19:25:46.32 [INFO] Done extending leases
19:27:06.32 [INFO] Extending leases
19:27:06.36 [INFO] Done extending leases
19:28:26.36 [INFO] Extending leases
19:28:26.40 [INFO] Done extending leases
19:29:46.40 [INFO] Extending leases
19:29:46.43 [INFO] Done extending leases
19:31:06.44 [INFO] Extending leases
19:31:06.47 [INFO] Done extending leases
19:32:26.48 [INFO] Extending leases
19:32:26.51 [INFO] Done extending leases
19:33:46.52 [INFO] Extending leases
19:33:46.55 [INFO] Done extending leases
19:35:06.56 [INFO] Extending leases
19:35:06.59 [INFO] Done extending leases
19:36:26.60 [INFO] Extending leases
19:36:26.63 [INFO] Done extending leases
19:37:46.64 [INFO] Extending leases
19:37:46.67 [INFO] Done extending leases
19:39:06.68 [INFO] Extending leases
19:39:06.71 [INFO] Done extending leases
19:40:26.72 [INFO] Extending leases
19:40:26.76 [INFO] Done extending leases
19:41:46.76 [INFO] Extending leases
19:41:46.79 [INFO] Done extending leases
19:42:35.81 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {".gitignore"}
19:42:35.81 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {".gitignore"}
19:42:35.81 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {".gitignore"}
19:42:35.81 [INFO] Filesystem changed during run: retrying `DigestFile(.gitignore)` in 500ms...
19:42:35.82 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {".gitignore"}
19:42:35.82 [INFO] notify invalidation: cleared 1 and dirtied 186 nodes for: {"", ".gitignore"}
19:42:35.82 [INFO] notify invalidation: cleared 1 and dirtied 186 nodes for: {".gitignore", ""}
19:42:35.83 [ERROR] saw filesystem changes covered by invalidation globs: content changed (Digest('51ac068dfb3dad3d770fae82b7c4b862582ccc45df885990be537733a74530c2', 170) fs Digest('fab6ce7b58fe00f04549cdc1b896e7e8417edccaf8243b059520fb1c0f5b12d0', 170)). terminating the daemon.
19:42:36.00 [ERROR] service failure for <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7f5cb57bffd0>.
19:42:36.01 [INFO] Waiting for ongoing runs to complete before exiting...
19:42:36.01 [INFO] Server exiting with Ok(())
19:42:36.02 [INFO] Waiting for Sessions to complete before exiting...
19:42:36.02 [INFO] Waiting for shutdown of: ["scheduler_service_session", "store_gc_service_session", "pants_run_2023_09_08_18_53_45_444_efdd8d710edf462b869e856238fe7443", "pants_run_2023_09_08_18_54_10_838_e23af2b700ab41c2b4b053f70a50243e", "pants_run_2023_09_08_18_56_34_604_7cf3158c02244d5db1e7bd4e2da7eadb"]
19:42:36.02 [INFO] Shutdown completed: "scheduler_service_session"
19:42:36.02 [INFO] Shutdown completed: "store_gc_service_session"
19:42:36.02 [INFO] Shutdown completed: "pants_run_2023_09_08_18_53_45_444_efdd8d710edf462b869e856238fe7443"
19:42:36.02 [INFO] Shutdown completed: "pants_run_2023_09_08_18_54_10_838_e23af2b700ab41c2b4b053f70a50243e"
19:42:36.02 [INFO] Shutdown completed: "pants_run_2023_09_08_18_56_34_604_7cf3158c02244d5db1e7bd4e2da7eadb"
19:42:36.02 [INFO] Exiting pantsd
19:42:36.03 [WARN] File watcher exiting with: The watcher was shut down.
21:59:07.55 [INFO] pantsd 2.17.0 running with PID: 3574
21:59:07.63 [INFO] handling request: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] run pip -- --outdated`
21:59:18.54 [INFO] request completed: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] run pip -- --outdated`
22:00:29.14 [INFO] handling request: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] roots --roots-sep= `
22:00:29.41 [INFO] request completed: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] roots --roots-sep= `
22:00:29.44 [INFO] handling request: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] generate-lockfiles`
22:00:38.29 [INFO] Extending leases
22:00:38.29 [INFO] Done extending leases
22:01:17.18 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
22:01:17.19 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
22:01:17.19 [INFO] notify invalidation: cleared 1 and dirtied 31 nodes for: {"src/python/form-uploader", "src/python/form-uploader/lambda_function.py"}
22:01:17.22 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader/lambda_function.py"}
22:01:58.32 [INFO] Extending leases
22:01:58.32 [INFO] Done extending leases
22:03:18.34 [INFO] Extending leases
22:03:18.34 [INFO] Done extending leases
22:03:46.97 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"python-default.lock"}
22:03:46.97 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"python-default.lock"}
22:03:46.97 [INFO] notify invalidation: cleared 1 and dirtied 61 nodes for: {"python-default.lock", ""}
22:03:46.97 [INFO] request completed: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] generate-lockfiles`
22:03:46.99 [INFO] handling request: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] export --py-resolve-format=symlinked_immutable_virtualenv --resolve=python-default`
22:03:47.19 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"python-default.lock"}
22:04:38.35 [INFO] Extending leases
22:04:38.36 [INFO] Done extending leases
22:04:48.58 [INFO] request completed: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] export --py-resolve-format=symlinked_immutable_virtualenv --resolve=python-default`
22:04:48.58 [INFO] notify invalidation: cleared 1 and dirtied 70 nodes for: {"", "CuykaaD4"}
22:04:48.58 [INFO] notify invalidation: cleared 1 and dirtied 70 nodes for: {"CuykaaD4", ""}
22:04:48.58 [INFO] notify invalidation: cleared 1 and dirtied 70 nodes for: {"", "CuykaaD4"}
22:04:48.58 [INFO] Filesystem changed during run: retrying `Scandir()` in 500ms...
22:04:48.59 [INFO] Filesystem changed during run: retrying `Scandir()` in 500ms...
22:04:48.59 [INFO] Filesystem changed during run: retrying `Scandir()` in 500ms...
22:05:58.39 [INFO] Extending leases
22:05:58.39 [INFO] Done extending leases
22:07:18.43 [INFO] Extending leases
22:07:18.44 [INFO] Done extending leases
22:08:38.45 [INFO] Extending leases
22:08:38.46 [INFO] Done extending leases
22:09:58.48 [INFO] Extending leases
22:09:58.49 [INFO] Done extending leases
22:11:18.50 [INFO] Extending leases
22:11:18.51 [INFO] Done extending leases
22:12:38.54 [INFO] Extending leases
22:12:38.55 [INFO] Done extending leases
22:13:58.57 [INFO] Extending leases
22:13:58.58 [INFO] Done extending leases
22:15:18.59 [INFO] Extending leases
22:15:18.60 [INFO] Done extending leases
22:16:38.62 [INFO] Extending leases
22:16:38.63 [INFO] Done extending leases
22:17:58.64 [INFO] Extending leases
22:17:58.65 [INFO] Done extending leases
22:19:18.67 [INFO] Extending leases
22:19:18.68 [INFO] Done extending leases
22:20:38.69 [INFO] Extending leases
22:20:38.70 [INFO] Done extending leases
22:21:58.71 [INFO] Extending leases
22:21:58.72 [INFO] Done extending leases
22:23:18.74 [INFO] Extending leases
22:23:18.75 [INFO] Done extending leases
22:24:38.78 [INFO] Extending leases
22:24:38.79 [INFO] Done extending leases
22:25:58.81 [INFO] Extending leases
22:25:58.82 [INFO] Done extending leases
22:27:18.83 [INFO] Extending leases
22:27:18.84 [INFO] Done extending leases
22:28:14.81 [INFO] notify invalidation: cleared 2 and dirtied 33 nodes for: {"src/python/form-uploader", "src/python"}
22:28:14.81 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form_uploader", "src/python"}
22:28:14.81 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form-uploader", "src/python", "src/python/form_uploader"}
22:28:14.81 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python", "src/python/form-uploader"}
22:28:14.85 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"src/python/form_uploader", "src/python"}
22:28:38.88 [INFO] Extending leases
22:28:38.89 [INFO] Done extending leases
22:29:32.07 [INFO] handling request: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] package src/python/form_uploader:lambda`
22:29:34.80 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"README.md"}
22:29:34.80 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"README.md"}
22:29:34.80 [INFO] notify invalidation: cleared 1 and dirtied 163 nodes for: {"", "README.md"}
22:29:34.82 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"README.md"}
22:29:41.27 [INFO] request completed: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] package src/python/form_uploader:lambda`
22:29:58.92 [INFO] Extending leases
22:29:58.93 [INFO] Done extending leases
22:31:18.98 [INFO] Extending leases
22:31:18.99 [INFO] Done extending leases
22:32:39.02 [INFO] Extending leases
22:32:39.03 [INFO] Done extending leases
22:32:42.43 [INFO] notify invalidation: cleared 1 and dirtied 163 nodes for: {"before.json", ""}
22:32:42.45 [INFO] handling request: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] peek ::`
22:32:42.57 [INFO] notify invalidation: cleared 1 and dirtied 163 nodes for: {"", "before.json"}
22:32:42.80 [INFO] request completed: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] peek ::`
22:32:42.82 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"before.json"}
22:33:05.42 [INFO] notify invalidation: cleared 1 and dirtied 226 nodes for: {"", "after.json"}
22:33:05.44 [INFO] handling request: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] --python-infer-use-rust-parser peek ::`
22:33:05.72 [INFO] notify invalidation: cleared 1 and dirtied 226 nodes for: {"after.json", ""}
22:33:05.79 [INFO] request completed: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] --python-infer-use-rust-parser peek ::`
22:33:05.80 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"after.json"}
22:33:59.06 [INFO] Extending leases
22:33:59.07 [INFO] Done extending leases
22:34:12.62 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"pants.toml"}
22:34:12.62 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"pants.toml"}
22:34:12.63 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"pants.toml"}
22:34:12.63 [INFO] Filesystem changed during run: retrying `DigestFile(pants.toml)` in 500ms...
22:34:12.63 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"pants.toml"}
22:34:12.63 [INFO] notify invalidation: cleared 1 and dirtied 229 nodes for: {"pants.toml", ""}
22:34:12.63 [INFO] notify invalidation: cleared 1 and dirtied 229 nodes for: {"", "pants.toml"}
22:34:12.63 [ERROR] saw filesystem changes covered by invalidation globs: content changed (Digest('eafefc060da91aff33afc9715dfce948d5e247c84e5c73be603971c942e0c1e2', 170) fs Digest('fb55171aaa78a1d534b6765af0257f1a32bc9b0830ae0e193e5e0abd9213b6be', 170)). terminating the daemon.
22:34:12.66 [INFO] notify invalidation: cleared 1 and dirtied 2 nodes for: {"pants.toml"}
22:34:12.67 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"pants.toml"}
22:34:12.87 [ERROR] service failure for <pants.pantsd.service.scheduler_service.SchedulerService object at 0x7ee71c235fa0>.
22:34:12.87 [INFO] Waiting for ongoing runs to complete before exiting...
22:34:12.87 [INFO] Server exiting with Ok(())
22:34:12.88 [INFO] Waiting for Sessions to complete before exiting...
22:34:12.88 [INFO] Waiting for shutdown of: ["scheduler_service_session", "store_gc_service_session", "pants_run_2023_09_12_22_00_29_344_6463fabfed5f4416a1be222f8e7d6bca", "pants_run_2023_09_12_22_00_29_675_d1d8bba5fea34659be7e97aaf0641965", "pants_run_2023_09_12_22_03_47_181_38382a9d31584b2ea10c9b18edc501c8", "pants_run_2023_09_12_22_29_32_283_f264bd1f822948e6b9eadea7f4f7ecbb", "pants_run_2023_09_12_22_32_42_653_8640dd3e4b954014ac68fd8dcf99acba", "pants_run_2023_09_12_22_33_05_709_5cbb449959d14f4197e294d7135666dd"]
22:34:12.88 [INFO] Shutdown completed: "scheduler_service_session"
22:34:12.88 [INFO] Shutdown completed: "store_gc_service_session"
22:34:12.88 [INFO] Shutdown completed: "pants_run_2023_09_12_22_00_29_344_6463fabfed5f4416a1be222f8e7d6bca"
22:34:12.88 [INFO] Shutdown completed: "pants_run_2023_09_12_22_00_29_675_d1d8bba5fea34659be7e97aaf0641965"
22:34:12.88 [INFO] Shutdown completed: "pants_run_2023_09_12_22_03_47_181_38382a9d31584b2ea10c9b18edc501c8"
22:34:12.88 [INFO] Shutdown completed: "pants_run_2023_09_12_22_29_32_283_f264bd1f822948e6b9eadea7f4f7ecbb"
22:34:12.88 [INFO] Shutdown completed: "pants_run_2023_09_12_22_32_42_653_8640dd3e4b954014ac68fd8dcf99acba"
22:34:12.88 [INFO] Shutdown completed: "pants_run_2023_09_12_22_33_05_709_5cbb449959d14f4197e294d7135666dd"
22:34:12.88 [INFO] Exiting pantsd
22:34:12.88 [WARN] File watcher exiting with: The watcher was shut down.
22:34:52.13 [INFO] pantsd 2.17.0 running with PID: 12669
22:34:52.20 [INFO] handling request: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] dependencies src/python/form_uploader::`
22:35:02.12 [INFO] request completed: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] dependencies src/python/form_uploader::`
22:35:55.96 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"variables.tf"}
22:35:55.96 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"variables.tf"}
22:35:55.96 [INFO] notify invalidation: cleared 1 and dirtied 108 nodes for: {"variables.tf", ""}
22:35:56.40 [INFO] notify invalidation: cleared 0 and dirtied 0 nodes for: {"variables.tf"}
22:36:21.95 [INFO] Extending leases
22:36:21.96 [INFO] Done extending leases
22:36:25.06 [INFO] handling request: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] package src/python/form_uploader:lambda`
22:36:25.82 [INFO] request completed: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] package src/python/form_uploader:lambda`
22:37:41.98 [INFO] Extending leases
22:37:41.99 [INFO] Done extending leases
22:39:02.01 [INFO] Extending leases
22:39:02.02 [INFO] Done extending leases
22:40:22.06 [INFO] Extending leases
22:40:22.07 [INFO] Done extending leases
22:41:42.09 [INFO] Extending leases
22:41:42.10 [INFO] Done extending leases
22:43:02.13 [INFO] Extending leases
22:43:02.14 [INFO] Done extending leases
22:44:22.18 [INFO] Extending leases
22:44:22.19 [INFO] Done extending leases
22:45:42.20 [INFO] Extending leases
22:45:42.21 [INFO] Done extending leases
22:47:02.22 [INFO] Extending leases
22:47:02.24 [INFO] Done extending leases
22:48:22.26 [INFO] Extending leases
22:48:22.27 [INFO] Done extending leases
22:49:42.29 [INFO] Extending leases
22:49:42.31 [INFO] Done extending leases
22:51:02.34 [INFO] Extending leases
22:51:02.35 [INFO] Done extending leases
22:52:13.74 [INFO] handling request: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] package src/python/form_uploader:lambda`
22:52:10.09 [INFO] request completed: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] package src/python/form_uploader:lambda`
22:52:22.39 [INFO] Extending leases
22:52:22.40 [INFO] Done extending leases
22:53:42.42 [INFO] Extending leases
22:53:42.43 [INFO] Done extending leases
22:55:02.45 [INFO] Extending leases
22:55:02.45 [INFO] Done extending leases
22:56:22.47 [INFO] Extending leases
22:56:22.49 [INFO] Done extending leases
22:57:42.50 [INFO] Extending leases
22:57:42.51 [INFO] Done extending leases
22:59:02.52 [INFO] Extending leases
22:59:02.53 [INFO] Done extending leases
23:00:22.55 [INFO] Extending leases
23:00:22.56 [INFO] Done extending leases
23:01:42.59 [INFO] Extending leases
23:01:42.60 [INFO] Done extending leases
23:02:50.24 [INFO] handling request: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] --version`
23:02:50.64 [INFO] request completed: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] --version`
23:03:02.63 [INFO] Extending leases
23:03:02.64 [INFO] Done extending leases
23:04:22.17 [INFO] pantsd 2.17.0 running with PID: 19627
23:04:22.21 [INFO] handling request: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] package src/python/form_uploader:lambda`
23:04:32.51 [INFO] request completed: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] package src/python/form_uploader:lambda`
23:05:51.85 [INFO] Extending leases
23:05:51.87 [INFO] Done extending leases
23:07:11.89 [INFO] Extending leases
23:07:11.90 [INFO] Done extending leases
23:08:31.92 [INFO] Extending leases
23:08:31.93 [INFO] Done extending leases
23:09:51.96 [INFO] Extending leases
23:09:51.97 [INFO] Done extending leases
23:11:05.16 [INFO] pantsd 2.17.0 running with PID: 21733
23:11:05.24 [INFO] handling request: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] --version`
23:11:15.18 [INFO] request completed: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] --version`
23:11:37.21 [INFO] handling request: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] package src/python/form_uploader:lambda`
23:11:38.09 [INFO] request completed: `--python-repos-find-links=-['file:///home/vscode/.cache/nce/260e9f180e257368873660af8dd93ef1ae670cb61bde99eea1fd914ad6e534bb/bindings/find_links/2.17.0/c0089a1c/index.html'] package src/python/form_uploader:lambda`
23:12:34.92 [INFO] Extending leases
23:12:34.94 [INFO] Done extending leases
23:13:54.95 [INFO] Extending leases
23:13:54.97 [INFO] Done extending leases

[huonw]

@thejcannon this looks like it's in FSDB. Might it be something similar-ish to https://github.com/pantsbuild/pants/pull/19645? If not, any theories?

[thejcannon]

Certainly FSDB, but unrelated to that other ticket. In this case the file must be read-only because we hardlink into the sandbox.

So this is an error trying to set the permissions on a file in the cache. I've seen something like this if pants was run as superuser previously. Alternatively, it maybe that umask already has it as read-only (unlikely but I'm spitballing).

@bjkeller what's the ls -ln <that file> say? And what's your UID/GID?

[bjkeller]

It does kind of smack of a UID shifting, and the container did get rebuilt at least once b/w the command not giving the error and giving it. But the UID and GID line up

ls -ln:

-r-xr-xr-x 1 1000 1000 12231468 Sep 13 14:25 /home/vscode/.cache/pants/lmdb_store/immutable/files/39/39589a7ed7a41afde02019677c33017641bb0ad1187d6efd9c45e06bb6b4eef6

The vscode user has UID & GID 1000. from /etc/passwd

vscode:x:1000:1000::/home/vscode:/bin/bash

I believe these are fixed in the devcontainer configuration

BTW this is the zip created by the command

-r-xr-xr-x 1 1000 1000 12231468 Sep 13 14:23 dist/src.python.form_uploader/lambda.zip

[thejcannon]

It's weird that the file already exists and is already read-only. Whats the umask?

[thejcannon]

My last thought would be a race between multiple threads/processes.

If that's the case, we could silence errors when attempting to mark as readonly, then verify its readonly, and if not.... I don't even know. Try again? Remove it and die loudly?

The danger is the file exists and isnt readonly, then someone mutates it from a hardlinked file in the sandbox and now reproducibility has gone byebye

[bjkeller]

It's weird that the file already exists and is already read-only. Whats the umask?

0022

[pietrobolcato]

I have the same isssue, would be great to get an update on this!

[pietrobolcato]

This is the output of: pants --print-stacktrace -ldebug package kittl/projects/minimal_lambda/:lambda

vscode ➜ /workspaces/kittl-python $ pants --print-stacktrace -ldebug package kittl/projects/minimal_lambda/:lambda
09:23:35.98 [DEBUG] acquiring lock: <pants.pantsd.lock.OwnerPrintingInterProcessFileLock object at 0xffffa3d52670>
09:23:35.98 [DEBUG] purging metadata directory: /workspaces/kittl-python/.pids/352a6f40839d/pantsd
09:23:35.98 [DEBUG] Launching pantsd
09:23:35.98 [DEBUG] purging metadata directory: /workspaces/kittl-python/.pids/352a6f40839d/pantsd
09:23:35.98 [DEBUG] pantsd command is: PANTS_DAEMON_ENTRYPOINT=pants.pantsd.pants_daemon:launch_new_pantsd_instance PYTHONPATH=/home/vscode/.cache/nce/7ace7eff81f177fb9b7a6ecbec4a9266de4406c5e61043bff4081f78d0c604ff/bindings/venvs/2.17.0/bin:/home/vscode/.cache/nce/f629b75ebfcafe9ceee2e796b7e4df5cf8dbd14f3c021afca078d159ab797acf/cpython-3.9.16+20230507-aarch64-unknown-linux-gnu-install_only.tar.gz/python/lib/python39.zip:/home/vscode/.cache/nce/f629b75ebfcafe9ceee2e796b7e4df5cf8dbd14f3c021afca078d159ab797acf/cpython-3.9.16+20230507-aarch64-unknown-linux-gnu-install_only.tar.gz/python/lib/python3.9:/home/vscode/.cache/nce/f629b75ebfcafe9ceee2e796b7e4df5cf8dbd14f3c021afca078d159ab797acf/cpython-3.9.16+20230507-aarch64-unknown-linux-gnu-install_only.tar.gz/python/lib/python3.9/lib-dynload:/home/vscode/.cache/nce/7ace7eff81f177fb9b7a6ecbec4a9266de4406c5e61043bff4081f78d0c604ff/bindings/venvs/2.17.0/lib/python3.9/site-packages /home/vscode/.cache/nce/7ace7eff81f177fb9b7a6ecbec4a9266de4406c5e61043bff4081f78d0c604ff/bindings/venvs/2.17.0/bin/python /home/vscode/.cache/nce/7ace7eff81f177fb9b7a6ecbec4a9266de4406c5e61043bff4081f78d0c604ff/bindings/venvs/2.17.0/bin/pants --python-repos-find-links=-['file:///home/vscode/.cache/nce/7ace7eff81f177fb9b7a6ecbec4a9266de4406c5e61043bff4081f78d0c604ff/bindings/find_links/2.17.0/c0089a1c/index.html'] --print-stacktrace -ldebug package kittl/projects/minimal_lambda/:lambda
09:23:39.89 [DEBUG] pantsd is running at pid 20048, pailgun port is 35501
09:23:39.89 [DEBUG] releasing lock: <pants.pantsd.lock.OwnerPrintingInterProcessFileLock object at 0xffffa3d52670>
09:23:39.89 [DEBUG] Connecting to pantsd on port 35501
09:23:39.89 [DEBUG] Connecting to pantsd on port 35501 attempt 1/3
09:23:39.89 [DEBUG] Connected to pantsd
09:23:39.89 [DEBUG] work dir: /workspaces/kittl-python
09:23:39.90 [DEBUG] Launching 1 roots (poll=false).
09:23:39.92 [DEBUG] computed 1 nodes in 0.014183 seconds. there are 9 total nodes.
09:23:39.92 [DEBUG] Launching 1 roots (poll=false).
09:23:39.92 [DEBUG] computed 1 nodes in 0.000318 seconds. there are 13 total nodes.
09:23:40.06 [INFO] Initializing scheduler...
09:23:40.07 [DEBUG] File handle limit is: 1048576
09:23:40.12 [DEBUG] Using [cache::CommandRunner { inner: bounded::CommandRunner { inner: SwitchedCommandRunner { .. }, .. }, .. }, cache::CommandRunner { inner: bounded::CommandRunner { inner: SwitchedCommandRunner { .. }, .. }, .. }] for process execution.
09:23:43.71 [DEBUG] Changes to /home/vscode/.cache/nce/7ace7eff81f177fb9b7a6ecbec4a9266de4406c5e61043bff4081f78d0c604ff/bindings/venvs/2.17.0/bin, outside of the buildroot, will not be invalidated.
09:23:43.71 [DEBUG] Changes to /home/vscode/.cache/nce/7ace7eff81f177fb9b7a6ecbec4a9266de4406c5e61043bff4081f78d0c604ff/bindings/venvs/2.17.0/bin, outside of the buildroot, will not be invalidated.
09:23:43.71 [DEBUG] Changes to /home/vscode/.cache/nce/f629b75ebfcafe9ceee2e796b7e4df5cf8dbd14f3c021afca078d159ab797acf/cpython-3.9.16+20230507-aarch64-unknown-linux-gnu-install_only.tar.gz/python/lib/python39.zip, outside of the buildroot, will not be invalidated.
09:23:43.71 [DEBUG] Changes to /home/vscode/.cache/nce/f629b75ebfcafe9ceee2e796b7e4df5cf8dbd14f3c021afca078d159ab797acf/cpython-3.9.16+20230507-aarch64-unknown-linux-gnu-install_only.tar.gz/python/lib/python3.9, outside of the buildroot, will not be invalidated.
09:23:43.71 [DEBUG] Changes to /home/vscode/.cache/nce/f629b75ebfcafe9ceee2e796b7e4df5cf8dbd14f3c021afca078d159ab797acf/cpython-3.9.16+20230507-aarch64-unknown-linux-gnu-install_only.tar.gz/python/lib/python3.9/lib-dynload, outside of the buildroot, will not be invalidated.
09:23:43.71 [DEBUG] Changes to /home/vscode/.cache/nce/7ace7eff81f177fb9b7a6ecbec4a9266de4406c5e61043bff4081f78d0c604ff/bindings/venvs/2.17.0/lib/python3.9/site-packages, outside of the buildroot, will not be invalidated.
09:23:43.71 [DEBUG] setting up service <pants.pantsd.service.scheduler_service.SchedulerService object at 0xffc3013dc0d0>
09:23:43.71 [DEBUG] setting up service <pants.pantsd.service.store_gc_service.StoreGCService object at 0xffc24dfe1550>
09:23:43.71 [DEBUG] starting service <pants.pantsd.service.scheduler_service.SchedulerService object at 0xffc3013dc0d0>
09:23:43.71 [DEBUG] starting service <pants.pantsd.service.store_gc_service.StoreGCService object at 0xffc24dfe1550>
09:23:43.71 [INFO] Scheduler initialized.
09:23:43.71 [DEBUG] Launching 1 roots (poll=false).
09:23:43.71 [DEBUG] computed 1 nodes in 0.000314 seconds. there are 13 total nodes.
09:23:43.71 [DEBUG] Launching 1 roots (poll=false).
09:23:43.71 [DEBUG] computed 1 nodes in 0.000101 seconds. there are 13 total nodes.
09:23:43.77 [DEBUG] specs are: Specs(includes=RawSpecs(description_of_origin='CLI arguments', address_literals=(AddressLiteralSpec(path_component='kittl/projects/minimal_lambda', target_component='lambda', generated_component=None, parameters=FrozenDict({})),), file_literals=(), file_globs=(), dir_literals=(), dir_globs=(), recursive_globs=(), ancestor_globs=(), unmatched_glob_behavior=<GlobMatchErrorBehavior.error: 'error'>, filter_by_global_options=True, from_change_detection=False), ignores=RawSpecs(description_of_origin='CLI arguments', address_literals=(), file_literals=(), file_globs=(), dir_literals=(), dir_globs=(), recursive_globs=(), ancestor_globs=(), unmatched_glob_behavior=<GlobMatchErrorBehavior.error: 'error'>, filter_by_global_options=False, from_change_detection=False))
09:23:43.77 [DEBUG] changed_options are: ChangedOptions(since=None, diffspec=None, dependents=<DependentsOption.NONE: 'none'>)
09:23:43.77 [DEBUG] Launching 1 roots (poll=false).
09:23:43.79 [DEBUG] computed 1 nodes in 0.016810 seconds. there are 14 total nodes.
09:23:43.79 [DEBUG] Launching 1 roots (poll=false).
09:23:43.79 [DEBUG] computed 1 nodes in 0.000724 seconds. there are 19 total nodes.
09:23:43.79 [DEBUG] Launching 1 roots (poll=false).
09:23:43.79 [DEBUG] computed 1 nodes in 0.000182 seconds. there are 19 total nodes.
09:23:43.79 [DEBUG] requesting <class 'pants.core.goals.package.Package'> to satisfy execution of `package` goal
09:23:43.79 [DEBUG] Launching 1 roots (poll=false).
09:23:43.80 [DEBUG] Completed: Find targets from input specs
09:23:43.90 [DEBUG] Completed: Generate `python_requirement` targets from requirements.txt or PEP 621 compliant pyproject.toml
09:23:43.91 [DEBUG] Completed: Find all targets in the project
09:23:43.91 [DEBUG] Completed: Find all Python targets in project
09:23:43.91 [DEBUG] Completed: Creating map of third party targets to Python modules
09:23:43.92 [DEBUG] Completed: Creating map of first party Python targets to Python modules
09:23:43.92 [DEBUG] Completed: pants.backend.python.dependency_inference.module_mapper.merge_first_party_module_mappings
09:23:43.93 [DEBUG] Completed: Determine Python dependencies for "kittl/projects/minimal_lambda/example.py"
09:23:43.93 [DEBUG] Completed: pants.backend.python.dependency_inference.parse_python_dependencies.parse_python_dependencies
09:23:43.93 [DEBUG] Completed: Determine Python dependencies for "kittl/projects/minimal_lambda/summer.py"
09:23:43.93 [DEBUG] Completed: pants.backend.python.dependency_inference.parse_python_dependencies.parse_python_dependencies
09:23:43.93 [DEBUG] Completed: Resolve transitive targets
09:23:43.95 [DEBUG] Completed: pants.backend.python.util_rules.python_sources.prepare_python_sources
09:23:43.95 [DEBUG] Completed: pants.backend.python.util_rules.python_sources.strip_python_sources
09:23:43.95 [DEBUG] Completed: pants.backend.python.util_rules.pex_from_targets.create_pex_from_targets
09:23:43.97 [DEBUG] Completed: pants.core.util_rules.search_paths.validate_search_paths
09:23:43.97 [DEBUG] Completed: Prepare environment for running PEXes
09:23:44.99 [DEBUG] Completed: Downloading: https://github.com/pantsbuild/pex/releases/download/v2.1.137/pex (3.91 MB)
09:23:45.01 [DEBUG] Completed: Extracting an archive file
09:23:45.01 [DEBUG] Completed: pants.core.util_rules.external_tool.download_external_tool
09:23:45.01 [DEBUG] Completed: acquire_command_runner_slot
09:23:45.01 [DEBUG] Running Building 1 requirement for faas_repository.pex from the python_default.lock resolve: numpy~=1.25.0 under semaphore with concurrency id: 1, and concurrency: 1
09:23:45.02 [DEBUG] Completed: setup_sandbox
09:23:45.03 [DEBUG] spawned local process as Some(20135) for Process { argv: ["/home/vscode/.cache/nce/7ace7eff81f177fb9b7a6ecbec4a9266de4406c5e61043bff4081f78d0c604ff/bindings/venvs/2.17.0/bin/python", "./pex", "--tmpdir", ".tmp", "--jobs", "1", "--pip-version", "23.1.2", "--python-path", "/home/vscode/.pyenv/versions/3.10.13/bin", "--output-file", "faas_repository.pex", "--no-emit-warnings", "--manylinux=manylinux2014", "--resolve-local-platforms", "--platform", "linux_x86_64-cp-310-cp310", "--sources-directory=source_files", "numpy~=1.25.0", "--lock", "python_default.lock", "--no-pypi", "--index=https://pypi.org/simple/", "--manylinux", "manylinux2014", "--layout", "packed"], env: {"CPPFLAGS": "", "LANG": "en_US.UTF-8", "LDFLAGS": "", "PATH": "~/bin/:/home/vscode/.pyenv/shims:/home/vscode/.pyenv/bin:/vscode/vscode-server/bin/linux-arm64/abd2f3db4bdb28f9e95536dfa84d8479f1eb312d/bin/remote-cli:/usr/local/python/current/bin:/usr/local/py-utils/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/home/vscode/.local/bin", "PEX_IGNORE_RCFILES": "true", "PEX_PYTHON": "/home/vscode/.cache/nce/7ace7eff81f177fb9b7a6ecbec4a9266de4406c5e61043bff4081f78d0c604ff/bindings/venvs/2.17.0/bin/python", "PEX_ROOT": ".cache/pex_root"}, working_directory: None, input_digests: InputDigests { complete: DirectoryDigest { digest: Digest { hash: Fingerprint<78825dac1e15b01bbc75a8ea5f2263ece513724d3002daedf2b2bae9ef3b6601>, size_bytes: 340 }, tree: "Some(..)" }, nailgun: DirectoryDigest { digest: Digest { hash: Fingerprint<e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855>, size_bytes: 0 }, tree: "Some(..)" }, inputs: DirectoryDigest { digest: Digest { hash: Fingerprint<78825dac1e15b01bbc75a8ea5f2263ece513724d3002daedf2b2bae9ef3b6601>, size_bytes: 340 }, tree: "Some(..)" }, immutable_inputs: {}, use_nailgun: {} }, output_files: {}, output_directories: {RelativePath("faas_repository.pex")}, timeout: None, execution_slot_variable: None, concurrency_available: 1, description: "Building 1 requirement for faas_repository.pex from the python_default.lock resolve: numpy~=1.25.0", level: Info, append_only_caches: {CacheName("pex_root"): RelativePath(".cache/pex_root"), CacheName("python_build_standalone"): RelativePath(".python-build-standalone")}, jdk_home: None, cache_scope: Successful, execution_environment: ProcessExecutionEnvironment { name: None, platform: Linux_arm64, strategy: Local }, remote_cache_speculation_delay: 0ns }
09:23:46.49 [INFO] Completed: Building 1 requirement for faas_repository.pex from the python_default.lock resolve: numpy~=1.25.0
09:23:46.50 [DEBUG] Completed: Scheduling: Building 1 requirement for faas_repository.pex from the python_default.lock resolve: numpy~=1.25.0
09:23:46.50 [DEBUG] Completed: pants.backend.python.util_rules.pex.build_pex
09:23:46.50 [DEBUG] Completed: acquire_command_runner_slot
09:23:46.50 [DEBUG] Running Build python_awslambda artifact for kittl/projects/minimal_lambda:lambda under semaphore with concurrency id: 2, and concurrency: 1
09:23:46.52 [DEBUG] Completed: setup_sandbox
09:23:46.53 [DEBUG] spawned local process as Some(20180) for Process { argv: ["/home/vscode/.cache/nce/7ace7eff81f177fb9b7a6ecbec4a9266de4406c5e61043bff4081f78d0c604ff/bindings/venvs/2.17.0/bin/python", "./pex", "venv", "create", "--tmpdir", ".tmp", "--python-path", "/home/vscode/.pyenv/versions/3.10.13/bin", "--dest-dir=kittl.projects.minimal_lambda/lambda", "--pex-repository=faas_repository.pex", "--layout=flat-zipped", "--platform", "linux_x86_64-cp-310-cp310"], env: {"CPPFLAGS": "", "LANG": "en_US.UTF-8", "LDFLAGS": "", "PATH": "~/bin/:/home/vscode/.pyenv/shims:/home/vscode/.pyenv/bin:/vscode/vscode-server/bin/linux-arm64/abd2f3db4bdb28f9e95536dfa84d8479f1eb312d/bin/remote-cli:/usr/local/python/current/bin:/usr/local/py-utils/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/home/vscode/.local/bin", "PEX_IGNORE_RCFILES": "true", "PEX_PYTHON": "/home/vscode/.cache/nce/7ace7eff81f177fb9b7a6ecbec4a9266de4406c5e61043bff4081f78d0c604ff/bindings/venvs/2.17.0/bin/python", "PEX_ROOT": ".cache/pex_root", "PEX_SCRIPT": "pex3"}, working_directory: None, input_digests: InputDigests { complete: DirectoryDigest { digest: Digest { hash: Fingerprint<c4be3b40d93b96306d6818131a4bd75bb8f270e8d35b88a0e39175c5cec37370>, size_bytes: 252 }, tree: "Some(..)" }, nailgun: DirectoryDigest { digest: Digest { hash: Fingerprint<e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855>, size_bytes: 0 }, tree: "Some(..)" }, inputs: DirectoryDigest { digest: Digest { hash: Fingerprint<c4be3b40d93b96306d6818131a4bd75bb8f270e8d35b88a0e39175c5cec37370>, size_bytes: 252 }, tree: "Some(..)" }, immutable_inputs: {}, use_nailgun: {} }, output_files: {RelativePath("kittl.projects.minimal_lambda/lambda.zip")}, output_directories: {}, timeout: None, execution_slot_variable: None, concurrency_available: 0, description: "Build python_awslambda artifact for kittl/projects/minimal_lambda:lambda", level: Info, append_only_caches: {CacheName("pex_root"): RelativePath(".cache/pex_root"), CacheName("python_build_standalone"): RelativePath(".python-build-standalone")}, jdk_home: None, cache_scope: Successful, execution_environment: ProcessExecutionEnvironment { name: None, platform: Linux_arm64, strategy: Local }, remote_cache_speculation_delay: 0ns }
09:23:49.50 [INFO] Completed: Build python_awslambda artifact for kittl/projects/minimal_lambda:lambda
09:23:49.50 [DEBUG] Completed: Scheduling: Build python_awslambda artifact for kittl/projects/minimal_lambda:lambda
09:23:49.51 [DEBUG] Completed: Create Python AWS Lambda - kittl/projects/minimal_lambda:lambda
09:23:49.72 [DEBUG] Completed: `package` goal
09:23:49.72 [DEBUG] computed 1 nodes in 5.929578 seconds. there are 1141 total nodes.
09:23:49.72 [ERROR] 1 Exception encountered:

Engine traceback:
  in select
    ..
  in pants.core.goals.package.package_asset
    `package` goal

Traceback (no traceback):
  <pants native internals>
Exception: Error setting permissions on /workspaces/kittl-python/.cache/immutable/files/b9/b9b93ca2e34791d3ffdac6df6fe4f5086588bf75aa3295db8d3e1ae20a933d54: Permission denied (os error 13)

[JianlongZhong]

Hitting the same issue. It can be resolved by manually run chmod +w but a bit annoying and had to explain to end users every time.

[YuseongJay]

Same issue, when running package on container entrypoint. However, when I run package in container by execute the command after entering in running container, it's fine.

I ran a container with docker compose.

[natehardison]

Also having same issue. Set up dummy repo to reproduce: https://github.com/natehardison/pants-test.

[narayanacharya6]

Any updates or workarounds that one can share?

[huonw]

It seems like there's no updates.

---

I believe the relevant code within Pants is:

https://github.com/pantsbuild/pants/blob/cfb3cafcac2386c909bc4a3fee3997e1bd8b03d7/src/rust/engine/fs/store/src/lib.rs#L1369-L1371

The next steps towards fixing this might be trying to create a reduced standalone reproducer separate to the main Pants codebase. For example, a small standalone Rust program that does similar operations and exhibits the same error.

[narayanacharya6]

For those not using VSCode, I forked @natehardison 's repo (https://github.com/natehardison/pants-test) and updated the example to run the package command in a Docker container with the Dockerfile provided. You can check it out here - https://github.com/narayanacharya6/pants-test. FYI, I also bumped the pants version used from 2.19.1 to 2.21.0 and I get the same error in the newer version.

[huonw]

I've tried to what seem to be the relevant parts of the Pants codebase in https://gist.github.com/huonw/53027f52e274674574c4614818752e27

git clone git@gist.github.com:53027f52e274674574c4614818752e27.git
cd 53027f52e274674574c4614818752e27
cargo run -- some/paths go/here

The key part is main.rs:

use std::os::unix::fs::PermissionsExt;

/// Adjust `path` to have each mode that Pants might use, printing the result
///
/// Mode options from https://github.com/pantsbuild/pants/blob/cfb3cafcac2386c909bc4a3fee3997e1bd8b03d7/src/rust/engine/fs/store/src/lib.rs#L1354-L1372
async fn try_set_permissions(path: &str) {
    for mode in [0o555, 0o444, 0o755, 0o644] {
        let permission = std::fs::Permissions::from_mode(mode);
        let result = tokio::fs::set_permissions(path, permission).await;
        println!("path={path}, mode={mode:o} => result={:?}", result);
    }
}

#[tokio::main]
async fn main() {
    for path in std::env::args().skip(1) {
        try_set_permissions(&path).await;
    }
}

Theoretically that can be run by passing one or more file paths, like cargo run -- test doesnt_exist, and it gives output like:

path=test, mode=555 => result=Ok(())
path=test, mode=444 => result=Ok(())
path=test, mode=755 => result=Ok(())
path=test, mode=644 => result=Ok(())
path=doesnt_exist, mode=555 => result=Err(Os { code: 2, kind: NotFound, message: "No such file or directory" })
path=doesnt_exist, mode=444 => result=Err(Os { code: 2, kind: NotFound, message: "No such file or directory" })
path=doesnt_exist, mode=755 => result=Err(Os { code: 2, kind: NotFound, message: "No such file or directory" })
path=doesnt_exist, mode=644 => result=Err(Os { code: 2, kind: NotFound, message: "No such file or directory" })

Does that reproduce the issue in the affected environments? You may have to create files in particular directories etc.