niks3-go-unit-tests
checks.x86_64-linux.go-unit-tests
· build #421
· 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.03s)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 TestDumpPathSingleFile119=== CONT TestResolveStorePath120=== CONT TestScriptTokenScriptFails121=== CONT TestScriptTokenEmptyCommand122--- PASS: TestScriptTokenEmptyCommand (0.00s)123=== CONT TestScriptTokenEmptyToken124=== CONT TestScriptTokenNoExpiryRerunsEveryCall125=== CONT TestFileTokenEmpty126=== CONT TestFileTokenMissing127=== CONT TestFileTokenReadsAndCaches128--- PASS: TestDoServerRequestAttachesToken (0.00s)129=== CONT TestClientSignaturesByStorePath130--- PASS: TestClientSignaturesByStorePath (0.00s)131=== CONT TestStreamPushReportsSkippedPaths132=== CONT TestStaticToken133--- PASS: TestStaticToken (0.00s)134=== CONT TestStreamPushGivesUpOnDeadServer135=== CONT TestSetClientTLSDoesNotMutateDefaultTransport136--- PASS: TestFileTokenMissing (0.00s)137=== CONT TestStreamPushRequestLine138--- PASS: TestFileTokenEmpty (0.00s)139=== CONT TestStreamPushIsolatesFailures140=== CONT TestSetClientTLSErrors141=== CONT TestPartSizeForNAR142=== CONT TestSetClientTLS143=== CONT TestStreamPushStopsWhenCanceled144=== CONT TestShellSplitErrors145=== CONT TestShellSplit146=== CONT TestDoWithRetry_FinalResponseBodyReadable147=== CONT TestUploadMultipart_SupersededByPeer148=== CONT TestRetryTimeoutOutlastsMaxRetries149=== CONT TestDoWithRetry_BodyReplayedViaGetBody150=== CONT TestStreamPushBatchesUnderLoad151=== CONT TestScriptTokenBadJSON152=== CONT TestScriptTokenCachesUntilRefresh153=== CONT TestStreamPushReportsSignatures154--- PASS: TestResolveStorePath (0.00s)155--- PASS: TestFileTokenReadsAndCaches (0.00s)156=== CONT TestFilterOversizedClosures157=== RUN TestFilterOversizedClosures/no_limit_keeps_everything158=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything159=== CONT TestStreamPushReportsEveryPath160=== RUN TestPartSizeForNAR/zero_stays_at_minimum161--- PASS: TestScriptTokenScriptFails (0.00s)162=== CONT TestUploadMultipart_PartsInParallel163=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum164=== CONT TestDumpPathMatchesNix165=== RUN TestUploadMultipart_SupersededByPeer/exists166=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica167=== CONT TestParsePathInfoJSON168=== RUN TestParsePathInfoJSON/Nix_format169=== PAUSE TestParsePathInfoJSON/Nix_format170=== PAUSE TestUploadMultipart_SupersededByPeer/exists171=== RUN TestUploadMultipart_SupersededByPeer/missing172=== PAUSE TestUploadMultipart_SupersededByPeer/missing173=== RUN TestParsePathInfoJSON/Lix_format174=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer175=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped176=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped177--- PASS: TestShellSplitErrors (0.00s)178--- PASS: TestStreamPushStopsWhenCanceled (0.00s)179=== CONT TestSupersededNARStillUploadsListing180=== RUN TestPartSizeForNAR/small_stays_at_minimum181=== CONT TestRateLimiterFeedback182=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess183=== CONT TestPathInfoCACompatibility184=== CONT TestCaseHackSuffix185=== PAUSE TestParsePathInfoJSON/Lix_format186=== RUN TestFilterOversizedClosures/all_closures_skipped187--- PASS: TestShellSplit (0.00s)188--- PASS: TestStreamPushReportsSkippedPaths (0.00s)189=== PAUSE TestFilterOversizedClosures/all_closures_skipped190=== CONT TestRegisterUploadedObjectReusesConnections191=== CONT TestParsePathInfoJSONMultiplePaths192=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun193=== CONT TestPathInfoHashCompatibility194=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)195=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths196=== RUN TestSupersededNARStillUploadsListing/small_NAR197=== PAUSE TestPartSizeForNAR/small_stays_at_minimum198=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum199=== CONT TestGetStorePathHash200=== CONT TestEncodeNixBase32201=== RUN TestEncodeNixBase32/test_string_hash202=== PAUSE TestEncodeNixBase32/test_string_hash203=== RUN TestEncodeNixBase32/empty_input204=== PAUSE TestEncodeNixBase32/empty_input205=== CONT TestAuthenticatedRedirectStaysOnServer206=== CONT TestEncodeNixBase32WithRealHash207=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry208=== RUN TestGetStorePathHash/valid_store_path209=== PAUSE TestGetStorePathHash/valid_store_path210=== RUN TestGetStorePathHash/basename_without_hyphen_should_error211=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error212=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error213=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error214=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error215=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error216=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum217=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts218=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts219=== RUN TestPartSizeForNAR/1_TiB220=== PAUSE TestPartSizeForNAR/1_TiB221=== RUN TestPartSizeForNAR/5_TiB_S3_max_object222=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object223=== RUN TestPartSizeForNAR/capped_at_5_GiB224=== PAUSE TestPartSizeForNAR/capped_at_5_GiB225=== CONT TestDumpPathWriterError226=== RUN TestParsePathInfoJSON/empty_input227=== PAUSE TestParsePathInfoJSON/empty_input228=== RUN TestParsePathInfoJSON/whitespace_only229=== PAUSE TestParsePathInfoJSON/whitespace_only230=== RUN TestParsePathInfoJSON/invalid_JSON231=== PAUSE TestParsePathInfoJSON/invalid_JSON232=== RUN TestSetClientTLSErrors/missing_cert_file233=== PAUSE TestSetClientTLSErrors/missing_cert_file234=== RUN TestSetClientTLSErrors/missing_key_file235=== PAUSE TestSetClientTLSErrors/missing_key_file236=== RUN TestSetClientTLSErrors/missing_ca_file237=== PAUSE TestSetClientTLSErrors/missing_ca_file238=== RUN TestSetClientTLSErrors/invalid_ca_file239=== PAUSE TestSetClientTLSErrors/invalid_ca_file240=== CONT TestConvertHashToNix32241=== RUN TestConvertHashToNix32/SRI_format_to_Nix32242=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32243=== RUN TestConvertHashToNix32/already_Nix32_format244=== PAUSE TestConvertHashToNix32/already_Nix32_format245=== RUN TestConvertHashToNix32/invalid_format246=== PAUSE TestConvertHashToNix32/invalid_format247=== CONT TestUploadMultipart_SupersededByPeer/exists248--- PASS: TestStreamPushIsolatesFailures (0.00s)249--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)250--- PASS: TestStreamPushReportsSignatures (0.00s)251--- PASS: TestScriptTokenEmptyToken (0.00s)252=== RUN TestRateLimiterFeedback/429_enables_limiter253=== RUN TestPathInfoCACompatibility/null_ca_field254=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)255=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths256=== PAUSE TestSupersededNARStillUploadsListing/small_NAR257=== CONT TestUploadMultipart_SupersededByPeer/missing258=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped259=== CONT TestEncodeNixBase32/test_string_hash260=== CONT TestEncodeNixBase32/empty_input261=== CONT TestGetStorePathHash/valid_store_path262=== PAUSE TestPathInfoCACompatibility/null_ca_field263=== RUN TestPathInfoCACompatibility/old_string_format_-_text264=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text265=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive266=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive267=== RUN TestPathInfoCACompatibility/new_structured_format_-_text268=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text269=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method270=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method271=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon272=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon273=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI274=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI275=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512276=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512277=== CONT TestPartSizeForNAR/zero_stays_at_minimum278=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths279=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths280=== RUN TestSupersededNARStillUploadsListing/dump_cut_short281=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short282=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts283=== CONT TestPartSizeForNAR/5_TiB_S3_max_object284=== CONT TestPartSizeForNAR/1_TiB285=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum286=== CONT TestPartSizeForNAR/small_stays_at_minimum287=== CONT TestParsePathInfoJSON/Nix_format288=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails289=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails290=== CONT TestFilterOversizedClosures/all_closures_skipped291=== CONT TestParsePathInfoJSON/invalid_JSON292=== CONT TestParsePathInfoJSON/whitespace_only293=== CONT TestParsePathInfoJSON/Lix_format294=== CONT TestParsePathInfoJSON/empty_input295=== CONT TestSetClientTLSErrors/missing_key_file296=== CONT TestConvertHashToNix32/invalid_format297=== CONT TestConvertHashToNix32/already_Nix32_format298=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error299=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)300=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive301=== CONT TestPathInfoCACompatibility/old_string_format_-_text302=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512303=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error304=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI305=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon306=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method307=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths308=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths309=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails310=== CONT TestPathInfoCACompatibility/new_structured_format_-_text311=== CONT TestSupersededNARStillUploadsListing/dump_cut_short312=== CONT TestPartSizeForNAR/capped_at_5_GiB313=== PAUSE TestRateLimiterFeedback/429_enables_limiter314=== CONT TestGetStorePathHash/basename_without_hyphen_should_error315--- PASS: TestStreamPushReportsEveryPath (0.00s)316=== CONT TestSetClientTLSErrors/missing_cert_file317=== CONT TestConvertHashToNix32/SRI_format_to_Nix32318=== CONT TestSetClientTLSErrors/invalid_ca_file319=== RUN TestSetClientTLS/rejects_connection_without_client_cert320=== CONT TestSetClientTLSErrors/missing_ca_file321=== CONT TestPathInfoCACompatibility/null_ca_field322=== CONT TestFilterOversizedClosures/no_limit_keeps_everything323=== CONT TestSupersededNARStillUploadsListing/small_NAR324=== RUN TestRateLimiterFeedback/503_enables_limiter325--- PASS: TestScriptTokenBadJSON (0.00s)326--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)327--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)328--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.03s)329--- PASS: TestDumpPathSingleFile (0.03s)330--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)331--- PASS: TestEncodeNixBase32WithRealHash (0.00s)332--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)333--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)334--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.04s)335--- PASS: TestParsePathInfoJSON (0.03s)336 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)337 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)338 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)339 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)340 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)341=== PAUSE TestRateLimiterFeedback/503_enables_limiter342--- PASS: TestConvertHashToNix32 (0.00s)343 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)344 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)345 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)346=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert347=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA348=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA349=== RUN TestSetClientTLS/preserves_debug_logging_transport350=== PAUSE TestSetClientTLS/preserves_debug_logging_transport351=== CONT TestSetClientTLS/preserves_debug_logging_transport352=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter353=== CONT TestSetClientTLS/rejects_connection_without_client_cert354--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.00s)355--- PASS: TestEncodeNixBase32 (0.00s)356 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)357 --- PASS: TestEncodeNixBase32/empty_input (0.00s)358--- PASS: TestUploadMultipart_SupersededByPeer (0.00s)359 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)360 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)361=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA362--- PASS: TestPartSizeForNAR (0.03s)363 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)364 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)365 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)366 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)367 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)368 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)369 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)370--- PASS: TestGetStorePathHash (0.00s)371 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)372 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)373 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)374 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)375--- PASS: TestFilterOversizedClosures (0.03s)376 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)377 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)378 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)379--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)380 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)381 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)382--- PASS: TestPathInfoCACompatibility (0.00s)383 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)384 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)385 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)386 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)387 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)388--- PASS: TestPathInfoHashCompatibility (0.00s)389 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)390 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)391 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)392 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)393=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter394=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter395=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter396=== CONT TestRateLimiterFeedback/429_enables_limiter397=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter398=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter399=== CONT TestRateLimiterFeedback/503_enables_limiter400--- PASS: TestSetClientTLSErrors (0.03s)401 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)402 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)403 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)404 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)405--- PASS: TestRateLimiterFeedback (0.15s)406 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)407 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)408 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)409 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)410--- PASS: TestCaseHackSuffix (0.15s)411--- PASS: TestStreamPushRequestLine (0.18s)412--- PASS: TestSetClientTLS (0.05s)413 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)414 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.13s)415 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.01s)416--- PASS: TestRegisterUploadedObjectReusesConnections (0.16s)417--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.19s)418--- PASS: TestDumpPathWriterError (0.16s)419--- PASS: TestStreamPushBatchesUnderLoad (0.23s)420--- PASS: TestDumpPathMatchesNix (0.23s)421--- PASS: TestSupersededNARStillUploadsListing (0.00s)422 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.14s)423 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.14s)424 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.69s)425--- PASS: TestUploadMultipart_PartsInParallel (0.75s)426--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.02s)427--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)428--- PASS: TestAuthenticatedRedirectStaysOnServer (3.16s)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 TestDiscoveryFailures477=== RUN TestDiscoveryFailures/http-endpoint478=== PAUSE TestDiscoveryFailures/http-endpoint479=== RUN TestDiscoveryFailures/redirect480=== PAUSE TestDiscoveryFailures/redirect481=== RUN TestDiscoveryFailures/issuer482=== PAUSE TestDiscoveryFailures/issuer483=== RUN TestDiscoveryFailures/no-device484=== PAUSE TestDiscoveryFailures/no-device485=== CONT TestDeviceVerificationURL486=== RUN TestDeviceVerificationURL/complete487=== PAUSE TestDeviceVerificationURL/complete488=== RUN TestDeviceVerificationURL/basic-fallback489=== PAUSE TestDeviceVerificationURL/basic-fallback490=== RUN TestDeviceVerificationURL/insecure491=== PAUSE TestDeviceVerificationURL/insecure492=== RUN TestDeviceVerificationURL/userinfo493=== PAUSE TestDeviceVerificationURL/userinfo494=== CONT TestCanonicalServer495--- PASS: TestCanonicalServer (0.00s)496=== CONT TestConcurrentSources497=== CONT TestLogoutWaitsForRefresh498=== CONT TestProfileLockCancellation499=== CONT TestStoredTokenProcess500 manager_unix_test.go:224: subprocess helper501--- SKIP: TestStoredTokenProcess (0.00s)502=== CONT TestCrossProcessRefresh503=== CONT TestStoredNoIDRefresh504=== CONT TestStoreFailureDoesNotReturnRefreshedToken505=== CONT TestStoredLoginLifecycle506=== CONT TestFractionalTemporalClaims507=== CONT TestRefreshRejectsIdentityChangeAndKeepsRotation508=== CONT TestExpiredTokenRefresh509=== RUN TestExpiredTokenRefresh/new-id510=== PAUSE TestExpiredTokenRefresh/new-id511=== RUN TestExpiredTokenRefresh/no-id512=== PAUSE TestExpiredTokenRefresh/no-id513=== CONT TestExpiredTokenRefresh/new-id514=== CONT TestDeviceHTTPRequestTimeout515=== CONT TestDeviceCancellation516=== CONT TestTokenWithoutRefreshToken517=== RUN TestDeviceCancellation/polling518=== CONT TestRefreshRetainsOmittedRefreshToken519=== CONT TestRefreshContracts520=== CONT TestDeviceFailures521=== RUN TestRefreshContracts/new-id522=== PAUSE TestRefreshContracts/new-id523=== CONT TestDiscoveryFailures/no-device524=== CONT TestDiscoveryFailures/issuer525=== CONT TestDiscoveryFailures/redirect526=== RUN TestDeviceVerificationURL/fragment527=== CONT TestExpiredTokenRefresh/no-id528=== PAUSE TestDeviceCancellation/polling529=== RUN TestDeviceCancellation/initial-request530=== PAUSE TestDeviceCancellation/initial-request531=== CONT TestDeviceCancellation/polling532=== CONT TestDiscoveryFailures/http-endpoint533=== RUN TestDeviceFailures/future-iat534=== PAUSE TestDeviceFailures/future-iat535=== RUN TestDeviceFailures/wrong-azp536=== PAUSE TestDeviceFailures/wrong-azp537=== RUN TestDeviceFailures/multi-aud-no-azp538=== PAUSE TestDeviceFailures/multi-aud-no-azp539=== RUN TestDeviceFailures/denied540=== PAUSE TestDeviceFailures/denied541=== RUN TestDeviceFailures/expired542=== PAUSE TestDeviceFailures/expired543=== RUN TestDeviceFailures/expired-id544=== PAUSE TestDeviceFailures/expired-id545=== RUN TestDeviceFailures/no-id546=== PAUSE TestDeviceFailures/no-id547=== RUN TestDeviceFailures/invalid-interval548=== PAUSE TestDeviceFailures/invalid-interval549=== RUN TestDeviceFailures/wrong-aud550=== RUN TestRefreshContracts/no-id551=== PAUSE TestRefreshContracts/no-id552=== CONT TestRefreshContracts/new-id553=== PAUSE TestDeviceVerificationURL/fragment554=== RUN TestDeviceVerificationURL/malformed555=== PAUSE TestDeviceVerificationURL/malformed556=== CONT TestDeviceVerificationURL/complete557=== CONT TestDeviceCancellation/initial-request558=== PAUSE TestDeviceFailures/wrong-aud559=== RUN TestDeviceFailures/wrong-issuer560=== PAUSE TestDeviceFailures/wrong-issuer561=== RUN TestDeviceFailures/future-nbf562=== PAUSE TestDeviceFailures/future-nbf563=== CONT TestRefreshContracts/no-id564--- PASS: TestRefreshRejectsIdentityChangeAndKeepsRotation (0.03s)565=== CONT TestDeviceVerificationURL/fragment566=== CONT TestDeviceVerificationURL/malformed567=== CONT TestDeviceVerificationURL/insecure568--- PASS: TestStoreFailureDoesNotReturnRefreshedToken (0.04s)569=== CONT TestDeviceVerificationURL/userinfo570--- PASS: TestFractionalTemporalClaims (0.05s)571=== CONT TestDeviceVerificationURL/basic-fallback572=== CONT TestDeviceFailures/future-iat573=== CONT TestDeviceFailures/no-id574=== CONT TestDeviceFailures/future-nbf575=== RUN TestTokenWithoutRefreshToken/before-refresh576=== PAUSE TestTokenWithoutRefreshToken/before-refresh577=== RUN TestTokenWithoutRefreshToken/at-refresh578=== PAUSE TestTokenWithoutRefreshToken/at-refresh579=== RUN TestTokenWithoutRefreshToken/before-expiry-margin580=== PAUSE TestTokenWithoutRefreshToken/before-expiry-margin581=== RUN TestTokenWithoutRefreshToken/at-expiry-margin582=== PAUSE TestTokenWithoutRefreshToken/at-expiry-margin583=== RUN TestTokenWithoutRefreshToken/expired584=== PAUSE TestTokenWithoutRefreshToken/expired585=== CONT TestDeviceFailures/wrong-issuer586=== CONT TestDeviceFailures/wrong-aud587--- PASS: TestExpiredTokenRefresh (0.00s)588 --- PASS: TestExpiredTokenRefresh/no-id (0.06s)589 --- PASS: TestExpiredTokenRefresh/new-id (0.08s)590=== CONT TestDeviceFailures/invalid-interval591--- PASS: TestStoredNoIDRefresh (0.10s)592=== CONT TestDeviceFailures/denied593--- PASS: TestProfileLockCancellation (0.10s)594=== CONT TestDeviceFailures/expired-id595--- PASS: TestCrossProcessRefresh (0.10s)596=== CONT TestDeviceFailures/expired597--- PASS: TestRefreshRetainsOmittedRefreshToken (0.10s)598=== CONT TestDeviceFailures/multi-aud-no-azp599--- PASS: TestRefreshContracts (0.00s)600 --- PASS: TestRefreshContracts/no-id (0.03s)601 --- PASS: TestRefreshContracts/new-id (0.11s)602=== CONT TestDeviceFailures/wrong-azp603=== CONT TestTokenWithoutRefreshToken/before-refresh604=== CONT TestTokenWithoutRefreshToken/at-expiry-margin605=== CONT TestTokenWithoutRefreshToken/expired606=== CONT TestTokenWithoutRefreshToken/before-expiry-margin607=== CONT TestTokenWithoutRefreshToken/at-refresh608--- PASS: TestTokenWithoutRefreshToken (0.07s)609 --- PASS: TestTokenWithoutRefreshToken/before-refresh (0.00s)610 --- PASS: TestTokenWithoutRefreshToken/at-expiry-margin (0.00s)611 --- PASS: TestTokenWithoutRefreshToken/expired (0.00s)612 --- PASS: TestTokenWithoutRefreshToken/before-expiry-margin (0.00s)613 --- PASS: TestTokenWithoutRefreshToken/at-refresh (0.00s)614--- PASS: TestDiscoveryFailures (0.00s)615 --- PASS: TestDiscoveryFailures/issuer (0.03s)616 --- PASS: TestDiscoveryFailures/no-device (0.08s)617 --- PASS: TestDiscoveryFailures/redirect (0.12s)618 --- PASS: TestDiscoveryFailures/http-endpoint (0.13s)619--- PASS: TestConcurrentSources (0.17s)620--- PASS: TestDeviceHTTPRequestTimeout (0.25s)621--- PASS: TestLogoutWaitsForRefresh (0.26s)622--- PASS: TestDeviceCancellation (0.00s)623 --- PASS: TestDeviceCancellation/polling (0.22s)624 --- PASS: TestDeviceCancellation/initial-request (0.26s)625--- PASS: TestStoredLoginLifecycle (1.06s)626--- PASS: TestDeviceVerificationURL (0.01s)627 --- PASS: TestDeviceVerificationURL/malformed (0.03s)628 --- PASS: TestDeviceVerificationURL/fragment (0.03s)629 --- PASS: TestDeviceVerificationURL/userinfo (0.11s)630 --- PASS: TestDeviceVerificationURL/insecure (0.13s)631 --- PASS: TestDeviceVerificationURL/complete (1.03s)632 --- PASS: TestDeviceVerificationURL/basic-fallback (1.06s)633--- PASS: TestDeviceFailures (0.00s)634 --- PASS: TestDeviceFailures/invalid-interval (0.12s)635 --- PASS: TestDeviceFailures/no-id (1.02s)636 --- PASS: TestDeviceFailures/future-nbf (1.06s)637 --- PASS: TestDeviceFailures/wrong-issuer (1.06s)638 --- PASS: TestDeviceFailures/expired-id (1.04s)639 --- PASS: TestDeviceFailures/future-iat (1.08s)640 --- PASS: TestDeviceFailures/multi-aud-no-azp (1.04s)641 --- PASS: TestDeviceFailures/wrong-aud (1.08s)642 --- PASS: TestDeviceFailures/denied (1.06s)643 --- PASS: TestDeviceFailures/expired (1.07s)644 --- PASS: TestDeviceFailures/wrong-azp (1.07s)645--- PASS: TestDeviceLogin (8.03s)646PASS647Running CLI config directory tests...648=== RUN TestDir649=== RUN TestDir/override650=== RUN TestDir/fallback651--- PASS: TestDir (0.00s)652 --- PASS: TestDir/override (0.00s)653 --- PASS: TestDir/fallback (0.00s)654PASS655Running command utility tests...656=== RUN TestAuthConfigDirectories657--- PASS: TestAuthConfigDirectories (0.00s)658=== RUN TestOIDCResolution659=== RUN TestOIDCResolution/saved-fallback660=== RUN TestOIDCResolution/explicit-token6612026/10/24 21:46:51 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/explicit-file663=== RUN TestOIDCResolution/env-file664=== RUN TestOIDCResolution/mtls665=== RUN TestOIDCResolution/explicit-profile666=== RUN TestOIDCResolution/explicit-token-over-profile6672026/10/24 21:46:51 WARN --auth-token is deprecated: tokens on the command line are visible in /proc and shell history; use --auth-token-path or --auth-token-script668=== RUN TestOIDCResolution/hook-does-not-select-profile669=== RUN TestOIDCResolution/hook-env-file670=== RUN TestOIDCResolution/device-conflict6712026/10/24 21:46:51 WARN --auth-token is deprecated: tokens on the command line are visible in /proc and shell history; use --auth-token-path or --auth-token-script672=== RUN TestOIDCResolution/device-profile-conflict673=== RUN TestOIDCResolution/issuer-without-device674--- PASS: TestOIDCResolution (0.00s)675 --- PASS: TestOIDCResolution/saved-fallback (0.00s)676 --- PASS: TestOIDCResolution/explicit-token (0.00s)677 --- PASS: TestOIDCResolution/explicit-file (0.00s)678 --- PASS: TestOIDCResolution/env-file (0.00s)679 --- PASS: TestOIDCResolution/mtls (0.00s)680 --- PASS: TestOIDCResolution/explicit-profile (0.00s)681 --- PASS: TestOIDCResolution/explicit-token-over-profile (0.00s)682 --- PASS: TestOIDCResolution/hook-does-not-select-profile (0.00s)683 --- PASS: TestOIDCResolution/hook-env-file (0.00s)684 --- PASS: TestOIDCResolution/device-conflict (0.00s)685 --- PASS: TestOIDCResolution/device-profile-conflict (0.00s)686 --- PASS: TestOIDCResolution/issuer-without-device (0.00s)687PASS688Running CLI tests...689=== RUN TestAuthHelpAndValidation690--- PASS: TestAuthHelpAndValidation (0.00s)691PASS692Running server tests...693The files belonging to this database system will be owned by user "nixbld".694This user must also own the server process.695696The database cluster will be initialized with locale "C".697The default database encoding has accordingly been set to "SQL_ASCII".698The default text search configuration will be set to "english".699700Data page checksums are enabled.701702creating directory /build/postgres4108414720/data ... ok703creating subdirectories ... ok704selecting dynamic shared memory implementation ... posix705selecting default "max_connections" ... 100706selecting default "shared_buffers" ... 128MB707selecting default time zone ... UTC708creating configuration files ... ok709running bootstrap script ... ok710performing post-bootstrap initialization ... ok711syncing data to disk ... ok712713initdb: warning: enabling "trust" authentication for local connections714initdb: 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.715716Success. You can now start the database server using:717718 pg_ctl -D /build/postgres4108414720/data -l logfile start719720/build/postgres4108414720:5432 - no response7212026-10-24 21:46:52.354 UTC [207] LOG: starting PostgreSQL 18.6 on x86_64-pc-linux-gnu, compiled by clang version 21.1.8, 64-bit7222026-10-24 21:46:52.355 UTC [207] LOG: listening on Unix socket "/build/postgres4108414720/.s.PGSQL.5432"7232026-10-24 21:46:52.359 UTC [214] LOG: database system was shut down at 2026-10-24 21:46:52 UTC7242026-10-24 21:46:52.362 UTC [207] LOG: database system is ready to accept connections725/build/postgres4108414720:5432 - accepting connections726=== RUN TestService_AuthMiddleware727=== PAUSE TestService_AuthMiddleware728=== RUN TestService_AuthMiddleware_MTLSProxyHeader729=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader730=== RUN TestService_AuthMiddleware_MTLSBoundSubjects731=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects732=== RUN TestService_ReadAuthMiddleware733=== PAUSE TestService_ReadAuthMiddleware734=== RUN TestService_AuthMiddleware_OIDC735=== PAUSE TestService_AuthMiddleware_OIDC736=== RUN TestService_RequireScope_OIDC737=== PAUSE TestService_RequireScope_OIDC738=== RUN TestService_ReadScope_PublicByDefault739=== PAUSE TestService_ReadScope_PublicByDefault740=== RUN TestCacheConfigHandler741=== PAUSE TestCacheConfigHandler742=== RUN TestCacheStatsHandler743=== PAUSE TestCacheStatsHandler744=== RUN TestClientCADerivations745=== PAUSE TestClientCADerivations746=== RUN TestClientErrorHandling747=== PAUSE TestClientErrorHandling748=== RUN TestClientIntegration749=== PAUSE TestClientIntegration750=== RUN TestClientMultipleUploads751=== PAUSE TestClientMultipleUploads752=== RUN TestClientWithDependencies753=== PAUSE TestClientWithDependencies754=== RUN TestClientSharedPathCommittedMidPush755=== PAUSE TestClientSharedPathCommittedMidPush756=== RUN TestPinProtectsFromGC757=== PAUSE TestPinProtectsFromGC758=== RUN TestClientPushesUseOnePush759=== PAUSE TestClientPushesUseOnePush760=== RUN TestClientFallsBackToClosures761=== PAUSE TestClientFallsBackToClosures762=== RUN TestDeleteClosuresRacingPins763=== PAUSE TestDeleteClosuresRacingPins764=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock765=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock766=== RUN TestResolveDBConnectionString767=== PAUSE TestResolveDBConnectionString768=== RUN TestConnectWaitsForAPeerMigration769=== PAUSE TestConnectWaitsForAPeerMigration770=== RUN TestLeadElectsOneAndHandsOver771=== PAUSE TestLeadElectsOneAndHandsOver772=== RUN TestLeadIncumbentWinsAfterRestart7732026/10/24 21:46:52 INFO lead: acquired remote=192.0.2.1:12347742026/10/24 21:46:53 INFO lead: released remote=192.0.2.1:12347752026/10/24 21:46:53 INFO lead: acquired remote=192.0.2.1:12347762026/10/24 21:46:54 INFO lead: released remote=192.0.2.1:1234777--- PASS: TestLeadIncumbentWinsAfterRestart (1.81s)778=== RUN TestLeadIncumbentAnnouncesAtOnce779=== PAUSE TestLeadIncumbentAnnouncesAtOnce780=== RUN TestLeadEndsOnShutdown781=== PAUSE TestLeadEndsOnShutdown782=== RUN TestLeadEndsWhenItsConnectionHangs7832026/10/24 21:46:54 INFO lead: acquired remote=192.0.2.1:12347842026-10-24 21:46:56.076 UTC [396] FATAL: terminating connection due to administrator command7852026/10/24 21:46:56 INFO lead: acquired remote=192.0.2.1:12347862026/10/24 21:46:57 WARN lead: lock connection lost error="timeout: context deadline exceeded"7872026/10/24 21:46:57 INFO lead: released remote=192.0.2.1:12347882026/10/24 21:46:57 INFO lead: released remote=192.0.2.1:1234789--- PASS: TestLeadEndsWhenItsConnectionHangs (3.10s)790=== RUN TestGCAdvisoryLockBlocksConcurrentRun791=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun792=== RUN TestGCBugBareHashReferences793=== PAUSE TestGCBugBareHashReferences794=== RUN TestGCMetrics795=== PAUSE TestGCMetrics796=== RUN TestPushDedupSurvivesConcurrentGC797=== PAUSE TestPushDedupSurvivesConcurrentGC798=== RUN TestDeduplicatedObjectsRecordedAsPending799=== PAUSE TestDeduplicatedObjectsRecordedAsPending800=== RUN TestGCSweepSkipsPendingObjects801=== PAUSE TestGCSweepSkipsPendingObjects802=== RUN TestTombstonedObjectOfferedWithoutWaiting803=== PAUSE TestTombstonedObjectOfferedWithoutWaiting804=== RUN TestGCSweepDeliversEachKeyOnce805=== PAUSE TestGCSweepDeliversEachKeyOnce806=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection807=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection808=== RUN TestForceGCDuringPushOffersSweptObject809=== PAUSE TestForceGCDuringPushOffersSweptObject810=== RUN TestFailedS3DeleteKeepsTombstone811=== PAUSE TestFailedS3DeleteKeepsTombstone812=== RUN TestSweepSkipsRowsLockedByPush813=== PAUSE TestSweepSkipsRowsLockedByPush814=== RUN TestRegisterCompletedObjectNeedsPendingRow815=== PAUSE TestRegisterCompletedObjectNeedsPendingRow816=== RUN TestGetExistingObjectsLocksRows817=== PAUSE TestGetExistingObjectsLocksRows818=== RUN TestSweepRechecksPendingAfterLocking819=== PAUSE TestSweepRechecksPendingAfterLocking820=== RUN TestPushWaitsForSweepHoldingRow821=== PAUSE TestPushWaitsForSweepHoldingRow822=== RUN TestCommitRacingPendingCleanupKeepsObjects823=== PAUSE TestCommitRacingPendingCleanupKeepsObjects824=== RUN TestGCEndsOnShutdown825=== PAUSE TestGCEndsOnShutdown826=== RUN TestGCTaskStore_StartNew827=== PAUSE TestGCTaskStore_StartNew828=== RUN TestGCTaskStore_DeduplicateSameParams829=== PAUSE TestGCTaskStore_DeduplicateSameParams830=== RUN TestGCTaskStore_ConflictDifferentParams831=== PAUSE TestGCTaskStore_ConflictDifferentParams832=== RUN TestGCTaskStore_GetEmpty833=== PAUSE TestGCTaskStore_GetEmpty834=== RUN TestGCTaskStore_GetReturnsLatest835=== PAUSE TestGCTaskStore_GetReturnsLatest836=== RUN TestGCTaskStore_CompletedAllowsNewTask837=== PAUSE TestGCTaskStore_CompletedAllowsNewTask838=== RUN TestGCTaskStore_PhaseUpdates839=== PAUSE TestGCTaskStore_PhaseUpdates840=== RUN TestGCTaskStore_Fail841=== PAUSE TestGCTaskStore_Fail842=== RUN TestGracefulShutdownDrainsInflight843=== PAUSE TestGracefulShutdownDrainsInflight844=== RUN TestService_healthCheckHandler845=== PAUSE TestService_healthCheckHandler846=== RUN TestService_readinessHandler847=== PAUSE TestService_readinessHandler848=== RUN TestGenerateLandingPage849=== PAUSE TestGenerateLandingPage850=== RUN TestCacheConfigHandlerMaxNarSize851=== PAUSE TestCacheConfigHandlerMaxNarSize852=== RUN TestCreatePendingClosureRejectsOversizedNAR853=== PAUSE TestCreatePendingClosureRejectsOversizedNAR854=== RUN TestNARDeduplicationMetadataUploadBug855=== PAUSE TestNARDeduplicationMetadataUploadBug856=== RUN TestMetricsInventory857=== PAUSE TestMetricsInventory858=== RUN TestMetricsCommit859=== PAUSE TestMetricsCommit860=== RUN TestService_NativeMTLS861=== PAUSE TestService_NativeMTLS862=== RUN TestServerTLSConfig863=== PAUSE TestServerTLSConfig864=== RUN TestMultipartCleanup865=== PAUSE TestMultipartCleanup866=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded867=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded868=== RUN TestPendingCleanupUsesOneCutoff869=== PAUSE TestPendingCleanupUsesOneCutoff870=== RUN TestNativeOIDCLoginPushRefresh871=== PAUSE TestNativeOIDCLoginPushRefresh872=== RUN TestObjectStatsTrigger873=== PAUSE TestObjectStatsTrigger874=== RUN TestObjectStatsLargeCommit875=== PAUSE TestObjectStatsLargeCommit876=== RUN TestOrphanedObjectsGC877=== PAUSE TestOrphanedObjectsGC878=== RUN TestOrphanedObjectsGCStressTest879=== PAUSE TestOrphanedObjectsGCStressTest880=== RUN TestCreatePin_ReservedPins881=== PAUSE TestCreatePin_ReservedPins882=== RUN TestPresentReportsOnlyClosureRoots883=== PAUSE TestPresentReportsOnlyClosureRoots884=== RUN TestPresentRefreshesOnlyStaleClosures885=== PAUSE TestPresentRefreshesOnlyStaleClosures886=== RUN TestPresentNotReportedWhileGCDeletesClosure887=== PAUSE TestPresentNotReportedWhileGCDeletesClosure888=== RUN TestParseSingleRange889=== PAUSE TestParseSingleRange890=== RUN TestProxyHeadersOnlyTrustedOnSocket8912026/10/24 21:46:57 INFO Starting HTTP server address=127.0.0.1:395538922026/10/24 21:46:57 INFO Starting HTTP server address=proxy.sock8932026/10/24 21:46:57 WARN mTLS auth: subject not in bound subjects subject="CN=someone"8942026/10/24 21:46:57 INFO Shutdown signal received, draining in-flight requests timeout=10s895--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.09s)896=== RUN TestIsValidCachePath897=== PAUSE TestIsValidCachePath898=== RUN TestReadProxyNarinfo899=== PAUSE TestReadProxyNarinfo900=== RUN TestReadProxyNarinfoAlreadyDecompressed901=== PAUSE TestReadProxyNarinfoAlreadyDecompressed902=== RUN TestReadProxyContentNegotiation903=== PAUSE TestReadProxyContentNegotiation904=== RUN TestReadProxyNarStreaming905=== PAUSE TestReadProxyNarStreaming906=== RUN TestReadProxy404907=== PAUSE TestReadProxy404908=== RUN TestReadProxyInvalidPath909=== PAUSE TestReadProxyInvalidPath910=== RUN TestReadProxyHead911=== PAUSE TestReadProxyHead912=== RUN TestReadProxyOutlastsServerWriteTimeout913=== PAUSE TestReadProxyOutlastsServerWriteTimeout914=== RUN TestReadProxyConditionalGet915=== PAUSE TestReadProxyConditionalGet916=== RUN TestReadProxyRootRedirectsToIndexHTML917=== PAUSE TestReadProxyRootRedirectsToIndexHTML918=== RUN TestReadProxyDisabled919=== PAUSE TestReadProxyDisabled920=== RUN TestReadRedirectNar921=== PAUSE TestReadRedirectNar922=== RUN TestReadRedirectKeepsNarinfoProxied923=== PAUSE TestReadRedirectKeepsNarinfoProxied924=== RUN TestReadProxyRangeRequest925=== PAUSE TestReadProxyRangeRequest926=== RUN TestReadRedirectUsesPublicS3URL927=== PAUSE TestReadRedirectUsesPublicS3URL928=== RUN TestPush_OverlappingRootsStoreOneRowPerKey929=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey930=== RUN TestPush_CompleteCommitsEveryRoot931=== PAUSE TestPush_CompleteCommitsEveryRoot932=== RUN TestPush_RepeatedRootCommitsOnce933=== PAUSE TestPush_RepeatedRootCommitsOnce934=== RUN TestPush_CompleteWaitsForCleanupOfThePush935=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush936=== RUN TestPush_RootsAreLockedInByteOrder937=== PAUSE TestPush_RootsAreLockedInByteOrder938=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit939=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit940=== RUN TestPush_RejectsBadRequests941=== PAUSE TestPush_RejectsBadRequests942=== RUN TestPush_SignsNarinfosOfItsPendingObjects943=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects944=== RUN TestRedundantMultipartUpload945=== PAUSE TestRedundantMultipartUpload946=== RUN TestCompleteMultipartUpload_ErrorButObjectExists947=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists948=== RUN TestCompletedNarNotReofferedAcrossClosures949=== PAUSE TestCompletedNarNotReofferedAcrossClosures950=== RUN TestPresignedUploadRegisteredBeforeCommit951=== PAUSE TestPresignedUploadRegisteredBeforeCommit952=== RUN TestService_Rustfstest953=== PAUSE TestService_Rustfstest954=== RUN TestParseSize955=== PAUSE TestParseSize956=== RUN TestSkippedUploadsHandler957=== PAUSE TestSkippedUploadsHandler958=== RUN TestSystemdListenerNotActivated959--- PASS: TestSystemdListenerNotActivated (0.00s)960=== RUN TestWatchdogBeatsWhenHealthy961--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)962=== RUN TestWatchdogSkipsWhenUnhealthy9632026/10/24 21:46:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9642026/10/24 21:46:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9652026/10/24 21:46:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9662026/10/24 21:46:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9672026/10/24 21:46:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9682026/10/24 21:46:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9692026/10/24 21:46:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9702026/10/24 21:46:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9712026/10/24 21:46:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"9722026/10/24 21:46:57 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"973--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)974=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle975=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle976=== RUN TestProxyWriteTimeout977=== PAUSE TestProxyWriteTimeout978=== RUN TestPendingClosureWriteTimeout979=== PAUSE TestPendingClosureWriteTimeout980=== RUN TestIsValidUploadKey981=== PAUSE TestIsValidUploadKey982=== RUN TestUploadHandlersRejectInvalidKeys983=== PAUSE TestUploadHandlersRejectInvalidKeys984=== RUN TestUploadHandlersRejectOversizedBody985=== PAUSE TestUploadHandlersRejectOversizedBody986=== RUN TestService_cleanupPendingClosuresHandler987=== PAUSE TestService_cleanupPendingClosuresHandler988=== RUN TestService_createPendingClosureHandler989=== PAUSE TestService_createPendingClosureHandler990=== RUN TestService_verifyS3Integrity991=== PAUSE TestService_verifyS3Integrity992=== RUN TestCompleteMultipartUnregistered993=== PAUSE TestCompleteMultipartUnregistered994=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT995=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT996=== CONT TestService_AuthMiddleware997=== CONT TestService_cleanupPendingClosuresHandler998=== CONT TestPresentNotReportedWhileGCDeletesClosure999=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1000=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1001=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1002=== CONT TestPush_RepeatedRootCommitsOnce1003=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1004=== CONT TestCompleteMultipartUnregistered1005=== CONT TestService_verifyS3Integrity1006=== CONT TestService_createPendingClosureHandler1007=== CONT TestUploadHandlersRejectOversizedBody1008=== CONT TestUploadHandlersRejectInvalidKeys1009=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1010=== CONT TestIsValidUploadKey1011=== CONT TestPendingClosureWriteTimeout1012=== CONT TestProxyWriteTimeout1013=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1014=== CONT TestSkippedUploadsHandler1015=== CONT TestParseSize1016=== CONT TestService_Rustfstest1017=== CONT TestPresignedUploadRegisteredBeforeCommit1018=== CONT TestCompletedNarNotReofferedAcrossClosures1019=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1020=== CONT TestRedundantMultipartUpload1021=== CONT TestPush_SignsNarinfosOfItsPendingObjects1022=== CONT TestPush_RejectsBadRequests1023=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1024=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1025=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1026=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1027=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1028=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1029=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1030=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1031=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1032=== CONT TestRegisterCompletedObjectNeedsPendingRow1033=== CONT TestPush_CompleteWaitsForCleanupOfThePush10342026/10/24 21:46:58 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001035=== RUN TestPendingClosureWriteTimeout/empty1036=== RUN TestProxyWriteTimeout/narinfo1037--- PASS: TestParseSize (0.00s)1038=== CONT TestPush_RootsAreLockedInByteOrder1039=== RUN TestIsValidUploadKey/narinfo1040=== PAUSE TestPendingClosureWriteTimeout/empty1041=== PAUSE TestIsValidUploadKey/narinfo1042=== RUN TestPendingClosureWriteTimeout/400_objects1043=== PAUSE TestPendingClosureWriteTimeout/400_objects1044=== RUN TestPendingClosureWriteTimeout/670k_objects1045=== PAUSE TestProxyWriteTimeout/narinfo1046=== RUN TestIsValidUploadKey/nar_zst1047=== RUN TestProxyWriteTimeout/1_GiB_nar1048--- PASS: TestSkippedUploadsHandler (0.01s)1049=== PAUSE TestPendingClosureWriteTimeout/670k_objects1050=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1051=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1052=== PAUSE TestIsValidUploadKey/nar_zst1053=== RUN TestIsValidUploadKey/nar_xz1054=== PAUSE TestIsValidUploadKey/nar_xz1055=== RUN TestIsValidUploadKey/nar_plain1056=== PAUSE TestIsValidUploadKey/nar_plain1057=== RUN TestIsValidUploadKey/listing1058=== PAUSE TestIsValidUploadKey/listing1059=== RUN TestIsValidUploadKey/build_log1060=== PAUSE TestIsValidUploadKey/build_log1061=== RUN TestIsValidUploadKey/build_log_home-manager_file1062=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1063=== PAUSE TestProxyWriteTimeout/1_GiB_nar1064=== CONT TestPresentRefreshesOnlyStaleClosures1065=== CONT TestPresentReportsOnlyClosureRoots1066=== RUN TestIsValidUploadKey/build_log_plus_in_name1067=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1068=== RUN TestIsValidUploadKey/build_log_question_mark1069=== PAUSE TestIsValidUploadKey/build_log_question_mark1070=== RUN TestIsValidUploadKey/build_log_equals1071=== PAUSE TestIsValidUploadKey/build_log_equals1072=== RUN TestIsValidUploadKey/realisation1073=== PAUSE TestIsValidUploadKey/realisation1074=== RUN TestIsValidUploadKey/realisation_plus_in_output1075=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1076=== RUN TestIsValidUploadKey/nix-cache-info1077=== PAUSE TestIsValidUploadKey/nix-cache-info1078=== RUN TestIsValidUploadKey/index.html1079=== PAUSE TestIsValidUploadKey/index.html1080=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1081=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1082=== RUN TestProxyWriteTimeout/10_GiB_nar1083=== PAUSE TestProxyWriteTimeout/10_GiB_nar1084=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1085=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1086=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1087=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1088=== RUN TestIsValidUploadKey/traversal1089=== PAUSE TestIsValidUploadKey/traversal1090=== RUN TestIsValidUploadKey/traversal_nar1091=== PAUSE TestIsValidUploadKey/traversal_nar1092=== RUN TestIsValidUploadKey/absolute1093=== PAUSE TestIsValidUploadKey/absolute1094=== RUN TestIsValidUploadKey/empty_key1095=== PAUSE TestIsValidUploadKey/empty_key1096=== RUN TestIsValidUploadKey/unknown_type1097=== PAUSE TestIsValidUploadKey/unknown_type1098=== RUN TestProxyWriteTimeout/unknown_size1099=== PAUSE TestProxyWriteTimeout/unknown_size1100=== CONT TestCreatePin_ReservedPins1101=== CONT TestOrphanedObjectsGCStressTest11022026/10/24 21:46:58 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32939/oidc1103=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1104=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1105=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1106=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1107=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1108=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1109=== CONT TestOrphanedObjectsGC11102026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures1111--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.32s)1112=== CONT TestObjectStatsLargeCommit11132026/10/24 21:46:58 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1114--- PASS: TestService_AuthMiddleware (0.33s)1115=== CONT TestObjectStatsTrigger1116--- PASS: TestService_Rustfstest (0.34s)1117=== CONT TestNativeOIDCLoginPushRefresh1118=== RUN TestNativeOIDCLoginPushRefresh/new-id-token1119=== PAUSE TestNativeOIDCLoginPushRefresh/new-id-token1120=== RUN TestNativeOIDCLoginPushRefresh/omitted-id-token1121=== PAUSE TestNativeOIDCLoginPushRefresh/omitted-id-token1122=== CONT TestGCTaskStore_Fail1123--- PASS: TestGCTaskStore_Fail (0.00s)1124=== CONT TestGCTaskStore_PhaseUpdates1125--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1126=== CONT TestGCTaskStore_CompletedAllowsNewTask1127--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1128=== CONT TestGCTaskStore_GetReturnsLatest1129--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1130=== CONT TestGCTaskStore_GetEmpty1131--- PASS: TestGCTaskStore_GetEmpty (0.00s)1132=== CONT TestGCTaskStore_ConflictDifferentParams1133--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1134=== CONT TestGCTaskStore_DeduplicateSameParams1135--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1136=== CONT TestGCTaskStore_StartNew1137--- PASS: TestGCTaskStore_StartNew (0.00s)1138=== CONT TestGCEndsOnShutdown1139=== RUN TestGCEndsOnShutdown/before_the_run1140=== PAUSE TestGCEndsOnShutdown/before_the_run1141=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1142=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1143=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1144=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1145=== CONT TestCommitRacingPendingCleanupKeepsObjects11462026/10/24 21:46:58 INFO Received push request method=POST path=/api/pushes11472026/10/24 21:46:58 INFO Received cleanup request method=DELETE path=/api/pending_closures11482026/10/24 21:46:58 INFO Aborted multipart uploads count=0 kept=011492026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures11502026/10/24 21:46:58 INFO Received complete push request method=POST path=/api/pushes/1/complete11512026/10/24 21:46:58 INFO Received cleanup request method=DELETE path=/api/pending_closures11522026/10/24 21:46:58 INFO Completed push id=1 objects=4 duration=6.522303ms1153--- PASS: TestPush_RepeatedRootCommitsOnce (0.39s)1154=== CONT TestPushWaitsForSweepHoldingRow11552026/10/24 21:46:58 INFO Aborted multipart uploads count=1 kept=011562026/10/24 21:46:58 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11572026-10-24 21:46:58.392 UTC [477] ERROR: Closure does not exist: id=111582026-10-24 21:46:58.392 UTC [477] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE11592026-10-24 21:46:58.392 UTC [477] STATEMENT: -- name: CommitPendingClosure :one1160 SELECT commit_pending_closure($1::bigint)::bigint1161 1162--- PASS: TestService_cleanupPendingClosuresHandler (0.40s)1163=== CONT TestSweepRechecksPendingAfterLocking11642026/10/24 21:46:58 INFO Received push request method=POST path=/api/pushes11652026/10/24 21:46:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11662026/10/24 21:46:58 INFO Signed narinfos id=1 count=111672026/10/24 21:46:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11682026/10/24 21:46:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11692026/10/24 21:46:58 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"11702026/10/24 21:46:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11712026/10/24 21:46:58 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"11722026/10/24 21:46:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11732026/10/24 21:46:58 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=111742026/10/24 21:46:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11752026/10/24 21:46:58 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1176--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.40s)1177=== CONT TestGracefulShutdownDrainsInflight11782026/10/24 21:46:58 INFO Starting HTTP server address=127.0.0.1:4402711792026/10/24 21:46:58 INFO Shutdown signal received, draining in-flight requests timeout=10s11802026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures11812026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures11822026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures11832026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures11842026/10/24 21:46:58 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11852026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures1186--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.44s)1187=== CONT TestGetExistingObjectsLocksRows11882026/10/24 21:46:58 INFO Received push request method=POST path=/api/pushes11892026/10/24 21:46:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11902026/10/24 21:46:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11912026/10/24 21:46:58 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjhjNDQ1ZTEtOTkwYS00MjFlLWJiYTQtN2ViNzcwNWRmMDE4LjA5Y2M5N2NkLTAyZjItNDE5NC05ZTAyLTBmN2QzNDIxNDQ5NHgxNzkyODc4NDE4NDQwMTM1NjEx11922026/10/24 21:46:58 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1193--- PASS: TestCompleteMultipartUnregistered (0.47s)1194=== CONT TestPendingCleanupUsesOneCutoff11952026/10/24 21:46:58 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZjhjNDQ1ZTEtOTkwYS00MjFlLWJiYTQtN2ViNzcwNWRmMDE4LjA5Y2M5N2NkLTAyZjItNDE5NC05ZTAyLTBmN2QzNDIxNDQ5NHgxNzkyODc4NDE4NDQwMTM1NjEx parts=11196--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.47s)1197=== CONT TestMetricsInventory1198--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1199=== CONT TestNARDeduplicationMetadataUploadBug12002026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures12012026/10/24 21:46:58 INFO Received push request method=POST path=/api/pushes12022026-10-24 21:46:58.730 UTC [535] ERROR: could not obtain lock on row in relation "closures"12032026-10-24 21:46:58.730 UTC [535] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12042026-10-24 21:46:58.730 UTC [535] ERROR: could not obtain lock on row in relation "closures"12052026-10-24 21:46:58.730 UTC [535] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12062026-10-24 21:46:58.730 UTC [535] ERROR: could not obtain lock on row in relation "closures"12072026-10-24 21:46:58.730 UTC [535] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12082026-10-24 21:46:58.730 UTC [535] ERROR: could not obtain lock on row in relation "closures"12092026-10-24 21:46:58.730 UTC [535] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT12102026-10-24 21:46:58.731 UTC [535] ERROR: could not obtain lock on row in relation "closures"12112026-10-24 21:46:58.731 UTC [535] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1212--- PASS: TestPresentRefreshesOnlyStaleClosures (0.67s)1213=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1214--- PASS: TestPush_RootsAreLockedInByteOrder (0.73s)1215=== CONT TestCreatePendingClosureRejectsOversizedNAR12162026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures1217--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1218=== CONT TestMultipartCleanup12192026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures12202026-10-24 21:46:58.763 UTC [516] ERROR: Push does not exist: id=112212026-10-24 21:46:58.763 UTC [516] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE12222026-10-24 21:46:58.763 UTC [516] STATEMENT: SELECT commit_push($1)12232026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures12242026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures1225--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (0.76s)12262026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures1227=== CONT TestCacheConfigHandlerMaxNarSize1228--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1229=== CONT TestServerTLSConfig1230=== RUN TestServerTLSConfig/no_client_CA1231=== PAUSE TestServerTLSConfig/no_client_CA1232=== RUN TestServerTLSConfig/missing_CA_file1233=== PAUSE TestServerTLSConfig/missing_CA_file1234=== RUN TestServerTLSConfig/not_a_PEM_file1235=== PAUSE TestServerTLSConfig/not_a_PEM_file1236=== CONT TestGenerateLandingPage1237--- PASS: TestGenerateLandingPage (0.00s)1238=== CONT TestService_NativeMTLS12392026/10/24 21:46:58 INFO Received push request method=POST path=/api/pushes12402026/10/24 21:46:58 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12412026/10/24 21:46:58 WARN Refused reserved pin name=worker-x86_64-linux12422026/10/24 21:46:58 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12432026/10/24 21:46:58 INFO Received create pin request method=POST path=/api/pins/my-app12442026/10/24 21:46:58 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1245--- PASS: TestCreatePin_ReservedPins (0.75s)1246=== CONT TestService_readinessHandler12472026/10/24 21:46:58 INFO Received complete push request method=POST path=/api/pushes/1/complete12482026/10/24 21:46:58 INFO Completed push id=1 objects=4 duration=9.441653ms12492026/10/24 21:46:58 INFO Received push request method=POST path=/api/pushes1250--- PASS: TestPresentReportsOnlyClosureRoots (0.79s)1251=== CONT TestMetricsCommit12522026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures12532026/10/24 21:46:58 INFO Aborted multipart uploads count=0 kept=012542026/10/24 21:46:58 WARN Force mode enabled - objects will be deleted immediately without grace period12552026/10/24 21:46:58 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=012562026/10/24 21:46:58 INFO Vacuumed table table=pending_closures12572026/10/24 21:46:58 INFO Vacuumed table table=pending_objects12582026/10/24 21:46:58 INFO Vacuumed table table=multipart_uploads12592026/10/24 21:46:58 INFO Vacuumed table table=closures12602026/10/24 21:46:58 INFO Vacuumed table table=objects12612026/10/24 21:46:58 INFO Received complete push request method=POST path=/api/pushes/2/complete12622026/10/24 21:46:58 INFO Completed push id=2 objects=4 duration=2.736961ms1263--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (0.91s)1264=== CONT TestService_healthCheckHandler1265=== RUN TestPush_RejectsBadRequests/root_not_in_objects1266=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1267=== RUN TestPush_RejectsBadRequests/no_roots1268=== PAUSE TestPush_RejectsBadRequests/no_roots1269=== RUN TestPush_RejectsBadRequests/no_objects1270=== PAUSE TestPush_RejectsBadRequests/no_objects1271=== RUN TestPush_RejectsBadRequests/bad_root1272=== PAUSE TestPush_RejectsBadRequests/bad_root1273=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1274--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.94s)1275=== CONT TestSweepSkipsRowsLockedByPush12762026/10/24 21:46:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12772026/10/24 21:46:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1278--- PASS: TestObjectStatsTrigger (0.66s)1279=== CONT TestFailedS3DeleteKeepsTombstone12802026/10/24 21:46:58 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZjhjNDQ1ZTEtOTkwYS00MjFlLWJiYTQtN2ViNzcwNWRmMDE4LmZjNDUwY2YwLWE1MTQtNGNmNi04ZmE3LWVjMmRhYjdlOGY5NngxNzkyODc4NDE4NDE2NjQ1OTMy parts=1212812026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures12822026/10/24 21:46:58 INFO Aborted multipart uploads count=0 kept=012832026/10/24 21:46:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12842026/10/24 21:46:58 INFO Received uploads request method=POST path=/api/pending_closures12852026/10/24 21:46:58 WARN Force mode enabled - objects will be deleted immediately without grace period12862026/10/24 21:46:59 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=012872026/10/24 21:46:59 INFO Vacuumed table table=pending_closures12882026/10/24 21:46:59 INFO Vacuumed table table=pending_objects12892026/10/24 21:46:59 INFO Vacuumed table table=multipart_uploads12902026/10/24 21:46:59 INFO Vacuumed table table=closures12912026/10/24 21:46:59 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZjhjNDQ1ZTEtOTkwYS00MjFlLWJiYTQtN2ViNzcwNWRmMDE4LmYwYzVhYWExLThmOWUtNDljMS1hOGFjLWM0NDIzYzFhYzE0OHgxNzkyODc4NDE4NDkzOTQ2OTAz parts=1012922026/10/24 21:46:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12932026/10/24 21:46:59 INFO Vacuumed table table=objects12942026/10/24 21:46:59 INFO Completed upload id=1 objects=2 duration=3.683071ms12952026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures12962026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures1297--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.67s)1298=== CONT TestClientErrorHandling1299=== RUN TestClientErrorHandling/InvalidStorePath1300=== PAUSE TestClientErrorHandling/InvalidStorePath1301=== RUN TestClientErrorHandling/InvalidAuthToken1302=== PAUSE TestClientErrorHandling/InvalidAuthToken1303=== RUN TestClientErrorHandling/ServerNotAvailable1304=== PAUSE TestClientErrorHandling/ServerNotAvailable1305=== CONT TestForceGCDuringPushOffersSweptObject1306=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1307=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1308=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1309=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1310=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection13112026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures13122026/10/24 21:46:59 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo13132026/10/24 21:46:59 WARN Found objects in DB but missing from S3, will re-upload count=11314--- PASS: TestService_verifyS3Integrity (1.03s)1315=== CONT TestClientSharedPathCommittedMidPush13162026/10/24 21:46:59 INFO Aborted multipart uploads count=0 kept=013172026/10/24 21:46:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13182026/10/24 21:46:59 WARN Force mode enabled - objects will be deleted immediately without grace period1319--- PASS: TestGetExistingObjectsLocksRows (0.65s)1320=== CONT TestGCSweepDeliversEachKeyOnce13212026/10/24 21:46:59 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=013222026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures13232026/10/24 21:46:59 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZjhjNDQ1ZTEtOTkwYS00MjFlLWJiYTQtN2ViNzcwNWRmMDE4LjU5NzhiMTczLWE3MjYtNDdmMi05NWExLTQ4MGI1YmMzYWY0NXgxNzkyODc4NDE4NzcwNDYwMTMy parts=1013242026/10/24 21:46:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13252026/10/24 21:46:59 INFO Vacuumed table table=pending_closures13262026/10/24 21:46:59 INFO Vacuumed table table=pending_objects13272026/10/24 21:46:59 INFO Completed upload id=1 objects=2 duration=3.772842ms13282026/10/24 21:46:59 INFO Vacuumed table table=multipart_uploads13292026/10/24 21:46:59 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000013302026/10/24 21:46:59 INFO Vacuumed table table=closures13312026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures13322026/10/24 21:46:59 INFO Vacuumed table table=objects13332026/10/24 21:46:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1334--- PASS: TestSweepRechecksPendingAfterLocking (0.71s)1335=== CONT TestClientWithDependencies13362026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures13372026/10/24 21:46:59 INFO Starting cleanup of old closures method=DELETE path=/api/closures13382026/10/24 21:46:59 INFO Received cleanup request method=DELETE path=/api/pending_closures13392026/10/24 21:46:59 INFO Aborted multipart uploads count=0 kept=013402026/10/24 21:46:59 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZjhjNDQ1ZTEtOTkwYS00MjFlLWJiYTQtN2ViNzcwNWRmMDE4LjNiOThlMTA5LTAxYmQtNDFhMS04MjlkLTJiMzZjN2NhODJmMXgxNzkyODc4NDE4NzQ4MjAzOTE0 parts=1213412026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures13422026/10/24 21:46:59 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=01343--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.13s)1344=== CONT TestClientMultipleUploads13452026/10/24 21:46:59 INFO Vacuumed table table=pending_closures1346--- PASS: TestMetricsInventory (0.66s)1347=== CONT TestClientIntegration13482026/10/24 21:46:59 INFO Vacuumed table table=pending_objects13492026/10/24 21:46:59 INFO Vacuumed table table=multipart_uploads13502026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures13512026/10/24 21:46:59 INFO Vacuumed table table=closures13522026/10/24 21:46:59 INFO Vacuumed table table=objects1353=== NAME TestOrphanedObjectsGC1354 orphaned_objects_gc_test.go:287: GC Test Summary:1355 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1356 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1357 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1358 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1359 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1360--- PASS: TestOrphanedObjectsGC (1.00s)1361=== CONT TestTombstonedObjectOfferedWithoutWaiting13622026/10/24 21:46:59 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001363--- PASS: TestService_createPendingClosureHandler (1.16s)1364=== CONT TestClientFallsBackToClosures13652026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures1366=== NAME TestNARDeduplicationMetadataUploadBug1367 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug3614907536/001/store/kr400y8bdd4gdq75iyy8a9dfvzwzkksk-file1.txt1368--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.45s)1369=== CONT TestPinProtectsFromGC13702026/10/24 21:46:59 WARN mTLS auth: subject not in bound subjects subject="CN=reader"13712026/10/24 21:46:59 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1372--- PASS: TestService_NativeMTLS (0.42s)1373=== CONT TestDeleteClosuresRacingPins13742026/10/24 21:46:59 WARN readiness check failed error="closed pool"1375--- PASS: TestService_readinessHandler (0.40s)1376=== CONT TestClientPushesUseOnePush13772026/10/24 21:46:59 INFO Received push request method=POST path=/api/pushes13782026/10/24 21:46:59 INFO Received push request method=POST path=/api/pushes13792026/10/24 21:46:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13802026/10/24 21:46:59 INFO Uploading kr400y8bdd4gdq75iyy8a9dfvzwzkksk-file1.txt (160B)13812026/10/24 21:46:59 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"13822026/10/24 21:46:59 WARN Failed to register uploaded object key=kr400y8bdd4gdq75iyy8a9dfvzwzkksk.ls error="server returned 404: 404 page not found\n"13832026/10/24 21:46:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13842026/10/24 21:46:59 INFO Signed narinfos id=1 count=113852026/10/24 21:46:59 INFO Uploading 1 narinfos13862026/10/24 21:46:59 INFO Received complete push request method=POST path=/api/pushes/1/complete13872026/10/24 21:46:59 WARN Failed to register uploaded object key=kr400y8bdd4gdq75iyy8a9dfvzwzkksk.narinfo error="server returned 404: 404 page not found\n"13882026/10/24 21:46:59 INFO Received complete push request method=POST path=/api/pushes/1/complete13892026/10/24 21:46:59 INFO Completed push id=1 objects=3 duration=6.710442ms13902026/10/24 21:46:59 INFO Upload complete. (58ms)1391=== NAME TestNARDeduplicationMetadataUploadBug1392 metadata_upload_test.go:54: Retrieved narinfo from S3:1393 StorePath: /build/TestNARDeduplicationMetadataUploadBug3614907536/001/store/kr400y8bdd4gdq75iyy8a9dfvzwzkksk-file1.txt1394 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1395 Compression: zstd1396 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1397 NarSize: 1601398 References: 1399 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf14002026/10/24 21:46:59 INFO Completed push id=1 objects=4 duration=8.113274ms1401 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1402 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1403 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}14042026/10/24 21:46:59 INFO Received cleanup request method=DELETE path=/api/pending_closures14052026/10/24 21:46:59 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket37/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""14062026/10/24 21:46:59 INFO Aborted multipart uploads count=0 kept=114072026/10/24 21:46:59 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14082026/10/24 21:46:59 INFO Completed upload id=2 objects=2 duration=1.515461ms14092026/10/24 21:46:59 INFO Received cleanup request method=DELETE path=/api/pending_closures14102026/10/24 21:46:59 INFO Aborted multipart uploads count=1 kept=01411--- PASS: TestMetricsCommit (0.41s)1412=== CONT TestService_RequireScope_OIDC1413--- PASS: TestMultipartCleanup (0.54s)1414=== CONT TestGCSweepSkipsPendingObjects1415--- PASS: TestService_healthCheckHandler (0.36s)1416=== CONT TestService_ReadAuthMiddleware14172026/10/24 21:46:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37379/oidc1418=== NAME TestNARDeduplicationMetadataUploadBug1419 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug3614907536/001/store/fpw5qzdbzyi8188kv3zxznxn9703dy82-file2.txt14202026/10/24 21:46:59 INFO Aborted multipart uploads count=0 kept=014212026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures14222026/10/24 21:46:59 WARN Force mode enabled - objects will be deleted immediately without grace period14232026/10/24 21:46:59 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=014242026/10/24 21:46:59 INFO Vacuumed table table=pending_closures14252026/10/24 21:46:59 INFO Vacuumed table table=pending_objects14262026/10/24 21:46:59 INFO Vacuumed table table=multipart_uploads14272026/10/24 21:46:59 INFO Vacuumed table table=closures14282026/10/24 21:46:59 INFO Vacuumed table table=objects14292026/10/24 21:46:59 INFO Aborted multipart uploads count=0 kept=014302026/10/24 21:46:59 WARN Force mode enabled - objects will be deleted immediately without grace period14312026/10/24 21:46:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14322026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures14332026/10/24 21:46:59 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=014342026/10/24 21:46:59 INFO Vacuumed table table=pending_closures14352026/10/24 21:46:59 INFO Vacuumed table table=pending_objects14362026/10/24 21:46:59 INFO Vacuumed table table=multipart_uploads14372026/10/24 21:46:59 INFO Vacuumed table table=closures14382026/10/24 21:46:59 INFO Vacuumed table table=objects1439--- PASS: TestSweepSkipsRowsLockedByPush (0.40s)1440=== CONT TestClientCADerivations14412026/10/24 21:46:59 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZjhjNDQ1ZTEtOTkwYS00MjFlLWJiYTQtN2ViNzcwNWRmMDE4LjlkNDE1ZWFkLTI4YWYtNDdmYi05NjU2LTczZTIyOTRjN2M2NngxNzkyODc4NDE4OTk5Mjg1NDk0 error="Get \"http://127.0.0.1:1/bucket10/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"14422026/10/24 21:46:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZjhjNDQ1ZTEtOTkwYS00MjFlLWJiYTQtN2ViNzcwNWRmMDE4LjM3MmRhMTk3LTUxMjctNDE2OS04NTZmLTFmNWFkMzMwMzg5ZHgxNzkyODc4NDE4OTk0NjA1MTcy parts=1214432026/10/24 21:46:59 INFO Received cleanup request method=DELETE path=/api/pending_closures14442026/10/24 21:46:59 INFO Aborted multipart uploads count=1 kept=014452026/10/24 21:46:59 INFO Received push request method=POST path=/api/pushes1446--- PASS: TestRedundantMultipartUpload (1.36s)1447=== CONT TestService_AuthMiddleware_OIDC14482026/10/24 21:46:59 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)14492026/10/24 21:46:59 WARN Failed to register uploaded object key=fpw5qzdbzyi8188kv3zxznxn9703dy82.ls error="server returned 404: 404 page not found\n"14502026/10/24 21:46:59 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14512026/10/24 21:46:59 INFO Signed narinfos id=2 count=114522026/10/24 21:46:59 INFO Uploading 1 narinfos14532026/10/24 21:46:59 INFO Received complete push request method=POST path=/api/pushes/2/complete14542026/10/24 21:46:59 WARN Failed to register uploaded object key=fpw5qzdbzyi8188kv3zxznxn9703dy82.narinfo error="server returned 404: 404 page not found\n"14552026/10/24 21:46:59 INFO Completed push id=2 objects=3 duration=1.46684ms14562026/10/24 21:46:59 INFO Upload complete. (47ms)1457=== NAME TestNARDeduplicationMetadataUploadBug1458 metadata_upload_test.go:76: Retrieved narinfo from S3:1459 StorePath: /build/TestNARDeduplicationMetadataUploadBug3614907536/001/store/fpw5qzdbzyi8188kv3zxznxn9703dy82-file2.txt1460 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1461 Compression: zstd1462 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1463 NarSize: 1601464 References: 1465 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1466 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1467 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1468 {"version":1,"root":{"type":"regular","size":44}}1469--- PASS: TestNARDeduplicationMetadataUploadBug (0.90s)1470=== CONT TestCacheStatsHandler14712026/10/24 21:46:59 INFO Aborted multipart uploads count=0 kept=014722026/10/24 21:46:59 INFO Aborted multipart uploads count=0 kept=014732026/10/24 21:46:59 WARN Force mode enabled - objects will be deleted immediately without grace period14742026/10/24 21:46:59 WARN Force mode enabled - objects will be deleted immediately without grace period14752026/10/24 21:46:59 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."14762026/10/24 21:46:59 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."14772026/10/24 21:46:59 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=01478--- PASS: TestFailedS3DeleteKeepsTombstone (0.41s)1479=== CONT TestCacheConfigHandler1480=== RUN TestCacheConfigHandler/full_config,_no_issuer14812026/10/24 21:46:59 INFO Vacuumed table table=pending_closures1482=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1483=== RUN TestCacheConfigHandler/no_cache_url_configured1484=== PAUSE TestCacheConfigHandler/no_cache_url_configured1485=== RUN TestCacheConfigHandler/no_signing_keys1486=== PAUSE TestCacheConfigHandler/no_signing_keys1487=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator14882026/10/24 21:46:59 INFO Vacuumed table table=pending_objects1489=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1490=== CONT TestService_ReadScope_PublicByDefault14912026/10/24 21:46:59 INFO Vacuumed table table=multipart_uploads14922026/10/24 21:46:59 INFO Vacuumed table table=closures14932026/10/24 21:46:59 INFO Vacuumed table table=objects1494--- PASS: TestGCSweepDeliversEachKeyOnce (0.32s)1495=== CONT TestLeadEndsOnShutdown14962026/10/24 21:46:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42819/oidc1497=== NAME TestClientIntegration1498 client_integration_test.go:286: Created store path: /build/TestClientIntegration1746574192/002/store/g0kpxdb1xhc582vgrxr7wmmmzib89k97-test-file.txt14992026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures1500--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.30s)1501=== CONT TestPushDedupSurvivesConcurrentGC1502=== NAME TestClientMultipleUploads1503 client_integration_test.go:358: Created store path 0: /build/TestClientMultipleUploads2445774014/001/store/yhdg4aivznzdk6psds20n0q2mv90f4v1-test-file-0.txt1504=== NAME TestClientWithDependencies1505 client_integration_test.go:613: Built derivation: /build/TestClientWithDependencies2375870168/001/store/qs2298xv7ndgcp2w0641i7yww00mq0hb-test-script1506--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (0.56s)1507=== CONT TestDeduplicatedObjectsRecordedAsPending15082026/10/24 21:46:59 INFO Received push request method=POST path=/api/pushes15092026/10/24 21:46:59 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)15102026/10/24 21:46:59 INFO Uploading y5zw8wzxmzxly8mf02r5044mn35nhgp8-shared-dep (136B)15112026/10/24 21:46:59 INFO Uploading n7q75gsb4ww6bfk6987rahl59zmz3cs4-top (224B)15122026/10/24 21:46:59 WARN Failed to register uploaded object key=n7q75gsb4ww6bfk6987rahl59zmz3cs4.ls error="server returned 404: 404 page not found\n"15132026/10/24 21:46:59 WARN Failed to register uploaded object key=y5zw8wzxmzxly8mf02r5044mn35nhgp8.ls error="server returned 404: 404 page not found\n"15142026/10/24 21:46:59 WARN Failed to register uploaded object key=nar/1qrnzw6aifq5wp1g976kydnxrs38a1hxls746hpa5hqv1zc3f9qp.nar.zst error="server returned 404: 404 page not found\n"15152026/10/24 21:46:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15162026/10/24 21:46:59 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15172026/10/24 21:46:59 INFO Signed narinfos id=1 count=215182026/10/24 21:46:59 INFO Uploading 2 narinfos1519=== NAME TestClientMultipleUploads1520 client_integration_test.go:358: Created store path 1: /build/TestClientMultipleUploads2445774014/001/store/vygs4lfks0sbs3f5r2pbpl8db22crq1b-test-file-1.txt1521=== NAME TestClientWithDependencies1522 client_integration_test.go:615: Found 1 dependencies (including self)15232026/10/24 21:46:59 WARN Failed to register uploaded object key=y5zw8wzxmzxly8mf02r5044mn35nhgp8.narinfo error="server returned 404: 404 page not found\n"15242026/10/24 21:46:59 INFO Received complete push request method=POST path=/api/pushes/1/complete15252026/10/24 21:46:59 WARN Failed to register uploaded object key=n7q75gsb4ww6bfk6987rahl59zmz3cs4.narinfo error="server returned 404: 404 page not found\n"15262026/10/24 21:46:59 INFO Received push request method=POST path=/api/pushes15272026/10/24 21:46:59 INFO Completed push id=1 objects=6 duration=9.196104ms15282026/10/24 21:46:59 INFO Upload complete. (60ms)15292026/10/24 21:46:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15302026/10/24 21:46:59 INFO Uploading g0kpxdb1xhc582vgrxr7wmmmzib89k97-test-file.txt (152B)1531=== NAME TestClientSharedPathCommittedMidPush1532 client_integration_test.go:680: Retrieved narinfo from S3:1533 StorePath: /build/TestClientSharedPathCommittedMidPush3556024645/001/store/y5zw8wzxmzxly8mf02r5044mn35nhgp8-shared-dep1534 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1535 Compression: zstd1536 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821537 NarSize: 1361538 References: 1539 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1540 client_integration_test.go:680: Retrieved narinfo from S3:1541 StorePath: /build/TestClientSharedPathCommittedMidPush3556024645/001/store/n7q75gsb4ww6bfk6987rahl59zmz3cs4-top1542 URL: nar/1qrnzw6aifq5wp1g976kydnxrs38a1hxls746hpa5hqv1zc3f9qp.nar.zst1543 Compression: zstd1544 NarHash: sha256:1qrnzw6aifq5wp1g976kydnxrs38a1hxls746hpa5hqv1zc3f9qp1545 NarSize: 2241546 References: /build/TestClientSharedPathCommittedMidPush3556024645/001/store/y5zw8wzxmzxly8mf02r5044mn35nhgp8-shared-dep1547 CA: text:sha256:09yfajhn6pyas217nfa1rbix13lxjanz13pq0n040lzblky9y2cs15482026/10/24 21:46:59 WARN Failed to register uploaded object key=g0kpxdb1xhc582vgrxr7wmmmzib89k97.ls error="server returned 404: 404 page not found\n"15492026/10/24 21:46:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15502026/10/24 21:46:59 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"15512026/10/24 21:46:59 INFO Signed narinfos id=1 count=115522026/10/24 21:46:59 INFO Uploading 1 narinfos1553--- PASS: TestClientSharedPathCommittedMidPush (0.49s)1554=== CONT TestGCMetrics15552026/10/24 21:46:59 INFO Received complete push request method=POST path=/api/pushes/1/complete15562026/10/24 21:46:59 WARN Failed to register uploaded object key=g0kpxdb1xhc582vgrxr7wmmmzib89k97.narinfo error="server returned 404: 404 page not found\n"1557--- PASS: TestPushWaitsForSweepHoldingRow (1.13s)1558=== CONT TestGCBugBareHashReferences15592026/10/24 21:46:59 INFO Completed push id=1 objects=3 duration=6.245472ms15602026/10/24 21:46:59 INFO Upload complete. (56ms)1561=== NAME TestClientMultipleUploads1562 client_integration_test.go:358: Created store path 2: /build/TestClientMultipleUploads2445774014/001/store/wwdp9xh06jrc1wiqbrzd6f88bnvig0mg-test-file-2.txt1563--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.52s)1564=== CONT TestGCAdvisoryLockBlocksConcurrentRun1565--- PASS: TestService_ReadAuthMiddleware (0.27s)1566=== CONT TestService_AuthMiddleware_MTLSProxyHeader15672026/10/24 21:46:59 INFO All 1 paths already cached1568=== NAME TestClientIntegration1569 client_integration_test.go:312: Retrieved narinfo from S3:1570 StorePath: /build/TestClientIntegration1746574192/002/store/g0kpxdb1xhc582vgrxr7wmmmzib89k97-test-file.txt1571 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1572 Compression: zstd1573 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11574 NarSize: 1521575 References: 1576 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11577 client_integration_test.go:313: Retrieved .ls file from S3 (compressed size: 77 bytes)1578 client_integration_test.go:313: Decompressed .ls content (64 bytes):1579 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1580 client_integration_test.go:316: Testing garbage collection...15812026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures15822026/10/24 21:46:59 INFO Received push request method=POST path=/api/pushes15832026/10/24 21:46:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15842026/10/24 21:46:59 INFO Uploading qs2298xv7ndgcp2w0641i7yww00mq0hb-test-script (136B)1585=== RUN TestService_RequireScope_OIDC/builder_may_write15862026/10/24 21:46:59 WARN Failed to register uploaded object key=qs2298xv7ndgcp2w0641i7yww00mq0hb.ls error="server returned 404: 404 page not found\n"1587=== PAUSE TestService_RequireScope_OIDC/builder_may_write1588=== RUN TestService_RequireScope_OIDC/builder_may_not_admin15892026/10/24 21:46:59 WARN Failed to register uploaded object key=log/q52ays0bknhm3xf772dppj6g86aaprkf-test-script.drv error="server returned 404: 404 page not found\n"1590=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1591=== RUN TestService_RequireScope_OIDC/ops_may_admin1592=== NAME TestPinProtectsFromGC15932026/10/24 21:46:59 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"1594 client_integration_test.go:731: Pinned store path: /build/TestPinProtectsFromGC1960108011/001/store/ll02k74zb7g8sv7symgp92a1c0vjsarh-pinned-file.txt15952026/10/24 21:46:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1596 client_integration_test.go:732: Unpinned store path: /build/TestPinProtectsFromGC1960108011/001/store/19bkykj2nza5kkdn64g93jg32x42za29-unpinned-file.txt1597=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1598=== RUN TestService_RequireScope_OIDC/ops_may_not_write1599=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1600=== RUN TestService_RequireScope_OIDC/reader_may_not_write1601=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write16022026/10/24 21:46:59 INFO Signed narinfos id=1 count=11603=== RUN TestService_RequireScope_OIDC/static_token_may_admin16042026/10/24 21:46:59 INFO Uploading 1 narinfos1605=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1606=== RUN TestService_RequireScope_OIDC/static_token_may_write1607=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1608=== RUN TestService_RequireScope_OIDC/reader_may_read1609=== PAUSE TestService_RequireScope_OIDC/reader_may_read1610=== RUN TestService_RequireScope_OIDC/writer_implies_read1611=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1612=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1613=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1614=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1615=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1616=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1617=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1618=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1619=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1620=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1621=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1622=== CONT TestLeadIncumbentAnnouncesAtOnce16232026/10/24 21:46:59 INFO Aborted multipart uploads count=0 kept=016242026/10/24 21:46:59 INFO Received complete push request method=POST path=/api/pushes/1/complete16252026/10/24 21:46:59 WARN Failed to register uploaded object key=qs2298xv7ndgcp2w0641i7yww00mq0hb.narinfo error="server returned 404: 404 page not found\n"16262026/10/24 21:46:59 INFO Starting cleanup of old closures method=DELETE path=/api/closures16272026/10/24 21:46:59 INFO Garbage collection started16282026/10/24 21:46:59 WARN Force mode enabled - objects will be deleted immediately without grace period16292026/10/24 21:46:59 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=016302026/10/24 21:46:59 INFO Completed push id=1 objects=4 duration=7.099743ms16312026/10/24 21:46:59 INFO Upload complete. (66ms)1632=== NAME TestClientWithDependencies1633 client_integration_test.go:617: Skipping nix copy test - isolated store (/build/TestClientWithDependencies2375870168/001/store) requires matching store prefix16342026/10/24 21:46:59 INFO Received push request method=POST path=/api/pushes16352026/10/24 21:46:59 INFO Aborted multipart uploads count=0 kept=016362026/10/24 21:46:59 INFO Vacuumed table table=pending_closures1637--- PASS: TestClientWithDependencies (0.51s)1638=== CONT TestConnectWaitsForAPeerMigration16392026/10/24 21:46:59 INFO Vacuumed table table=pending_objects16402026/10/24 21:46:59 INFO Vacuumed table table=multipart_uploads16412026/10/24 21:46:59 INFO Vacuumed table table=closures16422026/10/24 21:46:59 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)16432026/10/24 21:46:59 INFO Uploading vygs4lfks0sbs3f5r2pbpl8db22crq1b-test-file-1.txt (160B)16442026/10/24 21:46:59 WARN Force mode enabled - objects will be deleted immediately without grace period16452026/10/24 21:46:59 INFO Uploading wwdp9xh06jrc1wiqbrzd6f88bnvig0mg-test-file-2.txt (160B)16462026/10/24 21:46:59 INFO Uploading yhdg4aivznzdk6psds20n0q2mv90f4v1-test-file-0.txt (160B)16472026/10/24 21:46:59 INFO Vacuumed table table=objects16482026/10/24 21:46:59 WARN Failed to register uploaded object key=vygs4lfks0sbs3f5r2pbpl8db22crq1b.ls error="server returned 404: 404 page not found\n"16492026/10/24 21:46:59 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"16502026/10/24 21:46:59 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"16512026/10/24 21:46:59 WARN Failed to register uploaded object key=wwdp9xh06jrc1wiqbrzd6f88bnvig0mg.ls error="server returned 404: 404 page not found\n"16522026/10/24 21:46:59 WARN Failed to register uploaded object key=yhdg4aivznzdk6psds20n0q2mv90f4v1.ls error="server returned 404: 404 page not found\n"16532026/10/24 21:46:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16542026/10/24 21:46:59 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"16552026/10/24 21:46:59 INFO Signed narinfos id=1 count=316562026/10/24 21:46:59 INFO Uploading 3 narinfos16572026/10/24 21:46:59 WARN Failed to register uploaded object key=wwdp9xh06jrc1wiqbrzd6f88bnvig0mg.narinfo error="server returned 404: 404 page not found\n"16582026/10/24 21:46:59 WARN Failed to register uploaded object key=vygs4lfks0sbs3f5r2pbpl8db22crq1b.narinfo error="server returned 404: 404 page not found\n"16592026/10/24 21:46:59 INFO Received complete push request method=POST path=/api/pushes/1/complete16602026/10/24 21:46:59 WARN Failed to register uploaded object key=yhdg4aivznzdk6psds20n0q2mv90f4v1.narinfo error="server returned 404: 404 page not found\n"1661--- PASS: TestGCSweepSkipsPendingObjects (0.36s)1662=== CONT TestResolveDBConnectionString1663=== RUN TestResolveDBConnectionString/flag_wins1664=== PAUSE TestResolveDBConnectionString/flag_wins1665=== RUN TestResolveDBConnectionString/file_when_flag_empty1666=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1667=== RUN TestResolveDBConnectionString/missing_file_is_an_error1668=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1669=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1670=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1671=== RUN TestResolveDBConnectionString/nothing_configured1672=== PAUSE TestResolveDBConnectionString/nothing_configured1673=== CONT TestLeadElectsOneAndHandsOver16742026/10/24 21:46:59 INFO Completed push id=1 objects=9 duration=8.653443ms16752026/10/24 21:46:59 INFO Upload complete. (65ms)1676=== NAME TestClientMultipleUploads1677 client_integration_test.go:369: Uploaded 3 paths in 102.851301ms16782026/10/24 21:46:59 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=016792026/10/24 21:46:59 INFO Vacuumed table table=pending_closures1680--- PASS: TestClientMultipleUploads (0.50s)1681=== CONT TestReadProxyOutlastsServerWriteTimeout1682--- PASS: TestCacheStatsHandler (0.26s)1683=== CONT TestReadProxyContentNegotiation16842026/10/24 21:46:59 INFO lead: acquired remote=192.0.2.1:123416852026/10/24 21:46:59 INFO Vacuumed table table=pending_objects16862026/10/24 21:46:59 INFO Vacuumed table table=multipart_uploads16872026/10/24 21:46:59 INFO Vacuumed table table=closures16882026/10/24 21:46:59 INFO Vacuumed table table=objects16892026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures16902026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures1691--- PASS: TestService_ReadScope_PublicByDefault (0.25s)1692=== CONT TestService_AuthMiddleware_MTLSBoundSubjects16932026/10/24 21:46:59 INFO Received push request method=POST path=/api/pushes16942026/10/24 21:46:59 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16952026/10/24 21:46:59 INFO Uploading j2c9w0787jnqv94524rz9f6766d1mb3n-shared-dep (136B)16962026/10/24 21:46:59 INFO Uploading hl117k88byh02l50j485jzz0n44fgwdc-a (216B)16972026/10/24 21:46:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16982026/10/24 21:46:59 INFO Uploading ll02k74zb7g8sv7symgp92a1c0vjsarh-pinned-file.txt (128B)16992026/10/24 21:46:59 WARN Failed to register uploaded object key=j2c9w0787jnqv94524rz9f6766d1mb3n.ls error="server returned 404: 404 page not found\n"1700=== NAME TestClientCADerivations1701 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1504210464/001/store/vb0cr1h4z8srz0c9r8i0waz448ghbif8-ca-test17022026/10/24 21:46:59 INFO Received push request method=POST path=/api/pushes17032026/10/24 21:46:59 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17042026/10/24 21:46:59 INFO Uploading mriv0ickz9l5fw9rkgdczy5i7l161xwy-b (208B)17052026/10/24 21:46:59 INFO Uploading hx557d868ly559y4c7d8jx865k7ij656-shared-dep (136B)1706 client_ca_test.go:139: Found 1 dependencies (including self)17072026/10/24 21:46:59 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17082026/10/24 21:46:59 WARN Failed to register uploaded object key=gkjv7aqb73x99wsvbiivc095b0nc0c9r.ls error="server returned 404: 404 page not found\n"17092026/10/24 21:46:59 WARN Failed to register uploaded object key=nar/0dskyyzgvj943gvaqds9aw0yvxkdf8anag2g9hr2x9p7dz3d902n.nar.zst error="server returned 404: 404 page not found\n"17102026/10/24 21:46:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign17112026/10/24 21:46:59 WARN Failed to register uploaded object key=hl117k88byh02l50j485jzz0n44fgwdc.ls error="server returned 404: 404 page not found\n"17122026/10/24 21:46:59 INFO Signed narinfos id=1 count=217132026/10/24 21:46:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign17142026/10/24 21:46:59 INFO Signed narinfos id=2 count=217152026/10/24 21:46:59 INFO Uploading 4 narinfos17162026/10/24 21:46:59 WARN Failed to register uploaded object key=hx557d868ly559y4c7d8jx865k7ij656.ls error="server returned 404: 404 page not found\n"17172026/10/24 21:46:59 WARN Failed to register uploaded object key=ll02k74zb7g8sv7symgp92a1c0vjsarh.ls error="server returned 404: 404 page not found\n"17182026/10/24 21:46:59 WARN Failed to register uploaded object key=mriv0ickz9l5fw9rkgdczy5i7l161xwy.ls error="server returned 404: 404 page not found\n"17192026/10/24 21:46:59 WARN Failed to register uploaded object key=lvixdv29rq61sz44w1xr64vqkkg4nill.ls error="server returned 404: 404 page not found\n"17202026/10/24 21:46:59 WARN Failed to register uploaded object key=nar/0vdd1lb1vnql5a4lbpjlwrp78fzblj6bpbp4qr6ibyc71nvyx3jq.nar.zst error="server returned 404: 404 page not found\n"17212026/10/24 21:46:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17222026/10/24 21:46:59 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17232026/10/24 21:46:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17242026/10/24 21:46:59 INFO Signed narinfos id=1 count=317252026/10/24 21:46:59 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"17262026/10/24 21:46:59 INFO Uploading 3 narinfos17272026/10/24 21:46:59 INFO Signed narinfos id=1 count=117282026/10/24 21:46:59 INFO Uploading 1 narinfos17292026/10/24 21:46:59 WARN Failed to register uploaded object key=gkjv7aqb73x99wsvbiivc095b0nc0c9r.narinfo error="server returned 404: 404 page not found\n"17302026/10/24 21:46:59 WARN Failed to register uploaded object key=j2c9w0787jnqv94524rz9f6766d1mb3n.narinfo error="server returned 404: 404 page not found\n"17312026/10/24 21:46:59 WARN Failed to register uploaded object key=hx557d868ly559y4c7d8jx865k7ij656.narinfo error="server returned 404: 404 page not found\n"17322026/10/24 21:46:59 INFO Received complete push request method=POST path=/api/pushes/1/complete17332026/10/24 21:46:59 WARN Failed to register uploaded object key=ll02k74zb7g8sv7symgp92a1c0vjsarh.narinfo error="server returned 404: 404 page not found\n"17342026/10/24 21:46:59 INFO Received complete push request method=POST path=/api/pushes/1/complete17352026/10/24 21:46:59 WARN Failed to register uploaded object key=lvixdv29rq61sz44w1xr64vqkkg4nill.narinfo error="server returned 404: 404 page not found\n"17362026/10/24 21:46:59 WARN Failed to register uploaded object key=hl117k88byh02l50j485jzz0n44fgwdc.narinfo error="server returned 404: 404 page not found\n"17372026/10/24 21:46:59 WARN Failed to register uploaded object key=mriv0ickz9l5fw9rkgdczy5i7l161xwy.narinfo error="server returned 404: 404 page not found\n"17382026/10/24 21:46:59 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17392026/10/24 21:46:59 WARN Failed to register uploaded object key=j2c9w0787jnqv94524rz9f6766d1mb3n.narinfo error="server returned 404: 404 page not found\n"1740=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1741=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1742=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1743=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1744=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1745=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1746=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1747=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1748=== CONT TestPush_CompleteCommitsEveryRoot17492026/10/24 21:46:59 INFO Completed push id=1 objects=8 duration=7.066103ms17502026/10/24 21:46:59 INFO Upload complete. (94ms)17512026/10/24 21:46:59 INFO Completed upload id=1 objects=6 duration=5.008302ms17522026/10/24 21:46:59 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete1753=== NAME TestClientPushesUseOnePush1754 client_pushes_test.go:97: Retrieved narinfo from S3:1755 StorePath: /build/TestClientPushesUseOnePush912756473/001/store/hx557d868ly559y4c7d8jx865k7ij656-shared-dep1756 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1757 Compression: zstd1758 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821759 NarSize: 1361760 References: 1761 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17622026/10/24 21:46:59 INFO Completed upload id=2 objects=6 duration=1.594961ms17632026/10/24 21:46:59 INFO Upload complete. (137ms)1764 client_pushes_test.go:97: Retrieved narinfo from S3:1765 StorePath: /build/TestClientPushesUseOnePush912756473/001/store/lvixdv29rq61sz44w1xr64vqkkg4nill-a1766 URL: nar/0vdd1lb1vnql5a4lbpjlwrp78fzblj6bpbp4qr6ibyc71nvyx3jq.nar.zst1767 Compression: zstd1768 NarHash: sha256:0vdd1lb1vnql5a4lbpjlwrp78fzblj6bpbp4qr6ibyc71nvyx3jq1769 NarSize: 2081770 References: /build/TestClientPushesUseOnePush912756473/001/store/hx557d868ly559y4c7d8jx865k7ij656-shared-dep1771 CA: text:sha256:0kb8hiv2hm8qqrzjv7a6k6d1s1jsjr9mklx9azpl6m3pc8hdswl41772=== NAME TestClientFallsBackToClosures1773 client_pushes_test.go:112: Retrieved narinfo from S3:1774 StorePath: /build/TestClientFallsBackToClosures4040621850/001/store/j2c9w0787jnqv94524rz9f6766d1mb3n-shared-dep1775 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1776 Compression: zstd1777 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821778 NarSize: 1361779 References: 1780 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n17812026/10/24 21:46:59 INFO Completed push id=1 objects=3 duration=11.189985ms17822026/10/24 21:46:59 INFO Upload complete. (130ms)1783=== NAME TestClientPushesUseOnePush1784 client_pushes_test.go:97: Retrieved narinfo from S3:1785 StorePath: /build/TestClientPushesUseOnePush912756473/001/store/mriv0ickz9l5fw9rkgdczy5i7l161xwy-b1786 URL: nar/0vdd1lb1vnql5a4lbpjlwrp78fzblj6bpbp4qr6ibyc71nvyx3jq.nar.zst1787 Compression: zstd1788 NarHash: sha256:0vdd1lb1vnql5a4lbpjlwrp78fzblj6bpbp4qr6ibyc71nvyx3jq1789 NarSize: 2081790 References: /build/TestClientPushesUseOnePush912756473/001/store/hx557d868ly559y4c7d8jx865k7ij656-shared-dep1791 CA: text:sha256:0kb8hiv2hm8qqrzjv7a6k6d1s1jsjr9mklx9azpl6m3pc8hdswl41792=== NAME TestClientFallsBackToClosures1793 client_pushes_test.go:112: Retrieved narinfo from S3:1794 StorePath: /build/TestClientFallsBackToClosures4040621850/001/store/hl117k88byh02l50j485jzz0n44fgwdc-a1795 URL: nar/0dskyyzgvj943gvaqds9aw0yvxkdf8anag2g9hr2x9p7dz3d902n.nar.zst1796 Compression: zstd1797 NarHash: sha256:0dskyyzgvj943gvaqds9aw0yvxkdf8anag2g9hr2x9p7dz3d902n1798 NarSize: 2161799 References: /build/TestClientFallsBackToClosures4040621850/001/store/j2c9w0787jnqv94524rz9f6766d1mb3n-shared-dep1800 CA: text:sha256:0chq6zsd7x9qk00bz30wb5qfp97pzvwa6mr2fns394540d208xdr1801 client_pushes_test.go:112: Retrieved narinfo from S3:1802 StorePath: /build/TestClientFallsBackToClosures4040621850/001/store/gkjv7aqb73x99wsvbiivc095b0nc0c9r-b1803 URL: nar/0dskyyzgvj943gvaqds9aw0yvxkdf8anag2g9hr2x9p7dz3d902n.nar.zst1804 Compression: zstd1805 NarHash: sha256:0dskyyzgvj943gvaqds9aw0yvxkdf8anag2g9hr2x9p7dz3d902n1806 NarSize: 2161807 References: /build/TestClientFallsBackToClosures4040621850/001/store/j2c9w0787jnqv94524rz9f6766d1mb3n-shared-dep1808 CA: text:sha256:0chq6zsd7x9qk00bz30wb5qfp97pzvwa6mr2fns394540d208xdr1809--- PASS: TestClientPushesUseOnePush (0.55s)1810=== CONT TestReadProxyHead1811--- PASS: TestClientFallsBackToClosures (0.61s)1812=== CONT TestPush_OverlappingRootsStoreOneRowPerKey18132026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures18142026/10/24 21:46:59 INFO Received uploads request method=POST path=/api/pending_closures1815--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.34s)1816=== CONT TestReadProxy40418172026/10/24 21:46:59 INFO Received push request method=POST path=/api/pushes18182026/10/24 21:46:59 INFO Received push request method=POST path=/api/pushes18192026/10/24 21:46:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18202026/10/24 21:46:59 INFO Uploading 19bkykj2nza5kkdn64g93jg32x42za29-unpinned-file.txt (128B)18212026/10/24 21:46:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18222026/10/24 21:46:59 INFO Uploading vb0cr1h4z8srz0c9r8i0waz448ghbif8-ca-test (144B)18232026/10/24 21:46:59 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"18242026/10/24 21:46:59 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign18252026/10/24 21:46:59 INFO Signed narinfos id=2 count=118262026/10/24 21:46:59 WARN Failed to register uploaded object key=19bkykj2nza5kkdn64g93jg32x42za29.ls error="server returned 404: 404 page not found\n"18272026/10/24 21:46:59 INFO Uploading 1 narinfos18282026/10/24 21:46:59 INFO Aborted multipart uploads count=0 kept=018292026/10/24 21:46:59 WARN Failed to register uploaded object key=vb0cr1h4z8srz0c9r8i0waz448ghbif8.ls error="server returned 404: 404 page not found\n"18302026/10/24 21:46:59 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"18312026/10/24 21:46:59 WARN Failed to register uploaded object key=log/njhvhs7p942vx75vshq6ll8442q439kf-ca-test.drv error="server returned 404: 404 page not found\n"18322026/10/24 21:46:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18332026/10/24 21:46:59 INFO Signed narinfos id=1 count=118342026/10/24 21:46:59 INFO Uploading 1 narinfos18352026/10/24 21:46:59 INFO Received complete push request method=POST path=/api/pushes/2/complete18362026/10/24 21:46:59 WARN Failed to register uploaded object key=19bkykj2nza5kkdn64g93jg32x42za29.narinfo error="server returned 404: 404 page not found\n"18372026/10/24 21:46:59 INFO Received complete push request method=POST path=/api/pushes/1/complete18382026/10/24 21:46:59 WARN Failed to register uploaded object key=vb0cr1h4z8srz0c9r8i0waz448ghbif8.narinfo error="server returned 404: 404 page not found\n"18392026/10/24 21:46:59 INFO Completed push id=2 objects=3 duration=3.066141ms18402026/10/24 21:46:59 INFO Upload complete. (49ms)18412026/10/24 21:46:59 WARN Force mode enabled - objects will be deleted immediately without grace period18422026/10/24 21:46:59 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=018432026/10/24 21:46:59 INFO Vacuumed table table=pending_closures18442026/10/24 21:46:59 INFO Vacuumed table table=pending_objects18452026/10/24 21:46:59 INFO Completed push id=1 objects=4 duration=6.223652ms18462026/10/24 21:46:59 INFO Upload complete. (89ms)18472026/10/24 21:46:59 INFO Vacuumed table table=multipart_uploads18482026/10/24 21:46:59 INFO Vacuumed table table=closures18492026/10/24 21:46:59 INFO Vacuumed table table=objects1850=== NAME TestClientCADerivations1851 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1504210464/001/store/vb0cr1h4z8srz0c9r8i0waz448ghbif8-ca-test1852 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1853 Compression: zstd1854 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1855 NarSize: 1441856 References: 1857 Deriver: /build/TestClientCADerivations1504210464/001/store/njhvhs7p942vx75vshq6ll8442q439kf-ca-test.drv1858 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1859 client_ca_test.go:185: Checking for realisation files in S3...1860 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1861 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1862--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.31s)1863=== CONT TestReadProxyNarStreaming1864--- PASS: TestGCMetrics (0.34s)1865=== CONT TestReadProxyInvalidPath18662026/10/24 21:46:59 INFO Aborted multipart uploads count=0 kept=018672026/10/24 21:46:59 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=018682026/10/24 21:46:59 INFO Starting cleanup of old closures method=DELETE path=/api/closures18692026/10/24 21:46:59 INFO Garbage collection started18702026/10/24 21:46:59 INFO Vacuumed table table=pending_closures18712026/10/24 21:46:59 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"1872--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.33s)1873=== CONT TestReadRedirectNar18742026/10/24 21:46:59 INFO Vacuumed table table=pending_objects18752026/10/24 21:46:59 INFO Vacuumed table table=multipart_uploads18762026/10/24 21:46:59 INFO Aborted multipart uploads count=0 kept=018772026/10/24 21:46:59 INFO lead: acquired remote=192.0.2.1:123418782026/10/24 21:46:59 INFO lead: released remote=192.0.2.1:12341879--- PASS: TestLeadIncumbentAnnouncesAtOnce (0.29s)1880=== CONT TestReadProxyRootRedirectsToIndexHTML18812026/10/24 21:46:59 INFO Vacuumed table table=closures18822026/10/24 21:46:59 WARN Force mode enabled - objects will be deleted immediately without grace period18832026/10/24 21:46:59 INFO Vacuumed table table=objects18842026/10/24 21:46:59 INFO Aborted multipart uploads count=0 kept=018852026/10/24 21:46:59 WARN Force mode enabled - objects will be deleted immediately without grace period18862026/10/24 21:46:59 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=018872026/10/24 21:46:59 INFO Vacuumed table table=pending_closures18882026/10/24 21:46:59 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=018892026/10/24 21:46:59 INFO lead: acquired remote=192.0.2.1:123418902026/10/24 21:46:59 INFO Vacuumed table table=pending_objects18912026/10/24 21:46:59 INFO Vacuumed table table=multipart_uploads18922026/10/24 21:46:59 INFO Vacuumed table table=closures18932026/10/24 21:46:59 INFO Vacuumed table table=pending_closures18942026/10/24 21:46:59 INFO Vacuumed table table=objects1895--- PASS: TestPushDedupSurvivesConcurrentGC (0.46s)1896=== CONT TestReadProxyRangeRequest18972026/10/24 21:46:59 INFO Vacuumed table table=pending_objects18982026/10/24 21:46:59 INFO Vacuumed table table=multipart_uploads18992026/10/24 21:46:59 INFO Vacuumed table table=closures19002026/10/24 21:46:59 INFO Vacuumed table table=objects1901--- PASS: TestReadProxyContentNegotiation (0.32s)1902=== CONT TestReadProxyDisabled19032026/10/24 21:46:59 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"19042026/10/24 21:46:59 WARN mTLS auth: bound subjects configured but subject DN unavailable19052026/10/24 21:46:59 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1906--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.30s)1907=== CONT TestReadRedirectKeepsNarinfoProxied1908--- PASS: TestObjectStatsLargeCommit (1.66s)1909=== CONT TestReadRedirectUsesPublicS3URL19102026/10/24 21:46:59 INFO Received push request method=POST path=/api/pushes1911--- PASS: TestReadProxyHead (0.24s)1912=== CONT TestReadProxyNarinfo19132026/10/24 21:47:00 INFO Received complete push request method=POST path=/api/pushes/1/complete1914=== NAME TestClientCADerivations1915 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1916 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1917 error: binary cache 's3://bucket60?endpoint=http://localhost:41005®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1504210464/001/store'1918 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11919--- PASS: TestClientCADerivations (0.71s)1920=== CONT TestReadProxyConditionalGet19212026/10/24 21:47:00 INFO Completed push id=1 objects=6 duration=154.672092ms1922--- PASS: TestPush_CompleteCommitsEveryRoot (0.41s)1923=== CONT TestReadProxyNarinfoAlreadyDecompressed1924--- PASS: TestGCBugBareHashReferences (0.65s)1925=== CONT TestIsValidCachePath1926=== RUN TestIsValidCachePath/narinfo1927=== PAUSE TestIsValidCachePath/narinfo1928=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1929=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1930=== RUN TestIsValidCachePath/nar_zst1931=== PAUSE TestIsValidCachePath/nar_zst1932=== RUN TestIsValidCachePath/nar_xz1933=== PAUSE TestIsValidCachePath/nar_xz1934=== RUN TestIsValidCachePath/nar_bz21935=== PAUSE TestIsValidCachePath/nar_bz21936=== RUN TestIsValidCachePath/nar_uncompressed1937=== PAUSE TestIsValidCachePath/nar_uncompressed1938=== RUN TestIsValidCachePath/ls1939=== PAUSE TestIsValidCachePath/ls1940=== RUN TestIsValidCachePath/log1941=== PAUSE TestIsValidCachePath/log1942=== RUN TestIsValidCachePath/realisation1943=== PAUSE TestIsValidCachePath/realisation1944=== RUN TestIsValidCachePath/nix-cache-info1945=== PAUSE TestIsValidCachePath/nix-cache-info1946=== RUN TestIsValidCachePath/index.html1947=== PAUSE TestIsValidCachePath/index.html1948=== RUN TestIsValidCachePath/traversal_parent1949=== PAUSE TestIsValidCachePath/traversal_parent1950=== RUN TestIsValidCachePath/traversal_in_middle1951=== PAUSE TestIsValidCachePath/traversal_in_middle1952=== RUN TestIsValidCachePath/invalid_char_e1953=== PAUSE TestIsValidCachePath/invalid_char_e1954=== RUN TestIsValidCachePath/invalid_char_u1955=== PAUSE TestIsValidCachePath/invalid_char_u1956=== RUN TestIsValidCachePath/random_path1957=== PAUSE TestIsValidCachePath/random_path1958=== RUN TestIsValidCachePath/empty1959=== PAUSE TestIsValidCachePath/empty1960=== RUN TestIsValidCachePath/leading_slash1961=== PAUSE TestIsValidCachePath/leading_slash1962=== RUN TestIsValidCachePath/wrong_extension1963=== PAUSE TestIsValidCachePath/wrong_extension1964=== RUN TestIsValidCachePath/short_hash1965=== PAUSE TestIsValidCachePath/short_hash1966=== CONT TestParseSingleRange1967=== RUN TestParseSingleRange/none1968=== PAUSE TestParseSingleRange/none1969=== RUN TestParseSingleRange/unknown_unit1970=== PAUSE TestParseSingleRange/unknown_unit1971=== RUN TestParseSingleRange/multi-range_ignored1972=== PAUSE TestParseSingleRange/multi-range_ignored1973=== RUN TestParseSingleRange/malformed_no_dash1974=== PAUSE TestParseSingleRange/malformed_no_dash1975=== RUN TestParseSingleRange/malformed_both_empty1976=== PAUSE TestParseSingleRange/malformed_both_empty1977=== RUN TestParseSingleRange/malformed_end_before_start1978=== PAUSE TestParseSingleRange/malformed_end_before_start1979=== RUN TestParseSingleRange/closed1980=== PAUSE TestParseSingleRange/closed1981=== RUN TestParseSingleRange/open-ended1982=== PAUSE TestParseSingleRange/open-ended1983=== RUN TestParseSingleRange/end_clamped_to_size1984=== PAUSE TestParseSingleRange/end_clamped_to_size1985=== RUN TestParseSingleRange/suffix1986=== PAUSE TestParseSingleRange/suffix1987=== RUN TestParseSingleRange/suffix_exceeds_size1988=== PAUSE TestParseSingleRange/suffix_exceeds_size1989=== RUN TestParseSingleRange/single_byte1990=== PAUSE TestParseSingleRange/single_byte1991=== RUN TestParseSingleRange/start_past_EOF1992=== PAUSE TestParseSingleRange/start_past_EOF1993=== RUN TestParseSingleRange/start_far_past_EOF1994=== PAUSE TestParseSingleRange/start_far_past_EOF1995=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale19962026/10/24 21:47:00 INFO Received push request method=POST path=/api/pushes1997--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.45s)1998=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1999--- PASS: TestReadProxy404 (0.41s)2000=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info20012026/10/24 21:47:00 INFO Received uploads request method=POST path=/2002=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key20032026/10/24 21:47:00 INFO Received complete multipart upload request method=POST path=/2004=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key20052026/10/24 21:47:00 INFO Received request for more parts method=POST path=/2006=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal20072026/10/24 21:47:00 INFO Received uploads request method=POST path=/2008--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)2009 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)2010 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)2011 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)2012 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)2013=== CONT TestPendingClosureWriteTimeout/empty2014=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline2015--- PASS: TestReadProxyInvalidPath (0.36s)2016=== CONT TestPendingClosureWriteTimeout/670k_objects2017=== CONT TestPendingClosureWriteTimeout/400_objects2018=== CONT TestIsValidUploadKey/narinfo2019=== CONT TestIsValidUploadKey/index.html2020=== CONT TestIsValidUploadKey/nix-cache-info2021=== CONT TestIsValidUploadKey/realisation_plus_in_output2022=== CONT TestIsValidUploadKey/realisation2023=== CONT TestIsValidUploadKey/build_log_equals2024=== CONT TestIsValidUploadKey/build_log_question_mark2025=== CONT TestIsValidUploadKey/narinfo_key,_nar_type2026=== CONT TestIsValidUploadKey/build_log_plus_in_name2027=== CONT TestIsValidUploadKey/build_log_home-manager_file2028=== CONT TestIsValidUploadKey/build_log2029=== CONT TestIsValidUploadKey/listing2030=== CONT TestIsValidUploadKey/nar_plain2031=== CONT TestIsValidUploadKey/nar_xz2032=== CONT TestIsValidUploadKey/nar_zst2033=== CONT TestIsValidUploadKey/absolute2034=== CONT TestIsValidUploadKey/unknown_type2035=== CONT TestIsValidUploadKey/empty_key2036=== CONT TestIsValidUploadKey/traversal2037=== CONT TestIsValidUploadKey/traversal_nar2038=== CONT TestIsValidUploadKey/listing_key,_narinfo_type2039=== CONT TestIsValidUploadKey/nar_key,_narinfo_type2040--- PASS: TestIsValidUploadKey (0.06s)2041 --- PASS: TestIsValidUploadKey/narinfo (0.00s)2042 --- PASS: TestIsValidUploadKey/index.html (0.00s)2043 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)2044 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)2045 --- PASS: TestIsValidUploadKey/realisation (0.00s)2046 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)2047 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)2048 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)2049 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)2050 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)2051 --- PASS: TestIsValidUploadKey/build_log (0.00s)2052 --- PASS: TestIsValidUploadKey/listing (0.00s)2053 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)2054 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)2055 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)2056 --- PASS: TestIsValidUploadKey/absolute (0.00s)2057 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)2058 --- PASS: TestIsValidUploadKey/empty_key (0.00s)2059 --- PASS: TestIsValidUploadKey/traversal (0.00s)2060 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)2061 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)2062 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)2063=== CONT TestProxyWriteTimeout/narinfo2064=== CONT TestProxyWriteTimeout/unknown_size2065=== CONT TestProxyWriteTimeout/10_GiB_nar2066=== CONT TestProxyWriteTimeout/1_GiB_nar2067--- PASS: TestProxyWriteTimeout (0.06s)2068 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2069 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2070 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)2071 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2072=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure20732026/10/24 21:47:00 INFO Received uploads request method=POST path=/2074--- PASS: TestReadProxyNarStreaming (0.40s)2075=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart20762026/10/24 21:47:00 INFO Received complete multipart upload request method=POST path=/2077--- PASS: TestReadRedirectNar (0.39s)2078=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts20792026/10/24 21:47:00 INFO Received request for more parts method=POST path=/2080=== CONT TestNativeOIDCLoginPushRefresh/new-id-token2081--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.39s)2082=== CONT TestNativeOIDCLoginPushRefresh/omitted-id-token20832026/10/24 21:47:00 INFO OIDC provider initialized name=native issuer=http://127.0.0.1:443392084--- PASS: TestReadProxyRangeRequest (0.39s)2085=== CONT TestGCEndsOnShutdown/before_the_run2086=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark2087--- PASS: TestReadRedirectKeepsNarinfoProxied (0.36s)2088=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete2089--- PASS: TestReadProxyDisabled (0.38s)2090=== CONT TestServerTLSConfig/no_client_CA2091=== CONT TestServerTLSConfig/not_a_PEM_file2092=== CONT TestServerTLSConfig/missing_CA_file2093--- PASS: TestServerTLSConfig (0.00s)2094 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)2095 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)2096 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)2097=== CONT TestPush_RejectsBadRequests/root_not_in_objects20982026/10/24 21:47:00 INFO Received push request method=POST path=/api/pushes2099=== CONT TestPush_RejectsBadRequests/no_objects21002026/10/24 21:47:00 INFO Received push request method=POST path=/api/pushes2101=== CONT TestPush_RejectsBadRequests/bad_root21022026/10/24 21:47:00 INFO Received push request method=POST path=/api/pushes2103=== CONT TestPush_RejectsBadRequests/no_roots21042026/10/24 21:47:00 INFO Received push request method=POST path=/api/pushes2105=== CONT TestClientErrorHandling/InvalidStorePath2106--- PASS: TestPush_RejectsBadRequests (0.91s)2107 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)2108 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)2109 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)2110 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)21112026/10/24 21:47:00 INFO OIDC provider initialized name=native issuer=http://127.0.0.1:343932112--- PASS: TestReadRedirectUsesPublicS3URL (0.39s)2113=== CONT TestClientErrorHandling/ServerNotAvailable2114--- PASS: TestReadProxyConditionalGet (0.33s)2115=== CONT TestClientErrorHandling/InvalidAuthToken2116--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.26s)2117=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows21182026/10/24 21:47:00 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/present21192026/10/24 21:47:00 INFO Received uploads request method=POST path=/api/pending_closures21202026/10/24 21:47:00 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>2121--- PASS: TestReadProxyNarinfo (0.46s)2122=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check21232026-10-24 21:47:00.472 UTC [212] LOG: checkpoints are occurring too frequently (8 seconds apart)21242026-10-24 21:47:00.472 UTC [212] HINT: Consider increasing the configuration parameter "max_wal_size".21252026-10-24 21:47:00.472 UTC [212] LOG: checkpoint starting: wal2126--- PASS: TestDeleteClosuresRacingPins (1.30s)2127=== CONT TestCacheConfigHandler/full_config,_no_issuer2128=== CONT TestCacheConfigHandler/no_signing_keys2129=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2130=== CONT TestCacheConfigHandler/no_cache_url_configured2131--- PASS: TestCacheConfigHandler (0.00s)2132 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2133 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2134 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2135 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2136=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2137=== CONT TestService_RequireScope_OIDC/builder_may_write2138=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2139=== CONT TestService_RequireScope_OIDC/writer_implies_read2140=== CONT TestService_RequireScope_OIDC/reader_may_read2141=== CONT TestService_RequireScope_OIDC/static_token_may_write2142=== CONT TestService_RequireScope_OIDC/static_token_may_admin2143=== CONT TestService_RequireScope_OIDC/reader_may_not_write2144=== CONT TestService_RequireScope_OIDC/ops_may_not_write2145=== CONT TestService_RequireScope_OIDC/ops_may_admin2146=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2147=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read21482026/10/24 21:47:00 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]2149=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2150=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2151=== CONT TestResolveDBConnectionString/flag_wins2152=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2153=== CONT TestResolveDBConnectionString/nothing_configured2154=== CONT TestResolveDBConnectionString/missing_file_is_an_error2155=== CONT TestResolveDBConnectionString/file_when_flag_empty2156=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2157--- PASS: TestService_RequireScope_OIDC (0.33s)2158 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2159 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2160 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2161 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2162 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2163 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2164 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2165 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2166 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2167 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2168 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2169 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2170 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2171 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2172--- PASS: TestResolveDBConnectionString (0.00s)2173 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2174 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2175 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2176 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2177 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2178=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21792026/10/24 21:47:00 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]2180=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2181=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected21822026/10/24 21:47:00 WARN Authentication failed token_preview=eyJhbGciOi...DqDSKmHqIQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2183=== CONT TestIsValidCachePath/narinfo2184=== CONT TestIsValidCachePath/index.html2185=== CONT TestIsValidCachePath/short_hash2186=== CONT TestIsValidCachePath/wrong_extension2187=== CONT TestIsValidCachePath/leading_slash2188=== CONT TestIsValidCachePath/empty2189=== CONT TestIsValidCachePath/random_path2190=== CONT TestIsValidCachePath/invalid_char_u2191=== CONT TestIsValidCachePath/invalid_char_e2192=== CONT TestIsValidCachePath/traversal_in_middle2193=== CONT TestIsValidCachePath/traversal_parent2194=== CONT TestIsValidCachePath/nar_uncompressed2195=== CONT TestIsValidCachePath/nix-cache-info2196=== CONT TestIsValidCachePath/realisation2197=== CONT TestIsValidCachePath/log2198=== CONT TestIsValidCachePath/ls2199=== CONT TestIsValidCachePath/nar_xz2200=== CONT TestIsValidCachePath/nar_bz22201=== CONT TestIsValidCachePath/nar_zst2202=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2203=== CONT TestParseSingleRange/none2204=== CONT TestParseSingleRange/malformed_both_empty2205=== CONT TestParseSingleRange/closed2206--- PASS: TestIsValidCachePath (0.00s)2207 --- PASS: TestIsValidCachePath/narinfo (0.00s)2208 --- PASS: TestIsValidCachePath/index.html (0.00s)2209 --- PASS: TestIsValidCachePath/short_hash (0.00s)2210 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2211 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2212 --- PASS: TestIsValidCachePath/empty (0.00s)2213 --- PASS: TestIsValidCachePath/random_path (0.00s)2214 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2215 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2216 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2217 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2218 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2219 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2220 --- PASS: TestIsValidCachePath/realisation (0.00s)2221 --- PASS: TestIsValidCachePath/log (0.00s)2222 --- PASS: TestIsValidCachePath/ls (0.00s)2223 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2224 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2225 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2226 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2227--- PASS: TestService_AuthMiddleware_OIDC (0.39s)2228 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2229 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2230 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2231 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2232=== CONT TestParseSingleRange/malformed_end_before_start2233=== CONT TestParseSingleRange/multi-range_ignored2234=== CONT TestParseSingleRange/malformed_no_dash2235=== CONT TestParseSingleRange/unknown_unit2236=== CONT TestParseSingleRange/single_byte2237=== CONT TestParseSingleRange/start_far_past_EOF2238=== CONT TestParseSingleRange/start_past_EOF2239=== CONT TestParseSingleRange/suffix2240=== CONT TestParseSingleRange/suffix_exceeds_size2241=== CONT TestParseSingleRange/open-ended2242=== CONT TestParseSingleRange/end_clamped_to_size2243--- PASS: TestParseSingleRange (0.00s)2244 --- PASS: TestParseSingleRange/none (0.00s)2245 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)2246 --- PASS: TestParseSingleRange/closed (0.00s)2247 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)2248 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)2249 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)2250 --- PASS: TestParseSingleRange/unknown_unit (0.00s)2251 --- PASS: TestParseSingleRange/single_byte (0.00s)2252 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)2253 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)2254 --- PASS: TestParseSingleRange/suffix (0.00s)2255 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)2256 --- PASS: TestParseSingleRange/open-ended (0.00s)2257 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)22582026/10/24 21:47:00 INFO Aborted multipart uploads count=0 kept=022592026/10/24 21:47:00 WARN Force mode enabled - objects will be deleted immediately without grace period22602026/10/24 21:47:00 WARN Request failed, retrying attempt=2 backoff=197.593153ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22612026/10/24 21:47:00 INFO Aborted multipart uploads count=0 kept=022622026/10/24 21:47:00 WARN Force mode enabled - objects will be deleted immediately without grace period22632026/10/24 21:47:00 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:41005/bucket97/?delete=\": context canceled"2264--- PASS: TestGCEndsOnShutdown (0.00s)2265 --- PASS: TestGCEndsOnShutdown/before_the_run (0.21s)2266 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.24s)2267 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.24s)22682026/10/24 21:47:00 INFO Received uploads request method=POST path=/api/pending_closures22692026/10/24 21:47:00 INFO Aborted multipart uploads count=0 kept=022702026/10/24 21:47:00 WARN Force mode enabled - objects will be deleted immediately without grace period22712026/10/24 21:47:00 INFO Received uploads request method=POST path=/api/pending_closures22722026/10/24 21:47:00 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=022732026/10/24 21:47:00 INFO Vacuumed table table=pending_closures22742026/10/24 21:47:00 INFO Vacuumed table table=pending_objects22752026/10/24 21:47:00 INFO Vacuumed table table=multipart_uploads22762026/10/24 21:47:00 INFO Vacuumed table table=closures22772026/10/24 21:47:00 INFO Vacuumed table table=objects22782026/10/24 21:47:00 INFO Aborted multipart uploads count=0 kept=022792026/10/24 21:47:00 WARN Force mode enabled - objects will be deleted immediately without grace period22802026/10/24 21:47:00 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=022812026/10/24 21:47:00 INFO Vacuumed table table=pending_closures22822026/10/24 21:47:00 INFO Vacuumed table table=pending_objects22832026/10/24 21:47:00 INFO Vacuumed table table=multipart_uploads22842026/10/24 21:47:00 INFO Vacuumed table table=closures22852026/10/24 21:47:00 INFO Vacuumed table table=objects2286--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2287 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.21s)2288 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.17s)22892026/10/24 21:47:00 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22902026/10/24 21:47:00 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22912026/10/24 21:47:00 INFO lead: released remote=192.0.2.1:12342292--- PASS: TestLeadEndsOnShutdown (1.28s)2293=== NAME TestOrphanedObjectsGCStressTest2294 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2295 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion22962026/10/24 21:47:00 WARN Request failed, retrying attempt=3 backoff=385.321974ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2297--- PASS: TestUploadHandlersRejectOversizedBody (0.16s)2298 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)2299 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.05s)2300 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.60s)2301=== NAME TestOrphanedObjectsGCStressTest2302 orphaned_objects_gc_test.go:503: Stress test completed successfully:2303 orphaned_objects_gc_test.go:504: - Active objects preserved: 202304 orphaned_objects_gc_test.go:505: - Objects deleted: 2102305 orphaned_objects_gc_test.go:506: - Total GC'd: 2102306--- PASS: TestOrphanedObjectsGCStressTest (2.86s)2307--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2308 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (0.77s)2309 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (0.77s)23102026/10/24 21:47:01 INFO lead: released remote=192.0.2.1:123423112026/10/24 21:47:01 WARN Request failed, retrying attempt=4 backoff=777.701459ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present23122026/10/24 21:47:01 INFO lead: acquired remote=192.0.2.1:12342313--- PASS: TestPendingClosureWriteTimeout (0.06s)2314 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2315 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2316 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2317 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.05s)23182026/10/24 21:47:01 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02319=== NAME TestClientIntegration2320 client_integration_test.go:323: Objects in database after GC:2321 client_integration_test.go:323: Successfully deleted all objects with GC --force23222026/10/24 21:47:01 INFO Received push request method=POST path=/api/pushes23232026/10/24 21:47:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23242026/10/24 21:47:01 INFO Uploading 8yl9x72qx5v5mn4qz7pw0b1z8w8q72jr-native-oidc-0 (128B)2325--- PASS: TestClientIntegration (2.47s)23262026/10/24 21:47:01 WARN Failed to register uploaded object key=8yl9x72qx5v5mn4qz7pw0b1z8w8q72jr.ls error="server returned 404: 404 page not found\n"23272026/10/24 21:47:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23282026/10/24 21:47:01 INFO Signed narinfos id=1 count=123292026/10/24 21:47:01 INFO Uploading 1 narinfos23302026/10/24 21:47:01 INFO Received complete push request method=POST path=/api/pushes/1/complete23312026/10/24 21:47:01 INFO Completed push id=1 objects=3 duration=3.038171ms23322026/10/24 21:47:01 INFO Upload complete. (56ms)23332026/10/24 21:47:01 WARN Failed to register uploaded object key=nar/0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq.nar.zst error="server returned 404: 404 page not found\n"23342026/10/24 21:47:01 INFO Received push request method=POST path=/api/pushes23352026/10/24 21:47:01 WARN Failed to register uploaded object key=8yl9x72qx5v5mn4qz7pw0b1z8w8q72jr.narinfo error="server returned 404: 404 page not found\n"23362026/10/24 21:47:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23372026/10/24 21:47:01 INFO Uploading 79gammr7swzsw9zwmr98ynk92y3rfzk8-native-oidc-0 (128B)2338=== NAME TestNativeOIDCLoginPushRefresh/new-id-token2339 native_oidc_linux_test.go:139: Retrieved narinfo from S3:2340 StorePath: /build/TestNativeOIDCLoginPushRefreshnew-id-token1298359946/004/store/8yl9x72qx5v5mn4qz7pw0b1z8w8q72jr-native-oidc-02341 URL: nar/0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq.nar.zst2342 Compression: zstd2343 NarHash: sha256:0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq2344 NarSize: 1282345 References: 2346 CA: text:sha256:0wy0p28czvzd72v0sn9wi5v6vzg0w28gil36xf4di45srvg5vf0p23472026/10/24 21:47:01 WARN Failed to register uploaded object key=79gammr7swzsw9zwmr98ynk92y3rfzk8.ls error="server returned 404: 404 page not found\n"23482026/10/24 21:47:01 WARN Failed to register uploaded object key=nar/0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq.nar.zst error="server returned 404: 404 page not found\n"23492026/10/24 21:47:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign23502026/10/24 21:47:01 INFO Signed narinfos id=1 count=123512026/10/24 21:47:01 INFO Uploading 1 narinfos23522026/10/24 21:47:01 INFO Received complete push request method=POST path=/api/pushes/1/complete23532026/10/24 21:47:01 INFO Completed push id=1 objects=3 duration=3.215332ms23542026/10/24 21:47:01 INFO Upload complete. (106ms)23552026/10/24 21:47:01 INFO Received push request method=POST path=/api/pushes23562026/10/24 21:47:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23572026/10/24 21:47:01 INFO Uploading 7q2y4n8ca1vnmk776vn0nw0s24a9qmr7-native-oidc-1 (128B)23582026/10/24 21:47:01 WARN Failed to register uploaded object key=nar/0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg6.nar.zst error="server returned 404: 404 page not found\n"23592026/10/24 21:47:01 WARN Failed to register uploaded object key=79gammr7swzsw9zwmr98ynk92y3rfzk8.narinfo error="server returned 404: 404 page not found\n"2360=== NAME TestNativeOIDCLoginPushRefresh/omitted-id-token2361 native_oidc_linux_test.go:139: Retrieved narinfo from S3:2362 StorePath: /build/TestNativeOIDCLoginPushRefreshomitted-id-token2996782928/004/store/79gammr7swzsw9zwmr98ynk92y3rfzk8-native-oidc-02363 URL: nar/0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq.nar.zst2364 Compression: zstd2365 NarHash: sha256:0l8i3aj18dwl94z5nyf0rgfd3b4m7nm8xphi78vzi09r1m9763wq2366 NarSize: 1282367 References: 2368 CA: text:sha256:0wy0p28czvzd72v0sn9wi5v6vzg0w28gil36xf4di45srvg5vf0p23692026/10/24 21:47:01 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign23702026/10/24 21:47:01 INFO Signed narinfos id=2 count=123712026/10/24 21:47:01 INFO Uploading 1 narinfos23722026/10/24 21:47:01 INFO Received complete push request method=POST path=/api/pushes/2/complete23732026/10/24 21:47:01 INFO Completed push id=2 objects=3 duration=1.339481ms23742026/10/24 21:47:01 INFO Upload complete. (103ms)23752026/10/24 21:47:01 INFO Received push request method=POST path=/api/pushes23762026/10/24 21:47:01 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)23772026/10/24 21:47:01 INFO Uploading jsv3zbcdwjm7a5j848jrnvivyjkll49n-native-oidc-1 (128B)23782026/10/24 21:47:01 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=023792026/10/24 21:47:01 INFO Received create pin request method=POST path=/api/pins/myapp23802026/10/24 21:47:01 WARN Failed to register uploaded object key=jsv3zbcdwjm7a5j848jrnvivyjkll49n.ls error="server returned 404: 404 page not found\n"23812026/10/24 21:47:01 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1960108011/001/store/ll02k74zb7g8sv7symgp92a1c0vjsarh-pinned-file.txt narinfo_key=ll02k74zb7g8sv7symgp92a1c0vjsarh.narinfo23822026/10/24 21:47:01 INFO Starting cleanup of old closures method=DELETE path=/api/closures23832026/10/24 21:47:01 INFO Garbage collection started23842026/10/24 21:47:01 INFO Aborted multipart uploads count=0 kept=023852026/10/24 21:47:01 WARN Failed to register uploaded object key=7q2y4n8ca1vnmk776vn0nw0s24a9qmr7.ls error="server returned 404: 404 page not found\n"23862026/10/24 21:47:01 WARN Force mode enabled - objects will be deleted immediately without grace period23872026/10/24 21:47:01 WARN Failed to register uploaded object key=7q2y4n8ca1vnmk776vn0nw0s24a9qmr7.narinfo error="server returned 404: 404 page not found\n"23882026/10/24 21:47:01 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=023892026/10/24 21:47:01 INFO Vacuumed table table=pending_closures2390=== NAME TestNativeOIDCLoginPushRefresh/new-id-token23912026/10/24 21:47:01 INFO Vacuumed table table=pending_objects2392 native_oidc_linux_test.go:139: Retrieved narinfo from S3:2393 StorePath: /build/TestNativeOIDCLoginPushRefreshnew-id-token1298359946/004/store/7q2y4n8ca1vnmk776vn0nw0s24a9qmr7-native-oidc-12394 URL: nar/0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg6.nar.zst2395 Compression: zstd2396 NarHash: sha256:0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg62397 NarSize: 1282398 References: 2399 CA: text:sha256:0z7d88w8ivn9jiskv6fpsiikfgkan67r4qp4isjd1g0w9anr0xrd24002026/10/24 21:47:01 INFO Vacuumed table table=multipart_uploads24012026/10/24 21:47:01 INFO Vacuumed table table=closures24022026/10/24 21:47:01 INFO Vacuumed table table=objects24032026/10/24 21:47:01 WARN Request failed, retrying attempt=5 backoff=1.665677474s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present24042026/10/24 21:47:01 WARN Failed to register uploaded object key=nar/0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg6.nar.zst error="server returned 404: 404 page not found\n"24052026/10/24 21:47:01 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign24062026/10/24 21:47:01 INFO Signed narinfos id=2 count=124072026/10/24 21:47:01 INFO Uploading 1 narinfos24082026/10/24 21:47:01 INFO Received complete push request method=POST path=/api/pushes/2/complete24092026/10/24 21:47:01 INFO Completed push id=2 objects=3 duration=1.19008ms24102026/10/24 21:47:01 INFO Upload complete. (144ms)24112026/10/24 21:47:02 WARN Failed to register uploaded object key=jsv3zbcdwjm7a5j848jrnvivyjkll49n.narinfo error="server returned 404: 404 page not found\n"2412=== NAME TestNativeOIDCLoginPushRefresh/omitted-id-token2413 native_oidc_linux_test.go:139: Retrieved narinfo from S3:2414 StorePath: /build/TestNativeOIDCLoginPushRefreshomitted-id-token2996782928/004/store/jsv3zbcdwjm7a5j848jrnvivyjkll49n-native-oidc-12415 URL: nar/0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg6.nar.zst2416 Compression: zstd2417 NarHash: sha256:0i1rbc6xsac0fnqg64jaqdsa839xl8qsr0b6a9bqpsvh20r94vg62418 NarSize: 1282419 References: 2420 CA: text:sha256:0z7d88w8ivn9jiskv6fpsiikfgkan67r4qp4isjd1g0w9anr0xrd2421--- PASS: TestNativeOIDCLoginPushRefresh (0.00s)2422 --- PASS: TestNativeOIDCLoginPushRefresh/new-id-token (1.61s)2423 --- PASS: TestNativeOIDCLoginPushRefresh/omitted-id-token (1.76s)24242026/10/24 21:47:02 INFO lead: released remote=192.0.2.1:12342425--- PASS: TestLeadElectsOneAndHandsOver (2.63s)24262026/10/24 21:47:02 WARN Rate limiter enabled after throttle name=s3-test rate=524272026/10/24 21:47:02 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2428=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2429 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102430 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002431--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.99s)24322026/10/24 21:47:03 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-config24332026/10/24 21:47:03 WARN Request failed, retrying attempt=2 backoff=199.909741ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2434=== NAME TestPinProtectsFromGC2435 client_integration_test.go:840: Pin successfully protected closure from garbage collection2436--- PASS: TestPinProtectsFromGC (4.71s)24372026/10/24 21:47:03 WARN Request failed, retrying attempt=3 backoff=424.13213ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2438--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.52s)24392026/10/24 21:47:04 WARN Request failed, retrying attempt=4 backoff=814.440076ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2440--- PASS: TestConnectWaitsForAPeerMigration (5.17s)24412026/10/24 21:47:05 INFO Aborted multipart uploads count=1 kept=024422026/10/24 21:47:05 INFO Received cleanup request method=DELETE path=/api/pending_closures24432026/10/24 21:47:05 INFO Aborted multipart uploads count=1 kept=02444--- PASS: TestPendingCleanupUsesOneCutoff (6.66s)24452026/10/24 21:47:05 WARN Request failed, retrying attempt=5 backoff=1.626697333s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24462026/10/24 21:47:06 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"24472026/10/24 21:47:06 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-config24482026/10/24 21:47:06 WARN Request failed, retrying attempt=2 backoff=195.71861ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24492026/10/24 21:47:07 WARN Request failed, retrying attempt=3 backoff=360.196532ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24502026/10/24 21:47:07 WARN Request failed, retrying attempt=4 backoff=851.568776ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24512026/10/24 21:47:08 WARN Request failed, retrying attempt=5 backoff=1.562128262s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config24522026/10/24 21:47:09 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_closures24532026/10/24 21:47:09 WARN Request failed, retrying attempt=2 backoff=189.052434ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24542026/10/24 21:47:10 WARN Request failed, retrying attempt=3 backoff=403.348583ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24552026/10/24 21:47:10 WARN Request failed, retrying attempt=4 backoff=721.61496ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures24562026/10/24 21:47:11 WARN Request failed, retrying attempt=5 backoff=1.57839711s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2457--- PASS: TestClientErrorHandling (0.00s)2458 --- PASS: TestClientErrorHandling/InvalidStorePath (0.26s)2459 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.31s)2460 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.49s)2461PASS24622026-10-24 21:47:13.114 UTC [207] LOG: received smart shutdown request24632026-10-24 21:47:13.118 UTC [207] LOG: background worker "logical replication launcher" (PID 217) exited with exit code 124642026-10-24 21:47:14.695 UTC [212] LOG: checkpoint complete: wrote 10016 buffers (61.1%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=12.833 s, sync=1.328 s, total=14.224 s; sync files=34717, longest=0.027 s, average=0.001 s; distance=533630 kB, estimate=533630 kB; lsn=0/228718B0, redo lsn=0/2208562824652026-10-24 21:47:14.698 UTC [212] LOG: shutting down24662026-10-24 21:47:14.698 UTC [212] LOG: checkpoint starting: shutdown immediate24672026-10-24 21:47:14.855 UTC [212] LOG: checkpoint complete: wrote 1165 buffers (7.1%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.021 s, sync=0.133 s, total=0.158 s; sync files=428, longest=0.012 s, average=0.001 s; distance=8112 kB, estimate=481078 kB; lsn=0/22871928, redo lsn=0/2287192824682026-10-24 21:47:14.943 UTC [207] LOG: database system is shut down2469Running OIDC tests...2470=== RUN TestAudienceForIssuer2471=== PAUSE TestAudienceForIssuer2472=== RUN TestGlobMatch2473=== PAUSE TestGlobMatch2474=== RUN TestValidateToken_ValidToken2475=== PAUSE TestValidateToken_ValidToken2476=== RUN TestValidateToken_WrongAudience2477=== PAUSE TestValidateToken_WrongAudience2478=== RUN TestValidateToken_Expired2479=== PAUSE TestValidateToken_Expired2480=== RUN TestValidateToken_BoundClaimsMismatch2481=== PAUSE TestValidateToken_BoundClaimsMismatch2482=== RUN TestValidateToken_BoundSubjectMismatch2483=== PAUSE TestValidateToken_BoundSubjectMismatch2484=== RUN TestValidateToken_MultipleProviders2485=== PAUSE TestValidateToken_MultipleProviders2486=== RUN TestValidateToken_NoMatchingProvider2487=== PAUSE TestValidateToken_NoMatchingProvider2488=== RUN TestValidateToken_KubernetesServiceAccount2489=== PAUSE TestValidateToken_KubernetesServiceAccount2490=== RUN TestNewValidator_KubernetesRequiresCA2491=== PAUSE TestNewValidator_KubernetesRequiresCA2492=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2493=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2494=== RUN TestPins_ReservedForMatchingRule2495=== PAUSE TestPins_ReservedForMatchingRule2496=== RUN TestPins_TopLevelShorthand2497=== PAUSE TestPins_TopLevelShorthand2498=== RUN TestPins_ConfigValidation2499=== PAUSE TestPins_ConfigValidation2500=== RUN TestScopes_LegacyProviderDefaultsToWrite2501=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2502=== RUN TestScopes_Rules2503=== PAUSE TestScopes_Rules2504=== RUN TestScopes_ConfigValidation2505=== PAUSE TestScopes_ConfigValidation2506=== CONT TestAudienceForIssuer2507=== CONT TestValidateToken_KubernetesServiceAccount2508--- PASS: TestAudienceForIssuer (0.00s)2509=== CONT TestValidateToken_Expired2510=== CONT TestValidateToken_WrongAudience2511=== CONT TestValidateToken_ValidToken2512=== CONT TestValidateToken_BoundClaimsMismatch2513=== CONT TestValidateToken_NoMatchingProvider2514=== CONT TestGlobMatch2515=== CONT TestValidateToken_MultipleProviders2516=== CONT TestScopes_Rules2517=== CONT TestValidateToken_BoundSubjectMismatch2518=== CONT TestPins_ReservedForMatchingRule2519=== CONT TestScopes_ConfigValidation2520=== CONT TestPins_TopLevelShorthand2521=== CONT TestScopes_LegacyProviderDefaultsToWrite2522=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2523=== CONT TestNewValidator_KubernetesRequiresCA2524=== CONT TestPins_ConfigValidation2525=== RUN TestGlobMatch/foo_foo2526=== PAUSE TestGlobMatch/foo_foo2527=== RUN TestGlobMatch/foo_bar2528=== PAUSE TestGlobMatch/foo_bar2529--- PASS: TestScopes_ConfigValidation (0.00s)2530=== RUN TestGlobMatch/*_2531=== PAUSE TestGlobMatch/*_2532=== RUN TestGlobMatch/*_anything2533=== PAUSE TestGlobMatch/*_anything2534=== RUN TestGlobMatch/foo*_foo2535=== PAUSE TestGlobMatch/foo*_foo2536=== RUN TestGlobMatch/foo*_foobar2537=== PAUSE TestGlobMatch/foo*_foobar2538=== RUN TestGlobMatch/foo*_bar2539=== PAUSE TestGlobMatch/foo*_bar2540=== RUN TestGlobMatch/*bar_bar2541=== PAUSE TestGlobMatch/*bar_bar2542=== RUN TestGlobMatch/*bar_foobar2543=== PAUSE TestGlobMatch/*bar_foobar2544=== RUN TestGlobMatch/*bar_foo2545=== PAUSE TestGlobMatch/*bar_foo2546=== RUN TestGlobMatch/foo*bar_foobar2547=== PAUSE TestGlobMatch/foo*bar_foobar2548=== RUN TestGlobMatch/foo*bar_foo123bar2549=== PAUSE TestGlobMatch/foo*bar_foo123bar2550=== RUN TestGlobMatch/foo*bar_foobarbaz2551=== PAUSE TestGlobMatch/foo*bar_foobarbaz2552=== RUN TestGlobMatch/*/*_foo/bar2553=== PAUSE TestGlobMatch/*/*_foo/bar2554=== RUN TestGlobMatch/*/*_foo2555=== PAUSE TestGlobMatch/*/*_foo2556=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2557=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2558=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02559=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02560=== RUN TestGlobMatch/refs/*/main_refs/heads/main2561=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2562=== RUN TestGlobMatch/fo?_foo2563=== PAUSE TestGlobMatch/fo?_foo2564=== RUN TestGlobMatch/fo?_fo2565=== PAUSE TestGlobMatch/fo?_fo2566=== RUN TestGlobMatch/fo?_fooo2567=== PAUSE TestGlobMatch/fo?_fooo2568=== RUN TestGlobMatch/?oo_foo2569=== PAUSE TestGlobMatch/?oo_foo2570=== RUN TestGlobMatch/?oo_boo2571=== PAUSE TestGlobMatch/?oo_boo2572=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2573=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2574=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2575=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2576=== CONT TestGlobMatch/foo_foo2577=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2578=== CONT TestGlobMatch/foo*bar_foo123bar2579=== CONT TestGlobMatch/foo*bar_foobar2580=== CONT TestGlobMatch/*bar_foo2581=== CONT TestGlobMatch/foo*bar_foobarbaz2582=== CONT TestGlobMatch/*bar_bar2583=== CONT TestGlobMatch/foo*_bar2584=== CONT TestGlobMatch/foo*_foobar2585=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2586=== CONT TestGlobMatch/*_anything2587=== CONT TestGlobMatch/*_2588=== CONT TestGlobMatch/foo_bar2589=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2590=== CONT TestGlobMatch/*/*_foo2591=== CONT TestGlobMatch/fo?_foo2592=== CONT TestGlobMatch/refs/*/main_refs/heads/main2593=== CONT TestGlobMatch/?oo_boo2594=== CONT TestGlobMatch/?oo_foo2595=== CONT TestGlobMatch/fo?_fooo2596=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02597=== CONT TestGlobMatch/*/*_foo/bar2598=== CONT TestGlobMatch/*bar_foobar2599=== CONT TestGlobMatch/foo*_foo2600=== CONT TestGlobMatch/fo?_fo2601--- PASS: TestGlobMatch (0.00s)2602 --- PASS: TestGlobMatch/foo_foo (0.00s)2603 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2604 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2605 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2606 --- PASS: TestGlobMatch/*bar_foo (0.00s)2607 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2608 --- PASS: TestGlobMatch/*bar_bar (0.00s)2609 --- PASS: TestGlobMatch/foo*_bar (0.00s)2610 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2611 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2612 --- PASS: TestGlobMatch/*_anything (0.00s)2613 --- PASS: TestGlobMatch/*_ (0.00s)2614 --- PASS: TestGlobMatch/foo_bar (0.00s)2615 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2616 --- PASS: TestGlobMatch/*/*_foo (0.00s)2617 --- PASS: TestGlobMatch/fo?_foo (0.00s)2618 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2619 --- PASS: TestGlobMatch/?oo_boo (0.00s)2620 --- PASS: TestGlobMatch/?oo_foo (0.00s)2621 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2622 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2623 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2624 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2625 --- PASS: TestGlobMatch/foo*_foo (0.00s)2626 --- PASS: TestGlobMatch/fo?_fo (0.00s)2627--- PASS: TestPins_ConfigValidation (0.00s)26282026/10/24 21:47:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38109/oidc2629--- PASS: TestValidateToken_ValidToken (0.03s)26302026/10/24 21:47:16 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12326312026/10/24 21:47:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43977/oidc2632--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.05s)2633--- PASS: TestValidateToken_BoundClaimsMismatch (0.06s)26342026/10/24 21:47:16 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:3714926352026/10/24 21:47:16 http: TLS handshake error from 127.0.0.1:35446: remote error: tls: bad certificate2636--- PASS: TestNewValidator_KubernetesRequiresCA (0.06s)26372026/10/24 21:47:16 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:45557/oidc2638--- PASS: TestValidateToken_KubernetesServiceAccount (0.07s)26392026/10/24 21:47:16 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:43645/oidc26402026/10/24 21:47:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45295/oidc2641--- PASS: TestValidateToken_MultipleProviders (0.07s)2642--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.07s)26432026/10/24 21:47:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36583/oidc2644--- PASS: TestValidateToken_BoundSubjectMismatch (0.07s)26452026/10/24 21:47:16 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39687/oidc2646--- PASS: TestValidateToken_NoMatchingProvider (0.11s)26472026/10/24 21:47:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34673/oidc2648--- PASS: TestPins_ReservedForMatchingRule (0.13s)26492026/10/24 21:47:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39989/oidc2650--- PASS: TestValidateToken_WrongAudience (0.15s)26512026/10/24 21:47:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38493/oidc2652--- PASS: TestValidateToken_Expired (0.16s)26532026/10/24 21:47:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37483/oidc2654--- PASS: TestPins_TopLevelShorthand (0.17s)26552026/10/24 21:47:16 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35871/oidc2656--- PASS: TestScopes_Rules (0.21s)2657PASS2658Running hook tests...2659=== RUN TestSendPathsEmpty2660=== PAUSE TestSendPathsEmpty2661=== RUN TestQueueEnqueueAndFetch2662=== PAUSE TestQueueEnqueueAndFetch2663=== RUN TestQueueDeduplication2664=== PAUSE TestQueueDeduplication2665=== RUN TestQueueRemove2666=== PAUSE TestQueueRemove2667=== RUN TestQueueFetchBatchLimit2668=== PAUSE TestQueueFetchBatchLimit2669=== RUN TestQueueRetryMovesToBack2670=== PAUSE TestQueueRetryMovesToBack2671=== RUN TestQueueFetchRemoveLifecycle2672=== PAUSE TestQueueFetchRemoveLifecycle2673=== RUN TestQueueConcurrentWriters2674=== PAUSE TestQueueConcurrentWriters2675=== RUN TestQueueRemoveLargeClosure2676=== PAUSE TestQueueRemoveLargeClosure2677=== RUN TestServerClientIntegration2678--- PASS: TestServerClientIntegration (0.00s)2679=== RUN TestServerQueueError26802026/10/24 21:47:16 ERROR Failed to queue paths error="permission denied" count=12681--- PASS: TestServerQueueError (0.00s)2682=== RUN TestGetListenerSocketActivation2683 server_test.go:219: === RUN TestGetListenerSocketActivation2684 --- PASS: TestGetListenerSocketActivation (0.00s)2685 PASS2686 2687--- PASS: TestGetListenerSocketActivation (0.01s)2688=== RUN TestDrainIsolatesPoisonPath2689=== PAUSE TestDrainIsolatesPoisonPath2690=== RUN TestRunNotBlockedByPoisonHead2691=== PAUSE TestRunNotBlockedByPoisonHead2692=== RUN TestDrainGivesUpWhenServerDown2693=== PAUSE TestDrainGivesUpWhenServerDown2694=== RUN TestFailedPathPrunedByLaterClosure2695=== PAUSE TestFailedPathPrunedByLaterClosure2696=== RUN TestWorkerUploadsAndRemoves2697=== PAUSE TestWorkerUploadsAndRemoves2698=== RUN TestWorkerSkipsGCdPaths2699=== PAUSE TestWorkerSkipsGCdPaths2700=== RUN TestWorkerPrunesClosureDeps2701=== PAUSE TestWorkerPrunesClosureDeps2702=== RUN TestDrainTimeout2703=== PAUSE TestDrainTimeout2704=== CONT TestSendPathsEmpty2705=== CONT TestQueueConcurrentWriters2706--- PASS: TestSendPathsEmpty (0.00s)2707=== CONT TestDrainTimeout2708=== CONT TestWorkerPrunesClosureDeps2709=== CONT TestWorkerSkipsGCdPaths2710=== CONT TestWorkerUploadsAndRemoves2711=== CONT TestFailedPathPrunedByLaterClosure2712=== CONT TestDrainGivesUpWhenServerDown2713=== CONT TestRunNotBlockedByPoisonHead2714=== CONT TestDrainIsolatesPoisonPath2715=== CONT TestQueueFetchBatchLimit2716=== CONT TestQueueRemove2717=== CONT TestQueueDeduplication2718=== CONT TestQueueRetryMovesToBack2719=== CONT TestQueueEnqueueAndFetch2720=== CONT TestQueueFetchRemoveLifecycle2721=== CONT TestQueueRemoveLargeClosure27222026/10/24 21:47:16 INFO Uploading batch count=127232026/10/24 21:47:16 ERROR Upload failed error="upload failed" count=127242026/10/24 21:47:16 INFO Upload queue status pending=327252026/10/24 21:47:16 INFO Upload queue status pending=227262026/10/24 21:47:16 INFO Uploading batch count=127272026/10/24 21:47:16 ERROR Upload failed error="upload failed" count=127282026/10/24 21:47:16 INFO Upload queue status pending=227292026/10/24 21:47:16 INFO Uploading batch count=227302026/10/24 21:47:16 INFO Upload queue status pending=227312026/10/24 21:47:16 ERROR Upload failed error="upload failed" count=227322026/10/24 21:47:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3439396698/002/a2733--- PASS: TestQueueFetchBatchLimit (0.01s)27342026/10/24 21:47:16 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths2318796035/002/nonexistent27352026/10/24 21:47:16 INFO Uploading batch count=227362026/10/24 21:47:16 INFO Uploading batch count=127372026/10/24 21:47:16 INFO Uploading batch count=427382026/10/24 21:47:16 ERROR Upload failed error="upload failed" count=42739--- PASS: TestQueueEnqueueAndFetch (0.01s)27402026/10/24 21:47:16 INFO Uploading batch count=127412026/10/24 21:47:16 INFO Uploading batch count=227422026/10/24 21:47:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3439396698/002/b27432026/10/24 21:47:16 INFO Uploading batch count=12744--- PASS: TestQueueFetchRemoveLifecycle (0.01s)27452026/10/24 21:47:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath2921056445/002/bbb27462026/10/24 21:47:16 INFO Uploading batch count=127472026/10/24 21:47:16 INFO Uploading batch count=227482026/10/24 21:47:16 ERROR Upload failed error="upload failed" count=22749--- PASS: TestQueueDeduplication (0.01s)27502026/10/24 21:47:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3439396698/002/c2751--- PASS: TestQueueRemove (0.02s)2752--- PASS: TestQueueRetryMovesToBack (0.01s)27532026/10/24 21:47:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3439396698/002/d27542026/10/24 21:47:16 INFO Uploading batch count=227552026/10/24 21:47:16 ERROR Upload failed error="upload failed" count=227562026/10/24 21:47:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3439396698/002/e27572026/10/24 21:47:16 INFO Uploading batch count=127582026/10/24 21:47:16 ERROR Upload failed error="upload failed" count=127592026/10/24 21:47:16 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown3439396698/002/f2760--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)27612026/10/24 21:47:16 ERROR Drain finished with paths left in queue remaining=1027622026/10/24 21:47:16 INFO Uploading batch count=127632026/10/24 21:47:16 ERROR Upload failed error="upload failed" count=127642026/10/24 21:47:16 INFO Uploading batch count=127652026/10/24 21:47:16 ERROR Upload failed error="upload failed" count=127662026/10/24 21:47:16 ERROR Drain finished with paths left in queue remaining=12767--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2768--- PASS: TestDrainIsolatesPoisonPath (0.02s)2769--- PASS: TestWorkerUploadsAndRemoves (0.03s)2770--- PASS: TestWorkerSkipsGCdPaths (0.04s)2771--- PASS: TestWorkerPrunesClosureDeps (0.04s)2772--- PASS: TestQueueRemoveLargeClosure (0.05s)27732026/10/24 21:47:17 ERROR Upload failed error="context deadline exceeded" count=227742026/10/24 21:47:17 ERROR Drain finished with paths left in queue remaining=42775--- PASS: TestDrainTimeout (0.22s)2776--- PASS: TestQueueConcurrentWriters (0.27s)27772026/10/24 21:47:17 INFO Uploading batch count=127782026/10/24 21:47:17 INFO Uploading batch count=127792026/10/24 21:47:17 INFO Uploading batch count=127802026/10/24 21:47:17 ERROR Upload failed error="upload failed" count=127812026/10/24 21:47:17 INFO Uploading batch count=127822026/10/24 21:47:17 ERROR Upload failed error="upload failed" count=127832026/10/24 21:47:17 INFO Uploading batch count=127842026/10/24 21:47:17 ERROR Upload failed error="upload failed" count=127852026/10/24 21:47:17 INFO Uploading batch count=127862026/10/24 21:47:17 ERROR Upload failed error="upload failed" count=127872026/10/24 21:47:17 ERROR Drain finished with paths left in queue remaining=12788--- PASS: TestRunNotBlockedByPoisonHead (1.03s)2789PASS2790Running signing tests...2791=== RUN TestExternalSigner2792=== PAUSE TestExternalSigner2793=== RUN TestExternalSignerWrongPublicKey2794=== PAUSE TestExternalSignerWrongPublicKey2795=== RUN TestExternalSignerErrors2796=== PAUSE TestExternalSignerErrors2797=== RUN TestExternalSignerRestartsAfterCrash2798=== PAUSE TestExternalSignerRestartsAfterCrash2799=== RUN TestExternalSignerProgramErrorKeepsProcess2800=== PAUSE TestExternalSignerProgramErrorKeepsProcess2801=== RUN TestExternalSignerClose2802=== PAUSE TestExternalSignerClose2803=== RUN TestExternalSignerRejectsInvalidPublicKey2804=== PAUSE TestExternalSignerRejectsInvalidPublicKey2805=== RUN TestExternalSignerCancellation2806=== PAUSE TestExternalSignerCancellation2807=== RUN TestGenerateFingerprint2808=== PAUSE TestGenerateFingerprint2809=== RUN TestParseSigningKey2810=== PAUSE TestParseSigningKey2811=== RUN TestSign2812=== PAUSE TestSign2813=== RUN TestSignBatch2814=== PAUSE TestSignBatch2815=== RUN TestNilKeyPublicKey2816=== PAUSE TestNilKeyPublicKey2817=== RUN TestSignErrors2818=== PAUSE TestSignErrors2819=== CONT TestExternalSigner2820=== CONT TestExternalSignerCancellation2821=== CONT TestExternalSignerProgramErrorKeepsProcess2822=== CONT TestSignErrors2823=== CONT TestNilKeyPublicKey2824=== CONT TestExternalSignerClose2825--- PASS: TestNilKeyPublicKey (0.00s)2826=== CONT TestSignBatch2827=== CONT TestParseSigningKey2828=== CONT TestSign2829=== CONT TestExternalSignerErrors2830=== CONT TestGenerateFingerprint2831=== CONT TestExternalSignerRestartsAfterCrash2832=== CONT TestExternalSignerWrongPublicKey2833=== CONT TestExternalSignerRejectsInvalidPublicKey2834=== RUN TestParseSigningKey/valid_32-byte_key2835=== RUN TestGenerateFingerprint/basic_with_references2836=== PAUSE TestParseSigningKey/valid_32-byte_key2837=== RUN TestExternalSignerErrors/invalid_signature_base642838=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2839=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2840=== RUN TestSignErrors/nil_key2841--- PASS: TestSign (0.00s)2842=== RUN TestExternalSignerRejectsInvalidPublicKey/#002843=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002844=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2845--- PASS: TestSignBatch (0.00s)2846=== PAUSE TestExternalSignerErrors/invalid_signature_base642847=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2848=== PAUSE TestGenerateFingerprint/basic_with_references2849=== RUN TestGenerateFingerprint/no_references2850=== PAUSE TestGenerateFingerprint/no_references2851=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2852=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2853=== RUN TestParseSigningKey/no_colon2854=== PAUSE TestParseSigningKey/no_colon2855=== PAUSE TestSignErrors/nil_key2856=== RUN TestExternalSignerErrors/program_error2857=== PAUSE TestExternalSignerErrors/program_error2858=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2859=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2860=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2861=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2862=== RUN TestGenerateFingerprint/invalid_nar_hash_length2863=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2864=== RUN TestGenerateFingerprint/invalid_store_path_prefix2865=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2866=== RUN TestGenerateFingerprint/invalid_reference_prefix2867=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2868=== CONT TestGenerateFingerprint/basic_with_references2869=== RUN TestSignErrors/nil_narinfo2870=== PAUSE TestSignErrors/nil_narinfo2871=== CONT TestGenerateFingerprint/invalid_nar_hash_length2872=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2873=== RUN TestExternalSignerErrors/exit_on_request2874=== PAUSE TestExternalSignerErrors/exit_on_request2875=== RUN TestExternalSignerErrors/invalid_JSON2876=== PAUSE TestExternalSignerErrors/invalid_JSON2877=== RUN TestExternalSignerErrors/wrong_id2878=== PAUSE TestExternalSignerErrors/wrong_id2879=== RUN TestExternalSignerErrors/wrong_signature_name2880=== PAUSE TestExternalSignerErrors/wrong_signature_name2881=== RUN TestExternalSignerErrors/wrong_shape2882=== PAUSE TestExternalSignerErrors/wrong_shape2883=== RUN TestExternalSignerErrors/wrong_signature_length2884=== PAUSE TestExternalSignerErrors/wrong_signature_length2885=== RUN TestExternalSignerErrors/exit_at_startup2886=== PAUSE TestExternalSignerErrors/exit_at_startup2887=== RUN TestExternalSignerErrors/null_signatures2888=== PAUSE TestExternalSignerErrors/null_signatures2889=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2890=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2891=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2892=== CONT TestGenerateFingerprint/invalid_reference_prefix2893=== CONT TestGenerateFingerprint/invalid_store_path_prefix2894=== CONT TestGenerateFingerprint/no_references2895=== RUN TestSignErrors/invalid_narinfo2896=== PAUSE TestSignErrors/invalid_narinfo2897=== RUN TestParseSigningKey/empty_name2898=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2899--- PASS: TestGenerateFingerprint (0.00s)2900 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2901 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2902 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2903 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2904 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2905 --- PASS: TestGenerateFingerprint/no_references (0.00s)2906 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2907=== RUN TestExternalSignerErrors/wrong_signatures_shape2908=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2909=== CONT TestExternalSignerRejectsInvalidPublicKey/#002910=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2911=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2912=== PAUSE TestParseSigningKey/empty_name2913=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2914=== RUN TestExternalSignerErrors/unrequested_key2915=== PAUSE TestExternalSignerErrors/unrequested_key2916=== RUN TestSignErrors/canceled2917=== PAUSE TestSignErrors/canceled2918=== CONT TestSignErrors/nil_key2919=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2920=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2921--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.00s)2922--- PASS: TestExternalSignerWrongPublicKey (0.00s)2923=== RUN TestParseSigningKey/invalid_base642924=== PAUSE TestParseSigningKey/invalid_base642925=== RUN TestParseSigningKey/wrong_length2926=== PAUSE TestParseSigningKey/wrong_length2927=== CONT TestParseSigningKey/valid_32-byte_key2928=== RUN TestExternalSignerErrors/null2929=== PAUSE TestExternalSignerErrors/null2930=== CONT TestParseSigningKey/no_colon2931=== CONT TestParseSigningKey/empty_name2932=== CONT TestSignErrors/canceled2933=== CONT TestSignErrors/nil_narinfo2934--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2935 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2936 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2937 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2938 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2939 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2940=== CONT TestParseSigningKey/wrong_length2941=== CONT TestParseSigningKey/invalid_base642942=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2943=== CONT TestSignErrors/invalid_narinfo2944=== RUN TestExternalSignerErrors/missing_signatures2945=== PAUSE TestExternalSignerErrors/missing_signatures2946=== RUN TestExternalSignerErrors/too_few_signatures2947=== PAUSE TestExternalSignerErrors/too_few_signatures2948--- PASS: TestExternalSignerClose (0.00s)2949=== RUN TestExternalSignerErrors/missing_signature_name2950=== PAUSE TestExternalSignerErrors/missing_signature_name2951--- PASS: TestParseSigningKey (0.00s)2952 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2953 --- PASS: TestParseSigningKey/no_colon (0.00s)2954 --- PASS: TestParseSigningKey/empty_name (0.00s)2955 --- PASS: TestParseSigningKey/wrong_length (0.00s)2956 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2957 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2958--- PASS: TestSignErrors (0.00s)2959 --- PASS: TestSignErrors/nil_key (0.00s)2960 --- PASS: TestSignErrors/canceled (0.00s)2961 --- PASS: TestSignErrors/nil_narinfo (0.00s)2962 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2963=== CONT TestExternalSignerErrors/invalid_signature_base642964=== CONT TestExternalSignerErrors/missing_signature_name2965=== CONT TestExternalSignerErrors/too_few_signatures2966=== CONT TestExternalSignerErrors/missing_signatures2967=== CONT TestExternalSignerErrors/null2968=== CONT TestExternalSignerErrors/unrequested_key2969=== CONT TestExternalSignerErrors/wrong_signatures_shape2970=== CONT TestExternalSignerErrors/null_signatures2971=== CONT TestExternalSignerErrors/wrong_id2972=== CONT TestExternalSignerErrors/invalid_JSON2973=== CONT TestExternalSignerErrors/exit_on_request2974=== CONT TestExternalSignerErrors/wrong_signature_name2975=== CONT TestExternalSignerErrors/program_error2976=== CONT TestExternalSignerErrors/exit_at_startup2977=== CONT TestExternalSignerErrors/wrong_signature_length2978=== CONT TestExternalSignerErrors/wrong_shape2979--- PASS: TestExternalSigner (0.01s)2980--- PASS: TestExternalSignerRestartsAfterCrash (0.01s)2981--- PASS: TestExternalSignerErrors (0.00s)2982 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (0.00s)2983 --- PASS: TestExternalSignerErrors/missing_signature_name (0.00s)2984 --- PASS: TestExternalSignerErrors/null (0.00s)2985 --- PASS: TestExternalSignerErrors/invalid_JSON (0.00s)2986 --- PASS: TestExternalSignerErrors/wrong_shape (0.00s)2987 --- PASS: TestExternalSignerErrors/too_few_signatures (0.01s)2988 --- PASS: TestExternalSignerErrors/wrong_signature_length (0.00s)2989 --- PASS: TestExternalSignerErrors/exit_on_request (0.00s)2990 --- PASS: TestExternalSignerErrors/missing_signatures (0.01s)2991 --- PASS: TestExternalSignerErrors/unrequested_key (0.01s)2992 --- PASS: TestExternalSignerErrors/program_error (0.00s)2993 --- PASS: TestExternalSignerErrors/wrong_id (0.01s)2994 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.00s)2995 --- PASS: TestExternalSignerErrors/exit_at_startup (0.00s)2996 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (0.01s)2997 --- PASS: TestExternalSignerErrors/null_signatures (0.01s)2998--- PASS: TestExternalSignerCancellation (0.02s)2999PASS3000Running OpenBao signer tests...3001=== RUN TestSign3002=== PAUSE TestSign3003=== RUN TestSignErrors3004=== PAUSE TestSignErrors3005=== RUN TestServe3006=== PAUSE TestServe3007=== RUN TestServeRejectsGarbage3008=== PAUSE TestServeRejectsGarbage3009=== CONT TestSign3010=== CONT TestServe3011=== CONT TestSignErrors3012=== CONT TestServeRejectsGarbage3013=== RUN TestSignErrors/invalid_base643014=== PAUSE TestSignErrors/invalid_base643015=== RUN TestSignErrors/http_error3016=== PAUSE TestSignErrors/http_error3017--- PASS: TestServeRejectsGarbage (0.00s)3018=== RUN TestSignErrors/invalid_json3019=== PAUSE TestSignErrors/invalid_json3020=== RUN TestSignErrors/no_prefix3021=== PAUSE TestSignErrors/no_prefix3022=== CONT TestSignErrors/invalid_base643023=== CONT TestSignErrors/invalid_json3024=== CONT TestSignErrors/http_error3025=== CONT TestSignErrors/no_prefix3026--- PASS: TestServe (0.00s)3027--- PASS: TestSign (0.00s)3028--- PASS: TestSignErrors (0.00s)3029 --- PASS: TestSignErrors/no_prefix (0.00s)3030 --- PASS: TestSignErrors/invalid_json (0.00s)3031 --- PASS: TestSignErrors/invalid_base64 (0.00s)3032 --- PASS: TestSignErrors/http_error (0.00s)3033PASS