niks3-go-unit-tests
checks.aarch64-linux.go-unit-tests
· build #348
· 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.07s)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 8311 of 32768000 bytes45--- PASS: TestDumpPathWriterErrorStopsReading (0.64s)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 TestSetClientTLSErrors129=== CONT TestEncodeNixBase32WithRealHash130=== CONT TestParsePathInfoJSONMultiplePaths131=== CONT TestStreamPushReportsSignatures132=== CONT TestStreamPushReportsEveryPath133=== CONT TestStaticToken134=== CONT TestSetClientTLSDoesNotMutateDefaultTransport135=== CONT TestStreamPushStopsOnCancel136=== CONT TestClientSignaturesByStorePath137=== CONT TestScriptTokenCachesUntilRefresh138=== CONT TestGetStorePathHash139=== RUN TestGetStorePathHash/valid_store_path140=== RUN TestStreamPushStopsOnCancel/waiting_for_input141=== PAUSE TestGetStorePathHash/valid_store_path142=== CONT TestScriptTokenDoesNotWaitForItsChildren143=== PAUSE TestStreamPushStopsOnCancel/waiting_for_input144=== RUN TestGetStorePathHash/basename_without_hyphen_should_error145=== RUN TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot146=== CONT TestDumpPathSingleFile147=== CONT TestFileTokenMissing148=== CONT TestStreamPushIsolatesFailures149=== CONT TestScriptTokenNoExpiryRerunsEveryCall150=== CONT TestUploadMultipart_ProducerErrorIsNotEOF151=== CONT TestScriptTokenEmptyToken152=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica153=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry154=== CONT TestCompletePendingClosure_NotFoundWithoutKey155=== CONT TestResolveStorePath156=== CONT TestScriptTokenEmptyCommand157=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths158=== CONT TestDoServerRequestAttachesToken159--- PASS: TestEncodeNixBase32WithRealHash (0.00s)160=== CONT TestScriptTokenScriptFails161=== CONT TestSetClientTLS162=== CONT TestConvertHashToNix32163=== RUN TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs164=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error165=== PAUSE TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot166=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part167=== CONT TestDumpPathMatchesNix168=== CONT TestEncodeNixBase32169=== RUN TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot170=== CONT TestPathInfoCACompatibility171=== RUN TestEncodeNixBase32/test_string_hash172=== RUN TestPathInfoCACompatibility/null_ca_field173=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths174--- PASS: TestScriptTokenEmptyCommand (0.00s)175=== RUN TestConvertHashToNix32/SRI_format_to_Nix32176--- PASS: TestStaticToken (0.00s)177=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs178=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths179=== PAUSE TestEncodeNixBase32/test_string_hash180=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error181=== PAUSE TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot182=== CONT TestStreamPushGivesUpOnDeadServer183=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part184=== PAUSE TestPathInfoCACompatibility/null_ca_field185=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer186=== RUN TestPathInfoCACompatibility/old_string_format_-_text187=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32188=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths189=== CONT TestStreamPushBatchesUnderLoad190=== RUN TestStreamPushBatchesUnderLoad/together191=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text192=== PAUSE TestStreamPushBatchesUnderLoad/together193=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error194=== RUN TestEncodeNixBase32/empty_input195=== CONT TestParsePathInfoJSON196=== RUN TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot197=== RUN TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary198--- PASS: TestClientSignaturesByStorePath (0.00s)199=== CONT TestPathInfoHashCompatibility200=== RUN TestConvertHashToNix32/already_Nix32_format201=== RUN TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout202=== CONT TestDumpPathWriterError203=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive204=== RUN TestStreamPushBatchesUnderLoad/one_at_a_time205=== PAUSE TestEncodeNixBase32/empty_input206=== RUN TestParsePathInfoJSON/Nix_format207=== RUN TestSetClientTLSErrors/missing_cert_file208=== PAUSE TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary209=== PAUSE TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot210=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error211--- PASS: TestFileTokenMissing (0.00s)212=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)213=== PAUSE TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout214=== CONT TestUploadMultipart_FailedPartBufferNotReused215=== CONT TestSupersededNARStillUploadsListing216=== CONT TestPartSizeForNAR217=== CONT TestShellSplit218=== PAUSE TestConvertHashToNix32/already_Nix32_format219=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive220=== PAUSE TestStreamPushBatchesUnderLoad/one_at_a_time221=== CONT TestRateLimiterFeedback222=== PAUSE TestParsePathInfoJSON/Nix_format223=== PAUSE TestSetClientTLSErrors/missing_cert_file224=== RUN TestParsePathInfoJSON/Lix_format225=== CONT TestUploadMultipart_SupersededByPeer226=== RUN TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot227--- PASS: TestStreamPushReportsEveryPath (0.00s)228=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error229=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)230=== CONT TestDoWithRetry_FinalResponseBodyReadable231=== CONT TestUploadMultipart_PartsInParallel232=== RUN TestSupersededNARStillUploadsListing/small_NAR233=== RUN TestPartSizeForNAR/zero_stays_at_minimum234=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent235=== RUN TestConvertHashToNix32/invalid_format236=== CONT TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure237=== RUN TestPathInfoCACompatibility/new_structured_format_-_text238=== CONT TestFilterOversizedClosures239=== RUN TestSetClientTLS/rejects_connection_without_client_cert240=== RUN TestRateLimiterFeedback/429_enables_limiter241=== RUN TestFilterOversizedClosures/no_limit_keeps_everything242=== PAUSE TestRateLimiterFeedback/429_enables_limiter243=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything244=== RUN TestSetClientTLSErrors/missing_key_file245=== RUN TestRateLimiterFeedback/503_enables_limiter246=== PAUSE TestSetClientTLSErrors/missing_key_file247=== PAUSE TestRateLimiterFeedback/503_enables_limiter248=== PAUSE TestParsePathInfoJSON/Lix_format249=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter250=== RUN TestUploadMultipart_SupersededByPeer/exists251--- PASS: TestResolveStorePath (0.00s)252=== PAUSE TestUploadMultipart_SupersededByPeer/exists253=== PAUSE TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot254=== RUN TestStreamPushStopsOnCancel/lines_read_but_not_taken255=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun256=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon257=== PAUSE TestSupersededNARStillUploadsListing/small_NAR258=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum259=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier260=== RUN TestSupersededNARStillUploadsListing/dump_cut_short261=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text262=== PAUSE TestConvertHashToNix32/invalid_format263=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped264=== RUN TestSetClientTLSErrors/missing_ca_file265=== CONT TestRegisterUploadedObjectReusesConnections266=== RUN TestParsePathInfoJSON/empty_input267=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter268--- PASS: TestScriptTokenScriptFails (0.01s)269=== RUN TestUploadMultipart_SupersededByPeer/missing270=== PAUSE TestStreamPushStopsOnCancel/lines_read_but_not_taken271=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon272=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert273=== CONT TestDoWithRetry_BodyReplayedViaGetBody274=== RUN TestPartSizeForNAR/small_stays_at_minimum275=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier276=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short277=== CONT TestCaseHackSuffix278=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails279=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped280=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails281=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method282=== CONT TestFileTokenEmpty283=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method284=== PAUSE TestSetClientTLSErrors/missing_ca_file285=== RUN TestSetClientTLSErrors/invalid_ca_file286=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess287=== PAUSE TestSetClientTLSErrors/invalid_ca_file288=== PAUSE TestParsePathInfoJSON/empty_input289=== RUN TestParsePathInfoJSON/whitespace_only290--- PASS: TestScriptTokenEmptyToken (0.01s)291=== PAUSE TestParsePathInfoJSON/whitespace_only292=== CONT TestTruncatedNARDumpIsNotCompleted293=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter294=== CONT TestFileTokenReadsAndCaches295=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter296--- PASS: TestStreamPushIsolatesFailures (0.01s)297--- PASS: TestStreamPushReportsSignatures (0.01s)298--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.02s)299=== RUN TestParsePathInfoJSON/invalid_JSON300=== PAUSE TestParsePathInfoJSON/invalid_JSON301=== PAUSE TestUploadMultipart_SupersededByPeer/missing302--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.02s)303=== CONT TestScriptTokenBadJSON304=== CONT TestShellSplitErrors305=== CONT TestEncodeNixBase32/empty_input306=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI307=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA308=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA309=== RUN TestSetClientTLS/preserves_debug_logging_transport310=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI311=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512312=== PAUSE TestSetClientTLS/preserves_debug_logging_transport313=== RUN TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up314=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512315=== CONT TestEncodeNixBase32/test_string_hash316=== PAUSE TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up317=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths318=== CONT TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs319=== RUN TestFilterOversizedClosures/all_closures_skipped320=== CONT TestStreamPushBatchesUnderLoad/together321=== PAUSE TestFilterOversizedClosures/all_closures_skipped322=== CONT TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout323--- PASS: TestScriptTokenCachesUntilRefresh (0.02s)324--- PASS: TestCompletePendingClosure_NotFoundWithoutKey (0.02s)325--- PASS: TestStreamPushGivesUpOnDeadServer (0.01s)326=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths327=== CONT TestGetStorePathHash/valid_store_path328=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error329--- PASS: TestDoServerRequestAttachesToken (0.02s)330=== CONT TestGetStorePathHash/basename_without_hyphen_should_error331=== CONT TestStreamPushRequestLine332=== CONT TestConvertHashToNix32/already_Nix32_format333=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error334--- PASS: TestShellSplit (0.00s)335=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part336=== CONT TestStreamPushStopsOnCancel/waiting_for_input337=== CONT TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot338=== CONT TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot339=== CONT TestConvertHashToNix32/invalid_format340=== CONT TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot341=== CONT TestStreamPushStopsOnCancel/lines_read_but_not_taken342=== CONT TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot343=== CONT TestStreamPushBatchesUnderLoad/one_at_a_time344--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.03s)345--- PASS: TestDumpPathSingleFile (0.04s)346--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.04s)347--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)348--- PASS: TestFileTokenEmpty (0.00s)349=== CONT TestConvertHashToNix32/SRI_format_to_Nix32350=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails351=== PAUSE TestPartSizeForNAR/small_stays_at_minimum352--- PASS: TestFileTokenReadsAndCaches (0.00s)353=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum354=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum355--- PASS: TestShellSplitErrors (0.00s)356=== CONT TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary357--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)358=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts359=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts360--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)361=== RUN TestPartSizeForNAR/1_TiB362--- PASS: TestScriptTokenBadJSON (0.01s)363=== PAUSE TestPartSizeForNAR/1_TiB364=== RUN TestPartSizeForNAR/5_TiB_S3_max_object365=== CONT TestSupersededNARStillUploadsListing/small_NAR366--- PASS: TestEncodeNixBase32 (0.01s)367 --- PASS: TestEncodeNixBase32/empty_input (0.00s)368 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)369--- PASS: TestParsePathInfoJSONMultiplePaths (0.02s)370 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)371 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)372--- PASS: TestGetStorePathHash (0.03s)373 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)374 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)375 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)376 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)377--- PASS: TestStreamPushBatchesUnderLoad (0.01s)378 --- PASS: TestStreamPushBatchesUnderLoad/together (0.00s)379 --- PASS: TestStreamPushBatchesUnderLoad/one_at_a_time (0.22s)380--- PASS: TestCaseHackSuffix (0.24s)381--- PASS: TestConvertHashToNix32 (0.04s)382 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)383 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)384 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)385=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object386=== CONT TestPathInfoCACompatibility/old_string_format_-_text387=== CONT TestSupersededNARStillUploadsListing/dump_cut_short388=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive389=== CONT TestPathInfoCACompatibility/new_structured_format_-_text390=== RUN TestPartSizeForNAR/capped_at_5_GiB391=== PAUSE TestPartSizeForNAR/capped_at_5_GiB392=== CONT TestSetClientTLSErrors/missing_cert_file393=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method394=== CONT TestSetClientTLSErrors/missing_key_file395=== CONT TestPathInfoCACompatibility/null_ca_field396=== CONT TestRateLimiterFeedback/503_enables_limiter397--- PASS: TestPathInfoCACompatibility (0.04s)398 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)399 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)400 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)401 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)402 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)403=== CONT TestUploadMultipart_SupersededByPeer/missing404=== CONT TestParsePathInfoJSON/empty_input405=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon406=== CONT TestSetClientTLSErrors/missing_ca_file407=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512408=== CONT TestSetClientTLS/rejects_connection_without_client_cert409=== CONT TestSetClientTLSErrors/invalid_ca_file410=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up411=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI412=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)413=== CONT TestParsePathInfoJSON/invalid_JSON414=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter415=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter416--- PASS: TestSetClientTLSErrors (0.04s)417 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)418 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)419 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)420 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)421--- PASS: TestPathInfoHashCompatibility (0.03s)422 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)423 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)424 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)425 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)426=== CONT TestRateLimiterFeedback/429_enables_limiter427=== CONT TestParsePathInfoJSON/Lix_format428=== CONT TestParsePathInfoJSON/Nix_format429=== CONT TestUploadMultipart_SupersededByPeer/exists430--- PASS: TestStreamPushStopsOnCancel (0.04s)431 --- PASS: TestStreamPushStopsOnCancel/waiting_for_input (0.23s)432 --- PASS: TestStreamPushStopsOnCancel/input_closed,_last_batch_waiting_for_a_slot (0.23s)433 --- PASS: TestStreamPushStopsOnCancel/request_line_waiting_for_a_slot (0.23s)434 --- PASS: TestStreamPushStopsOnCancel/lines_read_but_not_taken (0.23s)435 --- PASS: TestStreamPushStopsOnCancel/partial_batch_waiting_for_a_slot (0.23s)436 --- PASS: TestStreamPushStopsOnCancel/full_batch_waiting_for_a_slot (0.24s)437=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA438=== CONT TestParsePathInfoJSON/whitespace_only439--- PASS: TestParsePathInfoJSON (0.03s)440 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)441 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)442 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)443 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)444 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)445=== CONT TestFilterOversizedClosures/no_limit_keeps_everything446=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped447=== CONT TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier448=== CONT TestSetClientTLS/preserves_debug_logging_transport449=== CONT TestFilterOversizedClosures/all_closures_skipped450=== CONT TestPartSizeForNAR/small_stays_at_minimum451=== CONT TestPartSizeForNAR/capped_at_5_GiB452--- PASS: TestFilterOversizedClosures (0.02s)453 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)454 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)455 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)456--- PASS: TestRateLimiterFeedback (0.01s)457 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)458 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)459 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)460 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)461=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts462=== CONT TestPartSizeForNAR/5_TiB_S3_max_object463=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum464=== CONT TestPartSizeForNAR/zero_stays_at_minimum465=== CONT TestPartSizeForNAR/1_TiB466--- PASS: TestPartSizeForNAR (0.26s)467 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)468 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)469 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)470 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)471 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)472 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)473 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)474--- PASS: TestUploadMultipart_SupersededByPeer (0.02s)475 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.01s)476 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.00s)477--- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent (0.02s)478 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/cleaned_up (0.00s)479 --- PASS: TestCompletePendingClosure_NotFoundIsSuccessWhenClosurePresent/committed_earlier (0.00s)480--- PASS: TestDumpPathWriterError (0.29s)481--- PASS: TestPushPathsReportsOnlyUnuploadablePathsOfSkippedClosure (0.29s)482--- PASS: TestSetClientTLS (0.04s)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.32s)486--- PASS: TestUploadMultipart_ProducerErrorIsNotEOF (0.02s)487 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/empty_read_on_a_part_boundary (0.56s)488 --- PASS: TestUploadMultipart_ProducerErrorIsNotEOF/short_read_inside_a_part (0.57s)489--- PASS: TestRegisterUploadedObjectReusesConnections (0.63s)490--- PASS: TestDumpPathMatchesNix (0.67s)491--- PASS: TestStreamPushRequestLine (0.64s)492--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)493--- PASS: TestSupersededNARStillUploadsListing (0.02s)494 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.25s)495 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.02s)496 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (1.10s)497--- PASS: TestTruncatedNARDumpIsNotCompleted (1.35s)498--- PASS: TestUploadMultipart_PartsInParallel (1.37s)499--- PASS: TestUploadMultipart_FailedPartBufferNotReused (1.42s)500--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (2.00s)501--- PASS: TestScriptTokenDoesNotWaitForItsChildren (0.02s)502 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/child_left_holding_stdout (2.01s)503 --- PASS: TestScriptTokenDoesNotWaitForItsChildren/cancelled_while_a_child_runs (2.23s)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/postgres3722999130/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/postgres3722999130/data -l logfile start532533/build/postgres3722999130:5432 - no response5342026-10-02 20:37:54.788 UTC [175] LOG: starting PostgreSQL 18.6 on aarch64-unknown-linux-gnu, compiled by clang version 21.1.8, 64-bit5352026-10-02 20:37:54.789 UTC [175] LOG: listening on Unix socket "/build/postgres3722999130/.s.PGSQL.5432"5362026-10-02 20:37:54.793 UTC [182] LOG: database system was shut down at 2026-10-02 20:37:54 UTC5372026-10-02 20:37:54.797 UTC [175] LOG: database system is ready to accept connections538/build/postgres3722999130: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/02 20:37:55 INFO lead: acquired remote=192.0.2.1:12345872026/10/02 20:37:56 INFO lead: released remote=192.0.2.1:12345882026/10/02 20:37:56 INFO lead: acquired remote=192.0.2.1:12345892026/10/02 20:37:57 INFO lead: released remote=192.0.2.1:1234590--- PASS: TestLeadIncumbentWinsAfterRestart (2.43s)591=== RUN TestLeadEndsOnShutdown592=== PAUSE TestLeadEndsOnShutdown593=== RUN TestLeadEndsWhenItsConnectionHangs5942026/10/02 20:37:57 INFO lead: acquired remote=192.0.2.1:12345952026-10-02 20:37:59.063 UTC [429] FATAL: terminating connection due to administrator command5962026/10/02 20:37:59 INFO lead: acquired remote=192.0.2.1:12345972026/10/02 20:38:00 WARN lead: lock connection lost error="timeout: context deadline exceeded"5982026/10/02 20:38:00 INFO lead: released remote=192.0.2.1:12345992026/10/02 20:38:00 INFO lead: released remote=192.0.2.1:1234600--- PASS: TestLeadEndsWhenItsConnectionHangs (3.15s)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 TestOrphanedObjectsGC688=== PAUSE TestOrphanedObjectsGC689=== RUN TestOrphanedObjectsGCStressTest690=== PAUSE TestOrphanedObjectsGCStressTest691=== RUN TestCreatePin_ReservedPins692=== PAUSE TestCreatePin_ReservedPins693=== RUN TestConcurrentPinUpdatesAgree694=== PAUSE TestConcurrentPinUpdatesAgree695=== RUN TestCreatePinRejectsBadInput696=== PAUSE TestCreatePinRejectsBadInput697=== RUN TestDeletePinKeepsRowWhenS3Fails698=== PAUSE TestDeletePinKeepsRowWhenS3Fails699=== RUN TestPresentReportsOnlyClosureRoots700=== PAUSE TestPresentReportsOnlyClosureRoots701=== RUN TestPresentNotReportedWhileGCDeletesClosure702=== PAUSE TestPresentNotReportedWhileGCDeletesClosure703=== RUN TestParseSingleRange704=== PAUSE TestParseSingleRange705=== RUN TestProxyHeadersOnlyTrustedOnSocket706=== PAUSE TestProxyHeadersOnlyTrustedOnSocket707=== RUN TestIsValidCachePath708=== PAUSE TestIsValidCachePath709=== RUN TestReadProxyNarinfo710=== PAUSE TestReadProxyNarinfo711=== RUN TestReadProxyNarinfoAlreadyDecompressed712=== PAUSE TestReadProxyNarinfoAlreadyDecompressed713=== RUN TestReadProxyNarStreaming714=== PAUSE TestReadProxyNarStreaming715=== RUN TestReadProxy404716=== PAUSE TestReadProxy404717=== RUN TestReadProxyInvalidPath718=== PAUSE TestReadProxyInvalidPath719=== RUN TestReadProxyHead720=== PAUSE TestReadProxyHead721=== RUN TestReadProxyOutlastsServerWriteTimeout722=== PAUSE TestReadProxyOutlastsServerWriteTimeout723=== RUN TestReadProxyConditionalGet724=== PAUSE TestReadProxyConditionalGet725=== RUN TestReadProxyRootRedirectsToIndexHTML726=== PAUSE TestReadProxyRootRedirectsToIndexHTML727=== RUN TestReadProxyDisabled728=== PAUSE TestReadProxyDisabled729=== RUN TestReadRedirectNar730=== PAUSE TestReadRedirectNar731=== RUN TestReadRedirectKeepsNarinfoProxied732=== PAUSE TestReadRedirectKeepsNarinfoProxied733=== RUN TestReadProxyRangeRequest734=== PAUSE TestReadProxyRangeRequest735=== RUN TestReadRedirectUsesPublicS3URL736=== PAUSE TestReadRedirectUsesPublicS3URL737=== RUN TestPush_OverlappingRootsStoreOneRowPerKey738=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey739=== RUN TestPush_CompleteCommitsEveryRoot740=== PAUSE TestPush_CompleteCommitsEveryRoot741=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit742=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit743=== RUN TestPush_RejectsBadRequests744=== PAUSE TestPush_RejectsBadRequests745=== RUN TestPush_SignsNarinfosOfItsPendingObjects746=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects747=== RUN TestRedundantMultipartUpload748=== PAUSE TestRedundantMultipartUpload749=== RUN TestCompleteMultipartUpload_ErrorButObjectExists750=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists751=== RUN TestCompletedNarNotReofferedAcrossClosures752=== PAUSE TestCompletedNarNotReofferedAcrossClosures753=== RUN TestPresignedUploadRegisteredBeforeCommit754=== PAUSE TestPresignedUploadRegisteredBeforeCommit755=== RUN TestService_Rustfstest756=== PAUSE TestService_Rustfstest757=== RUN TestParseSize758=== PAUSE TestParseSize759=== RUN TestSkippedUploadsHandler760=== PAUSE TestSkippedUploadsHandler761=== RUN TestSystemdListenerNotActivated762--- PASS: TestSystemdListenerNotActivated (0.00s)763=== RUN TestWatchdogBeatsWhenHealthy764--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)765=== RUN TestWatchdogSkipsWhenUnhealthy7662026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7742026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7752026/10/02 20:38:00 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"776--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)777=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle778=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle779=== RUN TestProxyWriteTimeout780=== PAUSE TestProxyWriteTimeout781=== RUN TestPendingClosureWriteTimeout782=== PAUSE TestPendingClosureWriteTimeout783=== RUN TestIsValidUploadKey784=== PAUSE TestIsValidUploadKey785=== RUN TestUploadHandlersRejectInvalidKeys786=== PAUSE TestUploadHandlersRejectInvalidKeys787=== RUN TestUploadHandlersRejectOversizedBody788=== PAUSE TestUploadHandlersRejectOversizedBody789=== RUN TestService_cleanupPendingClosuresHandler790=== PAUSE TestService_cleanupPendingClosuresHandler791=== RUN TestService_createPendingClosureHandler792=== PAUSE TestService_createPendingClosureHandler793=== RUN TestService_verifyS3Integrity794=== PAUSE TestService_verifyS3Integrity795=== RUN TestCompleteMultipartUnregistered796=== PAUSE TestCompleteMultipartUnregistered797=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT798=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT799=== CONT TestSkippedUploadsHandler800=== CONT TestService_cleanupPendingClosuresHandler801=== CONT TestGCTaskStore_DeduplicateSameParams802=== CONT TestService_Rustfstest803=== CONT TestReadRedirectKeepsNarinfoProxied804=== CONT TestUploadHandlersRejectOversizedBody805=== CONT TestParseSize806=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT807=== CONT TestPresignedUploadRegisteredBeforeCommit808=== CONT TestCompleteMultipartUpload_ErrorButObjectExists809=== CONT TestCompletedNarNotReofferedAcrossClosures810=== CONT TestPush_SignsNarinfosOfItsPendingObjects811=== CONT TestCompleteMultipartUnregistered812=== CONT TestPush_RejectsBadRequests813=== CONT TestPendingClosureWriteTimeout814=== CONT TestPush_CompleteCommitsEveryRoot815=== CONT TestReadProxyRangeRequest816=== CONT TestUploadHandlersRejectInvalidKeys817=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info818=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info819=== CONT TestService_verifyS3Integrity820=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit821=== CONT TestPush_OverlappingRootsStoreOneRowPerKey822=== CONT TestReadRedirectUsesPublicS3URL823=== CONT TestService_AuthMiddleware824=== CONT TestProxyWriteTimeout825=== RUN TestProxyWriteTimeout/narinfo826=== CONT TestReadRedirectNar827--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)828--- PASS: TestParseSize (0.00s)829=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle830=== RUN TestPendingClosureWriteTimeout/empty831=== PAUSE TestPendingClosureWriteTimeout/empty832=== RUN TestPendingClosureWriteTimeout/400_objects833=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal8342026/10/02 20:38:00 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000835=== PAUSE TestProxyWriteTimeout/narinfo836=== RUN TestProxyWriteTimeout/1_GiB_nar837=== PAUSE TestPendingClosureWriteTimeout/400_objects838=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal839=== PAUSE TestProxyWriteTimeout/1_GiB_nar840=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key841=== RUN TestPendingClosureWriteTimeout/670k_objects842=== RUN TestProxyWriteTimeout/10_GiB_nar843=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key844=== PAUSE TestPendingClosureWriteTimeout/670k_objects845=== PAUSE TestProxyWriteTimeout/10_GiB_nar846=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline847=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline848=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key849=== RUN TestProxyWriteTimeout/unknown_size850=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key851=== CONT TestReadProxyOutlastsServerWriteTimeout852=== CONT TestService_createPendingClosureHandler853=== PAUSE TestProxyWriteTimeout/unknown_size854=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock855=== CONT TestParseSingleRange856--- PASS: TestSkippedUploadsHandler (0.04s)857=== RUN TestParseSingleRange/none858=== PAUSE TestParseSingleRange/none859=== RUN TestParseSingleRange/unknown_unit860=== PAUSE TestParseSingleRange/unknown_unit861=== RUN TestParseSingleRange/multi-range_ignored862=== PAUSE TestParseSingleRange/multi-range_ignored863=== RUN TestParseSingleRange/malformed_no_dash864=== PAUSE TestParseSingleRange/malformed_no_dash865=== RUN TestParseSingleRange/malformed_both_empty866=== PAUSE TestParseSingleRange/malformed_both_empty867=== RUN TestParseSingleRange/malformed_end_before_start868=== PAUSE TestParseSingleRange/malformed_end_before_start869=== RUN TestParseSingleRange/closed870=== PAUSE TestParseSingleRange/closed871=== RUN TestParseSingleRange/open-ended872=== PAUSE TestParseSingleRange/open-ended873=== RUN TestParseSingleRange/end_clamped_to_size874=== PAUSE TestParseSingleRange/end_clamped_to_size875=== RUN TestParseSingleRange/suffix876=== PAUSE TestParseSingleRange/suffix877=== RUN TestParseSingleRange/suffix_exceeds_size878=== PAUSE TestParseSingleRange/suffix_exceeds_size879=== RUN TestParseSingleRange/single_byte880=== PAUSE TestParseSingleRange/single_byte881=== RUN TestParseSingleRange/start_past_EOF882=== PAUSE TestParseSingleRange/start_past_EOF883=== RUN TestParseSingleRange/start_far_past_EOF884=== PAUSE TestParseSingleRange/start_far_past_EOF885=== CONT TestCacheStatsHandler886=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure887=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure888=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart889=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart890=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts891=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts892=== CONT TestPresentReportsOnlyClosureRoots893--- PASS: TestService_Rustfstest (0.51s)894=== CONT TestClientPushesUseOnePush8952026/10/02 20:38:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8962026/10/02 20:38:01 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst897--- PASS: TestCompleteMultipartUnregistered (0.53s)898=== CONT TestCreatePinRejectsBadInput8992026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures9002026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures9012026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures902=== RUN TestPush_RejectsBadRequests/no_roots903=== PAUSE TestPush_RejectsBadRequests/no_roots904=== RUN TestPush_RejectsBadRequests/no_objects905=== PAUSE TestPush_RejectsBadRequests/no_objects906=== RUN TestPush_RejectsBadRequests/bad_root907=== PAUSE TestPush_RejectsBadRequests/bad_root908=== RUN TestPush_RejectsBadRequests/root_not_in_objects909=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects910=== CONT TestClientIntegration911--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (0.59s)912=== CONT TestClientWithDependencies9132026/10/02 20:38:01 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9142026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures915=== CONT TestGetExistingObjectsLocksRows916--- PASS: TestPresignedUploadRegisteredBeforeCommit (0.62s)9172026/10/02 20:38:01 INFO Received cleanup request method=DELETE path=/api/pending_closures9182026/10/02 20:38:01 INFO Aborted multipart uploads count=0 kept=09192026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures9202026/10/02 20:38:01 INFO Received cleanup request method=DELETE path=/api/pending_closures9212026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures9222026/10/02 20:38:01 INFO Aborted multipart uploads count=1 kept=09232026/10/02 20:38:01 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete9242026-10-02 20:38:01.574 UTC [505] ERROR: Closure does not exist: id=19252026-10-02 20:38:01.574 UTC [505] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 12 at RAISE9262026-10-02 20:38:01.574 UTC [505] STATEMENT: -- name: CommitPendingClosure :exec927 SELECT commit_pending_closure($1::bigint)928 929--- PASS: TestService_cleanupPendingClosuresHandler (0.68s)930=== CONT TestSweepRechecksPendingAfterLocking931--- PASS: TestReadRedirectKeepsNarinfoProxied (0.73s)932=== CONT TestObjectStatsTrigger933--- PASS: TestReadProxyRangeRequest (0.74s)934=== CONT TestResolveDBConnectionString935=== RUN TestResolveDBConnectionString/flag_wins936=== PAUSE TestResolveDBConnectionString/flag_wins937=== RUN TestResolveDBConnectionString/file_when_flag_empty938=== PAUSE TestResolveDBConnectionString/file_when_flag_empty939=== RUN TestResolveDBConnectionString/missing_file_is_an_error940=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error941=== RUN TestResolveDBConnectionString/PGHOST_allows_empty942=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty943=== RUN TestResolveDBConnectionString/nothing_configured944=== PAUSE TestResolveDBConnectionString/nothing_configured945=== CONT TestOrphanedObjectsGC9462026/10/02 20:38:01 INFO Received push request method=POST path=/api/pushes9472026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures9482026/10/02 20:38:01 INFO Received push request method=POST path=/api/pushes949=== CONT TestDeduplicatedObjectsRecordedAsPending950--- PASS: TestCacheStatsHandler (0.80s)9512026/10/02 20:38:01 INFO Received push request method=POST path=/api/pushes952--- PASS: TestReadRedirectUsesPublicS3URL (0.86s)953=== CONT TestMultipartCleanup954--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (0.89s)955=== CONT TestGCSweepSkipsPendingObjects9562026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures9572026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures9582026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures959=== CONT TestLeadEndsOnShutdown960--- PASS: TestReadRedirectNar (0.91s)9612026/10/02 20:38:01 INFO Received uploads request method=POST path=/api/pending_closures9622026/10/02 20:38:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9632026/10/02 20:38:01 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLjI5Yzg0Y2E1LWRmYTctNDVlOC04MDBkLTBkY2NmMGMyYTVjNngxNzkwOTczNDgxNTgwNDQxOTg09642026/10/02 20:38:01 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"965--- PASS: TestService_AuthMiddleware (0.97s)966=== CONT TestPendingCleanupUsesOneCutoff9672026/10/02 20:38:01 INFO Received push request method=POST path=/api/pushes9682026/10/02 20:38:01 WARN Failed to abort multipart upload key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLjI5Yzg0Y2E1LWRmYTctNDVlOC04MDBkLTBkY2NmMGMyYTVjNngxNzkwOTczNDgxNTgwNDQxOTg0 error="Delete \"http://localhost:45423/bucket12/nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst?uploadId=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLjI5Yzg0Y2E1LWRmYTctNDVlOC04MDBkLTBkY2NmMGMyYTVjNngxNzkwOTczNDgxNTgwNDQxOTg0\": injected: abort refused"9692026/10/02 20:38:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9702026/10/02 20:38:01 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLjI5Yzg0Y2E1LWRmYTctNDVlOC04MDBkLTBkY2NmMGMyYTVjNngxNzkwOTczNDgxNTgwNDQxOTg09712026/10/02 20:38:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9722026/10/02 20:38:01 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLjI5Yzg0Y2E1LWRmYTctNDVlOC04MDBkLTBkY2NmMGMyYTVjNngxNzkwOTczNDgxNTgwNDQxOTg0 parts=19732026/10/02 20:38:01 INFO Signed narinfos id=1 count=1974--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (1.02s)975=== CONT TestServerTLSConfig976=== RUN TestServerTLSConfig/no_client_CA977=== PAUSE TestServerTLSConfig/no_client_CA978=== RUN TestServerTLSConfig/missing_CA_file979=== PAUSE TestServerTLSConfig/missing_CA_file980=== RUN TestServerTLSConfig/not_a_PEM_file981=== PAUSE TestServerTLSConfig/not_a_PEM_file982=== CONT TestGCMetrics9832026/10/02 20:38:01 INFO Received complete multipart upload request method=POST path=/api/multipart/complete984--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (1.03s)985=== CONT TestIsValidUploadKey986=== RUN TestIsValidUploadKey/narinfo987=== PAUSE TestIsValidUploadKey/narinfo988=== RUN TestIsValidUploadKey/nar_zst989=== PAUSE TestIsValidUploadKey/nar_zst990=== RUN TestIsValidUploadKey/nar_xz991=== PAUSE TestIsValidUploadKey/nar_xz992=== RUN TestIsValidUploadKey/nar_plain993=== PAUSE TestIsValidUploadKey/nar_plain994=== RUN TestIsValidUploadKey/listing995=== PAUSE TestIsValidUploadKey/listing996=== RUN TestIsValidUploadKey/build_log997=== PAUSE TestIsValidUploadKey/build_log998=== RUN TestIsValidUploadKey/build_log_home-manager_file999=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1000=== RUN TestIsValidUploadKey/build_log_plus_in_name1001=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1002=== RUN TestIsValidUploadKey/build_log_question_mark1003=== PAUSE TestIsValidUploadKey/build_log_question_mark1004=== RUN TestIsValidUploadKey/build_log_equals1005=== PAUSE TestIsValidUploadKey/build_log_equals1006=== RUN TestIsValidUploadKey/realisation1007=== PAUSE TestIsValidUploadKey/realisation1008=== RUN TestIsValidUploadKey/realisation_plus_in_output1009=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1010=== RUN TestIsValidUploadKey/nix-cache-info1011=== PAUSE TestIsValidUploadKey/nix-cache-info1012=== RUN TestIsValidUploadKey/index.html1013=== PAUSE TestIsValidUploadKey/index.html1014=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1015=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1016=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1017=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1018=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1019=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1020=== RUN TestIsValidUploadKey/traversal1021=== PAUSE TestIsValidUploadKey/traversal1022=== RUN TestIsValidUploadKey/traversal_nar1023=== PAUSE TestIsValidUploadKey/traversal_nar1024=== RUN TestIsValidUploadKey/absolute1025=== PAUSE TestIsValidUploadKey/absolute1026=== RUN TestIsValidUploadKey/empty_key1027=== PAUSE TestIsValidUploadKey/empty_key1028=== RUN TestIsValidUploadKey/unknown_type1029=== PAUSE TestIsValidUploadKey/unknown_type1030=== CONT TestReconnectLeavesObjectsUnlocked1031--- PASS: TestPresentReportsOnlyClosureRoots (0.64s)1032=== CONT TestReadProxyDisabled10332026/10/02 20:38:01 INFO Received create pin request method=POST path=/api/pins/deploy10342026/10/02 20:38:01 INFO Received create pin request method=POST path=/api/pins/deploy10352026/10/02 20:38:01 INFO Received create pin request method=POST path=/api/pins/deploy10362026/10/02 20:38:01 INFO Received create pin request method=POST path=/api/pins/deploy10372026/10/02 20:38:01 INFO Received create pin request method=POST path=/api/pins/deploy10382026/10/02 20:38:01 INFO Received create pin request method=POST path=/api/pins/deploy10392026/10/02 20:38:01 INFO Received create pin request method=POST path=/api/pins/deploy10402026/10/02 20:38:01 INFO Received create pin request method=POST path=/api/pins/deploy10412026/10/02 20:38:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10422026/10/02 20:38:02 INFO Received create pin request method=POST path=/api/pins/deploy10432026/10/02 20:38:02 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLjA3MmRmODUxLWQ2YTEtNDI3OS1iNTYyLWMxMjllZTM0NzE1N3gxNzkwOTczNDgxNDYxODMwODcy parts=1210442026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures1045--- PASS: TestCompletedNarNotReofferedAcrossClosures (1.14s)1046=== CONT TestGCAdvisoryLockBlocksConcurrentRun1047=== NAME TestClientIntegration1048 client_integration_test.go:334: Created store path: /build/TestClientIntegration159999187/002/store/zzhj9sqzmwjb0xxj69h4wjm63wq3aj09-test-file.txt1049=== CONT TestReadProxyConditionalGet1050--- PASS: TestGetExistingObjectsLocksRows (0.54s)10512026/10/02 20:38:02 INFO Aborted multipart uploads count=0 kept=010522026/10/02 20:38:02 WARN Force mode enabled - objects will be deleted immediately without grace period1053=== NAME TestClientWithDependencies1054 client_integration_test.go:735: Built derivation: /build/TestClientWithDependencies1731007739/001/store/m1qp6gf5r613fs72l1jssknm03vaqz4v-test-script10552026/10/02 20:38:02 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=010562026/10/02 20:38:02 INFO Vacuumed table table=pending_closures10572026/10/02 20:38:02 INFO Vacuumed table table=pending_objects10582026/10/02 20:38:02 INFO Vacuumed table table=multipart_uploads10592026/10/02 20:38:02 INFO Vacuumed table table=closures10602026/10/02 20:38:02 INFO Vacuumed table table=objects10612026/10/02 20:38:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1062 client_integration_test.go:737: Found 1 dependencies (including self)1063--- PASS: TestObjectStatsTrigger (0.49s)1064=== CONT TestConnectWaitsForAPeerMigration1065--- PASS: TestSweepRechecksPendingAfterLocking (0.54s)1066=== CONT TestConnectSerialisesConcurrentMigrations10672026/10/02 20:38:02 INFO Received push request method=POST path=/api/pushes10682026/10/02 20:38:02 INFO Received push request method=POST path=/api/pushes10692026/10/02 20:38:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10702026/10/02 20:38:02 INFO Uploading zzhj9sqzmwjb0xxj69h4wjm63wq3aj09-test-file.txt (152B)10712026/10/02 20:38:02 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLmJkNjA4YzI2LTgyMGUtNDcwMS04ZWNhLTY0MGE2OTFlMWU5OXgxNzkwOTczNDgxNjczNzEwMjA2 parts=1010722026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures10732026/10/02 20:38:02 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10742026/10/02 20:38:02 INFO Uploading 8qajx48s40yczsxf2zlllal44x76dvq1-shared-dep (136B)10752026/10/02 20:38:02 INFO Uploading yms1lmpxqpv1i8pcvacksgcqvvin88ch-a (216B)10762026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"10772026/10/02 20:38:02 WARN Failed to register uploaded object key=zzhj9sqzmwjb0xxj69h4wjm63wq3aj09.ls error="server returned 404: 404 page not found\n"10782026/10/02 20:38:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10792026/10/02 20:38:02 WARN Failed to register uploaded object key=zv1a76d1xw5pmbd9sb8bqwsxf96v7gn0.ls error="server returned 404: 404 page not found\n"10802026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/0vp20ihxaz7pn76dg55zjsg8gf64vmxp0kf6amn5arl1zxmfvwci.nar.zst error="server returned 404: 404 page not found\n"10812026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10822026/10/02 20:38:02 INFO Signed narinfos id=1 count=110832026/10/02 20:38:02 INFO Uploading 1 narinfos10842026/10/02 20:38:02 WARN Failed to register uploaded object key=yms1lmpxqpv1i8pcvacksgcqvvin88ch.ls error="server returned 404: 404 page not found\n"10852026/10/02 20:38:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10862026/10/02 20:38:02 WARN Failed to register uploaded object key=8qajx48s40yczsxf2zlllal44x76dvq1.ls error="server returned 404: 404 page not found\n"10872026/10/02 20:38:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10882026/10/02 20:38:02 INFO Signed narinfos id=1 count=310892026/10/02 20:38:02 INFO Received complete push request method=POST path=/api/pushes/1/complete10902026/10/02 20:38:02 INFO Uploading 3 narinfos10912026/10/02 20:38:02 WARN Failed to register uploaded object key=zzhj9sqzmwjb0xxj69h4wjm63wq3aj09.narinfo error="server returned 404: 404 page not found\n"10922026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures1093--- PASS: TestDeduplicatedObjectsRecordedAsPending (0.42s)1094=== CONT TestGCTaskStore_StartNew1095--- PASS: TestGCTaskStore_StartNew (0.00s)1096=== CONT TestReadProxyHead10972026/10/02 20:38:02 WARN Failed to register uploaded object key=8qajx48s40yczsxf2zlllal44x76dvq1.narinfo error="server returned 404: 404 page not found\n"10982026/10/02 20:38:02 INFO Upload complete. (78ms)10992026/10/02 20:38:02 INFO Received complete push request method=POST path=/api/pushes/1/complete11002026/10/02 20:38:02 WARN Failed to register uploaded object key=zv1a76d1xw5pmbd9sb8bqwsxf96v7gn0.narinfo error="server returned 404: 404 page not found\n"11012026/10/02 20:38:02 WARN Failed to register uploaded object key=yms1lmpxqpv1i8pcvacksgcqvvin88ch.narinfo error="server returned 404: 404 page not found\n"11022026/10/02 20:38:02 INFO Upload complete. (92ms)11032026/10/02 20:38:02 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLjhlYWExZmZkLWIyNzAtNGRlYy04YTE3LTJjZWVhZDBiYmE1NngxNzkwOTczNDgxNzE5MjQxMjE4 parts=1011042026/10/02 20:38:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete1105=== NAME TestClientPushesUseOnePush1106 client_pushes_test.go:97: Retrieved narinfo from S3:1107 StorePath: /build/TestClientPushesUseOnePush3775749535/001/store/8qajx48s40yczsxf2zlllal44x76dvq1-shared-dep1108 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1109 Compression: zstd1110 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821111 NarSize: 1361112 References: 1113 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n11142026/10/02 20:38:02 INFO Completed upload id=111152026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures1116 client_pushes_test.go:97: Retrieved narinfo from S3:1117 StorePath: /build/TestClientPushesUseOnePush3775749535/001/store/yms1lmpxqpv1i8pcvacksgcqvvin88ch-a1118 URL: nar/0vp20ihxaz7pn76dg55zjsg8gf64vmxp0kf6amn5arl1zxmfvwci.nar.zst1119 Compression: zstd1120 NarHash: sha256:0vp20ihxaz7pn76dg55zjsg8gf64vmxp0kf6amn5arl1zxmfvwci1121 NarSize: 2161122 References: /build/TestClientPushesUseOnePush3775749535/001/store/8qajx48s40yczsxf2zlllal44x76dvq1-shared-dep1123 CA: text:sha256:1x2cff1q16zq34g239b1ii8yah36ikf0rhqm39gcfm5dmna6npqk11242026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures11252026/10/02 20:38:02 INFO Received push request method=POST path=/api/pushes11262026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures1127 client_pushes_test.go:97: Retrieved narinfo from S3:1128 StorePath: /build/TestClientPushesUseOnePush3775749535/001/store/zv1a76d1xw5pmbd9sb8bqwsxf96v7gn0-b1129 URL: nar/0vp20ihxaz7pn76dg55zjsg8gf64vmxp0kf6amn5arl1zxmfvwci.nar.zst1130 Compression: zstd1131 NarHash: sha256:0vp20ihxaz7pn76dg55zjsg8gf64vmxp0kf6amn5arl1zxmfvwci1132 NarSize: 2161133 References: /build/TestClientPushesUseOnePush3775749535/001/store/8qajx48s40yczsxf2zlllal44x76dvq1-shared-dep1134 CA: text:sha256:1x2cff1q16zq34g239b1ii8yah36ikf0rhqm39gcfm5dmna6npqk11352026/10/02 20:38:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)11362026/10/02 20:38:02 INFO Uploading m1qp6gf5r613fs72l1jssknm03vaqz4v-test-script (136B)11372026/10/02 20:38:02 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo11382026/10/02 20:38:02 WARN Found objects in DB but missing from S3, will re-upload count=111392026/10/02 20:38:02 INFO All 1 paths already cached1140=== NAME TestClientIntegration1141 client_integration_test.go:360: Retrieved narinfo from S3:1142 StorePath: /build/TestClientIntegration159999187/002/store/zzhj9sqzmwjb0xxj69h4wjm63wq3aj09-test-file.txt1143 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1144 Compression: zstd1145 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11146 NarSize: 1521147 References: 1148 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk111492026/10/02 20:38:02 INFO Received complete upload request method=POST path=/api/pending_closures/3/complete11502026/10/02 20:38:02 INFO Completed upload id=31151 client_integration_test.go:361: Retrieved .ls file from S3 (compressed size: 77 bytes)11522026-10-02 20:38:02.227 UTC [902] ERROR: duplicate key value violates unique constraint "pg_type_typname_nsp_index"11532026-10-02 20:38:02.227 UTC [902] DETAIL: Key (typname, typnamespace)=(goose_db_version, 2200) already exists.11542026-10-02 20:38:02.227 UTC [902] STATEMENT: CREATE TABLE goose_db_version (1155 id integer PRIMARY KEY GENERATED BY DEFAULT AS IDENTITY,1156 version_id bigint NOT NULL,1157 is_applied boolean NOT NULL,1158 tstamp timestamp NOT NULL DEFAULT now()1159 )1160 client_integration_test.go:361: Decompressed .ls content (64 bytes):1161 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}11622026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"11632026/10/02 20:38:02 INFO Aborted multipart uploads count=0 kept=011642026/10/02 20:38:02 WARN Failed to register uploaded object key=log/ahr02q3aylclglc1vw2ljkqzv30iy8yi-test-script.drv error="server returned 404: 404 page not found\n"11652026/10/02 20:38:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11662026/10/02 20:38:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign11672026/10/02 20:38:02 WARN Force mode enabled - objects will be deleted immediately without grace period11682026/10/02 20:38:02 WARN Failed to register uploaded object key=m1qp6gf5r613fs72l1jssknm03vaqz4v.ls error="server returned 404: 404 page not found\n"11692026/10/02 20:38:02 INFO Signed narinfos id=1 count=111702026/10/02 20:38:02 INFO Uploading 1 narinfos11712026/10/02 20:38:02 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=011722026/10/02 20:38:02 INFO Vacuumed table table=pending_closures1173--- PASS: TestClientPushesUseOnePush (0.81s)1174=== CONT TestGCEndsOnShutdown1175=== RUN TestGCEndsOnShutdown/before_the_run1176=== PAUSE TestGCEndsOnShutdown/before_the_run1177=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1178=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1179=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1180=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1181=== CONT TestCommitRacingPendingCleanupKeepsObjects11822026/10/02 20:38:02 INFO Vacuumed table table=pending_objects11832026/10/02 20:38:02 INFO Received complete push request method=POST path=/api/pushes/1/complete11842026/10/02 20:38:02 INFO Vacuumed table table=multipart_uploads11852026/10/02 20:38:02 WARN Failed to register uploaded object key=m1qp6gf5r613fs72l1jssknm03vaqz4v.narinfo error="server returned 404: 404 page not found\n"11862026/10/02 20:38:02 INFO Vacuumed table table=closures1187--- PASS: TestService_verifyS3Integrity (1.33s)1188=== CONT TestPresentNotReportedWhileGCDeletesClosure11892026/10/02 20:38:02 INFO Vacuumed table table=objects11902026/10/02 20:38:02 INFO lead: acquired remote=192.0.2.1:123411912026/10/02 20:38:02 INFO Upload complete. (91ms)11922026/10/02 20:38:02 INFO Completed multipart upload object_key=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa00000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLmZmMWI1NDRiLWVhMWUtNGM2OS04MzFjLTA0ZDVjOGRiNjhlZHgxNzkwOTczNDgxNzgxNDc4NzYw parts=1011932026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures11942026/10/02 20:38:02 INFO Aborted multipart uploads count=0 kept=011952026/10/02 20:38:02 WARN Force mode enabled - objects will be deleted immediately without grace period1196=== CONT TestClientCADerivations1197--- PASS: TestGCSweepSkipsPendingObjects (0.47s)11982026/10/02 20:38:02 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=011992026/10/02 20:38:02 INFO Vacuumed table table=pending_closures12002026/10/02 20:38:02 INFO Vacuumed table table=pending_objects12012026/10/02 20:38:02 INFO Vacuumed table table=multipart_uploads12022026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures12032026/10/02 20:38:02 INFO Vacuumed table table=closures12042026/10/02 20:38:02 INFO Vacuumed table table=objects1205=== NAME TestClientWithDependencies1206 client_integration_test.go:753: Skipping nix copy test - isolated store (/build/TestClientWithDependencies1731007739/001/store) requires matching store prefix12072026/10/02 20:38:02 INFO Received cleanup request method=DELETE path=/api/pending_closures12082026/10/02 20:38:02 INFO Received push request method=POST path=/api/pushes12092026/10/02 20:38:02 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket36/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""12102026/10/02 20:38:02 INFO Aborted multipart uploads count=0 kept=112112026/10/02 20:38:02 INFO Aborted multipart uploads count=0 kept=012122026/10/02 20:38:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12132026/10/02 20:38:02 INFO Received cleanup request method=DELETE path=/api/pending_closures12142026/10/02 20:38:02 INFO Object in database but missing from S3 key=zzhj9sqzmwjb0xxj69h4wjm63wq3aj09.ls12152026/10/02 20:38:02 WARN Found objects in DB but missing from S3, will re-upload count=112162026/10/02 20:38:02 INFO Received cleanup request method=DELETE path=/api/pending_closures12172026/10/02 20:38:02 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12182026/10/02 20:38:02 WARN Force mode enabled - objects will be deleted immediately without grace period12192026/10/02 20:38:02 INFO Aborted multipart uploads count=1 kept=012202026/10/02 20:38:02 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=012212026/10/02 20:38:02 INFO Vacuumed table table=pending_closures12222026/10/02 20:38:02 INFO Vacuumed table table=pending_objects12232026/10/02 20:38:02 INFO Vacuumed table table=multipart_uploads12242026/10/02 20:38:02 INFO Vacuumed table table=closures12252026/10/02 20:38:02 INFO Vacuumed table table=objects12262026/10/02 20:38:02 INFO Received complete push request method=POST path=/api/pushes/2/complete12272026/10/02 20:38:02 WARN Failed to register uploaded object key=zzhj9sqzmwjb0xxj69h4wjm63wq3aj09.ls error="server returned 404: 404 page not found\n"1228=== CONT TestPushWaitsForSweepHoldingRow1229--- PASS: TestClientWithDependencies (0.81s)12302026/10/02 20:38:02 INFO Upload complete. (60ms)1231=== NAME TestClientIntegration1232 client_integration_test.go:389: Retrieved .ls file from S3 (compressed size: 62 bytes)12332026/10/02 20:38:02 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLjE1M2Y2YzA3LTVlZjItNDE1OS1iN2NiLTVlZjQ3NDA4OWQ4ZXgxNzkwOTczNDgxODI4MTY2MjYy parts=101234 client_integration_test.go:389: Decompressed .ls content (49 bytes):1235 {"version":1,"root":{"type":"regular","size":39}}12362026/10/02 20:38:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12372026/10/02 20:38:02 INFO Completed upload id=11238=== CONT TestClientFallsBackToClosures1239--- PASS: TestMultipartCleanup (0.56s)12402026/10/02 20:38:02 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012412026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures12422026/10/02 20:38:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures12432026/10/02 20:38:02 INFO Aborted multipart uploads count=0 kept=012442026/10/02 20:38:02 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=01245--- PASS: TestGCMetrics (0.43s)1246=== CONT TestDeletePinKeepsRowWhenS3Fails1247--- PASS: TestReconnectLeavesObjectsUnlocked (0.42s)1248=== CONT TestService_ReadAuthMiddleware12492026/10/02 20:38:02 INFO Vacuumed table table=pending_closures12502026/10/02 20:38:02 INFO Vacuumed table table=pending_objects12512026/10/02 20:38:02 INFO Vacuumed table table=multipart_uploads1252=== CONT TestCacheConfigHandler1253--- PASS: TestReadProxyDisabled (0.43s)1254=== RUN TestCacheConfigHandler/full_config,_no_issuer1255=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1256=== RUN TestCacheConfigHandler/no_cache_url_configured1257=== PAUSE TestCacheConfigHandler/no_cache_url_configured1258=== RUN TestCacheConfigHandler/no_signing_keys1259=== PAUSE TestCacheConfigHandler/no_signing_keys1260=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1261=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1262=== CONT TestReadProxyInvalidPath12632026/10/02 20:38:02 INFO Vacuumed table table=closures12642026/10/02 20:38:02 INFO Vacuumed table table=objects12652026/10/02 20:38:02 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001266=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1267--- PASS: TestService_createPendingClosureHandler (1.49s)12682026/10/02 20:38:02 INFO Received push request method=POST path=/api/pushes12692026/10/02 20:38:02 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12702026/10/02 20:38:02 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"12712026/10/02 20:38:02 INFO Received complete push request method=POST path=/api/pushes/3/complete12722026/10/02 20:38:02 WARN Failed to register uploaded object key=zzhj9sqzmwjb0xxj69h4wjm63wq3aj09.ls error="server returned 404: 404 page not found\n"12732026/10/02 20:38:02 INFO Upload complete. (70ms)1274=== NAME TestClientIntegration1275 client_integration_test.go:405: Retrieved .ls file from S3 (compressed size: 62 bytes)1276 client_integration_test.go:405: Decompressed .ls content (49 bytes):1277 {"version":1,"root":{"type":"regular","size":39}}1278--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (0.46s)1279=== CONT TestReadProxy4041280=== NAME TestOrphanedObjectsGC1281 orphaned_objects_gc_test.go:290: GC Test Summary:1282 orphaned_objects_gc_test.go:291: - Kept: 2 objects from closure A1283 orphaned_objects_gc_test.go:292: - Deleted: 2 objects from closure B1284 orphaned_objects_gc_test.go:293: - Deleted: 6 orphaned chain objects (X1->X2->X3)1285 orphaned_objects_gc_test.go:294: - Deleted: 2 orphaned single objects (Y)1286 orphaned_objects_gc_test.go:295: - Total deleted: 10 objects1287=== CONT TestLeadElectsOneAndHandsOver1288--- PASS: TestOrphanedObjectsGC (0.89s)12892026/10/02 20:38:02 INFO Aborted multipart uploads count=0 kept=012902026/10/02 20:38:02 WARN Force mode enabled - objects will be deleted immediately without grace period12912026/10/02 20:38:02 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=012922026/10/02 20:38:02 INFO Vacuumed table table=pending_closures1293--- PASS: TestReadProxyConditionalGet (0.49s)1294=== CONT TestConcurrentPinUpdatesAgree12952026/10/02 20:38:02 INFO Vacuumed table table=pending_objects12962026/10/02 20:38:02 INFO Vacuumed table table=multipart_uploads12972026/10/02 20:38:02 INFO Vacuumed table table=closures12982026/10/02 20:38:02 INFO Vacuumed table table=objects12992026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures1300--- PASS: TestReadProxyHead (0.40s)1301=== CONT TestClientMultipleUploads13022026/10/02 20:38:02 INFO Received push request method=POST path=/api/pushes13032026/10/02 20:38:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13042026/10/02 20:38:02 INFO Uploading bn6l25bjg4mc04a7lkcah250zpaf4gsx-lost-commit.txt (152B)1305--- PASS: TestCommitRacingPendingCleanupKeepsObjects (0.35s)1306=== CONT TestService_ReadScope_PublicByDefault13072026/10/02 20:38:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13082026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst error="server returned 404: 404 page not found\n"13092026/10/02 20:38:02 WARN Failed to register uploaded object key=bn6l25bjg4mc04a7lkcah250zpaf4gsx.ls error="server returned 404: 404 page not found\n"13102026/10/02 20:38:02 INFO Received sign narinfos request method=POST path=/api/pushes/4/sign13112026/10/02 20:38:02 INFO Signed narinfos id=4 count=113122026/10/02 20:38:02 INFO Uploading 1 narinfos13132026/10/02 20:38:02 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLjYzM2M0MjJlLTA2NjQtNGQyZi1hMzJhLTk3YmVhNzk4OTM3MXgxNzkwOTczNDgxNjc0NjU3MDU1 parts=1013142026/10/02 20:38:02 INFO Received complete push request method=POST path=/api/pushes/1/complete13152026/10/02 20:38:02 INFO Received complete push request method=POST path=/api/pushes/4/complete13162026/10/02 20:38:02 WARN Failed to register uploaded object key=bn6l25bjg4mc04a7lkcah250zpaf4gsx.narinfo error="server returned 404: 404 page not found\n"13172026/10/02 20:38:02 WARN Request failed, retrying attempt=1 max_attempts=6 backoff=100ms error="Post \"http://127.0.0.1:33713/api/pushes/4/complete\": EOF" url=http://127.0.0.1:33713/api/pushes/4/complete13182026/10/02 20:38:02 INFO Received create pin request method=POST path=/api/pins/app13192026/10/02 20:38:02 INFO Received push request method=POST path=/api/pushes13202026/10/02 20:38:02 INFO Created/updated pin name=app store_path=/nix/store/cccccccccccccccccccccccccccccccc-app narinfo_key=cccccccccccccccccccccccccccccccc.narinfo13212026/10/02 20:38:02 INFO Received delete pin request method=DELETE path=/api/pins/app13222026/10/02 20:38:02 ERROR Failed to delete pin from S3 key=pins/app error="Get \"http://127.0.0.1:1/bucket52/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"13232026/10/02 20:38:02 INFO Received delete pin request method=DELETE path=/api/pins/app1324=== NAME TestClientCADerivations1325 client_ca_test.go:136: Built CA derivation: /build/TestClientCADerivations1163529136/001/store/dfbjg200lpc5q9rjh5rlk168xcmx9s8f-ca-test13262026/10/02 20:38:02 INFO Deleted pin name=app1327=== CONT TestService_AuthMiddleware_MTLSProxyHeader1328--- PASS: TestService_ReadAuthMiddleware (0.29s)1329=== CONT TestRedundantMultipartUpload1330--- PASS: TestDeletePinKeepsRowWhenS3Fails (0.29s)1331=== NAME TestClientCADerivations1332 client_ca_test.go:139: Found 1 dependencies (including self)1333--- PASS: TestReadProxyInvalidPath (0.30s)1334=== CONT TestReadProxyNarStreaming13352026/10/02 20:38:02 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"13362026/10/02 20:38:02 WARN mTLS auth: bound subjects configured but subject DN unavailable13372026/10/02 20:38:02 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"13382026/10/02 20:38:02 INFO Aborted multipart uploads count=0 kept=01339=== CONT TestService_RequireScope_OIDC1340--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (0.29s)13412026/10/02 20:38:02 WARN Force mode enabled - objects will be deleted immediately without grace period13422026/10/02 20:38:02 INFO Received complete push request method=POST path=/api/pushes/4/complete13432026-10-02 20:38:02.719 UTC [539] ERROR: Push does not exist: id=413442026-10-02 20:38:02.719 UTC [539] CONTEXT: PL/pgSQL function commit_push(bigint) line 9 at RAISE13452026-10-02 20:38:02.719 UTC [539] STATEMENT: -- name: CommitPush :exec1346 SELECT commit_push($1::bigint)1347 13482026/10/02 20:38:02 INFO Upload complete. (177ms)13492026/10/02 20:38:02 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=01350=== NAME TestClientIntegration1351 client_integration_test.go:435: Retrieved narinfo from S3:1352 StorePath: /build/TestClientIntegration159999187/002/store/bn6l25bjg4mc04a7lkcah250zpaf4gsx-lost-commit.txt1353 URL: nar/04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl.nar.zst1354 Compression: zstd1355 NarHash: sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl1356 NarSize: 1521357 References: 1358 CA: fixed:r:sha256:04d5klw9iix884nk82y7nlkps8afh2bg119y7zkvcf1pc1x2y2jl13592026/10/02 20:38:02 INFO Vacuumed table table=pending_closures13602026/10/02 20:38:02 INFO Vacuumed table table=pending_objects1361 client_integration_test.go:438: Testing garbage collection...13622026/10/02 20:38:02 INFO Vacuumed table table=multipart_uploads13632026/10/02 20:38:02 INFO Vacuumed table table=closures13642026/10/02 20:38:02 INFO lead: acquired remote=192.0.2.1:123413652026/10/02 20:38:02 INFO Vacuumed table table=objects13662026/10/02 20:38:02 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13672026/10/02 20:38:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures13682026/10/02 20:38:02 INFO Received create pin request method=POST path=/api/pins/app13692026/10/02 20:38:02 INFO Garbage collection started13702026/10/02 20:38:02 INFO Aborted multipart uploads count=0 kept=01371=== CONT TestProxyHeadersOnlyTrustedOnSocket13722026/10/02 20:38:02 INFO Received create pin request method=POST path=/api/pins/app1373--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (1.86s)13742026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures13752026/10/02 20:38:02 INFO Completed multipart upload object_key=nar/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb00000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLjkwNDE4Nzg1LTdkNGItNDk3YS05ZmZlLTYyMzY2YTcyOWIwZHgxNzkwOTczNDgxNzgxOTA3MjQ0 parts=1013762026/10/02 20:38:02 WARN Force mode enabled - objects will be deleted immediately without grace period13772026/10/02 20:38:02 INFO Received push request method=POST path=/api/pushes13782026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures13792026/10/02 20:38:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)13802026/10/02 20:38:02 INFO Uploading dfbjg200lpc5q9rjh5rlk168xcmx9s8f-ca-test (144B)13812026/10/02 20:38:02 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13822026/10/02 20:38:02 INFO Uploading 106nnjzhix4j53nwapdhry047jgj2sxd-b (216B)13832026/10/02 20:38:02 INFO Uploading mb55ldbg7cb9ad5rzq4iksig4v902h8v-shared-dep (136B)13842026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"13852026/10/02 20:38:02 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=013862026/10/02 20:38:02 WARN Failed to register uploaded object key=log/fwvp6vi59a9bvxpxbql15h9qlmi0fspw-ca-test.drv error="server returned 404: 404 page not found\n"13872026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/1nqhmdxmg9wacn7zclh2x2g5dkhsm2n60gm6n7nj664jiifvvkvd.nar.zst error="server returned 404: 404 page not found\n"13882026/10/02 20:38:02 WARN Failed to register uploaded object key=dfbjg200lpc5q9rjh5rlk168xcmx9s8f.ls error="server returned 404: 404 page not found\n"13892026/10/02 20:38:02 INFO Vacuumed table table=pending_closures13902026/10/02 20:38:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign13912026/10/02 20:38:02 INFO Signed narinfos id=1 count=113922026/10/02 20:38:02 INFO Uploading 1 narinfos13932026/10/02 20:38:02 WARN Failed to register uploaded object key=0hb9fzg5ldg99f178x5398pqkyv24s9a.ls error="server returned 404: 404 page not found\n"13942026/10/02 20:38:02 WARN Failed to register uploaded object key=106nnjzhix4j53nwapdhry047jgj2sxd.ls error="server returned 404: 404 page not found\n"13952026/10/02 20:38:02 INFO Vacuumed table table=pending_objects13962026/10/02 20:38:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"13972026/10/02 20:38:02 INFO Vacuumed table table=multipart_uploads13982026/10/02 20:38:02 INFO Vacuumed table table=closures13992026/10/02 20:38:02 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14002026/10/02 20:38:02 WARN Failed to register uploaded object key=mb55ldbg7cb9ad5rzq4iksig4v902h8v.ls error="server returned 404: 404 page not found\n"14012026/10/02 20:38:02 INFO Signed narinfos id=1 count=214022026/10/02 20:38:02 INFO Vacuumed table table=objects14032026/10/02 20:38:02 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14042026/10/02 20:38:02 INFO Signed narinfos id=2 count=214052026/10/02 20:38:02 INFO Uploading 4 narinfos1406=== CONT TestTombstonedObjectOfferedWithoutWaiting14072026/10/02 20:38:02 INFO Received complete push request method=POST path=/api/pushes/1/complete1408--- PASS: TestService_ReadScope_PublicByDefault (0.23s)14092026/10/02 20:38:02 WARN Failed to register uploaded object key=dfbjg200lpc5q9rjh5rlk168xcmx9s8f.narinfo error="server returned 404: 404 page not found\n"1410=== NAME TestClientMultipleUploads1411 client_integration_test.go:480: Created store path 0: /build/TestClientMultipleUploads2119465974/001/store/7w2rqqj5058sqli1xssh00g29awqc0gz-test-file-0.txt14122026/10/02 20:38:02 WARN Failed to register uploaded object key=mb55ldbg7cb9ad5rzq4iksig4v902h8v.narinfo error="server returned 404: 404 page not found\n"14132026/10/02 20:38:02 WARN Failed to register uploaded object key=mb55ldbg7cb9ad5rzq4iksig4v902h8v.narinfo error="server returned 404: 404 page not found\n"14142026/10/02 20:38:02 INFO Upload complete. (129ms)14152026/10/02 20:38:02 WARN Failed to register uploaded object key=106nnjzhix4j53nwapdhry047jgj2sxd.narinfo error="server returned 404: 404 page not found\n"14162026/10/02 20:38:02 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14172026/10/02 20:38:02 WARN Failed to register uploaded object key=0hb9fzg5ldg99f178x5398pqkyv24s9a.narinfo error="server returned 404: 404 page not found\n"1418=== NAME TestClientCADerivations1419 client_ca_test.go:180: Narinfo contains CA field: StorePath: /build/TestClientCADerivations1163529136/001/store/dfbjg200lpc5q9rjh5rlk168xcmx9s8f-ca-test1420 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1421 Compression: zstd1422 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1423 NarSize: 1441424 References: 1425 Deriver: /build/TestClientCADerivations1163529136/001/store/fwvp6vi59a9bvxpxbql15h9qlmi0fspw-ca-test.drv1426 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1427 client_ca_test.go:185: Checking for realisation files in S3...1428 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1429 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache14302026/10/02 20:38:02 INFO Completed upload id=114312026/10/02 20:38:02 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14322026/10/02 20:38:02 INFO Completed upload id=214332026/10/02 20:38:02 INFO Upload complete. (104ms)1434=== NAME TestClientFallsBackToClosures1435 client_pushes_test.go:112: Retrieved narinfo from S3:1436 StorePath: /build/TestClientFallsBackToClosures3908578124/001/store/mb55ldbg7cb9ad5rzq4iksig4v902h8v-shared-dep1437 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1438 Compression: zstd1439 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821440 NarSize: 1361441 References: 1442 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1443=== CONT TestService_AuthMiddleware_OIDC1444--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (0.20s)1445=== NAME TestClientFallsBackToClosures1446 client_pushes_test.go:112: Retrieved narinfo from S3:1447 StorePath: /build/TestClientFallsBackToClosures3908578124/001/store/0hb9fzg5ldg99f178x5398pqkyv24s9a-a1448 URL: nar/1nqhmdxmg9wacn7zclh2x2g5dkhsm2n60gm6n7nj664jiifvvkvd.nar.zst1449 Compression: zstd1450 NarHash: sha256:1nqhmdxmg9wacn7zclh2x2g5dkhsm2n60gm6n7nj664jiifvvkvd1451 NarSize: 2161452 References: /build/TestClientFallsBackToClosures3908578124/001/store/mb55ldbg7cb9ad5rzq4iksig4v902h8v-shared-dep1453 CA: text:sha256:07p9lrqnhl26lib96044gf0yl8q70zxpp2abyww6nk66k1fifaaw14542026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures1455 client_pushes_test.go:112: Retrieved narinfo from S3:1456 StorePath: /build/TestClientFallsBackToClosures3908578124/001/store/106nnjzhix4j53nwapdhry047jgj2sxd-b1457 URL: nar/1nqhmdxmg9wacn7zclh2x2g5dkhsm2n60gm6n7nj664jiifvvkvd.nar.zst1458 Compression: zstd1459 NarHash: sha256:1nqhmdxmg9wacn7zclh2x2g5dkhsm2n60gm6n7nj664jiifvvkvd1460 NarSize: 2161461 References: /build/TestClientFallsBackToClosures3908578124/001/store/mb55ldbg7cb9ad5rzq4iksig4v902h8v-shared-dep1462 CA: text:sha256:07p9lrqnhl26lib96044gf0yl8q70zxpp2abyww6nk66k1fifaaw1463=== NAME TestClientMultipleUploads1464 client_integration_test.go:480: Created store path 1: /build/TestClientMultipleUploads2119465974/001/store/ax5998sq2vmgg1amc8lzx6vnplan6qyj-test-file-1.txt14652026/10/02 20:38:02 INFO Received uploads request method=POST path=/api/pending_closures1466--- PASS: TestClientFallsBackToClosures (0.56s)1467=== CONT TestClientErrorHandling1468=== RUN TestClientErrorHandling/InvalidStorePath1469=== PAUSE TestClientErrorHandling/InvalidStorePath1470=== RUN TestClientErrorHandling/InvalidAuthToken1471=== PAUSE TestClientErrorHandling/InvalidAuthToken1472=== RUN TestClientErrorHandling/ServerNotAvailable1473=== PAUSE TestClientErrorHandling/ServerNotAvailable1474=== CONT TestReadProxyNarinfoAlreadyDecompressed1475=== NAME TestClientMultipleUploads1476 client_integration_test.go:480: Created store path 2: /build/TestClientMultipleUploads2119465974/001/store/vw1gvf3swqxvpphqirwa7yvhkdsaq3ld-test-file-2.txt1477=== CONT TestCreatePin_ReservedPins1478--- PASS: TestReadProxyNarStreaming (0.23s)14792026/10/02 20:38:02 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:45427/oidc1480=== NAME TestClientCADerivations1481 client_ca_test.go:258: nix copy output: warning: you don't have Internet access; disabling some network-dependent features1482 warning: failed to create TLS context for AWS credential providers; SSO, STS WebIdentity, and ECS container authentication will be unavailable1483 error: binary cache 's3://bucket49?endpoint=http://localhost:45423®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/build/TestClientCADerivations1163529136/001/store'1484 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 114852026/10/02 20:38:02 INFO Starting HTTP server address=127.0.0.1:3375914862026/10/02 20:38:02 INFO Starting HTTP server address=/build/TestProxyHeadersOnlyTrustedOnSocket204448307/001/proxy.sock14872026/10/02 20:38:02 WARN mTLS auth: subject not in bound subjects subject="CN=someone"14882026/10/02 20:38:02 INFO Shutdown signal received, draining in-flight requests timeout=10s1489--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.19s)1490=== CONT TestPinProtectsFromGC1491--- PASS: TestClientCADerivations (0.70s)1492=== CONT TestOrphanedObjectsGCStressTest14932026/10/02 20:38:02 INFO Received push request method=POST path=/api/pushes1494--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.75s)1495=== CONT TestService_NativeMTLS14962026/10/02 20:38:02 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14972026/10/02 20:38:02 INFO Uploading 7w2rqqj5058sqli1xssh00g29awqc0gz-test-file-0.txt (160B)14982026/10/02 20:38:02 INFO Uploading vw1gvf3swqxvpphqirwa7yvhkdsaq3ld-test-file-2.txt (160B)14992026/10/02 20:38:02 INFO Uploading ax5998sq2vmgg1amc8lzx6vnplan6qyj-test-file-1.txt (160B)15002026/10/02 20:38:02 INFO Received create pin request method=POST path=/api/pins/deploy15012026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures15022026/10/02 20:38:03 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"15032026/10/02 20:38:03 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"15042026/10/02 20:38:03 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"15052026/10/02 20:38:03 INFO Created/updated pin name=deploy store_path="/nix/store/dddddddddddddddddddddddddddddddd-app-1.0+git_x?y=z" narinfo_key=dddddddddddddddddddddddddddddddd.narinfo15062026/10/02 20:38:03 WARN Failed to register uploaded object key=7w2rqqj5058sqli1xssh00g29awqc0gz.ls error="server returned 404: 404 page not found\n"15072026/10/02 20:38:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:38679/oidc15082026/10/02 20:38:03 WARN Failed to register uploaded object key=ax5998sq2vmgg1amc8lzx6vnplan6qyj.ls error="server returned 404: 404 page not found\n"15092026/10/02 20:38:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15102026/10/02 20:38:03 WARN Failed to register uploaded object key=vw1gvf3swqxvpphqirwa7yvhkdsaq3ld.ls error="server returned 404: 404 page not found\n"15112026/10/02 20:38:03 INFO Signed narinfos id=1 count=315122026/10/02 20:38:03 INFO Uploading 3 narinfos15132026/10/02 20:38:03 WARN Failed to register uploaded object key=ax5998sq2vmgg1amc8lzx6vnplan6qyj.narinfo error="server returned 404: 404 page not found\n"15142026/10/02 20:38:03 WARN Failed to register uploaded object key=vw1gvf3swqxvpphqirwa7yvhkdsaq3ld.narinfo error="server returned 404: 404 page not found\n"15152026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/1/complete15162026/10/02 20:38:03 WARN Failed to register uploaded object key=7w2rqqj5058sqli1xssh00g29awqc0gz.narinfo error="server returned 404: 404 page not found\n"1517=== CONT TestPushDedupSurvivesConcurrentGC1518--- PASS: TestTombstonedObjectOfferedWithoutWaiting (0.20s)1519=== CONT TestGCSweepDeliversEachKeyOnce1520--- PASS: TestCreatePinRejectsBadInput (1.58s)15212026/10/02 20:38:03 INFO Upload complete. (94ms)1522=== NAME TestClientMultipleUploads1523 client_integration_test.go:491: Uploaded 3 paths in 130.505299ms15242026/10/02 20:38:03 WARN Rate limiter enabled after throttle name=s3-test rate=515252026/10/02 20:38:03 WARN S3 rate limit hit during proxy key=4hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo error="Please reduce your request rate."1526=== CONT TestFailedS3DeleteKeepsTombstone1527--- PASS: TestClientMultipleUploads (0.50s)1528--- PASS: TestReadProxyNarinfoAlreadyDecompressed (0.18s)1529=== CONT TestForceGCDuringPushOffersSweptObject1530=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1531=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1532=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1533=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1534=== CONT TestPendingClosureFailureAbortsItsUploads1535--- PASS: TestPushWaitsForSweepHoldingRow (0.77s)1536=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection15372026/10/02 20:38:03 WARN Rate limiter backed off name=s3-test rate=515382026/10/02 20:38:03 WARN S3 rate limit hit during proxy key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhhh.nar.zst error="Please reduce your request rate."1539--- PASS: TestReadProxy404 (0.63s)1540=== CONT TestSweepSkipsRowsLockedByPush1541=== RUN TestService_RequireScope_OIDC/builder_may_write1542=== PAUSE TestService_RequireScope_OIDC/builder_may_write1543=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1544=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1545=== RUN TestService_RequireScope_OIDC/ops_may_admin1546=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1547=== RUN TestService_RequireScope_OIDC/ops_may_not_write1548=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1549=== RUN TestService_RequireScope_OIDC/reader_may_not_write1550=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1551=== RUN TestService_RequireScope_OIDC/static_token_may_admin1552=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1553=== RUN TestService_RequireScope_OIDC/static_token_may_write1554=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1555=== RUN TestService_RequireScope_OIDC/reader_may_read1556=== PAUSE TestService_RequireScope_OIDC/reader_may_read1557=== RUN TestService_RequireScope_OIDC/writer_implies_read1558=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1559=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1560=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1561=== CONT TestReadProxyNarinfo15622026/10/02 20:38:03 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15632026/10/02 20:38:03 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1564=== CONT TestMetricsInventory1565--- PASS: TestService_NativeMTLS (0.23s)1566=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1567=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1568=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1569=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1570=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1571=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1572=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1573=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1574=== CONT TestRegisterCompletedObjectNeedsPendingRow15752026/10/02 20:38:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1576=== CONT TestGCTaskStore_ConflictDifferentParams1577--- PASS: TestConnectSerialisesConcurrentMigrations (1.11s)1578=== CONT TestClientSharedPathCommittedMidPush1579--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)15802026/10/02 20:38:03 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLjlkNWMyOTQ4LWQxYjAtNDMwZS1iYTdmLWZkNmZkYjdhZTc1Y3gxNzkwOTczNDgyNjM3NjI4MjE2 parts=1015812026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/2/complete1582=== NAME TestPinProtectsFromGC1583 client_integration_test.go:867: Pinned store path: /build/TestPinProtectsFromGC1736206771/001/store/vzkbcdwmbyx8h1qrxgsygqz3l20ch9rn-pinned-file.txt1584 client_integration_test.go:868: Unpinned store path: /build/TestPinProtectsFromGC1736206771/001/store/r776yfw9nmq2gw4m1b3bj411m220flvv-unpinned-file.txt15852026/10/02 20:38:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15862026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures15872026/10/02 20:38:03 INFO Created/updated pin name=app store_path=/nix/store/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa-app narinfo_key=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.narinfo1588--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (2.37s)1589=== CONT TestCreatePendingClosureRejectsOversizedNAR15902026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures15912026/10/02 20:38:03 INFO Completed multipart upload object_key=nar/cccccccccccccccccccccccccccccccc00000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLjBkMmZjYzc0LTc4Y2ItNDBiOC04ZTliLTU1ZDg5MjY5ZGQ5YngxNzkwOTczNDgxNzgwNzY3MjM0 parts=1015922026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/1/complete1593--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1594=== CONT TestNARDeduplicationMetadataUploadBug15952026/10/02 20:38:03 INFO Created/updated pin name=app store_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-app narinfo_key=bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb.narinfo15962026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures15972026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=015982026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period1599--- PASS: TestConcurrentPinUpdatesAgree (0.76s)1600=== CONT TestPendingClosureFailureTracksEveryUpload1601--- PASS: TestPush_CompleteCommitsEveryRoot (2.41s)1602=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded16032026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes16042026/10/02 20:38:03 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=016052026/10/02 20:38:03 INFO Vacuumed table table=pending_closures16062026/10/02 20:38:03 INFO Vacuumed table table=pending_objects16072026/10/02 20:38:03 INFO Vacuumed table table=multipart_uploads16082026/10/02 20:38:03 INFO Vacuumed table table=closures16092026/10/02 20:38:03 INFO Vacuumed table table=objects16102026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures16112026/10/02 20:38:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16122026/10/02 20:38:03 INFO Uploading vzkbcdwmbyx8h1qrxgsygqz3l20ch9rn-pinned-file.txt (128B)16132026/10/02 20:38:03 INFO lead: released remote=192.0.2.1:123416142026/10/02 20:38:03 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:42435/oidc16152026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=016162026/10/02 20:38:03 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"1617=== CONT TestGCTaskStore_PhaseUpdates1618--- PASS: TestGCSweepDeliversEachKeyOnce (0.33s)1619=== CONT TestCacheConfigHandlerMaxNarSize1620--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1621--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1622=== CONT TestGCBugBareHashReferences16232026/10/02 20:38:03 WARN Failed to register uploaded object key=vzkbcdwmbyx8h1qrxgsygqz3l20ch9rn.ls error="server returned 404: 404 page not found\n"16242026/10/02 20:38:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign1625--- PASS: TestPendingClosureFailureAbortsItsUploads (0.28s)1626=== CONT TestIsValidCachePath1627=== RUN TestIsValidCachePath/narinfo1628=== PAUSE TestIsValidCachePath/narinfo1629=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars1630=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars1631=== RUN TestIsValidCachePath/nar_zst1632=== PAUSE TestIsValidCachePath/nar_zst1633=== RUN TestIsValidCachePath/nar_xz1634=== PAUSE TestIsValidCachePath/nar_xz1635=== RUN TestIsValidCachePath/nar_bz21636=== PAUSE TestIsValidCachePath/nar_bz21637=== RUN TestIsValidCachePath/nar_uncompressed16382026/10/02 20:38:03 INFO Signed narinfos id=1 count=11639=== PAUSE TestIsValidCachePath/nar_uncompressed1640=== RUN TestIsValidCachePath/ls1641=== PAUSE TestIsValidCachePath/ls1642=== RUN TestIsValidCachePath/log1643=== PAUSE TestIsValidCachePath/log1644=== RUN TestIsValidCachePath/realisation1645=== PAUSE TestIsValidCachePath/realisation1646=== RUN TestIsValidCachePath/nix-cache-info1647=== PAUSE TestIsValidCachePath/nix-cache-info1648=== RUN TestIsValidCachePath/index.html16492026/10/02 20:38:03 INFO Uploading 1 narinfos1650=== PAUSE TestIsValidCachePath/index.html1651=== RUN TestIsValidCachePath/traversal_parent1652=== PAUSE TestIsValidCachePath/traversal_parent1653=== RUN TestIsValidCachePath/traversal_in_middle1654=== PAUSE TestIsValidCachePath/traversal_in_middle1655=== RUN TestIsValidCachePath/invalid_char_e1656=== PAUSE TestIsValidCachePath/invalid_char_e1657=== RUN TestIsValidCachePath/invalid_char_u1658=== PAUSE TestIsValidCachePath/invalid_char_u1659=== RUN TestIsValidCachePath/random_path1660=== PAUSE TestIsValidCachePath/random_path1661=== RUN TestIsValidCachePath/empty1662=== PAUSE TestIsValidCachePath/empty1663=== RUN TestIsValidCachePath/leading_slash1664=== PAUSE TestIsValidCachePath/leading_slash1665=== RUN TestIsValidCachePath/wrong_extension1666=== PAUSE TestIsValidCachePath/wrong_extension1667=== RUN TestIsValidCachePath/short_hash1668=== PAUSE TestIsValidCachePath/short_hash1669=== CONT TestService_readinessHandler16702026/10/02 20:38:03 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=016712026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures16722026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/1/complete16732026/10/02 20:38:03 WARN Failed to register uploaded object key=vzkbcdwmbyx8h1qrxgsygqz3l20ch9rn.narinfo error="server returned 404: 404 page not found\n"1674=== CONT TestGCTaskStore_GetReturnsLatest1675--- PASS: TestLeadEndsOnShutdown (1.54s)1676=== CONT TestService_healthCheckHandler1677--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)16782026/10/02 20:38:03 INFO Vacuumed table table=pending_closures16792026/10/02 20:38:03 INFO Upload complete. (83ms)16802026/10/02 20:38:03 INFO Vacuumed table table=pending_objects16812026/10/02 20:38:03 INFO Vacuumed table table=multipart_uploads16822026/10/02 20:38:03 INFO Vacuumed table table=closures16832026/10/02 20:38:03 INFO Vacuumed table table=objects16842026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=016852026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period16862026/10/02 20:38:03 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=016872026/10/02 20:38:03 INFO Vacuumed table table=pending_closures16882026/10/02 20:38:03 INFO Vacuumed table table=pending_objects16892026/10/02 20:38:03 INFO Vacuumed table table=multipart_uploads16902026/10/02 20:38:03 INFO Vacuumed table table=closures16912026/10/02 20:38:03 INFO Vacuumed table table=objects16922026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=016932026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period16942026/10/02 20:38:03 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=016952026/10/02 20:38:03 INFO Vacuumed table table=pending_closures16962026/10/02 20:38:03 INFO Vacuumed table table=pending_objects16972026/10/02 20:38:03 INFO Vacuumed table table=multipart_uploads16982026/10/02 20:38:03 INFO Vacuumed table table=closures16992026/10/02 20:38:03 INFO Vacuumed table table=objects1700--- PASS: TestPushDedupSurvivesConcurrentGC (0.44s)1701=== CONT TestGracefulShutdownDrainsInflight17022026/10/02 20:38:03 INFO Starting HTTP server address=127.0.0.1:3800117032026/10/02 20:38:03 INFO Shutdown signal received, draining in-flight requests timeout=10s17042026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=017052026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period17062026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes17072026/10/02 20:38:03 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=017082026/10/02 20:38:03 INFO Vacuumed table table=pending_closures17092026/10/02 20:38:03 INFO Vacuumed table table=pending_objects17102026/10/02 20:38:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17112026/10/02 20:38:03 INFO Received complete multipart upload request method=POST path=/api/multipart/complete17122026/10/02 20:38:03 INFO Uploading r776yfw9nmq2gw4m1b3bj411m220flvv-unpinned-file.txt (128B)17132026/10/02 20:38:03 INFO Vacuumed table table=multipart_uploads17142026/10/02 20:38:03 INFO Vacuumed table table=closures17152026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=017162026/10/02 20:38:03 INFO Vacuumed table table=objects17172026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period17182026/10/02 20:38:03 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17192026/10/02 20:38:03 WARN Failed to register uploaded object key=r776yfw9nmq2gw4m1b3bj411m220flvv.ls error="server returned 404: 404 page not found\n"17202026/10/02 20:38:03 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17212026/10/02 20:38:03 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."17222026/10/02 20:38:03 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."17232026/10/02 20:38:03 INFO Signed narinfos id=2 count=117242026/10/02 20:38:03 INFO Uploading 1 narinfos1725=== CONT TestGCTaskStore_Fail1726--- PASS: TestRegisterCompletedObjectNeedsPendingRow (0.28s)1727--- PASS: TestGCTaskStore_Fail (0.00s)1728=== CONT TestReadProxyRootRedirectsToIndexHTML1729--- PASS: TestSweepSkipsRowsLockedByPush (0.36s)1730=== CONT TestGCTaskStore_GetEmpty1731--- PASS: TestGCTaskStore_GetEmpty (0.00s)1732=== CONT TestGenerateLandingPage17332026/10/02 20:38:03 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLjgyODBlZGU1LWRhYzgtNDg1OC1hNmI3LTNjZjhiMWZmNjgzNXgxNzkwOTczNDgyODcwOTYzOTY0 parts=1217342026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures1735--- PASS: TestGenerateLandingPage (0.01s)1736=== CONT TestGCTaskStore_CompletedAllowsNewTask17372026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/2/complete1738=== CONT TestPendingClosureWriteTimeout/empty1739--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)17402026/10/02 20:38:03 WARN Failed to register uploaded object key=r776yfw9nmq2gw4m1b3bj411m220flvv.narinfo error="server returned 404: 404 page not found\n"1741=== CONT TestPendingClosureWriteTimeout/400_objects1742=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17432026/10/02 20:38:03 INFO Upload complete. (74ms)1744--- PASS: TestFailedS3DeleteKeepsTombstone (0.45s)1745=== CONT TestPendingClosureWriteTimeout/670k_objects1746=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info17472026/10/02 20:38:03 INFO Received uploads request method=POST path=/1748=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key17492026/10/02 20:38:03 INFO Received request for more parts method=POST path=/17502026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures1751=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key17522026/10/02 20:38:03 INFO Received complete multipart upload request method=POST path=/1753=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal17542026/10/02 20:38:03 INFO Received uploads request method=POST path=/1755=== CONT TestProxyWriteTimeout/unknown_size1756--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1757 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1758 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1759 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1760 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1761=== CONT TestProxyWriteTimeout/1_GiB_nar1762=== CONT TestProxyWriteTimeout/10_GiB_nar1763=== CONT TestProxyWriteTimeout/narinfo1764=== CONT TestParseSingleRange/unknown_unit1765--- PASS: TestProxyWriteTimeout (0.00s)1766 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1767 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1768 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1769 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1770=== CONT TestParseSingleRange/start_far_past_EOF1771=== CONT TestParseSingleRange/suffix1772=== CONT TestParseSingleRange/single_byte1773=== CONT TestParseSingleRange/start_past_EOF1774=== CONT TestParseSingleRange/suffix_exceeds_size1775=== CONT TestParseSingleRange/end_clamped_to_size1776=== CONT TestParseSingleRange/open-ended1777=== CONT TestParseSingleRange/malformed_no_dash1778=== CONT TestParseSingleRange/multi-range_ignored1779=== CONT TestParseSingleRange/closed1780=== CONT TestParseSingleRange/none1781=== CONT TestParseSingleRange/malformed_both_empty1782=== CONT TestParseSingleRange/malformed_end_before_start1783=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart1784--- PASS: TestParseSingleRange (0.00s)1785 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1786 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1787 --- PASS: TestParseSingleRange/suffix (0.00s)1788 --- PASS: TestParseSingleRange/single_byte (0.00s)1789 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1790 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1791 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1792 --- PASS: TestParseSingleRange/open-ended (0.00s)1793 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1794 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1795 --- PASS: TestParseSingleRange/closed (0.00s)1796 --- PASS: TestParseSingleRange/none (0.00s)1797 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1798 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)17992026/10/02 20:38:03 INFO Received complete multipart upload request method=POST path=/1800--- PASS: TestMetricsInventory (0.31s)1801=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18022026/10/02 20:38:03 INFO Received request for more parts method=POST path=/1803--- PASS: TestGracefulShutdownDrainsInflight (0.07s)1804=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18052026/10/02 20:38:03 INFO Received uploads request method=POST path=/18062026/10/02 20:38:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures18072026/10/02 20:38:03 INFO Garbage collection started18082026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures18092026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=01810--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (0.48s)1811=== CONT TestPush_RejectsBadRequests/root_not_in_objects18122026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes1813=== CONT TestPush_RejectsBadRequests/no_roots18142026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period18152026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes1816=== CONT TestPush_RejectsBadRequests/no_objects18172026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes1818=== CONT TestPush_RejectsBadRequests/bad_root18192026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes1820=== CONT TestResolveDBConnectionString/missing_file_is_an_error1821=== CONT TestResolveDBConnectionString/nothing_configured1822=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1823=== CONT TestResolveDBConnectionString/file_when_flag_empty1824=== CONT TestResolveDBConnectionString/flag_wins1825=== CONT TestServerTLSConfig/missing_CA_file1826=== CONT TestServerTLSConfig/no_client_CA1827=== CONT TestServerTLSConfig/not_a_PEM_file1828--- PASS: TestResolveDBConnectionString (0.00s)1829 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1830 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1831 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1832 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1833 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1834=== CONT TestIsValidUploadKey/nar_zst1835--- PASS: TestServerTLSConfig (0.00s)1836 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1837 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1838 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1839=== CONT TestIsValidUploadKey/build_log_equals1840=== CONT TestIsValidUploadKey/realisation1841=== CONT TestIsValidUploadKey/build_log_question_mark18422026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures1843=== CONT TestIsValidUploadKey/unknown_type1844=== CONT TestIsValidUploadKey/listing1845=== CONT TestIsValidUploadKey/absolute1846=== CONT TestIsValidUploadKey/nar_xz1847=== CONT TestIsValidUploadKey/empty_key1848=== CONT TestIsValidUploadKey/build_log_home-manager_file1849=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1850=== CONT TestIsValidUploadKey/narinfo1851=== CONT TestIsValidUploadKey/realisation_plus_in_output1852=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1853=== CONT TestIsValidUploadKey/index.html1854=== CONT TestIsValidUploadKey/traversal1855=== CONT TestIsValidUploadKey/traversal_nar1856=== CONT TestIsValidUploadKey/build_log1857=== CONT TestIsValidUploadKey/nar_plain1858=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1859=== CONT TestIsValidUploadKey/nix-cache-info1860=== CONT TestIsValidUploadKey/build_log_plus_in_name1861=== CONT TestGCEndsOnShutdown/before_the_run1862--- PASS: TestIsValidUploadKey (0.00s)1863 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1864 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1865 --- PASS: TestIsValidUploadKey/realisation (0.00s)1866 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1867 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1868 --- PASS: TestIsValidUploadKey/listing (0.00s)1869 --- PASS: TestIsValidUploadKey/absolute (0.00s)1870 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1871 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1872 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1873 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1874 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1875 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1876 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1877 --- PASS: TestIsValidUploadKey/index.html (0.00s)1878 --- PASS: TestIsValidUploadKey/traversal (0.00s)1879 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1880 --- PASS: TestIsValidUploadKey/build_log (0.00s)1881 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1882 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1883 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1884 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1885=== NAME TestNARDeduplicationMetadataUploadBug1886 metadata_upload_test.go:48: First store path: /build/TestNARDeduplicationMetadataUploadBug1765718089/001/store/p59nwc53vkwnl4jn0brkvbk8bbv54m5k-file1.txt18872026/10/02 20:38:03 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=018882026/10/02 20:38:03 INFO Vacuumed table table=pending_closures1889--- PASS: TestPush_RejectsBadRequests (0.61s)1890 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1891 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1892 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1893 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)18942026/10/02 20:38:03 INFO Vacuumed table table=pending_objects18952026/10/02 20:38:03 INFO Vacuumed table table=multipart_uploads18962026/10/02 20:38:03 INFO Vacuumed table table=closures18972026/10/02 20:38:03 INFO Vacuumed table table=objects18982026/10/02 20:38:03 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux18992026/10/02 20:38:03 WARN Refused reserved pin name=worker-x86_64-linux1900=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1901--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (0.29s)19022026/10/02 20:38:03 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux19032026/10/02 20:38:03 INFO Received create pin request method=POST path=/api/pins/my-app19042026/10/02 20:38:03 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux19052026/10/02 20:38:03 WARN readiness check failed error="closed pool"1906=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1907--- PASS: TestCreatePin_ReservedPins (0.72s)1908--- PASS: TestService_readinessHandler (0.28s)1909=== CONT TestCacheConfigHandler/no_signing_keys1910=== CONT TestCacheConfigHandler/no_cache_url_configured1911=== CONT TestCacheConfigHandler/full_config,_no_issuer1912=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1913=== CONT TestClientErrorHandling/InvalidStorePath1914--- PASS: TestCacheConfigHandler (0.00s)1915 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1916 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)1917 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1918 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)19192026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes19202026/10/02 20:38:03 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19212026/10/02 20:38:03 INFO Uploading p59nwc53vkwnl4jn0brkvbk8bbv54m5k-file1.txt (160B)19222026/10/02 20:38:03 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"19232026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes19242026/10/02 20:38:03 WARN Failed to register uploaded object key=p59nwc53vkwnl4jn0brkvbk8bbv54m5k.ls error="server returned 404: 404 page not found\n"19252026/10/02 20:38:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19262026/10/02 20:38:03 INFO Signed narinfos id=1 count=119272026/10/02 20:38:03 INFO Uploading 1 narinfos19282026/10/02 20:38:03 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)19292026/10/02 20:38:03 INFO Uploading 304psf2nn0r31sr4k71g1pxgmmjsw27r-shared-dep (136B)19302026/10/02 20:38:03 INFO Uploading ydnsp897szm9nhp1v7fzm1i328va08b5-top (224B)19312026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/1/complete19322026/10/02 20:38:03 WARN Failed to register uploaded object key=p59nwc53vkwnl4jn0brkvbk8bbv54m5k.narinfo error="server returned 404: 404 page not found\n"19332026/10/02 20:38:03 INFO Upload complete. (75ms)1934--- PASS: TestService_healthCheckHandler (0.32s)1935=== CONT TestClientErrorHandling/ServerNotAvailable1936=== NAME TestNARDeduplicationMetadataUploadBug1937 metadata_upload_test.go:54: Retrieved narinfo from S3:1938 StorePath: /build/TestNARDeduplicationMetadataUploadBug1765718089/001/store/p59nwc53vkwnl4jn0brkvbk8bbv54m5k-file1.txt1939 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1940 Compression: zstd1941 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1942 NarSize: 1601943 References: 1944 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf19452026/10/02 20:38:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19462026/10/02 20:38:03 WARN Failed to register uploaded object key=nar/16n7aivmmjbs0rhbrz938zngz6aqqjy643dd0mgrlqhp0b935dp8.nar.zst error="server returned 404: 404 page not found\n"19472026/10/02 20:38:03 WARN Failed to register uploaded object key=ydnsp897szm9nhp1v7fzm1i328va08b5.ls error="server returned 404: 404 page not found\n"19482026/10/02 20:38:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19492026/10/02 20:38:03 WARN Failed to register uploaded object key=304psf2nn0r31sr4k71g1pxgmmjsw27r.ls error="server returned 404: 404 page not found\n"19502026/10/02 20:38:03 INFO Signed narinfos id=1 count=219512026/10/02 20:38:03 INFO Uploading 2 narinfos1952 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1953 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1954 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}19552026/10/02 20:38:03 WARN Failed to register uploaded object key=304psf2nn0r31sr4k71g1pxgmmjsw27r.narinfo error="server returned 404: 404 page not found\n"19562026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/1/complete19572026/10/02 20:38:03 WARN Failed to register uploaded object key=ydnsp897szm9nhp1v7fzm1i328va08b5.narinfo error="server returned 404: 404 page not found\n"19582026/10/02 20:38:03 INFO Upload complete. (82ms)1959=== NAME TestClientSharedPathCommittedMidPush1960 client_integration_test.go:816: Retrieved narinfo from S3:1961 StorePath: /build/TestClientSharedPathCommittedMidPush2244687460/001/store/304psf2nn0r31sr4k71g1pxgmmjsw27r-shared-dep1962 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1963 Compression: zstd1964 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821965 NarSize: 1361966 References: 1967 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1968=== CONT TestClientErrorHandling/InvalidAuthToken1969--- PASS: TestReadProxyRootRedirectsToIndexHTML (0.21s)19702026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures1971=== NAME TestClientSharedPathCommittedMidPush1972 client_integration_test.go:816: Retrieved narinfo from S3:1973 StorePath: /build/TestClientSharedPathCommittedMidPush2244687460/001/store/ydnsp897szm9nhp1v7fzm1i328va08b5-top1974 URL: nar/16n7aivmmjbs0rhbrz938zngz6aqqjy643dd0mgrlqhp0b935dp8.nar.zst1975 Compression: zstd1976 NarHash: sha256:16n7aivmmjbs0rhbrz938zngz6aqqjy643dd0mgrlqhp0b935dp81977 NarSize: 2241978 References: /build/TestClientSharedPathCommittedMidPush2244687460/001/store/304psf2nn0r31sr4k71g1pxgmmjsw27r-shared-dep1979 CA: text:sha256:0lx7vnvp6vabnylam8nx9gp9nyagciinx7dlsdrr701zsm611na11980=== NAME TestNARDeduplicationMetadataUploadBug1981 metadata_upload_test.go:64: Second store path (same content): /build/TestNARDeduplicationMetadataUploadBug1765718089/001/store/62c1nz55idgdw8xzc70x7h2i69xdavlj-file2.txt1982=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1983--- PASS: TestClientSharedPathCommittedMidPush (0.51s)1984=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19852026/10/02 20:38:03 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/present19862026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=019872026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period19882026/10/02 20:38:03 INFO Received push request method=POST path=/api/pushes19892026/10/02 20:38:03 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19902026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=019912026-10-02 20:38:03.818 UTC [1997] ERROR: canceling statement due to user request19922026-10-02 20:38:03.818 UTC [1997] CONTEXT: PL/pgSQL function object_stats_apply() line 5 at statement block19932026-10-02 20:38:03.818 UTC [1997] STATEMENT: -- name: MarkStaleObjects :execrows1994 WITH RECURSIVE ct AS (1995 SELECT timezone('UTC', now()) AS now1996 ),1997 closure_reach AS (1998 -- Start with all closure keys1999 SELECT o.key, o.refs2000 FROM objects o2001 INNER JOIN closures c ON o.key = c.key2002 UNION2003 -- Recursively add all referenced objects2004 SELECT o.key, o.refs2005 FROM objects o2006 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2007 ),2008 reachable_objects AS (2009 SELECT DISTINCT key FROM closure_reach2010 ),2011 stale_objects AS (2012 SELECT o.key2013 FROM objects AS o, ct2014 WHERE2015 NOT EXISTS (2016 SELECT 12017 FROM reachable_objects ro2018 WHERE ro.key = o.key2019 )2020 AND NOT EXISTS (2021 SELECT 12022 FROM pending_objects AS po2023 WHERE po.key = o.key2024 )2025 AND o.deleted_at IS NULL -- Only mark fresh objects2026 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2027 FOR UPDATE2028 )2029 UPDATE objects2030 SET2031 deleted_at = ct.now,2032 first_deleted_at = COALESCE(first_deleted_at, ct.now)2033 FROM stale_objects, ct2034 WHERE objects.key = stale_objects.key2035 20362026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period20372026/10/02 20:38:03 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign20382026/10/02 20:38:03 WARN Failed to register uploaded object key=62c1nz55idgdw8xzc70x7h2i69xdavlj.ls error="server returned 404: 404 page not found\n"20392026/10/02 20:38:03 INFO Signed narinfos id=2 count=120402026/10/02 20:38:03 INFO Uploading 1 narinfos20412026/10/02 20:38:03 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:45423/bucket93/?delete=\": context canceled"20422026/10/02 20:38:03 INFO Received complete push request method=POST path=/api/pushes/2/complete20432026/10/02 20:38:03 WARN Failed to register uploaded object key=62c1nz55idgdw8xzc70x7h2i69xdavlj.narinfo error="server returned 404: 404 page not found\n"20442026/10/02 20:38:03 INFO Upload complete. (65ms)2045=== NAME TestNARDeduplicationMetadataUploadBug2046 metadata_upload_test.go:76: Retrieved narinfo from S3:2047 StorePath: /build/TestNARDeduplicationMetadataUploadBug1765718089/001/store/62c1nz55idgdw8xzc70x7h2i69xdavlj-file2.txt2048 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst2049 Compression: zstd2050 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2051 NarSize: 1602052 References: 2053 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf2054=== CONT TestService_RequireScope_OIDC/builder_may_write2055=== CONT TestService_RequireScope_OIDC/reader_may_not_write2056=== CONT TestService_RequireScope_OIDC/static_token_may_write2057=== CONT TestService_RequireScope_OIDC/ops_may_admin2058=== CONT TestService_RequireScope_OIDC/writer_implies_read2059=== NAME TestNARDeduplicationMetadataUploadBug2060 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)2061 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):2062 {"version":1,"root":{"type":"regular","size":44}}2063=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2064=== CONT TestService_RequireScope_OIDC/reader_may_read2065=== CONT TestService_RequireScope_OIDC/ops_may_not_write2066=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2067--- PASS: TestGCEndsOnShutdown (0.00s)2068 --- PASS: TestGCEndsOnShutdown/before_the_run (0.19s)2069 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (0.22s)2070 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (0.21s)2071=== CONT TestService_RequireScope_OIDC/static_token_may_admin2072=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2073=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2074=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20752026/10/02 20:38:03 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]2076=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20772026/10/02 20:38:03 WARN Authentication failed token_preview=eyJhbGciOi...VI3IGyN2Sw token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2078=== CONT TestIsValidCachePath/short_hash2079=== CONT TestIsValidCachePath/narinfo2080=== CONT TestIsValidCachePath/invalid_char_u2081=== CONT TestIsValidCachePath/wrong_extension2082=== CONT TestIsValidCachePath/leading_slash2083=== CONT TestIsValidCachePath/empty2084=== CONT TestIsValidCachePath/random_path2085=== CONT TestIsValidCachePath/invalid_char_e2086=== CONT TestIsValidCachePath/traversal_in_middle2087=== CONT TestIsValidCachePath/traversal_parent2088=== CONT TestIsValidCachePath/index.html2089=== CONT TestIsValidCachePath/nar_bz22090=== CONT TestIsValidCachePath/realisation2091=== CONT TestIsValidCachePath/nix-cache-info2092=== CONT TestIsValidCachePath/ls2093=== CONT TestIsValidCachePath/log2094=== CONT TestIsValidCachePath/nar_uncompressed2095=== CONT TestIsValidCachePath/nar_xz2096=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars2097=== CONT TestIsValidCachePath/nar_zst2098--- PASS: TestIsValidCachePath (0.00s)2099 --- PASS: TestIsValidCachePath/short_hash (0.00s)2100 --- PASS: TestIsValidCachePath/narinfo (0.00s)2101 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)2102 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)2103 --- PASS: TestIsValidCachePath/leading_slash (0.00s)2104 --- PASS: TestIsValidCachePath/empty (0.00s)2105 --- PASS: TestIsValidCachePath/random_path (0.00s)2106 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)2107 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)2108 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)2109 --- PASS: TestIsValidCachePath/index.html (0.00s)2110 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)2111 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)2112 --- PASS: TestIsValidCachePath/realisation (0.00s)2113 --- PASS: TestIsValidCachePath/ls (0.00s)2114 --- PASS: TestIsValidCachePath/log (0.00s)2115 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)2116 --- PASS: TestIsValidCachePath/nar_xz (0.00s)2117 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)2118 --- PASS: TestIsValidCachePath/nar_zst (0.00s)2119--- PASS: TestService_RequireScope_OIDC (0.46s)2120 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2121 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2122 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2123 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2124 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2125 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)2126 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2127 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2128 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2129 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)21302026/10/02 20:38:03 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=209.080928ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2131--- PASS: TestNARDeduplicationMetadataUploadBug (0.61s)2132--- PASS: TestService_AuthMiddleware_OIDC (0.42s)2133 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2134 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2135 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2136 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)2137--- PASS: TestGCBugBareHashReferences (0.55s)21382026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures21392026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=021402026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period21412026/10/02 20:38:03 INFO lead: released remote=192.0.2.1:123421422026/10/02 20:38:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21432026/10/02 20:38:03 INFO Received uploads request method=POST path=/api/pending_closures21442026/10/02 20:38:03 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=021452026/10/02 20:38:03 INFO Vacuumed table table=pending_closures21462026/10/02 20:38:03 INFO Vacuumed table table=pending_objects21472026/10/02 20:38:03 INFO Vacuumed table table=multipart_uploads21482026/10/02 20:38:03 INFO Vacuumed table table=closures21492026/10/02 20:38:03 INFO Vacuumed table table=objects21502026/10/02 20:38:03 INFO Aborted multipart uploads count=0 kept=021512026/10/02 20:38:03 WARN Force mode enabled - objects will be deleted immediately without grace period21522026/10/02 20:38:03 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=021532026/10/02 20:38:03 INFO Vacuumed table table=pending_closures21542026/10/02 20:38:03 INFO Vacuumed table table=pending_objects21552026/10/02 20:38:03 INFO Vacuumed table table=multipart_uploads21562026/10/02 20:38:03 INFO Vacuumed table table=closures21572026/10/02 20:38:03 INFO Vacuumed table table=objects21582026/10/02 20:38:03 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21592026/10/02 20:38:03 ERROR Failed to decompress narinfo error="decompressed size exceeds configured limit"21602026/10/02 20:38:03 INFO lead: acquired remote=192.0.2.1:12342161--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2162 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (0.24s)2163 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (0.23s)21642026/10/02 20:38:04 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21652026/10/02 20:38:04 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=412.181284ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21662026/10/02 20:38:04 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLmMzNTE1NWIyLThkMzctNDVjMy1hYTlkLWI4NmE5MGE4ODE5MHgxNzkwOTczNDgzNTMzNzU4NTcz error="Get \"http://127.0.0.1:1/bucket62/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"21672026/10/02 20:38:04 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=OTM4YmFiYWMtN2Y2NC00ZTI3LTk3MWEtNGM1OTIwYmFiMjcwLjNlNTc5MjU1LThiNGQtNDdlOS1hZGY2LTEwZjZjZmU4NDU0NHgxNzkwOTczNDgzNTIwMDc3NTQ5 parts=1221682026/10/02 20:38:04 INFO Received cleanup request method=DELETE path=/api/pending_closures2169--- PASS: TestPendingClosureFailureTracksEveryUpload (0.78s)21702026/10/02 20:38:04 INFO Aborted multipart uploads count=1 kept=02171--- PASS: TestRedundantMultipartUpload (1.46s)21722026/10/02 20:38:04 ERROR Refusing narinfo larger than the limit key=5hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=167772162173--- PASS: TestReadProxyNarinfo (1.23s)21742026/10/02 20:38:04 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=754.097549ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2175--- PASS: TestPendingClosureWriteTimeout (0.00s)2176 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2177 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2178 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2179 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (1.03s)2180=== NAME TestOrphanedObjectsGCStressTest2181 orphaned_objects_gc_test.go:425: Created 10 active closures, 5 to-delete closures, 20 orphaned chains2182 orphaned_objects_gc_test.go:446: Marked 210 objects for deletion21832026/10/02 20:38:04 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=2 objects_marked=6 objects_deleted=6 objects_failed=02184=== NAME TestClientIntegration2185 client_integration_test.go:445: Objects in database after GC:2186 client_integration_test.go:445: Successfully deleted all objects with GC --force2187--- PASS: TestClientIntegration (3.29s)2188=== NAME TestOrphanedObjectsGCStressTest2189 orphaned_objects_gc_test.go:509: Stress test completed successfully:2190 orphaned_objects_gc_test.go:510: - Active objects preserved: 202191 orphaned_objects_gc_test.go:511: - Objects deleted: 2102192 orphaned_objects_gc_test.go:512: - Total GC'd: 2102193--- PASS: TestOrphanedObjectsGCStressTest (2.04s)21942026/10/02 20:38:05 INFO lead: released remote=192.0.2.1:12342195--- PASS: TestLeadElectsOneAndHandsOver (2.51s)21962026/10/02 20:38:05 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.58149059s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21972026/10/02 20:38:05 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=021982026/10/02 20:38:05 INFO Received create pin request method=POST path=/api/pins/myapp21992026/10/02 20:38:05 INFO Created/updated pin name=myapp store_path=/build/TestPinProtectsFromGC1736206771/001/store/vzkbcdwmbyx8h1qrxgsygqz3l20ch9rn-pinned-file.txt narinfo_key=vzkbcdwmbyx8h1qrxgsygqz3l20ch9rn.narinfo22002026/10/02 20:38:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures22012026/10/02 20:38:05 INFO Garbage collection started22022026/10/02 20:38:05 INFO Aborted multipart uploads count=0 kept=022032026/10/02 20:38:05 WARN Force mode enabled - objects will be deleted immediately without grace period22042026/10/02 20:38:05 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=022052026/10/02 20:38:05 INFO Vacuumed table table=pending_closures22062026/10/02 20:38:05 INFO Vacuumed table table=pending_objects22072026/10/02 20:38:05 INFO Vacuumed table table=multipart_uploads22082026/10/02 20:38:05 INFO Vacuumed table table=closures22092026/10/02 20:38:05 INFO Vacuumed table table=objects2210--- PASS: TestReadProxyOutlastsServerWriteTimeout (5.03s)22112026/10/02 20:38:06 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-config22122026/10/02 20:38:06 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=199.229601ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22132026/10/02 20:38:07 WARN Rate limiter enabled after throttle name=s3-test rate=522142026/10/02 20:38:07 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."2215=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle2216 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=102217 throttle_test.go:215: Rate limiter: enabled=true, rate=5.002218--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (6.19s)22192026/10/02 20:38:07 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=367.804147ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2220--- PASS: TestConnectWaitsForAPeerMigration (5.14s)22212026/10/02 20:38:07 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=770.840438ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2222=== NAME TestPinProtectsFromGC2223 client_integration_test.go:976: Pin successfully protected closure from garbage collection2224--- PASS: TestPinProtectsFromGC (4.63s)22252026/10/02 20:38:08 INFO Aborted multipart uploads count=1 kept=022262026/10/02 20:38:08 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.583216244s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22272026/10/02 20:38:08 INFO Received cleanup request method=DELETE path=/api/pending_closures22282026/10/02 20:38:08 INFO Aborted multipart uploads count=1 kept=02229--- PASS: TestPendingCleanupUsesOneCutoff (6.46s)22302026/10/02 20:38:09 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"22312026/10/02 20:38:09 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-config22322026/10/02 20:38:10 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=182.277589ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22332026/10/02 20:38:10 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=405.251ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22342026/10/02 20:38:10 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=728.939652ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22352026/10/02 20:38:11 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.646008443s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22362026/10/02 20:38:12 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_closures22372026/10/02 20:38:13 WARN Request failed, retrying attempt=2 max_attempts=6 backoff=202.411168ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22382026/10/02 20:38:13 WARN Request failed, retrying attempt=3 max_attempts=6 backoff=415.654024ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22392026/10/02 20:38:13 WARN Request failed, retrying attempt=4 max_attempts=6 backoff=875.554977ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22402026/10/02 20:38:14 WARN Request failed, retrying attempt=5 max_attempts=6 backoff=1.49695256s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2241--- PASS: TestClientErrorHandling (0.00s)2242 --- PASS: TestClientErrorHandling/InvalidStorePath (0.26s)2243 --- PASS: TestClientErrorHandling/InvalidAuthToken (0.28s)2244 --- PASS: TestClientErrorHandling/ServerNotAvailable (12.39s)2245--- PASS: TestUploadHandlersRejectOversizedBody (0.39s)2246 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.83s)2247 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.88s)2248 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (13.87s)2249PASS2250{"timestamp":"2026-10-02T20:38:17.41400878Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59344","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(200)"}2251{"timestamp":"2026-10-02T20:38:17.413724018Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59518","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)"}2252{"timestamp":"2026-10-02T20:38:17.413565456Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58080","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)"}2253{"timestamp":"2026-10-02T20:38:17.413742178Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58256","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(199)"}2254{"timestamp":"2026-10-02T20:38:17.413730918Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58948","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(196)"}2255{"timestamp":"2026-10-02T20:38:17.413661577Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58962","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(204)"}2256{"timestamp":"2026-10-02T20:38:17.413692718Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:58738","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)"}22572026-10-02 20:38:17.708 UTC [175] LOG: received smart shutdown request22582026-10-02 20:38:17.711 UTC [175] LOG: background worker "logical replication launcher" (PID 185) exited with exit code 122592026-10-02 20:38:17.723 UTC [180] LOG: shutting down22602026-10-02 20:38:17.723 UTC [180] LOG: checkpoint starting: shutdown immediate22612026-10-02 20:38:18.663 UTC [180] LOG: checkpoint complete: wrote 10576 buffers (64.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 28 recycled; write=0.195 s, sync=0.711 s, total=0.941 s; sync files=33362, longest=0.002 s, average=0.001 s; distance=467274 kB, estimate=467274 kB; lsn=0/1DFB8888, redo lsn=0/1DFB888822622026-10-02 20:38:18.733 UTC [175] LOG: database system is shut down2263Running OIDC tests...2264=== RUN TestAudienceForIssuer2265=== PAUSE TestAudienceForIssuer2266=== RUN TestHTTPClientForHasTimeouts2267=== PAUSE TestHTTPClientForHasTimeouts2268=== RUN TestGlobMatch2269=== PAUSE TestGlobMatch2270=== RUN TestValidateToken_ValidToken2271=== PAUSE TestValidateToken_ValidToken2272=== RUN TestValidateToken_WrongAudience2273=== PAUSE TestValidateToken_WrongAudience2274=== RUN TestValidateToken_Expired2275=== PAUSE TestValidateToken_Expired2276=== RUN TestValidateToken_BoundClaimsMismatch2277=== PAUSE TestValidateToken_BoundClaimsMismatch2278=== RUN TestValidateToken_BoundSubjectMismatch2279=== PAUSE TestValidateToken_BoundSubjectMismatch2280=== RUN TestValidateToken_MultipleProviders2281=== PAUSE TestValidateToken_MultipleProviders2282=== RUN TestValidateToken_NoMatchingProvider2283=== PAUSE TestValidateToken_NoMatchingProvider2284=== RUN TestValidateToken_KubernetesServiceAccount2285=== PAUSE TestValidateToken_KubernetesServiceAccount2286=== RUN TestNewValidator_KubernetesRequiresCA2287=== PAUSE TestNewValidator_KubernetesRequiresCA2288=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2289=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2290=== RUN TestPins_ReservedForMatchingRule2291=== PAUSE TestPins_ReservedForMatchingRule2292=== RUN TestPins_TopLevelShorthand2293=== PAUSE TestPins_TopLevelShorthand2294=== RUN TestPins_ConfigValidation2295=== PAUSE TestPins_ConfigValidation2296=== RUN TestScopes_LegacyProviderDefaultsToWrite2297=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2298=== RUN TestScopes_Rules2299=== PAUSE TestScopes_Rules2300=== RUN TestScopes_ConfigValidation2301=== PAUSE TestScopes_ConfigValidation2302=== CONT TestAudienceForIssuer2303=== CONT TestScopes_LegacyProviderDefaultsToWrite2304=== CONT TestNewValidator_KubernetesRequiresCA2305=== CONT TestValidateToken_KubernetesServiceAccount2306=== CONT TestScopes_ConfigValidation2307=== CONT TestScopes_Rules2308=== CONT TestPins_TopLevelShorthand2309=== CONT TestValidateToken_WrongAudience2310=== CONT TestPins_ReservedForMatchingRule2311=== CONT TestValidateToken_MultipleProviders2312=== CONT TestValidateToken_BoundSubjectMismatch2313=== CONT TestValidateToken_BoundClaimsMismatch2314=== CONT TestPins_ConfigValidation2315=== CONT TestValidateToken_ValidToken2316=== CONT TestValidateToken_Expired2317=== CONT TestHTTPClientForHasTimeouts2318=== CONT TestValidateToken_NoMatchingProvider2319=== CONT TestGlobMatch2320=== RUN TestGlobMatch/foo_foo2321=== PAUSE TestGlobMatch/foo_foo2322=== RUN TestGlobMatch/foo_bar2323--- PASS: TestAudienceForIssuer (0.00s)2324=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2325=== PAUSE TestGlobMatch/foo_bar2326--- PASS: TestScopes_ConfigValidation (0.00s)2327=== RUN TestGlobMatch/*_2328=== PAUSE TestGlobMatch/*_2329=== RUN TestGlobMatch/*_anything2330=== PAUSE TestGlobMatch/*_anything2331=== RUN TestGlobMatch/foo*_foo2332=== PAUSE TestGlobMatch/foo*_foo2333=== RUN TestGlobMatch/foo*_foobar2334=== PAUSE TestGlobMatch/foo*_foobar2335=== RUN TestGlobMatch/foo*_bar2336=== PAUSE TestGlobMatch/foo*_bar2337=== RUN TestGlobMatch/*bar_bar2338=== PAUSE TestGlobMatch/*bar_bar2339=== RUN TestGlobMatch/*bar_foobar2340--- PASS: TestPins_ConfigValidation (0.00s)2341=== PAUSE TestGlobMatch/*bar_foobar2342=== RUN TestGlobMatch/*bar_foo2343=== PAUSE TestGlobMatch/*bar_foo2344=== RUN TestGlobMatch/foo*bar_foobar2345=== PAUSE TestGlobMatch/foo*bar_foobar2346=== RUN TestGlobMatch/foo*bar_foo123bar2347=== PAUSE TestGlobMatch/foo*bar_foo123bar2348=== RUN TestGlobMatch/foo*bar_foobarbaz2349=== PAUSE TestGlobMatch/foo*bar_foobarbaz2350=== RUN TestGlobMatch/*/*_foo/bar2351=== PAUSE TestGlobMatch/*/*_foo/bar2352=== RUN TestGlobMatch/*/*_foo2353=== PAUSE TestGlobMatch/*/*_foo2354=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2355=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2356=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02357=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02358=== RUN TestGlobMatch/refs/*/main_refs/heads/main2359=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2360=== RUN TestGlobMatch/fo?_foo2361=== PAUSE TestGlobMatch/fo?_foo2362=== RUN TestGlobMatch/fo?_fo2363=== PAUSE TestGlobMatch/fo?_fo2364=== RUN TestGlobMatch/fo?_fooo2365=== PAUSE TestGlobMatch/fo?_fooo2366=== RUN TestGlobMatch/?oo_foo2367=== PAUSE TestGlobMatch/?oo_foo2368=== RUN TestGlobMatch/?oo_boo2369=== PAUSE TestGlobMatch/?oo_boo2370=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2371=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2372=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2373=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2374=== CONT TestGlobMatch/foo_bar2375=== CONT TestGlobMatch/?oo_boo2376=== CONT TestGlobMatch/*/*_foo/bar2377=== CONT TestGlobMatch/*bar_foobar2378=== CONT TestGlobMatch/foo*_foobar2379=== CONT TestGlobMatch/*bar_bar2380=== CONT TestGlobMatch/fo?_fo2381=== CONT TestGlobMatch/?oo_foo2382=== CONT TestGlobMatch/fo?_fooo2383=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2384=== CONT TestGlobMatch/refs/*/main_refs/heads/main2385=== CONT TestGlobMatch/*/*_foo2386=== CONT TestGlobMatch/foo*_bar2387=== CONT TestGlobMatch/foo*bar_foobarbaz2388=== CONT TestGlobMatch/foo_foo2389=== CONT TestGlobMatch/foo*_foo2390=== CONT TestGlobMatch/foo*bar_foobar2391=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02392=== CONT TestGlobMatch/foo*bar_foo123bar2393=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2394=== CONT TestGlobMatch/*bar_foo2395=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2396=== CONT TestGlobMatch/*_anything2397=== CONT TestGlobMatch/fo?_foo2398=== CONT TestGlobMatch/*_2399--- PASS: TestGlobMatch (0.00s)2400 --- PASS: TestGlobMatch/?oo_boo (0.00s)2401 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2402 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2403 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2404 --- PASS: TestGlobMatch/*bar_bar (0.00s)2405 --- PASS: TestGlobMatch/?oo_foo (0.00s)2406 --- PASS: TestGlobMatch/fo?_fo (0.00s)2407 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2408 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2409 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2410 --- PASS: TestGlobMatch/*/*_foo (0.00s)2411 --- PASS: TestGlobMatch/foo*_bar (0.00s)2412 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2413 --- PASS: TestGlobMatch/foo_foo (0.00s)2414 --- PASS: TestGlobMatch/foo*_foo (0.00s)2415 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2416 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2417 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2418 --- PASS: TestGlobMatch/foo_bar (0.00s)2419 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2420 --- PASS: TestGlobMatch/*bar_foo (0.00s)2421 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2422 --- PASS: TestGlobMatch/*_anything (0.00s)2423 --- PASS: TestGlobMatch/*_ (0.00s)2424 --- PASS: TestGlobMatch/fo?_foo (0.00s)24252026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:40435/oidc2426--- PASS: TestPins_ReservedForMatchingRule (0.10s)24272026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33845/oidc24282026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:41933/oidc24292026/10/02 20:38:21 http: TLS handshake error from 127.0.0.1:53418: remote error: tls: bad certificate2430--- PASS: TestNewValidator_KubernetesRequiresCA (0.16s)2431--- PASS: TestValidateToken_WrongAudience (0.16s)2432--- PASS: TestScopes_Rules (0.17s)24332026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:33619/oidc24342026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:32917/oidc2435--- PASS: TestPins_TopLevelShorthand (0.20s)24362026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34963/oidc2437--- PASS: TestValidateToken_BoundSubjectMismatch (0.20s)2438--- PASS: TestHTTPClientForHasTimeouts (0.20s)2439--- PASS: TestValidateToken_BoundClaimsMismatch (0.20s)24402026/10/02 20:38:21 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:404072441--- PASS: TestValidateToken_KubernetesServiceAccount (0.24s)24422026/10/02 20:38:21 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232443--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.26s)24442026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:34247/oidc2445--- PASS: TestValidateToken_Expired (0.27s)24462026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:43647/oidc2447--- PASS: TestValidateToken_ValidToken (0.28s)24482026/10/02 20:38:21 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:46065/oidc2449--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.29s)24502026/10/02 20:38:22 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:33919/oidc24512026/10/02 20:38:22 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:43067/oidc2452--- PASS: TestValidateToken_MultipleProviders (0.40s)24532026/10/02 20:38:22 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:37199/oidc2454--- PASS: TestValidateToken_NoMatchingProvider (0.43s)2455PASS2456Running signing tests...2457=== RUN TestGenerateFingerprint2458=== PAUSE TestGenerateFingerprint2459=== RUN TestParseSigningKey2460=== PAUSE TestParseSigningKey2461=== RUN TestSignMessage2462=== PAUSE TestSignMessage2463=== RUN TestSignNarinfo2464=== PAUSE TestSignNarinfo2465=== CONT TestSignMessage2466=== CONT TestSignNarinfo2467=== CONT TestParseSigningKey2468=== CONT TestGenerateFingerprint2469=== RUN TestParseSigningKey/valid_32-byte_key2470=== RUN TestGenerateFingerprint/basic_with_references2471=== PAUSE TestParseSigningKey/valid_32-byte_key2472=== PAUSE TestGenerateFingerprint/basic_with_references2473=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2474=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2475=== RUN TestParseSigningKey/no_colon2476=== RUN TestGenerateFingerprint/no_references2477=== PAUSE TestGenerateFingerprint/no_references2478=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2479=== PAUSE TestParseSigningKey/no_colon2480=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2481=== RUN TestParseSigningKey/empty_name2482=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2483=== PAUSE TestParseSigningKey/empty_name2484=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2485=== RUN TestParseSigningKey/invalid_base642486=== PAUSE TestParseSigningKey/invalid_base642487=== RUN TestGenerateFingerprint/invalid_nar_hash_length2488=== RUN TestParseSigningKey/wrong_length2489=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2490=== PAUSE TestParseSigningKey/wrong_length2491=== RUN TestGenerateFingerprint/invalid_store_path_prefix2492=== CONT TestParseSigningKey/valid_32-byte_key2493=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2494=== RUN TestGenerateFingerprint/invalid_reference_prefix2495=== CONT TestParseSigningKey/no_colon2496=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2497=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2498=== CONT TestParseSigningKey/wrong_length2499=== CONT TestParseSigningKey/empty_name2500=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2501=== CONT TestParseSigningKey/invalid_base642502=== CONT TestGenerateFingerprint/invalid_store_path_prefix2503=== CONT TestGenerateFingerprint/invalid_nar_hash_length2504=== CONT TestGenerateFingerprint/no_references2505=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2506=== CONT TestGenerateFingerprint/basic_with_references2507=== CONT TestGenerateFingerprint/invalid_reference_prefix2508--- PASS: TestGenerateFingerprint (0.00s)2509 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2510 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2511 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2512 --- PASS: TestGenerateFingerprint/no_references (0.00s)2513 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2514 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2515 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2516--- PASS: TestParseSigningKey (0.00s)2517 --- PASS: TestParseSigningKey/no_colon (0.00s)2518 --- PASS: TestParseSigningKey/wrong_length (0.00s)2519 --- PASS: TestParseSigningKey/empty_name (0.00s)2520 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2521 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.01s)2522 --- PASS: TestParseSigningKey/valid_32-byte_key (0.01s)2523--- PASS: TestSignMessage (0.01s)2524--- PASS: TestSignNarinfo (0.02s)2525PASS2526Running hook tests...2527=== RUN TestSendPathsEmpty2528=== PAUSE TestSendPathsEmpty2529=== RUN TestQueueEnqueueAndFetch2530=== PAUSE TestQueueEnqueueAndFetch2531=== RUN TestQueueDeduplication2532=== PAUSE TestQueueDeduplication2533=== RUN TestQueueRemove2534=== PAUSE TestQueueRemove2535=== RUN TestQueueFetchBatchLimit2536=== PAUSE TestQueueFetchBatchLimit2537=== RUN TestQueueRetryMovesToBack2538=== PAUSE TestQueueRetryMovesToBack2539=== RUN TestQueueFetchRemoveLifecycle2540=== PAUSE TestQueueFetchRemoveLifecycle2541=== RUN TestQueueConcurrentWriters2542=== PAUSE TestQueueConcurrentWriters2543=== RUN TestQueueEnqueueWaitsOutSlowWriter2544=== PAUSE TestQueueEnqueueWaitsOutSlowWriter2545=== RUN TestQueueRemoveLargeClosure2546=== PAUSE TestQueueRemoveLargeClosure2547=== RUN TestServerClientIntegration2548=== PAUSE TestServerClientIntegration2549=== RUN TestServerQueueError2550=== PAUSE TestServerQueueError2551=== RUN TestServerRefusesOversizedAndNonStoreRequests2552=== PAUSE TestServerRefusesOversizedAndNonStoreRequests2553=== RUN TestGetListenerSocketActivation2554 server_test.go:317: === RUN TestGetListenerSocketActivation2555 --- PASS: TestGetListenerSocketActivation (0.00s)2556 PASS2557 2558--- PASS: TestGetListenerSocketActivation (1.02s)2559=== RUN TestServerStalledClientDoesNotBlockShutdown2560=== PAUSE TestServerStalledClientDoesNotBlockShutdown2561=== RUN TestServerBacksOffOnAcceptErrors2562=== PAUSE TestServerBacksOffOnAcceptErrors2563=== RUN TestDrainIsolatesPoisonPath2564=== PAUSE TestDrainIsolatesPoisonPath2565=== RUN TestRunNotBlockedByPoisonHead2566=== PAUSE TestRunNotBlockedByPoisonHead2567=== RUN TestDrainGivesUpWhenServerDown2568=== PAUSE TestDrainGivesUpWhenServerDown2569=== RUN TestFailedPathPrunedByLaterClosure2570=== PAUSE TestFailedPathPrunedByLaterClosure2571=== RUN TestWorkerUploadsAndRemoves2572=== PAUSE TestWorkerUploadsAndRemoves2573=== RUN TestWorkerSkipsGCdPaths2574=== PAUSE TestWorkerSkipsGCdPaths2575=== RUN TestWorkerPrunesClosureDeps2576=== PAUSE TestWorkerPrunesClosureDeps2577=== RUN TestWorkerRemovesCachedPathBatchedWithLargerClosure2578=== PAUSE TestWorkerRemovesCachedPathBatchedWithLargerClosure2579=== RUN TestDrainTimeout2580=== PAUSE TestDrainTimeout2581=== RUN TestDrainTimeoutDuringIsolation2582=== PAUSE TestDrainTimeoutDuringIsolation2583=== RUN TestShutdownFinishesInFlightPush2584=== PAUSE TestShutdownFinishesInFlightPush2585=== RUN TestWorkerRemoveFailureIsNotProgress2586=== PAUSE TestWorkerRemoveFailureIsNotProgress2587=== RUN TestWorkerKeepsPathItCannotStat2588=== PAUSE TestWorkerKeepsPathItCannotStat2589=== CONT TestQueueFetchRemoveLifecycle2590=== CONT TestServerQueueError2591=== CONT TestDrainGivesUpWhenServerDown2592=== CONT TestWorkerPrunesClosureDeps2593=== CONT TestWorkerKeepsPathItCannotStat2594=== CONT TestQueueRemoveLargeClosure2595=== CONT TestWorkerUploadsAndRemoves2596=== CONT TestServerBacksOffOnAcceptErrors2597=== CONT TestServerStalledClientDoesNotBlockShutdown2598=== CONT TestServerRefusesOversizedAndNonStoreRequests2599=== CONT TestQueueConcurrentWriters2600=== CONT TestQueueRetryMovesToBack2601=== CONT TestQueueFetchBatchLimit2602=== CONT TestQueueRemove2603=== CONT TestQueueDeduplication26042026/10/02 20:38:25 ERROR Failed to queue paths error="permission denied" count=126052026/10/02 20:38:25 ERROR Accept failed error="too many open files"2606=== CONT TestQueueEnqueueAndFetch26072026/10/02 20:38:25 ERROR Refusing path outside the store path=/etc/shadow store=/nix/store2608=== CONT TestSendPathsEmpty26092026/10/02 20:38:25 ERROR Refusing path outside the store path=/nix/store store=/nix/store2610=== CONT TestFailedPathPrunedByLaterClosure2611=== CONT TestDrainTimeoutDuringIsolation2612=== CONT TestServerClientIntegration2613=== CONT TestDrainIsolatesPoisonPath2614=== CONT TestQueueEnqueueWaitsOutSlowWriter2615=== CONT TestWorkerSkipsGCdPaths2616=== CONT TestWorkerRemovesCachedPathBatchedWithLargerClosure2617=== CONT TestShutdownFinishesInFlightPush2618--- PASS: TestServerQueueError (0.00s)2619=== RUN TestShutdownFinishesInFlightPush/completes26202026/10/02 20:38:25 ERROR Refusing path outside the store path=/nix/store/ store=/nix/store2621--- PASS: TestSendPathsEmpty (0.00s)2622=== PAUSE TestShutdownFinishesInFlightPush/completes2623=== RUN TestDrainTimeoutDuringIsolation/probe_cut_short2624=== RUN TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2625=== PAUSE TestDrainTimeoutDuringIsolation/probe_cut_short2626=== PAUSE TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout2627=== CONT TestWorkerRemoveFailureIsNotProgress2628=== RUN TestWorkerRemoveFailureIsNotProgress/collected_path2629=== RUN TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2630=== CONT TestDrainTimeout26312026/10/02 20:38:25 ERROR Refusing path outside the store path=/nix/store/../../etc/shadow store=/nix/store2632=== PAUSE TestWorkerRemoveFailureIsNotProgress/collected_path2633=== PAUSE TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline2634=== RUN TestWorkerRemoveFailureIsNotProgress/pushed_batch2635=== CONT TestRunNotBlockedByPoisonHead2636=== PAUSE TestWorkerRemoveFailureIsNotProgress/pushed_batch2637=== RUN TestWorkerRemoveFailureIsNotProgress/isolated_paths2638=== PAUSE TestWorkerRemoveFailureIsNotProgress/isolated_paths2639=== CONT TestShutdownFinishesInFlightPush/completes26402026/10/02 20:38:25 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello/bin/sh store=/nix/store2641--- PASS: TestServerClientIntegration (0.00s)2642=== CONT TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout26432026/10/02 20:38:25 ERROR Refusing path outside the store path=nix/store/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26442026/10/02 20:38:25 ERROR Accept failed error="too many open files"26452026/10/02 20:38:25 ERROR Refusing path outside the store path=/nix/storeX/0123456789abcdfghijklmnpqrsvwxyz-hello store=/nix/store26462026/10/02 20:38:25 ERROR Refusing path outside the store path=/nix/store/.links store=/nix/store26472026/10/02 20:38:25 ERROR Refusing path outside the store path=/nix/store/aaa-hello store=/nix/store26482026/10/02 20:38:25 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz store=/nix/store26492026/10/02 20:38:25 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz- store=/nix/store26502026/10/02 20:38:25 ERROR Refusing path outside the store path=/nix/store/0123456789ebcdfghijklmnpqrsvwxyz-hello store=/nix/store26512026/10/02 20:38:25 ERROR Refusing path outside the store path="/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel\x00lo" store=/nix/store26522026/10/02 20:38:25 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-hel/lo store=/nix/store26532026/10/02 20:38:25 ERROR Refusing path outside the store path=/nix/store/0123456789abcdfghijklmnpqrsvwxyz-xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx store=/nix/store26542026/10/02 20:38:25 ERROR Failed to decode request error="unexpected EOF"2655--- PASS: TestServerRefusesOversizedAndNonStoreRequests (0.01s)2656=== CONT TestDrainTimeoutDuringIsolation/probe_cut_short26572026/10/02 20:38:25 ERROR Accept failed error="too many open files"26582026/10/02 20:38:25 ERROR Accept failed error="too many open files"26592026/10/02 20:38:25 INFO Upload queue status pending=326602026/10/02 20:38:25 INFO Uploading batch count=126612026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=126622026/10/02 20:38:25 INFO Upload queue status pending=226632026/10/02 20:38:25 INFO Uploading batch count=426642026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=426652026/10/02 20:38:25 INFO Upload queue status pending=226662026/10/02 20:38:25 INFO Upload queue status pending=226672026/10/02 20:38:25 INFO Uploading batch count=226682026/10/02 20:38:25 INFO Uploading batch count=126692026/10/02 20:38:25 INFO Uploading batch count=226702026/10/02 20:38:25 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainIsolatesPoisonPath57763229/002/bbb26712026/10/02 20:38:25 INFO Uploading batch count=126722026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=126732026/10/02 20:38:25 INFO Upload queue status pending=22674--- PASS: TestQueueFetchBatchLimit (0.06s)2675=== CONT TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline26762026/10/02 20:38:25 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2522537434/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2522537434/002/locked/aaa: permission denied"26772026/10/02 20:38:25 INFO Uploading batch count=226782026/10/02 20:38:25 INFO Uploading batch count=226792026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=226802026/10/02 20:38:25 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown914831944/002/a2681--- PASS: TestQueueRemove (0.07s)2682=== CONT TestWorkerRemoveFailureIsNotProgress/pushed_batch26832026/10/02 20:38:25 INFO Uploading batch count=126842026/10/02 20:38:25 INFO Upload queue status pending=32685--- PASS: TestQueueFetchRemoveLifecycle (0.07s)2686=== CONT TestWorkerRemoveFailureIsNotProgress/isolated_paths26872026/10/02 20:38:25 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown914831944/002/b26882026/10/02 20:38:25 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2522537434/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2522537434/002/locked/aaa: permission denied"26892026/10/02 20:38:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerSkipsGCdPaths4199441636/002/nonexistent26902026/10/02 20:38:25 INFO Uploading batch count=426912026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=426922026/10/02 20:38:25 INFO Uploading batch count=226932026/10/02 20:38:25 INFO Upload queue status pending=22694--- PASS: TestQueueEnqueueAndFetch (0.07s)2695=== CONT TestWorkerRemoveFailureIsNotProgress/collected_path26962026/10/02 20:38:25 INFO Uploading batch count=226972026/10/02 20:38:25 INFO Uploading batch count=12698--- PASS: TestQueueRetryMovesToBack (0.07s)26992026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=127002026/10/02 20:38:25 WARN Cannot stat store path, will retry later path=/build/TestWorkerKeepsPathItCannotStat2522537434/002/locked/aaa error="lstat /build/TestWorkerKeepsPathItCannotStat2522537434/002/locked/aaa: permission denied"27012026/10/02 20:38:25 INFO Uploading batch count=127022026/10/02 20:38:25 INFO Uploading batch count=227032026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=227042026/10/02 20:38:25 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown914831944/002/c27052026/10/02 20:38:25 INFO Uploading batch count=227062026/10/02 20:38:25 ERROR Accept failed error="too many open files"27072026/10/02 20:38:25 ERROR Drain finished with paths left in queue remaining=127082026/10/02 20:38:25 INFO Uploading batch count=127092026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=127102026/10/02 20:38:25 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown914831944/002/d2711--- PASS: TestQueueDeduplication (0.08s)27122026/10/02 20:38:25 INFO Uploading batch count=127132026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=127142026/10/02 20:38:25 INFO Uploading batch count=227152026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=227162026/10/02 20:38:25 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown914831944/002/e2717--- PASS: TestWorkerKeepsPathItCannotStat (0.08s)27182026/10/02 20:38:25 ERROR Upload failed, will retry later error="upload failed" path=/build/TestDrainGivesUpWhenServerDown914831944/002/f27192026/10/02 20:38:25 ERROR Drain finished with paths left in queue remaining=12720--- PASS: TestFailedPathPrunedByLaterClosure (0.09s)27212026/10/02 20:38:25 ERROR Drain finished with paths left in queue remaining=102722--- PASS: TestWorkerPrunesClosureDeps (0.09s)2723--- PASS: TestDrainIsolatesPoisonPath (0.09s)27242026/10/02 20:38:25 INFO Uploading batch count=427252026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=42726--- PASS: TestWorkerUploadsAndRemoves (0.09s)2727--- PASS: TestDrainGivesUpWhenServerDown (0.10s)2728--- PASS: TestWorkerSkipsGCdPaths (0.09s)2729--- PASS: TestWorkerRemovesCachedPathBatchedWithLargerClosure (0.10s)27302026/10/02 20:38:25 INFO Uploading batch count=227312026/10/02 20:38:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227322026/10/02 20:38:25 INFO Uploading batch count=227332026/10/02 20:38:25 INFO Uploading batch count=227342026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=227352026/10/02 20:38:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227362026/10/02 20:38:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127372026/10/02 20:38:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127382026/10/02 20:38:25 INFO Uploading batch count=227392026/10/02 20:38:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1988239088/001/nonexistent27402026/10/02 20:38:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=227412026/10/02 20:38:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127422026/10/02 20:38:25 INFO Uploading batch count=227432026/10/02 20:38:25 ERROR Drain finished with paths left in queue remaining=227442026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=227452026/10/02 20:38:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127462026/10/02 20:38:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1988239088/001/nonexistent27472026/10/02 20:38:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127482026/10/02 20:38:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127492026/10/02 20:38:25 INFO Uploading batch count=227502026/10/02 20:38:25 ERROR Upload failed error="upload failed" count=227512026/10/02 20:38:25 WARN Store path no longer exists (garbage collected?), removing from queue path=/build/TestWorkerRemoveFailureIsNotProgresscollected_path1988239088/001/nonexistent27522026/10/02 20:38:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127532026/10/02 20:38:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127542026/10/02 20:38:25 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=127552026/10/02 20:38:25 ERROR Drain finished with paths left in queue remaining=127562026/10/02 20:38:25 ERROR Drain finished with paths left in queue remaining=22757--- PASS: TestWorkerRemoveFailureIsNotProgress (0.00s)2758 --- PASS: TestWorkerRemoveFailureIsNotProgress/pushed_batch (0.05s)2759 --- PASS: TestWorkerRemoveFailureIsNotProgress/collected_path (0.05s)2760 --- PASS: TestWorkerRemoveFailureIsNotProgress/isolated_paths (0.05s)27612026/10/02 20:38:25 ERROR Accept failed error="too many open files"27622026/10/02 20:38:25 ERROR Failed to decode request error="read unix /build/hook1264898646/test.sock->@: i/o timeout"27632026/10/02 20:38:25 ERROR Failed to write response error="write unix /build/hook1264898646/test.sock->@: i/o timeout"2764--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)27652026/10/02 20:38:25 ERROR Upload failed error="context canceled" count=227662026/10/02 20:38:25 ERROR Drain finished with paths left in queue remaining=22767--- PASS: TestShutdownFinishesInFlightPush (0.00s)2768 --- PASS: TestShutdownFinishesInFlightPush/completes (0.17s)2769 --- PASS: TestShutdownFinishesInFlightPush/hung_push_bounded_by_the_drain_timeout (0.26s)27702026/10/02 20:38:25 ERROR Upload failed error="context canceled" count=227712026/10/02 20:38:25 ERROR Drain finished with paths left in queue remaining=427722026/10/02 20:38:25 ERROR Drain finished with paths left in queue remaining=42773--- PASS: TestDrainTimeout (0.27s)27742026/10/02 20:38:25 ERROR Accept failed error="too many open files"27752026/10/02 20:38:25 ERROR Drain finished with paths left in queue remaining=32776--- PASS: TestDrainTimeoutDuringIsolation (0.00s)2777 --- PASS: TestDrainTimeoutDuringIsolation/probe_cut_short (0.26s)2778 --- PASS: TestDrainTimeoutDuringIsolation/probe_outlasts_the_deadline (0.33s)2779--- PASS: TestQueueConcurrentWriters (0.52s)27802026/10/02 20:38:25 ERROR Accept failed error="too many open files"2781--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)27822026/10/02 20:38:26 INFO Uploading batch count=127832026/10/02 20:38:26 INFO Uploading batch count=127842026/10/02 20:38:26 INFO Uploading batch count=127852026/10/02 20:38:26 ERROR Upload failed error="upload failed" count=127862026/10/02 20:38:26 INFO Uploading batch count=127872026/10/02 20:38:26 ERROR Upload failed error="upload failed" count=127882026/10/02 20:38:26 INFO Uploading batch count=127892026/10/02 20:38:26 ERROR Upload failed error="upload failed" count=127902026/10/02 20:38:26 INFO Uploading batch count=127912026/10/02 20:38:26 ERROR Upload failed error="upload failed" count=127922026/10/02 20:38:26 ERROR Drain finished with paths left in queue remaining=12793--- PASS: TestRunNotBlockedByPoisonHead (1.07s)2794--- PASS: TestQueueRemoveLargeClosure (3.57s)2795--- PASS: TestQueueEnqueueWaitsOutSlowWriter (6.07s)2796PASS2797Running niks3-hook command tests...2798=== RUN TestServeSecondSignalEndsDrain2799=== PAUSE TestServeSecondSignalEndsDrain2800=== RUN TestServeThenDrainPushesSendAcceptedBeforeShutdown2801=== PAUSE TestServeThenDrainPushesSendAcceptedBeforeShutdown2802=== CONT TestServeSecondSignalEndsDrain2803=== CONT TestServeThenDrainPushesSendAcceptedBeforeShutdown2804--- PASS: TestServeSecondSignalEndsDrain (0.07s)28052026/10/02 20:38:32 INFO Upload queue status pending=128062026/10/02 20:38:32 INFO Uploading batch count=12807--- PASS: TestServeThenDrainPushesSendAcceptedBeforeShutdown (0.13s)2808PASS2809Running rate limiter tests...2810=== RUN TestAdaptiveRateLimiter_ThreadSafety2811=== PAUSE TestAdaptiveRateLimiter_ThreadSafety2812=== CONT TestAdaptiveRateLimiter_ThreadSafety28132026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=7028142026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=4928152026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=34.328162026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=24.00999999999999828172026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=16.80728182026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=11.76489999999999928192026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=8.2354328202026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=5.76480099999999928212026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528222026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=5.12435000000000128232026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528242026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528252026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528262026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528272026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528282026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528292026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528302026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528312026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528322026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528332026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528342026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528352026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528362026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528372026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528382026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528392026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528402026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528412026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528422026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528432026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528442026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528452026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528462026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528472026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528482026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528492026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528502026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528512026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528522026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528532026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528542026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528552026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528562026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528572026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528582026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528592026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528602026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528612026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528622026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528632026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528642026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528652026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528662026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528672026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528682026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528692026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528702026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528712026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528722026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528732026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528742026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528752026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528762026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528772026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528782026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528792026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528802026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528812026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528822026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528832026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528842026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528852026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528862026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528872026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528882026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528892026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528902026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528912026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528922026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528932026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528942026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528952026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528962026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528972026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528982026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=528992026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529002026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529012026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529022026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529032026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529042026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529052026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529062026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529072026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529082026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529092026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529102026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529112026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=529122026/10/02 20:38:33 WARN Rate limiter backed off name=test rate=52913--- PASS: TestAdaptiveRateLimiter_ThreadSafety (2.92s)2914PASS