niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #421
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestDebugHTTPRedactsCredentials10--- PASS: TestDebugHTTPRedactsCredentials (0.01s)11=== RUN TestAuthenticatedRedirectStaysOnServer12=== PAUSE TestAuthenticatedRedirectStaysOnServer13=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica14=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica15=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun16=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun17=== RUN TestCaseHackSuffix18=== PAUSE TestCaseHackSuffix19=== RUN TestFilterOversizedClosures20=== PAUSE TestFilterOversizedClosures21=== RUN TestUploadMultipart_PartsInParallel22=== PAUSE TestUploadMultipart_PartsInParallel23=== RUN TestPartSizeForNAR24=== PAUSE TestPartSizeForNAR25=== RUN TestUploadMultipart_SupersededByPeer26=== PAUSE TestUploadMultipart_SupersededByPeer27=== RUN TestDumpPathCaseHackMatchesNix28--- PASS: TestDumpPathCaseHackMatchesNix (0.42s)29=== RUN TestDumpPathCaseHackCollision30--- PASS: TestDumpPathCaseHackCollision (0.00s)31=== RUN TestSupersededNARStillUploadsListing32=== PAUSE TestSupersededNARStillUploadsListing33=== RUN TestDumpPathMatchesNix34=== PAUSE TestDumpPathMatchesNix35=== RUN TestDumpPathSingleFile36=== PAUSE TestDumpPathSingleFile37=== RUN TestDumpPathWriterError38=== PAUSE TestDumpPathWriterError39=== RUN TestEncodeNixBase3240=== PAUSE TestEncodeNixBase3241=== RUN TestEncodeNixBase32WithRealHash42=== PAUSE TestEncodeNixBase32WithRealHash43=== RUN TestConvertHashToNix3244=== PAUSE TestConvertHashToNix3245=== RUN TestGetStorePathHash46=== PAUSE TestGetStorePathHash47=== RUN TestPathInfoHashCompatibility48=== PAUSE TestPathInfoHashCompatibility49=== RUN TestParsePathInfoJSON50=== PAUSE TestParsePathInfoJSON51=== RUN TestParsePathInfoJSONMultiplePaths52=== PAUSE TestParsePathInfoJSONMultiplePaths53=== RUN TestPathInfoCACompatibility54=== PAUSE TestPathInfoCACompatibility55=== RUN TestRateLimiterFeedback56=== PAUSE TestRateLimiterFeedback57=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess58=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess59=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer60=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer61=== RUN TestResolveStorePath62=== PAUSE TestResolveStorePath63=== RUN TestDoWithRetry_BodyReplayedViaGetBody64=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody65=== RUN TestRetryTimeoutOutlastsMaxRetries66=== PAUSE TestRetryTimeoutOutlastsMaxRetries67=== RUN TestDoWithRetry_FinalResponseBodyReadable68=== PAUSE TestDoWithRetry_FinalResponseBodyReadable69=== RUN TestShellSplit70=== PAUSE TestShellSplit71=== RUN TestShellSplitErrors72=== PAUSE TestShellSplitErrors73=== RUN TestStreamPushReportsEveryPath74=== PAUSE TestStreamPushReportsEveryPath75=== RUN TestStreamPushBatchesUnderLoad76=== PAUSE TestStreamPushBatchesUnderLoad77=== RUN TestStreamPushIsolatesFailures78=== PAUSE TestStreamPushIsolatesFailures79=== RUN TestStreamPushGivesUpOnDeadServer80=== PAUSE TestStreamPushGivesUpOnDeadServer81=== RUN TestStreamPushRequestLine82=== PAUSE TestStreamPushRequestLine83=== RUN TestStreamPushReportsSignatures84=== PAUSE TestStreamPushReportsSignatures85=== RUN TestStreamPushReportsSkippedPaths86=== PAUSE TestStreamPushReportsSkippedPaths87=== RUN TestClientSignaturesByStorePath88=== PAUSE TestClientSignaturesByStorePath89=== RUN TestStreamPushStopsWhenCanceled90=== PAUSE TestStreamPushStopsWhenCanceled91=== RUN TestSetClientTLS92=== PAUSE TestSetClientTLS93=== RUN TestSetClientTLSDoesNotMutateDefaultTransport94=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport95=== RUN TestSetClientTLSErrors96=== PAUSE TestSetClientTLSErrors97=== RUN TestStaticToken98=== PAUSE TestStaticToken99=== RUN TestFileTokenReadsAndCaches100=== PAUSE TestFileTokenReadsAndCaches101=== RUN TestFileTokenMissing102=== PAUSE TestFileTokenMissing103=== RUN TestFileTokenEmpty104=== PAUSE TestFileTokenEmpty105=== RUN TestScriptTokenNoExpiryRerunsEveryCall106=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall107=== RUN TestScriptTokenCachesUntilRefresh108=== PAUSE TestScriptTokenCachesUntilRefresh109=== RUN TestScriptTokenEmptyToken110=== PAUSE TestScriptTokenEmptyToken111=== RUN TestScriptTokenBadJSON112=== PAUSE TestScriptTokenBadJSON113=== RUN TestScriptTokenScriptFails114=== PAUSE TestScriptTokenScriptFails115=== RUN TestScriptTokenEmptyCommand116=== PAUSE TestScriptTokenEmptyCommand117=== CONT TestScriptTokenEmptyCommand118--- PASS: TestScriptTokenEmptyCommand (0.00s)119=== CONT TestFilterOversizedClosures120=== CONT TestDoServerRequestAttachesToken121=== CONT TestScriptTokenScriptFails122=== CONT TestScriptTokenBadJSON123=== CONT TestScriptTokenEmptyToken124=== CONT TestScriptTokenCachesUntilRefresh125=== CONT TestScriptTokenNoExpiryRerunsEveryCall126=== CONT TestFileTokenEmpty127--- PASS: TestScriptTokenScriptFails (1.01s)128=== CONT TestFileTokenMissing129=== CONT TestPathInfoCACompatibility130=== CONT TestParsePathInfoJSONMultiplePaths131=== CONT TestParsePathInfoJSON132=== CONT TestPathInfoHashCompatibility133=== CONT TestGetStorePathHash134=== CONT TestConvertHashToNix32135=== CONT TestEncodeNixBase32WithRealHash136=== CONT TestEncodeNixBase32137=== CONT TestDumpPathWriterError138=== CONT TestDumpPathSingleFile139=== CONT TestDumpPathMatchesNix140=== CONT TestSupersededNARStillUploadsListing141=== CONT TestUploadMultipart_SupersededByPeer142=== CONT TestUploadMultipart_PartsInParallel143=== CONT TestRateLimiterFeedback144=== RUN TestFilterOversizedClosures/no_limit_keeps_everything145=== CONT TestCaseHackSuffix146=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun147=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica148=== RUN TestEncodeNixBase32/test_string_hash149--- PASS: TestScriptTokenBadJSON (1.01s)150--- PASS: TestFileTokenEmpty (0.00s)151--- PASS: TestEncodeNixBase32WithRealHash (0.00s)152=== CONT TestAuthenticatedRedirectStaysOnServer153--- PASS: TestScriptTokenEmptyToken (1.01s)154=== CONT TestRegisterUploadedObjectReusesConnections155=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths156=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths157=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths158=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths159=== RUN TestParsePathInfoJSON/Nix_format160=== PAUSE TestParsePathInfoJSON/Nix_format161=== RUN TestParsePathInfoJSON/Lix_format162=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)163=== RUN TestSupersededNARStillUploadsListing/small_NAR164=== RUN TestPathInfoCACompatibility/null_ca_field165=== PAUSE TestSupersededNARStillUploadsListing/small_NAR166=== RUN TestGetStorePathHash/valid_store_path167=== PAUSE TestGetStorePathHash/valid_store_path168=== RUN TestGetStorePathHash/basename_without_hyphen_should_error169=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error170=== RUN TestConvertHashToNix32/SRI_format_to_Nix32171=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32172=== RUN TestUploadMultipart_SupersededByPeer/exists173=== PAUSE TestUploadMultipart_SupersededByPeer/exists174--- PASS: TestFileTokenMissing (0.00s)175=== PAUSE TestEncodeNixBase32/test_string_hash176=== CONT TestStreamPushGivesUpOnDeadServer177=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error178=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error179=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error180=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error181=== RUN TestConvertHashToNix32/already_Nix32_format182=== PAUSE TestConvertHashToNix32/already_Nix32_format183=== RUN TestConvertHashToNix32/invalid_format184=== PAUSE TestConvertHashToNix32/invalid_format185=== CONT TestFileTokenReadsAndCaches186=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry187=== RUN TestSupersededNARStillUploadsListing/dump_cut_short188=== RUN TestUploadMultipart_SupersededByPeer/missing189=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short190=== RUN TestEncodeNixBase32/empty_input191=== PAUSE TestEncodeNixBase32/empty_input192=== RUN TestRateLimiterFeedback/429_enables_limiter193=== PAUSE TestRateLimiterFeedback/429_enables_limiter194=== RUN TestRateLimiterFeedback/503_enables_limiter195=== PAUSE TestRateLimiterFeedback/503_enables_limiter196=== CONT TestSetClientTLSErrors197=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)198=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon199=== PAUSE TestPathInfoCACompatibility/null_ca_field200=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything201=== PAUSE TestParsePathInfoJSON/Lix_format202=== CONT TestStaticToken203--- PASS: TestStaticToken (0.00s)204=== CONT TestSetClientTLSDoesNotMutateDefaultTransport205=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails206=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails207=== CONT TestSetClientTLS208=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon209=== PAUSE TestUploadMultipart_SupersededByPeer/missing210=== CONT TestStreamPushStopsWhenCanceled211=== CONT TestClientSignaturesByStorePath212=== CONT TestStreamPushReportsSkippedPaths213=== RUN TestParsePathInfoJSON/empty_input214=== PAUSE TestParsePathInfoJSON/empty_input215=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI216=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI217=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512218=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512219=== RUN TestPathInfoCACompatibility/old_string_format_-_text220=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text221=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive222=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive223=== RUN TestPathInfoCACompatibility/new_structured_format_-_text224=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text225=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method226=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method227=== RUN TestParsePathInfoJSON/whitespace_only228=== CONT TestStreamPushReportsSignatures229=== CONT TestStreamPushRequestLine230=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped231=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped232=== RUN TestFilterOversizedClosures/all_closures_skipped233=== PAUSE TestFilterOversizedClosures/all_closures_skipped234=== CONT TestResolveStorePath235=== PAUSE TestParsePathInfoJSON/whitespace_only236=== CONT TestDoWithRetry_BodyReplayedViaGetBody237=== RUN TestParsePathInfoJSON/invalid_JSON238=== PAUSE TestParsePathInfoJSON/invalid_JSON239=== CONT TestStreamPushReportsEveryPath240=== CONT TestStreamPushIsolatesFailures241=== CONT TestStreamPushBatchesUnderLoad242=== CONT TestRetryTimeoutOutlastsMaxRetries243=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess244=== CONT TestPartSizeForNAR245=== RUN TestPartSizeForNAR/zero_stays_at_minimum246=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter247=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter248=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter249=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter250=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer251=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum252=== RUN TestPartSizeForNAR/small_stays_at_minimum253=== PAUSE TestPartSizeForNAR/small_stays_at_minimum254=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum255=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum256=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts257=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts258=== RUN TestPartSizeForNAR/1_TiB259=== PAUSE TestPartSizeForNAR/1_TiB260=== RUN TestPartSizeForNAR/5_TiB_S3_max_object261=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object262=== RUN TestPartSizeForNAR/capped_at_5_GiB263=== PAUSE TestPartSizeForNAR/capped_at_5_GiB264--- PASS: TestFileTokenReadsAndCaches (0.00s)265--- PASS: TestStreamPushStopsWhenCanceled (0.00s)266--- PASS: TestClientSignaturesByStorePath (0.00s)267--- PASS: TestStreamPushReportsSkippedPaths (0.00s)268--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)269--- PASS: TestStreamPushReportsEveryPath (0.00s)270--- PASS: TestStreamPushIsolatesFailures (0.00s)271--- PASS: TestResolveStorePath (0.00s)272--- PASS: TestStreamPushReportsSignatures (0.00s)273=== CONT TestShellSplitErrors274--- PASS: TestShellSplitErrors (0.00s)275=== CONT TestDoWithRetry_FinalResponseBodyReadable276=== CONT TestShellSplit277--- PASS: TestShellSplit (0.00s)278=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths279--- PASS: TestScriptTokenCachesUntilRefresh (1.74s)280=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths281=== CONT TestGetStorePathHash/valid_store_path282=== CONT TestConvertHashToNix32/SRI_format_to_Nix32283--- PASS: TestDumpPathSingleFile (0.72s)284=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error285=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error286=== CONT TestConvertHashToNix32/invalid_format287--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)288 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)289 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)290--- PASS: TestDoServerRequestAttachesToken (1.74s)291=== CONT TestEncodeNixBase32/test_string_hash292=== CONT TestEncodeNixBase32/empty_input293--- PASS: TestCaseHackSuffix (0.73s)294=== CONT TestSupersededNARStillUploadsListing/dump_cut_short295--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.72s)296=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)297=== CONT TestConvertHashToNix32/already_Nix32_format298--- PASS: TestConvertHashToNix32 (0.00s)299 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)300 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)301 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)302--- PASS: TestEncodeNixBase32 (0.00s)303 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)304 --- PASS: TestEncodeNixBase32/empty_input (0.00s)305=== CONT TestUploadMultipart_SupersededByPeer/exists306=== CONT TestGetStorePathHash/basename_without_hyphen_should_error307=== CONT TestSupersededNARStillUploadsListing/small_NAR308=== CONT TestPathInfoCACompatibility/null_ca_field309=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails310=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512311=== RUN TestSetClientTLSErrors/missing_cert_file312--- PASS: TestGetStorePathHash (0.00s)313 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)314 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)315 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)316 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)317=== PAUSE TestSetClientTLSErrors/missing_cert_file318=== RUN TestSetClientTLSErrors/missing_key_file319=== PAUSE TestSetClientTLSErrors/missing_key_file320=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon321=== RUN TestSetClientTLSErrors/missing_ca_file322=== CONT TestFilterOversizedClosures/no_limit_keeps_everything323=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI324--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.73s)325=== CONT TestUploadMultipart_SupersededByPeer/missing326--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (1.75s)327--- PASS: TestDoWithRetry_FinalResponseBodyReadable (1.03s)328=== CONT TestParsePathInfoJSON/Nix_format329=== PAUSE TestSetClientTLSErrors/missing_ca_file330=== RUN TestSetClientTLSErrors/invalid_ca_file331=== PAUSE TestSetClientTLSErrors/invalid_ca_file332=== CONT TestParsePathInfoJSON/invalid_JSON333=== CONT TestParsePathInfoJSON/Lix_format334=== CONT TestParsePathInfoJSON/whitespace_only335=== CONT TestPathInfoCACompatibility/new_structured_format_-_text336=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive337=== CONT TestPathInfoCACompatibility/old_string_format_-_text338=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method339=== CONT TestFilterOversizedClosures/all_closures_skipped340=== CONT TestParsePathInfoJSON/empty_input341=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter342=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter343--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (1.04s)344--- PASS: TestPathInfoCACompatibility (0.00s)345 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)346 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)347 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)348 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)349 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)350=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped351=== CONT TestRateLimiterFeedback/503_enables_limiter352--- PASS: TestParsePathInfoJSON (0.00s)353 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)354 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)355 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)356 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)357 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)358--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (1.03s)359=== CONT TestRateLimiterFeedback/429_enables_limiter360=== CONT TestPartSizeForNAR/zero_stays_at_minimum361=== CONT TestPartSizeForNAR/capped_at_5_GiB362=== CONT TestPartSizeForNAR/5_TiB_S3_max_object363=== CONT TestPartSizeForNAR/1_TiB364=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts365=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum366=== CONT TestPartSizeForNAR/small_stays_at_minimum367--- PASS: TestPartSizeForNAR (0.00s)368 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)369 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)370 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)371 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)372 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)373 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)374 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)375=== CONT TestSetClientTLSErrors/missing_cert_file376=== CONT TestSetClientTLSErrors/invalid_ca_file377=== CONT TestSetClientTLSErrors/missing_ca_file378=== CONT TestSetClientTLSErrors/missing_key_file379--- PASS: TestRateLimiterFeedback (0.00s)380 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)381 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)382 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)383 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)384--- PASS: TestSetClientTLSErrors (1.04s)385 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)386 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)387 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)388 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)389--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.04s)390--- PASS: TestPathInfoHashCompatibility (0.00s)391 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)392 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)393 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)394 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)395--- PASS: TestFilterOversizedClosures (1.02s)396 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)397 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)398 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)399=== RUN TestSetClientTLS/rejects_connection_without_client_cert400--- PASS: TestStreamPushBatchesUnderLoad (1.05s)401=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert402=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA403=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA404=== RUN TestSetClientTLS/preserves_debug_logging_transport405=== PAUSE TestSetClientTLS/preserves_debug_logging_transport406=== CONT TestSetClientTLS/rejects_connection_without_client_cert407=== CONT TestSetClientTLS/preserves_debug_logging_transport408=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA409--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)410 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.32s)411 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.02s)412--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (1.06s)413--- PASS: TestDumpPathWriterError (1.07s)414--- PASS: TestRegisterUploadedObjectReusesConnections (1.07s)415--- PASS: TestSetClientTLS (1.06s)416 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.00s)417 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)418 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)419--- PASS: TestStreamPushRequestLine (1.07s)420--- PASS: TestRetryTimeoutOutlastsMaxRetries (1.07s)421--- PASS: TestDumpPathMatchesNix (1.20s)422--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.52s)423--- PASS: TestSupersededNARStillUploadsListing (0.00s)424 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.31s)425 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.32s)426 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.87s)427--- PASS: TestUploadMultipart_PartsInParallel (1.66s)428--- PASS: TestAuthenticatedRedirectStaysOnServer (4.29s)429PASS430Running native OIDC login tests...431=== RUN TestDeviceLogin432=== PAUSE TestDeviceLogin433=== RUN TestDeviceFailures434=== PAUSE TestDeviceFailures435=== RUN TestDiscoveryFailures436=== PAUSE TestDiscoveryFailures437=== RUN TestDeviceCancellation438=== PAUSE TestDeviceCancellation439=== RUN TestRefreshContracts440=== PAUSE TestRefreshContracts441=== RUN TestTokenWithoutRefreshToken442=== PAUSE TestTokenWithoutRefreshToken443=== RUN TestRefreshRejectsIdentityChangeAndKeepsRotation444=== PAUSE TestRefreshRejectsIdentityChangeAndKeepsRotation445=== RUN TestRefreshRetainsOmittedRefreshToken446=== PAUSE TestRefreshRetainsOmittedRefreshToken447=== RUN TestExpiredTokenRefresh448=== PAUSE TestExpiredTokenRefresh449=== RUN TestFractionalTemporalClaims450=== PAUSE TestFractionalTemporalClaims451=== RUN TestDeviceHTTPRequestTimeout452=== PAUSE TestDeviceHTTPRequestTimeout453=== RUN TestDeviceVerificationURL454=== PAUSE TestDeviceVerificationURL455=== RUN TestStoredLoginLifecycle456=== PAUSE TestStoredLoginLifecycle457=== RUN TestStoreFailureDoesNotReturnRefreshedToken458=== PAUSE TestStoreFailureDoesNotReturnRefreshedToken459=== RUN TestStoredNoIDRefresh460=== PAUSE TestStoredNoIDRefresh461=== RUN TestCrossProcessRefresh462=== PAUSE TestCrossProcessRefresh463=== RUN TestStoredTokenProcess464=== PAUSE TestStoredTokenProcess465=== RUN TestProfileLockCancellation466=== PAUSE TestProfileLockCancellation467=== RUN TestLogoutWaitsForRefresh468=== PAUSE TestLogoutWaitsForRefresh469=== RUN TestConcurrentSources470=== PAUSE TestConcurrentSources471=== RUN TestCanonicalServer472=== PAUSE TestCanonicalServer473=== RUN TestSecretServiceBackend474--- PASS: TestSecretServiceBackend (1.44s)475=== CONT TestDeviceLogin476=== CONT TestDeviceVerificationURL477=== RUN TestDeviceVerificationURL/complete478=== CONT TestStoredTokenProcess479=== CONT TestLogoutWaitsForRefresh480=== NAME TestStoredTokenProcess481 manager_unix_test.go:224: subprocess helper482=== PAUSE TestDeviceVerificationURL/complete483=== CONT TestStoreFailureDoesNotReturnRefreshedToken484=== RUN TestDeviceVerificationURL/basic-fallback485=== PAUSE TestDeviceVerificationURL/basic-fallback486=== RUN TestDeviceVerificationURL/insecure487=== PAUSE TestDeviceVerificationURL/insecure488=== RUN TestDeviceVerificationURL/userinfo489=== PAUSE TestDeviceVerificationURL/userinfo490=== RUN TestDeviceVerificationURL/fragment491=== PAUSE TestDeviceVerificationURL/fragment492=== RUN TestDeviceVerificationURL/malformed493=== PAUSE TestDeviceVerificationURL/malformed494=== CONT TestDeviceVerificationURL/complete495=== CONT TestStoredNoIDRefresh496=== CONT TestDeviceVerificationURL/userinfo497=== CONT TestDeviceVerificationURL/insecure498=== CONT TestDeviceVerificationURL/basic-fallback499=== CONT TestDeviceVerificationURL/malformed500=== CONT TestStoredLoginLifecycle501=== CONT TestCrossProcessRefresh502=== CONT TestRefreshRejectsIdentityChangeAndKeepsRotation503=== CONT TestConcurrentSources504=== CONT TestDeviceHTTPRequestTimeout505=== CONT TestCanonicalServer506=== CONT TestFractionalTemporalClaims507=== CONT TestProfileLockCancellation508=== CONT TestExpiredTokenRefresh509=== RUN TestExpiredTokenRefresh/new-id510=== PAUSE TestExpiredTokenRefresh/new-id511=== CONT TestDeviceCancellation512=== RUN TestDeviceCancellation/polling513=== PAUSE TestDeviceCancellation/polling514=== CONT TestRefreshRetainsOmittedRefreshToken515=== CONT TestTokenWithoutRefreshToken516=== CONT TestDiscoveryFailures517=== CONT TestRefreshContracts518=== CONT TestDeviceFailures519--- SKIP: TestStoredTokenProcess (0.00s)520=== CONT TestDeviceVerificationURL/fragment521=== RUN TestDeviceFailures/denied522=== PAUSE TestDeviceFailures/denied523=== RUN TestDeviceFailures/expired524=== PAUSE TestDeviceFailures/expired525=== RUN TestDeviceFailures/no-id526=== PAUSE TestDeviceFailures/no-id527=== RUN TestDeviceFailures/invalid-interval528=== PAUSE TestDeviceFailures/invalid-interval529=== RUN TestDeviceFailures/wrong-aud530=== PAUSE TestDeviceFailures/wrong-aud531=== RUN TestDeviceFailures/future-iat532=== PAUSE TestDeviceFailures/future-iat533=== RUN TestDeviceFailures/multi-aud-no-azp534=== PAUSE TestDeviceFailures/multi-aud-no-azp535=== RUN TestDeviceFailures/wrong-issuer536=== PAUSE TestDeviceFailures/wrong-issuer537=== RUN TestDeviceFailures/expired-id538=== PAUSE TestDeviceFailures/expired-id539=== RUN TestDeviceFailures/future-nbf540=== PAUSE TestDeviceFailures/future-nbf541=== RUN TestDeviceFailures/wrong-azp542=== PAUSE TestDeviceFailures/wrong-azp543=== CONT TestDeviceFailures/denied544--- PASS: TestCanonicalServer (0.00s)545=== RUN TestExpiredTokenRefresh/no-id546=== PAUSE TestExpiredTokenRefresh/no-id547=== RUN TestDeviceCancellation/initial-request548=== PAUSE TestDeviceCancellation/initial-request549=== CONT TestDeviceFailures/multi-aud-no-azp550=== RUN TestDiscoveryFailures/issuer551=== PAUSE TestDiscoveryFailures/issuer552=== RUN TestDiscoveryFailures/no-device553=== PAUSE TestDiscoveryFailures/no-device554=== RUN TestDiscoveryFailures/http-endpoint555=== PAUSE TestDiscoveryFailures/http-endpoint556=== RUN TestDiscoveryFailures/redirect557=== PAUSE TestDiscoveryFailures/redirect558=== CONT TestDeviceFailures/wrong-azp559=== RUN TestRefreshContracts/new-id560=== PAUSE TestRefreshContracts/new-id561=== RUN TestRefreshContracts/no-id562=== PAUSE TestRefreshContracts/no-id563=== CONT TestDeviceFailures/future-nbf564=== CONT TestDeviceFailures/expired-id565--- PASS: TestProfileLockCancellation (0.41s)566=== CONT TestDeviceFailures/wrong-issuer567=== CONT TestDeviceFailures/invalid-interval568=== CONT TestDeviceFailures/future-iat569=== CONT TestDeviceFailures/wrong-aud570--- PASS: TestRefreshRejectsIdentityChangeAndKeepsRotation (0.47s)571=== CONT TestDeviceFailures/no-id572--- PASS: TestFractionalTemporalClaims (0.51s)573=== CONT TestDeviceFailures/expired574=== CONT TestExpiredTokenRefresh/new-id575--- PASS: TestRefreshRetainsOmittedRefreshToken (0.54s)576=== CONT TestDeviceCancellation/polling577=== RUN TestTokenWithoutRefreshToken/before-refresh578=== PAUSE TestTokenWithoutRefreshToken/before-refresh579=== RUN TestTokenWithoutRefreshToken/at-refresh580=== PAUSE TestTokenWithoutRefreshToken/at-refresh581=== RUN TestTokenWithoutRefreshToken/before-expiry-margin582=== PAUSE TestTokenWithoutRefreshToken/before-expiry-margin583=== RUN TestTokenWithoutRefreshToken/at-expiry-margin584=== PAUSE TestTokenWithoutRefreshToken/at-expiry-margin585=== RUN TestTokenWithoutRefreshToken/expired586=== PAUSE TestTokenWithoutRefreshToken/expired587=== CONT TestExpiredTokenRefresh/no-id588=== CONT TestDeviceCancellation/initial-request589--- PASS: TestConcurrentSources (1.16s)590=== CONT TestDiscoveryFailures/issuer591--- PASS: TestDeviceHTTPRequestTimeout (1.19s)592=== CONT TestDiscoveryFailures/redirect593--- PASS: TestStoredNoIDRefresh (1.21s)594=== CONT TestDiscoveryFailures/http-endpoint595=== CONT TestDiscoveryFailures/no-device596=== CONT TestRefreshContracts/new-id597=== CONT TestRefreshContracts/no-id598=== CONT TestTokenWithoutRefreshToken/before-refresh599=== CONT TestTokenWithoutRefreshToken/at-expiry-margin600--- PASS: TestStoreFailureDoesNotReturnRefreshedToken (1.27s)601=== CONT TestTokenWithoutRefreshToken/expired602=== CONT TestTokenWithoutRefreshToken/before-expiry-margin603=== CONT TestTokenWithoutRefreshToken/at-refresh604--- PASS: TestTokenWithoutRefreshToken (0.57s)605 --- PASS: TestTokenWithoutRefreshToken/before-refresh (0.00s)606 --- PASS: TestTokenWithoutRefreshToken/expired (0.00s)607 --- PASS: TestTokenWithoutRefreshToken/at-expiry-margin (0.00s)608 --- PASS: TestTokenWithoutRefreshToken/before-expiry-margin (0.00s)609 --- PASS: TestTokenWithoutRefreshToken/at-refresh (0.00s)610--- PASS: TestDiscoveryFailures (0.00s)611 --- PASS: TestDiscoveryFailures/issuer (0.05s)612 --- PASS: TestDiscoveryFailures/redirect (0.03s)613 --- PASS: TestDiscoveryFailures/http-endpoint (0.06s)614 --- PASS: TestDiscoveryFailures/no-device (0.08s)615--- PASS: TestExpiredTokenRefresh (0.00s)616 --- PASS: TestExpiredTokenRefresh/new-id (0.12s)617 --- PASS: TestExpiredTokenRefresh/no-id (0.16s)618--- PASS: TestLogoutWaitsForRefresh (1.31s)619--- PASS: TestDeviceCancellation (0.00s)620 --- PASS: TestDeviceCancellation/polling (0.22s)621 --- PASS: TestDeviceCancellation/initial-request (0.28s)622--- PASS: TestRefreshContracts (0.00s)623 --- PASS: TestRefreshContracts/no-id (0.16s)624 --- PASS: TestRefreshContracts/new-id (0.21s)625--- PASS: TestCrossProcessRefresh (1.77s)626--- PASS: TestDeviceVerificationURL (0.00s)627 --- PASS: TestDeviceVerificationURL/insecure (1.01s)628 --- PASS: TestDeviceVerificationURL/malformed (1.01s)629 --- PASS: TestDeviceVerificationURL/fragment (0.46s)630 --- PASS: TestDeviceVerificationURL/userinfo (1.11s)631 --- PASS: TestDeviceVerificationURL/complete (2.07s)632 --- PASS: TestDeviceVerificationURL/basic-fallback (2.08s)633--- PASS: TestDeviceFailures (0.00s)634 --- PASS: TestDeviceFailures/invalid-interval (0.15s)635 --- PASS: TestDeviceFailures/wrong-azp (1.44s)636 --- PASS: TestDeviceFailures/denied (1.47s)637 --- PASS: TestDeviceFailures/wrong-issuer (1.12s)638 --- PASS: TestDeviceFailures/no-id (1.08s)639 --- PASS: TestDeviceFailures/multi-aud-no-azp (1.55s)640 --- PASS: TestDeviceFailures/future-nbf (1.56s)641 --- PASS: TestDeviceFailures/future-iat (1.14s)642 --- PASS: TestDeviceFailures/expired (1.14s)643 --- PASS: TestDeviceFailures/expired-id (1.74s)644 --- PASS: TestDeviceFailures/wrong-aud (1.29s)645--- PASS: TestStoredLoginLifecycle (2.45s)646--- PASS: TestDeviceLogin (9.08s)647PASS648Running CLI config directory tests...649=== RUN TestDir650=== RUN TestDir/override651=== RUN TestDir/fallback652--- PASS: TestDir (0.00s)653 --- PASS: TestDir/override (0.00s)654 --- PASS: TestDir/fallback (0.00s)655PASS656Running command utility tests...657=== RUN TestAuthConfigDirectories658--- PASS: TestAuthConfigDirectories (0.00s)659=== RUN TestOIDCResolution660=== RUN TestOIDCResolution/saved-fallback661=== RUN TestOIDCResolution/explicit-token6622026/10/24 21:48:10 WARN --auth-token is deprecated: tokens on the command line are visible in /proc and shell history; use --auth-token-path or --auth-token-script663=== RUN TestOIDCResolution/explicit-file664=== RUN TestOIDCResolution/env-file665=== RUN TestOIDCResolution/mtls666=== RUN TestOIDCResolution/explicit-profile667=== RUN TestOIDCResolution/explicit-token-over-profile6682026/10/24 21:48:10 WARN --auth-token is deprecated: tokens on the command line are visible in /proc and shell history; use --auth-token-path or --auth-token-script669=== RUN TestOIDCResolution/hook-does-not-select-profile670=== RUN TestOIDCResolution/hook-env-file671=== RUN TestOIDCResolution/device-conflict6722026/10/24 21:48:10 WARN --auth-token is deprecated: tokens on the command line are visible in /proc and shell history; use --auth-token-path or --auth-token-script673=== RUN TestOIDCResolution/device-profile-conflict674=== RUN TestOIDCResolution/issuer-without-device675--- PASS: TestOIDCResolution (0.00s)676 --- PASS: TestOIDCResolution/saved-fallback (0.00s)677 --- PASS: TestOIDCResolution/explicit-token (0.00s)678 --- PASS: TestOIDCResolution/explicit-file (0.00s)679 --- PASS: TestOIDCResolution/env-file (0.00s)680 --- PASS: TestOIDCResolution/mtls (0.00s)681 --- PASS: TestOIDCResolution/explicit-profile (0.00s)682 --- PASS: TestOIDCResolution/explicit-token-over-profile (0.00s)683 --- PASS: TestOIDCResolution/hook-does-not-select-profile (0.00s)684 --- PASS: TestOIDCResolution/hook-env-file (0.00s)685 --- PASS: TestOIDCResolution/device-conflict (0.00s)686 --- PASS: TestOIDCResolution/device-profile-conflict (0.00s)687 --- PASS: TestOIDCResolution/issuer-without-device (0.00s)688PASS689Running CLI tests...690=== RUN TestAuthHelpAndValidation691--- PASS: TestAuthHelpAndValidation (0.00s)692PASS693Running server tests...694The files belonging to this database system will be owned by user "nixbld".695This user must also own the server process.696697The database cluster will be initialized with locale "C".698The default database encoding has accordingly been set to "SQL_ASCII".699The default text search configuration will be set to "english".700701Data page checksums are enabled.702703creating directory /build/postgres3984700450/data ... ok704creating subdirectories ... ok705selecting dynamic shared memory implementation ... posix706selecting default "max_connections" ... 100707selecting default "shared_buffers" ... 128MB708selecting default time zone ... UTC709creating configuration files ... ok710running bootstrap script ... ok711performing post-bootstrap initialization ... ok712syncing data to disk ... ok713714initdb: warning: enabling "trust" authentication for local connections715initdb: 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.716717Success. You can now start the database server using:718719 pg_ctl -D /build/postgres3984700450/data -l logfile start720721/build/postgres3984700450:5432 - no response722/build/postgres3984700450:5432 - no response723/build/postgres3984700450:5432 - no response724/build/postgres3984700450:5432 - no response725/build/postgres3984700450:5432 - no response726/build/postgres3984700450:5432 - no response727/build/postgres3984700450:5432 - no response728/build/postgres3984700450:5432 - no response729/build/postgres3984700450:5432 - no response730/build/postgres3984700450:5432 - no response731/build/postgres3984700450:5432 - no response732/build/postgres3984700450:5432 - no response733/build/postgres3984700450:5432 - no response734/build/postgres3984700450:5432 - no response735/build/postgres3984700450:5432 - no response736/build/postgres3984700450:5432 - no response737/build/postgres3984700450:5432 - no response738/build/postgres3984700450:5432 - no response739/build/postgres3984700450:5432 - no response740/build/postgres3984700450:5432 - no response7412026-10-24 21:48:23.722 UTC [204] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit7422026-10-24 21:48:23.723 UTC [204] LOG: listening on Unix socket "/build/postgres3984700450/.s.PGSQL.5432"7432026-10-24 21:48:23.728 UTC [230] LOG: database system was shut down at 2026-10-24 21:48:21 UTC7442026-10-24 21:48:23.733 UTC [204] LOG: database system is ready to accept connections745/build/postgres3984700450:5432 - accepting connections746{"timestamp":"2026-10-24T21:48:31.273282811Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"52f62622-c7bb-4293-a7b9-d56e5262354c","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":11,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(195)"}747{"timestamp":"2026-10-24T21:48:31.382628106Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b5e0ec2e-3b72-4ee7-a703-5e60d53eed88","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(196)"}748=== RUN TestService_AuthMiddleware749=== PAUSE TestService_AuthMiddleware750=== RUN TestService_AuthMiddleware_MTLSProxyHeader751=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader752=== RUN TestService_AuthMiddleware_MTLSBoundSubjects753=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects754=== RUN TestService_ReadAuthMiddleware755=== PAUSE TestService_ReadAuthMiddleware756=== RUN TestService_AuthMiddleware_OIDC757=== PAUSE TestService_AuthMiddleware_OIDC758=== RUN TestService_RequireScope_OIDC759=== PAUSE TestService_RequireScope_OIDC760=== RUN TestService_ReadScope_PublicByDefault761=== PAUSE TestService_ReadScope_PublicByDefault762=== RUN TestCacheConfigHandler763=== PAUSE TestCacheConfigHandler764=== RUN TestCacheStatsHandler765=== PAUSE TestCacheStatsHandler766=== RUN TestClientCADerivations767=== PAUSE TestClientCADerivations768=== RUN TestClientErrorHandling769=== PAUSE TestClientErrorHandling770=== RUN TestClientIntegration771=== PAUSE TestClientIntegration772=== RUN TestClientMultipleUploads773=== PAUSE TestClientMultipleUploads774=== RUN TestClientWithDependencies775=== PAUSE TestClientWithDependencies776=== RUN TestClientSharedPathCommittedMidPush777=== PAUSE TestClientSharedPathCommittedMidPush778=== RUN TestPinProtectsFromGC779=== PAUSE TestPinProtectsFromGC780=== RUN TestClientPushesUseOnePush781=== PAUSE TestClientPushesUseOnePush782=== RUN TestClientFallsBackToClosures783=== PAUSE TestClientFallsBackToClosures784=== RUN TestDeleteClosuresRacingPins785=== PAUSE TestDeleteClosuresRacingPins786=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock787=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock788=== RUN TestResolveDBConnectionString789=== PAUSE TestResolveDBConnectionString790=== RUN TestConnectWaitsForAPeerMigration791=== PAUSE TestConnectWaitsForAPeerMigration792=== RUN TestLeadElectsOneAndHandsOver793=== PAUSE TestLeadElectsOneAndHandsOver794=== RUN TestLeadIncumbentWinsAfterRestart7952026/10/24 21:48:31 INFO lead: acquired remote=192.0.2.1:12347962026/10/24 21:48:32 INFO lead: released remote=192.0.2.1:12347972026/10/24 21:48:32 INFO lead: acquired remote=192.0.2.1:12347982026/10/24 21:48:33 INFO lead: released remote=192.0.2.1:1234799--- PASS: TestLeadIncumbentWinsAfterRestart (2.22s)800=== RUN TestLeadIncumbentAnnouncesAtOnce801=== PAUSE TestLeadIncumbentAnnouncesAtOnce802=== RUN TestLeadEndsOnShutdown803=== PAUSE TestLeadEndsOnShutdown804=== RUN TestLeadEndsWhenItsConnectionHangs8052026/10/24 21:48:34 INFO lead: acquired remote=192.0.2.1:12348062026-10-24 21:48:35.596 UTC [480] FATAL: terminating connection due to administrator command8072026/10/24 21:48:35 INFO lead: acquired remote=192.0.2.1:12348082026/10/24 21:48:36 WARN lead: lock connection lost error="timeout: context deadline exceeded"8092026/10/24 21:48:36 INFO lead: released remote=192.0.2.1:12348102026/10/24 21:48:37 INFO lead: released remote=192.0.2.1:1234811--- PASS: TestLeadEndsWhenItsConnectionHangs (3.47s)812=== RUN TestGCAdvisoryLockBlocksConcurrentRun813=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun814=== RUN TestGCBugBareHashReferences815=== PAUSE TestGCBugBareHashReferences816=== RUN TestGCMetrics817=== PAUSE TestGCMetrics818=== RUN TestPushDedupSurvivesConcurrentGC819=== PAUSE TestPushDedupSurvivesConcurrentGC820=== RUN TestDeduplicatedObjectsRecordedAsPending821=== PAUSE TestDeduplicatedObjectsRecordedAsPending822=== RUN TestGCSweepSkipsPendingObjects823=== PAUSE TestGCSweepSkipsPendingObjects824=== RUN TestTombstonedObjectOfferedWithoutWaiting825=== PAUSE TestTombstonedObjectOfferedWithoutWaiting826=== RUN TestGCSweepDeliversEachKeyOnce827=== PAUSE TestGCSweepDeliversEachKeyOnce828=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection829=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection830=== RUN TestForceGCDuringPushOffersSweptObject831=== PAUSE TestForceGCDuringPushOffersSweptObject832=== RUN TestFailedS3DeleteKeepsTombstone833=== PAUSE TestFailedS3DeleteKeepsTombstone834=== RUN TestSweepSkipsRowsLockedByPush835=== PAUSE TestSweepSkipsRowsLockedByPush836=== RUN TestRegisterCompletedObjectNeedsPendingRow837=== PAUSE TestRegisterCompletedObjectNeedsPendingRow838=== RUN TestGetExistingObjectsLocksRows839=== PAUSE TestGetExistingObjectsLocksRows840=== RUN TestSweepRechecksPendingAfterLocking841=== PAUSE TestSweepRechecksPendingAfterLocking842=== RUN TestPushWaitsForSweepHoldingRow843=== PAUSE TestPushWaitsForSweepHoldingRow844=== RUN TestCommitRacingPendingCleanupKeepsObjects845=== PAUSE TestCommitRacingPendingCleanupKeepsObjects846=== RUN TestGCEndsOnShutdown847=== PAUSE TestGCEndsOnShutdown848=== RUN TestGCTaskStore_StartNew849=== PAUSE TestGCTaskStore_StartNew850=== RUN TestGCTaskStore_DeduplicateSameParams851=== PAUSE TestGCTaskStore_DeduplicateSameParams852=== RUN TestGCTaskStore_ConflictDifferentParams853=== PAUSE TestGCTaskStore_ConflictDifferentParams854=== RUN TestGCTaskStore_GetEmpty855=== PAUSE TestGCTaskStore_GetEmpty856=== RUN TestGCTaskStore_GetReturnsLatest857=== PAUSE TestGCTaskStore_GetReturnsLatest858=== RUN TestGCTaskStore_CompletedAllowsNewTask859=== PAUSE TestGCTaskStore_CompletedAllowsNewTask860=== RUN TestGCTaskStore_PhaseUpdates861=== PAUSE TestGCTaskStore_PhaseUpdates862=== RUN TestGCTaskStore_Fail863=== PAUSE TestGCTaskStore_Fail864=== RUN TestGracefulShutdownDrainsInflight865=== PAUSE TestGracefulShutdownDrainsInflight866=== RUN TestService_healthCheckHandler867=== PAUSE TestService_healthCheckHandler868=== RUN TestService_readinessHandler869=== PAUSE TestService_readinessHandler870=== RUN TestGenerateLandingPage871=== PAUSE TestGenerateLandingPage872=== RUN TestCacheConfigHandlerMaxNarSize873=== PAUSE TestCacheConfigHandlerMaxNarSize874=== RUN TestCreatePendingClosureRejectsOversizedNAR875=== PAUSE TestCreatePendingClosureRejectsOversizedNAR876=== RUN TestNARDeduplicationMetadataUploadBug877=== PAUSE TestNARDeduplicationMetadataUploadBug878=== RUN TestMetricsInventory879=== PAUSE TestMetricsInventory880=== RUN TestMetricsCommit881=== PAUSE TestMetricsCommit882=== RUN TestService_NativeMTLS883=== PAUSE TestService_NativeMTLS884=== RUN TestServerTLSConfig885=== PAUSE TestServerTLSConfig886=== RUN TestMultipartCleanup887=== PAUSE TestMultipartCleanup888=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded889=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded890=== RUN TestPendingCleanupUsesOneCutoff891=== PAUSE TestPendingCleanupUsesOneCutoff892=== RUN TestNativeOIDCLoginPushRefresh893=== PAUSE TestNativeOIDCLoginPushRefresh894=== RUN TestObjectStatsTrigger895=== PAUSE TestObjectStatsTrigger896=== RUN TestObjectStatsLargeCommit897=== PAUSE TestObjectStatsLargeCommit898=== RUN TestOrphanedObjectsGC899=== PAUSE TestOrphanedObjectsGC900=== RUN TestOrphanedObjectsGCStressTest901=== PAUSE TestOrphanedObjectsGCStressTest902=== RUN TestCreatePin_ReservedPins903=== PAUSE TestCreatePin_ReservedPins904=== RUN TestPresentReportsOnlyClosureRoots905=== PAUSE TestPresentReportsOnlyClosureRoots906=== RUN TestPresentRefreshesOnlyStaleClosures907=== PAUSE TestPresentRefreshesOnlyStaleClosures908=== RUN TestPresentNotReportedWhileGCDeletesClosure909=== PAUSE TestPresentNotReportedWhileGCDeletesClosure910=== RUN TestParseSingleRange911=== PAUSE TestParseSingleRange912=== RUN TestProxyHeadersOnlyTrustedOnSocket9132026/10/24 21:48:37 INFO Starting HTTP server address=127.0.0.1:338579142026/10/24 21:48:37 INFO Starting HTTP server address=proxy.sock9152026/10/24 21:48:37 WARN mTLS auth: subject not in bound subjects subject="CN=someone"9162026/10/24 21:48:37 INFO Shutdown signal received, draining in-flight requests timeout=10s917--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.40s)918=== RUN TestIsValidCachePath919=== PAUSE TestIsValidCachePath920=== RUN TestReadProxyNarinfo921=== PAUSE TestReadProxyNarinfo922=== RUN TestReadProxyNarinfoAlreadyDecompressed923=== PAUSE TestReadProxyNarinfoAlreadyDecompressed924=== RUN TestReadProxyContentNegotiation925=== PAUSE TestReadProxyContentNegotiation926=== RUN TestReadProxyNarStreaming927=== PAUSE TestReadProxyNarStreaming928=== RUN TestReadProxy404929=== PAUSE TestReadProxy404930=== RUN TestReadProxyInvalidPath931=== PAUSE TestReadProxyInvalidPath932=== RUN TestReadProxyHead933=== PAUSE TestReadProxyHead934=== RUN TestReadProxyOutlastsServerWriteTimeout935=== PAUSE TestReadProxyOutlastsServerWriteTimeout936=== RUN TestReadProxyConditionalGet937=== PAUSE TestReadProxyConditionalGet938=== RUN TestReadProxyRootRedirectsToIndexHTML939=== PAUSE TestReadProxyRootRedirectsToIndexHTML940=== RUN TestReadProxyDisabled941=== PAUSE TestReadProxyDisabled942=== RUN TestReadRedirectNar943=== PAUSE TestReadRedirectNar944=== RUN TestReadRedirectKeepsNarinfoProxied945=== PAUSE TestReadRedirectKeepsNarinfoProxied946=== RUN TestReadProxyRangeRequest947=== PAUSE TestReadProxyRangeRequest948=== RUN TestReadRedirectUsesPublicS3URL949=== PAUSE TestReadRedirectUsesPublicS3URL950=== RUN TestPush_OverlappingRootsStoreOneRowPerKey951=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey952=== RUN TestPush_CompleteCommitsEveryRoot953=== PAUSE TestPush_CompleteCommitsEveryRoot954=== RUN TestPush_RepeatedRootCommitsOnce955=== PAUSE TestPush_RepeatedRootCommitsOnce956=== RUN TestPush_CompleteWaitsForCleanupOfThePush957=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush958=== RUN TestPush_RootsAreLockedInByteOrder959=== PAUSE TestPush_RootsAreLockedInByteOrder960=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit961=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit962=== RUN TestPush_RejectsBadRequests963=== PAUSE TestPush_RejectsBadRequests964=== RUN TestPush_SignsNarinfosOfItsPendingObjects965=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects966=== RUN TestRedundantMultipartUpload967=== PAUSE TestRedundantMultipartUpload968=== RUN TestCompleteMultipartUpload_ErrorButObjectExists969=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists970=== RUN TestCompletedNarNotReofferedAcrossClosures971=== PAUSE TestCompletedNarNotReofferedAcrossClosures972=== RUN TestPresignedUploadRegisteredBeforeCommit973=== PAUSE TestPresignedUploadRegisteredBeforeCommit974=== RUN TestService_Rustfstest975=== PAUSE TestService_Rustfstest976=== RUN TestParseSize977=== PAUSE TestParseSize978=== RUN TestSkippedUploadsHandler979=== PAUSE TestSkippedUploadsHandler980=== RUN TestSystemdListenerNotActivated981--- PASS: TestSystemdListenerNotActivated (0.00s)982=== RUN TestWatchdogBeatsWhenHealthy983--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)984=== RUN TestWatchdogSkipsWhenUnhealthy9852026/10/24 21:48:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9862026/10/24 21:48:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9872026/10/24 21:48:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9882026/10/24 21:48:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9892026/10/24 21:48:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9902026/10/24 21:48:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9912026/10/24 21:48:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9922026/10/24 21:48:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9932026/10/24 21:48:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9942026/10/24 21:48:37 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"995--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)996=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle997=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle998=== RUN TestProxyWriteTimeout999=== PAUSE TestProxyWriteTimeout1000=== RUN TestPendingClosureWriteTimeout1001=== PAUSE TestPendingClosureWriteTimeout1002=== RUN TestIsValidUploadKey1003=== PAUSE TestIsValidUploadKey1004=== RUN TestUploadHandlersRejectInvalidKeys1005=== PAUSE TestUploadHandlersRejectInvalidKeys1006=== RUN TestUploadHandlersRejectOversizedBody1007=== PAUSE TestUploadHandlersRejectOversizedBody1008=== RUN TestService_cleanupPendingClosuresHandler1009=== PAUSE TestService_cleanupPendingClosuresHandler1010=== RUN TestService_createPendingClosureHandler1011=== PAUSE TestService_createPendingClosureHandler1012=== RUN TestService_verifyS3Integrity1013=== PAUSE TestService_verifyS3Integrity1014=== RUN TestCompleteMultipartUnregistered1015=== PAUSE TestCompleteMultipartUnregistered1016=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT1017=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT1018=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1019=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1020=== CONT TestServerTLSConfig1021=== CONT TestCreatePendingClosureRejectsOversizedNAR1022=== CONT TestSkippedUploadsHandler1023=== CONT TestService_AuthMiddleware1024=== CONT TestParseSize1025--- PASS: TestParseSize (0.00s)1026=== CONT TestGCTaskStore_GetEmpty1027=== CONT TestService_NativeMTLS1028=== CONT TestService_Rustfstest1029=== CONT TestMetricsCommit1030=== CONT TestPresignedUploadRegisteredBeforeCommit1031=== CONT TestMetricsInventory1032=== CONT TestCompletedNarNotReofferedAcrossClosures1033=== CONT TestNARDeduplicationMetadataUploadBug1034=== CONT TestCacheConfigHandlerMaxNarSize1035=== CONT TestGenerateLandingPage1036=== CONT TestService_readinessHandler1037=== CONT TestService_healthCheckHandler1038=== CONT TestGracefulShutdownDrainsInflight1039=== CONT TestGCTaskStore_Fail1040=== CONT TestGCTaskStore_PhaseUpdates1041=== CONT TestGCTaskStore_CompletedAllowsNewTask1042=== CONT TestGCTaskStore_GetReturnsLatest1043=== CONT TestReadProxyInvalidPath1044=== RUN TestServerTLSConfig/no_client_CA1045=== PAUSE TestServerTLSConfig/no_client_CA1046=== RUN TestServerTLSConfig/missing_CA_file1047=== PAUSE TestServerTLSConfig/missing_CA_file1048=== RUN TestServerTLSConfig/not_a_PEM_file1049=== PAUSE TestServerTLSConfig/not_a_PEM_file10502026/10/24 21:48:37 INFO Client skipped oversized paths paths=3 nar_bytes=500000000010512026/10/24 21:48:37 INFO Received uploads request method=POST path=/api/pending_closures1052=== CONT TestGCTaskStore_StartNew1053=== CONT TestGCEndsOnShutdown1054=== RUN TestGCEndsOnShutdown/before_the_run1055=== PAUSE TestGCEndsOnShutdown/before_the_run1056=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1057=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1058=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1059=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1060=== CONT TestRedundantMultipartUpload1061=== CONT TestCommitRacingPendingCleanupKeepsObjects1062--- PASS: TestGCTaskStore_GetEmpty (0.00s)1063--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1064--- PASS: TestGCTaskStore_StartNew (0.00s)1065--- PASS: TestGCTaskStore_Fail (0.00s)1066=== CONT TestGCTaskStore_DeduplicateSameParams1067--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1068=== CONT TestPush_SignsNarinfosOfItsPendingObjects1069--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1070=== CONT TestPushWaitsForSweepHoldingRow1071=== CONT TestGCTaskStore_ConflictDifferentParams1072--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1073=== CONT TestPush_RejectsBadRequests1074--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1075--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1076=== CONT TestSweepRechecksPendingAfterLocking1077=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1078--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1079=== CONT TestGetExistingObjectsLocksRows10802026/10/24 21:48:38 INFO Starting HTTP server address=127.0.0.1:440471081--- PASS: TestSkippedUploadsHandler (0.75s)1082=== CONT TestPush_RootsAreLockedInByteOrder10832026/10/24 21:48:38 INFO Shutdown signal received, draining in-flight requests timeout=10s1084--- PASS: TestGenerateLandingPage (0.57s)1085=== CONT TestRegisterCompletedObjectNeedsPendingRow1086--- PASS: TestGracefulShutdownDrainsInflight (0.50s)1087=== CONT TestPush_CompleteWaitsForCleanupOfThePush10882026/10/24 21:48:39 INFO Received uploads request method=POST path=/api/pending_closures10892026/10/24 21:48:39 INFO Received uploads request method=POST path=/api/pending_closures10902026/10/24 21:48:39 INFO Received uploads request method=POST path=/api/pending_closures10912026/10/24 21:48:39 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1092--- PASS: TestService_AuthMiddleware (1.40s)1093=== CONT TestPush_RepeatedRootCommitsOnce10942026/10/24 21:48:39 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst10952026/10/24 21:48:39 INFO Received uploads request method=POST path=/api/pending_closures1096--- PASS: TestPresignedUploadRegisteredBeforeCommit (1.41s)1097=== CONT TestSweepSkipsRowsLockedByPush1098--- PASS: TestService_Rustfstest (1.42s)1099=== CONT TestPush_CompleteCommitsEveryRoot11002026/10/24 21:48:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11012026/10/24 21:48:39 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDk1ZDM5N2YtZThjZS00NzBkLThhZDUtNTRiMWQ0NDQ3YjQyLjZkYzc3ZDBmLWE3MTctNDMzOC1iNjM2LWQ2OWZjNzZhY2UwN3gxNzkyODc4NTE5MjAyNDA4OTI311022026/10/24 21:48:39 INFO Aborted multipart uploads count=0 kept=011032026/10/24 21:48:39 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11042026/10/24 21:48:39 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1105--- PASS: TestService_NativeMTLS (1.45s)1106=== CONT TestPresentReportsOnlyClosureRoots11072026/10/24 21:48:39 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDk1ZDM5N2YtZThjZS00NzBkLThhZDUtNTRiMWQ0NDQ3YjQyLjZkYzc3ZDBmLWE3MTctNDMzOC1iNjM2LWQ2OWZjNzZhY2UwN3gxNzkyODc4NTE5MjAyNDA4OTI3 parts=11108--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.46s)1109=== CONT TestReadProxy40411102026/10/24 21:48:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11112026/10/24 21:48:39 INFO Received push request method=POST path=/api/pushes11122026/10/24 21:48:39 INFO Received uploads request method=POST path=/api/pending_closures11132026/10/24 21:48:39 INFO Received complete push request method=POST path=/api/pushes/1/complete11142026/10/24 21:48:39 INFO Received uploads request method=POST path=/api/pending_closures1115--- PASS: TestMetricsInventory (1.55s)1116=== CONT TestFailedS3DeleteKeepsTombstone11172026/10/24 21:48:39 WARN Force mode enabled - objects will be deleted immediately without grace period11182026/10/24 21:48:39 INFO Completed push id=1 objects=4 duration=42.624655ms11192026/10/24 21:48:39 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11202026/10/24 21:48:39 INFO Received push request method=POST path=/api/pushes11212026/10/24 21:48:39 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011222026/10/24 21:48:39 INFO Completed upload id=2 objects=2 duration=2.420882ms11232026/10/24 21:48:39 INFO Vacuumed table table=pending_closures1124--- PASS: TestMetricsCommit (1.57s)1125=== CONT TestReadProxyNarStreaming11262026/10/24 21:48:39 INFO Vacuumed table table=pending_objects11272026/10/24 21:48:39 INFO Vacuumed table table=multipart_uploads11282026/10/24 21:48:39 INFO Vacuumed table table=closures11292026/10/24 21:48:39 INFO Vacuumed table table=objects1130--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.59s)1131=== CONT TestReadProxyContentNegotiation11322026-10-24 21:48:39.451 UTC [603] ERROR: could not obtain lock on row in relation "closures"11332026-10-24 21:48:39.451 UTC [603] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11342026-10-24 21:48:39.452 UTC [603] ERROR: could not obtain lock on row in relation "closures"11352026-10-24 21:48:39.452 UTC [603] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11362026-10-24 21:48:39.453 UTC [603] ERROR: could not obtain lock on row in relation "closures"11372026-10-24 21:48:39.453 UTC [603] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11382026-10-24 21:48:39.454 UTC [603] ERROR: could not obtain lock on row in relation "closures"11392026-10-24 21:48:39.454 UTC [603] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11402026-10-24 21:48:39.458 UTC [603] ERROR: could not obtain lock on row in relation "closures"11412026-10-24 21:48:39.458 UTC [603] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1142--- PASS: TestPush_RootsAreLockedInByteOrder (0.89s)1143=== CONT TestReadProxyNarinfoAlreadyDecompressed11442026/10/24 21:48:39 INFO Received uploads request method=POST path=/api/pending_closures11452026/10/24 21:48:39 INFO Received push request method=POST path=/api/pushes11462026/10/24 21:48:39 INFO Received complete push request method=POST path=/api/pushes/1/complete11472026/10/24 21:48:39 INFO Received push request method=POST path=/api/pushes11482026/10/24 21:48:39 INFO Received complete push request method=POST path=/api/pushes/1/complete1149--- PASS: TestReadProxyInvalidPath (1.56s)1150=== CONT TestPush_OverlappingRootsStoreOneRowPerKey11512026/10/24 21:48:39 INFO Completed push id=1 objects=4 duration=67.172763ms11522026/10/24 21:48:39 INFO Completed push id=1 objects=6 duration=42.625736ms1153--- PASS: TestPush_RepeatedRootCommitsOnce (0.38s)1154=== CONT TestReadProxyNarinfo1155--- PASS: TestPush_CompleteCommitsEveryRoot (0.35s)1156=== CONT TestReadRedirectUsesPublicS3URL11572026/10/24 21:48:39 WARN readiness check failed error="closed pool"1158--- PASS: TestService_readinessHandler (1.60s)1159=== CONT TestReadProxyRootRedirectsToIndexHTML11602026/10/24 21:48:39 INFO Aborted multipart uploads count=0 kept=01161=== NAME TestNARDeduplicationMetadataUploadBug1162 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug2197444684/001/store/yqp8izq373s7g8i4rv9jzbv03ka6m1hz-file1.txt11632026/10/24 21:48:39 WARN Force mode enabled - objects will be deleted immediately without grace period11642026/10/24 21:48:39 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=011652026/10/24 21:48:39 INFO Vacuumed table table=pending_closures11662026/10/24 21:48:39 INFO Received uploads request method=POST path=/api/pending_closures11672026/10/24 21:48:39 INFO Vacuumed table table=pending_objects11682026/10/24 21:48:39 INFO Vacuumed table table=multipart_uploads11692026/10/24 21:48:39 INFO Vacuumed table table=closures11702026/10/24 21:48:39 INFO Vacuumed table table=objects1171--- PASS: TestSweepRechecksPendingAfterLocking (1.12s)1172=== CONT TestReadProxyConditionalGet1173--- PASS: TestRegisterCompletedObjectNeedsPendingRow (1.12s)1174=== CONT TestReadProxyOutlastsServerWriteTimeout11752026/10/24 21:48:39 INFO Aborted multipart uploads count=0 kept=01176--- PASS: TestPresentReportsOnlyClosureRoots (0.51s)1177=== CONT TestReadProxyHead1178--- PASS: TestReadProxyNarStreaming (0.45s)1179=== CONT TestService_cleanupPendingClosuresHandler1180--- PASS: TestReadProxy404 (0.58s)1181=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1182--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.40s)1183=== CONT TestIsValidCachePath1184=== RUN TestIsValidCachePath/narinfo1185=== PAUSE TestIsValidCachePath/narinfo1186=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1187=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1188=== RUN TestIsValidCachePath/nar_zst1189=== PAUSE TestIsValidCachePath/nar_zst1190=== RUN TestIsValidCachePath/nar_xz1191=== PAUSE TestIsValidCachePath/nar_xz1192=== RUN TestIsValidCachePath/nar_bz21193=== PAUSE TestIsValidCachePath/nar_bz21194=== RUN TestIsValidCachePath/nar_uncompressed1195=== PAUSE TestIsValidCachePath/nar_uncompressed1196=== RUN TestIsValidCachePath/ls1197=== PAUSE TestIsValidCachePath/ls1198=== RUN TestIsValidCachePath/log1199=== PAUSE TestIsValidCachePath/log1200=== RUN TestIsValidCachePath/realisation1201=== PAUSE TestIsValidCachePath/realisation1202=== RUN TestIsValidCachePath/nix-cache-info1203=== PAUSE TestIsValidCachePath/nix-cache-info1204=== RUN TestIsValidCachePath/index.html1205=== PAUSE TestIsValidCachePath/index.html1206=== RUN TestIsValidCachePath/traversal_parent1207=== PAUSE TestIsValidCachePath/traversal_parent1208=== RUN TestIsValidCachePath/traversal_in_middle1209=== PAUSE TestIsValidCachePath/traversal_in_middle1210=== RUN TestIsValidCachePath/invalid_char_e1211=== PAUSE TestIsValidCachePath/invalid_char_e12122026/10/24 21:48:39 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1213=== RUN TestIsValidCachePath/invalid_char_u1214=== PAUSE TestIsValidCachePath/invalid_char_u1215=== RUN TestIsValidCachePath/random_path1216=== PAUSE TestIsValidCachePath/random_path1217=== RUN TestIsValidCachePath/empty1218=== PAUSE TestIsValidCachePath/empty1219=== RUN TestIsValidCachePath/leading_slash1220=== PAUSE TestIsValidCachePath/leading_slash1221=== RUN TestIsValidCachePath/wrong_extension1222=== PAUSE TestIsValidCachePath/wrong_extension1223=== RUN TestIsValidCachePath/short_hash1224=== PAUSE TestIsValidCachePath/short_hash1225=== CONT TestCompleteMultipartUnregistered12262026/10/24 21:48:39 INFO Received push request method=POST path=/api/pushes12272026/10/24 21:48:39 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NDk1ZDM5N2YtZThjZS00NzBkLThhZDUtNTRiMWQ0NDQ3YjQyLjQxODBhZjllLWI5MTEtNDM1Yi1iYzdlLWE0ZWFiN2ZiNzYzMHgxNzkyODc4NTE5MzM4NTQ5Mzkw parts=1212282026/10/24 21:48:39 INFO Received uploads request method=POST path=/api/pending_closures1229--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.34s)1230=== CONT TestReadProxyDisabled12312026/10/24 21:48:39 INFO Received uploads request method=POST path=/api/pending_closures12322026/10/24 21:48:40 WARN Force mode enabled - objects will be deleted immediately without grace period12332026/10/24 21:48:40 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=012342026/10/24 21:48:40 INFO Vacuumed table table=pending_closures12352026/10/24 21:48:40 INFO Vacuumed table table=pending_objects12362026/10/24 21:48:40 INFO Vacuumed table table=multipart_uploads12372026/10/24 21:48:40 INFO Vacuumed table table=closures12382026/10/24 21:48:40 INFO Vacuumed table table=objects12392026/10/24 21:48:40 INFO Aborted multipart uploads count=0 kept=012402026/10/24 21:48:40 WARN Force mode enabled - objects will be deleted immediately without grace period12412026/10/24 21:48:40 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=012422026/10/24 21:48:40 INFO Vacuumed table table=pending_closures12432026/10/24 21:48:40 INFO Vacuumed table table=pending_objects12442026/10/24 21:48:40 INFO Vacuumed table table=multipart_uploads12452026/10/24 21:48:40 INFO Vacuumed table table=closures12462026/10/24 21:48:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12472026/10/24 21:48:40 INFO Vacuumed table table=objects1248--- PASS: TestSweepSkipsRowsLockedByPush (0.85s)1249=== CONT TestParseSingleRange1250=== RUN TestParseSingleRange/none1251=== PAUSE TestParseSingleRange/none1252=== RUN TestParseSingleRange/unknown_unit1253=== PAUSE TestParseSingleRange/unknown_unit1254=== RUN TestParseSingleRange/multi-range_ignored1255=== PAUSE TestParseSingleRange/multi-range_ignored1256=== RUN TestParseSingleRange/malformed_no_dash1257=== PAUSE TestParseSingleRange/malformed_no_dash1258=== RUN TestParseSingleRange/malformed_both_empty1259=== PAUSE TestParseSingleRange/malformed_both_empty1260=== RUN TestParseSingleRange/malformed_end_before_start1261=== PAUSE TestParseSingleRange/malformed_end_before_start1262=== RUN TestParseSingleRange/closed1263=== PAUSE TestParseSingleRange/closed1264=== RUN TestParseSingleRange/open-ended1265=== PAUSE TestParseSingleRange/open-ended1266=== RUN TestParseSingleRange/end_clamped_to_size1267=== PAUSE TestParseSingleRange/end_clamped_to_size1268=== RUN TestParseSingleRange/suffix1269=== PAUSE TestParseSingleRange/suffix1270=== RUN TestParseSingleRange/suffix_exceeds_size1271=== PAUSE TestParseSingleRange/suffix_exceeds_size1272=== RUN TestParseSingleRange/single_byte1273=== PAUSE TestParseSingleRange/single_byte1274=== RUN TestParseSingleRange/start_past_EOF1275=== PAUSE TestParseSingleRange/start_past_EOF1276=== RUN TestParseSingleRange/start_far_past_EOF1277=== PAUSE TestParseSingleRange/start_far_past_EOF1278=== CONT TestService_verifyS3Integrity1279--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.49s)1280=== CONT TestPresentNotReportedWhileGCDeletesClosure1281=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1282=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1283=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1284=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1285=== CONT TestReadProxyRangeRequest12862026/10/24 21:48:40 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NDk1ZDM5N2YtZThjZS00NzBkLThhZDUtNTRiMWQ0NDQ3YjQyLjJhZTkwZjVhLTBiMGUtNGI1YS05N2IxLTcwZjMyNjBiMWE4MngxNzkyODc4NTE5NTAxMDE1ODc5 parts=1212872026/10/24 21:48:40 INFO Received uploads request method=POST path=/api/pending_closures1288--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.55s)1289=== CONT TestService_createPendingClosureHandler1290--- PASS: TestReadProxyDisabled (0.23s)1291=== CONT TestPresentRefreshesOnlyStaleClosures12922026/10/24 21:48:40 INFO Received cleanup request method=DELETE path=/api/pending_closures12932026/10/24 21:48:40 INFO Aborted multipart uploads count=0 kept=012942026/10/24 21:48:40 INFO Received uploads request method=POST path=/api/pending_closures12952026/10/24 21:48:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12962026/10/24 21:48:40 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1297--- PASS: TestCompleteMultipartUnregistered (0.33s)1298=== CONT TestReadRedirectKeepsNarinfoProxied12992026/10/24 21:48:40 INFO Received cleanup request method=DELETE path=/api/pending_closures1300--- PASS: TestPushWaitsForSweepHoldingRow (1.62s)1301=== CONT TestReadRedirectNar13022026/10/24 21:48:40 INFO Aborted multipart uploads count=1 kept=013032026/10/24 21:48:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13042026-10-24 21:48:40.205 UTC [703] ERROR: Closure does not exist: id=113052026-10-24 21:48:40.205 UTC [703] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE13062026-10-24 21:48:40.205 UTC [703] STATEMENT: -- name: CommitPendingClosure :one1307 SELECT commit_pending_closure($1::bigint)::bigint1308 1309--- PASS: TestService_cleanupPendingClosuresHandler (0.35s)1310=== CONT TestForceGCDuringPushOffersSweptObject1311=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1312=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1313=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1314=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1315=== CONT TestGCBugBareHashReferences13162026/10/24 21:48:40 INFO Received uploads request method=POST path=/api/pending_closures13172026/10/24 21:48:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13182026/10/24 21:48:40 INFO Received uploads request method=POST path=/api/pending_closures13192026/10/24 21:48:40 INFO Received uploads request method=POST path=/api/pending_closures13202026/10/24 21:48:40 INFO Received uploads request method=POST path=/api/pending_closures1321--- PASS: TestReadProxyRangeRequest (0.29s)1322=== CONT TestClientFallsBackToClosures13232026/10/24 21:48:40 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NDk1ZDM5N2YtZThjZS00NzBkLThhZDUtNTRiMWQ0NDQ3YjQyLjNkOTk3N2RkLTllZjktNDA1NS04ZDJkLTAxYTI0YmRkZTkwYngxNzkyODc4NTE5OTE2MzQ1OTE2 error="Get \"http://127.0.0.1:1/bucket12/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13242026/10/24 21:48:40 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=NDk1ZDM5N2YtZThjZS00NzBkLThhZDUtNTRiMWQ0NDQ3YjQyLjIwNTVjOWZhLTU0MzItNDBiNy1iNjg3LWExMGUzZGNhOGRiNXgxNzkyODc4NTE5OTAzOTc3MjQx parts=1213252026/10/24 21:48:40 INFO Received cleanup request method=DELETE path=/api/pending_closures13262026/10/24 21:48:40 INFO Aborted multipart uploads count=1 kept=01327--- PASS: TestRedundantMultipartUpload (2.59s)1328=== CONT TestClientPushesUseOnePush1329--- PASS: TestPresentRefreshesOnlyStaleClosures (0.30s)1330=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection13312026/10/24 21:48:40 INFO Received uploads request method=POST path=/api/pending_closures1332--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.60s)1333=== CONT TestGCAdvisoryLockBlocksConcurrentRun1334--- PASS: TestService_healthCheckHandler (1.92s)1335=== CONT TestObjectStatsTrigger1336=== RUN TestPush_RejectsBadRequests/no_roots1337=== PAUSE TestPush_RejectsBadRequests/no_roots1338=== RUN TestPush_RejectsBadRequests/no_objects1339=== PAUSE TestPush_RejectsBadRequests/no_objects1340=== RUN TestPush_RejectsBadRequests/bad_root1341=== PAUSE TestPush_RejectsBadRequests/bad_root1342=== RUN TestPush_RejectsBadRequests/root_not_in_objects1343=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1344=== CONT TestGCSweepDeliversEachKeyOnce13452026/10/24 21:48:40 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1346--- PASS: TestReadProxyNarinfo (0.98s)1347=== CONT TestPinProtectsFromGC1348--- PASS: TestReadProxyHead (0.82s)1349=== CONT TestTombstonedObjectOfferedWithoutWaiting1350--- PASS: TestReadProxyConditionalGet (0.93s)1351=== CONT TestCreatePin_ReservedPins1352--- PASS: TestGetExistingObjectsLocksRows (2.15s)1353=== CONT TestCacheConfigHandler1354=== RUN TestCacheConfigHandler/full_config,_no_issuer1355=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1356=== RUN TestCacheConfigHandler/no_cache_url_configured1357=== PAUSE TestCacheConfigHandler/no_cache_url_configured1358=== RUN TestCacheConfigHandler/no_signing_keys1359=== PAUSE TestCacheConfigHandler/no_signing_keys1360=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1361=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1362=== CONT TestGCSweepSkipsPendingObjects1363--- PASS: TestReadProxyContentNegotiation (1.31s)1364=== CONT TestService_ReadScope_PublicByDefault1365--- PASS: TestReadRedirectUsesPublicS3URL (1.17s)1366=== CONT TestDeduplicatedObjectsRecordedAsPending13672026/10/24 21:48:40 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39089/oidc13682026/10/24 21:48:40 INFO Received uploads request method=POST path=/api/pending_closures13692026/10/24 21:48:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13702026/10/24 21:48:40 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13712026/10/24 21:48:40 INFO Received push request method=POST path=/api/pushes13722026/10/24 21:48:40 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NDk1ZDM5N2YtZThjZS00NzBkLThhZDUtNTRiMWQ0NDQ3YjQyLjI2YWM2YmNiLTk0NGItNDU1Yi05ZmE5LTZhN2Y0MmMxNDQwYngxNzkyODc4NTIwMzU5MDA1MTY3 parts=1013732026/10/24 21:48:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13742026/10/24 21:48:40 INFO Completed upload id=1 objects=2 duration=3.496412ms13752026/10/24 21:48:40 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NDk1ZDM5N2YtZThjZS00NzBkLThhZDUtNTRiMWQ0NDQ3YjQyLmVlMTIwNjU1LTI0NTItNGVhZS1hODVkLWEwMTc3MTVjY2ZjYXgxNzkyODc4NTIwNDAxMzUxNTQw parts=1013762026/10/24 21:48:40 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13772026/10/24 21:48:40 INFO Received uploads request method=POST path=/api/pending_closures13782026/10/24 21:48:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13792026/10/24 21:48:40 INFO Signed narinfos id=1 count=113802026/10/24 21:48:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13812026/10/24 21:48:40 INFO Completed upload id=1 objects=2 duration=6.608281ms13822026/10/24 21:48:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13832026/10/24 21:48:40 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"13842026/10/24 21:48:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13852026/10/24 21:48:40 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"13862026/10/24 21:48:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13872026/10/24 21:48:40 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=113882026/10/24 21:48:40 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013892026/10/24 21:48:40 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13902026/10/24 21:48:40 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1391--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (2.28s)1392=== CONT TestService_RequireScope_OIDC13932026/10/24 21:48:40 INFO Received uploads request method=POST path=/api/pending_closures13942026/10/24 21:48:40 INFO Received uploads request method=POST path=/api/pending_closures13952026/10/24 21:48:40 INFO Starting cleanup of old closures method=DELETE path=/api/closures13962026/10/24 21:48:40 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13972026/10/24 21:48:40 WARN Found objects in DB but missing from S3, will re-upload count=11398--- PASS: TestService_verifyS3Integrity (0.76s)1399=== CONT TestPushDedupSurvivesConcurrentGC14002026/10/24 21:48:40 INFO Aborted multipart uploads count=0 kept=014012026/10/24 21:48:40 INFO Aborted multipart uploads count=0 kept=014022026/10/24 21:48:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41057/oidc14032026/10/24 21:48:41 INFO Received push request method=POST path=/api/pushes14042026/10/24 21:48:41 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14052026/10/24 21:48:41 INFO Uploading yqp8izq373s7g8i4rv9jzbv03ka6m1hz-file1.txt (160B)14062026/10/24 21:48:41 WARN Failed to register uploaded object key=yqp8izq373s7g8i4rv9jzbv03ka6m1hz.ls error="server returned 404: 404 page not found\n"14072026/10/24 21:48:41 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14082026/10/24 21:48:41 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14092026/10/24 21:48:41 INFO Signed narinfos id=1 count=114102026/10/24 21:48:41 INFO Uploading 1 narinfos14112026/10/24 21:48:41 INFO Received complete push request method=POST path=/api/pushes/1/complete14122026/10/24 21:48:41 WARN Failed to register uploaded object key=yqp8izq373s7g8i4rv9jzbv03ka6m1hz.narinfo error="server returned 404: 404 page not found\n"14132026/10/24 21:48:41 INFO Completed push id=1 objects=3 duration=13.786147ms14142026/10/24 21:48:41 INFO Upload complete. (1.013s)1415=== NAME TestNARDeduplicationMetadataUploadBug1416 metadata_upload_test.go:54: Retrieved narinfo from S3:1417 StorePath: /build/TestNARDeduplicationMetadataUploadBug2197444684/001/store/yqp8izq373s7g8i4rv9jzbv03ka6m1hz-file1.txt1418 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1419 Compression: zstd1420 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1421 NarSize: 1601422 References: 1423 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1424 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1425 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1426 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}14272026/10/24 21:48:41 INFO Aborted multipart uploads count=0 kept=01428--- PASS: TestService_ReadScope_PublicByDefault (0.63s)1429=== CONT TestService_AuthMiddleware_OIDC14302026/10/24 21:48:41 INFO Received uploads request method=POST path=/api/pending_closures14312026/10/24 21:48:41 INFO Aborted multipart uploads count=0 kept=014322026/10/24 21:48:41 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"1433--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.96s)1434=== CONT TestGCMetrics1435--- PASS: TestObjectStatsTrigger (0.96s)1436=== CONT TestService_ReadAuthMiddleware14372026/10/24 21:48:41 INFO Received uploads request method=POST path=/api/pending_closures1438--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.88s)1439=== CONT TestOrphanedObjectsGCStressTest14402026/10/24 21:48:41 INFO Received uploads request method=POST path=/api/pending_closures14412026/10/24 21:48:41 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43187/oidc1442--- PASS: TestReadRedirectNar (1.39s)1443=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14442026/10/24 21:48:41 INFO Received push request method=POST path=/api/pushes1445=== RUN TestService_RequireScope_OIDC/builder_may_write1446=== PAUSE TestService_RequireScope_OIDC/builder_may_write1447=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1448=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1449=== RUN TestService_RequireScope_OIDC/ops_may_admin1450=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1451=== RUN TestService_RequireScope_OIDC/ops_may_not_write1452=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1453=== RUN TestService_RequireScope_OIDC/reader_may_not_write1454=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1455=== RUN TestService_RequireScope_OIDC/static_token_may_admin1456=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1457=== RUN TestService_RequireScope_OIDC/static_token_may_write1458=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1459=== RUN TestService_RequireScope_OIDC/reader_may_read1460=== PAUSE TestService_RequireScope_OIDC/reader_may_read1461=== RUN TestService_RequireScope_OIDC/writer_implies_read1462=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1463=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1464=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1465=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1466=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1467=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1468=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1469=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1470=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1471=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1472=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1473=== CONT TestService_AuthMiddleware_MTLSProxyHeader14742026/10/24 21:48:41 INFO Received complete push request method=POST path=/api/pushes/1/complete14752026/10/24 21:48:41 WARN Force mode enabled - objects will be deleted immediately without grace period14762026/10/24 21:48:41 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=014772026/10/24 21:48:41 INFO Completed push id=1 objects=4 duration=54.012941ms14782026/10/24 21:48:41 INFO Received push request method=POST path=/api/pushes14792026/10/24 21:48:41 INFO Vacuumed table table=pending_closures14802026/10/24 21:48:41 INFO Vacuumed table table=pending_objects14812026/10/24 21:48:41 INFO Vacuumed table table=multipart_uploads14822026/10/24 21:48:41 INFO Vacuumed table table=closures14832026/10/24 21:48:41 INFO Vacuumed table table=objects1484--- PASS: TestGCSweepSkipsPendingObjects (1.03s)1485=== CONT TestOrphanedObjectsGC1486--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (1.33s)1487=== CONT TestCacheStatsHandler1488--- PASS: TestGCBugBareHashReferences (1.59s)1489=== CONT TestIsValidUploadKey1490=== RUN TestIsValidUploadKey/narinfo1491=== PAUSE TestIsValidUploadKey/narinfo1492=== RUN TestIsValidUploadKey/nar_zst1493=== PAUSE TestIsValidUploadKey/nar_zst1494=== RUN TestIsValidUploadKey/nar_xz1495=== PAUSE TestIsValidUploadKey/nar_xz1496=== RUN TestIsValidUploadKey/nar_plain1497=== PAUSE TestIsValidUploadKey/nar_plain1498=== RUN TestIsValidUploadKey/listing1499=== PAUSE TestIsValidUploadKey/listing1500=== RUN TestIsValidUploadKey/build_log1501=== PAUSE TestIsValidUploadKey/build_log1502=== RUN TestIsValidUploadKey/build_log_home-manager_file1503=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1504=== RUN TestIsValidUploadKey/build_log_plus_in_name1505=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1506=== RUN TestIsValidUploadKey/build_log_question_mark1507=== PAUSE TestIsValidUploadKey/build_log_question_mark1508=== RUN TestIsValidUploadKey/build_log_equals1509=== PAUSE TestIsValidUploadKey/build_log_equals1510=== RUN TestIsValidUploadKey/realisation1511=== PAUSE TestIsValidUploadKey/realisation1512=== RUN TestIsValidUploadKey/realisation_plus_in_output1513=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1514=== RUN TestIsValidUploadKey/nix-cache-info1515=== PAUSE TestIsValidUploadKey/nix-cache-info1516=== RUN TestIsValidUploadKey/index.html1517=== PAUSE TestIsValidUploadKey/index.html1518=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1519=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1520=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1521=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1522=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1523=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1524=== RUN TestIsValidUploadKey/traversal1525=== PAUSE TestIsValidUploadKey/traversal1526=== RUN TestIsValidUploadKey/traversal_nar1527=== PAUSE TestIsValidUploadKey/traversal_nar1528=== RUN TestIsValidUploadKey/absolute1529=== PAUSE TestIsValidUploadKey/absolute1530=== RUN TestIsValidUploadKey/empty_key1531=== PAUSE TestIsValidUploadKey/empty_key1532=== RUN TestIsValidUploadKey/unknown_type1533=== PAUSE TestIsValidUploadKey/unknown_type1534=== CONT TestObjectStatsLargeCommit15352026/10/24 21:48:41 INFO Aborted multipart uploads count=0 kept=015362026/10/24 21:48:41 WARN Force mode enabled - objects will be deleted immediately without grace period15372026/10/24 21:48:41 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=015382026/10/24 21:48:41 INFO Vacuumed table table=pending_closures15392026/10/24 21:48:41 INFO Vacuumed table table=pending_objects15402026/10/24 21:48:41 INFO Aborted multipart uploads count=0 kept=015412026/10/24 21:48:41 INFO Vacuumed table table=multipart_uploads15422026/10/24 21:48:41 WARN Force mode enabled - objects will be deleted immediately without grace period15432026/10/24 21:48:41 INFO Vacuumed table table=closures15442026/10/24 21:48:41 INFO Vacuumed table table=objects15452026/10/24 21:48:41 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=015462026/10/24 21:48:41 INFO Received complete push request method=POST path=/api/pushes/2/complete15472026/10/24 21:48:41 INFO Vacuumed table table=pending_closures15482026/10/24 21:48:41 INFO Vacuumed table table=pending_objects15492026/10/24 21:48:41 INFO Vacuumed table table=multipart_uploads15502026/10/24 21:48:41 INFO Vacuumed table table=closures15512026/10/24 21:48:41 INFO Vacuumed table table=objects15522026/10/24 21:48:41 INFO Completed push id=2 objects=4 duration=5.441471ms1553--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (3.28s)1554=== CONT TestClientSharedPathCommittedMidPush1555--- PASS: TestGCMetrics (0.44s)1556=== CONT TestUploadHandlersRejectInvalidKeys1557=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1558=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1559=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1560=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1561=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1562=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1563=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1564=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1565=== CONT TestClientWithDependencies1566--- PASS: TestService_ReadAuthMiddleware (0.41s)1567=== CONT TestConnectWaitsForAPeerMigration15682026/10/24 21:48:41 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=015692026/10/24 21:48:41 WARN Force mode enabled - objects will be deleted immediately without grace period15702026/10/24 21:48:41 INFO Vacuumed table table=pending_closures15712026/10/24 21:48:41 WARN Force mode enabled - objects will be deleted immediately without grace period15722026/10/24 21:48:41 INFO Received uploads request method=POST path=/api/pending_closures1573=== NAME TestNARDeduplicationMetadataUploadBug1574 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug2197444684/001/store/rvfrwcv5sahbgmg6jv3amm79k12jgcfp-file2.txt15752026/10/24 21:48:41 INFO Received uploads request method=POST path=/api/pending_closures15762026/10/24 21:48:41 INFO Received push request method=POST path=/api/pushes15772026/10/24 21:48:41 INFO Vacuumed table table=pending_objects15782026/10/24 21:48:41 INFO Vacuumed table table=multipart_uploads15792026/10/24 21:48:41 INFO Received uploads request method=POST path=/api/pending_closures1580--- PASS: TestDeduplicatedObjectsRecordedAsPending (1.17s)1581=== CONT TestClientMultipleUploads15822026/10/24 21:48:41 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15832026/10/24 21:48:41 INFO Uploading d3lnlzip6v1zwj6x026ijmdpz8gvwilq-shared-dep (136B)15842026/10/24 21:48:41 INFO Uploading d5idky4nsyapn1m5j7jbckqk0dvrdzwa-b (216B)15852026/10/24 21:48:41 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=015862026/10/24 21:48:41 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15872026/10/24 21:48:41 INFO Uploading wlfh7zryn5gagb77ws7rflihg00klv5q-a (216B)15882026/10/24 21:48:41 INFO Uploading 7f2p8pl5920anqd0rdjbi9ixm36mdi87-shared-dep (136B)15892026/10/24 21:48:41 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."15902026/10/24 21:48:41 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."15912026/10/24 21:48:41 INFO Vacuumed table table=pending_closures15922026/10/24 21:48:41 INFO Vacuumed table table=pending_objects15932026/10/24 21:48:41 INFO Vacuumed table table=multipart_uploads15942026/10/24 21:48:41 INFO Vacuumed table table=closures15952026/10/24 21:48:41 INFO Vacuumed table table=closures1596--- PASS: TestFailedS3DeleteKeepsTombstone (2.57s)1597=== CONT TestUploadHandlersRejectOversizedBody15982026/10/24 21:48:41 INFO Vacuumed table table=objects15992026/10/24 21:48:41 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001600--- PASS: TestService_createPendingClosureHandler (1.84s)1601=== CONT TestPendingCleanupUsesOneCutoff16022026/10/24 21:48:42 INFO Vacuumed table table=objects1603=== NAME TestPinProtectsFromGC1604 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1470336257/001/store/lip3dvzlddxj1szjn1agr83b8xqrh92g-pinned-file.txt1605 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1470336257/001/store/rza6qs91r0jvlgvi4mh8hhq6ignpc7sh-unpinned-file.txt1606--- PASS: TestGCSweepDeliversEachKeyOnce (1.52s)1607=== CONT TestClientIntegration16082026/10/24 21:48:42 WARN Failed to register uploaded object key=d5idky4nsyapn1m5j7jbckqk0dvrdzwa.ls error="server returned 404: 404 page not found\n"16092026/10/24 21:48:42 WARN Failed to register uploaded object key=wlfh7zryn5gagb77ws7rflihg00klv5q.ls error="server returned 404: 404 page not found\n"16102026/10/24 21:48:42 WARN Failed to register uploaded object key=9xgq3r6jsgmz73wvy3j8mx3aq608z3jl.ls error="server returned 404: 404 page not found\n"16112026/10/24 21:48:42 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16122026/10/24 21:48:42 WARN Failed to register uploaded object key=7f2p8pl5920anqd0rdjbi9ixm36mdi87.ls error="server returned 404: 404 page not found\n"1613=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1614=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1615=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16162026/10/24 21:48:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign1617=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected16182026/10/24 21:48:42 WARN Failed to register uploaded object key=nar/11hzlb04hdhwf5wpv5a9y5ssx1cfpiplqp8pi21ly79vxjgmdx08.nar.zst error="server returned 404: 404 page not found\n"1619=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected16202026/10/24 21:48:42 WARN Failed to register uploaded object key=52s70hdsgh752arxyqxyazwb24zwi0yc.ls error="server returned 404: 404 page not found\n"1621=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected16222026/10/24 21:48:42 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"1623=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured16242026/10/24 21:48:42 WARN Failed to register uploaded object key=d3lnlzip6v1zwj6x026ijmdpz8gvwilq.ls error="server returned 404: 404 page not found\n"1625=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1626=== CONT TestLeadIncumbentAnnouncesAtOnce16272026/10/24 21:48:42 INFO Signed narinfos id=1 count=316282026/10/24 21:48:42 INFO Signed narinfos id=1 count=216292026/10/24 21:48:42 INFO Uploading 3 narinfos16302026/10/24 21:48:42 WARN Failed to register uploaded object key=nar/0g0vp87k3h10p50kh2shkli5k4cfa8hd8xrll6ly1rs0bmsgyyk4.nar.zst error="server returned 404: 404 page not found\n"16312026/10/24 21:48:42 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16322026/10/24 21:48:42 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16332026/10/24 21:48:42 INFO Signed narinfos id=2 count=216342026/10/24 21:48:42 INFO Uploading 4 narinfos16352026/10/24 21:48:42 WARN Failed to register uploaded object key=d5idky4nsyapn1m5j7jbckqk0dvrdzwa.narinfo error="server returned 404: 404 page not found\n"16362026/10/24 21:48:42 WARN Failed to register uploaded object key=9xgq3r6jsgmz73wvy3j8mx3aq608z3jl.narinfo error="server returned 404: 404 page not found\n"16372026/10/24 21:48:42 WARN Failed to register uploaded object key=7f2p8pl5920anqd0rdjbi9ixm36mdi87.narinfo error="server returned 404: 404 page not found\n"16382026/10/24 21:48:42 WARN Failed to register uploaded object key=52s70hdsgh752arxyqxyazwb24zwi0yc.narinfo error="server returned 404: 404 page not found\n"16392026/10/24 21:48:42 WARN Failed to register uploaded object key=wlfh7zryn5gagb77ws7rflihg00klv5q.narinfo error="server returned 404: 404 page not found\n"16402026/10/24 21:48:42 WARN Failed to register uploaded object key=d3lnlzip6v1zwj6x026ijmdpz8gvwilq.narinfo error="server returned 404: 404 page not found\n"16412026/10/24 21:48:42 INFO Received complete push request method=POST path=/api/pushes/1/complete16422026/10/24 21:48:42 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16432026/10/24 21:48:42 WARN Failed to register uploaded object key=7f2p8pl5920anqd0rdjbi9ixm36mdi87.narinfo error="server returned 404: 404 page not found\n"16442026/10/24 21:48:42 INFO Completed push id=1 objects=8 duration=10.354976ms16452026/10/24 21:48:42 INFO Upload complete. (191ms)1646=== NAME TestClientPushesUseOnePush1647 client_pushes_test.go:97: Retrieved narinfo from S3:1648 StorePath: /build/TestClientPushesUseOnePush2514213782/001/store/d3lnlzip6v1zwj6x026ijmdpz8gvwilq-shared-dep1649 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1650 Compression: zstd1651 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821652 NarSize: 1361653 References: 1654 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n16552026/10/24 21:48:42 INFO Completed upload id=1 objects=6 duration=10.120893ms16562026/10/24 21:48:42 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16572026/10/24 21:48:42 INFO Completed upload id=2 objects=6 duration=2.772485ms16582026/10/24 21:48:42 INFO Upload complete. (199ms)16592026/10/24 21:48:42 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"16602026/10/24 21:48:42 WARN mTLS auth: bound subjects configured but subject DN unavailable16612026/10/24 21:48:42 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1662--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.48s)1663=== CONT TestNativeOIDCLoginPushRefresh1664=== RUN TestNativeOIDCLoginPushRefresh/new-id-token1665=== PAUSE TestNativeOIDCLoginPushRefresh/new-id-token1666=== RUN TestNativeOIDCLoginPushRefresh/omitted-id-token1667=== PAUSE TestNativeOIDCLoginPushRefresh/omitted-id-token1668=== CONT TestClientErrorHandling1669=== RUN TestClientErrorHandling/InvalidStorePath1670=== PAUSE TestClientErrorHandling/InvalidStorePath1671=== RUN TestClientErrorHandling/InvalidAuthToken1672=== PAUSE TestClientErrorHandling/InvalidAuthToken1673=== RUN TestClientErrorHandling/ServerNotAvailable1674=== PAUSE TestClientErrorHandling/ServerNotAvailable1675=== CONT TestLeadElectsOneAndHandsOver1676=== NAME TestClientPushesUseOnePush1677 client_pushes_test.go:97: Retrieved narinfo from S3:1678 StorePath: /build/TestClientPushesUseOnePush2514213782/001/store/9xgq3r6jsgmz73wvy3j8mx3aq608z3jl-a1679 URL: nar/0g0vp87k3h10p50kh2shkli5k4cfa8hd8xrll6ly1rs0bmsgyyk4.nar.zst1680 Compression: zstd1681 NarHash: sha256:0g0vp87k3h10p50kh2shkli5k4cfa8hd8xrll6ly1rs0bmsgyyk41682 NarSize: 2161683 References: /build/TestClientPushesUseOnePush2514213782/001/store/d3lnlzip6v1zwj6x026ijmdpz8gvwilq-shared-dep1684 CA: text:sha256:1ynrzq0508vb41ildx33xypqd8s0kn35832556h54vk7x5x4xib31685=== NAME TestClientFallsBackToClosures1686 client_pushes_test.go:112: Retrieved narinfo from S3:1687 StorePath: /build/TestClientFallsBackToClosures2647387321/001/store/7f2p8pl5920anqd0rdjbi9ixm36mdi87-shared-dep1688 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1689 Compression: zstd1690 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821691 NarSize: 1361692 References: 1693 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1694 client_pushes_test.go:112: Retrieved narinfo from S3:1695 StorePath: /build/TestClientFallsBackToClosures2647387321/001/store/wlfh7zryn5gagb77ws7rflihg00klv5q-a1696 URL: nar/11hzlb04hdhwf5wpv5a9y5ssx1cfpiplqp8pi21ly79vxjgmdx08.nar.zst1697 Compression: zstd1698 NarHash: sha256:11hzlb04hdhwf5wpv5a9y5ssx1cfpiplqp8pi21ly79vxjgmdx081699 NarSize: 2161700 References: /build/TestClientFallsBackToClosures2647387321/001/store/7f2p8pl5920anqd0rdjbi9ixm36mdi87-shared-dep1701 CA: text:sha256:1yj6xzb65zmym2sm53sdwj2rfhznxgdmgqkkw8pdaxnsnzjmv2jp1702=== NAME TestClientPushesUseOnePush1703 client_pushes_test.go:97: Retrieved narinfo from S3:1704 StorePath: /build/TestClientPushesUseOnePush2514213782/001/store/d5idky4nsyapn1m5j7jbckqk0dvrdzwa-b1705 URL: nar/0g0vp87k3h10p50kh2shkli5k4cfa8hd8xrll6ly1rs0bmsgyyk4.nar.zst1706 Compression: zstd1707 NarHash: sha256:0g0vp87k3h10p50kh2shkli5k4cfa8hd8xrll6ly1rs0bmsgyyk41708 NarSize: 2161709 References: /build/TestClientPushesUseOnePush2514213782/001/store/d3lnlzip6v1zwj6x026ijmdpz8gvwilq-shared-dep1710 CA: text:sha256:1ynrzq0508vb41ildx33xypqd8s0kn35832556h54vk7x5x4xib31711=== NAME TestClientFallsBackToClosures1712 client_pushes_test.go:112: Retrieved narinfo from S3:1713 StorePath: /build/TestClientFallsBackToClosures2647387321/001/store/52s70hdsgh752arxyqxyazwb24zwi0yc-b1714 URL: nar/11hzlb04hdhwf5wpv5a9y5ssx1cfpiplqp8pi21ly79vxjgmdx08.nar.zst1715 Compression: zstd1716 NarHash: sha256:11hzlb04hdhwf5wpv5a9y5ssx1cfpiplqp8pi21ly79vxjgmdx081717 NarSize: 2161718 References: /build/TestClientFallsBackToClosures2647387321/001/store/7f2p8pl5920anqd0rdjbi9ixm36mdi87-shared-dep1719 CA: text:sha256:1yj6xzb65zmym2sm53sdwj2rfhznxgdmgqkkw8pdaxnsnzjmv2jp1720--- PASS: TestClientPushesUseOnePush (1.66s)1721=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1722--- PASS: TestClientFallsBackToClosures (1.69s)1723=== CONT TestClientCADerivations1724--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.48s)1725=== CONT TestResolveDBConnectionString1726=== RUN TestResolveDBConnectionString/flag_wins1727=== PAUSE TestResolveDBConnectionString/flag_wins1728=== RUN TestResolveDBConnectionString/file_when_flag_empty1729=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1730=== RUN TestResolveDBConnectionString/missing_file_is_an_error1731=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1732=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1733=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1734=== RUN TestResolveDBConnectionString/nothing_configured1735=== PAUSE TestResolveDBConnectionString/nothing_configured1736=== CONT TestMultipartCleanup1737=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1738=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1739=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1740=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1741=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1742=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1743=== CONT TestLeadEndsOnShutdown17442026/10/24 21:48:42 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux17452026/10/24 21:48:42 WARN Refused reserved pin name=worker-x86_64-linux1746--- PASS: TestCacheStatsHandler (0.39s)1747=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded17482026/10/24 21:48:42 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux17492026/10/24 21:48:42 INFO Received create pin request method=POST path=/api/pins/my-app17502026/10/24 21:48:42 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1751--- PASS: TestCreatePin_ReservedPins (1.53s)1752=== CONT TestPendingClosureWriteTimeout1753=== RUN TestPendingClosureWriteTimeout/empty1754=== PAUSE TestPendingClosureWriteTimeout/empty1755=== RUN TestPendingClosureWriteTimeout/400_objects1756=== PAUSE TestPendingClosureWriteTimeout/400_objects1757=== RUN TestPendingClosureWriteTimeout/670k_objects1758=== PAUSE TestPendingClosureWriteTimeout/670k_objects1759=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1760=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1761=== CONT TestProxyWriteTimeout1762=== RUN TestProxyWriteTimeout/narinfo1763=== PAUSE TestProxyWriteTimeout/narinfo1764=== RUN TestProxyWriteTimeout/1_GiB_nar1765=== PAUSE TestProxyWriteTimeout/1_GiB_nar1766=== RUN TestProxyWriteTimeout/10_GiB_nar1767=== PAUSE TestProxyWriteTimeout/10_GiB_nar1768=== RUN TestProxyWriteTimeout/unknown_size1769=== PAUSE TestProxyWriteTimeout/unknown_size1770=== CONT TestDeleteClosuresRacingPins17712026/10/24 21:48:42 INFO Received uploads request method=POST path=/api/pending_closures17722026/10/24 21:48:42 INFO Received push request method=POST path=/api/pushes1773--- PASS: TestReadRedirectKeepsNarinfoProxied (2.07s)1774=== CONT TestServerTLSConfig/no_client_CA1775=== CONT TestGCEndsOnShutdown/before_the_run17762026/10/24 21:48:42 INFO Aborted multipart uploads count=0 kept=017772026-10-24 21:48:42.589 UTC [1122] ERROR: Push does not exist: id=117782026-10-24 21:48:42.589 UTC [1122] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE17792026-10-24 21:48:42.589 UTC [1122] STATEMENT: SELECT commit_push($1)1780--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (3.51s)1781=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17822026/10/24 21:48:42 INFO Received push request method=POST path=/api/pushes17832026/10/24 21:48:42 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=017842026/10/24 21:48:42 INFO Vacuumed table table=pending_closures17852026/10/24 21:48:42 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17862026/10/24 21:48:42 INFO Vacuumed table table=pending_objects17872026/10/24 21:48:42 INFO Vacuumed table table=multipart_uploads17882026/10/24 21:48:42 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17892026/10/24 21:48:42 INFO Signed narinfos id=2 count=117902026/10/24 21:48:42 WARN Failed to register uploaded object key=rvfrwcv5sahbgmg6jv3amm79k12jgcfp.ls error="server returned 404: 404 page not found\n"17912026/10/24 21:48:42 INFO Uploading 1 narinfos17922026/10/24 21:48:42 INFO Received complete push request method=POST path=/api/pushes/2/complete17932026/10/24 21:48:42 WARN Failed to register uploaded object key=rvfrwcv5sahbgmg6jv3amm79k12jgcfp.narinfo error="server returned 404: 404 page not found\n"17942026/10/24 21:48:42 INFO Completed push id=2 objects=3 duration=22.180227ms17952026/10/24 21:48:42 INFO Upload complete. (767ms)17962026/10/24 21:48:42 INFO Vacuumed table table=closures1797=== NAME TestNARDeduplicationMetadataUploadBug1798 metadata_upload_test.go:76: Retrieved narinfo from S3:1799 StorePath: /build/TestNARDeduplicationMetadataUploadBug2197444684/001/store/rvfrwcv5sahbgmg6jv3amm79k12jgcfp-file2.txt1800 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1801 Compression: zstd1802 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1803 NarSize: 1601804 References: 1805 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf18062026/10/24 21:48:42 INFO Vacuumed table table=objects1807 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1808 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1809 {"version":1,"root":{"type":"regular","size":44}}1810--- PASS: TestNARDeduplicationMetadataUploadBug (4.24s)1811=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1812=== NAME TestOrphanedObjectsGC1813 orphaned_objects_gc_test.go:287: GC Test Summary:1814 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1815 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1816 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1817 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1818 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1819--- PASS: TestOrphanedObjectsGC (1.07s)1820=== CONT TestServerTLSConfig/missing_CA_file1821=== CONT TestServerTLSConfig/not_a_PEM_file1822--- PASS: TestServerTLSConfig (0.00s)1823 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1824 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1825 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1826=== CONT TestIsValidCachePath/narinfo1827=== CONT TestIsValidCachePath/index.html1828=== CONT TestIsValidCachePath/short_hash1829=== CONT TestIsValidCachePath/wrong_extension1830=== CONT TestIsValidCachePath/leading_slash1831=== CONT TestIsValidCachePath/empty1832=== CONT TestIsValidCachePath/random_path1833=== CONT TestIsValidCachePath/invalid_char_u1834=== CONT TestIsValidCachePath/invalid_char_e1835=== CONT TestIsValidCachePath/traversal_in_middle1836=== CONT TestIsValidCachePath/traversal_parent1837=== CONT TestIsValidCachePath/nar_uncompressed1838=== CONT TestIsValidCachePath/nix-cache-info1839=== CONT TestIsValidCachePath/realisation1840=== CONT TestIsValidCachePath/log1841=== CONT TestIsValidCachePath/ls1842=== CONT TestIsValidCachePath/nar_xz1843=== CONT TestIsValidCachePath/nar_bz21844=== CONT TestIsValidCachePath/nar_zst1845=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1846--- PASS: TestIsValidCachePath (0.00s)1847 --- PASS: TestIsValidCachePath/narinfo (0.00s)1848 --- PASS: TestIsValidCachePath/index.html (0.00s)1849 --- PASS: TestIsValidCachePath/short_hash (0.00s)1850 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1851 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1852 --- PASS: TestIsValidCachePath/empty (0.00s)1853 --- PASS: TestIsValidCachePath/random_path (0.00s)1854 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1855 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1856 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1857 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1858 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1859 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1860 --- PASS: TestIsValidCachePath/realisation (0.00s)1861 --- PASS: TestIsValidCachePath/log (0.00s)1862 --- PASS: TestIsValidCachePath/ls (0.00s)1863 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1864 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1865 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1866 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1867=== CONT TestParseSingleRange/none1868=== CONT TestParseSingleRange/suffix_exceeds_size1869=== CONT TestParseSingleRange/suffix1870=== CONT TestParseSingleRange/end_clamped_to_size1871=== CONT TestParseSingleRange/open-ended1872=== CONT TestParseSingleRange/closed1873=== CONT TestParseSingleRange/malformed_end_before_start1874=== CONT TestParseSingleRange/malformed_both_empty1875=== CONT TestParseSingleRange/malformed_no_dash1876=== CONT TestParseSingleRange/single_byte1877=== CONT TestParseSingleRange/multi-range_ignored1878=== CONT TestParseSingleRange/unknown_unit1879=== CONT TestParseSingleRange/start_far_past_EOF1880=== CONT TestParseSingleRange/start_past_EOF1881--- PASS: TestParseSingleRange (0.00s)1882 --- PASS: TestParseSingleRange/none (0.00s)1883 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1884 --- PASS: TestParseSingleRange/suffix (0.00s)1885 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1886 --- PASS: TestParseSingleRange/open-ended (0.00s)1887 --- PASS: TestParseSingleRange/closed (0.00s)1888 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1889 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1890 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1891 --- PASS: TestParseSingleRange/single_byte (0.00s)1892 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1893 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1894 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1895 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1896=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh18972026/10/24 21:48:42 INFO Aborted multipart uploads count=0 kept=018982026/10/24 21:48:42 WARN Force mode enabled - objects will be deleted immediately without grace period18992026/10/24 21:48:42 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=019002026/10/24 21:48:42 INFO Vacuumed table table=pending_closures19012026/10/24 21:48:42 INFO Vacuumed table table=pending_objects19022026/10/24 21:48:42 INFO Vacuumed table table=multipart_uploads19032026/10/24 21:48:42 INFO Vacuumed table table=closures19042026/10/24 21:48:42 INFO Vacuumed table table=objects1905--- PASS: TestPushDedupSurvivesConcurrentGC (2.03s)1906=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1907=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows19082026/10/24 21:48:42 INFO Aborted multipart uploads count=0 kept=019092026/10/24 21:48:42 INFO Received uploads request method=POST path=/api/pending_closures19102026/10/24 21:48:42 INFO Received uploads request method=POST path=/api/pending_closures1911--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.86s)1912=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19132026/10/24 21:48:43 INFO lead: acquired remote=192.0.2.1:123419142026/10/24 21:48:43 INFO lead: acquired remote=192.0.2.1:123419152026/10/24 21:48:43 INFO lead: released remote=192.0.2.1:12341916--- PASS: TestLeadIncumbentAnnouncesAtOnce (1.02s)1917=== CONT TestPush_RejectsBadRequests/no_roots19182026/10/24 21:48:43 INFO Received push request method=POST path=/api/pushes1919=== CONT TestPush_RejectsBadRequests/bad_root19202026/10/24 21:48:43 INFO Received push request method=POST path=/api/pushes1921=== CONT TestPush_RejectsBadRequests/root_not_in_objects19222026/10/24 21:48:43 INFO Received push request method=POST path=/api/pushes1923=== CONT TestPush_RejectsBadRequests/no_objects19242026/10/24 21:48:43 INFO Received push request method=POST path=/api/pushes1925=== CONT TestCacheConfigHandler/full_config,_no_issuer1926--- PASS: TestPush_RejectsBadRequests (1.94s)1927 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1928 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1929 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1930 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1931=== CONT TestCacheConfigHandler/no_signing_keys1932=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1933=== CONT TestCacheConfigHandler/no_cache_url_configured1934--- PASS: TestCacheConfigHandler (0.00s)1935 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1936 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1937 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1938 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1939=== CONT TestService_RequireScope_OIDC/builder_may_write1940=== CONT TestService_RequireScope_OIDC/reader_may_read1941=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1942=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19432026/10/24 21:48:43 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]1944=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1945=== CONT TestService_RequireScope_OIDC/writer_implies_read1946=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1947=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1948=== CONT TestService_RequireScope_OIDC/reader_may_not_write1949=== CONT TestService_RequireScope_OIDC/static_token_may_write1950=== CONT TestService_RequireScope_OIDC/static_token_may_admin1951=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1952=== CONT TestService_RequireScope_OIDC/ops_may_not_write1953=== CONT TestService_RequireScope_OIDC/ops_may_admin1954--- PASS: TestService_RequireScope_OIDC (0.78s)1955 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)1956 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1957 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1958 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1959 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1960 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1961 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1962 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1963 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1964 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1965 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1966 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1967 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1968 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1969=== CONT TestIsValidUploadKey/narinfo1970=== CONT TestIsValidUploadKey/realisation_plus_in_output1971=== CONT TestIsValidUploadKey/unknown_type1972=== CONT TestIsValidUploadKey/empty_key1973=== CONT TestIsValidUploadKey/absolute1974=== CONT TestIsValidUploadKey/traversal_nar1975=== CONT TestIsValidUploadKey/traversal1976=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1977=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1978=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1979=== CONT TestIsValidUploadKey/index.html1980=== CONT TestIsValidUploadKey/nix-cache-info1981=== CONT TestIsValidUploadKey/build_log_home-manager_file1982=== CONT TestIsValidUploadKey/realisation1983=== CONT TestIsValidUploadKey/build_log_equals1984=== CONT TestIsValidUploadKey/build_log_question_mark1985=== CONT TestIsValidUploadKey/build_log_plus_in_name1986=== CONT TestIsValidUploadKey/nar_plain1987=== CONT TestIsValidUploadKey/build_log1988=== CONT TestIsValidUploadKey/listing1989=== CONT TestIsValidUploadKey/nar_xz1990=== CONT TestIsValidUploadKey/nar_zst1991--- PASS: TestIsValidUploadKey (0.00s)1992 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1993 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1994 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1995 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1996 --- PASS: TestIsValidUploadKey/absolute (0.00s)1997 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1998 --- PASS: TestIsValidUploadKey/traversal (0.00s)1999 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2000 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2001 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2002 --- PASS: TestIsValidUploadKey/index.html (0.00s)2003 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2004 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2005 --- PASS: TestIsValidUploadKey/realisation (0.00s)2006 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2007 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2008 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2009 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2010 --- PASS: TestIsValidUploadKey/build_log (0.00s)2011 --- PASS: TestIsValidUploadKey/listing (0.00s)2012 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2013 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2014=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info20152026/10/24 21:48:43 INFO Received uploads request method=POST path=/2016=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key20172026/10/24 21:48:43 INFO Received complete multipart upload request method=POST path=/2018=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20192026/10/24 21:48:43 INFO Received uploads request method=POST path=/2020=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key20212026/10/24 21:48:43 INFO Received request for more parts method=POST path=/2022--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2023 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2024 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2025 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2026 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2027=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2028=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20292026/10/24 21:48:43 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]2030=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2031=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20322026/10/24 21:48:43 WARN Authentication failed token_preview=eyJhbGciOi...OQFRaXIGHg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2033=== CONT TestNativeOIDCLoginPushRefresh/new-id-token2034--- PASS: TestService_AuthMiddleware_OIDC (0.67s)2035 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2036 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2037 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2038 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20392026/10/24 21:48:43 INFO lead: acquired remote=192.0.2.1:123420402026/10/24 21:48:43 INFO Received cleanup request method=DELETE path=/api/pending_closures20412026/10/24 21:48:43 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket82/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""20422026/10/24 21:48:43 INFO Aborted multipart uploads count=0 kept=120432026/10/24 21:48:43 INFO Received cleanup request method=DELETE path=/api/pending_closures20442026/10/24 21:48:43 INFO Aborted multipart uploads count=1 kept=02045--- PASS: TestMultipartCleanup (1.02s)2046=== CONT TestNativeOIDCLoginPushRefresh/omitted-id-token20472026/10/24 21:48:43 INFO Received uploads request method=POST path=/api/pending_closures20482026/10/24 21:48:43 INFO Received uploads request method=POST path=/api/pending_closures20492026/10/24 21:48:43 INFO OIDC provider initialized name=native issuer=http://127.0.0.1:3389720502026/10/24 21:48:43 INFO Received cleanup request method=DELETE path=/api/pending_closures20512026/10/24 21:48:43 INFO OIDC provider initialized name=native issuer=http://127.0.0.1:3369520522026/10/24 21:48:43 WARN Force mode enabled - objects will be deleted immediately without grace period20532026/10/24 21:48:43 INFO Received push request method=POST path=/api/pushes20542026/10/24 21:48:43 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)20552026/10/24 21:48:43 INFO Uploading lip3dvzlddxj1szjn1agr83b8xqrh92g-pinned-file.txt (128B)2056=== NAME TestClientIntegration2057 client_integration_test.go:286: Created store path: /build/TestClientIntegration116220055/002/store/dwngnvmlhx5m2w3gs8w5w4rbvzq104cb-test-file.txt2058=== NAME TestClientMultipleUploads2059 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads198854184/001/store/ww7ccli6938njmrcl50r31840pzn4v00-test-file-0.txt20602026/10/24 21:48:43 WARN Failed to register uploaded object key=lip3dvzlddxj1szjn1agr83b8xqrh92g.ls error="server returned 404: 404 page not found\n"2061=== CONT TestClientErrorHandling/InvalidStorePath20622026/10/24 21:48:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign20632026/10/24 21:48:43 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"20642026/10/24 21:48:43 INFO Signed narinfos id=1 count=120652026/10/24 21:48:43 INFO Uploading 1 narinfos20662026/10/24 21:48:43 INFO Received complete push request method=POST path=/api/pushes/1/complete20672026/10/24 21:48:43 WARN Failed to register uploaded object key=lip3dvzlddxj1szjn1agr83b8xqrh92g.narinfo error="server returned 404: 404 page not found\n"20682026/10/24 21:48:43 INFO Completed push id=1 objects=3 duration=11.583387ms20692026/10/24 21:48:43 INFO Upload complete. (914ms)2070--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.58s)2071=== CONT TestClientErrorHandling/ServerNotAvailable20722026/10/24 21:48:43 INFO Aborted multipart uploads count=0 kept=020732026/10/24 21:48:43 INFO Received uploads request method=POST path=/api/pending_closures20742026/10/24 21:48:43 INFO Aborted multipart uploads count=0 kept=020752026/10/24 21:48:43 INFO Received uploads request method=POST path=/api/pending_closures20762026/10/24 21:48:43 INFO Aborted multipart uploads count=0 kept=02077=== NAME TestOrphanedObjectsGCStressTest2078 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains20792026/10/24 21:48:44 INFO lead: released remote=192.0.2.1:12342080--- PASS: TestLeadEndsOnShutdown (1.98s)2081=== CONT TestClientErrorHandling/InvalidAuthToken2082=== NAME TestOrphanedObjectsGCStressTest2083 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2084=== CONT TestResolveDBConnectionString/flag_wins2085=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2086=== CONT TestResolveDBConnectionString/nothing_configured2087=== CONT TestResolveDBConnectionString/missing_file_is_an_error2088=== CONT TestResolveDBConnectionString/file_when_flag_empty2089=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20902026/10/24 21:48:44 INFO Received request for more parts method=POST path=/2091--- PASS: TestResolveDBConnectionString (0.00s)2092 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2093 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2094 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2095 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2096 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)20972026/10/24 21:48:44 INFO lead: released remote=192.0.2.1:12342098=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20992026/10/24 21:48:44 INFO Received complete multipart upload request method=POST path=/2100--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2101 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (1.33s)2102 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (1.47s)2103=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure21042026/10/24 21:48:44 INFO Received uploads request method=POST path=/21052026/10/24 21:48:44 INFO lead: acquired remote=192.0.2.1:12342106=== CONT TestPendingClosureWriteTimeout/empty2107=== CONT TestPendingClosureWriteTimeout/670k_objects2108=== CONT TestPendingClosureWriteTimeout/400_objects2109=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline2110=== NAME TestOrphanedObjectsGCStressTest2111 orphaned_objects_gc_test.go:503: Stress test completed successfully:2112 orphaned_objects_gc_test.go:504: - Active objects preserved: 202113 orphaned_objects_gc_test.go:505: - Objects deleted: 2102114 orphaned_objects_gc_test.go:506: - Total GC'd: 2102115--- PASS: TestOrphanedObjectsGCStressTest (2.96s)2116=== CONT TestProxyWriteTimeout/narinfo2117=== CONT TestProxyWriteTimeout/10_GiB_nar2118=== CONT TestProxyWriteTimeout/1_GiB_nar2119=== CONT TestProxyWriteTimeout/unknown_size2120--- PASS: TestProxyWriteTimeout (0.00s)2121 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2122 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2123 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2124 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)21252026/10/24 21:48:45 WARN lead: lock connection lost error="timeout: context already done: context deadline exceeded"21262026/10/24 21:48:45 INFO lead: released remote=192.0.2.1:12342127=== NAME TestLeadElectsOneAndHandsOver2128 farm_test.go:130: lead stream closed2129--- FAIL: TestLeadElectsOneAndHandsOver (3.79s)2130=== NAME TestClientCADerivations2131 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations4237447721/001/store/407mnpqfcb7vli156vibidms02rlqxmp-ca-test2132=== NAME TestClientWithDependencies2133 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2499347294/001/store/cdn02kny3hy22h8f3vpa17mh57aljzhn-test-script21342026/10/24 21:48:45 WARN Rate limiter enabled after throttle name=s3-test rate=521352026/10/24 21:48:45 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2136=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2137 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102138 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002139--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (8.04s)2140--- PASS: TestReadProxyOutlastsServerWriteTimeout (6.17s)21412026/10/24 21:48:45 WARN Force mode enabled - objects will be deleted immediately without grace period21422026/10/24 21:48:45 WARN Force mode enabled - objects will be deleted immediately without grace period21432026/10/24 21:48:45 WARN Force mode enabled - objects will be deleted immediately without grace period21442026/10/24 21:48:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=02145=== NAME TestClientMultipleUploads2146 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads198854184/001/store/mv0716jybbk4wd579d4ib4cmk49n2d6q-test-file-1.txt21472026/10/24 21:48:45 INFO Vacuumed table table=pending_closures21482026/10/24 21:48:45 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:43333/bucket93/?delete=\": context canceled"2149--- PASS: TestGCEndsOnShutdown (0.00s)2150 --- PASS: TestGCEndsOnShutdown/before_the_run (0.65s)2151 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (1.04s)2152 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (3.08s)21532026/10/24 21:48:45 INFO Vacuumed table table=pending_objects21542026/10/24 21:48:45 INFO Vacuumed table table=multipart_uploads21552026/10/24 21:48:45 INFO Vacuumed table table=closures21562026/10/24 21:48:45 INFO Vacuumed table table=objects21572026/10/24 21:48:45 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=1 objects-deleted-after-grace-period=1 objects-failed-to-delete=021582026/10/24 21:48:45 INFO Vacuumed table table=pending_closures21592026/10/24 21:48:45 INFO Vacuumed table table=pending_objects21602026/10/24 21:48:45 INFO Vacuumed table table=multipart_uploads21612026/10/24 21:48:45 INFO Vacuumed table table=closures21622026/10/24 21:48:45 INFO Vacuumed table table=objects2163--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2164 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (2.91s)2165 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (3.02s)21662026/10/24 21:48:45 INFO Received uploads request method=POST path=/api/pending_closures2167--- PASS: TestUploadHandlersRejectOversizedBody (0.19s)2168 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.08s)2169 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)2170 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (2.16s)21712026/10/24 21:48:46 INFO Received push request method=POST path=/api/pushes2172=== NAME TestClientMultipleUploads2173 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads198854184/001/store/13z1l77dq00fyywqgm5lnfgznb9k8y1s-test-file-2.txt2174=== NAME TestClientWithDependencies2175 client_integration_test.go:615: Found 1 dependencies (including self)21762026/10/24 21:48:46 INFO Received push request method=POST path=/api/pushes21772026/10/24 21:48:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21782026/10/24 21:48:46 INFO Uploading rza6qs91r0jvlgvi4mh8hhq6ignpc7sh-unpinned-file.txt (128B)21792026/10/24 21:48:46 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21802026/10/24 21:48:46 INFO Uploading dwngnvmlhx5m2w3gs8w5w4rbvzq104cb-test-file.txt (152B)21812026/10/24 21:48:46 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"2182=== NAME TestClientCADerivations2183 client_ca_test.go:139: Found 1 dependencies (including self)21842026/10/24 21:48:46 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign21852026/10/24 21:48:46 WARN Failed to register uploaded object key=rza6qs91r0jvlgvi4mh8hhq6ignpc7sh.ls error="server returned 404: 404 page not found\n"21862026/10/24 21:48:46 INFO Signed narinfos id=2 count=121872026/10/24 21:48:46 INFO Uploading 1 narinfos21882026/10/24 21:48:46 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21892026/10/24 21:48:46 WARN Failed to register uploaded object key=dwngnvmlhx5m2w3gs8w5w4rbvzq104cb.ls error="server returned 404: 404 page not found\n"21902026/10/24 21:48:46 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign21912026/10/24 21:48:46 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"21922026/10/24 21:48:46 INFO Signed narinfos id=1 count=121932026/10/24 21:48:46 INFO Uploading 1 narinfos21942026/10/24 21:48:46 INFO Received complete push request method=POST path=/api/pushes/2/complete21952026/10/24 21:48:46 WARN Failed to register uploaded object key=rza6qs91r0jvlgvi4mh8hhq6ignpc7sh.narinfo error="server returned 404: 404 page not found\n"21962026/10/24 21:48:46 INFO Received complete push request method=POST path=/api/pushes/1/complete21972026/10/24 21:48:46 WARN Failed to register uploaded object key=dwngnvmlhx5m2w3gs8w5w4rbvzq104cb.narinfo error="server returned 404: 404 page not found\n"21982026/10/24 21:48:46 INFO Completed push id=2 objects=3 duration=12.94356ms21992026/10/24 21:48:46 INFO Upload complete. (769ms)22002026/10/24 21:48:46 INFO Completed push id=1 objects=3 duration=11.598188ms22012026/10/24 21:48:46 INFO Upload complete. (770ms)22022026/10/24 21:48:46 WARN Request failed, retrying attempt=2 backoff=211.221479ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2203--- PASS: TestPendingClosureWriteTimeout (0.00s)2204 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2205 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2206 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2207 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (2.42s)22082026/10/24 21:48:46 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2209--- PASS: TestObjectStatsLargeCommit (5.04s)22102026/10/24 21:48:46 WARN Request failed, retrying attempt=3 backoff=366.225578ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22112026/10/24 21:48:47 WARN Request failed, retrying attempt=4 backoff=815.984101ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22122026/10/24 21:48:47 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22132026/10/24 21:48:47 INFO All 1 paths already cached2214=== NAME TestClientIntegration2215 client_integration_test.go:312: Retrieved narinfo from S3:2216 StorePath: /build/TestClientIntegration116220055/002/store/dwngnvmlhx5m2w3gs8w5w4rbvzq104cb-test-file.txt2217 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst2218 Compression: zstd2219 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12220 NarSize: 1522221 References: 2222 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk12223--- PASS: TestConnectWaitsForAPeerMigration (5.57s)2224=== NAME TestClientIntegration2225 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)2226 client_integration_test.go:313: Decompressed .ls content (64 bytes):2227 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}2228 client_integration_test.go:316: Testing garbage collection...22292026/10/24 21:48:47 INFO Starting cleanup of old closures method=DELETE path=/api/closures22302026/10/24 21:48:47 INFO Garbage collection started22312026/10/24 21:48:47 INFO Aborted multipart uploads count=0 kept=022322026/10/24 21:48:48 WARN Request failed, retrying attempt=5 backoff=1.52770373s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22332026-10-24 21:48:48.371 UTC [228] LOG: checkpoints are occurring too frequently (25 seconds apart)22342026-10-24 21:48:48.371 UTC [228] HINT: Consider increasing the configuration parameter "max_wal_size".22352026-10-24 21:48:48.371 UTC [228] LOG: checkpoint starting: wal22362026/10/24 21:48:48 INFO Received push request method=POST path=/api/pushes22372026/10/24 21:48:48 INFO Received push request method=POST path=/api/pushes22382026/10/24 21:48:48 INFO Received push request method=POST path=/api/pushes22392026/10/24 21:48:48 WARN Force mode enabled - objects will be deleted immediately without grace period22402026/10/24 21:48:48 INFO Starting cleanup of old closures method=DELETE path=/api/closures22412026/10/24 21:48:48 INFO Received push request method=POST path=/api/pushes22422026/10/24 21:48:48 INFO Garbage collection started22432026/10/24 21:48:48 INFO Received push request method=POST path=/api/pushes22442026/10/24 21:48:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22452026/10/24 21:48:48 INFO Uploading 0p4npbszvsrnlvjmvq6dx13za3j0sh0j-native-oidc-0 (128B)22462026/10/24 21:48:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22472026/10/24 21:48:48 INFO Uploading 5yfiz8ii53wqyjygfcgsv95kwiwrmixq-native-oidc-0 (128B)22482026/10/24 21:48:48 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)22492026/10/24 21:48:48 INFO Uploading 7grx2mxaqn7m18g73fcdfjk5pi3ccbvx-shared-dep (136B)22502026/10/24 21:48:48 INFO Uploading na09j54xcq12sjaqagv03j0p3s5pkxsb-top (224B)22512026/10/24 21:48:48 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)22522026/10/24 21:48:48 INFO Uploading mv0716jybbk4wd579d4ib4cmk49n2d6q-test-file-1.txt (160B)22532026/10/24 21:48:48 INFO Uploading ww7ccli6938njmrcl50r31840pzn4v00-test-file-0.txt (160B)22542026/10/24 21:48:48 INFO Uploading 13z1l77dq00fyywqgm5lnfgznb9k8y1s-test-file-2.txt (160B)22552026/10/24 21:48:48 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)22562026/10/24 21:48:48 INFO Uploading cdn02kny3hy22h8f3vpa17mh57aljzhn-test-script (136B)22572026/10/24 21:48:48 INFO Aborted multipart uploads count=0 kept=022582026/10/24 21:48:48 WARN Failed to register uploaded object key=0p4npbszvsrnlvjmvq6dx13za3j0sh0j.ls error="server returned 404: 404 page not found\n"22592026/10/24 21:48:48 WARN Failed to register uploaded object key=5yfiz8ii53wqyjygfcgsv95kwiwrmixq.ls error="server returned 404: 404 page not found\n"22602026/10/24 21:48:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22612026/10/24 21:48:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22622026/10/24 21:48:48 INFO Signed narinfos id=1 count=122632026/10/24 21:48:48 INFO Signed narinfos id=1 count=122642026/10/24 21:48:48 INFO Uploading 1 narinfos22652026/10/24 21:48:48 INFO Uploading 1 narinfos22662026/10/24 21:48:48 WARN Failed to register uploaded object key=na09j54xcq12sjaqagv03j0p3s5pkxsb.ls error="server returned 404: 404 page not found\n"22672026/10/24 21:48:48 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"22682026/10/24 21:48:48 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"22692026/10/24 21:48:48 WARN Failed to register uploaded object key=nar/1zqdmdn64v565qmxazzb3j30v9w6n4larl6myp39zp1b0bip12aj.nar.zst error="server returned 404: 404 page not found\n"22702026/10/24 21:48:48 WARN Failed to register uploaded object key=7grx2mxaqn7m18g73fcdfjk5pi3ccbvx.ls error="server returned 404: 404 page not found\n"22712026/10/24 21:48:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22722026/10/24 21:48:48 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"22732026/10/24 21:48:48 WARN Failed to register uploaded object key=ww7ccli6938njmrcl50r31840pzn4v00.ls error="server returned 404: 404 page not found\n"22742026/10/24 21:48:48 INFO Signed narinfos id=1 count=222752026/10/24 21:48:48 INFO Uploading 2 narinfos22762026/10/24 21:48:48 WARN Failed to register uploaded object key=13z1l77dq00fyywqgm5lnfgznb9k8y1s.ls error="server returned 404: 404 page not found\n"22772026/10/24 21:48:48 INFO Received complete push request method=POST path=/api/pushes/1/complete22782026/10/24 21:48:48 WARN Failed to register uploaded object key=mv0716jybbk4wd579d4ib4cmk49n2d6q.ls error="server returned 404: 404 page not found\n"22792026/10/24 21:48:48 WARN Failed to register uploaded object key=cdn02kny3hy22h8f3vpa17mh57aljzhn.ls error="server returned 404: 404 page not found\n"22802026/10/24 21:48:48 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"22812026/10/24 21:48:48 INFO Received complete push request method=POST path=/api/pushes/1/complete22822026/10/24 21:48:48 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"22832026/10/24 21:48:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22842026/10/24 21:48:48 WARN Failed to register uploaded object key=7grx2mxaqn7m18g73fcdfjk5pi3ccbvx.narinfo error="server returned 404: 404 page not found\n"22852026/10/24 21:48:48 WARN Failed to register uploaded object key=log/angc7gr0y004gpxkvci4422kfsd6q16k-test-script.drv error="server returned 404: 404 page not found\n"22862026/10/24 21:48:48 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign22872026/10/24 21:48:48 INFO Received complete push request method=POST path=/api/pushes/1/complete22882026/10/24 21:48:48 WARN Failed to register uploaded object key=na09j54xcq12sjaqagv03j0p3s5pkxsb.narinfo error="server returned 404: 404 page not found\n"22892026/10/24 21:48:48 INFO Signed narinfos id=1 count=322902026/10/24 21:48:48 INFO Signed narinfos id=1 count=122912026/10/24 21:48:48 INFO Uploading 3 narinfos22922026/10/24 21:48:48 INFO Uploading 1 narinfos22932026/10/24 21:48:48 WARN Failed to register uploaded object key=5yfiz8ii53wqyjygfcgsv95kwiwrmixq.narinfo error="server returned 404: 404 page not found\n"22942026/10/24 21:48:48 WARN Failed to register uploaded object key=0p4npbszvsrnlvjmvq6dx13za3j0sh0j.narinfo error="server returned 404: 404 page not found\n"22952026/10/24 21:48:48 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=022962026/10/24 21:48:48 INFO Completed push id=1 objects=3 duration=9.395587ms22972026/10/24 21:48:48 INFO Completed push id=1 objects=3 duration=8.894843ms22982026/10/24 21:48:48 INFO Upload complete. (985ms)22992026/10/24 21:48:48 INFO Upload complete. (963ms)23002026/10/24 21:48:48 INFO Completed push id=1 objects=6 duration=9.68853ms23012026/10/24 21:48:48 INFO Upload complete. (967ms)23022026/10/24 21:48:48 INFO Received complete push request method=POST path=/api/pushes/1/complete23032026/10/24 21:48:48 WARN Failed to register uploaded object key=13z1l77dq00fyywqgm5lnfgznb9k8y1s.narinfo error="server returned 404: 404 page not found\n"23042026/10/24 21:48:48 WARN Failed to register uploaded object key=ww7ccli6938njmrcl50r31840pzn4v00.narinfo error="server returned 404: 404 page not found\n"23052026/10/24 21:48:48 INFO Received complete push request method=POST path=/api/pushes/1/complete23062026/10/24 21:48:48 WARN Failed to register uploaded object key=cdn02kny3hy22h8f3vpa17mh57aljzhn.narinfo error="server returned 404: 404 page not found\n"23072026/10/24 21:48:48 WARN Failed to register uploaded object key=mv0716jybbk4wd579d4ib4cmk49n2d6q.narinfo error="server returned 404: 404 page not found\n"2308=== NAME TestClientSharedPathCommittedMidPush2309 client_integration_test.go:680: Retrieved narinfo from S3:2310 StorePath: /build/TestClientSharedPathCommittedMidPush2067949826/001/store/7grx2mxaqn7m18g73fcdfjk5pi3ccbvx-shared-dep2311 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst2312 Compression: zstd2313 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y822314 NarSize: 1362315 References: 2316 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n23172026/10/24 21:48:48 INFO Vacuumed table table=pending_closures2318 client_integration_test.go:680: Retrieved narinfo from S3:2319 StorePath: /build/TestClientSharedPathCommittedMidPush2067949826/001/store/na09j54xcq12sjaqagv03j0p3s5pkxsb-top2320 URL: nar/1zqdmdn64v565qmxazzb3j30v9w6n4larl6myp39zp1b0bip12aj.nar.zst2321 Compression: zstd2322 NarHash: sha256:1zqdmdn64v565qmxazzb3j30v9w6n4larl6myp39zp1b0bip12aj2323 NarSize: 2242324 References: /build/TestClientSharedPathCommittedMidPush2067949826/001/store/7grx2mxaqn7m18g73fcdfjk5pi3ccbvx-shared-dep2325 CA: text:sha256:08gdxlil126x01vqxk664x8ah1jy54r4li1c8mnq8370a0mkd41823262026/10/24 21:48:48 INFO Vacuumed table table=pending_objects23272026/10/24 21:48:48 INFO Completed push id=1 objects=4 duration=8.826142ms23282026/10/24 21:48:48 INFO Vacuumed table table=multipart_uploads23292026/10/24 21:48:48 INFO Upload complete. (978ms)2330--- PASS: TestClientSharedPathCommittedMidPush (6.57s)23312026/10/24 21:48:48 INFO Completed push id=1 objects=9 duration=10.856001ms23322026/10/24 21:48:48 INFO Upload complete. (981ms)2333=== NAME TestClientMultipleUploads2334 client_integration_test.go:369: Uploaded 3 paths in 1.826125897s23352026/10/24 21:48:48 INFO Vacuumed table table=closures2336=== NAME TestClientWithDependencies2337 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2499347294/001/store) requires matching store prefix2338--- PASS: TestClientWithDependencies (6.57s)2339--- PASS: TestClientMultipleUploads (6.50s)23402026/10/24 21:48:48 INFO Vacuumed table table=objects23412026/10/24 21:48:48 WARN Failed to register uploaded object key=nar/0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq.nar.zst error="server returned 404: 404 page not found\n"23422026/10/24 21:48:48 WARN Failed to register uploaded object key=nar/0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq.nar.zst error="server returned 404: 404 page not found\n"2343=== NAME TestNativeOIDCLoginPushRefresh/omitted-id-token2344 native_oidc_linux_test.go:139: Retrieved narinfo from S3:2345 StorePath: /build/TestNativeOIDCLoginPushRefreshomitted-id-token1483813146/004/store/5yfiz8ii53wqyjygfcgsv95kwiwrmixq-native-oidc-02346 URL: nar/0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq.nar.zst2347 Compression: zstd2348 NarHash: sha256:0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq2349 NarSize: 1282350 References: 2351 CA: text:sha256:0wy0p28czvzd72v0sn9wi5v6vzg0w28gil36xf4di45srvg5vf0p2352=== NAME TestNativeOIDCLoginPushRefresh/new-id-token2353 native_oidc_linux_test.go:139: Retrieved narinfo from S3:2354 StorePath: /build/TestNativeOIDCLoginPushRefreshnew-id-token2557146158/004/store/0p4npbszvsrnlvjmvq6dx13za3j0sh0j-native-oidc-02355 URL: nar/0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq.nar.zst2356 Compression: zstd2357 NarHash: sha256:0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq2358 NarSize: 1282359 References: 2360 CA: text:sha256:0wy0p28czvzd72v0sn9wi5v6vzg0w28gil36xf4di45srvg5vf0p23612026/10/24 21:48:49 INFO Aborted multipart uploads count=1 kept=023622026/10/24 21:48:49 INFO Received cleanup request method=DELETE path=/api/pending_closures23632026/10/24 21:48:49 INFO Aborted multipart uploads count=1 kept=02364--- PASS: TestPendingCleanupUsesOneCutoff (7.26s)23652026/10/24 21:48:49 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=023662026/10/24 21:48:49 INFO Received create pin request method=POST path=/api/pins/myapp23672026/10/24 21:48:49 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1470336257/001/store/lip3dvzlddxj1szjn1agr83b8xqrh92g-pinned-file.txt narinfo_key=lip3dvzlddxj1szjn1agr83b8xqrh92g.narinfo23682026/10/24 21:48:49 INFO Starting cleanup of old closures method=DELETE path=/api/closures23692026/10/24 21:48:49 INFO Garbage collection started23702026/10/24 21:48:49 INFO Aborted multipart uploads count=0 kept=023712026/10/24 21:48:49 WARN Force mode enabled - objects will be deleted immediately without grace period23722026/10/24 21:48:49 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=023732026/10/24 21:48:49 INFO Received push request method=POST path=/api/pushes23742026/10/24 21:48:49 INFO Vacuumed table table=pending_closures23752026/10/24 21:48:49 WARN Force mode enabled - objects will be deleted immediately without grace period23762026/10/24 21:48:49 INFO Vacuumed table table=pending_objects23772026/10/24 21:48:49 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23782026/10/24 21:48:49 INFO Uploading 407mnpqfcb7vli156vibidms02rlqxmp-ca-test (144B)23792026/10/24 21:48:49 INFO Vacuumed table table=multipart_uploads23802026/10/24 21:48:49 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=023812026/10/24 21:48:49 INFO Vacuumed table table=closures23822026/10/24 21:48:49 INFO Vacuumed table table=pending_closures23832026/10/24 21:48:49 INFO Vacuumed table table=pending_objects23842026/10/24 21:48:49 INFO Vacuumed table table=multipart_uploads23852026/10/24 21:48:49 INFO Vacuumed table table=objects23862026/10/24 21:48:49 INFO Vacuumed table table=closures23872026/10/24 21:48:49 WARN Failed to register uploaded object key=407mnpqfcb7vli156vibidms02rlqxmp.ls error="server returned 404: 404 page not found\n"23882026/10/24 21:48:49 WARN Failed to register uploaded object key=log/64cjax3nr2mgxm8ni908izq21xshg9p1-ca-test.drv error="server returned 404: 404 page not found\n"23892026/10/24 21:48:49 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23902026/10/24 21:48:49 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"23912026/10/24 21:48:49 INFO Signed narinfos id=1 count=123922026/10/24 21:48:49 INFO Uploading 1 narinfos23932026/10/24 21:48:49 INFO Vacuumed table table=objects23942026/10/24 21:48:49 INFO Received complete push request method=POST path=/api/pushes/1/complete23952026/10/24 21:48:49 WARN Failed to register uploaded object key=407mnpqfcb7vli156vibidms02rlqxmp.narinfo error="server returned 404: 404 page not found\n"23962026/10/24 21:48:49 INFO Completed push id=1 objects=4 duration=9.894872ms23972026/10/24 21:48:49 INFO Upload complete. (2.116s)2398=== NAME TestClientCADerivations2399 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations4237447721/001/store/407mnpqfcb7vli156vibidms02rlqxmp-ca-test2400 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2401 Compression: zstd2402 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2403 NarSize: 1442404 References: 2405 Deriver: /build/TestClientCADerivations4237447721/001/store/64cjax3nr2mgxm8ni908izq21xshg9p1-ca-test.drv2406 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2407 client_ca_test.go:185: Checking for realisation files in S3...2408 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2409 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2410--- PASS: TestDeleteClosuresRacingPins (7.57s)24112026/10/24 21:48:50 INFO Received push request method=POST path=/api/pushes24122026/10/24 21:48:50 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24132026/10/24 21:48:50 INFO Uploading dnivpsqgslvq5w1vm8wmviyqgjnsiyvx-native-oidc-1 (128B)24142026/10/24 21:48:50 WARN Failed to register uploaded object key=dnivpsqgslvq5w1vm8wmviyqgjnsiyvx.ls error="server returned 404: 404 page not found\n"24152026/10/24 21:48:50 WARN Failed to register uploaded object key=nar/0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg6.nar.zst error="server returned 404: 404 page not found\n"24162026/10/24 21:48:50 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign24172026/10/24 21:48:50 INFO Signed narinfos id=2 count=124182026/10/24 21:48:50 INFO Uploading 1 narinfos24192026/10/24 21:48:50 INFO Received complete push request method=POST path=/api/pushes/2/complete24202026/10/24 21:48:50 INFO Completed push id=2 objects=3 duration=1.802716ms24212026/10/24 21:48:50 INFO Upload complete. (172ms)24222026/10/24 21:48:50 WARN Failed to register uploaded object key=dnivpsqgslvq5w1vm8wmviyqgjnsiyvx.narinfo error="server returned 404: 404 page not found\n"2423=== NAME TestNativeOIDCLoginPushRefresh/new-id-token2424 native_oidc_linux_test.go:139: Retrieved narinfo from S3:2425 StorePath: /build/TestNativeOIDCLoginPushRefreshnew-id-token2557146158/004/store/dnivpsqgslvq5w1vm8wmviyqgjnsiyvx-native-oidc-12426 URL: nar/0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg6.nar.zst2427 Compression: zstd2428 NarHash: sha256:0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg62429 NarSize: 1282430 References: 2431 CA: text:sha256:0z7d88w8ivn9jiskv6fpsiikfgkan67r4qp4isjd1g0w9anr0xrd24322026/10/24 21:48:50 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02433=== NAME TestClientIntegration2434 client_integration_test.go:323: Objects in database after GC:2435 client_integration_test.go:323: Successfully deleted all objects with GC --force2436--- PASS: TestClientIntegration (8.35s)24372026/10/24 21:48:51 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24382026/10/24 21:48:51 INFO Received push request method=POST path=/api/pushes24392026/10/24 21:48:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)24402026/10/24 21:48:51 INFO Uploading 82pj41y064fpp8clh69dk2qpmn8m6s42-native-oidc-1 (128B)24412026/10/24 21:48:51 WARN Failed to register uploaded object key=nar/0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg6.nar.zst error="server returned 404: 404 page not found\n"24422026/10/24 21:48:51 WARN Failed to register uploaded object key=82pj41y064fpp8clh69dk2qpmn8m6s42.ls error="server returned 404: 404 page not found\n"24432026/10/24 21:48:51 WARN Request failed, retrying attempt=2 backoff=210.181968ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24442026/10/24 21:48:51 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign24452026/10/24 21:48:51 INFO Signed narinfos id=2 count=124462026/10/24 21:48:51 INFO Uploading 1 narinfos24472026/10/24 21:48:51 INFO Received complete push request method=POST path=/api/pushes/2/complete24482026/10/24 21:48:51 INFO Completed push id=2 objects=3 duration=1.831997ms24492026/10/24 21:48:51 INFO Upload complete. (113ms)24502026/10/24 21:48:51 WARN Failed to register uploaded object key=82pj41y064fpp8clh69dk2qpmn8m6s42.narinfo error="server returned 404: 404 page not found\n"2451=== NAME TestNativeOIDCLoginPushRefresh/omitted-id-token2452 native_oidc_linux_test.go:139: Retrieved narinfo from S3:2453 StorePath: /build/TestNativeOIDCLoginPushRefreshomitted-id-token1483813146/004/store/82pj41y064fpp8clh69dk2qpmn8m6s42-native-oidc-12454 URL: nar/0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg6.nar.zst2455 Compression: zstd2456 NarHash: sha256:0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg62457 NarSize: 1282458 References: 2459 CA: text:sha256:0z7d88w8ivn9jiskv6fpsiikfgkan67r4qp4isjd1g0w9anr0xrd2460--- PASS: TestNativeOIDCLoginPushRefresh (0.00s)2461 --- PASS: TestNativeOIDCLoginPushRefresh/new-id-token (7.20s)2462 --- PASS: TestNativeOIDCLoginPushRefresh/omitted-id-token (8.05s)24632026/10/24 21:48:51 WARN Request failed, retrying attempt=3 backoff=429.585614ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2464=== NAME TestPinProtectsFromGC2465 client_integration_test.go:840: Pin successfully protected closure from garbage collection2466--- PASS: TestPinProtectsFromGC (10.89s)24672026/10/24 21:48:51 WARN Request failed, retrying attempt=4 backoff=864.421201ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24682026/10/24 21:48:52 WARN Request failed, retrying attempt=5 backoff=1.443662464s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24692026/10/24 21:48:54 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"24702026/10/24 21:48:54 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24712026/10/24 21:48:54 WARN Request failed, retrying attempt=2 backoff=183.018799ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24722026/10/24 21:48:54 WARN Request failed, retrying attempt=3 backoff=438.779002ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2473=== NAME TestClientCADerivations2474 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2475 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2476 error: binary cache 's3://bucket84?endpoint=http://localhost:43333®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations4237447721/001/store'2477 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12478--- PASS: TestClientCADerivations (12.57s)24792026/10/24 21:48:54 WARN Request failed, retrying attempt=4 backoff=862.561324ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24802026/10/24 21:48:55 WARN Request failed, retrying attempt=5 backoff=1.744405545s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24812026/10/24 21:48:57 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24822026/10/24 21:48:57 WARN Request failed, retrying attempt=2 backoff=195.781891ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24832026/10/24 21:48:57 WARN Request failed, retrying attempt=3 backoff=412.791805ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24842026/10/24 21:48:58 WARN Request failed, retrying attempt=4 backoff=861.37529ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24852026/10/24 21:48:58 WARN Request failed, retrying attempt=5 backoff=1.498301944s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2486--- PASS: TestClientErrorHandling (0.00s)2487 --- PASS: TestClientErrorHandling/InvalidStorePath (2.97s)2488 --- PASS: TestClientErrorHandling/InvalidAuthToken (3.31s)2489 --- PASS: TestClientErrorHandling/ServerNotAvailable (16.83s)2490FAIL24912026-10-24 21:49:00.791 UTC [204] LOG: received smart shutdown request24922026-10-24 21:49:00.802 UTC [204] LOG: background worker "logical replication launcher" (PID 233) exited with exit code 124932026-10-24 21:49:01.439 UTC [228] LOG: checkpoint complete: wrote 11669 buffers (71.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=12.715 s, sync=0.299 s, total=13.069 s; sync files=34717, longest=0.014 s, average=0.001 s; distance=533597 kB, estimate=533597 kB; lsn=0/22827890, redo lsn=0/2207D35024942026-10-24 21:49:01.444 UTC [228] LOG: shutting down24952026-10-24 21:49:01.444 UTC [228] LOG: checkpoint starting: shutdown immediate24962026-10-24 21:49:01.458 UTC [228] LOG: checkpoint complete: wrote 101 buffers (0.6%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.003 s, sync=0.009 s, total=0.014 s; sync files=63, longest=0.001 s, average=0.001 s; distance=7849 kB, estimate=481022 kB; lsn=0/22827908, redo lsn=0/2282790824972026-10-24 21:49:01.638 UTC [204] LOG: database system is shut down