niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #347
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestCaseHackSuffix8=== PAUSE TestCaseHackSuffix9=== RUN TestFilterOversizedClosures10=== PAUSE TestFilterOversizedClosures11=== RUN TestUploadMultipart_PartsInParallel12=== PAUSE TestUploadMultipart_PartsInParallel13=== RUN TestPartSizeForNAR14=== PAUSE TestPartSizeForNAR15=== RUN TestUploadMultipart_SupersededByPeer16=== PAUSE TestUploadMultipart_SupersededByPeer17=== RUN TestDumpPathCaseHackMatchesNix18--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)19=== RUN TestDumpPathCaseHackCollision20--- PASS: TestDumpPathCaseHackCollision (0.00s)21=== RUN TestDumpPathMatchesNix22=== PAUSE TestDumpPathMatchesNix23=== RUN TestDumpPathSingleFile24=== PAUSE TestDumpPathSingleFile25=== RUN TestDumpPathWriterError26=== PAUSE TestDumpPathWriterError27=== RUN TestEncodeNixBase3228=== PAUSE TestEncodeNixBase3229=== RUN TestEncodeNixBase32WithRealHash30=== PAUSE TestEncodeNixBase32WithRealHash31=== RUN TestConvertHashToNix3232=== PAUSE TestConvertHashToNix3233=== RUN TestGetStorePathHash34=== PAUSE TestGetStorePathHash35=== RUN TestPathInfoHashCompatibility36=== PAUSE TestPathInfoHashCompatibility37=== RUN TestParsePathInfoJSON38=== PAUSE TestParsePathInfoJSON39=== RUN TestParsePathInfoJSONMultiplePaths40=== PAUSE TestParsePathInfoJSONMultiplePaths41=== RUN TestPathInfoCACompatibility42=== PAUSE TestPathInfoCACompatibility43=== RUN TestRateLimiterFeedback44=== PAUSE TestRateLimiterFeedback45=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess46=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess47=== RUN TestResolveStorePath48=== PAUSE TestResolveStorePath49=== RUN TestDoWithRetry_BodyReplayedViaGetBody50=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody51=== RUN TestShellSplit52=== PAUSE TestShellSplit53=== RUN TestShellSplitErrors54=== PAUSE TestShellSplitErrors55=== RUN TestStreamPushReportsEveryPath56=== PAUSE TestStreamPushReportsEveryPath57=== RUN TestStreamPushBatchesUnderLoad58=== PAUSE TestStreamPushBatchesUnderLoad59=== RUN TestStreamPushIsolatesFailures60=== PAUSE TestStreamPushIsolatesFailures61=== RUN TestStreamPushGivesUpOnDeadServer62=== PAUSE TestStreamPushGivesUpOnDeadServer63=== RUN TestStreamPushRequestLine64=== PAUSE TestStreamPushRequestLine65=== RUN TestStreamPushReportsSignatures66=== PAUSE TestStreamPushReportsSignatures67=== RUN TestClientSignaturesByStorePath68=== PAUSE TestClientSignaturesByStorePath69=== RUN TestSetClientTLS70=== PAUSE TestSetClientTLS71=== RUN TestSetClientTLSDoesNotMutateDefaultTransport72=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport73=== RUN TestSetClientTLSErrors74=== PAUSE TestSetClientTLSErrors75=== RUN TestStaticToken76=== PAUSE TestStaticToken77=== RUN TestFileTokenReadsAndCaches78=== PAUSE TestFileTokenReadsAndCaches79=== RUN TestFileTokenMissing80=== PAUSE TestFileTokenMissing81=== RUN TestFileTokenEmpty82=== PAUSE TestFileTokenEmpty83=== RUN TestScriptTokenNoExpiryRerunsEveryCall84=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall85=== RUN TestScriptTokenCachesUntilRefresh86=== PAUSE TestScriptTokenCachesUntilRefresh87=== RUN TestScriptTokenEmptyToken88=== PAUSE TestScriptTokenEmptyToken89=== RUN TestScriptTokenBadJSON90=== PAUSE TestScriptTokenBadJSON91=== RUN TestScriptTokenScriptFails92=== PAUSE TestScriptTokenScriptFails93=== RUN TestScriptTokenEmptyCommand94=== PAUSE TestScriptTokenEmptyCommand95=== CONT TestDoServerRequestAttachesToken96=== CONT TestScriptTokenEmptyCommand97--- PASS: TestScriptTokenEmptyCommand (0.00s)98=== CONT TestSetClientTLSErrors99=== CONT TestScriptTokenScriptFails100=== CONT TestEncodeNixBase32WithRealHash101--- PASS: TestEncodeNixBase32WithRealHash (0.00s)102=== CONT TestSetClientTLSDoesNotMutateDefaultTransport103=== CONT TestParsePathInfoJSON104=== RUN TestParsePathInfoJSON/Nix_format105=== PAUSE TestParsePathInfoJSON/Nix_format106=== RUN TestParsePathInfoJSON/Lix_format107=== PAUSE TestParsePathInfoJSON/Lix_format108=== RUN TestParsePathInfoJSON/empty_input109=== PAUSE TestParsePathInfoJSON/empty_input110=== RUN TestParsePathInfoJSON/whitespace_only111=== PAUSE TestParsePathInfoJSON/whitespace_only112=== RUN TestParsePathInfoJSON/invalid_JSON113=== PAUSE TestParsePathInfoJSON/invalid_JSON114=== CONT TestPathInfoHashCompatibility115=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)116=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)117=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon118=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon119=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI120=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI121=== CONT TestDoWithRetry_BodyReplayedViaGetBody122=== CONT TestStreamPushGivesUpOnDeadServer123=== CONT TestGetStorePathHash124=== RUN TestGetStorePathHash/valid_store_path125=== PAUSE TestGetStorePathHash/valid_store_path126=== CONT TestScriptTokenBadJSON1272026/10/01 13:03:36 ERROR Upload failed error="connection refused" count=20128=== CONT TestConvertHashToNix321292026/10/01 13:03:36 ERROR Server seems unavailable, giving up on batch untried=17130=== RUN TestConvertHashToNix32/SRI_format_to_Nix32131=== CONT TestScriptTokenEmptyToken132=== CONT TestUploadMultipart_SupersededByPeer133=== CONT TestScriptTokenCachesUntilRefresh134=== CONT TestEncodeNixBase32135=== CONT TestScriptTokenNoExpiryRerunsEveryCall136=== CONT TestDumpPathWriterError137=== RUN TestEncodeNixBase32/test_string_hash138=== CONT TestDumpPathSingleFile139=== CONT TestFileTokenEmpty140=== CONT TestFileTokenMissing141=== CONT TestFileTokenReadsAndCaches142=== PAUSE TestEncodeNixBase32/test_string_hash143=== RUN TestEncodeNixBase32/empty_input144=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess145=== CONT TestStaticToken146=== CONT TestResolveStorePath1472026/10/01 13:03:36 WARN Rate limiter enabled after throttle name=server-test rate=51482026/10/01 13:03:36 WARN Rate limiter enabled after throttle name=server-test rate=5149=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha5121502026/10/01 13:03:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33673151--- PASS: TestScriptTokenScriptFails (0.00s)152=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512153=== CONT TestStreamPushIsolatesFailures154=== RUN TestGetStorePathHash/basename_without_hyphen_should_error155=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32156=== RUN TestUploadMultipart_SupersededByPeer/exists157=== CONT TestDumpPathMatchesNix158=== PAUSE TestEncodeNixBase32/empty_input159=== CONT TestSetClientTLS160=== CONT TestStreamPushBatchesUnderLoad161=== CONT TestClientSignaturesByStorePath162=== CONT TestStreamPushReportsSignatures163--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)164=== RUN TestSetClientTLSErrors/missing_cert_file165=== CONT TestStreamPushReportsEveryPath166=== PAUSE TestSetClientTLSErrors/missing_cert_file167=== RUN TestConvertHashToNix32/already_Nix32_format168=== PAUSE TestConvertHashToNix32/already_Nix32_format169=== CONT TestShellSplitErrors170=== CONT TestFilterOversizedClosures171=== CONT TestStreamPushRequestLine172=== CONT TestRateLimiterFeedback173=== CONT TestPartSizeForNAR174=== RUN TestConvertHashToNix32/invalid_format175=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error176=== PAUSE TestUploadMultipart_SupersededByPeer/exists177--- PASS: TestFileTokenMissing (0.00s)178=== CONT TestShellSplit179=== RUN TestSetClientTLSErrors/missing_key_file180=== RUN TestFilterOversizedClosures/no_limit_keeps_everything181=== RUN TestRateLimiterFeedback/429_enables_limiter182--- PASS: TestFileTokenEmpty (0.00s)183=== PAUSE TestSetClientTLSErrors/missing_key_file184=== RUN TestUploadMultipart_SupersededByPeer/missing1852026/10/01 13:03:36 ERROR Upload failed error="bad path" count=3186=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error187=== RUN TestSetClientTLSErrors/missing_ca_file188--- PASS: TestStaticToken (0.00s)189=== PAUSE TestSetClientTLSErrors/missing_ca_file190=== PAUSE TestUploadMultipart_SupersededByPeer/missing191=== PAUSE TestConvertHashToNix32/invalid_format192=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything193=== PAUSE TestRateLimiterFeedback/429_enables_limiter194=== RUN TestPartSizeForNAR/zero_stays_at_minimum195=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error196=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum197=== RUN TestSetClientTLSErrors/invalid_ca_file198=== CONT TestParsePathInfoJSON/Lix_format199=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error200=== RUN TestRateLimiterFeedback/503_enables_limiter201=== PAUSE TestSetClientTLSErrors/invalid_ca_file202=== RUN TestPartSizeForNAR/small_stays_at_minimum203=== CONT TestCaseHackSuffix204=== CONT TestPathInfoCACompatibility205=== CONT TestRegisterUploadedObjectReusesConnections206=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped207=== CONT TestParsePathInfoJSONMultiplePaths208=== CONT TestParsePathInfoJSON/Nix_format209=== CONT TestUploadMultipart_PartsInParallel2102026/10/01 13:03:36 WARN Rate limiter backed off name=server-test rate=5211--- PASS: TestFileTokenReadsAndCaches (0.00s)212=== PAUSE TestRateLimiterFeedback/503_enables_limiter213=== CONT TestParsePathInfoJSON/empty_input2142026/10/01 13:03:36 ERROR Upload failed error=boom count=1215=== RUN TestPathInfoCACompatibility/null_ca_field216=== PAUSE TestPathInfoCACompatibility/null_ca_field217=== CONT TestParsePathInfoJSON/invalid_JSON218=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths219=== PAUSE TestPartSizeForNAR/small_stays_at_minimum220=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum221--- PASS: TestScriptTokenEmptyToken (0.00s)222=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter223=== RUN TestPathInfoCACompatibility/old_string_format_-_text224--- PASS: TestShellSplitErrors (0.00s)225--- PASS: TestStreamPushReportsEveryPath (0.00s)226--- PASS: TestClientSignaturesByStorePath (0.00s)227--- PASS: TestShellSplit (0.00s)228--- PASS: TestResolveStorePath (0.00s)229--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)230--- PASS: TestScriptTokenBadJSON (0.01s)231--- PASS: TestStreamPushIsolatesFailures (0.00s)232--- PASS: TestDoServerRequestAttachesToken (0.01s)233--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)234=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512235--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)236=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI237=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon238=== CONT TestEncodeNixBase32/test_string_hash239=== CONT TestEncodeNixBase32/empty_input240=== CONT TestUploadMultipart_SupersededByPeer/exists241--- PASS: TestEncodeNixBase32 (0.00s)242 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)243 --- PASS: TestEncodeNixBase32/empty_input (0.00s)244=== CONT TestUploadMultipart_SupersededByPeer/missing245=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped246=== RUN TestFilterOversizedClosures/all_closures_skipped247=== PAUSE TestFilterOversizedClosures/all_closures_skipped248=== CONT TestConvertHashToNix32/SRI_format_to_Nix32249=== CONT TestConvertHashToNix32/invalid_format250=== CONT TestConvertHashToNix32/already_Nix32_format251=== CONT TestSetClientTLSErrors/missing_cert_file252=== CONT TestSetClientTLSErrors/invalid_ca_file253--- PASS: TestConvertHashToNix32 (0.01s)254 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)255 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)256 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)257=== CONT TestSetClientTLSErrors/missing_ca_file2582026/10/01 13:03:36 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:33673259=== CONT TestParsePathInfoJSON/whitespace_only260=== CONT TestFilterOversizedClosures/no_limit_keeps_everything261--- PASS: TestParsePathInfoJSON (0.00s)262 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)263 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)264 --- PASS: TestParsePathInfoJSON/Nix_format (0.01s)265 --- PASS: TestParsePathInfoJSON/Lix_format (0.01s)266 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)267=== CONT TestFilterOversizedClosures/all_closures_skipped268=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter269=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum270=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter2712026/10/01 13:03:36 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=50272=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)273=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error2742026/10/01 13:03:36 ERROR Upload failed error=boom count=1275=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped2762026/10/01 13:03:36 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=2000277=== CONT TestSetClientTLSErrors/missing_key_file278=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter279=== CONT TestRateLimiterFeedback/429_enables_limiter280=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter281=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error282=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error283=== CONT TestGetStorePathHash/valid_store_path284=== CONT TestRateLimiterFeedback/503_enables_limiter285=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths2862026/10/01 13:03:36 WARN Rate limiter enabled after throttle name=server-test rate=5287--- PASS: TestStreamPushReportsSignatures (0.04s)2882026/10/01 13:03:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:32787289--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.05s)290--- PASS: TestFilterOversizedClosures (0.01s)291 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)292 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)293 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)294=== CONT TestGetStorePathHash/basename_without_hyphen_should_error295=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter296--- PASS: TestPathInfoHashCompatibility (0.01s)297 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)298 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)299 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)300 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)301--- PASS: TestDumpPathSingleFile (0.05s)3022026/10/01 13:03:36 WARN Rate limiter enabled after throttle name=server-test rate=5303--- PASS: TestGetStorePathHash (0.02s)304 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)305 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)306 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)307 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)3082026/10/01 13:03:36 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:43233309--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)310 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.03s)311 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.03s)3122026/10/01 13:03:36 WARN Rate limiter backed off name=server-test rate=53132026/10/01 13:03:36 WARN Rate limiter backed off name=server-test rate=5314--- PASS: TestRateLimiterFeedback (0.04s)315 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)316 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)317 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)318 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)319--- PASS: TestSetClientTLSErrors (0.01s)320 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)321 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)322 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)323 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)324=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts325=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths326=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths327=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths328=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text329=== RUN TestSetClientTLS/rejects_connection_without_client_cert330=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert331=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts332=== RUN TestPartSizeForNAR/1_TiB333=== PAUSE TestPartSizeForNAR/1_TiB334=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths335=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive336=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA337=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA338=== RUN TestPartSizeForNAR/5_TiB_S3_max_object339=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object340--- PASS: TestParsePathInfoJSONMultiplePaths (0.04s)341 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)342 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)343=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive344=== RUN TestSetClientTLS/preserves_debug_logging_transport345=== RUN TestPartSizeForNAR/capped_at_5_GiB346=== PAUSE TestPartSizeForNAR/capped_at_5_GiB347=== CONT TestPartSizeForNAR/zero_stays_at_minimum348=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts349=== CONT TestPartSizeForNAR/1_TiB350=== CONT TestPartSizeForNAR/small_stays_at_minimum351=== PAUSE TestSetClientTLS/preserves_debug_logging_transport352=== CONT TestSetClientTLS/rejects_connection_without_client_cert353=== CONT TestSetClientTLS/preserves_debug_logging_transport354=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA355=== CONT TestPartSizeForNAR/capped_at_5_GiB356=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum357=== CONT TestPartSizeForNAR/5_TiB_S3_max_object358--- PASS: TestPartSizeForNAR (0.04s)359 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)360 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)361 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)362 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)363 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)364 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)365 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)366=== RUN TestPathInfoCACompatibility/new_structured_format_-_text367=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text368=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method369=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method370=== CONT TestPathInfoCACompatibility/null_ca_field371=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method372=== CONT TestPathInfoCACompatibility/new_structured_format_-_text373=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive374=== CONT TestPathInfoCACompatibility/old_string_format_-_text375--- PASS: TestPathInfoCACompatibility (0.04s)376 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)377 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)378 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)379 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)380 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)3812026/10/01 13:03:36 http: TLS handshake error from 127.0.0.1:35434: remote error: tls: bad certificate382--- PASS: TestSetClientTLS (0.04s)383 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)384 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)385 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)386--- PASS: TestRegisterUploadedObjectReusesConnections (0.06s)387--- PASS: TestStreamPushRequestLine (0.07s)388--- PASS: TestDumpPathWriterError (0.08s)389--- PASS: TestCaseHackSuffix (0.07s)390--- PASS: TestStreamPushBatchesUnderLoad (0.10s)391--- PASS: TestDumpPathMatchesNix (0.11s)392--- PASS: TestUploadMultipart_PartsInParallel (0.64s)393--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)394PASS395Running server tests...396The files belonging to this database system will be owned by user "nixbld".397This user must also own the server process.398399The database cluster will be initialized with locale "C".400The default database encoding has accordingly been set to "SQL_ASCII".401The default text search configuration will be set to "english".402403Data page checksums are enabled.404405creating directory /build/postgres12451758/data ... ok406creating subdirectories ... ok407selecting dynamic shared memory implementation ... posix408selecting default "max_connections" ... 100409selecting default "shared_buffers" ... 128MB410selecting default time zone ... UTC411creating configuration files ... ok412running bootstrap script ... ok413performing post-bootstrap initialization ... ok414syncing data to disk ... ok415416initdb: warning: enabling "trust" authentication for local connections417initdb: 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.418419Success. You can now start the database server using:420421 pg_ctl -D /build/postgres12451758/data -l logfile start422423/build/postgres12451758:5432 - no response4242026-10-01 13:03:37.758 UTC [128] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit4252026-10-01 13:03:37.758 UTC [128] LOG: listening on Unix socket "/build/postgres12451758/.s.PGSQL.5432"4262026-10-01 13:03:37.762 UTC [135] LOG: database system was shut down at 2026-10-01 13:03:37 UTC4272026-10-01 13:03:37.766 UTC [128] LOG: database system is ready to accept connections428/build/postgres12451758:5432 - accepting connections429{"timestamp":"2026-10-01T13:03:37.95746984Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"ab041b97-aa90-4c3f-a54b-06e6a7c759c3","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(194)"}430=== RUN TestService_AuthMiddleware431=== PAUSE TestService_AuthMiddleware432=== RUN TestService_AuthMiddleware_MTLSProxyHeader433=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader434=== RUN TestService_AuthMiddleware_MTLSBoundSubjects435=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects436=== RUN TestService_ReadAuthMiddleware437=== PAUSE TestService_ReadAuthMiddleware438=== RUN TestService_AuthMiddleware_OIDC439=== PAUSE TestService_AuthMiddleware_OIDC440=== RUN TestService_RequireScope_OIDC441=== PAUSE TestService_RequireScope_OIDC442=== RUN TestService_ReadScope_PublicByDefault443=== PAUSE TestService_ReadScope_PublicByDefault444=== RUN TestCacheConfigHandler445=== PAUSE TestCacheConfigHandler446=== RUN TestCacheStatsHandler447=== PAUSE TestCacheStatsHandler448=== RUN TestClientCADerivations449=== PAUSE TestClientCADerivations450=== RUN TestClientErrorHandling451=== PAUSE TestClientErrorHandling452=== RUN TestClientIntegration453=== PAUSE TestClientIntegration454=== RUN TestClientMultipleUploads455=== PAUSE TestClientMultipleUploads456=== RUN TestClientWithDependencies457=== PAUSE TestClientWithDependencies458=== RUN TestClientSharedPathCommittedMidPush459=== PAUSE TestClientSharedPathCommittedMidPush460=== RUN TestPinProtectsFromGC461=== PAUSE TestPinProtectsFromGC462=== RUN TestClientPushesUseOnePush463=== PAUSE TestClientPushesUseOnePush464=== RUN TestClientFallsBackToClosures465=== PAUSE TestClientFallsBackToClosures466=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock467=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock468=== RUN TestResolveDBConnectionString469=== PAUSE TestResolveDBConnectionString470=== RUN TestConnectWaitsForAPeerMigration471=== PAUSE TestConnectWaitsForAPeerMigration472=== RUN TestLeadElectsOneAndHandsOver473=== PAUSE TestLeadElectsOneAndHandsOver474=== RUN TestLeadIncumbentWinsAfterRestart4752026/10/01 13:03:38 INFO lead: acquired remote=192.0.2.1:12344762026/10/01 13:03:39 INFO lead: released remote=192.0.2.1:12344772026/10/01 13:03:39 INFO lead: acquired remote=192.0.2.1:12344782026/10/01 13:03:40 INFO lead: released remote=192.0.2.1:1234479--- PASS: TestLeadIncumbentWinsAfterRestart (2.32s)480=== RUN TestLeadEndsOnShutdown481=== PAUSE TestLeadEndsOnShutdown482=== RUN TestLeadEndsWhenItsConnectionHangs4832026/10/01 13:03:40 INFO lead: acquired remote=192.0.2.1:12344842026-10-01 13:03:41.890 UTC [379] FATAL: terminating connection due to administrator command4852026/10/01 13:03:42 INFO lead: acquired remote=192.0.2.1:12344862026/10/01 13:03:43 WARN lead: lock connection lost error="timeout: context deadline exceeded"4872026/10/01 13:03:43 INFO lead: released remote=192.0.2.1:12344882026/10/01 13:03:43 INFO lead: released remote=192.0.2.1:1234489--- PASS: TestLeadEndsWhenItsConnectionHangs (3.10s)490=== RUN TestGCAdvisoryLockBlocksConcurrentRun491=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun492=== RUN TestGCBugBareHashReferences493=== PAUSE TestGCBugBareHashReferences494=== RUN TestGCMetrics495=== PAUSE TestGCMetrics496=== RUN TestPushDedupSurvivesConcurrentGC497=== PAUSE TestPushDedupSurvivesConcurrentGC498=== RUN TestDeduplicatedObjectsRecordedAsPending499=== PAUSE TestDeduplicatedObjectsRecordedAsPending500=== RUN TestGCSweepSkipsPendingObjects501=== PAUSE TestGCSweepSkipsPendingObjects502=== RUN TestTombstonedObjectOfferedWithoutWaiting503=== PAUSE TestTombstonedObjectOfferedWithoutWaiting504=== RUN TestGCSweepDeliversEachKeyOnce505=== PAUSE TestGCSweepDeliversEachKeyOnce506=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection507=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection508=== RUN TestForceGCDuringPushOffersSweptObject509=== PAUSE TestForceGCDuringPushOffersSweptObject510=== RUN TestFailedS3DeleteKeepsTombstone511=== PAUSE TestFailedS3DeleteKeepsTombstone512=== RUN TestSweepSkipsRowsLockedByPush513=== PAUSE TestSweepSkipsRowsLockedByPush514=== RUN TestRegisterCompletedObjectNeedsPendingRow515=== PAUSE TestRegisterCompletedObjectNeedsPendingRow516=== RUN TestGetExistingObjectsLocksRows517=== PAUSE TestGetExistingObjectsLocksRows518=== RUN TestSweepRechecksPendingAfterLocking519=== PAUSE TestSweepRechecksPendingAfterLocking520=== RUN TestPushWaitsForSweepHoldingRow521=== PAUSE TestPushWaitsForSweepHoldingRow522=== RUN TestCommitRacingPendingCleanupKeepsObjects523=== PAUSE TestCommitRacingPendingCleanupKeepsObjects524=== RUN TestGCEndsOnShutdown525=== PAUSE TestGCEndsOnShutdown526=== RUN TestGCTaskStore_StartNew527=== PAUSE TestGCTaskStore_StartNew528=== RUN TestGCTaskStore_DeduplicateSameParams529=== PAUSE TestGCTaskStore_DeduplicateSameParams530=== RUN TestGCTaskStore_ConflictDifferentParams531=== PAUSE TestGCTaskStore_ConflictDifferentParams532=== RUN TestGCTaskStore_GetEmpty533=== PAUSE TestGCTaskStore_GetEmpty534=== RUN TestGCTaskStore_GetReturnsLatest535=== PAUSE TestGCTaskStore_GetReturnsLatest536=== RUN TestGCTaskStore_CompletedAllowsNewTask537=== PAUSE TestGCTaskStore_CompletedAllowsNewTask538=== RUN TestGCTaskStore_PhaseUpdates539=== PAUSE TestGCTaskStore_PhaseUpdates540=== RUN TestGCTaskStore_Fail541=== PAUSE TestGCTaskStore_Fail542=== RUN TestGracefulShutdownDrainsInflight543=== PAUSE TestGracefulShutdownDrainsInflight544=== RUN TestService_healthCheckHandler545=== PAUSE TestService_healthCheckHandler546=== RUN TestService_readinessHandler547=== PAUSE TestService_readinessHandler548=== RUN TestGenerateLandingPage549=== PAUSE TestGenerateLandingPage550=== RUN TestCacheConfigHandlerMaxNarSize551=== PAUSE TestCacheConfigHandlerMaxNarSize552=== RUN TestCreatePendingClosureRejectsOversizedNAR553=== PAUSE TestCreatePendingClosureRejectsOversizedNAR554=== RUN TestNARDeduplicationMetadataUploadBug555=== PAUSE TestNARDeduplicationMetadataUploadBug556=== RUN TestMetricsInventory557=== PAUSE TestMetricsInventory558=== RUN TestService_NativeMTLS559=== PAUSE TestService_NativeMTLS560=== RUN TestServerTLSConfig561=== PAUSE TestServerTLSConfig562=== RUN TestMultipartCleanup563=== PAUSE TestMultipartCleanup564=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded565=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded566=== RUN TestPendingCleanupUsesOneCutoff567=== PAUSE TestPendingCleanupUsesOneCutoff568=== RUN TestObjectStatsTrigger569=== PAUSE TestObjectStatsTrigger570=== RUN TestOrphanedObjectsGC571=== PAUSE TestOrphanedObjectsGC572=== RUN TestOrphanedObjectsGCStressTest573=== PAUSE TestOrphanedObjectsGCStressTest574=== RUN TestCreatePin_ReservedPins575=== PAUSE TestCreatePin_ReservedPins576=== RUN TestPresentReportsOnlyClosureRoots577=== PAUSE TestPresentReportsOnlyClosureRoots578=== RUN TestPresentNotReportedWhileGCDeletesClosure579=== PAUSE TestPresentNotReportedWhileGCDeletesClosure580=== RUN TestParseSingleRange581=== PAUSE TestParseSingleRange582=== RUN TestProxyHeadersOnlyTrustedOnSocket583=== PAUSE TestProxyHeadersOnlyTrustedOnSocket584=== RUN TestIsValidCachePath585=== PAUSE TestIsValidCachePath586=== RUN TestReadProxyNarinfo587=== PAUSE TestReadProxyNarinfo588=== RUN TestReadProxyNarinfoAlreadyDecompressed589=== PAUSE TestReadProxyNarinfoAlreadyDecompressed590=== RUN TestReadProxyNarStreaming591=== PAUSE TestReadProxyNarStreaming592=== RUN TestReadProxy404593=== PAUSE TestReadProxy404594=== RUN TestReadProxyInvalidPath595=== PAUSE TestReadProxyInvalidPath596=== RUN TestReadProxyHead597=== PAUSE TestReadProxyHead598=== RUN TestReadProxyOutlastsServerWriteTimeout599=== PAUSE TestReadProxyOutlastsServerWriteTimeout600=== RUN TestReadProxyConditionalGet601=== PAUSE TestReadProxyConditionalGet602=== RUN TestReadProxyRootRedirectsToIndexHTML603=== PAUSE TestReadProxyRootRedirectsToIndexHTML604=== RUN TestReadProxyDisabled605=== PAUSE TestReadProxyDisabled606=== RUN TestReadRedirectNar607=== PAUSE TestReadRedirectNar608=== RUN TestReadRedirectKeepsNarinfoProxied609=== PAUSE TestReadRedirectKeepsNarinfoProxied610=== RUN TestReadProxyRangeRequest611=== PAUSE TestReadProxyRangeRequest612=== RUN TestReadRedirectUsesPublicS3URL613=== PAUSE TestReadRedirectUsesPublicS3URL614=== RUN TestPush_OverlappingRootsStoreOneRowPerKey615=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey616=== RUN TestPush_CompleteCommitsEveryRoot617=== PAUSE TestPush_CompleteCommitsEveryRoot618=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit619=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit620=== RUN TestPush_RejectsBadRequests621=== PAUSE TestPush_RejectsBadRequests622=== RUN TestPush_SignsNarinfosOfItsPendingObjects623=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects624=== RUN TestRedundantMultipartUpload625=== PAUSE TestRedundantMultipartUpload626=== RUN TestCompleteMultipartUpload_ErrorButObjectExists627=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists628=== RUN TestCompletedNarNotReofferedAcrossClosures629=== PAUSE TestCompletedNarNotReofferedAcrossClosures630=== RUN TestPresignedUploadRegisteredBeforeCommit631=== PAUSE TestPresignedUploadRegisteredBeforeCommit632=== RUN TestService_Rustfstest633=== PAUSE TestService_Rustfstest634=== RUN TestParseSize635=== PAUSE TestParseSize636=== RUN TestSkippedUploadsHandler637=== PAUSE TestSkippedUploadsHandler638=== RUN TestSystemdListenerNotActivated639--- PASS: TestSystemdListenerNotActivated (0.00s)640=== RUN TestWatchdogBeatsWhenHealthy641--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)642=== RUN TestWatchdogSkipsWhenUnhealthy6432026/10/01 13:03:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6442026/10/01 13:03:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6452026/10/01 13:03:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6462026/10/01 13:03:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6472026/10/01 13:03:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6482026/10/01 13:03:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6492026/10/01 13:03:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6502026/10/01 13:03:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6512026/10/01 13:03:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6522026/10/01 13:03:43 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"653--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)654=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle655=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle656=== RUN TestProxyWriteTimeout657=== PAUSE TestProxyWriteTimeout658=== RUN TestPendingClosureWriteTimeout659=== PAUSE TestPendingClosureWriteTimeout660=== RUN TestIsValidUploadKey661=== PAUSE TestIsValidUploadKey662=== RUN TestUploadHandlersRejectInvalidKeys663=== PAUSE TestUploadHandlersRejectInvalidKeys664=== RUN TestUploadHandlersRejectOversizedBody665=== PAUSE TestUploadHandlersRejectOversizedBody666=== RUN TestService_cleanupPendingClosuresHandler667=== PAUSE TestService_cleanupPendingClosuresHandler668=== RUN TestService_createPendingClosureHandler669=== PAUSE TestService_createPendingClosureHandler670=== RUN TestService_verifyS3Integrity671=== PAUSE TestService_verifyS3Integrity672=== RUN TestCompleteMultipartUnregistered673=== PAUSE TestCompleteMultipartUnregistered674=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT675=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT676=== CONT TestSkippedUploadsHandler677=== CONT TestUploadHandlersRejectOversizedBody678=== CONT TestService_verifyS3Integrity679=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit680=== CONT TestParseSize681--- PASS: TestParseSize (0.00s)682=== CONT TestReadProxy404683=== CONT TestService_Rustfstest684=== CONT TestPresignedUploadRegisteredBeforeCommit6852026/10/01 13:03:43 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000686=== CONT TestCompletedNarNotReofferedAcrossClosures687=== CONT TestCompleteMultipartUpload_ErrorButObjectExists688=== CONT TestRedundantMultipartUpload689=== CONT TestPush_RejectsBadRequests690=== CONT TestPush_CompleteCommitsEveryRoot691=== CONT TestPush_OverlappingRootsStoreOneRowPerKey692=== CONT TestReadRedirectUsesPublicS3URL693=== CONT TestReadProxyRangeRequest694=== CONT TestReadRedirectKeepsNarinfoProxied695=== CONT TestReadRedirectNar696=== CONT TestReadProxyDisabled697=== CONT TestReadProxyRootRedirectsToIndexHTML698=== CONT TestReadProxyConditionalGet699=== CONT TestReadProxyOutlastsServerWriteTimeout700=== CONT TestReadProxyHead701=== CONT TestReadProxyInvalidPath702=== CONT TestService_AuthMiddleware703--- PASS: TestSkippedUploadsHandler (0.01s)704=== CONT TestReadProxyNarStreaming705=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts706=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts707=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure708=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure709=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart710=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart711=== CONT TestReadProxyNarinfoAlreadyDecompressed7122026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures713--- PASS: TestService_Rustfstest (0.25s)714=== CONT TestReadProxyNarinfo7152026/10/01 13:03:43 INFO Received uploads request method=POST path=/api/pending_closures7162026/10/01 13:03:44 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst7172026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures718--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.29s)719=== CONT TestIsValidCachePath720=== RUN TestIsValidCachePath/narinfo7212026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures722=== PAUSE TestIsValidCachePath/narinfo723=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars724=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars725=== RUN TestIsValidCachePath/nar_zst726=== PAUSE TestIsValidCachePath/nar_zst727=== RUN TestIsValidCachePath/nar_xz728=== PAUSE TestIsValidCachePath/nar_xz729=== RUN TestIsValidCachePath/nar_bz2730=== PAUSE TestIsValidCachePath/nar_bz2731=== RUN TestIsValidCachePath/nar_uncompressed732=== PAUSE TestIsValidCachePath/nar_uncompressed733=== RUN TestIsValidCachePath/ls734=== PAUSE TestIsValidCachePath/ls735=== RUN TestIsValidCachePath/log736=== PAUSE TestIsValidCachePath/log737=== RUN TestIsValidCachePath/realisation738=== PAUSE TestIsValidCachePath/realisation739=== RUN TestIsValidCachePath/nix-cache-info740=== PAUSE TestIsValidCachePath/nix-cache-info741=== RUN TestIsValidCachePath/index.html742=== PAUSE TestIsValidCachePath/index.html743=== RUN TestIsValidCachePath/traversal_parent744=== PAUSE TestIsValidCachePath/traversal_parent745=== RUN TestIsValidCachePath/traversal_in_middle746=== PAUSE TestIsValidCachePath/traversal_in_middle747=== RUN TestIsValidCachePath/invalid_char_e748=== PAUSE TestIsValidCachePath/invalid_char_e749=== RUN TestIsValidCachePath/invalid_char_u750=== PAUSE TestIsValidCachePath/invalid_char_u751=== RUN TestIsValidCachePath/random_path752=== PAUSE TestIsValidCachePath/random_path753=== RUN TestIsValidCachePath/empty754=== PAUSE TestIsValidCachePath/empty755=== RUN TestIsValidCachePath/leading_slash756=== PAUSE TestIsValidCachePath/leading_slash757=== RUN TestIsValidCachePath/wrong_extension758=== PAUSE TestIsValidCachePath/wrong_extension759=== RUN TestIsValidCachePath/short_hash760=== PAUSE TestIsValidCachePath/short_hash761=== CONT TestProxyHeadersOnlyTrustedOnSocket7622026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures7632026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures7642026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures7652026/10/01 13:03:44 INFO Received push request method=POST path=/api/pushes7662026/10/01 13:03:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete7672026/10/01 13:03:44 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGZmNGFiODEtOWRhYy00OTY3LWJlN2MtNDFjNjA2M2Y1YjU2LmEyYjliZDlmLWJjOGUtNDA5Mi04NGJiLTRmOGE3NTI0ZDJiZXgxNzkwODU5ODI0MDQ5NzE1NDgz7682026/10/01 13:03:44 INFO Received complete push request method=POST path=/api/pushes/1/complete7692026/10/01 13:03:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OGZmNGFiODEtOWRhYy00OTY3LWJlN2MtNDFjNjA2M2Y1YjU2LmEyYjliZDlmLWJjOGUtNDA5Mi04NGJiLTRmOGE3NTI0ZDJiZXgxNzkwODU5ODI0MDQ5NzE1NDgz parts=1770=== RUN TestPush_RejectsBadRequests/no_roots771=== PAUSE TestPush_RejectsBadRequests/no_roots772=== RUN TestPush_RejectsBadRequests/no_objects773=== PAUSE TestPush_RejectsBadRequests/no_objects774=== RUN TestPush_RejectsBadRequests/bad_root775=== PAUSE TestPush_RejectsBadRequests/bad_root776=== RUN TestPush_RejectsBadRequests/root_not_in_objects777=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects778=== CONT TestParseSingleRange779=== RUN TestParseSingleRange/none780=== PAUSE TestParseSingleRange/none781=== RUN TestParseSingleRange/unknown_unit782=== PAUSE TestParseSingleRange/unknown_unit783=== RUN TestParseSingleRange/multi-range_ignored784=== PAUSE TestParseSingleRange/multi-range_ignored785=== RUN TestParseSingleRange/malformed_no_dash786=== PAUSE TestParseSingleRange/malformed_no_dash787=== RUN TestParseSingleRange/malformed_both_empty788=== PAUSE TestParseSingleRange/malformed_both_empty789=== RUN TestParseSingleRange/malformed_end_before_start790=== PAUSE TestParseSingleRange/malformed_end_before_start791=== RUN TestParseSingleRange/closed792=== PAUSE TestParseSingleRange/closed793=== RUN TestParseSingleRange/open-ended794=== PAUSE TestParseSingleRange/open-ended795=== RUN TestParseSingleRange/end_clamped_to_size796=== PAUSE TestParseSingleRange/end_clamped_to_size797=== RUN TestParseSingleRange/suffix798=== PAUSE TestParseSingleRange/suffix799=== RUN TestParseSingleRange/suffix_exceeds_size800=== PAUSE TestParseSingleRange/suffix_exceeds_size801=== RUN TestParseSingleRange/single_byte802=== PAUSE TestParseSingleRange/single_byte803=== RUN TestParseSingleRange/start_past_EOF804=== PAUSE TestParseSingleRange/start_past_EOF805=== RUN TestParseSingleRange/start_far_past_EOF806=== PAUSE TestParseSingleRange/start_far_past_EOF807=== CONT TestPresentNotReportedWhileGCDeletesClosure808=== CONT TestPresentReportsOnlyClosureRoots809--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.36s)8102026/10/01 13:03:44 INFO Received push request method=POST path=/api/pushes8112026/10/01 13:03:44 INFO Received push request method=POST path=/api/pushes812--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.40s)813=== CONT TestCreatePin_ReservedPins8142026/10/01 13:03:44 INFO Received push request method=POST path=/api/pushes8152026/10/01 13:03:44 INFO Received complete push request method=POST path=/api/pushes/1/complete8162026/10/01 13:03:44 INFO Aborted multipart uploads count=0 kept=08172026/10/01 13:03:44 WARN Force mode enabled - objects will be deleted immediately without grace period818--- PASS: TestPush_CompleteCommitsEveryRoot (0.43s)819=== CONT TestOrphanedObjectsGCStressTest8202026/10/01 13:03:44 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=2 objects-deleted-after-grace-period=2 objects-failed-to-delete=08212026/10/01 13:03:44 INFO Vacuumed table table=pending_closures8222026/10/01 13:03:44 INFO Vacuumed table table=pending_objects8232026/10/01 13:03:44 INFO Vacuumed table table=multipart_uploads8242026/10/01 13:03:44 INFO Vacuumed table table=closures8252026/10/01 13:03:44 INFO Vacuumed table table=objects826--- PASS: TestReadProxy404 (0.45s)827=== CONT TestOrphanedObjectsGC8282026/10/01 13:03:44 INFO Received complete push request method=POST path=/api/pushes/2/complete829--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.46s)830=== CONT TestObjectStatsTrigger831--- PASS: TestReadRedirectUsesPublicS3URL (0.46s)832=== CONT TestPendingCleanupUsesOneCutoff833--- PASS: TestReadProxyRangeRequest (0.47s)834=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded8352026/10/01 13:03:44 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36457/oidc8362026/10/01 13:03:44 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"837--- PASS: TestService_AuthMiddleware (0.41s)838=== CONT TestMultipartCleanup839--- PASS: TestReadProxyNarStreaming (0.44s)840=== CONT TestServerTLSConfig841=== RUN TestServerTLSConfig/no_client_CA842=== PAUSE TestServerTLSConfig/no_client_CA843=== RUN TestServerTLSConfig/missing_CA_file844=== PAUSE TestServerTLSConfig/missing_CA_file845=== RUN TestServerTLSConfig/not_a_PEM_file846=== PAUSE TestServerTLSConfig/not_a_PEM_file847=== CONT TestService_NativeMTLS848--- PASS: TestReadProxyHead (0.46s)849=== CONT TestMetricsInventory850--- PASS: TestReadProxyInvalidPath (0.48s)851=== CONT TestNARDeduplicationMetadataUploadBug852--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.50s)853=== CONT TestCreatePendingClosureRejectsOversizedNAR8542026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures855--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)856=== CONT TestCacheConfigHandlerMaxNarSize857--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)858=== CONT TestGenerateLandingPage8592026/10/01 13:03:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete860--- PASS: TestGenerateLandingPage (0.00s)861=== CONT TestService_readinessHandler8622026/10/01 13:03:44 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OGZmNGFiODEtOWRhYy00OTY3LWJlN2MtNDFjNjA2M2Y1YjU2LjAxMzVhMTcxLTdlNzQtNGU5NS04OWNiLTFlN2FlZDQ4YmE1ZHgxNzkwODU5ODIzOTUzNzg3NDMy parts=128632026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures864--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.60s)865=== CONT TestService_healthCheckHandler866--- PASS: TestReadRedirectKeepsNarinfoProxied (0.53s)867=== CONT TestGracefulShutdownDrainsInflight8682026/10/01 13:03:44 INFO Starting HTTP server address=127.0.0.1:440938692026/10/01 13:03:44 INFO Shutdown signal received, draining in-flight requests timeout=10s8702026/10/01 13:03:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete871--- PASS: TestReadProxyDisabled (0.55s)872=== CONT TestGCTaskStore_Fail873--- PASS: TestGCTaskStore_Fail (0.00s)874=== CONT TestGCTaskStore_PhaseUpdates875--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)876=== CONT TestGCTaskStore_CompletedAllowsNewTask877--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)878=== CONT TestGCTaskStore_GetReturnsLatest879--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)880=== CONT TestGCTaskStore_GetEmpty881--- PASS: TestGCTaskStore_GetEmpty (0.00s)882=== CONT TestGCTaskStore_ConflictDifferentParams883--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)884=== CONT TestGCTaskStore_DeduplicateSameParams885--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)886=== CONT TestGCTaskStore_StartNew887--- PASS: TestGCTaskStore_StartNew (0.00s)888=== CONT TestGCEndsOnShutdown8892026/10/01 13:03:44 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OGZmNGFiODEtOWRhYy00OTY3LWJlN2MtNDFjNjA2M2Y1YjU2LmUwZjQyNDY3LTMyZTctNGYwNC1hZTE3LTA0M2I0OWQxZWE1M3gxNzkwODU5ODI0MDM2MzU1OTA1 parts=108902026/10/01 13:03:44 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8912026/10/01 13:03:44 INFO Completed upload id=18922026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures8932026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures8942026/10/01 13:03:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8952026/10/01 13:03:44 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8962026/10/01 13:03:44 WARN Found objects in DB but missing from S3, will re-upload count=1897--- PASS: TestService_verifyS3Integrity (0.64s)898=== CONT TestPendingClosureWriteTimeout899=== RUN TestPendingClosureWriteTimeout/empty900=== PAUSE TestPendingClosureWriteTimeout/empty901=== RUN TestPendingClosureWriteTimeout/400_objects902=== PAUSE TestPendingClosureWriteTimeout/400_objects903=== RUN TestPendingClosureWriteTimeout/670k_objects904=== PAUSE TestPendingClosureWriteTimeout/670k_objects905=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline906=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline907=== CONT TestUploadHandlersRejectInvalidKeys908=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info909=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info910=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal911=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal912=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key913=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key914=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key915=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key916=== CONT TestIsValidUploadKey917=== RUN TestIsValidUploadKey/narinfo918=== PAUSE TestIsValidUploadKey/narinfo919=== RUN TestIsValidUploadKey/nar_zst920=== PAUSE TestIsValidUploadKey/nar_zst921=== RUN TestIsValidUploadKey/nar_xz922=== PAUSE TestIsValidUploadKey/nar_xz923=== RUN TestIsValidUploadKey/nar_plain924=== PAUSE TestIsValidUploadKey/nar_plain925=== RUN TestIsValidUploadKey/listing926=== PAUSE TestIsValidUploadKey/listing927=== RUN TestIsValidUploadKey/build_log928=== PAUSE TestIsValidUploadKey/build_log929=== RUN TestIsValidUploadKey/build_log_home-manager_file930=== PAUSE TestIsValidUploadKey/build_log_home-manager_file931=== RUN TestIsValidUploadKey/build_log_plus_in_name932=== PAUSE TestIsValidUploadKey/build_log_plus_in_name933=== RUN TestIsValidUploadKey/build_log_question_mark934=== PAUSE TestIsValidUploadKey/build_log_question_mark935=== RUN TestIsValidUploadKey/build_log_equals936=== PAUSE TestIsValidUploadKey/build_log_equals937=== RUN TestIsValidUploadKey/realisation938=== PAUSE TestIsValidUploadKey/realisation939=== RUN TestIsValidUploadKey/realisation_plus_in_output940=== PAUSE TestIsValidUploadKey/realisation_plus_in_output941=== RUN TestIsValidUploadKey/nix-cache-info942=== PAUSE TestIsValidUploadKey/nix-cache-info943=== RUN TestIsValidUploadKey/index.html944=== PAUSE TestIsValidUploadKey/index.html945=== RUN TestIsValidUploadKey/narinfo_key,_nar_type946=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type947=== RUN TestIsValidUploadKey/nar_key,_narinfo_type948=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type949=== RUN TestIsValidUploadKey/listing_key,_narinfo_type950=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type951=== RUN TestIsValidUploadKey/traversal952=== PAUSE TestIsValidUploadKey/traversal953=== RUN TestIsValidUploadKey/traversal_nar954=== PAUSE TestIsValidUploadKey/traversal_nar955=== RUN TestIsValidUploadKey/absolute956=== PAUSE TestIsValidUploadKey/absolute957=== RUN TestIsValidUploadKey/empty_key958=== PAUSE TestIsValidUploadKey/empty_key959=== RUN TestIsValidUploadKey/unknown_type960=== PAUSE TestIsValidUploadKey/unknown_type961=== CONT TestCommitRacingPendingCleanupKeepsObjects9622026/10/01 13:03:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OGZmNGFiODEtOWRhYy00OTY3LWJlN2MtNDFjNjA2M2Y1YjU2LjExNWYzZGM4LTEwZTItNDY4MS1hYjA4LTY0MTQwNTFkODJhZngxNzkwODU5ODI0MDExNzU2MTI2 parts=129632026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures9642026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures965--- PASS: TestReadRedirectNar (0.59s)966=== CONT TestPushWaitsForSweepHoldingRow967--- PASS: TestGracefulShutdownDrainsInflight (0.07s)968=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT969--- PASS: TestReadProxyConditionalGet (0.61s)970=== CONT TestSweepRechecksPendingAfterLocking971--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.54s)972=== CONT TestProxyWriteTimeout973=== RUN TestProxyWriteTimeout/narinfo974=== PAUSE TestProxyWriteTimeout/narinfo975=== RUN TestProxyWriteTimeout/1_GiB_nar976=== PAUSE TestProxyWriteTimeout/1_GiB_nar977=== RUN TestProxyWriteTimeout/10_GiB_nar978=== PAUSE TestProxyWriteTimeout/10_GiB_nar979=== RUN TestProxyWriteTimeout/unknown_size980=== PAUSE TestProxyWriteTimeout/unknown_size981=== CONT TestGetExistingObjectsLocksRows9822026/10/01 13:03:44 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3343090324/001/proxy.sock9832026/10/01 13:03:44 INFO Starting HTTP server address=127.0.0.1:422439842026/10/01 13:03:44 WARN mTLS auth: subject not in bound subjects subject="CN=someone"9852026/10/01 13:03:44 INFO Shutdown signal received, draining in-flight requests timeout=10s986--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.45s)987=== CONT TestRegisterCompletedObjectNeedsPendingRow9882026/10/01 13:03:44 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"989--- PASS: TestPresentReportsOnlyClosureRoots (0.44s)990=== CONT TestClientFallsBackToClosures991--- PASS: TestObjectStatsTrigger (0.40s)992=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock9932026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures9942026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures9952026/10/01 13:03:44 INFO Received cleanup request method=DELETE path=/api/pending_closures9962026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures9972026/10/01 13:03:44 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216998--- PASS: TestReadProxyNarinfo (0.65s)999=== CONT TestClientPushesUseOnePush1000--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.44s)1001=== CONT TestSweepSkipsRowsLockedByPush10022026/10/01 13:03:44 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10032026/10/01 13:03:44 WARN Refused reserved pin name=worker-x86_64-linux10042026/10/01 13:03:44 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10052026/10/01 13:03:44 INFO Received create pin request method=POST path=/api/pins/my-app10062026/10/01 13:03:44 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1007--- PASS: TestCreatePin_ReservedPins (0.53s)1008=== CONT TestCacheConfigHandler1009=== RUN TestCacheConfigHandler/full_config,_no_issuer1010=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1011=== RUN TestCacheConfigHandler/no_cache_url_configured1012=== PAUSE TestCacheConfigHandler/no_cache_url_configured1013=== RUN TestCacheConfigHandler/no_signing_keys1014=== PAUSE TestCacheConfigHandler/no_signing_keys1015=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1016=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1017=== CONT TestFailedS3DeleteKeepsTombstone10182026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures10192026/10/01 13:03:44 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10202026/10/01 13:03:44 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1021--- PASS: TestService_NativeMTLS (0.45s)1022=== CONT TestService_ReadScope_PublicByDefault1023--- PASS: TestMetricsInventory (0.45s)1024=== CONT TestForceGCDuringPushOffersSweptObject1025=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1026=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1027=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1028=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1029=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10302026/10/01 13:03:44 WARN readiness check failed error="closed pool"1031--- PASS: TestService_readinessHandler (0.44s)1032=== CONT TestService_RequireScope_OIDC1033=== NAME TestNARDeduplicationMetadataUploadBug1034 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug680974501/001/store/45qad2fbjgbsqbqkvx1al5d1i0qr5m52-file1.txt1035--- PASS: TestService_healthCheckHandler (0.44s)1036=== CONT TestGCSweepDeliversEachKeyOnce10372026/10/01 13:03:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10382026/10/01 13:03:44 INFO Received cleanup request method=DELETE path=/api/pending_closures10392026/10/01 13:03:44 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket37/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10402026/10/01 13:03:44 INFO Aborted multipart uploads count=0 kept=110412026/10/01 13:03:44 INFO Received cleanup request method=DELETE path=/api/pending_closures10422026/10/01 13:03:44 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OGZmNGFiODEtOWRhYy00OTY3LWJlN2MtNDFjNjA2M2Y1YjU2LmI0NDIxYzA5LWI4OTQtNDkwYi1iZWFmLThiZmZiZmMyYjIzN3gxNzkwODU5ODI0MzgxNTQyNjQ5 error="Get \"http://127.0.0.1:1/bucket6/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10432026/10/01 13:03:44 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OGZmNGFiODEtOWRhYy00OTY3LWJlN2MtNDFjNjA2M2Y1YjU2LjIyMjQ1NGExLTFhM2ItNGZmNi04MmI5LWIwNWJmNjMzOWYyNHgxNzkwODU5ODI0Mzc1MjMzMzkz parts=1210442026/10/01 13:03:44 INFO Aborted multipart uploads count=1 kept=010452026/10/01 13:03:44 INFO Received cleanup request method=DELETE path=/api/pending_closures10462026/10/01 13:03:44 INFO Aborted multipart uploads count=1 kept=01047--- PASS: TestMultipartCleanup (0.58s)1048=== CONT TestService_AuthMiddleware_OIDC1049--- PASS: TestRedundantMultipartUpload (1.07s)1050=== CONT TestTombstonedObjectOfferedWithoutWaiting1051--- PASS: TestGCEndsOnShutdown (0.45s)1052=== CONT TestService_ReadAuthMiddleware10532026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures10542026/10/01 13:03:44 INFO Aborted multipart uploads count=0 kept=010552026/10/01 13:03:44 INFO Received push request method=POST path=/api/pushes10562026/10/01 13:03:44 WARN Force mode enabled - objects will be deleted immediately without grace period10572026/10/01 13:03:44 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10582026/10/01 13:03:44 INFO Uploading 45qad2fbjgbsqbqkvx1al5d1i0qr5m52-file1.txt (160B)10592026/10/01 13:03:44 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=010602026/10/01 13:03:44 INFO Vacuumed table table=pending_closures10612026/10/01 13:03:44 INFO Received uploads request method=POST path=/api/pending_closures10622026/10/01 13:03:44 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10632026/10/01 13:03:44 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10642026/10/01 13:03:44 INFO Vacuumed table table=pending_objects10652026/10/01 13:03:44 WARN Failed to register uploaded object key=45qad2fbjgbsqbqkvx1al5d1i0qr5m52.ls error="server returned 404: 404 page not found\n"10662026/10/01 13:03:44 INFO Signed narinfos id=1 count=110672026/10/01 13:03:44 INFO Vacuumed table table=multipart_uploads10682026/10/01 13:03:44 INFO Uploading 1 narinfos10692026/10/01 13:03:44 INFO Vacuumed table table=closures10702026/10/01 13:03:44 INFO Vacuumed table table=objects10712026/10/01 13:03:44 INFO Received complete push request method=POST path=/api/pushes/1/complete10722026/10/01 13:03:44 WARN Failed to register uploaded object key=45qad2fbjgbsqbqkvx1al5d1i0qr5m52.narinfo error="server returned 404: 404 page not found\n"1073--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.46s)1074=== CONT TestGCSweepSkipsPendingObjects10752026/10/01 13:03:44 INFO Upload complete. (58ms)1076--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.50s)1077=== CONT TestDeduplicatedObjectsRecordedAsPending1078=== NAME TestNARDeduplicationMetadataUploadBug1079 metadata_upload_test.go:54: Retrieved narinfo from S3:1080 StorePath: /build/TestNARDeduplicationMetadataUploadBug680974501/001/store/45qad2fbjgbsqbqkvx1al5d1i0qr5m52-file1.txt1081 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1082 Compression: zstd1083 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1084 NarSize: 1601085 References: 1086 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1087 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1088 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1089 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}10902026/10/01 13:03:44 INFO Aborted multipart uploads count=0 kept=010912026/10/01 13:03:44 WARN Force mode enabled - objects will be deleted immediately without grace period10922026/10/01 13:03:44 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=01093 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug680974501/001/store/zvj882ldczkbalfi8chg776d1h1pw37i-file2.txt10942026/10/01 13:03:44 INFO Vacuumed table table=pending_closures1095--- PASS: TestGetExistingObjectsLocksRows (0.47s)1096=== CONT TestPushDedupSurvivesConcurrentGC10972026/10/01 13:03:44 INFO Vacuumed table table=pending_objects10982026/10/01 13:03:44 INFO Vacuumed table table=multipart_uploads10992026/10/01 13:03:44 INFO Vacuumed table table=closures11002026/10/01 13:03:44 INFO Vacuumed table table=objects1101--- PASS: TestSweepRechecksPendingAfterLocking (0.49s)1102=== CONT TestService_AuthMiddleware_MTLSProxyHeader1103--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.44s)1104=== CONT TestCacheStatsHandler1105=== NAME TestOrphanedObjectsGC1106 orphaned_objects_gc_test.go:290: GC Test Summary:1107 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1108 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1109 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1110 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1111 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1112--- PASS: TestOrphanedObjectsGC (0.75s)1113=== CONT TestService_cleanupPendingClosuresHandler11142026/10/01 13:03:44 INFO Received push request method=POST path=/api/pushes11152026/10/01 13:03:44 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11162026/10/01 13:03:44 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11172026/10/01 13:03:44 INFO Signed narinfos id=2 count=111182026/10/01 13:03:44 WARN Failed to register uploaded object key=zvj882ldczkbalfi8chg776d1h1pw37i.ls error="server returned 404: 404 page not found\n"11192026/10/01 13:03:44 INFO Uploading 1 narinfos11202026/10/01 13:03:44 INFO Received complete push request method=POST path=/api/pushes/2/complete11212026/10/01 13:03:44 WARN Failed to register uploaded object key=zvj882ldczkbalfi8chg776d1h1pw37i.narinfo error="server returned 404: 404 page not found\n"11222026/10/01 13:03:44 INFO Upload complete. (50ms)1123=== NAME TestNARDeduplicationMetadataUploadBug1124 metadata_upload_test.go:76: Retrieved narinfo from S3:1125 StorePath: /build/TestNARDeduplicationMetadataUploadBug680974501/001/store/zvj882ldczkbalfi8chg776d1h1pw37i-file2.txt1126 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1127 Compression: zstd1128 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1129 NarSize: 1601130 References: 1131 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1132 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1133 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1134 {"version":1,"root":{"type":"regular","size":44}}1135--- PASS: TestNARDeduplicationMetadataUploadBug (0.72s)1136=== CONT TestService_createPendingClosureHandler1137--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.91s)1138=== CONT TestGCMetrics11392026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=011402026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period11412026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures11422026/10/01 13:03:45 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=011432026/10/01 13:03:45 INFO Vacuumed table table=pending_closures11442026/10/01 13:03:45 INFO Vacuumed table table=pending_objects11452026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads11462026/10/01 13:03:45 INFO Vacuumed table table=closures11472026/10/01 13:03:45 INFO Vacuumed table table=objects11482026/10/01 13:03:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39733/oidc11492026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=011502026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period1151--- PASS: TestService_ReadScope_PublicByDefault (0.36s)1152=== CONT TestService_AuthMiddleware_MTLSBoundSubjects11532026/10/01 13:03:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=1 objects-failed-to-delete=011542026/10/01 13:03:45 INFO Vacuumed table table=pending_closures11552026/10/01 13:03:45 INFO Vacuumed table table=pending_objects11562026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads11572026/10/01 13:03:45 INFO Vacuumed table table=closures11582026/10/01 13:03:45 INFO Vacuumed table table=objects1159--- PASS: TestSweepSkipsRowsLockedByPush (0.41s)1160=== CONT TestCompleteMultipartUnregistered11612026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures11622026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=011632026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period1164--- PASS: TestService_ReadAuthMiddleware (0.31s)1165=== CONT TestGCBugBareHashReferences11662026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=011672026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period11682026/10/01 13:03:45 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."11692026/10/01 13:03:45 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1170--- PASS: TestFailedS3DeleteKeepsTombstone (0.46s)1171=== CONT TestPinProtectsFromGC11722026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures11732026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures11742026/10/01 13:03:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=011752026/10/01 13:03:45 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11762026/10/01 13:03:45 INFO Uploading 7sqhc2dar5c77fflzldih1iwgfii2vna-shared-dep (136B)11772026/10/01 13:03:45 INFO Uploading 758kbvimsmh0h85djl9xl7pb5nh8cdhb-a (216B)11782026/10/01 13:03:45 INFO Vacuumed table table=pending_closures11792026/10/01 13:03:45 INFO Vacuumed table table=pending_objects11802026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads11812026/10/01 13:03:45 INFO Vacuumed table table=closures11822026/10/01 13:03:45 WARN Failed to register uploaded object key=5af2799h2w6wyair97q1vq0krz3nqq47.ls error="server returned 404: 404 page not found\n"11832026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures11842026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/1wm5zkdrjbx1fpbrxnds3l6z2k23s4wz1p711vd0ksvn6p0s7rsf.nar.zst error="server returned 404: 404 page not found\n"11852026/10/01 13:03:45 WARN Failed to register uploaded object key=758kbvimsmh0h85djl9xl7pb5nh8cdhb.ls error="server returned 404: 404 page not found\n"11862026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11872026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11882026/10/01 13:03:45 WARN Failed to register uploaded object key=7sqhc2dar5c77fflzldih1iwgfii2vna.ls error="server returned 404: 404 page not found\n"11892026/10/01 13:03:45 INFO Signed narinfos id=1 count=211902026/10/01 13:03:45 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34715/oidc11912026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11922026/10/01 13:03:45 INFO Signed narinfos id=2 count=211932026/10/01 13:03:45 INFO Uploading 4 narinfos11942026/10/01 13:03:45 INFO Vacuumed table table=objects1195--- PASS: TestGCSweepDeliversEachKeyOnce (0.36s)1196=== CONT TestGCAdvisoryLockBlocksConcurrentRun11972026/10/01 13:03:45 WARN Failed to register uploaded object key=7sqhc2dar5c77fflzldih1iwgfii2vna.narinfo error="server returned 404: 404 page not found\n"11982026/10/01 13:03:45 WARN Failed to register uploaded object key=758kbvimsmh0h85djl9xl7pb5nh8cdhb.narinfo error="server returned 404: 404 page not found\n"11992026/10/01 13:03:45 WARN Failed to register uploaded object key=5af2799h2w6wyair97q1vq0krz3nqq47.narinfo error="server returned 404: 404 page not found\n"1200--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.34s)1201=== CONT TestClientMultipleUploads12022026/10/01 13:03:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12032026/10/01 13:03:45 WARN Failed to register uploaded object key=7sqhc2dar5c77fflzldih1iwgfii2vna.narinfo error="server returned 404: 404 page not found\n"12042026/10/01 13:03:45 INFO Completed upload id=112052026/10/01 13:03:45 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12062026/10/01 13:03:45 INFO Completed upload id=212072026/10/01 13:03:45 INFO Upload complete. (64ms)1208=== NAME TestClientFallsBackToClosures1209 client_pushes_test.go:112: Retrieved narinfo from S3:1210 StorePath: /build/TestClientFallsBackToClosures3066204947/001/store/7sqhc2dar5c77fflzldih1iwgfii2vna-shared-dep1211 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1212 Compression: zstd1213 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821214 NarSize: 1361215 References: 1216 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1217 client_pushes_test.go:112: Retrieved narinfo from S3:1218 StorePath: /build/TestClientFallsBackToClosures3066204947/001/store/758kbvimsmh0h85djl9xl7pb5nh8cdhb-a1219 URL: nar/1wm5zkdrjbx1fpbrxnds3l6z2k23s4wz1p711vd0ksvn6p0s7rsf.nar.zst1220 Compression: zstd1221 NarHash: sha256:1wm5zkdrjbx1fpbrxnds3l6z2k23s4wz1p711vd0ksvn6p0s7rsf1222 NarSize: 2161223 References: /build/TestClientFallsBackToClosures3066204947/001/store/7sqhc2dar5c77fflzldih1iwgfii2vna-shared-dep1224 CA: text:sha256:06yy6pamqv0vs2q4g96d90l1jx87wxcm5msnighijfalnawi2mq31225 client_pushes_test.go:112: Retrieved narinfo from S3:1226 StorePath: /build/TestClientFallsBackToClosures3066204947/001/store/5af2799h2w6wyair97q1vq0krz3nqq47-b1227 URL: nar/1wm5zkdrjbx1fpbrxnds3l6z2k23s4wz1p711vd0ksvn6p0s7rsf.nar.zst1228 Compression: zstd1229 NarHash: sha256:1wm5zkdrjbx1fpbrxnds3l6z2k23s4wz1p711vd0ksvn6p0s7rsf1230 NarSize: 2161231 References: /build/TestClientFallsBackToClosures3066204947/001/store/7sqhc2dar5c77fflzldih1iwgfii2vna-shared-dep1232 CA: text:sha256:06yy6pamqv0vs2q4g96d90l1jx87wxcm5msnighijfalnawi2mq312332026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures1234--- PASS: TestClientFallsBackToClosures (0.61s)1235=== CONT TestClientIntegration1236--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.29s)1237=== CONT TestLeadEndsOnShutdown12382026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes12392026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures12402026/10/01 13:03:45 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12412026/10/01 13:03:45 INFO Uploading jwg429mp4wwr2rl5v8ikfm4djxj4mq1n-b (216B)12422026/10/01 13:03:45 INFO Uploading 3l7wzjvzjb80sncns228h017rdclk0mf-shared-dep (136B)12432026/10/01 13:03:45 WARN Failed to register uploaded object key=flny803n3l2mx0va3cwl8j1v518p0nvd.ls error="server returned 404: 404 page not found\n"12442026/10/01 13:03:45 WARN Failed to register uploaded object key=3l7wzjvzjb80sncns228h017rdclk0mf.ls error="server returned 404: 404 page not found\n"12452026/10/01 13:03:45 WARN Failed to register uploaded object key=jwg429mp4wwr2rl5v8ikfm4djxj4mq1n.ls error="server returned 404: 404 page not found\n"12462026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12472026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12482026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/08rrjdjkdqqwsibhpl6qscqrmqi15kncav56bjwi156lddvks71s.nar.zst error="server returned 404: 404 page not found\n"12492026/10/01 13:03:45 INFO Signed narinfos id=1 count=312502026/10/01 13:03:45 INFO Uploading 3 narinfos12512026/10/01 13:03:45 WARN Failed to register uploaded object key=jwg429mp4wwr2rl5v8ikfm4djxj4mq1n.narinfo error="server returned 404: 404 page not found\n"12522026/10/01 13:03:45 WARN Failed to register uploaded object key=3l7wzjvzjb80sncns228h017rdclk0mf.narinfo error="server returned 404: 404 page not found\n"12532026/10/01 13:03:45 INFO Received complete push request method=POST path=/api/pushes/1/complete12542026/10/01 13:03:45 WARN Failed to register uploaded object key=flny803n3l2mx0va3cwl8j1v518p0nvd.narinfo error="server returned 404: 404 page not found\n"12552026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=012562026/10/01 13:03:45 INFO Upload complete. (67ms)1257=== NAME TestClientPushesUseOnePush1258 client_pushes_test.go:97: Retrieved narinfo from S3:1259 StorePath: /build/TestClientPushesUseOnePush1161707635/001/store/3l7wzjvzjb80sncns228h017rdclk0mf-shared-dep1260 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1261 Compression: zstd1262 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821263 NarSize: 1361264 References: 1265 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n12662026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period1267 client_pushes_test.go:97: Retrieved narinfo from S3:1268 StorePath: /build/TestClientPushesUseOnePush1161707635/001/store/flny803n3l2mx0va3cwl8j1v518p0nvd-a1269 URL: nar/08rrjdjkdqqwsibhpl6qscqrmqi15kncav56bjwi156lddvks71s.nar.zst1270 Compression: zstd1271 NarHash: sha256:08rrjdjkdqqwsibhpl6qscqrmqi15kncav56bjwi156lddvks71s1272 NarSize: 2161273 References: /build/TestClientPushesUseOnePush1161707635/001/store/3l7wzjvzjb80sncns228h017rdclk0mf-shared-dep1274 CA: text:sha256:1fcxhpkbgfmk49l7jx3vbj65rnw658jly09m99ssm9k7kw6k61za1275 client_pushes_test.go:97: Retrieved narinfo from S3:1276 StorePath: /build/TestClientPushesUseOnePush1161707635/001/store/jwg429mp4wwr2rl5v8ikfm4djxj4mq1n-b12772026/10/01 13:03:45 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=01278 URL: nar/08rrjdjkdqqwsibhpl6qscqrmqi15kncav56bjwi156lddvks71s.nar.zst1279 Compression: zstd1280 NarHash: sha256:08rrjdjkdqqwsibhpl6qscqrmqi15kncav56bjwi156lddvks71s1281 NarSize: 2161282 References: /build/TestClientPushesUseOnePush1161707635/001/store/3l7wzjvzjb80sncns228h017rdclk0mf-shared-dep1283 CA: text:sha256:1fcxhpkbgfmk49l7jx3vbj65rnw658jly09m99ssm9k7kw6k61za12842026/10/01 13:03:45 INFO Vacuumed table table=pending_closures1285--- PASS: TestClientPushesUseOnePush (0.58s)1286=== CONT TestClientSharedPathCommittedMidPush12872026/10/01 13:03:45 INFO Vacuumed table table=pending_objects12882026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads12892026/10/01 13:03:45 INFO Vacuumed table table=closures12902026/10/01 13:03:45 INFO Vacuumed table table=objects1291--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.30s)1292=== CONT TestClientErrorHandling1293=== RUN TestClientErrorHandling/InvalidStorePath1294=== PAUSE TestClientErrorHandling/InvalidStorePath1295=== RUN TestClientErrorHandling/InvalidAuthToken1296=== PAUSE TestClientErrorHandling/InvalidAuthToken1297=== RUN TestClientErrorHandling/ServerNotAvailable1298=== PAUSE TestClientErrorHandling/ServerNotAvailable1299=== CONT TestLeadElectsOneAndHandsOver13002026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures1301--- PASS: TestGCSweepSkipsPendingObjects (0.35s)1302=== CONT TestClientWithDependencies1303--- PASS: TestCacheStatsHandler (0.33s)1304=== CONT TestClientCADerivations13052026/10/01 13:03:45 INFO Received cleanup request method=DELETE path=/api/pending_closures13062026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=013072026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures13082026/10/01 13:03:45 INFO Received cleanup request method=DELETE path=/api/pending_closures13092026/10/01 13:03:45 INFO Aborted multipart uploads count=1 kept=01310--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.55s)1311=== CONT TestConnectWaitsForAPeerMigration13122026/10/01 13:03:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13132026-10-01 13:03:45.263 UTC [748] ERROR: Closure does not exist: id=113142026-10-01 13:03:45.263 UTC [748] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE13152026-10-01 13:03:45.263 UTC [748] STATEMENT: -- name: CommitPendingClosure :exec1316 SELECT commit_pending_closure($1::bigint)1317 1318--- PASS: TestService_cleanupPendingClosuresHandler (0.35s)1319=== CONT TestPush_SignsNarinfosOfItsPendingObjects13202026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures13212026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures13222026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures13232026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=013242026/10/01 13:03:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013252026/10/01 13:03:45 INFO Vacuumed table table=pending_closures13262026/10/01 13:03:45 INFO Vacuumed table table=pending_objects13272026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads13282026/10/01 13:03:45 INFO Vacuumed table table=closures13292026/10/01 13:03:45 INFO Vacuumed table table=objects13302026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=013312026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period13322026/10/01 13:03:45 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=013332026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=013342026/10/01 13:03:45 INFO Vacuumed table table=pending_closures13352026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period13362026/10/01 13:03:45 INFO Vacuumed table table=pending_objects13372026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads13382026/10/01 13:03:45 INFO Vacuumed table table=closures13392026/10/01 13:03:45 INFO Vacuumed table table=objects13402026/10/01 13:03:45 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=01341--- PASS: TestPushDedupSurvivesConcurrentGC (0.41s)1342=== CONT TestResolveDBConnectionString1343=== RUN TestResolveDBConnectionString/flag_wins1344=== PAUSE TestResolveDBConnectionString/flag_wins1345=== RUN TestResolveDBConnectionString/file_when_flag_empty1346=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1347=== RUN TestResolveDBConnectionString/missing_file_is_an_error1348=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1349=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1350=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1351=== RUN TestResolveDBConnectionString/nothing_configured13522026/10/01 13:03:45 INFO Vacuumed table table=pending_closures1353=== PAUSE TestResolveDBConnectionString/nothing_configured1354=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle13552026/10/01 13:03:45 INFO Vacuumed table table=pending_objects13562026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads13572026/10/01 13:03:45 INFO Vacuumed table table=closures13582026/10/01 13:03:45 INFO Vacuumed table table=objects13592026/10/01 13:03:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13602026/10/01 13:03:45 WARN mTLS auth: bound subjects configured but subject DN unavailable13612026/10/01 13:03:45 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1362--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.28s)1363=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart13642026/10/01 13:03:45 INFO Received complete multipart upload request method=POST path=/1365--- PASS: TestGCMetrics (0.32s)1366=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure13672026/10/01 13:03:45 INFO Received uploads request method=POST path=/1368--- PASS: TestPushWaitsForSweepHoldingRow (0.95s)1369=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts13702026/10/01 13:03:45 INFO Received request for more parts method=POST path=/1371=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1372=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1373=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1374=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1375=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1376=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1377=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1378=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1379=== CONT TestIsValidCachePath/narinfo1380=== CONT TestIsValidCachePath/short_hash1381=== CONT TestIsValidCachePath/wrong_extension1382=== CONT TestIsValidCachePath/leading_slash1383=== CONT TestIsValidCachePath/empty1384=== CONT TestIsValidCachePath/log1385=== CONT TestIsValidCachePath/ls1386=== CONT TestIsValidCachePath/nar_uncompressed1387=== CONT TestIsValidCachePath/nar_bz21388=== CONT TestIsValidCachePath/nar_xz1389=== CONT TestIsValidCachePath/realisation1390=== CONT TestIsValidCachePath/nar_zst1391=== CONT TestIsValidCachePath/random_path1392=== CONT TestIsValidCachePath/traversal_parent1393=== CONT TestIsValidCachePath/invalid_char_u1394=== CONT TestIsValidCachePath/invalid_char_e1395=== CONT TestIsValidCachePath/index.html1396=== CONT TestIsValidCachePath/traversal_in_middle1397=== CONT TestIsValidCachePath/nix-cache-info1398=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1399--- PASS: TestIsValidCachePath (0.00s)1400 --- PASS: TestIsValidCachePath/narinfo (0.00s)1401 --- PASS: TestIsValidCachePath/short_hash (0.00s)1402 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1403 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1404 --- PASS: TestIsValidCachePath/empty (0.00s)1405 --- PASS: TestIsValidCachePath/log (0.00s)1406 --- PASS: TestIsValidCachePath/ls (0.00s)1407 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1408 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1409 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1410 --- PASS: TestIsValidCachePath/realisation (0.00s)1411 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1412 --- PASS: TestIsValidCachePath/random_path (0.00s)1413 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1414 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1415 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1416 --- PASS: TestIsValidCachePath/index.html (0.00s)1417 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1418 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1419 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1420=== CONT TestPush_RejectsBadRequests/no_roots14212026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes1422=== CONT TestPush_RejectsBadRequests/bad_root14232026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes1424=== CONT TestPush_RejectsBadRequests/root_not_in_objects14252026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes1426=== CONT TestPush_RejectsBadRequests/no_objects14272026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes1428=== CONT TestParseSingleRange/none1429=== CONT TestParseSingleRange/suffix_exceeds_size1430=== CONT TestParseSingleRange/suffix1431=== CONT TestParseSingleRange/end_clamped_to_size1432=== CONT TestParseSingleRange/open-ended1433=== CONT TestParseSingleRange/closed1434=== CONT TestParseSingleRange/malformed_end_before_start1435--- PASS: TestPush_RejectsBadRequests (0.36s)1436 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1437 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1438 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1439 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1440=== CONT TestParseSingleRange/malformed_both_empty1441=== CONT TestParseSingleRange/malformed_no_dash1442=== CONT TestParseSingleRange/multi-range_ignored1443=== CONT TestParseSingleRange/unknown_unit1444=== CONT TestParseSingleRange/single_byte1445=== CONT TestParseSingleRange/start_far_past_EOF1446=== CONT TestParseSingleRange/start_past_EOF1447--- PASS: TestParseSingleRange (0.00s)1448 --- PASS: TestParseSingleRange/none (0.00s)1449 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1450 --- PASS: TestParseSingleRange/suffix (0.00s)1451 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1452 --- PASS: TestParseSingleRange/open-ended (0.00s)1453 --- PASS: TestParseSingleRange/closed (0.00s)1454 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1455 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1456 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1457 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1458 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1459 --- PASS: TestParseSingleRange/single_byte (0.00s)1460 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1461 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1462=== CONT TestServerTLSConfig/no_client_CA1463=== CONT TestServerTLSConfig/not_a_PEM_file1464=== CONT TestServerTLSConfig/missing_CA_file1465--- PASS: TestServerTLSConfig (0.00s)1466 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1467 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1468 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1469=== CONT TestPendingClosureWriteTimeout/empty1470=== CONT TestPendingClosureWriteTimeout/670k_objects1471=== CONT TestPendingClosureWriteTimeout/400_objects1472=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline14732026/10/01 13:03:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14742026/10/01 13:03:45 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1475--- PASS: TestCompleteMultipartUnregistered (0.32s)1476=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14772026/10/01 13:03:45 INFO Received uploads request method=POST path=/1478=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14792026/10/01 13:03:45 INFO Received complete multipart upload request method=POST path=/1480=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14812026/10/01 13:03:45 INFO Received request for more parts method=POST path=/1482=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14832026/10/01 13:03:45 INFO Received uploads request method=POST path=/1484--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1485 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1486 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1487 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1488 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1489=== CONT TestIsValidUploadKey/narinfo1490=== CONT TestIsValidUploadKey/unknown_type1491=== CONT TestIsValidUploadKey/empty_key1492=== CONT TestIsValidUploadKey/absolute1493=== CONT TestIsValidUploadKey/traversal_nar1494=== CONT TestIsValidUploadKey/traversal1495=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1496=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1497=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1498=== CONT TestIsValidUploadKey/index.html1499=== CONT TestIsValidUploadKey/nix-cache-info1500=== CONT TestIsValidUploadKey/realisation_plus_in_output1501=== CONT TestIsValidUploadKey/realisation1502=== CONT TestIsValidUploadKey/listing1503=== CONT TestIsValidUploadKey/nar_plain1504=== CONT TestIsValidUploadKey/nar_xz1505=== CONT TestIsValidUploadKey/nar_zst1506=== CONT TestIsValidUploadKey/build_log_question_mark1507=== CONT TestIsValidUploadKey/build_log_equals1508=== CONT TestIsValidUploadKey/build_log1509=== CONT TestIsValidUploadKey/build_log_plus_in_name1510=== CONT TestIsValidUploadKey/build_log_home-manager_file1511--- PASS: TestIsValidUploadKey (0.00s)1512 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1513 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1514 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1515 --- PASS: TestIsValidUploadKey/absolute (0.00s)1516 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1517 --- PASS: TestIsValidUploadKey/traversal (0.00s)1518 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1519 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1520 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1521 --- PASS: TestIsValidUploadKey/index.html (0.00s)1522 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1523 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1524 --- PASS: TestIsValidUploadKey/realisation (0.00s)1525 --- PASS: TestIsValidUploadKey/listing (0.00s)1526 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1527 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1528 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1529 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1530 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1531 --- PASS: TestIsValidUploadKey/build_log (0.00s)1532 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1533 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1534=== CONT TestProxyWriteTimeout/narinfo1535=== CONT TestProxyWriteTimeout/10_GiB_nar1536=== CONT TestProxyWriteTimeout/unknown_size1537=== CONT TestProxyWriteTimeout/1_GiB_nar1538--- PASS: TestProxyWriteTimeout (0.00s)1539 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1540 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1541 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1542 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1543=== CONT TestCacheConfigHandler/full_config,_no_issuer1544=== CONT TestCacheConfigHandler/no_signing_keys1545=== CONT TestCacheConfigHandler/no_cache_url_configured1546=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1547--- PASS: TestCacheConfigHandler (0.00s)1548 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1549 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1550 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1551 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1552=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1553--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.80s)1554=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1555=== CONT TestClientErrorHandling/InvalidStorePath1556=== CONT TestClientErrorHandling/InvalidAuthToken1557=== RUN TestService_RequireScope_OIDC/builder_may_write1558=== PAUSE TestService_RequireScope_OIDC/builder_may_write1559=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1560=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1561=== RUN TestService_RequireScope_OIDC/ops_may_admin1562=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1563=== RUN TestService_RequireScope_OIDC/ops_may_not_write1564=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1565=== RUN TestService_RequireScope_OIDC/reader_may_not_write1566=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1567=== RUN TestService_RequireScope_OIDC/static_token_may_admin1568=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1569=== RUN TestService_RequireScope_OIDC/static_token_may_write1570=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1571=== RUN TestService_RequireScope_OIDC/reader_may_read1572=== PAUSE TestService_RequireScope_OIDC/reader_may_read1573=== RUN TestService_RequireScope_OIDC/writer_implies_read1574=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1575=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1576=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1577=== CONT TestClientErrorHandling/ServerNotAvailable1578--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.36s)1579=== CONT TestResolveDBConnectionString/flag_wins1580=== CONT TestResolveDBConnectionString/nothing_configured1581=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1582=== CONT TestResolveDBConnectionString/missing_file_is_an_error1583=== CONT TestResolveDBConnectionString/file_when_flag_empty1584=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1585--- PASS: TestResolveDBConnectionString (0.00s)1586 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1587 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1588 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1589 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1590 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1591=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected15922026/10/01 13:03:45 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]1593=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1594=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected15952026/10/01 13:03:45 WARN Authentication failed token_preview=eyJhbGciOi...hvhFAwroog token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1596=== CONT TestService_RequireScope_OIDC/builder_may_write1597--- PASS: TestService_AuthMiddleware_OIDC (0.55s)1598 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1599 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1600 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1601 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1602=== CONT TestService_RequireScope_OIDC/writer_implies_read1603=== CONT TestService_RequireScope_OIDC/reader_may_read1604=== CONT TestService_RequireScope_OIDC/static_token_may_write1605=== CONT TestService_RequireScope_OIDC/static_token_may_admin1606=== CONT TestService_RequireScope_OIDC/reader_may_not_write1607=== CONT TestService_RequireScope_OIDC/ops_may_not_write1608=== CONT TestService_RequireScope_OIDC/ops_may_admin1609=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1610=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1611--- PASS: TestService_RequireScope_OIDC (0.74s)1612 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1613 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1614 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1615 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1616 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1617 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1618 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1619 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1620 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1621 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1622=== NAME TestPinProtectsFromGC1623 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC902303668/001/store/3d69cjydiwwn2mk0kh8zlzw70ksl75a2-pinned-file.txt1624 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC902303668/001/store/nipgp1liwcqn0y3cyk8vxy1lp93ifqmr-unpinned-file.txt16252026/10/01 13:03:45 INFO lead: acquired remote=192.0.2.1:12341626=== NAME TestClientMultipleUploads1627 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads4021127810/001/store/lgp3l99dv7k6b1pid1dcs1hg78z714p0-test-file-0.txt16282026/10/01 13:03:45 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1629=== NAME TestClientIntegration1630 client_integration_test.go:286: Created store path: /build/TestClientIntegration387055127/002/store/fh4iqhfz0al7ckwsg2yrznv1r6mapm93-test-file.txt16312026/10/01 13:03:45 INFO lead: acquired remote=192.0.2.1:12341632=== NAME TestClientMultipleUploads1633 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads4021127810/001/store/x1lh2b6k311zyx67k69v4rdwfrnx2cnj-test-file-1.txt16342026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes16352026/10/01 13:03:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16362026/10/01 13:03:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16372026/10/01 13:03:45 INFO Uploading 3d69cjydiwwn2mk0kh8zlzw70ksl75a2-pinned-file.txt (128B)16382026/10/01 13:03:45 WARN Failed to register uploaded object key=3d69cjydiwwn2mk0kh8zlzw70ksl75a2.ls error="server returned 404: 404 page not found\n"16392026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16402026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16412026/10/01 13:03:45 INFO Signed narinfos id=1 count=116422026/10/01 13:03:45 INFO Uploading 1 narinfos16432026/10/01 13:03:45 INFO Received complete push request method=POST path=/api/pushes/1/complete16442026/10/01 13:03:45 WARN Failed to register uploaded object key=3d69cjydiwwn2mk0kh8zlzw70ksl75a2.narinfo error="server returned 404: 404 page not found\n"16452026/10/01 13:03:45 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OGZmNGFiODEtOWRhYy00OTY3LWJlN2MtNDFjNjA2M2Y1YjU2Ljk2NmE4Y2ZmLWUyNWEtNGJmZS05NTVhLWNmYjg4MmUwYmI1M3gxNzkwODU5ODI1MjcxNzI0Nzkx parts=1016462026/10/01 13:03:45 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16472026/10/01 13:03:45 INFO Completed upload id=116482026/10/01 13:03:45 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000016492026/10/01 13:03:45 INFO Upload complete. (58ms)16502026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures16512026/10/01 13:03:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures1652 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads4021127810/001/store/bvf56dk5awg0f0a74ddznsvnvsi9d7ff-test-file-2.txt16532026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=016542026/10/01 13:03:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016552026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes16562026/10/01 13:03:45 INFO Vacuumed table table=pending_closures16572026/10/01 13:03:45 INFO Vacuumed table table=pending_objects16582026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads16592026/10/01 13:03:45 INFO Vacuumed table table=closures16602026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16612026/10/01 13:03:45 INFO Signed narinfos id=1 count=116622026/10/01 13:03:45 INFO Vacuumed table table=objects1663--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.35s)16642026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes16652026/10/01 13:03:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16662026/10/01 13:03:45 INFO Uploading fh4iqhfz0al7ckwsg2yrznv1r6mapm93-test-file.txt (152B)16672026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"16682026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16692026/10/01 13:03:45 WARN Failed to register uploaded object key=fh4iqhfz0al7ckwsg2yrznv1r6mapm93.ls error="server returned 404: 404 page not found\n"16702026/10/01 13:03:45 INFO Signed narinfos id=1 count=116712026/10/01 13:03:45 INFO Uploading 1 narinfos16722026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures16732026/10/01 13:03:45 INFO Received complete push request method=POST path=/api/pushes/1/complete16742026/10/01 13:03:45 WARN Failed to register uploaded object key=fh4iqhfz0al7ckwsg2yrznv1r6mapm93.narinfo error="server returned 404: 404 page not found\n"1675--- PASS: TestGCBugBareHashReferences (0.54s)16762026/10/01 13:03:45 INFO Upload complete. (54ms)16772026/10/01 13:03:45 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=219.765094ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present16782026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures16792026/10/01 13:03:45 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001680--- PASS: TestService_createPendingClosureHandler (0.67s)16812026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes1682=== NAME TestClientWithDependencies1683 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies3088074205/001/store/jyc9srfr49pp7dm0f4qm851rlphzy320-test-script16842026/10/01 13:03:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16852026/10/01 13:03:45 INFO Uploading nipgp1liwcqn0y3cyk8vxy1lp93ifqmr-unpinned-file.txt (128B)16862026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes16872026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16882026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16892026/10/01 13:03:45 WARN Failed to register uploaded object key=nipgp1liwcqn0y3cyk8vxy1lp93ifqmr.ls error="server returned 404: 404 page not found\n"16902026/10/01 13:03:45 INFO Signed narinfos id=2 count=116912026/10/01 13:03:45 INFO Uploading 1 narinfos16922026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures16932026/10/01 13:03:45 INFO All 1 paths already cached16942026/10/01 13:03:45 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)1695=== NAME TestClientIntegration1696 client_integration_test.go:312: Retrieved narinfo from S3:1697 StorePath: /build/TestClientIntegration387055127/002/store/fh4iqhfz0al7ckwsg2yrznv1r6mapm93-test-file.txt16982026/10/01 13:03:45 INFO Received complete push request method=POST path=/api/pushes/2/complete1699 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst17002026/10/01 13:03:45 INFO Uploading bvf56dk5awg0f0a74ddznsvnvsi9d7ff-test-file-2.txt (160B)1701 Compression: zstd1702 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11703 NarSize: 1521704 References: 1705 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk117062026/10/01 13:03:45 WARN Failed to register uploaded object key=nipgp1liwcqn0y3cyk8vxy1lp93ifqmr.narinfo error="server returned 404: 404 page not found\n"17072026/10/01 13:03:45 INFO Uploading lgp3l99dv7k6b1pid1dcs1hg78z714p0-test-file-0.txt (160B)17082026/10/01 13:03:45 INFO Uploading x1lh2b6k311zyx67k69v4rdwfrnx2cnj-test-file-1.txt (160B)17092026/10/01 13:03:45 INFO Upload complete. (45ms)1710 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1711 client_integration_test.go:313: Decompressed .ls content (64 bytes):1712 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1713 client_integration_test.go:316: Testing garbage collection...17142026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=017152026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17162026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17172026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17182026/10/01 13:03:45 WARN Failed to register uploaded object key=lgp3l99dv7k6b1pid1dcs1hg78z714p0.ls error="server returned 404: 404 page not found\n"17192026/10/01 13:03:45 WARN Failed to register uploaded object key=bvf56dk5awg0f0a74ddznsvnvsi9d7ff.ls error="server returned 404: 404 page not found\n"17202026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17212026/10/01 13:03:45 WARN Failed to register uploaded object key=x1lh2b6k311zyx67k69v4rdwfrnx2cnj.ls error="server returned 404: 404 page not found\n"17222026/10/01 13:03:45 INFO Signed narinfos id=1 count=317232026/10/01 13:03:45 INFO Uploading 3 narinfos17242026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period1725=== NAME TestClientCADerivations1726 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3802258435/001/store/91ii4qd60dk4cp0bk3zl97fhsp11gzfw-ca-test17272026/10/01 13:03:45 WARN Failed to register uploaded object key=lgp3l99dv7k6b1pid1dcs1hg78z714p0.narinfo error="server returned 404: 404 page not found\n"17282026/10/01 13:03:45 WARN Failed to register uploaded object key=x1lh2b6k311zyx67k69v4rdwfrnx2cnj.narinfo error="server returned 404: 404 page not found\n"17292026/10/01 13:03:45 INFO Received complete push request method=POST path=/api/pushes/1/complete17302026/10/01 13:03:45 WARN Failed to register uploaded object key=bvf56dk5awg0f0a74ddznsvnvsi9d7ff.narinfo error="server returned 404: 404 page not found\n"17312026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes17322026/10/01 13:03:45 INFO Upload complete. (51ms)1733=== NAME TestClientMultipleUploads1734 client_integration_test.go:369: Uploaded 3 paths in 82.662614ms17352026/10/01 13:03:45 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)17362026/10/01 13:03:45 INFO Uploading 7ic63pz4m79m4k7p9977mav82x33p90b-top (224B)17372026/10/01 13:03:45 INFO Uploading l68jqzqh66bchbxshg6b7lvzfa5xw3qa-shared-dep (136B)17382026/10/01 13:03:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=017392026/10/01 13:03:45 INFO Vacuumed table table=pending_closures17402026/10/01 13:03:45 INFO Vacuumed table table=pending_objects17412026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads17422026/10/01 13:03:45 INFO Vacuumed table table=closures17432026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17442026/10/01 13:03:45 WARN Failed to register uploaded object key=7ic63pz4m79m4k7p9977mav82x33p90b.ls error="server returned 404: 404 page not found\n"17452026/10/01 13:03:45 WARN Failed to register uploaded object key=l68jqzqh66bchbxshg6b7lvzfa5xw3qa.ls error="server returned 404: 404 page not found\n"17462026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17472026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/13zsnbnwq7p5sr48vzr9clqc58x3v6gyqf2zfg2xgjid23hmzyd4.nar.zst error="server returned 404: 404 page not found\n"17482026/10/01 13:03:45 INFO Vacuumed table table=objects17492026/10/01 13:03:45 INFO Signed narinfos id=1 count=217502026/10/01 13:03:45 INFO Uploading 2 narinfos17512026/10/01 13:03:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1752=== NAME TestClientWithDependencies1753 client_integration_test.go:615: Found 1 dependencies (including self)1754--- PASS: TestClientMultipleUploads (0.57s)17552026/10/01 13:03:45 INFO Received complete push request method=POST path=/api/pushes/1/complete17562026/10/01 13:03:45 WARN Failed to register uploaded object key=7ic63pz4m79m4k7p9977mav82x33p90b.narinfo error="server returned 404: 404 page not found\n"17572026/10/01 13:03:45 WARN Failed to register uploaded object key=l68jqzqh66bchbxshg6b7lvzfa5xw3qa.narinfo error="server returned 404: 404 page not found\n"17582026/10/01 13:03:45 INFO Upload complete. (55ms)1759=== NAME TestClientSharedPathCommittedMidPush1760 client_integration_test.go:680: Retrieved narinfo from S3:1761 StorePath: /build/TestClientSharedPathCommittedMidPush1952820793/001/store/l68jqzqh66bchbxshg6b7lvzfa5xw3qa-shared-dep1762 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1763 Compression: zstd1764 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821765 NarSize: 1361766 References: 1767 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1768=== NAME TestClientCADerivations1769 client_ca_test.go:139: Found 1 dependencies (including self)1770=== NAME TestClientSharedPathCommittedMidPush1771 client_integration_test.go:680: Retrieved narinfo from S3:1772 StorePath: /build/TestClientSharedPathCommittedMidPush1952820793/001/store/7ic63pz4m79m4k7p9977mav82x33p90b-top1773 URL: nar/13zsnbnwq7p5sr48vzr9clqc58x3v6gyqf2zfg2xgjid23hmzyd4.nar.zst1774 Compression: zstd1775 NarHash: sha256:13zsnbnwq7p5sr48vzr9clqc58x3v6gyqf2zfg2xgjid23hmzyd41776 NarSize: 2241777 References: /build/TestClientSharedPathCommittedMidPush1952820793/001/store/l68jqzqh66bchbxshg6b7lvzfa5xw3qa-shared-dep1778 CA: text:sha256:0p1m1y1axlz3yhai0l0iq4pbd66nir650qgmdjjry7b3scny02i717792026/10/01 13:03:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures17802026/10/01 13:03:45 INFO Garbage collection started17812026/10/01 13:03:45 INFO Starting cleanup of old closures method=DELETE path=/api/closures17822026/10/01 13:03:45 INFO Garbage collection started1783--- PASS: TestClientSharedPathCommittedMidPush (0.52s)17842026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=017852026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period17862026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=017872026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period17882026/10/01 13:03:45 INFO Received uploads request method=POST path=/api/pending_closures17892026/10/01 13:03:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=017902026/10/01 13:03:45 INFO Vacuumed table table=pending_closures17912026/10/01 13:03:45 INFO Vacuumed table table=pending_objects17922026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads17932026/10/01 13:03:45 INFO Vacuumed table table=closures17942026/10/01 13:03:45 INFO Aborted multipart uploads count=0 kept=017952026/10/01 13:03:45 INFO Vacuumed table table=objects17962026/10/01 13:03:45 WARN Force mode enabled - objects will be deleted immediately without grace period17972026/10/01 13:03:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=1 objects-marked-for-deletion=3 objects-deleted-after-grace-period=3 objects-failed-to-delete=017982026/10/01 13:03:45 INFO Vacuumed table table=pending_closures17992026/10/01 13:03:45 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=018002026/10/01 13:03:45 INFO Vacuumed table table=pending_objects18012026/10/01 13:03:45 INFO Vacuumed table table=pending_closures18022026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads18032026/10/01 13:03:45 INFO Vacuumed table table=pending_objects18042026/10/01 13:03:45 INFO Vacuumed table table=multipart_uploads18052026/10/01 13:03:45 INFO Vacuumed table table=closures18062026/10/01 13:03:45 INFO Vacuumed table table=closures18072026/10/01 13:03:45 INFO Vacuumed table table=objects18082026/10/01 13:03:45 INFO Vacuumed table table=objects1809--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1810 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.35s)1811 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.47s)18122026/10/01 13:03:45 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18132026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes18142026/10/01 13:03:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18152026/10/01 13:03:45 INFO Uploading jyc9srfr49pp7dm0f4qm851rlphzy320-test-script (136B)18162026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18172026/10/01 13:03:45 WARN Failed to register uploaded object key=log/l3a4423j8j78djhb5fxw6qkvkmklc580-test-script.drv error="server returned 404: 404 page not found\n"18182026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18192026/10/01 13:03:45 WARN Failed to register uploaded object key=jyc9srfr49pp7dm0f4qm851rlphzy320.ls error="server returned 404: 404 page not found\n"18202026/10/01 13:03:45 INFO Signed narinfos id=1 count=118212026/10/01 13:03:45 INFO Uploading 1 narinfos18222026/10/01 13:03:45 INFO Received complete push request method=POST path=/api/pushes/1/complete18232026/10/01 13:03:45 WARN Failed to register uploaded object key=jyc9srfr49pp7dm0f4qm851rlphzy320.narinfo error="server returned 404: 404 page not found\n"18242026/10/01 13:03:45 INFO Upload complete. (53ms)1825=== NAME TestClientWithDependencies1826 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3088074205/001/store) requires matching store prefix18272026/10/01 13:03:45 INFO Received push request method=POST path=/api/pushes1828--- PASS: TestClientWithDependencies (0.66s)18292026/10/01 13:03:45 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18302026/10/01 13:03:45 INFO Uploading 91ii4qd60dk4cp0bk3zl97fhsp11gzfw-ca-test (144B)18312026/10/01 13:03:45 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=394.110282ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18322026/10/01 13:03:45 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"18332026/10/01 13:03:45 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18342026/10/01 13:03:45 WARN Failed to register uploaded object key=91ii4qd60dk4cp0bk3zl97fhsp11gzfw.ls error="server returned 404: 404 page not found\n"18352026/10/01 13:03:45 WARN Failed to register uploaded object key=log/i4914zf4rsccdz7ai95lg02ianzqzxhn-ca-test.drv error="server returned 404: 404 page not found\n"18362026/10/01 13:03:45 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18372026/10/01 13:03:45 INFO Signed narinfos id=1 count=118382026/10/01 13:03:45 INFO Uploading 1 narinfos18392026/10/01 13:03:45 INFO Received complete push request method=POST path=/api/pushes/1/complete18402026/10/01 13:03:45 WARN Failed to register uploaded object key=91ii4qd60dk4cp0bk3zl97fhsp11gzfw.narinfo error="server returned 404: 404 page not found\n"18412026/10/01 13:03:45 INFO Upload complete. (76ms)1842=== NAME TestClientCADerivations1843 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3802258435/001/store/91ii4qd60dk4cp0bk3zl97fhsp11gzfw-ca-test1844 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1845 Compression: zstd1846 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1847 NarSize: 1441848 References: 1849 Deriver: /build/TestClientCADerivations3802258435/001/store/i4914zf4rsccdz7ai95lg02ianzqzxhn-ca-test.drv1850 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1851 client_ca_test.go:185: Checking for realisation files in S3...1852 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1853 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1854=== NAME TestOrphanedObjectsGCStressTest1855 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1856 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1857=== NAME TestClientCADerivations1858 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1859 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1860 error: binary cache 's3://bucket81?endpoint=http://localhost:33367®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3802258435/001/store'1861 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11862--- PASS: TestClientCADerivations (0.74s)1863=== NAME TestOrphanedObjectsGCStressTest1864 orphaned_objects_gc_test.go:509: Stress test completed successfully:1865 orphaned_objects_gc_test.go:510: - Active objects preserved: 201866 orphaned_objects_gc_test.go:511: - Objects deleted: 2101867 orphaned_objects_gc_test.go:512: - Total GC'd: 2101868--- PASS: TestOrphanedObjectsGCStressTest (2.03s)18692026/10/01 13:03:46 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=874.858275ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1870--- PASS: TestUploadHandlersRejectOversizedBody (0.17s)1871 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.06s)1872 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1873 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.02s)1874--- PASS: TestPendingClosureWriteTimeout (0.00s)1875 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1876 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1877 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1878 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.11s)18792026/10/01 13:03:46 INFO lead: released remote=192.0.2.1:12341880--- PASS: TestLeadEndsOnShutdown (1.43s)18812026/10/01 13:03:46 INFO lead: released remote=192.0.2.1:123418822026/10/01 13:03:46 INFO lead: acquired remote=192.0.2.1:123418832026/10/01 13:03:47 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.688360763s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18842026/10/01 13:03:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01885=== NAME TestClientIntegration1886 client_integration_test.go:323: Objects in database after GC:18872026/10/01 13:03:47 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01888 client_integration_test.go:323: Successfully deleted all objects with GC --force18892026/10/01 13:03:47 INFO Received create pin request method=POST path=/api/pins/myapp1890--- PASS: TestClientIntegration (2.57s)18912026/10/01 13:03:47 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC902303668/001/store/3d69cjydiwwn2mk0kh8zlzw70ksl75a2-pinned-file.txt narinfo_key=3d69cjydiwwn2mk0kh8zlzw70ksl75a2.narinfo18922026/10/01 13:03:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures18932026/10/01 13:03:47 INFO Garbage collection started18942026/10/01 13:03:47 INFO Aborted multipart uploads count=0 kept=018952026/10/01 13:03:47 WARN Force mode enabled - objects will be deleted immediately without grace period18962026/10/01 13:03:47 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=018972026/10/01 13:03:47 INFO Vacuumed table table=pending_closures18982026/10/01 13:03:47 INFO Vacuumed table table=pending_objects18992026/10/01 13:03:47 INFO Vacuumed table table=multipart_uploads19002026/10/01 13:03:47 INFO Vacuumed table table=closures19012026/10/01 13:03:47 INFO Vacuumed table table=objects19022026/10/01 13:03:47 INFO lead: released remote=192.0.2.1:12341903--- PASS: TestLeadElectsOneAndHandsOver (2.77s)1904--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.78s)19052026/10/01 13:03:48 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-config19062026/10/01 13:03:48 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=196.991424ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19072026/10/01 13:03:49 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=393.133197ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19082026/10/01 13:03:49 WARN Rate limiter enabled after throttle name=s3-test rate=519092026/10/01 13:03:49 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1910=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1911 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101912 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001913--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.04s)19142026/10/01 13:03:49 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=821.459972ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1915=== NAME TestPinProtectsFromGC1916 client_integration_test.go:840: Pin successfully protected closure from garbage collection1917--- PASS: TestPinProtectsFromGC (4.62s)19182026/10/01 13:03:50 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.66274921s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1919--- PASS: TestConnectWaitsForAPeerMigration (5.13s)19202026/10/01 13:03:50 INFO Aborted multipart uploads count=1 kept=019212026/10/01 13:03:50 INFO Received cleanup request method=DELETE path=/api/pending_closures19222026/10/01 13:03:50 INFO Aborted multipart uploads count=1 kept=01923--- PASS: TestPendingCleanupUsesOneCutoff (6.44s)19242026/10/01 13:03:52 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"19252026/10/01 13:03:52 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-config19262026/10/01 13:03:52 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=193.517911ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19272026/10/01 13:03:52 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=381.662948ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19282026/10/01 13:03:52 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=801.00076ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19292026/10/01 13:03:53 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.747491028s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19302026/10/01 13:03:55 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_closures19312026/10/01 13:03:55 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=202.472136ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19322026/10/01 13:03:55 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=385.671144ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19332026/10/01 13:03:55 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=830.990783ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures19342026/10/01 13:03:56 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.533220222s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures1935--- PASS: TestClientErrorHandling (0.00s)1936 --- PASS: TestClientErrorHandling/InvalidStorePath (0.34s)1937 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.47s)1938 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.86s)1939PASS19402026-10-01 13:03:58.567 UTC [128] LOG: received smart shutdown request19412026-10-01 13:03:58.570 UTC [128] LOG: background worker "logical replication launcher" (PID 138) exited with exit code 119422026-10-01 13:03:58.582 UTC [133] LOG: shutting down19432026-10-01 13:03:58.583 UTC [133] LOG: checkpoint starting: shutdown immediate19442026-10-01 13:03:59.422 UTC [133] LOG: checkpoint complete: wrote 10503 buffers (64.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 25 recycled; write=0.173 s, sync=0.638 s, total=0.840 s; sync files=29992, longest=0.002 s, average=0.001 s; distance=414804 kB, estimate=414804 kB; lsn=0/1AC7AF20, redo lsn=0/1AC7AF2019452026-10-01 13:03:59.493 UTC [128] LOG: database system is shut down1946Running OIDC tests...1947=== RUN TestAudienceForIssuer1948=== PAUSE TestAudienceForIssuer1949=== RUN TestGlobMatch1950=== PAUSE TestGlobMatch1951=== RUN TestValidateToken_ValidToken1952=== PAUSE TestValidateToken_ValidToken1953=== RUN TestValidateToken_WrongAudience1954=== PAUSE TestValidateToken_WrongAudience1955=== RUN TestValidateToken_Expired1956=== PAUSE TestValidateToken_Expired1957=== RUN TestValidateToken_BoundClaimsMismatch1958=== PAUSE TestValidateToken_BoundClaimsMismatch1959=== RUN TestValidateToken_BoundSubjectMismatch1960=== PAUSE TestValidateToken_BoundSubjectMismatch1961=== RUN TestValidateToken_MultipleProviders1962=== PAUSE TestValidateToken_MultipleProviders1963=== RUN TestValidateToken_NoMatchingProvider1964=== PAUSE TestValidateToken_NoMatchingProvider1965=== RUN TestValidateToken_KubernetesServiceAccount1966=== PAUSE TestValidateToken_KubernetesServiceAccount1967=== RUN TestNewValidator_KubernetesRequiresCA1968=== PAUSE TestNewValidator_KubernetesRequiresCA1969=== RUN TestValidateToken_KubernetesIssuerFromOwnToken1970=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken1971=== RUN TestPins_ReservedForMatchingRule1972=== PAUSE TestPins_ReservedForMatchingRule1973=== RUN TestPins_TopLevelShorthand1974=== PAUSE TestPins_TopLevelShorthand1975=== RUN TestPins_ConfigValidation1976=== PAUSE TestPins_ConfigValidation1977=== RUN TestScopes_LegacyProviderDefaultsToWrite1978=== PAUSE TestScopes_LegacyProviderDefaultsToWrite1979=== RUN TestScopes_Rules1980=== PAUSE TestScopes_Rules1981=== RUN TestScopes_ConfigValidation1982=== PAUSE TestScopes_ConfigValidation1983=== CONT TestAudienceForIssuer1984=== CONT TestValidateToken_BoundClaimsMismatch1985=== CONT TestValidateToken_MultipleProviders1986--- PASS: TestAudienceForIssuer (0.00s)1987=== CONT TestValidateToken_Expired1988=== CONT TestValidateToken_WrongAudience1989=== CONT TestValidateToken_ValidToken1990=== CONT TestGlobMatch1991=== RUN TestGlobMatch/foo_foo1992=== CONT TestPins_ConfigValidation1993=== CONT TestScopes_ConfigValidation1994=== CONT TestScopes_Rules1995=== CONT TestValidateToken_KubernetesServiceAccount1996=== CONT TestScopes_LegacyProviderDefaultsToWrite1997=== CONT TestPins_TopLevelShorthand1998=== CONT TestValidateToken_BoundSubjectMismatch1999=== CONT TestPins_ReservedForMatchingRule2000--- PASS: TestPins_ConfigValidation (0.00s)2001=== CONT TestValidateToken_NoMatchingProvider2002=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2003=== CONT TestNewValidator_KubernetesRequiresCA2004=== PAUSE TestGlobMatch/foo_foo2005=== RUN TestGlobMatch/foo_bar2006=== PAUSE TestGlobMatch/foo_bar2007=== RUN TestGlobMatch/*_2008=== PAUSE TestGlobMatch/*_2009=== RUN TestGlobMatch/*_anything2010=== PAUSE TestGlobMatch/*_anything2011--- PASS: TestScopes_ConfigValidation (0.00s)2012=== RUN TestGlobMatch/foo*_foo2013=== PAUSE TestGlobMatch/foo*_foo2014=== RUN TestGlobMatch/foo*_foobar2015=== PAUSE TestGlobMatch/foo*_foobar2016=== RUN TestGlobMatch/foo*_bar2017=== PAUSE TestGlobMatch/foo*_bar2018=== RUN TestGlobMatch/*bar_bar2019=== PAUSE TestGlobMatch/*bar_bar2020=== RUN TestGlobMatch/*bar_foobar2021=== PAUSE TestGlobMatch/*bar_foobar2022=== RUN TestGlobMatch/*bar_foo2023=== PAUSE TestGlobMatch/*bar_foo2024=== RUN TestGlobMatch/foo*bar_foobar2025=== PAUSE TestGlobMatch/foo*bar_foobar2026=== RUN TestGlobMatch/foo*bar_foo123bar2027=== PAUSE TestGlobMatch/foo*bar_foo123bar2028=== RUN TestGlobMatch/foo*bar_foobarbaz2029=== PAUSE TestGlobMatch/foo*bar_foobarbaz2030=== RUN TestGlobMatch/*/*_foo/bar2031=== PAUSE TestGlobMatch/*/*_foo/bar2032=== RUN TestGlobMatch/*/*_foo2033=== PAUSE TestGlobMatch/*/*_foo2034=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2035=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2036=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02037=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02038=== RUN TestGlobMatch/refs/*/main_refs/heads/main2039=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2040=== RUN TestGlobMatch/fo?_foo2041=== PAUSE TestGlobMatch/fo?_foo2042=== RUN TestGlobMatch/fo?_fo2043=== PAUSE TestGlobMatch/fo?_fo2044=== RUN TestGlobMatch/fo?_fooo2045=== PAUSE TestGlobMatch/fo?_fooo2046=== RUN TestGlobMatch/?oo_foo2047=== PAUSE TestGlobMatch/?oo_foo2048=== RUN TestGlobMatch/?oo_boo2049=== PAUSE TestGlobMatch/?oo_boo2050=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2051=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2052=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2053=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2054=== CONT TestGlobMatch/foo_foo2055=== CONT TestGlobMatch/?oo_foo2056=== CONT TestGlobMatch/foo*bar_foo123bar2057=== CONT TestGlobMatch/foo*bar_foobar2058=== CONT TestGlobMatch/*bar_foo2059=== CONT TestGlobMatch/*bar_foobar2060=== CONT TestGlobMatch/*bar_bar2061=== CONT TestGlobMatch/fo?_fooo2062=== CONT TestGlobMatch/foo*_foobar2063=== CONT TestGlobMatch/foo*_foo2064=== CONT TestGlobMatch/*_anything2065=== CONT TestGlobMatch/fo?_fo2066=== CONT TestGlobMatch/foo_bar2067=== CONT TestGlobMatch/fo?_foo2068=== CONT TestGlobMatch/?oo_boo2069=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2070=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02071=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2072=== CONT TestGlobMatch/*/*_foo2073=== CONT TestGlobMatch/*/*_foo/bar2074=== CONT TestGlobMatch/foo*bar_foobarbaz2075=== CONT TestGlobMatch/foo*_bar2076=== CONT TestGlobMatch/*_2077=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2078=== CONT TestGlobMatch/refs/*/main_refs/heads/main2079--- PASS: TestGlobMatch (0.00s)2080 --- PASS: TestGlobMatch/foo_foo (0.00s)2081 --- PASS: TestGlobMatch/?oo_foo (0.00s)2082 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2083 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2084 --- PASS: TestGlobMatch/*bar_foo (0.00s)2085 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2086 --- PASS: TestGlobMatch/*bar_bar (0.00s)2087 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2088 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2089 --- PASS: TestGlobMatch/foo*_foo (0.00s)2090 --- PASS: TestGlobMatch/*_anything (0.00s)2091 --- PASS: TestGlobMatch/fo?_fo (0.00s)2092 --- PASS: TestGlobMatch/foo_bar (0.00s)2093 --- PASS: TestGlobMatch/fo?_foo (0.00s)2094 --- PASS: TestGlobMatch/?oo_boo (0.00s)2095 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2096 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2097 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2098 --- PASS: TestGlobMatch/*/*_foo (0.00s)2099 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2100 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2101 --- PASS: TestGlobMatch/foo*_bar (0.00s)2102 --- PASS: TestGlobMatch/*_ (0.00s)2103 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2104 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)21052026/10/01 13:04:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44861/oidc21062026/10/01 13:04:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42121/oidc2107--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.06s)2108--- PASS: TestPins_ReservedForMatchingRule (0.06s)21092026/10/01 13:04:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45667/oidc21102026/10/01 13:04:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35941/oidc2111--- PASS: TestValidateToken_Expired (0.07s)2112--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)21132026/10/01 13:04:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44889/oidc2114--- PASS: TestValidateToken_WrongAudience (0.08s)21152026/10/01 13:04:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38275/oidc21162026/10/01 13:04:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36165/oidc2117--- PASS: TestPins_TopLevelShorthand (0.15s)21182026/10/01 13:04:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41163/oidc21192026/10/01 13:04:01 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45309/oidc21202026/10/01 13:04:01 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232121--- PASS: TestValidateToken_ValidToken (0.16s)2122--- PASS: TestValidateToken_NoMatchingProvider (0.15s)2123--- PASS: TestScopes_Rules (0.16s)2124--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.16s)21252026/10/01 13:04:01 http: TLS handshake error from 127.0.0.1:56066: remote error: tls: bad certificate2126--- PASS: TestNewValidator_KubernetesRequiresCA (0.19s)21272026/10/01 13:04:01 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43331/oidc21282026/10/01 13:04:01 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:44939/oidc2129--- PASS: TestValidateToken_MultipleProviders (0.27s)21302026/10/01 13:04:01 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:408272131--- PASS: TestValidateToken_KubernetesServiceAccount (0.29s)21322026/10/01 13:04:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45003/oidc2133--- PASS: TestValidateToken_BoundSubjectMismatch (0.30s)2134PASS2135Running hook tests...2136=== RUN TestSendPathsEmpty2137=== PAUSE TestSendPathsEmpty2138=== RUN TestQueueEnqueueAndFetch2139=== PAUSE TestQueueEnqueueAndFetch2140=== RUN TestQueueDeduplication2141=== PAUSE TestQueueDeduplication2142=== RUN TestQueueRemove2143=== PAUSE TestQueueRemove2144=== RUN TestQueueFetchBatchLimit2145=== PAUSE TestQueueFetchBatchLimit2146=== RUN TestQueueRetryMovesToBack2147=== PAUSE TestQueueRetryMovesToBack2148=== RUN TestQueueFetchRemoveLifecycle2149=== PAUSE TestQueueFetchRemoveLifecycle2150=== RUN TestQueueConcurrentWriters2151=== PAUSE TestQueueConcurrentWriters2152=== RUN TestQueueRemoveLargeClosure2153=== PAUSE TestQueueRemoveLargeClosure2154=== RUN TestServerClientIntegration2155=== PAUSE TestServerClientIntegration2156=== RUN TestServerQueueError2157=== PAUSE TestServerQueueError2158=== RUN TestGetListenerSocketActivation2159 server_test.go:210: === RUN TestGetListenerSocketActivation2160 --- PASS: TestGetListenerSocketActivation (0.00s)2161 PASS2162 2163--- PASS: TestGetListenerSocketActivation (0.01s)2164=== RUN TestDrainIsolatesPoisonPath2165=== PAUSE TestDrainIsolatesPoisonPath2166=== RUN TestRunNotBlockedByPoisonHead2167=== PAUSE TestRunNotBlockedByPoisonHead2168=== RUN TestDrainGivesUpWhenServerDown2169=== PAUSE TestDrainGivesUpWhenServerDown2170=== RUN TestFailedPathPrunedByLaterClosure2171=== PAUSE TestFailedPathPrunedByLaterClosure2172=== RUN TestWorkerUploadsAndRemoves2173=== PAUSE TestWorkerUploadsAndRemoves2174=== RUN TestWorkerSkipsGCdPaths2175=== PAUSE TestWorkerSkipsGCdPaths2176=== RUN TestWorkerPrunesClosureDeps2177=== PAUSE TestWorkerPrunesClosureDeps2178=== RUN TestDrainTimeout2179=== PAUSE TestDrainTimeout2180=== CONT TestSendPathsEmpty2181=== CONT TestServerQueueError2182=== CONT TestDrainGivesUpWhenServerDown2183--- PASS: TestSendPathsEmpty (0.00s)2184=== CONT TestQueueFetchBatchLimit2185=== CONT TestQueueRemove2186=== CONT TestQueueDeduplication2187=== CONT TestQueueEnqueueAndFetch2188=== CONT TestQueueRetryMovesToBack2189=== CONT TestWorkerUploadsAndRemoves2190=== CONT TestDrainTimeout2191=== CONT TestWorkerPrunesClosureDeps2192=== CONT TestServerClientIntegration21932026/10/01 13:04:01 ERROR Failed to queue paths error="permission denied" count=12194=== CONT TestWorkerSkipsGCdPaths2195=== CONT TestQueueRemoveLargeClosure2196--- PASS: TestServerQueueError (0.00s)2197=== CONT TestQueueConcurrentWriters2198=== CONT TestRunNotBlockedByPoisonHead2199--- PASS: TestServerClientIntegration (0.00s)2200=== CONT TestQueueFetchRemoveLifecycle2201=== CONT TestFailedPathPrunedByLaterClosure2202=== CONT TestDrainIsolatesPoisonPath22032026/10/01 13:04:01 INFO Upload queue status pending=222042026/10/01 13:04:01 INFO Uploading batch count=122052026/10/01 13:04:01 ERROR Upload failed error="upload failed" count=122062026/10/01 13:04:01 INFO Uploading batch count=422072026/10/01 13:04:01 ERROR Upload failed error="upload failed" count=422082026/10/01 13:04:01 INFO Uploading batch count=222092026/10/01 13:04:01 INFO Uploading batch count=222102026/10/01 13:04:01 INFO Upload queue status pending=322112026/10/01 13:04:01 INFO Upload queue status pending=22212--- PASS: TestQueueFetchBatchLimit (0.01s)22132026/10/01 13:04:01 INFO Uploading batch count=122142026/10/01 13:04:01 ERROR Upload failed error="upload failed" count=122152026/10/01 13:04:01 INFO Uploading batch count=122162026/10/01 13:04:01 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2093209461/002/nonexistent2217--- PASS: TestQueueRetryMovesToBack (0.01s)2218--- PASS: TestQueueFetchRemoveLifecycle (0.01s)22192026/10/01 13:04:01 INFO Uploading batch count=222202026/10/01 13:04:01 ERROR Upload failed error="upload failed" count=222212026/10/01 13:04:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath1889878139/002/bbb22222026/10/01 13:04:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2854288329/002/a22232026/10/01 13:04:01 INFO Uploading batch count=122242026/10/01 13:04:01 INFO Uploading batch count=12225--- PASS: TestQueueEnqueueAndFetch (0.01s)22262026/10/01 13:04:01 INFO Upload queue status pending=22227--- PASS: TestQueueDeduplication (0.01s)22282026/10/01 13:04:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2854288329/002/b22292026/10/01 13:04:01 INFO Uploading batch count=12230--- PASS: TestQueueRemove (0.02s)22312026/10/01 13:04:01 INFO Uploading batch count=222322026/10/01 13:04:01 ERROR Upload failed error="upload failed" count=222332026/10/01 13:04:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2854288329/002/c22342026/10/01 13:04:01 INFO Uploading batch count=122352026/10/01 13:04:01 ERROR Upload failed error="upload failed" count=122362026/10/01 13:04:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2854288329/002/d2237--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)22382026/10/01 13:04:01 INFO Uploading batch count=222392026/10/01 13:04:01 ERROR Upload failed error="upload failed" count=222402026/10/01 13:04:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2854288329/002/e22412026/10/01 13:04:01 INFO Uploading batch count=122422026/10/01 13:04:01 ERROR Upload failed error="upload failed" count=122432026/10/01 13:04:01 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown2854288329/002/f22442026/10/01 13:04:01 INFO Uploading batch count=122452026/10/01 13:04:01 ERROR Upload failed error="upload failed" count=122462026/10/01 13:04:01 ERROR Drain finished with paths left in queue remaining=122472026/10/01 13:04:01 ERROR Drain finished with paths left in queue remaining=102248--- PASS: TestDrainIsolatesPoisonPath (0.02s)2249--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2250--- PASS: TestWorkerUploadsAndRemoves (0.03s)2251--- PASS: TestWorkerSkipsGCdPaths (0.03s)2252--- PASS: TestWorkerPrunesClosureDeps (0.03s)2253--- PASS: TestQueueConcurrentWriters (0.13s)2254--- PASS: TestQueueRemoveLargeClosure (0.14s)22552026/10/01 13:04:01 ERROR Upload failed error="context deadline exceeded" count=222562026/10/01 13:04:01 ERROR Drain finished with paths left in queue remaining=42257--- PASS: TestDrainTimeout (0.21s)22582026/10/01 13:04:02 INFO Uploading batch count=122592026/10/01 13:04:02 INFO Uploading batch count=122602026/10/01 13:04:02 INFO Uploading batch count=122612026/10/01 13:04:02 ERROR Upload failed error="upload failed" count=122622026/10/01 13:04:02 INFO Uploading batch count=122632026/10/01 13:04:02 ERROR Upload failed error="upload failed" count=122642026/10/01 13:04:02 INFO Uploading batch count=122652026/10/01 13:04:02 ERROR Upload failed error="upload failed" count=122662026/10/01 13:04:02 INFO Uploading batch count=122672026/10/01 13:04:02 ERROR Upload failed error="upload failed" count=122682026/10/01 13:04:02 ERROR Drain finished with paths left in queue remaining=12269--- PASS: TestRunNotBlockedByPoisonHead (1.02s)2270PASS