niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #425
· raw
1tribuchet: building on mac022Running 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 TestUploadMultipart_PartsInParallel18=== PAUSE TestUploadMultipart_PartsInParallel19=== RUN TestUploadMultipart_FailedPartBufferNotReused20=== PAUSE TestUploadMultipart_FailedPartBufferNotReused21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestUploadMultipart_SupersededByPeer24=== PAUSE TestUploadMultipart_SupersededByPeer25=== RUN TestDumpPathCaseHackMatchesNix26--- PASS: TestDumpPathCaseHackMatchesNix (0.14s)27=== RUN TestDumpPathCaseHackCollision28--- PASS: TestDumpPathCaseHackCollision (0.00s)29=== RUN TestSupersededNARStillUploadsListing30=== PAUSE TestSupersededNARStillUploadsListing31=== RUN TestDumpPathMatchesNix32=== PAUSE TestDumpPathMatchesNix33=== RUN TestDumpPathSingleFile34=== PAUSE TestDumpPathSingleFile35=== RUN TestDumpPathWriterError36=== PAUSE TestDumpPathWriterError37=== RUN TestEncodeNixBase3238=== PAUSE TestEncodeNixBase3239=== RUN TestEncodeNixBase32WithRealHash40=== PAUSE TestEncodeNixBase32WithRealHash41=== RUN TestConvertHashToNix3242=== PAUSE TestConvertHashToNix3243=== RUN TestGetStorePathHash44=== PAUSE TestGetStorePathHash45=== RUN TestPathInfoHashCompatibility46=== PAUSE TestPathInfoHashCompatibility47=== RUN TestParsePathInfoJSON48=== PAUSE TestParsePathInfoJSON49=== RUN TestParsePathInfoJSONMultiplePaths50=== PAUSE TestParsePathInfoJSONMultiplePaths51=== RUN TestPathInfoCACompatibility52=== PAUSE TestPathInfoCACompatibility53=== RUN TestRateLimiterFeedback54=== PAUSE TestRateLimiterFeedback55=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess56=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess57=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer58=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer59=== RUN TestResolveStorePath60=== PAUSE TestResolveStorePath61=== RUN TestDoWithRetry_BodyReplayedViaGetBody62=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody63=== RUN TestRetryTimeoutOutlastsMaxRetries64=== PAUSE TestRetryTimeoutOutlastsMaxRetries65=== RUN TestDoWithRetry_FinalResponseBodyReadable66=== PAUSE TestDoWithRetry_FinalResponseBodyReadable67=== RUN TestShellSplit68=== PAUSE TestShellSplit69=== RUN TestShellSplitErrors70=== PAUSE TestShellSplitErrors71=== RUN TestStreamPushReportsEveryPath72=== PAUSE TestStreamPushReportsEveryPath73=== RUN TestStreamPushBatchesUnderLoad74=== PAUSE TestStreamPushBatchesUnderLoad75=== RUN TestStreamPushIsolatesFailures76=== PAUSE TestStreamPushIsolatesFailures77=== RUN TestStreamPushGivesUpOnDeadServer78=== PAUSE TestStreamPushGivesUpOnDeadServer79=== RUN TestStreamPushRequestLine80=== PAUSE TestStreamPushRequestLine81=== RUN TestStreamPushReportsSignatures82=== PAUSE TestStreamPushReportsSignatures83=== RUN TestStreamPushReportsSkippedPaths84=== PAUSE TestStreamPushReportsSkippedPaths85=== RUN TestClientSignaturesByStorePath86=== PAUSE TestClientSignaturesByStorePath87=== RUN TestStreamPushStopsWhenCanceled88=== PAUSE TestStreamPushStopsWhenCanceled89=== RUN TestSetClientTLS90=== PAUSE TestSetClientTLS91=== RUN TestSetClientTLSDoesNotMutateDefaultTransport92=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport93=== RUN TestSetClientTLSErrors94=== PAUSE TestSetClientTLSErrors95=== RUN TestStaticToken96=== PAUSE TestStaticToken97=== RUN TestFileTokenReadsAndCaches98=== PAUSE TestFileTokenReadsAndCaches99=== RUN TestFileTokenMissing100=== PAUSE TestFileTokenMissing101=== RUN TestFileTokenEmpty102=== PAUSE TestFileTokenEmpty103=== RUN TestScriptTokenNoExpiryRerunsEveryCall104=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall105=== RUN TestScriptTokenCachesUntilRefresh106=== PAUSE TestScriptTokenCachesUntilRefresh107=== RUN TestScriptTokenEmptyToken108=== PAUSE TestScriptTokenEmptyToken109=== RUN TestScriptTokenBadJSON110=== PAUSE TestScriptTokenBadJSON111=== RUN TestScriptTokenScriptFails112=== PAUSE TestScriptTokenScriptFails113=== RUN TestScriptTokenEmptyCommand114=== PAUSE TestScriptTokenEmptyCommand115=== CONT TestDoServerRequestAttachesToken116=== CONT TestScriptTokenBadJSON117=== CONT TestRetryTimeoutOutlastsMaxRetries118=== CONT TestDumpPathWriterError119=== CONT TestScriptTokenEmptyCommand120--- PASS: TestScriptTokenEmptyCommand (0.00s)121=== CONT TestStreamPushRequestLine122=== CONT TestScriptTokenScriptFails123=== CONT TestDoWithRetry_BodyReplayedViaGetBody124=== CONT TestResolveStorePath125=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer126=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess127=== CONT TestRateLimiterFeedback128=== CONT TestPathInfoCACompatibility129=== CONT TestParsePathInfoJSONMultiplePaths130=== CONT TestParsePathInfoJSON131=== CONT TestPathInfoHashCompatibility132=== CONT TestGetStorePathHash133=== CONT TestConvertHashToNix32134=== CONT TestEncodeNixBase32WithRealHash135=== CONT TestEncodeNixBase32136=== CONT TestStreamPushIsolatesFailures137=== CONT TestClientSignaturesByStorePath138=== CONT TestStreamPushReportsSkippedPaths139=== CONT TestStreamPushReportsSignatures140=== CONT TestStreamPushStopsWhenCanceled141=== RUN TestRateLimiterFeedback/429_enables_limiter142=== RUN TestPathInfoCACompatibility/null_ca_field143=== PAUSE TestPathInfoCACompatibility/null_ca_field144=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths145=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths146=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)147=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)148=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon149=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon150=== RUN TestParsePathInfoJSON/Nix_format151=== PAUSE TestParsePathInfoJSON/Nix_format152=== PAUSE TestRateLimiterFeedback/429_enables_limiter153=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths154=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths155=== RUN TestPathInfoCACompatibility/old_string_format_-_text156=== RUN TestEncodeNixBase32/test_string_hash157=== RUN TestConvertHashToNix32/SRI_format_to_Nix32158=== PAUSE TestEncodeNixBase32/test_string_hash159=== CONT TestStaticToken160=== CONT TestSetClientTLSErrors161=== RUN TestEncodeNixBase32/empty_input162=== RUN TestRateLimiterFeedback/503_enables_limiter163=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text1642026/10/25 16:08:41 ERROR Upload failed error=boom count=11652026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:606741662026/10/25 16:08:41 ERROR Upload failed error="bad path" count=3167=== CONT TestFileTokenReadsAndCaches168=== CONT TestFileTokenMissing1692026/10/25 16:08:41 ERROR Upload failed error=boom count=1170=== CONT TestSetClientTLS171=== CONT TestScriptTokenEmptyToken172=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive173=== CONT TestScriptTokenCachesUntilRefresh174=== CONT TestScriptTokenNoExpiryRerunsEveryCall1752026/10/25 16:08:41 WARN Rate limiter enabled after throttle name=server-test rate=51762026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:60678177=== PAUSE TestEncodeNixBase32/empty_input178=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive179=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32180=== CONT TestStreamPushGivesUpOnDeadServer181=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI182=== RUN TestGetStorePathHash/valid_store_path183--- PASS: TestEncodeNixBase32WithRealHash (0.00s)184--- PASS: TestClientSignaturesByStorePath (0.00s)185--- PASS: TestStaticToken (0.00s)186--- PASS: TestStreamPushStopsWhenCanceled (0.00s)187--- PASS: TestStreamPushReportsSkippedPaths (0.00s)188--- PASS: TestStreamPushReportsSignatures (0.00s)189--- PASS: TestResolveStorePath (0.00s)190--- PASS: TestFileTokenReadsAndCaches (0.00s)191--- PASS: TestFileTokenMissing (0.00s)192=== RUN TestParsePathInfoJSON/Lix_format193=== PAUSE TestParsePathInfoJSON/Lix_format1942026/10/25 16:08:41 WARN Rate limiter enabled after throttle name=server-test rate=5195=== PAUSE TestRateLimiterFeedback/503_enables_limiter196=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter197=== CONT TestSetClientTLSDoesNotMutateDefaultTransport198=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter199=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter200=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter201=== CONT TestDumpPathMatchesNix2022026/10/25 16:08:41 ERROR Upload failed error="connection refused" count=202032026/10/25 16:08:41 ERROR Server seems unavailable, giving up on batch untried=17204=== CONT TestUploadMultipart_PartsInParallel205=== CONT TestSupersededNARStillUploadsListing206=== RUN TestParsePathInfoJSON/empty_input207--- PASS: TestStreamPushIsolatesFailures (0.00s)208=== CONT TestFileTokenEmpty209=== PAUSE TestGetStorePathHash/valid_store_path2102026/10/25 16:08:41 WARN Rate limiter backed off name=server-test rate=52112026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:60678212--- PASS: TestScriptTokenScriptFails (0.01s)213--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)214=== RUN TestGetStorePathHash/basename_without_hyphen_should_error215=== PAUSE TestParsePathInfoJSON/empty_input216=== RUN TestPathInfoCACompatibility/new_structured_format_-_text217=== RUN TestSetClientTLSErrors/missing_cert_file218=== CONT TestDumpPathSingleFile219=== RUN TestConvertHashToNix32/already_Nix32_format220=== RUN TestParsePathInfoJSON/whitespace_only221=== RUN TestSupersededNARStillUploadsListing/small_NAR222--- PASS: TestDoServerRequestAttachesToken (0.01s)223=== CONT TestUploadMultipart_FailedPartBufferNotReused224=== CONT TestShellSplitErrors225=== CONT TestStreamPushBatchesUnderLoad2262026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:60674227=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text228=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method229=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method230=== PAUSE TestSetClientTLSErrors/missing_cert_file231=== RUN TestSetClientTLSErrors/missing_key_file232=== PAUSE TestSetClientTLSErrors/missing_key_file233=== RUN TestSetClientTLSErrors/missing_ca_file234=== PAUSE TestSetClientTLSErrors/missing_ca_file235=== RUN TestSetClientTLSErrors/invalid_ca_file236=== PAUSE TestSetClientTLSErrors/invalid_ca_file237=== RUN TestSetClientTLS/rejects_connection_without_client_cert238=== CONT TestStreamPushReportsEveryPath239=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert240=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA241=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA242=== RUN TestSetClientTLS/preserves_debug_logging_transport243=== PAUSE TestSetClientTLS/preserves_debug_logging_transport244=== PAUSE TestConvertHashToNix32/already_Nix32_format245=== RUN TestConvertHashToNix32/invalid_format246=== PAUSE TestConvertHashToNix32/invalid_format247=== CONT TestPartSizeForNAR248=== RUN TestPartSizeForNAR/zero_stays_at_minimum249=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum250=== RUN TestPartSizeForNAR/small_stays_at_minimum251=== PAUSE TestPartSizeForNAR/small_stays_at_minimum252=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum253=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum254=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts255=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts256=== RUN TestPartSizeForNAR/1_TiB257=== PAUSE TestPartSizeForNAR/1_TiB258=== RUN TestPartSizeForNAR/5_TiB_S3_max_object259=== PAUSE TestParsePathInfoJSON/whitespace_only260--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)261--- PASS: TestFileTokenEmpty (0.01s)262--- PASS: TestShellSplitErrors (0.00s)263=== PAUSE TestSupersededNARStillUploadsListing/small_NAR264=== RUN TestSupersededNARStillUploadsListing/dump_cut_short265=== PAUSE TestSupersededNARStillUploadsListing/dump_cut_short266=== RUN TestSupersededNARStillUploadsListing/listing_upload_fails267=== CONT TestUploadMultipart_SupersededByPeer268=== RUN TestUploadMultipart_SupersededByPeer/exists269=== CONT TestShellSplit270--- PASS: TestStreamPushReportsEveryPath (0.00s)271=== CONT TestRegisterUploadedObjectReusesConnections272--- PASS: TestShellSplit (0.00s)273=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry274=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object275=== RUN TestPartSizeForNAR/capped_at_5_GiB276=== CONT TestFilterOversizedClosures277=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI278=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error279=== PAUSE TestSupersededNARStillUploadsListing/listing_upload_fails280=== CONT TestCaseHackSuffix281--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.02s)282=== CONT TestDoWithRetry_FinalResponseBodyReadable283=== PAUSE TestPartSizeForNAR/capped_at_5_GiB284=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica285=== PAUSE TestUploadMultipart_SupersededByPeer/exists286=== RUN TestParsePathInfoJSON/invalid_JSON287=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512288=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512289--- PASS: TestScriptTokenBadJSON (0.03s)290=== PAUSE TestParsePathInfoJSON/invalid_JSON291=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun292=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths293=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error294=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error295=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error296=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error297=== RUN TestUploadMultipart_SupersededByPeer/missing298=== PAUSE TestUploadMultipart_SupersededByPeer/missing299=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths300=== CONT TestRateLimiterFeedback/429_enables_limiter301=== RUN TestFilterOversizedClosures/no_limit_keeps_everything302=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything303=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped304=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped305=== RUN TestFilterOversizedClosures/all_closures_skipped306=== PAUSE TestFilterOversizedClosures/all_closures_skipped307=== CONT TestEncodeNixBase32/test_string_hash308=== CONT TestEncodeNixBase32/empty_input309=== CONT TestPathInfoCACompatibility/null_ca_field310=== CONT TestSetClientTLSErrors/missing_cert_file311=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter312=== CONT TestSetClientTLS/rejects_connection_without_client_cert313--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)314 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)315 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)316--- PASS: TestEncodeNixBase32 (0.00s)317 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)318 --- PASS: TestEncodeNixBase32/empty_input (0.00s)319=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter320=== CONT TestRateLimiterFeedback/503_enables_limiter3212026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:606743222026/10/25 16:08:41 INFO Garbage collection started323--- PASS: TestScriptTokenEmptyToken (0.03s)324=== CONT TestPathInfoCACompatibility/old_string_format_-_text325=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method326=== CONT TestPathInfoCACompatibility/new_structured_format_-_text327=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive328=== CONT TestConvertHashToNix32/SRI_format_to_Nix32329=== CONT TestSetClientTLS/preserves_debug_logging_transport330--- PASS: TestPathInfoCACompatibility (0.01s)331 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)332 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)333 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)334 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)335 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)3362026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:606743372026/10/25 16:08:41 WARN Rate limiter enabled after throttle name=s3-test rate=53382026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:60747339--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.02s)340=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA3412026/10/25 16:08:41 INFO Garbage collection started3422026/10/25 16:08:41 WARN Rate limiter enabled after throttle name=server-test rate=53432026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:60757344=== CONT TestConvertHashToNix32/invalid_format345=== CONT TestConvertHashToNix32/already_Nix32_format3462026/10/25 16:08:41 WARN Rate limiter enabled after throttle name=server-test rate=53472026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:60741348--- PASS: TestConvertHashToNix32 (0.01s)349 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)350 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)351 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)352=== CONT TestSetClientTLSErrors/invalid_ca_file3532026/10/25 16:08:41 WARN Rate limiter enabled after throttle name=server-test rate=53542026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:607703552026/10/25 16:08:41 INFO Garbage collection progress phase=running_on_another_replica failed_uploads_deleted=0 old_closures_deleted=0 objects_marked=0 objects_deleted=0 objects_failed=0356=== CONT TestSetClientTLSErrors/missing_ca_file357=== CONT TestSetClientTLSErrors/missing_key_file358=== CONT TestSupersededNARStillUploadsListing/dump_cut_short359=== CONT TestSupersededNARStillUploadsListing/small_NAR3602026/10/25 16:08:41 WARN Rate limiter backed off name=server-test rate=53612026/10/25 16:08:41 WARN Rate limiter backed off name=server-test rate=53622026/10/25 16:08:41 WARN Rate limiter backed off name=server-test rate=5363--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.02s)364=== CONT TestPartSizeForNAR/zero_stays_at_minimum365=== CONT TestSupersededNARStillUploadsListing/listing_upload_fails366--- PASS: TestSetClientTLSErrors (0.02s)367 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)368 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)369 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)370 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)371--- PASS: TestRateLimiterFeedback (0.01s)372 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)373 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)374 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.02s)375 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.02s)3762026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:60674377=== CONT TestPartSizeForNAR/5_TiB_S3_max_object378=== CONT TestPartSizeForNAR/1_TiB379=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts380=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum381=== CONT TestPartSizeForNAR/small_stays_at_minimum382=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)383=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512384=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI385=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon386--- PASS: TestPathInfoHashCompatibility (0.02s)387 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)388 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)389 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)390 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)391=== CONT TestParsePathInfoJSON/Nix_format392=== CONT TestParsePathInfoJSON/invalid_JSON393=== CONT TestParsePathInfoJSON/empty_input394=== CONT TestParsePathInfoJSON/whitespace_only395=== CONT TestParsePathInfoJSON/Lix_format396--- PASS: TestParsePathInfoJSON (0.02s)397 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)398 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)399 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)400 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)401 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)402=== CONT TestGetStorePathHash/valid_store_path403=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error404=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error405=== CONT TestGetStorePathHash/basename_without_hyphen_should_error406--- PASS: TestGetStorePathHash (0.02s)407 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)408 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)409 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)410 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)411=== CONT TestUploadMultipart_SupersededByPeer/exists4122026/10/25 16:08:41 INFO Uploading abc-hello (1.0GB)413=== CONT TestPartSizeForNAR/capped_at_5_GiB414--- PASS: TestPartSizeForNAR (0.01s)415 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)416 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)417 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)418 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)419 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)420 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)421 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)422=== CONT TestUploadMultipart_SupersededByPeer/missing423=== CONT TestFilterOversizedClosures/no_limit_keeps_everything424=== CONT TestFilterOversizedClosures/all_closures_skipped425--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)426=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped4272026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:606744282026/10/25 16:08:41 WARN Rate limiter enabled after throttle name=s3-test rate=54292026/10/25 16:08:41 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper nar_size=100 max_nar_size=504302026/10/25 16:08:41 WARN Skipping closure: path exceeds server max NAR size top_level_path=/nix/store/cccccccccccccccccccccccccccccccc-wrapper oversized_path=/nix/store/bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb-vm-image nar_size=5000 max_nar_size=2000431--- PASS: TestFilterOversizedClosures (0.00s)432 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)433 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)434 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)4352026/10/25 16:08:41 INFO Uploading abc-hello (1.0GB)436--- PASS: TestStreamPushRequestLine (0.05s)4372026/10/25 16:08:41 WARN Garbage collection finished on another replica. Its statistics are not available here438--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.03s)4392026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:60674440--- PASS: TestUploadMultipart_SupersededByPeer (0.01s)441 --- PASS: TestUploadMultipart_SupersededByPeer/missing (0.00s)442 --- PASS: TestUploadMultipart_SupersededByPeer/exists (0.01s)4432026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:606744442026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:60674445--- PASS: TestScriptTokenCachesUntilRefresh (0.06s)4462026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:606744472026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:606744482026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:606744492026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:606744502026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:606744512026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:606744522026/10/25 16:08:41 http: TLS handshake error from 127.0.0.1:60767: read tcp 127.0.0.1:60686->127.0.0.1:60767: use of closed network connection453--- PASS: TestSetClientTLS (0.01s)454 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.03s)455 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.03s)456 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.05s)457--- PASS: TestRegisterUploadedObjectReusesConnections (0.07s)4582026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:60674459--- PASS: TestDumpPathWriterError (0.09s)4602026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:606744612026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:60674462--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.09s)4632026/10/25 16:08:41 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:60674464--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.10s)4652026/10/25 16:08:41 INFO Uploading abc-hello (1.0GB)4662026/10/25 16:08:41 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:60779/part/2\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:60779/part/2467--- PASS: TestStreamPushBatchesUnderLoad (0.10s)4682026/10/25 16:08:41 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:60779/part/3\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:60779/part/34692026/10/25 16:08:42 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:60779/part/4\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:60779/part/4470--- PASS: TestDumpPathSingleFile (0.11s)4712026/10/25 16:08:42 WARN Request failed, retrying attempt=1 backoff=100ms error="Put \"http://127.0.0.1:60779/part/5\": uploading part 1: server returned 404: no such upload\n" url=http://127.0.0.1:60779/part/54722026/10/25 16:08:42 ERROR Failed to close zstd encoder error="io: read/write on closed pipe"473--- PASS: TestCaseHackSuffix (0.12s)474--- PASS: TestDumpPathMatchesNix (0.18s)475--- PASS: TestUploadMultipart_FailedPartBufferNotReused (0.59s)476--- PASS: TestSupersededNARStillUploadsListing (0.01s)477 --- PASS: TestSupersededNARStillUploadsListing/small_NAR (0.01s)478 --- PASS: TestSupersededNARStillUploadsListing/listing_upload_fails (0.01s)479 --- PASS: TestSupersededNARStillUploadsListing/dump_cut_short (0.57s)480--- PASS: TestUploadMultipart_PartsInParallel (0.63s)4812026/10/25 16:08:42 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:60680/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:60680/api/uploads/complete4822026/10/25 16:08:42 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4832026/10/25 16:08:42 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:60680/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:60680/api/uploads/complete4842026/10/25 16:08:42 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4852026/10/25 16:08:42 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:60680/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:60680/api/uploads/complete4862026/10/25 16:08:42 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"487--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)488--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (1.01s)489PASS490Running server tests...491The files belonging to this database system will be owned by user "_tribuchetbld1".492This user must also own the server process.493494The database cluster will be initialized with locale "C".495The default database encoding has accordingly been set to "SQL_ASCII".496The default text search configuration will be set to "english".497498Data page checksums are enabled.499500creating directory /private/var/tb/1/scratch/39f8670b40371dc1/build/postgres1397542716/data ... ok501creating subdirectories ... ok502selecting dynamic shared memory implementation ... posix503selecting default "max_connections" ... 100504selecting default "shared_buffers" ... 128MB505selecting default time zone ... UTC506creating configuration files ... ok507running bootstrap script ... ok508performing post-bootstrap initialization ... ok509syncing data to disk ... ok510511initdb: warning: enabling "trust" authentication for local connections512initdb: 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.513514Success. You can now start the database server using:515516 pg_ctl -D /private/var/tb/1/scratch/39f8670b40371dc1/build/postgres1397542716/data -l logfile start5175182026-10-25 16:08:43.937 UTC [28681] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit5192026-10-25 16:08:43.937 UTC [28681] LOG: listening on Unix socket "/private/var/tb/1/scratch/39f8670b40371dc1/build/postgres1397542716/.s.PGSQL.5432"5202026-10-25 16:08:43.945 UTC [28691] LOG: database system was shut down at 2026-10-25 16:08:43 UTC5212026-10-25 16:08:43.946 UTC [28681] LOG: database system is ready to accept connections5222026-10-25 16:08:43.947 UTC [28692] FATAL: the database system is starting up523/private/var/tb/1/scratch/39f8670b40371dc1/build/postgres1397542716:5432 - rejecting connections524/private/var/tb/1/scratch/39f8670b40371dc1/build/postgres1397542716:5432 - accepting connections525{"timestamp":"2026-10-25T16:08:44.334778Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"45c458ff-4748-4383-b4bf-c9954205439a","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":29,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(4)"}526{"timestamp":"2026-10-25T16:08:44.451571Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"449f81c4-be04-4ea0-a96a-f4bb2d99763e","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(6)"}527{"timestamp":"2026-10-25T16:08:44.554664Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"bcc60be9-0885-4751-8986-840b45a3507b","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}528{"timestamp":"2026-10-25T16:08:44.656167Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"90207162-a2e9-48a2-a3e7-2463101b0456","trace_id":"unknown","span_id":"unknown","peer_addr":"127.0.0.1","method":"GET","uri":"/health/ready","status_code":503,"suppressed_errors":0,"duration_ms":0,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":501,"threadName":"rustfs-worker","threadId":"ThreadId(11)"}529=== RUN TestService_AuthMiddleware530=== PAUSE TestService_AuthMiddleware531=== RUN TestService_AuthMiddleware_MTLSProxyHeader532=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader533=== RUN TestService_AuthMiddleware_MTLSBoundSubjects534=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects535=== RUN TestService_ReadAuthMiddleware536=== PAUSE TestService_ReadAuthMiddleware537=== RUN TestService_AuthMiddleware_OIDC538=== PAUSE TestService_AuthMiddleware_OIDC539=== RUN TestService_RequireScope_OIDC540=== PAUSE TestService_RequireScope_OIDC541=== RUN TestService_ReadScope_PublicByDefault542=== PAUSE TestService_ReadScope_PublicByDefault543=== RUN TestCacheConfigHandler544=== PAUSE TestCacheConfigHandler545=== RUN TestCacheStatsHandler546=== PAUSE TestCacheStatsHandler547=== RUN TestClientCADerivations548=== PAUSE TestClientCADerivations549=== RUN TestClientErrorHandling550=== PAUSE TestClientErrorHandling551=== RUN TestClientIntegration552=== PAUSE TestClientIntegration553=== RUN TestClientMultipleUploads554=== PAUSE TestClientMultipleUploads555=== RUN TestClientWithDependencies556=== PAUSE TestClientWithDependencies557=== RUN TestClientSharedPathCommittedMidPush558=== PAUSE TestClientSharedPathCommittedMidPush559=== RUN TestPinProtectsFromGC560=== PAUSE TestPinProtectsFromGC561=== RUN TestClientPushesUseOnePush562=== PAUSE TestClientPushesUseOnePush563=== RUN TestClientFallsBackToClosures564=== PAUSE TestClientFallsBackToClosures565=== RUN TestDeleteClosuresRacingPins566=== PAUSE TestDeleteClosuresRacingPins567=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock568=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock569=== RUN TestResolveDBConnectionString570=== PAUSE TestResolveDBConnectionString571=== RUN TestConnectWaitsForAPeerMigration572=== PAUSE TestConnectWaitsForAPeerMigration573=== RUN TestLeadElectsOneAndHandsOver574=== PAUSE TestLeadElectsOneAndHandsOver575=== RUN TestLeadIncumbentWinsAfterRestart5762026/10/25 16:08:45 INFO lead: acquired remote=192.0.2.1:12345772026/10/25 16:08:45 INFO lead: released remote=192.0.2.1:12345782026/10/25 16:08:45 INFO lead: acquired remote=192.0.2.1:12345792026/10/25 16:08:46 INFO lead: released remote=192.0.2.1:1234580--- PASS: TestLeadIncumbentWinsAfterRestart (2.21s)581=== RUN TestLeadIncumbentAnnouncesAtOnce582=== PAUSE TestLeadIncumbentAnnouncesAtOnce583=== RUN TestLeadEndsOnShutdown584=== PAUSE TestLeadEndsOnShutdown585=== RUN TestLeadEndsWhenItsConnectionHangs5862026/10/25 16:08:47 INFO lead: acquired remote=192.0.2.1:12345872026-10-25 16:08:48.624 UTC [29288] FATAL: terminating connection due to administrator command5882026/10/25 16:08:48 INFO lead: acquired remote=192.0.2.1:12345892026/10/25 16:08:49 WARN lead: lock connection lost error="timeout: context deadline exceeded"5902026/10/25 16:08:49 INFO lead: released remote=192.0.2.1:12345912026/10/25 16:08:50 INFO lead: released remote=192.0.2.1:1234592--- PASS: TestLeadEndsWhenItsConnectionHangs (3.05s)593=== RUN TestGCAdvisoryLockBlocksConcurrentRun594=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun595=== RUN TestGCBugBareHashReferences596=== PAUSE TestGCBugBareHashReferences597=== RUN TestGCMetrics598=== PAUSE TestGCMetrics599=== RUN TestPushDedupSurvivesConcurrentGC600=== PAUSE TestPushDedupSurvivesConcurrentGC601=== RUN TestDeduplicatedObjectsRecordedAsPending602=== PAUSE TestDeduplicatedObjectsRecordedAsPending603=== RUN TestGCSweepSkipsPendingObjects604=== PAUSE TestGCSweepSkipsPendingObjects605=== RUN TestTombstonedObjectOfferedWithoutWaiting606=== PAUSE TestTombstonedObjectOfferedWithoutWaiting607=== RUN TestGCSweepDeliversEachKeyOnce608=== PAUSE TestGCSweepDeliversEachKeyOnce609=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection610=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection611=== RUN TestForceGCDuringPushOffersSweptObject612=== PAUSE TestForceGCDuringPushOffersSweptObject613=== RUN TestFailedS3DeleteKeepsTombstone614=== PAUSE TestFailedS3DeleteKeepsTombstone615=== RUN TestSweepSkipsRowsLockedByPush616=== PAUSE TestSweepSkipsRowsLockedByPush617=== RUN TestRegisterCompletedObjectNeedsPendingRow618=== PAUSE TestRegisterCompletedObjectNeedsPendingRow619=== RUN TestGetExistingObjectsLocksRows620=== PAUSE TestGetExistingObjectsLocksRows621=== RUN TestSweepRechecksPendingAfterLocking622=== PAUSE TestSweepRechecksPendingAfterLocking623=== RUN TestPushWaitsForSweepHoldingRow624=== PAUSE TestPushWaitsForSweepHoldingRow625=== RUN TestCommitRacingPendingCleanupKeepsObjects626=== PAUSE TestCommitRacingPendingCleanupKeepsObjects627=== RUN TestGCEndsOnShutdown628=== PAUSE TestGCEndsOnShutdown629=== RUN TestGCTaskStore_StartNew630=== PAUSE TestGCTaskStore_StartNew631=== RUN TestGCTaskStore_DeduplicateSameParams632=== PAUSE TestGCTaskStore_DeduplicateSameParams633=== RUN TestGCTaskStore_ConflictDifferentParams634=== PAUSE TestGCTaskStore_ConflictDifferentParams635=== RUN TestGCTaskStore_GetEmpty636=== PAUSE TestGCTaskStore_GetEmpty637=== RUN TestGCTaskStore_GetReturnsLatest638=== PAUSE TestGCTaskStore_GetReturnsLatest639=== RUN TestGCTaskStore_CompletedAllowsNewTask640=== PAUSE TestGCTaskStore_CompletedAllowsNewTask641=== RUN TestGCTaskStore_PhaseUpdates642=== PAUSE TestGCTaskStore_PhaseUpdates643=== RUN TestGCTaskStore_Fail644=== PAUSE TestGCTaskStore_Fail645=== RUN TestGracefulShutdownDrainsInflight646=== PAUSE TestGracefulShutdownDrainsInflight647=== RUN TestService_healthCheckHandler648=== PAUSE TestService_healthCheckHandler649=== RUN TestService_readinessHandler650=== PAUSE TestService_readinessHandler651=== RUN TestGenerateLandingPage652=== PAUSE TestGenerateLandingPage653=== RUN TestCacheConfigHandlerMaxNarSize654=== PAUSE TestCacheConfigHandlerMaxNarSize655=== RUN TestCreatePendingClosureRejectsOversizedNAR656=== PAUSE TestCreatePendingClosureRejectsOversizedNAR657=== RUN TestNARDeduplicationMetadataUploadBug658=== PAUSE TestNARDeduplicationMetadataUploadBug659=== RUN TestMetricsInventory660=== PAUSE TestMetricsInventory661=== RUN TestMetricsCommit662=== PAUSE TestMetricsCommit663=== RUN TestService_NativeMTLS664=== PAUSE TestService_NativeMTLS665=== RUN TestServerTLSConfig666=== PAUSE TestServerTLSConfig667=== RUN TestMultipartCleanup668=== PAUSE TestMultipartCleanup669=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded670=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded671=== RUN TestPendingCleanupUsesOneCutoff672=== PAUSE TestPendingCleanupUsesOneCutoff673=== RUN TestObjectStatsTrigger674=== PAUSE TestObjectStatsTrigger675=== RUN TestObjectStatsUpdatedOncePerCommit676=== PAUSE TestObjectStatsUpdatedOncePerCommit677=== RUN TestOrphanedObjectsGC678=== PAUSE TestOrphanedObjectsGC679=== RUN TestOrphanedObjectsGCStressTest680=== PAUSE TestOrphanedObjectsGCStressTest681=== RUN TestCreatePin_ReservedPins682=== PAUSE TestCreatePin_ReservedPins683=== RUN TestPresentReportsOnlyClosureRoots684=== PAUSE TestPresentReportsOnlyClosureRoots685=== RUN TestPresentRefreshesOnlyStaleClosures686=== PAUSE TestPresentRefreshesOnlyStaleClosures687=== RUN TestPresentNotReportedWhileGCDeletesClosure688=== PAUSE TestPresentNotReportedWhileGCDeletesClosure689=== RUN TestParseSingleRange690=== PAUSE TestParseSingleRange691=== RUN TestProxyHeadersOnlyTrustedOnSocket6922026/10/25 16:08:50 INFO Starting HTTP server address=127.0.0.1:608426932026/10/25 16:08:50 INFO Starting HTTP server address=proxy.sock6942026/10/25 16:08:50 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6952026/10/25 16:08:50 INFO Shutdown signal received, draining in-flight requests timeout=10s696--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.24s)697=== RUN TestIsValidCachePath698=== PAUSE TestIsValidCachePath699=== RUN TestReadProxyNarinfo700=== PAUSE TestReadProxyNarinfo701=== RUN TestReadProxyNarinfoAlreadyDecompressed702=== PAUSE TestReadProxyNarinfoAlreadyDecompressed703=== RUN TestReadProxyContentNegotiation704=== PAUSE TestReadProxyContentNegotiation705=== RUN TestReadProxyNarStreaming706=== PAUSE TestReadProxyNarStreaming707=== RUN TestReadProxy404708=== PAUSE TestReadProxy404709=== RUN TestReadProxyInvalidPath710=== PAUSE TestReadProxyInvalidPath711=== RUN TestReadProxyHead712=== PAUSE TestReadProxyHead713=== RUN TestReadProxyOutlastsServerWriteTimeout714=== PAUSE TestReadProxyOutlastsServerWriteTimeout715=== RUN TestReadProxyConditionalGet716=== PAUSE TestReadProxyConditionalGet717=== RUN TestReadProxyRootRedirectsToIndexHTML718=== PAUSE TestReadProxyRootRedirectsToIndexHTML719=== RUN TestReadProxyDisabled720=== PAUSE TestReadProxyDisabled721=== RUN TestReadRedirectNar722=== PAUSE TestReadRedirectNar723=== RUN TestReadRedirectKeepsNarinfoProxied724=== PAUSE TestReadRedirectKeepsNarinfoProxied725=== RUN TestReadProxyRangeRequest726=== PAUSE TestReadProxyRangeRequest727=== RUN TestReadRedirectUsesPublicS3URL728=== PAUSE TestReadRedirectUsesPublicS3URL729=== RUN TestPush_OverlappingRootsStoreOneRowPerKey730=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey731=== RUN TestPush_CompleteCommitsEveryRoot732=== PAUSE TestPush_CompleteCommitsEveryRoot733=== RUN TestPush_RepeatedRootCommitsOnce734=== PAUSE TestPush_RepeatedRootCommitsOnce735=== RUN TestPush_CompleteWaitsForCleanupOfThePush736=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush737=== RUN TestPush_RootsAreLockedInByteOrder738=== PAUSE TestPush_RootsAreLockedInByteOrder739=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit740=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit741=== RUN TestPush_RejectsBadRequests742=== PAUSE TestPush_RejectsBadRequests743=== RUN TestPush_SignsNarinfosOfItsPendingObjects744=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects745=== RUN TestRedundantMultipartUpload746=== PAUSE TestRedundantMultipartUpload747=== RUN TestCompleteMultipartUpload_ErrorButObjectExists748=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists749=== RUN TestCompletedNarNotReofferedAcrossClosures750=== PAUSE TestCompletedNarNotReofferedAcrossClosures751=== RUN TestPresignedUploadRegisteredBeforeCommit752=== PAUSE TestPresignedUploadRegisteredBeforeCommit753=== RUN TestService_Rustfstest754=== PAUSE TestService_Rustfstest755=== RUN TestParseSize756=== PAUSE TestParseSize757=== RUN TestSkippedUploadsHandler758=== PAUSE TestSkippedUploadsHandler759=== RUN TestSystemdListenerNotActivated760--- PASS: TestSystemdListenerNotActivated (0.00s)761=== RUN TestWatchdogBeatsWhenHealthy762--- PASS: TestWatchdogBeatsWhenHealthy (0.02s)763=== RUN TestWatchdogSkipsWhenUnhealthy7642026/10/25 16:08:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7652026/10/25 16:08:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7662026/10/25 16:08:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7672026/10/25 16:08:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7682026/10/25 16:08:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7692026/10/25 16:08:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7702026/10/25 16:08:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7712026/10/25 16:08:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7722026/10/25 16:08:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7732026/10/25 16:08:50 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"774--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)775=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle776=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle777=== RUN TestProxyWriteTimeout778=== PAUSE TestProxyWriteTimeout779=== RUN TestPendingClosureWriteTimeout780=== PAUSE TestPendingClosureWriteTimeout781=== RUN TestIsValidUploadKey782=== PAUSE TestIsValidUploadKey783=== RUN TestUploadHandlersRejectInvalidKeys784=== PAUSE TestUploadHandlersRejectInvalidKeys785=== RUN TestUploadHandlersRejectOversizedBody786=== PAUSE TestUploadHandlersRejectOversizedBody787=== RUN TestService_cleanupPendingClosuresHandler788=== PAUSE TestService_cleanupPendingClosuresHandler789=== RUN TestService_createPendingClosureHandler790=== PAUSE TestService_createPendingClosureHandler791=== RUN TestService_verifyS3Integrity792=== PAUSE TestService_verifyS3Integrity793=== RUN TestCompleteMultipartUnregistered794=== PAUSE TestCompleteMultipartUnregistered795=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT796=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT797=== CONT TestReadProxyNarinfoAlreadyDecompressed798=== CONT TestSweepSkipsRowsLockedByPush799=== CONT TestDeduplicatedObjectsRecordedAsPending800=== CONT TestPinProtectsFromGC801=== CONT TestGenerateLandingPage802=== CONT TestFailedS3DeleteKeepsTombstone803--- PASS: TestGenerateLandingPage (0.02s)804=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock805=== CONT TestLeadElectsOneAndHandsOver806=== CONT TestReadProxyNarinfo807=== CONT TestIsValidCachePath808=== RUN TestIsValidCachePath/narinfo809=== PAUSE TestIsValidCachePath/narinfo810=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars811=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars812=== RUN TestIsValidCachePath/nar_zst813=== PAUSE TestIsValidCachePath/nar_zst814=== RUN TestIsValidCachePath/nar_xz815=== PAUSE TestIsValidCachePath/nar_xz816=== RUN TestIsValidCachePath/nar_bz2817=== PAUSE TestIsValidCachePath/nar_bz2818=== RUN TestIsValidCachePath/nar_uncompressed819=== PAUSE TestIsValidCachePath/nar_uncompressed820=== RUN TestIsValidCachePath/ls821=== PAUSE TestIsValidCachePath/ls822=== RUN TestIsValidCachePath/log823=== PAUSE TestIsValidCachePath/log824=== RUN TestIsValidCachePath/realisation825=== PAUSE TestIsValidCachePath/realisation826=== RUN TestIsValidCachePath/nix-cache-info827=== PAUSE TestIsValidCachePath/nix-cache-info828=== RUN TestIsValidCachePath/index.html829=== PAUSE TestIsValidCachePath/index.html830=== RUN TestIsValidCachePath/traversal_parent831=== PAUSE TestIsValidCachePath/traversal_parent832=== RUN TestIsValidCachePath/traversal_in_middle833=== PAUSE TestIsValidCachePath/traversal_in_middle834=== RUN TestIsValidCachePath/invalid_char_e835=== PAUSE TestIsValidCachePath/invalid_char_e836=== RUN TestIsValidCachePath/invalid_char_u837=== PAUSE TestIsValidCachePath/invalid_char_u838=== RUN TestIsValidCachePath/random_path839=== PAUSE TestIsValidCachePath/random_path840=== RUN TestIsValidCachePath/empty841=== PAUSE TestIsValidCachePath/empty842=== RUN TestIsValidCachePath/leading_slash843=== PAUSE TestIsValidCachePath/leading_slash844=== CONT TestParseSingleRange845=== RUN TestParseSingleRange/none846=== PAUSE TestParseSingleRange/none847=== RUN TestParseSingleRange/unknown_unit848=== PAUSE TestParseSingleRange/unknown_unit849=== RUN TestParseSingleRange/multi-range_ignored850=== PAUSE TestParseSingleRange/multi-range_ignored851=== RUN TestParseSingleRange/malformed_no_dash852=== PAUSE TestParseSingleRange/malformed_no_dash853=== RUN TestParseSingleRange/malformed_both_empty854=== PAUSE TestParseSingleRange/malformed_both_empty855=== RUN TestParseSingleRange/malformed_end_before_start856=== PAUSE TestParseSingleRange/malformed_end_before_start857=== RUN TestParseSingleRange/closed858=== PAUSE TestParseSingleRange/closed859=== RUN TestParseSingleRange/open-ended860=== PAUSE TestParseSingleRange/open-ended861=== RUN TestParseSingleRange/end_clamped_to_size862=== PAUSE TestParseSingleRange/end_clamped_to_size863=== RUN TestParseSingleRange/suffix864=== PAUSE TestParseSingleRange/suffix865=== RUN TestParseSingleRange/suffix_exceeds_size866=== PAUSE TestParseSingleRange/suffix_exceeds_size867=== RUN TestParseSingleRange/single_byte868=== PAUSE TestParseSingleRange/single_byte869=== RUN TestParseSingleRange/start_past_EOF870=== PAUSE TestParseSingleRange/start_past_EOF871=== RUN TestParseSingleRange/start_far_past_EOF872=== PAUSE TestParseSingleRange/start_far_past_EOF873=== CONT TestPresentNotReportedWhileGCDeletesClosure874=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale875=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale876=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh877=== CONT TestConnectWaitsForAPeerMigration878=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh879=== CONT TestPresentRefreshesOnlyStaleClosures880=== CONT TestResolveDBConnectionString881=== CONT TestForceGCDuringPushOffersSweptObject882=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows883=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows884=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check885=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check886=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection887=== CONT TestGCSweepDeliversEachKeyOnce888=== CONT TestTombstonedObjectOfferedWithoutWaiting889=== RUN TestResolveDBConnectionString/flag_wins890=== PAUSE TestResolveDBConnectionString/flag_wins891=== RUN TestResolveDBConnectionString/file_when_flag_empty892=== PAUSE TestResolveDBConnectionString/file_when_flag_empty893=== RUN TestResolveDBConnectionString/missing_file_is_an_error894=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error895=== RUN TestResolveDBConnectionString/PGHOST_allows_empty896=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty897=== RUN TestResolveDBConnectionString/nothing_configured898=== PAUSE TestResolveDBConnectionString/nothing_configured899=== CONT TestDeleteClosuresRacingPins900=== CONT TestClientFallsBackToClosures901=== CONT TestGCSweepSkipsPendingObjects902=== CONT TestPushDedupSurvivesConcurrentGC903=== CONT TestGCMetrics904=== CONT TestGCBugBareHashReferences905=== CONT TestGCAdvisoryLockBlocksConcurrentRun906=== CONT TestLeadEndsOnShutdown907=== CONT TestLeadIncumbentAnnouncesAtOnce908=== CONT TestService_AuthMiddleware909=== RUN TestIsValidCachePath/wrong_extension910=== PAUSE TestIsValidCachePath/wrong_extension911=== RUN TestIsValidCachePath/short_hash912=== PAUSE TestIsValidCachePath/short_hash913=== CONT TestClientPushesUseOnePush9142026/10/25 16:08:52 INFO Received uploads request method=POST path=/api/pending_closures9152026/10/25 16:08:53 INFO Aborted multipart uploads count=0 kept=09162026/10/25 16:08:53 WARN Force mode enabled - objects will be deleted immediately without grace period9172026/10/25 16:08:53 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."9182026/10/25 16:08:53 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."919--- PASS: TestFailedS3DeleteKeepsTombstone (2.82s)920=== CONT TestCacheStatsHandler921--- PASS: TestReadProxyNarinfoAlreadyDecompressed (3.16s)922=== CONT TestCacheConfigHandler923=== RUN TestCacheConfigHandler/full_config,_no_issuer924=== PAUSE TestCacheConfigHandler/full_config,_no_issuer925=== RUN TestCacheConfigHandler/no_cache_url_configured926=== PAUSE TestCacheConfigHandler/no_cache_url_configured927=== RUN TestCacheConfigHandler/no_signing_keys928=== PAUSE TestCacheConfigHandler/no_signing_keys929=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator930=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator931=== CONT TestService_ReadScope_PublicByDefault9322026/10/25 16:08:54 INFO Aborted multipart uploads count=0 kept=09332026/10/25 16:08:54 WARN Force mode enabled - objects will be deleted immediately without grace period9342026/10/25 16:08:54 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=09352026/10/25 16:08:54 INFO Vacuumed table table=pending_closures9362026/10/25 16:08:54 INFO Vacuumed table table=pending_objects9372026/10/25 16:08:54 INFO Vacuumed table table=multipart_uploads9382026/10/25 16:08:54 INFO Vacuumed table table=closures9392026/10/25 16:08:54 INFO Vacuumed table table=objects940--- PASS: TestGCSweepDeliversEachKeyOnce (3.72s)941=== CONT TestClientSharedPathCommittedMidPush9422026/10/25 16:08:54 INFO Received uploads request method=POST path=/api/pending_closures943--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (3.96s)944=== CONT TestService_RequireScope_OIDC9452026/10/25 16:08:54 INFO Aborted multipart uploads count=0 kept=09462026/10/25 16:08:54 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=09472026/10/25 16:08:54 INFO Vacuumed table table=pending_closures9482026/10/25 16:08:54 INFO Vacuumed table table=pending_objects9492026/10/25 16:08:54 INFO Vacuumed table table=multipart_uploads9502026/10/25 16:08:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60875/oidc9512026/10/25 16:08:54 INFO Aborted multipart uploads count=0 kept=09522026/10/25 16:08:54 INFO Vacuumed table table=closures9532026/10/25 16:08:54 WARN Force mode enabled - objects will be deleted immediately without grace period9542026/10/25 16:08:54 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=09552026/10/25 16:08:54 INFO Vacuumed table table=pending_closures9562026/10/25 16:08:54 INFO Vacuumed table table=pending_objects9572026/10/25 16:08:54 INFO Vacuumed table table=objects9582026/10/25 16:08:54 INFO Vacuumed table table=multipart_uploads9592026/10/25 16:08:54 INFO Vacuumed table table=closures9602026/10/25 16:08:54 INFO Vacuumed table table=objects9612026/10/25 16:08:54 INFO Aborted multipart uploads count=0 kept=09622026/10/25 16:08:54 WARN Force mode enabled - objects will be deleted immediately without grace period9632026/10/25 16:08:54 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=09642026/10/25 16:08:54 INFO Aborted multipart uploads count=0 kept=09652026/10/25 16:08:54 WARN Force mode enabled - objects will be deleted immediately without grace period9662026/10/25 16:08:54 INFO Vacuumed table table=pending_closures9672026/10/25 16:08:54 INFO Vacuumed table table=pending_objects9682026/10/25 16:08:54 INFO Vacuumed table table=multipart_uploads9692026/10/25 16:08:54 INFO Vacuumed table table=closures9702026/10/25 16:08:54 INFO Vacuumed table table=objects9712026/10/25 16:08:54 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=09722026/10/25 16:08:54 INFO Vacuumed table table=pending_closures973--- PASS: TestPushDedupSurvivesConcurrentGC (4.17s)9742026/10/25 16:08:54 INFO Vacuumed table table=pending_objects975=== CONT TestClientWithDependencies9762026/10/25 16:08:54 INFO Vacuumed table table=multipart_uploads9772026/10/25 16:08:54 INFO Vacuumed table table=closures9782026/10/25 16:08:54 INFO lead: acquired remote=192.0.2.1:12349792026/10/25 16:08:54 INFO lead: released remote=192.0.2.1:1234980--- PASS: TestLeadIncumbentAnnouncesAtOnce (4.18s)981=== CONT TestService_AuthMiddleware_OIDC9822026/10/25 16:08:54 INFO Vacuumed table table=objects983--- PASS: TestSweepSkipsRowsLockedByPush (4.23s)984=== CONT TestClientMultipleUploads9852026/10/25 16:08:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60879/oidc9862026/10/25 16:08:54 INFO Aborted multipart uploads count=0 kept=09872026/10/25 16:08:54 WARN Force mode enabled - objects will be deleted immediately without grace period9882026/10/25 16:08:54 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=09892026/10/25 16:08:54 INFO Vacuumed table table=pending_closures9902026/10/25 16:08:54 INFO Vacuumed table table=pending_objects9912026/10/25 16:08:54 INFO Vacuumed table table=multipart_uploads9922026/10/25 16:08:54 INFO Vacuumed table table=closures9932026/10/25 16:08:54 INFO Vacuumed table table=objects994--- PASS: TestGCMetrics (4.43s)995=== CONT TestClientIntegration9962026/10/25 16:08:55 INFO lead: acquired remote=192.0.2.1:12349972026/10/25 16:08:55 INFO lead: acquired remote=192.0.2.1:1234998--- PASS: TestPresentRefreshesOnlyStaleClosures (5.01s)999=== CONT TestService_ReadAuthMiddleware10002026/10/25 16:08:55 INFO Received uploads request method=POST path=/api/pending_closures1001--- PASS: TestDeduplicatedObjectsRecordedAsPending (5.29s)1002=== CONT TestClientErrorHandling1003=== RUN TestClientErrorHandling/InvalidStorePath1004=== PAUSE TestClientErrorHandling/InvalidStorePath1005=== RUN TestClientErrorHandling/InvalidAuthToken1006=== PAUSE TestClientErrorHandling/InvalidAuthToken1007=== RUN TestClientErrorHandling/ServerNotAvailable1008=== PAUSE TestClientErrorHandling/ServerNotAvailable1009=== CONT TestClientCADerivations10102026/10/25 16:08:55 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld1 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1011--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (5.43s)1012=== CONT TestService_AuthMiddleware_MTLSBoundSubjects10132026/10/25 16:08:56 INFO lead: released remote=192.0.2.1:123410142026/10/25 16:08:56 INFO lead: acquired remote=192.0.2.1:123410152026/10/25 16:08:56 INFO lead: released remote=192.0.2.1:12341016--- PASS: TestLeadEndsOnShutdown (5.86s)1017=== CONT TestService_AuthMiddleware_MTLSProxyHeader1018=== NAME TestPinProtectsFromGC1019 client_integration_test.go:731: Pinned store path: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestPinProtectsFromGC2519105593/001/store/3xbkh87qxrcbmfkmfh2mdw7h6i1rkkgh-pinned-file.txt1020 client_integration_test.go:732: Unpinned store path: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestPinProtectsFromGC2519105593/001/store/2qpji1w9g1z0zkdwv8f82s3mq8b3naml-unpinned-file.txt10212026/10/25 16:08:57 INFO Received push request method=POST path=/api/pushes10222026/10/25 16:08:57 INFO lead: released remote=192.0.2.1:12341023--- PASS: TestLeadElectsOneAndHandsOver (6.97s)1024=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded10252026/10/25 16:08:57 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10262026/10/25 16:08:57 INFO Uploading 3xbkh87qxrcbmfkmfh2mdw7h6i1rkkgh-pinned-file.txt (128B)10272026/10/25 16:08:57 WARN Failed to register uploaded object key=3xbkh87qxrcbmfkmfh2mdw7h6i1rkkgh.ls error="server returned 404: 404 page not found\n"10282026/10/25 16:08:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10292026/10/25 16:08:57 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"10302026/10/25 16:08:57 INFO Signed narinfos id=1 count=110312026/10/25 16:08:57 INFO Uploading 1 narinfos10322026/10/25 16:08:57 INFO Received complete push request method=POST path=/api/pushes/1/complete10332026/10/25 16:08:57 WARN Failed to register uploaded object key=3xbkh87qxrcbmfkmfh2mdw7h6i1rkkgh.narinfo error="server returned 404: 404 page not found\n"10342026/10/25 16:08:57 INFO Completed push id=1 objects=3 duration=24.860125ms10352026/10/25 16:08:57 INFO Upload complete. (1.07s)10362026/10/25 16:08:57 INFO Received uploads request method=POST path=/api/pending_closures1037--- PASS: TestConnectWaitsForAPeerMigration (7.47s)1038=== CONT TestPresentReportsOnlyClosureRoots10392026/10/25 16:08:58 INFO Aborted multipart uploads count=0 kept=010402026/10/25 16:08:58 WARN Force mode enabled - objects will be deleted immediately without grace period10412026/10/25 16:08:58 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=010422026/10/25 16:08:58 INFO Received push request method=POST path=/api/pushes10432026/10/25 16:08:58 INFO Vacuumed table table=pending_closures10442026/10/25 16:08:58 INFO Vacuumed table table=pending_objects10452026/10/25 16:08:58 INFO Vacuumed table table=multipart_uploads10462026/10/25 16:08:58 INFO Vacuumed table table=closures10472026/10/25 16:08:58 INFO Vacuumed table table=objects10482026/10/25 16:08:58 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)10492026/10/25 16:08:58 INFO Uploading 6fw0l59kidvcj0zw12zidcgjxd592y3n-b (256B)10502026/10/25 16:08:58 INFO Uploading f32h1zmv0fhk69dyrp5wafir2hniq041-shared-dep (136B)1051--- PASS: TestGCSweepSkipsPendingObjects (8.23s)1052=== CONT TestGCTaskStore_ConflictDifferentParams1053--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1054=== CONT TestCreatePin_ReservedPins10552026/10/25 16:08:58 WARN Failed to register uploaded object key=0gwpp0mjmdmafws75pyh89c4288fkl7h.ls error="server returned 404: 404 page not found\n"10562026/10/25 16:08:58 INFO Received push request method=POST path=/api/pushes10572026/10/25 16:08:58 WARN Failed to register uploaded object key=nar/04w55sr6ncrxiapawb001as3bdk0cgyhjmn0yfkps66wpp7b8xbp.nar.zst error="server returned 404: 404 page not found\n"10582026/10/25 16:08:58 WARN Failed to register uploaded object key=f32h1zmv0fhk69dyrp5wafir2hniq041.ls error="server returned 404: 404 page not found\n"10592026/10/25 16:08:58 WARN Failed to register uploaded object key=6fw0l59kidvcj0zw12zidcgjxd592y3n.ls error="server returned 404: 404 page not found\n"10602026/10/25 16:08:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)10612026/10/25 16:08:58 INFO Uploading 2qpji1w9g1z0zkdwv8f82s3mq8b3naml-unpinned-file.txt (128B)10622026/10/25 16:08:58 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10632026/10/25 16:08:58 INFO Signed narinfos id=1 count=310642026/10/25 16:08:58 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"10652026/10/25 16:08:58 INFO Uploading 3 narinfos10662026/10/25 16:08:59 WARN Failed to register uploaded object key=2qpji1w9g1z0zkdwv8f82s3mq8b3naml.ls error="server returned 404: 404 page not found\n"10672026/10/25 16:08:59 WARN Failed to register uploaded object key=f32h1zmv0fhk69dyrp5wafir2hniq041.narinfo error="server returned 404: 404 page not found\n"10682026/10/25 16:08:59 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign10692026/10/25 16:08:59 INFO Signed narinfos id=2 count=110702026/10/25 16:08:59 WARN Failed to register uploaded object key=6fw0l59kidvcj0zw12zidcgjxd592y3n.narinfo error="server returned 404: 404 page not found\n"10712026/10/25 16:08:59 INFO Received complete push request method=POST path=/api/pushes/1/complete10722026/10/25 16:08:59 INFO Uploading 1 narinfos10732026/10/25 16:08:59 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"10742026/10/25 16:08:59 WARN Failed to register uploaded object key=0gwpp0mjmdmafws75pyh89c4288fkl7h.narinfo error="server returned 404: 404 page not found\n"10752026/10/25 16:08:59 INFO Completed push id=1 objects=8 duration=80.855583ms10762026/10/25 16:08:59 INFO Upload complete. (1.127s)1077=== NAME TestClientPushesUseOnePush1078 client_pushes_test.go:97: Retrieved narinfo from S3:1079 StorePath: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestClientPushesUseOnePush4113579921/001/store/f32h1zmv0fhk69dyrp5wafir2hniq041-shared-dep1080 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1081 Compression: zstd1082 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821083 NarSize: 1361084 References: 1085 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1086 client_pushes_test.go:97: Retrieved narinfo from S3:1087 StorePath: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestClientPushesUseOnePush4113579921/001/store/0gwpp0mjmdmafws75pyh89c4288fkl7h-a1088 URL: nar/04w55sr6ncrxiapawb001as3bdk0cgyhjmn0yfkps66wpp7b8xbp.nar.zst1089 Compression: zstd1090 NarHash: sha256:04w55sr6ncrxiapawb001as3bdk0cgyhjmn0yfkps66wpp7b8xbp1091 NarSize: 2561092 References: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestClientPushesUseOnePush4113579921/001/store/f32h1zmv0fhk69dyrp5wafir2hniq041-shared-dep1093 CA: text:sha256:1gnq2033zj1x63il1m90mpx6l10367f589v8z5dk93ns10ai8wyr10942026/10/25 16:08:59 INFO Received complete push request method=POST path=/api/pushes/2/complete10952026/10/25 16:08:59 WARN Failed to register uploaded object key=2qpji1w9g1z0zkdwv8f82s3mq8b3naml.narinfo error="server returned 404: 404 page not found\n"10962026/10/25 16:08:59 INFO Completed push id=2 objects=3 duration=7.9505ms10972026/10/25 16:08:59 INFO Upload complete. (1.038s)1098 client_pushes_test.go:97: Retrieved narinfo from S3:1099 StorePath: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestClientPushesUseOnePush4113579921/001/store/6fw0l59kidvcj0zw12zidcgjxd592y3n-b1100 URL: nar/04w55sr6ncrxiapawb001as3bdk0cgyhjmn0yfkps66wpp7b8xbp.nar.zst1101 Compression: zstd1102 NarHash: sha256:04w55sr6ncrxiapawb001as3bdk0cgyhjmn0yfkps66wpp7b8xbp1103 NarSize: 2561104 References: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestClientPushesUseOnePush4113579921/001/store/f32h1zmv0fhk69dyrp5wafir2hniq041-shared-dep1105 CA: text:sha256:1gnq2033zj1x63il1m90mpx6l10367f589v8z5dk93ns10ai8wyr1106--- PASS: TestClientPushesUseOnePush (8.84s)1107=== CONT TestService_readinessHandler11082026/10/25 16:08:59 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60933/oidc1109--- PASS: TestGCBugBareHashReferences (9.06s)1110=== CONT TestOrphanedObjectsGCStressTest11112026/10/25 16:08:59 INFO Starting cleanup of old closures method=DELETE path=/api/closures11122026/10/25 16:08:59 INFO Garbage collection started11132026/10/25 16:08:59 INFO Aborted multipart uploads count=0 kept=011142026/10/25 16:08:59 WARN Force mode enabled - objects will be deleted immediately without grace period11152026/10/25 16:08:59 INFO Received uploads request method=POST path=/api/pending_closures1116--- PASS: TestTombstonedObjectOfferedWithoutWaiting (9.56s)1117=== CONT TestService_healthCheckHandler11182026/10/25 16:09:00 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=011192026/10/25 16:09:00 INFO Vacuumed table table=pending_closures11202026/10/25 16:09:00 INFO Vacuumed table table=pending_objects11212026/10/25 16:09:00 INFO Vacuumed table table=multipart_uploads11222026/10/25 16:09:00 INFO Vacuumed table table=closures11232026/10/25 16:09:00 INFO Vacuumed table table=objects11242026/10/25 16:09:01 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"1125--- PASS: TestService_AuthMiddleware (10.91s)1126=== CONT TestOrphanedObjectsGC11272026/10/25 16:09:01 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=011282026/10/25 16:09:01 INFO Received create pin request method=POST path=/api/pins/myapp11292026/10/25 16:09:01 INFO Created/updated pin name=myapp store_path=/private/var/tb/1/scratch/39f8670b40371dc1/build/TestPinProtectsFromGC2519105593/001/store/3xbkh87qxrcbmfkmfh2mdw7h6i1rkkgh-pinned-file.txt narinfo_key=3xbkh87qxrcbmfkmfh2mdw7h6i1rkkgh.narinfo11302026/10/25 16:09:01 INFO Starting cleanup of old closures method=DELETE path=/api/closures11312026/10/25 16:09:01 INFO Garbage collection started11322026/10/25 16:09:01 INFO Aborted multipart uploads count=0 kept=011332026/10/25 16:09:02 WARN Force mode enabled - objects will be deleted immediately without grace period11342026/10/25 16:09: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=011352026/10/25 16:09:02 INFO Vacuumed table table=pending_closures11362026/10/25 16:09:02 INFO Vacuumed table table=pending_objects11372026/10/25 16:09:02 INFO Vacuumed table table=multipart_uploads11382026/10/25 16:09:02 INFO Vacuumed table table=closures11392026/10/25 16:09:02 INFO Vacuumed table table=objects11402026/10/25 16:09:02 INFO Received uploads request method=POST path=/api/pending_closures1141--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (12.09s)1142=== CONT TestGracefulShutdownDrainsInflight11432026/10/25 16:09:02 INFO Starting HTTP server address=127.0.0.1:6094711442026/10/25 16:09:02 INFO Shutdown signal received, draining in-flight requests timeout=10s1145--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1146=== CONT TestGCTaskStore_Fail1147--- PASS: TestGCTaskStore_Fail (0.00s)1148=== CONT TestGCTaskStore_PhaseUpdates1149--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1150=== CONT TestObjectStatsUpdatedOncePerCommit11512026/10/25 16:09:02 INFO Received uploads request method=POST path=/api/pending_closures11522026/10/25 16:09:02 INFO Received uploads request method=POST path=/api/pending_closures11532026/10/25 16:09:02 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)11542026/10/25 16:09:02 INFO Uploading jpi6i0hn6z0pzvs64wm64n8jg3vsrm4a-shared-dep (136B)11552026/10/25 16:09:02 INFO Uploading iiklzi5rr4bfhnkbxr2gbx0141jzdhjy-b (256B)11562026/10/25 16:09:03 WARN Failed to register uploaded object key=5ilgm68m21z5qf4cbfbfls2rf0zr73np.ls error="server returned 404: 404 page not found\n"11572026/10/25 16:09:03 WARN Failed to register uploaded object key=iiklzi5rr4bfhnkbxr2gbx0141jzdhjy.ls error="server returned 404: 404 page not found\n"11582026/10/25 16:09:03 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"11592026/10/25 16:09:03 WARN Failed to register uploaded object key=jpi6i0hn6z0pzvs64wm64n8jg3vsrm4a.ls error="server returned 404: 404 page not found\n"11602026/10/25 16:09:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign11612026/10/25 16:09:03 WARN Failed to register uploaded object key=nar/0hdp256rkhyykgkjm0q38nx58xdynpv18g3yfwb1mg5llbvxdwxn.nar.zst error="server returned 404: 404 page not found\n"11622026/10/25 16:09:03 INFO Signed narinfos id=1 count=211632026/10/25 16:09:03 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign11642026/10/25 16:09:03 INFO Signed narinfos id=2 count=211652026/10/25 16:09:03 INFO Uploading 4 narinfos11662026/10/25 16:09:03 WARN Failed to register uploaded object key=5ilgm68m21z5qf4cbfbfls2rf0zr73np.narinfo error="server returned 404: 404 page not found\n"11672026/10/25 16:09:03 WARN Failed to register uploaded object key=jpi6i0hn6z0pzvs64wm64n8jg3vsrm4a.narinfo error="server returned 404: 404 page not found\n"11682026/10/25 16:09:03 WARN Failed to register uploaded object key=iiklzi5rr4bfhnkbxr2gbx0141jzdhjy.narinfo error="server returned 404: 404 page not found\n"11692026/10/25 16:09:03 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11702026/10/25 16:09:03 WARN Failed to register uploaded object key=jpi6i0hn6z0pzvs64wm64n8jg3vsrm4a.narinfo error="server returned 404: 404 page not found\n"11712026/10/25 16:09:03 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>11722026/10/25 16:09:03 INFO Completed upload id=1 objects=6 duration=26.66075ms1173--- PASS: TestReadProxyNarinfo (12.96s)1174=== CONT TestObjectStatsTrigger11752026/10/25 16:09:03 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11762026/10/25 16:09:03 INFO Completed upload id=2 objects=6 duration=7.774458ms11772026/10/25 16:09:03 INFO Upload complete. (1.076s)1178=== NAME TestClientFallsBackToClosures1179 client_pushes_test.go:112: Retrieved narinfo from S3:1180 StorePath: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestClientFallsBackToClosures3566577451/001/store/jpi6i0hn6z0pzvs64wm64n8jg3vsrm4a-shared-dep1181 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1182 Compression: zstd1183 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821184 NarSize: 1361185 References: 1186 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1187 client_pushes_test.go:112: Retrieved narinfo from S3:1188 StorePath: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestClientFallsBackToClosures3566577451/001/store/5ilgm68m21z5qf4cbfbfls2rf0zr73np-a1189 URL: nar/0hdp256rkhyykgkjm0q38nx58xdynpv18g3yfwb1mg5llbvxdwxn.nar.zst1190 Compression: zstd1191 NarHash: sha256:0hdp256rkhyykgkjm0q38nx58xdynpv18g3yfwb1mg5llbvxdwxn1192 NarSize: 2561193 References: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestClientFallsBackToClosures3566577451/001/store/jpi6i0hn6z0pzvs64wm64n8jg3vsrm4a-shared-dep1194 CA: text:sha256:0x54q7h1hch16w35r6dhicg8aayi5cg724p8gliir9pm1scvlwg11195 client_pushes_test.go:112: Retrieved narinfo from S3:1196 StorePath: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestClientFallsBackToClosures3566577451/001/store/iiklzi5rr4bfhnkbxr2gbx0141jzdhjy-b1197 URL: nar/0hdp256rkhyykgkjm0q38nx58xdynpv18g3yfwb1mg5llbvxdwxn.nar.zst1198 Compression: zstd1199 NarHash: sha256:0hdp256rkhyykgkjm0q38nx58xdynpv18g3yfwb1mg5llbvxdwxn1200 NarSize: 2561201 References: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestClientFallsBackToClosures3566577451/001/store/jpi6i0hn6z0pzvs64wm64n8jg3vsrm4a-shared-dep1202 CA: text:sha256:0x54q7h1hch16w35r6dhicg8aayi5cg724p8gliir9pm1scvlwg11203--- PASS: TestClientFallsBackToClosures (13.09s)1204=== CONT TestGCTaskStore_CompletedAllowsNewTask1205--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1206=== CONT TestPendingCleanupUsesOneCutoff1207--- PASS: TestCacheStatsHandler (10.60s)1208=== CONT TestGCTaskStore_GetReturnsLatest1209--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1210=== CONT TestGCTaskStore_StartNew1211--- PASS: TestGCTaskStore_StartNew (0.00s)1212=== CONT TestCommitRacingPendingCleanupKeepsObjects1213=== NAME TestPinProtectsFromGC1214 client_integration_test.go:840: Pin successfully protected closure from garbage collection1215--- PASS: TestPinProtectsFromGC (13.53s)1216=== CONT TestGCTaskStore_GetEmpty1217--- PASS: TestGCTaskStore_GetEmpty (0.00s)1218=== CONT TestGCTaskStore_DeduplicateSameParams1219--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1220=== CONT TestGCEndsOnShutdown1221=== RUN TestGCEndsOnShutdown/before_the_run1222=== PAUSE TestGCEndsOnShutdown/before_the_run1223=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1224=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1225=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1226=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1227=== CONT TestSweepRechecksPendingAfterLocking1228--- PASS: TestDeleteClosuresRacingPins (13.54s)1229=== CONT TestPush_RejectsBadRequests1230--- PASS: TestService_ReadScope_PublicByDefault (10.84s)1231=== CONT TestPushWaitsForSweepHoldingRow1232=== RUN TestService_RequireScope_OIDC/builder_may_write1233=== PAUSE TestService_RequireScope_OIDC/builder_may_write1234=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1235=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1236=== RUN TestService_RequireScope_OIDC/ops_may_admin1237=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1238=== RUN TestService_RequireScope_OIDC/ops_may_not_write1239=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1240=== RUN TestService_RequireScope_OIDC/reader_may_not_write1241=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1242=== RUN TestService_RequireScope_OIDC/static_token_may_admin1243=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1244=== RUN TestService_RequireScope_OIDC/static_token_may_write1245=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1246=== RUN TestService_RequireScope_OIDC/reader_may_read1247=== PAUSE TestService_RequireScope_OIDC/reader_may_read1248=== RUN TestService_RequireScope_OIDC/writer_implies_read1249=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1250=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1251=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1252=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1253=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1254=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1255=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1256=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1257=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1258=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1259=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1260=== CONT TestMetricsCommit1261=== NAME TestClientMultipleUploads1262 client_integration_test.go:330: unexpected error: Put "http://localhost:60796/bucket31/": context deadline exceeded1263 1264--- FAIL: TestClientMultipleUploads (11.32s)1265=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT1266=== NAME TestClientWithDependencies1267 client_integration_test.go:597: unexpected error: context deadline exceeded1268 1269--- FAIL: TestClientWithDependencies (11.36s)1270=== CONT TestGetExistingObjectsLocksRows1271=== NAME TestService_AuthMiddleware_OIDC1272 auth_test.go:269: unexpected error: Put "http://localhost:60796/bucket33/": context deadline exceeded1273 1274--- FAIL: TestService_AuthMiddleware_OIDC (11.41s)1275=== CONT TestCompleteMultipartUnregistered1276=== NAME TestClientIntegration1277 client_integration_test.go:254: unexpected error: Put "http://localhost:60796/bucket34/": context deadline exceeded1278 1279--- FAIL: TestClientIntegration (11.22s)1280=== CONT TestMultipartCleanup12812026/10/25 16:09:06 INFO Received push request method=POST path=/api/pushes12822026/10/25 16:09:06 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)12832026/10/25 16:09:06 INFO Uploading kmzqymwwxbj77nr7y67mdgswzgvgj582-top (264B)12842026/10/25 16:09:06 INFO Uploading 342dmz9frfsdlmdwi3zyij28vplp3pww-shared-dep (136B)12852026/10/25 16:09:06 WARN Failed to register uploaded object key=kmzqymwwxbj77nr7y67mdgswzgvgj582.ls error="server returned 404: 404 page not found\n"12862026/10/25 16:09:06 WARN Failed to register uploaded object key=342dmz9frfsdlmdwi3zyij28vplp3pww.ls error="server returned 404: 404 page not found\n"12872026/10/25 16:09:06 WARN Failed to register uploaded object key=nar/1nzxls7866619cyql4qc2qgbxgbpca85liwnnigfv3l63rcr3x2b.nar.zst error="server returned 404: 404 page not found\n"12882026/10/25 16:09:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12892026/10/25 16:09:06 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"12902026/10/25 16:09:06 INFO Signed narinfos id=1 count=21291=== NAME TestService_ReadAuthMiddleware1292 auth_test.go:194: unexpected error: Put "http://localhost:60796/bucket35/": context deadline exceeded1293 1294--- FAIL: TestService_ReadAuthMiddleware (11.05s)1295=== CONT TestService_verifyS3Integrity12962026/10/25 16:09:06 INFO Uploading 2 narinfos1297=== NAME TestClientCADerivations1298 client_ca_test.go:118: unexpected error: Put "http://localhost:60796/bucket36/": context deadline exceeded1299 1300--- FAIL: TestClientCADerivations (10.86s)1301=== CONT TestServerTLSConfig1302=== RUN TestServerTLSConfig/no_client_CA1303=== PAUSE TestServerTLSConfig/no_client_CA1304=== RUN TestServerTLSConfig/missing_CA_file1305=== PAUSE TestServerTLSConfig/missing_CA_file1306=== RUN TestServerTLSConfig/not_a_PEM_file1307=== PAUSE TestServerTLSConfig/not_a_PEM_file1308=== CONT TestService_NativeMTLS1309=== NAME TestService_AuthMiddleware_MTLSBoundSubjects1310 auth_test.go:116: unexpected error: Put "http://localhost:60796/bucket37/": context deadline exceeded1311 1312--- FAIL: TestService_AuthMiddleware_MTLSBoundSubjects (10.75s)1313=== CONT TestService_createPendingClosureHandler13142026/10/25 16:09:06 WARN Failed to register uploaded object key=342dmz9frfsdlmdwi3zyij28vplp3pww.narinfo error="server returned 404: 404 page not found\n"1315=== NAME TestService_AuthMiddleware_MTLSProxyHeader1316 auth_test.go:55: unexpected error: Put "http://localhost:60796/bucket38/": context deadline exceeded1317 1318--- FAIL: TestService_AuthMiddleware_MTLSProxyHeader (10.39s)1319=== CONT TestService_cleanupPendingClosuresHandler13202026/10/25 16:09:06 INFO Received complete push request method=POST path=/api/pushes/1/complete13212026/10/25 16:09:06 WARN Failed to register uploaded object key=kmzqymwwxbj77nr7y67mdgswzgvgj582.narinfo error="server returned 404: 404 page not found\n"13222026/10/25 16:09:06 INFO Completed push id=1 objects=6 duration=59.750958ms13232026/10/25 16:09:06 INFO Upload complete. (903ms)1324=== NAME TestClientSharedPathCommittedMidPush1325 client_integration_test.go:680: Retrieved narinfo from S3:1326 StorePath: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestClientSharedPathCommittedMidPush3319483224/001/store/342dmz9frfsdlmdwi3zyij28vplp3pww-shared-dep1327 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1328 Compression: zstd1329 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821330 NarSize: 1361331 References: 1332 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1333 client_integration_test.go:680: Retrieved narinfo from S3:1334 StorePath: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestClientSharedPathCommittedMidPush3319483224/001/store/kmzqymwwxbj77nr7y67mdgswzgvgj582-top1335 URL: nar/1nzxls7866619cyql4qc2qgbxgbpca85liwnnigfv3l63rcr3x2b.nar.zst1336 Compression: zstd1337 NarHash: sha256:1nzxls7866619cyql4qc2qgbxgbpca85liwnnigfv3l63rcr3x2b1338 NarSize: 2641339 References: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestClientSharedPathCommittedMidPush3319483224/001/store/342dmz9frfsdlmdwi3zyij28vplp3pww-shared-dep1340 CA: text:sha256:0wrky5c5p8wlkjj7fwwpfzpd2gnvy64xvc9y4b2d1kqa6vx6cm8g1341--- PASS: TestClientSharedPathCommittedMidPush (12.79s)1342=== CONT TestReadRedirectNar13432026/10/25 16:09:07 INFO Received uploads request method=POST path=/api/pending_closures1344--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (10.59s)1345=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit1346=== NAME TestPresentReportsOnlyClosureRoots1347 present_test.go:19: unexpected error: Put "http://localhost:60796/bucket40/": context deadline exceeded1348 1349--- FAIL: TestPresentReportsOnlyClosureRoots (10.39s)1350=== CONT TestUploadHandlersRejectOversizedBody1351=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart1352=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart1353=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts1354=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts1355=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure1356=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure1357=== CONT TestPush_CompleteCommitsEveryRoot13582026/10/25 16:09:09 WARN readiness check failed error="closed pool"1359--- PASS: TestService_readinessHandler (9.70s)1360=== CONT TestUploadHandlersRejectInvalidKeys1361=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1362=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1363=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1364=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1365=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1366=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1367=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1368=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1369=== CONT TestPush_RootsAreLockedInByteOrder13702026/10/25 16:09:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13712026/10/25 16:09:09 WARN Refused reserved pin name=worker-x86_64-linux13722026/10/25 16:09:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux13732026/10/25 16:09:09 INFO Received create pin request method=POST path=/api/pins/my-app13742026/10/25 16:09:09 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1375--- PASS: TestCreatePin_ReservedPins (10.60s)1376=== CONT TestPush_OverlappingRootsStoreOneRowPerKey1377--- PASS: TestService_healthCheckHandler (9.92s)1378=== CONT TestIsValidUploadKey1379=== RUN TestIsValidUploadKey/narinfo1380=== PAUSE TestIsValidUploadKey/narinfo1381=== RUN TestIsValidUploadKey/nar_zst1382=== PAUSE TestIsValidUploadKey/nar_zst1383=== RUN TestIsValidUploadKey/nar_xz1384=== PAUSE TestIsValidUploadKey/nar_xz1385=== RUN TestIsValidUploadKey/nar_plain1386=== PAUSE TestIsValidUploadKey/nar_plain1387=== RUN TestIsValidUploadKey/listing1388=== PAUSE TestIsValidUploadKey/listing1389=== RUN TestIsValidUploadKey/build_log1390=== PAUSE TestIsValidUploadKey/build_log1391=== RUN TestIsValidUploadKey/build_log_home-manager_file1392=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1393=== RUN TestIsValidUploadKey/build_log_plus_in_name1394=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1395=== RUN TestIsValidUploadKey/build_log_question_mark1396=== PAUSE TestIsValidUploadKey/build_log_question_mark1397=== RUN TestIsValidUploadKey/build_log_equals1398=== PAUSE TestIsValidUploadKey/build_log_equals1399=== RUN TestIsValidUploadKey/realisation1400=== PAUSE TestIsValidUploadKey/realisation1401=== RUN TestIsValidUploadKey/realisation_plus_in_output1402=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1403=== RUN TestIsValidUploadKey/nix-cache-info1404=== PAUSE TestIsValidUploadKey/nix-cache-info1405=== RUN TestIsValidUploadKey/index.html1406=== PAUSE TestIsValidUploadKey/index.html1407=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1408=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1409=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1410=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1411=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1412=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1413=== RUN TestIsValidUploadKey/traversal1414=== PAUSE TestIsValidUploadKey/traversal1415=== RUN TestIsValidUploadKey/traversal_nar1416=== PAUSE TestIsValidUploadKey/traversal_nar1417=== RUN TestIsValidUploadKey/absolute1418=== PAUSE TestIsValidUploadKey/absolute1419=== RUN TestIsValidUploadKey/empty_key1420=== PAUSE TestIsValidUploadKey/empty_key1421=== RUN TestIsValidUploadKey/unknown_type1422=== PAUSE TestIsValidUploadKey/unknown_type1423=== CONT TestPush_CompleteWaitsForCleanupOfThePush1424--- PASS: TestObjectStatsUpdatedOncePerCommit (8.01s)1425=== CONT TestPendingClosureWriteTimeout1426=== RUN TestPendingClosureWriteTimeout/empty1427=== PAUSE TestPendingClosureWriteTimeout/empty1428=== RUN TestPendingClosureWriteTimeout/400_objects1429=== PAUSE TestPendingClosureWriteTimeout/400_objects1430=== RUN TestPendingClosureWriteTimeout/670k_objects1431=== PAUSE TestPendingClosureWriteTimeout/670k_objects1432=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1433=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1434=== CONT TestReadRedirectUsesPublicS3URL14352026/10/25 16:09:10 INFO Received uploads request method=POST path=/api/pending_closures14362026/10/25 16:09:10 INFO Received uploads request method=POST path=/api/pending_closures14372026/10/25 16:09:10 INFO Received cleanup request method=DELETE path=/api/pending_closures1438--- PASS: TestObjectStatsTrigger (7.81s)1439=== CONT TestPush_RepeatedRootCommitsOnce1440=== NAME TestOrphanedObjectsGC1441 orphaned_objects_gc_test.go:287: GC Test Summary:1442 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1443 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1444 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1445 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1446 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1447--- PASS: TestOrphanedObjectsGC (10.00s)1448=== CONT TestProxyWriteTimeout1449=== RUN TestProxyWriteTimeout/narinfo1450=== PAUSE TestProxyWriteTimeout/narinfo1451=== RUN TestProxyWriteTimeout/1_GiB_nar1452=== PAUSE TestProxyWriteTimeout/1_GiB_nar1453=== RUN TestProxyWriteTimeout/10_GiB_nar1454=== PAUSE TestProxyWriteTimeout/10_GiB_nar1455=== RUN TestProxyWriteTimeout/unknown_size1456=== PAUSE TestProxyWriteTimeout/unknown_size1457=== CONT TestReadProxyRangeRequest14582026/10/25 16:09:11 INFO Aborted multipart uploads count=0 kept=014592026/10/25 16:09:11 WARN Force mode enabled - objects will be deleted immediately without grace period14602026/10/25 16:09:11 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=014612026/10/25 16:09:11 INFO Vacuumed table table=pending_closures14622026/10/25 16:09:11 INFO Vacuumed table table=pending_objects14632026/10/25 16:09:11 INFO Vacuumed table table=multipart_uploads1464=== RUN TestPush_RejectsBadRequests/no_objects1465=== PAUSE TestPush_RejectsBadRequests/no_objects1466=== RUN TestPush_RejectsBadRequests/bad_root1467=== PAUSE TestPush_RejectsBadRequests/bad_root1468=== RUN TestPush_RejectsBadRequests/root_not_in_objects1469=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1470=== RUN TestPush_RejectsBadRequests/no_roots1471=== PAUSE TestPush_RejectsBadRequests/no_roots1472=== CONT TestRegisterCompletedObjectNeedsPendingRow14732026/10/25 16:09:11 INFO Vacuumed table table=closures14742026/10/25 16:09:11 INFO Vacuumed table table=objects1475--- PASS: TestCommitRacingPendingCleanupKeepsObjects (8.01s)1476=== CONT TestReadRedirectKeepsNarinfoProxied14772026/10/25 16:09:12 INFO Aborted multipart uploads count=0 kept=014782026/10/25 16:09:12 WARN Force mode enabled - objects will be deleted immediately without grace period14792026/10/25 16:09:12 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=014802026/10/25 16:09:12 INFO Vacuumed table table=pending_closures14812026/10/25 16:09:12 INFO Vacuumed table table=pending_objects14822026/10/25 16:09:12 INFO Vacuumed table table=multipart_uploads14832026/10/25 16:09:12 INFO Vacuumed table table=closures14842026/10/25 16:09:12 INFO Vacuumed table table=objects1485--- PASS: TestSweepRechecksPendingAfterLocking (8.63s)1486=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle14872026/10/25 16:09:12 INFO Received uploads request method=POST path=/api/pending_closures14882026/10/25 16:09:13 INFO Received push request method=POST path=/api/pushes14892026/10/25 16:09:13 INFO Received complete push request method=POST path=/api/pushes/1/complete14902026/10/25 16:09:13 INFO Completed push id=1 objects=4 duration=26.336708ms14912026/10/25 16:09:13 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14922026/10/25 16:09:13 INFO Completed upload id=2 objects=2 duration=1.846542ms1493--- PASS: TestMetricsCommit (7.45s)1494--- PASS: TestPushWaitsForSweepHoldingRow (8.73s)1495=== CONT TestReadProxyHead1496=== CONT TestReadProxyRootRedirectsToIndexHTML1497--- PASS: TestGetExistingObjectsLocksRows (7.46s)1498=== CONT TestReadProxyDisabled14992026/10/25 16:09:13 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15002026/10/25 16:09:13 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1501--- PASS: TestCompleteMultipartUnregistered (7.71s)1502=== CONT TestSkippedUploadsHandler15032026/10/25 16:09:13 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001504--- PASS: TestSkippedUploadsHandler (0.00s)1505=== CONT TestReadProxyConditionalGet15062026/10/25 16:09:14 INFO Received uploads request method=POST path=/api/pending_closures1507--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (8.33s)1508=== CONT TestNARDeduplicationMetadataUploadBug15092026/10/25 16:09:14 INFO Received uploads request method=POST path=/api/pending_closures15102026/10/25 16:09:14 INFO Received cleanup request method=DELETE path=/api/pending_closures15112026/10/25 16:09:14 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket57/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""15122026/10/25 16:09:14 INFO Aborted multipart uploads count=0 kept=115132026/10/25 16:09:14 INFO Received cleanup request method=DELETE path=/api/pending_closures15142026/10/25 16:09:14 INFO Aborted multipart uploads count=1 kept=01515--- PASS: TestMultipartCleanup (8.74s)1516=== CONT TestReadProxyOutlastsServerWriteTimeout15172026/10/25 16:09:15 INFO Received uploads request method=POST path=/api/pending_closures15182026/10/25 16:09:15 INFO Received uploads request method=POST path=/api/pending_closures15192026/10/25 16:09:15 INFO Received uploads request method=POST path=/api/pending_closures15202026/10/25 16:09:15 INFO Received cleanup request method=DELETE path=/api/pending_closures15212026/10/25 16:09:15 INFO Aborted multipart uploads count=0 kept=015222026/10/25 16:09:15 INFO Received uploads request method=POST path=/api/pending_closures15232026/10/25 16:09:15 INFO Received cleanup request method=DELETE path=/api/pending_closures15242026/10/25 16:09:15 INFO Aborted multipart uploads count=1 kept=015252026/10/25 16:09:15 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15262026-10-25 16:09:15.589 UTC [30247] ERROR: Closure does not exist: id=115272026-10-25 16:09:15.589 UTC [30247] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE15282026-10-25 16:09:15.589 UTC [30247] STATEMENT: -- name: CommitPendingClosure :one1529 SELECT commit_pending_closure($1::bigint)::bigint1530 1531--- PASS: TestService_cleanupPendingClosuresHandler (8.78s)1532=== CONT TestMetricsInventory15332026/10/25 16:09:15 INFO Received uploads request method=POST path=/api/pending_closures15342026/10/25 16:09:16 WARN mTLS auth: subject not in bound subjects subject="CN=reader"15352026/10/25 16:09:16 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1536--- PASS: TestService_NativeMTLS (9.66s)1537=== CONT TestCompleteMultipartUpload_ErrorButObjectExists1538--- PASS: TestReadRedirectNar (9.83s)1539=== CONT TestRedundantMultipartUpload15402026/10/25 16:09:17 INFO Aborted multipart uploads count=1 kept=015412026/10/25 16:09:17 INFO Received cleanup request method=DELETE path=/api/pending_closures15422026/10/25 16:09:17 INFO Aborted multipart uploads count=1 kept=01543--- PASS: TestPendingCleanupUsesOneCutoff (13.43s)1544=== CONT TestPush_SignsNarinfosOfItsPendingObjects15452026/10/25 16:09:17 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15462026/10/25 16:09:17 INFO Received push request method=POST path=/api/pushes15472026/10/25 16:09:17 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MjdkNjQ2MGEtZjAyZi00OGE5LWI2OTctZDcyYTYwNTU1MTA3LjI5MmVmMTdmLTM5YjQtNGY1MS05ZGNlLTViNzMxYzBmMzE4OHgxNzkyOTQ0NTU1MDk4MDkwMDAw parts=1015482026/10/25 16:09:17 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15492026/10/25 16:09:17 INFO Completed upload id=1 objects=2 duration=24.65975ms15502026/10/25 16:09:17 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000015512026/10/25 16:09:17 INFO Received uploads request method=POST path=/api/pending_closures15522026/10/25 16:09:17 INFO Received complete push request method=POST path=/api/pushes/1/complete15532026/10/25 16:09:17 INFO Starting cleanup of old closures method=DELETE path=/api/closures15542026/10/25 16:09:17 INFO Completed push id=1 objects=4 duration=55.253042ms15552026/10/25 16:09:17 INFO Received push request method=POST path=/api/pushes15562026/10/25 16:09:17 INFO Aborted multipart uploads count=0 kept=015572026/10/25 16:09:17 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=015582026/10/25 16:09:17 INFO Vacuumed table table=pending_closures15592026/10/25 16:09:17 INFO Vacuumed table table=pending_objects15602026/10/25 16:09:17 INFO Aborted multipart uploads count=0 kept=015612026/10/25 16:09:17 WARN Force mode enabled - objects will be deleted immediately without grace period15622026/10/25 16:09:17 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=015632026/10/25 16:09:17 INFO Vacuumed table table=multipart_uploads15642026/10/25 16:09:17 INFO Received push request method=POST path=/api/pushes15652026/10/25 16:09:17 INFO Vacuumed table table=closures15662026/10/25 16:09:17 INFO Vacuumed table table=pending_closures15672026/10/25 16:09:17 INFO Vacuumed table table=objects15682026/10/25 16:09:17 INFO Vacuumed table table=pending_objects15692026/10/25 16:09:17 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001570--- PASS: TestService_createPendingClosureHandler (11.22s)1571=== CONT TestReadProxy40415722026/10/25 16:09:17 INFO Vacuumed table table=multipart_uploads15732026/10/25 16:09:18 INFO Received complete push request method=POST path=/api/pushes/1/complete15742026/10/25 16:09:18 INFO Vacuumed table table=closures15752026/10/25 16:09:18 INFO Completed push id=1 objects=6 duration=53.728708ms15762026/10/25 16:09:18 INFO Vacuumed table table=objects1577--- PASS: TestPush_CompleteCommitsEveryRoot (9.66s)15782026/10/25 16:09:18 INFO Received complete push request method=POST path=/api/pushes/2/complete1579=== CONT TestReadProxyInvalidPath15802026/10/25 16:09:18 INFO Completed push id=2 objects=4 duration=8.317458ms1581--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (10.08s)1582=== CONT TestService_Rustfstest15832026/10/25 16:09:18 INFO Received complete multipart upload request method=POST path=/api/multipart/complete15842026/10/25 16:09:18 INFO Received push request method=POST path=/api/pushes15852026/10/25 16:09:18 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MjdkNjQ2MGEtZjAyZi00OGE5LWI2OTctZDcyYTYwNTU1MTA3LjAxM2VkYmIwLWE3ZmQtNDJkZC1hMmEyLWEwNmNhODY5NmY0M3gxNzkyOTQ0NTU1ODY1NzUxMDAw parts=1015862026/10/25 16:09:18 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15872026/10/25 16:09:18 INFO Completed upload id=1 objects=2 duration=49.54525ms15882026/10/25 16:09:18 INFO Received uploads request method=POST path=/api/pending_closures15892026/10/25 16:09:18 INFO Received uploads request method=POST path=/api/pending_closures15902026/10/25 16:09:18 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo15912026/10/25 16:09:18 WARN Found objects in DB but missing from S3, will re-upload count=11592--- PASS: TestService_verifyS3Integrity (11.94s)1593=== CONT TestParseSize1594--- PASS: TestParseSize (0.00s)1595=== CONT TestPresignedUploadRegisteredBeforeCommit15962026-10-25 16:09:18.726 UTC [31475] ERROR: could not obtain lock on row in relation "closures"15972026-10-25 16:09:18.726 UTC [31475] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT15982026-10-25 16:09:18.731 UTC [31475] ERROR: could not obtain lock on row in relation "closures"15992026-10-25 16:09:18.731 UTC [31475] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT16002026-10-25 16:09:18.738 UTC [31475] ERROR: could not obtain lock on row in relation "closures"16012026-10-25 16:09:18.738 UTC [31475] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT16022026-10-25 16:09:18.744 UTC [31475] ERROR: could not obtain lock on row in relation "closures"16032026-10-25 16:09:18.744 UTC [31475] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT16042026-10-25 16:09:18.749 UTC [31475] ERROR: could not obtain lock on row in relation "closures"16052026-10-25 16:09:18.749 UTC [31475] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1606--- PASS: TestPush_RootsAreLockedInByteOrder (9.69s)1607=== CONT TestReadProxyNarStreaming16082026/10/25 16:09:18 INFO Received push request method=POST path=/api/pushes1609--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (9.70s)1610=== CONT TestCreatePendingClosureRejectsOversizedNAR16112026/10/25 16:09:19 INFO Received uploads request method=POST path=/api/pending_closures1612--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1613=== CONT TestCacheConfigHandlerMaxNarSize1614--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1615=== CONT TestReadProxyContentNegotiation16162026/10/25 16:09:19 INFO Received push request method=POST path=/api/pushes16172026-10-25 16:09:19.812 UTC [31500] ERROR: Push does not exist: id=116182026-10-25 16:09:19.812 UTC [31500] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE16192026-10-25 16:09:19.812 UTC [31500] STATEMENT: SELECT commit_push($1)1620--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (9.78s)1621=== CONT TestCompletedNarNotReofferedAcrossClosures1622--- PASS: TestReadRedirectUsesPublicS3URL (9.10s)1623=== CONT TestParseSingleRange/none1624=== CONT TestParseSingleRange/open-ended1625=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1626--- PASS: TestReadProxyRangeRequest (8.82s)1627=== CONT TestParseSingleRange/multi-range_ignored1628=== CONT TestParseSingleRange/unknown_unit1629=== CONT TestParseSingleRange/start_far_past_EOF1630=== CONT TestParseSingleRange/start_past_EOF1631=== CONT TestParseSingleRange/single_byte1632=== CONT TestParseSingleRange/suffix_exceeds_size1633=== CONT TestParseSingleRange/suffix1634=== CONT TestParseSingleRange/end_clamped_to_size1635=== CONT TestParseSingleRange/malformed_no_dash1636=== CONT TestParseSingleRange/closed1637=== CONT TestParseSingleRange/malformed_end_before_start1638=== CONT TestParseSingleRange/malformed_both_empty1639--- PASS: TestParseSingleRange (0.00s)1640 --- PASS: TestParseSingleRange/none (0.00s)1641 --- PASS: TestParseSingleRange/open-ended (0.00s)1642 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1643 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1644 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1645 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1646 --- PASS: TestParseSingleRange/single_byte (0.00s)1647 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1648 --- PASS: TestParseSingleRange/suffix (0.00s)1649 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1650 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1651 --- PASS: TestParseSingleRange/closed (0.00s)1652 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1653 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1654=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh16552026/10/25 16:09:20 INFO Received push request method=POST path=/api/pushes16562026/10/25 16:09:20 INFO Received complete push request method=POST path=/api/pushes/1/complete16572026/10/25 16:09:20 INFO Completed push id=1 objects=4 duration=48.50075ms1658--- PASS: TestPush_RepeatedRootCommitsOnce (9.57s)1659=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1660--- PASS: TestReadRedirectKeepsNarinfoProxied (9.18s)1661=== CONT TestResolveDBConnectionString/flag_wins1662=== CONT TestResolveDBConnectionString/nothing_configured1663=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1664=== CONT TestResolveDBConnectionString/missing_file_is_an_error1665=== CONT TestResolveDBConnectionString/file_when_flag_empty1666=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1667--- PASS: TestResolveDBConnectionString (0.02s)1668 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1669 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1670 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1671 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1672 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1673--- PASS: TestRegisterCompletedObjectNeedsPendingRow (9.72s)1674=== CONT TestIsValidCachePath/narinfo1675=== CONT TestIsValidCachePath/short_hash1676=== CONT TestIsValidCachePath/wrong_extension1677=== CONT TestIsValidCachePath/leading_slash1678=== CONT TestIsValidCachePath/empty1679=== CONT TestIsValidCachePath/random_path1680=== CONT TestIsValidCachePath/invalid_char_u1681=== CONT TestIsValidCachePath/invalid_char_e1682=== CONT TestIsValidCachePath/traversal_in_middle1683=== CONT TestIsValidCachePath/traversal_parent1684=== CONT TestIsValidCachePath/index.html1685=== CONT TestIsValidCachePath/nix-cache-info1686=== CONT TestIsValidCachePath/realisation1687=== CONT TestIsValidCachePath/log1688=== CONT TestIsValidCachePath/ls1689=== CONT TestIsValidCachePath/nar_uncompressed1690=== CONT TestIsValidCachePath/nar_bz21691=== CONT TestIsValidCachePath/nar_xz1692=== CONT TestIsValidCachePath/nar_zst1693=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1694--- PASS: TestIsValidCachePath (0.01s)1695 --- PASS: TestIsValidCachePath/narinfo (0.00s)1696 --- PASS: TestIsValidCachePath/short_hash (0.00s)1697 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1698 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1699 --- PASS: TestIsValidCachePath/empty (0.00s)1700 --- PASS: TestIsValidCachePath/random_path (0.00s)1701 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1702 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1703 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1704 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1705 --- PASS: TestIsValidCachePath/index.html (0.00s)1706 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1707 --- PASS: TestIsValidCachePath/realisation (0.00s)1708 --- PASS: TestIsValidCachePath/log (0.00s)1709 --- PASS: TestIsValidCachePath/ls (0.00s)1710 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1711 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1712 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1713 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1714 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1715=== CONT TestCacheConfigHandler/full_config,_no_issuer1716=== CONT TestCacheConfigHandler/no_signing_keys1717=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1718=== CONT TestCacheConfigHandler/no_cache_url_configured1719=== CONT TestClientErrorHandling/InvalidStorePath1720--- PASS: TestCacheConfigHandler (0.00s)1721 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)1722 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)1723 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)1724 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)17252026/10/25 16:09:22 INFO Received uploads request method=POST path=/api/pending_closures1726--- PASS: TestReadProxyHead (9.39s)1727=== CONT TestClientErrorHandling/ServerNotAvailable17282026/10/25 16:09:22 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1729--- PASS: TestReadProxyRootRedirectsToIndexHTML (9.88s)1730=== CONT TestClientErrorHandling/InvalidAuthToken17312026/10/25 16:09:23 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17322026/10/25 16:09:23 WARN Request failed, retrying attempt=2 backoff=190.599666ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1733--- PASS: TestReadProxyDisabled (9.96s)1734=== CONT TestGCEndsOnShutdown/before_the_run17352026/10/25 16:09:23 WARN Request failed, retrying attempt=3 backoff=408.757919ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present17362026/10/25 16:09:23 WARN Request failed, retrying attempt=4 backoff=879.645166ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1737--- PASS: TestReadProxyConditionalGet (10.13s)1738=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17392026/10/25 16:09:24 WARN Request failed, retrying attempt=5 backoff=1.513786899s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1740=== NAME TestNARDeduplicationMetadataUploadBug1741 metadata_upload_test.go:48: First store path: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestNARDeduplicationMetadataUploadBug3891473999/001/store/hn9cxvjvf1yz3vz20v7bzc96iq55xnjp-file1.txt17422026/10/25 16:09:25 INFO Received push request method=POST path=/api/pushes17432026/10/25 16:09:25 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17442026/10/25 16:09:25 INFO Uploading hn9cxvjvf1yz3vz20v7bzc96iq55xnjp-file1.txt (160B)17452026/10/25 16:09:25 WARN Failed to register uploaded object key=hn9cxvjvf1yz3vz20v7bzc96iq55xnjp.ls error="server returned 404: 404 page not found\n"17462026/10/25 16:09:25 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17472026/10/25 16:09:25 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"17482026/10/25 16:09:25 INFO Signed narinfos id=1 count=117492026/10/25 16:09:25 INFO Uploading 1 narinfos1750--- PASS: TestMetricsInventory (9.78s)1751=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17522026/10/25 16:09:25 INFO Received complete push request method=POST path=/api/pushes/1/complete17532026/10/25 16:09:25 WARN Failed to register uploaded object key=hn9cxvjvf1yz3vz20v7bzc96iq55xnjp.narinfo error="server returned 404: 404 page not found\n"17542026/10/25 16:09:25 INFO Completed push id=1 objects=3 duration=23.249916ms17552026/10/25 16:09:25 INFO Upload complete. (352ms)1756=== NAME TestNARDeduplicationMetadataUploadBug1757 metadata_upload_test.go:54: Retrieved narinfo from S3:1758 StorePath: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestNARDeduplicationMetadataUploadBug3891473999/001/store/hn9cxvjvf1yz3vz20v7bzc96iq55xnjp-file1.txt1759 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1760 Compression: zstd1761 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1762 NarSize: 1601763 References: 1764 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1765 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1766 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1767 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1768=== NAME TestOrphanedObjectsGCStressTest1769 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1770 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1771=== NAME TestNARDeduplicationMetadataUploadBug1772 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/1/scratch/39f8670b40371dc1/build/TestNARDeduplicationMetadataUploadBug3891473999/001/store/n0rxzpjk1rdr9kj4ch77mxh3y3brdrnr-file2.txt17732026/10/25 16:09:25 INFO Received uploads request method=POST path=/api/pending_closures17742026/10/25 16:09:25 INFO Received push request method=POST path=/api/pushes17752026/10/25 16:09:25 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)17762026/10/25 16:09:26 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17772026/10/25 16:09:26 INFO Signed narinfos id=2 count=117782026/10/25 16:09:26 INFO Uploading 1 narinfos17792026/10/25 16:09:26 WARN Failed to register uploaded object key=n0rxzpjk1rdr9kj4ch77mxh3y3brdrnr.ls error="server returned 404: 404 page not found\n"17802026/10/25 16:09:26 INFO Received uploads request method=POST path=/api/pending_closures17812026/10/25 16:09:26 INFO Received complete push request method=POST path=/api/pushes/2/complete17822026/10/25 16:09:26 WARN Failed to register uploaded object key=n0rxzpjk1rdr9kj4ch77mxh3y3brdrnr.narinfo error="server returned 404: 404 page not found\n"17832026/10/25 16:09:26 INFO Completed push id=2 objects=3 duration=17.481625ms17842026/10/25 16:09:26 INFO Upload complete. (551ms)1785 metadata_upload_test.go:76: Retrieved narinfo from S3:1786 StorePath: /private/var/tb/1/scratch/39f8670b40371dc1/build/TestNARDeduplicationMetadataUploadBug3891473999/001/store/n0rxzpjk1rdr9kj4ch77mxh3y3brdrnr-file2.txt1787 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1788 Compression: zstd1789 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1790 NarSize: 1601791 References: 1792 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1793 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1794 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1795 {"version":1,"root":{"type":"regular","size":44}}1796--- PASS: TestNARDeduplicationMetadataUploadBug (11.92s)1797=== CONT TestService_RequireScope_OIDC/builder_may_write17982026/10/25 16:09:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1799=== CONT TestService_RequireScope_OIDC/reader_may_read1800=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1801=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read18022026/10/25 16:09:26 WARN Authentication failed token_preview=wrong token_length=5 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]1803=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1804=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc1805=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read1806=== CONT TestService_RequireScope_OIDC/writer_implies_read1807=== CONT TestService_RequireScope_OIDC/reader_may_not_write1808=== CONT TestService_RequireScope_OIDC/ops_may_admin1809=== CONT TestService_RequireScope_OIDC/ops_may_not_write1810=== CONT TestService_RequireScope_OIDC/builder_may_not_admin1811=== CONT TestService_RequireScope_OIDC/static_token_may_admin1812=== CONT TestService_RequireScope_OIDC/static_token_may_write1813=== CONT TestServerTLSConfig/no_client_CA1814=== CONT TestServerTLSConfig/not_a_PEM_file1815--- PASS: TestService_RequireScope_OIDC (11.29s)1816 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.01s)1817 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)1818 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)1819 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)1820 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)1821 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)1822 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)1823 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)1824 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)1825 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)1826 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)1827 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)1828 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)1829 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)1830=== CONT TestServerTLSConfig/missing_CA_file1831--- PASS: TestServerTLSConfig (0.00s)1832 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1833 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.00s)1834 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1835=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18362026/10/25 16:09:26 INFO Received complete multipart upload request method=POST path=/1837=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18382026/10/25 16:09:26 INFO Received uploads request method=POST path=/18392026/10/25 16:09:26 INFO Received uploads request method=POST path=/api/pending_closures18402026/10/25 16:09:26 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjdkNjQ2MGEtZjAyZi00OGE5LWI2OTctZDcyYTYwNTU1MTA3LjZmNzUwYTVhLTEwOTAtNDNiYi05NzMwLTI2M2U0MTMxMmIxZHgxNzkyOTQ0NTY1NjkyOTQyMDAw18412026/10/25 16:09:26 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MjdkNjQ2MGEtZjAyZi00OGE5LWI2OTctZDcyYTYwNTU1MTA3LjZmNzUwYTVhLTEwOTAtNDNiYi05NzMwLTI2M2U0MTMxMmIxZHgxNzkyOTQ0NTY1NjkyOTQyMDAw parts=11842--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (10.27s)1843=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18442026/10/25 16:09:26 INFO Received request for more parts method=POST path=/1845=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18462026/10/25 16:09:26 INFO Received uploads request method=POST path=/1847=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18482026/10/25 16:09:26 INFO Received complete multipart upload request method=POST path=/1849=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18502026/10/25 16:09:26 INFO Received request for more parts method=POST path=/1851=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18522026/10/25 16:09:26 INFO Received uploads request method=POST path=/1853--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1854 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1855 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1856 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1857 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1858=== CONT TestIsValidUploadKey/narinfo1859=== CONT TestIsValidUploadKey/realisation_plus_in_output1860=== CONT TestIsValidUploadKey/unknown_type1861=== CONT TestIsValidUploadKey/empty_key1862=== CONT TestIsValidUploadKey/absolute1863=== CONT TestIsValidUploadKey/traversal_nar1864=== CONT TestIsValidUploadKey/traversal1865=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1866=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1867=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1868=== CONT TestIsValidUploadKey/index.html1869=== CONT TestIsValidUploadKey/nix-cache-info1870=== CONT TestIsValidUploadKey/build_log_home-manager_file1871=== CONT TestIsValidUploadKey/realisation1872=== CONT TestIsValidUploadKey/build_log_equals1873=== CONT TestIsValidUploadKey/build_log_question_mark1874=== CONT TestIsValidUploadKey/build_log_plus_in_name1875=== CONT TestIsValidUploadKey/nar_xz1876=== CONT TestIsValidUploadKey/nar_zst1877=== CONT TestIsValidUploadKey/build_log1878=== CONT TestIsValidUploadKey/listing1879=== CONT TestIsValidUploadKey/nar_plain1880--- PASS: TestIsValidUploadKey (0.01s)1881 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1882 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1883 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1884 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1885 --- PASS: TestIsValidUploadKey/absolute (0.00s)1886 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1887 --- PASS: TestIsValidUploadKey/traversal (0.00s)1888 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1889 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1890 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1891 --- PASS: TestIsValidUploadKey/index.html (0.00s)1892 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1893 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1894 --- PASS: TestIsValidUploadKey/realisation (0.00s)1895 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1896 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1897 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1898 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1899 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1900 --- PASS: TestIsValidUploadKey/build_log (0.00s)1901 --- PASS: TestIsValidUploadKey/listing (0.00s)1902 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1903=== CONT TestPendingClosureWriteTimeout/empty1904=== CONT TestPendingClosureWriteTimeout/670k_objects1905=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline19062026/10/25 16:09:26 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19072026/10/25 16:09:26 INFO Received push request method=POST path=/api/pushes19082026/10/25 16:09:26 WARN Request failed, retrying attempt=2 backoff=195.936536ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19092026/10/25 16:09:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19102026/10/25 16:09:27 WARN Request failed, retrying attempt=3 backoff=428.354536ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19112026/10/25 16:09:27 INFO Signed narinfos id=1 count=119122026/10/25 16:09:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19132026/10/25 16:09:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19142026/10/25 16:09:27 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"19152026/10/25 16:09:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19162026/10/25 16:09:27 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"19172026/10/25 16:09:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19182026/10/25 16:09:27 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=119192026/10/25 16:09:27 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19202026/10/25 16:09:27 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1921--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (10.09s)1922=== CONT TestPendingClosureWriteTimeout/400_objects1923=== CONT TestProxyWriteTimeout/narinfo1924=== CONT TestProxyWriteTimeout/10_GiB_nar1925=== CONT TestProxyWriteTimeout/unknown_size1926=== CONT TestProxyWriteTimeout/1_GiB_nar1927--- PASS: TestProxyWriteTimeout (0.00s)1928 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1929 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1930 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1931 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1932=== CONT TestPush_RejectsBadRequests/no_objects19332026/10/25 16:09:27 INFO Received push request method=POST path=/api/pushes1934=== CONT TestPush_RejectsBadRequests/root_not_in_objects19352026/10/25 16:09:27 INFO Received push request method=POST path=/api/pushes1936=== CONT TestPush_RejectsBadRequests/no_roots19372026/10/25 16:09:27 INFO Received push request method=POST path=/api/pushes1938=== CONT TestPush_RejectsBadRequests/bad_root19392026/10/25 16:09:27 INFO Received push request method=POST path=/api/pushes1940--- PASS: TestPush_RejectsBadRequests (7.82s)1941 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1942 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1943 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1944 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)19452026/10/25 16:09:27 WARN Rate limiter enabled after throttle name=s3-test rate=519462026/10/25 16:09:27 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1947=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1948 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101949 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001950--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (14.86s)19512026/10/25 16:09:27 WARN Request failed, retrying attempt=4 backoff=873.743753ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1952--- PASS: TestUploadHandlersRejectOversizedBody (0.07s)1953 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.05s)1954 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.10s)1955 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (1.27s)1956--- PASS: TestReadProxy404 (10.00s)1957--- PASS: TestService_Rustfstest (9.83s)1958--- PASS: TestReadProxyInvalidPath (10.30s)19592026/10/25 16:09:28 WARN Request failed, retrying attempt=5 backoff=1.469097982s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config1960--- PASS: TestReadProxyNarStreaming (10.07s)19612026/10/25 16:09:29 INFO Received uploads request method=POST path=/api/pending_closures19622026/10/25 16:09:29 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst19632026/10/25 16:09:29 INFO Received uploads request method=POST path=/api/pending_closures1964--- PASS: TestPresignedUploadRegisteredBeforeCommit (10.53s)1965--- PASS: TestReadProxyOutlastsServerWriteTimeout (14.24s)19662026/10/25 16:09:29 INFO Received complete multipart upload request method=POST path=/api/multipart/complete19672026/10/25 16:09:29 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MjdkNjQ2MGEtZjAyZi00OGE5LWI2OTctZDcyYTYwNTU1MTA3LjEwMTdjODVmLWJlMDQtNDc3OS05YTM2LTI5MDk3MTRjOWZjNHgxNzkyOTQ0NTY2MzIzNTI4MDAw parts=1219682026/10/25 16:09:29 INFO Received uploads request method=POST path=/api/pending_closures19692026/10/25 16:09:29 INFO Received uploads request method=POST path=/api/pending_closures1970--- PASS: TestReadProxyContentNegotiation (10.37s)19712026/10/25 16:09:29 INFO Received uploads request method=POST path=/api/pending_closures19722026/10/25 16:09:29 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"19732026/10/25 16:09:30 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19742026/10/25 16:09:30 WARN Request failed, retrying attempt=2 backoff=214.693102ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19752026/10/25 16:09:30 WARN Request failed, retrying attempt=3 backoff=430.894503ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19762026/10/25 16:09:30 INFO Received uploads request method=POST path=/api/pending_closures19772026/10/25 16:09:30 INFO Aborted multipart uploads count=0 kept=019782026/10/25 16:09:30 WARN Force mode enabled - objects will be deleted immediately without grace period19792026/10/25 16:09:30 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=019802026/10/25 16:09:30 INFO Vacuumed table table=pending_closures19812026/10/25 16:09:30 INFO Vacuumed table table=pending_objects19822026/10/25 16:09:30 INFO Vacuumed table table=multipart_uploads19832026/10/25 16:09:30 INFO Vacuumed table table=closures19842026/10/25 16:09:30 INFO Vacuumed table table=objects1985--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)1986 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (10.51s)1987 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (10.31s)19882026/10/25 16:09:30 INFO Received uploads request method=POST path=/api/pending_closures19892026/10/25 16:09:30 WARN Request failed, retrying attempt=4 backoff=788.770287ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config19902026/10/25 16:09:30 INFO Aborted multipart uploads count=0 kept=019912026/10/25 16:09:30 WARN Force mode enabled - objects will be deleted immediately without grace period19922026/10/25 16:09:30 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=019932026/10/25 16:09:30 INFO Vacuumed table table=pending_closures19942026/10/25 16:09:30 INFO Vacuumed table table=pending_objects19952026/10/25 16:09:30 INFO Vacuumed table table=multipart_uploads19962026/10/25 16:09:30 INFO Vacuumed table table=closures19972026/10/25 16:09:30 INFO Vacuumed table table=objects1998--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)1999 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (9.90s)2000 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (9.74s)2001=== NAME TestOrphanedObjectsGCStressTest2002 orphaned_objects_gc_test.go:503: Stress test completed successfully:2003 orphaned_objects_gc_test.go:504: - Active objects preserved: 202004 orphaned_objects_gc_test.go:505: - Objects deleted: 2102005 orphaned_objects_gc_test.go:506: - Total GC'd: 2102006--- PASS: TestOrphanedObjectsGCStressTest (31.37s)20072026/10/25 16:09:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20082026/10/25 16:09:31 WARN Failed to abort redundant multipart upload, keeping its row object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MjdkNjQ2MGEtZjAyZi00OGE5LWI2OTctZDcyYTYwNTU1MTA3LmViZjRlNTBmLTdmM2MtNGU3OS04NGEyLTA4MjViYTViMGY5MXgxNzkyOTQ0NTY5MzY2MDAxMDAw error="Get \"http://127.0.0.1:1/bucket82/?location=\": dial tcp 127.0.0.1:1: connect: connection refused"20092026/10/25 16:09:31 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0200000000000000000000.nar.zst upload_id=MjdkNjQ2MGEtZjAyZi00OGE5LWI2OTctZDcyYTYwNTU1MTA3LmRjMDY2NjNmLWU4NTItNDllMC1hMGJiLWRmYjQyYTdjYjY1ZngxNzkyOTQ0NTY5MzIyODE5MDAw parts=1220102026/10/25 16:09:31 INFO Received cleanup request method=DELETE path=/api/pending_closures20112026/10/25 16:09:31 INFO Aborted multipart uploads count=1 kept=02012--- PASS: TestRedundantMultipartUpload (14.20s)20132026/10/25 16:09:31 INFO Received complete multipart upload request method=POST path=/api/multipart/complete20142026/10/25 16:09:31 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MjdkNjQ2MGEtZjAyZi00OGE5LWI2OTctZDcyYTYwNTU1MTA3LmVhNTU0YTBiLTk1ZWQtNDllZC1iMjQ2LTQ3MzdlZGM0MzQ3ZXgxNzkyOTQ0NTY5NjQyOTk5MDAw parts=1220152026/10/25 16:09:31 INFO Received uploads request method=POST path=/api/pending_closures2016--- PASS: TestCompletedNarNotReofferedAcrossClosures (11.52s)20172026/10/25 16:09:31 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20182026/10/25 16:09:31 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"20192026/10/25 16:09:31 WARN Request failed, retrying attempt=5 backoff=1.443515666s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config20202026/10/25 16:09:31 INFO Aborted multipart uploads count=0 kept=020212026/10/25 16:09:31 WARN Force mode enabled - objects will be deleted immediately without grace period20222026-10-25 16:09:31.694 UTC [32242] ERROR: canceling statement due to user request20232026-10-25 16:09:31.694 UTC [32242] CONTEXT: PL/pgSQL function object_stats_update() line 16 at RETURN20242026-10-25 16:09:31.694 UTC [32242] STATEMENT: -- name: MarkStaleObjects :execrows2025 WITH RECURSIVE ct AS (2026 SELECT timezone('UTC', now()) AS now2027 ),2028 closure_reach AS (2029 -- Start with all closure keys2030 SELECT o.key, o.refs2031 FROM objects o2032 INNER JOIN closures c ON o.key = c.key2033 UNION2034 -- Recursively add all referenced objects2035 SELECT o.key, o.refs2036 FROM objects o2037 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2038 ),2039 reachable_objects AS (2040 SELECT DISTINCT key FROM closure_reach2041 ),2042 stale_objects AS (2043 SELECT o.key2044 FROM objects AS o, ct2045 WHERE2046 NOT EXISTS (2047 SELECT 12048 FROM reachable_objects ro2049 WHERE ro.key = o.key2050 )2051 AND NOT EXISTS (2052 SELECT 12053 FROM pending_objects AS po2054 WHERE po.key = o.key2055 )2056 AND o.deleted_at IS NULL -- Only mark fresh objects2057 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2058 FOR UPDATE2059 )2060 UPDATE objects2061 SET2062 deleted_at = ct.now,2063 first_deleted_at = COALESCE(first_deleted_at, ct.now)2064 FROM stale_objects, ct2065 WHERE objects.key = stale_objects.key2066 20672026/10/25 16:09:31 INFO Aborted multipart uploads count=0 kept=020682026/10/25 16:09:31 WARN Force mode enabled - objects will be deleted immediately without grace period20692026/10/25 16:09:31 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:60796/bucket99/?delete=\": context canceled"2070--- PASS: TestGCEndsOnShutdown (0.00s)2071 --- PASS: TestGCEndsOnShutdown/before_the_run (8.00s)2072 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (7.68s)2073 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (6.47s)20742026/10/25 16:09:31 INFO Received uploads request method=POST path=/api/pending_closures2075--- PASS: TestPendingClosureWriteTimeout (0.03s)2076 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2077 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2078 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2079 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (6.05s)20802026/10/25 16:09:33 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20812026/10/25 16:09:33 WARN Request failed, retrying attempt=2 backoff=198.609594ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20822026/10/25 16:09:33 WARN Request failed, retrying attempt=3 backoff=430.835872ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20832026/10/25 16:09:33 WARN Request failed, retrying attempt=4 backoff=751.400789ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures20842026/10/25 16:09:34 WARN Request failed, retrying attempt=5 backoff=1.590530928s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2085--- PASS: TestClientErrorHandling (0.00s)2086 --- PASS: TestClientErrorHandling/InvalidStorePath (9.37s)2087 --- PASS: TestClientErrorHandling/InvalidAuthToken (8.41s)2088 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.44s)2089FAIL2090{"timestamp":"2026-10-25T16:09:36.096342Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:61092","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2386,"threadName":"rustfs-worker","threadId":"ThreadId(5)"}2091{"timestamp":"2026-10-25T16:09:36.09647Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:60994","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2386,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}20922026-10-25 16:09:36.264 UTC [28681] LOG: received smart shutdown request20932026/10/25 16:09:46 INFO killed process group pgid=2868120942026-10-25 16:09:46.268 UTC [29849] FATAL: terminating connection due to unexpected postmaster exit20952026-10-25 16:09:46.268 UTC [29851] FATAL: terminating connection due to unexpected postmaster exit20962026-10-25 16:09:46.268 UTC [29879] FATAL: terminating connection due to unexpected postmaster exit20972026/10/25 16:09:46 ERROR failed to wait for process error="signal: killed"20982026-10-25 16:09:46.268 UTC [29945] FATAL: terminating connection due to unexpected postmaster exit20992026-10-25 16:09:46.268 UTC [29872] FATAL: terminating connection due to unexpected postmaster exit21002026-10-25 16:09:46.268 UTC [29850] FATAL: terminating connection due to unexpected postmaster exit21012026-10-25 16:09:46.268 UTC [29877] FATAL: terminating connection due to unexpected postmaster exit21022026-10-25 16:09:46.273 UTC [29874] FATAL: terminating connection due to unexpected postmaster exit21032026-10-25 16:09:46.268 UTC [29855] FATAL: terminating connection due to unexpected postmaster exit