niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #420
· raw
1tribuchet: building on jamie2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestDebugHTTPRedactsCredentials10--- PASS: TestDebugHTTPRedactsCredentials (0.00s)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.04s)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 TestDoServerRequestAttachesToken118=== CONT TestScriptTokenCachesUntilRefresh119=== CONT TestScriptTokenNoExpiryRerunsEveryCall120=== CONT TestScriptTokenEmptyCommand121--- PASS: TestScriptTokenEmptyCommand (0.00s)122=== CONT TestPathInfoHashCompatibility123=== CONT TestScriptTokenBadJSON124=== CONT TestScriptTokenEmptyToken125=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess126=== CONT TestFileTokenEmpty127=== CONT TestFileTokenMissing128=== CONT TestFileTokenReadsAndCaches129=== CONT TestStaticToken130--- PASS: TestStaticToken (0.00s)131=== CONT TestSetClientTLSErrors132=== CONT TestSetClientTLSDoesNotMutateDefaultTransport133=== CONT TestSetClientTLS134=== CONT TestDumpPathMatchesNix135=== CONT TestStreamPushStopsWhenCanceled136=== CONT TestClientSignaturesByStorePath137=== CONT TestRateLimiterFeedback138=== CONT TestStreamPushReportsSkippedPaths139=== CONT TestPathInfoCACompatibility140=== CONT TestParsePathInfoJSONMultiplePaths141=== CONT TestStreamPushReportsSignatures142=== CONT TestParsePathInfoJSON143=== CONT TestScriptTokenScriptFails144=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)145=== CONT TestStreamPushRequestLine146=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths147=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths148=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)149=== RUN TestRateLimiterFeedback/429_enables_limiter150--- PASS: TestFileTokenMissing (0.00s)151=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths152=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon153--- PASS: TestFileTokenEmpty (0.00s)154--- PASS: TestFileTokenReadsAndCaches (0.00s)155=== CONT TestConvertHashToNix32156=== CONT TestGetStorePathHash157=== RUN TestPathInfoCACompatibility/null_ca_field158--- PASS: TestClientSignaturesByStorePath (0.00s)159=== CONT TestStreamPushIsolatesFailures160=== RUN TestParsePathInfoJSON/Nix_format161=== PAUSE TestParsePathInfoJSON/Nix_format162=== CONT TestStreamPushBatchesUnderLoad163=== RUN TestParsePathInfoJSON/Lix_format164=== CONT TestEncodeNixBase32WithRealHash165=== CONT TestStreamPushReportsEveryPath166--- PASS: TestDoServerRequestAttachesToken (0.01s)167=== CONT TestStreamPushGivesUpOnDeadServer168=== RUN TestGetStorePathHash/valid_store_path169=== CONT TestCaseHackSuffix170=== PAUSE TestGetStorePathHash/valid_store_path171=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths172=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon173=== RUN TestConvertHashToNix32/SRI_format_to_Nix32174=== PAUSE TestRateLimiterFeedback/429_enables_limiter175=== PAUSE TestPathInfoCACompatibility/null_ca_field176=== PAUSE TestParsePathInfoJSON/Lix_format177=== RUN TestParsePathInfoJSON/empty_input178=== CONT TestEncodeNixBase32179=== CONT TestUploadMultipart_SupersededByPeer180=== CONT TestPartSizeForNAR181=== RUN TestUploadMultipart_SupersededByPeer/exists182=== PAUSE TestUploadMultipart_SupersededByPeer/exists183=== CONT TestUploadMultipart_PartsInParallel184=== CONT TestDumpPathSingleFile185=== RUN TestPartSizeForNAR/zero_stays_at_minimum186--- PASS: TestStreamPushStopsWhenCanceled (0.00s)187--- PASS: TestScriptTokenBadJSON (0.01s)188--- PASS: TestEncodeNixBase32WithRealHash (0.00s)189--- PASS: TestScriptTokenScriptFails (0.00s)190=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32191=== PAUSE TestParsePathInfoJSON/empty_input192=== RUN TestEncodeNixBase32/test_string_hash193=== RUN TestPathInfoCACompatibility/old_string_format_-_text194=== RUN TestRateLimiterFeedback/503_enables_limiter195=== CONT TestDumpPathWriterError196=== CONT TestFilterOversizedClosures197=== RUN TestUploadMultipart_SupersededByPeer/missing198=== PAUSE TestUploadMultipart_SupersededByPeer/missing199=== RUN TestGetStorePathHash/basename_without_hyphen_should_error200=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error201=== CONT TestSupersededNARStillUploadsListing202=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum203--- PASS: TestStreamPushReportsSkippedPaths (0.00s)204=== PAUSE TestEncodeNixBase32/test_string_hash205=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text206=== CONT TestAuthenticatedRedirectStaysOnServer207--- PASS: TestStreamPushIsolatesFailures (0.00s)208--- PASS: TestStreamPushReportsSignatures (0.00s)209--- PASS: TestStreamPushReportsEveryPath (0.00s)210--- PASS: TestScriptTokenEmptyToken (0.01s)211--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)212--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)213=== CONT TestRegisterUploadedObjectReusesConnections214=== PAUSE TestRateLimiterFeedback/503_enables_limiter215--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)216=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun217--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)218=== CONT TestShellSplitErrors219--- PASS: TestShellSplitErrors (0.00s)220=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica221--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)222=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry223=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI224=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI225=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512226=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512227=== RUN TestParsePathInfoJSON/whitespace_only228=== PAUSE TestParsePathInfoJSON/whitespace_only229=== RUN TestParsePathInfoJSON/invalid_JSON230=== PAUSE TestParsePathInfoJSON/invalid_JSON231=== RUN TestConvertHashToNix32/already_Nix32_format232=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error233=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error234=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error235=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error236=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer237=== RUN TestSupersededNARStillUploadsListing/small_NAR238=== PAUSE TestSupersededNARStillUploadsListing/small_NAR239=== RUN TestSupersededNARStillUploadsListing/dump_cut_short240=== RUN TestSetClientTLS/rejects_connection_without_client_cert241=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert242=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA243=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA244=== RUN TestSetClientTLS/preserves_debug_logging_transport245=== PAUSE TestSetClientTLS/preserves_debug_logging_transport246=== PAUSE TestConvertHashToNix32/already_Nix32_format247=== RUN TestConvertHashToNix32/invalid_format248=== PAUSE TestConvertHashToNix32/invalid_format249=== RUN TestFilterOversizedClosures/no_limit_keeps_everything250=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything251=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped252=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped253=== RUN TestFilterOversizedClosures/all_closures_skipped254=== PAUSE TestFilterOversizedClosures/all_closures_skipped255=== CONT TestResolveStorePath256=== CONT TestRetryTimeoutOutlastsMaxRetries257=== CONT TestShellSplit258--- PASS: TestShellSplit (0.00s)259=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short260=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths261=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails262=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails263=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths264=== RUN TestPartSizeForNAR/small_stays_at_minimum265=== PAUSE TestPartSizeForNAR/small_stays_at_minimum266=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum267=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum268=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts269=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts270=== RUN TestPartSizeForNAR/1_TiB271=== PAUSE TestPartSizeForNAR/1_TiB272=== RUN TestPartSizeForNAR/5_TiB_S3_max_object273=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object274=== RUN TestPartSizeForNAR/capped_at_5_GiB275=== PAUSE TestPartSizeForNAR/capped_at_5_GiB276=== RUN TestEncodeNixBase32/empty_input277=== PAUSE TestEncodeNixBase32/empty_input278=== CONT TestUploadMultipart_SupersededByPeer/exists279=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI280=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)281=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon282=== CONT TestParsePathInfoJSON/Nix_format283=== CONT TestDoWithRetry_BodyReplayedViaGetBody284=== CONT TestParsePathInfoJSON/whitespace_only285=== CONT TestParsePathInfoJSON/empty_input286=== CONT TestParsePathInfoJSON/Lix_format287--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)288 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)289 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)290--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)291=== CONT TestParsePathInfoJSON/invalid_JSON292=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error293=== CONT TestGetStorePathHash/basename_without_hyphen_should_error294=== CONT TestSetClientTLS/rejects_connection_without_client_cert295=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive296=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive297=== RUN TestPathInfoCACompatibility/new_structured_format_-_text298=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text299=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method300=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method301=== RUN TestSetClientTLSErrors/missing_cert_file302=== PAUSE TestSetClientTLSErrors/missing_cert_file303=== RUN TestSetClientTLSErrors/missing_key_file304=== PAUSE TestSetClientTLSErrors/missing_key_file305=== RUN TestSetClientTLSErrors/missing_ca_file306=== PAUSE TestSetClientTLSErrors/missing_ca_file307=== RUN TestSetClientTLSErrors/invalid_ca_file308=== PAUSE TestSetClientTLSErrors/invalid_ca_file309=== CONT TestSetClientTLS/preserves_debug_logging_transport310=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter311=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter312=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter313=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter314=== CONT TestConvertHashToNix32/SRI_format_to_Nix32315=== CONT TestConvertHashToNix32/invalid_format316=== CONT TestFilterOversizedClosures/no_limit_keeps_everything317=== CONT TestConvertHashToNix32/already_Nix32_format318=== CONT TestFilterOversizedClosures/all_closures_skipped319=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped320=== CONT TestSupersededNARStillUploadsListing/small_NAR321=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails322=== CONT TestDoWithRetry_FinalResponseBodyReadable323=== CONT TestUploadMultipart_SupersededByPeer/missing324=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512325=== CONT TestGetStorePathHash/valid_store_path326=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error327--- PASS: TestResolveStorePath (0.00s)328=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA329=== CONT TestPartSizeForNAR/zero_stays_at_minimum330=== CONT TestPartSizeForNAR/capped_at_5_GiB331=== CONT TestPartSizeForNAR/1_TiB332=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts333=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum334=== CONT TestPartSizeForNAR/small_stays_at_minimum335=== CONT TestEncodeNixBase32/test_string_hash336=== CONT TestEncodeNixBase32/empty_input337=== CONT TestPathInfoCACompatibility/null_ca_field338=== CONT TestSetClientTLSErrors/missing_cert_file339=== CONT TestPartSizeForNAR/5_TiB_S3_max_object340--- PASS: TestParsePathInfoJSON (0.04s)341 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)342 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)343 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)344 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)345 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)346--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)347=== CONT TestPathInfoCACompatibility/new_structured_format_-_text348=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method349=== CONT TestSupersededNARStillUploadsListing/dump_cut_short350--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.00s)351--- PASS: TestConvertHashToNix32 (0.05s)352 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)353 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)354 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)355--- PASS: TestEncodeNixBase32 (0.05s)356 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)357 --- PASS: TestEncodeNixBase32/empty_input (0.00s)358=== CONT TestPathInfoCACompatibility/old_string_format_-_text359=== CONT TestRateLimiterFeedback/429_enables_limiter360--- PASS: TestPathInfoHashCompatibility (0.04s)361 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)362 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)363 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)364 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)365=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive366=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter367=== CONT TestRateLimiterFeedback/503_enables_limiter368=== CONT TestSetClientTLSErrors/missing_ca_file369=== CONT TestSetClientTLSErrors/missing_key_file370--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)371 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)372 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)373--- PASS: TestFilterOversizedClosures (0.04s)374 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)375 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)376 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)377--- PASS: TestGetStorePathHash (0.05s)378 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)379 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)380 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)381 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)382--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)383--- PASS: TestPartSizeForNAR (0.05s)384 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)385 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)386 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)387 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)388 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)389 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)390 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)391=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter392--- PASS: TestPathInfoCACompatibility (0.04s)393 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)394 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)395 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)396 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)397 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)398=== CONT TestSetClientTLSErrors/invalid_ca_file399--- PASS: TestRateLimiterFeedback (0.04s)400 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)401 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)402 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)403 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)404--- PASS: TestSetClientTLSErrors (0.05s)405 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.01s)406 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)407 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)408 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)409--- PASS: TestSetClientTLS (0.04s)410 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)411 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)412 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)413--- PASS: TestStreamPushBatchesUnderLoad (0.18s)414--- PASS: TestDumpPathSingleFile (0.18s)415--- PASS: TestCaseHackSuffix (0.18s)416--- PASS: TestStreamPushRequestLine (0.19s)417--- PASS: TestRegisterUploadedObjectReusesConnections (0.18s)418--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.16s)419--- PASS: TestDumpPathWriterError (0.19s)420--- PASS: TestDumpPathMatchesNix (0.23s)421--- PASS: TestSupersededNARStillUploadsListing (0.04s)422 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.01s)423 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.01s)424 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.67s)425--- PASS: TestUploadMultipart_PartsInParallel (0.75s)426--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)427--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.00s)428--- PASS: TestAuthenticatedRedirectStaysOnServer (3.31s)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 (0.02s)475=== CONT TestDeviceLogin476=== CONT TestDeviceVerificationURL477=== RUN TestDeviceVerificationURL/complete478=== PAUSE TestDeviceVerificationURL/complete479=== RUN TestDeviceVerificationURL/basic-fallback480=== PAUSE TestDeviceVerificationURL/basic-fallback481=== RUN TestDeviceVerificationURL/insecure482=== PAUSE TestDeviceVerificationURL/insecure483=== RUN TestDeviceVerificationURL/userinfo484=== PAUSE TestDeviceVerificationURL/userinfo485=== RUN TestDeviceVerificationURL/fragment486=== PAUSE TestDeviceVerificationURL/fragment487=== RUN TestDeviceVerificationURL/malformed488=== PAUSE TestDeviceVerificationURL/malformed489=== CONT TestDeviceVerificationURL/complete490=== CONT TestDeviceVerificationURL/userinfo491=== CONT TestRefreshContracts492=== RUN TestRefreshContracts/new-id493=== PAUSE TestRefreshContracts/new-id494=== RUN TestRefreshContracts/no-id495=== PAUSE TestRefreshContracts/no-id496=== CONT TestDeviceVerificationURL/insecure497=== CONT TestDeviceVerificationURL/fragment498=== CONT TestCanonicalServer499--- PASS: TestCanonicalServer (0.00s)500=== CONT TestDeviceVerificationURL/basic-fallback501=== CONT TestStoredTokenProcess502 manager_linux_test.go:222: subprocess helper503--- SKIP: TestStoredTokenProcess (0.00s)504=== CONT TestCrossProcessRefresh505=== CONT TestProfileLockCancellation506=== CONT TestConcurrentSources507=== CONT TestStoredNoIDRefresh508=== CONT TestLogoutWaitsForRefresh509=== CONT TestRefreshRetainsOmittedRefreshToken510=== CONT TestDeviceHTTPRequestTimeout511=== CONT TestFractionalTemporalClaims512=== CONT TestStoredLoginLifecycle513=== CONT TestExpiredTokenRefresh514=== RUN TestExpiredTokenRefresh/new-id515=== CONT TestRefreshRejectsIdentityChangeAndKeepsRotation516=== CONT TestTokenWithoutRefreshToken517=== CONT TestDeviceFailures518=== CONT TestDeviceCancellation519=== CONT TestStoreFailureDoesNotReturnRefreshedToken520=== CONT TestDiscoveryFailures521=== CONT TestDeviceVerificationURL/malformed522=== CONT TestRefreshContracts/new-id523=== RUN TestDeviceCancellation/polling524=== PAUSE TestDeviceCancellation/polling525=== RUN TestDeviceCancellation/initial-request526=== PAUSE TestDeviceCancellation/initial-request527=== CONT TestRefreshContracts/no-id528=== PAUSE TestExpiredTokenRefresh/new-id529=== RUN TestExpiredTokenRefresh/no-id530=== PAUSE TestExpiredTokenRefresh/no-id531=== RUN TestDiscoveryFailures/http-endpoint532=== PAUSE TestDiscoveryFailures/http-endpoint533=== RUN TestDiscoveryFailures/redirect534=== PAUSE TestDiscoveryFailures/redirect535=== RUN TestDiscoveryFailures/issuer536=== PAUSE TestDiscoveryFailures/issuer537=== RUN TestDiscoveryFailures/no-device538=== PAUSE TestDiscoveryFailures/no-device539=== CONT TestDeviceCancellation/polling540=== CONT TestExpiredTokenRefresh/new-id541=== RUN TestDeviceFailures/wrong-aud542=== PAUSE TestDeviceFailures/wrong-aud543=== RUN TestDeviceFailures/expired-id544=== PAUSE TestDeviceFailures/expired-id545=== RUN TestDeviceFailures/future-iat546=== PAUSE TestDeviceFailures/future-iat547=== RUN TestDeviceFailures/wrong-azp548=== PAUSE TestDeviceFailures/wrong-azp549=== RUN TestDeviceFailures/expired550=== PAUSE TestDeviceFailures/expired551=== RUN TestDeviceFailures/no-id552=== PAUSE TestDeviceFailures/no-id553=== RUN TestDeviceFailures/wrong-issuer554=== PAUSE TestDeviceFailures/wrong-issuer555=== RUN TestDeviceFailures/future-nbf556=== PAUSE TestDeviceFailures/future-nbf557=== RUN TestDeviceFailures/multi-aud-no-azp558=== PAUSE TestDeviceFailures/multi-aud-no-azp559=== RUN TestDeviceFailures/denied560=== PAUSE TestDeviceFailures/denied561=== RUN TestDeviceFailures/invalid-interval562=== PAUSE TestDeviceFailures/invalid-interval563=== CONT TestDiscoveryFailures/http-endpoint564=== CONT TestExpiredTokenRefresh/no-id565=== CONT TestDeviceCancellation/initial-request566--- PASS: TestRefreshRetainsOmittedRefreshToken (0.04s)567=== CONT TestDeviceFailures/wrong-aud568=== CONT TestDeviceFailures/invalid-interval569--- PASS: TestFractionalTemporalClaims (0.05s)570=== CONT TestDeviceFailures/denied571--- PASS: TestExpiredTokenRefresh (0.00s)572 --- PASS: TestExpiredTokenRefresh/new-id (0.03s)573 --- PASS: TestExpiredTokenRefresh/no-id (0.02s)574=== CONT TestDeviceFailures/multi-aud-no-azp575=== CONT TestDeviceFailures/future-nbf576--- PASS: TestStoreFailureDoesNotReturnRefreshedToken (0.06s)577=== CONT TestDeviceFailures/wrong-issuer578=== CONT TestDeviceFailures/no-id579=== RUN TestTokenWithoutRefreshToken/before-refresh580=== PAUSE TestTokenWithoutRefreshToken/before-refresh581=== RUN TestTokenWithoutRefreshToken/at-refresh582=== PAUSE TestTokenWithoutRefreshToken/at-refresh583=== RUN TestTokenWithoutRefreshToken/before-expiry-margin584=== PAUSE TestTokenWithoutRefreshToken/before-expiry-margin585=== RUN TestTokenWithoutRefreshToken/at-expiry-margin586=== PAUSE TestTokenWithoutRefreshToken/at-expiry-margin587=== RUN TestTokenWithoutRefreshToken/expired588=== PAUSE TestTokenWithoutRefreshToken/expired589=== CONT TestDeviceFailures/expired590=== CONT TestDeviceFailures/wrong-azp591=== CONT TestDeviceFailures/future-iat592=== CONT TestDeviceFailures/expired-id593--- PASS: TestRefreshContracts (0.00s)594 --- PASS: TestRefreshContracts/no-id (0.07s)595 --- PASS: TestRefreshContracts/new-id (0.08s)596=== CONT TestDiscoveryFailures/issuer597--- PASS: TestProfileLockCancellation (0.10s)598=== CONT TestDiscoveryFailures/redirect599--- PASS: TestRefreshRejectsIdentityChangeAndKeepsRotation (0.10s)600=== CONT TestDiscoveryFailures/no-device601--- PASS: TestStoredNoIDRefresh (0.12s)602=== CONT TestTokenWithoutRefreshToken/before-refresh603=== CONT TestTokenWithoutRefreshToken/at-expiry-margin604=== CONT TestTokenWithoutRefreshToken/expired605=== CONT TestTokenWithoutRefreshToken/before-expiry-margin606=== CONT TestTokenWithoutRefreshToken/at-refresh607--- PASS: TestTokenWithoutRefreshToken (0.07s)608 --- PASS: TestTokenWithoutRefreshToken/before-refresh (0.00s)609 --- PASS: TestTokenWithoutRefreshToken/at-expiry-margin (0.00s)610 --- PASS: TestTokenWithoutRefreshToken/expired (0.00s)611 --- PASS: TestTokenWithoutRefreshToken/before-expiry-margin (0.00s)612 --- PASS: TestTokenWithoutRefreshToken/at-refresh (0.00s)613--- PASS: TestCrossProcessRefresh (0.14s)614--- PASS: TestDeviceHTTPRequestTimeout (0.16s)615--- PASS: TestDeviceCancellation (0.00s)616 --- PASS: TestDeviceCancellation/polling (0.13s)617 --- PASS: TestDeviceCancellation/initial-request (0.15s)618--- PASS: TestConcurrentSources (0.19s)619--- PASS: TestDiscoveryFailures (0.00s)620 --- PASS: TestDiscoveryFailures/http-endpoint (0.06s)621 --- PASS: TestDiscoveryFailures/issuer (0.04s)622 --- PASS: TestDiscoveryFailures/redirect (0.06s)623 --- PASS: TestDiscoveryFailures/no-device (0.11s)624--- PASS: TestLogoutWaitsForRefresh (0.22s)625--- PASS: TestStoredLoginLifecycle (1.12s)626--- PASS: TestDeviceVerificationURL (0.00s)627 --- PASS: TestDeviceVerificationURL/insecure (0.04s)628 --- PASS: TestDeviceVerificationURL/fragment (0.05s)629 --- PASS: TestDeviceVerificationURL/malformed (0.04s)630 --- PASS: TestDeviceVerificationURL/userinfo (0.07s)631 --- PASS: TestDeviceVerificationURL/basic-fallback (1.10s)632 --- PASS: TestDeviceVerificationURL/complete (1.16s)633--- PASS: TestDeviceFailures (0.00s)634 --- PASS: TestDeviceFailures/invalid-interval (0.03s)635 --- PASS: TestDeviceFailures/expired (1.01s)636 --- PASS: TestDeviceFailures/future-nbf (1.04s)637 --- PASS: TestDeviceFailures/denied (1.05s)638 --- PASS: TestDeviceFailures/multi-aud-no-azp (1.06s)639 --- PASS: TestDeviceFailures/wrong-aud (1.08s)640 --- PASS: TestDeviceFailures/wrong-issuer (1.06s)641 --- PASS: TestDeviceFailures/wrong-azp (1.05s)642 --- PASS: TestDeviceFailures/no-id (1.07s)643 --- PASS: TestDeviceFailures/future-iat (1.06s)644 --- PASS: TestDeviceFailures/expired-id (1.13s)645--- PASS: TestDeviceLogin (8.10s)646PASS647Running command utility tests...648=== RUN TestOIDCResolution649=== RUN TestOIDCResolution/saved-fallback650=== RUN TestOIDCResolution/explicit-token6512026/10/24 18:16:24 WARN --auth-token is deprecated: tokens on the command line are visible in /proc and shell history; use --auth-token-path or --auth-token-script652=== RUN TestOIDCResolution/explicit-file653=== RUN TestOIDCResolution/env-file654=== RUN TestOIDCResolution/mtls655=== RUN TestOIDCResolution/explicit-profile656=== RUN TestOIDCResolution/explicit-token-over-profile6572026/10/24 18:16:24 WARN --auth-token is deprecated: tokens on the command line are visible in /proc and shell history; use --auth-token-path or --auth-token-script658=== RUN TestOIDCResolution/hook-does-not-select-profile659=== RUN TestOIDCResolution/hook-env-file660=== RUN TestOIDCResolution/device-conflict6612026/10/24 18:16:24 WARN --auth-token is deprecated: tokens on the command line are visible in /proc and shell history; use --auth-token-path or --auth-token-script662=== RUN TestOIDCResolution/device-profile-conflict663=== RUN TestOIDCResolution/issuer-without-device664--- PASS: TestOIDCResolution (0.00s)665 --- PASS: TestOIDCResolution/saved-fallback (0.00s)666 --- PASS: TestOIDCResolution/explicit-token (0.00s)667 --- PASS: TestOIDCResolution/explicit-file (0.00s)668 --- PASS: TestOIDCResolution/env-file (0.00s)669 --- PASS: TestOIDCResolution/mtls (0.00s)670 --- PASS: TestOIDCResolution/explicit-profile (0.00s)671 --- PASS: TestOIDCResolution/explicit-token-over-profile (0.00s)672 --- PASS: TestOIDCResolution/hook-does-not-select-profile (0.00s)673 --- PASS: TestOIDCResolution/hook-env-file (0.00s)674 --- PASS: TestOIDCResolution/device-conflict (0.00s)675 --- PASS: TestOIDCResolution/device-profile-conflict (0.00s)676 --- PASS: TestOIDCResolution/issuer-without-device (0.00s)677PASS678Running CLI tests...679=== RUN TestAuthHelpAndValidation680=== PAUSE TestAuthHelpAndValidation681=== CONT TestAuthHelpAndValidation682--- PASS: TestAuthHelpAndValidation (0.00s)683PASS684Running server tests...685The files belonging to this database system will be owned by user "nixbld".686This user must also own the server process.687688The database cluster will be initialized with locale "C".689The default database encoding has accordingly been set to "SQL_ASCII".690The default text search configuration will be set to "english".691692Data page checksums are enabled.693694creating directory /build/postgres157799846/data ... ok695creating subdirectories ... ok696selecting dynamic shared memory implementation ... posix697selecting default "max_connections" ... 100698selecting default "shared_buffers" ... 128MB699selecting default time zone ... UTC700creating configuration files ... ok701running bootstrap script ... ok702performing post-bootstrap initialization ... ok703syncing data to disk ... ok704705initdb: warning: enabling "trust" authentication for local connections706initdb: 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.707708Success. You can now start the database server using:709710 pg_ctl -D /build/postgres157799846/data -l logfile start711712/build/postgres157799846:5432 - no response7132026-10-24 18:16:25.781 UTC [201] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit7142026-10-24 18:16:25.782 UTC [201] LOG: listening on Unix socket "/build/postgres157799846/.s.PGSQL.5432"7152026-10-24 18:16:25.787 UTC [208] LOG: database system was shut down at 2026-10-24 18:16:25 UTC7162026-10-24 18:16:25.790 UTC [201] LOG: database system is ready to accept connections717/build/postgres157799846:5432 - accepting connections718{"timestamp":"2026-10-24T18:16:26.082703379Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"8dd99c68-659d-479f-9132-8be2bef486f5","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":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(139)"}719=== RUN TestService_AuthMiddleware720=== PAUSE TestService_AuthMiddleware721=== RUN TestService_AuthMiddleware_MTLSProxyHeader722=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader723=== RUN TestService_AuthMiddleware_MTLSBoundSubjects724=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects725=== RUN TestService_ReadAuthMiddleware726=== PAUSE TestService_ReadAuthMiddleware727=== RUN TestService_AuthMiddleware_OIDC728=== PAUSE TestService_AuthMiddleware_OIDC729=== RUN TestService_RequireScope_OIDC730=== PAUSE TestService_RequireScope_OIDC731=== RUN TestService_ReadScope_PublicByDefault732=== PAUSE TestService_ReadScope_PublicByDefault733=== RUN TestCacheConfigHandler734=== PAUSE TestCacheConfigHandler735=== RUN TestCacheStatsHandler736=== PAUSE TestCacheStatsHandler737=== RUN TestClientCADerivations738=== PAUSE TestClientCADerivations739=== RUN TestClientErrorHandling740=== PAUSE TestClientErrorHandling741=== RUN TestClientIntegration742=== PAUSE TestClientIntegration743=== RUN TestClientMultipleUploads744=== PAUSE TestClientMultipleUploads745=== RUN TestClientWithDependencies746=== PAUSE TestClientWithDependencies747=== RUN TestClientSharedPathCommittedMidPush748=== PAUSE TestClientSharedPathCommittedMidPush749=== RUN TestPinProtectsFromGC750=== PAUSE TestPinProtectsFromGC751=== RUN TestClientPushesUseOnePush752=== PAUSE TestClientPushesUseOnePush753=== RUN TestClientFallsBackToClosures754=== PAUSE TestClientFallsBackToClosures755=== RUN TestDeleteClosuresRacingPins756=== PAUSE TestDeleteClosuresRacingPins757=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock758=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock759=== RUN TestResolveDBConnectionString760=== PAUSE TestResolveDBConnectionString761=== RUN TestConnectWaitsForAPeerMigration762=== PAUSE TestConnectWaitsForAPeerMigration763=== RUN TestLeadElectsOneAndHandsOver764=== PAUSE TestLeadElectsOneAndHandsOver765=== RUN TestLeadIncumbentWinsAfterRestart7662026/10/24 18:16:26 INFO lead: acquired remote=192.0.2.1:12347672026/10/24 18:16:26 INFO lead: released remote=192.0.2.1:12347682026/10/24 18:16:26 INFO lead: acquired remote=192.0.2.1:12347692026/10/24 18:16:28 INFO lead: released remote=192.0.2.1:1234770--- PASS: TestLeadIncumbentWinsAfterRestart (1.83s)771=== RUN TestLeadIncumbentAnnouncesAtOnce772=== PAUSE TestLeadIncumbentAnnouncesAtOnce773=== RUN TestLeadEndsOnShutdown774=== PAUSE TestLeadEndsOnShutdown775=== RUN TestLeadEndsWhenItsConnectionHangs7762026/10/24 18:16:28 INFO lead: acquired remote=192.0.2.1:12347772026-10-24 18:16:29.526 UTC [392] FATAL: terminating connection due to administrator command7782026/10/24 18:16:29 INFO lead: acquired remote=192.0.2.1:12347792026/10/24 18:16:30 WARN lead: lock connection lost error="timeout: context deadline exceeded"7802026/10/24 18:16:30 INFO lead: released remote=192.0.2.1:12347812026/10/24 18:16:31 INFO lead: released remote=192.0.2.1:1234782--- PASS: TestLeadEndsWhenItsConnectionHangs (3.11s)783=== RUN TestGCAdvisoryLockBlocksConcurrentRun784=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun785=== RUN TestGCBugBareHashReferences786=== PAUSE TestGCBugBareHashReferences787=== RUN TestGCMetrics788=== PAUSE TestGCMetrics789=== RUN TestPushDedupSurvivesConcurrentGC790=== PAUSE TestPushDedupSurvivesConcurrentGC791=== RUN TestDeduplicatedObjectsRecordedAsPending792=== PAUSE TestDeduplicatedObjectsRecordedAsPending793=== RUN TestGCSweepSkipsPendingObjects794=== PAUSE TestGCSweepSkipsPendingObjects795=== RUN TestTombstonedObjectOfferedWithoutWaiting796=== PAUSE TestTombstonedObjectOfferedWithoutWaiting797=== RUN TestGCSweepDeliversEachKeyOnce798=== PAUSE TestGCSweepDeliversEachKeyOnce799=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection800=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection801=== RUN TestForceGCDuringPushOffersSweptObject802=== PAUSE TestForceGCDuringPushOffersSweptObject803=== RUN TestFailedS3DeleteKeepsTombstone804=== PAUSE TestFailedS3DeleteKeepsTombstone805=== RUN TestSweepSkipsRowsLockedByPush806=== PAUSE TestSweepSkipsRowsLockedByPush807=== RUN TestRegisterCompletedObjectNeedsPendingRow808=== PAUSE TestRegisterCompletedObjectNeedsPendingRow809=== RUN TestGetExistingObjectsLocksRows810=== PAUSE TestGetExistingObjectsLocksRows811=== RUN TestSweepRechecksPendingAfterLocking812=== PAUSE TestSweepRechecksPendingAfterLocking813=== RUN TestPushWaitsForSweepHoldingRow814=== PAUSE TestPushWaitsForSweepHoldingRow815=== RUN TestCommitRacingPendingCleanupKeepsObjects816=== PAUSE TestCommitRacingPendingCleanupKeepsObjects817=== RUN TestGCEndsOnShutdown818=== PAUSE TestGCEndsOnShutdown819=== RUN TestGCTaskStore_StartNew820=== PAUSE TestGCTaskStore_StartNew821=== RUN TestGCTaskStore_DeduplicateSameParams822=== PAUSE TestGCTaskStore_DeduplicateSameParams823=== RUN TestGCTaskStore_ConflictDifferentParams824=== PAUSE TestGCTaskStore_ConflictDifferentParams825=== RUN TestGCTaskStore_GetEmpty826=== PAUSE TestGCTaskStore_GetEmpty827=== RUN TestGCTaskStore_GetReturnsLatest828=== PAUSE TestGCTaskStore_GetReturnsLatest829=== RUN TestGCTaskStore_CompletedAllowsNewTask830=== PAUSE TestGCTaskStore_CompletedAllowsNewTask831=== RUN TestGCTaskStore_PhaseUpdates832=== PAUSE TestGCTaskStore_PhaseUpdates833=== RUN TestGCTaskStore_Fail834=== PAUSE TestGCTaskStore_Fail835=== RUN TestGracefulShutdownDrainsInflight836=== PAUSE TestGracefulShutdownDrainsInflight837=== RUN TestService_healthCheckHandler838=== PAUSE TestService_healthCheckHandler839=== RUN TestService_readinessHandler840=== PAUSE TestService_readinessHandler841=== RUN TestGenerateLandingPage842=== PAUSE TestGenerateLandingPage843=== RUN TestCacheConfigHandlerMaxNarSize844=== PAUSE TestCacheConfigHandlerMaxNarSize845=== RUN TestCreatePendingClosureRejectsOversizedNAR846=== PAUSE TestCreatePendingClosureRejectsOversizedNAR847=== RUN TestNARDeduplicationMetadataUploadBug848=== PAUSE TestNARDeduplicationMetadataUploadBug849=== RUN TestMetricsInventory850=== PAUSE TestMetricsInventory851=== RUN TestMetricsCommit852=== PAUSE TestMetricsCommit853=== RUN TestService_NativeMTLS854=== PAUSE TestService_NativeMTLS855=== RUN TestServerTLSConfig856=== PAUSE TestServerTLSConfig857=== RUN TestMultipartCleanup858=== PAUSE TestMultipartCleanup859=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded860=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded861=== RUN TestPendingCleanupUsesOneCutoff862=== PAUSE TestPendingCleanupUsesOneCutoff863=== RUN TestNativeOIDCLoginPushRefresh864=== PAUSE TestNativeOIDCLoginPushRefresh865=== RUN TestObjectStatsTrigger866=== PAUSE TestObjectStatsTrigger867=== RUN TestObjectStatsLargeCommit868=== PAUSE TestObjectStatsLargeCommit869=== RUN TestOrphanedObjectsGC870=== PAUSE TestOrphanedObjectsGC871=== RUN TestOrphanedObjectsGCStressTest872=== PAUSE TestOrphanedObjectsGCStressTest873=== RUN TestCreatePin_ReservedPins874=== PAUSE TestCreatePin_ReservedPins875=== RUN TestPresentReportsOnlyClosureRoots876=== PAUSE TestPresentReportsOnlyClosureRoots877=== RUN TestPresentRefreshesOnlyStaleClosures878=== PAUSE TestPresentRefreshesOnlyStaleClosures879=== RUN TestPresentNotReportedWhileGCDeletesClosure880=== PAUSE TestPresentNotReportedWhileGCDeletesClosure881=== RUN TestParseSingleRange882=== PAUSE TestParseSingleRange883=== RUN TestProxyHeadersOnlyTrustedOnSocket8842026/10/24 18:16:31 INFO Starting HTTP server address=127.0.0.1:413258852026/10/24 18:16:31 INFO Starting HTTP server address=proxy.sock8862026/10/24 18:16:31 WARN mTLS auth: subject not in bound subjects subject="CN=someone"8872026/10/24 18:16:31 INFO Shutdown signal received, draining in-flight requests timeout=10s888--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.10s)889=== RUN TestIsValidCachePath890=== PAUSE TestIsValidCachePath891=== RUN TestReadProxyNarinfo892=== PAUSE TestReadProxyNarinfo893=== RUN TestReadProxyNarinfoAlreadyDecompressed894=== PAUSE TestReadProxyNarinfoAlreadyDecompressed895=== RUN TestReadProxyContentNegotiation896=== PAUSE TestReadProxyContentNegotiation897=== RUN TestReadProxyNarStreaming898=== PAUSE TestReadProxyNarStreaming899=== RUN TestReadProxy404900=== PAUSE TestReadProxy404901=== RUN TestReadProxyInvalidPath902=== PAUSE TestReadProxyInvalidPath903=== RUN TestReadProxyHead904=== PAUSE TestReadProxyHead905=== RUN TestReadProxyOutlastsServerWriteTimeout906=== PAUSE TestReadProxyOutlastsServerWriteTimeout907=== RUN TestReadProxyConditionalGet908=== PAUSE TestReadProxyConditionalGet909=== RUN TestReadProxyRootRedirectsToIndexHTML910=== PAUSE TestReadProxyRootRedirectsToIndexHTML911=== RUN TestReadProxyDisabled912=== PAUSE TestReadProxyDisabled913=== RUN TestReadRedirectNar914=== PAUSE TestReadRedirectNar915=== RUN TestReadRedirectKeepsNarinfoProxied916=== PAUSE TestReadRedirectKeepsNarinfoProxied917=== RUN TestReadProxyRangeRequest918=== PAUSE TestReadProxyRangeRequest919=== RUN TestReadRedirectUsesPublicS3URL920=== PAUSE TestReadRedirectUsesPublicS3URL921=== RUN TestPush_OverlappingRootsStoreOneRowPerKey922=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey923=== RUN TestPush_CompleteCommitsEveryRoot924=== PAUSE TestPush_CompleteCommitsEveryRoot925=== RUN TestPush_RepeatedRootCommitsOnce926=== PAUSE TestPush_RepeatedRootCommitsOnce927=== RUN TestPush_CompleteWaitsForCleanupOfThePush928=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush929=== RUN TestPush_RootsAreLockedInByteOrder930=== PAUSE TestPush_RootsAreLockedInByteOrder931=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit932=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit933=== RUN TestPush_RejectsBadRequests934=== PAUSE TestPush_RejectsBadRequests935=== RUN TestPush_SignsNarinfosOfItsPendingObjects936=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects937=== RUN TestRedundantMultipartUpload938=== PAUSE TestRedundantMultipartUpload939=== RUN TestCompleteMultipartUpload_ErrorButObjectExists940=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists941=== RUN TestCompletedNarNotReofferedAcrossClosures942=== PAUSE TestCompletedNarNotReofferedAcrossClosures943=== RUN TestPresignedUploadRegisteredBeforeCommit944=== PAUSE TestPresignedUploadRegisteredBeforeCommit945=== RUN TestService_Rustfstest946=== PAUSE TestService_Rustfstest947=== RUN TestParseSize948=== PAUSE TestParseSize949=== RUN TestSkippedUploadsHandler950=== PAUSE TestSkippedUploadsHandler951=== RUN TestSystemdListenerNotActivated952--- PASS: TestSystemdListenerNotActivated (0.00s)953=== RUN TestWatchdogBeatsWhenHealthy954--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)955=== RUN TestWatchdogSkipsWhenUnhealthy9562026/10/24 18:16:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9572026/10/24 18:16:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9582026/10/24 18:16:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9592026/10/24 18:16:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9602026/10/24 18:16:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9612026/10/24 18:16:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9622026/10/24 18:16:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9632026/10/24 18:16:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9642026/10/24 18:16:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9652026/10/24 18:16:31 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"966--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)967=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle968=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle969=== RUN TestProxyWriteTimeout970=== PAUSE TestProxyWriteTimeout971=== RUN TestPendingClosureWriteTimeout972=== PAUSE TestPendingClosureWriteTimeout973=== RUN TestIsValidUploadKey974=== PAUSE TestIsValidUploadKey975=== RUN TestUploadHandlersRejectInvalidKeys976=== PAUSE TestUploadHandlersRejectInvalidKeys977=== RUN TestUploadHandlersRejectOversizedBody978=== PAUSE TestUploadHandlersRejectOversizedBody979=== RUN TestService_cleanupPendingClosuresHandler980=== PAUSE TestService_cleanupPendingClosuresHandler981=== RUN TestService_createPendingClosureHandler982=== PAUSE TestService_createPendingClosureHandler983=== RUN TestService_verifyS3Integrity984=== PAUSE TestService_verifyS3Integrity985=== RUN TestCompleteMultipartUnregistered986=== PAUSE TestCompleteMultipartUnregistered987=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT988=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT989=== CONT TestService_AuthMiddleware990=== CONT TestPush_CompleteWaitsForCleanupOfThePush991=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT992=== CONT TestCompleteMultipartUnregistered993=== CONT TestService_verifyS3Integrity994=== CONT TestService_createPendingClosureHandler995=== CONT TestService_cleanupPendingClosuresHandler996=== CONT TestUploadHandlersRejectOversizedBody997=== CONT TestUploadHandlersRejectInvalidKeys998=== CONT TestIsValidUploadKey999=== CONT TestPendingClosureWriteTimeout1000=== RUN TestIsValidUploadKey/narinfo1001=== RUN TestPendingClosureWriteTimeout/empty1002=== PAUSE TestPendingClosureWriteTimeout/empty1003=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1004=== CONT TestSkippedUploadsHandler1005=== CONT TestParseSize1006=== CONT TestService_Rustfstest1007=== CONT TestPresignedUploadRegisteredBeforeCommit1008=== CONT TestCompletedNarNotReofferedAcrossClosures1009=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1010=== CONT TestRedundantMultipartUpload1011=== CONT TestPush_SignsNarinfosOfItsPendingObjects1012=== CONT TestPush_RejectsBadRequests1013=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1014=== CONT TestPush_RootsAreLockedInByteOrder1015=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1016=== CONT TestProxyWriteTimeout1017=== PAUSE TestIsValidUploadKey/narinfo1018=== RUN TestIsValidUploadKey/nar_zst1019=== PAUSE TestIsValidUploadKey/nar_zst1020=== RUN TestIsValidUploadKey/nar_xz1021=== PAUSE TestIsValidUploadKey/nar_xz1022=== RUN TestIsValidUploadKey/nar_plain1023=== PAUSE TestIsValidUploadKey/nar_plain1024=== RUN TestIsValidUploadKey/listing1025=== PAUSE TestIsValidUploadKey/listing1026=== RUN TestIsValidUploadKey/build_log1027=== PAUSE TestIsValidUploadKey/build_log1028=== RUN TestIsValidUploadKey/build_log_home-manager_file1029=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1030=== RUN TestIsValidUploadKey/build_log_plus_in_name1031=== RUN TestPendingClosureWriteTimeout/400_objects1032--- PASS: TestParseSize (0.00s)10332026/10/24 18:16:31 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001034=== CONT TestPresentReportsOnlyClosureRoots1035--- PASS: TestSkippedUploadsHandler (0.01s)1036=== CONT TestPush_RepeatedRootCommitsOnce1037=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1038=== RUN TestIsValidUploadKey/build_log_question_mark1039=== RUN TestProxyWriteTimeout/narinfo1040=== PAUSE TestPendingClosureWriteTimeout/400_objects1041=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1042=== PAUSE TestProxyWriteTimeout/narinfo1043=== RUN TestPendingClosureWriteTimeout/670k_objects1044=== PAUSE TestPendingClosureWriteTimeout/670k_objects1045=== PAUSE TestIsValidUploadKey/build_log_question_mark1046=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1047=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1048=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1049=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1050=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1051=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1052=== RUN TestProxyWriteTimeout/1_GiB_nar1053=== PAUSE TestProxyWriteTimeout/1_GiB_nar1054=== RUN TestProxyWriteTimeout/10_GiB_nar1055=== PAUSE TestProxyWriteTimeout/10_GiB_nar1056=== RUN TestProxyWriteTimeout/unknown_size1057=== PAUSE TestProxyWriteTimeout/unknown_size1058=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1059=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1060=== CONT TestReadRedirectUsesPublicS3URL1061=== RUN TestIsValidUploadKey/build_log_equals1062=== PAUSE TestIsValidUploadKey/build_log_equals1063=== RUN TestIsValidUploadKey/realisation1064=== PAUSE TestIsValidUploadKey/realisation1065=== RUN TestIsValidUploadKey/realisation_plus_in_output1066=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1067=== RUN TestIsValidUploadKey/nix-cache-info1068=== PAUSE TestIsValidUploadKey/nix-cache-info1069=== CONT TestPush_CompleteCommitsEveryRoot1070=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1071=== RUN TestIsValidUploadKey/index.html1072=== PAUSE TestIsValidUploadKey/index.html1073=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1074=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1075=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1076=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1077=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1078=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1079=== RUN TestIsValidUploadKey/traversal1080=== PAUSE TestIsValidUploadKey/traversal1081=== RUN TestIsValidUploadKey/traversal_nar1082=== PAUSE TestIsValidUploadKey/traversal_nar1083=== RUN TestIsValidUploadKey/absolute1084=== PAUSE TestIsValidUploadKey/absolute1085=== RUN TestIsValidUploadKey/empty_key1086=== PAUSE TestIsValidUploadKey/empty_key1087=== RUN TestIsValidUploadKey/unknown_type1088=== PAUSE TestIsValidUploadKey/unknown_type1089=== CONT TestReadProxyRangeRequest1090=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1091=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1092=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1093=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1094=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1095=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1096=== CONT TestGCTaskStore_GetReturnsLatest1097--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1098=== CONT TestReadRedirectKeepsNarinfoProxied10992026/10/24 18:16:31 INFO Received uploads request method=POST path=/api/pending_closures11002026/10/24 18:16:31 INFO Received cleanup request method=DELETE path=/api/pending_closures11012026/10/24 18:16:31 INFO Aborted multipart uploads count=0 kept=01102--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.31s)1103=== CONT TestCreatePin_ReservedPins11042026/10/24 18:16:31 INFO Received uploads request method=POST path=/api/pending_closures11052026/10/24 18:16:31 INFO Received cleanup request method=DELETE path=/api/pending_closures11062026/10/24 18:16:31 INFO Aborted multipart uploads count=1 kept=011072026/10/24 18:16:31 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11082026-10-24 18:16:31.786 UTC [461] ERROR: Closure does not exist: id=111092026-10-24 18:16:31.786 UTC [461] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE11102026-10-24 18:16:31.786 UTC [461] STATEMENT: -- name: CommitPendingClosure :one1111 SELECT commit_pending_closure($1::bigint)::bigint1112 11132026/10/24 18:16:31 INFO Received push request method=POST path=/api/pushes1114--- PASS: TestService_cleanupPendingClosuresHandler (0.33s)1115=== CONT TestReadRedirectNar11162026/10/24 18:16:31 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1117--- PASS: TestService_AuthMiddleware (0.35s)1118=== CONT TestOrphanedObjectsGCStressTest11192026/10/24 18:16:31 INFO Received uploads request method=POST path=/api/pending_closures11202026/10/24 18:16:31 INFO Received uploads request method=POST path=/api/pending_closures11212026/10/24 18:16:31 INFO Received uploads request method=POST path=/api/pending_closures1122--- PASS: TestService_Rustfstest (0.38s)1123=== CONT TestReadProxyDisabled1124=== RUN TestPush_RejectsBadRequests/bad_root1125=== PAUSE TestPush_RejectsBadRequests/bad_root1126=== RUN TestPush_RejectsBadRequests/root_not_in_objects1127=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1128=== RUN TestPush_RejectsBadRequests/no_roots1129=== PAUSE TestPush_RejectsBadRequests/no_roots1130=== RUN TestPush_RejectsBadRequests/no_objects1131=== PAUSE TestPush_RejectsBadRequests/no_objects1132=== CONT TestOrphanedObjectsGC11332026/10/24 18:16:31 INFO Received uploads request method=POST path=/api/pending_closures11342026/10/24 18:16:31 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46203/oidc11352026/10/24 18:16:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11362026/10/24 18:16:31 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1137--- PASS: TestCompleteMultipartUnregistered (0.43s)1138=== CONT TestReadProxyRootRedirectsToIndexHTML11392026/10/24 18:16:31 INFO Received uploads request method=POST path=/api/pending_closures1140--- PASS: TestPresentReportsOnlyClosureRoots (0.47s)1141=== CONT TestReadProxyConditionalGet11422026/10/24 18:16:31 INFO Received uploads request method=POST path=/api/pending_closures11432026/10/24 18:16:31 INFO Received uploads request method=POST path=/api/pending_closures11442026/10/24 18:16:31 INFO Received uploads request method=POST path=/api/pending_closures11452026/10/24 18:16:31 INFO Received push request method=POST path=/api/pushes11462026/10/24 18:16:31 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11472026/10/24 18:16:31 INFO Received uploads request method=POST path=/api/pending_closures1148--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.53s)1149=== CONT TestObjectStatsLargeCommit11502026/10/24 18:16:32 INFO Received complete push request method=POST path=/api/pushes/1/complete11512026/10/24 18:16:32 INFO Received uploads request method=POST path=/api/pending_closures11522026/10/24 18:16:32 INFO Completed push id=1 objects=4 duration=7.344042ms1153--- PASS: TestPush_RepeatedRootCommitsOnce (0.54s)1154=== CONT TestObjectStatsTrigger11552026/10/24 18:16:32 INFO Received push request method=POST path=/api/pushes11562026/10/24 18:16:32 INFO Received push request method=POST path=/api/pushes11572026/10/24 18:16:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11582026/10/24 18:16:32 INFO Signed narinfos id=1 count=111592026/10/24 18:16:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11602026/10/24 18:16:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11612026/10/24 18:16:32 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"11622026/10/24 18:16:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11632026/10/24 18:16:32 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"11642026/10/24 18:16:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11652026/10/24 18:16:32 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=111662026/10/24 18:16:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11672026/10/24 18:16:32 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1168--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.59s)1169=== CONT TestNativeOIDCLoginPushRefresh1170=== RUN TestNativeOIDCLoginPushRefresh/new-id-token1171=== PAUSE TestNativeOIDCLoginPushRefresh/new-id-token1172=== RUN TestNativeOIDCLoginPushRefresh/omitted-id-token1173=== PAUSE TestNativeOIDCLoginPushRefresh/omitted-id-token1174=== CONT TestPendingCleanupUsesOneCutoff11752026/10/24 18:16:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11762026/10/24 18:16:32 INFO Received push request method=POST path=/api/pushes1177--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.50s)1178=== CONT TestReadProxyOutlastsServerWriteTimeout11792026/10/24 18:16:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11802026/10/24 18:16:32 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZDdiYzgwNzgtM2UxZS00MmVkLWFmOTMtMmUyMDA3MmQ0MzEwLjE5OWVkNGI5LTEwYjgtNDEwZS05OTlhLWFkZGYzMGU5Y2Y0YXgxNzkyODY1NzkxODI4OTI5NTAy parts=1011812026/10/24 18:16:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11822026/10/24 18:16:32 INFO Received complete push request method=POST path=/api/pushes/1/complete11832026/10/24 18:16:32 INFO Completed upload id=1 objects=2 duration=3.527441ms11842026/10/24 18:16:32 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011852026/10/24 18:16:32 INFO Received uploads request method=POST path=/api/pending_closures11862026-10-24 18:16:32.100 UTC [493] ERROR: Push does not exist: id=111872026-10-24 18:16:32.100 UTC [493] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11882026-10-24 18:16:32.100 UTC [493] STATEMENT: SELECT commit_push($1)1189--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.64s)1190=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded11912026/10/24 18:16:32 INFO Starting cleanup of old closures method=DELETE path=/api/closures1192--- PASS: TestReadProxyRangeRequest (0.53s)1193=== CONT TestMultipartCleanup11942026/10/24 18:16:32 INFO Completed push id=1 objects=6 duration=9.572393ms1195--- PASS: TestPush_CompleteCommitsEveryRoot (0.53s)1196=== CONT TestServerTLSConfig1197=== RUN TestServerTLSConfig/no_client_CA1198=== PAUSE TestServerTLSConfig/no_client_CA1199=== RUN TestServerTLSConfig/missing_CA_file1200=== PAUSE TestServerTLSConfig/missing_CA_file1201=== RUN TestServerTLSConfig/not_a_PEM_file1202=== PAUSE TestServerTLSConfig/not_a_PEM_file1203=== CONT TestReadProxyHead12042026/10/24 18:16:32 INFO Aborted multipart uploads count=0 kept=012052026/10/24 18:16:32 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=01206--- PASS: TestReadRedirectUsesPublicS3URL (0.55s)1207=== CONT TestService_NativeMTLS12082026/10/24 18:16:32 INFO Vacuumed table table=pending_closures12092026/10/24 18:16:32 INFO Vacuumed table table=pending_objects12102026/10/24 18:16:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12112026/10/24 18:16:32 INFO Received push request method=POST path=/api/pushes12122026/10/24 18:16:32 INFO Vacuumed table table=multipart_uploads12132026/10/24 18:16:32 INFO Received uploads request method=POST path=/api/pending_closures12142026/10/24 18:16:32 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZDdiYzgwNzgtM2UxZS00MmVkLWFmOTMtMmUyMDA3MmQ0MzEwLjU2YzVhYTUzLTc5ZTMtNGFhYS04NDg5LThmMzkwZTc1ODgzNXgxNzkyODY1NzkxODc2NTA3NDE2 parts=1012152026/10/24 18:16:32 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12162026/10/24 18:16:32 INFO Vacuumed table table=closures12172026/10/24 18:16:32 INFO Completed upload id=1 objects=2 duration=4.927451ms12182026/10/24 18:16:32 INFO Vacuumed table table=objects12192026/10/24 18:16:32 INFO Received uploads request method=POST path=/api/pending_closures12202026/10/24 18:16:32 INFO Received uploads request method=POST path=/api/pending_closures12212026/10/24 18:16:32 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12222026/10/24 18:16:32 WARN Found objects in DB but missing from S3, will re-upload count=11223--- PASS: TestService_verifyS3Integrity (0.71s)1224=== CONT TestReadProxyInvalidPath12252026/10/24 18:16:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1226--- PASS: TestReadRedirectKeepsNarinfoProxied (0.52s)1227=== CONT TestMetricsCommit12282026/10/24 18:16:32 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDdiYzgwNzgtM2UxZS00MmVkLWFmOTMtMmUyMDA3MmQ0MzEwLjJlOTA2MWIxLTBkM2ItNDFmMi1hODA3LWQ3ODU3YjI5ZjI0N3gxNzkyODY1NzkyMTYxMjEwODI012292026-10-24 18:16:32.181 UTC [553] ERROR: could not obtain lock on row in relation "closures"12302026-10-24 18:16:32.181 UTC [553] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12312026-10-24 18:16:32.181 UTC [553] ERROR: could not obtain lock on row in relation "closures"12322026-10-24 18:16:32.181 UTC [553] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12332026-10-24 18:16:32.182 UTC [553] ERROR: could not obtain lock on row in relation "closures"12342026-10-24 18:16:32.182 UTC [553] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12352026-10-24 18:16:32.182 UTC [553] ERROR: could not obtain lock on row in relation "closures"12362026-10-24 18:16:32.182 UTC [553] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12372026-10-24 18:16:32.182 UTC [553] ERROR: could not obtain lock on row in relation "closures"12382026-10-24 18:16:32.182 UTC [553] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1239--- PASS: TestPush_RootsAreLockedInByteOrder (0.62s)1240=== CONT TestReadProxy40412412026/10/24 18:16:32 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZDdiYzgwNzgtM2UxZS00MmVkLWFmOTMtMmUyMDA3MmQ0MzEwLjJlOTA2MWIxLTBkM2ItNDFmMi1hODA3LWQ3ODU3YjI5ZjI0N3gxNzkyODY1NzkyMTYxMjEwODI0 parts=11242--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.62s)1243=== CONT TestMetricsInventory12442026/10/24 18:16:32 INFO Received push request method=POST path=/api/pushes12452026/10/24 18:16:32 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001246--- PASS: TestService_createPendingClosureHandler (0.75s)1247=== CONT TestReadProxyNarStreaming12482026/10/24 18:16:32 INFO Received complete push request method=POST path=/api/pushes/1/complete12492026/10/24 18:16:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1250--- PASS: TestReadRedirectNar (0.46s)1251=== CONT TestNARDeduplicationMetadataUploadBug12522026/10/24 18:16:32 INFO Completed push id=1 objects=4 duration=9.402533ms12532026/10/24 18:16:32 INFO Received push request method=POST path=/api/pushes12542026/10/24 18:16:32 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZDdiYzgwNzgtM2UxZS00MmVkLWFmOTMtMmUyMDA3MmQ0MzEwLmI0YWJkNzQ1LWM5NGMtNGJlNy1hMDQyLWEzY2UzNThjNTU1NHgxNzkyODY1NzkxOTIwNDQ3MTA4 parts=1212552026/10/24 18:16:32 INFO Received uploads request method=POST path=/api/pending_closures1256--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.81s)1257=== CONT TestCreatePendingClosureRejectsOversizedNAR12582026/10/24 18:16:32 INFO Received uploads request method=POST path=/api/pending_closures1259--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1260=== CONT TestCacheConfigHandlerMaxNarSize1261--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1262=== CONT TestGenerateLandingPage1263--- PASS: TestGenerateLandingPage (0.00s)1264=== CONT TestService_readinessHandler1265--- PASS: TestReadProxyDisabled (0.45s)1266=== CONT TestService_healthCheckHandler12672026/10/24 18:16:32 INFO Aborted multipart uploads count=0 kept=012682026/10/24 18:16:32 WARN Force mode enabled - objects will be deleted immediately without grace period12692026/10/24 18:16:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12702026/10/24 18:16:32 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=012712026/10/24 18:16:32 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12722026/10/24 18:16:32 WARN Refused reserved pin name=worker-x86_64-linux12732026/10/24 18:16:32 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12742026/10/24 18:16:32 INFO Received create pin request method=POST path=/api/pins/my-app12752026/10/24 18:16:32 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1276--- PASS: TestCreatePin_ReservedPins (0.56s)1277=== CONT TestReadProxyContentNegotiation12782026/10/24 18:16:32 INFO Vacuumed table table=pending_closures12792026/10/24 18:16:32 INFO Vacuumed table table=pending_objects12802026/10/24 18:16:32 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZDdiYzgwNzgtM2UxZS00MmVkLWFmOTMtMmUyMDA3MmQ0MzEwLjUzNmRlMzg1LTc2ZDQtNDJiZC05ZTQ3LTgwNTEzYzVmZGU3YXgxNzkyODY1NzkxOTUwNTc2MDY2 parts=1212812026/10/24 18:16:32 INFO Received uploads request method=POST path=/api/pending_closures12822026/10/24 18:16:32 INFO Vacuumed table table=multipart_uploads1283--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.47s)1284=== CONT TestGracefulShutdownDrainsInflight12852026/10/24 18:16:32 INFO Vacuumed table table=closures12862026/10/24 18:16:32 INFO Starting HTTP server address=127.0.0.1:3981512872026/10/24 18:16:32 INFO Shutdown signal received, draining in-flight requests timeout=10s12882026/10/24 18:16:32 INFO Received uploads request method=POST path=/api/pending_closures12892026/10/24 18:16:32 INFO Vacuumed table table=objects12902026/10/24 18:16:32 INFO Received complete push request method=POST path=/api/pushes/2/complete12912026/10/24 18:16:32 INFO Completed push id=2 objects=4 duration=4.912651ms1292--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.80s)1293=== CONT TestReadProxyNarinfoAlreadyDecompressed1294--- PASS: TestReadProxyConditionalGet (0.45s)1295=== CONT TestGCTaskStore_Fail1296--- PASS: TestGCTaskStore_Fail (0.00s)1297=== CONT TestReadProxyNarinfo1298--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1299=== CONT TestGCTaskStore_PhaseUpdates1300--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1301=== CONT TestIsValidCachePath1302=== RUN TestIsValidCachePath/narinfo1303=== PAUSE TestIsValidCachePath/narinfo1304=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1305=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1306=== RUN TestIsValidCachePath/nar_zst1307=== PAUSE TestIsValidCachePath/nar_zst1308=== RUN TestIsValidCachePath/nar_xz1309=== PAUSE TestIsValidCachePath/nar_xz1310=== RUN TestIsValidCachePath/nar_bz21311=== PAUSE TestIsValidCachePath/nar_bz21312=== RUN TestIsValidCachePath/nar_uncompressed1313=== PAUSE TestIsValidCachePath/nar_uncompressed1314=== RUN TestIsValidCachePath/ls1315=== PAUSE TestIsValidCachePath/ls1316=== RUN TestIsValidCachePath/log1317=== PAUSE TestIsValidCachePath/log1318=== RUN TestIsValidCachePath/realisation1319=== PAUSE TestIsValidCachePath/realisation1320=== RUN TestIsValidCachePath/nix-cache-info1321=== PAUSE TestIsValidCachePath/nix-cache-info1322=== RUN TestIsValidCachePath/index.html1323=== PAUSE TestIsValidCachePath/index.html1324=== RUN TestIsValidCachePath/traversal_parent1325=== PAUSE TestIsValidCachePath/traversal_parent1326=== RUN TestIsValidCachePath/traversal_in_middle1327=== PAUSE TestIsValidCachePath/traversal_in_middle1328=== RUN TestIsValidCachePath/invalid_char_e1329=== PAUSE TestIsValidCachePath/invalid_char_e1330=== RUN TestIsValidCachePath/invalid_char_u1331=== PAUSE TestIsValidCachePath/invalid_char_u1332=== RUN TestIsValidCachePath/random_path1333=== PAUSE TestIsValidCachePath/random_path1334=== RUN TestIsValidCachePath/empty1335=== PAUSE TestIsValidCachePath/empty1336=== RUN TestIsValidCachePath/leading_slash1337=== PAUSE TestIsValidCachePath/leading_slash1338=== RUN TestIsValidCachePath/wrong_extension1339=== PAUSE TestIsValidCachePath/wrong_extension1340=== RUN TestIsValidCachePath/short_hash1341=== PAUSE TestIsValidCachePath/short_hash1342=== CONT TestGCTaskStore_CompletedAllowsNewTask1343--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1344=== CONT TestParseSingleRange1345=== RUN TestParseSingleRange/none1346=== PAUSE TestParseSingleRange/none1347=== RUN TestParseSingleRange/unknown_unit1348=== PAUSE TestParseSingleRange/unknown_unit1349=== RUN TestParseSingleRange/multi-range_ignored1350=== PAUSE TestParseSingleRange/multi-range_ignored1351=== RUN TestParseSingleRange/malformed_no_dash1352=== PAUSE TestParseSingleRange/malformed_no_dash1353=== RUN TestParseSingleRange/malformed_both_empty1354=== PAUSE TestParseSingleRange/malformed_both_empty1355=== RUN TestParseSingleRange/malformed_end_before_start1356=== PAUSE TestParseSingleRange/malformed_end_before_start1357=== RUN TestParseSingleRange/closed1358=== PAUSE TestParseSingleRange/closed1359=== RUN TestParseSingleRange/open-ended1360=== PAUSE TestParseSingleRange/open-ended1361=== RUN TestParseSingleRange/end_clamped_to_size1362=== PAUSE TestParseSingleRange/end_clamped_to_size1363=== RUN TestParseSingleRange/suffix1364=== PAUSE TestParseSingleRange/suffix1365=== RUN TestParseSingleRange/suffix_exceeds_size1366=== PAUSE TestParseSingleRange/suffix_exceeds_size1367=== RUN TestParseSingleRange/single_byte1368=== PAUSE TestParseSingleRange/single_byte1369=== RUN TestParseSingleRange/start_past_EOF1370=== PAUSE TestParseSingleRange/start_past_EOF1371=== RUN TestParseSingleRange/start_far_past_EOF1372=== PAUSE TestParseSingleRange/start_far_past_EOF1373=== CONT TestPresentNotReportedWhileGCDeletesClosure1374=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1375=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1376=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1377=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1378=== CONT TestPresentRefreshesOnlyStaleClosures13792026/10/24 18:16:32 INFO Received uploads request method=POST path=/api/pending_closures1380--- PASS: TestObjectStatsTrigger (0.44s)1381=== CONT TestLeadEndsOnShutdown13822026/10/24 18:16:32 INFO Received uploads request method=POST path=/api/pending_closures13832026/10/24 18:16:32 INFO Received cleanup request method=DELETE path=/api/pending_closures13842026/10/24 18:16:32 INFO Received uploads request method=POST path=/api/pending_closures13852026/10/24 18:16:32 INFO Received uploads request method=POST path=/api/pending_closures1386--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.44s)1387=== CONT TestClientMultipleUploads1388--- PASS: TestReadProxyHead (0.43s)1389=== CONT TestGCTaskStore_GetEmpty1390--- PASS: TestGCTaskStore_GetEmpty (0.00s)1391=== CONT TestLeadIncumbentAnnouncesAtOnce13922026/10/24 18:16:32 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13932026/10/24 18:16:32 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1394--- PASS: TestService_NativeMTLS (0.43s)1395=== CONT TestGCTaskStore_ConflictDifferentParams1396--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1397=== CONT TestLeadElectsOneAndHandsOver1398--- PASS: TestReadProxyInvalidPath (0.41s)1399=== CONT TestGCTaskStore_DeduplicateSameParams1400--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1401=== CONT TestConnectWaitsForAPeerMigration14022026/10/24 18:16:32 INFO Received push request method=POST path=/api/pushes14032026/10/24 18:16:32 INFO Received cleanup request method=DELETE path=/api/pending_closures14042026/10/24 18:16:32 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket39/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""14052026/10/24 18:16:32 INFO Aborted multipart uploads count=0 kept=114062026/10/24 18:16:32 INFO Received cleanup request method=DELETE path=/api/pending_closures14072026/10/24 18:16:32 INFO Aborted multipart uploads count=1 kept=01408--- PASS: TestMultipartCleanup (0.52s)1409=== CONT TestGCTaskStore_StartNew1410--- PASS: TestGCTaskStore_StartNew (0.00s)1411=== CONT TestGCEndsOnShutdown1412=== RUN TestGCEndsOnShutdown/before_the_run1413=== PAUSE TestGCEndsOnShutdown/before_the_run1414=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1415=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1416=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1417=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1418=== CONT TestResolveDBConnectionString1419=== RUN TestResolveDBConnectionString/flag_wins1420=== PAUSE TestResolveDBConnectionString/flag_wins1421=== RUN TestResolveDBConnectionString/file_when_flag_empty1422=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1423=== RUN TestResolveDBConnectionString/missing_file_is_an_error1424=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1425=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1426=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1427=== RUN TestResolveDBConnectionString/nothing_configured1428=== PAUSE TestResolveDBConnectionString/nothing_configured1429=== CONT TestCommitRacingPendingCleanupKeepsObjects14302026/10/24 18:16:32 INFO Received complete push request method=POST path=/api/pushes/1/complete1431--- PASS: TestReadProxy404 (0.46s)1432=== CONT TestPushWaitsForSweepHoldingRow14332026/10/24 18:16:32 INFO Completed push id=1 objects=4 duration=11.209093ms14342026/10/24 18:16:32 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1435=== NAME TestOrphanedObjectsGC1436 orphaned_objects_gc_test.go:287: GC Test Summary:1437 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1438 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1439 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1440 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)14412026/10/24 18:16:32 INFO Completed upload id=2 objects=2 duration=2.00695ms1442 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1443--- PASS: TestOrphanedObjectsGC (0.81s)1444=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1445--- PASS: TestReadProxyNarStreaming (0.45s)1446=== CONT TestSweepRechecksPendingAfterLocking1447--- PASS: TestMetricsCommit (0.48s)1448=== CONT TestDeleteClosuresRacingPins1449--- PASS: TestMetricsInventory (0.52s)1450=== CONT TestClientFallsBackToClosures14512026/10/24 18:16:32 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14522026/10/24 18:16:32 WARN readiness check failed error="closed pool"1453--- PASS: TestService_readinessHandler (0.44s)1454=== CONT TestGetExistingObjectsLocksRows14552026/10/24 18:16:32 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDdiYzgwNzgtM2UxZS00MmVkLWFmOTMtMmUyMDA3MmQ0MzEwLjU1ODI2OWU0LTI2YmQtNDE3OS1iMDMxLWM2YTFjM2ViODRlYXgxNzkyODY1NzkyMzYxNTQ3NDM5 error="Get \"http://127.0.0.1:1/bucket15/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"14562026/10/24 18:16:32 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZDdiYzgwNzgtM2UxZS00MmVkLWFmOTMtMmUyMDA3MmQ0MzEwLjQzNTQ2YTE4LThlYTgtNGFkYi04NGJkLTkxODE1N2RjMWUyM3gxNzkyODY1NzkyMzU0NDczOTI3 parts=1214572026/10/24 18:16:32 INFO Received cleanup request method=DELETE path=/api/pending_closures14582026/10/24 18:16:32 INFO Aborted multipart uploads count=1 kept=01459--- PASS: TestService_healthCheckHandler (0.45s)1460=== CONT TestClientPushesUseOnePush1461--- PASS: TestRedundantMultipartUpload (1.27s)1462=== CONT TestPinProtectsFromGC1463=== NAME TestNARDeduplicationMetadataUploadBug1464 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug361060423/001/store/92fjbd405kg6pimyx286rfp7fa22spk6-file1.txt1465--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.41s)1466=== CONT TestRegisterCompletedObjectNeedsPendingRow1467--- PASS: TestReadProxyContentNegotiation (0.45s)1468=== CONT TestClientSharedPathCommittedMidPush14692026/10/24 18:16:32 INFO Received push request method=POST path=/api/pushes1470--- PASS: TestPresentRefreshesOnlyStaleClosures (0.39s)1471=== CONT TestSweepSkipsRowsLockedByPush14722026/10/24 18:16:32 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14732026/10/24 18:16:32 INFO Uploading 92fjbd405kg6pimyx286rfp7fa22spk6-file1.txt (160B)14742026/10/24 18:16:32 INFO lead: acquired remote=192.0.2.1:123414752026/10/24 18:16:32 WARN Failed to register uploaded object key=92fjbd405kg6pimyx286rfp7fa22spk6.ls error="server returned 404: 404 page not found\n"14762026/10/24 18:16:32 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14772026/10/24 18:16:32 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"14782026/10/24 18:16:32 INFO Signed narinfos id=1 count=114792026/10/24 18:16:32 INFO Uploading 1 narinfos14802026/10/24 18:16:32 INFO Received complete push request method=POST path=/api/pushes/1/complete14812026/10/24 18:16:32 WARN Failed to register uploaded object key=92fjbd405kg6pimyx286rfp7fa22spk6.narinfo error="server returned 404: 404 page not found\n"14822026/10/24 18:16:32 INFO Completed push id=1 objects=3 duration=8.862403ms14832026/10/24 18:16:32 INFO Upload complete. (68ms)1484=== NAME TestNARDeduplicationMetadataUploadBug1485 metadata_upload_test.go:54: Retrieved narinfo from S3:1486 StorePath: /build/TestNARDeduplicationMetadataUploadBug361060423/001/store/92fjbd405kg6pimyx286rfp7fa22spk6-file1.txt1487 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1488 Compression: zstd1489 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1490 NarSize: 1601491 References: 1492 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1493 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1494 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1495 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}14962026/10/24 18:16:32 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1497--- PASS: TestReadProxyNarinfo (0.47s)1498=== CONT TestClientWithDependencies14992026/10/24 18:16:32 INFO lead: acquired remote=192.0.2.1:123415002026/10/24 18:16:32 INFO lead: released remote=192.0.2.1:12341501--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.33s)1502=== CONT TestFailedS3DeleteKeepsTombstone1503=== NAME TestNARDeduplicationMetadataUploadBug1504 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug361060423/001/store/bgv96vs7663wnzic4hyws889np6bdznz-file2.txt15052026/10/24 18:16:32 INFO lead: acquired remote=192.0.2.1:12341506=== NAME TestClientMultipleUploads1507 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads4100633040/001/store/2bll07iwjgw4y9zg0njyan6qlayj5xym-test-file-0.txt1508 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads4100633040/001/store/21x7inf036qs3blp0h93gki1pl4k898k-test-file-1.txt15092026/10/24 18:16:32 INFO Aborted multipart uploads count=0 kept=015102026/10/24 18:16:32 WARN Force mode enabled - objects will be deleted immediately without grace period15112026/10/24 18:16:32 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015122026/10/24 18:16:32 INFO Vacuumed table table=pending_closures15132026/10/24 18:16:32 INFO Received push request method=POST path=/api/pushes15142026/10/24 18:16:32 INFO Vacuumed table table=pending_objects15152026/10/24 18:16:32 INFO Vacuumed table table=multipart_uploads15162026/10/24 18:16:32 INFO Vacuumed table table=closures15172026/10/24 18:16:32 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)15182026/10/24 18:16:32 INFO Vacuumed table table=objects1519 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads4100633040/001/store/l142zqqk0766c8789gd49jb3q1vl4bmk-test-file-2.txt15202026/10/24 18:16:32 WARN Failed to register uploaded object key=bgv96vs7663wnzic4hyws889np6bdznz.ls error="server returned 404: 404 page not found\n"15212026/10/24 18:16:32 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15222026/10/24 18:16:32 INFO Signed narinfos id=2 count=115232026/10/24 18:16:32 INFO Uploading 1 narinfos1524--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.33s)1525=== CONT TestForceGCDuringPushOffersSweptObject1526=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1527=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1528=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1529=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1530=== CONT TestClientCADerivations15312026/10/24 18:16:32 INFO Received complete push request method=POST path=/api/pushes/2/complete15322026/10/24 18:16:32 WARN Failed to register uploaded object key=bgv96vs7663wnzic4hyws889np6bdznz.narinfo error="server returned 404: 404 page not found\n"15332026/10/24 18:16:32 INFO Aborted multipart uploads count=0 kept=015342026/10/24 18:16:32 INFO Completed push id=2 objects=3 duration=2.84617ms15352026/10/24 18:16:32 INFO Upload complete. (50ms)1536=== NAME TestNARDeduplicationMetadataUploadBug1537 metadata_upload_test.go:76: Retrieved narinfo from S3:1538 StorePath: /build/TestNARDeduplicationMetadataUploadBug361060423/001/store/bgv96vs7663wnzic4hyws889np6bdznz-file2.txt1539 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1540 Compression: zstd1541 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1542 NarSize: 1601543 References: 1544 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf15452026/10/24 18:16:32 WARN Force mode enabled - objects will be deleted immediately without grace period1546 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1547 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1548 {"version":1,"root":{"type":"regular","size":44}}1549--- PASS: TestNARDeduplicationMetadataUploadBug (0.72s)1550=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection15512026/10/24 18:16:32 INFO Received uploads request method=POST path=/api/pending_closures15522026/10/24 18:16:32 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=015532026/10/24 18:16:32 INFO Vacuumed table table=pending_closures15542026/10/24 18:16:32 INFO Vacuumed table table=pending_objects15552026/10/24 18:16:32 INFO Vacuumed table table=multipart_uploads15562026/10/24 18:16:32 INFO Vacuumed table table=closures15572026/10/24 18:16:32 INFO Vacuumed table table=objects1558--- PASS: TestSweepRechecksPendingAfterLocking (0.34s)1559=== CONT TestClientIntegration1560--- PASS: TestGetExistingObjectsLocksRows (0.30s)1561=== CONT TestGCSweepDeliversEachKeyOnce15622026/10/24 18:16:33 INFO Received push request method=POST path=/api/pushes15632026/10/24 18:16:33 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)15642026/10/24 18:16:33 INFO Uploading l142zqqk0766c8789gd49jb3q1vl4bmk-test-file-2.txt (160B)15652026/10/24 18:16:33 INFO Uploading 2bll07iwjgw4y9zg0njyan6qlayj5xym-test-file-0.txt (160B)15662026/10/24 18:16:33 INFO Uploading 21x7inf036qs3blp0h93gki1pl4k898k-test-file-1.txt (160B)15672026/10/24 18:16:33 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15682026/10/24 18:16:33 WARN Failed to register uploaded object key=l142zqqk0766c8789gd49jb3q1vl4bmk.ls error="server returned 404: 404 page not found\n"15692026/10/24 18:16:33 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15702026/10/24 18:16:33 WARN Failed to register uploaded object key=2bll07iwjgw4y9zg0njyan6qlayj5xym.ls error="server returned 404: 404 page not found\n"15712026/10/24 18:16:33 WARN Failed to register uploaded object key=21x7inf036qs3blp0h93gki1pl4k898k.ls error="server returned 404: 404 page not found\n"15722026/10/24 18:16:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15732026/10/24 18:16:33 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15742026/10/24 18:16:33 INFO Signed narinfos id=1 count=315752026/10/24 18:16:33 INFO Uploading 3 narinfos15762026/10/24 18:16:33 WARN Failed to register uploaded object key=2bll07iwjgw4y9zg0njyan6qlayj5xym.narinfo error="server returned 404: 404 page not found\n"15772026/10/24 18:16:33 WARN Failed to register uploaded object key=l142zqqk0766c8789gd49jb3q1vl4bmk.narinfo error="server returned 404: 404 page not found\n"15782026/10/24 18:16:33 INFO Received complete push request method=POST path=/api/pushes/1/complete15792026/10/24 18:16:33 WARN Failed to register uploaded object key=21x7inf036qs3blp0h93gki1pl4k898k.narinfo error="server returned 404: 404 page not found\n"15802026/10/24 18:16:33 INFO Completed push id=1 objects=9 duration=5.815992ms15812026/10/24 18:16:33 INFO Upload complete. (66ms)1582=== NAME TestClientMultipleUploads1583 client_integration_test.go:369: Uploaded 3 paths in 96.330137ms1584--- PASS: TestClientMultipleUploads (0.53s)1585=== CONT TestClientErrorHandling1586=== RUN TestClientErrorHandling/InvalidStorePath1587=== PAUSE TestClientErrorHandling/InvalidStorePath1588=== RUN TestClientErrorHandling/InvalidAuthToken1589=== PAUSE TestClientErrorHandling/InvalidAuthToken1590=== RUN TestClientErrorHandling/ServerNotAvailable1591=== PAUSE TestClientErrorHandling/ServerNotAvailable1592=== CONT TestTombstonedObjectOfferedWithoutWaiting1593--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.30s)1594=== CONT TestPushDedupSurvivesConcurrentGC15952026/10/24 18:16:33 INFO Aborted multipart uploads count=0 kept=015962026/10/24 18:16:33 WARN Force mode enabled - objects will be deleted immediately without grace period1597=== NAME TestPinProtectsFromGC1598 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC977651676/001/store/gdbsn8kxbfrcx6rsvnh9wysvy47gsi2i-pinned-file.txt1599 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC977651676/001/store/ah1jwsxz6pnrwwdvyy2yj7fvnharznkp-unpinned-file.txt16002026/10/24 18:16:33 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=016012026/10/24 18:16:33 INFO Vacuumed table table=pending_closures16022026/10/24 18:16:33 INFO Vacuumed table table=pending_objects16032026/10/24 18:16:33 INFO Vacuumed table table=multipart_uploads16042026/10/24 18:16:33 INFO Vacuumed table table=closures16052026/10/24 18:16:33 INFO Vacuumed table table=objects1606--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.49s)1607=== CONT TestGCMetrics16082026/10/24 18:16:33 INFO Aborted multipart uploads count=0 kept=016092026/10/24 18:16:33 WARN Force mode enabled - objects will be deleted immediately without grace period16102026/10/24 18:16:33 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=016112026/10/24 18:16:33 INFO Vacuumed table table=pending_closures16122026/10/24 18:16:33 INFO Vacuumed table table=pending_objects16132026/10/24 18:16:33 INFO Vacuumed table table=multipart_uploads16142026/10/24 18:16:33 INFO Vacuumed table table=closures16152026/10/24 18:16:33 INFO Vacuumed table table=objects1616--- PASS: TestSweepSkipsRowsLockedByPush (0.34s)1617=== CONT TestGCSweepSkipsPendingObjects16182026/10/24 18:16:33 INFO Received push request method=POST path=/api/pushes16192026/10/24 18:16:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16202026/10/24 18:16:33 INFO Uploading gdbsn8kxbfrcx6rsvnh9wysvy47gsi2i-pinned-file.txt (128B)16212026/10/24 18:16:33 INFO Received uploads request method=POST path=/api/pending_closures16222026/10/24 18:16:33 INFO Received push request method=POST path=/api/pushes16232026/10/24 18:16:33 WARN Failed to register uploaded object key=gdbsn8kxbfrcx6rsvnh9wysvy47gsi2i.ls error="server returned 404: 404 page not found\n"16242026/10/24 18:16:33 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16252026/10/24 18:16:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16262026/10/24 18:16:33 INFO Signed narinfos id=1 count=116272026/10/24 18:16:33 INFO Uploading 1 narinfos16282026/10/24 18:16:33 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16292026/10/24 18:16:33 INFO Uploading rbqvrlx0xg13wpa2a66kpcms8006kp0r-a (216B)16302026/10/24 18:16:33 INFO Uploading znb4iw4kn5973vwz3km56yq750ibsfk7-shared-dep (136B)16312026/10/24 18:16:33 INFO Received complete push request method=POST path=/api/pushes/1/complete16322026/10/24 18:16:33 WARN Failed to register uploaded object key=gdbsn8kxbfrcx6rsvnh9wysvy47gsi2i.narinfo error="server returned 404: 404 page not found\n"16332026/10/24 18:16:33 WARN Failed to register uploaded object key=lmn2gda9fnrycxbs87chy2fnzywwsmhh.ls error="server returned 404: 404 page not found\n"16342026/10/24 18:16:33 WARN Failed to register uploaded object key=rbqvrlx0xg13wpa2a66kpcms8006kp0r.ls error="server returned 404: 404 page not found\n"16352026/10/24 18:16:33 WARN Failed to register uploaded object key=nar/1rqp43zvsl2h5a0386a1wahgvy8g7lhhhkpwmi7ij44bn2nxsl3l.nar.zst error="server returned 404: 404 page not found\n"16362026/10/24 18:16:33 WARN Failed to register uploaded object key=znb4iw4kn5973vwz3km56yq750ibsfk7.ls error="server returned 404: 404 page not found\n"16372026/10/24 18:16:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16382026/10/24 18:16:33 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16392026/10/24 18:16:33 INFO Signed narinfos id=1 count=316402026/10/24 18:16:33 INFO Uploading 3 narinfos16412026/10/24 18:16:33 INFO Completed push id=1 objects=3 duration=5.368721ms16422026/10/24 18:16:33 INFO Upload complete. (53ms)16432026/10/24 18:16:33 INFO Received complete push request method=POST path=/api/pushes/1/complete16442026/10/24 18:16:33 WARN Failed to register uploaded object key=znb4iw4kn5973vwz3km56yq750ibsfk7.narinfo error="server returned 404: 404 page not found\n"16452026/10/24 18:16:33 WARN Failed to register uploaded object key=rbqvrlx0xg13wpa2a66kpcms8006kp0r.narinfo error="server returned 404: 404 page not found\n"16462026/10/24 18:16:33 WARN Failed to register uploaded object key=lmn2gda9fnrycxbs87chy2fnzywwsmhh.narinfo error="server returned 404: 404 page not found\n"1647=== NAME TestClientWithDependencies1648 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies1438566595/001/store/d60rjc3lv7v5m6va55dmkki1szxwa53g-test-script16492026/10/24 18:16:33 INFO Completed push id=1 objects=8 duration=7.508702ms16502026/10/24 18:16:33 INFO Upload complete. (59ms)1651=== NAME TestClientPushesUseOnePush1652 client_pushes_test.go:97: Retrieved narinfo from S3:1653 StorePath: /build/TestClientPushesUseOnePush3103801454/001/store/znb4iw4kn5973vwz3km56yq750ibsfk7-shared-dep1654 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1655 Compression: zstd1656 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821657 NarSize: 1361658 References: 1659 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1660 client_pushes_test.go:97: Retrieved narinfo from S3:1661 StorePath: /build/TestClientPushesUseOnePush3103801454/001/store/rbqvrlx0xg13wpa2a66kpcms8006kp0r-a1662 URL: nar/1rqp43zvsl2h5a0386a1wahgvy8g7lhhhkpwmi7ij44bn2nxsl3l.nar.zst1663 Compression: zstd1664 NarHash: sha256:1rqp43zvsl2h5a0386a1wahgvy8g7lhhhkpwmi7ij44bn2nxsl3l1665 NarSize: 2161666 References: /build/TestClientPushesUseOnePush3103801454/001/store/znb4iw4kn5973vwz3km56yq750ibsfk7-shared-dep1667 CA: text:sha256:0cgvlvc23b10in6y6gn3bf633dfmigck14v8014f8wpw7xhba4nz1668 client_pushes_test.go:97: Retrieved narinfo from S3:1669 StorePath: /build/TestClientPushesUseOnePush3103801454/001/store/lmn2gda9fnrycxbs87chy2fnzywwsmhh-b1670 URL: nar/1rqp43zvsl2h5a0386a1wahgvy8g7lhhhkpwmi7ij44bn2nxsl3l.nar.zst1671 Compression: zstd1672 NarHash: sha256:1rqp43zvsl2h5a0386a1wahgvy8g7lhhhkpwmi7ij44bn2nxsl3l1673 NarSize: 2161674 References: /build/TestClientPushesUseOnePush3103801454/001/store/znb4iw4kn5973vwz3km56yq750ibsfk7-shared-dep1675 CA: text:sha256:0cgvlvc23b10in6y6gn3bf633dfmigck14v8014f8wpw7xhba4nz16762026/10/24 18:16:33 INFO Received uploads request method=POST path=/api/pending_closures1677--- PASS: TestClientPushesUseOnePush (0.50s)1678=== CONT TestGCBugBareHashReferences16792026/10/24 18:16:33 INFO Received uploads request method=POST path=/api/pending_closures16802026/10/24 18:16:33 INFO Received push request method=POST path=/api/pushes16812026/10/24 18:16:33 INFO Received uploads request method=POST path=/api/pending_closures16822026/10/24 18:16:33 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16832026/10/24 18:16:33 INFO Uploading rxy1l6rsph67lijd271ja5khbcri2h0w-shared-dep (136B)16842026/10/24 18:16:33 INFO Uploading 57br5v1rcxxkr1yl6b100rdf2vim58zc-b (216B)16852026/10/24 18:16:33 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16862026/10/24 18:16:33 INFO Uploading hh44l0c033khpjh8g8mdfv2x71pv5jwj-top (224B)16872026/10/24 18:16:33 INFO Uploading bzqw26xjbsh0lipr1h5psxx1mlkzwwsz-shared-dep (136B)16882026/10/24 18:16:33 WARN Failed to register uploaded object key=4yc8cd33ca38rlnq0phqpw550bd00mkw.ls error="server returned 404: 404 page not found\n"16892026/10/24 18:16:33 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16902026/10/24 18:16:33 WARN Failed to register uploaded object key=rxy1l6rsph67lijd271ja5khbcri2h0w.ls error="server returned 404: 404 page not found\n"16912026/10/24 18:16:33 WARN Failed to register uploaded object key=57br5v1rcxxkr1yl6b100rdf2vim58zc.ls error="server returned 404: 404 page not found\n"16922026/10/24 18:16:33 WARN Failed to register uploaded object key=hh44l0c033khpjh8g8mdfv2x71pv5jwj.ls error="server returned 404: 404 page not found\n"1693=== NAME TestClientWithDependencies16942026/10/24 18:16:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign1695 client_integration_test.go:615: Found 1 dependencies (including self)16962026/10/24 18:16:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16972026/10/24 18:16:33 WARN Failed to register uploaded object key=nar/1v0d74ldq0a96scrnz1na2yj1dk2vgic1mif387l4dxzsa6wsn6v.nar.zst error="server returned 404: 404 page not found\n"16982026/10/24 18:16:33 WARN Failed to register uploaded object key=nar/1ia824yhmzncglspm2cx2pcg1r01hhzydr4s4941kg16n82z4mds.nar.zst error="server returned 404: 404 page not found\n"16992026/10/24 18:16:33 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17002026/10/24 18:16:33 WARN Failed to register uploaded object key=bzqw26xjbsh0lipr1h5psxx1mlkzwwsz.ls error="server returned 404: 404 page not found\n"17012026/10/24 18:16:33 INFO Signed narinfos id=2 count=217022026/10/24 18:16:33 INFO Signed narinfos id=1 count=217032026/10/24 18:16:33 INFO Uploading 2 narinfos17042026/10/24 18:16:33 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17052026/10/24 18:16:33 INFO Signed narinfos id=1 count=217062026/10/24 18:16:33 INFO Uploading 4 narinfos17072026/10/24 18:16:33 WARN Failed to register uploaded object key=hh44l0c033khpjh8g8mdfv2x71pv5jwj.narinfo error="server returned 404: 404 page not found\n"17082026/10/24 18:16:33 WARN Failed to register uploaded object key=rxy1l6rsph67lijd271ja5khbcri2h0w.narinfo error="server returned 404: 404 page not found\n"17092026/10/24 18:16:33 WARN Failed to register uploaded object key=4yc8cd33ca38rlnq0phqpw550bd00mkw.narinfo error="server returned 404: 404 page not found\n"17102026/10/24 18:16:33 INFO Received complete push request method=POST path=/api/pushes/1/complete17112026/10/24 18:16:33 WARN Failed to register uploaded object key=bzqw26xjbsh0lipr1h5psxx1mlkzwwsz.narinfo error="server returned 404: 404 page not found\n"17122026/10/24 18:16:33 WARN Failed to register uploaded object key=57br5v1rcxxkr1yl6b100rdf2vim58zc.narinfo error="server returned 404: 404 page not found\n"17132026/10/24 18:16:33 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17142026/10/24 18:16:33 WARN Failed to register uploaded object key=rxy1l6rsph67lijd271ja5khbcri2h0w.narinfo error="server returned 404: 404 page not found\n"17152026/10/24 18:16:33 INFO Completed push id=1 objects=6 duration=6.601932ms17162026/10/24 18:16:33 INFO Upload complete. (73ms)1717=== NAME TestClientSharedPathCommittedMidPush1718 client_integration_test.go:680: Retrieved narinfo from S3:1719 StorePath: /build/TestClientSharedPathCommittedMidPush1998454426/001/store/bzqw26xjbsh0lipr1h5psxx1mlkzwwsz-shared-dep1720 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1721 Compression: zstd1722 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821723 NarSize: 1361724 References: 1725 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17262026/10/24 18:16:33 INFO Completed upload id=1 objects=6 duration=5.137141ms17272026/10/24 18:16:33 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1728 client_integration_test.go:680: Retrieved narinfo from S3:1729 StorePath: /build/TestClientSharedPathCommittedMidPush1998454426/001/store/hh44l0c033khpjh8g8mdfv2x71pv5jwj-top1730 URL: nar/1ia824yhmzncglspm2cx2pcg1r01hhzydr4s4941kg16n82z4mds.nar.zst1731 Compression: zstd1732 NarHash: sha256:1ia824yhmzncglspm2cx2pcg1r01hhzydr4s4941kg16n82z4mds1733 NarSize: 2241734 References: /build/TestClientSharedPathCommittedMidPush1998454426/001/store/bzqw26xjbsh0lipr1h5psxx1mlkzwwsz-shared-dep1735 CA: text:sha256:0mx0dks9gdfbfbrlnl50jla2ys58655ryv2s42rcd1r5g1mhjpv217362026/10/24 18:16:33 INFO Completed upload id=2 objects=6 duration=3.07892ms17372026/10/24 18:16:33 INFO Upload complete. (83ms)1738=== NAME TestClientFallsBackToClosures1739 client_pushes_test.go:112: Retrieved narinfo from S3:1740 StorePath: /build/TestClientFallsBackToClosures3188538443/001/store/rxy1l6rsph67lijd271ja5khbcri2h0w-shared-dep1741 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1742 Compression: zstd1743 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821744 NarSize: 1361745 References: 1746 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1747--- PASS: TestClientSharedPathCommittedMidPush (0.49s)1748=== CONT TestDeduplicatedObjectsRecordedAsPending1749=== NAME TestClientFallsBackToClosures1750 client_pushes_test.go:112: Retrieved narinfo from S3:1751 StorePath: /build/TestClientFallsBackToClosures3188538443/001/store/4yc8cd33ca38rlnq0phqpw550bd00mkw-a1752 URL: nar/1v0d74ldq0a96scrnz1na2yj1dk2vgic1mif387l4dxzsa6wsn6v.nar.zst1753 Compression: zstd1754 NarHash: sha256:1v0d74ldq0a96scrnz1na2yj1dk2vgic1mif387l4dxzsa6wsn6v1755 NarSize: 2161756 References: /build/TestClientFallsBackToClosures3188538443/001/store/rxy1l6rsph67lijd271ja5khbcri2h0w-shared-dep1757 CA: text:sha256:1sjx0i4qy4h6c493mk5c10nick0yknvqps9lsj37zhidkcym2a7p1758 client_pushes_test.go:112: Retrieved narinfo from S3:1759 StorePath: /build/TestClientFallsBackToClosures3188538443/001/store/57br5v1rcxxkr1yl6b100rdf2vim58zc-b1760 URL: nar/1v0d74ldq0a96scrnz1na2yj1dk2vgic1mif387l4dxzsa6wsn6v.nar.zst1761 Compression: zstd1762 NarHash: sha256:1v0d74ldq0a96scrnz1na2yj1dk2vgic1mif387l4dxzsa6wsn6v1763 NarSize: 2161764 References: /build/TestClientFallsBackToClosures3188538443/001/store/rxy1l6rsph67lijd271ja5khbcri2h0w-shared-dep1765 CA: text:sha256:1sjx0i4qy4h6c493mk5c10nick0yknvqps9lsj37zhidkcym2a7p17662026/10/24 18:16:33 INFO Aborted multipart uploads count=0 kept=01767--- PASS: TestClientFallsBackToClosures (0.57s)1768=== CONT TestGCAdvisoryLockBlocksConcurrentRun17692026/10/24 18:16:33 WARN Force mode enabled - objects will be deleted immediately without grace period17702026/10/24 18:16:33 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."17712026/10/24 18:16:33 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1772--- PASS: TestFailedS3DeleteKeepsTombstone (0.42s)1773=== CONT TestCacheStatsHandler17742026/10/24 18:16:33 INFO Received push request method=POST path=/api/pushes17752026/10/24 18:16:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17762026/10/24 18:16:33 INFO Uploading ah1jwsxz6pnrwwdvyy2yj7fvnharznkp-unpinned-file.txt (128B)17772026/10/24 18:16:33 INFO Aborted multipart uploads count=0 kept=017782026/10/24 18:16:33 INFO Received uploads request method=POST path=/api/pending_closures1779=== NAME TestClientIntegration1780 client_integration_test.go:286: Created store path: /build/TestClientIntegration160372582/002/store/g24pzckkg3y54dnpypxkibly6cwr30li-test-file.txt17812026/10/24 18:16:33 WARN Failed to register uploaded object key=ah1jwsxz6pnrwwdvyy2yj7fvnharznkp.ls error="server returned 404: 404 page not found\n"17822026/10/24 18:16:33 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17832026/10/24 18:16:33 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17842026/10/24 18:16:33 INFO Signed narinfos id=2 count=117852026/10/24 18:16:33 INFO Uploading 1 narinfos17862026/10/24 18:16:33 WARN Force mode enabled - objects will be deleted immediately without grace period17872026/10/24 18:16:33 INFO Received complete push request method=POST path=/api/pushes/2/complete17882026/10/24 18:16:33 WARN Failed to register uploaded object key=ah1jwsxz6pnrwwdvyy2yj7fvnharznkp.narinfo error="server returned 404: 404 page not found\n"1789--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.24s)1790=== CONT TestService_ReadAuthMiddleware17912026/10/24 18:16:33 INFO Completed push id=2 objects=3 duration=2.412231ms17922026/10/24 18:16:33 INFO Upload complete. (50ms)1793=== NAME TestClientCADerivations1794 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3242571063/001/store/jrhf1l2lxcwhk1mcdsnx673algj82f70-ca-test17952026/10/24 18:16:33 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=017962026/10/24 18:16:33 INFO Vacuumed table table=pending_closures17972026/10/24 18:16:33 INFO Vacuumed table table=pending_objects17982026/10/24 18:16:33 INFO Vacuumed table table=multipart_uploads17992026/10/24 18:16:33 INFO Vacuumed table table=closures1800--- PASS: TestObjectStatsLargeCommit (1.34s)1801=== CONT TestService_RequireScope_OIDC18022026/10/24 18:16:33 INFO Received push request method=POST path=/api/pushes18032026/10/24 18:16:33 INFO Vacuumed table table=objects1804--- PASS: TestGCSweepDeliversEachKeyOnce (0.31s)1805=== CONT TestService_AuthMiddleware_OIDC18062026/10/24 18:16:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18072026/10/24 18:16:33 INFO Uploading d60rjc3lv7v5m6va55dmkki1szxwa53g-test-script (136B)18082026/10/24 18:16:33 INFO Received uploads request method=POST path=/api/pending_closures18092026/10/24 18:16:33 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"18102026/10/24 18:16:33 WARN Failed to register uploaded object key=d60rjc3lv7v5m6va55dmkki1szxwa53g.ls error="server returned 404: 404 page not found\n"18112026/10/24 18:16:33 WARN Failed to register uploaded object key=log/6kix8jrsy06ybg30ijl5jzkp5bvpmgbn-test-script.drv error="server returned 404: 404 page not found\n"18122026/10/24 18:16:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18132026/10/24 18:16:33 INFO Signed narinfos id=1 count=118142026/10/24 18:16:33 INFO Uploading 1 narinfos18152026/10/24 18:16:33 INFO Received uploads request method=POST path=/api/pending_closures18162026/10/24 18:16:33 INFO Starting cleanup of old closures method=DELETE path=/api/closures18172026/10/24 18:16:33 INFO Garbage collection started18182026/10/24 18:16:33 INFO Received complete push request method=POST path=/api/pushes/1/complete18192026/10/24 18:16:33 WARN Failed to register uploaded object key=d60rjc3lv7v5m6va55dmkki1szxwa53g.narinfo error="server returned 404: 404 page not found\n"18202026/10/24 18:16:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44201/oidc18212026/10/24 18:16:33 INFO Aborted multipart uploads count=0 kept=01822=== NAME TestClientCADerivations1823 client_ca_test.go:139: Found 1 dependencies (including self)18242026/10/24 18:16:33 INFO Completed push id=1 objects=4 duration=11.778524ms18252026/10/24 18:16:33 INFO Upload complete. (68ms)1826=== NAME TestClientWithDependencies1827 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1438566595/001/store) requires matching store prefix18282026/10/24 18:16:33 WARN Force mode enabled - objects will be deleted immediately without grace period1829--- PASS: TestClientWithDependencies (0.51s)1830=== CONT TestCacheConfigHandler1831=== RUN TestCacheConfigHandler/full_config,_no_issuer1832=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1833=== RUN TestCacheConfigHandler/no_cache_url_configured1834=== PAUSE TestCacheConfigHandler/no_cache_url_configured1835=== RUN TestCacheConfigHandler/no_signing_keys1836=== PAUSE TestCacheConfigHandler/no_signing_keys1837=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1838=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1839=== CONT TestService_AuthMiddleware_MTLSBoundSubjects18402026/10/24 18:16:33 INFO Aborted multipart uploads count=0 kept=018412026/10/24 18:16:33 INFO Received push request method=POST path=/api/pushes18422026/10/24 18:16:33 INFO Aborted multipart uploads count=0 kept=018432026/10/24 18:16:33 WARN Force mode enabled - objects will be deleted immediately without grace period18442026/10/24 18:16:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18452026/10/24 18:16:33 INFO Uploading g24pzckkg3y54dnpypxkibly6cwr30li-test-file.txt (152B)18462026/10/24 18:16:33 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=018472026/10/24 18:16:33 WARN Force mode enabled - objects will be deleted immediately without grace period18482026/10/24 18:16:33 INFO Vacuumed table table=pending_closures18492026/10/24 18:16:33 INFO Vacuumed table table=pending_objects18502026/10/24 18:16:33 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=018512026/10/24 18:16:33 INFO Vacuumed table table=multipart_uploads18522026/10/24 18:16:33 INFO Vacuumed table table=closures18532026/10/24 18:16:33 INFO Vacuumed table table=objects18542026/10/24 18:16:33 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=018552026/10/24 18:16:33 WARN Failed to register uploaded object key=g24pzckkg3y54dnpypxkibly6cwr30li.ls error="server returned 404: 404 page not found\n"18562026/10/24 18:16:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18572026/10/24 18:16:33 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18582026/10/24 18:16:33 INFO Signed narinfos id=1 count=118592026/10/24 18:16:33 INFO Uploading 1 narinfos18602026/10/24 18:16:33 INFO Vacuumed table table=pending_closures1861--- PASS: TestGCMetrics (0.23s)1862=== CONT TestService_AuthMiddleware_MTLSProxyHeader18632026/10/24 18:16:33 INFO Vacuumed table table=pending_closures18642026/10/24 18:16:33 INFO Received complete push request method=POST path=/api/pushes/1/complete18652026/10/24 18:16:33 WARN Failed to register uploaded object key=g24pzckkg3y54dnpypxkibly6cwr30li.narinfo error="server returned 404: 404 page not found\n"18662026/10/24 18:16:33 INFO Vacuumed table table=pending_objects18672026/10/24 18:16:33 INFO Vacuumed table table=multipart_uploads18682026/10/24 18:16:33 INFO Vacuumed table table=closures18692026/10/24 18:16:33 INFO Vacuumed table table=pending_objects18702026/10/24 18:16:33 INFO Vacuumed table table=multipart_uploads18712026/10/24 18:16:33 INFO Vacuumed table table=objects18722026/10/24 18:16:33 INFO Completed push id=1 objects=3 duration=5.751541ms18732026/10/24 18:16:33 INFO Upload complete. (50ms)18742026/10/24 18:16:33 INFO Vacuumed table table=closures18752026/10/24 18:16:33 INFO Vacuumed table table=objects1876--- PASS: TestGCSweepSkipsPendingObjects (0.22s)1877=== CONT TestService_ReadScope_PublicByDefault18782026/10/24 18:16:33 INFO Aborted multipart uploads count=0 kept=018792026/10/24 18:16:33 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=018802026/10/24 18:16:33 INFO All 1 paths already cached1881=== NAME TestClientIntegration1882 client_integration_test.go:312: Retrieved narinfo from S3:1883 StorePath: /build/TestClientIntegration160372582/002/store/g24pzckkg3y54dnpypxkibly6cwr30li-test-file.txt1884 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1885 Compression: zstd1886 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11887 NarSize: 1521888 References: 1889 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk118902026/10/24 18:16:33 INFO Vacuumed table table=pending_closures1891 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1892 client_integration_test.go:313: Decompressed .ls content (64 bytes):1893 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1894 client_integration_test.go:316: Testing garbage collection...18952026/10/24 18:16:33 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34263/oidc18962026/10/24 18:16:33 INFO Vacuumed table table=pending_objects18972026/10/24 18:16:33 INFO Vacuumed table table=multipart_uploads18982026/10/24 18:16:33 INFO Vacuumed table table=closures18992026/10/24 18:16:33 INFO Vacuumed table table=objects19002026/10/24 18:16:33 INFO Aborted multipart uploads count=0 kept=019012026/10/24 18:16:33 WARN Force mode enabled - objects will be deleted immediately without grace period19022026/10/24 18:16:33 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=019032026/10/24 18:16:33 INFO Vacuumed table table=pending_closures19042026/10/24 18:16:33 INFO Received push request method=POST path=/api/pushes19052026/10/24 18:16:33 INFO Vacuumed table table=pending_objects19062026/10/24 18:16:33 INFO Vacuumed table table=multipart_uploads19072026/10/24 18:16:33 INFO Vacuumed table table=closures19082026/10/24 18:16:33 INFO Starting cleanup of old closures method=DELETE path=/api/closures19092026/10/24 18:16:33 INFO Garbage collection started1910--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.48s)1911=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19122026/10/24 18:16:33 INFO Received uploads request method=POST path=/1913=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19142026/10/24 18:16:33 INFO Received request for more parts method=POST path=/1915=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19162026/10/24 18:16:33 INFO Received complete multipart upload request method=POST path=/1917=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19182026/10/24 18:16:33 INFO Received uploads request method=POST path=/1919--- PASS: TestUploadHandlersRejectInvalidKeys (0.11s)1920 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1921 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1922 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1923 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1924=== CONT TestProxyWriteTimeout/narinfo1925=== CONT TestProxyWriteTimeout/10_GiB_nar1926=== CONT TestProxyWriteTimeout/1_GiB_nar1927=== CONT TestProxyWriteTimeout/unknown_size1928--- PASS: TestProxyWriteTimeout (0.00s)1929 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1930 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1931 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1932 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1933=== CONT TestPendingClosureWriteTimeout/empty1934=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline19352026/10/24 18:16:33 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19362026/10/24 18:16:33 INFO Uploading jrhf1l2lxcwhk1mcdsnx673algj82f70-ca-test (144B)19372026/10/24 18:16:33 INFO Aborted multipart uploads count=0 kept=019382026/10/24 18:16:33 INFO Received uploads request method=POST path=/api/pending_closures19392026/10/24 18:16:33 INFO Vacuumed table table=objects1940--- PASS: TestPushDedupSurvivesConcurrentGC (0.38s)1941=== CONT TestPendingClosureWriteTimeout/670k_objects1942=== CONT TestPendingClosureWriteTimeout/400_objects1943=== CONT TestIsValidUploadKey/narinfo1944=== CONT TestIsValidUploadKey/realisation_plus_in_output1945=== CONT TestIsValidUploadKey/realisation1946=== CONT TestIsValidUploadKey/build_log_equals1947=== CONT TestIsValidUploadKey/build_log_question_mark1948=== CONT TestIsValidUploadKey/build_log_plus_in_name1949=== CONT TestIsValidUploadKey/build_log_home-manager_file1950=== CONT TestIsValidUploadKey/build_log1951=== CONT TestIsValidUploadKey/listing1952=== CONT TestIsValidUploadKey/nar_plain1953=== CONT TestIsValidUploadKey/nar_xz1954=== CONT TestIsValidUploadKey/nar_zst1955=== CONT TestIsValidUploadKey/traversal_nar1956=== CONT TestIsValidUploadKey/nix-cache-info1957=== CONT TestIsValidUploadKey/traversal1958=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1959=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1960=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1961=== CONT TestIsValidUploadKey/index.html1962=== CONT TestIsValidUploadKey/empty_key1963=== CONT TestIsValidUploadKey/unknown_type1964=== CONT TestIsValidUploadKey/absolute1965--- PASS: TestIsValidUploadKey (0.11s)1966 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1967 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1968 --- PASS: TestIsValidUploadKey/realisation (0.00s)1969 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1970 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1971 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1972 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1973 --- PASS: TestIsValidUploadKey/build_log (0.00s)1974 --- PASS: TestIsValidUploadKey/listing (0.00s)1975 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1976 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1977 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1978 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1979 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1980 --- PASS: TestIsValidUploadKey/traversal (0.00s)1981 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1982 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1983 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1984 --- PASS: TestIsValidUploadKey/index.html (0.00s)1985 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1986 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1987 --- PASS: TestIsValidUploadKey/absolute (0.00s)1988=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure19892026/10/24 18:16:33 INFO Received uploads request method=POST path=/19902026/10/24 18:16:33 WARN Failed to register uploaded object key=log/sp8aqq3ah24f1prdcfzp3nm68v1jwqmr-ca-test.drv error="server returned 404: 404 page not found\n"19912026/10/24 18:16:33 WARN Failed to register uploaded object key=jrhf1l2lxcwhk1mcdsnx673algj82f70.ls error="server returned 404: 404 page not found\n"19922026/10/24 18:16:33 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19932026/10/24 18:16:33 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19942026/10/24 18:16:33 INFO Signed narinfos id=1 count=119952026/10/24 18:16:33 INFO Uploading 1 narinfos19962026/10/24 18:16:33 WARN Force mode enabled - objects will be deleted immediately without grace period1997--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.19s)1998=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart19992026/10/24 18:16:33 INFO Received complete multipart upload request method=POST path=/20002026/10/24 18:16:33 INFO Received complete push request method=POST path=/api/pushes/1/complete20012026/10/24 18:16:33 WARN Failed to register uploaded object key=jrhf1l2lxcwhk1mcdsnx673algj82f70.narinfo error="server returned 404: 404 page not found\n"20022026/10/24 18:16:33 INFO Completed push id=1 objects=4 duration=9.640703ms20032026/10/24 18:16:33 INFO Upload complete. (98ms)2004=== NAME TestClientCADerivations2005 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3242571063/001/store/jrhf1l2lxcwhk1mcdsnx673algj82f70-ca-test2006 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst2007 Compression: zstd2008 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2009 NarSize: 1442010 References: 2011 Deriver: /build/TestClientCADerivations3242571063/001/store/sp8aqq3ah24f1prdcfzp3nm68v1jwqmr-ca-test.drv2012 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2013 client_ca_test.go:185: Checking for realisation files in S3...20142026/10/24 18:16:33 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=02015 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2016 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache2017--- PASS: TestPushWaitsForSweepHoldingRow (0.83s)2018=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20192026/10/24 18:16:33 INFO Received request for more parts method=POST path=/20202026/10/24 18:16:33 INFO Vacuumed table table=pending_closures20212026/10/24 18:16:33 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"2022--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.21s)2023=== CONT TestPush_RejectsBadRequests/bad_root20242026/10/24 18:16:33 INFO Received push request method=POST path=/api/pushes2025=== CONT TestPush_RejectsBadRequests/no_roots20262026/10/24 18:16:33 INFO Received push request method=POST path=/api/pushes2027=== CONT TestPush_RejectsBadRequests/no_objects20282026/10/24 18:16:33 INFO Received push request method=POST path=/api/pushes2029=== CONT TestPush_RejectsBadRequests/root_not_in_objects20302026/10/24 18:16:33 INFO Received push request method=POST path=/api/pushes2031=== CONT TestNativeOIDCLoginPushRefresh/new-id-token2032--- PASS: TestPush_RejectsBadRequests (0.39s)2033 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2034 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)2035 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2036 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2037=== CONT TestNativeOIDCLoginPushRefresh/omitted-id-token20382026/10/24 18:16:33 INFO Vacuumed table table=pending_objects20392026/10/24 18:16:33 INFO Vacuumed table table=multipart_uploads2040=== CONT TestServerTLSConfig/no_client_CA2041=== CONT TestServerTLSConfig/not_a_PEM_file2042=== CONT TestServerTLSConfig/missing_CA_file2043--- PASS: TestServerTLSConfig (0.00s)2044 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2045 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2046 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2047=== CONT TestIsValidCachePath/narinfo2048=== CONT TestIsValidCachePath/index.html2049=== CONT TestIsValidCachePath/short_hash2050=== CONT TestIsValidCachePath/wrong_extension2051=== CONT TestIsValidCachePath/leading_slash2052=== CONT TestIsValidCachePath/empty2053=== CONT TestIsValidCachePath/random_path2054=== CONT TestIsValidCachePath/invalid_char_u2055=== CONT TestIsValidCachePath/invalid_char_e2056=== CONT TestIsValidCachePath/traversal_in_middle2057=== CONT TestIsValidCachePath/nar_uncompressed2058=== CONT TestIsValidCachePath/nix-cache-info2059=== CONT TestIsValidCachePath/realisation2060=== CONT TestIsValidCachePath/traversal_parent2061=== CONT TestIsValidCachePath/log2062=== CONT TestIsValidCachePath/ls2063=== CONT TestIsValidCachePath/nar_xz2064=== CONT TestIsValidCachePath/nar_zst2065=== CONT TestIsValidCachePath/nar_bz22066=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2067--- PASS: TestIsValidCachePath (0.00s)2068 --- PASS: TestIsValidCachePath/narinfo (0.00s)2069 --- PASS: TestIsValidCachePath/index.html (0.00s)2070 --- PASS: TestIsValidCachePath/short_hash (0.00s)2071 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2072 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2073 --- PASS: TestIsValidCachePath/empty (0.00s)2074 --- PASS: TestIsValidCachePath/random_path (0.00s)2075 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2076 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2077 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2078 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2079 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2080 --- PASS: TestIsValidCachePath/realisation (0.00s)2081 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2082 --- PASS: TestIsValidCachePath/log (0.00s)2083 --- PASS: TestIsValidCachePath/ls (0.00s)2084 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2085 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2086 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2087 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2088=== CONT TestParseSingleRange/none2089=== CONT TestParseSingleRange/open-ended20902026/10/24 18:16:33 INFO Vacuumed table table=closures2091=== CONT TestParseSingleRange/start_far_past_EOF2092=== CONT TestParseSingleRange/start_past_EOF2093=== CONT TestParseSingleRange/single_byte2094=== CONT TestParseSingleRange/suffix_exceeds_size2095=== CONT TestParseSingleRange/suffix2096=== CONT TestParseSingleRange/end_clamped_to_size2097=== CONT TestParseSingleRange/malformed_both_empty2098=== CONT TestParseSingleRange/closed2099=== CONT TestParseSingleRange/malformed_end_before_start2100=== CONT TestParseSingleRange/multi-range_ignored2101=== CONT TestParseSingleRange/malformed_no_dash2102=== CONT TestParseSingleRange/unknown_unit2103--- PASS: TestParseSingleRange (0.00s)2104 --- PASS: TestParseSingleRange/none (0.00s)2105 --- PASS: TestParseSingleRange/open-ended (0.00s)2106 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2107 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2108 --- PASS: TestParseSingleRange/single_byte (0.00s)2109 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2110 --- PASS: TestParseSingleRange/suffix (0.00s)2111 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)2112 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2113 --- PASS: TestParseSingleRange/closed (0.00s)2114 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2115 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2116 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2117 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2118=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale21192026/10/24 18:16:33 INFO Vacuumed table table=objects2120--- PASS: TestService_ReadAuthMiddleware (0.24s)2121=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh21222026/10/24 18:16:33 INFO OIDC provider initialized name=native issuer=http://127.0.0.1:4599521232026/10/24 18:16:33 INFO OIDC provider initialized name=native issuer=http://127.0.0.1:4256921242026/10/24 18:16:33 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21252026/10/24 18:16:33 WARN mTLS auth: bound subjects configured but subject DN unavailable21262026/10/24 18:16:33 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2127--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.23s)2128=== CONT TestGCEndsOnShutdown/before_the_run2129--- PASS: TestCacheStatsHandler (0.29s)2130=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark2131=== NAME TestClientCADerivations2132 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features2133 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable2134 error: binary cache 's3://bucket73?endpoint=http://localhost:45943®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3242571063/001/store'2135 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12136=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2137=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2138=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2139=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2140=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2141=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2142=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2143=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2144=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2145--- PASS: TestClientCADerivations (0.67s)2146=== CONT TestResolveDBConnectionString/flag_wins2147=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2148=== CONT TestResolveDBConnectionString/nothing_configured2149=== CONT TestResolveDBConnectionString/missing_file_is_an_error2150=== CONT TestResolveDBConnectionString/file_when_flag_empty2151=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows2152--- PASS: TestResolveDBConnectionString (0.00s)2153 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2154 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2155 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2156 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2157 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2158--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.27s)2159=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check2160--- PASS: TestGCBugBareHashReferences (0.43s)2161=== CONT TestClientErrorHandling/InvalidStorePath2162--- PASS: TestService_ReadScope_PublicByDefault (0.28s)2163=== CONT TestClientErrorHandling/ServerNotAvailable2164=== RUN TestService_RequireScope_OIDC/builder_may_write2165=== PAUSE TestService_RequireScope_OIDC/builder_may_write2166=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2167=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2168=== RUN TestService_RequireScope_OIDC/ops_may_admin2169=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2170=== RUN TestService_RequireScope_OIDC/ops_may_not_write2171=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2172=== RUN TestService_RequireScope_OIDC/reader_may_not_write2173=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2174=== RUN TestService_RequireScope_OIDC/static_token_may_admin2175=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2176=== RUN TestService_RequireScope_OIDC/static_token_may_write2177=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2178=== RUN TestService_RequireScope_OIDC/reader_may_read2179=== PAUSE TestService_RequireScope_OIDC/reader_may_read2180=== RUN TestService_RequireScope_OIDC/writer_implies_read2181=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2182=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2183=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2184=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc2185=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc2186=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2187=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2188=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2189=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2190=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2191=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2192=== CONT TestClientErrorHandling/InvalidAuthToken21932026/10/24 18:16:33 INFO Received uploads request method=POST path=/api/pending_closures21942026/10/24 18:16:33 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/present21952026-10-24 18:16:33.758 UTC [206] LOG: checkpoints are occurring too frequently (8 seconds apart)21962026-10-24 18:16:33.758 UTC [206] HINT: Consider increasing the configuration parameter "max_wal_size".21972026-10-24 18:16:33.758 UTC [206] LOG: checkpoint starting: wal21982026/10/24 18:16:33 INFO Aborted multipart uploads count=0 kept=021992026/10/24 18:16:33 WARN Force mode enabled - objects will be deleted immediately without grace period2200=== CONT TestCacheConfigHandler/full_config,_no_issuer2201=== CONT TestCacheConfigHandler/no_signing_keys2202=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2203=== CONT TestCacheConfigHandler/no_cache_url_configured2204--- PASS: TestCacheConfigHandler (0.00s)2205 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2206 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2207 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2208 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2209=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2210=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected22112026/10/24 18:16:33 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]2212=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2213=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected22142026/10/24 18:16:33 WARN Authentication failed token_preview=eyJhbGciOi...Ll9FXN7vvg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2215=== CONT TestService_RequireScope_OIDC/builder_may_write2216--- PASS: TestService_AuthMiddleware_OIDC (0.30s)2217 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2218 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2219 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2220 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2221=== CONT TestService_RequireScope_OIDC/reader_may_read2222=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2223=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read22242026/10/24 18:16:33 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]2225=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2226=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2227=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2228=== CONT TestService_RequireScope_OIDC/writer_implies_read2229=== CONT TestService_RequireScope_OIDC/reader_may_not_write2230=== CONT TestService_RequireScope_OIDC/static_token_may_write2231=== CONT TestService_RequireScope_OIDC/static_token_may_admin2232=== CONT TestService_RequireScope_OIDC/ops_may_admin2233=== CONT TestService_RequireScope_OIDC/ops_may_not_write2234=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2235--- PASS: TestService_RequireScope_OIDC (0.37s)2236 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2237 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2238 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2239 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2240 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2241 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2242 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2243 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2244 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2245 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2246 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2247 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2248 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2249 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)22502026/10/24 18:16:33 INFO Received uploads request method=POST path=/api/pending_closures22512026/10/24 18:16:33 INFO Aborted multipart uploads count=0 kept=022522026/10/24 18:16:33 WARN Force mode enabled - objects will be deleted immediately without grace period22532026/10/24 18:16:33 WARN Request failed, retrying attempt=2 backoff=195.90144ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22542026/10/24 18:16:33 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=022552026/10/24 18:16:33 INFO Received uploads request method=POST path=/api/pending_closures22562026/10/24 18:16:33 INFO Vacuumed table table=pending_closures22572026/10/24 18:16:33 INFO Vacuumed table table=pending_objects22582026/10/24 18:16:33 INFO Vacuumed table table=multipart_uploads22592026/10/24 18:16:33 INFO Vacuumed table table=closures22602026/10/24 18:16:33 INFO Vacuumed table table=objects22612026/10/24 18:16:33 INFO Aborted multipart uploads count=0 kept=022622026/10/24 18:16:33 WARN Force mode enabled - objects will be deleted immediately without grace period22632026/10/24 18:16:33 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=022642026/10/24 18:16:33 INFO Vacuumed table table=pending_closures22652026/10/24 18:16:33 INFO Vacuumed table table=pending_objects22662026/10/24 18:16:33 INFO Vacuumed table table=multipart_uploads22672026/10/24 18:16:33 INFO Aborted multipart uploads count=0 kept=022682026/10/24 18:16:33 INFO Vacuumed table table=closures22692026/10/24 18:16:33 INFO Vacuumed table table=objects22702026/10/24 18:16:33 WARN Force mode enabled - objects will be deleted immediately without grace period22712026/10/24 18:16:33 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:45943/bucket99/?delete=\": context canceled"2272--- PASS: TestGCEndsOnShutdown (0.00s)2273 --- PASS: TestGCEndsOnShutdown/before_the_run (0.21s)2274 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.22s)2275 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.24s)2276--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2277 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.21s)2278 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.24s)22792026/10/24 18:16:33 INFO lead: released remote=192.0.2.1:12342280--- PASS: TestLeadEndsOnShutdown (1.43s)22812026/10/24 18:16:33 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22822026/10/24 18:16:33 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2283=== NAME TestOrphanedObjectsGCStressTest2284 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2285 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion2286--- PASS: TestDeleteClosuresRacingPins (1.35s)22872026/10/24 18:16:34 WARN Request failed, retrying attempt=3 backoff=366.352887ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22882026/10/24 18:16:34 INFO lead: released remote=192.0.2.1:12342289--- PASS: TestUploadHandlersRejectOversizedBody (0.20s)2290 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)2291 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.04s)2292 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.63s)22932026/10/24 18:16:34 INFO lead: acquired remote=192.0.2.1:12342294--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2295 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.70s)2296 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.70s)2297=== NAME TestOrphanedObjectsGCStressTest2298 orphaned_objects_gc_test.go:503: Stress test completed successfully:2299 orphaned_objects_gc_test.go:504: - Active objects preserved: 202300 orphaned_objects_gc_test.go:505: - Objects deleted: 2102301 orphaned_objects_gc_test.go:506: - Total GC'd: 2102302--- PASS: TestOrphanedObjectsGCStressTest (2.46s)23032026/10/24 18:16:34 WARN Request failed, retrying attempt=4 backoff=738.992697ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2304--- PASS: TestPendingClosureWriteTimeout (0.11s)2305 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2306 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2307 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2308 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.05s)23092026/10/24 18:16:34 INFO Received push request method=POST path=/api/pushes23102026/10/24 18:16:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23112026/10/24 18:16:34 INFO Uploading d6ih1idci1viqxw8vixhqrh4n07wv59m-native-oidc-0 (128B)23122026/10/24 18:16:34 WARN Failed to register uploaded object key=d6ih1idci1viqxw8vixhqrh4n07wv59m.ls error="server returned 404: 404 page not found\n"23132026/10/24 18:16:34 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23142026/10/24 18:16:34 INFO Signed narinfos id=1 count=123152026/10/24 18:16:34 INFO Uploading 1 narinfos23162026/10/24 18:16:34 INFO Received complete push request method=POST path=/api/pushes/1/complete23172026/10/24 18:16:34 INFO Completed push id=1 objects=3 duration=3.035011ms23182026/10/24 18:16:34 INFO Upload complete. (54ms)23192026/10/24 18:16:34 INFO Received push request method=POST path=/api/pushes23202026/10/24 18:16:34 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23212026/10/24 18:16:34 INFO Uploading aglmrxv6aj342rd87irnfm28176qa7p2-native-oidc-0 (128B)23222026/10/24 18:16:34 WARN Failed to register uploaded object key=aglmrxv6aj342rd87irnfm28176qa7p2.ls error="server returned 404: 404 page not found\n"23232026/10/24 18:16:34 WARN Failed to register uploaded object key=nar/0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq.nar.zst error="server returned 404: 404 page not found\n"23242026/10/24 18:16:34 WARN Failed to register uploaded object key=d6ih1idci1viqxw8vixhqrh4n07wv59m.narinfo error="server returned 404: 404 page not found\n"2325=== NAME TestNativeOIDCLoginPushRefresh/new-id-token2326 native_oidc_linux_test.go:139: Retrieved narinfo from S3:2327 StorePath: /build/TestNativeOIDCLoginPushRefreshnew-id-token290403838/004/store/d6ih1idci1viqxw8vixhqrh4n07wv59m-native-oidc-02328 URL: nar/0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq.nar.zst2329 Compression: zstd2330 NarHash: sha256:0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq2331 NarSize: 1282332 References: 2333 CA: text:sha256:0wy0p28czvzd72v0sn9wi5v6vzg0w28gil36xf4di45srvg5vf0p23342026/10/24 18:16:34 WARN Failed to register uploaded object key=nar/0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq.nar.zst error="server returned 404: 404 page not found\n"23352026/10/24 18:16:35 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23362026/10/24 18:16:35 INFO Signed narinfos id=1 count=123372026/10/24 18:16:35 INFO Uploading 1 narinfos23382026/10/24 18:16:35 INFO Received complete push request method=POST path=/api/pushes/1/complete23392026/10/24 18:16:35 INFO Completed push id=1 objects=3 duration=3.791951ms23402026/10/24 18:16:35 INFO Upload complete. (149ms)23412026/10/24 18:16:35 INFO Received push request method=POST path=/api/pushes23422026/10/24 18:16:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23432026/10/24 18:16:35 INFO Uploading 6wi673gp24xamhl9m7apl30wv5xmk1jc-native-oidc-1 (128B)23442026/10/24 18:16:35 WARN Failed to register uploaded object key=6wi673gp24xamhl9m7apl30wv5xmk1jc.ls error="server returned 404: 404 page not found\n"23452026/10/24 18:16:35 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign23462026/10/24 18:16:35 INFO Signed narinfos id=2 count=123472026/10/24 18:16:35 INFO Uploading 1 narinfos23482026/10/24 18:16:35 INFO Received complete push request method=POST path=/api/pushes/2/complete23492026/10/24 18:16:35 INFO Completed push id=2 objects=3 duration=1.316061ms23502026/10/24 18:16:35 INFO Upload complete. (47ms)23512026/10/24 18:16:35 WARN Failed to register uploaded object key=aglmrxv6aj342rd87irnfm28176qa7p2.narinfo error="server returned 404: 404 page not found\n"2352=== NAME TestNativeOIDCLoginPushRefresh/omitted-id-token2353 native_oidc_linux_test.go:139: Retrieved narinfo from S3:2354 StorePath: /build/TestNativeOIDCLoginPushRefreshomitted-id-token2553115854/004/store/aglmrxv6aj342rd87irnfm28176qa7p2-native-oidc-02355 URL: nar/0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq.nar.zst2356 Compression: zstd2357 NarHash: sha256:0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq2358 NarSize: 1282359 References: 2360 CA: text:sha256:0wy0p28czvzd72v0sn9wi5v6vzg0w28gil36xf4di45srvg5vf0p23612026/10/24 18:16:35 WARN Failed to register uploaded object key=nar/0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg6.nar.zst error="server returned 404: 404 page not found\n"23622026/10/24 18:16:35 WARN Failed to register uploaded object key=6wi673gp24xamhl9m7apl30wv5xmk1jc.narinfo error="server returned 404: 404 page not found\n"2363=== NAME TestNativeOIDCLoginPushRefresh/new-id-token2364 native_oidc_linux_test.go:139: Retrieved narinfo from S3:2365 StorePath: /build/TestNativeOIDCLoginPushRefreshnew-id-token290403838/004/store/6wi673gp24xamhl9m7apl30wv5xmk1jc-native-oidc-12366 URL: nar/0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg6.nar.zst2367 Compression: zstd2368 NarHash: sha256:0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg62369 NarSize: 1282370 References: 2371 CA: text:sha256:0z7d88w8ivn9jiskv6fpsiikfgkan67r4qp4isjd1g0w9anr0xrd23722026/10/24 18:16:35 WARN Request failed, retrying attempt=5 backoff=1.48828088s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23732026/10/24 18:16:35 INFO Received push request method=POST path=/api/pushes23742026/10/24 18:16:35 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23752026/10/24 18:16:35 INFO Uploading ybj42i7ylbln04nfyyia8p7q2v7sbqm2-native-oidc-1 (128B)23762026/10/24 18:16:35 WARN Failed to register uploaded object key=ybj42i7ylbln04nfyyia8p7q2v7sbqm2.ls error="server returned 404: 404 page not found\n"23772026/10/24 18:16:35 INFO lead: released remote=192.0.2.1:12342378--- PASS: TestLeadElectsOneAndHandsOver (2.63s)23792026/10/24 18:16:35 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign23802026/10/24 18:16:35 INFO Signed narinfos id=2 count=123812026/10/24 18:16:35 INFO Uploading 1 narinfos23822026/10/24 18:16:35 INFO Received complete push request method=POST path=/api/pushes/2/complete23832026/10/24 18:16:35 INFO Completed push id=2 objects=3 duration=1.157181ms23842026/10/24 18:16:35 INFO Upload complete. (97ms)23852026/10/24 18:16:35 WARN Failed to register uploaded object key=nar/0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg6.nar.zst error="server returned 404: 404 page not found\n"23862026/10/24 18:16:35 WARN Failed to register uploaded object key=ybj42i7ylbln04nfyyia8p7q2v7sbqm2.narinfo error="server returned 404: 404 page not found\n"2387=== NAME TestNativeOIDCLoginPushRefresh/omitted-id-token2388 native_oidc_linux_test.go:139: Retrieved narinfo from S3:2389 StorePath: /build/TestNativeOIDCLoginPushRefreshomitted-id-token2553115854/004/store/ybj42i7ylbln04nfyyia8p7q2v7sbqm2-native-oidc-12390 URL: nar/0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg6.nar.zst2391 Compression: zstd2392 NarHash: sha256:0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg62393 NarSize: 1282394 References: 2395 CA: text:sha256:0z7d88w8ivn9jiskv6fpsiikfgkan67r4qp4isjd1g0w9anr0xrd2396--- PASS: TestNativeOIDCLoginPushRefresh (0.00s)2397 --- PASS: TestNativeOIDCLoginPushRefresh/new-id-token (1.62s)2398 --- PASS: TestNativeOIDCLoginPushRefresh/omitted-id-token (1.78s)23992026/10/24 18:16:35 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=024002026/10/24 18:16:35 INFO Received create pin request method=POST path=/api/pins/myapp24012026/10/24 18:16:35 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC977651676/001/store/gdbsn8kxbfrcx6rsvnh9wysvy47gsi2i-pinned-file.txt narinfo_key=gdbsn8kxbfrcx6rsvnh9wysvy47gsi2i.narinfo24022026/10/24 18:16:35 INFO Starting cleanup of old closures method=DELETE path=/api/closures24032026/10/24 18:16:35 INFO Garbage collection started24042026/10/24 18:16:35 INFO Aborted multipart uploads count=0 kept=024052026/10/24 18:16:35 WARN Force mode enabled - objects will be deleted immediately without grace period24062026/10/24 18:16:35 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=024072026/10/24 18:16:35 INFO Vacuumed table table=pending_closures24082026/10/24 18:16:35 INFO Vacuumed table table=pending_objects24092026/10/24 18:16:35 INFO Vacuumed table table=multipart_uploads24102026/10/24 18:16:35 INFO Vacuumed table table=closures24112026/10/24 18:16:35 INFO Vacuumed table table=objects24122026/10/24 18:16:35 WARN Rate limiter enabled after throttle name=s3-test rate=524132026/10/24 18:16:35 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2414=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2415 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102416 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002417--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (3.92s)24182026/10/24 18:16:35 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02419=== NAME TestClientIntegration2420 client_integration_test.go:323: Objects in database after GC:2421 client_integration_test.go:323: Successfully deleted all objects with GC --force2422--- PASS: TestClientIntegration (2.46s)24232026/10/24 18:16:36 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-config2424--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.61s)24252026/10/24 18:16:36 WARN Request failed, retrying attempt=2 backoff=203.426272ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24262026/10/24 18:16:36 WARN Request failed, retrying attempt=3 backoff=394.652701ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2427=== NAME TestPinProtectsFromGC2428 client_integration_test.go:840: Pin successfully protected closure from garbage collection2429--- PASS: TestPinProtectsFromGC (4.62s)24302026/10/24 18:16:37 WARN Request failed, retrying attempt=4 backoff=781.421738ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2431--- PASS: TestConnectWaitsForAPeerMigration (5.25s)24322026/10/24 18:16:38 WARN Request failed, retrying attempt=5 backoff=1.527999981s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24332026/10/24 18:16:38 INFO Aborted multipart uploads count=1 kept=024342026/10/24 18:16:38 INFO Received cleanup request method=DELETE path=/api/pending_closures24352026/10/24 18:16:38 INFO Aborted multipart uploads count=1 kept=02436--- PASS: TestPendingCleanupUsesOneCutoff (6.43s)24372026/10/24 18:16:39 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"24382026/10/24 18:16:39 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-config24392026/10/24 18:16:39 WARN Request failed, retrying attempt=2 backoff=185.308248ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24402026/10/24 18:16:39 WARN Request failed, retrying attempt=3 backoff=366.080637ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24412026/10/24 18:16:40 WARN Request failed, retrying attempt=4 backoff=795.177754ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24422026/10/24 18:16:41 WARN Request failed, retrying attempt=5 backoff=1.444849905s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24432026/10/24 18:16:42 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_closures24442026/10/24 18:16:42 WARN Request failed, retrying attempt=2 backoff=185.136162ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24452026/10/24 18:16:42 WARN Request failed, retrying attempt=3 backoff=394.14826ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24462026/10/24 18:16:43 WARN Request failed, retrying attempt=4 backoff=729.80126ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24472026/10/24 18:16:43 WARN Request failed, retrying attempt=5 backoff=1.734264888s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2448--- PASS: TestClientErrorHandling (0.00s)2449 --- PASS: TestClientErrorHandling/InvalidStorePath (0.24s)2450 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.28s)2451 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.06s)2452PASS2453{"timestamp":"2026-10-24T18:16:45.729905311Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:57078","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2386,"threadName":"rustfs-worker","threadId":"ThreadId(143)"}24542026-10-24 18:16:45.964 UTC [201] LOG: received smart shutdown request24552026-10-24 18:16:45.969 UTC [201] LOG: background worker "logical replication launcher" (PID 211) exited with exit code 124562026-10-24 18:16:47.239 UTC [206] LOG: checkpoint complete: wrote 10568 buffers (64.5%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=12.402 s, sync=1.031 s, total=13.481 s; sync files=34717, longest=0.001 s, average=0.001 s; distance=533852 kB, estimate=533852 kB; lsn=0/22A45FA8, redo lsn=0/220BCFE024572026-10-24 18:16:47.241 UTC [206] LOG: shutting down24582026-10-24 18:16:47.242 UTC [206] LOG: checkpoint starting: shutdown immediate24592026-10-24 18:16:47.302 UTC [206] LOG: checkpoint complete: wrote 363 buffers (2.2%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.008 s, sync=0.049 s, total=0.061 s; sync files=224, longest=0.001 s, average=0.001 s; distance=9764 kB, estimate=481443 kB; lsn=0/22A46038, redo lsn=0/22A4603824602026-10-24 18:16:47.351 UTC [201] LOG: database system is shut down2461Running OIDC tests...2462=== RUN TestAudienceForIssuer2463=== PAUSE TestAudienceForIssuer2464=== RUN TestGlobMatch2465=== PAUSE TestGlobMatch2466=== RUN TestValidateToken_ValidToken2467=== PAUSE TestValidateToken_ValidToken2468=== RUN TestValidateToken_WrongAudience2469=== PAUSE TestValidateToken_WrongAudience2470=== RUN TestValidateToken_Expired2471=== PAUSE TestValidateToken_Expired2472=== RUN TestValidateToken_BoundClaimsMismatch2473=== PAUSE TestValidateToken_BoundClaimsMismatch2474=== RUN TestValidateToken_BoundSubjectMismatch2475=== PAUSE TestValidateToken_BoundSubjectMismatch2476=== RUN TestValidateToken_MultipleProviders2477=== PAUSE TestValidateToken_MultipleProviders2478=== RUN TestValidateToken_NoMatchingProvider2479=== PAUSE TestValidateToken_NoMatchingProvider2480=== RUN TestValidateToken_KubernetesServiceAccount2481=== PAUSE TestValidateToken_KubernetesServiceAccount2482=== RUN TestNewValidator_KubernetesRequiresCA2483=== PAUSE TestNewValidator_KubernetesRequiresCA2484=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2485=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2486=== RUN TestPins_ReservedForMatchingRule2487=== PAUSE TestPins_ReservedForMatchingRule2488=== RUN TestPins_TopLevelShorthand2489=== PAUSE TestPins_TopLevelShorthand2490=== RUN TestPins_ConfigValidation2491=== PAUSE TestPins_ConfigValidation2492=== RUN TestScopes_LegacyProviderDefaultsToWrite2493=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2494=== RUN TestScopes_Rules2495=== PAUSE TestScopes_Rules2496=== RUN TestScopes_ConfigValidation2497=== PAUSE TestScopes_ConfigValidation2498=== CONT TestAudienceForIssuer2499=== CONT TestValidateToken_KubernetesServiceAccount2500--- PASS: TestAudienceForIssuer (0.00s)2501=== CONT TestValidateToken_ValidToken2502=== CONT TestGlobMatch2503=== CONT TestValidateToken_MultipleProviders2504=== CONT TestValidateToken_NoMatchingProvider2505=== CONT TestValidateToken_Expired2506=== CONT TestPins_ConfigValidation2507=== CONT TestScopes_ConfigValidation2508=== CONT TestScopes_Rules2509=== CONT TestScopes_LegacyProviderDefaultsToWrite2510=== CONT TestValidateToken_BoundSubjectMismatch2511=== CONT TestPins_ReservedForMatchingRule2512=== CONT TestPins_TopLevelShorthand2513=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2514=== CONT TestValidateToken_BoundClaimsMismatch2515=== CONT TestNewValidator_KubernetesRequiresCA2516=== CONT TestValidateToken_WrongAudience2517=== RUN TestGlobMatch/foo_foo2518=== PAUSE TestGlobMatch/foo_foo2519--- PASS: TestPins_ConfigValidation (0.00s)2520--- PASS: TestScopes_ConfigValidation (0.00s)2521=== RUN TestGlobMatch/foo_bar2522=== PAUSE TestGlobMatch/foo_bar2523=== RUN TestGlobMatch/*_2524=== PAUSE TestGlobMatch/*_2525=== RUN TestGlobMatch/*_anything2526=== PAUSE TestGlobMatch/*_anything2527=== RUN TestGlobMatch/foo*_foo2528=== PAUSE TestGlobMatch/foo*_foo2529=== RUN TestGlobMatch/foo*_foobar2530=== PAUSE TestGlobMatch/foo*_foobar2531=== RUN TestGlobMatch/foo*_bar2532=== PAUSE TestGlobMatch/foo*_bar2533=== RUN TestGlobMatch/*bar_bar2534=== PAUSE TestGlobMatch/*bar_bar2535=== RUN TestGlobMatch/*bar_foobar2536=== PAUSE TestGlobMatch/*bar_foobar2537=== RUN TestGlobMatch/*bar_foo2538=== PAUSE TestGlobMatch/*bar_foo2539=== RUN TestGlobMatch/foo*bar_foobar2540=== PAUSE TestGlobMatch/foo*bar_foobar2541=== RUN TestGlobMatch/foo*bar_foo123bar2542=== PAUSE TestGlobMatch/foo*bar_foo123bar2543=== RUN TestGlobMatch/foo*bar_foobarbaz2544=== PAUSE TestGlobMatch/foo*bar_foobarbaz2545=== RUN TestGlobMatch/*/*_foo/bar2546=== PAUSE TestGlobMatch/*/*_foo/bar2547=== RUN TestGlobMatch/*/*_foo2548=== PAUSE TestGlobMatch/*/*_foo2549=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2550=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2551=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02552=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02553=== RUN TestGlobMatch/refs/*/main_refs/heads/main2554=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2555=== RUN TestGlobMatch/fo?_foo2556=== PAUSE TestGlobMatch/fo?_foo2557=== RUN TestGlobMatch/fo?_fo2558=== PAUSE TestGlobMatch/fo?_fo2559=== RUN TestGlobMatch/fo?_fooo2560=== PAUSE TestGlobMatch/fo?_fooo2561=== RUN TestGlobMatch/?oo_foo2562=== PAUSE TestGlobMatch/?oo_foo2563=== RUN TestGlobMatch/?oo_boo2564=== PAUSE TestGlobMatch/?oo_boo2565=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2566=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2567=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2568=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2569=== CONT TestGlobMatch/foo_foo2570=== CONT TestGlobMatch/foo*_bar2571=== CONT TestGlobMatch/foo*_foobar2572=== CONT TestGlobMatch/foo*_foo2573=== CONT TestGlobMatch/*_anything2574=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2575=== CONT TestGlobMatch/*bar_bar2576=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2577=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02578=== CONT TestGlobMatch/fo?_foo2579=== CONT TestGlobMatch/refs/*/main_refs/heads/main2580=== CONT TestGlobMatch/?oo_boo2581=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2582=== CONT TestGlobMatch/foo*bar_foobarbaz2583=== CONT TestGlobMatch/fo?_fooo2584=== CONT TestGlobMatch/*/*_foo2585=== CONT TestGlobMatch/*/*_foo/bar2586=== CONT TestGlobMatch/foo*bar_foo123bar2587=== CONT TestGlobMatch/foo*bar_foobar2588=== CONT TestGlobMatch/*bar_foo2589=== CONT TestGlobMatch/*bar_foobar2590=== CONT TestGlobMatch/*_2591=== CONT TestGlobMatch/fo?_fo2592=== CONT TestGlobMatch/foo_bar2593=== CONT TestGlobMatch/?oo_foo2594--- PASS: TestGlobMatch (0.01s)2595 --- PASS: TestGlobMatch/foo_foo (0.00s)2596 --- PASS: TestGlobMatch/foo*_bar (0.00s)2597 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2598 --- PASS: TestGlobMatch/foo*_foo (0.00s)2599 --- PASS: TestGlobMatch/*_anything (0.00s)2600 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2601 --- PASS: TestGlobMatch/*bar_bar (0.00s)2602 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2603 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2604 --- PASS: TestGlobMatch/fo?_foo (0.00s)2605 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2606 --- PASS: TestGlobMatch/?oo_boo (0.00s)2607 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2608 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2609 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2610 --- PASS: TestGlobMatch/*/*_foo (0.00s)2611 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2612 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2613 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2614 --- PASS: TestGlobMatch/*bar_foo (0.00s)2615 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2616 --- PASS: TestGlobMatch/*_ (0.00s)2617 --- PASS: TestGlobMatch/fo?_fo (0.00s)2618 --- PASS: TestGlobMatch/foo_bar (0.00s)2619 --- PASS: TestGlobMatch/?oo_foo (0.00s)26202026/10/24 18:16:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35823/oidc2621--- PASS: TestValidateToken_Expired (0.02s)26222026/10/24 18:16:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36953/oidc2623--- PASS: TestValidateToken_BoundSubjectMismatch (0.03s)26242026/10/24 18:16:49 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:4111526252026/10/24 18:16:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45719/oidc2626--- PASS: TestValidateToken_KubernetesServiceAccount (0.04s)2627--- PASS: TestValidateToken_WrongAudience (0.03s)26282026/10/24 18:16:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40867/oidc2629--- PASS: TestValidateToken_ValidToken (0.04s)26302026/10/24 18:16:49 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45741/oidc2631--- PASS: TestValidateToken_NoMatchingProvider (0.05s)26322026/10/24 18:16:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33177/oidc26332026/10/24 18:16:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41197/oidc2634--- PASS: TestPins_TopLevelShorthand (0.05s)26352026/10/24 18:16:49 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232636--- PASS: TestPins_ReservedForMatchingRule (0.05s)2637--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.06s)26382026/10/24 18:16:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46755/oidc2639--- PASS: TestScopes_Rules (0.07s)26402026/10/24 18:16:49 http: TLS handshake error from 127.0.0.1:54444: remote error: tls: bad certificate2641--- PASS: TestNewValidator_KubernetesRequiresCA (0.09s)26422026/10/24 18:16:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44097/oidc2643--- PASS: TestValidateToken_BoundClaimsMismatch (0.11s)26442026/10/24 18:16:49 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41913/oidc2645--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.19s)26462026/10/24 18:16:49 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45693/oidc26472026/10/24 18:16:49 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:33243/oidc2648--- PASS: TestValidateToken_MultipleProviders (0.24s)2649PASS2650Running hook tests...2651=== RUN TestSendPathsEmpty2652=== PAUSE TestSendPathsEmpty2653=== RUN TestQueueEnqueueAndFetch2654=== PAUSE TestQueueEnqueueAndFetch2655=== RUN TestQueueDeduplication2656=== PAUSE TestQueueDeduplication2657=== RUN TestQueueRemove2658=== PAUSE TestQueueRemove2659=== RUN TestQueueFetchBatchLimit2660=== PAUSE TestQueueFetchBatchLimit2661=== RUN TestQueueRetryMovesToBack2662=== PAUSE TestQueueRetryMovesToBack2663=== RUN TestQueueFetchRemoveLifecycle2664=== PAUSE TestQueueFetchRemoveLifecycle2665=== RUN TestQueueConcurrentWriters2666=== PAUSE TestQueueConcurrentWriters2667=== RUN TestQueueRemoveLargeClosure2668=== PAUSE TestQueueRemoveLargeClosure2669=== RUN TestServerClientIntegration2670--- PASS: TestServerClientIntegration (0.00s)2671=== RUN TestServerQueueError26722026/10/24 18:16:49 ERROR Failed to queue paths error="permission denied" count=12673--- PASS: TestServerQueueError (0.00s)2674=== RUN TestGetListenerSocketActivation2675 server_test.go:219: === RUN TestGetListenerSocketActivation2676 --- PASS: TestGetListenerSocketActivation (0.00s)2677 PASS2678 2679--- PASS: TestGetListenerSocketActivation (0.01s)2680=== RUN TestDrainIsolatesPoisonPath2681=== PAUSE TestDrainIsolatesPoisonPath2682=== RUN TestRunNotBlockedByPoisonHead2683=== PAUSE TestRunNotBlockedByPoisonHead2684=== RUN TestDrainGivesUpWhenServerDown2685=== PAUSE TestDrainGivesUpWhenServerDown2686=== RUN TestFailedPathPrunedByLaterClosure2687=== PAUSE TestFailedPathPrunedByLaterClosure2688=== RUN TestWorkerUploadsAndRemoves2689=== PAUSE TestWorkerUploadsAndRemoves2690=== RUN TestWorkerSkipsGCdPaths2691=== PAUSE TestWorkerSkipsGCdPaths2692=== RUN TestWorkerPrunesClosureDeps2693=== PAUSE TestWorkerPrunesClosureDeps2694=== RUN TestDrainTimeout2695=== PAUSE TestDrainTimeout2696=== CONT TestSendPathsEmpty2697=== CONT TestFailedPathPrunedByLaterClosure2698=== CONT TestDrainTimeout2699=== CONT TestWorkerPrunesClosureDeps2700=== CONT TestWorkerSkipsGCdPaths2701=== CONT TestWorkerUploadsAndRemoves2702--- PASS: TestSendPathsEmpty (0.00s)2703=== CONT TestDrainIsolatesPoisonPath2704=== CONT TestQueueRemoveLargeClosure2705=== CONT TestQueueConcurrentWriters2706=== CONT TestQueueFetchRemoveLifecycle2707=== CONT TestQueueRetryMovesToBack2708=== CONT TestDrainGivesUpWhenServerDown2709=== CONT TestQueueFetchBatchLimit2710=== CONT TestQueueRemove2711=== CONT TestRunNotBlockedByPoisonHead2712=== CONT TestQueueEnqueueAndFetch2713=== CONT TestQueueDeduplication27142026/10/24 18:16:49 INFO Upload queue status pending=227152026/10/24 18:16:49 INFO Upload queue status pending=327162026/10/24 18:16:49 INFO Uploading batch count=127172026/10/24 18:16:49 ERROR Upload failed error="upload failed" count=127182026/10/24 18:16:49 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths387965542/002/nonexistent27192026/10/24 18:16:49 INFO Uploading batch count=427202026/10/24 18:16:49 ERROR Upload failed error="upload failed" count=427212026/10/24 18:16:49 INFO Upload queue status pending=227222026/10/24 18:16:49 INFO Uploading batch count=127232026/10/24 18:16:49 ERROR Upload failed error="upload failed" count=127242026/10/24 18:16:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2738246982/002/bbb27252026/10/24 18:16:49 INFO Upload queue status pending=22726--- PASS: TestQueueFetchBatchLimit (0.01s)27272026/10/24 18:16:49 INFO Uploading batch count=127282026/10/24 18:16:49 INFO Uploading batch count=227292026/10/24 18:16:49 INFO Uploading batch count=227302026/10/24 18:16:49 INFO Uploading batch count=227312026/10/24 18:16:49 ERROR Upload failed error="upload failed" count=227322026/10/24 18:16:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3275848533/002/a27332026/10/24 18:16:49 INFO Uploading batch count=12734--- PASS: TestQueueEnqueueAndFetch (0.01s)2735--- PASS: TestQueueDeduplication (0.01s)27362026/10/24 18:16:49 INFO Uploading batch count=12737--- PASS: TestQueueRemove (0.01s)27382026/10/24 18:16:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3275848533/002/b2739--- PASS: TestQueueRetryMovesToBack (0.02s)27402026/10/24 18:16:49 INFO Uploading batch count=127412026/10/24 18:16:49 INFO Uploading batch count=127422026/10/24 18:16:49 ERROR Upload failed error="upload failed" count=127432026/10/24 18:16:49 INFO Uploading batch count=22744--- PASS: TestQueueFetchRemoveLifecycle (0.02s)27452026/10/24 18:16:49 ERROR Upload failed error="upload failed" count=227462026/10/24 18:16:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3275848533/002/c27472026/10/24 18:16:49 INFO Uploading batch count=127482026/10/24 18:16:49 ERROR Upload failed error="upload failed" count=127492026/10/24 18:16:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3275848533/002/d27502026/10/24 18:16:49 INFO Uploading batch count=127512026/10/24 18:16:49 ERROR Upload failed error="upload failed" count=127522026/10/24 18:16:49 INFO Uploading batch count=227532026/10/24 18:16:49 ERROR Upload failed error="upload failed" count=227542026/10/24 18:16:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3275848533/002/e2755--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)27562026/10/24 18:16:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3275848533/002/f27572026/10/24 18:16:49 ERROR Drain finished with paths left in queue remaining=127582026/10/24 18:16:49 ERROR Drain finished with paths left in queue remaining=102759--- PASS: TestDrainIsolatesPoisonPath (0.02s)2760--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2761--- PASS: TestWorkerSkipsGCdPaths (0.03s)2762--- PASS: TestWorkerPrunesClosureDeps (0.03s)2763--- PASS: TestWorkerUploadsAndRemoves (0.03s)2764--- PASS: TestQueueRemoveLargeClosure (0.06s)27652026/10/24 18:16:49 ERROR Upload failed error="context deadline exceeded" count=227662026/10/24 18:16:49 ERROR Drain finished with paths left in queue remaining=42767--- PASS: TestDrainTimeout (0.22s)2768--- PASS: TestQueueConcurrentWriters (0.27s)27692026/10/24 18:16:50 INFO Uploading batch count=127702026/10/24 18:16:50 INFO Uploading batch count=127712026/10/24 18:16:50 INFO Uploading batch count=127722026/10/24 18:16:50 ERROR Upload failed error="upload failed" count=127732026/10/24 18:16:50 INFO Uploading batch count=127742026/10/24 18:16:50 ERROR Upload failed error="upload failed" count=127752026/10/24 18:16:50 INFO Uploading batch count=127762026/10/24 18:16:50 ERROR Upload failed error="upload failed" count=127772026/10/24 18:16:50 INFO Uploading batch count=127782026/10/24 18:16:50 ERROR Upload failed error="upload failed" count=127792026/10/24 18:16:50 ERROR Drain finished with paths left in queue remaining=12780--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2781PASS2782Running signing tests...2783=== RUN TestExternalSigner2784=== PAUSE TestExternalSigner2785=== RUN TestExternalSignerWrongPublicKey2786=== PAUSE TestExternalSignerWrongPublicKey2787=== RUN TestExternalSignerErrors2788=== PAUSE TestExternalSignerErrors2789=== RUN TestExternalSignerRestartsAfterCrash2790=== PAUSE TestExternalSignerRestartsAfterCrash2791=== RUN TestExternalSignerProgramErrorKeepsProcess2792=== PAUSE TestExternalSignerProgramErrorKeepsProcess2793=== RUN TestExternalSignerClose2794=== PAUSE TestExternalSignerClose2795=== RUN TestExternalSignerRejectsInvalidPublicKey2796=== PAUSE TestExternalSignerRejectsInvalidPublicKey2797=== RUN TestExternalSignerCancellation2798=== PAUSE TestExternalSignerCancellation2799=== RUN TestGenerateFingerprint2800=== PAUSE TestGenerateFingerprint2801=== RUN TestParseSigningKey2802=== PAUSE TestParseSigningKey2803=== RUN TestSign2804=== PAUSE TestSign2805=== RUN TestSignBatch2806=== PAUSE TestSignBatch2807=== RUN TestNilKeyPublicKey2808=== PAUSE TestNilKeyPublicKey2809=== RUN TestSignErrors2810=== PAUSE TestSignErrors2811=== CONT TestExternalSigner2812=== CONT TestExternalSignerCancellation2813=== CONT TestSignBatch2814=== CONT TestSignErrors2815=== CONT TestNilKeyPublicKey2816=== CONT TestExternalSignerProgramErrorKeepsProcess2817=== CONT TestExternalSignerRejectsInvalidPublicKey2818=== CONT TestParseSigningKey2819=== RUN TestParseSigningKey/valid_32-byte_key2820=== CONT TestExternalSignerClose2821=== CONT TestSign2822=== CONT TestGenerateFingerprint2823=== CONT TestExternalSignerErrors2824=== CONT TestExternalSignerRestartsAfterCrash2825=== CONT TestExternalSignerWrongPublicKey2826--- PASS: TestNilKeyPublicKey (0.00s)2827=== RUN TestExternalSignerRejectsInvalidPublicKey/#002828=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002829=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2830=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2831=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2832=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2833=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2834=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2835--- PASS: TestSign (0.00s)2836=== PAUSE TestParseSigningKey/valid_32-byte_key2837=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2838=== RUN TestSignErrors/nil_key2839=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2840=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2841=== CONT TestExternalSignerRejectsInvalidPublicKey/#002842=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2843=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2844=== RUN TestParseSigningKey/no_colon2845=== PAUSE TestSignErrors/nil_key2846=== PAUSE TestParseSigningKey/no_colon2847--- PASS: TestSignBatch (0.00s)2848=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2849=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2850=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2851--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2852 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2853 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2854 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2855 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2856 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2857=== RUN TestExternalSignerErrors/invalid_JSON2858=== RUN TestSignErrors/nil_narinfo2859=== RUN TestGenerateFingerprint/basic_with_references2860=== RUN TestParseSigningKey/empty_name2861=== PAUSE TestParseSigningKey/empty_name2862=== RUN TestParseSigningKey/invalid_base642863=== PAUSE TestParseSigningKey/invalid_base642864=== RUN TestParseSigningKey/wrong_length2865=== PAUSE TestParseSigningKey/wrong_length2866=== PAUSE TestExternalSignerErrors/invalid_JSON2867=== PAUSE TestSignErrors/nil_narinfo2868=== PAUSE TestGenerateFingerprint/basic_with_references2869=== CONT TestParseSigningKey/valid_32-byte_key2870=== CONT TestParseSigningKey/wrong_length2871=== CONT TestParseSigningKey/invalid_base642872=== CONT TestParseSigningKey/empty_name2873=== CONT TestParseSigningKey/no_colon2874=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2875--- PASS: TestParseSigningKey (0.00s)2876 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2877 --- PASS: TestParseSigningKey/wrong_length (0.00s)2878 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2879 --- PASS: TestParseSigningKey/empty_name (0.00s)2880 --- PASS: TestParseSigningKey/no_colon (0.00s)2881 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2882=== RUN TestExternalSignerErrors/missing_signature_name2883=== RUN TestSignErrors/invalid_narinfo2884=== PAUSE TestExternalSignerErrors/missing_signature_name2885=== RUN TestExternalSignerErrors/null2886=== PAUSE TestExternalSignerErrors/null2887=== RUN TestExternalSignerErrors/wrong_signatures_shape2888=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2889=== PAUSE TestSignErrors/invalid_narinfo2890=== RUN TestGenerateFingerprint/no_references2891=== PAUSE TestGenerateFingerprint/no_references2892=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2893=== RUN TestExternalSignerErrors/too_few_signatures2894=== PAUSE TestExternalSignerErrors/too_few_signatures2895=== RUN TestSignErrors/canceled2896=== PAUSE TestSignErrors/canceled2897=== CONT TestSignErrors/nil_key2898=== CONT TestSignErrors/canceled2899=== CONT TestSignErrors/invalid_narinfo2900=== RUN TestExternalSignerErrors/unrequested_key2901=== PAUSE TestExternalSignerErrors/unrequested_key2902=== CONT TestSignErrors/nil_narinfo2903--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2904--- PASS: TestSignErrors (0.00s)2905 --- PASS: TestSignErrors/nil_key (0.00s)2906 --- PASS: TestSignErrors/canceled (0.00s)2907 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2908 --- PASS: TestSignErrors/nil_narinfo (0.00s)2909--- PASS: TestExternalSignerWrongPublicKey (0.00s)2910=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2911=== RUN TestExternalSignerErrors/wrong_signature_name2912=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2913=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2914=== RUN TestGenerateFingerprint/invalid_nar_hash_length2915=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2916=== RUN TestGenerateFingerprint/invalid_store_path_prefix2917=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2918=== RUN TestGenerateFingerprint/invalid_reference_prefix2919=== PAUSE TestExternalSignerErrors/wrong_signature_name2920=== RUN TestExternalSignerErrors/invalid_signature_base642921=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2922=== CONT TestGenerateFingerprint/basic_with_references2923=== CONT TestGenerateFingerprint/invalid_nar_hash_length2924=== PAUSE TestExternalSignerErrors/invalid_signature_base642925=== RUN TestExternalSignerErrors/wrong_signature_length2926=== PAUSE TestExternalSignerErrors/wrong_signature_length2927=== RUN TestExternalSignerErrors/exit_at_startup2928=== PAUSE TestExternalSignerErrors/exit_at_startup2929=== RUN TestExternalSignerErrors/wrong_shape2930=== CONT TestGenerateFingerprint/invalid_reference_prefix2931=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2932=== CONT TestGenerateFingerprint/invalid_store_path_prefix2933=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2934=== CONT TestGenerateFingerprint/no_references2935--- PASS: TestGenerateFingerprint (0.00s)2936 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2937 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2938 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2939 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2940 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2941 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2942 --- PASS: TestGenerateFingerprint/no_references (0.00s)2943=== PAUSE TestExternalSignerErrors/wrong_shape2944=== RUN TestExternalSignerErrors/wrong_id2945=== PAUSE TestExternalSignerErrors/wrong_id2946=== RUN TestExternalSignerErrors/null_signatures2947=== PAUSE TestExternalSignerErrors/null_signatures2948=== RUN TestExternalSignerErrors/program_error2949=== PAUSE TestExternalSignerErrors/program_error2950=== RUN TestExternalSignerErrors/exit_on_request2951=== PAUSE TestExternalSignerErrors/exit_on_request2952=== RUN TestExternalSignerErrors/missing_signatures2953=== PAUSE TestExternalSignerErrors/missing_signatures2954=== CONT TestExternalSignerErrors/invalid_JSON2955=== CONT TestExternalSignerErrors/wrong_id2956=== CONT TestExternalSignerErrors/wrong_shape2957=== CONT TestExternalSignerErrors/missing_signatures2958=== CONT TestExternalSignerErrors/exit_on_request2959=== CONT TestExternalSignerErrors/program_error2960=== CONT TestExternalSignerErrors/null_signatures2961--- PASS: TestExternalSignerClose (0.00s)2962=== CONT TestExternalSignerErrors/exit_at_startup2963=== CONT TestExternalSignerErrors/too_few_signatures2964=== CONT TestExternalSignerErrors/wrong_signature_name2965=== CONT TestExternalSignerErrors/unrequested_key2966=== CONT TestExternalSignerErrors/invalid_signature_base642967=== CONT TestExternalSignerErrors/null2968=== CONT TestExternalSignerErrors/missing_signature_name2969=== CONT TestExternalSignerErrors/wrong_signatures_shape2970=== CONT TestExternalSignerErrors/wrong_signature_length2971--- PASS: TestExternalSigner (0.01s)2972--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2973--- PASS: TestExternalSignerErrors (0.00s)2974 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2975 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2976 --- PASS: TestExternalSignerErrors/wrong_id (0.00s)2977 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2978 --- PASS: TestExternalSignerErrors/missing_signatures (0.00s)2979 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2980 --- PASS: TestExternalSignerErrors/exit_at_startup (0.01s)2981 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2982 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2983 --- PASS: TestExternalSignerErrors/missing_signature_name (0.01s)2984 --- PASS: TestExternalSignerErrors/program_error (0.01s)2985 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2986 --- PASS: TestExternalSignerErrors/null (0.01s)2987 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2988 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2989 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.01s)2990--- PASS: TestExternalSignerCancellation (0.02s)2991PASS2992Running OpenBao signer tests...2993=== RUN TestSign2994=== PAUSE TestSign2995=== RUN TestSignErrors2996=== PAUSE TestSignErrors2997=== RUN TestServe2998=== PAUSE TestServe2999=== RUN TestServeRejectsGarbage3000=== PAUSE TestServeRejectsGarbage3001=== CONT TestSign3002=== CONT TestServe3003=== CONT TestSignErrors3004=== RUN TestSignErrors/http_error3005=== CONT TestServeRejectsGarbage3006--- PASS: TestServeRejectsGarbage (0.00s)3007--- PASS: TestServe (0.00s)3008=== PAUSE TestSignErrors/http_error3009=== RUN TestSignErrors/invalid_json3010=== PAUSE TestSignErrors/invalid_json3011=== RUN TestSignErrors/no_prefix3012=== PAUSE TestSignErrors/no_prefix3013=== RUN TestSignErrors/invalid_base643014=== PAUSE TestSignErrors/invalid_base643015=== CONT TestSignErrors/http_error3016=== CONT TestSignErrors/invalid_json3017=== CONT TestSignErrors/invalid_base643018=== CONT TestSignErrors/no_prefix3019--- PASS: TestSign (0.00s)3020--- PASS: TestSignErrors (0.00s)3021 --- PASS: TestSignErrors/invalid_json (0.00s)3022 --- PASS: TestSignErrors/http_error (0.00s)3023 --- PASS: TestSignErrors/invalid_base64 (0.00s)3024 --- PASS: TestSignErrors/no_prefix (0.00s)3025PASS