niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #181
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestCaseHackSuffix5=== PAUSE TestCaseHackSuffix6=== RUN TestFilterOversizedClosures7=== PAUSE TestFilterOversizedClosures8=== RUN TestPartSizeForNAR9=== PAUSE TestPartSizeForNAR10=== RUN TestUploadMultipart_SupersededByPeer11=== PAUSE TestUploadMultipart_SupersededByPeer12=== RUN TestDumpPathMatchesNix13=== PAUSE TestDumpPathMatchesNix14=== RUN TestDumpPathSingleFile15=== PAUSE TestDumpPathSingleFile16=== RUN TestDumpPathWriterError17=== PAUSE TestDumpPathWriterError18=== RUN TestEncodeNixBase3219=== PAUSE TestEncodeNixBase3220=== RUN TestEncodeNixBase32WithRealHash21=== PAUSE TestEncodeNixBase32WithRealHash22=== RUN TestConvertHashToNix3223=== PAUSE TestConvertHashToNix3224=== RUN TestGetStorePathHash25=== PAUSE TestGetStorePathHash26=== RUN TestPathInfoHashCompatibility27=== PAUSE TestPathInfoHashCompatibility28=== RUN TestParsePathInfoJSON29=== PAUSE TestParsePathInfoJSON30=== RUN TestParsePathInfoJSONMultiplePaths31=== PAUSE TestParsePathInfoJSONMultiplePaths32=== RUN TestPathInfoCACompatibility33=== PAUSE TestPathInfoCACompatibility34=== RUN TestRateLimiterFeedback35=== PAUSE TestRateLimiterFeedback36=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess37=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess38=== RUN TestResolveStorePath39=== PAUSE TestResolveStorePath40=== RUN TestDoWithRetry_BodyReplayedViaGetBody41=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody42=== RUN TestShellSplit43=== PAUSE TestShellSplit44=== RUN TestShellSplitErrors45=== PAUSE TestShellSplitErrors46=== RUN TestSetClientTLS47=== PAUSE TestSetClientTLS48=== RUN TestSetClientTLSDoesNotMutateDefaultTransport49=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport50=== RUN TestSetClientTLSErrors51=== PAUSE TestSetClientTLSErrors52=== RUN TestStaticToken53=== PAUSE TestStaticToken54=== RUN TestFileTokenReadsAndCaches55=== PAUSE TestFileTokenReadsAndCaches56=== RUN TestFileTokenMissing57=== PAUSE TestFileTokenMissing58=== RUN TestFileTokenEmpty59=== PAUSE TestFileTokenEmpty60=== RUN TestScriptTokenNoExpiryRerunsEveryCall61=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall62=== RUN TestScriptTokenCachesUntilRefresh63=== PAUSE TestScriptTokenCachesUntilRefresh64=== RUN TestScriptTokenEmptyToken65=== PAUSE TestScriptTokenEmptyToken66=== RUN TestScriptTokenBadJSON67=== PAUSE TestScriptTokenBadJSON68=== RUN TestScriptTokenScriptFails69=== PAUSE TestScriptTokenScriptFails70=== RUN TestScriptTokenEmptyCommand71=== PAUSE TestScriptTokenEmptyCommand72=== CONT TestDoServerRequestAttachesToken73=== CONT TestFileTokenMissing74=== CONT TestResolveStorePath75=== CONT TestEncodeNixBase32WithRealHash76--- PASS: TestEncodeNixBase32WithRealHash (0.00s)77=== CONT TestParsePathInfoJSON78=== CONT TestParsePathInfoJSONMultiplePaths79=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths80=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths81=== RUN TestParsePathInfoJSON/Nix_format82=== CONT TestPathInfoHashCompatibility83=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)84=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)85=== CONT TestGetStorePathHash86=== RUN TestGetStorePathHash/valid_store_path87=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths88=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon89=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon90=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI91=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI92=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths93=== PAUSE TestGetStorePathHash/valid_store_path94=== CONT TestUploadMultipart_SupersededByPeer95=== CONT TestConvertHashToNix3296=== RUN TestGetStorePathHash/basename_without_hyphen_should_error97=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error98=== RUN TestConvertHashToNix32/SRI_format_to_Nix3299=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error100=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32101=== RUN TestUploadMultipart_SupersededByPeer/exists102=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error103=== PAUSE TestUploadMultipart_SupersededByPeer/exists104=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error105=== RUN TestUploadMultipart_SupersededByPeer/missing106=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error107=== CONT TestPartSizeForNAR108=== CONT TestDumpPathWriterError109=== RUN TestPartSizeForNAR/zero_stays_at_minimum110=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum111=== RUN TestPartSizeForNAR/small_stays_at_minimum112=== PAUSE TestPartSizeForNAR/small_stays_at_minimum113=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum114=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum115=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts116=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts117=== CONT TestFilterOversizedClosures118=== RUN TestFilterOversizedClosures/no_limit_keeps_everything119=== RUN TestConvertHashToNix32/already_Nix32_format120=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything121=== PAUSE TestConvertHashToNix32/already_Nix32_format122=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped123=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped124=== RUN TestPartSizeForNAR/1_TiB125=== RUN TestFilterOversizedClosures/all_closures_skipped126=== PAUSE TestFilterOversizedClosures/all_closures_skipped127=== RUN TestConvertHashToNix32/invalid_format128=== PAUSE TestConvertHashToNix32/invalid_format129=== CONT TestEncodeNixBase32130=== PAUSE TestUploadMultipart_SupersededByPeer/missing131=== PAUSE TestPartSizeForNAR/1_TiB132=== PAUSE TestParsePathInfoJSON/Nix_format133=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512134=== RUN TestPartSizeForNAR/5_TiB_S3_max_object135=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512136=== RUN TestParsePathInfoJSON/Lix_format137=== CONT TestStaticToken138=== PAUSE TestParsePathInfoJSON/Lix_format139=== RUN TestParsePathInfoJSON/empty_input140--- PASS: TestStaticToken (0.00s)141=== CONT TestSetClientTLSErrors142=== PAUSE TestParsePathInfoJSON/empty_input143=== RUN TestParsePathInfoJSON/whitespace_only144=== PAUSE TestParsePathInfoJSON/whitespace_only145=== RUN TestParsePathInfoJSON/invalid_JSON146=== PAUSE TestParsePathInfoJSON/invalid_JSON147=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object148=== RUN TestEncodeNixBase32/test_string_hash149=== PAUSE TestEncodeNixBase32/test_string_hash150=== CONT TestSetClientTLSDoesNotMutateDefaultTransport151=== RUN TestEncodeNixBase32/empty_input152=== PAUSE TestEncodeNixBase32/empty_input153=== CONT TestDumpPathSingleFile154=== CONT TestSetClientTLS155--- PASS: TestFileTokenMissing (0.00s)156=== CONT TestShellSplitErrors157--- PASS: TestShellSplitErrors (0.00s)158=== CONT TestRateLimiterFeedback159=== RUN TestRateLimiterFeedback/429_enables_limiter160=== PAUSE TestRateLimiterFeedback/429_enables_limiter161=== RUN TestRateLimiterFeedback/503_enables_limiter162=== PAUSE TestRateLimiterFeedback/503_enables_limiter163=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter164=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter165=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter166--- PASS: TestDoServerRequestAttachesToken (0.00s)167=== RUN TestPartSizeForNAR/capped_at_5_GiB168=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess169=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter170=== CONT TestFileTokenReadsAndCaches171=== PAUSE TestPartSizeForNAR/capped_at_5_GiB172=== CONT TestCaseHackSuffix1732026/09/07 10:04:22 WARN Rate limiter enabled after throttle name=server-test rate=5174=== CONT TestShellSplit175--- PASS: TestShellSplit (0.00s)176=== CONT TestScriptTokenEmptyToken177--- PASS: TestResolveStorePath (0.00s)178=== CONT TestScriptTokenEmptyCommand179--- PASS: TestScriptTokenEmptyCommand (0.00s)180=== CONT TestScriptTokenScriptFails181=== RUN TestSetClientTLSErrors/missing_cert_file182=== PAUSE TestSetClientTLSErrors/missing_cert_file183=== RUN TestSetClientTLSErrors/missing_key_file184=== PAUSE TestSetClientTLSErrors/missing_key_file185=== RUN TestSetClientTLSErrors/missing_ca_file186=== PAUSE TestSetClientTLSErrors/missing_ca_file187=== RUN TestSetClientTLSErrors/invalid_ca_file188=== PAUSE TestSetClientTLSErrors/invalid_ca_file189=== CONT TestScriptTokenBadJSON190--- PASS: TestFileTokenReadsAndCaches (0.00s)191--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)192--- PASS: TestScriptTokenScriptFails (0.01s)193=== CONT TestDoWithRetry_BodyReplayedViaGetBody194=== CONT TestScriptTokenCachesUntilRefresh195=== CONT TestScriptTokenNoExpiryRerunsEveryCall196=== RUN TestSetClientTLS/rejects_connection_without_client_cert197=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert198=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA199=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA200=== RUN TestSetClientTLS/preserves_debug_logging_transport201=== PAUSE TestSetClientTLS/preserves_debug_logging_transport202=== CONT TestFileTokenEmpty203--- PASS: TestFileTokenEmpty (0.00s)204=== CONT TestPathInfoCACompatibility205=== RUN TestPathInfoCACompatibility/null_ca_field206=== PAUSE TestPathInfoCACompatibility/null_ca_field207=== RUN TestPathInfoCACompatibility/old_string_format_-_text208=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text209=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive210=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive211=== RUN TestPathInfoCACompatibility/new_structured_format_-_text212=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text213=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method214=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method215=== CONT TestDumpPathMatchesNix2162026/09/07 10:04:22 WARN Rate limiter enabled after throttle name=server-test rate=52172026/09/07 10:04:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:612162182026/09/07 10:04:22 WARN Rate limiter backed off name=server-test rate=52192026/09/07 10:04:22 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:61216220--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)221=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths222=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths223--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)224 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)225 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)226=== CONT TestGetStorePathHash/valid_store_path227=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error228=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error229=== CONT TestGetStorePathHash/basename_without_hyphen_should_error230--- PASS: TestGetStorePathHash (0.00s)231 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)232 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)233 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)234 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)235=== CONT TestFilterOversizedClosures/no_limit_keeps_everything236=== CONT TestConvertHashToNix32/SRI_format_to_Nix32237=== CONT TestUploadMultipart_SupersededByPeer/exists238=== CONT TestFilterOversizedClosures/all_closures_skipped2392026/09/07 10:04:22 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=50240=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2412026/09/07 10:04:22 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000242--- PASS: TestFilterOversizedClosures (0.00s)243 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)244 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)245 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)246=== CONT TestConvertHashToNix32/invalid_format247=== CONT TestConvertHashToNix32/already_Nix32_format248--- PASS: TestConvertHashToNix32 (0.00s)249 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)250 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)251 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)252=== CONT TestUploadMultipart_SupersededByPeer/missing253--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)254 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)255 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)256=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)257=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI258=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512259=== CONT TestParsePathInfoJSON/Nix_format260=== CONT TestParsePathInfoJSON/invalid_JSON261=== CONT TestParsePathInfoJSON/whitespace_only262=== CONT TestParsePathInfoJSON/empty_input263=== CONT TestParsePathInfoJSON/Lix_format264--- PASS: TestParsePathInfoJSON (0.00s)265 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)266 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)267 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)268 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)269 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)270=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon271--- PASS: TestPathInfoHashCompatibility (0.00s)272 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)273 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)274 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)275 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)276=== CONT TestEncodeNixBase32/test_string_hash277=== CONT TestEncodeNixBase32/empty_input278--- PASS: TestEncodeNixBase32 (0.00s)279 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)280 --- PASS: TestEncodeNixBase32/empty_input (0.00s)281=== CONT TestPartSizeForNAR/zero_stays_at_minimum282=== CONT TestRateLimiterFeedback/429_enables_limiter2832026/09/07 10:04:22 WARN Rate limiter enabled after throttle name=server-test rate=52842026/09/07 10:04:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:612222852026/09/07 10:04:22 WARN Rate limiter backed off name=server-test rate=5286=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter287=== CONT TestPartSizeForNAR/1_TiB288=== CONT TestPartSizeForNAR/capped_at_5_GiB289=== CONT TestPartSizeForNAR/5_TiB_S3_max_object290=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum291=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts292=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter293=== CONT TestRateLimiterFeedback/503_enables_limiter2942026/09/07 10:04:22 WARN Rate limiter enabled after throttle name=server-test rate=52952026/09/07 10:04:22 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:612282962026/09/07 10:04:22 WARN Rate limiter backed off name=server-test rate=5297--- PASS: TestRateLimiterFeedback (0.00s)298 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)299 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)300 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)301 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)302=== CONT TestPartSizeForNAR/small_stays_at_minimum303--- PASS: TestPartSizeForNAR (0.00s)304 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)305 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)306 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)307 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)308 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)309 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)310 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)311=== CONT TestSetClientTLSErrors/missing_cert_file312=== CONT TestSetClientTLSErrors/missing_ca_file313--- PASS: TestScriptTokenEmptyToken (0.02s)314=== CONT TestSetClientTLSErrors/invalid_ca_file315=== CONT TestSetClientTLSErrors/missing_key_file316=== CONT TestSetClientTLS/rejects_connection_without_client_cert317--- PASS: TestScriptTokenBadJSON (0.01s)318=== CONT TestSetClientTLS/preserves_debug_logging_transport319=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA320--- PASS: TestSetClientTLSErrors (0.00s)321 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)322 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)323 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)324 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)325=== CONT TestPathInfoCACompatibility/null_ca_field326=== CONT TestPathInfoCACompatibility/new_structured_format_-_text327=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method328=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive329=== CONT TestPathInfoCACompatibility/old_string_format_-_text330--- PASS: TestPathInfoCACompatibility (0.00s)331 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)332 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)333 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)334 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)335 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)3362026/09/07 10:04:22 http: TLS handshake error from 127.0.0.1:61230: remote error: tls: bad certificate337--- PASS: TestSetClientTLS (0.01s)338 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)339 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)340 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)341--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)342--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)343--- PASS: TestDumpPathWriterError (0.04s)344--- PASS: TestCaseHackSuffix (0.06s)345--- PASS: TestDumpPathSingleFile (0.06s)346--- PASS: TestDumpPathMatchesNix (0.09s)347--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)348PASS349Running server tests...350The files belonging to this database system will be owned by user "_nixbld13".351This user must also own the server process.352353The database cluster will be initialized with locale "C".354The default database encoding has accordingly been set to "SQL_ASCII".355The default text search configuration will be set to "english".356357Data page checksums are enabled.358359creating directory /nix/var/nix/builds/nix-76543-4286199278/postgres290378001/data ... ok360creating subdirectories ... ok361selecting dynamic shared memory implementation ... posix362selecting default "max_connections" ... 100363selecting default "shared_buffers" ... 128MB364selecting default time zone ... UTC365creating configuration files ... ok366running bootstrap script ... ok367performing post-bootstrap initialization ... ok368syncing data to disk ... ok369370initdb: warning: enabling "trust" authentication for local connections371initdb: hint: You can change this by editing pg_hba.conf or using the option -A, or --auth-local and --auth-host, the next time you run initdb.372373Success. You can now start the database server using:374375 pg_ctl -D /nix/var/nix/builds/nix-76543-4286199278/postgres290378001/data -l logfile start376377/nix/var/nix/builds/nix-76543-4286199278/postgres290378001:5432 - no response3782026-09-07 10:04:24.970 UTC [77435] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit3792026-09-07 10:04:24.970 UTC [77435] LOG: listening on Unix socket "/nix/var/nix/builds/nix-76543-4286199278/postgres290378001/.s.PGSQL.5432"3802026-09-07 10:04:24.976 UTC [77444] LOG: database system was shut down at 2026-09-07 10:04:24 UTC3812026-09-07 10:04:24.977 UTC [77435] LOG: database system is ready to accept connections382/nix/var/nix/builds/nix-76543-4286199278/postgres290378001:5432 - accepting connections383=== RUN TestService_AuthMiddleware384=== PAUSE TestService_AuthMiddleware385=== RUN TestService_AuthMiddleware_MTLSProxyHeader386=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader387=== RUN TestService_AuthMiddleware_MTLSBoundSubjects388=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects389=== RUN TestService_ReadAuthMiddleware390=== PAUSE TestService_ReadAuthMiddleware391=== RUN TestService_AuthMiddleware_OIDC392=== PAUSE TestService_AuthMiddleware_OIDC393=== RUN TestService_RequireScope_OIDC394=== PAUSE TestService_RequireScope_OIDC395=== RUN TestService_ReadScope_PublicByDefault396=== PAUSE TestService_ReadScope_PublicByDefault397=== RUN TestCacheConfigHandler398=== PAUSE TestCacheConfigHandler399=== RUN TestCacheStatsHandler400=== PAUSE TestCacheStatsHandler401=== RUN TestClaim_BuildWaitComplete402=== PAUSE TestClaim_BuildWaitComplete403=== RUN TestClaim_GCMarkedOutputCountsAsAbsent404=== PAUSE TestClaim_GCMarkedOutputCountsAsAbsent405=== RUN TestClaim_TooManyStreams406=== PAUSE TestClaim_TooManyStreams407=== RUN TestClaim_HolderDisconnectKeepsClaim408=== PAUSE TestClaim_HolderDisconnectKeepsClaim409=== RUN TestClaim_FailWakesWaitersButIsNotRemembered410=== PAUSE TestClaim_FailWakesWaitersButIsNotRemembered411=== RUN TestClaim_FailWithoutKindReleases412=== PAUSE TestClaim_FailWithoutKindReleases413=== RUN TestClaim_StaleHeartbeatStolen414=== PAUSE TestClaim_StaleHeartbeatStolen415=== RUN TestClaim_TwoInstances416=== PAUSE TestClaim_TwoInstances417=== RUN TestClaim_InputsTouched418=== PAUSE TestClaim_InputsTouched419=== RUN TestClaim_StreamsThroughServer420=== PAUSE TestClaim_StreamsThroughServer421=== RUN TestClientCADerivations422=== PAUSE TestClientCADerivations423=== RUN TestClientErrorHandling424=== PAUSE TestClientErrorHandling425=== RUN TestClientIntegration426=== PAUSE TestClientIntegration427=== RUN TestClientMultipleUploads428=== PAUSE TestClientMultipleUploads429=== RUN TestClientWithDependencies430=== PAUSE TestClientWithDependencies431=== RUN TestPinProtectsFromGC432=== PAUSE TestPinProtectsFromGC433=== RUN TestResolveDBConnectionString434=== PAUSE TestResolveDBConnectionString435=== RUN TestGCAdvisoryLockBlocksConcurrentRun4362026-09-07 10:04:25.418 UTC [77534] ERROR: relation "goose_db_version" does not exist at character 364372026-09-07 10:04:25.418 UTC [77534] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC4382026/09/07 10:04:25 OK 20241026095416_initial_model.sql (8.72ms)4392026/09/07 10:04:25 OK 20251210153512_drop_unused_gin_index.sql (1.09ms)4402026/09/07 10:04:25 OK 20251218171726_add_pins.sql (2.24ms)4412026/09/07 10:04:25 OK 20260628120000_add_object_size_and_stats.sql (2.4ms)4422026/09/07 10:04:25 OK 20260905000000_add_claims.sql (2.77ms)4432026/09/07 10:04:25 goose: successfully migrated database to version: 202609050000004442026/09/07 10:04:25 OK 1_commit_pending_closure.sql (1.99ms)4452026/09/07 10:04:25 OK 2_object_stats_trigger.sql (593.46µs)4462026/09/07 10:04:25 goose: up to current file version: 2447--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.32s)448=== RUN TestGCBugBareHashReferences449=== PAUSE TestGCBugBareHashReferences450=== RUN TestGCMetrics451=== PAUSE TestGCMetrics452=== RUN TestGCTaskStore_StartNew453=== PAUSE TestGCTaskStore_StartNew454=== RUN TestGCTaskStore_DeduplicateSameParams455=== PAUSE TestGCTaskStore_DeduplicateSameParams456=== RUN TestGCTaskStore_ConflictDifferentParams457=== PAUSE TestGCTaskStore_ConflictDifferentParams458=== RUN TestGCTaskStore_GetEmpty459=== PAUSE TestGCTaskStore_GetEmpty460=== RUN TestGCTaskStore_GetReturnsLatest461=== PAUSE TestGCTaskStore_GetReturnsLatest462=== RUN TestGCTaskStore_CompletedAllowsNewTask463=== PAUSE TestGCTaskStore_CompletedAllowsNewTask464=== RUN TestGCTaskStore_PhaseUpdates465=== PAUSE TestGCTaskStore_PhaseUpdates466=== RUN TestGCTaskStore_Fail467=== PAUSE TestGCTaskStore_Fail468=== RUN TestGracefulShutdownDrainsInflight469=== PAUSE TestGracefulShutdownDrainsInflight470=== RUN TestService_healthCheckHandler471=== PAUSE TestService_healthCheckHandler472=== RUN TestService_readinessHandler473=== PAUSE TestService_readinessHandler474=== RUN TestGenerateLandingPage475=== PAUSE TestGenerateLandingPage476=== RUN TestCacheConfigHandlerMaxNarSize477=== PAUSE TestCacheConfigHandlerMaxNarSize478=== RUN TestCreatePendingClosureRejectsOversizedNAR479=== PAUSE TestCreatePendingClosureRejectsOversizedNAR480=== RUN TestNARDeduplicationMetadataUploadBug481=== PAUSE TestNARDeduplicationMetadataUploadBug482=== RUN TestMetricsInventory483=== PAUSE TestMetricsInventory484=== RUN TestService_NativeMTLS485=== PAUSE TestService_NativeMTLS486=== RUN TestServerTLSConfig487=== PAUSE TestServerTLSConfig488=== RUN TestMultipartCleanup489=== PAUSE TestMultipartCleanup490=== RUN TestObjectStatsTrigger491=== PAUSE TestObjectStatsTrigger492=== RUN TestOrphanedObjectsGC493=== PAUSE TestOrphanedObjectsGC494=== RUN TestOrphanedObjectsGCStressTest495=== PAUSE TestOrphanedObjectsGCStressTest496=== RUN TestResurrectedObjectNotDeleted497=== PAUSE TestResurrectedObjectNotDeleted498=== RUN TestParseSingleRange499=== PAUSE TestParseSingleRange500=== RUN TestIsValidCachePath501=== PAUSE TestIsValidCachePath502=== RUN TestReadProxyNarinfo503=== PAUSE TestReadProxyNarinfo504=== RUN TestReadProxyNarinfoAlreadyDecompressed505=== PAUSE TestReadProxyNarinfoAlreadyDecompressed506=== RUN TestReadProxyNarStreaming507=== PAUSE TestReadProxyNarStreaming508=== RUN TestReadProxy404509=== PAUSE TestReadProxy404510=== RUN TestReadProxyInvalidPath511=== PAUSE TestReadProxyInvalidPath512=== RUN TestReadProxyHead513=== PAUSE TestReadProxyHead514=== RUN TestReadProxyConditionalGet515=== PAUSE TestReadProxyConditionalGet516=== RUN TestReadProxyRootRedirectsToIndexHTML517=== PAUSE TestReadProxyRootRedirectsToIndexHTML518=== RUN TestReadProxyDisabled519=== PAUSE TestReadProxyDisabled520=== RUN TestReadRedirectNar521=== PAUSE TestReadRedirectNar522=== RUN TestReadRedirectKeepsNarinfoProxied523=== PAUSE TestReadRedirectKeepsNarinfoProxied524=== RUN TestReadProxyRangeRequest525=== PAUSE TestReadProxyRangeRequest526=== RUN TestReadRedirectUsesPublicS3URL527=== PAUSE TestReadRedirectUsesPublicS3URL528=== RUN TestRedundantMultipartUpload529=== PAUSE TestRedundantMultipartUpload530=== RUN TestCompleteMultipartUpload_ErrorButObjectExists531=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists532=== RUN TestCompletedNarNotReofferedAcrossClosures533=== PAUSE TestCompletedNarNotReofferedAcrossClosures534=== RUN TestPresignedUploadRegisteredBeforeCommit535=== PAUSE TestPresignedUploadRegisteredBeforeCommit536=== RUN TestService_Rustfstest537=== PAUSE TestService_Rustfstest538=== RUN TestParseSize539=== PAUSE TestParseSize540=== RUN TestSkippedUploadsHandler541=== PAUSE TestSkippedUploadsHandler542=== RUN TestSystemdListenerNotActivated543--- PASS: TestSystemdListenerNotActivated (0.00s)544=== RUN TestWatchdogBeatsWhenHealthy545--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)546=== RUN TestWatchdogSkipsWhenUnhealthy5472026/09/07 10:04:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5482026/09/07 10:04:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5492026/09/07 10:04:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5502026/09/07 10:04:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5512026/09/07 10:04:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5522026/09/07 10:04:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5532026/09/07 10:04:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5542026/09/07 10:04:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"5552026/09/07 10:04:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"556--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)557=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle558=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle559=== RUN TestProxyWriteTimeout560=== PAUSE TestProxyWriteTimeout561=== RUN TestIsValidUploadKey562=== PAUSE TestIsValidUploadKey563=== RUN TestUploadHandlersRejectInvalidKeys564=== PAUSE TestUploadHandlersRejectInvalidKeys565=== RUN TestUploadHandlersRejectOversizedBody566=== PAUSE TestUploadHandlersRejectOversizedBody567=== RUN TestService_cleanupPendingClosuresHandler568=== PAUSE TestService_cleanupPendingClosuresHandler569=== RUN TestService_createPendingClosureHandler570=== PAUSE TestService_createPendingClosureHandler571=== RUN TestService_verifyS3Integrity572=== PAUSE TestService_verifyS3Integrity573=== RUN TestCompleteMultipartUnregistered574=== PAUSE TestCompleteMultipartUnregistered575=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT576=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT577=== CONT TestService_AuthMiddleware578=== CONT TestNARDeduplicationMetadataUploadBug579=== CONT TestClientIntegration580=== CONT TestCreatePendingClosureRejectsOversizedNAR581=== CONT TestClaim_TooManyStreams582=== CONT TestReadRedirectKeepsNarinfoProxied5832026/09/07 10:04:25 INFO Received uploads request method=POST path=/api/pending_closures584=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT585=== CONT TestCompleteMultipartUnregistered586=== CONT TestService_verifyS3Integrity587--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)588=== CONT TestService_cleanupPendingClosuresHandler589=== CONT TestService_createPendingClosureHandler5902026-09-07 10:04:25.997 UTC [77603] ERROR: relation "goose_db_version" does not exist at character 365912026-09-07 10:04:25.997 UTC [77603] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5922026-09-07 10:04:25.998 UTC [77604] ERROR: relation "goose_db_version" does not exist at character 365932026-09-07 10:04:25.998 UTC [77604] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5942026-09-07 10:04:26.001 UTC [77605] ERROR: relation "goose_db_version" does not exist at character 365952026-09-07 10:04:26.001 UTC [77605] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5962026-09-07 10:04:26.005 UTC [77606] ERROR: relation "goose_db_version" does not exist at character 365972026-09-07 10:04:26.005 UTC [77606] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC5982026/09/07 10:04:26 OK 20241026095416_initial_model.sql (11.07ms)5992026-09-07 10:04:26.021 UTC [77608] ERROR: relation "goose_db_version" does not exist at character 366002026-09-07 10:04:26.021 UTC [77608] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6012026/09/07 10:04:26 OK 20241026095416_initial_model.sql (12.08ms)6022026/09/07 10:04:26 OK 20241026095416_initial_model.sql (12.4ms)6032026/09/07 10:04:26 OK 20241026095416_initial_model.sql (10.04ms)6042026/09/07 10:04:26 OK 20251210153512_drop_unused_gin_index.sql (832.13µs)6052026/09/07 10:04:26 OK 20251210153512_drop_unused_gin_index.sql (1.01ms)6062026/09/07 10:04:26 OK 20251210153512_drop_unused_gin_index.sql (923.46µs)6072026/09/07 10:04:26 OK 20251210153512_drop_unused_gin_index.sql (837.88µs)6082026-09-07 10:04:26.024 UTC [77609] ERROR: relation "goose_db_version" does not exist at character 366092026-09-07 10:04:26.024 UTC [77609] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6102026/09/07 10:04:26 OK 20251218171726_add_pins.sql (2.13ms)6112026/09/07 10:04:26 OK 20251218171726_add_pins.sql (2.06ms)6122026/09/07 10:04:26 OK 20251218171726_add_pins.sql (2.43ms)6132026-09-07 10:04:26.026 UTC [77611] ERROR: relation "goose_db_version" does not exist at character 366142026-09-07 10:04:26.026 UTC [77611] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6152026/09/07 10:04:26 OK 20251218171726_add_pins.sql (2.46ms)6162026-09-07 10:04:26.027 UTC [77610] ERROR: relation "goose_db_version" does not exist at character 366172026-09-07 10:04:26.027 UTC [77610] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6182026/09/07 10:04:26 OK 20260628120000_add_object_size_and_stats.sql (1.92ms)6192026/09/07 10:04:26 OK 20260628120000_add_object_size_and_stats.sql (2.43ms)6202026/09/07 10:04:26 OK 20260628120000_add_object_size_and_stats.sql (2.17ms)6212026/09/07 10:04:26 OK 20260628120000_add_object_size_and_stats.sql (2.55ms)6222026/09/07 10:04:26 OK 20260905000000_add_claims.sql (2.16ms)6232026/09/07 10:04:26 goose: successfully migrated database to version: 202609050000006242026/09/07 10:04:26 OK 20260905000000_add_claims.sql (2.7ms)6252026/09/07 10:04:26 goose: successfully migrated database to version: 202609050000006262026/09/07 10:04:26 OK 20260905000000_add_claims.sql (3.47ms)6272026/09/07 10:04:26 goose: successfully migrated database to version: 202609050000006282026/09/07 10:04:26 OK 20260905000000_add_claims.sql (2.85ms)6292026/09/07 10:04:26 goose: successfully migrated database to version: 202609050000006302026/09/07 10:04:26 OK 1_commit_pending_closure.sql (2.06ms)6312026/09/07 10:04:26 OK 1_commit_pending_closure.sql (1.61ms)6322026/09/07 10:04:26 OK 2_object_stats_trigger.sql (566.5µs)6332026/09/07 10:04:26 goose: up to current file version: 26342026/09/07 10:04:26 OK 2_object_stats_trigger.sql (558.75µs)6352026/09/07 10:04:26 goose: up to current file version: 26362026/09/07 10:04:26 OK 1_commit_pending_closure.sql (1.35ms)6372026/09/07 10:04:26 OK 1_commit_pending_closure.sql (1.95ms)6382026/09/07 10:04:26 OK 2_object_stats_trigger.sql (511.75µs)6392026/09/07 10:04:26 goose: up to current file version: 26402026/09/07 10:04:26 OK 2_object_stats_trigger.sql (590.46µs)6412026/09/07 10:04:26 goose: up to current file version: 26422026/09/07 10:04:26 OK 20241026095416_initial_model.sql (84.13ms)6432026/09/07 10:04:26 OK 20251210153512_drop_unused_gin_index.sql (7.58ms)6442026/09/07 10:04:26 OK 20241026095416_initial_model.sql (90.47ms)6452026/09/07 10:04:26 OK 20241026095416_initial_model.sql (95.33ms)6462026/09/07 10:04:26 OK 20251210153512_drop_unused_gin_index.sql (4.52ms)6472026/09/07 10:04:26 OK 20251218171726_add_pins.sql (7.77ms)6482026/09/07 10:04:26 OK 20251210153512_drop_unused_gin_index.sql (8.22ms)6492026/09/07 10:04:26 OK 20251218171726_add_pins.sql (9.08ms)6502026/09/07 10:04:26 OK 20260628120000_add_object_size_and_stats.sql (8.56ms)6512026/09/07 10:04:26 OK 20251218171726_add_pins.sql (2.94ms)6522026/09/07 10:04:26 OK 20241026095416_initial_model.sql (103.4ms)6532026/09/07 10:04:26 OK 20251210153512_drop_unused_gin_index.sql (6.01ms)6542026/09/07 10:04:26 OK 20260628120000_add_object_size_and_stats.sql (7.21ms)6552026/09/07 10:04:26 OK 20260628120000_add_object_size_and_stats.sql (15.16ms)6562026/09/07 10:04:26 OK 20260905000000_add_claims.sql (15.03ms)6572026/09/07 10:04:26 goose: successfully migrated database to version: 202609050000006582026/09/07 10:04:26 OK 20251218171726_add_pins.sql (8.45ms)6592026/09/07 10:04:26 OK 1_commit_pending_closure.sql (3.05ms)6602026/09/07 10:04:26 OK 2_object_stats_trigger.sql (614.38µs)6612026/09/07 10:04:26 goose: up to current file version: 26622026/09/07 10:04:26 OK 20260905000000_add_claims.sql (16.43ms)6632026/09/07 10:04:26 goose: successfully migrated database to version: 202609050000006642026/09/07 10:04:26 OK 1_commit_pending_closure.sql (2.63ms)6652026/09/07 10:04:26 OK 2_object_stats_trigger.sql (382.08µs)6662026/09/07 10:04:26 goose: up to current file version: 26672026/09/07 10:04:26 OK 20260628120000_add_object_size_and_stats.sql (18.05ms)6682026/09/07 10:04:26 OK 20260905000000_add_claims.sql (19.13ms)6692026/09/07 10:04:26 goose: successfully migrated database to version: 202609050000006702026/09/07 10:04:26 OK 1_commit_pending_closure.sql (2.32ms)6712026/09/07 10:04:26 OK 2_object_stats_trigger.sql (829.58µs)6722026/09/07 10:04:26 goose: up to current file version: 26732026/09/07 10:04:26 OK 20260905000000_add_claims.sql (9.61ms)6742026/09/07 10:04:26 goose: successfully migrated database to version: 202609050000006752026/09/07 10:04:26 OK 1_commit_pending_closure.sql (6.45ms)6762026/09/07 10:04:26 OK 2_object_stats_trigger.sql (668.83µs)6772026/09/07 10:04:26 goose: up to current file version: 26782026/09/07 10:04:26 WARN claim: cannot clear write deadline error="feature not supported"6792026-09-07 10:04:26.222 UTC [77618] ERROR: relation "goose_db_version" does not exist at character 366802026-09-07 10:04:26.222 UTC [77618] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC6812026-09-07 10:04:26.222 UTC [77619] ERROR: relation "goose_db_version" does not exist at character 366822026-09-07 10:04:26.222 UTC [77619] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC683--- PASS: TestClaim_TooManyStreams (0.47s)684=== CONT TestUploadHandlersRejectOversizedBody685=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure686=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure687=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart688=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart689=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts690=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts691=== CONT TestUploadHandlersRejectInvalidKeys692=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info693=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info694=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal695=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal696=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key697=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key698=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key699=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key700=== CONT TestIsValidUploadKey701=== RUN TestIsValidUploadKey/narinfo702=== PAUSE TestIsValidUploadKey/narinfo703=== RUN TestIsValidUploadKey/nar_zst704=== PAUSE TestIsValidUploadKey/nar_zst705=== RUN TestIsValidUploadKey/nar_xz706=== PAUSE TestIsValidUploadKey/nar_xz707=== RUN TestIsValidUploadKey/nar_plain708=== PAUSE TestIsValidUploadKey/nar_plain709=== RUN TestIsValidUploadKey/listing710=== PAUSE TestIsValidUploadKey/listing711=== RUN TestIsValidUploadKey/build_log712=== PAUSE TestIsValidUploadKey/build_log713=== RUN TestIsValidUploadKey/build_log_home-manager_file714=== PAUSE TestIsValidUploadKey/build_log_home-manager_file715=== RUN TestIsValidUploadKey/build_log_plus_in_name716=== PAUSE TestIsValidUploadKey/build_log_plus_in_name717=== RUN TestIsValidUploadKey/build_log_question_mark718=== PAUSE TestIsValidUploadKey/build_log_question_mark719=== RUN TestIsValidUploadKey/build_log_equals720=== PAUSE TestIsValidUploadKey/build_log_equals721=== RUN TestIsValidUploadKey/realisation722=== PAUSE TestIsValidUploadKey/realisation723=== RUN TestIsValidUploadKey/realisation_plus_in_output724=== PAUSE TestIsValidUploadKey/realisation_plus_in_output725=== RUN TestIsValidUploadKey/nix-cache-info726=== PAUSE TestIsValidUploadKey/nix-cache-info727=== RUN TestIsValidUploadKey/index.html728=== PAUSE TestIsValidUploadKey/index.html729=== RUN TestIsValidUploadKey/narinfo_key,_nar_type730=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type731=== RUN TestIsValidUploadKey/nar_key,_narinfo_type732=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type733=== RUN TestIsValidUploadKey/listing_key,_narinfo_type734=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type735=== RUN TestIsValidUploadKey/traversal736=== PAUSE TestIsValidUploadKey/traversal737=== RUN TestIsValidUploadKey/traversal_nar738=== PAUSE TestIsValidUploadKey/traversal_nar739=== RUN TestIsValidUploadKey/absolute740=== PAUSE TestIsValidUploadKey/absolute741=== RUN TestIsValidUploadKey/empty_key742=== PAUSE TestIsValidUploadKey/empty_key743=== RUN TestIsValidUploadKey/unknown_type744=== PAUSE TestIsValidUploadKey/unknown_type745=== CONT TestIsValidCachePath746=== RUN TestIsValidCachePath/narinfo747=== PAUSE TestIsValidCachePath/narinfo748=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars749=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars750=== RUN TestIsValidCachePath/nar_zst751=== PAUSE TestIsValidCachePath/nar_zst752=== RUN TestIsValidCachePath/nar_xz753=== PAUSE TestIsValidCachePath/nar_xz754=== RUN TestIsValidCachePath/nar_bz2755=== PAUSE TestIsValidCachePath/nar_bz2756=== RUN TestIsValidCachePath/nar_uncompressed757=== PAUSE TestIsValidCachePath/nar_uncompressed758=== RUN TestIsValidCachePath/ls759=== PAUSE TestIsValidCachePath/ls760=== RUN TestIsValidCachePath/log761=== PAUSE TestIsValidCachePath/log762=== RUN TestIsValidCachePath/realisation763=== PAUSE TestIsValidCachePath/realisation764=== RUN TestIsValidCachePath/nix-cache-info765=== PAUSE TestIsValidCachePath/nix-cache-info766=== RUN TestIsValidCachePath/index.html767=== PAUSE TestIsValidCachePath/index.html768=== RUN TestIsValidCachePath/traversal_parent769=== PAUSE TestIsValidCachePath/traversal_parent770=== RUN TestIsValidCachePath/traversal_in_middle771=== PAUSE TestIsValidCachePath/traversal_in_middle772=== RUN TestIsValidCachePath/invalid_char_e773=== PAUSE TestIsValidCachePath/invalid_char_e774=== RUN TestIsValidCachePath/invalid_char_u775=== PAUSE TestIsValidCachePath/invalid_char_u776=== RUN TestIsValidCachePath/random_path777=== PAUSE TestIsValidCachePath/random_path778=== RUN TestIsValidCachePath/empty779=== PAUSE TestIsValidCachePath/empty780=== RUN TestIsValidCachePath/leading_slash781=== PAUSE TestIsValidCachePath/leading_slash782=== RUN TestIsValidCachePath/wrong_extension783=== PAUSE TestIsValidCachePath/wrong_extension784=== RUN TestIsValidCachePath/short_hash785=== PAUSE TestIsValidCachePath/short_hash786=== CONT TestParseSingleRange787=== RUN TestParseSingleRange/none788=== PAUSE TestParseSingleRange/none789=== RUN TestParseSingleRange/unknown_unit790=== PAUSE TestParseSingleRange/unknown_unit791=== RUN TestParseSingleRange/multi-range_ignored792=== PAUSE TestParseSingleRange/multi-range_ignored793=== RUN TestParseSingleRange/malformed_no_dash794=== PAUSE TestParseSingleRange/malformed_no_dash795=== RUN TestParseSingleRange/malformed_both_empty796=== PAUSE TestParseSingleRange/malformed_both_empty797=== RUN TestParseSingleRange/malformed_end_before_start798=== PAUSE TestParseSingleRange/malformed_end_before_start799=== RUN TestParseSingleRange/closed800=== PAUSE TestParseSingleRange/closed801=== RUN TestParseSingleRange/open-ended802=== PAUSE TestParseSingleRange/open-ended803=== RUN TestParseSingleRange/end_clamped_to_size804=== PAUSE TestParseSingleRange/end_clamped_to_size805=== RUN TestParseSingleRange/suffix806=== PAUSE TestParseSingleRange/suffix807=== RUN TestParseSingleRange/suffix_exceeds_size808=== PAUSE TestParseSingleRange/suffix_exceeds_size809=== RUN TestParseSingleRange/single_byte810=== PAUSE TestParseSingleRange/single_byte811=== RUN TestParseSingleRange/start_past_EOF812=== PAUSE TestParseSingleRange/start_past_EOF813=== RUN TestParseSingleRange/start_far_past_EOF814=== PAUSE TestParseSingleRange/start_far_past_EOF815=== CONT TestResurrectedObjectNotDeleted8162026/09/07 10:04:26 OK 20241026095416_initial_model.sql (84.01ms)8172026/09/07 10:04:26 OK 20251210153512_drop_unused_gin_index.sql (10.84ms)8182026/09/07 10:04:26 OK 20241026095416_initial_model.sql (95.64ms)8192026/09/07 10:04:26 OK 20251210153512_drop_unused_gin_index.sql (12.19ms)8202026/09/07 10:04:26 OK 20251218171726_add_pins.sql (21.88ms)8212026/09/07 10:04:26 INFO Received uploads request method=POST path=/api/pending_closures8222026/09/07 10:04:26 OK 20251218171726_add_pins.sql (14.57ms)8232026/09/07 10:04:26 OK 20260628120000_add_object_size_and_stats.sql (20.15ms)8242026/09/07 10:04:26 OK 20260628120000_add_object_size_and_stats.sql (24.5ms)825--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.65s)826=== CONT TestOrphanedObjectsGCStressTest8272026/09/07 10:04:26 OK 20260905000000_add_claims.sql (29.26ms)8282026/09/07 10:04:26 goose: successfully migrated database to version: 202609050000008292026/09/07 10:04:26 OK 1_commit_pending_closure.sql (7.47ms)8302026/09/07 10:04:26 OK 2_object_stats_trigger.sql (711.79µs)8312026/09/07 10:04:26 goose: up to current file version: 28322026/09/07 10:04:26 OK 20260905000000_add_claims.sql (32.24ms)8332026/09/07 10:04:26 goose: successfully migrated database to version: 202609050000008342026/09/07 10:04:26 OK 1_commit_pending_closure.sql (6.68ms)8352026/09/07 10:04:26 OK 2_object_stats_trigger.sql (671.33µs)8362026/09/07 10:04:26 goose: up to current file version: 2837--- PASS: TestReadRedirectKeepsNarinfoProxied (0.79s)838=== CONT TestOrphanedObjectsGC8392026/09/07 10:04:26 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"840--- PASS: TestService_AuthMiddleware (0.93s)841=== CONT TestProxyWriteTimeout842=== RUN TestProxyWriteTimeout/narinfo843=== PAUSE TestProxyWriteTimeout/narinfo844=== RUN TestProxyWriteTimeout/1_GiB_nar845=== PAUSE TestProxyWriteTimeout/1_GiB_nar846=== RUN TestProxyWriteTimeout/10_GiB_nar847=== PAUSE TestProxyWriteTimeout/10_GiB_nar848=== RUN TestProxyWriteTimeout/unknown_size849=== PAUSE TestProxyWriteTimeout/unknown_size850=== CONT TestObjectStatsTrigger8512026-09-07 10:04:26.706 UTC [77655] ERROR: relation "goose_db_version" does not exist at character 368522026-09-07 10:04:26.706 UTC [77655] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8532026-09-07 10:04:26.747 UTC [77660] ERROR: relation "goose_db_version" does not exist at character 368542026-09-07 10:04:26.747 UTC [77660] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8552026/09/07 10:04:26 OK 20241026095416_initial_model.sql (49.8ms)8562026/09/07 10:04:26 OK 20251210153512_drop_unused_gin_index.sql (1.11ms)8572026/09/07 10:04:26 OK 20251218171726_add_pins.sql (15.3ms)8582026/09/07 10:04:26 OK 20260628120000_add_object_size_and_stats.sql (12.14ms)8592026/09/07 10:04:26 OK 20260905000000_add_claims.sql (24.49ms)8602026/09/07 10:04:26 goose: successfully migrated database to version: 202609050000008612026/09/07 10:04:26 OK 20241026095416_initial_model.sql (61.71ms)8622026/09/07 10:04:26 OK 1_commit_pending_closure.sql (2.35ms)8632026/09/07 10:04:26 OK 2_object_stats_trigger.sql (645.29µs)8642026/09/07 10:04:26 goose: up to current file version: 28652026/09/07 10:04:26 OK 20251210153512_drop_unused_gin_index.sql (7.35ms)8662026/09/07 10:04:26 OK 20251218171726_add_pins.sql (7.59ms)8672026/09/07 10:04:26 OK 20260628120000_add_object_size_and_stats.sql (13.63ms)8682026/09/07 10:04:26 OK 20260905000000_add_claims.sql (15.44ms)8692026/09/07 10:04:26 goose: successfully migrated database to version: 202609050000008702026/09/07 10:04:26 OK 1_commit_pending_closure.sql (12.27ms)8712026/09/07 10:04:26 OK 2_object_stats_trigger.sql (620.5µs)8722026/09/07 10:04:26 goose: up to current file version: 28732026-09-07 10:04:26.905 UTC [77679] ERROR: relation "goose_db_version" does not exist at character 368742026-09-07 10:04:26.905 UTC [77679] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC875=== NAME TestClientIntegration876 client_integration_test.go:277: Created store path: /nix/var/nix/builds/nix-76543-4286199278/TestClientIntegration4221110551/002/store/7m86p0mw9v35w62a8jy13gn7rj268b9i-test-file.txt8772026/09/07 10:04:26 INFO Received uploads request method=POST path=/api/pending_closures8782026/09/07 10:04:26 INFO Received uploads request method=POST path=/api/pending_closures8792026/09/07 10:04:26 INFO Received uploads request method=POST path=/api/pending_closures8802026/09/07 10:04:26 OK 20241026095416_initial_model.sql (52.11ms)8812026/09/07 10:04:26 OK 20251210153512_drop_unused_gin_index.sql (5.11ms)8822026/09/07 10:04:27 OK 20251218171726_add_pins.sql (20.98ms)8832026/09/07 10:04:27 OK 20260628120000_add_object_size_and_stats.sql (9.1ms)8842026-09-07 10:04:27.033 UTC [77734] ERROR: relation "goose_db_version" does not exist at character 368852026-09-07 10:04:27.033 UTC [77734] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC8862026/09/07 10:04:27 OK 20260905000000_add_claims.sql (11.97ms)8872026/09/07 10:04:27 goose: successfully migrated database to version: 202609050000008882026/09/07 10:04:27 OK 1_commit_pending_closure.sql (7.31ms)8892026/09/07 10:04:27 OK 2_object_stats_trigger.sql (644.79µs)8902026/09/07 10:04:27 goose: up to current file version: 28912026/09/07 10:04:27 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"8922026/09/07 10:04:27 OK 20241026095416_initial_model.sql (70.6ms)8932026/09/07 10:04:27 OK 20251210153512_drop_unused_gin_index.sql (10.9ms)8942026/09/07 10:04:27 OK 20251218171726_add_pins.sql (26.86ms)8952026/09/07 10:04:27 INFO Received uploads request method=POST path=/api/pending_closures8962026/09/07 10:04:27 OK 20260628120000_add_object_size_and_stats.sql (12.17ms)8972026/09/07 10:04:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)8982026/09/07 10:04:27 INFO Uploading 7m86p0mw9v35w62a8jy13gn7rj268b9i-test-file.txt (152B)8992026/09/07 10:04:27 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"9002026/09/07 10:04:27 OK 20260905000000_add_claims.sql (14.71ms)9012026/09/07 10:04:27 goose: successfully migrated database to version: 202609050000009022026/09/07 10:04:27 WARN Failed to register uploaded object key=7m86p0mw9v35w62a8jy13gn7rj268b9i.ls error="server returned 404: 404 page not found\n"9032026/09/07 10:04:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9042026/09/07 10:04:27 INFO Signed narinfos id=1 count=19052026/09/07 10:04:27 INFO Uploading 1 narinfos9062026/09/07 10:04:27 OK 1_commit_pending_closure.sql (2.06ms)9072026/09/07 10:04:27 OK 2_object_stats_trigger.sql (587.67µs)9082026/09/07 10:04:27 goose: up to current file version: 29092026/09/07 10:04:27 WARN Failed to register uploaded object key=7m86p0mw9v35w62a8jy13gn7rj268b9i.narinfo error="server returned 404: 404 page not found\n"9102026/09/07 10:04:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9112026/09/07 10:04:27 INFO Completed upload id=19122026/09/07 10:04:27 INFO Upload complete. (196ms)913 client_integration_test.go:293: Retrieved narinfo from S3:914 StorePath: /nix/var/nix/builds/nix-76543-4286199278/TestClientIntegration4221110551/002/store/7m86p0mw9v35w62a8jy13gn7rj268b9i-test-file.txt915 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst916 Compression: zstd917 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1918 NarSize: 152919 References: 920 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1921 client_integration_test.go:294: Retrieved .ls file from S3 (compressed size: 77 bytes)922 client_integration_test.go:294: Decompressed .ls content (64 bytes):923 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}924 client_integration_test.go:297: Testing garbage collection...925=== NAME TestNARDeduplicationMetadataUploadBug926 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-76543-4286199278/TestNARDeduplicationMetadataUploadBug381549900/001/store/lmcnb055gq2a3iy687frlmqa5na0ak7a-file1.txt9272026/09/07 10:04:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures9282026/09/07 10:04:27 INFO Garbage collection started9292026/09/07 10:04:27 INFO Aborted multipart uploads count=09302026/09/07 10:04:27 WARN Force mode enabled - objects will be deleted immediately without grace period9312026/09/07 10:04:27 INFO Received cleanup request method=DELETE path=/api/pending_closures9322026/09/07 10:04:27 INFO Aborted multipart uploads count=09332026/09/07 10:04:27 INFO Received uploads request method=POST path=/api/pending_closures9342026/09/07 10:04:27 INFO Received cleanup request method=DELETE path=/api/pending_closures9352026/09/07 10:04:27 INFO Aborted multipart uploads count=19362026/09/07 10:04:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9372026-09-07 10:04:27.386 UTC [77610] ERROR: Closure does not exist: id=19382026-09-07 10:04:27.386 UTC [77610] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 16 at RAISE9392026-09-07 10:04:27.386 UTC [77610] STATEMENT: -- name: CommitPendingClosure :exec940 SELECT commit_pending_closure($1::bigint)941 942--- PASS: TestService_cleanupPendingClosuresHandler (1.63s)943=== CONT TestMultipartCleanup9442026/09/07 10:04:27 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"9452026/09/07 10:04:27 INFO Received uploads request method=POST path=/api/pending_closures9462026/09/07 10:04:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)9472026/09/07 10:04:27 INFO Uploading lmcnb055gq2a3iy687frlmqa5na0ak7a-file1.txt (160B)9482026/09/07 10:04:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9492026/09/07 10:04:27 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst950--- PASS: TestCompleteMultipartUnregistered (1.79s)951=== CONT TestServerTLSConfig952=== RUN TestServerTLSConfig/no_client_CA953=== PAUSE TestServerTLSConfig/no_client_CA954=== RUN TestServerTLSConfig/missing_CA_file955=== PAUSE TestServerTLSConfig/missing_CA_file956=== RUN TestServerTLSConfig/not_a_PEM_file957=== PAUSE TestServerTLSConfig/not_a_PEM_file958=== CONT TestService_NativeMTLS9592026/09/07 10:04:27 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"9602026/09/07 10:04:27 WARN Failed to register uploaded object key=lmcnb055gq2a3iy687frlmqa5na0ak7a.ls error="server returned 404: 404 page not found\n"9612026/09/07 10:04:27 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign9622026/09/07 10:04:27 INFO Signed narinfos id=1 count=19632026/09/07 10:04:27 INFO Uploading 1 narinfos9642026/09/07 10:04:27 WARN Failed to register uploaded object key=lmcnb055gq2a3iy687frlmqa5na0ak7a.narinfo error="server returned 404: 404 page not found\n"9652026/09/07 10:04:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9662026/09/07 10:04:27 INFO Completed upload id=19672026/09/07 10:04:27 INFO Upload complete. (261ms)968=== NAME TestNARDeduplicationMetadataUploadBug969 metadata_upload_test.go:54: Retrieved narinfo from S3:970 StorePath: /nix/var/nix/builds/nix-76543-4286199278/TestNARDeduplicationMetadataUploadBug381549900/001/store/lmcnb055gq2a3iy687frlmqa5na0ak7a-file1.txt971 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst972 Compression: zstd973 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf974 NarSize: 160975 References: 976 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf977 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)978 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):979 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}9802026-09-07 10:04:27.650 UTC [78151] ERROR: relation "goose_db_version" does not exist at character 369812026-09-07 10:04:27.650 UTC [78151] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC9822026/09/07 10:04:27 OK 20241026095416_initial_model.sql (12.74ms)9832026/09/07 10:04:27 OK 20251210153512_drop_unused_gin_index.sql (587.17µs)9842026/09/07 10:04:27 OK 20251218171726_add_pins.sql (845.79µs)9852026/09/07 10:04:27 OK 20260628120000_add_object_size_and_stats.sql (1.74ms)9862026/09/07 10:04:27 OK 20260905000000_add_claims.sql (1.27ms)9872026/09/07 10:04:27 goose: successfully migrated database to version: 202609050000009882026/09/07 10:04:27 OK 1_commit_pending_closure.sql (943.79µs)9892026/09/07 10:04:27 OK 2_object_stats_trigger.sql (422.17µs)9902026/09/07 10:04:27 goose: up to current file version: 29912026/09/07 10:04:27 INFO Received uploads request method=POST path=/api/pending_closures9922026-09-07 10:04:27.855 UTC [78183] ERROR: relation "goose_db_version" does not exist at character 369932026-09-07 10:04:27.855 UTC [78183] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC994 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-76543-4286199278/TestNARDeduplicationMetadataUploadBug381549900/001/store/1k45664ihdsfwzi9cb6271x6x4d4q2yf-file2.txt9952026/09/07 10:04:27 OK 20241026095416_initial_model.sql (19.07ms)9962026/09/07 10:04:27 OK 20251210153512_drop_unused_gin_index.sql (964.88µs)9972026/09/07 10:04:27 OK 20251218171726_add_pins.sql (1.25ms)9982026/09/07 10:04:27 OK 20260628120000_add_object_size_and_stats.sql (2.41ms)9992026/09/07 10:04:27 OK 20260905000000_add_claims.sql (1.23ms)10002026/09/07 10:04:27 goose: successfully migrated database to version: 2026090500000010012026/09/07 10:04:27 OK 1_commit_pending_closure.sql (1.22ms)10022026/09/07 10:04:27 OK 2_object_stats_trigger.sql (221.96µs)10032026/09/07 10:04:27 goose: up to current file version: 210042026/09/07 10:04:28 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=010052026/09/07 10:04:28 INFO Vacuumed table table=pending_closures1006--- PASS: TestResurrectedObjectNotDeleted (1.95s)1007=== CONT TestMetricsInventory10082026/09/07 10:04:28 INFO Vacuumed table table=pending_objects10092026/09/07 10:04:28 INFO Vacuumed table table=multipart_uploads10102026/09/07 10:04:28 INFO Vacuumed table table=closures10112026/09/07 10:04:28 INFO Vacuumed table table=objects10122026/09/07 10:04:28 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"10132026/09/07 10:04:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10142026/09/07 10:04:28 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NTU5MDNjNWQtYTgxMC00Y2ZlLTk4M2EtYmMwMDc3ZDRhNTlmLjU0NTM4OTJhLTRmMGMtNGU5Ny1iOWQ4LTdjOTJkNWM4MTMyNXgxNzg4Nzc1NDY2OTg3MzI1MDAw parts=1010152026/09/07 10:04:28 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10162026/09/07 10:04:28 INFO Received uploads request method=POST path=/api/pending_closures10172026/09/07 10:04:28 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)10182026/09/07 10:04:28 INFO Completed upload id=110192026/09/07 10:04:28 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000010202026/09/07 10:04:28 INFO Received uploads request method=POST path=/api/pending_closures10212026/09/07 10:04:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures10222026/09/07 10:04:28 INFO Aborted multipart uploads count=010232026/09/07 10:04:28 WARN Failed to register uploaded object key=1k45664ihdsfwzi9cb6271x6x4d4q2yf.ls error="server returned 404: 404 page not found\n"10242026/09/07 10:04:28 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign10252026/09/07 10:04:28 INFO Signed narinfos id=2 count=110262026/09/07 10:04:28 INFO Uploading 1 narinfos10272026/09/07 10:04:28 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=0 objects-failed-to-delete=010282026/09/07 10:04:28 INFO Vacuumed table table=pending_closures10292026/09/07 10:04:28 WARN Failed to register uploaded object key=1k45664ihdsfwzi9cb6271x6x4d4q2yf.narinfo error="server returned 404: 404 page not found\n"10302026/09/07 10:04:28 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete10312026/09/07 10:04:28 INFO Completed upload id=210322026/09/07 10:04:28 INFO Upload complete. (247ms)1033=== NAME TestNARDeduplicationMetadataUploadBug1034 metadata_upload_test.go:76: Retrieved narinfo from S3:1035 StorePath: /nix/var/nix/builds/nix-76543-4286199278/TestNARDeduplicationMetadataUploadBug381549900/001/store/1k45664ihdsfwzi9cb6271x6x4d4q2yf-file2.txt1036 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1037 Compression: zstd1038 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1039 NarSize: 1601040 References: 1041 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1042 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1043 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1044 {"version":1,"root":{"type":"regular","size":44}}10452026/09/07 10:04:28 INFO Vacuumed table table=pending_objects1046--- PASS: TestNARDeduplicationMetadataUploadBug (2.66s)1047=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle10482026/09/07 10:04:28 INFO Vacuumed table table=multipart_uploads10492026/09/07 10:04:28 INFO Vacuumed table table=closures10502026/09/07 10:04:28 INFO Vacuumed table table=objects10512026/09/07 10:04:28 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001052--- PASS: TestService_createPendingClosureHandler (2.72s)1053=== CONT TestSkippedUploadsHandler10542026/09/07 10:04:28 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001055--- PASS: TestSkippedUploadsHandler (0.00s)1056=== CONT TestParseSize1057--- PASS: TestParseSize (0.00s)1058=== CONT TestService_ReadScope_PublicByDefault1059--- PASS: TestObjectStatsTrigger (2.08s)1060=== CONT TestService_Rustfstest10612026-09-07 10:04:28.910 UTC [78338] ERROR: relation "goose_db_version" does not exist at character 3610622026-09-07 10:04:28.910 UTC [78338] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10632026/09/07 10:04:28 OK 20241026095416_initial_model.sql (22.08ms)10642026/09/07 10:04:28 OK 20251210153512_drop_unused_gin_index.sql (1.22ms)10652026/09/07 10:04:28 OK 20251218171726_add_pins.sql (39.08ms)10662026/09/07 10:04:29 OK 20260628120000_add_object_size_and_stats.sql (32.65ms)10672026/09/07 10:04:29 INFO Received uploads request method=POST path=/api/pending_closures10682026/09/07 10:04:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10692026/09/07 10:04:29 OK 20260905000000_add_claims.sql (62.51ms)10702026/09/07 10:04:29 goose: successfully migrated database to version: 2026090500000010712026/09/07 10:04:29 OK 1_commit_pending_closure.sql (6.38ms)10722026/09/07 10:04:29 OK 2_object_stats_trigger.sql (637.67µs)10732026/09/07 10:04:29 goose: up to current file version: 210742026/09/07 10:04:29 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NTU5MDNjNWQtYTgxMC00Y2ZlLTk4M2EtYmMwMDc3ZDRhNTlmLjA3YTM1N2RhLWUwMGQtNDlmYi04YTAwLTAyNTUzNmQyOTVjNHgxNzg4Nzc1NDY3ODc2NzY2MDAw parts=1010752026/09/07 10:04:29 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10762026/09/07 10:04:29 INFO Completed upload id=110772026/09/07 10:04:29 INFO Received uploads request method=POST path=/api/pending_closures10782026/09/07 10:04:29 INFO Received uploads request method=POST path=/api/pending_closures10792026/09/07 10:04:29 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10802026/09/07 10:04:29 WARN Found objects in DB but missing from S3, will re-upload count=11081--- PASS: TestService_verifyS3Integrity (3.37s)1082=== CONT TestPresignedUploadRegisteredBeforeCommit10832026-09-07 10:04:29.156 UTC [78375] ERROR: relation "goose_db_version" does not exist at character 3610842026-09-07 10:04:29.156 UTC [78375] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10852026/09/07 10:04:29 OK 20241026095416_initial_model.sql (6.96ms)10862026/09/07 10:04:29 OK 20251210153512_drop_unused_gin_index.sql (1.15ms)10872026-09-07 10:04:29.174 UTC [78380] ERROR: relation "goose_db_version" does not exist at character 3610882026-09-07 10:04:29.174 UTC [78380] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC10892026/09/07 10:04:29 OK 20251218171726_add_pins.sql (15.34ms)10902026/09/07 10:04:29 OK 20260628120000_add_object_size_and_stats.sql (18.79ms)10912026/09/07 10:04:29 INFO Received cleanup request method=DELETE path=/api/pending_closures10922026/09/07 10:04:29 OK 20260905000000_add_claims.sql (10.41ms)10932026/09/07 10:04:29 goose: successfully migrated database to version: 2026090500000010942026/09/07 10:04:29 OK 1_commit_pending_closure.sql (1.66ms)10952026/09/07 10:04:29 OK 2_object_stats_trigger.sql (794.54µs)10962026/09/07 10:04:29 goose: up to current file version: 210972026/09/07 10:04:29 INFO Aborted multipart uploads count=110982026/09/07 10:04:29 OK 20241026095416_initial_model.sql (39.37ms)1099--- PASS: TestMultipartCleanup (1.85s)1100=== CONT TestCompletedNarNotReofferedAcrossClosures11012026/09/07 10:04:29 OK 20251210153512_drop_unused_gin_index.sql (6.78ms)11022026/09/07 10:04:29 OK 20251218171726_add_pins.sql (26.9ms)11032026/09/07 10:04:29 OK 20260628120000_add_object_size_and_stats.sql (13.8ms)11042026/09/07 10:04:29 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=01105=== NAME TestClientIntegration1106 client_integration_test.go:304: Objects in database after GC:1107 client_integration_test.go:304: Successfully deleted all objects with GC --force11082026/09/07 10:04:29 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11092026/09/07 10:04:29 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1110--- PASS: TestService_NativeMTLS (1.76s)1111=== CONT TestCompleteMultipartUpload_ErrorButObjectExists11122026/09/07 10:04:29 OK 20260905000000_add_claims.sql (36.7ms)11132026/09/07 10:04:29 goose: successfully migrated database to version: 202609050000001114--- PASS: TestClientIntegration (3.56s)1115=== CONT TestClaim_GCMarkedOutputCountsAsAbsent11162026/09/07 10:04:29 OK 1_commit_pending_closure.sql (8.14ms)11172026/09/07 10:04:29 OK 2_object_stats_trigger.sql (4.92ms)11182026/09/07 10:04:29 goose: up to current file version: 211192026-09-07 10:04:29.336 UTC [78408] ERROR: relation "goose_db_version" does not exist at character 3611202026-09-07 10:04:29.336 UTC [78408] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1121=== NAME TestOrphanedObjectsGC1122 orphaned_objects_gc_test.go:290: GC Test Summary:1123 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1124 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1125 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1126 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1127 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1128--- PASS: TestOrphanedObjectsGC (2.81s)1129=== CONT TestClaim_BuildWaitComplete11302026/09/07 10:04:29 OK 20241026095416_initial_model.sql (50.55ms)11312026/09/07 10:04:29 OK 20251210153512_drop_unused_gin_index.sql (6.09ms)11322026/09/07 10:04:29 OK 20251218171726_add_pins.sql (10.31ms)11332026/09/07 10:04:29 OK 20260628120000_add_object_size_and_stats.sql (7.85ms)11342026/09/07 10:04:29 OK 20260905000000_add_claims.sql (16.71ms)11352026/09/07 10:04:29 goose: successfully migrated database to version: 2026090500000011362026/09/07 10:04:29 OK 1_commit_pending_closure.sql (1.83ms)11372026/09/07 10:04:29 OK 2_object_stats_trigger.sql (520.25µs)11382026/09/07 10:04:29 goose: up to current file version: 21139--- PASS: TestMetricsInventory (1.38s)1140=== CONT TestCacheStatsHandler11412026-09-07 10:04:29.613 UTC [78472] ERROR: relation "goose_db_version" does not exist at character 3611422026-09-07 10:04:29.613 UTC [78472] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11432026/09/07 10:04:29 OK 20241026095416_initial_model.sql (69.25ms)11442026/09/07 10:04:29 OK 20251210153512_drop_unused_gin_index.sql (1.44ms)11452026/09/07 10:04:29 OK 20251218171726_add_pins.sql (13.38ms)11462026/09/07 10:04:29 INFO Received uploads request method=POST path=/api/pending_closures11472026/09/07 10:04:29 OK 20260628120000_add_object_size_and_stats.sql (20.13ms)11482026/09/07 10:04:29 OK 20260905000000_add_claims.sql (3.75ms)11492026/09/07 10:04:29 goose: successfully migrated database to version: 2026090500000011502026/09/07 10:04:29 OK 1_commit_pending_closure.sql (2.49ms)11512026/09/07 10:04:29 OK 2_object_stats_trigger.sql (683.63µs)11522026/09/07 10:04:29 goose: up to current file version: 211532026-09-07 10:04:29.826 UTC [78496] ERROR: relation "goose_db_version" does not exist at character 3611542026-09-07 10:04:29.826 UTC [78496] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1155--- PASS: TestService_ReadScope_PublicByDefault (1.52s)1156=== CONT TestCacheConfigHandler1157=== RUN TestCacheConfigHandler/full_config,_no_issuer1158=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1159=== RUN TestCacheConfigHandler/no_cache_url_configured1160=== PAUSE TestCacheConfigHandler/no_cache_url_configured1161=== RUN TestCacheConfigHandler/no_signing_keys1162=== PAUSE TestCacheConfigHandler/no_signing_keys1163=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1164=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1165=== CONT TestRedundantMultipartUpload11662026/09/07 10:04:30 OK 20241026095416_initial_model.sql (118.76ms)11672026/09/07 10:04:30 OK 20251210153512_drop_unused_gin_index.sql (11.71ms)11682026/09/07 10:04:30 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11692026-09-07 10:04:30.033 UTC [78509] ERROR: relation "goose_db_version" does not exist at character 3611702026-09-07 10:04:30.033 UTC [78509] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11712026/09/07 10:04:30 OK 20251218171726_add_pins.sql (47.67ms)11722026/09/07 10:04:30 OK 20260628120000_add_object_size_and_stats.sql (12.62ms)11732026/09/07 10:04:30 OK 20260905000000_add_claims.sql (28.18ms)11742026/09/07 10:04:30 goose: successfully migrated database to version: 2026090500000011752026-09-07 10:04:30.102 UTC [78517] ERROR: relation "goose_db_version" does not exist at character 3611762026-09-07 10:04:30.102 UTC [78517] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11772026/09/07 10:04:30 OK 1_commit_pending_closure.sql (2.56ms)11782026/09/07 10:04:30 OK 2_object_stats_trigger.sql (691.88µs)11792026/09/07 10:04:30 goose: up to current file version: 211802026-09-07 10:04:30.125 UTC [78521] ERROR: relation "goose_db_version" does not exist at character 3611812026-09-07 10:04:30.125 UTC [78521] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC11822026/09/07 10:04:30 OK 20241026095416_initial_model.sql (53.68ms)11832026/09/07 10:04:30 OK 20251210153512_drop_unused_gin_index.sql (7.42ms)11842026/09/07 10:04:30 OK 20241026095416_initial_model.sql (42.55ms)11852026/09/07 10:04:30 OK 20251218171726_add_pins.sql (4.5ms)11862026/09/07 10:04:30 OK 20251210153512_drop_unused_gin_index.sql (4.68ms)11872026/09/07 10:04:30 OK 20241026095416_initial_model.sql (20.13ms)11882026/09/07 10:04:30 OK 20251210153512_drop_unused_gin_index.sql (10.5ms)11892026/09/07 10:04:30 OK 20260628120000_add_object_size_and_stats.sql (13.16ms)11902026/09/07 10:04:30 OK 20251218171726_add_pins.sql (9.03ms)11912026/09/07 10:04:30 OK 20251218171726_add_pins.sql (19.87ms)11922026/09/07 10:04:30 OK 20260628120000_add_object_size_and_stats.sql (10.66ms)11932026/09/07 10:04:30 OK 20260905000000_add_claims.sql (19.84ms)11942026/09/07 10:04:30 goose: successfully migrated database to version: 2026090500000011952026/09/07 10:04:30 OK 1_commit_pending_closure.sql (10.58ms)11962026/09/07 10:04:30 OK 2_object_stats_trigger.sql (2.59ms)11972026/09/07 10:04:30 goose: up to current file version: 211982026/09/07 10:04:30 OK 20260628120000_add_object_size_and_stats.sql (26.59ms)11992026/09/07 10:04:30 OK 20260905000000_add_claims.sql (24.04ms)12002026/09/07 10:04:30 goose: successfully migrated database to version: 2026090500000012012026/09/07 10:04:30 OK 1_commit_pending_closure.sql (8.84ms)12022026/09/07 10:04:30 OK 2_object_stats_trigger.sql (610.25µs)12032026/09/07 10:04:30 goose: up to current file version: 21204--- PASS: TestService_Rustfstest (1.47s)1205=== CONT TestReadRedirectUsesPublicS3URL12062026/09/07 10:04:30 OK 20260905000000_add_claims.sql (28.13ms)12072026/09/07 10:04:30 goose: successfully migrated database to version: 2026090500000012082026/09/07 10:04:30 OK 1_commit_pending_closure.sql (5.27ms)12092026/09/07 10:04:30 OK 2_object_stats_trigger.sql (3.63ms)12102026/09/07 10:04:30 goose: up to current file version: 212112026-09-07 10:04:30.258 UTC [78553] ERROR: relation "goose_db_version" does not exist at character 3612122026-09-07 10:04:30.258 UTC [78553] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12132026/09/07 10:04:30 OK 20241026095416_initial_model.sql (15.16ms)12142026/09/07 10:04:30 OK 20251210153512_drop_unused_gin_index.sql (625.25µs)12152026/09/07 10:04:30 OK 20251218171726_add_pins.sql (2.23ms)12162026/09/07 10:04:30 OK 20260628120000_add_object_size_and_stats.sql (14.43ms)12172026/09/07 10:04:30 OK 20260905000000_add_claims.sql (9.59ms)12182026/09/07 10:04:30 goose: successfully migrated database to version: 2026090500000012192026/09/07 10:04:30 OK 1_commit_pending_closure.sql (2.72ms)12202026/09/07 10:04:30 OK 2_object_stats_trigger.sql (780.29µs)12212026/09/07 10:04:30 goose: up to current file version: 212222026/09/07 10:04:30 INFO Received uploads request method=POST path=/api/pending_closures12232026-09-07 10:04:30.464 UTC [78581] ERROR: relation "goose_db_version" does not exist at character 3612242026-09-07 10:04:30.464 UTC [78581] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12252026/09/07 10:04:30 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst12262026/09/07 10:04:30 INFO Received uploads request method=POST path=/api/pending_closures1227--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.33s)1228=== CONT TestReadProxyRangeRequest12292026/09/07 10:04:30 OK 20241026095416_initial_model.sql (28.48ms)12302026/09/07 10:04:30 OK 20251210153512_drop_unused_gin_index.sql (1.65ms)12312026/09/07 10:04:30 OK 20251218171726_add_pins.sql (14.88ms)12322026/09/07 10:04:30 OK 20260628120000_add_object_size_and_stats.sql (20.51ms)12332026-09-07 10:04:30.578 UTC [78607] ERROR: relation "goose_db_version" does not exist at character 3612342026-09-07 10:04:30.578 UTC [78607] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12352026/09/07 10:04:30 OK 20260905000000_add_claims.sql (19.98ms)12362026/09/07 10:04:30 goose: successfully migrated database to version: 2026090500000012372026/09/07 10:04:30 OK 1_commit_pending_closure.sql (8.46ms)12382026/09/07 10:04:30 OK 2_object_stats_trigger.sql (1.6ms)12392026/09/07 10:04:30 goose: up to current file version: 212402026/09/07 10:04:30 INFO Received uploads request method=POST path=/api/pending_closures12412026/09/07 10:04:30 OK 20241026095416_initial_model.sql (43.6ms)12422026/09/07 10:04:30 OK 20251210153512_drop_unused_gin_index.sql (1.02ms)12432026/09/07 10:04:30 OK 20251218171726_add_pins.sql (3.05ms)12442026/09/07 10:04:30 OK 20260628120000_add_object_size_and_stats.sql (26.07ms)12452026/09/07 10:04:30 OK 20260905000000_add_claims.sql (11.87ms)12462026/09/07 10:04:30 goose: successfully migrated database to version: 2026090500000012472026/09/07 10:04:30 OK 1_commit_pending_closure.sql (2.19ms)12482026/09/07 10:04:30 OK 2_object_stats_trigger.sql (590.29µs)12492026/09/07 10:04:30 goose: up to current file version: 212502026/09/07 10:04:30 INFO Received uploads request method=POST path=/api/pending_closures12512026-09-07 10:04:30.980 UTC [78643] ERROR: relation "goose_db_version" does not exist at character 3612522026-09-07 10:04:30.980 UTC [78643] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC12532026/09/07 10:04:31 OK 20241026095416_initial_model.sql (6.96ms)12542026/09/07 10:04:31 OK 20251210153512_drop_unused_gin_index.sql (1.09ms)12552026/09/07 10:04:31 OK 20251218171726_add_pins.sql (3.88ms)12562026/09/07 10:04:31 OK 20260628120000_add_object_size_and_stats.sql (3.24ms)12572026/09/07 10:04:31 OK 20260905000000_add_claims.sql (4.41ms)12582026/09/07 10:04:31 goose: successfully migrated database to version: 2026090500000012592026/09/07 10:04:31 OK 1_commit_pending_closure.sql (3.39ms)12602026/09/07 10:04:31 OK 2_object_stats_trigger.sql (652.71µs)12612026/09/07 10:04:31 goose: up to current file version: 212622026/09/07 10:04:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12632026/09/07 10:04:31 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTU5MDNjNWQtYTgxMC00Y2ZlLTk4M2EtYmMwMDc3ZDRhNTlmLmU5ZjdkZDU5LTkzZTUtNGQzYy1iN2Q5LWRmMTE0MzBkNDdhM3gxNzg4Nzc1NDcwODg1NDQ5MDAw12642026/09/07 10:04:31 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NTU5MDNjNWQtYTgxMC00Y2ZlLTk4M2EtYmMwMDc3ZDRhNTlmLmU5ZjdkZDU5LTkzZTUtNGQzYy1iN2Q5LWRmMTE0MzBkNDdhM3gxNzg4Nzc1NDcwODg1NDQ5MDAw parts=11265--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.80s)1266=== CONT TestService_ReadAuthMiddleware12672026/09/07 10:04:31 WARN claim: cannot clear write deadline error="feature not supported"12682026/09/07 10:04:31 WARN claim: cannot clear write deadline error="feature not supported"12692026/09/07 10:04:31 WARN claim: cannot clear write deadline error="feature not supported"12702026/09/07 10:04:31 INFO Received uploads request method=POST path=/api/pending_closures12712026/09/07 10:04:31 INFO Received uploads request method=POST path=/api/pending_closures1272--- PASS: TestCacheStatsHandler (2.23s)1273=== CONT TestService_RequireScope_OIDC12742026/09/07 10:04:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61325/oidc12752026/09/07 10:04:32 INFO Received uploads request method=POST path=/api/pending_closures12762026/09/07 10:04:32 INFO Received uploads request method=POST path=/api/pending_closures12772026/09/07 10:04:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12782026/09/07 10:04:32 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NTU5MDNjNWQtYTgxMC00Y2ZlLTk4M2EtYmMwMDc3ZDRhNTlmLmEzN2U5MzBkLWUzZjUtNDBkOC1hMGFiLTJhNzEwNDA3MWJlN3gxNzg4Nzc1NDcwNjUyNDM2MDAw parts=1212792026/09/07 10:04:32 INFO Received uploads request method=POST path=/api/pending_closures1280--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.18s)1281=== CONT TestService_AuthMiddleware_OIDC12822026/09/07 10:04:32 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61331/oidc12832026-09-07 10:04:32.464 UTC [78718] ERROR: relation "goose_db_version" does not exist at character 3612842026-09-07 10:04:32.464 UTC [78718] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1285--- PASS: TestReadRedirectUsesPublicS3URL (2.34s)1286=== CONT TestReadProxyHead12872026/09/07 10:04:32 OK 20241026095416_initial_model.sql (276.4ms)12882026/09/07 10:04:32 OK 20251210153512_drop_unused_gin_index.sql (10.19ms)12892026/09/07 10:04:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12902026/09/07 10:04:32 OK 20251218171726_add_pins.sql (84.44ms)12912026/09/07 10:04:32 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001000000000000000000000.nar.zst upload_id=NTU5MDNjNWQtYTgxMC00Y2ZlLTk4M2EtYmMwMDc3ZDRhNTlmLmJjNjQwNjFjLTkyYWYtNGVjMC1iYmNkLTkzNzljMWM2ZGIwNXgxNzg4Nzc1NDcxMjA2NTg4MDAw parts=1012922026/09/07 10:04:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12932026/09/07 10:04:32 INFO Signed narinfos id=1 count=112942026/09/07 10:04:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12952026/09/07 10:04:32 INFO Received uploads request method=POST path=/api/pending_closures12962026/09/07 10:04:32 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12972026/09/07 10:04:32 INFO Signed narinfos id=2 count=112982026/09/07 10:04:32 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12992026/09/07 10:04:32 INFO Completed upload id=213002026/09/07 10:04:32 WARN claim: cannot clear write deadline error="feature not supported"1301--- PASS: TestClaim_BuildWaitComplete (3.59s)1302=== CONT TestGCTaskStore_GetEmpty1303--- PASS: TestGCTaskStore_GetEmpty (0.00s)1304=== CONT TestCacheConfigHandlerMaxNarSize1305--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1306=== CONT TestReadRedirectNar13072026/09/07 10:04:32 OK 20260628120000_add_object_size_and_stats.sql (53.88ms)13082026/09/07 10:04:33 OK 20260905000000_add_claims.sql (39.41ms)13092026/09/07 10:04:33 goose: successfully migrated database to version: 2026090500000013102026/09/07 10:04:33 OK 1_commit_pending_closure.sql (3.4ms)13112026/09/07 10:04:33 OK 2_object_stats_trigger.sql (950.71µs)13122026/09/07 10:04:33 goose: up to current file version: 21313--- PASS: TestReadProxyRangeRequest (2.54s)1314=== CONT TestReadProxyDisabled13152026/09/07 10:04:33 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13162026/09/07 10:04:33 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001100000000000000000000.nar.zst upload_id=NTU5MDNjNWQtYTgxMC00Y2ZlLTk4M2EtYmMwMDc3ZDRhNTlmLmMzZDZjZDZjLTIwOWYtNDQzYS1iYzRmLTliOGZjZjA4OWMzNngxNzg4Nzc1NDcxNDIzMDY0MDAw parts=1013172026/09/07 10:04:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13182026/09/07 10:04:33 INFO Completed upload id=113192026/09/07 10:04:33 WARN claim: cannot clear write deadline error="feature not supported"13202026/09/07 10:04:33 WARN claim: cannot clear write deadline error="feature not supported"1321--- PASS: TestClaim_GCMarkedOutputCountsAsAbsent (4.01s)1322=== CONT TestReadProxyRootRedirectsToIndexHTML1323--- PASS: TestService_ReadAuthMiddleware (2.29s)1324=== CONT TestReadProxyConditionalGet1325=== NAME TestOrphanedObjectsGCStressTest1326 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains13272026-09-07 10:04:33.570 UTC [79194] ERROR: relation "goose_db_version" does not exist at character 3613282026-09-07 10:04:33.570 UTC [79194] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1329 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion13302026/09/07 10:04:33 OK 20241026095416_initial_model.sql (17.45ms)13312026/09/07 10:04:33 OK 20251210153512_drop_unused_gin_index.sql (677.42µs)13322026/09/07 10:04:33 OK 20251218171726_add_pins.sql (1.85ms)13332026/09/07 10:04:33 OK 20260628120000_add_object_size_and_stats.sql (33.32ms)13342026/09/07 10:04:33 OK 20260905000000_add_claims.sql (9.29ms)13352026/09/07 10:04:33 goose: successfully migrated database to version: 2026090500000013362026/09/07 10:04:33 OK 1_commit_pending_closure.sql (1.79ms)13372026/09/07 10:04:33 OK 2_object_stats_trigger.sql (334.08µs)13382026/09/07 10:04:33 goose: up to current file version: 213392026-09-07 10:04:33.657 UTC [79195] ERROR: relation "goose_db_version" does not exist at character 3613402026-09-07 10:04:33.657 UTC [79195] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13412026-09-07 10:04:33.718 UTC [79198] ERROR: relation "goose_db_version" does not exist at character 3613422026-09-07 10:04:33.718 UTC [79198] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13432026/09/07 10:04:33 OK 20241026095416_initial_model.sql (68.72ms)13442026/09/07 10:04:33 OK 20251210153512_drop_unused_gin_index.sql (14.71ms)13452026/09/07 10:04:33 OK 20251218171726_add_pins.sql (24.54ms)13462026/09/07 10:04:33 OK 20260628120000_add_object_size_and_stats.sql (2.32ms)13472026/09/07 10:04:33 OK 20260905000000_add_claims.sql (32.73ms)13482026/09/07 10:04:33 goose: successfully migrated database to version: 2026090500000013492026/09/07 10:04:33 OK 1_commit_pending_closure.sql (9.59ms)13502026/09/07 10:04:33 OK 2_object_stats_trigger.sql (645.54µs)13512026/09/07 10:04:33 goose: up to current file version: 213522026/09/07 10:04:33 OK 20241026095416_initial_model.sql (101.59ms)13532026/09/07 10:04:33 OK 20251210153512_drop_unused_gin_index.sql (14.66ms)13542026/09/07 10:04:33 OK 20251218171726_add_pins.sql (16.73ms)13552026-09-07 10:04:33.923 UTC [79208] ERROR: relation "goose_db_version" does not exist at character 3613562026-09-07 10:04:33.923 UTC [79208] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13572026/09/07 10:04:33 OK 20260628120000_add_object_size_and_stats.sql (21.41ms)1358=== RUN TestService_RequireScope_OIDC/builder_may_write1359=== PAUSE TestService_RequireScope_OIDC/builder_may_write1360=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1361=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1362=== RUN TestService_RequireScope_OIDC/ops_may_admin1363=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1364=== RUN TestService_RequireScope_OIDC/ops_may_not_write1365=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1366=== RUN TestService_RequireScope_OIDC/reader_may_not_write1367=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1368=== RUN TestService_RequireScope_OIDC/static_token_may_admin1369=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1370=== RUN TestService_RequireScope_OIDC/static_token_may_write1371=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1372=== RUN TestService_RequireScope_OIDC/reader_may_read1373=== PAUSE TestService_RequireScope_OIDC/reader_may_read1374=== RUN TestService_RequireScope_OIDC/writer_implies_read1375=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1376=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1377=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1378=== CONT TestGCTaskStore_Fail1379--- PASS: TestGCTaskStore_Fail (0.00s)1380=== CONT TestGenerateLandingPage13812026/09/07 10:04:33 OK 20260905000000_add_claims.sql (13.47ms)13822026/09/07 10:04:33 goose: successfully migrated database to version: 2026090500000013832026/09/07 10:04:33 OK 1_commit_pending_closure.sql (1.33ms)13842026/09/07 10:04:33 OK 2_object_stats_trigger.sql (554.5µs)13852026/09/07 10:04:33 goose: up to current file version: 21386--- PASS: TestGenerateLandingPage (0.01s)1387=== CONT TestGCTaskStore_PhaseUpdates1388--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1389=== CONT TestService_readinessHandler13902026-09-07 10:04:33.955 UTC [79213] ERROR: relation "goose_db_version" does not exist at character 3613912026-09-07 10:04:33.955 UTC [79213] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13922026-09-07 10:04:33.990 UTC [79217] ERROR: relation "goose_db_version" does not exist at character 3613932026-09-07 10:04:33.990 UTC [79217] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC13942026/09/07 10:04:33 OK 20241026095416_initial_model.sql (36.15ms)13952026/09/07 10:04:34 OK 20251210153512_drop_unused_gin_index.sql (16.49ms)13962026/09/07 10:04:34 OK 20251218171726_add_pins.sql (29.97ms)13972026/09/07 10:04:34 OK 20260628120000_add_object_size_and_stats.sql (29.52ms)13982026/09/07 10:04:34 OK 20241026095416_initial_model.sql (93.78ms)13992026/09/07 10:04:34 OK 20251210153512_drop_unused_gin_index.sql (8.61ms)14002026/09/07 10:04:34 OK 20260905000000_add_claims.sql (22.92ms)14012026/09/07 10:04:34 goose: successfully migrated database to version: 2026090500000014022026/09/07 10:04:34 OK 20251218171726_add_pins.sql (6.67ms)14032026/09/07 10:04:34 OK 1_commit_pending_closure.sql (2.23ms)14042026/09/07 10:04:34 OK 20241026095416_initial_model.sql (69.88ms)14052026/09/07 10:04:34 OK 2_object_stats_trigger.sql (644.96µs)14062026/09/07 10:04:34 goose: up to current file version: 214072026/09/07 10:04:34 OK 20260628120000_add_object_size_and_stats.sql (3.49ms)14082026/09/07 10:04:34 OK 20251210153512_drop_unused_gin_index.sql (849.63µs)14092026/09/07 10:04:34 OK 20251218171726_add_pins.sql (2.09ms)14102026/09/07 10:04:34 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14112026/09/07 10:04:34 OK 20260905000000_add_claims.sql (2.94ms)14122026/09/07 10:04:34 goose: successfully migrated database to version: 2026090500000014132026-09-07 10:04:34.105 UTC [79225] ERROR: relation "goose_db_version" does not exist at character 3614142026-09-07 10:04:34.105 UTC [79225] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14152026/09/07 10:04:34 OK 1_commit_pending_closure.sql (2.9ms)14162026/09/07 10:04:34 OK 2_object_stats_trigger.sql (513.92µs)14172026/09/07 10:04:34 goose: up to current file version: 214182026/09/07 10:04:34 OK 20260628120000_add_object_size_and_stats.sql (38.57ms)14192026/09/07 10:04:34 OK 20260905000000_add_claims.sql (33.5ms)14202026/09/07 10:04:34 goose: successfully migrated database to version: 2026090500000014212026/09/07 10:04:34 OK 1_commit_pending_closure.sql (2.65ms)14222026/09/07 10:04:34 OK 2_object_stats_trigger.sql (586.46µs)14232026/09/07 10:04:34 goose: up to current file version: 214242026/09/07 10:04:34 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NTU5MDNjNWQtYTgxMC00Y2ZlLTk4M2EtYmMwMDc3ZDRhNTlmLjU5NGRiNDg4LTc2NzAtNDM2Ny05MGI2LWRmMWFiZGFhNWFkZHgxNzg4Nzc1NDcyMTY5MjM4MDAw parts=121425--- PASS: TestRedundantMultipartUpload (4.19s)1426=== CONT TestService_healthCheckHandler1427=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1428=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1429=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1430=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1431=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1432=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1433=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1434=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1435=== CONT TestGracefulShutdownDrainsInflight14362026/09/07 10:04:34 INFO Starting HTTP server address=127.0.0.1:6134914372026/09/07 10:04:34 INFO Shutdown signal received, draining in-flight requests timeout=10s14382026/09/07 10:04:34 OK 20241026095416_initial_model.sql (42.82ms)14392026/09/07 10:04:34 OK 20251210153512_drop_unused_gin_index.sql (7.98ms)14402026/09/07 10:04:34 OK 20251218171726_add_pins.sql (6.67ms)14412026/09/07 10:04:34 OK 20260628120000_add_object_size_and_stats.sql (9.12ms)14422026/09/07 10:04:34 OK 20260905000000_add_claims.sql (10.06ms)14432026/09/07 10:04:34 goose: successfully migrated database to version: 2026090500000014442026/09/07 10:04:34 OK 1_commit_pending_closure.sql (3.48ms)14452026/09/07 10:04:34 OK 2_object_stats_trigger.sql (321.25µs)14462026/09/07 10:04:34 goose: up to current file version: 21447--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1448=== CONT TestReadProxy4041449--- PASS: TestReadProxyHead (1.78s)1450=== CONT TestReadProxyInvalidPath14512026/09/07 10:04:34 WARN Rate limiter enabled after throttle name=s3-test rate=514522026/09/07 10:04:34 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1453=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1454 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101455 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001456--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.08s)1457=== CONT TestGCTaskStore_CompletedAllowsNewTask1458--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1459=== CONT TestGCBugBareHashReferences1460--- PASS: TestReadRedirectNar (1.57s)1461=== CONT TestGCTaskStore_ConflictDifferentParams1462--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1463=== CONT TestGCTaskStore_DeduplicateSameParams1464--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1465=== CONT TestGCTaskStore_StartNew1466--- PASS: TestGCTaskStore_StartNew (0.00s)1467=== CONT TestGCMetrics14682026-09-07 10:04:34.534 UTC [79249] ERROR: relation "goose_db_version" does not exist at character 3614692026-09-07 10:04:34.534 UTC [79249] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14702026/09/07 10:04:34 OK 20241026095416_initial_model.sql (56.95ms)14712026/09/07 10:04:34 OK 20251210153512_drop_unused_gin_index.sql (2.38ms)14722026/09/07 10:04:34 OK 20251218171726_add_pins.sql (15.59ms)14732026/09/07 10:04:34 OK 20260628120000_add_object_size_and_stats.sql (28.79ms)14742026/09/07 10:04:34 OK 20260905000000_add_claims.sql (36.12ms)14752026/09/07 10:04:34 goose: successfully migrated database to version: 2026090500000014762026/09/07 10:04:34 OK 1_commit_pending_closure.sql (9.79ms)1477--- PASS: TestReadProxyDisabled (1.69s)1478=== CONT TestReadProxyNarStreaming14792026/09/07 10:04:34 OK 2_object_stats_trigger.sql (1.29ms)14802026/09/07 10:04:34 goose: up to current file version: 214812026-09-07 10:04:34.742 UTC [79255] ERROR: relation "goose_db_version" does not exist at character 3614822026-09-07 10:04:34.742 UTC [79255] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14832026/09/07 10:04:34 OK 20241026095416_initial_model.sql (57.13ms)14842026/09/07 10:04:34 OK 20251210153512_drop_unused_gin_index.sql (7.02ms)14852026/09/07 10:04:34 OK 20251218171726_add_pins.sql (15.25ms)14862026/09/07 10:04:34 OK 20260628120000_add_object_size_and_stats.sql (22.08ms)14872026/09/07 10:04:34 OK 20260905000000_add_claims.sql (25.68ms)14882026/09/07 10:04:34 goose: successfully migrated database to version: 2026090500000014892026/09/07 10:04:34 OK 1_commit_pending_closure.sql (3.72ms)14902026/09/07 10:04:34 OK 2_object_stats_trigger.sql (667.83µs)14912026/09/07 10:04:34 goose: up to current file version: 21492--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.60s)1493=== CONT TestGCTaskStore_GetReturnsLatest1494--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1495=== CONT TestPinProtectsFromGC14962026-09-07 10:04:34.976 UTC [79264] ERROR: relation "goose_db_version" does not exist at character 3614972026-09-07 10:04:34.976 UTC [79264] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC14982026/09/07 10:04:35 OK 20241026095416_initial_model.sql (43.52ms)14992026/09/07 10:04:35 OK 20251210153512_drop_unused_gin_index.sql (2.34ms)15002026/09/07 10:04:35 OK 20251218171726_add_pins.sql (9.03ms)15012026-09-07 10:04:35.068 UTC [79267] ERROR: relation "goose_db_version" does not exist at character 3615022026-09-07 10:04:35.068 UTC [79267] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15032026/09/07 10:04:35 OK 20260628120000_add_object_size_and_stats.sql (37.33ms)15042026/09/07 10:04:35 OK 20260905000000_add_claims.sql (24.06ms)15052026/09/07 10:04:35 goose: successfully migrated database to version: 2026090500000015062026/09/07 10:04:35 OK 1_commit_pending_closure.sql (2.28ms)15072026/09/07 10:04:35 OK 2_object_stats_trigger.sql (693.08µs)15082026/09/07 10:04:35 goose: up to current file version: 21509--- PASS: TestReadProxyConditionalGet (1.73s)1510=== CONT TestResolveDBConnectionString1511=== RUN TestResolveDBConnectionString/flag_wins1512=== PAUSE TestResolveDBConnectionString/flag_wins1513=== RUN TestResolveDBConnectionString/file_when_flag_empty1514=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1515=== RUN TestResolveDBConnectionString/missing_file_is_an_error1516=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1517=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1518=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1519=== RUN TestResolveDBConnectionString/nothing_configured1520=== PAUSE TestResolveDBConnectionString/nothing_configured1521=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15222026/09/07 10:04:35 OK 20241026095416_initial_model.sql (67.09ms)15232026/09/07 10:04:35 OK 20251210153512_drop_unused_gin_index.sql (12.18ms)15242026/09/07 10:04:35 OK 20251218171726_add_pins.sql (32.84ms)15252026/09/07 10:04:35 OK 20260628120000_add_object_size_and_stats.sql (15.91ms)15262026/09/07 10:04:35 OK 20260905000000_add_claims.sql (28.61ms)15272026/09/07 10:04:35 goose: successfully migrated database to version: 2026090500000015282026/09/07 10:04:35 OK 1_commit_pending_closure.sql (12.21ms)15292026/09/07 10:04:35 OK 2_object_stats_trigger.sql (493.92µs)15302026/09/07 10:04:35 goose: up to current file version: 215312026/09/07 10:04:35 WARN readiness check failed error="closed pool"1532--- PASS: TestService_readinessHandler (1.44s)1533=== CONT TestService_AuthMiddleware_MTLSProxyHeader15342026-09-07 10:04:35.530 UTC [79280] ERROR: relation "goose_db_version" does not exist at character 3615352026-09-07 10:04:35.530 UTC [79280] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15362026-09-07 10:04:35.556 UTC [79282] ERROR: relation "goose_db_version" does not exist at character 3615372026-09-07 10:04:35.556 UTC [79282] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1538--- PASS: TestService_healthCheckHandler (1.46s)1539=== CONT TestReadProxyNarinfoAlreadyDecompressed15402026/09/07 10:04:35 OK 20241026095416_initial_model.sql (126.33ms)15412026/09/07 10:04:35 OK 20241026095416_initial_model.sql (142.4ms)15422026/09/07 10:04:35 OK 20251210153512_drop_unused_gin_index.sql (7.5ms)15432026/09/07 10:04:35 OK 20251210153512_drop_unused_gin_index.sql (9.07ms)15442026/09/07 10:04:35 OK 20251218171726_add_pins.sql (11.49ms)15452026/09/07 10:04:35 OK 20251218171726_add_pins.sql (10ms)15462026/09/07 10:04:35 OK 20260628120000_add_object_size_and_stats.sql (17.43ms)15472026/09/07 10:04:35 OK 20260628120000_add_object_size_and_stats.sql (26.26ms)15482026/09/07 10:04:35 OK 20260905000000_add_claims.sql (39.92ms)15492026/09/07 10:04:35 goose: successfully migrated database to version: 2026090500000015502026/09/07 10:04:35 OK 20260905000000_add_claims.sql (49.4ms)15512026/09/07 10:04:35 goose: successfully migrated database to version: 2026090500000015522026/09/07 10:04:35 OK 1_commit_pending_closure.sql (2.05ms)15532026/09/07 10:04:35 OK 1_commit_pending_closure.sql (1.86ms)15542026/09/07 10:04:35 OK 2_object_stats_trigger.sql (598.88µs)15552026/09/07 10:04:35 goose: up to current file version: 215562026/09/07 10:04:35 OK 2_object_stats_trigger.sql (525.92µs)15572026/09/07 10:04:35 goose: up to current file version: 215582026-09-07 10:04:35.844 UTC [79287] ERROR: relation "goose_db_version" does not exist at character 3615592026-09-07 10:04:35.844 UTC [79287] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC1560--- PASS: TestReadProxy404 (1.65s)1561=== CONT TestClaim_TwoInstances15622026/09/07 10:04:35 OK 20241026095416_initial_model.sql (54.61ms)15632026/09/07 10:04:35 OK 20251210153512_drop_unused_gin_index.sql (13.75ms)15642026-09-07 10:04:35.990 UTC [79295] ERROR: relation "goose_db_version" does not exist at character 3615652026-09-07 10:04:35.990 UTC [79295] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC15662026/09/07 10:04:36 OK 20251218171726_add_pins.sql (45.47ms)1567=== NAME TestOrphanedObjectsGCStressTest1568 orphaned_objects_gc_test.go:509: Stress test completed successfully:1569 orphaned_objects_gc_test.go:510: - Active objects preserved: 201570 orphaned_objects_gc_test.go:511: - Objects deleted: 2101571 orphaned_objects_gc_test.go:512: - Total GC'd: 2101572--- PASS: TestOrphanedObjectsGCStressTest (9.60s)1573=== CONT TestClientErrorHandling1574=== RUN TestClientErrorHandling/InvalidStorePath1575=== PAUSE TestClientErrorHandling/InvalidStorePath1576=== RUN TestClientErrorHandling/InvalidAuthToken1577=== PAUSE TestClientErrorHandling/InvalidAuthToken1578=== RUN TestClientErrorHandling/ServerNotAvailable1579=== PAUSE TestClientErrorHandling/ServerNotAvailable1580=== CONT TestClientWithDependencies15812026/09/07 10:04:36 OK 20260628120000_add_object_size_and_stats.sql (41.73ms)15822026/09/07 10:04:36 OK 20260905000000_add_claims.sql (59.52ms)15832026/09/07 10:04:36 goose: successfully migrated database to version: 2026090500000015842026/09/07 10:04:36 OK 1_commit_pending_closure.sql (8.36ms)15852026/09/07 10:04:36 OK 2_object_stats_trigger.sql (615.25µs)15862026/09/07 10:04:36 goose: up to current file version: 21587--- PASS: TestReadProxyInvalidPath (1.84s)1588=== CONT TestClientMultipleUploads15892026/09/07 10:04:36 OK 20241026095416_initial_model.sql (171.53ms)15902026/09/07 10:04:36 OK 20251210153512_drop_unused_gin_index.sql (11.21ms)15912026/09/07 10:04:36 OK 20251218171726_add_pins.sql (29.23ms)15922026/09/07 10:04:36 OK 20260628120000_add_object_size_and_stats.sql (27.27ms)15932026/09/07 10:04:36 OK 20260905000000_add_claims.sql (59.13ms)15942026/09/07 10:04:36 goose: successfully migrated database to version: 2026090500000015952026/09/07 10:04:36 OK 1_commit_pending_closure.sql (2.85ms)15962026/09/07 10:04:36 OK 2_object_stats_trigger.sql (629.71µs)15972026/09/07 10:04:36 goose: up to current file version: 215982026/09/07 10:04:36 INFO Aborted multipart uploads count=015992026/09/07 10:04:36 WARN Force mode enabled - objects will be deleted immediately without grace period16002026/09/07 10:04:36 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016012026/09/07 10:04:36 INFO Vacuumed table table=pending_closures16022026/09/07 10:04:36 INFO Vacuumed table table=pending_objects16032026/09/07 10:04:36 INFO Vacuumed table table=multipart_uploads16042026/09/07 10:04:36 INFO Vacuumed table table=closures16052026/09/07 10:04:36 INFO Vacuumed table table=objects1606--- PASS: TestGCMetrics (1.92s)1607=== CONT TestClaim_StreamsThroughServer16082026-09-07 10:04:36.709 UTC [79314] ERROR: relation "goose_db_version" does not exist at character 3616092026-09-07 10:04:36.709 UTC [79314] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16102026/09/07 10:04:36 OK 20241026095416_initial_model.sql (100.67ms)16112026-09-07 10:04:36.861 UTC [79318] ERROR: relation "goose_db_version" does not exist at character 3616122026-09-07 10:04:36.861 UTC [79318] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16132026/09/07 10:04:36 OK 20251210153512_drop_unused_gin_index.sql (2.69ms)16142026/09/07 10:04:36 OK 20251218171726_add_pins.sql (26.03ms)16152026/09/07 10:04:36 OK 20260628120000_add_object_size_and_stats.sql (17.38ms)1616--- PASS: TestReadProxyNarStreaming (2.21s)1617=== CONT TestClientCADerivations16182026-09-07 10:04:36.911 UTC [79320] ERROR: relation "goose_db_version" does not exist at character 3616192026-09-07 10:04:36.911 UTC [79320] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16202026/09/07 10:04:36 OK 20260905000000_add_claims.sql (5.39ms)16212026/09/07 10:04:36 goose: successfully migrated database to version: 202609050000001622--- PASS: TestGCBugBareHashReferences (2.41s)1623=== CONT TestClaim_InputsTouched16242026/09/07 10:04:36 OK 1_commit_pending_closure.sql (21.46ms)16252026/09/07 10:04:36 OK 2_object_stats_trigger.sql (584.75µs)16262026/09/07 10:04:36 goose: up to current file version: 216272026/09/07 10:04:36 OK 20241026095416_initial_model.sql (64.84ms)16282026/09/07 10:04:36 OK 20251210153512_drop_unused_gin_index.sql (2.13ms)16292026/09/07 10:04:36 OK 20251218171726_add_pins.sql (3.86ms)16302026/09/07 10:04:36 OK 20260628120000_add_object_size_and_stats.sql (27.12ms)16312026/09/07 10:04:37 OK 20260905000000_add_claims.sql (20.45ms)16322026/09/07 10:04:37 goose: successfully migrated database to version: 2026090500000016332026/09/07 10:04:37 OK 1_commit_pending_closure.sql (3.21ms)16342026/09/07 10:04:37 OK 2_object_stats_trigger.sql (339.79µs)16352026/09/07 10:04:37 goose: up to current file version: 216362026/09/07 10:04:37 OK 20241026095416_initial_model.sql (60.61ms)16372026/09/07 10:04:37 OK 20251210153512_drop_unused_gin_index.sql (1.62ms)16382026/09/07 10:04:37 OK 20251218171726_add_pins.sql (9.72ms)16392026/09/07 10:04:37 OK 20260628120000_add_object_size_and_stats.sql (16.14ms)16402026/09/07 10:04:37 OK 20260905000000_add_claims.sql (3.44ms)16412026/09/07 10:04:37 goose: successfully migrated database to version: 2026090500000016422026/09/07 10:04:37 OK 1_commit_pending_closure.sql (3.03ms)16432026/09/07 10:04:37 OK 2_object_stats_trigger.sql (610.13µs)16442026/09/07 10:04:37 goose: up to current file version: 216452026-09-07 10:04:37.153 UTC [79328] ERROR: relation "goose_db_version" does not exist at character 3616462026-09-07 10:04:37.153 UTC [79328] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16472026-09-07 10:04:37.183 UTC [79332] ERROR: relation "goose_db_version" does not exist at character 3616482026-09-07 10:04:37.183 UTC [79332] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16492026/09/07 10:04:37 OK 20241026095416_initial_model.sql (41.72ms)16502026/09/07 10:04:37 OK 20251210153512_drop_unused_gin_index.sql (1.78ms)16512026/09/07 10:04:37 OK 20251218171726_add_pins.sql (14.18ms)16522026/09/07 10:04:37 OK 20260628120000_add_object_size_and_stats.sql (15.33ms)16532026/09/07 10:04:37 OK 20241026095416_initial_model.sql (61.26ms)16542026/09/07 10:04:37 OK 20251210153512_drop_unused_gin_index.sql (8.08ms)16552026/09/07 10:04:37 OK 20260905000000_add_claims.sql (26.07ms)16562026/09/07 10:04:37 goose: successfully migrated database to version: 2026090500000016572026/09/07 10:04:37 OK 20251218171726_add_pins.sql (10.29ms)16582026/09/07 10:04:37 OK 1_commit_pending_closure.sql (7.69ms)16592026/09/07 10:04:37 OK 2_object_stats_trigger.sql (570.46µs)16602026/09/07 10:04:37 goose: up to current file version: 216612026/09/07 10:04:37 OK 20260628120000_add_object_size_and_stats.sql (26.5ms)16622026/09/07 10:04:37 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16632026/09/07 10:04:37 WARN mTLS auth: bound subjects configured but subject DN unavailable16642026/09/07 10:04:37 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1665--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.18s)1666=== CONT TestClaim_FailWithoutKindReleases16672026/09/07 10:04:37 OK 20260905000000_add_claims.sql (9.16ms)16682026/09/07 10:04:37 goose: successfully migrated database to version: 2026090500000016692026/09/07 10:04:37 OK 1_commit_pending_closure.sql (1.47ms)16702026/09/07 10:04:37 OK 2_object_stats_trigger.sql (293.54µs)16712026/09/07 10:04:37 goose: up to current file version: 216722026-09-07 10:04:37.334 UTC [79338] ERROR: relation "goose_db_version" does not exist at character 3616732026-09-07 10:04:37.334 UTC [79338] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16742026-09-07 10:04:37.393 UTC [79341] ERROR: relation "goose_db_version" does not exist at character 3616752026-09-07 10:04:37.393 UTC [79341] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC16762026/09/07 10:04:37 OK 20241026095416_initial_model.sql (89.52ms)1677=== NAME TestPinProtectsFromGC1678 client_integration_test.go:648: Pinned store path: /nix/var/nix/builds/nix-76543-4286199278/TestPinProtectsFromGC402682251/001/store/9lg57xmc2r5yzg0j5gx1kn9xkvk1nghm-pinned-file.txt1679 client_integration_test.go:649: Unpinned store path: /nix/var/nix/builds/nix-76543-4286199278/TestPinProtectsFromGC402682251/001/store/f1fqsg2f078i380w8wlnp6sn1vgbad0k-unpinned-file.txt16802026/09/07 10:04:37 OK 20251210153512_drop_unused_gin_index.sql (10.7ms)1681--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.08s)1682=== CONT TestClaim_StaleHeartbeatStolen16832026/09/07 10:04:37 OK 20251218171726_add_pins.sql (2.33ms)16842026/09/07 10:04:37 OK 20260628120000_add_object_size_and_stats.sql (14.32ms)16852026/09/07 10:04:37 OK 20260905000000_add_claims.sql (15.17ms)16862026/09/07 10:04:37 goose: successfully migrated database to version: 2026090500000016872026/09/07 10:04:37 OK 1_commit_pending_closure.sql (1.73ms)16882026/09/07 10:04:37 OK 2_object_stats_trigger.sql (260.67µs)16892026/09/07 10:04:37 goose: up to current file version: 216902026/09/07 10:04:37 OK 20241026095416_initial_model.sql (37.94ms)16912026/09/07 10:04:37 OK 20251210153512_drop_unused_gin_index.sql (5.82ms)16922026/09/07 10:04:37 OK 20251218171726_add_pins.sql (12.92ms)16932026/09/07 10:04:37 OK 20260628120000_add_object_size_and_stats.sql (20.41ms)16942026/09/07 10:04:37 OK 20260905000000_add_claims.sql (34.84ms)16952026/09/07 10:04:37 goose: successfully migrated database to version: 2026090500000016962026/09/07 10:04:37 OK 1_commit_pending_closure.sql (1.4ms)16972026/09/07 10:04:37 OK 2_object_stats_trigger.sql (275.75µs)16982026/09/07 10:04:37 goose: up to current file version: 216992026/09/07 10:04:37 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1700--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.97s)1701=== CONT TestClaim_FailWakesWaitersButIsNotRemembered17022026-09-07 10:04:37.639 UTC [79353] ERROR: relation "goose_db_version" does not exist at character 3617032026-09-07 10:04:37.639 UTC [79353] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17042026-09-07 10:04:37.639 UTC [79354] ERROR: relation "goose_db_version" does not exist at character 3617052026-09-07 10:04:37.639 UTC [79354] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17062026/09/07 10:04:37 INFO Received uploads request method=POST path=/api/pending_closures17072026/09/07 10:04:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17082026/09/07 10:04:37 INFO Uploading 9lg57xmc2r5yzg0j5gx1kn9xkvk1nghm-pinned-file.txt (128B)17092026/09/07 10:04:37 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17102026/09/07 10:04:37 WARN Failed to register uploaded object key=9lg57xmc2r5yzg0j5gx1kn9xkvk1nghm.ls error="server returned 404: 404 page not found\n"17112026/09/07 10:04:37 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17122026/09/07 10:04:37 INFO Signed narinfos id=1 count=117132026/09/07 10:04:37 INFO Uploading 1 narinfos17142026/09/07 10:04:37 OK 20241026095416_initial_model.sql (72.69ms)17152026/09/07 10:04:37 WARN claim: cannot clear write deadline error="feature not supported"17162026/09/07 10:04:37 WARN Failed to register uploaded object key=9lg57xmc2r5yzg0j5gx1kn9xkvk1nghm.narinfo error="server returned 404: 404 page not found\n"17172026/09/07 10:04:37 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17182026/09/07 10:04:37 OK 20251210153512_drop_unused_gin_index.sql (984.5µs)17192026/09/07 10:04:37 OK 20241026095416_initial_model.sql (70.03ms)17202026/09/07 10:04:37 OK 20251218171726_add_pins.sql (2.71ms)17212026/09/07 10:04:37 INFO Completed upload id=117222026/09/07 10:04:37 OK 20251210153512_drop_unused_gin_index.sql (7.56ms)17232026/09/07 10:04:37 INFO Upload complete. (237ms)17242026/09/07 10:04:37 WARN claim: cannot clear write deadline error="feature not supported"17252026/09/07 10:04:37 WARN claim: cannot clear write deadline error="feature not supported"17262026/09/07 10:04:37 INFO Received uploads request method=POST path=/api/pending_closures17272026/09/07 10:04:37 OK 20251218171726_add_pins.sql (13.08ms)17282026/09/07 10:04:37 OK 20260628120000_add_object_size_and_stats.sql (26.5ms)17292026/09/07 10:04:37 OK 20260628120000_add_object_size_and_stats.sql (13.2ms)17302026/09/07 10:04:37 OK 20260905000000_add_claims.sql (19.66ms)17312026/09/07 10:04:37 goose: successfully migrated database to version: 2026090500000017322026/09/07 10:04:37 OK 1_commit_pending_closure.sql (5.25ms)17332026/09/07 10:04:37 OK 2_object_stats_trigger.sql (462.17µs)17342026/09/07 10:04:37 goose: up to current file version: 217352026/09/07 10:04:37 OK 20260905000000_add_claims.sql (26.06ms)17362026/09/07 10:04:37 goose: successfully migrated database to version: 2026090500000017372026/09/07 10:04:37 OK 1_commit_pending_closure.sql (7.41ms)17382026/09/07 10:04:37 OK 2_object_stats_trigger.sql (680.75µs)17392026/09/07 10:04:37 goose: up to current file version: 217402026/09/07 10:04:37 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"17412026/09/07 10:04:37 INFO Received uploads request method=POST path=/api/pending_closures17422026/09/07 10:04:37 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17432026/09/07 10:04:37 INFO Uploading f1fqsg2f078i380w8wlnp6sn1vgbad0k-unpinned-file.txt (128B)17442026/09/07 10:04:38 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17452026/09/07 10:04:38 WARN Failed to register uploaded object key=f1fqsg2f078i380w8wlnp6sn1vgbad0k.ls error="server returned 404: 404 page not found\n"17462026/09/07 10:04:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17472026/09/07 10:04:38 INFO Signed narinfos id=2 count=117482026/09/07 10:04:38 INFO Uploading 1 narinfos17492026/09/07 10:04:38 WARN Failed to register uploaded object key=f1fqsg2f078i380w8wlnp6sn1vgbad0k.narinfo error="server returned 404: 404 page not found\n"17502026/09/07 10:04:38 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete17512026/09/07 10:04:38 INFO Completed upload id=217522026/09/07 10:04:38 INFO Upload complete. (255ms)17532026/09/07 10:04:38 INFO Received create pin request method=POST path=/api/pins/myapp17542026/09/07 10:04:38 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-76543-4286199278/TestPinProtectsFromGC402682251/001/store/9lg57xmc2r5yzg0j5gx1kn9xkvk1nghm-pinned-file.txt narinfo_key=9lg57xmc2r5yzg0j5gx1kn9xkvk1nghm.narinfo17552026/09/07 10:04:38 INFO Starting cleanup of old closures method=DELETE path=/api/closures17562026/09/07 10:04:38 INFO Garbage collection started17572026/09/07 10:04:38 INFO Aborted multipart uploads count=017582026/09/07 10:04:38 WARN Force mode enabled - objects will be deleted immediately without grace period17592026-09-07 10:04:38.155 UTC [79373] ERROR: relation "goose_db_version" does not exist at character 3617602026-09-07 10:04:38.155 UTC [79373] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17612026/09/07 10:04:38 OK 20241026095416_initial_model.sql (85.15ms)17622026/09/07 10:04:38 OK 20251210153512_drop_unused_gin_index.sql (20.06ms)17632026/09/07 10:04:38 OK 20251218171726_add_pins.sql (4.63ms)17642026/09/07 10:04:38 OK 20260628120000_add_object_size_and_stats.sql (25.05ms)1765=== NAME TestClientMultipleUploads1766 client_integration_test.go:339: Created store path 0: /nix/var/nix/builds/nix-76543-4286199278/TestClientMultipleUploads3544768745/001/store/wf7im8yz6idhjp5kv064jwxc9gyhnlqd-test-file-0.txt17672026/09/07 10:04:38 OK 20260905000000_add_claims.sql (14.44ms)17682026/09/07 10:04:38 goose: successfully migrated database to version: 2026090500000017692026/09/07 10:04:38 OK 1_commit_pending_closure.sql (6.82ms)17702026/09/07 10:04:38 OK 2_object_stats_trigger.sql (1.04ms)17712026/09/07 10:04:38 goose: up to current file version: 217722026-09-07 10:04:38.332 UTC [79377] ERROR: relation "goose_db_version" does not exist at character 3617732026-09-07 10:04:38.332 UTC [79377] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17742026/09/07 10:04:38 OK 20241026095416_initial_model.sql (62.02ms)17752026/09/07 10:04:38 OK 20251210153512_drop_unused_gin_index.sql (11.98ms)17762026-09-07 10:04:38.444 UTC [79379] ERROR: relation "goose_db_version" does not exist at character 3617772026-09-07 10:04:38.444 UTC [79379] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC17782026/09/07 10:04:38 OK 20251218171726_add_pins.sql (16.82ms)17792026/09/07 10:04:38 OK 20260628120000_add_object_size_and_stats.sql (14.39ms)17802026/09/07 10:04:38 OK 20260905000000_add_claims.sql (14.45ms)17812026/09/07 10:04:38 goose: successfully migrated database to version: 2026090500000017822026/09/07 10:04:38 OK 1_commit_pending_closure.sql (5.6ms)17832026/09/07 10:04:38 OK 2_object_stats_trigger.sql (625.54µs)17842026/09/07 10:04:38 goose: up to current file version: 21785 client_integration_test.go:339: Created store path 1: /nix/var/nix/builds/nix-76543-4286199278/TestClientMultipleUploads3544768745/001/store/ak8p2snqvrg5k02bbhqmf1ni42xly3g2-test-file-1.txt17862026/09/07 10:04:38 OK 20241026095416_initial_model.sql (76.42ms)17872026/09/07 10:04:38 OK 20251210153512_drop_unused_gin_index.sql (10.84ms)17882026/09/07 10:04:38 OK 20251218171726_add_pins.sql (16.66ms)17892026/09/07 10:04:38 OK 20260628120000_add_object_size_and_stats.sql (12.36ms)17902026/09/07 10:04:38 OK 20260905000000_add_claims.sql (3.91ms)17912026/09/07 10:04:38 goose: successfully migrated database to version: 2026090500000017922026/09/07 10:04:38 OK 1_commit_pending_closure.sql (2.24ms)17932026/09/07 10:04:38 OK 2_object_stats_trigger.sql (619.17µs)17942026/09/07 10:04:38 goose: up to current file version: 217952026/09/07 10:04:38 INFO Received uploads request method=POST path=/api/pending_closures1796 client_integration_test.go:339: Created store path 2: /nix/var/nix/builds/nix-76543-4286199278/TestClientMultipleUploads3544768745/001/store/2l8ywp6jdvflwfhw6rinmj12aa0291z1-test-file-2.txt17972026/09/07 10:04:38 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=2001 objects-failed-to-delete=017982026/09/07 10:04:38 INFO Vacuumed table table=pending_closures17992026/09/07 10:04:38 INFO Vacuumed table table=pending_objects18002026/09/07 10:04:38 INFO Vacuumed table table=multipart_uploads18012026/09/07 10:04:38 INFO Vacuumed table table=closures18022026/09/07 10:04:38 INFO Vacuumed table table=objects18032026/09/07 10:04:38 INFO Received complete multipart upload request method=POST path=/api/multipart/complete18042026/09/07 10:04:38 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001600000000000000000000.nar.zst upload_id=NTU5MDNjNWQtYTgxMC00Y2ZlLTk4M2EtYmMwMDc3ZDRhNTlmLmJjMTU5ZjdiLWU5NzUtNDY0Zi04YWY3LTA2MDcxOTc2MmQzYngxNzg4Nzc1NDc3NzY0MzUyMDAw parts=1018052026/09/07 10:04:38 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18062026/09/07 10:04:38 INFO Signed narinfos id=1 count=118072026/09/07 10:04:38 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18082026/09/07 10:04:38 INFO Completed upload id=11809--- PASS: TestClaim_TwoInstances (2.94s)1810=== CONT TestClaim_HolderDisconnectKeepsClaim1811--- PASS: TestClaim_StreamsThroughServer (2.50s)1812=== CONT TestReadProxyNarinfo18132026/09/07 10:04:38 WARN claim: cannot clear write deadline error="feature not supported"18142026/09/07 10:04:38 WARN claim: cannot clear write deadline error="feature not supported"1815--- PASS: TestClaim_FailWithoutKindReleases (1.68s)1816=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18172026/09/07 10:04:38 INFO Received uploads request method=POST path=/18182026/09/07 10:04:39 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"1819=== NAME TestClientWithDependencies1820 client_integration_test.go:594: Built derivation: /nix/var/nix/builds/nix-76543-4286199278/TestClientWithDependencies2700331408/001/store/p1jyky6vzmp3mfry645nq4467r6azfrw-test-script18212026/09/07 10:04:39 WARN claim: cannot clear write deadline error="feature not supported"18222026/09/07 10:04:39 WARN claim: cannot clear write deadline error="feature not supported"1823--- PASS: TestClaim_StaleHeartbeatStolen (1.73s)1824=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18252026/09/07 10:04:39 INFO Received request for more parts method=POST path=/1826=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18272026/09/07 10:04:39 INFO Received complete multipart upload request method=POST path=/18282026/09/07 10:04:39 INFO Received uploads request method=POST path=/api/pending_closures1829=== NAME TestClientWithDependencies1830 client_integration_test.go:596: Found 1 dependencies (including self)18312026/09/07 10:04:39 INFO Received uploads request method=POST path=/api/pending_closures18322026/09/07 10:04:39 INFO Received uploads request method=POST path=/api/pending_closures18332026/09/07 10:04:39 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18342026/09/07 10:04:39 INFO Uploading wf7im8yz6idhjp5kv064jwxc9gyhnlqd-test-file-0.txt (160B)18352026/09/07 10:04:39 INFO Uploading 2l8ywp6jdvflwfhw6rinmj12aa0291z1-test-file-2.txt (160B)18362026/09/07 10:04:39 INFO Uploading ak8p2snqvrg5k02bbhqmf1ni42xly3g2-test-file-1.txt (160B)18372026/09/07 10:04:39 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18382026/09/07 10:04:39 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18392026/09/07 10:04:39 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18402026/09/07 10:04:39 WARN Failed to register uploaded object key=wf7im8yz6idhjp5kv064jwxc9gyhnlqd.ls error="server returned 404: 404 page not found\n"18412026/09/07 10:04:39 WARN Failed to register uploaded object key=2l8ywp6jdvflwfhw6rinmj12aa0291z1.ls error="server returned 404: 404 page not found\n"18422026/09/07 10:04:39 WARN Failed to register uploaded object key=ak8p2snqvrg5k02bbhqmf1ni42xly3g2.ls error="server returned 404: 404 page not found\n"18432026/09/07 10:04:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign18442026/09/07 10:04:39 INFO Signed narinfos id=2 count=118452026/09/07 10:04:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/3/sign18462026/09/07 10:04:39 INFO Signed narinfos id=3 count=118472026/09/07 10:04:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign18482026/09/07 10:04:39 INFO Signed narinfos id=1 count=118492026/09/07 10:04:39 INFO Uploading 3 narinfos18502026/09/07 10:04:39 WARN Failed to register uploaded object key=2l8ywp6jdvflwfhw6rinmj12aa0291z1.narinfo error="server returned 404: 404 page not found\n"18512026/09/07 10:04:39 WARN Failed to register uploaded object key=wf7im8yz6idhjp5kv064jwxc9gyhnlqd.narinfo error="server returned 404: 404 page not found\n"18522026/09/07 10:04:39 WARN Failed to register uploaded object key=ak8p2snqvrg5k02bbhqmf1ni42xly3g2.narinfo error="server returned 404: 404 page not found\n"18532026/09/07 10:04:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete18542026/09/07 10:04:39 INFO Completed upload id=118552026/09/07 10:04:39 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete18562026/09/07 10:04:39 INFO Completed upload id=218572026/09/07 10:04:39 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete18582026/09/07 10:04:39 INFO Completed upload id=318592026/09/07 10:04:39 INFO Upload complete. (393ms)1860=== NAME TestClientMultipleUploads1861 client_integration_test.go:350: Uploaded 3 paths in 540.7975ms1862=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18632026/09/07 10:04:39 INFO Received uploads request method=POST path=/1864=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18652026/09/07 10:04:39 INFO Received complete multipart upload request method=POST path=/1866=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18672026/09/07 10:04:39 INFO Received request for more parts method=POST path=/1868=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18692026/09/07 10:04:39 INFO Received uploads request method=POST path=/1870--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1871 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1872 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1873 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1874 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1875=== CONT TestIsValidUploadKey/narinfo1876=== CONT TestIsValidUploadKey/realisation_plus_in_output1877=== CONT TestIsValidUploadKey/unknown_type1878=== CONT TestIsValidUploadKey/empty_key1879=== CONT TestIsValidUploadKey/absolute1880=== CONT TestIsValidUploadKey/traversal_nar1881=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1882=== CONT TestIsValidUploadKey/index.html1883=== CONT TestIsValidUploadKey/nix-cache-info1884=== CONT TestIsValidUploadKey/traversal1885=== CONT TestIsValidUploadKey/build_log_home-manager_file1886=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1887=== CONT TestIsValidUploadKey/realisation1888=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1889=== CONT TestIsValidUploadKey/build_log_equals1890=== CONT TestIsValidUploadKey/build_log_question_mark1891=== CONT TestIsValidUploadKey/build_log_plus_in_name1892=== CONT TestIsValidUploadKey/nar_plain1893=== CONT TestIsValidUploadKey/build_log1894=== CONT TestIsValidUploadKey/nar_xz1895=== CONT TestIsValidUploadKey/listing1896=== CONT TestIsValidUploadKey/nar_zst1897--- PASS: TestIsValidUploadKey (0.00s)1898 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1899 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1900 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1901 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1902 --- PASS: TestIsValidUploadKey/absolute (0.00s)1903 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1904 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1905 --- PASS: TestIsValidUploadKey/index.html (0.00s)1906 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1907 --- PASS: TestIsValidUploadKey/traversal (0.00s)1908 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1909 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1910 --- PASS: TestIsValidUploadKey/realisation (0.00s)1911 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1912 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1913 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1914 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1915 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1916 --- PASS: TestIsValidUploadKey/build_log (0.00s)1917 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1918 --- PASS: TestIsValidUploadKey/listing (0.00s)1919 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1920=== CONT TestIsValidCachePath/narinfo1921=== CONT TestIsValidCachePath/leading_slash1922=== CONT TestIsValidCachePath/empty1923=== CONT TestIsValidCachePath/random_path1924=== CONT TestIsValidCachePath/invalid_char_u1925=== CONT TestIsValidCachePath/invalid_char_e1926=== CONT TestIsValidCachePath/traversal_in_middle1927=== CONT TestIsValidCachePath/traversal_parent1928=== CONT TestIsValidCachePath/index.html1929=== CONT TestIsValidCachePath/nix-cache-info1930=== CONT TestIsValidCachePath/realisation1931=== CONT TestIsValidCachePath/log1932=== CONT TestIsValidCachePath/ls1933=== CONT TestIsValidCachePath/nar_uncompressed1934=== CONT TestIsValidCachePath/nar_bz21935=== CONT TestIsValidCachePath/nar_xz1936=== CONT TestIsValidCachePath/nar_zst1937=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1938=== CONT TestIsValidCachePath/wrong_extension1939=== CONT TestIsValidCachePath/short_hash1940=== CONT TestParseSingleRange/none1941=== CONT TestParseSingleRange/open-ended1942--- PASS: TestIsValidCachePath (0.00s)1943 --- PASS: TestIsValidCachePath/narinfo (0.00s)1944 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1945 --- PASS: TestIsValidCachePath/empty (0.00s)1946 --- PASS: TestIsValidCachePath/random_path (0.00s)1947 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1948 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1949 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1950 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1951 --- PASS: TestIsValidCachePath/index.html (0.00s)1952 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1953 --- PASS: TestIsValidCachePath/realisation (0.00s)1954 --- PASS: TestIsValidCachePath/log (0.00s)1955 --- PASS: TestIsValidCachePath/ls (0.00s)1956 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1957 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1958 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1959 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1960 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1961 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1962 --- PASS: TestIsValidCachePath/short_hash (0.00s)1963=== CONT TestParseSingleRange/start_far_past_EOF1964=== CONT TestParseSingleRange/start_past_EOF1965=== CONT TestParseSingleRange/single_byte1966=== CONT TestParseSingleRange/suffix_exceeds_size1967=== CONT TestParseSingleRange/suffix1968=== CONT TestParseSingleRange/end_clamped_to_size1969=== CONT TestParseSingleRange/malformed_both_empty1970=== CONT TestParseSingleRange/closed1971=== CONT TestParseSingleRange/malformed_end_before_start1972=== CONT TestParseSingleRange/malformed_no_dash1973=== CONT TestParseSingleRange/multi-range_ignored1974=== CONT TestParseSingleRange/unknown_unit1975--- PASS: TestParseSingleRange (0.00s)1976 --- PASS: TestParseSingleRange/none (0.00s)1977 --- PASS: TestParseSingleRange/open-ended (0.00s)1978 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1979 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1980 --- PASS: TestParseSingleRange/single_byte (0.00s)1981 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1982 --- PASS: TestParseSingleRange/suffix (0.00s)1983 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1984 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1985 --- PASS: TestParseSingleRange/closed (0.00s)1986 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1987 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1988 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1989 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1990=== CONT TestProxyWriteTimeout/narinfo1991=== CONT TestProxyWriteTimeout/10_GiB_nar1992=== CONT TestProxyWriteTimeout/unknown_size1993=== CONT TestProxyWriteTimeout/1_GiB_nar1994--- PASS: TestProxyWriteTimeout (0.00s)1995 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1996 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1997 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1998 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1999=== CONT TestServerTLSConfig/no_client_CA2000=== CONT TestServerTLSConfig/not_a_PEM_file2001=== CONT TestServerTLSConfig/missing_CA_file2002--- PASS: TestServerTLSConfig (0.00s)2003 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2004 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)2005 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2006=== CONT TestCacheConfigHandler/full_config,_no_issuer2007=== CONT TestCacheConfigHandler/no_signing_keys2008=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2009=== CONT TestCacheConfigHandler/no_cache_url_configured2010--- PASS: TestCacheConfigHandler (0.00s)2011 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2012 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2013 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2014 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2015=== CONT TestService_RequireScope_OIDC/builder_may_write20162026/09/07 10:04:39 INFO OIDC auth successful provider=test scopes=[write]2017=== CONT TestService_RequireScope_OIDC/static_token_may_admin2018=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2019=== CONT TestService_RequireScope_OIDC/writer_implies_read20202026/09/07 10:04:39 INFO OIDC auth successful provider=test scopes=[write]2021=== CONT TestService_RequireScope_OIDC/reader_may_read20222026/09/07 10:04:39 INFO OIDC auth successful provider=test scopes=[read]2023=== CONT TestService_RequireScope_OIDC/static_token_may_write2024=== CONT TestService_RequireScope_OIDC/ops_may_not_write20252026/09/07 10:04:39 INFO OIDC auth successful provider=test scopes=[admin]2026=== CONT TestService_RequireScope_OIDC/reader_may_not_write20272026/09/07 10:04:39 INFO OIDC auth successful provider=test scopes=[read]2028=== CONT TestService_RequireScope_OIDC/ops_may_admin20292026/09/07 10:04:39 INFO OIDC auth successful provider=test scopes=[admin]2030=== CONT TestService_RequireScope_OIDC/builder_may_not_admin20312026/09/07 10:04:39 INFO OIDC auth successful provider=test scopes=[write]2032=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20332026/09/07 10:04:39 INFO OIDC auth successful provider=test scopes=[write]2034=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20352026/09/07 10:04:39 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2036=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2037=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2038--- PASS: TestService_RequireScope_OIDC (2.12s)2039 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2040 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2041 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2042 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2043 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2044 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2045 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2046 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2047 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2048 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20492026/09/07 10:04:39 WARN Authentication failed token_preview=eyJhbGciOi...9HY8VphseQ token_length=702 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]20502026/09/07 10:04:39 WARN claim: cannot clear write deadline error="feature not supported"2051--- PASS: TestClientMultipleUploads (3.15s)2052=== CONT TestResolveDBConnectionString/flag_wins2053=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2054=== CONT TestResolveDBConnectionString/missing_file_is_an_error2055=== CONT TestResolveDBConnectionString/file_when_flag_empty2056=== CONT TestResolveDBConnectionString/nothing_configured2057=== CONT TestClientErrorHandling/InvalidStorePath2058=== CONT TestClientErrorHandling/ServerNotAvailable2059--- PASS: TestResolveDBConnectionString (0.01s)2060 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2061 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2062 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2063 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2064 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2065--- PASS: TestService_AuthMiddleware_OIDC (1.80s)2066 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2067 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2068 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2069 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20702026/09/07 10:04:39 WARN claim: cannot clear write deadline error="feature not supported"20712026/09/07 10:04:39 WARN claim: cannot clear write deadline error="feature not supported"2072--- PASS: TestClaim_FailWakesWaitersButIsNotRemembered (1.75s)2073=== CONT TestClientErrorHandling/InvalidAuthToken20742026/09/07 10:04:39 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"20752026/09/07 10:04:39 INFO Received uploads request method=POST path=/api/pending_closures20762026/09/07 10:04:39 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20772026/09/07 10:04:39 INFO Uploading p1jyky6vzmp3mfry645nq4467r6azfrw-test-script (136B)20782026/09/07 10:04:39 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"20792026/09/07 10:04:39 WARN Failed to register uploaded object key=p1jyky6vzmp3mfry645nq4467r6azfrw.ls error="server returned 404: 404 page not found\n"20802026/09/07 10:04:39 WARN Failed to register uploaded object key=log/vnkcay9lirfap0zqikci6bb1njir34rb-test-script.drv error="server returned 404: 404 page not found\n"20812026/09/07 10:04:39 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign20822026/09/07 10:04:39 INFO Signed narinfos id=1 count=120832026/09/07 10:04:39 INFO Uploading 1 narinfos20842026/09/07 10:04:39 WARN Failed to register uploaded object key=p1jyky6vzmp3mfry645nq4467r6azfrw.narinfo error="server returned 404: 404 page not found\n"20852026/09/07 10:04:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete20862026-09-07 10:04:39.523 UTC [79420] ERROR: relation "goose_db_version" does not exist at character 3620872026-09-07 10:04:39.523 UTC [79420] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20882026/09/07 10:04:39 INFO Completed upload id=120892026/09/07 10:04:39 INFO Upload complete. (203ms)2090=== NAME TestClientWithDependencies2091 client_integration_test.go:598: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-76543-4286199278/TestClientWithDependencies2700331408/001/store) requires matching store prefix2092--- PASS: TestClientWithDependencies (3.55s)20932026/09/07 10:04:39 OK 20241026095416_initial_model.sql (30.02ms)20942026/09/07 10:04:39 OK 20251210153512_drop_unused_gin_index.sql (1.15ms)20952026/09/07 10:04:39 OK 20251218171726_add_pins.sql (4.41ms)20962026-09-07 10:04:39.589 UTC [79422] ERROR: relation "goose_db_version" does not exist at character 3620972026-09-07 10:04:39.589 UTC [79422] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC20982026/09/07 10:04:39 OK 20260628120000_add_object_size_and_stats.sql (3.54ms)20992026/09/07 10:04:39 OK 20260905000000_add_claims.sql (3.1ms)21002026/09/07 10:04:39 goose: successfully migrated database to version: 2026090500000021012026/09/07 10:04:39 OK 1_commit_pending_closure.sql (2.04ms)21022026/09/07 10:04:39 OK 2_object_stats_trigger.sql (551.5µs)21032026/09/07 10:04:39 goose: up to current file version: 221042026/09/07 10:04:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21052026/09/07 10:04:39 OK 20241026095416_initial_model.sql (109.18ms)21062026/09/07 10:04:39 OK 20251210153512_drop_unused_gin_index.sql (5.74ms)21072026/09/07 10:04:39 INFO Completed multipart upload object_key=nar/0000000000000000000000000000001700000000000000000000.nar.zst upload_id=NTU5MDNjNWQtYTgxMC00Y2ZlLTk4M2EtYmMwMDc3ZDRhNTlmLmJmYWRjZjZiLWQ1OTQtNGZkNS05M2ZmLTNmNjhmNmFhMDE3ZngxNzg4Nzc1NDc4NzY2NjgxMDAw parts=1021082026/09/07 10:04:39 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21092026/09/07 10:04:39 OK 20251218171726_add_pins.sql (9.34ms)21102026/09/07 10:04:39 INFO Completed upload id=121112026/09/07 10:04:39 WARN claim: cannot clear write deadline error="feature not supported"21122026/09/07 10:04:39 OK 20260628120000_add_object_size_and_stats.sql (8.52ms)21132026/09/07 10:04:39 INFO Aborted multipart uploads count=021142026/09/07 10:04:39 WARN Force mode enabled - objects will be deleted immediately without grace period21152026/09/07 10:04:39 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=021162026/09/07 10:04:39 INFO Vacuumed table table=pending_closures21172026/09/07 10:04:39 OK 20260905000000_add_claims.sql (26.24ms)21182026/09/07 10:04:39 goose: successfully migrated database to version: 2026090500000021192026/09/07 10:04:39 INFO Vacuumed table table=pending_objects21202026/09/07 10:04:39 OK 1_commit_pending_closure.sql (6.6ms)21212026/09/07 10:04:39 OK 2_object_stats_trigger.sql (619.67µs)21222026/09/07 10:04:39 goose: up to current file version: 221232026/09/07 10:04:39 INFO Vacuumed table table=multipart_uploads21242026/09/07 10:04:39 WARN claim: cannot clear write deadline error="feature not supported"21252026/09/07 10:04:39 INFO Vacuumed table table=closures21262026/09/07 10:04:39 INFO Vacuumed table table=objects2127--- PASS: TestClaim_InputsTouched (2.88s)21282026/09/07 10:04:39 WARN claim: cannot clear write deadline error="feature not supported"21292026/09/07 10:04:39 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21302026-09-07 10:04:39.884 UTC [79491] ERROR: relation "goose_db_version" does not exist at character 3621312026-09-07 10:04:39.884 UTC [79491] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC2132=== NAME TestClientCADerivations2133 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-76543-4286199278/TestClientCADerivations1450262591/001/store/ypd5c1qkbmpjn2pnpjby4il3ls9xywrb-ca-test21342026/09/07 10:04:39 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.625919ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21352026-09-07 10:04:39.923 UTC [79504] ERROR: relation "goose_db_version" does not exist at character 3621362026-09-07 10:04:39.923 UTC [79504] STATEMENT: SELECT version_id, is_applied from goose_db_version ORDER BY id DESC21372026/09/07 10:04:39 OK 20241026095416_initial_model.sql (23.07ms)21382026/09/07 10:04:39 OK 20251210153512_drop_unused_gin_index.sql (1.38ms)21392026/09/07 10:04:39 OK 20251218171726_add_pins.sql (12.19ms)21402026/09/07 10:04:39 OK 20260628120000_add_object_size_and_stats.sql (2.6ms)2141--- PASS: TestReadProxyNarinfo (1.00s)21422026/09/07 10:04:39 OK 20260905000000_add_claims.sql (3.06ms)21432026/09/07 10:04:39 goose: successfully migrated database to version: 2026090500000021442026/09/07 10:04:39 OK 20241026095416_initial_model.sql (7.07ms)21452026/09/07 10:04:39 OK 1_commit_pending_closure.sql (1.96ms)21462026/09/07 10:04:39 OK 2_object_stats_trigger.sql (495.21µs)21472026/09/07 10:04:39 goose: up to current file version: 221482026/09/07 10:04:39 OK 20251210153512_drop_unused_gin_index.sql (895µs)21492026/09/07 10:04:39 OK 20251218171726_add_pins.sql (2.61ms)21502026/09/07 10:04:39 OK 20260628120000_add_object_size_and_stats.sql (7.07ms)21512026/09/07 10:04:39 OK 20260905000000_add_claims.sql (13.87ms)21522026/09/07 10:04:39 goose: successfully migrated database to version: 2026090500000021532026/09/07 10:04:39 OK 1_commit_pending_closure.sql (2.11ms)21542026/09/07 10:04:39 OK 2_object_stats_trigger.sql (555.75µs)21552026/09/07 10:04:39 goose: up to current file version: 22156=== NAME TestClientCADerivations2157 client_ca_test.go:139: Found 1 dependencies (including self)21582026/09/07 10:04:40 WARN claim: cannot clear write deadline error="feature not supported"21592026/09/07 10:04:40 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=381.623547ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21602026/09/07 10:04:40 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=2001 objects_failed=02161=== NAME TestPinProtectsFromGC2162 client_integration_test.go:711: Pin successfully protected closure from garbage collection2163--- PASS: TestPinProtectsFromGC (5.22s)21642026/09/07 10:04:40 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21652026/09/07 10:04:40 INFO Received uploads request method=POST path=/api/pending_closures21662026/09/07 10:04:40 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21672026/09/07 10:04:40 INFO Uploading ypd5c1qkbmpjn2pnpjby4il3ls9xywrb-ca-test (144B)21682026/09/07 10:04:40 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"21692026/09/07 10:04:40 WARN Failed to register uploaded object key=log/v4rkx554sld79lxgdbqzkd9m84llyzlb-ca-test.drv error="server returned 404: 404 page not found\n"21702026/09/07 10:04:40 WARN Failed to register uploaded object key=ypd5c1qkbmpjn2pnpjby4il3ls9xywrb.ls error="server returned 404: 404 page not found\n"21712026/09/07 10:04:40 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign21722026/09/07 10:04:40 INFO Signed narinfos id=1 count=121732026/09/07 10:04:40 INFO Uploading 1 narinfos21742026/09/07 10:04:40 WARN Failed to register uploaded object key=ypd5c1qkbmpjn2pnpjby4il3ls9xywrb.narinfo error="server returned 404: 404 page not found\n"21752026/09/07 10:04:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21762026/09/07 10:04:40 INFO Completed upload id=121772026/09/07 10:04:40 INFO Upload complete. (202ms)2178=== NAME TestClientCADerivations2179 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-76543-4286199278/TestClientCADerivations1450262591/001/store/ypd5c1qkbmpjn2pnpjby4il3ls9xywrb-ca-test2180 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2181 Compression: zstd2182 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2183 NarSize: 1442184 References: 2185 Deriver: /nix/var/nix/builds/nix-76543-4286199278/TestClientCADerivations1450262591/001/store/v4rkx554sld79lxgdbqzkd9m84llyzlb-ca-test.drv2186 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2187 client_ca_test.go:185: Checking for realisation files in S3...2188 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2189 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2190 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket54?endpoint=http://localhost:61237®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-76543-4286199278/TestClientCADerivations1450262591/001/store'2191 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12192--- PASS: TestClientCADerivations (3.45s)21932026/09/07 10:04:40 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: server returned 404: 404 page not found\n"21942026/09/07 10:04:40 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=866.515086ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21952026/09/07 10:04:40 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2196--- PASS: TestClaim_HolderDisconnectKeepsClaim (1.93s)2197--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)2198 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.03s)2199 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.11s)2200 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (2.25s)22012026/09/07 10:04:41 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.509165245s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22022026/09/07 10:04:42 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"22032026/09/07 10:04:42 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22042026/09/07 10:04:43 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.6667ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22052026/09/07 10:04:43 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=407.520297ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22062026/09/07 10:04:43 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=778.651469ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22072026/09/07 10:04:44 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.746328099s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2208--- PASS: TestClientErrorHandling (0.00s)2209 --- PASS: TestClientErrorHandling/InvalidStorePath (0.79s)2210 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.20s)2211 --- PASS: TestClientErrorHandling/ServerNotAvailable (6.89s)2212PASS2213{"timestamp":"2026-09-07T10:04:46.246226Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:61294","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":1866,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}22142026-09-07 10:04:46.393 UTC [77435] LOG: received smart shutdown request22152026-09-07 10:04:46.395 UTC [77435] LOG: background worker "logical replication launcher" (PID 77448) exited with exit code 122162026-09-07 10:04:46.400 UTC [77442] LOG: shutting down22172026-09-07 10:04:46.400 UTC [77442] LOG: checkpoint starting: shutdown immediate22182026-09-07 10:04:49.602 UTC [77442] LOG: checkpoint complete: wrote 13170 buffers (80.4%), wrote 3 SLRU buffers; 0 WAL file(s) added, 0 removed, 18 recycled; write=0.855 s, sync=2.343 s, total=3.203 s; sync files=21000, longest=0.130 s, average=0.001 s; distance=287769 kB, estimate=287769 kB; lsn=0/130933A0, redo lsn=0/130933A022192026-09-07 10:04:49.614 UTC [77435] LOG: database system is shut down2220Running OIDC tests...2221=== RUN TestGlobMatch2222=== PAUSE TestGlobMatch2223=== RUN TestAudienceForIssuer2224=== PAUSE TestAudienceForIssuer2225=== RUN TestValidateToken_ValidToken2226=== PAUSE TestValidateToken_ValidToken2227=== RUN TestValidateToken_WrongAudience2228=== PAUSE TestValidateToken_WrongAudience2229=== RUN TestValidateToken_Expired2230=== PAUSE TestValidateToken_Expired2231=== RUN TestValidateToken_BoundClaimsMismatch2232=== PAUSE TestValidateToken_BoundClaimsMismatch2233=== RUN TestValidateToken_BoundSubjectMismatch2234=== PAUSE TestValidateToken_BoundSubjectMismatch2235=== RUN TestValidateToken_MultipleProviders2236=== PAUSE TestValidateToken_MultipleProviders2237=== RUN TestValidateToken_NoMatchingProvider2238=== PAUSE TestValidateToken_NoMatchingProvider2239=== RUN TestValidateToken_KubernetesServiceAccount2240=== PAUSE TestValidateToken_KubernetesServiceAccount2241=== RUN TestNewValidator_KubernetesRequiresCA2242=== PAUSE TestNewValidator_KubernetesRequiresCA2243=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2244=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2245=== RUN TestScopes_LegacyProviderDefaultsToWrite2246=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2247=== RUN TestScopes_Rules2248=== PAUSE TestScopes_Rules2249=== RUN TestScopes_ConfigValidation2250=== PAUSE TestScopes_ConfigValidation2251=== CONT TestGlobMatch2252=== CONT TestValidateToken_NoMatchingProvider2253=== RUN TestGlobMatch/foo_foo2254=== PAUSE TestGlobMatch/foo_foo2255=== RUN TestGlobMatch/foo_bar2256=== PAUSE TestGlobMatch/foo_bar2257=== CONT TestScopes_LegacyProviderDefaultsToWrite2258=== RUN TestGlobMatch/*_2259=== PAUSE TestGlobMatch/*_2260=== RUN TestGlobMatch/*_anything2261=== PAUSE TestGlobMatch/*_anything2262=== RUN TestGlobMatch/foo*_foo2263=== PAUSE TestGlobMatch/foo*_foo2264=== RUN TestGlobMatch/foo*_foobar2265=== PAUSE TestGlobMatch/foo*_foobar2266=== RUN TestGlobMatch/foo*_bar2267=== PAUSE TestGlobMatch/foo*_bar2268=== RUN TestGlobMatch/*bar_bar2269=== PAUSE TestGlobMatch/*bar_bar2270=== RUN TestGlobMatch/*bar_foobar2271=== PAUSE TestGlobMatch/*bar_foobar2272=== RUN TestGlobMatch/*bar_foo2273=== PAUSE TestGlobMatch/*bar_foo2274=== RUN TestGlobMatch/foo*bar_foobar2275=== PAUSE TestGlobMatch/foo*bar_foobar2276=== RUN TestGlobMatch/foo*bar_foo123bar2277=== PAUSE TestGlobMatch/foo*bar_foo123bar2278=== RUN TestGlobMatch/foo*bar_foobarbaz2279=== PAUSE TestGlobMatch/foo*bar_foobarbaz2280=== RUN TestGlobMatch/*/*_foo/bar2281=== CONT TestValidateToken_MultipleProviders2282=== CONT TestValidateToken_BoundSubjectMismatch2283=== CONT TestValidateToken_BoundClaimsMismatch2284=== CONT TestValidateToken_Expired2285=== CONT TestValidateToken_WrongAudience2286=== CONT TestValidateToken_ValidToken2287=== CONT TestAudienceForIssuer2288--- PASS: TestAudienceForIssuer (0.00s)2289=== CONT TestValidateToken_KubernetesServiceAccount2290=== PAUSE TestGlobMatch/*/*_foo/bar2291=== RUN TestGlobMatch/*/*_foo2292=== PAUSE TestGlobMatch/*/*_foo2293=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2294=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2295=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02296=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02297=== RUN TestGlobMatch/refs/*/main_refs/heads/main2298=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2299=== RUN TestGlobMatch/fo?_foo2300=== PAUSE TestGlobMatch/fo?_foo2301=== RUN TestGlobMatch/fo?_fo2302=== PAUSE TestGlobMatch/fo?_fo2303=== RUN TestGlobMatch/fo?_fooo2304=== PAUSE TestGlobMatch/fo?_fooo2305=== RUN TestGlobMatch/?oo_foo2306=== PAUSE TestGlobMatch/?oo_foo2307=== RUN TestGlobMatch/?oo_boo2308=== PAUSE TestGlobMatch/?oo_boo2309=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2310=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2311=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2312=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2313=== CONT TestScopes_ConfigValidation23142026/09/07 10:04:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61507/oidc23152026/09/07 10:04:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61511/oidc23162026/09/07 10:04:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61506/oidc23172026/09/07 10:04:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61510/oidc23182026/09/07 10:04:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61509/oidc23192026/09/07 10:04:51 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:61505/oidc2320--- PASS: TestScopes_ConfigValidation (0.00s)2321=== CONT TestScopes_Rules23222026/09/07 10:04:51 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:61513/oidc23232026/09/07 10:04:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61508/oidc23242026/09/07 10:04:51 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:61524/oidc23252026/09/07 10:04:51 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:61504/oidc2326--- PASS: TestValidateToken_Expired (0.01s)2327=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2328--- PASS: TestValidateToken_BoundClaimsMismatch (0.01s)2329=== CONT TestNewValidator_KubernetesRequiresCA2330--- PASS: TestValidateToken_ValidToken (0.01s)2331=== CONT TestGlobMatch/foo_foo2332--- PASS: TestValidateToken_BoundSubjectMismatch (0.01s)2333=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2334=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2335=== CONT TestGlobMatch/?oo_boo2336=== CONT TestGlobMatch/?oo_foo2337=== CONT TestGlobMatch/fo?_fooo2338=== CONT TestGlobMatch/fo?_fo2339=== CONT TestGlobMatch/fo?_foo2340=== CONT TestGlobMatch/refs/*/main_refs/heads/main2341=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02342=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2343=== CONT TestGlobMatch/*/*_foo2344=== CONT TestGlobMatch/*bar_bar2345=== CONT TestGlobMatch/foo*bar_foobar2346=== CONT TestGlobMatch/*bar_foo2347=== CONT TestGlobMatch/foo*bar_foobarbaz2348=== CONT TestGlobMatch/*bar_foobar2349=== CONT TestGlobMatch/foo*_bar2350=== CONT TestGlobMatch/foo*_foobar2351=== CONT TestGlobMatch/*_2352=== CONT TestGlobMatch/foo_bar2353=== CONT TestGlobMatch/*_anything2354--- PASS: TestValidateToken_WrongAudience (0.01s)2355--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.01s)2356=== CONT TestGlobMatch/foo*bar_foo123bar2357=== CONT TestGlobMatch/*/*_foo/bar2358=== CONT TestGlobMatch/foo*_foo2359--- PASS: TestGlobMatch (0.00s)2360 --- PASS: TestGlobMatch/foo_foo (0.00s)2361 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2362 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2363 --- PASS: TestGlobMatch/?oo_boo (0.00s)2364 --- PASS: TestGlobMatch/?oo_foo (0.00s)2365 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2366 --- PASS: TestGlobMatch/fo?_fo (0.00s)2367 --- PASS: TestGlobMatch/fo?_foo (0.00s)2368 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2369 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2370 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2371 --- PASS: TestGlobMatch/*/*_foo (0.00s)2372 --- PASS: TestGlobMatch/*bar_bar (0.00s)2373 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2374 --- PASS: TestGlobMatch/*bar_foo (0.00s)2375 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2376 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2377 --- PASS: TestGlobMatch/foo*_bar (0.00s)2378 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2379 --- PASS: TestGlobMatch/*_ (0.00s)2380 --- PASS: TestGlobMatch/foo_bar (0.00s)2381 --- PASS: TestGlobMatch/*_anything (0.00s)2382 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2383 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2384 --- PASS: TestGlobMatch/foo*_foo (0.00s)2385--- PASS: TestValidateToken_MultipleProviders (0.01s)23862026/09/07 10:04:51 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:615142387--- PASS: TestValidateToken_NoMatchingProvider (0.01s)23882026/09/07 10:04:51 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232389--- PASS: TestValidateToken_KubernetesServiceAccount (0.01s)2390--- PASS: TestScopes_Rules (0.01s)2391--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.01s)23922026/09/07 10:04:51 http: TLS handshake error from 127.0.0.1:61528: remote error: tls: bad certificate2393--- PASS: TestNewValidator_KubernetesRequiresCA (0.01s)2394PASS2395Running hook tests...2396=== RUN TestSendPathsEmpty2397=== PAUSE TestSendPathsEmpty2398=== RUN TestQueueEnqueueAndFetch2399=== PAUSE TestQueueEnqueueAndFetch2400=== RUN TestQueueDeduplication2401=== PAUSE TestQueueDeduplication2402=== RUN TestQueueRemove2403=== PAUSE TestQueueRemove2404=== RUN TestQueueFetchBatchLimit2405=== PAUSE TestQueueFetchBatchLimit2406=== RUN TestQueueRetryMovesToBack2407=== PAUSE TestQueueRetryMovesToBack2408=== RUN TestQueueFetchRemoveLifecycle2409=== PAUSE TestQueueFetchRemoveLifecycle2410=== RUN TestQueueConcurrentWriters2411=== PAUSE TestQueueConcurrentWriters2412=== RUN TestQueueRemoveLargeClosure2413=== PAUSE TestQueueRemoveLargeClosure2414=== RUN TestServerClientIntegration2415=== PAUSE TestServerClientIntegration2416=== RUN TestServerQueueError2417=== PAUSE TestServerQueueError2418=== RUN TestGetListenerSocketActivation2419 server_test.go:214: === RUN TestGetListenerSocketActivation2420 --- PASS: TestGetListenerSocketActivation (0.00s)2421 PASS2422 2423--- PASS: TestGetListenerSocketActivation (0.01s)2424=== RUN TestServerWait2425=== PAUSE TestServerWait2426=== RUN TestDrainIsolatesPoisonPath2427=== PAUSE TestDrainIsolatesPoisonPath2428=== RUN TestRunNotBlockedByPoisonHead2429=== PAUSE TestRunNotBlockedByPoisonHead2430=== RUN TestDrainGivesUpWhenServerDown2431=== PAUSE TestDrainGivesUpWhenServerDown2432=== RUN TestFailedPathPrunedByLaterClosure2433=== PAUSE TestFailedPathPrunedByLaterClosure2434=== RUN TestWorkerUploadsAndRemoves2435=== PAUSE TestWorkerUploadsAndRemoves2436=== RUN TestWorkerSkipsGCdPaths2437=== PAUSE TestWorkerSkipsGCdPaths2438=== RUN TestWorkerPrunesClosureDeps2439=== PAUSE TestWorkerPrunesClosureDeps2440=== RUN TestDrainTimeout2441=== PAUSE TestDrainTimeout2442=== CONT TestSendPathsEmpty2443=== CONT TestServerQueueError2444=== CONT TestFailedPathPrunedByLaterClosure2445--- PASS: TestSendPathsEmpty (0.00s)2446=== CONT TestServerClientIntegration2447=== CONT TestQueueRemoveLargeClosure2448=== CONT TestQueueConcurrentWriters2449=== CONT TestQueueFetchRemoveLifecycle2450=== CONT TestQueueRetryMovesToBack2451=== CONT TestQueueFetchBatchLimit2452=== CONT TestQueueRemove2453=== CONT TestQueueDeduplication24542026/09/07 10:04:52 ERROR Hook request failed error="permission denied" wait=false count=12455--- PASS: TestServerQueueError (0.00s)2456=== CONT TestQueueEnqueueAndFetch2457=== CONT TestRunNotBlockedByPoisonHead2458--- PASS: TestServerClientIntegration (0.00s)24592026/09/07 10:04:52 INFO Uploading batch count=124602026/09/07 10:04:52 ERROR Upload failed error="upload failed" count=124612026/09/07 10:04:52 INFO Upload queue status pending=324622026/09/07 10:04:52 INFO Uploading batch count=12463--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2464=== CONT TestDrainGivesUpWhenServerDown2465--- PASS: TestQueueRetryMovesToBack (0.01s)2466=== CONT TestDrainIsolatesPoisonPath24672026/09/07 10:04:52 INFO Uploading batch count=124682026/09/07 10:04:52 ERROR Upload failed error="upload failed" count=124692026/09/07 10:04:52 INFO Uploading batch count=12470--- PASS: TestQueueFetchBatchLimit (0.01s)2471=== CONT TestServerWait2472--- PASS: TestQueueRemove (0.01s)2473=== CONT TestWorkerPrunesClosureDeps2474--- PASS: TestServerWait (0.00s)2475=== CONT TestDrainTimeout2476--- PASS: TestQueueDeduplication (0.01s)2477=== CONT TestWorkerSkipsGCdPaths2478--- PASS: TestQueueEnqueueAndFetch (0.01s)2479=== CONT TestWorkerUploadsAndRemoves2480--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)24812026/09/07 10:04:52 INFO Uploading batch count=424822026/09/07 10:04:52 ERROR Upload failed error="upload failed" count=424832026/09/07 10:04:52 INFO Upload queue status pending=224842026/09/07 10:04:52 INFO Upload queue status pending=224852026/09/07 10:04:52 INFO Uploading batch count=224862026/09/07 10:04:52 INFO Uploading batch count=124872026/09/07 10:04:52 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-76543-4286199278/TestWorkerSkipsGCdPaths2587870021/002/nonexistent24882026/09/07 10:04:52 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-76543-4286199278/TestDrainIsolatesPoisonPath4087786694/002/bbb24892026/09/07 10:04:52 INFO Uploading batch count=224902026/09/07 10:04:52 ERROR Upload failed error="upload failed" count=224912026/09/07 10:04:52 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-76543-4286199278/TestDrainGivesUpWhenServerDown1499413361/002/a24922026/09/07 10:04:52 INFO Uploading batch count=124932026/09/07 10:04:52 INFO Upload queue status pending=224942026/09/07 10:04:52 INFO Uploading batch count=224952026/09/07 10:04:52 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-76543-4286199278/TestDrainGivesUpWhenServerDown1499413361/002/b24962026/09/07 10:04:52 INFO Uploading batch count=124972026/09/07 10:04:52 ERROR Upload failed error="upload failed" count=124982026/09/07 10:04:52 INFO Uploading batch count=224992026/09/07 10:04:52 ERROR Upload failed error="upload failed" count=225002026/09/07 10:04:52 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-76543-4286199278/TestDrainGivesUpWhenServerDown1499413361/002/c25012026/09/07 10:04:52 INFO Uploading batch count=125022026/09/07 10:04:52 ERROR Upload failed error="upload failed" count=125032026/09/07 10:04:52 INFO Uploading batch count=125042026/09/07 10:04:52 ERROR Upload failed error="upload failed" count=125052026/09/07 10:04:52 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-76543-4286199278/TestDrainGivesUpWhenServerDown1499413361/002/d25062026/09/07 10:04:52 ERROR Drain finished with paths left in queue remaining=125072026/09/07 10:04:52 INFO Uploading batch count=225082026/09/07 10:04:52 ERROR Upload failed error="upload failed" count=225092026/09/07 10:04:52 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-76543-4286199278/TestDrainGivesUpWhenServerDown1499413361/002/e25102026/09/07 10:04:52 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-76543-4286199278/TestDrainGivesUpWhenServerDown1499413361/002/f25112026/09/07 10:04:52 ERROR Drain finished with paths left in queue remaining=102512--- PASS: TestDrainIsolatesPoisonPath (0.01s)2513--- PASS: TestDrainGivesUpWhenServerDown (0.01s)2514--- PASS: TestWorkerPrunesClosureDeps (0.02s)2515--- PASS: TestWorkerSkipsGCdPaths (0.03s)2516--- PASS: TestWorkerUploadsAndRemoves (0.03s)2517--- PASS: TestQueueRemoveLargeClosure (0.11s)2518--- PASS: TestQueueConcurrentWriters (0.12s)25192026/09/07 10:04:52 ERROR Upload failed error="context deadline exceeded" count=225202026/09/07 10:04:52 ERROR Drain finished with paths left in queue remaining=42521--- PASS: TestDrainTimeout (0.21s)25222026/09/07 10:04:53 INFO Uploading batch count=125232026/09/07 10:04:53 INFO Uploading batch count=125242026/09/07 10:04:53 INFO Uploading batch count=125252026/09/07 10:04:53 ERROR Upload failed error="upload failed" count=125262026/09/07 10:04:53 INFO Uploading batch count=125272026/09/07 10:04:53 ERROR Upload failed error="upload failed" count=125282026/09/07 10:04:53 INFO Uploading batch count=125292026/09/07 10:04:53 ERROR Upload failed error="upload failed" count=125302026/09/07 10:04:53 INFO Uploading batch count=125312026/09/07 10:04:53 ERROR Upload failed error="upload failed" count=125322026/09/07 10:04:53 ERROR Drain finished with paths left in queue remaining=12533--- PASS: TestRunNotBlockedByPoisonHead (1.01s)2534PASS