niks3-go-unit-tests
checks.aarch64-darwin.go-unit-tests
· build #482
· 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.06s)25=== RUN TestDumpPathCaseHackCollision26--- PASS: TestDumpPathCaseHackCollision (0.00s)27=== RUN TestDumpPathMatchesNix28=== PAUSE TestDumpPathMatchesNix29=== RUN TestDumpPathSingleFile30=== PAUSE TestDumpPathSingleFile31=== RUN TestDumpPathWriterError32=== PAUSE TestDumpPathWriterError33=== RUN TestEncodeNixBase3234=== PAUSE TestEncodeNixBase3235=== RUN TestEncodeNixBase32WithRealHash36=== PAUSE TestEncodeNixBase32WithRealHash37=== RUN TestConvertHashToNix3238=== PAUSE TestConvertHashToNix3239=== RUN TestGetStorePathHash40=== PAUSE TestGetStorePathHash41=== RUN TestPathInfoHashCompatibility42=== PAUSE TestPathInfoHashCompatibility43=== RUN TestParsePathInfoJSON44=== PAUSE TestParsePathInfoJSON45=== RUN TestParsePathInfoJSONMultiplePaths46=== PAUSE TestParsePathInfoJSONMultiplePaths47=== RUN TestPathInfoCACompatibility48=== PAUSE TestPathInfoCACompatibility49=== RUN TestRateLimiterFeedback50=== PAUSE TestRateLimiterFeedback51=== RUN TestRateLimiterFeedback_400DoesNotCountAsSuccess52=== PAUSE TestRateLimiterFeedback_400DoesNotCountAsSuccess53=== RUN TestRegisterUploadedObject_BoundedAgainstSilentServer54=== PAUSE TestRegisterUploadedObject_BoundedAgainstSilentServer55=== RUN TestRegisterUploadedObject_OutlivesPush56=== PAUSE TestRegisterUploadedObject_OutlivesPush57=== RUN TestResolveStorePath58=== PAUSE TestResolveStorePath59=== RUN TestDoWithRetry_BodyReplayedViaGetBody60=== PAUSE TestDoWithRetry_BodyReplayedViaGetBody61=== RUN TestRetryTimeoutOutlastsMaxRetries62=== PAUSE TestRetryTimeoutOutlastsMaxRetries63=== RUN TestDoWithRetry_FinalResponseBodyReadable64=== PAUSE TestDoWithRetry_FinalResponseBodyReadable65=== RUN TestShellSplit66=== PAUSE TestShellSplit67=== RUN TestShellSplitErrors68=== PAUSE TestShellSplitErrors69=== RUN TestStreamPushReportsEveryPath70=== PAUSE TestStreamPushReportsEveryPath71=== RUN TestStreamPushBatchesUnderLoad72=== PAUSE TestStreamPushBatchesUnderLoad73=== RUN TestStreamPushIsolatesFailures74=== PAUSE TestStreamPushIsolatesFailures75=== RUN TestStreamPushGivesUpOnDeadServer76=== PAUSE TestStreamPushGivesUpOnDeadServer77=== RUN TestStreamPushRequestLine78=== PAUSE TestStreamPushRequestLine79=== RUN TestStreamPushReportsSignatures80=== PAUSE TestStreamPushReportsSignatures81=== RUN TestStreamPushReportsSkippedPaths82=== PAUSE TestStreamPushReportsSkippedPaths83=== RUN TestClientSignaturesByStorePath84=== PAUSE TestClientSignaturesByStorePath85=== RUN TestStreamPushStopsWhenCanceled86=== PAUSE TestStreamPushStopsWhenCanceled87=== RUN TestSetClientTLS88=== PAUSE TestSetClientTLS89=== RUN TestSetClientTLSDoesNotMutateDefaultTransport90=== PAUSE TestSetClientTLSDoesNotMutateDefaultTransport91=== RUN TestSetClientTLSErrors92=== PAUSE TestSetClientTLSErrors93=== RUN TestStaticToken94=== PAUSE TestStaticToken95=== RUN TestFileTokenReadsAndCaches96=== PAUSE TestFileTokenReadsAndCaches97=== RUN TestFileTokenMissing98=== PAUSE TestFileTokenMissing99=== RUN TestFileTokenEmpty100=== PAUSE TestFileTokenEmpty101=== RUN TestScriptTokenNoExpiryRerunsEveryCall102=== PAUSE TestScriptTokenNoExpiryRerunsEveryCall103=== RUN TestScriptTokenCachesUntilRefresh104=== PAUSE TestScriptTokenCachesUntilRefresh105=== RUN TestScriptTokenEmptyToken106=== PAUSE TestScriptTokenEmptyToken107=== RUN TestScriptTokenBadJSON108=== PAUSE TestScriptTokenBadJSON109=== RUN TestScriptTokenScriptFails110=== PAUSE TestScriptTokenScriptFails111=== RUN TestScriptTokenEmptyCommand112=== PAUSE TestScriptTokenEmptyCommand113=== CONT TestDoServerRequestAttachesToken114=== CONT TestStreamPushRequestLine115=== CONT TestFileTokenReadsAndCaches116=== CONT TestScriptTokenEmptyCommand117--- PASS: TestScriptTokenEmptyCommand (0.00s)118=== CONT TestRateLimiterFeedback_400DoesNotCountAsSuccess119=== CONT TestScriptTokenScriptFails120=== CONT TestScriptTokenBadJSON121=== CONT TestScriptTokenEmptyToken122=== CONT TestScriptTokenCachesUntilRefresh123=== CONT TestScriptTokenNoExpiryRerunsEveryCall124=== CONT TestFileTokenEmpty125=== CONT TestFileTokenMissing126=== CONT TestParsePathInfoJSON127=== CONT TestStreamPushGivesUpOnDeadServer128=== CONT TestStreamPushIsolatesFailures129=== CONT TestStreamPushBatchesUnderLoad130=== CONT TestStreamPushReportsEveryPath131=== CONT TestShellSplitErrors132=== CONT TestShellSplit133=== CONT TestDoWithRetry_FinalResponseBodyReadable134=== CONT TestRetryTimeoutOutlastsMaxRetries135=== CONT TestDoWithRetry_BodyReplayedViaGetBody136=== CONT TestResolveStorePath137=== CONT TestRegisterUploadedObject_OutlivesPush138=== CONT TestRegisterUploadedObject_BoundedAgainstSilentServer1392026/11/11 22:22:42 WARN Rate limiter enabled after throttle name=server-test rate=5140--- PASS: TestFileTokenReadsAndCaches (0.00s)141=== CONT TestRateLimiterFeedback1422026/11/11 22:22:42 ERROR Upload failed error=boom count=1143--- PASS: TestShellSplitErrors (0.00s)144=== CONT TestPathInfoCACompatibility145=== RUN TestPathInfoCACompatibility/null_ca_field146=== PAUSE TestPathInfoCACompatibility/null_ca_field147=== RUN TestPathInfoCACompatibility/old_string_format_-_text148=== PAUSE TestPathInfoCACompatibility/old_string_format_-_text149=== RUN TestPathInfoCACompatibility/old_string_format_-_fixed_recursive150=== PAUSE TestPathInfoCACompatibility/old_string_format_-_fixed_recursive151=== RUN TestPathInfoCACompatibility/new_structured_format_-_text152=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_text153=== RUN TestPathInfoCACompatibility/new_structured_format_-_nar_method154=== PAUSE TestPathInfoCACompatibility/new_structured_format_-_nar_method155--- PASS: TestShellSplit (0.00s)156=== CONT TestParsePathInfoJSONMultiplePaths157=== RUN TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths158=== PAUSE TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths159--- PASS: TestStreamPushReportsEveryPath (0.00s)160=== RUN TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths161=== PAUSE TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths162=== CONT TestEncodeNixBase32WithRealHash163=== CONT TestGetStorePathHash1642026/11/11 22:22:42 ERROR Upload failed error="connection refused" count=201652026/11/11 22:22:42 ERROR Server seems unavailable, giving up on batch untried=17166=== RUN TestGetStorePathHash/valid_store_path167=== PAUSE TestGetStorePathHash/valid_store_path168--- PASS: TestEncodeNixBase32WithRealHash (0.00s)169=== CONT TestConvertHashToNix32170=== CONT TestPathInfoHashCompatibility171=== RUN TestRateLimiterFeedback/429_enables_limiter172=== PAUSE TestRateLimiterFeedback/429_enables_limiter173=== RUN TestParsePathInfoJSON/Nix_format174=== RUN TestGetStorePathHash/basename_without_hyphen_should_error175=== RUN TestConvertHashToNix32/SRI_format_to_Nix32176=== RUN TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)177=== RUN TestRateLimiterFeedback/503_enables_limiter178--- PASS: TestScriptTokenScriptFails (0.00s)179=== CONT TestPartSizeForNAR180=== RUN TestPartSizeForNAR/zero_stays_at_minimum181--- PASS: TestFileTokenMissing (0.00s)182=== CONT TestSetClientTLS183=== PAUSE TestParsePathInfoJSON/Nix_format184=== RUN TestParsePathInfoJSON/Lix_format1852026/11/11 22:22:42 ERROR Upload failed error="bad path" count=3186=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=false187--- PASS: TestStreamPushIsolatesFailures (0.00s)188--- PASS: TestDoServerRequestAttachesToken (0.00s)189=== CONT TestStaticToken190=== PAUSE TestGetStorePathHash/basename_without_hyphen_should_error191=== PAUSE TestParsePathInfoJSON/Lix_format1922026/11/11 22:22:42 WARN Rate limiter enabled after throttle name=server-test rate=5193=== RUN TestParsePathInfoJSON/empty_input194=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=false195=== PAUSE TestParsePathInfoJSON/empty_input196=== RUN TestParsePathInfoJSON/whitespace_only197=== PAUSE TestParsePathInfoJSON/whitespace_only198--- PASS: TestFileTokenEmpty (0.00s)199--- PASS: TestResolveStorePath (0.00s)200=== CONT TestSetClientTLSErrors201=== CONT TestDumpPathWriterError202=== RUN TestStreamPushBatchesUnderLoad/oneAtATime=true203=== RUN TestParsePathInfoJSON/invalid_JSON2042026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:54400205=== PAUSE TestConvertHashToNix32/SRI_format_to_Nix32206=== PAUSE TestStreamPushBatchesUnderLoad/oneAtATime=true207=== CONT TestSetClientTLSDoesNotMutateDefaultTransport208--- PASS: TestStreamPushGivesUpOnDeadServer (0.00s)209=== CONT TestEncodeNixBase32210=== CONT TestDumpPathSingleFile211=== PAUSE TestParsePathInfoJSON/invalid_JSON212=== CONT TestDumpPathMatchesNix213=== PAUSE TestRateLimiterFeedback/503_enables_limiter214=== PAUSE TestPartSizeForNAR/zero_stays_at_minimum215--- PASS: TestStaticToken (0.00s)2162026/11/11 22:22:42 WARN Rate limiter backed off name=server-test rate=5217=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)218=== RUN TestPartSizeForNAR/small_stays_at_minimum2192026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:54397220=== RUN TestRateLimiterFeedback/200_does_not_enable_limiter221=== CONT TestUploadMultipart_PartsInParallel222=== RUN TestConvertHashToNix32/already_Nix32_format223=== RUN TestEncodeNixBase32/test_string_hash224--- PASS: TestDoWithRetry_FinalResponseBodyReadable (0.01s)225=== CONT TestUploadMultipart_ReturnsAfterDroppedBody226=== PAUSE TestEncodeNixBase32/test_string_hash227=== PAUSE TestRateLimiterFeedback/200_does_not_enable_limiter228=== PAUSE TestPartSizeForNAR/small_stays_at_minimum229=== RUN TestGetStorePathHash/hash_with_invalid_characters_should_error230=== PAUSE TestGetStorePathHash/hash_with_invalid_characters_should_error231=== RUN TestGetStorePathHash/hash_with_wrong_length_should_error232=== PAUSE TestGetStorePathHash/hash_with_wrong_length_should_error233=== RUN TestPathInfoHashCompatibility/old_string_format_with_colon234=== PAUSE TestPathInfoHashCompatibility/old_string_format_with_colon235=== RUN TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI236=== RUN TestEncodeNixBase32/empty_input237=== CONT TestClientSignaturesByStorePath238=== CONT TestCaseHackSuffix239--- PASS: TestSetClientTLSDoesNotMutateDefaultTransport (0.00s)240=== PAUSE TestConvertHashToNix32/already_Nix32_format241--- PASS: TestClientSignaturesByStorePath (0.00s)242=== PAUSE TestEncodeNixBase32/empty_input243=== RUN TestConvertHashToNix32/invalid_format244=== PAUSE TestConvertHashToNix32/invalid_format2452026/11/11 22:22:42 WARN Rate limiter enabled after throttle name=server-test rate=52462026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:54401247=== RUN TestRateLimiterFeedback/400_does_not_enable_limiter248=== PAUSE TestRateLimiterFeedback/400_does_not_enable_limiter249=== RUN TestPartSizeForNAR/80_GiB_fits_at_minimum250=== PAUSE TestPartSizeForNAR/80_GiB_fits_at_minimum251=== RUN TestPartSizeForNAR/115_GiB_needs_larger_parts252=== PAUSE TestPartSizeForNAR/115_GiB_needs_larger_parts253=== RUN TestPartSizeForNAR/1_TiB254=== PAUSE TestPartSizeForNAR/1_TiB255=== RUN TestPartSizeForNAR/5_TiB_S3_max_object256=== PAUSE TestPartSizeForNAR/5_TiB_S3_max_object257=== RUN TestPartSizeForNAR/capped_at_5_GiB258=== PAUSE TestPartSizeForNAR/capped_at_5_GiB259=== CONT TestFilterOversizedClosures260=== RUN TestFilterOversizedClosures/no_limit_keeps_everything261--- PASS: TestRegisterUploadedObject_OutlivesPush (0.01s)262=== PAUSE TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI263=== CONT TestStreamPushStopsWhenCanceled264--- PASS: TestStreamPushStopsWhenCanceled (0.00s)265=== CONT TestUploadBuildLog_FileBodyReplayedOnRetry2662026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:543972672026/11/11 22:22:42 WARN Rate limiter backed off name=server-test rate=52682026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=2 backoff=0s status=503 url=http://127.0.0.1:54401269=== RUN TestPathInfoHashCompatibility/new_structured_format_with_sha512270=== PAUSE TestPathInfoHashCompatibility/new_structured_format_with_sha512271=== CONT TestRunGarbageCollection_NotFoundAfterLocalRun272=== CONT TestRegisterUploadedObjectReusesConnections273--- PASS: TestScriptTokenEmptyToken (0.01s)274=== CONT TestPathInfoCACompatibility/new_structured_format_-_nar_method275=== CONT TestPathInfoCACompatibility/new_structured_format_-_text276=== CONT TestPathInfoCACompatibility/old_string_format_-_fixed_recursive277=== CONT TestPathInfoCACompatibility/old_string_format_-_text278=== CONT TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths279=== CONT TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths280=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=false281--- PASS: TestScriptTokenBadJSON (0.01s)282=== CONT TestRunGarbageCollection_FinishedOnAnotherReplica283--- PASS: TestParsePathInfoJSONMultiplePaths (0.00s)284 --- PASS: TestParsePathInfoJSONMultiplePaths/Nix_multiple_paths (0.00s)285 --- PASS: TestParsePathInfoJSONMultiplePaths/Lix_multiple_paths (0.00s)286=== CONT TestStreamPushReportsSkippedPaths287=== CONT TestStreamPushBatchesUnderLoad/oneAtATime=true288=== CONT TestParsePathInfoJSON/Nix_format289=== CONT TestParsePathInfoJSON/whitespace_only290=== CONT TestParsePathInfoJSON/invalid_JSON291=== CONT TestParsePathInfoJSON/empty_input292=== CONT TestParsePathInfoJSON/Lix_format293=== CONT TestGetStorePathHash/valid_store_path294=== CONT TestGetStorePathHash/hash_with_invalid_characters_should_error295=== CONT TestGetStorePathHash/basename_without_hyphen_should_error296=== CONT TestEncodeNixBase32/test_string_hash297=== CONT TestEncodeNixBase32/empty_input298=== CONT TestConvertHashToNix32/SRI_format_to_Nix32299=== CONT TestConvertHashToNix32/invalid_format300=== CONT TestConvertHashToNix32/already_Nix32_format301=== CONT TestRateLimiterFeedback/429_enables_limiter302=== CONT TestGetStorePathHash/hash_with_wrong_length_should_error303=== CONT TestRateLimiterFeedback/400_does_not_enable_limiter304=== CONT TestRateLimiterFeedback/200_does_not_enable_limiter305=== CONT TestStreamPushReportsSignatures3062026/11/11 22:22:42 INFO Garbage collection started307=== CONT TestPathInfoCACompatibility/null_ca_field308=== CONT TestRateLimiterFeedback/503_enables_limiter309--- PASS: TestDoWithRetry_BodyReplayedViaGetBody (0.01s)310--- PASS: TestStreamPushReportsSkippedPaths (0.00s)311=== RUN TestSetClientTLSErrors/missing_cert_file312=== PAUSE TestSetClientTLSErrors/missing_cert_file313=== RUN TestSetClientTLSErrors/missing_key_file314=== PAUSE TestSetClientTLSErrors/missing_key_file315=== RUN TestSetClientTLSErrors/missing_ca_file316=== PAUSE TestSetClientTLSErrors/missing_ca_file317=== RUN TestSetClientTLSErrors/invalid_ca_file318=== PAUSE TestSetClientTLSErrors/invalid_ca_file3192026/11/11 22:22:42 WARN Rate limiter enabled after throttle name=server-test rate=5320--- PASS: TestParsePathInfoJSON (0.00s)321 --- PASS: TestParsePathInfoJSON/Nix_format (0.00s)322 --- PASS: TestParsePathInfoJSON/whitespace_only (0.00s)323 --- PASS: TestParsePathInfoJSON/invalid_JSON (0.00s)324 --- PASS: TestParsePathInfoJSON/empty_input (0.00s)325 --- PASS: TestParsePathInfoJSON/Lix_format (0.00s)326=== CONT TestPartSizeForNAR/zero_stays_at_minimum327=== CONT TestPartSizeForNAR/1_TiB328=== CONT TestPartSizeForNAR/80_GiB_fits_at_minimum329=== PAUSE TestFilterOversizedClosures/no_limit_keeps_everything330=== RUN TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped331=== PAUSE TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped332=== RUN TestFilterOversizedClosures/all_closures_skipped333=== PAUSE TestFilterOversizedClosures/all_closures_skipped334=== CONT TestPartSizeForNAR/capped_at_5_GiB335=== CONT TestPartSizeForNAR/5_TiB_S3_max_object336=== RUN TestSetClientTLS/rejects_connection_without_client_cert337=== CONT TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI)338=== PAUSE TestSetClientTLS/rejects_connection_without_client_cert339=== RUN TestSetClientTLS/succeeds_with_client_cert_and_CA340=== PAUSE TestSetClientTLS/succeeds_with_client_cert_and_CA341=== CONT TestPartSizeForNAR/small_stays_at_minimum342=== CONT TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI343=== CONT TestPathInfoHashCompatibility/old_string_format_with_colon344=== CONT TestSetClientTLSErrors/missing_cert_file345=== CONT TestSetClientTLSErrors/invalid_ca_file346--- PASS: TestEncodeNixBase32 (0.01s)347 --- PASS: TestEncodeNixBase32/test_string_hash (0.00s)348 --- PASS: TestEncodeNixBase32/empty_input (0.00s)349--- PASS: TestConvertHashToNix32 (0.01s)350 --- PASS: TestConvertHashToNix32/SRI_format_to_Nix32 (0.00s)351 --- PASS: TestConvertHashToNix32/invalid_format (0.00s)352 --- PASS: TestConvertHashToNix32/already_Nix32_format (0.00s)353--- PASS: TestGetStorePathHash (0.01s)354 --- PASS: TestGetStorePathHash/valid_store_path (0.00s)355 --- PASS: TestGetStorePathHash/hash_with_invalid_characters_should_error (0.00s)356 --- PASS: TestGetStorePathHash/basename_without_hyphen_should_error (0.00s)357 --- PASS: TestGetStorePathHash/hash_with_wrong_length_should_error (0.00s)358--- PASS: TestStreamPushBatchesUnderLoad (0.00s)359 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=true (0.00s)360 --- PASS: TestStreamPushBatchesUnderLoad/oneAtATime=false (0.00s)361--- PASS: TestPathInfoCACompatibility (0.00s)362 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_nar_method (0.00s)363 --- PASS: TestPathInfoCACompatibility/new_structured_format_-_text (0.00s)364 --- PASS: TestPathInfoCACompatibility/old_string_format_-_fixed_recursive (0.00s)365 --- PASS: TestPathInfoCACompatibility/old_string_format_-_text (0.00s)366 --- PASS: TestPathInfoCACompatibility/null_ca_field (0.00s)367=== CONT TestPathInfoHashCompatibility/new_structured_format_with_sha512368--- PASS: TestPathInfoHashCompatibility (0.01s)369 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_dash_(SRI) (0.00s)370 --- PASS: TestPathInfoHashCompatibility/new_structured_format_-_converts_to_SRI (0.00s)371 --- PASS: TestPathInfoHashCompatibility/old_string_format_with_colon (0.00s)372 --- PASS: TestPathInfoHashCompatibility/new_structured_format_with_sha512 (0.00s)373=== CONT TestSetClientTLSErrors/missing_ca_file374=== CONT TestSetClientTLSErrors/missing_key_file375=== CONT TestFilterOversizedClosures/no_limit_keeps_everything376=== CONT TestFilterOversizedClosures/all_closures_skipped377=== CONT TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped378--- PASS: TestUploadMultipart_ReturnsAfterDroppedBody (0.01s)3792026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=429 url=http://127.0.0.1:544213802026/11/11 22:22:42 ERROR Upload failed error=boom count=13812026/11/11 22:22:42 WARN Rate limiter enabled after throttle name=server-test rate=53822026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:544393832026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=1 backoff=1ms status=502 url=http://127.0.0.1:543973842026/11/11 22:22:42 INFO Garbage collection started3852026/11/11 22:22:42 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=503862026/11/11 22:22:42 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=20003872026/11/11 22:22:42 WARN Rate limiter backed off name=server-test rate=53882026/11/11 22:22:42 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=03892026/11/11 22:22:42 WARN Rate limiter backed off name=server-test rate=5390=== CONT TestPartSizeForNAR/115_GiB_needs_larger_parts391=== RUN TestSetClientTLS/preserves_debug_logging_transport392--- PASS: TestStreamPushReportsSignatures (0.00s)393--- PASS: TestFilterOversizedClosures (0.00s)394 --- PASS: TestFilterOversizedClosures/no_limit_keeps_everything (0.00s)395 --- PASS: TestFilterOversizedClosures/all_closures_skipped (0.00s)396 --- PASS: TestFilterOversizedClosures/closure_with_oversized_dependency_is_skipped (0.00s)397=== PAUSE TestSetClientTLS/preserves_debug_logging_transport398=== CONT TestSetClientTLS/rejects_connection_without_client_cert399=== CONT TestSetClientTLS/preserves_debug_logging_transport400--- PASS: TestPartSizeForNAR (0.01s)401 --- PASS: TestPartSizeForNAR/zero_stays_at_minimum (0.00s)402 --- PASS: TestPartSizeForNAR/1_TiB (0.00s)403 --- PASS: TestPartSizeForNAR/80_GiB_fits_at_minimum (0.00s)404 --- PASS: TestPartSizeForNAR/capped_at_5_GiB (0.00s)405 --- PASS: TestPartSizeForNAR/5_TiB_S3_max_object (0.00s)406 --- PASS: TestPartSizeForNAR/small_stays_at_minimum (0.00s)407 --- PASS: TestPartSizeForNAR/115_GiB_needs_larger_parts (0.00s)408=== CONT TestSetClientTLS/succeeds_with_client_cert_and_CA409--- PASS: TestRateLimiterFeedback (0.01s)410 --- PASS: TestRateLimiterFeedback/400_does_not_enable_limiter (0.00s)411 --- PASS: TestRateLimiterFeedback/503_enables_limiter (0.00s)412 --- PASS: TestRateLimiterFeedback/429_enables_limiter (0.00s)413 --- PASS: TestRateLimiterFeedback/200_does_not_enable_limiter (0.00s)414--- PASS: TestRunGarbageCollection_NotFoundAfterLocalRun (0.00s)4152026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=2 backoff=1ms status=502 url=http://127.0.0.1:543974162026/11/11 22:22:42 WARN Garbage collection finished on another replica. Its statistics are not available here417--- PASS: TestRunGarbageCollection_FinishedOnAnotherReplica (0.00s)418--- PASS: TestStreamPushRequestLine (0.02s)419--- PASS: TestSetClientTLSErrors (0.01s)420 --- PASS: TestSetClientTLSErrors/missing_cert_file (0.00s)421 --- PASS: TestSetClientTLSErrors/missing_ca_file (0.00s)422 --- PASS: TestSetClientTLSErrors/missing_key_file (0.00s)423 --- PASS: TestSetClientTLSErrors/invalid_ca_file (0.00s)4242026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=3 backoff=1ms status=502 url=http://127.0.0.1:543974252026/11/11 22:22:42 WARN Rate limiter enabled after throttle name=s3-test rate=54262026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=1 backoff=0s status=503 url=http://127.0.0.1:544574272026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=4 backoff=1ms status=502 url=http://127.0.0.1:54397428--- PASS: TestUploadBuildLog_FileBodyReplayedOnRetry (0.01s)4292026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=5 backoff=1ms status=502 url=http://127.0.0.1:543974302026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=6 backoff=1ms status=502 url=http://127.0.0.1:543974312026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=7 backoff=1ms status=502 url=http://127.0.0.1:543974322026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=8 backoff=1ms status=502 url=http://127.0.0.1:543974332026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=9 backoff=1ms status=502 url=http://127.0.0.1:543974342026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=10 backoff=1ms status=502 url=http://127.0.0.1:543974352026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=11 backoff=1ms status=502 url=http://127.0.0.1:543974362026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=12 backoff=1ms status=502 url=http://127.0.0.1:54397437--- PASS: TestRegisterUploadedObjectReusesConnections (0.03s)4382026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=13 backoff=1ms status=502 url=http://127.0.0.1:543974392026/11/11 22:22:42 http: TLS handshake error from 127.0.0.1:54466: remote error: tls: bad certificate4402026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=14 backoff=1ms status=502 url=http://127.0.0.1:54397441--- PASS: TestSetClientTLS (0.01s)442 --- PASS: TestSetClientTLS/succeeds_with_client_cert_and_CA (0.01s)443 --- PASS: TestSetClientTLS/preserves_debug_logging_transport (0.01s)444 --- PASS: TestSetClientTLS/rejects_connection_without_client_cert (0.03s)4452026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=15 backoff=1ms status=502 url=http://127.0.0.1:54397446--- PASS: TestScriptTokenNoExpiryRerunsEveryCall (0.05s)4472026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=16 backoff=1ms status=502 url=http://127.0.0.1:543974482026/11/11 22:22:42 WARN Request returned retryable status, retrying attempt=17 backoff=1ms status=502 url=http://127.0.0.1:54397449--- PASS: TestScriptTokenCachesUntilRefresh (0.05s)450--- PASS: TestRetryTimeoutOutlastsMaxRetries (0.05s)451--- PASS: TestDumpPathWriterError (0.05s)452--- PASS: TestDumpPathSingleFile (0.06s)453--- PASS: TestCaseHackSuffix (0.06s)454--- PASS: TestDumpPathMatchesNix (0.08s)4552026/11/11 22:22:42 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:54398/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:54398/api/uploads/complete4562026/11/11 22:22:42 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:54398/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:54398/api/uploads/complete4572026/11/11 22:22:42 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://127.0.0.1:54398/api/uploads/complete\": context deadline exceeded" url=http://127.0.0.1:54398/api/uploads/complete4582026/11/11 22:22:42 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4592026/11/11 22:22:42 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"4602026/11/11 22:22:42 WARN Failed to register uploaded object key=abc.narinfo error="sending request: context canceled during retry: context deadline exceeded"461--- PASS: TestRegisterUploadedObject_BoundedAgainstSilentServer (0.10s)462--- PASS: TestUploadMultipart_PartsInParallel (0.62s)463--- PASS: TestRateLimiterFeedback_400DoesNotCountAsSuccess (1.00s)464PASS465Running server tests...466The files belonging to this database system will be owned by user "_tribuchetbld3".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/3/scratch/ba280157b5421d9f/build/postgres3644503004/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/3/scratch/ba280157b5421d9f/build/postgres3644503004/data -l logfile start4924932026-11-11 22:22:45.697 UTC [57510] LOG: starting PostgreSQL 18.6 on aarch64-apple-darwin25.6.0, compiled by clang version 21.1.8, 64-bit4942026-11-11 22:22:45.697 UTC [57510] LOG: listening on Unix socket "/private/var/tb/3/scratch/ba280157b5421d9f/build/postgres3644503004/.s.PGSQL.5432"4952026-11-11 22:22:45.699 UTC [57517] LOG: database system was shut down at 2026-11-11 22:22:45 UTC4962026-11-11 22:22:45.700 UTC [57510] LOG: database system is ready to accept connections497/private/var/tb/3/scratch/ba280157b5421d9f/build/postgres3644503004:5432 - accepting connections498{"timestamp":"2026-11-11T22:22:48.001161Z","level":"ERROR","message":"HTTP request completed","event":"http_request_completed","component":"server","subsystem":"http","request_id":"b0dc3e4b-b105-4068-ac79-7d8069bb7087","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":1,"result":"server_error","target":"rustfs::server::http","filename":"rustfs/src/server/layer.rs","line_number":502,"threadName":"rustfs-worker","threadId":"ThreadId(2)"}499=== RUN TestAbortSucceeded500=== PAUSE TestAbortSucceeded501=== RUN TestService_AuthMiddleware502=== PAUSE TestService_AuthMiddleware503=== RUN TestService_AuthMiddleware_MTLSProxyHeader504=== PAUSE TestService_AuthMiddleware_MTLSProxyHeader505=== RUN TestService_AuthMiddleware_MTLSBoundSubjects506=== PAUSE TestService_AuthMiddleware_MTLSBoundSubjects507=== RUN TestService_ReadAuthMiddleware508=== PAUSE TestService_ReadAuthMiddleware509=== RUN TestService_AuthMiddleware_OIDC510=== PAUSE TestService_AuthMiddleware_OIDC511=== RUN TestService_RequireScope_OIDC512=== PAUSE TestService_RequireScope_OIDC513=== RUN TestService_ReadScope_PublicByDefault514=== PAUSE TestService_ReadScope_PublicByDefault515=== RUN TestCacheConfigHandler516=== PAUSE TestCacheConfigHandler517=== RUN TestCacheStatsHandler518=== PAUSE TestCacheStatsHandler519=== RUN TestClientCADerivations520=== PAUSE TestClientCADerivations521=== RUN TestClientErrorHandling522=== PAUSE TestClientErrorHandling523=== RUN TestClientIntegration524=== PAUSE TestClientIntegration525=== RUN TestClientMultipleUploads526=== PAUSE TestClientMultipleUploads527=== RUN TestClientWithDependencies528=== PAUSE TestClientWithDependencies529=== RUN TestClientSharedPathCommittedMidPush530=== PAUSE TestClientSharedPathCommittedMidPush531=== RUN TestPinProtectsFromGC532=== PAUSE TestPinProtectsFromGC533=== RUN TestClientPushesUseOnePush534=== PAUSE TestClientPushesUseOnePush535=== RUN TestClientFallsBackToClosures536=== PAUSE TestClientFallsBackToClosures537=== RUN TestDeleteClosuresRacingPins538=== PAUSE TestDeleteClosuresRacingPins539=== RUN TestConcurrentCommitsSharingObjectsDoNotDeadlock540=== PAUSE TestConcurrentCommitsSharingObjectsDoNotDeadlock541=== RUN TestResolveDBConnectionString542=== PAUSE TestResolveDBConnectionString543=== RUN TestConnectWaitsForAPeerMigration544=== PAUSE TestConnectWaitsForAPeerMigration545=== RUN TestLeadElectsOneAndHandsOver546=== PAUSE TestLeadElectsOneAndHandsOver547=== RUN TestLeadIncumbentWinsAfterRestart5482026/11/11 22:22:48 INFO lead: acquired remote=192.0.2.1:1234 generation=15492026/11/11 22:22:49 INFO lead: released remote=192.0.2.1:1234 generation=15502026/11/11 22:22:49 INFO lead: acquired remote=192.0.2.1:1234 generation=25512026/11/11 22:22:50 INFO lead: released remote=192.0.2.1:1234 generation=2552--- PASS: TestLeadIncumbentWinsAfterRestart (2.16s)553=== RUN TestLeadUnannouncedStandbyYieldsToIncumbent554=== PAUSE TestLeadUnannouncedStandbyYieldsToIncumbent555=== RUN TestLeadIncumbentAnnouncesAtOnce556=== PAUSE TestLeadIncumbentAnnouncesAtOnce557=== RUN TestLeadGenerationGrowsWithEveryGrant558=== PAUSE TestLeadGenerationGrowsWithEveryGrant559=== RUN TestLeadEndsOnShutdown560=== PAUSE TestLeadEndsOnShutdown561=== RUN TestLeadEndsWhenItsConnectionHangs5622026/11/11 22:22:50 INFO lead: acquired remote=192.0.2.1:1234 generation=15632026-11-11 22:22:51.841 UTC [57573] FATAL: terminating connection due to administrator command5642026/11/11 22:22:52 INFO lead: acquired remote=192.0.2.1:1234 generation=25652026/11/11 22:22:53 WARN lead: lock connection lost error="timeout: context deadline exceeded"5662026/11/11 22:22:53 INFO lead: released remote=192.0.2.1:1234 generation=15672026/11/11 22:22:53 INFO lead: released remote=192.0.2.1:1234 generation=2568--- PASS: TestLeadEndsWhenItsConnectionHangs (2.98s)569=== RUN TestGCAdvisoryLockBlocksConcurrentRun570=== PAUSE TestGCAdvisoryLockBlocksConcurrentRun571=== RUN TestGCBugBareHashReferences572=== PAUSE TestGCBugBareHashReferences573=== RUN TestGCMetrics574=== PAUSE TestGCMetrics575=== RUN TestPushDedupSurvivesConcurrentGC576=== PAUSE TestPushDedupSurvivesConcurrentGC577=== RUN TestDeduplicatedObjectsRecordedAsPending578=== PAUSE TestDeduplicatedObjectsRecordedAsPending579=== RUN TestGCSweepSkipsPendingObjects580=== PAUSE TestGCSweepSkipsPendingObjects581=== RUN TestTombstonedObjectOfferedWithoutWaiting582=== PAUSE TestTombstonedObjectOfferedWithoutWaiting583=== RUN TestGCSweepDeliversEachKeyOnce584=== PAUSE TestGCSweepDeliversEachKeyOnce585=== RUN TestCreatePendingClosureVerifyS3FailureReleasesConnection586=== PAUSE TestCreatePendingClosureVerifyS3FailureReleasesConnection587=== RUN TestForceGCDuringPushOffersSweptObject588=== PAUSE TestForceGCDuringPushOffersSweptObject589=== RUN TestFailedS3DeleteKeepsTombstone590=== PAUSE TestFailedS3DeleteKeepsTombstone591=== RUN TestSweepSkipsRowsLockedByPush592=== PAUSE TestSweepSkipsRowsLockedByPush593=== RUN TestRegisterCompletedObjectNeedsPendingRow594=== PAUSE TestRegisterCompletedObjectNeedsPendingRow595=== RUN TestGetExistingObjectsLocksRows596=== PAUSE TestGetExistingObjectsLocksRows597=== RUN TestSweepRechecksPendingAfterLocking598=== PAUSE TestSweepRechecksPendingAfterLocking599=== RUN TestPushWaitsForSweepHoldingRow600=== PAUSE TestPushWaitsForSweepHoldingRow601=== RUN TestCommitRacingPendingCleanupKeepsObjects602=== PAUSE TestCommitRacingPendingCleanupKeepsObjects603=== RUN TestGCEndsOnShutdown604=== PAUSE TestGCEndsOnShutdown605=== RUN TestGCTaskStore_StartNew606=== PAUSE TestGCTaskStore_StartNew607=== RUN TestGCTaskStore_DeduplicateSameParams608=== PAUSE TestGCTaskStore_DeduplicateSameParams609=== RUN TestGCTaskStore_ConflictDifferentParams610=== PAUSE TestGCTaskStore_ConflictDifferentParams611=== RUN TestGCTaskStore_GetEmpty612=== PAUSE TestGCTaskStore_GetEmpty613=== RUN TestGCTaskStore_GetReturnsLatest614=== PAUSE TestGCTaskStore_GetReturnsLatest615=== RUN TestGCTaskStore_CompletedAllowsNewTask616=== PAUSE TestGCTaskStore_CompletedAllowsNewTask617=== RUN TestGCTaskStore_PhaseUpdates618=== PAUSE TestGCTaskStore_PhaseUpdates619=== RUN TestGCTaskStore_Fail620=== PAUSE TestGCTaskStore_Fail621=== RUN TestGracefulShutdownDrainsInflight622=== PAUSE TestGracefulShutdownDrainsInflight623=== RUN TestService_healthCheckHandler624=== PAUSE TestService_healthCheckHandler625=== RUN TestService_readinessHandler626=== PAUSE TestService_readinessHandler627=== RUN TestGenerateLandingPage628=== PAUSE TestGenerateLandingPage629=== RUN TestEnsureAbortUploadsRule630=== PAUSE TestEnsureAbortUploadsRule631=== RUN TestCacheConfigHandlerMaxNarSize632=== PAUSE TestCacheConfigHandlerMaxNarSize633=== RUN TestCreatePendingClosureRejectsOversizedNAR634=== PAUSE TestCreatePendingClosureRejectsOversizedNAR635=== RUN TestNARDeduplicationMetadataUploadBug636=== PAUSE TestNARDeduplicationMetadataUploadBug637=== RUN TestMetricsInventory638=== PAUSE TestMetricsInventory639=== RUN TestMetricsCommit640=== PAUSE TestMetricsCommit641=== RUN TestService_NativeMTLS642=== PAUSE TestService_NativeMTLS643=== RUN TestServerTLSConfig644=== PAUSE TestServerTLSConfig645=== RUN TestMultipartCleanup646=== PAUSE TestMultipartCleanup647=== RUN TestMultipartUploadAbortedWhenCancelledBeforeRecorded648=== PAUSE TestMultipartUploadAbortedWhenCancelledBeforeRecorded649=== RUN TestPendingCleanupUsesOneCutoff650=== PAUSE TestPendingCleanupUsesOneCutoff651=== RUN TestObjectStatsTrigger652=== PAUSE TestObjectStatsTrigger653=== RUN TestObjectStatsUpdatedOncePerCommit654=== PAUSE TestObjectStatsUpdatedOncePerCommit655=== RUN TestOrphanedObjectsGC656=== PAUSE TestOrphanedObjectsGC657=== RUN TestOrphanedObjectsGCStressTest658=== PAUSE TestOrphanedObjectsGCStressTest659=== RUN TestCreatePin_ReservedPins660=== PAUSE TestCreatePin_ReservedPins661=== RUN TestPresentReportsOnlyClosureRoots662=== PAUSE TestPresentReportsOnlyClosureRoots663=== RUN TestPresentRefreshesOnlyStaleClosures664=== PAUSE TestPresentRefreshesOnlyStaleClosures665=== RUN TestPresentNotReportedWhileGCDeletesClosure666=== PAUSE TestPresentNotReportedWhileGCDeletesClosure667=== RUN TestParseSingleRange668=== PAUSE TestParseSingleRange669=== RUN TestProxyHeadersOnlyTrustedOnSocket6702026/11/11 22:22:53 INFO Starting HTTP server address=127.0.0.1:545546712026/11/11 22:22:53 INFO Starting HTTP server address=proxy.sock6722026/11/11 22:22:53 WARN mTLS auth: subject not in bound subjects subject="CN=someone"6732026/11/11 22:22:53 INFO Shutdown signal received, draining in-flight requests timeout=10s674--- PASS: TestProxyHeadersOnlyTrustedOnSocket (0.19s)675=== RUN TestIsValidCachePath676=== PAUSE TestIsValidCachePath677=== RUN TestReadProxyNarinfo678=== PAUSE TestReadProxyNarinfo679=== RUN TestReadProxyNarinfoAlreadyDecompressed680=== PAUSE TestReadProxyNarinfoAlreadyDecompressed681=== RUN TestReadProxyContentNegotiation682=== PAUSE TestReadProxyContentNegotiation683=== RUN TestReadProxyNarStreaming684=== PAUSE TestReadProxyNarStreaming685=== RUN TestReadProxy404686=== PAUSE TestReadProxy404687=== RUN TestReadProxyInvalidPath688=== PAUSE TestReadProxyInvalidPath689=== RUN TestReadProxyHead690=== PAUSE TestReadProxyHead691=== RUN TestReadProxyOutlastsServerWriteTimeout692=== PAUSE TestReadProxyOutlastsServerWriteTimeout693=== RUN TestReadProxyConditionalGet694=== PAUSE TestReadProxyConditionalGet695=== RUN TestReadProxyRootRedirectsToIndexHTML696=== PAUSE TestReadProxyRootRedirectsToIndexHTML697=== RUN TestReadProxyDisabled698=== PAUSE TestReadProxyDisabled699=== RUN TestReadRedirectNar700=== PAUSE TestReadRedirectNar701=== RUN TestReadRedirectKeepsNarinfoProxied702=== PAUSE TestReadRedirectKeepsNarinfoProxied703=== RUN TestReadProxyRangeRequest704=== PAUSE TestReadProxyRangeRequest705=== RUN TestReadRedirectUsesPublicS3URL706=== PAUSE TestReadRedirectUsesPublicS3URL707=== RUN TestPush_OverlappingRootsStoreOneRowPerKey708=== PAUSE TestPush_OverlappingRootsStoreOneRowPerKey709=== RUN TestPush_CompleteCommitsEveryRoot710=== PAUSE TestPush_CompleteCommitsEveryRoot711=== RUN TestPush_RepeatedRootCommitsOnce712=== PAUSE TestPush_RepeatedRootCommitsOnce713=== RUN TestPush_CompleteWaitsForCleanupOfThePush714=== PAUSE TestPush_CompleteWaitsForCleanupOfThePush715=== RUN TestPush_RootsAreLockedInByteOrder716=== PAUSE TestPush_RootsAreLockedInByteOrder717=== RUN TestPush_SkippedKeySurvivesGCBeforeCommit718=== PAUSE TestPush_SkippedKeySurvivesGCBeforeCommit719=== RUN TestPush_RejectsBadRequests720=== PAUSE TestPush_RejectsBadRequests721=== RUN TestPush_SignsNarinfosOfItsPendingObjects722=== PAUSE TestPush_SignsNarinfosOfItsPendingObjects723=== RUN TestSharedNarBothUploadsComplete724=== PAUSE TestSharedNarBothUploadsComplete725=== RUN TestCompleteMultipartUpload_ErrorButObjectExists726=== PAUSE TestCompleteMultipartUpload_ErrorButObjectExists727=== RUN TestCompletedNarNotReofferedAcrossClosures728=== PAUSE TestCompletedNarNotReofferedAcrossClosures729=== RUN TestPresignedUploadRegisteredBeforeCommit730=== PAUSE TestPresignedUploadRegisteredBeforeCommit731=== RUN TestService_Rustfstest732=== PAUSE TestService_Rustfstest733=== RUN TestParseSize734=== PAUSE TestParseSize735=== RUN TestSkippedUploadsHandler736=== PAUSE TestSkippedUploadsHandler737=== RUN TestSystemdListenerNotActivated738--- PASS: TestSystemdListenerNotActivated (0.00s)739=== RUN TestWatchdogBeatsWhenHealthy740--- PASS: TestWatchdogBeatsWhenHealthy (0.03s)741=== RUN TestWatchdogSkipsWhenUnhealthy7422026/11/11 22:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7432026/11/11 22:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7442026/11/11 22:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7452026/11/11 22:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7462026/11/11 22:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7472026/11/11 22:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7482026/11/11 22:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7492026/11/11 22:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7502026/11/11 22:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"7512026/11/11 22:22:53 WARN watchdog liveness check failed, skipping heartbeat error="context deadline exceeded"752--- PASS: TestWatchdogSkipsWhenUnhealthy (0.20s)753=== RUN TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle754=== PAUSE TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle755=== RUN TestProxyWriteTimeout756=== PAUSE TestProxyWriteTimeout757=== RUN TestPendingClosureWriteTimeout758=== PAUSE TestPendingClosureWriteTimeout759=== RUN TestIsValidUploadKey760=== PAUSE TestIsValidUploadKey761=== RUN TestUploadHandlersRejectInvalidKeys762=== PAUSE TestUploadHandlersRejectInvalidKeys763=== RUN TestUploadHandlersRejectOversizedBody764=== PAUSE TestUploadHandlersRejectOversizedBody765=== RUN TestService_cleanupPendingClosuresHandler766=== PAUSE TestService_cleanupPendingClosuresHandler767=== RUN TestService_createPendingClosureHandler768=== PAUSE TestService_createPendingClosureHandler769=== RUN TestService_verifyS3Integrity770=== PAUSE TestService_verifyS3Integrity771=== RUN TestService_verifyS3ReuploadsStaleNarinfo772=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo773=== RUN TestCompleteMultipartUnregistered774=== PAUSE TestCompleteMultipartUnregistered775=== RUN TestCreatePendingClosure_SmallNARUsesSimplePUT776=== PAUSE TestCreatePendingClosure_SmallNARUsesSimplePUT777=== CONT TestService_Rustfstest778=== CONT TestService_cleanupPendingClosuresHandler779=== CONT TestCommitRacingPendingCleanupKeepsObjects780=== CONT TestUploadHandlersRejectOversizedBody781=== CONT TestAbortSucceeded782--- PASS: TestAbortSucceeded (0.00s)783=== CONT TestGCTaskStore_GetReturnsLatest784--- PASS: TestGCTaskStore_GetReturnsLatest (0.00s)785=== CONT TestPush_RepeatedRootCommitsOnce786=== CONT TestCreatePendingClosure_SmallNARUsesSimplePUT787=== CONT TestCompleteMultipartUnregistered788=== CONT TestService_verifyS3ReuploadsStaleNarinfo789=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed790=== CONT TestService_verifyS3Integrity791=== CONT TestService_createPendingClosureHandler792=== CONT TestPresignedUploadRegisteredBeforeCommit793=== CONT TestCompletedNarNotReofferedAcrossClosures794=== CONT TestCompleteMultipartUpload_ErrorButObjectExists795=== CONT TestSharedNarBothUploadsComplete796=== CONT TestPush_SignsNarinfosOfItsPendingObjects797=== CONT TestPush_RejectsBadRequests798=== CONT TestPush_SkippedKeySurvivesGCBeforeCommit799=== CONT TestGCTaskStore_GetEmpty800--- PASS: TestGCTaskStore_GetEmpty (0.00s)801=== CONT TestPush_CompleteCommitsEveryRoot802=== CONT TestGCTaskStore_ConflictDifferentParams803--- PASS: TestGCTaskStore_ConflictDifferentParams (0.00s)804=== CONT TestPush_OverlappingRootsStoreOneRowPerKey805=== CONT TestGCTaskStore_DeduplicateSameParams806=== CONT TestGCTaskStore_StartNew807=== CONT TestGCEndsOnShutdown808=== CONT TestPush_RootsAreLockedInByteOrder809=== CONT TestPush_CompleteWaitsForCleanupOfThePush810=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed811=== RUN TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed812--- PASS: TestGCTaskStore_DeduplicateSameParams (0.00s)813=== CONT TestReadRedirectUsesPublicS3URL814--- PASS: TestGCTaskStore_StartNew (0.00s)815=== CONT TestReadProxyRangeRequest816=== RUN TestGCEndsOnShutdown/before_the_run817=== PAUSE TestGCEndsOnShutdown/before_the_run818=== RUN TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete819=== PAUSE TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete820=== RUN TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark821=== PAUSE TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark822=== CONT TestReadRedirectKeepsNarinfoProxied823=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed824=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost825=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost826=== RUN TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed827=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed828=== RUN TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed829=== PAUSE TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed830=== CONT TestReadRedirectNar831=== RUN TestUploadHandlersRejectOversizedBody/complete_multipart832=== PAUSE TestUploadHandlersRejectOversizedBody/complete_multipart833=== RUN TestUploadHandlersRejectOversizedBody/request_more_parts834=== PAUSE TestUploadHandlersRejectOversizedBody/request_more_parts835=== RUN TestUploadHandlersRejectOversizedBody/create_pending_closure836=== PAUSE TestUploadHandlersRejectOversizedBody/create_pending_closure837=== CONT TestReadProxyDisabled838=== RUN TestPush_RejectsBadRequests/no_roots839=== PAUSE TestPush_RejectsBadRequests/no_roots840=== RUN TestPush_RejectsBadRequests/no_objects841=== PAUSE TestPush_RejectsBadRequests/no_objects842=== RUN TestPush_RejectsBadRequests/bad_root843=== PAUSE TestPush_RejectsBadRequests/bad_root844=== RUN TestPush_RejectsBadRequests/root_not_in_objects845=== PAUSE TestPush_RejectsBadRequests/root_not_in_objects846=== CONT TestReadProxyRootRedirectsToIndexHTML8472026/11/11 22:22:55 INFO Aborted multipart uploads count=0 kept=08482026/11/11 22:22:55 WARN Force mode enabled - objects will be deleted immediately without grace period8492026/11/11 22:22:55 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=08502026/11/11 22:22:55 INFO Received uploads request method=POST path=/api/pending_closures8512026/11/11 22:22:55 INFO Vacuumed table table=pending_closures8522026/11/11 22:22:55 INFO Vacuumed table table=pending_objects8532026/11/11 22:22:55 INFO Vacuumed table table=multipart_uploads8542026/11/11 22:22:55 INFO Vacuumed table table=closures8552026/11/11 22:22:55 INFO Vacuumed table table=objects856--- PASS: TestCommitRacingPendingCleanupKeepsObjects (1.78s)857=== CONT TestReadProxyConditionalGet8582026/11/11 22:22:55 INFO Received uploads request method=POST path=/api/pending_closures8592026/11/11 22:22:55 INFO Received uploads request method=POST path=/api/pending_closures8602026/11/11 22:22:55 INFO Received uploads request method=POST path=/api/pending_closures8612026/11/11 22:22:55 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8622026/11/11 22:22:55 ERROR Failed to get multipart upload error="no rows in result set" upload_id=does-not-exist object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst863--- PASS: TestCompleteMultipartUnregistered (2.21s)864=== CONT TestReadProxyOutlastsServerWriteTimeout865--- PASS: TestService_Rustfstest (2.43s)866=== CONT TestReadProxyHead8672026/11/11 22:22:56 INFO Received uploads request method=POST path=/api/pending_closures868--- PASS: TestCreatePendingClosure_SmallNARUsesSimplePUT (2.73s)869=== CONT TestReadProxyInvalidPath8702026/11/11 22:22:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8712026/11/11 22:22:56 INFO Received cleanup request method=DELETE path=/api/pending_closures8722026/11/11 22:22:56 INFO Aborted multipart uploads count=0 kept=08732026/11/11 22:22:56 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst upload_id=MWJkMzIxMDEtNmFiMy00YzM5LTkwMzQtOTJkOWUyMjEzODlhLjUyNDMxY2RhLWI2NWMtNDJlOC1iZGFiLWQzM2E1MjRjMDBlNngxNzk0NDM1Nzc1NDM5NjIyMDAw parts=108742026/11/11 22:22:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8752026/11/11 22:22:56 INFO Received uploads request method=POST path=/api/pending_closures8762026/11/11 22:22:56 INFO Completed upload id=1 objects=2 duration=23.817084ms8772026/11/11 22:22:56 INFO Received uploads request method=POST path=/api/pending_closures8782026/11/11 22:22:56 INFO Received uploads request method=POST path=/api/pending_closures8792026/11/11 22:22:56 INFO Object in database but missing from S3 key=dadb44fdadb44fdadb44fdadb44f0000.narinfo8802026/11/11 22:22:56 WARN Found objects in DB but missing from S3, will re-upload count=1881--- PASS: TestService_verifyS3Integrity (3.01s)882=== CONT TestReadProxy4048832026/11/11 22:22:56 INFO Received cleanup request method=DELETE path=/api/pending_closures8842026/11/11 22:22:56 INFO Aborted multipart uploads count=1 kept=08852026/11/11 22:22:56 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8862026-11-11 22:22:56.837 UTC [57648] ERROR: Closure does not exist: id=18872026-11-11 22:22:56.837 UTC [57648] CONTEXT: PL/pgSQL function commit_pending_closure(bigint) line 13 at RAISE8882026-11-11 22:22:56.837 UTC [57648] STATEMENT: -- name: CommitPendingClosure :one889 SELECT commit_pending_closure($1::bigint)::bigint890 891--- PASS: TestService_cleanupPendingClosuresHandler (3.17s)892=== CONT TestReadProxyNarStreaming8932026/11/11 22:22:56 INFO Received push request method=POST path=/api/pushes8942026/11/11 22:22:56 INFO Received complete multipart upload request method=POST path=/api/multipart/complete8952026/11/11 22:22:57 INFO Received complete push request method=POST path=/api/pushes/1/complete8962026/11/11 22:22:57 INFO Completed multipart upload object_key=nar/0000000000000000000000000000000000000000000000000000.nar.zst upload_id=MWJkMzIxMDEtNmFiMy00YzM5LTkwMzQtOTJkOWUyMjEzODlhLmI0NGVlNDE0LTRjZmMtNDZjMy1hYzViLTBkYjllMzRlNzY0Y3gxNzk0NDM1Nzc1NzA0NTEyMDAw parts=108972026/11/11 22:22:57 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete8982026/11/11 22:22:57 INFO Completed upload id=1 objects=2 duration=15.489334ms8992026/11/11 22:22:57 INFO Received get closure request method=GET path=/api/closures/000000000000000000000000000000009002026/11/11 22:22:57 INFO Received uploads request method=POST path=/api/pending_closures9012026/11/11 22:22:57 INFO Completed push id=1 objects=4 duration=31.283792ms902--- PASS: TestPush_RepeatedRootCommitsOnce (3.37s)903=== CONT TestReadProxyContentNegotiation9042026/11/11 22:22:57 INFO Starting cleanup of old closures method=DELETE path=/api/closures9052026/11/11 22:22:57 INFO Aborted multipart uploads count=0 kept=09062026/11/11 22:22:57 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=09072026/11/11 22:22:57 INFO Vacuumed table table=pending_closures9082026/11/11 22:22:57 INFO Received uploads request method=POST path=/api/pending_closures9092026/11/11 22:22:57 INFO Vacuumed table table=pending_objects9102026/11/11 22:22:57 INFO Vacuumed table table=multipart_uploads9112026/11/11 22:22:57 INFO Vacuumed table table=closures9122026/11/11 22:22:57 INFO Vacuumed table table=objects9132026/11/11 22:22:57 INFO Received get closure request method=GET path=/api/closures/00000000000000000000000000000000914--- PASS: TestService_createPendingClosureHandler (3.48s)915=== CONT TestReadProxyNarinfoAlreadyDecompressed9162026/11/11 22:22:57 INFO Registered completed upload object_key=nar/jjjjjjjjjjjjjjjjjjjjjjjjjjjjjj0100000000000000000000.nar.zst9172026/11/11 22:22:57 INFO Received uploads request method=POST path=/api/pending_closures918--- PASS: TestPresignedUploadRegisteredBeforeCommit (3.52s)919=== CONT TestReadProxyNarinfo9202026/11/11 22:22:57 INFO Received push request method=POST path=/api/pushes9212026/11/11 22:22:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9222026/11/11 22:22:57 INFO Signed narinfos id=1 count=19232026/11/11 22:22:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9242026/11/11 22:22:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9252026/11/11 22:22:57 ERROR Failed to sign narinfos signer="index 1" error="signing key cannot be nil"9262026/11/11 22:22:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9272026/11/11 22:22:57 ERROR Failed to sign narinfos signer=niks3-test-1 error="signer failed"9282026/11/11 22:22:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9292026/11/11 22:22:57 ERROR Signer returned unexpected signature count signer=niks3-test-1 got=0 want=19302026/11/11 22:22:57 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign9312026/11/11 22:22:57 ERROR Signer returned unexpected object key signer=niks3-test-1 object_key=unexpected.narinfo932--- PASS: TestPush_SignsNarinfosOfItsPendingObjects (3.67s)933=== CONT TestIsValidCachePath934=== RUN TestIsValidCachePath/narinfo935=== PAUSE TestIsValidCachePath/narinfo936=== RUN TestIsValidCachePath/narinfo_all_nix_base32_chars937=== PAUSE TestIsValidCachePath/narinfo_all_nix_base32_chars938=== RUN TestIsValidCachePath/nar_zst939=== PAUSE TestIsValidCachePath/nar_zst940=== RUN TestIsValidCachePath/nar_xz941=== PAUSE TestIsValidCachePath/nar_xz942=== RUN TestIsValidCachePath/nar_bz2943=== PAUSE TestIsValidCachePath/nar_bz2944=== RUN TestIsValidCachePath/nar_uncompressed945=== PAUSE TestIsValidCachePath/nar_uncompressed946=== RUN TestIsValidCachePath/ls947=== PAUSE TestIsValidCachePath/ls948=== RUN TestIsValidCachePath/log949=== PAUSE TestIsValidCachePath/log950=== RUN TestIsValidCachePath/realisation951=== PAUSE TestIsValidCachePath/realisation952=== RUN TestIsValidCachePath/nix-cache-info953=== PAUSE TestIsValidCachePath/nix-cache-info954=== RUN TestIsValidCachePath/index.html955=== PAUSE TestIsValidCachePath/index.html956=== RUN TestIsValidCachePath/traversal_parent957=== PAUSE TestIsValidCachePath/traversal_parent958=== RUN TestIsValidCachePath/traversal_in_middle959=== PAUSE TestIsValidCachePath/traversal_in_middle960=== RUN TestIsValidCachePath/invalid_char_e961=== PAUSE TestIsValidCachePath/invalid_char_e962=== RUN TestIsValidCachePath/invalid_char_u963=== PAUSE TestIsValidCachePath/invalid_char_u964=== RUN TestIsValidCachePath/random_path965=== PAUSE TestIsValidCachePath/random_path966=== RUN TestIsValidCachePath/empty967=== PAUSE TestIsValidCachePath/empty968=== RUN TestIsValidCachePath/leading_slash969=== PAUSE TestIsValidCachePath/leading_slash970=== RUN TestIsValidCachePath/wrong_extension971=== PAUSE TestIsValidCachePath/wrong_extension972=== RUN TestIsValidCachePath/short_hash973=== PAUSE TestIsValidCachePath/short_hash974=== CONT TestParseSingleRange975=== RUN TestParseSingleRange/none976=== PAUSE TestParseSingleRange/none977=== RUN TestParseSingleRange/unknown_unit978=== PAUSE TestParseSingleRange/unknown_unit979=== RUN TestParseSingleRange/multi-range_ignored980=== PAUSE TestParseSingleRange/multi-range_ignored981=== RUN TestParseSingleRange/malformed_no_dash982=== PAUSE TestParseSingleRange/malformed_no_dash983=== RUN TestParseSingleRange/malformed_both_empty984=== PAUSE TestParseSingleRange/malformed_both_empty985=== RUN TestParseSingleRange/malformed_end_before_start986=== PAUSE TestParseSingleRange/malformed_end_before_start987=== RUN TestParseSingleRange/closed988=== PAUSE TestParseSingleRange/closed989=== RUN TestParseSingleRange/open-ended990=== PAUSE TestParseSingleRange/open-ended991=== RUN TestParseSingleRange/end_clamped_to_size992=== PAUSE TestParseSingleRange/end_clamped_to_size993=== RUN TestParseSingleRange/suffix994=== PAUSE TestParseSingleRange/suffix995=== RUN TestParseSingleRange/suffix_exceeds_size996=== PAUSE TestParseSingleRange/suffix_exceeds_size997=== RUN TestParseSingleRange/single_byte998=== PAUSE TestParseSingleRange/single_byte999=== RUN TestParseSingleRange/start_past_EOF1000=== PAUSE TestParseSingleRange/start_past_EOF1001=== RUN TestParseSingleRange/start_far_past_EOF1002=== PAUSE TestParseSingleRange/start_far_past_EOF1003=== CONT TestMetricsCommit10042026/11/11 22:22:57 INFO Received uploads request method=POST path=/api/pending_closures10052026/11/11 22:22:57 INFO Received uploads request method=POST path=/api/pending_closures10062026/11/11 22:22:57 INFO Received push request method=POST path=/api/pushes10072026-11-11 22:22:57.864 UTC [57701] ERROR: could not obtain lock on row in relation "closures"10082026-11-11 22:22:57.864 UTC [57701] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10092026-11-11 22:22:57.872 UTC [57701] ERROR: could not obtain lock on row in relation "closures"10102026-11-11 22:22:57.872 UTC [57701] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10112026-11-11 22:22:57.874 UTC [57701] ERROR: could not obtain lock on row in relation "closures"10122026-11-11 22:22:57.874 UTC [57701] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10132026-11-11 22:22:57.874 UTC [57701] ERROR: could not obtain lock on row in relation "closures"10142026-11-11 22:22:57.874 UTC [57701] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT10152026-11-11 22:22:57.875 UTC [57701] ERROR: could not obtain lock on row in relation "closures"10162026-11-11 22:22:57.875 UTC [57701] STATEMENT: SELECT 1 FROM closures WHERE key = $1 FOR UPDATE NOWAIT1017--- PASS: TestPush_RootsAreLockedInByteOrder (4.15s)1018=== CONT TestMetricsInventory10192026/11/11 22:22:58 INFO Received uploads request method=POST path=/api/pending_closures1020--- PASS: TestReadRedirectKeepsNarinfoProxied (4.67s)1021=== CONT TestNARDeduplicationMetadataUploadBug10222026/11/11 22:22:58 INFO Received uploads request method=POST path=/api/pending_closures10232026/11/11 22:22:58 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10242026/11/11 22:22:58 WARN CompleteMultipartUpload errored but object exists; treating as success error="The specified key does not exist." object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWJkMzIxMDEtNmFiMy00YzM5LTkwMzQtOTJkOWUyMjEzODlhLjZhNDQyODhmLWQzYjItNDc1ZC1hY2QyLWExZTdmYzQ1ZjAxN3gxNzk0NDM1Nzc4Njc4MzE0MDAw10252026/11/11 22:22:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0300000000000000000000.nar.zst upload_id=MWJkMzIxMDEtNmFiMy00YzM5LTkwMzQtOTJkOWUyMjEzODlhLjZhNDQyODhmLWQzYjItNDc1ZC1hY2QyLWExZTdmYzQ1ZjAxN3gxNzk0NDM1Nzc4Njc4MzE0MDAw parts=11026--- PASS: TestCompleteMultipartUpload_ErrorButObjectExists (5.35s)1027=== CONT TestService_NativeMTLS1028--- PASS: TestReadProxyRangeRequest (5.36s)1029=== CONT TestCreatePendingClosureRejectsOversizedNAR10302026/11/11 22:22:59 INFO Received uploads request method=POST path=/api/pending_closures1031--- PASS: TestCreatePendingClosureRejectsOversizedNAR (0.00s)1032=== CONT TestPresentNotReportedWhileGCDeletesClosure1033=== RUN TestPresentNotReportedWhileGCDeletesClosure/stale1034=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/stale1035=== RUN TestPresentNotReportedWhileGCDeletesClosure/fresh1036=== PAUSE TestPresentNotReportedWhileGCDeletesClosure/fresh1037=== CONT TestCacheConfigHandlerMaxNarSize1038--- PASS: TestCacheConfigHandlerMaxNarSize (0.00s)1039=== CONT TestPresentRefreshesOnlyStaleClosures10402026/11/11 22:22:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10412026/11/11 22:22:59 INFO Received push request method=POST path=/api/pushes10422026/11/11 22:22:59 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MWJkMzIxMDEtNmFiMy00YzM5LTkwMzQtOTJkOWUyMjEzODlhLmE5OWViNTcyLTBiYTAtNDAyNC1hNjNlLTBkMDViYjFkOTMzZngxNzk0NDM1Nzc3NTEyMDYwMDAw parts=121043--- PASS: TestPush_OverlappingRootsStoreOneRowPerKey (5.72s)1044=== CONT TestPresentReportsOnlyClosureRoots10452026/11/11 22:22:59 INFO Received push request method=POST path=/api/pushes10462026/11/11 22:22:59 INFO Received complete push request method=POST path=/api/pushes/1/complete10472026/11/11 22:22:59 INFO Completed push id=1 objects=6 duration=37.711208ms1048--- PASS: TestPush_CompleteCommitsEveryRoot (6.09s)1049=== CONT TestEnsureAbortUploadsRule10502026/11/11 22:22:59 INFO Received push request method=POST path=/api/pushes10512026/11/11 22:22:59 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10522026/11/11 22:23:00 INFO Received complete push request method=POST path=/api/pushes/1/complete10532026/11/11 22:23:00 INFO Completed multipart upload object_key=nar/hhhhhhhhhhhhhhhhhhhhhhhhhhhhhh0100000000000000000000.nar.zst upload_id=MWJkMzIxMDEtNmFiMy00YzM5LTkwMzQtOTJkOWUyMjEzODlhLmI2OTk4NDc2LTU0OTUtNDVkNS04Yzg0LTViMmMxN2VlOGM5ZngxNzk0NDM1Nzc4MDU4MDgwMDAw parts=1210542026/11/11 22:23:00 INFO Received uploads request method=POST path=/api/pending_closures1055--- PASS: TestCompletedNarNotReofferedAcrossClosures (6.37s)1056=== CONT TestGenerateLandingPage1057--- PASS: TestGenerateLandingPage (0.00s)1058=== CONT TestCreatePin_ReservedPins10592026/11/11 22:23:00 INFO Completed push id=1 objects=4 duration=51.178292ms10602026/11/11 22:23:00 INFO Received push request method=POST path=/api/pushes10612026/11/11 22:23:00 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54598/oidc10622026/11/11 22:23:00 INFO Aborted multipart uploads count=0 kept=010632026/11/11 22:23:00 WARN Force mode enabled - objects will be deleted immediately without grace period10642026/11/11 22:23:00 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=010652026/11/11 22:23:00 INFO Received push request method=POST path=/api/pushes10662026/11/11 22:23:00 INFO Vacuumed table table=pending_closures10672026/11/11 22:23:00 INFO Vacuumed table table=pending_objects10682026/11/11 22:23:00 INFO Vacuumed table table=multipart_uploads10692026/11/11 22:23:00 INFO Vacuumed table table=closures10702026/11/11 22:23:00 INFO Vacuumed table table=objects10712026/11/11 22:23:00 INFO Received complete push request method=POST path=/api/pushes/2/complete10722026/11/11 22:23:00 INFO Completed push id=2 objects=4 duration=3.481292ms1073--- PASS: TestPush_SkippedKeySurvivesGCBeforeCommit (6.63s)1074=== CONT TestService_readinessHandler1075--- PASS: TestReadProxyDisabled (6.69s)1076=== CONT TestOrphanedObjectsGCStressTest10772026-11-11 22:23:00.632 UTC [57733] ERROR: Push does not exist: id=110782026-11-11 22:23:00.632 UTC [57733] CONTEXT: PL/pgSQL function commit_push(bigint) line 11 at RAISE10792026-11-11 22:23:00.632 UTC [57733] STATEMENT: SELECT commit_push($1)1080--- PASS: TestPush_CompleteWaitsForCleanupOfThePush (6.91s)1081=== CONT TestService_healthCheckHandler1082--- PASS: TestReadRedirectUsesPublicS3URL (7.03s)1083=== CONT TestOrphanedObjectsGC10842026/11/11 22:23:00 INFO Received complete multipart upload request method=POST path=/api/multipart/complete10852026/11/11 22:23:00 INFO Completed multipart upload object_key=nar/gggggggggggggggggggggggggggggg0100000000000000000000.nar.zst upload_id=MWJkMzIxMDEtNmFiMy00YzM5LTkwMzQtOTJkOWUyMjEzODlhLjE0NGNhZWQ5LWUwMzItNGFiMC1hOWI5LTU4M2Q4YjI3NDA3NHgxNzk0NDM1Nzc3NTQyNjk5MDAw parts=121086--- PASS: TestSharedNarBothUploadsComplete (7.29s)1087=== CONT TestGracefulShutdownDrainsInflight10882026/11/11 22:23:00 INFO Starting HTTP server address=127.0.0.1:5460810892026/11/11 22:23:00 INFO Shutdown signal received, draining in-flight requests timeout=10s1090--- PASS: TestGracefulShutdownDrainsInflight (0.08s)1091=== CONT TestObjectStatsUpdatedOncePerCommit1092--- PASS: TestReadRedirectNar (7.35s)1093=== CONT TestGCTaskStore_Fail1094--- PASS: TestGCTaskStore_Fail (0.00s)1095=== CONT TestObjectStatsTrigger1096--- PASS: TestReadProxyRootRedirectsToIndexHTML (6.46s)1097=== CONT TestGCTaskStore_PhaseUpdates1098--- PASS: TestGCTaskStore_PhaseUpdates (0.00s)1099=== CONT TestPendingCleanupUsesOneCutoff1100--- PASS: TestReadProxyConditionalGet (6.11s)1101=== CONT TestGCTaskStore_CompletedAllowsNewTask1102--- PASS: TestGCTaskStore_CompletedAllowsNewTask (0.00s)1103=== CONT TestMultipartUploadAbortedWhenCancelledBeforeRecorded1104--- PASS: TestReadProxyHead (6.14s)1105=== CONT TestMultipartCleanup1106--- PASS: TestReadProxyInvalidPath (6.03s)1107=== CONT TestServerTLSConfig1108=== RUN TestServerTLSConfig/no_client_CA1109=== PAUSE TestServerTLSConfig/no_client_CA1110=== RUN TestServerTLSConfig/missing_CA_file1111=== PAUSE TestServerTLSConfig/missing_CA_file1112=== RUN TestServerTLSConfig/not_a_PEM_file1113=== PAUSE TestServerTLSConfig/not_a_PEM_file1114=== CONT TestProxyWriteTimeout1115=== RUN TestProxyWriteTimeout/narinfo1116=== PAUSE TestProxyWriteTimeout/narinfo1117=== RUN TestProxyWriteTimeout/1_GiB_nar1118=== PAUSE TestProxyWriteTimeout/1_GiB_nar1119=== RUN TestProxyWriteTimeout/10_GiB_nar1120=== PAUSE TestProxyWriteTimeout/10_GiB_nar1121=== RUN TestProxyWriteTimeout/unknown_size1122=== PAUSE TestProxyWriteTimeout/unknown_size1123=== CONT TestUploadHandlersRejectInvalidKeys1124=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1125=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info1126=== RUN TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1127=== PAUSE TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal1128=== RUN TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1129=== PAUSE TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key1130=== RUN TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1131=== PAUSE TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key1132=== CONT TestIsValidUploadKey1133=== RUN TestIsValidUploadKey/narinfo1134=== PAUSE TestIsValidUploadKey/narinfo1135=== RUN TestIsValidUploadKey/nar_zst1136=== PAUSE TestIsValidUploadKey/nar_zst1137=== RUN TestIsValidUploadKey/nar_xz1138=== PAUSE TestIsValidUploadKey/nar_xz1139=== RUN TestIsValidUploadKey/nar_plain1140=== PAUSE TestIsValidUploadKey/nar_plain1141=== RUN TestIsValidUploadKey/listing1142=== PAUSE TestIsValidUploadKey/listing1143=== RUN TestIsValidUploadKey/build_log1144=== PAUSE TestIsValidUploadKey/build_log1145=== RUN TestIsValidUploadKey/build_log_home-manager_file1146=== PAUSE TestIsValidUploadKey/build_log_home-manager_file1147=== RUN TestIsValidUploadKey/build_log_plus_in_name1148=== PAUSE TestIsValidUploadKey/build_log_plus_in_name1149=== RUN TestIsValidUploadKey/build_log_question_mark1150=== PAUSE TestIsValidUploadKey/build_log_question_mark1151=== RUN TestIsValidUploadKey/build_log_equals1152=== PAUSE TestIsValidUploadKey/build_log_equals1153=== RUN TestIsValidUploadKey/realisation1154=== PAUSE TestIsValidUploadKey/realisation1155=== RUN TestIsValidUploadKey/realisation_plus_in_output1156=== PAUSE TestIsValidUploadKey/realisation_plus_in_output1157=== RUN TestIsValidUploadKey/nix-cache-info1158=== PAUSE TestIsValidUploadKey/nix-cache-info1159=== RUN TestIsValidUploadKey/index.html1160=== PAUSE TestIsValidUploadKey/index.html1161=== RUN TestIsValidUploadKey/narinfo_key,_nar_type1162=== PAUSE TestIsValidUploadKey/narinfo_key,_nar_type1163=== RUN TestIsValidUploadKey/nar_key,_narinfo_type1164=== PAUSE TestIsValidUploadKey/nar_key,_narinfo_type1165=== RUN TestIsValidUploadKey/listing_key,_narinfo_type1166=== PAUSE TestIsValidUploadKey/listing_key,_narinfo_type1167=== RUN TestIsValidUploadKey/traversal1168=== PAUSE TestIsValidUploadKey/traversal1169=== RUN TestIsValidUploadKey/traversal_nar1170=== PAUSE TestIsValidUploadKey/traversal_nar1171=== RUN TestIsValidUploadKey/absolute1172=== PAUSE TestIsValidUploadKey/absolute1173=== RUN TestIsValidUploadKey/empty_key1174=== PAUSE TestIsValidUploadKey/empty_key1175=== RUN TestIsValidUploadKey/unknown_type1176=== PAUSE TestIsValidUploadKey/unknown_type1177=== CONT TestPendingClosureWriteTimeout1178=== RUN TestPendingClosureWriteTimeout/empty1179=== PAUSE TestPendingClosureWriteTimeout/empty1180=== RUN TestPendingClosureWriteTimeout/400_objects1181=== PAUSE TestPendingClosureWriteTimeout/400_objects1182=== RUN TestPendingClosureWriteTimeout/670k_objects1183=== PAUSE TestPendingClosureWriteTimeout/670k_objects1184=== RUN TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1185=== PAUSE TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1186=== CONT TestSkippedUploadsHandler11872026/11/11 22:23:02 INFO Client skipped oversized paths paths=3 nar_bytes=50000000001188--- PASS: TestSkippedUploadsHandler (0.00s)1189=== CONT TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1190--- PASS: TestReadProxyNarStreaming (6.33s)1191=== CONT TestClientErrorHandling1192=== RUN TestClientErrorHandling/InvalidStorePath1193=== PAUSE TestClientErrorHandling/InvalidStorePath1194=== RUN TestClientErrorHandling/InvalidAuthToken1195=== PAUSE TestClientErrorHandling/InvalidAuthToken1196=== RUN TestClientErrorHandling/ServerNotAvailable1197=== PAUSE TestClientErrorHandling/ServerNotAvailable1198=== CONT TestConnectWaitsForAPeerMigration1199--- PASS: TestReadProxy404 (6.63s)1200=== CONT TestPushWaitsForSweepHoldingRow1201--- PASS: TestReadProxyContentNegotiation (6.51s)1202=== CONT TestSweepRechecksPendingAfterLocking1203--- PASS: TestReadProxyNarinfoAlreadyDecompressed (6.52s)1204=== CONT TestGetExistingObjectsLocksRows12052026/11/11 22:23:04 ERROR Failed to decode narinfo key=3hcdxyjf9yiq7qf3i4548drb6sjmwa1v.narinfo limit=16777216 error=<nil>1206--- PASS: TestReadProxyNarinfo (6.83s)1207=== CONT TestRegisterCompletedObjectNeedsPendingRow12082026/11/11 22:23:04 INFO Received push request method=POST path=/api/pushes12092026/11/11 22:23:04 INFO Received complete push request method=POST path=/api/pushes/1/complete12102026/11/11 22:23:04 INFO Completed push id=1 objects=4 duration=47.594333ms12112026/11/11 22:23:04 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete12122026/11/11 22:23:04 INFO Completed upload id=2 objects=2 duration=2.812292ms1213--- PASS: TestMetricsCommit (7.09s)1214=== CONT TestSweepSkipsRowsLockedByPush1215--- PASS: TestMetricsInventory (6.80s)1216=== CONT TestFailedS3DeleteKeepsTombstone1217=== NAME TestNARDeduplicationMetadataUploadBug1218 metadata_upload_test.go:48: First store path: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestNARDeduplicationMetadataUploadBug1277451011/001/store/pf35cxrx36m175n51af9zw4vqrzmcwib-file1.txt12192026/11/11 22:23:05 WARN mTLS auth: subject not in bound subjects subject="CN=reader"12202026/11/11 22:23:05 WARN mTLS auth: subject not in bound subjects subject="CN=reader"1221--- PASS: TestService_NativeMTLS (6.09s)1222=== CONT TestForceGCDuringPushOffersSweptObject1223=== RUN TestForceGCDuringPushOffersSweptObject/before_pending_rows1224=== PAUSE TestForceGCDuringPushOffersSweptObject/before_pending_rows1225=== RUN TestForceGCDuringPushOffersSweptObject/after_presence_check1226=== PAUSE TestForceGCDuringPushOffersSweptObject/after_presence_check1227=== CONT TestCreatePendingClosureVerifyS3FailureReleasesConnection12282026/11/11 22:23:05 INFO Received push request method=POST path=/api/pushes12292026/11/11 22:23:05 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)12302026/11/11 22:23:05 INFO Uploading pf35cxrx36m175n51af9zw4vqrzmcwib-file1.txt (160B)12312026/11/11 22:23:05 WARN Failed to register uploaded object key=pf35cxrx36m175n51af9zw4vqrzmcwib.ls error="server returned 404: 404 page not found\n"12322026/11/11 22:23:05 WARN Failed to register uploaded object key=nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst error="server returned 404: 404 page not found\n"12332026/11/11 22:23:05 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign12342026/11/11 22:23:05 INFO Signed narinfos id=1 count=112352026/11/11 22:23:05 INFO Uploading 1 narinfos12362026/11/11 22:23:05 INFO Received complete push request method=POST path=/api/pushes/1/complete12372026/11/11 22:23:05 WARN Failed to register uploaded object key=pf35cxrx36m175n51af9zw4vqrzmcwib.narinfo error="server returned 404: 404 page not found\n"12382026/11/11 22:23:05 INFO Completed push id=1 objects=3 duration=30.571791ms12392026/11/11 22:23:05 INFO Upload complete. (286ms)1240=== NAME TestNARDeduplicationMetadataUploadBug1241 metadata_upload_test.go:54: Retrieved narinfo from S3:1242 StorePath: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestNARDeduplicationMetadataUploadBug1277451011/001/store/pf35cxrx36m175n51af9zw4vqrzmcwib-file1.txt1243 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1244 Compression: zstd1245 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1246 NarSize: 1601247 References: 1248 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1249 metadata_upload_test.go:55: Retrieved .ls file from S3 (compressed size: 77 bytes)1250 metadata_upload_test.go:55: Decompressed .ls content (64 bytes):1251 {"version":1,"root":{"type":"regular","size":44,"narOffset":96}}1252--- PASS: TestPresentRefreshesOnlyStaleClosures (6.33s)1253=== CONT TestResolveDBConnectionString1254=== RUN TestResolveDBConnectionString/flag_wins1255=== PAUSE TestResolveDBConnectionString/flag_wins1256=== RUN TestResolveDBConnectionString/file_when_flag_empty1257=== PAUSE TestResolveDBConnectionString/file_when_flag_empty1258=== RUN TestResolveDBConnectionString/missing_file_is_an_error1259=== PAUSE TestResolveDBConnectionString/missing_file_is_an_error1260=== RUN TestResolveDBConnectionString/PGHOST_allows_empty1261=== PAUSE TestResolveDBConnectionString/PGHOST_allows_empty1262=== RUN TestResolveDBConnectionString/nothing_configured1263=== PAUSE TestResolveDBConnectionString/nothing_configured1264=== CONT TestConcurrentCommitsSharingObjectsDoNotDeadlock1265=== NAME TestNARDeduplicationMetadataUploadBug1266 metadata_upload_test.go:64: Second store path (same content): /private/var/tb/3/scratch/ba280157b5421d9f/build/TestNARDeduplicationMetadataUploadBug1277451011/001/store/lzl4irjj19vr9q7vxa95gyl8gn7vxv9r-file2.txt12672026/11/11 22:23:05 INFO Received push request method=POST path=/api/pushes12682026/11/11 22:23:05 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)12692026/11/11 22:23:05 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign12702026/11/11 22:23:05 WARN Failed to register uploaded object key=lzl4irjj19vr9q7vxa95gyl8gn7vxv9r.ls error="server returned 404: 404 page not found\n"12712026/11/11 22:23:05 INFO Signed narinfos id=2 count=112722026/11/11 22:23:05 INFO Uploading 1 narinfos1273--- PASS: TestPresentReportsOnlyClosureRoots (6.26s)1274=== CONT TestDeleteClosuresRacingPins12752026/11/11 22:23:05 INFO Received complete push request method=POST path=/api/pushes/2/complete12762026/11/11 22:23:05 WARN Failed to register uploaded object key=lzl4irjj19vr9q7vxa95gyl8gn7vxv9r.narinfo error="server returned 404: 404 page not found\n"12772026/11/11 22:23:05 INFO Completed push id=2 objects=3 duration=1.503417ms12782026/11/11 22:23:05 INFO Upload complete. (147ms)1279=== NAME TestNARDeduplicationMetadataUploadBug1280 metadata_upload_test.go:76: Retrieved narinfo from S3:1281 StorePath: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestNARDeduplicationMetadataUploadBug1277451011/001/store/lzl4irjj19vr9q7vxa95gyl8gn7vxv9r-file2.txt1282 URL: nar/1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf.nar.zst1283 Compression: zstd1284 NarHash: sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1285 NarSize: 1601286 References: 1287 CA: fixed:r:sha256:1byf36hhc5sn8lvwqfkjh3ybgn76slmx8naakslrypxs6mna71rf1288 metadata_upload_test.go:77: Retrieved .ls file from S3 (compressed size: 62 bytes)1289 metadata_upload_test.go:77: Decompressed .ls content (49 bytes):1290 {"version":1,"root":{"type":"regular","size":44}}1291--- PASS: TestNARDeduplicationMetadataUploadBug (7.34s)1292=== CONT TestClientFallsBackToClosures12932026/11/11 22:23:05 INFO Installed lifecycle rule aborting incomplete NAR uploads bucket=bucket44 days=21294--- PASS: TestEnsureAbortUploadsRule (6.14s)1295=== CONT TestGCSweepDeliversEachKeyOnce12962026/11/11 22:23:06 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12972026/11/11 22:23:06 WARN Refused reserved pin name=worker-x86_64-linux12982026/11/11 22:23:06 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux12992026/11/11 22:23:06 INFO Received create pin request method=POST path=/api/pins/my-app13002026/11/11 22:23:06 INFO Received create pin request method=POST path=/api/pins/worker-x86_64-linux1301--- PASS: TestCreatePin_ReservedPins (5.99s)1302=== CONT TestTombstonedObjectOfferedWithoutWaiting1303--- PASS: TestReadProxyOutlastsServerWriteTimeout (10.31s)1304=== CONT TestGCSweepSkipsPendingObjects13052026/11/11 22:23:06 WARN readiness check failed error="closed pool"1306--- PASS: TestService_readinessHandler (5.90s)1307=== CONT TestDeduplicatedObjectsRecordedAsPending1308--- PASS: TestService_healthCheckHandler (6.02s)1309=== CONT TestPushDedupSurvivesConcurrentGC1310--- PASS: TestObjectStatsUpdatedOncePerCommit (6.39s)1311=== CONT TestGCMetrics1312--- PASS: TestObjectStatsTrigger (6.51s)1313=== CONT TestClientPushesUseOnePush13142026/11/11 22:23:07 INFO Received uploads request method=POST path=/api/pending_closures13152026/11/11 22:23:08 INFO Received uploads request method=POST path=/api/pending_closures13162026/11/11 22:23:08 INFO Received cleanup request method=DELETE path=/api/pending_closures13172026/11/11 22:23:08 INFO Received uploads request method=POST path=/api/pending_closures1318--- PASS: TestMultipartUploadAbortedWhenCancelledBeforeRecorded (6.84s)1319=== CONT TestGCBugBareHashReferences13202026/11/11 22:23:08 INFO Received uploads request method=POST path=/api/pending_closures1321=== NAME TestOrphanedObjectsGC1322 orphaned_objects_gc_test.go:287: GC Test Summary:1323 orphaned_objects_gc_test.go:288: - Kept: 2 objects from closure A1324 orphaned_objects_gc_test.go:289: - Deleted: 2 objects from closure B1325 orphaned_objects_gc_test.go:290: - Deleted: 6 orphaned chain objects (X1->X2->X3)1326 orphaned_objects_gc_test.go:291: - Deleted: 2 orphaned single objects (Y)1327 orphaned_objects_gc_test.go:292: - Total deleted: 10 objects1328--- PASS: TestOrphanedObjectsGC (8.22s)1329=== CONT TestPinProtectsFromGC13302026/11/11 22:23:09 INFO Received cleanup request method=DELETE path=/api/pending_closures13312026/11/11 22:23:09 WARN Failed to abort upload, keeping its closure key=nar/dadb44fdadb44fdadb44fdadb44f000000000000000000000000.nar.zst error="Get \"http://127.0.0.1:1/bucket54/?location=\": dial tcp 127.0.0.1:1: connect: connection refused" code=""13322026/11/11 22:23:09 INFO Aborted multipart uploads count=0 kept=113332026/11/11 22:23:09 INFO Received cleanup request method=DELETE path=/api/pending_closures13342026/11/11 22:23:09 INFO Aborted multipart uploads count=1 kept=01335--- PASS: TestMultipartCleanup (6.89s)1336=== CONT TestGCAdvisoryLockBlocksConcurrentRun13372026/11/11 22:23:09 INFO Received uploads request method=POST path=/api/pending_closures13382026/11/11 22:23:09 INFO Received uploads request method=POST path=/api/pending_closures13392026/11/11 22:23:09 INFO Received complete multipart upload request method=POST path=/api/multipart/complete1340--- PASS: TestGetExistingObjectsLocksRows (6.14s)1341=== CONT TestClientSharedPathCommittedMidPush1342--- PASS: TestPushWaitsForSweepHoldingRow (6.67s)1343=== CONT TestClientWithDependencies13442026/11/11 22:23:10 INFO Aborted multipart uploads count=0 kept=013452026/11/11 22:23:10 WARN Force mode enabled - objects will be deleted immediately without grace period13462026/11/11 22:23: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=013472026/11/11 22:23:10 INFO Vacuumed table table=pending_closures13482026/11/11 22:23:10 INFO Vacuumed table table=pending_objects13492026/11/11 22:23:10 INFO Vacuumed table table=multipart_uploads13502026/11/11 22:23:10 INFO Vacuumed table table=closures13512026/11/11 22:23:10 INFO Vacuumed table table=objects1352--- PASS: TestSweepRechecksPendingAfterLocking (6.79s)1353=== CONT TestLeadEndsOnShutdown1354--- PASS: TestRegisterCompletedObjectNeedsPendingRow (6.33s)1355=== CONT TestLeadGenerationGrowsWithEveryGrant1356--- PASS: TestConnectWaitsForAPeerMigration (7.34s)1357=== CONT TestLeadIncumbentAnnouncesAtOnce13582026/11/11 22:23:10 INFO Aborted multipart uploads count=0 kept=013592026/11/11 22:23:10 WARN Force mode enabled - objects will be deleted immediately without grace period13602026/11/11 22:23: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=013612026/11/11 22:23:10 INFO Vacuumed table table=pending_closures13622026/11/11 22:23:10 INFO Vacuumed table table=pending_objects13632026/11/11 22:23:10 INFO Vacuumed table table=multipart_uploads13642026/11/11 22:23:10 INFO Vacuumed table table=closures13652026/11/11 22:23:10 INFO Vacuumed table table=objects13662026/11/11 22:23:10 INFO Aborted multipart uploads count=0 kept=013672026/11/11 22:23:10 WARN Force mode enabled - objects will be deleted immediately without grace period13682026/11/11 22:23:10 INFO Received uploads request method=POST path=/api/pending_closures13692026/11/11 22:23:11 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=013702026/11/11 22:23:11 INFO Vacuumed table table=pending_closures13712026/11/11 22:23:11 INFO Vacuumed table table=pending_objects13722026/11/11 22:23:11 INFO Vacuumed table table=multipart_uploads13732026/11/11 22:23:11 INFO Vacuumed table table=closures13742026/11/11 22:23:11 INFO Vacuumed table table=objects1375--- PASS: TestSweepSkipsRowsLockedByPush (6.75s)1376=== CONT TestLeadUnannouncedStandbyYieldsToIncumbent13772026/11/11 22:23:11 INFO Aborted multipart uploads count=0 kept=013782026/11/11 22:23:11 WARN Force mode enabled - objects will be deleted immediately without grace period13792026/11/11 22:23:11 ERROR failed to remove object object=nar/dddddddddddddddddddddddddddddddddddddddddddddddddddd.nar.zst error="Access Denied."13802026/11/11 22:23:11 ERROR failed to remove object object=dddddddddddddddddddddddddddddddd.narinfo error="Access Denied."1381--- PASS: TestFailedS3DeleteKeepsTombstone (6.60s)1382=== CONT TestLeadElectsOneAndHandsOver13832026/11/11 22:23:11 INFO Received uploads request method=POST path=/api/pending_closures1384--- PASS: TestCreatePendingClosureVerifyS3FailureReleasesConnection (6.42s)1385=== CONT TestClientMultipleUploads13862026/11/11 22:23:12 INFO Aborted multipart uploads count=0 kept=013872026/11/11 22:23:12 WARN Force mode enabled - objects will be deleted immediately without grace period13882026/11/11 22:23:12 INFO Received uploads request method=POST path=/api/pending_closures13892026/11/11 22:23:12 INFO Received uploads request method=POST path=/api/pending_closures13902026/11/11 22:23:12 INFO Received uploads request method=POST path=/api/pending_closures13912026/11/11 22:23:12 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)13922026/11/11 22:23:12 INFO Uploading 5r3x00gma0c8zmscx2l3rkcvz97fdxpz-a (256B)13932026/11/11 22:23:12 INFO Uploading hnayqza3421mjp8w8pdpa9sahb896f78-shared-dep (136B)1394--- PASS: TestTombstonedObjectOfferedWithoutWaiting (6.85s)1395=== CONT TestClientIntegration13962026/11/11 22:23:12 WARN Failed to register uploaded object key=5r3x00gma0c8zmscx2l3rkcvz97fdxpz.ls error="server returned 404: 404 page not found\n"13972026/11/11 22:23:12 WARN Failed to register uploaded object key=hnayqza3421mjp8w8pdpa9sahb896f78.ls error="server returned 404: 404 page not found\n"13982026/11/11 22:23:12 WARN Failed to register uploaded object key=0rnph95f6qm4q2v1mijqy1dpgz6v91yr.ls error="server returned 404: 404 page not found\n"13992026/11/11 22:23:12 WARN Failed to register uploaded object key=nar/0nhl309d599n1cpdilz1fcqw86p7vkpl3pf048sdj9k00nddl3v0.nar.zst error="server returned 404: 404 page not found\n"14002026/11/11 22:23:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/2/sign14012026/11/11 22:23:12 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"14022026/11/11 22:23:12 INFO Signed narinfos id=2 count=214032026/11/11 22:23:12 INFO Received sign narinfos request method=POST path=/api/pending_closures/1/sign14042026/11/11 22:23:12 INFO Signed narinfos id=1 count=214052026/11/11 22:23:12 INFO Uploading 4 narinfos14062026/11/11 22:23:13 WARN Failed to register uploaded object key=5r3x00gma0c8zmscx2l3rkcvz97fdxpz.narinfo error="server returned 404: 404 page not found\n"14072026/11/11 22:23:13 WARN Failed to register uploaded object key=hnayqza3421mjp8w8pdpa9sahb896f78.narinfo error="server returned 404: 404 page not found\n"14082026/11/11 22:23:13 WARN Failed to register uploaded object key=0rnph95f6qm4q2v1mijqy1dpgz6v91yr.narinfo error="server returned 404: 404 page not found\n"14092026/11/11 22:23:13 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete14102026/11/11 22:23:13 WARN Failed to register uploaded object key=hnayqza3421mjp8w8pdpa9sahb896f78.narinfo error="server returned 404: 404 page not found\n"14112026/11/11 22:23:13 INFO Completed upload id=1 objects=6 duration=65.662917ms14122026/11/11 22:23:13 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete14132026/11/11 22:23:13 INFO Completed upload id=2 objects=6 duration=1.430291ms14142026/11/11 22:23:13 INFO Upload complete. (519ms)1415=== NAME TestClientFallsBackToClosures1416 client_pushes_test.go:112: Retrieved narinfo from S3:1417 StorePath: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientFallsBackToClosures1529809612/001/store/hnayqza3421mjp8w8pdpa9sahb896f78-shared-dep1418 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1419 Compression: zstd1420 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821421 NarSize: 1361422 References: 1423 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1424 client_pushes_test.go:112: Retrieved narinfo from S3:1425 StorePath: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientFallsBackToClosures1529809612/001/store/5r3x00gma0c8zmscx2l3rkcvz97fdxpz-a1426 URL: nar/0nhl309d599n1cpdilz1fcqw86p7vkpl3pf048sdj9k00nddl3v0.nar.zst1427 Compression: zstd1428 NarHash: sha256:0nhl309d599n1cpdilz1fcqw86p7vkpl3pf048sdj9k00nddl3v01429 NarSize: 2561430 References: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientFallsBackToClosures1529809612/001/store/hnayqza3421mjp8w8pdpa9sahb896f78-shared-dep1431 CA: text:sha256:0dbiv42yvmvq7ryqyv9jcixxjgm9b3wkyky04lbq1ip9n10sl82p1432 client_pushes_test.go:112: Retrieved narinfo from S3:1433 StorePath: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientFallsBackToClosures1529809612/001/store/0rnph95f6qm4q2v1mijqy1dpgz6v91yr-b1434 URL: nar/0nhl309d599n1cpdilz1fcqw86p7vkpl3pf048sdj9k00nddl3v0.nar.zst1435 Compression: zstd1436 NarHash: sha256:0nhl309d599n1cpdilz1fcqw86p7vkpl3pf048sdj9k00nddl3v01437 NarSize: 2561438 References: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientFallsBackToClosures1529809612/001/store/hnayqza3421mjp8w8pdpa9sahb896f78-shared-dep1439 CA: text:sha256:0dbiv42yvmvq7ryqyv9jcixxjgm9b3wkyky04lbq1ip9n10sl82p1440--- PASS: TestConcurrentCommitsSharingObjectsDoNotDeadlock (7.85s)1441=== CONT TestParseSize1442--- PASS: TestParseSize (0.00s)1443=== CONT TestService_RequireScope_OIDC14442026/11/11 22:23:13 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=014452026/11/11 22:23:13 INFO Vacuumed table table=pending_closures14462026/11/11 22:23:13 INFO Received uploads request method=POST path=/api/pending_closures14472026/11/11 22:23:13 INFO Vacuumed table table=pending_objects14482026/11/11 22:23:13 INFO Vacuumed table table=multipart_uploads14492026/11/11 22:23:13 INFO Vacuumed table table=closures1450--- PASS: TestClientFallsBackToClosures (7.64s)1451=== CONT TestClientCADerivations14522026/11/11 22:23:13 INFO Vacuumed table table=objects1453--- PASS: TestGCSweepDeliversEachKeyOnce (7.44s)1454=== CONT TestCacheStatsHandler14552026/11/11 22:23:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54707/oidc14562026/11/11 22:23:13 INFO Aborted multipart uploads count=0 kept=014572026/11/11 22:23:13 WARN Force mode enabled - objects will be deleted immediately without grace period14582026/11/11 22:23:13 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=014592026/11/11 22:23:13 INFO Vacuumed table table=pending_closures14602026/11/11 22:23:13 INFO Vacuumed table table=pending_objects14612026/11/11 22:23:13 INFO Vacuumed table table=multipart_uploads14622026/11/11 22:23:13 INFO Vacuumed table table=closures14632026/11/11 22:23:13 INFO Vacuumed table table=objects1464--- PASS: TestGCSweepSkipsPendingObjects (7.33s)1465=== CONT TestService_AuthMiddleware_MTLSBoundSubjects14662026/11/11 22:23:13 INFO Received uploads request method=POST path=/api/pending_closures14672026/11/11 22:23:13 WARN Rate limiter enabled after throttle name=s3-test rate=514682026/11/11 22:23:13 WARN S3 rate limit hit operation="complete multipart upload" error="Please reduce your request rate."1469=== NAME TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle1470 throttle_test.go:213: Proxy stats: total=13, throttled=10, completeMultipart=101471 throttle_test.go:215: Rate limiter: enabled=true, rate=5.001472--- PASS: TestCompleteMultipartUploadHandler_RateLimitTriggersThrottle (11.14s)1473=== CONT TestService_AuthMiddleware_OIDC1474--- PASS: TestDeduplicatedObjectsRecordedAsPending (7.39s)1475=== CONT TestService_ReadAuthMiddleware14762026/11/11 22:23:13 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54711/oidc14772026/11/11 22:23:13 INFO Received uploads request method=POST path=/api/pending_closures14782026/11/11 22:23:14 INFO Aborted multipart uploads count=1 kept=014792026/11/11 22:23:14 INFO Received cleanup request method=DELETE path=/api/pending_closures14802026/11/11 22:23:14 INFO Aborted multipart uploads count=1 kept=01481--- PASS: TestPendingCleanupUsesOneCutoff (12.85s)1482=== CONT TestService_AuthMiddleware_MTLSProxyHeader14832026/11/11 22:23:14 INFO Aborted multipart uploads count=0 kept=014842026/11/11 22:23:14 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=014852026/11/11 22:23:14 INFO Aborted multipart uploads count=0 kept=014862026/11/11 22:23:14 WARN Force mode enabled - objects will be deleted immediately without grace period14872026/11/11 22:23:14 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=014882026/11/11 22:23:14 INFO Vacuumed table table=pending_closures14892026/11/11 22:23:14 INFO Vacuumed table table=pending_closures14902026/11/11 22:23:14 INFO Vacuumed table table=pending_objects14912026/11/11 22:23:14 INFO Vacuumed table table=multipart_uploads14922026/11/11 22:23:14 INFO Vacuumed table table=closures14932026/11/11 22:23:14 INFO Vacuumed table table=pending_objects14942026/11/11 22:23:14 INFO Vacuumed table table=objects14952026/11/11 22:23:14 INFO Vacuumed table table=multipart_uploads1496--- PASS: TestGCMetrics (6.83s)1497=== CONT TestCacheConfigHandler1498=== RUN TestCacheConfigHandler/full_config,_no_issuer1499=== PAUSE TestCacheConfigHandler/full_config,_no_issuer1500=== RUN TestCacheConfigHandler/no_cache_url_configured1501=== PAUSE TestCacheConfigHandler/no_cache_url_configured1502=== RUN TestCacheConfigHandler/no_signing_keys1503=== PAUSE TestCacheConfigHandler/no_signing_keys1504=== RUN TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1505=== PAUSE TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator1506=== CONT TestService_ReadScope_PublicByDefault15072026/11/11 22:23:14 INFO Vacuumed table table=closures15082026/11/11 22:23:14 INFO Vacuumed table table=objects15092026/11/11 22:23:14 INFO Aborted multipart uploads count=0 kept=015102026/11/11 22:23:14 WARN Force mode enabled - objects will be deleted immediately without grace period15112026/11/11 22:23:14 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=015122026/11/11 22:23:14 INFO Vacuumed table table=pending_closures15132026/11/11 22:23:14 INFO Vacuumed table table=pending_objects15142026/11/11 22:23:14 INFO Vacuumed table table=multipart_uploads15152026/11/11 22:23:14 INFO Vacuumed table table=closures15162026/11/11 22:23:14 INFO Vacuumed table table=objects1517--- PASS: TestPushDedupSurvivesConcurrentGC (7.75s)1518=== CONT TestService_AuthMiddleware1519--- PASS: TestGCBugBareHashReferences (6.62s)1520=== CONT TestGCEndsOnShutdown/before_the_run15212026/11/11 22:23:15 INFO Received push request method=POST path=/api/pushes15222026/11/11 22:23:15 INFO Uploading 2 paths to 127.0.0.1 (1 already cached)15232026/11/11 22:23:15 INFO Uploading cm36x1zs8kipw4p96kp1z0m9xqwjcwgz-shared-dep (136B)15242026/11/11 22:23:15 INFO Uploading 171rmbsaavi8phzg63i29bh31d8lm73f-b (256B)15252026/11/11 22:23:15 WARN Failed to register uploaded object key=cm36x1zs8kipw4p96kp1z0m9xqwjcwgz.ls error="server returned 404: 404 page not found\n"15262026/11/11 22:23:15 WARN Failed to register uploaded object key=171rmbsaavi8phzg63i29bh31d8lm73f.ls error="server returned 404: 404 page not found\n"15272026/11/11 22:23:15 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"15282026/11/11 22:23:15 WARN Failed to register uploaded object key=1xi4b1328vbn0fqyskz8mnrgx234qa0j.ls error="server returned 404: 404 page not found\n"15292026/11/11 22:23:15 WARN Failed to register uploaded object key=nar/0v15ll2mrpzvhm4a3xms9vn0fldsigg9p29py4syfw6ac5rm4kym.nar.zst error="server returned 404: 404 page not found\n"15302026/11/11 22:23:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15312026/11/11 22:23:15 INFO Signed narinfos id=1 count=315322026/11/11 22:23:15 INFO Uploading 3 narinfos15332026/11/11 22:23:15 WARN Failed to register uploaded object key=1xi4b1328vbn0fqyskz8mnrgx234qa0j.narinfo error="server returned 404: 404 page not found\n"15342026/11/11 22:23:15 WARN Failed to register uploaded object key=171rmbsaavi8phzg63i29bh31d8lm73f.narinfo error="server returned 404: 404 page not found\n"15352026/11/11 22:23:15 INFO Received complete push request method=POST path=/api/pushes/1/complete15362026/11/11 22:23:15 WARN Failed to register uploaded object key=cm36x1zs8kipw4p96kp1z0m9xqwjcwgz.narinfo error="server returned 404: 404 page not found\n"15372026/11/11 22:23:15 INFO Completed push id=1 objects=8 duration=40.426125ms15382026/11/11 22:23:15 INFO Upload complete. (348ms)1539=== NAME TestClientPushesUseOnePush1540 client_pushes_test.go:97: Retrieved narinfo from S3:1541 StorePath: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientPushesUseOnePush2458599549/001/store/cm36x1zs8kipw4p96kp1z0m9xqwjcwgz-shared-dep1542 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1543 Compression: zstd1544 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821545 NarSize: 1361546 References: 1547 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1548 client_pushes_test.go:97: Retrieved narinfo from S3:1549 StorePath: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientPushesUseOnePush2458599549/001/store/1xi4b1328vbn0fqyskz8mnrgx234qa0j-a1550 URL: nar/0v15ll2mrpzvhm4a3xms9vn0fldsigg9p29py4syfw6ac5rm4kym.nar.zst1551 Compression: zstd1552 NarHash: sha256:0v15ll2mrpzvhm4a3xms9vn0fldsigg9p29py4syfw6ac5rm4kym1553 NarSize: 2561554 References: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientPushesUseOnePush2458599549/001/store/cm36x1zs8kipw4p96kp1z0m9xqwjcwgz-shared-dep1555 CA: text:sha256:1qx03svisn3b7cwhyyw32rcbcdp5m6zkpzbgdik152jk191yp9gh1556 client_pushes_test.go:97: Retrieved narinfo from S3:1557 StorePath: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientPushesUseOnePush2458599549/001/store/171rmbsaavi8phzg63i29bh31d8lm73f-b1558 URL: nar/0v15ll2mrpzvhm4a3xms9vn0fldsigg9p29py4syfw6ac5rm4kym.nar.zst1559 Compression: zstd1560 NarHash: sha256:0v15ll2mrpzvhm4a3xms9vn0fldsigg9p29py4syfw6ac5rm4kym1561 NarSize: 2561562 References: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientPushesUseOnePush2458599549/001/store/cm36x1zs8kipw4p96kp1z0m9xqwjcwgz-shared-dep1563 CA: text:sha256:1qx03svisn3b7cwhyyw32rcbcdp5m6zkpzbgdik152jk191yp9gh1564--- PASS: TestClientPushesUseOnePush (7.81s)1565=== CONT TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark1566=== NAME TestPinProtectsFromGC1567 client_integration_test.go:778: Pinned store path: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestPinProtectsFromGC1609749400/001/store/9jjyvxbwwb4kql8hr2886k8qhl0j3fzk-pinned-file.txt1568 client_integration_test.go:779: Unpinned store path: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestPinProtectsFromGC1609749400/001/store/q0rprgg311a2vsy7ri00rdccs38sy89m-unpinned-file.txt15692026/11/11 22:23:15 ERROR failed to check GC advisory lock error="query pg_locks: failed to connect to `user=_tribuchetbld3 database=niks3`: /nonexistent/.s.PGSQL.5432 (/nonexistent): dial error: dial unix /nonexistent/.s.PGSQL.5432: connect: no such file or directory"1570--- PASS: TestGCAdvisoryLockBlocksConcurrentRun (6.36s)1571=== CONT TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete15722026/11/11 22:23:15 INFO Received push request method=POST path=/api/pushes15732026/11/11 22:23:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15742026/11/11 22:23:15 INFO Uploading 9jjyvxbwwb4kql8hr2886k8qhl0j3fzk-pinned-file.txt (128B)15752026/11/11 22:23:15 WARN Failed to register uploaded object key=9jjyvxbwwb4kql8hr2886k8qhl0j3fzk.ls error="server returned 404: 404 page not found\n"15762026/11/11 22:23:15 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign15772026/11/11 22:23:15 WARN Failed to register uploaded object key=nar/0qmhsg42pqsz7x6hh02j8gznnac3yi3qpjhrqbwvz88i194jbb5s.nar.zst error="server returned 404: 404 page not found\n"15782026/11/11 22:23:15 INFO Signed narinfos id=1 count=115792026/11/11 22:23:15 INFO Uploading 1 narinfos15802026/11/11 22:23:15 INFO Received complete push request method=POST path=/api/pushes/1/complete15812026/11/11 22:23:15 WARN Failed to register uploaded object key=9jjyvxbwwb4kql8hr2886k8qhl0j3fzk.narinfo error="server returned 404: 404 page not found\n"15822026/11/11 22:23:15 INFO Completed push id=1 objects=3 duration=17.924917ms15832026/11/11 22:23:15 INFO Upload complete. (242ms)15842026/11/11 22:23:15 INFO Received push request method=POST path=/api/pushes15852026/11/11 22:23:15 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)15862026/11/11 22:23:15 INFO Uploading q0rprgg311a2vsy7ri00rdccs38sy89m-unpinned-file.txt (128B)15872026/11/11 22:23:15 WARN Failed to register uploaded object key=q0rprgg311a2vsy7ri00rdccs38sy89m.ls error="server returned 404: 404 page not found\n"15882026/11/11 22:23:15 INFO Received sign narinfos request method=POST path=/api/pushes/2/sign15892026/11/11 22:23:15 WARN Failed to register uploaded object key=nar/0gh0wdnr6gmk4r5sfzzh12isnl14rgmkrwy1ws41hpsrlndclg5h.nar.zst error="server returned 404: 404 page not found\n"15902026/11/11 22:23:15 INFO Signed narinfos id=2 count=115912026/11/11 22:23:15 INFO Uploading 1 narinfos15922026/11/11 22:23:16 INFO Received complete push request method=POST path=/api/pushes/2/complete15932026/11/11 22:23:16 WARN Failed to register uploaded object key=q0rprgg311a2vsy7ri00rdccs38sy89m.narinfo error="server returned 404: 404 page not found\n"15942026/11/11 22:23:16 INFO Completed push id=2 objects=3 duration=1.101541ms15952026/11/11 22:23:16 INFO Upload complete. (224ms)15962026/11/11 22:23:16 INFO Starting cleanup of old closures method=DELETE path=/api/closures15972026/11/11 22:23:16 INFO Garbage collection started15982026/11/11 22:23:16 INFO Aborted multipart uploads count=0 kept=015992026/11/11 22:23:16 WARN Force mode enabled - objects will be deleted immediately without grace period16002026/11/11 22:23:16 INFO Received push request method=POST path=/api/pushes16012026/11/11 22:23:16 INFO Uploading 2 paths to 127.0.0.1 (0 already cached)16022026/11/11 22:23:16 INFO Uploading bbygppl2hr0877hbfabwj1vgvg4fsmqm-top (264B)16032026/11/11 22:23:16 INFO Uploading s9h4845hdc7ycs572n9cl2l7rrhhvfn9-shared-dep (136B)16042026/11/11 22:23:16 WARN Failed to register uploaded object key=bbygppl2hr0877hbfabwj1vgvg4fsmqm.ls error="server returned 404: 404 page not found\n"16052026/11/11 22:23:16 WARN Failed to register uploaded object key=nar/1bja4bq253mb64xspmwmywvcf9ldidlhqjzsn33fs5aknbi8m24s.nar.zst error="server returned 404: 404 page not found\n"16062026/11/11 22:23:16 WARN Failed to register uploaded object key=s9h4845hdc7ycs572n9cl2l7rrhhvfn9.ls error="server returned 404: 404 page not found\n"16072026/11/11 22:23:16 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16082026/11/11 22:23:16 WARN Failed to register uploaded object key=nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst error="server returned 404: 404 page not found\n"16092026/11/11 22:23:16 INFO Signed narinfos id=1 count=216102026/11/11 22:23:16 INFO Uploading 2 narinfos16112026/11/11 22:23:16 INFO lead: acquired remote=192.0.2.1:1234 generation=116122026/11/11 22:23:16 WARN Failed to register uploaded object key=s9h4845hdc7ycs572n9cl2l7rrhhvfn9.narinfo error="server returned 404: 404 page not found\n"16132026/11/11 22:23:16 INFO Received complete push request method=POST path=/api/pushes/1/complete16142026/11/11 22:23:16 WARN Failed to register uploaded object key=bbygppl2hr0877hbfabwj1vgvg4fsmqm.narinfo error="server returned 404: 404 page not found\n"1615--- PASS: TestDeleteClosuresRacingPins (10.88s)1616=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed16172026/11/11 22:23:16 INFO Completed push id=1 objects=6 duration=29.515584ms16182026/11/11 22:23:16 INFO Upload complete. (402ms)1619=== NAME TestClientSharedPathCommittedMidPush1620 client_integration_test.go:727: Retrieved narinfo from S3:1621 StorePath: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientSharedPathCommittedMidPush1963740814/001/store/s9h4845hdc7ycs572n9cl2l7rrhhvfn9-shared-dep1622 URL: nar/1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y82.nar.zst1623 Compression: zstd1624 NarHash: sha256:1vnl0g6w4zgpfz06rb321mfd3jqsrs120jcl8dg2dxn014875y821625 NarSize: 1361626 References: 1627 CA: text:sha256:08nxw05k7b0pzzy0f3swvnw4ldxdbclkdnklpidwmrxdhvfrmv7n1628 client_integration_test.go:727: Retrieved narinfo from S3:1629 StorePath: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientSharedPathCommittedMidPush1963740814/001/store/bbygppl2hr0877hbfabwj1vgvg4fsmqm-top1630 URL: nar/1bja4bq253mb64xspmwmywvcf9ldidlhqjzsn33fs5aknbi8m24s.nar.zst1631 Compression: zstd1632 NarHash: sha256:1bja4bq253mb64xspmwmywvcf9ldidlhqjzsn33fs5aknbi8m24s1633 NarSize: 2641634 References: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientSharedPathCommittedMidPush1963740814/001/store/s9h4845hdc7ycs572n9cl2l7rrhhvfn9-shared-dep1635 CA: text:sha256:0y33sw019ibjafcc45nss48v2sb45kd5p1q21p5kww0rdriqp5xr16362026/11/11 22:23:16 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=016372026/11/11 22:23:16 INFO Vacuumed table table=pending_closures16382026/11/11 22:23:16 INFO Vacuumed table table=pending_objects16392026/11/11 22:23:16 INFO Vacuumed table table=multipart_uploads1640--- PASS: TestClientSharedPathCommittedMidPush (6.86s)1641=== CONT TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed16422026/11/11 22:23:16 INFO Vacuumed table table=closures16432026/11/11 22:23:16 INFO Vacuumed table table=objects1644=== NAME TestClientWithDependencies1645 client_integration_test.go:660: Built derivation: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientWithDependencies2115722383/001/store/snpnggqjdhvkrmxd3kvxdxjxks27i4g9-test-script16462026/11/11 22:23:16 INFO lead: acquired remote=192.0.2.1:1234 generation=11647 client_integration_test.go:662: Found 1 dependencies (including self)16482026/11/11 22:23:16 INFO Received push request method=POST path=/api/pushes16492026/11/11 22:23:17 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)16502026/11/11 22:23:17 INFO Uploading snpnggqjdhvkrmxd3kvxdxjxks27i4g9-test-script (136B)16512026/11/11 22:23:17 WARN Failed to register uploaded object key=snpnggqjdhvkrmxd3kvxdxjxks27i4g9.ls error="server returned 404: 404 page not found\n"16522026/11/11 22:23:17 WARN Failed to register uploaded object key=nar/1s7yghixzpinyqm7g59kyn3sav81pmnsdi5v63m6x4r2vacy907j.nar.zst error="server returned 404: 404 page not found\n"16532026/11/11 22:23:17 WARN Failed to register uploaded object key=log/wxj66i5p7jgh417m5rkm9krdzh13qfss-test-script.drv error="server returned 404: 404 page not found\n"16542026/11/11 22:23:17 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign16552026/11/11 22:23:17 INFO Signed narinfos id=1 count=116562026/11/11 22:23:17 INFO Uploading 1 narinfos16572026/11/11 22:23:17 INFO Received complete push request method=POST path=/api/pushes/1/complete16582026/11/11 22:23:17 WARN Failed to register uploaded object key=snpnggqjdhvkrmxd3kvxdxjxks27i4g9.narinfo error="server returned 404: 404 page not found\n"16592026/11/11 22:23:17 INFO lead: acquired remote=192.0.2.1:1234 generation=116602026/11/11 22:23:17 INFO lead: released remote=192.0.2.1:1234 generation=11661--- PASS: TestLeadIncumbentAnnouncesAtOnce (6.69s)1662=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed16632026/11/11 22:23:17 INFO Completed push id=1 objects=4 duration=38.418792ms16642026/11/11 22:23:17 INFO Upload complete. (361ms)1665=== NAME TestClientWithDependencies1666 client_integration_test.go:664: Skipping nix copy test - isolated store (/private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientWithDependencies2115722383/001/store) requires matching store prefix1667--- PASS: TestClientWithDependencies (7.34s)1668=== CONT TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost16692026/11/11 22:23:17 INFO lead: acquired remote=192.0.2.1:1234 generation=116702026/11/11 22:23:17 INFO lead: released remote=192.0.2.1:1234 generation=11671--- PASS: TestLeadEndsOnShutdown (7.21s)1672=== CONT TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed16732026/11/11 22:23:17 INFO lead: acquired remote=192.0.2.1:1234 generation=116742026/11/11 22:23:17 INFO lead: released remote=192.0.2.1:1234 generation=116752026/11/11 22:23:17 INFO lead: acquired remote=192.0.2.1:1234 generation=216762026/11/11 22:23:18 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=016772026/11/11 22:23:18 INFO Received create pin request method=POST path=/api/pins/myapp16782026/11/11 22:23:18 INFO Created/updated pin name=myapp store_path=/private/var/tb/3/scratch/ba280157b5421d9f/build/TestPinProtectsFromGC1609749400/001/store/9jjyvxbwwb4kql8hr2886k8qhl0j3fzk-pinned-file.txt narinfo_key=9jjyvxbwwb4kql8hr2886k8qhl0j3fzk.narinfo16792026/11/11 22:23:18 INFO Starting cleanup of old closures method=DELETE path=/api/closures16802026/11/11 22:23:18 INFO Garbage collection started16812026/11/11 22:23:18 INFO Aborted multipart uploads count=0 kept=016822026/11/11 22:23:18 WARN Force mode enabled - objects will be deleted immediately without grace period16832026/11/11 22:23:18 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=016842026/11/11 22:23:18 INFO Vacuumed table table=pending_closures16852026/11/11 22:23:18 INFO Vacuumed table table=pending_objects16862026/11/11 22:23:18 INFO Vacuumed table table=multipart_uploads16872026/11/11 22:23:18 INFO Vacuumed table table=closures16882026/11/11 22:23:18 INFO Vacuumed table table=objects1689=== NAME TestClientMultipleUploads1690 client_integration_test.go:405: Created store path 0: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientMultipleUploads451787732/001/store/jybrl73q6wwmribmkzps4cqgvnw1ihr6-test-file-0.txt16912026/11/11 22:23:18 INFO lead: released remote=192.0.2.1:1234 generation=116922026/11/11 22:23:18 INFO lead: acquired remote=192.0.2.1:1234 generation=216932026/11/11 22:23:18 INFO lead: given back to the incumbent remote=192.0.2.1:1234 generation=216942026/11/11 22:23:18 INFO lead: acquired remote=192.0.2.1:1234 generation=31695 client_integration_test.go:405: Created store path 1: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientMultipleUploads451787732/001/store/pk7jshchxdxlwf0cmsg6d77a5dik4vcw-test-file-1.txt1696=== NAME TestOrphanedObjectsGCStressTest1697 orphaned_objects_gc_test.go:422: Created 10 active closures, 5 to-delete closures, 20 orphaned chains1698=== NAME TestClientMultipleUploads1699 client_integration_test.go:405: Created store path 2: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientMultipleUploads451787732/001/store/wig7b9qa8a7hsj0camygnld8l6sxf8zw-test-file-2.txt1700=== NAME TestClientIntegration1701 client_integration_test.go:291: Created store path: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientIntegration2773348901/002/store/c63m8zzvmdzxnq7mlqlmpyfhjgzj0x70-test-file.txt1702=== NAME TestOrphanedObjectsGCStressTest1703 orphaned_objects_gc_test.go:440: Marked 210 objects for deletion17042026/11/11 22:23:18 INFO Received push request method=POST path=/api/pushes17052026/11/11 22:23:18 INFO Received push request method=POST path=/api/pushes17062026/11/11 22:23:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)17072026/11/11 22:23:19 INFO Uploading c63m8zzvmdzxnq7mlqlmpyfhjgzj0x70-test-file.txt (152B)17082026/11/11 22:23:19 INFO Uploading 3 paths to 127.0.0.1 (0 already cached)17092026/11/11 22:23:19 INFO Uploading jybrl73q6wwmribmkzps4cqgvnw1ihr6-test-file-0.txt (160B)17102026/11/11 22:23:19 INFO Uploading wig7b9qa8a7hsj0camygnld8l6sxf8zw-test-file-2.txt (160B)17112026/11/11 22:23:19 INFO Uploading pk7jshchxdxlwf0cmsg6d77a5dik4vcw-test-file-1.txt (160B)17122026/11/11 22:23:19 INFO lead: released remote=192.0.2.1:1234 generation=217132026/11/11 22:23:19 INFO lead: acquired remote=192.0.2.1:1234 generation=317142026/11/11 22:23:19 INFO lead: released remote=192.0.2.1:1234 generation=31715--- PASS: TestLeadGenerationGrowsWithEveryGrant (8.72s)1716=== CONT TestUploadHandlersRejectOversizedBody/complete_multipart17172026/11/11 22:23:19 INFO Received complete multipart upload request method=POST path=/17182026/11/11 22:23:19 WARN Failed to register uploaded object key=c63m8zzvmdzxnq7mlqlmpyfhjgzj0x70.ls error="server returned 404: 404 page not found\n"17192026/11/11 22:23:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17202026/11/11 22:23:19 WARN Failed to register uploaded object key=nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst error="server returned 404: 404 page not found\n"17212026/11/11 22:23:19 INFO lead: released remote=192.0.2.1:1234 generation=117222026/11/11 22:23:19 INFO Signed narinfos id=1 count=11723=== CONT TestUploadHandlersRejectOversizedBody/create_pending_closure17242026/11/11 22:23:19 INFO Received uploads request method=POST path=/17252026/11/11 22:23:19 INFO Uploading 1 narinfos17262026/11/11 22:23:19 WARN Failed to register uploaded object key=nar/13p9pqi0ga6fx2apcwls9hjnv7nmf740ggpn5zvfzdsp5vz2bbg4.nar.zst error="server returned 404: 404 page not found\n"17272026/11/11 22:23:19 WARN Failed to register uploaded object key=jybrl73q6wwmribmkzps4cqgvnw1ihr6.ls error="server returned 404: 404 page not found\n"17282026/11/11 22:23:19 WARN Failed to register uploaded object key=wig7b9qa8a7hsj0camygnld8l6sxf8zw.ls error="server returned 404: 404 page not found\n"17292026/11/11 22:23:19 WARN Failed to register uploaded object key=nar/1823g6vx4q5zqvr73m7lkq1wpk40fin7bsc792di430yk7sg4lka.nar.zst error="server returned 404: 404 page not found\n"17302026/11/11 22:23:19 INFO lead: acquired remote=192.0.2.1:1234 generation=217312026/11/11 22:23:19 WARN Failed to register uploaded object key=nar/0ahq3izw3h0b0c08p3xdfclh758fwxnp85ccvflasb4vnfsv50ri.nar.zst error="server returned 404: 404 page not found\n"17322026/11/11 22:23:19 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign17332026/11/11 22:23:19 WARN Failed to register uploaded object key=pk7jshchxdxlwf0cmsg6d77a5dik4vcw.ls error="server returned 404: 404 page not found\n"17342026/11/11 22:23:19 INFO Signed narinfos id=1 count=317352026/11/11 22:23:19 INFO Uploading 3 narinfos17362026/11/11 22:23:19 INFO Received complete push request method=POST path=/api/pushes/1/complete17372026/11/11 22:23:19 WARN Failed to register uploaded object key=c63m8zzvmdzxnq7mlqlmpyfhjgzj0x70.narinfo error="server returned 404: 404 page not found\n"17382026/11/11 22:23:19 WARN Failed to register uploaded object key=pk7jshchxdxlwf0cmsg6d77a5dik4vcw.narinfo error="server returned 404: 404 page not found\n"17392026/11/11 22:23:19 WARN Failed to register uploaded object key=wig7b9qa8a7hsj0camygnld8l6sxf8zw.narinfo error="server returned 404: 404 page not found\n"17402026/11/11 22:23:19 INFO Received complete push request method=POST path=/api/pushes/1/complete17412026/11/11 22:23:19 WARN Failed to register uploaded object key=jybrl73q6wwmribmkzps4cqgvnw1ihr6.narinfo error="server returned 404: 404 page not found\n"17422026/11/11 22:23:19 INFO Completed push id=1 objects=3 duration=65.655083ms17432026/11/11 22:23:19 INFO Upload complete. (414ms)1744=== RUN TestService_RequireScope_OIDC/builder_may_write1745=== PAUSE TestService_RequireScope_OIDC/builder_may_write1746=== RUN TestService_RequireScope_OIDC/builder_may_not_admin1747=== PAUSE TestService_RequireScope_OIDC/builder_may_not_admin1748=== RUN TestService_RequireScope_OIDC/ops_may_admin1749=== PAUSE TestService_RequireScope_OIDC/ops_may_admin1750=== RUN TestService_RequireScope_OIDC/ops_may_not_write1751=== PAUSE TestService_RequireScope_OIDC/ops_may_not_write1752=== RUN TestService_RequireScope_OIDC/reader_may_not_write1753=== PAUSE TestService_RequireScope_OIDC/reader_may_not_write1754=== RUN TestService_RequireScope_OIDC/static_token_may_admin1755=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin1756=== RUN TestService_RequireScope_OIDC/static_token_may_write1757=== PAUSE TestService_RequireScope_OIDC/static_token_may_write1758=== RUN TestService_RequireScope_OIDC/reader_may_read1759=== PAUSE TestService_RequireScope_OIDC/reader_may_read1760=== RUN TestService_RequireScope_OIDC/writer_implies_read1761=== PAUSE TestService_RequireScope_OIDC/writer_implies_read1762=== RUN TestService_RequireScope_OIDC/anonymous_may_not_read1763=== PAUSE TestService_RequireScope_OIDC/anonymous_may_not_read1764=== RUN TestService_RequireScope_OIDC/reader_may_read_with_netrc1765=== PAUSE TestService_RequireScope_OIDC/reader_may_read_with_netrc1766=== RUN TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1767=== PAUSE TestService_RequireScope_OIDC/static_token_may_admin_with_netrc1768=== RUN TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1769=== PAUSE TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read1770=== RUN TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1771=== PAUSE TestService_RequireScope_OIDC/empty_netrc_password_may_not_read1772=== CONT TestUploadHandlersRejectOversizedBody/request_more_parts17732026/11/11 22:23:19 INFO Received request for more parts method=POST path=/17742026/11/11 22:23:19 INFO Completed push id=1 objects=9 duration=36.115959ms17752026/11/11 22:23:19 INFO All 1 paths already cached17762026/11/11 22:23:19 INFO Upload complete. (453ms)1777=== NAME TestClientMultipleUploads1778 client_integration_test.go:416: Uploaded 3 paths in 493.797083ms1779=== NAME TestClientIntegration1780 client_integration_test.go:317: Retrieved narinfo from S3:1781 StorePath: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientIntegration2773348901/002/store/c63m8zzvmdzxnq7mlqlmpyfhjgzj0x70-test-file.txt1782 URL: nar/11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk1.nar.zst1783 Compression: zstd1784 NarHash: sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11785 NarSize: 1521786 References: 1787 CA: fixed:r:sha256:11l1b7hsy9g9pz8i2rcn4n128l6pyr2yf58d49r12hr5caw9dzk11788=== CONT TestPush_RejectsBadRequests/no_roots17892026/11/11 22:23:19 INFO Received push request method=POST path=/api/pushes1790=== NAME TestClientIntegration1791 client_integration_test.go:318: Retrieved .ls file from S3 (compressed size: 77 bytes)1792=== CONT TestPush_RejectsBadRequests/bad_root1793=== NAME TestClientIntegration17942026/11/11 22:23:19 INFO Received push request method=POST path=/api/pushes1795 client_integration_test.go:318: Decompressed .ls content (64 bytes):1796 {"version":1,"root":{"type":"regular","size":39,"narOffset":96}}1797=== CONT TestPush_RejectsBadRequests/root_not_in_objects17982026/11/11 22:23:19 INFO Received push request method=POST path=/api/pushes1799=== CONT TestPush_RejectsBadRequests/no_objects18002026/11/11 22:23:19 INFO Received push request method=POST path=/api/pushes1801=== CONT TestIsValidCachePath/narinfo1802=== CONT TestIsValidCachePath/index.html1803--- PASS: TestPush_RejectsBadRequests (1.14s)1804 --- PASS: TestPush_RejectsBadRequests/no_roots (0.01s)1805 --- PASS: TestPush_RejectsBadRequests/bad_root (0.00s)1806 --- PASS: TestPush_RejectsBadRequests/root_not_in_objects (0.00s)1807 --- PASS: TestPush_RejectsBadRequests/no_objects (0.00s)1808=== CONT TestIsValidCachePath/short_hash1809=== CONT TestIsValidCachePath/wrong_extension1810=== CONT TestIsValidCachePath/leading_slash1811=== CONT TestIsValidCachePath/empty1812=== CONT TestIsValidCachePath/random_path1813=== CONT TestIsValidCachePath/invalid_char_u1814=== CONT TestIsValidCachePath/invalid_char_e1815=== CONT TestIsValidCachePath/traversal_in_middle1816=== CONT TestIsValidCachePath/traversal_parent1817=== CONT TestIsValidCachePath/nar_uncompressed1818=== CONT TestIsValidCachePath/nix-cache-info1819=== CONT TestIsValidCachePath/realisation1820=== CONT TestIsValidCachePath/log1821=== CONT TestIsValidCachePath/ls1822=== CONT TestIsValidCachePath/nar_xz1823=== CONT TestIsValidCachePath/nar_bz21824=== CONT TestIsValidCachePath/nar_zst1825=== CONT TestIsValidCachePath/narinfo_all_nix_base32_chars1826--- PASS: TestIsValidCachePath (0.00s)1827 --- PASS: TestIsValidCachePath/narinfo (0.00s)1828 --- PASS: TestIsValidCachePath/index.html (0.00s)1829 --- PASS: TestIsValidCachePath/short_hash (0.00s)1830 --- PASS: TestIsValidCachePath/wrong_extension (0.00s)1831 --- PASS: TestIsValidCachePath/leading_slash (0.00s)1832 --- PASS: TestIsValidCachePath/empty (0.00s)1833 --- PASS: TestIsValidCachePath/random_path (0.00s)1834 --- PASS: TestIsValidCachePath/invalid_char_u (0.00s)1835 --- PASS: TestIsValidCachePath/invalid_char_e (0.00s)1836 --- PASS: TestIsValidCachePath/traversal_in_middle (0.00s)1837 --- PASS: TestIsValidCachePath/traversal_parent (0.00s)1838 --- PASS: TestIsValidCachePath/nar_uncompressed (0.00s)1839 --- PASS: TestIsValidCachePath/nix-cache-info (0.00s)1840 --- PASS: TestIsValidCachePath/realisation (0.00s)1841 --- PASS: TestIsValidCachePath/log (0.00s)1842 --- PASS: TestIsValidCachePath/ls (0.00s)1843 --- PASS: TestIsValidCachePath/nar_xz (0.00s)1844 --- PASS: TestIsValidCachePath/nar_bz2 (0.00s)1845 --- PASS: TestIsValidCachePath/nar_zst (0.00s)1846 --- PASS: TestIsValidCachePath/narinfo_all_nix_base32_chars (0.00s)1847=== CONT TestParseSingleRange/none1848=== CONT TestParseSingleRange/open-ended1849=== CONT TestParseSingleRange/start_far_past_EOF1850=== CONT TestParseSingleRange/start_past_EOF1851=== CONT TestParseSingleRange/single_byte1852=== CONT TestParseSingleRange/suffix_exceeds_size1853=== CONT TestParseSingleRange/suffix1854=== CONT TestParseSingleRange/end_clamped_to_size1855=== CONT TestParseSingleRange/malformed_both_empty1856=== CONT TestParseSingleRange/closed1857=== CONT TestParseSingleRange/malformed_end_before_start1858=== CONT TestParseSingleRange/multi-range_ignored1859=== CONT TestParseSingleRange/malformed_no_dash1860=== CONT TestParseSingleRange/unknown_unit1861--- PASS: TestParseSingleRange (0.00s)1862 --- PASS: TestParseSingleRange/none (0.00s)1863 --- PASS: TestParseSingleRange/open-ended (0.00s)1864 --- PASS: TestParseSingleRange/start_far_past_EOF (0.00s)1865 --- PASS: TestParseSingleRange/start_past_EOF (0.00s)1866 --- PASS: TestParseSingleRange/single_byte (0.00s)1867 --- PASS: TestParseSingleRange/suffix_exceeds_size (0.00s)1868 --- PASS: TestParseSingleRange/suffix (0.00s)1869 --- PASS: TestParseSingleRange/end_clamped_to_size (0.00s)1870 --- PASS: TestParseSingleRange/malformed_both_empty (0.00s)1871 --- PASS: TestParseSingleRange/closed (0.00s)1872 --- PASS: TestParseSingleRange/malformed_end_before_start (0.00s)1873 --- PASS: TestParseSingleRange/multi-range_ignored (0.00s)1874 --- PASS: TestParseSingleRange/malformed_no_dash (0.00s)1875 --- PASS: TestParseSingleRange/unknown_unit (0.00s)1876=== CONT TestPresentNotReportedWhileGCDeletesClosure/stale1877--- PASS: TestUploadHandlersRejectOversizedBody (0.07s)1878 --- PASS: TestUploadHandlersRejectOversizedBody/complete_multipart (0.03s)1879 --- PASS: TestUploadHandlersRejectOversizedBody/request_more_parts (0.02s)1880 --- PASS: TestUploadHandlersRejectOversizedBody/create_pending_closure (0.28s)1881=== CONT TestPresentNotReportedWhileGCDeletesClosure/fresh1882--- PASS: TestClientMultipleUploads (7.92s)1883=== CONT TestServerTLSConfig/no_client_CA1884=== CONT TestProxyWriteTimeout/narinfo1885=== CONT TestServerTLSConfig/not_a_PEM_file1886=== CONT TestServerTLSConfig/missing_CA_file1887--- PASS: TestServerTLSConfig (0.00s)1888 --- PASS: TestServerTLSConfig/no_client_CA (0.00s)1889 --- PASS: TestServerTLSConfig/not_a_PEM_file (0.03s)1890 --- PASS: TestServerTLSConfig/missing_CA_file (0.00s)1891=== CONT TestProxyWriteTimeout/10_GiB_nar1892=== CONT TestProxyWriteTimeout/unknown_size1893=== CONT TestProxyWriteTimeout/1_GiB_nar1894--- PASS: TestProxyWriteTimeout (0.00s)1895 --- PASS: TestProxyWriteTimeout/narinfo (0.00s)1896 --- PASS: TestProxyWriteTimeout/10_GiB_nar (0.00s)1897 --- PASS: TestProxyWriteTimeout/unknown_size (0.00s)1898 --- PASS: TestProxyWriteTimeout/1_GiB_nar (0.00s)1899=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info19002026/11/11 22:23:19 INFO Received uploads request method=POST path=/1901=== CONT TestIsValidUploadKey/narinfo1902=== CONT TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key19032026/11/11 22:23:19 INFO Received request for more parts method=POST path=/1904=== CONT TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key19052026/11/11 22:23:19 INFO Received complete multipart upload request method=POST path=/1906=== CONT TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal19072026/11/11 22:23:19 INFO Received uploads request method=POST path=/1908--- PASS: TestUploadHandlersRejectInvalidKeys (0.00s)1909 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_nix-cache-info (0.00s)1910 --- PASS: TestUploadHandlersRejectInvalidKeys/request_more_parts_rejects_non-NAR_key (0.00s)1911 --- PASS: TestUploadHandlersRejectInvalidKeys/complete_multipart_rejects_non-NAR_key (0.00s)1912 --- PASS: TestUploadHandlersRejectInvalidKeys/create_pending_closure_rejects_path_traversal (0.00s)1913=== CONT TestPendingClosureWriteTimeout/empty1914=== CONT TestIsValidUploadKey/unknown_type1915=== CONT TestIsValidUploadKey/empty_key1916=== CONT TestIsValidUploadKey/absolute1917=== CONT TestIsValidUploadKey/traversal_nar1918=== CONT TestIsValidUploadKey/traversal1919=== CONT TestIsValidUploadKey/listing_key,_narinfo_type1920=== CONT TestIsValidUploadKey/nar_key,_narinfo_type1921=== CONT TestIsValidUploadKey/narinfo_key,_nar_type1922=== CONT TestIsValidUploadKey/index.html1923=== CONT TestIsValidUploadKey/nix-cache-info1924=== CONT TestIsValidUploadKey/realisation_plus_in_output1925=== CONT TestIsValidUploadKey/realisation1926=== CONT TestIsValidUploadKey/build_log_equals1927=== CONT TestIsValidUploadKey/build_log_question_mark1928=== CONT TestIsValidUploadKey/build_log_plus_in_name1929=== CONT TestIsValidUploadKey/build_log_home-manager_file1930=== CONT TestIsValidUploadKey/build_log1931=== CONT TestIsValidUploadKey/listing1932=== CONT TestIsValidUploadKey/nar_plain1933=== CONT TestIsValidUploadKey/nar_xz1934=== CONT TestIsValidUploadKey/nar_zst1935--- PASS: TestIsValidUploadKey (0.00s)1936 --- PASS: TestIsValidUploadKey/narinfo (0.00s)1937 --- PASS: TestIsValidUploadKey/unknown_type (0.00s)1938 --- PASS: TestIsValidUploadKey/empty_key (0.00s)1939 --- PASS: TestIsValidUploadKey/absolute (0.00s)1940 --- PASS: TestIsValidUploadKey/traversal_nar (0.00s)1941 --- PASS: TestIsValidUploadKey/traversal (0.00s)1942 --- PASS: TestIsValidUploadKey/listing_key,_narinfo_type (0.00s)1943 --- PASS: TestIsValidUploadKey/nar_key,_narinfo_type (0.00s)1944 --- PASS: TestIsValidUploadKey/narinfo_key,_nar_type (0.00s)1945 --- PASS: TestIsValidUploadKey/index.html (0.00s)1946 --- PASS: TestIsValidUploadKey/nix-cache-info (0.00s)1947 --- PASS: TestIsValidUploadKey/realisation_plus_in_output (0.00s)1948 --- PASS: TestIsValidUploadKey/realisation (0.00s)1949 --- PASS: TestIsValidUploadKey/build_log_equals (0.00s)1950 --- PASS: TestIsValidUploadKey/build_log_question_mark (0.00s)1951 --- PASS: TestIsValidUploadKey/build_log_plus_in_name (0.00s)1952 --- PASS: TestIsValidUploadKey/build_log_home-manager_file (0.00s)1953 --- PASS: TestIsValidUploadKey/build_log (0.00s)1954 --- PASS: TestIsValidUploadKey/listing (0.00s)1955 --- PASS: TestIsValidUploadKey/nar_plain (0.00s)1956 --- PASS: TestIsValidUploadKey/nar_xz (0.00s)1957 --- PASS: TestIsValidUploadKey/nar_zst (0.00s)1958=== CONT TestPendingClosureWriteTimeout/670k_objects1959=== CONT TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline1960=== NAME TestClientCADerivations1961 client_ca_test.go:136: Built CA derivation: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientCADerivations947937895/001/store/9svlm5wwhy6zfr8hkx7pld6wbrf3vmca-ca-test19622026/11/11 22:23:19 INFO Received push request method=POST path=/api/pushes19632026/11/11 22:23:19 INFO Object in database but missing from S3 key=c63m8zzvmdzxnq7mlqlmpyfhjgzj0x70.ls19642026/11/11 22:23:19 WARN Found objects in DB but missing from S3, will re-upload count=119652026/11/11 22:23:19 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)1966 client_ca_test.go:139: Found 1 dependencies (including self)1967--- PASS: TestCacheStatsHandler (6.31s)1968=== CONT TestPendingClosureWriteTimeout/400_objects1969=== CONT TestClientErrorHandling/InvalidStorePath19702026/11/11 22:23:19 INFO Received complete push request method=POST path=/api/pushes/2/complete19712026/11/11 22:23:19 WARN Failed to register uploaded object key=c63m8zzvmdzxnq7mlqlmpyfhjgzj0x70.ls error="server returned 404: 404 page not found\n"19722026/11/11 22:23:19 INFO Completed push id=2 objects=3 duration=1.032167ms19732026/11/11 22:23:19 INFO Upload complete. (144ms)1974=== NAME TestClientIntegration1975 client_integration_test.go:335: Retrieved .ls file from S3 (compressed size: 62 bytes)1976 client_integration_test.go:335: Decompressed .ls content (49 bytes):1977 {"version":1,"root":{"type":"regular","size":39}}19782026/11/11 22:23:19 INFO Received push request method=POST path=/api/pushes19792026/11/11 22:23:19 INFO Uploading 1 paths to 127.0.0.1 (0 already cached)19802026/11/11 22:23:19 INFO Uploading 9svlm5wwhy6zfr8hkx7pld6wbrf3vmca-ca-test (144B)19812026/11/11 22:23:19 WARN Failed to register uploaded object key=nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst error="server returned 404: 404 page not found\n"19822026/11/11 22:23:19 WARN Failed to register uploaded object key=9svlm5wwhy6zfr8hkx7pld6wbrf3vmca.ls error="server returned 404: 404 page not found\n"19832026/11/11 22:23:19 WARN Failed to register uploaded object key=log/3scgq5xw6vvv0d2k4g7jzdbz6q1vpg5f-ca-test.drv error="server returned 404: 404 page not found\n"19842026/11/11 22:23:20 INFO Received sign narinfos request method=POST path=/api/pushes/1/sign19852026/11/11 22:23:20 INFO Signed narinfos id=1 count=119862026/11/11 22:23:20 INFO Uploading 1 narinfos1987--- PASS: TestService_ReadAuthMiddleware (6.41s)1988=== CONT TestClientErrorHandling/ServerNotAvailable19892026/11/11 22:23:20 INFO Received complete push request method=POST path=/api/pushes/1/complete19902026/11/11 22:23:20 WARN Failed to register uploaded object key=9svlm5wwhy6zfr8hkx7pld6wbrf3vmca.narinfo error="server returned 404: 404 page not found\n"19912026/11/11 22:23:20 INFO Completed push id=1 objects=4 duration=31.834459ms19922026/11/11 22:23:20 INFO Upload complete. (399ms)1993=== NAME TestClientCADerivations1994 client_ca_test.go:180: Narinfo contains CA field: StorePath: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientCADerivations947937895/001/store/9svlm5wwhy6zfr8hkx7pld6wbrf3vmca-ca-test1995 URL: nar/04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n.nar.zst1996 Compression: zstd1997 NarHash: sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n1998 NarSize: 1441999 References: 2000 Deriver: /private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientCADerivations947937895/001/store/3scgq5xw6vvv0d2k4g7jzdbz6q1vpg5f-ca-test.drv2001 CA: fixed:r:sha256:04jj7iiy79vhzp5kk3r2751n9x3xa44j98y5bk1ds4jp31kky74n2002 client_ca_test.go:185: Checking for realisation files in S3...2003 client_ca_test.go:207: No realisation files uploaded - this is expected for locally built CA derivations2004 client_ca_test.go:208: Locally built CA derivations don't have DrvOutput IDs until they're substituted from a cache20052026/11/11 22:23:20 INFO Received push request method=POST path=/api/pushes20062026/11/11 22:23:20 INFO Uploading 0 paths to 127.0.0.1 (1 already cached)2007=== NAME TestPinProtectsFromGC2008 client_integration_test.go:887: Pin successfully protected closure from garbage collection20092026/11/11 22:23:20 INFO Received complete push request method=POST path=/api/pushes/3/complete20102026/11/11 22:23:20 WARN Failed to register uploaded object key=c63m8zzvmdzxnq7mlqlmpyfhjgzj0x70.ls error="server returned 404: 404 page not found\n"20112026/11/11 22:23:20 INFO Completed push id=3 objects=3 duration=676.792µs20122026/11/11 22:23:20 INFO Upload complete. (127ms)2013=== NAME TestClientIntegration2014 client_integration_test.go:352: Retrieved .ls file from S3 (compressed size: 62 bytes)2015 client_integration_test.go:352: Decompressed .ls content (49 bytes):2016 {"version":1,"root":{"type":"regular","size":39}}2017 client_integration_test.go:363: Testing garbage collection...20182026/11/11 22:23:20 INFO Starting cleanup of old closures method=DELETE path=/api/closures20192026/11/11 22:23:20 INFO Garbage collection started2020=== NAME TestClientCADerivations20212026/11/11 22:23:20 INFO lead: released remote=192.0.2.1:1234 generation=22022 client_ca_test.go:258: nix copy output: error: binary cache 's3://bucket85?endpoint=http://localhost:54501®ion=eu-west-1' is for Nix stores with prefix '/nix/store', not '/private/var/tb/3/scratch/ba280157b5421d9f/build/TestClientCADerivations947937895/001/store'2023 client_ca_test.go:259: nix copy failed (might be expected with isolated stores): exit status 12024--- PASS: TestLeadElectsOneAndHandsOver (8.99s)2025=== CONT TestClientErrorHandling/InvalidAuthToken20262026/11/11 22:23:20 INFO Aborted multipart uploads count=0 kept=020272026/11/11 22:23:20 WARN Force mode enabled - objects will be deleted immediately without grace period2028--- PASS: TestPinProtectsFromGC (11.33s)2029=== CONT TestForceGCDuringPushOffersSweptObject/before_pending_rows20302026/11/11 22:23:20 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20312026/11/11 22:23:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted,O=Other"20322026/11/11 22:23:20 WARN mTLS auth: bound subjects configured but subject DN unavailable20332026/11/11 22:23:20 WARN mTLS auth: subject not in bound subjects subject="CN=untrusted"2034--- PASS: TestService_AuthMiddleware_MTLSBoundSubjects (6.82s)2035=== CONT TestForceGCDuringPushOffersSweptObject/after_presence_check2036--- PASS: TestClientCADerivations (7.08s)2037=== CONT TestResolveDBConnectionString/flag_wins2038=== CONT TestResolveDBConnectionString/PGHOST_allows_empty2039=== CONT TestResolveDBConnectionString/nothing_configured2040=== CONT TestResolveDBConnectionString/missing_file_is_an_error2041=== CONT TestResolveDBConnectionString/file_when_flag_empty2042=== CONT TestCacheConfigHandler/full_config,_no_issuer2043=== CONT TestCacheConfigHandler/no_signing_keys2044=== CONT TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator2045=== CONT TestCacheConfigHandler/no_cache_url_configured2046--- PASS: TestCacheConfigHandler (0.00s)2047 --- PASS: TestCacheConfigHandler/full_config,_no_issuer (0.00s)2048 --- PASS: TestCacheConfigHandler/no_signing_keys (0.00s)2049 --- PASS: TestCacheConfigHandler/issuer_requested_but_no_OIDC_validator (0.00s)2050 --- PASS: TestCacheConfigHandler/no_cache_url_configured (0.00s)2051=== CONT TestService_RequireScope_OIDC/builder_may_write2052--- PASS: TestResolveDBConnectionString (0.02s)2053 --- PASS: TestResolveDBConnectionString/flag_wins (0.00s)2054 --- PASS: TestResolveDBConnectionString/PGHOST_allows_empty (0.00s)2055 --- PASS: TestResolveDBConnectionString/nothing_configured (0.00s)2056 --- PASS: TestResolveDBConnectionString/missing_file_is_an_error (0.00s)2057 --- PASS: TestResolveDBConnectionString/file_when_flag_empty (0.00s)2058=== CONT TestService_RequireScope_OIDC/reader_may_read2059=== CONT TestService_RequireScope_OIDC/empty_netrc_password_may_not_read2060=== CONT TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read20612026/11/11 22:23:20 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]2062=== CONT TestService_RequireScope_OIDC/static_token_may_admin_with_netrc20632026/11/11 22:23:20 WARN Request failed, retrying attempt=2 backoff=206.395755ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2064=== CONT TestService_RequireScope_OIDC/reader_may_read_with_netrc2065=== CONT TestService_RequireScope_OIDC/anonymous_may_not_read2066=== CONT TestService_RequireScope_OIDC/writer_implies_read2067=== CONT TestService_RequireScope_OIDC/reader_may_not_write2068=== CONT TestService_RequireScope_OIDC/static_token_may_write2069=== CONT TestService_RequireScope_OIDC/static_token_may_admin2070=== CONT TestService_RequireScope_OIDC/ops_may_admin2071=== CONT TestService_RequireScope_OIDC/ops_may_not_write2072=== CONT TestService_RequireScope_OIDC/builder_may_not_admin2073--- PASS: TestService_RequireScope_OIDC (6.01s)2074 --- PASS: TestService_RequireScope_OIDC/builder_may_write (0.00s)2075 --- PASS: TestService_RequireScope_OIDC/reader_may_read (0.00s)2076 --- PASS: TestService_RequireScope_OIDC/empty_netrc_password_may_not_read (0.00s)2077 --- PASS: TestService_RequireScope_OIDC/wrong_netrc_password_may_not_read (0.00s)2078 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin_with_netrc (0.00s)2079 --- PASS: TestService_RequireScope_OIDC/reader_may_read_with_netrc (0.00s)2080 --- PASS: TestService_RequireScope_OIDC/anonymous_may_not_read (0.00s)2081 --- PASS: TestService_RequireScope_OIDC/writer_implies_read (0.00s)2082 --- PASS: TestService_RequireScope_OIDC/reader_may_not_write (0.00s)2083 --- PASS: TestService_RequireScope_OIDC/static_token_may_write (0.00s)2084 --- PASS: TestService_RequireScope_OIDC/static_token_may_admin (0.00s)2085 --- PASS: TestService_RequireScope_OIDC/ops_may_admin (0.00s)2086 --- PASS: TestService_RequireScope_OIDC/ops_may_not_write (0.00s)2087 --- PASS: TestService_RequireScope_OIDC/builder_may_not_admin (0.00s)20882026/11/11 22:23:20 INFO lead: released remote=192.0.2.1:1234 generation=32089--- PASS: TestLeadUnannouncedStandbyYieldsToIncumbent (9.43s)20902026/11/11 22:23:20 WARN Request failed, retrying attempt=3 backoff=433.58704ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present20912026/11/11 22:23:20 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=020922026/11/11 22:23:20 INFO Vacuumed table table=pending_closures2093=== RUN TestService_AuthMiddleware_OIDC/valid_OIDC_token2094=== PAUSE TestService_AuthMiddleware_OIDC/valid_OIDC_token2095=== RUN TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2096=== PAUSE TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2097=== RUN TestService_AuthMiddleware_OIDC/malformed_token_rejected2098=== PAUSE TestService_AuthMiddleware_OIDC/malformed_token_rejected2099=== RUN TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2100=== PAUSE TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured2101=== CONT TestService_AuthMiddleware_OIDC/valid_OIDC_token2102=== CONT TestService_AuthMiddleware_OIDC/malformed_token_rejected21032026/11/11 22:23:20 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]2104=== CONT TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected2105=== CONT TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured21062026/11/11 22:23:20 WARN Authentication failed token_preview=eyJhbGciOi...zuxhQYOWmg token_length=701 oidc_error="no rule matched: claim \"repository_owner\" value [otherorg] not in allowed patterns [myorg]" oidc_provider=test tried_providers=[test]2107--- PASS: TestService_AuthMiddleware_OIDC (7.24s)2108 --- PASS: TestService_AuthMiddleware_OIDC/malformed_token_rejected (0.00s)2109 --- PASS: TestService_AuthMiddleware_OIDC/valid_OIDC_token (0.01s)2110 --- PASS: TestService_AuthMiddleware_OIDC/static_token_still_works_with_OIDC_configured (0.00s)2111 --- PASS: TestService_AuthMiddleware_OIDC/OIDC_token_with_wrong_org_rejected (0.01s)21122026/11/11 22:23:20 INFO Vacuumed table table=pending_objects21132026/11/11 22:23:20 INFO Vacuumed table table=multipart_uploads21142026/11/11 22:23:20 INFO Vacuumed table table=closures21152026/11/11 22:23:20 INFO Vacuumed table table=objects21162026/11/11 22:23:21 WARN Request failed, retrying attempt=4 backoff=835.414581ms error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present2117--- PASS: TestService_AuthMiddleware_MTLSProxyHeader (7.09s)21182026/11/11 22:23:21 WARN Authentication failed token_preview=wrongtoken token_length=10 reason="static API token mismatch"2119--- PASS: TestService_AuthMiddleware (7.25s)21202026/11/11 22:23:21 WARN Request failed, retrying attempt=5 backoff=1.685886374s error="Post \"http://localhost:19999/api/objects/present\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/objects/present21212026-11-11 22:23:21.988 UTC [57515] LOG: checkpoint starting: wal2122--- PASS: TestService_ReadScope_PublicByDefault (7.78s)21232026/11/11 22:23:22 INFO Garbage collection progress phase="" failed_uploads_deleted=0 old_closures_deleted=1 objects_marked=3 objects_deleted=3 objects_failed=02124=== NAME TestClientIntegration2125 client_integration_test.go:370: Objects in database after GC:2126 client_integration_test.go:370: Successfully deleted all objects with GC --force2127--- PASS: TestClientIntegration (9.44s)21282026/11/11 22:23:22 INFO Aborted multipart uploads count=0 kept=021292026/11/11 22:23:22 WARN Force mode enabled - objects will be deleted immediately without grace period21302026-11-11 22:23:22.888 UTC [58027] ERROR: canceling statement due to user request21312026-11-11 22:23:22.888 UTC [58027] STATEMENT: -- name: MarkStaleObjects :execrows2132 WITH RECURSIVE ct AS (2133 SELECT timezone('UTC', now()) AS now2134 ),2135 closure_reach AS (2136 -- Start with all closure keys2137 SELECT o.key, o.refs2138 FROM objects o2139 INNER JOIN closures c ON o.key = c.key2140 UNION2141 -- Recursively add all referenced objects2142 SELECT o.key, o.refs2143 FROM objects o2144 INNER JOIN closure_reach cr ON o.key = ANY(cr.refs)2145 ),2146 reachable_objects AS (2147 SELECT DISTINCT key FROM closure_reach2148 ),2149 stale_objects AS (2150 SELECT o.key2151 FROM objects AS o, ct2152 WHERE2153 NOT EXISTS (2154 SELECT 12155 FROM reachable_objects ro2156 WHERE ro.key = o.key2157 )2158 AND NOT EXISTS (2159 SELECT 12160 FROM pending_objects AS po2161 WHERE po.key = o.key2162 )2163 AND o.deleted_at IS NULL -- Only mark fresh objects2164 ORDER BY o.key COLLATE "C" -- lock in key order, like commit_pending_closure2165 FOR UPDATE2166 )2167 UPDATE objects2168 SET2169 deleted_at = ct.now,2170 first_deleted_at = COALESCE(first_deleted_at, ct.now)2171 FROM stale_objects, ct2172 WHERE objects.key = stale_objects.key2173 21742026/11/11 22:23:23 INFO Aborted multipart uploads count=0 kept=021752026/11/11 22:23:23 WARN Force mode enabled - objects will be deleted immediately without grace period21762026/11/11 22:23:23 ERROR failed to remove object object=nar/aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa.nar.zst error="Post \"http://localhost:54501/bucket96/?delete=\": context canceled"2177--- PASS: TestGCEndsOnShutdown (0.00s)2178 --- PASS: TestGCEndsOnShutdown/before_the_run (7.43s)2179 --- PASS: TestGCEndsOnShutdown/blocked_on_a_row_lock_in_the_mark (7.49s)2180 --- PASS: TestGCEndsOnShutdown/blocked_in_the_sweep's_S3_delete (7.73s)21812026/11/11 22:23:23 INFO Received uploads request method=POST path=/api/pending_closures21822026/11/11 22:23:23 INFO Received uploads request method=POST path=/api/pending_closures21832026/11/11 22:23:23 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21842026/11/11 22:23:23 WARN Request failed, retrying attempt=2 backoff=187.080655ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21852026/11/11 22:23:24 INFO Received uploads request method=POST path=/api/pending_closures21862026/11/11 22:23:24 WARN Request failed, retrying attempt=3 backoff=419.64002ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21872026/11/11 22:23:24 INFO Received uploads request method=POST path=/api/pending_closures21882026/11/11 22:23:24 WARN Request failed, retrying attempt=4 backoff=826.361829ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21892026/11/11 22:23:24 INFO Received uploads request method=POST path=/api/pending_closures21902026/11/11 22:23:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21912026/11/11 22:23:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst upload_id=MWJkMzIxMDEtNmFiMy00YzM5LTkwMzQtOTJkOWUyMjEzODlhLjEwN2Q2NTcwLThhODktNDY1ZC04Nzg5LThhMzFkNDkyNGY4ZXgxNzk0NDM1ODAzNDEzOTQ1MDAw parts=1021922026/11/11 22:23:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21932026/11/11 22:23:25 INFO Completed upload id=1 objects=3 duration=20.714458ms21942026/11/11 22:23:25 WARN Request failed, retrying attempt=5 backoff=1.58332676s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config21952026/11/11 22:23:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete21962026/11/11 22:23:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst upload_id=MWJkMzIxMDEtNmFiMy00YzM5LTkwMzQtOTJkOWUyMjEzODlhLmE4MGEzMzk3LTNlMjUtNDUzYS1hMWNhLTUxYmU0ZjA2YWFhZHgxNzk0NDM1ODAzNzIxMzU4MDAw parts=1021972026/11/11 22:23:25 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete21982026/11/11 22:23:25 INFO Completed upload id=1 objects=3 duration=13.778042ms21992026/11/11 22:23:25 INFO Received uploads request method=POST path=/api/pending_closures22002026/11/11 22:23:25 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000100000000000000000000.nar.zst22012026/11/11 22:23:25 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0001.narinfo22022026/11/11 22:23:25 INFO Received uploads request method=POST path=/api/pending_closures22032026/11/11 22:23:25 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22042026/11/11 22:23:25 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst upload_id=MWJkMzIxMDEtNmFiMy00YzM5LTkwMzQtOTJkOWUyMjEzODlhLmIyNmM4YzVlLWZjMjktNGViMC04YjViLThlMDU5OThiNzg1MHgxNzk0NDM1ODA0MDMyMzkyMDAw parts=1022052026/11/11 22:23:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete2206--- PASS: TestPresentNotReportedWhileGCDeletesClosure (0.00s)2207 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/stale (6.26s)2208 --- PASS: TestPresentNotReportedWhileGCDeletesClosure/fresh (6.61s)22092026/11/11 22:23:26 INFO Completed upload id=1 objects=3 duration=12.995416ms22102026/11/11 22:23:26 INFO Received uploads request method=POST path=/api/pending_closures22112026/11/11 22:23:26 INFO Received uploads request method=POST path=/api/pending_closures22122026/11/11 22:23:26 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000500000000000000000000.nar.zst22132026/11/11 22:23:26 WARN Found objects in DB but missing from S3, will re-upload count=122142026/11/11 22:23:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22152026/11/11 22:23:26 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst upload_id=MWJkMzIxMDEtNmFiMy00YzM5LTkwMzQtOTJkOWUyMjEzODlhLjdiYjY1YjI0LTQyMDgtNGQ4MS1iNTU5LTEwYjlkMmFiMWUwZXgxNzk0NDM1ODA0MzMyMDIzMDAw parts=1022162026/11/11 22:23:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22172026/11/11 22:23:26 INFO Completed upload id=1 objects=3 duration=12.394166ms22182026/11/11 22:23:26 INFO Received uploads request method=POST path=/api/pending_closures22192026/11/11 22:23:26 INFO Received complete multipart upload request method=POST path=/api/multipart/complete2220--- PASS: TestPendingClosureWriteTimeout (0.00s)2221 --- PASS: TestPendingClosureWriteTimeout/empty (0.00s)2222 --- PASS: TestPendingClosureWriteTimeout/670k_objects (0.00s)2223 --- PASS: TestPendingClosureWriteTimeout/400_objects (0.00s)2224 --- PASS: TestPendingClosureWriteTimeout/handler_extends_the_server's_deadline (7.15s)22252026/11/11 22:23:26 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f000200000000000000000000.nar.zst upload_id=MWJkMzIxMDEtNmFiMy00YzM5LTkwMzQtOTJkOWUyMjEzODlhLmJhOTA2ZTg3LWJkZmQtNGU0Zi05YjY3LWZiMzFiOTg2OWQwOXgxNzk0NDM1ODA0NzQzMDk5MDAw parts=1022262026/11/11 22:23:26 INFO Received complete upload request method=POST path=/api/pending_closures/1/complete22272026/11/11 22:23:26 INFO Completed upload id=1 objects=3 duration=8.732416ms22282026/11/11 22:23:26 INFO Received uploads request method=POST path=/api/pending_closures22292026/11/11 22:23:26 INFO Received uploads request method=POST path=/api/pending_closures22302026/11/11 22:23:26 WARN Failed to fetch cache config, uploading without size limit error="fetching cache config: sending request: request failed after retries: Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused"22312026/11/11 22:23:26 WARN Request failed, retrying attempt=1 backoff=100ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22322026/11/11 22:23:26 INFO Aborted multipart uploads count=0 kept=022332026/11/11 22:23:26 WARN Force mode enabled - objects will be deleted immediately without grace period22342026/11/11 22:23:26 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22352026/11/11 22:23:26 WARN Authentication failed token_preview=invalid-token token_length=13 reason="static API token mismatch"22362026/11/11 22:23:27 WARN Request failed, retrying attempt=2 backoff=219.000201ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22372026/11/11 22:23:27 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=022382026/11/11 22:23:27 INFO Vacuumed table table=pending_closures22392026/11/11 22:23:27 INFO Vacuumed table table=pending_objects22402026/11/11 22:23:27 INFO Vacuumed table table=multipart_uploads22412026/11/11 22:23:27 INFO Vacuumed table table=closures22422026/11/11 22:23:27 INFO Vacuumed table table=objects22432026/11/11 22:23:27 INFO Received uploads request method=POST path=/api/pending_closures22442026/11/11 22:23:27 WARN Request failed, retrying attempt=3 backoff=404.651026ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22452026/11/11 22:23:27 INFO Aborted multipart uploads count=0 kept=022462026/11/11 22:23:27 WARN Force mode enabled - objects will be deleted immediately without grace period22472026/11/11 22:23:27 INFO Garbage collection completed failed-uploads-deleted=0 old-closures-deleted=0 objects-marked-for-deletion=0 objects-deleted-after-grace-period=0 objects-failed-to-delete=022482026/11/11 22:23:27 INFO Vacuumed table table=pending_closures22492026/11/11 22:23:27 INFO Vacuumed table table=pending_objects22502026/11/11 22:23:27 INFO Vacuumed table table=multipart_uploads22512026/11/11 22:23:27 INFO Vacuumed table table=closures22522026/11/11 22:23:27 INFO Vacuumed table table=objects2253--- PASS: TestForceGCDuringPushOffersSweptObject (0.01s)2254 --- PASS: TestForceGCDuringPushOffersSweptObject/before_pending_rows (6.99s)2255 --- PASS: TestForceGCDuringPushOffersSweptObject/after_presence_check (7.00s)22562026/11/11 22:23:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22572026/11/11 22:23:27 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100300000000000000000000.nar.zst upload_id=MWJkMzIxMDEtNmFiMy00YzM5LTkwMzQtOTJkOWUyMjEzODlhLjkwMjMwMTMxLTA0MDktNGJlZi1iNmQzLTM5MmQ5NDJjM2ZhNngxNzk0NDM1ODA2MDUyNjY3MDAw parts=1022582026/11/11 22:23:27 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22592026/11/11 22:23:27 INFO Completed upload id=2 objects=3 duration=1.360459ms22602026/11/11 22:23:27 WARN Request failed, retrying attempt=4 backoff=835.7262ms error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22612026/11/11 22:23:27 INFO Received complete multipart upload request method=POST path=/api/multipart/complete22622026/11/11 22:23:27 INFO Completed multipart upload object_key=nar/dadb44fdadb44fdadb44fdadb44f100400000000000000000000.nar.zst upload_id=MWJkMzIxMDEtNmFiMy00YzM5LTkwMzQtOTJkOWUyMjEzODlhLjBlZjEyODFhLWEzMDQtNDk2NS1hZDg2LTQyZTc2MWUxZDA0OXgxNzk0NDM1ODA2MzgyMDA3MDAw parts=1022632026/11/11 22:23:27 INFO Received complete upload request method=POST path=/api/pending_closures/2/complete22642026/11/11 22:23:27 INFO Completed upload id=2 objects=3 duration=1.300333ms22652026/11/11 22:23:27 INFO Received uploads request method=POST path=/api/pending_closures22662026/11/11 22:23:27 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000300000000000000000000.nar.zst22672026/11/11 22:23:27 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0003.narinfo22682026/11/11 22:23:28 INFO Received uploads request method=POST path=/api/pending_closures22692026/11/11 22:23:28 INFO Object in database but missing from S3 key=nar/dadb44fdadb44fdadb44fdadb44f000400000000000000000000.nar.zst22702026/11/11 22:23:28 WARN Narinfo references a NAR missing from S3, will re-upload narinfo=dadb44fdadb44fdadb44fdadb44f0004.narinfo2271--- PASS: TestService_verifyS3ReuploadsStaleNarinfo (0.04s)2272 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_other_NAR_pushed (9.26s)2273 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/lost,_same_NAR_pushed (9.41s)2274 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/intact,_other_NAR_pushed (9.24s)2275 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost (10.60s)2276 --- PASS: TestService_verifyS3ReuploadsStaleNarinfo/first_of_two_lost,_second_pushed (10.85s)22772026/11/11 22:23:28 WARN Request failed, retrying attempt=5 backoff=1.693360259s error="Get \"http://localhost:19999/api/cache-config\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/cache-config22782026/11/11 22:23:30 WARN Request failed, retrying attempt=1 backoff=100ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22792026/11/11 22:23:30 WARN Request failed, retrying attempt=2 backoff=194.550999ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22802026/11/11 22:23:30 WARN Request failed, retrying attempt=3 backoff=399.104279ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22812026/11/11 22:23:30 WARN Request failed, retrying attempt=4 backoff=764.612352ms error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures22822026/11/11 22:23:31 WARN Request failed, retrying attempt=5 backoff=1.44632997s error="Post \"http://localhost:19999/api/pending_closures\": dial tcp 127.0.0.1:19999: connect: connection refused" url=http://localhost:19999/api/pending_closures2283--- PASS: TestClientErrorHandling (0.00s)2284 --- PASS: TestClientErrorHandling/InvalidStorePath (6.56s)2285 --- PASS: TestClientErrorHandling/InvalidAuthToken (6.80s)2286 --- PASS: TestClientErrorHandling/ServerNotAvailable (13.33s)2287=== NAME TestOrphanedObjectsGCStressTest2288 orphaned_objects_gc_test.go:503: Stress test completed successfully:2289 orphaned_objects_gc_test.go:504: - Active objects preserved: 202290 orphaned_objects_gc_test.go:505: - Objects deleted: 2102291 orphaned_objects_gc_test.go:506: - Total GC'd: 2102292--- PASS: TestOrphanedObjectsGCStressTest (36.44s)2293PASS2294{"timestamp":"2026-11-11T22:23:36.891082Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:54781","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}2295{"timestamp":"2026-11-11T22:23:36.891225Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:54567","error_kind":"io_error","error":"Cancelled","result":"transport_error","target":"rustfs::server::http","filename":"rustfs/src/server/http.rs","line_number":2561,"threadName":"rustfs-worker","threadId":"ThreadId(9)"}2296{"timestamp":"2026-11-11T22:23:36.891258Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:54841","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)"}2297{"timestamp":"2026-11-11T22:23:36.891306Z","level":"ERROR","message":"HTTP transport failed","event":"http_transport_failed","component":"server","subsystem":"transport","peer_addr":"127.0.0.1:54854","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)"}22982026-11-11 22:23:37.159 UTC [57510] LOG: received smart shutdown request22992026-11-11 22:23:37.160 UTC [57510] LOG: background worker "logical replication launcher" (PID 57520) exited with exit code 123002026-11-11 22:23:39.149 UTC [57515] LOG: checkpoint complete: wrote 10740 buffers (65.6%), wrote 5 SLRU buffers; 0 WAL file(s) added, 0 removed, 33 recycled; write=16.213 s, sync=0.895 s, total=17.161 s; sync files=36842, longest=0.005 s, average=0.001 s; distance=534751 kB, estimate=534751 kB; lsn=0/228AB590, redo lsn=0/221C4E4023012026-11-11 22:23:39.151 UTC [57515] LOG: shutting down23022026-11-11 22:23:39.151 UTC [57515] LOG: checkpoint starting: shutdown immediate23032026-11-11 22:23:39.878 UTC [57515] LOG: checkpoint complete: wrote 1082 buffers (6.6%), wrote 1 SLRU buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.703 s, sync=0.022 s, total=0.728 s; sync files=499, longest=0.001 s, average=0.001 s; distance=7065 kB, estimate=481983 kB; lsn=0/228AB608, redo lsn=0/228AB60823042026-11-11 22:23:39.896 UTC [57510] LOG: database system is shut down2305Running OIDC tests...2306=== RUN TestAudienceForIssuer2307=== PAUSE TestAudienceForIssuer2308=== RUN TestGlobMatch2309=== PAUSE TestGlobMatch2310=== RUN TestValidateToken_ValidToken2311=== PAUSE TestValidateToken_ValidToken2312=== RUN TestValidateToken_WrongAudience2313=== PAUSE TestValidateToken_WrongAudience2314=== RUN TestValidateToken_Expired2315=== PAUSE TestValidateToken_Expired2316=== RUN TestValidateToken_BoundClaimsMismatch2317=== PAUSE TestValidateToken_BoundClaimsMismatch2318=== RUN TestValidateToken_BoundSubjectMismatch2319=== PAUSE TestValidateToken_BoundSubjectMismatch2320=== RUN TestValidateToken_MultipleProviders2321=== PAUSE TestValidateToken_MultipleProviders2322=== RUN TestValidateToken_NoMatchingProvider2323=== PAUSE TestValidateToken_NoMatchingProvider2324=== RUN TestValidateToken_KubernetesServiceAccount2325=== PAUSE TestValidateToken_KubernetesServiceAccount2326=== RUN TestNewValidator_KubernetesRequiresCA2327=== PAUSE TestNewValidator_KubernetesRequiresCA2328=== RUN TestValidateToken_KubernetesIssuerFromOwnToken2329=== PAUSE TestValidateToken_KubernetesIssuerFromOwnToken2330=== RUN TestPins_ReservedForMatchingRule2331=== PAUSE TestPins_ReservedForMatchingRule2332=== RUN TestPins_TopLevelShorthand2333=== PAUSE TestPins_TopLevelShorthand2334=== RUN TestPins_ConfigValidation2335=== PAUSE TestPins_ConfigValidation2336=== RUN TestScopes_LegacyProviderDefaultsToWrite2337=== PAUSE TestScopes_LegacyProviderDefaultsToWrite2338=== RUN TestScopes_Rules2339=== PAUSE TestScopes_Rules2340=== RUN TestScopes_ConfigValidation2341=== PAUSE TestScopes_ConfigValidation2342=== CONT TestAudienceForIssuer2343=== CONT TestPins_ConfigValidation2344=== CONT TestPins_ReservedForMatchingRule2345--- PASS: TestAudienceForIssuer (0.00s)2346=== CONT TestValidateToken_NoMatchingProvider2347=== CONT TestValidateToken_MultipleProviders2348=== CONT TestValidateToken_BoundSubjectMismatch2349=== CONT TestValidateToken_BoundClaimsMismatch2350=== CONT TestValidateToken_Expired2351=== CONT TestValidateToken_WrongAudience2352--- PASS: TestPins_ConfigValidation (0.01s)2353=== CONT TestValidateToken_ValidToken2354=== CONT TestGlobMatch2355=== RUN TestGlobMatch/foo_foo2356=== PAUSE TestGlobMatch/foo_foo2357=== RUN TestGlobMatch/foo_bar2358=== PAUSE TestGlobMatch/foo_bar2359=== RUN TestGlobMatch/*_2360=== PAUSE TestGlobMatch/*_2361=== RUN TestGlobMatch/*_anything2362=== PAUSE TestGlobMatch/*_anything2363=== RUN TestGlobMatch/foo*_foo2364=== PAUSE TestGlobMatch/foo*_foo2365=== RUN TestGlobMatch/foo*_foobar2366=== PAUSE TestGlobMatch/foo*_foobar2367=== RUN TestGlobMatch/foo*_bar2368=== PAUSE TestGlobMatch/foo*_bar2369=== RUN TestGlobMatch/*bar_bar2370=== PAUSE TestGlobMatch/*bar_bar2371=== RUN TestGlobMatch/*bar_foobar2372=== PAUSE TestGlobMatch/*bar_foobar2373=== RUN TestGlobMatch/*bar_foo2374=== CONT TestPins_TopLevelShorthand2375=== CONT TestScopes_Rules2376=== CONT TestScopes_ConfigValidation2377=== CONT TestValidateToken_KubernetesIssuerFromOwnToken2378=== CONT TestScopes_LegacyProviderDefaultsToWrite2379=== CONT TestNewValidator_KubernetesRequiresCA2380=== CONT TestValidateToken_KubernetesServiceAccount2381=== PAUSE TestGlobMatch/*bar_foo2382=== RUN TestGlobMatch/foo*bar_foobar2383=== PAUSE TestGlobMatch/foo*bar_foobar2384=== RUN TestGlobMatch/foo*bar_foo123bar2385=== PAUSE TestGlobMatch/foo*bar_foo123bar2386=== RUN TestGlobMatch/foo*bar_foobarbaz2387=== PAUSE TestGlobMatch/foo*bar_foobarbaz2388=== RUN TestGlobMatch/*/*_foo/bar2389=== PAUSE TestGlobMatch/*/*_foo/bar2390=== RUN TestGlobMatch/*/*_foo2391=== PAUSE TestGlobMatch/*/*_foo2392=== RUN TestGlobMatch/refs/heads/*_refs/heads/main2393=== PAUSE TestGlobMatch/refs/heads/*_refs/heads/main2394=== RUN TestGlobMatch/refs/heads/*_refs/tags/v1.02395=== PAUSE TestGlobMatch/refs/heads/*_refs/tags/v1.02396=== RUN TestGlobMatch/refs/*/main_refs/heads/main2397=== PAUSE TestGlobMatch/refs/*/main_refs/heads/main2398=== RUN TestGlobMatch/fo?_foo2399=== PAUSE TestGlobMatch/fo?_foo2400=== RUN TestGlobMatch/fo?_fo2401=== PAUSE TestGlobMatch/fo?_fo2402=== RUN TestGlobMatch/fo?_fooo2403=== PAUSE TestGlobMatch/fo?_fooo2404=== RUN TestGlobMatch/?oo_foo2405=== PAUSE TestGlobMatch/?oo_foo2406=== RUN TestGlobMatch/?oo_boo2407=== PAUSE TestGlobMatch/?oo_boo2408=== RUN TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2409=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2410=== RUN TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2411=== PAUSE TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2412=== CONT TestGlobMatch/foo_foo2413=== CONT TestGlobMatch/*/*_foo2414=== CONT TestGlobMatch/fo?_fooo2415=== CONT TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main2416=== CONT TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main2417=== CONT TestGlobMatch/refs/*/main_refs/heads/main2418=== CONT TestGlobMatch/fo?_fo2419=== CONT TestGlobMatch/fo?_foo2420=== CONT TestGlobMatch/*bar_bar2421=== CONT TestGlobMatch/*/*_foo/bar2422=== CONT TestGlobMatch/foo*bar_foobarbaz2423=== CONT TestGlobMatch/foo*bar_foo123bar2424=== CONT TestGlobMatch/foo*bar_foobar2425=== CONT TestGlobMatch/*bar_foo2426=== CONT TestGlobMatch/*bar_foobar2427=== CONT TestGlobMatch/refs/heads/*_refs/tags/v1.02428=== CONT TestGlobMatch/?oo_boo2429=== CONT TestGlobMatch/refs/heads/*_refs/heads/main2430--- PASS: TestScopes_ConfigValidation (0.00s)2431=== CONT TestGlobMatch/foo*_foo2432=== CONT TestGlobMatch/foo*_bar2433=== CONT TestGlobMatch/foo*_foobar2434=== CONT TestGlobMatch/?oo_foo2435=== CONT TestGlobMatch/*_2436=== CONT TestGlobMatch/*_anything2437=== CONT TestGlobMatch/foo_bar2438--- PASS: TestGlobMatch (0.00s)2439 --- PASS: TestGlobMatch/foo_foo (0.00s)2440 --- PASS: TestGlobMatch/*/*_foo (0.00s)2441 --- PASS: TestGlobMatch/fo?_fooo (0.00s)2442 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:myorg/myrepo:ref:refs/heads/main (0.00s)2443 --- PASS: TestGlobMatch/repo:myorg/*:*_repo:otherorg/myrepo:ref:refs/heads/main (0.00s)2444 --- PASS: TestGlobMatch/refs/*/main_refs/heads/main (0.00s)2445 --- PASS: TestGlobMatch/fo?_fo (0.00s)2446 --- PASS: TestGlobMatch/fo?_foo (0.00s)2447 --- PASS: TestGlobMatch/*bar_bar (0.00s)2448 --- PASS: TestGlobMatch/*/*_foo/bar (0.00s)2449 --- PASS: TestGlobMatch/foo*bar_foobarbaz (0.00s)2450 --- PASS: TestGlobMatch/foo*bar_foo123bar (0.00s)2451 --- PASS: TestGlobMatch/foo*bar_foobar (0.00s)2452 --- PASS: TestGlobMatch/*bar_foo (0.00s)2453 --- PASS: TestGlobMatch/*bar_foobar (0.00s)2454 --- PASS: TestGlobMatch/refs/heads/*_refs/tags/v1.0 (0.00s)2455 --- PASS: TestGlobMatch/?oo_boo (0.00s)2456 --- PASS: TestGlobMatch/refs/heads/*_refs/heads/main (0.00s)2457 --- PASS: TestGlobMatch/foo*_foo (0.00s)2458 --- PASS: TestGlobMatch/foo*_bar (0.00s)2459 --- PASS: TestGlobMatch/foo*_foobar (0.00s)2460 --- PASS: TestGlobMatch/?oo_foo (0.00s)2461 --- PASS: TestGlobMatch/*_ (0.00s)2462 --- PASS: TestGlobMatch/*_anything (0.00s)2463 --- PASS: TestGlobMatch/foo_bar (0.00s)24642026/11/11 22:23:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54890/oidc2465--- PASS: TestValidateToken_Expired (0.05s)24662026/11/11 22:23:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54892/oidc2467--- PASS: TestPins_TopLevelShorthand (0.06s)24682026/11/11 22:23:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54896/oidc2469--- PASS: TestValidateToken_BoundClaimsMismatch (0.08s)24702026/11/11 22:23:42 http: TLS handshake error from 127.0.0.1:54895: remote error: tls: bad certificate2471--- PASS: TestNewValidator_KubernetesRequiresCA (0.08s)24722026/11/11 22:23:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54898/oidc2473--- PASS: TestValidateToken_WrongAudience (0.10s)24742026/11/11 22:23:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54900/oidc2475--- PASS: TestValidateToken_BoundSubjectMismatch (0.13s)24762026/11/11 22:23:42 INFO OIDC provider initialized name=kubernetes issuer=https://oidc.eks.invalid/id/ABC1232477--- PASS: TestValidateToken_KubernetesIssuerFromOwnToken (0.13s)24782026/11/11 22:23:42 INFO OIDC provider initialized name=kubernetes issuer=https://127.0.0.1:5490424792026/11/11 22:23:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54906/oidc2480--- PASS: TestValidateToken_KubernetesServiceAccount (0.13s)2481--- PASS: TestPins_ReservedForMatchingRule (0.15s)24822026/11/11 22:23:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54909/oidc2483--- PASS: TestValidateToken_ValidToken (0.15s)24842026/11/11 22:23:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54912/oidc2485--- PASS: TestScopes_LegacyProviderDefaultsToWrite (0.16s)24862026/11/11 22:23:42 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54911/oidc24872026/11/11 22:23:42 INFO OIDC provider initialized name=provider2 issuer=http://127.0.0.1:54914/oidc2488--- PASS: TestValidateToken_MultipleProviders (0.18s)24892026/11/11 22:23:42 INFO OIDC provider initialized name=test issuer=http://127.0.0.1:54917/oidc2490--- PASS: TestScopes_Rules (0.25s)24912026/11/11 22:23:42 INFO OIDC provider initialized name=provider1 issuer=http://127.0.0.1:54889/oidc2492--- PASS: TestValidateToken_NoMatchingProvider (0.28s)2493PASS2494Running hook tests...2495=== RUN TestSendPathsEmpty2496=== PAUSE TestSendPathsEmpty2497=== RUN TestQueueEnqueueAndFetch2498=== PAUSE TestQueueEnqueueAndFetch2499=== RUN TestQueueDeduplication2500=== PAUSE TestQueueDeduplication2501=== RUN TestQueueRemove2502=== PAUSE TestQueueRemove2503=== RUN TestQueueFetchBatchLimit2504=== PAUSE TestQueueFetchBatchLimit2505=== RUN TestQueueRetryMovesToBack2506=== PAUSE TestQueueRetryMovesToBack2507=== RUN TestQueueFetchRemoveLifecycle2508=== PAUSE TestQueueFetchRemoveLifecycle2509=== RUN TestQueueConcurrentWriters2510=== PAUSE TestQueueConcurrentWriters2511=== RUN TestQueueRemoveLargeClosure2512=== PAUSE TestQueueRemoveLargeClosure2513=== RUN TestServerClientIntegration2514--- PASS: TestServerClientIntegration (0.00s)2515=== RUN TestServerQueueError25162026/11/11 22:23:42 ERROR Failed to queue paths error="permission denied" count=12517--- PASS: TestServerQueueError (0.00s)2518=== RUN TestGetListenerSocketActivation2519 server_test.go:145: systemd socket activation does not exist on darwin2520--- SKIP: TestGetListenerSocketActivation (0.00s)2521=== RUN TestServerStalledClientDoesNotBlockShutdown2522=== PAUSE TestServerStalledClientDoesNotBlockShutdown2523=== RUN TestServerBacksOffOnAcceptErrors2524=== PAUSE TestServerBacksOffOnAcceptErrors2525=== RUN TestDrainIsolatesPoisonPath2526=== PAUSE TestDrainIsolatesPoisonPath2527=== RUN TestRunNotBlockedByPoisonHead2528=== PAUSE TestRunNotBlockedByPoisonHead2529=== RUN TestDrainGivesUpWhenServerDown2530=== PAUSE TestDrainGivesUpWhenServerDown2531=== RUN TestFailedPathPrunedByLaterClosure2532=== PAUSE TestFailedPathPrunedByLaterClosure2533=== RUN TestWorkerUploadsAndRemoves2534=== PAUSE TestWorkerUploadsAndRemoves2535=== RUN TestWorkerSkipsGCdPaths2536=== PAUSE TestWorkerSkipsGCdPaths2537=== RUN TestWorkerPrunesClosureDeps2538=== PAUSE TestWorkerPrunesClosureDeps2539=== RUN TestDrainTimeout2540=== PAUSE TestDrainTimeout2541=== RUN TestWorkerRemoveFailureIsNotProgress2542=== PAUSE TestWorkerRemoveFailureIsNotProgress2543=== RUN TestWorkerKeepsPathItCannotStat2544=== PAUSE TestWorkerKeepsPathItCannotStat2545=== CONT TestSendPathsEmpty2546=== CONT TestDrainTimeout2547--- PASS: TestSendPathsEmpty (0.00s)2548=== CONT TestWorkerKeepsPathItCannotStat2549=== CONT TestWorkerRemoveFailureIsNotProgress2550=== CONT TestDrainIsolatesPoisonPath2551=== CONT TestQueueRetryMovesToBack2552=== CONT TestQueueFetchBatchLimit2553=== CONT TestQueueRemove2554=== CONT TestQueueDeduplication2555=== CONT TestQueueEnqueueAndFetch2556=== CONT TestQueueFetchRemoveLifecycle2557=== CONT TestWorkerUploadsAndRemoves2558=== CONT TestServerBacksOffOnAcceptErrors2559=== CONT TestWorkerPrunesClosureDeps25602026/11/11 22:23:42 ERROR Accept failed error="too many open files"2561=== CONT TestServerStalledClientDoesNotBlockShutdown2562=== CONT TestWorkerSkipsGCdPaths2563=== CONT TestQueueRemoveLargeClosure2564=== CONT TestDrainGivesUpWhenServerDown2565=== CONT TestFailedPathPrunedByLaterClosure2566=== CONT TestQueueConcurrentWriters2567=== CONT TestRunNotBlockedByPoisonHead25682026/11/11 22:23:42 ERROR Accept failed error="too many open files"25692026/11/11 22:23:42 INFO Upload queue status pending=225702026/11/11 22:23:42 INFO Uploading batch count=125712026/11/11 22:23:42 INFO Upload queue status pending=225722026/11/11 22:23:42 INFO Uploading batch count=225732026/11/11 22:23:42 WARN Cannot stat store path, will retry later path=/private/var/tb/3/scratch/ba280157b5421d9f/build/TestWorkerKeepsPathItCannotStat2944765966/002/locked/aaa error="stat /private/var/tb/3/scratch/ba280157b5421d9f/build/TestWorkerKeepsPathItCannotStat2944765966/002/locked/aaa: permission denied"25742026/11/11 22:23:42 ERROR Accept failed error="too many open files"25752026/11/11 22:23:42 INFO Uploading batch count=425762026/11/11 22:23:42 ERROR Upload failed error="upload failed" count=425772026/11/11 22:23:42 INFO Upload queue status pending=22578--- PASS: TestQueueFetchRemoveLifecycle (0.02s)25792026/11/11 22:23:42 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/ba280157b5421d9f/build/TestWorkerSkipsGCdPaths3794564567/002/nonexistent25802026/11/11 22:23:42 INFO Uploading batch count=125812026/11/11 22:23:42 ERROR Upload failed error="upload failed" count=125822026/11/11 22:23:42 WARN Cannot stat store path, will retry later path=/private/var/tb/3/scratch/ba280157b5421d9f/build/TestWorkerKeepsPathItCannotStat2944765966/002/locked/aaa error="stat /private/var/tb/3/scratch/ba280157b5421d9f/build/TestWorkerKeepsPathItCannotStat2944765966/002/locked/aaa: permission denied"2583--- PASS: TestQueueEnqueueAndFetch (0.02s)25842026/11/11 22:23:42 WARN Cannot stat store path, will retry later path=/private/var/tb/3/scratch/ba280157b5421d9f/build/TestWorkerKeepsPathItCannotStat2944765966/002/locked/aaa error="stat /private/var/tb/3/scratch/ba280157b5421d9f/build/TestWorkerKeepsPathItCannotStat2944765966/002/locked/aaa: permission denied"2585--- PASS: TestQueueRemove (0.02s)25862026/11/11 22:23:42 INFO Uploading batch count=125872026/11/11 22:23:42 INFO Uploading batch count=225882026/11/11 22:23:42 INFO Uploading batch count=225892026/11/11 22:23:42 ERROR Upload failed error="upload failed" count=225902026/11/11 22:23:42 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/ba280157b5421d9f/build/TestDrainGivesUpWhenServerDown2001413348/002/a25912026/11/11 22:23:42 INFO Uploading batch count=125922026/11/11 22:23:42 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/ba280157b5421d9f/build/TestDrainGivesUpWhenServerDown2001413348/002/b2593--- PASS: TestQueueDeduplication (0.02s)25942026/11/11 22:23:42 ERROR Drain finished with paths left in queue remaining=12595--- PASS: TestQueueRetryMovesToBack (0.02s)25962026/11/11 22:23:42 INFO Upload queue status pending=325972026/11/11 22:23:42 INFO Uploading batch count=125982026/11/11 22:23:42 ERROR Upload failed error="upload failed" count=125992026/11/11 22:23:42 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/ba280157b5421d9f/build/TestDrainIsolatesPoisonPath2442042130/002/bbb26002026/11/11 22:23:42 INFO Uploading batch count=226012026/11/11 22:23:42 ERROR Upload failed error="upload failed" count=226022026/11/11 22:23:42 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/ba280157b5421d9f/build/TestDrainGivesUpWhenServerDown2001413348/002/c26032026/11/11 22:23:42 INFO Uploading batch count=126042026/11/11 22:23:42 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/ba280157b5421d9f/build/TestDrainGivesUpWhenServerDown2001413348/002/d26052026/11/11 22:23:42 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/ba280157b5421d9f/build/TestWorkerRemoveFailureIsNotProgress1213245655/002/nonexistent2606--- PASS: TestQueueFetchBatchLimit (0.02s)26072026/11/11 22:23:42 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126082026/11/11 22:23:42 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/ba280157b5421d9f/build/TestWorkerRemoveFailureIsNotProgress1213245655/002/nonexistent26092026/11/11 22:23:42 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126102026/11/11 22:23:42 INFO Uploading batch count=226112026/11/11 22:23:42 ERROR Upload failed error="upload failed" count=226122026/11/11 22:23:42 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/ba280157b5421d9f/build/TestDrainGivesUpWhenServerDown2001413348/002/e26132026/11/11 22:23:42 WARN Store path no longer exists (garbage collected?), removing from queue path=/private/var/tb/3/scratch/ba280157b5421d9f/build/TestWorkerRemoveFailureIsNotProgress1213245655/002/nonexistent26142026/11/11 22:23:42 ERROR Failed to remove paths from queue error="deleting paths: attempt to write a readonly database (8)" count=126152026/11/11 22:23:42 ERROR Drain finished with paths left in queue remaining=12616--- PASS: TestWorkerKeepsPathItCannotStat (0.02s)26172026/11/11 22:23:42 INFO Uploading batch count=126182026/11/11 22:23:42 ERROR Upload failed error="upload failed" count=12619--- PASS: TestWorkerRemoveFailureIsNotProgress (0.02s)26202026/11/11 22:23:42 INFO Uploading batch count=126212026/11/11 22:23:42 ERROR Upload failed error="upload failed" count=126222026/11/11 22:23:42 ERROR Upload failed, will retry later error="upload failed" path=/private/var/tb/3/scratch/ba280157b5421d9f/build/TestDrainGivesUpWhenServerDown2001413348/002/f26232026/11/11 22:23:42 ERROR Drain finished with paths left in queue remaining=1026242026/11/11 22:23:42 INFO Uploading batch count=126252026/11/11 22:23:42 ERROR Upload failed error="upload failed" count=126262026/11/11 22:23:42 ERROR Drain finished with paths left in queue remaining=12627--- PASS: TestFailedPathPrunedByLaterClosure (0.02s)2628--- PASS: TestDrainGivesUpWhenServerDown (0.02s)2629--- PASS: TestDrainIsolatesPoisonPath (0.03s)2630--- PASS: TestWorkerPrunesClosureDeps (0.03s)2631--- PASS: TestWorkerUploadsAndRemoves (0.03s)26322026/11/11 22:23:42 ERROR Accept failed error="too many open files"2633--- PASS: TestWorkerSkipsGCdPaths (0.04s)2634--- PASS: TestQueueRemoveLargeClosure (0.05s)2635--- PASS: TestQueueConcurrentWriters (0.07s)26362026/11/11 22:23:42 ERROR Accept failed error="too many open files"26372026/11/11 22:23:42 ERROR Accept failed error="too many open files"26382026/11/11 22:23:42 ERROR Failed to decode request error="read unix /private/var/tb/3/scratch/ba280157b5421d9f/build/hook3007127560/test.sock->: i/o timeout"26392026/11/11 22:23:42 ERROR Failed to write response error="write unix /private/var/tb/3/scratch/ba280157b5421d9f/build/hook3007127560/test.sock->: i/o timeout"2640--- PASS: TestServerStalledClientDoesNotBlockShutdown (0.20s)26412026/11/11 22:23:42 ERROR Upload failed error="context deadline exceeded" count=226422026/11/11 22:23:42 ERROR Drain finished with paths left in queue remaining=42643--- PASS: TestDrainTimeout (0.23s)26442026/11/11 22:23:42 ERROR Accept failed error="too many open files"26452026/11/11 22:23:43 ERROR Accept failed error="too many open files"2646--- PASS: TestServerBacksOffOnAcceptErrors (0.64s)26472026/11/11 22:23:43 INFO Uploading batch count=126482026/11/11 22:23:43 INFO Uploading batch count=126492026/11/11 22:23:43 INFO Uploading batch count=126502026/11/11 22:23:43 ERROR Upload failed error="upload failed" count=126512026/11/11 22:23:43 INFO Uploading batch count=126522026/11/11 22:23:43 ERROR Upload failed error="upload failed" count=126532026/11/11 22:23:43 INFO Uploading batch count=126542026/11/11 22:23:43 ERROR Upload failed error="upload failed" count=126552026/11/11 22:23:43 INFO Uploading batch count=126562026/11/11 22:23:43 ERROR Upload failed error="upload failed" count=126572026/11/11 22:23:43 ERROR Drain finished with paths left in queue remaining=12658--- PASS: TestRunNotBlockedByPoisonHead (1.04s)2659PASS2660Running signing tests...2661=== RUN TestExternalSigner2662=== PAUSE TestExternalSigner2663=== RUN TestExternalSignerWrongPublicKey2664=== PAUSE TestExternalSignerWrongPublicKey2665=== RUN TestExternalSignerErrors2666=== PAUSE TestExternalSignerErrors2667=== RUN TestExternalSignerRestartsAfterCrash2668=== PAUSE TestExternalSignerRestartsAfterCrash2669=== RUN TestExternalSignerProgramErrorKeepsProcess2670=== PAUSE TestExternalSignerProgramErrorKeepsProcess2671=== RUN TestExternalSignerClose2672=== PAUSE TestExternalSignerClose2673=== RUN TestExternalSignerRejectsInvalidPublicKey2674=== PAUSE TestExternalSignerRejectsInvalidPublicKey2675=== RUN TestExternalSignerCancellation2676=== PAUSE TestExternalSignerCancellation2677=== RUN TestGenerateFingerprint2678=== PAUSE TestGenerateFingerprint2679=== RUN TestParseSigningKey2680=== PAUSE TestParseSigningKey2681=== RUN TestSign2682=== PAUSE TestSign2683=== RUN TestSignBatch2684=== PAUSE TestSignBatch2685=== RUN TestNilKeyPublicKey2686=== PAUSE TestNilKeyPublicKey2687=== RUN TestSignErrors2688=== PAUSE TestSignErrors2689=== CONT TestExternalSigner2690=== CONT TestExternalSignerCancellation2691=== CONT TestSignErrors2692=== CONT TestSignBatch2693=== CONT TestNilKeyPublicKey2694--- PASS: TestNilKeyPublicKey (0.00s)2695=== CONT TestExternalSignerProgramErrorKeepsProcess2696=== CONT TestExternalSignerRejectsInvalidPublicKey2697=== RUN TestExternalSignerRejectsInvalidPublicKey/#002698=== PAUSE TestExternalSignerRejectsInvalidPublicKey/#002699=== RUN TestExternalSignerRejectsInvalidPublicKey/no-colon2700=== PAUSE TestExternalSignerRejectsInvalidPublicKey/no-colon2701=== RUN TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2702=== PAUSE TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2703=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2704=== CONT TestExternalSignerClose2705=== CONT TestParseSigningKey2706=== RUN TestParseSigningKey/valid_32-byte_key2707=== PAUSE TestParseSigningKey/valid_32-byte_key2708=== CONT TestSign2709=== CONT TestGenerateFingerprint2710=== RUN TestGenerateFingerprint/basic_with_references2711=== CONT TestExternalSignerErrors2712=== RUN TestExternalSignerErrors/null_signatures2713=== PAUSE TestExternalSignerErrors/null_signatures2714=== CONT TestExternalSignerRestartsAfterCrash2715=== CONT TestExternalSignerWrongPublicKey2716=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2717=== RUN TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2718=== PAUSE TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2719=== CONT TestExternalSignerRejectsInvalidPublicKey/#002720=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:invalid!2721=== RUN TestParseSigningKey/valid_32-byte_key_with_different_name2722=== PAUSE TestParseSigningKey/valid_32-byte_key_with_different_name2723=== RUN TestParseSigningKey/no_colon2724=== PAUSE TestParseSigningKey/no_colon2725=== RUN TestParseSigningKey/empty_name2726=== CONT TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=2727=== PAUSE TestGenerateFingerprint/basic_with_references2728=== RUN TestGenerateFingerprint/no_references2729=== RUN TestExternalSignerErrors/program_error2730=== PAUSE TestExternalSignerErrors/program_error2731=== RUN TestExternalSignerErrors/missing_signatures2732=== CONT TestExternalSignerRejectsInvalidPublicKey/no-colon2733=== CONT TestExternalSignerRejectsInvalidPublicKey/test-key:YQ==2734--- PASS: TestExternalSignerRejectsInvalidPublicKey (0.00s)2735 --- PASS: TestExternalSignerRejectsInvalidPublicKey/#00 (0.00s)2736 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:invalid! (0.00s)2737 --- PASS: TestExternalSignerRejectsInvalidPublicKey/:AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA= (0.00s)2738 --- PASS: TestExternalSignerRejectsInvalidPublicKey/no-colon (0.00s)2739 --- PASS: TestExternalSignerRejectsInvalidPublicKey/test-key:YQ== (0.00s)2740=== PAUSE TestParseSigningKey/empty_name2741=== PAUSE TestGenerateFingerprint/no_references2742=== RUN TestGenerateFingerprint/unsorted_references_get_sorted2743=== PAUSE TestExternalSignerErrors/missing_signatures2744=== RUN TestParseSigningKey/invalid_base642745=== PAUSE TestParseSigningKey/invalid_base642746=== RUN TestParseSigningKey/wrong_length2747=== PAUSE TestGenerateFingerprint/unsorted_references_get_sorted2748=== RUN TestExternalSignerErrors/wrong_signatures_shape2749=== PAUSE TestExternalSignerErrors/wrong_signatures_shape2750=== RUN TestExternalSignerErrors/too_few_signatures2751=== PAUSE TestParseSigningKey/wrong_length2752=== CONT TestParseSigningKey/valid_32-byte_key2753=== CONT TestParseSigningKey/invalid_base642754=== PAUSE TestExternalSignerErrors/too_few_signatures2755=== RUN TestExternalSignerErrors/missing_signature_name2756=== PAUSE TestExternalSignerErrors/missing_signature_name2757=== RUN TestExternalSignerErrors/invalid_signature_base642758=== PAUSE TestExternalSignerErrors/invalid_signature_base642759=== RUN TestGenerateFingerprint/invalid_nar_hash_prefix2760=== PAUSE TestGenerateFingerprint/invalid_nar_hash_prefix2761=== RUN TestGenerateFingerprint/invalid_nar_hash_length2762=== PAUSE TestGenerateFingerprint/invalid_nar_hash_length2763=== RUN TestGenerateFingerprint/invalid_store_path_prefix2764=== PAUSE TestGenerateFingerprint/invalid_store_path_prefix2765=== RUN TestGenerateFingerprint/invalid_reference_prefix2766=== CONT TestParseSigningKey/wrong_length2767=== CONT TestParseSigningKey/no_colon2768=== CONT TestParseSigningKey/empty_name2769=== CONT TestParseSigningKey/valid_32-byte_key_with_different_name2770=== RUN TestExternalSignerErrors/wrong_signature_length2771=== PAUSE TestExternalSignerErrors/wrong_signature_length2772=== RUN TestExternalSignerErrors/exit_at_startup2773=== PAUSE TestExternalSignerErrors/exit_at_startup2774=== RUN TestExternalSignerErrors/wrong_shape2775=== PAUSE TestGenerateFingerprint/invalid_reference_prefix2776=== CONT TestGenerateFingerprint/basic_with_references2777=== CONT TestGenerateFingerprint/invalid_nar_hash_length2778=== PAUSE TestExternalSignerErrors/wrong_shape2779=== RUN TestExternalSignerErrors/null2780=== PAUSE TestExternalSignerErrors/null2781=== RUN TestExternalSignerErrors/unrequested_key2782=== PAUSE TestExternalSignerErrors/unrequested_key2783=== RUN TestExternalSignerErrors/invalid_JSON2784=== PAUSE TestExternalSignerErrors/invalid_JSON2785=== CONT TestGenerateFingerprint/invalid_reference_prefix2786=== CONT TestGenerateFingerprint/invalid_store_path_prefix2787=== CONT TestGenerateFingerprint/unsorted_references_get_sorted2788=== CONT TestGenerateFingerprint/invalid_nar_hash_prefix2789=== CONT TestGenerateFingerprint/no_references2790--- PASS: TestGenerateFingerprint (0.00s)2791 --- PASS: TestGenerateFingerprint/basic_with_references (0.00s)2792 --- PASS: TestGenerateFingerprint/invalid_nar_hash_length (0.00s)2793 --- PASS: TestGenerateFingerprint/invalid_reference_prefix (0.00s)2794 --- PASS: TestGenerateFingerprint/invalid_store_path_prefix (0.00s)2795 --- PASS: TestGenerateFingerprint/unsorted_references_get_sorted (0.00s)2796 --- PASS: TestGenerateFingerprint/invalid_nar_hash_prefix (0.00s)2797 --- PASS: TestGenerateFingerprint/no_references (0.00s)2798=== RUN TestExternalSignerErrors/wrong_id2799=== PAUSE TestExternalSignerErrors/wrong_id2800=== RUN TestExternalSignerErrors/wrong_signature_name2801=== PAUSE TestExternalSignerErrors/wrong_signature_name2802=== RUN TestExternalSignerErrors/exit_on_request2803=== PAUSE TestExternalSignerErrors/exit_on_request2804=== CONT TestExternalSignerErrors/null_signatures2805=== CONT TestExternalSignerErrors/exit_at_startup2806=== RUN TestSignErrors/nil_key2807=== PAUSE TestSignErrors/nil_key2808=== RUN TestSignErrors/nil_narinfo2809=== PAUSE TestSignErrors/nil_narinfo2810=== RUN TestSignErrors/invalid_narinfo2811=== PAUSE TestSignErrors/invalid_narinfo2812=== RUN TestSignErrors/canceled2813=== PAUSE TestSignErrors/canceled2814=== CONT TestExternalSignerErrors/too_few_signatures2815--- PASS: TestSign (0.00s)2816=== CONT TestExternalSignerErrors/missing_signatures2817--- PASS: TestParseSigningKey (0.00s)2818 --- PASS: TestParseSigningKey/invalid_base64 (0.00s)2819 --- PASS: TestParseSigningKey/wrong_length (0.00s)2820 --- PASS: TestParseSigningKey/no_colon (0.00s)2821 --- PASS: TestParseSigningKey/empty_name (0.00s)2822 --- PASS: TestParseSigningKey/valid_32-byte_key (0.00s)2823 --- PASS: TestParseSigningKey/valid_32-byte_key_with_different_name (0.00s)2824=== CONT TestSignErrors/nil_key2825=== CONT TestSignErrors/canceled2826=== CONT TestSignErrors/invalid_narinfo2827=== CONT TestExternalSignerErrors/wrong_shape2828=== CONT TestExternalSignerErrors/wrong_signatures_shape2829=== CONT TestExternalSignerErrors/invalid_signature_base642830=== CONT TestExternalSignerErrors/missing_signature_name2831=== CONT TestExternalSignerErrors/invalid_JSON2832=== CONT TestExternalSignerErrors/exit_on_request2833=== CONT TestExternalSignerErrors/wrong_signature_name2834=== CONT TestExternalSignerErrors/wrong_id2835=== CONT TestExternalSignerErrors/null2836=== CONT TestExternalSignerErrors/unrequested_key2837=== CONT TestExternalSignerErrors/program_error2838--- PASS: TestSignBatch (0.00s)2839=== CONT TestExternalSignerErrors/wrong_signature_length2840=== CONT TestSignErrors/nil_narinfo2841--- PASS: TestSignErrors (0.00s)2842 --- PASS: TestSignErrors/nil_key (0.00s)2843 --- PASS: TestSignErrors/canceled (0.00s)2844 --- PASS: TestSignErrors/invalid_narinfo (0.00s)2845 --- PASS: TestSignErrors/nil_narinfo (0.00s)2846--- PASS: TestExternalSigner (0.64s)2847--- PASS: TestExternalSignerCancellation (0.83s)2848--- PASS: TestExternalSignerClose (1.56s)2849--- PASS: TestExternalSignerRestartsAfterCrash (2.14s)2850--- PASS: TestExternalSignerWrongPublicKey (2.31s)2851--- PASS: TestExternalSignerProgramErrorKeepsProcess (4.41s)2852--- PASS: TestExternalSignerErrors (0.00s)2853 --- PASS: TestExternalSignerErrors/null (1.00s)2854 --- PASS: TestExternalSignerErrors/unrequested_key (1.19s)2855 --- PASS: TestExternalSignerErrors/exit_at_startup (1.37s)2856 --- PASS: TestExternalSignerErrors/missing_signatures (1.74s)2857 --- PASS: TestExternalSignerErrors/wrong_signature_length (1.93s)2858 --- PASS: TestExternalSignerErrors/wrong_signatures_shape (2.50s)2859 --- PASS: TestExternalSignerErrors/null_signatures (2.69s)2860 --- PASS: TestExternalSignerErrors/wrong_shape (2.88s)2861 --- PASS: TestExternalSignerErrors/missing_signature_name (3.07s)2862 --- PASS: TestExternalSignerErrors/invalid_JSON (3.26s)2863 --- PASS: TestExternalSignerErrors/exit_on_request (3.45s)2864 --- PASS: TestExternalSignerErrors/too_few_signatures (3.64s)2865 --- PASS: TestExternalSignerErrors/invalid_signature_base64 (3.83s)2866 --- PASS: TestExternalSignerErrors/wrong_id (4.21s)2867 --- PASS: TestExternalSignerErrors/program_error (4.60s)2868 --- PASS: TestExternalSignerErrors/wrong_signature_name (4.78s)2869PASS2870Running OpenBao signer tests...2871=== RUN TestSign2872=== PAUSE TestSign2873=== RUN TestSignErrors2874=== PAUSE TestSignErrors2875=== RUN TestServe2876=== PAUSE TestServe2877=== RUN TestServeRejectsGarbage2878=== PAUSE TestServeRejectsGarbage2879=== CONT TestSign2880=== CONT TestSignErrors2881=== RUN TestSignErrors/http_error2882=== CONT TestServeRejectsGarbage2883=== CONT TestServe2884--- PASS: TestServeRejectsGarbage (0.00s)2885=== PAUSE TestSignErrors/http_error2886=== RUN TestSignErrors/invalid_json2887=== PAUSE TestSignErrors/invalid_json2888=== RUN TestSignErrors/no_prefix2889=== PAUSE TestSignErrors/no_prefix2890=== RUN TestSignErrors/invalid_base642891=== PAUSE TestSignErrors/invalid_base642892=== CONT TestSignErrors/http_error2893=== CONT TestSignErrors/no_prefix2894=== CONT TestSignErrors/invalid_base642895=== CONT TestSignErrors/invalid_json2896--- PASS: TestServe (0.00s)2897--- PASS: TestSign (0.00s)2898--- PASS: TestSignErrors (0.00s)2899 --- PASS: TestSignErrors/invalid_json (0.00s)2900 --- PASS: TestSignErrors/no_prefix (0.00s)2901 --- PASS: TestSignErrors/http_error (0.00s)2902 --- PASS: TestSignErrors/invalid_base64 (0.00s)2903PASS