niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #359
· raw
1Running client tests...2=== RUN TestDoServerRequestAttachesToken3=== PAUSE TestDoServerRequestAttachesToken4=== RUN TestRegisterUploadedObjectReusesConnections5=== PAUSE TestRegisterUploadedObjectReusesConnections6=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica7=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica8=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun9=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun10=== RUN TestCaseHackSuffix11=== PAUSE TestCaseHackSuffix12=== RUN TestFilterOversizedClosures13=== PAUSE TestFilterOversizedClosures14=== RUN TestUploadMultipart_PartsInParallel15=== PAUSE TestUploadMultipart_PartsInParallel16=== RUN TestPartSizeForNAR17=== PAUSE TestPartSizeForNAR18=== RUN TestUploadMultipart_SupersededByPeer19=== PAUSE TestUploadMultipart_SupersededByPeer20=== RUN TestDumpPathCaseHackMatchesNix21--- PASS: TestDumpPathCaseHackMatchesNix (0.11s)22=== RUN TestDumpPathCaseHackCollision23--- PASS: TestDumpPathCaseHackCollision (0.00s)24=== RUN TestDumpPathMatchesNix25=== PAUSE TestDumpPathMatchesNix26=== RUN TestDumpPathSingleFile27=== PAUSE TestDumpPathSingleFile28=== RUN TestDumpPathWriterError29=== PAUSE TestDumpPathWriterError30=== RUN TestEncodeNixBase3231=== PAUSE TestEncodeNixBase3232=== RUN TestEncodeNixBase32WithRealHash33=== PAUSE TestEncodeNixBase32WithRealHash34=== RUN TestConvertHashToNix3235=== PAUSE TestConvertHashToNix3236=== RUN TestGetStorePathHash37=== PAUSE TestGetStorePathHash38=== RUN TestPathInfoHashCompatibility39=== PAUSE TestPathInfoHashCompatibility40=== RUN TestParsePathInfoJSON41=== PAUSE TestParsePathInfoJSON42=== RUN TestParsePathInfoJSONMultiplePaths43=== PAUSE TestParsePathInfoJSONMultiplePaths44=== RUN TestPathInfoCACompatibility45=== PAUSE TestPathInfoCACompatibility46=== RUN TestRateLimiterFeedback47=== PAUSE TestRateLimiterFeedback48=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess49=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== RUN TestResolveStorePath51=== PAUSE TestResolveStorePath52=== RUN TestDoWithRetry_BodyReplayedViaGetBody53=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody54=== RUN TestShellSplit55=== PAUSE TestShellSplit56=== RUN TestShellSplitErrors57=== PAUSE TestShellSplitErrors58=== RUN TestStreamPushReportsEveryPath59=== PAUSE TestStreamPushReportsEveryPath60=== RUN TestStreamPushBatchesUnderLoad61=== PAUSE TestStreamPushBatchesUnderLoad62=== RUN TestStreamPushIsolatesFailures63=== PAUSE TestStreamPushIsolatesFailures64=== RUN TestStreamPushGivesUpOnDeadServer65=== PAUSE TestStreamPushGivesUpOnDeadServer66=== RUN TestStreamPushRequestLine67=== PAUSE TestStreamPushRequestLine68=== RUN TestStreamPushReportsSignatures69=== PAUSE TestStreamPushReportsSignatures70=== RUN TestClientSignaturesByStorePath71=== PAUSE TestClientSignaturesByStorePath72=== RUN TestSetClientTLS73=== PAUSE TestSetClientTLS74=== RUN TestSetClientTLSDoesNotMutateDefaultTransport75=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport76=== RUN TestSetClientTLSErrors77=== PAUSE TestSetClientTLSErrors78=== RUN TestStaticToken79=== PAUSE TestStaticToken80=== RUN TestFileTokenReadsAndCaches81=== PAUSE TestFileTokenReadsAndCaches82=== RUN TestFileTokenMissing83=== PAUSE TestFileTokenMissing84=== RUN TestFileTokenEmpty85=== PAUSE TestFileTokenEmpty86=== RUN TestScriptTokenNoExpiryRerunsEveryCall87=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall88=== RUN TestScriptTokenCachesUntilRefresh89=== PAUSE TestScriptTokenCachesUntilRefresh90=== RUN TestScriptTokenEmptyToken91=== PAUSE TestScriptTokenEmptyToken92=== RUN TestScriptTokenBadJSON93=== PAUSE TestScriptTokenBadJSON94=== RUN TestScriptTokenScriptFails95=== PAUSE TestScriptTokenScriptFails96=== RUN TestScriptTokenEmptyCommand97=== PAUSE TestScriptTokenEmptyCommand98=== CONT TestDoServerRequestAttachesToken99=== CONT TestStreamPushIsolatesFailures100=== CONT TestConvertHashToNix32101=== CONT TestRateLimiterFeedback102=== RUN TestRateLimiterFeedback/429_enables_limiter103=== PAUSE TestRateLimiterFeedback/429_enables_limiter104=== RUN TestRateLimiterFeedback/503_enables_limiter105=== PAUSE TestRateLimiterFeedback/503_enables_limiter106=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter107=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter108=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter109=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter110=== CONT TestPathInfoCACompatibility111=== RUN TestPathInfoCACompatibility/null_ca_field112=== PAUSE TestPathInfoCACompatibility/null_ca_field113=== RUN TestPathInfoCACompatibility/old_string_format_-_text114=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text115=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive116=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive117=== CONT TestShellSplitErrors118--- PASS: TestShellSplitErrors (0.00s)119=== RUN TestPathInfoCACompatibility/new_structured_format_-_text120=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text121=== CONT TestParsePathInfoJSON122=== RUN TestParsePathInfoJSON/Nix_format123=== CONT TestPathInfoHashCompatibility124=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)125=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)126=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon1272026/10/05 11:42:57 ERROR Upload failed error="bad path" count=3128=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon129=== CONT TestGetStorePathHash130=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess131=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI132=== RUN TestConvertHashToNix32/SRI_format_to_Nix32133=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32134=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI135=== RUN TestConvertHashToNix32/already_Nix32_format136=== PAUSE TestConvertHashToNix32/already_Nix32_format137=== RUN TestConvertHashToNix32/invalid_format1382026/10/05 11:42:57 WARN Rate limiter enabled after throttle name=server-test rate=5139=== PAUSE TestConvertHashToNix32/invalid_format140=== CONT TestParsePathInfoJSONMultiplePaths141=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths142=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths143=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths144=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths145=== CONT TestStreamPushReportsEveryPath146=== CONT TestStreamPushBatchesUnderLoad147=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method148=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method149=== PAUSE TestParsePathInfoJSON/Nix_format150=== RUN TestParsePathInfoJSON/Lix_format151=== CONT TestFileTokenReadsAndCaches152=== RUN TestGetStorePathHash/valid_store_path153=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512154=== CONT TestScriptTokenEmptyCommand155--- PASS: TestStreamPushReportsEveryPath (0.00s)156=== CONT TestScriptTokenScriptFails157=== PAUSE TestParsePathInfoJSON/Lix_format158=== RUN TestParsePathInfoJSON/empty_input159=== PAUSE TestParsePathInfoJSON/empty_input160=== RUN TestParsePathInfoJSON/whitespace_only161=== PAUSE TestParsePathInfoJSON/whitespace_only162=== RUN TestParsePathInfoJSON/invalid_JSON163=== PAUSE TestParsePathInfoJSON/invalid_JSON164=== CONT TestScriptTokenBadJSON165--- PASS: TestStreamPushIsolatesFailures (0.00s)166=== CONT TestScriptTokenEmptyToken167=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512168=== CONT TestScriptTokenCachesUntilRefresh169=== PAUSE TestGetStorePathHash/valid_store_path170=== RUN TestGetStorePathHash/basename_without_hyphen_should_error171=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error172=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error173=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error174=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error175=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error176=== CONT TestFileTokenEmpty177--- PASS: TestScriptTokenEmptyCommand (0.00s)178=== CONT TestScriptTokenNoExpiryRerunsEveryCall179--- PASS: TestFileTokenEmpty (0.00s)180--- PASS: TestFileTokenReadsAndCaches (0.00s)181=== CONT TestDoWithRetry_BodyReplayedViaGetBody182--- PASS: TestScriptTokenScriptFails (0.01s)183=== CONT TestShellSplit184--- PASS: TestShellSplit (0.00s)185=== CONT TestPartSizeForNAR186=== RUN TestPartSizeForNAR/zero_stays_at_minimum187=== CONT TestFileTokenMissing188--- PASS: TestDoServerRequestAttachesToken (0.01s)189=== CONT TestEncodeNixBase32WithRealHash190=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum191--- PASS: TestEncodeNixBase32WithRealHash (0.00s)192=== CONT TestEncodeNixBase32193=== RUN TestPartSizeForNAR/small_stays_at_minimum194=== RUN TestEncodeNixBase32/test_string_hash195=== PAUSE TestPartSizeForNAR/small_stays_at_minimum196=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum197=== PAUSE TestEncodeNixBase32/test_string_hash198=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum199=== RUN TestEncodeNixBase32/empty_input200=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts201=== PAUSE TestEncodeNixBase32/empty_input202=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts203=== RUN TestPartSizeForNAR/1_TiB204=== PAUSE TestPartSizeForNAR/1_TiB205=== CONT TestDumpPathWriterError206=== RUN TestPartSizeForNAR/5_TiB_S3_max_object207=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object208=== RUN TestPartSizeForNAR/capped_at_5_GiB209=== PAUSE TestPartSizeForNAR/capped_at_5_GiB210=== CONT TestDumpPathSingleFile2112026/10/05 11:42:57 WARN Rate limiter enabled after throttle name=server-test rate=52122026/10/05 11:42:57 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:55145213--- PASS: TestFileTokenMissing (0.00s)214=== CONT TestDumpPathMatchesNix2152026/10/05 11:42:57 WARN Rate limiter backed off name=server-test rate=52162026/10/05 11:42:57 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:55145217--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)218=== CONT TestUploadMultipart_SupersededByPeer219=== RUN TestUploadMultipart_SupersededByPeer/exists220=== PAUSE TestUploadMultipart_SupersededByPeer/exists221=== RUN TestUploadMultipart_SupersededByPeer/missing222=== PAUSE TestUploadMultipart_SupersededByPeer/missing223=== CONT TestStreamPushReportsSignatures2242026/10/05 11:42:57 ERROR Upload failed error=boom count=1225--- PASS: TestStreamPushReportsSignatures (0.00s)226=== CONT TestClientSignaturesByStorePath227--- PASS: TestClientSignaturesByStorePath (0.00s)228=== CONT TestSetClientTLSErrors229=== RUN TestSetClientTLSErrors/missing_cert_file230=== PAUSE TestSetClientTLSErrors/missing_cert_file231=== RUN TestSetClientTLSErrors/missing_key_file232=== PAUSE TestSetClientTLSErrors/missing_key_file233=== RUN TestSetClientTLSErrors/missing_ca_file234=== PAUSE TestSetClientTLSErrors/missing_ca_file235=== RUN TestSetClientTLSErrors/invalid_ca_file236=== PAUSE TestSetClientTLSErrors/invalid_ca_file237=== CONT TestStaticToken238--- PASS: TestStaticToken (0.00s)239=== CONT TestResolveStorePath240--- PASS: TestResolveStorePath (0.00s)241=== CONT TestCaseHackSuffix242--- PASS: TestScriptTokenEmptyToken (0.01s)243=== CONT TestUploadMultipart_PartsInParallel244--- PASS: TestScriptTokenBadJSON (0.02s)245=== CONT TestFilterOversizedClosures246=== RUN TestFilterOversizedClosures/no_limit_keeps_everything247=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything248=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped249=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped250=== RUN TestFilterOversizedClosures/all_closures_skipped251=== PAUSE TestFilterOversizedClosures/all_closures_skipped252=== CONT TestSetClientTLS253=== RUN TestSetClientTLS/rejects_connection_without_client_cert254=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert255=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA256=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA257=== RUN TestSetClientTLS/preserves_debug_logging_transport258=== PAUSE TestSetClientTLS/preserves_debug_logging_transport259=== CONT TestSetClientTLSDoesNotMutateDefaultTransport260--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)261=== CONT TestStreamPushRequestLine2622026/10/05 11:42:57 ERROR Upload failed error=boom count=1263--- PASS: TestScriptTokenCachesUntilRefresh (0.03s)264=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica2652026/10/05 11:42:57 INFO Garbage collection started2662026/10/05 11:42:57 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0267--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)268=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun269--- PASS: TestStreamPushRequestLine (0.01s)270=== CONT TestRegisterUploadedObjectReusesConnections2712026/10/05 11:42:57 INFO Garbage collection started2722026/10/05 11:42:57 WARN Garbage collection finished on another replica. Its statistics are not available here273--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)274=== CONT TestStreamPushGivesUpOnDeadServer2752026/10/05 11:42:57 ERROR Upload failed error="connection refused" count=202762026/10/05 11:42:57 ERROR Server seems unavailable, giving up on batch untried=17277--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)278=== CONT TestRateLimiterFeedback/429_enables_limiter279--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)280=== CONT TestRateLimiterFeedback/503_enables_limiter2812026/10/05 11:42:57 WARN Rate limiter enabled after throttle name=server-test rate=52822026/10/05 11:42:57 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:551992832026/10/05 11:42:57 WARN Rate limiter enabled after throttle name=server-test rate=52842026/10/05 11:42:57 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:552232852026/10/05 11:42:57 WARN Rate limiter backed off name=server-test rate=5286=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter2872026/10/05 11:42:57 WARN Rate limiter backed off name=server-test rate=5288=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter289=== CONT TestConvertHashToNix32/SRI_format_to_Nix32290=== CONT TestConvertHashToNix32/invalid_format291=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths292=== CONT TestConvertHashToNix32/already_Nix32_format293--- PASS: TestConvertHashToNix32 (0.00s)294 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)295 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)296 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)297=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths298--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)299 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)300 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)301=== CONT TestPathInfoCACompatibility/null_ca_field302=== CONT TestPathInfoCACompatibility/new_structured_format_-_text303=== CONT TestPathInfoCACompatibility/old_string_format_-_text304=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive305=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method306=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)307=== CONT TestParsePathInfoJSON/whitespace_only308=== CONT TestParsePathInfoJSON/invalid_JSON309=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512310=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI311=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon312=== CONT TestParsePathInfoJSON/empty_input313--- PASS: TestRateLimiterFeedback (0.00s)314 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)315 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)316 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)317 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)318--- PASS: TestPathInfoCACompatibility (0.00s)319 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)320 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)321 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)322 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)323 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)324=== CONT TestParsePathInfoJSON/Nix_format325=== CONT TestParsePathInfoJSON/Lix_format326=== CONT TestGetStorePathHash/valid_store_path327=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error328=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error329=== CONT TestGetStorePathHash/basename_without_hyphen_should_error330=== CONT TestEncodeNixBase32/test_string_hash331=== CONT TestEncodeNixBase32/empty_input332=== CONT TestPartSizeForNAR/zero_stays_at_minimum333=== CONT TestPartSizeForNAR/1_TiB334=== CONT TestPartSizeForNAR/capped_at_5_GiB335=== CONT TestPartSizeForNAR/5_TiB_S3_max_object336=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum337=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts338=== CONT TestPartSizeForNAR/small_stays_at_minimum339=== CONT TestUploadMultipart_SupersededByPeer/exists340--- PASS: TestPathInfoHashCompatibility (0.00s)341 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)342 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)343 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)344 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)345=== CONT TestUploadMultipart_SupersededByPeer/missing346--- PASS: TestGetStorePathHash (0.00s)347 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)348 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)349 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)350 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)351--- PASS: TestEncodeNixBase32 (0.00s)352 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)353 --- PASS: TestEncodeNixBase32/empty_input (0.00s)354--- PASS: TestPartSizeForNAR (0.00s)355 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)356 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)357 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)358 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)359 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)360 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)361 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)362--- PASS: TestParsePathInfoJSON (0.00s)363 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)364 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)365 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)366 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)367 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)368=== CONT TestSetClientTLSErrors/missing_cert_file369=== CONT TestSetClientTLSErrors/missing_ca_file370=== CONT TestSetClientTLSErrors/invalid_ca_file371=== CONT TestSetClientTLSErrors/missing_key_file372--- PASS: TestDumpPathWriterError (0.04s)373=== CONT TestFilterOversizedClosures/all_closures_skipped3742026/10/05 11:42:57 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=50375=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3762026/10/05 11:42:57 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=2000377=== CONT TestSetClientTLS/rejects_connection_without_client_cert378--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)379 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)380 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)381=== CONT TestFilterOversizedClosures/no_limit_keeps_everything382--- PASS: TestSetClientTLSErrors (0.00s)383 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)384 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)385 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)386 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)387--- PASS: TestFilterOversizedClosures (0.00s)388 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)389 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)390 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)391=== CONT TestSetClientTLS/preserves_debug_logging_transport392=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA393--- PASS: TestRegisterUploadedObjectReusesConnections (0.02s)3942026/10/05 11:42:57 http: TLS handshake error from 127.0.0.1:55234: remote error: tls: bad certificate395--- PASS: TestSetClientTLS (0.00s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)397 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)398 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)399--- PASS: TestCaseHackSuffix (0.06s)400--- PASS: TestDumpPathSingleFile (0.07s)401--- PASS: TestStreamPushBatchesUnderLoad (0.10s)402--- PASS: TestDumpPathMatchesNix (0.11s)403--- PASS: TestUploadMultipart_PartsInParallel (0.61s)404--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)405PASS406Running server tests...407The files belonging to this database system will be owned by user "_nixbld17".408This user must also own the server process.409410The database cluster will be initialized with locale "C".411The default database encoding has accordingly been set to "SQL_ASCII".412The default text search configuration will be set to "english".413414Data page checksums are enabled.415416creating directory /nix/var/nix/builds/nix-49597-1397232080/postgres92909533/data ... ok417creating subdirectories ... ok418selecting dynamic shared memory implementation ... posix419selecting default "max_connections" ... 100420selecting default "shared_buffers" ... 128MB421selecting default time zone ... UTC422creating configuration files ... ok423running bootstrap script ... ok424performing post-bootstrap initialization ... ok425syncing data to disk ... ok426427initdb: warning: enabling "trust" authentication for local connections428initdb: 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.429430Success. You can now start the database server using:431432 pg_ctl -D /nix/var/nix/builds/nix-49597-1397232080/postgres92909533/data -l logfile start433434/nix/var/nix/builds/nix-49597-1397232080/postgres92909533:5432 - no response4352026-10-05 11:42:59.683 UTC [50259] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4362026-10-05 11:42:59.684 UTC [50259] LOG: listening on Unix socket "/nix/var/nix/builds/nix-49597-1397232080/postgres92909533/.s.PGSQL.5432"4372026-10-05 11:42:59.691 UTC [50271] LOG: database system was shut down at 2026-10-05 11:42:59 UTC4382026-10-05 11:42:59.692 UTC [50259] LOG: database system is ready to accept connections439/nix/var/nix/builds/nix-49597-1397232080/postgres92909533:5432 - accepting connections440{"timestamp":"2026-10-05T11:42:59.943303Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"a776bfe3-0888-4a42-b05c-3daaa2ef2b6c","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":14,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}441{"timestamp":"2026-10-05T11:43:00.056728Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3e463265-5328-4c98-b883-38377146e617","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(4)"}442{"timestamp":"2026-10-05T11:43:00.159701Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"1f5b1846-b49f-4fe9-8c2a-86c727d9cff3","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(10)"}443=== RUN TestService_AuthMiddleware444=== PAUSE TestService_AuthMiddleware445=== RUN TestService_AuthMiddleware_MTLSProxyHeader446=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader447=== RUN TestService_AuthMiddleware_MTLSBoundSubjects448=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects449=== RUN TestService_ReadAuthMiddleware450=== PAUSE TestService_ReadAuthMiddleware451=== RUN TestService_AuthMiddleware_OIDC452=== PAUSE TestService_AuthMiddleware_OIDC453=== RUN TestService_RequireScope_OIDC454=== PAUSE TestService_RequireScope_OIDC455=== RUN TestService_ReadScope_PublicByDefault456=== PAUSE TestService_ReadScope_PublicByDefault457=== RUN TestCacheConfigHandler458=== PAUSE TestCacheConfigHandler459=== RUN TestCacheStatsHandler460=== PAUSE TestCacheStatsHandler461=== RUN TestClientCADerivations462=== PAUSE TestClientCADerivations463=== RUN TestClientErrorHandling464=== PAUSE TestClientErrorHandling465=== RUN TestClientIntegration466=== PAUSE TestClientIntegration467=== RUN TestClientMultipleUploads468=== PAUSE TestClientMultipleUploads469=== RUN TestClientWithDependencies470=== PAUSE TestClientWithDependencies471=== RUN TestClientSharedPathCommittedMidPush472=== PAUSE TestClientSharedPathCommittedMidPush473=== RUN TestPinProtectsFromGC474=== PAUSE TestPinProtectsFromGC475=== RUN TestClientPushesUseOnePush476=== PAUSE TestClientPushesUseOnePush477=== RUN TestClientFallsBackToClosures478=== PAUSE TestClientFallsBackToClosures479=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock481=== RUN TestResolveDBConnectionString482=== PAUSE TestResolveDBConnectionString483=== RUN TestConnectWaitsForAPeerMigration484=== PAUSE TestConnectWaitsForAPeerMigration485=== RUN TestLeadElectsOneAndHandsOver486=== PAUSE TestLeadElectsOneAndHandsOver487=== RUN TestLeadIncumbentWinsAfterRestart4882026/10/05 11:43:00 INFO lead: acquired remote=192.0.2.1:12344892026/10/05 11:43:01 INFO lead: released remote=192.0.2.1:12344902026/10/05 11:43:01 INFO lead: acquired remote=192.0.2.1:12344912026/10/05 11:43:02 INFO lead: released remote=192.0.2.1:1234492--- PASS: TestLeadIncumbentWinsAfterRestart (2.06s)493=== RUN TestLeadIncumbentAnnouncesAtOnce494=== PAUSE TestLeadIncumbentAnnouncesAtOnce495=== RUN TestLeadEndsOnShutdown496=== PAUSE TestLeadEndsOnShutdown497=== RUN TestLeadEndsWhenItsConnectionHangs4982026/10/05 11:43:02 INFO lead: acquired remote=192.0.2.1:12344992026-10-05 11:43:03.903 UTC [50568] FATAL: terminating connection due to administrator command5002026/10/05 11:43:04 INFO lead: acquired remote=192.0.2.1:12345012026/10/05 11:43:05 WARN lead: lock connection lost error="timeout: context deadline exceeded"5022026/10/05 11:43:05 INFO lead: released remote=192.0.2.1:12345032026/10/05 11:43:05 INFO lead: released remote=192.0.2.1:1234504--- PASS: TestLeadEndsWhenItsConnectionHangs (2.98s)505=== RUN TestGCAdvisoryLockBlocksConcurrentRun506=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun507=== RUN TestGCBugBareHashReferences508=== PAUSE TestGCBugBareHashReferences509=== RUN TestGCMetrics510=== PAUSE TestGCMetrics511=== RUN TestPushDedupSurvivesConcurrentGC512=== PAUSE TestPushDedupSurvivesConcurrentGC513=== RUN TestDeduplicatedObjectsRecordedAsPending514=== PAUSE TestDeduplicatedObjectsRecordedAsPending515=== RUN TestGCSweepSkipsPendingObjects516=== PAUSE TestGCSweepSkipsPendingObjects517=== RUN TestTombstonedObjectOfferedWithoutWaiting518=== PAUSE TestTombstonedObjectOfferedWithoutWaiting519=== RUN TestGCSweepDeliversEachKeyOnce520=== PAUSE TestGCSweepDeliversEachKeyOnce521=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection523=== RUN TestForceGCDuringPushOffersSweptObject524=== PAUSE TestForceGCDuringPushOffersSweptObject525=== RUN TestFailedS3DeleteKeepsTombstone526=== PAUSE TestFailedS3DeleteKeepsTombstone527=== RUN TestSweepSkipsRowsLockedByPush528=== PAUSE TestSweepSkipsRowsLockedByPush529=== RUN TestRegisterCompletedObjectNeedsPendingRow530=== PAUSE TestRegisterCompletedObjectNeedsPendingRow531=== RUN TestGetExistingObjectsLocksRows532=== PAUSE TestGetExistingObjectsLocksRows533=== RUN TestSweepRechecksPendingAfterLocking534=== PAUSE TestSweepRechecksPendingAfterLocking535=== RUN TestPushWaitsForSweepHoldingRow536=== PAUSE TestPushWaitsForSweepHoldingRow537=== RUN TestCommitRacingPendingCleanupKeepsObjects538=== PAUSE TestCommitRacingPendingCleanupKeepsObjects539=== RUN TestGCEndsOnShutdown540=== PAUSE TestGCEndsOnShutdown541=== RUN TestGCTaskStore_StartNew542=== PAUSE TestGCTaskStore_StartNew543=== RUN TestGCTaskStore_DeduplicateSameParams544=== PAUSE TestGCTaskStore_DeduplicateSameParams545=== RUN TestGCTaskStore_ConflictDifferentParams546=== PAUSE TestGCTaskStore_ConflictDifferentParams547=== RUN TestGCTaskStore_GetEmpty548=== PAUSE TestGCTaskStore_GetEmpty549=== RUN TestGCTaskStore_GetReturnsLatest550=== PAUSE TestGCTaskStore_GetReturnsLatest551=== RUN TestGCTaskStore_CompletedAllowsNewTask552=== PAUSE TestGCTaskStore_CompletedAllowsNewTask553=== RUN TestGCTaskStore_PhaseUpdates554=== PAUSE TestGCTaskStore_PhaseUpdates555=== RUN TestGCTaskStore_Fail556=== PAUSE TestGCTaskStore_Fail557=== RUN TestGracefulShutdownDrainsInflight558=== PAUSE TestGracefulShutdownDrainsInflight559=== RUN TestService_healthCheckHandler560=== PAUSE TestService_healthCheckHandler561=== RUN TestService_readinessHandler562=== PAUSE TestService_readinessHandler563=== RUN TestGenerateLandingPage564=== PAUSE TestGenerateLandingPage565=== RUN TestCacheConfigHandlerMaxNarSize566=== PAUSE TestCacheConfigHandlerMaxNarSize567=== RUN TestCreatePendingClosureRejectsOversizedNAR568=== PAUSE TestCreatePendingClosureRejectsOversizedNAR569=== RUN TestNARDeduplicationMetadataUploadBug570=== PAUSE TestNARDeduplicationMetadataUploadBug571=== RUN TestMetricsInventory572=== PAUSE TestMetricsInventory573=== RUN TestService_NativeMTLS574=== PAUSE TestService_NativeMTLS575=== RUN TestServerTLSConfig576=== PAUSE TestServerTLSConfig577=== RUN TestMultipartCleanup578=== PAUSE TestMultipartCleanup579=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded580=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded581=== RUN TestPendingCleanupUsesOneCutoff582=== PAUSE TestPendingCleanupUsesOneCutoff583=== RUN TestObjectStatsTrigger584=== PAUSE TestObjectStatsTrigger585=== RUN TestOrphanedObjectsGC586=== PAUSE TestOrphanedObjectsGC587=== RUN TestOrphanedObjectsGCStressTest588=== PAUSE TestOrphanedObjectsGCStressTest589=== RUN TestCreatePin_ReservedPins590=== PAUSE TestCreatePin_ReservedPins591=== RUN TestPresentReportsOnlyClosureRoots592=== PAUSE TestPresentReportsOnlyClosureRoots593=== RUN TestPresentNotReportedWhileGCDeletesClosure594=== PAUSE TestPresentNotReportedWhileGCDeletesClosure595=== RUN TestParseSingleRange596=== PAUSE TestParseSingleRange597=== RUN TestProxyHeadersOnlyTrustedOnSocket598=== PAUSE TestProxyHeadersOnlyTrustedOnSocket599=== RUN TestIsValidCachePath600=== PAUSE TestIsValidCachePath601=== RUN TestReadProxyNarinfo602=== PAUSE TestReadProxyNarinfo603=== RUN TestReadProxyNarinfoAlreadyDecompressed604=== PAUSE TestReadProxyNarinfoAlreadyDecompressed605=== RUN TestReadProxyNarStreaming606=== PAUSE TestReadProxyNarStreaming607=== RUN TestReadProxy404608=== PAUSE TestReadProxy404609=== RUN TestReadProxyInvalidPath610=== PAUSE TestReadProxyInvalidPath611=== RUN TestReadProxyHead612=== PAUSE TestReadProxyHead613=== RUN TestReadProxyOutlastsServerWriteTimeout614=== PAUSE TestReadProxyOutlastsServerWriteTimeout615=== RUN TestReadProxyConditionalGet616=== PAUSE TestReadProxyConditionalGet617=== RUN TestReadProxyRootRedirectsToIndexHTML618=== PAUSE TestReadProxyRootRedirectsToIndexHTML619=== RUN TestReadProxyDisabled620=== PAUSE TestReadProxyDisabled621=== RUN TestReadRedirectNar622=== PAUSE TestReadRedirectNar623=== RUN TestReadRedirectKeepsNarinfoProxied624=== PAUSE TestReadRedirectKeepsNarinfoProxied625=== RUN TestReadProxyRangeRequest626=== PAUSE TestReadProxyRangeRequest627=== RUN TestReadRedirectUsesPublicS3URL628=== PAUSE TestReadRedirectUsesPublicS3URL629=== RUN TestPush_OverlappingRootsStoreOneRowPerKey630=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey631=== RUN TestPush_CompleteCommitsEveryRoot632=== PAUSE TestPush_CompleteCommitsEveryRoot633=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit634=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit635=== RUN TestPush_RejectsBadRequests636=== PAUSE TestPush_RejectsBadRequests637=== RUN TestPush_SignsNarinfosOfItsPendingObjects638=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects639=== RUN TestRedundantMultipartUpload640=== PAUSE TestRedundantMultipartUpload641=== RUN TestCompleteMultipartUpload_ErrorButObjectExists642=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists643=== RUN TestCompletedNarNotReofferedAcrossClosures644=== PAUSE TestCompletedNarNotReofferedAcrossClosures645=== RUN TestPresignedUploadRegisteredBeforeCommit646=== PAUSE TestPresignedUploadRegisteredBeforeCommit647=== RUN TestService_Rustfstest648=== PAUSE TestService_Rustfstest649=== RUN TestParseSize650=== PAUSE TestParseSize651=== RUN TestSkippedUploadsHandler652=== PAUSE TestSkippedUploadsHandler653=== RUN TestSystemdListenerNotActivated654--- PASS: TestSystemdListenerNotActivated (0.00s)655=== RUN TestWatchdogBeatsWhenHealthy656--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)657=== RUN TestWatchdogSkipsWhenUnhealthy6582026/10/05 11:43:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/05 11:43:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/05 11:43:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/05 11:43:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/05 11:43:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/05 11:43:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/05 11:43:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/05 11:43:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/05 11:43:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6672026/10/05 11:43:05 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"668--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)669=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle670=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle671=== RUN TestProxyWriteTimeout672=== PAUSE TestProxyWriteTimeout673=== RUN TestPendingClosureWriteTimeout674=== PAUSE TestPendingClosureWriteTimeout675=== RUN TestIsValidUploadKey676=== PAUSE TestIsValidUploadKey677=== RUN TestUploadHandlersRejectInvalidKeys678=== PAUSE TestUploadHandlersRejectInvalidKeys679=== RUN TestUploadHandlersRejectOversizedBody680=== PAUSE TestUploadHandlersRejectOversizedBody681=== RUN TestService_cleanupPendingClosuresHandler682=== PAUSE TestService_cleanupPendingClosuresHandler683=== RUN TestService_createPendingClosureHandler684=== PAUSE TestService_createPendingClosureHandler685=== RUN TestService_verifyS3Integrity686=== PAUSE TestService_verifyS3Integrity687=== RUN TestCompleteMultipartUnregistered688=== PAUSE TestCompleteMultipartUnregistered689=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT690=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT691=== CONT TestService_AuthMiddleware692=== CONT TestCreatePendingClosureRejectsOversizedNAR693=== CONT TestDeduplicatedObjectsRecordedAsPending694=== CONT TestClientSharedPathCommittedMidPush695=== CONT TestGCTaskStore_StartNew696--- PASS: TestGCTaskStore_StartNew (0.00s)697=== CONT TestSweepSkipsRowsLockedByPush698=== CONT TestCacheConfigHandlerMaxNarSize6992026/10/05 11:43:05 INFO Received uploads request method=POST path=/api/pending_closures700=== CONT TestGenerateLandingPage701=== CONT TestService_readinessHandler702=== CONT TestService_healthCheckHandler703=== CONT TestGCTaskStore_PhaseUpdates704=== CONT TestGCTaskStore_CompletedAllowsNewTask705=== CONT TestGCTaskStore_GetReturnsLatest706=== CONT TestGCTaskStore_GetEmpty707=== CONT TestGCTaskStore_ConflictDifferentParams708=== CONT TestGCTaskStore_DeduplicateSameParams709=== CONT TestReadRedirectNar710=== CONT TestGracefulShutdownDrainsInflight711--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)712--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)713--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)714--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)715--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)716--- PASS: TestGCTaskStore_GetEmpty (0.00s)717--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)718=== CONT TestGCTaskStore_Fail719=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT720--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)721--- PASS: TestGCTaskStore_Fail (0.00s)7222026/10/05 11:43:05 INFO Starting HTTP server address=127.0.0.1:552727232026/10/05 11:43:05 INFO Shutdown signal received, draining in-flight requests timeout=10s724--- PASS: TestGenerateLandingPage (0.00s)725=== CONT TestCompleteMultipartUnregistered726--- PASS: TestGracefulShutdownDrainsInflight (0.07s)727=== CONT TestService_verifyS3Integrity7282026/10/05 11:43:05 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"729--- PASS: TestService_AuthMiddleware (0.39s)730=== CONT TestService_createPendingClosureHandler7312026/10/05 11:43:06 INFO Received uploads request method=POST path=/api/pending_closures732--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.65s)733=== CONT TestService_cleanupPendingClosuresHandler734--- PASS: TestService_healthCheckHandler (0.72s)735=== CONT TestUploadHandlersRejectOversizedBody736=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure737=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure738=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart739=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart740=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts741=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts742=== CONT TestUploadHandlersRejectInvalidKeys743=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info744=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info745=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal746=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal747=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key748=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key749=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key750=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key751=== CONT TestIsValidUploadKey752=== RUN TestIsValidUploadKey/narinfo753=== PAUSE TestIsValidUploadKey/narinfo754=== RUN TestIsValidUploadKey/nar_zst755=== PAUSE TestIsValidUploadKey/nar_zst756=== RUN TestIsValidUploadKey/nar_xz757=== PAUSE TestIsValidUploadKey/nar_xz758=== RUN TestIsValidUploadKey/nar_plain759=== PAUSE TestIsValidUploadKey/nar_plain760=== RUN TestIsValidUploadKey/listing761=== PAUSE TestIsValidUploadKey/listing762=== RUN TestIsValidUploadKey/build_log763=== PAUSE TestIsValidUploadKey/build_log764=== RUN TestIsValidUploadKey/build_log_home-manager_file765=== PAUSE TestIsValidUploadKey/build_log_home-manager_file766=== RUN TestIsValidUploadKey/build_log_plus_in_name767=== PAUSE TestIsValidUploadKey/build_log_plus_in_name768=== RUN TestIsValidUploadKey/build_log_question_mark769=== PAUSE TestIsValidUploadKey/build_log_question_mark770=== RUN TestIsValidUploadKey/build_log_equals771=== PAUSE TestIsValidUploadKey/build_log_equals772=== RUN TestIsValidUploadKey/realisation773=== PAUSE TestIsValidUploadKey/realisation774=== RUN TestIsValidUploadKey/realisation_plus_in_output775=== PAUSE TestIsValidUploadKey/realisation_plus_in_output776=== RUN TestIsValidUploadKey/nix-cache-info777=== PAUSE TestIsValidUploadKey/nix-cache-info778=== RUN TestIsValidUploadKey/index.html779=== PAUSE TestIsValidUploadKey/index.html780=== RUN TestIsValidUploadKey/narinfo_key,_nar_type781=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type782=== RUN TestIsValidUploadKey/nar_key,_narinfo_type783=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type784=== RUN TestIsValidUploadKey/listing_key,_narinfo_type785=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type786=== RUN TestIsValidUploadKey/traversal787=== PAUSE TestIsValidUploadKey/traversal788=== RUN TestIsValidUploadKey/traversal_nar789=== PAUSE TestIsValidUploadKey/traversal_nar790=== RUN TestIsValidUploadKey/absolute791=== PAUSE TestIsValidUploadKey/absolute792=== RUN TestIsValidUploadKey/empty_key793=== PAUSE TestIsValidUploadKey/empty_key794=== RUN TestIsValidUploadKey/unknown_type795=== PAUSE TestIsValidUploadKey/unknown_type796=== CONT TestPendingClosureWriteTimeout797=== RUN TestPendingClosureWriteTimeout/empty798=== PAUSE TestPendingClosureWriteTimeout/empty799=== RUN TestPendingClosureWriteTimeout/400_objects800=== PAUSE TestPendingClosureWriteTimeout/400_objects801=== RUN TestPendingClosureWriteTimeout/670k_objects802=== PAUSE TestPendingClosureWriteTimeout/670k_objects803=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline804=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline805=== CONT TestProxyWriteTimeout806=== RUN TestProxyWriteTimeout/narinfo807=== PAUSE TestProxyWriteTimeout/narinfo808=== RUN TestProxyWriteTimeout/1_GiB_nar809=== PAUSE TestProxyWriteTimeout/1_GiB_nar810=== RUN TestProxyWriteTimeout/10_GiB_nar811=== PAUSE TestProxyWriteTimeout/10_GiB_nar812=== RUN TestProxyWriteTimeout/unknown_size813=== PAUSE TestProxyWriteTimeout/unknown_size814=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle8152026/10/05 11:43:06 INFO Aborted multipart uploads count=0 kept=08162026/10/05 11:43:06 WARN Force mode enabled - objects will be deleted immediately without grace period8172026/10/05 11:43:06 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=08182026/10/05 11:43:06 INFO Vacuumed table table=pending_closures8192026/10/05 11:43:06 INFO Vacuumed table table=pending_objects8202026/10/05 11:43:06 INFO Vacuumed table table=multipart_uploads8212026/10/05 11:43:06 INFO Vacuumed table table=closures8222026/10/05 11:43:06 INFO Vacuumed table table=objects8232026/10/05 11:43:06 INFO Aborted multipart uploads count=0 kept=08242026/10/05 11:43:06 WARN Force mode enabled - objects will be deleted immediately without grace period8252026/10/05 11:43:06 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=08262026/10/05 11:43:06 INFO Vacuumed table table=pending_closures8272026/10/05 11:43:06 INFO Vacuumed table table=pending_objects8282026/10/05 11:43:06 INFO Vacuumed table table=multipart_uploads8292026/10/05 11:43:06 INFO Vacuumed table table=closures8302026/10/05 11:43:06 INFO Vacuumed table table=objects831--- PASS: TestSweepSkipsRowsLockedByPush (1.02s)832=== CONT TestSkippedUploadsHandler8332026/10/05 11:43:06 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000834--- PASS: TestSkippedUploadsHandler (0.00s)835=== CONT TestParseSize836--- PASS: TestParseSize (0.00s)837=== CONT TestService_Rustfstest8382026/10/05 11:43:06 INFO Received uploads request method=POST path=/api/pending_closures839--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.13s)840=== CONT TestPresignedUploadRegisteredBeforeCommit8412026/10/05 11:43:06 INFO Received uploads request method=POST path=/api/pending_closures8422026/10/05 11:43:07 WARN readiness check failed error="closed pool"843--- PASS: TestService_readinessHandler (1.58s)844=== CONT TestCompletedNarNotReofferedAcrossClosures8452026/10/05 11:43:07 INFO Received push request method=POST path=/api/pushes8462026/10/05 11:43:07 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)8472026/10/05 11:43:07 INFO Uploading iaabpj45yr42bns4dgvkyvfkfhrm52ki-top (256B)8482026/10/05 11:43:07 INFO Uploading zxz6l0hnhjy4rrgki7y9xy8jczrisq52-shared-dep (136B)8492026/10/05 11:43:07 WARN Failed to register uploaded object key=iaabpj45yr42bns4dgvkyvfkfhrm52ki.ls error="server returned 404: 404 page not found\n"8502026/10/05 11:43:07 WARN Failed to register uploaded object key=nar/1df6dijaxnqzlw5j33p4dircjffaxicymw7is93znp1vp543g897.nar.zst error="server returned 404: 404 page not found\n"8512026/10/05 11:43:07 WARN Failed to register uploaded object key=zxz6l0hnhjy4rrgki7y9xy8jczrisq52.ls error="server returned 404: 404 page not found\n"8522026/10/05 11:43:07 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8532026/10/05 11:43:07 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"8542026/10/05 11:43:07 INFO Signed narinfos id=1 count=28552026/10/05 11:43:07 INFO Uploading 2 narinfos8562026/10/05 11:43:07 INFO Received complete push request method=POST path=/api/pushes/1/complete8572026/10/05 11:43:07 WARN Failed to register uploaded object key=iaabpj45yr42bns4dgvkyvfkfhrm52ki.narinfo error="server returned 404: 404 page not found\n"8582026/10/05 11:43:07 WARN Failed to register uploaded object key=zxz6l0hnhjy4rrgki7y9xy8jczrisq52.narinfo error="server returned 404: 404 page not found\n"8592026/10/05 11:43:07 INFO Upload complete. (168ms)860=== NAME TestClientSharedPathCommittedMidPush861 client_integration_test.go:680: Retrieved narinfo from S3:862 StorePath: /nix/var/nix/builds/nix-49597-1397232080/TestClientSharedPathCommittedMidPush2558912133/001/store/zxz6l0hnhjy4rrgki7y9xy8jczrisq52-shared-dep863 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst864 Compression: zstd865 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82866 NarSize: 136867 References: 868 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n869 client_integration_test.go:680: Retrieved narinfo from S3:870 StorePath: /nix/var/nix/builds/nix-49597-1397232080/TestClientSharedPathCommittedMidPush2558912133/001/store/iaabpj45yr42bns4dgvkyvfkfhrm52ki-top871 URL: nar/1df6dijaxnqzlw5j33p4dircjffaxicymw7is93znp1vp543g897.nar.zst872 Compression: zstd873 NarHash: sha256:1df6dijaxnqzlw5j33p4dircjffaxicymw7is93znp1vp543g897874 NarSize: 256875 References: /nix/var/nix/builds/nix-49597-1397232080/TestClientSharedPathCommittedMidPush2558912133/001/store/zxz6l0hnhjy4rrgki7y9xy8jczrisq52-shared-dep876 CA: text:sha256:1wpb0208d309cvx7ifc5kqgsyyynmmfd3jxpr55h9fkm5nrzyf9z877--- PASS: TestClientSharedPathCommittedMidPush (1.75s)878=== CONT TestCompleteMultipartUpload_ErrorButObjectExists879--- PASS: TestReadRedirectNar (1.84s)880=== CONT TestRedundantMultipartUpload8812026/10/05 11:43:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8822026/10/05 11:43:07 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst883--- PASS: TestCompleteMultipartUnregistered (2.05s)884=== CONT TestPush_SignsNarinfosOfItsPendingObjects8852026/10/05 11:43:07 INFO Received uploads request method=POST path=/api/pending_closures8862026/10/05 11:43:07 INFO Received uploads request method=POST path=/api/pending_closures8872026/10/05 11:43:07 INFO Received uploads request method=POST path=/api/pending_closures8882026/10/05 11:43:08 INFO Received cleanup request method=DELETE path=/api/pending_closures8892026/10/05 11:43:08 INFO Aborted multipart uploads count=0 kept=08902026/10/05 11:43:08 INFO Received uploads request method=POST path=/api/pending_closures8912026/10/05 11:43:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8922026/10/05 11:43:08 INFO Received cleanup request method=DELETE path=/api/pending_closures8932026/10/05 11:43:08 INFO Aborted multipart uploads count=1 kept=08942026/10/05 11:43:08 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZDIwOTY5MTItZGY4Mi00MTNlLWI1OTctNjg5OGRkYzdlNmE0LjU3MDBiMTMzLTU5OWItNDJlMi05YWY1LWEwNGM1NGM4NjdlYXgxNzkxMjAwNTg2OTYwOTQxMDAw parts=108952026/10/05 11:43:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8962026/10/05 11:43:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8972026-10-05 11:43:08.211 UTC [50893] ERROR: Closure does not exist: id=18982026-10-05 11:43:08.211 UTC [50893] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8992026-10-05 11:43:08.211 UTC [50893] STATEMENT: -- name: CommitPendingClosure :exec900 SELECT commit_pending_closure($1::bigint)901 902--- PASS: TestService_cleanupPendingClosuresHandler (2.03s)903=== CONT TestPush_RejectsBadRequests9042026/10/05 11:43:08 INFO Completed upload id=19052026/10/05 11:43:08 INFO Received uploads request method=POST path=/api/pending_closures9062026/10/05 11:43:08 INFO Received uploads request method=POST path=/api/pending_closures9072026/10/05 11:43:08 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9082026/10/05 11:43:08 WARN Found objects in DB but missing from S3, will re-upload count=1909--- PASS: TestService_verifyS3Integrity (2.62s)910=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit9112026/10/05 11:43:08 INFO Received uploads request method=POST path=/api/pending_closures912--- PASS: TestService_Rustfstest (2.13s)913=== CONT TestPush_CompleteCommitsEveryRoot9142026/10/05 11:43:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9152026/10/05 11:43:08 INFO Received uploads request method=POST path=/api/pending_closures9162026/10/05 11:43:08 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9172026/10/05 11:43:08 INFO Received uploads request method=POST path=/api/pending_closures918--- PASS: TestPresignedUploadRegisteredBeforeCommit (2.27s)919=== CONT TestPush_OverlappingRootsStoreOneRowPerKey9202026/10/05 11:43:09 INFO Received uploads request method=POST path=/api/pending_closures9212026/10/05 11:43:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9222026/10/05 11:43:09 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZDIwOTY5MTItZGY4Mi00MTNlLWI1OTctNjg5OGRkYzdlNmE0LmQzNTI1MmQ3LWU2M2MtNDI5OS1hMTdlLWZjNjlkZDA0MDI0M3gxNzkxMjAwNTg3ODczMTI2MDAw parts=109232026/10/05 11:43:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9242026/10/05 11:43:09 INFO Completed upload id=19252026/10/05 11:43:09 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009262026/10/05 11:43:09 INFO Received uploads request method=POST path=/api/pending_closures9272026/10/05 11:43:09 INFO Starting cleanup of old closures method=DELETE path=/api/closures9282026/10/05 11:43:09 INFO Aborted multipart uploads count=0 kept=09292026/10/05 11:43:09 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=09302026/10/05 11:43:09 INFO Vacuumed table table=pending_closures9312026/10/05 11:43:09 INFO Vacuumed table table=pending_objects9322026/10/05 11:43:09 INFO Vacuumed table table=multipart_uploads9332026/10/05 11:43:09 INFO Vacuumed table table=closures9342026/10/05 11:43:09 INFO Vacuumed table table=objects9352026/10/05 11:43:09 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000936--- PASS: TestService_createPendingClosureHandler (3.37s)937=== CONT TestReadRedirectUsesPublicS3URL9382026/10/05 11:43:09 INFO Received uploads request method=POST path=/api/pending_closures9392026/10/05 11:43:09 INFO Received uploads request method=POST path=/api/pending_closures9402026/10/05 11:43:09 INFO Received uploads request method=POST path=/api/pending_closures9412026/10/05 11:43:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9422026/10/05 11:43:09 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDIwOTY5MTItZGY4Mi00MTNlLWI1OTctNjg5OGRkYzdlNmE0Ljc5N2FiODNkLTRiN2UtNDhmZi1iOWJkLTU1NTAxNTk0ZTAxOXgxNzkxMjAwNTg5NjI1ODU1MDAw9432026/10/05 11:43:09 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDIwOTY5MTItZGY4Mi00MTNlLWI1OTctNjg5OGRkYzdlNmE0Ljc5N2FiODNkLTRiN2UtNDhmZi1iOWJkLTU1NTAxNTk0ZTAxOXgxNzkxMjAwNTg5NjI1ODU1MDAw parts=1944--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (2.60s)945=== CONT TestReadProxyRangeRequest9462026/10/05 11:43:09 INFO Received push request method=POST path=/api/pushes9472026/10/05 11:43:09 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9482026/10/05 11:43:09 INFO Signed narinfos id=1 count=1949--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.39s)950=== CONT TestReadRedirectKeepsNarinfoProxied951=== RUN TestPush_RejectsBadRequests/no_roots952=== PAUSE TestPush_RejectsBadRequests/no_roots953=== RUN TestPush_RejectsBadRequests/no_objects954=== PAUSE TestPush_RejectsBadRequests/no_objects955=== RUN TestPush_RejectsBadRequests/bad_root956=== PAUSE TestPush_RejectsBadRequests/bad_root957=== RUN TestPush_RejectsBadRequests/root_not_in_objects958=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects959=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection9602026/10/05 11:43:10 INFO Received push request method=POST path=/api/pushes9612026/10/05 11:43:10 INFO Received complete push request method=POST path=/api/pushes/1/complete9622026/10/05 11:43:10 INFO Received push request method=POST path=/api/pushes9632026/10/05 11:43:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9642026/10/05 11:43:10 INFO Aborted multipart uploads count=0 kept=09652026/10/05 11:43:10 WARN Force mode enabled - objects will be deleted immediately without grace period9662026/10/05 11:43:10 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=09672026/10/05 11:43:10 INFO Vacuumed table table=pending_closures9682026/10/05 11:43:10 INFO Vacuumed table table=pending_objects9692026/10/05 11:43:10 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZDIwOTY5MTItZGY4Mi00MTNlLWI1OTctNjg5OGRkYzdlNmE0LjQyNWRiYzJhLTkzNDItNDJkMC1hNTViLTE4OGY2OGFkZTJiMngxNzkxMjAwNTg5MTQ1MTA1MDAw parts=129702026/10/05 11:43:10 INFO Received uploads request method=POST path=/api/pending_closures971--- PASS: TestCompletedNarNotReofferedAcrossClosures (3.54s)972=== CONT TestFailedS3DeleteKeepsTombstone9732026/10/05 11:43:10 INFO Vacuumed table table=multipart_uploads9742026/10/05 11:43:10 INFO Vacuumed table table=closures9752026/10/05 11:43:10 INFO Vacuumed table table=objects9762026/10/05 11:43:10 INFO Received complete push request method=POST path=/api/pushes/2/complete977--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.51s)978=== CONT TestTombstonedObjectOfferedWithoutWaiting9792026/10/05 11:43:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9802026/10/05 11:43:10 INFO Received push request method=POST path=/api/pushes9812026/10/05 11:43:11 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZDIwOTY5MTItZGY4Mi00MTNlLWI1OTctNjg5OGRkYzdlNmE0LjM0NzZjYzViLTM2ZjktNDEyYy1iMmUzLTc2Y2E2YzAyNzcwY3gxNzkxMjAwNTg5Mzc5MjIzMDAw parts=129822026/10/05 11:43:11 INFO Received uploads request method=POST path=/api/pending_closures9832026/10/05 11:43:11 INFO Received complete push request method=POST path=/api/pushes/1/complete9842026/10/05 11:43:11 INFO Received uploads request method=POST path=/api/pending_closures985--- PASS: TestPush_CompleteCommitsEveryRoot (2.37s)986=== CONT TestForceGCDuringPushOffersSweptObject987=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows988=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows989=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check990=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check991=== CONT TestGCSweepDeliversEachKeyOnce9922026/10/05 11:43:11 INFO Received push request method=POST path=/api/pushes993--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (2.39s)994=== CONT TestPushWaitsForSweepHoldingRow995--- PASS: TestReadRedirectUsesPublicS3URL (2.32s)996=== CONT TestGCEndsOnShutdown997=== RUN TestGCEndsOnShutdown/before_the_run998=== PAUSE TestGCEndsOnShutdown/before_the_run999=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1000=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1001=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1002=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1003=== CONT TestCommitRacingPendingCleanupKeepsObjects1004--- PASS: TestReadProxyRangeRequest (2.19s)1005=== CONT TestGetExistingObjectsLocksRows1006--- PASS: TestReadRedirectKeepsNarinfoProxied (2.32s)1007=== CONT TestSweepRechecksPendingAfterLocking10082026/10/05 11:43:12 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10092026/10/05 11:43:12 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDIwOTY5MTItZGY4Mi00MTNlLWI1OTctNjg5OGRkYzdlNmE0LmU0MWQzMzY3LTQyMjQtNDEwYy05NDAyLWJjMzFlMzg0ODA2M3gxNzkxMjAwNTkxMDQ2NTg0MDAw error="Get \"http://127.0.0.1:1/bucket19/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"10102026/10/05 11:43:12 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDIwOTY5MTItZGY4Mi00MTNlLWI1OTctNjg5OGRkYzdlNmE0Ljk3NmJhNDc5LWQ3NmItNGI4Zi04ODcxLTUyYzg2YTQ2N2I0NXgxNzkxMjAwNTkxMDA1MDE5MDAw parts=1210112026/10/05 11:43:12 INFO Received cleanup request method=DELETE path=/api/pending_closures10122026/10/05 11:43:12 INFO Aborted multipart uploads count=1 kept=01013--- PASS: TestRedundantMultipartUpload (5.16s)1014=== CONT TestGCSweepSkipsPendingObjects10152026/10/05 11:43:12 INFO Received uploads request method=POST path=/api/pending_closures10162026/10/05 11:43:12 INFO Received uploads request method=POST path=/api/pending_closures1017--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (2.69s)1018=== CONT TestCacheConfigHandler1019=== RUN TestCacheConfigHandler/full_config,_no_issuer1020=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1021=== RUN TestCacheConfigHandler/no_cache_url_configured1022=== PAUSE TestCacheConfigHandler/no_cache_url_configured1023=== RUN TestCacheConfigHandler/no_signing_keys1024=== PAUSE TestCacheConfigHandler/no_signing_keys1025=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1026=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1027=== CONT TestLeadElectsOneAndHandsOver10282026/10/05 11:43:12 INFO Aborted multipart uploads count=0 kept=010292026/10/05 11:43:12 WARN Force mode enabled - objects will be deleted immediately without grace period10302026/10/05 11:43:12 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."10312026/10/05 11:43:12 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1032--- PASS: TestFailedS3DeleteKeepsTombstone (2.32s)1033=== CONT TestPushDedupSurvivesConcurrentGC10342026/10/05 11:43:13 INFO Received uploads request method=POST path=/api/pending_closures1035--- PASS: TestTombstonedObjectOfferedWithoutWaiting (2.40s)1036=== CONT TestGCMetrics10372026/10/05 11:43:13 INFO Aborted multipart uploads count=0 kept=010382026/10/05 11:43:13 WARN Force mode enabled - objects will be deleted immediately without grace period10392026/10/05 11:43:13 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=010402026/10/05 11:43:13 INFO Vacuumed table table=pending_closures10412026/10/05 11:43:13 INFO Vacuumed table table=pending_objects10422026/10/05 11:43:13 INFO Vacuumed table table=multipart_uploads10432026/10/05 11:43:13 INFO Vacuumed table table=closures10442026/10/05 11:43:13 INFO Vacuumed table table=objects1045--- PASS: TestGCSweepDeliversEachKeyOnce (2.51s)1046=== CONT TestGCBugBareHashReferences10472026/10/05 11:43:13 INFO Received uploads request method=POST path=/api/pending_closures10482026/10/05 11:43:13 WARN Rate limiter enabled after throttle name=s3-test rate=510492026/10/05 11:43:13 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1050=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1051 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101052 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001053--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.60s)1054=== CONT TestGCAdvisoryLockBlocksConcurrentRun10552026/10/05 11:43:14 INFO Aborted multipart uploads count=0 kept=010562026/10/05 11:43:14 WARN Force mode enabled - objects will be deleted immediately without grace period10572026/10/05 11:43:14 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=010582026/10/05 11:43:14 INFO Vacuumed table table=pending_closures10592026/10/05 11:43:14 INFO Vacuumed table table=pending_objects10602026/10/05 11:43:14 INFO Vacuumed table table=multipart_uploads10612026/10/05 11:43:14 INFO Vacuumed table table=closures10622026/10/05 11:43:14 INFO Vacuumed table table=objects1063--- PASS: TestCommitRacingPendingCleanupKeepsObjects (2.54s)1064=== CONT TestLeadEndsOnShutdown1065--- PASS: TestPushWaitsForSweepHoldingRow (2.85s)1066=== CONT TestLeadIncumbentAnnouncesAtOnce1067--- PASS: TestGetExistingObjectsLocksRows (2.62s)1068=== CONT TestClientWithDependencies10692026/10/05 11:43:14 INFO Received uploads request method=POST path=/api/pending_closures10702026/10/05 11:43:14 INFO Aborted multipart uploads count=0 kept=010712026/10/05 11:43:14 WARN Force mode enabled - objects will be deleted immediately without grace period10722026/10/05 11:43:14 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=010732026/10/05 11:43:14 INFO Vacuumed table table=pending_closures10742026/10/05 11:43:15 INFO Vacuumed table table=pending_objects10752026/10/05 11:43:15 INFO Vacuumed table table=multipart_uploads10762026/10/05 11:43:15 INFO Vacuumed table table=closures10772026/10/05 11:43:15 INFO Vacuumed table table=objects1078--- PASS: TestGCSweepSkipsPendingObjects (2.51s)1079=== CONT TestClientMultipleUploads10802026/10/05 11:43:15 INFO Aborted multipart uploads count=0 kept=010812026/10/05 11:43:15 WARN Force mode enabled - objects will be deleted immediately without grace period10822026/10/05 11:43:15 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=010832026/10/05 11:43:15 INFO Vacuumed table table=pending_closures10842026/10/05 11:43:15 INFO Vacuumed table table=pending_objects10852026/10/05 11:43:15 INFO Vacuumed table table=multipart_uploads10862026/10/05 11:43:15 INFO Vacuumed table table=closures10872026/10/05 11:43:15 INFO Vacuumed table table=objects1088--- PASS: TestSweepRechecksPendingAfterLocking (2.94s)1089=== CONT TestClientIntegration10902026/10/05 11:43:15 INFO lead: acquired remote=192.0.2.1:123410912026/10/05 11:43:15 INFO Received uploads request method=POST path=/api/pending_closures10922026/10/05 11:43:15 INFO Aborted multipart uploads count=0 kept=010932026/10/05 11:43:15 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=010942026/10/05 11:43:15 INFO Aborted multipart uploads count=0 kept=010952026/10/05 11:43:15 INFO Vacuumed table table=pending_closures10962026/10/05 11:43:15 WARN Force mode enabled - objects will be deleted immediately without grace period10972026/10/05 11:43:15 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=010982026/10/05 11:43:15 INFO Vacuumed table table=pending_closures10992026/10/05 11:43:15 INFO Vacuumed table table=pending_objects11002026/10/05 11:43:15 INFO Vacuumed table table=multipart_uploads11012026/10/05 11:43:15 INFO Vacuumed table table=closures11022026/10/05 11:43:15 INFO Vacuumed table table=objects1103--- PASS: TestGCMetrics (2.64s)1104=== CONT TestClientErrorHandling1105=== RUN TestClientErrorHandling/InvalidStorePath1106=== PAUSE TestClientErrorHandling/InvalidStorePath1107=== RUN TestClientErrorHandling/InvalidAuthToken1108=== PAUSE TestClientErrorHandling/InvalidAuthToken1109=== RUN TestClientErrorHandling/ServerNotAvailable1110=== PAUSE TestClientErrorHandling/ServerNotAvailable1111=== CONT TestClientCADerivations11122026/10/05 11:43:15 INFO Vacuumed table table=pending_objects11132026/10/05 11:43:15 INFO Vacuumed table table=multipart_uploads11142026/10/05 11:43:15 INFO Vacuumed table table=closures11152026/10/05 11:43:15 INFO Vacuumed table table=objects11162026/10/05 11:43:15 INFO Aborted multipart uploads count=0 kept=011172026/10/05 11:43:15 WARN Force mode enabled - objects will be deleted immediately without grace period11182026/10/05 11:43:15 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=011192026/10/05 11:43:15 INFO Vacuumed table table=pending_closures11202026/10/05 11:43:15 INFO Vacuumed table table=pending_objects11212026/10/05 11:43:15 INFO Vacuumed table table=multipart_uploads11222026/10/05 11:43:15 INFO Vacuumed table table=closures11232026/10/05 11:43:15 INFO Vacuumed table table=objects1124--- PASS: TestPushDedupSurvivesConcurrentGC (2.89s)1125=== CONT TestCacheStatsHandler11262026/10/05 11:43:16 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_nixbld17 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1127--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (2.26s)1128=== CONT TestPendingCleanupUsesOneCutoff1129--- PASS: TestGCBugBareHashReferences (2.66s)1130=== CONT TestParseSingleRange1131=== RUN TestParseSingleRange/none1132=== PAUSE TestParseSingleRange/none1133=== RUN TestParseSingleRange/unknown_unit1134=== PAUSE TestParseSingleRange/unknown_unit1135=== RUN TestParseSingleRange/multi-range_ignored1136=== PAUSE TestParseSingleRange/multi-range_ignored1137=== RUN TestParseSingleRange/malformed_no_dash1138=== PAUSE TestParseSingleRange/malformed_no_dash1139=== RUN TestParseSingleRange/malformed_both_empty1140=== PAUSE TestParseSingleRange/malformed_both_empty1141=== RUN TestParseSingleRange/malformed_end_before_start1142=== PAUSE TestParseSingleRange/malformed_end_before_start1143=== RUN TestParseSingleRange/closed1144=== PAUSE TestParseSingleRange/closed1145=== RUN TestParseSingleRange/open-ended1146=== PAUSE TestParseSingleRange/open-ended1147=== RUN TestParseSingleRange/end_clamped_to_size1148=== PAUSE TestParseSingleRange/end_clamped_to_size1149=== RUN TestParseSingleRange/suffix1150=== PAUSE TestParseSingleRange/suffix1151=== RUN TestParseSingleRange/suffix_exceeds_size1152=== PAUSE TestParseSingleRange/suffix_exceeds_size1153=== RUN TestParseSingleRange/single_byte1154=== PAUSE TestParseSingleRange/single_byte1155=== RUN TestParseSingleRange/start_past_EOF1156=== PAUSE TestParseSingleRange/start_past_EOF1157=== RUN TestParseSingleRange/start_far_past_EOF1158=== PAUSE TestParseSingleRange/start_far_past_EOF1159=== CONT TestPresentNotReportedWhileGCDeletesClosure11602026/10/05 11:43:16 INFO lead: acquired remote=192.0.2.1:123411612026/10/05 11:43:16 INFO lead: released remote=192.0.2.1:123411622026/10/05 11:43:16 INFO lead: acquired remote=192.0.2.1:123411632026/10/05 11:43:16 INFO lead: released remote=192.0.2.1:12341164--- PASS: TestLeadIncumbentAnnouncesAtOnce (2.33s)1165=== CONT TestPresentReportsOnlyClosureRoots11662026/10/05 11:43:16 INFO lead: acquired remote=192.0.2.1:12341167=== NAME TestClientMultipleUploads1168 client_integration_test.go:358: Created store path 0: /nix/var/nix/builds/nix-49597-1397232080/TestClientMultipleUploads614761958/001/store/ids91ygzmpklrv37hg0i77cvc1rr9xdj-test-file-0.txt1169 client_integration_test.go:358: Created store path 1: /nix/var/nix/builds/nix-49597-1397232080/TestClientMultipleUploads614761958/001/store/f1p1xrmnczn2lsky140kbzl056iklxkr-test-file-1.txt1170=== NAME TestClientIntegration1171 client_integration_test.go:286: Created store path: /nix/var/nix/builds/nix-49597-1397232080/TestClientIntegration3981383095/002/store/m2zi4va2agm294np705hi171drj2xzg1-test-file.txt11722026/10/05 11:43:17 INFO lead: released remote=192.0.2.1:12341173--- PASS: TestLeadEndsOnShutdown (3.24s)1174=== CONT TestCreatePin_ReservedPins1175=== NAME TestClientMultipleUploads1176 client_integration_test.go:358: Created store path 2: /nix/var/nix/builds/nix-49597-1397232080/TestClientMultipleUploads614761958/001/store/6mf763c2qkvvd92c93rqs60l3icxpmxq-test-file-2.txt11772026/10/05 11:43:17 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55428/oidc11782026/10/05 11:43:17 INFO Received push request method=POST path=/api/pushes1179=== NAME TestClientWithDependencies1180 client_integration_test.go:613: Built derivation: /nix/var/nix/builds/nix-49597-1397232080/TestClientWithDependencies2399445983/001/store/w7gi7lfcv1vingr008m8vrkrc7yn8q1c-test-script11812026/10/05 11:43:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11822026/10/05 11:43:17 INFO Uploading m2zi4va2agm294np705hi171drj2xzg1-test-file.txt (152B)11832026/10/05 11:43:17 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"11842026/10/05 11:43:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11852026/10/05 11:43:17 WARN Failed to register uploaded object key=m2zi4va2agm294np705hi171drj2xzg1.ls error="server returned 404: 404 page not found\n"11862026/10/05 11:43:17 INFO Signed narinfos id=1 count=111872026/10/05 11:43:17 INFO Uploading 1 narinfos11882026/10/05 11:43:17 INFO Received complete push request method=POST path=/api/pushes/1/complete11892026/10/05 11:43:17 WARN Failed to register uploaded object key=m2zi4va2agm294np705hi171drj2xzg1.narinfo error="server returned 404: 404 page not found\n"11902026/10/05 11:43:17 INFO Upload complete. (135ms)11912026/10/05 11:43:17 INFO Received push request method=POST path=/api/pushes11922026/10/05 11:43:17 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)11932026/10/05 11:43:17 INFO Uploading 6mf763c2qkvvd92c93rqs60l3icxpmxq-test-file-2.txt (160B)11942026/10/05 11:43:17 INFO Uploading ids91ygzmpklrv37hg0i77cvc1rr9xdj-test-file-0.txt (160B)11952026/10/05 11:43:17 INFO Uploading f1p1xrmnczn2lsky140kbzl056iklxkr-test-file-1.txt (160B)11962026/10/05 11:43:17 INFO All 1 paths already cached1197=== NAME TestClientIntegration1198 client_integration_test.go:312: Retrieved narinfo from S3:1199 StorePath: /nix/var/nix/builds/nix-49597-1397232080/TestClientIntegration3981383095/002/store/m2zi4va2agm294np705hi171drj2xzg1-test-file.txt1200 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1201 Compression: zstd1202 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11203 NarSize: 1521204 References: 1205 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11206 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1207 client_integration_test.go:313: Decompressed .ls content (64 bytes):1208 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1209 client_integration_test.go:316: Testing garbage collection...12102026/10/05 11:43:17 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"12112026/10/05 11:43:17 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"12122026/10/05 11:43:17 WARN Failed to register uploaded object key=6mf763c2qkvvd92c93rqs60l3icxpmxq.ls error="server returned 404: 404 page not found\n"12132026/10/05 11:43:17 WARN Failed to register uploaded object key=ids91ygzmpklrv37hg0i77cvc1rr9xdj.ls error="server returned 404: 404 page not found\n"12142026/10/05 11:43:17 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"12152026/10/05 11:43:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12162026/10/05 11:43:17 WARN Failed to register uploaded object key=f1p1xrmnczn2lsky140kbzl056iklxkr.ls error="server returned 404: 404 page not found\n"12172026/10/05 11:43:17 INFO Signed narinfos id=1 count=312182026/10/05 11:43:17 INFO Uploading 3 narinfos12192026/10/05 11:43:17 WARN Failed to register uploaded object key=6mf763c2qkvvd92c93rqs60l3icxpmxq.narinfo error="server returned 404: 404 page not found\n"12202026/10/05 11:43:17 WARN Failed to register uploaded object key=f1p1xrmnczn2lsky140kbzl056iklxkr.narinfo error="server returned 404: 404 page not found\n"12212026/10/05 11:43:17 WARN Failed to register uploaded object key=ids91ygzmpklrv37hg0i77cvc1rr9xdj.narinfo error="server returned 404: 404 page not found\n"12222026/10/05 11:43:17 INFO Received complete push request method=POST path=/api/pushes/1/complete12232026/10/05 11:43:17 INFO Upload complete. (179ms)1224=== NAME TestClientMultipleUploads1225 client_integration_test.go:369: Uploaded 3 paths in 238.268375ms12262026/10/05 11:43:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures12272026/10/05 11:43:17 INFO Garbage collection started12282026/10/05 11:43:17 INFO lead: released remote=192.0.2.1:12341229--- PASS: TestLeadElectsOneAndHandsOver (4.83s)1230=== CONT TestOrphanedObjectsGCStressTest12312026/10/05 11:43:17 INFO Aborted multipart uploads count=0 kept=012322026/10/05 11:43:17 WARN Force mode enabled - objects will be deleted immediately without grace period1233--- PASS: TestCacheStatsHandler (1.81s)1234=== CONT TestReadProxyDisabled1235--- PASS: TestClientMultipleUploads (2.64s)1236=== CONT TestReadProxyRootRedirectsToIndexHTML1237=== NAME TestClientWithDependencies1238 client_integration_test.go:615: Found 1 dependencies (including self)12392026/10/05 11:43:17 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=012402026/10/05 11:43:17 INFO Vacuumed table table=pending_closures12412026/10/05 11:43:17 INFO Vacuumed table table=pending_objects12422026/10/05 11:43:17 INFO Vacuumed table table=multipart_uploads12432026/10/05 11:43:17 INFO Vacuumed table table=closures12442026/10/05 11:43:17 INFO Vacuumed table table=objects12452026/10/05 11:43:17 INFO Received uploads request method=POST path=/api/pending_closures12462026/10/05 11:43:17 INFO Received push request method=POST path=/api/pushes12472026/10/05 11:43:17 INFO Received uploads request method=POST path=/api/pending_closures12482026/10/05 11:43:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12492026/10/05 11:43:17 INFO Uploading w7gi7lfcv1vingr008m8vrkrc7yn8q1c-test-script (136B)12502026/10/05 11:43:17 WARN Failed to register uploaded object key=w7gi7lfcv1vingr008m8vrkrc7yn8q1c.ls error="server returned 404: 404 page not found\n"12512026/10/05 11:43:17 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"12522026/10/05 11:43:17 WARN Failed to register uploaded object key=log/ri225yhcz8a8vknmg5spil5dgv5ddn5s-test-script.drv error="server returned 404: 404 page not found\n"12532026/10/05 11:43:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12542026/10/05 11:43:17 INFO Signed narinfos id=1 count=112552026/10/05 11:43:17 INFO Uploading 1 narinfos12562026/10/05 11:43:17 INFO Received cleanup request method=DELETE path=/api/pending_closures12572026/10/05 11:43:17 INFO Received complete push request method=POST path=/api/pushes/1/complete12582026/10/05 11:43:17 WARN Failed to register uploaded object key=w7gi7lfcv1vingr008m8vrkrc7yn8q1c.narinfo error="server returned 404: 404 page not found\n"12592026/10/05 11:43:17 INFO Upload complete. (233ms)1260 client_integration_test.go:617: Skipping nix copy test - isolated store (/nix/var/nix/builds/nix-49597-1397232080/TestClientWithDependencies2399445983/001/store) requires matching store prefix1261--- PASS: TestClientWithDependencies (3.37s)1262=== CONT TestOrphanedObjectsGC1263--- PASS: TestPresentReportsOnlyClosureRoots (1.81s)1264=== CONT TestObjectStatsTrigger1265=== NAME TestClientCADerivations1266 client_ca_test.go:136: Built CA derivation: /nix/var/nix/builds/nix-49597-1397232080/TestClientCADerivations2432578959/001/store/xdil2ciyk426rmxj1bdq5hfff6q9mc34-ca-test12672026/10/05 11:43:18 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12682026/10/05 11:43:18 WARN Refused reserved pin name=worker-x86_64-linux12692026/10/05 11:43:18 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12702026/10/05 11:43:18 INFO Received create pin request method=POST path=/api/pins/my-app12712026/10/05 11:43:18 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1272--- PASS: TestCreatePin_ReservedPins (1.16s)1273=== CONT TestConnectWaitsForAPeerMigration1274=== NAME TestClientCADerivations1275 client_ca_test.go:139: Found 1 dependencies (including self)1276--- PASS: TestPresentNotReportedWhileGCDeletesClosure (2.41s)1277=== CONT TestReadProxyConditionalGet1278--- PASS: TestReadProxyDisabled (1.12s)1279=== CONT TestResolveDBConnectionString1280=== RUN TestResolveDBConnectionString/flag_wins1281=== PAUSE TestResolveDBConnectionString/flag_wins1282=== RUN TestResolveDBConnectionString/file_when_flag_empty1283=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1284=== RUN TestResolveDBConnectionString/missing_file_is_an_error1285=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1286=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1287=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1288=== RUN TestResolveDBConnectionString/nothing_configured1289=== PAUSE TestResolveDBConnectionString/nothing_configured1290=== CONT TestReadProxyOutlastsServerWriteTimeout12912026/10/05 11:43:18 INFO Received push request method=POST path=/api/pushes12922026/10/05 11:43:18 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12932026/10/05 11:43:18 INFO Uploading xdil2ciyk426rmxj1bdq5hfff6q9mc34-ca-test (144B)12942026/10/05 11:43:18 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"12952026/10/05 11:43:18 WARN Failed to register uploaded object key=xdil2ciyk426rmxj1bdq5hfff6q9mc34.ls error="server returned 404: 404 page not found\n"12962026/10/05 11:43:18 WARN Failed to register uploaded object key=log/bgc42rsj7v64jk5r7706axck617zha0a-ca-test.drv error="server returned 404: 404 page not found\n"12972026/10/05 11:43:18 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12982026/10/05 11:43:18 INFO Signed narinfos id=1 count=112992026/10/05 11:43:18 INFO Uploading 1 narinfos13002026/10/05 11:43:18 INFO Received complete push request method=POST path=/api/pushes/1/complete13012026/10/05 11:43:18 WARN Failed to register uploaded object key=xdil2ciyk426rmxj1bdq5hfff6q9mc34.narinfo error="server returned 404: 404 page not found\n"13022026/10/05 11:43:18 INFO Upload complete. (259ms)1303=== NAME TestClientCADerivations1304 client_ca_test.go:180: Narinfo contains CA field: StorePath: /nix/var/nix/builds/nix-49597-1397232080/TestClientCADerivations2432578959/001/store/xdil2ciyk426rmxj1bdq5hfff6q9mc34-ca-test1305 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1306 Compression: zstd1307 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1308 NarSize: 1441309 References: 1310 Deriver: /nix/var/nix/builds/nix-49597-1397232080/TestClientCADerivations2432578959/001/store/bgc42rsj7v64jk5r7706axck617zha0a-ca-test.drv1311 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1312 client_ca_test.go:185: Checking for realisation files in S3...1313 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1314 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1315 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket48?endpoint=http://localhost:55244®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/nix/var/nix/builds/nix-49597-1397232080/TestClientCADerivations2432578959/001/store'1316 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11317--- PASS: TestClientCADerivations (3.44s)1318=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1319--- PASS: TestReadProxyRootRedirectsToIndexHTML (1.63s)1320=== CONT TestRegisterCompletedObjectNeedsPendingRow13212026/10/05 11:43:19 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01322=== NAME TestClientIntegration1323 client_integration_test.go:323: Objects in database after GC:1324 client_integration_test.go:323: Successfully deleted all objects with GC --force1325--- PASS: TestClientIntegration (4.51s)1326=== CONT TestReadProxyHead1327--- PASS: TestObjectStatsTrigger (1.60s)1328=== CONT TestClientPushesUseOnePush1329=== NAME TestOrphanedObjectsGC1330 orphaned_objects_gc_test.go:290: GC Test Summary:1331 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1332 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1333 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1334 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1335 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1336--- PASS: TestOrphanedObjectsGC (2.08s)1337=== CONT TestReadProxyInvalidPath1338--- PASS: TestReadProxyConditionalGet (1.86s)1339=== CONT TestClientFallsBackToClosures1340--- PASS: TestRegisterCompletedObjectNeedsPendingRow (2.27s)1341=== CONT TestReadProxy4041342--- PASS: TestReadProxyHead (2.27s)1343=== CONT TestReadProxyNarStreaming1344--- PASS: TestReadProxyInvalidPath (2.43s)1345=== CONT TestReadProxyNarinfoAlreadyDecompressed13462026/10/05 11:43:22 INFO Received push request method=POST path=/api/pushes13472026/10/05 11:43:22 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13482026/10/05 11:43:22 INFO Uploading lbghsjjvjl5fkj01yy35kch43p1fh4kb-shared-dep (136B)13492026/10/05 11:43:22 INFO Uploading s4ixfa41n1gq2yajdj1m9m6z2p6p313l-a (248B)13502026/10/05 11:43:22 WARN Failed to register uploaded object key=bxmx5fjsj1sxlgc6bp3mk0c36bn5kg94.ls error="server returned 404: 404 page not found\n"13512026/10/05 11:43:22 WARN Failed to register uploaded object key=nar/15cydhi6wv8s7avd3vjkqcgrb13h2k4lk4nprxfjkxfzcj5v6vja.nar.zst error="server returned 404: 404 page not found\n"13522026/10/05 11:43:22 WARN Failed to register uploaded object key=s4ixfa41n1gq2yajdj1m9m6z2p6p313l.ls error="server returned 404: 404 page not found\n"13532026/10/05 11:43:22 WARN Failed to register uploaded object key=lbghsjjvjl5fkj01yy35kch43p1fh4kb.ls error="server returned 404: 404 page not found\n"13542026/10/05 11:43:22 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13552026/10/05 11:43:22 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13562026/10/05 11:43:22 INFO Signed narinfos id=1 count=313572026/10/05 11:43:22 INFO Uploading 3 narinfos13582026/10/05 11:43:22 WARN Failed to register uploaded object key=lbghsjjvjl5fkj01yy35kch43p1fh4kb.narinfo error="server returned 404: 404 page not found\n"13592026/10/05 11:43:22 WARN Failed to register uploaded object key=s4ixfa41n1gq2yajdj1m9m6z2p6p313l.narinfo error="server returned 404: 404 page not found\n"13602026/10/05 11:43:22 INFO Received complete push request method=POST path=/api/pushes/1/complete13612026/10/05 11:43:22 WARN Failed to register uploaded object key=bxmx5fjsj1sxlgc6bp3mk0c36bn5kg94.narinfo error="server returned 404: 404 page not found\n"1362--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (3.65s)1363=== CONT TestReadProxyNarinfo13642026/10/05 11:43:22 INFO Upload complete. (171ms)1365=== NAME TestClientPushesUseOnePush1366 client_pushes_test.go:97: Retrieved narinfo from S3:1367 StorePath: /nix/var/nix/builds/nix-49597-1397232080/TestClientPushesUseOnePush475381917/001/store/lbghsjjvjl5fkj01yy35kch43p1fh4kb-shared-dep1368 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1369 Compression: zstd1370 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821371 NarSize: 1361372 References: 1373 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1374 client_pushes_test.go:97: Retrieved narinfo from S3:1375 StorePath: /nix/var/nix/builds/nix-49597-1397232080/TestClientPushesUseOnePush475381917/001/store/s4ixfa41n1gq2yajdj1m9m6z2p6p313l-a1376 URL: nar/15cydhi6wv8s7avd3vjkqcgrb13h2k4lk4nprxfjkxfzcj5v6vja.nar.zst1377 Compression: zstd1378 NarHash: sha256:15cydhi6wv8s7avd3vjkqcgrb13h2k4lk4nprxfjkxfzcj5v6vja1379 NarSize: 2481380 References: /nix/var/nix/builds/nix-49597-1397232080/TestClientPushesUseOnePush475381917/001/store/lbghsjjvjl5fkj01yy35kch43p1fh4kb-shared-dep1381 CA: text:sha256:005h5v25nji6fj8a2b1r70wc8awkmip57zqdpwlpmmf5m0la6imv1382 client_pushes_test.go:97: Retrieved narinfo from S3:1383 StorePath: /nix/var/nix/builds/nix-49597-1397232080/TestClientPushesUseOnePush475381917/001/store/bxmx5fjsj1sxlgc6bp3mk0c36bn5kg94-b1384 URL: nar/15cydhi6wv8s7avd3vjkqcgrb13h2k4lk4nprxfjkxfzcj5v6vja.nar.zst1385 Compression: zstd1386 NarHash: sha256:15cydhi6wv8s7avd3vjkqcgrb13h2k4lk4nprxfjkxfzcj5v6vja1387 NarSize: 2481388 References: /nix/var/nix/builds/nix-49597-1397232080/TestClientPushesUseOnePush475381917/001/store/lbghsjjvjl5fkj01yy35kch43p1fh4kb-shared-dep1389 CA: text:sha256:005h5v25nji6fj8a2b1r70wc8awkmip57zqdpwlpmmf5m0la6imv1390--- PASS: TestClientPushesUseOnePush (2.97s)1391=== CONT TestIsValidCachePath1392=== RUN TestIsValidCachePath/narinfo1393=== PAUSE TestIsValidCachePath/narinfo1394=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1395=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1396=== RUN TestIsValidCachePath/nar_zst1397=== PAUSE TestIsValidCachePath/nar_zst1398=== RUN TestIsValidCachePath/nar_xz1399=== PAUSE TestIsValidCachePath/nar_xz1400=== RUN TestIsValidCachePath/nar_bz21401=== PAUSE TestIsValidCachePath/nar_bz21402=== RUN TestIsValidCachePath/nar_uncompressed1403=== PAUSE TestIsValidCachePath/nar_uncompressed1404=== RUN TestIsValidCachePath/ls1405=== PAUSE TestIsValidCachePath/ls1406=== RUN TestIsValidCachePath/log1407=== PAUSE TestIsValidCachePath/log1408=== RUN TestIsValidCachePath/realisation1409=== PAUSE TestIsValidCachePath/realisation1410=== RUN TestIsValidCachePath/nix-cache-info1411=== PAUSE TestIsValidCachePath/nix-cache-info1412=== RUN TestIsValidCachePath/index.html1413=== PAUSE TestIsValidCachePath/index.html1414=== RUN TestIsValidCachePath/traversal_parent1415=== PAUSE TestIsValidCachePath/traversal_parent1416=== RUN TestIsValidCachePath/traversal_in_middle1417=== PAUSE TestIsValidCachePath/traversal_in_middle1418=== RUN TestIsValidCachePath/invalid_char_e1419=== PAUSE TestIsValidCachePath/invalid_char_e1420=== RUN TestIsValidCachePath/invalid_char_u1421=== PAUSE TestIsValidCachePath/invalid_char_u1422=== RUN TestIsValidCachePath/random_path1423=== PAUSE TestIsValidCachePath/random_path1424=== RUN TestIsValidCachePath/empty1425=== PAUSE TestIsValidCachePath/empty1426=== RUN TestIsValidCachePath/leading_slash1427=== PAUSE TestIsValidCachePath/leading_slash1428=== RUN TestIsValidCachePath/wrong_extension1429=== PAUSE TestIsValidCachePath/wrong_extension1430=== RUN TestIsValidCachePath/short_hash1431=== PAUSE TestIsValidCachePath/short_hash1432=== CONT TestProxyHeadersOnlyTrustedOnSocket14332026/10/05 11:43:23 INFO Received uploads request method=POST path=/api/pending_closures14342026/10/05 11:43:23 INFO Received uploads request method=POST path=/api/pending_closures14352026/10/05 11:43:23 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14362026/10/05 11:43:23 INFO Uploading npx5bqs57z9v9cl4664mqc5cnnml3w1y-a (248B)14372026/10/05 11:43:23 INFO Uploading 6d9cazkq35g3zdzn12m2ngq0ln8azfyj-shared-dep (136B)14382026/10/05 11:43:23 WARN Failed to register uploaded object key=nar/0xgh1fclznw03p29q8137djssix0cvadh4hvyzgwsdnlzlpp9l51.nar.zst error="server returned 404: 404 page not found\n"14392026/10/05 11:43:23 WARN Failed to register uploaded object key=npx5bqs57z9v9cl4664mqc5cnnml3w1y.ls error="server returned 404: 404 page not found\n"14402026/10/05 11:43:23 WARN Failed to register uploaded object key=6d9cazkq35g3zdzn12m2ngq0ln8azfyj.ls error="server returned 404: 404 page not found\n"14412026/10/05 11:43:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14422026/10/05 11:43:23 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14432026/10/05 11:43:23 WARN Failed to register uploaded object key=1qwk8ap0vznvffmyc8q8x966nwifjbh3.ls error="server returned 404: 404 page not found\n"1444--- PASS: TestReadProxy404 (1.95s)1445=== CONT TestService_AuthMiddleware_OIDC14462026/10/05 11:43:23 INFO Signed narinfos id=2 count=214472026/10/05 11:43:23 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14482026/10/05 11:43:23 INFO Signed narinfos id=1 count=214492026/10/05 11:43:23 INFO Uploading 4 narinfos14502026/10/05 11:43:23 WARN Failed to register uploaded object key=1qwk8ap0vznvffmyc8q8x966nwifjbh3.narinfo error="server returned 404: 404 page not found\n"14512026/10/05 11:43:23 WARN Failed to register uploaded object key=npx5bqs57z9v9cl4664mqc5cnnml3w1y.narinfo error="server returned 404: 404 page not found\n"14522026/10/05 11:43:23 WARN Failed to register uploaded object key=6d9cazkq35g3zdzn12m2ngq0ln8azfyj.narinfo error="server returned 404: 404 page not found\n"14532026/10/05 11:43:23 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14542026/10/05 11:43:23 WARN Failed to register uploaded object key=6d9cazkq35g3zdzn12m2ngq0ln8azfyj.narinfo error="server returned 404: 404 page not found\n"14552026/10/05 11:43:23 INFO Completed upload id=114562026/10/05 11:43:23 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14572026/10/05 11:43:23 INFO Completed upload id=214582026/10/05 11:43:23 INFO Upload complete. (165ms)1459=== NAME TestClientFallsBackToClosures1460 client_pushes_test.go:112: Retrieved narinfo from S3:1461 StorePath: /nix/var/nix/builds/nix-49597-1397232080/TestClientFallsBackToClosures1592794775/001/store/6d9cazkq35g3zdzn12m2ngq0ln8azfyj-shared-dep1462 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1463 Compression: zstd1464 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821465 NarSize: 1361466 References: 1467 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1468 client_pushes_test.go:112: Retrieved narinfo from S3:1469 StorePath: /nix/var/nix/builds/nix-49597-1397232080/TestClientFallsBackToClosures1592794775/001/store/npx5bqs57z9v9cl4664mqc5cnnml3w1y-a1470 URL: nar/0xgh1fclznw03p29q8137djssix0cvadh4hvyzgwsdnlzlpp9l51.nar.zst1471 Compression: zstd1472 NarHash: sha256:0xgh1fclznw03p29q8137djssix0cvadh4hvyzgwsdnlzlpp9l511473 NarSize: 2481474 References: /nix/var/nix/builds/nix-49597-1397232080/TestClientFallsBackToClosures1592794775/001/store/6d9cazkq35g3zdzn12m2ngq0ln8azfyj-shared-dep1475 CA: text:sha256:0zcj37qqzdic22xlz7bzjxcjl393vrnz2c3w5yipg5pv0p3936001476 client_pushes_test.go:112: Retrieved narinfo from S3:1477 StorePath: /nix/var/nix/builds/nix-49597-1397232080/TestClientFallsBackToClosures1592794775/001/store/1qwk8ap0vznvffmyc8q8x966nwifjbh3-b1478 URL: nar/0xgh1fclznw03p29q8137djssix0cvadh4hvyzgwsdnlzlpp9l51.nar.zst1479 Compression: zstd1480 NarHash: sha256:0xgh1fclznw03p29q8137djssix0cvadh4hvyzgwsdnlzlpp9l511481 NarSize: 2481482 References: /nix/var/nix/builds/nix-49597-1397232080/TestClientFallsBackToClosures1592794775/001/store/6d9cazkq35g3zdzn12m2ngq0ln8azfyj-shared-dep1483 CA: text:sha256:0zcj37qqzdic22xlz7bzjxcjl393vrnz2c3w5yipg5pv0p3936001484--- PASS: TestClientFallsBackToClosures (3.14s)1485=== CONT TestService_AuthMiddleware_MTLSProxyHeader14862026/10/05 11:43:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55560/oidc1487--- PASS: TestReadProxyNarStreaming (1.90s)1488=== CONT TestService_ReadScope_PublicByDefault14892026/10/05 11:43:23 INFO Aborted multipart uploads count=1 kept=014902026/10/05 11:43:23 INFO Received cleanup request method=DELETE path=/api/pending_closures14912026/10/05 11:43:23 INFO Aborted multipart uploads count=1 kept=01492--- PASS: TestPendingCleanupUsesOneCutoff (7.84s)1493=== CONT TestService_RequireScope_OIDC1494=== NAME TestOrphanedObjectsGCStressTest1495 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains14962026/10/05 11:43:24 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55566/oidc1497 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion1498--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.86s)1499=== CONT TestServerTLSConfig1500=== RUN TestServerTLSConfig/no_client_CA1501=== PAUSE TestServerTLSConfig/no_client_CA1502=== RUN TestServerTLSConfig/missing_CA_file1503=== PAUSE TestServerTLSConfig/missing_CA_file1504=== RUN TestServerTLSConfig/not_a_PEM_file1505=== PAUSE TestServerTLSConfig/not_a_PEM_file1506=== CONT TestService_AuthMiddleware_MTLSBoundSubjects15072026/10/05 11:43:24 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"1508--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.24s)1509=== CONT TestMultipartCleanup15102026/10/05 11:43:25 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161511--- PASS: TestReadProxyNarinfo (2.39s)1512=== CONT TestService_ReadAuthMiddleware15132026/10/05 11:43:25 INFO Starting HTTP server address=127.0.0.1:5558015142026/10/05 11:43:25 INFO Starting HTTP server address=/nix/var/nix/builds/nix-49597-1397232080/TestProxyHeadersOnlyTrustedOnSocket2464924012/001/proxy.sock15152026/10/05 11:43:25 WARN mTLS auth: subject not in bound subjects subject="CN=someone"15162026/10/05 11:43:25 INFO Shutdown signal received, draining in-flight requests timeout=10s1517--- PASS: TestProxyHeadersOnlyTrustedOnSocket (2.37s)1518=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1519--- PASS: TestConnectWaitsForAPeerMigration (6.84s)1520=== CONT TestMetricsInventory1521=== NAME TestOrphanedObjectsGCStressTest1522 orphaned_objects_gc_test.go:509: Stress test completed successfully:1523 orphaned_objects_gc_test.go:510: - Active objects preserved: 201524 orphaned_objects_gc_test.go:511: - Objects deleted: 2101525 orphaned_objects_gc_test.go:512: - Total GC'd: 2101526--- PASS: TestOrphanedObjectsGCStressTest (7.98s)1527=== CONT TestService_NativeMTLS1528=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1529=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1530=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1531=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1532=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1533=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1534=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1535=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1536=== CONT TestNARDeduplicationMetadataUploadBug1537--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (2.43s)1538=== CONT TestPinProtectsFromGC1539--- PASS: TestService_ReadScope_PublicByDefault (2.40s)1540=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15412026/10/05 11:43:26 INFO Received uploads request method=POST path=/1542=== RUN TestService_RequireScope_OIDC/builder_may_write1543=== PAUSE TestService_RequireScope_OIDC/builder_may_write1544=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1545=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1546=== RUN TestService_RequireScope_OIDC/ops_may_admin1547=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1548=== RUN TestService_RequireScope_OIDC/ops_may_not_write1549=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1550=== RUN TestService_RequireScope_OIDC/reader_may_not_write1551=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1552=== RUN TestService_RequireScope_OIDC/static_token_may_admin1553=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1554=== RUN TestService_RequireScope_OIDC/static_token_may_write1555=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1556=== RUN TestService_RequireScope_OIDC/reader_may_read1557=== PAUSE TestService_RequireScope_OIDC/reader_may_read1558=== RUN TestService_RequireScope_OIDC/writer_implies_read1559=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1560=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1561=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1562=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1563=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1564=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1565=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1566=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1567=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1568=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1569=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1570=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15712026/10/05 11:43:26 INFO Received uploads request method=POST path=/1572=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15732026/10/05 11:43:26 INFO Received request for more parts method=POST path=/1574=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15752026/10/05 11:43:26 INFO Received complete multipart upload request method=POST path=/1576=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15772026/10/05 11:43:26 INFO Received complete multipart upload request method=POST path=/1578=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15792026/10/05 11:43:26 INFO Received request for more parts method=POST path=/1580=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15812026/10/05 11:43:26 INFO Received uploads request method=POST path=/1582--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1583 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1584 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1585 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1586 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1587=== CONT TestIsValidUploadKey/narinfo1588=== CONT TestIsValidUploadKey/realisation_plus_in_output1589=== CONT TestIsValidUploadKey/unknown_type1590=== CONT TestIsValidUploadKey/empty_key1591=== CONT TestIsValidUploadKey/absolute1592=== CONT TestIsValidUploadKey/traversal_nar1593=== CONT TestIsValidUploadKey/traversal1594=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1595=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1596=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1597=== CONT TestIsValidUploadKey/index.html1598=== CONT TestIsValidUploadKey/nix-cache-info1599=== CONT TestIsValidUploadKey/build_log_home-manager_file1600=== CONT TestIsValidUploadKey/realisation1601=== CONT TestIsValidUploadKey/build_log_equals1602=== CONT TestIsValidUploadKey/build_log_question_mark1603=== CONT TestIsValidUploadKey/build_log_plus_in_name1604=== CONT TestIsValidUploadKey/nar_plain1605=== CONT TestIsValidUploadKey/build_log1606=== CONT TestIsValidUploadKey/listing1607=== CONT TestIsValidUploadKey/nar_xz1608=== CONT TestIsValidUploadKey/nar_zst1609--- PASS: TestIsValidUploadKey (0.00s)1610 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1611 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1612 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1613 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1614 --- PASS: TestIsValidUploadKey/absolute (0.00s)1615 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1616 --- PASS: TestIsValidUploadKey/traversal (0.00s)1617 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1618 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1619 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1620 --- PASS: TestIsValidUploadKey/index.html (0.00s)1621 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1622 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1623 --- PASS: TestIsValidUploadKey/realisation (0.00s)1624 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1625 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1626 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1627 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1628 --- PASS: TestIsValidUploadKey/build_log (0.00s)1629 --- PASS: TestIsValidUploadKey/listing (0.00s)1630 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1631 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1632=== CONT TestPendingClosureWriteTimeout/empty1633=== CONT TestProxyWriteTimeout/narinfo1634=== CONT TestPendingClosureWriteTimeout/400_objects1635=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline16362026/10/05 11:43:27 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16372026/10/05 11:43:27 WARN mTLS auth: bound subjects configured but subject DN unavailable16382026/10/05 11:43:27 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1639--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (2.66s)1640=== CONT TestProxyWriteTimeout/10_GiB_nar1641=== CONT TestProxyWriteTimeout/unknown_size1642=== CONT TestProxyWriteTimeout/1_GiB_nar1643--- PASS: TestProxyWriteTimeout (0.00s)1644 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1645 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1646 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1647 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1648=== CONT TestPendingClosureWriteTimeout/670k_objects1649=== CONT TestPush_RejectsBadRequests/no_roots16502026/10/05 11:43:27 INFO Received push request method=POST path=/api/pushes1651=== CONT TestPush_RejectsBadRequests/bad_root16522026/10/05 11:43:27 INFO Received push request method=POST path=/api/pushes1653=== CONT TestPush_RejectsBadRequests/root_not_in_objects16542026/10/05 11:43:27 INFO Received push request method=POST path=/api/pushes1655=== CONT TestPush_RejectsBadRequests/no_objects16562026/10/05 11:43:27 INFO Received push request method=POST path=/api/pushes1657=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1658--- PASS: TestPush_RejectsBadRequests (1.93s)1659 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1660 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1661 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1662 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)16632026/10/05 11:43:27 INFO Received uploads request method=POST path=/api/pending_closures16642026/10/05 11:43:27 INFO Received cleanup request method=DELETE path=/api/pending_closures16652026/10/05 11:43:27 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket77/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""16662026/10/05 11:43:27 INFO Aborted multipart uploads count=0 kept=116672026/10/05 11:43:27 INFO Received cleanup request method=DELETE path=/api/pending_closures16682026/10/05 11:43:27 INFO Aborted multipart uploads count=1 kept=01669--- PASS: TestMultipartCleanup (2.78s)1670=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1671--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)1672 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1673 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.10s)1674 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.53s)1675=== CONT TestGCEndsOnShutdown/before_the_run16762026/10/05 11:43:27 INFO Received uploads request method=POST path=/api/pending_closures1677--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (2.75s)1678=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1679--- PASS: TestService_ReadAuthMiddleware (2.99s)1680=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1681--- PASS: TestMetricsInventory (3.17s)1682=== CONT TestCacheConfigHandler/full_config,_no_issuer1683=== CONT TestCacheConfigHandler/no_signing_keys1684=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1685=== CONT TestCacheConfigHandler/no_cache_url_configured1686--- PASS: TestCacheConfigHandler (0.00s)1687 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1688 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1689 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1690 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1691=== CONT TestClientErrorHandling/InvalidStorePath16922026/10/05 11:43:28 WARN mTLS auth: subject not in bound subjects subject="CN=reader"16932026/10/05 11:43:28 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1694--- PASS: TestService_NativeMTLS (3.11s)1695=== CONT TestClientErrorHandling/ServerNotAvailable16962026/10/05 11:43:29 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/present16972026/10/05 11:43:29 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=195.556314ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1698=== NAME TestNARDeduplicationMetadataUploadBug1699 metadata_upload_test.go:48: First store path: /nix/var/nix/builds/nix-49597-1397232080/TestNARDeduplicationMetadataUploadBug2196469085/001/store/clyfl05bbm7aj4nrjp2ylk8a7gn9sj7i-file1.txt17002026/10/05 11:43:29 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=380.018602ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17012026/10/05 11:43:29 INFO Received push request method=POST path=/api/pushes17022026/10/05 11:43:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17032026/10/05 11:43:29 INFO Uploading clyfl05bbm7aj4nrjp2ylk8a7gn9sj7i-file1.txt (160B)17042026/10/05 11:43:29 WARN Failed to register uploaded object key=clyfl05bbm7aj4nrjp2ylk8a7gn9sj7i.ls error="server returned 404: 404 page not found\n"17052026/10/05 11:43:29 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17062026/10/05 11:43:29 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"17072026/10/05 11:43:29 INFO Signed narinfos id=1 count=117082026/10/05 11:43:29 INFO Uploading 1 narinfos17092026/10/05 11:43:29 INFO Received complete push request method=POST path=/api/pushes/1/complete17102026/10/05 11:43:29 WARN Failed to register uploaded object key=clyfl05bbm7aj4nrjp2ylk8a7gn9sj7i.narinfo error="server returned 404: 404 page not found\n"17112026/10/05 11:43:29 INFO Upload complete. (229ms)1712 metadata_upload_test.go:54: Retrieved narinfo from S3:1713 StorePath: /nix/var/nix/builds/nix-49597-1397232080/TestNARDeduplicationMetadataUploadBug2196469085/001/store/clyfl05bbm7aj4nrjp2ylk8a7gn9sj7i-file1.txt1714 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1715 Compression: zstd1716 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1717 NarSize: 1601718 References: 1719 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1720 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1721 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1722 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}17232026/10/05 11:43:29 INFO Received uploads request method=POST path=/api/pending_closures1724 metadata_upload_test.go:64: Second store path (same content): /nix/var/nix/builds/nix-49597-1397232080/TestNARDeduplicationMetadataUploadBug2196469085/001/store/zgs5fswxhjwymyjgjvcqjhqab52xp7i9-file2.txt17252026/10/05 11:43:29 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=734.221205ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1726=== NAME TestPinProtectsFromGC1727 client_integration_test.go:731: Pinned store path: /nix/var/nix/builds/nix-49597-1397232080/TestPinProtectsFromGC3418058813/001/store/f664ldzywdi3jcda21zd1z13fb70afk2-pinned-file.txt1728 client_integration_test.go:732: Unpinned store path: /nix/var/nix/builds/nix-49597-1397232080/TestPinProtectsFromGC3418058813/001/store/crhn7cdm5sfpp2ip5mhl0zy31jgl8cz1-unpinned-file.txt17292026/10/05 11:43:29 INFO Received push request method=POST path=/api/pushes17302026/10/05 11:43:29 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17312026/10/05 11:43:29 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17322026/10/05 11:43:29 INFO Signed narinfos id=2 count=117332026/10/05 11:43:29 INFO Uploading 1 narinfos17342026/10/05 11:43:29 WARN Failed to register uploaded object key=zgs5fswxhjwymyjgjvcqjhqab52xp7i9.ls error="server returned 404: 404 page not found\n"17352026/10/05 11:43:29 INFO Received complete push request method=POST path=/api/pushes/2/complete17362026/10/05 11:43:29 WARN Failed to register uploaded object key=zgs5fswxhjwymyjgjvcqjhqab52xp7i9.narinfo error="server returned 404: 404 page not found\n"17372026/10/05 11:43:29 INFO Upload complete. (141ms)1738=== NAME TestNARDeduplicationMetadataUploadBug1739 metadata_upload_test.go:76: Retrieved narinfo from S3:1740 StorePath: /nix/var/nix/builds/nix-49597-1397232080/TestNARDeduplicationMetadataUploadBug2196469085/001/store/zgs5fswxhjwymyjgjvcqjhqab52xp7i9-file2.txt1741 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1742 Compression: zstd1743 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1744 NarSize: 1601745 References: 1746 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1747 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1748 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1749 {"version":1,"root":{"type":"regular","size":44}}17502026/10/05 11:43:29 INFO Received push request method=POST path=/api/pushes17512026/10/05 11:43:29 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17522026/10/05 11:43:29 INFO Uploading f664ldzywdi3jcda21zd1z13fb70afk2-pinned-file.txt (128B)1753--- PASS: TestNARDeduplicationMetadataUploadBug (4.25s)1754=== CONT TestClientErrorHandling/InvalidAuthToken17552026/10/05 11:43:30 INFO Received uploads request method=POST path=/api/pending_closures17562026/10/05 11:43:30 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17572026/10/05 11:43:30 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17582026/10/05 11:43:30 WARN Failed to register uploaded object key=f664ldzywdi3jcda21zd1z13fb70afk2.ls error="server returned 404: 404 page not found\n"17592026/10/05 11:43:30 INFO Signed narinfos id=1 count=117602026/10/05 11:43:30 INFO Uploading 1 narinfos17612026/10/05 11:43:30 INFO Aborted multipart uploads count=0 kept=017622026/10/05 11:43:30 INFO Received complete push request method=POST path=/api/pushes/1/complete17632026/10/05 11:43:30 WARN Failed to register uploaded object key=f664ldzywdi3jcda21zd1z13fb70afk2.narinfo error="server returned 404: 404 page not found\n"17642026/10/05 11:43:30 WARN Force mode enabled - objects will be deleted immediately without grace period17652026/10/05 11:43:30 INFO Upload complete. (197ms)17662026/10/05 11:43:30 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=017672026/10/05 11:43:30 INFO Vacuumed table table=pending_closures17682026/10/05 11:43:30 INFO Vacuumed table table=pending_objects17692026/10/05 11:43:30 INFO Vacuumed table table=multipart_uploads17702026/10/05 11:43:30 INFO Vacuumed table table=closures17712026/10/05 11:43:30 INFO Vacuumed table table=objects1772=== CONT TestParseSingleRange/none1773=== CONT TestParseSingleRange/open-ended1774=== CONT TestParseSingleRange/start_far_past_EOF1775=== CONT TestParseSingleRange/start_past_EOF1776=== CONT TestParseSingleRange/single_byte1777=== CONT TestParseSingleRange/suffix_exceeds_size1778=== CONT TestParseSingleRange/suffix1779=== CONT TestParseSingleRange/end_clamped_to_size1780=== CONT TestParseSingleRange/malformed_both_empty1781=== CONT TestParseSingleRange/closed1782=== CONT TestParseSingleRange/malformed_end_before_start1783=== CONT TestParseSingleRange/multi-range_ignored1784=== CONT TestParseSingleRange/malformed_no_dash1785=== CONT TestParseSingleRange/unknown_unit1786--- PASS: TestParseSingleRange (0.00s)1787 --- PASS: TestParseSingleRange/none (0.00s)1788 --- PASS: TestParseSingleRange/open-ended (0.00s)1789 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1790 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1791 --- PASS: TestParseSingleRange/single_byte (0.00s)1792 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1793 --- PASS: TestParseSingleRange/suffix (0.00s)1794 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1795 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1796 --- PASS: TestParseSingleRange/closed (0.00s)1797 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1798 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1799 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1800 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1801=== CONT TestResolveDBConnectionString/flag_wins1802=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1803=== CONT TestResolveDBConnectionString/nothing_configured1804=== CONT TestResolveDBConnectionString/missing_file_is_an_error1805=== CONT TestResolveDBConnectionString/file_when_flag_empty1806=== CONT TestIsValidCachePath/narinfo1807=== CONT TestIsValidCachePath/index.html1808=== CONT TestIsValidCachePath/short_hash1809=== CONT TestIsValidCachePath/wrong_extension1810=== CONT TestIsValidCachePath/leading_slash1811=== CONT TestIsValidCachePath/empty1812=== CONT TestIsValidCachePath/random_path1813=== CONT TestIsValidCachePath/invalid_char_u1814=== CONT TestIsValidCachePath/invalid_char_e1815=== CONT TestIsValidCachePath/traversal_in_middle1816=== CONT TestIsValidCachePath/traversal_parent1817=== CONT TestIsValidCachePath/nar_uncompressed1818=== CONT TestIsValidCachePath/nix-cache-info1819=== CONT TestIsValidCachePath/realisation1820=== CONT TestIsValidCachePath/log1821=== CONT TestIsValidCachePath/ls1822=== CONT TestIsValidCachePath/nar_xz1823=== CONT TestIsValidCachePath/nar_bz21824=== CONT TestIsValidCachePath/nar_zst1825=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1826--- PASS: TestIsValidCachePath (0.00s)1827 --- PASS: TestIsValidCachePath/narinfo (0.00s)1828 --- PASS: TestIsValidCachePath/index.html (0.00s)1829 --- PASS: TestIsValidCachePath/short_hash (0.00s)1830 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1831 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1832 --- PASS: TestIsValidCachePath/empty (0.00s)1833 --- PASS: TestIsValidCachePath/random_path (0.00s)1834 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1835 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1836 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1837 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1838 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1839 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1840 --- PASS: TestIsValidCachePath/realisation (0.00s)1841 --- PASS: TestIsValidCachePath/log (0.00s)1842 --- PASS: TestIsValidCachePath/ls (0.00s)1843 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1844 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1845 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1846 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1847=== CONT TestServerTLSConfig/no_client_CA1848=== CONT TestServerTLSConfig/not_a_PEM_file1849--- PASS: TestResolveDBConnectionString (0.03s)1850 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1851 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1852 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1853 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1854 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1855=== CONT TestServerTLSConfig/missing_CA_file1856--- PASS: TestServerTLSConfig (0.00s)1857 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1858 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1859 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1860=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1861=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18622026/10/05 11:43:30 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]1863=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1864=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18652026/10/05 11:43:30 WARN Authentication failed token_preview=eyJhbGciOi...aGtIHo4epQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1866=== CONT TestService_RequireScope_OIDC/builder_may_write1867=== CONT TestService_RequireScope_OIDC/reader_may_not_write1868=== CONT TestService_RequireScope_OIDC/static_token_may_write1869=== CONT TestService_RequireScope_OIDC/static_token_may_admin1870=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1871=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1872=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18732026/10/05 11:43:30 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1874=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1875=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1876=== CONT TestService_RequireScope_OIDC/ops_may_admin1877=== CONT TestService_RequireScope_OIDC/ops_may_not_write1878=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1879=== CONT TestService_RequireScope_OIDC/writer_implies_read1880=== CONT TestService_RequireScope_OIDC/reader_may_read1881--- PASS: TestService_AuthMiddleware_OIDC (2.23s)1882 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)1883 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1884 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1885 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1886--- PASS: TestService_RequireScope_OIDC (2.84s)1887 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1888 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1889 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1890 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1891 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1892 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1893 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1894 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1895 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1896 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1897 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1898 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1899 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1900 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)19012026/10/05 11:43:30 INFO Received push request method=POST path=/api/pushes19022026/10/05 11:43:30 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19032026/10/05 11:43:30 INFO Uploading crhn7cdm5sfpp2ip5mhl0zy31jgl8cz1-unpinned-file.txt (128B)19042026/10/05 11:43:30 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"19052026/10/05 11:43:30 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign19062026/10/05 11:43:30 WARN Failed to register uploaded object key=crhn7cdm5sfpp2ip5mhl0zy31jgl8cz1.ls error="server returned 404: 404 page not found\n"19072026/10/05 11:43:30 INFO Signed narinfos id=2 count=119082026/10/05 11:43:30 INFO Uploading 1 narinfos19092026/10/05 11:43:30 INFO Received complete push request method=POST path=/api/pushes/2/complete19102026/10/05 11:43:30 WARN Failed to register uploaded object key=crhn7cdm5sfpp2ip5mhl0zy31jgl8cz1.narinfo error="server returned 404: 404 page not found\n"19112026/10/05 11:43:30 INFO Upload complete. (180ms)19122026/10/05 11:43:30 INFO Received uploads request method=POST path=/api/pending_closures1913--- PASS: TestPendingClosureWriteTimeout (0.00s)1914 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1915 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1916 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1917 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (3.52s)19182026/10/05 11:43:30 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.753574347s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19192026/10/05 11:43:30 INFO Aborted multipart uploads count=0 kept=019202026/10/05 11:43:30 WARN Force mode enabled - objects will be deleted immediately without grace period19212026/10/05 11:43:30 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=019222026/10/05 11:43:30 INFO Vacuumed table table=pending_closures19232026/10/05 11:43:30 INFO Starting cleanup of old closures method=DELETE path=/api/closures19242026/10/05 11:43:30 INFO Garbage collection started19252026/10/05 11:43:30 INFO Vacuumed table table=pending_objects19262026/10/05 11:43:30 INFO Vacuumed table table=multipart_uploads19272026/10/05 11:43:30 INFO Vacuumed table table=closures19282026/10/05 11:43:30 INFO Aborted multipart uploads count=0 kept=019292026/10/05 11:43:30 WARN Force mode enabled - objects will be deleted immediately without grace period19302026/10/05 11:43:30 INFO Vacuumed table table=objects1931--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1932 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (3.13s)1933 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.74s)19342026/10/05 11:43:30 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=019352026/10/05 11:43:30 INFO Vacuumed table table=pending_closures19362026/10/05 11:43:30 INFO Vacuumed table table=pending_objects19372026/10/05 11:43:30 INFO Vacuumed table table=multipart_uploads19382026/10/05 11:43:30 INFO Vacuumed table table=closures19392026/10/05 11:43:30 INFO Vacuumed table table=objects19402026/10/05 11:43:30 INFO Aborted multipart uploads count=0 kept=019412026/10/05 11:43:30 WARN Force mode enabled - objects will be deleted immediately without grace period19422026/10/05 11:43:30 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:55244/bucket88/?delete=\": context canceled"19432026/10/05 11:43:31 INFO Aborted multipart uploads count=0 kept=019442026/10/05 11:43:31 WARN Force mode enabled - objects will be deleted immediately without grace period19452026-10-05 11:43:31.231 UTC [51626] ERROR: canceling statement due to user request19462026-10-05 11:43:31.231 UTC [51626] STATEMENT: -- name: MarkStaleObjects :execrows1947 WITH RECURSIVE ct AS (1948 SELECT timezone('UTC', now()) AS now1949 ),1950 closure_reach AS (1951 -- Start with all closure keys1952 SELECT o.key, o.refs1953 FROM objects o1954 INNER JOIN closures c ON o.key = c.key1955 UNION1956 -- Recursively add all referenced objects1957 SELECT o.key, o.refs1958 FROM objects o1959 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1960 ),1961 reachable_objects AS (1962 SELECT DISTINCT key FROM closure_reach1963 ),1964 stale_objects AS (1965 SELECT o.key1966 FROM objects AS o, ct1967 WHERE1968 NOT EXISTS (1969 SELECT 11970 FROM reachable_objects ro1971 WHERE ro.key = o.key1972 )1973 AND NOT EXISTS (1974 SELECT 11975 FROM pending_objects AS po1976 WHERE po.key = o.key1977 )1978 AND o.deleted_at IS NULL -- Only mark fresh objects1979 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1980 FOR UPDATE1981 )1982 UPDATE objects1983 SET1984 deleted_at = ct.now,1985 first_deleted_at = COALESCE(first_deleted_at, ct.now)1986 FROM stale_objects, ct1987 WHERE objects.key = stale_objects.key1988 1989--- PASS: TestGCEndsOnShutdown (0.00s)1990 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (2.76s)1991 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (3.22s)1992 --- PASS: TestGCEndsOnShutdown/before_the_run (3.57s)19932026/10/05 11:43:31 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19942026/10/05 11:43:31 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19952026/10/05 11:43:32 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-config19962026/10/05 11:43:32 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.236954ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19972026/10/05 11:43:32 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019982026/10/05 11:43:32 INFO Received create pin request method=POST path=/api/pins/myapp19992026/10/05 11:43:32 INFO Created/updated pin name=myapp store_path=/nix/var/nix/builds/nix-49597-1397232080/TestPinProtectsFromGC3418058813/001/store/f664ldzywdi3jcda21zd1z13fb70afk2-pinned-file.txt narinfo_key=f664ldzywdi3jcda21zd1z13fb70afk2.narinfo20002026/10/05 11:43:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures20012026/10/05 11:43:32 INFO Garbage collection started20022026/10/05 11:43:32 INFO Aborted multipart uploads count=0 kept=020032026/10/05 11:43:32 WARN Force mode enabled - objects will be deleted immediately without grace period20042026/10/05 11:43:32 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=020052026/10/05 11:43:32 INFO Vacuumed table table=pending_closures20062026/10/05 11:43:32 INFO Vacuumed table table=pending_objects20072026/10/05 11:43:32 INFO Vacuumed table table=multipart_uploads20082026/10/05 11:43:32 INFO Vacuumed table table=closures20092026/10/05 11:43:32 INFO Vacuumed table table=objects20102026/10/05 11:43:32 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=378.327821ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20112026/10/05 11:43:32 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=765.789041ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20122026/10/05 11:43:33 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.727639508s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2013=== NAME TestPinProtectsFromGC2014 client_integration_test.go:840: Pin successfully protected closure from garbage collection2015--- PASS: TestPinProtectsFromGC (8.48s)20162026/10/05 11:43:35 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"20172026/10/05 11:43:35 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-config20182026/10/05 11:43:35 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=200.18716ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20192026/10/05 11:43:35 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=379.253749ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20202026/10/05 11:43:36 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=874.705282ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20212026/10/05 11:43:37 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.721491002s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20222026/10/05 11:43:38 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_closures20232026/10/05 11:43:38 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=206.024102ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20242026/10/05 11:43:39 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=395.803335ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20252026/10/05 11:43:39 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=770.081229ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20262026/10/05 11:43:40 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.720367744s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2027--- PASS: TestClientErrorHandling (0.00s)2028 --- PASS: TestClientErrorHandling/InvalidStorePath (2.17s)2029 --- PASS: TestClientErrorHandling/InvalidAuthToken (1.93s)2030 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.19s)2031PASS20322026-10-05 11:43:42.177 UTC [50259] LOG: received smart shutdown request20332026-10-05 11:43:42.179 UTC [50259] LOG: background worker "logical replication launcher" (PID 50275) exited with exit code 120342026-10-05 11:43:42.198 UTC [50269] LOG: shutting down20352026-10-05 11:43:42.198 UTC [50269] LOG: checkpoint starting: shutdown immediate20362026-10-05 11:43:46.663 UTC [50269] LOG: checkpoint complete: wrote 12793 buffers (78.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 27 recycled; write=0.754 s, sync=3.620 s, total=4.466 s; sync files=31000, longest=0.202 s, average=0.001 s; distance=435703 kB, estimate=435703 kB; lsn=0/1C10ABD8, redo lsn=0/1C10ABD820372026-10-05 11:43:46.734 UTC [50259] LOG: database system is shut down2038Running OIDC tests...2039=== RUN TestAudienceForIssuer2040=== PAUSE TestAudienceForIssuer2041=== RUN TestGlobMatch2042=== PAUSE TestGlobMatch2043=== RUN TestValidateToken_ValidToken2044=== PAUSE TestValidateToken_ValidToken2045=== RUN TestValidateToken_WrongAudience2046=== PAUSE TestValidateToken_WrongAudience2047=== RUN TestValidateToken_Expired2048=== PAUSE TestValidateToken_Expired2049=== RUN TestValidateToken_BoundClaimsMismatch2050=== PAUSE TestValidateToken_BoundClaimsMismatch2051=== RUN TestValidateToken_BoundSubjectMismatch2052=== PAUSE TestValidateToken_BoundSubjectMismatch2053=== RUN TestValidateToken_MultipleProviders2054=== PAUSE TestValidateToken_MultipleProviders2055=== RUN TestValidateToken_NoMatchingProvider2056=== PAUSE TestValidateToken_NoMatchingProvider2057=== RUN TestValidateToken_KubernetesServiceAccount2058=== PAUSE TestValidateToken_KubernetesServiceAccount2059=== RUN TestNewValidator_KubernetesRequiresCA2060=== PAUSE TestNewValidator_KubernetesRequiresCA2061=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2062=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2063=== RUN TestPins_ReservedForMatchingRule2064=== PAUSE TestPins_ReservedForMatchingRule2065=== RUN TestPins_TopLevelShorthand2066=== PAUSE TestPins_TopLevelShorthand2067=== RUN TestPins_ConfigValidation2068=== PAUSE TestPins_ConfigValidation2069=== RUN TestScopes_LegacyProviderDefaultsToWrite2070=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2071=== RUN TestScopes_Rules2072=== PAUSE TestScopes_Rules2073=== RUN TestScopes_ConfigValidation2074=== PAUSE TestScopes_ConfigValidation2075=== CONT TestAudienceForIssuer2076--- PASS: TestAudienceForIssuer (0.00s)2077=== CONT TestScopes_ConfigValidation2078=== CONT TestValidateToken_BoundClaimsMismatch2079=== CONT TestScopes_Rules2080=== CONT TestScopes_LegacyProviderDefaultsToWrite2081=== CONT TestValidateToken_MultipleProviders2082=== CONT TestPins_ReservedForMatchingRule2083=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2084=== CONT TestNewValidator_KubernetesRequiresCA2085=== CONT TestValidateToken_NoMatchingProvider2086=== CONT TestValidateToken_KubernetesServiceAccount2087--- PASS: TestScopes_ConfigValidation (0.00s)2088=== CONT TestPins_ConfigValidation2089--- PASS: TestPins_ConfigValidation (0.00s)2090=== CONT TestValidateToken_BoundSubjectMismatch20912026/10/05 11:43:50 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12320922026/10/05 11:43:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55719/oidc2093--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.04s)2094=== CONT TestPins_TopLevelShorthand2095--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.04s)2096=== CONT TestValidateToken_WrongAudience20972026/10/05 11:43:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55723/oidc20982026/10/05 11:43:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55725/oidc2099--- PASS: TestScopes_Rules (0.06s)2100=== CONT TestValidateToken_Expired2101--- PASS: TestPins_ReservedForMatchingRule (0.07s)2102=== CONT TestValidateToken_ValidToken21032026/10/05 11:43:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55727/oidc2104--- PASS: TestValidateToken_Expired (0.02s)2105=== CONT TestGlobMatch2106=== RUN TestGlobMatch/foo_foo2107=== PAUSE TestGlobMatch/foo_foo2108=== RUN TestGlobMatch/foo_bar2109=== PAUSE TestGlobMatch/foo_bar2110=== RUN TestGlobMatch/*_2111=== PAUSE TestGlobMatch/*_2112=== RUN TestGlobMatch/*_anything2113=== PAUSE TestGlobMatch/*_anything2114=== RUN TestGlobMatch/foo*_foo2115=== PAUSE TestGlobMatch/foo*_foo2116=== RUN TestGlobMatch/foo*_foobar2117=== PAUSE TestGlobMatch/foo*_foobar2118=== RUN TestGlobMatch/foo*_bar2119=== PAUSE TestGlobMatch/foo*_bar2120=== RUN TestGlobMatch/*bar_bar2121=== PAUSE TestGlobMatch/*bar_bar2122=== RUN TestGlobMatch/*bar_foobar2123=== PAUSE TestGlobMatch/*bar_foobar2124=== RUN TestGlobMatch/*bar_foo2125=== PAUSE TestGlobMatch/*bar_foo2126=== RUN TestGlobMatch/foo*bar_foobar2127=== PAUSE TestGlobMatch/foo*bar_foobar2128=== RUN TestGlobMatch/foo*bar_foo123bar2129=== PAUSE TestGlobMatch/foo*bar_foo123bar2130=== RUN TestGlobMatch/foo*bar_foobarbaz2131=== PAUSE TestGlobMatch/foo*bar_foobarbaz2132=== RUN TestGlobMatch/*/*_foo/bar2133=== PAUSE TestGlobMatch/*/*_foo/bar2134=== RUN TestGlobMatch/*/*_foo2135=== PAUSE TestGlobMatch/*/*_foo2136=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2137=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2138=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02139=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02140=== RUN TestGlobMatch/refs/*/main_refs/heads/main2141=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2142=== RUN TestGlobMatch/fo?_foo2143=== PAUSE TestGlobMatch/fo?_foo2144=== RUN TestGlobMatch/fo?_fo2145=== PAUSE TestGlobMatch/fo?_fo2146=== RUN TestGlobMatch/fo?_fooo2147=== PAUSE TestGlobMatch/fo?_fooo2148=== RUN TestGlobMatch/?oo_foo2149=== PAUSE TestGlobMatch/?oo_foo2150=== RUN TestGlobMatch/?oo_boo2151=== PAUSE TestGlobMatch/?oo_boo2152=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2153=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2154=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2155=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2156=== CONT TestGlobMatch/foo_foo2157=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2158=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2159=== CONT TestGlobMatch/?oo_boo2160=== CONT TestGlobMatch/?oo_foo2161=== CONT TestGlobMatch/fo?_fooo2162=== CONT TestGlobMatch/fo?_fo2163=== CONT TestGlobMatch/fo?_foo2164=== CONT TestGlobMatch/refs/*/main_refs/heads/main2165=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02166=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2167=== CONT TestGlobMatch/*/*_foo2168=== CONT TestGlobMatch/*/*_foo/bar2169=== CONT TestGlobMatch/foo*bar_foobarbaz2170=== CONT TestGlobMatch/foo*bar_foo123bar2171=== CONT TestGlobMatch/foo*bar_foobar2172=== CONT TestGlobMatch/*bar_foo2173=== CONT TestGlobMatch/*bar_foobar2174=== CONT TestGlobMatch/*bar_bar2175=== CONT TestGlobMatch/foo*_bar2176=== CONT TestGlobMatch/foo*_foobar2177=== CONT TestGlobMatch/foo*_foo2178=== CONT TestGlobMatch/*_anything2179=== CONT TestGlobMatch/*_2180=== CONT TestGlobMatch/foo_bar2181--- PASS: TestGlobMatch (0.00s)2182 --- PASS: TestGlobMatch/foo_foo (0.00s)2183 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2184 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2185 --- PASS: TestGlobMatch/?oo_boo (0.00s)2186 --- PASS: TestGlobMatch/?oo_foo (0.00s)2187 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2188 --- PASS: TestGlobMatch/fo?_fo (0.00s)2189 --- PASS: TestGlobMatch/fo?_foo (0.00s)2190 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2191 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2192 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2193 --- PASS: TestGlobMatch/*/*_foo (0.00s)2194 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2195 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2196 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2197 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2198 --- PASS: TestGlobMatch/*bar_foo (0.00s)2199 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2200 --- PASS: TestGlobMatch/*bar_bar (0.00s)2201 --- PASS: TestGlobMatch/foo*_bar (0.00s)2202 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2203 --- PASS: TestGlobMatch/foo*_foo (0.00s)2204 --- PASS: TestGlobMatch/*_anything (0.00s)2205 --- PASS: TestGlobMatch/*_ (0.00s)2206 --- PASS: TestGlobMatch/foo_bar (0.00s)22072026/10/05 11:43:50 http: TLS handshake error from 127.0.0.1:55730: read tcp 127.0.0.1:55729->127.0.0.1:55730: use of closed network connection2208--- PASS: TestNewValidator_KubernetesRequiresCA (0.10s)22092026/10/05 11:43:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55731/oidc2210--- PASS: TestValidateToken_BoundClaimsMismatch (0.25s)22112026/10/05 11:43:50 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5573322122026/10/05 11:43:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55735/oidc2213--- PASS: TestValidateToken_WrongAudience (0.21s)2214--- PASS: TestValidateToken_KubernetesServiceAccount (0.25s)22152026/10/05 11:43:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55737/oidc2216--- PASS: TestValidateToken_BoundSubjectMismatch (0.27s)22172026/10/05 11:43:50 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:55722/oidc22182026/10/05 11:43:50 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:55739/oidc2219--- PASS: TestValidateToken_MultipleProviders (0.33s)22202026/10/05 11:43:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55743/oidc2221--- PASS: TestPins_TopLevelShorthand (0.36s)22222026/10/05 11:43:50 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:55745/oidc2223--- PASS: TestValidateToken_ValidToken (0.39s)22242026/10/05 11:43:50 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:55742/oidc2225--- PASS: TestValidateToken_NoMatchingProvider (0.58s)2226PASS2227Running hook tests...2228=== RUN TestSendPathsEmpty2229=== PAUSE TestSendPathsEmpty2230=== RUN TestQueueEnqueueAndFetch2231=== PAUSE TestQueueEnqueueAndFetch2232=== RUN TestQueueDeduplication2233=== PAUSE TestQueueDeduplication2234=== RUN TestQueueRemove2235=== PAUSE TestQueueRemove2236=== RUN TestQueueFetchBatchLimit2237=== PAUSE TestQueueFetchBatchLimit2238=== RUN TestQueueRetryMovesToBack2239=== PAUSE TestQueueRetryMovesToBack2240=== RUN TestQueueFetchRemoveLifecycle2241=== PAUSE TestQueueFetchRemoveLifecycle2242=== RUN TestQueueConcurrentWriters2243=== PAUSE TestQueueConcurrentWriters2244=== RUN TestQueueRemoveLargeClosure2245=== PAUSE TestQueueRemoveLargeClosure2246=== RUN TestServerClientIntegration2247=== PAUSE TestServerClientIntegration2248=== RUN TestServerQueueError2249=== PAUSE TestServerQueueError2250=== RUN TestGetListenerSocketActivation2251 server_test.go:210: === RUN TestGetListenerSocketActivation2252 --- PASS: TestGetListenerSocketActivation (0.00s)2253 PASS2254 2255--- PASS: TestGetListenerSocketActivation (0.02s)2256=== RUN TestDrainIsolatesPoisonPath2257=== PAUSE TestDrainIsolatesPoisonPath2258=== RUN TestRunNotBlockedByPoisonHead2259=== PAUSE TestRunNotBlockedByPoisonHead2260=== RUN TestDrainGivesUpWhenServerDown2261=== PAUSE TestDrainGivesUpWhenServerDown2262=== RUN TestFailedPathPrunedByLaterClosure2263=== PAUSE TestFailedPathPrunedByLaterClosure2264=== RUN TestWorkerUploadsAndRemoves2265=== PAUSE TestWorkerUploadsAndRemoves2266=== RUN TestWorkerSkipsGCdPaths2267=== PAUSE TestWorkerSkipsGCdPaths2268=== RUN TestWorkerPrunesClosureDeps2269=== PAUSE TestWorkerPrunesClosureDeps2270=== RUN TestDrainTimeout2271=== PAUSE TestDrainTimeout2272=== CONT TestSendPathsEmpty2273--- PASS: TestSendPathsEmpty (0.00s)2274=== CONT TestServerQueueError2275=== CONT TestServerClientIntegration2276=== CONT TestQueueRemoveLargeClosure2277=== CONT TestQueueConcurrentWriters2278=== CONT TestQueueFetchRemoveLifecycle2279=== CONT TestQueueRetryMovesToBack2280=== CONT TestQueueFetchBatchLimit2281=== CONT TestQueueRemove2282=== CONT TestQueueDeduplication2283=== CONT TestQueueEnqueueAndFetch22842026/10/05 11:43:50 ERROR Failed to queue paths error="permission denied" count=12285--- PASS: TestServerClientIntegration (0.01s)2286=== CONT TestDrainGivesUpWhenServerDown2287--- PASS: TestServerQueueError (0.01s)2288=== CONT TestFailedPathPrunedByLaterClosure2289--- PASS: TestQueueEnqueueAndFetch (0.01s)2290=== CONT TestWorkerPrunesClosureDeps22912026/10/05 11:43:50 INFO Uploading batch count=122922026/10/05 11:43:50 ERROR Upload failed error="upload failed" count=12293--- PASS: TestQueueFetchBatchLimit (0.01s)2294=== CONT TestDrainTimeout2295--- PASS: TestQueueRetryMovesToBack (0.01s)22962026/10/05 11:43:50 INFO Uploading batch count=12297=== CONT TestWorkerSkipsGCdPaths2298--- PASS: TestQueueRemove (0.01s)2299=== CONT TestRunNotBlockedByPoisonHead23002026/10/05 11:43:50 INFO Uploading batch count=223012026/10/05 11:43:50 ERROR Upload failed error="upload failed" count=223022026/10/05 11:43:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49597-1397232080/TestDrainGivesUpWhenServerDown2586449550/002/a23032026/10/05 11:43:50 INFO Uploading batch count=123042026/10/05 11:43:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49597-1397232080/TestDrainGivesUpWhenServerDown2586449550/002/b2305--- PASS: TestQueueFetchRemoveLifecycle (0.01s)2306=== CONT TestDrainIsolatesPoisonPath23072026/10/05 11:43:50 INFO Uploading batch count=223082026/10/05 11:43:50 ERROR Upload failed error="upload failed" count=223092026/10/05 11:43:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49597-1397232080/TestDrainGivesUpWhenServerDown2586449550/002/c23102026/10/05 11:43:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49597-1397232080/TestDrainGivesUpWhenServerDown2586449550/002/d23112026/10/05 11:43:50 INFO Upload queue status pending=223122026/10/05 11:43:50 INFO Uploading batch count=123132026/10/05 11:43:50 INFO Uploading batch count=223142026/10/05 11:43:50 ERROR Upload failed error="upload failed" count=223152026/10/05 11:43:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49597-1397232080/TestDrainGivesUpWhenServerDown2586449550/002/e2316--- PASS: TestQueueDeduplication (0.01s)2317=== CONT TestWorkerUploadsAndRemoves23182026/10/05 11:43:50 INFO Uploading batch count=223192026/10/05 11:43:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49597-1397232080/TestDrainGivesUpWhenServerDown2586449550/002/f23202026/10/05 11:43:50 ERROR Drain finished with paths left in queue remaining=102321--- PASS: TestFailedPathPrunedByLaterClosure (0.01s)23222026/10/05 11:43:50 INFO Upload queue status pending=323232026/10/05 11:43:50 INFO Uploading batch count=123242026/10/05 11:43:50 ERROR Upload failed error="upload failed" count=123252026/10/05 11:43:50 INFO Upload queue status pending=223262026/10/05 11:43:50 WARN Store path no longer exists (garbage collected?), removing from queue path=/nix/var/nix/builds/nix-49597-1397232080/TestWorkerSkipsGCdPaths427115534/002/nonexistent23272026/10/05 11:43:50 INFO Uploading batch count=123282026/10/05 11:43:50 INFO Uploading batch count=423292026/10/05 11:43:50 ERROR Upload failed error="upload failed" count=423302026/10/05 11:43:50 ERROR Upload failed, will retry later error="upload failed" path=/nix/var/nix/builds/nix-49597-1397232080/TestDrainIsolatesPoisonPath3137478253/002/bbb2331--- PASS: TestDrainGivesUpWhenServerDown (0.01s)23322026/10/05 11:43:50 INFO Uploading batch count=123332026/10/05 11:43:50 ERROR Upload failed error="upload failed" count=123342026/10/05 11:43:50 INFO Uploading batch count=123352026/10/05 11:43:50 ERROR Upload failed error="upload failed" count=123362026/10/05 11:43:50 INFO Uploading batch count=123372026/10/05 11:43:50 INFO Upload queue status pending=223382026/10/05 11:43:50 INFO Uploading batch count=223392026/10/05 11:43:50 ERROR Upload failed error="upload failed" count=123402026/10/05 11:43:50 ERROR Drain finished with paths left in queue remaining=12341--- PASS: TestDrainIsolatesPoisonPath (0.00s)2342--- PASS: TestWorkerPrunesClosureDeps (0.02s)2343--- PASS: TestWorkerSkipsGCdPaths (0.02s)2344--- PASS: TestWorkerUploadsAndRemoves (0.02s)2345--- PASS: TestQueueRemoveLargeClosure (0.06s)2346--- PASS: TestQueueConcurrentWriters (0.15s)23472026/10/05 11:43:51 ERROR Upload failed error="context deadline exceeded" count=223482026/10/05 11:43:51 ERROR Drain finished with paths left in queue remaining=42349--- PASS: TestDrainTimeout (0.21s)23502026/10/05 11:43:51 INFO Uploading batch count=123512026/10/05 11:43:51 INFO Uploading batch count=123522026/10/05 11:43:51 INFO Uploading batch count=123532026/10/05 11:43:51 ERROR Upload failed error="upload failed" count=123542026/10/05 11:43:51 INFO Uploading batch count=123552026/10/05 11:43:51 ERROR Upload failed error="upload failed" count=123562026/10/05 11:43:51 INFO Uploading batch count=123572026/10/05 11:43:51 ERROR Upload failed error="upload failed" count=123582026/10/05 11:43:51 INFO Uploading batch count=123592026/10/05 11:43:51 ERROR Upload failed error="upload failed" count=123602026/10/05 11:43:51 ERROR Drain finished with paths left in queue remaining=12361--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2362PASS