niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #359
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestRegisterUploadedObjectReusesConnections6=== PAUSE TestRegisterUploadedObjectReusesConnections7=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica8=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica9=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun10=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun11=== RUN TestCaseHackSuffix12=== PAUSE TestCaseHackSuffix13=== RUN TestFilterOversizedClosures14=== PAUSE TestFilterOversizedClosures15=== RUN TestUploadMultipart_PartsInParallel16=== PAUSE TestUploadMultipart_PartsInParallel17=== RUN TestPartSizeForNAR18=== PAUSE TestPartSizeForNAR19=== RUN TestUploadMultipart_SupersededByPeer20=== PAUSE TestUploadMultipart_SupersededByPeer21=== RUN TestDumpPathCaseHackMatchesNix22--- PASS: TestDumpPathCaseHackMatchesNix (0.04s)23=== RUN TestDumpPathCaseHackCollision24--- PASS: TestDumpPathCaseHackCollision (0.00s)25=== RUN TestDumpPathMatchesNix26=== PAUSE TestDumpPathMatchesNix27=== RUN TestDumpPathSingleFile28=== PAUSE TestDumpPathSingleFile29=== RUN TestDumpPathWriterError30=== PAUSE TestDumpPathWriterError31=== RUN TestEncodeNixBase3232=== PAUSE TestEncodeNixBase3233=== RUN TestEncodeNixBase32WithRealHash34=== PAUSE TestEncodeNixBase32WithRealHash35=== RUN TestConvertHashToNix3236=== PAUSE TestConvertHashToNix3237=== RUN TestGetStorePathHash38=== PAUSE TestGetStorePathHash39=== RUN TestPathInfoHashCompatibility40=== PAUSE TestPathInfoHashCompatibility41=== RUN TestParsePathInfoJSON42=== PAUSE TestParsePathInfoJSON43=== RUN TestParsePathInfoJSONMultiplePaths44=== PAUSE TestParsePathInfoJSONMultiplePaths45=== RUN TestPathInfoCACompatibility46=== PAUSE TestPathInfoCACompatibility47=== RUN TestRateLimiterFeedback48=== PAUSE TestRateLimiterFeedback49=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess50=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess51=== RUN TestResolveStorePath52=== PAUSE TestResolveStorePath53=== RUN TestDoWithRetry_BodyReplayedViaGetBody54=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody55=== RUN TestShellSplit56=== PAUSE TestShellSplit57=== RUN TestShellSplitErrors58=== PAUSE TestShellSplitErrors59=== RUN TestStreamPushReportsEveryPath60=== PAUSE TestStreamPushReportsEveryPath61=== RUN TestStreamPushBatchesUnderLoad62=== PAUSE TestStreamPushBatchesUnderLoad63=== RUN TestStreamPushIsolatesFailures64=== PAUSE TestStreamPushIsolatesFailures65=== RUN TestStreamPushGivesUpOnDeadServer66=== PAUSE TestStreamPushGivesUpOnDeadServer67=== RUN TestStreamPushRequestLine68=== PAUSE TestStreamPushRequestLine69=== RUN TestStreamPushReportsSignatures70=== PAUSE TestStreamPushReportsSignatures71=== RUN TestClientSignaturesByStorePath72=== PAUSE TestClientSignaturesByStorePath73=== RUN TestSetClientTLS74=== PAUSE TestSetClientTLS75=== RUN TestSetClientTLSDoesNotMutateDefaultTransport76=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport77=== RUN TestSetClientTLSErrors78=== PAUSE TestSetClientTLSErrors79=== RUN TestStaticToken80=== PAUSE TestStaticToken81=== RUN TestFileTokenReadsAndCaches82=== PAUSE TestFileTokenReadsAndCaches83=== RUN TestFileTokenMissing84=== PAUSE TestFileTokenMissing85=== RUN TestFileTokenEmpty86=== PAUSE TestFileTokenEmpty87=== RUN TestScriptTokenNoExpiryRerunsEveryCall88=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall89=== RUN TestScriptTokenCachesUntilRefresh90=== PAUSE TestScriptTokenCachesUntilRefresh91=== RUN TestScriptTokenEmptyToken92=== PAUSE TestScriptTokenEmptyToken93=== RUN TestScriptTokenBadJSON94=== PAUSE TestScriptTokenBadJSON95=== RUN TestScriptTokenScriptFails96=== PAUSE TestScriptTokenScriptFails97=== RUN TestScriptTokenEmptyCommand98=== PAUSE TestScriptTokenEmptyCommand99=== CONT TestDoServerRequestAttachesToken100=== CONT TestDoWithRetry_BodyReplayedViaGetBody101=== CONT TestSetClientTLSErrors102=== CONT TestEncodeNixBase32103=== RUN TestEncodeNixBase32/test_string_hash104=== PAUSE TestEncodeNixBase32/test_string_hash105=== RUN TestEncodeNixBase32/empty_input106=== PAUSE TestEncodeNixBase32/empty_input107=== CONT TestResolveStorePath108=== CONT TestScriptTokenEmptyCommand109--- PASS: TestScriptTokenEmptyCommand (0.00s)110=== CONT TestFileTokenReadsAndCaches111=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess112=== CONT TestRateLimiterFeedback113=== CONT TestPathInfoCACompatibility114--- PASS: TestFileTokenReadsAndCaches (0.00s)115=== CONT TestParsePathInfoJSONMultiplePaths116=== CONT TestParsePathInfoJSON117=== CONT TestPathInfoHashCompatibility118=== CONT TestGetStorePathHash119=== RUN TestGetStorePathHash/valid_store_path120=== CONT TestConvertHashToNix32121=== CONT TestEncodeNixBase32WithRealHash122=== CONT TestFileTokenMissing123=== CONT TestScriptTokenNoExpiryRerunsEveryCall1242026/10/05 11:42:45 WARN Rate limiter enabled after throttle name=server-test rate=5125=== CONT TestFileTokenEmpty126=== CONT TestSetClientTLSDoesNotMutateDefaultTransport127=== CONT TestUploadMultipart_PartsInParallel128=== CONT TestDumpPathWriterError129=== CONT TestDumpPathSingleFile130=== CONT TestDumpPathMatchesNix131=== CONT TestUploadMultipart_SupersededByPeer132=== CONT TestPartSizeForNAR133=== CONT TestScriptTokenScriptFails134=== CONT TestScriptTokenBadJSON135=== PAUSE TestGetStorePathHash/valid_store_path136=== RUN TestParsePathInfoJSON/Nix_format137=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)138--- PASS: TestEncodeNixBase32WithRealHash (0.00s)139=== RUN TestRateLimiterFeedback/429_enables_limiter140=== RUN TestConvertHashToNix32/SRI_format_to_Nix32141=== RUN TestPathInfoCACompatibility/null_ca_field142=== PAUSE TestParsePathInfoJSON/Nix_format143=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32144=== CONT TestStreamPushGivesUpOnDeadServer145--- PASS: TestResolveStorePath (0.00s)146=== PAUSE TestRateLimiterFeedback/429_enables_limiter147=== RUN TestUploadMultipart_SupersededByPeer/exists148=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)149=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths150=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths151=== RUN TestPartSizeForNAR/zero_stays_at_minimum152=== PAUSE TestPathInfoCACompatibility/null_ca_field153--- PASS: TestFileTokenMissing (0.00s)154=== CONT TestSetClientTLS155=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum156=== RUN TestParsePathInfoJSON/Lix_format1572026/10/05 11:42:45 ERROR Upload failed error="connection refused" count=20158=== PAUSE TestParsePathInfoJSON/Lix_format1592026/10/05 11:42:45 ERROR Server seems unavailable, giving up on batch untried=17160=== RUN TestPathInfoCACompatibility/old_string_format_-_text1612026/10/05 11:42:45 WARN Rate limiter enabled after throttle name=server-test rate=5162=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text1632026/10/05 11:42:45 WARN Request returned retryable status, retrying attempt=1 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37543164=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths165=== RUN TestGetStorePathHash/basename_without_hyphen_should_error166=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error167=== RUN TestPartSizeForNAR/small_stays_at_minimum168=== PAUSE TestPartSizeForNAR/small_stays_at_minimum169=== CONT TestStreamPushReportsSignatures170=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum171=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum172=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts173=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts174=== RUN TestPartSizeForNAR/1_TiB175=== PAUSE TestPartSizeForNAR/1_TiB176=== RUN TestPartSizeForNAR/5_TiB_S3_max_object177=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object178=== RUN TestPartSizeForNAR/capped_at_5_GiB179=== PAUSE TestPartSizeForNAR/capped_at_5_GiB180=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths181=== CONT TestStreamPushRequestLine182=== RUN TestParsePathInfoJSON/empty_input183=== PAUSE TestParsePathInfoJSON/empty_input184=== RUN TestParsePathInfoJSON/whitespace_only185=== PAUSE TestParsePathInfoJSON/whitespace_only1862026/10/05 11:42:45 WARN Rate limiter backed off name=server-test rate=5187=== RUN TestParsePathInfoJSON/invalid_JSON188=== PAUSE TestParsePathInfoJSON/invalid_JSON1892026/10/05 11:42:45 WARN Request returned retryable status, retrying attempt=2 max_attempts=6 backoff=0s status=503 url=http://127.0.0.1:37543190=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive1912026/10/05 11:42:45 ERROR Upload failed error=boom count=1192=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive193=== CONT TestStreamPushBatchesUnderLoad1942026/10/05 11:42:45 ERROR Upload failed error=boom count=1195=== RUN TestPathInfoCACompatibility/new_structured_format_-_text196--- PASS: TestFileTokenEmpty (0.00s)197=== RUN TestConvertHashToNix32/already_Nix32_format198=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text199=== RUN TestRateLimiterFeedback/503_enables_limiter200=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon201=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon202=== PAUSE TestUploadMultipart_SupersededByPeer/exists203=== CONT TestClientSignaturesByStorePath204=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error205=== CONT TestStaticToken206=== RUN TestUploadMultipart_SupersededByPeer/missing207=== PAUSE TestUploadMultipart_SupersededByPeer/missing208=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error209=== CONT TestCaseHackSuffix210=== CONT TestStreamPushIsolatesFailures211=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error212--- PASS: TestStreamPushGivesUpOnDeadServer (0.08s)213--- PASS: TestDoServerRequestAttachesToken (0.09s)214=== PAUSE TestConvertHashToNix32/already_Nix32_format2152026/10/05 11:42:45 ERROR Upload failed error="bad path" count=3216=== RUN TestSetClientTLSErrors/missing_cert_file217=== CONT TestShellSplit218=== RUN TestConvertHashToNix32/invalid_format219=== PAUSE TestRateLimiterFeedback/503_enables_limiter220=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun221=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter222=== CONT TestFilterOversizedClosures223=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter224=== CONT TestRegisterUploadedObjectReusesConnections225=== RUN TestFilterOversizedClosures/no_limit_keeps_everything226=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything227=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter228=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter229=== CONT TestStreamPushReportsEveryPath230=== CONT TestShellSplitErrors231=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error232=== CONT TestEncodeNixBase32/test_string_hash233=== CONT TestEncodeNixBase32/empty_input234=== CONT TestPartSizeForNAR/zero_stays_at_minimum235=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum236=== CONT TestPartSizeForNAR/capped_at_5_GiB237=== CONT TestPartSizeForNAR/5_TiB_S3_max_object238=== CONT TestPartSizeForNAR/1_TiB239=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts240=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths241=== CONT TestParsePathInfoJSON/Nix_format242=== CONT TestParsePathInfoJSON/whitespace_only243=== CONT TestParsePathInfoJSON/invalid_JSON244=== CONT TestParsePathInfoJSON/empty_input245=== CONT TestParsePathInfoJSON/Lix_format246=== RUN TestSetClientTLS/rejects_connection_without_client_cert247=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert248=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA249=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA250=== RUN TestSetClientTLS/preserves_debug_logging_transport251=== PAUSE TestSetClientTLS/preserves_debug_logging_transport252=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths253=== CONT TestRateLimiterFeedback/429_enables_limiter254=== CONT TestGetStorePathHash/valid_store_path255=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error256=== CONT TestUploadMultipart_SupersededByPeer/missing257=== CONT TestScriptTokenCachesUntilRefresh2582026/10/05 11:42:45 INFO Garbage collection started2592026/10/05 11:42:45 WARN Rate limiter enabled after throttle name=server-test rate=52602026/10/05 11:42:45 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=429 url=http://127.0.0.1:417712612026/10/05 11:42:45 WARN Rate limiter backed off name=server-test rate=5262=== CONT TestGetStorePathHash/basename_without_hyphen_should_error263=== CONT TestRateLimiterFeedback/503_enables_limiter264=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter265=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter266=== CONT TestUploadMultipart_SupersededByPeer/exists267=== CONT TestSetClientTLS/rejects_connection_without_client_cert268=== CONT TestPartSizeForNAR/small_stays_at_minimum269=== CONT TestSetClientTLS/preserves_debug_logging_transport270=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method271=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method272=== CONT TestScriptTokenEmptyToken273=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA2742026/10/05 11:42:45 WARN Rate limiter enabled after throttle name=server-test rate=52752026/10/05 11:42:45 WARN Request returned retryable status, retrying attempt=1 max_attempts=2 backoff=0s status=503 url=http://127.0.0.1:35021276=== CONT TestPathInfoCACompatibility/null_ca_field277=== PAUSE TestSetClientTLSErrors/missing_cert_file278=== CONT TestPathInfoCACompatibility/new_structured_format_-_text279=== PAUSE TestConvertHashToNix32/invalid_format280=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica281=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI282=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped283--- PASS: TestStreamPushReportsSignatures (0.00s)284=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error285--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.09s)286=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method287--- PASS: TestClientSignaturesByStorePath (0.00s)288--- PASS: TestStaticToken (0.00s)289--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.09s)290--- PASS: TestStreamPushIsolatesFailures (0.00s)291--- PASS: TestShellSplit (0.00s)292--- PASS: TestScriptTokenScriptFails (0.09s)293=== RUN TestSetClientTLSErrors/missing_key_file294--- PASS: TestShellSplitErrors (0.00s)295--- PASS: TestStreamPushReportsEveryPath (0.00s)2962026/10/05 11:42:45 WARN Rate limiter backed off name=server-test rate=5297=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive298--- PASS: TestScriptTokenBadJSON (0.00s)299=== PAUSE TestSetClientTLSErrors/missing_key_file3002026/10/05 11:42:45 INFO Garbage collection started301=== CONT TestPathInfoCACompatibility/old_string_format_-_text302=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped303=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI304=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512305=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512306=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)307=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI308=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon309=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512310=== CONT TestConvertHashToNix32/invalid_format311=== CONT TestConvertHashToNix32/already_Nix32_format312--- PASS: TestParsePathInfoJSON (0.09s)313 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)314 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)315 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)316 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)317 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)318=== RUN TestSetClientTLSErrors/missing_ca_file319=== PAUSE TestSetClientTLSErrors/missing_ca_file320=== RUN TestSetClientTLSErrors/invalid_ca_file321=== PAUSE TestSetClientTLSErrors/invalid_ca_file322=== RUN TestFilterOversizedClosures/all_closures_skipped323=== PAUSE TestFilterOversizedClosures/all_closures_skipped324=== CONT TestFilterOversizedClosures/no_limit_keeps_everything325=== CONT TestFilterOversizedClosures/all_closures_skipped3262026/10/05 11:42:45 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=50327=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3282026/10/05 11:42:45 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=2000329--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.09s)330--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)3312026/10/05 11:42:45 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=0332--- PASS: TestEncodeNixBase32 (0.00s)333 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)334 --- PASS: TestEncodeNixBase32/empty_input (0.00s)335--- PASS: TestScriptTokenEmptyToken (0.01s)336--- PASS: TestParsePathInfoJSONMultiplePaths (0.09s)337 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)338 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)339=== CONT TestSetClientTLSErrors/missing_cert_file340=== CONT TestSetClientTLSErrors/invalid_ca_file341=== CONT TestSetClientTLSErrors/missing_ca_file342=== CONT TestSetClientTLSErrors/missing_key_file343=== CONT TestConvertHashToNix32/SRI_format_to_Nix32344--- PASS: TestUploadMultipart_SupersededByPeer (0.08s)345 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)346 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)347--- PASS: TestPartSizeForNAR (0.08s)348 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)349 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)350 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)351 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)352 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)353 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)354 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)355--- PASS: TestRateLimiterFeedback (0.09s)356 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)357 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)358 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)359 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)360--- PASS: TestGetStorePathHash (0.09s)361 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)362 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)363 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)364 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)365--- PASS: TestPathInfoCACompatibility (0.09s)366 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)367 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)368 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.01s)369 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)370 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)371--- PASS: TestPathInfoHashCompatibility (0.11s)372 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)373 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)374 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)375 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)376--- PASS: TestFilterOversizedClosures (0.02s)377 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)378 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)379 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)380--- PASS: TestConvertHashToNix32 (0.10s)381 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)382 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)383 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)3842026/10/05 11:42:45 WARN Garbage collection finished on another replica. Its statistics are not available here385--- PASS: TestSetClientTLSErrors (0.11s)386 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)387 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)388 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)389 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)390--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)391--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)392--- PASS: TestStreamPushRequestLine (0.03s)3932026/10/05 11:42:45 http: TLS handshake error from 127.0.0.1:40360: remote error: tls: bad certificate394--- PASS: TestSetClientTLS (0.00s)395 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)396 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)397 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)398--- PASS: TestCaseHackSuffix (0.03s)399--- PASS: TestDumpPathSingleFile (0.12s)400--- PASS: TestRegisterUploadedObjectReusesConnections (0.04s)401--- PASS: TestDumpPathWriterError (0.14s)402--- PASS: TestStreamPushBatchesUnderLoad (0.10s)403--- PASS: TestDumpPathMatchesNix (0.19s)404--- PASS: TestUploadMultipart_PartsInParallel (0.71s)405--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)406PASS407Running server tests...408The files belonging to this database system will be owned by user "nixbld".409This user must also own the server process.410411The database cluster will be initialized with locale "C".412The default database encoding has accordingly been set to "SQL_ASCII".413The default text search configuration will be set to "english".414415Data page checksums are enabled.416417creating directory /build/postgres2668208383/data ... ok418creating subdirectories ... ok419selecting dynamic shared memory implementation ... posix420selecting default "max_connections" ... 100421selecting default "shared_buffers" ... 128MB422selecting default time zone ... UTC423creating configuration files ... ok424running bootstrap script ... ok425performing post-bootstrap initialization ... ok426syncing data to disk ... ok427428initdb: warning: enabling "trust" authentication for local connections429initdb: 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.430431Success. You can now start the database server using:432433 pg_ctl -D /build/postgres2668208383/data -l logfile start434435/build/postgres2668208383:5432 - no response4362026-10-05 11:42:47.069 UTC [129] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit4372026-10-05 11:42:47.070 UTC [129] LOG: listening on Unix socket "/build/postgres2668208383/.s.PGSQL.5432"4382026-10-05 11:42:47.074 UTC [136] LOG: database system was shut down at 2026-10-05 11:42:46 UTC4392026-10-05 11:42:47.078 UTC [129] LOG: database system is ready to accept connections440/build/postgres2668208383:5432 - accepting connections441{"timestamp":"2026-10-05T11:42:47.375395414Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"3d92ce41-096c-48fe-a615-c53540ebaa93","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(397)"}442=== RUN TestService_AuthMiddleware443=== PAUSE TestService_AuthMiddleware444=== RUN TestService_AuthMiddleware_MTLSProxyHeader445=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader446=== RUN TestService_AuthMiddleware_MTLSBoundSubjects447=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects448=== RUN TestService_ReadAuthMiddleware449=== PAUSE TestService_ReadAuthMiddleware450=== RUN TestService_AuthMiddleware_OIDC451=== PAUSE TestService_AuthMiddleware_OIDC452=== RUN TestService_RequireScope_OIDC453=== PAUSE TestService_RequireScope_OIDC454=== RUN TestService_ReadScope_PublicByDefault455=== PAUSE TestService_ReadScope_PublicByDefault456=== RUN TestCacheConfigHandler457=== PAUSE TestCacheConfigHandler458=== RUN TestCacheStatsHandler459=== PAUSE TestCacheStatsHandler460=== RUN TestClientCADerivations461=== PAUSE TestClientCADerivations462=== RUN TestClientErrorHandling463=== PAUSE TestClientErrorHandling464=== RUN TestClientIntegration465=== PAUSE TestClientIntegration466=== RUN TestClientMultipleUploads467=== PAUSE TestClientMultipleUploads468=== RUN TestClientWithDependencies469=== PAUSE TestClientWithDependencies470=== RUN TestClientSharedPathCommittedMidPush471=== PAUSE TestClientSharedPathCommittedMidPush472=== RUN TestPinProtectsFromGC473=== PAUSE TestPinProtectsFromGC474=== RUN TestClientPushesUseOnePush475=== PAUSE TestClientPushesUseOnePush476=== RUN TestClientFallsBackToClosures477=== PAUSE TestClientFallsBackToClosures478=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock479=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock480=== RUN TestResolveDBConnectionString481=== PAUSE TestResolveDBConnectionString482=== RUN TestConnectWaitsForAPeerMigration483=== PAUSE TestConnectWaitsForAPeerMigration484=== RUN TestLeadElectsOneAndHandsOver485=== PAUSE TestLeadElectsOneAndHandsOver486=== RUN TestLeadIncumbentWinsAfterRestart4872026/10/05 11:42:47 INFO lead: acquired remote=192.0.2.1:12344882026/10/05 11:42:48 INFO lead: released remote=192.0.2.1:12344892026/10/05 11:42:48 INFO lead: acquired remote=192.0.2.1:12344902026/10/05 11:42:49 INFO lead: released remote=192.0.2.1:1234491--- PASS: TestLeadIncumbentWinsAfterRestart (1.90s)492=== RUN TestLeadIncumbentAnnouncesAtOnce493=== PAUSE TestLeadIncumbentAnnouncesAtOnce494=== RUN TestLeadEndsOnShutdown495=== PAUSE TestLeadEndsOnShutdown496=== RUN TestLeadEndsWhenItsConnectionHangs4972026/10/05 11:42:49 INFO lead: acquired remote=192.0.2.1:12344982026-10-05 11:42:50.911 UTC [578] FATAL: terminating connection due to administrator command4992026/10/05 11:42:51 INFO lead: acquired remote=192.0.2.1:12345002026/10/05 11:42:52 WARN lead: lock connection lost error="timeout: context deadline exceeded"5012026/10/05 11:42:52 INFO lead: released remote=192.0.2.1:12345022026/10/05 11:42:52 INFO lead: released remote=192.0.2.1:1234503--- PASS: TestLeadEndsWhenItsConnectionHangs (2.93s)504=== RUN TestGCAdvisoryLockBlocksConcurrentRun505=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun506=== RUN TestGCBugBareHashReferences507=== PAUSE TestGCBugBareHashReferences508=== RUN TestGCMetrics509=== PAUSE TestGCMetrics510=== RUN TestPushDedupSurvivesConcurrentGC511=== PAUSE TestPushDedupSurvivesConcurrentGC512=== RUN TestDeduplicatedObjectsRecordedAsPending513=== PAUSE TestDeduplicatedObjectsRecordedAsPending514=== RUN TestGCSweepSkipsPendingObjects515=== PAUSE TestGCSweepSkipsPendingObjects516=== RUN TestTombstonedObjectOfferedWithoutWaiting517=== PAUSE TestTombstonedObjectOfferedWithoutWaiting518=== RUN TestGCSweepDeliversEachKeyOnce519=== PAUSE TestGCSweepDeliversEachKeyOnce520=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection521=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection522=== RUN TestForceGCDuringPushOffersSweptObject523=== PAUSE TestForceGCDuringPushOffersSweptObject524=== RUN TestFailedS3DeleteKeepsTombstone525=== PAUSE TestFailedS3DeleteKeepsTombstone526=== RUN TestSweepSkipsRowsLockedByPush527=== PAUSE TestSweepSkipsRowsLockedByPush528=== RUN TestRegisterCompletedObjectNeedsPendingRow529=== PAUSE TestRegisterCompletedObjectNeedsPendingRow530=== RUN TestGetExistingObjectsLocksRows531=== PAUSE TestGetExistingObjectsLocksRows532=== RUN TestSweepRechecksPendingAfterLocking533=== PAUSE TestSweepRechecksPendingAfterLocking534=== RUN TestPushWaitsForSweepHoldingRow535=== PAUSE TestPushWaitsForSweepHoldingRow536=== RUN TestCommitRacingPendingCleanupKeepsObjects537=== PAUSE TestCommitRacingPendingCleanupKeepsObjects538=== RUN TestGCEndsOnShutdown539=== PAUSE TestGCEndsOnShutdown540=== RUN TestGCTaskStore_StartNew541=== PAUSE TestGCTaskStore_StartNew542=== RUN TestGCTaskStore_DeduplicateSameParams543=== PAUSE TestGCTaskStore_DeduplicateSameParams544=== RUN TestGCTaskStore_ConflictDifferentParams545=== PAUSE TestGCTaskStore_ConflictDifferentParams546=== RUN TestGCTaskStore_GetEmpty547=== PAUSE TestGCTaskStore_GetEmpty548=== RUN TestGCTaskStore_GetReturnsLatest549=== PAUSE TestGCTaskStore_GetReturnsLatest550=== RUN TestGCTaskStore_CompletedAllowsNewTask551=== PAUSE TestGCTaskStore_CompletedAllowsNewTask552=== RUN TestGCTaskStore_PhaseUpdates553=== PAUSE TestGCTaskStore_PhaseUpdates554=== RUN TestGCTaskStore_Fail555=== PAUSE TestGCTaskStore_Fail556=== RUN TestGracefulShutdownDrainsInflight557=== PAUSE TestGracefulShutdownDrainsInflight558=== RUN TestService_healthCheckHandler559=== PAUSE TestService_healthCheckHandler560=== RUN TestService_readinessHandler561=== PAUSE TestService_readinessHandler562=== RUN TestGenerateLandingPage563=== PAUSE TestGenerateLandingPage564=== RUN TestCacheConfigHandlerMaxNarSize565=== PAUSE TestCacheConfigHandlerMaxNarSize566=== RUN TestCreatePendingClosureRejectsOversizedNAR567=== PAUSE TestCreatePendingClosureRejectsOversizedNAR568=== RUN TestNARDeduplicationMetadataUploadBug569=== PAUSE TestNARDeduplicationMetadataUploadBug570=== RUN TestMetricsInventory571=== PAUSE TestMetricsInventory572=== RUN TestService_NativeMTLS573=== PAUSE TestService_NativeMTLS574=== RUN TestServerTLSConfig575=== PAUSE TestServerTLSConfig576=== RUN TestMultipartCleanup577=== PAUSE TestMultipartCleanup578=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded579=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded580=== RUN TestPendingCleanupUsesOneCutoff581=== PAUSE TestPendingCleanupUsesOneCutoff582=== RUN TestObjectStatsTrigger583=== PAUSE TestObjectStatsTrigger584=== RUN TestOrphanedObjectsGC585=== PAUSE TestOrphanedObjectsGC586=== RUN TestOrphanedObjectsGCStressTest587=== PAUSE TestOrphanedObjectsGCStressTest588=== RUN TestCreatePin_ReservedPins589=== PAUSE TestCreatePin_ReservedPins590=== RUN TestPresentReportsOnlyClosureRoots591=== PAUSE TestPresentReportsOnlyClosureRoots592=== RUN TestPresentNotReportedWhileGCDeletesClosure593=== PAUSE TestPresentNotReportedWhileGCDeletesClosure594=== RUN TestParseSingleRange595=== PAUSE TestParseSingleRange596=== RUN TestProxyHeadersOnlyTrustedOnSocket597=== PAUSE TestProxyHeadersOnlyTrustedOnSocket598=== RUN TestIsValidCachePath599=== PAUSE TestIsValidCachePath600=== RUN TestReadProxyNarinfo601=== PAUSE TestReadProxyNarinfo602=== RUN TestReadProxyNarinfoAlreadyDecompressed603=== PAUSE TestReadProxyNarinfoAlreadyDecompressed604=== RUN TestReadProxyNarStreaming605=== PAUSE TestReadProxyNarStreaming606=== RUN TestReadProxy404607=== PAUSE TestReadProxy404608=== RUN TestReadProxyInvalidPath609=== PAUSE TestReadProxyInvalidPath610=== RUN TestReadProxyHead611=== PAUSE TestReadProxyHead612=== RUN TestReadProxyOutlastsServerWriteTimeout613=== PAUSE TestReadProxyOutlastsServerWriteTimeout614=== RUN TestReadProxyConditionalGet615=== PAUSE TestReadProxyConditionalGet616=== RUN TestReadProxyRootRedirectsToIndexHTML617=== PAUSE TestReadProxyRootRedirectsToIndexHTML618=== RUN TestReadProxyDisabled619=== PAUSE TestReadProxyDisabled620=== RUN TestReadRedirectNar621=== PAUSE TestReadRedirectNar622=== RUN TestReadRedirectKeepsNarinfoProxied623=== PAUSE TestReadRedirectKeepsNarinfoProxied624=== RUN TestReadProxyRangeRequest625=== PAUSE TestReadProxyRangeRequest626=== RUN TestReadRedirectUsesPublicS3URL627=== PAUSE TestReadRedirectUsesPublicS3URL628=== RUN TestPush_OverlappingRootsStoreOneRowPerKey629=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey630=== RUN TestPush_CompleteCommitsEveryRoot631=== PAUSE TestPush_CompleteCommitsEveryRoot632=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit633=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit634=== RUN TestPush_RejectsBadRequests635=== PAUSE TestPush_RejectsBadRequests636=== RUN TestPush_SignsNarinfosOfItsPendingObjects637=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects638=== RUN TestRedundantMultipartUpload639=== PAUSE TestRedundantMultipartUpload640=== RUN TestCompleteMultipartUpload_ErrorButObjectExists641=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists642=== RUN TestCompletedNarNotReofferedAcrossClosures643=== PAUSE TestCompletedNarNotReofferedAcrossClosures644=== RUN TestPresignedUploadRegisteredBeforeCommit645=== PAUSE TestPresignedUploadRegisteredBeforeCommit646=== RUN TestService_Rustfstest647=== PAUSE TestService_Rustfstest648=== RUN TestParseSize649=== PAUSE TestParseSize650=== RUN TestSkippedUploadsHandler651=== PAUSE TestSkippedUploadsHandler652=== RUN TestSystemdListenerNotActivated653--- PASS: TestSystemdListenerNotActivated (0.00s)654=== RUN TestWatchdogBeatsWhenHealthy655--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)656=== RUN TestWatchdogSkipsWhenUnhealthy6572026/10/05 11:42:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6582026/10/05 11:42:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6592026/10/05 11:42:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6602026/10/05 11:42:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6612026/10/05 11:42:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6622026/10/05 11:42:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6632026/10/05 11:42:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6642026/10/05 11:42:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6652026/10/05 11:42:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"6662026/10/05 11:42:52 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"667--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)668=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle669=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle670=== RUN TestProxyWriteTimeout671=== PAUSE TestProxyWriteTimeout672=== RUN TestPendingClosureWriteTimeout673=== PAUSE TestPendingClosureWriteTimeout674=== RUN TestIsValidUploadKey675=== PAUSE TestIsValidUploadKey676=== RUN TestUploadHandlersRejectInvalidKeys677=== PAUSE TestUploadHandlersRejectInvalidKeys678=== RUN TestUploadHandlersRejectOversizedBody679=== PAUSE TestUploadHandlersRejectOversizedBody680=== RUN TestService_cleanupPendingClosuresHandler681=== PAUSE TestService_cleanupPendingClosuresHandler682=== RUN TestService_createPendingClosureHandler683=== PAUSE TestService_createPendingClosureHandler684=== RUN TestService_verifyS3Integrity685=== PAUSE TestService_verifyS3Integrity686=== RUN TestCompleteMultipartUnregistered687=== PAUSE TestCompleteMultipartUnregistered688=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT689=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT690=== CONT TestService_AuthMiddleware691=== CONT TestPush_SignsNarinfosOfItsPendingObjects692=== CONT TestPush_CompleteCommitsEveryRoot693=== CONT TestCompleteMultipartUnregistered694=== CONT TestService_verifyS3Integrity695=== CONT TestService_createPendingClosureHandler696=== CONT TestService_cleanupPendingClosuresHandler697=== CONT TestUploadHandlersRejectOversizedBody698=== CONT TestUploadHandlersRejectInvalidKeys699=== CONT TestIsValidUploadKey700=== RUN TestIsValidUploadKey/narinfo701=== PAUSE TestIsValidUploadKey/narinfo702=== CONT TestPendingClosureWriteTimeout703=== CONT TestProxyWriteTimeout704=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle705=== CONT TestSkippedUploadsHandler706=== RUN TestPendingClosureWriteTimeout/empty707=== PAUSE TestPendingClosureWriteTimeout/empty708=== RUN TestPendingClosureWriteTimeout/400_objects709=== CONT TestService_Rustfstest710=== CONT TestPresignedUploadRegisteredBeforeCommit711=== CONT TestCompletedNarNotReofferedAcrossClosures7122026/10/05 11:42:52 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000713=== CONT TestCompleteMultipartUpload_ErrorButObjectExists714=== CONT TestRedundantMultipartUpload715=== CONT TestGCTaskStore_ConflictDifferentParams716=== CONT TestPush_OverlappingRootsStoreOneRowPerKey717=== CONT TestReadRedirectUsesPublicS3URL718=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT719=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info720=== RUN TestIsValidUploadKey/nar_zst721=== PAUSE TestIsValidUploadKey/nar_zst722=== RUN TestIsValidUploadKey/nar_xz723=== PAUSE TestIsValidUploadKey/nar_xz724=== RUN TestIsValidUploadKey/nar_plain725=== PAUSE TestIsValidUploadKey/nar_plain726=== RUN TestIsValidUploadKey/listing727=== PAUSE TestIsValidUploadKey/listing728=== RUN TestIsValidUploadKey/build_log729=== PAUSE TestIsValidUploadKey/build_log730=== RUN TestIsValidUploadKey/build_log_home-manager_file731=== PAUSE TestIsValidUploadKey/build_log_home-manager_file732=== RUN TestIsValidUploadKey/build_log_plus_in_name733=== PAUSE TestIsValidUploadKey/build_log_plus_in_name734=== RUN TestIsValidUploadKey/build_log_question_mark735=== PAUSE TestIsValidUploadKey/build_log_question_mark736=== RUN TestIsValidUploadKey/build_log_equals737=== PAUSE TestIsValidUploadKey/build_log_equals738=== RUN TestIsValidUploadKey/realisation739=== PAUSE TestIsValidUploadKey/realisation740=== RUN TestIsValidUploadKey/realisation_plus_in_output741=== PAUSE TestIsValidUploadKey/realisation_plus_in_output742=== RUN TestIsValidUploadKey/nix-cache-info743=== PAUSE TestIsValidUploadKey/nix-cache-info744=== RUN TestIsValidUploadKey/index.html745=== PAUSE TestIsValidUploadKey/index.html746=== RUN TestIsValidUploadKey/narinfo_key,_nar_type747=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type748=== RUN TestIsValidUploadKey/nar_key,_narinfo_type749=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type750=== RUN TestIsValidUploadKey/listing_key,_narinfo_type751=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type752=== RUN TestIsValidUploadKey/traversal753=== PAUSE TestIsValidUploadKey/traversal754=== RUN TestIsValidUploadKey/traversal_nar755=== PAUSE TestIsValidUploadKey/traversal_nar756=== RUN TestIsValidUploadKey/absolute757=== PAUSE TestIsValidUploadKey/absolute758=== RUN TestIsValidUploadKey/empty_key759=== PAUSE TestIsValidUploadKey/empty_key760=== RUN TestIsValidUploadKey/unknown_type761=== PAUSE TestIsValidUploadKey/unknown_type762=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info763=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal764=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal765=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key766=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key767=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key768=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key769=== RUN TestProxyWriteTimeout/narinfo770=== PAUSE TestProxyWriteTimeout/narinfo771=== RUN TestProxyWriteTimeout/1_GiB_nar772=== PAUSE TestProxyWriteTimeout/1_GiB_nar773=== RUN TestProxyWriteTimeout/10_GiB_nar774=== PAUSE TestProxyWriteTimeout/10_GiB_nar775=== RUN TestProxyWriteTimeout/unknown_size776=== PAUSE TestProxyWriteTimeout/unknown_size777=== CONT TestReadRedirectKeepsNarinfoProxied778--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)779=== CONT TestReadProxyDisabled780=== CONT TestParseSize781=== CONT TestReadRedirectNar782=== CONT TestReadProxyRangeRequest783--- PASS: TestParseSize (0.00s)784=== CONT TestReadProxyRootRedirectsToIndexHTML785=== PAUSE TestPendingClosureWriteTimeout/400_objects786=== RUN TestPendingClosureWriteTimeout/670k_objects787=== PAUSE TestPendingClosureWriteTimeout/670k_objects788=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline789=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline790=== CONT TestReadProxyConditionalGet791--- PASS: TestSkippedUploadsHandler (0.01s)792=== CONT TestReadProxyOutlastsServerWriteTimeout793=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure794=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure795=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart796=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart797=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts798=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts799=== CONT TestReadProxyHead8002026/10/05 11:42:52 INFO Received uploads request method=POST path=/api/pending_closures801--- PASS: TestReadProxyDisabled (0.25s)802=== CONT TestReadProxyInvalidPath8032026/10/05 11:42:52 INFO Received uploads request method=POST path=/api/pending_closures8042026/10/05 11:42:52 INFO Received uploads request method=POST path=/api/pending_closures8052026/10/05 11:42:52 INFO Received uploads request method=POST path=/api/pending_closures806--- PASS: TestService_Rustfstest (0.31s)807=== CONT TestReadProxy4048082026/10/05 11:42:53 INFO Received cleanup request method=DELETE path=/api/pending_closures8092026/10/05 11:42:53 INFO Aborted multipart uploads count=0 kept=08102026/10/05 11:42:53 INFO Received uploads request method=POST path=/api/pending_closures8112026/10/05 11:42:53 INFO Received cleanup request method=DELETE path=/api/pending_closures8122026/10/05 11:42:53 INFO Aborted multipart uploads count=1 kept=08132026/10/05 11:42:53 INFO Received push request method=POST path=/api/pushes8142026/10/05 11:42:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8152026-10-05 11:42:53.061 UTC [646] ERROR: Closure does not exist: id=18162026-10-05 11:42:53.061 UTC [646] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE8172026-10-05 11:42:53.061 UTC [646] STATEMENT: -- name: CommitPendingClosure :exec818 SELECT commit_pending_closure($1::bigint)819 820--- PASS: TestService_cleanupPendingClosuresHandler (0.52s)821=== CONT TestReadProxyNarStreaming8222026/10/05 11:42:53 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign8232026/10/05 11:42:53 INFO Signed narinfos id=1 count=1824--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.54s)825=== CONT TestReadProxyNarinfoAlreadyDecompressed8262026/10/05 11:42:53 INFO Received push request method=POST path=/api/pushes8272026/10/05 11:42:53 INFO Received complete push request method=POST path=/api/pushes/1/complete8282026/10/05 11:42:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8292026/10/05 11:42:53 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst830--- PASS: TestCompleteMultipartUnregistered (0.58s)831=== CONT TestReadProxyNarinfo832--- PASS: TestPush_CompleteCommitsEveryRoot (0.58s)833=== CONT TestIsValidCachePath834=== RUN TestIsValidCachePath/narinfo835=== PAUSE TestIsValidCachePath/narinfo836=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars837=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars838=== RUN TestIsValidCachePath/nar_zst839=== PAUSE TestIsValidCachePath/nar_zst840=== RUN TestIsValidCachePath/nar_xz841=== PAUSE TestIsValidCachePath/nar_xz842=== RUN TestIsValidCachePath/nar_bz2843=== PAUSE TestIsValidCachePath/nar_bz2844=== RUN TestIsValidCachePath/nar_uncompressed845=== PAUSE TestIsValidCachePath/nar_uncompressed846=== RUN TestIsValidCachePath/ls847=== PAUSE TestIsValidCachePath/ls848=== RUN TestIsValidCachePath/log849=== PAUSE TestIsValidCachePath/log850=== RUN TestIsValidCachePath/realisation851=== PAUSE TestIsValidCachePath/realisation852=== RUN TestIsValidCachePath/nix-cache-info853=== PAUSE TestIsValidCachePath/nix-cache-info854=== RUN TestIsValidCachePath/index.html855=== PAUSE TestIsValidCachePath/index.html856=== RUN TestIsValidCachePath/traversal_parent857=== PAUSE TestIsValidCachePath/traversal_parent858=== RUN TestIsValidCachePath/traversal_in_middle859=== PAUSE TestIsValidCachePath/traversal_in_middle860=== RUN TestIsValidCachePath/invalid_char_e861=== PAUSE TestIsValidCachePath/invalid_char_e862=== RUN TestIsValidCachePath/invalid_char_u863=== PAUSE TestIsValidCachePath/invalid_char_u864=== RUN TestIsValidCachePath/random_path865=== PAUSE TestIsValidCachePath/random_path866=== RUN TestIsValidCachePath/empty867=== PAUSE TestIsValidCachePath/empty868=== RUN TestIsValidCachePath/leading_slash869=== PAUSE TestIsValidCachePath/leading_slash870=== RUN TestIsValidCachePath/wrong_extension871=== PAUSE TestIsValidCachePath/wrong_extension872=== RUN TestIsValidCachePath/short_hash873=== PAUSE TestIsValidCachePath/short_hash874=== CONT TestProxyHeadersOnlyTrustedOnSocket8752026/10/05 11:42:53 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"876--- PASS: TestService_AuthMiddleware (0.60s)877=== CONT TestParseSingleRange878=== RUN TestParseSingleRange/none879=== PAUSE TestParseSingleRange/none880=== RUN TestParseSingleRange/unknown_unit881=== PAUSE TestParseSingleRange/unknown_unit882=== RUN TestParseSingleRange/multi-range_ignored883=== PAUSE TestParseSingleRange/multi-range_ignored884=== RUN TestParseSingleRange/malformed_no_dash885=== PAUSE TestParseSingleRange/malformed_no_dash886=== RUN TestParseSingleRange/malformed_both_empty887=== PAUSE TestParseSingleRange/malformed_both_empty888=== RUN TestParseSingleRange/malformed_end_before_start889=== PAUSE TestParseSingleRange/malformed_end_before_start890=== RUN TestParseSingleRange/closed891=== PAUSE TestParseSingleRange/closed892=== RUN TestParseSingleRange/open-ended893=== PAUSE TestParseSingleRange/open-ended894=== RUN TestParseSingleRange/end_clamped_to_size895=== PAUSE TestParseSingleRange/end_clamped_to_size896=== RUN TestParseSingleRange/suffix897=== PAUSE TestParseSingleRange/suffix898=== RUN TestParseSingleRange/suffix_exceeds_size899=== PAUSE TestParseSingleRange/suffix_exceeds_size900=== RUN TestParseSingleRange/single_byte901=== PAUSE TestParseSingleRange/single_byte902=== RUN TestParseSingleRange/start_past_EOF903=== PAUSE TestParseSingleRange/start_past_EOF904=== RUN TestParseSingleRange/start_far_past_EOF905=== PAUSE TestParseSingleRange/start_far_past_EOF906=== CONT TestPresentNotReportedWhileGCDeletesClosure9072026/10/05 11:42:53 INFO Received uploads request method=POST path=/api/pending_closures9082026/10/05 11:42:53 INFO Received uploads request method=POST path=/api/pending_closures909--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.55s)910=== CONT TestPresentReportsOnlyClosureRoots9112026/10/05 11:42:53 INFO Received uploads request method=POST path=/api/pending_closures9122026/10/05 11:42:53 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9132026/10/05 11:42:53 INFO Received uploads request method=POST path=/api/pending_closures914--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.59s)915=== CONT TestCreatePin_ReservedPins9162026/10/05 11:42:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete917--- PASS: TestReadRedirectKeepsNarinfoProxied (0.60s)918=== CONT TestOrphanedObjectsGCStressTest919--- PASS: TestReadRedirectNar (0.63s)920=== CONT TestOrphanedObjectsGC921--- PASS: TestReadProxyHead (0.59s)922=== CONT TestObjectStatsTrigger923--- PASS: TestReadRedirectUsesPublicS3URL (0.70s)924=== CONT TestPendingCleanupUsesOneCutoff9252026/10/05 11:42:53 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39735/oidc9262026/10/05 11:42:53 INFO Received push request method=POST path=/api/pushes9272026/10/05 11:42:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete928--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.73s)929=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded9302026/10/05 11:42:53 INFO Received uploads request method=POST path=/api/pending_closures9312026/10/05 11:42:53 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MTM4NzQ1MjAtZDdlNy00NTQxLWFmMmUtZjc0ZDZlMzYyZDZjLjdlNDliZTg2LWM1OGItNDcxNi1hOTc0LTE5NWI5OTc0OGM0OHgxNzkxMjAwNTcyOTMzMjMwOTI1 parts=109322026/10/05 11:42:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9332026/10/05 11:42:53 INFO Completed upload id=19342026/10/05 11:42:53 INFO Received uploads request method=POST path=/api/pending_closures9352026/10/05 11:42:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9362026/10/05 11:42:53 INFO Received uploads request method=POST path=/api/pending_closures9372026/10/05 11:42:53 INFO Received uploads request method=POST path=/api/pending_closures9382026/10/05 11:42:53 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo9392026/10/05 11:42:53 WARN Found objects in DB but missing from S3, will re-upload count=1940--- PASS: TestService_verifyS3Integrity (0.93s)941=== CONT TestMultipartCleanup9422026/10/05 11:42:53 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MTM4NzQ1MjAtZDdlNy00NTQxLWFmMmUtZjc0ZDZlMzYyZDZjLmY2MTA2ZWVkLWEyMzMtNDk2NS04YjJlLTZlYjhmMzJhNjQ3Y3gxNzkxMjAwNTcyOTc3MzEyODg3 parts=109432026/10/05 11:42:53 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9442026/10/05 11:42:53 INFO Received uploads request method=POST path=/api/pending_closures9452026/10/05 11:42:53 INFO Completed upload id=19462026/10/05 11:42:53 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009472026/10/05 11:42:53 INFO Received uploads request method=POST path=/api/pending_closures9482026/10/05 11:42:53 INFO Starting cleanup of old closures method=DELETE path=/api/closures9492026/10/05 11:42:53 INFO Aborted multipart uploads count=0 kept=0950--- PASS: TestReadProxyRangeRequest (0.80s)951=== CONT TestServerTLSConfig952=== RUN TestServerTLSConfig/no_client_CA953=== PAUSE TestServerTLSConfig/no_client_CA954=== RUN TestServerTLSConfig/missing_CA_file955=== PAUSE TestServerTLSConfig/missing_CA_file956=== RUN TestServerTLSConfig/not_a_PEM_file957=== PAUSE TestServerTLSConfig/not_a_PEM_file958=== CONT TestService_NativeMTLS9592026/10/05 11:42:53 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=09602026/10/05 11:42:53 INFO Vacuumed table table=pending_closures9612026/10/05 11:42:53 INFO Vacuumed table table=pending_objects9622026/10/05 11:42:53 INFO Vacuumed table table=multipart_uploads9632026/10/05 11:42:53 INFO Vacuumed table table=closures9642026/10/05 11:42:53 INFO Received uploads request method=POST path=/api/pending_closures9652026/10/05 11:42:53 INFO Vacuumed table table=objects9662026/10/05 11:42:53 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000967--- PASS: TestService_createPendingClosureHandler (1.00s)968=== CONT TestMetricsInventory9692026/10/05 11:42:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9702026/10/05 11:42:53 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTM4NzQ1MjAtZDdlNy00NTQxLWFmMmUtZjc0ZDZlMzYyZDZjLmJlNTE4YTM0LWU1NzAtNDQ4Yi05MTQ1LTI2MjlkNTIzOWNjOHgxNzkxMjAwNTczNTM1NzM2Mjg1971--- PASS: TestReadProxyConditionalGet (0.87s)972=== CONT TestNARDeduplicationMetadataUploadBug9732026/10/05 11:42:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MTM4NzQ1MjAtZDdlNy00NTQxLWFmMmUtZjc0ZDZlMzYyZDZjLmJlNTE4YTM0LWU1NzAtNDQ4Yi05MTQ1LTI2MjlkNTIzOWNjOHgxNzkxMjAwNTczNTM1NzM2Mjg1 parts=1974--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.89s)975=== CONT TestCreatePendingClosureRejectsOversizedNAR9762026/10/05 11:42:53 INFO Received uploads request method=POST path=/api/pending_closures977--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)978=== CONT TestCacheConfigHandlerMaxNarSize979--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)980=== CONT TestGenerateLandingPage981--- PASS: TestGenerateLandingPage (0.00s)982=== CONT TestService_readinessHandler983--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.90s)984=== CONT TestService_healthCheckHandler985--- PASS: TestReadProxyInvalidPath (0.68s)986=== CONT TestGracefulShutdownDrainsInflight9872026/10/05 11:42:53 INFO Starting HTTP server address=127.0.0.1:433599882026/10/05 11:42:53 INFO Shutdown signal received, draining in-flight requests timeout=10s989--- PASS: TestReadProxy404 (0.68s)990=== CONT TestGCTaskStore_Fail991--- PASS: TestGCTaskStore_Fail (0.00s)992=== CONT TestGCTaskStore_PhaseUpdates993--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)994=== CONT TestGCTaskStore_CompletedAllowsNewTask995--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)996=== CONT TestGCTaskStore_GetReturnsLatest997--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)998=== CONT TestGCTaskStore_GetEmpty999--- PASS: TestGCTaskStore_GetEmpty (0.00s)1000=== CONT TestLeadIncumbentAnnouncesAtOnce1001--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1002=== CONT TestGCTaskStore_DeduplicateSameParams1003--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1004=== CONT TestGCTaskStore_StartNew1005--- PASS: TestGCTaskStore_StartNew (0.00s)1006=== CONT TestGCEndsOnShutdown1007=== RUN TestGCEndsOnShutdown/before_the_run1008=== PAUSE TestGCEndsOnShutdown/before_the_run1009=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1010=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1011=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1012=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1013=== CONT TestCommitRacingPendingCleanupKeepsObjects1014--- PASS: TestReadProxyNarStreaming (0.63s)1015=== CONT TestPushWaitsForSweepHoldingRow1016--- PASS: TestReadProxyNarinfoAlreadyDecompressed (1.01s)1017=== CONT TestSweepRechecksPendingAfterLocking10182026/10/05 11:42:54 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"10192026/10/05 11:42:54 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket562587784/001/proxy.sock10202026/10/05 11:42:54 INFO Starting HTTP server address=127.0.0.1:4506110212026/10/05 11:42:54 WARN mTLS auth: subject not in bound subjects subject="CN=someone"10222026/10/05 11:42:54 INFO Shutdown signal received, draining in-flight requests timeout=10s1023--- PASS: TestProxyHeadersOnlyTrustedOnSocket (1.09s)1024=== CONT TestGetExistingObjectsLocksRows1025--- PASS: TestPresentReportsOnlyClosureRoots (1.02s)1026=== CONT TestRegisterCompletedObjectNeedsPendingRow1027--- PASS: TestObjectStatsTrigger (1.01s)1028=== CONT TestSweepSkipsRowsLockedByPush10292026/10/05 11:42:54 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10302026/10/05 11:42:54 WARN Refused reserved pin name=worker-x86_64-linux10312026/10/05 11:42:54 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10322026/10/05 11:42:54 INFO Received create pin request method=POST path=/api/pins/my-app10332026/10/05 11:42:54 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1034--- PASS: TestCreatePin_ReservedPins (1.10s)1035=== CONT TestFailedS3DeleteKeepsTombstone10362026/10/05 11:42:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10372026/10/05 11:42:54 INFO Received uploads request method=POST path=/api/pending_closures10382026/10/05 11:42:54 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MTM4NzQ1MjAtZDdlNy00NTQxLWFmMmUtZjc0ZDZlMzYyZDZjLmYzNDhiM2ZjLWJjNDgtNDY4YS1iNDk0LWJlZjBiZWM4MDk2YXgxNzkxMjAwNTczNDQyMTcyMzQ3 parts=1210392026/10/05 11:42:54 INFO Received uploads request method=POST path=/api/pending_closures10402026/10/05 11:42:54 INFO Received uploads request method=POST path=/api/pending_closures10412026/10/05 11:42:54 INFO Received uploads request method=POST path=/api/pending_closures1042--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.75s)1043=== CONT TestForceGCDuringPushOffersSweptObject1044=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1045=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1046=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1047=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1048=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10492026/10/05 11:42:54 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10502026/10/05 11:42:54 INFO Received cleanup request method=DELETE path=/api/pending_closures10512026/10/05 11:42:54 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161052--- PASS: TestReadProxyNarinfo (1.34s)1053=== CONT TestGCSweepDeliversEachKeyOnce1054--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (1.04s)1055=== CONT TestTombstonedObjectOfferedWithoutWaiting10562026/10/05 11:42:54 INFO Received uploads request method=POST path=/api/pending_closures10572026/10/05 11:42:54 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MTM4NzQ1MjAtZDdlNy00NTQxLWFmMmUtZjc0ZDZlMzYyZDZjLjI3MjA5NDE3LTRmMTEtNGI5My1iNzdlLTQzNjkwODY5YzdjZngxNzkxMjAwNTczNDczNzIxNDEz parts=1210582026/10/05 11:42:54 INFO Received uploads request method=POST path=/api/pending_closures10592026/10/05 11:42:54 INFO Received uploads request method=POST path=/api/pending_closures10602026/10/05 11:42:54 WARN mTLS auth: subject not in bound subjects subject="CN=reader"10612026/10/05 11:42:54 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1062--- PASS: TestService_NativeMTLS (1.00s)1063=== CONT TestGCSweepSkipsPendingObjects1064--- PASS: TestMetricsInventory (1.02s)1065=== CONT TestDeduplicatedObjectsRecordedAsPending10662026/10/05 11:42:54 INFO Received cleanup request method=DELETE path=/api/pending_closures10672026/10/05 11:42:54 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket41/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""10682026/10/05 11:42:54 INFO Aborted multipart uploads count=0 kept=110692026/10/05 11:42:54 INFO Received cleanup request method=DELETE path=/api/pending_closures10702026/10/05 11:42:54 INFO Aborted multipart uploads count=1 kept=010712026/10/05 11:42:54 WARN readiness check failed error="closed pool"1072--- PASS: TestService_readinessHandler (1.01s)1073=== CONT TestPushDedupSurvivesConcurrentGC1074--- PASS: TestMultipartCleanup (1.13s)1075=== CONT TestGCMetrics1076=== NAME TestNARDeduplicationMetadataUploadBug1077 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug700734000/001/store/8m8qszvhc51ainc0j8sakd2a99s8gqhb-file1.txt1078--- PASS: TestService_healthCheckHandler (1.04s)1079=== CONT TestGCBugBareHashReferences1080=== NAME TestOrphanedObjectsGC1081 orphaned_objects_gc_test.go:290: GC Test Summary:1082 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1083 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1084 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1085 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1086 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1087--- PASS: TestOrphanedObjectsGC (1.36s)1088=== CONT TestGCAdvisoryLockBlocksConcurrentRun1089--- PASS: TestPresentNotReportedWhileGCDeletesClosure (1.55s)1090=== CONT TestLeadEndsOnShutdown10912026/10/05 11:42:54 INFO lead: acquired remote=192.0.2.1:123410922026/10/05 11:42:54 INFO lead: released remote=192.0.2.1:12341093--- PASS: TestLeadIncumbentAnnouncesAtOnce (1.01s)1094=== CONT TestClientIntegration10952026/10/05 11:42:54 INFO Received push request method=POST path=/api/pushes10962026/10/05 11:42:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10972026/10/05 11:42:54 INFO Uploading 8m8qszvhc51ainc0j8sakd2a99s8gqhb-file1.txt (160B)10982026/10/05 11:42:54 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"10992026/10/05 11:42:54 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11002026/10/05 11:42:54 WARN Failed to register uploaded object key=8m8qszvhc51ainc0j8sakd2a99s8gqhb.ls error="server returned 404: 404 page not found\n"11012026/10/05 11:42:54 INFO Signed narinfos id=1 count=111022026/10/05 11:42:54 INFO Uploading 1 narinfos11032026/10/05 11:42:54 INFO Received complete push request method=POST path=/api/pushes/1/complete11042026/10/05 11:42:54 WARN Failed to register uploaded object key=8m8qszvhc51ainc0j8sakd2a99s8gqhb.narinfo error="server returned 404: 404 page not found\n"11052026/10/05 11:42:54 INFO Upload complete. (71ms)1106=== NAME TestNARDeduplicationMetadataUploadBug1107 metadata_upload_test.go:54: Retrieved narinfo from S3:1108 StorePath: /build/TestNARDeduplicationMetadataUploadBug700734000/001/store/8m8qszvhc51ainc0j8sakd2a99s8gqhb-file1.txt1109 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1110 Compression: zstd1111 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1112 NarSize: 1601113 References: 1114 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1115 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1116 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1117 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}11182026/10/05 11:42:54 INFO Received uploads request method=POST path=/api/pending_closures11192026/10/05 11:42:54 INFO Aborted multipart uploads count=0 kept=011202026/10/05 11:42:54 WARN Force mode enabled - objects will be deleted immediately without grace period1121 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug700734000/001/store/w8y0rra8110687m6pmgwgygyq3jpg5fd-file2.txt11222026/10/05 11:42:54 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=011232026/10/05 11:42:54 INFO Vacuumed table table=pending_closures11242026/10/05 11:42:54 INFO Vacuumed table table=pending_objects11252026/10/05 11:42:54 INFO Vacuumed table table=multipart_uploads11262026/10/05 11:42:54 INFO Vacuumed table table=closures11272026/10/05 11:42:54 INFO Vacuumed table table=objects1128--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.26s)1129=== CONT TestLeadElectsOneAndHandsOver11302026/10/05 11:42:54 INFO Received push request method=POST path=/api/pushes11312026/10/05 11:42:54 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)11322026/10/05 11:42:54 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign11332026/10/05 11:42:54 WARN Failed to register uploaded object key=w8y0rra8110687m6pmgwgygyq3jpg5fd.ls error="server returned 404: 404 page not found\n"11342026/10/05 11:42:54 INFO Signed narinfos id=2 count=111352026/10/05 11:42:54 INFO Uploading 1 narinfos11362026/10/05 11:42:54 INFO Aborted multipart uploads count=0 kept=011372026/10/05 11:42:54 INFO Received complete push request method=POST path=/api/pushes/2/complete11382026/10/05 11:42:54 WARN Failed to register uploaded object key=w8y0rra8110687m6pmgwgygyq3jpg5fd.narinfo error="server returned 404: 404 page not found\n"11392026/10/05 11:42:54 WARN Force mode enabled - objects will be deleted immediately without grace period11402026/10/05 11:42:54 INFO Upload complete. (50ms)1141=== NAME TestNARDeduplicationMetadataUploadBug1142 metadata_upload_test.go:76: Retrieved narinfo from S3:1143 StorePath: /build/TestNARDeduplicationMetadataUploadBug700734000/001/store/w8y0rra8110687m6pmgwgygyq3jpg5fd-file2.txt1144 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1145 Compression: zstd1146 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1147 NarSize: 1601148 References: 1149 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1150 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1151 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1152 {"version":1,"root":{"type":"regular","size":44}}1153--- PASS: TestNARDeduplicationMetadataUploadBug (1.41s)1154=== CONT TestConnectWaitsForAPeerMigration11552026/10/05 11:42:54 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=011562026/10/05 11:42:54 INFO Vacuumed table table=pending_closures11572026/10/05 11:42:54 INFO Vacuumed table table=pending_objects11582026/10/05 11:42:55 INFO Vacuumed table table=multipart_uploads11592026/10/05 11:42:55 INFO Vacuumed table table=closures1160--- PASS: TestGetExistingObjectsLocksRows (0.78s)1161=== CONT TestResolveDBConnectionString11622026/10/05 11:42:55 INFO Vacuumed table table=objects1163=== RUN TestResolveDBConnectionString/flag_wins1164=== PAUSE TestResolveDBConnectionString/flag_wins1165=== RUN TestResolveDBConnectionString/file_when_flag_empty1166=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1167=== RUN TestResolveDBConnectionString/missing_file_is_an_error1168=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1169=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1170=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1171=== RUN TestResolveDBConnectionString/nothing_configured1172=== PAUSE TestResolveDBConnectionString/nothing_configured1173=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1174--- PASS: TestSweepRechecksPendingAfterLocking (0.92s)1175=== CONT TestClientFallsBackToClosures1176--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.76s)1177=== CONT TestClientPushesUseOnePush11782026/10/05 11:42:55 INFO Aborted multipart uploads count=0 kept=011792026/10/05 11:42:55 WARN Force mode enabled - objects will be deleted immediately without grace period11802026/10/05 11:42:55 INFO Received uploads request method=POST path=/api/pending_closures11812026/10/05 11:42:55 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=011822026/10/05 11:42:55 INFO Vacuumed table table=pending_closures11832026/10/05 11:42:55 INFO Vacuumed table table=pending_objects11842026/10/05 11:42:55 INFO Vacuumed table table=multipart_uploads11852026/10/05 11:42:55 INFO Vacuumed table table=closures11862026/10/05 11:42:55 INFO Vacuumed table table=objects11872026/10/05 11:42:55 INFO Aborted multipart uploads count=0 kept=011882026/10/05 11:42:55 WARN Force mode enabled - objects will be deleted immediately without grace period11892026/10/05 11:42:55 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=011902026/10/05 11:42:55 INFO Vacuumed table table=pending_closures11912026/10/05 11:42:55 INFO Vacuumed table table=pending_objects11922026/10/05 11:42:55 INFO Vacuumed table table=multipart_uploads11932026/10/05 11:42:55 INFO Vacuumed table table=closures11942026/10/05 11:42:55 INFO Vacuumed table table=objects11952026/10/05 11:42:55 INFO Received uploads request method=POST path=/api/pending_closures1196--- PASS: TestSweepSkipsRowsLockedByPush (0.74s)1197=== CONT TestPinProtectsFromGC11982026/10/05 11:42:55 INFO Received uploads request method=POST path=/api/pending_closures1199--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.69s)1200=== CONT TestClientSharedPathCommittedMidPush12012026/10/05 11:42:55 INFO Aborted multipart uploads count=0 kept=012022026/10/05 11:42:55 WARN Force mode enabled - objects will be deleted immediately without grace period12032026/10/05 11:42:55 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12042026/10/05 11:42:55 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1205--- PASS: TestFailedS3DeleteKeepsTombstone (0.80s)1206=== CONT TestClientWithDependencies12072026/10/05 11:42:55 INFO Aborted multipart uploads count=0 kept=012082026/10/05 11:42:55 INFO Received uploads request method=POST path=/api/pending_closures12092026/10/05 11:42:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12102026/10/05 11:42:55 WARN Force mode enabled - objects will be deleted immediately without grace period12112026/10/05 11:42:55 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=012122026/10/05 11:42:55 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MTM4NzQ1MjAtZDdlNy00NTQxLWFmMmUtZjc0ZDZlMzYyZDZjLmU1NzAxODg2LWFiZWEtNDQ4My05NTY2LWZmMmUzYjYwNWUyMXgxNzkxMjAwNTc0NDkyODE0MTc2 error="Get \"http://127.0.0.1:1/bucket23/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"12132026/10/05 11:42:55 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MTM4NzQ1MjAtZDdlNy00NTQxLWFmMmUtZjc0ZDZlMzYyZDZjLmMyMzY3Mjg0LWIwMjYtNGZiOC04MDRiLTA3ZWJiNzFjYzg2MngxNzkxMjAwNTc0NDgzNjUyNDc2 parts=1212142026/10/05 11:42:55 INFO Vacuumed table table=pending_closures12152026/10/05 11:42:55 INFO Aborted multipart uploads count=0 kept=012162026/10/05 11:42:55 INFO Vacuumed table table=pending_objects12172026/10/05 11:42:55 INFO Vacuumed table table=multipart_uploads12182026/10/05 11:42:55 INFO Vacuumed table table=closures12192026/10/05 11:42:55 INFO Received cleanup request method=DELETE path=/api/pending_closures12202026/10/05 11:42:55 WARN Force mode enabled - objects will be deleted immediately without grace period12212026/10/05 11:42:55 INFO Vacuumed table table=objects1222--- PASS: TestGCSweepDeliversEachKeyOnce (0.76s)1223=== CONT TestClientMultipleUploads12242026/10/05 11:42:55 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=012252026/10/05 11:42:55 INFO Aborted multipart uploads count=1 kept=012262026/10/05 11:42:55 INFO Received uploads request method=POST path=/api/pending_closures12272026/10/05 11:42:55 INFO Vacuumed table table=pending_closures12282026/10/05 11:42:55 INFO Vacuumed table table=pending_objects12292026/10/05 11:42:55 INFO Vacuumed table table=multipart_uploads12302026/10/05 11:42:55 INFO Vacuumed table table=closures1231--- PASS: TestRedundantMultipartUpload (2.54s)1232=== CONT TestService_ReadScope_PublicByDefault12332026/10/05 11:42:55 INFO Vacuumed table table=objects1234--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.68s)1235=== CONT TestClientErrorHandling1236=== RUN TestClientErrorHandling/InvalidStorePath1237=== PAUSE TestClientErrorHandling/InvalidStorePath1238=== RUN TestClientErrorHandling/InvalidAuthToken1239=== PAUSE TestClientErrorHandling/InvalidAuthToken1240=== RUN TestClientErrorHandling/ServerNotAvailable1241=== PAUSE TestClientErrorHandling/ServerNotAvailable1242=== CONT TestClientCADerivations1243--- PASS: TestGCSweepSkipsPendingObjects (0.74s)1244=== CONT TestCacheStatsHandler12452026/10/05 11:42:55 INFO Received uploads request method=POST path=/api/pending_closures1246--- PASS: TestPushWaitsForSweepHoldingRow (1.59s)1247=== CONT TestCacheConfigHandler1248=== RUN TestCacheConfigHandler/full_config,_no_issuer1249=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1250=== RUN TestCacheConfigHandler/no_cache_url_configured1251=== PAUSE TestCacheConfigHandler/no_cache_url_configured1252=== RUN TestCacheConfigHandler/no_signing_keys1253=== PAUSE TestCacheConfigHandler/no_signing_keys1254=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1255=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1256=== CONT TestPush_RejectsBadRequests12572026/10/05 11:42:55 INFO Aborted multipart uploads count=0 kept=012582026/10/05 11:42:55 WARN Force mode enabled - objects will be deleted immediately without grace period12592026/10/05 11:42:55 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=012602026/10/05 11:42:55 INFO Vacuumed table table=pending_closures12612026/10/05 11:42:55 INFO Vacuumed table table=pending_objects12622026/10/05 11:42:55 INFO Vacuumed table table=multipart_uploads12632026/10/05 11:42:55 INFO Vacuumed table table=closures12642026/10/05 11:42:55 INFO Vacuumed table table=objects1265--- PASS: TestGCMetrics (0.71s)1266=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1267--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.88s)1268=== CONT TestService_AuthMiddleware_MTLSBoundSubjects12692026/10/05 11:42:55 INFO lead: acquired remote=192.0.2.1:123412702026/10/05 11:42:55 INFO Aborted multipart uploads count=0 kept=012712026/10/05 11:42:55 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=012722026/10/05 11:42:55 INFO Vacuumed table table=pending_closures12732026/10/05 11:42:55 INFO Vacuumed table table=pending_objects12742026/10/05 11:42:55 INFO Vacuumed table table=multipart_uploads12752026/10/05 11:42:55 INFO Vacuumed table table=closures12762026/10/05 11:42:55 INFO Vacuumed table table=objects12772026/10/05 11:42:55 INFO Aborted multipart uploads count=0 kept=012782026/10/05 11:42:55 WARN Force mode enabled - objects will be deleted immediately without grace period12792026/10/05 11:42:55 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=012802026/10/05 11:42:55 INFO Vacuumed table table=pending_closures12812026/10/05 11:42:55 INFO Vacuumed table table=pending_objects12822026/10/05 11:42:55 INFO Vacuumed table table=multipart_uploads12832026/10/05 11:42:55 INFO Vacuumed table table=closures12842026/10/05 11:42:55 INFO Vacuumed table table=objects1285--- PASS: TestPushDedupSurvivesConcurrentGC (0.80s)1286=== CONT TestService_ReadAuthMiddleware12872026/10/05 11:42:55 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=nixbld database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1288--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.74s)1289=== CONT TestService_RequireScope_OIDC1290=== NAME TestClientIntegration1291 client_integration_test.go:286: Created store path: /build/TestClientIntegration3355054282/002/store/2r4xilw92h7hw8vnwjr9gv04gbs0cqda-test-file.txt12922026/10/05 11:42:55 INFO lead: acquired remote=192.0.2.1:123412932026/10/05 11:42:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33769/oidc12942026/10/05 11:42:55 INFO Received push request method=POST path=/api/pushes12952026/10/05 11:42:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12962026/10/05 11:42:55 INFO Uploading 2r4xilw92h7hw8vnwjr9gv04gbs0cqda-test-file.txt (152B)12972026/10/05 11:42:55 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"12982026/10/05 11:42:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12992026/10/05 11:42:55 WARN Failed to register uploaded object key=2r4xilw92h7hw8vnwjr9gv04gbs0cqda.ls error="server returned 404: 404 page not found\n"13002026/10/05 11:42:55 INFO Signed narinfos id=1 count=113012026/10/05 11:42:55 INFO Uploading 1 narinfos13022026/10/05 11:42:55 INFO Received complete push request method=POST path=/api/pushes/1/complete13032026/10/05 11:42:55 WARN Failed to register uploaded object key=2r4xilw92h7hw8vnwjr9gv04gbs0cqda.narinfo error="server returned 404: 404 page not found\n"13042026/10/05 11:42:55 INFO Upload complete. (79ms)13052026/10/05 11:42:55 INFO All 1 paths already cached1306 client_integration_test.go:312: Retrieved narinfo from S3:1307 StorePath: /build/TestClientIntegration3355054282/002/store/2r4xilw92h7hw8vnwjr9gv04gbs0cqda-test-file.txt1308 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1309 Compression: zstd1310 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11311 NarSize: 1521312 References: 1313 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11314 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1315 client_integration_test.go:313: Decompressed .ls content (64 bytes):1316 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1317 client_integration_test.go:316: Testing garbage collection...1318--- PASS: TestGCBugBareHashReferences (0.95s)1319=== CONT TestService_AuthMiddleware_OIDC13202026/10/05 11:42:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures13212026/10/05 11:42:55 INFO Garbage collection started13222026/10/05 11:42:55 INFO Aborted multipart uploads count=0 kept=013232026/10/05 11:42:55 WARN Force mode enabled - objects will be deleted immediately without grace period1324=== NAME TestPinProtectsFromGC1325 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC394553515/001/store/jhsbwg776i4x8ingmzlf6r52bbdy437n-pinned-file.txt1326 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC394553515/001/store/k8m6fibsv0j6cwm6sajhlv2dvgmlqdj0-unpinned-file.txt1327--- PASS: TestService_ReadScope_PublicByDefault (0.40s)1328=== CONT TestService_AuthMiddleware_MTLSProxyHeader13292026/10/05 11:42:55 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39909/oidc13302026/10/05 11:42:55 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=013312026/10/05 11:42:55 INFO Vacuumed table table=pending_closures13322026/10/05 11:42:55 INFO Vacuumed table table=pending_objects13332026/10/05 11:42:55 INFO Vacuumed table table=multipart_uploads13342026/10/05 11:42:55 INFO Vacuumed table table=closures13352026/10/05 11:42:55 INFO Vacuumed table table=objects13362026/10/05 11:42:55 INFO Received uploads request method=POST path=/api/pending_closures13372026/10/05 11:42:55 INFO Received uploads request method=POST path=/api/pending_closures13382026/10/05 11:42:55 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13392026/10/05 11:42:55 INFO Uploading syfzc84yy0mz6cd4i4grbn1f6hcd1qyb-shared-dep (136B)13402026/10/05 11:42:55 INFO Uploading x9p9cvms5d28616wnk8m1lmby3s0iixp-a (216B)13412026/10/05 11:42:55 WARN Failed to register uploaded object key=d8wlfkb50g2jj10zpafjkbvwaj2jcj10.ls error="server returned 404: 404 page not found\n"13422026/10/05 11:42:55 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13432026/10/05 11:42:55 WARN Failed to register uploaded object key=nar/0pa8jgx0kp8gzf3fp4zfxfjfmy4r2yb2mfzdfbgd5434zwk0w7f6.nar.zst error="server returned 404: 404 page not found\n"13442026/10/05 11:42:55 WARN Failed to register uploaded object key=x9p9cvms5d28616wnk8m1lmby3s0iixp.ls error="server returned 404: 404 page not found\n"13452026/10/05 11:42:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign13462026/10/05 11:42:55 WARN Failed to register uploaded object key=syfzc84yy0mz6cd4i4grbn1f6hcd1qyb.ls error="server returned 404: 404 page not found\n"13472026/10/05 11:42:55 INFO Signed narinfos id=2 count=213482026/10/05 11:42:55 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign13492026/10/05 11:42:55 INFO Signed narinfos id=1 count=213502026/10/05 11:42:55 INFO Uploading 4 narinfos13512026/10/05 11:42:55 WARN Failed to register uploaded object key=x9p9cvms5d28616wnk8m1lmby3s0iixp.narinfo error="server returned 404: 404 page not found\n"13522026/10/05 11:42:55 WARN Failed to register uploaded object key=d8wlfkb50g2jj10zpafjkbvwaj2jcj10.narinfo error="server returned 404: 404 page not found\n"13532026/10/05 11:42:55 WARN Failed to register uploaded object key=syfzc84yy0mz6cd4i4grbn1f6hcd1qyb.narinfo error="server returned 404: 404 page not found\n"1354=== NAME TestClientWithDependencies1355 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies64017097/001/store/6cpg3iwvcaqjqn40an2hg2bl1f9xk153-test-script13562026/10/05 11:42:55 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13572026/10/05 11:42:55 WARN Failed to register uploaded object key=syfzc84yy0mz6cd4i4grbn1f6hcd1qyb.narinfo error="server returned 404: 404 page not found\n"13582026/10/05 11:42:55 INFO Received push request method=POST path=/api/pushes1359=== NAME TestClientMultipleUploads1360 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads1666192366/001/store/k9zfvi8pyl7qn33d09i4yb06qhf0jm7a-test-file-0.txt13612026/10/05 11:42:55 INFO Completed upload id=213622026/10/05 11:42:55 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13632026/10/05 11:42:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13642026/10/05 11:42:55 INFO Uploading jhsbwg776i4x8ingmzlf6r52bbdy437n-pinned-file.txt (128B)13652026/10/05 11:42:55 INFO Completed upload id=113662026/10/05 11:42:55 INFO Upload complete. (91ms)1367=== NAME TestClientFallsBackToClosures1368 client_pushes_test.go:112: Retrieved narinfo from S3:1369 StorePath: /build/TestClientFallsBackToClosures3733668368/001/store/syfzc84yy0mz6cd4i4grbn1f6hcd1qyb-shared-dep1370 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1371 Compression: zstd1372 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821373 NarSize: 1361374 References: 1375 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n13762026/10/05 11:42:55 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13772026/10/05 11:42:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13782026/10/05 11:42:55 INFO Received push request method=POST path=/api/pushes13792026/10/05 11:42:55 WARN Failed to register uploaded object key=jhsbwg776i4x8ingmzlf6r52bbdy437n.ls error="server returned 404: 404 page not found\n"13802026/10/05 11:42:55 INFO Signed narinfos id=1 count=113812026/10/05 11:42:55 INFO Uploading 1 narinfos1382 client_pushes_test.go:112: Retrieved narinfo from S3:1383 StorePath: /build/TestClientFallsBackToClosures3733668368/001/store/x9p9cvms5d28616wnk8m1lmby3s0iixp-a1384 URL: nar/0pa8jgx0kp8gzf3fp4zfxfjfmy4r2yb2mfzdfbgd5434zwk0w7f6.nar.zst1385 Compression: zstd1386 NarHash: sha256:0pa8jgx0kp8gzf3fp4zfxfjfmy4r2yb2mfzdfbgd5434zwk0w7f61387 NarSize: 2161388 References: /build/TestClientFallsBackToClosures3733668368/001/store/syfzc84yy0mz6cd4i4grbn1f6hcd1qyb-shared-dep1389 CA: text:sha256:0sc708y7pd0kqgswrizmj38xf67ak77j547cf42s1m7rcn2mzzlz13902026/10/05 11:42:55 INFO Received complete push request method=POST path=/api/pushes/1/complete1391 client_pushes_test.go:112: Retrieved narinfo from S3:1392 StorePath: /build/TestClientFallsBackToClosures3733668368/001/store/d8wlfkb50g2jj10zpafjkbvwaj2jcj10-b1393 URL: nar/0pa8jgx0kp8gzf3fp4zfxfjfmy4r2yb2mfzdfbgd5434zwk0w7f6.nar.zst1394 Compression: zstd13952026/10/05 11:42:55 WARN Failed to register uploaded object key=jhsbwg776i4x8ingmzlf6r52bbdy437n.narinfo error="server returned 404: 404 page not found\n"1396 NarHash: sha256:0pa8jgx0kp8gzf3fp4zfxfjfmy4r2yb2mfzdfbgd5434zwk0w7f61397 NarSize: 2161398 References: /build/TestClientFallsBackToClosures3733668368/001/store/syfzc84yy0mz6cd4i4grbn1f6hcd1qyb-shared-dep1399 CA: text:sha256:0sc708y7pd0kqgswrizmj38xf67ak77j547cf42s1m7rcn2mzzlz1400=== NAME TestClientWithDependencies1401 client_integration_test.go:615: Found 1 dependencies (including self)1402--- PASS: TestCacheStatsHandler (0.49s)14032026/10/05 11:42:55 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)1404=== CONT TestIsValidUploadKey/narinfo1405=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info14062026/10/05 11:42:55 INFO Uploading 5pl8bacirk1dsx07szpwzif4g2l28i3x-a (216B)14072026/10/05 11:42:55 INFO Uploading y32wkssjpnww0b63xxvk4hh6qbbrnriy-shared-dep (136B)14082026/10/05 11:42:55 INFO Received uploads request method=POST path=/1409=== CONT TestIsValidUploadKey/build_log_equals1410=== CONT TestProxyWriteTimeout/narinfo1411=== CONT TestIsValidUploadKey/build_log_question_mark1412=== CONT TestIsValidUploadKey/build_log_plus_in_name1413=== CONT TestIsValidUploadKey/build_log_home-manager_file1414=== CONT TestIsValidUploadKey/build_log1415=== CONT TestIsValidUploadKey/listing1416=== CONT TestIsValidUploadKey/nar_plain1417=== CONT TestIsValidUploadKey/nar_xz1418=== CONT TestIsValidUploadKey/nar_zst1419=== CONT TestIsValidUploadKey/unknown_type1420=== CONT TestIsValidUploadKey/empty_key1421=== CONT TestIsValidUploadKey/absolute1422=== CONT TestIsValidUploadKey/traversal_nar1423=== CONT TestIsValidUploadKey/traversal1424=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1425=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1426=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1427=== CONT TestIsValidUploadKey/index.html1428=== CONT TestIsValidUploadKey/nix-cache-info1429=== CONT TestIsValidUploadKey/realisation_plus_in_output1430=== CONT TestIsValidUploadKey/realisation1431--- PASS: TestIsValidUploadKey (0.00s)1432 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1433 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1434 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1435 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1436 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1437 --- PASS: TestIsValidUploadKey/build_log (0.00s)1438 --- PASS: TestIsValidUploadKey/listing (0.00s)1439 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1440 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1441 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1442 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1443 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1444 --- PASS: TestIsValidUploadKey/absolute (0.00s)1445 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1446 --- PASS: TestIsValidUploadKey/traversal (0.00s)1447 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1448 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1449 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1450 --- PASS: TestIsValidUploadKey/index.html (0.00s)1451 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1452 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1453 --- PASS: TestIsValidUploadKey/realisation (0.00s)1454=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key14552026/10/05 11:42:55 INFO Received complete multipart upload request method=POST path=/1456=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key14572026/10/05 11:42:55 INFO Received request for more parts method=POST path=/1458=== CONT TestProxyWriteTimeout/10_GiB_nar1459=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal14602026/10/05 11:42:55 INFO Received uploads request method=POST path=/1461--- PASS: TestUploadHandlersRejectInvalidKeys (0.15s)1462 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1463 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1464 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1465 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1466=== CONT TestProxyWriteTimeout/unknown_size1467=== CONT TestProxyWriteTimeout/1_GiB_nar1468--- PASS: TestProxyWriteTimeout (0.00s)1469 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1470 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1471 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1472 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1473=== CONT TestPendingClosureWriteTimeout/empty1474=== CONT TestPendingClosureWriteTimeout/670k_objects1475=== CONT TestPendingClosureWriteTimeout/400_objects1476=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline14772026/10/05 11:42:55 WARN Failed to register uploaded object key=1171qx6mh65w5jcn1vllv7vcs1p7m13k.ls error="server returned 404: 404 page not found\n"14782026/10/05 11:42:55 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1479--- PASS: TestClientFallsBackToClosures (0.73s)1480=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure14812026/10/05 11:42:55 INFO Received uploads request method=POST path=/14822026/10/05 11:42:55 WARN Failed to register uploaded object key=5pl8bacirk1dsx07szpwzif4g2l28i3x.ls error="server returned 404: 404 page not found\n"14832026/10/05 11:42:55 WARN Failed to register uploaded object key=nar/1skr2phddfaqx19519c0ywxafn1xbg13a81n81qnvza64fdddc2q.nar.zst error="server returned 404: 404 page not found\n"14842026/10/05 11:42:55 WARN Failed to register uploaded object key=y32wkssjpnww0b63xxvk4hh6qbbrnriy.ls error="server returned 404: 404 page not found\n"14852026/10/05 11:42:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14862026/10/05 11:42:55 INFO Upload complete. (66ms)14872026/10/05 11:42:55 INFO Signed narinfos id=1 count=314882026/10/05 11:42:55 INFO Uploading 3 narinfos14892026/10/05 11:42:55 WARN Failed to register uploaded object key=1171qx6mh65w5jcn1vllv7vcs1p7m13k.narinfo error="server returned 404: 404 page not found\n"1490=== RUN TestPush_RejectsBadRequests/no_roots1491=== PAUSE TestPush_RejectsBadRequests/no_roots1492=== RUN TestPush_RejectsBadRequests/no_objects1493=== PAUSE TestPush_RejectsBadRequests/no_objects1494=== RUN TestPush_RejectsBadRequests/bad_root1495=== PAUSE TestPush_RejectsBadRequests/bad_root1496=== RUN TestPush_RejectsBadRequests/root_not_in_objects1497=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1498=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts14992026/10/05 11:42:55 INFO Received request for more parts method=POST path=/15002026/10/05 11:42:55 WARN Failed to register uploaded object key=y32wkssjpnww0b63xxvk4hh6qbbrnriy.narinfo error="server returned 404: 404 page not found\n"15012026/10/05 11:42:55 INFO Received complete push request method=POST path=/api/pushes/1/complete15022026/10/05 11:42:55 WARN Failed to register uploaded object key=5pl8bacirk1dsx07szpwzif4g2l28i3x.narinfo error="server returned 404: 404 page not found\n"1503=== NAME TestClientMultipleUploads1504 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads1666192366/001/store/frfvci4dlnklgas6b31y7wn12i5mi8y2-test-file-1.txt15052026/10/05 11:42:55 INFO Upload complete. (68ms)1506=== NAME TestClientPushesUseOnePush1507 client_pushes_test.go:97: Retrieved narinfo from S3:1508 StorePath: /build/TestClientPushesUseOnePush3024759736/001/store/y32wkssjpnww0b63xxvk4hh6qbbrnriy-shared-dep1509 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1510 Compression: zstd1511 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821512 NarSize: 1361513 References: 1514 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1515 client_pushes_test.go:97: Retrieved narinfo from S3:1516 StorePath: /build/TestClientPushesUseOnePush3024759736/001/store/5pl8bacirk1dsx07szpwzif4g2l28i3x-a1517 URL: nar/1skr2phddfaqx19519c0ywxafn1xbg13a81n81qnvza64fdddc2q.nar.zst1518 Compression: zstd1519 NarHash: sha256:1skr2phddfaqx19519c0ywxafn1xbg13a81n81qnvza64fdddc2q1520 NarSize: 2161521 References: /build/TestClientPushesUseOnePush3024759736/001/store/y32wkssjpnww0b63xxvk4hh6qbbrnriy-shared-dep1522 CA: text:sha256:0mbq0rg5vi1s9c66dyhw56zz9npix2nq1hkgs9i033b59fn5jla51523 client_pushes_test.go:97: Retrieved narinfo from S3:1524 StorePath: /build/TestClientPushesUseOnePush3024759736/001/store/1171qx6mh65w5jcn1vllv7vcs1p7m13k-b1525 URL: nar/1skr2phddfaqx19519c0ywxafn1xbg13a81n81qnvza64fdddc2q.nar.zst1526 Compression: zstd1527 NarHash: sha256:1skr2phddfaqx19519c0ywxafn1xbg13a81n81qnvza64fdddc2q1528 NarSize: 2161529 References: /build/TestClientPushesUseOnePush3024759736/001/store/y32wkssjpnww0b63xxvk4hh6qbbrnriy-shared-dep1530 CA: text:sha256:0mbq0rg5vi1s9c66dyhw56zz9npix2nq1hkgs9i033b59fn5jla51531--- PASS: TestClientPushesUseOnePush (0.75s)1532=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15332026/10/05 11:42:55 INFO Received complete multipart upload request method=POST path=/15342026/10/05 11:42:55 INFO Received push request method=POST path=/api/pushes15352026/10/05 11:42:55 INFO Received push request method=POST path=/api/pushes15362026/10/05 11:42:55 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15372026/10/05 11:42:55 INFO Uploading gv6ryn3mbdfkwnvlrydyr95cypf55jw9-top (224B)15382026/10/05 11:42:55 INFO Uploading gxgwhi7ly0d4km3i95ks00xmhfsnl90y-shared-dep (136B)15392026/10/05 11:42:55 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15402026/10/05 11:42:55 WARN Failed to register uploaded object key=gv6ryn3mbdfkwnvlrydyr95cypf55jw9.ls error="server returned 404: 404 page not found\n"15412026/10/05 11:42:55 WARN Failed to register uploaded object key=nar/1r6ygswzwr8xs4h2n03a779wirh8wnc5dz9xkki17kd2v89g8lrk.nar.zst error="server returned 404: 404 page not found\n"15422026/10/05 11:42:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1543=== NAME TestClientCADerivations15442026/10/05 11:42:55 WARN Failed to register uploaded object key=gxgwhi7ly0d4km3i95ks00xmhfsnl90y.ls error="server returned 404: 404 page not found\n"1545 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1972017277/001/store/28ij30fkrgvgqah7f6vnssq7yi2b779b-ca-test15462026/10/05 11:42:55 INFO Signed narinfos id=1 count=215472026/10/05 11:42:55 INFO Uploading 2 narinfos1548=== NAME TestClientMultipleUploads1549 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads1666192366/001/store/vbcy2z54dawv693ncgcb0in6rs8bkpgn-test-file-2.txt15502026/10/05 11:42:55 INFO Received complete push request method=POST path=/api/pushes/1/complete15512026/10/05 11:42:55 WARN Failed to register uploaded object key=gv6ryn3mbdfkwnvlrydyr95cypf55jw9.narinfo error="server returned 404: 404 page not found\n"15522026/10/05 11:42:55 INFO Received complete push request method=POST path=/api/pushes/1/complete15532026/10/05 11:42:55 WARN Failed to register uploaded object key=gxgwhi7ly0d4km3i95ks00xmhfsnl90y.narinfo error="server returned 404: 404 page not found\n"15542026/10/05 11:42:55 INFO Received push request method=POST path=/api/pushes15552026/10/05 11:42:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"15562026/10/05 11:42:55 WARN mTLS auth: bound subjects configured but subject DN unavailable15572026/10/05 11:42:55 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1558--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.47s)1559=== CONT TestIsValidCachePath/narinfo1560=== CONT TestIsValidCachePath/index.html1561=== CONT TestIsValidCachePath/short_hash1562=== CONT TestIsValidCachePath/wrong_extension1563=== CONT TestIsValidCachePath/leading_slash1564=== CONT TestIsValidCachePath/empty1565=== CONT TestIsValidCachePath/random_path1566=== CONT TestIsValidCachePath/invalid_char_u1567=== CONT TestIsValidCachePath/invalid_char_e1568=== CONT TestIsValidCachePath/traversal_in_middle1569=== CONT TestIsValidCachePath/traversal_parent1570=== CONT TestIsValidCachePath/realisation1571=== CONT TestIsValidCachePath/nix-cache-info1572=== CONT TestIsValidCachePath/log1573=== CONT TestIsValidCachePath/ls1574=== CONT TestIsValidCachePath/nar_xz1575=== CONT TestIsValidCachePath/nar_bz21576=== CONT TestIsValidCachePath/nar_uncompressed1577=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1578=== CONT TestIsValidCachePath/nar_zst1579--- PASS: TestIsValidCachePath (0.00s)1580 --- PASS: TestIsValidCachePath/narinfo (0.00s)1581 --- PASS: TestIsValidCachePath/index.html (0.00s)1582 --- PASS: TestIsValidCachePath/short_hash (0.00s)1583 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1584 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1585 --- PASS: TestIsValidCachePath/empty (0.00s)1586 --- PASS: TestIsValidCachePath/random_path (0.00s)1587 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1588 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1589 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1590 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1591 --- PASS: TestIsValidCachePath/realisation (0.00s)1592 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1593 --- PASS: TestIsValidCachePath/log (0.00s)1594 --- PASS: TestIsValidCachePath/ls (0.00s)1595 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1596 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1597 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1598 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1599 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1600=== CONT TestParseSingleRange/none1601=== CONT TestParseSingleRange/open-ended1602=== CONT TestParseSingleRange/start_far_past_EOF1603=== CONT TestParseSingleRange/start_past_EOF1604=== CONT TestParseSingleRange/single_byte1605=== CONT TestParseSingleRange/suffix_exceeds_size1606=== CONT TestParseSingleRange/suffix1607=== CONT TestParseSingleRange/end_clamped_to_size1608=== CONT TestParseSingleRange/malformed_both_empty1609=== CONT TestParseSingleRange/closed1610=== CONT TestParseSingleRange/malformed_end_before_start1611=== CONT TestParseSingleRange/unknown_unit1612=== CONT TestParseSingleRange/multi-range_ignored1613=== CONT TestParseSingleRange/malformed_no_dash1614--- PASS: TestParseSingleRange (0.00s)1615 --- PASS: TestParseSingleRange/none (0.00s)1616 --- PASS: TestParseSingleRange/open-ended (0.00s)1617 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1618 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1619 --- PASS: TestParseSingleRange/single_byte (0.00s)1620 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1621 --- PASS: TestParseSingleRange/suffix (0.00s)1622 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1623 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1624 --- PASS: TestParseSingleRange/closed (0.00s)1625 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1626 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1627 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1628 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1629=== CONT TestServerTLSConfig/no_client_CA1630=== CONT TestServerTLSConfig/not_a_PEM_file16312026/10/05 11:42:55 INFO Received push request method=POST path=/api/pushes1632=== CONT TestServerTLSConfig/missing_CA_file1633--- PASS: TestServerTLSConfig (0.00s)1634 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1635 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1636 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1637=== CONT TestGCEndsOnShutdown/before_the_run1638=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1639=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete16402026/10/05 11:42:55 INFO Upload complete. (114ms)1641=== NAME TestClientSharedPathCommittedMidPush1642 client_integration_test.go:680: Retrieved narinfo from S3:1643 StorePath: /build/TestClientSharedPathCommittedMidPush2335114692/001/store/gxgwhi7ly0d4km3i95ks00xmhfsnl90y-shared-dep1644 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1645 Compression: zstd1646 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821647 NarSize: 1361648 References: 1649 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1650--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.85s)1651=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1652=== NAME TestClientSharedPathCommittedMidPush1653 client_integration_test.go:680: Retrieved narinfo from S3:1654 StorePath: /build/TestClientSharedPathCommittedMidPush2335114692/001/store/gv6ryn3mbdfkwnvlrydyr95cypf55jw9-top1655 URL: nar/1r6ygswzwr8xs4h2n03a779wirh8wnc5dz9xkki17kd2v89g8lrk.nar.zst1656 Compression: zstd1657 NarHash: sha256:1r6ygswzwr8xs4h2n03a779wirh8wnc5dz9xkki17kd2v89g8lrk1658 NarSize: 22416592026/10/05 11:42:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)1660 References: /build/TestClientSharedPathCommittedMidPush2335114692/001/store/gxgwhi7ly0d4km3i95ks00xmhfsnl90y-shared-dep1661 CA: text:sha256:0z5kcicnaag5sky8bx66qrsgcj6zi0ffx8x5cp3dav2nwqa2xbb516622026/10/05 11:42:55 INFO Uploading 6cpg3iwvcaqjqn40an2hg2bl1f9xk153-test-script (136B)1663=== NAME TestClientCADerivations1664 client_ca_test.go:139: Found 1 dependencies (including self)16652026/10/05 11:42:55 INFO Received push request method=POST path=/api/pushes16662026/10/05 11:42:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16672026/10/05 11:42:55 INFO Uploading k8m6fibsv0j6cwm6sajhlv2dvgmlqdj0-unpinned-file.txt (128B)1668--- PASS: TestClientSharedPathCommittedMidPush (0.70s)1669=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check16702026/10/05 11:42:55 WARN Failed to register uploaded object key=6cpg3iwvcaqjqn40an2hg2bl1f9xk153.ls error="server returned 404: 404 page not found\n"16712026/10/05 11:42:55 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16722026/10/05 11:42:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16732026/10/05 11:42:55 WARN Failed to register uploaded object key=log/6zp8yrlpbh1qah808bv2llr84b13i372-test-script.drv error="server returned 404: 404 page not found\n"16742026/10/05 11:42:55 INFO Signed narinfos id=1 count=116752026/10/05 11:42:55 INFO Uploading 1 narinfos16762026/10/05 11:42:55 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16772026/10/05 11:42:55 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16782026/10/05 11:42:55 WARN Failed to register uploaded object key=k8m6fibsv0j6cwm6sajhlv2dvgmlqdj0.ls error="server returned 404: 404 page not found\n"16792026/10/05 11:42:55 INFO Signed narinfos id=2 count=116802026/10/05 11:42:55 INFO Uploading 1 narinfos16812026/10/05 11:42:55 INFO Received complete push request method=POST path=/api/pushes/1/complete16822026/10/05 11:42:55 WARN Failed to register uploaded object key=6cpg3iwvcaqjqn40an2hg2bl1f9xk153.narinfo error="server returned 404: 404 page not found\n"16832026/10/05 11:42:55 INFO Received complete push request method=POST path=/api/pushes/2/complete16842026/10/05 11:42:55 WARN Failed to register uploaded object key=k8m6fibsv0j6cwm6sajhlv2dvgmlqdj0.narinfo error="server returned 404: 404 page not found\n"16852026/10/05 11:42:55 INFO Upload complete. (110ms)16862026/10/05 11:42:55 INFO Upload complete. (100ms)1687--- PASS: TestService_ReadAuthMiddleware (0.47s)1688=== CONT TestResolveDBConnectionString/flag_wins1689=== NAME TestClientWithDependencies1690 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies64017097/001/store) requires matching store prefix1691=== CONT TestResolveDBConnectionString/nothing_configured1692=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1693=== CONT TestResolveDBConnectionString/missing_file_is_an_error1694=== CONT TestResolveDBConnectionString/file_when_flag_empty1695=== CONT TestClientErrorHandling/InvalidStorePath1696--- PASS: TestResolveDBConnectionString (0.00s)1697 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1698 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1699 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1700 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1701 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1702--- PASS: TestClientWithDependencies (0.69s)1703=== CONT TestClientErrorHandling/ServerNotAvailable17042026/10/05 11:42:55 INFO Received push request method=POST path=/api/pushes17052026/10/05 11:42:55 INFO Aborted multipart uploads count=0 kept=017062026/10/05 11:42:55 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17072026/10/05 11:42:55 INFO Uploading k9zfvi8pyl7qn33d09i4yb06qhf0jm7a-test-file-0.txt (160B)17082026/10/05 11:42:55 INFO Uploading frfvci4dlnklgas6b31y7wn12i5mi8y2-test-file-1.txt (160B)17092026/10/05 11:42:55 INFO Uploading vbcy2z54dawv693ncgcb0in6rs8bkpgn-test-file-2.txt (160B)17102026/10/05 11:42:55 WARN Force mode enabled - objects will be deleted immediately without grace period17112026/10/05 11:42:55 INFO Starting cleanup of old closures method=DELETE path=/api/closures17122026/10/05 11:42:55 INFO Garbage collection started17132026/10/05 11:42:55 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17142026/10/05 11:42:55 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17152026/10/05 11:42:55 WARN Failed to register uploaded object key=frfvci4dlnklgas6b31y7wn12i5mi8y2.ls error="server returned 404: 404 page not found\n"17162026/10/05 11:42:55 WARN Failed to register uploaded object key=k9zfvi8pyl7qn33d09i4yb06qhf0jm7a.ls error="server returned 404: 404 page not found\n"17172026/10/05 11:42:55 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17182026/10/05 11:42:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17192026/10/05 11:42:55 WARN Failed to register uploaded object key=vbcy2z54dawv693ncgcb0in6rs8bkpgn.ls error="server returned 404: 404 page not found\n"17202026/10/05 11:42:55 INFO Signed narinfos id=1 count=317212026/10/05 11:42:55 INFO Uploading 3 narinfos17222026/10/05 11:42:55 WARN Failed to register uploaded object key=frfvci4dlnklgas6b31y7wn12i5mi8y2.narinfo error="server returned 404: 404 page not found\n"17232026/10/05 11:42:55 WARN Failed to register uploaded object key=k9zfvi8pyl7qn33d09i4yb06qhf0jm7a.narinfo error="server returned 404: 404 page not found\n"17242026/10/05 11:42:55 INFO Received complete push request method=POST path=/api/pushes/1/complete17252026/10/05 11:42:55 WARN Failed to register uploaded object key=vbcy2z54dawv693ncgcb0in6rs8bkpgn.narinfo error="server returned 404: 404 page not found\n"1726=== RUN TestService_RequireScope_OIDC/builder_may_write1727=== PAUSE TestService_RequireScope_OIDC/builder_may_write1728=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1729=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1730=== RUN TestService_RequireScope_OIDC/ops_may_admin1731=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1732=== RUN TestService_RequireScope_OIDC/ops_may_not_write1733=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1734=== RUN TestService_RequireScope_OIDC/reader_may_not_write1735=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1736=== RUN TestService_RequireScope_OIDC/static_token_may_admin1737=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1738=== RUN TestService_RequireScope_OIDC/static_token_may_write1739=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1740=== RUN TestService_RequireScope_OIDC/reader_may_read1741=== PAUSE TestService_RequireScope_OIDC/reader_may_read1742=== RUN TestService_RequireScope_OIDC/writer_implies_read1743=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1744=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1745=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1746=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1747=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1748=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1749=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1750=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1751=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1752=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1753=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1754=== CONT TestClientErrorHandling/InvalidAuthToken17552026/10/05 11:42:55 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=017562026/10/05 11:42:55 INFO Aborted multipart uploads count=0 kept=01757=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1758=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1759=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1760=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1761=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1762=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1763=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1764=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1765=== CONT TestCacheConfigHandler/full_config,_no_issuer1766=== CONT TestCacheConfigHandler/no_signing_keys1767=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1768=== CONT TestCacheConfigHandler/no_cache_url_configured1769--- PASS: TestCacheConfigHandler (0.00s)1770 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1771 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1772 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1773 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1774=== CONT TestPush_RejectsBadRequests/no_roots17752026/10/05 11:42:55 INFO Received push request method=POST path=/api/pushes1776=== CONT TestPush_RejectsBadRequests/bad_root17772026/10/05 11:42:55 INFO Received push request method=POST path=/api/pushes1778=== CONT TestPush_RejectsBadRequests/root_not_in_objects17792026/10/05 11:42:55 INFO Received push request method=POST path=/api/pushes1780=== CONT TestPush_RejectsBadRequests/no_objects17812026/10/05 11:42:55 INFO Received push request method=POST path=/api/pushes1782=== CONT TestService_RequireScope_OIDC/builder_may_write1783--- PASS: TestPush_RejectsBadRequests (0.46s)1784 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1785 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1786 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1787 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)17882026/10/05 11:42:55 INFO Vacuumed table table=pending_closures1789=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc17902026/10/05 11:42:55 WARN Force mode enabled - objects will be deleted immediately without grace period17912026/10/05 11:42:55 INFO Upload complete. (78ms)1792=== NAME TestClientMultipleUploads1793 client_integration_test.go:369: Uploaded 3 paths in 144.105662ms1794=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1795=== CONT TestService_RequireScope_OIDC/writer_implies_read1796=== CONT TestService_RequireScope_OIDC/reader_may_read1797=== CONT TestService_RequireScope_OIDC/static_token_may_write1798=== CONT TestService_RequireScope_OIDC/static_token_may_admin1799=== CONT TestService_RequireScope_OIDC/reader_may_not_write1800=== CONT TestService_RequireScope_OIDC/ops_may_not_write1801=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1802=== CONT TestService_RequireScope_OIDC/ops_may_admin1803=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1804=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1805=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18062026/10/05 11:42:55 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]1807=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token1808--- PASS: TestService_RequireScope_OIDC (0.50s)1809 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1810 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1811 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1812 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1813 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1814 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1815 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1816 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1817 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1818 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1819 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1820 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1821 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1822 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)18232026/10/05 11:42:55 INFO Vacuumed table table=pending_objects1824=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected18252026/10/05 11:42:55 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]1826=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected18272026/10/05 11:42:55 INFO Vacuumed table table=multipart_uploads18282026/10/05 11:42:55 WARN Authentication failed token_preview=eyJhbGciOi...e_vLzgWZaw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]1829=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1830--- PASS: TestService_AuthMiddleware_OIDC (0.34s)1831 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)1832 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)1833 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)1834 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)1835--- PASS: TestClientMultipleUploads (0.71s)18362026/10/05 11:42:55 INFO Vacuumed table table=closures18372026/10/05 11:42:55 INFO Vacuumed table table=objects18382026/10/05 11:42:55 INFO Received complete push request method=POST path=/api/pushes/2/complete1839--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.31s)18402026/10/05 11:42:55 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=018412026/10/05 11:42:55 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/present1842--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.64s)18432026/10/05 11:42:55 INFO Received push request method=POST path=/api/pushes18442026/10/05 11:42:55 INFO Vacuumed table table=pending_closures18452026/10/05 11:42:55 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18462026/10/05 11:42:55 INFO Uploading 28ij30fkrgvgqah7f6vnssq7yi2b779b-ca-test (144B)18472026/10/05 11:42:55 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18482026/10/05 11:42:55 WARN Failed to register uploaded object key=28ij30fkrgvgqah7f6vnssq7yi2b779b.ls error="server returned 404: 404 page not found\n"18492026/10/05 11:42:55 WARN Failed to register uploaded object key=log/mgqqksdqailb3kkxnan0sfnq8s2vc2x4-ca-test.drv error="server returned 404: 404 page not found\n"18502026/10/05 11:42:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18512026/10/05 11:42:55 INFO Signed narinfos id=1 count=118522026/10/05 11:42:55 INFO Uploading 1 narinfos18532026/10/05 11:42:55 INFO Vacuumed table table=pending_objects18542026/10/05 11:42:55 INFO Vacuumed table table=multipart_uploads18552026/10/05 11:42:55 INFO Received complete push request method=POST path=/api/pushes/1/complete18562026/10/05 11:42:55 WARN Failed to register uploaded object key=28ij30fkrgvgqah7f6vnssq7yi2b779b.narinfo error="server returned 404: 404 page not found\n"18572026/10/05 11:42:55 INFO Vacuumed table table=closures18582026/10/05 11:42:55 INFO Vacuumed table table=objects18592026/10/05 11:42:55 INFO Received uploads request method=POST path=/api/pending_closures18602026/10/05 11:42:55 INFO Upload complete. (102ms)1861=== NAME TestClientCADerivations1862 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1972017277/001/store/28ij30fkrgvgqah7f6vnssq7yi2b779b-ca-test1863 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1864 Compression: zstd1865 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1866 NarSize: 1441867 References: 1868 Deriver: /build/TestClientCADerivations1972017277/001/store/mgqqksdqailb3kkxnan0sfnq8s2vc2x4-ca-test.drv1869 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1870 client_ca_test.go:185: Checking for realisation files in S3...1871 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1872 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache18732026/10/05 11:42:56 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=218.314229ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present18742026/10/05 11:42:56 INFO Aborted multipart uploads count=0 kept=018752026/10/05 11:42:56 WARN Force mode enabled - objects will be deleted immediately without grace period18762026-10-05 11:42:56.076 UTC [1945] ERROR: canceling statement due to user request18772026-10-05 11:42:56.076 UTC [1945] CONTEXT: SQL statement "UPDATE object_stats1878 SET object_count = object_count + d_count,1879 total_bytes = total_bytes + d_bytes1880 WHERE id"1881 PL/pgSQL function object_stats_apply() line 17 at SQL statement18822026-10-05 11:42:56.076 UTC [1945] STATEMENT: -- name: MarkStaleObjects :execrows1883 WITH RECURSIVE ct AS (1884 SELECT timezone('UTC', now()) AS now1885 ),1886 closure_reach AS (1887 -- Start with all closure keys1888 SELECT o.key, o.refs1889 FROM objects o1890 INNER JOIN closures c ON o.key = c.key1891 UNION1892 -- Recursively add all referenced objects1893 SELECT o.key, o.refs1894 FROM objects o1895 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)1896 ),1897 reachable_objects AS (1898 SELECT DISTINCT key FROM closure_reach1899 ),1900 stale_objects AS (1901 SELECT o.key1902 FROM objects AS o, ct1903 WHERE1904 NOT EXISTS (1905 SELECT 11906 FROM reachable_objects ro1907 WHERE ro.key = o.key1908 )1909 AND NOT EXISTS (1910 SELECT 11911 FROM pending_objects AS po1912 WHERE po.key = o.key1913 )1914 AND o.deleted_at IS NULL -- Only mark fresh objects1915 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure1916 FOR UPDATE1917 )1918 UPDATE objects1919 SET1920 deleted_at = ct.now,1921 first_deleted_at = COALESCE(first_deleted_at, ct.now)1922 FROM stale_objects, ct1923 WHERE objects.key = stale_objects.key1924 19252026/10/05 11:42:56 INFO Aborted multipart uploads count=0 kept=019262026/10/05 11:42:56 WARN Force mode enabled - objects will be deleted immediately without grace period19272026/10/05 11:42:56 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:41645/bucket87/?delete=\": context canceled"1928--- PASS: TestGCEndsOnShutdown (0.00s)1929 --- PASS: TestGCEndsOnShutdown/before_the_run (0.22s)1930 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.26s)1931 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.25s)19322026/10/05 11:42:56 INFO Received uploads request method=POST path=/api/pending_closures19332026/10/05 11:42:56 INFO Aborted multipart uploads count=0 kept=019342026/10/05 11:42:56 WARN Force mode enabled - objects will be deleted immediately without grace period1935=== NAME TestClientCADerivations1936 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1937 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1938 error: binary cache 's3://bucket75?endpoint=http://localhost:41645®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1972017277/001/store'1939 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11940--- PASS: TestClientCADerivations (0.87s)19412026/10/05 11:42:56 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=019422026/10/05 11:42:56 INFO Vacuumed table table=pending_closures19432026/10/05 11:42:56 INFO Vacuumed table table=pending_objects19442026/10/05 11:42:56 INFO Vacuumed table table=multipart_uploads19452026/10/05 11:42:56 INFO Vacuumed table table=closures19462026/10/05 11:42:56 INFO Vacuumed table table=objects19472026/10/05 11:42:56 INFO Received uploads request method=POST path=/api/pending_closures19482026/10/05 11:42:56 INFO Aborted multipart uploads count=0 kept=019492026/10/05 11:42:56 WARN Force mode enabled - objects will be deleted immediately without grace period19502026/10/05 11:42:56 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=019512026/10/05 11:42:56 INFO Vacuumed table table=pending_closures19522026/10/05 11:42:56 INFO Vacuumed table table=pending_objects19532026/10/05 11:42:56 INFO Vacuumed table table=multipart_uploads19542026/10/05 11:42:56 INFO Vacuumed table table=closures19552026/10/05 11:42:56 INFO Vacuumed table table=objects1956--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1957 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.29s)1958 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.30s)1959=== NAME TestOrphanedObjectsGCStressTest1960 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1961 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion19622026/10/05 11:42:56 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19632026/10/05 11:42:56 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"19642026/10/05 11:42:56 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=361.360314ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19652026/10/05 11:42:56 INFO lead: released remote=192.0.2.1:12341966--- PASS: TestLeadEndsOnShutdown (1.71s)1967--- PASS: TestUploadHandlersRejectOversizedBody (0.22s)1968 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.07s)1969 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.07s)1970 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.72s)1971=== NAME TestOrphanedObjectsGCStressTest1972 orphaned_objects_gc_test.go:509: Stress test completed successfully:1973 orphaned_objects_gc_test.go:510: - Active objects preserved: 201974 orphaned_objects_gc_test.go:511: - Objects deleted: 2101975 orphaned_objects_gc_test.go:512: - Total GC'd: 2101976--- PASS: TestOrphanedObjectsGCStressTest (3.28s)19772026/10/05 11:42:56 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=803.734648ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19782026/10/05 11:42:56 INFO lead: released remote=192.0.2.1:123419792026/10/05 11:42:56 INFO lead: acquired remote=192.0.2.1:12341980--- PASS: TestPendingClosureWriteTimeout (0.00s)1981 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)1982 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)1983 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)1984 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.05s)1985--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.71s)19862026/10/05 11:42:57 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.619816283s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19872026/10/05 11:42:57 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=01988=== NAME TestClientIntegration1989 client_integration_test.go:323: Objects in database after GC:1990 client_integration_test.go:323: Successfully deleted all objects with GC --force1991--- PASS: TestClientIntegration (2.94s)19922026/10/05 11:42:57 WARN Rate limiter enabled after throttle name=s3-test rate=519932026/10/05 11:42:57 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1994=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1995 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101996 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001997--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.96s)19982026/10/05 11:42:57 INFO lead: released remote=192.0.2.1:12341999--- PASS: TestLeadElectsOneAndHandsOver (2.85s)20002026/10/05 11:42:57 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020012026/10/05 11:42:57 INFO Received create pin request method=POST path=/api/pins/myapp20022026/10/05 11:42:57 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC394553515/001/store/jhsbwg776i4x8ingmzlf6r52bbdy437n-pinned-file.txt narinfo_key=jhsbwg776i4x8ingmzlf6r52bbdy437n.narinfo20032026/10/05 11:42:57 INFO Starting cleanup of old closures method=DELETE path=/api/closures20042026/10/05 11:42:57 INFO Garbage collection started20052026/10/05 11:42:57 INFO Aborted multipart uploads count=0 kept=020062026/10/05 11:42:57 WARN Force mode enabled - objects will be deleted immediately without grace period20072026/10/05 11:42:57 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=020082026/10/05 11:42:57 INFO Vacuumed table table=pending_closures20092026/10/05 11:42:57 INFO Vacuumed table table=pending_objects20102026/10/05 11:42:57 INFO Vacuumed table table=multipart_uploads20112026/10/05 11:42:57 INFO Vacuumed table table=closures20122026/10/05 11:42:57 INFO Vacuumed table table=objects20132026/10/05 11:42:59 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-config20142026/10/05 11:42:59 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.328323ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20152026/10/05 11:42:59 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=379.670934ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20162026/10/05 11:42:59 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=811.660294ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2017=== NAME TestPinProtectsFromGC2018 client_integration_test.go:840: Pin successfully protected closure from garbage collection2019--- PASS: TestPinProtectsFromGC (4.82s)2020--- PASS: TestConnectWaitsForAPeerMigration (5.16s)20212026/10/05 11:43:00 INFO Aborted multipart uploads count=1 kept=020222026/10/05 11:43:00 INFO Received cleanup request method=DELETE path=/api/pending_closures20232026/10/05 11:43:00 INFO Aborted multipart uploads count=1 kept=02024--- PASS: TestPendingCleanupUsesOneCutoff (7.09s)20252026/10/05 11:43:00 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.448044241s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20262026/10/05 11:43:02 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"20272026/10/05 11:43:02 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-config20282026/10/05 11:43:02 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=215.299174ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20292026/10/05 11:43:02 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=435.810292ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20302026/10/05 11:43:02 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=860.717869ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20312026/10/05 11:43:03 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.557668451s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20322026/10/05 11:43:05 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_closures20332026/10/05 11:43:05 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=194.285158ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20342026/10/05 11:43:05 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=414.838387ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20352026/10/05 11:43:05 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=875.831983ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20362026/10/05 11:43:06 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.45950799s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2037--- PASS: TestClientErrorHandling (0.00s)2038 --- PASS: TestClientErrorHandling/InvalidStorePath (0.31s)2039 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.36s)2040 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.43s)2041PASS2042{"timestamp":"2026-10-05T11:43:08.311732282Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:41662","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(391)"}20432026-10-05 11:43:08.658 UTC [129] LOG: received smart shutdown request20442026-10-05 11:43:08.665 UTC [129] LOG: background worker "logical replication launcher" (PID 139) exited with exit code 120452026-10-05 11:43:08.677 UTC [134] LOG: shutting down20462026-10-05 11:43:08.677 UTC [134] LOG: checkpoint starting: shutdown immediate20472026-10-05 11:43:09.940 UTC [134] LOG: checkpoint complete: wrote 11153 buffers (68.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 26 recycled; write=0.276 s, sync=0.942 s, total=1.263 s; sync files=31000, longest=0.057 s, average=0.001 s; distance=428436 kB, estimate=428436 kB; lsn=0/1B9CAE40, redo lsn=0/1B9CAE4020482026-10-05 11:43:09.997 UTC [129] LOG: database system is shut down2049Running OIDC tests...2050=== RUN TestAudienceForIssuer2051=== PAUSE TestAudienceForIssuer2052=== RUN TestGlobMatch2053=== PAUSE TestGlobMatch2054=== RUN TestValidateToken_ValidToken2055=== PAUSE TestValidateToken_ValidToken2056=== RUN TestValidateToken_WrongAudience2057=== PAUSE TestValidateToken_WrongAudience2058=== RUN TestValidateToken_Expired2059=== PAUSE TestValidateToken_Expired2060=== RUN TestValidateToken_BoundClaimsMismatch2061=== PAUSE TestValidateToken_BoundClaimsMismatch2062=== RUN TestValidateToken_BoundSubjectMismatch2063=== PAUSE TestValidateToken_BoundSubjectMismatch2064=== RUN TestValidateToken_MultipleProviders2065=== PAUSE TestValidateToken_MultipleProviders2066=== RUN TestValidateToken_NoMatchingProvider2067=== PAUSE TestValidateToken_NoMatchingProvider2068=== RUN TestValidateToken_KubernetesServiceAccount2069=== PAUSE TestValidateToken_KubernetesServiceAccount2070=== RUN TestNewValidator_KubernetesRequiresCA2071=== PAUSE TestNewValidator_KubernetesRequiresCA2072=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2073=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2074=== RUN TestPins_ReservedForMatchingRule2075=== PAUSE TestPins_ReservedForMatchingRule2076=== RUN TestPins_TopLevelShorthand2077=== PAUSE TestPins_TopLevelShorthand2078=== RUN TestPins_ConfigValidation2079=== PAUSE TestPins_ConfigValidation2080=== RUN TestScopes_LegacyProviderDefaultsToWrite2081=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2082=== RUN TestScopes_Rules2083=== PAUSE TestScopes_Rules2084=== RUN TestScopes_ConfigValidation2085=== PAUSE TestScopes_ConfigValidation2086=== CONT TestAudienceForIssuer2087=== CONT TestValidateToken_BoundClaimsMismatch2088--- PASS: TestAudienceForIssuer (0.00s)2089=== CONT TestValidateToken_ValidToken2090=== CONT TestValidateToken_KubernetesServiceAccount2091=== CONT TestValidateToken_WrongAudience2092=== CONT TestValidateToken_Expired2093=== CONT TestPins_ConfigValidation2094=== CONT TestScopes_Rules2095=== CONT TestScopes_ConfigValidation2096=== CONT TestPins_ReservedForMatchingRule2097=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2098--- PASS: TestScopes_ConfigValidation (0.00s)2099=== CONT TestNewValidator_KubernetesRequiresCA2100--- PASS: TestPins_ConfigValidation (0.00s)2101=== CONT TestScopes_LegacyProviderDefaultsToWrite2102=== CONT TestGlobMatch2103=== RUN TestGlobMatch/foo_foo2104=== CONT TestValidateToken_NoMatchingProvider2105=== PAUSE TestGlobMatch/foo_foo2106=== RUN TestGlobMatch/foo_bar2107=== PAUSE TestGlobMatch/foo_bar2108=== RUN TestGlobMatch/*_2109=== PAUSE TestGlobMatch/*_2110=== CONT TestValidateToken_BoundSubjectMismatch2111=== CONT TestPins_TopLevelShorthand2112=== CONT TestValidateToken_MultipleProviders2113=== RUN TestGlobMatch/*_anything2114=== PAUSE TestGlobMatch/*_anything2115=== RUN TestGlobMatch/foo*_foo2116=== PAUSE TestGlobMatch/foo*_foo2117=== RUN TestGlobMatch/foo*_foobar2118=== PAUSE TestGlobMatch/foo*_foobar2119=== RUN TestGlobMatch/foo*_bar2120=== PAUSE TestGlobMatch/foo*_bar2121=== RUN TestGlobMatch/*bar_bar2122=== PAUSE TestGlobMatch/*bar_bar2123=== RUN TestGlobMatch/*bar_foobar2124=== PAUSE TestGlobMatch/*bar_foobar2125=== RUN TestGlobMatch/*bar_foo2126=== PAUSE TestGlobMatch/*bar_foo2127=== RUN TestGlobMatch/foo*bar_foobar2128=== PAUSE TestGlobMatch/foo*bar_foobar2129=== RUN TestGlobMatch/foo*bar_foo123bar2130=== PAUSE TestGlobMatch/foo*bar_foo123bar2131=== RUN TestGlobMatch/foo*bar_foobarbaz2132=== PAUSE TestGlobMatch/foo*bar_foobarbaz2133=== RUN TestGlobMatch/*/*_foo/bar2134=== PAUSE TestGlobMatch/*/*_foo/bar2135=== RUN TestGlobMatch/*/*_foo2136=== PAUSE TestGlobMatch/*/*_foo2137=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2138=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2139=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02140=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02141=== RUN TestGlobMatch/refs/*/main_refs/heads/main2142=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2143=== RUN TestGlobMatch/fo?_foo2144=== PAUSE TestGlobMatch/fo?_foo2145=== RUN TestGlobMatch/fo?_fo2146=== PAUSE TestGlobMatch/fo?_fo2147=== RUN TestGlobMatch/fo?_fooo2148=== PAUSE TestGlobMatch/fo?_fooo2149=== RUN TestGlobMatch/?oo_foo2150=== PAUSE TestGlobMatch/?oo_foo2151=== RUN TestGlobMatch/?oo_boo2152=== PAUSE TestGlobMatch/?oo_boo2153=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2154=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2155=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2156=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2157=== CONT TestGlobMatch/foo_foo2158=== CONT TestGlobMatch/foo*bar_foobarbaz2159=== CONT TestGlobMatch/foo*bar_foo123bar2160=== CONT TestGlobMatch/foo*bar_foobar2161=== CONT TestGlobMatch/*bar_foo2162=== CONT TestGlobMatch/*bar_foobar2163=== CONT TestGlobMatch/*bar_bar2164=== CONT TestGlobMatch/foo*_bar2165=== CONT TestGlobMatch/foo*_foobar2166=== CONT TestGlobMatch/foo*_foo2167=== CONT TestGlobMatch/*_anything2168=== CONT TestGlobMatch/*_2169=== CONT TestGlobMatch/foo_bar2170=== CONT TestGlobMatch/fo?_fo2171=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2172=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2173=== CONT TestGlobMatch/?oo_boo2174=== CONT TestGlobMatch/?oo_foo2175=== CONT TestGlobMatch/fo?_fooo2176=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02177=== CONT TestGlobMatch/fo?_foo2178=== CONT TestGlobMatch/refs/*/main_refs/heads/main2179=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2180=== CONT TestGlobMatch/*/*_foo/bar2181=== CONT TestGlobMatch/*/*_foo2182--- PASS: TestGlobMatch (0.00s)2183 --- PASS: TestGlobMatch/foo_foo (0.00s)2184 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2185 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2186 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2187 --- PASS: TestGlobMatch/*bar_foo (0.00s)2188 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2189 --- PASS: TestGlobMatch/*bar_bar (0.00s)2190 --- PASS: TestGlobMatch/foo*_bar (0.00s)2191 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2192 --- PASS: TestGlobMatch/foo*_foo (0.00s)2193 --- PASS: TestGlobMatch/*_anything (0.00s)2194 --- PASS: TestGlobMatch/*_ (0.00s)2195 --- PASS: TestGlobMatch/foo_bar (0.00s)2196 --- PASS: TestGlobMatch/fo?_fo (0.00s)2197 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2198 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2199 --- PASS: TestGlobMatch/?oo_boo (0.00s)2200 --- PASS: TestGlobMatch/?oo_foo (0.00s)2201 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2202 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2203 --- PASS: TestGlobMatch/fo?_foo (0.00s)2204 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2205 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2206 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2207 --- PASS: TestGlobMatch/*/*_foo (0.00s)22082026/10/05 11:43:12 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:405332209--- PASS: TestValidateToken_KubernetesServiceAccount (0.03s)22102026/10/05 11:43:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36921/oidc22112026/10/05 11:43:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42173/oidc2212--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.03s)2213--- PASS: TestPins_ReservedForMatchingRule (0.03s)22142026/10/05 11:43:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35857/oidc2215--- PASS: TestValidateToken_BoundClaimsMismatch (0.05s)22162026/10/05 11:43:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40771/oidc2217--- PASS: TestPins_TopLevelShorthand (0.04s)22182026/10/05 11:43:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36205/oidc2219--- PASS: TestValidateToken_ValidToken (0.06s)22202026/10/05 11:43:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34611/oidc2221--- PASS: TestScopes_Rules (0.06s)22222026/10/05 11:43:12 http: TLS handshake error from 127.0.0.1:47324: remote error: tls: bad certificate2223--- PASS: TestNewValidator_KubernetesRequiresCA (0.07s)22242026/10/05 11:43:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43749/oidc2225--- PASS: TestValidateToken_Expired (0.08s)22262026/10/05 11:43:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40925/oidc2227--- PASS: TestValidateToken_BoundSubjectMismatch (0.08s)22282026/10/05 11:43:12 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232229--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)22302026/10/05 11:43:12 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:35299/oidc2231--- PASS: TestValidateToken_NoMatchingProvider (0.12s)22322026/10/05 11:43:12 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34613/oidc2233--- PASS: TestValidateToken_WrongAudience (0.18s)22342026/10/05 11:43:12 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:41579/oidc22352026/10/05 11:43:12 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:44031/oidc2236--- PASS: TestValidateToken_MultipleProviders (0.21s)2237PASS2238Running hook tests...2239=== RUN TestSendPathsEmpty2240=== PAUSE TestSendPathsEmpty2241=== RUN TestQueueEnqueueAndFetch2242=== PAUSE TestQueueEnqueueAndFetch2243=== RUN TestQueueDeduplication2244=== PAUSE TestQueueDeduplication2245=== RUN TestQueueRemove2246=== PAUSE TestQueueRemove2247=== RUN TestQueueFetchBatchLimit2248=== PAUSE TestQueueFetchBatchLimit2249=== RUN TestQueueRetryMovesToBack2250=== PAUSE TestQueueRetryMovesToBack2251=== RUN TestQueueFetchRemoveLifecycle2252=== PAUSE TestQueueFetchRemoveLifecycle2253=== RUN TestQueueConcurrentWriters2254=== PAUSE TestQueueConcurrentWriters2255=== RUN TestQueueRemoveLargeClosure2256=== PAUSE TestQueueRemoveLargeClosure2257=== RUN TestServerClientIntegration2258=== PAUSE TestServerClientIntegration2259=== RUN TestServerQueueError2260=== PAUSE TestServerQueueError2261=== RUN TestGetListenerSocketActivation2262 server_test.go:210: === RUN TestGetListenerSocketActivation2263 --- PASS: TestGetListenerSocketActivation (0.00s)2264 PASS2265 2266--- PASS: TestGetListenerSocketActivation (0.01s)2267=== RUN TestDrainIsolatesPoisonPath2268=== PAUSE TestDrainIsolatesPoisonPath2269=== RUN TestRunNotBlockedByPoisonHead2270=== PAUSE TestRunNotBlockedByPoisonHead2271=== RUN TestDrainGivesUpWhenServerDown2272=== PAUSE TestDrainGivesUpWhenServerDown2273=== RUN TestFailedPathPrunedByLaterClosure2274=== PAUSE TestFailedPathPrunedByLaterClosure2275=== RUN TestWorkerUploadsAndRemoves2276=== PAUSE TestWorkerUploadsAndRemoves2277=== RUN TestWorkerSkipsGCdPaths2278=== PAUSE TestWorkerSkipsGCdPaths2279=== RUN TestWorkerPrunesClosureDeps2280=== PAUSE TestWorkerPrunesClosureDeps2281=== RUN TestDrainTimeout2282=== PAUSE TestDrainTimeout2283=== CONT TestSendPathsEmpty2284--- PASS: TestSendPathsEmpty (0.00s)2285=== CONT TestFailedPathPrunedByLaterClosure2286=== CONT TestWorkerUploadsAndRemoves2287=== CONT TestWorkerSkipsGCdPaths2288=== CONT TestServerClientIntegration2289=== CONT TestQueueRemoveLargeClosure2290=== CONT TestQueueConcurrentWriters2291=== CONT TestQueueFetchRemoveLifecycle2292=== CONT TestQueueRetryMovesToBack2293=== CONT TestQueueFetchBatchLimit2294=== CONT TestQueueRemove2295=== CONT TestQueueDeduplication2296=== CONT TestQueueEnqueueAndFetch2297=== CONT TestServerQueueError2298=== CONT TestWorkerPrunesClosureDeps2299=== CONT TestDrainTimeout2300=== CONT TestRunNotBlockedByPoisonHead2301=== CONT TestDrainGivesUpWhenServerDown2302=== CONT TestDrainIsolatesPoisonPath23032026/10/05 11:43:12 ERROR Failed to queue paths error="permission denied" count=12304--- PASS: TestServerQueueError (0.00s)2305--- PASS: TestServerClientIntegration (0.00s)23062026/10/05 11:43:12 INFO Uploading batch count=123072026/10/05 11:43:12 ERROR Upload failed error="upload failed" count=123082026/10/05 11:43:12 INFO Upload queue status pending=223092026/10/05 11:43:12 INFO Upload queue status pending=323102026/10/05 11:43:12 INFO Uploading batch count=123112026/10/05 11:43:12 ERROR Upload failed error="upload failed" count=123122026/10/05 11:43:12 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths4258433278/002/nonexistent23132026/10/05 11:43:12 INFO Uploading batch count=223142026/10/05 11:43:12 INFO Uploading batch count=423152026/10/05 11:43:12 INFO Uploading batch count=223162026/10/05 11:43:12 INFO Upload queue status pending=223172026/10/05 11:43:12 INFO Uploading batch count=123182026/10/05 11:43:12 INFO Upload queue status pending=223192026/10/05 11:43:12 ERROR Upload failed error="upload failed" count=223202026/10/05 11:43:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3723175077/002/a23212026/10/05 11:43:12 ERROR Upload failed error="upload failed" count=423222026/10/05 11:43:12 INFO Uploading batch count=223232026/10/05 11:43:12 INFO Uploading batch count=12324--- PASS: TestQueueEnqueueAndFetch (0.02s)2325--- PASS: TestQueueFetchBatchLimit (0.02s)23262026/10/05 11:43:12 INFO Uploading batch count=123272026/10/05 11:43:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3866510207/002/bbb23282026/10/05 11:43:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3723175077/002/b23292026/10/05 11:43:12 INFO Uploading batch count=12330--- PASS: TestQueueRemove (0.02s)2331--- PASS: TestQueueFetchRemoveLifecycle (0.02s)2332--- PASS: TestQueueRetryMovesToBack (0.02s)2333--- PASS: TestQueueDeduplication (0.02s)23342026/10/05 11:43:12 INFO Uploading batch count=223352026/10/05 11:43:12 ERROR Upload failed error="upload failed" count=223362026/10/05 11:43:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3723175077/002/c23372026/10/05 11:43:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3723175077/002/d2338--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)23392026/10/05 11:43:12 INFO Uploading batch count=123402026/10/05 11:43:12 INFO Uploading batch count=223412026/10/05 11:43:12 ERROR Upload failed error="upload failed" count=223422026/10/05 11:43:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3723175077/002/e23432026/10/05 11:43:12 ERROR Upload failed error="upload failed" count=123442026/10/05 11:43:12 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3723175077/002/f23452026/10/05 11:43:12 INFO Uploading batch count=123462026/10/05 11:43:12 ERROR Upload failed error="upload failed" count=123472026/10/05 11:43:12 ERROR Drain finished with paths left in queue remaining=1023482026/10/05 11:43:12 INFO Uploading batch count=123492026/10/05 11:43:12 ERROR Upload failed error="upload failed" count=123502026/10/05 11:43:12 ERROR Drain finished with paths left in queue remaining=12351--- PASS: TestDrainGivesUpWhenServerDown (0.03s)2352--- PASS: TestDrainIsolatesPoisonPath (0.03s)2353--- PASS: TestWorkerSkipsGCdPaths (0.04s)2354--- PASS: TestWorkerPrunesClosureDeps (0.04s)2355--- PASS: TestWorkerUploadsAndRemoves (0.04s)2356--- PASS: TestQueueRemoveLargeClosure (0.10s)23572026/10/05 11:43:12 ERROR Upload failed error="context deadline exceeded" count=223582026/10/05 11:43:12 ERROR Drain finished with paths left in queue remaining=42359--- PASS: TestDrainTimeout (0.22s)2360--- PASS: TestQueueConcurrentWriters (0.38s)23612026/10/05 11:43:13 INFO Uploading batch count=123622026/10/05 11:43:13 INFO Uploading batch count=123632026/10/05 11:43:13 INFO Uploading batch count=123642026/10/05 11:43:13 ERROR Upload failed error="upload failed" count=123652026/10/05 11:43:13 INFO Uploading batch count=123662026/10/05 11:43:13 ERROR Upload failed error="upload failed" count=123672026/10/05 11:43:13 INFO Uploading batch count=123682026/10/05 11:43:13 ERROR Upload failed error="upload failed" count=123692026/10/05 11:43:13 INFO Uploading batch count=123702026/10/05 11:43:13 ERROR Upload failed error="upload failed" count=123712026/10/05 11:43:13 ERROR Drain finished with paths left in queue remaining=12372--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2373PASS