niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #490
· 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_ReturnsAfterDroppedBody20=== PAUSE TestUploadMultipart_ReturnsAfterDroppedBody21=== RUN TestPartSizeForNAR22=== PAUSE TestPartSizeForNAR23=== RUN TestDumpPathCaseHackMatchesNix24--- PASS: TestDumpPathCaseHackMatchesNix (0.05s)25=== RUN TestDumpPathCaseHackCollision26--- PASS: TestDumpPathCaseHackCollision (0.00s)27=== RUN TestDumpPathMatchesNix28=== PAUSE TestDumpPathMatchesNix29=== RUN TestDumpPathSingleFile30=== PAUSE TestDumpPathSingleFile31=== RUN TestDumpPathWriterError32=== PAUSE TestDumpPathWriterError33=== RUN TestEncodeNixBase3234=== PAUSE TestEncodeNixBase3235=== RUN TestEncodeNixBase32WithRealHash36=== PAUSE TestEncodeNixBase32WithRealHash37=== RUN TestConvertHashToNix3238=== PAUSE TestConvertHashToNix3239=== RUN TestGetStorePathHash40=== PAUSE TestGetStorePathHash41=== RUN TestPathInfoHashCompatibility42=== PAUSE TestPathInfoHashCompatibility43=== RUN TestParsePathInfoJSON44=== PAUSE TestParsePathInfoJSON45=== RUN TestParsePathInfoJSONMultiplePaths46=== PAUSE TestParsePathInfoJSONMultiplePaths47=== RUN TestPathInfoCACompatibility48=== PAUSE TestPathInfoCACompatibility49=== RUN TestRateLimiterFeedback50=== PAUSE TestRateLimiterFeedback51=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess52=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess53=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer54=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer55=== RUN TestRegisterUploadedObject_OutlivesPush56=== PAUSE TestRegisterUploadedObject_OutlivesPush57=== RUN TestResolveStorePath58=== PAUSE TestResolveStorePath59=== RUN TestDoWithRetry_BodyReplayedViaGetBody60=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody61=== RUN TestRetryTimeoutOutlastsMaxRetries62=== PAUSE TestRetryTimeoutOutlastsMaxRetries63=== RUN TestDoWithRetry_FinalResponseBodyReadable64=== PAUSE TestDoWithRetry_FinalResponseBodyReadable65=== RUN TestShellSplit66=== PAUSE TestShellSplit67=== RUN TestShellSplitErrors68=== PAUSE TestShellSplitErrors69=== RUN TestStreamPushReportsEveryPath70=== PAUSE TestStreamPushReportsEveryPath71=== RUN TestStreamPushBatchesUnderLoad72=== PAUSE TestStreamPushBatchesUnderLoad73=== RUN TestStreamPushIsolatesFailures74=== PAUSE TestStreamPushIsolatesFailures75=== RUN TestStreamPushGivesUpOnDeadServer76=== PAUSE TestStreamPushGivesUpOnDeadServer77=== RUN TestStreamPushRequestLine78=== PAUSE TestStreamPushRequestLine79=== RUN TestStreamPushReportsSignatures80=== PAUSE TestStreamPushReportsSignatures81=== RUN TestStreamPushReportsSkippedPaths82=== PAUSE TestStreamPushReportsSkippedPaths83=== RUN TestClientSignaturesByStorePath84=== PAUSE TestClientSignaturesByStorePath85=== RUN TestStreamPushStopsWhenCanceled86=== PAUSE TestStreamPushStopsWhenCanceled87=== RUN TestSetClientTLS88=== PAUSE TestSetClientTLS89=== RUN TestSetClientTLSDoesNotMutateDefaultTransport90=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport91=== RUN TestSetClientTLSErrors92=== PAUSE TestSetClientTLSErrors93=== RUN TestStaticToken94=== PAUSE TestStaticToken95=== RUN TestFileTokenReadsAndCaches96=== PAUSE TestFileTokenReadsAndCaches97=== RUN TestFileTokenMissing98=== PAUSE TestFileTokenMissing99=== RUN TestFileTokenEmpty100=== PAUSE TestFileTokenEmpty101=== RUN TestScriptTokenNoExpiryRerunsEveryCall102=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall103=== RUN TestScriptTokenCachesUntilRefresh104=== PAUSE TestScriptTokenCachesUntilRefresh105=== RUN TestScriptTokenEmptyToken106=== PAUSE TestScriptTokenEmptyToken107=== RUN TestScriptTokenBadJSON108=== PAUSE TestScriptTokenBadJSON109=== RUN TestScriptTokenScriptFails110=== PAUSE TestScriptTokenScriptFails111=== RUN TestScriptTokenEmptyCommand112=== PAUSE TestScriptTokenEmptyCommand113=== CONT TestDoServerRequestAttachesToken114=== CONT TestStreamPushRequestLine115=== CONT TestFileTokenReadsAndCaches116=== CONT TestScriptTokenEmptyCommand117--- PASS: TestScriptTokenEmptyCommand (0.00s)118=== CONT TestConvertHashToNix32119=== RUN TestConvertHashToNix32/SRI_format_to_Nix32120=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32121=== RUN TestConvertHashToNix32/already_Nix32_format122=== CONT TestScriptTokenScriptFails123=== CONT TestScriptTokenBadJSON124=== CONT TestScriptTokenEmptyToken125=== CONT TestScriptTokenCachesUntilRefresh126=== CONT TestScriptTokenNoExpiryRerunsEveryCall127=== CONT TestFileTokenEmpty128=== CONT TestFileTokenMissing129=== CONT TestParsePathInfoJSON130=== RUN TestParsePathInfoJSON/Nix_format131=== CONT TestStreamPushGivesUpOnDeadServer132=== CONT TestStreamPushIsolatesFailures133=== CONT TestResolveStorePath1342026/11/11 23:34:27 ERROR Upload failed error=boom count=1135=== CONT TestRegisterUploadedObject_OutlivesPush136=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer137=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess138=== CONT TestRateLimiterFeedback139=== CONT TestPathInfoCACompatibility140=== CONT TestParsePathInfoJSONMultiplePaths141=== CONT TestPartSizeForNAR142=== CONT TestPathInfoHashCompatibility143=== CONT TestGetStorePathHash144=== PAUSE TestConvertHashToNix32/already_Nix32_format145=== PAUSE TestParsePathInfoJSON/Nix_format146--- PASS: TestFileTokenReadsAndCaches (0.00s)147=== RUN TestRateLimiterFeedback/429_enables_limiter148=== PAUSE TestRateLimiterFeedback/429_enables_limiter149=== RUN TestRateLimiterFeedback/503_enables_limiter150=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1512026/11/11 23:34:27 ERROR Upload failed error="connection refused" count=20152=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths1532026/11/11 23:34:27 ERROR Server seems unavailable, giving up on batch untried=171542026/11/11 23:34:27 ERROR Upload failed error="bad path" count=3155=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths156=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths157=== CONT TestStreamPushBatchesUnderLoad158=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false159=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false160=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true161=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true162=== RUN TestPathInfoCACompatibility/null_ca_field163=== CONT TestStreamPushReportsEveryPath164=== CONT TestShellSplitErrors165=== CONT TestShellSplit166=== CONT TestDoWithRetry_FinalResponseBodyReadable167=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)168=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)169=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon170=== PAUSE TestPathInfoCACompatibility/null_ca_field171=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon172=== RUN TestPathInfoCACompatibility/old_string_format_-_text173=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI174=== RUN TestGetStorePathHash/valid_store_path175=== RUN TestPartSizeForNAR/zero_stays_at_minimum176=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI177=== CONT TestDumpPathWriterError178=== RUN TestParsePathInfoJSON/Lix_format1792026/11/11 23:34:27 WARN Rate limiter enabled after throttle name=server-test rate=5180=== CONT TestDoWithRetry_BodyReplayedViaGetBody181=== PAUSE TestGetStorePathHash/valid_store_path182=== RUN TestGetStorePathHash/basename_without_hyphen_should_error183=== PAUSE TestRateLimiterFeedback/503_enables_limiter184--- PASS: TestStreamPushIsolatesFailures (0.00s)185=== CONT TestRetryTimeoutOutlastsMaxRetries186=== RUN TestConvertHashToNix32/invalid_format187=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum188=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512189=== CONT TestDumpPathSingleFile190=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text191=== CONT TestCaseHackSuffix192=== PAUSE TestParsePathInfoJSON/Lix_format1932026/11/11 23:34:27 WARN Rate limiter enabled after throttle name=server-test rate=51942026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:589031952026/11/11 23:34:27 WARN Rate limiter enabled after throttle name=server-test rate=5196=== CONT TestEncodeNixBase32197=== RUN TestEncodeNixBase32/test_string_hash198=== PAUSE TestEncodeNixBase32/test_string_hash199=== RUN TestEncodeNixBase32/empty_input200=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error201--- PASS: TestShellSplitErrors (0.00s)202=== PAUSE TestConvertHashToNix32/invalid_format2032026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:58894204=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter205=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter206=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter207=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter208=== CONT TestFilterOversizedClosures209=== RUN TestFilterOversizedClosures/no_limit_keeps_everything210=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything211=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped212=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped213=== RUN TestPartSizeForNAR/small_stays_at_minimum214=== PAUSE TestPartSizeForNAR/small_stays_at_minimum215=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512216=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive217=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive218=== CONT TestSetClientTLS219=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun220=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica221=== CONT TestUploadMultipart_ReturnsAfterDroppedBody222=== CONT TestUploadMultipart_PartsInParallel223=== RUN TestParsePathInfoJSON/empty_input2242026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:58905225=== PAUSE TestEncodeNixBase32/empty_input2262026/11/11 23:34:27 WARN Rate limiter backed off name=server-test rate=52272026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:58903228=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error229--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)230--- PASS: TestShellSplit (0.00s)231--- PASS: TestFileTokenEmpty (0.00s)232--- PASS: TestScriptTokenScriptFails (0.01s)233--- PASS: TestFileTokenMissing (0.00s)234--- PASS: TestStreamPushReportsEveryPath (0.00s)235--- PASS: TestResolveStorePath (0.00s)236--- PASS: TestRegisterUploadedObject_OutlivesPush (0.00s)237--- PASS: TestDoServerRequestAttachesToken (0.01s)238=== PAUSE TestParsePathInfoJSON/empty_input2392026/11/11 23:34:27 WARN Rate limiter backed off name=server-test rate=52402026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:589052412026/11/11 23:34:27 INFO Garbage collection started242=== RUN TestFilterOversizedClosures/all_closures_skipped243=== PAUSE TestFilterOversizedClosures/all_closures_skipped244=== CONT TestSetClientTLSErrors245=== CONT TestRegisterUploadedObjectReusesConnections246=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum247=== RUN TestPathInfoCACompatibility/new_structured_format_-_text248=== CONT TestStaticToken249--- PASS: TestScriptTokenBadJSON (0.01s)250=== RUN TestSetClientTLS/rejects_connection_without_client_cert251=== CONT TestClientSignaturesByStorePath252=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry2532026/11/11 23:34:27 INFO Garbage collection started254=== CONT TestStreamPushReportsSkippedPaths255=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum256=== CONT TestDumpPathMatchesNix257=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts258=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts259=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert260=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA261=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA262=== RUN TestSetClientTLS/preserves_debug_logging_transport263=== PAUSE TestSetClientTLS/preserves_debug_logging_transport264=== CONT TestStreamPushStopsWhenCanceled265=== CONT TestEncodeNixBase32WithRealHash266=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths267=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text268=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method269=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error270=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error271=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error272=== RUN TestParsePathInfoJSON/whitespace_only273=== PAUSE TestParsePathInfoJSON/whitespace_only274=== RUN TestParsePathInfoJSON/invalid_JSON275=== PAUSE TestParsePathInfoJSON/invalid_JSON276=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths277=== CONT TestConvertHashToNix32/SRI_format_to_Nix32278=== CONT TestRateLimiterFeedback/429_enables_limiter279=== RUN TestSetClientTLSErrors/missing_cert_file280=== PAUSE TestSetClientTLSErrors/missing_cert_file281=== RUN TestSetClientTLSErrors/missing_key_file282=== PAUSE TestSetClientTLSErrors/missing_key_file283=== RUN TestSetClientTLSErrors/missing_ca_file284=== PAUSE TestSetClientTLSErrors/missing_ca_file285=== RUN TestSetClientTLSErrors/invalid_ca_file286=== PAUSE TestSetClientTLSErrors/invalid_ca_file287=== CONT TestConvertHashToNix32/invalid_format288=== CONT TestConvertHashToNix32/already_Nix32_format289=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)290=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI291=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512292=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter293=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true294=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false295=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method296=== RUN TestPartSizeForNAR/1_TiB297=== PAUSE TestPartSizeForNAR/1_TiB298=== RUN TestPartSizeForNAR/5_TiB_S3_max_object299=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object300=== RUN TestPartSizeForNAR/capped_at_5_GiB301=== PAUSE TestPartSizeForNAR/capped_at_5_GiB302=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter303=== CONT TestRateLimiterFeedback/503_enables_limiter304=== CONT TestEncodeNixBase32/test_string_hash305=== CONT TestEncodeNixBase32/empty_input306=== CONT TestFilterOversizedClosures/no_limit_keeps_everything307=== CONT TestFilterOversizedClosures/all_closures_skipped3082026/11/11 23:34:27 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=50309=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped3102026/11/11 23:34:27 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=2000311=== CONT TestSetClientTLS/rejects_connection_without_client_cert312=== CONT TestSetClientTLSDoesNotMutateDefaultTransport313=== CONT TestStreamPushReportsSignatures314=== CONT TestSetClientTLS/preserves_debug_logging_transport315--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)316--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)317--- PASS: TestScriptTokenEmptyToken (0.01s)318--- PASS: TestClientSignaturesByStorePath (0.00s)319--- PASS: TestStaticToken (0.00s)320--- PASS: TestStreamPushReportsSkippedPaths (0.00s)321--- PASS: TestStreamPushStopsWhenCanceled (0.00s)322--- PASS: TestEncodeNixBase32WithRealHash (0.00s)3232026/11/11 23:34:27 ERROR Upload failed error=boom count=1324--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)325 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)326 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)327--- PASS: TestStreamPushReportsSignatures (0.00s)328--- PASS: TestConvertHashToNix32 (0.01s)329 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)330 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)331 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)332=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA333--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.01s)334--- PASS: TestEncodeNixBase32 (0.00s)335 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)336 --- PASS: TestEncodeNixBase32/empty_input (0.00s)337--- PASS: TestStreamPushBatchesUnderLoad (0.00s)338 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)339 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)340--- PASS: TestFilterOversizedClosures (0.01s)341 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)342 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)343 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)344=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon345--- PASS: TestPathInfoHashCompatibility (0.01s)346 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)347 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)348 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)349 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)350=== CONT TestGetStorePathHash/valid_store_path351=== CONT TestParsePathInfoJSON/Nix_format352=== CONT TestSetClientTLSErrors/missing_cert_file353=== CONT TestSetClientTLSErrors/missing_ca_file354=== CONT TestSetClientTLSErrors/invalid_ca_file355=== CONT TestSetClientTLSErrors/missing_key_file356--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.01s)357=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error358=== CONT TestGetStorePathHash/basename_without_hyphen_should_error359=== CONT TestPartSizeForNAR/zero_stays_at_minimum360=== CONT TestPathInfoCACompatibility/new_structured_format_-_text361=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive362=== CONT TestPathInfoCACompatibility/old_string_format_-_text363=== CONT TestPartSizeForNAR/capped_at_5_GiB364=== CONT TestPartSizeForNAR/5_TiB_S3_max_object365=== CONT TestPartSizeForNAR/1_TiB366=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts367=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum368=== CONT TestPartSizeForNAR/small_stays_at_minimum369--- PASS: TestPartSizeForNAR (0.01s)370 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)371 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)372 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)373 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)374 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)375 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)376 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)377=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error378--- PASS: TestGetStorePathHash (0.01s)379 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)380 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)381 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)382 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)383=== CONT TestParsePathInfoJSON/invalid_JSON384=== CONT TestParsePathInfoJSON/whitespace_only385=== CONT TestParsePathInfoJSON/Lix_format386=== CONT TestPathInfoCACompatibility/null_ca_field387=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method3882026/11/11 23:34:27 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=0389--- PASS: TestPathInfoCACompatibility (0.01s)390 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)391 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)392 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)393 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)394 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)3952026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:589053962026/11/11 23:34:27 WARN Rate limiter enabled after throttle name=server-test rate=53972026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:58961398=== CONT TestParsePathInfoJSON/empty_input399--- PASS: TestParsePathInfoJSON (0.01s)400 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)401 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)402 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)403 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)404 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)4052026/11/11 23:34:27 WARN Rate limiter enabled after throttle name=server-test rate=54062026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:589284072026/11/11 23:34:27 WARN Rate limiter backed off name=server-test rate=54082026/11/11 23:34:27 WARN Rate limiter backed off name=server-test rate=5409--- PASS: TestRateLimiterFeedback (0.01s)410 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)411 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)412 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)413 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)4142026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:589054152026/11/11 23:34:27 WARN Rate limiter enabled after throttle name=s3-test rate=54162026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:589744172026/11/11 23:34:27 WARN Garbage collection finished on another replica. Its statistics are not available here418--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)419--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)420--- PASS: TestSetClientTLSErrors (0.01s)421 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)422 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)423 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)424 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)425--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)4262026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:58905427--- PASS: TestStreamPushRequestLine (0.03s)4282026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:589054292026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:589054302026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:589054312026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:589054322026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:589054332026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:589054342026/11/11 23:34:27 http: TLS handshake error from 127.0.0.1:58963: read tcp 127.0.0.1:58913->127.0.0.1:58963: use of closed network connection4352026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:58905436--- PASS: TestSetClientTLS (0.01s)437 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.00s)438 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)439 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.02s)440--- PASS: TestScriptTokenCachesUntilRefresh (0.04s)4412026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:58905442--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)4432026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:589054442026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:58905445--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)4462026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:589054472026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:589054482026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:589054492026/11/11 23:34:27 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:58905450--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.05s)451--- PASS: TestDumpPathWriterError (0.06s)452--- PASS: TestDumpPathSingleFile (0.05s)453--- PASS: TestCaseHackSuffix (0.06s)454--- PASS: TestDumpPathMatchesNix (0.08s)4552026/11/11 23:34:27 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:58893/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:58893/api/uploads/complete4562026/11/11 23:34:27 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:58893/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:58893/api/uploads/complete4572026/11/11 23:34:27 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4582026/11/11 23:34:27 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4592026/11/11 23:34:27 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:58893/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:58893/api/uploads/complete4602026/11/11 23:34:27 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"461--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.11s)462--- PASS: TestUploadMultipart_PartsInParallel (0.62s)463--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.01s)464PASS465Running server tests...466The files belonging to this database system will be owned by user "_tribuchetbld5".467This user must also own the server process.468469The database cluster will be initialized with locale "C".470The default database encoding has accordingly been set to "SQL_ASCII".471The default text search configuration will be set to "english".472473Data page checksums are enabled.474475creating directory /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/postgres31241280/data ... ok476creating subdirectories ... ok477selecting dynamic shared memory implementation ... posix478selecting default "max_connections" ... 100479selecting default "shared_buffers" ... 128MB480selecting default time zone ... UTC481creating configuration files ... ok482running bootstrap script ... ok483performing post-bootstrap initialization ... ok484syncing data to disk ... ok485486initdb: warning: enabling "trust" authentication for local connections487initdb: 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.488489Success. You can now start the database server using:490491 pg_ctl -D /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/postgres31241280/data -l logfile start492493/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/postgres31241280:5432 - no response4942026-11-11 23:34:29.274 UTC [86715] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4952026-11-11 23:34:29.274 UTC [86715] LOG: listening on Unix socket "/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/postgres31241280/.s.PGSQL.5432"4962026-11-11 23:34:29.276 UTC [86722] LOG: database system was shut down at 2026-11-11 23:34:29 UTC4972026-11-11 23:34:29.277 UTC [86715] LOG: database system is ready to accept connections498/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/postgres31241280:5432 - accepting connections499{"timestamp":"2026-11-11T23:34:29.493088Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"9588a94a-a603-4522-b91f-75ee81d7c4eb","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":502,"threadName":"rustfs-worker","threadId":"ThreadId(10)"}500=== RUN TestAbortSucceeded501=== PAUSE TestAbortSucceeded502=== RUN TestService_AuthMiddleware503=== PAUSE TestService_AuthMiddleware504=== RUN TestService_AuthMiddleware_MTLSProxyHeader505=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader506=== RUN TestService_AuthMiddleware_MTLSBoundSubjects507=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects508=== RUN TestService_ReadAuthMiddleware509=== PAUSE TestService_ReadAuthMiddleware510=== RUN TestService_AuthMiddleware_OIDC511=== PAUSE TestService_AuthMiddleware_OIDC512=== RUN TestService_RequireScope_OIDC513=== PAUSE TestService_RequireScope_OIDC514=== RUN TestService_ReadScope_PublicByDefault515=== PAUSE TestService_ReadScope_PublicByDefault516=== RUN TestCacheConfigHandler517=== PAUSE TestCacheConfigHandler518=== RUN TestCacheStatsHandler519=== PAUSE TestCacheStatsHandler520=== RUN TestClientCADerivations521=== PAUSE TestClientCADerivations522=== RUN TestClientErrorHandling523=== PAUSE TestClientErrorHandling524=== RUN TestClientIntegration525=== PAUSE TestClientIntegration526=== RUN TestClientMultipleUploads527=== PAUSE TestClientMultipleUploads528=== RUN TestClientWithDependencies529=== PAUSE TestClientWithDependencies530=== RUN TestClientSharedPathCommittedMidPush531=== PAUSE TestClientSharedPathCommittedMidPush532=== RUN TestPinProtectsFromGC533=== PAUSE TestPinProtectsFromGC534=== RUN TestClientPushesUseOnePush535=== PAUSE TestClientPushesUseOnePush536=== RUN TestClientFallsBackToClosures537=== PAUSE TestClientFallsBackToClosures538=== RUN TestDeleteClosuresRacingPins539=== PAUSE TestDeleteClosuresRacingPins540=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock541=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock542=== RUN TestResolveDBConnectionString543=== PAUSE TestResolveDBConnectionString544=== RUN TestConnectWaitsForAPeerMigration545=== PAUSE TestConnectWaitsForAPeerMigration546=== RUN TestLeadElectsOneAndHandsOver547=== PAUSE TestLeadElectsOneAndHandsOver548=== RUN TestLeadIncumbentWinsAfterRestart5492026/11/11 23:34:29 INFO lead: acquired remote=192.0.2.1:1234 generation=15502026/11/11 23:34:30 INFO lead: released remote=192.0.2.1:1234 generation=15512026/11/11 23:34:30 INFO lead: acquired remote=192.0.2.1:1234 generation=25522026/11/11 23:34:31 INFO lead: released remote=192.0.2.1:1234 generation=2553--- PASS: TestLeadIncumbentWinsAfterRestart (1.91s)554=== RUN TestLeadUnannouncedStandbyYieldsToIncumbent555=== PAUSE TestLeadUnannouncedStandbyYieldsToIncumbent556=== RUN TestLeadIncumbentAnnouncesAtOnce557=== PAUSE TestLeadIncumbentAnnouncesAtOnce558=== RUN TestLeadGenerationGrowsWithEveryGrant559=== PAUSE TestLeadGenerationGrowsWithEveryGrant560=== RUN TestLeadEndsOnShutdown561=== PAUSE TestLeadEndsOnShutdown562=== RUN TestLeadEndsWhenItsConnectionHangs5632026/11/11 23:34:31 INFO lead: acquired remote=192.0.2.1:1234 generation=15642026-11-11 23:34:33.083 UTC [86759] FATAL: terminating connection due to administrator command5652026/11/11 23:34:33 INFO lead: acquired remote=192.0.2.1:1234 generation=25662026/11/11 23:34:34 WARN lead: lock connection lost error="timeout: context deadline exceeded"5672026/11/11 23:34:34 INFO lead: released remote=192.0.2.1:1234 generation=15682026/11/11 23:34:34 INFO lead: released remote=192.0.2.1:1234 generation=2569--- PASS: TestLeadEndsWhenItsConnectionHangs (2.98s)570=== RUN TestGCAdvisoryLockBlocksConcurrentRun571=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun572=== RUN TestGCBugBareHashReferences573=== PAUSE TestGCBugBareHashReferences574=== RUN TestGCMetrics575=== PAUSE TestGCMetrics576=== RUN TestPushDedupSurvivesConcurrentGC577=== PAUSE TestPushDedupSurvivesConcurrentGC578=== RUN TestDeduplicatedObjectsRecordedAsPending579=== PAUSE TestDeduplicatedObjectsRecordedAsPending580=== RUN TestGCSweepSkipsPendingObjects581=== PAUSE TestGCSweepSkipsPendingObjects582=== RUN TestTombstonedObjectOfferedWithoutWaiting583=== PAUSE TestTombstonedObjectOfferedWithoutWaiting584=== RUN TestGCSweepDeliversEachKeyOnce585=== PAUSE TestGCSweepDeliversEachKeyOnce586=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection587=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection588=== RUN TestForceGCDuringPushOffersSweptObject589=== PAUSE TestForceGCDuringPushOffersSweptObject590=== RUN TestFailedS3DeleteKeepsTombstone591=== PAUSE TestFailedS3DeleteKeepsTombstone592=== RUN TestSweepSkipsRowsLockedByPush593=== PAUSE TestSweepSkipsRowsLockedByPush594=== RUN TestRegisterCompletedObjectNeedsPendingRow595=== PAUSE TestRegisterCompletedObjectNeedsPendingRow596=== RUN TestGetExistingObjectsLocksRows597=== PAUSE TestGetExistingObjectsLocksRows598=== RUN TestSweepRechecksPendingAfterLocking599=== PAUSE TestSweepRechecksPendingAfterLocking600=== RUN TestPushWaitsForSweepHoldingRow601=== PAUSE TestPushWaitsForSweepHoldingRow602=== RUN TestCommitRacingPendingCleanupKeepsObjects603=== PAUSE TestCommitRacingPendingCleanupKeepsObjects604=== RUN TestGCEndsOnShutdown605=== PAUSE TestGCEndsOnShutdown606=== RUN TestGCTaskStore_StartNew607=== PAUSE TestGCTaskStore_StartNew608=== RUN TestGCTaskStore_DeduplicateSameParams609=== PAUSE TestGCTaskStore_DeduplicateSameParams610=== RUN TestGCTaskStore_ConflictDifferentParams611=== PAUSE TestGCTaskStore_ConflictDifferentParams612=== RUN TestGCTaskStore_GetEmpty613=== PAUSE TestGCTaskStore_GetEmpty614=== RUN TestGCTaskStore_GetReturnsLatest615=== PAUSE TestGCTaskStore_GetReturnsLatest616=== RUN TestGCTaskStore_CompletedAllowsNewTask617=== PAUSE TestGCTaskStore_CompletedAllowsNewTask618=== RUN TestGCTaskStore_PhaseUpdates619=== PAUSE TestGCTaskStore_PhaseUpdates620=== RUN TestGCTaskStore_Fail621=== PAUSE TestGCTaskStore_Fail622=== RUN TestGracefulShutdownDrainsInflight623=== PAUSE TestGracefulShutdownDrainsInflight624=== RUN TestService_healthCheckHandler625=== PAUSE TestService_healthCheckHandler626=== RUN TestService_readinessHandler627=== PAUSE TestService_readinessHandler628=== RUN TestGenerateLandingPage629=== PAUSE TestGenerateLandingPage630=== RUN TestEnsureAbortUploadsRule631=== PAUSE TestEnsureAbortUploadsRule632=== RUN TestCacheConfigHandlerMaxNarSize633=== PAUSE TestCacheConfigHandlerMaxNarSize634=== RUN TestCreatePendingClosureRejectsOversizedNAR635=== PAUSE TestCreatePendingClosureRejectsOversizedNAR636=== RUN TestNARDeduplicationMetadataUploadBug637=== PAUSE TestNARDeduplicationMetadataUploadBug638=== RUN TestMetricsInventory639=== PAUSE TestMetricsInventory640=== RUN TestMetricsCommit641=== PAUSE TestMetricsCommit642=== RUN TestService_NativeMTLS643=== PAUSE TestService_NativeMTLS644=== RUN TestServerTLSConfig645=== PAUSE TestServerTLSConfig646=== RUN TestMultipartCleanup647=== PAUSE TestMultipartCleanup648=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded649=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded650=== RUN TestPendingCleanupUsesOneCutoff651=== PAUSE TestPendingCleanupUsesOneCutoff652=== RUN TestObjectStatsTrigger653=== PAUSE TestObjectStatsTrigger654=== RUN TestObjectStatsUpdatedOncePerCommit655=== PAUSE TestObjectStatsUpdatedOncePerCommit656=== RUN TestOrphanedObjectsGC657=== PAUSE TestOrphanedObjectsGC658=== RUN TestOrphanedObjectsGCStressTest659=== PAUSE TestOrphanedObjectsGCStressTest660=== RUN TestCreatePin_ReservedPins661=== PAUSE TestCreatePin_ReservedPins662=== RUN TestPresentReportsOnlyClosureRoots663=== PAUSE TestPresentReportsOnlyClosureRoots664=== RUN TestPresentRefreshesOnlyStaleClosures665=== PAUSE TestPresentRefreshesOnlyStaleClosures666=== RUN TestPresentNotReportedWhileGCDeletesClosure667=== PAUSE TestPresentNotReportedWhileGCDeletesClosure668=== RUN TestParseSingleRange669=== PAUSE TestParseSingleRange670=== RUN TestProxyHeadersOnlyTrustedOnSocket6712026/11/11 23:34:34 INFO Starting HTTP server address=127.0.0.1:590146722026/11/11 23:34:34 INFO Starting HTTP server address=proxy.sock6732026/11/11 23:34:34 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6742026/11/11 23:34:34 INFO Shutdown signal received, draining in-flight requests timeout=10s675--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.16s)676=== RUN TestIsValidCachePath677=== PAUSE TestIsValidCachePath678=== RUN TestReadProxyNarinfo679=== PAUSE TestReadProxyNarinfo680=== RUN TestReadProxyNarinfoAlreadyDecompressed681=== PAUSE TestReadProxyNarinfoAlreadyDecompressed682=== RUN TestReadProxyContentNegotiation683=== PAUSE TestReadProxyContentNegotiation684=== RUN TestReadProxyNarStreaming685=== PAUSE TestReadProxyNarStreaming686=== RUN TestReadProxy404687=== PAUSE TestReadProxy404688=== RUN TestReadProxyInvalidPath689=== PAUSE TestReadProxyInvalidPath690=== RUN TestReadProxyHead691=== PAUSE TestReadProxyHead692=== RUN TestReadProxyOutlastsServerWriteTimeout693=== PAUSE TestReadProxyOutlastsServerWriteTimeout694=== RUN TestReadProxyConditionalGet695=== PAUSE TestReadProxyConditionalGet696=== RUN TestReadProxyRootRedirectsToIndexHTML697=== PAUSE TestReadProxyRootRedirectsToIndexHTML698=== RUN TestReadProxyDisabled699=== PAUSE TestReadProxyDisabled700=== RUN TestReadRedirectNar701=== PAUSE TestReadRedirectNar702=== RUN TestReadRedirectKeepsNarinfoProxied703=== PAUSE TestReadRedirectKeepsNarinfoProxied704=== RUN TestReadProxyRangeRequest705=== PAUSE TestReadProxyRangeRequest706=== RUN TestReadRedirectUsesPublicS3URL707=== PAUSE TestReadRedirectUsesPublicS3URL708=== RUN TestPush_OverlappingRootsStoreOneRowPerKey709=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey710=== RUN TestPush_CompleteCommitsEveryRoot711=== PAUSE TestPush_CompleteCommitsEveryRoot712=== RUN TestPush_RepeatedRootCommitsOnce713=== PAUSE TestPush_RepeatedRootCommitsOnce714=== RUN TestPush_CompleteWaitsForCleanupOfThePush715=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush716=== RUN TestPush_RootsAreLockedInByteOrder717=== PAUSE TestPush_RootsAreLockedInByteOrder718=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit719=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit720=== RUN TestPush_RejectsBadRequests721=== PAUSE TestPush_RejectsBadRequests722=== RUN TestPush_SignsNarinfosOfItsPendingObjects723=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects724=== RUN TestSharedNarBothUploadsComplete725=== PAUSE TestSharedNarBothUploadsComplete726=== RUN TestCompleteMultipartUpload_ErrorButObjectExists727=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists728=== RUN TestCompletedNarNotReofferedAcrossClosures729=== PAUSE TestCompletedNarNotReofferedAcrossClosures730=== RUN TestPresignedUploadRegisteredBeforeCommit731=== PAUSE TestPresignedUploadRegisteredBeforeCommit732=== RUN TestService_Rustfstest733=== PAUSE TestService_Rustfstest734=== RUN TestParseSize735=== PAUSE TestParseSize736=== RUN TestSkippedUploadsHandler737=== PAUSE TestSkippedUploadsHandler738=== RUN TestSystemdListenerNotActivated739--- PASS: TestSystemdListenerNotActivated (0.00s)740=== RUN TestWatchdogBeatsWhenHealthy741--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)742=== RUN TestWatchdogSkipsWhenUnhealthy7432026/11/11 23:34:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7442026/11/11 23:34:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7452026/11/11 23:34:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7462026/11/11 23:34:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7472026/11/11 23:34:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7482026/11/11 23:34:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7492026/11/11 23:34:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7502026/11/11 23:34:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7512026/11/11 23:34:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7522026/11/11 23:34:34 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"753--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)754=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle755=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle756=== RUN TestProxyWriteTimeout757=== PAUSE TestProxyWriteTimeout758=== RUN TestPendingClosureWriteTimeout759=== PAUSE TestPendingClosureWriteTimeout760=== RUN TestIsValidUploadKey761=== PAUSE TestIsValidUploadKey762=== RUN TestUploadHandlersRejectInvalidKeys763=== PAUSE TestUploadHandlersRejectInvalidKeys764=== RUN TestUploadHandlersRejectOversizedBody765=== PAUSE TestUploadHandlersRejectOversizedBody766=== RUN TestService_cleanupPendingClosuresHandler767=== PAUSE TestService_cleanupPendingClosuresHandler768=== RUN TestService_createPendingClosureHandler769=== PAUSE TestService_createPendingClosureHandler770=== RUN TestService_verifyS3Integrity771=== PAUSE TestService_verifyS3Integrity772=== RUN TestService_verifyS3ReuploadsStaleNarinfo773=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo774=== RUN TestCompleteMultipartUnregistered775=== PAUSE TestCompleteMultipartUnregistered776=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT777=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT778=== CONT TestReadRedirectUsesPublicS3URL779=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT780=== CONT TestFailedS3DeleteKeepsTombstone781=== CONT TestReadRedirectNar782=== CONT TestGetExistingObjectsLocksRows783=== CONT TestReadProxyRangeRequest784=== CONT TestParseSize785--- PASS: TestParseSize (0.00s)786=== CONT TestReadRedirectKeepsNarinfoProxied787=== CONT TestPresentNotReportedWhileGCDeletesClosure788=== CONT TestReadProxyDisabled789=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale790=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale791=== CONT TestReadProxyRootRedirectsToIndexHTML792=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh793=== CONT TestReadProxyConditionalGet794=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh795=== CONT TestPresentRefreshesOnlyStaleClosures796=== CONT TestReadProxyOutlastsServerWriteTimeout797=== CONT TestReadProxyHead798=== CONT TestReadProxyInvalidPath799=== CONT TestReadProxy404800=== CONT TestReadProxyNarStreaming801=== CONT TestRegisterCompletedObjectNeedsPendingRow802=== CONT TestSweepSkipsRowsLockedByPush803=== CONT TestReadProxyContentNegotiation804=== CONT TestReadProxyNarinfoAlreadyDecompressed805=== CONT TestReadProxyNarinfo806=== CONT TestIsValidCachePath807=== RUN TestIsValidCachePath/narinfo808=== CONT TestParseSingleRange809=== CONT TestAbortSucceeded810=== PAUSE TestIsValidCachePath/narinfo811--- PASS: TestAbortSucceeded (0.00s)812=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars813=== RUN TestParseSingleRange/none814=== CONT TestPresentReportsOnlyClosureRoots815=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars816=== RUN TestIsValidCachePath/nar_zst817=== PAUSE TestParseSingleRange/none818=== RUN TestParseSingleRange/unknown_unit819=== PAUSE TestIsValidCachePath/nar_zst820=== PAUSE TestParseSingleRange/unknown_unit821=== RUN TestIsValidCachePath/nar_xz822=== PAUSE TestIsValidCachePath/nar_xz823=== RUN TestIsValidCachePath/nar_bz2824=== RUN TestParseSingleRange/multi-range_ignored825=== PAUSE TestParseSingleRange/multi-range_ignored826=== RUN TestParseSingleRange/malformed_no_dash827=== PAUSE TestIsValidCachePath/nar_bz2828=== PAUSE TestParseSingleRange/malformed_no_dash829=== RUN TestParseSingleRange/malformed_both_empty830=== RUN TestIsValidCachePath/nar_uncompressed831=== PAUSE TestParseSingleRange/malformed_both_empty832=== RUN TestParseSingleRange/malformed_end_before_start833=== PAUSE TestParseSingleRange/malformed_end_before_start834=== PAUSE TestIsValidCachePath/nar_uncompressed835=== RUN TestParseSingleRange/closed836=== PAUSE TestParseSingleRange/closed837=== RUN TestIsValidCachePath/ls838=== RUN TestParseSingleRange/open-ended839=== PAUSE TestParseSingleRange/open-ended840=== PAUSE TestIsValidCachePath/ls841=== RUN TestParseSingleRange/end_clamped_to_size842=== RUN TestIsValidCachePath/log843=== PAUSE TestParseSingleRange/end_clamped_to_size844=== RUN TestParseSingleRange/suffix845=== PAUSE TestParseSingleRange/suffix846=== RUN TestParseSingleRange/suffix_exceeds_size847=== PAUSE TestParseSingleRange/suffix_exceeds_size848=== RUN TestParseSingleRange/single_byte849=== PAUSE TestParseSingleRange/single_byte850=== RUN TestParseSingleRange/start_past_EOF851=== PAUSE TestParseSingleRange/start_past_EOF852=== PAUSE TestIsValidCachePath/log853=== RUN TestIsValidCachePath/realisation854=== PAUSE TestIsValidCachePath/realisation855=== RUN TestParseSingleRange/start_far_past_EOF856=== RUN TestIsValidCachePath/nix-cache-info857=== PAUSE TestIsValidCachePath/nix-cache-info858=== RUN TestIsValidCachePath/index.html859=== PAUSE TestIsValidCachePath/index.html860=== RUN TestIsValidCachePath/traversal_parent861=== PAUSE TestParseSingleRange/start_far_past_EOF862=== PAUSE TestIsValidCachePath/traversal_parent863=== CONT TestCreatePin_ReservedPins864=== RUN TestIsValidCachePath/traversal_in_middle865=== PAUSE TestIsValidCachePath/traversal_in_middle866=== RUN TestIsValidCachePath/invalid_char_e867=== PAUSE TestIsValidCachePath/invalid_char_e868=== RUN TestIsValidCachePath/invalid_char_u869=== PAUSE TestIsValidCachePath/invalid_char_u870=== RUN TestIsValidCachePath/random_path871=== PAUSE TestIsValidCachePath/random_path872=== RUN TestIsValidCachePath/empty873=== PAUSE TestIsValidCachePath/empty874=== RUN TestIsValidCachePath/leading_slash875=== PAUSE TestIsValidCachePath/leading_slash876=== RUN TestIsValidCachePath/wrong_extension877=== PAUSE TestIsValidCachePath/wrong_extension878=== RUN TestIsValidCachePath/short_hash879=== PAUSE TestIsValidCachePath/short_hash880=== CONT TestPush_RejectsBadRequests8812026/11/11 23:34:35 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59017/oidc8822026/11/11 23:34:35 INFO Received uploads request method=POST path=/api/pending_closures8832026/11/11 23:34:36 INFO Aborted multipart uploads count=0 kept=08842026/11/11 23:34:36 WARN Force mode enabled - objects will be deleted immediately without grace period8852026/11/11 23:34:36 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."8862026/11/11 23:34:36 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."887--- PASS: TestFailedS3DeleteKeepsTombstone (1.21s)888=== CONT TestOrphanedObjectsGCStressTest889--- PASS: TestReadRedirectNar (1.24s)890=== CONT TestService_Rustfstest8912026/11/11 23:34:36 INFO Received uploads request method=POST path=/api/pending_closures892--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (1.57s)893=== CONT TestOrphanedObjectsGC894--- PASS: TestGetExistingObjectsLocksRows (1.86s)895=== CONT TestPresignedUploadRegisteredBeforeCommit896--- PASS: TestReadRedirectUsesPublicS3URL (2.08s)897=== CONT TestCompletedNarNotReofferedAcrossClosures898--- PASS: TestPresentRefreshesOnlyStaleClosures (2.22s)899=== CONT TestCompleteMultipartUpload_ErrorButObjectExists900--- PASS: TestReadProxyRangeRequest (2.35s)901=== CONT TestSharedNarBothUploadsComplete902--- PASS: TestReadProxyDisabled (2.49s)903=== CONT TestPush_SignsNarinfosOfItsPendingObjects904--- PASS: TestReadProxyHead (2.71s)905=== CONT TestObjectStatsUpdatedOncePerCommit906--- PASS: TestReadProxyRootRedirectsToIndexHTML (2.89s)907=== CONT TestPush_CompleteWaitsForCleanupOfThePush908--- PASS: TestReadProxyConditionalGet (3.11s)909=== CONT TestObjectStatsTrigger910--- PASS: TestReadRedirectKeepsNarinfoProxied (3.27s)911=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit912--- PASS: TestReadProxyInvalidPath (3.42s)913=== CONT TestPendingCleanupUsesOneCutoff914--- PASS: TestRegisterCompletedObjectNeedsPendingRow (3.59s)915=== CONT TestPush_RootsAreLockedInByteOrder916=== RUN TestPush_RejectsBadRequests/no_roots917=== PAUSE TestPush_RejectsBadRequests/no_roots918=== RUN TestPush_RejectsBadRequests/no_objects919=== PAUSE TestPush_RejectsBadRequests/no_objects920=== RUN TestPush_RejectsBadRequests/bad_root921=== PAUSE TestPush_RejectsBadRequests/bad_root922=== RUN TestPush_RejectsBadRequests/root_not_in_objects923=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects924=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded925--- PASS: TestReadProxyContentNegotiation (4.28s)926=== CONT TestMultipartCleanup9272026/11/11 23:34:39 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>928--- PASS: TestReadProxyNarinfo (4.43s)929=== CONT TestUploadHandlersRejectOversizedBody930=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure931=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure932=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart933=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart934=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts935=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts936=== CONT TestCompleteMultipartUnregistered937--- PASS: TestReadProxyNarStreaming (4.56s)938=== CONT TestServerTLSConfig939=== RUN TestServerTLSConfig/no_client_CA940=== PAUSE TestServerTLSConfig/no_client_CA941=== RUN TestServerTLSConfig/missing_CA_file942=== PAUSE TestServerTLSConfig/missing_CA_file943=== RUN TestServerTLSConfig/not_a_PEM_file944=== PAUSE TestServerTLSConfig/not_a_PEM_file945=== CONT TestService_verifyS3ReuploadsStaleNarinfo946=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed947=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed948=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed949=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed950=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost951=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost952=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed953=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed954=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed955=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed956=== CONT TestService_verifyS3Integrity957--- PASS: TestReadProxyNarinfoAlreadyDecompressed (4.70s)958=== CONT TestService_NativeMTLS9592026/11/11 23:34:39 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9602026/11/11 23:34:39 WARN Refused reserved pin name=worker-x86_64-linux9612026/11/11 23:34:39 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux9622026/11/11 23:34:39 INFO Received create pin request method=POST path=/api/pins/my-app9632026/11/11 23:34:39 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux964--- PASS: TestCreatePin_ReservedPins (5.07s)965=== CONT TestService_createPendingClosureHandler966--- PASS: TestReadProxy404 (5.20s)967=== CONT TestMetricsCommit9682026/11/11 23:34:40 INFO Aborted multipart uploads count=0 kept=09692026/11/11 23:34:40 WARN Force mode enabled - objects will be deleted immediately without grace period9702026/11/11 23:34:40 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=09712026/11/11 23:34:40 INFO Vacuumed table table=pending_closures9722026/11/11 23:34:40 INFO Vacuumed table table=pending_objects9732026/11/11 23:34:40 INFO Vacuumed table table=multipart_uploads9742026/11/11 23:34:40 INFO Vacuumed table table=closures9752026/11/11 23:34:40 INFO Vacuumed table table=objects9762026/11/11 23:34:40 INFO Aborted multipart uploads count=0 kept=09772026/11/11 23:34:40 WARN Force mode enabled - objects will be deleted immediately without grace period978--- PASS: TestPresentReportsOnlyClosureRoots (5.49s)979=== CONT TestGCTaskStore_CompletedAllowsNewTask980--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)981=== CONT TestService_cleanupPendingClosuresHandler9822026/11/11 23:34:40 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=09832026/11/11 23:34:40 INFO Vacuumed table table=pending_closures9842026/11/11 23:34:40 INFO Vacuumed table table=pending_objects9852026/11/11 23:34:40 INFO Vacuumed table table=multipart_uploads9862026/11/11 23:34:40 INFO Vacuumed table table=closures9872026/11/11 23:34:40 INFO Vacuumed table table=objects988--- PASS: TestSweepSkipsRowsLockedByPush (5.61s)989=== CONT TestPush_CompleteCommitsEveryRoot990--- PASS: TestService_Rustfstest (4.62s)991=== CONT TestPush_RepeatedRootCommitsOnce9922026/11/11 23:34:41 INFO Received uploads request method=POST path=/api/pending_closures9932026/11/11 23:34:41 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9942026/11/11 23:34:41 INFO Received uploads request method=POST path=/api/pending_closures995--- PASS: TestPresignedUploadRegisteredBeforeCommit (4.68s)996=== CONT TestGCTaskStore_PhaseUpdates997--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)998=== CONT TestGCTaskStore_StartNew999--- PASS: TestGCTaskStore_StartNew (0.00s)1000=== CONT TestGCTaskStore_GetReturnsLatest1001--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1002=== CONT TestGCEndsOnShutdown1003=== RUN TestGCEndsOnShutdown/before_the_run1004=== PAUSE TestGCEndsOnShutdown/before_the_run1005=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1006=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1007=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1008=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1009=== CONT TestMetricsInventory10102026/11/11 23:34:41 INFO Received uploads request method=POST path=/api/pending_closures10112026/11/11 23:34:42 INFO Received uploads request method=POST path=/api/pending_closures10122026/11/11 23:34:42 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10132026/11/11 23:34:42 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDU4MTQ1NDUtNTBmMC00NDM2LWIwNTUtMWZiYTFlMDMwMmU1LjBkNTI3OTVlLTZjNWQtNDZkMC1hZTM3LTI0Y2EyNDMyMzIwN3gxNzk0NDQwMDgyMTg3MjM5MDAw10142026/11/11 23:34:42 INFO Received uploads request method=POST path=/api/pending_closures1015=== NAME TestOrphanedObjectsGC1016 orphaned_objects_gc_test.go:287: GC Test Summary:1017 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1018 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1019 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1020 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1021 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1022--- PASS: TestOrphanedObjectsGC (6.42s)1023=== CONT TestCommitRacingPendingCleanupKeepsObjects10242026/11/11 23:34:42 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=NDU4MTQ1NDUtNTBmMC00NDM2LWIwNTUtMWZiYTFlMDMwMmU1LjBkNTI3OTVlLTZjNWQtNDZkMC1hZTM3LTI0Y2EyNDMyMzIwN3gxNzk0NDQwMDgyMTg3MjM5MDAw parts=11025--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (5.79s)1026=== CONT TestNARDeduplicationMetadataUploadBug10272026/11/11 23:34:42 INFO Received uploads request method=POST path=/api/pending_closures1028--- PASS: TestReadProxyOutlastsServerWriteTimeout (8.20s)1029=== CONT TestPushWaitsForSweepHoldingRow10302026/11/11 23:34:43 INFO Received push request method=POST path=/api/pushes10312026/11/11 23:34:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10322026/11/11 23:34:43 INFO Signed narinfos id=1 count=110332026/11/11 23:34:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10342026/11/11 23:34:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10352026/11/11 23:34:43 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10362026/11/11 23:34:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10372026/11/11 23:34:43 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10382026/11/11 23:34:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10392026/11/11 23:34:43 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110402026/11/11 23:34:43 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10412026/11/11 23:34:43 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1042--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (5.96s)1043=== CONT TestCreatePendingClosureRejectsOversizedNAR10442026/11/11 23:34:43 INFO Received uploads request method=POST path=/api/pending_closures1045--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.01s)1046=== CONT TestCacheConfigHandlerMaxNarSize1047--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1048=== CONT TestSweepRechecksPendingAfterLocking1049--- PASS: TestObjectStatsUpdatedOncePerCommit (6.27s)1050=== CONT TestGCTaskStore_GetEmpty1051--- PASS: TestGCTaskStore_GetEmpty (0.00s)1052=== CONT TestGCTaskStore_ConflictDifferentParams1053--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1054=== CONT TestGCTaskStore_DeduplicateSameParams1055--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1056=== CONT TestPendingClosureWriteTimeout1057=== RUN TestPendingClosureWriteTimeout/empty1058=== PAUSE TestPendingClosureWriteTimeout/empty1059=== RUN TestPendingClosureWriteTimeout/400_objects1060=== PAUSE TestPendingClosureWriteTimeout/400_objects1061=== RUN TestPendingClosureWriteTimeout/670k_objects1062=== PAUSE TestPendingClosureWriteTimeout/670k_objects1063=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1064=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1065=== CONT TestUploadHandlersRejectInvalidKeys1066=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1067=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1068=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1069=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1070=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1071=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1072=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1073=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1074=== CONT TestIsValidUploadKey1075=== RUN TestIsValidUploadKey/narinfo1076=== PAUSE TestIsValidUploadKey/narinfo1077=== RUN TestIsValidUploadKey/nar_zst1078=== PAUSE TestIsValidUploadKey/nar_zst1079=== RUN TestIsValidUploadKey/nar_xz1080=== PAUSE TestIsValidUploadKey/nar_xz1081=== RUN TestIsValidUploadKey/nar_plain1082=== PAUSE TestIsValidUploadKey/nar_plain1083=== RUN TestIsValidUploadKey/listing1084=== PAUSE TestIsValidUploadKey/listing1085=== RUN TestIsValidUploadKey/build_log1086=== PAUSE TestIsValidUploadKey/build_log1087=== RUN TestIsValidUploadKey/build_log_home-manager_file1088=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1089=== RUN TestIsValidUploadKey/build_log_plus_in_name1090=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1091=== RUN TestIsValidUploadKey/build_log_question_mark1092=== PAUSE TestIsValidUploadKey/build_log_question_mark1093=== RUN TestIsValidUploadKey/build_log_equals1094=== PAUSE TestIsValidUploadKey/build_log_equals1095=== RUN TestIsValidUploadKey/realisation1096=== PAUSE TestIsValidUploadKey/realisation1097=== RUN TestIsValidUploadKey/realisation_plus_in_output1098=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1099=== RUN TestIsValidUploadKey/nix-cache-info1100=== PAUSE TestIsValidUploadKey/nix-cache-info1101=== RUN TestIsValidUploadKey/index.html1102=== PAUSE TestIsValidUploadKey/index.html1103=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1104=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1105=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1106=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1107=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1108=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1109=== RUN TestIsValidUploadKey/traversal1110=== PAUSE TestIsValidUploadKey/traversal1111=== RUN TestIsValidUploadKey/traversal_nar1112=== PAUSE TestIsValidUploadKey/traversal_nar1113=== RUN TestIsValidUploadKey/absolute1114=== PAUSE TestIsValidUploadKey/absolute1115=== RUN TestIsValidUploadKey/empty_key1116=== PAUSE TestIsValidUploadKey/empty_key1117=== RUN TestIsValidUploadKey/unknown_type1118=== PAUSE TestIsValidUploadKey/unknown_type1119=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle11202026/11/11 23:34:43 INFO Received push request method=POST path=/api/pushes11212026/11/11 23:34:44 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11222026-11-11 23:34:44.406 UTC [86927] ERROR: Push does not exist: id=111232026-11-11 23:34:44.406 UTC [86927] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE11242026-11-11 23:34:44.406 UTC [86927] STATEMENT: SELECT commit_push($1)1125--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (6.65s)1126=== CONT TestProxyWriteTimeout1127=== RUN TestProxyWriteTimeout/narinfo1128=== PAUSE TestProxyWriteTimeout/narinfo1129=== RUN TestProxyWriteTimeout/1_GiB_nar1130=== PAUSE TestProxyWriteTimeout/1_GiB_nar1131=== RUN TestProxyWriteTimeout/10_GiB_nar1132=== PAUSE TestProxyWriteTimeout/10_GiB_nar1133=== RUN TestProxyWriteTimeout/unknown_size1134=== PAUSE TestProxyWriteTimeout/unknown_size1135=== CONT TestEnsureAbortUploadsRule1136=== CONT TestGCBugBareHashReferences1137--- PASS: TestObjectStatsTrigger (6.46s)11382026/11/11 23:34:44 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=NDU4MTQ1NDUtNTBmMC00NDM2LWIwNTUtMWZiYTFlMDMwMmU1LmFlZDliOGVmLTc4ODQtNDM4Yy04NjUwLTRkYzU5Y2ZiNmRlZXgxNzk0NDQwMDgxNzI3MDIyMDAw parts=1211392026/11/11 23:34:44 INFO Received uploads request method=POST path=/api/pending_closures1140--- PASS: TestCompletedNarNotReofferedAcrossClosures (7.53s)1141=== CONT TestGenerateLandingPage1142--- PASS: TestGenerateLandingPage (0.00s)1143=== CONT TestDeleteClosuresRacingPins11442026/11/11 23:34:44 INFO Received push request method=POST path=/api/pushes11452026/11/11 23:34:44 INFO Received complete push request method=POST path=/api/pushes/1/complete11462026/11/11 23:34:44 INFO Completed push id=1 objects=4 duration=48.070667ms11472026/11/11 23:34:44 INFO Received push request method=POST path=/api/pushes11482026/11/11 23:34:44 INFO Aborted multipart uploads count=0 kept=011492026/11/11 23:34:45 WARN Force mode enabled - objects will be deleted immediately without grace period11502026/11/11 23:34:45 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=011512026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures11522026/11/11 23:34:45 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11532026/11/11 23:34:45 INFO Vacuumed table table=pending_closures11542026/11/11 23:34:45 INFO Vacuumed table table=pending_objects11552026/11/11 23:34:45 INFO Vacuumed table table=multipart_uploads11562026/11/11 23:34:45 INFO Vacuumed table table=closures11572026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures11582026/11/11 23:34:45 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NDU4MTQ1NDUtNTBmMC00NDM2LWIwNTUtMWZiYTFlMDMwMmU1LjUxMjA0MTMyLTE1YjgtNGE5Yi04NmZhLTVjZWIxNGY1OGE2MHgxNzk0NDQwMDgyODg1NDU4MDAw parts=1211592026/11/11 23:34:45 INFO Vacuumed table table=objects11602026/11/11 23:34:45 INFO Received complete push request method=POST path=/api/pushes/2/complete11612026/11/11 23:34:45 INFO Completed push id=2 objects=4 duration=11.850125ms1162--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (7.08s)11632026/11/11 23:34:45 INFO Received cleanup request method=DELETE path=/api/pending_closures1164=== CONT TestService_readinessHandler11652026/11/11 23:34:45 INFO Received push request method=POST path=/api/pushes11662026-11-11 23:34:45.654 UTC [86941] ERROR: could not obtain lock on row in relation "closures"11672026-11-11 23:34:45.654 UTC [86941] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11682026-11-11 23:34:45.662 UTC [86941] ERROR: could not obtain lock on row in relation "closures"11692026-11-11 23:34:45.662 UTC [86941] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11702026-11-11 23:34:45.669 UTC [86941] ERROR: could not obtain lock on row in relation "closures"11712026-11-11 23:34:45.669 UTC [86941] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11722026-11-11 23:34:45.672 UTC [86941] ERROR: could not obtain lock on row in relation "closures"11732026-11-11 23:34:45.672 UTC [86941] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT11742026-11-11 23:34:45.675 UTC [86941] ERROR: could not obtain lock on row in relation "closures"11752026-11-11 23:34:45.675 UTC [86941] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1176--- PASS: TestPush_RootsAreLockedInByteOrder (7.23s)1177=== CONT TestGCAdvisoryLockBlocksConcurrentRun11782026/11/11 23:34:45 INFO Received uploads request method=POST path=/api/pending_closures1179--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (7.38s)1180=== CONT TestService_healthCheckHandler11812026/11/11 23:34:46 INFO Received uploads request method=POST path=/api/pending_closures11822026/11/11 23:34:46 INFO Received cleanup request method=DELETE path=/api/pending_closures11832026/11/11 23:34:46 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket43/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11842026/11/11 23:34:46 INFO Aborted multipart uploads count=0 kept=111852026/11/11 23:34:46 INFO Received cleanup request method=DELETE path=/api/pending_closures11862026/11/11 23:34:46 INFO Aborted multipart uploads count=1 kept=01187--- PASS: TestMultipartCleanup (7.41s)1188=== CONT TestLeadEndsOnShutdown11892026/11/11 23:34:46 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11902026/11/11 23:34:46 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst1191--- PASS: TestCompleteMultipartUnregistered (7.34s)1192=== CONT TestGracefulShutdownDrainsInflight11932026/11/11 23:34:46 INFO Starting HTTP server address=127.0.0.1:5911411942026/11/11 23:34:46 INFO Shutdown signal received, draining in-flight requests timeout=10s1195--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1196=== CONT TestGCTaskStore_Fail1197--- PASS: TestGCTaskStore_Fail (0.00s)1198=== CONT TestForceGCDuringPushOffersSweptObject1199=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1200=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1201=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1202=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1203=== CONT TestDeduplicatedObjectsRecordedAsPending12042026/11/11 23:34:47 INFO Received uploads request method=POST path=/api/pending_closures12052026/11/11 23:34:47 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12062026/11/11 23:34:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12072026/11/11 23:34:47 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1208--- PASS: TestService_NativeMTLS (7.86s)1209=== CONT TestLeadGenerationGrowsWithEveryGrant12102026/11/11 23:34:47 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=NDU4MTQ1NDUtNTBmMC00NDM2LWIwNTUtMWZiYTFlMDMwMmU1LjRkODYyNTljLTJkZDEtNDRlZi1hMjQxLWIyODY3OGIyNjhhMngxNzk0NDQwMDgyOTYxNjYwMDAw parts=121211--- PASS: TestSharedNarBothUploadsComplete (10.38s)1212=== CONT TestPushDedupSurvivesConcurrentGC12132026/11/11 23:34:47 INFO Received uploads request method=POST path=/api/pending_closures12142026/11/11 23:34:47 INFO Received uploads request method=POST path=/api/pending_closures12152026/11/11 23:34:47 INFO Received uploads request method=POST path=/api/pending_closures12162026/11/11 23:34:48 INFO Received push request method=POST path=/api/pushes12172026/11/11 23:34:48 INFO Received complete push request method=POST path=/api/pushes/1/complete12182026/11/11 23:34:48 INFO Completed push id=1 objects=4 duration=44.383542ms12192026/11/11 23:34:48 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12202026/11/11 23:34:48 INFO Completed upload id=2 objects=2 duration=585.208µs1221--- PASS: TestMetricsCommit (8.41s)1222=== CONT TestGCSweepSkipsPendingObjects12232026/11/11 23:34:48 INFO Received cleanup request method=DELETE path=/api/pending_closures12242026/11/11 23:34:48 INFO Aborted multipart uploads count=0 kept=012252026/11/11 23:34:48 INFO Received uploads request method=POST path=/api/pending_closures12262026/11/11 23:34:48 INFO Received cleanup request method=DELETE path=/api/pending_closures12272026/11/11 23:34:48 INFO Aborted multipart uploads count=1 kept=012282026/11/11 23:34:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12292026-11-11 23:34:48.994 UTC [86921] ERROR: Closure does not exist: id=112302026-11-11 23:34:48.994 UTC [86921] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE12312026-11-11 23:34:48.994 UTC [86921] STATEMENT: -- name: CommitPendingClosure :one1232 SELECT commit_pending_closure($1::bigint)::bigint1233 1234--- PASS: TestService_cleanupPendingClosuresHandler (8.62s)1235=== CONT TestGCMetrics12362026/11/11 23:34:49 INFO Received push request method=POST path=/api/pushes12372026/11/11 23:34:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete12382026/11/11 23:34:49 INFO Received complete push request method=POST path=/api/pushes/1/complete12392026/11/11 23:34:49 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=NDU4MTQ1NDUtNTBmMC00NDM2LWIwNTUtMWZiYTFlMDMwMmU1LmViNzY3YzM0LThjOTctNDVmYi1hMDg0LWI2MDkzNDNlZWY2M3gxNzk0NDQwMDg3MTE3NTA1MDAw parts=1012402026/11/11 23:34:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12412026/11/11 23:34:49 INFO Completed push id=1 objects=6 duration=76.22075ms1242--- PASS: TestPush_CompleteCommitsEveryRoot (8.99s)1243=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12442026/11/11 23:34:49 INFO Completed upload id=1 objects=2 duration=44.910916ms12452026/11/11 23:34:49 INFO Received uploads request method=POST path=/api/pending_closures12462026/11/11 23:34:49 INFO Received uploads request method=POST path=/api/pending_closures12472026/11/11 23:34:49 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo12482026/11/11 23:34:49 WARN Found objects in DB but missing from S3, will re-upload count=11249--- PASS: TestService_verifyS3Integrity (10.08s)1250=== CONT TestGCSweepDeliversEachKeyOnce12512026/11/11 23:34:49 INFO Received push request method=POST path=/api/pushes12522026/11/11 23:34:49 INFO Received complete push request method=POST path=/api/pushes/1/complete12532026/11/11 23:34:49 INFO Completed push id=1 objects=4 duration=35.695ms1254--- PASS: TestPush_RepeatedRootCommitsOnce (9.15s)1255=== CONT TestSkippedUploadsHandler12562026/11/11 23:34:49 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001257--- PASS: TestSkippedUploadsHandler (0.01s)1258=== CONT TestTombstonedObjectOfferedWithoutWaiting12592026/11/11 23:34:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1260--- PASS: TestMetricsInventory (8.75s)1261=== CONT TestPush_OverlappingRootsStoreOneRowPerKey12622026/11/11 23:34:50 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=NDU4MTQ1NDUtNTBmMC00NDM2LWIwNTUtMWZiYTFlMDMwMmU1LjJmOTJlNWQ1LWI5ODQtNGJmNy05OWVhLTMzZWNiNzdjYzYzOHgxNzk0NDQwMDg3OTgzNzA0MDAw parts=1012632026/11/11 23:34:50 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete12642026/11/11 23:34:50 INFO Completed upload id=1 objects=2 duration=24.059416ms12652026/11/11 23:34:50 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000012662026/11/11 23:34:50 INFO Received uploads request method=POST path=/api/pending_closures12672026/11/11 23:34:50 INFO Starting cleanup of old closures method=DELETE path=/api/closures12682026/11/11 23:34:50 INFO Aborted multipart uploads count=0 kept=012692026/11/11 23:34:50 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=012702026/11/11 23:34:50 INFO Vacuumed table table=pending_closures12712026/11/11 23:34:50 INFO Vacuumed table table=pending_objects12722026/11/11 23:34:50 INFO Vacuumed table table=multipart_uploads12732026/11/11 23:34:50 INFO Vacuumed table table=closures12742026/11/11 23:34:50 INFO Vacuumed table table=objects12752026/11/11 23:34:50 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001276--- PASS: TestService_createPendingClosureHandler (10.68s)1277=== CONT TestLeadIncumbentAnnouncesAtOnce1278=== NAME TestNARDeduplicationMetadataUploadBug1279 metadata_upload_test.go:48: First store path: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestNARDeduplicationMetadataUploadBug4103108306/001/store/8xzgn68acrzbxmc22ax5pf1sqk889g9i-file1.txt12802026/11/11 23:34:51 INFO Received push request method=POST path=/api/pushes12812026/11/11 23:34:51 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12822026/11/11 23:34:51 INFO Uploading 8xzgn68acrzbxmc22ax5pf1sqk889g9i-file1.txt (160B)12832026/11/11 23:34:51 INFO Aborted multipart uploads count=0 kept=012842026/11/11 23:34:51 WARN Force mode enabled - objects will be deleted immediately without grace period12852026/11/11 23:34:51 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=012862026/11/11 23:34:51 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12872026/11/11 23:34:51 INFO Vacuumed table table=pending_closures12882026/11/11 23:34:51 WARN Failed to register uploaded object key=8xzgn68acrzbxmc22ax5pf1sqk889g9i.ls error="server returned 404: 404 page not found\n"12892026/11/11 23:34:51 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12902026/11/11 23:34:51 INFO Signed narinfos id=1 count=112912026/11/11 23:34:51 INFO Uploading 1 narinfos12922026/11/11 23:34:51 INFO Vacuumed table table=pending_objects12932026/11/11 23:34:51 INFO Vacuumed table table=multipart_uploads12942026/11/11 23:34:51 INFO Received complete push request method=POST path=/api/pushes/1/complete12952026/11/11 23:34:51 WARN Failed to register uploaded object key=8xzgn68acrzbxmc22ax5pf1sqk889g9i.narinfo error="server returned 404: 404 page not found\n"12962026/11/11 23:34:51 INFO Vacuumed table table=closures12972026/11/11 23:34:51 INFO Vacuumed table table=objects12982026/11/11 23:34:51 INFO Completed push id=1 objects=3 duration=33.483417ms12992026/11/11 23:34:51 INFO Upload complete. (270ms)1300 metadata_upload_test.go:54: Retrieved narinfo from S3:1301 StorePath: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestNARDeduplicationMetadataUploadBug4103108306/001/store/8xzgn68acrzbxmc22ax5pf1sqk889g9i-file1.txt1302--- PASS: TestCommitRacingPendingCleanupKeepsObjects (8.36s)1303=== CONT TestClientCADerivations1304=== NAME TestNARDeduplicationMetadataUploadBug1305 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1306 Compression: zstd1307 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1308 NarSize: 1601309 References: 1310 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1311 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1312 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1313 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}13142026/11/11 23:34:51 INFO Aborted multipart uploads count=1 kept=013152026/11/11 23:34:51 INFO Received uploads request method=POST path=/api/pending_closures13162026/11/11 23:34:51 INFO Received cleanup request method=DELETE path=/api/pending_closures13172026/11/11 23:34:51 INFO Aborted multipart uploads count=1 kept=01318--- PASS: TestPendingCleanupUsesOneCutoff (13.02s)1319=== CONT TestLeadUnannouncedStandbyYieldsToIncumbent1320=== NAME TestNARDeduplicationMetadataUploadBug1321 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestNARDeduplicationMetadataUploadBug4103108306/001/store/0kh2jlkd844zs18jjk9r03qklp3vmj1i-file2.txt13222026/11/11 23:34:51 INFO Received push request method=POST path=/api/pushes13232026/11/11 23:34:51 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)13242026/11/11 23:34:51 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign13252026/11/11 23:34:51 WARN Failed to register uploaded object key=0kh2jlkd844zs18jjk9r03qklp3vmj1i.ls error="server returned 404: 404 page not found\n"13262026/11/11 23:34:51 INFO Signed narinfos id=2 count=113272026/11/11 23:34:51 INFO Uploading 1 narinfos13282026/11/11 23:34:51 INFO Received complete push request method=POST path=/api/pushes/2/complete13292026/11/11 23:34:51 WARN Failed to register uploaded object key=0kh2jlkd844zs18jjk9r03qklp3vmj1i.narinfo error="server returned 404: 404 page not found\n"13302026/11/11 23:34:51 INFO Completed push id=2 objects=3 duration=20.503833ms13312026/11/11 23:34:51 INFO Upload complete. (199ms)1332 metadata_upload_test.go:76: Retrieved narinfo from S3:1333 StorePath: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestNARDeduplicationMetadataUploadBug4103108306/001/store/0kh2jlkd844zs18jjk9r03qklp3vmj1i-file2.txt1334 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1335 Compression: zstd1336 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1337 NarSize: 1601338 References: 1339 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1340 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1341 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1342 {"version":1,"root":{"type":"regular","size":44}}1343--- PASS: TestPushWaitsForSweepHoldingRow (8.71s)1344=== CONT TestConnectWaitsForAPeerMigration13452026/11/11 23:34:51 INFO Aborted multipart uploads count=0 kept=01346--- PASS: TestNARDeduplicationMetadataUploadBug (8.91s)1347=== CONT TestResolveDBConnectionString13482026/11/11 23:34:51 WARN Force mode enabled - objects will be deleted immediately without grace period1349=== RUN TestResolveDBConnectionString/flag_wins1350=== PAUSE TestResolveDBConnectionString/flag_wins1351=== RUN TestResolveDBConnectionString/file_when_flag_empty1352=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1353=== RUN TestResolveDBConnectionString/missing_file_is_an_error1354=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1355=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1356=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1357=== RUN TestResolveDBConnectionString/nothing_configured1358=== PAUSE TestResolveDBConnectionString/nothing_configured1359=== CONT TestLeadElectsOneAndHandsOver13602026/11/11 23:34:51 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=013612026/11/11 23:34:51 INFO Vacuumed table table=pending_closures13622026/11/11 23:34:51 INFO Vacuumed table table=pending_objects13632026/11/11 23:34:51 INFO Vacuumed table table=multipart_uploads13642026/11/11 23:34:51 INFO Vacuumed table table=closures13652026/11/11 23:34:52 INFO Vacuumed table table=objects1366--- PASS: TestSweepRechecksPendingAfterLocking (8.71s)1367=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock13682026/11/11 23:34:52 INFO Received uploads request method=POST path=/api/pending_closures13692026/11/11 23:34:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete13702026/11/11 23:34:52 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket58 days=21371--- PASS: TestEnsureAbortUploadsRule (8.35s)1372=== CONT TestClientFallsBackToClosures1373--- PASS: TestGCBugBareHashReferences (8.78s)1374=== CONT TestPinProtectsFromGC13752026/11/11 23:34:53 WARN readiness check failed error="closed pool"1376--- PASS: TestService_readinessHandler (8.35s)1377=== CONT TestClientPushesUseOnePush13782026/11/11 23:34:53 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld5 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1379--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (8.26s)1380=== CONT TestClientWithDependencies1381--- PASS: TestService_healthCheckHandler (8.28s)1382=== CONT TestClientMultipleUploads13832026/11/11 23:34:54 INFO lead: acquired remote=192.0.2.1:1234 generation=113842026/11/11 23:34:54 INFO Received uploads request method=POST path=/api/pending_closures1385--- PASS: TestDeduplicatedObjectsRecordedAsPending (8.11s)1386=== CONT TestService_AuthMiddleware_OIDC13872026/11/11 23:34:54 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59152/oidc13882026/11/11 23:34:55 INFO Received uploads request method=POST path=/api/pending_closures1389=== NAME TestOrphanedObjectsGCStressTest1390 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains13912026/11/11 23:34:55 INFO lead: acquired remote=192.0.2.1:1234 generation=11392 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion13932026/11/11 23:34:55 INFO Aborted multipart uploads count=0 kept=013942026/11/11 23:34:55 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=013952026/11/11 23:34:55 INFO Vacuumed table table=pending_closures13962026/11/11 23:34:55 INFO Vacuumed table table=pending_objects13972026/11/11 23:34:55 INFO Vacuumed table table=multipart_uploads13982026/11/11 23:34:55 INFO Vacuumed table table=closures13992026/11/11 23:34:55 INFO Vacuumed table table=objects14002026/11/11 23:34:55 INFO Aborted multipart uploads count=0 kept=014012026/11/11 23:34:55 WARN Force mode enabled - objects will be deleted immediately without grace period14022026/11/11 23:34:55 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=014032026/11/11 23:34:55 INFO Vacuumed table table=pending_closures14042026/11/11 23:34:55 INFO Vacuumed table table=pending_objects14052026/11/11 23:34:55 INFO Vacuumed table table=multipart_uploads14062026/11/11 23:34:55 INFO Vacuumed table table=closures14072026/11/11 23:34:55 INFO Vacuumed table table=objects14082026/11/11 23:34:55 INFO Received uploads request method=POST path=/api/pending_closures1409--- PASS: TestPushDedupSurvivesConcurrentGC (7.99s)1410=== CONT TestClientSharedPathCommittedMidPush14112026/11/11 23:34:55 INFO lead: released remote=192.0.2.1:1234 generation=11412--- PASS: TestLeadEndsOnShutdown (9.10s)1413=== CONT TestClientIntegration14142026/11/11 23:34:55 INFO Aborted multipart uploads count=0 kept=014152026/11/11 23:34:55 WARN Force mode enabled - objects will be deleted immediately without grace period14162026/11/11 23:34:55 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=014172026/11/11 23:34:55 INFO Vacuumed table table=pending_closures14182026/11/11 23:34:55 INFO Vacuumed table table=pending_objects14192026/11/11 23:34:55 INFO Vacuumed table table=multipart_uploads14202026/11/11 23:34:55 INFO Vacuumed table table=closures14212026/11/11 23:34:55 INFO Vacuumed table table=objects1422--- PASS: TestGCSweepSkipsPendingObjects (7.30s)1423=== CONT TestClientErrorHandling1424=== RUN TestClientErrorHandling/InvalidStorePath1425=== PAUSE TestClientErrorHandling/InvalidStorePath1426=== RUN TestClientErrorHandling/InvalidAuthToken1427=== PAUSE TestClientErrorHandling/InvalidAuthToken1428=== RUN TestClientErrorHandling/ServerNotAvailable1429=== PAUSE TestClientErrorHandling/ServerNotAvailable1430=== CONT TestService_ReadAuthMiddleware14312026/11/11 23:34:55 INFO Aborted multipart uploads count=0 kept=014322026/11/11 23:34:55 WARN Force mode enabled - objects will be deleted immediately without grace period14332026/11/11 23:34:55 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=014342026/11/11 23:34:55 INFO Vacuumed table table=pending_closures14352026/11/11 23:34:55 INFO Vacuumed table table=pending_objects14362026/11/11 23:34:55 INFO Vacuumed table table=multipart_uploads14372026/11/11 23:34:55 INFO Vacuumed table table=closures14382026/11/11 23:34:55 INFO Vacuumed table table=objects1439--- PASS: TestGCMetrics (6.90s)1440=== CONT TestService_ReadScope_PublicByDefault14412026/11/11 23:34:56 INFO Received uploads request method=POST path=/api/pending_closures1442--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (6.93s)1443=== CONT TestCacheStatsHandler14442026/11/11 23:34:56 INFO lead: released remote=192.0.2.1:1234 generation=114452026/11/11 23:34:56 INFO lead: acquired remote=192.0.2.1:1234 generation=214462026/11/11 23:34:56 INFO Aborted multipart uploads count=0 kept=014472026/11/11 23:34:56 WARN Force mode enabled - objects will be deleted immediately without grace period14482026/11/11 23:34:56 INFO Received uploads request method=POST path=/api/pending_closures1449--- PASS: TestTombstonedObjectOfferedWithoutWaiting (6.92s)1450=== CONT TestService_RequireScope_OIDC14512026/11/11 23:34:56 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59162/oidc14522026/11/11 23:34:57 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=014532026/11/11 23:34:57 INFO Received push request method=POST path=/api/pushes14542026/11/11 23:34:57 INFO Vacuumed table table=pending_closures14552026/11/11 23:34:57 INFO Vacuumed table table=pending_objects14562026/11/11 23:34:57 INFO Vacuumed table table=multipart_uploads14572026/11/11 23:34:57 INFO Vacuumed table table=closures14582026/11/11 23:34:57 INFO Vacuumed table table=objects1459--- PASS: TestGCSweepDeliversEachKeyOnce (7.73s)1460=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1461--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (7.07s)1462=== CONT TestCacheConfigHandler1463=== RUN TestCacheConfigHandler/full_config,_no_issuer1464=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1465=== RUN TestCacheConfigHandler/no_cache_url_configured1466=== PAUSE TestCacheConfigHandler/no_cache_url_configured1467=== RUN TestCacheConfigHandler/no_signing_keys1468=== PAUSE TestCacheConfigHandler/no_signing_keys1469=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1470=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1471=== CONT TestService_AuthMiddleware_MTLSProxyHeader1472--- PASS: TestDeleteClosuresRacingPins (12.90s)1473=== CONT TestService_AuthMiddleware14742026/11/11 23:34:57 INFO lead: acquired remote=192.0.2.1:1234 generation=114752026/11/11 23:34:57 INFO lead: released remote=192.0.2.1:1234 generation=11476--- PASS: TestLeadIncumbentAnnouncesAtOnce (6.84s)1477=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale14782026/11/11 23:34:57 INFO lead: released remote=192.0.2.1:1234 generation=214792026/11/11 23:34:57 INFO lead: acquired remote=192.0.2.1:1234 generation=314802026/11/11 23:34:57 INFO lead: released remote=192.0.2.1:1234 generation=31481--- PASS: TestLeadGenerationGrowsWithEveryGrant (10.14s)1482=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh14832026/11/11 23:34:57 WARN Rate limiter enabled after throttle name=s3-test rate=514842026/11/11 23:34:57 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1485=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1486 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101487 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001488--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (13.76s)1489=== CONT TestParseSingleRange/none1490=== CONT TestParseSingleRange/end_clamped_to_size1491=== CONT TestParseSingleRange/open-ended1492=== CONT TestParseSingleRange/closed1493=== CONT TestParseSingleRange/malformed_end_before_start1494=== CONT TestParseSingleRange/malformed_both_empty1495=== CONT TestParseSingleRange/malformed_no_dash1496=== CONT TestParseSingleRange/multi-range_ignored1497=== CONT TestParseSingleRange/unknown_unit1498=== CONT TestParseSingleRange/start_past_EOF1499=== CONT TestParseSingleRange/suffix_exceeds_size1500=== CONT TestParseSingleRange/single_byte1501=== CONT TestParseSingleRange/suffix1502=== CONT TestParseSingleRange/start_far_past_EOF1503--- PASS: TestParseSingleRange (0.00s)1504 --- PASS: TestParseSingleRange/none (0.00s)1505 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1506 --- PASS: TestParseSingleRange/open-ended (0.00s)1507 --- PASS: TestParseSingleRange/closed (0.00s)1508 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1509 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1510 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1511 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1512 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1513 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1514 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1515 --- PASS: TestParseSingleRange/single_byte (0.00s)1516 --- PASS: TestParseSingleRange/suffix (0.00s)1517 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1518=== CONT TestIsValidCachePath/narinfo1519=== CONT TestIsValidCachePath/index.html1520=== CONT TestIsValidCachePath/short_hash1521=== CONT TestIsValidCachePath/wrong_extension1522=== CONT TestIsValidCachePath/leading_slash1523=== CONT TestIsValidCachePath/empty1524=== CONT TestIsValidCachePath/random_path1525=== CONT TestIsValidCachePath/invalid_char_u1526=== CONT TestIsValidCachePath/invalid_char_e1527=== CONT TestIsValidCachePath/traversal_in_middle1528=== CONT TestIsValidCachePath/traversal_parent1529=== CONT TestIsValidCachePath/nar_uncompressed1530=== CONT TestIsValidCachePath/nix-cache-info1531=== CONT TestIsValidCachePath/realisation1532=== CONT TestIsValidCachePath/log1533=== CONT TestIsValidCachePath/ls1534=== CONT TestIsValidCachePath/nar_xz1535=== CONT TestIsValidCachePath/nar_bz21536=== CONT TestIsValidCachePath/nar_zst1537=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1538--- PASS: TestIsValidCachePath (0.01s)1539 --- PASS: TestIsValidCachePath/narinfo (0.00s)1540 --- PASS: TestIsValidCachePath/index.html (0.00s)1541 --- PASS: TestIsValidCachePath/short_hash (0.00s)1542 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1543 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1544 --- PASS: TestIsValidCachePath/empty (0.00s)1545 --- PASS: TestIsValidCachePath/random_path (0.00s)1546 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1547 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1548 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1549 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1550 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1551 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1552 --- PASS: TestIsValidCachePath/realisation (0.00s)1553 --- PASS: TestIsValidCachePath/log (0.00s)1554 --- PASS: TestIsValidCachePath/ls (0.00s)1555 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1556 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1557 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1558 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1559=== CONT TestPush_RejectsBadRequests/no_roots15602026/11/11 23:34:57 INFO Received push request method=POST path=/api/pushes1561=== CONT TestPush_RejectsBadRequests/root_not_in_objects15622026/11/11 23:34:57 INFO Received push request method=POST path=/api/pushes1563=== CONT TestPush_RejectsBadRequests/bad_root15642026/11/11 23:34:57 INFO Received push request method=POST path=/api/pushes1565=== CONT TestPush_RejectsBadRequests/no_objects15662026/11/11 23:34:57 INFO Received push request method=POST path=/api/pushes1567--- PASS: TestPush_RejectsBadRequests (3.75s)1568 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1569 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.01s)1570 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1571 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1572=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure15732026/11/11 23:34:57 INFO Received uploads request method=POST path=/15742026/11/11 23:34:57 INFO lead: acquired remote=192.0.2.1:1234 generation=11575=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart15762026/11/11 23:34:58 INFO Received complete multipart upload request method=POST path=/1577=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts15782026/11/11 23:34:58 INFO Received request for more parts method=POST path=/1579--- PASS: TestUploadHandlersRejectOversizedBody (0.03s)1580 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.30s)1581 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1582 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1583=== CONT TestServerTLSConfig/no_client_CA1584=== CONT TestServerTLSConfig/not_a_PEM_file1585=== CONT TestServerTLSConfig/missing_CA_file1586--- PASS: TestServerTLSConfig (0.00s)1587 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1588 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.02s)1589 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1590=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed15912026/11/11 23:34:58 INFO lead: acquired remote=192.0.2.1:1234 generation=11592=== NAME TestClientCADerivations1593 client_ca_test.go:136: Built CA derivation: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientCADerivations1881975410/001/store/4jr4n05q2mgxh7pk9g1x5wcyjw39xbxx-ca-test1594 client_ca_test.go:139: Found 1 dependencies (including self)15952026/11/11 23:34:58 INFO lead: released remote=192.0.2.1:1234 generation=115962026/11/11 23:34:58 INFO Received push request method=POST path=/api/pushes15972026/11/11 23:34:58 INFO lead: acquired remote=192.0.2.1:1234 generation=215982026/11/11 23:34:58 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15992026/11/11 23:34:58 INFO Uploading 4jr4n05q2mgxh7pk9g1x5wcyjw39xbxx-ca-test (144B)16002026/11/11 23:34:58 INFO lead: given back to the incumbent remote=192.0.2.1:1234 generation=216012026/11/11 23:34:58 INFO lead: acquired remote=192.0.2.1:1234 generation=316022026/11/11 23:34:59 WARN Failed to register uploaded object key=4jr4n05q2mgxh7pk9g1x5wcyjw39xbxx.ls error="server returned 404: 404 page not found\n"16032026/11/11 23:34:59 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"16042026/11/11 23:34:59 WARN Failed to register uploaded object key=log/m9q9x0hlj6cbm52by3afhfb1wkj2i2rj-ca-test.drv error="server returned 404: 404 page not found\n"16052026/11/11 23:34:59 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16062026/11/11 23:34:59 INFO Signed narinfos id=1 count=116072026/11/11 23:34:59 INFO Uploading 1 narinfos16082026/11/11 23:34:59 INFO Received complete push request method=POST path=/api/pushes/1/complete16092026/11/11 23:34:59 WARN Failed to register uploaded object key=4jr4n05q2mgxh7pk9g1x5wcyjw39xbxx.narinfo error="server returned 404: 404 page not found\n"16102026/11/11 23:34:59 INFO Completed push id=1 objects=4 duration=33.433791ms16112026/11/11 23:34:59 INFO Upload complete. (376ms)1612 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientCADerivations1881975410/001/store/4jr4n05q2mgxh7pk9g1x5wcyjw39xbxx-ca-test1613 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1614 Compression: zstd1615 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1616 NarSize: 1441617 References: 1618 Deriver: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientCADerivations1881975410/001/store/m9q9x0hlj6cbm52by3afhfb1wkj2i2rj-ca-test.drv1619 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1620 client_ca_test.go:185: Checking for realisation files in S3...1621 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1622 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1623 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket76?endpoint=http://localhost:58999®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientCADerivations1881975410/001/store'1624 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 11625--- PASS: TestClientCADerivations (8.16s)1626=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed16272026/11/11 23:34:59 INFO Received uploads request method=POST path=/api/pending_closures16282026/11/11 23:34:59 INFO lead: released remote=192.0.2.1:1234 generation=116292026/11/11 23:34:59 INFO Received uploads request method=POST path=/api/pending_closures16302026/11/11 23:34:59 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)16312026/11/11 23:34:59 INFO Uploading aiqxrnrkc39zxlc45szvyvz1k5malz00-shared-dep (136B)16322026/11/11 23:34:59 INFO Uploading 5l85wlzg50zqj08d2cal06v75prvrrvs-a (256B)16332026/11/11 23:34:59 INFO lead: acquired remote=192.0.2.1:1234 generation=21634=== NAME TestPinProtectsFromGC1635 client_integration_test.go:779: Pinned store path: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestPinProtectsFromGC350700099/001/store/c5rv8hhba71wjp1jark1dypzfr332vaw-pinned-file.txt1636 client_integration_test.go:780: Unpinned store path: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestPinProtectsFromGC350700099/001/store/wflrg06w1dibw9inbwpnqgg5qif3h93r-unpinned-file.txt16372026/11/11 23:34:59 WARN Failed to register uploaded object key=aiqxrnrkc39zxlc45szvyvz1k5malz00.ls error="server returned 404: 404 page not found\n"16382026/11/11 23:34:59 WARN Failed to register uploaded object key=a0lr1y94wir5xl0vsn7h3qzvggmhkikr.ls error="server returned 404: 404 page not found\n"16392026/11/11 23:34:59 WARN Failed to register uploaded object key=5l85wlzg50zqj08d2cal06v75prvrrvs.ls error="server returned 404: 404 page not found\n"16402026/11/11 23:34:59 WARN Failed to register uploaded object key=nar/0ndrw848i9zvijsgqb9m6dndgsj9pz7069jg6v8rahqw4wlqy8g5.nar.zst error="server returned 404: 404 page not found\n"16412026/11/11 23:34:59 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16422026/11/11 23:34:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign16432026/11/11 23:34:59 INFO Signed narinfos id=1 count=216442026/11/11 23:34:59 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign16452026/11/11 23:34:59 INFO Signed narinfos id=2 count=216462026/11/11 23:34:59 INFO Uploading 4 narinfos16472026/11/11 23:34:59 WARN Failed to register uploaded object key=5l85wlzg50zqj08d2cal06v75prvrrvs.narinfo error="server returned 404: 404 page not found\n"16482026/11/11 23:34:59 WARN Failed to register uploaded object key=a0lr1y94wir5xl0vsn7h3qzvggmhkikr.narinfo error="server returned 404: 404 page not found\n"16492026/11/11 23:34:59 WARN Failed to register uploaded object key=aiqxrnrkc39zxlc45szvyvz1k5malz00.narinfo error="server returned 404: 404 page not found\n"16502026/11/11 23:34:59 INFO Received push request method=POST path=/api/pushes16512026/11/11 23:34:59 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16522026/11/11 23:34:59 INFO Uploading c5rv8hhba71wjp1jark1dypzfr332vaw-pinned-file.txt (128B)16532026/11/11 23:34:59 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete16542026/11/11 23:34:59 WARN Failed to register uploaded object key=aiqxrnrkc39zxlc45szvyvz1k5malz00.narinfo error="server returned 404: 404 page not found\n"16552026/11/11 23:34:59 WARN Failed to register uploaded object key=c5rv8hhba71wjp1jark1dypzfr332vaw.ls error="server returned 404: 404 page not found\n"16562026/11/11 23:35:00 INFO Completed upload id=2 objects=6 duration=34.250333ms16572026/11/11 23:35:00 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete16582026/11/11 23:35:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16592026/11/11 23:35:00 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"16602026/11/11 23:35:00 INFO Completed upload id=1 objects=6 duration=524.625µs16612026/11/11 23:35:00 INFO Upload complete. (454ms)16622026/11/11 23:35:00 INFO Signed narinfos id=1 count=11663=== NAME TestClientFallsBackToClosures1664 client_pushes_test.go:112: Retrieved narinfo from S3:1665 StorePath: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientFallsBackToClosures1971310584/001/store/aiqxrnrkc39zxlc45szvyvz1k5malz00-shared-dep16662026/11/11 23:35:00 INFO Uploading 1 narinfos1667 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1668 Compression: zstd1669 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821670 NarSize: 1361671 References: 1672 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1673 client_pushes_test.go:112: Retrieved narinfo from S3:1674 StorePath: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientFallsBackToClosures1971310584/001/store/5l85wlzg50zqj08d2cal06v75prvrrvs-a1675 URL: nar/0ndrw848i9zvijsgqb9m6dndgsj9pz7069jg6v8rahqw4wlqy8g5.nar.zst1676 Compression: zstd1677 NarHash: sha256:0ndrw848i9zvijsgqb9m6dndgsj9pz7069jg6v8rahqw4wlqy8g51678 NarSize: 2561679 References: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientFallsBackToClosures1971310584/001/store/aiqxrnrkc39zxlc45szvyvz1k5malz00-shared-dep1680 CA: text:sha256:0i5l7hlanaaj7zxhj3i4p1agpzzdkqw8704w3xd4qdwc2fn7prx31681 client_pushes_test.go:112: Retrieved narinfo from S3:1682 StorePath: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientFallsBackToClosures1971310584/001/store/a0lr1y94wir5xl0vsn7h3qzvggmhkikr-b1683 URL: nar/0ndrw848i9zvijsgqb9m6dndgsj9pz7069jg6v8rahqw4wlqy8g5.nar.zst1684 Compression: zstd1685 NarHash: sha256:0ndrw848i9zvijsgqb9m6dndgsj9pz7069jg6v8rahqw4wlqy8g51686 NarSize: 2561687 References: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientFallsBackToClosures1971310584/001/store/aiqxrnrkc39zxlc45szvyvz1k5malz00-shared-dep1688 CA: text:sha256:0i5l7hlanaaj7zxhj3i4p1agpzzdkqw8704w3xd4qdwc2fn7prx316892026/11/11 23:35:00 INFO Received complete push request method=POST path=/api/pushes/1/complete16902026/11/11 23:35:00 WARN Failed to register uploaded object key=c5rv8hhba71wjp1jark1dypzfr332vaw.narinfo error="server returned 404: 404 page not found\n"1691--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (8.03s)1692=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed16932026/11/11 23:35:00 INFO Completed push id=1 objects=3 duration=23.004041ms16942026/11/11 23:35:00 INFO Upload complete. (323ms)1695--- PASS: TestClientFallsBackToClosures (7.37s)1696=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost1697--- PASS: TestConnectWaitsForAPeerMigration (8.41s)1698=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed16992026/11/11 23:35:00 INFO Received push request method=POST path=/api/pushes17002026/11/11 23:35:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17012026/11/11 23:35:00 INFO Uploading wflrg06w1dibw9inbwpnqgg5qif3h93r-unpinned-file.txt (128B)17022026/11/11 23:35:00 WARN Failed to register uploaded object key=wflrg06w1dibw9inbwpnqgg5qif3h93r.ls error="server returned 404: 404 page not found\n"17032026/11/11 23:35:00 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign17042026/11/11 23:35:00 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"17052026/11/11 23:35:00 INFO Signed narinfos id=2 count=117062026/11/11 23:35:00 INFO Uploading 1 narinfos17072026/11/11 23:35:00 INFO Received complete push request method=POST path=/api/pushes/2/complete17082026/11/11 23:35:00 WARN Failed to register uploaded object key=wflrg06w1dibw9inbwpnqgg5qif3h93r.narinfo error="server returned 404: 404 page not found\n"17092026/11/11 23:35:00 INFO Completed push id=2 objects=3 duration=1.096416ms17102026/11/11 23:35:00 INFO Upload complete. (206ms)17112026/11/11 23:35:00 INFO Starting cleanup of old closures method=DELETE path=/api/closures17122026/11/11 23:35:00 INFO Garbage collection started17132026/11/11 23:35:00 INFO Aborted multipart uploads count=0 kept=017142026/11/11 23:35:00 WARN Force mode enabled - objects will be deleted immediately without grace period17152026/11/11 23:35:00 INFO Received push request method=POST path=/api/pushes17162026/11/11 23:35:00 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)17172026/11/11 23:35:00 INFO Uploading b9g784ml7hiny3lijmv0wnrx69an1vwl-shared-dep (136B)17182026/11/11 23:35:00 INFO Uploading 6xb2zwy1fn78rkc7wp9chncrci72s5x7-a (256B)17192026/11/11 23:35:00 WARN Failed to register uploaded object key=l0d33snlzsymcy6xg8gb24cx1dfr01lk.ls error="server returned 404: 404 page not found\n"17202026/11/11 23:35:00 WARN Failed to register uploaded object key=b9g784ml7hiny3lijmv0wnrx69an1vwl.ls error="server returned 404: 404 page not found\n"17212026/11/11 23:35:00 WARN Failed to register uploaded object key=6xb2zwy1fn78rkc7wp9chncrci72s5x7.ls error="server returned 404: 404 page not found\n"17222026/11/11 23:35:00 WARN Failed to register uploaded object key=nar/127kd4gi427ahzv97hcwyk796vw0wzz1fw8rxd805skh90m0ar41.nar.zst error="server returned 404: 404 page not found\n"17232026/11/11 23:35:00 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17242026/11/11 23:35:00 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"17252026/11/11 23:35:00 INFO Signed narinfos id=1 count=317262026/11/11 23:35:00 INFO Uploading 3 narinfos17272026/11/11 23:35:00 WARN Failed to register uploaded object key=6xb2zwy1fn78rkc7wp9chncrci72s5x7.narinfo error="server returned 404: 404 page not found\n"17282026/11/11 23:35:00 WARN Failed to register uploaded object key=b9g784ml7hiny3lijmv0wnrx69an1vwl.narinfo error="server returned 404: 404 page not found\n"17292026/11/11 23:35:00 INFO Received complete push request method=POST path=/api/pushes/1/complete17302026/11/11 23:35:00 WARN Failed to register uploaded object key=l0d33snlzsymcy6xg8gb24cx1dfr01lk.narinfo error="server returned 404: 404 page not found\n"1731=== NAME TestClientWithDependencies1732 client_integration_test.go:661: Built derivation: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientWithDependencies3257327260/001/store/crnhwvmgsn4s9rnxx5sx3p4apxw6ir80-test-script17332026/11/11 23:35:00 INFO lead: released remote=192.0.2.1:1234 generation=21734--- PASS: TestLeadElectsOneAndHandsOver (8.92s)1735=== CONT TestGCEndsOnShutdown/before_the_run17362026/11/11 23:35:00 INFO Completed push id=1 objects=8 duration=46.054958ms17372026/11/11 23:35:00 INFO Upload complete. (396ms)1738=== NAME TestClientPushesUseOnePush1739 client_pushes_test.go:97: Retrieved narinfo from S3:1740 StorePath: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientPushesUseOnePush1785518253/001/store/b9g784ml7hiny3lijmv0wnrx69an1vwl-shared-dep1741 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1742 Compression: zstd1743 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821744 NarSize: 1361745 References: 1746 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1747=== NAME TestClientWithDependencies1748 client_integration_test.go:663: Found 1 dependencies (including self)1749=== NAME TestClientPushesUseOnePush1750 client_pushes_test.go:97: Retrieved narinfo from S3:1751 StorePath: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientPushesUseOnePush1785518253/001/store/6xb2zwy1fn78rkc7wp9chncrci72s5x7-a1752 URL: nar/127kd4gi427ahzv97hcwyk796vw0wzz1fw8rxd805skh90m0ar41.nar.zst1753 Compression: zstd1754 NarHash: sha256:127kd4gi427ahzv97hcwyk796vw0wzz1fw8rxd805skh90m0ar411755 NarSize: 2561756 References: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientPushesUseOnePush1785518253/001/store/b9g784ml7hiny3lijmv0wnrx69an1vwl-shared-dep1757 CA: text:sha256:18j0rq5gdv6gdgbgzw4mkbx4m9jdajqchjlk11vwmc80b16288vv1758 client_pushes_test.go:97: Retrieved narinfo from S3:1759 StorePath: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientPushesUseOnePush1785518253/001/store/l0d33snlzsymcy6xg8gb24cx1dfr01lk-b1760 URL: nar/127kd4gi427ahzv97hcwyk796vw0wzz1fw8rxd805skh90m0ar41.nar.zst1761 Compression: zstd1762 NarHash: sha256:127kd4gi427ahzv97hcwyk796vw0wzz1fw8rxd805skh90m0ar411763 NarSize: 2561764 References: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientPushesUseOnePush1785518253/001/store/b9g784ml7hiny3lijmv0wnrx69an1vwl-shared-dep1765 CA: text:sha256:18j0rq5gdv6gdgbgzw4mkbx4m9jdajqchjlk11vwmc80b16288vv17662026/11/11 23:35:00 INFO lead: released remote=192.0.2.1:1234 generation=31767--- PASS: TestLeadUnannouncedStandbyYieldsToIncumbent (9.56s)1768=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark17692026/11/11 23:35:00 INFO Received push request method=POST path=/api/pushes1770=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1771=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1772=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1773=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1774=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1775=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1776=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1777=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1778=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete17792026/11/11 23:35: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=017802026/11/11 23:35:00 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17812026/11/11 23:35:00 INFO Uploading crnhwvmgsn4s9rnxx5sx3p4apxw6ir80-test-script (136B)1782=== NAME TestClientMultipleUploads1783 client_integration_test.go:406: Created store path 0: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientMultipleUploads995546014/001/store/ismjid8lhbqwxrlqkn49xpp28qpmdpqf-test-file-0.txt1784--- PASS: TestClientPushesUseOnePush (7.40s)1785=== CONT TestPendingClosureWriteTimeout/empty1786=== CONT TestPendingClosureWriteTimeout/670k_objects1787=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline17882026/11/11 23:35:01 INFO Vacuumed table table=pending_closures17892026/11/11 23:35:01 WARN Failed to register uploaded object key=crnhwvmgsn4s9rnxx5sx3p4apxw6ir80.ls error="server returned 404: 404 page not found\n"17902026/11/11 23:35:01 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17912026/11/11 23:35:01 INFO Vacuumed table table=pending_objects17922026/11/11 23:35:01 INFO Vacuumed table table=multipart_uploads17932026/11/11 23:35:01 WARN Failed to register uploaded object key=log/c7vs0gbdywli077n2d5dxdwrc60hc93i-test-script.drv error="server returned 404: 404 page not found\n"17942026/11/11 23:35:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17952026/11/11 23:35:01 INFO Signed narinfos id=1 count=117962026/11/11 23:35:01 INFO Uploading 1 narinfos1797=== NAME TestClientMultipleUploads1798 client_integration_test.go:406: Created store path 1: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientMultipleUploads995546014/001/store/cb733bks3c0r6kglddfxsi3hqdsmpqb9-test-file-1.txt17992026/11/11 23:35:01 INFO Vacuumed table table=closures18002026/11/11 23:35:01 INFO Received complete push request method=POST path=/api/pushes/1/complete18012026/11/11 23:35:01 WARN Failed to register uploaded object key=crnhwvmgsn4s9rnxx5sx3p4apxw6ir80.narinfo error="server returned 404: 404 page not found\n"18022026/11/11 23:35:01 INFO Vacuumed table table=objects18032026/11/11 23:35:01 INFO Completed push id=1 objects=4 duration=36.621458ms18042026/11/11 23:35:01 INFO Upload complete. (350ms)1805=== NAME TestClientWithDependencies1806 client_integration_test.go:665: Skipping nix copy test - isolated store (/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientWithDependencies3257327260/001/store) requires matching store prefix1807=== NAME TestClientMultipleUploads1808 client_integration_test.go:406: Created store path 2: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientMultipleUploads995546014/001/store/8pn71spbabbapkbbdkszlkrmq0awlsl6-test-file-2.txt1809--- PASS: TestClientWithDependencies (7.31s)1810=== CONT TestPendingClosureWriteTimeout/400_objects1811=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info18122026/11/11 23:35:01 INFO Received uploads request method=POST path=/1813=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key18142026/11/11 23:35:01 INFO Received complete multipart upload request method=POST path=/1815=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key18162026/11/11 23:35:01 INFO Received request for more parts method=POST path=/1817=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal18182026/11/11 23:35:01 INFO Received uploads request method=POST path=/1819=== CONT TestIsValidUploadKey/narinfo1820=== CONT TestIsValidUploadKey/realisation_plus_in_output1821=== CONT TestIsValidUploadKey/unknown_type1822=== CONT TestIsValidUploadKey/empty_key1823=== CONT TestIsValidUploadKey/absolute1824=== CONT TestIsValidUploadKey/traversal_nar1825=== CONT TestIsValidUploadKey/traversal1826--- PASS: TestUploadHandlersRejectInvalidKeys (0.01s)1827 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.01s)1828 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1829 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1830 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1831=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1832=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1833=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1834=== CONT TestIsValidUploadKey/index.html1835=== CONT TestIsValidUploadKey/nix-cache-info1836=== CONT TestIsValidUploadKey/build_log_home-manager_file1837=== CONT TestIsValidUploadKey/realisation1838=== CONT TestIsValidUploadKey/build_log_equals1839=== CONT TestIsValidUploadKey/build_log_question_mark1840=== CONT TestIsValidUploadKey/build_log_plus_in_name1841=== CONT TestIsValidUploadKey/nar_plain1842=== CONT TestIsValidUploadKey/build_log1843=== CONT TestIsValidUploadKey/nar_xz1844=== CONT TestIsValidUploadKey/nar_zst1845=== CONT TestIsValidUploadKey/listing1846--- PASS: TestIsValidUploadKey (0.01s)1847 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1848 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1849 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1850 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1851 --- PASS: TestIsValidUploadKey/absolute (0.00s)1852 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1853 --- PASS: TestIsValidUploadKey/traversal (0.00s)1854 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1855 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1856 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1857 --- PASS: TestIsValidUploadKey/index.html (0.00s)1858 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1859 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1860 --- PASS: TestIsValidUploadKey/realisation (0.00s)1861 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1862 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1863 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1864 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1865 --- PASS: TestIsValidUploadKey/build_log (0.00s)1866 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1867 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1868 --- PASS: TestIsValidUploadKey/listing (0.00s)1869=== CONT TestProxyWriteTimeout/narinfo1870=== CONT TestProxyWriteTimeout/10_GiB_nar1871=== CONT TestProxyWriteTimeout/unknown_size1872=== CONT TestProxyWriteTimeout/1_GiB_nar1873--- PASS: TestProxyWriteTimeout (0.01s)1874 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1875 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1876 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1877 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1878=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows18792026/11/11 23:35:01 INFO Received push request method=POST path=/api/pushes18802026/11/11 23:35:01 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)18812026/11/11 23:35:01 INFO Uploading 8pn71spbabbapkbbdkszlkrmq0awlsl6-test-file-2.txt (160B)18822026/11/11 23:35:01 INFO Uploading cb733bks3c0r6kglddfxsi3hqdsmpqb9-test-file-1.txt (160B)18832026/11/11 23:35:01 INFO Uploading ismjid8lhbqwxrlqkn49xpp28qpmdpqf-test-file-0.txt (160B)18842026/11/11 23:35:01 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"18852026/11/11 23:35:01 WARN Failed to register uploaded object key=8pn71spbabbapkbbdkszlkrmq0awlsl6.ls error="server returned 404: 404 page not found\n"18862026/11/11 23:35:01 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"18872026/11/11 23:35:01 WARN Failed to register uploaded object key=cb733bks3c0r6kglddfxsi3hqdsmpqb9.ls error="server returned 404: 404 page not found\n"18882026/11/11 23:35:01 WARN Failed to register uploaded object key=ismjid8lhbqwxrlqkn49xpp28qpmdpqf.ls error="server returned 404: 404 page not found\n"18892026/11/11 23:35:01 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"18902026/11/11 23:35:01 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18912026/11/11 23:35:01 INFO Signed narinfos id=1 count=318922026/11/11 23:35:01 INFO Uploading 3 narinfos18932026/11/11 23:35:01 WARN Failed to register uploaded object key=cb733bks3c0r6kglddfxsi3hqdsmpqb9.narinfo error="server returned 404: 404 page not found\n"18942026/11/11 23:35:01 INFO Received complete push request method=POST path=/api/pushes/1/complete18952026/11/11 23:35:01 WARN Failed to register uploaded object key=8pn71spbabbapkbbdkszlkrmq0awlsl6.narinfo error="server returned 404: 404 page not found\n"18962026/11/11 23:35:01 WARN Failed to register uploaded object key=ismjid8lhbqwxrlqkn49xpp28qpmdpqf.narinfo error="server returned 404: 404 page not found\n"18972026/11/11 23:35:01 INFO Completed push id=1 objects=9 duration=100.280125ms18982026/11/11 23:35:01 INFO Upload complete. (431ms)1899=== NAME TestClientMultipleUploads1900 client_integration_test.go:417: Uploaded 3 paths in 474.944792ms1901--- PASS: TestClientMultipleUploads (7.51s)1902=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check19032026/11/11 23:35:01 INFO Received push request method=POST path=/api/pushes1904--- PASS: TestService_ReadAuthMiddleware (6.18s)1905=== CONT TestResolveDBConnectionString/flag_wins1906=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1907=== CONT TestResolveDBConnectionString/nothing_configured1908=== CONT TestResolveDBConnectionString/missing_file_is_an_error1909=== CONT TestResolveDBConnectionString/file_when_flag_empty1910=== CONT TestClientErrorHandling/InvalidStorePath19112026/11/11 23:35:02 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)19122026/11/11 23:35:02 INFO Uploading fcr7w638a0hs61lkf8c5700p6aj0q2w0-top (264B)19132026/11/11 23:35:02 INFO Uploading yfxpn146szd9ywh250kg3vnhmwhcvbxa-shared-dep (136B)1914--- PASS: TestResolveDBConnectionString (0.03s)1915 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1916 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1917 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1918 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1919 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)1920=== NAME TestClientIntegration1921 client_integration_test.go:292: Created store path: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientIntegration1094551860/002/store/dizycng34546n6jg1dc719cakv7y2ifa-test-file.txt19222026/11/11 23:35:02 WARN Failed to register uploaded object key=yfxpn146szd9ywh250kg3vnhmwhcvbxa.ls error="server returned 404: 404 page not found\n"19232026/11/11 23:35:02 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"19242026/11/11 23:35:02 WARN Failed to register uploaded object key=fcr7w638a0hs61lkf8c5700p6aj0q2w0.ls error="server returned 404: 404 page not found\n"19252026/11/11 23:35:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19262026/11/11 23:35:02 WARN Failed to register uploaded object key=nar/12anffic47ywfabzdpwg1cja7px6icflj8y33mdp192lxm7ybz60.nar.zst error="server returned 404: 404 page not found\n"19272026/11/11 23:35:02 INFO Signed narinfos id=1 count=219282026/11/11 23:35:02 INFO Uploading 2 narinfos19292026/11/11 23:35:02 WARN Failed to register uploaded object key=fcr7w638a0hs61lkf8c5700p6aj0q2w0.narinfo error="server returned 404: 404 page not found\n"19302026/11/11 23:35:02 INFO Received complete push request method=POST path=/api/pushes/1/complete19312026/11/11 23:35:02 WARN Failed to register uploaded object key=yfxpn146szd9ywh250kg3vnhmwhcvbxa.narinfo error="server returned 404: 404 page not found\n"19322026/11/11 23:35:02 INFO Completed push id=1 objects=6 duration=19.51575ms19332026/11/11 23:35:02 INFO Upload complete. (270ms)19342026/11/11 23:35:02 INFO Received push request method=POST path=/api/pushes1935=== NAME TestClientSharedPathCommittedMidPush1936 client_integration_test.go:728: Retrieved narinfo from S3:1937 StorePath: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientSharedPathCommittedMidPush2049634430/001/store/yfxpn146szd9ywh250kg3vnhmwhcvbxa-shared-dep1938 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1939 Compression: zstd1940 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821941 NarSize: 1361942 References: 1943 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1944 client_integration_test.go:728: Retrieved narinfo from S3:1945 StorePath: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientSharedPathCommittedMidPush2049634430/001/store/fcr7w638a0hs61lkf8c5700p6aj0q2w0-top1946 URL: nar/12anffic47ywfabzdpwg1cja7px6icflj8y33mdp192lxm7ybz60.nar.zst1947 Compression: zstd1948 NarHash: sha256:12anffic47ywfabzdpwg1cja7px6icflj8y33mdp192lxm7ybz601949 NarSize: 2641950 References: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientSharedPathCommittedMidPush2049634430/001/store/yfxpn146szd9ywh250kg3vnhmwhcvbxa-shared-dep1951 CA: text:sha256:1n5c3sskv02apipw12vn92gikak6zzjw6svk09w0fp5rx7kz8ssc19522026/11/11 23:35:02 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19532026/11/11 23:35:02 INFO Uploading dizycng34546n6jg1dc719cakv7y2ifa-test-file.txt (152B)19542026/11/11 23:35:02 WARN Failed to register uploaded object key=dizycng34546n6jg1dc719cakv7y2ifa.ls error="server returned 404: 404 page not found\n"19552026/11/11 23:35:02 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19562026/11/11 23:35:02 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"19572026/11/11 23:35:02 INFO Signed narinfos id=1 count=119582026/11/11 23:35:02 INFO Uploading 1 narinfos1959--- PASS: TestClientSharedPathCommittedMidPush (6.70s)1960=== CONT TestClientErrorHandling/ServerNotAvailable1961--- PASS: TestService_ReadScope_PublicByDefault (6.42s)1962=== CONT TestClientErrorHandling/InvalidAuthToken19632026/11/11 23:35:02 INFO Received complete push request method=POST path=/api/pushes/1/complete19642026/11/11 23:35:02 WARN Failed to register uploaded object key=dizycng34546n6jg1dc719cakv7y2ifa.narinfo error="server returned 404: 404 page not found\n"19652026/11/11 23:35:02 INFO Completed push id=1 objects=3 duration=60.411291ms19662026/11/11 23:35:02 INFO Upload complete. (313ms)19672026/11/11 23:35:02 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=019682026/11/11 23:35:02 INFO Received create pin request method=POST path=/api/pins/myapp19692026/11/11 23:35:02 INFO All 1 paths already cached1970=== NAME TestClientIntegration1971 client_integration_test.go:318: Retrieved narinfo from S3:1972 StorePath: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestClientIntegration1094551860/002/store/dizycng34546n6jg1dc719cakv7y2ifa-test-file.txt1973 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1974 Compression: zstd1975 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11976 NarSize: 1521977 References: 1978 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11979 client_integration_test.go:319: Retrieved .ls file from S3 (compressed size: 77 bytes)1980 client_integration_test.go:319: Decompressed .ls content (64 bytes):1981 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}19822026/11/11 23:35:02 INFO Created/updated pin name=myapp store_path=/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestPinProtectsFromGC350700099/001/store/c5rv8hhba71wjp1jark1dypzfr332vaw-pinned-file.txt narinfo_key=c5rv8hhba71wjp1jark1dypzfr332vaw.narinfo19832026/11/11 23:35:02 INFO Starting cleanup of old closures method=DELETE path=/api/closures19842026/11/11 23:35:02 INFO Garbage collection started19852026/11/11 23:35:02 INFO Aborted multipart uploads count=0 kept=019862026/11/11 23:35:02 WARN Force mode enabled - objects will be deleted immediately without grace period19872026/11/11 23:35: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=019882026/11/11 23:35:02 INFO Vacuumed table table=pending_closures19892026/11/11 23:35:02 INFO Vacuumed table table=pending_objects19902026/11/11 23:35:02 INFO Vacuumed table table=multipart_uploads19912026/11/11 23:35:02 INFO Vacuumed table table=closures19922026/11/11 23:35:02 INFO Vacuumed table table=objects19932026/11/11 23:35:02 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present19942026/11/11 23:35:02 WARN Request failed, retrying attempt=2 backoff=216.221981ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present1995--- PASS: TestCacheStatsHandler (6.35s)1996=== CONT TestCacheConfigHandler/full_config,_no_issuer1997=== CONT TestCacheConfigHandler/no_signing_keys1998=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1999=== CONT TestCacheConfigHandler/no_cache_url_configured2000--- PASS: TestCacheConfigHandler (0.00s)2001 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2002 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2003 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2004 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2005=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2006=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2007=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20082026/11/11 23:35:02 WARN Authentication failed token_preview=not-a-valid-jwt token_length=15 oidc_error="no provider could verify the token (signature or issuer mismatch)" oidc_provider="" tried_providers=[test]2009=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected20102026/11/11 23:35:02 WARN Authentication failed token_preview=eyJhbGciOi...3W5SQW-odg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2011--- PASS: TestService_AuthMiddleware_OIDC (6.09s)2012 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2013 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2014 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.01s)2015 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.00s)20162026/11/11 23:35:02 INFO Received push request method=POST path=/api/pushes20172026/11/11 23:35:02 INFO Object in database but missing from S3 key=dizycng34546n6jg1dc719cakv7y2ifa.ls20182026/11/11 23:35:02 WARN Found objects in DB but missing from S3, will re-upload count=120192026/11/11 23:35:02 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20202026/11/11 23:35:02 INFO Received complete push request method=POST path=/api/pushes/2/complete20212026/11/11 23:35:02 WARN Failed to register uploaded object key=dizycng34546n6jg1dc719cakv7y2ifa.ls error="server returned 404: 404 page not found\n"20222026/11/11 23:35:02 INFO Completed push id=2 objects=3 duration=783.208µs20232026/11/11 23:35:02 INFO Upload complete. (170ms)2024=== NAME TestClientIntegration20252026/11/11 23:35:02 WARN Request failed, retrying attempt=3 backoff=430.121998ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2026 client_integration_test.go:336: Retrieved .ls file from S3 (compressed size: 62 bytes)2027 client_integration_test.go:336: Decompressed .ls content (49 bytes):2028 {"version":1,"root":{"type":"regular","size":39}}2029=== RUN TestService_RequireScope_OIDC/builder_may_write2030=== PAUSE TestService_RequireScope_OIDC/builder_may_write2031=== RUN TestService_RequireScope_OIDC/builder_may_not_admin2032=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin2033=== RUN TestService_RequireScope_OIDC/ops_may_admin2034=== PAUSE TestService_RequireScope_OIDC/ops_may_admin2035=== RUN TestService_RequireScope_OIDC/ops_may_not_write2036=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write2037=== RUN TestService_RequireScope_OIDC/reader_may_not_write2038=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write2039=== RUN TestService_RequireScope_OIDC/static_token_may_admin2040=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin2041=== RUN TestService_RequireScope_OIDC/static_token_may_write2042=== PAUSE TestService_RequireScope_OIDC/static_token_may_write2043=== RUN TestService_RequireScope_OIDC/reader_may_read2044=== PAUSE TestService_RequireScope_OIDC/reader_may_read2045=== RUN TestService_RequireScope_OIDC/writer_implies_read2046=== PAUSE TestService_RequireScope_OIDC/writer_implies_read2047=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read2048=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read2049=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc2050=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc2051=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2052=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2053=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2054=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read2055=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2056=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2057=== CONT TestService_RequireScope_OIDC/builder_may_write2058=== CONT TestService_RequireScope_OIDC/reader_may_read2059=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2060=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2061=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20622026/11/11 23:35:03 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]2063=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2064=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2065=== CONT TestService_RequireScope_OIDC/writer_implies_read2066=== CONT TestService_RequireScope_OIDC/reader_may_not_write2067=== CONT TestService_RequireScope_OIDC/static_token_may_admin2068=== CONT TestService_RequireScope_OIDC/static_token_may_write2069=== CONT TestService_RequireScope_OIDC/ops_may_admin2070=== CONT TestService_RequireScope_OIDC/ops_may_not_write2071=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2072--- PASS: TestService_RequireScope_OIDC (6.35s)2073 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2074 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2075 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2076 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2077 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.01s)2078 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2079 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2080 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2081 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2082 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2083 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2084 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2085 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2086 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20872026/11/11 23:35:03 INFO Received push request method=POST path=/api/pushes20882026/11/11 23:35:03 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)20892026/11/11 23:35:03 WARN Request failed, retrying attempt=4 backoff=806.611371ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20902026/11/11 23:35:03 INFO Received complete push request method=POST path=/api/pushes/3/complete20912026/11/11 23:35:03 WARN Failed to register uploaded object key=dizycng34546n6jg1dc719cakv7y2ifa.ls error="server returned 404: 404 page not found\n"20922026/11/11 23:35:03 INFO Completed push id=3 objects=3 duration=957.5µs20932026/11/11 23:35:03 INFO Upload complete. (146ms)2094=== NAME TestClientIntegration2095 client_integration_test.go:353: Retrieved .ls file from S3 (compressed size: 62 bytes)2096 client_integration_test.go:353: Decompressed .ls content (49 bytes):2097 {"version":1,"root":{"type":"regular","size":39}}2098 client_integration_test.go:364: Testing garbage collection...20992026/11/11 23:35:03 INFO Starting cleanup of old closures method=DELETE path=/api/closures21002026/11/11 23:35:03 INFO Garbage collection started21012026/11/11 23:35:03 INFO Aborted multipart uploads count=0 kept=021022026/11/11 23:35:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"21032026/11/11 23:35:03 WARN mTLS auth: bound subjects configured but subject DN unavailable21042026/11/11 23:35:03 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2105--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (6.24s)21062026/11/11 23:35:03 WARN Force mode enabled - objects will be deleted immediately without grace period21072026-11-11 23:35:03.787 UTC [86720] LOG: checkpoint starting: wal2108--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (6.74s)21092026/11/11 23:35:04 WARN Request failed, retrying attempt=5 backoff=1.658176092s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21102026/11/11 23:35:04 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=021112026/11/11 23:35:04 INFO Vacuumed table table=pending_closures21122026/11/11 23:35:04 INFO Vacuumed table table=pending_objects21132026/11/11 23:35:04 INFO Vacuumed table table=multipart_uploads21142026/11/11 23:35:04 INFO Vacuumed table table=closures21152026/11/11 23:35:04 INFO Vacuumed table table=objects21162026/11/11 23:35:04 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"2117=== NAME TestPinProtectsFromGC2118 client_integration_test.go:888: Pin successfully protected closure from garbage collection2119--- PASS: TestService_AuthMiddleware (7.12s)2120--- PASS: TestPinProtectsFromGC (11.45s)21212026/11/11 23:35:05 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02122=== NAME TestClientIntegration2123 client_integration_test.go:371: Objects in database after GC:2124 client_integration_test.go:371: Successfully deleted all objects with GC --force2125--- PASS: TestClientIntegration (9.93s)21262026/11/11 23:35:05 INFO Received uploads request method=POST path=/api/pending_closures21272026/11/11 23:35:05 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2128--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2129 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (8.05s)2130 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (8.41s)21312026/11/11 23:35:06 WARN Request failed, retrying attempt=2 backoff=197.285259ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21322026/11/11 23:35:06 INFO Received uploads request method=POST path=/api/pending_closures21332026/11/11 23:35:06 WARN Request failed, retrying attempt=3 backoff=393.675543ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21342026/11/11 23:35:06 INFO Received uploads request method=POST path=/api/pending_closures21352026/11/11 23:35:06 WARN Request failed, retrying attempt=4 backoff=801.424864ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21362026/11/11 23:35:06 INFO Received uploads request method=POST path=/api/pending_closures21372026/11/11 23:35:07 INFO Received uploads request method=POST path=/api/pending_closures21382026/11/11 23:35:07 WARN Request failed, retrying attempt=5 backoff=1.656464729s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21392026/11/11 23:35:07 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21402026/11/11 23:35:07 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=NDU4MTQ1NDUtNTBmMC00NDM2LWIwNTUtMWZiYTFlMDMwMmU1LjRlNGI1OTk0LTdjOTctNDUzZi1hODlkLTRiYzEyMzBlNzJjNHgxNzk0NDQwMTA1ODYxNzQ3MDAw parts=1021412026/11/11 23:35:07 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21422026/11/11 23:35:07 INFO Completed upload id=1 objects=3 duration=20.58675ms21432026/11/11 23:35:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21442026/11/11 23:35:08 INFO Aborted multipart uploads count=0 kept=021452026/11/11 23:35:08 WARN Force mode enabled - objects will be deleted immediately without grace period21462026/11/11 23:35:08 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:58999/bucket102/?delete=\": context canceled"21472026/11/11 23:35:08 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=NDU4MTQ1NDUtNTBmMC00NDM2LWIwNTUtMWZiYTFlMDMwMmU1LmVkZTg3MjQ5LWYyY2EtNGY2Zi04OGZlLTM2MTI2ZGZiZjRhMngxNzk0NDQwMTA2MjEwNDUwMDAw parts=1021482026/11/11 23:35:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21492026/11/11 23:35:08 INFO Completed upload id=1 objects=3 duration=19.175875ms21502026/11/11 23:35:08 INFO Received uploads request method=POST path=/api/pending_closures21512026/11/11 23:35:08 INFO Received uploads request method=POST path=/api/pending_closures21522026/11/11 23:35:08 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst21532026/11/11 23:35:08 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo21542026/11/11 23:35:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21552026/11/11 23:35:08 INFO Aborted multipart uploads count=0 kept=021562026/11/11 23:35:08 WARN Force mode enabled - objects will be deleted immediately without grace period21572026/11/11 23:35:08 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=NDU4MTQ1NDUtNTBmMC00NDM2LWIwNTUtMWZiYTFlMDMwMmU1LmQ5NGI1NGViLWQ1OWYtNGE5OC04OWRiLTI1MjE4NzlhNTlhMXgxNzk0NDQwMTA2NTQyMzk5MDAw parts=1021582026-11-11 23:35:08.710 UTC [87211] ERROR: canceling statement due to user request21592026-11-11 23:35:08.710 UTC [87211] STATEMENT: -- name: MarkStaleObjects :execrows2160 WITH RECURSIVE ct AS (2161 SELECT timezone('UTC', now()) AS now2162 ),2163 closure_reach AS (2164 -- Start with all closure keys2165 SELECT o.key, o.refs2166 FROM objects o2167 INNER JOIN closures c ON o.key = c.key2168 UNION2169 -- Recursively add all referenced objects2170 SELECT o.key, o.refs2171 FROM objects o2172 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2173 ),2174 reachable_objects AS (2175 SELECT DISTINCT key FROM closure_reach2176 ),2177 stale_objects AS (2178 SELECT o.key2179 FROM objects AS o, ct2180 WHERE2181 NOT EXISTS (2182 SELECT 12183 FROM reachable_objects ro2184 WHERE ro.key = o.key2185 )2186 AND NOT EXISTS (2187 SELECT 12188 FROM pending_objects AS po2189 WHERE po.key = o.key2190 )2191 AND o.deleted_at IS NULL -- Only mark fresh objects2192 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2193 FOR UPDATE2194 )2195 UPDATE objects2196 SET2197 deleted_at = ct.now,2198 first_deleted_at = COALESCE(first_deleted_at, ct.now)2199 FROM stale_objects, ct2200 WHERE objects.key = stale_objects.key2201 2202--- PASS: TestGCEndsOnShutdown (0.01s)2203 --- PASS: TestGCEndsOnShutdown/before_the_run (6.95s)2204 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (7.26s)2205 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (7.80s)22062026/11/11 23:35:08 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22072026/11/11 23:35:08 INFO Completed upload id=1 objects=3 duration=5.944667ms22082026/11/11 23:35:08 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22092026/11/11 23:35:08 INFO Received uploads request method=POST path=/api/pending_closures22102026/11/11 23:35:09 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=NDU4MTQ1NDUtNTBmMC00NDM2LWIwNTUtMWZiYTFlMDMwMmU1LmU3ZmNkODg3LTk4ODMtNDMwNi04MTFkLTdlNGU3MTkyYWMzZngxNzk0NDQwMTA2OTI5NTUzMDAw parts=1022112026/11/11 23:35:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22122026/11/11 23:35:09 INFO Completed upload id=1 objects=3 duration=24.432917ms22132026/11/11 23:35:09 INFO Received uploads request method=POST path=/api/pending_closures22142026/11/11 23:35:09 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused"22152026/11/11 23:35:09 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22162026/11/11 23:35:09 INFO Received uploads request method=POST path=/api/pending_closures22172026/11/11 23:35:09 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst22182026/11/11 23:35:09 WARN Found objects in DB but missing from S3, will re-upload count=122192026/11/11 23:35:09 WARN Request failed, retrying attempt=2 backoff=205.056491ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22202026/11/11 23:35:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22212026/11/11 23:35:09 WARN Request failed, retrying attempt=3 backoff=393.253542ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22222026/11/11 23:35:09 INFO Received uploads request method=POST path=/api/pending_closures22232026/11/11 23:35:09 INFO Aborted multipart uploads count=0 kept=022242026/11/11 23:35:09 WARN Force mode enabled - objects will be deleted immediately without grace period22252026/11/11 23:35:09 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=NDU4MTQ1NDUtNTBmMC00NDM2LWIwNTUtMWZiYTFlMDMwMmU1Ljk4ODlhODEwLTU0NDUtNDQ4ZC1iM2I4LWUwMWJlZTNlZWRhYngxNzk0NDQwMTA3MzIxNDEwMDAw parts=1022262026/11/11 23:35:09 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22272026/11/11 23:35:09 INFO Completed upload id=1 objects=3 duration=14.594459ms22282026/11/11 23:35:09 INFO Received uploads request method=POST path=/api/pending_closures22292026/11/11 23:35:09 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=022302026/11/11 23:35:09 INFO Vacuumed table table=pending_closures22312026/11/11 23:35:09 INFO Vacuumed table table=pending_objects22322026/11/11 23:35:09 INFO Vacuumed table table=multipart_uploads22332026/11/11 23:35:09 INFO Vacuumed table table=closures2234--- PASS: TestPendingClosureWriteTimeout (0.02s)2235 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2236 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2237 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2238 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (8.78s)22392026/11/11 23:35:09 INFO Vacuumed table table=objects22402026/11/11 23:35:09 WARN Request failed, retrying attempt=4 backoff=856.336235ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22412026/11/11 23:35:09 INFO Received uploads request method=POST path=/api/pending_closures22422026/11/11 23:35:09 INFO Aborted multipart uploads count=0 kept=022432026/11/11 23:35:09 WARN Force mode enabled - objects will be deleted immediately without grace period22442026/11/11 23:35:09 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=022452026/11/11 23:35:09 INFO Vacuumed table table=pending_closures22462026/11/11 23:35:09 INFO Vacuumed table table=pending_objects22472026/11/11 23:35:09 INFO Vacuumed table table=multipart_uploads22482026/11/11 23:35:09 INFO Vacuumed table table=closures22492026/11/11 23:35:10 INFO Vacuumed table table=objects2250--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2251 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (8.64s)2252 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (8.25s)22532026/11/11 23:35:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22542026/11/11 23:35:10 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=NDU4MTQ1NDUtNTBmMC00NDM2LWIwNTUtMWZiYTFlMDMwMmU1LjEyMDNmMTY4LWYxMzEtNDhiNS1hN2M5LWY3MjFhZjJjYWZkN3gxNzk0NDQwMTA4Mzg5NDU5MDAw parts=1022552026/11/11 23:35:10 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22562026/11/11 23:35:10 INFO Completed upload id=2 objects=3 duration=518.084µs22572026/11/11 23:35:10 INFO Received uploads request method=POST path=/api/pending_closures22582026/11/11 23:35:10 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst22592026/11/11 23:35:10 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo22602026/11/11 23:35:10 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22612026/11/11 23:35:10 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22622026/11/11 23:35:10 WARN Request failed, retrying attempt=5 backoff=1.744436638s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22632026/11/11 23:35:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22642026/11/11 23:35:10 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=NDU4MTQ1NDUtNTBmMC00NDM2LWIwNTUtMWZiYTFlMDMwMmU1LjA2MDY0YjM5LTA2ZTItNDc2Yi05ZWZiLTVkYTZkMzM5ZTZjMngxNzk0NDQwMTA5NjExMzQ4MDAw parts=1022652026/11/11 23:35:10 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22662026/11/11 23:35:10 INFO Completed upload id=2 objects=3 duration=463.333µs22672026/11/11 23:35:11 INFO Received uploads request method=POST path=/api/pending_closures22682026/11/11 23:35:11 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst22692026/11/11 23:35:11 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo2270--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.00s)2271 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (10.35s)2272 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (8.93s)2273 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (9.18s)2274 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (11.20s)2275 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (11.24s)22762026/11/11 23:35:12 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22772026/11/11 23:35:12 WARN Request failed, retrying attempt=2 backoff=204.936472ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22782026/11/11 23:35:12 WARN Request failed, retrying attempt=3 backoff=382.272494ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22792026/11/11 23:35:13 WARN Request failed, retrying attempt=4 backoff=832.218823ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22802026/11/11 23:35:13 WARN Request failed, retrying attempt=5 backoff=1.5914071s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2281--- PASS: TestClientErrorHandling (0.00s)2282 --- PASS: TestClientErrorHandling/InvalidStorePath (8.16s)2283 --- PASS: TestClientErrorHandling/InvalidAuthToken (8.34s)2284 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.47s)2285=== NAME TestOrphanedObjectsGCStressTest2286 orphaned_objects_gc_test.go:503: Stress test completed successfully:2287 orphaned_objects_gc_test.go:504: - Active objects preserved: 202288 orphaned_objects_gc_test.go:505: - Objects deleted: 2102289 orphaned_objects_gc_test.go:506: - Total GC'd: 2102290--- PASS: TestOrphanedObjectsGCStressTest (40.00s)2291PASS2292{"timestamp":"2026-11-11T23:35:16.102374Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59125","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}2293{"timestamp":"2026-11-11T23:35:16.102378Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59298","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(7)"}2294{"timestamp":"2026-11-11T23:35:16.10246Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59252","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(3)"}2295{"timestamp":"2026-11-11T23:35:16.102462Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59324","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}22962026-11-11 23:35:16.231 UTC [86715] LOG: received smart shutdown request22972026-11-11 23:35:16.232 UTC [86715] LOG: background worker "logical replication launcher" (PID 86725) exited with exit code 122982026-11-11 23:35:17.526 UTC [86720] LOG: checkpoint complete: wrote 10841 buffers (66.2%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=12.732 s, sync=0.687 s, total=13.740 s; sync files=36842, longest=0.001 s, average=0.001 s; distance=533155 kB, estimate=533155 kB; lsn=0/2295F2A0, redo lsn=0/22035D7822992026-11-11 23:35:17.528 UTC [86720] LOG: shutting down23002026-11-11 23:35:17.528 UTC [86720] LOG: checkpoint starting: shutdown immediate23012026-11-11 23:35:17.580 UTC [86720] LOG: checkpoint complete: wrote 1220 buffers (7.4%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.029 s, sync=0.022 s, total=0.053 s; sync files=560, longest=0.001 s, average=0.001 s; distance=9381 kB, estimate=480778 kB; lsn=0/2295F318, redo lsn=0/2295F31823022026-11-11 23:35:17.587 UTC [86715] LOG: database system is shut down2303Running OIDC tests...2304=== RUN TestAudienceForIssuer2305=== PAUSE TestAudienceForIssuer2306=== RUN TestGlobMatch2307=== PAUSE TestGlobMatch2308=== RUN TestValidateToken_ValidToken2309=== PAUSE TestValidateToken_ValidToken2310=== RUN TestValidateToken_WrongAudience2311=== PAUSE TestValidateToken_WrongAudience2312=== RUN TestValidateToken_Expired2313=== PAUSE TestValidateToken_Expired2314=== RUN TestValidateToken_BoundClaimsMismatch2315=== PAUSE TestValidateToken_BoundClaimsMismatch2316=== RUN TestValidateToken_BoundSubjectMismatch2317=== PAUSE TestValidateToken_BoundSubjectMismatch2318=== RUN TestValidateToken_MultipleProviders2319=== PAUSE TestValidateToken_MultipleProviders2320=== RUN TestValidateToken_NoMatchingProvider2321=== PAUSE TestValidateToken_NoMatchingProvider2322=== RUN TestValidateToken_KubernetesServiceAccount2323=== PAUSE TestValidateToken_KubernetesServiceAccount2324=== RUN TestNewValidator_KubernetesRequiresCA2325=== PAUSE TestNewValidator_KubernetesRequiresCA2326=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2327=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2328=== RUN TestPins_ReservedForMatchingRule2329=== PAUSE TestPins_ReservedForMatchingRule2330=== RUN TestPins_TopLevelShorthand2331=== PAUSE TestPins_TopLevelShorthand2332=== RUN TestPins_ConfigValidation2333=== PAUSE TestPins_ConfigValidation2334=== RUN TestScopes_LegacyProviderDefaultsToWrite2335=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2336=== RUN TestScopes_Rules2337=== PAUSE TestScopes_Rules2338=== RUN TestScopes_ConfigValidation2339=== PAUSE TestScopes_ConfigValidation2340=== CONT TestAudienceForIssuer2341--- PASS: TestAudienceForIssuer (0.00s)2342=== CONT TestValidateToken_Expired2343=== CONT TestValidateToken_NoMatchingProvider2344=== CONT TestValidateToken_BoundClaimsMismatch2345=== CONT TestValidateToken_KubernetesServiceAccount2346=== CONT TestScopes_ConfigValidation2347=== CONT TestScopes_Rules2348=== CONT TestScopes_LegacyProviderDefaultsToWrite2349=== CONT TestPins_TopLevelShorthand2350--- PASS: TestScopes_ConfigValidation (0.00s)2351=== CONT TestPins_ReservedForMatchingRule2352=== CONT TestPins_ConfigValidation2353=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2354--- PASS: TestPins_ConfigValidation (0.00s)2355=== CONT TestNewValidator_KubernetesRequiresCA2356=== CONT TestValidateToken_WrongAudience2357=== CONT TestValidateToken_MultipleProviders2358=== CONT TestGlobMatch2359=== RUN TestGlobMatch/foo_foo2360=== PAUSE TestGlobMatch/foo_foo2361=== RUN TestGlobMatch/foo_bar2362=== PAUSE TestGlobMatch/foo_bar2363=== RUN TestGlobMatch/*_2364=== PAUSE TestGlobMatch/*_2365=== RUN TestGlobMatch/*_anything2366=== PAUSE TestGlobMatch/*_anything2367=== RUN TestGlobMatch/foo*_foo2368=== PAUSE TestGlobMatch/foo*_foo2369=== RUN TestGlobMatch/foo*_foobar2370=== PAUSE TestGlobMatch/foo*_foobar2371=== RUN TestGlobMatch/foo*_bar2372=== PAUSE TestGlobMatch/foo*_bar2373=== RUN TestGlobMatch/*bar_bar2374=== PAUSE TestGlobMatch/*bar_bar2375=== RUN TestGlobMatch/*bar_foobar2376=== PAUSE TestGlobMatch/*bar_foobar2377=== RUN TestGlobMatch/*bar_foo2378=== PAUSE TestGlobMatch/*bar_foo2379=== RUN TestGlobMatch/foo*bar_foobar2380=== PAUSE TestGlobMatch/foo*bar_foobar2381=== RUN TestGlobMatch/foo*bar_foo123bar2382=== PAUSE TestGlobMatch/foo*bar_foo123bar2383=== RUN TestGlobMatch/foo*bar_foobarbaz2384=== PAUSE TestGlobMatch/foo*bar_foobarbaz2385=== RUN TestGlobMatch/*/*_foo/bar2386=== PAUSE TestGlobMatch/*/*_foo/bar2387=== RUN TestGlobMatch/*/*_foo2388=== PAUSE TestGlobMatch/*/*_foo2389=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2390=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2391=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02392=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02393=== RUN TestGlobMatch/refs/*/main_refs/heads/main2394=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2395=== RUN TestGlobMatch/fo?_foo2396=== PAUSE TestGlobMatch/fo?_foo2397=== RUN TestGlobMatch/fo?_fo2398=== PAUSE TestGlobMatch/fo?_fo2399=== RUN TestGlobMatch/fo?_fooo2400=== PAUSE TestGlobMatch/fo?_fooo2401=== RUN TestGlobMatch/?oo_foo2402=== PAUSE TestGlobMatch/?oo_foo2403=== RUN TestGlobMatch/?oo_boo2404=== PAUSE TestGlobMatch/?oo_boo2405=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2406=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2407=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2408=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2409=== CONT TestGlobMatch/foo_foo2410=== CONT TestValidateToken_ValidToken2411=== CONT TestGlobMatch/*/*_foo/bar2412=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2413=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2414=== CONT TestGlobMatch/?oo_boo2415=== CONT TestGlobMatch/?oo_foo2416=== CONT TestGlobMatch/fo?_fooo2417=== CONT TestGlobMatch/fo?_fo2418=== CONT TestGlobMatch/fo?_foo2419=== CONT TestGlobMatch/refs/*/main_refs/heads/main2420=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02421=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2422=== CONT TestGlobMatch/*/*_foo2423=== CONT TestGlobMatch/*bar_bar2424=== CONT TestGlobMatch/foo*bar_foobarbaz2425=== CONT TestGlobMatch/foo*bar_foo123bar2426=== CONT TestGlobMatch/foo*bar_foobar2427=== CONT TestGlobMatch/*bar_foo2428=== CONT TestGlobMatch/*bar_foobar2429=== CONT TestGlobMatch/foo*_foo2430=== CONT TestGlobMatch/foo*_bar2431=== CONT TestGlobMatch/foo*_foobar2432=== CONT TestGlobMatch/*_2433=== CONT TestGlobMatch/*_anything2434=== CONT TestGlobMatch/foo_bar2435--- PASS: TestGlobMatch (0.00s)2436 --- PASS: TestGlobMatch/foo_foo (0.00s)2437 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2438 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2439 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2440 --- PASS: TestGlobMatch/?oo_boo (0.00s)2441 --- PASS: TestGlobMatch/?oo_foo (0.00s)2442 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2443 --- PASS: TestGlobMatch/fo?_fo (0.00s)2444 --- PASS: TestGlobMatch/fo?_foo (0.00s)2445 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2446 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2447 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2448 --- PASS: TestGlobMatch/*/*_foo (0.00s)2449 --- PASS: TestGlobMatch/*bar_bar (0.00s)2450 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2451 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2452 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2453 --- PASS: TestGlobMatch/*bar_foo (0.00s)2454 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2455 --- PASS: TestGlobMatch/foo*_foo (0.00s)2456 --- PASS: TestGlobMatch/foo*_bar (0.00s)2457 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2458 --- PASS: TestGlobMatch/*_ (0.00s)2459 --- PASS: TestGlobMatch/*_anything (0.00s)2460 --- PASS: TestGlobMatch/foo_bar (0.00s)2461=== CONT TestValidateToken_BoundSubjectMismatch24622026/11/11 23:35:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59344/oidc2463--- PASS: TestValidateToken_BoundSubjectMismatch (0.03s)24642026/11/11 23:35:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59349/oidc2465--- PASS: TestPins_TopLevelShorthand (0.06s)24662026/11/11 23:35:19 http: TLS handshake error from 127.0.0.1:59347: read tcp 127.0.0.1:59346->127.0.0.1:59347: use of closed network connection2467--- PASS: TestNewValidator_KubernetesRequiresCA (0.07s)24682026/11/11 23:35:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59352/oidc2469--- PASS: TestPins_ReservedForMatchingRule (0.08s)24702026/11/11 23:35:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59354/oidc24712026/11/11 23:35:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59356/oidc2472--- PASS: TestScopes_Rules (0.10s)24732026/11/11 23:35:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59358/oidc24742026/11/11 23:35:19 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232475--- PASS: TestValidateToken_BoundClaimsMismatch (0.10s)2476--- PASS: TestValidateToken_WrongAudience (0.09s)2477--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.10s)24782026/11/11 23:35:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59362/oidc2479--- PASS: TestValidateToken_ValidToken (0.10s)24802026/11/11 23:35:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59364/oidc2481--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.12s)24822026/11/11 23:35:19 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59366/oidc2483--- PASS: TestValidateToken_Expired (0.12s)24842026/11/11 23:35:19 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:593682485--- PASS: TestValidateToken_KubernetesServiceAccount (0.14s)24862026/11/11 23:35:19 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59348/oidc24872026/11/11 23:35:19 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:59370/oidc2488--- PASS: TestValidateToken_MultipleProviders (0.13s)24892026/11/11 23:35:19 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:59351/oidc2490--- PASS: TestValidateToken_NoMatchingProvider (0.17s)2491PASS2492Running hook tests...2493=== RUN TestSendPathsEmpty2494=== PAUSE TestSendPathsEmpty2495=== RUN TestQueueEnqueueAndFetch2496=== PAUSE TestQueueEnqueueAndFetch2497=== RUN TestQueueDeduplication2498=== PAUSE TestQueueDeduplication2499=== RUN TestQueueRemove2500=== PAUSE TestQueueRemove2501=== RUN TestQueueFetchBatchLimit2502=== PAUSE TestQueueFetchBatchLimit2503=== RUN TestQueueRetryMovesToBack2504=== PAUSE TestQueueRetryMovesToBack2505=== RUN TestQueueFetchRemoveLifecycle2506=== PAUSE TestQueueFetchRemoveLifecycle2507=== RUN TestQueueConcurrentWriters2508=== PAUSE TestQueueConcurrentWriters2509=== RUN TestQueueRemoveLargeClosure2510=== PAUSE TestQueueRemoveLargeClosure2511=== RUN TestServerClientIntegration2512--- PASS: TestServerClientIntegration (0.00s)2513=== RUN TestServerQueueError25142026/11/11 23:35:19 ERROR Failed to queue paths error="permission denied" count=12515--- PASS: TestServerQueueError (0.00s)2516=== RUN TestGetListenerSocketActivation2517 server_test.go:147: systemd socket activation does not exist on darwin2518--- SKIP: TestGetListenerSocketActivation (0.00s)2519=== RUN TestServerStalledClientDoesNotBlockShutdown2520=== PAUSE TestServerStalledClientDoesNotBlockShutdown2521=== RUN TestServerBacksOffOnAcceptErrors2522=== PAUSE TestServerBacksOffOnAcceptErrors2523=== RUN TestDrainIsolatesPoisonPath2524=== PAUSE TestDrainIsolatesPoisonPath2525=== RUN TestRunNotBlockedByPoisonHead2526=== PAUSE TestRunNotBlockedByPoisonHead2527=== RUN TestDrainGivesUpWhenServerDown2528=== PAUSE TestDrainGivesUpWhenServerDown2529=== RUN TestFailedPathPrunedByLaterClosure2530=== PAUSE TestFailedPathPrunedByLaterClosure2531=== RUN TestWorkerUploadsAndRemoves2532=== PAUSE TestWorkerUploadsAndRemoves2533=== RUN TestWorkerSkipsGCdPaths2534=== PAUSE TestWorkerSkipsGCdPaths2535=== RUN TestWorkerPrunesClosureDeps2536=== PAUSE TestWorkerPrunesClosureDeps2537=== RUN TestDrainTimeout2538=== PAUSE TestDrainTimeout2539=== RUN TestWorkerRemoveFailureIsNotProgress2540=== PAUSE TestWorkerRemoveFailureIsNotProgress2541=== RUN TestWorkerKeepsPathItCannotStat2542=== PAUSE TestWorkerKeepsPathItCannotStat2543=== CONT TestSendPathsEmpty2544=== CONT TestFailedPathPrunedByLaterClosure2545--- PASS: TestSendPathsEmpty (0.00s)2546=== CONT TestWorkerKeepsPathItCannotStat2547=== CONT TestWorkerRemoveFailureIsNotProgress2548=== CONT TestDrainTimeout2549=== CONT TestWorkerPrunesClosureDeps2550=== CONT TestQueueRemoveLargeClosure2551=== CONT TestWorkerUploadsAndRemoves2552=== CONT TestWorkerSkipsGCdPaths2553=== CONT TestDrainIsolatesPoisonPath2554=== CONT TestQueueConcurrentWriters2555=== CONT TestDrainGivesUpWhenServerDown2556=== CONT TestQueueFetchRemoveLifecycle2557=== CONT TestRunNotBlockedByPoisonHead2558=== CONT TestQueueRetryMovesToBack2559=== CONT TestServerBacksOffOnAcceptErrors25602000/01/01 00:00:00 ERROR Accept failed error="too many open files"25612000/01/01 00:00:00 ERROR Accept failed error="too many open files"25622000/01/01 00:00:00 ERROR Accept failed error="too many open files"25632000/01/01 00:00:00 ERROR Accept failed error="too many open files"25642000/01/01 00:00:00 ERROR Accept failed error="too many open files"25652000/01/01 00:00:00 ERROR Accept failed error="too many open files"25662000/01/01 00:00:00 ERROR Accept failed error="too many open files"2567=== CONT TestQueueFetchBatchLimit25682000/01/01 00:00:00 ERROR Accept failed error="too many open files"2569--- PASS: TestServerBacksOffOnAcceptErrors (0.00s)2570=== CONT TestQueueRemove2571=== CONT TestServerStalledClientDoesNotBlockShutdown2572=== CONT TestQueueDeduplication2573=== CONT TestQueueEnqueueAndFetch25742026/11/11 23:35:19 INFO Uploading batch count=125752026/11/11 23:35:19 ERROR Upload failed error="upload failed" count=125762026/11/11 23:35:19 INFO Upload queue status pending=325772026/11/11 23:35:19 INFO Uploading batch count=125782026/11/11 23:35:19 ERROR Upload failed error="upload failed" count=125792026/11/11 23:35:19 INFO Uploading batch count=125802026/11/11 23:35:19 WARN Cannot stat store path, will retry later path=/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestWorkerKeepsPathItCannotStat1666762125/002/locked/aaa error="stat /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestWorkerKeepsPathItCannotStat1666762125/002/locked/aaa: permission denied"25812026/11/11 23:35:19 INFO Uploading batch count=125822026/11/11 23:35:19 INFO Upload queue status pending=225832026/11/11 23:35:19 INFO Uploading batch count=125842026/11/11 23:35:19 INFO Uploading batch count=425852026/11/11 23:35:19 ERROR Upload failed error="upload failed" count=425862026/11/11 23:35:19 WARN Cannot stat store path, will retry later path=/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestWorkerKeepsPathItCannotStat1666762125/002/locked/aaa error="stat /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestWorkerKeepsPathItCannotStat1666762125/002/locked/aaa: permission denied"25872026/11/11 23:35:19 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestDrainIsolatesPoisonPath353461821/002/bbb2588--- PASS: TestQueueDeduplication (0.01s)2589--- PASS: TestQueueRetryMovesToBack (0.01s)2590--- PASS: TestQueueFetchBatchLimit (0.01s)2591--- PASS: TestQueueFetchRemoveLifecycle (0.01s)25922026/11/11 23:35:19 INFO Upload queue status pending=225932026/11/11 23:35:19 INFO Upload queue status pending=225942026/11/11 23:35:19 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestWorkerSkipsGCdPaths4222468354/002/nonexistent25952026/11/11 23:35:19 INFO Uploading batch count=225962026/11/11 23:35:19 WARN Cannot stat store path, will retry later path=/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestWorkerKeepsPathItCannotStat1666762125/002/locked/aaa error="stat /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestWorkerKeepsPathItCannotStat1666762125/002/locked/aaa: permission denied"25972026/11/11 23:35:19 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestWorkerRemoveFailureIsNotProgress2316998320/002/nonexistent25982026/11/11 23:35:19 INFO Uploading batch count=125992026/11/11 23:35:19 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126002026/11/11 23:35:19 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestWorkerRemoveFailureIsNotProgress2316998320/002/nonexistent26012026/11/11 23:35:19 ERROR Drain finished with paths left in queue remaining=126022026/11/11 23:35:19 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126032026/11/11 23:35:19 INFO Uploading batch count=226042026/11/11 23:35:19 ERROR Upload failed error="upload failed" count=226052026/11/11 23:35:19 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestDrainGivesUpWhenServerDown159319301/002/a26062026/11/11 23:35:19 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestWorkerRemoveFailureIsNotProgress2316998320/002/nonexistent26072000/01/01 00:00:00 INFO Uploading batch count=226082026/11/11 23:35:19 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126092026/11/11 23:35:19 INFO Uploading batch count=126102000/01/01 00:00:00 ERROR Upload failed error="context deadline exceeded" count=226112026/11/11 23:35:19 ERROR Upload failed error="upload failed" count=12612--- PASS: TestQueueEnqueueAndFetch (0.01s)26132026/11/11 23:35:19 ERROR Drain finished with paths left in queue remaining=126142000/01/01 00:00:00 ERROR Drain finished with paths left in queue remaining=426152026/11/11 23:35:19 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestDrainGivesUpWhenServerDown159319301/002/b2616--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2617--- PASS: TestQueueRemove (0.02s)26182026/11/11 23:35:19 INFO Uploading batch count=226192026/11/11 23:35:19 ERROR Upload failed error="upload failed" count=226202026/11/11 23:35:19 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestDrainGivesUpWhenServerDown159319301/002/c26212026/11/11 23:35:19 INFO Uploading batch count=126222026/11/11 23:35:19 ERROR Upload failed error="upload failed" count=12623--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)26242026/11/11 23:35:19 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestDrainGivesUpWhenServerDown159319301/002/d26252026/11/11 23:35:19 INFO Uploading batch count=126262026/11/11 23:35:19 ERROR Upload failed error="upload failed" count=126272026/11/11 23:35:19 INFO Uploading batch count=226282026/11/11 23:35:19 ERROR Upload failed error="upload failed" count=226292026/11/11 23:35:19 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestDrainGivesUpWhenServerDown159319301/002/e26302026/11/11 23:35:19 ERROR Drain finished with paths left in queue remaining=126312026/11/11 23:35:19 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestDrainGivesUpWhenServerDown159319301/002/f26322026/11/11 23:35:19 ERROR Drain finished with paths left in queue remaining=102633--- PASS: TestDrainTimeout (0.02s)2634--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)2635--- PASS: TestDrainIsolatesPoisonPath (0.02s)2636--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2637--- PASS: TestWorkerPrunesClosureDeps (0.03s)2638--- PASS: TestWorkerSkipsGCdPaths (0.03s)2639--- PASS: TestWorkerUploadsAndRemoves (0.04s)2640--- PASS: TestQueueRemoveLargeClosure (0.05s)2641--- PASS: TestQueueConcurrentWriters (0.06s)26422026/11/11 23:35:19 ERROR Failed to decode request error="read unix /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/hook3825207448/test.sock->: i/o timeout"26432026/11/11 23:35:19 ERROR Failed to write response error="write unix /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/hook3825207448/test.sock->: i/o timeout"2644--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)26452026/11/11 23:35:20 INFO Uploading batch count=126462026/11/11 23:35:20 INFO Uploading batch count=126472026/11/11 23:35:20 INFO Uploading batch count=126482026/11/11 23:35:20 ERROR Upload failed error="upload failed" count=126492026/11/11 23:35:20 INFO Uploading batch count=126502026/11/11 23:35:20 ERROR Upload failed error="upload failed" count=126512026/11/11 23:35:20 INFO Uploading batch count=126522026/11/11 23:35:20 ERROR Upload failed error="upload failed" count=126532026/11/11 23:35:20 INFO Uploading batch count=126542026/11/11 23:35:20 ERROR Upload failed error="upload failed" count=126552026/11/11 23:35:20 ERROR Drain finished with paths left in queue remaining=12656--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2657PASS2658Running signing tests...2659=== RUN TestExternalSigner2660=== PAUSE TestExternalSigner2661=== RUN TestExternalSignerWrongPublicKey2662=== PAUSE TestExternalSignerWrongPublicKey2663=== RUN TestExternalSignerErrors2664=== PAUSE TestExternalSignerErrors2665=== RUN TestExternalSignerRestartsAfterCrash2666=== PAUSE TestExternalSignerRestartsAfterCrash2667=== RUN TestExternalSignerProgramErrorKeepsProcess2668=== PAUSE TestExternalSignerProgramErrorKeepsProcess2669=== RUN TestExternalSignerClose2670=== PAUSE TestExternalSignerClose2671=== RUN TestExternalSignerRejectsInvalidPublicKey2672=== PAUSE TestExternalSignerRejectsInvalidPublicKey2673=== RUN TestExternalSignerCancellation2674=== PAUSE TestExternalSignerCancellation2675=== RUN TestGenerateFingerprint2676=== PAUSE TestGenerateFingerprint2677=== RUN TestParseSigningKey2678=== PAUSE TestParseSigningKey2679=== RUN TestSign2680=== PAUSE TestSign2681=== RUN TestSignBatch2682=== PAUSE TestSignBatch2683=== RUN TestNilKeyPublicKey2684=== PAUSE TestNilKeyPublicKey2685=== RUN TestSignErrors2686=== PAUSE TestSignErrors2687=== CONT TestExternalSigner2688=== CONT TestExternalSignerProgramErrorKeepsProcess2689=== CONT TestExternalSignerErrors2690=== CONT TestExternalSignerCancellation2691=== CONT TestSignErrors2692=== CONT TestNilKeyPublicKey2693--- PASS: TestNilKeyPublicKey (0.00s)2694=== CONT TestSignBatch2695=== CONT TestSign2696=== CONT TestParseSigningKey2697=== RUN TestParseSigningKey/valid_32-byte_key2698=== PAUSE TestParseSigningKey/valid_32-byte_key2699=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2700=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2701=== RUN TestParseSigningKey/no_colon2702=== PAUSE TestParseSigningKey/no_colon2703=== RUN TestParseSigningKey/empty_name2704=== PAUSE TestParseSigningKey/empty_name2705=== RUN TestParseSigningKey/invalid_base642706=== PAUSE TestParseSigningKey/invalid_base642707=== RUN TestParseSigningKey/wrong_length2708=== PAUSE TestParseSigningKey/wrong_length2709=== CONT TestParseSigningKey/valid_32-byte_key2710=== CONT TestParseSigningKey/wrong_length2711=== CONT TestParseSigningKey/invalid_base642712=== CONT TestParseSigningKey/empty_name2713=== CONT TestParseSigningKey/no_colon2714=== CONT TestGenerateFingerprint2715=== RUN TestGenerateFingerprint/basic_with_references2716=== CONT TestExternalSignerRestartsAfterCrash2717=== CONT TestExternalSignerRejectsInvalidPublicKey2718=== RUN TestExternalSignerRejectsInvalidPublicKey/#002719=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002720=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2721=== CONT TestExternalSignerWrongPublicKey2722=== CONT TestExternalSignerClose2723=== RUN TestExternalSignerErrors/exit_at_startup2724=== PAUSE TestExternalSignerErrors/exit_at_startup2725=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2726=== PAUSE TestGenerateFingerprint/basic_with_references2727=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2728=== RUN TestExternalSignerErrors/invalid_JSON2729=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2730=== PAUSE TestExternalSignerErrors/invalid_JSON2731=== RUN TestGenerateFingerprint/no_references2732=== PAUSE TestGenerateFingerprint/no_references2733=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2734=== RUN TestExternalSignerErrors/wrong_shape2735=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2736=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2737=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2738=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2739=== CONT TestExternalSignerRejectsInvalidPublicKey/#002740=== PAUSE TestExternalSignerErrors/wrong_shape2741=== RUN TestExternalSignerErrors/wrong_id2742=== PAUSE TestExternalSignerErrors/wrong_id2743=== RUN TestExternalSignerErrors/null_signatures2744=== PAUSE TestExternalSignerErrors/null_signatures2745=== RUN TestExternalSignerErrors/missing_signature_name2746=== PAUSE TestExternalSignerErrors/missing_signature_name2747=== RUN TestExternalSignerErrors/wrong_signature_name2748=== PAUSE TestExternalSignerErrors/wrong_signature_name2749=== RUN TestExternalSignerErrors/wrong_signature_length2750=== PAUSE TestExternalSignerErrors/wrong_signature_length2751=== RUN TestExternalSignerErrors/exit_on_request2752=== PAUSE TestExternalSignerErrors/exit_on_request2753=== RUN TestExternalSignerErrors/null2754=== PAUSE TestExternalSignerErrors/null2755=== RUN TestExternalSignerErrors/wrong_signatures_shape2756=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2757=== RUN TestExternalSignerErrors/too_few_signatures2758=== PAUSE TestExternalSignerErrors/too_few_signatures2759=== RUN TestExternalSignerErrors/unrequested_key2760=== PAUSE TestExternalSignerErrors/unrequested_key2761=== RUN TestExternalSignerErrors/invalid_signature_base642762=== PAUSE TestExternalSignerErrors/invalid_signature_base642763=== RUN TestExternalSignerErrors/missing_signatures2764=== PAUSE TestExternalSignerErrors/missing_signatures2765=== RUN TestExternalSignerErrors/program_error2766=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2767=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2768=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2769=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2770=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2771=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2772=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2773--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2774 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2775 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2776 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2777 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2778 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2779=== PAUSE TestExternalSignerErrors/program_error2780=== CONT TestExternalSignerErrors/exit_at_startup2781=== RUN TestSignErrors/nil_key2782=== CONT TestExternalSignerErrors/null2783=== CONT TestExternalSignerErrors/program_error2784=== CONT TestExternalSignerErrors/wrong_id2785=== CONT TestExternalSignerErrors/wrong_signature_length2786--- PASS: TestSign (0.00s)2787=== CONT TestExternalSignerErrors/missing_signatures2788=== CONT TestExternalSignerErrors/wrong_signatures_shape2789--- PASS: TestParseSigningKey (0.00s)2790 --- PASS: TestParseSigningKey/wrong_length (0.00s)2791 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2792 --- PASS: TestParseSigningKey/empty_name (0.00s)2793 --- PASS: TestParseSigningKey/no_colon (0.00s)2794 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2795 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2796=== CONT TestExternalSignerErrors/too_few_signatures2797=== CONT TestExternalSignerErrors/exit_on_request2798=== CONT TestExternalSignerErrors/wrong_signature_name2799=== CONT TestExternalSignerErrors/missing_signature_name2800--- PASS: TestSignBatch (0.00s)2801=== CONT TestExternalSignerErrors/unrequested_key2802=== PAUSE TestSignErrors/nil_key2803=== RUN TestSignErrors/nil_narinfo2804=== PAUSE TestSignErrors/nil_narinfo2805=== CONT TestExternalSignerErrors/wrong_shape2806=== CONT TestExternalSignerErrors/invalid_signature_base642807=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2808=== RUN TestGenerateFingerprint/invalid_nar_hash_length2809=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2810=== CONT TestExternalSignerErrors/invalid_JSON2811=== CONT TestExternalSignerErrors/null_signatures2812=== RUN TestSignErrors/invalid_narinfo2813=== PAUSE TestSignErrors/invalid_narinfo2814=== RUN TestSignErrors/canceled2815=== PAUSE TestSignErrors/canceled2816=== CONT TestSignErrors/nil_key2817=== CONT TestSignErrors/canceled2818=== CONT TestSignErrors/invalid_narinfo2819=== RUN TestGenerateFingerprint/invalid_store_path_prefix2820=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2821=== RUN TestGenerateFingerprint/invalid_reference_prefix2822=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2823=== CONT TestSignErrors/nil_narinfo2824=== CONT TestGenerateFingerprint/basic_with_references2825=== CONT TestGenerateFingerprint/invalid_reference_prefix2826=== CONT TestGenerateFingerprint/invalid_store_path_prefix2827=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2828--- PASS: TestSignErrors (0.01s)2829 --- PASS: TestSignErrors/nil_key (0.00s)2830 --- PASS: TestSignErrors/canceled (0.00s)2831 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2832 --- PASS: TestSignErrors/nil_narinfo (0.00s)2833=== CONT TestGenerateFingerprint/invalid_nar_hash_length2834=== CONT TestGenerateFingerprint/no_references2835=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2836--- PASS: TestGenerateFingerprint (0.01s)2837 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2838 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2839 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2840 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2841 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2842 --- PASS: TestGenerateFingerprint/no_references (0.00s)2843 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2844--- PASS: TestExternalSigner (0.23s)2845--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.43s)2846--- PASS: TestExternalSignerCancellation (0.62s)2847--- PASS: TestExternalSignerClose (1.16s)2848--- PASS: TestExternalSignerWrongPublicKey (1.92s)2849--- PASS: TestExternalSignerRestartsAfterCrash (2.69s)2850/private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestExternalSignerRestartsAfterCrash1096930534/001/sign program: line 7: /private/var/tb/5/scratch/16aa376f2b8bbdfe/build/TestExternalSignerRestartsAfterCrash1096930534/001/sign program.starts: No such file or directory2851--- PASS: TestExternalSignerErrors (0.00s)2852 --- PASS: TestExternalSignerErrors/wrong_id (0.78s)2853 --- PASS: TestExternalSignerErrors/exit_at_startup (0.97s)2854 --- PASS: TestExternalSignerErrors/exit_on_request (1.35s)2855 --- PASS: TestExternalSignerErrors/wrong_signature_name (1.54s)2856 --- PASS: TestExternalSignerErrors/program_error (1.73s)2857 --- PASS: TestExternalSignerErrors/missing_signature_name (2.11s)2858 --- PASS: TestExternalSignerErrors/wrong_shape (2.29s)2859 --- PASS: TestExternalSignerErrors/unrequested_key (2.48s)2860 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (2.86s)2861 --- PASS: TestExternalSignerErrors/too_few_signatures (3.05s)2862 --- PASS: TestExternalSignerErrors/null (3.24s)2863 --- PASS: TestExternalSignerErrors/wrong_signature_length (3.43s)2864 --- PASS: TestExternalSignerErrors/missing_signatures (3.61s)2865 --- PASS: TestExternalSignerErrors/null_signatures (3.80s)2866 --- PASS: TestExternalSignerErrors/invalid_JSON (3.98s)2867 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (4.18s)2868PASS2869Running OpenBao signer tests...2870=== RUN TestSign2871=== PAUSE TestSign2872=== RUN TestSignErrors2873=== PAUSE TestSignErrors2874=== RUN TestServe2875=== PAUSE TestServe2876=== RUN TestServeRejectsGarbage2877=== PAUSE TestServeRejectsGarbage2878=== CONT TestSign2879=== CONT TestSignErrors2880=== CONT TestServe2881=== CONT TestServeRejectsGarbage2882--- PASS: TestServeRejectsGarbage (0.00s)2883=== RUN TestSignErrors/http_error2884=== PAUSE TestSignErrors/http_error2885=== RUN TestSignErrors/invalid_json2886=== PAUSE TestSignErrors/invalid_json2887=== RUN TestSignErrors/no_prefix2888=== PAUSE TestSignErrors/no_prefix2889=== RUN TestSignErrors/invalid_base642890=== PAUSE TestSignErrors/invalid_base642891=== CONT TestSignErrors/http_error2892=== CONT TestSignErrors/no_prefix2893=== CONT TestSignErrors/invalid_base642894=== CONT TestSignErrors/invalid_json2895--- PASS: TestServe (0.00s)2896--- PASS: TestSign (0.00s)2897--- PASS: TestSignErrors (0.00s)2898 --- PASS: TestSignErrors/invalid_json (0.00s)2899 --- PASS: TestSignErrors/invalid_base64 (0.00s)2900 --- PASS: TestSignErrors/no_prefix (0.00s)2901 --- PASS: TestSignErrors/http_error (0.00s)2902PASS