niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #469
· 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.12s)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 TestRetryTimeoutOutlastsMaxRetries115=== CONT TestSetClientTLS116=== CONT TestStreamPushGivesUpOnDeadServer117=== CONT TestStreamPushStopsWhenCanceled118--- PASS: TestStreamPushStopsWhenCanceled (0.00s)119=== CONT TestStreamPushRequestLine120=== CONT TestStreamPushReportsSignatures121=== CONT TestStreamPushReportsSkippedPaths122=== CONT TestEncodeNixBase32123=== CONT TestClientSignaturesByStorePath1242026/11/06 08:38:36 ERROR Upload failed error="connection refused" count=20125=== CONT TestScriptTokenNoExpiryRerunsEveryCall1262026/11/06 08:38:36 ERROR Server seems unavailable, giving up on batch untried=17127=== CONT TestScriptTokenEmptyCommand128=== CONT TestScriptTokenScriptFails129=== CONT TestScriptTokenBadJSON130=== CONT TestScriptTokenEmptyToken131=== CONT TestScriptTokenCachesUntilRefresh132=== RUN TestEncodeNixBase32/test_string_hash133=== CONT TestDoWithRetry_BodyReplayedViaGetBody134=== CONT TestResolveStorePath135=== CONT TestRegisterUploadedObject_OutlivesPush136=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer137=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess138=== CONT TestRateLimiterFeedback139=== CONT TestPathInfoCACompatibility140=== CONT TestParsePathInfoJSONMultiplePaths141=== CONT TestParsePathInfoJSON142--- PASS: TestClientSignaturesByStorePath (0.00s)143--- PASS: TestStreamPushReportsSkippedPaths (0.00s)144=== CONT TestPathInfoHashCompatibility145=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)146=== CONT TestGetStorePathHash147=== RUN TestGetStorePathHash/valid_store_path1482026/11/06 08:38:36 ERROR Upload failed error=boom count=1149--- PASS: TestScriptTokenEmptyCommand (0.00s)150=== CONT TestConvertHashToNix32151=== RUN TestConvertHashToNix32/SRI_format_to_Nix32152=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32153=== RUN TestConvertHashToNix32/already_Nix32_format154=== PAUSE TestConvertHashToNix32/already_Nix32_format155=== RUN TestConvertHashToNix32/invalid_format1562026/11/06 08:38:36 ERROR Upload failed error=boom count=1157=== PAUSE TestConvertHashToNix32/invalid_format158--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)159=== CONT TestFilterOversizedClosures160=== CONT TestEncodeNixBase32WithRealHash161--- PASS: TestStreamPushReportsSignatures (0.00s)162--- PASS: TestEncodeNixBase32WithRealHash (0.00s)163=== CONT TestDumpPathSingleFile164=== CONT TestDumpPathWriterError165=== RUN TestFilterOversizedClosures/no_limit_keeps_everything166=== PAUSE TestEncodeNixBase32/test_string_hash167=== RUN TestEncodeNixBase32/empty_input168=== PAUSE TestEncodeNixBase32/empty_input1692026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:590131702026/11/06 08:38:36 WARN Rate limiter enabled after throttle name=server-test rate=5171=== CONT TestDumpPathMatchesNix172=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything173=== PAUSE TestGetStorePathHash/valid_store_path174=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)175=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon176=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon177=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI178=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI179=== RUN TestPathInfoCACompatibility/null_ca_field180--- PASS: TestScriptTokenScriptFails (0.01s)181=== CONT TestPartSizeForNAR182=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths183=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths184=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths185=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths186=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512187=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512188=== PAUSE TestPathInfoCACompatibility/null_ca_field189=== RUN TestPathInfoCACompatibility/old_string_format_-_text190=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text191=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive192=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive193=== RUN TestPathInfoCACompatibility/new_structured_format_-_text194=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text195=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method196=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method197--- PASS: TestDoServerRequestAttachesToken (0.02s)198=== RUN TestPartSizeForNAR/zero_stays_at_minimum199=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum200=== RUN TestPartSizeForNAR/small_stays_at_minimum201=== PAUSE TestPartSizeForNAR/small_stays_at_minimum202=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum203=== RUN TestRateLimiterFeedback/429_enables_limiter204=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum205=== CONT TestShellSplitErrors206=== CONT TestStreamPushIsolatesFailures207--- PASS: TestShellSplitErrors (0.00s)208=== CONT TestStreamPushBatchesUnderLoad209=== PAUSE TestRateLimiterFeedback/429_enables_limiter210=== RUN TestRateLimiterFeedback/503_enables_limiter211=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts212=== RUN TestParsePathInfoJSON/Nix_format213=== PAUSE TestRateLimiterFeedback/503_enables_limiter2142026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:59013215=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped216=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped217=== RUN TestFilterOversizedClosures/all_closures_skipped218--- PASS: TestRegisterUploadedObject_OutlivesPush (0.01s)219=== PAUSE TestFilterOversizedClosures/all_closures_skipped220=== CONT TestStreamPushReportsEveryPath221=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false222=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false223=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true224=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true2252026/11/06 08:38:36 ERROR Upload failed error="bad path" count=3226=== CONT TestUploadMultipart_ReturnsAfterDroppedBody227=== CONT TestCaseHackSuffix228=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts229=== CONT TestUploadMultipart_PartsInParallel230=== RUN TestSetClientTLS/rejects_connection_without_client_cert231=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert232=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA233=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA234=== RUN TestSetClientTLS/preserves_debug_logging_transport235=== PAUSE TestSetClientTLS/preserves_debug_logging_transport236=== RUN TestGetStorePathHash/basename_without_hyphen_should_error237=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error238=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error239=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error240=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error241=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error242=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun243=== CONT TestFileTokenReadsAndCaches244--- PASS: TestStreamPushIsolatesFailures (0.00s)245=== CONT TestFileTokenMissing246=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica247=== CONT TestFileTokenEmpty248=== PAUSE TestParsePathInfoJSON/Nix_format249=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter250=== RUN TestPartSizeForNAR/1_TiB251=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry2522026/11/06 08:38:36 WARN Rate limiter enabled after throttle name=server-test rate=52532026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:590162542026/11/06 08:38:36 WARN Rate limiter backed off name=server-test rate=52552026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:590162562026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:59013257--- PASS: TestStreamPushReportsEveryPath (0.00s)258--- PASS: TestResolveStorePath (0.01s)259--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.01s)260--- PASS: TestScriptTokenBadJSON (0.02s)261=== CONT TestShellSplit262--- PASS: TestShellSplit (0.00s)263=== CONT TestSetClientTLSErrors264--- PASS: TestFileTokenReadsAndCaches (0.00s)265=== CONT TestSetClientTLSDoesNotMutateDefaultTransport266=== RUN TestParsePathInfoJSON/Lix_format267=== PAUSE TestParsePathInfoJSON/Lix_format268=== RUN TestParsePathInfoJSON/empty_input269=== PAUSE TestParsePathInfoJSON/empty_input270=== RUN TestParsePathInfoJSON/whitespace_only271=== PAUSE TestParsePathInfoJSON/whitespace_only272=== RUN TestParsePathInfoJSON/invalid_JSON273=== PAUSE TestParsePathInfoJSON/invalid_JSON274=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter275=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter276=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter277=== CONT TestDoWithRetry_FinalResponseBodyReadable278=== PAUSE TestPartSizeForNAR/1_TiB2792026/11/06 08:38:36 INFO Garbage collection started280=== CONT TestConvertHashToNix32/SRI_format_to_Nix32281--- PASS: TestFileTokenMissing (0.00s)282--- PASS: TestStreamPushRequestLine (0.03s)283=== RUN TestPartSizeForNAR/5_TiB_S3_max_object284=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object285--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.03s)286=== CONT TestEncodeNixBase32/test_string_hash287=== CONT TestEncodeNixBase32/empty_input288--- PASS: TestEncodeNixBase32 (0.00s)289 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)290 --- PASS: TestEncodeNixBase32/empty_input (0.00s)291=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths292=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)293=== CONT TestPathInfoCACompatibility/null_ca_field294=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI295=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths296--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)297 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)298 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)299=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon300=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method3012026/11/06 08:38:36 WARN Rate limiter enabled after throttle name=s3-test rate=53022026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:590343032026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:590133042026/11/06 08:38:36 WARN Rate limiter enabled after throttle name=server-test rate=53052026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:590363062026/11/06 08:38:36 INFO Garbage collection started307=== CONT TestPathInfoCACompatibility/new_structured_format_-_text308=== CONT TestConvertHashToNix32/invalid_format309=== RUN TestSetClientTLSErrors/missing_cert_file310=== CONT TestConvertHashToNix32/already_Nix32_format311=== CONT TestStaticToken312=== CONT TestRegisterUploadedObjectReusesConnections313=== RUN TestPartSizeForNAR/capped_at_5_GiB3142026/11/06 08:38:36 WARN Rate limiter backed off name=server-test rate=5315=== PAUSE TestPartSizeForNAR/capped_at_5_GiB316=== CONT TestPathInfoCACompatibility/old_string_format_-_text317--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.00s)318=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512319=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false320--- PASS: TestPathInfoHashCompatibility (0.01s)321 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)322 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)323 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)324 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)325=== CONT TestFilterOversizedClosures/all_closures_skipped326=== PAUSE TestSetClientTLSErrors/missing_cert_file327=== RUN TestSetClientTLSErrors/missing_key_file328=== PAUSE TestSetClientTLSErrors/missing_key_file329=== RUN TestSetClientTLSErrors/missing_ca_file330=== PAUSE TestSetClientTLSErrors/missing_ca_file331--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)332=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped333=== RUN TestSetClientTLSErrors/invalid_ca_file334=== PAUSE TestSetClientTLSErrors/invalid_ca_file335--- PASS: TestConvertHashToNix32 (0.00s)336 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)337 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)338 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)339=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true340=== CONT TestFilterOversizedClosures/no_limit_keeps_everything341=== CONT TestSetClientTLS/rejects_connection_without_client_cert342--- PASS: TestStaticToken (0.00s)343=== CONT TestGetStorePathHash/valid_store_path3442026/11/06 08:38:36 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=50345--- PASS: TestScriptTokenEmptyToken (0.03s)346--- PASS: TestFileTokenEmpty (0.00s)347=== CONT TestGetStorePathHash/basename_without_hyphen_should_error348=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error349=== CONT TestRateLimiterFeedback/429_enables_limiter350=== CONT TestParsePathInfoJSON/Nix_format351=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error352--- PASS: TestGetStorePathHash (0.02s)353 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)354 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)355 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)356 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)357=== CONT TestParsePathInfoJSON/invalid_JSON358=== CONT TestParsePathInfoJSON/empty_input359=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA360=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive361--- PASS: TestPathInfoCACompatibility (0.00s)362 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)363 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)364 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)365 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)366 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)367=== CONT TestParsePathInfoJSON/whitespace_only368=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter369=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter370=== CONT TestParsePathInfoJSON/Lix_format371--- PASS: TestParsePathInfoJSON (0.02s)372 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)373 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)374 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)375 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)376 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)377=== CONT TestRateLimiterFeedback/503_enables_limiter378=== CONT TestSetClientTLS/preserves_debug_logging_transport379=== CONT TestPartSizeForNAR/zero_stays_at_minimum380=== CONT TestSetClientTLSErrors/missing_cert_file381=== CONT TestSetClientTLSErrors/invalid_ca_file382=== CONT TestSetClientTLSErrors/missing_ca_file383=== CONT TestSetClientTLSErrors/missing_key_file384--- PASS: TestStreamPushBatchesUnderLoad (0.00s)385 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)386 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)387=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts388=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum389=== CONT TestPartSizeForNAR/small_stays_at_minimum390=== CONT TestPartSizeForNAR/capped_at_5_GiB391=== CONT TestPartSizeForNAR/5_TiB_S3_max_object392=== CONT TestPartSizeForNAR/1_TiB393--- PASS: TestPartSizeForNAR (0.02s)394 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)395 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)396 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)397 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)398 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)399 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)400 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)4012026/11/06 08:38:36 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=2000402--- PASS: TestFilterOversizedClosures (0.01s)403 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)404 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)405 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)4062026/11/06 08:38:36 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=0407--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.01s)4082026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:590134092026/11/06 08:38:36 WARN Rate limiter enabled after throttle name=server-test rate=54102026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:590554112026/11/06 08:38:36 WARN Rate limiter enabled after throttle name=server-test rate=54122026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:59040413--- PASS: TestSetClientTLSErrors (0.01s)414 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)415 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)416 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)417 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)4182026/11/06 08:38:36 WARN Garbage collection finished on another replica. Its statistics are not available here419--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.01s)4202026/11/06 08:38:36 WARN Rate limiter backed off name=server-test rate=54212026/11/06 08:38:36 WARN Rate limiter backed off name=server-test rate=5422--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.02s)4232026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:59013424--- PASS: TestRateLimiterFeedback (0.02s)425 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.01s)426 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.01s)427 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.01s)428 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.01s)4292026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:590134302026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:590134312026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:590134322026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:590134332026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:590134342026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:590134352026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:590134362026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:590134372026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:590134382026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:590134392026/11/06 08:38:36 http: TLS handshake error from 127.0.0.1:59065: remote error: tls: bad certificate440--- PASS: TestSetClientTLS (0.02s)441 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)442 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.02s)443 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.05s)444--- PASS: TestRegisterUploadedObjectReusesConnections (0.05s)4452026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:59013446--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.09s)4472026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:59013448--- PASS: TestDumpPathWriterError (0.11s)449--- PASS: TestScriptTokenCachesUntilRefresh (0.11s)4502026/11/06 08:38:36 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:59022/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:59022/api/uploads/complete4512026/11/06 08:38:36 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:59022/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:59022/api/uploads/complete4522026/11/06 08:38:36 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4532026/11/06 08:38:36 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4542026/11/06 08:38:36 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:59022/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:59022/api/uploads/complete4552026/11/06 08:38:36 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"456--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.13s)4572026/11/06 08:38:36 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:59013458--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.14s)459--- PASS: TestDumpPathSingleFile (0.16s)460--- PASS: TestCaseHackSuffix (0.16s)461--- PASS: TestDumpPathMatchesNix (0.23s)462--- PASS: TestUploadMultipart_PartsInParallel (0.67s)463--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)464PASS465Running server tests...466The files belonging to this database system will be owned by user "_tribuchetbld8".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/8/scratch/2059c74a22533349/build/postgres3130169681/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/8/scratch/2059c74a22533349/build/postgres3130169681/data -l logfile start492493/private/var/tb/8/scratch/2059c74a22533349/build/postgres3130169681:5432 - no response4942026-11-06 08:38:38.883 UTC [18827] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4952026-11-06 08:38:38.883 UTC [18827] LOG: listening on Unix socket "/private/var/tb/8/scratch/2059c74a22533349/build/postgres3130169681/.s.PGSQL.5432"4962026-11-06 08:38:38.895 UTC [18834] LOG: database system was shut down at 2026-11-06 08:38:38 UTC4972026-11-06 08:38:38.897 UTC [18827] LOG: database system is ready to accept connections498/private/var/tb/8/scratch/2059c74a22533349/build/postgres3130169681:5432 - accepting connections499{"timestamp":"2026-11-06T08:38:39.219869Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b335c55f-8ade-4049-aeec-e9cada85abe2","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":6,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}500{"timestamp":"2026-11-06T08:38:39.329169Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"e7f00c5a-45e7-43d2-88d6-7251b28f2378","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(2)"}501{"timestamp":"2026-11-06T08:38:39.4314Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"33c0c2dc-51b7-4491-9ca7-62dc8dc4a9ef","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)"}502=== RUN TestAbortSucceeded503=== PAUSE TestAbortSucceeded504=== RUN TestService_AuthMiddleware505=== PAUSE TestService_AuthMiddleware506=== RUN TestService_AuthMiddleware_MTLSProxyHeader507=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader508=== RUN TestService_AuthMiddleware_MTLSBoundSubjects509=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects510=== RUN TestService_ReadAuthMiddleware511=== PAUSE TestService_ReadAuthMiddleware512=== RUN TestService_AuthMiddleware_OIDC513=== PAUSE TestService_AuthMiddleware_OIDC514=== RUN TestService_RequireScope_OIDC515=== PAUSE TestService_RequireScope_OIDC516=== RUN TestService_ReadScope_PublicByDefault517=== PAUSE TestService_ReadScope_PublicByDefault518=== RUN TestCacheConfigHandler519=== PAUSE TestCacheConfigHandler520=== RUN TestCacheStatsHandler521=== PAUSE TestCacheStatsHandler522=== RUN TestClientCADerivations523=== PAUSE TestClientCADerivations524=== RUN TestClientErrorHandling525=== PAUSE TestClientErrorHandling526=== RUN TestClientIntegration527=== PAUSE TestClientIntegration528=== RUN TestClientMultipleUploads529=== PAUSE TestClientMultipleUploads530=== RUN TestClientWithDependencies531=== PAUSE TestClientWithDependencies532=== RUN TestClientSharedPathCommittedMidPush533=== PAUSE TestClientSharedPathCommittedMidPush534=== RUN TestPinProtectsFromGC535=== PAUSE TestPinProtectsFromGC536=== RUN TestClientPushesUseOnePush537=== PAUSE TestClientPushesUseOnePush538=== RUN TestClientFallsBackToClosures539=== PAUSE TestClientFallsBackToClosures540=== RUN TestDeleteClosuresRacingPins541=== PAUSE TestDeleteClosuresRacingPins542=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock543=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock544=== RUN TestResolveDBConnectionString545=== PAUSE TestResolveDBConnectionString546=== RUN TestConnectWaitsForAPeerMigration547=== PAUSE TestConnectWaitsForAPeerMigration548=== RUN TestLeadElectsOneAndHandsOver549=== PAUSE TestLeadElectsOneAndHandsOver550=== RUN TestLeadIncumbentWinsAfterRestart5512026/11/06 08:38:39 INFO lead: acquired remote=192.0.2.1:12345522026/11/06 08:38:40 INFO lead: released remote=192.0.2.1:12345532026/11/06 08:38:40 INFO lead: acquired remote=192.0.2.1:12345542026/11/06 08:38:41 INFO lead: released remote=192.0.2.1:1234555--- PASS: TestLeadIncumbentWinsAfterRestart (2.17s)556=== RUN TestLeadIncumbentAnnouncesAtOnce557=== PAUSE TestLeadIncumbentAnnouncesAtOnce558=== RUN TestLeadEndsOnShutdown559=== PAUSE TestLeadEndsOnShutdown560=== RUN TestLeadEndsWhenItsConnectionHangs5612026/11/06 08:38:41 INFO lead: acquired remote=192.0.2.1:12345622026-11-06 08:38:43.312 UTC [18949] FATAL: terminating connection due to administrator command5632026/11/06 08:38:43 INFO lead: acquired remote=192.0.2.1:12345642026/11/06 08:38:44 WARN lead: lock connection lost error="timeout: context deadline exceeded"5652026/11/06 08:38:44 INFO lead: released remote=192.0.2.1:12345662026/11/06 08:38:44 INFO lead: released remote=192.0.2.1:1234567--- PASS: TestLeadEndsWhenItsConnectionHangs (2.98s)568=== RUN TestGCAdvisoryLockBlocksConcurrentRun569=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun570=== RUN TestGCBugBareHashReferences571=== PAUSE TestGCBugBareHashReferences572=== RUN TestGCMetrics573=== PAUSE TestGCMetrics574=== RUN TestPushDedupSurvivesConcurrentGC575=== PAUSE TestPushDedupSurvivesConcurrentGC576=== RUN TestDeduplicatedObjectsRecordedAsPending577=== PAUSE TestDeduplicatedObjectsRecordedAsPending578=== RUN TestGCSweepSkipsPendingObjects579=== PAUSE TestGCSweepSkipsPendingObjects580=== RUN TestTombstonedObjectOfferedWithoutWaiting581=== PAUSE TestTombstonedObjectOfferedWithoutWaiting582=== RUN TestGCSweepDeliversEachKeyOnce583=== PAUSE TestGCSweepDeliversEachKeyOnce584=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection585=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection586=== RUN TestForceGCDuringPushOffersSweptObject587=== PAUSE TestForceGCDuringPushOffersSweptObject588=== RUN TestFailedS3DeleteKeepsTombstone589=== PAUSE TestFailedS3DeleteKeepsTombstone590=== RUN TestSweepSkipsRowsLockedByPush591=== PAUSE TestSweepSkipsRowsLockedByPush592=== RUN TestRegisterCompletedObjectNeedsPendingRow593=== PAUSE TestRegisterCompletedObjectNeedsPendingRow594=== RUN TestGetExistingObjectsLocksRows595=== PAUSE TestGetExistingObjectsLocksRows596=== RUN TestSweepRechecksPendingAfterLocking597=== PAUSE TestSweepRechecksPendingAfterLocking598=== RUN TestPushWaitsForSweepHoldingRow599=== PAUSE TestPushWaitsForSweepHoldingRow600=== RUN TestCommitRacingPendingCleanupKeepsObjects601=== PAUSE TestCommitRacingPendingCleanupKeepsObjects602=== RUN TestGCEndsOnShutdown603=== PAUSE TestGCEndsOnShutdown604=== RUN TestGCTaskStore_StartNew605=== PAUSE TestGCTaskStore_StartNew606=== RUN TestGCTaskStore_DeduplicateSameParams607=== PAUSE TestGCTaskStore_DeduplicateSameParams608=== RUN TestGCTaskStore_ConflictDifferentParams609=== PAUSE TestGCTaskStore_ConflictDifferentParams610=== RUN TestGCTaskStore_GetEmpty611=== PAUSE TestGCTaskStore_GetEmpty612=== RUN TestGCTaskStore_GetReturnsLatest613=== PAUSE TestGCTaskStore_GetReturnsLatest614=== RUN TestGCTaskStore_CompletedAllowsNewTask615=== PAUSE TestGCTaskStore_CompletedAllowsNewTask616=== RUN TestGCTaskStore_PhaseUpdates617=== PAUSE TestGCTaskStore_PhaseUpdates618=== RUN TestGCTaskStore_Fail619=== PAUSE TestGCTaskStore_Fail620=== RUN TestGracefulShutdownDrainsInflight621=== PAUSE TestGracefulShutdownDrainsInflight622=== RUN TestService_healthCheckHandler623=== PAUSE TestService_healthCheckHandler624=== RUN TestService_readinessHandler625=== PAUSE TestService_readinessHandler626=== RUN TestGenerateLandingPage627=== PAUSE TestGenerateLandingPage628=== RUN TestEnsureAbortUploadsRule629=== PAUSE TestEnsureAbortUploadsRule630=== RUN TestCacheConfigHandlerMaxNarSize631=== PAUSE TestCacheConfigHandlerMaxNarSize632=== RUN TestCreatePendingClosureRejectsOversizedNAR633=== PAUSE TestCreatePendingClosureRejectsOversizedNAR634=== RUN TestNARDeduplicationMetadataUploadBug635=== PAUSE TestNARDeduplicationMetadataUploadBug636=== RUN TestMetricsInventory637=== PAUSE TestMetricsInventory638=== RUN TestMetricsCommit639=== PAUSE TestMetricsCommit640=== RUN TestService_NativeMTLS641=== PAUSE TestService_NativeMTLS642=== RUN TestServerTLSConfig643=== PAUSE TestServerTLSConfig644=== RUN TestMultipartCleanup645=== PAUSE TestMultipartCleanup646=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded647=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded648=== RUN TestPendingCleanupUsesOneCutoff649=== PAUSE TestPendingCleanupUsesOneCutoff650=== RUN TestObjectStatsTrigger651=== PAUSE TestObjectStatsTrigger652=== RUN TestObjectStatsUpdatedOncePerCommit653=== PAUSE TestObjectStatsUpdatedOncePerCommit654=== RUN TestOrphanedObjectsGC655=== PAUSE TestOrphanedObjectsGC656=== RUN TestOrphanedObjectsGCStressTest657=== PAUSE TestOrphanedObjectsGCStressTest658=== RUN TestCreatePin_ReservedPins659=== PAUSE TestCreatePin_ReservedPins660=== RUN TestPresentReportsOnlyClosureRoots661=== PAUSE TestPresentReportsOnlyClosureRoots662=== RUN TestPresentRefreshesOnlyStaleClosures663=== PAUSE TestPresentRefreshesOnlyStaleClosures664=== RUN TestPresentNotReportedWhileGCDeletesClosure665=== PAUSE TestPresentNotReportedWhileGCDeletesClosure666=== RUN TestParseSingleRange667=== PAUSE TestParseSingleRange668=== RUN TestProxyHeadersOnlyTrustedOnSocket6692026/11/06 08:38:44 INFO Starting HTTP server address=proxy.sock6702026/11/06 08:38:44 INFO Starting HTTP server address=127.0.0.1:593486712026/11/06 08:38:44 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6722026/11/06 08:38:44 INFO Shutdown signal received, draining in-flight requests timeout=10s673--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.22s)674=== RUN TestIsValidCachePath675=== PAUSE TestIsValidCachePath676=== RUN TestReadProxyNarinfo677=== PAUSE TestReadProxyNarinfo678=== RUN TestReadProxyNarinfoAlreadyDecompressed679=== PAUSE TestReadProxyNarinfoAlreadyDecompressed680=== RUN TestReadProxyContentNegotiation681=== PAUSE TestReadProxyContentNegotiation682=== RUN TestReadProxyNarStreaming683=== PAUSE TestReadProxyNarStreaming684=== RUN TestReadProxy404685=== PAUSE TestReadProxy404686=== RUN TestReadProxyInvalidPath687=== PAUSE TestReadProxyInvalidPath688=== RUN TestReadProxyHead689=== PAUSE TestReadProxyHead690=== RUN TestReadProxyOutlastsServerWriteTimeout691=== PAUSE TestReadProxyOutlastsServerWriteTimeout692=== RUN TestReadProxyConditionalGet693=== PAUSE TestReadProxyConditionalGet694=== RUN TestReadProxyRootRedirectsToIndexHTML695=== PAUSE TestReadProxyRootRedirectsToIndexHTML696=== RUN TestReadProxyDisabled697=== PAUSE TestReadProxyDisabled698=== RUN TestReadRedirectNar699=== PAUSE TestReadRedirectNar700=== RUN TestReadRedirectKeepsNarinfoProxied701=== PAUSE TestReadRedirectKeepsNarinfoProxied702=== RUN TestReadProxyRangeRequest703=== PAUSE TestReadProxyRangeRequest704=== RUN TestReadRedirectUsesPublicS3URL705=== PAUSE TestReadRedirectUsesPublicS3URL706=== RUN TestPush_OverlappingRootsStoreOneRowPerKey707=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey708=== RUN TestPush_CompleteCommitsEveryRoot709=== PAUSE TestPush_CompleteCommitsEveryRoot710=== RUN TestPush_RepeatedRootCommitsOnce711=== PAUSE TestPush_RepeatedRootCommitsOnce712=== RUN TestPush_CompleteWaitsForCleanupOfThePush713=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush714=== RUN TestPush_RootsAreLockedInByteOrder715=== PAUSE TestPush_RootsAreLockedInByteOrder716=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit717=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit718=== RUN TestPush_RejectsBadRequests719=== PAUSE TestPush_RejectsBadRequests720=== RUN TestPush_SignsNarinfosOfItsPendingObjects721=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects722=== RUN TestSharedNarBothUploadsComplete723=== PAUSE TestSharedNarBothUploadsComplete724=== RUN TestCompleteMultipartUpload_ErrorButObjectExists725=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists726=== RUN TestCompletedNarNotReofferedAcrossClosures727=== PAUSE TestCompletedNarNotReofferedAcrossClosures728=== RUN TestPresignedUploadRegisteredBeforeCommit729=== PAUSE TestPresignedUploadRegisteredBeforeCommit730=== RUN TestService_Rustfstest731=== PAUSE TestService_Rustfstest732=== RUN TestParseSize733=== PAUSE TestParseSize734=== RUN TestSkippedUploadsHandler735=== PAUSE TestSkippedUploadsHandler736=== RUN TestSystemdListenerNotActivated737--- PASS: TestSystemdListenerNotActivated (0.00s)738=== RUN TestWatchdogBeatsWhenHealthy739--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)740=== RUN TestWatchdogSkipsWhenUnhealthy7412026/11/06 08:38:44 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7422026/11/06 08:38:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7432026/11/06 08:38:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7442026/11/06 08:38:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7452026/11/06 08:38:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7462026/11/06 08:38:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7472026/11/06 08:38:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7482026/11/06 08:38:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7492026/11/06 08:38:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7502026/11/06 08:38:45 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"751--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)752=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle753=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle754=== RUN TestProxyWriteTimeout755=== PAUSE TestProxyWriteTimeout756=== RUN TestPendingClosureWriteTimeout757=== PAUSE TestPendingClosureWriteTimeout758=== RUN TestIsValidUploadKey759=== PAUSE TestIsValidUploadKey760=== RUN TestUploadHandlersRejectInvalidKeys761=== PAUSE TestUploadHandlersRejectInvalidKeys762=== RUN TestUploadHandlersRejectOversizedBody763=== PAUSE TestUploadHandlersRejectOversizedBody764=== RUN TestService_cleanupPendingClosuresHandler765=== PAUSE TestService_cleanupPendingClosuresHandler766=== RUN TestService_createPendingClosureHandler767=== PAUSE TestService_createPendingClosureHandler768=== RUN TestService_verifyS3Integrity769=== PAUSE TestService_verifyS3Integrity770=== RUN TestService_verifyS3ReuploadsStaleNarinfo771=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo772=== RUN TestCompleteMultipartUnregistered773=== PAUSE TestCompleteMultipartUnregistered774=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT775=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT776=== CONT TestService_verifyS3Integrity777=== CONT TestParseSize778--- PASS: TestParseSize (0.00s)779=== CONT TestService_Rustfstest780=== CONT TestGracefulShutdownDrainsInflight781=== CONT TestCompletedNarNotReofferedAcrossClosures782=== CONT TestAbortSucceeded783--- PASS: TestAbortSucceeded (0.00s)784=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT785=== CONT TestCompleteMultipartUnregistered786=== CONT TestReadProxyNarinfo787=== CONT TestCompleteMultipartUpload_ErrorButObjectExists788=== CONT TestService_verifyS3ReuploadsStaleNarinfo789=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed790=== CONT TestReadProxyNarinfoAlreadyDecompressed791=== CONT TestSharedNarBothUploadsComplete7922026/11/06 08:38:45 INFO Starting HTTP server address=127.0.0.1:59358793=== CONT TestService_cleanupPendingClosuresHandler794=== CONT TestUploadHandlersRejectOversizedBody795=== CONT TestUploadHandlersRejectInvalidKeys796=== CONT TestIsValidUploadKey797=== RUN TestIsValidUploadKey/narinfo798=== PAUSE TestIsValidUploadKey/narinfo799=== RUN TestIsValidUploadKey/nar_zst800=== PAUSE TestIsValidUploadKey/nar_zst801=== CONT TestPendingClosureWriteTimeout802=== CONT TestProxyWriteTimeout803=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle804=== CONT TestSkippedUploadsHandler805=== CONT TestPresignedUploadRegisteredBeforeCommit806=== CONT TestPush_SignsNarinfosOfItsPendingObjects807=== CONT TestPush_RejectsBadRequests808=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit809=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed810=== CONT TestService_createPendingClosureHandler811=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info812=== RUN TestPendingClosureWriteTimeout/empty813=== PAUSE TestPendingClosureWriteTimeout/empty814=== RUN TestPendingClosureWriteTimeout/400_objects815=== PAUSE TestPendingClosureWriteTimeout/400_objects816=== RUN TestPendingClosureWriteTimeout/670k_objects817=== PAUSE TestPendingClosureWriteTimeout/670k_objects818=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline819=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline8202026/11/06 08:38:46 INFO Client skipped oversized paths paths=3 nar_bytes=5000000000821=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info822=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal823=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal824=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key825=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key826=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key827=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key828=== RUN TestProxyWriteTimeout/narinfo829=== PAUSE TestProxyWriteTimeout/narinfo830=== RUN TestProxyWriteTimeout/1_GiB_nar831=== PAUSE TestProxyWriteTimeout/1_GiB_nar832=== RUN TestProxyWriteTimeout/10_GiB_nar833=== PAUSE TestProxyWriteTimeout/10_GiB_nar834=== RUN TestProxyWriteTimeout/unknown_size835=== PAUSE TestProxyWriteTimeout/unknown_size836=== CONT TestIsValidCachePath837=== RUN TestIsValidCachePath/narinfo838=== PAUSE TestIsValidCachePath/narinfo839=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars840=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars841=== RUN TestIsValidCachePath/nar_zst842=== PAUSE TestIsValidCachePath/nar_zst843=== RUN TestIsValidCachePath/nar_xz844=== PAUSE TestIsValidCachePath/nar_xz845=== RUN TestIsValidCachePath/nar_bz2846=== PAUSE TestIsValidCachePath/nar_bz2847=== RUN TestIsValidCachePath/nar_uncompressed848=== PAUSE TestIsValidCachePath/nar_uncompressed849=== RUN TestIsValidCachePath/ls850=== PAUSE TestIsValidCachePath/ls851=== RUN TestIsValidCachePath/log852=== PAUSE TestIsValidCachePath/log853=== RUN TestIsValidCachePath/realisation854=== PAUSE TestIsValidCachePath/realisation855=== RUN TestIsValidCachePath/nix-cache-info856=== PAUSE TestIsValidCachePath/nix-cache-info857=== RUN TestIsValidCachePath/index.html858=== PAUSE TestIsValidCachePath/index.html859=== RUN TestIsValidCachePath/traversal_parent860=== PAUSE TestIsValidCachePath/traversal_parent861=== RUN TestIsValidCachePath/traversal_in_middle862=== PAUSE TestIsValidCachePath/traversal_in_middle863=== RUN TestIsValidCachePath/invalid_char_e864=== PAUSE TestIsValidCachePath/invalid_char_e865=== RUN TestIsValidCachePath/invalid_char_u866=== PAUSE TestIsValidCachePath/invalid_char_u867=== RUN TestIsValidCachePath/random_path868=== PAUSE TestIsValidCachePath/random_path869=== RUN TestIsValidCachePath/empty870=== RUN TestIsValidUploadKey/nar_xz8712026/11/06 08:38:46 INFO Shutdown signal received, draining in-flight requests timeout=10s872=== CONT TestParseSingleRange873=== RUN TestParseSingleRange/none874=== PAUSE TestParseSingleRange/none875=== RUN TestParseSingleRange/unknown_unit876=== PAUSE TestParseSingleRange/unknown_unit877=== RUN TestParseSingleRange/multi-range_ignored878=== PAUSE TestParseSingleRange/multi-range_ignored879=== RUN TestParseSingleRange/malformed_no_dash880=== PAUSE TestParseSingleRange/malformed_no_dash881=== RUN TestParseSingleRange/malformed_both_empty882=== PAUSE TestParseSingleRange/malformed_both_empty883=== CONT TestPresentNotReportedWhileGCDeletesClosure884=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed885=== RUN TestParseSingleRange/malformed_end_before_start886=== PAUSE TestParseSingleRange/malformed_end_before_start887=== RUN TestParseSingleRange/closed888=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale889=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale890=== PAUSE TestIsValidUploadKey/nar_xz891=== RUN TestIsValidUploadKey/nar_plain892=== PAUSE TestIsValidCachePath/empty893=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed894=== PAUSE TestParseSingleRange/closed895=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh896=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh897=== RUN TestIsValidCachePath/leading_slash898=== PAUSE TestIsValidCachePath/leading_slash899=== RUN TestIsValidCachePath/wrong_extension900=== PAUSE TestIsValidCachePath/wrong_extension901=== RUN TestIsValidCachePath/short_hash902=== PAUSE TestIsValidCachePath/short_hash903=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost904=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost905=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed906=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed907=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed908=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed909=== RUN TestParseSingleRange/open-ended910=== PAUSE TestParseSingleRange/open-ended911=== RUN TestParseSingleRange/end_clamped_to_size912=== PAUSE TestParseSingleRange/end_clamped_to_size913=== RUN TestParseSingleRange/suffix914=== PAUSE TestParseSingleRange/suffix915=== RUN TestParseSingleRange/suffix_exceeds_size916=== PAUSE TestParseSingleRange/suffix_exceeds_size917=== RUN TestParseSingleRange/single_byte918=== PAUSE TestParseSingleRange/single_byte919=== CONT TestCreatePin_ReservedPins920--- PASS: TestSkippedUploadsHandler (0.02s)921=== RUN TestParseSingleRange/start_past_EOF922=== PAUSE TestParseSingleRange/start_past_EOF923=== RUN TestParseSingleRange/start_far_past_EOF924=== PAUSE TestParseSingleRange/start_far_past_EOF925=== CONT TestOrphanedObjectsGC926=== CONT TestPresentRefreshesOnlyStaleClosures927=== PAUSE TestIsValidUploadKey/nar_plain928=== RUN TestIsValidUploadKey/listing929=== PAUSE TestIsValidUploadKey/listing930=== RUN TestIsValidUploadKey/build_log931=== PAUSE TestIsValidUploadKey/build_log932=== RUN TestIsValidUploadKey/build_log_home-manager_file933=== PAUSE TestIsValidUploadKey/build_log_home-manager_file934=== RUN TestIsValidUploadKey/build_log_plus_in_name935=== PAUSE TestIsValidUploadKey/build_log_plus_in_name936=== RUN TestIsValidUploadKey/build_log_question_mark937=== PAUSE TestIsValidUploadKey/build_log_question_mark938=== RUN TestIsValidUploadKey/build_log_equals939=== PAUSE TestIsValidUploadKey/build_log_equals940=== RUN TestIsValidUploadKey/realisation941=== PAUSE TestIsValidUploadKey/realisation942=== RUN TestIsValidUploadKey/realisation_plus_in_output943=== PAUSE TestIsValidUploadKey/realisation_plus_in_output944=== RUN TestIsValidUploadKey/nix-cache-info945=== PAUSE TestIsValidUploadKey/nix-cache-info946=== RUN TestIsValidUploadKey/index.html947=== PAUSE TestIsValidUploadKey/index.html948=== RUN TestIsValidUploadKey/narinfo_key,_nar_type949=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type950=== RUN TestIsValidUploadKey/nar_key,_narinfo_type951=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type952=== RUN TestIsValidUploadKey/listing_key,_narinfo_type953=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type954=== RUN TestIsValidUploadKey/traversal955=== PAUSE TestIsValidUploadKey/traversal956=== RUN TestIsValidUploadKey/traversal_nar957=== PAUSE TestIsValidUploadKey/traversal_nar958=== RUN TestIsValidUploadKey/absolute959=== PAUSE TestIsValidUploadKey/absolute960=== RUN TestIsValidUploadKey/empty_key961=== PAUSE TestIsValidUploadKey/empty_key962=== RUN TestIsValidUploadKey/unknown_type963=== PAUSE TestIsValidUploadKey/unknown_type964=== CONT TestPresentReportsOnlyClosureRoots965=== CONT TestOrphanedObjectsGCStressTest966=== CONT TestObjectStatsUpdatedOncePerCommit9672026/11/06 08:38:46 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59361/oidc968=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure969=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure970=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart971=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart972=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts973=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts974=== CONT TestObjectStatsTrigger975--- PASS: TestGracefulShutdownDrainsInflight (1.05s)976=== CONT TestPendingCleanupUsesOneCutoff9772026/11/06 08:38:47 INFO Received uploads request method=POST path=/api/pending_closures9782026/11/06 08:38:48 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>979--- PASS: TestReadProxyNarinfo (3.07s)980=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded9812026/11/06 08:38:48 INFO Received uploads request method=POST path=/api/pending_closures982--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (3.13s)983=== CONT TestMultipartCleanup9842026/11/06 08:38:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete9852026/11/06 08:38:48 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst986--- PASS: TestCompleteMultipartUnregistered (3.23s)987=== CONT TestServerTLSConfig988=== RUN TestServerTLSConfig/no_client_CA989=== PAUSE TestServerTLSConfig/no_client_CA990=== RUN TestServerTLSConfig/missing_CA_file991=== PAUSE TestServerTLSConfig/missing_CA_file992=== RUN TestServerTLSConfig/not_a_PEM_file993=== PAUSE TestServerTLSConfig/not_a_PEM_file994=== CONT TestService_NativeMTLS995--- PASS: TestReadProxyNarinfoAlreadyDecompressed (3.39s)996=== CONT TestMetricsCommit9972026/11/06 08:38:48 INFO Received uploads request method=POST path=/api/pending_closures998--- PASS: TestService_Rustfstest (3.71s)999=== CONT TestMetricsInventory10002026/11/06 08:38:48 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10012026/11/06 08:38:48 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=Yjk4MjNjN2YtNWM5MC00N2IzLWIxMDYtZTQxNDAzY2EzMzFiLjAwOWRmOTY1LWUzODMtNDNiNC05NDVkLTYxODI4NTU1YjMxZngxNzkzOTU0MzI3NzUwNTAyMDAw parts=1010022026/11/06 08:38:48 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10032026/11/06 08:38:48 INFO Completed upload id=1 objects=2 duration=9.408ms10042026/11/06 08:38:49 INFO Received uploads request method=POST path=/api/pending_closures10052026/11/06 08:38:49 INFO Received uploads request method=POST path=/api/pending_closures10062026/11/06 08:38:49 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo10072026/11/06 08:38:49 WARN Found objects in DB but missing from S3, will re-upload count=11008--- PASS: TestService_verifyS3Integrity (3.87s)1009=== CONT TestNARDeduplicationMetadataUploadBug10102026/11/06 08:38:49 INFO Received cleanup request method=DELETE path=/api/pending_closures10112026/11/06 08:38:49 INFO Aborted multipart uploads count=0 kept=010122026/11/06 08:38:49 INFO Received uploads request method=POST path=/api/pending_closures10132026/11/06 08:38:49 INFO Received cleanup request method=DELETE path=/api/pending_closures10142026/11/06 08:38:49 INFO Aborted multipart uploads count=1 kept=010152026/11/06 08:38:49 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete10162026-11-06 08:38:49.218 UTC [19240] ERROR: Closure does not exist: id=110172026-11-06 08:38:49.218 UTC [19240] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE10182026-11-06 08:38:49.218 UTC [19240] STATEMENT: -- name: CommitPendingClosure :one1019 SELECT commit_pending_closure($1::bigint)::bigint1020 1021--- PASS: TestService_cleanupPendingClosuresHandler (4.05s)1022=== CONT TestCreatePendingClosureRejectsOversizedNAR10232026/11/06 08:38:49 INFO Received uploads request method=POST path=/api/pending_closures1024--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1025=== CONT TestCacheConfigHandlerMaxNarSize1026--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1027=== CONT TestEnsureAbortUploadsRule10282026/11/06 08:38:49 INFO Received uploads request method=POST path=/api/pending_closures10292026/11/06 08:38:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10302026/11/06 08:38:49 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1031--- PASS: TestObjectStatsUpdatedOncePerCommit (3.78s)1032=== CONT TestGenerateLandingPage1033--- PASS: TestGenerateLandingPage (0.00s)1034=== CONT TestService_readinessHandler10352026/11/06 08:38:49 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=Yjk4MjNjN2YtNWM5MC00N2IzLWIxMDYtZTQxNDAzY2EzMzFiLjcwNTBmOGQwLTg2NGEtNGE4My1iMDFjLTgyNTBhYWNlNTFlNHgxNzkzOTU0MzI4NzI1MDI1MDAw parts=1210362026/11/06 08:38:49 INFO Received uploads request method=POST path=/api/pending_closures1037--- PASS: TestCompletedNarNotReofferedAcrossClosures (4.77s)1038=== CONT TestService_healthCheckHandler10392026/11/06 08:38:49 INFO Received push request method=POST path=/api/pushes10402026/11/06 08:38:50 INFO Received complete push request method=POST path=/api/pushes/1/complete10412026/11/06 08:38:50 INFO Completed push id=1 objects=4 duration=19.046208ms10422026/11/06 08:38:50 INFO Received push request method=POST path=/api/pushes10432026/11/06 08:38:50 INFO Aborted multipart uploads count=0 kept=010442026/11/06 08:38:50 WARN Force mode enabled - objects will be deleted immediately without grace period10452026/11/06 08:38:50 INFO Received uploads request method=POST path=/api/pending_closures10462026/11/06 08:38:50 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=010472026/11/06 08:38:50 INFO Vacuumed table table=pending_closures10482026/11/06 08:38:50 INFO Vacuumed table table=pending_objects10492026/11/06 08:38:50 INFO Vacuumed table table=multipart_uploads10502026/11/06 08:38:50 INFO Vacuumed table table=closures10512026/11/06 08:38:50 INFO Vacuumed table table=objects10522026/11/06 08:38:50 INFO Received complete push request method=POST path=/api/pushes/2/complete10532026/11/06 08:38:50 INFO Completed push id=2 objects=4 duration=4.271083ms1054--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (4.21s)1055=== CONT TestGCAdvisoryLockBlocksConcurrentRun10562026/11/06 08:38:50 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10572026/11/06 08:38:50 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Yjk4MjNjN2YtNWM5MC00N2IzLWIxMDYtZTQxNDAzY2EzMzFiLmM1Zjc3ZDlmLWI0Y2EtNGM1YS05NTQ4LWQ4MmIyODdjYjM3ZXgxNzkzOTU0MzMwMTQ3NTExMDAw10582026/11/06 08:38:50 INFO Received push request method=POST path=/api/pushes10592026/11/06 08:38:50 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=Yjk4MjNjN2YtNWM5MC00N2IzLWIxMDYtZTQxNDAzY2EzMzFiLmM1Zjc3ZDlmLWI0Y2EtNGM1YS05NTQ4LWQ4MmIyODdjYjM3ZXgxNzkzOTU0MzMwMTQ3NTExMDAw parts=11060--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (5.20s)1061=== CONT TestGCTaskStore_Fail1062--- PASS: TestGCTaskStore_Fail (0.00s)1063=== CONT TestGCTaskStore_PhaseUpdates1064--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1065=== CONT TestGCTaskStore_CompletedAllowsNewTask1066--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1067=== CONT TestGCTaskStore_GetReturnsLatest1068--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)1069=== CONT TestFailedS3DeleteKeepsTombstone10702026/11/06 08:38:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10712026/11/06 08:38:50 INFO Signed narinfos id=1 count=110722026/11/06 08:38:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10732026/11/06 08:38:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10742026/11/06 08:38:50 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"10752026/11/06 08:38:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10762026/11/06 08:38:50 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"10772026/11/06 08:38:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10782026/11/06 08:38:50 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=110792026/11/06 08:38:50 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign10802026/11/06 08:38:50 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo1081--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (4.37s)1082=== CONT TestForceGCDuringPushOffersSweptObject1083=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1084=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1085=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1086=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1087=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection10882026/11/06 08:38:50 INFO Received uploads request method=POST path=/api/pending_closures10892026/11/06 08:38:50 INFO Received uploads request method=POST path=/api/pending_closures10902026/11/06 08:38:50 INFO Received uploads request method=POST path=/api/pending_closures10912026/11/06 08:38:50 INFO Received uploads request method=POST path=/api/pending_closures10922026/11/06 08:38:50 INFO Received uploads request method=POST path=/api/pending_closures1093=== NAME TestOrphanedObjectsGC1094 orphaned_objects_gc_test.go:287: GC Test Summary:1095 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1096 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1097 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1098 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1099 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1100--- PASS: TestOrphanedObjectsGC (4.90s)1101=== CONT TestSweepSkipsRowsLockedByPush1102--- PASS: TestObjectStatsTrigger (5.03s)1103=== CONT TestGCSweepDeliversEachKeyOnce11042026/11/06 08:38:51 INFO Received uploads request method=POST path=/api/pending_closures11052026/11/06 08:38:51 INFO Received uploads request method=POST path=/api/pending_closures11062026/11/06 08:38:51 INFO Received cleanup request method=DELETE path=/api/pending_closures11072026/11/06 08:38:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11082026/11/06 08:38:51 WARN Refused reserved pin name=worker-x86_64-linux11092026/11/06 08:38:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux11102026/11/06 08:38:51 INFO Received create pin request method=POST path=/api/pins/my-app11112026/11/06 08:38:51 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1112--- PASS: TestCreatePin_ReservedPins (5.59s)1113=== CONT TestGCTaskStore_GetEmpty1114--- PASS: TestGCTaskStore_GetEmpty (0.00s)1115=== CONT TestGCTaskStore_ConflictDifferentParams1116--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)1117=== CONT TestGCTaskStore_DeduplicateSameParams1118--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)1119=== CONT TestGCTaskStore_StartNew1120--- PASS: TestGCTaskStore_StartNew (0.00s)1121=== CONT TestGCEndsOnShutdown1122=== RUN TestGCEndsOnShutdown/before_the_run1123=== PAUSE TestGCEndsOnShutdown/before_the_run1124=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1125=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete1126=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1127=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1128=== CONT TestTombstonedObjectOfferedWithoutWaiting1129--- PASS: TestPresentReportsOnlyClosureRoots (5.89s)1130=== CONT TestCommitRacingPendingCleanupKeepsObjects11312026/11/06 08:38:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11322026/11/06 08:38:52 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11332026/11/06 08:38:52 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=Yjk4MjNjN2YtNWM5MC00N2IzLWIxMDYtZTQxNDAzY2EzMzFiLjkxNmRmYWI1LWEzMmYtNDJhMS1hN2JiLTQwM2UyOTFmMGEyZXgxNzkzOTU0MzMwOTkxNjE4MDAw parts=1011342026/11/06 08:38:52 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete11352026/11/06 08:38:52 INFO Completed upload id=1 objects=2 duration=13.58525ms11362026/11/06 08:38:52 INFO Received get closure request method=GET path=/api/closures/0000000000000000000000000000000011372026/11/06 08:38:52 INFO Received uploads request method=POST path=/api/pending_closures11382026/11/06 08:38:52 INFO Starting cleanup of old closures method=DELETE path=/api/closures11392026/11/06 08:38:52 INFO Received uploads request method=POST path=/api/pending_closures11402026/11/06 08:38:52 INFO Aborted multipart uploads count=0 kept=011412026/11/06 08:38:52 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Yjk4MjNjN2YtNWM5MC00N2IzLWIxMDYtZTQxNDAzY2EzMzFiLmI5M2FiZDJhLThjNGYtNGYxNS04MDFiLWNkOGYzNjM5YmYwYXgxNzkzOTU0MzMwNjA4NTgwMDAw parts=1211422026/11/06 08:38:52 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=011432026/11/06 08:38:52 INFO Vacuumed table table=pending_closures11442026/11/06 08:38:52 INFO Vacuumed table table=pending_objects11452026/11/06 08:38:52 INFO Vacuumed table table=multipart_uploads11462026/11/06 08:38:52 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst11472026/11/06 08:38:52 INFO Received uploads request method=POST path=/api/pending_closures11482026/11/06 08:38:52 INFO Vacuumed table table=closures1149--- PASS: TestPresignedUploadRegisteredBeforeCommit (6.27s)1150=== CONT TestGCSweepSkipsPendingObjects11512026/11/06 08:38:52 INFO Vacuumed table table=objects11522026/11/06 08:38:52 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000001153--- PASS: TestService_createPendingClosureHandler (6.34s)1154=== CONT TestPushWaitsForSweepHoldingRow1155--- PASS: TestPresentRefreshesOnlyStaleClosures (6.63s)1156=== CONT TestDeduplicatedObjectsRecordedAsPending1157=== RUN TestPush_RejectsBadRequests/root_not_in_objects1158=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects1159=== RUN TestPush_RejectsBadRequests/no_roots1160=== PAUSE TestPush_RejectsBadRequests/no_roots1161=== RUN TestPush_RejectsBadRequests/no_objects1162=== PAUSE TestPush_RejectsBadRequests/no_objects1163=== RUN TestPush_RejectsBadRequests/bad_root1164=== PAUSE TestPush_RejectsBadRequests/bad_root1165=== CONT TestSweepRechecksPendingAfterLocking11662026/11/06 08:38:53 INFO Received uploads request method=POST path=/api/pending_closures1167--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (5.07s)1168=== CONT TestPushDedupSurvivesConcurrentGC11692026/11/06 08:38:53 WARN mTLS auth: subject not in bound subjects subject="CN=reader"11702026/11/06 08:38:53 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1171--- PASS: TestService_NativeMTLS (5.05s)1172=== CONT TestGetExistingObjectsLocksRows11732026/11/06 08:38:53 INFO Received complete multipart upload request method=POST path=/api/multipart/complete11742026/11/06 08:38:53 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=Yjk4MjNjN2YtNWM5MC00N2IzLWIxMDYtZTQxNDAzY2EzMzFiLjdjNjhlNjA2LTAyN2QtNGJkOC1hYTU3LTljNDFjNTNkNTI5YngxNzkzOTU0MzMwNjQzNjg2MDAw parts=121175--- PASS: TestSharedNarBothUploadsComplete (8.42s)1176=== CONT TestRegisterCompletedObjectNeedsPendingRow11772026/11/06 08:38:53 WARN Rate limiter enabled after throttle name=s3-test rate=511782026/11/06 08:38:53 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1179=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1180 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101181 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001182--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (7.64s)1183=== CONT TestReadProxyDisabled11842026/11/06 08:38:53 INFO Received uploads request method=POST path=/api/pending_closures11852026/11/06 08:38:53 INFO Received cleanup request method=DELETE path=/api/pending_closures11862026/11/06 08:38:53 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket30/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""11872026/11/06 08:38:53 INFO Aborted multipart uploads count=0 kept=111882026/11/06 08:38:53 INFO Received cleanup request method=DELETE path=/api/pending_closures11892026/11/06 08:38:53 INFO Aborted multipart uploads count=1 kept=01190--- PASS: TestMultipartCleanup (5.67s)1191=== CONT TestPush_CompleteWaitsForCleanupOfThePush11922026/11/06 08:38:54 INFO Received push request method=POST path=/api/pushes11932026/11/06 08:38:54 INFO Received complete push request method=POST path=/api/pushes/1/complete11942026/11/06 08:38:54 INFO Completed push id=1 objects=4 duration=32.565792ms11952026/11/06 08:38:54 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete11962026/11/06 08:38:54 INFO Completed upload id=2 objects=2 duration=1.003417ms1197--- PASS: TestMetricsCommit (5.60s)1198=== CONT TestGCMetrics1199--- PASS: TestMetricsInventory (5.70s)1200=== CONT TestPush_RepeatedRootCommitsOnce1201=== NAME TestNARDeduplicationMetadataUploadBug1202 metadata_upload_test.go:48: First store path: /private/var/tb/8/scratch/2059c74a22533349/build/TestNARDeduplicationMetadataUploadBug1515180997/001/store/mlrdpsdb88apb6hxrgx45i8djx78wip3-file1.txt12032026/11/06 08:38:54 INFO Received push request method=POST path=/api/pushes12042026/11/06 08:38:54 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12052026/11/06 08:38:54 INFO Uploading mlrdpsdb88apb6hxrgx45i8djx78wip3-file1.txt (160B)12062026/11/06 08:38:54 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket34 days=21207--- PASS: TestEnsureAbortUploadsRule (5.76s)1208=== CONT TestGCBugBareHashReferences12092026/11/06 08:38:55 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12102026/11/06 08:38:55 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12112026/11/06 08:38:55 WARN Failed to register uploaded object key=mlrdpsdb88apb6hxrgx45i8djx78wip3.ls error="server returned 404: 404 page not found\n"12122026/11/06 08:38:55 INFO Signed narinfos id=1 count=112132026/11/06 08:38:55 INFO Uploading 1 narinfos12142026/11/06 08:38:55 INFO Received complete push request method=POST path=/api/pushes/1/complete12152026/11/06 08:38:55 WARN Failed to register uploaded object key=mlrdpsdb88apb6hxrgx45i8djx78wip3.narinfo error="server returned 404: 404 page not found\n"12162026/11/06 08:38:55 INFO Completed push id=1 objects=3 duration=33.000125ms12172026/11/06 08:38:55 INFO Upload complete. (389ms)1218=== NAME TestNARDeduplicationMetadataUploadBug1219 metadata_upload_test.go:54: Retrieved narinfo from S3:1220 StorePath: /private/var/tb/8/scratch/2059c74a22533349/build/TestNARDeduplicationMetadataUploadBug1515180997/001/store/mlrdpsdb88apb6hxrgx45i8djx78wip3-file1.txt1221 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1222 Compression: zstd1223 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1224 NarSize: 1601225 References: 1226 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1227 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1228 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1229 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}12302026/11/06 08:38:55 WARN readiness check failed error="closed pool"1231--- PASS: TestService_readinessHandler (5.26s)1232=== CONT TestPush_CompleteCommitsEveryRoot1233=== NAME TestNARDeduplicationMetadataUploadBug1234 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/8/scratch/2059c74a22533349/build/TestNARDeduplicationMetadataUploadBug1515180997/001/store/4cx8dq4g3bdlw9a3fllj0dxrayk21dyk-file2.txt1235--- PASS: TestService_healthCheckHandler (5.53s)1236=== CONT TestReadProxyRangeRequest12372026/11/06 08:38:55 INFO Received push request method=POST path=/api/pushes12382026/11/06 08:38:55 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12392026/11/06 08:38:55 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12402026/11/06 08:38:55 INFO Signed narinfos id=2 count=112412026/11/06 08:38:55 INFO Uploading 1 narinfos12422026/11/06 08:38:55 WARN Failed to register uploaded object key=4cx8dq4g3bdlw9a3fllj0dxrayk21dyk.ls error="server returned 404: 404 page not found\n"12432026/11/06 08:38:55 INFO Received complete push request method=POST path=/api/pushes/2/complete12442026/11/06 08:38:55 WARN Failed to register uploaded object key=4cx8dq4g3bdlw9a3fllj0dxrayk21dyk.narinfo error="server returned 404: 404 page not found\n"12452026/11/06 08:38:55 INFO Completed push id=2 objects=3 duration=1.317875ms12462026/11/06 08:38:55 INFO Upload complete. (365ms)1247=== NAME TestNARDeduplicationMetadataUploadBug1248 metadata_upload_test.go:76: Retrieved narinfo from S3:1249 StorePath: /private/var/tb/8/scratch/2059c74a22533349/build/TestNARDeduplicationMetadataUploadBug1515180997/001/store/4cx8dq4g3bdlw9a3fllj0dxrayk21dyk-file2.txt1250 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1251 Compression: zstd1252 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1253 NarSize: 1601254 References: 1255 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1256 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1257 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1258 {"version":1,"root":{"type":"regular","size":44}}1259--- PASS: TestNARDeduplicationMetadataUploadBug (6.65s)1260=== CONT TestReadRedirectKeepsNarinfoProxied12612026/11/06 08:38:55 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld8 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1262--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (5.51s)1263=== CONT TestPush_OverlappingRootsStoreOneRowPerKey12642026/11/06 08:38:55 INFO Received uploads request method=POST path=/api/pending_closures12652026/11/06 08:38:56 INFO Aborted multipart uploads count=0 kept=012662026/11/06 08:38:56 WARN Force mode enabled - objects will be deleted immediately without grace period12672026/11/06 08:38:56 INFO Received uploads request method=POST path=/api/pending_closures12682026/11/06 08:38:56 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."12692026/11/06 08:38:56 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1270--- PASS: TestFailedS3DeleteKeepsTombstone (5.85s)1271=== CONT TestReadRedirectUsesPublicS3URL1272--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (6.01s)1273=== CONT TestReadRedirectNar12742026/11/06 08:38:56 INFO Aborted multipart uploads count=0 kept=012752026/11/06 08:38:56 WARN Force mode enabled - objects will be deleted immediately without grace period12762026/11/06 08:38:56 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=012772026/11/06 08:38:56 INFO Vacuumed table table=pending_closures12782026/11/06 08:38:56 INFO Vacuumed table table=pending_objects12792026/11/06 08:38:56 INFO Vacuumed table table=multipart_uploads12802026/11/06 08:38:56 INFO Vacuumed table table=closures12812026/11/06 08:38:56 INFO Vacuumed table table=objects12822026/11/06 08:38:56 INFO Aborted multipart uploads count=0 kept=012832026/11/06 08:38:56 WARN Force mode enabled - objects will be deleted immediately without grace period12842026/11/06 08:38:56 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=012852026/11/06 08:38:56 INFO Vacuumed table table=pending_closures12862026/11/06 08:38:56 INFO Vacuumed table table=pending_objects12872026/11/06 08:38:56 INFO Vacuumed table table=multipart_uploads12882026/11/06 08:38:56 INFO Vacuumed table table=closures12892026/11/06 08:38:56 INFO Aborted multipart uploads count=0 kept=012902026/11/06 08:38:56 INFO Vacuumed table table=objects1291--- PASS: TestSweepSkipsRowsLockedByPush (5.76s)1292=== CONT TestReadProxyHead12932026/11/06 08:38:56 WARN Force mode enabled - objects will be deleted immediately without grace period12942026/11/06 08:38:56 INFO Received uploads request method=POST path=/api/pending_closures1295--- PASS: TestTombstonedObjectOfferedWithoutWaiting (5.17s)1296=== CONT TestReadProxyRootRedirectsToIndexHTML12972026/11/06 08:38: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=012982026/11/06 08:38:57 INFO Vacuumed table table=pending_closures12992026/11/06 08:38:57 INFO Vacuumed table table=pending_objects13002026/11/06 08:38:57 INFO Vacuumed table table=multipart_uploads13012026/11/06 08:38:57 INFO Vacuumed table table=closures13022026/11/06 08:38:57 INFO Vacuumed table table=objects1303--- PASS: TestGCSweepDeliversEachKeyOnce (5.86s)1304=== CONT TestReadProxyConditionalGet13052026/11/06 08:38:57 INFO Aborted multipart uploads count=0 kept=013062026/11/06 08:38:57 WARN Force mode enabled - objects will be deleted immediately without grace period13072026/11/06 08:38:57 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=013082026/11/06 08:38:57 INFO Vacuumed table table=pending_closures13092026/11/06 08:38:57 INFO Vacuumed table table=pending_objects13102026/11/06 08:38:57 INFO Vacuumed table table=multipart_uploads13112026/11/06 08:38:57 INFO Vacuumed table table=closures13122026/11/06 08:38:57 INFO Received uploads request method=POST path=/api/pending_closures13132026/11/06 08:38:57 INFO Vacuumed table table=objects1314--- PASS: TestCommitRacingPendingCleanupKeepsObjects (5.35s)1315=== CONT TestReadProxyOutlastsServerWriteTimeout13162026/11/06 08:38:57 INFO Aborted multipart uploads count=0 kept=013172026/11/06 08:38:57 WARN Force mode enabled - objects will be deleted immediately without grace period13182026/11/06 08:38:57 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=013192026/11/06 08:38:57 INFO Vacuumed table table=pending_closures13202026/11/06 08:38:57 INFO Vacuumed table table=pending_objects13212026/11/06 08:38:57 INFO Vacuumed table table=multipart_uploads13222026/11/06 08:38:57 INFO Vacuumed table table=closures13232026/11/06 08:38:57 INFO Vacuumed table table=objects13242026/11/06 08:38:57 INFO Received uploads request method=POST path=/api/pending_closures1325--- PASS: TestGCSweepSkipsPendingObjects (5.16s)1326=== CONT TestReadProxy40413272026/11/06 08:38:57 INFO Aborted multipart uploads count=1 kept=013282026/11/06 08:38:57 INFO Received cleanup request method=DELETE path=/api/pending_closures13292026/11/06 08:38:57 INFO Aborted multipart uploads count=1 kept=01330--- PASS: TestPendingCleanupUsesOneCutoff (11.36s)1331=== CONT TestReadProxyInvalidPath13322026/11/06 08:38:57 INFO Received uploads request method=POST path=/api/pending_closures1333--- PASS: TestDeduplicatedObjectsRecordedAsPending (4.99s)1334=== CONT TestClientMultipleUploads13352026/11/06 08:38:57 INFO Aborted multipart uploads count=0 kept=013362026/11/06 08:38:57 WARN Force mode enabled - objects will be deleted immediately without grace period13372026/11/06 08:38:57 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=01338--- PASS: TestPushWaitsForSweepHoldingRow (5.58s)1339=== CONT TestLeadEndsOnShutdown13402026/11/06 08:38:58 INFO Vacuumed table table=pending_closures13412026/11/06 08:38:58 INFO Vacuumed table table=pending_objects13422026/11/06 08:38:58 INFO Vacuumed table table=multipart_uploads13432026/11/06 08:38:58 INFO Vacuumed table table=closures13442026/11/06 08:38:58 INFO Vacuumed table table=objects1345--- PASS: TestSweepRechecksPendingAfterLocking (5.16s)1346=== CONT TestLeadIncumbentAnnouncesAtOnce1347--- PASS: TestGetExistingObjectsLocksRows (4.66s)1348=== CONT TestLeadElectsOneAndHandsOver1349--- PASS: TestRegisterCompletedObjectNeedsPendingRow (4.72s)1350=== CONT TestConnectWaitsForAPeerMigration13512026/11/06 08:38:58 INFO Received uploads request method=POST path=/api/pending_closures13522026/11/06 08:38:58 INFO Received push request method=POST path=/api/pushes13532026/11/06 08:38:58 INFO Aborted multipart uploads count=0 kept=013542026/11/06 08:38:58 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=013552026/11/06 08:38:58 INFO Vacuumed table table=pending_closures13562026/11/06 08:38:58 INFO Vacuumed table table=pending_objects13572026/11/06 08:38:58 INFO Vacuumed table table=multipart_uploads13582026/11/06 08:38:58 INFO Vacuumed table table=closures1359--- PASS: TestReadProxyDisabled (5.30s)1360=== CONT TestResolveDBConnectionString1361=== RUN TestResolveDBConnectionString/flag_wins1362=== PAUSE TestResolveDBConnectionString/flag_wins1363=== RUN TestResolveDBConnectionString/file_when_flag_empty1364=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1365=== RUN TestResolveDBConnectionString/missing_file_is_an_error1366=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1367=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1368=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1369=== RUN TestResolveDBConnectionString/nothing_configured1370=== PAUSE TestResolveDBConnectionString/nothing_configured1371=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock13722026/11/06 08:38:59 INFO Vacuumed table table=objects13732026/11/06 08:38:59 INFO Aborted multipart uploads count=0 kept=013742026/11/06 08:38:59 WARN Force mode enabled - objects will be deleted immediately without grace period13752026/11/06 08:38:59 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013762026/11/06 08:38:59 INFO Vacuumed table table=pending_closures13772026/11/06 08:38:59 INFO Vacuumed table table=pending_objects13782026/11/06 08:38:59 INFO Vacuumed table table=multipart_uploads13792026/11/06 08:38:59 INFO Vacuumed table table=closures13802026/11/06 08:38:59 INFO Vacuumed table table=objects1381--- PASS: TestPushDedupSurvivesConcurrentGC (5.77s)1382=== CONT TestDeleteClosuresRacingPins13832026-11-06 08:38:59.178 UTC [19864] ERROR: Push does not exist: id=113842026-11-06 08:38:59.178 UTC [19864] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE13852026-11-06 08:38:59.178 UTC [19864] STATEMENT: SELECT commit_push($1)1386--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (5.21s)1387=== CONT TestClientFallsBackToClosures13882026/11/06 08:38:59 INFO Aborted multipart uploads count=0 kept=013892026/11/06 08:38:59 WARN Force mode enabled - objects will be deleted immediately without grace period13902026/11/06 08:38:59 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=013912026/11/06 08:38:59 INFO Vacuumed table table=pending_closures13922026/11/06 08:38:59 INFO Vacuumed table table=pending_objects13932026/11/06 08:38:59 INFO Vacuumed table table=multipart_uploads13942026/11/06 08:38:59 INFO Vacuumed table table=closures13952026/11/06 08:38:59 INFO Vacuumed table table=objects1396--- PASS: TestGCMetrics (5.24s)1397=== CONT TestClientPushesUseOnePush13982026/11/06 08:38:59 INFO Received push request method=POST path=/api/pushes13992026/11/06 08:38:59 INFO Received complete push request method=POST path=/api/pushes/1/complete14002026/11/06 08:38:59 INFO Completed push id=1 objects=4 duration=19.643ms1401--- PASS: TestPush_RepeatedRootCommitsOnce (5.05s)1402=== CONT TestPinProtectsFromGC14032026/11/06 08:38:59 INFO Received push request method=POST path=/api/pushes14042026/11/06 08:39:00 INFO Received complete push request method=POST path=/api/pushes/1/complete14052026/11/06 08:39:00 INFO Completed push id=1 objects=6 duration=61.609542ms1406--- PASS: TestGCBugBareHashReferences (5.11s)1407=== CONT TestClientSharedPathCommittedMidPush1408--- PASS: TestPush_CompleteCommitsEveryRoot (4.95s)1409=== CONT TestClientWithDependencies1410--- PASS: TestReadProxyRangeRequest (4.75s)1411=== CONT TestService_ReadScope_PublicByDefault1412--- PASS: TestReadRedirectKeepsNarinfoProxied (4.77s)1413=== CONT TestClientIntegration14142026/11/06 08:39:00 INFO Received push request method=POST path=/api/pushes1415--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (5.00s)1416=== CONT TestClientErrorHandling1417=== RUN TestClientErrorHandling/InvalidStorePath1418=== PAUSE TestClientErrorHandling/InvalidStorePath1419=== RUN TestClientErrorHandling/InvalidAuthToken1420=== PAUSE TestClientErrorHandling/InvalidAuthToken1421=== RUN TestClientErrorHandling/ServerNotAvailable1422=== PAUSE TestClientErrorHandling/ServerNotAvailable1423=== CONT TestClientCADerivations1424--- PASS: TestReadRedirectUsesPublicS3URL (4.78s)1425=== CONT TestCacheStatsHandler1426--- PASS: TestReadRedirectNar (4.75s)1427=== CONT TestCacheConfigHandler1428=== RUN TestCacheConfigHandler/full_config,_no_issuer1429=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1430=== RUN TestCacheConfigHandler/no_cache_url_configured1431=== PAUSE TestCacheConfigHandler/no_cache_url_configured1432=== RUN TestCacheConfigHandler/no_signing_keys1433=== PAUSE TestCacheConfigHandler/no_signing_keys1434=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1435=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1436=== CONT TestService_ReadAuthMiddleware1437--- PASS: TestReadProxyHead (4.75s)1438=== CONT TestService_RequireScope_OIDC14392026/11/06 08:39:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59949/oidc1440--- PASS: TestReadProxyRootRedirectsToIndexHTML (4.82s)1441=== CONT TestService_AuthMiddleware_OIDC14422026/11/06 08:39:01 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:59955/oidc1443=== NAME TestOrphanedObjectsGCStressTest1444 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1445 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion1446--- PASS: TestReadProxyConditionalGet (4.80s)1447=== CONT TestReadProxyNarStreaming1448--- PASS: TestReadProxyInvalidPath (4.89s)1449=== CONT TestService_AuthMiddleware_MTLSProxyHeader1450--- PASS: TestReadProxy404 (5.11s)1451=== CONT TestService_AuthMiddleware_MTLSBoundSubjects1452=== NAME TestClientMultipleUploads1453 client_integration_test.go:405: Created store path 0: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientMultipleUploads561240689/001/store/7qmv46r94pxbqrpbi78vvz2jb89i3rnd-test-file-0.txt14542026/11/06 08:39:02 INFO lead: acquired remote=192.0.2.1:12341455 client_integration_test.go:405: Created store path 1: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientMultipleUploads561240689/001/store/54qs2j2w6mbxkldj8va3sfxk62v40a5z-test-file-1.txt1456 client_integration_test.go:405: Created store path 2: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientMultipleUploads561240689/001/store/9y8v2ms3lmv8yd5hqidp6p95fjzyf8ac-test-file-2.txt14572026/11/06 08:39:03 INFO lead: acquired remote=192.0.2.1:123414582026/11/06 08:39:03 INFO Received push request method=POST path=/api/pushes14592026/11/06 08:39:03 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)14602026/11/06 08:39:03 INFO Uploading 7qmv46r94pxbqrpbi78vvz2jb89i3rnd-test-file-0.txt (160B)14612026/11/06 08:39:03 INFO Uploading 54qs2j2w6mbxkldj8va3sfxk62v40a5z-test-file-1.txt (160B)14622026/11/06 08:39:03 INFO Uploading 9y8v2ms3lmv8yd5hqidp6p95fjzyf8ac-test-file-2.txt (160B)14632026/11/06 08:39:03 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"14642026/11/06 08:39:03 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"14652026/11/06 08:39:03 WARN Failed to register uploaded object key=7qmv46r94pxbqrpbi78vvz2jb89i3rnd.ls error="server returned 404: 404 page not found\n"14662026/11/06 08:39:03 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"14672026/11/06 08:39:03 WARN Failed to register uploaded object key=9y8v2ms3lmv8yd5hqidp6p95fjzyf8ac.ls error="server returned 404: 404 page not found\n"14682026/11/06 08:39:03 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign14692026/11/06 08:39:03 WARN Failed to register uploaded object key=54qs2j2w6mbxkldj8va3sfxk62v40a5z.ls error="server returned 404: 404 page not found\n"14702026/11/06 08:39:03 INFO Signed narinfos id=1 count=314712026/11/06 08:39:03 INFO Uploading 3 narinfos14722026/11/06 08:39:03 WARN Failed to register uploaded object key=9y8v2ms3lmv8yd5hqidp6p95fjzyf8ac.narinfo error="server returned 404: 404 page not found\n"14732026/11/06 08:39:03 WARN Failed to register uploaded object key=7qmv46r94pxbqrpbi78vvz2jb89i3rnd.narinfo error="server returned 404: 404 page not found\n"14742026/11/06 08:39:03 INFO Received complete push request method=POST path=/api/pushes/1/complete14752026/11/06 08:39:03 WARN Failed to register uploaded object key=54qs2j2w6mbxkldj8va3sfxk62v40a5z.narinfo error="server returned 404: 404 page not found\n"14762026/11/06 08:39:03 INFO lead: acquired remote=192.0.2.1:123414772026/11/06 08:39:03 INFO lead: released remote=192.0.2.1:12341478--- PASS: TestLeadIncumbentAnnouncesAtOnce (5.27s)1479=== CONT TestService_AuthMiddleware14802026/11/06 08:39:03 INFO Completed push id=1 objects=9 duration=16.294ms14812026/11/06 08:39:03 INFO Upload complete. (207ms)1482=== NAME TestClientMultipleUploads1483 client_integration_test.go:416: Uploaded 3 paths in 246.371958ms1484--- PASS: TestClientMultipleUploads (5.67s)1485=== CONT TestReadProxyContentNegotiation14862026/11/06 08:39:04 INFO lead: released remote=192.0.2.1:123414872026/11/06 08:39:04 INFO Received uploads request method=POST path=/api/pending_closures14882026/11/06 08:39:04 INFO Received uploads request method=POST path=/api/pending_closures14892026/11/06 08:39:04 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)14902026/11/06 08:39:04 INFO Uploading zsdkc5ib6alqai39kxklnprm0swm1hha-a (256B)14912026/11/06 08:39:04 INFO Uploading g54s6f6n6igqmfwj8bsczwf5y3ysh4zr-shared-dep (136B)14922026/11/06 08:39:04 INFO lead: acquired remote=192.0.2.1:123414932026/11/06 08:39:04 INFO lead: released remote=192.0.2.1:12341494--- PASS: TestLeadEndsOnShutdown (6.19s)1495=== CONT TestPush_RootsAreLockedInByteOrder14962026/11/06 08:39:04 WARN Failed to register uploaded object key=gx522lgff07ki2fixk2pg0d15yb756r3.ls error="server returned 404: 404 page not found\n"14972026/11/06 08:39:04 WARN Failed to register uploaded object key=zsdkc5ib6alqai39kxklnprm0swm1hha.ls error="server returned 404: 404 page not found\n"14982026/11/06 08:39:04 WARN Failed to register uploaded object key=g54s6f6n6igqmfwj8bsczwf5y3ysh4zr.ls error="server returned 404: 404 page not found\n"14992026/11/06 08:39:04 WARN Failed to register uploaded object key=nar/1wlk7lhxqrzbmmqf5613hf86qi1yhj41by4r0zjnb9m94yi9pxdf.nar.zst error="server returned 404: 404 page not found\n"15002026/11/06 08:39:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign15012026/11/06 08:39:04 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15022026/11/06 08:39:04 INFO Signed narinfos id=1 count=215032026/11/06 08:39:04 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign15042026/11/06 08:39:04 INFO Signed narinfos id=2 count=215052026/11/06 08:39:04 INFO Uploading 4 narinfos15062026/11/06 08:39:04 WARN Failed to register uploaded object key=zsdkc5ib6alqai39kxklnprm0swm1hha.narinfo error="server returned 404: 404 page not found\n"15072026/11/06 08:39:04 WARN Failed to register uploaded object key=gx522lgff07ki2fixk2pg0d15yb756r3.narinfo error="server returned 404: 404 page not found\n"15082026/11/06 08:39:04 WARN Failed to register uploaded object key=g54s6f6n6igqmfwj8bsczwf5y3ysh4zr.narinfo error="server returned 404: 404 page not found\n"15092026/11/06 08:39:04 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete15102026/11/06 08:39:04 WARN Failed to register uploaded object key=g54s6f6n6igqmfwj8bsczwf5y3ysh4zr.narinfo error="server returned 404: 404 page not found\n"15112026/11/06 08:39:04 INFO Completed upload id=1 objects=6 duration=32.522959ms15122026/11/06 08:39:04 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete15132026/11/06 08:39:04 INFO Completed upload id=2 objects=6 duration=851.792µs15142026/11/06 08:39:04 INFO Upload complete. (312ms)1515=== NAME TestClientFallsBackToClosures1516 client_pushes_test.go:112: Retrieved narinfo from S3:1517 StorePath: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientFallsBackToClosures2562252165/001/store/g54s6f6n6igqmfwj8bsczwf5y3ysh4zr-shared-dep1518 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1519 Compression: zstd1520 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821521 NarSize: 1361522 References: 1523 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1524 client_pushes_test.go:112: Retrieved narinfo from S3:1525 StorePath: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientFallsBackToClosures2562252165/001/store/zsdkc5ib6alqai39kxklnprm0swm1hha-a1526 URL: nar/1wlk7lhxqrzbmmqf5613hf86qi1yhj41by4r0zjnb9m94yi9pxdf.nar.zst1527 Compression: zstd1528 NarHash: sha256:1wlk7lhxqrzbmmqf5613hf86qi1yhj41by4r0zjnb9m94yi9pxdf1529 NarSize: 2561530 References: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientFallsBackToClosures2562252165/001/store/g54s6f6n6igqmfwj8bsczwf5y3ysh4zr-shared-dep1531 CA: text:sha256:04yhh4ng8rzbz9dc96v5gnsr1126jn54cq7q448dybwvc968dffg1532 client_pushes_test.go:112: Retrieved narinfo from S3:1533 StorePath: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientFallsBackToClosures2562252165/001/store/gx522lgff07ki2fixk2pg0d15yb756r3-b1534 URL: nar/1wlk7lhxqrzbmmqf5613hf86qi1yhj41by4r0zjnb9m94yi9pxdf.nar.zst1535 Compression: zstd1536 NarHash: sha256:1wlk7lhxqrzbmmqf5613hf86qi1yhj41by4r0zjnb9m94yi9pxdf1537 NarSize: 2561538 References: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientFallsBackToClosures2562252165/001/store/g54s6f6n6igqmfwj8bsczwf5y3ysh4zr-shared-dep1539 CA: text:sha256:04yhh4ng8rzbz9dc96v5gnsr1126jn54cq7q448dybwvc968dffg1540--- PASS: TestClientFallsBackToClosures (5.26s)1541=== CONT TestPendingClosureWriteTimeout/empty1542=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1543=== NAME TestPinProtectsFromGC1544 client_integration_test.go:778: Pinned store path: /private/var/tb/8/scratch/2059c74a22533349/build/TestPinProtectsFromGC1793883503/001/store/35vqx1v9l44hwd63w4hsj77kar8d5a0p-pinned-file.txt1545 client_integration_test.go:779: Unpinned store path: /private/var/tb/8/scratch/2059c74a22533349/build/TestPinProtectsFromGC1793883503/001/store/30gp3fb7wk2q5wygl5z26s76b46f43g6-unpinned-file.txt15462026/11/06 08:39:04 INFO Received push request method=POST path=/api/pushes15472026/11/06 08:39:04 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15482026/11/06 08:39:04 INFO Uploading gg3igv1iihazzpmay8diqpfqr3f3ybrl-shared-dep (136B)15492026/11/06 08:39:04 INFO Uploading jidz411zmrhvzxh0xnp6v77z67jh5wsm-b (256B)15502026/11/06 08:39:04 WARN Failed to register uploaded object key=4s9yn677b14b2vskvpd2plnnx46nqk26.ls error="server returned 404: 404 page not found\n"1551--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (5.67s)1552=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info15532026/11/06 08:39:04 INFO Received uploads request method=POST path=/15542026/11/06 08:39:04 WARN Failed to register uploaded object key=jidz411zmrhvzxh0xnp6v77z67jh5wsm.ls error="server returned 404: 404 page not found\n"1555=== CONT TestProxyWriteTimeout/narinfo1556=== CONT TestPendingClosureWriteTimeout/400_objects15572026/11/06 08:39:04 WARN Failed to register uploaded object key=nar/0ks07m7pmi1pc7xsq0cicczyff6340df3mzpvhcj4qa803cj5ah1.nar.zst error="server returned 404: 404 page not found\n"1558=== CONT TestPendingClosureWriteTimeout/670k_objects1559=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key15602026/11/06 08:39:04 INFO Received request for more parts method=POST path=/1561=== CONT TestProxyWriteTimeout/10_GiB_nar1562=== CONT TestProxyWriteTimeout/unknown_size1563=== CONT TestProxyWriteTimeout/1_GiB_nar1564--- PASS: TestProxyWriteTimeout (0.01s)1565 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1566 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1567 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1568 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1569=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key15702026/11/06 08:39:04 INFO Received complete multipart upload request method=POST path=/1571=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal15722026/11/06 08:39:04 INFO Received uploads request method=POST path=/1573--- PASS: TestUploadHandlersRejectInvalidKeys (0.91s)1574 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1575 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1576 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1577 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1578=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale15792026/11/06 08:39:04 WARN Failed to register uploaded object key=gg3igv1iihazzpmay8diqpfqr3f3ybrl.ls error="server returned 404: 404 page not found\n"15802026/11/06 08:39:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15812026/11/06 08:39:04 INFO Received push request method=POST path=/api/pushes15822026/11/06 08:39:04 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15832026/11/06 08:39:04 INFO Signed narinfos id=1 count=315842026/11/06 08:39:04 INFO Uploading 3 narinfos15852026/11/06 08:39:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15862026/11/06 08:39:04 INFO Uploading 35vqx1v9l44hwd63w4hsj77kar8d5a0p-pinned-file.txt (128B)15872026/11/06 08:39:04 WARN Failed to register uploaded object key=4s9yn677b14b2vskvpd2plnnx46nqk26.narinfo error="server returned 404: 404 page not found\n"15882026/11/06 08:39:04 WARN Failed to register uploaded object key=gg3igv1iihazzpmay8diqpfqr3f3ybrl.narinfo error="server returned 404: 404 page not found\n"15892026/11/06 08:39:04 INFO Received complete push request method=POST path=/api/pushes/1/complete15902026/11/06 08:39:04 WARN Failed to register uploaded object key=jidz411zmrhvzxh0xnp6v77z67jh5wsm.narinfo error="server returned 404: 404 page not found\n"15912026/11/06 08:39:04 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15922026/11/06 08:39:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15932026/11/06 08:39:04 WARN Failed to register uploaded object key=35vqx1v9l44hwd63w4hsj77kar8d5a0p.ls error="server returned 404: 404 page not found\n"15942026/11/06 08:39:04 INFO Completed push id=1 objects=8 duration=23.166708ms15952026/11/06 08:39:04 INFO Upload complete. (236ms)15962026/11/06 08:39:04 INFO Signed narinfos id=1 count=115972026/11/06 08:39:04 INFO Uploading 1 narinfos1598=== NAME TestClientPushesUseOnePush1599 client_pushes_test.go:97: Retrieved narinfo from S3:1600 StorePath: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientPushesUseOnePush3973686196/001/store/gg3igv1iihazzpmay8diqpfqr3f3ybrl-shared-dep1601 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1602 Compression: zstd1603 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821604 NarSize: 1361605 References: 1606 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1607 client_pushes_test.go:97: Retrieved narinfo from S3:1608 StorePath: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientPushesUseOnePush3973686196/001/store/4s9yn677b14b2vskvpd2plnnx46nqk26-a1609 URL: nar/0ks07m7pmi1pc7xsq0cicczyff6340df3mzpvhcj4qa803cj5ah1.nar.zst1610 Compression: zstd1611 NarHash: sha256:0ks07m7pmi1pc7xsq0cicczyff6340df3mzpvhcj4qa803cj5ah11612 NarSize: 2561613 References: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientPushesUseOnePush3973686196/001/store/gg3igv1iihazzpmay8diqpfqr3f3ybrl-shared-dep1614 CA: text:sha256:0r5vpw47dihfjljdp3q65y47fc32h7xf669b2d5y04d3425d9a5l1615 client_pushes_test.go:97: Retrieved narinfo from S3:1616 StorePath: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientPushesUseOnePush3973686196/001/store/jidz411zmrhvzxh0xnp6v77z67jh5wsm-b1617 URL: nar/0ks07m7pmi1pc7xsq0cicczyff6340df3mzpvhcj4qa803cj5ah1.nar.zst1618 Compression: zstd1619 NarHash: sha256:0ks07m7pmi1pc7xsq0cicczyff6340df3mzpvhcj4qa803cj5ah11620 NarSize: 2561621 References: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientPushesUseOnePush3973686196/001/store/gg3igv1iihazzpmay8diqpfqr3f3ybrl-shared-dep1622 CA: text:sha256:0r5vpw47dihfjljdp3q65y47fc32h7xf669b2d5y04d3425d9a5l16232026/11/06 08:39:04 INFO Received complete push request method=POST path=/api/pushes/1/complete16242026/11/06 08:39:04 WARN Failed to register uploaded object key=35vqx1v9l44hwd63w4hsj77kar8d5a0p.narinfo error="server returned 404: 404 page not found\n"1625--- PASS: TestClientPushesUseOnePush (5.43s)1626=== CONT TestIsValidCachePath/narinfo1627=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed16282026/11/06 08:39:04 INFO Completed push id=1 objects=3 duration=20.144375ms16292026/11/06 08:39:04 INFO Upload complete. (216ms)16302026/11/06 08:39:04 INFO Received push request method=POST path=/api/pushes16312026/11/06 08:39:04 INFO Received push request method=POST path=/api/pushes16322026/11/06 08:39:04 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16332026/11/06 08:39:04 INFO Uploading 30gp3fb7wk2q5wygl5z26s76b46f43g6-unpinned-file.txt (128B)16342026/11/06 08:39:04 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16352026/11/06 08:39:04 INFO Uploading rskchq7rydvjpsi6x2n81sphpawk882i-top (264B)16362026/11/06 08:39:04 INFO Uploading gxs8c9xdpcjbfyp2yp8g0qmz3vn0mj2l-shared-dep (136B)16372026/11/06 08:39:04 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"16382026/11/06 08:39:04 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign16392026/11/06 08:39:04 WARN Failed to register uploaded object key=30gp3fb7wk2q5wygl5z26s76b46f43g6.ls error="server returned 404: 404 page not found\n"16402026/11/06 08:39:04 INFO Signed narinfos id=2 count=116412026/11/06 08:39:04 INFO Uploading 1 narinfos16422026/11/06 08:39:04 WARN Failed to register uploaded object key=rskchq7rydvjpsi6x2n81sphpawk882i.ls error="server returned 404: 404 page not found\n"1643--- PASS: TestService_ReadScope_PublicByDefault (4.76s)16442026/11/06 08:39:04 WARN Failed to register uploaded object key=gxs8c9xdpcjbfyp2yp8g0qmz3vn0mj2l.ls error="server returned 404: 404 page not found\n"1645=== CONT TestIsValidCachePath/index.html1646=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh16472026/11/06 08:39:04 WARN Failed to register uploaded object key=nar/0vs3y7wf7y9cmsln802wf4x8ld4jksz0iyhh7085wcwvdyjjxiz2.nar.zst error="server returned 404: 404 page not found\n"16482026/11/06 08:39:04 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16492026/11/06 08:39:04 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16502026/11/06 08:39:04 INFO Signed narinfos id=1 count=216512026/11/06 08:39:04 INFO Uploading 2 narinfos16522026/11/06 08:39:05 INFO Received complete push request method=POST path=/api/pushes/2/complete16532026/11/06 08:39:05 WARN Failed to register uploaded object key=30gp3fb7wk2q5wygl5z26s76b46f43g6.narinfo error="server returned 404: 404 page not found\n"16542026/11/06 08:39:05 INFO Completed push id=2 objects=3 duration=556.25µs16552026/11/06 08:39:05 INFO Upload complete. (130ms)16562026/11/06 08:39:05 WARN Failed to register uploaded object key=gxs8c9xdpcjbfyp2yp8g0qmz3vn0mj2l.narinfo error="server returned 404: 404 page not found\n"16572026/11/06 08:39:05 INFO Received complete push request method=POST path=/api/pushes/1/complete16582026/11/06 08:39:05 WARN Failed to register uploaded object key=rskchq7rydvjpsi6x2n81sphpawk882i.narinfo error="server returned 404: 404 page not found\n"16592026/11/06 08:39:05 INFO Completed push id=1 objects=6 duration=10.4195ms16602026/11/06 08:39:05 INFO Upload complete. (176ms)1661=== NAME TestClientSharedPathCommittedMidPush1662 client_integration_test.go:727: Retrieved narinfo from S3:1663 StorePath: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientSharedPathCommittedMidPush1775375378/001/store/gxs8c9xdpcjbfyp2yp8g0qmz3vn0mj2l-shared-dep1664 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1665 Compression: zstd1666 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821667 NarSize: 1361668 References: 1669 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1670 client_integration_test.go:727: Retrieved narinfo from S3:1671 StorePath: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientSharedPathCommittedMidPush1775375378/001/store/rskchq7rydvjpsi6x2n81sphpawk882i-top1672 URL: nar/0vs3y7wf7y9cmsln802wf4x8ld4jksz0iyhh7085wcwvdyjjxiz2.nar.zst1673 Compression: zstd1674 NarHash: sha256:0vs3y7wf7y9cmsln802wf4x8ld4jksz0iyhh7085wcwvdyjjxiz21675 NarSize: 2641676 References: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientSharedPathCommittedMidPush1775375378/001/store/gxs8c9xdpcjbfyp2yp8g0qmz3vn0mj2l-shared-dep1677 CA: text:sha256:1vjmrwidxdprfa3fxs0srgpb1zbarv2n3a4x4cpzww36jvggjdy216782026/11/06 08:39:05 INFO Starting cleanup of old closures method=DELETE path=/api/closures16792026/11/06 08:39:05 INFO Garbage collection started16802026/11/06 08:39:05 INFO Aborted multipart uploads count=0 kept=01681--- PASS: TestClientSharedPathCommittedMidPush (4.98s)1682=== CONT TestIsValidCachePath/nix-cache-info1683=== CONT TestIsValidCachePath/realisation1684=== CONT TestIsValidCachePath/log1685=== CONT TestIsValidCachePath/ls1686=== CONT TestIsValidCachePath/nar_uncompressed1687=== CONT TestIsValidCachePath/nar_bz21688=== CONT TestIsValidCachePath/nar_xz1689=== CONT TestIsValidCachePath/nar_zst1690=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1691=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed16922026/11/06 08:39:05 WARN Force mode enabled - objects will be deleted immediately without grace period1693=== NAME TestClientWithDependencies1694 client_integration_test.go:660: Built derivation: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientWithDependencies833234574/001/store/8r1p5ldsn11lqk03mdg5arj4zriamiba-test-script1695 client_integration_test.go:662: Found 1 dependencies (including self)16962026/11/06 08:39:05 INFO lead: released remote=192.0.2.1:12341697--- PASS: TestLeadElectsOneAndHandsOver (7.15s)1698=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed16992026/11/06 08:39:05 INFO Received push request method=POST path=/api/pushes1700--- PASS: TestConnectWaitsForAPeerMigration (6.99s)1701=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost17022026/11/06 08:39:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17032026/11/06 08:39:05 INFO Uploading 8r1p5ldsn11lqk03mdg5arj4zriamiba-test-script (136B)17042026/11/06 08:39:05 WARN Failed to register uploaded object key=8r1p5ldsn11lqk03mdg5arj4zriamiba.ls error="server returned 404: 404 page not found\n"17052026/11/06 08:39:05 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"17062026/11/06 08:39:05 WARN Failed to register uploaded object key=log/ng5a0z6mpl0zldhas4rcxj460nihgv0g-test-script.drv error="server returned 404: 404 page not found\n"17072026/11/06 08:39:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17082026/11/06 08:39:05 INFO Signed narinfos id=1 count=117092026/11/06 08:39:05 INFO Uploading 1 narinfos17102026/11/06 08:39:05 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=017112026/11/06 08:39:05 INFO Received complete push request method=POST path=/api/pushes/1/complete17122026/11/06 08:39:05 WARN Failed to register uploaded object key=8r1p5ldsn11lqk03mdg5arj4zriamiba.narinfo error="server returned 404: 404 page not found\n"17132026/11/06 08:39:05 INFO Vacuumed table table=pending_closures17142026/11/06 08:39:05 INFO Vacuumed table table=pending_objects17152026/11/06 08:39:05 INFO Completed push id=1 objects=4 duration=26.130167ms17162026/11/06 08:39:05 INFO Vacuumed table table=multipart_uploads17172026/11/06 08:39:05 INFO Upload complete. (254ms)1718=== NAME TestClientWithDependencies1719 client_integration_test.go:664: Skipping nix copy test - isolated store (/private/var/tb/8/scratch/2059c74a22533349/build/TestClientWithDependencies833234574/001/store) requires matching store prefix1720=== NAME TestClientIntegration1721 client_integration_test.go:291: Created store path: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientIntegration1808003846/002/store/5p41lgkksl5cx9rmycw06l7dm6lacpa3-test-file.txt17222026/11/06 08:39:05 INFO Vacuumed table table=closures17232026/11/06 08:39:05 INFO Vacuumed table table=objects1724--- PASS: TestCacheStatsHandler (4.53s)1725=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed1726--- PASS: TestClientWithDependencies (5.45s)1727=== CONT TestIsValidCachePath/random_path1728=== CONT TestIsValidCachePath/short_hash1729=== CONT TestIsValidCachePath/wrong_extension1730=== CONT TestIsValidCachePath/leading_slash1731=== CONT TestIsValidCachePath/empty1732=== CONT TestIsValidCachePath/invalid_char_e1733=== CONT TestIsValidCachePath/invalid_char_u1734=== CONT TestIsValidCachePath/traversal_in_middle1735=== CONT TestIsValidCachePath/traversal_parent1736--- PASS: TestIsValidCachePath (0.01s)1737 --- PASS: TestIsValidCachePath/narinfo (0.00s)1738 --- PASS: TestIsValidCachePath/index.html (0.00s)1739 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1740 --- PASS: TestIsValidCachePath/realisation (0.00s)1741 --- PASS: TestIsValidCachePath/log (0.00s)1742 --- PASS: TestIsValidCachePath/ls (0.00s)1743 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1744 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1745 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1746 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1747 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1748 --- PASS: TestIsValidCachePath/random_path (0.00s)1749 --- PASS: TestIsValidCachePath/short_hash (0.00s)1750 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1751 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1752 --- PASS: TestIsValidCachePath/empty (0.00s)1753 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1754 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1755 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1756 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1757=== CONT TestParseSingleRange/none1758=== CONT TestParseSingleRange/open-ended1759=== CONT TestParseSingleRange/start_far_past_EOF1760=== CONT TestParseSingleRange/start_past_EOF1761=== CONT TestParseSingleRange/single_byte1762=== CONT TestParseSingleRange/suffix_exceeds_size1763=== CONT TestParseSingleRange/suffix1764=== CONT TestParseSingleRange/end_clamped_to_size1765=== CONT TestParseSingleRange/malformed_both_empty1766=== CONT TestParseSingleRange/closed1767=== CONT TestParseSingleRange/malformed_end_before_start1768=== CONT TestParseSingleRange/multi-range_ignored1769=== CONT TestParseSingleRange/malformed_no_dash1770=== CONT TestParseSingleRange/unknown_unit1771=== CONT TestIsValidUploadKey/narinfo1772--- PASS: TestParseSingleRange (0.02s)1773 --- PASS: TestParseSingleRange/none (0.00s)1774 --- PASS: TestParseSingleRange/open-ended (0.00s)1775 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1776 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1777 --- PASS: TestParseSingleRange/single_byte (0.00s)1778 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1779 --- PASS: TestParseSingleRange/suffix (0.00s)1780 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1781 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1782 --- PASS: TestParseSingleRange/closed (0.00s)1783 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1784 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1785 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1786 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1787=== CONT TestIsValidUploadKey/unknown_type1788=== CONT TestIsValidUploadKey/empty_key1789=== CONT TestIsValidUploadKey/absolute1790=== CONT TestIsValidUploadKey/traversal_nar1791=== CONT TestIsValidUploadKey/traversal1792=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1793=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1794=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1795=== CONT TestIsValidUploadKey/index.html1796=== CONT TestIsValidUploadKey/nix-cache-info1797=== CONT TestIsValidUploadKey/realisation_plus_in_output1798=== CONT TestIsValidUploadKey/realisation1799=== CONT TestIsValidUploadKey/build_log_equals1800=== CONT TestIsValidUploadKey/build_log_question_mark1801=== CONT TestIsValidUploadKey/build_log_plus_in_name1802=== CONT TestIsValidUploadKey/build_log_home-manager_file1803=== CONT TestIsValidUploadKey/build_log1804=== CONT TestIsValidUploadKey/listing1805=== CONT TestIsValidUploadKey/nar_plain1806=== CONT TestIsValidUploadKey/nar_xz1807=== CONT TestIsValidUploadKey/nar_zst1808--- PASS: TestIsValidUploadKey (0.93s)1809 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1810 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1811 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1812 --- PASS: TestIsValidUploadKey/absolute (0.00s)1813 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1814 --- PASS: TestIsValidUploadKey/traversal (0.00s)1815 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1816 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1817 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1818 --- PASS: TestIsValidUploadKey/index.html (0.00s)1819 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1820 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1821 --- PASS: TestIsValidUploadKey/realisation (0.00s)1822 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1823 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1824 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1825 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1826 --- PASS: TestIsValidUploadKey/build_log (0.00s)1827 --- PASS: TestIsValidUploadKey/listing (0.00s)1828 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1829 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1830 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1831=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure18322026/11/06 08:39:05 INFO Received uploads request method=POST path=/18332026/11/06 08:39:05 INFO Received push request method=POST path=/api/pushes18342026/11/06 08:39:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)18352026/11/06 08:39:05 INFO Uploading 5p41lgkksl5cx9rmycw06l7dm6lacpa3-test-file.txt (152B)18362026/11/06 08:39:05 WARN Failed to register uploaded object key=5p41lgkksl5cx9rmycw06l7dm6lacpa3.ls error="server returned 404: 404 page not found\n"18372026/11/06 08:39:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign18382026/11/06 08:39:05 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"18392026/11/06 08:39:05 INFO Signed narinfos id=1 count=118402026/11/06 08:39:05 INFO Uploading 1 narinfos18412026/11/06 08:39:05 INFO Received complete push request method=POST path=/api/pushes/1/complete18422026/11/06 08:39:05 WARN Failed to register uploaded object key=5p41lgkksl5cx9rmycw06l7dm6lacpa3.narinfo error="server returned 404: 404 page not found\n"18432026/11/06 08:39:05 INFO Completed push id=1 objects=3 duration=29.018917ms18442026/11/06 08:39:05 INFO Upload complete. (258ms)18452026/11/06 08:39:05 INFO All 1 paths already cached1846=== NAME TestClientIntegration1847 client_integration_test.go:317: Retrieved narinfo from S3:1848 StorePath: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientIntegration1808003846/002/store/5p41lgkksl5cx9rmycw06l7dm6lacpa3-test-file.txt1849 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1850 Compression: zstd1851 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11852 NarSize: 1521853 References: 1854 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11855 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1856 client_integration_test.go:318: Decompressed .ls content (64 bytes):1857 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1858--- PASS: TestService_ReadAuthMiddleware (4.72s)1859=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts18602026/11/06 08:39:05 INFO Received request for more parts method=POST path=/1861=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart18622026/11/06 08:39:05 INFO Received complete multipart upload request method=POST path=/1863=== CONT TestServerTLSConfig/no_client_CA1864=== CONT TestServerTLSConfig/not_a_PEM_file1865=== CONT TestServerTLSConfig/missing_CA_file1866--- PASS: TestServerTLSConfig (0.01s)1867 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1868 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.01s)1869 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1870=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows1871=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check1872--- PASS: TestUploadHandlersRejectOversizedBody (1.04s)1873 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1874 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.02s)1875 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.48s)18762026/11/06 08:39:06 INFO Received push request method=POST path=/api/pushes1877=== RUN TestService_RequireScope_OIDC/builder_may_write1878=== PAUSE TestService_RequireScope_OIDC/builder_may_write1879=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1880=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1881=== RUN TestService_RequireScope_OIDC/ops_may_admin1882=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1883=== RUN TestService_RequireScope_OIDC/ops_may_not_write1884=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1885=== RUN TestService_RequireScope_OIDC/reader_may_not_write1886=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1887=== RUN TestService_RequireScope_OIDC/static_token_may_admin1888=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1889=== RUN TestService_RequireScope_OIDC/static_token_may_write1890=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1891=== RUN TestService_RequireScope_OIDC/reader_may_read1892=== PAUSE TestService_RequireScope_OIDC/reader_may_read1893=== RUN TestService_RequireScope_OIDC/writer_implies_read1894=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1895=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1896=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1897=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1898=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1899=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1900=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc19012026/11/06 08:39:06 INFO Object in database but missing from S3 key=5p41lgkksl5cx9rmycw06l7dm6lacpa3.ls19022026/11/06 08:39:06 WARN Found objects in DB but missing from S3, will re-upload count=11903=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read19042026/11/06 08:39:06 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1905=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1906=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1907=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1908=== CONT TestGCEndsOnShutdown/before_the_run19092026/11/06 08:39:06 INFO Received complete push request method=POST path=/api/pushes/2/complete19102026/11/06 08:39:06 WARN Failed to register uploaded object key=5p41lgkksl5cx9rmycw06l7dm6lacpa3.ls error="server returned 404: 404 page not found\n"19112026/11/06 08:39:06 INFO Completed push id=2 objects=3 duration=901.417µs19122026/11/06 08:39:06 INFO Upload complete. (131ms)1913=== NAME TestClientIntegration1914 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1915 client_integration_test.go:335: Decompressed .ls content (49 bytes):1916 {"version":1,"root":{"type":"regular","size":39}}1917=== NAME TestClientCADerivations1918 client_ca_test.go:136: Built CA derivation: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientCADerivations1607953152/001/store/7jfdm29zpwlzla2kdp2l26h4dzfvsar9-ca-test1919--- PASS: TestReadProxyOutlastsServerWriteTimeout (8.98s)1920=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1921=== NAME TestClientCADerivations1922 client_ca_test.go:139: Found 1 dependencies (including self)1923=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token1924=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token1925=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1926=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected1927=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected1928=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected1929=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1930=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured1931=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete19322026/11/06 08:39:06 INFO Received push request method=POST path=/api/pushes19332026/11/06 08:39:06 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)19342026/11/06 08:39:06 INFO Received complete push request method=POST path=/api/pushes/3/complete19352026/11/06 08:39:06 WARN Failed to register uploaded object key=5p41lgkksl5cx9rmycw06l7dm6lacpa3.ls error="server returned 404: 404 page not found\n"19362026/11/06 08:39:06 INFO Received push request method=POST path=/api/pushes19372026/11/06 08:39:06 INFO Completed push id=3 objects=3 duration=1.478792ms19382026/11/06 08:39:06 INFO Upload complete. (128ms)1939=== NAME TestClientIntegration1940 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)1941 client_integration_test.go:352: Decompressed .ls content (49 bytes):1942 {"version":1,"root":{"type":"regular","size":39}}1943 client_integration_test.go:363: Testing garbage collection...19442026/11/06 08:39:06 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19452026/11/06 08:39:06 INFO Uploading 7jfdm29zpwlzla2kdp2l26h4dzfvsar9-ca-test (144B)19462026/11/06 08:39:06 INFO Starting cleanup of old closures method=DELETE path=/api/closures19472026/11/06 08:39:06 INFO Garbage collection started19482026/11/06 08:39:06 INFO Aborted multipart uploads count=0 kept=019492026/11/06 08:39:06 WARN Force mode enabled - objects will be deleted immediately without grace period19502026/11/06 08:39:06 WARN Failed to register uploaded object key=7jfdm29zpwlzla2kdp2l26h4dzfvsar9.ls error="server returned 404: 404 page not found\n"19512026/11/06 08:39:06 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19522026/11/06 08:39:06 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19532026/11/06 08:39:06 INFO Signed narinfos id=1 count=119542026/11/06 08:39:06 WARN Failed to register uploaded object key=log/6acbcsdcfziabxxm89ih90yz7kx9vmmn-ca-test.drv error="server returned 404: 404 page not found\n"19552026/11/06 08:39:06 INFO Uploading 1 narinfos1956--- PASS: TestReadProxyNarStreaming (4.77s)1957=== CONT TestPush_RejectsBadRequests/root_not_in_objects19582026/11/06 08:39:06 INFO Received push request method=POST path=/api/pushes1959=== CONT TestPush_RejectsBadRequests/no_objects19602026/11/06 08:39:06 INFO Received push request method=POST path=/api/pushes1961=== CONT TestPush_RejectsBadRequests/bad_root19622026/11/06 08:39:06 INFO Received push request method=POST path=/api/pushes1963=== CONT TestPush_RejectsBadRequests/no_roots19642026/11/06 08:39:06 INFO Received push request method=POST path=/api/pushes1965=== CONT TestResolveDBConnectionString/flag_wins1966=== CONT TestResolveDBConnectionString/PGHOST_allows_empty1967--- PASS: TestPush_RejectsBadRequests (6.83s)1968 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1969 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1970 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1971 --- PASS: TestPush_RejectsBadRequests/no_roots (0.00s)1972=== CONT TestResolveDBConnectionString/nothing_configured1973=== CONT TestResolveDBConnectionString/missing_file_is_an_error1974=== CONT TestResolveDBConnectionString/file_when_flag_empty1975=== CONT TestClientErrorHandling/InvalidStorePath1976--- PASS: TestResolveDBConnectionString (0.02s)1977 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)1978 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)1979 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)1980 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)1981 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)19822026/11/06 08:39:06 INFO Received complete push request method=POST path=/api/pushes/1/complete19832026/11/06 08:39:06 WARN Failed to register uploaded object key=7jfdm29zpwlzla2kdp2l26h4dzfvsar9.narinfo error="server returned 404: 404 page not found\n"19842026/11/06 08:39:06 INFO Completed push id=1 objects=4 duration=49.793875ms19852026/11/06 08:39:06 INFO Upload complete. (392ms)1986=== NAME TestClientCADerivations1987 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientCADerivations1607953152/001/store/7jfdm29zpwlzla2kdp2l26h4dzfvsar9-ca-test1988 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1989 Compression: zstd1990 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1991 NarSize: 1441992 References: 1993 Deriver: /private/var/tb/8/scratch/2059c74a22533349/build/TestClientCADerivations1607953152/001/store/6acbcsdcfziabxxm89ih90yz7kx9vmmn-ca-test.drv1994 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1995 client_ca_test.go:185: Checking for realisation files in S3...1996 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations1997 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache1998--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (4.48s)1999=== CONT TestClientErrorHandling/ServerNotAvailable2000=== NAME TestClientCADerivations2001 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket82?endpoint=http://localhost:59172®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/8/scratch/2059c74a22533349/build/TestClientCADerivations1607953152/001/store'2002 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12003--- PASS: TestDeleteClosuresRacingPins (7.94s)2004=== CONT TestClientErrorHandling/InvalidAuthToken20052026/11/06 08:39:07 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=020062026/11/06 08:39:07 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=020072026/11/06 08:39:07 INFO Received create pin request method=POST path=/api/pins/myapp20082026/11/06 08:39:07 INFO Vacuumed table table=pending_closures20092026/11/06 08:39:07 INFO Vacuumed table table=pending_objects20102026/11/06 08:39:07 INFO Vacuumed table table=multipart_uploads2011--- PASS: TestClientCADerivations (6.33s)20122026/11/06 08:39:07 INFO Created/updated pin name=myapp store_path=/private/var/tb/8/scratch/2059c74a22533349/build/TestPinProtectsFromGC1793883503/001/store/35vqx1v9l44hwd63w4hsj77kar8d5a0p-pinned-file.txt narinfo_key=35vqx1v9l44hwd63w4hsj77kar8d5a0p.narinfo2013=== CONT TestCacheConfigHandler/full_config,_no_issuer2014=== CONT TestCacheConfigHandler/no_signing_keys20152026/11/06 08:39:07 INFO Starting cleanup of old closures method=DELETE path=/api/closures2016=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2017=== CONT TestCacheConfigHandler/no_cache_url_configured2018--- PASS: TestCacheConfigHandler (0.00s)2019 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2020 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2021 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2022 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2023=== CONT TestService_RequireScope_OIDC/builder_may_write20242026/11/06 08:39:07 INFO Garbage collection started2025=== CONT TestService_RequireScope_OIDC/reader_may_read2026=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2027=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20282026/11/06 08:39:07 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]2029=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc2030=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2031=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2032=== CONT TestService_RequireScope_OIDC/writer_implies_read2033=== CONT TestService_RequireScope_OIDC/reader_may_not_write2034=== CONT TestService_RequireScope_OIDC/static_token_may_write2035=== CONT TestService_RequireScope_OIDC/static_token_may_admin2036=== CONT TestService_RequireScope_OIDC/ops_may_admin2037=== CONT TestService_RequireScope_OIDC/ops_may_not_write2038=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2039=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token20402026/11/06 08:39:07 INFO Aborted multipart uploads count=0 kept=02041=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected20422026/11/06 08:39:07 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]2043=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2044=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2045--- PASS: TestService_RequireScope_OIDC (4.67s)2046 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2047 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2048 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2049 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2050 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2051 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2052 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2053 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2054 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2055 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2056 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2057 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2058 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2059 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20602026/11/06 08:39:07 INFO Vacuumed table table=closures20612026/11/06 08:39:07 WARN Authentication failed token_preview=eyJhbGciOi...87aLnhFLBQ token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]20622026/11/06 08:39:07 WARN Force mode enabled - objects will be deleted immediately without grace period2063--- PASS: TestService_AuthMiddleware_OIDC (4.73s)2064 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.00s)2065 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2066 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2067 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)20682026/11/06 08:39:07 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=020692026/11/06 08:39:07 INFO Vacuumed table table=pending_closures20702026/11/06 08:39:07 INFO Vacuumed table table=pending_objects20712026/11/06 08:39:07 INFO Vacuumed table table=multipart_uploads20722026/11/06 08:39:07 INFO Vacuumed table table=closures20732026/11/06 08:39:07 INFO Vacuumed table table=objects20742026/11/06 08:39:07 INFO Vacuumed table table=objects20752026/11/06 08:39:07 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20762026/11/06 08:39:07 WARN mTLS auth: bound subjects configured but subject DN unavailable20772026/11/06 08:39:07 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2078--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (4.63s)20792026/11/06 08:39:07 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20802026/11/06 08:39:07 WARN Request failed, retrying attempt=2 backoff=186.341013ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20812026/11/06 08:39:07 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"2082--- PASS: TestService_AuthMiddleware (4.12s)20832026/11/06 08:39:07 WARN Request failed, retrying attempt=3 backoff=411.581725ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2084--- PASS: TestReadProxyContentNegotiation (4.53s)20852026/11/06 08:39:08 INFO Received push request method=POST path=/api/pushes20862026/11/06 08:39:08 WARN Request failed, retrying attempt=4 backoff=852.339336ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20872026-11-06 08:39:08.203 UTC [20172] ERROR: could not obtain lock on row in relation "closures"20882026-11-06 08:39:08.203 UTC [20172] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT20892026-11-06 08:39:08.205 UTC [20172] ERROR: could not obtain lock on row in relation "closures"20902026-11-06 08:39:08.205 UTC [20172] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT20912026-11-06 08:39:08.205 UTC [20172] ERROR: could not obtain lock on row in relation "closures"20922026-11-06 08:39:08.205 UTC [20172] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT20932026-11-06 08:39:08.205 UTC [20172] ERROR: could not obtain lock on row in relation "closures"20942026-11-06 08:39:08.205 UTC [20172] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT20952026-11-06 08:39:08.206 UTC [20172] ERROR: could not obtain lock on row in relation "closures"20962026-11-06 08:39:08.206 UTC [20172] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT2097--- PASS: TestPush_RootsAreLockedInByteOrder (4.03s)20982026/11/06 08:39:08 INFO Received uploads request method=POST path=/api/pending_closures20992026/11/06 08:39:08 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02100=== NAME TestClientIntegration2101 client_integration_test.go:370: Objects in database after GC:2102 client_integration_test.go:370: Successfully deleted all objects with GC --force2103--- PASS: TestClientIntegration (8.24s)21042026/11/06 08:39:08 INFO Received uploads request method=POST path=/api/pending_closures21052026/11/06 08:39:08 WARN Request failed, retrying attempt=5 backoff=1.752822623s error="Post \"http://localhost:19999/api/objects/present\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2106=== NAME TestPinProtectsFromGC2107 client_integration_test.go:887: Pin successfully protected closure from garbage collection2108--- PASS: TestPendingClosureWriteTimeout (0.00s)2109 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2110 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2111 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2112 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (4.72s)2113--- PASS: TestPinProtectsFromGC (9.58s)21142026/11/06 08:39:09 INFO Received uploads request method=POST path=/api/pending_closures21152026/11/06 08:39:09 INFO Received uploads request method=POST path=/api/pending_closures2116--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2117 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (4.40s)2118 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (4.63s)21192026/11/06 08:39:09 INFO Received uploads request method=POST path=/api/pending_closures21202026/11/06 08:39:09 INFO Received uploads request method=POST path=/api/pending_closures21212026/11/06 08:39:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21222026/11/06 08:39:10 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=Yjk4MjNjN2YtNWM5MC00N2IzLWIxMDYtZTQxNDAzY2EzMzFiLmZmOWQ4Y2YyLWU0ZWUtNDZiOC05NzNlLTA5ZGEyNjFhODA0MXgxNzkzOTU0MzQ4ODY1NTQzMDAw parts=1021232026/11/06 08:39:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21242026/11/06 08:39:10 INFO Completed upload id=1 objects=3 duration=8.731042ms21252026/11/06 08:39:10 INFO Received uploads request method=POST path=/api/pending_closures21262026/11/06 08:39:10 INFO Aborted multipart uploads count=0 kept=021272026/11/06 08:39:10 WARN Force mode enabled - objects will be deleted immediately without grace period21282026/11/06 08:39:10 INFO Received uploads request method=POST path=/api/pending_closures21292026/11/06 08:39:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21302026/11/06 08:39:10 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst21312026/11/06 08:39:10 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo21322026/11/06 08:39:10 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=021332026/11/06 08:39:10 INFO Vacuumed table table=pending_closures21342026/11/06 08:39:10 INFO Vacuumed table table=pending_objects21352026/11/06 08:39:10 INFO Vacuumed table table=multipart_uploads21362026/11/06 08:39:10 INFO Vacuumed table table=closures21372026/11/06 08:39:10 INFO Vacuumed table table=objects21382026/11/06 08:39:10 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=Yjk4MjNjN2YtNWM5MC00N2IzLWIxMDYtZTQxNDAzY2EzMzFiLjI0MmE1ZmFmLWU2YTctNDcyMC05MjNhLTgzNDZjOGY1OWM2MngxNzkzOTU0MzQ5MzExMTQ0MDAw parts=1021392026/11/06 08:39:10 INFO Received uploads request method=POST path=/api/pending_closures21402026/11/06 08:39:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21412026/11/06 08:39:10 INFO Completed upload id=1 objects=3 duration=9.974958ms21422026/11/06 08:39:10 INFO Aborted multipart uploads count=0 kept=021432026/11/06 08:39:10 WARN Force mode enabled - objects will be deleted immediately without grace period21442026/11/06 08:39:10 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=021452026/11/06 08:39:10 INFO Vacuumed table table=pending_closures21462026/11/06 08:39:10 INFO Vacuumed table table=pending_objects21472026/11/06 08:39:10 INFO Vacuumed table table=multipart_uploads21482026/11/06 08:39:10 INFO Vacuumed table table=closures21492026/11/06 08:39:10 INFO Vacuumed table table=objects21502026/11/06 08:39:10 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21512026/11/06 08:39:10 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2152--- PASS: TestForceGCDuringPushOffersSweptObject (0.00s)2153 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (4.71s)2154 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (4.76s)21552026/11/06 08:39:10 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=Yjk4MjNjN2YtNWM5MC00N2IzLWIxMDYtZTQxNDAzY2EzMzFiLjJmYjA0OGJlLTY1MWItNGIyNi1iNWU1LTgwYjdhMzFlYTgwY3gxNzkzOTU0MzQ5NTIxODE4MDAw parts=1021562026/11/06 08:39:10 WARN Request failed, retrying attempt=2 backoff=208.337987ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21572026/11/06 08:39:10 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21582026/11/06 08:39:10 INFO Completed upload id=1 objects=3 duration=5.602041ms21592026/11/06 08:39:10 INFO Received uploads request method=POST path=/api/pending_closures21602026/11/06 08:39:10 INFO Received uploads request method=POST path=/api/pending_closures21612026/11/06 08:39:10 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst21622026/11/06 08:39:10 WARN Found objects in DB but missing from S3, will re-upload count=121632026/11/06 08:39:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21642026/11/06 08:39:11 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=Yjk4MjNjN2YtNWM5MC00N2IzLWIxMDYtZTQxNDAzY2EzMzFiLjk1MDhiYTc1LTVkZmEtNDIzNS05NzkxLTUyYWM0NmM2NDgxOXgxNzkzOTU0MzQ5NzM0NzUzMDAw parts=1021652026/11/06 08:39:11 WARN Request failed, retrying attempt=3 backoff=368.216622ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21662026/11/06 08:39:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21672026/11/06 08:39:11 INFO Aborted multipart uploads count=0 kept=021682026/11/06 08:39:11 INFO Completed upload id=1 objects=3 duration=5.588208ms21692026/11/06 08:39:11 INFO Received uploads request method=POST path=/api/pending_closures21702026/11/06 08:39:11 WARN Force mode enabled - objects will be deleted immediately without grace period21712026/11/06 08:39:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21722026/11/06 08:39:11 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=Yjk4MjNjN2YtNWM5MC00N2IzLWIxMDYtZTQxNDAzY2EzMzFiLjUyZjY3ZTZhLWMxMDUtNDBkZC1iMDM2LTE4NGQ5YThjOTA3ZHgxNzkzOTU0MzQ5OTc5OTAwMDAw parts=1021732026/11/06 08:39:11 INFO Aborted multipart uploads count=0 kept=021742026/11/06 08:39:11 WARN Force mode enabled - objects will be deleted immediately without grace period21752026/11/06 08:39:11 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:59172/bucket104/?delete=\": context canceled"2176--- PASS: TestGCEndsOnShutdown (0.00s)2177 --- PASS: TestGCEndsOnShutdown/before_the_run (4.66s)2178 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (4.81s)2179 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (4.92s)21802026/11/06 08:39:11 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21812026/11/06 08:39:11 INFO Completed upload id=1 objects=3 duration=7.904667ms21822026/11/06 08:39:11 INFO Received uploads request method=POST path=/api/pending_closures21832026/11/06 08:39:11 WARN Request failed, retrying attempt=4 backoff=767.462989ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21842026/11/06 08:39:11 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21852026/11/06 08:39:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21862026/11/06 08:39:11 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=Yjk4MjNjN2YtNWM5MC00N2IzLWIxMDYtZTQxNDAzY2EzMzFiLjhhNzYzMjA5LWViNjgtNGE3Yy1iMzYzLWU4NzM2NGU5MTE0NXgxNzkzOTU0MzUwOTI2MTQ4MDAw parts=1021872026/11/06 08:39:11 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21882026/11/06 08:39:11 INFO Completed upload id=2 objects=3 duration=353.458µs21892026/11/06 08:39:11 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"21902026/11/06 08:39:11 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21912026/11/06 08:39:11 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=Yjk4MjNjN2YtNWM5MC00N2IzLWIxMDYtZTQxNDAzY2EzMzFiLmYzNTdjZTU4LWY2ODMtNGViOS1hZWQxLWJmZjUxYjZhODliY3gxNzkzOTU0MzUxMTE2MzE2MDAw parts=1021922026/11/06 08:39:11 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete21932026/11/06 08:39:11 INFO Completed upload id=2 objects=3 duration=371.083µs21942026/11/06 08:39:12 INFO Received uploads request method=POST path=/api/pending_closures21952026/11/06 08:39:12 WARN Request failed, retrying attempt=5 backoff=1.445899693s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21962026/11/06 08:39:12 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst21972026/11/06 08:39:12 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo21982026/11/06 08:39:12 INFO Received uploads request method=POST path=/api/pending_closures21992026/11/06 08:39:12 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst22002026/11/06 08:39:12 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo2201--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.92s)2202 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (5.71s)2203 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (5.89s)2204 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (5.83s)2205 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (6.98s)2206 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (7.34s)22072026/11/06 08:39:13 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused"22082026/11/06 08:39:13 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22092026/11/06 08:39:13 WARN Request failed, retrying attempt=2 backoff=202.995043ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22102026/11/06 08:39:13 WARN Request failed, retrying attempt=3 backoff=395.024264ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22112026/11/06 08:39:14 WARN Request failed, retrying attempt=4 backoff=851.069272ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22122026/11/06 08:39:15 WARN Request failed, retrying attempt=5 backoff=1.650557538s error="Get \"http://localhost:19999/api/cache-config\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/cache-config2213=== NAME TestOrphanedObjectsGCStressTest2214 orphaned_objects_gc_test.go:503: Stress test completed successfully:2215 orphaned_objects_gc_test.go:504: - Active objects preserved: 202216 orphaned_objects_gc_test.go:505: - Objects deleted: 2102217 orphaned_objects_gc_test.go:506: - Total GC'd: 2102218--- PASS: TestOrphanedObjectsGCStressTest (29.55s)22192026/11/06 08:39:16 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22202026/11/06 08:39:17 WARN Request failed, retrying attempt=2 backoff=218.269727ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22212026/11/06 08:39:17 WARN Request failed, retrying attempt=3 backoff=416.545053ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22222026/11/06 08:39:17 WARN Request failed, retrying attempt=4 backoff=867.888158ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22232026/11/06 08:39:18 WARN Request failed, retrying attempt=5 backoff=1.54456616s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp [::1]:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2224--- PASS: TestClientErrorHandling (0.01s)2225 --- PASS: TestClientErrorHandling/InvalidStorePath (4.80s)2226 --- PASS: TestClientErrorHandling/InvalidAuthToken (4.85s)2227 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.11s)2228PASS2229{"timestamp":"2026-11-06T08:39:20.076772Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:60252","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(6)"}2230{"timestamp":"2026-11-06T08:39:20.07698Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:60263","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(5)"}2231{"timestamp":"2026-11-06T08:39:20.0771Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:59464","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(6)"}2232{"timestamp":"2026-11-06T08:39:20.077733Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:60239","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(8)"}2233{"timestamp":"2026-11-06T08:39:20.078252Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:60145","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(8)"}22342026-11-06 08:39:20.224 UTC [18827] LOG: received smart shutdown request22352026-11-06 08:39:20.226 UTC [18827] LOG: background worker "logical replication launcher" (PID 18838) exited with exit code 122362026-11-06 08:39:20.230 UTC [18832] LOG: shutting down22372026-11-06 08:39:20.230 UTC [18832] LOG: checkpoint starting: shutdown immediate22382026-11-06 08:39:22.040 UTC [18832] LOG: checkpoint complete: wrote 12174 buffers (74.3%), wrote 4 SLRU buffers; 0 WAL file(s) added, 0 removed, 32 recycled; write=1.066 s, sync=0.707 s, total=1.810 s; sync files=36060, longest=0.016 s, average=0.001 s; distance=529959 kB, estimate=529959 kB; lsn=0/21D16D78, redo lsn=0/21D16D7822392026-11-06 08:39:22.049 UTC [18827] LOG: database system is shut down2240Running OIDC tests...2241=== RUN TestAudienceForIssuer2242=== PAUSE TestAudienceForIssuer2243=== RUN TestGlobMatch2244=== PAUSE TestGlobMatch2245=== RUN TestValidateToken_ValidToken2246=== PAUSE TestValidateToken_ValidToken2247=== RUN TestValidateToken_WrongAudience2248=== PAUSE TestValidateToken_WrongAudience2249=== RUN TestValidateToken_Expired2250=== PAUSE TestValidateToken_Expired2251=== RUN TestValidateToken_BoundClaimsMismatch2252=== PAUSE TestValidateToken_BoundClaimsMismatch2253=== RUN TestValidateToken_BoundSubjectMismatch2254=== PAUSE TestValidateToken_BoundSubjectMismatch2255=== RUN TestValidateToken_MultipleProviders2256=== PAUSE TestValidateToken_MultipleProviders2257=== RUN TestValidateToken_NoMatchingProvider2258=== PAUSE TestValidateToken_NoMatchingProvider2259=== RUN TestValidateToken_KubernetesServiceAccount2260=== PAUSE TestValidateToken_KubernetesServiceAccount2261=== RUN TestNewValidator_KubernetesRequiresCA2262=== PAUSE TestNewValidator_KubernetesRequiresCA2263=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2264=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2265=== RUN TestPins_ReservedForMatchingRule2266=== PAUSE TestPins_ReservedForMatchingRule2267=== RUN TestPins_TopLevelShorthand2268=== PAUSE TestPins_TopLevelShorthand2269=== RUN TestPins_ConfigValidation2270=== PAUSE TestPins_ConfigValidation2271=== RUN TestScopes_LegacyProviderDefaultsToWrite2272=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2273=== RUN TestScopes_Rules2274=== PAUSE TestScopes_Rules2275=== RUN TestScopes_ConfigValidation2276=== PAUSE TestScopes_ConfigValidation2277=== CONT TestAudienceForIssuer2278--- PASS: TestAudienceForIssuer (0.00s)2279=== CONT TestPins_ConfigValidation2280=== CONT TestValidateToken_KubernetesServiceAccount2281=== CONT TestPins_ReservedForMatchingRule2282=== CONT TestValidateToken_NoMatchingProvider2283=== CONT TestValidateToken_MultipleProviders2284=== CONT TestValidateToken_BoundSubjectMismatch2285--- PASS: TestPins_ConfigValidation (0.00s)2286=== CONT TestValidateToken_BoundClaimsMismatch2287=== CONT TestValidateToken_Expired2288=== CONT TestValidateToken_WrongAudience2289=== CONT TestValidateToken_ValidToken2290=== CONT TestGlobMatch2291=== RUN TestGlobMatch/foo_foo2292=== PAUSE TestGlobMatch/foo_foo2293=== RUN TestGlobMatch/foo_bar2294=== PAUSE TestGlobMatch/foo_bar2295=== RUN TestGlobMatch/*_2296=== PAUSE TestGlobMatch/*_2297=== RUN TestGlobMatch/*_anything2298=== PAUSE TestGlobMatch/*_anything2299=== RUN TestGlobMatch/foo*_foo2300=== PAUSE TestGlobMatch/foo*_foo2301=== RUN TestGlobMatch/foo*_foobar2302=== PAUSE TestGlobMatch/foo*_foobar2303=== RUN TestGlobMatch/foo*_bar2304=== PAUSE TestGlobMatch/foo*_bar2305=== RUN TestGlobMatch/*bar_bar2306=== PAUSE TestGlobMatch/*bar_bar2307=== RUN TestGlobMatch/*bar_foobar2308=== PAUSE TestGlobMatch/*bar_foobar2309=== RUN TestGlobMatch/*bar_foo2310=== PAUSE TestGlobMatch/*bar_foo2311=== RUN TestGlobMatch/foo*bar_foobar2312=== PAUSE TestGlobMatch/foo*bar_foobar2313=== RUN TestGlobMatch/foo*bar_foo123bar2314=== PAUSE TestGlobMatch/foo*bar_foo123bar2315=== RUN TestGlobMatch/foo*bar_foobarbaz2316=== PAUSE TestGlobMatch/foo*bar_foobarbaz2317=== RUN TestGlobMatch/*/*_foo/bar2318=== PAUSE TestGlobMatch/*/*_foo/bar2319=== RUN TestGlobMatch/*/*_foo2320=== PAUSE TestGlobMatch/*/*_foo2321=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2322=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2323=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02324=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02325=== RUN TestGlobMatch/refs/*/main_refs/heads/main2326=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2327=== RUN TestGlobMatch/fo?_foo2328=== PAUSE TestGlobMatch/fo?_foo2329=== RUN TestGlobMatch/fo?_fo2330=== PAUSE TestGlobMatch/fo?_fo2331=== RUN TestGlobMatch/fo?_fooo2332=== PAUSE TestGlobMatch/fo?_fooo2333=== RUN TestGlobMatch/?oo_foo2334=== PAUSE TestGlobMatch/?oo_foo2335=== RUN TestGlobMatch/?oo_boo2336=== PAUSE TestGlobMatch/?oo_boo2337=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2338=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2339=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2340=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2341=== CONT TestGlobMatch/foo_foo2342=== CONT TestPins_TopLevelShorthand2343=== CONT TestGlobMatch/*/*_foo/bar2344=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2345=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2346=== CONT TestGlobMatch/?oo_boo2347=== CONT TestGlobMatch/?oo_foo2348=== CONT TestGlobMatch/fo?_fooo2349=== CONT TestGlobMatch/fo?_fo2350=== CONT TestGlobMatch/fo?_foo2351=== CONT TestGlobMatch/refs/*/main_refs/heads/main2352=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02353=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2354=== CONT TestGlobMatch/*/*_foo2355=== CONT TestGlobMatch/*bar_bar2356=== CONT TestGlobMatch/foo*bar_foobarbaz2357=== CONT TestGlobMatch/foo*bar_foo123bar2358=== CONT TestGlobMatch/foo*bar_foobar2359=== CONT TestGlobMatch/*bar_foo2360=== CONT TestGlobMatch/*bar_foobar2361=== CONT TestGlobMatch/foo*_foo2362=== CONT TestGlobMatch/foo*_bar2363=== CONT TestGlobMatch/foo*_foobar2364=== CONT TestGlobMatch/*_2365=== CONT TestGlobMatch/*_anything2366=== CONT TestGlobMatch/foo_bar2367--- PASS: TestGlobMatch (0.00s)2368 --- PASS: TestGlobMatch/foo_foo (0.00s)2369 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2370 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2371 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2372 --- PASS: TestGlobMatch/?oo_boo (0.00s)2373 --- PASS: TestGlobMatch/?oo_foo (0.00s)2374 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2375 --- PASS: TestGlobMatch/fo?_fo (0.00s)2376 --- PASS: TestGlobMatch/fo?_foo (0.00s)2377 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2378 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2379 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2380 --- PASS: TestGlobMatch/*/*_foo (0.00s)2381 --- PASS: TestGlobMatch/*bar_bar (0.00s)2382 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2383 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2384 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2385 --- PASS: TestGlobMatch/*bar_foo (0.00s)2386 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2387 --- PASS: TestGlobMatch/foo*_foo (0.00s)2388 --- PASS: TestGlobMatch/foo*_bar (0.00s)2389 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2390 --- PASS: TestGlobMatch/*_ (0.00s)2391 --- PASS: TestGlobMatch/*_anything (0.00s)2392 --- PASS: TestGlobMatch/foo_bar (0.00s)2393=== CONT TestScopes_Rules2394=== CONT TestScopes_ConfigValidation2395=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2396--- PASS: TestScopes_ConfigValidation (0.00s)2397=== CONT TestNewValidator_KubernetesRequiresCA2398=== CONT TestScopes_LegacyProviderDefaultsToWrite23992026/11/06 08:39:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60310/oidc24002026/11/06 08:39:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60309/oidc24012026/11/06 08:39:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60312/oidc2402--- PASS: TestValidateToken_ValidToken (0.05s)2403--- PASS: TestValidateToken_WrongAudience (0.06s)2404--- PASS: TestValidateToken_Expired (0.06s)24052026/11/06 08:39:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60316/oidc24062026/11/06 08:39:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60315/oidc2407--- PASS: TestPins_ReservedForMatchingRule (0.07s)2408--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)24092026/11/06 08:39:23 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC12324102026/11/06 08:39:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60321/oidc2411--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.06s)2412--- PASS: TestValidateToken_BoundSubjectMismatch (0.09s)24132026/11/06 08:39:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60324/oidc24142026/11/06 08:39:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60326/oidc2415--- PASS: TestScopes_Rules (0.08s)2416--- PASS: TestPins_TopLevelShorthand (0.09s)24172026/11/06 08:39:23 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:603282418--- PASS: TestValidateToken_KubernetesServiceAccount (0.12s)24192026/11/06 08:39:23 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:60331/oidc2420--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.11s)24212026/11/06 08:39:23 http: TLS handshake error from 127.0.0.1:60335: read tcp 127.0.0.1:60334->127.0.0.1:60335: use of closed network connection2422--- PASS: TestNewValidator_KubernetesRequiresCA (0.18s)24232026/11/06 08:39:23 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:60333/oidc2424--- PASS: TestValidateToken_NoMatchingProvider (0.22s)24252026/11/06 08:39:23 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:60330/oidc24262026/11/06 08:39:23 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:60338/oidc2427--- PASS: TestValidateToken_MultipleProviders (0.23s)2428PASS2429Running hook tests...2430=== RUN TestSendPathsEmpty2431=== PAUSE TestSendPathsEmpty2432=== RUN TestQueueEnqueueAndFetch2433=== PAUSE TestQueueEnqueueAndFetch2434=== RUN TestQueueDeduplication2435=== PAUSE TestQueueDeduplication2436=== RUN TestQueueRemove2437=== PAUSE TestQueueRemove2438=== RUN TestQueueFetchBatchLimit2439=== PAUSE TestQueueFetchBatchLimit2440=== RUN TestQueueRetryMovesToBack2441=== PAUSE TestQueueRetryMovesToBack2442=== RUN TestQueueFetchRemoveLifecycle2443=== PAUSE TestQueueFetchRemoveLifecycle2444=== RUN TestQueueConcurrentWriters2445=== PAUSE TestQueueConcurrentWriters2446=== RUN TestQueueRemoveLargeClosure2447=== PAUSE TestQueueRemoveLargeClosure2448=== RUN TestServerClientIntegration2449--- PASS: TestServerClientIntegration (0.00s)2450=== RUN TestServerQueueError24512026/11/06 08:39:24 ERROR Failed to queue paths error="permission denied" count=12452--- PASS: TestServerQueueError (0.00s)2453=== RUN TestGetListenerSocketActivation2454 server_test.go:145: systemd socket activation does not exist on darwin2455--- SKIP: TestGetListenerSocketActivation (0.00s)2456=== RUN TestServerStalledClientDoesNotBlockShutdown2457=== PAUSE TestServerStalledClientDoesNotBlockShutdown2458=== RUN TestServerBacksOffOnAcceptErrors2459=== PAUSE TestServerBacksOffOnAcceptErrors2460=== RUN TestDrainIsolatesPoisonPath2461=== PAUSE TestDrainIsolatesPoisonPath2462=== RUN TestRunNotBlockedByPoisonHead2463=== PAUSE TestRunNotBlockedByPoisonHead2464=== RUN TestDrainGivesUpWhenServerDown2465=== PAUSE TestDrainGivesUpWhenServerDown2466=== RUN TestFailedPathPrunedByLaterClosure2467=== PAUSE TestFailedPathPrunedByLaterClosure2468=== RUN TestWorkerUploadsAndRemoves2469=== PAUSE TestWorkerUploadsAndRemoves2470=== RUN TestWorkerSkipsGCdPaths2471=== PAUSE TestWorkerSkipsGCdPaths2472=== RUN TestWorkerPrunesClosureDeps2473=== PAUSE TestWorkerPrunesClosureDeps2474=== RUN TestDrainTimeout2475=== PAUSE TestDrainTimeout2476=== RUN TestWorkerRemoveFailureIsNotProgress2477=== PAUSE TestWorkerRemoveFailureIsNotProgress2478=== RUN TestWorkerKeepsPathItCannotStat2479=== PAUSE TestWorkerKeepsPathItCannotStat2480=== CONT TestSendPathsEmpty2481=== CONT TestQueueFetchRemoveLifecycle2482--- PASS: TestSendPathsEmpty (0.00s)2483=== CONT TestWorkerKeepsPathItCannotStat2484=== CONT TestWorkerRemoveFailureIsNotProgress2485=== CONT TestDrainTimeout2486=== CONT TestWorkerPrunesClosureDeps2487=== CONT TestWorkerSkipsGCdPaths2488=== CONT TestWorkerUploadsAndRemoves2489=== CONT TestFailedPathPrunedByLaterClosure2490=== CONT TestDrainGivesUpWhenServerDown2491=== CONT TestRunNotBlockedByPoisonHead2492=== CONT TestDrainIsolatesPoisonPath2493=== CONT TestQueueRetryMovesToBack2494=== CONT TestServerStalledClientDoesNotBlockShutdown2495=== CONT TestQueueFetchBatchLimit2496=== CONT TestServerBacksOffOnAcceptErrors24972026/11/06 08:39:24 ERROR Accept failed error="too many open files"2498=== CONT TestQueueRemove2499=== CONT TestQueueDeduplication2500=== CONT TestQueueEnqueueAndFetch2501=== CONT TestQueueRemoveLargeClosure2502=== CONT TestQueueConcurrentWriters25032026/11/06 08:39:24 ERROR Accept failed error="too many open files"25042026/11/06 08:39:24 INFO Upload queue status pending=225052026/11/06 08:39:24 INFO Uploading batch count=125062026/11/06 08:39:24 INFO Uploading batch count=225072026/11/06 08:39:24 INFO Upload queue status pending=325082026/11/06 08:39:24 INFO Uploading batch count=125092026/11/06 08:39:24 ERROR Upload failed error="upload failed" count=125102026/11/06 08:39:24 INFO Uploading batch count=225112026/11/06 08:39:24 ERROR Upload failed error="upload failed" count=225122026/11/06 08:39:24 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/2059c74a22533349/build/TestDrainGivesUpWhenServerDown2634098174/002/a2513--- PASS: TestQueueFetchBatchLimit (0.01s)25142026/11/06 08:39:24 INFO Uploading batch count=125152026/11/06 08:39:24 ERROR Upload failed error="upload failed" count=12516--- PASS: TestQueueRemove (0.01s)25172026/11/06 08:39:24 INFO Upload queue status pending=225182026/11/06 08:39:24 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/2059c74a22533349/build/TestDrainGivesUpWhenServerDown2634098174/002/b25192026/11/06 08:39:24 INFO Uploading batch count=125202026/11/06 08:39:24 INFO Upload queue status pending=225212026/11/06 08:39:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/2059c74a22533349/build/TestWorkerSkipsGCdPaths1711430655/002/nonexistent25222026/11/06 08:39:24 INFO Uploading batch count=425232026/11/06 08:39:24 ERROR Upload failed error="upload failed" count=425242026/11/06 08:39:24 INFO Uploading batch count=125252026/11/06 08:39:24 INFO Uploading batch count=12526--- PASS: TestQueueDeduplication (0.01s)25272026/11/06 08:39:24 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/2059c74a22533349/build/TestDrainIsolatesPoisonPath1673371186/002/bbb25282026/11/06 08:39:24 INFO Uploading batch count=225292026/11/06 08:39:24 ERROR Upload failed error="upload failed" count=225302026/11/06 08:39:24 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/2059c74a22533349/build/TestDrainGivesUpWhenServerDown2634098174/002/c25312026/11/06 08:39:24 INFO Uploading batch count=225322026/11/06 08:39:24 ERROR Accept failed error="too many open files"2533--- PASS: TestQueueEnqueueAndFetch (0.01s)25342026/11/06 08:39:24 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/2059c74a22533349/build/TestDrainGivesUpWhenServerDown2634098174/002/d2535--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25362026/11/06 08:39:24 INFO Uploading batch count=225372026/11/06 08:39:24 ERROR Upload failed error="upload failed" count=225382026/11/06 08:39:24 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/2059c74a22533349/build/TestDrainGivesUpWhenServerDown2634098174/002/e2539--- PASS: TestQueueRetryMovesToBack (0.02s)25402026/11/06 08:39:24 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/8/scratch/2059c74a22533349/build/TestDrainGivesUpWhenServerDown2634098174/002/f25412026/11/06 08:39:24 ERROR Drain finished with paths left in queue remaining=1025422026/11/06 08:39:24 WARN Cannot stat store path, will retry later path=/private/var/tb/8/scratch/2059c74a22533349/build/TestWorkerKeepsPathItCannotStat1568633719/002/locked/aaa error="stat /private/var/tb/8/scratch/2059c74a22533349/build/TestWorkerKeepsPathItCannotStat1568633719/002/locked/aaa: permission denied"25432026/11/06 08:39:24 INFO Uploading batch count=125442026/11/06 08:39:24 ERROR Upload failed error="upload failed" count=12545--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)25462026/11/06 08:39:24 WARN Cannot stat store path, will retry later path=/private/var/tb/8/scratch/2059c74a22533349/build/TestWorkerKeepsPathItCannotStat1568633719/002/locked/aaa error="stat /private/var/tb/8/scratch/2059c74a22533349/build/TestWorkerKeepsPathItCannotStat1568633719/002/locked/aaa: permission denied"25472026/11/06 08:39:24 WARN Cannot stat store path, will retry later path=/private/var/tb/8/scratch/2059c74a22533349/build/TestWorkerKeepsPathItCannotStat1568633719/002/locked/aaa error="stat /private/var/tb/8/scratch/2059c74a22533349/build/TestWorkerKeepsPathItCannotStat1568633719/002/locked/aaa: permission denied"25482026/11/06 08:39:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/2059c74a22533349/build/TestWorkerRemoveFailureIsNotProgress3938686841/002/nonexistent25492026/11/06 08:39:24 INFO Uploading batch count=125502026/11/06 08:39:24 ERROR Upload failed error="upload failed" count=125512026/11/06 08:39:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125522026/11/06 08:39:24 INFO Uploading batch count=125532026/11/06 08:39:24 ERROR Upload failed error="upload failed" count=125542026/11/06 08:39:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/2059c74a22533349/build/TestWorkerRemoveFailureIsNotProgress3938686841/002/nonexistent25552026/11/06 08:39:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125562026/11/06 08:39:24 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/8/scratch/2059c74a22533349/build/TestWorkerRemoveFailureIsNotProgress3938686841/002/nonexistent25572026/11/06 08:39:24 ERROR Drain finished with paths left in queue remaining=125582026/11/06 08:39:24 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=125592026/11/06 08:39:24 ERROR Drain finished with paths left in queue remaining=125602026/11/06 08:39:24 ERROR Drain finished with paths left in queue remaining=12561--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2562--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)2563--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)2564--- PASS: TestDrainIsolatesPoisonPath (0.02s)2565--- PASS: TestWorkerPrunesClosureDeps (0.03s)25662026/11/06 08:39:24 ERROR Accept failed error="too many open files"2567--- PASS: TestWorkerSkipsGCdPaths (0.04s)2568--- PASS: TestWorkerUploadsAndRemoves (0.04s)2569--- PASS: TestQueueRemoveLargeClosure (0.04s)2570--- PASS: TestQueueConcurrentWriters (0.04s)25712026/11/06 08:39:24 ERROR Accept failed error="too many open files"25722026/11/06 08:39:24 ERROR Accept failed error="too many open files"25732026/11/06 08:39:24 ERROR Failed to decode request error="read unix /private/var/tb/8/scratch/2059c74a22533349/build/hook471088581/test.sock->: i/o timeout"25742026/11/06 08:39:24 ERROR Failed to write response error="write unix /private/var/tb/8/scratch/2059c74a22533349/build/hook471088581/test.sock->: i/o timeout"2575--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)25762026/11/06 08:39:24 ERROR Upload failed error="context deadline exceeded" count=225772026/11/06 08:39:24 ERROR Drain finished with paths left in queue remaining=42578--- PASS: TestDrainTimeout (0.22s)25792026/11/06 08:39:24 ERROR Accept failed error="too many open files"25802026/11/06 08:39:24 ERROR Accept failed error="too many open files"2581--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)25822026/11/06 08:39:25 INFO Uploading batch count=125832026/11/06 08:39:25 INFO Uploading batch count=125842026/11/06 08:39:25 INFO Uploading batch count=125852026/11/06 08:39:25 ERROR Upload failed error="upload failed" count=125862026/11/06 08:39:25 INFO Uploading batch count=125872026/11/06 08:39:25 ERROR Upload failed error="upload failed" count=125882026/11/06 08:39:25 INFO Uploading batch count=125892026/11/06 08:39:25 ERROR Upload failed error="upload failed" count=125902026/11/06 08:39:25 INFO Uploading batch count=125912026/11/06 08:39:25 ERROR Upload failed error="upload failed" count=125922026/11/06 08:39:25 ERROR Drain finished with paths left in queue remaining=12593--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2594PASS2595Running signing tests...2596=== RUN TestExternalSigner2597=== PAUSE TestExternalSigner2598=== RUN TestExternalSignerWrongPublicKey2599=== PAUSE TestExternalSignerWrongPublicKey2600=== RUN TestExternalSignerErrors2601=== PAUSE TestExternalSignerErrors2602=== RUN TestExternalSignerRestartsAfterCrash2603=== PAUSE TestExternalSignerRestartsAfterCrash2604=== RUN TestExternalSignerProgramErrorKeepsProcess2605=== PAUSE TestExternalSignerProgramErrorKeepsProcess2606=== RUN TestExternalSignerClose2607=== PAUSE TestExternalSignerClose2608=== RUN TestExternalSignerRejectsInvalidPublicKey2609=== PAUSE TestExternalSignerRejectsInvalidPublicKey2610=== RUN TestExternalSignerCancellation2611=== PAUSE TestExternalSignerCancellation2612=== RUN TestGenerateFingerprint2613=== PAUSE TestGenerateFingerprint2614=== RUN TestParseSigningKey2615=== PAUSE TestParseSigningKey2616=== RUN TestSign2617=== PAUSE TestSign2618=== RUN TestSignBatch2619=== PAUSE TestSignBatch2620=== RUN TestNilKeyPublicKey2621=== PAUSE TestNilKeyPublicKey2622=== RUN TestSignErrors2623=== PAUSE TestSignErrors2624=== CONT TestExternalSigner2625=== CONT TestExternalSignerCancellation2626=== CONT TestSignBatch2627=== CONT TestParseSigningKey2628=== RUN TestParseSigningKey/valid_32-byte_key2629=== CONT TestGenerateFingerprint2630=== PAUSE TestParseSigningKey/valid_32-byte_key2631=== CONT TestExternalSignerProgramErrorKeepsProcess2632=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2633=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2634=== RUN TestParseSigningKey/no_colon2635=== PAUSE TestParseSigningKey/no_colon2636=== RUN TestParseSigningKey/empty_name2637=== PAUSE TestParseSigningKey/empty_name2638=== RUN TestParseSigningKey/invalid_base642639=== PAUSE TestParseSigningKey/invalid_base642640=== RUN TestParseSigningKey/wrong_length2641=== PAUSE TestParseSigningKey/wrong_length2642=== CONT TestParseSigningKey/valid_32-byte_key2643=== RUN TestGenerateFingerprint/basic_with_references2644=== PAUSE TestGenerateFingerprint/basic_with_references2645=== RUN TestGenerateFingerprint/no_references2646=== PAUSE TestGenerateFingerprint/no_references2647=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2648=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2649=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2650=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2651=== RUN TestGenerateFingerprint/invalid_nar_hash_length2652=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2653=== RUN TestGenerateFingerprint/invalid_store_path_prefix2654=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2655=== RUN TestGenerateFingerprint/invalid_reference_prefix2656=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2657=== CONT TestGenerateFingerprint/basic_with_references2658=== CONT TestParseSigningKey/wrong_length2659=== CONT TestParseSigningKey/invalid_base642660=== CONT TestParseSigningKey/empty_name2661=== CONT TestParseSigningKey/no_colon2662=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2663=== CONT TestSign2664=== CONT TestSignErrors2665=== CONT TestExternalSignerRejectsInvalidPublicKey2666=== RUN TestExternalSignerRejectsInvalidPublicKey/#002667=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002668=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2669=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2670=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2671=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2672=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2673=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2674=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2675=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2676=== CONT TestExternalSignerRejectsInvalidPublicKey/#002677=== CONT TestGenerateFingerprint/invalid_reference_prefix2678=== CONT TestGenerateFingerprint/invalid_store_path_prefix2679=== CONT TestGenerateFingerprint/invalid_nar_hash_length2680=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2681=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2682=== CONT TestExternalSignerClose2683=== CONT TestExternalSignerErrors2684=== RUN TestExternalSignerErrors/wrong_signatures_shape2685=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2686=== RUN TestExternalSignerErrors/exit_at_startup2687=== PAUSE TestExternalSignerErrors/exit_at_startup2688=== RUN TestExternalSignerErrors/exit_on_request2689=== PAUSE TestExternalSignerErrors/exit_on_request2690=== RUN TestExternalSignerErrors/null2691=== PAUSE TestExternalSignerErrors/null2692=== CONT TestExternalSignerRestartsAfterCrash2693=== RUN TestExternalSignerErrors/missing_signature_name2694=== PAUSE TestExternalSignerErrors/missing_signature_name2695=== RUN TestExternalSignerErrors/program_error2696=== PAUSE TestExternalSignerErrors/program_error2697=== RUN TestExternalSignerErrors/wrong_shape2698=== PAUSE TestExternalSignerErrors/wrong_shape2699=== RUN TestExternalSignerErrors/null_signatures2700=== PAUSE TestExternalSignerErrors/null_signatures2701=== RUN TestExternalSignerErrors/wrong_signature_name2702=== PAUSE TestExternalSignerErrors/wrong_signature_name2703=== CONT TestExternalSignerWrongPublicKey2704=== RUN TestExternalSignerErrors/invalid_signature_base642705=== PAUSE TestExternalSignerErrors/invalid_signature_base642706=== RUN TestExternalSignerErrors/wrong_signature_length2707=== PAUSE TestExternalSignerErrors/wrong_signature_length2708=== RUN TestExternalSignerErrors/invalid_JSON2709=== PAUSE TestExternalSignerErrors/invalid_JSON2710=== RUN TestExternalSignerErrors/wrong_id2711=== PAUSE TestExternalSignerErrors/wrong_id2712=== CONT TestNilKeyPublicKey2713--- PASS: TestNilKeyPublicKey (0.00s)2714=== RUN TestExternalSignerErrors/missing_signatures2715=== PAUSE TestExternalSignerErrors/missing_signatures2716=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2717=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2718=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2719=== CONT TestGenerateFingerprint/no_references2720=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2721--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2722 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2723 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2724 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2725 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2726 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2727=== RUN TestExternalSignerErrors/too_few_signatures2728=== PAUSE TestExternalSignerErrors/too_few_signatures2729--- PASS: TestGenerateFingerprint (0.00s)2730 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2731 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2732 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2733 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2734 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2735 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2736 --- PASS: TestGenerateFingerprint/no_references (0.00s)2737=== RUN TestExternalSignerErrors/unrequested_key2738=== PAUSE TestExternalSignerErrors/unrequested_key2739=== CONT TestExternalSignerErrors/wrong_signatures_shape2740=== CONT TestExternalSignerErrors/wrong_signature_name2741--- PASS: TestSignBatch (0.00s)2742=== CONT TestExternalSignerErrors/missing_signature_name2743=== CONT TestExternalSignerErrors/unrequested_key2744--- PASS: TestParseSigningKey (0.00s)2745 --- PASS: TestParseSigningKey/wrong_length (0.00s)2746 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2747 --- PASS: TestParseSigningKey/empty_name (0.00s)2748 --- PASS: TestParseSigningKey/no_colon (0.00s)2749 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2750 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2751--- PASS: TestSign (0.00s)2752=== CONT TestExternalSignerErrors/too_few_signatures2753=== CONT TestExternalSignerErrors/missing_signatures2754=== CONT TestExternalSignerErrors/wrong_signature_length2755=== CONT TestExternalSignerErrors/exit_on_request2756=== CONT TestExternalSignerErrors/invalid_signature_base642757=== CONT TestExternalSignerErrors/invalid_JSON2758=== CONT TestExternalSignerErrors/null2759=== CONT TestExternalSignerErrors/exit_at_startup2760=== CONT TestExternalSignerErrors/wrong_shape2761=== CONT TestExternalSignerErrors/program_error2762=== CONT TestExternalSignerErrors/wrong_id2763=== CONT TestExternalSignerErrors/null_signatures2764=== RUN TestSignErrors/nil_key2765=== PAUSE TestSignErrors/nil_key2766=== RUN TestSignErrors/nil_narinfo2767=== PAUSE TestSignErrors/nil_narinfo2768=== RUN TestSignErrors/invalid_narinfo2769=== PAUSE TestSignErrors/invalid_narinfo2770=== RUN TestSignErrors/canceled2771=== PAUSE TestSignErrors/canceled2772=== CONT TestSignErrors/nil_key2773=== CONT TestSignErrors/canceled2774=== CONT TestSignErrors/invalid_narinfo2775=== CONT TestSignErrors/nil_narinfo2776--- PASS: TestSignErrors (0.00s)2777 --- PASS: TestSignErrors/nil_key (0.00s)2778 --- PASS: TestSignErrors/canceled (0.00s)2779 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2780 --- PASS: TestSignErrors/nil_narinfo (0.00s)2781--- PASS: TestExternalSigner (0.24s)2782--- PASS: TestExternalSignerClose (0.43s)2783--- PASS: TestExternalSignerProgramErrorKeepsProcess (0.62s)2784--- PASS: TestExternalSignerWrongPublicKey (1.97s)2785--- PASS: TestExternalSignerCancellation (2.56s)2786--- PASS: TestExternalSignerRestartsAfterCrash (2.75s)2787/private/var/tb/8/scratch/2059c74a22533349/build/TestExternalSignerRestartsAfterCrash1671781037/001/sign program: line 7: /private/var/tb/8/scratch/2059c74a22533349/build/TestExternalSignerRestartsAfterCrash1671781037/001/sign program.starts: No such file or directory2788--- PASS: TestExternalSignerErrors (0.00s)2789 --- PASS: TestExternalSignerErrors/wrong_signature_name (0.81s)2790 --- PASS: TestExternalSignerErrors/program_error (1.00s)2791 --- PASS: TestExternalSignerErrors/too_few_signatures (1.19s)2792 --- PASS: TestExternalSignerErrors/null_signatures (1.38s)2793 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (1.58s)2794 --- PASS: TestExternalSignerErrors/missing_signature_name (1.78s)2795 --- PASS: TestExternalSignerErrors/invalid_JSON (2.15s)2796 --- PASS: TestExternalSignerErrors/wrong_id (2.35s)2797 --- PASS: TestExternalSignerErrors/missing_signatures (2.91s)2798 --- PASS: TestExternalSignerErrors/wrong_shape (3.10s)2799 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (3.29s)2800 --- PASS: TestExternalSignerErrors/unrequested_key (3.48s)2801 --- PASS: TestExternalSignerErrors/null (3.67s)2802 --- PASS: TestExternalSignerErrors/exit_on_request (3.88s)2803 --- PASS: TestExternalSignerErrors/exit_at_startup (4.07s)2804 --- PASS: TestExternalSignerErrors/wrong_signature_length (4.26s)2805PASS2806Running OpenBao signer tests...2807=== RUN TestSign2808=== PAUSE TestSign2809=== RUN TestSignErrors2810=== PAUSE TestSignErrors2811=== RUN TestServe2812=== PAUSE TestServe2813=== RUN TestServeRejectsGarbage2814=== PAUSE TestServeRejectsGarbage2815=== CONT TestSign2816=== CONT TestSignErrors2817=== RUN TestSignErrors/no_prefix2818=== PAUSE TestSignErrors/no_prefix2819=== CONT TestServeRejectsGarbage2820=== CONT TestServe2821--- PASS: TestServeRejectsGarbage (0.00s)2822=== RUN TestSignErrors/invalid_base642823=== PAUSE TestSignErrors/invalid_base642824=== RUN TestSignErrors/http_error2825=== PAUSE TestSignErrors/http_error2826=== RUN TestSignErrors/invalid_json2827=== PAUSE TestSignErrors/invalid_json2828=== CONT TestSignErrors/no_prefix2829=== CONT TestSignErrors/http_error2830=== CONT TestSignErrors/invalid_json2831--- PASS: TestServe (0.00s)2832=== CONT TestSignErrors/invalid_base642833--- PASS: TestSign (0.00s)2834--- PASS: TestSignErrors (0.00s)2835 --- PASS: TestSignErrors/invalid_base64 (0.00s)2836 --- PASS: TestSignErrors/invalid_json (0.00s)2837 --- PASS: TestSignErrors/no_prefix (0.00s)2838 --- PASS: TestSignErrors/http_error (0.00s)2839PASS