niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #307
· raw
1tribuchet: building on eliza2Running client tests...3=== RUN TestDoServerRequestAttachesToken4=== PAUSE TestDoServerRequestAttachesToken5=== RUN TestUploadBuildLog_FileBodyReplayedOnRetry6=== PAUSE TestUploadBuildLog_FileBodyReplayedOnRetry7=== RUN TestRegisterUploadedObjectReusesConnections8=== PAUSE TestRegisterUploadedObjectReusesConnections9=== RUN TestRunGarbageCollection_FinishedOnAnotherReplica10=== PAUSE TestRunGarbageCollection_FinishedOnAnotherReplica11=== RUN TestRunGarbageCollection_NotFoundAfterLocalRun12=== PAUSE TestRunGarbageCollection_NotFoundAfterLocalRun13=== RUN TestCaseHackSuffix14=== PAUSE TestCaseHackSuffix15=== RUN TestFilterOversizedClosures16=== PAUSE TestFilterOversizedClosures17=== RUN TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure18=== PAUSE TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure19=== RUN TestUploadMultipart_PartsInParallel20=== PAUSE TestUploadMultipart_PartsInParallel21=== RUN TestUploadMultipart_ProducerErrorIsNotEOF22=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF23=== RUN TestUploadMultipart_FailedPartBufferNotReused24=== PAUSE TestUploadMultipart_FailedPartBufferNotReused25=== RUN TestPartSizeForNAR26=== PAUSE TestPartSizeForNAR27=== RUN TestUploadMultipart_SupersededByPeer28=== PAUSE TestUploadMultipart_SupersededByPeer29=== RUN TestDumpPathCaseHackMatchesNix30--- PASS: TestDumpPathCaseHackMatchesNix (0.03s)31=== RUN TestDumpPathCaseHackCollision32--- PASS: TestDumpPathCaseHackCollision (0.00s)33=== RUN TestSupersededNARStillUploadsListing34=== PAUSE TestSupersededNARStillUploadsListing35=== RUN TestTruncatedNARDumpIsNotCompleted36=== PAUSE TestTruncatedNARDumpIsNotCompleted37=== RUN TestDumpPathMatchesNix38=== PAUSE TestDumpPathMatchesNix39=== RUN TestDumpPathSingleFile40=== PAUSE TestDumpPathSingleFile41=== RUN TestDumpPathWriterError42=== PAUSE TestDumpPathWriterError43=== RUN TestDumpPathWriterErrorStopsReading44 nar_test.go:289: read 114 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.61s)46=== RUN TestEncodeNixBase3247=== PAUSE TestEncodeNixBase3248=== RUN TestEncodeNixBase32WithRealHash49=== PAUSE TestEncodeNixBase32WithRealHash50=== RUN TestConvertHashToNix3251=== PAUSE TestConvertHashToNix3252=== RUN TestGetStorePathHash53=== PAUSE TestGetStorePathHash54=== RUN TestPathInfoHashCompatibility55=== PAUSE TestPathInfoHashCompatibility56=== RUN TestParsePathInfoJSON57=== PAUSE TestParsePathInfoJSON58=== RUN TestParsePathInfoJSONMultiplePaths59=== PAUSE TestParsePathInfoJSONMultiplePaths60=== RUN TestPathInfoCACompatibility61=== PAUSE TestPathInfoCACompatibility62=== RUN TestUploadPendingObjectsStopsStartingAfterFailure63--- PASS: TestUploadPendingObjectsStopsStartingAfterFailure (0.02s)64=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent65=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent66=== RUN TestCompletePendingClosure_NotFoundWithoutKey67=== PAUSE TestCompletePendingClosure_NotFoundWithoutKey68=== RUN TestRateLimiterFeedback69=== PAUSE TestRateLimiterFeedback70=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess71=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess72=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer73=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer74=== RUN TestResolveStorePath75=== PAUSE TestResolveStorePath76=== RUN TestDoWithRetry_BodyReplayedViaGetBody77=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody78=== RUN TestDoWithRetry_FinalResponseBodyReadable79=== PAUSE TestDoWithRetry_FinalResponseBodyReadable80=== RUN TestShellSplit81=== PAUSE TestShellSplit82=== RUN TestShellSplitErrors83=== PAUSE TestShellSplitErrors84=== RUN TestStreamPushReportsEveryPath85=== PAUSE TestStreamPushReportsEveryPath86=== RUN TestStreamPushBatchesUnderLoad87=== PAUSE TestStreamPushBatchesUnderLoad88=== RUN TestStreamPushIsolatesFailures89=== PAUSE TestStreamPushIsolatesFailures90=== RUN TestStreamPushGivesUpOnDeadServer91=== PAUSE TestStreamPushGivesUpOnDeadServer92=== RUN TestStreamPushRequestLine93=== PAUSE TestStreamPushRequestLine94=== RUN TestStreamPushReportsSignatures95=== PAUSE TestStreamPushReportsSignatures96=== RUN TestClientSignaturesByStorePath97=== PAUSE TestClientSignaturesByStorePath98=== RUN TestStreamPushStopsOnCancel99=== PAUSE TestStreamPushStopsOnCancel100=== RUN TestSetClientTLS101=== PAUSE TestSetClientTLS102=== RUN TestSetClientTLSDoesNotMutateDefaultTransport103=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport104=== RUN TestSetClientTLSErrors105=== PAUSE TestSetClientTLSErrors106=== RUN TestStaticToken107=== PAUSE TestStaticToken108=== RUN TestFileTokenReadsAndCaches109=== PAUSE TestFileTokenReadsAndCaches110=== RUN TestFileTokenMissing111=== PAUSE TestFileTokenMissing112=== RUN TestFileTokenEmpty113=== PAUSE TestFileTokenEmpty114=== RUN TestScriptTokenNoExpiryRerunsEveryCall115=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall116=== RUN TestScriptTokenCachesUntilRefresh117=== PAUSE TestScriptTokenCachesUntilRefresh118=== RUN TestScriptTokenEmptyToken119=== PAUSE TestScriptTokenEmptyToken120=== RUN TestScriptTokenBadJSON121=== PAUSE TestScriptTokenBadJSON122=== RUN TestScriptTokenScriptFails123=== PAUSE TestScriptTokenScriptFails124=== RUN TestScriptTokenEmptyCommand125=== PAUSE TestScriptTokenEmptyCommand126=== RUN TestScriptTokenDoesNotWaitForItsChildren127=== PAUSE TestScriptTokenDoesNotWaitForItsChildren128=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure129=== CONT TestGetStorePathHash130=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry131=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent132=== CONT TestFileTokenReadsAndCaches133=== CONT TestUploadMultipart_PartsInParallel134=== RUN TestGetStorePathHash/valid_store_path135=== CONT TestScriptTokenEmptyCommand136=== CONT TestParsePathInfoJSONMultiplePaths137=== CONT TestStreamPushReportsSignatures138=== CONT TestScriptTokenDoesNotWaitForItsChildren139=== CONT TestStreamPushStopsOnCancel140=== CONT TestUploadMultipart_FailedPartBufferNotReused141=== CONT TestStreamPushGivesUpOnDeadServer142=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs143=== CONT TestDumpPathWriterError144=== CONT TestPathInfoHashCompatibility145=== CONT TestStreamPushBatchesUnderLoad146=== CONT TestUploadMultipart_SupersededByPeer147=== CONT TestConvertHashToNix32148=== CONT TestStreamPushIsolatesFailures149=== CONT TestClientSignaturesByStorePath150=== CONT TestDumpPathMatchesNix151=== CONT TestCompletePendingClosure_NotFoundWithoutKey152=== CONT TestScriptTokenEmptyToken153=== CONT TestSetClientTLSErrors154=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier155=== CONT TestPathInfoCACompatibility156=== PAUSE TestGetStorePathHash/valid_store_path157--- PASS: TestScriptTokenEmptyCommand (0.00s)158=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths159=== RUN TestStreamPushStopsOnCancel/waiting_for_input160=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)161=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs162=== RUN TestStreamPushBatchesUnderLoad/together163=== RUN TestUploadMultipart_SupersededByPeer/exists164=== RUN TestConvertHashToNix32/SRI_format_to_Nix32165=== CONT TestDoWithRetry_FinalResponseBodyReadable166=== RUN TestPathInfoCACompatibility/null_ca_field167=== RUN TestGetStorePathHash/basename_without_hyphen_should_error168--- PASS: TestClientSignaturesByStorePath (0.00s)169=== CONT TestSetClientTLSDoesNotMutateDefaultTransport170=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier171=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout172=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input173=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot174=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout175=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error176=== CONT TestTruncatedNARDumpIsNotCompleted177=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer178=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths179--- PASS: TestFileTokenReadsAndCaches (0.00s)180--- PASS: TestStreamPushReportsSignatures (0.01s)181=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up182=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32183=== PAUSE TestStreamPushBatchesUnderLoad/together184=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time185=== CONT TestSetClientTLS186=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time187=== PAUSE TestUploadMultipart_SupersededByPeer/exists188=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot189=== PAUSE TestPathInfoCACompatibility/null_ca_field190=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)191=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error192=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon193=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths194--- PASS: TestStreamPushIsolatesFailures (0.00s)195=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon196=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up197=== RUN TestConvertHashToNix32/already_Nix32_format198=== CONT TestPartSizeForNAR199=== PAUSE TestConvertHashToNix32/already_Nix32_format200=== RUN TestPartSizeForNAR/zero_stays_at_minimum201=== CONT TestScriptTokenCachesUntilRefresh202=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum203=== RUN TestUploadMultipart_SupersededByPeer/missing204=== CONT TestStreamPushRequestLine205=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot206=== CONT TestStreamPushReportsEveryPath207=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot208=== RUN TestPathInfoCACompatibility/old_string_format_-_text209=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot210=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text211=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error212=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive213=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error214--- PASS: TestScriptTokenEmptyToken (0.00s)215=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error216=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths217=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI218=== CONT TestEncodeNixBase32219=== CONT TestScriptTokenBadJSON220=== RUN TestEncodeNixBase32/test_string_hash221=== RUN TestConvertHashToNix32/invalid_format222=== PAUSE TestConvertHashToNix32/invalid_format223=== RUN TestPartSizeForNAR/small_stays_at_minimum224=== PAUSE TestUploadMultipart_SupersededByPeer/missing225=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot226=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive227--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)228--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)229=== CONT TestEncodeNixBase32WithRealHash230=== CONT TestDoServerRequestAttachesToken231=== CONT TestUploadMultipart_ProducerErrorIsNotEOF232=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI233=== PAUSE TestEncodeNixBase32/test_string_hash234=== CONT TestScriptTokenScriptFails235=== RUN TestEncodeNixBase32/empty_input236=== CONT TestRateLimiterFeedback237=== PAUSE TestPartSizeForNAR/small_stays_at_minimum238=== RUN TestRateLimiterFeedback/429_enables_limiter239=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum240=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun241=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot242=== RUN TestPathInfoCACompatibility/new_structured_format_-_text243=== CONT TestDoWithRetry_BodyReplayedViaGetBody244=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot245--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.01s)246=== RUN TestSetClientTLSErrors/missing_cert_file247=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part248=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512249=== PAUSE TestEncodeNixBase32/empty_input250=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512251=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum252=== PAUSE TestRateLimiterFeedback/429_enables_limiter253=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text254=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken255--- PASS: TestStreamPushReportsEveryPath (0.00s)256=== PAUSE TestSetClientTLSErrors/missing_cert_file257=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part258=== CONT TestShellSplit259=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary260=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary261=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken262=== CONT TestScriptTokenNoExpiryRerunsEveryCall263=== CONT TestFileTokenMissing264=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts265=== CONT TestFileTokenEmpty266=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts267=== RUN TestRateLimiterFeedback/503_enables_limiter268=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method269=== PAUSE TestRateLimiterFeedback/503_enables_limiter270=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method271=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter272=== CONT TestResolveStorePath273=== CONT TestShellSplitErrors274=== RUN TestSetClientTLSErrors/missing_key_file275=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess276=== RUN TestPartSizeForNAR/1_TiB277--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)278=== CONT TestStaticToken279=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter280=== CONT TestParsePathInfoJSON281=== CONT TestRegisterUploadedObjectReusesConnections282=== RUN TestParsePathInfoJSON/Nix_format283=== PAUSE TestParsePathInfoJSON/Nix_format284=== CONT TestDumpPathSingleFile285=== RUN TestParsePathInfoJSON/Lix_format286=== PAUSE TestParsePathInfoJSON/Lix_format287=== PAUSE TestSetClientTLSErrors/missing_key_file288=== CONT TestSupersededNARStillUploadsListing289=== PAUSE TestPartSizeForNAR/1_TiB290=== RUN TestSupersededNARStillUploadsListing/small_NAR291=== RUN TestPartSizeForNAR/5_TiB_S3_max_object292=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter293=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object294=== CONT TestFilterOversizedClosures295=== RUN TestFilterOversizedClosures/no_limit_keeps_everything296=== CONT TestCaseHackSuffix297=== RUN TestPartSizeForNAR/capped_at_5_GiB298=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything299=== PAUSE TestPartSizeForNAR/capped_at_5_GiB300=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped301=== RUN TestParsePathInfoJSON/empty_input302=== PAUSE TestParsePathInfoJSON/empty_input303--- PASS: TestEncodeNixBase32WithRealHash (0.00s)304=== PAUSE TestSupersededNARStillUploadsListing/small_NAR305=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter306=== RUN TestParsePathInfoJSON/whitespace_only307=== RUN TestSupersededNARStillUploadsListing/dump_cut_short308=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short309=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails310=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs311=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails312=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica313=== RUN TestSetClientTLSErrors/missing_ca_file314=== PAUSE TestSetClientTLSErrors/missing_ca_file315--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)316--- PASS: TestShellSplit (0.00s)317=== RUN TestSetClientTLS/rejects_connection_without_client_cert318=== PAUSE TestParsePathInfoJSON/whitespace_only319=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped320=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout321=== RUN TestSetClientTLSErrors/invalid_ca_file322=== CONT TestStreamPushBatchesUnderLoad/together323=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time324=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up325--- PASS: TestDoServerRequestAttachesToken (0.00s)326=== RUN TestFilterOversizedClosures/all_closures_skipped327=== PAUSE TestSetClientTLSErrors/invalid_ca_file328=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier329--- PASS: TestScriptTokenScriptFails (0.00s)330--- PASS: TestShellSplitErrors (0.00s)331--- PASS: TestStaticToken (0.00s)332--- PASS: TestFileTokenMissing (0.00s)333--- PASS: TestFileTokenEmpty (0.00s)334--- PASS: TestScriptTokenBadJSON (0.00s)335--- PASS: TestResolveStorePath (0.00s)336=== PAUSE TestFilterOversizedClosures/all_closures_skipped337=== CONT TestGetStorePathHash/valid_store_path338--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.00s)339--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)340--- PASS: TestScriptTokenCachesUntilRefresh (0.01s)341=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error342=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths343=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert344=== RUN TestParsePathInfoJSON/invalid_JSON345=== PAUSE TestParsePathInfoJSON/invalid_JSON346=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error347=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA348=== CONT TestGetStorePathHash/basename_without_hyphen_should_error349=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths350=== CONT TestConvertHashToNix32/invalid_format351=== CONT TestConvertHashToNix32/SRI_format_to_Nix32352=== CONT TestConvertHashToNix32/already_Nix32_format353--- PASS: TestGetStorePathHash (0.01s)354 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)355 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)356 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)357 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)358=== CONT TestUploadMultipart_SupersededByPeer/exists359=== CONT TestUploadMultipart_SupersededByPeer/missing360=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA361=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon362=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)363=== CONT TestEncodeNixBase32/empty_input364=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI365=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary366=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part367--- PASS: TestParsePathInfoJSONMultiplePaths (0.01s)368 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)369 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)370=== CONT TestEncodeNixBase32/test_string_hash371=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken372=== RUN TestSetClientTLS/preserves_debug_logging_transport373=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512374=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot375=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot376=== PAUSE TestSetClientTLS/preserves_debug_logging_transport377=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot378=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot379=== CONT TestStreamPushStopsOnCancel/waiting_for_input380--- PASS: TestStreamPushBatchesUnderLoad (0.00s)381 --- PASS: TestStreamPushBatchesUnderLoad/together (0.01s)382 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.01s)383--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.25s)384=== CONT TestPathInfoCACompatibility/null_ca_field385--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.01s)386--- PASS: TestConvertHashToNix32 (0.01s)387 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)388 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)389 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)390=== CONT TestPathInfoCACompatibility/new_structured_format_-_text391--- PASS: TestEncodeNixBase32 (0.00s)392 --- PASS: TestEncodeNixBase32/empty_input (0.00s)393 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)394--- PASS: TestDumpPathSingleFile (0.25s)395=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive396--- PASS: TestPathInfoHashCompatibility (0.01s)397 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)398 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)399 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)400 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)401--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.01s)402 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)403 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.24s)404=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method405=== CONT TestPathInfoCACompatibility/old_string_format_-_text406=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum407--- PASS: TestCaseHackSuffix (0.26s)408=== CONT TestPartSizeForNAR/capped_at_5_GiB409--- PASS: TestPathInfoCACompatibility (0.01s)410 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)411 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)412 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)413 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)414 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)415=== CONT TestPartSizeForNAR/5_TiB_S3_max_object416=== CONT TestPartSizeForNAR/1_TiB417=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts418=== CONT TestPartSizeForNAR/small_stays_at_minimum419=== CONT TestPartSizeForNAR/zero_stays_at_minimum420=== CONT TestSupersededNARStillUploadsListing/dump_cut_short421=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails422=== CONT TestSupersededNARStillUploadsListing/small_NAR423--- PASS: TestPartSizeForNAR (0.01s)424 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)425 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)426 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)427 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)428 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)429 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)430 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)431--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)432 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.24s)433 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.25s)434=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter435=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter436=== CONT TestRateLimiterFeedback/503_enables_limiter437=== CONT TestRateLimiterFeedback/429_enables_limiter438=== CONT TestSetClientTLSErrors/missing_cert_file439=== CONT TestSetClientTLSErrors/invalid_ca_file440=== CONT TestSetClientTLSErrors/missing_key_file441=== CONT TestSetClientTLSErrors/missing_ca_file442--- PASS: TestRateLimiterFeedback (0.01s)443 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)444 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)445 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)446 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)447=== CONT TestFilterOversizedClosures/no_limit_keeps_everything448--- PASS: TestSetClientTLSErrors (0.01s)449 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)450 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)451 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)452 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)453=== CONT TestParsePathInfoJSON/empty_input454=== CONT TestParsePathInfoJSON/invalid_JSON455=== CONT TestFilterOversizedClosures/all_closures_skipped456=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped457=== CONT TestParsePathInfoJSON/whitespace_only458--- PASS: TestFilterOversizedClosures (0.01s)459 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)460 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)461 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)462=== CONT TestParsePathInfoJSON/Lix_format463=== CONT TestParsePathInfoJSON/Nix_format464=== CONT TestSetClientTLS/rejects_connection_without_client_cert465=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA466--- PASS: TestParsePathInfoJSON (0.01s)467 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)468 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)469 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)470 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)471 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)472=== CONT TestSetClientTLS/preserves_debug_logging_transport473--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.31s)474--- PASS: TestDumpPathWriterError (0.31s)475--- PASS: TestStreamPushStopsOnCancel (0.01s)476 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.05s)477 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.05s)478 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.05s)479 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.05s)480 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.05s)481 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.05s)482--- PASS: TestSetClientTLS (0.26s)483 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)484 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.02s)485 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.09s)486--- PASS: TestRegisterUploadedObjectReusesConnections (0.57s)487--- PASS: TestDumpPathMatchesNix (0.59s)488--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.00s)489 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.55s)490 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.60s)491--- PASS: TestStreamPushRequestLine (0.62s)492--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)493--- PASS: TestUploadMultipart_PartsInParallel (1.32s)494--- PASS: TestTruncatedNARDumpIsNotCompleted (1.33s)495--- PASS: TestSupersededNARStillUploadsListing (0.00s)496 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.02s)497 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.02s)498 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.07s)499--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.35s)500--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)501--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.01s)502 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.00s)503 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.25s)504PASS505Running server tests...506The files belonging to this database system will be owned by user "nixbld".507This user must also own the server process.508509The database cluster will be initialized with locale "C".510The default database encoding has accordingly been set to "SQL_ASCII".511The default text search configuration will be set to "english".512513Data page checksums are enabled.514515creating directory /build/postgres2152699245/data ... ok516creating subdirectories ... ok517selecting dynamic shared memory implementation ... posix518selecting default "max_connections" ... 100519selecting default "shared_buffers" ... 128MB520selecting default time zone ... UTC521creating configuration files ... ok522running bootstrap script ... ok523performing post-bootstrap initialization ... ok524syncing data to disk ... ok525526initdb: warning: enabling "trust" authentication for local connections527initdb: 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.528529Success. You can now start the database server using:530531 pg_ctl -D /build/postgres2152699245/data -l logfile start532533/build/postgres2152699245:5432 - no response5342026-10-01 09:22:20.004 UTC [173] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5352026-10-01 09:22:20.004 UTC [173] LOG: listening on Unix socket "/build/postgres2152699245/.s.PGSQL.5432"5362026-10-01 09:22:20.008 UTC [180] LOG: database system was shut down at 2026-10-01 09:22:19 UTC5372026-10-01 09:22:20.012 UTC [173] LOG: database system is ready to accept connections538/build/postgres2152699245:5432 - accepting connections539=== RUN TestService_AuthMiddleware540=== PAUSE TestService_AuthMiddleware541=== RUN TestService_AuthMiddleware_MTLSProxyHeader542=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader543=== RUN TestService_AuthMiddleware_MTLSBoundSubjects544=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects545=== RUN TestService_ReadAuthMiddleware546=== PAUSE TestService_ReadAuthMiddleware547=== RUN TestService_AuthMiddleware_OIDC548=== PAUSE TestService_AuthMiddleware_OIDC549=== RUN TestService_RequireScope_OIDC550=== PAUSE TestService_RequireScope_OIDC551=== RUN TestService_ReadScope_PublicByDefault552=== PAUSE TestService_ReadScope_PublicByDefault553=== RUN TestCacheConfigHandler554=== PAUSE TestCacheConfigHandler555=== RUN TestCacheStatsHandler556=== PAUSE TestCacheStatsHandler557=== RUN TestClientCADerivations558=== PAUSE TestClientCADerivations559=== RUN TestClientErrorHandling560=== PAUSE TestClientErrorHandling561=== RUN TestClientIntegration562=== PAUSE TestClientIntegration563=== RUN TestClientMultipleUploads564=== PAUSE TestClientMultipleUploads565=== RUN TestClientWithDependencies566=== PAUSE TestClientWithDependencies567=== RUN TestClientSharedPathCommittedMidPush568=== PAUSE TestClientSharedPathCommittedMidPush569=== RUN TestPinProtectsFromGC570=== PAUSE TestPinProtectsFromGC571=== RUN TestClientPushesUseOnePush572=== PAUSE TestClientPushesUseOnePush573=== RUN TestClientFallsBackToClosures574=== PAUSE TestClientFallsBackToClosures575=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock576=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock577=== RUN TestResolveDBConnectionString578=== PAUSE TestResolveDBConnectionString579=== RUN TestConnectWaitsForAPeerMigration580=== PAUSE TestConnectWaitsForAPeerMigration581=== RUN TestConnectSerialisesConcurrentMigrations582=== PAUSE TestConnectSerialisesConcurrentMigrations583=== RUN TestLeadElectsOneAndHandsOver584=== PAUSE TestLeadElectsOneAndHandsOver585=== RUN TestLeadIncumbentWinsAfterRestart5862026/10/01 09:22:20 INFO lead: acquired remote=192.0.2.1:12345872026/10/01 09:22:21 INFO lead: released remote=192.0.2.1:12345882026/10/01 09:22:21 INFO lead: acquired remote=192.0.2.1:12345892026/10/01 09:22:22 INFO lead: released remote=192.0.2.1:1234590--- PASS: TestLeadIncumbentWinsAfterRestart (2.31s)591=== RUN TestLeadEndsOnShutdown592=== PAUSE TestLeadEndsOnShutdown593=== RUN TestLeadEndsWhenItsConnectionHangs5942026/10/01 09:22:22 INFO lead: acquired remote=192.0.2.1:12345952026-10-01 09:22:23.843 UTC [429] FATAL: terminating connection due to administrator command5962026/10/01 09:22:24 INFO lead: acquired remote=192.0.2.1:12345972026/10/01 09:22:25 WARN lead: lock connection lost error="timeout: context deadline exceeded"5982026/10/01 09:22:25 INFO lead: released remote=192.0.2.1:12345992026/10/01 09:22:25 INFO lead: released remote=192.0.2.1:1234600--- PASS: TestLeadEndsWhenItsConnectionHangs (2.74s)601=== RUN TestGCAdvisoryLockBlocksConcurrentRun602=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun603=== RUN TestGCBugBareHashReferences604=== PAUSE TestGCBugBareHashReferences605=== RUN TestGCMetrics606=== PAUSE TestGCMetrics607=== RUN TestPushDedupSurvivesConcurrentGC608=== PAUSE TestPushDedupSurvivesConcurrentGC609=== RUN TestDeduplicatedObjectsRecordedAsPending610=== PAUSE TestDeduplicatedObjectsRecordedAsPending611=== RUN TestGCSweepSkipsPendingObjects612=== PAUSE TestGCSweepSkipsPendingObjects613=== RUN TestTombstonedObjectOfferedWithoutWaiting614=== PAUSE TestTombstonedObjectOfferedWithoutWaiting615=== RUN TestGCSweepDeliversEachKeyOnce616=== PAUSE TestGCSweepDeliversEachKeyOnce617=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection618=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection619=== RUN TestForceGCDuringPushOffersSweptObject620=== PAUSE TestForceGCDuringPushOffersSweptObject621=== RUN TestFailedS3DeleteKeepsTombstone622=== PAUSE TestFailedS3DeleteKeepsTombstone623=== RUN TestSweepSkipsRowsLockedByPush624=== PAUSE TestSweepSkipsRowsLockedByPush625=== RUN TestRegisterCompletedObjectNeedsPendingRow626=== PAUSE TestRegisterCompletedObjectNeedsPendingRow627=== RUN TestGetExistingObjectsLocksRows628=== PAUSE TestGetExistingObjectsLocksRows629=== RUN TestSweepRechecksPendingAfterLocking630=== PAUSE TestSweepRechecksPendingAfterLocking631=== RUN TestPushWaitsForSweepHoldingRow632=== PAUSE TestPushWaitsForSweepHoldingRow633=== RUN TestCommitRacingPendingCleanupKeepsObjects634=== PAUSE TestCommitRacingPendingCleanupKeepsObjects635=== RUN TestGCEndsOnShutdown636=== PAUSE TestGCEndsOnShutdown637=== RUN TestGCTaskStore_StartNew638=== PAUSE TestGCTaskStore_StartNew639=== RUN TestGCTaskStore_DeduplicateSameParams640=== PAUSE TestGCTaskStore_DeduplicateSameParams641=== RUN TestGCTaskStore_ConflictDifferentParams642=== PAUSE TestGCTaskStore_ConflictDifferentParams643=== RUN TestGCTaskStore_GetEmpty644=== PAUSE TestGCTaskStore_GetEmpty645=== RUN TestGCTaskStore_GetReturnsLatest646=== PAUSE TestGCTaskStore_GetReturnsLatest647=== RUN TestGCTaskStore_CompletedAllowsNewTask648=== PAUSE TestGCTaskStore_CompletedAllowsNewTask649=== RUN TestGCTaskStore_PhaseUpdates650=== PAUSE TestGCTaskStore_PhaseUpdates651=== RUN TestGCTaskStore_Fail652=== PAUSE TestGCTaskStore_Fail653=== RUN TestGracefulShutdownDrainsInflight654=== PAUSE TestGracefulShutdownDrainsInflight655=== RUN TestService_healthCheckHandler656=== PAUSE TestService_healthCheckHandler657=== RUN TestService_readinessHandler658=== PAUSE TestService_readinessHandler659=== RUN TestGenerateLandingPage660=== PAUSE TestGenerateLandingPage661=== RUN TestCacheConfigHandlerMaxNarSize662=== PAUSE TestCacheConfigHandlerMaxNarSize663=== RUN TestCreatePendingClosureRejectsOversizedNAR664=== PAUSE TestCreatePendingClosureRejectsOversizedNAR665=== RUN TestNARDeduplicationMetadataUploadBug666=== PAUSE TestNARDeduplicationMetadataUploadBug667=== RUN TestMetricsInventory668=== PAUSE TestMetricsInventory669=== RUN TestService_NativeMTLS670=== PAUSE TestService_NativeMTLS671=== RUN TestServerTLSConfig672=== PAUSE TestServerTLSConfig673=== RUN TestMultipartCleanup674=== PAUSE TestMultipartCleanup675=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded676=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded677=== RUN TestPendingCleanupUsesOneCutoff678=== PAUSE TestPendingCleanupUsesOneCutoff679=== RUN TestPendingClosureFailureTracksEveryUpload680=== PAUSE TestPendingClosureFailureTracksEveryUpload681=== RUN TestPendingClosureFailureAbortsItsUploads682=== PAUSE TestPendingClosureFailureAbortsItsUploads683=== RUN TestObjectStatsTrigger684=== PAUSE TestObjectStatsTrigger685=== RUN TestReconnectLeavesObjectsUnlocked686=== PAUSE TestReconnectLeavesObjectsUnlocked687=== RUN TestValidateS3Concurrency688=== PAUSE TestValidateS3Concurrency689=== RUN TestOrphanedObjectsGC690=== PAUSE TestOrphanedObjectsGC691=== RUN TestOrphanedObjectsGCStressTest692=== PAUSE TestOrphanedObjectsGCStressTest693=== RUN TestCreatePin_ReservedPins694=== PAUSE TestCreatePin_ReservedPins695=== RUN TestConcurrentPinUpdatesAgree696=== PAUSE TestConcurrentPinUpdatesAgree697=== RUN TestCreatePinRejectsBadInput698=== PAUSE TestCreatePinRejectsBadInput699=== RUN TestDeletePinKeepsRowWhenS3Fails700=== PAUSE TestDeletePinKeepsRowWhenS3Fails701=== RUN TestPresentReportsOnlyClosureRoots702=== PAUSE TestPresentReportsOnlyClosureRoots703=== RUN TestPresentNotReportedWhileGCDeletesClosure704=== PAUSE TestPresentNotReportedWhileGCDeletesClosure705=== RUN TestParseSingleRange706=== PAUSE TestParseSingleRange707=== RUN TestProxyHeadersOnlyTrustedOnSocket708=== PAUSE TestProxyHeadersOnlyTrustedOnSocket709=== RUN TestIsValidCachePath710=== PAUSE TestIsValidCachePath711=== RUN TestReadProxyNarinfo712=== PAUSE TestReadProxyNarinfo713=== RUN TestReadProxyNarinfoAlreadyDecompressed714=== PAUSE TestReadProxyNarinfoAlreadyDecompressed715=== RUN TestReadProxyNarStreaming716=== PAUSE TestReadProxyNarStreaming717=== RUN TestReadProxy404718=== PAUSE TestReadProxy404719=== RUN TestReadProxyInvalidPath720=== PAUSE TestReadProxyInvalidPath721=== RUN TestReadProxyHead722=== PAUSE TestReadProxyHead723=== RUN TestReadProxyOutlastsServerWriteTimeout724=== PAUSE TestReadProxyOutlastsServerWriteTimeout725=== RUN TestReadProxyConditionalGet726=== PAUSE TestReadProxyConditionalGet727=== RUN TestReadProxyRootRedirectsToIndexHTML728=== PAUSE TestReadProxyRootRedirectsToIndexHTML729=== RUN TestReadProxyDisabled730=== PAUSE TestReadProxyDisabled731=== RUN TestReadRedirectNar732=== PAUSE TestReadRedirectNar733=== RUN TestReadRedirectKeepsNarinfoProxied734=== PAUSE TestReadRedirectKeepsNarinfoProxied735=== RUN TestReadProxyRangeRequest736=== PAUSE TestReadProxyRangeRequest737=== RUN TestReadRedirectUsesPublicS3URL738=== PAUSE TestReadRedirectUsesPublicS3URL739=== RUN TestPush_OverlappingRootsStoreOneRowPerKey740=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey741=== RUN TestPush_CompleteCommitsEveryRoot742=== PAUSE TestPush_CompleteCommitsEveryRoot743=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit744=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit745=== RUN TestPush_RejectsBadRequests746=== PAUSE TestPush_RejectsBadRequests747=== RUN TestPush_SignsNarinfosOfItsPendingObjects748=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects749=== RUN TestRedundantMultipartUpload750=== PAUSE TestRedundantMultipartUpload751=== RUN TestCompleteMultipartUpload_ErrorButObjectExists752=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists753=== RUN TestCompletedNarNotReofferedAcrossClosures754=== PAUSE TestCompletedNarNotReofferedAcrossClosures755=== RUN TestPresignedUploadRegisteredBeforeCommit756=== PAUSE TestPresignedUploadRegisteredBeforeCommit757=== RUN TestService_Rustfstest758=== PAUSE TestService_Rustfstest759=== RUN TestParseSize760=== PAUSE TestParseSize761=== RUN TestSkippedUploadsHandler762=== PAUSE TestSkippedUploadsHandler763=== RUN TestSystemdListenerNotActivated764--- PASS: TestSystemdListenerNotActivated (0.00s)765=== RUN TestWatchdogBeatsWhenHealthy766--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)767=== RUN TestWatchdogSkipsWhenUnhealthy7682026/10/01 09:22:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/01 09:22:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/01 09:22:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/01 09:22:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/01 09:22:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/01 09:22:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/01 09:22:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/10/01 09:22:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7762026/10/01 09:22:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7772026/10/01 09:22:25 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"778--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)779=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle780=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle781=== RUN TestProxyWriteTimeout782=== PAUSE TestProxyWriteTimeout783=== RUN TestPendingClosureWriteTimeout784=== PAUSE TestPendingClosureWriteTimeout785=== RUN TestIsValidUploadKey786=== PAUSE TestIsValidUploadKey787=== RUN TestUploadHandlersRejectInvalidKeys788=== PAUSE TestUploadHandlersRejectInvalidKeys789=== RUN TestUploadHandlersRejectOversizedBody790=== PAUSE TestUploadHandlersRejectOversizedBody791=== RUN TestService_cleanupPendingClosuresHandler792=== PAUSE TestService_cleanupPendingClosuresHandler793=== RUN TestService_createPendingClosureHandler794=== PAUSE TestService_createPendingClosureHandler795=== RUN TestService_verifyS3Integrity796=== PAUSE TestService_verifyS3Integrity797=== RUN TestCompleteMultipartUnregistered798=== PAUSE TestCompleteMultipartUnregistered799=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT800=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT801=== CONT TestSkippedUploadsHandler802=== CONT TestParseSize803=== CONT TestGCTaskStore_GetReturnsLatest804=== CONT TestReadProxyHead805=== CONT TestService_ReadAuthMiddleware806=== CONT TestCreatePin_ReservedPins807=== CONT TestConcurrentPinUpdatesAgree808=== CONT TestDeletePinKeepsRowWhenS3Fails809=== CONT TestReconnectLeavesObjectsUnlocked810=== CONT TestValidateS3Concurrency811=== CONT TestReadRedirectUsesPublicS3URL812=== CONT TestReadProxyConditionalGet813=== CONT TestPendingClosureFailureAbortsItsUploads814=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection815=== CONT TestReadProxyRootRedirectsToIndexHTML816=== CONT TestReadProxyInvalidPath817=== CONT TestTombstonedObjectOfferedWithoutWaiting818=== CONT TestReadProxyNarStreaming819=== CONT TestPendingClosureFailureTracksEveryUpload820=== CONT TestGCSweepSkipsPendingObjects821=== CONT TestReadProxy404822=== CONT TestGCTaskStore_PhaseUpdates823=== CONT TestDeduplicatedObjectsRecordedAsPending824=== CONT TestService_NativeMTLS825=== CONT TestReadProxyNarinfoAlreadyDecompressed826=== CONT TestOrphanedObjectsGC827=== CONT TestConnectWaitsForAPeerMigration828--- PASS: TestParseSize (0.00s)829--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)830=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock831--- PASS: TestValidateS3Concurrency (0.00s)832--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)8332026/10/01 09:22:25 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000834=== CONT TestResolveDBConnectionString835--- PASS: TestSkippedUploadsHandler (0.04s)836=== RUN TestResolveDBConnectionString/flag_wins837=== PAUSE TestResolveDBConnectionString/flag_wins838=== RUN TestResolveDBConnectionString/file_when_flag_empty839=== PAUSE TestResolveDBConnectionString/file_when_flag_empty840=== RUN TestResolveDBConnectionString/missing_file_is_an_error841=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error842=== RUN TestResolveDBConnectionString/PGHOST_allows_empty843=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty844=== RUN TestResolveDBConnectionString/nothing_configured845=== PAUSE TestResolveDBConnectionString/nothing_configured846=== CONT TestClientPushesUseOnePush8472026/10/01 09:22:25 INFO Received create pin request method=POST path=/api/pins/app8482026/10/01 09:22:25 INFO Received create pin request method=POST path=/api/pins/app849=== CONT TestPresentReportsOnlyClosureRoots850--- PASS: TestService_ReadAuthMiddleware (0.28s)8512026/10/01 09:22:25 INFO Received create pin request method=POST path=/api/pins/app852=== CONT TestServerTLSConfig853=== RUN TestServerTLSConfig/no_client_CA854--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.29s)855=== PAUSE TestServerTLSConfig/no_client_CA856=== RUN TestServerTLSConfig/missing_CA_file857=== PAUSE TestServerTLSConfig/missing_CA_file858=== RUN TestServerTLSConfig/not_a_PEM_file859=== PAUSE TestServerTLSConfig/not_a_PEM_file860=== CONT TestMetricsInventory8612026/10/01 09:22:25 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo8622026/10/01 09:22:25 INFO Received delete pin request method=DELETE path=/api/pins/app8632026/10/01 09:22:25 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket7/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"8642026/10/01 09:22:25 INFO Received delete pin request method=DELETE path=/api/pins/app8652026/10/01 09:22:25 INFO Deleted pin name=app866=== CONT TestGCTaskStore_Fail867--- PASS: TestReadProxyInvalidPath (0.32s)868=== CONT TestGracefulShutdownDrainsInflight869--- PASS: TestGCTaskStore_Fail (0.00s)8702026/10/01 09:22:25 INFO Starting HTTP server address=127.0.0.1:380238712026/10/01 09:22:25 INFO Shutdown signal received, draining in-flight requests timeout=10s872=== CONT TestSweepSkipsRowsLockedByPush873--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.33s)8742026/10/01 09:22:25 INFO Received uploads request method=POST path=/api/pending_closures8752026/10/01 09:22:25 INFO Aborted multipart uploads count=0 kept=08762026/10/01 09:22:25 WARN Force mode enabled - objects will be deleted immediately without grace period8772026/10/01 09:22:25 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=08782026/10/01 09:22:25 INFO Vacuumed table table=pending_closures8792026/10/01 09:22:25 INFO Vacuumed table table=pending_objects8802026/10/01 09:22:25 INFO Vacuumed table table=multipart_uploads8812026/10/01 09:22:25 INFO Vacuumed table table=closures8822026/10/01 09:22:25 INFO Vacuumed table table=objects8832026/10/01 09:22:25 INFO Received uploads request method=POST path=/api/pending_closures884--- PASS: TestGracefulShutdownDrainsInflight (0.07s)885=== CONT TestReadProxyOutlastsServerWriteTimeout886--- PASS: TestGCSweepSkipsPendingObjects (0.40s)887=== CONT TestPushDedupSurvivesConcurrentGC888=== CONT TestObjectStatsTrigger889--- PASS: TestReadRedirectUsesPublicS3URL (0.41s)8902026/10/01 09:22:25 INFO Received uploads request method=POST path=/api/pending_closures891--- PASS: TestPendingClosureFailureAbortsItsUploads (0.43s)892=== CONT TestGCBugBareHashReferences8932026/10/01 09:22:25 INFO Received uploads request method=POST path=/api/pending_closures894--- PASS: TestReconnectLeavesObjectsUnlocked (0.44s)895=== CONT TestReadProxyNarinfo8962026/10/01 09:22:25 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35775/oidc897=== CONT TestGCTaskStore_CompletedAllowsNewTask898--- PASS: TestReadProxyConditionalGet (0.46s)899=== CONT TestIsValidCachePath900--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)901=== RUN TestIsValidCachePath/narinfo902=== PAUSE TestIsValidCachePath/narinfo903=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars904=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars905=== RUN TestIsValidCachePath/nar_zst906=== PAUSE TestIsValidCachePath/nar_zst907=== RUN TestIsValidCachePath/nar_xz9082026/10/01 09:22:25 WARN mTLS auth: subject not in bound subjects subject="CN=reader"909=== PAUSE TestIsValidCachePath/nar_xz910=== RUN TestIsValidCachePath/nar_bz2911=== PAUSE TestIsValidCachePath/nar_bz2912=== RUN TestIsValidCachePath/nar_uncompressed9132026/10/01 09:22:25 WARN mTLS auth: subject not in bound subjects subject="CN=reader"914=== PAUSE TestIsValidCachePath/nar_uncompressed915=== RUN TestIsValidCachePath/ls916=== PAUSE TestIsValidCachePath/ls917=== RUN TestIsValidCachePath/log918=== PAUSE TestIsValidCachePath/log919=== RUN TestIsValidCachePath/realisation920=== PAUSE TestIsValidCachePath/realisation921=== RUN TestIsValidCachePath/nix-cache-info922=== PAUSE TestIsValidCachePath/nix-cache-info923=== RUN TestIsValidCachePath/index.html924=== PAUSE TestIsValidCachePath/index.html925=== RUN TestIsValidCachePath/traversal_parent926=== PAUSE TestIsValidCachePath/traversal_parent927=== RUN TestIsValidCachePath/traversal_in_middle928=== PAUSE TestIsValidCachePath/traversal_in_middle929=== RUN TestIsValidCachePath/invalid_char_e930=== PAUSE TestIsValidCachePath/invalid_char_e931=== RUN TestIsValidCachePath/invalid_char_u932=== PAUSE TestIsValidCachePath/invalid_char_u933=== RUN TestIsValidCachePath/random_path934=== PAUSE TestIsValidCachePath/random_path935=== RUN TestIsValidCachePath/empty936=== PAUSE TestIsValidCachePath/empty937=== RUN TestIsValidCachePath/leading_slash938=== PAUSE TestIsValidCachePath/leading_slash939=== RUN TestIsValidCachePath/wrong_extension940=== PAUSE TestIsValidCachePath/wrong_extension941=== RUN TestIsValidCachePath/short_hash942=== PAUSE TestIsValidCachePath/short_hash943=== CONT TestCreatePendingClosureRejectsOversizedNAR9442026/10/01 09:22:25 INFO Received uploads request method=POST path=/api/pending_closures945--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)946=== CONT TestGCAdvisoryLockBlocksConcurrentRun947--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.46s)948=== CONT TestParseSingleRange949=== RUN TestParseSingleRange/none950=== PAUSE TestParseSingleRange/none951=== RUN TestParseSingleRange/unknown_unit952=== PAUSE TestParseSingleRange/unknown_unit953=== RUN TestParseSingleRange/multi-range_ignored954=== PAUSE TestParseSingleRange/multi-range_ignored955=== RUN TestParseSingleRange/malformed_no_dash956=== PAUSE TestParseSingleRange/malformed_no_dash957=== RUN TestParseSingleRange/malformed_both_empty958=== PAUSE TestParseSingleRange/malformed_both_empty959=== RUN TestParseSingleRange/malformed_end_before_start960=== PAUSE TestParseSingleRange/malformed_end_before_start961=== RUN TestParseSingleRange/closed962=== PAUSE TestParseSingleRange/closed963=== RUN TestParseSingleRange/open-ended964=== PAUSE TestParseSingleRange/open-ended965=== RUN TestParseSingleRange/end_clamped_to_size966=== PAUSE TestParseSingleRange/end_clamped_to_size967=== RUN TestParseSingleRange/suffix968=== PAUSE TestParseSingleRange/suffix969=== RUN TestParseSingleRange/suffix_exceeds_size970=== PAUSE TestParseSingleRange/suffix_exceeds_size971=== RUN TestParseSingleRange/single_byte972=== PAUSE TestParseSingleRange/single_byte973=== RUN TestParseSingleRange/start_past_EOF974=== PAUSE TestParseSingleRange/start_past_EOF975=== RUN TestParseSingleRange/start_far_past_EOF976=== PAUSE TestParseSingleRange/start_far_past_EOF977=== CONT TestGCMetrics978--- PASS: TestReadProxyHead (0.47s)979=== CONT TestPendingCleanupUsesOneCutoff980--- PASS: TestService_NativeMTLS (0.48s)981=== CONT TestLeadElectsOneAndHandsOver982--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.52s)983=== CONT TestProxyHeadersOnlyTrustedOnSocket9842026/10/01 09:22:26 INFO Received uploads request method=POST path=/api/pending_closures985=== CONT TestMultipartCleanup986--- PASS: TestReadProxyNarStreaming (0.59s)987=== CONT TestConnectSerialisesConcurrentMigrations988--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.65s)9892026/10/01 09:22:26 INFO Received uploads request method=POST path=/api/pending_closures990--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.67s)991=== CONT TestPresentNotReportedWhileGCDeletesClosure992=== CONT TestLeadEndsOnShutdown993--- PASS: TestPresentReportsOnlyClosureRoots (0.42s)9942026-10-01 09:22:26.223 UTC [636] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"9952026-10-01 09:22:26.223 UTC [636] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.9962026-10-01 09:22:26.223 UTC [636] STATEMENT: CREATE TABLE goose_db_version (997 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,998 version_id bigint NOT NULL,999 is_applied boolean NOT NULL,1000 tstamp timestamp NOT NULL DEFAULT now()1001 )10022026/10/01 09:22:26 INFO Aborted multipart uploads count=0 kept=010032026/10/01 09:22:26 WARN Force mode enabled - objects will be deleted immediately without grace period10042026/10/01 09:22:26 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=010052026/10/01 09:22:26 INFO Vacuumed table table=pending_closures10062026/10/01 09:22:26 INFO Vacuumed table table=pending_objects10072026/10/01 09:22:26 INFO Vacuumed table table=multipart_uploads10082026/10/01 09:22:26 INFO Vacuumed table table=closures10092026/10/01 09:22:26 INFO Vacuumed table table=objects10102026/10/01 09:22:26 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo10112026/10/01 09:22:26 INFO Aborted multipart uploads count=0 kept=01012=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1013--- PASS: TestMetricsInventory (0.46s)10142026/10/01 09:22:26 WARN Force mode enabled - objects will be deleted immediately without grace period10152026/10/01 09:22:26 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo10162026/10/01 09:22:26 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=010172026/10/01 09:22:26 INFO Received uploads request method=POST path=/api/pending_closures10182026/10/01 09:22:26 INFO Vacuumed table table=pending_closures10192026/10/01 09:22:26 INFO Vacuumed table table=pending_objects10202026/10/01 09:22:26 INFO Vacuumed table table=multipart_uploads10212026/10/01 09:22:26 INFO Vacuumed table table=closures10222026/10/01 09:22:26 INFO Vacuumed table table=objects1023--- PASS: TestConcurrentPinUpdatesAgree (0.78s)1024=== CONT TestCacheConfigHandlerMaxNarSize1025--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1026=== CONT TestNARDeduplicationMetadataUploadBug1027=== CONT TestClientFallsBackToClosures1028--- PASS: TestSweepSkipsRowsLockedByPush (0.46s)10292026/10/01 09:22:26 WARN Rate limiter enabled after throttle name=s3-test rate=510302026/10/01 09:22:26 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."1031--- PASS: TestObjectStatsTrigger (0.40s)1032=== CONT TestService_readinessHandler10332026/10/01 09:22:26 INFO Received push request method=POST path=/api/pushes10342026/10/01 09:22:26 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10352026/10/01 09:22:26 INFO Uploading 6npa3yrzalwkkfl0ph82cvd31f8yl8xs-shared-dep (136B)10362026/10/01 09:22:26 INFO Uploading m0lxhj30wk2n7f633mlv9069k1qq2320-a (216B)10372026/10/01 09:22:26 INFO Aborted multipart uploads count=0 kept=010382026/10/01 09:22:26 WARN Failed to register uploaded object key=m4rr6vj4s3vhf4p25jpv5aqadg5d2ibd.ls error="server returned 404: 404 page not found\n"10392026/10/01 09:22:26 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=010402026/10/01 09:22:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10412026/10/01 09:22:26 INFO Vacuumed table table=pending_closures10422026/10/01 09:22:26 WARN Failed to register uploaded object key=nar/0y1alcgq1jxj8c9c3zsqivcnyjccz6vs725cnxyjnakcsyb55mgm.nar.zst error="server returned 404: 404 page not found\n"10432026/10/01 09:22:26 WARN Failed to register uploaded object key=6npa3yrzalwkkfl0ph82cvd31f8yl8xs.ls error="server returned 404: 404 page not found\n"10442026/10/01 09:22:26 INFO Vacuumed table table=pending_objects10452026/10/01 09:22:26 INFO Vacuumed table table=multipart_uploads10462026/10/01 09:22:26 INFO Vacuumed table table=closures10472026/10/01 09:22:26 WARN Failed to register uploaded object key=m0lxhj30wk2n7f633mlv9069k1qq2320.ls error="server returned 404: 404 page not found\n"10482026/10/01 09:22:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10492026/10/01 09:22:26 INFO Vacuumed table table=objects10502026/10/01 09:22:26 INFO Signed narinfos id=1 count=310512026/10/01 09:22:26 INFO Uploading 3 narinfos10522026/10/01 09:22:26 INFO Aborted multipart uploads count=0 kept=010532026/10/01 09:22:26 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10542026/10/01 09:22:26 WARN Refused reserved pin name=worker-x86_64-linux10552026/10/01 09:22:26 WARN Failed to register uploaded object key=m4rr6vj4s3vhf4p25jpv5aqadg5d2ibd.narinfo error="server returned 404: 404 page not found\n"10562026/10/01 09:22:26 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10572026/10/01 09:22:26 WARN Force mode enabled - objects will be deleted immediately without grace period10582026/10/01 09:22:26 INFO Received create pin request method=POST path=/api/pins/my-app10592026/10/01 09:22:26 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux10602026/10/01 09:22:26 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=010612026/10/01 09:22:26 WARN Failed to register uploaded object key=m0lxhj30wk2n7f633mlv9069k1qq2320.narinfo error="server returned 404: 404 page not found\n"10622026/10/01 09:22:26 WARN Failed to register uploaded object key=6npa3yrzalwkkfl0ph82cvd31f8yl8xs.narinfo error="server returned 404: 404 page not found\n"10632026/10/01 09:22:26 INFO Received complete push request method=POST path=/api/pushes/1/complete10642026/10/01 09:22:26 INFO Vacuumed table table=pending_closures10652026/10/01 09:22:26 INFO Vacuumed table table=pending_objects10662026/10/01 09:22:26 INFO Vacuumed table table=multipart_uploads10672026/10/01 09:22:26 INFO Vacuumed table table=closures10682026/10/01 09:22:26 INFO Vacuumed table table=objects10692026/10/01 09:22:26 INFO Upload complete. (104ms)10702026/10/01 09:22:26 INFO Aborted multipart uploads count=0 kept=010712026/10/01 09:22:26 WARN Force mode enabled - objects will be deleted immediately without grace period1072=== NAME TestClientPushesUseOnePush1073 client_pushes_test.go:97: Retrieved narinfo from S3:1074 StorePath: /build/TestClientPushesUseOnePush2506832353/001/store/6npa3yrzalwkkfl0ph82cvd31f8yl8xs-shared-dep1075 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1076 Compression: zstd1077 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821078 NarSize: 1361079 References: 1080 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n10812026/10/01 09:22:26 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=01082--- PASS: TestCreatePin_ReservedPins (0.90s)1083=== CONT TestService_healthCheckHandler10842026/10/01 09:22:26 INFO Received uploads request method=POST path=/api/pending_closures10852026/10/01 09:22:26 INFO Vacuumed table table=pending_closures10862026/10/01 09:22:26 INFO Vacuumed table table=pending_objects10872026/10/01 09:22:26 INFO Vacuumed table table=multipart_uploads1088=== NAME TestClientPushesUseOnePush1089 client_pushes_test.go:97: Retrieved narinfo from S3:1090 StorePath: /build/TestClientPushesUseOnePush2506832353/001/store/m0lxhj30wk2n7f633mlv9069k1qq2320-a1091 URL: nar/0y1alcgq1jxj8c9c3zsqivcnyjccz6vs725cnxyjnakcsyb55mgm.nar.zst1092 Compression: zstd1093 NarHash: sha256:0y1alcgq1jxj8c9c3zsqivcnyjccz6vs725cnxyjnakcsyb55mgm1094 NarSize: 2161095 References: /build/TestClientPushesUseOnePush2506832353/001/store/6npa3yrzalwkkfl0ph82cvd31f8yl8xs-shared-dep1096 CA: text:sha256:1svispacav2l62q6a7bd2mm5s1kdhrxrrydvpa7aih3x6fdr7f5q10972026/10/01 09:22:26 INFO Vacuumed table table=closures10982026/10/01 09:22:26 INFO Vacuumed table table=objects1099--- PASS: TestPushDedupSurvivesConcurrentGC (0.51s)1100=== CONT TestClientSharedPathCommittedMidPush1101=== NAME TestClientPushesUseOnePush1102 client_pushes_test.go:97: Retrieved narinfo from S3:1103 StorePath: /build/TestClientPushesUseOnePush2506832353/001/store/m4rr6vj4s3vhf4p25jpv5aqadg5d2ibd-b1104 URL: nar/0y1alcgq1jxj8c9c3zsqivcnyjccz6vs725cnxyjnakcsyb55mgm.nar.zst1105 Compression: zstd1106 NarHash: sha256:0y1alcgq1jxj8c9c3zsqivcnyjccz6vs725cnxyjnakcsyb55mgm1107 NarSize: 2161108 References: /build/TestClientPushesUseOnePush2506832353/001/store/6npa3yrzalwkkfl0ph82cvd31f8yl8xs-shared-dep1109 CA: text:sha256:1svispacav2l62q6a7bd2mm5s1kdhrxrrydvpa7aih3x6fdr7f5q11102026/10/01 09:22:26 INFO lead: acquired remote=192.0.2.1:123411112026/10/01 09:22:26 INFO Received uploads request method=POST path=/api/pending_closures1112--- PASS: TestClientPushesUseOnePush (0.91s)1113=== CONT TestPinProtectsFromGC11142026/10/01 09:22:26 INFO Received cleanup request method=DELETE path=/api/pending_closures11152026/10/01 09:22:26 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket3747100545/001/proxy.sock11162026/10/01 09:22:26 INFO Starting HTTP server address=127.0.0.1:4169911172026/10/01 09:22:26 WARN mTLS auth: subject not in bound subjects subject="CN=someone"1118=== NAME TestOrphanedObjectsGC1119 orphaned_objects_gc_test.go:290: GC Test Summary:1120 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1121 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1122 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1123 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1124 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects11252026/10/01 09:22:26 INFO Shutdown signal received, draining in-flight requests timeout=10s1126=== CONT TestClientMultipleUploads1127--- PASS: TestGCMetrics (0.49s)1128--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.45s)1129=== CONT TestClientWithDependencies11302026/10/01 09:22:26 INFO Received uploads request method=POST path=/api/pending_closures1131=== CONT TestGenerateLandingPage1132--- PASS: TestOrphanedObjectsGC (0.96s)11332026/10/01 09:22:26 WARN Rate limiter backed off name=s3-test rate=511342026/10/01 09:22:26 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1135--- PASS: TestReadProxy404 (0.99s)1136=== CONT TestClientErrorHandling1137=== RUN TestClientErrorHandling/InvalidStorePath1138=== PAUSE TestClientErrorHandling/InvalidStorePath1139=== RUN TestClientErrorHandling/InvalidAuthToken1140=== PAUSE TestClientErrorHandling/InvalidAuthToken1141=== RUN TestClientErrorHandling/ServerNotAvailable1142=== PAUSE TestClientErrorHandling/ServerNotAvailable1143=== CONT TestUploadHandlersRejectOversizedBody1144=== CONT TestCreatePinRejectsBadInput1145--- PASS: TestGenerateLandingPage (0.03s)11462026/10/01 09:22:26 INFO lead: acquired remote=192.0.2.1:123411472026/10/01 09:22:26 INFO Received uploads request method=POST path=/api/pending_closures1148--- PASS: TestGCBugBareHashReferences (0.62s)1149=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1150=== CONT TestUploadHandlersRejectInvalidKeys1151=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1152--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.32s)1153=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1154=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1155=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1156=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1157=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1158=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1159=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1160=== CONT TestClientCADerivations11612026/10/01 09:22:26 WARN readiness check failed error="closed pool"11622026/10/01 09:22:26 INFO Received cleanup request method=DELETE path=/api/pending_closures1163=== NAME TestNARDeduplicationMetadataUploadBug1164 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug372677122/001/store/y7zz9yyy84bmx9gvqjpxcgnfzpfcl7iw-file1.txt11652026/10/01 09:22:26 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket39/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11662026/10/01 09:22:26 INFO Aborted multipart uploads count=0 kept=111672026/10/01 09:22:26 INFO Received cleanup request method=DELETE path=/api/pending_closures11682026/10/01 09:22:26 INFO Aborted multipart uploads count=1 kept=01169=== CONT TestIsValidUploadKey1170--- PASS: TestService_readinessHandler (0.31s)1171=== RUN TestIsValidUploadKey/narinfo1172=== PAUSE TestIsValidUploadKey/narinfo1173=== RUN TestIsValidUploadKey/nar_zst1174=== PAUSE TestIsValidUploadKey/nar_zst1175=== RUN TestIsValidUploadKey/nar_xz1176=== PAUSE TestIsValidUploadKey/nar_xz1177=== RUN TestIsValidUploadKey/nar_plain1178=== PAUSE TestIsValidUploadKey/nar_plain1179=== RUN TestIsValidUploadKey/listing1180=== PAUSE TestIsValidUploadKey/listing1181=== RUN TestIsValidUploadKey/build_log1182=== PAUSE TestIsValidUploadKey/build_log1183=== RUN TestIsValidUploadKey/build_log_home-manager_file1184=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1185=== RUN TestIsValidUploadKey/build_log_plus_in_name1186=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1187=== RUN TestIsValidUploadKey/build_log_question_mark1188=== PAUSE TestIsValidUploadKey/build_log_question_mark1189=== RUN TestIsValidUploadKey/build_log_equals1190=== PAUSE TestIsValidUploadKey/build_log_equals1191=== RUN TestIsValidUploadKey/realisation1192=== PAUSE TestIsValidUploadKey/realisation1193=== RUN TestIsValidUploadKey/realisation_plus_in_output1194=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1195=== RUN TestIsValidUploadKey/nix-cache-info1196=== PAUSE TestIsValidUploadKey/nix-cache-info1197=== RUN TestIsValidUploadKey/index.html1198=== PAUSE TestIsValidUploadKey/index.html1199=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1200=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1201=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1202=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1203=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1204=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1205=== RUN TestIsValidUploadKey/traversal1206=== PAUSE TestIsValidUploadKey/traversal1207=== RUN TestIsValidUploadKey/traversal_nar1208=== PAUSE TestIsValidUploadKey/traversal_nar1209=== RUN TestIsValidUploadKey/absolute1210=== PAUSE TestIsValidUploadKey/absolute1211=== RUN TestIsValidUploadKey/empty_key1212=== PAUSE TestIsValidUploadKey/empty_key1213=== RUN TestIsValidUploadKey/unknown_type1214=== PAUSE TestIsValidUploadKey/unknown_type1215=== CONT TestService_Rustfstest12162026/10/01 09:22:26 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"1217--- PASS: TestPendingClosureFailureTracksEveryUpload (1.12s)1218=== CONT TestCacheConfigHandler1219=== RUN TestCacheConfigHandler/full_config,_no_issuer1220=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1221=== RUN TestCacheConfigHandler/no_cache_url_configured1222=== PAUSE TestCacheConfigHandler/no_cache_url_configured1223=== RUN TestCacheConfigHandler/no_signing_keys1224=== PAUSE TestCacheConfigHandler/no_signing_keys1225=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1226=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1227=== CONT TestOrphanedObjectsGCStressTest1228--- PASS: TestMultipartCleanup (0.54s)1229=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1230--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.69s)1231=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1232--- PASS: TestService_healthCheckHandler (0.26s)1233=== CONT TestPresignedUploadRegisteredBeforeCommit12342026/10/01 09:22:26 INFO Received push request method=POST path=/api/pushes12352026/10/01 09:22:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12362026/10/01 09:22:26 INFO Uploading y7zz9yyy84bmx9gvqjpxcgnfzpfcl7iw-file1.txt (160B)12372026/10/01 09:22:26 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12382026/10/01 09:22:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12392026/10/01 09:22:26 WARN Failed to register uploaded object key=y7zz9yyy84bmx9gvqjpxcgnfzpfcl7iw.ls error="server returned 404: 404 page not found\n"12402026/10/01 09:22:26 INFO Signed narinfos id=1 count=112412026/10/01 09:22:26 INFO Uploading 1 narinfos12422026/10/01 09:22:26 INFO Received complete push request method=POST path=/api/pushes/1/complete12432026/10/01 09:22:26 WARN Failed to register uploaded object key=y7zz9yyy84bmx9gvqjpxcgnfzpfcl7iw.narinfo error="server returned 404: 404 page not found\n"12442026/10/01 09:22:26 INFO Upload complete. (90ms)1245=== NAME TestNARDeduplicationMetadataUploadBug1246 metadata_upload_test.go:54: Retrieved narinfo from S3:1247 StorePath: /build/TestNARDeduplicationMetadataUploadBug372677122/001/store/y7zz9yyy84bmx9gvqjpxcgnfzpfcl7iw-file1.txt1248 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1249 Compression: zstd1250 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1251 NarSize: 1601252 References: 1253 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1254 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1255 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1256 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1257 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug372677122/001/store/nw4y33ly482z52sx4r81xrf5dcgkmdbk-file2.txt1258=== NAME TestPinProtectsFromGC1259 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC2016511476/001/store/25cnrq42racgplppq84ni48rj6fd7ajv-pinned-file.txt1260 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC2016511476/001/store/xa6dqhm3blwfz5vq0102dz74kackh47a-unpinned-file.txt12612026/10/01 09:22:26 INFO Received uploads request method=POST path=/api/pending_closures12622026/10/01 09:22:26 INFO Received create pin request method=POST path=/api/pins/deploy12632026/10/01 09:22:26 INFO Received create pin request method=POST path=/api/pins/deploy12642026/10/01 09:22:26 INFO Received create pin request method=POST path=/api/pins/deploy12652026/10/01 09:22:26 INFO Received create pin request method=POST path=/api/pins/deploy12662026/10/01 09:22:26 INFO Received create pin request method=POST path=/api/pins/deploy12672026/10/01 09:22:26 INFO Received create pin request method=POST path=/api/pins/deploy12682026/10/01 09:22:26 INFO Received create pin request method=POST path=/api/pins/deploy12692026/10/01 09:22:26 INFO Received create pin request method=POST path=/api/pins/deploy1270=== NAME TestClientMultipleUploads1271 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads437991896/001/store/i3qgzmdkrs4g3qqa9bah5nmrvj9j5n89-test-file-0.txt12722026/10/01 09:22:26 INFO Received uploads request method=POST path=/api/pending_closures12732026/10/01 09:22:26 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)12742026/10/01 09:22:26 INFO Uploading zvwwkry3pr9spn66fxb49mcv7wbrq6mm-shared-dep (136B)12752026/10/01 09:22:26 INFO Uploading 9j3h3yxpx93g8ajgmi515hc1h8qc98xh-b (216B)12762026/10/01 09:22:26 INFO Received push request method=POST path=/api/pushes12772026/10/01 09:22:26 INFO Received create pin request method=POST path=/api/pins/deploy1278 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads437991896/001/store/i3wpjfjz5qixm2clc53zfmswi85i9vbd-test-file-1.txt12792026/10/01 09:22:26 INFO Received push request method=POST path=/api/pushes12802026/10/01 09:22:26 INFO Received push request method=POST path=/api/pushes12812026/10/01 09:22:26 INFO Received push request method=POST path=/api/pushes12822026/10/01 09:22:26 WARN Failed to register uploaded object key=9f3qvkhx2lsjsljnd19d15galpr582jd.ls error="server returned 404: 404 page not found\n"12832026/10/01 09:22:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12842026/10/01 09:22:26 WARN Failed to register uploaded object key=nar/0lzhh6fgk5fhxfniavnavmmgi4izibkz6xv4z89iy1jznvwfids8.nar.zst error="server returned 404: 404 page not found\n"12852026/10/01 09:22:26 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12862026/10/01 09:22:26 WARN Failed to register uploaded object key=zvwwkry3pr9spn66fxb49mcv7wbrq6mm.ls error="server returned 404: 404 page not found\n"12872026/10/01 09:22:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12882026/10/01 09:22:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign12892026/10/01 09:22:26 INFO Uploading 25cnrq42racgplppq84ni48rj6fd7ajv-pinned-file.txt (128B)12902026/10/01 09:22:26 WARN Failed to register uploaded object key=9j3h3yxpx93g8ajgmi515hc1h8qc98xh.ls error="server returned 404: 404 page not found\n"12912026/10/01 09:22:26 INFO Signed narinfos id=2 count=21292=== NAME TestClientWithDependencies1293 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies3929157999/001/store/d43h066raaxjs2y6y1ranppsspx8b3sz-test-script12942026/10/01 09:22:26 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12952026/10/01 09:22:26 INFO Uploading 8n1mip17ansy051pzk8mcmq2r4ngwl9a-shared-dep (136B)12962026/10/01 09:22:26 INFO Uploading zb15vis5cjgkfz1y9f3s58bjkw84b60k-top (224B)12972026/10/01 09:22:26 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign12982026/10/01 09:22:26 INFO Signed narinfos id=1 count=212992026/10/01 09:22:26 INFO Uploading 4 narinfos13002026/10/01 09:22:26 WARN Failed to register uploaded object key=nw4y33ly482z52sx4r81xrf5dcgkmdbk.ls error="server returned 404: 404 page not found\n"13012026/10/01 09:22:26 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13022026/10/01 09:22:26 INFO Signed narinfos id=2 count=113032026/10/01 09:22:26 INFO Uploading 1 narinfos13042026/10/01 09:22:26 WARN Failed to register uploaded object key=nar/0x9a7mmxl94nj0psql9dhx2rvszrhnbyjl78c8lgnm09lg66xxxa.nar.zst error="server returned 404: 404 page not found\n"1305=== NAME TestClientMultipleUploads1306 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads437991896/001/store/lx0bmb30wh587l4vmrvqmp333sxnafl5-test-file-2.txt13072026/10/01 09:22:26 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13082026/10/01 09:22:26 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"13092026/10/01 09:22:26 WARN Failed to register uploaded object key=zb15vis5cjgkfz1y9f3s58bjkw84b60k.ls error="server returned 404: 404 page not found\n"13102026/10/01 09:22:26 WARN Failed to register uploaded object key=8n1mip17ansy051pzk8mcmq2r4ngwl9a.ls error="server returned 404: 404 page not found\n"13112026/10/01 09:22:26 WARN Failed to register uploaded object key=zvwwkry3pr9spn66fxb49mcv7wbrq6mm.narinfo error="server returned 404: 404 page not found\n"13122026/10/01 09:22:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13132026/10/01 09:22:26 WARN Failed to register uploaded object key=9f3qvkhx2lsjsljnd19d15galpr582jd.narinfo error="server returned 404: 404 page not found\n"13142026/10/01 09:22:26 WARN Failed to register uploaded object key=25cnrq42racgplppq84ni48rj6fd7ajv.ls error="server returned 404: 404 page not found\n"13152026/10/01 09:22:26 WARN Failed to register uploaded object key=9j3h3yxpx93g8ajgmi515hc1h8qc98xh.narinfo error="server returned 404: 404 page not found\n"13162026/10/01 09:22:26 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13172026/10/01 09:22:26 INFO Received complete push request method=POST path=/api/pushes/2/complete13182026/10/01 09:22:26 INFO Signed narinfos id=1 count=213192026/10/01 09:22:26 INFO Signed narinfos id=1 count=113202026/10/01 09:22:26 WARN Failed to register uploaded object key=nw4y33ly482z52sx4r81xrf5dcgkmdbk.narinfo error="server returned 404: 404 page not found\n"13212026/10/01 09:22:26 INFO Uploading 2 narinfos13222026/10/01 09:22:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete13232026/10/01 09:22:26 INFO Uploading 1 narinfos13242026/10/01 09:22:26 WARN Failed to register uploaded object key=zvwwkry3pr9spn66fxb49mcv7wbrq6mm.narinfo error="server returned 404: 404 page not found\n"13252026/10/01 09:22:26 INFO Upload complete. (64ms)1326=== NAME TestNARDeduplicationMetadataUploadBug1327 metadata_upload_test.go:76: Retrieved narinfo from S3:1328 StorePath: /build/TestNARDeduplicationMetadataUploadBug372677122/001/store/nw4y33ly482z52sx4r81xrf5dcgkmdbk-file2.txt1329 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1330 Compression: zstd1331 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1332 NarSize: 1601333 References: 1334 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf13352026/10/01 09:22:26 INFO Completed upload id=113362026/10/01 09:22:26 INFO Received complete push request method=POST path=/api/pushes/1/complete13372026/10/01 09:22:26 WARN Failed to register uploaded object key=8n1mip17ansy051pzk8mcmq2r4ngwl9a.narinfo error="server returned 404: 404 page not found\n"13382026/10/01 09:22:26 WARN Failed to register uploaded object key=25cnrq42racgplppq84ni48rj6fd7ajv.narinfo error="server returned 404: 404 page not found\n"13392026/10/01 09:22:26 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete13402026/10/01 09:22:26 INFO Completed upload id=213412026/10/01 09:22:26 INFO Upload complete. (132ms)13422026/10/01 09:22:26 INFO Received complete push request method=POST path=/api/pushes/1/complete13432026/10/01 09:22:26 WARN Failed to register uploaded object key=zb15vis5cjgkfz1y9f3s58bjkw84b60k.narinfo error="server returned 404: 404 page not found\n"1344=== NAME TestClientFallsBackToClosures1345 client_pushes_test.go:112: Retrieved narinfo from S3:1346 StorePath: /build/TestClientFallsBackToClosures2651033413/001/store/zvwwkry3pr9spn66fxb49mcv7wbrq6mm-shared-dep1347 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1348 Compression: zstd1349 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821350 NarSize: 1361351 References: 1352 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1353=== NAME TestNARDeduplicationMetadataUploadBug1354 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1355 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1356 {"version":1,"root":{"type":"regular","size":44}}13572026/10/01 09:22:26 INFO Upload complete. (71ms)1358=== NAME TestClientFallsBackToClosures1359 client_pushes_test.go:112: Retrieved narinfo from S3:1360 StorePath: /build/TestClientFallsBackToClosures2651033413/001/store/9f3qvkhx2lsjsljnd19d15galpr582jd-a1361 URL: nar/0lzhh6fgk5fhxfniavnavmmgi4izibkz6xv4z89iy1jznvwfids8.nar.zst1362 Compression: zstd1363 NarHash: sha256:0lzhh6fgk5fhxfniavnavmmgi4izibkz6xv4z89iy1jznvwfids81364 NarSize: 2161365 References: /build/TestClientFallsBackToClosures2651033413/001/store/zvwwkry3pr9spn66fxb49mcv7wbrq6mm-shared-dep1366 CA: text:sha256:18fgn3l1hpv5wgmf5vqijnmrl7b46s1hk1hfw1klyz290m31md1n13672026/10/01 09:22:26 INFO Upload complete. (76ms)1368=== NAME TestClientSharedPathCommittedMidPush1369 client_integration_test.go:816: Retrieved narinfo from S3:1370 StorePath: /build/TestClientSharedPathCommittedMidPush2828073334/001/store/8n1mip17ansy051pzk8mcmq2r4ngwl9a-shared-dep1371 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1372 Compression: zstd1373 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821374 NarSize: 1361375 References: 1376 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1377=== NAME TestClientWithDependencies1378 client_integration_test.go:737: Found 1 dependencies (including self)1379=== NAME TestClientFallsBackToClosures1380 client_pushes_test.go:112: Retrieved narinfo from S3:1381 StorePath: /build/TestClientFallsBackToClosures2651033413/001/store/9j3h3yxpx93g8ajgmi515hc1h8qc98xh-b1382 URL: nar/0lzhh6fgk5fhxfniavnavmmgi4izibkz6xv4z89iy1jznvwfids8.nar.zst1383 Compression: zstd1384 NarHash: sha256:0lzhh6fgk5fhxfniavnavmmgi4izibkz6xv4z89iy1jznvwfids81385 NarSize: 2161386 References: /build/TestClientFallsBackToClosures2651033413/001/store/zvwwkry3pr9spn66fxb49mcv7wbrq6mm-shared-dep1387 CA: text:sha256:18fgn3l1hpv5wgmf5vqijnmrl7b46s1hk1hfw1klyz290m31md1n1388=== NAME TestClientSharedPathCommittedMidPush1389 client_integration_test.go:816: Retrieved narinfo from S3:1390 StorePath: /build/TestClientSharedPathCommittedMidPush2828073334/001/store/zb15vis5cjgkfz1y9f3s58bjkw84b60k-top1391 URL: nar/0x9a7mmxl94nj0psql9dhx2rvszrhnbyjl78c8lgnm09lg66xxxa.nar.zst1392 Compression: zstd1393 NarHash: sha256:0x9a7mmxl94nj0psql9dhx2rvszrhnbyjl78c8lgnm09lg66xxxa1394 NarSize: 2241395 References: /build/TestClientSharedPathCommittedMidPush2828073334/001/store/8n1mip17ansy051pzk8mcmq2r4ngwl9a-shared-dep1396 CA: text:sha256:1yvc81001fjskbyxrm6ddndhfs2z4amw6jv701ik01s6md8pcrfj1397--- PASS: TestNARDeduplicationMetadataUploadBug (0.62s)1398=== CONT TestCompleteMultipartUnregistered13992026/10/01 09:22:26 INFO Received uploads request method=POST path=/api/pending_closures1400--- PASS: TestClientSharedPathCommittedMidPush (0.50s)1401=== CONT TestCompletedNarNotReofferedAcrossClosures1402=== CONT TestService_verifyS3Integrity1403--- PASS: TestClientFallsBackToClosures (0.62s)1404=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1405=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1406=== NAME TestClientCADerivations1407 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations3250021139/001/store/pv8xq8vazwmrrp9442rlxqmavf4b314n-ca-test1408=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1409=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1410=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1411=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1412=== CONT TestCompleteMultipartUpload_ErrorButObjectExists14132026/10/01 09:22:26 INFO Received push request method=POST path=/api/pushes14142026/10/01 09:22:26 INFO Received push request method=POST path=/api/pushes14152026/10/01 09:22:26 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14162026/10/01 09:22:26 INFO Uploading xa6dqhm3blwfz5vq0102dz74kackh47a-unpinned-file.txt (128B)14172026/10/01 09:22:26 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"14182026/10/01 09:22:26 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14192026/10/01 09:22:26 INFO Uploading lx0bmb30wh587l4vmrvqmp333sxnafl5-test-file-2.txt (160B)14202026/10/01 09:22:26 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"14212026/10/01 09:22:26 INFO Uploading i3wpjfjz5qixm2clc53zfmswi85i9vbd-test-file-1.txt (160B)14222026/10/01 09:22:26 INFO Uploading i3qgzmdkrs4g3qqa9bah5nmrvj9j5n89-test-file-0.txt (160B)14232026/10/01 09:22:26 WARN Failed to register uploaded object key=xa6dqhm3blwfz5vq0102dz74kackh47a.ls error="server returned 404: 404 page not found\n"14242026/10/01 09:22:26 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign14252026/10/01 09:22:26 INFO Signed narinfos id=2 count=114262026/10/01 09:22:26 INFO Uploading 1 narinfos1427--- PASS: TestService_Rustfstest (0.38s)1428=== CONT TestService_createPendingClosureHandler14292026/10/01 09:22:26 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"14302026/10/01 09:22:26 WARN mTLS auth: bound subjects configured but subject DN unavailable14312026/10/01 09:22:26 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"1432=== NAME TestClientCADerivations1433 client_ca_test.go:139: Found 1 dependencies (including self)14342026/10/01 09:22:26 INFO Received complete push request method=POST path=/api/pushes/2/complete14352026/10/01 09:22:26 WARN Failed to register uploaded object key=xa6dqhm3blwfz5vq0102dz74kackh47a.narinfo error="server returned 404: 404 page not found\n"14362026/10/01 09:22:26 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14372026/10/01 09:22:26 INFO Received push request method=POST path=/api/pushes14382026/10/01 09:22:27 INFO Upload complete. (100ms)14392026/10/01 09:22:27 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14402026/10/01 09:22:27 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"1441--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.36s)1442=== CONT TestPush_SignsNarinfosOfItsPendingObjects14432026/10/01 09:22:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)14442026/10/01 09:22:27 INFO Uploading d43h066raaxjs2y6y1ranppsspx8b3sz-test-script (136B)14452026/10/01 09:22:27 WARN Failed to register uploaded object key=lx0bmb30wh587l4vmrvqmp333sxnafl5.ls error="server returned 404: 404 page not found\n"14462026/10/01 09:22:27 WARN Failed to register uploaded object key=i3wpjfjz5qixm2clc53zfmswi85i9vbd.ls error="server returned 404: 404 page not found\n"14472026/10/01 09:22:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14482026/10/01 09:22:27 WARN Failed to register uploaded object key=i3qgzmdkrs4g3qqa9bah5nmrvj9j5n89.ls error="server returned 404: 404 page not found\n"14492026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures14502026/10/01 09:22:27 INFO Signed narinfos id=1 count=314512026/10/01 09:22:27 INFO Uploading 3 narinfos14522026/10/01 09:22:27 WARN Failed to register uploaded object key=d43h066raaxjs2y6y1ranppsspx8b3sz.ls error="server returned 404: 404 page not found\n"14532026/10/01 09:22:27 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"14542026/10/01 09:22:27 WARN Failed to register uploaded object key=log/inp44dkbfjj6ch8nmx48va9xy0plmqrs-test-script.drv error="server returned 404: 404 page not found\n"14552026/10/01 09:22:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14562026/10/01 09:22:27 INFO Signed narinfos id=1 count=11457=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1458--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.86s)14592026/10/01 09:22:27 INFO Uploading 1 narinfos14602026/10/01 09:22:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures14612026/10/01 09:22:27 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst14622026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures14632026/10/01 09:22:27 INFO Garbage collection started14642026/10/01 09:22:27 WARN Failed to register uploaded object key=lx0bmb30wh587l4vmrvqmp333sxnafl5.narinfo error="server returned 404: 404 page not found\n"14652026/10/01 09:22:27 INFO Received complete push request method=POST path=/api/pushes/1/complete14662026/10/01 09:22:27 WARN Failed to register uploaded object key=i3qgzmdkrs4g3qqa9bah5nmrvj9j5n89.narinfo error="server returned 404: 404 page not found\n"14672026/10/01 09:22:27 WARN Failed to register uploaded object key=i3wpjfjz5qixm2clc53zfmswi85i9vbd.narinfo error="server returned 404: 404 page not found\n"14682026/10/01 09:22:27 INFO Received complete push request method=POST path=/api/pushes/1/complete14692026/10/01 09:22:27 WARN Failed to register uploaded object key=d43h066raaxjs2y6y1ranppsspx8b3sz.narinfo error="server returned 404: 404 page not found\n"14702026/10/01 09:22:27 INFO Aborted multipart uploads count=0 kept=014712026/10/01 09:22:27 INFO Upload complete. (180ms)1472=== NAME TestClientMultipleUploads1473 client_integration_test.go:491: Uploaded 3 paths in 216.542079ms14742026/10/01 09:22:27 INFO Upload complete. (158ms)14752026/10/01 09:22:27 WARN Force mode enabled - objects will be deleted immediately without grace period1476=== CONT TestPush_RejectsBadRequests1477--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.42s)14782026/10/01 09:22:27 INFO Aborted multipart uploads count=0 kept=014792026/10/01 09:22:27 WARN Force mode enabled - objects will be deleted immediately without grace period14802026/10/01 09:22:27 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=014812026/10/01 09:22:27 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=014822026/10/01 09:22:27 INFO Vacuumed table table=pending_closures14832026/10/01 09:22:27 INFO Vacuumed table table=pending_closures14842026/10/01 09:22:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14852026/10/01 09:22:27 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst14862026/10/01 09:22:27 INFO Vacuumed table table=pending_objects14872026/10/01 09:22:27 INFO Vacuumed table table=pending_objects14882026/10/01 09:22:27 INFO Vacuumed table table=multipart_uploads14892026/10/01 09:22:27 INFO Vacuumed table table=multipart_uploads14902026/10/01 09:22:27 INFO Vacuumed table table=closures14912026/10/01 09:22:27 INFO Vacuumed table table=closures14922026/10/01 09:22:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete14932026/10/01 09:22:27 INFO Vacuumed table table=objects14942026/10/01 09:22:27 INFO Vacuumed table table=objects1495=== NAME TestClientWithDependencies1496 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies3929157999/001/store) requires matching store prefix1497--- PASS: TestClientMultipleUploads (0.67s)1498=== CONT TestService_cleanupPendingClosuresHandler1499--- PASS: TestCompleteMultipartUnregistered (0.23s)1500=== CONT TestRedundantMultipartUpload15012026/10/01 09:22:27 INFO Received push request method=POST path=/api/pushes1502--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.63s)1503=== CONT TestPendingClosureWriteTimeout1504=== RUN TestPendingClosureWriteTimeout/empty1505=== PAUSE TestPendingClosureWriteTimeout/empty1506=== RUN TestPendingClosureWriteTimeout/negative1507=== PAUSE TestPendingClosureWriteTimeout/negative1508=== RUN TestPendingClosureWriteTimeout/400_objects1509=== PAUSE TestPendingClosureWriteTimeout/400_objects1510=== RUN TestPendingClosureWriteTimeout/670k_objects1511=== PAUSE TestPendingClosureWriteTimeout/670k_objects1512=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1513=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1514=== CONT TestGCSweepDeliversEachKeyOnce15152026/10/01 09:22:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15162026/10/01 09:22:27 INFO Uploading pv8xq8vazwmrrp9442rlxqmavf4b314n-ca-test (144B)15172026/10/01 09:22:27 WARN Failed to register uploaded object key=log/bbc398js2spx82yv22nqf5fql89jydmh-ca-test.drv error="server returned 404: 404 page not found\n"15182026/10/01 09:22:27 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"1519=== CONT TestCacheStatsHandler1520--- PASS: TestClientWithDependencies (0.68s)15212026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures15222026/10/01 09:22:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15232026/10/01 09:22:27 WARN Failed to register uploaded object key=pv8xq8vazwmrrp9442rlxqmavf4b314n.ls error="server returned 404: 404 page not found\n"15242026/10/01 09:22:27 INFO Signed narinfos id=1 count=115252026/10/01 09:22:27 INFO Uploading 1 narinfos15262026/10/01 09:22:27 INFO Received complete push request method=POST path=/api/pushes/1/complete15272026/10/01 09:22:27 WARN Failed to register uploaded object key=pv8xq8vazwmrrp9442rlxqmavf4b314n.narinfo error="server returned 404: 404 page not found\n"15282026/10/01 09:22:27 INFO Upload complete. (119ms)15292026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures1530=== NAME TestClientCADerivations1531 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations3250021139/001/store/pv8xq8vazwmrrp9442rlxqmavf4b314n-ca-test1532 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1533 Compression: zstd1534 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1535 NarSize: 1441536 References: 1537 Deriver: /build/TestClientCADerivations3250021139/001/store/bbc398js2spx82yv22nqf5fql89jydmh-ca-test.drv1538 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1539 client_ca_test.go:185: Checking for realisation files in S3...1540 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1541 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache15422026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures15432026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures15442026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures15452026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures15462026/10/01 09:22:27 INFO Received push request method=POST path=/api/pushes15472026/10/01 09:22:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15482026/10/01 09:22:27 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LjZjMjM3ZDlhLTkwNTgtNGEwNS05MGM4LTNlMTM3MTk3MjdhM3gxNzkwODQ2NTQ3MTg5MDU4ODA31549--- PASS: TestConnectSerialisesConcurrentMigrations (1.10s)1550=== CONT TestService_AuthMiddleware15512026/10/01 09:22:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15522026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures15532026/10/01 09:22:27 INFO Signed narinfos id=1 count=11554=== NAME TestClientCADerivations1555 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1556 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1557 error: binary cache 's3://bucket54?endpoint=http://localhost:39841®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations3250021139/001/store'1558 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 115592026/10/01 09:22:27 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LjZjMjM3ZDlhLTkwNTgtNGEwNS05MGM4LTNlMTM3MTk3MjdhM3gxNzkwODQ2NTQ3MTg5MDU4ODA3 error="Delete \"http://localhost:39841/bucket63/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LjZjMjM3ZDlhLTkwNTgtNGEwNS05MGM4LTNlMTM3MTk3MjdhM3gxNzkwODQ2NTQ3MTg5MDU4ODA3\": injected: abort refused"15602026/10/01 09:22:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1561=== CONT TestReadProxyDisabled1562--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (0.26s)15632026/10/01 09:22:27 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LjZjMjM3ZDlhLTkwNTgtNGEwNS05MGM4LTNlMTM3MTk3MjdhM3gxNzkwODQ2NTQ3MTg5MDU4ODA31564=== RUN TestPush_RejectsBadRequests/root_not_in_objects1565=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1566=== RUN TestPush_RejectsBadRequests/no_roots1567=== PAUSE TestPush_RejectsBadRequests/no_roots1568=== RUN TestPush_RejectsBadRequests/no_objects1569=== PAUSE TestPush_RejectsBadRequests/no_objects1570=== RUN TestPush_RejectsBadRequests/bad_root1571=== PAUSE TestPush_RejectsBadRequests/bad_root1572=== CONT TestPush_CompleteCommitsEveryRoot1573=== CONT TestReadRedirectNar1574--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.25s)15752026/10/01 09:22:27 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LjZjMjM3ZDlhLTkwNTgtNGEwNS05MGM4LTNlMTM3MTk3MjdhM3gxNzkwODQ2NTQ3MTg5MDU4ODA3 parts=11576--- PASS: TestClientCADerivations (0.71s)1577=== CONT TestService_AuthMiddleware_MTLSProxyHeader15782026/10/01 09:22:27 INFO Received cleanup request method=DELETE path=/api/pending_closures15792026/10/01 09:22:27 INFO Aborted multipart uploads count=0 kept=01580--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (0.33s)1581=== CONT TestSweepRechecksPendingAfterLocking15822026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures15832026/10/01 09:22:27 INFO Received cleanup request method=DELETE path=/api/pending_closures15842026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures15852026/10/01 09:22:27 INFO Aborted multipart uploads count=1 kept=015862026/10/01 09:22:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15872026-10-01 09:22:27.323 UTC [1506] ERROR: Closure does not exist: id=115882026-10-01 09:22:27.323 UTC [1506] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE15892026-10-01 09:22:27.323 UTC [1506] STATEMENT: -- name: CommitPendingClosure :exec1590 SELECT commit_pending_closure($1::bigint)1591 15922026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures1593=== CONT TestGCTaskStore_ConflictDifferentParams1594=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1595--- PASS: TestService_cleanupPendingClosuresHandler (0.22s)1596--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)15972026/10/01 09:22:27 INFO Aborted multipart uploads count=0 kept=015982026/10/01 09:22:27 WARN Force mode enabled - objects will be deleted immediately without grace period1599--- PASS: TestCacheStatsHandler (0.25s)1600=== CONT TestGCEndsOnShutdown1601=== RUN TestGCEndsOnShutdown/before_the_run1602=== PAUSE TestGCEndsOnShutdown/before_the_run1603=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1604=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1605=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1606=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1607=== CONT TestClientIntegration16082026/10/01 09:22:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete16092026/10/01 09:22:27 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=016102026/10/01 09:22:27 INFO Vacuumed table table=pending_closures16112026/10/01 09:22:27 INFO Vacuumed table table=pending_objects16122026/10/01 09:22:27 INFO Vacuumed table table=multipart_uploads16132026/10/01 09:22:27 INFO Vacuumed table table=closures16142026/10/01 09:22:27 INFO Vacuumed table table=objects16152026/10/01 09:22:27 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"16162026/10/01 09:22:27 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LmY1ZDA3NjQ1LTc1NjktNGJiMi05ZjViLTk5OGMwZGY0ZjE4YngxNzkwODQ2NTQ2ODM0OTAyNTY5 parts=101617--- PASS: TestGCSweepDeliversEachKeyOnce (0.30s)1618=== CONT TestReadProxyRangeRequest1619=== CONT TestGCTaskStore_StartNew1620--- PASS: TestService_AuthMiddleware (0.19s)1621=== CONT TestReadRedirectKeepsNarinfoProxied1622--- PASS: TestGCTaskStore_StartNew (0.00s)16232026/10/01 09:22:27 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772161624--- PASS: TestReadProxyDisabled (0.19s)1625=== CONT TestService_ReadScope_PublicByDefault16262026/10/01 09:22:27 INFO Received push request method=POST path=/api/pushes1627=== CONT TestGCTaskStore_GetEmpty1628=== CONT TestRegisterCompletedObjectNeedsPendingRow1629--- PASS: TestReadProxyNarinfo (1.54s)1630--- PASS: TestGCTaskStore_GetEmpty (0.00s)1631--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.23s)1632=== CONT TestPushWaitsForSweepHoldingRow1633--- PASS: TestReadRedirectNar (0.27s)1634=== CONT TestService_AuthMiddleware_OIDC16352026/10/01 09:22:27 INFO lead: released remote=192.0.2.1:12341636--- PASS: TestLeadEndsOnShutdown (1.39s)1637=== CONT TestForceGCDuringPushOffersSweptObject1638=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1639=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1640=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1641=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1642=== CONT TestGetExistingObjectsLocksRows16432026/10/01 09:22:27 INFO Aborted multipart uploads count=0 kept=016442026/10/01 09:22:27 WARN Force mode enabled - objects will be deleted immediately without grace period16452026/10/01 09:22:27 INFO Received push request method=POST path=/api/pushes16462026/10/01 09:22:27 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=016472026/10/01 09:22:27 INFO Vacuumed table table=pending_closures16482026/10/01 09:22:27 INFO Vacuumed table table=pending_objects16492026/10/01 09:22:27 INFO Vacuumed table table=multipart_uploads16502026/10/01 09:22:27 INFO Vacuumed table table=closures16512026/10/01 09:22:27 INFO Vacuumed table table=objects16522026/10/01 09:22:27 INFO lead: released remote=192.0.2.1:12341653=== CONT TestFailedS3DeleteKeepsTombstone1654--- PASS: TestSweepRechecksPendingAfterLocking (0.33s)1655=== CONT TestGCTaskStore_DeduplicateSameParams16562026/10/01 09:22:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1657--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.30s)1658--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1659=== CONT TestCommitRacingPendingCleanupKeepsObjects16602026/10/01 09:22:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:39403/oidc16612026/10/01 09:22:27 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LmJlODZmYzMyLTUyMTYtNDBhYS1iYmVjLWE4OGI2NzQxZWE1MHgxNzkwODQ2NTQ3MTQ0ODgzNDk2 parts=1016622026/10/01 09:22:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16632026/10/01 09:22:27 INFO Completed upload id=11664=== NAME TestClientIntegration1665 client_integration_test.go:334: Created store path: /build/TestClientIntegration2968684663/002/store/yzhqp5j1j1wn3jrzv2gxndx2j1b9hic2-test-file.txt16662026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures16672026/10/01 09:22:27 INFO lead: acquired remote=192.0.2.1:123416682026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures1669--- PASS: TestReadProxyRangeRequest (0.25s)1670=== CONT TestProxyWriteTimeout1671=== RUN TestProxyWriteTimeout/narinfo1672=== PAUSE TestProxyWriteTimeout/narinfo1673=== RUN TestProxyWriteTimeout/1_GiB_nar1674=== PAUSE TestProxyWriteTimeout/1_GiB_nar1675=== RUN TestProxyWriteTimeout/10_GiB_nar1676=== PAUSE TestProxyWriteTimeout/10_GiB_nar1677=== RUN TestProxyWriteTimeout/unknown_size1678=== PAUSE TestProxyWriteTimeout/unknown_size1679=== CONT TestService_RequireScope_OIDC16802026/10/01 09:22:27 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo16812026/10/01 09:22:27 WARN Found objects in DB but missing from S3, will re-upload count=116822026/10/01 09:22:27 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete16832026/10/01 09:22:27 INFO Completed upload id=31684=== CONT TestResolveDBConnectionString/file_when_flag_empty1685--- PASS: TestService_ReadScope_PublicByDefault (0.24s)1686=== CONT TestResolveDBConnectionString/nothing_configured1687=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1688=== CONT TestResolveDBConnectionString/missing_file_is_an_error1689=== CONT TestResolveDBConnectionString/flag_wins1690=== CONT TestServerTLSConfig/no_client_CA1691=== CONT TestServerTLSConfig/not_a_PEM_file16922026/10/01 09:22:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1693=== CONT TestServerTLSConfig/missing_CA_file1694--- PASS: TestService_verifyS3Integrity (0.80s)1695=== CONT TestIsValidCachePath/narinfo1696=== CONT TestIsValidCachePath/index.html1697=== CONT TestIsValidCachePath/nix-cache-info1698=== CONT TestIsValidCachePath/realisation1699=== CONT TestIsValidCachePath/empty1700=== CONT TestIsValidCachePath/nar_uncompressed1701=== CONT TestIsValidCachePath/traversal_parent1702=== CONT TestIsValidCachePath/traversal_in_middle1703=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1704=== CONT TestIsValidCachePath/ls1705=== CONT TestIsValidCachePath/nar_bz21706=== CONT TestIsValidCachePath/log1707=== CONT TestIsValidCachePath/random_path1708=== CONT TestIsValidCachePath/invalid_char_e1709=== CONT TestIsValidCachePath/short_hash1710=== CONT TestIsValidCachePath/invalid_char_u1711=== CONT TestIsValidCachePath/wrong_extension1712=== CONT TestIsValidCachePath/nar_xz1713=== CONT TestIsValidCachePath/nar_zst1714=== CONT TestIsValidCachePath/leading_slash1715=== CONT TestParseSingleRange/unknown_unit1716--- PASS: TestIsValidCachePath (0.00s)1717 --- PASS: TestIsValidCachePath/narinfo (0.00s)1718 --- PASS: TestIsValidCachePath/index.html (0.00s)1719 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1720 --- PASS: TestIsValidCachePath/realisation (0.00s)1721 --- PASS: TestIsValidCachePath/empty (0.00s)1722 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1723 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1724 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1725 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1726 --- PASS: TestIsValidCachePath/ls (0.00s)1727 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1728 --- PASS: TestIsValidCachePath/log (0.00s)1729 --- PASS: TestIsValidCachePath/random_path (0.00s)1730 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1731 --- PASS: TestIsValidCachePath/short_hash (0.00s)1732 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1733 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1734 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1735 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1736 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1737=== CONT TestParseSingleRange/start_far_past_EOF1738=== CONT TestParseSingleRange/suffix_exceeds_size1739=== CONT TestParseSingleRange/single_byte1740=== CONT TestParseSingleRange/start_past_EOF1741=== CONT TestParseSingleRange/suffix1742=== CONT TestParseSingleRange/malformed_no_dash1743=== CONT TestParseSingleRange/end_clamped_to_size1744=== CONT TestParseSingleRange/malformed_end_before_start1745=== CONT TestParseSingleRange/malformed_both_empty1746=== CONT TestParseSingleRange/multi-range_ignored1747=== CONT TestParseSingleRange/none1748=== CONT TestParseSingleRange/open-ended1749=== CONT TestParseSingleRange/closed1750=== CONT TestClientErrorHandling/InvalidAuthToken1751--- PASS: TestParseSingleRange (0.00s)1752 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1753 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1754 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1755 --- PASS: TestParseSingleRange/single_byte (0.00s)1756 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1757 --- PASS: TestParseSingleRange/suffix (0.00s)1758 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1759 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1760 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1761 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1762 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1763 --- PASS: TestParseSingleRange/none (0.00s)1764 --- PASS: TestParseSingleRange/open-ended (0.00s)1765 --- PASS: TestParseSingleRange/closed (0.00s)17662026/10/01 09:22:27 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LjVhNWU1Njg2LWVlNGUtNDdmMy1iNDJiLWU0YTcxMGU1YmY1MHgxNzkwODQ2NTQ3MjIzNDQwNzky parts=1017672026/10/01 09:22:27 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete17682026/10/01 09:22:27 INFO Completed upload id=117692026/10/01 09:22:27 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000017702026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures1771--- PASS: TestResolveDBConnectionString (0.03s)1772 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1773 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1774 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1775 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1776 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1777=== CONT TestClientErrorHandling/InvalidStorePath1778--- PASS: TestServerTLSConfig (0.00s)1779 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1780 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1781 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.03s)17822026/10/01 09:22:27 INFO Starting cleanup of old closures method=DELETE path=/api/closures17832026/10/01 09:22:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17842026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures1785=== CONT TestClientErrorHandling/ServerNotAvailable1786--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.26s)17872026/10/01 09:22:27 INFO Aborted multipart uploads count=0 kept=01788--- PASS: TestReadRedirectKeepsNarinfoProxied (0.31s)17892026/10/01 09:22:27 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=01790=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17912026/10/01 09:22:27 INFO Received complete multipart upload request method=POST path=/1792=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17932026/10/01 09:22:27 INFO Received request for more parts method=POST path=/1794=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17952026/10/01 09:22:27 INFO Received uploads request method=POST path=/1796=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17972026/10/01 09:22:27 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46091/oidc17982026/10/01 09:22:27 INFO Received uploads request method=POST path=/1799=== CONT TestIsValidUploadKey/empty_key1800--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1801 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1802 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1803 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1804 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1805=== CONT TestIsValidUploadKey/narinfo1806=== CONT TestIsValidUploadKey/unknown_type1807=== CONT TestIsValidUploadKey/absolute1808=== CONT TestIsValidUploadKey/build_log_equals18092026/10/01 09:22:27 INFO Vacuumed table table=pending_closures1810=== CONT TestIsValidUploadKey/traversal_nar1811=== CONT TestIsValidUploadKey/traversal1812=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1813=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1814=== CONT TestIsValidUploadKey/index.html1815=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1816=== CONT TestIsValidUploadKey/realisation_plus_in_output1817=== CONT TestIsValidUploadKey/listing1818=== CONT TestIsValidUploadKey/nar_xz1819=== CONT TestIsValidUploadKey/nix-cache-info18202026/10/01 09:22:27 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LjY5OTRiOGU5LWQ3Y2QtNDdiMi05NjQyLTg3NDJhNTc5NGQzMXgxNzkwODQ2NTQ3MTc2MTY0OTkz parts=121821=== CONT TestIsValidUploadKey/nar_plain1822=== CONT TestIsValidUploadKey/build_log_plus_in_name1823=== CONT TestIsValidUploadKey/realisation1824=== CONT TestIsValidUploadKey/build_log_home-manager_file18252026/10/01 09:22:27 INFO Vacuumed table table=pending_objects1826=== CONT TestIsValidUploadKey/nar_zst1827=== CONT TestIsValidUploadKey/build_log_question_mark1828=== CONT TestIsValidUploadKey/build_log1829=== CONT TestCacheConfigHandler/full_config,_no_issuer1830--- PASS: TestIsValidUploadKey (0.00s)1831 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1832 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1833 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1834 --- PASS: TestIsValidUploadKey/absolute (0.00s)1835 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1836 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1837 --- PASS: TestIsValidUploadKey/traversal (0.00s)1838 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1839 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1840 --- PASS: TestIsValidUploadKey/index.html (0.00s)1841 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1842 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1843 --- PASS: TestIsValidUploadKey/listing (0.00s)1844 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1845 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1846 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1847 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1848 --- PASS: TestIsValidUploadKey/realisation (0.00s)1849 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1850 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1851 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1852 --- PASS: TestIsValidUploadKey/build_log (0.00s)1853=== CONT TestCacheConfigHandler/no_signing_keys1854=== CONT TestCacheConfigHandler/no_cache_url_configured18552026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures1856=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1857=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts1858--- PASS: TestCacheConfigHandler (0.00s)1859 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1860 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1861 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1862 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)18632026/10/01 09:22:27 INFO Received request for more parts method=POST path=/18642026/10/01 09:22:27 INFO Vacuumed table table=multipart_uploads18652026/10/01 09:22:27 INFO Vacuumed table table=closures18662026/10/01 09:22:27 INFO Vacuumed table table=objects18672026/10/01 09:22:27 INFO Received push request method=POST path=/api/pushes18682026/10/01 09:22:27 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18692026/10/01 09:22:27 INFO Uploading yzhqp5j1j1wn3jrzv2gxndx2j1b9hic2-test-file.txt (152B)1870--- PASS: TestCompletedNarNotReofferedAcrossClosures (0.87s)1871=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18722026/10/01 09:22:27 INFO Received uploads request method=POST path=/1873=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart1874--- PASS: TestGetExistingObjectsLocksRows (0.20s)18752026/10/01 09:22:27 INFO Received complete multipart upload request method=POST path=/18762026/10/01 09:22:27 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000018772026/10/01 09:22:27 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18782026/10/01 09:22:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18792026/10/01 09:22:27 WARN Failed to register uploaded object key=yzhqp5j1j1wn3jrzv2gxndx2j1b9hic2.ls error="server returned 404: 404 page not found\n"18802026/10/01 09:22:27 INFO Signed narinfos id=1 count=118812026/10/01 09:22:27 INFO Uploading 1 narinfos18822026/10/01 09:22:27 INFO Received complete push request method=POST path=/api/pushes/1/complete18832026/10/01 09:22:27 WARN Failed to register uploaded object key=yzhqp5j1j1wn3jrzv2gxndx2j1b9hic2.narinfo error="server returned 404: 404 page not found\n"1884=== CONT TestPendingClosureWriteTimeout/empty1885--- PASS: TestService_createPendingClosureHandler (0.81s)1886=== CONT TestPendingClosureWriteTimeout/400_objects1887=== CONT TestPendingClosureWriteTimeout/670k_objects1888=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline18892026/10/01 09:22:27 INFO Upload complete. (113ms)18902026/10/01 09:22:27 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1891=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1892=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1893=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1894=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1895=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1896=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1897=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1898=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1899=== CONT TestPendingClosureWriteTimeout/negative1900=== CONT TestPush_RejectsBadRequests/no_objects19012026/10/01 09:22:27 INFO Received push request method=POST path=/api/pushes1902=== CONT TestPush_RejectsBadRequests/bad_root19032026/10/01 09:22:27 INFO Received push request method=POST path=/api/pushes1904=== CONT TestPush_RejectsBadRequests/root_not_in_objects19052026/10/01 09:22:27 INFO Received push request method=POST path=/api/pushes1906=== CONT TestPush_RejectsBadRequests/no_roots19072026/10/01 09:22:27 INFO Received push request method=POST path=/api/pushes1908=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete19092026/10/01 09:22:27 INFO Received create pin request method=POST path=/api/pins/deploy19102026/10/01 09:22:27 INFO Aborted multipart uploads count=0 kept=019112026/10/01 09:22:27 WARN Force mode enabled - objects will be deleted immediately without grace period19122026/10/01 09:22:27 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo19132026/10/01 09:22:27 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=019142026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures19152026/10/01 09:22:27 INFO All 1 paths already cached19162026/10/01 09:22:27 INFO Vacuumed table table=pending_closures1917=== NAME TestClientIntegration1918 client_integration_test.go:360: Retrieved narinfo from S3:1919 StorePath: /build/TestClientIntegration2968684663/002/store/yzhqp5j1j1wn3jrzv2gxndx2j1b9hic2-test-file.txt1920 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1921 Compression: zstd1922 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11923 NarSize: 1521924 References: 1925 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk119262026/10/01 09:22:27 INFO Vacuumed table table=pending_objects19272026/10/01 09:22:27 INFO Vacuumed table table=multipart_uploads19282026/10/01 09:22:27 INFO Vacuumed table table=closures1929--- PASS: TestPush_RejectsBadRequests (0.23s)1930 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1931 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1932 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1933 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)19342026/10/01 09:22:27 INFO Vacuumed table table=objects1935=== NAME TestClientIntegration1936 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)1937 client_integration_test.go:361: Decompressed .ls content (64 bytes):1938 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}19392026/10/01 09:22:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1940=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1941--- PASS: TestCreatePinRejectsBadInput (1.37s)19422026/10/01 09:22:27 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LjFhMGI2ODRlLWY5ODYtNDNhMi05ZWQ1LWZkZmM0ZWNhODhiYngxNzkwODQ2NTQ2ODM0ODc5MDI5 parts=1019432026/10/01 09:22:27 INFO Received complete push request method=POST path=/api/pushes/1/complete19442026/10/01 09:22:27 INFO Received push request method=POST path=/api/pushes1945--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.25s)1946=== CONT TestGCEndsOnShutdown/before_the_run19472026/10/01 09:22:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19482026/10/01 09:22:27 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=213.317256ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19492026/10/01 09:22:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19502026/10/01 09:22:27 INFO Aborted multipart uploads count=0 kept=019512026/10/01 09:22:27 WARN Force mode enabled - objects will be deleted immediately without grace period19522026/10/01 09:22:27 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LmI4M2ZhYzc2LThjMGQtNDY4OC1hZTY0LTIxNmViZGY2OWVmNHgxNzkwODQ2NTQ3NDcxNzM3NTky parts=1019532026/10/01 09:22:27 INFO Received push request method=POST path=/api/pushes19542026/10/01 09:22:27 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LmMwMTNlN2JmLTZkZDAtNDQwNi1iMWU4LTU0ODM4YjllYjA3ZHgxNzkwODQ2NTQ3MzI2MzE5MTIz parts=1219552026/10/01 09:22:27 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."19562026/10/01 09:22:27 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."19572026/10/01 09:22:27 INFO Object in database but missing from S3 key=yzhqp5j1j1wn3jrzv2gxndx2j1b9hic2.ls19582026/10/01 09:22:27 WARN Found objects in DB but missing from S3, will re-upload count=119592026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures19602026/10/01 09:22:27 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19612026/10/01 09:22:27 WARN Failed to register uploaded object key=yzhqp5j1j1wn3jrzv2gxndx2j1b9hic2.ls error="server returned 404: 404 page not found\n"19622026/10/01 09:22:27 INFO Received complete push request method=POST path=/api/pushes/2/complete19632026/10/01 09:22:27 INFO Aborted multipart uploads count=0 kept=019642026/10/01 09:22:27 INFO Upload complete. (58ms)1965=== NAME TestClientIntegration1966 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)1967 client_integration_test.go:389: Decompressed .ls content (49 bytes):1968 {"version":1,"root":{"type":"regular","size":39}}19692026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures19702026/10/01 09:22:27 WARN Force mode enabled - objects will be deleted immediately without grace period1971--- PASS: TestFailedS3DeleteKeepsTombstone (0.33s)1972=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1973=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows19742026/10/01 09:22:27 INFO Received uploads request method=POST path=/api/pending_closures19752026/10/01 09:22:27 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=01976=== RUN TestService_RequireScope_OIDC/builder_may_write1977=== PAUSE TestService_RequireScope_OIDC/builder_may_write1978=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1979=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1980=== RUN TestService_RequireScope_OIDC/ops_may_admin1981=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1982=== RUN TestService_RequireScope_OIDC/ops_may_not_write1983=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1984=== RUN TestService_RequireScope_OIDC/reader_may_not_write1985=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1986=== RUN TestService_RequireScope_OIDC/static_token_may_admin1987=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1988=== RUN TestService_RequireScope_OIDC/static_token_may_write1989=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1990=== RUN TestService_RequireScope_OIDC/reader_may_read1991=== PAUSE TestService_RequireScope_OIDC/reader_may_read1992=== RUN TestService_RequireScope_OIDC/writer_implies_read1993=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1994=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1995=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1996=== CONT TestProxyWriteTimeout/unknown_size1997=== CONT TestProxyWriteTimeout/1_GiB_nar1998=== CONT TestProxyWriteTimeout/narinfo1999=== CONT TestProxyWriteTimeout/10_GiB_nar2000=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2001--- PASS: TestProxyWriteTimeout (0.00s)2002 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)2003 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)2004 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)2005 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)20062026/10/01 09:22:27 INFO Vacuumed table table=pending_closures20072026/10/01 09:22:27 INFO Vacuumed table table=pending_objects20082026/10/01 09:22:27 INFO Vacuumed table table=multipart_uploads2009=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20102026/10/01 09:22:27 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]2011=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20122026/10/01 09:22:27 INFO Vacuumed table table=closures20132026/10/01 09:22:27 WARN Authentication failed token_preview=eyJhbGciOi...0wQQfT-npA token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2014=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2015=== CONT TestService_RequireScope_OIDC/static_token_may_admin2016=== CONT TestService_RequireScope_OIDC/ops_may_not_write20172026/10/01 09:22:27 INFO Vacuumed table table=objects2018=== CONT TestService_RequireScope_OIDC/ops_may_admin2019=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2020=== CONT TestService_RequireScope_OIDC/reader_may_not_write2021=== CONT TestService_RequireScope_OIDC/reader_may_read2022=== CONT TestService_RequireScope_OIDC/builder_may_write2023=== CONT TestService_RequireScope_OIDC/static_token_may_write2024=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2025=== CONT TestService_RequireScope_OIDC/writer_implies_read20262026/10/01 09:22:27 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"2027--- PASS: TestService_AuthMiddleware_OIDC (0.30s)2028 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2029 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2030 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)2031 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)20322026/10/01 09:22:28 INFO Aborted multipart uploads count=0 kept=020332026/10/01 09:22:28 WARN Force mode enabled - objects will be deleted immediately without grace period2034--- PASS: TestService_RequireScope_OIDC (0.32s)2035 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2036 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2037 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2038 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2039 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2040 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2041 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2042 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2043 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2044 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)20452026/10/01 09:22:28 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:39841/bucket93/?delete=\": context canceled"20462026/10/01 09:22:28 INFO Received push request method=POST path=/api/pushes20472026/10/01 09:22:28 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20482026/10/01 09:22:28 INFO Aborted multipart uploads count=0 kept=020492026/10/01 09:22:28 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20502026/10/01 09:22:28 WARN Force mode enabled - objects will be deleted immediately without grace period20512026-10-01 09:22:28.042 UTC [2017] ERROR: canceling statement due to user request20522026-10-01 09:22:28.042 UTC [2017] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block20532026-10-01 09:22:28.042 UTC [2017] STATEMENT: -- name: MarkStaleObjects :execrows2054 WITH RECURSIVE ct AS (2055 SELECT timezone('UTC', now()) AS now2056 ),2057 closure_reach AS (2058 -- Start with all closure keys2059 SELECT o.key, o.refs2060 FROM objects o2061 INNER JOIN closures c ON o.key = c.key2062 UNION2063 -- Recursively add all referenced objects2064 SELECT o.key, o.refs2065 FROM objects o2066 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2067 ),2068 reachable_objects AS (2069 SELECT DISTINCT key FROM closure_reach2070 ),2071 stale_objects AS (2072 SELECT o.key2073 FROM objects AS o, ct2074 WHERE2075 NOT EXISTS (2076 SELECT 12077 FROM reachable_objects ro2078 WHERE ro.key = o.key2079 )2080 AND NOT EXISTS (2081 SELECT 12082 FROM pending_objects AS po2083 WHERE po.key = o.key2084 )2085 AND o.deleted_at IS NULL -- Only mark fresh objects2086 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2087 FOR UPDATE2088 )2089 UPDATE objects2090 SET2091 deleted_at = ct.now,2092 first_deleted_at = COALESCE(first_deleted_at, ct.now)2093 FROM stale_objects, ct2094 WHERE objects.key = stale_objects.key2095 20962026/10/01 09:22:28 INFO Received complete push request method=POST path=/api/pushes/3/complete20972026/10/01 09:22:28 WARN Failed to register uploaded object key=yzhqp5j1j1wn3jrzv2gxndx2j1b9hic2.ls error="server returned 404: 404 page not found\n"20982026/10/01 09:22:28 INFO Upload complete. (55ms)2099=== NAME TestClientIntegration2100 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)2101 client_integration_test.go:405: Decompressed .ls content (49 bytes):2102 {"version":1,"root":{"type":"regular","size":39}}2103--- PASS: TestGCEndsOnShutdown (0.00s)2104 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.21s)2105 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.20s)2106 --- PASS: TestGCEndsOnShutdown/before_the_run (0.23s)21072026/10/01 09:22:28 INFO Received uploads request method=POST path=/api/pending_closures21082026/10/01 09:22:28 INFO Aborted multipart uploads count=0 kept=021092026/10/01 09:22:28 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=361.89538ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21102026/10/01 09:22:28 WARN Force mode enabled - objects will be deleted immediately without grace period21112026/10/01 09:22:28 INFO Received uploads request method=POST path=/api/pending_closures21122026/10/01 09:22:28 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=021132026/10/01 09:22:28 INFO Vacuumed table table=pending_closures21142026/10/01 09:22:28 INFO Vacuumed table table=pending_objects21152026/10/01 09:22:28 INFO Vacuumed table table=multipart_uploads21162026/10/01 09:22:28 INFO Vacuumed table table=closures21172026/10/01 09:22:28 INFO Vacuumed table table=objects21182026/10/01 09:22:28 INFO Aborted multipart uploads count=0 kept=021192026/10/01 09:22:28 WARN Force mode enabled - objects will be deleted immediately without grace period21202026/10/01 09:22:28 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=021212026/10/01 09:22:28 INFO Vacuumed table table=pending_closures21222026/10/01 09:22:28 INFO Received push request method=POST path=/api/pushes21232026/10/01 09:22:28 INFO Vacuumed table table=pending_objects21242026/10/01 09:22:28 INFO Vacuumed table table=multipart_uploads21252026/10/01 09:22:28 INFO Vacuumed table table=closures21262026/10/01 09:22:28 INFO Vacuumed table table=objects21272026/10/01 09:22:28 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)21282026/10/01 09:22:28 INFO Uploading fxfs848lifkkdzc24hba8v64j1gn53vz-lost-commit.txt (152B)21292026/10/01 09:22:28 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"21302026/10/01 09:22:28 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign21312026/10/01 09:22:28 WARN Failed to register uploaded object key=fxfs848lifkkdzc24hba8v64j1gn53vz.ls error="server returned 404: 404 page not found\n"21322026/10/01 09:22:28 INFO Signed narinfos id=4 count=121332026/10/01 09:22:28 INFO Uploading 1 narinfos21342026/10/01 09:22:28 INFO Received complete push request method=POST path=/api/pushes/4/complete21352026/10/01 09:22:28 WARN Failed to register uploaded object key=fxfs848lifkkdzc24hba8v64j1gn53vz.narinfo error="server returned 404: 404 page not found\n"21362026/10/01 09:22:28 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:33443/api/pushes/4/complete\": EOF" url=http://127.0.0.1:33443/api/pushes/4/complete2137--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2138 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.23s)2139 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.24s)2140--- PASS: TestPushWaitsForSweepHoldingRow (0.74s)21412026/10/01 09:22:28 INFO Received complete push request method=POST path=/api/pushes/4/complete21422026-10-01 09:22:28.294 UTC [1678] ERROR: Push does not exist: id=421432026-10-01 09:22:28.294 UTC [1678] CONTEXT: PL/pgSQL function commit_push(bigint) line 9 at RAISE21442026-10-01 09:22:28.294 UTC [1678] STATEMENT: -- name: CommitPush :exec2145 SELECT commit_push($1::bigint)2146 21472026/10/01 09:22:28 INFO Upload complete. (174ms)2148=== NAME TestClientIntegration2149 client_integration_test.go:435: Retrieved narinfo from S3:2150 StorePath: /build/TestClientIntegration2968684663/002/store/fxfs848lifkkdzc24hba8v64j1gn53vz-lost-commit.txt2151 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst2152 Compression: zstd2153 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2154 NarSize: 1522155 References: 2156 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl2157 client_integration_test.go:438: Testing garbage collection...21582026/10/01 09:22:28 INFO Starting cleanup of old closures method=DELETE path=/api/closures21592026/10/01 09:22:28 INFO Garbage collection started21602026/10/01 09:22:28 INFO Aborted multipart uploads count=0 kept=021612026/10/01 09:22:28 WARN Force mode enabled - objects will be deleted immediately without grace period21622026/10/01 09:22:28 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=2 objects-marked-for-deletion=6 objects-deleted-after-grace-period=6 objects-failed-to-delete=021632026/10/01 09:22:28 INFO Vacuumed table table=pending_closures21642026/10/01 09:22:28 INFO Vacuumed table table=pending_objects21652026/10/01 09:22:28 INFO Vacuumed table table=multipart_uploads21662026/10/01 09:22:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21672026/10/01 09:22:28 INFO Vacuumed table table=closures21682026/10/01 09:22:28 INFO Vacuumed table table=objects21692026/10/01 09:22:28 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LmU3ZTQ2NTM0LTcyNDQtNGE1MS04OWU5LTQ1OGFhODk4MWVkOXgxNzkwODQ2NTQ3NDcxOTQ2MDkz parts=1021702026/10/01 09:22:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21712026/10/01 09:22:28 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LmE3ZWM0YWJmLTdhZDctNDAzZS1iZmQ3LWM4YWUwNTA5NjM3MHgxNzkwODQ2NTQ3ODg5NDYzNjMz parts=1021722026/10/01 09:22:28 INFO Received complete push request method=POST path=/api/pushes/2/complete2173--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (1.92s)21742026/10/01 09:22:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21752026/10/01 09:22:28 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LmY1NjNmMTI2LTFhZTktNDc3ZS1iYzM1LWE3OTQ1NjNjMjIzNXgxNzkwODQ2NTQ3OTYwMDcwOTM4 error="Get \"http://127.0.0.1:1/bucket69/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"21762026/10/01 09:22:28 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0Ljk2ZDAwOWViLWI2YzAtNDJmNi1hYjg0LTk5M2Q1MWY3NjE4YngxNzkwODQ2NTQ3OTQzNjc5ODMz parts=1221772026/10/01 09:22:28 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=851.113685ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21782026/10/01 09:22:28 INFO Received cleanup request method=DELETE path=/api/pending_closures21792026/10/01 09:22:28 INFO Aborted multipart uploads count=1 kept=02180--- PASS: TestRedundantMultipartUpload (1.40s)2181=== NAME TestOrphanedObjectsGCStressTest2182 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2183 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion21842026/10/01 09:22:28 INFO lead: released remote=192.0.2.1:12342185--- PASS: TestLeadElectsOneAndHandsOver (2.76s)2186--- PASS: TestPendingClosureWriteTimeout (0.00s)2187 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2188 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2189 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2190 --- PASS: TestPendingClosureWriteTimeout/negative (0.00s)2191 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (0.99s)21922026/10/01 09:22:28 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21932026/10/01 09:22:28 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=ZTJmYjE4N2UtM2I1Yi00MmFiLTk3OGYtYTE0NTE0YTQzN2U0LmE5OTJmZWFmLTNlMjEtNDIwNi1iOTQ1LTU0ODc0ZTE5ZDVhYngxNzkwODQ2NTQ3NDcxMDI2MDY1 parts=1021942026/10/01 09:22:28 INFO Received complete push request method=POST path=/api/pushes/1/complete2195--- PASS: TestPush_CompleteCommitsEveryRoot (1.57s)2196=== NAME TestOrphanedObjectsGCStressTest2197 orphaned_objects_gc_test.go:509: Stress test completed successfully:2198 orphaned_objects_gc_test.go:510: - Active objects preserved: 202199 orphaned_objects_gc_test.go:511: - Objects deleted: 2102200 orphaned_objects_gc_test.go:512: - Total GC'd: 2102201--- PASS: TestOrphanedObjectsGCStressTest (2.27s)22022026/10/01 09:22:29 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=022032026/10/01 09:22:29 INFO Received create pin request method=POST path=/api/pins/myapp22042026/10/01 09:22:29 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC2016511476/001/store/25cnrq42racgplppq84ni48rj6fd7ajv-pinned-file.txt narinfo_key=25cnrq42racgplppq84ni48rj6fd7ajv.narinfo22052026/10/01 09:22:29 INFO Starting cleanup of old closures method=DELETE path=/api/closures22062026/10/01 09:22:29 INFO Garbage collection started22072026/10/01 09:22:29 INFO Aborted multipart uploads count=0 kept=022082026/10/01 09:22:29 WARN Force mode enabled - objects will be deleted immediately without grace period22092026/10/01 09:22:29 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=022102026/10/01 09:22:29 INFO Vacuumed table table=pending_closures22112026/10/01 09:22:29 INFO Vacuumed table table=pending_objects22122026/10/01 09:22:29 INFO Vacuumed table table=multipart_uploads22132026/10/01 09:22:29 INFO Vacuumed table table=closures22142026/10/01 09:22:29 INFO Vacuumed table table=objects22152026/10/01 09:22:29 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.685243044s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present22162026/10/01 09:22:30 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02217=== NAME TestClientIntegration2218 client_integration_test.go:445: Objects in database after GC:2219 client_integration_test.go:445: Successfully deleted all objects with GC --force2220--- PASS: TestClientIntegration (2.97s)2221--- PASS: TestReadProxyOutlastsServerWriteTimeout (4.66s)22222026/10/01 09:22:30 WARN Rate limiter enabled after throttle name=s3-test rate=522232026/10/01 09:22:30 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2224=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2225 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102226 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002227--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (4.07s)2228--- PASS: TestConnectWaitsForAPeerMigration (5.25s)22292026/10/01 09:22:31 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2230=== NAME TestPinProtectsFromGC2231 client_integration_test.go:976: Pin successfully protected closure from garbage collection2232--- PASS: TestPinProtectsFromGC (4.65s)22332026/10/01 09:22:31 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=202.404324ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22342026/10/01 09:22:31 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=436.814473ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22352026/10/01 09:22:31 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=779.097161ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22362026/10/01 09:22:32 INFO Aborted multipart uploads count=1 kept=022372026/10/01 09:22:32 INFO Received cleanup request method=DELETE path=/api/pending_closures22382026/10/01 09:22:32 INFO Aborted multipart uploads count=1 kept=02239--- PASS: TestPendingCleanupUsesOneCutoff (6.51s)22402026/10/01 09:22:32 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.596432938s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22412026/10/01 09:22:34 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"22422026/10/01 09:22:34 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22432026/10/01 09:22:34 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=204.020076ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22442026/10/01 09:22:34 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=416.337553ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22452026/10/01 09:22:34 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=738.004959ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22462026/10/01 09:22:35 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.61676717s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22472026/10/01 09:22:37 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22482026/10/01 09:22:37 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=205.255146ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22492026/10/01 09:22:37 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=379.663125ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22502026/10/01 09:22:37 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=733.961586ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22512026/10/01 09:22:38 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.653288643s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2252--- PASS: TestClientErrorHandling (0.00s)2253 --- PASS: TestClientErrorHandling/InvalidStorePath (0.23s)2254 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.34s)2255 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.62s)2256--- PASS: TestUploadHandlersRejectOversizedBody (0.47s)2257 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.82s)2258 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.84s)2259 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (14.18s)2260PASS2261{"timestamp":"2026-10-01T09:22:41.956600798Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:42140","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(203)"}2262{"timestamp":"2026-10-01T09:22:41.95689268Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:40668","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(194)"}2263{"timestamp":"2026-10-01T09:22:41.956946781Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:40676","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(198)"}2264{"timestamp":"2026-10-01T09:22:41.957206103Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:41100","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(208)"}2265{"timestamp":"2026-10-01T09:22:41.957331104Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:41200","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2354,"threadName":"rustfs-worker","threadId":"ThreadId(202)"}22662026-10-01 09:22:42.239 UTC [173] LOG: received smart shutdown request22672026-10-01 09:22:42.243 UTC [173] LOG: background worker "logical replication launcher" (PID 183) exited with exit code 122682026-10-01 09:22:42.254 UTC [178] LOG: shutting down22692026-10-01 09:22:42.254 UTC [178] LOG: checkpoint starting: shutdown immediate22702026-10-01 09:22:43.223 UTC [178] LOG: checkpoint complete: wrote 10572 buffers (64.5%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 28 recycled; write=0.181 s, sync=0.755 s, total=0.969 s; sync files=33362, longest=0.002 s, average=0.001 s; distance=467286 kB, estimate=467286 kB; lsn=0/1DFBB660, redo lsn=0/1DFBB66022712026-10-01 09:22:43.294 UTC [173] LOG: database system is shut down2272Running OIDC tests...2273=== RUN TestAudienceForIssuer2274=== PAUSE TestAudienceForIssuer2275=== RUN TestHTTPClientForHasTimeouts2276=== PAUSE TestHTTPClientForHasTimeouts2277=== RUN TestGlobMatch2278=== PAUSE TestGlobMatch2279=== RUN TestValidateToken_ValidToken2280=== PAUSE TestValidateToken_ValidToken2281=== RUN TestValidateToken_WrongAudience2282=== PAUSE TestValidateToken_WrongAudience2283=== RUN TestValidateToken_Expired2284=== PAUSE TestValidateToken_Expired2285=== RUN TestValidateToken_BoundClaimsMismatch2286=== PAUSE TestValidateToken_BoundClaimsMismatch2287=== RUN TestValidateToken_BoundSubjectMismatch2288=== PAUSE TestValidateToken_BoundSubjectMismatch2289=== RUN TestValidateToken_MultipleProviders2290=== PAUSE TestValidateToken_MultipleProviders2291=== RUN TestValidateToken_NoMatchingProvider2292=== PAUSE TestValidateToken_NoMatchingProvider2293=== RUN TestValidateToken_KubernetesServiceAccount2294=== PAUSE TestValidateToken_KubernetesServiceAccount2295=== RUN TestNewValidator_KubernetesRequiresCA2296=== PAUSE TestNewValidator_KubernetesRequiresCA2297=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2298=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2299=== RUN TestPins_ReservedForMatchingRule2300=== PAUSE TestPins_ReservedForMatchingRule2301=== RUN TestPins_TopLevelShorthand2302=== PAUSE TestPins_TopLevelShorthand2303=== RUN TestPins_ConfigValidation2304=== PAUSE TestPins_ConfigValidation2305=== RUN TestScopes_LegacyProviderDefaultsToWrite2306=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2307=== RUN TestScopes_Rules2308=== PAUSE TestScopes_Rules2309=== RUN TestScopes_ConfigValidation2310=== PAUSE TestScopes_ConfigValidation2311=== CONT TestAudienceForIssuer2312=== CONT TestValidateToken_NoMatchingProvider2313--- PASS: TestAudienceForIssuer (0.00s)2314=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2315=== CONT TestScopes_Rules2316=== CONT TestPins_ConfigValidation2317=== CONT TestPins_ReservedForMatchingRule2318=== CONT TestScopes_ConfigValidation2319=== CONT TestNewValidator_KubernetesRequiresCA2320=== CONT TestValidateToken_Expired2321=== CONT TestPins_TopLevelShorthand2322=== CONT TestValidateToken_BoundSubjectMismatch2323--- PASS: TestPins_ConfigValidation (0.00s)2324=== CONT TestValidateToken_BoundClaimsMismatch2325=== CONT TestValidateToken_MultipleProviders2326=== CONT TestValidateToken_KubernetesServiceAccount2327=== CONT TestValidateToken_WrongAudience2328=== CONT TestValidateToken_ValidToken2329=== CONT TestHTTPClientForHasTimeouts2330=== CONT TestGlobMatch2331=== RUN TestGlobMatch/foo_foo2332=== CONT TestScopes_LegacyProviderDefaultsToWrite2333--- PASS: TestScopes_ConfigValidation (0.00s)2334=== PAUSE TestGlobMatch/foo_foo2335=== RUN TestGlobMatch/foo_bar2336=== PAUSE TestGlobMatch/foo_bar2337=== RUN TestGlobMatch/*_2338=== PAUSE TestGlobMatch/*_2339=== RUN TestGlobMatch/*_anything2340=== PAUSE TestGlobMatch/*_anything2341=== RUN TestGlobMatch/foo*_foo2342=== PAUSE TestGlobMatch/foo*_foo2343=== RUN TestGlobMatch/foo*_foobar2344=== PAUSE TestGlobMatch/foo*_foobar2345=== RUN TestGlobMatch/foo*_bar2346=== PAUSE TestGlobMatch/foo*_bar2347=== RUN TestGlobMatch/*bar_bar2348=== PAUSE TestGlobMatch/*bar_bar2349=== RUN TestGlobMatch/*bar_foobar2350=== PAUSE TestGlobMatch/*bar_foobar2351=== RUN TestGlobMatch/*bar_foo2352=== PAUSE TestGlobMatch/*bar_foo2353=== RUN TestGlobMatch/foo*bar_foobar2354=== PAUSE TestGlobMatch/foo*bar_foobar2355=== RUN TestGlobMatch/foo*bar_foo123bar2356=== PAUSE TestGlobMatch/foo*bar_foo123bar2357=== RUN TestGlobMatch/foo*bar_foobarbaz2358=== PAUSE TestGlobMatch/foo*bar_foobarbaz2359=== RUN TestGlobMatch/*/*_foo/bar2360=== PAUSE TestGlobMatch/*/*_foo/bar2361=== RUN TestGlobMatch/*/*_foo2362=== PAUSE TestGlobMatch/*/*_foo2363=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2364=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2365=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02366=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02367=== RUN TestGlobMatch/refs/*/main_refs/heads/main2368=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2369=== RUN TestGlobMatch/fo?_foo2370=== PAUSE TestGlobMatch/fo?_foo2371=== RUN TestGlobMatch/fo?_fo2372=== PAUSE TestGlobMatch/fo?_fo2373=== RUN TestGlobMatch/fo?_fooo2374=== PAUSE TestGlobMatch/fo?_fooo2375=== RUN TestGlobMatch/?oo_foo2376=== PAUSE TestGlobMatch/?oo_foo2377=== RUN TestGlobMatch/?oo_boo2378=== PAUSE TestGlobMatch/?oo_boo2379=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2380=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2381=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2382=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2383=== CONT TestGlobMatch/foo_bar2384=== CONT TestGlobMatch/*/*_foo2385=== CONT TestGlobMatch/*_2386=== CONT TestGlobMatch/*_anything2387=== CONT TestGlobMatch/*bar_foo2388=== CONT TestGlobMatch/foo_foo2389=== CONT TestGlobMatch/foo*bar_foo123bar2390=== CONT TestGlobMatch/fo?_fooo2391=== CONT TestGlobMatch/foo*bar_foobar2392=== CONT TestGlobMatch/foo*bar_foobarbaz2393=== CONT TestGlobMatch/*bar_foobar2394=== CONT TestGlobMatch/*bar_bar2395=== CONT TestGlobMatch/foo*_bar2396=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2397=== CONT TestGlobMatch/foo*_foobar2398=== CONT TestGlobMatch/foo*_foo2399=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2400=== CONT TestGlobMatch/?oo_boo2401=== CONT TestGlobMatch/?oo_foo2402=== CONT TestGlobMatch/fo?_foo2403=== CONT TestGlobMatch/fo?_fo2404=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2405=== CONT TestGlobMatch/refs/*/main_refs/heads/main2406=== CONT TestGlobMatch/*/*_foo/bar2407=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02408--- PASS: TestGlobMatch (0.00s)2409 --- PASS: TestGlobMatch/foo_bar (0.00s)2410 --- PASS: TestGlobMatch/*/*_foo (0.00s)2411 --- PASS: TestGlobMatch/*_ (0.00s)2412 --- PASS: TestGlobMatch/*_anything (0.00s)2413 --- PASS: TestGlobMatch/*bar_foo (0.00s)2414 --- PASS: TestGlobMatch/foo_foo (0.00s)2415 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2416 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2417 --- PASS: TestGlobMatch/*bar_bar (0.00s)2418 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2419 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2420 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2421 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2422 --- PASS: TestGlobMatch/foo*_bar (0.00s)2423 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2424 --- PASS: TestGlobMatch/foo*_foo (0.00s)2425 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2426 --- PASS: TestGlobMatch/?oo_foo (0.00s)2427 --- PASS: TestGlobMatch/fo?_foo (0.00s)2428 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2429 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2430 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2431 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2432 --- PASS: TestGlobMatch/?oo_boo (0.00s)2433 --- PASS: TestGlobMatch/fo?_fo (0.00s)24342026/10/01 09:22:46 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232435--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.07s)24362026/10/01 09:22:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:37981/oidc24372026/10/01 09:22:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:44875/oidc2438--- PASS: TestPins_TopLevelShorthand (0.10s)24392026/10/01 09:22:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38021/oidc2440--- PASS: TestValidateToken_ValidToken (0.10s)2441--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.10s)24422026/10/01 09:22:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:36839/oidc2443--- PASS: TestValidateToken_WrongAudience (0.15s)24442026/10/01 09:22:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46267/oidc24452026/10/01 09:22:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:35861/oidc2446--- PASS: TestHTTPClientForHasTimeouts (0.20s)2447--- PASS: TestValidateToken_BoundClaimsMismatch (0.21s)2448--- PASS: TestPins_ReservedForMatchingRule (0.21s)24492026/10/01 09:22:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38899/oidc2450--- PASS: TestValidateToken_BoundSubjectMismatch (0.23s)24512026/10/01 09:22:46 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:464432452--- PASS: TestValidateToken_KubernetesServiceAccount (0.24s)24532026/10/01 09:22:46 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:39149/oidc2454--- PASS: TestValidateToken_NoMatchingProvider (0.26s)24552026/10/01 09:22:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42137/oidc24562026/10/01 09:22:46 http: TLS handshake error from 127.0.0.1:43388: remote error: tls: bad certificate2457--- PASS: TestNewValidator_KubernetesRequiresCA (0.34s)2458--- PASS: TestScopes_Rules (0.36s)24592026/10/01 09:22:46 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:43623/oidc24602026/10/01 09:22:46 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:43395/oidc2461--- PASS: TestValidateToken_MultipleProviders (0.44s)24622026/10/01 09:22:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34967/oidc2463--- PASS: TestValidateToken_Expired (0.47s)2464PASS2465Running signing tests...2466=== RUN TestGenerateFingerprint2467=== PAUSE TestGenerateFingerprint2468=== RUN TestParseSigningKey2469=== PAUSE TestParseSigningKey2470=== RUN TestSignMessage2471=== PAUSE TestSignMessage2472=== RUN TestSignNarinfo2473=== PAUSE TestSignNarinfo2474=== CONT TestSignMessage2475=== CONT TestParseSigningKey2476=== CONT TestSignNarinfo2477=== RUN TestParseSigningKey/valid_32-byte_key2478=== CONT TestGenerateFingerprint2479=== PAUSE TestParseSigningKey/valid_32-byte_key2480=== RUN TestGenerateFingerprint/basic_with_references2481=== PAUSE TestGenerateFingerprint/basic_with_references2482=== RUN TestGenerateFingerprint/no_references2483=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2484=== PAUSE TestGenerateFingerprint/no_references2485=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2486=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2487=== RUN TestParseSigningKey/no_colon2488=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2489=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2490=== PAUSE TestParseSigningKey/no_colon2491=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2492=== RUN TestParseSigningKey/empty_name2493=== RUN TestGenerateFingerprint/invalid_nar_hash_length2494=== PAUSE TestParseSigningKey/empty_name2495=== RUN TestParseSigningKey/invalid_base642496=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2497=== RUN TestGenerateFingerprint/invalid_store_path_prefix2498=== PAUSE TestParseSigningKey/invalid_base642499=== RUN TestParseSigningKey/wrong_length2500=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2501=== PAUSE TestParseSigningKey/wrong_length2502=== RUN TestGenerateFingerprint/invalid_reference_prefix2503=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2504=== CONT TestParseSigningKey/no_colon2505=== CONT TestParseSigningKey/invalid_base642506=== CONT TestParseSigningKey/empty_name2507=== CONT TestParseSigningKey/valid_32-byte_key2508=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2509=== CONT TestParseSigningKey/wrong_length2510=== CONT TestGenerateFingerprint/no_references2511=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2512=== CONT TestGenerateFingerprint/invalid_reference_prefix2513=== CONT TestGenerateFingerprint/invalid_store_path_prefix2514=== CONT TestGenerateFingerprint/invalid_nar_hash_length2515=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2516=== CONT TestGenerateFingerprint/basic_with_references2517--- PASS: TestGenerateFingerprint (0.00s)2518 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2519 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2520 --- PASS: TestGenerateFingerprint/no_references (0.00s)2521 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2522 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2523 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2524 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2525--- PASS: TestParseSigningKey (0.00s)2526 --- PASS: TestParseSigningKey/no_colon (0.00s)2527 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2528 --- PASS: TestParseSigningKey/empty_name (0.00s)2529 --- PASS: TestParseSigningKey/wrong_length (0.00s)2530 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)2531 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)2532--- PASS: TestSignMessage (0.01s)2533--- PASS: TestSignNarinfo (0.02s)2534PASS2535Running hook tests...2536=== RUN TestSendPathsEmpty2537=== PAUSE TestSendPathsEmpty2538=== RUN TestQueueEnqueueAndFetch2539=== PAUSE TestQueueEnqueueAndFetch2540=== RUN TestQueueDeduplication2541=== PAUSE TestQueueDeduplication2542=== RUN TestQueueRemove2543=== PAUSE TestQueueRemove2544=== RUN TestQueueFetchBatchLimit2545=== PAUSE TestQueueFetchBatchLimit2546=== RUN TestQueueRetryMovesToBack2547=== PAUSE TestQueueRetryMovesToBack2548=== RUN TestQueueFetchRemoveLifecycle2549=== PAUSE TestQueueFetchRemoveLifecycle2550=== RUN TestQueueConcurrentWriters2551=== PAUSE TestQueueConcurrentWriters2552=== RUN TestQueueEnqueueWaitsOutSlowWriter2553=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2554=== RUN TestQueueRemoveLargeClosure2555=== PAUSE TestQueueRemoveLargeClosure2556=== RUN TestServerClientIntegration2557=== PAUSE TestServerClientIntegration2558=== RUN TestServerQueueError2559=== PAUSE TestServerQueueError2560=== RUN TestServerRefusesOversizedAndNonStoreRequests2561=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2562=== RUN TestGetListenerSocketActivation2563 server_test.go:317: === RUN TestGetListenerSocketActivation2564 --- PASS: TestGetListenerSocketActivation (0.00s)2565 PASS2566 2567--- PASS: TestGetListenerSocketActivation (1.02s)2568=== RUN TestServerStalledClientDoesNotBlockShutdown2569=== PAUSE TestServerStalledClientDoesNotBlockShutdown2570=== RUN TestServerBacksOffOnAcceptErrors2571=== PAUSE TestServerBacksOffOnAcceptErrors2572=== RUN TestDrainIsolatesPoisonPath2573=== PAUSE TestDrainIsolatesPoisonPath2574=== RUN TestRunNotBlockedByPoisonHead2575=== PAUSE TestRunNotBlockedByPoisonHead2576=== RUN TestDrainGivesUpWhenServerDown2577=== PAUSE TestDrainGivesUpWhenServerDown2578=== RUN TestFailedPathPrunedByLaterClosure2579=== PAUSE TestFailedPathPrunedByLaterClosure2580=== RUN TestWorkerUploadsAndRemoves2581=== PAUSE TestWorkerUploadsAndRemoves2582=== RUN TestWorkerSkipsGCdPaths2583=== PAUSE TestWorkerSkipsGCdPaths2584=== RUN TestWorkerPrunesClosureDeps2585=== PAUSE TestWorkerPrunesClosureDeps2586=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2587=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2588=== RUN TestDrainTimeout2589=== PAUSE TestDrainTimeout2590=== RUN TestDrainTimeoutDuringIsolation2591=== PAUSE TestDrainTimeoutDuringIsolation2592=== RUN TestShutdownFinishesInFlightPush2593=== PAUSE TestShutdownFinishesInFlightPush2594=== RUN TestWorkerRemoveFailureIsNotProgress2595=== PAUSE TestWorkerRemoveFailureIsNotProgress2596=== RUN TestWorkerKeepsPathItCannotStat2597=== PAUSE TestWorkerKeepsPathItCannotStat2598=== CONT TestSendPathsEmpty2599=== CONT TestDrainTimeoutDuringIsolation2600=== CONT TestQueueRemoveLargeClosure2601--- PASS: TestSendPathsEmpty (0.00s)2602=== CONT TestWorkerKeepsPathItCannotStat2603=== CONT TestShutdownFinishesInFlightPush2604=== CONT TestWorkerUploadsAndRemoves2605=== CONT TestQueueDeduplication2606=== CONT TestQueueFetchBatchLimit2607=== CONT TestQueueEnqueueAndFetch2608=== CONT TestQueueRetryMovesToBack2609=== CONT TestQueueConcurrentWriters2610=== CONT TestWorkerPrunesClosureDeps2611=== CONT TestDrainTimeout2612=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2613=== CONT TestWorkerRemoveFailureIsNotProgress2614=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2615=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2616=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2617=== CONT TestFailedPathPrunedByLaterClosure2618=== CONT TestWorkerSkipsGCdPaths2619=== CONT TestDrainGivesUpWhenServerDown2620=== CONT TestQueueFetchRemoveLifecycle2621=== CONT TestServerRefusesOversizedAndNonStoreRequests2622=== CONT TestServerBacksOffOnAcceptErrors2623=== CONT TestDrainIsolatesPoisonPath2624=== CONT TestServerStalledClientDoesNotBlockShutdown2625=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2626=== CONT TestServerQueueError2627=== CONT TestRunNotBlockedByPoisonHead2628=== RUN TestShutdownFinishesInFlightPush/completes2629=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2630=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2631=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2632=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26332026/10/01 09:22:49 ERROR Accept failed error="too many open files"2634=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2635=== PAUSE TestShutdownFinishesInFlightPush/completes2636=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2637=== CONT TestServerClientIntegration2638=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2639=== CONT TestQueueEnqueueWaitsOutSlowWriter2640=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2641=== CONT TestQueueRemove26422026/10/01 09:22:49 ERROR Failed to queue paths error="permission denied" count=126432026/10/01 09:22:49 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2644--- PASS: TestServerQueueError (0.00s)2645=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths26462026/10/01 09:22:49 ERROR Refusing path outside the store path=/nix/store store=/nix/store2647=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path2648--- PASS: TestServerClientIntegration (0.00s)26492026/10/01 09:22:49 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store26502026/10/01 09:22:49 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store26512026/10/01 09:22:49 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store26522026/10/01 09:22:49 ERROR Accept failed error="too many open files"26532026/10/01 09:22:49 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26542026/10/01 09:22:49 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26552026/10/01 09:22:49 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store26562026/10/01 09:22:49 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store26572026/10/01 09:22:49 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store26582026/10/01 09:22:49 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store26592026/10/01 09:22:49 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store26602026/10/01 09:22:49 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store26612026/10/01 09:22:49 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store26622026/10/01 09:22:49 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store26632026/10/01 09:22:49 ERROR Failed to decode request error="unexpected EOF"2664=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch2665--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)26662026/10/01 09:22:49 ERROR Accept failed error="too many open files"26672026/10/01 09:22:49 ERROR Accept failed error="too many open files"26682026/10/01 09:22:49 INFO Uploading batch count=126692026/10/01 09:22:49 ERROR Upload failed error="upload failed" count=126702026/10/01 09:22:49 INFO Upload queue status pending=326712026/10/01 09:22:49 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths3662825792/002/nonexistent26722026/10/01 09:22:49 INFO Uploading batch count=426732026/10/01 09:22:49 ERROR Upload failed error="upload failed" count=426742026/10/01 09:22:49 INFO Uploading batch count=126752026/10/01 09:22:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath3716255317/002/bbb26762026/10/01 09:22:49 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat629714955/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat629714955/002/locked/aaa: permission denied"2677=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short2678--- PASS: TestQueueFetchBatchLimit (0.07s)26792026/10/01 09:22:49 INFO Upload queue status pending=326802026/10/01 09:22:49 INFO Uploading batch count=226812026/10/01 09:22:49 INFO Upload queue status pending=226822026/10/01 09:22:49 INFO Uploading batch count=126832026/10/01 09:22:49 ERROR Upload failed error="upload failed" count=126842026/10/01 09:22:49 INFO Uploading batch count=226852026/10/01 09:22:49 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat629714955/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat629714955/002/locked/aaa: permission denied"26862026/10/01 09:22:49 INFO Uploading batch count=12687--- PASS: TestQueueDeduplication (0.07s)2688=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26892026/10/01 09:22:49 INFO Uploading batch count=126902026/10/01 09:22:49 INFO Upload queue status pending=226912026/10/01 09:22:49 INFO Uploading batch count=226922026/10/01 09:22:49 INFO Uploading batch count=126932026/10/01 09:22:49 ERROR Upload failed error="upload failed" count=12694=== CONT TestShutdownFinishesInFlightPush/completes2695--- PASS: TestQueueRetryMovesToBack (0.07s)26962026/10/01 09:22:49 INFO Upload queue status pending=226972026/10/01 09:22:49 ERROR Accept failed error="too many open files"26982026/10/01 09:22:49 INFO Uploading batch count=226992026/10/01 09:22:49 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat629714955/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat629714955/002/locked/aaa: permission denied"2700--- PASS: TestQueueEnqueueAndFetch (0.08s)2701=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout27022026/10/01 09:22:49 INFO Uploading batch count=127032026/10/01 09:22:49 ERROR Upload failed error="upload failed" count=12704--- PASS: TestQueueFetchRemoveLifecycle (0.08s)27052026/10/01 09:22:49 INFO Uploading batch count=227062026/10/01 09:22:49 ERROR Upload failed error="upload failed" count=227072026/10/01 09:22:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4176845656/002/a27082026/10/01 09:22:49 ERROR Drain finished with paths left in queue remaining=12709--- PASS: TestFailedPathPrunedByLaterClosure (0.09s)27102026/10/01 09:22:49 INFO Uploading batch count=127112026/10/01 09:22:49 ERROR Upload failed error="upload failed" count=12712--- PASS: TestWorkerSkipsGCdPaths (0.09s)27132026/10/01 09:22:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4176845656/002/b27142026/10/01 09:22:49 ERROR Drain finished with paths left in queue remaining=12715--- PASS: TestQueueRemove (0.09s)2716--- PASS: TestWorkerKeepsPathItCannotStat (0.10s)2717--- PASS: TestWorkerPrunesClosureDeps (0.10s)27182026/10/01 09:22:49 INFO Uploading batch count=227192026/10/01 09:22:49 ERROR Upload failed error="upload failed" count=227202026/10/01 09:22:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4176845656/002/c2721--- PASS: TestWorkerUploadsAndRemoves (0.10s)2722--- PASS: TestDrainIsolatesPoisonPath (0.10s)27232026/10/01 09:22:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4176845656/002/d2724--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.10s)27252026/10/01 09:22:49 INFO Uploading batch count=227262026/10/01 09:22:49 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227272026/10/01 09:22:49 INFO Uploading batch count=227282026/10/01 09:22:49 ERROR Upload failed error="upload failed" count=227292026/10/01 09:22:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4176845656/002/e27302026/10/01 09:22:49 INFO Uploading batch count=227312026/10/01 09:22:49 INFO Uploading batch count=427322026/10/01 09:22:49 ERROR Upload failed error="upload failed" count=427332026/10/01 09:22:49 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227342026/10/01 09:22:49 INFO Uploading batch count=427352026/10/01 09:22:49 ERROR Upload failed error="upload failed" count=427362026/10/01 09:22:49 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path244286177/001/nonexistent27372026/10/01 09:22:49 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown4176845656/002/f27382026/10/01 09:22:49 INFO Uploading batch count=227392026/10/01 09:22:49 INFO Uploading batch count=227402026/10/01 09:22:49 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127412026/10/01 09:22:49 ERROR Upload failed error="upload failed" count=227422026/10/01 09:22:49 INFO Upload queue status pending=227432026/10/01 09:22:49 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127442026/10/01 09:22:49 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227452026/10/01 09:22:49 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path244286177/001/nonexistent27462026/10/01 09:22:49 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127472026/10/01 09:22:49 ERROR Drain finished with paths left in queue remaining=227482026/10/01 09:22:49 ERROR Drain finished with paths left in queue remaining=1027492026/10/01 09:22:49 INFO Uploading batch count=227502026/10/01 09:22:49 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127512026/10/01 09:22:49 INFO Uploading batch count=227522026/10/01 09:22:49 ERROR Upload failed error="upload failed" count=227532026/10/01 09:22:49 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path244286177/001/nonexistent27542026/10/01 09:22:49 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127552026/10/01 09:22:49 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127562026/10/01 09:22:49 INFO Upload queue status pending=227572026/10/01 09:22:49 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127582026/10/01 09:22:49 ERROR Drain finished with paths left in queue remaining=127592026/10/01 09:22:49 INFO Uploading batch count=227602026/10/01 09:22:49 INFO Uploading batch count=227612026/10/01 09:22:49 ERROR Upload failed error="upload failed" count=22762--- PASS: TestDrainGivesUpWhenServerDown (0.12s)27632026/10/01 09:22:49 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127642026/10/01 09:22:49 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127652026/10/01 09:22:49 ERROR Drain finished with paths left in queue remaining=22766--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2767 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.10s)2768 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.11s)2769 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.12s)27702026/10/01 09:22:49 ERROR Accept failed error="too many open files"27712026/10/01 09:22:49 ERROR Failed to decode request error="read unix /build/hook317730511/test.sock->@: i/o timeout"27722026/10/01 09:22:49 ERROR Failed to write response error="write unix /build/hook317730511/test.sock->@: i/o timeout"2773--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)27742026/10/01 09:22:49 ERROR Upload failed error="context canceled" count=227752026/10/01 09:22:49 ERROR Drain finished with paths left in queue remaining=42776--- PASS: TestDrainTimeout (0.27s)27772026/10/01 09:22:49 ERROR Drain finished with paths left in queue remaining=427782026/10/01 09:22:50 ERROR Upload failed error="context canceled" count=227792026/10/01 09:22:50 ERROR Drain finished with paths left in queue remaining=227802026/10/01 09:22:50 ERROR Accept failed error="too many open files"2781--- PASS: TestShutdownFinishesInFlightPush (0.00s)2782 --- PASS: TestShutdownFinishesInFlightPush/completes (0.14s)2783 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.24s)27842026/10/01 09:22:50 ERROR Drain finished with paths left in queue remaining=32785--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2786 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.24s)2787 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.34s)2788--- PASS: TestQueueConcurrentWriters (0.51s)27892026/10/01 09:22:50 ERROR Accept failed error="too many open files"2790--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)27912026/10/01 09:22:50 INFO Uploading batch count=127922026/10/01 09:22:50 INFO Uploading batch count=127932026/10/01 09:22:50 INFO Uploading batch count=127942026/10/01 09:22:50 ERROR Upload failed error="upload failed" count=127952026/10/01 09:22:50 INFO Uploading batch count=127962026/10/01 09:22:50 ERROR Upload failed error="upload failed" count=127972026/10/01 09:22:50 INFO Uploading batch count=127982026/10/01 09:22:50 ERROR Upload failed error="upload failed" count=127992026/10/01 09:22:50 INFO Uploading batch count=128002026/10/01 09:22:50 ERROR Upload failed error="upload failed" count=128012026/10/01 09:22:50 ERROR Drain finished with paths left in queue remaining=12802--- PASS: TestRunNotBlockedByPoisonHead (1.11s)2803--- PASS: TestQueueRemoveLargeClosure (4.19s)2804--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.07s)2805PASS2806Running niks3-hook command tests...2807=== RUN TestServeSecondSignalEndsDrain2808=== PAUSE TestServeSecondSignalEndsDrain2809=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown2810=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown2811=== CONT TestServeSecondSignalEndsDrain2812=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown2813--- PASS: TestServeSecondSignalEndsDrain (0.07s)28142026/10/01 09:22:56 INFO Upload queue status pending=128152026/10/01 09:22:56 INFO Uploading batch count=12816--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)2817PASS2818Running rate limiter tests...2819=== RUN TestAdaptiveRateLimiter_ThreadSafety2820=== PAUSE TestAdaptiveRateLimiter_ThreadSafety2821=== CONT TestAdaptiveRateLimiter_ThreadSafety28222026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=112.7357000000000728232026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=78.9149900000000528242026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=55.2404930000000328252026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=38.6683451000000228262026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=27.0678415700000128272026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=18.94748909900000628282026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=13.26324236930000428292026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=9.28426965851000228302026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=6.49898876095700128312026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528322026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=6.82050985000000228332026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528342026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528352026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528362026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528372026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528382026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528392026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528402026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528412026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528422026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528432026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528442026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528452026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528462026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528472026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528482026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528492026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528502026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528512026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528522026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528532026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528542026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528552026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528562026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528572026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528582026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528592026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528602026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528612026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528622026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528632026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528642026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528652026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528662026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528672026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528682026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528692026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528702026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528712026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528722026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528732026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528742026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528752026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528762026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528772026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528782026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528792026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528802026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528812026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528822026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528832026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528842026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528852026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528862026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528872026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528882026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528892026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528902026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528912026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528922026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528932026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528942026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528952026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=5.12435000000000128962026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528972026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528982026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=528992026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529002026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529012026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529022026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529032026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529042026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529052026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529062026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529072026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529082026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=5.12435000000000129092026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529102026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529112026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529122026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529132026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529142026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529152026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529162026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529172026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529182026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529192026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529202026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=529212026/10/01 09:22:57 WARN Rate limiter backed off name=test rate=52922--- PASS: TestAdaptiveRateLimiter_ThreadSafety (2.24s)2923PASS